[exodus454]

So the past few days I've been having problems with the recorded TV from WMC not showing up on my xbmc clients. I've been running serverwmc on my win8.1 media server for almost a week now. When I first installed it the shows were being populated on the clients but sometime recently it stopped working. One client is a server 2012 machine running Gotham, the other is my htpc running a stable version of openelec.

I was looking at the logs tonight and this popped up in serverwmc -

Code:

2014/01/23 05:45:04.466    SetChannel> Tuner: Ceton InfiniTV PCIe (00-80-68-8c) Tuner 3 (00-00-22-00-00-80-68-8c) / 3a75a8d9-316d-4d25-84af-6cc79c596e53
2014/01/23 05:45:04.466    SetChannel> > Digital: True
2014/01/23 05:45:04.466    SetChannel> > Encrypted: False
2014/01/23 05:45:04.466    SetChannel> > RecorderInfo found: True
2014/01/23 05:45:04.466    SetChannel > busy: False, client:
2014/01/23 05:45:04.466    SetChannel> > tuner is available (taking tuner from ) => stopping search
2014/01/23 05:45:04.466    SetChannel> Recorder Content Protection: PROT_COPY_FREE
2014/01/23 05:45:04.466    SetChannel> Recorder acquired: True
2014/01/23 05:45:04.466    SetChannel> TuneRequest set
2014/01/23 05:45:04.482    RecService> priming tuners - done
2014/01/23 05:45:04.482    LoadGenreDict> 'GenreDict.xml' loaded OK
2014/01/23 05:45:04.482    CheckChannelIcons> Channel icons processed: 0
2014/01/23 05:45:04.482    RecService> starting recording service - done
2014/01/23 05:45:04.482    Local 'Recorded tv' path: R:\Recorded TV\
2014/01/23 05:45:04.482    Format: NTFS
2014/01/23 05:45:04.482    Network 'Recorded tv' path: smb://admin:************@192.168.1.61/Recorded TV/
2014/01/23 05:45:05.285    SocketServer> starting up SocketServer
2014/01/23 05:45:05.285    SocketServer> permission to access sockets granted
2014/01/23 05:45:05.291    SocketServer> socket object created
2014/01/23 05:45:05.292    SocketServer> started on port: 9080
2014/01/23 05:45:05.294    MaintenanceTimer> callback at 5:45 AM
2014/01/23 05:45:05.299    MaintenanceTimer> callback - complete
2014/01/23 05:45:09.346    Client: '192.168.1.141' addon Version: 0.1.92, Client OS:
2014/01/23 05:45:09.346    Client: '192.168.1.141' running remotely: True
2014/01/23 05:45:09.376    Client: '192.168.1.141' path to Rec Folder: 'smb://admin:************@192.168.1.61/Recorded TV/'
2014/01/23 05:45:09.376    Received client request: 192.168.1.141|GetServerVersion
2014/01/23 05:45:09.376    Finished request GetServerVersion in 0.00s
2014/01/23 05:45:09.456    Received client request: 192.168.1.141|GetChannels
2014/01/23 05:45:10.376    Finished request GetChannels in 0.92s
2014/01/23 05:45:10.476    Received client request: 192.168.1.141|GetTimers
2014/01/23 05:45:10.955    Finished request GetTimers in 0.48s
2014/01/23 05:45:10.974    Received client request: 192.168.1.141|GetRecordings
2014/01/23 05:45:17.247    GetRecordings> Metadata read error on: R:\Recorded TV\TV\Late Night With Jimmy Fallon\Late Night With Jimmy Fallon Season 2014\Late Night With Jimmy Fallon-S2014E1-Matthew McConaughey, Gisele Bundchen, Stephen Malkmus and the Jicks-Esquire-01_13-05_55.wtv
2014/01/23 05:45:17.287    GetRecordings> Content protected file: True Detective, hiding: False
2014/01/23 05:45:17.347    GetRecordings> Metadata read error on: R:\Recorded TV\TV\Late Night With Jimmy Fallon\Late Night With Jimmy Fallon Season 2014\Late Night With Jimmy Fallon-S2014E7-Bruce Springsteen-WNBC-01_15-00_31.wtv
2014/01/23 05:45:50.087    GetRecordings> Metadata read error on: R:\Recorded TV\TV\The Legend of Korra\The Legend of Korra Season 01\The Legend of Korra-S01E9-Out of the Past-Nicktoons Network-09_02-07_28.wtv
2014/01/23 05:45:52.057    GetRecordings error: System.Runtime.InteropServices.COMException (0x8000FFFF): Catastrophic failure (Exception from HRESULT: 0x8000FFFF (E_UNEXPECTED))
   at Metadata.Utilities.IFileSourceFilter.Load(String pszFileName, AmMediaType pmt)
   at Metadata.Utilities.DvrmsMetadataEditor..ctor(String filepath)
   at ServerWMC.Worker.RecService.GetRecordings()
