Date: Fri, 11 Jan 2013 11:50:47 +0100 From: Hans Petter Selasky <hselasky@c2i.net> To: Andreas Longwitz <longwitz@incore.de> Cc: freebsd-isdn@freebsd.org Subject: Re: ISDN4BSD (HPS version) is going into ports Message-ID: <201301111150.47312.hselasky@c2i.net> In-Reply-To: <50EF40E4.7030805@incore.de> References: <509E87EF.9070607@incore.de> <201301101756.16289.hselasky@c2i.net> <50EF40E4.7030805@incore.de>
next in thread | previous in thread | raw e-mail | index | archive | help
On Thursday 10 January 2013 23:29:56 Andreas Longwitz wrote:
> 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.
Hi,
Looks like you are almost there. I will reply to your other comments later.
Can you try to add a printf in "src/sys/i4b/driver/i4b_isppp.c":
static void
i4bisppp_start(struct ifnet *ifp)
{
struct i4bisppp_softc *sc = ifp->if_softc;
printf("ifp=%p sc=%p\n", sc, ifp);
is the "sc" NULL ?
Looks like another issue.
--HPS
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?201301111150.47312.hselasky>