Log spam in 22.1.2 version

[Gujal00]

After updating to 22.1.2 version, whenever inputstream.ffmpegdirect is used, it is filling the log with messages as below, the video is playing normally as before

2025-06-23 17:36:43.629 T:2417     info <general>: Opening stream: 0 source: 256
2025-06-23 17:36:43.629 T:2417     info <general>: Opening stream: 1 source: 256
2025-06-23 17:36:43.630 T:2417     info <general>: Opening stream: 0 source: 256
2025-06-23 17:36:43.630 T:2417     info <general>: Opening stream: 1 source: 256
2025-06-23 17:36:43.631 T:2417     info <general>: Opening stream: 0 source: 256
2025-06-23 17:36:43.631 T:2417     info <general>: Opening stream: 1 source: 256
2025-06-23 17:36:43.634 T:2417     info <general>: Opening stream: 0 source: 256
2025-06-23 17:36:43.634 T:2417     info <general>: Opening stream: 1 source: 256
2025-06-23 17:36:43.634 T:2417     info <general>: Opening stream: 0 source: 256
2025-06-23 17:36:43.634 T:2417     info <general>: Opening stream: 1 source: 256
2025-06-23 17:36:43.635 T:2417     info <general>: Opening stream: 0 source: 256
2025-06-23 17:36:43.635 T:2417     info <general>: Opening stream: 1 source: 256
2025-06-23 17:36:43.635 T:2417     info <general>: Opening stream: 0 source: 256
2025-06-23 17:36:43.636 T:2417     info <general>: Opening stream: 1 source: 256
2025-06-23 17:36:43.637 T:2417     info <general>: Opening stream: 0 source: 256
2025-06-23 17:36:43.638 T:2417     info <general>: Opening stream: 1 source: 256

The messages keep filling non stop until video playback is stopped resulting in huge logfiles

Tested on two platforms, same behaviour
Ubuntu 24.04LTS
Windows 10 22H2

[phunkyfish]

Have you tried disabling the ffmpeg logging in the addon settings?

[Gujal00]

Yes, I have not changed the default on either windows or linux

[phunkyfish]

Ok I can see two places where the log level is set. The first is as follows:

  FFmpegLog::SetLogLevel(AV_LOG_INFO);
  FFmpegLog::SetEnabled(kodi::addon::GetSettingBoolean("allowFFmpegLogging"));
  av_log_set_callback(ff_avutil_log);

However the second is just:

FFmpegLog::SetEnabled(kodi::addon::GetSettingBoolean("allowFFmpegLogging"));

I'll create a PR for you to test on windows that mirrors the first instance, Kodi Piers (22). You'll need to install the zip manually.

[phunkyfish]

PR create here. It will take a while to build. Please test once it's done.

If this doesn't work we can try setting the log level to something more stringent to see if that work.

[phunkyfish]

Here are the testbuilds: https://jenkins.kodi.tv/blue/organizations/jenkins/xbmc%2Finputstream.ffmpegdirect/detail/PR-333/1/artifacts

[Gujal00]

Thanks for that patched build
Tested it with KodiSetup-20250626-523ef087-master-x64.exe on Windows 10 64 bit and it is still doing it

