cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
8948
Views
10
Helpful
72
Replies

problem with VDSL on 887

Jeroen Janssens
Level 1
Level 1

I already have a 887 working with VDSL on a second location.  I configured another 887 with the same config (changing logins, passwords and IP ranges) and while the connection seems to come up (ppp led goes on), the CD led starts blinking again after a short time and the connection goes down again.  I contacted the ISP and they checked the line and everthing should be fine.  Their own device also comes up without issues.   When I took the 887 from the other location and connected it on the new location, the connection came up.  

 

This is some debug output but I am not an expert so I can't make sense out of it.  Any help would be appreciated.  I can post both configs if that would help.

 

*Jun 23 09:03:45.188: %LINK-3-UPDOWN: Interface Dialer0, changed state to up
*Jun 23 09:03:48.252: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:03:48.908: VDSL 0: SM_LINE_SHOWTIME boolean event
*Jun 23 09:03:48.908: VDSL 0: line state : showtime !
*Jun 23 09:03:49.908: vdsl_daemon_sm VDSL 0: during state training, got event 18(showtime)
*Jun 23 09:03:49.908: @@@ vdsl_daemon_sm VDSL 0: training -> ready
*Jun 23 09:03:49.908: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=14, seq = 0, len=28, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 23 09:03:49.908: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD131C0, rx_len = 36 @0x1DD131C0
*Jun 23 09:03:49.908: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:03:49.908: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 14x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:49.908: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:49.908: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 001E: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 23 09:03:49.908: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:49.908: TX: Msg for opcode(14)...waiting for Response from Mailbox!

*Jun 23 09:03:50.020: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 60E : hdr= E002, total len= 36, msg len= 36, @618
*Jun 23 09:03:50.020: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 36 00x 02x 14x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.020: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 02x 00x
*Jun 23 09:03:50.020: 00x 00x 00x
*Jun 23 09:03:50.020: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD131E4, len= 36
*Jun 23 09:03:50.020: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 36, 0x1DD131C0
*Jun 23 09:03:50.020: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=14
*Jun 23 09:03:50.020: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D33C opcode=14 to caller

*Jun 23 09:03:50.020: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 14

*Jun 23 09:03:50.020: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:03:50.020: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.020: TX: Call for opcode 14 Success!

*Jun 23 09:03:50.020: VDSL 0: selected tc = 0, sysif = -1
*Jun 23 09:03:50.020: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=17, seq = 0, len=28, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 23 09:03:50.020: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD131C0, rx_len = 36 @0x1DD131C0
*Jun 23 09:03:50.020: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:03:50.020: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 17x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.020: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.020: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0000: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 23 09:03:50.020: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.020: TX: Msg for opcode(17)...waiting for Response from Mailbox!

*Jun 23 09:03:50.116: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5F0 : hdr= E002, total len= 36, msg len= 36, @618
*Jun 23 09:03:50.116: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 36 00x 02x 17x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.116: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.116: 00x 00x 01x
*Jun 23 09:03:50.116: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD131E4, len= 36
*Jun 23 09:03:50.116: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 36, 0x1DD131C0
*Jun 23 09:03:50.116: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=17
*Jun 23 09:03:50.116: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D330 opcode=17 to caller

*Jun 23 09:03:50.116: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 17

*Jun 23 09:03:50.116: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:03:50.116: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.116: TX: Call for opcode 17 Success!

*Jun 23 09:03:50.116: ipc VDSL 0: vdsl_g997_atu_systemenabling_status_get,
*Jun 23 09:03:50.116: vdsl_g997_atu_systemenabling_status_get: Successful Return !

*Jun 23 09:03:50.116: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=10, seq = 0, len=28, tx buf @0x1DD138C0, rx buf @0x1DD138C0

*Jun 23 09:03:50.116: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD138C0, rx_len = 140 @0x1DD138C0
*Jun 23 09:03:50.116: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:03:50.116: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 10x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.120: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.120: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 000A: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 23 09:03:50.120: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.120: TX: Msg for opcode(10)...waiting for Response from Mailbox!

*Jun 23 09:03:50.244: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5FA : hdr= E002, total len= 140, msg len= 140, @618
*Jun 23 09:03:50.244: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD138C0, len= 140 00x 02x 10x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.244: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.244: 00x 116x 23x 00x 00x 116x 23x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.244: 00x 12x 4294967168x 00x 00x 00x 01x 00x 00x 00x 00x 00x 00x 00x 01x 00x
*Jun 23 09:03:50.244: 00x 00x 4294967193x 00x 00x 00x 06x 00x 00x 30x 123x 00x 00x 00x 4294967193x 00x
*Jun 23 09:03:50.244: 00x 00x 00x 00x 00x 00x 00x 00x 01x 17x 109x 00x 01x 17x 109x 00x
*Jun 23 09:03:50.244: 00x 00x 00x
*Jun 23 09:03:50.244: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1394C, len= 140
*Jun 23 09:03:50.244: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 140, 0x1DD138C0
*Jun 23 09:03:50.244: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=10
*Jun 23 09:03:50.244: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D33C opcode=10 to caller

*Jun 23 09:03:50.244: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 10

*Jun 23 09:03:50.244: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:03:50.244: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.244: TX: Call for opcode 10 Success!

*Jun 23 09:03:50.244: ipc VDSL 0: vdsl_g997_channel_status_get,
*Jun 23 09:03:50.244: vdsl_g997_channel_status_get: Successful Return !

*Jun 23 09:03:50.244: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=10, seq = 0, len=28, tx buf @0x1DD138C0, rx buf @0x1DD138C0

*Jun 23 09:03:50.244: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD138C0, rx_len = 140 @0x1DD138C0
*Jun 23 09:03:50.244: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:03:50.244: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 10x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 01x 00x 00x 00x
*Jun 23 09:03:50.244: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.244: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0014: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 23 09:03:50.244: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.244: TX: Msg for opcode(10)...waiting for Response from Mailbox!

*Jun 23 09:03:50.364: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 604 : hdr= E002, total len= 140, msg len= 140, @618
*Jun 23 09:03:50.364: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD138C0, len= 140 00x 02x 10x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 01x 00x 00x 00x
*Jun 23 09:03:50.364: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.368: 00x 116x 23x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.368: 00x 01x 4294967184x 00x 00x 00x 01x 00x 00x 00x 00x 00x 00x 00x 01x 00x
*Jun 23 09:03:50.368: 00x 00x 32x 00x 00x 00x 16x 00x 00x 00x 16x 00x 00x 00x 32x 00x
*Jun 23 09:03:50.368: 00x 00x 01x 00x 00x 00x 00x 00x 01x 17x 109x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.368: 00x 00x 00x
*Jun 23 09:03:50.368: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1394C, len= 140
*Jun 23 09:03:50.368: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 140, 0x1DD138C0
*Jun 23 09:03:50.368: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=10
*Jun 23 09:03:50.368: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D330 opcode=10 to caller

*Jun 23 09:03:50.368: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 10

*Jun 23 09:03:50.368: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:03:50.368: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.368: TX: Call for opcode 10 Success!

*Jun 23 09:03:50.368: ipc VDSL 0: vdsl_g997_channel_status_get,
*Jun 23 09:03:50.368: vdsl_g997_channel_status_get: Successful Return !

*Jun 23 09:03:50.368: %CONTROLLER-5-UPDOWN: Controller VDSL 0, changed state to up
*Jun 23 09:03:50.368: VDSL 0: api (sys if get) ret = 0
*Jun 23 09:03:50.368: vdsl_daemon_sm VDSL 0: during state ready, got event 20(conn_mode_chk)
*Jun 23 09:03:50.368: @@@ vdsl_daemon_sm VDSL 0: ready -> mode_pending
*Jun 23 09:03:50.368: vdsl_daemon_sm VDSL 0: idle during state mode_pending
*Jun 23 09:03:50.368: @@@ vdsl_daemon_sm VDSL 0: mode_pending -> ready
*Jun 23 09:03:50.368: VDSL 0: tc mode selected = 0
*Jun 23 09:03:50.368: vdsl_daemon_sm VDSL 0: during state ready, got event 22(if_state_chk)
*Jun 23 09:03:50.368: @@@ vdsl_daemon_sm VDSL 0: ready -> readyLink b/w CPUs is set to PTMActivating PTM FPGA mode
*Jun 23 09:03:50.368: vdsl_daemon_sm VDSL 0: during state ready, got event 21(if_wakeup)
*Jun 23 09:03:50.368: @@@ vdsl_daemon_sm VDSL 0: ready -> running
*Jun 23 09:03:50.368: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=10, seq = 0, len=28, tx buf @0x1DD138C0, rx buf @0x1DD138C0

*Jun 23 09:03:50.368: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD138C0, rx_len = 140 @0x1DD138C0
*Jun 23 09:03:50.368: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:03:50.368: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 10x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.368: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.368: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 001E: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 23 09:03:50.368: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.368: TX: Msg for opcode(10)...waiting for Response from Mailbox!

*Jun 23 09:03:50.492: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 60E : hdr= E002, total len= 140, msg len= 140, @618
*Jun 23 09:03:50.492: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD138C0, len= 140 00x 02x 10x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.492: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.492: 00x 116x 23x 00x 00x 116x 23x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.492: 00x 12x 4294967168x 00x 00x 00x 01x 00x 00x 00x 00x 00x 00x 00x 01x 00x
*Jun 23 09:03:50.492: 00x 00x 4294967193x 00x 00x 00x 06x 00x 00x 30x 123x 00x 00x 00x 4294967193x 00x
*Jun 23 09:03:50.492: 00x 00x 00x 00x 00x 00x 00x 00x 01x 17x 109x 00x 01x 17x 109x 00x
*Jun 23 09:03:50.492: 00x 00x 00x
*Jun 23 09:03:50.492: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1394C, len= 140
*Jun 23 09:03:50.492: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 140, 0x1DD138C0
*Jun 23 09:03:50.492: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=10
*Jun 23 09:03:50.492: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D33C opcode=10 to caller

*Jun 23 09:03:50.492: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 10

*Jun 23 09:03:50.492: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:03:50.492: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.492: TX: Call for opcode 10 Success!

*Jun 23 09:03:50.492: ipc VDSL 0: vdsl_g997_channel_status_get,
*Jun 23 09:03:50.492: vdsl_g997_channel_status_get: Successful Return !

*Jun 23 09:03:50.496: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=70, seq = 0, len=64, tx buf @0x1DD155C0, rx buf @0x1DD155C0

*Jun 23 09:03:50.496: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 64 @0x1DD155C0, rx_len = 4160 @0x1DD155C0
*Jun 23 09:03:50.496: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:03:50.496: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 70x 01x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 23 09:03:50.496: 102x 105x 103x 32x 101x 116x 104x 49x 32x 117x 112x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.496: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.496: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 16x 00x
*Jun 23 09:03:50.496: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0000: hdr= E382,
total len= 64, msg len= 64, @28
*Jun 23 09:03:50.496: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.496: TX: Msg for opcode(70)...waiting for Response from Mailbox!

