From owner-freebsd-isdn Wed Sep 23 12:21:01 1998 Return-Path: Received: (from majordom@localhost) by hub.freebsd.org (8.8.8/8.8.8) id MAA25716 for freebsd-isdn-outgoing; Wed, 23 Sep 1998 12:21:01 -0700 (PDT) (envelope-from owner-freebsd-isdn@FreeBSD.ORG) Received: from shire.domestic.de (kuebart.stuttgart.netsurf.de [194.233.216.182]) by hub.freebsd.org (8.8.8/8.8.8) with ESMTP id MAA25696 for ; Wed, 23 Sep 1998 12:20:52 -0700 (PDT) (envelope-from joki@kuebart.stuttgart.netsurf.de) Received: (from joki@localhost) by shire.domestic.de (8.8.8/8.8.7) id VAA00494; Wed, 23 Sep 1998 21:21:25 +0200 (CEST) (envelope-from joki) From: Joachim Kuebart Message-Id: <199809231921.VAA00494@shire.domestic.de> Subject: Problem with Q.931 implementation To: isdn@FreeBSD.ORG Date: Wed, 23 Sep 1998 21:21:24 +0200 (CEST) Cc: hm@kts.org X-Mailer: ELM [version 2.4ME+ PL31 (25)] MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Sender: owner-freebsd-isdn@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.org Hi, for a few weeks now, I've got the following problem: The log files lead me to conclude that some Q.931 isn't properly understood by the driver. Due to some follow-up errors this leads to a reboot as soon as a connection succeeds. This version of i4b: -rw-r--r-- 1 root bin 525165 10 Jul 10:10 i4b-00.63-alpha-100798.tgz This is the debug log: 1st attempt ------------- Sep 23 21:05:44 shire /kernel: isppp0: lcp open(initial) Sep 23 21:05:44 shire /kernel: isppp0: phase establish Sep 23 21:05:44 shire isdnd[214]: DBG msg_dialout: dial req from isppp, unit 0 Sep 23 21:05:44 shire isdnd[214]: DBG find_device: found entry 0! Sep 23 21:05:44 shire isdnd[214]: DBG FSM event [msg-dialout]: [idle => dialing] Sep 23 21:05:44 shire isdnd[214]: DBG F_DIAL: local dial out request Sep 23 21:05:44 shire isdnd[214]: DBG select_first_dialno: only one no, no = 726704 Sep 23 21:05:44 shire isdnd[214]: CHD 00004 Netsurf rate 240 sec/unit (rate) Sep 23 21:05:44 shire isdnd[214]: CHD 00004 Netsurf dialing out from 653706 to 726704 Sep 23 21:05:44 shire isdnd[214]: CHD 00004 Netsurf outgoing call proceeding (ctl 0, ch 0) Sep 23 21:05:45 shire isdnd[214]: CHD 00004 Netsurf incoming alert Sep 23 21:05:45 shire /kernel: isppp0: Up event Sep 23 21:05:45 shire /kernel: isppp0: lcp up(starting) Sep 23 21:05:45 shire /kernel: isppp0: lcp output Sep 23 21:05:45 shire isdnd[214]: DBG msg_charging: 1 unit(s) (estimated) Sep 23 21:05:45 shire /kernel: i4b-L3-i4b_decode_q931_message: STATUS message ^^^^^^^^^^^^^^^^^^^^^^^^^^ First error condition Sep 23 21:05:45 shire /kernel: i4b-L2-i4b_i_frame_queued_up: V(S) == ((V(A) + k) & 127)! Sep 23 21:05:45 shire /kernel: i4b-L2-i4b_i_frame_queued_up: state = ST_MULTIFR Sep 23 21:05:45 shire /kernel: i4b-L2-i4b_print_l2var: unit0 V(R)=13, V(S)=11, V(A)=10,ACKP=0,PBSY=0,OBSY=0 Sep 23 21:05:45 shire isdnd[214]: CHD 00004 Netsurf outgoing call active (ctl 0, ch 0) Sep 23 21:05:45 shire /kernel: isppp0: lcp down(req-sent) Sep 23 21:05:45 shire /kernel: isppp0: Down event (carrier loss) Sep 23 21:05:45 shire /kernel: isppp0: lcp close(starting) Sep 23 21:05:46 shire /kernel: isppp0: phase dead Sep 23 21:05:45 shire isdnd[214]: DBG exec_prog: popmail, args: 00004 Netsurf outgoing call active (ctl 0, ch 0) Sep 23 21:05:45 shire isdnd[214]: DBG FSM event [msg-con-act-ind]: [dialing => connected] Sep 23 21:05:45 shire isdnd[214]: DBG F_DOK: dial out ok Sep 23 21:05:45 shire isdnd[214]: DBG select_this_dialno: index = 0, no = 726704 Sep 23 21:05:45 shire isdnd[214]: DBG normal child (pid=1384) termination, exitstat = 0 Sep 23 21:05:45 shire isdnd[214]: DBG msg_charging: 1 unit(s) (AOCE) Sep 23 21:05:45 shire isdnd[214]: CHD 00004 Netsurf outgoing call disconnected (remote) Sep 23 21:05:45 shire isdnd[214]: CHD 00004 Netsurf cause 101: Message not compatible with call state (Q.850) Sep 23 21:05:45 shire isdnd[214]: CHD 00004 Netsurf charging: 1 units, 0 seconds Sep 23 21:05:45 shire isdnd[214]: CHD 00004 Netsurf accounting: in 0, out 19 (in 0, out 0) Sep 23 21:05:45 shire isdnd[214]: DBG FSM event [msg-disc-ind]: [connected => idle] Sep 23 21:05:45 shire isdnd[214]: DBG F_IDIS: disconnect indication 2nd attempt ------------- Sep 23 21:05:52 shire /kernel: isppp0: lcp open(initial) Sep 23 21:05:52 shire /kernel: isppp0: phase establish Sep 23 21:05:52 shire isdnd[214]: DBG msg_dialout: dial req from isppp, unit 0 Sep 23 21:05:52 shire isdnd[214]: DBG find_device: found entry 0! Sep 23 21:05:52 shire isdnd[214]: DBG FSM event [msg-dialout]: [idle => dialing] Sep 23 21:05:52 shire isdnd[214]: DBG F_DIAL: local dial out request Sep 23 21:05:52 shire isdnd[214]: DBG select_first_dialno: only one no, no = 726704 Sep 23 21:05:52 shire isdnd[214]: CHD 00005 Netsurf rate 240 sec/unit (rate) Sep 23 21:05:52 shire isdnd[214]: CHD 00005 Netsurf dialing out from 653706 to 726704 Sep 23 21:05:52 shire /kernel: i4b-L3-i4b_decode_q931: cannot find calldescriptor for cr = 0x65, crflag = 0x1, msg = 0x4d, frame = 0x4d 0x8 0x2 0x82 0xd1 ^^^^^^^^^^^^^^^^^^^^^ Now something weired is happening... Sep 23 21:05:56 shire /kernel: i4b-L3-T303_timeout: SETUP not answered, cr = 41 Sep 23 21:05:56 shire /kernel: i4b-L3-i4b_decode_q931: cannot find calldescriptor for cr = 0x65, crflag = 0x1, msg = 0x4d, frame = 0x4d 0x8 0x2 0x82 0xd1 Sep 23 21:05:56 shire isdnd[214]: CHD 00005 Netsurf outgoing call proceeding (ctl 0, ch 0) Sep 23 21:05:57 shire isdnd[214]: CHD 00005 Netsurf incoming alert Sep 23 21:05:57 shire /kernel: isppp0: Up event Sep 23 21:05:57 shire /kernel: isppp0: lcp up(starting) Sep 23 21:05:57 shire /kernel: isppp0: lcp output Sep 23 21:05:57 shire /kernel: isppp0: lcp input(req-sent): Sep 23 21:05:57 shire /kernel: isppp0: lcp parse opts: 0x0 [rej] mru auth-proto 0x11 [rej] 0x13 [rej] send conf-rej Sep 23 21:05:57 shire /kernel: isppp0: lcp output Sep 23 21:05:57 shire /kernel: isppp0: lcp input(req-sent): Sep 23 21:05:57 shire /kernel: isppp0: lcp rej opts: auth-proto [don't insist on auth for callout] Sep 23 21:05:57 shire /kernel: isppp0: lcp output Sep 23 21:05:58 shire /kernel: isppp0: lcp input(req-sent): Sep 23 21:05:58 shire /kernel: isppp0: lcp parse opts: mru auth-proto Sep 23 21:05:58 shire /kernel: isppp0: lcp parse opt values: mru 1524 auth-proto send conf-ack Sep 23 21:05:58 shire /kernel: isppp0: lcp output Sep 23 21:05:58 shire /kernel: isppp0: lcp input(ack-sent): Sep 23 21:05:58 shire /kernel: isppp0: lcp tlu Sep 23 21:05:58 shire /kernel: isppp0: phase authenticate Sep 23 21:05:57 shire isdnd[214]: DBG msg_charging: 1 unit(s) (estimated) Sep 23 21:05:58 shire /kernel: isppp0: chap input Sep 23 21:05:58 shire /kernel: isppp0: chap output Sep 23 21:05:58 shire /kernel: isppp0: chap success: \x0 Sep 23 21:05:58 shire /kernel: isppp0: phase network Sep 23 21:05:58 shire /kernel: isppp0: ipcp open(initial) Sep 23 21:05:58 shire /kernel: isppp0: ipcp up(starting) Sep 23 21:05:58 shire /kernel: isppp0: ipcp output Sep 23 21:05:58 shire /kernel: isppp0: ipcp input(req-sent): Sep 23 21:05:58 shire /kernel: isppp0: ipcp parse opts: compression [rej] address send conf-rej Sep 23 21:05:58 shire /kernel: isppp0: ipcp output Sep 23 21:05:58 shire /kernel: isppp0: ipcp input(req-sent): Sep 23 21:05:58 shire /kernel: isppp0: ipcp nak opts: address [wantaddr 194.233.216.182] [agree] Sep 23 21:05:59 shire /kernel: isppp0: ipcp output Sep 23 21:05:59 shire /kernel: isppp0: ipcp input(req-sent): Sep 23 21:05:59 shire /kernel: isppp0: ipcp parse opts: address Sep 23 21:05:59 shire /kernel: isppp0: ipcp parse opt values: address 0.0.0.1 [ack] send conf-ack Sep 23 21:05:59 shire /kernel: isppp0: ipcp output Sep 23 21:05:59 shire /kernel: isppp0: ipcp input(ack-sent): Sep 23 21:05:59 shire /kernel: isppp0: ipcp tlu Sep 23 21:08:00 shire syslogd: restart ^^^^^^^ And now this... :-( Sep 23 21:08:00 shire /kernel: Copyright (c) 1992-1998 FreeBSD Inc. Sep 23 21:08:00 shire /kernel: Copyright (c) 1982, 1986, 1989, 1991, 1993 Sep 23 21:08:00 shire /kernel: The Regents of the University of California. All rights reserved. Sep 23 21:08:01 shire /kernel: Sep 23 21:08:01 shire /kernel: FreeBSD 2.2.6-STABLE #0: Wed Sep 23 19:45:55 CEST 1998 ... This is the isdn part of dmesg: isic0 at 0x240 irq 10 flags 0x8 on isa isic0: AVM A1 or AVM Fritz!Card isic0: ISAC 2085 Version A1/A2 or 2086/2186 Version 1.1 (IOM-2) (Addr=0x1620) isic0: HSCX 82525 or 21525 Version 2.1 (AddrA=0x620, AddrB=0xe20) i4b: ISDN call control device attached i4bisppp: 4 ISDN SyncPPP device(s) attached i4bctl: ISDN system control port attached i4bipr: 4 IP over raw HDLC ISDN device(s) attached i4btel: 2 ISDN telephony interface device(s) attached i4brbch: 4 raw B channel access device(s) attached i4btrc: 4 ISDN trace device(s) attached cu Jo --------------------------------------------------------------------- FreeBSD: The Power to Serve Joachim Kuebart Tel: +49 711 653706 Replicants are like any other machine -- Germany they're either a benefit or a hazard. To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-isdn" in the body of the message