2025-06-27 23:11:32.128 T:1516     info <general>: Creating InputStream
2025-06-27 23:11:32.131 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: inputstream.ffmpegdirect: OpenStream() - Num Props: 1
2025-06-27 23:11:32.131 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: inputstream.ffmpegdirect property: inputstream.ffmpegdirect.is_realtime_stream = true
2025-06-27 23:11:32.131 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: Stream mimetype: video/mp2t
2025-06-27 23:11:32.131 T:1516  warning <general>: Interface_Filesystem::ADDON::Interface_Filesystem::TranslateFileReadBitsToKodi - detected use of deprecated 'ADDON_READ_CHUNKED' flag
2025-06-27 23:11:33.551 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpegdirect::FFmpegStream::OpenWithCURL - IO handled by Kodi's cURL
2025-06-27 23:11:33.551 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[E6F2DCDA]: Input #0, mpegts, from 'http://m3u.sstv.one:80/live/xxxxxx/xxxxxxxx/33130.ts':
2025-06-27 23:11:33.551 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[E6F2DCDA]:   Duration: N/A, bitrate: N/A
2025-06-27 23:11:33.551 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[E6F2DCDA]:   Program 1 
2025-06-27 23:11:33.552 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[E6F2DCDA]:     Metadata:
2025-06-27 23:11:33.552 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[E6F2DCDA]:       service_name    : Service01
2025-06-27 23:11:33.552 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[E6F2DCDA]:       service_provider: FFmpeg
2025-06-27 23:11:33.552 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[E6F2DCDA]:   Stream #0:0[0x100]: Video: h264 ([27][0][0][0] / 0x001B), none, 90k tbn
2025-06-27 23:11:33.552 T:1516     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[E6F2DCDA]:   Stream #0:1[0x101]: Audio: aac ([15][0][0][0] / 0x000F), 0 channels
2025-06-27 23:11:33.552 T:1516     info <general>: Creating Demuxer
2025-06-27 23:11:33.553 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:33.555 T:1516     info <general>: Creating video codec with codec id: 27
2025-06-27 23:11:33.555 T:1516     info <general>: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2025-06-27 23:11:33.556 T:1516     info <general>: Creating video thread
2025-06-27 23:11:33.556 T:11056    info <general>: running thread: video_thread
2025-06-27 23:11:33.556 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:33.556 T:1516     info <general>: Finding audio codec for: 86018
2025-06-27 23:11:33.562 T:1516     info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2025-06-27 23:11:33.562 T:1516     info <general>: void __cdecl CVideoPlayerAudio::OpenStream(class CDVDStreamInfo &,class std::unique_ptr<class CDVDAudioCodec,struct std::default_delete<class CDVDAudioCodec> >): Allowing max Out-Of-Sync Value of 50 ms
2025-06-27 23:11:33.562 T:1516     info <general>: Creating audio thread
2025-06-27 23:11:33.562 T:488      info <general>: running thread: CVideoPlayerAudio::Process()
2025-06-27 23:11:34.685 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:34.685 T:1516     info <general>: Creating video codec with codec id: 27
2025-06-27 23:11:34.685 T:1516     info <general>: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2025-06-27 23:11:34.687 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:34.689 T:11056    info <general>: bool __cdecl DXVA::CContext::CreateContext(void): creating discrete d3d11va device for decoding.
2025-06-27 23:11:34.731 T:11056    info <general>: bool __cdecl DXVA::CContext::CreateContext(void): device for decoding created on adapter 'NVIDIA GeForce RTX 3060' with D3D_FEATURE_LEVEL_12_1
2025-06-27 23:11:34.731 T:11056    info <general>: bool __cdecl DXVA::CDecoder::Open(struct AVCodecContext *,struct AVCodecContext *,const enum AVPixelFormat): Total video memory available is 28468 MB (dedicated = 12115 MB, shared = 16353 MB)
2025-06-27 23:11:34.884 T:11056    info <general>: void __cdecl DXVA::CVideoBufferShared::InitializeFence(class DXVA::CDecoder *): fence synchronization activated.
2025-06-27 23:11:34.888 T:12120    info <general>: bool __cdecl CRendererDXVA::Configure(const struct VideoPicture &,float,unsigned int): chosen conversion: NV12 / YCBCR_STUDIO_G22_LEFT_P709 to R10G10B10A2_UNORM / RGB_FULL_G22_NONE_P709
2025-06-27 23:11:34.888 T:12120    info <general>: struct DXVA::ProcessorCapabilities __cdecl DXVA::CEnumeratorHD::ProbeProcessorCaps(void): supported deinterlace methods: blend:yes, bob:yes, adaptive:yes, mocomp:no.
2025-06-27 23:11:34.888 T:12120 warning <general>: void __cdecl CRendererHQ::CheckVideoParameters(void): chosen scaling method 1 is not supported by renderer
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.008 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.016 T:488      info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2025-06-27 23:11:35.016 T:488      info <general>: Skipped 1 duplicate messages..
2025-06-27 23:11:35.016 T:488      info <general>: Creating audio stream (codec id: 86018, channels: 2, sample rate: 48000, no pass-through)
2025-06-27 23:11:35.052 T:6720     info <general>: CActiveAESink::OpenSink - initialize sink
2025-06-27 23:11:35.259 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.259 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.260 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.261 T:11056    info <general>: void __cdecl DXVA::CVideoBufferShared::InitializeFence(class DXVA::CDecoder *): fence synchronization activated.
2025-06-27 23:11:35.269 T:12120    info <general>: Skipped 4 duplicate messages..
2025-06-27 23:11:35.269 T:12120    info <general>: Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY
2025-06-27 23:11:35.271 T:11056    info <general>: void __cdecl DXVA::CVideoBufferShared::InitializeFence(class DXVA::CDecoder *): fence synchronization activated.
2025-06-27 23:11:35.354 T:11056    info <general>: CDVDVideoCodecFFmpeg::CDropControl: calculated diff time: 16636
2025-06-27 23:11:35.519 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.519 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.519 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.519 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.519 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.519 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.520 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.520 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.520 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.520 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.520 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.520 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.520 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.520 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.520 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.520 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.655 T:1516     info <general>: Opening stream: 1 source: 256
2025-06-27 23:11:35.656 T:1516     info <general>: Opening stream: 0 source: 256
2025-06-27 23:11:35.656 T:1516     info <general>: Opening stream: 1 source: 256
>>>>>
>>>>> SNIP
>>>>>
2025-06-27 23:21:13.182 T:10208    info <general>: Opening stream: 0 source: 256
2025-06-27 23:21:13.182 T:10208    info <general>: Opening stream: 1 source: 256
2025-06-27 23:21:13.182 T:10208    info <general>: Opening stream: 0 source: 256
2025-06-27 23:21:13.182 T:10208    info <general>: Opening stream: 1 source: 256
2025-06-27 23:21:13.182 T:10208    info <general>: Opening stream: 0 source: 256
2025-06-27 23:21:13.182 T:10208    info <general>: Opening stream: 1 source: 256
2025-06-27 23:21:13.182 T:10208    info <general>: Opening stream: 0 source: 256
2025-06-27 23:21:13.182 T:10208    info <general>: Opening stream: 1 source: 256
2025-06-27 23:21:13.182 T:10208    info <general>: Opening stream: 0 source: 256
2025-06-27 23:21:13.182 T:10208    info <general>: Opening stream: 1 source: 256
2025-06-27 23:21:13.183 T:10208    info <general>: Opening stream: 0 source: 256
2025-06-27 23:21:13.183 T:10208    info <general>: Opening stream: 1 source: 256
2025-06-27 23:21:13.183 T:10208    info <general>: Opening stream: 0 source: 256
2025-06-27 23:21:13.183 T:10208    info <general>: Opening stream: 1 source: 256
2025-06-27 23:21:13.200 T:10208    info <general>: Opening stream: 0 source: 256
2025-06-27 23:21:13.200 T:10208    info <general>: Opening stream: 1 source: 256
2025-06-27 23:21:13.200 T:10208    info <general>: Opening stream: 0 source: 256
2025-06-27 23:21:13.200 T:10208    info <general>: Opening stream: 1 source: 256
2025-06-27 23:21:13.681 T:12120    info <general>: CVideoPlayerAudio::Process - stream stalled
2025-06-27 23:21:13.748 T:13072    info <general>: CVideoPlayer::CloseFile()
2025-06-27 23:21:13.748 T:13072    info <general>: VideoPlayer: waiting for threads to exit
2025-06-27 23:21:13.854 T:10208    info <general>: CVideoPlayer::OnExit()
2025-06-27 23:21:13.854 T:10208    info <general>: Closing stream player 1
2025-06-27 23:21:13.854 T:10208    info <general>: Waiting for audio thread to exit
2025-06-27 23:21:13.856 T:12120    info <general>: thread end: CVideoPlayerAudio::OnExit()
2025-06-27 23:21:13.856 T:10208    info <general>: Closing audio device
2025-06-27 23:21:13.859 T:10208    info <general>: Deleting audio codec
2025-06-27 23:21:13.859 T:10208    info <general>: Closing stream player 2
2025-06-27 23:21:13.859 T:10208    info <general>: waiting for video thread to exit
2025-06-27 23:21:13.859 T:11056    info <general>: CActiveAESink::OpenSink - initialize sink
2025-06-27 23:21:13.887 T:13972 warning <general>: CVideoPlayerVideo::OutputPicture - timeout waiting for buffer
2025-06-27 23:21:13.887 T:13972    info <general>: thread end: video_thread
2025-06-27 23:21:13.888 T:10208    info <general>: deleting video codec
2025-06-27 23:21:13.888 T:10208    info <general>: void __cdecl DXVA::CDecoder::Close(void): closing decoder.
2025-06-27 23:21:13.888 T:10208    info <general>: DXVA: closing decoder context.
2025-06-27 23:21:14.035 T:10208    info <general>: ADDON: Dll Destroyed - Inputstream FFmpeg Direct
2025-06-27 23:21:14.035 T:13072    info <general>: VideoPlayer: finished waiting
2025-06-27 23:21:14.035 T:13072    info <general>: CVideoPlayer::CloseFile()
2025-06-27 23:21:14.035 T:13072    info <general>: VideoPlayer: waiting for threads to exit
2025-06-27 23:21:14.035 T:13072    info <general>: VideoPlayer: finished waiting

