TheShanMan 34 Posted December 29, 2015 Share Posted December 29, 2015 When I use the web interface to watch live tv or cast live tv from my phone to my TV's chromecast, the stream always dies at some seemingly random spot. Sometimes it's 5 minutes in, sometimes it's an hour or so in, but usually it happens somewhere around 10 to 20 minutes. My wild guess is that perhaps it has trouble dealing with signal issues from an antenna that doesn't give a perfect signal all the time. Perhaps if there's a break in the signal for greater than a certain threshold, it gives up. Sometimes after this problem happens, it's hard/impossible to get another live tv stream going again. The emby server as a whole seems to bog down extremely. Restarting emby and/or ServerWMC doesn't seem to fix it so I end up having to reboot. I haven't seen this happen with recordings although I don't record very much. Would this be a ServerWMC problem or an emby problem? How can I troubleshoot and hopefully fix this? It pretty much makes live tv useless. Link to comment Share on other sites More sharing options...
krustyreturns 191 Posted December 29, 2015 Share Posted December 29, 2015 Did you try this: http://emby.media/community/index.php?/topic/22609-fix-for-problem-of-live-streams-stopping-early/ Link to comment Share on other sites More sharing options...
TheShanMan 34 Posted December 29, 2015 Author Share Posted December 29, 2015 I haven't but thank you so much for pointing me to it. I'll try it!!! Link to comment Share on other sites More sharing options...
TheShanMan 34 Posted December 30, 2015 Author Share Posted December 30, 2015 That seems to help but not solve my problem entirely. I was able to play a channel in the web interface for 5 hours today without it stopping (over the internet!). It also seemed to help somewhat with casting from my phone to my chromecast tonight, but eventually my emby server seemed to bog down again. I think the bogging down isn't a symptom of the problem but actually a cause. In other words, once it bogs down enough, the stream eventually dies. So the question is why is it bogging down? It only happens when I play live TV so I know I can't blame it on something else going on with my server. Interestingly, it doesn't appear that ServerWMC is closing the streams, at least when using chromecast. Here is the ServerWMC status page with nothing actually playing anymore: WMC database : 'Opened' Channels found: 63 Tuners found: 3 Clients online: Emby^THEATER Totals of items transferred to clients: Channels: 62 EPG Entries: 13940 Timers: 14 Recordings: 195 Active Recordings: ActiveStreams: Streaming ATSC channel 32.2 to [Emby^THEATER^3] Streaming ATSC channel 6.1 to [Emby^THEATER^5] Tuners: Hauppauge WinTV-7164 BDA ATSC/QAM Tuner #1, Space: ATSC, Channel_Count: 62, Status: LiveTv, Clients: Emby^THEATER^3, Channel: ANTEN/32.2, Program: One Day at a Time Hauppauge WinTV-7164 Analog TV Tuner #1, Space: FM Radio, Channel_Count: 0, Status: Available, Clients: Hauppauge WinTV-7164 BDA ATSC/QAM Tuner #2, Space: ATSC, Channel_Count: 62, Status: LiveTv, Clients: Emby^THEATER^5, Channel: KOINHD/6.1, Program: NCIS Those "active streams" are the last 2 things I watched. The first I stopped in order to switch to the channel shown in the second, and the second one is the one that died when the system bogged down. I'm not sure if these streams not closing is the cause of the bogging down but I have to think it's not helping matters any. How do I get them to close? Or is it a bug? How do I determine what is causing the system to bog way down? Process Explorer doesn't seem to help me much oddly enough. The cpu isn't pegged and memory usage isn't extreme yet just as an example it took a minute or 2 for Process Explorer to even launch. FWIW the log file doesn't have anything relating to these streams or anything else while the streams were running, much less anything about the streams dying. As a secondary issue (nit pic), I use ServerWMC as a service and when I launch the app to change settings the HTTP tab says "error starting service, see log". When I first set this up on your advice I thought something was wrong, but the "issue" was that the windows service had already opened the port so the app couldn't also do it. The error message really ought to be more accurate than that, perhaps being smart enough to know the state of the HTTP listener in the service, or at least saying something better like "error starting service, it may be running already in another process, otherwise see log". Appreciate the help! Link to comment Share on other sites More sharing options...
krustyreturns 191 Posted December 30, 2015 Share Posted December 30, 2015 I'm not sure why the streams aren't closing either, but the serverwmc log should have the answer (my guess is its a client app problem). If you want to know whether its just the fact that two streams are running that is causing the 'bogging down' of the server, why not just run two live streams in two web browser windows simultaneously? If your processor is not pegging, then I expect its your disk that might be the bottleneck (that might also explain why it took so long to start explorer). Link to comment Share on other sites More sharing options...
krustyreturns 191 Posted December 30, 2015 Share Posted December 30, 2015 Also, I get your point about the start up error message, I'll fix that. Link to comment Share on other sites More sharing options...
TheShanMan 34 Posted December 30, 2015 Author Share Posted December 30, 2015 I'm not sure why the streams aren't closing either, but the serverwmc log should have the answer (my guess is its a client app problem). If you want to know whether its just the fact that two streams are running that is causing the 'bogging down' of the server, why not just run two live streams in two web browser windows simultaneously? If your processor is not pegging, then I expect its your disk that might be the bottleneck (that might also explain why it took so long to start explorer). Turns out the reason the log file had nothing relevant is because the app opens the wrong log file (the one for the app, not the one for the service). Another example of where another instructive message in the UI about configurations which use the service could be helpful. So here is a good chunk of the log file, from before the stream died until I rebooted the machine. 2015/12/29 19:57:00.066 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:00.066 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:03.586 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:03.586 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:07.148 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:07.148 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:10.695 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:10.696 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:14.278 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:14.278 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:18.274 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:18.274 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:21.857 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:21.857 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:25.375 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:25.375 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:28.923 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:28.923 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:32.461 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:32.461 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:36.109 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:36.109 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:39.720 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:39.720 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:43.278 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:43.278 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:46.817 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:46.817 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:50.350 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:50.350 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:53.986 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:53.986 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:57:57.556 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:57:57.556 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:58:01.087 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:58:01.088 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:58:04.730 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:58:04.730 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:58:04.793 WriteChunk> long interval between writes (ms): 3047 2015/12/29 19:58:04.793 WriteChunk> long interval between writes (ms): 3047 2015/12/29 19:58:08.293 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 19:58:08.293 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 19:58:11.363 Received client request: MediaBrowser^@THEATER@6|127.0.0.1|CloseLiveStream 2015/12/29 19:58:11.363 CloseStream> -----------------start------------------------ 2015/12/29 19:58:11.459 DeleteTS> ts file size: 14,039,875,584 2015/12/29 19:58:11.626 RemoveMuxOutput> ts file deleted: C:\Users\Public\Recorded TV\TempSWMC\LiveTV_Emby^THEATER^6_ATSC_6.1_2015_12_29_18_16_10.ts 2015/12/29 19:58:11.626 RemoveMultiStreamOutput> MuxFilter output removed for Emby^THEATER^6 2015/12/29 19:58:11.626 Close> closed stream for client: Emby^THEATER^6 2015/12/29 19:58:11.626 CloseStream> -----------------done------------------------- 2015/12/29 19:58:11.627 Finished request CloseLiveStream in 0.26s 2015/12/29 19:58:21.707 GetNextGuid> meta chunk found, guid count: 4012828, file offset: 3400C0000 (13,959,430,144) 2015/12/29 19:58:21.707 GetNextGuid> before offset guid: Guid: Null, len: 0, pad 0, sId: 0, WtvCnt: 0, isValid: False (guidIsEmpty) 2015/12/29 19:58:21.707 GetNextGuid> after offset guid: Guid: DSATTRIB_CAPTURE_STREAMTIME, len: 40, pad 0, sId: 18, WtvCnt: 899512, isValid: True 2015/12/29 19:58:21.707 GetNextGuid> meta offset added to skip list, skip count: 4 2015/12/29 19:58:21.708 AdvanceDataRead> meta chunk at offset: 3400C0000 (13,959,430,144) skipped 2015/12/29 20:02:20.607 MaintenanceTimer> Callback started... 2015/12/29 20:02:20.607 RecordingCache_Refresh> [TimerMaintenance] Cache background refresh started. 2015/12/29 20:02:20.607 TimerCache_Refresh> [TimerMaintenance] Cache background refresh started. 2015/12/29 20:02:20.609 MaintenanceTimer> Callback completed in 0.00 sec. 2015/12/29 20:02:20.654 TimerCache_WorkerCompleted> [TimerMaintenance] Cache background refresh completed in 0.05 sec, client: Emby^THEATER. 2015/12/29 20:02:20.698 RecordingCache_WorkerCompleted> [TimerMaintenance] Cache background refresh completed in 0.09 sec, client: Emby^THEATER. 2015/12/29 20:10:18.387 Received client request: MediaBrowser^@THEATER@|127.0.0.1|GetTranscodeProfiles|118900 2015/12/29 20:10:18.387 Finished request GetTranscodeProfiles in 0.00s 2015/12/29 20:10:20.643 MaintenanceTimer> Callback started... 2015/12/29 20:10:20.643 RecordingCache_Refresh> [TimerMaintenance] Cache background refresh started. 2015/12/29 20:10:20.643 TimerCache_Refresh> [TimerMaintenance] Cache background refresh started. 2015/12/29 20:10:20.644 MaintenanceTimer> Callback completed in 0.00 sec. 2015/12/29 20:10:20.673 TimerCache_WorkerCompleted> [TimerMaintenance] Cache background refresh completed in 0.03 sec, client: Emby^THEATER. 2015/12/29 20:10:20.732 RecordingCache_WorkerCompleted> [TimerMaintenance] Cache background refresh completed in 0.09 sec, client: Emby^THEATER. 2015/12/29 20:14:51.437 WriteChunk> long interval between writes (ms): 2206 2015/12/29 20:15:26.714 WriteChunk> long interval between writes (ms): 2178 2015/12/29 20:15:39.554 WriteChunk> long interval between writes (ms): 2110 2015/12/29 20:17:26.461 GetPage> Status 2015/12/29 20:18:20.679 MaintenanceTimer> Callback started... 2015/12/29 20:18:20.679 RecordingCache_Refresh> [TimerMaintenance] Cache background refresh started. 2015/12/29 20:18:20.679 TimerCache_Refresh> [TimerMaintenance] Cache background refresh started. 2015/12/29 20:18:20.680 MaintenanceTimer> Callback completed in 0.00 sec. 2015/12/29 20:18:20.750 TimerCache_WorkerCompleted> [TimerMaintenance] Cache background refresh completed in 0.07 sec, client: Emby^THEATER. 2015/12/29 20:18:20.779 RecordingCache_WorkerCompleted> [TimerMaintenance] Cache background refresh completed in 0.10 sec, client: Emby^THEATER. 2015/12/29 20:24:59.882 WriteChunk> long interval between writes (ms): 3473 2015/12/29 20:26:04.995 WriteChunk> long interval between writes (ms): 2125 2015/12/29 20:26:20.703 MaintenanceTimer> Callback started... 2015/12/29 20:26:20.703 RecordingCache_Refresh> [TimerMaintenance] Cache background refresh started. 2015/12/29 20:26:20.703 TimerCache_Refresh> [TimerMaintenance] Cache background refresh started. 2015/12/29 20:26:20.704 MaintenanceTimer> Callback completed in 0.00 sec. 2015/12/29 20:26:20.738 TimerCache_WorkerCompleted> [TimerMaintenance] Cache background refresh completed in 0.04 sec, client: Emby^THEATER. 2015/12/29 20:26:20.793 RecordingCache_WorkerCompleted> [TimerMaintenance] Cache background refresh completed in 0.09 sec, client: Emby^THEATER. 2015/12/29 20:28:32.435 GetNextGuid> meta chunk found, guid count: 5375281, file offset: 437040000 (18,102,878,208) 2015/12/29 20:28:32.435 GetNextGuid> before offset guid: Guid: Null, len: 0, pad 0, sId: 0, WtvCnt: 0, isValid: False (guidIsEmpty) 2015/12/29 20:28:32.435 GetNextGuid> after offset guid: Guid: NO DESC GIVEN 2, len: 116, pad 4, sId: 17, WtvCnt: 1331206, isValid: True 2015/12/29 20:28:32.436 GetNextGuid> meta offset added to skip list, skip count: 5 2015/12/29 20:28:32.436 AdvanceDataRead> meta chunk at offset: 437040000 (18,102,878,208) skipped 2015/12/29 20:34:20.734 MaintenanceTimer> Callback started... 2015/12/29 20:34:20.734 RecordingCache_Refresh> [TimerMaintenance] Cache background refresh started. 2015/12/29 20:34:20.734 TimerCache_Refresh> [TimerMaintenance] Cache background refresh started. 2015/12/29 20:34:20.736 MaintenanceTimer> Callback completed in 0.00 sec. 2015/12/29 20:34:26.285 TimerCache_WorkerCompleted> [TimerMaintenance] Cache background refresh completed in 5.55 sec, client: Emby^THEATER. 2015/12/29 20:34:27.416 RecordingCache_WorkerCompleted> [TimerMaintenance] Cache background refresh completed in 6.68 sec, client: Emby^THEATER. 2015/12/29 20:39:59.914 WriteChunk> long interval between writes (ms): 2520 2015/12/29 20:40:02.573 GetNextGuid> end of stream is coming, next empty guid will terminate 2015/12/29 20:40:02.573 GetNextGuid> wtv file size: 3,304,325,120 (0xC4F40000) 2015/12/29 20:40:02.588 WtvToPesDemuxer::Parse> Guid header detects stream end 2015/12/29 20:40:02.588 Pass Type: 'Remux': 2015/12/29 20:40:02.588 > WtvToPesDemuxer::Parse> total guid headers processed: 3,042,580 2015/12/29 20:40:02.588 > WtvToPesDemuxer::Parse> total data packets processed: 344,263 2015/12/29 20:40:02.588 Remux> ENDED, >>>>>>>>>> Run Time: 148.56 min <<<<<<<<<< 2015/12/29 20:40:02.776 WriteChunk> long interval between writes (ms): 2121 2015/12/29 20:40:21.308 WriteChunk> long interval between writes (ms): 15022 2015/12/29 20:40:23.024 Received client request: MediaBrowser^@THEATER@0|127.0.0.1|CloseLiveStream 2015/12/29 20:40:23.024 CloseStream> -----------------start------------------------ 2015/12/29 20:40:23.024 CloseStream> -----------------done------------------------- 2015/12/29 20:40:23.024 Finished request CloseLiveStream in 0.00s 2015/12/29 20:40:23.024 Received client request: MediaBrowser^@THEATER@3|127.0.0.1|CloseLiveStream 2015/12/29 20:40:23.024 CloseStream> -----------------start------------------------ 2015/12/29 20:40:23.024 LiveRemuxStream::Close> remux thread had already stopped 2015/12/29 20:40:23.087 DeleteTS> ts file size: 3,273,293,824 2015/12/29 20:40:23.430 LiveRemuxStream::Close> ts file deleted: C:\Users\Public\Recorded TV\TempSWMC\LiveTV_Emby^THEATER^3_ATSC_32.2_2015_12_29_18_11_26.ts 2015/12/29 20:40:23.445 WriteChunk> long interval between writes (ms): 2137 2015/12/29 20:40:23.664 RecordToWTV::Close> exception at recorded stop: The RPC server is unavailable. (Exception from HRESULT: 0x800706BA) 2015/12/29 20:40:23.664 LiveRemuxStream::Close> wtv closed successfully 2015/12/29 20:40:23.726 LiveRemuxStream::Close> wtv file size: 3,304,325,120 (0xC4F40000) 2015/12/29 20:40:23.726 LiveRemuxStream::Close> wtv file deleted: C:\Users\Public\Recorded TV\TempSWMC\LiveTV_Emby^THEATER^3_ATSC_32.2_2015_12_29_18_11_26.wtv 2015/12/29 20:40:23.726 LiveRemuxStream::Close> closed in 0.70 sec 2015/12/29 20:40:23.726 Close> closed stream for client: Emby^THEATER^3 2015/12/29 20:40:23.726 CloseStream> -----------------done------------------------- 2015/12/29 20:40:23.726 Finished request CloseLiveStream in 0.70s 2015/12/29 20:40:23.726 Received client request: MediaBrowser^@THEATER@5|127.0.0.1|CloseLiveStream 2015/12/29 20:40:23.726 CloseStream> -----------------start------------------------ 2015/12/29 20:40:23.726 Remux::Stop> stop remux requested 2015/12/29 20:40:24.007 Pass Type: 'Remux': 2015/12/29 20:40:24.007 > WtvToPesDemuxer::Parse> total guid headers processed: 5,892,786 2015/12/29 20:40:24.007 > WtvToPesDemuxer::Parse> total data packets processed: 855,483 2015/12/29 20:40:24.007 Remux> ENDED, >>>>>>>>>> Run Time: 144.25 min <<<<<<<<<< 2015/12/29 20:40:24.038 LiveRemuxStream::Close> remux stopped successfully 2015/12/29 20:40:24.101 DeleteTS> ts file size: 19,814,481,920 2015/12/29 20:40:24.397 LiveRemuxStream::Close> ts file deleted: C:\Users\Public\Recorded TV\TempSWMC\LiveTV_Emby^THEATER^5_ATSC_6.1_2015_12_29_18_16_07.ts 2015/12/29 20:40:24.397 RecordToWTV::Close> exception at recorded stop: The RPC server is unavailable. (Exception from HRESULT: 0x800706BA) 2015/12/29 20:40:24.397 LiveRemuxStream::Close> wtv closed successfully 2015/12/29 20:40:24.459 LiveRemuxStream::Close> wtv file size: 19,678,363,648 (0x494EC0000) 2015/12/29 20:40:24.740 LiveRemuxStream::Close> wtv file deleted: C:\Users\Public\Recorded TV\TempSWMC\LiveTV_Emby^THEATER^5_ATSC_6.1_2015_12_29_18_16_07.wtv 2015/12/29 20:40:24.740 LiveRemuxStream::Close> closed in 1.01 sec 2015/12/29 20:40:24.740 Close> closed stream for client: Emby^THEATER^5 2015/12/29 20:40:24.740 CloseStream> -----------------done------------------------- 2015/12/29 20:40:24.740 Finished request CloseLiveStream in 1.01s 2015/12/29 20:40:24.990 Received client request: MediaBrowser^@THEATER@|127.0.0.1|ClientGoingDown 2015/12/29 20:40:24.990 ClientGoingDown> Client 'Emby^THEATER' disconnecting 2015/12/29 20:40:25.395 Finished request ClientGoingDown in 0.41s 2015/12/29 20:40:28.328 GetTunerStatus> error: System.Runtime.InteropServices.COMException (0x80040154): Retrieving the COM class factory for component with CLSID {F4396DC6-E851-4D3A-8D01-34E6949F3500} failed due to the following error: 80040154 Class not registered (Exception from HRESULT: 0x80040154 (REGDB_E_CLASSNOTREG)). at ServerWMC.Worker.Tuner.GetRecorderInfo(Guid guid) at ServerWMC.Worker.Tuner.GetTunerStatus(Boolean logNonErrors) 2015/12/29 20:40:28.328 GetTunerStatus> returning empty tuner list 2015/12/29 20:40:28.593 GetTunerStatus> error: System.Runtime.InteropServices.COMException (0x80040154): Retrieving the COM class factory for component with CLSID {F4396DC6-E851-4D3A-8D01-34E6949F3500} failed due to the following error: 80040154 Class not registered (Exception from HRESULT: 0x80040154 (REGDB_E_CLASSNOTREG)). at ServerWMC.Worker.Tuner.GetRecorderInfo(Guid guid) at ServerWMC.Worker.Tuner.GetTunerStatus(Boolean logNonErrors) 2015/12/29 20:40:28.593 GetTunerStatus> returning empty tuner list 2015/12/29 20:40:28.593 GetTunerStatus> error: System.Runtime.InteropServices.COMException (0x80040154): Retrieving the COM class factory for component with CLSID {F4396DC6-E851-4D3A-8D01-34E6949F3500} failed due to the following error: 80040154 Class not registered (Exception from HRESULT: 0x80040154 (REGDB_E_CLASSNOTREG)). at ServerWMC.Worker.Tuner.GetRecorderInfo(Guid guid) at ServerWMC.Worker.Tuner.GetTunerStatus(Boolean logNonErrors) 2015/12/29 20:40:28.593 GetTunerStatus> returning empty tuner list Are you saying you think running 2 streams will help figure this out? I didn't necessarily think it was 2 streams that was causing it. I was just thinking that it was, over time, consuming more and more resources and not freeing them up or something along those lines (obviously not memory since that didn't seem to be an issue). So rather than being caused by 2 simultaneous streams, my thinking was that it's just the more you use it (changing channels and whatnot), the sooner you'll bring about the problem. I was also thinking perhaps it's related to casting to my chromecast since that adds an extra layer of complexity. If you want me to do some debugging though, such as running 2 streams in a web browser, I'd be happy to try whatever you want. You're probably right about disk I/O. I was thinking I had Process Explorer set to show disk I/O but instead it's showing network I/O. Next time it happens I'll check for disk I/O but I'd bet money you're right. That'll be helpful too because it will tell me which process is doing it so I can bounce that process/service rather than rebooting the machine. Appreciate the help. Hopefully you can find the smoking gun in those logs. Link to comment Share on other sites More sharing options...
krustyreturns 191 Posted December 30, 2015 Share Posted December 30, 2015 According to this log a stream was closed, When you can, please restart swmc then do the channel switch - and assuming it fails to close the first stream - then post that log (the entire log). No need to stop swmc or emby The only resource that I know of that would start to tax the system is having multiple streams running, so I am assuming its multiple streams that is bogging you down. Also looking at the log you posted, swmc is reporting quite a few times that it is having trouble writing data to the disk - so I think a disk bottleneck is probably likely. Link to comment Share on other sites More sharing options...
TheShanMan 34 Posted December 30, 2015 Author Share Posted December 30, 2015 2 streams running in and of itself shouldn't cause a fairly powerful machine to massively bog down, so why it's causing the problem is the question. The stream wasn't closed by me. If it was closed by emby then it was closed because it gave up waiting for the stream to continue (i.e. ServerWMC was failing to stream reliably). I'll try again later and post my results, and since I'll be able to see which process is causing all the disk I/O this time, hopefully it'll help get us a step closer to figuring out the problem. Thanks! As an aside, would you expect different results if I'm streaming an "in progress" recording as opposed to Live TV? I'm curious to see how reliable this is. I'm assuming it's a very different scenario and will probably not suffer from this same issue. Link to comment Share on other sites More sharing options...
krustyreturns 191 Posted December 30, 2015 Share Posted December 30, 2015 Playing an in-progress recording is almost the same thing, except its the windows recording service that started capturing data in a wtv file and not emby/serverwmc. We also know that the recording service closes the stream once the recording completes, but we need to see if emby is sending the close live stream command when you change channels on your client. Also, do you have this close problem if you stop the stream on your client and then start a new channel? Rather than trying to switch channels? Link to comment Share on other sites More sharing options...
TheShanMan 34 Posted December 31, 2015 Author Share Posted December 31, 2015 Reproduced it tonight. I changed back and forth between 2 channels a bunch of times. I attached the log file. I started streaming at about 6:28 PM. As you can see from the screenshot of the status page, it kept opening new streams each time I switched channels but the old ones remained open for the most part. Does that suggest that Emby is misbehaving? Even so, shouldn't it be able to detect that nothing is listening to the stream and auto-close it? I'm not sure if I've tried stopping a stream and then switching to the next channel. I think (yesterday and today at least) I've only changed channels without stopping the last one first. Perhaps I'll try that next. And this time it didn't bog down quite as much as last night but the system was still a lot less responsive than usual. And looking at Process Explorer, the main disk I/O culprit was both serverwmc and ehrecvr.exe. So yesterday when I tried restarting emby and serverwmc it was still bogged down. Tonight I restarted serverwmc and killed ehrecvr.exe and it was no longer bogged down. Hopefully this all helps. BTW, it might be nice if there was a way via the http site to manually kill a stream if it doesn't get closed properly. ServerWMC_Service.1.log Link to comment Share on other sites More sharing options...
TheShanMan 34 Posted December 31, 2015 Author Share Posted December 31, 2015 (edited) I get the sense that if there is any hiccup in the TV signal (I'm using an antenna and it may not be perfect at pulling in the signal 100% of the time), a new stream starts. I think I experienced that after the experiment in the last post. The result is emby seems to start another stream in an attempt to jump start the video. I ended up with 3 streams listed on the status page, and then eventually the stream died. Bear in mind this is without ANY channel changing, and also remember that this is casting from my phone to a chromecast, just as in the prior couple of tests. Another symptom of this "bogging down" problem is the emby android app displays a spinner literally forever when trying to populate the dynamic menu items and it's clearly hung trying to find out about the live TV stuff, because if I kill ehrecvr.exe and then restart the android app, it has no problem populating the menu. So once again, extra streams are getting created without the old ones closing (and whether emby is misbehaving or not, I wonder if serverwmc should be smart enough to auto-close them eventually), and ehrecvr.exe is ending up in a bad state. BTW, I now see that ehrecvr.exe is "Windows Media Center Receiver Service" (probably not news to you though). Edited December 31, 2015 by TheShanMan Link to comment Share on other sites More sharing options...
TheShanMan 34 Posted December 31, 2015 Author Share Posted December 31, 2015 (edited) This morning I was trying just playing live tv on my phone (no chromecasting). For whatever reason, I was getting an error like "there was an error processing your request" so I couldn't get it to play. Nevertheless, it opened a stream in ServerWMC that remained open. Next, I went back to casting. I could see the stream listed in ServerWMC, and when I pressed stop, it was no longer listed. So here is an overall summary of my observations... Sure seems to me like emby must not be doing its job of closing the stream in all cases. I'd like your confirmation and then either you or I can report the problem (I'm happy to do so but perhaps you'd be able to provide better technical guidance). I'm not sure if that's quite the same as the earlier scenario where emby seems to be restarting the stream over and over when there are hiccups in ServerWMC's stream. The more streams there are, the more the computer seems to bog down, so leaving these streams open absolutely can't happen. Even if emby doesn't tell ServerWMC to close a stream, ServerWMC ought to auto-close the stream once it detects that nothing is listening to it anymore. Ehrecvr is being left active. Maybe that's a direct reflection of the streams being left open in ServerWMC (and therefore the problem will disappear once streams are no longer left open), or maybe it's a different aspect of this problem that requires some attention in and of itself. I'm not sure. Emby's web interface didn't seem to suffer from these problems, though I want to do further testing here to verify. That sums it up, but the details provided in prior posts may still be helpful so it might still be worth reading them if you haven't already. Edited December 31, 2015 by TheShanMan Link to comment Share on other sites More sharing options...
TheShanMan 34 Posted January 3, 2016 Author Share Posted January 3, 2016 Bumping this now that this site is back up. Link to comment Share on other sites More sharing options...
krustyreturns 191 Posted January 4, 2016 Share Posted January 4, 2016 Looking through the last log you posted... I see that Emby opens streams with ID: 0,1,2,3,4,5,6,7,8,9,10,11,12 (this is in the order they were opened in the log) It issues a close streams for IDs: 1,3,5,7,10,9,12,11 (this is in the order they were closed in the log) So obviously not all the streams were closed. Assuming you used one client to start/stop all these streams emby should have been issuing a close command before each stream was opened. Link to comment Share on other sites More sharing options...
TheShanMan 34 Posted January 4, 2016 Author Share Posted January 4, 2016 OK, so you've confirmed my suspicion (although I'm not sure if it would be an emby android or emby server bug). Thanks! What are the next steps? And shouldn't ServerWMC recognize that unclosed streams are dead and auto-close them? Link to comment Share on other sites More sharing options...
krustyreturns 191 Posted January 4, 2016 Share Posted January 4, 2016 Serverwmc will auto-close the stream if it detects nothing is reading data from the temp file it creates, but if emby is still reading data then this fails. I assume its a problem with the android client since this problem doesn't happen with web clients (last I checked!) - so I guess the next step is to report a bug there. Link to comment Share on other sites More sharing options...
TheShanMan 34 Posted January 5, 2016 Author Share Posted January 5, 2016 Thanks! Started a thread about it in the android forum: http://emby.media/community/index.php?/topic/29500-not-closing-live-tv-streams/ Link to comment Share on other sites More sharing options...
Luke 37008 Posted January 7, 2018 Share Posted January 7, 2018 @@TheShanMan We now have native Hauppauge support available for testing in the Emby Server beta: https://emby.media/community/index.php?/topic/54560-32609-hauppauge-support/?hl=hauppauge No plugin required. Thanks ! Link to comment Share on other sites More sharing options...
Recommended Posts
Create an account or sign in to comment
You need to be a member in order to leave a comment
Create an account
Sign up for a new account in our community. It's easy!
Register a new accountSign in
Already have an account? Sign in here.
Sign In Now