2014/01/23 05:45:52.057    Finished request GetRecordings in 41.08s
2014/01/23 05:45:52.057    Received client request: 192.168.1.141|GetChannelCount
2014/01/23 05:45:52.057    Finished request GetChannelCount in 0.00s
2014/01/23 05:45:52.057    Received client request: 192.168.1.141|GetTimerCount
2014/01/23 05:45:52.157    Finished request GetTimerCount in 0.10s

Could that be any clue as to why it hasn't been working? Live TV has been working for the most part aside from the occasional buffering and "no video found" (or something like that) on initial tuning but that will usually work itself out.

Also I've noticed in the serverwmc program that it doesn't like to save the configuration changes I make probably more than 3/4 of the time. I've tried reinstalling it and deleting everything from program data and program files but it hasn't seemed to help. Lately I've just been editing the config file directly because that always saves the changes. Any idea why that might be? I doubt the problems are related but maybe there's a permissions issue or something. I am running a Windows domain so security stuff can interfere in tons of places.. Both my WMC pc and the server are domain joined. Also now that I think of it, sometimes the logs don't update either.. if you go click the log buttons or go find them in the directory sometimes they haven't been updated in hours. That actually does make me think there might be an issue with permissions..

Just to be sure though - when specifying a username and password for the recorded TV folder, should I be using "domain\domainuser:password", "domainuser:password" or should I be using a local account? I'm not 100% sure because of the smb share.

I'm going to play with it more later today, just wanted to get some input though so I'm not chasing ghosts all evening!

Thanks for the help, and let me know if any more logs are necessary.

[scarecrow420]

It seems we are crashing out when trying to get the metadata on at least one of your recording files. This is causing no recordings to be returned. Apart from fixing whatever this problem is with this particular recording/s we also should handle a failure on a per file basis but still continue processing others and ultimately return back to XBMC whatever we can, rather than nothing.

How many recordings do you have out of interest? As that call is taking 41 seconds to complete (the exceptions could be causing the increased time though) which seems quite lengthy. Apart from moving all your recent recording files away temporarily (since you said this has been happening the last few days) and then putting them back selectively to try and determine which one/s are not handled, you'll need to wait for us to provide a build that contains some debugging output to identify the problem files, better resiliency when a problem file is hit, and better yet an actual fix to the meta data retrieval code so that the file isnt a problem anymore

Any more info about your recordings setup? Eg i notice some outputs of some files (note i dont think these are the ones that caused the crash) are in a folder structure that indicates some type of post processing/renaming of recordings is happening. If you are using things like MCEBuddy anbd whatnot let me know just for context. Also whether those ones are just a back catalog of older recordings or whether you still have some sort of renaming/organising system going on. (also to plug one of our new features, if you do want to do post processing you should check out the ExternalAction stuff in the latest builds that I developed... i havent had any testing/feedback from users about it yet)

[krustyreturns]

exodus,

In addition, can you also go the file:
%programdata%\VDsoftware\ServerWMC\config.xml

find:
<UseMetaDataForRecordings>true</UseMetaDataForRecordings>
change it to:
<UseMetaDataForRecordings>false</UseMetaDataForRecordings>

Save it, then restart serverwmc and see if the recordings load. Let us know either way.

[exodus454]

