Scan media library hanging since the new release

[Guest virtualtinker]

It's been about 2 hours now and the percentage has not moved since hitting 56.6% which was the point that it was scanning my collection earlier.  I've attached the last log which shows what it's been doing the past 2 hours.

[Luke 37238]

Hmm. I would stop it and try uninstalling plugins one by one to see if we can narrow it down. thanks.

[Guest virtualtinker]

Since updating to the new beta release this morning, I have run into issues where the 'scan media library' scheduled task will simply hang at X%.  The scan job was running with no problems prior to the update.    .I understand that a full media rescan was to occur which I was expecting.  However, since the percentage sits at X% for upwwards of at least 15 minutes with no incremental increases, I can only assume this is something else.  For the sake of clarity and not having to read big walls of text, I've tried breaking out what I did and my general thought process below while trying to troubleshoot.

 

1.  When the problem occurred, I started by trying to isolate, so I removed all UNC paths to my media except to my Blu Ray movies as a starting point.  I then enabled the Debug logs and restarted MBS.

2.  Once the job hung, I checked the server log and noticed that it was hanging on a specific movies (I think it was Boondock Saints), so for the time being, I copied the movie folder and all its contents to my local drive and deleted the movie.

3.  Doing a restart of MBS, the job started up again and it kept on going, so it looked happy.  However, the job would then stall at another movie at which point I performed the same tasks.

4.  At some point, I decided to experiment by deleting all of the XML files entirely for the movie in question that the log was pointing to and the job would still hang.

5.  After deleting about 10 movies, I was originally thinking that maybe something occurred and MBS was no longer liking the MKV file itself (All of these files were encoded in MKV via Handbrake), until the logs pointed to a collection folder that was causing the scan job to hang.

6.  Again, I tried clearing out all metadata, but the job still hangs.  I also took all of the movies out of the collection folder, and now in addition to the collection folder, the logs seem to indicate that it doesn't like either of the three movies that had been previously in there.

7.  I have stopped troubleshooting at this point as the problem seems to be more than simply MBS not liking something in my metadata since the change and is something more directly related to MBS and the update itself.

 

 

As this had worked prior to the update and is only now giving me problems, I feel like maybe the update didn't properly get every record pertaining to my media so it's getting tripped up when doing the scan.  In any case, I have attached a lot of server logs from my various restarts in case there is anything similar among the logs that can be correlated to a root cause.  Let me know if there's anything else I can provide, or if it would be helpful in doing a screen share.

[Luke 37238]

I've looked at half the logs and I don't see anything abnormal. Part of the rescan is probing your media. Maybe some probe operations are taking a little longer than normal. In any event, I would give it more time and be patient before stopping it. 

 

Also, there was a change with live tv as well. The database now cleans up after itself and removes old records. So the first refresh guide task after the update will take extra time while it deletes old records. That might be contributing to the scan running a little slower. In any event, I would just be a little more patient. As long as the log is continuing to grow, you know it's not idling.

[iam4uk 26]

I have noticed something similar with MBS 3.0.5168.16132, so I am just going to give the scan a couple of hours and check back to see if it progresses.  (MBC ...129, Win7HPx64)

[Guest virtualtinker]

I removed the four plugins I had installed (Movie/TV Themes, Rotten Tomatoes Reviews, and ServerWMC).  The scan media job is still hanging at 56.6%.

 

I know I'm not all that familiar with how the application itself works, but what happens when the scan media job runs?  Obviously it is scanning the media locations, but it must put the contents of those reads into a database of some sort.  Can that database's record be queried against to compare the "bad" records against those that have correctly scanned?  Was the database touched in any way as part of this upgrade?  Is it possible to delete the database and let MBS scan and recreate the contents of my scanned media from scratch, or was this what was supposed to happen as part of the upgrade?

[Luke 37238]

you can delete the library db and refresh info db files.

 

actually what you might consider doing is deleting those files and also removing all library paths. then restart with serer with an empty library. then add a library path, let it scan, and repeat. that will help identify if the problem is related to a certain location or not. thanks.

