problem with coda when running qt-gstreamer and video reaches its end (resending in plain text)

problem with coda when running qt-gstreamer and video reaches its end (resending in plain text)

[Piotr Lewicki]

[-- Attachment #1: Type: text/plain, Size: 3906 bytes --]


Hello,
I'm running an application that plays video on an embedded device. It 
uses Qt5.4 and qt-gstreamer plugin and it runs on imx6q processor with 
yocto based linux (kernel version 3.19.5).
When I built a sample from this qt-gstreamer package called qmlplayer2 
and used it to play video I came across following problem:

1. When video reaches it's end I start receiving kernel ringbuffer message:
# [ 1371.618854] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1372.618713] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1373.618653] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1374.618872] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1375.618712] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1376.618707] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1377.618860] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1378.738700] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1379.738632] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1380.828872] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1381.828697] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1382.828875] coda 2040000.vpu: CODA PIC_RUN timeout
# [ 1383.938704] coda 2040000.vpu: CODA PIC_RUN timeout

The video is stopped but I can see last frame on the screen although in 
qt application it should receive end-of-stream message and stop the 
video (resulting with black screen).

2. If I don't terminate the application and several times press "stop" 
and "play" video I get message:

# [ 3041.650483] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
# [ 3044.205362] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
# [ 3044.214711] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
# [ 3047.189317] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
# [ 3047.196056] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed

and finally

# [ 3049.161708] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
# "Failed to allocate required memory."

Video is not playing here and CODA PIC_RUN timeout message shows up 
every second.

- Depending on the type of video I'm playing the step 2 differs.
What I wrote above is true for playing matroska format (mkv) file.
When I use h264 I receive:

# [  322.610658] coda 2040000.vpu: Failed to allocate fb2 buffer of size 
537600
# [ 322.619083] coda 2040000.vpu: failed to allocate framebuffers

# [ 327.656542] coda 2040000.vpu: Failed to allocate fb0 buffer of size 
537600
# [ 327.663513] coda 2040000.vpu: failed to allocate framebuffers

Or

# [ 723.496813] coda 2040000.vpu: Failed to allocate workbuf buffer of 
size 606208
# [ 723.504122] coda 2040000.vpu: failed to allocate 0 byte context buffer

# [ 731.524607] coda 2040000.vpu: Failed to allocate slicebuf buffer of 
size 480512
# [ 731.532018] coda 2040000.vpu: failed to allocate 0 byte slice buffer

# [ 734.793931] coda 2040000.vpu: dma_alloc_coherent of size 462848 failed
# [ 734.800771] coda 2040000.vpu: dma_alloc_coherent of size 462848 failed
# "Failed to allocate required memory."

Or

# [ 2793.514984] coda 2040000.vpu: Failed to allocate fb0 buffer of size 
537600
# [ 2793.521961] coda 2040000.vpu: failed to allocate framebuffers
# [ 2793.596919] coda 2040000.vpu: failed to allocate bitstream ringbuffer

3. One more "stop" and "play" outputs with:
# [ 3050.530538] coda 2040000.vpu: failed to allocate bitstream ringbuffer

But here the video starts playing again and when it reaches the end- the 
end-of-stream message is received in the Qt application.

Ocasionally after playing many videos this way and shutting down the 
application I receive kernel oops or probable deadlock warning (both 
attached in this mail).



I'm pretty sure that the problem resides in the coda driver but 
unfortunately I'm newbie in kernel drivers development area and cannot 
resolve it myself.

Have you ever came across similar problem?
Do you think you could help me with that?

Best regards,
Piotr Lewicki



[-- Attachment #2: backtrace --]
[-- Type: text/plain, Size: 7065 bytes --]

[ 1687.508917] ======================================================
[ 1687.515103] [ INFO: possible circular locking dependency detected ]
[ 1687.521379] 3.19.5-iMX6-PD15.2.0 #1 Not tainted
[ 1687.525916] -------------------------------------------------------
[ 1687.532189] kworker/u8:2/74 is trying to acquire lock:
[ 1687.537333]  (&sb->s_type->i_mutex_key){+.+.+.}, at: [<802748c8>] debugfs_remove+0x40/0x80
[ 1687.545691]
[ 1687.545691] but task is already holding lock:
[ 1687.551530]  (&dev->coda_mutex){+.+.+.}, at: [<7f08903c>] coda_seq_end_work+0x38/0xf4 [coda]
[ 1687.560068]
[ 1687.560068] which lock already depends on the new lock.
[ 1687.560068]
[ 1687.568254]
[ 1687.568254] the existing dependency chain (in reverse order) is:
[ 1687.575742]
-> #3 (&dev->coda_mutex){+.+.+.}:
[ 1687.580341]        [<806de3b8>] mutex_lock_nested+0x54/0x3e8
[ 1687.586037]        [<7f08b4cc>] coda_start_decoding+0x28/0x44 [coda]
[ 1687.592426]        [<7f08613c>] coda_start_streaming+0xac/0x20c [coda]
[ 1687.598981]        [<804dd6f4>] vb2_start_streaming+0x78/0x1c8
[ 1687.604840]        [<804dfc00>] vb2_internal_streamon+0xf4/0x150
[ 1687.610871]        [<804dfc90>] vb2_streamon+0x34/0x58
[ 1687.616031]        [<7f0777d4>] v4l2_m2m_streamon+0x28/0x40 [v4l2_mem2mem]
[ 1687.622945]        [<7f077804>] v4l2_m2m_ioctl_streamon+0x18/0x1c [v4l2_mem2mem]
[ 1687.630370]        [<804c81f4>] v4l_streamon+0x20/0x24
[ 1687.635540]        [<804cb200>] __video_do_ioctl+0x280/0x2fc
[ 1687.641225]        [<804cac2c>] video_usercopy+0x168/0x4a0
[ 1687.646733]        [<804caf78>] video_ioctl2+0x14/0x1c
[ 1687.651893]        [<804c6bac>] v4l2_ioctl+0x13c/0x160
[ 1687.657055]        [<80105618>] do_vfs_ioctl+0x410/0x67c
[ 1687.662394]        [<801058c0>] SyS_ioctl+0x3c/0x64
[ 1687.667294]        [<8000ec40>] ret_fast_syscall+0x0/0x4c
[ 1687.672723]
-> #2 (&dev->dev_mutex){+.+.+.}:
[ 1687.677235]        [<806df018>] mutex_lock_interruptible_nested+0x60/0x470
[ 1687.684135]        [<7f077d70>] v4l2_m2m_fop_mmap+0x2c/0x88 [v4l2_mem2mem]
[ 1687.691041]        [<804c6628>] v4l2_mmap+0x5c/0x94
[ 1687.695943]        [<800dc9e0>] mmap_region+0x378/0x6a0
[ 1687.701197]        [<800dd02c>] do_mmap_pgoff+0x324/0x3b4
[ 1687.706618]        [<800c81e0>] vm_mmap_pgoff+0x68/0x98
[ 1687.711867]        [<800db4b4>] SyS_mmap_pgoff+0x9c/0xc4
[ 1687.717201]        [<8000ec40>] ret_fast_syscall+0x0/0x4c
[ 1687.722626]
-> #1 (&mm->mmap_sem){++++++}:
[ 1687.726964]        [<800d482c>] might_fault+0x68/0x9c
[ 1687.732038]        [<80105be4>] filldir64+0x74/0x18c
[ 1687.737026]        [<801530c0>] proc_readfd_common+0x1f4/0x2ac
[ 1687.742892]        [<8015318c>] proc_readfd+0x14/0x1c
[ 1687.747966]        [<80105970>] iterate_dir+0x88/0x108
[ 1687.753126]        [<80105e70>] SyS_getdents64+0x7c/0xf0
[ 1687.758461]        [<8000ec40>] ret_fast_syscall+0x0/0x4c
[ 1687.763884]
-> #0 (&sb->s_type->i_mutex_key){+.+.+.}:
[ 1687.769175]        [<800647d4>] lock_acquire+0x74/0x94
[ 1687.774344]        [<806de3b8>] mutex_lock_nested+0x54/0x3e8
[ 1687.780027]        [<802748c8>] debugfs_remove+0x40/0x80
[ 1687.785365]        [<7f087a24>] coda_free_aux_buf+0x64/0x78 [coda]
[ 1687.791582]        [<7f08909c>] coda_seq_end_work+0x98/0xf4 [coda]
[ 1687.797793]        [<8004048c>] process_one_work+0x194/0x410
[ 1687.803483]        [<80041104>] worker_thread+0x1d4/0x498
[ 1687.808907]        [<80045988>] kthread+0xdc/0xf8
[ 1687.813635]        [<8000ed10>] ret_from_fork+0x14/0x24
[ 1687.818887]
[ 1687.818887] other info that might help us debug this:
[ 1687.818887]
[ 1687.826899] Chain exists of:
&sb->s_type->i_mutex_key --> &dev->dev_mutex --> &dev->coda_mutex

[ 1687.836042]  Possible unsafe locking scenario:
[ 1687.836042]
[ 1687.841968]        CPU0                    CPU1
[ 1687.846503]        ----                    ----
[ 1687.851036]   lock(&dev->coda_mutex);
[ 1687.854733]                                lock(&dev->dev_mutex);
[ 1687.860861]                                lock(&dev->coda_mutex);
[ 1687.867075]   lock(&sb->s_type->i_mutex_key);
[ 1687.871466]
[ 1687.871466]  *** DEADLOCK ***
[ 1687.871466]
[ 1687.877397] 4 locks held by kworker/u8:2/74:
[ 1687.881671]  #0:  ("coda"){++++.+}, at: [<80040420>] process_one_work+0x128/0x410
[ 1687.889244]  #1:  ((&ctx->seq_end_work)){+.+...}, at: [<80040420>] process_one_work+0x128/0x410
[ 1687.898032]  #2:  (&ctx->buffer_mutex){+.+.+.}, at: [<7f089030>] coda_seq_end_work+0x2c/0xf4 [coda]
[ 1687.907175]  #3:  (&dev->coda_mutex){+.+.+.}, at: [<7f08903c>] coda_seq_end_work+0x38/0xf4 [coda]
[ 1687.916141]
[ 1687.916141] stack backtrace:
[ 1687.920510] CPU: 1 PID: 74 Comm: kworker/u8:2 Not tainted 3.19.5-iMX6-PD15.2.0 #1
[ 1687.928000] Hardware name: Freescale i.MX6 Quad/DualLite (Device Tree)
[ 1687.934545] Workqueue: coda coda_seq_end_work [coda]
[ 1687.939529] Backtrace:
[ 1687.942012] [<80012628>] (dump_backtrace) from [<80012844>] (show_stack+0x18/0x1c)
[ 1687.949588]  r6:809d6694 r5:00000000 r4:00000000 r3:00000002
[ 1687.955331] [<8001282c>] (show_stack) from [<806da27c>] (dump_stack+0x8c/0xa4)
[ 1687.962569] [<806da1f0>] (dump_stack) from [<80060314>] (print_circular_bug+0x1d4/0x318)
[ 1687.970664]  r6:80b85050 r5:80b8c640 r4:80b4c820 r3:00000002
[ 1687.976404] [<80060140>] (print_circular_bug) from [<80063e64>] (__lock_acquire+0x1cd4/0x1e88)
[ 1687.985019]  r10:af12a1f8 r9:00000004 r8:00000004 r7:8120778c r6:809d6778 r5:af129d40
[ 1687.992939]  r4:af12a1f8 r3:af12a1e0
[ 1687.996559] [<80062190>] (__lock_acquire) from [<800647d4>] (lock_acquire+0x74/0x94)
[ 1688.004308]  r10:aec2c0b8 r9:ae1c8000 r8:ae1c8004 r7:00000001 r6:802748c8 r5:60080013
[ 1688.012227]  r4:00000000
[ 1688.014789] [<80064760>] (lock_acquire) from [<806de3b8>] (mutex_lock_nested+0x54/0x3e8)
[ 1688.022884]  r7:af129d40 r6:8120778c r5:802748c8 r4:00000000
[ 1688.028627] [<806de364>] (mutex_lock_nested) from [<802748c8>] (debugfs_remove+0x40/0x80)
[ 1688.036808]  r10:00000001 r9:ae1c8000 r8:ae1c8004 r7:af323244 r6:ae1c8494 r5:aec02228
[ 1688.044728]  r4:ad62d8a0
[ 1688.047299] [<80274888>] (debugfs_remove) from [<7f087a24>] (coda_free_aux_buf+0x64/0x78 [coda])
[ 1688.056088]  r5:ae1c8074 r4:ae1c844c
[ 1688.059723] [<7f0879c0>] (coda_free_aux_buf [coda]) from [<7f08909c>] (coda_seq_end_work+0x98/0xf4 [coda])
[ 1688.069380]  r5:ae1c8074 r4:ae1c8464
[ 1688.073010] [<7f089004>] (coda_seq_end_work [coda]) from [<8004048c>] (process_one_work+0x194/0x410)
[ 1688.082146]  r9:ae925eb0 r8:00000000 r7:ae43a100 r6:af009c00 r5:ae1c8074 r4:ae8dff00
[ 1688.089987] [<800402f8>] (process_one_work) from [<80041104>] (worker_thread+0x1d4/0x498)
[ 1688.098169]  r10:af009c00 r9:ae8dff00 r8:80a17e42 r7:00000088 r6:af009c30 r5:ae8dff18
[ 1688.106086]  r4:af009c00
[ 1688.108648] [<80040f30>] (worker_thread) from [<80045988>] (kthread+0xdc/0xf8)
[ 1688.115874]  r10:00000000 r9:00000000 r8:00000000 r7:80040f30 r6:ae8dff00 r5:ae920200
[ 1688.123793]  r4:00000000
[ 1688.126356] [<800458ac>] (kthread) from [<8000ed10>] (ret_from_fork+0x14/0x24)
[ 1688.133582]  r7:00000000 r6:00000000 r5:800458ac r4:ae920200


[-- Attachment #3: oops --]
[-- Type: text/plain, Size: 11525 bytes --]

[ 6803.348540] coda 2040000.vpu: CODA PIC_RUN timeout
[ 6804.348533] coda 2040000.vpu: CODA PIC_RUN timeout
[ 6805.348545] coda 2040000.vpu: CODA PIC_RUN timeout
^C[ 6806.058071] Unable to handle kernel NULL pointer dereference at virtual address 0000009c
[ 6806.066183] pgd = 80004000
[ 6806.068897] [0000009c] *pgd=00000000
[ 6806.072501] Internal error: Oops: 17 [#1] SMP ARM
[ 6806.077212] Modules linked in: phytec_color_shifter imx_ipu_scaler imx_ipuv3_csi mt9p031 imx_ipu aptina_pll coda videobuf2_vmalloc v4l2_mem2mem phytec_mediabus imx_media ipv6
[ 6806.092997] CPU: 3 PID: 893 Comm: QSGRenderThread Not tainted 3.19.5-iMX6-PD15.2.0 #1
[ 6806.100834] Hardware name: Freescale i.MX6 Quad/DualLite (Device Tree)
[ 6806.107368] task: aa4d89c0 ti: aa308000 task.ti: aa308000
[ 6806.112791] PC is at mutex_lock_nested+0x94/0x3e8
[ 6806.117513] LR is at trace_hardirqs_off+0x14/0x18
[ 6806.122225] pc : [<806de3f8>]    lr : [<8005ee4c>]    psr: 600e0193
[ 6806.122225] sp : aa309ce8  ip : aa309cd8  fp : aa309d3c
[ 6806.133709] r10: 00000098  r9 : ae3c9e00  r8 : ad7e7450
[ 6806.138940] r7 : aa4d89c0  r6 : 8120778c  r5 : 600e0113  r4 : 0000009c
[ 6806.145473] r3 : aa308000  r2 : aa4d89c0  r1 : 00000000  r0 : 806de3f4
[ 6806.152009] Flags: nZCv  IRQs off  FIQs on  Mode SVC_32  ISA ARM  Segment user
[ 6806.159237] Control: 10c5387d  Table: 3a46004a  DAC: 00000015
[ 6806.164990] Process QSGRenderThread (pid: 893, stack limit = 0xaa308238)
[ 6806.171697] Stack: (0xaa309ce8 to 0xaa30a000)
[ 6806.176065] 9ce0:                   00000001 00000000 80274954 ae171028 aa309d14 aa309d08
[ 6806.184254] 9d00: 80061e34 80061c38 aa309d34 aa309d18 806df538 ae1711e8 ad7e7450 af323010
[ 6806.192442] 9d20: ad7e74f4 ad7e7450 ae3c9e00 00000008 aa309d64 aa309d40 80274954 806de370
[ 6806.200629] 9d40: 00000002 ae1711e8 af322010 af323010 ae171000 af024600 aa309d9c aa309d68
[ 6806.208817] 9d60: 7f087cc0 80274914 aa309d74 00000001 ae3e6dc8 00000004 801128b4 ae3e6dc0
[ 6806.217004] 9d80: af322420 ae3c9e00 ae4a7c10 aec0aac8 aa309db4 aa309da0 804c6928 7f087b14
[ 6806.225192] 9da0: ae3e6dc0 00000000 aa309df4 aa309db8 800f5144 804c68f4 00000000 00000000
[ 6806.233380] 9dc0: aa4d8d80 ae3e6dc8 aa4d8d80 aa4d8d70 80a1a4d4 ae3e7180 aa4d89c0 00000000
[ 6806.241567] 9de0: 00000001 418004fc aa309e04 aa309df8 800f52f4 800f50c0 aa309e2c aa309e08
[ 6806.249755] 9e00: 800440bc 800f52f0 00000000 aa4d89c0 aa4d8d80 af30c054 ae0a2400 af30c000
[ 6806.257943] 9e20: aa309e5c aa309e30 8002c59c 8004400c 80035298 af30c054 00000000 ae115784
[ 6806.266130] 9e40: ae115784 aa309edc aa309e64 ae0a2400 aa309e7c aa309e60 8002dbd4 8002c2bc
[ 6806.274318] 9e60: aa308000 00418004 ae115784 aa309edc aa309ec4 aa309e80 80037a54 8002db8c
[ 6806.282506] 9e80: aa309ea4 aa309e90 806e13f8 80061e2c aa4d89c0 af740700 aa309edc aa309ec8
[ 6806.290693] 9ea0: aa309fb0 00000000 00000000 00000000 aa308000 5dd6ac60 aa309f8c aa309ec8
[ 6806.298881] 9ec0: 80011b7c 800378bc 809ae700 af30c000 aa309f7c aa309ee0 806dbfec 00000009
[ 6806.307069] 9ee0: 00000000 00000000 00000000 00000000 809b209c 00000007 aa309f4c aa309f08
[ 6806.315256] 9f00: 809ae700 af30c000 800165f8 8007de00 aa309f2c aa309f20 8005ee4c 8005ed70
[ 6806.323443] 9f20: aa309f4c aa309f30 80079ac8 8005ee44 809adc74 00000000 809b8d80 00000000
[ 6806.331631] 9f40: aa309f64 aa309f50 8002eb80 80079a60 00000159 00000002 aa308000 aa309fb0
[ 6806.339818] 9f60: 200e0010 00000001 aa308000 aa309fb0 00000000 00000000 aa308000 5dd6ac60
[ 6806.348006] 9f80: aa309fac aa309f90 80012024 80011abc 751e3398 200e0010 ffffffff 10c5387d
[ 6806.356193] 9fa0: 00000000 aa309fb0 8000ec9c 80011f88 5dd6b660 5dd6bb60 6bfbbc20 00000008
[ 6806.364381] 9fc0: 5dd6b160 19191a1b 00000000 5dd6ac60 00000500 00000500 5dd6ac60 00000a00
[ 6806.372568] 9fe0: 00000500 68aeb588 751e6cb8 751e3398 200e0010 ffffffff 00000000 00000000
[ 6806.380749] Backtrace:
[ 6806.383239] [<806de364>] (mutex_lock_nested) from [<80274954>] (debugfs_remove_recursive+0x4c/0x16c)
[ 6806.392376]  r10:00000008 r9:ae3c9e00 r8:ad7e7450 r7:ad7e74f4 r6:af323010 r5:ad7e7450
[ 6806.400297]  r4:ae1711e8
[ 6806.402884] [<80274908>] (debugfs_remove_recursive) from [<7f087cc0>] (coda_release+0x1b8/0x22c [coda])
[ 6806.412283]  r8:af024600 r7:ae171000 r6:af323010 r5:af322010 r4:ae1711e8 r3:00000002
[ 6806.420142] [<7f087b08>] (coda_release [coda]) from [<804c6928>] (v4l2_release+0x40/0x80)
[ 6806.428324]  r8:aec0aac8 r7:ae4a7c10 r6:ae3c9e00 r5:af322420 r4:ae3e6dc0
[ 6806.435123] [<804c68e8>] (v4l2_release) from [<800f5144>] (__fput+0x90/0x1e0)
[ 6806.442263]  r5:00000000 r4:ae3e6dc0
[ 6806.445882] [<800f50b4>] (__fput) from [<800f52f4>] (____fput+0x10/0x14)
[ 6806.452588]  r10:418004fc r9:00000001 r8:00000000 r7:aa4d89c0 r6:ae3e7180 r5:80a1a4d4
[ 6806.460506]  r4:aa4d8d70
[ 6806.463076] [<800f52e4>] (____fput) from [<800440bc>] (task_work_run+0xbc/0xf0)
[ 6806.470401] [<80044000>] (task_work_run) from [<8002c59c>] (do_exit+0x2ec/0x990)
[ 6806.477802]  r8:af30c000 r7:ae0a2400 r6:af30c054 r5:aa4d8d80 r4:aa4d89c0 r3:00000000
[ 6806.485640] [<8002c2b0>] (do_exit) from [<8002dbd4>] (do_group_exit+0x54/0xcc)
[ 6806.492867]  r7:ae0a2400
[ 6806.495436] [<8002db80>] (do_group_exit) from [<80037a54>] (get_signal+0x1a4/0x688)
[ 6806.503096]  r6:aa309edc r5:ae115784 r4:00418004 r3:aa308000
[ 6806.508845] [<800378b0>] (get_signal) from [<80011b7c>] (do_signal+0xcc/0x3b4)
[ 6806.516072]  r10:5dd6ac60 r9:aa308000 r8:00000000 r7:00000000 r6:00000000 r5:aa309fb0
[ 6806.523991]  r4:aa309ec8
[ 6806.526554] [<80011ab0>] (do_signal) from [<80012024>] (do_work_pending+0xa8/0xb8)
[ 6806.534128]  r10:5dd6ac60 r9:aa308000 r8:00000000 r7:00000000 r6:aa309fb0 r5:aa308000
[ 6806.542046]  r4:00000001
[ 6806.544609] [<80011f7c>] (do_work_pending) from [<8000ec9c>] (work_pending+0xc/0x20)
[ 6806.552356]  r7:10c5387d r6:ffffffff r5:200e0010 r4:751e3398
[ 6806.558092] Code: f10c0080 e28a4004 ebe60290 f5d4f000 (e1943f9f)
[ 6806.564200] ---[ end trace 5d9e0b3a5660a6a8 ]---
[ 6806.568825] Fixing recursive fault but reboot is needed!

Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.072501] Internal error: Oops: 17 [#1] SMP ARM


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.164990] Process QSGRenderThread (pid: 893, stack limit = 0xaa308238)


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.171697] Stack: (0xaa309ce8 to 0xaa30a000)


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.176065] 9ce0:                   00000001 00000000 80274954 ae171028 aa309d14 aa309d08


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.184254] 9d00: 80061e34 80061c38 aa309d34 aa309d18 806df538 ae1711e8 ad7e7450 af323010


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.192442] 9d20: ad7e74f4 ad7e7450 ae3c9e00 00000008 aa309d64 aa309d40 80274954 806de370


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.200629] 9d40: 00000002 ae1711e8 af322010 af323010 ae171000 af024600 aa309d9c aa309d68


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.208817] 9d60: 7f087cc0 80274914 aa309d74 00000001 ae3e6dc8 00000004 801128b4 ae3e6dc0


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.217004] 9d80: af322420 ae3c9e00 ae4a7c10 aec0aac8 aa309db4 aa309da0 804c6928 7f087b14


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.225192] 9da0: ae3e6dc0 00000000 aa309df4 aa309db8 800f5144 804c68f4 00000000 00000000


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.233380] 9dc0: aa4d8d80 ae3e6dc8 aa4d8d80 aa4d8d70 80a1a4d4 ae3e7180 aa4d89c0 00000000


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:01 UTC):