Thanks, that seems to have done it for now! I have around 200 recordings maybe, wmc is only monitoring my single terabyte recording drive at the moment. I do have recordings stored on other network drives but wmc isn't watching them.

In the past I've used MCEbuddy to organize/convert my recordings but that doesn't really seem as reliable as I thought. A lot of recordings were getting screwed up because mcebuddy wasn't running locally so I turned it off for now. Last night I moved to wtv-metarenamer which seems like a much more robust and less fiddly solution, its reorganizing and renaming my library now.

I'm trying to find the best solution for ultimately storing recordings and having all the metadata/art populated accurately for xbmc. It seems none of the library managers can read wtv metadata so I'm trying converting them to the standard "show/season/episode/title-S##E##-episode.ext“ format which hopefully the scrapers can pick up on more accurately.

Was the recorded TV issue I was having possibly related to an mcebuddy screwup?

I've also been running serverwmc as a service lately and it seems much more stable for whatever reason. I switched it to run under the "network service" user and all seems copacetic so far.

I'd be happy to give the ExternalAction stuff a try, can you point me to some documentation or give me a rundown on how to use it?

Thanks for the help, and I really love the work you've done so far! I can't tell you how fvucking ecstatic I am not having to rely on Xbox extenders anymore!

[krustyreturns]

When you can, try the newest version of serverwmc (1118) with the above config.xml setting back to 'true'. We think we fixed the bug you were having in the older version, but it would be nice to get confirmation.

I don't know if mcebuddy is the cause of the problem you were having, but I doubt it. Certainly the renamer program should cause no problem.

You only need to rename the wtv files if you want the regular xbmc scrapper to be able to scrape the files, but I think you know that. If you view these files using the pvr.wmc addon, renaming is not required to see the correct metadata, but I think you know that too.

Scarecrow did a preliminary explanation of the external action function here:
http://forum.xbmc.org/showthread.php?tid=178996&page=9

[scarecrow420]

Thanks, that seems to have done it for now! I have around 200 recordings maybe, wmc is only monitoring my single terabyte recording drive at the moment. I do have recordings stored on other network drives but wmc isn't watching them.

In the past I've used MCEbuddy to organize/convert my recordings but that doesn't really seem as reliable as I thought. A lot of recordings were getting screwed up because mcebuddy wasn't running locally so I turned it off for now. Last night I moved to wtv-metarenamer which seems like a much more robust and less fiddly solution, its reorganizing and renaming my library now.

I'm trying to find the best solution for ultimately storing recordings and having all the metadata/art populated accurately for xbmc. It seems none of the library managers can read wtv metadata so I'm trying converting them to the standard "show/season/episode/title-S##E##-episode.ext“ format which hopefully the scrapers can pick up on more accurately.

Was the recorded TV issue I was having possibly related to an mcebuddy screwup?

I've also been running serverwmc as a service lately and it seems much more stable for whatever reason. I switched it to run under the "network service" user and all seems copacetic so far.

I'd be happy to give the ExternalAction stuff a try, can you point me to some documentation or give me a rundown on how to use it?

Thanks for the help, and I really love the work you've done so far! I can't tell you how fvucking ecstatic I am not having to rely on Xbox extenders anymore!

Build 1118 has been released which should now handle a "bad metadata" file (by this i mean it logs a warning an skips over that file but will continue to process other recordings). If you update to this build, turn back on the metadata option, then we can see in your log files which recordings have "bad metadata" that we are unable to read. So give that a shot if you want

The ExternalAction stuff, I posted some info in the Feature Request thread where the guys had asked for it. My bad that it's buried there, I need to get TechLife to add it to the wiki
http://forum.xbmc.org/showthread.php?tid...pid1605365

edit: Look like krusty beat me to the reply lol

[exodus454]

Just updated to build 1118, we'll see how it goes. Before I updated the service had crashed with the following in the logs -

Code:

2014/01/23 08:36:31.273    GetRecordings error: System.Runtime.InteropServices.COMException (0x8000FFFF): Catastrophic failure (Exception from HRESULT: 0x8000FFFF (E_UNEXPECTED))
   at Metadata.Utilities.IFileSourceFilter.Load(String pszFileName, AmMediaType pmt)
   at Metadata.Utilities.DvrmsMetadataEditor..ctor(String filepath)
   at ServerWMC.Worker.RecService.GetRecordings()
