Ruuzis
Posts: 49
Joined: Wed May 21, 2014 11:35 am

video_render ignoring frames after reconfiguration

Sun May 15, 2016 5:00 pm

Hi,

after changing my H264 streaming pipeline my Raspberry Pi OMX based playback pipeline started to fail after a resolution change happened. I tried to understand what is failing from the video core log, but I see no errors. What happens is that after the resolution change video_render component prints lines that it is ignoring the new frames. Any pointers?

Here is a snippet of the log with the last frame from the 640x480 fragment which plays fine and the switch to 1920x1080:

Code: Select all

2293393.751: video_decode:1:RIL:cb:entered with buffer = 0x1f5fc330, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f28a0
2293393.826: video_decode:1:RIL:cb:P time:391297, cb:0x1f5f28a0, ar:4/3, crop:0x0 640x480, interval:40000000, interlace:0,0,0
2293393.860: video_decode:1:RIL:output dec_frames_full:1f5f4578 out:0
2293393.899: decode: display frame 1f5fc330 T=391297 sts=0
2293393.918: video_render:0:RIL:display_image 1f5fc330 state 4
2293394.016: video_render:0:RIL: update arrived, dst 0 x 0
2293394.051: video_render:0:RIL: cb:0 tx:-1 cb=[img:1f5fc370 t:-1] inuse=[10]
2293394.132: video_render:0:RIL: doing update on dn:0 img:1f5fc330,other fs:1 tx:0 640x480-(0x15)800x450
2293394.290: video_render:0:RIL:return omx buffers:free 0
2293394.320: video_decode:1:RIL: disp_cb passed 1f5fc330/391297/0x10
2293406.158: video_render:0:RIL:cb:freeing cb:0 b:1f5fc370 t:-1
2293406.175: video_render:0:RIL:cb:sending 1f5fc370 to disp queue
2293406.196: video_render:0:RIL:cb:use=[00]
2293406.223: video_render:0:RIL:release_images:releasing 1f5fc370
2293406.251: video_render:0:RIL:return omx buffers:free 0
2293431.128: video_decode:1:EmptyThisBuffer(1f5f6180,1009,0->130)
2293431.147: video_decode:1: queueBuffer (input : 1009)
2293431.161: video_decode:1:qb RIL:1
2293431.199: video_decode:1:RIL: extract from fifo: len:1009 flags:10 time:395285
2293431.231: video_decode:1:RIL: decoding 1009 bytes, 395285us, flags 10, (cb:0x1f5f28bc)
2293431.249: video_decode:1:RIL: asking for more
2293431.265: h264pwr_enable(10000000,00000000)
2293431.285: h264pwr_enable newa newb (10000011,00000001)
2293431.325: MCI: start 00000000 00000080 00002970 00002960 00000063 00000000 00000000 00000064
2293431.393: MCI: end   00000001 00000080 00002d70 00002d60 00000064 00000000 00000000 00000000
2293431.409: h264pwr_disable(10000000,00000000)
2293431.425: h264pwr_disable newa newb (00000011,00000001)
2293431.465: video_decode:1:cb:consumed_input_buffer(1f5f6180,0b,0f) RIL:1
2293431.509: h264pwr_enable(00040800,00000000)
2293431.525: h264pwr_enable newa newb (00040811,00000001)
2293431.588: h264pwr_disable(00040800,00000000)
2293431.606: h264pwr_disable newa newb (00000011,00000001)
2293431.683: MSG: id=1f5fcb40, AUStart[size=608 AU=00000064] FrNum=0 FFPicId=-1 Grey=-1 Flags=IDR,Ref Display=16 DirOut=0000bb80 UD=100:1f5f28bc  Flags=IDR,Ref Display=16
2293431.748: MSG: id=1f5fcb40, Slice[size=192 AU=00000064] Data=36 bits into 00002970+000003ed in 55+00100000 Type=I FirstMB=0 DirIn=ffffffff
2293431.796: MSG: id=1f5fcb40, AUEnd[size=64 AU=00000064] PicId=0 Release=0
2293431.855: h264pwr_enable(0c1cd5e0,00000000)
2293431.874: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293431.893: h264pwr_open()
2293431.908: h264pwr_enable(04000800,00000000)
2293431.925: h264pwr_enable newa newb (0c1cddf1,00000001)
2293434.761: h264pwr_disable(04000800,00000000)
2293434.780: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293434.794: h264pwr_close() handle=6
2293434.818: h264pwr_disable(0c1cd5e0,00000000)
2293434.835: h264pwr_disable newa newb (00000011,00000001)
2293434.874: video_decode:1:RIL:cb:entered with buffer = 0x1f5fc370, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f28bc
2293434.948: video_decode:1:RIL:cb:IDR time:395285, cb:0x1f5f28bc, ar:4/3, crop:0x0 640x480, interval:40000000, interlace:0,0,0
2293434.982: video_decode:1:RIL:output dec_frames_full:1f5f45dc out:0
2293435.020: decode: display frame 1f5fc370 T=395285 sts=0
2293435.039: video_render:0:RIL:display_image 1f5fc370 state 4
2293435.141: video_render:0:RIL: update arrived, dst 0 x 0
2293435.177: video_render:0:RIL: cb:0 tx:-1 cb=[img:1f5fc330 t:-1] inuse=[10]
2293435.259: video_render:0:RIL: doing update on dn:0 img:1f5fc370,other fs:1 tx:0 640x480-(0x15)800x450
2293435.417: video_render:0:RIL:return omx buffers:free 0
2293435.447: video_decode:1:RIL: disp_cb passed 1f5fc370/395285/0x10
2293439.784: video_render:0:RIL:cb:freeing cb:0 b:1f5fc330 t:-1
2293439.803: video_render:0:RIL:cb:sending 1f5fc330 to disp queue
2293439.825: video_render:0:RIL:cb:use=[00]
2293439.854: video_render:0:RIL:release_images:releasing 1f5fc330
2293439.883: video_render:0:RIL:return omx buffers:free 0
2293505.300: video_decode:1:EmptyThisBuffer(1f5f6180,38,0->130)
2293505.320: video_decode:1: queueBuffer (input : 38)
2293505.334: video_decode:1:qb RIL:1
2293505.373: video_decode:1:RIL: extract from fifo: len:38 flags:0 time:402752
2293505.403: video_decode:1:RIL: decoding 38 bytes, 402752us, flags 0, (cb:0x1f5f28d8)
2293505.425: video_decode:1:RIL: asking for more
2293505.443: h264pwr_enable(10000000,00000000)
2293505.462: h264pwr_enable newa newb (10000011,00000001)
2293505.505: MCI: start 00000000 00000080 00002d90 00002d80 00000064 00000000 00000000 00000065
2293505.564: MCI: end   30000001 000000a0 00002dd4 00002dc0 00000065 00000000 00000000 00000000
2293505.579: h264pwr_disable(10000000,00000000)
2293505.597: h264pwr_disable newa newb (00000011,00000001)
2293505.634: video_decode:1:cb:consumed_input_buffer(1f5f6180,0b,0f) RIL:1
2293505.680: h264pwr_enable(00040800,00000000)
2293505.698: h264pwr_enable newa newb (00040811,00000001)
2293505.746: h264pwr_disable(00040800,00000000)
2293505.765: h264pwr_disable newa newb (00000011,00000001)
2293505.803: MSG: id=1f5fcb40, Ignore[size=32 AU=00000065] Opcode=67 Reason=00023005
2293507.946: video_decode:1:EmptyThisBuffer(1f5f6200,1463,0->130)
2293507.966: video_decode:1: queueBuffer (input : 1463)
2293507.981: video_decode:1:qb RIL:1
2293508.021: video_decode:1:RIL: extract from fifo: len:1463 flags:0 time:402752
2293508.053: video_decode:1:RIL: decoding 1463 bytes, 402752us, flags 0, (cb:0x1f5f28f4)
2293508.075: video_decode:1:RIL: asking for more
2293508.091: h264pwr_enable(10000000,00000000)
2293508.111: h264pwr_enable newa newb (10000011,00000001)
2293508.151: MCI: start 30000000 000000a0 00002dd4 00002dc0 00000065 00000000 00000000 00000066
2293508.221: MCI: end   10000001 00002e18 000033a0 00002de0 00000066 aebae900 00000018 00000000
2293508.238: h264pwr_disable(10000000,00000000)
2293508.255: h264pwr_disable newa newb (00000011,00000001)
2293508.293: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293508.338: h264pwr_enable(00040800,00000000)
2293508.354: h264pwr_enable newa newb (00040811,00000001)
2293508.538: h264pwr_disable(00040800,00000000)
2293508.558: h264pwr_disable newa newb (00000011,00000001)
2293508.596: MSG: id=1f5fcb40, Ignore[size=32 AU=00000065] Opcode=68 Reason=00023005
2293510.168: video_decode:1:EmptyThisBuffer(1f5f6180,1458,0->130)
2293510.188: video_decode:1: queueBuffer (input : 1458)
2293510.202: video_decode:1:qb RIL:1
2293510.243: video_decode:1:RIL: extract from fifo: len:1458 flags:0 time:402752
2293510.273: video_decode:1:RIL: decoding 1458 bytes, 402752us, flags 0, (cb:0x1f5f2910)
2293510.295: video_decode:1:RIL: asking for more
2293510.313: h264pwr_enable(10000000,00000000)
2293510.333: h264pwr_enable newa newb (10000011,00000001)
2293510.375: MCI: start 10000000 00002e18 000033a0 00002de0 00000066 aebae900 00000018 00000067
2293510.446: MCI: end   10000000 00005ba8 00003954 00002de0 00000066 ae000000 00000008 00000000
2293510.462: h264pwr_disable(10000000,00000000)
2293510.480: h264pwr_disable newa newb (00000011,00000001)
2293510.519: video_decode:1:cb:consumed_input_buffer(1f5f6180,0b,0f) RIL:1
2293512.037: video_decode:1:EmptyThisBuffer(1f5f6200,1458,0->130)
2293512.055: video_decode:1: queueBuffer (input : 1458)
2293512.068: video_decode:1:qb RIL:1
2293512.105: video_decode:1:RIL: extract from fifo: len:1458 flags:0 time:402752
2293512.138: video_decode:1:RIL: decoding 1458 bytes, 402752us, flags 0, (cb:0x1f5f292c)
2293512.157: video_decode:1:RIL: asking for more
2293512.177: h264pwr_enable(10000000,00000000)
2293512.194: h264pwr_enable newa newb (10000011,00000001)
2293512.236: MCI: start 10000000 00005ba8 00003954 00002de0 00000066 ae000000 00000008 00000067
2293512.307: MCI: end   10000000 00008938 00003f04 00002de0 00000066 aebaeb00 00000018 00000000
2293512.325: h264pwr_disable(10000000,00000000)
2293512.343: h264pwr_disable newa newb (00000011,00000001)
2293512.382: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293514.599: video_decode:1:EmptyThisBuffer(1f5f6180,1458,0->130)
2293514.617: video_decode:1: queueBuffer (input : 1458)
2293514.631: video_decode:1:qb RIL:1
2293514.668: video_decode:1:RIL: extract from fifo: len:1458 flags:0 time:402752
2293514.699: video_decode:1:RIL: decoding 1458 bytes, 402752us, flags 0, (cb:0x1f5f2948)
2293514.718: video_decode:1:RIL: asking for more
2293514.734: h264pwr_enable(10000000,00000000)
2293514.753: h264pwr_enable newa newb (10000011,00000001)
2293514.793: MCI: start 10000000 00008938 00003f04 00002de0 00000066 aebaeb00 00000018 00000067
2293514.862: MCI: end   10000000 0000b6c8 000044b8 00002de0 00000066 ba000000 00000008 00000000
2293514.879: h264pwr_disable(10000000,00000000)
2293514.896: h264pwr_disable newa newb (00000011,00000001)
2293514.935: video_decode:1:cb:consumed_input_buffer(1f5f6180,0b,0f) RIL:1
2293518.399: video_decode:1:EmptyThisBuffer(1f5f6200,537,0->130)
2293518.416: video_decode:1: queueBuffer (input : 537)
2293518.430: video_decode:1:qb RIL:1
2293518.465: video_decode:1:RIL: extract from fifo: len:537 flags:10 time:402752
2293518.498: video_decode:1:RIL: decoding 537 bytes, 402752us, flags 10, (cb:0x1f5f2964)
2293518.515: video_decode:1:RIL: asking for more
2293518.532: h264pwr_enable(10000000,00000000)
2293518.548: h264pwr_enable newa newb (10000011,00000001)
2293518.590: MCI: start 10000000 0000b6c8 000044b8 00002de0 00000066 ba000000 00000008 00000067
2293518.656: MCI: end   00000001 00000080 000046f0 000046e0 00000066 00000000 00000000 00000000
2293518.674: h264pwr_disable(10000000,00000000)
2293518.692: h264pwr_disable newa newb (00000011,00000001)
2293518.734: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293518.776: h264pwr_enable(00040800,00000000)
2293518.794: h264pwr_enable newa newb (00040811,00000001)
2293518.833: h264pwr_disable(00040800,00000000)
2293518.850: h264pwr_disable newa newb (00000011,00000001)
2293518.883: MSG: id=1f5fcb40, SeqEnd[size=64 AU=00000065] Display=None Release=0
2293518.929: h264pwr_enable(00040800,00000000)
2293518.947: h264pwr_enable newa newb (00040811,00000001)
2293519.038: video_decode:1:RIL: new image requirements (1920x1088(1920x1080)x2)
2293519.395: h264pwr_disable(00040800,00000000)
2293519.413: h264pwr_disable newa newb (00000011,00000001)
2293519.472: MSG: id=1f5fcb40, SeqStart[size=2304 AU=00000065] SpsId=1 Profile=4(100) Level=50 Size=120x68 Error=0
2293519.696: h264pwr_enable(00040800,00000000)
2293519.714: h264pwr_enable newa newb (00040811,00000001)
2293519.766: h264pwr_disable(00040800,00000000)
2293519.782: h264pwr_disable newa newb (00000011,00000001)
2293519.856: MSG: id=1f5fcb40, AUStart[size=608 AU=00000065] FrNum=0 FFPicId=-1 Grey=-1 Flags=IDR,Ref Display=16 DirOut=0004fb00 UD=101:1f5f28d8  Flags=IDR,Ref Display=16
2293519.926: MSG: id=1f5fcb40, Slice[size=192 AU=00000065] Data=40 bits into 00002df0+000018e2 in 55+00100000 Type=I FirstMB=0 DirIn=ffffffffЋƞ`_cފ2293519.993: MSG: id=1f5fcb40, AUEnd[size=64 AU=00000065] PicId=0 Release=None
2293520.042: h264pwr_enable(0c1cd5e0,00000000)
2293520.060: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293520.080: h264pwr_open()
2293520.095: h264pwr_enable(04000800,00000000)
2293520.112: h264pwr_enable newa newb (0c1cddf1,00000001)
2293534.242: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293534.261: video_decode:1: queueBuffer (input : 12)
2293534.275: video_decode:1:qb RIL:1
2293534.316: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:405434
2293534.347: video_decode:1:RIL: decoding 12 bytes, 405434us, flags 10, (cb:0x1f5f2980)
2293534.366: video_decode:1:RIL: asking for more
2293534.381: h264pwr_enable(10000000,00000000)
2293534.400: h264pwr_enable newa newb (1c1cddf1,00000001)
2293534.441: MCI: start 00000000 00000080 00004710 00004700 00000066 00000000 00000000 00000067
2293534.503: MCI: end   00000001 00000080 00004730 00004720 00000067 00000000 00000000 00000000
2293534.520: h264pwr_disable(10000000,00000000)
2293534.537: h264pwr_disable newa newb (0c1cddf1,00000001)
2293534.577: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293534.623: h264pwr_enable(00040800,00000000)
2293534.640: h264pwr_enable newa newb (0c1cddf1,00000001)
2293534.708: h264pwr_disable(00040800,00000000)
2293534.727: h264pwr_disable newa newb (0c1cddf1,00000001)
2293534.799: MSG: id=1f5fcb40, AUStart[size=608 AU=00000066] FrNum=1 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=00000000 UD=103:1f5f2980  Flags=Ref Display=16
2293534.975: MSG: id=1f5fcb40, Slice[size=256 AU=00000066] Data=36 bits into 00004710+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293535.024: MSG: id=1f5fcb40, AUEnd[size=64 AU=00000066] PicId=0 Release=0
2293538.711: h264pwr_disable(04000800,00000000)
2293538.729: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293538.742: h264pwr_close() handle=6
2293538.766: h264pwr_disable(0c1cd5e0,00000000)
2293538.782: h264pwr_disable newa newb (00000011,00000001)
2293538.823: video_decode:1:RIL:cb:entered with buffer = 0x1f6131f0, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f28d8
2293538.898: video_decode:1:RIL:cb:IDR time:402752, cb:0x1f5f28d8, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293538.930: video_decode:1:RIL:output dec_frames_full:1f5f4640 out:0
2293538.947: video_decode:1:RIL:resolution changing
2293538.964: h264pwr_enable(0c1cd5e0,00000000)
2293538.981: video_decode:1:cb:callback parameter changed 131,0
2293538.999: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293539.019: h264pwr_open()
2293539.036: h264pwr_enable(04000800,00000000)
2293539.054: h264pwr_enable newa newb (0c1cddf1,00000001)
2293540.933: video_render:0:GetParameter(2000001)
2293540.950: video_render:0:RIL:GetParameter(2000001)
2293541.895: video_render:0:SendCommand(2,90,1f568574) Disable 90
2293541.913: video_render:0:sending cmd 2 to 90
2293541.944: video_render:0:starting command 2
2293541.969: video_render:0:RIL:set_port_state 90 to state 1 (was 4)
2293541.995: video_render:0:RIL:set_port_state  90 state - now state 4, error 0
2293542.009: video_render:0:RIL:GetParameter(2000001)
2293542.040: video_render:0:RIL:set_port_state 90 to state 1 (was 4)
2293542.065: video_render:0:RIL:set_port_state  90 state - now state 4, error 0
2293542.082: video_render:0:RIL:GetParameter(2000001)
2293542.112: video_render:0:RIL:set_port_state 90 to state 1 (was 4)
2293542.138: video_render:0:RIL:set_port_state  90 state - now state 4, error 0
2293542.153: video_render:0:RIL:GetParameter(2000001)
2293542.171: video_render:0:RIL:change_port_state(1f5f0204)
2293542.186: video_render:0:RIL:removing current image 1f5fc370
2293542.220: video_render:0:RIL: cb:0 tx:-1 cb=[img:1f5fc370 t:-1] inuse=[10]
2293555.966: h264pwr_disable(04000800,00000000)
2293555.983: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293555.996: h264pwr_close() handle=6
2293556.022: h264pwr_disable(0c1cd5e0,00000000)
2293556.040: h264pwr_disable newa newb (00000011,00000001)
2293556.082: video_decode:1:RIL:cb:entered with buffer = 0x1f613230, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f2980
2293556.155: video_decode:1:RIL:cb:P time:405434, cb:0x1f5f2980, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293556.193: video_decode:1:RIL:output dec_frames_full:1f5f4640 out:0
2293557.480: video_render:0:RIL:cb:freeing cb:0 b:1f5fc370 t:-1
2293557.497: video_render:0:RIL:cb:sending 1f5fc370 to disp queue
2293557.519: video_render:0:RIL:cb:use=[00]
2293557.544: video_render:0:RIL:release_images:releasing 1f5fc370
2293557.596: video_render:0:RIL:set_port_state 90 to state 1 (was 1)
2293557.621: video_render:0:RIL:set_port_state  90 state - now state 1, error 0
2293557.636: video_render:0:RIL:GetParameter(2000001)
2293557.663: video_render:0:processingCommand=0
2293557.684: video_render:0:RIL:return omx buffers:free 0
2293558.007: video_decode:1:GetParameter(2000001)
2293558.022: video_decode:1:RIL:GetParameter(1f5f23c4)
2293558.326: video_decode:1:SendCommand(2,131,1f568574) Disable 131
2293558.346: video_decode:1:sending cmd 2 to 131
2293558.374: video_decode:1:RIL:output dec_frames_full:1f5f4640 out:0
2293558.398: video_decode:1:starting command 2
2293558.411: video_render:0:RIL:flush images
2293558.429: video_decode:1:RIL:GetParameter(1f5f23c4)
2293558.455: video_decode:1:processingCommand=0
2293558.742: video_render:0:GetParameter(7f000003)
2293558.766: video_render:0:ComponentTunnelRequest(90,clear)
2293558.780: video_render:0:RIL:GetParameter(7f000006)
2293558.800: video_decode:1:SetParameter(7f000009)
2293558.816: video_decode:1:RIL:SetParameter(7f000009)
2293559.090: video_decode:1:GetParameter(7f000003)
2293559.112: video_decode:1:ComponentTunnelRequest(131,clear)
2293559.128: video_decode:1:RIL:GetParameter(1f5f23c4)
2293560.207: video_decode:1:GetParameter(7f000003)
2293560.229: video_decode:1:ComponentTunnelRequest(131,setup)
2293560.251: video_decode:1:CTR: Output port 131 is not supplier
2293560.555: video_render:0:GetParameter(7f000003)
2293560.575: video_render:0:ComponentTunnelRequest(90,setup)
2293560.592: video_decode:1:GetParameter(2000001)
2293560.607: video_decode:1:RIL:GetParameter(1f5f23c4)
2293560.625: video_render:0:RIL:GetParameter(2000001)
2293560.643: video_decode:1:SetParameter(7f000009)
2293560.660: video_decode:1:RIL:SetParameter(7f000009)
2293560.678: video_decode:1:GetParameter(2000001)
2293560.694: video_decode:1:RIL:GetParameter(1f5f23c4)
2293560.712: video_decode:1:SetParameter(2000001)
2293560.726: video_decode:1:RIL:SetParameter(2000001)
2293560.739: video_decode:1:RIL:PortDef, port 131
2293560.752: video_decode:1:RIL: set output format 20
2293560.771: video_render:0:RIL:SetParameter(2000001)
2293560.786: video_render:0:RIL:SetPortFormat(Port 90)
2293560.795:  - compression format 0x0
2293560.807:  - color format 0x14
2293560.820:  - count 0, min 0
2293560.835: video_render:0:RIL:GetParameter(2000001)
2293560.851: video_decode:1:SetParameter(2000002)
2293560.871: video_decode:1:SP: Output port 131 is not supplier
2293560.892: video_render:0:CTR: Input port 90 is supplier
2293561.172: video_decode:1:GetParameter(2000001)
2293561.187: video_decode:1:RIL:GetParameter(1f5f23c4)
2293561.516: video_decode:1:SendCommand(3,131,1f568574) Enable 131
2293561.535: video_decode:1:sending cmd 3 to 131
2293561.566: video_decode:1:starting command 3
2293561.584: video_decode:1:RIL:GetParameter(1f5f23c4)
2293561.610: video_decode:1:processingCommand=0
2293561.907: video_render:0:GetParameter(2000001)
2293561.923: video_render:0:RIL:GetParameter(2000001)
2293562.200: video_render:0:SendCommand(3,90,1f568574) Enable 90
2293562.218: video_render:0:sending cmd 3 to 90
2293562.246: video_render:0:starting command 3
2293562.268: video_render:0:RIL:set_port_state 90 to state 4 (was 1)
2293562.294: video_render:0:RIL:set_port_state  90 state - now state 1, error 0
2293562.321: video_render:0:RIL:set_port_state 90 to state 4 (was 1)
2293562.344: video_render:0:RIL:set_port_state  90 state - now state 1, error 0
2293562.363: video_render:0:RIL:change_port_state(1f5f0204)
2293562.391: video_render:0:RIL:set_port_state 90 to state 4 (was 4)
2293562.416: video_render:0:RIL:set_port_state  90 state - now state 4, error 0
2293562.430: video_render:0:RIL:GetParameter(2000001)
2293562.455: video_render:0:processingCommand=0
2293574.128: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293574.145: video_decode:1: queueBuffer (input : 12)
2293574.157: video_decode:1:qb RIL:1
2293574.194: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:409455
2293574.227: video_decode:1:RIL: decoding 12 bytes, 409455us, flags 10, (cb:0x1f5f299c)
2293574.247: video_decode:1:RIL: asking for more
2293574.265: h264pwr_enable(10000000,00000000)
2293574.281: video_decode:1:RIL:output dec_frames_full:1f5f4640 out:0
2293574.299: h264pwr_enable newa newb (10000011,00000001)
2293574.341: MCI: start 00000000 00000080 00004750 00004740 00000067 00000000 00000000 00000068
2293574.364: decode: display frame 1f6131f0 T=402752 sts=0
2293574.391: video_render:0:RIL:display_image 1f6131f0 state 4
2293574.434: MCI: end   00000001 00000080 00004770 00004760 00000068 00000000 00000000 00000000
2293574.450: video_render:0:RIL: update ignored, no display
2293574.466: h264pwr_disable(10000000,00000000)
2293574.479: video_render:0:RIL:return omx buffers:free 0
2293574.497: h264pwr_disable newa newb (00000011,00000001)
2293574.519: video_decode:1:RIL: disp_cb passed 1f6131f0/402752/0x10
2293574.543: video_decode:1:RIL:output dec_frames_full:1f5f46a4 out:0
2293574.577: decode: display frame 1f613230 T=405434 sts=0
2293574.596: video_render:0:RIL:display_image 1f613230 state 4
2293574.614: video_render:0:RIL:skipping buffer 1f6131f0 in favour of 1f613230
2293574.652: video_render:0:RIL: update ignored, no display
2293574.668: video_render:0:RIL:return omx buffers:free 0
2293574.694: video_decode:1:RIL: disp_cb passed 1f613230/405434/0x10
2293574.736: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293574.780: h264pwr_enable(00040800,00000000)
2293574.796: h264pwr_enable newa newb (00040811,00000001)
2293574.862: h264pwr_disable(00040800,00000000)
2293574.881: h264pwr_disable newa newb (00000011,00000001)
2293574.954: MSG: id=1f5fcb40, AUStart[size=608 AU=00000067] FrNum=2 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=0004fb00 UD=104:1f5f299c  Flags=Ref Display=16
2293575.132: MSG: id=1f5fcb40, Slice[size=256 AU=00000067] Data=36 bits into 00004750+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293575.180: MSG: id=1f5fcb40, AUEnd[size=64 AU=00000067] PicId=0 Release=0
2293575.230: h264pwr_enable(0c1cd5e0,00000000)
2293575.248: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293575.266: h264pwr_open()
2293575.282: h264pwr_enable(04000800,00000000)
2293575.298: h264pwr_enable newa newb (0c1cddf1,00000001)
2293592.202: h264pwr_disable(04000800,00000000)
2293592.221: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293592.235: h264pwr_close() handle=6
2293592.259: h264pwr_disable(0c1cd5e0,00000000)
2293592.275: h264pwr_disable newa newb (00000011,00000001)
2293592.316: video_decode:1:RIL:cb:entered with buffer = 0x1f6131f0, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f299c
2293592.391: video_decode:1:RIL:cb:P time:409455, cb:0x1f5f299c, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293592.424: video_decode:1:RIL:output dec_frames_full:1f5f4708 out:0
2293592.459: decode: display frame 1f6131f0 T=409455 sts=0
2293592.477: video_render:0:RIL:display_image 1f6131f0 state 4
2293592.496: video_render:0:RIL:skipping buffer 1f613230 in favour of 1f6131f0
2293592.536: video_render:0:RIL: update ignored, no display
2293592.554: video_render:0:RIL:return omx buffers:free 0
2293592.583: video_decode:1:RIL: disp_cb passed 1f6131f0/409455/0x10
2293612.393: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293612.410: video_decode:1: queueBuffer (input : 12)
2293612.422: video_decode:1:qb RIL:1
2293612.458: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:413378
2293612.491: video_decode:1:RIL: decoding 12 bytes, 413378us, flags 10, (cb:0x1f5f29b8)
2293612.511: video_decode:1:RIL: asking for more
2293612.529: h264pwr_enable(10000000,00000000)
2293612.544: h264pwr_enable newa newb (10000011,00000001)
2293612.587: MCI: start 00000000 00000080 00004790 00004780 00000068 00000000 00000000 00000069
2293612.651: MCI: end   00000001 00000080 000047b0 000047a0 00000069 00000000 00000000 00000000
2293612.669: h264pwr_disable(10000000,00000000)
2293612.687: h264pwr_disable newa newb (00000011,00000001)
2293612.726: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293612.768: h264pwr_enable(00040800,00000000)
2293612.786: h264pwr_enable newa newb (00040811,00000001)
2293612.849: h264pwr_disable(00040800,00000000)
2293612.867: h264pwr_disable newa newb (00000011,00000001)
2293612.936: MSG: id=1f5fcb40, AUStart[size=608 AU=00000068] FrNum=3 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=00000000 UD=105:1f5f29b8  Flags=Ref Display=16
2293613.116: MSG: id=1f5fcb40, Slice[size=256 AU=00000068] Data=36 bits into 00004790+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293613.160: MSG: id=1f5fcb40, AUEnd[size=64 AU=00000068] PicId=0 Release=0
2293613.210: h264pwr_enable(0c1cd5e0,00000000)
2293613.226: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293613.246: h264pwr_open()
2293613.262: h264pwr_enable(04000800,00000000)
2293613.280: h264pwr_enable newa newb (0c1cddf1,00000001)
2293630.180: h264pwr_disable(04000800,00000000)
2293630.198: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293630.210: h264pwr_close() handle=6
2293630.235: h264pwr_disable(0c1cd5e0,00000000)
2293630.253: h264pwr_disable newa newb (00000011,00000001)
2293630.295: video_decode:1:RIL:cb:entered with buffer = 0x1f613230, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f29b8
2293630.367: video_decode:1:RIL:cb:P time:413378, cb:0x1f5f29b8, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293630.401: video_decode:1:RIL:output dec_frames_full:1f5f476c out:0
2293630.439: decode: display frame 1f613230 T=413378 sts=0
2293630.459: video_render:0:RIL:display_image 1f613230 state 4
2293630.477: video_render:0:RIL:skipping buffer 1f6131f0 in favour of 1f613230
2293630.517: video_render:0:RIL: update ignored, no display
2293630.533: video_render:0:RIL:return omx buffers:free 0
2293630.561: video_decode:1:RIL: disp_cb passed 1f613230/413378/0x10
2293651.640: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293651.658: video_decode:1: queueBuffer (input : 12)
2293651.671: video_decode:1:qb RIL:1
2293651.707: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:417301
2293651.739: video_decode:1:RIL: decoding 12 bytes, 417301us, flags 10, (cb:0x1f5f29d4)
2293651.755: video_decode:1:RIL: asking for more
2293651.772: h264pwr_enable(10000000,00000000)
2293651.791: h264pwr_enable newa newb (10000011,00000001)
2293651.832: MCI: start 00000000 00000080 000047d0 000047c0 00000069 00000000 00000000 0000006a
2293651.894: MCI: end   00000001 00000080 000047f0 000047e0 0000006a 00000000 00000000 00000000
2293651.910: h264pwr_disable(10000000,00000000)
2293651.927: h264pwr_disable newa newb (00000011,00000001)
2293651.965: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293652.008: h264pwr_enable(00040800,00000000)
2293652.025: h264pwr_enable newa newb (00040811,00000001)
2293652.091: h264pwr_disable(00040800,00000000)
2293652.110: h264pwr_disable newa newb (00000011,00000001)
2293652.183: MSG: id=1f5fcb40, AUStart[size=608 AU=00000069] FrNum=4 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=0004fb00 UD=106:1f5f29d4  Flags=Ref Display=16
2293652.360: MSG: id=1f5fcb40, Slice[size=256 AU=00000069] Data=36 bits into 000047d0+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293652.409: MSG: id=1f5fcb40, AUEnd[size=64 AU=00000069] PicId=0 Release=0
2293652.460: h264pwr_enable(0c1cd5e0,00000000)
2293652.478: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293652.496: h264pwr_open()
2293652.511: h264pwr_enable(04000800,00000000)
2293652.528: h264pwr_enable newa newb (0c1cddf1,00000001)
2293669.430: h264pwr_disable(04000800,00000000)
2293669.449: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293669.463: h264pwr_close() handle=6
2293669.488: h264pwr_disable(0c1cd5e0,00000000)
2293669.505: h264pwr_disable newa newb (00000011,00000001)
2293669.545: video_decode:1:RIL:cb:entered with buffer = 0x1f6131f0, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f29d4
2293669.620: video_decode:1:RIL:cb:P time:417301, cb:0x1f5f29d4, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293669.651: video_decode:1:RIL:output dec_frames_full:1f5f47d0 out:0
2293669.688: decode: display frame 1f6131f0 T=417301 sts=0
2293669.706: video_render:0:RIL:display_image 1f6131f0 state 4
2293669.726: video_render:0:RIL:skipping buffer 1f613230 in favour of 1f6131f0
2293669.764: video_render:0:RIL: update ignored, no display
2293669.782: video_render:0:RIL:return omx buffers:free 0
2293669.821: video_decode:1:RIL: disp_cb passed 1f6131f0/417301/0x10
2293691.067: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293691.084: video_decode:1: queueBuffer (input : 12)
2293691.095: video_decode:1:qb RIL:1
2293691.131: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:421261
2293691.164: video_decode:1:RIL: decoding 12 bytes, 421261us, flags 10, (cb:0x1f5f29f0)
2293691.184: video_decode:1:RIL: asking for more
2293691.202: h264pwr_enable(10000000,00000000)
2293691.219: h264pwr_enable newa newb (10000011,00000001)
2293691.261: MCI: start 00000000 00000080 00004810 00004800 0000006a 00000000 00000000 0000006b
2293691.325: MCI: end   00000001 00000080 00004830 00004820 0000006b 00000000 00000000 00000000
2293691.343: h264pwr_disable(10000000,00000000)
2293691.361: h264pwr_disable newa newb (00000011,00000001)
2293691.400: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293691.442: h264pwr_enable(00040800,00000000)
2293691.460: h264pwr_enable newa newb (00040811,00000001)
2293691.522: h264pwr_disable(00040800,00000000)
2293691.539: h264pwr_disable newa newb (00000011,00000001)
2293691.610: MSG: id=1f5fcb40, AUStart[size=608 AU=0000006a] FrNum=5 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=00000000 UD=107:1f5f29f0  Flags=Ref Display=16
2293691.789: MSG: id=1f5fcb40, Slice[size=256 AU=0000006a] Data=36 bits into 00004810+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293691.832: MSG: id=1f5fcb40, AUEnd[size=64 AU=0000006a] PicId=0 Release=0
2293691.883: h264pwr_enable(0c1cd5e0,00000000)
2293691.900: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293691.922: h264pwr_open()
2293691.938: h264pwr_enable(04000800,00000000)
2293691.956: h264pwr_enable newa newb (0c1cddf1,00000001)
2293708.859: h264pwr_disable(04000800,00000000)
2293708.876: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293708.888: h264pwr_close() handle=6
2293708.914: h264pwr_disable(0c1cd5e0,00000000)
2293708.932: h264pwr_disable newa newb (00000011,00000001)
2293708.974: video_decode:1:RIL:cb:entered with buffer = 0x1f613230, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f29f0
2293709.047: video_decode:1:RIL:cb:P time:421261, cb:0x1f5f29f0, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293709.081: video_decode:1:RIL:output dec_frames_full:1f5f4834 out:0
2293709.119: decode: display frame 1f613230 T=421261 sts=0
2293709.139: video_render:0:RIL:display_image 1f613230 state 4
2293709.156: video_render:0:RIL:skipping buffer 1f6131f0 in favour of 1f613230
2293709.197: video_render:0:RIL: update ignored, no display
2293709.214: video_render:0:RIL:return omx buffers:free 0
2293709.241: video_decode:1:RIL: disp_cb passed 1f613230/421261/0x10
2293728.762: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293728.780: video_decode:1: queueBuffer (input : 12)
2293728.793: video_decode:1:qb RIL:1
2293728.830: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:425176
2293728.861: video_decode:1:RIL: decoding 12 bytes, 425176us, flags 10, (cb:0x1f5f2a0c)
2293728.880: video_decode:1:RIL: asking for more
2293728.897: h264pwr_enable(10000000,00000000)
2293728.916: h264pwr_enable newa newb (10000011,00000001)
2293728.956: MCI: start 00000000 00000080 00004850 00004840 0000006b 00000000 00000000 0000006c
2293729.014: MCI: end   00000001 00000080 00004870 00004860 0000006c 00000000 00000000 00000000
2293729.030: h264pwr_disable(10000000,00000000)
2293729.046: h264pwr_disable newa newb (00000011,00000001)
2293729.085: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293729.129: h264pwr_enable(00040800,00000000)
2293729.145: h264pwr_enable newa newb (00040811,00000001)
2293729.210: h264pwr_disable(00040800,00000000)
2293729.229: h264pwr_disable newa newb (00000011,00000001)
2293729.301: MSG: id=1f5fcb40, AUStart[size=608 AU=0000006b] FrNum=6 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=0004fb00 UD=108:1f5f2a0c  Flags=Ref Display=16
2293729.479: MSG: id=1f5fcb40, Slice[size=256 AU=0000006b] Data=36 bits into 00004850+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293729.530: MSG: id=1f5fcb40, AUEnd[size=64 AU=0000006b] PicId=0 Release=0
2293729.585: h264pwr_enable(0c1cd5e0,00000000)
2293729.603: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293729.624: h264pwr_open()
2293729.639: h264pwr_enable(04000800,00000000)
2293729.656: h264pwr_enable newa newb (0c1cddf1,00000001)
2293746.567: h264pwr_disable(04000800,00000000)
2293746.585: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293746.599: h264pwr_close() handle=6
2293746.623: h264pwr_disable(0c1cd5e0,00000000)
2293746.639: h264pwr_disable newa newb (00000011,00000001)
2293746.681: video_decode:1:RIL:cb:entered with buffer = 0x1f6131f0, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f2a0c
2293746.755: video_decode:1:RIL:cb:P time:425176, cb:0x1f5f2a0c, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293746.811: video_decode:1:RIL:output dec_frames_full:1f5f4898 out:0
2293746.847: decode: display frame 1f6131f0 T=425176 sts=0
2293746.865: video_render:0:RIL:display_image 1f6131f0 state 4
2293746.885: video_render:0:RIL:skipping buffer 1f613230 in favour of 1f6131f0
2293746.923: video_render:0:RIL: update ignored, no display
2293746.941: video_render:0:RIL:return omx buffers:free 0
2293746.970: video_decode:1:RIL: disp_cb passed 1f6131f0/425176/0x10
2293769.668: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293769.684: video_decode:1: queueBuffer (input : 12)
2293769.697: video_decode:1:qb RIL:1
2293769.733: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:429178
2293769.767: video_decode:1:RIL: decoding 12 bytes, 429178us, flags 10, (cb:0x1f5f2a28)
2293769.787: video_decode:1:RIL: asking for more
2293769.806: h264pwr_enable(10000000,00000000)
2293769.822: h264pwr_enable newa newb (10000011,00000001)
2293769.865: MCI: start 00000000 00000080 00004890 00004880 0000006c 00000000 00000000 0000006d
2293769.926: MCI: end   00000001 00000080 000048b0 000048a0 0000006d 00000000 00000000 00000000
2293769.943: h264pwr_disable(10000000,00000000)
2293769.962: h264pwr_disable newa newb (00000011,00000001)
2293770.000: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293770.042: h264pwr_enable(00040800,00000000)
2293770.059: h264pwr_enable newa newb (00040811,00000001)
2293770.122: h264pwr_disable(00040800,00000000)
2293770.140: h264pwr_disable newa newb (00000011,00000001)
2293770.210: MSG: id=1f5fcb40, AUStart[size=608 AU=0000006c] FrNum=7 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=00000000 UD=109:1f5f2a28  Flags=Ref Display=16
2293770.392: MSG: id=1f5fcb40, Slice[size=256 AU=0000006c] Data=36 bits into 00004890+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293770.440: MSG: id=1f5fcb40, AUEnd[size=64 AU=0000006c] PicId=0 Release=0
2293770.496: h264pwr_enable(0c1cd5e0,00000000)
2293770.514: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293770.536: h264pwr_open()
2293770.552: h264pwr_enable(04000800,00000000)
2293770.571: h264pwr_enable newa newb (0c1cddf1,00000001)
2293787.479: h264pwr_disable(04000800,00000000)
2293787.497: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293787.509: h264pwr_close() handle=6
2293787.536: h264pwr_disable(0c1cd5e0,00000000)
2293787.553: h264pwr_disable newa newb (00000011,00000001)
2293787.596: video_decode:1:RIL:cb:entered with buffer = 0x1f613230, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f2a28
2293787.668: video_decode:1:RIL:cb:P time:429178, cb:0x1f5f2a28, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293787.702: video_decode:1:RIL:output dec_frames_full:1f5f48fc out:0
2293787.740: decode: display frame 1f613230 T=429178 sts=0
2293787.760: video_render:0:RIL:display_image 1f613230 state 4
2293787.778: video_render:0:RIL:skipping buffer 1f6131f0 in favour of 1f613230
2293787.819: video_render:0:RIL: update ignored, no display
2293787.835: video_render:0:RIL:return omx buffers:free 0
2293787.863: video_decode:1:RIL: disp_cb passed 1f613230/429178/0x10
2293809.232: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293809.250: video_decode:1: queueBuffer (input : 12)
2293809.263: video_decode:1:qb RIL:1
2293809.300: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:433131
2293809.332: video_decode:1:RIL: decoding 12 bytes, 433131us, flags 10, (cb:0x1f5f2a44)
2293809.349: video_decode:1:RIL: asking for more
2293809.367: h264pwr_enable(10000000,00000000)
2293809.387: h264pwr_enable newa newb (10000011,00000001)
2293809.428: MCI: start 00000000 00000080 000048d0 000048c0 0000006d 00000000 00000000 0000006e
2293809.488: MCI: end   00000001 00000080 000048f0 000048e0 0000006e 00000000 00000000 00000000
2293809.503: h264pwr_disable(10000000,00000000)
2293809.521: h264pwr_disable newa newb (00000011,00000001)
2293809.558: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293809.602: h264pwr_enable(00040800,00000000)
2293809.620: h264pwr_enable newa newb (00040811,00000001)
2293809.687: h264pwr_disable(00040800,00000000)
2293809.707: h264pwr_disable newa newb (00000011,00000001)
2293809.783: MSG: id=1f5fcb40, AUStart[size=608 AU=0000006d] FrNum=8 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=0004fb00 UD=110:1f5f2a44  Flags=Ref Display=16
2293809.962: MSG: id=1f5fcb40, Slice[size=256 AU=0000006d] Data=36 bits into 000048d0+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293810.015: MSG: id=1f5fcb40, AUEnd[size=64 AU=0000006d] PicId=0 Release=0
2293810.074: h264pwr_enable(0c1cd5e0,00000000)
2293810.093: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293810.113: h264pwr_open()
2293810.128: h264pwr_enable(04000800,00000000)
2293810.146: h264pwr_enable newa newb (0c1cddf1,00000001)
2293827.056: h264pwr_disable(04000800,00000000)
2293827.076: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293827.091: h264pwr_close() handle=6
2293827.116: h264pwr_disable(0c1cd5e0,00000000)
2293827.134: h264pwr_disable newa newb (00000011,00000001)
2293827.175: video_decode:1:RIL:cb:entered with buffer = 0x1f6131f0, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f2a44
2293827.251: video_decode:1:RIL:cb:P time:433131, cb:0x1f5f2a44, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293827.281: video_decode:1:RIL:output dec_frames_full:1f5f4960 out:0
2293827.318: decode: display frame 1f6131f0 T=433131 sts=0
2293827.338: video_render:0:RIL:display_image 1f6131f0 state 4
2293827.359: video_render:0:RIL:skipping buffer 1f613230 in favour of 1f6131f0
2293827.396: video_render:0:RIL: update ignored, no display
2293827.416: video_render:0:RIL:return omx buffers:free 0
2293827.446: video_decode:1:RIL: disp_cb passed 1f6131f0/433131/0x10
2293848.686: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293848.704: video_decode:1: queueBuffer (input : 12)
2293848.715: video_decode:1:qb RIL:1
2293848.750: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:437073
2293848.784: video_decode:1:RIL: decoding 12 bytes, 437073us, flags 10, (cb:0x1f5f2a60)
2293848.806: video_decode:1:RIL: asking for more
2293848.826: h264pwr_enable(10000000,00000000)
2293848.845: h264pwr_enable newa newb (10000011,00000001)
2293848.889: MCI: start 00000000 00000080 00004910 00004900 0000006e 00000000 00000000 0000006f
2293848.954: MCI: end   00000001 00000080 00004930 00004920 0000006f 00000000 00000000 00000000
2293848.973: h264pwr_disable(10000000,00000000)
2293848.992: h264pwr_disable newa newb (00000011,00000001)
2293849.033: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293849.075: h264pwr_enable(00040800,00000000)
2293849.095: h264pwr_enable newa newb (00040811,00000001)
2293849.157: h264pwr_disable(00040800,00000000)
2293849.174: h264pwr_disable newa newb (00000011,00000001)
2293849.245: MSG: id=1f5fcb40, AUStart[size=608 AU=0000006e] FrNum=9 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=00000000 UD=111:1f5f2a60  Flags=Ref Display=16
2293849.429: MSG: id=1f5fcb40, Slice[size=256 AU=0000006e] Data=36 bits into 00004910+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293849.477: MSG: id=1f5fcb40, AUEnd[size=64 AU=0000006e] PicId=0 Release=0
2293849.536: h264pwr_enable(0c1cd5e0,00000000)
2293849.553: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293849.575: h264pwr_open()
2293849.593: h264pwr_enable(04000800,00000000)
2293849.612: h264pwr_enable newa newb (0c1cddf1,00000001)
2293866.518: h264pwr_disable(04000800,00000000)
2293866.535: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293866.548: h264pwr_close() handle=6
2293866.574: h264pwr_disable(0c1cd5e0,00000000)
2293866.592: h264pwr_disable newa newb (00000011,00000001)
2293866.634: video_decode:1:RIL:cb:entered with buffer = 0x1f613230, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f2a60
2293866.706: video_decode:1:RIL:cb:P time:437073, cb:0x1f5f2a60, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293866.742: video_decode:1:RIL:output dec_frames_full:1f5f49c4 out:0
2293866.780: decode: display frame 1f613230 T=437073 sts=0
2293866.823: video_render:0:RIL:display_image 1f613230 state 4
2293866.841: video_render:0:RIL:skipping buffer 1f6131f0 in favour of 1f613230
2293866.880: video_render:0:RIL: update ignored, no display
2293866.897: video_render:0:RIL:return omx buffers:free 0
2293866.925: video_decode:1:RIL: disp_cb passed 1f613230/437073/0x10
2293887.369: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293887.387: video_decode:1: queueBuffer (input : 12)
2293887.401: video_decode:1:qb RIL:1
2293887.436: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:441050
2293887.466: video_decode:1:RIL: decoding 12 bytes, 441050us, flags 10, (cb:0x1f5f2a7c)
2293887.485: video_decode:1:RIL: asking for more
2293887.502: h264pwr_enable(10000000,00000000)
2293887.520: h264pwr_enable newa newb (10000011,00000001)
2293887.560: MCI: start 00000000 00000080 00004950 00004940 0000006f 00000000 00000000 00000070
2293887.622: MCI: end   00000001 00000080 00004970 00004960 00000070 00000000 00000000 00000000
2293887.638: h264pwr_disable(10000000,00000000)
2293887.654: h264pwr_disable newa newb (00000011,00000001)
2293887.693: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293887.737: h264pwr_enable(00040800,00000000)
2293887.753: h264pwr_enable newa newb (00040811,00000001)
2293887.818: h264pwr_disable(00040800,00000000)
2293887.836: h264pwr_disable newa newb (00000011,00000001)
2293887.910: MSG: id=1f5fcb40, AUStart[size=608 AU=0000006f] FrNum=10 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=0004fb00 UD=112:1f5f2a7c  Flags=Ref Display=16
2293888.085: MSG: id=1f5fcb40, Slice[size=256 AU=0000006f] Data=36 bits into 00004950+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293888.130: MSG: id=1f5fcb40, AUEnd[size=64 AU=0000006f] PicId=0 Release=0
2293888.178: h264pwr_enable(0c1cd5e0,00000000)
2293888.195: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293888.215: h264pwr_open()
2293888.232: h264pwr_enable(04000800,00000000)
2293888.250: h264pwr_enable newa newb (0c1cddf1,00000001)
2293905.151: h264pwr_disable(04000800,00000000)
2293905.169: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293905.181: h264pwr_close() handle=6
2293905.206: h264pwr_disable(0c1cd5e0,00000000)
2293905.224: h264pwr_disable newa newb (00000011,00000001)
2293905.267: video_decode:1:RIL:cb:entered with buffer = 0x1f6131f0, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f2a7c
2293905.338: video_decode:1:RIL:cb:P time:441050, cb:0x1f5f2a7c, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293905.374: video_decode:1:RIL:output dec_frames_full:1f5f4a28 out:0
2293905.413: decode: display frame 1f6131f0 T=441050 sts=0
2293905.433: video_render:0:RIL:display_image 1f6131f0 state 4
2293905.451: video_render:0:RIL:skipping buffer 1f613230 in favour of 1f6131f0
2293905.491: video_render:0:RIL: update ignored, no display
2293905.508: video_render:0:RIL:return omx buffers:free 0
2293905.536: video_decode:1:RIL: disp_cb passed 1f6131f0/441050/0x10
2293927.777: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293927.796: video_decode:1: queueBuffer (input : 12)
2293927.809: video_decode:1:qb RIL:1
2293927.847: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:444988
2293927.879: video_decode:1:RIL: decoding 12 bytes, 444988us, flags 10, (cb:0x1f5f2a98)
2293927.897: video_decode:1:RIL: asking for more
2293927.914: h264pwr_enable(10000000,00000000)
2293927.933: h264pwr_enable newa newb (10000011,00000001)
2293927.975: MCI: start 00000000 00000080 00004990 00004980 00000070 00000000 00000000 00000071
2293928.039: MCI: end   00000001 00000080 000049b0 000049a0 00000071 00000000 00000000 00000000
2293928.054: h264pwr_disable(10000000,00000000)
2293928.071: h264pwr_disable newa newb (00000011,00000001)
2293928.109: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293928.151: h264pwr_enable(00040800,00000000)
2293928.169: h264pwr_enable newa newb (00040811,00000001)
2293928.233: h264pwr_disable(00040800,00000000)
2293928.252: h264pwr_disable newa newb (00000011,00000001)
2293928.326: MSG: id=1f5fcb40, AUStart[size=608 AU=00000070] FrNum=11 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=00000000 UD=113:1f5f2a98  Flags=Ref Display=16
2293928.506: MSG: id=1f5fcb40, Slice[size=256 AU=00000070] Data=36 bits into 00004990+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293928.552: MSG: id=1f5fcb40, AUEnd[size=64 AU=00000070] PicId=0 Release=0
2293928.608: h264pwr_enable(0c1cd5e0,00000000)
2293928.625: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293928.647: h264pwr_open()
2293928.664: h264pwr_enable(04000800,00000000)
2293928.683: h264pwr_enable newa newb (0c1cddf1,00000001)
2293945.588: h264pwr_disable(04000800,00000000)
2293945.605: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293945.618: h264pwr_close() handle=6
2293945.643: h264pwr_disable(0c1cd5e0,00000000)
2293945.661: h264pwr_disable newa newb (00000011,00000001)
2293945.703: video_decode:1:RIL:cb:entered with buffer = 0x1f613230, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f2a98
2293945.776: video_decode:1:RIL:cb:P time:444988, cb:0x1f5f2a98, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293945.812: video_decode:1:RIL:output dec_frames_full:1f5f4a8c out:0
2293945.850: decode: display frame 1f613230 T=444988 sts=0
2293945.870: video_render:0:RIL:display_image 1f613230 state 4
2293945.887: video_render:0:RIL:skipping buffer 1f6131f0 in favour of 1f613230
2293945.927: video_render:0:RIL: update ignored, no display
2293945.944: video_render:0:RIL:return omx buffers:free 0
2293945.971: video_decode:1:RIL: disp_cb passed 1f613230/444988/0x10
2293966.043: video_decode:1:EmptyThisBuffer(1f5f6200,12,0->130)
2293966.061: video_decode:1: queueBuffer (input : 12)
2293966.075: video_decode:1:qb RIL:1
2293966.112: video_decode:1:RIL: extract from fifo: len:12 flags:10 time:448917
2293966.142: video_decode:1:RIL: decoding 12 bytes, 448917us, flags 10, (cb:0x1f5f2ab4)
2293966.161: video_decode:1:RIL: asking for more
2293966.178: h264pwr_enable(10000000,00000000)
2293966.198: h264pwr_enable newa newb (10000011,00000001)
2293966.238: MCI: start 00000000 00000080 000049d0 000049c0 00000071 00000000 00000000 00000072
2293966.305: MCI: end   00000001 00000080 000049f0 000049e0 00000072 00000000 00000000 00000000
2293966.321: h264pwr_disable(10000000,00000000)
2293966.338: h264pwr_disable newa newb (00000011,00000001)
2293966.377: video_decode:1:cb:consumed_input_buffer(1f5f6200,0b,0f) RIL:1
2293966.421: h264pwr_enable(00040800,00000000)
2293966.437: h264pwr_enable newa newb (00040811,00000001)
2293966.504: h264pwr_disable(00040800,00000000)
2293966.523: h264pwr_disable newa newb (00000011,00000001)
2293966.597: MSG: id=1f5fcb40, AUStart[size=608 AU=00000071] FrNum=12 FFPicId=-1 Grey=-1 Flags=Ref Display=16 DirOut=0004fb00 UD=114:1f5f2ab4  Flags=Ref Display=16
2293966.775: MSG: id=1f5fcb40, Slice[size=256 AU=00000071] Data=36 bits into 000049d0+00000008 in 55+00100000 Type=P FirstMB=0 DirIn=ffffffff
                          MSG:      List0=0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2293966.827: MSG: id=1f5fcb40, AUEnd[size=64 AU=00000071] PicId=0 Release=0
2293966.883: h264pwr_enable(0c1cd5e0,00000000)
2293966.900: h264pwr_enable newa newb (0c1cd5f1,00000001)
2293966.922: h264pwr_open()
2293966.938: h264pwr_enable(04000800,00000000)
2293966.956: h264pwr_enable newa newb (0c1cddf1,00000001)
2293983.865: h264pwr_disable(04000800,00000000)
2293983.883: h264pwr_disable newa newb (0c1cd5f1,00000001)
2293983.895: h264pwr_close() handle=6
2293983.921: h264pwr_disable(0c1cd5e0,00000000)
2293983.939: h264pwr_disable newa newb (00000011,00000001)
2293983.981: video_decode:1:RIL:cb:entered with buffer = 0x1f6131f0, frame_info = 0x1f60b938, status = 0, cb= 0x1f5f2ab4
2293984.053: video_decode:1:RIL:cb:P time:448917, cb:0x1f5f2ab4, ar:1/1, crop:0x0 1920x1080, interval:40000000, interlace:0,0,0
2293984.088: video_decode:1:RIL:output dec_frames_full:1f5f4af0 out:0
2293984.126: decode: display frame 1f6131f0 T=448917 sts=0
2293984.146: video_render:0:RIL:display_image 1f6131f0 state 4
2293984.165: video_render:0:RIL:skipping buffer 1f613230 in favour of 1f6131f0
2293984.205: video_render:0:RIL: update ignored, no display
2293984.221: video_render:0:RIL:return omx buffers:free 0

Ruuzis
Posts: 49
Joined: Wed May 21, 2014 11:35 am

Re: video_render ignoring frames after reconfiguration

Sun May 15, 2016 8:58 pm

I happily tracked down the one line change (after 3 days of debugging :D) that introduced this and I honestly do not quite understand why it had such effect so if anyone can enlighten me that would be great:)

So previously when I got the port settings changed event I only set up a new tunnel between the output port of video_decode and 0 and did not touch the video_render input port. At some point in the new code I added setting up a tunnel from 0 to the input port of video_render when port settings changed (I guess I thought that I must nullify both sides of the previously active tunnel). And then when connecting the video_decode and video_render components again no frames got rendered.

6by9
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 7308
Joined: Wed Dec 04, 2013 11:27 am
Location: ZZ9 Plural Z Alpha, aka just outside Cambridge.

Re: video_render ignoring frames after reconfiguration

Sun May 15, 2016 9:50 pm

Code: Select all

2293574.652: video_render:0:RIL: update ignored, no display
You've managed to select a display number that is judged invalid when passed to dispman_display_open.

Pass as to why trying to clear a tunnel from NULL to video_render input does that, but my recollection is that that step is not needed. Have a look at the ilclient code for confirmation.
Software Engineer at Raspberry Pi Trading. Views expressed are still personal views.
I'm not interested in doing contracts for bespoke functionality - please don't ask.

Ruuzis
Posts: 49
Joined: Wed May 21, 2014 11:35 am

Re: video_render ignoring frames after reconfiguration

Mon May 16, 2016 9:40 am

Hi 6by9,

thank you very much for looking into this even though it was a stupid mistake from my side. Just out of curiosity - when I tear down the tunnel why do I need to create a new tunnel only on the output port of the video decoder (tunneling it to nowhere)? Shouldn't both ends be detached or does this new tunnel effectively nullify the other end of the previous tunnel as well?

6by9
Raspberry Pi Engineer & Forum Moderator
Raspberry Pi Engineer & Forum Moderator
Posts: 7308
Joined: Wed Dec 04, 2013 11:27 am
Location: ZZ9 Plural Z Alpha, aka just outside Cambridge.

Re: video_render ignoring frames after reconfiguration

Mon May 16, 2016 10:30 am

Pass. I try to ignore IL these days.
]ilclient_setup_tunnel on failure clears both input and output.
ilclient_teardown_tunnels also clears both.
Software Engineer at Raspberry Pi Trading. Views expressed are still personal views.
I'm not interested in doing contracts for bespoke functionality - please don't ask.

Ruuzis
Posts: 49
Joined: Wed May 21, 2014 11:35 am

Re: video_render ignoring frames after reconfiguration

Mon May 16, 2016 12:04 pm

Hi 6by9,

thank you very much for the code references. Indeed seems that my intuition was right and both ends should be cleared:) I'll do some more debugging to see why in my case it fails.

Return to “Graphics, sound and multimedia”