*Jun 23 09:03:50.700: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5F0 : hdr= E002, total len= 4160, msg len= 4160, @618
*Jun 23 09:03:50.700: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD155C0, len= 4160 00x 02x 70x 02x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 23 09:03:50.700: 102x 105x 103x 32x 101x 116x 104x 49x 32x 117x 112x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.700: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.700: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 4294967191x
*Jun 23 09:03:50.700: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x
*Jun 23 09:03:50.700: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 00x 00x 00x 00x 00x 00x 26x 17x 00x
*Jun 23 09:03:50.700: 67x 05x 4294967232x
*Jun 23 09:03:50.700: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD16600, len= 4160
*Jun 23 09:03:50.700: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 4160, 0x1DD155C0
*Jun 23 09:03:50.700: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=70
*Jun 23 09:03:50.700: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D330 opcode=70 to caller

*Jun 23 09:03:50.700: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 70

*Jun 23 09:03:50.700: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:03:50.700: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.700: TX: Call for opcode 70 Success!

*Jun 23 09:03:50.700: ipc VDSL 0: vdsl_send_modem_command,
*Jun 23 09:03:50.700: vdsl_send_modem_command: Successful Return !

*Jun 23 09:03:50.800: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=91, seq = 0, len=76, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 23 09:03:50.800: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 76 @0x1DD131C0, rx_len = 76 @0x1DD131C0
*Jun 23 09:03:50.800: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:03:50.800: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 91x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.800: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.800: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.800: 00x 00x 00x 00x 4294967292x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.800: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.800: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 000A: hdr= E382,
total len= 76, msg len= 76, @28
*Jun 23 09:03:50.800: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.800: TX: Msg for opcode(91)...waiting for Response from Mailbox!

*Jun 23 09:03:50.944: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5FA : hdr= E002, total len= 76, msg len= 76, @618
*Jun 23 09:03:50.944: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 76 00x 02x 91x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.944: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.944: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.944: 00x 00x 00x 00x 4294967292x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.944: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:03:50.944: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1320C, len= 76
*Jun 23 09:03:50.944: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 76, 0x1DD131C0
*Jun 23 09:03:50.944: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=91
*Jun 23 09:03:50.944: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D33C opcode=91 to caller

*Jun 23 09:03:50.944: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 91

*Jun 23 09:03:50.944: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:03:50.944: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:03:50.944: TX: Call for opcode 91 Success!

*Jun 23 09:03:50.944: ipc VDSL 0: vdsl_send_watermark_command,
*Jun 23 09:03:50.944: vdsl_send_watermark_command: Successful Return !

*Jun 23 09:03:50.944: VDSL 0: VDSL PTM mode is activated
*Jun 23 09:03:50.944: vdsl_daemon_sm VDSL 0: during state running, got event 23(linkup)
*Jun 23 09:03:50.944: @@@ vdsl_daemon_sm VDSL 0: running -> running
*Jun 23 09:03:50.944: VDSL 0: api (sys if get) ret = 0
*Jun 23 09:03:52.492: %LINK-3-UPDOWN: Interface Ethernet0, changed state to up
*Jun 23 09:03:53.492: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0, changed state to up
*Jun 23 09:03:59.012: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:04:00.872: %DIALER-6-BIND: Interface Vi2 bound to profile Di0
*Jun 23 09:04:00.872: Vi2 Debug: Condition 1, interface Di0 triggered, count 1
*Jun 23 09:04:00.876: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up
*Jun 23 09:04:00.876: Vi2 DDR: Dialer statechange to up
*Jun 23 09:04:00.876: Vi2 PPP: Authorization required
*Jun 23 09:04:00.876: Vi2 PPP: Using dialer call direction
*Jun 23 09:04:00.876: Vi2 PPP: Treating connection as a callout
*Jun 23 09:04:00.876: Vi2 PPP: Session handle[C100000B] Session id[11]
*Jun 23 09:04:00.876: Vi2 PPP LCP: negotiation authorized = 1, tacacs author = 0
*Jun 23 09:04:00.876: Vi2 PPP LCP: neg is authorized, processing CP UP event
*Jun 23 09:04:00.884: Vi2 PPP LCP: neg is authorized, processing incoming CONFREQ
*Jun 23 09:04:00.908: Vi2 PPP: No authorization without authentication
*Jun 23 09:04:00.908: Vi2 CHAP: I CHALLENGE id 1 len 30 from "MSR91GEN9"
*Jun 23 09:04:00.908: Vi2 PPP: Sent CHAP SENDAUTH Request
*Jun 23 09:04:00.908: Vi2 PPP: Received SENDAUTH Response FAIL
*Jun 23 09:04:00.908: Vi2 CHAP: Using hostname from interface CHAP
*Jun 23 09:04:00.908: Vi2 CHAP: Using password from interface CHAP
*Jun 23 09:04:00.908: Vi2 CHAP: O RESPONSE id 1 len 38 from "fd618575@proximus"
*Jun 23 09:04:01.072: Vi2 CHAP: I SUCCESS id 1 len 42 msg is "CHAP authentication success, unit 3389"
*Jun 23 09:04:01.076: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to up
*Jun 23 09:04:01.076: Vi2 PPP IPCP: negotiation authorized = 1, tacacs author = 0
*Jun 23 09:04:01.076: Vi2 PPP IPCP: neg is authorized, processing CP UP event
*Jun 23 09:04:01.084: Vi2 PPP IPCP: neg is authorized, processing incoming CONFREQ
*Jun 23 09:04:01.100: Vi2 DDR: dialer protocol up
*Jun 23 09:04:01.100: Di0 DDR: dialer protocol up
*Jun 23 09:04:08.892: VDSL 0: SM_LINE_DOWN boolean event
*Jun 23 09:04:08.892: %CONTROLLER-5-UPDOWN: Controller VDSL 0, changed state to down
*Jun 23 09:04:08.892: vdsl_daemon_sm VDSL 0: during state running, got event 24(linkdown)
*Jun 23 09:04:08.892: @@@ vdsl_daemon_sm VDSL 0: running -> training
*Jun 23 09:04:08.892: VDSL 0: VDSL PTM mode is de-activated
*Jun 23 09:04:08.892: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=70, seq = 0, len=64, tx buf @0x1DD155C0, rx buf @0x1DD155C0

*Jun 23 09:04:08.892: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 64 @0x1DD155C0, rx_len = 4160 @0x1DD155C0
*Jun 23 09:04:08.892: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:04:08.892: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 70x 01x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 23 09:04:08.892: 102x 105x 103x 32x 101x 116x 104x 49x 32x 100x 111x 119x 110x 00x 00x 00x
*Jun 23 09:04:08.892: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:04:08.892: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 16x 00x
*Jun 23 09:04:08.892: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0014: hdr= E382,
total len= 64, msg len= 64, @28
*Jun 23 09:04:08.892: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:04:08.892: TX: Msg for opcode(70)...waiting for Response from Mailbox!

*Jun 23 09:04:09.120: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 604 : hdr= E002, total len= 4160, msg len= 4160, @618
*Jun 23 09:04:09.120: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD155C0, len= 4160 00x 02x 70x 02x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 23 09:04:09.120: 102x 105x 103x 32x 101x 116x 104x 49x 32x 100x 111x 119x 110x 00x 00x 00x
*Jun 23 09:04:09.120: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:04:09.120: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 4294967191x
*Jun 23 09:04:09.120: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x
*Jun 23 09:04:09.120: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 00x 00x 00x 00x 00x 00x 26x 17x 00x
*Jun 23 09:04:09.124: 67x 05x 4294967232x
*Jun 23 09:04:09.124: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD16600, len= 4160
*Jun 23 09:04:09.124: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 4160, 0x1DD155C0
*Jun 23 09:04:09.124: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=70
*Jun 23 09:04:09.124: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D330 opcode=70 to caller

*Jun 23 09:04:09.124: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 70

*Jun 23 09:04:09.124: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:04:09.124: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:04:09.124: TX: Call for opcode 70 Success!

*Jun 23 09:04:09.124: ipc VDSL 0: vdsl_send_modem_command,
*Jun 23 09:04:09.124: vdsl_send_modem_command: Successful Return !

*Jun 23 09:04:09.124: vdsl_daemon_sm VDSL 0: during state training, got event 17(line_training)
*Jun 23 09:04:09.124: @@@ vdsl_daemon_sm VDSL 0: training -> training
*Jun 23 09:04:09.164: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:04:09.892: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0, changed state to down
*Jun 23 09:04:11.124: %LINK-3-UPDOWN: Interface Ethernet0, changed state to down
*Jun 23 09:04:11.148: ipc VDSL 0: vdsl_notif_interrupt, Sending LINE_STATE to VDSL Daemon, state = 8

*Jun 23 09:04:11.148: VDSL 0: vdsl line state : discovery
*Jun 23 09:04:11.148: VDSL 0: SM_LINE_TRAIN boolean event
*Jun 23 09:04:11.148: vdsl_daemon_sm VDSL 0: during state training, got event 17(line_training)
*Jun 23 09:04:11.148: @@@ vdsl_daemon_sm VDSL 0: training -> training
*Jun 23 09:04:19.164: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:04:29.164: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:04:39.152: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 60E : hdr= E004, total len= 28, msg len= 28, @618
*Jun 23 09:04:39.152: mbx VDSL 0: vdsl_msg_rcv_isr, Notification msg type 4, len= 28
*Jun 23 09:04:39.152: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1E936000, len= 28 00x 04x 11x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 42x
*Jun 23 09:04:39.152: 4294967242x 55x 16x 127x 4294967193x 28x 4294967288x 00x 00x 00x 00x
*Jun 23 09:04:39.152: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1E93601C, len= 28
*Jun 23 09:04:39.152: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 4 rx handler, err= 0, len= 28, 0x1E936000
*Jun 23 09:04:39.192: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:04:41.164: ipc VDSL 0: vdsl_notif_interrupt, Sending LINE_STATE to VDSL Daemon, state = 7