2014/01/23 08:36:31.273    Finished request GetRecordings in 11.87s
2014/01/23 08:37:03.108    System.IO.IOException: There is not enough space on the disk.

   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.FileStream.WriteCore(Byte[] buffer, Int32 offset, Int32 count)
   at Remuxer.common.ByteBuffer.Write(FileStream fStream)
   at Remuxer.common.BufferedWritableByteChannel.WriteChunk()
   at Remuxer.common.BufferedWritableByteChannel.close()
   at Remuxer.muxer.ts.TsPacketWriter.close()
2014/01/23 08:37:03.108    Parse> Exception:
2014/01/23 08:37:03.108    Parse>   Pass: mux2ts
2014/01/23 08:37:03.108    Parse>   Guid count: 4543445
2014/01/23 08:37:03.108    Parse>   Header: Guid: DATA_GUID, len: 1674, pad 6, sId: 122, WtvCnt: 1042723, isValid: True
2014/01/23 08:37:03.108    Parse>   re-throwing exception
2014/01/23 08:37:03.108    Remux> error: System.IO.IOException: There is not enough space on the disk.

   at Remuxer.demux.microsoft.WtvToPesDemuxer.parse(JobStreamI stream, MuxManager muxManager)
   at Remuxer.muxer.MuxManager.mux(JobStreamI stream)
   at Remuxer.Remux.Start()

Again, this log is from the previous build. Is the remuxer running out of physical disk space? I have 10gb free on my OS SSD and 100gb free on my recording drive..


Now running 1118, the recorded TV seems to be pushed out to the clients correctly even after re-enabling the metadata. I'm still getting odd things popping up in the logs like this -

Code:

2014/01/25 01:08:32.526    Received client request: 192.168.1.141|GetRecordings
2014/01/25 01:08:32.693    GetRecordings> Content protected file: True Detective, hiding: False
2014/01/25 01:08:32.722    GetRecordings> local file will be ignored by remote client, file: R:\Archived TV\True Detective\Season 01\True Detective - S01E02 - Seeing Things.wtv
2014/01/25 01:08:32.963    GetRecordings> Metadata read error on: R:\Archived TV\The Legend of Korra\Season 01\The Legend of Korra - S01E09 - Out of the Past.wtv
2014/01/25 01:08:34.658    GetRecordings> Metadata read error on: R:\Archived TV\Late Night with Jimmy Fallon\Season 2014\Late Night with Jimmy Fallon - S2014E01 - Matthew McConaughey, Gisele Bundchen, Stephen Malkmus and the Jicks.wtv
2014/01/25 01:08:38.661    GetRecordings> Metadata read error on: R:\Recorded TV\Late Night With Jimmy Fallon-S2014E7-Bruce Springsteen-WNBC-01_15-00_31.wtv
2014/01/25 01:08:39.157    GetRecordings> Completed for client 192.168.1.141,  results:
2014/01/25 01:08:39.157    GetRecordings>    Transfered: RecTV folder files: 51,  watched files: 0
2014/01/25 01:08:39.157    GetRecordings>    Ignored:  local files: 157, temp files: 0
2014/01/25 01:08:39.157    GetRecordings>    Weird files:  no program: 0, no channel: 4, orphaned: 0
2014/01/25 01:08:39.157    GetRecordings>    Misc:  content protected: 2, icons: 0, instantRec: 0, metaDataReads: 195

Code:

