Bug 5869

Another ppp failure in 2.6.15.  This one led to a panic.

Begin forwarded message:

Date: Wed, 11 Jan 2006 13:15:07 -0800
From: bugme-daemon@bugzilla.kernel.org
To: bugme-new@lists.osdl.org
Subject: [Bugme-new] [Bug 5869] New: After pon: Kernel BUG at net/core/skbuff.c:94 - seems to disable keyboard


http://bugzilla.kernel.org/show_bug.cgi?id=5869

           Summary: After pon: Kernel BUG at net/core/skbuff.c:94 - seems to
                    disable keyboard
    Kernel Version: 2.6.15
            Status: NEW
          Severity: high
             Owner: acme@conectiva.com.br
         Submitter: wol@kulmbach.net


Most recent kernel where this bug did not occur: 2.6.9 (did not test any later) 
Distribution: 64bit Debian 
Hardware Environment: AMD64, PS/2 keyboard, 3COM US Robotics modem 
Software Environment: dist-upgrade on 2006-01-10 
Problem Description: First: I am not really familiar with kernel bug reporting. 
So if you have questions, ask me at wol (at) kulmbach (dot) net 
 
I did a dist-upgrade and a kernel-update from 2.6.9 to 2.6.15. Afterwards: When 
I do a pon, a bug report (attached below) is filed to the logs. The behaviour I 
observe is: I seem to get no connection, although it seems to login at my 
provider. AND: My keyboard stops working while it dials. So after the first 
pon, I have no keyboard until rebooting. 
 
After several seconds, the modem shuts up. 
 
Steps to reproduce: 
 
Log: 
 
