[mythtv-users] very many errors following a commercial flagging
Klaas de Waal
klaas.de.waal at gmail.com
Tue Sep 20 16:45:36 UTC 2022
I've seen these repeated "decoding error End of file" messages also with
other use cases (live TV and recordings) so it is not specific for
mythcommflag.
I had not realized that this bug was already that old, but having a "good"
and a "bad" date does make bisecting possible.
Klaas.
On Tue, 20 Sept 2022 at 12:21, Eyal Lebedinsky <eyal at eyal.emu.id.au> wrote:
> 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)
> _______________________________________________
> mythtv-users mailing list
> mythtv-users at mythtv.org
> http://lists.mythtv.org/mailman/listinfo/mythtv-users
> http://wiki.mythtv.org/Mailing_List_etiquette
> MythTV Forums: https://forum.mythtv.org
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mythtv.org/pipermail/mythtv-users/attachments/20220920/f133c2b6/attachment.htm>
More information about the mythtv-users
mailing list