|
From: Ralf G. R. B. <ra...@RW...> - 2002-04-22 07:23:11
|
Hi there,
first the facts:
* I'm running kernel 2.4.18
* with FreeSwan 1.96 (Debian "testing" package ver. 1.96-1.2.)
* on a Debian testing system
* My internet connection is a leased line, CLIP (classical IP over ATM) over
ADSL, i.e. NO PPPoE!
* My ATM adapter is a NICstAr (Integrated Device Tech IDT77211 ATM Adapter
(rev 3))
I've just begun mucking around with FreeSWAN, so I would definitely call
myself a beginner. Therefore, please bear with me should I make any newbie
errors.
After the secure connection to the peer system has been established (AFAICT it
IS properly established, according to the messages I find in syslog) if I try
to ping the peer the machine locks hard with an oops.
I've decoded the oops. Here it is:
CPU: 0
EIP: 0010:[<c019c799>] Not tainted
Using defaults from ksymoops -t elf32-i386 -a i386
EFLAGS: 00010282
eax: 00000028 ebx: c26050b0 ecx: c4cac000 edx: c4fcb990
esi: c4c26c00 edi: c44ac0f4 ebp: c4c26b38 esp: c4cad7ec
ds: 0018 es: 0018 ss: 0018
Process ping (pid: 3601, stackpage=c4cad000)
Stack: c01f17e0 c01d6321 00000090 00000008 c4c26a00 c01d632a c26050b0 00000008
c01d6321 c4777c70 c4c26a00 c26050b0 c01b00d0 c01a624e c26050b0 c4c26a00
c02524c8 c4c26a00 00000000 c019ffe3 c4c26a00 c26050b0 00000000 00000004
Call Trace: [<c01d6321>] [<c01d632a>] [<c01d6321>] [<c01b00d0>] [<c01a624e>]
[<c019ffe3>] [<c01b015d>] [<c01a5a17>] [<c594d4f0>] [<c01b00a2>]
[<c01b00d0>]
[<c594d516>] [<c01a5a17>] [<c594c3ff>] [<c594d4f0>] [<c597de60>]
[<c010524d>]
[<c597de60>] [<c019fde5>] [<c01b00d0>] [<c01a624e>] [<c597de60>]
[<c597de60>]
[<c019ffe3>] [<c597de60>] [<c597de60>] [<c01a3506>] [<c01b015d>]
[<c597de60>]
[<c01a5a17>] [<c597de60>] [<c01b00b0>] [<c01aed2a>] [<c597de60>]
[<c01b00d0>]
[<c597de60>] [<c01b00bd>] [<c01a5a17>] [<c01af9c0>] [<c597de60>]
[<c01b00b0>]
[<c01c67ab>] [<c01c6430>] [<c01cd069>] [<c0199989>] [<c019a730>]
[<c010df40>]
[<c0119950>] [<c019af5b>] [<c0106c43>]
Code: 0f 0b 83 c4 14 c3 90 57 56 53 a1 c8 24 25 c0 f7 d8 8b 7c 24
>>EIP; c019c799 <skb_under_panic+29/30> <=====
>>ebx; c26050b0 <_end+2395240/5592190>
>>ecx; c4cac000 <_end+4a3c190/5592190>
>>edx; c4fcb990 <_end+4d5bb20/5592190>
>>esi; c4c26c00 <_end+49b6d90/5592190>
>>edi; c44ac0f4 <_end+423c284/5592190>
>>ebp; c4c26b38 <_end+49b6cc8/5592190>
>>esp; c4cad7ec <_end+4a3d97c/5592190>
Trace; c01d6321 <clip_start_xmit+f1/1d0>
Trace; c01d632a <clip_start_xmit+fa/1d0>
Trace; c01d6321 <clip_start_xmit+f1/1d0>
Trace; c01b00d0 <ip_finish_output2+0/d0>
Trace; c01a624e <qdisc_restart+4e/d0>
Trace; c019ffe3 <dev_queue_xmit+f3/240>
Trace; c01b015d <ip_finish_output2+8d/d0>
Trace; c01a5a17 <nf_hook_slow+e7/140>
Trace; c594d4f0 <END_OF_CODE+1442d/????>
Trace; c01b00a2 <ip_finish_output+102/110>
Trace; c01b00d0 <ip_finish_output2+0/d0>
Trace; c594d516 <END_OF_CODE+14453/????>
Trace; c01a5a17 <nf_hook_slow+e7/140>
Trace; c594c3ff <END_OF_CODE+1333c/????>
Trace; c594d4f0 <END_OF_CODE+1442d/????>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c010524d <machine_real_restart+3d/b0>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c019fde5 <dev_queue_xmit_nit+15/b0>
Trace; c01b00d0 <ip_finish_output2+0/d0>
Trace; c01a624e <qdisc_restart+4e/d0>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c019ffe3 <dev_queue_xmit+f3/240>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c01a3506 <neigh_compat_output+76/80>
Trace; c01b015d <ip_finish_output2+8d/d0>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c01a5a17 <nf_hook_slow+e7/140>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c01b00b0 <output_maybe_reroute+0/20>
Trace; c01aed2a <ip_output+12a/130>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c01b00d0 <ip_finish_output2+0/d0>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c01b00bd <output_maybe_reroute+d/20>
Trace; c01a5a17 <nf_hook_slow+e7/140>
Trace; c01af9c0 <ip_build_xmit+2d0/350>
Trace; c597de60 <END_OF_CODE+44d9d/????>
Trace; c01b00b0 <output_maybe_reroute+0/20>
Trace; c01c67ab <raw_sendmsg+28b/300>
Trace; c01c6430 <raw_getfrag+0/30>
Trace; c01cd069 <inet_sendmsg+39/40>
Trace; c0199989 <sock_sendmsg+69/90>
Trace; c019a730 <sys_sendto+d0/f0>
Trace; c010df40 <do_page_fault+0/494>
Trace; c0119950 <sys_rt_sigaction+90/f0>
Trace; c019af5b <sys_socketcall+14b/210>
Trace; c0106c43 <system_call+33/40>
Code; c019c799 <skb_under_panic+29/30>
00000000 <_EIP>:
Code; c019c799 <skb_under_panic+29/30> <=====
0: 0f 0b ud2a <=====
Code; c019c79b <skb_under_panic+2b/30>
2: 83 c4 14 add $0x14,%esp
Code; c019c79e <skb_under_panic+2e/30>
5: c3 ret
Code; c019c79f <skb_under_panic+2f/30>
6: 90 nop
Code; c019c7a0 <alloc_skb+0/180>
7: 57 push %edi
Code; c019c7a1 <alloc_skb+1/180>
8: 56 push %esi
Code; c019c7a2 <alloc_skb+2/180>
9: 53 push %ebx
Code; c019c7a3 <alloc_skb+3/180>
a: a1 c8 24 25 c0 mov 0xc02524c8,%eax
Code; c019c7a8 <alloc_skb+8/180>
f: f7 d8 neg %eax
Code; c019c7aa <alloc_skb+a/180>
11: 8b 7c 24 00 mov 0x0(%esp,1),%edi
<0>Kernel panic: Aiee, killing interrupt handler!
Here's the relevant syslog snippet from the local machine (the one that
crashes):
Apr 21 20:38:37 adslgate kernel: klips_info:ipsec_init: KLIPS startup,
FreeS/WAN IPSec version: 1.96
Apr 21 20:38:37 adslgate kernel: klips_info:ipsec_ext_init: KLIPS ext v=0.7.2-
1 (EALG_MAX=255, AALG_MAX=15)
Apr 21 20:38:37 adslgate kernel: klips_info:ipsec_ext_init: calling
ipsec_ext_static_init()
Apr 21 20:38:37 adslgate ipsec_setup: KLIPS debug `none'
Apr 21 20:38:37 adslgate ipsec_setup: KLIPS ipsec0 on atm0
aaa.bbb.cc.ddd/255.255.255.252
Apr 21 20:38:38 adslgate ipsec__plutorun: Starting Pluto subsystem...
Apr 21 20:38:38 adslgate Pluto[3391]: Starting Pluto (FreeS/WAN Version 1.96)
Apr 21 20:38:38 adslgate Pluto[3391]: including X.509 patch (Version 0.9.9)
Apr 21 20:38:40 adslgate Pluto[3391]: Changing to directory
'/etc/ipsec.d/cacerts'
Apr 21 20:38:40 adslgate Pluto[3391]: loaded cacert file 'cacert.pem' (1915
bytes)
Apr 21 20:38:49 adslgate Pluto[3391]: Changing to directory
'/etc/ipsec.d/crls'
Apr 21 20:38:49 adslgate Pluto[3391]: loaded crl file 'crl.pem' (784 bytes)
Apr 21 20:38:53 adslgate Pluto[3391]: loaded my X.509 cert file
'/etc/x509cert.der' (1269 bytes)
Apr 21 20:39:02 adslgate Pluto[3391]: added connection description "ralf-lkt"
Apr 21 20:39:02 adslgate Pluto[3391]: listening for IKE messages
Apr 21 20:39:02 adslgate Pluto[3391]: adding interface ipsec0/atm0
aaa.bbb.cc.ddd
Apr 21 20:39:02 adslgate Pluto[3391]: loading secrets from
"/etc/ipsec.secrets"
Apr 21 20:39:02 adslgate Pluto[3391]: loaded private key file
'/etc/ipsec.d/private/rabeKey.pem' (887 bytes)
Apr 21 20:39:04 adslgate Pluto[3391]: "ralf-lkt" #1: initiating Main Mode
Apr 21 20:39:32 adslgate Pluto[3391]: ERROR: asynchronous network error report
on atm0 for message to bbb.ccc.dd.ee port 500, complainant aaa.bbb.cc.eee:
Message too long [errno 90, origin ICMP type 3 code 4 (not authenticated)]
Apr 21 20:39:33 adslgate Pluto[3391]: "ralf-lkt" #2: responding to Main Mode
Apr 21 20:39:37 adslgate Pluto[3391]: "ralf-lkt" #1: discarding duplicate
packet; already STATE_MAIN_I3
Apr 21 20:39:39 adslgate Pluto[3391]: "ralf-lkt" #2: shared DH secret has
leading zero -- triggers Pluto 1.0 bug
Apr 21 20:39:40 adslgate Pluto[3391]: "ralf-lkt" #2: regenerating DH private
secret to avoid Pluto 1.0 bug handling shared secret with leading zero
Apr 21 20:39:55 adslgate Pluto[3391]: "ralf-lkt" #2: Peer ID is ID_DER_ASN1
_DN: 'C=DE, ST=Bavaria, O=Foobar, OU=Institute of Blah, CN=WWW.foobar.DE,
E=...@fo...'
Apr 21 20:40:17 adslgate Pluto[3391]: "ralf-lkt" #2: sent MR3, ISAKMP SA
established
Apr 21 20:40:21 adslgate Pluto[3391]: "ralf-lkt" #1: discarding duplicate
packet; already STATE_MAIN_I3
Apr 21 20:40:30 adslgate Pluto[3391]: "ralf-lkt" #1: Peer ID is ID_DER_ASN1
_DN: 'C=DE, ST=Bavaria, O=Foobar, OU=Institute of Blah, CN=WWW.foobar.DE,
E=...@fo...'
Apr 21 20:40:42 adslgate Pluto[3391]: "ralf-lkt" #1: ISAKMP SA established
Apr 21 20:40:42 adslgate Pluto[3391]: "ralf-lkt" #3: initiating Quick Mode
RSASIG+ENCRYPT+TUNNEL+PFS
Apr 21 20:40:52 adslgate Pluto[3391]: "ralf-lkt" #2: retransmitting in
response to duplicate packet; already STATE_MAIN_R3
Apr 21 20:41:00 adslgate Pluto[3391]: "ralf-lkt" #1: discarding duplicate
packet; already STATE_MAIN_I4
Apr 21 20:41:09 adslgate ipsec__plutorun: 104 "ralf-lkt" #1: STATE_MAIN_I1:
initiate
Apr 21 20:41:09 adslgate ipsec__plutorun: 106 "ralf-lkt" #1: STATE_MAIN_I2:
sent MI2, expecting MR2
Apr 21 20:41:09 adslgate ipsec__plutorun: 108 "ralf-lkt" #1: STATE_MAIN_I3:
sent MI3, expecting MR3
Apr 21 20:41:09 adslgate ipsec__plutorun: 003 "ralf-lkt" #1: discarding
duplicate packet; already STATE_MAIN_I3
Apr 21 20:41:09 adslgate ipsec__plutorun: 010 "ralf-lkt" #1: STATE_MAIN_I3:
retransmission; will wait 20s for response
Apr 21 20:41:09 adslgate ipsec__plutorun: 010 "ralf-lkt" #1: STATE_MAIN_I3:
retransmission; will wait 40s for response
Apr 21 20:41:09 adslgate ipsec__plutorun: 003 "ralf-lkt" #1: discarding
duplicate packet; already STATE_MAIN_I3
Apr 21 20:41:09 adslgate ipsec__plutorun: 004 "ralf-lkt" #1: STATE_MAIN_I4:
ISAKMP SA established
Apr 21 20:41:09 adslgate ipsec__plutorun: 112 "ralf-lkt" #3: STATE_QUICK_I1:
initiate
Apr 21 20:41:09 adslgate ipsec__plutorun: 010 "ralf-lkt" #3: STATE_QUICK_I1:
retransmission; will wait 20s for response
Apr 21 20:41:09 adslgate ipsec__plutorun: 004 "ralf-lkt" #3: STATE_QUICK_I2:
sent QI2, IPsec SA established
Apr 21 20:41:09 adslgate Pluto[3391]: "ralf-lkt" #3: sent QI2, IPsec SA
established
Apr 21 20:41:11 adslgate Pluto[3391]: "ralf-lkt" #3: retransmitting in
response to duplicate packet; already STATE_QUICK_I2
Note that the order of the above lines may be incorrect. I combined the part
of the syslog that got flushed to the harddrive before the crash occured with
part of the syslog that got sent via UPD to a listening syslog in my LAN.
Ok, and here's the part from the remote machine (logfile times on BOTH
machines are synced to a timeserver, so they should be pretty much in sync to
each other):
Apr 21 20:38:45 WWW Pluto[6470]: "lkt-ralf" #215: ERROR: asynchronous network
error report on eth0 for message to aaa.bbb.cc.ddd port 500, complainant
aaa.bbb.cc.ddd: Connection refused [errno 111, origin ICMP type 3 code 3 (not
authenticated)]
Apr 21 20:39:11 WWW Pluto[6470]: "lkt-ralf" #216: responding to Main Mode
Apr 21 20:39:53 WWW Pluto[6470]: "lkt-ralf" #216: Peer ID is ID_DER_ASN1_DN:
'C=DE, ST=Northrhine-Westfalia, L=Aachen, O=Aachen U of Tech, OU=Somewhere
Inc., CN=www.somewhere.DE, E=...@so...'
Apr 21 20:40:05 WWW Pluto[6470]: "lkt-ralf" #216: sent MR3, ISAKMP SA
established
Apr 21 20:40:20 WWW Pluto[6470]: "lkt-ralf" #215: Peer ID is ID_DER_ASN1_DN:
'C=DE, ST=Northrhine-Westfalia, L=Aachen, O=Aachen U of Tech, OU=Somewhere
Inc., CN=www.somewhere.DE, E=...@so...'
Apr 21 20:40:26 WWW Pluto[6470]: "lkt-ralf" #215: ISAKMP SA established
Apr 21 20:40:28 WWW Pluto[6470]: "lkt-ralf" #216: retransmitting in response
to duplicate packet; already STATE_MAIN_R3
Apr 21 20:40:51 WWW Pluto[6470]: "lkt-ralf" #217: responding to Quick Mode
Apr 21 20:40:58 WWW Pluto[6470]: "lkt-ralf" #215: discarding duplicate packet;
already STATE_MAIN_I4
Apr 21 20:41:02 WWW Pluto[6470]: "lkt-ralf" #217: discarding duplicate packet;
already STATE_QUICK_R1
Apr 21 20:41:11 WWW Pluto[6470]: "lkt-ralf" #217: IPsec SA established
Apr 21 20:41:12 WWW Pluto[6470]: "lkt-ralf" #217: discarding duplicate packet;
already STATE_QUICK_R2
I hope that I didn't forget anything important.
Any idea of where to start debugging this whole mess?
Thanks,
Ralf
--
Sign the EU petition against SPAM: L I N U X .~.
http://www.politik-digital.de/spam/ The Choice /V\
of a GNU /( )\
Generation ^^-^^
|