*Jun 23 09:04:41.164: VDSL 0: vdsl line state : fullinit
*Jun 23 09:04:49.192: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:04:59.188: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:05:01.164: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to down
*Jun 23 09:05:01.164: Vi2 PPP: Clearing AAA Unique Id = 17
*Jun 23 09:05:01.164: %DIALER-6-UNBIND: Interface Vi2 unbound from profile Di0
*Jun 23 09:05:01.164: Vi2 DDR: disconnecting call
*Jun 23 09:05:01.168: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to down
*Jun 23 09:05:01.168: Vi2 Debug: Condition 1, interface Di0 cleared, count 0
*Jun 23 09:05:09.188: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5F0 : hdr= E004, total len= 28, msg len= 28, @618
*Jun 23 09:05:09.188: mbx VDSL 0: vdsl_msg_rcv_isr, Notification msg type 4, len= 28
*Jun 23 09:05:09.188: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1E936000, len= 28 00x 04x 11x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 42x
*Jun 23 09:05:09.188: 4294967242x 55x 16x 127x 4294967193x 28x 4294967288x 00x 00x 00x 00x
*Jun 23 09:05:09.188: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1E93601C, len= 28
*Jun 23 09:05:09.188: mbx VDSL 0: vdsl_msg_rcv_complete, debug interface dialer0call msg 4 rx handler, err= 0, len= 28, 0x1E936000
*Jun 23 09:05:09.216: ipc VDSL 0: vdsl_mbx_interrupt_handlercopy run start
*Jun 23 09:05:19.216: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:05:23.471: VDSL 0: SM_LINE_SHOWTIME boolean event
*Jun 23 09:05:23.471: VDSL 0: line state : showtime !
*Jun 23 09:05:24.471: vdsl_daemon_sm VDSL 0: during state training, got event 18(showtime)
*Jun 23 09:05:24.471: @@@ vdsl_daemon_sm VDSL 0: training -> ready
*Jun 23 09:05:24.471: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=14, seq = 0, len=28, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 23 09:05:24.471: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD131C0, rx_len = 36 @0x1DD131C0
*Jun 23 09:05:24.471: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:05:24.471: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 14x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.471: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.471: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 001E: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 23 09:05:24.471: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:24.471: TX: Msg for opcode(14)...waiting for Response from Mailbox!

*Jun 23 09:05:24.583: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5FA : hdr= E002, total len= 36, msg len= 36, @618
*Jun 23 09:05:24.583: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 36 00x 02x 14x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.583: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 02x 00x
*Jun 23 09:05:24.583: 00x 00x 00x
*Jun 23 09:05:24.583: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD131E4, len= 36
*Jun 23 09:05:24.583: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 36, 0x1DD131C0
*Jun 23 09:05:24.583: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=14
*Jun 23 09:05:24.583: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D33C opcode=14 to caller

*Jun 23 09:05:24.583: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 14

*Jun 23 09:05:24.583: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:05:24.583: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:24.583: TX: Call for opcode 14 Success!

*Jun 23 09:05:24.583: VDSL 0: selected tc = 0, sysif = -1
*Jun 23 09:05:24.583: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=17, seq = 0, len=28, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 23 09:05:24.583: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD131C0, rx_len = 36 @0x1DD131C0
*Jun 23 09:05:24.583: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:05:24.583: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 17x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.583: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.583: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0000: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 23 09:05:24.583: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:24.583: TX: Msg for opcode(17)...waiting for Response from Mailbox!

*Jun 23 09:05:24.687: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 604 : hdr= E002, total len= 36, msg len= 36, @618
*Jun 23 09:05:24.687: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 36 00x 02x 17x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.687: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.687: 00x 00x 01x
*Jun 23 09:05:24.687: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD131E4, len= 36
*Jun 23 09:05:24.687: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 36, 0x1DD131C0
*Jun 23 09:05:24.687: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=17
*Jun 23 09:05:24.687: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D330 opcode=17 to caller

*Jun 23 09:05:24.687: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 17

*Jun 23 09:05:24.687: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:05:24.687: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:24.687: TX: Call for opcode 17 Success!

*Jun 23 09:05:24.687: ipc VDSL 0: vdsl_g997_atu_systemenabling_status_get,
*Jun 23 09:05:24.687: vdsl_g997_atu_systemenabling_status_get: Successful Return !

*Jun 23 09:05:24.687: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=10, seq = 0, len=28, tx buf @0x1DD138C0, rx buf @0x1DD138C0

*Jun 23 09:05:24.687: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD138C0, rx_len = 140 @0x1DD138C0
*Jun 23 09:05:24.687: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:05:24.687: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 10x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.687: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.687: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 000A: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 23 09:05:24.687: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:24.687: TX: Msg for opcode(10)...waiting for Response from Mailbox!

*Jun 23 09:05:24.811: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 60E : hdr= E002, total len= 140, msg len= 140, @618
*Jun 23 09:05:24.811: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD138C0, len= 140 00x 02x 10x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.811: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.811: 00x 116x 23x 00x 00x 116x 23x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.811: 00x 12x 4294967168x 00x 00x 00x 01x 00x 00x 00x 00x 00x 00x 00x 01x 00x
*Jun 23 09:05:24.811: 00x 00x 4294967193x 00x 00x 00x 06x 00x 00x 30x 123x 00x 00x 00x 4294967193x 00x
*Jun 23 09:05:24.811: 00x 00x 00x 00x 00x 00x 00x 00x 01x 17x 109x 00x 01x 17x 109x 00x
*Jun 23 09:05:24.811: 00x 00x 00x
*Jun 23 09:05:24.811: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1394C, len= 140
*Jun 23 09:05:24.811: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 140, 0x1DD138C0
*Jun 23 09:05:24.811: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=10
*Jun 23 09:05:24.811: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D33C opcode=10 to caller

*Jun 23 09:05:24.811: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 10

*Jun 23 09:05:24.811: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:05:24.811: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:24.811: TX: Call for opcode 10 Success!

*Jun 23 09:05:24.811: ipc VDSL 0: vdsl_g997_channel_status_get,
*Jun 23 09:05:24.811: vdsl_g997_channel_status_get: Successful Return !

*Jun 23 09:05:24.811: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=10, seq = 0, len=28, tx buf @0x1DD138C0, rx buf @0x1DD138C0

*Jun 23 09:05:24.811: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD138C0, rx_len = 140 @0x1DD138C0
*Jun 23 09:05:24.811: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:05:24.811: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 10x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 01x 00x 00x 00x
*Jun 23 09:05:24.811: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.811: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0014: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 23 09:05:24.811: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:24.811: TX: Msg for opcode(10)...waiting for Response from Mailbox!

*Jun 23 09:05:24.935: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5F0 : hdr= E002, total len= 140, msg len= 140, @618
*Jun 23 09:05:24.935: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD138C0, len= 140 00x 02x 10x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 01x 00x 00x 00x
*Jun 23 09:05:24.935: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.935: 00x 116x 23x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.935: 00x 01x 4294967184x 00x 00x 00x 01x 00x 00x 00x 00x 00x 00x 00x 01x 00x
*Jun 23 09:05:24.935: 00x 00x 32x 00x 00x 00x 16x 00x 00x 00x 16x 00x 00x 00x 32x 00x
*Jun 23 09:05:24.935: 00x 00x 01x 00x 00x 00x 00x 00x 01x 17x 109x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.935: 00x 00x 00x
*Jun 23 09:05:24.935: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1394C, len= 140
*Jun 23 09:05:24.935: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 140, 0x1DD138C0
*Jun 23 09:05:24.935: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=10
*Jun 23 09:05:24.935: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D330 opcode=10 to caller

*Jun 23 09:05:24.935: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 10

*Jun 23 09:05:24.935: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:05:24.935: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:24.935: TX: Call for opcode 10 Success!

*Jun 23 09:05:24.935: ipc VDSL 0: vdsl_g997_channel_status_get,
*Jun 23 09:05:24.935: vdsl_g997_channel_status_get: Successful Return !

*Jun 23 09:05:24.935: %CONTROLLER-5-UPDOWN: Controller VDSL 0, changed state to up
*Jun 23 09:05:24.935: VDSL 0: api (sys if get) ret = 0
*Jun 23 09:05:24.935: vdsl_daemon_sm VDSL 0: during state ready, got event 20(conn_mode_chk)
*Jun 23 09:05:24.935: @@@ vdsl_daemon_sm VDSL 0: ready -> mode_pending
*Jun 23 09:05:24.935: vdsl_daemon_sm VDSL 0: idle during state mode_pending
*Jun 23 09:05:24.935: @@@ vdsl_daemon_sm VDSL 0: mode_pending -> ready
*Jun 23 09:05:24.935: VDSL 0: tc mode selected = 0
*Jun 23 09:05:24.935: vdsl_daemon_sm VDSL 0: during state ready, got event 22(if_state_chk)
*Jun 23 09:05:24.935: @@@ vdsl_daemon_sm VDSL 0: ready -> readyLink b/w CPUs is set to PTMActivating PTM FPGA mode
*Jun 23 09:05:24.935: vdsl_daemon_sm VDSL 0: during state ready, got event 21(if_wakeup)
*Jun 23 09:05:24.935: @@@ vdsl_daemon_sm VDSL 0: ready -> running
*Jun 23 09:05:24.935: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=10, seq = 0, len=28, tx buf @0x1DD138C0, rx buf @0x1DD138C0

*Jun 23 09:05:24.935: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD138C0, rx_len = 140 @0x1DD138C0
*Jun 23 09:05:24.935: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:05:24.935: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 10x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.935: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:24.935: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 001E: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 23 09:05:24.935: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:24.935: TX: Msg for opcode(10)...waiting for Response from Mailbox!

*Jun 23 09:05:25.059: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5FA : hdr= E002, total len= 140, msg leundebugn= 140, @618
*Jun 23 09:05:25.059: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD138C0, len= 140 00x 02x 10x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.063: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.063: 00x 116x 23x 00x 00x 116x 23x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.063: 00x 12x 4294967168x 00x 00x 00x 01x 00x 00x 00x 00x 00x 00x 00x 01x 00x
*Jun 23 09:05:25.063: 00x 00x 4294967193x 00x 00x 00x 06x 00x 00x 30x 123x 00x 00x 00x 4294967193x 00x
*Jun 23 09:05:25.063: 00x 00x 00x 00x 00x 00x 00x 00x 01x 17x 109x 00x 01x 17x 109x 00x
*Jun 23 09:05:25.063: 00x 00x 00x
*Jun 23 09:05:25.063: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1394C, len= 140
*Jun 23 09:05:25.063: mbx VDSL 0: vdsl_msg_rcv_comp all
Destination filename [startundebug]? lete, call msg 2 rx handler, err= 0, len= 140, 0x1DD138C0
*Jun 23 09:05:25.063: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=10
*Jun 23 09:05:25.063: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D33C opcode=10 to caller

*Jun 23 09:05:25.063: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 10

*Jun 23 09:05:25.063: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:05:25.063: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:25.063: TX: Call for opcode 10 Success!

*Jun 23 09:05:25.063: ipc VDSL 0: vdsl_g997_channel_status_get,
*Jun 23 09:05:25.063: vdsl_g997_channel_status_get: Successful Return !

*Jun 23 09:05:25.063: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=70, seq = 0, len=64, tx buf @0x1DD155C0, rx buf @0x1DD155C0

*Jun 23 09:05:25.063: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 64 @0x1DD155C0, rx_len = 4160 @0x1DD155C0
*Jun 23 09:05:25.063: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:05:25.063: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 70x 01x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 23 09:05:25.063: 102x 105x 103x 32x 101x 116x 104x 49x 32x 117x 112x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.063: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.063: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 16x 00x
*Jun 23 09:05:25.063: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0000: hdr= E382,
total len= 64, msg len= 64, @28
*Jun 23 09:05:25.063: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:25.063: TX: Msg for opcode(70)...waiting for Response from Mailbox!

