Fri Aug 16 21:39:25 [1858] INFO: starting markad v3.6.6 (d65ceb8) (64bit) Fri Aug 16 21:39:25 [1858] DEBUG: running on VDRSuedHD Fri Aug 16 21:39:25 [1858] DEBUG: called with parameter cmd = nice Fri Aug 16 21:39:25 [1858] INFO: using libavcodec.so.59.18.100 (3871332) with -1 threads Fri Aug 16 21:39:25 [1858] DEBUG: libavcodec config: --enable-nonfree --cross-prefix=x86_64-mld-linux- --ld='x86_64-mld-linux-gcc -m64 -march=core2 -mtune=core2 -msse3 -mfpmath=sse --sysroot=/recipe-sysroot' --cc='x86_64-mld-linux-gcc -m64 -march=core2 -mtune=core2 -msse3 -mfpmath=sse --sysroot=/recipe-sysroot' --cxx='x86_64-mld-linux-g++ -m64 -march=core2 -mtune=core2 -msse3 -mfpmath=sse --sysroot=/recipe-sysroot' --arch=x86_64 --target-os=linux --enable-cross-compile --extra-cflags=' -O2 -pipe -g -feliminate-unused-debug-types -fmacro-prefix-map==/usr/src/debug/ffmpeg/5.0.1-r0 -fdebug-prefix-map==/usr/src/debug/ffmpeg/5.0.1-r0 -fdebug-prefix-map=/recipe-sysroot= -fdebug-prefix-map=/recipe-sysroot-native= -m64 -march=core2 -mtune=core2 -msse3 -mfpmath=sse --sysroot=/recipe-sysroot' --extra-ldflags='-Wl,-O1 -Wl,--hash-style=gnu -Wl,--as-needed -fmacro-prefix-map==/usr/src/debug/ffmpeg/5.0.1-r0 -fdebug-prefix-map==/usr/src/debug/ffmpeg/5.0.1-r0 -fdebug-prefix-map=/recipe-sysroot= -fdebug-prefix-map=/recipe-sysroot-native= ' --sysroot=/recipe-sysroot --libdir=/usr/lib --shlibdir=/usr/lib --datadir=/usr/share/ffmpeg --cpu=generic --pkg-config=pkg-config --enable-alsa --disable-altivec --enable-avcodec --enable-avdevice --enable-avfilter --enable-avformat --enable-bzlib --disable-libfdk-aac --enable-gpl --disable-libgsm --disable-indev=jack --disable-libopus --disable-libvorbis --enable-lzma --disable-libmfx --disable-mipsdsp --disable-mipsdspr2 --disable-libmp3lame --enable-openssl --enable-pic --enable-postproc --enable-pthreads --disable-sdl2 --enable-shared --disable-libspeex --disable-libsrt --disable-stripping --enable-swresample --enable-swscale --enable-libtheora --enable-vaapi --enable-vdpau --disable-libvpx --enable-libx264 --disable-libx265 --enable-libxcb --enable-outdev=xv --enable-zlib Fri Aug 16 21:39:25 [1858] INFO: on /data/tv/Großstadtrevier_(473)/Der_tätowierte_Priester/2024-08-12.18.48.1-0.rec Fri Aug 16 21:39:25 [1858] INFO: aspect ratio 16:9 (from vdr info) Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::GetRecordingStart(): mount option noatime is not set Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::GetRecordingStart(): recording start from VDR info file modification time Mon Aug 12 18:48:00 2024 Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::GetRecordingStart(): use recording start from VDR info file modification time Mon Aug 12 18:48:00 2024 Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::LoadInfo(): recording start at Mon Aug 12 18:48:00 2024 Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::LoadInfo(): timer start at Mon Aug 12 18:50:00 2024 Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::LoadInfo(): event start at offset: 120s -> 0:02:00h Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::LoadInfo(): no VPS start event found Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::LoadInfo(): broadcast start 120s after recording start Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::LoadInfo(): length of broadcast 3300s -> 0:55:00h Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::CheckLogo(): using logo directory /var/lib/markad Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::CheckLogo(): searching logo for Das_Erste_HD Fri Aug 16 21:39:25 [1858] INFO: no logo for Das_Erste_HD 16:9 found in logo cache directory /var/lib/markad, trying to find logo in recording directory Fri Aug 16 21:39:25 [1858] INFO: no logo for Das_Erste_HD 16:9 found in recording directory /data/tv/Großstadtrevier_(473)/Der_tätowierte_Priester/2024-08-12.18.48.1-0.rec, trying to extract logo from recording Fri Aug 16 21:39:25 [1858] DEBUG: ---------------------------------------------------------------------------- Fri Aug 16 21:39:25 [1858] DEBUG: cExtractLogo::SearchLogo(): start extract logo from frame 3000 with aspect ratio 16:9, force = 0 Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::cDecoder(): create new decoder instance Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::cDecoder(): init with 1 threads Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdBlackBordersHoriz::Clear(): clear hborder state Fri Aug 16 21:39:25 [1858] DEBUG: cExtractLogo::WaitForFrames(): frames recorded (201036) read frames (-1) minFrame (0) Fri Aug 16 21:39:25 [1858] DEBUG: cExtractLogo::DeleteFrames(): delete frames from 0 to 3000 Fri Aug 16 21:39:25 [1858] DEBUG: cExtractLogo::SearchLogo(): we have no frames already stored Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): filename: /data/tv/Großstadtrevier_(473)/Der_tätowierte_Priester/2024-08-12.18.48.1-0.rec/00001.ts Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): opened file /data/tv/Großstadtrevier_(473)/Der_tätowierte_Priester/2024-08-12.18.48.1-0.rec/00001.ts Fri Aug 16 21:39:25 [1858] TRACE: AVlog(): mmco: unref short failure Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 0: codec id 27 -> H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10 Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): average framerate 50/1 Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): real framerate 50/1 Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 1: codec id 86016 -> MP2 (MPEG audio layer 2) Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 2: codec id 86016 -> MP2 (MPEG audio layer 2) Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 3: codec id 86016 -> MP2 (MPEG audio layer 2) Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 4: codec id 86019 -> ATSC A/52A (AC-3) Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 5: codec id 94209 -> DVB subtitles Fri Aug 16 21:39:25 [1858] ERROR: cDecoder::DecodeFile(): could not find decoder for stream 6 codec id 94215 Fri Aug 16 21:39:25 [1858] DEBUG: cExtractLogo::SearchLogo(): read (0) frames and could not get enough valid frames (0) Fri Aug 16 21:39:25 [1858] DEBUG: cExtractLogo::SearchLogo(): no similar frames for logo detection found Fri Aug 16 21:39:25 [1858] DEBUG: cExtractLogo::SearchLogo(): no valid logo found Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::~cDecoder(): call avformat_close_input Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::~cDecoder(): decoder instance deleted Fri Aug 16 21:39:25 [1858] DEBUG: cExtractLogo::SearchLogo(): failed, last frame 0 Fri Aug 16 21:39:25 [1858] DEBUG: ---------------------------------------------------------------------------- Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::CheckLogo(): logo search failed Fri Aug 16 21:39:25 [1858] INFO: pre-timer: 0:02:00h Fri Aug 16 21:39:25 [1858] INFO: broadcast length: 0:55:00h Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdBlackBordersHoriz::Clear(): clear hborder state Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdVideo::Clear(): reset detection status, isRestart = 0 Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdBlackBordersHoriz::Clear(): clear hborder state Fri Aug 16 21:39:25 [1858] DEBUG: cEvaluateLogoStopStartPair::cEvaluateLogoStopStartPair(): called Fri Aug 16 21:39:25 [1858] INFO: channel: Das_Erste_HD Fri Aug 16 21:39:25 [1858] DEBUG: parameter --loglevel is set to 7 Fri Aug 16 21:39:25 [1858] DEBUG: markad process nice level 19 Fri Aug 16 21:39:25 [1858] DEBUG: markad IO priority class 3 Fri Aug 16 21:39:25 [1858] DEBUG: parameter --logocachedir is set to /var/lib/markad Fri Aug 16 21:39:25 [1858] DEBUG: parameter --threads is set to -1 Fri Aug 16 21:39:25 [1858] DEBUG: parameter --astopoffs is set to 0 Fri Aug 16 21:39:25 [1858] DEBUG: parameter --log2rec is set Fri Aug 16 21:39:25 [1858] DEBUG: parameter --vps is set Fri Aug 16 21:39:25 [1858] DEBUG: parameter --autologo is set to 2 Fri Aug 16 21:39:25 [1858] DEBUG: parameter --fulldecode is set Fri Aug 16 21:39:25 [1858] DEBUG: ======================================================================================================================= Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::ProcessFiles(): start processing files Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::cDecoder(): create new decoder instance Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::cDecoder(): init with 1 threads Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): filename: /data/tv/Großstadtrevier_(473)/Der_tätowierte_Priester/2024-08-12.18.48.1-0.rec/00001.ts Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): opened file /data/tv/Großstadtrevier_(473)/Der_tätowierte_Priester/2024-08-12.18.48.1-0.rec/00001.ts Fri Aug 16 21:39:25 [1858] TRACE: AVlog(): mmco: unref short failure Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 0: codec id 27 -> H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10 Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): average framerate 50/1 Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): real framerate 50/1 Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 1: codec id 86016 -> MP2 (MPEG audio layer 2) Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 2: codec id 86016 -> MP2 (MPEG audio layer 2) Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 3: codec id 86016 -> MP2 (MPEG audio layer 2) Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 4: codec id 86019 -> ATSC A/52A (AC-3) Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 5: codec id 94209 -> DVB subtitles Fri Aug 16 21:39:25 [1858] ERROR: cDecoder::DecodeFile(): could not find decoder for stream 6 codec id 94215 Fri Aug 16 21:39:25 [1858] DEBUG: ======================================================================================================================= Fri Aug 16 21:39:25 [1858] ERROR: no marks at all detected, something went very wrong Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::ProcessFiles(): end processing files Fri Aug 16 21:39:25 [1858] DEBUG: ======================================================================================================================= Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::LogoMarkOptimization(): start logo mark optimization Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::LogoMarkOptimization(): no logo marks used Fri Aug 16 21:39:25 [1858] DEBUG: ======================================================================================================================= Fri Aug 16 21:39:25 [1858] DEBUG: ProcessOverlap(): start overlap detection Fri Aug 16 21:39:25 [1858] DEBUG: *********************************************************************************************************************** Fri Aug 16 21:39:25 [1858] DEBUG: cMarkAdStandalone::DebugMarks(): current marks: Fri Aug 16 21:39:25 [1858] DEBUG: *********************************************************************************************************************** Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): filename: /data/tv/Großstadtrevier_(473)/Der_tätowierte_Priester/2024-08-12.18.48.1-0.rec/00001.ts Fri Aug 16 21:39:25 [1858] DEBUG: cDecoder::DecodeFile(): opened file /data/tv/Großstadtrevier_(473)/Der_tätowierte_Priester/2024-08-12.18.48.1-0.rec/00001.ts Fri Aug 16 21:39:25 [1858] TRACE: AVlog(): mmco: unref short failure Fri Aug 16 21:39:26 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 0: codec id 27 -> H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10 Fri Aug 16 21:39:26 [1858] DEBUG: cDecoder::DecodeFile(): average framerate 50/1 Fri Aug 16 21:39:26 [1858] DEBUG: cDecoder::DecodeFile(): real framerate 50/1 Fri Aug 16 21:39:26 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 1: codec id 86016 -> MP2 (MPEG audio layer 2) Fri Aug 16 21:39:26 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 2: codec id 86016 -> MP2 (MPEG audio layer 2) Fri Aug 16 21:39:26 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 3: codec id 86016 -> MP2 (MPEG audio layer 2) Fri Aug 16 21:39:26 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 4: codec id 86019 -> ATSC A/52A (AC-3) Fri Aug 16 21:39:26 [1858] DEBUG: cDecoder::DecodeFile(): using decoder for stream 5: codec id 94209 -> DVB subtitles Fri Aug 16 21:39:26 [1858] ERROR: cDecoder::DecodeFile(): could not find decoder for stream 6 codec id 94215 Fri Aug 16 21:39:26 [1858] DEBUG: ----------------------------------------------------------------------------------------------------------------------- Fri Aug 16 21:39:26 [1858] DEBUG: cMarkAdStandalone::ProcessOverlap(): check last stop mark for advertisement in frame with logo or closing credits Fri Aug 16 21:39:26 [1858] DEBUG: cMarkAdStandalone::ProcessOverlap(): end Fri Aug 16 21:39:26 [1858] DEBUG: ----------------------------------------------------------------------------------------------------------------------- Fri Aug 16 21:39:26 [1858] DEBUG: cMarkAdStandalone::BlackScreenOptimization(): start mark optimization with black screen Fri Aug 16 21:39:26 [1858] DEBUG: *********************************************************************************************************************** Fri Aug 16 21:39:26 [1858] DEBUG: cMarkAdStandalone::DebugMarks(): current marks: Fri Aug 16 21:39:26 [1858] DEBUG: *********************************************************************************************************************** Fri Aug 16 21:39:26 [1858] DEBUG: ======================================================================================================================= Fri Aug 16 21:39:26 [1858] DEBUG: cMarkAdStandalone::SilenceOptimization(): start mark optimization with silence scenes Fri Aug 16 21:39:26 [1858] DEBUG: *********************************************************************************************************************** Fri Aug 16 21:39:26 [1858] DEBUG: cMarkAdStandalone::DebugMarks(): current marks: Fri Aug 16 21:39:26 [1858] DEBUG: *********************************************************************************************************************** Fri Aug 16 21:39:26 [1858] DEBUG: ----------------------------------------------------------------------------------------------------------------------- Fri Aug 16 21:39:26 [1858] DEBUG: cMarkAdStandalone::LowerBorderOptimization(): start mark optimization with lower black or white border Fri Aug 16 21:39:26 [1858] DEBUG: cMarkCriteria::GetMarkTypeState(): horizontal border: unknown Fri Aug 16 21:39:26 [1858] DEBUG: *********************************************************************************************************************** Fri Aug 16 21:39:26 [1858] DEBUG: cMarkAdStandalone::DebugMarks(): current marks: Fri Aug 16 21:39:26 [1858] DEBUG: *********************************************************************************************************************** Fri Aug 16 21:39:26 [1858] DEBUG: ----------------------------------------------------------------------------------------------------------------------- Fri Aug 16 21:39:26 [1858] DEBUG: cMarkAdStandalone::SceneChangeOptimization(): start mark optimization with scene changes Fri Aug 16 21:39:26 [1858] DEBUG: *********************************************************************************************************************** Fri Aug 16 21:39:26 [1858] DEBUG: cMarkAdStandalone::DebugMarks(): current marks: Fri Aug 16 21:39:26 [1858] DEBUG: *********************************************************************************************************************** Fri Aug 16 21:39:26 [1858] DEBUG: cMarks::Save(): save marks, isRunningRecording=0 force=1 Fri Aug 16 21:39:26 [1858] DEBUG: ----------------------------------------------------------------------------------------------------------------------- Fri Aug 16 21:39:26 [1858] DEBUG: recording statistics: ----------------------------------------------------------------------- Fri Aug 16 21:39:26 [1858] ERROR: cMarks::Length(): no marks found Fri Aug 16 21:39:26 [1858] ERROR: cMarks::Length(): no marks found Fri Aug 16 21:39:26 [1858] DEBUG: broadcast length without advertisement: 0 frames, 0s -> 0:00:00h Fri Aug 16 21:39:26 [1858] DEBUG: processing statistics: ---------------------------------------------------------------------- Fri Aug 16 21:39:26 [1858] DEBUG: pass 1 (initial logosearch): time 0s -> 0:00:00h Fri Aug 16 21:39:26 [1858] DEBUG: pass 2 (mark detection): time 0s -> 0:00:00h Fri Aug 16 21:39:26 [1858] DEBUG: pass 3 (mark optimation): time 0s -> 0:00:00h Fri Aug 16 21:39:26 [1858] DEBUG: pass 4 (overlap detection): time 0s -> 0:00:00h Fri Aug 16 21:39:26 [1858] DEBUG: global statistics: -------------------------------------------------------------------------- Fri Aug 16 21:39:26 [1858] DEBUG: decoding: time 0s -> 0:00:00h Fri Aug 16 21:39:26 [1858] INFO: duration: time 0s -> 0:00:00h Fri Aug 16 21:39:26 [1858] DEBUG: ---------------------------------------------------------------------------------------------- Fri Aug 16 21:39:26 [1858] DEBUG: cDecoder::~cDecoder(): call avformat_close_input Fri Aug 16 21:39:26 [1858] DEBUG: cDecoder::~cDecoder(): decoder instance deleted Fri Aug 16 21:39:26 [1858] DEBUG: cEvaluateLogoStopStartPair::~cEvaluateLogoStopStartPair(): called