CLOSE requested (1) dynamic CA: 23 01 01 20 04 c0 a8 b2 24 21 04 ff ff ff 00 22 04 c0 a8 b2 01 27 01 0a 24 01 00 28 01 14 01 01 00 46 01 00 47 01 00 33 01 fe 32 01 00 19 01 01 18 01 01 11 01 01 10 00 13 01 00 12 00 15 01 00 14 00 17 01 05 16 14 2f 61 75 74 6f 65 78 65 63 5f 64 6d 38 30 30 30 2e 62 61 74 1b 01 01 1a 3c 63 6f 6e 73 6f 6c 65 3d 74 74 79 53 30 2c 31 31 35 32 30 30 20 72 6f 6f 74 3d 2f 64 65 76 2f 6d 74 64 62 6c 6f 63 6b 33 20 72 6f 6f 74 66 73 74 79 70 65 3d 6a 66 66 73 32 20 72 77 02 01 00 45 01 00 ff 02 00 6b config saved. BCM97400 AB FFFFFFFF 1s Sync=1 LLMB=1 L2=1 RAC_I=1 RAC_D=1 Copy Code...34TUCV (c) 2007,2008 Dream Multimedia GmbH. All rights reserved. Dreambox DM8000 FIRST STAGE 1.10 {BO23456}  2ND STAGE OK, build #83 (2011-03-22) 0.000 - BCM board setup Configure MEMC1_2........ Done 0.039 - fp init FP version 7 detected 0.106 - ca init 0.595 - load config 1.175 - config loaded. * press [S] to enter setup OLED found! lcd: BOOT #83 - NAND PROBE: 2c da 80 95 (normal) - read config file: /boot/secondstage.conf detected jffs2 blocksize: 128kb ++++++++++++++++++++++++++++++++++++++++++++++++++++++++ dreamupd initialized Scanning JFFS2 FS: . | / - \ | / - \ | / - \ | / - \ | / - \ | / - \ | / -  done. find_inode failed for name=secondstage.conf load: Failed to find inode - failed to open /boot/secondstage.conf - failed to open /cf/autorun.bat lcd: /flash/bootlogo.elf bootlogo size: 326312 *** BHDM_EDID: Unknown/Unsupported Detailed Timing Format 1920 x 1080 (1080p) Supported modes: 1080i !1080p 720p 480p 1080i_50Hz 1080p_24Hz 1080p_25Hz 1080p_30Hz !1080p_50Hz !1250i_50Hz 720p_24Hz 720p_50Hz 576p_50Hz DVI_640x480p !DVI_1280x720p_50Hz !DVI_1280x720p !DVI_1280x720p_ReducedBlank !DVI_1280x720p_70Hz !DVI_1280x720p_72Hz !DVI_1280x720p_75Hz !DVI_1280x720p_85Hz !DVI_1920x1080p_60Hz_Red !Custom0 !Custom1 best supported mode is 25 using 1920x1080i (50.00 Hz) HDMI using colorspace: 1 *** BHDM: Waiting to transition to HDMI mode... 000CB001 0 *** BHDM: Waiting to transition to HDMI mode... 000CB001 0 *** BHDM: HDMI Output Mode: HDMI (Audio+Video) create surface 1920 1080 Using the Small jpeg decoder library, Copyright (c) 2006, Luc Saillard parsing JPEG header.. Virtual FB Size: 1280x720 lcd: /flash/vmlinux.gz <5>Linux version 2.6.18-7.4-dm8000 (oozoon@oozoon) (gcc version 4.4.3 (GCC) ) #1 SMP Mon Aug 1 20:12:56 CEST 2011 Fetching vars from bootloader... none present, using defaults. Detected 256 MB on MEMC0 (strap 0x2219c310) <4>WARNING: read invalid MAC address ff:ff:ff:ff:ff:ff from flash @ 0xbffff824 Default command line = root=/dev/mtdblock3 rootfstype=jffs2 rw console=null 2 831ffec4 8302af24 g_board_RAM_size=256MB Options: sata=1 enet=1 emac_1=0 no_mdio=0 docsis=0 ebi_war=0 pci=1 smp=1 CPU revision is: 0002a042 FPU revision is: 00130001 Determined physical RAM map: memory: 10000000 @ 00000000 (usable) ---> memsize from bootloader: 154 User-defined physical RAM map: node [00000000, 09a00000: RAM] node [09a00000, 06600000: RSVD] <5>Reserving 102 MB upper memory starting at 09a00000 <7>On node 0 totalpages: 65536 <7> DMA zone: 65536 pages, LIFO batch:15 Built 1 zonelists. Total pages: 65536 <5>Kernel command line: console=ttyS0,115200 root=/dev/mtdblock3 rootfstype=jffs2 rw before init RAC 0x01e0701f 0x0000000f 0x2fff0000 after init RAC 0x01e0705f 0x0000000f 0x2fff0000 [4294667.296000] ======> Before RAC_init:$22s5=00000020, $22s6(CBA)=11f0000c [4294667.296000] @B1F0_001C=00000001, @B1F0_0004=2fff0000, @B1F0_0000=01e0701f, @B1F0_0008=0000000f [4294667.296000] CBA = 11f00000 VALUE = 255 PAR_VAL2 = 0fff0000 [4294667.296000] RAC0 = b1f00000 RAC1 = b1f00008 RAC_RANGE = b1f00004 [4294667.296000] RAC_VALUE = 00087000 [4294667.296000] ******* Using CFE setting for RAC [4294667.296000] ******* $22s0=e30e3406, $22s5=00000020, $22s6=11f0000c [4294667.296000] Primary instruction cache 32kB, physically tagged, 2-way, linesize 64 bytes. [4294667.296000] Primary data cache 64kB, 4-way, linesize 64 bytes. [4294667.296000] Synthesized TLB refill handler (23 instructions). [4294667.296000] Synthesized TLB load handler fastpath (37 instructions). [4294667.296000] Synthesized TLB store handler fastpath (37 instructions). [4294667.296000] Synthesized TLB modify handler fastpath (36 instructions). [4294667.296000] PID hash table entries: 2048 (order: 11, 8192 bytes) [4294667.296000] Found MIPS counter frequency: 203 Mhz [4294667.296000] Using 202.501 MHz high precision timer. [4294667.296000] Console: colour dummy device 80x25 [4294667.400000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes) [4294667.406000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes) [4294667.424000] Memory: 151680k/262144k available (2619k kernel code, 110284k reserved, 573k data, 164k init, 0k highmem) [4294667.456000] Mount-cache hash table entries: 512 [4294667.460000] Checking for 'wait' instruction... available. [4294667.465000] plat_prepare_cpus: ENABLING 2nd Thread... [4294667.470000] TP0: prom_boot_secondary: Kick off 2nd CPU... [4294667.475000] CPU revision is: 0002a042 [4294667.475000] FPU revision is: 00130001 [4294667.475000] Primary instruction cache 32kB, physically tagged, 2-way, linesize 64 bytes. [4294667.475000] Primary data cache 64kB, 4-way, linesize 64 bytes. [4294667.475000] Synthesized TLB refill handler (23 instructions). [4294667.496000] Brought up 2 CPUs [4294667.610000] migration_cost=2000 [4294667.624000] NET: Registered protocol family 16 [4294667.629000] registering PCI controller with io_map_base unset [4294667.634000] registering PCI controller with io_map_base unset [4294667.639000] SCSI subsystem initialized [4294667.643000] usbcore: registered new driver usbfs [4294667.647000] usbcore: registered new driver hub [4294667.651000] PCI DEV in slot 1, ID=168c:001a [4294667.651000] PCI PnP: PCI_BAR[0] = ffff0000 [4294667.658000] PCI PnP: size requested is 10000 [4294667.662000] NET: Registered protocol family 2 [4294667.678000] IP route cache hash table entries: 2048 (order: 1, 8192 bytes) [4294667.685000] TCP established hash table entries: 8192 (order: 4, 65536 bytes) [4294667.691000] TCP bind hash table entries: 4096 (order: 3, 32768 bytes) [4294667.697000] TCP: Hash tables configured (established 8192 bind 4096) [4294667.703000] TCP reno registered [4294667.706000] brcm-pm: disabling power to USB block [4294667.710000] brcm-pm: disabling power to ENET block [4294667.714000] brcm-pm: disabling power to SATA block [4294667.719000] JFFS2 version 2.2. (NAND) (SUMMARY) (C) 2001-2006 Red Hat, Inc. [4294667.726000] Initializing Cryptographic API [4294667.730000] io scheduler noop registered [4294667.734000] io scheduler anticipatory registered [4294667.737000] io scheduler deadline registered [4294667.741000] io scheduler cfq registered (default) [4294667.748000] Serial: 8250/16550 driver $Revision: 1.90 $ 1 ports, IRQ sharing disabled [4294667.756000] serial8250: ttyS0 at MMIO 0x0 (irq = 65) is a 16550A [4294667.761000] brcm-pm: enabling power to ENET block [4294667.765000] Broadcom BCM7400 P42 Ethernet Network Device v2.0 Aug 1 2011 20:12:03 [4294667.772000] SUNDRY revision = 74000032, have IP Hdr Opt=1 [4294667.780000] Config Internal PHY Through MDIO: 100 MB Full-Duplex (auto-neg) [4294669.739000] brcm-pm: enabling power to SATA block [4294669.759000] ata1: SATA max UDMA/133 cmd 0xB0510000 ctl 0xB0510020 bmdma 0xB0510030 irq 42 [4294669.767000] ata2: SATA max UDMA/133 cmd 0xB0510100 ctl 0xB0510120 bmdma 0xB0510130 irq 42 [4294669.775000] scsi0 : sata_svw [4294670.080000] ata1: SATA link down (SStatus 4 SControl 300) [4294670.116000] ATA: abnormal status 0x7F on port 0xb051001c [4294670.122000] scsi1 : sata_svw [4294670.432000] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl F0000) [4294670.438000] ata2.00: ATA-8, max UDMA/133, 62533296 sectors: LBA48 NCQ (depth 0/32) [4294670.446000] ata2.00: ata2: dev 0 multi count 1 [4294670.452000] ata2.00: configured for UDMA/133 [4294670.457000] Vendor: ATA Model: STT_FTM32GX25H Rev: 1916 [4294670.462000] Type: Direct-Access ANSI SCSI revision: 05 [4294670.469000] SCSI device sda: 62533296 512-byte hdwr sectors (32017 MB) [4294670.475000] sda: Write Protect is off [4294670.478000] SCSI device sda: drive cache: write back [4294670.482000] SCSI device sda: 62533296 512-byte hdwr sectors (32017 MB) [4294670.488000] sda: Write Protect is off [4294670.491000] SCSI device sda: drive cache: write back [4294670.495000] sda: sda1 [4294670.498000] sd 1:0:0:0: Attached scsi disk sda [4294670.502000] sd 1:0:0:0: Attached scsi generic sg0 type 0 [4294670.724000] 4608 kb/s [4294670.727000] - NAND PROBE: 2c da 80 95 [4294670.730000] NAND device: Manufacturer ID: 0x2c, Chip ID: 0xda (Unknown NAND 256MiB 3,3V 8-bit) [4294670.738000] Scanning device for bad blocks [4294670.827000] Creating 4 MTD partitions on "NAND 256MiB 3,3V 8-bit": [4294670.834000] 0x0000000000000000-0x0000000010000000 : "complete" [4294670.839000] 0x0000000000000000-0x0000000000100000 : "loader" [4294670.844000] 0x0000000000100000-0x0000000000800000 : "boot partition" [4294670.850000] 0x0000000000800000-0x0000000010000000 : "root partition" [4294670.856000] ehci_hcd_brcm_init: Initializing 2 EHCI controller(s) [4294670.862000] brcm-pm: enabling power to USB block [4294670.865000] 10 Dec 2004 USB 2.0 'Enhanced' Host Controller (EHCI) Driver (EHCI-brcm-0) [4294670.873000] drivers/usb/host/ehci-brcm.c: starting brcm EHCI USB Controller [4294670.879000] - USB h/w setup mode [4294670.879000] - USB power enable set for active LOW mode [4294670.887000] brcm-ehci brcm-ehci.0: BRCM EHCI [4294670.891000] brcm-ehci brcm-ehci.0: new USB bus registered, assigned bus number 1 [4294670.897000] brcm-ehci brcm-ehci.0: irq 62, io mem 0x10480300 [4294670.902000] brcm-ehci brcm-ehci.0: USB 0.0 started, EHCI 1.00, driver 10 Dec 2004 [4294670.909000] usb usb1: configuration #1 chosen from 1 choice [4294670.914000] hub 1-0:1.0: USB hub found [4294670.917000] hub 1-0:1.0: 2 ports detected [4294671.022000] 10 Dec 2004 USB 2.0 'Enhanced' Host Controller (EHCI) Driver (EHCI-brcm-1) [4294671.030000] drivers/usb/host/ehci-brcm.c: starting brcm EHCI USB Controller [4294671.036000] brcm-ehci-1 brcm-ehci-1.1: BRCM EHCI [4294671.040000] brcm-ehci-1 brcm-ehci-1.1: new USB bus registered, assigned bus number 2 [4294671.047000] brcm-ehci-1 brcm-ehci-1.1: irq 57, io mem 0x10480500 [4294671.052000] brcm-ehci-1 brcm-ehci-1.1: USB 0.0 started, EHCI 1.00, driver 10 Dec 2004 [4294671.060000] usb usb2: configuration #1 chosen from 1 choice [4294671.065000] hub 2-0:1.0: USB hub found [4294671.068000] hub 2-0:1.0: 2 ports detected [4294671.172000] ohci_hcd_brcm_init: Initializing 2 OHCI controller(s) [4294671.178000] 2005 April 22 USB 1.1 'Open' Host Controller (OHCI) Driver (OHCI-brcm-0) [4294671.185000] drivers/usb/host/ohci-brcm.c: starting brcm OHCI USB Controller [4294671.191000] - Resetting at b0480408 [4294671.194000] <-- brcm_start_hc [4294671.196000] brcm-ohci-0 brcm-ohci-0.0: BRCM OHCI [4294671.200000] brcm-ohci-0 brcm-ohci-0.0: new USB bus registered, assigned bus number 3 [4294671.207000] brcm-ohci-0 brcm-ohci-0.0: irq 63, io mem 0x10480400 [4294671.236000] usb 1-1: new high speed USB device using brcm-ehci and address 2 [4294671.267000] usb usb3: configuration #1 chosen from 1 choice [4294671.273000] hub 3-0:1.0: USB hub found [4294671.276000] hub 3-0:1.0: 2 ports detected [4294671.357000] usb 1-1: configuration #1 chosen from 1 choice [4294671.363000] hub 1-1:1.0: USB hub found [4294671.366000] hub 1-1:1.0: 4 ports detected [4294671.380000] 2005 April 22 USB 1.1 'Open' Host Controller (OHCI) Driver (OHCI-brcm-1) [4294671.388000] drivers/usb/host/ohci-brcm.c: starting brcm OHCI USB Controller [4294671.394000] - Resetting at b0480608 [4294671.397000] <-- brcm_start_hc [4294671.399000] brcm-ohci-1 brcm-ohci-1.1: BRCM OHCI [4294671.403000] brcm-ohci-1 brcm-ohci-1.1: new USB bus registered, assigned bus number 4 [4294671.410000] brcm-ohci-1 brcm-ohci-1.1: irq 64, io mem 0x10480600 [4294671.470000] usb usb4: configuration #1 chosen from 1 choice [4294671.476000] hub 4-0:1.0: USB hub found [4294671.479000] hub 4-0:1.0: 2 ports detected [4294671.583000] Initializing USB Mass Storage driver... [4294671.588000] usbcore: registered new driver usb-storage [4294671.592000] USB Mass Storage support registered. [4294671.596000] i2c /dev entries driver [4294671.599000] TCP bic registered [4294671.601000] NET: Registered protocol family 1 [4294671.605000] NET: Registered protocol family 17 [4294671.609000] Freeing unused kernel memory: 164k freed Jumpin'Jack Flash initramfs by gutemine Version 1.0 Kernel: 2.6.18-7.4-dm8000 Kernel commandline: console=ttyS0,115200 root=/dev/mtdblock3 rootfstype=jffs2 rw Jumpin Flash ... Continue booting... INIT: version 2.86 booting [4294677.527000] stb_core: module license 'Proprietary' taints kernel. [4294677.664000] 4005335 ms: [4294677.713000] 46 ms: 28 Starting /etc/rcS.d/S02sysfs... [4294677.730000] 12 ms: =s Startting the hotplug events dispatcher Synthesizing the initial hotplug events Waiting for /dev to be fully populated [4294679.466000] ath_hal: 2008-08-15 (AR5210, AR5211, AR5212, AR5416, RF5111, RF5112, RF2413, RF5413, RF2133, RF2425, REGOPS_FUNC, DFS, XR) [4294679.742000] wlan: svn r3314 [4294679.928000] ath_pci: svn r3314 [4294679.932000] Atheros HAL provided by OpenWrt, DD-WRT and MakSat Technologies [4294680.531000] MadWifi: ath_getchannels: HAL returned 22 channels. [4294680.538000] MadWifi: ath_getchannels: Channel 1 (2412 MHz) Max Tx Power 18 dBm (hw limited) [18 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.550000] MadWifi: ath_getchannels: Channel 1 (2412 MHz) Max Tx Power 18 dBm (hw limited) [18 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.562000] MadWifi: ath_getchannels: Channel 2 (2417 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.573000] MadWifi: ath_getchannels: Channel 2 (2417 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.585000] MadWifi: ath_getchannels: Channel 3 (2422 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.597000] MadWifi: ath_getchannels: Channel 3 (2422 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.609000] MadWifi: ath_getchannels: Channel 4 (2427 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.621000] MadWifi: ath_getchannels: Channel 4 (2427 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.633000] MadWifi: ath_getchannels: Channel 5 (2432 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.645000] MadWifi: ath_getchannels: Channel 5 (2432 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.657000] MadWifi: ath_getchannels: Channel 6 (2437 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.669000] MadWifi: ath_getchannels: Channel 6 (2437 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.681000] MadWifi: ath_getchannels: Channel 7 (2442 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.693000] MadWifi: ath_getchannels: Channel 7 (2442 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.705000] MadWifi: ath_getchannels: Channel 8 (2447 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.717000] MadWifi: ath_getchannels: Channel 8 (2447 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.729000] MadWifi: ath_getchannels: Channel 9 (2452 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.741000] MadWifi: ath_getchannels: Channel 9 (2452 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.753000] MadWifi: ath_getchannels: Channel 10 (2457 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.765000] MadWifi: ath_getchannels: Channel 10 (2457 MHz) Max Tx Power 19 dBm (hw limited) [19 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.777000] MadWifi: ath_getchannels: Channel 11 (2462 MHz) Max Tx Power 17 dBm (hw limited) [17 hw 27 reg] Flags CF_CCK CF_2GHZ [4294680.788000] MadWifi: ath_getchannels: Channel 11 (2462 MHz) Max Tx Power 17 dBm (hw limited) [17 hw 27 reg] Flags CF_OFDM CF_2GHZ [4294680.800000] MadWifi: ath_attach: Switching rfkill capability off [4294680.834000] ath_rate_sample: 1.2 (svn r3314) [4294680.841000] MadWifi: ath_attach: Switching per-packet transmit power control off [4294680.850000] wifi0: 11b rates: 1Mbps 2Mbps 5.5Mbps 11Mbps [4294680.856000] wifi0: 11g rates: 1Mbps 2Mbps 5.5Mbps 11Mbps 6Mbps 9Mbps 12Mbps 18Mbps 24Mbps 36Mbps 48Mbps 54Mbps [4294680.866000] wifi0: H/W encryption support: WEP AES AES_CCM TKIP [4294680.873000] wifi0: ath_announce: Use hw queue 1 for WME_AC_BE traffic [4294680.879000] wifi0: ath_announce: Use hw queue 0 for WME_AC_BK traffic [4294680.886000] wifi0: ath_announce: Use hw queue 2 for WME_AC_VI traffic [4294680.893000] wifi0: ath_announce: Use hw queue 3 for WME_AC_VO traffic [4294680.899000] wifi0: ath_announce: Use hw queue 8 for CAB traffic [4294680.905000] wifi0: ath_announce: Use hw queue 9 for beacons [4294680.942000] ath_pci: wifi0: Atheros 2413: mem=0xd1000000, irq=33 done [4294681.065000] 3333 ms: 31 Starting /etc/rcS.d/S03udev... [4294681.078000] 8 ms: =s find: /dev/disk/by-label/: No such file or directory dFlash found no Flash Device, bo[4294681.355000] 274 ms: 34 Starting /etc/rcS.d/S04Flash... oting continues ... [4294681.375000] 13 ms: =s [4294681.394000] 17 ms: 37 Starting /etc/rcS.d/S04bootup... [4294681.406000] 7 ms: 10 [4294681.640000] EXT2-fs warning (device sda1): ext2_fill_super: mounting ext3 filesystem as ext2 [4294681.649000] EXT2-fs warning: mounting unchecked fs, running e2fsck is recommended [4294681.658000] 250 ms: 12 [4294681.851000] Adding 262136k swap on /hdd/swapfile. Priority:-1 extents:124 across:766500k [4294681.860000] 199 ms: 14 [4294681.877000] 15 ms: 15 /dev/sda: setting standby[4294681.944000] 64 ms: 16 to 120 (10 minutes) /dev/sda: sett[4294681.953000] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x40000000 action 0x0 ing acoustic man[4294681.962000] ata2.00: tag 0 cmd 0xef Emask 0x1 stat 0x51 err 0x4 (device error) agement to 128 [4294681.970000] ata2: EH complete HDIO_DRIVE_CMD:[4294681.973000] SCSI device sda: 62533296 512-byte hdwr sectors (32017 MB) ACOUSTIC failed:[4294681.980000] sda: Write Protect is off Input/output er[4294681.985000] 37 ms: 17 [4294681.985000] SCSI device sda: drive cache: write back ror acoustic = not supported [4294682.024000] input: dreambox remote control (native) as /class/input/input0 [4294682.032000] input: dreambox advanced remote control (native) as /class/input/input1 [4294682.055000] input: dreambox ir keyboard as /class/input/input2 [4294682.062000] input: dreambox ir mouse as /class/input/input3 modprobe: module 8712u not found in modules.dep [4294682.572000] fpga init [4294684.889000] done OK 0 [4294688.277000] enter base init, xvd 20100413, vdc 20100413, rap 20090430, xpt 20100825 [4294688.286000] !!! kernMemSize: 154 MB [4294688.292000] smca set muxes [4294688.295000] smcb set muxes [4294688.297000] smcc set muxes [4294688.311000] 21:15013000 SMCA: controller reset timed out [4294688.326000] 21:30011000 SMCB: controller reset timed out [4294690.326000] register adapter [4294690.329000] register adapter [4294690.332000] register adapter [4294690.335000] register adapter [4294690.337000] register adapter [4294690.462000] FP Version 7 [4294690.472000] input: dreambox front panel as /class/input/input4 [4294690.562000] maskffffffff [4294690.565000] using fpga version 2a [4294690.568000] tsmux set tsports reg 02 to val dc [4294690.571000] tsmux set tsports reg 02 to val dc [4294690.575000] tsmux set tsports reg 03 to val fe [4294690.579000] tsmux set tsports reg 03 to val fe [4294690.582000] tsmux set cisource reg 00 to val 55 [4294690.586000] tsmux set cisource reg 00 to val 55 [4294690.590000] tsmux set cisource reg 01 to val 55 [4294690.594000] tsmux set cisource reg 01 to val 55 [4294690.597000] HDMI: device attached [4294690.627000] set sb to 3(2) [4294690.630000] set fb to 2(-1) [4294690.632000] set input to 0 [4294690.634000] set fb to 2(-1) [4294690.639000] bcm_video_analog_port_setup (fmt=7) [4294690.643000] SET FORMAT: display[1], format=7 [4294690.647000] display 0 uses vbi path 1 [4294690.650000] display 1 uses vbi path 0 [4294690.653000] HDMI: hotplug handler! [4294690.656000] Write AVS: 40 40 00 00 00 00 00 03 00 02 00 00 00 ff [4294690.667000] Write AVS: 40 40 00 00 00 00 18 63 00 02 00 00 00 ff [4294690.677000] set sb to 3(2) [4294690.680000] set sb to 3(2) [4294690.691000] using 50.00Hz as MonitorRefreshRate [4294690.696000] SET FORMAT: display[0], format=37 [4294690.700000] HDMI detected [4294690.701000] HDMI mode [4294690.704000] use EDID to detect colorspace [4294690.707000] using colorspace: 1 [4294690.781000] set fb to 2(0) [4294690.783000] bcm_video_analog_port_setup (fmt=7) [4294690.787000] SET FORMAT: display[1], format=7 [4294690.791000] disable wss on display 0 [4294690.794000] disable wss on display 1 [4294690.797000] bcmfb: creating surface with pixel format 0x07e48888 (BPXL_eA8_R8_G8_B8) udevd-event[432]: node_symlink: rename(/dev/fb.udev-tmp, /dev/fb) failed: Is a directory [4294690.944000] enable mad [4294691.002000] VIDEO0: set fallback framerate to 60000 [4294691.007000] VIDEO0: set progressive override mode to 1 [4294691.012000] VIDEO0: set streamtype! [4294691.015000] set MPEG2 [4294691.016000] sw rave disabled! [4294691.146000] enable mad [4294691.149000] VIDEO1: set fallback framerate to 60000 [4294691.153000] VIDEO1: set progressive override mode to 1 [4294691.158000] VIDEO1: set streamtype! [4294691.161000] set MPEG2 [4294691.162000] sw rave disabled! [4294691.168000] sync is off so we enable it [4294691.172000] playback! [4294691.174000] total video delay: 0 (0 ms) [4294691.178000] VIDEO0: start decode [4294691.181000] flush video decoder [4294691.184000] VIDEO0 got pts failed !!!! (ret 0) [4294691.599000] set ac3 to downmix [4294691.602000] set aac to downmix [4294691.626000] VIDEO0: first pts 0x0 [4294691.657000] init ALSA! [4294691.661000] DVB: registering new adapter (BCM7400) [4294691.770000] autodetecting NIMs... [4294691.775000] ret: 2, feid: 13 [4294691.778000] Found: Slot C, ID: 13 (by CA) [4294691.781000] enable tsm0 [4294691.784000] ret: 2, feid: 13 [4294691.787000] Found: Slot D, ID: 13 (by CA) [4294691.790000] Initializing adapter 0 (BCM4501 (internal)-DVB-S2) [4294691.795000] fe_common: retrying i2c transfer [4294691.799000] fe_common: retrying i2c transfer [4294691.803000] fe_common: retrying i2c transfer [4294691.807000] fe_common: retrying i2c transfer [4294691.810000] fe_common: retrying i2c transfer [4294691.814000] fe_common: retrying i2c transfer [4294691.819000] fe_common: retrying i2c transfer [4294691.822000] fe_common: retrying i2c transfer [4294691.826000] fe_common: retrying i2c transfer [4294691.830000] fe_common: retrying i2c transfer [4294691.833000] fe: write ret=-145 [4294691.836000] bcm4501: mbox read error [4294691.839000] attach bcm4501 failed.. try now bcm4506 [4294691.844000] bcm4506: found 4506, revision 0(a1) [4294691.849000] bcm_initAP [4294691.857000] BCM4506: upload & start firmware [4294693.947000] 450X uCode 0x52 [4294693.966000] no bcm3445 detected [4294693.980000] DVB: registering adapter 0 frontend 0 (bcm4506)... [4294693.986000] Initializing adapter 1 (BCM4506 (internal)-DVB-S2) [4294694.001000] no bcm3445 detected [4294694.017000] DVB: registering adapter 0 frontend 0 (bcm4506)... [4294694.023000] Initializing adapter 2 (BCM4505-DVB-S2) [4294694.081000] bcm4506: found 4505, revision 0(b0) [4294694.085000] bcm_initAP [4294694.092000] BCM4506: upload & start firmware [4294696.016000] 450X uCode 0x52 [4294696.063000] no bcm3445 detected [4294696.077000] DVB: registering adapter 0 frontend 0 (bcm4506)... [4294696.083000] Initializing adapter 3 (BCM4505-DVB-S2) [4294696.140000] bcm4506: found 4505, revision 0(b0) [4294696.145000] bcm_initAP [4294696.152000] BCM4506: upload & start firmware [4294698.105000] 450X uCode 0x52 [4294698.152000] no bcm3445 detected [4294698.166000] DVB: registering adapter 0 frontend 0 (bcm4506)... [4294698.172000] CI removed... [4294698.174000] CI removed... [4294698.175000] CI removed... [4294698.175000] registered vtuner vtuner0, minor 53 [4294698.175000] registered vtuner vtuner1, minor 52 [4294698.175000] CI removed... [4294698.955000] VIDEO0: stop decode [4294698.959000] no decoder left in sync handling so disable xpt_sync modprobe: module cdc-acm not found in modules.dep [4294699.097000] cdfs 2.6.27 loaded. modprobe: module cp2101 not found in modules.dep modprobe: module ftdi-sio not found in modules.dep modprobe: module fuse not found in modules.dep modprobe: module hfs not found in modules.dep modprobe: module hfsplus not found in modules.dep modprobe: module nfsd not found in modules.dep [4294699.431000] NTFS driver 2.1.27 [Flags: R/O MODULE]. modprobe: module pl2303 not found in modules.dep modprobe: module rt73 not found in modules.dep modprobe: module rt3070 not found in modules.dep modprobe: module tun not found in modules.dep modprobe: module usbhid not found in modules.dep modprobe: module usbserial not found in modules.dep modprobe: module zd1211b not fou[4294699.601000] 17608 ms: 18 nd in modules.dep [4294699.781000] using 50.00Hz as MonitorRefreshRate [4294699.899000] SET FORMAT: display[0], format=27 [4294699.904000] HDMI detected [4294699.906000] HDMI mode [4294699.907000] use EDID to detect colorspace [4294699.912000] using colorspace: 1 [4294699.976000] bcm_video_analog_port_setup (fmt=7) [4294700.133000] SET FORMAT: display[1], format=7 [4294700.252000] set current avs auto aspect to 16:9 [4294700.257000] disable wss on display 0 [4294700.260000] disable wss on display 1 [4294700.263000] set sb to 3(1) [4294700.265000] Write AVS: 40 40662 ms: 19 [4294700.269000] 00 00 00 00 18 61 00 02 00 00 00 ff [4294700.284000] 10 ms: 20 [4294700.317000] 30 ms: 21 [4294700.327000] 7 ms: 22 [4294700.330000] 0 ms: 23 [4294700.485000] VIDEO0: set blank to 0 [4294700.489000] sync is off so we enable it [4294700.493000] playback! [4294700.496000] total video delay: 0 (0 ms) [4294700.501000] VIDEO0: start decode [4294700.505000] flush video decoder [4294700.544000] VIDEO0: first pts 0x0 [4294700.548000] VIDEO0: framerate changed 3 [4294700.551000] VIDEO0: resolution changed (1280 720) [4294700.555000] VIDEO0: aspect changed 3 [4294700.558000] set current avs auto aspect to 16:9 [4294700.562000] disable wss on display 0 [4294700.566000] disable wss on display 1 [4294700.570000] set current avs auto aspect to 16:9 [4294700.575000] disable wss on display 0 [4294700.579000] disable wss on display 1 [4294700.583000] set sb to 3(1) [4294700.666000] VIDEO0: set blank to 0 [4294700.670000] VIDEO0: stop decode [4294700.673000] VIDEO0: set blank to 0 [4294700.677000] no decoder left in sync handling so disable xpt_sync ldconfig: Can't open configuration file /etc/ld.so.conf: No such file or directory [4294708.133000] JFFS2 notice: (539) check_node_data: wrong data CRC in data node at 0x0702d800: read 0x995ce531, calculated 0x13775ef0. [4294709.327000] 8995 ms: 24 [4294709.595000] 265 ms: 25 [4294709.609000] 11 ms: =s [4294709.667000] 55 ms: 40 Starting /etc/rcS.d/S10tpmd... [4294709.693000] 21 ms: =s [4294709.748000] 53 ms: 43 Starting /etc/rcS.d/S20modutils.sh... [4294709.774000] 20 ms: =s [4294709.858000] 81 ms: 46 Starting /etc/rcS.d/S38devpts.sh... [4294709.879000] 15 ms: =s Setting up IP spoofing protection: rp_filter. Configuring network interfaces... eth0 no wireless extensions. udhcpc (v1.15.3) started Sending discover... Sending select for 192.168.178.36... Lease of 192.168.178.36 obtained, lease time 864000 adding dns 192.168.178.1 done. [4294714.804000] 4922 ms: 49 Starting /etc/rcS.d/S40networking... INIT: Entering runlevel: 3 Starting system message bus: dbus. Starting Dropbear SSH server: dropbear. Starting internet superserver: inetd. Starting syslogd/klogd: done * starting FTP Server: vsftpd... done. Starting automounter: done. * Starting Avahi mDNS/DNS-SD Daemon: avahi-daemon [ ok ] -------------------------------------- [SCRIPT] stop: CCcam 2.2.1 -------------------------------------- -------------------------------------- [SCRIPT] start: CCcam 2.2.1 -------------------------------------- [4294722.420000] VIDEO0: set blank to 0 [4294722.423000] sync is off so we enable it [4294722.427000] playback! [4294722.429000] total video delay: 0 (0 ms) [4294722.433000] VIDEO0: start decode [4294722.437000] flush video decoder [4294722.492000] VIDEO0: first pts 0x0 [4294722.599000] VIDEO0: set blank to 0 [4294722.602000] VIDEO0: stop decode [4294722.606000] VIDEO0: set blank to 0 [4294722.609000] no decoder left in sync handling so disable xpt_sync setenv('prefix', '/usr', 0) setenv('exec_prefix', '/usr', 0) setenv('bindir', '/usr/bin', 0) setenv('sbindir', '/usr/sbin', 0) setenv('libexecdir', '/usr/libexec', 0) setenv('datarootdir', '${prefix}/share', 0) setenv('datadir', '/usr/share', 0) setenv('sysconfdir', '/etc', 0) setenv('sharedstatedir', '/com', 0) setenv('localstatedir', '/var', 0) setenv('libdir', '/usr/lib', 0) setenv('localedir', '${datarootdir}/locale', 0) setenv('prefix', '/usr', 1) setenv('exec_prefix', '/usr', 1) setenv('bindir', '/usr/bin', 1) setenv('sbindir', '/usr/sbin', 1) setenv('libexecdir', '/usr/libexec', 1) setenv('datarootdir', '/usr/share', 1) setenv('datadir', '/usr/share', 1) setenv('sysconfdir', '/etc', 1) setenv('sharedstatedir', '/com', 1) setenv('localstatedir', '/var', 1) setenv('libdir', '/usr/lib', 1) setenv('localedir', '/usr/share/locale', 1) resolve: resolve ${datadir}/enigma2/encoding.conf resolve: -> /usr/share/enigma2/encoding.conf [4294726.424000] JFFS2 notice: (24) check_node_data: wrong data CRC in data node at 0x0dc22000: read 0xbca072dc, calculated 0xee567140. [4294727.766000] JFFS2 notice: (859) check_node_data: wrong data CRC in data node at 0x058e4000: read 0x8227ae00, calculated 0x6ce40ac3. enigma2::receiver model dm8000(1) detected enigma2::TPM signature OK resolve: resolve ${libdir}/enigma2/python resolve: -> /usr/lib/enigma2/python PYTHONPATH: /usr/lib/enigma2/python + (1) Background File Eraser + (8) graphics acceleration manager + (9) GFBDC 16384k video mem [4294729.879000] bcmfb: enable manual blit SetMode : wanted: 720x576x32, got 720x576x32 [4294729.894000] bcmfb: creating surface with pixel format 0x07e48888 (BPXL_eA8_R8_G8_B8) - double buffering available! 13144kB available for acceleration surfaces. resolution: 720 x 576 x 32 (stride: 2880) + (9) gLCDDC found OLED display! lcd buffer 0x6b8138 8448 bytes, stride 132 + (9) Font Render Class [FONT] initializing lib... [FONT] loading fonts... [FONT] Intializing font cache, using max. 4MB... + (10) gRC RC thread created success[4294730.114000] tsmux set cisource reg 00 to val 54 fully + (15) eWindowStyleManage[4294730.122000] tsmux set cisource reg 00 to val 44 r + (20) DVB-CI UI + (20) UHF [4294730.130000] tsmux set cisource reg 01 to val 54 Modulator couldnt open /dev/rfm[4294730.137000] tsmux set cisource reg 01 to val 44 od0!!!! + (20) RC Input layer [4294730.145000] tsmux set tsports reg 02 to val dc + (20) misc options + (20) AVSw[4294730.152000] tsmux set tsports reg 02 to val dc itch Driver + (21) input device[4294730.159000] tsmux set tsports reg 03 to val fe driver Input d[4294730.166000] tsmux set tsports reg 03 to val fe evice "dreambox remote control (native)" is not a keyboard. Input device "dreambox advanced remote control (native)" is not a keyboard. Input device "dreambox ir keyboard" is a keyboard. Input device "dreambox ir mouse" is not a keyboard. Input device "dreambox front panel" is not a keyboard. Found 5 input devices! + (21) Console RC Driver + (30) eActionMap + (35) CI Slots scanning for common interfaces.. CI Slot 0 setSource(0) CI Slot 1 setSource(0) CI Slot 2 setSource(0) CI Slot 3 setSource(0) eDVBCIInterfaces->setInputSource(0, 0) eDVBCIInterfaces->setInputSource(1, 1) eDVBCIInterfaces->setInputSource(2, 2) eDVBCIInterfaces->setInputSource(3, 3) done, found 4 common interface slots + (40) eServiceCenter settings instance. + (41) eServiceFactoryM2TS + (41) eServiceFactoryMP3 + (41) eServiceFactoryFS + (41) eServiceFactoryDVB reached rl 70 resolve: resolve ${sysconfdir}/enigma2/lamedb resolve: -> /etc/enigma2/lamedb ---- opening lame channel db main thread is non-idle! display spinner! no spinner DC! reading services (version 4) main thread is non-idle! display spinner! no spinner DC! loaded 3734 services scanning for frontends.. opening frontend 0 [4294734.209000] bcm4506 channel 0 is in normale mode now detected satellite frontend close frontend 0 opening frontend 1 [4294734.225000] bcm4506 channel 1 is in normale mode now detected satellite frontend close frontend 1 opening frontend 2 [4294734.242000] bcm4506 channel 0 is in normale mode now detected satellite frontend close frontend 2 opening frontend 3 [4294734.257000] bcm4506 channel 0 is in normale mode now detected satellite frontend close frontend 3 found 1 adapter, 4 frontends(4 sim) and 5 demux, boxtype 4 Use valid Linux Time :) (RTC?) [EPGC] Initialized EPGCache (wait for setCacheFile call now) resolve: resolve ${datadir}/enigma2/skin_default/pal.png resolve: -> /usr/share/enigma2/skin_default/pal.png Loading spinners... resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait1.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait1.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait2.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait2.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait3.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait3.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait4.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait4.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait5.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait5.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait6.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait6.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait7.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait7.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait8.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait8.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait9.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait9.png found 8 spinner! executing main setIoPrio best-effort level 3 ok resolve: resolve ${libdir}/enigma2/python/mytest.py resolve: -> /usr/lib/enigma2/python/mytest.py resolve: resolve ${sysconfdir}/ resolve: -> /etc/ resolve: resolve ${sysconfdir}/ resolve: -> /etc/ resolve: resolve ${datadir}/fonts/ resolve: -> /usr/share/fonts/ resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ resolve: resolve ${libdir}/enigma2/python/Plugins/ resolve: -> /usr/lib/enigma2/python/Plugins/ resolve: resolve ${datadir}/enigma2/po/ resolve: -> /usr/share/enigma2/po/ resolve: resolve ${datadir}/enigma2/ resolve: -> /usr/share/enigma2/ resolve: resolve ${datadir}/enigma2/ resolve: -> /usr/share/enigma2/ resolve: resolve ${sysconfdir}/enigma2/playlist/ resolve: -> /etc/enigma2/playlist/ resolve: resolve ${datadir}/enigma2/defaults/ resolve: -> /usr/share/enigma2/defaults/ resolve: resolve ${datadir}/enigma2/dealer resolve: -> /usr/share/enigma2/dealer resolve: resolve ${datadir}/meta resolve: -> /usr/share/meta resolve: resolve ${datadir}/enigma2/defaults/ resolve: -> /usr/share/enigma2/defaults/ [4294735.230000] 20420 ms: =s [4294735.242000] 10 ms: 50 [4294735.898000] 653 ms: 50 [4294736.029000] 128 ms: 50 [4294736.077000] 45 ms: 50 main thread is non-idle! display spinner! [4294736.210000] JFFS2 notice: (859) check_node_data: wrong data CRC in data node at 0x0e955800: read 0x7c2849ed, calculated 0xdc3a6f41. [4294736.814000] 735 ms: 50 /proc/stb/frontend/0/lnb_sense is 0 enumerating block devices... found block device 'mtdblock3': blacklisted found block device 'mtdblock2': blacklisted found block device 'mtdblock1': blacklisted found block device 'mtdblock0': blacklisted found block device 'sda': ok, removable=False, cdrom=False, partitions=['sda1'] new Harddisk sda -> /dev/sda -> /dev/sda [ePopen] command: ('hdparm', 'hdparm', '-S0', '/dev/sda') found block device 'sda1': error querying properties [4294737.220000] bcm4506 channel 0 is sleeping now [4294737.234000] bcm4506 channel 1 is sleeping now [4294737.250000] bcm4506 channel 0 is sleeping now [4294737.265000] bcm4506 channel 0 is sleeping now [4294737.359000] 543 ms: 51 [4294737.881000] 519 ms: 52 [4294738.029000] 145 ms: 52 [4294738.044000] 12 ms: 53 [4294738.048000] 2 ms: 53 [4294738.053000] 2 ms: 53 main thread is non-idle! display spinner! Preferred tag editor set to None [4294738.451000] 396 ms: 53 [4294738.455000] 2 ms: 53 [4294738.641000] 183 ms: 53 [4294739.232000] 588 ms: 53 Reading satellites.xml resolve: resolve ${datadir}/enigma2/unicable.xml resolve: -> /usr/share/enigma2/unicable.xml removing internal link on frontend id 1 sec config cleared setSlotInfo for dvb frontend 0 to slotid 0, descr BCM4506 (internal), need rotorworkaround No, enabled Yes, DVB-S2 Yes setSlotInfo for dvb frontend 1 to slotid 1, descr BCM4506 (internal), need rotorworkaround No, enabled Yes, DVB-S2 Yes setSlotInfo for dvb frontend 2 to slotid 2, descr BCM4505, need [4294742.693000] 3458 ms: 54 rotorworkaround No, enabled Yes, DVB-S2 Yes setSlotInfo for dvb frontend 3 to slotid 3, descr BCM4505, need rotorworkaround No, enabled Yes, DVB-S2 Yes slot: 0 configmode: simple diseqcmode: diseqc_a_b slot: 1 configmode: simple diseqcmode: diseqc_a_b slot: 2 configmode: simple diseqcmode: diseqc_a_b slot: 3 configmode: sim[4294742.725000] 28 ms: 59 ple diseqcmode: diseqc_a_b se[4294742.729000] 2 ms: 59 c config completed [4294742.732000] 0 ms: 59 [4294742.762000] 27 ms: 59 [4294742.791000] 26 ms: 59 resolve: resolve ${datadir}/enigma2/setup.xml resolve: -> /usr/share/enigma2/setup.xml [4294743.831000] 1037 ms: 59 [4294743.840000] 7 ms: 61 [4294743.859000] 16 ms: 61 resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/bouquets.tv resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.favourites.tv 105 entries in Bouquet userbouquet.favourites.tv resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.dbe00.tv 42 entries in Bouquet userbouquet.dbe00.tv resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.favourit[4294743.913000] 51 ms: 61 es_hd.tv 30 entries in Bouquet userbouquet.favourites_hd.tv resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.dbe02.tv 8 entries in Bouquet userbouquet.dbe02.tv resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.dbe03.tv 34 entries in Bouquet userbouquet.dbe03.tv 5 entries in Bouquet bouquets.tv resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/bouquets.radio resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.favourites.radio 10 entries in Bouquet userbouquet.favourites.radio 1 entries in Bouquet bouquets.radio [4294744.110000] 194 ms: 61 [4294744.174000] 61 ms: 61 [4294744.178000] 1 ms: 61 [4294744.183000] 2 ms: 61 [eDVBLocalTimeHa[4294744.192000] 7 ms: 61 ndler] enable sync local time with transponder time! /usr/lib/python2.6/site-packages/twisted/internet/_sslverify.py:5: DeprecationWarning: the md5 module is deprecated; use hashlib instead [4294746.822000] 2626 ms: 61 [4294746.831000] 6 ms: 65 add dreampackage scanner plugin added [4294747.132000] 298 ms: 65 [4294747.136000] 1 ms: 65 [4294747.228000] 90 ms: 65 [4294747.234000] 3 ms: 65 [4294747.241000] 5 ms: 65 [4294747.251000] 8 ms: 65 [4294747.278000] 24 ms: 65 [4294747.304000] 23 ms: 65 [4294747.309000] 3 ms: 65 [FONT] adding font /usr/share/fonts/nmsbd.ttf...OK (Display) SetMode : wanted: 1280x720x32, got 720x576x32 [4294747.536000] bcmfb: creating surface with pixel format 0x07e48888 (BPXL_eA8_R8_G8_B8) - double buffering available! 9184kB available for acceleration surfaces. resolution: 1280 x 720 x 32 (stride: 5120) [FONT] adding font /usr/share/enigma2/Vali.HD.flex/hd.ttf...OK (Regular) [FONT] adding font /usr/share/fonts/lcd.ttf...OK (LCD) [FONT] adding font /usr/share/fonts/tuxtxt.ttf...OK (Console) [FONT] adding font /usr/share/fonts/skinuser.ttf...OK (Swiss-MAD_Us[4294748.364000] 1052 ms: 65 erSkinFont) [iInputDevices] setRepeat for device event1 to 340 ms [iInputDevices] setDelay for device event1 to 3200 ms [4294748.442000] 75 ms: 66 [4294748.457000] Write AVS: 40 40 00 00 00 00 00 61 00 02 00 00 00 ff [4294748.498000] set current avs auto aspect to 4:3 [4294748.503000] disable wss on display 0 [4294748.506000] disable wss on display 1 [4294748.508000] set sb to 3(2) [4294748.510000] Write AVS: 40 40 00 00 00 00 00 63 00 02 00 00 00 ff [4294748.593000] set current avs auto aspect to 4:3 [4294748.598000] disable wss on display 0 [4294748.601000] disable wss on display 1 [4294748.603000] set sb to 3(2) [4294748.606000] disable wss on display 0 [4294748.610000] set wss 8 on display 1 [4294748.649000] set input to 0 [4294748.652000] set fb to 2(0) [4294748.654000] set current avs auto aspect to 4:3 [4294748.658000] disable wss on display 0 [4294748.661000] set wss 8 on display 1 [4294748.663000] set sb to 3(2) [4294748.668000] set ac3 to passthrough --> setting scaler_sharpness to: 00000014 [4294748.721000] 277 ms: 66 [4294748.735000] 11 ms: 66 couldn't open /proc/stb/misc/12V_output resolve: resolve ${datadir}/enigma2/keymap.xml resolve: -> /usr/share/enigma2/keymap.xml [4294748.809000] 72 ms: 66 [4294749.031000] 219 ms: 66 [ePopen] command: ip -o addr show dev ath0 [ePopen] command: ip -o addr show dev eth0 [4294749.097000] 64 ms: 67 setLCDBrightness 25 setLCDBrightness 127 [4294749.180000] 80 ms: 67 main thread is non-idle! display spinner! resolve: resolve ${datadir}/keymaps/ resolve: -> /usr/share/keymaps/ resolve: resolve ${datadir}/keymaps/ resolve: -> /usr/share/keymaps/ resolve: resolve ${datadir}/keymaps/ resolve: -> /usr/share/keymaps/ Activating keymap: Keyboard English resolve: resolve ${datadir}/keymaps/ resolve: -> /usr/share/keymaps/ [ePopen] command: loadkmap < /usr/share/keymaps/eng.kmap Activating language German language set to de_DE [4294751.005000] 1822 ms: 67 [4294751.022000] 14 ms: 70 [4294751.050000] 25 ms: 70 It's now Fri Aug 5 17:06:18 2011 [timer.py] next activation: 1312556878 (in 99357 ms) Media Center: Import VLC Stuff failed /usr/lib/enigma2/python/Plugins/Extensions/WebInterface/__init__.py:4: DeprecationWarning: the sha module is deprecated; use the hashlib module instead import os, gettext, sha [WebInterface] set language to de [WebInterface] set language to de [4294755.910000] JFFS2 notice: (859) check_node_data: wrong data CRC in data node at 0x0ad07000: read 0x82953ad3, calculated 0x19be4f95. [WebInterface] fallback to default translation for Webinterface [Bonjour.reloadConfig] reloading config [Bonjour.__parse] parsing /etc/avahi/services/https.service [Bonjour.registerService] {'text': '', 'type': '_https._tcp', 'name': '%h HTTPS', 'file': 'https.service', 'port': '443'} [Bonjour.__writeService] Creating service file 'https.service' [Bonjour.__parse] parsing /etc/avahi/services/sftp-ssh.service [Bonjour.registerService] {'text': '', 'type': '_sftp-ssh._tcp', 'name': 'SFTP File Transfer on %h', 'file': 'sftp-ssh.service', 'port': '22'} [Bonjour.__writeService] Creating service file 'sftp-ssh.service' [Bonjour.__parse] parsing /etc/avahi/services/smb.service [Bonjour.registerService] {'text': '', 'type': '_smb._tcp', 'name': '%h SMB', 'file': 'smb.service', 'port': '139'} [Bonjour.__writeService] Creating service file 'smb.service' [Bonjour.__parse] parsing /etc/avahi/services/http.service [Bonjour.registerService] {'text': '', 'type': '_http._tcp', 'name': '%h HTTP', 'file': 'http.service', 'port': '80'} [Bonjour.__writeService] Creating service file 'http.service' [Bonjour.__parse] parsing /etc/avahi/services/ftp.service [Bonjour.registerService] {'text': '', 'type': '_ftp._tcp', 'name': '%h FTP', 'file': 'ftp.service', 'port': '21'} [Bonjour.__writeService] Creating service file 'ftp.service' [Bonjour.__parse] parsing /etc/avahi/services/ssh.service [Bonjour.registerService] {'text': '', 'type': '_ssh._tcp', 'name': '%h', 'file': 'ssh.service', 'port': '22'} [Bonjour.__writeService] Creating service file 'ssh.service' [Bonjour.registerDefaultServices] called [dFlash] /tmp/dflash.sh created [AudioSync] set language to de [AudioSync] set language to de resolve: resolve ${libdir}/enigma2/python/Plugins/SystemPlugins/WirelessLan resolve: -> /usr/lib/enigma2/python/Plugins/SystemPlugins/WirelessLan getModeList for port DVI-PC getModeList for port YPbPr getModeList for port Scart getModeList for port DVI-PC getModeList for port DVI hotplug on dvi -> setting aspect, policy, policy2, wss 16:9 bestfit bestfit auto [4294759.410000] set current avs auto aspect to 16:9 [4294759.415000] disable wss on display 0 [4294759.418000] set wss 7 on display 1 [4294759.420000] set sb to 3(1) [4294759.422000] Write AVS: 40 40 00 00 00 00 00 61 00 02 00 00 00 ff [4294759.445000] set current avs auto aspect to 16:9 [4294759.450000] disable wss on display 0 [4294759.453000] set wss 7 on display 1 [4294759.455000] set sb to 3(1) [4294759.458000] disable wss on display 0 [4294759.461000] set wss 7 on display 1 [4294759.465000] set current avs auto aspect to 16:9 [4294759.470000] disable wss on display 0 [4294759.473000] set wss 7 on display 1 [4294759.476000] set sb to 3(1) -> setting aspect, policy, polic[4294759.481000] set current avs auto aspect to 16:9 y2, wss 16:9 bes[4294759.487000] disable wss on display 0 tfit bestfit aut[4294759.492000] set wss 7 on display 1 o [4294759.497000] set sb to 3(1) [4294759.501000] set current avs auto aspect to 16:9 [4294759.506000] disable wss on display 0 [4294759.509000] set wss 7 on display 1 [4294759.512000] set sb to 3(1) [4294759.514000] disable wss on display 0 [4294759.518000] set wss 7 on display 1 [4294759.523000] set current avs auto aspect to 16:9 [4294759.528000] disable wss on display 0 [4294759.531000] set wss 7 on display 1 [4294759.535000] set sb to 3(1) -> setting aspect, policy, polic[4294759.543000] set current avs auto aspect to 16:9 y2, wss 16:9 bes[4294759.549000] disable wss on display 0 tfit bestfit aut[4294759.554000] set wss 7 on display 1 o [4294759.559000] set sb to 3(1) [4294759.563000] set current avs auto aspect to 16:9 [4294759.568000] disable wss on display 0 [4294759.571000] set wss 7 on display 1 [4294759.574000] set sb to 3(1) [4294759.576000] disable wss on display 0 [4294759.580000] set wss 7 on display 1 [4294759.582000] set current avs auto aspect to 16:9 [4294759.587000] disable wss on display 0 [4294759.591000] set wss 7 on display 1 [4294759.593000] set sb to 3(1) -> setting aspect, policy, polic[4294759.599000] set current avs auto aspect to 16:9 y2, wss 16:9 bes[4294759.605000] disable wss on display 0 tfit bestfit aut[4294759.610000] set wss 7 on display 1 o [4294759.615000] set sb to 3(1) [4294759.619000] set current avs auto aspect to 16:9 [4294759.624000] disable wss on display 0 [4294759.627000] set wss 7 on display 1 [4294759.630000] set sb to 3(1) [4294759.632000] disable wss on display 0 [4294759.636000] set wss 7 on display 1 [4294759.641000] set current avs auto aspect to 16:9 [4294759.646000] disable wss on display 0 [4294759.650000] set wss 7 on display 1 [4294759.653000] set sb to 3(1) setMode - port: DVI mode: 1080i[4294759.661000] set current avs auto aspect to 16:9 rate: 50Hz [4294759.666000] disable wss on display 0 [4294759.670000] set wss 7 on display 1 [4294759.673000] set sb to 3(1) [4294759.676000] set current avs auto aspect to 16:9 [4294759.681000] disable wss on display 0 [4294759.685000] set wss 7 on display 1 [4294759.688000] set sb to 3(1) -> setting aspect, policy, polic[4294759.698000] set current avs auto aspect to 16:9 y2, wss 16:9 bes[4294759.704000] disable wss on display 0 tfit bestfit aut[4294759.708000] set wss 7 on display 1 o [4294759.712000] set sb to 3(1) [4294759.715000] set current avs auto aspect to 16:9 [4294759.720000] disable wss on display 0 [4294759.724000] set wss 7 on display 1 [4294759.727000] set sb to 3(1) [4294759.732000] disable wss on display 0 [4294759.735000] set wss 7 on display 1 [4294759.738000] set current avs auto aspect to 16:9 [4294759.743000] disable wss on display 0 [4294759.746000] set wss 7 on display 1 [4294759.749000] set sb to 3(1) resolve: resolve ${datadir}/enigma2/ resolve: -> /usr/share/enigma2/ [GP2DisplayRepresentation] found LANGUAGE= de [GP2DisplayRepresentation] found LANGUAGE= de resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ starting hotplug handler [CI_Assignment] activating ci configs: [CI_Activate] FOUND 4 CI Slots resolve: resolve ${sysconfdir}/enigma2/ci resolve: -> [4294761.191000] 10139 ms: 70 /etc/enigma2/ci [CI_Activate_Config_CI0] no config file found [CI_Activate_Config_CI0] error parsing xml... resolve: resolve ${sysconfdir}/enigma2/ci resolve: -> /etc/enigma2/ci [CI_Activate_Config_CI1] no config file found [CI_Activate_Config_CI1] error parsing xml... resolve: resolve ${sysconfdir}/enigma2/ci resolve: -> /etc/enigma2/ci [CI_Activate_Config_CI2] no config file found [CI_Activate_Config_CI2] error parsing xml... resolve: resolve ${sysconfdir}/enigma2/ci resolve: -> /etc/enigma2/ci [CI_Activate_Config_CI3] no config file found [CI_Activate_Config_CI3] error parsing xml... It's now Fri Aug 5 17:06:27 2011 [timer.py] next activation: 1312556887 (in 99358 ms) [TIMER] record time changed, start prepare is now: Fri Aug 5 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:27 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556887 (in 99026 ms) [TIMER] record time changed, start prepare is now: Sun Aug 7 20:11:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:27 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556887 (in 99012 ms) [TIMER] record time changed, start prepare is now: Sun Aug 7 21:13:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:28 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556888 (in 99995 ms) [TIMER] record time changed, start prepare is now: Mon Aug 8 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:28 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556888 (in 99975 ms) [TIMER] record time changed, start prepare is now: Mon Aug 8 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:28 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556888 (in 99951 ms) [TIMER] record time changed, start prepare is now: Tue Aug 9 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:28 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556888 (in 99386 ms) [TIMER] record time changed, start prepare is now: Tue Aug 9 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:28 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556888 (in 99358 ms) [TIMER] record time changed, start prepare is now: Wed Aug 10 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:28 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556888 (in 99326 ms) [TIMER] record time changed, start prepare is now: Wed Aug 10 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:28 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556888 (in 99294 ms) [TIMER] record time changed, start prepare is now: Thu Aug 11 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:28 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556888 (in 99260 ms) [TIMER] record time changed, start prepare is now: Thu Aug 11 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:06:28 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556888 (in 99221 ms) [TIMER] record time changed, start prepare is now: Fri Jul 29 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Sat Jul 30 06:17:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Sat Jul 30 07:27:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:2F08:441:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Sun Jul 31 20:11:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Sun Jul 31 22:17:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:A:2:85:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Sun Jul 31 21:12:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Mon Aug 1 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Mon Aug 1 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Mon Aug 1 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Tue Aug 2 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Tue Aug 2 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Tue Aug 2 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Wed Aug 3 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Wed Aug 3 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Wed Aug 3 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Wed Aug 3 23:41:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF75:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Wed Aug 3 23:13:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF75:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Thu Aug 4 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Thu Aug 4 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Thu Aug 4 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Thu Aug 4 21:12:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Fri Aug 5 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Fri Aug 5 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 It's now Fri Aug 5 17:06:31 2011 [timer.py] next activation: 1312556891 (in 99938 ms) Repeated: 1 Repeated: 3 Repeated: 7 Repeated: 15 Repeated: 31 Repeated: 63 Repeated: 127 ProcessRepeated localrepeatedbegindate: Fri Aug 5 17:15:00 2011 localbegin: Fri Aug 5 17:15:00 2011 localend: Fri Aug 5 17:15:00 2011 localnow: Fri Aug 5 17:06:32 2011 Day: 0 Day: 1 Day: 2 Day: 3 Day: 4 Day: 5 Day: 6 ProcessRepeated result Fri Aug 5 17:15:00 2011 Fri Aug 5 17:15:01 2011 It's now Fri Aug 5 17:06:31 2011 next real activation is Fri Aug 5 17:15:01 2011 [timer.py] next activation: 1312556891 (in 99882 ms) [FanControl2] Starting up [FanControl2] ATA(STT_FTM32GX25H) /dev/sda Mode:auto [FanControl2] HDD Temperature not readable [FanControl2] HDD not supports Temp reading without Spinup -> Disabled [FanControl2] HDD Temp 0C Looking for embedded skin [dFlash] autostart [CHECKSOFTWAREUPDATE] autostart check [CHECKSOFTWAREUPDATE] doing check [CHECKSOFTWAREUPDATE] planning dummy check Looking for embedded skin [AutomaticTimerlistCleanUp] Starting AutomaticTimerlistCleanUp... [AutomaticTimerlistCleanUp] Cleaning up timerlist-entries older than Fri Jul 29 17:06:37 2011 [AutomaticTimerlistCleanUp] Next automatic timerlist cleanup at Sat Aug 6 17:06:37 2011 [Toplevel.importExternalModules] Imported external module: dFlash [Toplevel.importExternalModules] Imported external module: AutoTimer [Toplevel.importExternalModules] Imported external module: EPGRefresh [Toplevel.importExternalModules] Imported external module: Example [WebInterface] checking for SSL Certificates [Webinterface] started on 0.0.0.0:80 auth=True ssl=False [Bonjour.registerService] {'text': '', 'type': '_http._tcp', 'name': '%h HTTP', 'file': 'http.service', 'port': 80} [Bonjour.__writeService] Creating service file 'http.service' [WebInterface.registerBonjourService] Service for protocol 'http' with port '80' registered! [Webinterface] started on 0.0.0.0:443 auth=True ssl=True [Bonjour.registerService] {'text': '', 'type': '_https._tcp', 'name': '%h HTTPS', 'fil[4294772.232000] 11037 ms: 84 e': 'https.service', 'port': 443} [Bonjour.__writeService] Creating service file 'https.service' [WebInterface.registerBonjourService] Service for protocol 'https' with port '443' registered! [EPGC] setCacheFile read/write epg data from/to '/hdd/epg.dat' [EPGC] time updated.. start EPG Mainloop before: 1 after: 1 not showing fine-tuning wizard, config variable doesn't exist showtestcard is false Looking for embedded skin [4294772.312000] 76 ms: 99 setValue 95 [4294772.380000] set mute 0 (000) 1 cannot open /proc/stb/audio/j1_m[4294772.386000] 71 ms: 99 ute(No such file or directory) Setvolume: 100 100 (raw) Setvolume: 0 0 (-1db) Setvolume: 95 95 (raw) Setvolume: 4 4 (-1db) [4294772.401000] 12 ms: 99 nr_read 110 nr_write 1 sum 111 prev_sum 0 hdd was accessed since previous check! [IDLE] 0 120 False lookup for events with 'Gute Zeiten, schlechte Zeiten' as title(case sensitive) [EPGC] 6674 events read from /hdd/epg.dat [EPGC] start cleanloop [EPGC] stop cleanloop [EPGC] 566584 bytes for cache used lookup for events with 'Navy CIS: L.A.' as title(case sensitive) lookup for events with 'Dr. House' as title(case sensitive) lookup for events with 'Bones' in title(case sensitive) lookup for events with 'Psych' as title(case sensitive) lookup for events with 'Disney Micky Maus Wunderhaus' as title(case sensitive) lookup for events with 'The Mentalist' as title(case sensitive) [AutoTimer] Won't modify existing timer because either no modification allowed or repeated timer lookup for events with 'Navy CIS' as title(case sensitive) [AutoTimer] Skipping an event because it starts in less than 60 seconds [AutoTimer] Won't modify existing timer because either no modification allowed or repeated timer lookup for events with 'Mein Mann kann' as title(case sensitive) lookup for events with 'Cougar Town' in title(ignore case) lookup for events with 'Die Sendung mit dem Elefanten' as title(case sensitive) lookup for events with 'Kleiner Roter Traktor' as title(case sensitive) allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! resolve: resolve ${datadir}/enigma2/%s/ resolve: -> /usr/share/enigma2/%s/ allocating new converter! allocating new converter! allocating new converter! reused converter! RemovePopup, id = ZapError allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! reused converter! allocating new converter! reused converter! allocating new converter! reused converter! nr_read 115 nr_write 1 sum 116 prev_sum 111 hdd was accessed since previous check! [IDLE] 0 120 False playing 1:0:19:EF74:3F9:1:C00000:0:0:0: not pauseable. RemovePopup, id = ZapError allocate channel.. 0[4294774.553000] bcm4506 channel 0 is in normale mode now 3f9:0001 opening frontend 0 [eDVBCAService] new channel 0x2dd607b8! (0)tune RotorCmd ffffffff, lastRotorCmd ffffffff prepare_sat System 1 Freq 11464250 Pol 0 SR 22000000 INV 2 FEC 2 orbpos 192 system 1 modulation 2 pilot 2, rolloff 0 tuning to 1714 mhz OURSTATE: [4294774.586000] signal_strength -289.87dbm tuning allocate Channel: res 0 [eDVBCIInterfaces] addPMTHandler 1:0:19:EF74:3F9:1:C00000:0:0:0: allocate demux resolve: resolve ${sysconfdir}/scan_tp_valid_check.py resolve: -> /etc/scan_tp_valid_check.py [SEC] set static current limiting set sequence pos 3 set sequence pos 4 [SEC] setVoltage 2 [SEC] sleep 200ms child has terminated pipes closed child has terminated pipes closed [ePopen] command: route -n | grep ath0 child has terminated pipes closed [ePopen] command: route -n | grep eth0 poll: unhandled POLLERR/HUP/NVAL for fd 34(16) child has terminated pipes closed poll: unhandled POLLERR/HUP/NVAL for fd 39(16) poll: unhandled POLLERR/HUP/NVAL for fd 40(16) poll: unhandled POLLERR/HUP/NVAL for fd 42(16) [SEC] invalidate current switch params Timeout! use cached_channel [4294777.711000] signal_strength -289.87dbm [4294777.721000] signal_strength -289.87dbm [SEC] sendDiseqc: e00000(DiSEqC reset) [4294777.894000] signal_strength -289.87dbm [SEC] sleep 50ms child has terminated pipes closed child has terminated pipes closed 192.168 169.254 0.0.0.0 nameservers: [[192, 168, 178, 1]] read configured interface: {'lo': {'dhcp': False}, 'eth0': {'dhcp': True}} self.ifaces after loading: {'ath0': {'preup': False, 'predown': False, 'ip': [0, 0, 0, 0], 'up': False, 'mac': 'd8:5d:4c:eb:39:30', 'dhcp': True, 'netmask': [0, 0, 0, 0], 'gateway': [0, 0, 0, 0]}, 'eth0': {'preup': False, 'predown': False, 'ip': [192, 168, 178, 36], 'up': True, 'mac': '00:09:34:1c:b8:c5', 'dhcp': True, 'bcast': [192, 168, 178, 255], 'netmask': [255, 255, 255, 0], 'gateway': [192, 168, 178, 1]}} poll: unhandled POLLERR/HUP/NVAL for fd 40(16) poll: unhandled POLLERR/HUP/NVAL for fd 41(16) [SEC] sendDiseqc: e00003(DiSEqC peripherial power on) [SEC] sleep 150ms [SEC] sendDiseqc: e01038f2 [SEC] sleep 50ms set sequence pos 3 set sequence pos 3 [SEC] update current switch params [SEC] startTuneTimeout 5000 [SEC] setFrontend 1 setting frontend 0 [SEC] sleep 500ms (0)fe event: status 0, inversion off, m_tuning 1 (0)fe event: status 1, inversion off, m_tuning 2 [4294778.726000] signal_strength -120.35dbm (0)fe event: status 0, inversion off, m_tuning 3 [SEC] set dynamic current limiting (0)fe event: status 1f, inversion off, m_tuning 4 OURSTATE: ok [eDVBCAService] channel 0x2dd607b8 running [eDVBLocalTimerHandler] channel 0x2dd607b8 running no version filtering 0014: 70 00 00 00 00 00 mask: fc 00 00 00 00 00 mode:[4294778.977000] start pcr0 on dmx 0 pid:ff index 0 00 00 00 00 00 00 [eEPGCache][4294778.984000] start audio on dmx 0 pid:103 channel 0x2dd60[4294778.989000] audio xpt start 7b8 running sto[4294778.992000] sync is off so we enable it p release channe[4294778.997000] demux-index 0 pcr0pid ff l timer no vers[4294779.001000] using 0 as pcr0 pidchannel ion filtering 0[4294779.005000] AC3 012: 4e ef 74 0[4294779.008000] audio: streamtype set 1 0 00 00 mask: [4294779.012000] audio: streamtype_set: stop rave ff ff ff 00 00 0[4294779.017000] passthru 0 mode: 00 00 00 00 00 00 [EPGC] next update in 2 sec ok ... now we start!! no version filtering 0000: 00 00 00 00 00 00 mask: ff 00 00[4294779.030000] audio: streamtype_set: restart rave 00 00 00 mode:[4294779.036000] set mute 0 (001) 1 00 00 00 00 00[4294779.040000] audio: decoder start 2 00 eventNewProgramInfo 0 0 have 1 video stream(s) (00ff), and 1 audio stream(s) (0103), and the pcr pid is 00ff, and the text[4294779.054000] video delay 0 (0 ms) pid is 0020 al[4294779.057000] total video delay: 0 (0 ms) locate demux di[4294779.062000] VIDEO0: set streamtype! sable teletext s[4294779.066000] set H264 ubtitles decode[4294779.069000] sw rave disabled! r state: play, v[4294779.072000] video delay 0 (0 ms) pid=255, apid=25[4294779.076000] total video delay: 0 (0 ms) 9 DMX_SET_PES_F[4294779.081000] start video0 on dmx 0 pid:ff ILTER(0xff) - pc[4294779.085000] total video delay: 18000 (200 ms) r - ok DEMUX_START - pcr - ok [4294779.090000] VIDEO0: start decode DMX_SET_PES_FILTER(0x103) - audio - ok DEMUX_START - audio - ok AUDIO_SET_BYPASS(0) - ok AUDIO_PAUSE - ok AUDIO_PLAY - ok Video Device: /dev/dvb/adapter0/video0 demux device: /dev/dvb/adapter0/demux0 VIDEO_SET_STREAMTYPE 1 - ok DMX_SET_PES_FILTER(0xff) - video - ok DEMUX_START -[4294779.118000] signal_strength -119.52dbm video - ok VIDEO_FREEZE - ok VIDEO_PLAY - ok DMX_SET_PES_FILTER(0x20) - ttx - ok DEMUX_START - ttx - ok VIDEO_SLOWMOTION(0) - ok VIDEO_FAST_FORWARD(0) - ok VIDEO_CONTINUE - ok AUDIO_CONTINUE - ok AUDIO_CHANNEL_SELECT(0) - ok not pauseable. [ePopen] command: ping -c 1 82.149.226.170 [ePopen] command: ping -c 1 193.99.144.85 [ePopen] command: ping -c 1 209.85.135.103 -+ 1/2 TID 4e + 1/1 TID 00 done! PATready use pmtpid 0060 for service_id ef74 no version filtering 0060: 02 ef 74 00 00 00 mask: ff ff ff 00 00 00 mode: 00 00 00 00 00 00 doing version filtering 0000: 00 00 00 2d 00 00 mask: ff 00 00 3f 00 00 mode: 00 00 00 3e 00 00 VIDEO_GET_EVENT - ok VIDEO_GET_EVENT - ok child has terminated pipes closed poll: unhandled POLLERR/HUP/NVAL for fd 70(16) child has terminated pipes closed poll: unhandled POLLERR/HUP/NVAL for fd 67(16) + 1/1 TID 02 done! eventNewProgramInfo 0 0 have 1 video stream(s) (00ff), and 1 audio stream(s) (0103), and the pcr pid is 00ff, and the text pid is 0020 decoder state: play, vpid=255, apid=259 [4294779.476000] signal_strength -115.69dbm [eDVBCAService] new service 1:0:19:EF74:3F9:1:C00000:0:0:0: [eDVBCAService] add demux 0 to slot 0 service 1:0:19:EF74:3F9:1:C00000:0:0:0: [eDVBCIInterfaces] gotPMT demux 0 mask 01 prevhash 00000000 [eDVBCAService] send 174 bytes 9f 80 32 81 a9 03 ef 74 03 00 8f 01 81 08 00 c0 00 00 03 f9 00 01 82 02 01 00 84 02 00 60 09 14 18 30 fa ea 86 0e 00 80 11 0f 9f 20 fc 01 80 11 0d 7a 20 fc 09 5c 18 43 f9 ea 86 0e 00 80 11 0f 9f 20 fc 01 80 11 0d 7a 20 fc 8c 46 00 00 43 8c 13 00 80 11 08 02 18 43 20 0a 09 38 59 00 0f 9f 59 00 0f 9f aa 15 03 80 11 5d 00 00 66 00 03 03 21 00 00 02 18 43 5d 00 00 66 00 aa 15 03 80 11 00 00 0b ea 00 03 03 21 00 00 02 18 43 5d 00 0b ea 00 09 06 09 c4 fb ea 00 00 06 00 20 00 00 1b 00 ff 00 00 06 01 03 00 00 05 01 05 00 00 doing version filtering 0060: 02 ef 74 03 00 00 mask: ff ff ff 3f 00 00 mode: 00 00 00 3e 00 00 ++ 2/2 TID 4e done! doing version filtering 0012: 4e ef 74 39 00 00 mask: ff ff ff 3f 00 00 mode: 00 00 00 3e 00 00 [4294779.746000] signal_strength -114.13dbm [4294779.763000] signal_strength -114.13dbm [FanControl2] Fan Reset [FanControl2] Reread [4294780.079000] ch0: lock [4294780.081000] RAP first pts 0x1e1a560c0, stc 0x1e1a55a0e, pcr valid [4294780.107000] ch0: lock [4294780.140000] ch0: lock [4294780.169000] ch0: lock [4294780.204000] ch0: lock [4294780.232000] ch0: lock sdt update done! [4294780.332000] RAP sampling rate info isr [4294780.467000] RAP pts error 0 PTS 0xf0d2e300, STC 0xf0d2f247, type 1 [FanControl2] Fan Reset [FanControl2] Reread use cached_channel [4294780.754000] signal_strength -120.03dbm [eDVBLocalTimerHandler] diff is 1 [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time [eDVBLocalTimerHandler] update RTC [eDVBLocalTimerHandler] time update to 17:06:48 [eDVBLocalTimerHandler] m_time_difference is 1 [eDVBLocalTimerHandler] set Linux Time [EPGC] start cleanloop [EPGC] stop cleanloop [EPGC] 566584 bytes for cache used Timeout! [4294780.956000] signal_strength -120.18dbm [EPGC] start caching events(1312556808) [4294780.966000] signal_strength -120.18dbm [4294781.096000] signal_strength -120.18dbm [FanControl2] Fan Reset [FanControl2] Vlt:255 Pwm:90 Fan:4pin - BoxOn HDDon [FanControl2] aktuellRPM:90 zielRPM:1000 Temp:51.5 [4294781.637000] VIDEO0: first pts 0x1e1a8546c [4294781.641000] VIDEO0: resolution changed (1920 1080) VIDEO_GET_EVENT - ok [4294781.690000] signal_strength -118.45dbm [4294781.791000] enable tsm0 [4294781.995000] signal_strength -119.68dbm [4294782.133000] VIDEO0: progressive changed (0) VIDEO_GET_EVENT - ok PTS-Plugin: Erasing stranded timeshift pts_livebuffer.1 before: 1 after: 1 before: 1 before: 1 setIoPrio best-effort level 7 ok use cached_channel [4294783.041000] signal_strength -118.75dbm [4294783.120000] signal_strength -118.75dbm file /media/hdd//pts_livebuffer.1.del erased file /media/hdd//pts_livebuffer.1.meta.del erased file /media/hdd//pts_livebuffer.1.eit.del erased action -> InfobarChannelSelection switchChannelUp allocating new converter! allocating new converter! reused converter! reused converter! reused converter! reused converter! reused converter! reused converter! #####Picon#######################1:0:19:EF10:421:1:C00000:0:0:0: nr_read 689 nr_write 1 sum 690 prev_sum 116 hdd was accessed since previous check! [IDLE] 0 120 False action -> ChannelSelectBaseActions prevBouquet #####Picon#######################1:64:5:0:0:0:0:0:0:0::AB18 #####Picon#######################1:0:1:3780:44C:13E:820000:0:0:0: #####Picon#######################1:0:1:14:578:13E:82ACCE:0:0:0: [EPGC] abort non avail schedule other reading [EPGC] abort non avail viasat reading [EPGC] abort non avail mhw reading [EPGC] nownext finished(1312556815) action -> OkCancelActions ok playing 1:0:1:14:578:13E:82ACCE:0:0:0: [eDVBCAService] free slot 0 demux 0 for service 1:0:19:EF74:3F9:1:C00000:0:0:0: [eDVBCAService] free service 1:0:19:EF74:3F9:1:C00000:0:0:0: !!!!!!!!!!!!!! PTS-Plugin: __evEnd decoder state: p[4294788.340000] stop pcr0 on dmx 0 pid:ff lay, vpid=-1, ap[4294788.345000] stop video0 on dmx 0 pid:ff id=-1 DEMUX_STOP - pcr - ok DEMUX_STOP - video - [4294788.378000] VIDEO0: stop decode ok VIDEO_STOP - [4294788.382000] VIDEO0: set blank to 1 ok AUDIO_STOP - [4294788.387000] audio: decoder stop ok DEMUX_STOP - a[4294788.402000] stop audio on dmx 0 pid:103 udio - [4294788.407000] audio: xpt stop(4) [4294788.410000] no decoder left in sync handling so disable xpt_sync [4294788.416000] bcm_audio_channel_stop(4) done ok AUDIO_CONTINUE - ok DEMUX_STOP - ttx - ok start release channel timer not pauseable. RemovePopup, id = ZapError [eDVBCAService] remove channel 0x2dd607b8 [eDVBLocalTimerHandler] remove channel 0x2dd607b8 [eEPGCache] remove channel 0x2dd607b8 [EPGC] abort caching events !! allocate channel.. 0578:013e [eDVBCAService] new channel 0x2dd607b8! (0)tune RotorCmd ffffffff, lastRotorCmd ffffffff prepare_sat System 0 Freq 11470760 Pol 1 SR 27500000 INV 2 FEC 4 orbpos 130 system 0 modulation 1 pilot 2, rolloff 0 tuning to 1720 mhz OURSTATE: tuning allocate Channel: res 0 [eDVBCIInterfaces] addPMTHandler 1:0:1:14:578:13E:82ACCE:0:0:0: allocate demux resolve: resolve ${sysconfdir}/scan_tp_valid_check.py resolve: -> /etc/scan_tp_valid_check.py [SEC] set static current limiting [4294788.555000] signal_strength -118.74dbm [4294788.561000] signal_strength -118.74dbm [4294788.674000] signal_strength -118.74dbm set sequence pos 3 [4294788.760000] VIDEO0: dst_left, dst_top, dst_width and dst_height is 0.. reset to defaults! [4294788.878000] set current avs auto aspect to 16:9 [4294788.883000] disable wss on display 0 [4294788.886000] set wss 7 on display 1 [4294788.888000] set sb to 3(1) [SEC] setVoltage 1 [SEC] sleep 20ms set sequence pos 3 [SEC] invalidate current switch params [SEC] sendDiseqc: e01038f4 [SEC] sleep 50ms set sequence pos 3 set sequence pos 3 [SEC] update current switch params [SEC] startTuneTimeout 5000 [SEC] setFrontend 1 setting frontend 0 [SEC] sleep 500ms (0)fe event: status 0, inversion off, m_tuning 1 (0)fe event: status 1, inversion off, m_tuning 2 (0)fe event: status 1f, inversion off, m_tuning 3 OURSTATE: ok [eDVBCAService] channel 0x2dd607b8 running [eDVBLocalTimerHandler] channel 0x2dd607b8 running no version filtering 0014: 70 00 00 00 00 00 [4294789.285000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) mask: fc 00 00 00 00 00 mode: 00 00 00 00 00[4294789.295000] start pcr0 on dmx 0 pid:27 index 4 00 [eEPGCache] channel 0x2dd60[4294789.301000] start audio on dmx 0 pid:26 7b8 running sto[4294789.306000] audio xpt start p release channe[4294789.309000] sync is off so we enable it l timer [EPGC] [4294789.314000] demux-index 0 pcr0pid 27 next update in 2[4294789.318000] using 4 as pcr0 pidchannel sec no version[4294789.322000] MPEG filtering 0012[4294789.325000] audio: streamtype set 0 : 4e 00 14 00 0[4294789.329000] audio: streamtype_set: stop rave 0 00 mask: ff ff ff 00 00 00 mode: 00 00 00 00 00 00 ok ... now we start!! no version filtering 0000: 00 00 00 00 00 00 mask: ff 00 00[4294789.344000] audio: streamtype_set: restart rave 00 00 00 mode:[4294789.350000] set mute 0 (111) 0 00 00 00 00 00[4294789.354000] audio: decoder start 0 00 eventNewProgramInfo 0 0 have 1 video stream(s) (0027), and 1 audio stream(s) (0026), and the pcr pid is 0027, and the text pid is ffffffff allocate demux disable telete[4294789.372000] audio delay 18000 (200 ms) xt subtitles PE[4294789.376000] total video delay: 18000 (200 ms) S filter: DMX_SET_PES_FILTER - I[4294789.381000] VIDEO0: set streamtype! nvalid argument [4294789.386000] set MPEG2 decoder state: [4294789.389000] sw rave disabled! play, vpid=39, a[4294789.393000] video delay 0 (0 ms) pid=38 DMX_SET_[4294789.397000] total video delay: 0 (0 ms) PES_FILTER(0x27)[4294789.401000] start video0 on dmx 0 pid:27 - pcr - ok DEM[4294789.405000] total video delay: 0 (0 ms) UX_START - pcr - ok DMX_SET_PES[4294789.410000] VIDEO0: start decode _FILTER(0x26) - audio - ok DEMUX_START - audio - ok AUDIO_SET_BYPASS(1) - ok AUDIO_PAUSE - ok AUDIO_PLAY - ok Video Device: /dev/dvb/adapter0/video0 demux device: /dev/dvb/adapter0/demux0 VIDEO_SET_STREAMTYPE 0 - ok DMX_SET_PES_FILTER(0x27) - video - ok DEMUX_START - video - ok VIDEO_FREEZE - ok VIDEO_PLAY - ok VIDEO_SLOWMOTION(0) - ok VIDEO_FAST_FORWAR[4294789.445000] signal_strength -211.54dbm D(0) - ok VIDEO_CONTINUE - ok AUDIO_CONTINUE - ok not pauseable. [4294789.567000] signal_strength -213.38dbm [SEC] set dynamic current limiti[4294789.594000] signal_strength -213.38dbm ng [eDVBLocalTimerHandler] diff is 3 [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time [eDVBLocalTimerHandler] update RTC [eDVBLocalTimerHandler] time update to 17:07:00 [eDVBLocalTimerHandler] m_time_difference is 3 [eDVBLocalTimerHandler] set Linux Time [EPGC] start cleanloop + 1/1 TID 0[4294789.673000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) 0 done! [EPGC] stop cleanloop [EPGC] 566584 bytes for cache used PATready use pmtpid 0043 for service_id 0014 no version filtering 0043: 02 00 14 00 00 00 mask: ff ff ff 00 00 00 mode: 00 00 00 00 00 00 doing version filtering 0000: 00 00 00[4294789.702000] signal_strength -213.38dbm 25 00 00 mask: ff 00 00 3f 00 00 mode: 00 00 00 3e 00 00 child has terminated pipes closed poll: unhandled POLLERR/HUP/NVAL for fd 73(16) + 1/1 TID 02 done! eventNewProgramInfo 0 0 have 1 video stream(s) (0027), and 1 audio stream(s) (0026), and the pcr pid is 0027, and the text pid is ffffffff PES filter: DMX_SET_PES_FILTER - Invalid argument decoder state: play, vpid=39, apid=38 VIDEO_SLOWMOTION(0) - ok VIDEO_FAST_FORWARD(0) - ok VIDEO_CONTINUE - ok AUDIO_CONTINUE - ok [4294789.824000] signal_strength -212.83dbm [eDVBCAService] new service 1:0:1:14:578:13E:82ACCE:0:0:0: [eDVBCAService] add demux 0 to slot 0 service 1:0:1:14:578:13E:82ACCE:0:0:0: [eDVBCIInterfaces] gotPMT demux 0 mask 01 prevhash 00000000 [eDVBCAService] send 56 bytes 9f 80 32 34 03 00 14 07 00 24 01 81 08 00 82 ac ce 05 78 01 3e 82 02 01 00 84 02 00 43 09 0f 05 00 e4 00 10 01 00 13 01 20 14 03 04 17 00 04 00 26 00 00 02 00 27 00 00 doing version filtering 0043: 02 00 14 07 00 00 mask: ff ff ff 3f 00 00 mode: 00 00 00 3e 00 00 sdt update done! [4294790.516000] ch0: lock [4294790.593000] RAP first pts 0xfcc5bec2, stc 0xfcc59b60, pcr valid [4294790.624000] signal_strength -211.78dbm [4294790.683000] signal_strength -211.78dbm use cached_channel [4294790.887000] RAP sampling rate info isr [4294790.891000] eBitRateChange Isr.. set source_changed_event! [4294790.896000] eModeChange Isr.. set source_changed_event! [EPGC] start caching events(1312556821) [FanControl2] Vlt:255 Pwm:95 Fan:4pin - BoxOn HDDon [FanControl2] aktuellRPM:930 zielRPM:1000 Temp:51.0 [4294791.600000] VIDEO0: first pts 0xfcc7bc80 [4294791.604000] VIDEO0: resolution changed (352 576) [4294791.608000] VIDEO0: aspect changed 2 [4294791.611000] set current avs auto aspect to 16:9 VIDEO_GET_EVENT [4294791.615000] disable wss on display 0 - [4294791.619000] set wss 7 on display 1 ok [4294791.622000] set sb to 3(1) [4294791.661000] signal_strength -212.05dbm [4294791.754000] enable tsm0 [4294791.765000] signal_strength -212.05dbm action -> InfobarChannelSelection zapDown playing 1:0:1:13:578:13E:82ACCE:0:0:0: [eDVBCAService] free slot 0 demux 0 for service 1:0:1:14:578:13E:82ACCE:0:0:0: [eDVBCAService] free service 1:0:1:14:578:13E:82ACCE:0:0:0: !!!!!!!!!!!!!! PTS-Plugin: __evEnd decoder state: p[4294792.384000] stop pcr0 on dmx 0 pid:27 lay, vpid=-1, ap[4294792.390000] stop video0 on dmx 0 pid:27 id=-1 DEMUX_STOP - pcr - ok DE[4294792.395000] VIDEO0: stop decode MUX_STOP - video[4294792.399000] VIDEO0: set blank to 1 - ok VIDEO_STO[4294792.403000] audio: decoder stop P - ok AUDIO_STOP - ok DEMUX_STOP - a[4294792.420000] stop audio on dmx 0 pid:26 udio - [4294792.425000] audio: xpt stop(3) [4294792.428000] no decoder left in sync handling so disable xpt_sync [4294792.434000] bcm_audio_channel_stop(3) done ok AUDIO_CONTINUE - ok start release channel timer not pauseable. RemovePopup, id = ZapError use cached_channel stop release channel timer allocate Channel: res 0 [eDVBCIInterfaces] addPMTHandler 1:0:1:13:578:13E:82ACCE:0:0:0: no version[4294792.583000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) filtering 0012[4294792.591000] start pcr0 on dmx 0 pid:4f index 3 : 4e 00 13 00 00 00 mask: ff [4294792.597000] start audio on dmx 0 pid:4e ff ff 00 00 00 [4294792.602000] audio xpt start mode: 00 00 00 [4294792.605000] sync is off so we enable it 00 00 00 ok ...[4294792.610000] demux-index 0 pcr0pid 4f now we start!! [4294792.614000] using 3 as pcr0 pidchannel no version filt[4294792.618000] MPEG ering 0000: 00[4294792.621000] audio: decoder start 0 00 00 00 00 00 mask: ff 00 00 00 00 00 mode: 00 00 00 00 00 00 eventNewProgramInfo 0 0 have 1 video stream(s) (004f), and 1 audio stream(s) (004e), and t[4294792.638000] video delay 0 (0 ms) he pcr pid is 00[4294792.641000] total video delay: 0 (0 ms) 4f, and the text pid is ffffffff[4294792.646000] start video0 on dmx 0 pid:4f disable teletext subtitles PE[4294792.652000] total video delay: 0 (0 ms) S filter: DMX_SET_PES_FILTER - I[4294792.659000] VIDEO0: start decode nvalid argument decoder state: play, vpid=79, apid=78 DMX_SET_PES_FILTER(0x4f) - pcr - ok DEMUX_START - pcr - ok DMX_SET_PES_FILTER(0x4e) - audio - ok DEMUX_START - audio - ok AUDIO_SET_BYPASS(1) - ok AUDIO_PAUSE - ok AUDIO_PLAY - ok Video Device: /dev/dvb/adapter0/video0 demux device: /dev/dvb/adapter0/demux0 VIDEO_SET_STREAMTYPE 0 - ok DMX_SET_PES_FILTER(0x4f) - video - ok DEMUX_START - video - ok VIDEO_FREEZE - ok VIDEO_PLAY - ok VIDEO_SLOWMOTION(0) - ok VIDEO_FAST_FORWARD(0) - ok VIDEO_CONTINUE - ok [4294792.707000] signal_strength -207.31dbm AUDIO_CONTINUE - ok not pauseable. [4294792.811000] signal_strength -207.31dbm resolve: resolve ${sysconfdir}/scan_tp_valid_check.py resolve: -> /etc/scan_tp_valid_check.py [4294792.839000] signal_strength -207.31dbm [4294792.847000] signal_strength -207.31dbm + 1/1 TID 00 done! PATready use pmtpid 0050 for service_id 0013 no version filtering 0050: 02 00 13 00 00 00 mask: ff ff ff 00 00 00 mode: 00 00 00 00 00 00 doing version filtering 0000: 00 00 00 25 00 00 mask: ff 00 00 3f 00 00 mode: 00 00 00 3e 00 00 + 1/1 TID 02 done! eventNewProgramInfo 0 0 have 1 video stream(s) [4294792.887000] dvb_demux_feed_del: feed not in list (type=0 state=0 pid=ffff) (004f), and 1 audio stream(s) (004e), and the pcr pid is 004f, and the text pid is ffffffff PES filter: DMX_SET_PES_FILTER - Invalid argument decoder state: play, vpid=79, apid=78 VIDEO_SLOWMOTION(0) - ok VIDEO_FAST_FORWARD(0) - ok VIDEO_CONTINUE - ok AUDIO_CONTINUE - ok [4294792.937000] signal_strength -213.25dbm [4294793.042000] signal_strength -213.25dbm [eDVBCAService] new service 1:0:1:13:578:13E:82ACCE:0:0:0: [eDVBCAService] add demux 0 to slot 0 service 1:0:1:13:578:13E:82ACCE:0:0:0: [eDVBCIInterfaces] gotPMT demux 0 mask 01 prevhash 00000000 [eDVBCAService] send 56 bytes 9f 80 32 34 03 00 13 07 00 24 01 81 08 00 82 ac ce 05 78 01 3e 82 02 01 00 84 02 00 50 09 0f 05 00 e4 01 10 01 00 13 01 20 14 03 04 17 00 04 00 4e 00 00 02 00 4f 00 00 doing version filtering 0050: 02 00 13 07 00 00 mask: ff ff ff 3f 00 00 mo[4294793.091000] ch0: lock de: 00 00 00 3e 00 00 [4294793.112000] RAP first pts 0xfcc914f2, stc 0xfcc8f166, pcr valid [4294793.265000] RAP sampling rate info isr [4294793.269000] eBitRateChange Isr.. set source_changed_event! [4294793.274000] eModeChange Isr.. set source_changed_event! [4294793.856000] signal_strength -211.23dbm [4294794.019000] VIDEO0: first pts 0xfccb23a4 use cached_channel [4294794.173000] enable tsm0 [4294794.689000] signal_strength -211.59dbm [4294794.864000] signal_strength -211.59dbm action -> InfobarChannelSelection zapDown playing 1:0:1:227B:238C:13E:820000:0:0:0: [eDVBCAService] free slot 0 demux 0 for service 1:0:1:13:578:13E:82ACCE:0:0:0: [eDVBCAService] free service 1:0:1:13:578:13E:82ACCE:0:0:0: !!!!!!!!!!!!!! PTS-Plugin: __evEnd decoder state: p[4294795.169000] stop pcr0 on dmx 0 pid:4f lay, vpid=-1, apid=-1 DEMUX_STO[4294795.175000] stop video0 on dmx 0 pid:4f P - pcr - ok DE[4294795.181000] VIDEO0: stop decode MUX_STOP - video[4294795.184000] VIDEO0: set blank to 1 - ok VIDEO_STO[4294795.188000] audio: decoder stop P - ok AUDIO_ST[4294795.192000] ch0: unlock OP - ok DEMUX_STOP - a[4294795.208000] stop audio on dmx 0 pid:4e udio - [4294795.213000] audio: xpt stop(2) [4294795.216000] no decoder left in sync handling so disable xpt_sync [4294795.221000] bcm_audio_channel_stop(2) done ok AUDIO_CONTINUE - ok start release channel timer not pauseable. RemovePopup, id = ZapError [eDVBCAService] remove channel 0x2dd607b8 [eDVBLocalTimerHandler] remove channel 0x2dd607b8 [eEPGCache] remove channel 0x2dd607b8 [EPGC] abort caching events !! allocate channel.. 238c:013e [eDVBCAService] new channel 0x2dd607b8! (0)tune RotorCmd ffffffff, lastRotorCmd ffffffff prepare_sat System 0 Freq 12539020 Pol 0 SR 27500000 INV 2 FEC 3 orbpos 130 system 0 modulation 1 pilot 2, rolloff 0 tuning to 1939 mhz OURSTATE: tuning allocate Channel: res 0 [eDVBCIInterfaces] addPMTHandler 1:0:1:227B:238C:13E:820000:0:0:0: allocate demux resolve: resolve ${sysconfdir}/scan_tp_valid_check.py resolve: -> /etc/scan_tp_valid_check.py [SEC] set static current limiting set sequence pos 3 [SEC] setVoltage 2 [SEC] sleep 20ms set sequence pos 3 [SEC] invalidate current switch params [SEC] sendDiseqc: e01038f7 [SEC] sleep 50ms set sequence pos 3 [SEC] setTone 1 [SEC] sleep 10ms [SEC] update current switch params [SEC] startTuneTimeout 5000 [SEC] setFrontend 1 setting frontend 0 [SEC] sleep 500ms (0)fe event: status 0, inversion off, m_tuning 1 (0)fe event: status 1, inversion off, m_tuning 2 [4294795.871000] signal_strength -214.82dbm (0)fe event: status 0, inversion off, m_tuning 3 [SEC] set dynamic current limiting (0)fe event: status 1, inversion off, m_tuning 4 use cached_channel (0)fe event: status 0, inversion off, m_tuning 5 (0)fe event: status 1, inversion off, m_tuning 6 [4294796.683000] signal_strength -222.95dbm nr_read 695 nr_write 1 sum 696 prev_sum 690 hdd was accessed since previous check! [IDLE] 0 120 False (0)fe event: status 0, inversion off, m_tuning 7 [4294796.878000] signal_strength -216.64dbm (0)fe event: status 21, inversion off, m_tuning 8 FE_TIMEDOUT! ..abort OURSTATE: failed tune failed. DVB service failed to tune - error 1 RemovePopup, id = ZapError AddPopup, id = ZapError ignore sdt update data.... incorrect transponder tuned!!! (0)fe event: status 20, inversion off, m_tuning 0 stateLostLock OURSTATE: lost lock, trying to retune (0)tune RotorCmd ffffffff, lastRotorCmd ffffffff prepare_sat System 0 Freq 12539020 Pol 0 SR 27500000 INV 2 FEC 3 orbpos 130 system 0 modulation 1 pilot 2, rolloff 0 tuning to 1939 mhz OURSTATE: tuning PC: 00000000 00000000 30008b00 00000000 00000000 7ffcf834 7ffcfadc 00000002 00000001 0055812c 00000004 2dd63230 0055812c 00000002 ffffffff 00000002 00000001 2dd12918 7ffcf834 00000000 00000000 0000000b 007bb780 00555c38 0059efbc 005be63c 00000000 00000001 00000000 2b53a020 7ffcf7e8 0055b314 00477dd4 ------- getResolvedKey config.plugins.crashlogautosubmit.sendAnonCrashlog failed !! (Typo??) resolve: resolve ${sysconfdir}/enigma2/settings resolve: -> /etc/enigma2/settings getResolvedKey config.plugins.crashlogautosubmit.addNetwork failed !! (Typo??) resolve: resolve ${sysconfdir}/enigma2/settings resolve: -> /etc/enigma2/settings getResolvedKey config.plugins.crashlogautosubmit.addWlan failed !! (Typo??) resolve: resolve ${sysconfdir}/enigma2/settings resolve: -> /etc/enigma2/settings resolve: resolve ${libdir}/enigma2/python/ resolve: -> /usr/lib/enigma2/python/ main thread is non-idle! display spinner! main thread is non-idle! display spinner! Killed [4294815.132000] bcm4506 channel 0 is sleeping now [4294815.148000] VIDEO0: set blank to 0 [4294815.153000] sync is off so we enable it [4294815.157000] playback! [4294815.159000] total video delay: 0 (0 ms) [4294815.166000] VIDEO0: start decode [4294815.171000] flush video decoder [4294815.175000] VIDEO0 use saved pts 0xfccbbe54 (ret 0) [4294815.222000] VIDEO0: first pts 0x0 [4294815.225000] VIDEO0: resolution changed (1280 720) [4294815.229000] VIDEO0: aspect changed 3 [4294815.232000] set current avs auto aspect to 16:9 [4294815.237000] disable wss on display 0 [4294815.241000] set wss 7 on display 1 [4294815.244000] set sb to 3(1) [4294815.339000] VIDEO0: set blank to 0 [4294815.343000] VIDEO0: stop decode [4294815.347000] VIDEO0: set blank to 0 [4294815.350000] no decoder left in sync handling so disable xpt_sync setenv('prefix', '/usr', 0) setenv('exec_prefix', '/usr', 0) setenv('bindir', '/usr/bin', 0) setenv('sbindir', '/usr/sbin', 0) setenv('libexecdir', '/usr/libexec', 0) setenv('datarootdir', '${prefix}/share', 0) setenv('datadir', '/usr/share', 0) setenv('sysconfdir', '/etc', 0) setenv('sharedstatedir', '/com', 0) setenv('localstatedir', '/var', 0) setenv('libdir', '/usr/lib', 0) setenv('localedir', '${datarootdir}/locale', 0) setenv('prefix', '/usr', 1) setenv('exec_prefix', '/usr', 1) setenv('bindir', '/usr/bin', 1) setenv('sbindir', '/usr/sbin', 1) setenv('libexecdir', '/usr/libexec', 1) setenv('datarootdir', '/usr/share', 1) setenv('datadir', '/usr/share', 1) setenv('sysconfdir', '/etc', 1) setenv('sharedstatedir', '/com', 1) setenv('localstatedir', '/var', 1) setenv('libdir', '/usr/lib', 1) setenv('localedir', '/usr/share/locale', 1) resolve: resolve ${datadir}/enigma2/encoding.conf resolve: -> /usr/share/enigma2/encoding.conf [4294816.179000] VIDEO0: progressive changed (1) enigma2::receiver model dm8000(1) detected enigma2::TPM signature OK resolve: resolve ${libdir}/enigma2/python resolve: -> /usr/lib/enigma2/python PYTHONPATH: /usr/lib/enigma2/python + (1) Background File Eraser + (8) graphics acceleration manager + (9) GFBDC 16384k video mem [4294816.962000] bcmfb: enable manual blit SetMode : wanted: 720x576x32, got 1280x720x32 [4294816.966000] bcmfb: creating surface with pixel format 0x07e48888 (BPXL_eA8_R8_G8_B8) - double buffering available! 13144kB available for acceleration surfaces. resolution: 720 x 576 x 32 (stride: 2880) + (9) gLCDDC found OLED display! lcd buffer 0x6b8138 [4294817.136000] tsmux set cisource reg 00 to val 44 8448 bytes, stride 132 + (9) Fo[4294817.144000] tsmux set cisource reg 00 to val 44 nt Render Class [FONT] initiali[4294817.150000] tsmux set cisource reg 01 to val 34 zing lib... [FONT] loading fonts... [FONT] Int[4294817.158000] tsmux set cisource reg 01 to val 44 ializing font cache, using max. [4294817.164000] tsmux set tsports reg 02 to val dc 4MB... + (10) gRC RC thread created successful[4294817.172000] tsmux set tsports reg 02 to val dc ly + (15) eWindowStyleManager [4294817.178000] tsmux set tsports reg 03 to val fe + (20) DVB-CI UI[4294817.184000] tsmux set tsports reg 03 to val fe + (20) UHF Modulator couldnt open /dev/rfmod0!!!! + (20) RC Input layer + (20) misc options + (20) AVSwitch Driver + (21) input device driver Input device "dreambox remote control (native)" is not a keyboard. Input device "dreambox advanced remote control (native)" is not a keyboard. Input device "dreambox ir keyboard" is a keyboard. Input device "dreambox ir mouse" is not a keyboard. Input device "dreambox front panel" is not a keyboard. Found 5 input devices! + (21) Console RC Driver + (30) eActionMap + (35) CI Slots scanning for common interfaces.. CI Slot 0 setSource(0) CI Slot 1 setSource(0) CI Slot 2 setSource(0) CI Slot 3 setSource(0) eDVBCIInterfaces->setInputSource(0, 0) eDVBCIInterfaces->setInputSource(1, 1) eDVBCIInterfaces->setInputSource(2, 2) eDVBCIInterfaces->setInputSource(3, 3) done, found 4 common interface slots + (40) eServiceCenter settings instance. + (41) eServiceFactoryM2TS + (41) eServiceFactoryMP3 + (41) eServiceFactoryFS + (41) eServiceFactoryDVB reached rl 70 resolve: resolve ${sysconfdir}/enigma2/lamedb resolve: -> /etc/enigma2/lamedb ---- opening lame channel db reading services (version 4) loaded 3734 services scanning for frontends.. opening frontend[4294817.807000] bcm4506 channel 0 is in normale mode now 0 detected satellite frontend close frontend 0 opening frontend 1 [4294817.828000] bcm4506 channel 1 is in normale mode now detected satellite frontend close frontend 1 opening frontend 2 [4294817.849000] bcm4506 channel 0 is in normale mode now detected satellite frontend close frontend 2 opening frontend 3 [4294817.864000] bcm4506 channel 0 is in normale mode now detected satellite frontend close frontend 3 found 1 adapter, 4 frontends(4 sim) and 5 demux, boxtype 4 Use valid Linux Time :) (RTC?) [EPGC] Initialized EPGCache (wait for setCacheFile call now) resolve: resolve ${datadir}/enigma2/skin_default/pal.png resolve: -> /usr/share/enigma2/skin_default/pal.png Loading spinners... resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait1.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait1.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait2.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait2.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait3.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait3.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait4.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait4.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait5.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait5.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait6.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait6.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait7.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait7.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait8.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait8.png resolve: resolve ${datadir}/enigma2/skin_default/spinner/wait9.png resolve: -> /usr/share/enigma2/skin_default/spinner/wait9.png found 8 spinner! executing main setIoPrio best-effort level 3 ok resolve: resolve ${libdir}/enigma2/python/mytest.py resolve: -> /usr/lib/enigma2/python/mytest.py resolve: resolve ${sysconfdir}/ resolve: -> /etc/ resolve: resolve ${sysconfdir}/ resolve: -> /etc/ resolve: resolve ${datadir}/fonts/ resolve: -> /usr/share/fonts/ resol[4294818.316000] 45912 ms: 100 ve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ resolve: resolve ${libdir}/enigma2/python/Plugins/ resolve: -> /usr/lib/enigma2/python/Plugins/ resolve: resolve ${datadir}/enigma2/po/ resolve: -> /usr/share/enigma2/po/ resolve: resolve ${datadir}/enigma2/ resolve: -> [4294818.344000] 24 ms: 50 /usr/share/enigma2/ resolve: resolve ${datadir}/enigma2/ resolve: -> /usr/share/enigma2/ resolve: resolve ${sysconfdir}/enigma2/playlist/ resolve: -> /etc/enigma2/playlist/ resolve: resolve ${datadir}/enigma2/defaults/ resolve: -> /usr/share/enigma2/defaults/ resolve: resolve ${datadir}/enigma2/dealer resolve: -> /usr/share/enigma2/dealer resolve: resolve ${datadir}/meta resolve: -> /usr/share/meta resolve: resolve ${datadir}/enigma2/defaults/ resolve: -> /usr/share/enigma2/defaults/ [4294818.456000] 109 ms: 50 [4294818.486000] 27 ms: 51 [4294818.499000] 10 ms: 51 [4294818.982000] 481 ms: 51 /proc/stb/frontend/0/lnb_sense is 0 enumerating block devices... found block device 'mtdblock3': blacklisted found block device 'mtdblock2': blacklisted found block device 'mtdblock1': blacklisted found block device 'mtdblock0': blacklisted found block device 'sda': ok, removable=False, cdrom=False, partitions=['sda1'] new Harddisk sda -> /dev/sda -> /dev/sda [ePopen] command: ('hdparm', 'hdparm', '-S0', '/dev/sda') found block device 'sda1': error querying properties main thread is non-idle! display spinner! [4294819.198000] 214 ms: 52 [4294819.582000] 381 ms: 53 [4294819.702000] 118 ms: 53 [4294819.719000] 14 ms: 54 [4294819.722000] 1 ms: 54 [4294819.725000] 1 ms: 54 Preferred tag editor set to None [4294819.933000] 205 ms: 54 [4294819.937000] 1 ms: 54 [4294819.986000] 46 ms: 54 [4294820.245000] 256 ms: 54 Reading satellites.xml [4294820.816000] bcm4506 channel 0 is sleeping now [4294820.836000] bcm4506 channel 1 is sleeping now [4294820.858000] bcm4506 channel 0 is sleeping now [4294820.873000] bcm4506 channel 0 is sleeping now main thread is non-idle! display spinner! resolve: resolve ${datadir}/enigma2/unicable.xml resolve: -> /usr/share/enigma2/unicable.xml removing internal link on frontend id 1 sec config cleared setSlotInfo for dvb frontend 0 to slotid 0, descr BCM4506 (internal), need rotorworkaround No, enabled Yes, DVB-S2 Yes setSlotInfo for dvb frontend 1 to slotid 1, descr BCM4506 (internal), need rotorworkaround No, enabled Yes, DVB-S2 Yes setSlotInfo for dvb frontend 2 to slotid 2, desc[4294822.812000] 2565 ms: 55 r BCM4505, need rotorworkaround No, enabled Yes, DVB-S2 Yes setSlotInfo for dvb frontend 3 to slotid 3, descr BCM4505, need rotorworkaround No, enabled Yes, DVB-S2 Yes slot: 0 configmode: simple diseqcmode[4294822.832000] 17 ms: 60 : diseqc_a_b slot: 1 configmod[4294822.837000] 1 ms: 60 e: simple diseqcmode: diseqc_a[4294822.843000] 2 ms: 60 _b slot: 2 configmode: simple diseqcmode: diseqc_a_b slot: 3 configmode: simple diseqcmode: diseqc_a_b sec config completed [4294822.931000] 85 ms: 60 [4294822.944000] 11 ms: 60 resolve: resolve ${datadir}/enigma2/setup.xml resolve: -> /usr/share/enigma2/setup.xml [4294823.768000] 821 ms: 60 [4294823.772000] 2 ms: 61 [4294823.786000] 11 ms: 61 resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/bouquets.tv resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.favourites.tv [4294823.810000] 21 ms: 61 105 entries in Bouquet userbouquet.favourites.tv resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.dbe00.tv 42 entries in Bouquet userbouquet.dbe00.tv resolve: resolve ${sysco[4294823.834000] 20 ms: 61 nfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.favourites_hd.tv 30 entries in Bouquet userbouquet.favourites_hd.tv resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.dbe02.tv 8 entries in Bouquet userbouquet.dbe02.tv resolve: reso[4294823.866000] 29 ms: 62 lve ${sysconfdir}/enigma2/ reso[4294823.871000] 2 ms: 62 lve: -> /etc/enigma2/ loading bouquet... /etc/e[4294823.878000] 3 ms: 62 nigma2/userbouquet.dbe03.tv 34 entries in Bouquet userbouquet.dbe03.tv 5 entries in Bouquet bouquets.tv resol[4294823.889000] 8 ms: 62 ve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/bouquets.radio resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ loading bouquet... /etc/enigma2/userbouquet.favourites.radio 10 entries in Bouquet userbouquet.favourites.radio 1 entries in Bouquet bouquets.radio [eDVBLocalTimeHandler] enable sync local time with transponder time! /usr/lib/python2.6/site-packages/twisted/internet/_sslverify.py:5: DeprecationWarning: the md5 module is deprecated; use hashlib instead [4294825.255000] 1362 ms: 62 [4294825.267000] 9 ms: 65 add dreampackage scanner plugin added [4294825.376000] 106 ms: 65 [4294825.386000] 7 ms: 66 [4294825.419000] 30 ms: 66 [4294825.424000] 3 ms: 66 [4294825.432000] 5 ms: 66 [4294825.439000] 4 ms: 66 [4294825.451000] 9 ms: 66 [4294825.464000] 10 ms: 66 [4294825.469000] 2 ms: 66 [FONT] adding font /usr/share/fonts/nmsbd.ttf...OK (Display) SetMode : wanted: 1280x720x32, got 720x576x32 [4294825.488000] bcmfb: creating surface with pixel format 0x07e48888 (BPXL_eA8_R8_G8_B8) - double buffering available! 9184kB available for acceleration surfaces. resolution: 1280 x 720 x 32 (stride: 5120) [FONT] adding font /usr/share/enigma2/Vali.HD.flex/hd.ttf...OK (Regular) [FONT] adding font /usr/share/fonts/lcd.ttf...OK (LCD) [FONT] adding font /usr/share/fonts/tuxtxt.ttf...OK (Console) [FONT] adding font /usr/share/fo[4294825.829000] 358 ms: 66 nts/skinuser.ttf...OK (Swiss-MAD_UserSkinFont) [iInputDevices] setRepeat for device event1 to 340 ms [iInputDevices] setDelay for device event1 to 3200 ms [4294825.890000] 57 ms: 67 [4294825.943000] set current avs auto aspect to 4:3 [4294825.947000] disable wss on display 0 [4294825.950000] set wss 8 on display 1 [4294825.953000] set sb to 3(2) [4294825.955000] Write AVS:set current avs auto aspect to 4:3 [4294825.955000] disable wss on display 0 [4294825.955000] set wss 8 on display 1 [4294825.955000] disable wss on display 0 [4294825.955000] set wss 8 on display 1 [4294825.975000] 40 40 00 00 00 00 00 63 00 02 00 00 00 ff [4294825.986000] set sb to 3(2) [4294825.989000] set input to 0 [4294825.991000] set fb to 2(0) [4294825.993000] set current avs auto aspect to 4:3 [4294825.997000] disable wss on display 0 [4294826.001000] set wss 8 on display 1 [4294826.003000] set sb to 3(2) [4294826.007000] set ac3 to passthrough --> setting scaler_sharpness to:[4294826.018000] 125 ms: 67 00000014 [4294826.034000] 13 ms: 68 couldn't open /proc/stb/misc/12V_output resolve: resolve ${datadir}/enigma2/keymap.xml resolve: -> /usr/share/enigma2/keymap.xml [4294826.108000] 71 ms: 68 [4294826.321000] 211 ms: 68 [ePopen] command: ip -o addr show dev ath0 [ePopen] command: ip -o addr show dev eth0 [4294826.362000] 38 ms: 68 setLCDBrightness 25 setLCDBrightness 127 [4294826.438000] 73 ms: 68 resolve: resolve ${datadir}/keymaps/ resolve: -> /usr/share/keymaps/ resolve: resolve ${datadir}/keymaps/ resolve: -> /usr/share/keymaps/ resolve: resolve ${datadir}/keymaps/ resolve: -> /usr/share/keymaps/ Activating keymap: Keyboard English resolve: resolve ${datadir}/keymaps/ resolve: -> /usr/share/keymaps/ [ePopen] command: loadkmap < /usr/share/keymaps/eng.kmap Activating language German main thread is non-idle! display spinner! language set to de_DE [4294828.075000] 1634 ms: 68 [4294828.087000] 9 ms: 71 [4294828.121000] 31 ms: 71 It's now Fri Aug 5 17:07:39 2011 [timer.py] next activation: 1312556959 (in 99897 ms) Media Center: Import VLC Stuff failed /usr/lib/enigma2/python/Plugins/Extensions/WebInterface/__init__.py:4: DeprecationWarning: the sha module is deprecated; use the hashlib module instead import os, gettext, sha [WebInterface] set language to de [WebInterface] set language to de [WebInterface] fallback to default translation for Webinterface [Bonjour.reloadConfig] reloading config [Bonjour.__parse] parsing /etc/avahi/services/https.service [Bonjour.registerService] {'text': '', 'type': '_https._tcp', 'name': '%h HTTPS', 'file': 'https.service', 'port': '443'} [Bonjour.__writeService] Creating service file 'https.service' [Bonjour.__parse] parsing /etc/avahi/services/sftp-ssh.service [Bonjour.registerService] {'text': '', 'type': '_sftp-ssh._tcp', 'name': 'SFTP File Transfer on %h', 'file': 'sftp-ssh.service', 'port': '22'} [Bonjour.__writeService] Creating service file 'sftp-ssh.service' [Bonjour.__parse] parsing /etc/avahi/services/smb.service [Bonjour.registerService] {'text': '', 'type': '_smb._tcp', 'name': '%h SMB', 'file': 'smb.service', 'port': '139'} [Bonjour.__writeService] Creating service file 'smb.service' [Bonjour.__parse] parsing /etc/avahi/services/http.service [Bonjour.registerService] {'text': '', 'type': '_http._tcp', 'name': '%h HTTP', 'file': 'http.service', 'port': '80'} [Bonjour.__writeService] Creating service file 'http.service' [Bonjour.__parse] parsing /etc/avahi/services/ftp.service [Bonjour.registerService] {'text': '', 'type': '_ftp._tcp', 'name': '%h FTP', 'file': 'ftp.service', 'port': '21'} [Bonjour.__writeService] Creating service file 'ftp.service' [Bonjour.__parse] parsing /etc/avahi/services/ssh.service [Bonjour.registerService] {'text': '', 'type': '_ssh._tcp', 'name': '%h', 'file': 'ssh.service', 'port': '22'} [Bonjour.__writeService] Creating service file 'ssh.service' [Bonjour.registerDefaultServices] called [dFlash] /tmp/dflash.sh created [AudioSync] set language to de [AudioSync] set language to de resolve: resolve ${libdir}/enigma2/python/Plugins/SystemPlugins/WirelessLan resolve: -> /usr/lib/enigma2/python/Plugins/SystemPlugins/WirelessLan getModeList for port DVI-PC getModeList for port YPbPr getModeList for port Scart getModeList for port DVI-PC getModeList for port DVI hotplug on dvi -> setting aspect, policy, policy2, wss 16:9 bestfit bestfit auto [4294832.962000] set current avs auto aspect to 16:9 [4294832.966000] disable wss on display 0 [4294832.969000] set wss 7 on display 1 [4294832.972000] set sb to 3(1) [4294832.974000] Write AVS: 40 40 00 00 00 00 00 61 00 02 00 00 00 ff [4294832.997000] set current avs auto aspect to 16:9 [4294833.001000] disable wss on display 0 [4294833.005000] set wss 7 on display 1 [4294833.009000] set sb to 3(1) [4294833.013000] disable wss on display 0 [4294833.017000] set wss 7 on display 1 [4294833.023000] set current avs auto aspect to 16:9 [4294833.028000] disable wss on display 0 [4294833.031000] set wss 7 on display 1 [4294833.034000] set sb to 3(1) -> setting aspect, policy, policy2, wss 16:9 bestfit bestfit aut[4294833.043000] set current avs auto aspect to 16:9 o [4294833.049000] disable wss on display 0 [4294833.052000] set wss 7 on display 1 [4294833.055000] set sb to 3(1) [4294833.057000] set current avs auto aspect to 16:9 [4294833.062000] disable wss on display 0 [4294833.066000] set wss 7 on display 1 [4294833.069000] set sb to 3(1) [4294833.074000] disable wss on display 0 [4294833.077000] set wss 7 on display 1 [4294833.081000] set current avs auto aspect to 16:9 [4294833.086000] disable wss on display 0 [4294833.089000] set wss 7 on display 1 [4294833.092000] set sb to 3(1) -> setting aspect, policy, polic[4294833.100000] set current avs auto aspect to 16:9 y2, wss 16:9 bes[4294833.105000] disable wss on display 0 tfit bestfit aut[4294833.110000] set wss 7 on display 1 o [4294833.115000] set sb to 3(1) [4294833.120000] set current avs auto aspect to 16:9 [4294833.125000] disable wss on display 0 [4294833.128000] set wss 7 on display 1 [4294833.131000] set sb to 3(1) [4294833.133000] disable wss on display 0 [4294833.137000] set wss 7 on display 1 [4294833.141000] set current avs auto aspect to 16:9 [4294833.146000] disable wss on display 0 [4294833.149000] set wss 7 on display 1 [4294833.151000] set sb to 3(1) -> setting aspect, policy, polic[4294833.157000] set current avs auto aspect to 16:9 y2, wss 16:9 bes[4294833.163000] disable wss on display 0 tfit bestfit aut[4294833.168000] set wss 7 on display 1 o [4294833.173000] set sb to 3(1) [4294833.177000] set current avs auto aspect to 16:9 [4294833.182000] disable wss on display 0 [4294833.186000] set wss 7 on display 1 [4294833.190000] set sb to 3(1) [4294833.194000] disable wss on display 0 [4294833.198000] set wss 7 on display 1 [4294833.200000] set current avs auto aspect to 16:9 [4294833.205000] disable wss on display 0 [4294833.208000] set wss 7 on display 1 [4294833.211000] set sb to 3(1) setMode - port: DVI mode: 1080i[4294833.216000] set current avs auto aspect to 16:9 rate: 50Hz [4294833.221000] disable wss on display 0 [4294833.225000] set wss 7 on display 1 [4294833.228000] set sb to 3(1) [4294833.233000] set current avs auto aspect to 16:9 [4294833.238000] disable wss on display 0 [4294833.242000] set wss 7 on display 1 [4294833.246000] set sb to 3(1) -> setting aspect, policy, polic[4294833.256000] set current avs auto aspect to 16:9 y2, wss 16:9 bes[4294833.262000] disable wss on display 0 tfit bestfit aut[4294833.267000] set wss 7 on display 1 o [4294833.272000] set sb to 3(1) [4294833.276000] set current avs auto aspect to 16:9 [4294833.281000] disable wss on display 0 [4294833.284000] set wss 7 on display 1 [4294833.287000] set sb to 3(1) [4294833.289000] disable wss on display 0 [4294833.293000] set wss 7 on display 1 [4294833.298000] set current avs auto aspect to 16:9 [4294833.303000] disable wss on display 0 [4294833.307000] set wss 7 on display 1 [4294833.310000] set sb to 3(1) resolve: resolve ${datadir}/enigma2/ resolve: -> /usr/share/enigma2/ [GP2DisplayRepresentation] found LANGUAGE= de [GP2DisplayRepresentation] found LANGUAGE= de resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ resolve: resolve ${sysconfdir}/enigma2/ resolve: -> /etc/enigma2/ starting hotplug handler [CI_Assignment] activating ci configs: [CI_Activate] FOUND 4 CI Slots resolve: resolve ${sysconfdir}/enigma2/ci resolve: -> /etc/enigma2/ci [4294834.082000] 5959 ms: 71 [CI_Activate_Config_CI0] no config file found [CI_Activate_Config_CI0] error parsing xml... resolve: resolve ${sysconfdir}/enigma2/ci resolve: -> /etc/enigma2/ci [CI_Activate_Config_CI1] no config file found [CI_Activate_Config_CI1] error parsing xml... resolve: resolve ${sysconfdir}/enigma2/ci resolve: -> /etc/enigma2/ci [CI_Activate_Config_CI2] no config file found [CI_Activate_Config_CI2] error parsing xml... resolve: resolve ${sysconfdir}/enigma2/ci resolve: -> /etc/enigma2/ci [CI_Activate_Config_CI3] no config file found [CI_Activate_Config_CI3] error parsing xml... It's now Fri Aug 5 17:07:44 2011 [timer.py] next activation: 1312556964 (in 99468 ms) [TIMER] record time changed, start prepare is now: Fri Aug 5 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:44 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556964 (in 99446 ms) [TIMER] record time changed, start prepare is now: Sun Aug 7 20:11:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:44 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556964 (in 99432 ms) [TIMER] record time changed, start prepare is now: Sun Aug 7 21:13:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:44 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556964 (in 99415 ms) [TIMER] record time changed, start prepare is now: Mon Aug 8 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:44 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556964 (in 99393 ms) [TIMER] record time changed, start prepare is now: Mon Aug 8 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:44 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556964 (in 99370 ms) [TIMER] record time changed, start prepare is now: Tue Aug 9 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:45 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556965 (in 99834 ms) [TIMER] record time changed, start prepare is now: Tue Aug 9 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:45 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556965 (in 99807 ms) [TIMER] record time changed, start prepare is now: Wed Aug 10 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:45 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556965 (in 99772 ms) [TIMER] record time changed, start prepare is now: Wed Aug 10 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:45 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556965 (in 99737 ms) [TIMER] record time changed, start prepare is now: Thu Aug 11 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:45 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556965 (in 99701 ms) [TIMER] record time changed, start prepare is now: Thu Aug 11 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated It's now Fri Aug 5 17:07:45 2011 next real activation is Fri Aug 5 19:34:40 2011 [timer.py] next activation: 1312556965 (in 99661 ms) [TIMER] record time changed, start prepare is now: Fri Jul 29 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Sat Jul 30 06:17:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Sat Jul 30 07:27:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:2F08:441:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Sun Jul 31 20:11:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Sun Jul 31 22:17:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:A:2:85:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Sun Jul 31 21:12:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Mon Aug 1 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Mon Aug 1 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Mon Aug 1 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Tue Aug 2 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Tue Aug 2 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Tue Aug 2 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Wed Aug 3 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Wed Aug 3 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Wed Aug 3 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Wed Aug 3 23:41:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF75:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Wed Aug 3 23:13:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF75:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Thu Aug 4 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Thu Aug 4 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Thu Aug 4 19:34:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Thu Aug 4 21:12:40 2011 sanitycheck check checkTimerlist recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Fri Aug 5 07:32:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 [TIMER] record time changed, start prepare is now: Fri Aug 5 08:02:40 2011 sanitycheck check checkTimerlist recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF10:421:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:19:EF74:3F9:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 recording service: 1:0:1:6D68:437:1:C00000:0:0:0: record: 0 [Timer] Record ProcessRepeated already passed, skipping shouldSkip: True state == ended False waiting && disabled: 0 It's now Fri Aug 5 17:07:47 2011 [timer.py] next activation: 1312556967 (in 99345 ms) Repeated: 1 Repeated: 3 Repeated: 7 Repeated: 15 Repeated: 31 Repeated: 63 Repeated: 127 ProcessRepeated localrepeatedbegindate: Fri Aug 5 17:15:00 2011 localbegin: Fri Aug 5 17:15:00 2011 localend: Fri Aug 5 17:15:00 2011 localnow: Fri Aug 5 17:07:48 2011 Day: 0 Day: 1 Day: 2 Day: 3 Day: 4 Day: 5 Day: 6 ProcessRepeated result Fri Aug 5 17:15:00 2011 Fri Aug 5 17:15:01 2011 It's now Fri Aug 5 17:07:47 2011 next real activation is Fri Aug 5 17:15:01 2011 [timer.py] next activation: 1312556967 (in 99290 ms) [FanControl2] Starting up [FanControl2] ATA(STT_FTM32GX25H) /dev/sda Mode:auto [FanControl2] HDD Temperature not readable [FanControl2] HDD not supports Temp reading without Spinup -> Disabled [FanControl2] HDD Temp 0C Looking for embedded skin [dFlash] autostart [CHECKSOFTWAREUPDATE] autostart check [CHECKSOFTWAREUPDATE] doing check [CHECKSOFTWAREUPDATE] planning dummy check Looking for embedded skin [AutomaticTimerlistCleanUp] Starting AutomaticTimerlistCleanUp... [AutomaticTimerlistCleanUp] Cleaning up timerlist-entries older than Fri Jul 29 17:07:54 2011 [AutomaticTimerlistCleanUp] Next automatic timerlist cleanup at Sat Aug 6 17:07:54 2011 [Toplevel.importExternalModules] Imported external module: dFlash [Toplevel.importExternalModules] Imported external module: AutoTimer [Toplevel.importExternalModules] Imported external module: EPGRefresh [Toplevel.importExternalModules] Imported external module: Example [WebInterface] checking for SSL Certificates [Webinterface] started on 0.0.0.0:80 auth=True ssl=False [Bonjour.registerService] {'text': '', 'type': '_http._tcp', 'name': '%h HTTP', 'file': 'http.service', 'port': 80} [Bonjour.__writeService] Creating service file 'http.service' [WebInterface.registerBonjourService] Service for protocol 'http' with port '80' registered! [Webinterface] started on 0.0.0.0:443 auth=True ssl=True [Bonjour.registerService] {'text': '', 'type': '_https._tcp', 'name': '%h HTTPS', 'file': 'https.service', 'port': 443} [Bonjour.__writeService] Creating service fil[4294844.709000] 10623 ms: 85 e 'https.service' [WebInterface.registerBonjourService] Service for protocol 'https' with port '443' registered! [EPGC] setCacheFile read/write epg data from/to '/hdd/epg.dat' [EPGC] time updated.. start EPG Mainloop before: 1 after: 1 not showing fine-tuning wizard, config variable doesn't exist showtestcard is false Looking for embedded skin [4294844.805000] 93 ms: 99 setValue 95 [4294844.865000] set mute 0 (111) 0 cannot open /proc/stb/audio/j1_m[4294844.869000] 61 ms: 99 ute(No such file or directory) Setvolume: 100 100 (raw) Setvolume: 0 0 (-1db) Setvolume: 95 95 (raw) Setvolume: 4 4 (-1db) [4294844.883000] 10 ms: 99 lookup for events with 'Gute Zeiten, schlechte Zeiten' as title(case sensitive) lookup for events with 'Navy CIS: L.A.' as title(case sensitive) lookup for events with 'Dr. House' as title(case sensitive) lookup for events with 'Bones' in title(case sensitive) lookup for events with 'Psych' as title(case sensitive) lookup for events with 'Disney Micky Maus Wunderhaus' as title(case sensitive) lookup for events with 'The Mentalist' as title(case sensitive) lookup for events with 'Navy CIS' as title(case sensitive) lookup for events with 'Mein Mann kann' as title(case sensitive) lookup for events with 'Cougar Town' in title(ignore case) lookup for events with 'Die Sendung mit dem Elefanten' as title(case sensitive) lookup for events with 'Kleiner Roter Traktor' as title(case sensitive) nr_read 699 nr_write 31 sum 730 prev_sum 0 hdd was accessed since previous check! [IDLE] 0 120 False allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! resolve: resolve ${datadir}/enigma2/%s/ resolve: -> /usr/share/enigma2/%s/ allocating new converter! allocating new converter! allocating new converter! reused converter! RemovePopup, id = ZapError allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! allocating new converter! allocating new converter! reused converter! allocating new converter! allocating new converter! reused converter! allocating new converter! reused converter! allocating new converter! reused converter! playing 1:0:19:EF74:3F9:1:C00000:0:0:0: not pauseable. RemovePopup, id = ZapError allocate channel.. 03f9:0001 openin[4294846.465000] bcm4506 channel 0 is in normale mode now g frontend 0 [eDVBCAService] new channel 0x2d724340! (0)tune RotorCmd ffffffff, lastRotorCmd ffffffff prepare_sat System 1 Freq 11464250 Pol 0 SR 22000000 INV 2 FEC 2 orbpos 192 system 1 modulation 2 pilot 2, rolloff 0 tuning to 1714 mhz OURSTATE: [4294846.498000] signal_strength -2892.33dbm tuning allocate Channel: res 0 [eDVBCIInterfaces] addPMTHandler 1:0:19:EF74:3F9:1:C00000:0:0:0: allocate demux resolve: resolve ${sysconfdir}/scan_tp_valid_check.py resolve: -> /etc/scan_tp_valid_check.py [SEC] set static current limiting set sequence pos 3 set sequence pos 4 [SEC] setVoltage 2 [SEC] sleep 200ms child has terminated pipes closed child has terminated pipes closed [ePopen] command: route -n | grep ath0 child has terminated pipes closed [ePopen] command: route -n | grep eth0 poll: unhandled POLLERR/HUP/NVAL for fd 34(16) child has terminated pipes closed poll: unhandled POLLERR/HUP/NVAL for fd 39(16) poll: unhandled POLLERR/HUP/NVAL for fd 40(16) poll: unhandled POLLERR/HUP/NVAL for fd 42(16) [SEC] invalidate current switch params Timeout! use cached_channel [4294849.548000] signal_strength -3648.35dbm [4294849.557000] signal_strength -3648.35dbm [SEC] sendDiseqc: e00000(DiSEqC reset) [SEC] sleep 50ms child has terminated pipes closed child has terminated pipes closed 192.168 169.254 0.0.0.0 nameservers: [[192, 168, 178, 1]] read configured interface: {'lo': {'dhcp': False}, 'eth0': {'dhcp': True}} self.ifaces after loading: {'ath0': {'preup': False, 'predown': False, 'ip': [0, 0, 0, 0], 'up': False, 'mac': 'd8:5d:4c:eb:39:30', 'dhcp': True, 'netmask': [0, 0, 0, 0], 'gateway': [0, 0, 0, 0]}, 'eth0': {'preup': False, 'predown': False, 'ip': [192, 168, 178, 36], 'up': True, 'mac': '00:09:34:1c:b8:c5', 'dhcp': True, 'bcast': [192, 168, 178, 255], 'netmask': [2[4294849.797000] signal_strength -3657.28dbm 55, 255, 255, 0], 'gateway': [192, 168, 178, 1]}} poll: unhandled POLLERR/HUP/NVAL for fd 40(16) poll: unhandled POLLERR/HUP/NVAL for fd 41(16) [SEC] sendDiseqc: e00003(DiSEqC peripherial power on) [SEC] sleep 150ms [SEC] sendDiseqc: e01038f2 [SEC] sleep 50ms nr_read 699 nr_write 31 sum 730 prev_sum 730 hdd IDLE! [IDLE] 5.08754897118 120 False set sequence pos 3 set sequence pos 3 [SEC] update current switch params [SEC] startTuneTimeout 5000 [SEC] setFrontend 1 setting frontend 0 [SEC] sleep 500ms (0)fe event: status 0, inversion off, m_tuning 1 (0)fe event: status 1, inversion off, m_tuning 2 (0)fe event: status 0, inversion off, m_tuning 3 (0)fe event: status 1f, inversion off, m_tuning 4 OURSTATE: ok [eDVBCAService] channel 0x2d724340 running [eDVBLocalTimerHandler] channel 0x2d724340 running no version filtering 0014: 70 00 00 00 00 00 mask: fc 00 00 00 00 00 mode: 00 00 00 00 00 00 [eEPGCache] channel 0x2d724[4294850.531000] start pcr0 on dmx 0 pid:ff index 0 340 running stop release channe[4294850.538000] start audio on dmx 0 pid:103 l timer [EPGC] [4294850.543000] audio xpt start next update in 2[4294850.546000] sync is off so we enable it sec no version[4294850.551000] demux-index 0 pcr0pid ff filtering 0012[4294850.555000] using 0 as pcr0 pidchannel : 4e ef 74 00 0[4294850.559000] AC3 0 00 mask: ff [4294850.562000] audio: streamtype set 1 ff ff 00 00 00 [4294850.566000] audio: streamtype_set: stop rave mode: 00 00 00 [4294850.571000] passthru 00 00 00 ok ... now we start!! no version filtering 0000: 00 00 00 00 00 00 mask: ff 00 00 00 00 00 mode: 00 00 00 00 00 00 eventNewProgramInfo 0 0 ha[4294850.585000] audio: streamtype_set: restart rave ve 1 video strea[4294850.591000] set mute 0 (001) 0 m(s) (00ff), and[4294850.595000] audio: decoder start 0 1 audio stream(s) (0103), and the pcr pid is 00ff, and the text pid is 0020 allocate demux disable teletext subtitles decode[4294850.609000] video delay 0 (0 ms) r state: play, v[4294850.612000] total video delay: 0 (0 ms) pid=255, apid=25[4294850.617000] VIDEO0: set streamtype! 9 DMX_SET_PES_F[4294850.621000] set H264 ILTER(0xff) - pc[4294850.623000] sw rave disabled! r - ok DEMUX_ST[4294850.627000] video delay 0 (0 ms) ART - pcr - ok [4294850.631000] total video delay: 0 (0 ms) DMX_SET_PES_FILTER(0x103) - audi[4294850.636000] start video0 on dmx 0 pid:ff o - ok DEMUX_ST[4294850.641000] total video delay: 18000 (200 ms) ART - audio - ok AUDIO_SET_BYPA[4294850.647000] VIDEO0: start decode SS(0) - ok AUDIO_PAUSE - ok AUDIO_PLAY - ok Video Device: /dev/dvb/adapter0/video0 demux device: /dev/dvb/adapter0/demux0 VIDEO_SET_STREAMTYPE 1 - ok DMX_SET_PES_FILTER(0xff) - video - ok DEMUX_START -[4294850.668000] signal_strength -116.01dbm video - ok VIDEO_FREEZE - ok VIDEO_PLAY - ok DMX_SET_PES_FILTER(0x20) - ttx - ok DEMUX_START - ttx - ok VIDEO_SLOWMOTION(0) - ok VIDEO_FAST_FORWARD(0) - ok VIDEO_CONTINUE - ok AUDIO_CONTINUE - ok AUDIO_CHANNEL_SELECT(0) - ok not pauseable. [ePopen] command: ping -c 1 82.149.226.170 [ePopen] command: ping -c 1 193.99.144.85 [ePopen] command: ping -c 1 209.85.135.103 [4294850.818000] signal_strength -117.69dbm [SEC] set dynamic current limiting -+ 1/2 TID 4e + 1/1 TID 00 done! PATready use pmtpid 0060 for service_id ef74 no version filtering 0060: 02 ef 74 00 00 00 mask: ff ff ff 00 00 00 mode: 00 00 00 00 00 00 doing version filtering 0000: 00 00 00 2d 00 00 mask: ff 00 00 3f 00 00 mode: 00 00 00 3e 00 00 VIDEO_GET_EVENT - ok child has terminated pipes closed + 1/1 TID 02 done! eventNewProgramInfo 0 0 have 1 video stream(s) (00ff), and 1 audio stream(s) (0103), and the pcr pid is 00ff, and the [4294850.913000] signal_strength -117.69dbm text pid is 0020 decoder state: play, vpid=255, apid=259 [eDVBCAService] new service 1:0:19:EF74:3F9:1:C00000:0:0:0: [eDVBCAService] add demux 0 to slot 0 service 1:0:19:EF74:3F9:1:C00000:0:0:0: [eDVBCIInterfaces] gotPMT demux 0 mask 01 prevhash 00000000 [eDVBCAService] send 174 bytes 9f 80 32 81 a9 03 ef 74 03 00 8f 01 81 08 00 c0 00 00 03 f9 00 01 82 02 01 00 84 02 00 60 09 14 18 30 fa ea 86 0e 00 80 11 0f 9f 20 fc 01 80 11 0d 7a 20 fc 09 5c 18 43 f9 ea 86 0e 00 80 11 0f 9f 20 fc 01 80 11 0d 7a 20 fc 8c 46 00 00 43 8c 13 00 80 11 08 02 18 43 20 0a 09 38 59 00 0f 9f 59 00 0f 9f aa 15 03 80 11 5d 00 00 66 00 03 03 21 00 00 02 18 43 5d 00 00 66 00 aa 15 03 80 11 00 00 0b ea 00 03 03 21 00 00 02 18 43 5d 00 0b ea 00 09 06 09 c4 fb ea 00 00 06 00 20 00 00 1b 00 ff 00 00 06 01 03 00 00 05 01 05 00 00 doing version filtering 0060: 02 ef 74 03 00 00 mask: ff ff ff 3f 00 00 mode: 00 00 00 3e 00 00 VIDEO_GET_EVENT - ok poll: unhandled POLLERR/HUP/NVAL for fd 67(16) child has terminated pipes closed poll: unhandled POLLERR/HUP/NVAL for fd 70(16) ++ 2/2 TID 4e done! doing version filtering 0012: 4e ef 74 39 00 00 mask: ff ff ff 3f 00 00 mode: 00 00 00 3e 00 00 [eDVBLocalTimerHandler] diff is -2 [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time [eDVBLocalTimerHandler] update RTC [eDVBLocalTimerHandler] time update to 17:07:59 [eDVBLocalTimerHandler] m_time_difference is -2 [eDVBLocalTimerHandler] set Linux Time [4294851.554000] ch0: lock [4294851.556000] RAP first pts 0x14348e538, stc 0x1e207e108, pcr valid [4294851.582000] ch0: lock [4294851.616000] ch0: lock [4294851.644000] ch0: lock [4294851.730000] signal_strength -115.21dbm [4294851.743000] RAP sampling rate info isr [4294851.846000] signal_strength -118.85dbm sdt update done! use cached_channel [FanControl2] Fan Reset [EPGC] start caching events(1312556880) [FanControl2] Reread Timeout! [4294852.767000] signal_strength -118.86dbm [4294852.773000] signal_strength -118.86dbm [4294852.912000] signal_strength -118.98dbm [FanControl2] Fan Reset [FanControl2] Reread [4294853.109000] VIDEO0: first pts 0x1e20ac46c [4294853.113000] VIDEO0: resolution changed (1920 1080) VIDEO_GET_EVENT - ok [4294853.167000] signal_strength -119.42dbm [4294853.263000] enable tsm0 [FanControl2] Fan Reset [FanControl2] Vlt:255 Pwm:90 Fan:4pin - BoxOn HDDon [FanControl2] aktuellRP