[mythtv-users] very many errors following a commercial flagging

Eyal Lebedinsky eyal at eyal.emu.id.au
Tue Sep 20 10:20:15 UTC 2022


This is on up-to-date f36.

I recently noticed that I get huge mythcommflag logs at times. I archive these so I checked back
and I can see that this started when mythbackend changed in 2019-07-15 from
	mythcommflag version: fixes/29 [v29.1-v29.1-36-gdde16d475a] www.mythtv.org
to
	mythcommflag version: fixes/30 [v30.0-v30.0-53-g6bd8cd4993] www.mythtv.org
and this is still happening.

It is by accident that I noticed the problem when archiving logs and wondering why they differ
so much in size, here are the logs of one recent day:

      8514  09-16-2022 01:41   mythcommflag.20220915142648.3928671.log
  30980901  09-16-2022 05:38   mythcommflag.20220915191854.413609.log
      8699  09-16-2022 05:36   mythcommflag.20220915192259.416517.log
      8698  09-16-2022 07:34   mythcommflag.20220915205604.451699.log
  31718559  09-16-2022 12:00   mythcommflag.20220916012610.568727.log
  32057355  09-16-2022 12:00   mythcommflag.20220916013215.572183.log
      4769  09-16-2022 12:00   mythcommflag.20220916020020.585123.log
  31217919  09-16-2022 17:35   mythcommflag.20220916065626.714662.log
      8700  09-16-2022 17:35   mythcommflag.20220916070231.720047.log
      8392  09-16-2022 18:04   mythcommflag.20220916072536.728798.log
     19879  09-16-2022 19:40   mythcommflag.20220916083002.763603.log
  30842026  09-16-2022 20:06   mythcommflag.20220916092707.788562.log
      7971  09-16-2022 19:44   mythcommflag.20220916093312.792514.log
      8697  09-16-2022 21:59   mythcommflag.20220916105818.834161.log
      8392  09-16-2022 22:20   mythcommflag.20220916113423.853572.log
     29126  09-16-2022 22:51   mythcommflag.20220916120628.870365.log

Here is the log of a typical small case.

2022-09-20 18:42:21.425692 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 0%% Completed @ 877.193 fps.
2022-09-20 18:42:38.604020 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 10%% Completed @ 526.224 fps.
2022-09-20 18:42:55.755361 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 20%% Completed @ 528.394 fps.
2022-09-20 18:48:11.804726 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 30%% Completed @ 77.605 fps.
2022-09-20 18:54:16.131881 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 40%% Completed @ 50.7822 fps.
2022-09-20 19:00:19.798849 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 50%% Completed @ 42.096 fps.
2022-09-20 19:06:20.835929 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 60%% Completed @ 37.7903 fps.
2022-09-20 19:12:24.337669 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 70%% Completed @ 35.2186 fps.
2022-09-20 19:18:24.700522 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 80%% Completed @ 33.5123 fps.
2022-09-20 19:24:28.523867 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 90%% Completed @ 32.2886 fps.
2022-09-20 19:30:32.806448 I [2945779/2945779] CoreContext ClassicCommDetector.cpp:542 (go) - 100%% Completed @ 31.3679 fps.
2022-09-20 19:35:25.417574 E [2945779/2950411] Decoder decoders/avformatdecoder.cpp:4964 (GetFrame) - decoding error End of file (-541478725)
2022-09-20 19:35:26.516100 N [2945779/2945779] CoreContext main.cpp:955 (FlagCommercials) - Finished, 3 break(s) found.
2022-09-20 19:35:26.553358 I [2945779/2945779] CoreContext platforms/mythpowerdbus.cpp:72 (~MythPowerDBus) - PowerDBus: Closing interfaces
2022-09-20 19:35:26.554205 I [2945779/2945779] CoreContext mythcontext.cpp:1667 (~MythContext) - Waiting for threads to exit.
2022-09-20 19:35:27.952436 I [2945779/2945779] CoreContext mythcontext.cpp:1673 (~MythContext) - Exiting

Here is the log of a typical large case.

At first I see the commercial flagging running while the recording happens (23:50:55-00:25:32).
Then, following the recording ending I get a burst (221,918 lines) of messages (00:30:05-00:30:07, 2 seconds).
Here is an excerpt from the log:

