Tool/software: Linux
Hi TI team,
Video can't be played after play an unplayable file. Could you please check from TI side. Thanks.
Upload the files and log to https://transfer.harman.com/link/2UPy7qyfDmNv1GLv7BbjDo .
Issue can be always reproduced by following steps:
1. Play "unins000.dat" attached
2. Play "MP4_H264_AVC_baseline_L3.0_480X360_25FPS_AAC-LC_numb.MP4" attached.
check the behavior after play "MP4_H264_AVC_baseline_L3.0_480X360_25FPS_AAC-LC_numb.MP4".
Analysis from our point of view (it's correct in Ittiam's plugins)
1. Play “unins000.dat” which is not supported and error comes.
1117 2019/01/28 14:46:56.000000 2923.0259 43 ECU1 CrM PlEg 8931 log verbose 1 T8938 PlayEngine[Default] << play:item://127.0.0.1:13800/usb/820D%2D4DB3/videoitem/movie/unins000%2Edat/?ALBUM=&ARTIST=&BrowseType=video&GENRE=&ITEMID=4558&PATH=unins000%2Edat&SIZE=47733&TITLE=unins000&TYPE=video&URL=container%3A%2F%2F127%2E0%2E0%2E1%3A13800%2Fusb%2F820D%252D4DB3%2Fcollection%2F%2F%3FBrowseType%3Dvideo&ViewId=5
1267 2019/01/28 14:46:56.000000 2923.0341 126 ECU1 CrM HMPE 8931 log info verbose 1 T8938 CgstBasePlayer::play. found last play position; id:4558; last play position:0; path:/tmp/USB1-1.4-sdb1/unins000.dat
1354 2019/01/28 14:46:56.000000 2923.0662 52 ECU1 CrM API 8931 log info verbose 1 T8938 CgstPlayerApi:waitFor() Wait for NULL
1356 2019/01/28 14:46:56.000000 2923.0663 54 ECU1 CrM API 8931 log info verbose 1 T8938 CgstPlayerApi:waitFor() Obtained the play state:[NULL] pending:[VOID_PENDING] ret = 1
1429 2019/01/28 14:46:56.000000 2923.0710 77 ECU1 CrM API 8931 log info verbose 1 T8931 CgstPlayerApi::gstBusCallback() Got state-changed message: Element "URI Pipeline" state NULL --> READY
2422 2019/01/28 14:46:56.000000 2923.2272 209 ECU1 CrM API 8931 log info verbose 1 T8970 GSTLogs INFO GST_ERROR_SYSTEM gstelement.c(1860):gst_element_message_full:<asink> posted error message: The stream is in the wrong format.
2437 2019/01/28 14:46:56.000000 2923.2320 212 ECU1 CrM API 8931 log error verbose 1 T8931 CgstPlayerApi::gstBusCallback() Got error message from Element errcode=11, domain=1658 "asink": The stream is in the wrong format. Debug Info: /home/buildserver/work/jenkins/var/lib/jenkins/workspace/MMT2020_ADV_STABLE_APPLINUX_R4-2/project/elina-distro/build-cpm-mmt-2020/tmp/work/cortexa15hf-vfp-neon-elina-linux-gnueabi/gstreamer1.0-plugins-base/1.6.3-r0/gst-plugins-base-1.6.3/gst-libs/gst/audio/gstaudiobasesink.c(1139): gst_audio_base_sink_wait_event (): /GstPlayBin:URI Pipeline/GstPlaySink:playsink/GstBin:abin/GstAlsaSink:asink: Sink not negotiated before eos event.
2. Try to play video "MP4_H264_AVC_baseline_L3.0_480X360_25FPS_AAC-LC_numb.MP4" and we can see stop() called( stop will set the NULL state to pipeline ), and NULL state arrived successfully. Then set state to PLAYING for another video, but playback is not started this time.
1117 2019/01/28 14:46:56.000000 2923.0259 43 ECU1 CrM PlEg 8931 log verbose 1 T8938 PlayEngine[Default] << play:item://127.0.0.1:13800/usb/820D%2D4DB3/videoitem/movie/unins000%2Edat/?ALBUM=&ARTIST=&BrowseType=video&GENRE=&ITEMID=4558&PATH=unins000%2Edat&SIZE=47733&TITLE=unins000&TYPE=video&URL=container%3A%2F%2F127%2E0%2E0%2E1%3A13800%2Fusb%2F820D%252D4DB3%2Fcollection%2F%2F%3FBrowseType%3Dvideo&ViewId=5
1267 2019/01/28 14:46:56.000000 2923.0341 126 ECU1 CrM HMPE 8931 log info verbose 1 T8938 CgstBasePlayer::play. found last play position; id:4558; last play position:0; path:/tmp/USB1-1.4-sdb1/unins000.dat
1354 2019/01/28 14:46:56.000000 2923.0662 52 ECU1 CrM API 8931 log info verbose 1 T8938 CgstPlayerApi:waitFor() Wait for NULL
1356 2019/01/28 14:46:56.000000 2923.0663 54 ECU1 CrM API 8931 log info verbose 1 T8938 CgstPlayerApi:waitFor() Obtained the play state:[NULL] pending:[VOID_PENDING] ret = 1
1429 2019/01/28 14:46:56.000000 2923.0710 77 ECU1 CrM API 8931 log info verbose 1 T8931 CgstPlayerApi::gstBusCallback() Got state-changed message: Element "URI Pipeline" state NULL --> READY
2422 2019/01/28 14:46:56.000000 2923.2272 209 ECU1 CrM API 8931 log info verbose 1 T8970 GSTLogs INFO GST_ERROR_SYSTEM gstelement.c(1860):gst_element_message_full:<asink> posted error message: The stream is in the wrong format.
2437 2019/01/28 14:46:56.000000 2923.2320 212 ECU1 CrM API 8931 log error verbose 1 T8931 CgstPlayerApi::gstBusCallback() Got error message from Element errcode=11, domain=1658 "asink": The stream is in the wrong format. Debug Info: /home/buildserver/work/jenkins/var/lib/jenkins/workspace/MMT2020_ADV_STABLE_APPLINUX_R4-2/project/elina-distro/build-cpm-mmt-2020/tmp/work/cortexa15hf-vfp-neon-elina-linux-gnueabi/gstreamer1.0-plugins-base/1.6.3-r0/gst-plugins-base-1.6.3/gst-libs/gst/audio/gstaudiobasesink.c(1139): gst_audio_base_sink_wait_event (): /GstPlayBin:URI Pipeline/GstPlaySink:playsink/GstBin:abin/GstAlsaSink:asink: Sink not negotiated before eos event.
6127 2019/01/28 14:47:02.000000 2929.4422 42 ECU1 CrM API 8931 log info verbose 1 T8938 CgstPlayerApi:waitFor() Wait for NULL
6129 2019/01/28 14:47:02.000000 2929.4422 44 ECU1 CrM API 8931 log info verbose 1 T8938 CgstPlayerApi:waitFor() Obtained the play state:[NULL] pending:[VOID_PENDING] ret = 1
6130 2019/01/28 14:47:02.000000 2929.4423 202 ECU1 CrM HMPE 8931 log info verbose 1 T8938 CURIPlayer::setNext() set play state to GST_STATE_NULL
6145 2019/01/28 14:47:02.000000 2929.4427 205 ECU1 CrM Glue 8931 log debug verbose 1 T8938 MPIf: Processing play pos 0 / 185000
6181 2019/01/28 14:47:02.000000 2929.4474 78 ECU1 CrM API 8931 log info verbose 1 T8931 CgstPlayerApi::gstBusCallback() Got state-changed message: Element "URI Pipeline" state NULL --> READY
6339 2019/01/28 14:47:02.000000 2929.4578 136 ECU1 CrM API 8931 log info verbose 1 T8938 CgstPlayerApi:waitFor() Wait for PLAYING
9118 2019/01/28 14:47:03.000000 2930.4581 213 ECU1 CrM API 8931 log info verbose 1 T8938 CgstPlayerApi:waitFor() Obtained the play state:[READY] pending:[PLAYING] ret = 2
10081 2019/01/28 14:47:04.000000 2931.4585 242 ECU1 CrM API 8931 log info verbose 1 T8938 CgstPlayerApi:waitFor() Obtained the play state:[READY] pending:[PLAYING] ret = 2
11061 2019/01/28 14:47:05.000000 2932.4588 15 ECU1 CrM API 8931 log info verbose 1 T8938 CgstPlayerApi:waitFor() Obtained the play state:[READY] pending:[PLAYING] ret = 2
3. And we can see lots of VPE plugins warning while launching playback. If we don't play "unins000.dat" first, we play "MP4_H264_AVC_baseline_L3.0_480X360_25FPS_AAC-LC_numb.MP4" first, we never see VPE warning below. see "videoBlockissue_Correct.dlt" to check correct logs with no vpe warning.
8391 2019/01/28 14:47:03.000000 2929.7673 0 ECU1 CrM API 8931 log info verbose 1 T8976 GSTLogs WARN bufferpool gstbufferpool.c(300):do_alloc_buffer:<vpebufferpool1> alloc function failed
8401 2019/01/28 14:47:03.000000 2929.7779 5 ECU1 CrM API 8931 log info verbose 1 T8976 GSTLogs WARN bufferpool gstbufferpool.c(300):do_alloc_buffer:<vpebufferpool1> alloc function failed8444 2019/01/28 14:47:03.000000 2929.8100 20 ECU1 CrM API 8931 log info verbose 1 T8976 GSTLogs WARN bufferpool gstbufferpool.c(300):do_alloc_buffer:<vpebufferpool1> alloc function failed
8469 2019/01/28 14:47:03.000000 2929.8206 25 ECU1 CrM API 8931 log info verbose 1 T8976 GSTLogs WARN bufferpool gstbufferpool.c(300):do_alloc_buffer:<vpebufferpool1> alloc function failed
