Sonarr version 2.0.0.4855:
Mono version 5.0.1.1:
OS: Debian 7
((Debug logs)):
https://drive.google.com/drive/folders/0BwK9igfCi5aiRjJDWTdfTW5qbDA?usp=sharing
Description of issue:
After restarting Sonarr when hung it will continue its disk scans and downloads but will hang after a few downloads complete. I have reinstalled Sonarr, deleted its databases, cleared nzbget’s history and still have issues. When Sonarr hangs it will be stuck at 100% CPU for a single core and checking “api/command?apikey=” the command it is stuck on is CheckForFinishedDownload. In NZBget all queued downloads complete with no issues. At this point I’m thinking it is possibly a bad video or file name it is getting stuck on.
Usually this is libmediainfo. Set the log level to Trace in Settings->General, restart sonarr and try again. The keyword is VideoFileInfoReader. Which you can also see at Debug level, but next you’ll see it actually reading parts of the file.
I have included the trace logs from when it hangs in the original link. I do see the VideoFileInfoReader lines but don’t see anything that would make it hang as it appears to finish each properly. I found these lines and didn’t know if they were normal.
17-7-20 10:04:23.8|Trace|Owin|SQLite error (5): database is locked
Those are normal, happens when multiple threads access the database, it’s basically sqlite saying 'I’m busy, I’ll retry in a couple of milliseconds", hence the Trace log level instead of Warn/Error.
CheckForFinishedDownload is indeed finishing properly. I think next you should keep track of the cpu usage, see when exactly it stuck on 100% CPU.
On a sidenote there, the logs does not corroborate your claim that “checking “api/command?apikey=” the command it is stuck on is CheckForFinishedDownload”. My guess is you’ll first have to reproduce the issue.
I have tested further and can recreate what may be causing the issues I’m seeing.
I start an automatic search.
Item is found and sent to nzbget, no activity is shown in Sonarr.
Item finishes downloading in nzbget and verified that files exist.
Sonarr is still stuck at CheckForFinishedDownload according to its command api.
If I kill and restart Sonarr it will instantly populate the activity page and will instantly import all hung downloads.
I have attached debug and trace logs of the time period of the above events.
https://drive.google.com/drive/folders/0BwK9igfCi5aiRjJDWTdfTW5qbDA?usp=sharing
17-7-31 01:17:39.4|Trace|CommandQueueManager|Publishing CheckForFinishedDownload
17-7-31 01:17:39.4|Trace|CommandQueueManager|Checking if command is queued or started: CheckForFinishedDownload
17-7-31 01:17:39.4|Trace|CommandQueueManager|Command is already in progress: CheckForFinishedDownload
need more of the preceding logs, since at this point it’s already running.
I have included the logs from a fresh start of Sonarr and then attempting to download The Tonight Show Starring Jimmy Fallon 4x178. Sonarr finds and sends the file to nzbget, it downloads. In Sonarr the status turns to episode is downloading, it never shows the progress bar, then after a bit turns back to episode missing from disk.
Logs
Sry it’s been a hectic few days, took a while for me to notice that browser tab I still had open as a reminder.
Here it is:
17-7-31 14:57:12.1|Debug|VideoFileInfoReader|Getting media info from /media/8e439a3c-62d5-4c2f-8e91-58a3ab5cb812/Share01/Completed/TV/Chopped.S35E02.Clock.Shock.HDTV.x264-VV/Chopped.S35E02.Clock.Shock.HDTV.x264-VV.mp4
17-7-31 14:57:12.1|Trace|MediaInfo|Read file offset 0-16384 (16384 bytes)
Never gets out of that, libmediainfo is stuck processing that file.
Can you run the mediainfo cmdline tool on it that mp4 file? (And please don’t throw away the file if it’s corrupt)
Here’s the output for the file. The file doesn’t appear to be corrupt. I copied it over local and plays fine in VLC.
[details=mediainfo Chopped.S35E02.Clock.Shock.HDTV.x264-VV.mp4]
General
Complete name : Chopped.S35E02.Clock.Shock.HDTV.x264-VV.mp4
Format : MPEG-4
Format profile : Base Media
Codec ID : isom
File size : 255 MiB
Duration : 41mn 59s
Overall bit rate : 849 Kbps
Movie name : Chopped S35E02 - RMTeam, RMZ.cr
Writing application : Lavf57.25.100
desc : Encoded By RMTeam, http://RMZ.cr
Video
ID : 1
Format : AVC
Format/Info : Advanced Video Codec
Format profile : High@L3.1
Format settings, CABAC : Yes
Format settings, ReFrames : 4 frames
Codec ID : avc1
Codec ID/Info : Advanced Video Coding
Duration : 41mn 59s
Bit rate : 737 Kbps
Width : 854 pixels
Height : 480 pixels
Display aspect ratio : 16:9
Frame rate mode : Variable
Frame rate : 59.940 fps
Minimum frame rate : 2.849 fps
Maximum frame rate : 62.500 fps
Color space : YUV
Chroma subsampling : 4:2:0
Bit depth : 8 bits
Scan type : Progressive
Bits/(Pixel*Frame) : 0.030
Stream size : 221 MiB (87%)
Writing library : x264 core 148 r333 90a61ec
Encoding settings : cabac=1 / ref=3 / deblock=1:0:0 / analyse=0x3:0x113 / me=umh / subme=8 / psy=1 / psy_rd=1.00:0.00 / mixed_ref=1 / me_range=16 / chroma_me=1 / trellis=1 / 8x8dct=1 / cqm=0 / deadzone=21,11 / fast_pskip=0 / chroma_qp_offset=-2 / threads=8 / lookahead_threads=2 / sliced_threads=0 / nr=0 / decimate=1 / interlaced=0 / bluray_compat=0 / constrained_intra=0 / bframes=8 / b_pyramid=2 / b_adapt=1 / b_bias=0 / direct=1 / weightb=1 / open_gop=0 / weightp=2 / keyint=250 / keyint_min=23 / scenecut=40 / intra_refresh=0 / rc_lookahead=40 / rc=crf / mbtree=1 / crf=25.0 / qcomp=0.60 / qpmin=0 / qpmax=69 / qpstep=4 / vbv_maxrate=10000 / vbv_bufsize=10000 / crf_max=0.0 / nal_hrd=none / filler=0 / ip_ratio=1.40 / aq=1:1.00
Audio
ID : 2
Format : AAC
Format/Info : Advanced Audio Codec
Format profile : LC
Codec ID : 40
Duration : 41mn 59s
Bit rate mode : Constant
Bit rate : 96.0 Kbps
Channel(s) : 2 channels
Channel positions : Front: L R
Sampling rate : 48.0 KHz
Compression mode : Lossy
Delay relative to video : -534ms
Stream size : 29.2 MiB (11%)
Language : English
Text #1
ID : 1-CC1
Format : EIA-608
Muxing mode : AVC / SCTE 128 / DTVCC Transport
Muxing mode, more info : Muxed in Video #1
Duration : 41mn 59s
Bit rate mode : Constant
Stream size : 0.00 Byte (0%)
Encoded stream size : 0.00 Byte (0%)
Text #2
ID : 1-1
Format : EIA-708
Muxing mode : AVC / SCTE 128 / DTVCC Transport
Muxing mode, more info : Muxed in Video #1
Duration : 41mn 59s
Bit rate mode : Constant
Stream size : 0.00 Byte (0%)
Encoded stream size : 0.00 Byte (0%)[/details]
I often have this situation.The bad video will have an inpact on it.
PS: If I run that file through Sonarr on windows, with mediainfo 0.7.93.0, I get:
[Debug] [34] VideoFileInfoReader: Getting media info from Z:\import\test\corruptiontest\Chopped.S35E02.Clock.Shock.HDTV.x264-VV.mp4
[Trace] [34] MediaInfo: Read file offset 0-16384 (16384 bytes)
[Trace] [34] MediaInfo: Read file offset 262626039-267311477 (4685438 bytes)
[Trace] [34] MediaInfo: Read file offset 48-32816 (32768 bytes)
[Trace] [34] MediaInfo: Read a total of 4734590 bytes (1,8%)
sha1sum of the file: f540db2d143de2e5dfdb39e8790d8e2a6ad96f68
On linux, with libmediainfo 0.7.91.0, same thing, gets parsed fine.
I did move the file out of the library and everything seems to be running fine now.
I have mediainfo 0.7.58 on Linux and 0.7.97 32 and 64 bit on Windows. All three seem to open the file fine.
My checksum matches yours.
mediainfo and Sonarr+libmediainfo is different though. I assume the 0.7.58 runs on the debian system with Sonarr, it’s a really old version, around 2012. I suggest you update it.
Btw. run your commandline test with mediainfo --ParseSpeed=0.0 ... that’s closer to what Sonarr does internally.
I’ll see about updating it. Don’t know why my repos would be that far out.
I ran the command line mediainfo with that argument and still receive no issue on either system.
debian is known for having old packages, especially for third party libs. You’ll need to use another apt repository.
Any idea what the root cause for this is or how to avoid it. Can there not be a sanity check on the libmediainfo call when it hangs in a situation like this?
I ask because I believe I have another download that has locked up on a bad file, but I’m unable to spot it in the log file.
Not really. It’s like you’ve ordered pest control to your house coz you got termites. They’re supposed to be done fumigating in 24h, sometimes 3 days. But for some reason they’ve been at it for a week now but you can’t just tell em to stop, break down the tent and leave, coz… poisonous gas and all.
Basically, we have no idea what libmediainfo is doing internally, and if it was happening to the latest version we’d try to reproduce on our own setup and send a sample file to the mediainfo dev to get a fix, but that’s not applicable here coz you were using an old libmediainfo version.
So unless you can update it, there’s nothing further we can do for you.
This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.