Hi,

for 180 days, my ISDN router (NetBSD/i386 1.6) has been working
well. Then for some reason, it went crazy:
isdnd dials out, immediately disconnects after connection
establishment, dials out again, disconnects, ad infimum (more
or less).

Here is an extract from isdnmonitor with debug messages
(watch out for msg_drvrdisc_req):
log: 18.11.2003 22:22:59 prio 7 what=DBG msg=setup_dialout: entry I4BPPP ok!
log: 18.11.2003 22:22:59 prio 7 what=DBG msg=find_by_device_for_dialout: found entry -1!
log: 18.11.2003 22:22:59 prio 7 what=DBG msg=msg_dialout: dial req from ippp0
log: 18.11.2003 22:22:59 prio 7 what=DBG msg=FSM event [msg-dialout]: [idle => dialing]
log: 18.11.2003 22:22:59 prio 7 what=DBG msg=F_DIAL: local dial out request
log: 18.11.2003 22:22:59 prio 7 what=DBG msg=select_first_dialno: only one no, no = dddddd
log: 18.11.2003 22:22:59 prio 6 what=CHD msg=03930 I4BPPP rate 300 sec/unit (conf)
log: 18.11.2003 22:22:59 prio 7 what=DBG msg=sendm_connect_req: ctrl = 0, chan = -1
log: 18.11.2003 22:22:59 prio 7 what=DBG msg=decr_free_channels: ctrl 0, now 1 chan free
log: 18.11.2003 22:23:00 prio 6 what=CHD msg=03930 I4BPPP dialing out from ssssss to dddddd
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 900000us - last 1069190579:860052 now 1069190580:8916
18.11.2003 22:23:00: layer 1 change on controller 0: up
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=msg_l12stat_ind: unit 0, layer 1, state 1
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 900000us - last 1069190579:860052 now 1069190580:83744
18.11.2003 22:23:00: controller 0, TEI is 78
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=msg_teiasg_ind: unit 0, tei = 78
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 900000us - last 1069190579:860052 now 1069190580:118633
18.11.2003 22:23:00: layer 2 change on controller 0: up
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=msg_l12stat_ind: unit 0, layer 2, state 1
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 900000us - last 1069190579:860052 now 1069190580:179137
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=set_channel_busy: controller [0] channel B1 set to BUSY!
log: 18.11.2003 22:23:00 prio 6 what=CHD msg=03930 I4BPPP outgoing call proceeding (ctl 0, ch 0)
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 900000us - last 1069190579:860052 now 1069190580:458687
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=msg_charging: 1 unit(s) (estimated)
18.11.2003 22:23:00: controller 0, channel 0, charge = 1 (estimated)
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 900000us - last 1069190579:860052 now 1069190580:483826
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=set_channel_busy: controller [0] channel B1 already busy!
log: 18.11.2003 22:23:00 prio 6 what=CHD msg=03930 I4BPPP outgoing call active (ctl 0, ch 0, ippp0)
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=exec_prog: /etc/isdn/scripts/ip_up.sh, args: 03930 I4BPPP outgoing call active (ctl 0, ch 0, ippp0)
18.11.2003 22:23:00: calling out to 'dddddd' [from msn: 'ssssss'], controller 0, channel 0, config 'I4BPPP' on device 'ippp0'
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=FSM event [msg-con-act-ind]: [dialing => connected]
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=F_DOK: dial out ok
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=select_this_dialno: index = 0, no = dddddd
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 900000us - last 1069190579:860052 now 1069190580:541976
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=ippp0: switched to state 3
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 900000us - last 1069190579:860052 now 1069190580:551549
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=msg_drvrdisc_req for call 3930
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=FSM event [disconnect-req]: [connected => waitdisconnect]
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=F_DRQ: local disconnect request
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=sendm_disconnect_req: sent DISCONNECT_REQ
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 900000us - last 1069190579:860052 now 1069190580:654937
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=msg_charging: 0 unit(s) (AOCD)
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time OK! - last 1069190579:860052 now 1069190580:827897
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 1 - last 1069190580:831434 now 1069190580:831780
log: 18.11.2003 22:23:00 prio 6 what=CHD msg=03930 I4BPPP outgoing call disconnected (local)
log: 18.11.2003 22:23:00 prio 6 what=CHD msg=03930 I4BPPP cause 0: normal call clearing (I4B)
18.11.2003 22:23:00: controller 0, channel 0 disconnected
log: 18.11.2003 22:23:00 prio 6 what=CHD msg=03930 I4BPPP charging: 0 units, 0 seconds
log: 18.11.2003 22:23:00 prio 6 what=CHD msg=03930 I4BPPP accounting: in 116, out 102 (in 0, out 0)
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=set_channel_idle: controller [0] channel B1 set to IDLE!
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=incr_free_channels: ctrl 0, now 2 chan free
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=FSM event [msg-disc-ind]: [waitdisconnect => idle]
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=F_MDI: disconnect indication, local disconnected
log: 18.11.2003 22:23:00 prio 7 what=DBG msg=time < 1 - last 1069190580:831434 now 1069190580:872905
log: 18.11.2003 22:23:01 prio 7 what=DBG msg=time OK! - last 1069190580:831434 now 1069190581:885521
log: 18.11.2003 22:23:02 prio 7 what=DBG msg=time OK! - last 1069190581:889958 now 1069190582:895485
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=setup_dialout: entry I4BPPP ok!
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=find_by_device_for_dialout: found entry -1!
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=msg_dialout: dial req from ippp0
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=FSM event [msg-dialout]: [idle => dialing]
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=F_DIAL: local dial out request
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=select_first_dialno: only one no, no = dddddd
log: 18.11.2003 22:23:03 prio 6 what=CHD msg=03931 I4BPPP rate 300 sec/unit (conf)
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=sendm_connect_req: ctrl = 0, chan = -1
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=decr_free_channels: ctrl 0, now 1 chan free
log: 18.11.2003 22:23:03 prio 6 what=CHD msg=03931 I4BPPP dialing out from ssssss to dddddd
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=time < 900000us - last 1069190582:899905 now 1069190583:53967
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=set_channel_busy: controller [0] channel B1 set to BUSY!
log: 18.11.2003 22:23:03 prio 6 what=CHD msg=03931 I4BPPP outgoing call proceeding (ctl 0, ch 0)
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=time < 900000us - last 1069190582:899905 now 1069190583:233749
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=msg_charging: 1 unit(s) (estimated)
18.11.2003 22:23:03: controller 0, channel 0, charge = 1 (estimated)
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=time < 900000us - last 1069190582:899905 now 1069190583:255756
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=set_channel_busy: controller [0] channel B1 already busy!
log: 18.11.2003 22:23:03 prio 6 what=CHD msg=03931 I4BPPP outgoing call active (ctl 0, ch 0, ippp0)
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=exec_prog: /etc/isdn/scripts/ip_up.sh, args: 03931 I4BPPP outgoing call active (ctl 0, ch 0, ippp0)
18.11.2003 22:23:03: calling out to 'dddddd' [from msn: 'ssssss'], controller 0, channel 0, config 'I4BPPP' on device 'ippp0'
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=FSM event [msg-con-act-ind]: [dialing => connected]
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=F_DOK: dial out ok
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=select_this_dialno: index = 0, no = dddddd
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=time < 900000us - last 1069190582:899905 now 1069190583:337775
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=ippp0: switched to state 3
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=time < 900000us - last 1069190582:899905 now 1069190583:343388
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=msg_drvrdisc_req for call 3931
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=FSM event [disconnect-req]: [connected => waitdisconnect]
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=F_DRQ: local disconnect request
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=sendm_disconnect_req: sent DISCONNECT_REQ
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=time < 900000us - last 1069190582:899905 now 1069190583:362355
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=msg_charging: 0 unit(s) (AOCD)
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=time < 900000us - last 1069190582:899905 now 1069190583:516650
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=time < 900000us - last 1069190582:899905 now 1069190583:520513
log: 18.11.2003 22:23:03 prio 6 what=CHD msg=03931 I4BPPP outgoing call disconnected (local)
log: 18.11.2003 22:23:03 prio 6 what=CHD msg=03931 I4BPPP cause 0: normal call clearing (I4B)
18.11.2003 22:23:03: controller 0, channel 0 disconnected
log: 18.11.2003 22:23:03 prio 6 what=CHD msg=03931 I4BPPP charging: 0 units, 0 seconds
log: 18.11.2003 22:23:03 prio 6 what=CHD msg=03931 I4BPPP accounting: in 116, out 102 (in 0, out 0)
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=set_channel_idle: controller [0] channel B1 set to IDLE!
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=incr_free_channels: ctrl 0, now 2 chan free
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=FSM event [msg-disc-ind]: [waitdisconnect => idle]
log: 18.11.2003 22:23:03 prio 7 what=DBG msg=F_MDI: disconnect indication, local disconnected

Note: I did not touch the machine (reloading isdnd.conf or
or something like that).

Reloading / restarting isdnd did not help. Neither did
ifconfig ippp0 down and then up. Or a shutdown to single
user mode and then going back to multi user.

Does anyone have an idea why msg_drvrdisc_req is sent?

Kind regards

    Ingolf