00005.429123: libctn91xx: ctn91xx_i2c_read_write:172 WARNING: slave busy read_addr: 00.54 write_addr: 00.00 00005.444154: MxL241SF: Ctrl_InitI2C:27 : compiled on 2011-10-23 21:10:53.073010 00005.445422: MxL241SF: Ctrl_InitI2C:28 : git id 1b2388aa47737de5f3a2b522b0b9df81e7c3bc68 00005.455754: libcetontune: mxl241sf_cetontune_instance_probe:195 : MxL241SF demod instance 0 i2c 0000.00c4 00005.472231: libcetontune: mxl241sf_cetontune_instance_probe:195 : MxL241SF demod instance 1 i2c 0000.00c2 00005.477992: libcetontune: mxl241sf_cetontune_instance_probe:195 : MxL241SF demod instance 2 i2c 0000.00c6 00005.484276: libcetontune: mxl241sf_cetontune_instance_probe:195 : MxL241SF demod instance 3 i2c 0000.00c8 00005.486385: libctn91xx: ctn91xx_i2c_read_write:172 WARNING: slave busy read_addr: 00.ffff write_addr: 00.ce 00005.488478: libctn91xx: ctn91xx_i2c_read_write:172 WARNING: slave busy read_addr: 00.ffff write_addr: 00.ce 00005.491080: libctn91xx: ctn91xx_i2c_read_write:172 WARNING: slave busy read_addr: 00.ffff write_addr: 00.ce 00005.492293: libcetontune: mxl241sf_cetontune_instance_probe:185 WARNING: Could not find MxL241SF for instance 4 (00.CE) 00005.494329: libctn91xx: ctn91xx_i2c_read_write:172 WARNING: slave busy read_addr: 00.ffff write_addr: 00.ca 00005.496417: libctn91xx: ctn91xx_i2c_read_write:172 WARNING: slave busy read_addr: 00.ffff write_addr: 00.ca 00005.498501: libctn91xx: ctn91xx_i2c_read_write:172 WARNING: slave busy read_addr: 00.ffff write_addr: 00.ca 00005.499711: libcetontune: mxl241sf_cetontune_instance_probe:185 WARNING: Could not find MxL241SF for instance 5 (00.CA) 00005.503948: ocur: tuner_pre_init:382 WARNING: Could not open tuner calibration file 00005.509934: ocur: global_init:401 : Proceeding with 4 active instances 00005.531663: ocur: system_init:190 : Firmware Version: (1.1.0.14) 00005.539012: ocur: system_detect_network_interface:61 : detected pci 00005.544036: ocur: system_get_mac_address:137 : Mac Address: 00:22:2c:80:5f:8f 00005.546299: libctn91xx: ctn91xx_stop_watchdog:129 : SYSTEM_CONTROL_CODE_IDENTIFIER_OFFSET 0 00005.547656: libctn91xx: ctn91xx_stop_watchdog:130 : SYSTEM_CONTROL_TIMEOUT_INDICATOR_OFFSET 0 00005.548515: libctn91xx: ctn91xx_stop_watchdog:131 : SYSTEM_CONTROL_WATCHDOG_TIMEOUT_OFFSET 00000000 00005.563411: ocur: cas_firmware_init_boot_table:749 : Firmware image ceton_monaco_prod_v1.IMAGE 00005.596528: ocur: cas_firmware_init_boot_table:819 : Firmware upgrade state "done" 00005.597569: ocur: cas_firmware_init:1022 : Watchdog was not set, normal boot 00005.598361: ocur: cas_firmware_init:1025 : Initial power on 00005.599114: ocur: cas_firmware_init:1060 : Factory appears to be the only image available. 00005.599877: ocur: cas_firmware_init:1064 : We will continue with the FACTORY image, checking upgrade state 00005.601393: ocur: cas_firmware_init:1145 : Resetting upgrade state from done to done 00005.602659: ocur: cas_write_upgrade_state:2415 : Writing firmware state: done 00005.784331: ocur: slot_number_callback:463 : slot_number: 0 00006.093363: ocur: sysinit_restart_network:256 : default 1 dhcp 0 static 0 ip 192.168.200.1 00006.104413: ocur: sysinit_restart_network:318 : ifconfig ctn0 192.168.200.1 00006.742597: mpeg: cetonmpeg_init:45 : compiled on 2011-10-23 21:10:53.303647 00006.743891: mpeg: cetonmpeg_init:46 : git id 29d90bf2eaf28ffc3367cb461b453346d7f71907 00006.818909: ocur: cas_RouteIntoCard:195 : Card routing 0 -> 1 on 0 00006.821142: ocur: cas_RouteIntoCard:195 : Card routing 0 -> 1 on 1 00006.822405: ocur: cas_RouteIntoCard:195 : Card routing 0 -> 1 on 2 00006.823664: ocur: cas_RouteIntoCard:195 : Card routing 0 -> 1 on 3 00006.835267: cyrano: [zdtv/logger:WARN] all systems go 00006.845267: cyrano: [zdtv/alarm:WARN] initialization completed 00006.860879: cyrano: Unable to open /ceton/ro/cablecard/host_CET_prod.ccc 00006.877183: cyrano: hal_zccard_setup:353 : Got generalized host file 00006.879892: cyrano: Unable to open /ceton/ro/cablecard/mfg_CET_prod.ccc 00006.898939: cyrano: hal_zccard_setup:362 : Got generalized mfg file 00006.945817: cyrano: [zccard/ccli:WARN] task started: 560B6D80 00007.023271: cyrano: [zccard/t:INFO] initialization completed 00007.033328: cyrano: [zccard/s:INFO] initialization completed 00007.078824: cyrano: [zccard/a:INFO] retrieve auth state 00007.129327: cyrano: [zccard/oobsi:WARN] task started: 580B6D80 00007.133919: cyrano: [zccard/a:INFO] initialization completed 00007.152486: cyrano: [zatsc:WARN]all systems go 00007.341651: ocur: DeviceStart:3422 : Initializing UPnP Sdk with ipaddress = "192.168.200.1" port = 80 00008.343793: ocur: EraseDevices:3263 WARNING: Removing instance 4 from announcement (pos 4). 00008.354393: ocur: EraseDevices:3263 WARNING: Removing instance 5 from announcement (pos 4). 00008.364889: ocur: EraseDevices:3263 WARNING: Removing instance 8 from announcement (pos 6). 00008.423600: ocur: UpdateUDNTable:3167 : UDN: uuid:89333102-EBE5-11D8-AC9A-00000805F8F1 00008.424784: ocur: UpdateUDNTable:3167 : UDN: uuid:89333102-EBE5-11D8-AC9A-00000805F8F2 00008.425943: ocur: UpdateUDNTable:3167 : UDN: uuid:89333102-EBE5-11D8-AC9A-00000805F8F3 00008.427120: ocur: UpdateUDNTable:3167 : UDN: uuid:89333102-EBE5-11D8-AC9A-00000805F8F4 00008.428289: ocur: UpdateUDNTable:3167 : UDN: uuid:89333102-EBE5-11D8-AC9A-00000805F8F5 00008.429460: ocur: UpdateUDNTable:3167 : UDN: uuid:89333102-EBE5-11D8-AC9A-00000805F8F6 00008.431232: ocur: UpdateUDNTable:3173 : OCTA UDN: uuid:89333102-EBE5-11D8-AC9A-00000805F8F7 00008.432437: ocur: UpdateUDNTable:3173 : OCTA UDN: uuid:89333102-EBE5-11D8-AC9A-00000805F8F8 00008.433692: ocur: UpdateUDNTable:3173 : OCTA UDN: uuid:89333102-EBE5-11D8-AC9A-00000805F8F9 00008.434932: ocur: UpdateUDNTable:3178 : Container UDN: uuid:89333102-EBE5-11D8-AC9A-00000805F8F0 00009.450760: ocur: DeviceStart:3473 : RootDevice Registered device_handle: 1 00009.451783: ocur: DeviceStart:3492 : UPnP Initialized ipaddress = "192.168.200.1" port = 80 00009.452782: ocur: DeviceStart:3503 : Specifying the webserver root directory -- ./web 00010.591952: ocur: DeviceHandleSubscriptionRequest:582 : Got first subscription 00010.615176: ocur: DeviceStart:3543 : Advertisements Sent for device urn:schemas-upnp-org:device:MediaServer:1 00010.773890: ocur: UpnpAdvertiseUntilSubscribed:3363 : Sending rapid advertise 00010.855405: ocur: finish_boot_process:191 : Done Booting. Took 00010.855211 seconds. Took 00005.332881 in server. 00010.858979: ocur: debug_WriteStampFile:141 : STT time Sun Jan 6 00:00:18 1980 UTC 00010.862808: libupnp: genaNotifyThread:480 ERROR: Event dropped because genaNotify failed (-303) 00012.292985: libctn91xx: ctn91xx_event_card_inserted:222 : got card inserted interrupt 00012.293803: libctn91xx: ctn91xx_event_card_inserted:223 : origin: 0, card_type: 41 00012.294705: ocur: card_inserted_callback:1251 : Insert -------------------------------------- 00012.299393: ocur: Event(cas[0]): CardStatus, "Inserted" 00012.303313: cyrano: [zccard/ccli:INFO] mcard inserted 00012.309000: ocur: fdc_reference_flow:381 : Flow for pid 0x1ffc refs 1 result 1 00012.313762: cyrano: [zccard/ccli:INFO] Clearing Queue 00012.324180: ocur: cas_hal_hal_pcmcia_reset_posted:2042 : Card reset 00012.436599: cyrano: pcmcia Reset 00012.444241: cyrano: [zccard/s:INFO] Session card mode 2, was 0 00012.447696: ocur: Event(cas[1]): CardStatus, "Inserted" 00012.448950: ocur: fdc_reference_flow:381 : Flow for pid 0x1ffc refs 2 result 1 00012.493618: ocur: Event(cas[2]): CardStatus, "Inserted" 00012.494877: ocur: fdc_reference_flow:381 : Flow for pid 0x1ffc refs 3 result 1 00012.497796: ocur: Event(cas[3]): CardStatus, "Inserted" 00012.499051: ocur: fdc_reference_flow:381 : Flow for pid 0x1ffc refs 4 result 1 00012.541299: ocur: cas_SetCardMessage:958 : SetCardMessage = (null) 00012.543896: ocur: Event(cas[0]): CardMessage, "" 00012.546192: ocur: Event(cas[1]): CardMessage, "" 00012.548565: ocur: Event(cas[2]): CardMessage, "" 00012.682572: ocur: Event(cas[3]): CardMessage, "" 00012.703624: ocur: cas_hal_hal_pcmcia_reset_done_posted:2058 : Card reset done 00012.704497: ocur: cas_SetCardMessage:958 : SetCardMessage = (null) 00012.707050: ocur: Event(cas[0]): CardMessage, "" 00012.709985: ocur: Event(cas[1]): CardMessage, "" 00012.747677: ocur: Event(cas[2]): CardMessage, "" 00012.852495: ocur: Event(cas[3]): CardMessage, "" 00016.979322: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00010041 00016.982805: cyrano: [zccard/s:INFO] Opened Resource Manager(1) 00017.132222: cyrano: [zccard/a:INFO] -> {profile_inq} 00017.284711: cyrano: [zccard/s:INFO] SPDU - session_number(): 0001 00017.293685: cyrano: [zccard/a:INFO] <- {profile_reply} 00017.296084: cyrano: [zccard/a:INFO] <- Resource Manager(1,1,1) 00017.298498: cyrano: [zccard/a:INFO] <- Resource Manager(2,2,2) 00017.301743: cyrano: [zccard/a:INFO] <- System Time(36,1,1) 00017.304105: cyrano: [zccard/a:INFO] <- MMI(64,2,1) 00017.306467: cyrano: [zccard/a:INFO] <- Homing(17,1,2) 00017.308858: cyrano: [zccard/a:INFO] <- Homing(144,1,2) 00017.442186: cyrano: [zccard/a:INFO] <- Generic Feature Control(42,1,4) 00017.444633: cyrano: [zccard/a:INFO] <- Generic Feature Control(160,1,6) 00017.447031: cyrano: [zccard/a:INFO] <- Conditional Access Support(3,2,1) 00017.449413: cyrano: [zccard/a:INFO] <- Host Control(32,2,1) 00017.582756: cyrano: [zccard/a:INFO] <- Copy Protection(176,4,4) 00017.585161: cyrano: [zccard/a:INFO] <- Copy Protection(260,2,2) 00017.587550: cyrano: [zccard/a:INFO] <- Copy Protection(43,1,1) 00017.589948: cyrano: [zccard/a:INFO] <- System Control(43,2,1) 00017.643373: cyrano: [zccard/a:INFO] <- System Control(4,1,1) 00017.645532: cyrano: [zccard/a:INFO] <- private:c0110101 00017.647696: cyrano: [zccard/a:INFO] <- private:c0110102 00017.649859: cyrano: [zccard/a:INFO] <- private:c0110103 00017.733324: cyrano: [zccard/a:INFO] <- Card Resource(38,3,1) 00017.735724: cyrano: [zccard/a:INFO] <- Headend Communication(44,1,1) 00017.738151: cyrano: [zccard/a:INFO] <- Headend Communication(256,1,1) 00017.801521: cyrano: [zccard/a:INFO] <- Headend Communication(90,1,1) 00017.803620: cyrano: [zccard/a:INFO] <- {/profile_reply} 00017.805749: cyrano: [zccard/a:INFO] -> {profile_changed} 00017.836994: cyrano: [zccard/s:INFO] SPDU - session_number(): 0001 00017.904439: cyrano: [zccard/a:INFO] <- {profile_inq} 00017.907076: cyrano: [zccard/a:INFO] -> {profile_reply} 00017.909547: cyrano: [zccard/a:INFO] -> Resource Manager(1,1,1) 00017.933052: cyrano: [zccard/a:INFO] -> Application Info(2,2,1) 00017.935528: cyrano: [zccard/a:INFO] -> Conditional Access Support(3,2,1) 00017.937977: cyrano: [zccard/a:INFO] -> Host Control(32,2,1) 00018.091815: cyrano: [zccard/a:INFO] -> System Time(36,1,1) 00018.094297: cyrano: [zccard/a:INFO] -> MMI(64,2,1) 00018.096713: cyrano: [zccard/a:INFO] -> Homing(17,1,2) 00018.099134: cyrano: [zccard/a:INFO] -> Copy Protection(176,4,3) 00018.167912: cyrano: [zccard/a:INFO] -> Copy Protection(176,4,4) 00018.251958: cyrano: [zccard/a:INFO] -> Generic Feature Control(42,1,4) 00018.254527: cyrano: [zccard/a:INFO] -> Headend Communication(44,1,1) 00018.257012: cyrano: [zccard/a:INFO] -> Extended Channel Support(160,1,1) 00018.259532: cyrano: [zccard/a:INFO] -> Generic Diagnostic Support(260,2,1) 00018.303086: cyrano: [zccard/a:INFO] -> System Control(43,2,1) 00018.305599: cyrano: [zccard/a:INFO] -> Card Resource(38,3,1) 00018.307711: cyrano: [zccard/a:INFO] -> {/profile_reply} 00018.361296: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00020081 00018.363450: cyrano: [zccard/s:INFO] Opened Application Info(3) 00018.419766: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 002600c1 00018.423946: cyrano: [zccard/s:INFO] Opened Card Resource(16) 00018.455025: cyrano: [zccard/a:INFO] -> {ai_req} 00018.457346: cyrano: [zccard/a:INFO] -> DisplayRows = 40 00018.459624: cyrano: [zccard/a:INFO] -> DisplayColumns = 80 00018.476492: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00030081 00018.483883: cyrano: [zccard/s:INFO] Opened Conditional Access Support(5) 00018.488426: cyrano: [zccard/a:INFO] -> Vertical_scrolling = 0 00018.496107: cyrano: [zccard/s:INFO] SPDU - session_number(): 0003 00018.498738: cyrano: [zccard/a:INFO] -> Horizonal_scrolling = 0 00018.505991: cyrano: [zccard/s:INFO] SPDU - session_number(): 0003 00018.515536: cyrano: [zccard/s:INFO] SPDU - session_number(): 0003 00018.582506: cyrano: [zccard/a:INFO] -> Display_type_support = 0 00018.584821: cyrano: [zccard/a:INFO] -> Data_entry_support = 0 00018.587101: cyrano: [zccard/a:INFO] -> HTML_support = 0 00018.589365: cyrano: [zccard/a:INFO] -> Link_support = 0 00018.622611: cyrano: [zccard/a:INFO] -> Form_support = 0 00018.624913: cyrano: [zccard/a:INFO] -> Table_support = 0 00018.627179: cyrano: [zccard/a:INFO] -> List_support = 0 00018.629446: cyrano: [zccard/a:INFO] -> Image_support = 0 00018.679741: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00240041 00018.685021: cyrano: [zccard/s:INFO] Opened System Time(14) 00018.695921: cyrano: [zccard/a:INFO] -> {/ai_req} 00018.746564: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 002a0044 00018.748760: cyrano: [zccard/s:INFO] Opened Generic Feature Control(11) 00018.756098: cyrano: [zccard/a:INFO] -> {ca_info_inq} 00018.764470: cyrano: [zccard/a:INFO] <- {cr_stream_profile} 00018.766808: cyrano: [zccard/a:INFO] <- max_number_of_streams = 6 00018.768864: cyrano: [zccard/a:INFO] <- {/cr_stream_profile} 00018.776225: cyrano: [zccard/s:INFO] SPDU - session_number(): 0005 00018.795552: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00018.814952: cyrano: [zccard/a:INFO] -> {cr_stream_profile_cnf} 00018.817333: cyrano: [zccard/a:INFO] -> number_of_streams_used = 4 00018.819419: cyrano: [zccard/a:INFO] -> {/cr_stream_profile_cnf} 00018.873882: cyrano: [zccard/a:INFO] <- {cr_program_profile} 00018.876201: cyrano: [zccard/a:INFO] <- max_number_of_programs = 6 00018.878252: cyrano: [zccard/a:INFO] <- {/cr_program_profile} 00018.885775: cyrano: [zccard/a:INFO] -> {cr_program_profile_cnf} 00018.903853: cyrano: [zccard/a:INFO] <- {cr_es_profile} 00018.906166: cyrano: [zccard/a:INFO] <- max_number_of_es = 120 00018.908212: cyrano: [zccard/a:INFO] <- {/cr_es_profile} 00018.924828: cyrano: [zccard/a:INFO] -> {cr_es_profile_cnf} 00019.024216: cyrano: [zccard/a:INFO] <- {system_time_inq} 00019.026786: cyrano: [zccard/a:INFO] -> {system_time} 00019.029346: cyrano: [zccard/a:INFO] -> system_time = 00000013 "Sun Jan 6 00:00:27 1980 UTC" 00019.032471: cyrano: [zccard/a:INFO] -> GPS_UTC_offset = 00 00019.034495: cyrano: [zccard/a:INFO] -> {/system_time} 00019.055946: cyrano: [zccard/a:INFO] <- {ai_cnf} 00019.058359: cyrano: [zccard/a:INFO] <- pod_manufacturer_id = Cisco (Scientific-Atlanta)(0x103) 00019.061529: cyrano: [zccard/a:INFO] <- pod_version_number = 1 00019.063588: cyrano: [zccard/a:INFO] <- {application} 00019.065859: cyrano: [zccard/a:INFO] <- type = Conditional Access 00019.068110: cyrano: [zccard/a:INFO] <- version_number = 1 00019.071243: cyrano: [zccard/a:INFO] <- name = CableCARD CA Screen 00019.073565: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/CaApp.html 00019.075606: cyrano: [zccard/a:INFO] <- {/application} 00019.077648: cyrano: [zccard/a:INFO] <- {application} 00019.079930: cyrano: [zccard/a:INFO] <- type = CableCard Pairing information (HOST_ID,POD_ID) 00019.103151: cyrano: [zccard/a:INFO] <- version_number = 1 00019.105468: cyrano: [zccard/a:INFO] <- name = CableCARD/Host ID Screen 00019.107820: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/CpDiag.html 00019.109864: cyrano: [zccard/a:INFO] <- {/application} 00019.132923: cyrano: [zccard/a:INFO] <- {application} 00019.135186: cyrano: [zccard/a:INFO] <- type = IP Service 00019.137440: cyrano: [zccard/a:INFO] <- version_number = 1 00019.139728: cyrano: [zccard/a:INFO] <- name = CableCARD IP Service 00019.163303: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/IPInfo.html 00019.165358: cyrano: [zccard/a:INFO] <- {/application} 00019.167418: cyrano: [zccard/a:INFO] <- {application} 00019.169733: cyrano: [zccard/a:INFO] <- type = Network Interface - SCTE 55-2 00019.193045: cyrano: [zccard/a:INFO] <- version_number = 1 00019.195385: cyrano: [zccard/a:INFO] <- name = CableCARD DAVIC Info 00019.198232: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/DavicInfo.html 00019.221362: cyrano: [zccard/a:INFO] <- {/application} 00019.223504: cyrano: [zccard/a:INFO] <- {application} 00019.225804: cyrano: [zccard/a:INFO] <- type = Copy Protection 00019.228090: cyrano: [zccard/a:INFO] <- version_number = 1 00019.251463: cyrano: [zccard/a:INFO] <- name = CableCARD CP Info 00019.253885: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/CpInfo.html 00019.255950: cyrano: [zccard/a:INFO] <- {/application} 00019.258045: cyrano: [zccard/a:INFO] <- {application} 00019.291865: cyrano: [zccard/a:INFO] <- type = Diagnostic 00019.294221: cyrano: [zccard/a:INFO] <- version_number = 1 00019.296535: cyrano: [zccard/a:INFO] <- name = CableCARD Diag Screen 00019.298889: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/diag.html 00019.331796: cyrano: [zccard/a:INFO] <- {/application} 00019.333915: cyrano: [zccard/a:INFO] <- {application} 00019.336220: cyrano: [zccard/a:INFO] <- type = Unknown 00019.338506: cyrano: [zccard/a:INFO] <- version_number = 1 00019.361751: cyrano: [zccard/a:INFO] <- name = CableCARD DSG Info 00019.364146: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/DsgInfo.html 00019.366200: cyrano: [zccard/a:INFO] <- {/application} 00019.368269: cyrano: [zccard/a:INFO] <- {application} 00019.391765: cyrano: [zccard/a:INFO] <- type = Unknown 00019.394121: cyrano: [zccard/a:INFO] <- version_number = 1 00019.396434: cyrano: [zccard/a:INFO] <- name = CableCARD CANH Screen 00019.398796: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/CANHandlerDiag.html 00019.422008: cyrano: [zccard/a:INFO] <- {/application} 00019.424078: cyrano: [zccard/a:INFO] <- {/ai_cnf} 00022.873755: ocur: [192.168.200.2] Get(av[0]): AVTransportURI "rtsp://192.168.200.1:8554/cetonmpeg0" 00023.512212: ocur: avtransport_rtsp_setup_callback:320 : [0] rtp setup for client 192.168.200.2:5001 00023.705976: ocur: avtransport_rtsp_teardown_callback:354 : [0] rtp teardown for client 192.168.200.2:5001 00024.312858: libctn91xx: ctn91xx_event_error:31 ERROR: type: "MCARD Reported Error" d7 origin: 00 control_byte: 00 seqno: 00 00024.315664: cyrano: error_report error_type:215 origin:0 00024.319098: ocur: fdc_NotifyFlowStatusUpdate:799 : available 0 flow_id 00000000 pid 0000 00024.323827: cyrano: [zccard/t:INFO] transport has been stopped. 00024.327529: cyrano: [zccard/s:WARN] skipping session close: 1 00024.337083: cyrano: [zccard/s:WARN] skipping session close: 2 00024.339459: cyrano: [zccard/s:WARN] skipping session close: 3 00024.344684: cyrano: [zccard/s:WARN] skipping session close: 4 00024.347059: cyrano: [zccard/s:WARN] skipping session close: 5 00024.349430: cyrano: [zccard/s:WARN] skipping session close: 6 00024.354847: ocur: fdc_NotifyFlowStatusUpdate:806 : All flows closed 00024.359876: cyrano: [zccard/oobsi:INFO] OOB MPEG FLOW disabled 00024.666526: ocur: [192.168.200.2] Get(av[1]): AVTransportURI "rtsp://192.168.200.1:8554/cetonmpeg1" 00024.672390: ocur: [192.168.200.2] Get(av[2]): AVTransportURI "rtsp://192.168.200.1:8554/cetonmpeg2" 00024.972522: cyrano: [zccard/a:INFO] -> {server_query} 00024.974842: cyrano: [zccard/a:INFO] -> transaction_number = 0 00024.977166: cyrano: [zccard/a:INFO] -> header = (null) 00024.979509: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00024.983487: cyrano: [zccard/a:INFO] -> {/server_query} 00024.991997: cyrano: [zccard/s:WARN] failed to get session_nb: 3/-1 00025.249137: ocur: [192.168.200.2] Get(fdc[0]): CarrierLock "0" 00025.647532: ocur: [192.168.200.2] Calling Action(aux[0]) GetAuxCapabilities 00025.649613: ocur: [192.168.200.2] Action(aux[0]) GetAuxCapabilities success 00026.093727: ocur: [192.168.200.2] Get(fdc[0]): CarrierLock "0" 00026.479140: ocur: [192.168.200.2] Calling Action(wmdrm[0]) SetRevInfo 00026.525358: ocur: [192.168.200.2] Get(av[3]): AVTransportURI "rtsp://192.168.200.1:8554/cetonmpeg3" 00027.670997: libctn91xx: wait_for_request_done:173 WARNING: request timed out. destination 10 seqno 0f 00027.675272: libctn91xx: ctn91xx_message_send:178 ERROR: rpc msg send timed out 00027.676606: libctn91xx: ctn91xx_rpc_send:306 ERROR: failed to send rpc message 00027.677526: ocur: avtransport_rtsp_setup_callback:320 : [2] rtp setup for client 192.168.200.2:5001 00028.271777: ocur: wmdrm_post_init:651 : WMDRM is "Ready" 00028.575904: libcetontune: mxl241sf_cetontune_instance_init:330 : MxL241SF initialized 00028.665980: libcetontune: mxl241sf_cetontune_instance_init:330 : MxL241SF initialized 00028.755649: libcetontune: mxl241sf_cetontune_instance_init:330 : MxL241SF initialized 00028.805599: libcetontune: mxl241sf_cetontune_instance_init:330 : MxL241SF initialized 00028.865666: libcetontune: mxl241sf_cetontune_oob_init:419 : Found demod with OOB capabilities 00029.012189: ocur: cas_hal_dri_error:1779 WARNING: Card Error State - error 38 occurances 1 00029.017071: cyrano: [zccard/card:ERROR] zapi/ccard/trunk/src/card/zccard_card_cchi.c:118 Skipping zccard_card_reset 00029.135528: ocur: [192.168.200.2] Action(wmdrm[0]) SetRevInfo success 00029.208984: ocur: [192.168.200.2] Calling Action(wmdrm[0]) SetCRL 00029.443707: ocur: [192.168.200.2] Action(wmdrm[0]) SetCRL success 00029.505064: ocur: [192.168.200.2] Calling Action(aux[0]) GetAuxCapabilities 00029.507173: ocur: [192.168.200.2] Action(aux[0]) GetAuxCapabilities success 00029.648520: ocur: [192.168.200.2] Calling Action(wmdrm[0]) ProcessRegistrationChallenge 00029.730995: libctn91xx: wait_for_request_done:173 WARNING: request timed out. destination 10 seqno 10 00029.732249: libctn91xx: ctn91xx_message_send:178 ERROR: rpc msg send timed out 00029.733138: libctn91xx: ctn91xx_rpc_send:306 ERROR: failed to send rpc message 00029.734052: ocur: avtransport_rtsp_setup_callback:320 : [1] rtp setup for client 192.168.200.2:5001 00031.891049: libctn91xx: wait_for_request_done:173 WARNING: request timed out. destination 10 seqno 11 00031.892308: libctn91xx: ctn91xx_message_send:178 ERROR: rpc msg send timed out 00031.893194: libctn91xx: ctn91xx_rpc_send:306 ERROR: failed to send rpc message 00031.894103: ocur: avtransport_rtsp_setup_callback:320 : [3] rtp setup for client 192.168.200.2:5001 00031.976220: ocur: [192.168.200.2] Get(fdc[2]): CarrierLock "0" 00032.033702: ocur: [192.168.200.2] Calling Action(aux[2]) GetAuxCapabilities 00032.035711: ocur: [192.168.200.2] Action(aux[2]) GetAuxCapabilities success 00032.701463: ocur: cas_hal_ServerQuery:3646 WARNING: server query already in progress 00032.702298: ocur: cas_card_watchdog:456 WARNING: CableCARD watchdog query failed 00033.126158: ocur: [192.168.200.2] Get(fdc[2]): CarrierLock "0" 00033.214838: ocur: [192.168.200.2] Calling Action(wmdrm[2]) SetRevInfo 00033.703007: ocur: [192.168.200.2] Action(wmdrm[2]) SetRevInfo success 00033.795769: ocur: [192.168.200.2] Calling Action(wmdrm[2]) SetCRL 00033.842544: ocur: wmdrm_ProcessRegistrationChallenge_impl:1712 : [0.0] We registered 00033.844599: ocur: [192.168.200.2] Action(wmdrm[0]) ProcessRegistrationChallenge success 00033.851464: libctn91xx: wait_for_request_done:173 WARNING: request timed out. destination 00 seqno 0c 00033.854310: cyrano: [zccard/ccli:INFO] zapi/ccard/trunk/src/ccli/zccard_ccli_mcard.c:129 CommErr at 67 00033.856286: cyrano: [zccard/ccli:ERROR] zccard_ccli_setErr(51) 00033.857605: ocur: cas_hal_dri_error:1793 WARNING: Z_CCARD_CCLI_ERR_WRITE_ERROR 00033.862229: cyrano: [zccard/card:ERROR] zapi/ccard/trunk/src/card/zccard_card_cchi.c:118 Skipping zccard_card_reset 00033.872938: cyrano: [zccard/ccli:INFO] Clearing Queue 00033.874845: cyrano: [zccard/ccli:INFO] Clearing LPDU from queue 00033.876818: cyrano: [zccard/ccli:INFO] Clearing LPDU from queue 00033.878808: cyrano: [zccard/ccli:INFO] Clearing SEND_PACKET from queue 00033.883022: cyrano: [zccard/ccli:INFO] Clearing SEND_PACKET from queue 00033.885076: cyrano: [zccard/ccli:INFO] Clearing SEND_PACKET from queue 00033.887098: cyrano: [zccard/ccli:INFO] Clearing SEND_PACKET from queue 00033.889098: cyrano: [zccard/ccli:INFO] Clearing LPDU from queue 00033.895246: ocur: cas_hal_hal_pcmcia_reset_posted:2042 : Card reset 00034.012158: cyrano: pcmcia Reset 00034.019169: cyrano: [zccard/s:INFO] Session card mode 2, was 0 00034.025149: ocur: cas_hal_hal_pcmcia_reset_done_posted:2058 : Card reset done 00034.026007: ocur: cas_SetCardMessage:958 : SetCardMessage = (null) 00034.029642: ocur: Event(cas[0]): CardMessage, "" 00034.047952: ocur: avtransport_rtsp_teardown_callback:354 : [2] rtp teardown for client 192.168.200.2:5001 00034.054072: cyrano: [zccard/ccli:ERROR] zapi/ccard/trunk/src/ccli/zccard_ccli.c:350 Cannot create flow 0:1 00034.061130: cyrano: [zccard/a:FATAL] overlapping timeouts 11, 38 00034.082831: ocur: Event(cas[1]): CardMessage, "" 00034.085496: ocur: Event(cas[2]): CardMessage, "" 00034.088286: ocur: Event(cas[3]): CardMessage, "" 00034.157256: ocur: [192.168.200.2] Get(fdc[1]): CarrierLock "0" 00034.174497: ocur: avtransport_rtsp_teardown_callback:354 : [1] rtp teardown for client 192.168.200.2:5001 00034.238548: cyrano: [zccard/a:FATAL] overlapping timeouts 11, 38 00034.256580: ocur: [192.168.200.2] Get(fdc[3]): CarrierLock "0" 00034.288680: ocur: avtransport_rtsp_teardown_callback:354 : [3] rtp teardown for client 192.168.200.2:5001 00034.358416: ocur: [192.168.200.2] Calling Action(aux[3]) GetAuxCapabilities 00034.371388: ocur: [192.168.200.2] Action(aux[3]) GetAuxCapabilities success 00034.496780: ocur: [192.168.200.2] Calling Action(aux[1]) GetAuxCapabilities 00034.498694: ocur: [192.168.200.2] Action(aux[1]) GetAuxCapabilities success 00034.761467: ocur: [192.168.200.2] Get(fdc[3]): CarrierLock "0" 00034.812775: ocur: [192.168.200.2] Action(wmdrm[2]) SetCRL success 00034.844898: ocur: [192.168.200.2] Get(fdc[1]): CarrierLock "0" 00034.916445: ocur: [192.168.200.2] Calling Action(wmdrm[3]) SetRevInfo 00034.991005: ocur: cas_hal_ServerQuery:3688 WARNING: server query timed out 00035.032426: cyrano: [zccard/a:INFO] -> {server_query} 00035.034714: cyrano: [zccard/a:INFO] -> transaction_number = 0 00035.037000: cyrano: [zccard/a:INFO] -> header = (null) 00035.039320: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00035.046252: cyrano: [zccard/a:INFO] -> {/server_query} 00035.065533: cyrano: [zccard/s:WARN] failed to get session_nb: 3/-1 00035.225585: ocur: [192.168.200.2] Action(wmdrm[3]) SetRevInfo success 00035.369876: ocur: [192.168.200.2] Calling Action(aux[2]) GetAuxCapabilities 00035.372581: ocur: [192.168.200.2] Action(aux[2]) GetAuxCapabilities success 00035.404396: ocur: [192.168.200.2] Get(fdc[0]): CarrierLock "0" 00035.508659: ocur: [192.168.200.2] Calling Action(wmdrm[1]) SetRevInfo 00035.517978: ocur: [192.168.200.2] Calling Action(wmdrm[3]) SetCRL 00036.298142: ocur: [192.168.200.2] Action(wmdrm[3]) SetCRL success 00036.336874: ocur: [192.168.200.2] Action(wmdrm[1]) SetRevInfo success 00037.058030: ocur: [192.168.200.2] Calling Action(aux[3]) GetAuxCapabilities 00037.063196: ocur: [192.168.200.2] Calling Action(wmdrm[1]) SetCRL 00037.073253: ocur: [192.168.200.2] Calling Action(wmdrm[2]) ProcessRegistrationChallenge 00037.113471: ocur: Event(security[0]): DrmPairingStatus, "Green" 00037.121982: ocur: [192.168.200.2] Action(aux[3]) GetAuxCapabilities success 00037.309153: ocur: [192.168.200.2] Calling Action(wmdrm[0]) ProcessLicenseChallenge 00038.072039: ocur: [192.168.200.2] Action(wmdrm[1]) SetCRL success 00038.581820: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00010041 00038.583956: cyrano: [zccard/s:INFO] Opened Resource Manager(1) 00038.623295: cyrano: [zccard/a:INFO] -> {profile_inq} 00038.656868: cyrano: [zccard/s:INFO] SPDU - session_number(): 0001 00038.663238: cyrano: [zccard/a:INFO] <- {profile_reply} 00038.665634: cyrano: [zccard/a:INFO] <- Resource Manager(1,1,1) 00038.668051: cyrano: [zccard/a:INFO] <- Resource Manager(2,2,2) 00038.671277: cyrano: [zccard/a:INFO] <- System Time(36,1,1) 00038.673634: cyrano: [zccard/a:INFO] <- MMI(64,2,1) 00038.675994: cyrano: [zccard/a:INFO] <- Homing(17,1,2) 00038.678383: cyrano: [zccard/a:INFO] <- Homing(144,1,2) 00038.691814: cyrano: [zccard/a:INFO] <- Generic Feature Control(42,1,4) 00038.694741: cyrano: [zccard/a:INFO] <- Generic Feature Control(160,1,6) 00038.697137: cyrano: [zccard/a:INFO] <- Conditional Access Support(3,2,1) 00038.699516: cyrano: [zccard/a:INFO] <- Host Control(32,2,1) 00038.722821: cyrano: [zccard/a:INFO] <- Copy Protection(176,4,4) 00038.725213: cyrano: [zccard/a:INFO] <- Copy Protection(260,2,2) 00038.727597: cyrano: [zccard/a:INFO] <- Copy Protection(43,1,1) 00038.729990: cyrano: [zccard/a:INFO] <- System Control(43,2,1) 00038.753282: cyrano: [zccard/a:INFO] <- System Control(4,1,1) 00038.755440: cyrano: [zccard/a:INFO] <- private:c0110101 00038.757602: cyrano: [zccard/a:INFO] <- private:c0110102 00038.759764: cyrano: [zccard/a:INFO] <- private:c0110103 00038.783193: cyrano: [zccard/a:INFO] <- Card Resource(38,3,1) 00038.785583: cyrano: [zccard/a:INFO] <- Headend Communication(44,1,1) 00038.788002: cyrano: [zccard/a:INFO] <- Headend Communication(256,1,1) 00038.811368: cyrano: [zccard/a:INFO] <- Headend Communication(90,1,1) 00038.813473: cyrano: [zccard/a:INFO] <- {/profile_reply} 00038.815606: cyrano: [zccard/a:INFO] -> {profile_changed} 00038.846753: cyrano: [zccard/s:INFO] SPDU - session_number(): 0001 00038.863807: cyrano: [zccard/a:INFO] <- {profile_inq} 00038.866468: cyrano: [zccard/a:INFO] -> {profile_reply} 00038.868956: cyrano: [zccard/a:INFO] -> Resource Manager(1,1,1) 00038.872268: cyrano: [zccard/a:INFO] -> Application Info(2,2,1) 00038.874736: cyrano: [zccard/a:INFO] -> Conditional Access Support(3,2,1) 00038.877175: cyrano: [zccard/a:INFO] -> Host Control(32,2,1) 00038.879632: cyrano: [zccard/a:INFO] -> System Time(36,1,1) 00038.882951: cyrano: [zccard/a:INFO] -> MMI(64,2,1) 00038.885394: cyrano: [zccard/a:INFO] -> Homing(17,1,2) 00038.887841: cyrano: [zccard/a:INFO] -> Copy Protection(176,4,3) 00038.911200: cyrano: [zccard/a:INFO] -> Copy Protection(176,4,4) 00038.913775: cyrano: [zccard/a:INFO] -> Generic Feature Control(42,1,4) 00038.916285: cyrano: [zccard/a:INFO] -> Headend Communication(44,1,1) 00038.918769: cyrano: [zccard/a:INFO] -> Extended Channel Support(160,1,1) 00038.942172: cyrano: [zccard/a:INFO] -> Generic Diagnostic Support(260,2,1) 00038.944700: cyrano: [zccard/a:INFO] -> System Control(43,2,1) 00038.947204: cyrano: [zccard/a:INFO] -> Card Resource(38,3,1) 00038.949307: cyrano: [zccard/a:INFO] -> {/profile_reply} 00039.021525: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00020081 00039.023655: cyrano: [zccard/s:INFO] Opened Application Info(3) 00039.063345: cyrano: [zccard/a:INFO] -> {ai_req} 00039.065651: cyrano: [zccard/a:INFO] -> DisplayRows = 40 00039.067903: cyrano: [zccard/a:INFO] -> DisplayColumns = 80 00039.076553: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 002600c1 00039.078741: cyrano: [zccard/s:INFO] Opened Card Resource(16) 00039.088096: cyrano: [zccard/a:INFO] -> Vertical_scrolling = 0 00039.116520: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00030081 00039.118675: cyrano: [zccard/s:INFO] Opened Conditional Access Support(5) 00039.126483: cyrano: [zccard/a:INFO] -> Horizonal_scrolling = 0 00039.128813: cyrano: [zccard/a:INFO] -> Display_type_support = 0 00039.135977: cyrano: [zccard/s:INFO] SPDU - session_number(): 0003 00039.138987: cyrano: [zccard/a:INFO] -> Data_entry_support = 0 00039.146795: cyrano: [zccard/s:INFO] SPDU - session_number(): 0003 00039.155368: cyrano: [zccard/s:INFO] SPDU - session_number(): 0003 00039.169797: cyrano: [zccard/a:INFO] -> HTML_support = 0 00039.176807: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00240041 00039.194351: cyrano: [zccard/s:INFO] Opened System Time(14) 00039.216787: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 002a0044 00039.218987: cyrano: [zccard/s:INFO] Opened Generic Feature Control(11) 00039.246769: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 002c0041 00039.248989: cyrano: [zccard/s:INFO] Opened Headend Communication(18) 00039.268395: cyrano: [zccard/a:INFO] -> Link_support = 0 00039.276814: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00a00041 00039.279028: cyrano: [zccard/s:INFO] Opened Extended Channel Support(8) 00039.288311: ocur: fdc_NotifyFlowStatusUpdate:799 : available 1 flow_id 00000000 pid 0000 00039.289363: ocur: fdc_NotifyFlowStatusUpdate:802 : Flows can be created 00039.313324: ocur: fdc_ActivateFlows:641 : Activating fdc pid 0x1ffc 00039.318264: cyrano: [zccard/oobsi:INFO] OOB MPEG FLOW enabled 00039.312229: cyrano: [zccard/a:INFO] -> Form_support = 0 00039.323475: cyrano: [zccard/a:INFO] -> Table_support = 0 00039.325732: cyrano: [zccard/a:INFO] -> List_support = 0 00039.327999: cyrano: [zccard/a:INFO] -> Image_support = 0 00039.349896: cyrano: [zccard/oobsi:INFO] Running oobsi filter nit, handle 80000001 00039.354529: cyrano: [zccard/card:INFO] zapi/ccard/trunk/src/card/zccard_card_cchi.c:982 Unable to create flow (pending one exists) 00039.375884: cyrano: [zccard/oobsi:INFO] Running oobsi filter svct, handle 80000002 00039.379785: cyrano: [zccard/card:INFO] zapi/ccard/trunk/src/card/zccard_card_cchi.c:982 Unable to create flow (pending one exists) 00039.401414: cyrano: [zccard/oobsi:INFO] Running oobsi filter stt, handle 80000003 00039.405317: cyrano: [zccard/card:INFO] zapi/ccard/trunk/src/card/zccard_card_cchi.c:982 Unable to create flow (pending one exists) 00039.425317: cyrano: [zccard/oobsi:INFO] Running oobsi filter ntt, handle 80000004 00039.429186: cyrano: [zccard/card:INFO] zapi/ccard/trunk/src/card/zccard_card_cchi.c:982 Unable to create flow (pending one exists) 00039.449831: cyrano: [zccard/oobsi:INFO] Running oobsi filter cea, handle 80000005 00039.454369: cyrano: [zccard/card:INFO] zapi/ccard/trunk/src/card/zccard_card_cchi.c:982 Unable to create flow (pending one exists) 00039.330583: cyrano: [zccard/a:INFO] -> {/ai_req} 00039.474035: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 01040081 00039.476269: cyrano: [zccard/s:INFO] Opened Generic Diagnostic Support(13) 00039.533005: cyrano: [zccard/a:INFO] -> {ca_info_inq} 00039.613877: cyrano: [zccard/a:INFO] <- {cr_stream_profile} 00039.616200: cyrano: [zccard/a:INFO] <- max_number_of_streams = 6 00039.618273: cyrano: [zccard/a:INFO] <- {/cr_stream_profile} 00039.625979: cyrano: [zccard/a:INFO] -> {cr_stream_profile_cnf} 00039.628319: cyrano: [zccard/a:INFO] -> number_of_streams_used = 4 00039.666753: cyrano: [zccard/a:INFO] -> {/cr_stream_profile_cnf} 00039.713761: cyrano: [zccard/s:INFO] SPDU - session_number(): 0005 00039.724519: cyrano: [zccard/s:INFO] SPDU - session_number(): 0006 00039.736516: cyrano: [zccard/s:INFO] SPDU - session_number(): 0009 00039.743761: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00039.754891: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00200081 00039.757068: cyrano: [zccard/s:INFO] Opened Host Control(7) 00039.763940: cyrano: [zccard/a:INFO] <- {cr_program_profile} 00039.766272: cyrano: [zccard/a:INFO] <- max_number_of_programs = 6 00039.768327: cyrano: [zccard/a:INFO] <- {/cr_program_profile} 00039.779017: cyrano: [zccard/s:INFO] SPDU - session_number(): 0004 00039.806775: cyrano: [zccard/s:INFO] SPDU - session_number(): 000a 00039.831203: cyrano: [zccard/a:INFO] -> {cr_program_profile_cnf} 00039.859562: cyrano: [zccard/a:INFO] <- {cr_es_profile} 00039.872884: cyrano: [zccard/a:INFO] <- max_number_of_es = 120 00039.874940: cyrano: [zccard/a:INFO] <- {/cr_es_profile} 00039.877943: cyrano: [zccard/a:INFO] -> {cr_es_profile_cnf} 00039.993369: cyrano: [zccard/a:INFO] -> {new_flow_req} 00039.995672: cyrano: [zccard/a:INFO] -> service_type = MPEG section 00039.997943: cyrano: [zccard/a:INFO] -> pid = 0x1ffc 00039.999985: cyrano: [zccard/a:INFO] -> {/new_flow_req} 00040.048976: cyrano: [zccard/s:INFO] SPDU - session_number(): 0008 00040.055160: cyrano: [zccard/a:INFO] <- {system_time_inq} 00040.057721: cyrano: [zccard/a:INFO] -> {system_time} 00040.061101: cyrano: [zccard/a:INFO] -> system_time = 00000028 "Sun Jan 6 00:00:48 1980 UTC" 00040.063434: cyrano: [zccard/a:INFO] -> GPS_UTC_offset = 00 00040.065458: cyrano: [zccard/a:INFO] -> {/system_time} 00040.074188: cyrano: [zccard/a:INFO] <- {feature_list_req} 00040.077676: cyrano: [zccard/a:INFO] -> {feature_list} 00040.079964: cyrano: [zccard/a:INFO] -> number_of_features = 7 00040.099415: cyrano: [zccard/a:INFO] -> feature_id = [0]RF Output Channel 00040.123245: cyrano: [zccard/a:INFO] -> feature_id = [1]Time Zone 00040.125657: cyrano: [zccard/a:INFO] -> feature_id = [2]Daylight Savings Control 00040.128054: cyrano: [zccard/a:INFO] -> feature_id = [3]Rating Region 00040.182859: cyrano: [zccard/a:INFO] -> feature_id = [4]Language 00040.185328: cyrano: [zccard/a:INFO] -> feature_id = [5]EA Location Code 00040.187714: cyrano: [zccard/a:INFO] -> feature_id = [6]Unknown 00040.189767: cyrano: [zccard/a:INFO] -> {/feature_list} 00040.256857: cyrano: [zccard/s:INFO] SPDU - session_number(): 0006 00040.272301: cyrano: [zccard/a:INFO] <- {diagnostic_req} 00040.274757: cyrano: [zccard/a:INFO] <- diagnostic = MAC address:0x00 00040.276823: cyrano: [zccard/a:INFO] <- {/diagnostic_req} 00040.311287: cyrano: [zccard/a:INFO] -> {diagnostic_cnf} 00040.314327: cyrano: [zccard/a:INFO] -> diagnostic = MAC address:0x00, diagnostic granted 00040.316442: cyrano: [zccard/a:INFO] -> {mac_address} 00040.318542: cyrano: [zccard/a:INFO] -> {mac_address_desc} 00040.351767: cyrano: [zccard/a:INFO] -> type = host 00040.355078: cyrano: [zccard/a:INFO] -> address = 00222C805F8F 00040.357219: cyrano: [zccard/a:INFO] -> {/mac_address_desc} 00040.359325: cyrano: [zccard/a:INFO] -> {/mac_address} 00040.392318: cyrano: [zccard/a:INFO] -> {/diagnostic_cnf} 00040.425569: cyrano: [zccard/a:INFO] <- {ai_cnf} 00040.428000: cyrano: [zccard/a:INFO] <- pod_manufacturer_id = Cisco (Scientific-Atlanta)(0x103) 00040.431103: cyrano: [zccard/a:INFO] <- pod_version_number = 1 00040.433198: cyrano: [zccard/a:INFO] <- {application} 00040.435493: cyrano: [zccard/a:INFO] <- type = Conditional Access 00040.437788: cyrano: [zccard/a:INFO] <- version_number = 1 00040.450936: cyrano: [zccard/a:INFO] <- name = CableCARD CA Screen 00040.453402: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/CaApp.html 00040.455457: cyrano: [zccard/a:INFO] <- {/application} 00040.457519: cyrano: [zccard/a:INFO] <- {application} 00040.459857: cyrano: [zccard/a:INFO] <- type = CableCard Pairing information (HOST_ID,POD_ID) 00040.513635: cyrano: [zccard/a:INFO] <- version_number = 1 00040.515971: cyrano: [zccard/a:INFO] <- name = CableCARD/Host ID Screen 00040.518322: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/CpDiag.html 00040.551431: cyrano: [zccard/a:INFO] <- {/application} 00040.553561: cyrano: [zccard/a:INFO] <- {application} 00040.555848: cyrano: [zccard/a:INFO] <- type = IP Service 00040.558146: cyrano: [zccard/a:INFO] <- version_number = 1 00040.591515: cyrano: [zccard/a:INFO] <- name = CableCARD IP Service 00040.593931: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/IPInfo.html 00040.595991: cyrano: [zccard/a:INFO] <- {/application} 00040.598078: cyrano: [zccard/a:INFO] <- {application} 00040.631398: cyrano: [zccard/a:INFO] <- type = Network Interface - SCTE 55-2 00040.633751: cyrano: [zccard/a:INFO] <- version_number = 1 00040.636082: cyrano: [zccard/a:INFO] <- name = CableCARD DAVIC Info 00040.638423: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/DavicInfo.html 00040.671472: cyrano: [zccard/a:INFO] <- {/application} 00040.673609: cyrano: [zccard/a:INFO] <- {application} 00040.675908: cyrano: [zccard/a:INFO] <- type = Copy Protection 00040.678219: cyrano: [zccard/a:INFO] <- version_number = 1 00040.711548: cyrano: [zccard/a:INFO] <- name = CableCARD CP Info 00040.713941: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/CpInfo.html 00040.715996: cyrano: [zccard/a:INFO] <- {/application} 00040.718060: cyrano: [zccard/a:INFO] <- {application} 00040.751291: cyrano: [zccard/a:INFO] <- type = Diagnostic 00040.753634: cyrano: [zccard/a:INFO] <- version_number = 1 00040.756450: cyrano: [zccard/a:INFO] <- name = CableCARD Diag Screen 00040.758799: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/diag.html 00040.792987: cyrano: [zccard/a:INFO] <- {/application} 00040.795135: cyrano: [zccard/a:INFO] <- {application} 00040.797429: cyrano: [zccard/a:INFO] <- type = Unknown 00040.799720: cyrano: [zccard/a:INFO] <- version_number = 1 00040.813058: cyrano: [zccard/a:INFO] <- name = CableCARD DSG Info 00040.815413: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/DsgInfo.html 00040.817477: cyrano: [zccard/a:INFO] <- {/application} 00040.819552: cyrano: [zccard/a:INFO] <- {application} 00040.852856: cyrano: [zccard/a:INFO] <- type = Unknown 00040.855154: cyrano: [zccard/a:INFO] <- version_number = 1 00040.857471: cyrano: [zccard/a:INFO] <- name = CableCARD CANH Screen 00040.859846: cyrano: [zccard/a:INFO] <- url = CableCARD///apps/CANHandlerDiag.html 00040.888511: cyrano: [zccard/a:INFO] <- {/application} 00040.951742: cyrano: [zccard/a:INFO] <- {/ai_cnf} 00041.084627: cyrano: [zccard/a:INFO] <- {ca_info} 00041.086932: cyrano: [zccard/a:INFO] <- ca_system_ids = {0xe00} 00041.088985: cyrano: [zccard/a:INFO] <- {/ca_info} 00041.091236: cyrano: dri_driEventListener:920 WARNING: No callback for dri event 00400000 00041.103925: cyrano: [zccard/a:INFO] <- {oob_rx_tune_req} 00041.106331: cyrano: [zccard/a:INFO] <- frequency_value = 75000Hz (0x1f4) 00041.108625: cyrano: [zccard/a:INFO] <- data rate = 1544 kbps (Mode B Grade A) 00041.131729: cyrano: [zccard/a:INFO] <- spectrum = non-inverted 00041.133816: cyrano: [zccard/a:INFO] <- {/oob_rx_tune_req} 00041.912719: cyrano: [zccard/a:INFO] -> {oob_rx_tune_cnf} 00041.915059: cyrano: [zccard/a:INFO] -> status = Tuning granted 00041.917133: cyrano: [zccard/a:INFO] -> {/oob_rx_tune_cnf} 00041.936703: cyrano: [zccard/a:WARN] zapi/ccard/trunk/src/cchi/application/zccard_cchi_extendedchannel.c:334 zccard_cchi_recv_ec_new_flow_cnf 0 00041.938867: cyrano: [zccard/a:INFO] <- {new_flow_cnf} 00041.941960: cyrano: [zccard/a:INFO] <- status = Request Granted 00041.944257: cyrano: [zccard/a:INFO] <- flows_remaining = 5 00041.946539: cyrano: [zccard/a:INFO] <- flow_id = 0x1 00041.948821: cyrano: [zccard/a:INFO] <- serviceType = MPEG section 00041.957165: cyrano: [zccard/a:INFO] <- {/new_flow_cnf} 00041.958545: ocur: cas_hal_callback_stub:417 WARNING: Stubbed callback 00041.967980: cyrano: [zccard/card:ERROR] zapi/ccard/trunk/src/card/zccard_card_cchi.c:819 Found 6 filters for pid 0x1ffc 00041.969307: ocur: fdc_NotifyFlowStatusUpdate:799 : available 1 flow_id 0x000001 pid 0x1ffc 00041.991759: ocur: fdc_NotifyFlowStatusUpdate:816 : Pid 0x1ffc Flow 0x000001 is now available 00041.994938: cyrano: [zccard/card:INFO] zapi/ccard/trunk/src/card/zccard_card.c:230 No pending flows. 00042.003911: cyrano: [zccard/a:INFO] <- {feature_list_cnf} 00042.006009: cyrano: [zccard/a:INFO] -> {feature_list_req} 00042.036735: cyrano: [zccard/s:INFO] SPDU - session_number(): 0006 00042.063857: cyrano: [zccard/a:INFO] <- {feature_list} 00042.066154: cyrano: [zccard/a:INFO] <- number_of_features = 11 00042.068536: cyrano: [zccard/a:INFO] <- feature_id = [0]RF Output Channel 00042.071617: cyrano: [zccard/a:INFO] <- feature_id = [1]Parental Control PIN 00042.073992: cyrano: [zccard/a:INFO] <- feature_id = [2]IPPV PIN 00042.076342: cyrano: [zccard/a:INFO] <- feature_id = [3]Time Zone 00042.078712: cyrano: [zccard/a:INFO] <- feature_id = [4]Daylight Savings Control 00042.092075: cyrano: [zccard/a:INFO] <- feature_id = [5]Reset PIN 00042.094506: cyrano: [zccard/a:INFO] <- feature_id = [6]VCT ID 00042.096867: cyrano: [zccard/a:INFO] <- feature_id = [7]Turn on channel 00042.099227: cyrano: [zccard/a:INFO] <- feature_id = [8]Unknown 00042.132999: cyrano: [zccard/a:INFO] <- feature_id = [9]Unknown 00042.135399: cyrano: [zccard/a:INFO] <- feature_id = [10]Unknown 00042.137445: cyrano: [zccard/a:INFO] <- {/feature_list} 00042.139606: cyrano: [zccard/a:INFO] -> {feature_list_cnf} 00042.608855: ocur: [192.168.200.2] Action(wmdrm[0]) ProcessLicenseChallenge success 00042.701832: ocur: [192.168.200.2] Calling Action(wmdrm[0]) AcknowledgeLicense 00042.703198: ocur: wmdrm_AcknowledgeLicense_impl:755 : [0.0] License Success Ack Received 00042.740911: ocur: [192.168.200.2] Action(wmdrm[0]) AcknowledgeLicense success 00042.801486: ocur: [192.168.200.2] Calling Action(aux[1]) GetAuxCapabilities 00042.803396: ocur: [192.168.200.2] Action(aux[1]) GetAuxCapabilities success 00043.047361: ocur: [192.168.200.2] Calling Action(wmdrm[1]) ProcessRegistrationChallenge 00044.038469: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 00b00103 00044.041543: cyrano: [zccard/s:INFO] Opened Copy Protection(6) 00044.085618: cyrano: [zccard/a:INFO] -> {cp_valid_req} 00044.103600: cyrano: [zccard/s:INFO] SPDU - session_number(): 000b 00044.109151: cyrano: [zccard/a:INFO] <- {cp_open_req} 00044.117033: cyrano: [zccard/a:INFO] -> {cp_open_cnf} 00044.119359: cyrano: [zccard/a:INFO] -> CP_system_id_bitmask = 0x2 00044.136698: cyrano: [zccard/s:INFO] SPDU - session_number(): 000b 00044.141843: cyrano: [zccard/a:INFO] -> {/cp_open_cnf} 00044.186709: cyrano: [zccard/s:INFO] SPDU - session_number(): 000b 00044.650807: ocur: wmdrm_ProcessRegistrationChallenge_impl:1712 : [2.0] We registered 00044.654392: ocur: [192.168.200.2] Action(wmdrm[2]) ProcessRegistrationChallenge success 00044.687776: cyrano: [zccard/s:INFO] SPDU - session_number(): 000a 00045.051136: ocur: cas_hal_ServerQuery:3688 WARNING: server query timed out 00049.047604: cyrano: [zccard/s:INFO] SPDU - open_session_request(): 002b0081 00049.049814: cyrano: [zccard/s:INFO] Opened System Control(15) 00049.086722: cyrano: [zccard/s:INFO] SPDU - session_number(): 000c 00050.673859: cyrano: [zccard/a:INFO] <- {cp_valid_cnf} 00050.676231: cyrano: [zccard/a:INFO] <- status = Card is busy with binding authentication process 00050.678305: cyrano: [zccard/a:INFO] <- {/cp_valid_cnf} 00050.694457: cyrano: [zccard/a:INFO] <- {cp_data_req} 00050.696562: cyrano: [zccard/a:INFO] <- {auth_key_verification_req} 00050.698635: cyrano: [zccard/a:INFO] <- {/auth_key_verification_req} 00050.711559: cyrano: [zccard/a:INFO] <- {/cp_data_req} 00050.713832: cyrano: [zccard/a:INFO] -> {cp_data_cnf} 00050.715957: cyrano: [zccard/a:INFO] -> {auth_key_verification_cnf} 00050.742235: cyrano: [zccard/a:INFO] -> AuthKey = DC296DDD0A50B57ABA527B7A7560BE5AA77D6FC2 00050.744395: cyrano: [zccard/a:INFO] -> {/auth_key_verification_cnf} 00050.746478: cyrano: [zccard/a:INFO] -> {/cp_data_cnf} 00050.803884: cyrano: [zccard/a:INFO] <- {oob_tx_tune_req} 00050.806230: cyrano: [zccard/a:INFO] <- frequency_value = 0x32c8 00050.808524: cyrano: [zccard/a:INFO] <- power_level = 0x5a 00050.818056: cyrano: [zccard/s:INFO] SPDU - session_number(): 000b 00050.839251: cyrano: [zccard/s:INFO] SPDU - session_number(): 000b 00050.851647: cyrano: [zccard/a:INFO] <- rate = 1544 kbps 00050.853768: cyrano: [zccard/a:INFO] <- {/oob_tx_tune_req} 00050.855954: cyrano: [zccard/a:INFO] -> {oob_tx_tune_cnf} 00050.858299: cyrano: [zccard/a:INFO] -> status = Tuning Denied - RF Transmitter not physically available 00050.881316: cyrano: [zccard/a:INFO] -> {/oob_tx_tune_cnf} 00050.923573: cyrano: [zccard/a:INFO] received invalid host_info_request(). 00050.929397: ocur: [192.168.200.2] Get(security[0]): HmsAssociationList "n5ByAAABlw5AAF+PAAAAAEYiuLcGBgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAsKpJZjs5QAqsNUT0G0bJax9cQGXlyzqUALFkZeEPKwyGAAAAAAAAAAAAAIawqklmOzlACqw1RPQbRslrCza+MWpm4ppuLoeflT3+64kAAAAAAAAAAAAAibCqSWY7OUAKrDVE9BtGyWvhchfkDnWuZxoy1agZWdMcjQAAAAAA" 00050.934018: cyrano: [zccard/a:INFO] <- {cp_data_req} 00050.938240: cyrano: [zccard/a:INFO] <- {key_generation_req} 00050.942640: cyrano: [zccard/a:INFO] <- POD_ID = 000000004622B8B7 00050.946168: cyrano: [zccard/a:INFO] <- N_module = 665D4969806ABCDF 00050.948222: cyrano: [zccard/a:INFO] <- {/key_generation_req} 00050.951066: cyrano: [zccard/a:INFO] <- {/cp_data_req} 00050.954921: cyrano: [zccard/a:INFO] -> {cp_data_cnf} 00050.957044: cyrano: [zccard/a:INFO] -> {key_generation_cnf} 00050.981572: cyrano: [zccard/a:INFO] -> Host_ID = 0E40005F8F 00050.985177: cyrano: [zccard/a:INFO] -> N_Host = F0F04434B1CEBA57 00050.987293: cyrano: [zccard/a:INFO] -> {/key_generation_cnf} 00050.989367: cyrano: [zccard/a:INFO] -> {/cp_data_cnf} 00054.593779: cyrano: [zccard/a:INFO] <- {cp_valid_cnf} 00054.596182: cyrano: [zccard/a:INFO] <- status = Validated, validation message is received, authenticated, and the IDs match tho 00054.598268: cyrano: [zccard/a:INFO] <- {/cp_valid_cnf} 00054.895828: ocur: wmdrm_ProcessRegistrationChallenge_impl:1712 : [1.0] We registered 00054.927859: cyrano: [zccard/a:INFO] -> {server_query} 00054.930923: cyrano: [zccard/a:INFO] -> transaction_number = 0 00054.933314: cyrano: [zccard/a:INFO] -> header = (null) 00054.935672: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00054.937741: cyrano: [zccard/a:INFO] -> {/server_query} 00054.959508: ocur: [192.168.200.2] Action(wmdrm[1]) ProcessRegistrationChallenge success 00054.983033: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00054.998629: cyrano: [zccard/a:INFO] <- {server_reply} 00055.001632: cyrano: [zccard/a:INFO] <- transaction_number = 0 00055.003856: cyrano: [zccard/a:INFO] <- file_status = OK 00055.006046: cyrano: [zccard/a:INFO] <- header = 00055.008288: cyrano: [zccard/a:INFO] <- file_length = 519 00055.011292: cyrano: [zccard/a:INFO] <- file_byte = <...> 00055.013334: cyrano: [zccard/a:INFO] <- {/server_reply} 00055.214685: ocur: [192.168.200.2] Get(fdc[2]): CarrierLock "1" 00055.294051: ocur: [192.168.200.2] Calling Action(wmdrm[3]) ProcessRegistrationChallenge 00055.311354: ocur: [192.168.200.2] Get(fdc[1]): CarrierLock "1" 00056.905895: ocur: Event(security[1]): DrmPairingStatus, "Green" 00057.379017: ocur: [192.168.200.2] Calling Action(wmdrm[1]) ProcessLicenseChallenge 00058.020869: ocur: Event(security[2]): DrmPairingStatus, "Green" 00058.249353: ocur: [192.168.200.2] Calling Action(wmdrm[2]) ProcessLicenseChallenge 00061.885284: ocur: [192.168.200.2] Action(wmdrm[1]) ProcessLicenseChallenge success 00062.557665: ocur: [192.168.200.2] Action(wmdrm[2]) ProcessLicenseChallenge success 00062.661740: ocur: [192.168.200.2] Calling Action(wmdrm[2]) AcknowledgeLicense 00062.663138: ocur: wmdrm_AcknowledgeLicense_impl:755 : [2.0] License Success Ack Received 00062.701093: ocur: [192.168.200.2] Action(wmdrm[2]) AcknowledgeLicense success 00062.807136: ocur: [192.168.200.2] Calling Action(wmdrm[1]) AcknowledgeLicense 00062.808462: ocur: wmdrm_AcknowledgeLicense_impl:755 : [1.0] License Success Ack Received 00062.840954: ocur: [192.168.200.2] Action(wmdrm[1]) AcknowledgeLicense success 00063.500805: ocur: wmdrm_ProcessRegistrationChallenge_impl:1712 : [3.0] We registered 00063.528823: ocur: [192.168.200.2] Action(wmdrm[3]) ProcessRegistrationChallenge success 00068.005392: ocur: [192.168.200.2] Get(security[1]): HmsAssociationList "n5ByAAAB7w5AAF+PAAAAAEYiuLcICAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAsKpJZjs5QAqsNUT0G0bJax9cQGXlyzqUALFkZeEPKwyGAAAAAAAAAAAAAIawqklmOzlACqw1RPQbRslrCza+MWpm4ppuLoeflT3+64kAAAAAAAAAAAAAibCqSWY7OUAKrDVE9BtGyWvhchfkDnWuZxoy1agZWdMcjQAAAAAA" 00068.107359: ocur: [192.168.200.2] Get(security[2]): HmsAssociationList "n5ByAAAB7w5AAF+PAAAAAEYiuLcICAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAsKpJZjs5QAqsNUT0G0bJax9cQGXlyzqUALFkZeEPKwyGAAAAAAAAAAAAAIawqklmOzlACqw1RPQbRslrCza+MWpm4ppuLoeflT3+64kAAAAAAAAAAAAAibCqSWY7OUAKrDVE9BtGyWvhchfkDnWuZxoy1agZWdMcjQAAAAAA" 00068.209365: ocur: [192.168.200.2] Get(fdc[3]): CarrierLock "1" 00068.481034: ocur: Event(security[3]): DrmPairingStatus, "Green" 00068.648431: ocur: [192.168.200.2] Calling Action(wmdrm[3]) ProcessLicenseChallenge 00070.212069: ocur: [192.168.200.2] Action(wmdrm[3]) ProcessLicenseChallenge success 00070.785910: ocur: [192.168.200.2] Calling Action(wmdrm[3]) AcknowledgeLicense 00070.787251: ocur: wmdrm_AcknowledgeLicense_impl:755 : [3.0] License Success Ack Received 00070.871938: ocur: [192.168.200.2] Action(wmdrm[3]) AcknowledgeLicense success 00072.497751: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00072.499051: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=1 SourceId=0 Mode=0) 00072.515928: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 1 00072.517862: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00072.518679: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 1 not found 00072.522321: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00072.731866: cyrano: [zccard/a:INFO] -> {server_query} 00072.734193: cyrano: [zccard/a:INFO] -> transaction_number = 0 00072.736518: cyrano: [zccard/a:INFO] -> header = (null) 00072.738879: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00072.742814: cyrano: [zccard/a:INFO] -> {/server_query} 00072.779847: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00072.786333: cyrano: [zccard/a:INFO] <- {server_reply} 00072.788650: cyrano: [zccard/a:INFO] <- transaction_number = 0 00072.796120: cyrano: [zccard/a:INFO] <- file_status = OK 00072.798451: cyrano: [zccard/a:INFO] <- header = 00072.811665: cyrano: [zccard/a:INFO] <- file_length = 513 00072.814007: cyrano: [zccard/a:INFO] <- file_byte = <...> 00072.816069: cyrano: [zccard/a:INFO] <- {/server_reply} 00075.037029: cyrano: [zccard/a:INFO] -> {server_query} 00075.039327: cyrano: [zccard/a:INFO] -> transaction_number = 0 00075.053597: cyrano: [zccard/a:INFO] -> header = (null) 00075.055961: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00075.058015: cyrano: [zccard/a:INFO] -> {/server_query} 00075.190612: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00075.199119: cyrano: [zccard/a:INFO] <- {server_reply} 00075.202258: cyrano: [zccard/a:INFO] <- transaction_number = 0 00075.204553: cyrano: [zccard/a:INFO] <- file_status = OK 00075.206800: cyrano: [zccard/a:INFO] <- header = 00075.209101: cyrano: [zccard/a:INFO] <- file_length = 513 00075.213427: cyrano: [zccard/a:INFO] <- file_byte = <...> 00075.215528: cyrano: [zccard/a:INFO] <- {/server_reply} 00075.992416: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00075.993714: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=2 SourceId=0 Mode=0) 00076.004010: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00076.005208: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00076.005978: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 2 not found 00076.023041: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00076.218707: cyrano: [zccard/a:INFO] -> {server_query} 00076.221744: cyrano: [zccard/a:INFO] -> transaction_number = 0 00076.224085: cyrano: [zccard/a:INFO] -> header = (null) 00076.226437: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00076.228500: cyrano: [zccard/a:INFO] -> {/server_query} 00076.273308: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00076.282311: cyrano: [zccard/a:INFO] <- {server_reply} 00076.284630: cyrano: [zccard/a:INFO] <- transaction_number = 0 00076.286903: cyrano: [zccard/a:INFO] <- file_status = OK 00076.289134: cyrano: [zccard/a:INFO] <- header = 00076.294328: cyrano: [zccard/a:INFO] <- file_length = 513 00076.296639: cyrano: [zccard/a:INFO] <- file_byte = <...> 00076.298710: cyrano: [zccard/a:INFO] <- {/server_reply} 00078.653717: ocur: [192.168.200.2] Get(security[3]): HmsAssociationList "n5ByAAAB7w5AAF+PAAAAAEYiuLcICAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAsKpJZjs5QAqsNUT0G0bJax9cQGXlyzqUALFkZeEPKwyGAAAAAAAAAAAAAIawqklmOzlACqw1RPQbRslrCza+MWpm4ppuLoeflT3+64kAAAAAAAAAAAAAibCqSWY7OUAKrDVE9BtGyWvhchfkDnWuZxoy1agZWdMcjQAAAAAA" 00079.108624: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00079.109949: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00079.116715: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00079.117929: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00079.119133: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00079.124625: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00079.272879: cyrano: [zccard/a:INFO] -> {server_query} 00079.275203: cyrano: [zccard/a:INFO] -> transaction_number = 0 00079.277530: cyrano: [zccard/a:INFO] -> header = (null) 00079.279898: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00079.283759: cyrano: [zccard/a:INFO] -> {/server_query} 00079.319739: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00079.326035: cyrano: [zccard/a:INFO] <- {server_reply} 00079.328343: cyrano: [zccard/a:INFO] <- transaction_number = 0 00079.331187: cyrano: [zccard/a:INFO] <- file_status = OK 00079.333453: cyrano: [zccard/a:INFO] <- header = 00079.335748: cyrano: [zccard/a:INFO] <- file_length = 513 00079.338026: cyrano: [zccard/a:INFO] <- file_byte = <...> 00079.340582: cyrano: [zccard/a:INFO] <- {/server_reply} 00079.466789: cyrano: [zccard/a:INFO] -> {server_query} 00079.469113: cyrano: [zccard/a:INFO] -> transaction_number = 0 00079.473984: cyrano: [zccard/a:INFO] -> header = (null) 00079.476367: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CpDiag.html 00079.478455: cyrano: [zccard/a:INFO] -> {/server_query} 00079.518323: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00079.523877: cyrano: [zccard/a:INFO] <- {server_reply} 00079.526198: cyrano: [zccard/a:INFO] <- transaction_number = 0 00079.528467: cyrano: [zccard/a:INFO] <- file_status = OK 00079.532485: cyrano: [zccard/a:INFO] <- header = 00079.534860: cyrano: [zccard/a:INFO] <- file_length = 388 00079.537148: cyrano: [zccard/a:INFO] <- file_byte = <...> 00079.539206: cyrano: [zccard/a:INFO] <- {/server_reply} 00079.583297: cyrano: [zccard/a:INFO] -> {server_query} 00079.585622: cyrano: [zccard/a:INFO] -> transaction_number = 0 00079.587942: cyrano: [zccard/a:INFO] -> header = (null) 00079.591095: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/diag.html 00079.593188: cyrano: [zccard/a:INFO] -> {/server_query} 00079.633092: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00079.638824: cyrano: [zccard/a:INFO] <- {server_reply} 00079.641731: cyrano: [zccard/a:INFO] <- transaction_number = 0 00079.644013: cyrano: [zccard/a:INFO] <- file_status = OK 00079.646251: cyrano: [zccard/a:INFO] <- header = 00079.648543: cyrano: [zccard/a:INFO] <- file_length = 663 00079.651263: cyrano: [zccard/a:INFO] <- file_byte = <...> 00079.653326: cyrano: [zccard/a:INFO] <- {/server_reply} 00079.703225: cyrano: [zccard/a:INFO] -> {server_query} 00079.705537: cyrano: [zccard/a:INFO] -> transaction_number = 0 00079.707846: cyrano: [zccard/a:INFO] -> header = (null) 00079.710688: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CpInfo.html 00079.712797: cyrano: [zccard/a:INFO] -> {/server_query} 00079.749507: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00079.755730: cyrano: [zccard/a:INFO] <- {server_reply} 00079.758047: cyrano: [zccard/a:INFO] <- transaction_number = 0 00079.760859: cyrano: [zccard/a:INFO] <- file_status = OK 00079.763130: cyrano: [zccard/a:INFO] <- header = 00079.765422: cyrano: [zccard/a:INFO] <- file_length = 570 00079.767699: cyrano: [zccard/a:INFO] <- file_byte = <...> 00079.769744: cyrano: [zccard/a:INFO] <- {/server_reply} 00079.918778: cyrano: [zccard/s:INFO] SPDU - session_number(): 000b 00079.932829: cyrano: [zccard/a:INFO] <- {cp_sync_req} 00079.968606: cyrano: [zccard/a:INFO] -> {cp_sync_cnf} 00079.971432: cyrano: [zccard/a:INFO] -> status = OK 00079.973489: cyrano: [zccard/a:INFO] -> {/cp_sync_cnf} 00095.235536: cyrano: [zccard/a:INFO] -> {server_query} 00095.237867: cyrano: [zccard/a:INFO] -> transaction_number = 0 00095.240712: cyrano: [zccard/a:INFO] -> header = (null) 00095.243105: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00095.245170: cyrano: [zccard/a:INFO] -> {/server_query} 00095.282621: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00095.289159: cyrano: [zccard/a:INFO] <- {server_reply} 00095.292028: cyrano: [zccard/a:INFO] <- transaction_number = 0 00095.294825: cyrano: [zccard/a:INFO] <- file_status = OK 00095.297071: cyrano: [zccard/a:INFO] <- header = 00095.299365: cyrano: [zccard/a:INFO] <- file_length = 513 00095.302162: cyrano: [zccard/a:INFO] <- file_byte = <...> 00095.304233: cyrano: [zccard/a:INFO] <- {/server_reply} 00112.372178: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00112.373509: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00112.379735: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00112.382794: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00112.383602: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00112.387305: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00112.535359: cyrano: [zccard/a:INFO] -> {server_query} 00112.537689: cyrano: [zccard/a:INFO] -> transaction_number = 0 00112.540558: cyrano: [zccard/a:INFO] -> header = (null) 00112.543117: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00112.545188: cyrano: [zccard/a:INFO] -> {/server_query} 00112.622205: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00112.633737: cyrano: [zccard/a:INFO] <- {server_reply} 00112.636072: cyrano: [zccard/a:INFO] <- transaction_number = 0 00112.638358: cyrano: [zccard/a:INFO] <- file_status = OK 00112.641222: cyrano: [zccard/a:INFO] <- header = 00112.643532: cyrano: [zccard/a:INFO] <- file_length = 513 00112.645793: cyrano: [zccard/a:INFO] <- file_byte = <...> 00112.647856: cyrano: [zccard/a:INFO] <- {/server_reply} 00112.773254: cyrano: [zccard/a:INFO] -> {server_query} 00112.775573: cyrano: [zccard/a:INFO] -> transaction_number = 0 00112.777890: cyrano: [zccard/a:INFO] -> header = (null) 00112.782050: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CpDiag.html 00112.784213: cyrano: [zccard/a:INFO] -> {/server_query} 00112.822038: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00112.827759: cyrano: [zccard/a:INFO] <- {server_reply} 00112.831734: cyrano: [zccard/a:INFO] <- transaction_number = 0 00112.834148: cyrano: [zccard/a:INFO] <- file_status = OK 00112.836413: cyrano: [zccard/a:INFO] <- header = 00112.838729: cyrano: [zccard/a:INFO] <- file_length = 397 00112.842826: cyrano: [zccard/a:INFO] <- file_byte = <...> 00112.844938: cyrano: [zccard/a:INFO] <- {/server_reply} 00112.893233: cyrano: [zccard/a:INFO] -> {server_query} 00112.895565: cyrano: [zccard/a:INFO] -> transaction_number = 0 00112.897897: cyrano: [zccard/a:INFO] -> header = (null) 00112.900853: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/diag.html 00112.902954: cyrano: [zccard/a:INFO] -> {/server_query} 00112.943446: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00112.949148: cyrano: [zccard/a:INFO] <- {server_reply} 00112.952012: cyrano: [zccard/a:INFO] <- transaction_number = 0 00112.954289: cyrano: [zccard/a:INFO] <- file_status = OK 00112.956543: cyrano: [zccard/a:INFO] <- header = 00112.958848: cyrano: [zccard/a:INFO] <- file_length = 663 00112.961659: cyrano: [zccard/a:INFO] <- file_byte = <...> 00112.963717: cyrano: [zccard/a:INFO] <- {/server_reply} 00113.013214: cyrano: [zccard/a:INFO] -> {server_query} 00113.015518: cyrano: [zccard/a:INFO] -> transaction_number = 0 00113.017820: cyrano: [zccard/a:INFO] -> header = (null) 00113.020595: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CpInfo.html 00113.022680: cyrano: [zccard/a:INFO] -> {/server_query} 00113.059336: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00113.065355: cyrano: [zccard/a:INFO] <- {server_reply} 00113.067663: cyrano: [zccard/a:INFO] <- transaction_number = 0 00113.069924: cyrano: [zccard/a:INFO] <- file_status = OK 00113.072616: cyrano: [zccard/a:INFO] <- header = 00113.074876: cyrano: [zccard/a:INFO] <- file_length = 570 00113.077104: cyrano: [zccard/a:INFO] <- file_byte = <...> 00113.079134: cyrano: [zccard/a:INFO] <- {/server_reply} 00115.325559: cyrano: [zccard/a:INFO] -> {server_query} 00115.327867: cyrano: [zccard/a:INFO] -> transaction_number = 0 00115.332705: cyrano: [zccard/a:INFO] -> header = (null) 00115.335130: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00115.337199: cyrano: [zccard/a:INFO] -> {/server_query} 00115.369304: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00115.377901: cyrano: [zccard/a:INFO] <- {server_reply} 00115.380954: cyrano: [zccard/a:INFO] <- transaction_number = 0 00115.383275: cyrano: [zccard/a:INFO] <- file_status = OK 00115.385512: cyrano: [zccard/a:INFO] <- header = 00115.387803: cyrano: [zccard/a:INFO] <- file_length = 513 00115.390723: cyrano: [zccard/a:INFO] <- file_byte = <...> 00115.392840: cyrano: [zccard/a:INFO] <- {/server_reply} 00135.405502: cyrano: [zccard/a:INFO] -> {server_query} 00135.407819: cyrano: [zccard/a:INFO] -> transaction_number = 0 00135.410608: cyrano: [zccard/a:INFO] -> header = (null) 00135.413003: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00135.415093: cyrano: [zccard/a:INFO] -> {/server_query} 00135.452378: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00135.458940: cyrano: [zccard/a:INFO] <- {server_reply} 00135.462934: cyrano: [zccard/a:INFO] <- transaction_number = 0 00135.465244: cyrano: [zccard/a:INFO] <- file_status = OK 00135.467508: cyrano: [zccard/a:INFO] <- header = 00135.469826: cyrano: [zccard/a:INFO] <- file_length = 513 00135.475467: cyrano: [zccard/a:INFO] <- file_byte = <...> 00135.477519: cyrano: [zccard/a:INFO] <- {/server_reply} 00145.093909: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00145.095215: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00145.103267: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00145.104484: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00145.105267: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00145.108965: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00145.255174: cyrano: [zccard/a:INFO] -> {server_query} 00145.257515: cyrano: [zccard/a:INFO] -> transaction_number = 0 00145.259856: cyrano: [zccard/a:INFO] -> header = (null) 00145.263018: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CaApp.html 00145.265085: cyrano: [zccard/a:INFO] -> {/server_query} 00145.334016: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00145.339697: cyrano: [zccard/a:INFO] <- {server_reply} 00145.358693: cyrano: [zccard/a:INFO] <- transaction_number = 0 00145.361439: cyrano: [zccard/a:INFO] <- file_status = OK 00145.363700: cyrano: [zccard/a:INFO] <- header = 00145.365993: cyrano: [zccard/a:INFO] <- file_length = 513 00145.368253: cyrano: [zccard/a:INFO] <- file_byte = <...> 00145.370876: cyrano: [zccard/a:INFO] <- {/server_reply} 00145.502994: cyrano: [zccard/a:INFO] -> {server_query} 00145.505315: cyrano: [zccard/a:INFO] -> transaction_number = 0 00145.507630: cyrano: [zccard/a:INFO] -> header = (null) 00145.509978: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CpDiag.html 00145.514821: cyrano: [zccard/a:INFO] -> {/server_query} 00145.558044: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00145.563910: cyrano: [zccard/a:INFO] <- {server_reply} 00145.566226: cyrano: [zccard/a:INFO] <- transaction_number = 0 00145.568487: cyrano: [zccard/a:INFO] <- file_status = OK 00145.572265: cyrano: [zccard/a:INFO] <- header = 00145.574622: cyrano: [zccard/a:INFO] <- file_length = 397 00145.576910: cyrano: [zccard/a:INFO] <- file_byte = <...> 00145.578950: cyrano: [zccard/a:INFO] <- {/server_reply} 00145.623481: cyrano: [zccard/a:INFO] -> {server_query} 00145.625807: cyrano: [zccard/a:INFO] -> transaction_number = 0 00145.628127: cyrano: [zccard/a:INFO] -> header = (null) 00145.631132: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/diag.html 00145.633239: cyrano: [zccard/a:INFO] -> {/server_query} 00145.683051: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00145.688738: cyrano: [zccard/a:INFO] <- {server_reply} 00145.691561: cyrano: [zccard/a:INFO] <- transaction_number = 0 00145.694357: cyrano: [zccard/a:INFO] <- file_status = OK 00145.696603: cyrano: [zccard/a:INFO] <- header = 00145.698895: cyrano: [zccard/a:INFO] <- file_length = 659 00145.701727: cyrano: [zccard/a:INFO] <- file_byte = <...> 00145.703785: cyrano: [zccard/a:INFO] <- {/server_reply} 00145.753217: cyrano: [zccard/a:INFO] -> {server_query} 00145.755539: cyrano: [zccard/a:INFO] -> transaction_number = 0 00145.757854: cyrano: [zccard/a:INFO] -> header = (null) 00145.760761: cyrano: [zccard/a:INFO] -> url = CableCARD///apps/CpInfo.html 00145.762895: cyrano: [zccard/a:INFO] -> {/server_query} 00145.800716: cyrano: [zccard/s:INFO] SPDU - session_number(): 0002 00145.806428: cyrano: [zccard/a:INFO] <- {server_reply} 00145.808752: cyrano: [zccard/a:INFO] <- transaction_number = 0 00145.811525: cyrano: [zccard/a:INFO] <- file_status = OK 00145.813794: cyrano: [zccard/a:INFO] <- header = 00145.816099: cyrano: [zccard/a:INFO] <- file_length = 570 00145.818370: cyrano: [zccard/a:INFO] <- file_byte = <...> 00145.821031: cyrano: [zccard/a:INFO] <- {/server_reply} 00148.931998: ocur: ocur_init:408 : turning off verbose prints 00168.502708: ocur: [192.168.200.2] Get(fdc[0]): CarrierLock "1" 00170.298604: ocur: [192.168.200.2] Get(fdc[1]): CarrierLock "1" 00171.483279: ocur: [192.168.200.2] Get(fdc[2]): CarrierLock "1" 00173.262408: ocur: [192.168.200.2] Get(fdc[3]): CarrierLock "1" 00174.308680: ocur: [192.168.200.2] Get(fdc[0]): CarrierLock "1" 00174.416043: ocur: [192.168.200.2] Get(fdc[1]): CarrierLock "1" 00174.554889: ocur: [192.168.200.2] Get(fdc[2]): CarrierLock "1" 00174.699022: ocur: [192.168.200.2] Get(fdc[3]): CarrierLock "1" 00175.135303: ocur: [192.168.200.2] Get(fdc[0]): CarrierLock "1" 00175.188875: ocur: [192.168.200.2] Get(fdc[1]): CarrierLock "1" 00175.238854: ocur: [192.168.200.2] Get(fdc[2]): CarrierLock "1" 00175.288926: ocur: [192.168.200.2] Get(fdc[3]): CarrierLock "1" 00177.962404: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00177.963701: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00177.973711: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00177.974929: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00177.975710: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00177.983049: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00195.385832: ocur: [192.168.200.2] Calling Action(ua[2]) GetUserActivityInterval 00195.388179: ocur: [192.168.200.2] Action(ua[2]) GetUserActivityInterval success 00195.442503: ocur: [192.168.200.2] Calling Action(ua[2]) UserActivityDetected 00195.444276: ocur: [192.168.200.2] Action(ua[2]) UserActivityDetected success 00196.679595: ocur: [192.168.200.2] Calling Action(cm[2]) GetCurrentConnectionInfo 00196.686560: ocur: [192.168.200.2] Action(cm[2]) GetCurrentConnectionInfo success 00196.746749: ocur: [192.168.200.2] Calling Action(cm[2]) GetCurrentConnectionInfo 00196.754494: ocur: [192.168.200.2] Action(cm[2]) GetCurrentConnectionInfo success 00196.817031: ocur: [192.168.200.2] Calling Action(cm[2]) GetCurrentConnectionInfo 00196.823574: ocur: [192.168.200.2] Action(cm[2]) GetCurrentConnectionInfo success 00196.898073: ocur: [192.168.200.2] Calling Action(cm[2]) PrepareForConnection 00196.925983: ocur: Event(cm[2]): CurrentConnectionIDs, "0" 00196.944419: ocur: [192.168.200.2] Action(cm[2]) PrepareForConnection success 00197.013927: ocur: avtransport_rtsp_setup_callback:320 : [2] rtp setup for client 192.168.200.2:5001 00197.112746: ocur: [192.168.200.2] Calling Action(av[2]) Play 00197.138782: ocur: [192.168.200.2] Action(av[2]) Play success 00197.209864: ocur: [192.168.200.2] Calling Action(fdc[2]) RequestTables 00197.214723: ocur: [192.168.200.2] Action(fdc[2]) RequestTables success 00198.332364: ocur: [192.168.200.2] Calling Action(cas[2]) SetChannel 00198.333670: ocur: cas_SetChannel_impl:2681 : [2] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00198.339196: ocur: mux_SetProgramVariable:1779 : [2] Program number set to 0, was 1 00198.341697: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00198.342517: ocur: cas_hal_TuneChannel:3021 WARNING: [2] Channel 3 not found 00198.346242: ocur: [192.168.200.2] Action(cas[2]) SetChannel success 00198.456472: ocur: mux_pid_union:328 : [2] Adding pid 0x0000 00198.519640: ocur: mux_pid_union:328 : [2] Adding pid 0x1ffb 00198.584344: ocur: [192.168.200.2] Calling Action(fdc[2]) RequestTables 00198.589111: ocur: [192.168.200.2] Action(fdc[2]) RequestTables success 00198.652204: ocur: [192.168.200.2] Calling Action(ua[2]) SetCurrentTunerUseReason 00198.653324: ocur: user_activity_SetCurrentTunerUseReason_impl:58 : [2] UA: use_reason 2 TA: use_status 0 00198.655112: ocur: [192.168.200.2] Action(ua[2]) SetCurrentTunerUseReason success 00211.533876: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00211.535184: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00211.545234: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00211.546460: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00211.547252: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00211.558710: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00245.666457: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00245.667766: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00245.674686: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00245.675908: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00245.676700: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00245.701584: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00278.338693: ocur: debug_WriteStampFile:141 : STT time Tue Jun 25 21:43:36 2019 UTC 00282.948520: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00282.949831: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00283.086572: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00283.087791: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00283.088578: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00283.321838: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00336.186124: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00336.187432: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00336.512487: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00336.654014: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00336.655239: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00336.656030: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00388.882015: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00388.883316: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00388.891448: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00389.052083: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00389.053303: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00389.054093: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00413.375765: ocur: [192.168.200.2] Calling Action(ua[2]) UserActivityDetected 00413.377465: ocur: [192.168.200.2] Action(ua[2]) UserActivityDetected success 00414.559531: ocur: [192.168.200.2] Calling Action(fdc[2]) RequestTables 00414.703092: ocur: [192.168.200.2] Action(fdc[2]) RequestTables success 00415.474335: ocur: [192.168.200.2] Calling Action(fdc[2]) RequestTables 00415.475830: ocur: [192.168.200.2] Action(fdc[2]) RequestTables success 00423.084975: ocur: [192.168.200.2] Calling Action(av[2]) Stop 00423.086106: ocur: cas_SoftDisableVideo:2283 WARNING: [2] Disabling video 00423.086973: ocur: mux_SetProgramVariable:1779 : [2] Program number set to 0, was 0 00423.508589: ocur: [192.168.200.2] Action(av[2]) Stop success 00424.271197: ocur: avtransport_rtsp_teardown_callback:354 : [2] rtp teardown for client 192.168.200.2:5001 00424.689347: ocur: [192.168.200.2] Calling Action(cm[2]) ConnectionComplete 00425.095677: ocur: Event(cm[2]): CurrentConnectionIDs, "" 00425.096931: ocur: [192.168.200.2] Action(cm[2]) ConnectionComplete success 00430.621000: ocur: UpnpAdvertiseUntilSubscribed:3382 : Done sending rapid advertise 00436.763966: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00436.765264: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00436.771437: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00436.793703: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00436.794926: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00436.795713: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00452.342132: ocur: cas_hal_ServerQuery:3688 WARNING: server query timed out 00452.343106: ocur: cas_card_watchdog:456 WARNING: CableCARD watchdog query failed 00482.361146: ocur: cas_hal_ServerQuery:3688 WARNING: server query timed out 00482.362120: ocur: cas_card_watchdog:456 WARNING: CableCARD watchdog query failed 00483.894552: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00483.895852: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00483.901463: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00484.067432: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00484.068648: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00484.069426: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00504.314134: ocur: cas_card_watchdog:465 WARNING: Resetting watchdog count to 0 since query succeeded 00531.037117: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00531.038400: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00531.053070: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00531.063209: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00531.064425: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00531.065206: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00569.145971: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00569.147290: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00569.252520: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00569.263785: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00569.265009: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00569.265799: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00609.967833: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00609.969139: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00610.091457: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00610.114517: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00610.115736: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00610.116520: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00650.582937: ocur: [192.168.200.2] Calling Action(cas[0]) SetChannel 00650.584250: ocur: cas_SetChannel_impl:2681 : [0] Attempting to SetChannel (Channel=3 SourceId=0 Mode=0) 00650.611478: ocur: [192.168.200.2] Action(cas[0]) SetChannel success 00650.729840: ocur: mux_SetProgramVariable:1779 : [0] Program number set to 0, was 0 00650.745236: ocur: cas_cm_LookupChannel_By_Channel_SourceID:327 WARNING: No current channel map 00650.746033: ocur: cas_hal_TuneChannel:3021 WARNING: [0] Channel 3 not found 00733.278691: ocur: presentation_get_info:598 ERROR: Unable to open presentation file "/stream_request.cgi" (No such file or directory) 00733.281982: ocur: presentation_write:1505 ERROR: unknown write handle 00733.492740: ocur: presentation_get_info:598 ERROR: Unable to open presentation file "/stream_request.cgi" (No such file or directory) 00733.495061: ocur: presentation_write:1505 ERROR: unknown write handle 00733.624083: ocur: presentation_get_info:598 ERROR: Unable to open presentation file "/stream_request.cgi" (No such file or directory) 00733.626452: ocur: presentation_write:1505 ERROR: unknown write handle 00733.709027: ocur: presentation_get_info:598 ERROR: Unable to open presentation file "/stream_request.cgi" (No such file or directory) 00733.711896: ocur: presentation_write:1505 ERROR: unknown write handle 00912.390977: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -8.625000 snr 18.570000) 00913.931221: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -8.875000 snr 17.823000) 00915.493494: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -7.500000 snr 19.149000) 00957.121049: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 15.297000) 01086.551049: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 24.327000) 01225.431613: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 24.870001) 01304.007355: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 24.327000) 01327.111633: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 24.327000) 01495.121216: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.500000 snr 24.590000) 01583.201000: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.875000 snr 25.662001) 01660.431611: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 24.590000) 01666.591604: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 24.870001) 01793.316021: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.375000 snr 25.839001) 01885.961590: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 18.058001) 01935.441050: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 23.621000) 02031.191213: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 23.207001) 02049.751617: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 14.813000) 02366.641053: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.500000 snr 24.327000) 02520.972757: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 12.287000) 02568.851636: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 14.177000) 02650.861213: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 24.077999) 02655.471050: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 24.327000) 02695.681041: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.875000 snr 24.726999) 02894.972599: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 25.017000) 03304.034413: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 25.662001) 03385.701218: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.875000 snr 24.590000) 03436.571213: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 27.337000) 03570.780967: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.875000 snr 18.570000) 03647.851613: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 23.409000) 03758.813092: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 26.024000) 03775.741846: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 23.621000) 03794.241605: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 23.014000) 03811.221051: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 16.461000) 03890.084883: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 28.027000) 04001.074569: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 25.327000) 04148.961607: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 20.611000) 04219.881210: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 26.419001) 04354.431117: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.875000 snr 18.058001) 04385.301229: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 18.306999) 04456.511634: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 25.169001) 04552.421049: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 24.077999) 04553.961047: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 16.461000) 04581.760969: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 25.662001) 04645.122383: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 26.853001) 04784.271602: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 25.327000) 05054.706158: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 16.632000) 05142.722863: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 17.823000) 05196.800993: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.625000 snr 22.316999) 05546.171218: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -44.750000 snr 21.316999) 05592.571216: libcetontune: mxl241sf_cetontune_get_oob_locked:1305 : override oob lock (sl -48.750000 snr 23.843000) 05764.012135: ocur: sysinit_start_recovery_socket:364 : got reset network command 05764.013005: ocur: sysinit_set_network_settings:740 : default 1 dhcp 0 static 0 ip 192.168.200.1 netmask 255.255.255.0 05764.352133: ocur: sysinit_restart_network:256 : default 1 dhcp 0 static 0 ip 192.168.200.1 05764.358756: ocur: sysinit_restart_network:318 : ifconfig ctn0 192.168.200.1 05764.629686: libupnp: UpnpUpdateHostIP:4096 : new ip 192.168.200.1 05764.649128: ocur: init_tuner_htpc_mapping:26 WARNING: Could not open htpc mappings file 05764.649978: ocur: set_tuner_htpc_mapping:84 : Setting htpc mapping for instance 0 to "none" 05764.669335: ocur: set_tuner_htpc_mapping:84 : Setting htpc mapping for instance 1 to "none" 05764.684877: ocur: set_tuner_htpc_mapping:84 : Setting htpc mapping for instance 2 to "none" 05764.701970: ocur: set_tuner_htpc_mapping:84 : Setting htpc mapping for instance 3 to "none" 05764.717646: ocur: set_tuner_htpc_mapping:84 : Setting htpc mapping for instance 4 to "none" 05764.732983: ocur: set_tuner_htpc_mapping:84 : Setting htpc mapping for instance 5 to "none" 05793.004409: ocur: [192.168.200.2] Calling Action(cm[0]) GetProtocolInfo 05793.006752: ocur: [192.168.200.2] Action(cm[0]) GetProtocolInfo success 05794.684715: ocur: [192.168.200.2] Get(tuner[0]): ModulationList "QAM64,QAM-64,QAM256,QAM-256,NTSC,NTSC-M,8VSB,8-VSB" 05795.856863: ocur: [192.168.200.2] Calling Action(cm[2]) GetProtocolInfo 05795.859256: ocur: [192.168.200.2] Action(cm[2]) GetProtocolInfo success 05797.536485: ocur: [192.168.200.2] Get(tuner[2]): ModulationList "QAM64,QAM-64,QAM256,QAM-256,NTSC,NTSC-M,8VSB,8-VSB" 05798.863293: ocur: [192.168.200.2] Calling Action(cm[1]) GetProtocolInfo 05798.865684: ocur: [192.168.200.2] Action(cm[1]) GetProtocolInfo success 05800.802976: ocur: [192.168.200.2] Get(tuner[1]): ModulationList "QAM64,QAM-64,QAM256,QAM-256,NTSC,NTSC-M,8VSB,8-VSB" 05802.345021: ocur: [192.168.200.2] Calling Action(cm[3]) GetProtocolInfo 05802.347406: ocur: [192.168.200.2] Action(cm[3]) GetProtocolInfo success 05804.297538: ocur: [192.168.200.2] Get(tuner[3]): ModulationList "QAM64,QAM-64,QAM256,QAM-256,NTSC,NTSC-M,8VSB,8-VSB" 05812.664752: ocur: [192.168.200.2] Get(av[2]): AVTransportURI "rtsp://192.168.200.1:8554/cetonmpeg2" 05812.685984: ocur: [192.168.200.2] Get(av[3]): AVTransportURI "rtsp://192.168.200.1:8554/cetonmpeg3" 05812.692722: ocur: [192.168.200.2] Get(av[0]): AVTransportURI "rtsp://192.168.200.1:8554/cetonmpeg0" 05812.820749: ocur: [192.168.200.2] Get(av[1]): AVTransportURI "rtsp://192.168.200.1:8554/cetonmpeg1" 05812.925035: ocur: avtransport_rtsp_setup_callback:320 : [3] rtp setup for client 192.168.200.2:5001 05812.984510: ocur: avtransport_rtsp_setup_callback:320 : [2] rtp setup for client 192.168.200.2:5001 05813.171711: ocur: avtransport_rtsp_teardown_callback:354 : [2] rtp teardown for client 192.168.200.2:5001 05813.211187: ocur: avtransport_rtsp_setup_callback:320 : [0] rtp setup for client 192.168.200.2:5001 05813.246463: ocur: [192.168.200.2] Get(fdc[2]): CarrierLock "1" 05813.439706: ocur: [192.168.200.2] Calling Action(aux[2]) GetAuxCapabilities 05813.442487: ocur: [192.168.200.2] Action(aux[2]) GetAuxCapabilities success 05813.515220: ocur: [192.168.200.2] Get(fdc[2]): CarrierLock "1" 05813.525985: ocur: avtransport_rtsp_setup_callback:320 : [1] rtp setup for client 192.168.200.2:5001 05813.605927: ocur: avtransport_rtsp_teardown_callback:354 : [3] rtp teardown for client 192.168.200.2:5001 05813.616038: ocur: [192.168.200.2] Get(fdc[3]): CarrierLock "1" 05813.706037: ocur: [192.168.200.2] Calling Action(aux[3]) GetAuxCapabilities 05813.707990: ocur: [192.168.200.2] Action(aux[3]) GetAuxCapabilities success 05813.812455: ocur: [192.168.200.2] Get(fdc[0]): CarrierLock "1" 05813.822976: ocur: [192.168.200.2] Calling Action(wmdrm[2]) SetRevInfo 05813.842486: ocur: avtransport_rtsp_teardown_callback:354 : [0] rtp teardown for client 192.168.200.2:5001 05813.907857: ocur: [192.168.200.2] Calling Action(aux[0]) GetAuxCapabilities 05813.909808: ocur: [192.168.200.2] Action(aux[0]) GetAuxCapabilities success 05813.957810: ocur: [192.168.200.2] Get(fdc[1]): CarrierLock "1" 05814.009682: ocur: [192.168.200.2] Calling Action(aux[1]) GetAuxCapabilities 05814.021524: ocur: avtransport_rtsp_teardown_callback:354 : [1] rtp teardown for client 192.168.200.2:5001 05814.043057: ocur: [192.168.200.2] Action(aux[1]) GetAuxCapabilities success 05814.173387: ocur: [192.168.200.2] Get(fdc[1]): CarrierLock "1" 05814.202178: ocur: [192.168.200.2] Get(fdc[0]): CarrierLock "1" 05814.367993: ocur: [192.168.200.2] Calling Action(wmdrm[0]) SetRevInfo 05816.072314: ocur: [192.168.200.2] Action(wmdrm[0]) SetRevInfo success 05816.369321: ocur: [192.168.200.2] Calling Action(wmdrm[0]) SetCRL 05816.385140: ocur: [192.168.200.2] Calling Action(wmdrm[1]) SetRevInfo 05816.751630: ocur: [192.168.200.2] Action(wmdrm[2]) SetRevInfo success 05818.517810: ocur: [192.168.200.2] Action(wmdrm[1]) SetRevInfo success 05818.664527: ocur: [192.168.200.2] Calling Action(aux[1]) GetAuxCapabilities 05818.666450: ocur: [192.168.200.2] Action(aux[1]) GetAuxCapabilities success 05818.845151: ocur: [192.168.200.2] Action(wmdrm[0]) SetCRL success 05818.925584: ocur: [192.168.200.2] Calling Action(wmdrm[1]) SetCRL 05819.482027: ocur: [192.168.200.2] Action(wmdrm[1]) SetCRL success 05819.599461: ocur: [192.168.200.2] Calling Action(aux[2]) GetAuxCapabilities 05819.605542: ocur: [192.168.200.2] Calling Action(aux[0]) GetAuxCapabilities 05819.624604: ocur: [192.168.200.2] Action(aux[0]) GetAuxCapabilities success 05819.619932: ocur: [192.168.200.2] Get(fdc[3]): CarrierLock "1" 05819.681844: ocur: [192.168.200.2] Action(aux[2]) GetAuxCapabilities success 05819.767296: ocur: [192.168.200.2] Calling Action(wmdrm[3]) SetRevInfo 05819.829238: ocur: [192.168.200.2] Calling Action(wmdrm[1]) ProcessRegistrationChallenge 05819.849439: ocur: wmdrm_ProcessRegistrationChallenge_impl:1617 : [1.0] Closed existing registration session 05820.302760: ocur: [192.168.200.2] Action(wmdrm[3]) SetRevInfo success 05822.707734: ocur: wmdrm_ProcessRegistrationChallenge_impl:1712 : [1.0] We registered 05822.749468: ocur: [192.168.200.2] Action(wmdrm[1]) ProcessRegistrationChallenge success 05822.942380: ocur: [192.168.200.2] Get(fdc[1]): CarrierLock "1" 05822.981676: ocur: [192.168.200.2] Calling Action(wmdrm[3]) SetCRL 05823.063540: ocur: [192.168.200.2] Calling Action(wmdrm[2]) SetCRL 05823.091033: ocur: [192.168.200.2] Calling Action(wmdrm[0]) ProcessRegistrationChallenge 05823.130921: ocur: wmdrm_ProcessRegistrationChallenge_impl:1617 : [0.0] Closed existing registration session 05823.682962: ocur: [192.168.200.2] Action(wmdrm[3]) SetCRL success 05823.838520: ocur: [192.168.200.2] Calling Action(aux[3]) GetAuxCapabilities 05823.861485: ocur: [192.168.200.2] Action(aux[3]) GetAuxCapabilities success 05823.934949: ocur: [192.168.200.2] Action(wmdrm[2]) SetCRL success 05823.951824: ocur: [192.168.200.2] Calling Action(wmdrm[1]) ProcessLicenseChallenge 05826.579423: ocur: [192.168.200.2] Action(wmdrm[1]) ProcessLicenseChallenge success 05826.696033: ocur: [192.168.200.2] Calling Action(wmdrm[1]) AcknowledgeLicense 05826.697382: ocur: wmdrm_AcknowledgeLicense_impl:755 : [1.0] License Success Ack Received 05826.810925: ocur: [192.168.200.2] Action(wmdrm[1]) AcknowledgeLicense success 05826.897565: ocur: [192.168.200.2] Calling Action(wmdrm[2]) ProcessRegistrationChallenge 05826.906341: ocur: [192.168.200.2] Calling Action(wmdrm[3]) ProcessRegistrationChallenge 05828.062183: ocur: wmdrm_ProcessRegistrationChallenge_impl:1617 : [2.0] Closed existing registration session 05828.090965: ocur: wmdrm_ProcessRegistrationChallenge_impl:1712 : [0.0] We registered 05828.108240: ocur: [192.168.200.2] Action(wmdrm[0]) ProcessRegistrationChallenge success 05832.266152: ocur: wmdrm_ProcessRegistrationChallenge_impl:1617 : [3.0] Closed existing registration session 05832.290905: ocur: wmdrm_ProcessRegistrationChallenge_impl:1712 : [2.0] We registered 05832.301641: ocur: [192.168.200.2] Action(wmdrm[2]) ProcessRegistrationChallenge success 05832.469875: ocur: [192.168.200.2] Get(fdc[2]): CarrierLock "1" 05832.866890: ocur: [192.168.200.2] Calling Action(wmdrm[2]) ProcessLicenseChallenge 05836.828546: ocur: [192.168.200.2] Action(wmdrm[2]) ProcessLicenseChallenge success 05836.972094: ocur: [192.168.200.2] Calling Action(wmdrm[2]) AcknowledgeLicense 05836.973449: ocur: wmdrm_AcknowledgeLicense_impl:755 : [2.0] License Success Ack Received 05837.010917: ocur: [192.168.200.2] Action(wmdrm[2]) AcknowledgeLicense success 05837.884122: ocur: [192.168.200.2] Get(security[1]): HmsAssociationList "n5ByAAACcw5AAF+PAAAAAEYiuLcLCwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAsKpJZjs5QAqsNUT0G0bJax9cQGXlyzqUALFkZeEPKwyGAAAAAAAAAAAAAIawqklmOzlACqw1RPQbRslrCza+MWpm4ppuLoeflT3+64kAAAAAAAAAAAAAibCqSWY7OUAKrDVE9BtGyWvhchfkDnWuZxoy1agZWdMcjQAAAAAA" 05838.800958: ocur: wmdrm_ProcessRegistrationChallenge_impl:1712 : [3.0] We registered 05838.841846: ocur: [192.168.200.2] Action(wmdrm[3]) ProcessRegistrationChallenge success 05840.710458: ocur: [192.168.200.2] Get(security[2]): HmsAssociationList "n5ByAAACnw5AAF+PAAAAAEYiuLcMDAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAsKpJZjs5QAqsNUT0G0bJax9cQGXlyzqUALFkZeEPKwyGAAAAAAAAAAAAAIawqklmOzlACqw1RPQbRslrCza+MWpm4ppuLoeflT3+64kAAAAAAAAAAAAAibCqSWY7OUAKrDVE9BtGyWvhchfkDnWuZxoy1agZWdMcjQAAAAAA" 05841.068151: ocur: [192.168.200.2] Calling Action(wmdrm[3]) ProcessLicenseChallenge 05841.478431: ocur: [192.168.200.2] Calling Action(wmdrm[0]) ProcessLicenseChallenge 05843.657987: ocur: [192.168.200.2] Action(wmdrm[3]) ProcessLicenseChallenge success 05843.938057: ocur: [192.168.200.2] Action(wmdrm[0]) ProcessLicenseChallenge success 05844.053420: ocur: [192.168.200.2] Get(fdc[0]): CarrierLock "1" 05844.117424: ocur: [192.168.200.2] Get(fdc[3]): CarrierLock "1" 05844.139297: ocur: [192.168.200.2] Calling Action(wmdrm[0]) AcknowledgeLicense 05844.144196: ocur: wmdrm_AcknowledgeLicense_impl:755 : [0.0] License Success Ack Received 05844.170920: ocur: [192.168.200.2] Action(wmdrm[0]) AcknowledgeLicense success 05844.284707: ocur: [192.168.200.2] Calling Action(wmdrm[3]) AcknowledgeLicense 05844.286066: ocur: wmdrm_AcknowledgeLicense_impl:755 : [3.0] License Success Ack Received 05844.300980: ocur: [192.168.200.2] Action(wmdrm[3]) AcknowledgeLicense success 05848.451967: ocur: [192.168.200.2] Get(security[3]): HmsAssociationList "n5ByAAACnw5AAF+PAAAAAEYiuLcMDAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAsKpJZjs5QAqsNUT0G0bJax9cQGXlyzqUALFkZeEPKwyGAAAAAAAAAAAAAIawqklmOzlACqw1RPQbRslrCza+MWpm4ppuLoeflT3+64kAAAAAAAAAAAAAibCqSWY7OUAKrDVE9BtGyWvhchfkDnWuZxoy1agZWdMcjQAAAAAA" 05848.492923: ocur: [192.168.200.2] Get(security[0]): HmsAssociationList "n5ByAAACnw5AAF+PAAAAAEYiuLcMDAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAsKpJZjs5QAqsNUT0G0bJax9cQGXlyzqUALFkZeEPKwyGAAAAAAAAAAAAAIawqklmOzlACqw1RPQbRslrCza+MWpm4ppuLoeflT3+64kAAAAAAAAAAAAAibCqSWY7OUAKrDVE9BtGyWvhchfkDnWuZxoy1agZWdMcjQAAAAAA"