ServerWMC Can't Play Audio Only Channels?

[theniteow1 25]

Hello, I'm just now discovering that ServerWMC doesn't seem to have the ability to play Audio Only Channels from my Cable company (Music Channels).  It never captures the stream and Emby just does the endless spinning circle.  I checked the logs, and it looks like it is definitely ServerWMC having an issue with it.  Has anybody found a work around for this?

 

2016/08/16 14:52:19.612 OpenLiveStream> -----------------start------------------------

2016/08/16 14:52:19.612 OpenLiveStream> transcode profile will be set to: none

2016/08/16 14:52:19.625 OpenLiveStream> client: Emby^MCSERVER requesting live stream on channel DMX: 80's Hits/918

2016/08/16 14:52:19.634 LiveRemuxStream> live-tv started

2016/08/16 14:52:19.637 SetChannel> Channel: 918 : DMX - 6322 = { (918 : DMX - 3002) + [ 900 : DMX - 629B, 901 : DMX - 629E, 902 : DMX - 62A1, 903 : DMX - 62A4, 904 : DMX - 62A7, 905 : DMX - 62AA, 908 : DMX - 62AD, 909 : DMX - 62B0, 911 : DMX - 62B3, 912 : DMX - 62B6, 913 : DMX - 62B9, 914 : DMX - 62BC, 915 : DMX - 62BF, 916 : DMX - 62C2, 917 : DMX - 62C5, 918 : DMX - 62C8, 919 : DMX - 62CB, 920 : DMX - 62CE, 921 : DMX - 62D1, 922 : DMX - 62D4, 923 : DMX - 62D7, 924 : DMX - 62DA, 925 : DMX - 62DD, 927 : DMX - 62E0, 928 : DMX - 62E3, 929 : DMX - 62E6, 930 : DMX - 62E9, 931 : DMX - 62EC, 932 : DMX - 62EF, 933 : DMX - 62F2, 935 : DMX - 62F5, 937 : DMX - 62F8, 939 : DMX - 62FB, 941 : DMX - 62FE] }

2016/08/16 14:52:19.645 SetChannel> Tuners available for this channel: 136

2016/08/16 14:52:19.645 SetChannel> Tuner DecoyMethod: OnDemand

2016/08/16 14:52:19.645 SetChannel> ---

2016/08/16 14:52:19.645 SetChannel> Attempt: 0,  Tuner: Hauppauge OpenCable Receiver 2010404A-1 / 2c252d67-de53-44af-9f5c-1d395723cb77

2016/08/16 14:52:19.645 SetChannel> > Encrypted: False

2016/08/16 14:52:19.647 SetChannel> > RecorderInfo found: True

2016/08/16 14:52:19.648 SetChannel> > Recorder Content Protection: PROT_COPY_FREE

2016/08/16 14:52:19.648 SetChannel> > Status: Available, client: 

2016/08/16 14:52:19.648 SetChannel>    ***  requested number of available tuners found, stopping search  ***

2016/08/16 14:52:19.648 SetChannel> ---

2016/08/16 14:52:19.648 SetChannel> available tuners found: 1 [decoys:0], requested: 1, searched: 1

2016/08/16 14:52:19.648 SetChannel> Tuner: Hauppauge OpenCable Receiver 2010404A-1 will be used for the live stream

2016/08/16 14:52:19.650 SetChannel> Recorder acquired: True

2016/08/16 14:52:19.651 SetChannel> TuneRequest set

2016/08/16 14:52:19.741 LiveRemuxStream> wtv recording started in 0.11 sec

2016/08/16 14:52:19.741 LiveRemuxStream> stream output file: LiveTV_Emby^MCSERVER^2_Digital Cable_918_2016_08_16_14_52_19.ts

2016/08/16 14:52:19.741 LiveRemuxStream> started remux thread: 'DMX-918:34362'

2016/08/16 14:52:19.744 Remux::Start> Starting descriptor scan...

2016/08/16 14:52:19.744 Remux::FindDescriptors> Scanning wtv for streams...

2016/08/16 14:52:21.914 Parse> Guid: 0 took 2.17 sec, it was attempted 1081 times

2016/08/16 14:52:21.914 Parse> Next 4 Guids: 0.00 sec, 0.00 sec, 0.00 sec, 0.00 sec, 

2016/08/16 14:52:21.915 Parse> Language 'eng' for stream Id 13

2016/08/16 14:52:23.997 Parse>  Warning, Number of attempts at getting new wtv data was large: 1039 (threshold: 500)

2016/08/16 14:52:24.042 WaitUntilTrueOrTimeout> remux data found

2016/08/16 14:52:26.245 Parse>  Warning, Number of attempts at getting new wtv data was large: 1120 (threshold: 500)

2016/08/16 14:52:28.485 Parse>  Warning, Number of attempts at getting new wtv data was large: 1116 (threshold: 500)

