cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
8942
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

72 Replies 72

Is the ACL 101 correct?  As it denies the traffic?  I am not familiar with the route-map command so maybe it needs to be like this?

Hello Jeroen,

 

ACL 101 keeps the traffic that needs to go through the VPN tunnel from being tranlated. 

 

Try and change:

 

ip nat inside source route-map SDM_RMAP_1 interface Dialer0 overload

 

to 

 

ip nat inside source list 101 interface Dialer0 overload

 

and check if that makes a difference...

doesn't seem to have any effect :(

this is really frustrating ...

Is there any way to debug/monitor the traffic that is send from the remote site to the main site?

OCWRTR01#sh crypto ipsec sa peer 194.78.59.5

interface: Dialer0
Crypto map tag: SDM_CMAP_1, local addr 109.135.19.130

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.4.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 500
PERMIT, flags={origin_is_acl,}
#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 0, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1400, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0x0(0)
PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

inbound pcp sas:

outbound esp sas:

outbound ah sas:

outbound pcp sas:

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.10.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 4500
PERMIT, flags={origin_is_acl,}
#pkts encaps: 1180, #pkts encrypt: 1180, #pkts digest: 1180
#pkts decaps: 1180, #pkts decrypt: 1180, #pkts verify: 1180
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 0, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1342, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0xBC0AB7D2(3154819026)
PFS (Y/N): Y, DH group: group2

inbound esp sas:
spi: 0xF148B6A5(4048074405)
transform: esp-3des esp-sha-hmac ,
in use settings ={Tunnel UDP-Encaps, }
conn id: 35, flow_id: Onboard VPN:35, sibling_flags 80000040, crypto map: SDM_CMAP_1
sa timing: remaining key lifetime (k/sec): (4162608/3565)
IV size: 8 bytes
replay detection support: Y
Status: ACTIVE(ACTIVE)

inbound ah sas:

inbound pcp sas:

outbound esp sas:
spi: 0xBC0AB7D2(3154819026)
transform: esp-3des esp-sha-hmac ,
in use settings ={Tunnel UDP-Encaps, }
conn id: 36, flow_id: Onboard VPN:36, sibling_flags 80000040, crypto map: SDM_CMAP_1
sa timing: remaining key lifetime (k/sec): (4162608/3565)
IV size: 8 bytes
replay detection support: Y
Status: ACTIVE(ACTIVE)

outbound ah sas:

outbound pcp sas:

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.11.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 500
PERMIT, flags={origin_is_acl,}
#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 0, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1400, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0x0(0)
PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

inbound pcp sas:

outbound esp sas:

outbound ah sas:

outbound pcp sas:

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.14.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 500
PERMIT, flags={origin_is_acl,}
#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 0, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1400, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0x0(0)
PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

inbound pcp sas:

outbound esp sas:

outbound ah sas:

outbound pcp sas:

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.15.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 500
PERMIT, flags={origin_is_acl,}
#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 0, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1400, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0x0(0)
PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

inbound pcp sas:

outbound esp sas:

outbound ah sas:

outbound pcp sas:

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.12.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 500
PERMIT, flags={origin_is_acl,ipsec_sa_request_sent}
#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 574, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1400, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0x0(0)
PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

inbound pcp sas:

outbound esp sas:

outbound ah sas:

outbound pcp sas:

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.13.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 500
PERMIT, flags={origin_is_acl,}
#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 0, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1400, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0x0(0)
PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

inbound pcp sas:

outbound esp sas:

outbound ah sas:

outbound pcp sas:

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.18.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 500
PERMIT, flags={origin_is_acl,}
#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 0, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1400, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0x0(0)
PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

inbound pcp sas:

outbound esp sas:

outbound ah sas:

outbound pcp sas:

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.19.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 500
PERMIT, flags={origin_is_acl,}
#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 0, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1400, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0x0(0)
PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

inbound pcp sas:

outbound esp sas:

outbound ah sas:

outbound pcp sas:

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.16.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 500
PERMIT, flags={origin_is_acl,}
#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 145, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1400, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0x0(0)
PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

inbound pcp sas:

outbound esp sas:

outbound ah sas:

outbound pcp sas:

protected vrf: (none)
local ident (addr/mask/prot/port): (10.0.130.32/255.255.255.224/0/0)
remote ident (addr/mask/prot/port): (10.0.17.0/255.255.255.0/0/0)
current_peer 194.78.59.5 port 500
PERMIT, flags={origin_is_acl,}
#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0
#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0
#pkts compressed: 0, #pkts decompressed: 0
#pkts not compressed: 0, #pkts compr. failed: 0
#pkts not decompressed: 0, #pkts decompress failed: 0
#send errors 0, #recv errors 0

local crypto endpt.: 109.135.19.130, remote crypto endpt.: 194.78.59.5
plaintext mtu 1400, path mtu 1400, ip mtu 1400, ip mtu idb Dialer0
current outbound spi: 0x0(0)
PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

inbound pcp sas:

outbound esp sas:

outbound ah sas:

outbound pcp sas:

OCWRTR01#show ip access-lists 100
Extended IP access list 100
10 permit ip 10.0.130.32 0.0.0.31 10.0.4.0 0.0.0.255
20 permit ip 10.0.130.32 0.0.0.31 10.0.10.0 0.0.0.255 (2239 matches)
30 permit ip 10.0.130.32 0.0.0.31 10.0.11.0 0.0.0.255
40 permit ip 10.0.130.32 0.0.0.31 10.0.12.0 0.0.0.255 (1026 matches)
50 permit ip 10.0.130.32 0.0.0.31 10.0.13.0 0.0.0.255
60 permit ip 10.0.130.32 0.0.0.31 10.0.14.0 0.0.0.255
70 permit ip 10.0.130.32 0.0.0.31 10.0.15.0 0.0.0.255
80 permit ip 10.0.130.32 0.0.0.31 10.0.16.0 0.0.0.255 (269 matches)
90 permit ip 10.0.130.32 0.0.0.31 10.0.17.0 0.0.0.255
100 permit ip 10.0.130.32 0.0.0.31 10.0.18.0 0.0.0.255
110 permit ip 10.0.130.32 0.0.0.31 10.0.19.0 0.0.0.255
OCWRTR01#show ip access-lists 101
Extended IP access list 101
10 deny ip 10.0.130.32 0.0.0.31 10.0.0.0 0.0.255.255 (4731 matches)
20 permit ip 10.0.130.32 0.0.0.31 any (2162 matches)

GADFRWL01# show access-list Outside_cryptomap_120
access-list Outside_cryptomap_120; 11 elements
access-list Outside_cryptomap_120 line 1 extended permit ip object-group GAD 10.0.130.32 255.255.255.224 0x3ff2d724
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.10.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=10869) 0x6e0e53ca
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.11.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=0) 0x69637245
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.12.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=9674) 0x61d7afc7
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.13.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=0) 0xa6a10c8d
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.14.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=0) 0xa99da925
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.15.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=0) 0xe91b16f9
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.16.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=10545) 0xa833eb3e
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.17.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=9) 0x97b5b02
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.18.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=0) 0x4f38d6a5
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.19.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=0) 0x6c50456
access-list Outside_cryptomap_120 line 1 extended permit ip 10.0.4.0 255.255.255.0 10.0.130.32 255.255.255.224 (hitcnt=0) 0x6a287bca

also tried a packet tracer from the main site (see attachment) ...

 

a ping from the main site to the remote site does work.

After I logged on the device with ip 10.0.12.32 and did a ping to 10.0.130.33, the packetracer on the ASA does allow the packet to be send succesfully.

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

that did it !!!!!!!

Final config ...
!
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 8.8.8.8
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 isakmp invalid-spi-recovery
!
!
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
set pfs group2
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 virtual-reassembly in
ip tcp adjust-mss 1412
!
interface Dialer0
mtu 1400
ip address 109.135.19.130 255.255.255.0
ip nat outside
ip virtual-reassembly in max-reassemblies 1024
ip virtual-reassembly out max-reassemblies 1024
encapsulation ppp
ip tcp adjust-mss 1360
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
!
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 list 101 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.4.0 0.0.0.255
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.10.0 0.0.0.255
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.11.0 0.0.0.255
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.12.0 0.0.0.255
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.13.0 0.0.0.255
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.14.0 0.0.0.255
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.15.0 0.0.0.255
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.16.0 0.0.0.255
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.17.0 0.0.0.255
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.18.0 0.0.0.255
access-list 100 permit ip 10.0.130.32 0.0.0.31 10.0.19.0 0.0.0.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

Hello Jeroen,

 

good stuff, glad it is resolved...

Thanks for all your time and effort!
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: