[KlotX]

I finally got a hang with only VideoPlayer debug enable.

the

Code:

ERROR: CMMALVideo::dec_control_port_cb Error (status=3 EINVAL)

error line is there, but there isn't much more that I can understand from the rest.

I've stripped down a bit the log, because this was originally 170MB of log, so I only left the last part starting from the last played channel, and until the last log line that was recorded in the file.

I hope this is useful, if not please let me know what else I can do.

Debug log file

[Karellen]

Hi KlotX

That is a huuuge file... 170MB. Your Kodi must have been running for quite a while to create one that big.

I can't see your log. Most of us don't like downloading unknown files, which is why we ask that you use pastebin, where we can just click on a link and almost instantly start reading the log.

The cutting it down is also an issue. Especially as you state that you have removed all upto the error. This means we can't see vital info at the startup.

Ways to reduce the log size...
1. Disable automatic Library Updates
2. Seems like your issue is difficult to replicate, which means you are creating large files while waiting for the error. Maybe just keep restarting it every so often to clear out the log a bit.

[KlotX]

Hi Karellen,

Yes, I have debug on until kodi crashes, and 170MB is not that much honestly, once the log file had 1.1GB as it has been running for days and when I realised it I restarted kodi. I restart it once in a while, but it's very easy to get to these file sizes as VideoPlayer debug is very verbose.

I can provide the full log file, but I'm not sure how usefull it is, the one I provided already has 17MB (contains about 8 minutes of kodi usage) so pastebin can't take it.

This was the first time I got this error with VideoPlayer debug enabled, I've been trying for months to reproduce it, I really hope this is helpful as it is.

If more info from the log file is required, I can surely paste it.

[KlotX]

Did anyone had a look at the log? Anything that standsout ?

It would be good to know if it is useful or not and if there is anything I can do to get more info.

[tgiesela]

Hi guys,

I have the same issuer as KlotX. The difference is that I have another configuration:

    Raspberry Pi 4 (4GB)
    Kodi Leia 18.4
    Audio Video Receiver connected via HDMI
    TVHeadend backend

The problem occurs when playing a tv-stream from tvheadend using the tvheadend plugin. It is exactly as KlotX mentions. After the appearence of the following message in the kodi.log:

ERROR: CMMALVideo::dec_control_port_cb Error (status=3 EINVAL)

the stream keeps playing. You do not notice that there is a problem. But when you want to switch channels or stop the playback all you get is a blank screen.
So it looks like there is an error in the way the error (status=2 EINVAL) is handled by the software.
In my case it only occurs when playing an video stream with AC3 audio enabled. If I switch to MP2 the problem does not occur, but the I have no multi-channel audio anymore.

I do have a log with debugging information, but is approx 45 MB in size. In the previous posts there seems to be an issue with the size of the log file. So please let me know what you want me to do with it.

The logfile contains the following info at the point the stream is stopped:

2019-09-24 15:13:30.427 T:3011279328   DEBUG: HandleKey: stop (0xf0bc) pressed, action is Stop
2019-09-24 15:13:30.427 T:3011279328  NOTICE: CVideoPlayer::CloseFile()
2019-09-24 15:13:30.427 T:3011279328   DEBUG: DeleteRenderer - deleting renderer
2019-09-24 15:13:30.427 T:3011279328   DEBUG: CMMALRenderer::~CMMALRenderer
2019-09-24 15:13:30.428 T:3011279328   DEBUG: CMMALRenderer:estroyDeinterlace
2019-09-24 15:13:30.432 T:3011279328   DEBUG: CMMALRenderer::UnInitMMAL
2019-09-24 15:13:30.433 T:2718200688   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Dropped packet with unknown stream index 1004
2019-09-24 15:13:30.435 T:2718200688   DEBUG: Previous line repeats 1 times.
2019-09-24 15:13:30.435 T:2718200688   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Dropped packet with unknown stream index 1001
2019-09-24 15:13:30.435 T:2718200688   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Dropped packet with unknown stream index 1004
2019-09-24 15:13:30.435 T:2718200688   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Dropped packet with unknown stream index 1001
2019-09-24 15:13:30.436 T:2718200688   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Dropped packet with unknown stream index 1002
2019-09-24 15:13:30.437 T:2519708528   DEBUG: Previous line repeats 5 times.
2019-09-24 15:13:30.437 T:2519708528   DEBUG: CMMALVideo::dec_input_port_cb port:0x9c3b30c0 buffer 0x9f7d27d0, len 0 cmd:0
2019-09-24 15:13:30.437 T:2519708528   DEBUG: CMMALVideo::dec_output_port_cb - omvb:0x9c9d76f8 mmal:0xafd47a70 len:128 dts:-9223372036854.775 pts:932.416 flags:30004:30000 pool:0x9c54d2ec 1920x1080 (1920x1088) 1920x1080 (1920x1088) enc:OPQV
2019-09-24 15:13:30.437 T:2486977392   DEBUG: CMMALVideo::GetPicture - ret(3) pics(0) inputs(1) slept(14) queued(0.16) (932.54:932.42) full(0) flags(0) preroll(0) eos(0 46555/-1)
2019-09-24 15:13:30.437 T:2519708528   DEBUG: CMMALPool::Configure pool:0x9c9c6cc0 1920x1080 (1920x1088) pix:-1 size:128 fmt:OPQV
2019-09-24 15:13:30.447 T:2502923120   DEBUG: CMMALPool::~CMMALPool Destroying pool 0x9b248230 for port vc.ril.image_fx:out:0(I420)
2019-09-24 15:13:30.447 T:2519708528   DEBUG: CMMALVideo::dec_output_port_cb - omvb:0x9c9d78d0 mmal:0x9c763100 len:128 dts:-9223372036854.775 pts:932.456 flags:30004:30000 pool:0x9c54d2ec 1920x1080 (1920x1088) 1920x1080 (1920x1088) enc:OPQV
2019-09-24 15:13:30.447 T:2519708528   DEBUG: CMMALPool::Configure pool:0x9c9c6cc0 1920x1080 (1920x1088) pix:-1 size:128 fmt:OPQV
2019-09-24 15:13:30.461 T:2502923120   DEBUG: CMMALRenderer::Run - stopping
2019-09-24 15:13:30.461 T:2502923120   DEBUG: Thread MMALProcess 2502923120 terminating
2019-09-24 15:13:30.461 T:3011279328  NOTICE: VideoPlayer: waiting for threads to exit
2019-09-24 15:13:30.461 T:2486977392   DEBUG: CMMALVideo::SetCodecControl 0->40000000
2019-09-24 15:13:30.462 T:2486977392   DEBUG: CMMALVideo::AddData - 0x9f7d27d0 1296  /0      dts:932.516 pts:932.556 flags:4 ready_queue(2)
2019-09-24 15:13:30.462 T:2486977392    INFO: CMMALVideo::GetPicture dts:0.000 pts:932.416 flags:0:30004 MMALBuffer:0xafd47a70 mmal_buffer:0x9c9d76f8
2019-09-24 15:13:30.462 T:2486977392   DEBUG: CMMALVideo::GetPicture - ret(4) pics(1) inputs(0) slept( 0) queued(0.10) (932.56:932.46) full(0) flags(40000000) preroll(0) eos(0 46556/-1)
2019-09-24 15:13:30.462 T:2519708528   DEBUG: CMMALVideo::dec_input_port_cb port:0x9c3b30c0 buffer 0x9f7d27d0, len 0 cmd:0
2019-09-24 15:13:30.484 T:2486977392    INFO: CMMALVideo::GetPicture dts:0.000 pts:932.456 flags:0:30004 MMALBuffer:0x9c763100 mmal_buffer:0x9c9d78d0
2019-09-24 15:13:30.484 T:2486977392   DEBUG: CMMALVideo::GetPicture - ret(4) pics(0) inputs(1) slept( 0) queued(0.10) (932.56:932.46) full(0) flags(40000000) preroll(0) eos(0 46556/-1)
2019-09-24 15:13:30.488 T:2416960368  NOTICE: CVideoPlayer::OnExit()
2019-09-24 15:13:30.488 T:2416960368  NOTICE: Closing stream player 1
2019-09-24 15:13:30.489 T:2416960368  NOTICE: Waiting for audio thread to exit
2019-09-24 15:13:30.491 T:2718200688   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Dropped packet with unknown stream index 1001
2019-09-24 15:13:30.491 T:2718200688   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Dropped packet with unknown stream index 1004
2019-09-24 15:13:30.491 T:2718200688   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Dropped packet with unknown stream index 1001
2019-09-24 15:13:30.491 T:2718200688   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Dropped packet with unknown stream index 1004
2019-09-24 15:13:30.492 T:2718200688   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Dropped packet with unknown stream index 1001