2016/08/16 14:52:30.804 Parse>  Warning, Number of attempts at getting new wtv data was large: 1111 (threshold: 500)

2016/08/16 14:52:33.038 Parse>  Warning, Number of attempts at getting new wtv data was large: 1078 (threshold: 500)

2016/08/16 14:52:34.042 WaitForTsFile> **** error: remux file has no data, second timout reached ****

2016/08/16 14:52:34.042 LiveRemuxStream> process start error: Remux is shutdown calling Close()

2016/08/16 14:52:34.042 Remux::Stop> caller is requesting to stop remux thread before descriptors are found

2016/08/16 14:52:34.042 Remux::Stop> stop remux requested

2016/08/16 14:52:34.043 WtvToPesDemuxer::Parse> Guid header detects stream end

2016/08/16 14:52:34.043 Parse> Total Descriptor parse time: 14.30 sec

2016/08/16 14:52:34.043 Pass Type: 'Descriptor':

2016/08/16 14:52:34.043  >  WtvToPesDemuxer::Parse> total guid headers processed: 316  (Min:500 - Max:2,000)

2016/08/16 14:52:34.043  >  WtvToPesDemuxer::Parse> total data packets processed: 70

2016/08/16 14:52:34.043 Remux::FindDescriptors> wtv scanned (14.30 sec), Streams found: 

2016/08/16 14:52:34.043  >  Audio: ID:13 (eng) ac3 2.0 48000 Hz 128 kb/s

2016/08/16 14:52:34.043 Remux::FindDescriptors> warning: no video streams to remux

2016/08/16 14:52:34.043 Remux::FindDescriptors> ended successfully.

2016/08/16 14:52:34.043 GetLinearStream> Stream used: ID:13 (eng) ac3 2.0 48000 Hz 128 kb/s

2016/08/16 14:52:34.043 Remux::Start> Starting data remux...

2016/08/16 14:52:34.076 WriteChunk> first output file write occurred

2016/08/16 14:52:35.248 Parse>  Warning, Number of attempts at getting new wtv data was large: 550 (threshold: 500)

2016/08/16 14:52:36.050 Parse> Exception: Thread was being aborted.

2016/08/16 14:52:36.051 Parse>   Pass Type: Remux

2016/08/16 14:52:36.052 Parse>   Guid count: 376  (Min:500 - Max:2,000)

2016/08/16 14:52:36.053 Parse>   Header: 

2016/08/16 14:52:36.053 Parse>   re-throwing exception

2016/08/16 14:52:36.056 Remux> error: System.Threading.ThreadAbortException: Thread was being aborted.

   at Remuxer.demux.microsoft.WtvToPesDemuxer.parse(JobStreamI jobStm, MuxManager muxManager)

   at Remuxer.muxer.MuxManager.mux(JobStreamI stream)

   at Remuxer.Remux.Start(String clientName, String outFullFileName)

2016/08/16 14:52:36.058 CloseRemux> warning: remux job did not end smoothly

2016/08/16 14:52:36.058 LiveRemuxStream::Close> remux stopped successfully

2016/08/16 14:52:36.058 RecordToWTV::Close> isPassive is False => COM recorder will be stopped

2016/08/16 14:52:36.058 Remux> requesting E:\Recorded TV\TempSWMC\LiveTV_Emby^MCSERVER^2_Digital Cable_918_2016_08_16_14_52_19.wtv be saved from deletion

2016/08/16 14:52:36.059 Remux> ENDED, >>>>>>>>>> Run Time: 0.03 min <<<<<<<<<<

[Luke 37116]

There's no reason why it can't, it's just that this hardly ever comes up so it really hasn't been tested much.

[theniteow1 25]

There's no reason why it can't, it's just that this hardly ever comes up so it really hasn't been tested much.

 

Yeah, I agree.  It seems from what the logs are saying since it doesn't see any video stream it kills it. and never passes it along to Emby.

[Luke 37116]

That part I think should be mentioned to krustyreturns but even once it gets past that, there might still be things on the Emby side to work out. We built this for flexibility to allow audio-only channels, but over the course of time with users not really mentioning them very much, things might have happened.

[d00zah 128]

@theniteow1,

 

 

check the CCI flags for your Music Choice channels. My provider sets them to 'Copy Control Information: "Copy Never" (0x03)' & Emby doesn't do DRM (yet?).. Can you tune them with any interface using 'Hauppauge OpenCable Receiver'?

 

Edit: My ServerWMC log also displays 'Recorder Content Protection: PROT_COPY_FREE'  like yours, but polling the tuner directly indicates 'Copy Never'. Back to believing it's DRM.

Edited August 16, 2016 by d00zah

[krustyreturns 191]

Serverwmc is looking for a video stream and not finding it.  Does this cable channel have accompanying video when played in wmc, or is it really just audio?