2014/01/25 01:13:40.329    Received client request: 192.168.1.141|GetRecordings
2014/01/25 01:13:40.841    GetRecordings> Metadata read error on: R:\Archived TV\The Legend of Korra\Season 01\The Legend of Korra - S01E09 - Out of the Past.wtv
2014/01/25 01:13:42.686    GetRecordings> Metadata read error on: R:\Archived TV\Late Night with Jimmy Fallon\Season 2014\Late Night with Jimmy Fallon - S2014E01 - Matthew McConaughey, Gisele Bundchen, Stephen Malkmus and the Jicks.wtv
2014/01/25 01:13:50.331    GetRecordings> Metadata read error on: R:\Recorded TV\Late Night With Jimmy Fallon-S2014E7-Bruce Springsteen-WNBC-01_15-00_31.wtv
2014/01/25 01:13:51.062    Finished request GetRecordings in 10.73s
2014/01/25 01:16:30.211    MaintenanceTimer> callback at 1:16 AM
2014/01/25 01:16:30.211    MaintenanceTimer> callback - complete
2014/01/25 01:18:40.438    Received client request: 192.168.1.141|GetTimers
2014/01/25 01:18:40.439    Finished request GetTimers in 0.00s
2014/01/25 01:18:40.441    Received client request: 192.168.1.141|GetRecordings
2014/01/25 01:18:40.828    GetRecordings> Metadata read error on: R:\Archived TV\The Legend of Korra\Season 01\The Legend of Korra - S01E09 - Out of the Past.wtv
2014/01/25 01:18:42.598    GetRecordings> Metadata read error on: R:\Archived TV\Late Night with Jimmy Fallon\Season 2014\Late Night with Jimmy Fallon - S2014E01 - Matthew McConaughey, Gisele Bundchen, Stephen Malkmus and the Jicks.wtv
2014/01/25 01:18:47.285    GetRecordings> Metadata read error on: R:\Recorded TV\Late Night With Jimmy Fallon-S2014E7-Bruce Springsteen-WNBC-01_15-00_31.wtv
2014/01/25 01:18:47.873    Finished request GetRecordings in 7.43s
2014/01/25 01:23:40.770    Received client request: 192.168.1.141|GetTimers
2014/01/25 01:23:40.770    Finished request GetTimers in 0.00s
2014/01/25 01:23:40.772    Received client request: 192.168.1.141|GetRecordings
2014/01/25 01:23:41.511    GetRecordings> Metadata read error on: R:\Archived TV\The Legend of Korra\Season 01\The Legend of Korra - S01E09 - Out of the Past.wtv
2014/01/25 01:23:43.875    GetRecordings> Metadata read error on: R:\Archived TV\Late Night with Jimmy Fallon\Season 2014\Late Night with Jimmy Fallon - S2014E01 - Matthew McConaughey, Gisele Bundchen, Stephen Malkmus and the Jicks.wtv
2014/01/25 01:23:50.035    GetRecordings> Metadata read error on: R:\Recorded TV\Late Night With Jimmy Fallon-S2014E7-Bruce Springsteen-WNBC-01_15-00_31.wtv
2014/01/25 01:23:50.723    Finished request GetRecordings in 9.95s
2014/01/25 01:24:30.442    MaintenanceTimer> callback at 1:24 AM
2014/01/25 01:24:30.442    MaintenanceTimer> callback - complete
2014/01/25 01:28:40.932    Received client request: 192.168.1.141|GetTimers
2014/01/25 01:28:40.932    Finished request GetTimers in 0.00s
2014/01/25 01:28:40.936    Received client request: 192.168.1.141|GetRecordings
2014/01/25 01:28:41.332    GetRecordings> Metadata read error on: R:\Archived TV\The Legend of Korra\Season 01\The Legend of Korra - S01E09 - Out of the Past.wtv
2014/01/25 01:28:43.127    GetRecordings> Metadata read error on: R:\Archived TV\Late Night with Jimmy Fallon\Season 2014\Late Night with Jimmy Fallon - S2014E01 - Matthew McConaughey, Gisele Bundchen, Stephen Malkmus and the Jicks.wtv
2014/01/25 01:29:07.446    GetRecordings> Metadata read error on: R:\Recorded TV\Late Night With Jimmy Fallon-S2014E7-Bruce Springsteen-WNBC-01_15-00_31.wtv
2014/01/25 01:29:08.713    Finished request GetRecordings in 27.78s

I'm guessing "metadata read error" is how it's supposed to behave now? I'll keep an eye on it and let you know if anything changes.. Heading to feature requests now!

[exodus454]

No other issues sofar.. the metadata error in the logs repeats itself and I'm getting this error sometimes when trying to tune a channel.. probably unrelated? Its getting kind of annoying though, always happens randomly.