*Jun 23 09:05:25.267: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 604 : hdr= E002, total len= 4160, msg len= 4160, @618
*Jun 23 09:05:25.267: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD155C0, len= 4160 00x 02x 70x 02x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 23 09:05:25.267: 102x 105x 103x 32x 101x 116x 104x 49x 32x 117x 112x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.267: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.267: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 4294967191x
*Jun 23 09:05:25.267: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x
*Jun 23 09:05:25.271: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 00x 00x 00x 00x 00x 00x 26x 17x 00x
*Jun 23 09:05:25.271: 67x 05x 4294967232x
*Jun 23 09:05:25.271: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD16600, len= 4160
*Jun 23 09:05:25.271: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 4160, 0x1DD155C0
*Jun 23 09:05:25.271: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=70
*Jun 23 09:05:25.271: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D330 opcode=70 to caller

*Jun 23 09:05:25.271: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 70

*Jun 23 09:05:25.271: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:05:25.271: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:25.271: TX: Call for opcode 70 Success!

*Jun 23 09:05:25.271: ipc VDSL 0: vdsl_send_modem_command,
*Jun 23 09:05:25.271: vdsl_send_modem_command: Successful Return !

*Jun 23 09:05:25.371: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=91, seq = 0, len=76, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 23 09:05:25.371: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 76 @0x1DD131C0, rx_len = 76 @0x1DD131C0
*Jun 23 09:05:25.371: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:05:25.371: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 91x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.371: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.371: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.371: 00x 00x 00x 00x 4294967292x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.371: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.371: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 000A: hdr= E382,
total len= 76, msg len= 76, @28
*Jun 23 09:05:25.371: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:25.371: TX: Msg for opcode(91)...waiting for Response from Mailbox!

*Jun 23 09:05:25.511: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 60E : hdr= E002, total len= 76, msg len= 76, @618
*Jun 23 09:05:25.511: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 76 00x 02x 91x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.511: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.511: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.511: 00x 00x 00x 00x 4294967292x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.515: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:25.515: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1320C, len= 76
*Jun 23 09:05:25.515: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 76, 0x1DD131C0
*Jun 23 09:05:25.515: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=91
*Jun 23 09:05:25.515: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D33C opcode=91 to caller

*Jun 23 09:05:25.515: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 91

*Jun 23 09:05:25.515: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:05:25.515: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:25.515: TX: Call for opcode 91 Success!

*Jun 23 09:05:25.515: ipc VDSL 0: vdsl_send_watermark_command,
*Jun 23 09:05:25.515: vdsl_send_watermark_command: Successful Return !

*Jun 23 09:05:25.515: VDSL 0: VDSL PTM mode is activated
*Jun 23 09:05:25.515: vdsl_daemon_sm VDSL 0: during state running, got event 23(linkup)
*Jun 23 09:05:25.515: @@@ vdsl_daemon_sm VDSL 0: running -> running
*Jun 23 09:05:25.515: VDSL 0: api (sys if get) ret = 0
*Jun 23 09:05:27.063: %LINK-3-UPDOWN: Interface Ethernet0, changed state to up
*Jun 23 09:05:27.671: %DIALER-6-BIND: Interface Vi2 bound to profile Di0
*Jun 23 09:05:27.671: Vi2 Debug: Condition 1, interface Di0 triggered, count 1
*Jun 23 09:05:27.675: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up
*Jun 23 09:05:27.675: Vi2 DDR: Dialer statechange to up
*Jun 23 09:05:27.675: Vi2 PPP: Authorization required
*Jun 23 09:05:27.675: Vi2 PPP: Using dialer call direction
*Jun 23 09:05:27.675: Vi2 PPP: Treating connection as a callout
*Jun 23 09:05:27.675: Vi2 PPP: Session handle[8600000C] Session id[12]
*Jun 23 09:05:27.675: Vi2 PPP LCP: negotiation authorized = 1, tacacs author = 0
*Jun 23 09:05:27.675: Vi2 PPP LCP: neg is authorized, processing CP UP event
*Jun 23 09:05:27.683: Vi2 PPP LCP: neg is authorized, processing incoming CONFREQ
*Jun 23 09:05:27.691: Vi2 PPP: No authorization without authentication
*Jun 23 09:05:27.695: Vi2 CHAP: I CHALLENGE id 1 len 30 from "MSR91GEN9"
*Jun 23 09:05:27.695: Vi2 PPP: Sent CHAP SENDAUTH Request
*Jun 23 09:05:27.695: Vi2 PPP: Received SENDAUTH Response FAIL
*Jun 23 09:05:27.695: Vi2 CHAP: Using hostname from interface CHAP
*Jun 23 09:05:27.695: Vi2 CHAP: Usin
g password from interface CHAP
*Jun 23 09:05:27.695: Vi2 CHAP: O RESPONSE id 1 len 38 from "fd618575@proximus"
*Jun 23 09:05:28.015: Vi2 CHAP: I SUCCESS id 1 len 42 msg is "CHAP authentication success, unit 4065"
*Jun 23 09:05:28.019: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to up
*Jun 23 09:05:28.019: Vi2 PPP IPCP: negotiation authorized = 1, tacacs author = 0
*Jun 23 09:05:28.019: Vi2 PPP IPCP: neg is authorized, processing CP UP event
*Jun 23 09:05:28.023: Vi2 PPP IPCP: neg is authorized, processing incoming CONFREQ
*Jun 23 09:05:28.043: Vi2 DDR: dialer protocol up
*Jun 23 09:05:28.043: Di0 DDR: dialer protocol up
*Jun 23 09:05:28.063: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0, changed state to up
*Jun 23 09:05:29.983: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:05:39.979: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 23 09:05:43.451: VDSL 0: SM_LINE_DOWN boolean event
*Jun 23 09:05:43.451: %CONTROLLER-5-UPDOWN: Controller VDSL 0, changed state to down
*Jun 23 09:05:43.451: vdsl_daemon_sm VDSL 0: during state running, got event 24(linkdown)
*Jun 23 09:05:43.451: @@@ vdsl_daemon_sm VDSL 0: running -> training
*Jun 23 09:05:43.455: VDSL 0: VDSL PTM mode is de-activated
*Jun 23 09:05:43.455: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=70, seq = 0, len=64, tx buf @0x1DD16600, rx buf @0x1DD16600

*Jun 23 09:05:43.455: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 64 @0x1DD16600, rx_len = 4160 @0x1DD16600
*Jun 23 09:05:43.455: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 23 09:05:43.455: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 0
58083 bytes copied in 1.652 secs (35159 bytes/sec)

OCWRTR01#u0x 02x 70x 01x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 23 09:05:43.455: 102x 105x 103x 32x 101x 116x 104x 49x 32x 100x 111x 119x 110x 00x 00x 00x
*Jun 23 09:05:43.455: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:43.455: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 16x 00x
*Jun 23 09:05:43.455: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0014: hdr= E382,
total len= 64, msg len= 64, @28
*Jun 23 09:05:43.455: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:43.455: TX: Msg for opcode(70)...waiting for Response from Mailbox!

*Jun 23 09:05:43.667: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5F0 : hdr= E002, total len= 4160, msg len= 4160, @618
*Jun 23 09:05:43.667: mbx VDSL 0: vdsl_process_msg_rcv, First message (1nde) : addr= 0x618, dest= 0x0x1DD16600, len= 4160 00x 02x 70x 02x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 23 09:05:43.671: 102x 105x 103x 32x 101x 116x 104x 49x 32x 100x 111x 119x 110x 00x 00x 00x
*Jun 23 09:05:43.671: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 23 09:05:43.671: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 4294967191x
*Jun 23 09:05:43.671: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x
*Jun 23 09:05:43.671: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 00x 00x 00x 00x 00x 00x 26x 17x 00x
*Jun 23 09:05:43.671: 67x 05x 4294967232x
*Jun 23 09:05:43.671: mbx VDSL 0: vdsl_process_msg_rcv,bug Last message (2) : addr= 0x618, dest= 0x1DD17640, len= 4160
*Jun 23 09:05:43.671: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 4160, 0x1DD16600
*Jun 23 09:05:43.671: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=70
*Jun 23 09:05:43.671: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x195D330 opcode=70 to caller

*Jun 23 09:05:43.671: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 70

*Jun 23 09:05:43.671: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 23 09:05:43.671: ipc VDSL 0: vdsl_ipc_send,
*Jun 23 09:05:43.671: TX: Call for opcode 70 Success!

*Jun 23 09:05:43.671: ipc VDSL 0: vdsl_send_modem_command,
*Jun 23 09:05:43.671: vdsl_send_modem_command: Successful Return !

*Jun 23 09:05:43.671: vdsl_daemon_sm VDSL 0: during state training, got event 17(line_training)
*Jun 23 09:05:43.671: @@@ vdsl_daemon_sm VDSL 0: training -> training
*Jun 23 09:05:44.455: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0, changed state to down
*Jun 23 09:05:45.279: ipc VDSL 0: vdsl_notif_interrupt, Sending LINE_STATE to VDSL Daemon, state = 8

*Jun 23 09:05:45.279: VDSL 0: vdsl line state : discovery
*Jun 23 09:05:45.279: VDSL 0: SM_LINE_TRAIN boolean event
*Jun 23 09:05:45.279: vdsl_daemon_sm VDSL 0: during state training, got event 17(line_training)
*Jun 23 09:05:45.279: @@@ vdsl_daemon_sm VDSL 0: training -> training
*Jun 23 09:05:45.671: %LINK-3-UPDOWN: Interface Ethernet0, changed state to down
*Jun 23 09:05:50.123: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE all

1 Accepted Solution

Accepted Solutions

Jeroen,

 

I think we have tried this before all the other stuff, but add 'set pfs group2' to the crypto map:

 

crypto map SDM_CMAP_1 1 ipsec-isakmp
description Tunnel to 194.78.59.5
set peer 194.78.59.5
set transform-set ESP-3DES-SHA

set pfs group2
match address 100

View solution in original post

72 Replies 72

Hello,

 

try 'operating mode auto' under the controller:

 

887#conf t

887(config)#controller vdsl 0

887(config-controller)#operating mode auto

Also post the full config of your router...

 

Who is your ISP ?

Proximus (Belgium)

Hello,

 

which firmware are you running on the controller ?

 

E.g.:

 

controller VDSL 0
firmware filename flash:VA_A_39d_B_38h3_24h_1.bin

 

Also, under the controller you should have various modem options:

 

887#conf t

887(config)#controller vdsl 0

887(config-controller)#modem ?

 

Which are those ?

OCWRTR01#conf t
Enter configuration commands, one per line. End with CNTL/Z.
OCWRTR01(config)#controller vdsl 0
OCWRTR01(config-controller)#modem ?
LINE command line string

I updated the firmware and now the connection seems to remain up.  There are still issues with VPN but I will look into those tomorrow.

Hello Jeroen,

 

for reference purposes can you post the working configuration ?

And what VPN issues are you experiencing ?

This is the current config:

 

OCWRTR01#show run
Building configuration...