[KRA 39]

I'd like to throw in a me 2 on this, since mine stops at 9.4% and done so for hours, but I see in logs it's working and saying:

 

" App: Failed to read image header for \\OPENINDIANA\Media\......\backdrop1.jpg. Doing it the slow way."

 

for what seems to be all folders, so I'm gonna leave it overnight and see what happens.

[Luke 37238]

Can you try disabling some of the internet metadata fetchers? thanks.

[Guest virtualtinker]

I removed all media paths and deleted the library and refreshinfo .db files.  On restarting the server, I added the Blu Ray movie path.  While it did start rescanning from scratch, the job ultimately hung at 56.6% again as in the past times.  I also removed and added (one at a time) my media paths for Movie DVDs, Television Blu Rays and Television DVDs.  In each of those cases, the jobs hung as well at different percentages on different files.

[danxmanly 0]

Add me to the list of the scan hanging up after updating to latest MB Server.  Mine has been @ 16.8% for hours.  With the exception of about 3 movies showing artwork, no other movies have artwork.  Overviews, critic ratings, etc all show up... but no pictures. 

 

Have restarted server, no effect.. immediately goes back to 16.8%.  Tried to stop the scan within MB Server configurator.. says it's stopping.. but never does even after 30 minutes.  When I shut down and restart.. back to 16.8%. 

 

Attaching the latest log from the last restart. 

 

server-63528866015.log

 

Have not removed any paths and tried to rescan.. but looks like that is not having an effect either. 

 

 

Edited February 25, 2014 by danxmanly

[Luke 37238]

also when it happens check and see if you've got any instances of ffmpeg or ffprobe stuck running

[Guest virtualtinker]

@@Luke

 

Okay, so we're a little closer.  After your suggestion, I narrowed down the cause of the hanging job to the FanArt image fetcher.  This was impacting both Moves, Television, and the Trailers.  Once I disabled all instances of checking FanArt metadata, the job was able to complete.  However, I now have a new problem.  While the job completed, my media library is still empty.  Please see the attached screenshot to get a better idea what I mean.  The only movies that show are the trailers.  If I try selecting either the Movies or Television media folder, there are zero entries in each.  I tried deleting both the library and refreshino .db files and recreate from scratch after resolving the metadata issue, however, that didn't seem to fix anything.  The library.db file is only 10 meg also which seems way too small considering the amount of data that should have been sucked in.

 

I do have a rather large 2 meg log file from the media library scan job, however, it's too large for me to upload.  If you have an alternate location for me to send the log, I can do that.  Or if you have anything else you'd like me to try or expand on anything I've mentioned, let me know.

 

Thanks so far for the assist in working through the new release!

[Luke 37238]

can you put the log on dropbox? does it have any errors? can you try putting fanart back on for trailers only? you will need to delete the db's again.

[Guest virtualtinker]

Here's the error I found in the log while I get dropbox setup.  I saw that error five times, and it looks like each instance was specific to a collection.  I saw a few other errors regarding image extraction, but those didn't throw an exception.  Regarding turning fanart back on, I can try that.  If it's anything like prior, it should lock up when I run the job to refresh the trailers list.  I'll let you know once I've confirmed that.

 

2014-02-24 21:01:22.9711 Error - App: Error in Media Browser Xml

Root element is missing.

