Plex Media Scanner crashing with "double free or corruption (out)"

Plex Media Server
1

Server Version#: 1.20.2.3402
Player Version#: 1.20.0.1406-f47a81b7
OS: Ubuntu 20.04.1

Every night for the last few days my Plex Media Scanner has crashed. Syslog reports:

Oct 10 02:07:29 Plex Media Server[587032]: double free or corruption (out)
Oct 10 02:07:29 Plex Media Server[587032]: ****** PLEX MEDIA SCANNER CRASHED, CRASH REPORT WRITTEN: /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Crash Reports/1.20.2.3402-0fec14d92/PLEX MEDIA SCANNER/23dd486e-8d90-f2ea-2b809fec-48f95bce.dmp

Last two crash reports attached.

Any advice?! Thanks.

Jon.

plex_crash_reports.tar (248 KB)

2

Thank you for that. I will setup to analyze it and then report to Engineering.

3

I’m looking through this now.

can you help me out a bit?

Do you have any inclination as to which type of media it’s crashing on?

It’s resampling the input, to extract info from it, when it dies.

What I’m finding is that it looks like a corrupt file (which it shouldn’t crash on anyway) but if we can identify the file which causes the crash it would make debugging and testing the correction easier.

4

Hi there. I’m not certain, as this is an automated nightly scan of everything, but looking at the various scanner logs it would seem to be a bad mp3. The scanner analysis log has this:

Oct 10, 2020 02:07:00.040 [0x7f2883f62bc0] DEBUG - [FFMPEG] - Setting default whitelist ‘file,crypto’
Oct 10, 2020 02:07:00.049 [0x7f2883f62bc0] WARN - [FFMPEG] - Format mp3 detected only with low score of 24, misdetection possible!
Oct 10, 2020 02:07:00.049 [0x7f2883f62bc0] DEBUG - [FFMPEG] - id3v2 ver:3 flags:00 len:43814
Oct 10, 2020 02:07:00.049 [0x7f2883f62bc0] WARN - [FFMPEG] - invalid concatenated file detected - using bitrate for duration
Oct 10, 2020 02:07:00.049 [0x7f2883f62bc0] DEBUG - [FFMPEG] - pad 576 576
Oct 10, 2020 02:07:00.049 [0x7f2883f62bc0] ERROR - [FFMPEG] - Failed to read frame size: Could not seek to 1255.

is that any use? If not I can send all the scanner logs from around that time.

5

I note that this log is 29 seconds before the scanner crashes, but its the last thing in the log.

6

Absolutely. You have a short file. the could not seek to 1255 is an index within the file. The file got damaged somehow (truncated) but the header still thinks it’s there.

Without deleting the file, might you be able to look for “short” MP3’s and then get me a copy of it, protected in a ZIP?

May I also have that full logs ZIP to include with the report?
Engineering will want to see the full scanner log and follow what it’s doing.

7

Ok - found the offending mp3s. Will remove and replace. I’ve had them for years so I do think the issue with the media scanner is new. Logs attached.

Thanks for looking into it!

logs.tar (20 KB)

8

PLEASE provide a few as samples???

Engineering will be grateful

9

I have literally just deleted them. I’ve got them on a backup disk but can’t get them until tomorrow. Will upload then.

10

Thank you. I would greatly appreciate having those.

By having the bad ones, we can verify we’ve actually repaired the problem.

PS: May I have ALL the logs? You only included 3 files. Having all will make them more comfortable plus they like cross checking in the other log files for completeness sake.

11

@jonewing

Not to press you but have you had opportunity to retrieve the backup of the defective MP3? Engineering is ready to triage the problem

12

Apologies for the delay. This is the culprit.

mp3.tar (67.5 KB)

13

Thank you!

I’ve forwarded to Engineering

14

@jonewing

Engineering couldn’t even get the file to be imported so that it would go to Loudness Analysis. They are convinced this is not the file.

Might you have grabbed the wrong one ?

15

Hi. This was definitely the “short” mp3 that we saw in the logs above. However, it’s possible that it wasn’t the short mp3 that’s causing the Scanner to crash. I looked in the “Deep Analysis” log and it seems to be struggling with this file - I think perhaps this is the one causing the crash as the timings match + it spawns a process to upload a crash report.

mp3.tar (8.4 MB)