2022-09-19 23:50:55.148850 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:365 (go) - Finding Logo
2022-09-19 23:51:07.898927 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 0%% Completed @ 1250 fps.
2022-09-19 23:51:10.838582 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 10%% Completed @ 2517.39 fps.
2022-09-19 23:51:13.724756 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 20%% Completed @ 2558.02 fps.
2022-09-19 23:51:16.797471 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 30%% Completed @ 2517.26 fps.
2022-09-19 23:55:32.964330 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 40%% Completed @ 113.524 fps.
2022-09-20 00:00:32.941836 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 50%% Completed @ 66.5342 fps.
2022-09-20 00:05:32.948848 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 60%% Completed @ 52.1309 fps.
2022-09-20 00:10:32.963011 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 70%% Completed @ 45.1447 fps.
2022-09-20 00:15:32.954310 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 80%% Completed @ 41.0202 fps.
2022-09-20 00:20:32.951947 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 90%% Completed @ 38.2974 fps.
2022-09-20 00:25:32.959836 I [3326968/3326968] CoreContext ClassicCommDetector.cpp:542 (go) - 100%% Completed @ 36.3656 fps.
2022-09-20 00:30:05.151147 E [3326968/3335951] Decoder decoders/avformatdecoder.cpp:4964 (GetFrame) - decoding error End of file (-541478725)
2022-09-20 00:30:05.151160 E [3326968/3335951] Decoder decoders/avformatdecoder.cpp:4964 (GetFrame) - decoding error End of file (-541478725)
2022-09-20 00:30:05.151169 E [3326968/3335951] Decoder decoders/avformatdecoder.cpp:4964 (GetFrame) - decoding error End of file (-541478725)
2022-09-20 00:30:05.151178 E [3326968/3335951] Decoder decoders/avformatdecoder.cpp:4964 (GetFrame) - decoding error End of file (-541478725)
2022-09-20 00:30:05.151187 E [3326968/3335951] Decoder decoders/avformatdecoder.cpp:4964 (GetFrame) - decoding error End of file (-541478725)
... [trimmed] many repeats of the last error message
2022-09-20 00:30:07.257395 N [3326968/3326968] CoreContext main.cpp:955 (FlagCommercials) - Finished, 3 break(s) found.
2022-09-20 00:30:07.257399 E [3326968/3335951] Decoder decoders/avformatdecoder.cpp:4964 (GetFrame) - decoding error End of file (-541478725)
2022-09-20 00:30:07.257408 E [3326968/3335951] Decoder decoders/avformatdecoder.cpp:4964 (GetFrame) - decoding error End of file (-541478725)
2022-09-20 00:30:07.257440 E [3326968/3335951] Decoder decoders/avformatdecoder.cpp:4964 (GetFrame) - decoding error End of file (-541478725)
2022-09-20 00:30:07.257449 E [3326968/3335951] Decoder decoders/avformatdecoder.cpp:4964 (GetFrame) - decoding error End of file (-541478725)
2022-09-20 00:30:07.266332 I [3326968/3326968] CoreContext platforms/mythpowerdbus.cpp:72 (~MythPowerDBus) - PowerDBus: Closing interfaces
2022-09-20 00:30:07.266524 I [3326968/3326968] CoreContext mythcontext.cpp:1667 (~MythContext) - Waiting for threads to exit.

$ grep -c '2022-09-20 00:30:0.*decoding error End of file' /data1/tmp/mythcommflag.20220919133532.3326968.log
221918

$ dnf list installed 'mythtv*'
Installed Packages
mythtv-backend.x86_64           32.0-1.44.20220625git4cf469cbbf.fc36 @rpmfusion-free-updates
mythtv-base-themes.x86_64       32.0-1.44.20220625git4cf469cbbf.fc36 @rpmfusion-free-updates
mythtv-common.x86_64            32.0-1.44.20220625git4cf469cbbf.fc36 @rpmfusion-free-updates
mythtv-docs.noarch              32.0-1.44.20220625git4cf469cbbf.fc36 @rpmfusion-free-updates
mythtv-frontend.x86_64          32.0-1.44.20220625git4cf469cbbf.fc36 @rpmfusion-free-updates
mythtv-libs.x86_64              32.0-1.44.20220625git4cf469cbbf.fc36 @rpmfusion-free-updates
mythtv-setup.x86_64             32.0-1.44.20220625git4cf469cbbf.fc36 @rpmfusion-free-updates
mythtv-status.noarch            1.0.1-8.fc36                         @rpmfusion-free

-- 
Eyal Lebedinsky (eyal at eyal.emu.id.au)


More information about the mythtv-users mailing list