Current configuration : 5520 bytes
!
! Last configuration change at 09:07:30 pctime Mon Jun 25 2018
!
version 15.5
no service pad
service timestamps debug datetime msec
service timestamps log datetime msec
service password-encryption
!
hostname OCWRTR01
!
boot-start-marker
boot-end-marker
!
aqm-register-fnf
!
enable secret ******************
enable password ******************
!
no aaa new-model
clock timezone pctime 1 0
clock summer-time pctime date Mar 30 2003 2:00 Oct 26 2003 3:00
!
crypto pki trustpoint TP-self-signed-372889659
enrollment selfsigned
subject-name cn=IOS-Self-Signed-Certificate-372889659
revocation-check none
rsakeypair TP-self-signed-372889659
!
!
crypto pki certificate chain TP-self-signed-372889659
certificate self-signed 01
30820229 30820192 A0030201 02020101 300D0609 2A864886 F70D0101 05050030
30312E30 2C060355 04031325 494F532D 53656C66 2D536967 6E65642D 43657274
69666963 6174652D 33373238 38393635 39301E17 0D313531 32303331 32353430
335A170D 32303031 30313030 30303030 5A303031 2E302C06 03550403 1325494F
532D5365 6C662D53 69676E65 642D4365 72746966 69636174 652D3337 32383839
36353930 819F300D 06092A86 4886F70D 01010105 0003818D 00308189 02818100
AE294AF5 4B3E652D 48B86C3E 8C55D813 0A77BCD7 FC443B6A F36562D3 2FE47AE8
C6FE44CC 45794852 07D468A0 0565092B 28D1C523 76A7ADD4 116C43EC DF14197E
298E8325 28A205D2 BF337E5C C34BA2D9 E3002988 A5B0577D B1AC6AA6 98F5CB6D
04FA3C1D 28AC01FA 96A86A2D E2499661 F30B1557 E1AC389C B35CA150 5683ED9B
02030100 01A35330 51300F06 03551D13 0101FF04 05300301 01FF301F 0603551D
23041830 16801419 13E44CE2 D16FB24C FF626FD0 1B5FDF0A 84468F30 1D060355
1D0E0416 04141913 E44CE2D1 6FB24CFF 626FD01B 5FDF0A84 468F300D 06092A86
4886F70D 01010505 00038181 008181CD 80376437 DB3B6DF0 2F75F47D A280C0A2
90E9FEB5 D59651BA 5D54CECE B16082DB B53DA7F7 2C40EF4B 7ACD7A42 4DA65F41
8C3680AB A5EC820D 07FD6C91 5CBC62B0 4E3E8F5C A5445FFC 2ABAE60E 56D24EBA
C5A2974C EA63DBB9 F567BC9E 843CAB45 203E0955 53B3B475 673D5589 987013EF
5E19E7CD AEEF039C 1FAB582B 36
quit
!
!
!
!
!
!
!
!
!
!
!
!
!
!
!


!
no ip dhcp use vrf connected
!
ip dhcp pool sdm-pool
import all
network 10.0.130.32 255.255.255.224
default-router 10.0.130.33
dns-server 10.0.12.32 10.0.12.16
lease 0 2
!
!
!
ip name-server 195.238.2.21
ip name-server 195.238.2.22
ip cef
no ipv6 cef
!
!
!
!
!
multilink bundle-name authenticated
!
!
!
!
!
!
!
license udi pid C887VAM-K9 sn FCZ222012JM
!
!
username janssens.j privilege 15 secret ******************
!
!
!
!
!
controller VDSL 0
no cdp run
!
!
!
crypto isakmp policy 1
encr 3des
authentication pre-share
group 2
crypto isakmp key ****************** address ******************
crypto isakmp fragmentation
!
!
crypto ipsec transform-set ESP-3DES-SHA esp-3des esp-sha-hmac
mode tunnel
!
!
!
crypto map SDM_CMAP_1 1 ipsec-isakmp
description Tunnel to ******************
set peer ******************
set transform-set ESP-3DES-SHA
match address 100
!
!
!
!
!
!
interface ATM0
no ip address
shutdown
no atm ilmi-keepalive
!
interface Ethernet0
no ip address
!
interface Ethernet0.10
encapsulation dot1Q 10
ip nat outside
ip virtual-reassembly in
pppoe enable group global
pppoe-client dial-pool-number 1
!
interface FastEthernet0
description trunk OCWL2SW01
switchport mode trunk
no ip address
!
interface FastEthernet1
no ip address
shutdown
!
interface FastEthernet2
no ip address
shutdown
!
interface FastEthernet3
no ip address
shutdown
!
interface Vlan1
ip address 10.0.130.33 255.255.255.224
ip nat inside
ip rip send version 2
ip rip receive version 2
ip virtual-reassembly in
ip tcp adjust-mss 1412
!
interface Dialer0
mtu 1200
ip address ****************** 255.255.255.0
ip nat outside
ip virtual-reassembly in
encapsulation ppp
dialer pool 1
dialer-group 1
ppp authentication chap callin
ppp chap hostname ******************
ppp chap password 7 ******************
no cdp enable
crypto map SDM_CMAP_1
crypto ipsec df-bit clear
!
router rip
version 2
redistribute static
network 10.0.0.0
default-information originate
no auto-summary
!
ip forward-protocol nd
no ip http server
ip http access-class 23
ip http authentication local
ip http secure-server
ip http timeout-policy idle 60 life 8640 requests 10000
!
!
ip nat inside source route-map SDM_RMAP_1 interface Dialer0 overload
ip route 0.0.0.0 0.0.0.0 Dialer0 permanent
!
dialer-list 1 protocol ip permit
!
route-map SDM_RMAP_1 permit 1
match ip address 101
!
snmp-server community public RO
access-list 1 remark SDM_ACL Category=2
access-list 1 permit 10.10.10.0 0.0.0.7
access-list 2 remark SDM_ACM Category=2
access-list 2 permit 10.0.130.32 0.0.0.31
access-list 23 permit 10.0.130.32 0.0.0.31
access-list 100 remark IPSec Rule
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.0.0 0.0.255.255
access-list 100 remark SDM_ACM Category=4
access-list 101 remark IPSec Rule
access-list 101 remark SDM_ACM Category=2
access-list 101 deny ip 10.0.130.32 0.0.0.31 10.0.0.0 0.0.255.255
access-list 101 permit ip 10.0.130.32 0.0.0.31 any
!
control-plane
!
!
!
mgcp behavior rsip-range tgcp-only
mgcp behavior comedia-role none
mgcp behavior comedia-check-media-src disable
mgcp behavior comedia-sdp-force disable
!
mgcp profile default
!
!
!
!
!
!
!
line con 0
exec-timeout 5 30
password 7 ******************
login
no modem enable
line aux 0
line vty 0 4
privilege level 15
password 7 ******************
login
transport input telnet ssh
!
scheduler max-task-time 5000
scheduler allocate 20000 1000
!
end

OCWRTR01#show ver
Cisco IOS Software, C800 Software (C800-UNIVERSALK9-M), Version 15.5(3)M5, RELEASE SOFTWARE (fc1)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2017 by Cisco Systems, Inc.
Compiled Wed 25-Jan-17 04:11 by prod_rel_team

ROM: System Bootstrap, Version 15.4(1r)T1, RELEASE SOFTWARE (fc1)

OCWRTR01 uptime is 1 day, 23 hours, 39 minutes
System returned to ROM by power-on
System image file is "flash:c800-universalk9-mz.SPA.155-3.M5.bin"
Last reload type: Normal Reload
Last reload reason: power-on

 

This product contains cryptographic features and is subject to United
States and local country laws governing import, export, transfer and
use. Delivery of Cisco cryptographic products does not imply
third-party authority to import, export, distribute or use encryption.
Importers, exporters, distributors and users are responsible for
compliance with U.S. and local country laws. By using this product you
agree to comply with applicable laws and regulations. If you are unable
to comply with U.S. and local laws, return this product immediately.

A summary of U.S. laws governing Cisco cryptographic products may be found at:
http://www.cisco.com/wwl/export/crypto/tool/stqrg.html

If you require further assistance please contact us by sending email to
export@cisco.com.

Cisco C887VAM-K9 (revision 1.0) with 488524K/35763K bytes of memory.
Processor board ID FCZ222012JM
1 DSL controller
1 Ethernet interface
4 FastEthernet interfaces
1 ATM interface
1 Virtual Private Network (VPN) Module
DRAM configuration is 32 bits wide
255K bytes of non-volatile configuration memory.
250880K bytes of ATA System CompactFlash (Read/Write)


License Info:

License UDI:

-------------------------------------------------
Device# PID SN
-------------------------------------------------
*1 C887VAM-K9 FCZ222012JM

 

License Information for 'c800'
License Level: advipservices Type: Default. No valid license found.
Next reboot license Level: advipservices


Configuration register is 0x2102

Hello,

 

I made some minor changes to your config (marked in bold).

 

On the dialer, you have a static IP address, typically this is set to 'negotiated', you might want to check that...

 

OCWRTR01#show run
Building configuration...

