From owner-freebsd-isdn@FreeBSD.ORG Thu Jan 10 22:30:01 2013 Return-Path: Delivered-To: freebsd-isdn@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by hub.freebsd.org (Postfix) with ESMTP id 5E8B5BA9 for ; Thu, 10 Jan 2013 22:30:01 +0000 (UTC) (envelope-from longwitz@incore.de) Received: from dss.incore.de (dss.incore.de [195.145.1.138]) by mx1.freebsd.org (Postfix) with ESMTP id D40CADAE for ; Thu, 10 Jan 2013 22:30:00 +0000 (UTC) Received: from inetmail.dmz (inetmail.dmz [10.3.0.3]) by dss.incore.de (Postfix) with ESMTP id CFBDF5CC05; Thu, 10 Jan 2013 23:29:58 +0100 (CET) X-Virus-Scanned: amavisd-new at incore.de Received: from dss.incore.de ([10.3.0.3]) by inetmail.dmz (inetmail.dmz [10.3.0.3]) (amavisd-new, port 10024) with LMTP id qWywaxMAfD73; Thu, 10 Jan 2013 23:29:57 +0100 (CET) Received: from mail.incore (fwintern.dmz [10.0.0.253]) by dss.incore.de (Postfix) with ESMTP id 5255E5CBF8; Thu, 10 Jan 2013 23:29:57 +0100 (CET) Received: from bsdmhs.longwitz (unknown [192.168.99.6]) by mail.incore (Postfix) with ESMTP id 7CB7550876; Thu, 10 Jan 2013 23:29:56 +0100 (CET) Message-ID: <50EF40E4.7030805@incore.de> Date: Thu, 10 Jan 2013 23:29:56 +0100 From: Andreas Longwitz User-Agent: Thunderbird 2.0.0.19 (X11/20090113) MIME-Version: 1.0 To: Hans Petter Selasky Subject: Re: ISDN4BSD (HPS version) is going into ports References: <509E87EF.9070607@incore.de> <201301100813.33186.hselasky@c2i.net> <50EEA232.2030403@incore.de> <201301101756.16289.hselasky@c2i.net> In-Reply-To: <201301101756.16289.hselasky@c2i.net> Content-Type: text/plain; charset=ISO-8859-15 Content-Transfer-Encoding: 7bit Cc: freebsd-isdn@freebsd.org X-BeenThere: freebsd-isdn@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Using ISDN with FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 10 Jan 2013 22:30:01 -0000 Hans Petter Selasky wrote: > Can you try the attached patch? Revert the previous ones. Yes I did, but system always crashes after first ping immediately after ihfc_b_setup was called: i4b-L1 ihfc1: ihfc_B_setup: fifo(#2/#3), protocol_1=1 Fatal trap 12: page fault while in kernel mode cpuid = 1; apic id = 00 fault virtual address = 0xbe fault code = supervisor write, page not present instruction pointer = 0x20:0xc06c7bff stack pointer = 0x28:0xc49e8be8 frame pointer = 0x28:0xc49e8bfc code segment = base 0x0, limit 0xfffff, type 0x1b = DPL 0, pres 1, def32 1, gran 1 processor eflags = interrupt enabled, resume, IOPL = 0 current process = 12 (swi4: clock) [thread pid 12 tid 100006 ] Stopped at _mtx_lock_flags+0x1f: lock cmpxchgl %edx,0x10(%ecx) db:0:kdb.enter.default> watchdog No argument provided, disabling watchdog db:0:kdb.enter.default> run ddbinfo db:1:ddbinfo> capture on db:1:on> run lockinfo db:2:lockinfo> show lock Giant class: sleep mutex name: Giant flags: {DEF, RECURSE} state: {UNOWNED} db:2:Giant> show lockedvnods Locked vnodes db:2:lockedvnods> show lockchain thread 100006 (pid 12, swi4: clock) running on CPU 1 db:2:lockchain> show sleepchain thread 100006 (pid 12, swi4: clock) running on CPU 1 db:1:sleepchain> show pcpu cpuid = 1 dynamic pcpu = 0x3fbcd80 curthread = 0xc4d33000: pid 12 "swi4: clock" curpcb = 0xc49e8d80 fpcurthread = none idlethread = 0xc4d338a0: tid 100003 "idle: cpu1" APIC ID = 0 currentldt = 0x50 db:1:pcpu> show allpcpu Current CPU: 1 cpuid = 0 dynamic pcpu = 0x61ed80 curthread = 0xc4de38a0: pid 12 "irq23: ihfc1" curpcb = 0xe514bd80 fpcurthread = none idlethread = 0xc4d335c0: tid 100004 "idle: cpu0" APIC ID = 3 currentldt = 0x50 cpuid = 1 dynamic pcpu = 0x3fbcd80 curthread = 0xc4d33000: pid 12 "swi4: clock" curpcb = 0xc49e8d80 fpcurthread = none idlethread = 0xc4d338a0: tid 100003 "idle: cpu1" APIC ID = 0 currentldt = 0x50 db:1:allpcpu> bt Tracing pid 12 tid 100006 td 0xc4d33000 _mtx_lock_flags(ae,0,c0bff2a6,f8,c4d33000,...) at _mtx_lock_flags+0x1f i4bisppp_start(c5532800,0,c49e8c50,c06fb6fc,c0a3c02c,...) at i4bisppp_start+0x5a softclock(c0a379c0,c4d33000,0,109,56c88f72,...) at softclock+0x237 intr_event_execute_handlers(c4d31560,c4d76680,c097e974,52c,c4d766f0,...) at intr_event_execute_handlers+0x13b ithread_loop(c4d30180,c49e8d28,0,c4d31560,0,...) at ithread_loop+0x6b fork_exit(c06b0290,c4d30180,c49e8d28) at fork_exit+0x97 fork_trampoline() at fork_trampoline+0x8 --- trap 0, eip = 0, esp = 0xc49e8d60, ebp = 0 --- db:1:bt> ps pid ppid pgrp uid state wmesg wchan cmd 1584 1357 1584 1003 S+ select 0xc63fb0e4 ping 1577 1 1562 0 S+ select 0xc5be1a64 isdndecode 1576 1 1562 0 S+ select 0xc56cb4a4 isdndecode 1575 1 1562 0 S+ select 0xc63fb5e4 isdndecode 1542 1094 23 0 S nanslp 0xc0a37984 sleep 1357 1356 1357 1003 Ss+ wait 0xc5fd22b0 bash .... 100022 I [swi6: task queue] 100021 I [swi6: Giant taskq] 100019 I [swi5: +] 100008 I [swi3: vm] 100007 RunQ [swi4: clock] 100006 Run CPU 1 [swi4: clock] 100005 I [swi1: netisr 0] 11 0 0 0 RL (threaded) idle 100004 CanRun [idle: cpu0] 100003 CanRun [idle: cpu1] 1 0 1 0 SLs wait 0xc4d31ac0 [init] 10 0 0 0 SL audit_wo 0xc0a53ac0 [audit] 0 0 0 0 SLs (threaded) kernel 100040 D - 0xc56ca6c0 [dummynet] 100038 D - 0xc5534940 [mca taskq] 100023 D - 0xc4e106c0 [kqueue taskq] 100020 D - 0xc4e10940 [thread taskq] 100018 D - 0xc4e10a00 [ffs_trim taskq] 100017 D - 0xc4e10a40 [acpi_task_2] 100016 D - 0xc4e10a40 [acpi_task_1] 100015 D - 0xc4e10a40 [acpi_task_0] 100000 D sched 0xc0a350a0 [swapper] db:1:ps> show thread Thread 100006 at 0xc4d33000: proc (pid 12): 0xc4d31560 name: swi4: clock stack: 0xc49e7000-0xc49e8fff flags: 0x50004 pflags: 0x200500 state: RUNNING (CPU 1) priority: 52 container lock: sched lock 1 (0xc0a3c000) db:1:thread> alltrace Tracing command ping pid 1584 tid 100156 td 0xc639f8a0 sched_switch(c639f8a0,0,104,56ccd79a,15d,...) at sched_switch+0x293 mi_switch(104,0,c63fb0c0,c63eb000,e754fa2c,...) at mi_switch+0x12f sleepq_switch(c639f8a0,0,c0985116,1a5,c639f8a0,...) at sleepq_switch+0xcc sleepq_catch_signals(c63fb0c0,0,c639f8a0,e754fa78,c06910f7,...) at sleepq_catch_signals+0x52 sleepq_timedwait_sig(c63fb0e4,0,c0986a0f,101,0,...) at sleepq_timedwait_sig+0x1c _cv_timedwait_sig(c63fb0e4,c63fb0d0,3e9,c6292b44,58,...) at _cv_timedwait_sig+0x1b7 seltdwait(e754fc18,e754fc20,c62b1300,c639f8a0,e754fac8,...) at seltdwait+0xc1 kern_select(c639f8a0,4,bfbee884,0,0,e754fc60,20,0,f4233) at kern_select+0x571 select(c639f8a0,e754fcec,c,c,c,...) at select+0x66 syscall(e754fd28) at syscall+0x342 Xint0x80_syscall() at Xint0x80_syscall+0x21 --- syscall (93, FreeBSD ELF32, select), eip = 0x881ae053, esp = 0xbfbee77c, ebp = 0xbfbfec48 --- Tracing command intr pid 12 tid 100028 td 0xc4de38a0 cpustop_handler(1,e514bb60,c08fe166,0,e514bb0c,...) at cpustop_handler+0x34 ipi_nmi_handler(0,e514bb0c,c0606dbb,c5510000,c4d31560,...) at ipi_nmi_handler+0x2f trap(e514bb6c) at trap+0x36 calltrap() at calltrap+0x6 --- trap 0x13, eip = 0xc0bd4fd6, esp = 0xe514bbac, ebp = 0xe514bbc4 --- avm_pci_chip_read(c50cd000,80,c64a6820,0,c50cd000,...) at avm_pci_chip_read+0x56 filter_rx(e514bc1d,c50cd000,49,c50cde78,20,...) at filter_rx+0x5c rx_hdlc(c50cd000,c50cde78,8001ae30,c50cd000,c4d76b80,...) at rx_hdlc+0x5d i4b_ipac_rx_program(c50cd000,c50cde78,c4de38a0,e514bc4c,c4d335c0,...) at i4b_ipac_rx_program+0x4a __ihfc_chip_interrupt(c50cd000,0,c0bfceb7,39b,c4f212c0,...) at __ihfc_chip_interrupt+0x171 ihfc_chip_interrupt(c50cd000,c4de38a0,0,109,4dbdab7e,...) at ihfc_chip_interrupt+0x38 intr_event_execute_handlers(c4d31560,c4d76b80,c097e974,52c,c4d76bf0,...) at intr_event_execute_handlers+0x13b ithread_loop(c525b040,e514bd28,0,c4d31560,0,...) at ithread_loop+0x6b fork_exit(c06b0290,c525b040,e514bd28) at fork_exit+0x97 fork_trampoline() at fork_trampoline+0x8 --- trap 0, eip = 0, esp = 0xe514bd60, ebp = 0 --- ... If I revert the use of isac_remove_stat_fifo_map from your last patch and use my i4b_filter.h hack instead, then no crash occurs and D-channel is ok. >> I will do more work on B-channel analysis. It would be very helpful for >> me, if you can give an answer to the following question: >> >> After the B-channel is established, the other side starts sending the >> following data packet (from isdndecode of the other side): >> >> -- TE->NT - unit:00 frame:351318 - time:10.01 11:34:12.595168 - >> length:18 ---- >> B01:000 ff 03 c0 21 01 d8 00 0e 05 06 31 13 cd b3 03 04 >> B01:010 c0 23 >> >> What should we read in avm_pci_b_status_read() with >> >> if(temp == 0) temp = 32; >> /* read FIFO */ >> bus_space_read_multi_4(t, h, offset + HSCX_FIFO, >> (u_int32_t *)sc->sc_buffer, (temp + 3) / 4); >> >> if everything works correct and how many interrupts can we expect for >> the message of 18 bytes ? > > You should either get 32+32+32+32+32 and so on, or you will get: > (18+((number_of_bit_stuffings+7)/8) +2) bytes. > The other side sends 11 frames of length 18 in B-channel and with my last kernel described above I see login: i4b-L1 ihfc1: ihfc_B_setup: fifo(#2/#3), protocol_1=1 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=1 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=17 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=17 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=17 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=17 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=17 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=17 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=17 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=17 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=17 i4b-L1 ihfc1: avm_pci_b_status_read: HSCX_LEN=18, protocol_1=17 i4b-L1 ihfc1: ihfc_B_setup: fifo(#2/#3), protocol_1=0 The debug message comes from temp = bus_space_read_1(t, h, offset + HSCX_LEN); if (bootverbose == 2) IHFC_ERR("HSCX_LEN=%d, protocol_1=%d\n", temp, f->prot_curr.protocol_1); temp = temp & 0x3F; if(temp == 0) temp = 32; This proves that your use of 0x3F is ok. I am not sure, but it seems to me, that the use of __aligned for the sc_buffer has changed things. In the sourcefile i4b_avm_pci.h of the ports version 2.0.6 the __aligned option was not present, you have introduced this later in your repository. -- Andreas Longwitz