System.Xml.XmlException

  at System.Xml.XmlTextReaderImpl.Throw(Exception e)

  at System.Xml.XmlTextReaderImpl.ParseDocumentContent()

  at System.Xml.XmlTextReaderImpl.Read()

  at System.Xml.XmlReader.MoveToContent()

  at MediaBrowser.Controller.Providers.BaseItemXmlParser`1.Fetch(T item, String metadataFile, XmlReaderSettings settings, Encoding encoding, CancellationToken cancellationToken)

  at MediaBrowser.Controller.Providers.BaseItemXmlParser`1.Fetch(T item, String metadataFile, CancellationToken cancellationToken)

  at MediaBrowser.Providers.BoxSets.BoxSetXmlProvider.Fetch(LocalMetadataResult`1 result, String path, CancellationToken cancellationToken)

  at MediaBrowser.Providers.BaseXmlProvider`1.<GetMetadata>d__0.MoveNext()

--- End of stack trace from previous location where exception was thrown ---

  at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

  at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

  at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)

  at MediaBrowser.Providers.Manager.MetadataService`2.<RefreshWithProviders>d__23.MoveNext()

 

2014-02-24 21:01:22.9711 Debug - ProviderManager: Saving \\localhost\Movies\Blu Ray\Resident Evil Collection, The to Media Browser Xml.

2014-02-24 21:01:22.9911 Error - ProviderManager: Error in metadata saver

Root element is missing.

System.Xml.XmlException

  at System.Xml.XmlTextReaderImpl.Throw(Exception e)

  at System.Xml.XmlTextReaderImpl.ParseDocumentContent()

  at System.Xml.XmlTextReaderImpl.Read()

  at System.Xml.XmlReader.MoveToContent()

  at MediaBrowser.Providers.Savers.XmlSaverHelpers.GetCustomTags(String path, List`1 xmlTagsUsed)

  at MediaBrowser.Providers.Savers.XmlSaverHelpers.Save(StringBuilder xml, String path, List`1 xmlTagsUsed)

  at MediaBrowser.Providers.Savers.BoxSetXmlSaver.Save(IHasMetadata item, CancellationToken cancellationToken)

  at MediaBrowser.Providers.Manager.ProviderManager.<SaveMetadata>d__54.MoveNext()

[Luke 37238]

well it might not lock up unless you delete the db's. with the new metadata rules, we can an item once and then it's hands off. so just enabling them won't do anything. are those the only errors? those really shouldn't be a problem. are all your movies in boxsets or do you have separate ones?

[Guest virtualtinker]

After re-enabling the fanart image fetcher, deleting the library.db and restarting MBS, the normal media scan completed fine, and the "Refresh Trailers" job is sitting at 72.6% for about 5 minutes now.

 

Regarding my errors, that was all I saw.  The vast majority of my movies are standalone in their own folder.  Only in the case of movies where it made sense to put them together as part of a collection did I do that.

 

The original 2 meg file from earlier is on DropBox now at https://www.dropbox.com/s/5hy6bha2zw7und3/server-63528872321.log

 

The new log file from my recent recreation of the library.db with the fanart image fetcher for trailers enabled is at https://www.dropbox.com/s/drkjbptlpo9azew/server-63528874372.log

[Luke 37238]

have you ever used fiddler? if not, can you download that?  i need you to repeat the test but with fiddler running. fiddler will show you all the outgoing http requests. then when you're done post the fiddler log. i just want to see if there's anything out of the ordinary, like an http request stuck in limbo. we have a timeout but who knows, maybe it's not timing out.

[Guest virtualtinker]

@@Luke

 

Here is the Fiddler log generated while doing a full media rescan as well as the trailer scan with the fanart image fetcher enabled.

 

https://www.dropbox.com/s/db5cec9vtd6pmxz/fanart_trailers_scan.saz

Edited February 25, 2014 by virtualtinker

[Rainking720 31]

For what it's worth I'm having a similar problem (and have had it since the previous build).   It stops scanning my media library at relatively arbitrary points and just hangs.    I haven't noticed any particular errors in the log but i honestly haven't looked too hard.  It does seem to me that if i restart the service it generally will scan a little bit further into the library but then still hang again.  Also worth noting is that if i try to stop the scan it never actually fully stops, it just sits in the "stopping" status until i restart the server.

[Luke 37238]

Can you please try the same tests as virtual tinker? Thanks.

[danxmanly 0]

I'll try those as well.. but this still seems to be "somewhat" limited to a few users. 

 

Of note, I think my computer restarted after applying windows updates, which may have been  right after MB server updated and was scanning my library. 

 

I didn't even check MB server after it rebooted, and only when I went to launch a movie on my HTPC, did I notice there wasn't any artwork.  That's when I went back into the server and saw it was stuck @ 16.8% on the library scan.

 

Can anyone else who's having this issue confirm if they may have rebooted the computer before MB server completed the library scan after latest update?

[Guest virtualtinker]

I hadn't rebooted my computer in a few days when I had applied the MBS update.  Since then, I did reboot my machine without applying updates and the problem I have is still occuring.  I've also updated the remaining high priority patches and that didn't make any difference, so you should be able to rule out the patches as a cause.

 

I did a little bit more troubleshooting on my end.  So after doing the media scan with fiddler running, I noticed that the problems seem to be occurring when trying to make the HTTP call to api.fanart.tv.  I did a telnet to it on port 80 and did receive a response.  I also ran a trace route to further confirm that I can successfully connect to it as well as the latency on the trip.  It looks to average around 137ms.  Unfortunately, as I do not know more about the application I can't test further this piece.  One other piece I tested to help rule out for me was my storage pool.  So I run FlexRaid's tRaid software RAID, and use their storage pooling functionality to aggregate my disks.  After some issues I ran into with viewing Live TV while using the storage pool, I went ahead and mapped some of the drives manually just to rule out that the changes were causing compatibility issues with the storage pool.  The problems persisted outside of that setup being mapped to the physical disks and not just simply the logical drive.

 

C:\WINDOWS\system32>tracert api.fanart.tv

 

Tracing route to api.fanart.tv [212.83.134.105]

over a maximum of 30 hops:

 

  1    <1 ms    <1 ms    <1 ms  Upstairs [192.168.10.1]

  2     1 ms    <1 ms    <1 ms  192.168.1.1

  3   158 ms     6 ms     7 ms  L100.DLLSTX-VFTTP-49.verizon-gni.net [173.64.199.1]

  4     9 ms     9 ms     8 ms  G0-3-3-0.DLLSTX-LCR-22.verizon-gni.net [130.81.58.90]

  5     9 ms    11 ms    28 ms  so-5-0-0-0.DFW9-BB-RTR2.verizon-gni.net [130.81.199.36]

  6    10 ms    11 ms    11 ms  0.ae3.XL4.DFW7.ALTER.NET [152.63.3.233]

  7    12 ms    16 ms     8 ms  TenGigE0-7-0-0.GW4.DFW13.ALTER.NET [152.63.101.9]

  8     9 ms     9 ms     8 ms  teliasonera-gw.customer.alter.net [63.65.123.46]

  9    44 ms    43 ms    46 ms  ash-bb3-link.telia.net [213.248.80.141]

 10   161 ms   136 ms   136 ms  prs-bb1-link.telia.net [80.91.251.242]

 11   129 ms   128 ms   136 ms  prs-b8-link.telia.net [213.155.131.9]

 12   132 ms   134 ms   131 ms  online-ic-305116-prs-b8.c.telia.net [62.115.40.86]

 13   138 ms   138 ms   141 ms  45x-s31-1-4090.dc3.poneytelecom.eu [195.154.1.35]

 14   133 ms   133 ms   133 ms  chiron.fanart.tv [62.210.177.168]

 15   138 ms   138 ms   136 ms  api.fanart.tv [212.83.134.105]

 

Trace complete.

 

 

So at this point, I'm not sure what to troubleshoot additionally.  Does anyone have any ideas?  At some point, I'd like to perhaps do a complete reinstall to try and rule out if I simply had a bad upgrade, but would rather not do that until my current situation has been vetted out further so as not to invalidate the current testing done.  For those that have been running into similar issues, do any of you have any pertinent information to add that might help lead us down the right direction?

Edited February 26, 2014 by virtualtinker

[Luke 37238]

can you set your update level to dev and see if it is still a problem there? i don't think it will solve it but just to make sure. thanks.

[danxmanly 0]

Ok, so I went back an unticked all the fanart references in the metadata section and it's rescanning now.  I missed one on the first attempt and it locked up at 25.4% on the rescan, but have gone back and modified and now my scan is at 53.3% and continuing.    Artwork is starting to show back up with MB3 library so I'll let it run why I head out for awhile and report back later.

Edited February 26, 2014 by danxmanly