From owner-freebsd-isdn Wed Apr 1 22:55:28 1998 Return-Path: Received: (from majordom@localhost) by hub.freebsd.org (8.8.8/8.8.8) id WAA08779 for freebsd-isdn-outgoing; Wed, 1 Apr 1998 22:55:28 -0800 (PST) (envelope-from owner-freebsd-isdn@FreeBSD.ORG) Received: from server.amis.net (server.amis.net [195.10.52.10]) by hub.freebsd.org (8.8.8/8.8.8) with ESMTP id WAA08765 for ; Wed, 1 Apr 1998 22:55:17 -0800 (PST) (envelope-from blaz@gold.amis.net) Received: (from uucp@localhost) by server.amis.net (8.8.8/8.8.8) with UUCP id IAA26917 for freebsd-isdn@freebsd.org; Thu, 2 Apr 1998 08:55:08 +0200 (CEST) Received: from localhost (blaz@localhost) by gold.amis.net (8.8.8/8.8.8) with SMTP id IAA00476 for ; Thu, 2 Apr 1998 08:52:40 +0200 (CEST) Date: Thu, 2 Apr 1998 08:52:40 +0200 (CEST) From: Blaz Zupan To: freebsd-isdn@FreeBSD.ORG Subject: Re: i4b-L1-F_ill:What is this? (fwd) Message-ID: MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII Sender: owner-freebsd-isdn@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.org Did anybody experience something like this? Anybody using an Ascom NT+2ab TA and a Teles 16.3 connected to it? Blaz Zupan, blaz@medinet.si, http://home.amis.net/blaz Medinet d.o.o., Linhartova 21, 2000 Maribor, Slovenia ---------- Forwarded message ---------- Date: Wed, 1 Apr 1998 23:28:27 +0200 (MET DST) From: Wolfgang Helbig To: Blaz Zupan Subject: Re: i4b-L1-F_ill:What is this? > > OK. This is a layer *3* illegal state, the applied patch fixed layer *1* > > illegal states. > > > > Your output shows that the TEI ID_Request didn't work. One possible reason for > > this *could* be a layer 1 problem. Another problem could be that your > > card does not interrupt at all. To help fixing it, please enter > > > > # isdndebug -l1 -s0xffff > > > > to turn on all debugging information right after rebooting your system. > > Then try to connect. Don't be terrified by the huge amount of debugging > > output from the kernel. Send us three pages of the /var/log/messages > > file, where this output is stored and we'll see. > > Here is what I get when the connection fails. I first typed the above > isdndebug command and then started my standard rc.isdn and then tried > pinging a host on the internet. The result was: Thanks for the reply. Your debugging output shows it *is* a layer 1 problem. The card was supposed to activate layer 1. And probably did so. (This might have happened before you got a chance to enable debugging output) But then the NT responded with a deactivation request, which is answered by another activation request from the card and which is normal. But now the NT does not reply to this activation request. This might be a bug in our software or a bug in the NT. To help us narrowing in the bug, do the following: - disable the isdn daemon, i. e. don't start it at next booting. - reboot - After rebooting enter isdndebug -l1 -s0xffff let it run for 5 minutes and send us the debugging information. This mail is CCed to freebsd-isdn, maybe someone else on this list has better ideas--or the same problem. Hope you don't mind Thanks Wolfgang > > Apr 1 21:36:47 gold isdnd[240]: DMN init_controller: controller 0 is Teles S0/16.3 > Apr 1 21:36:47 gold isdnd[240]: DMN init_controller: found 1 ISDN controller(s) > Apr 1 21:36:47 gold isdnd[240]: DMN daemon started (pid = 240) > Apr 1 21:36:48 gold /kernel: i4b-L1-isic_next_state: FSM event [EV_DR Deactivate Req]: [F7 Activated => F3c Deactivation] > Apr 1 21:36:49 gold /kernel: i4b-L1-F_DR: FSM function F_DR executing > Apr 1 21:36:49 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_TIM Activate Clocks] in state F7 Activated > Apr 1 21:36:49 gold /kernel: i4b-L1-dummy_mph_deactivate_ind: unit 0 > Apr 1 21:36:49 gold /kernel: i4b-L1-dummy_ph_deactivate_ind: unit 0 > Apr 1 21:36:49 gold /kernel: i4b-L1-isic_next_state: FSM event [EV_PU Power UP]: [F3c Deactivation => F3b Power Up] > Apr 1 21:36:50 gold /kernel: i4b-L1-F_PU: FSM function F_PU executing > Apr 1 21:36:50 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3c Deactivation > Apr 1 21:37:01 gold /kernel: isppp0: phase establish > Apr 1 21:37:01 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:01 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:01 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=4,count=7) > Apr 1 21:37:01 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:01 gold isdnd[240]: DMN rate=240 sec/unit (day=3, beg=21, end=24, current=21) > Apr 1 21:37:01 gold isdnd[240]: CHD 00001 dialing out from 3001551 to 3003030 > Apr 1 21:37:03 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:03 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:03 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:03 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:03 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:05 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:05 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:05 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:05 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:05 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:05 gold /kernel: i4b-L3-T303_timeout: cr = 104 > Apr 1 21:37:05 gold /kernel: i4b-L3-next_l3state: FSM illegal state, state = ST_OW - Out Wait EST, event = EV_T303EXP - T303 timeout! > Apr 1 21:37:07 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:07 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:07 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:07 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:07 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:09 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:09 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:09 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:09 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:09 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:11 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:11 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:11 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:11 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:11 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:13 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:13 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:13 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:13 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=4,count=7) > Apr 1 21:37:13 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:15 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:15 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:15 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:15 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:15 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:17 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:17 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:17 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:17 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=4,count=7) > Apr 1 21:37:17 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:19 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:19 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:19 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:19 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:19 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:21 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:21 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:21 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:21 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:21 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:23 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:23 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:23 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:23 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:23 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:25 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:25 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:25 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:25 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:25 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:27 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:27 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:27 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:27 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:27 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:28 gold /kernel: isppp0: phase dead > Apr 1 21:37:28 gold isdnd[240]: DMN daemon terminating, exitval = 15 > Apr 1 21:37:29 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:29 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:29 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:29 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=4,count=7) > Apr 1 21:37:29 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:31 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:31 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:31 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:31 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:31 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:33 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:33 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:33 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:33 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=4,count=7) > Apr 1 21:37:33 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:35 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:35 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:35 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:35 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=6,count=7) > Apr 1 21:37:35 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:37 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:37 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:37 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:37 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:37 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:39 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:39 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:39 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:39 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:39 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:41 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:41 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:41 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:41 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > Apr 1 21:37:41 gold /kernel: i4b-L1-isic_isac_l1_cmd: cmd [CMD_AR8 Activation 8] in state F3b Power Up > Apr 1 21:37:43 gold /kernel: i4b-L2-i4b_T202_timeout: unit 0, N202 = 3 > Apr 1 21:37:43 gold /kernel: i4b-L2-i4b_tei_assign: tx TEI ID_Request > Apr 1 21:37:43 gold /kernel: i4b-L1-ph_data_req: Not in ST_F7, sc->sc_I430state = F3b Power Up > Apr 1 21:37:43 gold /kernel: i4b-L1-isic_isac_enable_clk: clocks already running, return (i=5,count=7) > > When this happens, the S0 bus is basically dead, when I pick up the phone > I can hear a signal from my NT that tells me that all channels are busy. I > can reboot or turn off my computer, the S0 bus is still dead. After about > 2 minutes I can hear the NT click (it's an Ascom NT+2ab) and the S0 bus is > alive again. > > All other relevant data: FreeBSD 2.2.6-BETA on i486 with Teles 16.3, i4b > 0.50 plus the one TEI patch that you posted to freebsd-isdn. Ascom > NT+2ab. Siemens EWSD switch at the telco. Two analog phones connected to > both ports on the NT+2ab, nothing else on the S0 bus. The teles is on IRQ > 12 (if it matters any), all the other IRQ's are occupied (NE2000 network > card on IRQ 10, Adaptec 2940 on IRQ 11, S3 VGA card on 2/9, internal US > Robotics Sportster on IRQ 5. Terminal server accepting the call is a > Livingston Portmaster 3. > > I hope this is enough data to get you going. If you need more, just ask. > > Best regards, > > Blaz Zupan, blaz@medinet.si, http://home.amis.net/blaz > Medinet d.o.o., Linhartova 21, 2000 Maribor, Slovenia > > To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-isdn" in the body of the message