kernel[433]: [ 6806.241567] 9de0: 00000001 418004fc aa309e04 aa309df8 800f52f4 800f50c0 aa309e2c aa309e08


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.249755] 9e00: 800440bc 800f52f0 00000000 aa4d89c0 aa4d8d80 af30c054 ae0a2400 af30c000


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.257943] 9e20: aa309e5c aa309e30 8002c59c 8004400c 80035298 af30c054 00000000 ae115784


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.266130] 9e40: ae115784 aa309edc aa309e64 ae0a2400 aa309e7c aa309e60 8002dbd4 8002c2bc


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.274318] 9e60: aa308000 00418004 ae115784 aa309edc aa309ec4 aa309e80 80037a54 8002db8c


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.282506] 9e80: aa309ea4 aa309e90 806e13f8 80061e2c aa4d89c0 af740700 aa309edc aa309ec8


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.290693] 9ea0: aa309fb0 00000000 00000000 00000000 aa308000 5dd6ac60 aa309f8c aa309ec8


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.298881] 9ec0: 80011b7c 800378bc 809ae700 af30c000 aa309f7c aa309ee0 806dbfec 00000009


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.307069] 9ee0: 00000000 00000000 00000000 00000000 809b209c 00000007 aa309f4c aa309f08


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.315256] 9f00: 809ae700 af30c000 800165f8 8007de00 aa309f2c aa309f20 8005ee4c 8005ed70


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.323443] 9f20: aa309f4c aa309f30 80079ac8 8005ee44 809adc74 00000000 809b8d80 00000000


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.331631] 9f40: aa309f64 aa309f50 8002eb80 80079a60 00000159 00000002 aa308000 aa309fb0


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.339818] 9f60: 200e0010 00000001 aa308000 aa309fb0 00000000 00000000 aa308000 5dd6ac60


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.348006] 9f80: aa309fac aa309f90 80012024 80011abc 751e3398 200e0010 ffffffff 10c5387d


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.356193] 9fa0: 00000000 aa309fb0 8000ec9c 80011f88 5dd6b660 5dd6bb60 6bfbbc20 00000008


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.364381] 9fc0: 5dd6b160 19191a1b 00000000 5dd6ac60 00000500 00000500 5dd6ac60 00000a00


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.372568] 9fe0: 00000500 68aeb588 751e6cb8 751e3398 200e0010 ffffffff 00000000 00000000