[phunkyfish]

Do you know when this behaviour started?

Does it happen for the whole time the stream was playing? I.e. it’s continuous through the SNIP?

As they the info level logs I wonder if the problems lies in ffmpeg.

[Gujal00]

Yes, it happens the whole time the video is playing. (hence the snip)
I tested with 22.1.0 and 22.1.1 and it happens there too.
I will test on Kodi 21 and see if the issue goes away. As you say may be this is something with 22 nightlies

[Gujal00]

Here is the same ts stream playing in Kodi 21.2 with ISFFMpegDirect 21.3.8
No info messages from start to finish, nothing snipped

2025-06-28 09:25:08.354 T:6316     info <general>: Creating InputStream
2025-06-28 09:25:08.356 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: inputstream.ffmpegdirect: OpenStream() - Num Props: 1
2025-06-28 09:25:08.356 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: inputstream.ffmpegdirect property: inputstream.ffmpegdirect.is_realtime_stream = true
2025-06-28 09:25:08.357 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: Stream mimetype: video/mp2t
2025-06-28 09:25:10.020 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpegdirect::FFmpegStream::OpenWithCURL - IO handled by Kodi's cURL
2025-06-28 09:25:10.021 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[720BB1F1]: Input #0, mpegts, from 'http://m3u.sstv.one:80/live/xxxxx/xxxxxxxx/33130.ts':
2025-06-28 09:25:10.021 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[720BB1F1]:   Duration: N/A, bitrate: N/A
2025-06-28 09:25:10.021 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[720BB1F1]:   Program 1 
2025-06-28 09:25:10.021 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[720BB1F1]:     Metadata:
2025-06-28 09:25:10.021 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[720BB1F1]:       service_name    : Service01
2025-06-28 09:25:10.021 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[720BB1F1]:       service_provider: FFmpeg
2025-06-28 09:25:10.021 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[720BB1F1]:   Stream #0:0[0x100]: Video: h264 ([27][0][0][0] / 0x001B), none, 90k tbn
2025-06-28 09:25:10.021 T:6316     info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[720BB1F1]:   Stream #0:1[0x101]: Audio: aac ([15][0][0][0] / 0x000F), 0 channels
2025-06-28 09:25:10.021 T:6316     info <general>: Creating Demuxer
2025-06-28 09:25:10.022 T:6316     info <general>: Opening stream: 0 source: 256
2025-06-28 09:25:10.022 T:6316     info <general>: Creating video codec with codec id: 27
2025-06-28 09:25:10.022 T:6316     info <general>: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2025-06-28 09:25:10.022 T:6316     info <general>: Creating video thread
2025-06-28 09:25:10.022 T:7652     info <general>: running thread: video_thread
2025-06-28 09:25:10.022 T:6316     info <general>: Opening stream: 1 source: 256
2025-06-28 09:25:10.022 T:6316     info <general>: Finding audio codec for: 86018
2025-06-28 09:25:10.023 T:6316     info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2025-06-28 09:25:10.023 T:6316     info <general>: CVideoPlayerAudio::OpenStream: Allowing max Out-Of-Sync Value of 50 ms
2025-06-28 09:25:10.023 T:6316     info <general>: Creating audio thread
2025-06-28 09:25:10.023 T:9664     info <general>: running thread: CVideoPlayerAudio::Process()
2025-06-28 09:25:10.914 T:6316     info <general>: Opening stream: 0 source: 256
2025-06-28 09:25:10.914 T:6316     info <general>: Creating video codec with codec id: 27
2025-06-28 09:25:10.914 T:6316     info <general>: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2025-06-28 09:25:10.914 T:6316     info <general>: Opening stream: 1 source: 256
2025-06-28 09:25:10.915 T:7652     info <general>: DXVA::CContext::CreateContext: creating discrete d3d11va device for decoding.
2025-06-28 09:25:10.952 T:7652     info <general>: DXVA::CContext::CreateContext: device for decoding created on adapter 'NVIDIA GeForce RTX 3060' with D3D_FEATURE_LEVEL_12_1
2025-06-28 09:25:10.953 T:7652     info <general>: DXVA::CDecoder::Open: Total video memory available is 28468 MB (dedicated = 12115 MB, shared = 16353 MB)
2025-06-28 09:25:10.973 T:7652     info <general>: DXVA::CVideoBufferShared::InitializeFence: fence synchronization activated.
2025-06-28 09:25:10.976 T:4728     info <general>: CRendererDXVA::Configure: chosen conversion: NV12 / YCBCR_STUDIO_G22_LEFT_P709 to R10G10B10A2_UNORM / RGB_FULL_G22_NONE_P709
2025-06-28 09:25:10.976 T:4728     info <general>: DXVA::CEnumeratorHD::ProbeProcessorCaps: supported deinterlace methods: blend:yes, bob:yes, adaptive:yes, mocomp:no.
2025-06-28 09:25:10.977 T:4728  warning <general>: CRendererHQ::CheckVideoParameters: chosen scaling method 1 is not supported by renderer
2025-06-28 09:25:11.305 T:9664     info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2025-06-28 09:25:11.305 T:9664     info <general>: Skipped 1 duplicate messages..
2025-06-28 09:25:11.305 T:9664     info <general>: Creating audio stream (codec id: 86018, channels: 2, sample rate: 48000, no pass-through)
2025-06-28 09:25:11.343 T:1188     info <general>: CActiveAESink::OpenSink - initialize sink
2025-06-28 09:25:11.607 T:7652     info <general>: DXVA::CVideoBufferShared::InitializeFence: fence synchronization activated.
2025-06-28 09:25:11.610 T:4728     info <general>: Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY
2025-06-28 09:25:11.610 T:7652     info <general>: DXVA::CVideoBufferShared::InitializeFence: fence synchronization activated.
2025-06-28 09:25:11.694 T:7652     info <general>: Skipped 4 duplicate messages..
2025-06-28 09:25:11.694 T:7652     info <general>: CDVDVideoCodecFFmpeg::CDropControl: calculated diff time: 16636
2025-06-28 09:25:14.678 T:4728     info <general>: CRendererDXVA::Configure: chosen conversion: NV12 / YCBCR_STUDIO_G22_LEFT_P709 to R10G10B10A2_UNORM / RGB_FULL_G22_NONE_P709
2025-06-28 09:25:14.678 T:4728     info <general>: DXVA::CEnumeratorHD::ProbeProcessorCaps: supported deinterlace methods: blend:yes, bob:yes, adaptive:yes, mocomp:no.
2025-06-28 09:25:14.680 T:4728  warning <general>: CRendererHQ::CheckVideoParameters: chosen scaling method 1 is not supported by renderer
2025-06-28 09:25:15.933 T:2088  warning <general>: ActiveAE - large audio sync error: -89437.494100
2025-06-28 09:25:15.953 T:2088  warning <general>: ActiveAE - large audio sync error: -89438.389767
2025-06-28 09:25:19.282 T:4728     info <general>: Loading skin file: VideoOSD.xml, load type: KEEP_IN_MEMORY
2025-06-28 09:25:24.569 T:4728     info <general>: Loading skin file: DialogFullScreenInfo.xml, load type: KEEP_IN_MEMORY
2025-06-28 09:29:50.006 T:4728     info <general>: CVideoPlayer::CloseFile()
2025-06-28 09:29:50.006 T:4728     info <general>: VideoPlayer: waiting for threads to exit
2025-06-28 09:29:50.010 T:6316     info <general>: CVideoPlayer::OnExit()
2025-06-28 09:29:50.010 T:6316     info <general>: Closing stream player 1
2025-06-28 09:29:50.010 T:6316     info <general>: Waiting for audio thread to exit
2025-06-28 09:29:50.021 T:9664     info <general>: thread end: CVideoPlayerAudio::OnExit()
2025-06-28 09:29:50.021 T:6316     info <general>: Closing audio device
2025-06-28 09:29:50.042 T:1188     info <general>: CActiveAESink::OpenSink - initialize sink
2025-06-28 09:29:50.042 T:6316     info <general>: Deleting audio codec
2025-06-28 09:29:50.043 T:6316     info <general>: Closing stream player 2
2025-06-28 09:29:50.043 T:6316     info <general>: waiting for video thread to exit
2025-06-28 09:29:50.092 T:7652  warning <general>: CVideoPlayerVideo::OutputPicture - timeout waiting for buffer
2025-06-28 09:29:50.092 T:7652     info <general>: thread end: video_thread
2025-06-28 09:29:50.093 T:6316     info <general>: deleting video codec
2025-06-28 09:29:50.094 T:6316     info <general>: DXVA::CDecoder::Close: closing decoder.
2025-06-28 09:29:50.094 T:6316     info <general>: DXVA: closing decoder context.
2025-06-28 09:29:50.122 T:6316     info <general>: ADDON: Dll Destroyed - Inputstream FFmpeg Direct
2025-06-28 09:29:50.122 T:4728     info <general>: VideoPlayer: finished waiting
2025-06-28 09:29:50.122 T:4728     info <general>: CVideoPlayer::CloseFile()
2025-06-28 09:29:50.122 T:4728     info <general>: VideoPlayer: waiting for threads to exit
2025-06-28 09:29:50.122 T:4728     info <general>: VideoPlayer: finished waiting