Jan 11 21:22:02 eiswiese pppd[2372]: pppd 2.4.4b1 started by root, uid 0 
Jan 11 21:22:03 eiswiese chat[2373]: abort on (BUSY) 
Jan 11 21:22:03 eiswiese chat[2373]: abort on (NO CARRIER) 
Jan 11 21:22:03 eiswiese chat[2373]: abort on (VOICE) 
Jan 11 21:22:03 eiswiese chat[2373]: abort on (NO DIALTONE) 
Jan 11 21:22:03 eiswiese chat[2373]: abort on (NO DIAL TONE) 
Jan 11 21:22:03 eiswiese chat[2373]: abort on (NO ANSWER) 
Jan 11 21:22:03 eiswiese chat[2373]: abort on (DELAYED) 
Jan 11 21:22:03 eiswiese chat[2373]: send (AT&F1X3^M) 
Jan 11 21:22:03 eiswiese chat[2373]: expect (OK) 
Jan 11 21:22:03 eiswiese chat[2373]: AT&F1X3^M^M 
Jan 11 21:22:03 eiswiese chat[2373]: OK 
Jan 11 21:22:03 eiswiese chat[2373]:  -- got it 
Jan 11 21:22:03 eiswiese chat[2373]: send (ATDT019102244^M) 
Jan 11 21:22:04 eiswiese chat[2373]: expect (CONNECT) 
Jan 11 21:22:04 eiswiese chat[2373]: ^M 
Jan 11 21:22:29 eiswiese chat[2373]: ATDT019102244^M^M 
Jan 11 21:22:29 eiswiese chat[2373]: CONNECT 
Jan 11 21:22:29 eiswiese chat[2373]:  -- got it 
Jan 11 21:22:29 eiswiese chat[2373]: send (\d) 
Jan 11 21:22:30 eiswiese pppd[2372]: Serial connection established. 
Jan 11 21:22:30 eiswiese pppd[2372]: using channel 1 
Jan 11 21:22:30 eiswiese pppd[2372]: Using interface ppp0 
Jan 11 21:22:30 eiswiese pppd[2372]: Connect: ppp0 <--> /dev/ttyS0 
Jan 11 21:22:31 eiswiese pppd[2372]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> 
<magic 0x59aedb80> <pcomp> <accomp>] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [LCP ConfReq id=0x1 <mru 1524> 
<asyncmap 0x0> <auth pap> <pcomp> <accomp> <mrru 15 
24> <endpoint [local:73.74.61.63.6b.69.6e.67]>] 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [LCP ConfRej id=0x1 <mrru 1524>] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> 
<magic 0x59aedb80> <pcomp> <accomp>] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [LCP ConfReq id=0x2 <mru 1524> 
<asyncmap 0x0> <auth pap> <pcomp> <accomp> <endpoin 
t [local:73.74.61.63.6b.69.6e.67]>] 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [LCP ConfAck id=0x2 <mru 1524> 
<asyncmap 0x0> <auth pap> <pcomp> <accomp> <endpoin 
t [local:73.74.61.63.6b.69.6e.67]>] 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [LCP EchoReq id=0x0 magic=0x59aedb80] 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [PAP AuthReq id=0x1 
user="ONCOM/BNK-00823" password=<hidden>] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [LCP EchoRep id=0x0 magic=0x0] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [PAP AuthAck id=0x1 ""] 
Jan 11 21:22:32 eiswiese pppd[2372]: PAP authentication succeeded 
Jan 11 21:22:32 eiswiese pppd[2372]: kernel does not support PPP filtering 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [CCP ConfReq id=0x1 <deflate 15> 
<deflate(old#) 15>] 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 
01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 
 0.0.0.0>] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [IPCP ConfReq id=0x1 <compress VJ 0f 
01> <addr 193.158.132.145>] 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [IPCP ConfAck id=0x1 <compress VJ 0f 
01> <addr 193.158.132.145>] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 
04>] 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [CCP ConfRej id=0x1 < 11 05 00 01 
04>] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [CCP ConfRej id=0x1 <deflate 15> 
<deflate(old#) 15>] 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [CCP ConfReq id=0x2] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [IPCP ConfNak id=0x1 <addr 
217.250.225.117> <ms-dns1 217.237.151.97> <ms-dns3 217. 
237.150.33>] 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [IPCP ConfReq id=0x2 <compress VJ 0f 
01> <addr 217.250.225.117> <ms-dns1 217.237.1 
51.97> <ms-dns3 217.237.150.33>] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [CCP ConfReq id=0x2 < 11 06 00 01 01 
03>] 
Jan 11 21:22:32 eiswiese pppd[2372]: sent [CCP ConfRej id=0x2 < 11 06 00 01 01 
03>] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [CCP ConfRej id=0x2] 
Jan 11 21:22:32 eiswiese pppd[2372]: rcvd [IPCP ConfAck id=0x2 <compress VJ 0f 
01> <addr 217.250.225.117> <ms-dns1 217.237.1 
51.97> <ms-dns3 217.237.150.33>] 
Jan 11 21:22:32 eiswiese pppd[2372]: Cannot determine ethernet address for 
proxy ARP 
Jan 11 21:22:32 eiswiese pppd[2372]: local  IP address 217.250.225.117 
Jan 11 21:22:32 eiswiese pppd[2372]: remote IP address 193.158.132.145 
Jan 11 21:22:32 eiswiese pppd[2372]: primary   DNS address 217.237.151.97 
Jan 11 21:22:32 eiswiese pppd[2372]: secondary DNS address 217.237.150.33 
Jan 11 21:22:32 eiswiese pppd[2372]: Script /etc/ppp/ip-up started (pid 2393) 
Jan 11 21:22:33 eiswiese pppd[2372]: Script /etc/ppp/ip-up finished (pid 2393), 
status = 0x0 
Jan 11 21:22:45 eiswiese kernel: skb_over_panic: text:ffffffff802ce17a len:8 
put:8 head:ffff8100125a0800 data:ffff8101125a08 
03 tail:ffff8101125a080b end:ffff8100125a0e00 dev:<NULL> 
Jan 11 21:22:45 eiswiese kernel: ----------- [cut here ] --------- [please bite 
here ] --------- 
Jan 11 21:22:45 eiswiese kernel: Kernel BUG at net/core/skbuff.c:94 
Jan 11 21:22:45 eiswiese kernel: invalid operand: 0000 [1] PREEMPT 
Jan 11 21:22:45 eiswiese kernel: CPU 0 
Jan 11 21:22:45 eiswiese kernel: Modules linked in: ipv6 usb_storage sd_mod 
scsi_mod vfat fat 
Jan 11 21:22:45 eiswiese kernel: Pid: 3, comm: events/0 Not tainted 2.6.15 #1 
Jan 11 21:22:45 eiswiese kernel: RIP: 0010:[<ffffffff8032ad9c>] 
<ffffffff8032ad9c>{skb_over_panic+92} 
Jan 11 21:22:45 eiswiese kernel: RSP: 0000:ffff81001fe8fda8  EFLAGS: 00010096 
Jan 11 21:22:45 eiswiese kernel: RAX: 000000000000009a RBX: 0000000000000008 
RCX: ffffffff80433590 
Jan 11 21:22:45 eiswiese kernel: RDX: ffffffff80433590 RSI: 0000000000000001 
RDI: ffff81001da6f020 
Jan 11 21:22:45 eiswiese kernel: RBP: ffff810018de2000 R08: 000000003b9aca00 
R09: ffff81001ded4980 
Jan 11 21:22:45 eiswiese kernel: R10: 0000000000000010 R11: 0000000000000010 
R12: 0000000000000008 
Jan 11 21:22:45 eiswiese kernel: R13: ffff810012ffa5d0 R14: ffff8101125a0803 
R15: ffff810012ffa1d0 
Jan 11 21:22:45 eiswiese kernel: FS:  00002aaab1db1e80(0000) 
GS:ffffffff804ed800(0000) knlGS:0000000000000000 
Jan 11 21:22:45 eiswiese kernel: CS:  0010 DS: 0018 ES: 0018 CR0: 
000000008005003b 
Jan 11 21:22:45 eiswiese kernel: CR2: 00002aaaad4b7bb0 CR3: 0000000014657000 
CR4: 00000000000006e0 
Jan 11 21:22:45 eiswiese kernel: Process events/0 (pid: 3, threadinfo 
ffff81001fe8e000, task ffff81001fe80710) 
Jan 11 21:22:45 eiswiese kernel: Stack: ffff8101125a080b ffff8100125a0e00 
ffffffff803dfef3 ffffffff802ce184 
Jan 11 21:22:45 eiswiese kernel:        ffff810018de2088 ffff810012ffa000 
0000000000000286 ffff810012ffa000 
Jan 11 21:22:45 eiswiese kernel:        ffff810012ffa018 0000000000000008 
Jan 11 21:22:45 eiswiese kernel: Call 
Trace:<ffffffff802ce184>{ppp_asynctty_receive+564} 
<ffffffff80286d80>{flush_to_ldisc+0 
} 
Jan 11 21:22:45 eiswiese kernel:        <ffffffff80286ea6>{flush_to_ldisc+294} 
<ffffffff801430ed>{worker_thread+509} 
Jan 11 21:22:45 eiswiese kernel:        
<ffffffff8012d310>{default_wake_function+0} <ffffffff80142ef0>{worker_thread+0} 
Jan 11 21:22:45 eiswiese kernel:        <ffffffff80142ef0>{worker_thread+0} 
<ffffffff80147bcb>{kthread+219} 
Jan 11 21:22:45 eiswiese kernel:        <ffffffff8010f6fa>{child_rip+8} 
<ffffffff80147af0>{kthread+0} 
Jan 11 21:22:45 eiswiese kernel:        <ffffffff8010f6f2>{child_rip+0} 
Jan 11 21:22:45 eiswiese kernel: 
Jan 11 21:22:45 eiswiese kernel: Code: 0f 0b 68 ba 25 40 80 c2 5e 00 48 83 c4 
18 c3 66 66 90 66 90 
Jan 11 21:22:45 eiswiese kernel: RIP <ffffffff8032ad9c>{skb_over_panic+92} RSP 
<ffff81001fe8fda8> 
Jan 11 21:22:45 eiswiese kernel:  <6>note: events/0[3] exited with 
preempt_count 1 
Jan 11 21:25:02 eiswiese pppd[2372]: No response to 4 echo-requests 
Jan 11 21:25:02 eiswiese pppd[2372]: Serial link appears to be disconnected. 
Jan 11 21:25:02 eiswiese pppd[2372]: Connect time 2.5 minutes. 
Jan 11 21:25:02 eiswiese pppd[2372]: Sent 3186 bytes, received 3320 bytes. 
Jan 11 21:25:02 eiswiese pppd[2372]: Script /etc/ppp/ip-down started (pid 2441) 
Jan 11 21:25:02 eiswiese pppd[2372]: sent [LCP TermReq id=0x2 "Peer not 
responding"] 
Jan 11 21:25:02 eiswiese pppd[2372]: Script /etc/ppp/ip-down finished (pid 
2441), status = 0x0 
Jan 11 21:25:05 eiswiese pppd[2372]: sent [LCP TermReq id=0x3 "Peer not 
responding"] 
Jan 11 21:25:08 eiswiese pppd[2372]: Connection terminated.

------- You are receiving this mail because: -------
You are on the CC list for the bug, or are watching someone who is.

Created attachment 7048 [details]
/var/log/messages helpful portion - bug does not disable keyboard but network definitely yes

Comment on attachment 7048 [details]
/var/log/messages helpful portion - bug does not disable keyboard but network definitely yes

bug appeared twice today while surfing the web via bluetooth and gprs,

bug causes oops (my arch is AMD64) for rfcomm and bluetooth gprs connection
remains stuck

This could be a hardware problem or a compiler bug.  The data/tail pointers are
off by about 0x100000000.

Is this a vanilla kernel?

We have the same bug reported downstream:
http://bugs.gentoo.org/119467

I have asked him to reproduce it on vanilla 2.6.16-rc1 and will get back to you

Should be fixed by:

http://www.kernel.org/git/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=8243126c5e29030bf1a3fb75187a513966dcba62

I can't tell if it's queued for -stable or not -- it should be but
the tree hasn't been updated for a while:

http://www.kernel.org/git/?p=linux/kernel/git/chrisw/stable-queue.git;a=summary

Would somebody please close this bug?