[theniteow1 25]

Serverwmc is looking for a video stream and not finding it.  Does this cable channel have accompanying video when played in wmc, or is it really just audio?

 

No, it's strictly Audio only.  When I play i through Windows Media Center, it just says Audio service, and no video.

[theniteow1 25]

@@krustyreturns Here is a screenshot of what it looks like through Windows Media Center:

 

  

[krustyreturns 191]

These channels are supposed to be flagged as 'audio only' in the wmc database, so that serverwmc knows to not look for a video stream.  So we can either try to figure out why this isn't happening in your setup, or (if I recall right) you can force serverwmc to not look for video on these channels.  

 

To do the latter, you specify the channel numbers to ignore the video by using the poorly named setting ForcedRadioChannels.  For example

<ForcedRadioChannels>1000, 2200-2300, 5000</ForcedRadioChannels>

this says channel 1000, all channels in the range 2200 to 2300 (inclusive) and 5000 are audio only.  After making the change, save the settings file, then restart serverwmc.

 

To do the former, set Debug_AllChannelDetail to true, save, then restart serverwmc.  There will be a bunch of detailed info on each of your channels in the start of the log.  Look up the channel that is just audio and post what you find there.  Don't forget to reset this setting back to false to keep down the size of you logs.

[theniteow1 25]

These channels are supposed to be flagged as 'audio only' in the wmc database, so that serverwmc knows to not look for a video stream.  So we can either try to figure out why this isn't happening in your setup, or (if I recall right) you can force serverwmc to not look for video on these channels.  

 

To do the latter, you specify the channel numbers to ignore the video by using the poorly named setting ForcedRadioChannels.  For example

<ForcedRadioChannels>1000, 2200-2300, 5000</ForcedRadioChannels>

this says channel 1000, all channels in the range 2200 to 2300 (inclusive) and 5000 are audio only.  After making the change, save the settings file, then restart serverwmc.

 

To do the former, set Debug_AllChannelDetail to true, save, then restart serverwmc.  There will be a bunch of detailed info on each of your channels in the start of the log.  Look up the channel that is just audio and post what you find there.  Don't forget to reset this setting back to false to keep down the size of you logs.

 

This is awesome!  Thank you @@krustyreturns.  I was looking at the "advanced" settings in ServerWMC and wondered what the ForceRadioChannels did.  I will try this today, and let you know my results.  As far as why WMC is not flagging that channels that's anybody's guess.  Is it perhaps the way the guide is downloaded from the provider?  I will also try the Debug option and see what that gives us.

Edited August 19, 2016 by theniteow1

[theniteow1 25]

Ok, @@krustyreturns I turned on the Debug logging for the channels.  Here is the log file.  The audio channels are in the 900s.

ServerWMC.log

[theniteow1 25]

HI @@krustyreturns.  Another update, so when I do the ForceRadioChannels option, they no longer show up in the Emby guide, so I can't tune to them.  Is there another option I need to enable for them to show up?

 

UPDATE: I found the option <TreatRadioChannelsAsTV>true</TreatRadioChannelsAsTV> and that fixed it.  Now it will tune in the channel and play music!  However, I think there is something wrong my music channels which goes back to the original problem.  I noticed when I would tune in a channel it wouldn't play the music I thought it was suppose to.  I edit the sources, and I have like 130+ channels listed for one music channel!  I need to correct these, and try again. 

Edited August 19, 2016 by theniteow1

[theniteow1 25]

@@krustyreturns @@ebr Guys, I got everything working with the latest beta of the FireTV App 1.2.44a and ServerWMC 1.0.0.60 build 1233.  However, I noticed something strange.  Only in the FireTV App if I select an Audio only channel it will stream the channel twice in ServerWMC, creating two live streams at once. This doesn't happen in a browser.  However, if I stop the channel or select another one, it kills only one instance.  Leaving the tuner occupied by that channel that is not being listened too.  I have to manually kill it from the server console or it never goes away.  Thoughts on why it would create two streams?  I uploaded the ServerWMC logs for it.  The music channels are in the 900s.

ServerWMC.log

Edited September 1, 2016 by theniteow1

[krustyreturns 191]

Hi @theniteowl, would you mind generating a clean log (i.e. restart serverwmc) that displays a single example of the two stream opening problem? 

[theniteow1 25]

Hi @theniteowl, would you mind generating a clean log (i.e. restart serverwmc) that displays a single example of the two stream opening problem? 

 

No problem, I'll do that tonight.

[theniteow1 25]

No problem, I'll do that tonight.

 

@@krustyreturns Sorry, I've been extremely busy here are the logs and some screenshots.  I've had more time to play with it, I and I think it might be a timeout issue.  I've noticed it do this on TV channels too.  It seems that the longer it takes to tune in the channel the more likely another instance will be started.  With the audio only channels it does this a 100% of the time.  I don't notice it as much on the TV Channels, but it does happen occasionally.  The other day my wife had about 10 instances of one TV Channel going!

 

