This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

DRA746: Play video, meet error gstducatividdec.c(571):codec_process:<decoder> err=-5

Part Number: DRA746

Hi TI team,

We met the issue, play a video and switch to next, got error “ducati gstducatividdec.c(571):codec_process:<decoder> err=-5”. And also we see our process exit from g_main_loop_run().
Attached the log, videos trasfer to link . It is once rare occurrence. Could you please provide some comments from your POV. Thanks.

https://e2e.ti.com/cfs-file/__key/communityserver-discussions-components-files/791/drop_5F00_out_5F00_mediaOneonly.7z

Detail in log.
1. Here the previous song(Jimikki Kammal Dance - ஜிமிக்கி கம்மல் - ജിമ്മിക്കി കമ്മൽ കിടുവേ - Sheril Dance - Mohanlal.mp4) playback to the end:
3263744 2019/11/11 16:19:15.000000 401.0277 87 ECU1 CrM API 2397 log info verbose 1 T2397 CgstPlayerApi::gstBusCallback() Got eos message
3263745 2019/11/11 16:19:15.000000 401.0277 220 ECU1 CrM HMPE 2397 log info verbose 1 T2397 CgstBasePlayer::onHandleEOS() called
2. Here try to stop the playback:
3263814 2019/11/11 16:19:15.000000 401.0307 89 ECU1 CrM API 2397 log info verbose 1 T2561 CgstPlayerApi:stop() set state to stop
3263815 2019/11/11 16:19:15.000000 401.0307 90 ECU1 CrM API 2397 log info verbose 1 T2561 CgstPlayerApi:stopAsync() set state to stop
3. Try to playback the next track(Maan Karate - Darling Dambakku Video - Anirudh - Sivakarthikeyan.mp4):
3264184 2019/11/11 16:19:16.000000 401.3929 135 ECU1 CrM API 2397 log info verbose 1 T2561 CgstPlayerApi:playAsync() set state to playing
3264193 2019/11/11 16:19:16.000000 401.3992 138 ECU1 CrM API 2397 log info verbose 1 T2561 CgstPlayerApi:waitFor() Wait for PLAYING
4. But the playback not happened, instead we get an error, which cause our progress drop out, I guess maybe this error make our progress jump out g_main_loop_run().
3264659 2019/11/11 16:19:16.000000 401.7268 209 ECU1 CrM API 2397 log info verbose 1 T4862 GSTLogs WARN waylandsink wlvideoformat.c(102):gst_wl_shm_format_to_video_format: gst video format not found
3264660 2019/11/11 16:19:16.000000 401.7269 210 ECU1 CrM API 2397 log info verbose 1 T4862 GSTLogs WARN waylandsink wlvideoformat.c(102):gst_wl_shm_format_to_video_format: gst video format not found
3264662 2019/11/11 16:19:16.000000 401.7395 211 ECU1 CrM API 2397 log info verbose 1 T4862 GSTLogs WARN waylandsink wlvideoformat.c(102):gst_wl_shm_format_to_video_format: gst video format not found
3264663 2019/11/11 16:19:16.000000 401.7397 212 ECU1 CrM API 2397 log info verbose 1 T4862 GSTLogs WARN waylandsink wlvideoformat.c(102):gst_wl_shm_format_to_video_format: gst video format not found
3264756 2019/11/11 16:19:16.000000 401.8302 234 ECU1 CrM API 2397 log info verbose 1 T4862 GSTLogs WARN ducati gstducatividdec.c(571):codec_process:<decoder> err=-5, extendedError=00000000
3264840 2019/11/11 16:19:16.000000 401.8383 20 ECU1 CrM HMPE 2397 log info verbose 1 T4862 CBTDevicePlayer::~CBTDevicePlayer()
3264841 2019/11/11 16:19:16.000000 401.8383 21 ECU1 CrM HMPE 2397 log info verbose 1 T4862 CBTDevicePlayer::deInitialize()

  • Hi Vicky,

    Error -5 means DCE_EIPC_CALL_FAIL. This is returned from libdce when application invokes process call to  decoder running on IPU2.

    This error -5 can happen when MmRpc Call failed for some unknown reason.Can you check the state of IPU2 when this issue happened and also check if /dev/rpmsg-dce device node still exits.

    I have downloaded the video you have shared but this should not be a stream specific.

    Thanks

    RamPrasad

  • Hi RamPrasad,

    Thanks for your reply, as I mentioned it is once issue, difficult to reproduce.During ticket reproducing, we check the log again depend on your analysis, find the following related info, could you please check whether it is helpful for you?
    2458603 2019/11/11 16:12:59.000000 4.5123 25 ECU1 SYS JOUR 1635 log warn verbose 5 1970/01/01 00:00:02.684531 0.703923 kernel: Warning: remoteproc0: Direct firmware load for dra7-ipu1-fw.xem4 failed with error -2
    2458605 2019/11/11 16:12:59.000000 4.5124 27 ECU1 SYS JOUR 1635 log warn verbose 5 1970/01/01 00:00:02.684685 0.704297 kernel: Warning: remoteproc1: Direct firmware load for dra7-ipu2-fw.xem4 failed with error -2

    3264961 2019/11/11 16:19:16.000000 401.8567 228 ECU1 SYS JOUR 1635 log error verbose 5 2019/11/10 00:06:25.180402 401.837130 kernel: Error: rpmsg_rpc rpmsg-dce: unwinding UVA to RDA translations! translation = 1
    3264962 2019/11/11 16:19:16.000000 401.8585 229 ECU1 SYS JOUR 1635 log error verbose 5 2019/11/10 00:06:25.181587 401.837298 kernel: Error: rpmsg_rpc rpmsg-dce: failed to translate all pointers for remote core!

    And we have additional questions, could you please help on this? Thanks.
    1.How to check the IPU2 state? Could you please provide the command?
    2.How to check the /dev/rpmsg-dce device node? Is that OK using “ls /dev/rpmsg-dce”? We are working on MMT project and doesn't see rpmsg-dce under /dev.
    3.Whether the error -5(DCE_EIPC_CALL_FAIL) can cause our process jump out of g_main_loop_run(), is this the root cause make our process drop out?

  • Hi Vicky,

    3264961 2019/11/11 16:19:16.000000 401.8567 228 ECU1 SYS JOUR 1635 log error verbose 5 2019/11/10 00:06:25.180402 401.837130 kernel: Error: rpmsg_rpc rpmsg-dce: unwinding UVA to RDA translations! translation = 1
    3264962 2019/11/11 16:19:16.000000 401.8585 229 ECU1 SYS JOUR 1635 log error verbose 5 2019/11/10 00:06:25.181587 401.837298 kernel: Error: rpmsg_rpc rpmsg-dce: failed to translate all pointers for remote core!

    This log says, address passed from the application is invalid. 

    1. cat /sys/kernel/debug/remoteproc/remoteproc1/xxx  . Use these command , xxx are different sysfs for remoteproc1

    2. ls -l /dev/ should show rpmsg-dce node also to run ipumm

    3 In Gst ducati , for Error -5, it is  exiting . Refer the code

    RamPrasad

  • Hi RamPrasad,

    We get a separated log “seperate_log.7z”, could you please help to check again? And we also have following questions, could you please help on this?

    https://e2e.ti.com/cfs-file/__key/communityserver-discussions-components-files/791/seperate_5F00_log.7z

    1. You mentioned the error is because the address passed from the application is invalid, where TI get the address from? Is the invalid address cause the error DCE_EIPC_CALL_FAIL(-5)? Is there any reason can cause the invalid address? I mean from application side.
    2. Is there any suggestions for us to locate  this issue further?

    Thanks .

  • Hi Vicky,

    This log says addresses are wrong.

    3264961 2019/11/11 16:19:16.000000 401.8567 228 ECU1 SYS JOUR 1635 log error verbose 5 2019/11/10 00:06:25.180402 401.837130 kernel: Error: rpmsg_rpc rpmsg-dce: unwinding UVA to RDA translations! translation = 1
    3264962 2019/11/11 16:19:16.000000 401.8585 229 ECU1 SYS JOUR 1635 log error verbose 5 2019/11/10 00:06:25.181587 401.837298 kernel: Error: rpmsg_rpc rpmsg-dce: failed to translate all pointers for remote core!

    Address is passed from gst-ducati with VIDDEC3_process() invocations and resulted in the error.

    But if the issue can not be reproduced again consistently it is difficult rootcause what has gone wrong.

    RamPrasad

  • Hi RamPrasad,

    We will try to reproduce this issue, could you please let me know, which kind information will be helpful for your further analysis? We will check and provide once we reproduce this issue:

    1. Check the IPU2 status use following command:

               cat /sys/kernel/debug/remoteproc/remoteproc1/state

    1. Check if /dev/rpmsg-dce device node still exits use following command:

                ls /dev/rpmsg-dce

    1. Should we increate the gStreamer log level, which level is better for you?
    2. Should we enable any other specified component log?

    Please suggestion. Thanks.

  • Hi Vicky,

    Please try to get trace0 for remoteproc1 and collect dmesg logs

    Thanks

    RamPrasad