[phunkyfish]

Ffmpeg 7 is used in v22, maybe that’s it. But disabling the log should work anyway, maybe that behaviour changes in ffmpeg7

[phunkyfish]

Ok, I've updated to only set ffmpeg logging component if it's enabled. Once the PR has updated I'll link the new testbuilds to try.

[Gujal00]

I compiled it myself on ubuntu 24.04.2 LTS with PR#333 and seems to have made no difference to the amount of log entries. Will wait for your windows testbuild to see if it is any different

[phunkyfish]

Strange, you’d think we we didn’t tell ffmpeg the logging function to use it wouldn’t be able to log anything.

Must be something that changes in ffmpeg 7

[phunkyfish]

Hold on, I’m wondering if it’s kodi that is logging this and not the addon.

Looking closer at the log you can see that’s the case. Ffmpeg logs via ffmpegdirect print the addon name. The offending log statements don’t do that.

[Gujal00]

That is weird though. Here are the logs for the same ts stream playing on Kodi 22, first time without ffmpegdirect and then with ffmpegdirect. The info log spam only happens when ffmpegdirect is used

2025-07-03 08:18:26.475 T:12540    info <general>: VideoPlayer::OpenFile: http://m3u.sstv.one:80/live/xxxxx/xxxxxxxxxx/31754.ts
2025-07-03 08:18:26.475 T:13180    info <general>: Creating InputStream
2025-07-03 08:18:31.818 T:13180    info <general>: Creating Demuxer
2025-07-03 08:18:32.861 T:13180    info <general>: Opening stream: 0 source: 256
2025-07-03 08:18:32.861 T:13180    info <general>: Creating video codec with codec id: 27
2025-07-03 08:18:32.861 T:13180    info <general>: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2025-07-03 08:18:32.861 T:13180    info <general>: Creating video thread
2025-07-03 08:18:32.862 T:8652     info <general>: running thread: video_thread
2025-07-03 08:18:32.862 T:13180    info <general>: Opening stream: 1 source: 256
2025-07-03 08:18:32.862 T:13180    info <general>: Finding audio codec for: 86018
2025-07-03 08:18:32.862 T:13180    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2025-07-03 08:18:32.862 T:13180    info <general>: void __cdecl CVideoPlayerAudio::OpenStream(class CDVDStreamInfo &,class std::unique_ptr<class CDVDAudioCodec,struct std::default_delete<class CDVDAudioCodec> >): Allowing max Out-Of-Sync Value of 50 ms
2025-07-03 08:18:32.862 T:13180    info <general>: Creating audio thread
2025-07-03 08:18:32.862 T:9672     info <general>: running thread: CVideoPlayerAudio::Process()
2025-07-03 08:18:33.066 T:13180    info <general>: CDVDDemuxFFmpeg::Read() stream change
2025-07-03 08:18:33.066 T:13180    info <general>: Opening stream: 0 source: 256
2025-07-03 08:18:33.066 T:13180    info <general>: Creating video codec with codec id: 27
2025-07-03 08:18:33.066 T:13180    info <general>: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2025-07-03 08:18:33.066 T:13180    info <general>: Opening stream: 1 source: 256
2025-07-03 08:18:33.066 T:13180    info <general>: Finding audio codec for: 86018
2025-07-03 08:18:33.067 T:13180    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2025-07-03 08:18:33.067 T:8652     info <general>: bool __cdecl DXVA::CContext::CreateContext(void): creating discrete d3d11va device for decoding.
2025-07-03 08:18:33.069 T:9672     info <general>: void __cdecl CVideoPlayerAudio::OpenStream(class CDVDStreamInfo &,class std::unique_ptr<class CDVDAudioCodec,struct std::default_delete<class CDVDAudioCodec> >): Allowing max Out-Of-Sync Value of 50 ms
2025-07-03 08:18:33.069 T:9672     info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2025-07-03 08:18:33.069 T:9672     info <general>: Creating audio stream (codec id: 86018, channels: 2, sample rate: 48000, no pass-through)
2025-07-03 08:18:33.108 T:11816    info <general>: CActiveAESink::OpenSink - initialize sink
2025-07-03 08:18:33.113 T:8652     info <general>: bool __cdecl DXVA::CContext::CreateContext(void): device for decoding created on adapter 'NVIDIA GeForce RTX 3060' with D3D_FEATURE_LEVEL_12_1
2025-07-03 08:18:33.113 T:8652     info <general>: bool __cdecl DXVA::CDecoder::Open(struct AVCodecContext *,struct AVCodecContext *,const enum AVPixelFormat): Total video memory available is 28468 MB (dedicated = 12115 MB, shared = 16353 MB)
2025-07-03 08:18:33.134 T:8652     info <general>: void __cdecl DXVA::CVideoBufferShared::InitializeFence(class DXVA::CDecoder *): fence synchronization activated.
2025-07-03 08:18:33.146 T:12540    info <general>: bool __cdecl CRendererDXVA::Configure(const struct VideoPicture &,float,unsigned int): chosen conversion: NV12 / YCBCR_STUDIO_G22_LEFT_P709 to R10G10B10A2_UNORM / RGB_FULL_G22_NONE_P709
2025-07-03 08:18:33.146 T:12540    info <general>: struct DXVA::ProcessorCapabilities __cdecl DXVA::CEnumeratorHD::ProbeProcessorCaps(void): supported deinterlace methods: blend:yes, bob:yes, adaptive:yes, mocomp:no.
2025-07-03 08:18:33.146 T:12540 warning <general>: void __cdecl CRendererHQ::CheckVideoParameters(void): chosen scaling method 1 is not supported by renderer
2025-07-03 08:18:33.482 T:8652     info <general>: void __cdecl DXVA::CVideoBufferShared::InitializeFence(class DXVA::CDecoder *): fence synchronization activated.
2025-07-03 08:18:33.613 T:8652     info <general>: Skipped 5 duplicate messages..
2025-07-03 08:18:33.613 T:8652     info <general>: CDVDVideoCodecFFmpeg::CDropControl: calculated diff time: 16636
2025-07-03 08:18:36.547 T:12540    info <general>: bool __cdecl CRendererDXVA::Configure(const struct VideoPicture &,float,unsigned int): chosen conversion: NV12 / YCBCR_STUDIO_G22_LEFT_P709 to R10G10B10A2_UNORM / RGB_FULL_G22_NONE_P709
2025-07-03 08:18:36.547 T:12540    info <general>: struct DXVA::ProcessorCapabilities __cdecl DXVA::CEnumeratorHD::ProbeProcessorCaps(void): supported deinterlace methods: blend:yes, bob:yes, adaptive:yes, mocomp:no.
2025-07-03 08:18:36.549 T:12540 warning <general>: void __cdecl CRendererHQ::CheckVideoParameters(void): chosen scaling method 1 is not supported by renderer
2025-07-03 08:20:24.036 T:12540    info <general>: CVideoPlayer::CloseFile()
2025-07-03 08:20:24.037 T:12540    info <general>: VideoPlayer: waiting for threads to exit
2025-07-03 08:20:24.046 T:13180    info <general>: CVideoPlayer::OnExit()
2025-07-03 08:20:24.046 T:13180    info <general>: Closing stream player 1
2025-07-03 08:20:24.046 T:13180    info <general>: Waiting for audio thread to exit
2025-07-03 08:20:24.065 T:9672     info <general>: thread end: CVideoPlayerAudio::OnExit()
2025-07-03 08:20:24.065 T:13180    info <general>: Closing audio device
2025-07-03 08:20:24.086 T:11816    info <general>: CActiveAESink::OpenSink - initialize sink
2025-07-03 08:20:24.086 T:13180    info <general>: Deleting audio codec
2025-07-03 08:20:24.086 T:13180    info <general>: Closing stream player 2
2025-07-03 08:20:24.086 T:13180    info <general>: waiting for video thread to exit
2025-07-03 08:20:24.123 T:8652  warning <general>: CVideoPlayerVideo::OutputPicture - timeout waiting for buffer
2025-07-03 08:20:24.123 T:8652     info <general>: thread end: video_thread
2025-07-03 08:20:24.123 T:13180    info <general>: deleting video codec
2025-07-03 08:20:24.124 T:13180    info <general>: void __cdecl DXVA::CDecoder::Close(void): closing decoder.
2025-07-03 08:20:24.124 T:13180    info <general>: DXVA: closing decoder context.
2025-07-03 08:20:26.844 T:12540    info <general>: VideoPlayer: finished waiting
2025-07-03 08:20:26.844 T:12540    info <general>: CVideoPlayer::CloseFile()
2025-07-03 08:20:26.844 T:12540    info <general>: VideoPlayer: waiting for threads to exit
2025-07-03 08:20:26.844 T:12540    info <general>: VideoPlayer: finished waiting