Current configuration : 5520 bytes
!
! Last configuration change at 09:07:30 pctime Mon Jun 25 2018
!
version 15.5
no service pad
service timestamps debug datetime msec
service timestamps log datetime msec
service password-encryption
!
hostname OCWRTR01
!
boot-start-marker
boot-end-marker
!
aqm-register-fnf
!
enable secret ******************
enable password ******************
!
no aaa new-model
clock timezone pctime 1 0
clock summer-time pctime date Mar 30 2003 2:00 Oct 26 2003 3:00
!
crypto pki trustpoint TP-self-signed-372889659
enrollment selfsigned
subject-name cn=IOS-Self-Signed-Certificate-372889659
revocation-check none
rsakeypair TP-self-signed-372889659
!
!
crypto pki certificate chain TP-self-signed-372889659
certificate self-signed 01
30820229 30820192 A0030201 02020101 300D0609 2A864886 F70D0101 05050030
30312E30 2C060355 04031325 494F532D 53656C66 2D536967 6E65642D 43657274
69666963 6174652D 33373238 38393635 39301E17 0D313531 32303331 32353430
335A170D 32303031 30313030 30303030 5A303031 2E302C06 03550403 1325494F
532D5365 6C662D53 69676E65 642D4365 72746966 69636174 652D3337 32383839
36353930 819F300D 06092A86 4886F70D 01010105 0003818D 00308189 02818100
AE294AF5 4B3E652D 48B86C3E 8C55D813 0A77BCD7 FC443B6A F36562D3 2FE47AE8
C6FE44CC 45794852 07D468A0 0565092B 28D1C523 76A7ADD4 116C43EC DF14197E
298E8325 28A205D2 BF337E5C C34BA2D9 E3002988 A5B0577D B1AC6AA6 98F5CB6D
04FA3C1D 28AC01FA 96A86A2D E2499661 F30B1557 E1AC389C B35CA150 5683ED9B
02030100 01A35330 51300F06 03551D13 0101FF04 05300301 01FF301F 0603551D
23041830 16801419 13E44CE2 D16FB24C FF626FD0 1B5FDF0A 84468F30 1D060355
1D0E0416 04141913 E44CE2D1 6FB24CFF 626FD01B 5FDF0A84 468F300D 06092A86
4886F70D 01010505 00038181 008181CD 80376437 DB3B6DF0 2F75F47D A280C0A2
90E9FEB5 D59651BA 5D54CECE B16082DB B53DA7F7 2C40EF4B 7ACD7A42 4DA65F41
8C3680AB A5EC820D 07FD6C91 5CBC62B0 4E3E8F5C A5445FFC 2ABAE60E 56D24EBA
C5A2974C EA63DBB9 F567BC9E 843CAB45 203E0955 53B3B475 673D5589 987013EF
5E19E7CD AEEF039C 1FAB582B 36
quit
!
no ip dhcp use vrf connected
ip dhcp excluded-address 10.0.130.33
!
ip dhcp pool sdm-pool
import all
network 10.0.130.32 255.255.255.224
default-router 10.0.130.33
dns-server 10.0.12.32 10.0.12.16
lease 0 2
!
!
!
ip name-server 195.238.2.21
ip name-server 195.238.2.22
ip cef
no ipv6 cef
!
multilink bundle-name authenticated
!
license udi pid C887VAM-K9 sn FCZ222012JM
!
username janssens.j privilege 15 secret ******************
!
controller VDSL 0
modem co5
!
no cdp run
!
crypto isakmp policy 1
encr 3des
authentication pre-share
group 2
crypto isakmp key ****************** address ******************
crypto isakmp fragmentation
!
crypto ipsec transform-set ESP-3DES-SHA esp-3des esp-sha-hmac
mode tunnel
!
crypto map SDM_CMAP_1 1 ipsec-isakmp
description Tunnel to ******************
set peer ******************
set transform-set ESP-3DES-SHA
match address 100
!
interface ATM0
no ip address
shutdown
no atm ilmi-keepalive
!
interface Ethernet0
no ip address
!
interface Ethernet0.10
encapsulation dot1Q 10
ip nat outside
ip virtual-reassembly in
pppoe enable group global
pppoe-client dial-pool-number 1
!
interface FastEthernet0
description trunk OCWL2SW01
switchport mode trunk
no ip address
!
interface FastEthernet1
no ip address
shutdown
!
interface FastEthernet2
no ip address
shutdown
!
interface FastEthernet3
no ip address
shutdown
!
interface Vlan1
ip address 10.0.130.33 255.255.255.224
ip nat inside
ip rip send version 2
ip rip receive version 2
ip virtual-reassembly in
ip tcp adjust-mss 1412
!
interface Dialer0
mtu 1492
--> ip address negotiated
no ip redirects
no ip unreachables
ip nat outside
ip virtual-reassembly in
encapsulation ppp
dialer pool 1
dialer-group 1
ppp authentication chap callin
ppp chap hostname ******************
ppp chap password 7 ******************
ppp direction callout
ppp ipcp header-compression ack
ppp ipcp dns request accept
ppp ipcp address accept
no cdp enable
crypto map SDM_CMAP_1
crypto ipsec df-bit clear
!
router rip
version 2
redistribute static
network 10.0.0.0
default-information originate
no auto-summary
!
ip forward-protocol nd
no ip http server
ip http access-class 23
ip http authentication local
ip http secure-server
ip http timeout-policy idle 60 life 8640 requests 10000
!
ip nat inside source route-map SDM_RMAP_1 interface Dialer0 overload
ip route 0.0.0.0 0.0.0.0 Dialer0 permanent
!
dialer-list 1 protocol ip permit
!
route-map SDM_RMAP_1 permit 1
match ip address 101
match interface Dialer0
!
snmp-server community public RO
access-list 1 remark SDM_ACL Category=2
access-list 1 permit 10.10.10.0 0.0.0.7
access-list 2 remark SDM_ACM Category=2
access-list 2 permit 10.0.130.32 0.0.0.31
access-list 23 permit 10.0.130.32 0.0.0.31
access-list 100 remark IPSec Rule
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.0.0 0.0.255.255
access-list 100 remark SDM_ACM Category=4
access-list 101 remark IPSec Rule
access-list 101 remark SDM_ACM Category=2
access-list 101 deny ip 10.0.130.32 0.0.0.31 10.0.0.0 0.0.255.255
access-list 101 permit ip 10.0.130.32 0.0.0.31 any
!
control-plane
!
mgcp behavior rsip-range tgcp-only
mgcp behavior comedia-role none
mgcp behavior comedia-check-media-src disable
mgcp behavior comedia-sdp-force disable
!
mgcp profile default
!
line con 0
exec-timeout 5 30
password 7 ******************
login
no modem enable
line aux 0
line vty 0 4
privilege level 15
password 7 ******************
login
transport input telnet ssh
!
scheduler max-task-time 5000
scheduler allocate 20000 1000
!
end

I implemented the changes but doesn't seem to have any effect.


*Jun 25 08:50:21.222: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=67, seq = 0, len=16, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 25 08:50:21.222: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 16 @0x1DD131C0, rx_len = 16 @0x1DD131C0
*Jun 25 08:50:21.222: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 25 08:50:21.222: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 67x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:50:21.222: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0000: hdr= E382,
total len= 16, msg len= 16, @28
*Jun 25 08:50:21.222: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:50:21.222: TX: Msg for opcode(67)...waiting for Response from Mailbox!

*Jun 25 08:50:21.322: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5F0 : hdr= E002, total len= 16, msg len= 16, @618
*Jun 25 08:50:21.322: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 16 00x 02x 67x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:50:21.322: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD131D0, len= 16
*Jun 25 08:50:21.322: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 16, 0x1DD131C0
*Jun 25 08:50:21.322: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=67
*Jun 25 08:50:21.322: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x18EAB30 opcode=67 to caller

*Jun 25 08:50:21.322: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 67

*Jun 25 08:50:21.322: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 25 08:50:21.322: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:50:21.322: TX: Call for opcode 67 Success!

*Jun 25 08:50:21.322: ipc VDSL 0: vdsl_diag_start,
*Jun 25 08:50:21.322: vdsl_diag_start: Successful Return !

*Jun 25 08:50:25.221: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 25 08:50:35.221: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 25 08:50:45.217: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 25 08:50:51.353: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5FA : hdr= E004, total len= 28, msg len= 28, @618
*Jun 25 08:50:51.353: mbx VDSL 0: vdsl_msg_rcv_isr, Notification msg type 4, len= 28
*Jun 25 08:50:51.353: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1E933800, len= 28 00x 04x 11x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 42x
*Jun 25 08:50:51.353: 4294967242x 55x 16x 127x 4294967244x 4294967292x 4294967288x 00x 00x 00x 00x
*Jun 25 08:50:51.353: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1E93381C, len= 28
*Jun 25 08:50:51.353: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 4 rx handler, err= 0, len= 28, 0x1E933800
*Jun 25 08:50:55.249: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 25 08:50:59.725: VDSL 0: SM_LINE_SHOWTIME boolean event
*Jun 25 08:50:59.725: VDSL 0: line state : showtime !
*Jun 25 08:51:00.725: vdsl_daemon_sm VDSL 0: during state training, got event 18(showtime)
*Jun 25 08:51:00.725: @@@ vdsl_daemon_sm VDSL 0: training -> ready
*Jun 25 08:51:00.725: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=14, seq = 0, len=28, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 25 08:51:00.725: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD131C0, rx_len = 36 @0x1DD131C0
*Jun 25 08:51:00.725: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 25 08:51:00.725: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 14x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:00.725: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:00.725: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 000A: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 25 08:51:00.725: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:00.725: TX: Msg for opcode(14)...waiting for Response from Mailbox!

*Jun 25 08:51:00.833: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 604 : hdr= E002, total len= 36, msg len= 36, @618
*Jun 25 08:51:00.833: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 36 00x 02x 14x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:00.837: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 02x 00x
*Jun 25 08:51:00.837: 00x 00x 00x
*Jun 25 08:51:00.837: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD131E4, len= 36
*Jun 25 08:51:00.837: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 36, 0x1DD131C0
*Jun 25 08:51:00.837: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=14
*Jun 25 08:51:00.837: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x18EAB3C opcode=14 to caller

*Jun 25 08:51:00.837: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 14

*Jun 25 08:51:00.837: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 25 08:51:00.837: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:00.837: TX: Call for opcode 14 Success!

*Jun 25 08:51:00.837: VDSL 0: selected tc = 0, sysif = -1
*Jun 25 08:51:00.837: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=17, seq = 0, len=28, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 25 08:51:00.837: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD131C0, rx_len = 36 @0x1DD131C0
*Jun 25 08:51:00.837: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 25 08:51:00.837: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 17x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:00.837: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:00.837: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0014: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 25 08:51:00.837: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:00.837: TX: Msg for opcode(17)...waiting for Response from Mailbox!

*Jun 25 08:51:00.933: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 60E : hdr= E002, total len= 36, msg len= 36, @618
*Jun 25 08:51:00.933: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 36 00x 02x 17x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:00.933: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:00.933: 00x 00x 01x
*Jun 25 08:51:00.933: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD131E4, len= 36
*Jun 25 08:51:00.933: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 36, 0x1DD131C0
*Jun 25 08:51:00.933: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=17
*Jun 25 08:51:00.933: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x18EAB30 opcode=17 to caller

*Jun 25 08:51:00.933: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 17

*Jun 25 08:51:00.933: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 25 08:51:00.933: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:00.933: TX: Call for opcode 17 Success!

*Jun 25 08:51:00.933: ipc VDSL 0: vdsl_g997_atu_systemenabling_status_get,
*Jun 25 08:51:00.933: vdsl_g997_atu_systemenabling_status_get: Successful Return !

*Jun 25 08:51:00.933: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=10, seq = 0, len=28, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 25 08:51:00.933: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD131C0, rx_len = 140 @0x1DD131C0
*Jun 25 08:51:00.933: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 25 08:51:00.933: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 10x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:00.933: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:00.933: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 001E: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 25 08:51:00.933: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:00.933: TX: Msg for opcode(10)...waiting for Response from Mailbox!

*Jun 25 08:51:01.061: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5F0 : hdr= E002, total len= 140, msg len= 140, @618
*Jun 25 08:51:01.061: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 140 00x 02x 10x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.061: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.061: 00x 116x 23x 00x 00x 116x 23x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.061: 00x 12x 4294967168x 00x 00x 00x 01x 00x 00x 00x 00x 00x 00x 00x 01x 00x
*Jun 25 08:51:01.061: 00x 00x 4294967193x 00x 00x 00x 06x 00x 00x 30x 123x 00x 00x 00x 4294967193x 00x
*Jun 25 08:51:01.061: 00x 00x 00x 00x 00x 00x 00x 00x 01x 119x 4294967189x 00x 01x 119x 4294967189x 00x
*Jun 25 08:51:01.061: 00x 00x 00x
*Jun 25 08:51:01.061: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1324C, len= 140
*Jun 25 08:51:01.061: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 140, 0x1DD131C0
*Jun 25 08:51:01.061: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=10
*Jun 25 08:51:01.061: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x18EAB3C opcode=10 to caller

