john doe
2003-11-09 08:08:39 UTC
Hello,
I have a Cisco 800 SoHo router here with an ISDN dial-on-demand
connection to Demon. Theory is that it dials in when somebody wants to
get mail or access the web.
However, the router is dialing in like crazy (every few minutes) and
the telephone bil is horrendous.
When I go into DEBUG ISDN mode I see loads of errors (see log file
below) so I think it is not a bad configured station or some spyware
goign crazy or such, I think the cisco is somehow defective or the
ISND line is bad, causing the thing to retry and retry and retry, 24
hours per day. This also because of all the L3 errors which I think
you should not see at alll under normal circumstances.
Could anybody with more knowledge of these things give an educated
opinion on this?
Thanks!
Dries
LOGFILE:
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80
changed to up
17:01:17179910144: ISDN BR0: Activating
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.200
[51043]
17:01:04: Di1 DDR: ip (s=212.238.118.102, d=62.69.162.200), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:04: BR0 DDR: rotor dialout [priority]
17:01:04: BR0 DDR: Dialing cause ip (s=212.238.118.102,
d=62.69.162.200)
17:01:04: BR0 DDR: Attempting to dial 0676033666
17:01:04: ISDN BR0: Outgoing call id = 0x817E, dsl 0
17:01:04: DDR: Packet queued
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.200
[51044]
17:01:04: Di1 DDR: ip (s=212.238.118.102, d=62.69.162.200), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:04: DDR: Packet queued
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.200
[51045]
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=194.159.73.24
[51046]
17:01:04: Di1 DDR: ip (s=212.238.118.102, d=194.159.73.24), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:04: DDR: Packet queued
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.200 [4754]
17:01:04: Di1 DDR: ip (s=212.238.118.102, d=62.69.162.200), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17179869192: BRI0: wait for isdn carrier timeout, call id=0x817E
17:01:17187258988: DDR: Dialing failed, 9 packets unqueued and
discarded
17:01:17179869184: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80
changed to up
17:01:17187259236: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80
changed to up
17:01:17179910144: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80
changed to up
17:01:17179910144: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80
changed to up
17:01:17179910144: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17180722859: ISDN BR0: Shutting down ME
17:01:17179869184: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:18005569792: %ISDN-6-LAYER2DOWN: Layer 2 for Interface BRI0, TEI
80 changed to down
17:01:17179869184: %ISDN-6-LAYER2DOWN: Layer 2 for Interface BR0, TEI
80 changed to down
17:01:21474836479: L3: NLCB watch! cid 0x4B82F4 cr 0x73AA98 ev 0x211
ces 222 dsl 0
17:01:04: ISDN BR0: L1 is IF_ACTIVE
17:01:04: ISDN BR0: Event: Call to 0676033666 at 64 Kb/s
17:01:04: ISDN BR0: process_bri_call(): call id 0x817E, called_number
0676033666
, speed 64, call type DATA
17:01:17179910144: CC_CHAN_GetIdleChanbri: dsl 0
17:01:17179910144: Found idle channel B1
17:01:17187250612: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 96
changed to up
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.8 [4758]
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=212.72.38.71 [4759]
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.6 [4760]
17:01:04: %LINEPROTO-5-UPDOWN: Line protocol on Interface BRI0:1,
changed state
to down
17:01:17187275004: ISDN BR0: received HOST_PROCEEDING call_id 0x817E
17:01:25769844736: ISDN BR0: received HOST_ALERTING call_id 0x817E
17:01:25769803776: ISDN BR0: HOST_ALERTING: DEV_CALL_PROGRESSING:
VOICE ERROR: Bearer capability not available(0x3A): bchan 1, call id
817E
17:01:25777209596: ISDN BR0: received HOST_CONNECT call_id 0x817E
17:01:25769803787: %LINK-3-UPDOWN: Interface BRI0:2, changed state to
up
17:01:25769803776: BRI0:2: Expired call id received. id = 0x817E
17:01:25769803840: ISDN BR0: Event: Connected to <unknown> on B2 at 64
Kb/s
17:01:06: ISDN BR0: Event: Hangup call to call id 0x817E
17:01:06: ISDN BR0: process_disconnect(): call id 0x817E, call type is
DATA, b_idb 0x27A8130, ces 1, cause Normal call clearing(0x10)
17:01:25777209596: ISDN BR0: received HOST_DISCONNECT_ACK call_id
0x817E
17:01:25769803776: ISDN BR0: HOST_DISCONNECT_ACK: call type is DATA
17:01:30064771071: %LINK-3-UPDOWN: Interface BRI0:2, changed state to
down
17:01:25769803840: BR0:2 DDR: disconnecting call
17:01:09: %FW-6-SESS_AUDIT_TRAIL: http session initiator
(192.168.10.2:1086) sen
t 333 bytes -- responder (62.69.162.8:80) sent 464 bytes
17:01:68719476736: %ISDN-6-LAYER2DOWN: Layer 2 for Interface BR0, TEI
96 changed to down
17:01:68719517696: L3: NLCB watch! cid 0x4B82F4 cr 0x73AA5C ev 0x211
ces 222 dsl 0
17:01:37: ISDN BR0: Recvd MPH_EI1_IND from L1
17:01:38: ISDN BR0: Physical layer is IF_DOWN
17:01:163209629414: ISDN BR0: Shutting down ME
17:01:163208757248: ISDN BR0: Shutting down ISDN Layer 3
17:01:43: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.8 [4763]
17:01:43: Di1 DDR: ip (s=212.238.118.102, d=62.69.162.8), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:43: BR0 DDR: rotor dialout [priority]
17:01:43: BR0 DDR: Dialing cause ip (s=212.238.118.102, d=62.69.162.8)
17:01:43: BR0 DDR: Attempting to dial 0676033666
17:01:43: ISDN BR0: Outgoing call id = 0x817F, dsl 0
17:01:43: DDR: Packet queued
17:01:43: ISDN BR0: Event: Call to 0676033666 at 64 Kb/s
17:01:43: ISDN BR0: process_bri_call(): call id 0x817F, called_number
0676033666
, speed 64, call type DATA
17:01:184683634688: CC_CHAN_GetIdleChanbri: dsl 0
17:01:184683634688: Found idle channel B1
17:01:184683634688: ISDN BR0: Activating
17:01:184683634688: ISDN BR0: Could not bring up interface
17:01:184683593736: BRI0: wait for isdn carrier timeout, call
id=0x817F
17:01:184690983532: DDR: Dialing failed, 1 packets unqueued and
discarded
17:01:184683593728: ISDN BR0: Shutting down ISDN Layer 3
17:01:43: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.6 [4764]
17:01:43: Di1 DDR: ip (s=212.238.118.102, d=62.69.162.6), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:43: BR0 DDR: rotor dialout [priority]
17:01:43: BR0 DDR: Dialing cause ip (s=212.238.118.102, d=62.69.162.6)
17:01:43: BR0 DDR: Attempting to dial 0676033666
17:01:43: ISDN BR0: Outgoing call id = 0x8180, dsl 0
17:01:43: DDR: Packet queued
17:01:43: NAT: s=192.168.10.2->212.238.118.102, d=212.72.38.71 [4765]
17:01:43: Di1 DDR: ip (s=212.238.118.102, d=212.72.38.71), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:43: DDR: Packet queued
17:01:43: ISDN BR0: Event: Call to 0676033666 at 64 Kb/s
17:01:43: ISDN BR0: process_bri_call(): call id 0x8180, called_number
0676033666
, speed 64, call type DATA
17:01:184683634688: CC_CHAN_GetIdleChanbri: dsl 0
17:01:184683634688: Found idle channel B1
17:01:184690983780: ISDN BR0: Activating
17:01:184683634688: ISDN BR0: Could not bring up interface
17:01:184683593736: BRI0: wait for isdn carrier timeout, call
id=0x8180
17:01:184690983532: DDR: Dialing failed, 2 packets unqueued and
discarded
17:01:184683593728: ISDN BR0: Shutting down ISDN Layer 3
17:01:43: ISDN BR0: L1 is IF_ACTIVE
17:01:53: ISDN BR0: Recvd MPH_EI1_IND from L1
17:01:55: ISDN BR0: Physical layer is IF_DOWN
17:01:236223242240: ISDN BR0: Shutting down ME
17:01:236223242240: ISDN BR0: Shutting down ISDN Layer 3
I have a Cisco 800 SoHo router here with an ISDN dial-on-demand
connection to Demon. Theory is that it dials in when somebody wants to
get mail or access the web.
However, the router is dialing in like crazy (every few minutes) and
the telephone bil is horrendous.
When I go into DEBUG ISDN mode I see loads of errors (see log file
below) so I think it is not a bad configured station or some spyware
goign crazy or such, I think the cisco is somehow defective or the
ISND line is bad, causing the thing to retry and retry and retry, 24
hours per day. This also because of all the L3 errors which I think
you should not see at alll under normal circumstances.
Could anybody with more knowledge of these things give an educated
opinion on this?
Thanks!
Dries
LOGFILE:
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80
changed to up
17:01:17179910144: ISDN BR0: Activating
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.200
[51043]
17:01:04: Di1 DDR: ip (s=212.238.118.102, d=62.69.162.200), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:04: BR0 DDR: rotor dialout [priority]
17:01:04: BR0 DDR: Dialing cause ip (s=212.238.118.102,
d=62.69.162.200)
17:01:04: BR0 DDR: Attempting to dial 0676033666
17:01:04: ISDN BR0: Outgoing call id = 0x817E, dsl 0
17:01:04: DDR: Packet queued
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.200
[51044]
17:01:04: Di1 DDR: ip (s=212.238.118.102, d=62.69.162.200), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:04: DDR: Packet queued
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.200
[51045]
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=194.159.73.24
[51046]
17:01:04: Di1 DDR: ip (s=212.238.118.102, d=194.159.73.24), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:04: DDR: Packet queued
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.200 [4754]
17:01:04: Di1 DDR: ip (s=212.238.118.102, d=62.69.162.200), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17179869192: BRI0: wait for isdn carrier timeout, call id=0x817E
17:01:17187258988: DDR: Dialing failed, 9 packets unqueued and
discarded
17:01:17179869184: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80
changed to up
17:01:17187259236: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80
changed to up
17:01:17179910144: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80
changed to up
17:01:17179910144: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80
changed to up
17:01:17179910144: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17180722859: ISDN BR0: Shutting down ME
17:01:17179869184: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:17179910144: ISDN BR0: Activating
17:01:17179910144: ISDN BR0: Could not bring up interface
17:01:17187259236: ISDN BR0: Shutting down ISDN Layer 3
17:01:18005569792: %ISDN-6-LAYER2DOWN: Layer 2 for Interface BRI0, TEI
80 changed to down
17:01:17179869184: %ISDN-6-LAYER2DOWN: Layer 2 for Interface BR0, TEI
80 changed to down
17:01:21474836479: L3: NLCB watch! cid 0x4B82F4 cr 0x73AA98 ev 0x211
ces 222 dsl 0
17:01:04: ISDN BR0: L1 is IF_ACTIVE
17:01:04: ISDN BR0: Event: Call to 0676033666 at 64 Kb/s
17:01:04: ISDN BR0: process_bri_call(): call id 0x817E, called_number
0676033666
, speed 64, call type DATA
17:01:17179910144: CC_CHAN_GetIdleChanbri: dsl 0
17:01:17179910144: Found idle channel B1
17:01:17187250612: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 96
changed to up
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.8 [4758]
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=212.72.38.71 [4759]
17:01:04: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.6 [4760]
17:01:04: %LINEPROTO-5-UPDOWN: Line protocol on Interface BRI0:1,
changed state
to down
17:01:17187275004: ISDN BR0: received HOST_PROCEEDING call_id 0x817E
17:01:25769844736: ISDN BR0: received HOST_ALERTING call_id 0x817E
17:01:25769803776: ISDN BR0: HOST_ALERTING: DEV_CALL_PROGRESSING:
VOICE ERROR: Bearer capability not available(0x3A): bchan 1, call id
817E
17:01:25777209596: ISDN BR0: received HOST_CONNECT call_id 0x817E
17:01:25769803787: %LINK-3-UPDOWN: Interface BRI0:2, changed state to
up
17:01:25769803776: BRI0:2: Expired call id received. id = 0x817E
17:01:25769803840: ISDN BR0: Event: Connected to <unknown> on B2 at 64
Kb/s
17:01:06: ISDN BR0: Event: Hangup call to call id 0x817E
17:01:06: ISDN BR0: process_disconnect(): call id 0x817E, call type is
DATA, b_idb 0x27A8130, ces 1, cause Normal call clearing(0x10)
17:01:25777209596: ISDN BR0: received HOST_DISCONNECT_ACK call_id
0x817E
17:01:25769803776: ISDN BR0: HOST_DISCONNECT_ACK: call type is DATA
17:01:30064771071: %LINK-3-UPDOWN: Interface BRI0:2, changed state to
down
17:01:25769803840: BR0:2 DDR: disconnecting call
17:01:09: %FW-6-SESS_AUDIT_TRAIL: http session initiator
(192.168.10.2:1086) sen
t 333 bytes -- responder (62.69.162.8:80) sent 464 bytes
17:01:68719476736: %ISDN-6-LAYER2DOWN: Layer 2 for Interface BR0, TEI
96 changed to down
17:01:68719517696: L3: NLCB watch! cid 0x4B82F4 cr 0x73AA5C ev 0x211
ces 222 dsl 0
17:01:37: ISDN BR0: Recvd MPH_EI1_IND from L1
17:01:38: ISDN BR0: Physical layer is IF_DOWN
17:01:163209629414: ISDN BR0: Shutting down ME
17:01:163208757248: ISDN BR0: Shutting down ISDN Layer 3
17:01:43: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.8 [4763]
17:01:43: Di1 DDR: ip (s=212.238.118.102, d=62.69.162.8), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:43: BR0 DDR: rotor dialout [priority]
17:01:43: BR0 DDR: Dialing cause ip (s=212.238.118.102, d=62.69.162.8)
17:01:43: BR0 DDR: Attempting to dial 0676033666
17:01:43: ISDN BR0: Outgoing call id = 0x817F, dsl 0
17:01:43: DDR: Packet queued
17:01:43: ISDN BR0: Event: Call to 0676033666 at 64 Kb/s
17:01:43: ISDN BR0: process_bri_call(): call id 0x817F, called_number
0676033666
, speed 64, call type DATA
17:01:184683634688: CC_CHAN_GetIdleChanbri: dsl 0
17:01:184683634688: Found idle channel B1
17:01:184683634688: ISDN BR0: Activating
17:01:184683634688: ISDN BR0: Could not bring up interface
17:01:184683593736: BRI0: wait for isdn carrier timeout, call
id=0x817F
17:01:184690983532: DDR: Dialing failed, 1 packets unqueued and
discarded
17:01:184683593728: ISDN BR0: Shutting down ISDN Layer 3
17:01:43: NAT: s=192.168.10.2->212.238.118.102, d=62.69.162.6 [4764]
17:01:43: Di1 DDR: ip (s=212.238.118.102, d=62.69.162.6), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:43: BR0 DDR: rotor dialout [priority]
17:01:43: BR0 DDR: Dialing cause ip (s=212.238.118.102, d=62.69.162.6)
17:01:43: BR0 DDR: Attempting to dial 0676033666
17:01:43: ISDN BR0: Outgoing call id = 0x8180, dsl 0
17:01:43: DDR: Packet queued
17:01:43: NAT: s=192.168.10.2->212.238.118.102, d=212.72.38.71 [4765]
17:01:43: Di1 DDR: ip (s=212.238.118.102, d=212.72.38.71), 40 bytes,
outgoing interesting (ip PERMIT)
17:01:43: DDR: Packet queued
17:01:43: ISDN BR0: Event: Call to 0676033666 at 64 Kb/s
17:01:43: ISDN BR0: process_bri_call(): call id 0x8180, called_number
0676033666
, speed 64, call type DATA
17:01:184683634688: CC_CHAN_GetIdleChanbri: dsl 0
17:01:184683634688: Found idle channel B1
17:01:184690983780: ISDN BR0: Activating
17:01:184683634688: ISDN BR0: Could not bring up interface
17:01:184683593736: BRI0: wait for isdn carrier timeout, call
id=0x8180
17:01:184690983532: DDR: Dialing failed, 2 packets unqueued and
discarded
17:01:184683593728: ISDN BR0: Shutting down ISDN Layer 3
17:01:43: ISDN BR0: L1 is IF_ACTIVE
17:01:53: ISDN BR0: Recvd MPH_EI1_IND from L1
17:01:55: ISDN BR0: Physical layer is IF_DOWN
17:01:236223242240: ISDN BR0: Shutting down ME
17:01:236223242240: ISDN BR0: Shutting down ISDN Layer 3