2025-07-03 08:20:46.209 T:12540    info <general>: VideoPlayer::OpenFile: http://m3u.sstv.one:80/live/xxxxx/xxxxxxxxxx/31754.ts
2025-07-03 08:20:46.209 T:12064    info <general>: Creating InputStream
2025-07-03 08:20:46.215 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: inputstream.ffmpegdirect: OpenStream() - Num Props: 1
2025-07-03 08:20:46.215 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: inputstream.ffmpegdirect property: inputstream.ffmpegdirect.is_realtime_stream = true
2025-07-03 08:20:46.215 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: Stream mimetype: video/mp2t
2025-07-03 08:20:46.217 T:12064 warning <general>: Interface_Filesystem::ADDON::Interface_Filesystem::TranslateFileReadBitsToKodi - detected use of deprecated 'ADDON_READ_CHUNKED' flag
2025-07-03 08:20:51.513 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpegdirect::FFmpegStream::OpenWithCURL - IO handled by Kodi's cURL
2025-07-03 08:20:51.522 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[F07EC070]: Input #0, mpegts, from 'http://m3u.sstv.one:80/live/xxxxx/xxxxxxxxxx/31754.ts':
2025-07-03 08:20:51.522 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[F07EC070]:   Duration: N/A, bitrate: N/A
2025-07-03 08:20:51.522 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[F07EC070]:   Program 1 
2025-07-03 08:20:51.522 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[F07EC070]:     Metadata:
2025-07-03 08:20:51.522 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[F07EC070]:       service_name    : Service01
2025-07-03 08:20:51.522 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[F07EC070]:       service_provider: FFmpeg
2025-07-03 08:20:51.522 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[F07EC070]:   Stream #0:0[0x100]: Video: h264 ([27][0][0][0] / 0x001B), none, 90k tbn
2025-07-03 08:20:51.522 T:12064    info <general>: AddOnLog: inputstream.ffmpegdirect: ffmpeg[F07EC070]:   Stream #0:1[0x101]: Audio: aac ([15][0][0][0] / 0x000F), 0 channels
2025-07-03 08:20:51.524 T:12064    info <general>: Creating Demuxer
2025-07-03 08:20:51.524 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:51.524 T:12064    info <general>: Creating video codec with codec id: 27
2025-07-03 08:20:51.524 T:12064    info <general>: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2025-07-03 08:20:51.524 T:12064    info <general>: Creating video thread
2025-07-03 08:20:51.524 T:12044    info <general>: running thread: video_thread
2025-07-03 08:20:51.524 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:51.524 T:12064    info <general>: Finding audio codec for: 86018
2025-07-03 08:20:51.525 T:12064    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2025-07-03 08:20:51.525 T:12064    info <general>: void __cdecl CVideoPlayerAudio::OpenStream(class CDVDStreamInfo &,class std::unique_ptr<class CDVDAudioCodec,struct std::default_delete<class CDVDAudioCodec> >): Allowing max Out-Of-Sync Value of 50 ms
2025-07-03 08:20:51.525 T:12064    info <general>: Creating audio thread
2025-07-03 08:20:51.525 T:12336    info <general>: running thread: CVideoPlayerAudio::Process()
2025-07-03 08:20:52.135 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.135 T:12064    info <general>: Creating video codec with codec id: 27
2025-07-03 08:20:52.135 T:12064    info <general>: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2025-07-03 08:20:52.136 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.136 T:12044    info <general>: bool __cdecl DXVA::CContext::CreateContext(void): creating discrete d3d11va device for decoding.
2025-07-03 08:20:52.169 T:12044    info <general>: bool __cdecl DXVA::CContext::CreateContext(void): device for decoding created on adapter 'NVIDIA GeForce RTX 3060' with D3D_FEATURE_LEVEL_12_1
2025-07-03 08:20:52.169 T:12044    info <general>: bool __cdecl DXVA::CDecoder::Open(struct AVCodecContext *,struct AVCodecContext *,const enum AVPixelFormat): Total video memory available is 28468 MB (dedicated = 12115 MB, shared = 16353 MB)
2025-07-03 08:20:52.200 T:12044    info <general>: void __cdecl DXVA::CVideoBufferShared::InitializeFence(class DXVA::CDecoder *): fence synchronization activated.
2025-07-03 08:20:52.211 T:12540    info <general>: bool __cdecl CRendererDXVA::Configure(const struct VideoPicture &,float,unsigned int): chosen conversion: NV12 / YCBCR_STUDIO_G22_LEFT_P709 to R10G10B10A2_UNORM / RGB_FULL_G22_NONE_P709
2025-07-03 08:20:52.211 T:12540    info <general>: struct DXVA::ProcessorCapabilities __cdecl DXVA::CEnumeratorHD::ProbeProcessorCaps(void): supported deinterlace methods: blend:yes, bob:yes, adaptive:yes, mocomp:no.
2025-07-03 08:20:52.212 T:12540 warning <general>: void __cdecl CRendererHQ::CheckVideoParameters(void): chosen scaling method 1 is not supported by renderer
2025-07-03 08:20:52.346 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.346 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.346 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.346 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.347 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.349 T:12336    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2025-07-03 08:20:52.349 T:12336    info <general>: Skipped 1 duplicate messages..
2025-07-03 08:20:52.349 T:12336    info <general>: Creating audio stream (codec id: 86018, channels: 2, sample rate: 48000, no pass-through)
2025-07-03 08:20:52.377 T:11816    info <general>: CActiveAESink::OpenSink - initialize sink
2025-07-03 08:20:52.547 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.547 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.547 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.547 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.547 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.547 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.547 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.548 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.548 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.548 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.548 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.548 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.548 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.548 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.548 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.548 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.548 T:12044    info <general>: void __cdecl DXVA::CVideoBufferShared::InitializeFence(class DXVA::CDecoder *): fence synchronization activated.
2025-07-03 08:20:52.550 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.550 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.551 T:12044    info <general>: void __cdecl DXVA::CVideoBufferShared::InitializeFence(class DXVA::CDecoder *): fence synchronization activated.
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.551 T:12044    info <general>: void __cdecl DXVA::CVideoBufferShared::InitializeFence(class DXVA::CDecoder *): fence synchronization activated.
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.551 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:52.552 T:12044    info <general>: void __cdecl DXVA::CVideoBufferShared::InitializeFence(class DXVA::CDecoder *): fence synchronization activated.
2025-07-03 08:20:52.645 T:12044    info <general>: Skipped 2 duplicate messages..
2025-07-03 08:20:52.645 T:12044    info <general>: CDVDVideoCodecFFmpeg::CDropControl: calculated diff time: 16636
2025-07-03 08:20:52.756 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:52.756 T:12064    info <general>: Opening stream: 1 source: 256