Oct 12, 2020 02:07:24.099 [0x7f45ce60b700] DEBUG - [MI] Opening input file: “/mnt/storage/Music/file.mp3”
Oct 12, 2020 02:07:24.099 [0x7f45ce60b700] DEBUG - [FFMPEG] - Opening ‘/mnt/storage/Music/file.mp3’ for reading
Oct 12, 2020 02:07:24.099 [0x7f45ce60b700] DEBUG - [FFMPEG] - Setting default whitelist ‘file,crypto’
Oct 12, 2020 02:07:24.135 [0x7f45ce60b700] DEBUG - [FFMPEG] - Format mp3 probed with size=262144 and score=50
Oct 12, 2020 02:07:24.135 [0x7f45ce60b700] DEBUG - [FFMPEG] - id3v2 ver:3 flags:00 len:23173
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] INFO - [FFMPEG] - Skipping 344 bytes of junk at 23183.
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - Before avformat_find_stream_info() pos: 23527 bytes read:262144 seeks:0 nb_streams:2
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=d8 avail_size_in_buf=20761
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker parser used 0 bytes (0 bits)
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=e0 avail_size_in_buf=20759
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker parser used 16 bytes (128 bits)
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=db avail_size_in_buf=20741
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - index=0
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - qscale[0]: 2
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker parser used 67 bytes (536 bits)
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=db avail_size_in_buf=20672
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - index=1
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - qscale[1]: 4
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker parser used 67 bytes (536 bits)
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=c0 avail_size_in_buf=20603
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - Changing bps from 0 to 8
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - sof0: picture: 348x300
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - component 0 2:2 id: 0 quant:0
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - component 1 1:1 id: 1 quant:1
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - component 2 1:1 id: 2 quant:1
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - pix fmt id 22111100
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - Format yuvj420p chosen by get_format().
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker parser used 17 bytes (136 bits)
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=c4 avail_size_in_buf=20584
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker parser used 0 bytes (0 bits)
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=c4 avail_size_in_buf=20551
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker parser used 0 bytes (0 bits)
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=c4 avail_size_in_buf=20368
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker parser used 0 bytes (0 bits)
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=c4 avail_size_in_buf=20335
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker parser used 0 bytes (0 bits)
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - escaping removed 92 bytes
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=da avail_size_in_buf=20152
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker parser used 20060 bytes (160480 bits)
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - marker=d9 avail_size_in_buf=0
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - decode frame unused 0 bytes
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - All info found
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] WARN - [FFMPEG] - Estimating duration from bitrate, this may be inaccurate
Oct 12, 2020 02:07:24.136 [0x7f45ce60b700] DEBUG - [FFMPEG] - After avformat_find_stream_info() pos: 60391 bytes read:262144 seeks:0 frames:51
Oct 12, 2020 02:07:24.137 [0x7f45ce60b700] DEBUG - [FFMPEG] - Using s16p internally between filters
Oct 12, 2020 02:07:24.137 [0x7f45ce60b700] DEBUG - [FFMPEG] - Using fltp internally between filters
Oct 12, 2020 02:07:24.137 [0x7f45ce60b700] DEBUG - [FFMPEG] - Matrix coefficients:
Oct 12, 2020 02:07:24.137 [0x7f45ce60b700] DEBUG - [FFMPEG] - FL:
Oct 12, 2020 02:07:24.137 [0x7f45ce60b700] DEBUG - [FFMPEG] - FC:0.707107
Oct 12, 2020 02:07:24.137 [0x7f45ce60b700] DEBUG - [FFMPEG] -
Oct 12, 2020 02:07:24.137 [0x7f45ce60b700] DEBUG - [FFMPEG] - FR:
Oct 12, 2020 02:07:24.137 [0x7f45ce60b700] DEBUG - [FFMPEG] - FC:0.707107
Oct 12, 2020 02:07:24.137 [0x7f45ce60b700] DEBUG - [FFMPEG] -
Oct 12, 2020 02:07:24.202 [0x7f45ce60b700] DEBUG - Job running: ‘/usr/lib/plexmediaserver/CrashUploader’ '–directory=/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Crash Reports/1.20.2.34>
Oct 12, 2020 02:07:24.202 [0x7f45ce60b700] DEBUG - Jobs: Starting child process with pid 801228

16

Thanks, We’ll give that a shot :slight_smile:

Thank you for helping with this.

If it’s not this one, it’s the one right behind it in the Analysis queue.
Maybe upload your logs ZIP please?

(Engineering is monitoring this thread)

17

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.