Broadcast message from systemd-journald@phyflex-imx6-2 (Mon 2015-11-30 10:51:02 UTC):

kernel[433]: [ 6806.558092] Code: f10c0080 e28a4004 ebe60290 f5d4f000 (e1943f9f)

Re: problem with coda when running qt-gstreamer and video reaches its end (resending in plain text)

[Philipp Zabel]

Hi Piotr,

thank you for the report.

Am Mittwoch, den 16.12.2015, 14:09 +0100 schrieb Piotr Lewicki:
> Hello,
> I'm running an application that plays video on an embedded device. It 
> uses Qt5.4 and qt-gstreamer plugin and it runs on imx6q processor with 
> yocto based linux (kernel version 3.19.5).

First, could you repeat this using current versions of the coda driver
and GStreamer? There are about 60 coda patches in mainline between v3.19
and v4.3, and some of them are quite relevant for the end-of-stream and
buffer handling. I think the relevant GStreamer EOS change went into
1.5.2.

> When I built a sample from this qt-gstreamer package called qmlplayer2 
> and used it to play video I came across following problem:
> 
> 1. When video reaches it's end I start receiving kernel ringbuffer message:
> # [ 1371.618854] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1372.618713] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1373.618653] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1374.618872] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1375.618712] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1376.618707] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1377.618860] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1378.738700] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1379.738632] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1380.828872] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1381.828697] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1382.828875] coda 2040000.vpu: CODA PIC_RUN timeout
> # [ 1383.938704] coda 2040000.vpu: CODA PIC_RUN timeout
> 
> The video is stopped but I can see last frame on the screen although in 
> qt application it should receive end-of-stream message and stop the 
> video (resulting with black screen).