Code:

/25 02:24:16.800    SetChannel> > tuner is available (taking tuner from Prime_Digital Cable) => stopping search
2014/01/25 02:24:16.800    SetChannel> Recorder Content Protection: PROT_COPY_FREE
2014/01/25 02:24:16.800    SetChannel> Recorder acquired: True
2014/01/25 02:24:17.212    SetChannel> TuneRequest set
2014/01/25 02:24:17.230    StreamProc> wtv recording started in 0.48 sec
2014/01/25 02:24:17.230    StreamProc> stream output file: LiveTV_192.168.1.141_Digital Cable_756_2014_01_25_02_24_16.ts
2014/01/25 02:24:17.230    StreamProc> started remux thread: 'TOONHD-756: 13343010'
2014/01/25 02:24:17.230    Remux::FindDescriptors> Scanning wtv for streams...
2014/01/25 02:24:29.230    StreamProc> process start error: Stream file 'ts' does not exist (likely no data was found to remux), timeout: 10,000 ms reached. calling Close()
2014/01/25 02:24:29.240    WtvToPesDemuxer::Parse> Guid header detects stream end
2014/01/25 02:24:29.240    Parse> Descriptor pass done, using 0 guids in 12.01 sec
2014/01/25 02:24:29.240    Parse> Total Descriptor parse time: 12.01 sec
2014/01/25 02:24:29.240    Pass 'Descriptor':
2014/01/25 02:24:29.240     >  WtvToPesDemuxer::Parse> total guid headers processed: 0
2014/01/25 02:24:29.240     >  WtvToPesDemuxer::Parse> total data packets processed: 0
2014/01/25 02:24:29.240    Remux::FindDescriptors> no streams descriptors were found.
2014/01/25 02:24:29.240    Remux::FindDescriptors> error: no audio or video stream found - aborting remux
2014/01/25 02:24:29.240    Remux> requesting R:\Recorded TV\TempXBMC\LiveTV_192.168.1.141_Digital Cable_756_2014_01_25_02_24_16.wtv be saved from deletion
2014/01/25 02:24:29.240    Remux> ENDED, >>>>>>>>>> Run Time: 0.00 min <<<<<<<<<<
2014/01/25 02:24:29.260    StreamProc::Close> remux stopped successfully
2014/01/25 02:24:29.260    RecordToWTV::Close> isPassive is False => COM recorder will be stopped
2014/01/25 02:24:29.300    StreamProc::Close> wtv closed successfully
2014/01/25 02:24:29.360    StreamProc::Close> wtv file size: 524,288
2014/01/25 02:24:29.360    StreamProc::Close> WTV FILE SAVED FOR DEBUG: R:\Recorded TV\TempXBMC\LiveTV_192.168.1.141_Digital Cable_756_2014_01_25_02_24_16.wtv
2014/01/25 02:24:29.360    StreamProc::Close> closed in 0.13 sec
2014/01/25 02:24:29.360    OpenLiveStream> error: Stream file 'ts' does not exist (likely no data was found to remux), timeout: 10,000 ms reached.
2014/01/25 02:24:29.360    Finished request OpenLiveStream in 13.28s
2014/01/25 02:24:29.430    Received client request: 192.168.1.141|CloseLiveStream
2014/01/25 02:24:29.430    CloseLiveStream> -----------------start------------------------
2014/01/25 02:24:29.430    CloseLiveStream> -----------------done-------------------------

Any ideas on that one?

[krustyreturns]

I am curious why 195 of your recordings have bad metadata. Since that's the case though, I would set this value back to false:
<UseMetaDataForRecordings>false</UseMetaDataForRecordings>

then you won't get the error messages and getting recordings will be faster.

I am not sure why sometimes tuning to a channel is failing. Try turning off 'pre-start tuners' in the live-tv tab of swmc, then restart it. See if the problem persists after that.

[exodus454]

Is that bad metadata for all 195? There's only the 3 or 4 that are throwing errors in the logs

[krustyreturns]

You are right, there may only be a few that are bad. I mis-read the log.