*Jun 25 08:51:01.061: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 10

*Jun 25 08:51:01.061: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 25 08:51:01.061: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:01.061: TX: Call for opcode 10 Success!

*Jun 25 08:51:01.061: ipc VDSL 0: vdsl_g997_channel_status_get,
*Jun 25 08:51:01.061: vdsl_g997_channel_status_get: Successful Return !

*Jun 25 08:51:01.061: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=10, seq = 0, len=28, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 25 08:51:01.061: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD131C0, rx_len = 140 @0x1DD131C0
*Jun 25 08:51:01.061: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 25 08:51:01.061: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 10x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 01x 00x 00x 00x
*Jun 25 08:51:01.061: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.061: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0000: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 25 08:51:01.061: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:01.061: TX: Msg for opcode(10)...waiting for Response from Mailbox!

*Jun 25 08:51:01.185: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5FA : hdr= E002, total len= 140, msg len= 140, @618
*Jun 25 08:51:01.185: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 140 00x 02x 10x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 01x 00x 00x 00x
*Jun 25 08:51:01.185: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.185: 00x 116x 23x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.185: 00x 01x 4294967184x 00x 00x 00x 01x 00x 00x 00x 00x 00x 00x 00x 01x 00x
*Jun 25 08:51:01.185: 00x 00x 32x 00x 00x 00x 16x 00x 00x 00x 16x 00x 00x 00x 32x 00x
*Jun 25 08:51:01.185: 00x 00x 01x 00x 00x 00x 00x 00x 01x 119x 4294967189x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.185: 00x 00x 00x
*Jun 25 08:51:01.185: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1324C, len= 140
*Jun 25 08:51:01.185: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 140, 0x1DD131C0
*Jun 25 08:51:01.185: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=10
*Jun 25 08:51:01.185: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x18EAB30 opcode=10 to caller

*Jun 25 08:51:01.185: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 10

*Jun 25 08:51:01.185: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 25 08:51:01.185: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:01.185: TX: Call for opcode 10 Success!

*Jun 25 08:51:01.185: ipc VDSL 0: vdsl_g997_channel_status_get,
*Jun 25 08:51:01.185: vdsl_g997_channel_status_get: Successful Return !

*Jun 25 08:51:01.185: %CONTROLLER-5-UPDOWN: Controller VDSL 0, changed state to up
*Jun 25 08:51:01.185: VDSL 0: api (sys if get) ret = 0
*Jun 25 08:51:01.185: vdsl_daemon_sm VDSL 0: during state ready, got event 20(conn_mode_chk)
*Jun 25 08:51:01.185: @@@ vdsl_daemon_sm VDSL 0: ready -> mode_pending
*Jun 25 08:51:01.185: vdsl_daemon_sm VDSL 0: idle during state mode_pending
*Jun 25 08:51:01.185: @@@ vdsl_daemon_sm VDSL 0: mode_pending -> ready
*Jun 25 08:51:01.185: VDSL 0: tc mode selected = 0
*Jun 25 08:51:01.185: vdsl_daemon_sm VDSL 0: during state ready, got event 22(if_state_chk)
*Jun 25 08:51:01.185: @@@ vdsl_daemon_sm VDSL 0: ready -> readyLink b/w CPUs is set to PTMActivating PTM FPGA mode
*Jun 25 08:51:01.185: vdsl_daemon_sm VDSL 0: during state ready, got event 21(if_wakeup)
*Jun 25 08:51:01.185: @@@ vdsl_daemon_sm VDSL 0: ready -> running
*Jun 25 08:51:01.185: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=10, seq = 0, len=28, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 25 08:51:01.185: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 28 @0x1DD131C0, rx_len = 140 @0x1DD131C0
*Jun 25 08:51:01.185: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 25 08:51:01.185: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 10x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.185: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.185: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 000A: hdr= E382,
total len= 28, msg len= 28, @28
*Jun 25 08:51:01.185: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:01.185: TX: Msg for opcode(10)...waiting for Response from Mailbox!

*Jun 25 08:51:01.313: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 604 : hdr= E002, total len= 140, msg len= 140, @618
*Jun 25 08:51:01.313: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 140 00x 02x 10x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.313: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.313: 00x 116x 23x 00x 00x 116x 23x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.313: 00x 12x 4294967168x 00x 00x 00x 01x 00x 00x 00x 00x 00x 00x 00x 01x 00x
*Jun 25 08:51:01.313: 00x 00x 4294967193x 00x 00x 00x 06x 00x 00x 30x 123x 00x 00x 00x 4294967193x 00x
*Jun 25 08:51:01.313: 00x 00x 00x 00x 00x 00x 00x 00x 01x 119x 4294967189x 00x 01x 119x 4294967189x 00x
*Jun 25 08:51:01.313: 00x 00x 00x
*Jun 25 08:51:01.313: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1324C, len= 140
*Jun 25 08:51:01.313: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 140, 0x1DD131C0
*Jun 25 08:51:01.313: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=10
*Jun 25 08:51:01.313: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x18EAB3C opcode=10 to caller

*Jun 25 08:51:01.313: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 10

*Jun 25 08:51:01.313: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 25 08:51:01.313: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:01.313: TX: Call for opcode 10 Success!

*Jun 25 08:51:01.313: ipc VDSL 0: vdsl_g997_channel_status_get,
*Jun 25 08:51:01.313: vdsl_g997_channel_status_get: Successful Return !

*Jun 25 08:51:01.313: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=70, seq = 0, len=64, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 25 08:51:01.313: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 64 @0x1DD131C0, rx_len = 4160 @0x1DD131C0
*Jun 25 08:51:01.313: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 25 08:51:01.313: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 70x 01x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 25 08:51:01.313: 102x 105x 103x 32x 101x 116x 104x 49x 32x 117x 112x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.313: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.313: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 16x 00x
*Jun 25 08:51:01.313: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0014: hdr= E382,
total len= 64, msg len= 64, @28
*Jun 25 08:51:01.313: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:01.313: TX: Msg for opcode(70)...waiting for Response from Mailbox!

*Jun 25 08:51:01.517: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 60E : hdr= E002, total len= 4160, msg len= 4160, @618
*Jun 25 08:51:01.517: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 4160 00x 02x 70x 02x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 25 08:51:01.517: 102x 105x 103x 32x 101x 116x 104x 49x 32x 117x 112x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.521: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.521: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 4294967191x
*Jun 25 08:51:01.521: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x
*Jun 25 08:51:01.521: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 00x 00x 00x 00x 00x 00x 26x 17x 00x
*Jun 25 08:51:01.521: 67x 05x 4294967232x
*Jun 25 08:51:01.521: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD14200, len= 4160
*Jun 25 08:51:01.521: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 4160, 0x1DD131C0
*Jun 25 08:51:01.521: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=70
*Jun 25 08:51:01.521: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x18EAB30 opcode=70 to caller

*Jun 25 08:51:01.521: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 70

*Jun 25 08:51:01.521: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 25 08:51:01.521: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:01.521: TX: Call for opcode 70 Success!

*Jun 25 08:51:01.521: ipc VDSL 0: vdsl_send_modem_command,
*Jun 25 08:51:01.521: vdsl_send_modem_command: Successful Return !

*Jun 25 08:51:01.621: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=91, seq = 0, len=76, tx buf @0x1DD131C0, rx buf @0x1DD131C0

*Jun 25 08:51:01.621: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 76 @0x1DD131C0, rx_len = 76 @0x1DD131C0
*Jun 25 08:51:01.621: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 25 08:51:01.621: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 91x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.621: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.621: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.621: 00x 00x 00x 00x 4294967292x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.621: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.621: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 001E: hdr= E382,
total len= 76, msg len= 76, @28
*Jun 25 08:51:01.621: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:01.621: TX: Msg for opcode(91)...waiting for Response from Mailbox!

*Jun 25 08:51:01.765: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5F0 : hdr= E002, total len= 76, msg len= 76, @618
*Jun 25 08:51:01.765: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD131C0, len= 76 00x 02x 91x 02x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.765: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.765: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.765: 00x 00x 00x 00x 4294967292x 01x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.765: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:01.765: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD1320C, len= 76
*Jun 25 08:51:01.765: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 76, 0x1DD131C0
*Jun 25 08:51:01.765: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=91
*Jun 25 08:51:01.765: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x18EAB3C opcode=91 to caller

*Jun 25 08:51:01.765: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 91

*Jun 25 08:51:01.765: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 25 08:51:01.765: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:01.765: TX: Call for opcode 91 Success!

*Jun 25 08:51:01.765: ipc VDSL 0: vdsl_send_watermark_command,
*Jun 25 08:51:01.765: vdsl_send_watermark_command: Successful Return !

*Jun 25 08:51:01.765: VDSL 0: VDSL PTM mode is activated
*Jun 25 08:51:01.765: vdsl_daemon_sm VDSL 0: during state running, got event 23(linkup)
*Jun 25 08:51:01.765: @@@ vdsl_daemon_sm VDSL 0: running -> running
*Jun 25 08:51:01.765: VDSL 0: api (sys if get) ret = 0
*Jun 25 08:51:03.313: %LINK-3-UPDOWN: Interface Ethernet0, changed state to up
*Jun 25 08:51:04.313: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0, changed state to up
*Jun 25 08:51:06.013: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 25 08:51:16.009: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE
*Jun 25 08:51:19.709: VDSL 0: SM_LINE_DOWN boolean event
*Jun 25 08:51:19.709: %CONTROLLER-5-UPDOWN: Controller VDSL 0, changed state to down
*Jun 25 08:51:19.709: vdsl_daemon_sm VDSL 0: during state running, got event 24(linkdown)
*Jun 25 08:51:19.709: @@@ vdsl_daemon_sm VDSL 0: running -> training
*Jun 25 08:51:19.709: VDSL 0: VDSL PTM mode is de-activated
*Jun 25 08:51:19.709: ipc VDSL 0: vdsl_ipc_send, IPC Send: msg_type = 2, opcode=70, seq = 0, len=64, tx buf @0x1DD155C0, rx buf @0x1DD155C0

*Jun 25 08:51:19.709: mbx VDSL 0: vdsl_msg_send, type= 2, tx_len= 64 @0x1DD155C0, rx_len = 4160 @0x1DD155C0
*Jun 25 08:51:19.709: mbx VDSL 0: vdsl_mbx_find_free_buf, Used Start 0028, Used End 0028
*Jun 25 08:51:19.709: mbx VDSL 0: vdsl_mbx_find_free_buf, Free len 1480, Addr 00000028, Max size 2960 00x 02x 70x 01x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 25 08:51:19.709: 102x 105x 103x 32x 101x 116x 104x 49x 32x 100x 111x 119x 110x 00x 00x 00x
*Jun 25 08:51:19.709: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:19.709: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 16x 00x
*Jun 25 08:51:19.709: mbx VDSL 0: vdsl_mbx_send_direct, Writing to msg descriptor: 0000: hdr= E382,
total len= 64, msg len= 64, @28
*Jun 25 08:51:19.709: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:19.709: TX: Msg for opcode(70)...waiting for Response from Mailbox!

