openHDF Enigma2 crash log crashdate=Wed Dec 8 12:43:17 2021 compiledate=Dec 2 2021 skin=XionHDF/skin.xml sourcedate=2021-12-01 branch=master rev=11ed733 component=Enigma2 stbmodel=ultimo stbmodel=dm900 kernelcmdline=bmem=640M@384M bmem=384M@2048M console=ttyS0,1000000 root=/dev/mmcblk0p2 rootwait rootfstype=ext4 coherent_pool=2M nimsockets=NIM Socket 0: imageversion=6.5 imageissue=build 165 ENT SIZE_CHANGED 1920x1080 aspect 3 12:39:03.1831 < > dvb/decoder.cpp:551 video_event [eDVBVideo0] VIDEO_GET_EVENT unhandled DVBAPI Video Event 32 12:39:03.3337 [ ] dvb/pmt.cpp:301 AITready [eDVBServicePMTHandler] AITready 12:39:03.3338 [ ] dvb/pmt.cpp:320 AITready [eDVBServicePMTHandler] Section Length : 423, Total Section Length : 426 12:39:03.3338 [ ] dvb/pmt.cpp:331 AITready [eDVBServicePMTHandler] found applicaions ids >> pid : 0, orgid : 11, appid : 6838 12:39:03.3340 [ ] dvb/pmt.cpp:295 saveData [eDVBServicePMTHandler] Save Data Len : [426] 12:39:03.3341 [ ] dvb/demux.cpp:90 openDemux [eDVBDemux] open demux /dev/dvb/adapter0/demux0 12:39:03.3342 [ ] dvb/demux.cpp:286 start [eDVBSectionReader] DMX_SET_FILTER pid=7838 12:39:03.3347 [ ] dvb/pmt.cpp:331 AITready [eDVBServicePMTHandler] found applicaions ids >> pid : 0, orgid : 11, appid : 6810 12:39:03.3347 [ ] dvb/pmt.cpp:331 AITready [eDVBServicePMTHandler] found applicaions ids >> pid : 0, orgid : 11, appid : 32774 12:39:03.3348 [ ] dvb/pmt.cpp:469 AITready [eDVBServicePMTHandler] No found anything. 12:39:03.4050 [ ] service/servicedvb.cpp:1747 timeshift [eDVBServicePlay] timeshift 12:39:04.1787 < > dvb/decoder.cpp:551 video_event [eDVBVideo0] VIDEO_GET_EVENT PROGRESSIVE_CHANGED 0 12:39:04.7162 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:39:04+0100 [-] [VLC] Checking for buildin servicets ... no 12:39:04.7177 { E } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:39:04+0100 [-] [VLC] Checking for existing and usable servicets.so ... No module named servicets 12:39:04.7182 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:39:04+0100 [-] [VLC] Checking for usable gstreamer service ... yes 12:39:04.8130 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:39:04+0100 [-] EMC: Next trashcan cleanup in 741 minutes 12:39:06.8160 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:39:06+0100 [-] EMC delPathFromCache /media/hdd/movie/trashcan 12:39:06.8205 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:39:06+0100 [-] EMC: [EMCMS] trashcan cleanup: nothing to delete... 12:39:10.1312 [ ] dvb/epgcache.cpp:2253 abortNonAvail [eEPGCache] abort non avail schedule other reading 12:39:10.1316 [ ] dvb/epgcache.cpp:2277 abortNonAvail [eEPGCache] abort non avail netmed schedule reading 12:39:10.1318 [ ] dvb/epgcache.cpp:2284 abortNonAvail [eEPGCache] abort non avail netmed schedule other reading 12:39:10.1319 [ ] dvb/epgcache.cpp:2293 abortNonAvail [eEPGCache] abort non avail FreeSat schedule_other reading 12:39:10.1320 [ ] dvb/epgcache.cpp:2304 abortNonAvail [eEPGCache] abort non avail viasat reading 12:39:10.1574 < > dvb/epgcache.cpp:2583 readData [eEPGCache] nownext finished(1638963550) 12:39:15.4728 [ ] dvb/pmt.cpp:477 OCready [eDVBServicePMTHandler] OCready 12:39:19.2273 < > dvb/epgcache.cpp:2583 readData [eEPGCache] schedule finished(1638963559) 12:39:19.2276 [ ] dvb/epgcache.cpp:1602 finishEPG [eEPGCache] stop caching events(1638963559) 12:39:19.2277 [ ] dvb/epgcache.cpp:1604 finishEPG [eEPGCache] next update in 60 min 12:40:01.3742 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:40:01+0100 [-] [Console] command: ('sdparm', 'sdparm', '--flexible', '--readonly', '--command=stop', '/dev/sda') 12:40:01.3744 [ ] base/console.cpp:111 execute [eConsoleAppContainer] Starting sdparm 12:40:01.3827 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:40:01+0100 [-] [Console] finished: ('sdparm', 'sdparm', '--flexible', '--readonly', '--command=stop', '/dev/sda') 12:40:01.3829 [ ] base/ebase.cpp:280 processOneEvent [eMainloop::processOneEvent] unhandled POLLERR/HUP/NVAL for fd 93(16) 12:41:59.3396 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:41:59+0100 [-] [AutoTimer] current auto poll 2021-12-08 12:41:59 12:41:59.3402 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:41:59+0100 [-] [AutoTimer] Auto Poll Started 12:41:59.3411 [ E ] dvb/epgcache.cpp:2868 lookupEventId [eEPGCache] event 1671 not found in epgcache 12:41:59.3412 [ E ] dvb/epgcache.cpp:2868 lookupEventId [eEPGCache] event 1670 not found in epgcache 12:41:59.3435 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:41:59+0100 [-] [Task] job Components.Task.Job name=AutoTimer #tasks=0 completed with [] in None 12:41:59.3443 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:41:59+0100 [-] [AutoTimer] next auto poll at 2021-12-08 16:41:59 12:43:02.1638 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 8b 1 12:43:02.1652 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:02+0100 [-] action -> InfobarMenuActions mainMenu 12:43:02.1715 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:02+0100 [-] [SKIN] processing screen menu_mainmenu: 12:43:02.1846 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:02+0100 [-] [SKIN] processing screen MenuSummary: 12:43:02.3640 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 0 8b 1 12:43:03.1001 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 6a 1 12:43:03.3008 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 0 6a 1 12:43:04.0376 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 160 1 12:43:04.0387 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:04+0100 [-] action -> OkCancelActions ok 12:43:04.0482 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:04+0100 [-] [SKIN] processing screen menu_setup: 12:43:04.0572 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:04+0100 [-] [SKIN] processing screen MenuSummary: 12:43:04.3055 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 0 160 1 12:43:05.0160 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 6a 1 12:43:05.2191 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 0 6a 1 12:43:05.5482 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 160 1 12:43:05.5493 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:05+0100 [-] action -> OkCancelActions ok 12:43:05.5530 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:05+0100 [-] [SKIN] processing screen menu_scan: 12:43:05.5620 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:05+0100 [-] [SKIN] processing screen MenuSummary: 12:43:05.7904 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 0 160 1 12:43:06.2589 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 6c 1 12:43:06.3948 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 0 6c 1 12:43:06.5418 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 6c 1 12:43:06.6782 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 0 6c 1 12:43:06.7994 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 6c 1 12:43:06.9352 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 0 6c 1 12:43:07.2503 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 160 1 12:43:07.2516 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:07+0100 [-] action -> OkCancelActions ok 12:43:07.2777 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:07+0100 [-] ID: 0 12:43:07.2881 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:07+0100 [-] [SKIN] processing screen Blindscan: 12:43:07.2949 { E } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:07+0100 [-] [SKIN] SKIN ERROR in screen 'Blindscan' widget 'widget': {XionHDF/skin.xml}: source 'key_red' was not found in screen 'Blindscan'!. Please contact the skin's author! 12:43:07.2955 { E } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:07+0100 [-] [SKIN] SKIN ERROR in screen 'Blindscan' widget 'widget': {XionHDF/skin.xml}: source 'key_green' was not found in screen 'Blindscan'!. Please contact the skin's author! 12:43:07.2962 { E } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:07+0100 [-] [SKIN] SKIN ERROR in screen 'Blindscan' widget 'widget': {XionHDF/skin.xml}: source 'key_yellow' was not found in screen 'Blindscan'!. Please contact the skin's author! 12:43:07.2968 { E } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:07+0100 [-] [SKIN] SKIN ERROR in screen 'Blindscan' widget 'widget': {XionHDF/skin.xml}: source 'key_blue' was not found in screen 'Blindscan'!. Please contact the skin's author! 12:43:07.2984 { W } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:07+0100 [-] warning, skin is missing element introduction in 12:43:07.3077 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:07+0100 [-] [SKIN] processing screen SetupSummary: 12:43:07.5073 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 0 160 1 12:43:11.0454 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 18f 1 12:43:11.0466 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:11+0100 [-] action -> SetupActions save 12:43:11.0471 { W } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:11+0100 [-] unknown action SetupActions/save! typo in keymap? 12:43:11.0476 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:11+0100 [-] action -> SetupActions save 12:43:11.0480 { W } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:11+0100 [-] unknown action SetupActions/save! typo in keymap? 12:43:11.2613 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 0 18f 1 12:43:17.7218 [ ] driver/rcinput.cpp:38 handleCode [eRCDeviceInputDev] 1 160 1 12:43:17.7229 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] action -> SetupActions ok 12:43:17.7236 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] nim 0 12:43:17.7241 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] is compatible with DVB-S 12:43:17.7248 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] tunername Si2166B 12:43:17.7250 [ ] dvb/cahandler.cpp:333 unregisterService [eDVBCAService] free slot 0 demux 0 for service 1:0:19:7B:4B0:110:820000:0:0:0: 12:43:17.7250 [ ] dvb/cahandler.cpp:497 ~eDVBCAService [eDVBCAService] free service 1:0:19:7B:4B0:110:820000:0:0:0: 12:43:17.7297 [ ] service/servicedvb.cpp:1747 timeshift [eDVBServicePlay] timeshift 12:43:17.7299 [ ] service/servicedvb.cpp:1747 timeshift [eDVBServicePlay] timeshift 12:43:17.7304 [ ] dvb/decoder.cpp:874 setState [eTSMPEGDecoder] decoder state: play, vpid=ffffffff, apid=ffffffff 12:43:17.7305 < > dvb/decoder.cpp:766 stop [eDVBPCR0] DEMUX_STOP ok 12:43:17.7306 [ ] dvb/decoder.cpp:777 ~eDVBPCR [eDVBPCR0] destroy 12:43:17.7306 < > dvb/decoder.cpp:435 stop [eDVBVideo0] DEMUX_STOP ok 12:43:17.7315 < > dvb/decoder.cpp:444 stop [eDVBVideo0] VIDEO_STOP ok 12:43:17.7316 [ ] dvb/decoder.cpp:536 ~eDVBVideo [eDVBVideo0] destroy 12:43:17.7316 < > dvb/decoder.cpp:163 stop [eDVBAudio0] AUDIO_STOP ok 12:43:17.7519 < > dvb/decoder.cpp:171 stop [eDVBAudio0] DEMUX_STOP ok 12:43:17.7521 < > dvb/decoder.cpp:207 unfreeze [eDVBAudio0] AUDIO_CONTINUE ok 12:43:17.7521 [ ] dvb/decoder.cpp:251 ~eDVBAudio [eDVBAudio0] destroy 12:43:17.7521 < > dvb/decoder.cpp:844 stop [eDVBText0] DEMUX_STOP ok 12:43:17.7529 [ ] dvb/decoder.cpp:855 ~eDVBTText [eDVBText0] destroy 12:43:17.7543 [ ] dvb/dvbtime.cpp:700 DVBChannelStateChanged [eDVBLocalTimerHandler] remove channel 0x2121fc0 12:43:17.7544 [ ] dvb/epgcache.cpp:710 DVBChannelStateChanged [eEPGCache] remove channel 0x2121fc0 12:43:17.7589 [ ] dvb/frontend.cpp:3121 tune tune tuner 0 12:43:17.7590 [ ] dvb/sec.cpp:72 canTune [eDVBSatelliteEquipmentControl] direct_connected 1 12:43:17.7590 [ ] dvb/sec.cpp:111 canTune [eDVBSatelliteEquipmentControl] canTune 1 12:43:17.7591 [ ] dvb/sec.cpp:126 canTune [eDVBSatelliteEquipmentControl] lnb 0 found 12:43:17.7591 [ ] dvb/sec.cpp:136 canTune [eDVBSatelliteEquipmentControl] 1 option(s) at position 130 12:43:17.7591 [ ] dvb/sec.cpp:150 canTune [eDVBSatelliteEquipmentControl] sat 130 found 12:43:17.7591 [ ] dvb/sec.cpp:194 canTune ret1 10000 12:43:17.7591 [ ] dvb/sec.cpp:240 canTune [eDVBSatelliteEquipmentControl] ret5 10000 12:43:17.7591 [ ] dvb/sec.cpp:257 canTune [eDVBSatelliteEquipmentControl] ret 10000, score old 0 12:43:17.7591 [ ] dvb/sec.cpp:264 canTune [eDVBSatelliteEquipmentControl] score new 10000 12:43:17.7592 [ ] dvb/sec.cpp:126 canTune [eDVBSatelliteEquipmentControl] lnb 1 found 12:43:17.7592 [ ] dvb/sec.cpp:136 canTune [eDVBSatelliteEquipmentControl] 0 option(s) at position 130 12:43:17.7592 [ ] dvb/sec.cpp:279 canTune [eDVBSatelliteEquipmentControl] final score 10004 12:43:17.7592 [ ] dvb/sec.cpp:1058 prepare [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff 12:43:17.7593 [ ] dvb/frontend.cpp:3024 prepare_sat [eDVBFrontend0] prepare_sat System 1 Freq 10650000 Pol 0 SR 8000 INV 2 FEC 0 orbpos 130 system 1 modulation 1 pilot 2, rolloff 0, is_id -1, pls_mode 1, pls_code 0, t2mi_plp_id 0 t2mi_pid 0 12:43:17.7593 [ ] dvb/frontend.cpp:3047 prepare_sat tuning to 900 MHz 12:43:17.7593 [ ] dvb/dvb.cpp:1889 frontendStateChanged [eDVBChannel] OURSTATE: tuner 0 tuning 12:43:17.7612 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] Traceback (most recent call last): 12:43:17.7618 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] File "/usr/lib/enigma2/python/Components/ActionMap.py", line 72, in action 12:43:17.7626 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] File "/usr/lib/enigma2/python/Components/ActionMap.py", line 51, in action 12:43:17.7632 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] File "/usr/lib/enigma2/python/Plugins/SystemPlugins/Blindscan/plugin.py", line 761, in keyGo 12:43:17.7638 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] File "/usr/lib/enigma2/python/Plugins/SystemPlugins/Blindscan/plugin.py", line 451, in startSatelliteTransponderSearch 12:43:17.7644 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] File "/usr/lib/enigma2/python/Plugins/SystemPlugins/Blindscan/plugin.py", line 195, in updateStateSat 12:43:17.7650 { } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] File "/usr/lib/enigma2/python/Plugins/SystemPlugins/Blindscan/plugin.py", line 205, in frontendStateChanged 12:43:17.7656 { E } /usr/lib/python2.7/site-packages/twisted/python/util.py:815 untilConcludes 2021-12-08 12:43:17+0100 [-] UnboundLocalError: local variable 'x' referenced before assignment 12:43:17.7657 [ E ] python/python.cpp:213 call [ePyObject] (PyObject_CallObject(>,('SetupActions', 'ok')) failed) dmesg <4>[ 349.568027] HDMI: CEC recv ok! <6>[ 349.705312] si2166b(0): voltage is disabled now <4>[ 350.749395] VIDEO0: set streamtype! <4>[ 350.749410] -> set MPEG2 <4>[ 350.749416] -> sw rave disabled! <4>[ 350.749436] VIDEO0: set blank to 0 <4>[ 350.749612] sync0 is off so we enable it <4>[ 350.749619] sync0: allocated pcroffset 0 <4>[ 350.749629] sync0: playback! <4>[ 350.749654] VIDEO0: total delay: 0 (0 ms) <4>[ 350.754589] VIDEO0: start decode <4>[ 350.754614] VIDEO0: flush video decoder <4>[ 350.754623] VIDEO0 use saved pts 0x1efe606f4 (ret 0) <4>[ 350.794342] VIDEO0: first pts 0x0 <4>[ 350.794369] VIDEO0: resolution changed (1280 720) <3>[ 350.934683] bcm_accel: invalid opcode! 00000080 <6>[ 350.936620] bcmfb: creating surface with pixel format 0x07e48888 (BPXL_eA8_R8_G8_B8) <4>[ 350.959182] VIDEO0: enable tsm <4>[ 350.972667] HDMI: CEC device open ... state is 3, flushed 1 old messages from RX fifo <4>[ 350.972695] HDMI: CEC returned state 3 <4>[ 350.972700] HDMI: CEC state now 803 <6>[ 351.006740] si2166b(0): voltage is disabled now <6>[ 351.007959] si2166b(0): voltage is disabled now <6>[ 351.008713] si2166b(0): voltage is disabled now <6>[ 351.010426] si2166b(1): voltage is disabled now <6>[ 351.011566] si2166b(1): voltage is disabled now <6>[ 351.013260] si2166b(1): voltage is disabled now <4>[ 351.022810] VIDEO0: dst_left, dst_top, dst_width and dst_height is 0.. reset to defaults! <4>[ 351.022824] set current avs auto aspect to 16:9 <4>[ 351.022853] set sb to 3(1) <4>[ 351.023098] VIDEO1: dst_left, dst_top, dst_width and dst_height is 0.. reset to defaults! <4>[ 351.025172] VIDEO0: stop decode <4>[ 351.025189] sync0 1fff no decoder left in sync handling so disable <4>[ 351.025193] sync0: was last pcroffset0 user so free it <4>[ 351.099858] HDMI: CEC send ok! <4>[ 351.150600] 310278 ms: 63 <4>[ 351.170111] HDMI: CEC recv ok! <4>[ 351.183877] 33 ms: 50 <6>[ 351.387629] EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null) <4>[ 351.445409] 262 ms: 50 <4>[ 351.629145] 184 ms: 50 <4>[ 351.638253] 9 ms: 51 <4>[ 351.641090] 2 ms: 51 <4>[ 351.641750] 1 ms: 51 <4>[ 351.646608] 5 ms: 51 <4>[ 351.754343] VIDEO0: progressive changed (1) <4>[ 351.775400] 129 ms: 51 <4>[ 351.779916] 4 ms: 52 <4>[ 351.780541] 1 ms: 52 <4>[ 351.781243] 1 ms: 52 <4>[ 352.007577] 226 ms: 52 <4>[ 352.016168] 9 ms: 53 <4>[ 352.016704] 0 ms: 53 <4>[ 352.018789] 2 ms: 53 <4>[ 352.019499] 1 ms: 53 <4>[ 352.020184] 1 ms: 53 <4>[ 352.023062] 2 ms: 53 <4>[ 352.024797] 2 ms: 53 <4>[ 352.029461] 5 ms: 53 <4>[ 352.030210] 1 ms: 53 <4>[ 352.044476] 14 ms: 53 <4>[ 352.299850] 255 ms: 53 <4>[ 352.300726] 1 ms: 54 <4>[ 352.302760] 2 ms: 54 <4>[ 352.436041] 133 ms: 54 <4>[ 352.439301] 4 ms: 54 <4>[ 352.440983] 1 ms: 55 <4>[ 352.569678] 129 ms: 55 <4>[ 352.570718] 1 ms: 55 <4>[ 352.574676] 4 ms: 55 <4>[ 353.168915] HDMI: CEC recv ok! <4>[ 353.241600] 667 ms: 55 <4>[ 353.242487] 1 ms: 58 <4>[ 353.250383] 8 ms: 58 <4>[ 353.250904] 0 ms: 58 <4>[ 353.259218] 9 ms: 58 <4>[ 353.260027] 0 ms: 58 <4>[ 353.260876] 1 ms: 58 <4>[ 353.262016] 1 ms: 58 <4>[ 353.265150] 4 ms: 58 <4>[ 353.265741] 0 ms: 58 <4>[ 353.268337] 3 ms: 58 <4>[ 353.319383] 51 ms: 58 <4>[ 353.383740] 64 ms: 58 <4>[ 353.390071] set current avs auto aspect to 16:9 <4>[ 353.390141] set sb to 3(1) <4>[ 353.391202] set current avs auto aspect to 16:9 <4>[ 353.391222] set sb to 3(1) <4>[ 353.392002] set current avs auto aspect to 16:9 <4>[ 353.392025] set sb to 3(1) <4>[ 353.392568] set input to 0 <4>[ 353.392574] set fb to 2(-1) <4>[ 353.392580] set current avs auto aspect to 16:9 <4>[ 353.392598] set sb to 3(1) <4>[ 353.398056] using 50.00Hz as MonitorRefreshRate <4>[ 353.398071] VIDEO1: shared window not available <4>[ 353.451452] SET FORMAT: display[0], format='1080i50' <4>[ 353.451466] HDMI mode <4>[ 353.451470] use EDID to detect colorspace <4>[ 353.451474] preferred colorspace: Itu_R_BT_709 <4>[ 353.451477] using 8bit output <4>[ 353.571414] VIDEO1: shared window not available <4>[ 353.571447] set current avs auto aspect to 16:9 <4>[ 353.571477] set sb to 3(1) <4>[ 353.671461] using 50.00Hz as MonitorRefreshRate <4>[ 353.671475] VIDEO1: shared window not available <4>[ 353.671498] SET FORMAT: display[0], format='1080i50' <4>[ 353.671508] HDMI mode <4>[ 353.671512] use EDID to detect colorspace <4>[ 353.671516] preferred colorspace: Itu_R_BT_709 <4>[ 353.671519] using 8bit output <4>[ 353.791435] VIDEO1: shared window not available <4>[ 353.791474] set current avs auto aspect to 16:9 <4>[ 353.791960] set sb to 3(1) <4>[ 353.891442] using 50.00Hz as MonitorRefreshRate <4>[ 353.891456] VIDEO1: shared window not available <4>[ 353.891480] SET FORMAT: display[0], format='1080i50' <4>[ 353.891489] HDMI mode <4>[ 353.891494] use EDID to detect colorspace <4>[ 353.891497] preferred colorspace: Itu_R_BT_709 <4>[ 353.891500] using 8bit output <4>[ 354.011420] VIDEO1: shared window not available <4>[ 354.011458] set current avs auto aspect to 16:9 <4>[ 354.012725] set ac3 to downmix <4>[ 354.013093] set ac3plus to force_ac3 <4>[ 354.013483] set dtshd to downmix <4>[ 354.013721] set wmapro to downmix <4>[ 354.014086] set aac to downmix <4>[ 354.015889] set sb to 3(1) <4>[ 354.112586] set current avs auto aspect to 16:9 <4>[ 354.112618] set sb to 3(1) <4>[ 354.112704] set current avs auto aspect to 16:9 <4>[ 354.112716] set sb to 3(1) <4>[ 354.113038] 729 ms: 59 <4>[ 354.114798] 2 ms: 61 <4>[ 354.122691] 8 ms: 61 <4>[ 354.300775] 178 ms: 62 <4>[ 354.305087] 4 ms: 62 <4>[ 354.317474] 13 ms: 62 <4>[ 354.318225] 1 ms: 62 <4>[ 354.319388] 1 ms: 62 <4>[ 354.357274] 38 ms: 62 <4>[ 354.365764] 8 ms: 62 <4>[ 354.420388] set current avs auto aspect to 16:9 <4>[ 354.420422] set sb to 3(1) <4>[ 354.420699] set current avs auto aspect to 16:9 <4>[ 354.420715] set sb to 3(1) <4>[ 354.420961] set current avs auto aspect to 16:9 <4>[ 354.420976] set sb to 3(1) <4>[ 354.421371] set current avs auto aspect to 16:9 <4>[ 354.421390] set sb to 3(1) <4>[ 354.471489] using 50.00Hz as MonitorRefreshRate <4>[ 354.471503] VIDEO1: shared window not available <4>[ 354.511470] SET FORMAT: display[0], format='1080i50' <4>[ 354.511482] HDMI mode <4>[ 354.511486] use EDID to detect colorspace <4>[ 354.511490] preferred colorspace: Itu_R_BT_709 <4>[ 354.511494] using 8bit output <4>[ 354.631432] VIDEO1: shared window not available <4>[ 354.631461] set current avs auto aspect to 16:9 <4>[ 354.631488] set sb to 3(1) <4>[ 355.270384] HDMI: CEC recv ok! <4>[ 357.169448] HDMI: CEC recv ok! <4>[ 359.170346] HDMI: CEC recv ok! <4>[ 361.172726] HDMI: CEC recv ok! <4>[ 363.174225] HDMI: CEC recv ok! <4>[ 364.484149] set mute 0 0 <6>[ 365.087152] si2166b(0): voltage is disabled now <6>[ 365.166183] si2166b(0): tune timeout! <6>[ 365.173009] si2166b(0): voltage is 13V now <4>[ 365.175058] HDMI: CEC recv ok! <6>[ 365.849069] si2166b(0): tune freq 1682000, sr 29900000, delsys 6 <6>[ 365.917612] si2166b(0): found carrier after 69 ms <6>[ 365.917622] si2166b(0): final lock after 69 ms <4>[ 365.922720] start PCR0 on dmx 0 pid:420 index 2 <4>[ 365.922792] audio ch0: clip stuff already freed <4>[ 365.923013] start AUDIO0 on dmx 0 pid:484 index 3 <4>[ 365.923018] audio ch0: xpt start <4>[ 365.923037] sync0 is off so we enable it <4>[ 365.923042] sync0: allocated pcroffset 0 <4>[ 365.923053] sync0: demux-index 0 pcr pid 420 <4>[ 365.923065] sync0: using 2 as pcr pidchannel <4>[ 365.923082] audio ch0: AC3 <4>[ 365.923087] audio ch0: streamtype set 1 <4>[ 365.923091] audio ch0: streamtype_set: stop rave <4>[ 365.923140] audio ch0: decode <4>[ 365.923156] audio ch0: streamtype_set: restart rave <4>[ 365.923308] audio ch0: decoder start <4>[ 365.923316] audio ch0: video delay 0 (0 ms) <4>[ 365.923325] VIDEO0: total delay: 0 (0 ms) <4>[ 365.924287] VIDEO0: clip stuff already freed <4>[ 365.924415] VIDEO0: set streamtype! <4>[ 365.924423] -> set H264 <4>[ 365.924426] -> sw rave disabled! <4>[ 365.924440] audio ch0 delay 18000 (200 ms) <4>[ 365.924445] VIDEO0: total delay: 18000 (200 ms) <4>[ 365.924560] start VIDEO0 on dmx 0 pid:420 index 2 <4>[ 365.924592] VIDEO0: total delay: 18000 (200 ms) <4>[ 365.929600] VIDEO0: start decode <4>[ 366.379527] audio ch0: use saved pts 0x1efe5fe84 (0x1fdfdfdfe) (ret 1) <4>[ 366.379550] audio ch0: decoder stop <4>[ 366.385258] stop AUDIO0 on dmx 0 pid:484 <4>[ 366.385264] audio ch0: xpt stop <4>[ 366.385444] audio ch0: clip stuff already freed <4>[ 366.385641] start AUDIO0 on dmx 0 pid:4e8 index 3 <4>[ 366.385646] audio ch0: xpt start <4>[ 366.385670] audio ch0: MPEG <4>[ 366.385675] audio ch0: streamtype set 0 <4>[ 366.385679] audio ch0: streamtype_set: stop rave <4>[ 366.385713] audio ch0: streamtype_set: restart rave <4>[ 366.385815] audio ch0: decoder start <4>[ 366.385822] audio ch0 delay 18000 (200 ms) <4>[ 366.385828] VIDEO0: total delay: 18000 (200 ms) <4>[ 367.175988] HDMI: CEC recv ok! <4>[ 367.617978] audio ch0: first pts 0x1f00d1564, stc 0x1f00ce476, pcr valid <4>[ 367.638314] audio ch0: lock <4>[ 367.638347] audio ch0: sample rate changed isr (48000) <4>[ 367.638363] audio ch0: tsm fail <4>[ 367.638369] audio ch0: pts error 0 PTS 0xf00d1564, STC 0xf00ceba2, type 0 <4>[ 367.974532] VIDEO0: first pts 0x1f00e4ac4 <4>[ 367.974563] VIDEO0: resolution changed (1920 1080) <4>[ 368.025888] audio ch0: status ready isr <4>[ 368.124784] VIDEO0: enable tsm <4>[ 368.974507] VIDEO0: progressive changed (0) <4>[ 369.178217] HDMI: CEC recv ok! <4>[ 409.569071] HDMI: CEC recv ok! <4>[ 469.569920] HDMI: CEC recv ok! <4>[ 529.570572] HDMI: CEC recv ok! <4>[ 589.576211] HDMI: CEC recv ok! <4>[ 622.653303] stop PCR0 on dmx 0 pid:420 <4>[ 622.653390] stop VIDEO0 on dmx 0 pid:420 <4>[ 622.654182] VIDEO0: stop decode <4>[ 622.654345] VIDEO0: set blank to 1 <4>[ 622.654467] audio ch0: decoder stop <4>[ 622.674764] stop AUDIO0 on dmx 0 pid:4e8 <4>[ 622.674772] audio ch0: xpt stop <4>[ 622.674778] sync0 1fff no decoder left in sync handling so disable <4>[ 622.674782] sync0: was last pcroffset0 user so free it