server icon indicating copy to clipboard operation
server copied to clipboard

Seeking some formats cause CasparCG server to crash

Open Bohoaush opened this issue 2 years ago • 4 comments

Expected behaviour

Seek video and start playing

Current behaviour

Crash of CasparCG server - "Aborted (core dumped)" full log bellow


Steps to reproduce

  1. Download file seekTOcrash.mpg (bellow) to your media folder
  2. Start CasparCG server
  3. Send command PLAY 1-1 seekTOcrash SEEK 20

Environment

  • Commit: eacaf19 , f8e48f5 (I haven't tested this with other builds)
  • Server version: v2.3.3
  • Operating system: Ubuntu 20.04.5

Additional information & resources

############################################################################
[2022-12-06 09:27:50.181] [info]    Starting CasparCG Video and Graphics Playout Server 2.3.3 N/A Dev
[2022-12-06 09:27:50.403] [info]    Initializing OpenGL Device.
[2022-12-06 09:27:50.407] [info]    Initialized OpenGL 4.5.0 NVIDIA 525.60.11 NVIDIA Corporation
[2022-12-06 09:27:50.407] [info]    Initialized image module.
[2022-12-06 09:27:50.407] [info]    Initialized ffmpeg module.
[2022-12-06 09:27:50.407] [info]    Initialized oal module.
[2022-12-06 09:27:50.407] [info]    Initialized decklink module.
[2022-12-06 09:27:50.407] [info]    Initialized screen module.
[2022-12-06 09:27:50.407] [info]    Initialized newtek module.
[2022-12-06 09:27:50.560] [info]    Initialized html module.
[2022-12-06 09:27:50.560] [info]    "/home/plus2/caspar/server/casparcg_server/casparcg.config":
[2022-12-06 09:27:50.560] [info]    -----------------------------------------
[2022-12-06 09:27:50.560] [info]    <?xml version="1.0" encoding="utf-8"?>
[2022-12-06 09:27:50.560] [info]    <configuration>
[2022-12-06 09:27:50.560] [info]       <paths>
[2022-12-06 09:27:50.560] [info]          <media-path>media/</media-path>
[2022-12-06 09:27:50.560] [info]          <log-path>log/</log-path>
[2022-12-06 09:27:50.560] [info]          <data-path>data/</data-path>
[2022-12-06 09:27:50.560] [info]          <template-path>template/</template-path>
[2022-12-06 09:27:50.560] [info]       </paths>
[2022-12-06 09:27:50.560] [info]       <lock-clear-phrase>secret</lock-clear-phrase>
[2022-12-06 09:27:50.560] [info]       <channels>
[2022-12-06 09:27:50.560] [info]          <channel>
[2022-12-06 09:27:50.560] [info]             <video-mode>1080i5000</video-mode>
[2022-12-06 09:27:50.560] [info]             <consumers>
[2022-12-06 09:27:50.560] [info]                <ndi>
[2022-12-06 09:27:50.560] [info]                   <name>main</name>
[2022-12-06 09:27:50.560] [info]                   <allow-fields>true</allow-fields>
[2022-12-06 09:27:50.560] [info]                </ndi>
[2022-12-06 09:27:50.560] [info]                <decklink>
[2022-12-06 09:27:50.560] [info]                   <device>1</device>
[2022-12-06 09:27:50.560] [info]                   <embedded-audio>true</embedded-audio>
[2022-12-06 09:27:50.560] [info]                </decklink>
[2022-12-06 09:27:50.560] [info]             </consumers>
[2022-12-06 09:27:50.560] [info]          </channel>
[2022-12-06 09:27:50.560] [info]          <channel>
[2022-12-06 09:27:50.560] [info]             <video-mode>1080i5000</video-mode>
[2022-12-06 09:27:50.560] [info]             <consumers>
[2022-12-06 09:27:50.560] [info]                <ndi>
[2022-12-06 09:27:50.560] [info]                   <name>internet-stream</name>
[2022-12-06 09:27:50.560] [info]                   <allow-fields>true</allow-fields>
[2022-12-06 09:27:50.560] [info]                </ndi>
[2022-12-06 09:27:50.560] [info]             </consumers>
[2022-12-06 09:27:50.560] [info]          </channel>
[2022-12-06 09:27:50.560] [info]       </channels>
[2022-12-06 09:27:50.560] [info]       <controllers>
[2022-12-06 09:27:50.560] [info]          <tcp>
[2022-12-06 09:27:50.560] [info]             <port>5250</port>
[2022-12-06 09:27:50.560] [info]             <protocol>AMCP</protocol>
[2022-12-06 09:27:50.560] [info]          </tcp>
[2022-12-06 09:27:50.560] [info]       </controllers>
[2022-12-06 09:27:50.560] [info]       <amcp>
[2022-12-06 09:27:50.560] [info]          <media-server>
[2022-12-06 09:27:50.560] [info]             <host>localhost</host>
[2022-12-06 09:27:50.560] [info]             <port>8000</port>
[2022-12-06 09:27:50.560] [info]          </media-server>
[2022-12-06 09:27:50.560] [info]       </amcp>
[2022-12-06 09:27:50.560] [info]    </configuration>
[2022-12-06 09:27:50.560] [info]    -----------------------------------------
[2022-12-06 09:27:50.570] [info]    Initialized OpenGL Accelerated GPU Image Mixer for channel 1
[2022-12-06 09:27:50.570] [info]    video_channel[1|1080i5000] Successfully Initialized.
[2022-12-06 09:27:50.571] [info]    Initialized OpenGL Accelerated GPU Image Mixer for channel 2
[2022-12-06 09:27:50.571] [info]    video_channel[2|1080i5000] Successfully Initialized.
[2022-12-06 09:27:50.573] [info]    Loaded "/home/plus2/caspar/server/casparcg_server/libndi.so.5"
[2022-12-06 09:27:50.592] [info]    ndi_consumer[1|main] Initialized.
[2022-12-06 09:27:50.593] [info]    Starting ndi-send thread for ndi output: main
[2022-12-06 09:27:50.616] [info]    DeckLink SDI 4K [1-1|1080i5000] Enabled embedded-audio.
[2022-12-06 09:27:50.616] [info]    DeckLink SDI 4K [1-1|1080i5000] Disabled low-latency mode.
[2022-12-06 09:27:50.616] [error]   DeckLink SDI 4K [1-1|1080i5000] Failed to enable external keyer.
[2022-12-06 09:27:50.631] [info]    DeckLink SDI 4K [1-1|1080i5000] Initialized.
[2022-12-06 09:27:50.641] [info]    ndi_consumer[2|internet-stream] Initialized.
[2022-12-06 09:27:50.641] [info]    Initialized channels.
[2022-12-06 09:27:50.641] [info]    Starting ndi-send thread for ndi output: internet-stream
[2022-12-06 09:27:50.641] [info]    Initialized command repository.
[2022-12-06 09:27:50.641] [info]    Initialized startup producers.
[2022-12-06 09:27:50.642] [info]    Initialized controllers.
[2022-12-06 09:27:50.642] [info]    Initialized osc.
[2022-12-06 09:27:50.709] [info]    DeckLink SDI 4K [1-1|1080i5000] Reference signal: not detected.
[2022-12-06 09:27:58.780] [info]    Received message from Console: PLAY 1-1 seekTOcrash\r\n
[2022-12-06 09:27:58.849] [warning] ffmpeg[seekTOcrash.mpg|0.0000/32.1200] Latency: 3
[2022-12-06 09:28:12.758] [info]    Received message from Console: PLAY 1-1 seekTOcrash SEEK 20\r\n
[2022-12-06 09:28:12.793] [error]   [ffmpeg] [mp2 @ 0x7fc652b0e400] Header missing
[2022-12-06 09:28:12.793] [error]   
[2022-12-06 09:28:12.793] [error]   Exception: /source/modules/ffmpeg/producer/av_producer.cpp(156): Throw in function caspar::ffmpeg::Decoder::Decoder(AVStream*)::<lambda()>::<lambda()>
[2022-12-06 09:28:12.793] [error]   Dynamic exception type: boost::exception_detail::clone_impl<caspar::ffmpeg::ffmpeg_error_t>
[2022-12-06 09:28:12.793] [error]   [caspar::tag_stacktrace_info*] =  0# 0x0000560C06EC86CF in bin/casparcg
[2022-12-06 09:28:12.793] [error]    1# 0x0000560C070560DC in bin/casparcg
[2022-12-06 09:28:12.793] [error]    2# 0x0000560C070C2FF9 in bin/casparcg
[2022-12-06 09:28:12.793] [error]    3# 0x00007FC71FAA0609 in /home/plus2/caspar/server/casparcg_server/bin/../lib/libpthread.so.0
[2022-12-06 09:28:12.793] [error]    4# clone in /lib/x86_64-linux-gnu/libc.so.6
[2022-12-06 09:28:12.793] [error]   
[2022-12-06 09:28:12.793] [error]   [caspar::ffmpeg::tag_ffmpeg_errn_info*] = -1094995529
[2022-12-06 09:28:12.793] [error]   [boost::errinfo_errno_*] = 1094995529, "Unknown error 1094995529"
[2022-12-06 09:28:12.793] [error]   [boost::errinfo_api_function_*] = avcodec_send_packet(ctx.get(), packet.get())
[2022-12-06 09:28:12.793] [error]   
[2022-12-06 09:28:12.793] [error]    0# 0x0000560C06EDE5C4 in bin/casparcg
[2022-12-06 09:28:12.793] [error]    1# 0x00007FC72279138C in /lib/x86_64-linux-gnu/libstdc++.so.6
[2022-12-06 09:28:12.793] [error]    2# 0x00007FC7227913F7 in /lib/x86_64-linux-gnu/libstdc++.so.6
[2022-12-06 09:28:12.793] [error]    3# 0x00007FC7227916A9 in /lib/x86_64-linux-gnu/libstdc++.so.6
[2022-12-06 09:28:12.793] [error]    4# 0x0000560C070364ED in bin/casparcg
[2022-12-06 09:28:12.793] [error]    5# 0x0000560C070560EF in bin/casparcg
[2022-12-06 09:28:12.793] [error]    6# 0x0000560C070C2FF9 in bin/casparcg
[2022-12-06 09:28:12.793] [error]    7# 0x00007FC71FAA0609 in /home/plus2/caspar/server/casparcg_server/bin/../lib/libpthread.so.0
[2022-12-06 09:28:12.793] [error]    8# clone in /lib/x86_64-linux-gnu/libc.so.6
[2022-12-06 09:28:12.793] [error]   
  • When playing the same file with ffplay (c:\apps\ffmpeg\bin\ffplay.exe -ss 20 -i d:\_testing\seekTOcrash.mpg), I get simillar error "[mp2 @ 0000027706230500] Header missing", but the file seeks and plays with no problem.
  • On Windows with 2.3.3 LTS, the same error is present, but doesn't crash CasparCG, with eacaf19 it does. (EDIT: this information was wrong and missleading prior to this edit. After additional testing, it behaved as currently explained)

Bohoaush avatar Dec 06 '22 08:12 Bohoaush

Hi, The log said the error was thrown at line 156 of av_producer.cpp so I was able to mitigate the crash by adding catch(ffmpeg::ffmpeg_error_t) block to an already existing try with catch for boost::thread_interrupted&. Now it will countinue to play what it was playing and write [warning] ffmpeg[seekTOcrash.mpg|0.0000/31.9200] Waiting for audio frame... (e.g. sending PLAY 1-1 abcd, then PLAY 1-1 efgh SEEK 20 will result in abcd file still playing and said warnings). I will continue to look into it, but I don't really know c++, so my understanding of what's going on in there is very limited. Any help much appreciated.

Bohoaush avatar Dec 07 '22 09:12 Bohoaush

Hi again, I was able to solve the problem by copying the whole try block into my new catch block (see previous comment). I will continue to look into this, but I don't think I am capable of doing a propper fix.

Bohoaush avatar Dec 07 '22 11:12 Bohoaush

This and possibly crash related to issue 1460 was added in commit b657428

jpc0 avatar Mar 18 '23 23:03 jpc0

This is the previous threading logic that caught the exception in the commit just before. It still exists in commit b657428 here but no longer catches the error.

I think adding the following catches, which were used to catch this error before, into the catch block mentioned in pull request 1452 would solve the problem.

catch (ffmpeg::ffmpeg_error_t& ex) {
                if (auto errn = boost::get_error_info<ffmpeg_errn_info>(ex)) {
                    if (*errn == AVERROR_EXIT) {
                        return;
                    }
                }
                CASPAR_LOG_CURRENT_EXCEPTION();
            } catch (...) {
                CASPAR_LOG_CURRENT_EXCEPTION();
            }

jpc0 avatar Mar 19 '23 00:03 jpc0