*Jun 25 08:51:19.917: mbx VDSL 0: vdsl_msg_rcv_isr, Desc@ 5FA : hdr= E002, total len= 4160, msg len= 4160, @618
*Jun 25 08:51:19.917: mbx VDSL 0: vdsl_process_msg_rcv, First message (1) : addr= 0x618, dest= 0x0x1DD155C0, len= 4160 00x 02x 70x 02x 00x 00x 00x 00x 00x 00x 00x 00x 105x 102x 99x 111x 110x
*Jun 25 08:51:19.917: 102x 105x 103x 32x 101x 116x 104x 49x 32x 100x 111x 119x 110x 00x 00x 00x
*Jun 25 08:51:19.917: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x
*Jun 25 08:51:19.917: 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 00x 4294967191x
*Jun 25 08:51:19.917: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x
*Jun 25 08:51:19.917: 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 4294967191x 00x 00x 00x 00x 00x 00x 26x 17x 00x
*Jun 25 08:51:19.917: 67x 05x 4294967232x
*Jun 25 08:51:19.917: mbx VDSL 0: vdsl_process_msg_rcv, Last message (2) : addr= 0x618, dest= 0x1DD16600, len= 4160
*Jun 25 08:51:19.917: mbx VDSL 0: vdsl_msg_rcv_complete, call msg 2 rx handler, err= 0, len= 4160, 0x1DD155C0
*Jun 25 08:51:19.917: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Type Msg: opcode=70
*Jun 25 08:51:19.917: ipc VDSL 0: vdsl_msg_rcv_handler, Rx DSL Msg: enqueue 0x18EAB30 opcode=70 to caller

*Jun 25 08:51:19.917: ipc VDSL 0: vdsl_msg_rcv_handler, RX: Notify Waiting Process for opcode = 70

*Jun 25 08:51:19.917: ipc VDSL 0: vdsl_msg_rcv_handler, KEEPALIVE Msg to VDSL Daemon from DSL Msg Handler

*Jun 25 08:51:19.917: ipc VDSL 0: vdsl_ipc_send,
*Jun 25 08:51:19.917: TX: Call for opcode 70 Success!

*Jun 25 08:51:19.917: ipc VDSL 0: vdsl_send_modem_command,
*Jun 25 08:51:19.917: vdsl_send_modem_command: Successful Return !

*Jun 25 08:51:19.917: vdsl_daemon_sm VDSL 0: during state training, got event 17(line_training)
*Jun 25 08:51:19.917: @@@ vdsl_daemon_sm VDSL 0: training -> training
*Jun 25 08:51:20.709: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0, changed state to down
*Jun 25 08:51:21.917: %LINK-3-UPDOWN: Interface Ethernet0, changed state to down
*Jun 25 08:51:21.973: ipc VDSL 0: vdsl_notif_interrupt, Sending LINE_STATE to VDSL Daemon, state = 8

*Jun 25 08:51:21.973: VDSL 0: vdsl line state : discovery
*Jun 25 08:51:21.973: VDSL 0: SM_LINE_TRAIN boolean event
*Jun 25 08:51:21.973: vdsl_daemon_sm VDSL 0: during state training, got event 17(line_training)
*Jun 25 08:51:21.973: @@@ vdsl_daemon_sm VDSL 0: training -> training
*Jun 25 08:51:26.161: ipc VDSL 0: vdsl_mbx_interrupt_handler, Interrupt: KEEP_ALIVE

I used the IP address because this connection has a fixed ip address so I can set up a site-to-site vpn.

Hello Jeroen,

 

 

can you debug ppp negotiation and post the output ?

Jeroen Janssens
Level 1
Level 1

This is the current config.  With this, the VDSL/PPP stays up (although I cannot surf the internet when I connect my laptop).

 

OCWRTR01#show run
Building configuration...

Current configuration : 5599 bytes
!
version 15.5
no service pad
service timestamps debug datetime msec
service timestamps log datetime msec
service password-encryption
!
hostname OCWRTR01
!
boot-start-marker
boot-end-marker
!
aqm-register-fnf
!
enable secret 5 **********************
enable password 7 **********************
!
no aaa new-model
ethernet lmi ce
clock timezone pctime 1 0
clock summer-time pctime date Mar 30 2003 2:00 Oct 26 2003 3:00
!
crypto pki trustpoint TP-self-signed-372889659
enrollment selfsigned
subject-name cn=IOS-Self-Signed-Certificate-372889659
revocation-check none
rsakeypair TP-self-signed-372889659
!
!
crypto pki certificate chain TP-self-signed-372889659
certificate self-signed 01
30820229 30820192 A0030201 02020101 300D0609 2A864886 F70D0101 05050030
30312E30 2C060355 04031325 494F532D 53656C66 2D536967 6E65642D 43657274
69666963 6174652D 33373238 38393635 39301E17 0D313531 32303331 32353430
335A170D 32303031 30313030 30303030 5A303031 2E302C06 03550403 1325494F
532D5365 6C662D53 69676E65 642D4365 72746966 69636174 652D3337 32383839
36353930 819F300D 06092A86 4886F70D 01010105 0003818D 00308189 02818100
AE294AF5 4B3E652D 48B86C3E 8C55D813 0A77BCD7 FC443B6A F36562D3 2FE47AE8
C6FE44CC 45794852 07D468A0 0565092B 28D1C523 76A7ADD4 116C43EC DF14197E
298E8325 28A205D2 BF337E5C C34BA2D9 E3002988 A5B0577D B1AC6AA6 98F5CB6D
04FA3C1D 28AC01FA 96A86A2D E2499661 F30B1557 E1AC389C B35CA150 5683ED9B
02030100 01A35330 51300F06 03551D13 0101FF04 05300301 01FF301F 0603551D
23041830 16801419 13E44CE2 D16FB24C FF626FD0 1B5FDF0A 84468F30 1D060355
1D0E0416 04141913 E44CE2D1 6FB24CFF 626FD01B 5FDF0A84 468F300D 06092A86
4886F70D 01010505 00038181 008181CD 80376437 DB3B6DF0 2F75F47D A280C0A2
90E9FEB5 D59651BA 5D54CECE B16082DB B53DA7F7 2C40EF4B 7ACD7A42 4DA65F41
8C3680AB A5EC820D 07FD6C91 5CBC62B0 4E3E8F5C A5445FFC 2ABAE60E 56D24EBA
C5A2974C EA63DBB9 F567BC9E 843CAB45 203E0955 53B3B475 673D5589 987013EF
5E19E7CD AEEF039C 1FAB582B 36
quit
!
!
!
!
!
!
!
!
!
!
!
!
!
!
!


!
no ip dhcp use vrf connected
ip dhcp excluded-address 10.0.130.33
!
ip dhcp pool sdm-pool
import all
network 10.0.130.32 255.255.255.224
default-router 10.0.130.33
dns-server 10.0.12.32 10.0.12.16
lease 0 2
!
!
!
ip name-server 195.238.2.21
ip name-server 195.238.2.22
ip cef
no ipv6 cef
!
!
!
!
!
multilink bundle-name authenticated
!
!
!
!
!
!
!
license udi pid C887VAM-K9 sn FCZ222012JM
!
!
username janssens.j privilege 15 secret 5 **********************
!
!
!
!
!
controller VDSL 0
firmware filename flash:VA_A_39d_B_38h3_24h.bin
no cdp run
!
!
!
crypto isakmp policy 1
encr 3des
authentication pre-share
group 2
crypto isakmp key **********************address 194.78.59.5
crypto isakmp fragmentation
!
!
crypto ipsec transform-set ESP-3DES-SHA esp-3des esp-sha-hmac
mode tunnel
!
!
!
crypto map SDM_CMAP_1 1 ipsec-isakmp
description Tunnel to 194.78.59.5
set peer 194.78.59.5
set transform-set ESP-3DES-SHA
match address 100
!
!
!
!
!
!
interface ATM0
no ip address
shutdown
no atm ilmi-keepalive
!
interface Ethernet0
no ip address
!
interface Ethernet0.10
encapsulation dot1Q 10
ip nat outside
ip virtual-reassembly in
pppoe enable group global
pppoe-client dial-pool-number 1
!
interface FastEthernet0
description trunk OCWL2SW01
switchport mode trunk
no ip address
!
interface FastEthernet1
switchport access vlan 60
no ip address
!
interface FastEthernet2
no ip address
shutdown
!
interface FastEthernet3
no ip address
shutdown
!
interface Vlan1
ip address 10.0.130.33 255.255.255.224
ip nat inside
ip rip send version 2
ip rip receive version 2
ip virtual-reassembly in
ip tcp adjust-mss 1412
!
interface Dialer0
mtu 1200
ip address 109.135.19.130 255.255.255.0
ip nat outside
ip virtual-reassembly in
encapsulation ppp
dialer pool 1
dialer-group 1
ppp authentication chap callin
ppp chap hostname **********************
ppp chap password 7 **********************
no cdp enable
crypto map SDM_CMAP_1
crypto ipsec df-bit clear
!
router rip
version 2
redistribute static
network 10.0.0.0
default-information originate
no auto-summary
!
ip forward-protocol nd
no ip http server
ip http access-class 23
ip http authentication local
ip http secure-server
ip http timeout-policy idle 60 life 8640 requests 10000
!
!
ip nat inside source route-map SDM_RMAP_1 interface Dialer0 overload
ip route 0.0.0.0 0.0.0.0 Dialer0 permanent
!
dialer-list 1 protocol ip permit
!
route-map SDM_RMAP_1 permit 1
match ip address 101
match interface Dialer0
!
snmp-server community public RO
access-list 1 remark SDM_ACL Category=2
access-list 1 permit 10.10.10.0 0.0.0.7
access-list 2 remark SDM_ACM Category=2
access-list 2 permit 10.0.130.32 0.0.0.31
access-list 23 permit 10.0.130.32 0.0.0.31
access-list 100 remark IPSec Rule
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.0.0 0.0.255.255
access-list 100 remark SDM_ACM Category=4
access-list 101 remark IPSec Rule
access-list 101 remark SDM_ACM Category=2
access-list 101 deny ip 10.0.130.32 0.0.0.31 10.0.0.0 0.0.255.255
access-list 101 permit ip 10.0.130.32 0.0.0.31 any
!
control-plane
!
!
!
mgcp behavior rsip-range tgcp-only
mgcp behavior comedia-role none
mgcp behavior comedia-check-media-src disable
mgcp behavior comedia-sdp-force disable
!
mgcp profile default
!
!
!
!
!
!
!
line con 0
exec-timeout 5 30
password 7 **********************
login
no modem enable
line aux 0
line vty 0 4
privilege level 15
password 7 **********************
login
transport input telnet ssh
!
scheduler max-task-time 5000
scheduler allocate 20000 1000
!
end

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: