Error writing session log (raw mode) to file: putty.log Dreambox DM520 M0CZS L2=1 LLMB=1 BrCfg=E30FB7C6 #@ BCM973625A0 CFE v15.3, Endian Mode: Little Build Date: Fri Aug 19 11:48:16 2016 (Jann@Cynric) Copyright (C) Broadcom Corporation. CI box detected card if inited Enabling NAND flash at CS2: A5U4GA31ATS(DEVICE ID=0xC8DC9095), ECC Level=4, Spar e Area Size=16 MACRONIX SPI flash detected: Size = 16MB, Sector Size 4096, Page Size 256 CPU speed: 751MHz DDR Frequency: 1061 MHz DDR Mode: DDR3 Total memory(MEMC 0): 512MB MEMC 0 DDR Width: 16 Boot Device: SPI Total flash: 16MB RTS VERSION: rts_hevc10_1067 ETH0_PHY: INT ETH0_MDIO_MODE: 1 ETH0_SPEED: 100 ETH0_PHYADDR: 1 DM init finalization yxml: processing file of 131072 bytes... succeeded! no file loaded, create xml restoring default xml loaded network params of: DHCP, 192.168.0.219, 255.255.255.0, 192.168.0.1 [1] type 3, dev nandflash0.kernel, loader elf, filesys raw, file , options [2] type 3, dev flash0.kernel, loader elf, filesys raw, file , options [3] type 1, dev eth0, loader elf, filesys tftp, file , options bmem=192M@64M con sole=ttyS0,1000000 root=/dev/nfs ip=dhcp added 3 sources to autoboot list init fp Initializing USB. CFE initialized. found card in unknown state ca valid! ***** DREAMBOX SSBL ***** Not interrupted yet, trying autoboot or rescue loader, hit any key in the next 5 00ms to cancel Proceeding with autoboot.. You can try aborting with Ctrl+C *** Autoboot: Trying device 'nandflash0.kernel' file (raw,elf) Loader:elf Filesys:raw Dev:nandflash0.kernel File: Options: Loading: 0x80001000/7588032 0x8073d8c0/235952 Entry address is 0x805cd1d0 Closing network eth0 Ethernet link is up: 100 Mbps Full-Duplex Starting program at 0x805cd1d0 ¦[ 0.232000] console [ttyS0] enabled, bootconsole disabled [ 0.232000] console [ttyS0] enabled, bootconsole disabled [ 0.236000] loop: module loaded [ 0.237000] brcmstb_nand: NAND controller driver is loaded [ 0.238000] tun: Universal TUN/TAP device driver, 1.6 [ 0.239000] tun: (C) 1999-2004 Max Krasnyansky [ 0.361000] bcmgenet: configuring instance #0 for internal PHY [ 0.381000] bcmgenet bcmgenet.0: (unregistered net_device): link down [ 0.382000] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 0.383000] ehci-brcm ehci-brcm.0: Broadcom STB EHCI [ 0.383000] ehci-brcm ehci-brcm.0: new USB bus registered, assigned bus numbe r 1 [ 0.415000] ehci-brcm ehci-brcm.0: irq 66, io mem 0x10480300 [ 0.421000] ehci-brcm ehci-brcm.0: USB 0.0 started, EHCI 1.00 [ 0.422000] hub 1-0:1.0: USB hub found [ 0.422000] hub 1-0:1.0: 2 ports detected [ 0.423000] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 0.424000] ohci-brcm ohci-brcm.0: Broadcom STB OHCI [ 0.424000] ohci-brcm ohci-brcm.0: new USB bus registered, assigned bus numbe r 2 [ 0.425000] ohci-brcm ohci-brcm.0: irq 67, io mem 0x10480400 [ 0.491000] hub 2-0:1.0: USB hub found [ 0.491000] hub 2-0:1.0: 2 ports detected [ 0.492000] Initializing USB Mass Storage driver... [ 0.493000] usbcore: registered new interface driver usb-storage [ 0.494000] USB Mass Storage support registered. [ 0.494000] i2c /dev entries driver [ 0.495000] lirc_dev: IR Remote Control driver registered, major 253 [ 0.495000] usbcore: registered new interface driver btusb [ 0.497000] TCP: cubic registered [ 0.497000] NET: Registered protocol family 10 [ 0.499000] NET: Registered protocol family 17 [ 0.499000] Bluetooth: RFCOMM TTY layer initialized [ 0.500000] Bluetooth: RFCOMM socket layer initialized [ 0.501000] Bluetooth: RFCOMM ver 1.11 [ 0.501000] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 [ 0.502000] Bluetooth: BNEP filters: protocol multicast [ 0.502000] Bluetooth: HIDP (Human Interface Emulation) ver 1.2 [ 0.503000] L2TP core driver, V2.0 [ 0.503000] Registering the dns_resolver key type [ 0.504000] PM: CP0 COUNT/COMPARE frequency does not depend on divisor [ 0.506000] EBI CS2: setting up NAND flash (primary) [ 0.507000] NAND device: Manufacturer ID: 0xc8, Chip ID: 0xdc (Unknown NAND 5 12MiB 3,3V 8-bit) [ 0.508000] brcmnand brcmnand.0: 512MiB total, 128KiB blocks, 2KiB pages, 16B OOB, 8-bit, BCH-4 [ 0.508000] [ 0.510000] Bad block table found at page 262080, version 0x01 [ 0.511000] Bad block table found at page 262016, version 0x01 [ 0.512000] nand_read_bbt: bad block at 0x00000c060000 [ 0.513000] nand_read_bbt: bad block at 0x00000c660000 [ 0.513000] nand_read_bbt: bad block at 0x000010ac0000 [ 0.514000] nand_read_bbt: bad block at 0x000018600000 [ 0.515000] Creating 3 MTD partitions on "brcmnand.0": [ 0.516000] 0x000000000000-0x00001f500000 : "rootfs" [ 0.518000] 0x000000000000-0x000020000000 : "entire_device" [ 0.520000] 0x00001f500000-0x00001fa00000 : "kernel" [ 0.521000] EBI CS0: setting up SPI flash [ 0.522000] spi_brcmstb spi_brcmstb.0: 1-lane output, 3-byte address [ 0.523000] spi_brcmstb spi_brcmstb.0: master is unqueued, this is deprecated [ 0.524000] m25p80 spi0.0: found mx25l12805d, expected w25q128bv [ 0.524000] m25p80 spi0.0: mx25l12805d (16384 Kbytes) [ 0.527000] UBI: attaching mtd0 to ubi0 [ 0.527000] UBI: physical eraseblock size: 131072 bytes (128 KiB) [ 0.528000] UBI: logical eraseblock size: 126976 bytes [ 0.528000] UBI: smallest flash I/O unit: 2048 [ 0.529000] UBI: VID header offset: 2048 (aligned 2048) [ 0.530000] UBI: data offset: 4096 [ 3.671000] UBI: max. sequence number: 14785 [ 3.687000] UBI: attached mtd0 to ubi0 [ 3.687000] UBI: MTD device name: "rootfs" [ 3.688000] UBI: MTD device size: 501 MiB [ 3.688000] UBI: number of good PEBs: 4004 [ 3.689000] UBI: number of bad PEBs: 4 [ 3.689000] UBI: number of corrupted PEBs: 0 [ 3.690000] UBI: max. allowed volumes: 128 [ 3.690000] UBI: wear-leveling threshold: 4096 [ 3.691000] UBI: number of internal volumes: 1 [ 3.691000] UBI: number of user volumes: 1 [ 3.692000] UBI: available PEBs: 0 [ 3.692000] UBI: total number of reserved PEBs: 4004 [ 3.693000] UBI: number of PEBs reserved for bad PEB handling: 40 [ 3.694000] UBI: max/mean erase counter: 8/4 [ 3.694000] UBI: image sequence number: 793795032 [ 3.695000] UBI: background thread "ubi_bgt0d" started, PID 54 [ 3.697000] ALSA device list: [ 3.697000] No soundcards found. [ 3.809000] UBIFS: mounted UBI device 0, volume 0, name "dreambox-rootfs" [ 3.810000] UBIFS: file system size: 501428224 bytes (489676 KiB, 478 MiB, 3949 LEBs) [ 3.811000] UBIFS: journal size: 9023488 bytes (8812 KiB, 8 MiB, 72 LEB s) [ 3.811000] UBIFS: media format: w4/r0 (latest is w4/r0) [ 3.812000] UBIFS: default compressor: lzo [ 3.813000] UBIFS: reserved for root: 0 bytes (0 KiB) [ 3.815000] VFS: Mounted root (ubifs filesystem) on device 0:12. [ 3.818000] devtmpfs: mounted [ 4.256000] systemd[1]: systemd 230 running in system mode. (-PAM -AUDIT -SEL INUX -IMA -APPARMOR -SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT +GNUTLS +ACL + XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN) [ 4.259000] systemd[1]: Detected architecture mips. Welcome to opendreambox 2.5.0! [ 4.272000] systemd[1]: Set hostname to . [ 4.472000] systemd-fstab-generator[60]: Checking was requested for "rootfs", but it is not a device. [ 5.017000] systemd[1]: Listening on Journal Socket. [ OK ] Listening on Journal Socket. [ 5.022000] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 5.025000] systemd[1]: Reached target Paths. [ OK ] Reached target Paths. [ 5.088000] systemd[1]: Created slice System Slice. [ OK ] Created slice System Slice. [ 5.106000] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root and Kernel File Systems... [ 5.118000] systemd[1]: Starting Create list of required static device nodes for the current kernel... Starting Create list of required st... nodes for the current kernel... [ 5.130000] systemd[1]: Starting Generate environment for enigma2... Starting Generate environment for enigma2... [ 5.153000] systemd[1]: Starting Load Kernel Modules... Starting Load Kernel Modules... [ 5.166000] systemd[1]: Starting Journal Service... Starting Journal Service... [ 5.169000] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 5.171000] systemd[1]: Reached target Remote File Systems. [ OK ] Reached target Remote File Systems. [ 5.175000] systemd[1]: Created slice User and Session Slice. [ OK ] Created slice User and Session Slice. [ 5.179000] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 5.183000] systemd[1]: Created slice system-serial\x2dgetty.slice. [ OK ] Created slice system-serial\x2dgetty.slice. [ 5.200000] systemd[1]: Starting Setup Virtual Console... Starting Setup Virtual Console... [ 5.203000] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 5.248000] systemd[1]: Mounting POSIX Message Queue File System... Mounting POSIX Message Queue File System... [ 5.252000] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 5.282000] systemd[1]: Started Create list of required static device nodes f or the current kernel. [ OK ] Started Create list of required sta...ce nodes for the current kernel. [ 5.369000] systemd[1]: Mounted POSIX Message Queue File System. [ OK ] Mounted POSIX Message Queue File System. [ 5.383000] systemd[1]: Started Remount Root and Kernel File Systems. [ OK ] Started Remount Root and Kernel File Systems. [ 5.422000] systemd[1]: Starting udev Coldplug all Devices... Starting udev Coldplug all Devices... [ 5.432000] systemd[1]: Starting Create Static Device Nodes in /dev... Starting Create Static Device Nodes in /dev... [ 5.446000] systemd[1]: Started Setup Virtual Console. [ OK ] Started Setup Virtual Console. [ 5.471000] stb_core: module license 'Proprietary' taints kernel. [ 5.471000] Disabling lock debugging due to kernel taint [ 5.549000] input: dreambox remote control (native) as /devices/virtual/input /input0 [ 5.551000] input: dreambox advanced remote control (native) as /devices/virt ual/input/input1 [ 6.734000] bcm73625: xvd 20160630, vdc 20160630, rap 20160630, xpt 20160630, driver version 20170425-dm520 [ 6.748000] 6:747961929 SMCA: controller reset timed out [ 6.766000] systemd[1]: Started Journal Service. [ OK ] Started Journal Service. Starting Flush Journal to Persistent Storage... [ OK ] Started Create Static Device Nodes in /dev. Starting udev Kernel Device Manager... [ OK ] Reached target Local File Systems (Pre). Mounting /tmp... Mounting /var/volatile... [ OK ] Mounted /tmp. [ OK ] Mounted /var/volatile. [ OK ] Started udev Coldplug all Devices. [ OK ] Started Generate environment for enigma2. Starting Load/Save Random Seed... [ OK ] Reached target Local File Systems. [ OK ] Started Load/Save Random Seed. [ 7.312000] systemd-journald[74]: Received request to flush runtime journal f rom PID 1 [ OK ] Started Flush Journal to Persistent Storage. [ OK ] Started udev Kernel Device Manager. Starting Create Volatile Files and Directories... [ OK ] Found device /dev/sci0. [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... [ OK ] Found device /dev/ttyS0. [ OK ] Started Update UTMP about System Boot/Shutdown. [ OK ] Found device /dev/tpm0. [ 8.495000] register adapter [ 8.496000] register adapter [ 8.498000] register adapter [ 8.499000] input: dreambox front panel as /devices/virtual/input/input2 [ 8.500000] OFFSET 1497326834 8169428 [ 8.501000] WKTMR 14 2087810 [ 8.501000] LAST WKTMR 377 [ 8.502000] HDMI: CEC start ... state is now 1 [ 8.503000] set input to 0 [ 8.503000] set fb to 2(-1) [ 8.510000] startvideomode '1080i50' read from /etc/videomode [ 8.511000] bcmfb: creating surface with pixel format 0x07e48888 (BPXL_eA8_R8 _G8_B8) [ 8.546000] HDMI: now connected [ 8.573000] HDMI: CEC Physical Addr 1.0.0.0 set from EDID [ 8.573000] HDMI: EDID read ok [ 8.574000] HDMI: initial mode set! [ 8.574000] using 50.00Hz as MonitorRefreshRate [ 8.575000] SET FORMAT: display[0], format='1080i50' [ 8.575000] HDMI mode [ 8.575000] use EDID to detect colorspace [ 8.576000] using colorspace: Itu_R_BT_709 [ 8.576000] using 8bit output [ 8.689000] HDMI: CEC use logical address 3 [ 8.690000] HDMI: CEC init completed... state is now 3! [ 8.817000] VIDEO0: enable deinterlacer [ 8.817000] VIDEO0: set fallback framerate to 60000 [ 8.818000] VIDEO0: set progressive override mode to 1 [ 8.819000] VIDEO0: set streamtype! [ 8.819000] -> set MPEG2 [ 8.819000] -> sw rave disabled! [ 8.830000] set ac3 to downmix [ 8.831000] set wmapro to downmix [ 8.831000] set ac3plus to use_hdmi_caps [ 8.831000] set dtshd to force_dts [ 8.832000] set aac to downmix [ 8.832000] DVB: registering new adapter (BCM73625) [ 8.833000] HDMI: CEC send ok! [ OK ] Found device /dev/dvb/adapter0/ca0. [ OK ] Found device /dev/dvb/adapter0/demux0. [ 8.913000] Initializing adapter 0 (BCM73625 (G3)-DVB-S2) [ 8.914000] bcmast: init frontend core... [ 8.935000] DVB: registering adapter 0 frontend 0 (BCM73625 (G3))... [ 8.952000] CI stopped... [ 8.953000] init ALSA! [ 8.954000] registered vtuner misc/vtuner0, minor 54 [ 8.955000] registered vtuner misc/vtuner1, minor 53 [ 8.968000] input: dreambox ir keyboard as /devices/virtual/input/input3 [ OK 8.969000] input: dreambox ir mouse as /devices/virtual/input/input4 0m] Found device /dev/dvb/adapter0/video0. [ OK ] Started Load Kernel Modules. [ OK ] Reached target Sound Card. Starting Apply Kernel Variables... Starting Dreambox Bootlogo... [ OK ] Started Apply Kernel Variables. [ OK ] Started Dreambox Bootlogo. [ OK ] Reached target System Initialization. [ OK ] Listening on vsftpd.socket. [ 9.078000] VIDEO0: set blank to 0 [ 9.079000] sync0 is off so we enable it [ 9.079000] sync0: allocated pcroffset 0 [ 9.080000] sync0: playback! [ 9.080000] VIDEO0: total delay: 0 (0 ms) [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ 9.087000] VIDEO0: start decode [ 9.090000] VIDEO0: flush video decoder [ 9.090000] VIDEO0 got pts failed !!!! (ret 0) [ OK ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket. [ OK ] Listening on dccamd.socket. [ OK ] Listening on busybox-telnetd.socket. [ OK ] Listening on tpmd.socket. [ OK ] Listening on dropbear.socket. [ OK ] Listening on streamproxy.socket. [ 9.126000] VIDEO0: first pts 0x0 [ 9.127000] VIDEO0: framerate changed 3 [ 9.127000] VIDEO0: resolution changed (1280 720) [ 9.128000] VIDEO0: aspect changed 3 [ 9.128000] set current avs auto aspect to 16:9 [ 9.129000] set current avs auto aspect to 16:9 [ 9.129000] set sb to 3(1) [ OK ] Listening on dbttcd.socket. [ OK ] Listening on D-Bus System Message Bus Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting tpmd.service... [ OK ] Started D-Bus System Message Bus. [ 9.251000] VIDEO0: stop decode [ 9.251000] sync0 1fff no decoder left in sync handling so disable [ 9.252000] sync0: was last pcroffset0 user so free it Starting dbttcd.service... Starting dccamd.service... [ OK ] Started Serial Getty on ttyS0. [ OK ] Reached target Login Prompts. Starting enigma2... Starting Connection service... Starting Avahi mDNS/DNS-SD Stack... Starting Login Service... [ OK ] Started dccamd.service. [ OK ] Started Avahi mDNS/DNS-SD Stack. [ OK ] Started Login Service. [ OK ] Started Connection service. [ OK ] Reached target Network. Starting Samba NMB Daemon... Starting Wait for network to be configured by ConnMan... [ OK ] Started tpmd.service. [ 10.609000] HDMI: force disconnect! [ 10.609000] HDMI: now disconnected [ 10.609000] HDMI: CEC RX stopped, state is now 0 [ 10.610000] HDMI: now connected [ 10.636000] HDMI: CEC Physical Addr 1.0.0.0 set from EDID [ 10.637000] HDMI: EDID read ok [ 10.637000] using 50.00Hz as MonitorRefreshRate [ 10.638000] SET FORMAT: display[0], format='1080i50' [ 10.639000] HDMI mode [ 10.639000] use EDID to detect colorspace [ 10.639000] using colorspace: Itu_R_BT_709 [ 10.640000] using 8bit output [ 10.748000] set current avs auto aspect to 16:9 [ 10.748000] HDMI: CEC start ... state is now 1 [ 10.749000] set sb to 3(1) [ 10.812000] HDMI: CEC use logical address 3 [ 10.813000] HDMI: CEC init completed... state is now 3! [ 10.949000] HDMI: CEC send ok! Starting WPA supplicant... Starting Hostname Service... [ OK ] Started dbttcd.service. [ 11.484000] ADDRCONF(NETDEV_UP): eth0: link is not ready [ OK ] Started WPA supplicant. [ OK ] Started Hostname Service. [ 13.125000] bcmgenet bcmgenet.0: eth0: link up, 100 Mbps, full duplex [ 13.126000] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ OK ] Started Wait for network to be configured by ConnMan. [ OK ] Reached target Network is Online. Starting Automounts filesystems on demand... [ OK ] Started Automounts filesystems on demand. [ OK ] Started Samba NMB Daemon. Starting Samba SMB Daemon... opendreambox 2.5.0 dm520 ttyS0 dm520 login: [ 19.263000] bcmast: channel 0 is in normal mode now [ 19.268000] bcmast: channel 0 is sleeping now [ 19.283000] HDMI: CEC device open ... state is 3, flushed 0 old messages from RX fifo [ 19.287000] HDMI: CEC set devtype to 0 [ 19.287000] HDMI: CEC start ... state is now 1 [ 19.289000] HDMI: CEC returned state 1 [ 19.289000] HDMI: CEC state now 801 [ 19.351000] HDMI: CEC use logical address 3 [ 19.351000] HDMI: CEC init completed... state is now 3! [ 19.487000] HDMI: CEC send ok! [ 19.609000] bcmfb: creating surface with pixel format 0x07c68888 (BPXL_eA8_B8 _G8_R8) [ 23.655000] systemd-fstab-generator[245]: Checking was requested for "rootfs" , but it is not a device. [ 33.247000] set input to 0 [ 33.248000] set fb to 2(-1) [ 33.248000] set current avs auto aspect to 16:9 [ 33.249000] set sb to 3(1) [ 33.251000] set ac3 to downmix [ 33.253000] set ac3plus to use_hdmi_caps [ 40.069000] set current avs auto aspect to 16:9 [ 40.069000] set sb to 3(1) [ 40.071000] set current avs auto aspect to 16:9 [ 40.072000] set sb to 3(1) [ 40.075000] set current avs auto aspect to 16:9 [ 40.075000] set sb to 3(1) [ 40.092000] set current avs auto aspect to 16:9 [ 40.092000] set sb to 3(1) [ 40.094000] set current avs auto aspect to 16:9 [ 40.095000] set sb to 3(1) [ 40.095000] set current avs auto aspect to 16:9 [ 40.096000] set sb to 3(1) [ 40.100000] set current avs auto aspect to 16:9 [ 40.101000] set sb to 3(1) [ 40.101000] set current avs auto aspect to 16:9 [ 40.102000] set sb to 3(1) [ 40.102000] set current avs auto aspect to 16:9 [ 40.103000] set sb to 3(1) [ 40.106000] set current avs auto aspect to 16:9 [ 40.107000] set sb to 3(1) [ 40.107000] set current avs auto aspect to 16:9 [ 40.108000] set sb to 3(1) [ 40.112000] set current avs auto aspect to 16:9 [ 40.113000] set sb to 3(1) [ 40.114000] set current avs auto aspect to 16:9 [ 40.114000] set sb to 3(1) [ 40.115000] set current avs auto aspect to 16:9 [ 40.115000] set sb to 3(1) [ 42.547000] set mute 0 1 [ 42.714000] bcmast: channel 0 is in normal mode now [ 42.735000] al8304: static current limiting is enabled for 11ms only [ 42.770000] start PCR0 on dmx 4 pid:17de index 3 [ 42.773000] start AUDIO0 on dmx 4 pid:17e8 index 1 [ 42.774000] audio ch0: xpt start [ 42.774000] audio ch0: reset GA threshold to 8ms [ 42.775000] sync0 is off so we enable it [ 42.775000] sync0: allocated pcroffset 0 [ 42.776000] sync0: demux-index 4 pcr pid 17de [ 42.776000] sync0: using 3 as pcr pidchannel [ 42.777000] audio ch0: MPEG [ 42.777000] audio ch0: streamtype set 0 [ 42.778000] audio ch0: streamtype_set: stop rave [ 42.778000] audio ch0: add stereo input to mixer DAC [ 42.779000] audio ch0: add stereo input to mixer SPDIF [ 42.779000] audio ch0: add stereo input to mixer MAI [ 42.780000] audio ch0: mai sample rate changed isr (48000) [ 42.781000] audio ch0: streamtype_set: restart rave [ 42.782000] audio ch0: decoder start [ 42.783000] audio ch0: video delay 0 (0 ms) [ 42.783000] VIDEO0: total delay: 0 (0 ms) [ 42.786000] VIDEO0: set streamtype! [ 42.786000] -> set H264 [ 42.786000] -> sw rave disabled! [ 42.787000] audio ch0 delay 18000 (200 ms) [ 42.787000] VIDEO0: total delay: 18000 (200 ms) [ 42.789000] start VIDEO0 on dmx 4 pid:17de index 3 [ 42.789000] VIDEO0: total delay: 18000 (200 ms) [ 42.798000] VIDEO0: start decode [ 42.907000] HDMI: CEC returned state 3 [ 42.907000] HDMI: CEC state now 803 [ 43.236000] HDMI: CEC send ok! [ 43.466000] HDMI: CEC send ok! [ 44.411000] audio ch0: first pts 0x1952c100, stc 0x1952ad4c, pcr valid [ 44.433000] audio ch0: lock [ 44.434000] audio ch0: sample rate changed isr (48000) [ 44.696000] VIDEO0: first pts 0x1953b67c [ 44.697000] VIDEO0: framerate changed 6 [ 44.697000] set current avs auto aspect to 16:9 [ 44.698000] set sb to 3(1) [ 44.712000] audio ch0: status ready isr [ 44.863000] VIDEO0: enable tsm [ 44.869000] HDMI: CEC send ok! [ 45.151000] HDMI: CEC send ok! [ 45.347000] HDMI: CEC send ok! [ 45.475000] HDMI: CEC send ok! [ 46.146000] HDMI: CEC send ok! [ 54.559000] stop PCR0 on dmx 4 pid:17de [ 54.562000] stop VIDEO0 on dmx 4 pid:17de [ 54.563000] VIDEO0: stop decode [ 54.565000] VIDEO0: set blank to 1 [ 54.566000] audio ch0: decoder stop [ 54.595000] stop AUDIO0 on dmx 4 pid:17e8 [ 54.596000] audio ch0: xpt stop [ 54.596000] sync0 1fff no decoder left in sync handling so disable [ 54.597000] sync0: was last pcroffset0 user so free it [ 54.646000] al8304: static current limiting is enabled for 11ms only [ 54.660000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 55.223000] start PCR0 on dmx 4 pid:13ed index 9 [ 55.225000] start AUDIO0 on dmx 4 pid:13ee index 7 [ 55.226000] audio ch0: xpt start [ 55.226000] sync0 is off so we enable it [ 55.227000] sync0: allocated pcroffset 0 [ 55.227000] sync0: demux-index 4 pcr pid 13ed [ 55.228000] sync0: using 9 as pcr pidchannel [ 55.228000] audio ch0: MPEG [ 55.229000] audio ch0: decoder start [ 55.230000] audio ch0 delay 18000 (200 ms) [ 55.230000] VIDEO0: total delay: 18000 (200 ms) [ 55.233000] start VIDEO0 on dmx 4 pid:13ed index 9 [ 55.234000] VIDEO0: total delay: 18000 (200 ms) [ 55.243000] VIDEO0: start decode [ 55.307000] audio ch0: first pts 0x154220824, stc 0x15421f1fa, pcr valid [ 55.330000] audio ch0: lock [ 55.331000] audio ch0: sample rate changed isr (48000) [ 55.615000] audio ch0: status ready isr [ 56.116000] VIDEO0: first pts 0x154248536 [ 56.271000] VIDEO0: enable tsm [ 64.152000] stop PCR0 on dmx 4 pid:13ed [ 64.154000] stop VIDEO0 on dmx 4 pid:13ed [ 64.155000] VIDEO0: stop decode [ 64.157000] audio ch0: decoder stop [ 64.186000] stop AUDIO0 on dmx 4 pid:13ee [ 64.187000] audio ch0: xpt stop [ 64.187000] sync0 1fff no decoder left in sync handling so disable [ 64.188000] sync0: was last pcroffset0 user so free it [ 64.248000] al8304: static current limiting is enabled for 11ms only [ 64.255000] start PCR0 on dmx 4 pid:17de index 3 [ 64.257000] start AUDIO0 on dmx 4 pid:17e8 index 1 [ 64.258000] audio ch0: xpt start [ 64.258000] sync0 is off so we enable it [ 64.259000] sync0: allocated pcroffset 0 [ 64.259000] sync0: demux-index 4 pcr pid 17de [ 64.260000] sync0: using 3 as pcr pidchannel [ 64.260000] audio ch0: MPEG [ 64.261000] audio ch0: decoder start [ 64.262000] audio ch0 delay 18000 (200 ms) [ 64.262000] VIDEO0: total delay: 18000 (200 ms) [ 64.266000] start VIDEO0 on dmx 4 pid:17de index 3 [ 64.267000] VIDEO0: total delay: 18000 (200 ms) [ 64.275000] VIDEO0: start decode [ 64.571000] audio ch0: first pts 0x196e7080, stc 0x196e5cd2, pcr valid [ 64.594000] audio ch0: lock [ 64.594000] audio ch0: sample rate changed isr (48000) [ 64.836000] VIDEO0: first pts 0x196f7b14 [ 64.872000] audio ch0: status ready isr [ 64.987000] VIDEO0: enable tsm [ 69.590000] stop PCR0 on dmx 4 pid:17de [ 69.591000] stop VIDEO0 on dmx 4 pid:17de [ 69.593000] VIDEO0: stop decode [ 69.594000] audio ch0: decoder stop [ 69.627000] stop AUDIO0 on dmx 4 pid:17e8 [ 69.627000] audio ch0: xpt stop [ 69.628000] sync0 1fff no decoder left in sync handling so disable [ 69.629000] sync0: was last pcroffset0 user so free it [ 69.684000] al8304: static current limiting is enabled for 11ms only [ 69.691000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 70.241000] start PCR0 on dmx 4 pid:14e7 index 10 [ 70.245000] start AUDIO0 on dmx 4 pid:14e8 index 8 [ 70.246000] audio ch0: xpt start [ 70.246000] sync0 is off so we enable it [ 70.246000] sync0: allocated pcroffset 0 [ 70.247000] sync0: demux-index 4 pcr pid 14e7 [ 70.248000] sync0: using 10 as pcr pidchannel [ 70.248000] audio ch0: MPEG [ 70.249000] audio ch0: decoder start [ 70.250000] audio ch0 delay 18000 (200 ms) [ 70.250000] VIDEO0: total delay: 18000 (200 ms) [ 70.253000] start VIDEO0 on dmx 4 pid:14e7 index 10 [ 70.254000] VIDEO0: total delay: 18000 (200 ms) [ 70.263000] VIDEO0: start decode [ 70.289000] audio ch0: first pts 0xc82129ce, stc 0xc82113ae, pcr valid [ 70.311000] audio ch0: lock [ 70.311000] audio ch0: sample rate changed isr (48000) [ 70.597000] audio ch0: status ready isr [ 70.856000] VIDEO0: first pts 0xc8233852 [ 71.009000] VIDEO0: enable tsm [ 83.074000] stop PCR0 on dmx 4 pid:14e7 [ 83.075000] stop VIDEO0 on dmx 4 pid:14e7 [ 83.077000] VIDEO0: stop decode [ 83.079000] audio ch0: decoder stop [ 83.108000] stop AUDIO0 on dmx 4 pid:14e8 [ 83.108000] audio ch0: xpt stop [ 83.109000] sync0 1fff no decoder left in sync handling so disable [ 83.110000] sync0: was last pcroffset0 user so free it [ 83.147000] al8304: static current limiting is enabled for 11ms only [ 83.207000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 83.539000] start PCR0 on dmx 4 pid:157d index 10 [ 83.541000] start AUDIO0 on dmx 4 pid:157e index 8 [ 83.542000] audio ch0: xpt start [ 83.542000] sync0 is off so we enable it [ 83.543000] sync0: allocated pcroffset 0 [ 83.543000] sync0: demux-index 4 pcr pid 157d [ 83.544000] sync0: using 10 as pcr pidchannel [ 83.544000] audio ch0: MPEG [ 83.551000] audio ch0: decoder start [ 83.552000] audio ch0 delay 18000 (200 ms) [ 83.552000] VIDEO0: total delay: 18000 (200 ms) [ 83.561000] start VIDEO0 on dmx 4 pid:157d index 10 [ 83.562000] VIDEO0: total delay: 18000 (200 ms) [ 83.570000] VIDEO0: start decode [ 83.598000] audio ch0: first pts 0x1ced9d0e4, stc 0x1ced9a2b4, pcr valid [ 83.623000] audio ch0: lock [ 83.623000] audio ch0: sample rate changed isr (48000) [ 83.974000] audio ch0: status ready isr [ 84.356000] VIDEO0: first pts 0x1cedbea48 [ 84.508000] VIDEO0: enable tsm [ 88.903000] stop PCR0 on dmx 4 pid:157d [ 88.904000] stop VIDEO0 on dmx 4 pid:157d [ 88.906000] VIDEO0: stop decode [ 88.907000] audio ch0: decoder stop [ 88.936000] stop AUDIO0 on dmx 4 pid:157e [ 88.936000] audio ch0: xpt stop [ 88.937000] sync0 1fff no decoder left in sync handling so disable [ 88.938000] sync0: was last pcroffset0 user so free it [ 89.010000] al8304: static current limiting is enabled for 11ms only [ 89.015000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 89.669000] start PCR0 on dmx 4 pid:1401 index 9 [ 89.670000] start AUDIO0 on dmx 4 pid:1402 index 6 [ 89.671000] audio ch0: xpt start [ 89.671000] sync0 is off so we enable it [ 89.672000] sync0: allocated pcroffset 0 [ 89.673000] sync0: demux-index 4 pcr pid 1401 [ 89.673000] sync0: using 9 as pcr pidchannel [ 89.674000] audio ch0: MPEG [ 89.674000] audio ch0: decoder start [ 89.675000] audio ch0 delay 18000 (200 ms) [ 89.675000] VIDEO0: total delay: 18000 (200 ms) [ 89.678000] audio ch0: first pts 0x154513a9c, stc 0x6f3c5e, pcr invalid [ 89.678000] audio ch0: no valid pcr data yet... set stc to pts! [ 89.680000] start VIDEO0 on dmx 4 pid:1401 index 9 [ 89.680000] VIDEO0: total delay: 18000 (200 ms) [ 89.688000] VIDEO0: start decode [ 89.698000] audio ch0: lock [ 89.699000] audio ch0: sample rate changed isr (48000) [ 89.699000] audio ch0: tsm fail [ 89.700000] audio ch0: pts error 0 PTS 0x54513a9c, STC 0x54512cd0, type 0 [ 90.008000] audio ch0: status ready isr [ 90.237000] VIDEO0: first pts 0x1545374f0 [ 90.388000] VIDEO0: enable tsm [ 94.379000] stop PCR0 on dmx 4 pid:1401 [ 94.381000] stop VIDEO0 on dmx 4 pid:1401 [ 94.383000] VIDEO0: stop decode [ 94.384000] audio ch0: decoder stop [ 94.413000] stop AUDIO0 on dmx 4 pid:1402 [ 94.414000] audio ch0: xpt stop [ 94.414000] sync0 1fff no decoder left in sync handling so disable [ 94.415000] sync0: was last pcroffset0 user so free it [ 94.478000] al8304: static current limiting is enabled for 11ms only [ 94.485000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 94.876000] start PCR0 on dmx 4 pid:1451 index 10 [ 94.878000] start AUDIO0 on dmx 4 pid:1452 index 8 [ 94.879000] audio ch0: xpt start [ 94.879000] sync0 is off so we enable it [ 94.880000] sync0: allocated pcroffset 0 [ 94.880000] sync0: demux-index 4 pcr pid 1451 [ 94.881000] sync0: using 10 as pcr pidchannel [ 94.881000] audio ch0: MPEG [ 94.882000] audio ch0: decoder start [ 94.883000] audio ch0 delay 18000 (200 ms) [ 94.883000] VIDEO0: total delay: 18000 (200 ms) [ 94.886000] start VIDEO0 on dmx 4 pid:1451 index 10 [ 94.887000] VIDEO0: total delay: 18000 (200 ms) [ 94.895000] VIDEO0: start decode [ 94.974000] audio ch0: first pts 0xfc3c56e, stc 0xfc3af48, pcr valid [ 94.996000] audio ch0: lock [ 94.997000] audio ch0: sample rate changed isr (48000) [ 95.282000] audio ch0: status ready isr [ 95.377000] VIDEO0: first pts 0xfc5b75e [ 95.528000] VIDEO0: enable tsm [ 101.922000] stop PCR0 on dmx 4 pid:1451 [ 101.925000] stop VIDEO0 on dmx 4 pid:1451 [ 101.927000] VIDEO0: stop decode [ 101.932000] audio ch0: decoder stop [ 101.963000] stop AUDIO0 on dmx 4 pid:1452 [ 101.963000] audio ch0: xpt stop [ 101.964000] sync0 1fff no decoder left in sync handling so disable [ 101.964000] sync0: was last pcroffset0 user so free it [ 102.031000] al8304: static current limiting is enabled for 11ms only [ 102.033000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 103.190000] start PCR0 on dmx 4 pid:196e index 10 [ 103.191000] start AUDIO0 on dmx 4 pid:1978 index 8 [ 103.191000] audio ch0: xpt start [ 103.192000] sync0 is off so we enable it [ 103.192000] sync0: allocated pcroffset 0 [ 103.193000] sync0: demux-index 4 pcr pid 196e [ 103.193000] sync0: using 10 as pcr pidchannel [ 103.196000] audio ch0: MPEG [ 103.196000] audio ch0: decoder start [ 103.197000] audio ch0 delay 18000 (200 ms) [ 103.197000] VIDEO0: total delay: 18000 (200 ms) [ 103.200000] start VIDEO0 on dmx 4 pid:196e index 10 [ 103.201000] VIDEO0: total delay: 18000 (200 ms) [ 103.208000] VIDEO0: start decode [ 103.209000] audio ch0: first pts 0x199139dc, stc 0x81d16c, pcr invalid [ 103.232000] audio ch0: lock [ 103.232000] audio ch0: sample rate changed isr (48000) [ 103.233000] audio ch0: tsm fail [ 103.233000] audio ch0: pts error 0 PTS 0x199139dc, STC 0x19912eb2, type 0 [ 103.534000] audio ch0: status ready isr [ 103.637000] VIDEO0: first pts 0x1992338e [ 103.788000] VIDEO0: enable tsm [ 109.794000] stop PCR0 on dmx 4 pid:196e [ 109.795000] stop VIDEO0 on dmx 4 pid:196e [ 109.796000] VIDEO0: stop decode [ 109.798000] audio ch0: decoder stop [ 109.827000] stop AUDIO0 on dmx 4 pid:1978 [ 109.828000] audio ch0: xpt stop [ 109.828000] sync0 1fff no decoder left in sync handling so disable [ 109.829000] sync0: was last pcroffset0 user so free it [ 109.901000] al8304: static current limiting is enabled for 11ms only [ 109.906000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 110.574000] start PCR0 on dmx 4 pid:13f7 index 9 [ 110.576000] start AUDIO0 on dmx 4 pid:13f8 index 7 [ 110.576000] audio ch0: xpt start [ 110.577000] sync0 is off so we enable it [ 110.577000] sync0: allocated pcroffset 0 [ 110.578000] sync0: demux-index 4 pcr pid 13f7 [ 110.578000] sync0: using 9 as pcr pidchannel [ 110.579000] audio ch0: MPEG [ 110.580000] audio ch0: decoder start [ 110.580000] audio ch0 delay 18000 (200 ms) [ 110.581000] VIDEO0: total delay: 18000 (200 ms) [ 110.584000] start VIDEO0 on dmx 4 pid:13f7 index 9 [ 110.585000] VIDEO0: total delay: 18000 (200 ms) [ 110.593000] VIDEO0: start decode [ 110.620000] audio ch0: first pts 0x153913130, stc 0x153911b0e, pcr valid [ 110.642000] audio ch0: lock [ 110.642000] audio ch0: sample rate changed isr (48000) [ 110.928000] audio ch0: status ready isr [ 111.317000] VIDEO0: first pts 0x1539397e6 [ 111.468000] VIDEO0: enable tsm [ 118.269000] stop PCR0 on dmx 4 pid:13f7 [ 118.270000] stop VIDEO0 on dmx 4 pid:13f7 [ 118.272000] VIDEO0: stop decode [ 118.273000] audio ch0: decoder stop [ 118.302000] stop AUDIO0 on dmx 4 pid:13f8 [ 118.303000] audio ch0: xpt stop [ 118.303000] sync0 1fff no decoder left in sync handling so disable [ 118.304000] sync0: was last pcroffset0 user so free it [ 118.366000] al8304: static current limiting is enabled for 11ms only [ 118.373000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 118.733000] start PCR0 on dmx 4 pid:1523 index 10 [ 118.735000] start AUDIO0 on dmx 4 pid:1524 index 8 [ 118.735000] audio ch0: xpt start [ 118.736000] sync0 is off so we enable it [ 118.736000] sync0: allocated pcroffset 0 [ 118.737000] sync0: demux-index 4 pcr pid 1523 [ 118.738000] sync0: using 10 as pcr pidchannel [ 118.738000] audio ch0: MPEG [ 118.739000] audio ch0: decoder start [ 118.740000] audio ch0 delay 18000 (200 ms) [ 118.740000] VIDEO0: total delay: 18000 (200 ms) [ 118.742000] audio ch0: first pts 0x17de2a5f4, stc 0x972648, pcr invalid [ 118.743000] audio ch0: no valid pcr data yet... set stc to pts! [ 118.744000] start VIDEO0 on dmx 4 pid:1523 index 10 [ 118.745000] VIDEO0: total delay: 18000 (200 ms) [ 118.753000] VIDEO0: start decode [ 118.761000] audio ch0: lock [ 118.761000] audio ch0: sample rate changed isr (48000) [ 119.047000] audio ch0: status ready isr [ 119.717000] VIDEO0: first pts 0x17de5583c [ 119.868000] VIDEO0: enable tsm [ 138.737000] stop PCR0 on dmx 4 pid:1523 [ 138.739000] stop VIDEO0 on dmx 4 pid:1523 [ 138.741000] VIDEO0: stop decode [ 138.742000] audio ch0: decoder stop [ 138.771000] stop AUDIO0 on dmx 4 pid:1524 [ 138.772000] audio ch0: xpt stop [ 138.772000] sync0 1fff no decoder left in sync handling so disable [ 138.773000] sync0: was last pcroffset0 user so free it [ 138.831000] al8304: static current limiting is enabled for 11ms only [ 138.838000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 139.298000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 139.304000] start PCR0 on dmx 4 pid:ff index 9 [ 139.305000] start AUDIO0 on dmx 4 pid:103 index 8 [ 139.306000] audio ch0: xpt start [ 139.306000] sync0 is off so we enable it [ 139.307000] sync0: allocated pcroffset 0 [ 139.307000] sync0: demux-index 4 pcr pid ff [ 139.308000] sync0: using 9 as pcr pidchannel [ 139.308000] audio ch0: AC3 [ 139.309000] audio ch0: streamtype set 1 [ 139.309000] audio ch0: streamtype_set: stop rave [ 139.310000] audio ch0: decode [ 139.310000] audio ch0: streamtype_set: restart rave [ 139.317000] audio ch0: decoder start [ 139.318000] audio ch0 delay 18000 (200 ms) [ 139.318000] VIDEO0: total delay: 18000 (200 ms) [ 139.328000] start VIDEO0 on dmx 4 pid:ff index 9 [ 139.328000] VIDEO0: total delay: 18000 (200 ms) [ 139.336000] VIDEO0: start decode [ 139.344000] audio ch0: lock [ 139.344000] audio ch0: sample rate changed isr (48000) [ 139.345000] audio ch0: tsm fail [ 139.345000] audio ch0: ignore pts error when audio is not running [ 139.378000] audio ch0: tsm fail [ 139.378000] audio ch0: ignore pts error when audio is not running [ 139.379000] audio ch0: first pts 0x1562d8fe2, stc 0x1562d7db4, pcr valid [ 139.676000] audio ch0: status ready isr [ 139.676000] audio ch0: dialnorm change isr [ 140.737000] VIDEO0: first pts 0x1563010ba [ 140.738000] VIDEO0: framerate changed 3 [ 140.738000] VIDEO0: resolution changed (1280 1080) [ 140.739000] VIDEO0: progressive changed (0) [ 140.741000] set current avs auto aspect to 16:9 [ 140.741000] set sb to 3(1) [ 140.891000] VIDEO0: enable tsm [ 155.506000] stop PCR0 on dmx 4 pid:ff [ 155.507000] stop VIDEO0 on dmx 4 pid:ff [ 155.509000] VIDEO0: stop decode [ 155.510000] audio ch0: decoder stop [ 155.539000] stop AUDIO0 on dmx 4 pid:103 [ 155.540000] audio ch0: xpt stop [ 155.540000] sync0 1fff no decoder left in sync handling so disable [ 155.541000] sync0: was last pcroffset0 user so free it [ 155.599000] al8304: static current limiting is enabled for 11ms only [ 155.658000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 155.990000] start PCR0 on dmx 4 pid:4ff index 9 [ 155.994000] start AUDIO0 on dmx 4 pid:500 index 6 [ 155.994000] audio ch0: xpt start [ 155.995000] sync0 is off so we enable it [ 155.995000] sync0: allocated pcroffset 0 [ 155.996000] sync0: demux-index 4 pcr pid 4ff [ 155.996000] sync0: using 9 as pcr pidchannel [ 155.997000] audio ch0: MPEG [ 155.997000] audio ch0: streamtype set 0 [ 155.998000] audio ch0: streamtype_set: stop rave [ 155.998000] audio ch0: streamtype_set: restart rave [ 156.000000] audio ch0: decoder start [ 156.000000] audio ch0 delay 18000 (200 ms) [ 156.001000] VIDEO0: total delay: 18000 (200 ms) [ 156.003000] VIDEO0: set streamtype! [ 156.004000] -> set MPEG2 [ 156.004000] -> sw rave disabled! [ 156.005000] audio ch0: video delay 0 (0 ms) [ 156.005000] VIDEO0: total delay: 0 (0 ms) [ 156.006000] start VIDEO0 on dmx 4 pid:4ff index 9 [ 156.007000] VIDEO0: total delay: 0 (0 ms) [ 156.015000] VIDEO0: start decode [ 156.067000] audio ch0: first pts 0xb6620630, stc 0xb661e81e, pcr valid [ 156.089000] audio ch0: lock [ 156.090000] audio ch0: sample rate changed isr (48000) [ 156.197000] audio ch0: status ready isr [ 156.457000] VIDEO0: first pts 0xb662ab1a [ 156.458000] VIDEO0: resolution changed (720 576) [ 156.608000] VIDEO0: enable tsm [ 173.469000] stop PCR0 on dmx 4 pid:4ff [ 173.470000] stop VIDEO0 on dmx 4 pid:4ff [ 173.471000] VIDEO0: stop decode [ 173.473000] audio ch0: decoder stop [ 173.502000] stop AUDIO0 on dmx 4 pid:500 [ 173.503000] audio ch0: xpt stop [ 173.503000] sync0 1fff no decoder left in sync handling so disable [ 173.504000] sync0: was last pcroffset0 user so free it [ 173.541000] al8304: static current limiting is enabled for 11ms only [ 173.549000] start PCR0 on dmx 4 pid:14e7 index 3 [ 173.551000] start AUDIO0 on dmx 4 pid:14e8 index 1 [ 173.551000] audio ch0: xpt start [ 173.552000] sync0 is off so we enable it [ 173.552000] sync0: allocated pcroffset 0 [ 173.553000] sync0: demux-index 4 pcr pid 14e7 [ 173.553000] sync0: using 3 as pcr pidchannel [ 173.554000] audio ch0: MPEG [ 173.555000] audio ch0: decoder start [ 173.555000] audio ch0: video delay 0 (0 ms) [ 173.556000] VIDEO0: total delay: 0 (0 ms) [ 173.559000] VIDEO0: set streamtype! [ 173.559000] -> set H264 [ 173.560000] -> sw rave disabled! [ 173.560000] audio ch0 delay 18000 (200 ms) [ 173.561000] VIDEO0: total delay: 18000 (200 ms) [ 173.563000] start VIDEO0 on dmx 4 pid:14e7 index 3 [ 173.564000] VIDEO0: total delay: 18000 (200 ms) [ 173.573000] VIDEO0: start decode [ 173.970000] audio ch0: first pts 0xc8af8bce, stc 0xc8af75b0, pcr valid [ 173.992000] audio ch0: lock [ 173.993000] audio ch0: sample rate changed isr (48000) [ 174.278000] audio ch0: status ready isr [ 174.397000] VIDEO0: first pts 0xc8b17e32 [ 174.398000] VIDEO0: framerate changed 6 [ 174.398000] VIDEO0: resolution changed (1280 720) [ 174.401000] set current avs auto aspect to 16:9 [ 174.401000] set sb to 3(1) [ 174.551000] VIDEO0: enable tsm [ 174.577000] VIDEO0: progressive changed (1) [ 177.465000] stop PCR0 on dmx 4 pid:14e7 [ 177.466000] stop VIDEO0 on dmx 4 pid:14e7 [ 177.469000] VIDEO0: stop decode [ 177.470000] audio ch0: decoder stop [ 177.502000] stop AUDIO0 on dmx 4 pid:14e8 [ 177.503000] audio ch0: xpt stop [ 177.503000] sync0 1fff no decoder left in sync handling so disable [ 177.504000] sync0: was last pcroffset0 user so free it [ 177.545000] al8304: static current limiting is enabled for 11ms only [ 177.605000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 178.384000] start PCR0 on dmx 4 pid:a3 index 10 [ 178.388000] start AUDIO0 on dmx 4 pid:68 index 8 [ 178.388000] audio ch0: xpt start [ 178.389000] sync0 is off so we enable it [ 178.389000] sync0: allocated pcroffset 0 [ 178.390000] sync0: demux-index 4 pcr pid a3 [ 178.390000] sync0: using 10 as pcr pidchannel [ 178.391000] audio ch0: MPEG [ 178.392000] audio ch0: decoder start [ 178.392000] audio ch0 delay 18000 (200 ms) [ 178.393000] VIDEO0: total delay: 18000 (200 ms) [ 178.395000] VIDEO0: set streamtype! [ 178.396000] -> set MPEG2 [ 178.396000] -> sw rave disabled! [ 178.397000] audio ch0: video delay 0 (0 ms) [ 178.397000] VIDEO0: total delay: 0 (0 ms) [ 178.399000] start VIDEO0 on dmx 4 pid:a3 index 10 [ 178.399000] VIDEO0: total delay: 0 (0 ms) [ 178.403000] audio ch0: first pts 0xf27690ce, stc 0xe9147a, pcr invalid [ 178.408000] VIDEO0: start decode [ 178.425000] audio ch0: lock [ 178.425000] audio ch0: sample rate changed isr (48000) [ 178.426000] audio ch0: tsm fail [ 178.426000] audio ch0: pts error 0 PTS 0xf27690ce, STC 0xf276831e, type 0 [ 178.534000] audio ch0: status ready isr [ 178.938000] VIDEO0: first pts 0xf2779c2e [ 178.938000] VIDEO0: framerate changed 3 [ 178.939000] VIDEO0: resolution changed (720 576) [ 178.942000] set current avs auto aspect to 16:9 [ 178.942000] set sb to 3(1) [ 179.092000] VIDEO0: enable tsm [ 179.417000] VIDEO0: progressive changed (0) [ 181.626000] stop PCR0 on dmx 4 pid:a3 [ 181.627000] stop VIDEO0 on dmx 4 pid:a3 [ 181.629000] VIDEO0: stop decode [ 181.630000] audio ch0: decoder stop [ 181.660000] stop AUDIO0 on dmx 4 pid:68 [ 181.660000] audio ch0: xpt stop [ 181.661000] sync0 1fff no decoder left in sync handling so disable [ 181.661000] sync0: was last pcroffset0 user so free it [ 181.702000] al8304: static current limiting is enabled for 11ms only [ 181.709000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 182.025000] start PCR0 on dmx 4 pid:ff index 10 [ 182.026000] start AUDIO0 on dmx 4 pid:100 index 8 [ 182.027000] audio ch0: xpt start [ 182.027000] sync0 is off so we enable it [ 182.028000] sync0: allocated pcroffset 0 [ 182.028000] sync0: demux-index 4 pcr pid ff [ 182.029000] sync0: using 10 as pcr pidchannel [ 182.030000] audio ch0: MPEG [ 182.031000] audio ch0: decoder start [ 182.031000] audio ch0: video delay 0 (0 ms) [ 182.032000] VIDEO0: total delay: 0 (0 ms) [ 182.035000] start VIDEO0 on dmx 4 pid:ff index 10 [ 182.036000] VIDEO0: total delay: 0 (0 ms) [ 182.046000] VIDEO0: start decode [ 182.136000] audio ch0: first pts 0xb688aa1a, stc 0xb6888c02, pcr valid [ 182.159000] audio ch0: lock [ 182.159000] audio ch0: sample rate changed isr (48000) [ 182.267000] audio ch0: status ready isr [ 182.698000] VIDEO0: first pts 0xb68976d8 [ 182.849000] VIDEO0: enable tsm [ 201.352000] stop PCR0 on dmx 4 pid:ff [ 201.353000] stop VIDEO0 on dmx 4 pid:ff [ 201.356000] VIDEO0: stop decode [ 201.357000] audio ch0: decoder stop [ 201.386000] stop AUDIO0 on dmx 4 pid:100 [ 201.387000] audio ch0: xpt stop [ 201.387000] sync0 1fff no decoder left in sync handling so disable [ 201.388000] sync0: was last pcroffset0 user so free it [ 201.428000] al8304: static current limiting is enabled for 11ms only [ 201.435000] start PCR0 on dmx 4 pid:17de index 3 [ 201.437000] start AUDIO0 on dmx 4 pid:17e8 index 1 [ 201.438000] audio ch0: xpt start [ 201.439000] sync0 is off so we enable it [ 201.439000] sync0: allocated pcroffset 0 [ 201.440000] sync0: demux-index 4 pcr pid 17de [ 201.440000] sync0: using 3 as pcr pidchannel [ 201.441000] audio ch0: MPEG [ 201.442000] audio ch0: decoder start [ 201.442000] audio ch0: video delay 0 (0 ms) [ 201.443000] VIDEO0: total delay: 0 (0 ms) [ 201.446000] VIDEO0: set streamtype! [ 201.447000] -> set H264 [ 201.447000] -> sw rave disabled! [ 201.448000] audio ch0 delay 18000 (200 ms) [ 201.448000] VIDEO0: total delay: 18000 (200 ms) [ 201.450000] start VIDEO0 on dmx 4 pid:17de index 3 [ 201.450000] VIDEO0: total delay: 18000 (200 ms) [ 201.459000] VIDEO0: start decode [ 201.853000] audio ch0: first pts 0x1a2af700, stc 0x1094882, pcr invalid [ 201.876000] audio ch0: lock [ 201.876000] audio ch0: sample rate changed isr (48000) [ 201.877000] audio ch0: tsm fail [ 201.877000] audio ch0: pts error 0 PTS 0x1a2af700, STC 0x1a2aebda, type 0 [ 202.178000] audio ch0: status ready isr [ 202.418000] VIDEO0: first pts 0x1a2c1db4 [ 202.418000] VIDEO0: framerate changed 6 [ 202.419000] VIDEO0: resolution changed (1280 720) [ 202.420000] set current avs auto aspect to 16:9 [ 202.420000] set sb to 3(1) [ 202.458000] VIDEO0: progressive changed (1) [ 202.568000] VIDEO0: enable tsm [ 210.314000] stop PCR0 on dmx 4 pid:17de [ 210.315000] stop VIDEO0 on dmx 4 pid:17de [ 210.317000] VIDEO0: stop decode [ 210.319000] audio ch0: decoder stop [ 210.350000] stop AUDIO0 on dmx 4 pid:17e8 [ 210.350000] audio ch0: xpt stop [ 210.351000] sync0 1fff no decoder left in sync handling so disable [ 210.351000] sync0: was last pcroffset0 user so free it [ 210.414000] al8304: static current limiting is enabled for 11ms only [ 210.423000] start PCR0 on dmx 4 pid:14e7 index 3 [ 210.425000] start AUDIO0 on dmx 4 pid:14e8 index 1 [ 210.426000] audio ch0: xpt start [ 210.426000] sync0 is off so we enable it [ 210.427000] sync0: allocated pcroffset 0 [ 210.427000] sync0: demux-index 4 pcr pid 14e7 [ 210.428000] sync0: using 3 as pcr pidchannel [ 210.428000] audio ch0: MPEG [ 210.430000] audio ch0: decoder start [ 210.430000] audio ch0 delay 18000 (200 ms) [ 210.431000] VIDEO0: total delay: 18000 (200 ms) [ 210.435000] start VIDEO0 on dmx 4 pid:14e7 index 3 [ 210.435000] VIDEO0: total delay: 18000 (200 ms) [ 210.444000] VIDEO0: start decode [ 210.739000] audio ch0: first pts 0xc8e20a0e, stc 0xc8e1f3de, pcr valid [ 210.761000] audio ch0: lock [ 210.761000] audio ch0: sample rate changed isr (48000) [ 210.958000] VIDEO0: first pts 0xc8e3a542 [ 211.047000] audio ch0: status ready isr [ 211.111000] VIDEO0: enable tsm [ 214.872000] stop PCR0 on dmx 4 pid:14e7 [ 214.873000] stop VIDEO0 on dmx 4 pid:14e7 [ 214.875000] VIDEO0: stop decode [ 214.876000] audio ch0: decoder stop [ 214.905000] stop AUDIO0 on dmx 4 pid:14e8 [ 214.906000] audio ch0: xpt stop [ 214.906000] sync0 1fff no decoder left in sync handling so disable [ 214.907000] sync0: was last pcroffset0 user so free it [ 214.951000] al8304: static current limiting is enabled for 11ms only [ 215.011000] start PCR0 on dmx 4 pid:a3 index 3 [ 215.012000] start AUDIO0 on dmx 4 pid:68 index 1 [ 215.012000] audio ch0: xpt start [ 215.013000] sync0 is off so we enable it [ 215.013000] sync0: allocated pcroffset 0 [ 215.014000] sync0: demux-index 4 pcr pid a3 [ 215.014000] sync0: using 3 as pcr pidchannel [ 215.017000] audio ch0: MPEG [ 215.017000] audio ch0: decoder start [ 215.018000] audio ch0 delay 18000 (200 ms) [ 215.019000] VIDEO0: total delay: 18000 (200 ms) [ 215.021000] VIDEO0: set streamtype! [ 215.022000] -> set MPEG2 [ 215.022000] -> sw rave disabled! [ 215.023000] audio ch0: video delay 0 (0 ms) [ 215.023000] VIDEO0: total delay: 0 (0 ms) [ 215.024000] start VIDEO0 on dmx 4 pid:a3 index 3 [ 215.025000] VIDEO0: total delay: 0 (0 ms) [ 215.033000] VIDEO0: start decode [ 215.171000] audio ch0: first pts 0xf2a90f0e, stc 0xf2a8f928, pcr valid [ 215.193000] audio ch0: lock [ 215.194000] audio ch0: sample rate changed isr (48000) [ 215.279000] audio ch0: status ready isr [ 215.518000] VIDEO0: first pts 0xf2a9df5e [ 215.518000] VIDEO0: framerate changed 3 [ 215.519000] VIDEO0: resolution changed (720 576) [ 215.520000] set current avs auto aspect to 16:9 [ 215.520000] set sb to 3(1) [ 215.670000] VIDEO0: enable tsm [ 216.038000] VIDEO0: progressive changed (0) [ 217.656000] stop PCR0 on dmx 4 pid:a3 [ 217.659000] stop VIDEO0 on dmx 4 pid:a3 [ 217.661000] VIDEO0: stop decode [ 217.666000] audio ch0: decoder stop [ 217.698000] stop AUDIO0 on dmx 4 pid:68 [ 217.698000] audio ch0: xpt stop [ 217.699000] sync0 1fff no decoder left in sync handling so disable [ 217.699000] sync0: was last pcroffset0 user so free it [ 217.749000] al8304: static current limiting is enabled for 11ms only [ 217.759000] start PCR0 on dmx 4 pid:ff index 3 [ 217.760000] start AUDIO0 on dmx 4 pid:100 index 1 [ 217.761000] audio ch0: xpt start [ 217.762000] sync0 is off so we enable it [ 217.762000] sync0: allocated pcroffset 0 [ 217.763000] sync0: demux-index 4 pcr pid ff [ 217.763000] sync0: using 3 as pcr pidchannel [ 217.764000] audio ch0: MPEG [ 217.765000] audio ch0: decoder start [ 217.766000] audio ch0: video delay 0 (0 ms) [ 217.766000] VIDEO0: total delay: 0 (0 ms) [ 217.770000] start VIDEO0 on dmx 4 pid:ff index 3 [ 217.771000] VIDEO0: total delay: 0 (0 ms) [ 217.780000] VIDEO0: start decode [ 217.993000] audio ch0: first pts 0xb6b9e7ba, stc 0xb6b9c9a8, pcr valid [ 218.016000] audio ch0: lock [ 218.016000] audio ch0: sample rate changed isr (48000) [ 218.123000] audio ch0: status ready isr [ 218.178000] VIDEO0: first pts 0xb6ba3e58 [ 218.328000] VIDEO0: enable tsm [ 219.936000] stop PCR0 on dmx 4 pid:ff [ 219.937000] stop VIDEO0 on dmx 4 pid:ff [ 219.939000] VIDEO0: stop decode [ 219.940000] audio ch0: decoder stop [ 219.970000] stop AUDIO0 on dmx 4 pid:100 [ 219.970000] audio ch0: xpt stop [ 219.971000] sync0 1fff no decoder left in sync handling so disable [ 219.971000] sync0: was last pcroffset0 user so free it [ 220.010000] al8304: static current limiting is enabled for 11ms only [ 220.016000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 220.688000] start PCR0 on dmx 4 pid:a6 index 10 [ 220.690000] start AUDIO0 on dmx 4 pid:80 index 8 [ 220.691000] audio ch0: xpt start [ 220.691000] sync0 is off so we enable it [ 220.692000] sync0: allocated pcroffset 0 [ 220.692000] sync0: demux-index 4 pcr pid a6 [ 220.693000] sync0: using 10 as pcr pidchannel [ 220.693000] audio ch0: MPEG [ 220.694000] audio ch0: decoder start [ 220.695000] audio ch0: video delay 0 (0 ms) [ 220.695000] VIDEO0: total delay: 0 (0 ms) [ 220.699000] start VIDEO0 on dmx 4 pid:a6 index 10 [ 220.700000] VIDEO0: total delay: 0 (0 ms) [ 220.708000] VIDEO0: start decode [ 220.779000] audio ch0: first pts 0xf2b0c26c, stc 0xf2b0ac76, pcr valid [ 220.801000] audio ch0: lock [ 220.801000] audio ch0: sample rate changed isr (48000) [ 220.886000] audio ch0: status ready isr [ 221.338000] VIDEO0: first pts 0xf2b1cc84 [ 221.489000] VIDEO0: enable tsm [ 222.508000] stop PCR0 on dmx 4 pid:a6 [ 222.509000] stop VIDEO0 on dmx 4 pid:a6 [ 222.511000] VIDEO0: stop decode [ 222.512000] audio ch0: decoder stop [ 222.541000] stop AUDIO0 on dmx 4 pid:80 [ 222.542000] audio ch0: xpt stop [ 222.542000] sync0 1fff no decoder left in sync handling so disable [ 222.543000] sync0: was last pcroffset0 user so free it [ 222.584000] al8304: static current limiting is enabled for 11ms only [ 222.590000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 222.873000] start PCR0 on dmx 4 pid:1ff index 10 [ 222.877000] start AUDIO0 on dmx 4 pid:200 index 8 [ 222.878000] audio ch0: xpt start [ 222.879000] sync0 is off so we enable it [ 222.879000] sync0: allocated pcroffset 0 [ 222.880000] sync0: demux-index 4 pcr pid 1ff [ 222.880000] sync0: using 10 as pcr pidchannel [ 222.881000] audio ch0: MPEG [ 222.882000] audio ch0: decoder start [ 222.882000] audio ch0: video delay 0 (0 ms) [ 222.883000] VIDEO0: total delay: 0 (0 ms) [ 222.886000] start VIDEO0 on dmx 4 pid:1ff index 10 [ 222.887000] VIDEO0: total delay: 0 (0 ms) [ 222.895000] VIDEO0: start decode [ 222.936000] audio ch0: first pts 0xb6be17bc, stc 0xb6bdf9a4, pcr valid [ 222.959000] audio ch0: lock [ 222.959000] audio ch0: sample rate changed isr (48000) [ 223.067000] audio ch0: status ready isr [ 223.358000] VIDEO0: first pts 0xb6beb8dc [ 223.509000] VIDEO0: enable tsm [ 224.324000] stop PCR0 on dmx 4 pid:1ff [ 224.325000] stop VIDEO0 on dmx 4 pid:1ff [ 224.326000] VIDEO0: stop decode [ 224.327000] audio ch0: decoder stop [ 224.356000] stop AUDIO0 on dmx 4 pid:200 [ 224.357000] audio ch0: xpt stop [ 224.357000] sync0 1fff no decoder left in sync handling so disable [ 224.358000] sync0: was last pcroffset0 user so free it [ 224.395000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 224.543000] start PCR0 on dmx 4 pid:2ff index 8 [ 224.545000] start AUDIO0 on dmx 4 pid:300 index 5 [ 224.545000] audio ch0: xpt start [ 224.546000] sync0 is off so we enable it [ 224.546000] sync0: allocated pcroffset 0 [ 224.547000] sync0: demux-index 4 pcr pid 2ff [ 224.547000] sync0: using 8 as pcr pidchannel [ 224.548000] audio ch0: MPEG [ 224.549000] audio ch0: decoder start [ 224.549000] audio ch0: video delay 0 (0 ms) [ 224.550000] VIDEO0: total delay: 0 (0 ms) [ 224.553000] start VIDEO0 on dmx 4 pid:2ff index 8 [ 224.554000] VIDEO0: total delay: 0 (0 ms) [ 224.562000] VIDEO0: start decode [ 224.650000] audio ch0: first pts 0xb6c08fe4, stc 0xb6c071d6, pcr valid [ 224.673000] audio ch0: lock [ 224.673000] audio ch0: sample rate changed isr (48000) [ 224.781000] audio ch0: status ready isr [ 225.158000] VIDEO0: first pts 0xb6c18012 [ 225.309000] VIDEO0: enable tsm [ 226.209000] stop PCR0 on dmx 4 pid:2ff [ 226.210000] stop VIDEO0 on dmx 4 pid:2ff [ 226.211000] VIDEO0: stop decode [ 226.213000] audio ch0: decoder stop [ 226.243000] stop AUDIO0 on dmx 4 pid:300 [ 226.243000] audio ch0: xpt stop [ 226.243000] sync0 1fff no decoder left in sync handling so disable [ 226.244000] sync0: was last pcroffset0 user so free it [ 226.280000] al8304: static current limiting is enabled for 11ms only [ 226.286000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 226.659000] start PCR0 on dmx 4 pid:5ff index 10 [ 226.661000] start AUDIO0 on dmx 4 pid:600 index 8 [ 226.662000] audio ch0: xpt start [ 226.662000] sync0 is off so we enable it [ 226.663000] sync0: allocated pcroffset 0 [ 226.663000] sync0: demux-index 4 pcr pid 5ff [ 226.664000] sync0: using 10 as pcr pidchannel [ 226.664000] audio ch0: MPEG [ 226.665000] audio ch0: decoder start [ 226.666000] audio ch0: video delay 0 (0 ms) [ 226.666000] VIDEO0: total delay: 0 (0 ms) [ 226.670000] start VIDEO0 on dmx 4 pid:5ff index 10 [ 226.670000] VIDEO0: total delay: 0 (0 ms) [ 226.679000] VIDEO0: start decode [ 226.769000] audio ch0: first pts 0xc4b1ce2a, stc 0xc4b1b002, pcr valid [ 226.792000] audio ch0: lock [ 226.792000] audio ch0: sample rate changed isr (48000) [ 226.900000] audio ch0: status ready isr [ 227.043000] audio ch0: unlock [ 227.043000] audio ch0: lock [ 227.258000] VIDEO0: first pts 0xc4b2aa52 [ 227.259000] audio ch0: unlock [ 227.259000] audio ch0: lock [ 227.410000] VIDEO0: enable tsm [ 227.475000] audio ch0: unlock [ 227.475000] audio ch0: lock [ 227.763000] audio ch0: unlock [ 227.763000] audio ch0: lock [ 227.979000] audio ch0: unlock [ 227.979000] audio ch0: lock [ 228.219000] audio ch0: unlock [ 228.219000] audio ch0: lock [ 228.276000] stop PCR0 on dmx 4 pid:5ff [ 228.277000] stop VIDEO0 on dmx 4 pid:5ff [ 228.288000] VIDEO0: stop decode [ 228.290000] audio ch0: decoder stop [ 228.319000] stop AUDIO0 on dmx 4 pid:600 [ 228.320000] audio ch0: xpt stop [ 228.320000] sync0 1fff no decoder left in sync handling so disable [ 228.321000] sync0: was last pcroffset0 user so free it [ 228.356000] al8304: static current limiting is enabled for 11ms only [ 228.358000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 229.274000] start PCR0 on dmx 4 pid:a7 index 10 [ 229.277000] start AUDIO0 on dmx 4 pid:88 index 8 [ 229.277000] audio ch0: xpt start [ 229.278000] sync0 is off so we enable it [ 229.278000] sync0: allocated pcroffset 0 [ 229.279000] sync0: demux-index 4 pcr pid a7 [ 229.279000] sync0: using 10 as pcr pidchannel [ 229.280000] audio ch0: MPEG [ 229.282000] audio ch0: decoder start [ 229.282000] audio ch0: video delay 0 (0 ms) [ 229.282000] VIDEO0: total delay: 0 (0 ms) [ 229.284000] audio ch0: first pts 0xf2bc706a, stc 0x12ef45a, pcr invalid [ 229.285000] audio ch0: no valid pcr data yet... set stc to pts! [ 229.289000] start VIDEO0 on dmx 4 pid:a7 index 10 [ 229.289000] VIDEO0: total delay: 0 (0 ms) [ 229.298000] VIDEO0: start decode [ 229.306000] audio ch0: lock [ 229.306000] audio ch0: sample rate changed isr (48000) [ 229.307000] audio ch0: tsm fail [ 229.307000] audio ch0: pts error 0 PTS 0xf2bc706a, STC 0xf2bc62ba, type 0 [ 229.415000] audio ch0: status ready isr [ 229.478000] VIDEO0: first pts 0xf2bd193c [ 229.628000] VIDEO0: enable tsm [ 233.640000] stop PCR0 on dmx 4 pid:a7 [ 233.641000] stop VIDEO0 on dmx 4 pid:a7 [ 233.643000] VIDEO0: stop decode [ 233.644000] audio ch0: decoder stop [ 233.673000] stop AUDIO0 on dmx 4 pid:88 [ 233.674000] audio ch0: xpt stop [ 233.674000] sync0 1fff no decoder left in sync handling so disable [ 233.675000] sync0: was last pcroffset0 user so free it [ 233.721000] al8304: static current limiting is enabled for 11ms only [ 233.727000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) [ 234.309000] start PCR0 on dmx 4 pid:14d3 index 9 [ 234.310000] start AUDIO0 on dmx 4 pid:14d4 index 7 [ 234.311000] audio ch0: xpt start [ 234.311000] sync0 is off so we enable it [ 234.312000] sync0: allocated pcroffset 0 [ 234.312000] sync0: demux-index 4 pcr pid 14d3 [ 234.313000] sync0: using 9 as pcr pidchannel [ 234.319000] audio ch0: MPEG [ 234.319000] audio ch0: decoder start [ 234.320000] audio ch0: video delay 0 (0 ms) [ 234.320000] VIDEO0: total delay: 0 (0 ms) [ 234.326000] VIDEO0: set streamtype! [ 234.327000] -> set H264 [ 234.327000] -> sw rave disabled! [ 234.327000] audio ch0 delay 18000 (200 ms) [ 234.328000] VIDEO0: total delay: 18000 (200 ms) [ 234.329000] start VIDEO0 on dmx 4 pid:14d3 index 9 [ 234.330000] VIDEO0: total delay: 18000 (200 ms) [ 234.337000] VIDEO0: start decode [ 234.368000] audio ch0: first pts 0xc860ef76, stc 0xc860d954, pcr valid [ 234.390000] audio ch0: lock [ 234.390000] audio ch0: sample rate changed isr (48000) [ 234.676000] audio ch0: status ready isr [ 235.138000] VIDEO0: first pts 0xc8635518 [ 235.138000] VIDEO0: framerate changed 6 [ 235.138000] VIDEO0: resolution changed (1280 720) [ 235.139000] set current avs auto aspect to 16:9 [ 235.140000] set sb to 3(1) [ 235.290000] VIDEO0: enable tsm [ 235.338000] VIDEO0: progressive changed (1) [ 259.405000] stop PCR0 on dmx 4 pid:14d3 [ 259.406000] stop VIDEO0 on dmx 4 pid:14d3 [ 259.408000] VIDEO0: stop decode [ 259.409000] audio ch0: decoder stop [ 259.439000] stop AUDIO0 on dmx 4 pid:14d4 [ 259.439000] audio ch0: xpt stop [ 259.440000] sync0 1fff no decoder left in sync handling so disable [ 259.440000] sync0: was last pcroffset0 user so free it [ 259.499000] al8304: static current limiting is enabled for 11ms only [ 259.506000] start PCR0 on dmx 4 pid:1451 index 3 [ 259.508000] start AUDIO0 on dmx 4 pid:1452 index 1 [ 259.509000] audio ch0: xpt start [ 259.509000] sync0 is off so we enable it [ 259.510000] sync0: allocated pcroffset 0 [ 259.510000] sync0: demux-index 4 pcr pid 1451 [ 259.511000] sync0: using 3 as pcr pidchannel [ 259.511000] audio ch0: MPEG [ 259.512000] audio ch0: decoder start [ 259.513000] audio ch0 delay 18000 (200 ms) [ 259.513000] VIDEO0: total delay: 18000 (200 ms) [ 259.516000] start VIDEO0 on dmx 4 pid:1451 index 3 [ 259.517000] VIDEO0: total delay: 18000 (200 ms) [ 259.526000] VIDEO0: start decode [ 259.808000] audio ch0: first pts 0x10a6222e, stc 0x10a60c20, pcr valid [ 259.830000] audio ch0: lock [ 259.830000] audio ch0: sample rate changed isr (48000) [ 260.116000] audio ch0: status ready isr [ 260.518000] VIDEO0: first pts 0x10a8795e [ 260.670000] VIDEO0: enable tsm [ 269.627000] stop PCR0 on dmx 4 pid:1451 [ 269.628000] stop VIDEO0 on dmx 4 pid:1451 [ 269.632000] VIDEO0: stop decode [ 269.632000] audio ch0: decoder stop [ 269.662000] stop AUDIO0 on dmx 4 pid:1452 [ 269.663000] audio ch0: xpt stop [ 269.663000] sync0 1fff no decoder left in sync handling so disable [ 269.664000] sync0: was last pcroffset0 user so free it [ 269.705000] al8304: static current limiting is enabled for 11ms only [ 269.767000] start PCR0 on dmx 4 pid:ff index 3 [ 269.768000] start AUDIO0 on dmx 4 pid:100 index 1 [ 269.769000] audio ch0: xpt start [ 269.769000] sync0 is off so we enable it [ 269.770000] sync0: allocated pcroffset 0 [ 269.770000] sync0: demux-index 4 pcr pid ff [ 269.771000] sync0: using 3 as pcr pidchannel [ 269.771000] audio ch0: MPEG [ 269.772000] audio ch0: decoder start [ 269.773000] audio ch0 delay 18000 (200 ms) [ 269.773000] VIDEO0: total delay: 18000 (200 ms) [ 269.777000] VIDEO0: set streamtype! [ 269.778000] -> set MPEG2 [ 269.778000] -> sw rave disabled! [ 269.779000] audio ch0: video delay 0 (0 ms) [ 269.779000] VIDEO0: total delay: 0 (0 ms) [ 269.781000] start VIDEO0 on dmx 4 pid:ff index 3 [ 269.782000] VIDEO0: total delay: 0 (0 ms) [ 269.790000] VIDEO0: start decode [ 269.977000] audio ch0: first pts 0xb7014b5a, stc 0xb7012d46, pcr valid [ 270.000000] audio ch0: lock [ 270.000000] audio ch0: sample rate changed isr (48000) [ 270.108000] audio ch0: status ready isr [ 270.358000] VIDEO0: first pts 0xb7021818 [ 270.359000] VIDEO0: framerate changed 3 [ 270.359000] VIDEO0: resolution changed (720 576) [ 270.360000] set current avs auto aspect to 16:9 [ 270.361000] set sb to 3(1) [ 270.518000] VIDEO0: enable tsm [ 270.798000] VIDEO0: progressive changed (0) [ 278.091000] stop PCR0 on dmx 4 pid:ff [ 278.093000] stop VIDEO0 on dmx 4 pid:ff [ 278.094000] VIDEO0: stop decode [ 278.095000] audio ch0: decoder stop [ 278.124000] stop AUDIO0 on dmx 4 pid:100 [ 278.125000] audio ch0: xpt stop [ 278.125000] sync0 1fff no decoder left in sync handling so disable [ 278.126000] sync0: was last pcroffset0 user so free it [ 278.186000] al8304: static current limiting is enabled for 11ms only [ 278.194000] start PCR0 on dmx 4 pid:a3 index 3 [ 278.195000] start AUDIO0 on dmx 4 pid:68 index 1 [ 278.196000] audio ch0: xpt start [ 278.196000] sync0 is off so we enable it [ 278.197000] sync0: allocated pcroffset 0 [ 278.197000] sync0: demux-index 4 pcr pid a3 [ 278.198000] sync0: using 3 as pcr pidchannel [ 278.199000] audio ch0: MPEG [ 278.200000] audio ch0: decoder start [ 278.200000] audio ch0: video delay 0 (0 ms) [ 278.201000] VIDEO0: total delay: 0 (0 ms) [ 278.204000] start VIDEO0 on dmx 4 pid:a3 index 3 [ 278.205000] VIDEO0: total delay: 0 (0 ms) [ 278.213000] VIDEO0: start decode [ 278.340000] audio ch0: first pts 0xf2ffce8e, stc 0xf2ffb8a0, pcr valid [ 278.362000] audio ch0: lock [ 278.362000] audio ch0: sample rate changed isr (48000) [ 278.447000] audio ch0: status ready isr [ 278.678000] VIDEO0: first pts 0xf3008dfe [ 278.830000] VIDEO0: enable tsm [ 283.450000] stop PCR0 on dmx 4 pid:a3 [ 283.454000] stop VIDEO0 on dmx 4 pid:a3 [ 283.455000] VIDEO0: stop decode [ 283.461000] audio ch0: decoder stop [ 283.492000] stop AUDIO0 on dmx 4 pid:68 [ 283.493000] audio ch0: xpt stop [ 283.493000] sync0 1fff no decoder left in sync handling so disable [ 283.494000] sync0: was last pcroffset0 user so free it [ 283.600000] al8304: static current limiting is enabled for 11ms only [ 283.607000] start PCR0 on dmx 4 pid:14e7 index 3 [ 283.614000] start AUDIO0 on dmx 4 pid:14e8 index 1 [ 283.615000] audio ch0: xpt start [ 283.615000] sync0 is off so we enable it [ 283.616000] sync0: allocated pcroffset 0 [ 283.616000] sync0: demux-index 4 pcr pid 14e7 [ 283.617000] sync0: using 3 as pcr pidchannel [ 283.617000] audio ch0: MPEG [ 283.618000] audio ch0: decoder start [ 283.619000] audio ch0: video delay 0 (0 ms) [ 283.619000] VIDEO0: total delay: 0 (0 ms) [ 283.688000] VIDEO0: set streamtype! [ 283.689000] -> set H264 [ 283.689000] -> sw rave disabled! [ 283.689000] audio ch0 delay 18000 (200 ms) [ 283.690000] VIDEO0: total delay: 18000 (200 ms) [ 283.691000] start VIDEO0 on dmx 4 pid:14e7 index 3 [ 283.692000] VIDEO0: total delay: 18000 (200 ms) [ 283.700000] VIDEO0: start decode [ 284.084000] audio ch0: first pts 0xc946c30e, stc 0xc946ace4, pcr valid [ 284.106000] audio ch0: lock [ 284.106000] audio ch0: sample rate changed isr (48000) [ 284.392000] audio ch0: status ready isr [ 284.478000] VIDEO0: first pts 0xc948aa32 [ 284.479000] VIDEO0: framerate changed 6 [ 284.479000] VIDEO0: resolution changed (1280 720) [ 284.480000] set current avs auto aspect to 16:9 [ 284.481000] set sb to 3(1) [ 284.631000] VIDEO0: enable tsm [ 284.698000] VIDEO0: progressive changed (1) [ 293.061000] XPT4 queue 0 overflow (PID 0012) ! [ 294.198000] stop PCR0 on dmx 4 pid:14e7 [ 294.201000] stop VIDEO0 on dmx 4 pid:14e7 [ 294.202000] VIDEO0: stop decode [ 294.203000] audio ch0: decoder stop [ 294.235000] stop AUDIO0 on dmx 4 pid:14e8 [ 294.236000] audio ch0: xpt stop [ 294.236000] sync0 1fff no decoder left in sync handling so disable [ 294.237000] sync0: was last pcroffset0 user so free it [ 312.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 312.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO ) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 312.019000] Cpu 0 [ 312.019000] $ 0 : 00000000 10008700 00010000 00000045 [ 312.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 312.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 312.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 312.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 312.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 312.023000] $24 : 00000000 8005ba00 [ 312.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 312.024000] Hi : 00000042 [ 312.024000] Lo : fb012dc0 [ 312.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 312.025000] Tainted: P O [ 312.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 312.027000] Status: 10008703 KERNEL EXL IE [ 312.027000] Cause : 80808000 [ 312.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 340.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 340.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO ) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 340.019000] Cpu 0 [ 340.019000] $ 0 : 00000000 10008700 00010000 0000004e [ 340.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 340.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 340.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 340.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 340.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 340.023000] $24 : 00000000 8005ba00 [ 340.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 340.024000] Hi : 00000042 [ 340.024000] Lo : fb012dc0 [ 340.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 340.025000] Tainted: P O [ 340.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 340.027000] Status: 10008703 KERNEL EXL IE [ 340.027000] Cause : 00808000 [ 340.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 348.395000] INFO: rcu_sched self-detected stall on CPU [ 348.395000] 0: (59978 ticks this GP) idle=fb1/140000000000001/0 [ 348.396000] INFO: rcu_sched detected stalls on CPUs/tasks: [ 348.396000] 0: (59978 ticks this GP) idle=fb1/140000000000001/0 [ 348.396000] (detected by 1, t=60002 jiffies) [ 348.396000] INFO: Stall ended before state dump start [ 348.398000] (t=60004 jiffies) [ 348.399000] Call Trace: [ 348.399000] [<805cff24>] dump_stack+0x8/0x34 [ 348.399000] [<800937c4>] __rcu_pending+0x1dc/0x57c [ 348.400000] [<80094774>] rcu_check_callbacks+0xec/0x1ac [ 348.401000] [<80031e40>] update_process_times+0x48/0x74 [ 348.401000] [<80070750>] tick_sched_timer+0x74/0xe8 [ 348.402000] [<8004a620>] __run_hrtimer.isra.4+0x68/0x138 [ 348.402000] [<8004b378>] hrtimer_interrupt+0x1b4/0x4dc [ 348.403000] [<8000bd88>] c0_compare_interrupt+0x50/0x88 [ 348.404000] [<8008be38>] handle_irq_event_percpu+0x7c/0x28c [ 348.404000] [<800901c0>] handle_percpu_irq+0x88/0xb8 [ 348.405000] [<8008b48c>] generic_handle_irq+0x3c/0x54 [ 348.405000] [<800060c8>] do_IRQ+0x18/0x30 [ 348.406000] [<80003454>] plat_irq_dispatch+0xac/0x10c [ 348.406000] [<80004348>] ret_from_irq+0x0/0x4 [ 348.407000] [<805d735c>] _raw_write_unlock_irqrestore+0x30/0x180 [ 348.408000] [] BKNI_ReleaseMutex_tagged+0x0/0x4c [bcm73625] [ 348.409000] [ 376.017000] BUG: soft lockup - CPU#0 stuck for 23s! [b_event:89] [ 376.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO ) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 376.019000] Cpu 0 [ 376.019000] $ 0 : 00000000 10008700 00010000 0000002f [ 376.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 376.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 376.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 376.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 376.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 376.023000] $24 : 00000000 8005ba00 [ 376.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 376.024000] Hi : 00000042 [ 376.024000] Lo : fb012dc0 [ 376.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 376.025000] Tainted: P O [ 376.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 376.027000] Status: 10008703 KERNEL EXL IE [ 376.027000] Cause : 00808000 [ 376.027000] PrId : 0002a065 (Broadcom BMIPS4380) [ 404.017000] BUG: soft lockup - CPU#0 stuck for 23s! [b_event:89] [ 404.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO ) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 404.019000] Cpu 0 [ 404.019000] $ 0 : 00000000 10008700 00010000 00000037 [ 404.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 404.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 404.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 404.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 404.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 404.023000] $24 : 00000000 8005ba00 [ 404.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 404.024000] Hi : 00000042 [ 404.024000] Lo : fb012dc0 [ 404.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 404.025000] Tainted: P O [ 404.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 404.027000] Status: 10008703 KERNEL EXL IE [ 404.027000] Cause : 80808000 [ 404.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 432.017000] BUG: soft lockup - CPU#0 stuck for 23s! [b_event:89] [ 432.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO ) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 432.019000] Cpu 0 [ 432.019000] $ 0 : 00000000 10008700 00010000 00001203 [ 432.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 432.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 432.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 432.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 432.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 432.023000] $24 : 00000000 8005ba00 [ 432.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 432.024000] Hi : 00000042 [ 432.024000] Lo : fb012dc0 [ 432.025000] epc : 805d7368 _raw_write_unlock_irqrestore+0x3c/0x180 [ 432.025000] Tainted: P O [ 432.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 432.027000] Status: 10008703 KERNEL EXL IE [ 432.027000] Cause : 80808000 [ 432.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 460.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 460.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO ) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 460.019000] Cpu 0 [ 460.019000] $ 0 : 00000000 10008700 00010000 0000004d [ 460.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 460.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 460.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 460.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 460.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 460.023000] $24 : 00000000 8005ba00 [ 460.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 460.024000] Hi : 00000042 [ 460.024000] Lo : fb012dc0 [ 460.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 460.025000] Tainted: P O [ 460.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 460.027000] Status: 10008703 KERNEL EXL IE [ 460.027000] Cause : 00808000 [ 460.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 488.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 488.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO ) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 488.019000] Cpu 0 [ 488.019000] $ 0 : 00000000 10008700 00010000 0000000e [ 488.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 488.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 488.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 488.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 488.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 488.023000] $24 : 00000000 8005ba00 [ 488.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 488.024000] Hi : 00000042 [ 488.024000] Lo : fb012dc0 [ 488.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 488.025000] Tainted: P O [ 488.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 488.027000] Status: 10008703 KERNEL EXL IE [ 488.027000] Cause : 00808000 [ 488.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 516.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 516.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 516.019000] Cpu 0 [ 516.019000] $ 0 : 00000000 10008700 00010000 00000003 [ 516.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 516.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 516.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 516.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 516.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 516.023000] $24 : 00000000 8005ba00 [ 516.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 516.024000] Hi : 00000042 [ 516.024000] Lo : fb012dc0 [ 516.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 516.025000] Tainted: P O [ 516.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 516.027000] Status: 10008703 KERNEL EXL IE [ 516.027000] Cause : 00808000 [ 516.027000] PrId : 0002a065 (Broadcom BMIPS4380) [ 528.400000] INFO: rcu_sched self-detected stall on CPU [ 528.400000] 0: (239904 ticks this GP) idle=fb1/140000000000001/0 [ 528.401000] INFO: rcu_sched detected stalls on CPUs/tasks: [ 528.401000] 0: (239904 ticks this GP) idle=fb1/140000000000001/0 [ 528.401000] (detected by 1, t=240007 jiffies) [ 528.401000] INFO: Stall ended before state dump start [ 528.403000] (t=240009 jiffies) [ 528.404000] Call Trace: [ 528.404000] [<805cff24>] dump_stack+0x8/0x34 [ 528.404000] [<800937c4>] __rcu_pending+0x1dc/0x57c [ 528.405000] [<80094774>] rcu_check_callbacks+0xec/0x1ac [ 528.406000] [<80031e40>] update_process_times+0x48/0x74 [ 528.406000] [<80070750>] tick_sched_timer+0x74/0xe8 [ 528.407000] [<8004a620>] __run_hrtimer.isra.4+0x68/0x138 [ 528.407000] [<8004b378>] hrtimer_interrupt+0x1b4/0x4dc [ 528.408000] [<8000bd88>] c0_compare_interrupt+0x50/0x88 [ 528.409000] [<8008be38>] handle_irq_event_percpu+0x7c/0x28c [ 528.409000] [<800901c0>] handle_percpu_irq+0x88/0xb8 [ 528.410000] [<8008b48c>] generic_handle_irq+0x3c/0x54 [ 528.410000] [<800060c8>] do_IRQ+0x18/0x30 [ 528.411000] [<80003454>] plat_irq_dispatch+0xac/0x10c [ 528.412000] [<80004348>] ret_from_irq+0x0/0x4 [ 528.412000] [<805d735c>] _raw_write_unlock_irqrestore+0x30/0x180 [ 528.413000] [] BKNI_ReleaseMutex_tagged+0x0/0x4c [bcm73625] [ 528.414000] [ 556.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 556.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 556.019000] Cpu 0 [ 556.019000] $ 0 : 00000000 10008700 00010000 ffffffff [ 556.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 556.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 556.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 556.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 556.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 556.023000] $24 : 00000000 8005ba00 [ 556.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 556.024000] Hi : 00000042 [ 556.024000] Lo : fb012dc0 [ 556.025000] epc : 805d7364 _raw_write_unlock_irqrestore+0x38/0x180 [ 556.025000] Tainted: P O [ 556.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 556.027000] Status: 10008703 KERNEL EXL IE [ 556.027000] Cause : 00808000 [ 556.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 584.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 584.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 584.019000] Cpu 0 [ 584.019000] $ 0 : 00000000 10008700 00010000 0000003d [ 584.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 584.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 584.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 584.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 584.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 584.023000] $24 : 00000000 8005ba00 [ 584.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 584.024000] Hi : 00000042 [ 584.024000] Lo : fb012dc0 [ 584.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 584.025000] Tainted: P O [ 584.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 584.027000] Status: 10008703 KERNEL EXL IE [ 584.027000] Cause : 00808000 [ 584.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 612.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 612.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 612.019000] Cpu 0 [ 612.019000] $ 0 : 00000000 10008700 00010000 00000032 [ 612.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 612.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 612.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 612.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 612.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 612.023000] $24 : 00000000 8005ba00 [ 612.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 612.024000] Hi : 00000042 [ 612.024000] Lo : fb012dc0 [ 612.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 612.025000] Tainted: P O [ 612.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 612.027000] Status: 10008703 KERNEL EXL IE [ 612.027000] Cause : 00808000 [ 612.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 640.017000] BUG: soft lockup - CPU#0 stuck for 23s! [b_event:89] [ 640.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 640.019000] Cpu 0 [ 640.019000] $ 0 : 00000000 10008700 00010000 00000016 [ 640.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 640.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 640.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 640.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 640.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 640.023000] $24 : 00000000 8005ba00 [ 640.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 640.024000] Hi : 00000042 [ 640.024000] Lo : fb012dc0 [ 640.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 640.025000] Tainted: P O [ 640.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 640.027000] Status: 10008703 KERNEL EXL IE [ 640.027000] Cause : 00808000 [ 640.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 668.017000] BUG: soft lockup - CPU#0 stuck for 23s! [b_event:89] [ 668.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 668.019000] Cpu 0 [ 668.019000] $ 0 : 00000000 10008700 00010000 0000001c [ 668.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 668.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 668.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 668.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 668.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 668.023000] $24 : 00000000 8005ba00 [ 668.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 668.024000] Hi : 00000042 [ 668.024000] Lo : fb012dc0 [ 668.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 668.025000] Tainted: P O [ 668.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 668.027000] Status: 10008703 KERNEL EXL IE [ 668.027000] Cause : 80808000 [ 668.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 696.017000] BUG: soft lockup - CPU#0 stuck for 23s! [b_event:89] [ 696.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 696.019000] Cpu 0 [ 696.019000] $ 0 : 00000000 10008700 00010000 0000005b [ 696.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 696.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 696.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 696.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 696.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 696.023000] $24 : 00000000 8005ba00 [ 696.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 696.024000] Hi : 00000042 [ 696.024000] Lo : fb012dc0 [ 696.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 696.025000] Tainted: P O [ 696.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 696.027000] Status: 10008703 KERNEL EXL IE [ 696.027000] Cause : 00808000 [ 696.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 708.405000] INFO: rcu_sched self-detected stall on CPU [ 708.405000] 0: (419830 ticks this GP) idle=fb1/140000000000001/0 [ 708.406000] INFO: rcu_sched detected stalls on CPUs/tasks: [ 708.406000] 0: (419830 ticks this GP) idle=fb1/140000000000001/0 [ 708.406000] (detected by 1, t=420012 jiffies) [ 708.406000] INFO: Stall ended before state dump start [ 708.408000] (t=420014 jiffies) [ 708.409000] Call Trace: [ 708.409000] [<805cff24>] dump_stack+0x8/0x34 [ 708.409000] [<800937c4>] __rcu_pending+0x1dc/0x57c [ 708.410000] [<80094774>] rcu_check_callbacks+0xec/0x1ac [ 708.411000] [<80031e40>] update_process_times+0x48/0x74 [ 708.411000] [<80070750>] tick_sched_timer+0x74/0xe8 [ 708.412000] [<8004a620>] __run_hrtimer.isra.4+0x68/0x138 [ 708.412000] [<8004b378>] hrtimer_interrupt+0x1b4/0x4dc [ 708.413000] [<8000bd88>] c0_compare_interrupt+0x50/0x88 [ 708.414000] [<8008be38>] handle_irq_event_percpu+0x7c/0x28c [ 708.414000] [<800901c0>] handle_percpu_irq+0x88/0xb8 [ 708.415000] [<8008b48c>] generic_handle_irq+0x3c/0x54 [ 708.415000] [<800060c8>] do_IRQ+0x18/0x30 [ 708.416000] [<80003454>] plat_irq_dispatch+0xac/0x10c [ 708.417000] [<80004348>] ret_from_irq+0x0/0x4 [ 708.417000] [<805d735c>] _raw_write_unlock_irqrestore+0x30/0x180 [ 708.418000] [] BKNI_ReleaseMutex_tagged+0x0/0x4c [bcm73625] [ 708.419000] [ 736.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 736.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 736.019000] Cpu 0 [ 736.019000] $ 0 : 00000000 10008700 00010000 00000055 [ 736.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 736.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 736.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 736.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 736.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 736.023000] $24 : 00000000 8005ba00 [ 736.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 736.024000] Hi : 00000042 [ 736.024000] Lo : fb012dc0 [ 736.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 736.025000] Tainted: P O [ 736.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 736.027000] Status: 10008703 KERNEL EXL IE [ 736.027000] Cause : 00808000 [ 736.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 764.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 764.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 764.019000] Cpu 0 [ 764.019000] $ 0 : 00000000 10008700 00010000 00000017 [ 764.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 764.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 764.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 764.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 764.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 764.023000] $24 : 00000000 8005ba00 [ 764.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 764.024000] Hi : 00000042 [ 764.024000] Lo : fb012dc0 [ 764.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 764.025000] Tainted: P O [ 764.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 764.027000] Status: 10008703 KERNEL EXL IE [ 764.027000] Cause : 00808000 [ 764.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 792.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 792.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 792.019000] Cpu 0 [ 792.019000] $ 0 : 00000000 10008700 00010000 00000007 [ 792.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 792.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 792.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 792.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 792.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 792.023000] $24 : 00000000 8005ba00 [ 792.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 792.024000] Hi : 00000042 [ 792.024000] Lo : fb012dc0 [ 792.025000] epc : 805d735c _raw_write_unlock_irqrestore+0x30/0x180 [ 792.025000] Tainted: P O [ 792.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 792.027000] Status: 10008703 KERNEL EXL IE [ 792.027000] Cause : 80808000 [ 792.028000] PrId : 0002a065 (Broadcom BMIPS4380) [ 820.017000] BUG: soft lockup - CPU#0 stuck for 22s! [b_event:89] [ 820.017000] Modules linked in: dreambox_keyboard(PO) bcm73625(PO) atbm781x(PO) lnb_ctrl(PO) dreambox_rc2(PO) stb_core(PO) [ 820.019000] Cpu 0 [ 820.019000] $ 0 : 00000000 10008700 00010000 00001203 [ 820.019000] $ 4 : e0a49590 00001207 00000000 806cc9d4 [ 820.020000] $ 8 : 81607200 00000006 00000000 00000000 [ 820.021000] $12 : fb012dc0 00000042 00f53000 00000011 [ 820.021000] $16 : 805d6e58 e0a49b68 00000032 00000001 [ 820.022000] $20 : e0a47924 af548000 806d0000 0000006a [ 820.023000] $24 : 00000000 8005ba00 [ 820.023000] $28 : af500000 af501de0 e0a49590 e07865a0 [ 820.024000] Hi : 00000042 [ 820.024000] Lo : fb012dc0 [ 820.025000] epc : 805d7368 _raw_write_unlock_irqrestore+0x3c/0x180 [ 820.025000] Tainted: P O [ 820.026000] ra : e07865a0 bcm_dvb_ca_exit+0x1530/0x3658 [bcm73625] [ 820.027000] Status: 10008703 KERNEL EXL IE [ 820.027000] Cause : 80808000 [ 820.028000] PrId : 0002a065 (Broadcom BMIPS4380)