Welcome to our forums! Please take a few moments to read through our Community Guidelines (also conveniently linked in the header at the top of each page). There, you'll find guidelines on conduct, tips on getting the help you may be searching for, and more!

plex media scanner stuck & cannot be cancelled

anhtuan99anhtuan99 Members Posts: 38 ✭✭

Running Ubuntu 16.04 and Plex Media Server 1.7.6 (also had same issue on 1.7.5).

I'm able to scans all my movies but there seems to get stuck at TV shows. When I try to cancel the library scan from the Plex Web it says something like "Error stopping scanner". Then I cannot restart the library scan afterward. I've attached my log for debugging.

Comments

  • anhtuan99anhtuan99 Members Posts: 38 ✭✭
    edited July 26

    Log didn't get attached for some reason. Here it is.

  • ChuckPAChuckPA Members, Plex Pass, Plex Ninja, Plex Team Member Posts: 14,893 Plex Team Member

    The scanner keeps running because the database is extremely fragmented. This will happen if you add or move a lot of media all at once.
    In such cases, stopping the scan part way through and Optimize Databse (under Libraries) is the action needed. The butler preforms this for you but in extraordinary cases, optimization can't wait.

    Restart PMS.
    Optimize the database
    Continue Scanning the media

    From your logs:

    Server log

    Jul 25, 2017 17:34:19.195 [0x7f67f77ff700] DEBUG - Requesting more shows since stacking only returned 2 items.
    Jul 25, 2017 17:34:19.206 [0x7f68297ff700] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 1 items.
    Jul 25, 2017 17:34:19.206 [0x7f681e3fe700] DEBUG - It took 100.000000 ms to retrieve 1 items.
    

    Scanner log

    Jul 24, 2017 20:07:05.084 [0x7f6ce2a65800] WARN - Waited one whole second for a busy database.
    Jul 24, 2017 20:07:59.579 [0x7f6ce2a65800] WARN - Waited one whole second for a busy database.
    Jul 24, 2017 20:11:09.601 [0x7f6ce2a65800] WARN - Waited one whole second for a busy database.
    Jul 24, 2017 20:11:10.611 [0x7f6ce2a65800] ERROR - Failed to begin transaction (../Library/MetadataItem.cpp:2804) (tries=1): Cannot begin transaction. database is locked
    Jul 24, 2017 20:11:12.491 [0x7f6ce2a65800] WARN - Waited one whole second for a busy database.
    Jul 24, 2017 20:12:13.087 [0x7f6ce2a65800] WARN - Waited one whole second for a busy database.
    Jul 24, 2017 20:19:08.185 [0x7f6ce2a65800] WARN - Waited one whole second for a busy database.
    Jul 24, 2017 20:20:48.609 [0x7f6ce2a65800] WARN - Waited one whole second for a busy database.
    Jul 24, 2017 20:21:22.559 [0x7f6ce2a65800] WARN - Waited one whole second for a busy database.
    

    Please DISABLE Verbose logging until requested

    Please search before posting

    Primary support forums: Linux, Synology, and QNAP

    Please remember to report back. This benefits others.

    Useful links

     Installation and Basic Setup |  Media Preparation (How to name your media files)  |  Linux Permissions 

     Handling TV Specials | Handling Movie extras  |  Nas Compatibility List

     Reporting Plex Server issues | Plex Media Server FAQ

     

    Other useful guides: Local Subtitles | The Plex "dance" | Synology FAQ | PMS Release Announcements | Linux Tips

    No technical support via PM unless offered

    Please remember to mark the appropriate answer(s) which solved your issue.

     
  • anhtuan99anhtuan99 Members Posts: 38 ✭✭

    Gotcha. Thanks for the tip. I had to do a database restore recently and had to rescan a bunch of media.

  • ChuckPAChuckPA Members, Plex Pass, Plex Ninja, Plex Team Member Posts: 14,893 Plex Team Member

    I / We have been talking to engineering about getting them to have a 'Database too slow' detector and automatically self-optimizing. They like the idea. Finding the time to do it given the scope of how to coordinate it in the middle of all active processing is apparently the 'gotcha'.

    Please DISABLE Verbose logging until requested

    Please search before posting

    Primary support forums: Linux, Synology, and QNAP

    Please remember to report back. This benefits others.

    Useful links

     Installation and Basic Setup |  Media Preparation (How to name your media files)  |  Linux Permissions 

     Handling TV Specials | Handling Movie extras  |  Nas Compatibility List

     Reporting Plex Server issues | Plex Media Server FAQ

     

    Other useful guides: Local Subtitles | The Plex "dance" | Synology FAQ | PMS Release Announcements | Linux Tips

    No technical support via PM unless offered

    Please remember to mark the appropriate answer(s) which solved your issue.

     
  • anhtuan99anhtuan99 Members Posts: 38 ✭✭

    The scan worked again after optimizing the database. Thanks!

  • anhtuan99anhtuan99 Members Posts: 38 ✭✭

    @ChuckPA said:
    I / We have been talking to engineering about getting them to have a 'Database too slow' detector and automatically self-optimizing. They like the idea. Finding the time to do it given the scope of how to coordinate it in the middle of all active processing is apparently the 'gotcha'.

    I would think modern database software is smart enough to self-optimize on fly. But having this feature would definitely be useful.

  • anhtuan99anhtuan99 Members Posts: 38 ✭✭

    I've gotten recurrent server crashes now during manual database optimization. I've attached the log here, which should include at least 2 crashes. I triggered a memory dump during 1 of them.

  • ChuckPAChuckPA Members, Plex Pass, Plex Ninja, Plex Team Member Posts: 14,893 Plex Team Member

    It looks like your database is getting slow again. Here, it's actually locked. (a race condition)

    Aug 07, 2017 17:04:17.503 [0x7fcf57fff700] DEBUG - Updating metadata item (save) () with ID 168872
    Aug 07, 2017 17:04:18.522 [0x7fcf57fff700] WARN - Waited one whole second for a busy database.
    Aug 07, 2017 17:04:19.531 [0x7fcf57fff700] ERROR - Failed to begin transaction (../Library/MetadataItem.cpp:865) (tries=1): Cannot begin transaction. database is locked
    Aug 07, 2017 17:04:21.061 [0x7fcf5cfff700] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/flushMetadataCounterCache
    Aug 07, 2017 17:04:21.062 [0x7fcf57fff700] DEBUG - [MI] Closing input file: /data/media/tv/Sym-Bionic Titan/Season 01/Sym-Bionic.Titan.S01E11.SDTV.XviD.MP3-2hd.avi
    Aug 07, 2017 17:04:21.062 [0x7fcf5cfff700] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/flushMetadataCounterCache
    

    a little while later I see this in the main (1 item is just a reference.. you seem to have lost a file and not updated the library)

    Aug 08, 2017 00:59:08.170 [0x7f7508fff700] DEBUG - Committing media stream changes for part 357613
    Aug 08, 2017 00:59:08.275 [0x7f74e7bf9700] WARN - Waited one whole second for a busy database.
    Aug 08, 2017 00:59:08.310 [0x7f7508fff700] DEBUG - Loaded metadata for Red Dog: True Blue (ID 168701) in 3650.000000 ms
    Aug 08, 2017 00:59:08.310 [0x7f7508fff700] DEBUG - There was a change for metadata item 168701 (Red Dog: True Blue), saving.
    Aug 08, 2017 00:59:08.310 [0x7f7508fff700] DEBUG - Updating metadata item (save) (Red Dog: True Blue) with ID 168701
    Aug 08, 2017 00:59:08.341 [0x7f74e9bfd700] DEBUG - It took 10.000000 ms to retrieve 124 items.
    Aug 08, 2017 00:59:08.349 [0x7f74e9bfd700] DEBUG - It took 0.000000 ms to retrieve 113 items.
    Aug 08, 2017 00:59:08.367 [0x7f74f7fff700] ERROR - Error opening file '/data/media/movies/pre/Guardians of the Galaxy Vol. 2 (2017)/Guardians.of.the.Galaxy.Vol.2.2017.TELECINE.-BUCETINHA.mkv' - No such file or directory (2)
    Aug 08, 2017 00:59:08.371 [0x7f74f7fff700] DEBUG - We're going to try to auto-select an audio stream for account 1.
    Aug 08, 2017 00:59:08.371 [0x7f74f7fff700] DEBUG - Selecting best audio stream for part ID 287791 (autoselect: 1 lang
    

    Notice the Database is busy. Is your CPU or HD running at capacity?

    Please DISABLE Verbose logging until requested

    Please search before posting

    Primary support forums: Linux, Synology, and QNAP

    Please remember to report back. This benefits others.

    Useful links

     Installation and Basic Setup |  Media Preparation (How to name your media files)  |  Linux Permissions 

     Handling TV Specials | Handling Movie extras  |  Nas Compatibility List

     Reporting Plex Server issues | Plex Media Server FAQ

     

    Other useful guides: Local Subtitles | The Plex "dance" | Synology FAQ | PMS Release Announcements | Linux Tips

    No technical support via PM unless offered

    Please remember to mark the appropriate answer(s) which solved your issue.

     
  • anhtuan99anhtuan99 Members Posts: 38 ✭✭

    I just restarted the server because the database was busy and needed to be optimized. However, manually optimizing caused the crash. The CPU shouldn't be at capacity at that time because I just restarted plexmediaserver. HD don't believe is at capacity. I did just delete that file prior to running the optimization.

  • sa2000sa2000 Members, Plex Pass, Plex Ninja, Plex Team Member Posts: 28,090 Plex Team Member
    edited August 9

    Can't see any crash uploader logs in the zip and could not find crash reports on our crash reporting system - not recent ones
    Were these all the log files ?

    Can see what was a failure at 01:11 am on 8th August with server relaunched immediately after at 01:12am

    There was Optimize database starting at 01:06:44 am
    This was whilst the system was still coming up from the launch at 01:05:55
    It was till processing all the libraries automatic update list of directories for the fs notify large list

    It stopped on reaching 6001 items to watch for the inotify

    What is the maximum on the system for fs.inotify.max_user_watches
    just wondering if we hit a limit

    If you are getting crashes during optimization, could you delay starting it till the system is up and running and idle - and then see if we get a crash uploader

    Were there any crash related log entries in system journal / log - at or after 01:11:02

    The database optimization activity reached 25% and some warnings

    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Database optimization: Optimizing database. Starting by capturing all sessions.
    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Activity: updated activity a9374faf-f622-4f41-9840-46d5a2762351 - completed 0% - Optimizing database
    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Captured session 0.
    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Captured session 1.
    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Captured session 2.
    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Captured session 3.
    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Captured session 4.
    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Captured session 5.
    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Captured session 6.
    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Captured session 7.
    Aug 08, 2017 01:06:44.234 [0x7f7d25bff700] DEBUG - Captured session 8.
    Aug 08, 2017 01:06:44.235 [0x7f7d25bff700] DEBUG - Captured session 9.
    Aug 08, 2017 01:06:44.235 [0x7f7d25bff700] DEBUG - Captured session 10.
    Aug 08, 2017 01:06:44.235 [0x7f7d25bff700] DEBUG - Captured session 11.
    Aug 08, 2017 01:06:44.235 [0x7f7d25bff700] DEBUG - Captured session 12.
    Aug 08, 2017 01:06:44.235 [0x7f7d25bff700] DEBUG - Captured session 13.
    Aug 08, 2017 01:06:44.235 [0x7f7d25bff700] DEBUG - Captured session 14.
    Aug 08, 2017 01:06:44.235 [0x7f7d25bff700] DEBUG - Captured session 15.
    Aug 08, 2017 01:06:44.235 [0x7f7d25bff700] DEBUG - Captured session 16.
    Aug 08, 2017 01:06:44.235 [0x7f7d25bff700] DEBUG - Captured session 17.
    Aug 08, 2017 01:06:44.235 [0x7f7d25bff700] DEBUG - Captured session 18.
    Aug 08, 2017 01:06:45.642 [0x7f7d25bff700] DEBUG - Captured session 19.
    Aug 08, 2017 01:06:45.642 [0x7f7d25bff700] DEBUG - Database optimization: Rebuilding full text search tables.
    Aug 08, 2017 01:06:45.642 [0x7f7d25bff700] DEBUG - Activity: updated activity a9374faf-f622-4f41-9840-46d5a2762351 - completed 10% - Optimizing database
    Aug 08, 2017 01:06:52.175 [0x7f7d25bff700] WARN - Held transaction for too long (../Library/FullTextSearch.cpp:17): 3.680000 seconds
    Aug 08, 2017 01:06:56.095 [0x7f7d25bff700] WARN - Held transaction for too long (../Library/FullTextSearch.cpp:27): 1.670000 seconds
    Aug 08, 2017 01:07:02.161 [0x7f7d25bff700] WARN - Held transaction for too long (../Library/FullTextSearch.cpp:38): 5.290000 seconds
    Aug 08, 2017 01:07:05.796 [0x7f7d25bff700] WARN - Held transaction for too long (../Library/FullTextSearch.cpp:48): 2.070000 seconds
    Aug 08, 2017 01:07:06.268 [0x7f7d25bff700] DEBUG - Database optimization: starting.
    Aug 08, 2017 01:07:06.268 [0x7f7d25bff700] DEBUG - Activity: updated activity a9374faf-f622-4f41-9840-46d5a2762351 - completed 25% - Optimizing database
    

    After this we were continued to process the long list of directories to watch for inotify

    I thought we only watch directories - for some reasons the list includes about 100 .mkv files

    If it is crashing we need to get a crash dump to go with the logs

    Help given free on forums.            Fee-Based Personal Support & Help.        

    _______________________________________________________________________________________

    Plex Support Information              Troubleshooting               FAQs

    Plex Media Server:   Reporting Issues        Plex Web App: Debug Log    Plex Apps: Support pages and Logs    Logs: All Logs

    For list of 3rd party programs and malware / adware crashing Plex Media Server and mswsock.dll on windows, see Repeated crashing of Plex Media Server on Windows
     
Sign In or Register to comment.