Looks like the coda driver is constantly fed empty buffers, which don't
increase the bitstream payload level, and the PIC_RUN times out with a
bitstream buffer underflow. What GStreamer version is this?

> 2. If I don't terminate the application and several times press "stop" 
> and "play" video I get message:
> 
> # [ 3041.650483] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
> # [ 3044.205362] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
> # [ 3044.214711] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
> # [ 3047.189317] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
> # [ 3047.196056] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
> 
> and finally
> 
> # [ 3049.161708] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
> # "Failed to allocate required memory."

That shouldn't happen anymore in recent kernels. In the past, repeated
reqbufs calls would leak buffers because the cleanup was only done on
close.

Please let me know if you can reproduce any of the issues with more
recent kernels and GStreamer 1.6.

regards
Philipp

Re: problem with coda when running qt-gstreamer and video reaches its end (resending in plain text)

[Nicolas Dufresne]

[-- Attachment #1: Type: text/plain, Size: 1373 bytes --]

Le mercredi 16 décembre 2015 à 15:49 +0100, Philipp Zabel a écrit :
> > # [ 1382.828875] coda 2040000.vpu: CODA PIC_RUN timeout
> > # [ 1383.938704] coda 2040000.vpu: CODA PIC_RUN timeout
> > 
> > The video is stopped but I can see last frame on the screen although in 
> > qt application it should receive end-of-stream message and stop the 
> > video (resulting with black screen).
> 
> Looks like the coda driver is constantly fed empty buffers, which don't
> increase the bitstream payload level, and the PIC_RUN times out with a
> bitstream buffer underflow. What GStreamer version is this?

I believe this is side effect of how the MFC driver worked in it's
early stage. We had to keep pushing empty buffer to drain the driver.
So GStreamer still poll/queue/poll/queue/... until all capture buffers
are received. I notice recently that this behaviour can induce high CPU
load with some other drivers that don't do any active wait when a empty
buffer is queued. I would therefor suggest to change this code to only
push one empty buffer for your use case. An submitted patch to support
CMD_STOP can be found here, though is pending a re-submition by it's
author.

https://bugzilla.gnome.org/show_bug.cgi?id=733864

For proper EOS detection with CODA driver (using EPIPE return value),
you indeed need GStreamer 1.6+.

cheers,
Nicolas

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 181 bytes --]