So it looks like the stream is still playing (the dropped packet lines)?

I am rather dissapointed because on my Raspberry Pi 3B+ this problem did not occur.

Can someone have a look at the problem?

[Aux_]

Hi everybody,

I have the same issue as @tgiesela
The same Hardware but version Kodi leia_pi4_18.5-Leia

Here is an excerpt from the log before the picture freezes in black screen:

2020-01-30 11:03:34.514 T:2423251824  NOTICE: Finding audio codec for: 86019
2020-01-30 11:03:34.515 T:2423251824  NOTICE: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder ac3
2020-01-30 11:03:34.515 T:2423251824  NOTICE: Opening stream: 1003 source: 256
2020-01-30 11:03:34.515 T:2452611952  NOTICE: running thread: video_thread
2020-01-30 11:03:34.571 T:2461004656  NOTICE: Creating audio stream (codec id: 86019, channels: 2, sample rate: 48000, no pass-through)
2020-01-30 11:03:34.994 T:3011555936  NOTICE: Whitelist search for: width: 1440, height: 1080, fps: 25.000, 3D: false
2020-01-30 11:03:34.995 T:3011555936  NOTICE: Display resolution ADJUST : 1920x1080 @ 60.000000 Hz (27) (weight: 0.051)
2020-01-30 11:03:33.209 T:2452611952 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
2020-01-30 11:59:40.334 T:2378662768 WARNING: Previous line repeats 2 times.
2020-01-30 11:59:40.335 T:2378662768   ERROR: CMMALVideo::dec_control_port_cb Error (status=3 EINVAL)
2020-01-30 13:50:27.341 T:3011555936  NOTICE: CVideoPlayer::CloseFile()
2020-01-30 13:50:27.419 T:2423251824  NOTICE: CVideoPlayer::OnExit()
2020-01-30 13:50:27.419 T:2423251824  NOTICE: Closing stream player 1
2020-01-30 13:50:27.419 T:2423251824  NOTICE: Waiting for audio thread to exit
2020-01-30 13:50:27.422 T:3011555936  NOTICE: VideoPlayer: waiting for threads to exit
2020-01-30 13:50:27.444 T:2461004656  NOTICE: thread end: CVideoPlayerAudio::OnExit()
2020-01-30 13:50:27.444 T:2423251824  NOTICE: Closing audio device
2020-01-30 13:50:27.492 T:2423251824  NOTICE: Deleting audio codec
2020-01-30 13:50:27.492 T:2423251824  NOTICE: Closing stream player 2
2020-01-30 13:50:27.492 T:2423251824  NOTICE: waiting for video thread to exit
2020-01-30 13:50:27.532 T:2452611952  NOTICE: thread end: video_thread
2020-01-30 13:50:27.533 T:2423251824  NOTICE: deleting video codec

I could also try generating a debug log.
But I think it could be very difficult because this phenomenon occurs very rarely, once a day or twice a week ...
Then the log would weigh several MB.