Two streams going at once, 902 had two streams as well, until I tuned into channel 915:

 

 

ServerWMC never kills off the duplicate stream, after closing out the channel:

 

ServerWMC.log

Edited September 7, 2016 by theniteow1

[theniteow1 25]

Here is a perfect example of what I am seeing, it happened this afternoon to my wife.  Just keeps trying to start the same channel with different streams:

 

[krustyreturns 191]

Thanks for the data.  Is it still true that it only happens with the fire tv app?   Anyway, I have seen this before where emby opens a stream, swmc sets it up, but then emby doesn't read it and instead it just opens it again and never closes the first one.  I don't think it has anything to do with the stream being audio only, except that its probably exacerbated because swmc takes more time to open audio-only streams.  Since this is a problem that keeps cropping up, maybe its time to think about how swmc can safeguard against it.  I will try to come up with something.

[theniteow1 25]

Thanks for the data.  Is it still true that it only happens with the fire tv app?   Anyway, I have seen this before where emby opens a stream, swmc sets it up, but then emby doesn't read it and instead it just opens it again and never closes the first one.  I don't think it has anything to do with the stream being audio only, except that its probably exacerbated because swmc takes more time to open audio-only streams.  Since this is a problem that keeps cropping up, maybe its time to think about how swmc can safeguard against it.  I will try to come up with something.

 

You're awesome!  Thank you.  Let me know if there is anything I can do as far as testing, or what not.  It looks to be just a FireTV app thing, as I haven't experienced this with a web browser.  I agree with it being exacerbated by it taking so long to open the audio only streams.

Edited September 8, 2016 by theniteow1

[krustyreturns 191]

Hey @@theniteow1,

 

I have made a first cut at trying to solve this orphan stream problem.  To test it you'll need the newest preview version of swmc (1234) and a new release of the serverwmc plugin for emby (1.0.0.69).  Please let me know what you find (and include logs if it doesn't work).  Thanks.

[theniteow1 25]

Hey @@theniteow1,

 

I have made a first cut at trying to solve this orphan stream problem.  To test it you'll need the newest preview version of swmc (1234) and a new release of the serverwmc plugin for emby (1.0.0.69).  Please let me know what you find (and include logs if it doesn't work).  Thanks.

 

@@krustyreturns I'll give it a shot this weekend.  Thank you!

[krustyreturns 191]

Thanks.  FYI, what you should see is the 'failed' stream persist for around 15-30sec before swmc finds it and shuts it down.

[theniteow1 25]

Thanks.  FYI, what you should see is the 'failed' stream persist for around 15-30sec before swmc finds it and shuts it down.

Hi @@krustyreturns , I played with this all weekend, and the way it detects failed streams has definitely improved! Especially when using the music channels.  Good job!  However, there still seems to be occasions where streams will just remain in limbo.  It seems to depend on how I exit the channel.  On one example I tuned into a music channel and walked away.  Since there is no video the Fire TV went into screen saver mode, and kicked me off the channel, but the stream still remained, and the channel stopped playing on the Fire TV.  Such as right now it is still streaming channel 914, even though there is nothing on the dashboard:

 

 

ServerWMC.log

Edited September 12, 2016 by theniteow1

[krustyreturns 191]

Thanks @@theniteow1.  Over the weekend I fired up an ftv and was able to reproduce what you are seeing (at least I think its the same).  I am not playing music channels, just streaming live tv.  Most of the time it works, but occasionally ftv/emby goes crazy and starts sending a flood of open and close stream requests after the stream starts.  I am hoping I am doing something wrong in my plugin that will stop this, because frankly, I don't see how I'll be able to figure out how to filter these requests just on the swmc side.  I am in contact with the emby guys to see we can figure out what is going on.  I'll keep you posted if we have progress..

 

This may not be the only problem you are reporting, but I need to get this out of the way before the next one.

Edited September 12, 2016 by krustyreturns

[theniteow1 25]

Thanks @@theniteow1.  Over the weekend I fired up an ftv and was able to reproduce what you are seeing (at least I think its the same).  I am not playing music channels, just streaming live tv.  Most of the time it works, but occasionally ftv/emby goes crazy and starts sending a flood of open and close stream requests after the stream starts.  I am hoping I am doing something wrong in my plugin that will stop this, because frankly, I don't see how I'll be able to figure out how to filter these requests just on the swmc side.  I am in contact with the emby guys to see we can figure out what is going on.  I'll keep you posted if we have progress..

 

This may not be the only problem you are reporting, but I need to get this out of the way before the next one.

 

Excellent!  Glad you were able to reproduce it.  Thanks for keeping me informed.