PPP problems (fwd)

Carsten Pluntke (su0289@sx2.hrz.uni-dortmund.de)
Thu, 30 Jul 1998 08:31:34 +0200 (MET DST)


Although I'm using an Amiga 4000 with CyberStorm PPC (and therefor the
Linux-APUS-Kernel), I think (I'm convinced :) that this problem is less
architecture dependent but more of general interest.

Connecting to a Server driven by Windows NT I risk my Linux kernel (still
2.1.105) crashing.

The crash itself is not reproducible at all extent (sometimes I'm lucky),
but the dumped logs are all the same in the main points (meaning PC and
other registers show the same)

----------8<------- kernel messages log ----------------------------------
Jul 27 23:03:51 atlas syslogd 1.3-3: restart.
Jul 27 23:03:51 atlas kernel: klogd 1.3-3, log source = /proc/kmsg started.
Jul 27 23:03:52 atlas kernel: Loaded 9886 symbols from /usr/src/linux/System.map.
Jul 27 23:03:52 atlas kernel: Symbols match kernel version 2.1.105.
Jul 27 23:03:52 atlas kernel: No module symbols loaded - kernel modules not enabled.
Jul 27 23:03:52 atlas kernel: Total memory = 80MB; using 512kB for hash table (at c0180000)
Jul 27 23:03:52 atlas kernel: Linux version 2.1.105 (root@Atlas) (gcc version egcs-2.90.29 980515 (egcs-1.0.3 release)) #5 Mon Jul 27 17:29:13 UTC 1998
Jul 27 23:03:52 atlas kernel: Amiga hardware found: [A4000] VIDEO BLITTER AUDIO FLOPPY A4000_IDE KEYBOARD MOUSE SERIAL PARALLEL A3000_CLK CHIP_RAM PAULA LISA ALICE_PAL ZORRO3
Jul 27 23:03:52 atlas kernel: Probing AutoConfig expansion device(s):
Jul 27 23:03:52 atlas kernel: 00e90000: MacroSystems Germany VLab Video Board (64K)
Jul 27 23:03:52 atlas kernel: 00ea0000: BSC/Alfadata Oktagon 2008 SCSI Host Adapter (64K)
Jul 27 23:03:52 atlas kernel: 00eb0000: BSC/Alfadata Tandem AT-2008/508 IDE Interface (64K)
Jul 27 23:03:52 atlas kernel: 00ec0000: Reis-Ware Handyscanner Scanner Interface (64K)
Jul 27 23:03:52 atlas kernel: 00f00d44: Phase 5 CyberStorm Mk III Accelerator and SCSI Host Adapter (64K)
Jul 27 23:03:52 atlas kernel: PowerUp Bus Speed: 66MHz
Jul 27 23:03:52 atlas kernel: time_init: decrementer frequency = 990000000/60
Jul 27 23:03:52 atlas kernel: fb0: Amiga AGA frame buffer device, using 1280K of video memory
Jul 27 23:03:52 atlas kernel: kmem_alloc: NULL ptr (name=unknown)
Jul 27 23:03:52 atlas kernel: Console: colour frame buffer device 80x25
Jul 27 23:03:52 atlas kernel: Calibrating delay loop... 394.85 BogoMIPS
Jul 27 23:03:52 atlas kernel: Memory: 78500k available (1048k kernel code, 1860k data, 0k init) [c0000000,c5000000]
Jul 27 23:03:52 atlas kernel: VFS: Diskquotas version dquot_6.4.0 initialized
Jul 27 23:03:52 atlas kernel: POSIX conformance testing by UNIFIX
Jul 27 23:03:52 atlas kernel: Swansea University Computer Society NET3.039 for Linux 2.1
Jul 27 23:03:52 atlas kernel: NET3: Unix domain sockets 0.16 for Linux NET3.038.
Jul 27 23:03:52 atlas kernel: Swansea University Computer Society TCP/IP for NET3.037
Jul 27 23:03:52 atlas kernel: IP Protocols: ICMP, UDP, TCP
Jul 27 23:03:52 atlas kernel: Starting kswapd v 1.5
Jul 27 23:03:52 atlas kernel: M68K Serial driver version 1.01
Jul 27 23:03:52 atlas kernel: ttyS0 at 0x80dff018: Amiga builtin
Jul 27 23:03:52 atlas kernel: lp_init: lp using interrupt driver
Jul 27 23:03:52 atlas kernel: lp0: Builtin parallel port at 0x80bfe101
Jul 27 23:03:52 atlas kernel: Amiga mouse installed.
Jul 27 23:03:52 atlas kernel: DMA sound driver installed, using 4 buffers of 32k.
Jul 27 23:03:52 atlas kernel: Ramdisk driver initialized : 16 ramdisks of 4096K size
Jul 27 23:03:52 atlas kernel: ide0: Gayle IDE interface (A4000 style)
Jul 27 23:03:52 atlas kernel: hda: Maxtor 7540 AV, ATA DISK drive
Jul 27 23:03:52 atlas kernel: ide0 at 80dd2020 on irq 0x0000000c
Jul 27 23:03:52 atlas kernel: ide0: unexpected interrupt, status=0x51, count=1
Jul 27 23:03:52 atlas kernel: hda: Maxtor 7540 AV, 515MB w/32kB Cache, CHS=1046/16/63
Jul 27 23:03:52 atlas kernel: FD: probing units
Jul 27 23:03:52 atlas kernel: found fd0
Jul 27 23:03:52 atlas kernel: SCSI ID 7 Clock 25 MHz CCF=0 Time-Out 167 NCR53C9x(esp236) detected
Jul 27 23:03:52 atlas kernel:
Jul 27 23:03:52 atlas kernel: ESP: Total of 1 ESP hosts found, 1 actually in use.
Jul 27 23:03:52 atlas kernel: scsi0 : BSC Oktagon SCSI
Jul 27 23:03:52 atlas kernel: scsi : 1 host.
Jul 27 23:03:52 atlas kernel: Vendor: TEAC Model: MT-01F Rev: RV H
Jul 27 23:03:52 atlas kernel: Type: Sequential-Access ANSI SCSI revision: 02
Jul 27 23:03:52 atlas kernel: Detected scsi tape st0 at scsi0, channel 0, id 0, lun 0
Jul 27 23:03:52 atlas kernel: ide0: unexpected interrupt, status=0x51, count=10
Jul 27 23:03:52 atlas kernel: Vendor: QUANTUM Model: FIREBALL_TM2110S Rev: 300N
Jul 27 23:03:52 atlas kernel: Type: Direct-Access ANSI SCSI revision: 02
Jul 27 23:03:52 atlas kernel: Detected scsi disk sda at scsi0, channel 0, id 3, lun 0
Jul 27 23:03:52 atlas kernel: Vendor: TOSHIBA Model: CD-ROM XM-3401TA Rev: 3593
Jul 27 23:03:52 atlas kernel: Type: CD-ROM ANSI SCSI revision: 02
Jul 27 23:03:52 atlas kernel: Detected scsi CD-ROM sr0 at scsi0, channel 0, id 5, lun 0
Jul 27 23:03:52 atlas kernel: Vendor: IOMEGA Model: ZIP 100 Rev: J.02
Jul 27 23:03:52 atlas kernel: Type: Direct-Access ANSI SCSI revision: 02
Jul 27 23:03:52 atlas kernel: Detected scsi removable disk sdb at scsi0, channel 0, id 6, lun 0
Jul 27 23:03:52 atlas kernel: scsi : detected 1 SCSI tape 1 SCSI cdrom 2 SCSI disks total.
Jul 27 23:03:52 atlas kernel: esp0: Disabling sync for buggy Toshiba CDROM.
Jul 27 23:03:52 atlas kernel: esp0: Disabling DISCONNECT for target 5 lun 0
Jul 27 23:03:52 atlas kernel: esp0: target 5 asynchronous
Jul 27 23:03:52 atlas kernel: Uniform CD-ROM driver Revision: 2.12
Jul 27 23:03:52 atlas kernel: esp0: target 3 [period 200ns offset 15 5.00MHz synchronous SCSI]
Jul 27 23:03:52 atlas kernel: SCSI device sda: hdwr sector= 512 bytes. Sectors= 4124736 [2014 MB] [2.0 GB]
Jul 27 23:03:52 atlas kernel: sdb : READ CAPACITY failed.
Jul 27 23:03:52 atlas kernel: sdb : status = 0, message = 00, host = 0, driver = 28
Jul 27 23:03:52 atlas kernel: sdb : extended sense code = 2
Jul 27 23:03:52 atlas kernel: sdb : block size assumed to be 512 bytes, disk size 1GB.
Jul 27 23:03:52 atlas kernel: PPP: version 2.3.5 (demand dialling)
Jul 27 23:03:52 atlas kernel: TCP compression code copyright 1989 Regents of the University of California
Jul 27 23:03:52 atlas kernel: PPP line discipline registered.
Jul 27 23:03:52 atlas kernel: IP-Config: No network devices available.
Jul 27 23:03:52 atlas kernel: Partition check:
Jul 27 23:03:52 atlas kernel: sda: RDSK sda1 sda2 sda3 sda4 sda5 sda6
Jul 27 23:03:52 atlas kernel: sdb:scsidisk I/O error: dev 08:10, sector 0
Jul 27 23:03:52 atlas kernel: unable to read partition table
Jul 27 23:03:52 atlas kernel: hda: RDSK hda1 hda2 hda3
Jul 27 23:03:52 atlas kernel: VFS: Mounted root (ext2 filesystem) readonly.
Jul 27 23:03:52 atlas kernel: Freeing unused kernel memory: 0k init
Jul 27 23:03:52 atlas kernel: Adding Swap: 34996k swap-space (priority -1)
Jul 27 23:03:52 atlas kernel: AFFS: Dircache FS - mounting 08:04 read only
Jul 27 23:03:52 atlas kernel: AFFS: Dircache FS - mounting 08:05 read only

--- (configuration and diagnostics stuff) ---
(don't care about the sdb entries, it's an empty ZIP drive)

Jul 28 05:31:09 atlas pppd[1809]: pppd 2.3.5 started by root, uid 0
Jul 28 05:31:32 atlas pppd[1809]: Serial connection established.
Jul 28 05:31:33 atlas kernel: ppp_tty_ioctl: set flags to 190000
Jul 28 05:31:33 atlas kernel: ppp_tty_ioctl: set flags to 190000
Jul 28 05:31:33 atlas kernel: ppp_tty_ioctl: set xasyncmap
Jul 28 05:31:33 atlas kernel: ppp_tty_ioctl: set xmit asyncmap ffffffff
Jul 28 05:31:33 atlas kernel: ppp_tty_ioctl: set flags to 190000
Jul 28 05:31:33 atlas kernel: ppp_tty_ioctl: set mru to 5dc
Jul 28 05:31:33 atlas kernel: ppp_tty_ioctl: set rcv asyncmap ffffffff
Jul 28 05:31:33 atlas kernel: ppp_tty_ioctl: set flags to 190000
Jul 28 05:31:33 atlas pppd[1809]: Using interface ppp0
Jul 28 05:31:33 atlas pppd[1809]: Connect: ppp0 <--> /dev/modem1
Jul 28 05:31:34 atlas kernel: ppp_tty_ioctl: set xmit asyncmap 0
Jul 28 05:31:34 atlas kernel: ppp_tty_ioctl: set flags to f190002
Jul 28 05:31:34 atlas kernel: ppp_tty_ioctl: set mru to 5dc
Jul 28 05:31:34 atlas kernel: ppp_tty_ioctl: set rcv asyncmap ffffffff
Jul 28 05:31:34 atlas kernel: ppp_tty_ioctl: set flags to f190002
Jul 28 05:31:35 atlas pppd[1809]: Remote message:
Jul 28 05:31:35 atlas kernel: ppp_tty_ioctl: set flags to f190042
Jul 28 05:31:36 atlas pppd[1809]: local IP address 190.0.0.1
Jul 28 05:31:36 atlas pppd[1809]: remote IP address 190.0.0.0
Jul 28 05:31:36 atlas kernel: ppp_tty_ioctl: set maxcid to 16
Jul 28 05:31:36 atlas kernel: ppp_tty_ioctl: set flags to f19004e
Jul 28 05:31:36 atlas kernel: ppp: channel ppp0 going up for IP packets!
Jul 28 05:31:39 atlas kernel: ppp_tty_ioctl: set flags to f19000e
Jul 28 05:33:19 atlas kernel: NIP: *C0010084* XER: 20000000 LR: *C00CF424*
REGS: c27d9c70 TRAP: *0300*
Jul 28 05:33:19 atlas kernel: MSR: *00009972 EE: 1 PR: 0 FP: 0 ME: 1
IR/DR: 11*
Jul 28 05:33:19 atlas kernel: TASK = c27d8000[192] 'kfm' mm->pgd c27d6000 Last syscall: 142
Jul 28 05:33:19 atlas kernel: last math c27d8000
Jul 28 05:33:19 atlas kernel: GPR00: 3DD304C6 C27D9D60 C27D8000 *C4FFFFFC*
*C311C755* 07000000 C203B830 00000000
Jul 28 05:33:19 atlas kernel: GPR08: 00000000 C203B829 00000020 00000000
00000000 01957840 002BB1CC 00000000
Jul 28 05:33:19 atlas kernel: GPR16: FFFFFFFF FFFFFFFF 00000000 00000001
00001972 0A7D9E80 00000000 C0004520
Jul 28 05:33:19 atlas kernel: GPR24: 00000009 C3115384 00000000 C203B820
00000000 C311538C C2A82CC0 C31153A0
Jul 28 05:33:19 atlas kernel: Call backtrace:
Jul 28 05:33:19 atlas kernel: *C00CF36C C00D12B0 C00D0F94 C00D0E90
C00D0A70 C00B790C C0012C64
Jul 28 05:33:19 atlas kernel: C001A3A4 C0004588* 305AE890 304CE4CC
304266E0 3042C538 3042C8B0
Jul 28 05:33:19 atlas kernel: 3042D4EC 3042C5F0 018473CC 0180BB88
Jul 28 05:33:19 atlas kernel: Kernel panic: kernel access of bad area
pc *c0010084 lr c00cf424 address C5000000* tsk kfm/192

----------------------------------------------------------------

Enclosed in *'s there are the parts which are equal each crash.

Now come the symbols of the addresses in the marked parts of the call
backtrace...

C0010084 (PC) ip_fast_csum
C00CF36C slhc_uncompress
C00D12B0 rcv_proto_vjc_comp
C00D0F94 ppp_doframe_lower
C00D0E90 ppp_doframe
C00D0A70 ppp_tty_receive
C00B790C flush_to_ldisc
C0012C64 tqueue_bh
C001A3A4 do_bottom_half
C0004588 int_return

ip_fast_csum is called from slhc_uncompress in drivers/net/slhc.c and
assumes that ip->ihl (second parameter to ip_fast_csum) is at least 5.

Since I'm no PPP, PPC assembler or IP guru (ip_fast_csum is in
arch/ppc/lib/checksum.S) I just assume the ip_fast_csum routine crashes
with a page fault if the second parameter is less than five or even zero
(badly terminated loop?) and have to ask if it's possible in the context
of slhc_uncompress.
(Note we're talking about a Windows NT PPP server, I assume it may send
packets which are not quite protocol-compliant :)

Carsten

-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.rutgers.edu
Please read the FAQ at http://www.altern.org/andrebalsa/doc/lkml-faq.html