Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

libimxvpuapi freezes with normal h264 decoding #11

Closed
ttykkala opened this issue Apr 21, 2016 · 7 comments
Closed

libimxvpuapi freezes with normal h264 decoding #11

ttykkala opened this issue Apr 21, 2016 · 7 comments

Comments

@ttykkala
Copy link

I tested example/decode-example with given h264 test file (test-320x240.h264)
and it seems to run but on third execuction time it fails.

Here's the log:
//////////////////////////////////////////////////////////
/imxvpuapi/imxvpuapi_vpulib.c:1807 (imx_vpu_dec_decode) log: input info: 6214 byte
../imxvpuapi/imxvpuapi_vpulib.c:1846 (imx_vpu_dec_decode) log: pushing main frame data with 6214 byte
../imxvpuapi/imxvpuapi_vpulib.c:1691 (imx_vpu_dec_push_input_data) log: bitstream buffer status: read ptr 0x44c37090 write ptr 0x44c37093 num free bytes 3143676
../imxvpuapi/imxvpuapi_vpulib.c:2063 (imx_vpu_dec_decode) log: waiting for decoding completion
../imxvpuapi/imxvpuapi_vpulib.c:2072 (imx_vpu_dec_decode) info: timeout after waiting 500 ms for frame completion
../imxvpuapi/imxvpuapi_vpulib.c:2072 (imx_vpu_dec_decode) info: timeout after waiting 500 ms for frame completion
../imxvpuapi/imxvpuapi_vpulib.c:2072 (imx_vpu_dec_decode) info: timeout after waiting 500 ms for frame completion
../imxvpuapi/imxvpuapi_vpulib.c:2072 (imx_vpu_dec_decode) info: timeout after waiting 500 ms for frame completion
[ERR] fatal: VPU is busy in vpu_DecGetOutputInfo
imx_vpu_dec_decode() failed: timeout
../imxvpuapi/imxvpuapi_vpulib.c:1104 (imx_vpu_dec_close) debug: closing decoder
////////////////////////////////////////////////////////////

Should the provided example work normally with any number of execution times?
My goal is to decode h264 video on VPU.

The best,
Tommi
@dv1
Copy link
Collaborator

dv1 commented Apr 23, 2016

Yes, this should work no matter how often it is executed. Check out https://github.com/Freescale/gstreamer-imx/blob/master/docs/faq.md#vpu-operation-freezes-and-vpu-blocking-timeout-messages-appear . Also let me know your platform, your kernel version, and your imx-vpu version.

@ttykkala
Copy link
Author

ttykkala commented Apr 25, 2016 •
edited
Loading

Kernel version is 4.1.15:

Linux 10:0d:32:01:7e:d1 4.1.15-224156-g141e464 #3 SMP PREEMPT Thu Apr 21 11:34:38 EEST 2016 armv7l GNU/Linux

Its a custom platform, Freescale NXP IMX6 Yocto 2.0 Release
vpu firmware: 3.1, release 1, lib 5.4, librelease: 33

Normally, I have CONFIG_MX6_VPU_352M kernel parameter set On because the example
gets stuck worse without it. But now I disabled it so here's some tests:

Without CONFIG_MX6_VPU_352M flag, I get stuck like this (firmware 5.4.33):

10:0d:32:01:5f:aa:~/tmp/example$ ./decode-example2 -i test-320x240.h264 -o raaka.raw
../imxvpuapi/imxvpuapi_vpulib.c:293 (imx_vpu_load) log: VPU init instance counter: 0
../imxvpuapi/imxvpuapi_vpulib.c:302 (imx_vpu_load) info: libimxvpuapi version 0.10.1 vpulib backend
../imxvpuapi/imxvpuapi_vpulib.c:306 (imx_vpu_load) debug: loaded VPU
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 5236736 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x76742000 aligned: 0x76742000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x45200000 aligned: 0x45200000
../imxvpuapi/imxvpuapi_vpulib.c:961 (imx_vpu_dec_open) debug: opening decoder
../imxvpuapi/imxvpuapi_vpulib.c:1063 (imx_vpu_dec_open) debug: opening decoder, frame size: 0 x 0 pixel
[INFO] bitstreamMode 1, chromaInterleave 0, mapType 0, tiled2LinearEnable 0
../imxvpuapi/imxvpuapi_vpulib.c:1077 (imx_vpu_dec_open) debug: successfully opened decoder
encoded input frame: frame id: 0x64 size: 6466 byte
../imxvpuapi/imxvpuapi_vpulib.c:1800 (imx_vpu_dec_decode) log: input info: 6466 byte
../imxvpuapi/imxvpuapi_vpulib.c:1839 (imx_vpu_dec_decode) log: pushing main frame data with 6466 byte
../imxvpuapi/imxvpuapi_vpulib.c:1684 (imx_vpu_dec_push_input_data) log: bitstream buffer status: read ptr 0x45200000 write ptr 0x45200000 num free bytes 3143679

With firmware version 5.4.31 I get this kind of result:

10:0d:32:01:5f:aa:~/tmp/example$ ./decode-example2 -i test-320x240.h264 -o raaka.raw
../imxvpuapi/imxvpuapi_vpulib.c:293 (imx_vpu_load) log: VPU init instance counter: 0
../imxvpuapi/imxvpuapi_vpulib.c:302 (imx_vpu_load) info: libimxvpuapi version 0.10.1 vpulib backend
../imxvpuapi/imxvpuapi_vpulib.c:306 (imx_vpu_load) debug: loaded VPU
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 5236736 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x76765000 aligned: 0x76765000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x45200000 aligned: 0x45200000
../imxvpuapi/imxvpuapi_vpulib.c:961 (imx_vpu_dec_open) debug: opening decoder
../imxvpuapi/imxvpuapi_vpulib.c:1063 (imx_vpu_dec_open) debug: opening decoder, frame size: 0 x 0 pixel
[INFO] bitstreamMode 1, chromaInterleave 0, mapType 0, tiled2LinearEnable 0
../imxvpuapi/imxvpuapi_vpulib.c:1077 (imx_vpu_dec_open) debug: successfully opened decoder
encoded input frame: frame id: 0x64 size: 6466 byte
../imxvpuapi/imxvpuapi_vpulib.c:1800 (imx_vpu_dec_decode) log: input info: 6466 byte
../imxvpuapi/imxvpuapi_vpulib.c:1839 (imx_vpu_dec_decode) log: pushing main frame data with 6466 byte
../imxvpuapi/imxvpuapi_vpulib.c:1684 (imx_vpu_dec_push_input_data) log: bitstream buffer status: read ptr 0x45200000 write ptr 0x45200000 num free bytes 3143679
initial info: size: 320x240 pixel rate: 2000000000/1 min num required framebuffers: 11 interlacing: 0 framebuffer alignment: 1
calculated sizes: frame width&height: 320x240 Y stride: 320 CbCr stride: 160 Y size: 76800 CbCr size: 19200 MvCol size: 19200 total size: 134401
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x76744000 aligned: 0x76744000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x457c0000 aligned: 0x457c0000
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x76723000 aligned: 0x76723000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x45800000 aligned: 0x45800000
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x76702000 aligned: 0x76702000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x45840000 aligned: 0x45840000
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x766e1000 aligned: 0x766e1000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x45880000 aligned: 0x45880000
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x766c0000 aligned: 0x766c0000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x458c0000 aligned: 0x458c0000
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x7669f000 aligned: 0x7669f000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x45900000 aligned: 0x45900000
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x7667e000 aligned: 0x7667e000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x45940000 aligned: 0x45940000
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x7665d000 aligned: 0x7665d000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x45980000 aligned: 0x45980000
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x7663c000 aligned: 0x7663c000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x459c0000 aligned: 0x459c0000
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x7661b000 aligned: 0x7661b000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x45a00000 aligned: 0x45a00000
../imxvpuapi/imxvpuapi_vpulib.c:499 (default_dmabufalloc_allocate) debug: allocated 134401 bytes of physical memory
../imxvpuapi/imxvpuapi_vpulib.c:509 (default_dmabufalloc_allocate) debug: retrieved virtual address for physical memory
../imxvpuapi/imxvpuapi_vpulib.c:514 (default_dmabufalloc_allocate) debug: virtual address: 0x765fa000 aligned: 0x765fa000
../imxvpuapi/imxvpuapi_vpulib.c:515 (default_dmabufalloc_allocate) debug: physical address: 0x45a40000 aligned: 0x45a40000
../imxvpuapi/imxvpuapi_vpulib.c:1222 (imx_vpu_dec_register_framebuffers) debug: attempting to register 11 framebuffers
../imxvpuapi/imxvpuapi_vpulib.c:2055 (imx_vpu_dec_decode) log: waiting for decoding completion
../imxvpuapi/imxvpuapi_vpulib.c:2064 (imx_vpu_dec_decode) info: timeout after waiting 500 ms for frame completion
../imxvpuapi/imxvpuapi_vpulib.c:2064 (imx_vpu_dec_decode) info: timeout after waiting 500 ms for frame completion
../imxvpuapi/imxvpuapi_vpulib.c:2064 (imx_vpu_dec_decode) info: timeout after waiting 500 ms for frame completion
../imxvpuapi/imxvpuapi_vpulib.c:2064 (imx_vpu_dec_decode) info: timeout after waiting 500 ms for frame completion
[ERR] fatal: VPU is busy in vpu_DecGetOutputInfo
imx_vpu_dec_decode() failed: timeout
../imxvpuapi/imxvpuapi_vpulib.c:1097 (imx_vpu_dec_close) debug: closing decoder
^C

The best,
Tommi

@ttykkala
Copy link
Author

We found the reason for this timeout problem.

Seems to be due to our kernel configuration:
CONFIG_IMX_IPUV3_CORE flag seems to cause
problems for VPU decoding.

-T

@dv1
Copy link
Collaborator

dv1 commented May 1, 2016

Thanks! I added some notes about the VPU timeouts, and included your finding. Closing this now. Please reopen if you still have problems with the VPU.

@dv1 dv1 closed this as completed May 1, 2016
@ttykkala
Copy link
Author

Hi,

Additional info related to this problem.

The final real reason behind VPU timeouts was wrong input voltage
to SMARC processor card. After changing from 3.3V -> 5V
timeout problems disappeared.

-T

@dv1
Copy link
Collaborator

dv1 commented Jun 28, 2016

Excellent, thanks. Will add that to the documentation.

@ttykkala
Copy link
Author

After even further debugging it was finally a device tree patch which fixed this issue,

here's a link to device tree patch:
https://drive.google.com/file/d/0B2jrHa33l-ljSGVmLXMxZ0tONWM/view?usp=sharing

Cheers,
Tommi

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@dv1 @ttykkala