Loading dsp image: /lib/dspimage.ld DSP external memory mapped to 0x04724000 (User Sp) = 0x83E00000 (Kernel Sp) dimhw_init_dsp: dpr_base mapped to 0x03924000 (User sp) tiuo_hw_init, tcid 0, timeslot 1 tiuo_hw_init, tcid 1, timeslot 2 [INFO] [PACM.MTA_CONTROL(pid=325)]: PACM_MSMGetLoopVoltageStatusInit: Inform voice of voltage state Down [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - NCSDK Version: 2.7.0 [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - ROOT:Number of tcids in the system 2: 2: 2: 7 [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - MAS Version: 2.7.0(Build 51) [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - Following features compiled out of the build: [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_DNLD_PAGED_BOOT [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_DNLD_DIRECT [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_DNLD_MSG [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_DNLD_RST_DIRECT [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_CHAN_IF hw_config: tcid: 0 onhook volts = 48, offhook current = 26, country = 1 hw_config: tcid: 0 ringer type: 1 frequency: 20 amplitude: 66 offset: 0 Received request for gain settings for TCID: 0, rx = -4, tx = -2 hw_config: tcid: 1 onhook volts = 48, offhook current = 26, country = 1 hw_config: tcid: 1 ringer type: 1 frequency: 20 amplitude: 66 offset: 0 Received request for gain settings for TCID: 1, rx = -4, tx = -2 [ 1] Voice> FXS FXR = 16 Attempting to delete TCB: 4 XtDelete called lmxp_tcb_free called for 4 pcd: Rule VOICE_GGAPP: Success (Process /usr/sbin/ggncs (325)). [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - ANNC_IF [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_RTCP_IF [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_SIG_IF [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_AUDIO_IF [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_AFE_IF [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_LOMGR_GEN_FIFO [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_LOMGR_CHN_FIFO [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_LOMGR_MAIL_BOX [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - PROTO_AAL2 [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - PROTO_CLRDT pcd: Rule VOICE_LASTRULE: Success. [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - PROTO_MODEM [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_3PROC [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM_DETAILED_SPY [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - Following features not defined in build and have been enabled [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - by default; REVIEW to remove potential unecessary code: [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - All features are accounted for!!! [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - ISU: isu_module_init isu_event_base 0x0, task 0x00000000 [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - ISU: isu_create 0x00000008 queue 1 [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - CCU: ccu_module_init ccu_event_base 0x0, task 0x00000000 [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - CCU: ccu_create 0x0000000A queue 1 watchdog timer 2 [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM: status_request_period out of range [20 - 10000] [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - DIM: status_request_period set to default [1000] [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - TIU max tcids = 2, poll mode = 0, poll period = 5 [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - TIU: Polling period must be multiple of 2 msec [ERROR] [VOICE.XSPY(pid=325)]: 0000000726 - xSPU: init xgcpif error, can't continue [INFO] [ARRIS.SYS(pid=325)]: Arris PacketCable Initialization Start [INFO] [ARRIS.INIT(pid=325)]: LC_init process [INFO] [PACM.MTA_CONTROL(pid=325)]: PACM_MSMGetLoopVoltageStatusInit: Inform voice of voltage state Down [INFO] [PACM.MTA_CONTROL(pid=325)]: PACM_MSMGetLoopVoltageStatusInit: Inform voice of voltage state Down [INFO] [PACM.MTA_CONTROL(pid=325)]: PACM_MSMGetLoopVoltageStatusInit: Inform voice of voltage state Down [INFO] [PACM.MTA_CONTROL(pid=325)]: PACM_MSMGetLoopVoltageStatusInit: Inform voice of voltage state Down [INFO] [ARRIS.SYS(pid=325)]: Arris PacketCable Initialization Done [INFO] [ARRIS.INIT(pid=325)]: LC task started [INFO] [ARRIS.INIT(pid=325)]: LC init complete, starting TOS [INFO] [ARRIS.INIT(pid=325)]: LCMSG task started [ERROR] [VOICE.XSPY(pid=325)]: 0000000769 - ROOT: VOIM_FE initialized [INFO] [PACM.MTA_CONTROL(pid=325)]: PACM_MSMGetLoopVoltageStatusInit: Inform voice of voltage state Down [INFO] [PACM.MTA_CONTROL(pid=325)]: PACM_MSMGetLoopVoltageStatusInit: Inform voice of voltage state Down [ERROR] [VOICE.XSPY(pid=325)]: 0000000774 - DIM: 0:*, dimp_find_and_init_lo_mgr(). max simple msg len (128) < sizeof(mgb_t)(130) [INFO] [PACM.VOIM(pid=304)]: VoIM was initiated succesfully with ID 2054 pcd: Rule PACM_SNMP: Success (Process /usr/sbin/pacm_snmp_agent (304)). pcd: Rule PACM_INITDONE: Success. pcd: Starting process /usr/sbin/vendor_psm (Rule PACM_APPPSM). pcd: Starting process /usr/sbin/pacm_mta_control (Rule PACM_MTACTRL). pcd: Rule PACM_MTACTRL: Success (Process /usr/sbin/pacm_mta_control (349)). pcd: Rule PACM_APPPSM: Success (Process /usr/sbin/vendor_psm (348)). pcd: Rule PACM_LASTRULE: Success. pcd: Warning: Got READY event, but rule end condition is different. PCD API: ICC wait return value -768 [WARNING] [PACM.VENDOR_APP(pid=348)]: DDR is not in Async mode, clock reduction will not be performed [INFO] [PACM.MTA_CONTROL(pid=349)]: starting main of PACM MSM..... [INFO] [PACM.VOIM(pid=349)]: VoIM was initiated succesfully with ID 2055 [INFO] [PACM.MTA_CONTROL(pid=349)]: Starting TI_PACM_MODULE_MSM [INFO] [PACM.MTA_CONTROL(pid=349)]: Setting IPv6 Support to docsis - False [INFO] [PACM.MTA_CONTROL(pid=303)]: send response message ID 0 [INFO] [PACM.MTA_CONTROL(pid=349)]: BBU system not supported [INFO] [PACM.MTA_CONTROL(pid=349)]: LOOPV: Setting loop voltage status OFF [ERROR] [VOICE.XSPY(pid=325)]: 0000001000 - DIM: , CHECKSUM=31511 [ERROR] [VOICE.XSPY(pid=325)]: 0000001001 - DIM: 0:*, Core Download complete! [ERROR] [VOICE.XSPY(pid=325)]: 0000001004 - DIM: 0:*, dimp_find_and_init_lo_mgr(). max simple msg len (128) < sizeof(mgb_t)(130) [ERROR] [VOICE.XSPY(pid=325)]: 0000001006 - DSPA: DSP 0,Image 0:Download done! [INFO] [PACM.SNMP(pid=304)]: Setting Voice default configuration [INFO] [PACM.SNMP(pid=304)]: Done Setting Voice default configuration, sending event MSM_ev_DefaultsSetted [INFO] [PACM.MTA_CONTROL(pid=304)]: Sending Event MSM_ev_ConfigureDone, SNMP is ready. [INFO] [PACM.VOIM(pid=349)]: Waiting until Voice init finishes [INFO] [PACM.VOIM(pid=349)]: Voice Init done [INFO] [PACM.MTA_CONTROL(pid=349)]: Starting MSM..... [INFO] [PACM.MTA_CONTROL(pid=349)]: enter MSM_act_StartCM [INFO] [DOCSIS.CHM(pid=265)]: Init 8 DOCSIS DS channels [INFO] [DOCSIS.CHM(pid=265)]: Init 4 US channels [INFO] [DOCSIS.FREQ_SCAN(pid=265)]: [INFO] [DOCSIS.FREQ_SCAN(pid=265)]: *** CM SYNCHRONIZING... *** [INFO] [DOCSIS.FREQ_SCAN(pid=265)]: [INFO] [ARRIS.RF_SCAN(pid=265)]: ----> NB Scanning 603000000 Hz [INFO] [ARRIS.RF_SCAN(pid=265)]: --------> Tuner 0 moved to 603000000 Hz (96000000 CBW) [INFO] [DOCSIS.DS(pid=281)]: DS[1]: Try to lock on primary DS 603000000Hz... [WARNING] [DOCSIS.CHDB_RX(pid=281)]: Could not find DCID for freq 0 (port 1) [WARNING] [DOCSIS.DS(pid=281)]: Failed to Find DCID for DS Port 1. [INFO] [DOCSIS.HAL(pid=281)]: 1 Passed Qam Lock. [INFO] [DOCSIS.HAL(pid=281)]: 1 Passed FEC Lock. [INFO] [DOCSIS.HAL(pid=281)]: 1 Passed Mpeg Lock. [INFO] [DOCSIS.HAL(pid=281)]: 1 Completed successfully. [INFO] [DOCSIS.DS(pid=281)]: DS[1]: Locked on primary DS 603000000Hz. [INFO] [PACM.MTA_CONTROL(pid=349)]: Loop Voltage: QAM signal Regained [WARNING] [DOCSIS.DS(pid=281)]: Got SYNC-SA [00:00:ca:ff:7d:c6] but the MDD filter is disabled! [INFO] [DOCSIS.FREQ_SCAN(pid=265)]: MDD Not received on primary DS 603000000Hz. [INFO] [DOCSIS.DS(pid=281)]: DS[1]: MDD Lost - No MDD received for 6 sec. [INFO] [DOCSIS.UCD(pid=250)]: US[1] [UCID All]: UCD Collect on DS[1]... [WARNING] [DOCSIS.CHDB_RX(pid=250)]: Could not find DCID for freq 603000000 (port 1) [INFO] [ARRIS.TLM(pid=261)]: TLM upsAlarm: UPS Output Off [INFO] [ARRIS.TLM(pid=261)]: TLM upsAlarm: Battery Missing [INFO] [ARRIS.TLM(pid=261)]: TLM Log: BATTERY MISSING [INFO] [ARRIS.TLM(pid=261)]: TLM Console Log: Battery Missing [INFO] [ARRIS.TLM(pid=261)]: TLM: cal inited to 0xfc sec [INFO] [DOCSIS.UCD(pid=250)]: US[1] [UCID All]: 1 UCDs Found; 1 UCDs ordered [UCIDs: 1 0 0 0 0 0 0 0]. [INFO] [DOCSIS.US(pid=265)]: US[1] [UCID 1]: Start Ranging [sid 0] [tech 0]... [INFO] [DOCSIS.US(pid=292)]: startData.txAttr.powerOffset = 0xbe (47), startData.txAttr.freqOffset = 0x0 [INFO] [DOCSIS.US(pid=292)]: US[1] [UCID 1]: RNG-RSP CONTINUE. [INFO] [DOCSIS.US(pid=292)]: US[1] [UCID 1]: RNG-RSP SUCCESS. pcd: Starting process /usr/sbin/dmg_provisioning (Rule DOCSIS_DMGPROV). pcd: Rule DOCSIS_DMGPROV: Success (Process /usr/sbin/dmg_provisioning (351)). [INFO] [DOCSIS.PROVISIONING(pid=351)]: [INFO] [DOCSIS.PROVISIONING(pid=351)]: *** CM PROVISIONING... *** [INFO] [DOCSIS.PROVISIONING(pid=351)]: [INFO] [DOCSIS.PROVISIONING(pid=351)]: EAE Disabled. [INFO] [DOCSIS.IPP(pid=351)]: ------------------------------------------------------- [INFO] [DOCSIS.IPP(pid=351)]: IP provisioning start in the IP_PROV_V4_ONLY mode [INFO] [DOCSIS.IPP(pid=351)]: ------------------------------------------------------- pcd: Starting process /sbin/ti_udhcpc (Rule DOCSIS_DHCPV4). pcd: Rule DOCSIS_DHCPV4: Success (Process /sbin/ti_udhcpc (352)). [eth0] debug, default_plugin_init [eth0] info, Plugin UDHCPC Default registered successfully [wan0] info, Plugin Sample registered successfully [wan0] info, TI udhcp client (v1.0) started [wan0] info, TI udhcp client read_interface, udhcp_client_config.ifindex = 9 [wan0] debug, entering raw listen mode [INFO] [PACM.DOIM(pid=307)]: DOIM received DHCP_START [wan0] debug, Sending discover... [wan0] debug, found a plugin option Message type = 2 [INFO] [PACM.DOIM(pid=307)]: DOIM received DHCP_CHECK_PKT_OPTION stage 1 from DHCPv4 [INFO] [PACM.DOIM(pid=307)]: DHCP 122 suboption found and valid [INFO] [PACM.DOIM(pid=307)]: DHCP 122 suboption found and valid [INFO] [PACM.DOIM(pid=307)]: DOIM reply prepared option 0 [wan0] debug, Sending select for 10.80.117.21... [wan0] debug, found a plugin option SNMPA_CreateSocketEntry : type 1, addr = a507515, port = 161, ifname = wan0 List = 0x68860 SNMPA_CreateSocketEntry : Entry = 0x68DB0 SNMPA_CreateSocketEntry : type 1, addr = a507515, port = 162, ifname = wan0 List = 0x68860 SNMPA_CreateSocketEntry : Entry = 0x68E08 Message type = 5 [wan0] info, No DHCP_T2 option, by default T2=lease * 0.875 [wan0] debug, DHCP_T2 selected=75600 [wan0] info, No DHCP_T1 option, by default T1=lease/2 [wan0] debug, entering none listen mode [INFO] [PACM.DOIM(pid=307)]: DOIM received DHCP_CHECK_PKT_OPTION stage 2 from DHCPv4 [INFO] [PACM.DOIM(pid=307)]: DHCP 122 suboption found and valid [INFO] [PACM.DOIM(pid=307)]: DHCP 122 suboption found and valid [INFO] [DOCSIS.IPP(pid=352)]: [DHCP4_PLG]: Set to the wan0 addr: 10.80.117.21 mask: 255.255.255.0 router: 10.80.117.62 [INFO] [DOCSIS.UTILS(pid=352)]: 10.80.117.21 [INFO] [DOCSIS.UTILS(pid=352)]: 10.80.117.31 [INFO] [DOCSIS.UTILS(pid=352)]: 10.80.117.31 [INFO] [DOCSIS.UTILS(pid=352)]: 10.80.117.62 [INFO] [DOCSIS.UTILS(pid=352)]: 10.80.117.31 [INFO] [DOCSIS.UTILS(pid=352)]: 10.80.117.32 [INFO] [DOCSIS.UTILS(pid=351)]: 10.80.117.31 [INFO] [DOCSIS.UTILS(pid=351)]: 10.80.117.31 Info, default_plugin_init Info, Plugin TI_TODC Default registered successfully Info, Plugin libdocsis_todplg.so registered successfully TI ToD client (v1.0) started Info, EVENT:startup Info, Curr time from 10.80.117.31: Wed May 25 02:46:34 2011 Info, EVENT:Successfully retrieved time from TOD Server [INFO] [DOCSIS.PROV(pid=356)]: DOCSIS provisioning Got SIGCHLD, from pid = -1 [INFO] [DOCSIS.PROV(pid=351)]: DOCSIS provisioning Got SIGCHLD, from pid = 356 [INFO] [PACM.MTA_CONTROL(pid=349)]: CM sent event TOD achieved [INFO] [PACM.MTA_CONTROL(pid=304)]: Sending Event MSM_ev_ConfigureDone, SNMP is ready. [INFO] [DOCSIS.IPP(pid=357)]: ========================================= getting from 10.80.117.32:CM_arris_1.cfg to CM_arris_1.cfg [octet] [INFO] [DOCSIS.IPP(pid=357)]: [TOD_PLG]: Was revceived time Wed May 25 10:46:34 2011 from ToD server 10.80.117.31, timezone =28800 [INFO] [DOCSIS.IPP(pid=357)]: ========================================= [INFO] [DOCSIS.IPP(pid=351)]: Try 1 to download configuration file [CM_arris_1.cfg] from TFTP server [10.80.117.32]... SIZE set to: 1448 Received 116 bytes in 0.0 seconds [inf bits/sec] [INFO] [DOCSIS.PROV(pid=358)]: DOCSIS provisioning Got SIGCHLD, from pid = -1 [INFO] [DOCSIS.PROV(pid=351)]: DOCSIS provisioning Got SIGCHLD, from pid = 358 [INFO] [DOCSIS.IPP(pid=351)]: Configuration file [CM_arris_1.cfg] downloaded from TFTP server [10.80.117.32]. [ENTER] [DOCSIS.CFG_PARSER(pid=351)]: cfgfParserInit [ENTER] [DOCSIS.CFG_PARSER(pid=351)]: [performFirstPass(in)] [EXIT] [DOCSIS.CFG_PARSER(pid=351)]: [performFirstPass(out)] [ENTER] [DOCSIS.CFG_PARSER(pid=351)]: [verifyConfigFile(in)] [EXIT] [DOCSIS.CFG_PARSER(pid=351)]: [verifyConfigFile(out)] [ENTER] [DOCSIS.CFG_PARSER(pid=351)]: [resetDBs(in)] [EXIT] [DOCSIS.CFG_PARSER(pid=351)]: [resetDBs(out)] [INFO] [DOCSIS.CFG_PARSER(pid=351)]: Configuration file processing complete (status = 0). [INFO] [DOCSIS.CFG_PARSER(pid=351)]: Configuration file: Saved to NVRAM vendorClassId = 0 [INFO] [DOCSIS.IPP(pid=351)]: [INFO] [DOCSIS.IPP(pid=351)]: ********************************************************** [INFO] [DOCSIS.IPP(pid=351)]: ********************************************************** [INFO] [DOCSIS.IPP(pid=351)]: ** ** [INFO] [DOCSIS.IPP(pid=351)]: ** IP PROVISIONING FINISHED SUCCESSFULLY ** [INFO] [DOCSIS.IPP(pid=351)]: ** ------------------------------------- ** [INFO] [DOCSIS.IPP(pid=351)]: ** ** [INFO] [DOCSIS.IPP(pid=351)]: ********************************************************** [INFO] [DOCSIS.IPP(pid=351)]: ********************************************************** [INFO] [DOCSIS.IPP(pid=351)]: [INFO] [DOCSIS.REGISTRATION(pid=351)]: [INFO] [DOCSIS.REGISTRATION(pid=351)]: *** CM REGISTRATION... *** [INFO] [DOCSIS.REGISTRATION(pid=351)]: [INFO] [DOCSIS.REGISTRATION(pid=351)]: REG-REQ sent. [INFO] [DOCSIS.REGISTRATION(pid=250)]: REG-RSP received [CMTS Response 0]. [INFO] [DOCSIS.REGISTRATION(pid=250)]: Got MDF Support Mode 0 in REG-RSP [INFO] [DOCSIS.REGISTRATION(pid=351)]: pt3.RegAck not required [INFO] [DOCSIS.SNMP(pid=263)]: SNMP: Working in SNMP without any access mode!!!!! [INFO] [DOCSIS.DMG(pid=296)]: BPI Disabled. [WARNING] [DOCSIS.SWDL(pid=296)]: EFL could not find a usable entry info, DHCP Server state toggled to 0 error, Error on select [INFO] [PACM.MTA_CONTROL(pid=349)]: Docsis in IPv4 [INFO] [PACM.MTA_CONTROL(pid=349)]: Valid IPv4 DHCP server for MTA Provisioning [INFO] [PACM.MTA_CONTROL(pid=349)]: setting IPv4 DHCP servers: dhcp1:10.80.117.31, dhcp2:10.80.117.31 [INFO] [PACM.DHCP(pid=349)]: Initiator: PACM DHCP IP mode 1 process State 0 [INFO] [PACM.PROVISION(pid=349)]: Starting DHCP module with parameters: interface: mta0, backoff: 0 [INFO] [PACM.DHCP(pid=349)]: Initiator: Init [INFO] [PACM.DHCP(pid=349)]: DhcpInitiator_Init: entry point [INFO] [PACM.DHCP(pid=349)]: DhcpInitiator_Init: init DB [INFO] [PACM.DHCP(pid=349)]: DhcpInitiator_Init: init shared config [INFO] [PACM.DHCP(pid=349)]: DhcpInitiator_Init: Success [INFO] [PACM.DHCP(pid=349)]: Initiator: Spawn DHCP [INFO] [PACM.DHCP(pid=349)]: Initiator: Spawned DHCPv4 Process Success pcd: Starting process /sbin/ti_udhcpc (Rule PACM_DHCP). pcd: Rule PACM_DHCP: Success (Process /sbin/ti_udhcpc (362)). [eth0] debug, default_plugin_init [eth0] info, Plugin UDHCPC Default registered successfully [mta0] info, Plugin PacmProv registered successfully [mta0] info, TI udhcp client (v1.0) started [mta0] info, TI udhcp client read_interface, udhcp_client_config.ifindex = 11 [mta0] debug, entering raw listen mode [INFO] [PACM.VOIM(pid=362)]: VoIM was initiated succesfully with ID 2052 [INFO] [PACM.DHCP(pid=362)]: Vendor DHCP PLUG IN Disabled [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: got startup event (curr state 0, new state 0) [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: Using TI implementation of option 43 [mta0] debug, Sending discover... [mta0] debug, found a plugin option Message type = 2 [mta0] error, Plugin rejected Config [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Got OFFER [INFO] [PACM.DHCP(pid=362)]: DHCP : Calling Option 122 parser [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Received prov server fqdn address type [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: rejecting offer that does not match strongest flow (1 retries) [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: Rejecting offer (rc = -1) [INFO] [DOCSIS.DMG(pid=296)]: [INFO] [DOCSIS.DMG(pid=296)]: *** INITIALIZATION COMPLETE - MODEM IS OPERATIONAL *** [INFO] [DOCSIS.DMG(pid=296)]: [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: Using TI implementation of option 43 [mta0] debug, Sending discover... [mta0] debug, found a plugin option Message type = 2 [mta0] error, Plugin rejected Config [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Got OFFER [INFO] [PACM.DHCP(pid=362)]: DHCP : Calling Option 122 parser [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Received prov server fqdn address type [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: rejecting offer that does not match strongest flow (2 retries) [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: Rejecting offer (rc = -1) [mta0] debug, Sending discover... [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: Using TI implementation of option 43 [mta0] debug, found a plugin option Message type = 2 [mta0] error, Plugin rejected Config [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Got OFFER [INFO] [PACM.DHCP(pid=362)]: DHCP : Calling Option 122 parser [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Received prov server fqdn address type [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: rejecting offer that does not match strongest flow (3 retries) [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: Rejecting offer (rc = -1) [mta0] debug, Sending discover... [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: Using TI implementation of option 43 [mta0] debug, found a plugin option Message type = 2 [mta0] debug, Sending select for 10.80.117.22... [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Got OFFER [INFO] [PACM.DHCP(pid=362)]: DHCP : Calling Option 122 parser [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Received prov server fqdn address type [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: got Got Offer from Server event (curr state 0, new state 3) [WARNING] [PACM.DHCP(pid=362)]: DHCP plugin: Using TI implementation of option 43 [mta0] debug, found a plugin option Message type = 5 [mta0] info, No DHCP_T2 option, by default T2=lease * 0.875 [mta0] debug, DHCP_T2 selected=75600 [mta0] info, No DHCP_T1 option, by default T1=lease/2 [mta0] debug, entering none listen mode SNMPA_CreateSocketEntry : type 1, addr = a507516, port = 161, ifname = mta0 List = 0x6a9a0 SNMPA_CreateSocketEntry : Entry = 0x6B6C0 SNMPA_CreateSocketEntry : type 1, addr = a507516, port = 162, ifname = mta0 List = 0x6a9a0 SNMPA_CreateSocketEntry : Entry = 0x6B4E0 ti_api (ti_dns_start_query_scheduler): Starting RULI scheduler [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Got ACK [INFO] [PACM.DHCP(pid=362)]: DHCP : Calling Option 122 parser [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Received prov server fqdn address type [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Setting device - ip address 10.80.117.22 [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Setting device - subnet mask 255.255.255.0 [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: Setting device - Adding route 10.80.117.62 [INFO] [PACM.PROVISION(pid=362)]: send DHCP_ev_AckOK event [INFO] [PACM.DHCP(pid=362)]: DHCP plugin: got Got ACK from Server event (curr state 1, new state 2) [INFO] [PACM.PROVISION(pid=303)]: MTA Supports flows 0x7, ctrlRsp->flow = 0 [INFO] [PACM.PROVISION(pid=303)]: send Ctrl_ev_FlowSelect event. retuen STATUS_OK [INFO] [PACM.MTA_CONTROL(pid=303)]: send response message ID 3 [INFO] [PACM.PROVISION(pid=349)]: Setting SNMP socket on address 10.80.117.22 port 161 device mta0 [INFO] [PACM.SECURITY(pid=305)]: SecInitProcessOnReset, first time [INFO] [PACM.IPSEC(pid=305)]: IPSec module starting [INFO] [PACM.IPSEC(pid=305)]: Creating inbound socket [INFO] [PACM.IPSEC(pid=305)]: Registering inbound socket with kernel [INFO] [PACM.IPSEC(pid=305)]: Creating outbound socket [INFO] [PACM.IPSEC(pid=305)]: Initializing SPDB adaptor [INFO] [PACM.IPSEC(pid=305)]: Initializing SADB adaptor [WARNING] [PACM.IPSEC(pid=305)]: No default policy added [INFO] [PACM.IPSEC(pid=305)]: IPSec init done [INFO] [PACM.SECURITY(pid=305)]: Init IPSEC succeeded [INFO] [PACM.SECURITY(pid=305)]: Add default IPsec policy for MTA NCS port [INFO] [PACM.SECURITY(pid=305)]: Adding OUT default NCS ipsec policy [INFO] [PACM.IPSEC(pid=305)]: Policy added successfully [INFO] [PACM.SECURITY(pid=305)]: Adding IN SP [INFO] [PACM.IPSEC(pid=305)]: Policy added successfully [INFO] [PACM.SECURITY(pid=305)]: Add IPSEC socket [INFO] [PACM.SECURITY(pid=305)]: SecMtaInfoInit SNMP entity pactprov.pclab.com [INFO] [PACM.SECURITY(pid=305)]: Socket bind succeeded port 1293 socket 8 [INFO] [PACM.SECURITY(pid=305)]: Succeeded to get socket 8 port 1293 [INFO] [PACM.SECURITY(pid=305)]: SecInitProcessOnReset done [INFO] [PACM.PROVISION(pid=349)]: provisioning timer: Flag = FALSE, Timer = 10 pcd: Starting process /sbin/ti_tftp (Rule PACM_TFTP). [INFO] [PACM.PROVISION(pid=349)]: activate provisioning timer = 10 min [INFO] [PACM.SECURITY(pid=305)]: Invalidate tickets mask 0 [INFO] [PACM.SECURITY(pid=305)]: No tickets need to be invalidated [INFO] [PACM.PROVISION(pid=349)]: reset prov server ip [INFO] [PACM.PROVISION(pid=349)]: prov Server Reset Db Params success [INFO] [PACM.DNS_UTIL(pid=349)]: Initiate DNS resolution for name pactprov.pclab.com (isSrv=0, waitForRes=0) [INFO] [PACM.DNS_UTIL(pid=349)]: Waiting for DNS resolution of server (pactprov.pclab.com) [INFO] [PACM.PROVISION(pid=349)]: waiting for DNS resolution of provisioning server (server=pactprov.pclab.com) [INFO] [COMMON_COMPONENTS.EVENT_MNGR(pid=306)]: Opening SNMP service [INFO] [PACM.DNS_UTIL(pid=349)]: received DNS response...parsing [INFO] [PACM.DNS_UTIL(pid=349)]: Ret from parse_hostname_answer: (0)Success sizeof addr_list: 1 [INFO] [PACM.DNS_UTIL(pid=349)]: DNS query completed [INFO] [PACM.PROVISION(pid=349)]: current time = 1306320423 [INFO] [PACM.PROVISION(pid=349)]: RULI found IP: 10.80.117.31 [INFO] [PACM.PROVISION(pid=349)]: TTL: 86400 [INFO] [PACM.PROVISION(pid=349)]: Provisioning Server DNS query completed, send success event... [INFO] [PACM.SNMP(pid=304)]: PACM_SnmpCreateDefEntries is called [INFO] [PACM.SNMP(pid=304)]: adding default target to SNMPv2 DB [INFO] [PACM.SNMP(pid=304)]: SnmpDB_AddTarget: PACM_SNMP_INFORM_LIST index = 0 [INFO] [PACM.PROVISION(pid=349)]: SNMPA_CREATE_DEF_ENTRIES returned with status 0 [INFO] [PACM.PROVISION(pid=349)]: Proceeding with BASIC flow [INFO] [PACM.PROVISION(pid=349)]: start TFTP transfer from 10.80.117.32, of file MTA_arris_1.bin [INFO] [PACM.CFM(pid=349)]: Spawned ti_tftp client. Received 520 bytes in 0.0 seconds Loop Voltage -> ON Failed creating VB List pcd: Rule PACM_TFTP: Success (Process /sbin/ti_tftp (369)). [INFO] [PACM.PROVISION(pid=349)]: start TFTP COMMIT [INFO] [PACM.CFM(pid=349)]: Reading file [INFO] [PACM.CFM(pid=349)]: Opened local file MTA_arris_1.bin [INFO] [PACM.CFM(pid=349)]: Read 520 bytes [INFO] [PACM.CFM(pid=349)]: Authenticating file [INFO] [PACM.CFM(pid=349)]: Getting digest from file. [ERROR] [COMMON_COMPONENTS.TLV_PARSER(pid=349)]: 1st pass PARSER_UNKNOWNN_TYPE_TWO_BYTE_LEN - unknown type ptr 1fcb9 [ERROR] [COMMON_COMPONENTS.TLV_PARSER(pid=349)]: 1st pass PARSER_UNKNOWNN_TYPE_TWO_BYTE_LEN - unknown type ptr 1fcbc [ERROR] [COMMON_COMPONENTS.TLV_PARSER(pid=349)]: 1st pass PARSER_UNKNOWNN_TYPE_TWO_BYTE_LEN - unknown type ptr 1febe [INFO] [COMMON_COMPONENTS.TLV_PARSER(pid=349)]: PARSER_UNKNOWNN_TYPE_TWO_BYTE_LEN - unknown type ptr 1fcb9 [INFO] [COMMON_COMPONENTS.TLV_PARSER(pid=349)]: PARSER_UNKNOWNN_TYPE_TWO_BYTE_LEN - unknown type ptr 1fcbc [INFO] [COMMON_COMPONENTS.TLV_PARSER(pid=349)]: PARSER_UNKNOWNN_TYPE_TWO_BYTE_LEN - unknown type ptr 1febe [INFO] [PACM.CFM(pid=349)]: Checking Hash [INFO] [PACM.PROVISION(pid=349)]: configuration file integrity verified [INFO] [PACM.PROVISION(pid=349)]: TFTP File Commit - check file structure [INFO] [PACM.CFM(pid=349)]: CFM_ParameterParserStart: enter to TlvParseExtended [WARNING] [PACM.CFM(pid=349)]: fail parsing TLV43, Unknown subtype TLV69 [INFO] [PACM.CFM(pid=349)]: CFM_ParameterParserStart: TlvParseExtended finished [INFO] [PACM.CFM(pid=349)]: CFM_ParameterParserStart: num 254 valid [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.3.0) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.3.0 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.4.0) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.4.0 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.5.0) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.5.0 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.6.0) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.6.0 value=(null) reason=Unsupported OID [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.1.3.3.1.2.3.6.0 value=7 reason=WRONG_VALUE [WARNING] [PACM.PROVISION(pid=304)]: added Error OID 7/Unsatisfied dependency / WRONG_VALUE (1.3.6.1.4.1.4115.1.3.3.1.2.3.6.0) [WARNING] [PACM.CFM(pid=349)]: SNMPAIF_SetTLV11Config failed in parsing TLV11 block (status = -1) [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.8.0) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.8.0 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.9.0) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.9.0 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.1.1.2.1) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.1.1.2.1 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.1.1.3.1) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.1.1.3.1 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.1.1.4.1) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.1.1.4.1 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.1.1.5.1) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.1.1.5.1 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.1.1.2.2) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.1.1.2.2 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.1.1.3.2) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.1.1.3.2 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.1.1.4.2) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.1.1.4.2 value=(null) reason=Unsupported OID [WARNING] [PACM.PROVISION(pid=304)]: added Error OID (null)/Unsupported OID (1.3.6.1.4.1.4115.11.1.1.1.5.2) [INFO] [PACM.SNMP(pid=304)]: Populate Error OID 1.3.6.1.4.1.4115.11.1.1.1.5.2 value=(null) reason=Unsupported OID [WARNING] [PACM.CFM(pid=349)]: provStat != CFM OK. setting return code to pass with warning [ERROR] [PACM.PROVISION(pid=349)]: error in configuration file, error 1 [ERROR] [PACM.PROVISION(pid=349)]: error in optional parameters...continue [INFO] [PACM.PROVISION(pid=349)]: TFTP File Commit - check DB parameters [INFO] [PACM.CFM(pid=349)]: Endpoint 0 was not configures to be up - skipping [INFO] [PACM.CFM(pid=349)]: Endpoint 1 was not configures to be up - skipping [INFO] [PACM.CFM(pid=349)]: Conf file final tests succeed [INFO] [PACM.PROVISION(pid=349)]: start TFTP CLEANUP [INFO] [PACM.CFM(pid=349)]: cleaning up... [WARNING] [PACM.CFM(pid=349)]: SHA1_freeCS: TBD - clear cypto information after use [INFO] [PACM.MTA_CONTROL(pid=349)]: prov timer flag = TRUE [INFO] [PACM.MTA_CONTROL(pid=349)]: turning down prov timer [INFO] [PACM.MTA_CONTROL(pid=349)]: LOOPV: Setting loop voltage status ON [INFO] [PACM.MTA_CONTROL(pid=349)]: ************************************************* [INFO] [PACM.MTA_CONTROL(pid=349)]: ************************************************* [INFO] [PACM.MTA_CONTROL(pid=349)]: PC PROVISIONING SUCCEEDED, BUT PROBLEMS ENCOUNTERED. STATUS: PassWithWarnings [INFO] [PACM.MTA_CONTROL(pid=349)]: ************************************************* [INFO] [PACM.MTA_CONTROL(pid=349)]: ************************************************* [INFO] [PACM.MTA_CONTROL(pid=349)]: MTA 24 - PROV_COMPLETE_WARNINGS [WARNING] [COMMON_COMPONENTS.EVENT_MNGR(pid=306)]: Unknown specific event 90015 [INFO] [PACM.SNMP(pid=304)]: pk_mdb_DevEvLevel_get: success [ERROR] [PACM.SNMP(pid=304)]: Failed to bind endpoint name [INFO] [PACM.SNMP(pid=304)]: pk_mdb_DevEvLevel_get: success [INFO] [PACM.SNMP(pid=304)]: Success building vbl [INFO] [PACM.SNMP(pid=304)]: pk_mdb_DevEvLevel_get: success [INFO] [PACM.SNMP(pid=304)]: Success building vbl [INFO] [PACM.SNMP(pid=304)]: Snmp Inform Ack Handler [INFO] [PACM.SNMP(pid=304)]: Snmp Inform Ack Handler [INFO] [ARRIS.TLM(pid=261)]: TLM Log: BATTERY MISSING [INFO] [PACM.SNMP(pid=304)]: pk_mdb_DevEvLevel_get: success [INFO] [PACM.SNMP(pid=304)]: Success building vbl [INFO] [PACM.SNMP(pid=304)]: Snmp Inform Ack Handler event post to xgcp queue failedti_api (ti_dns_start_query_scheduler): Starting RULI scheduler [INFO] [PACM.MTA_CONTROL(pid=349)]: MTA 25 step [INFO] [PACM.SNMP(pid=304)]: building vbl for SNMP STATUS [INFO] [PACM.SNMP(pid=304)]: Success building vbl for SNMP STATUS [INFO] [PACM.MTA_CONTROL(pid=349)]: Setting FQDN name to MTA_ARRIS_1.pclab.com [INFO] [PACM.MTA_CONTROL(pid=349)]: Setting DNS primary server IP=10.80.117.31 [INFO] [PACM.MTA_CONTROL(pid=349)]: Setting DNS secondary server IP=0.0.0.0 [ERROR] [VOICE.XSPY(pid=325)]: 0000012259 - NWIF: DQOS is set to NORMAL [INFO] [PACM.MTA_CONTROL(pid=349)]: Activate voice configuration [INFO] [PACM.MTA_CONTROL(pid=349)]: waiting for configuration done from voice [INFO] [PACM.VOIM(pid=349)]: Message: MSPU: MSCS set to true and supported by DSP [INFO] [PACM.MTA_CONTROL(pid=349)]: voice configuration completed [INFO] [PACM.MTA_CONTROL(pid=349)]: configure status is down for end point 0, continue [INFO] [PACM.MTA_CONTROL(pid=349)]: configure status is down for end point 1, continue [INFO] [PACM.MTA_CONTROL(pid=349)]: not all end points are configured [INFO] [PACM.MTA_CONTROL(pid=349)]: configure status is down for end point 0, continue [INFO] [PACM.MTA_CONTROL(pid=349)]: configure status is down for end point 1, continue [INFO] [PACM.MTA_CONTROL(pid=349)]: set end points up - Success [INFO] [PACM.SECURITY(pid=305)]: Invoke Security_IpsecCreatePassPolicies [INFO] [PACM.SECURITY(pid=305)]: endpoint 0 not configured, status set to failed [INFO] [PACM.SECURITY(pid=305)]: endpoint 1 not configured, status set to failed [INFO] [PACM.SNMP(pid=304)]: Snmp Inform Ack Handler