Re: problem with coda when running qt-gstreamer and video reaches its end (resending in plain text)

[Piotr Lewicki]

[-- Attachment #1: Type: text/plain, Size: 3733 bytes --]

Thank you,
I updated GStreamer to version 1.6.1 and applied patches from Nicolas 
(https://bugzilla.gnome.org/show_bug.cgi?id=733864).
This resolved the issue witch "CODA PIC_RUN timeout".

At the moment situation looks a little bit different:
1. Playing flv videos (video codec: Sorenson Spark Video) allows me to 
play multiple videos and EOS message is received.

2. Playing h264 videos with lower resolution runs smoothly (no CODA 
PIC_RUN timeout) but when video reaches it's end - no message is 
reaching the qt application and thus I can only stop it manually.
* Is there a resolution of this problem with missing end-of-stream 
detection?

3. When playing h264 videos in HD resolution (tested with 
big_buck_bunny_1080p_h264.mov) the problem with "CODA PIC_RUN timeout" 
still occurs with small difference - when I press STOP "CODA PIC_RUN 
timeout" messages don't show up anymore while before they were showing 
up repeatedly (every second) until my qt application stopped.
- Another strange behaviour is that after I get "coda 2040000.vpu: 
failed to allocate bitstream ringbuffer" message -> the video starts 
running again (when I press PLAY) and it starts detecting end-of-stream 
(!) - see attached file

> > # [ 3049.161708] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
> > # "Failed to allocate required memory."
>
> That shouldn't happen anymore in recent kernels. In the past, repeated
> reqbufs calls would leak buffers because the cleanup was only done on
> close.

Dear Phillip,
Unfortunately I'm using i.MX6 device so kernel provided by Freescale is 
v3.14 and I am using kernel provided by Phytec company which is based on 
mainline but the newest version is 3.19 and I cannot upgrade it.

I have already came upon some patches you provided:
starting with 
https://www.mail-archive.com/linux-media@vger.kernel.org/msg77439.html 
and another pack starting with 
http://www.spinics.net/lists/linux-media/msg91575.html
but I think that some of these are dependent on other components like 
e.g. "[PATCH 07/10] [media] coda: drop custom list of pixel format 
descriptions".

* Is there a possibility for you to give me a list of patches to apply 
(and maybe dependent packages) so I can try to apply them manually?
I hope it's not too much too ask..

Best regards
Piotr Lewicki

On 16.12.2015 22:49, Nicolas Dufresne wrote:
> Le mercredi 16 décembre 2015 à 15:49 +0100, Philipp Zabel a écrit :
>>> # [ 1382.828875] coda 2040000.vpu: CODA PIC_RUN timeout
>>> # [ 1383.938704] coda 2040000.vpu: CODA PIC_RUN timeout
>>>   
>>> The video is stopped but I can see last frame on the screen although in
>>> qt application it should receive end-of-stream message and stop the
>>> video (resulting with black screen).
>> Looks like the coda driver is constantly fed empty buffers, which don't
>> increase the bitstream payload level, and the PIC_RUN times out with a
>> bitstream buffer underflow. What GStreamer version is this?
> I believe this is side effect of how the MFC driver worked in it's
> early stage. We had to keep pushing empty buffer to drain the driver.
> So GStreamer still poll/queue/poll/queue/... until all capture buffers
> are received. I notice recently that this behaviour can induce high CPU
> load with some other drivers that don't do any active wait when a empty
> buffer is queued. I would therefor suggest to change this code to only
> push one empty buffer for your use case. An submitted patch to support
> CMD_STOP can be found here, though is pending a re-submition by it's
> author.
>
> https://bugzilla.gnome.org/show_bug.cgi?id=733864
>
> For proper EOS detection with CODA driver (using EPIPE return value),
> you indeed need GStreamer 1.6+.
>
> cheers,
> Nicolas


[-- Attachment #2: 2015-12-18-run_1080p_h264.log --]
[-- Type: text/x-log, Size: 3415 bytes --]

root@phyflex-imx6-2:~# qmlplayer2 file:///.videos/big_buck_bunny_1080p_h264.mov 
QML debugging is enabled. Only use this in a safe environment.ny_1080p_h264.mov  
QEglFSImx6Hooks will set environment variable FB_MULTI_BUFFER=2 to enable double buffering and vsync.
 If this is not desired, you can override this via: export QT_EGLFS_IMX6_NO_FB_MULTI_BUFFER=1
Unable to query physical screen size, defaulting to 100 dpi.
To override, set QT_QPA_EGLFS_PHYSICAL_WIDTH and QT_QPA_EGLFS_PHYSICAL_HEIGHT (in millimeters).
** PLAY **
** video runs **
[ 2022.118671] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2023.118647] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2024.118645] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2025.118730] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2026.118638] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2027.118640] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2028.118723] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2029.118641] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2030.118638] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2031.118582] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2032.118651] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2033.118576] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2034.118582] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2035.118597] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2036.118632] coda 2040000.vpu: CODA PIC_RUN timeout
** STOP and PLAY **
** video runs **
[ 2446.438666] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2447.438753] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2448.438686] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2449.438733] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2450.438644] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2451.438730] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2452.438730] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2453.438728] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2454.438726] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2455.438732] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2456.438644] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2457.438569] coda 2040000.vpu: CODA PIC_RUN timeout
[ 2458.438656] coda 2040000.vpu: CODA PIC_RUN timeout
** STOP and PLAY **
** video not running **
[ 2461.043521] coda 2040000.vpu: Failed to allocate fb5 buffer of size 3655680
[ 2461.054544] coda 2040000.vpu: failed to allocate framebuffers
** STOP and PLAY **
** video not running **
[ 2560.075008] coda 2040000.vpu: Failed to allocate fb1 buffer of size 3655680
[ 2560.082640] coda 2040000.vpu: failed to allocate framebuffers
** STOP and PLAY **
** video not running **
[ 2569.879861] coda 2040000.vpu: dma_alloc_coherent of size 3133440 failed
[ 2569.886931] coda 2040000.vpu: Failed to allocate slicebuf buffer of size 3264512
[ 2569.894399] coda 2040000.vpu: failed to allocate 0 byte slice buffer
** STOP and PLAY **
[ 2574.797829] coda 2040000.vpu: failed to allocate bitstream ringbuffer
** video runs **
>MessageEos
Reached end of stream. Playing next!
about to play  "file:///.videos/big_buck_bunny_1080p_h264.mov"
coda 2040000.vpu: failed to allocate bitstream ringbuffer
** video runs **
>MessageEos
Reached end of stream. Playing next!
about to play  "file:///.videos/big_buck_bunny_1080p_h264.mov"
[ 3768.749155] coda 2040000.vpu: failed to allocate bitstream ringbuffer
** video runs **
>MessageEos
Reached end of stream. Playing next!
about to play  "file:///.videos/big_buck_bunny_1080p_h264.mov"
coda 2040000.vpu: failed to allocate bitstream ringbuffer