<<< SNIP 600 Lines >>>

2025-07-03 08:20:55.468 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:55.468 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:20:55.595 T:12540    info <general>: bool __cdecl CRendererDXVA::Configure(const struct VideoPicture &,float,unsigned int): chosen conversion: NV12 / YCBCR_STUDIO_G22_LEFT_P709 to R10G10B10A2_UNORM / RGB_FULL_G22_NONE_P709
2025-07-03 08:20:55.596 T:12540    info <general>: struct DXVA::ProcessorCapabilities __cdecl DXVA::CEnumeratorHD::ProbeProcessorCaps(void): supported deinterlace methods: blend:yes, bob:yes, adaptive:yes, mocomp:no.
2025-07-03 08:20:55.596 T:12540 warning <general>: void __cdecl CRendererHQ::CheckVideoParameters(void): chosen scaling method 1 is not supported by renderer
2025-07-03 08:20:55.656 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:20:55.656 T:12064    info <general>: Opening stream: 1 source: 256

<<< SNIP 300 Lines>>>

2025-07-03 08:21:04.457 T:12064    info <general>: Opening stream: 0 source: 256
2025-07-03 08:21:04.457 T:12064    info <general>: Opening stream: 1 source: 256
2025-07-03 08:21:04.487 T:12540    info <general>: CVideoPlayer::CloseFile()
2025-07-03 08:21:04.487 T:12540    info <general>: VideoPlayer: waiting for threads to exit
2025-07-03 08:21:04.488 T:12064    info <general>: CVideoPlayer::OnExit()
2025-07-03 08:21:04.488 T:12064    info <general>: Closing stream player 1
2025-07-03 08:21:04.488 T:12064    info <general>: Waiting for audio thread to exit
2025-07-03 08:21:04.505 T:12336    info <general>: thread end: CVideoPlayerAudio::OnExit()
2025-07-03 08:21:04.505 T:12064    info <general>: Closing audio device
2025-07-03 08:21:04.526 T:12064    info <general>: Deleting audio codec
2025-07-03 08:21:04.526 T:11816    info <general>: CActiveAESink::OpenSink - initialize sink
2025-07-03 08:21:04.526 T:12064    info <general>: Closing stream player 2
2025-07-03 08:21:04.526 T:12064    info <general>: waiting for video thread to exit
2025-07-03 08:21:04.570 T:12044 warning <general>: CVideoPlayerVideo::OutputPicture - timeout waiting for buffer
2025-07-03 08:21:04.570 T:12044    info <general>: thread end: video_thread
2025-07-03 08:21:04.571 T:12064    info <general>: deleting video codec
2025-07-03 08:21:04.571 T:12064    info <general>: void __cdecl DXVA::CDecoder::Close(void): closing decoder.
2025-07-03 08:21:04.571 T:12064    info <general>: DXVA: closing decoder context.
2025-07-03 08:21:04.600 T:12064    info <general>: ADDON: Dll Destroyed - Inputstream FFmpeg Direct
2025-07-03 08:21:04.601 T:12540    info <general>: VideoPlayer: finished waiting
2025-07-03 08:21:04.601 T:12540    info <general>: CVideoPlayer::CloseFile()
2025-07-03 08:21:04.601 T:12540    info <general>: VideoPlayer: waiting for threads to exit
2025-07-03 08:21:04.601 T:12540    info <general>: VideoPlayer: finished waiting