 |
|
HP : 0 / 1
MP : 0 / 0
EXP : 0%
|
|
新手上路
成员等级: 1
发表总数: 1
金币总数: 12
所属组别: 普通成员
注册日期: 2006/03/22
|
网络状况：
1、分支部门连接中心机房，以2M为主用线路，isdn为备用，配置为DDR方式；
2、分支部门设一台2611，IOS为12.1，一个WIC-1T模块接2M，一个1B/ST模块接isdn；
3、2M线路通过BNC转V35转换器接入WIC-1T模块；
故障现象：
进行线路切换演练时，模拟2M线路故障，机房人员直接将BNC转V35转换器上的BNC接头拧下，isdn正常拨号，但是传输不稳定，而且很有规律，就是ping中心端时，每9个成功的ping包后紧接着12个request timed out包；
还有一点，如果切换时直接拔掉BNC转V35转换器电源或者拔掉WIC-1T模块上的插头，isdn正常拨号，而且传输稳定！即串口是line protocol is down时有故障，若是serial0/0 is down就正常。
开了几个debug，未发现明显的异常信息，只好开了debug all，贴上一段log请参考。
Sep 6 17:04:32.383: in L2_Go at bailout DLCB is 80FDA45C
Sep 6 17:04:32.383: in L2_Go going to process event
Sep 6 17:04:32.383: in L2_ProcessEvent
Sep 6 17:04:32.383: in L2_FindEventIndex
Sep 6 17:04:32.383: in S8_REJ_RNR_RR
Sep 6 17:04:32.387: in L2_ValidNR
Sep 6 17:04:32.387: in L2_AdvanceVA
Sep 6 17:04:32.387: L2IF_StopTimer: timer (0x80FDA8EC), timer_type (0x1240), ds
l (0), event (1240)
Sep 6 17:04:32.387: L2IF_StartTimer: started - timer (0x80FDA9D0)
Sep 6 17:04:32.387: L2IF_StartTimer: timer (80FDAA1C), dsl (0), ticks (10000),
event (1250)
Sep 6 17:04:32.387: in L2_InvokeRetransmission
Sep 6 17:04:32.387: isdn_l2_process: TIMER_EVENT
Sep 6 17:04:32.391: isdn_l2_process: state (0x0), event_count (1)
Sep 6 17:04:32.499: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
17744
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:32.515: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
18304
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:32.531: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
18864
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:32.543: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
19424
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:32.559: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
19984
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:32.563: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185118864 WIN 16400
Sep 6 17:04:32.567: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185119984 WIN 17520
Sep 6 17:04:32.567: ISDN BRI0/0: isdn_is_bchannel_available: No Free B-channels
Sep 6 17:04:32.571: BR0/0 isdn_get_free_dialer() returned NULL
Sep 6 17:04:32.571: NTP: adj(0.000068972), rem. offset = 0.000000000, adj = 0.0
00068972
Sep 6 17:04:32.727: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185120544 WIN 16960
Sep 6 17:04:33.127: Serial0/0: attempting to restart
Sep 6 17:04:33.127: PowerQUICC(0/0): DCD is up.
Sep 6 17:04:33.127: PowerQUICC(0/0): DCD is up.
Sep 6 17:04:33.535: NTP: adj(0.000067897), rem. offset = 0.000000000, adj = 0.0
00067897
Sep 6 17:04:33.583: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
20544
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:33.599: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
21104
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:33.611: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
21664
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:33.627: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
22224
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:33.643: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
22784
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:33.647: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185121664 WIN 17520
Sep 6 17:04:33.647: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185122784 WIN 16400
Sep 6 17:04:33.819: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185123344 WIN 17520
Sep 6 17:04:34.535: NTP: adj(0.000066839), rem. offset = 0.000000000, adj = 0.0
00066839
Sep 6 17:04:34.567: ISDN BRI0/0: isdn_is_bchannel_available: No Free B-channels
Sep 6 17:04:34.567: BR0/0 isdn_get_free_dialer() returned NULL
Sep 6 17:04:34.663: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
23344
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:34.679: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
23904
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:34.691: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
24464
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:34.707: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
25024
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:34.719: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
25584
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:34.723: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185124464 WIN 16400
Sep 6 17:04:34.727: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185125584 WIN 17520
Sep 6 17:04:34.911: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185126144 WIN 16960
Sep 6 17:04:35.531: NTP: adj(0.000065797), rem. offset = 0.000000000, adj = 0.0
00065797
Sep 6 17:04:35.743: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
26144
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:35.755: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
26704
DATA 434 ACK 892228847 PSH WIN 4038
Sep 6 17:04:35.759: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185127138 WIN 17520
Sep 6 17:04:36.123: is_up: 0 state: 4 sub state: 1 line: 0
Sep 6 17:04:36.531: NTP: adj(0.000064772), rem. offset = 0.000000000, adj = 0.0
00064772
Sep 6 17:04:36.567: ISDN BRI0/0: isdn_is_bchannel_available: No Free B-channels
Sep 6 17:04:36.567: BR0/0 isdn_get_free_dialer() returned NULL
Sep 6 17:04:36.755: BR0/0:2 PPP: I pkt type 0xC021, datagramsize 16
Sep 6 17:04:36.755: BR0/0:1 PPP: I pkt type 0xC021, datagramsize 16
Sep 6 17:04:36.755: BR0/0:2 LCP: I ECHOREQ [Open] id 8 len 12 magic 0x0F72008C
Sep 6 17:04:36.755: BR0/0:2 LCP: O ECHOREP [Open] id 8 len 12 magic 0x049C020B
Sep 6 17:04:36.759: BR0/0:1 LCP: I ECHOREQ [Open] id 8 len 12 magic 0x0F71F1CD
Sep 6 17:04:36.759: BR0/0:1 LCP: O ECHOREP [Open] id 8 len 12 magic 0x049BF34A
Sep 6 17:04:36.783: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
27138
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:36.795: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
27698
DATA 405 ACK 892228847 PSH WIN 4038
Sep 6 17:04:36.799: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185128103 WIN 16555
Sep 6 17:04:37.494: IP: ager ran for 0ms, 2 entries, 2 examined, 0 aged, 0 reap
ed
Sep 6 17:04:37.530: NTP: adj(0.000063763), rem. offset = 0.000000000, adj = 0.0
00063763
Sep 6 17:04:37.730: CDP-IP: Writing prefix 10.2.0.0/24
Sep 6 17:04:37.730: CDP-PA: version 2 packet sent out on Ethernet0/0
Sep 6 17:04:37.730: CDP-IP: Writing prefix 192.168.7.0/24
Sep 6 17:04:37.730: BR0/0 DDR: cdp, 284 bytes, outgoing uninteresting (no list
matched)
Sep 6 17:04:37.734: DDR: 02B46175 0001000A 32363131 5F370002 00110000 00010101
Sep 6 17:04:37.738: DDR: CC00040A 02000700 03000A42 5249302F 30000400 08000000
Sep 6 17:04:37.742: BR0/0 DDR: sending broadcast to ip 10.2.0.1
Sep 6 17:04:37.742: BR0/0:2 PPP: O pkt type 0x0207, datagramsize 288
Sep 6 17:04:37.746: CDP-PA: version 2 packet sent out on BRI0/0
Sep 6 17:04:37.818: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
28103
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:37.834: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
28663
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:37.842: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
29223
DATA 199 ACK 892228847 PSH WIN 4038
Sep 6 17:04:37.846: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185129223 WIN 17520
Sep 6 17:04:37.966: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185129422 WIN 17321
Sep 6 17:04:38.526: NTP: adj(0.000062769), rem. offset = 0.000000000, adj = 0.0
00062769
Sep 6 17:04:38.566: ISDN BRI0/0: isdn_is_bchannel_available: No Free B-channels
Sep 6 17:04:38.566: BR0/0 isdn_get_free_dialer() returned NULL
Sep 6 17:04:38.866: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
29422
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:38.878: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
29982
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:38.886: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
30542
DATA 158 ACK 892228847 PSH WIN 4038
Sep 6 17:04:38.890: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185130542 WIN 16201
Sep 6 17:04:39.058: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185130700 WIN 17520
Sep 6 17:04:39.526: NTP: adj(0.000061791), rem. offset = 0.000000000, adj = 0.0
00061791
Sep 6 17:04:39.910: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
30700
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:39.914: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
31260
DATA 68 ACK 892228847 PSH WIN 4038
Sep 6 17:04:39.918: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185131328 WIN 16892
Sep 6 17:04:40.522: NTP: adj(0.000060828), rem. offset = 0.000000000, adj = 0.0
00060828
Sep 6 17:04:40.566: ISDN BRI0/0: isdn_is_bchannel_available: No Free B-channels
Sep 6 17:04:40.566: BR0/0 isdn_get_free_dialer() returned NULL
Sep 6 17:04:40.934: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
31328
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:40.942: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
31888
DATA 154 ACK 892228847 PSH WIN 4038
Sep 6 17:04:40.946: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185132042 WIN 16178
Sep 6 17:04:41.114: Serial0/0: HDLC myseq 9, mineseen 0, yourseen 0, line down
Sep 6 17:04:41.522: NTP: adj(0.000059881), rem. offset = 0.000000000, adj = 0.0
00059881
Sep 6 17:04:41.970: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
32042
DATA 560 ACK 892228847 WIN 4038
Sep 6 17:04:41.970: tcp66: O ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 11851
32602
DATA 60 ACK 892228847 PSH WIN 4038
Sep 6 17:04:41.974: tcp66: I ESTAB 192.168.7.23:3133 192.168.7.254:23 seq 89222
8847
ACK 1185132662 WIN 17520
Sep 6 17:04:42.370: isdn_l2_process: TIMER_EVENT
Sep 6 17:04:42.370: l2_timer: started
Sep 6 17:04:42.370: l2_timer: timer (0x80FDA9D0), timer_type (0x1250)
Sep 6 17:04:42.370: L2_Go(): DSL_Id=0, SAPI=0, CES=1, Event=1250
Sep 6 17:04:42.370: in L2_Go source_id is 20A
Sep 6 17:04:42.370: in L2_Go at bailout DLCB is 80FDA45C
Sep 6 17:04:42.370: in L2_Go going to process event
Sep 6 17:04:42.370: in L2_ProcessEvent
Sep 6 17:04:42.374: in L2_FindEventIndex
Sep 6 17:04:42.374: in S7_T203_EXPIRY
Sep 6 17:04:42.374: in L2_TransmitEnquiry
Sep 6 17:04:42.374: L2IF_GetDriverID: started
Sep 6 17:04:42.374: Sending data on BRI/PRI 0 to 200
Sep 6 17:04:42.374: L2IF_SendprimPkt: started
 |
下载附件 |
| debug_all.txt ( 下载次数: 7 ) |
|
