[Swan-dev] Crash with libreswan-git 24/10 (fwd)
Paul Wouters
paul at nohats.ca
Fri Oct 24 04:07:41 EEST 2014
I asked him to try with --leak-detective and EFENCE=-lefence and see if
we can get a litle more information.
Paul
---------- Forwarded message ----------
Date: Thu, 23 Oct 2014 20:12:28
From: Reuben Farrelly <reuben-libreswan at reub.net>
To: Paul Wouters <paul at nohats.ca>
Subject: Crash with libreswan-git 24/10
Hi Paul,
Still seeing this crash I reported to you a couple of weeks ago happen very
frequently. Here's the latest coredump which is built against current -git as
of now ( v3.11-80-g77c5f76-master ).
lightning reuben # gdb /usr/libexec/ipsec/pluto libreswan-core
GNU gdb (Gentoo 7.8 vanilla) 7.8
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-pc-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://bugs.gentoo.org/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/libexec/ipsec/pluto...done.
[New LWP 20170]
[New LWP 20172]
warning: Could not load shared library symbols for linux-vdso.so.1.
Do you need "set solib-search-path" or "set sysroot"?
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/libexec/ipsec/pluto --config /etc/ipsec.conf --'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00007fee79df78d0 in PK11_GetKeyLength () from /usr/lib64/libnss3.so
(gdb) bt full
#0 0x00007fee79df78d0 in PK11_GetKeyLength () from /usr/lib64/libnss3.so
No symbol table info available.
#1 0x0000000000424530 in hmac_init (ctx=0x7fff21ddeab0, h=0x724a00
<crypto_integ_sha1>, symkey=0x0)
at
/var/tmp/portage/net-misc/libreswan-9999/work/libreswan-9999/programs/pluto/hmac.c:59
status = 32767
tkey1 = 0xa207c
tkey2 = 0x0
klen = 568192544
hmac_opad = {ptr = 0x0, len = 4863520}
hmac_ipad = {ptr = 0x7fff21ddeab0 "calling processor R1: process
INFORMATIONAL", len = 140733761579648}
hmac_pad = {ptr = 0x2774656c20776f4e <error: Cannot access memory at
address 0x2774656c20776f4e>, len = 7299318426373202035}
#2 0x0000000000446d5a in ikev2_decrypt_msg (md=0x1041380, role=O_RESPONDER)
at
/var/tmp/portage/net-misc/libreswan-9999/work/libreswan-9999/programs/pluto/ikev2_parent.c:1442
td =
"0▒▒!▒\177\000\000\205\004I\000\000\000\000\000^\000\000\000\000\000\000\064▒▒▒!▒\177\000\000Z▒▒!▒\177\000\000▒▒▒!▒\177\000\000▒\000\000\000\000\000\000\000ЭL\000\000\000\000"
ctx = {h = 0x20676e696c6c6163, hmac_digest_len = 8030889439828865648,
hash_ctx = {ctx_md5 = {ctx_nss = 0x7270203a31522072},
ctx_sha1 = {ctx_nss = 0x7270203a31522072}, ctx_sha256 = {ctx_nss =
0x7270203a31522072}, ctx_sha384 = {
ctx_nss = 0x7270203a31522072}, ctx_sha512 = {ctx_nss =
0x7270203a31522072}, ctx_aes_xcbc = {
ctx_nss = 0x7270203a31522072}},
buf1 = "ocess INFORMATIONAL\000ing\000AL", '\000' <repeats 16 times>,
"@\000\000\000\000\000\000B.\023▒▒\001p process",
buf2 = "ing version=2.0 packet with exchange
type=ISAKMP_v2_INFORMATIONA", ctx_sha256 = {ctx_nss = 0x29373328204c},
ctx_sha512 = {ctx_nss = 0x0}, ctx_aes_xcbc = {ctx_nss = 0x0}, ikey =
0x6e6f636573200000, okey = 0x7fff21007364,
ctx_nss = 0x421dd0020}
st = 0x1043ff0
pst = 0x1043ff0
e_pbs = 0x1041528
authstart = 0x10452a0 "▒\004\221C:▒▒\224P%<~Q9▒▒. %\b"
iv = 0x10452c0 "\222\061▒\022q▒▒▒▒\202S▒▒\\3`\217I▒▒\035,▒▒"
integ_len = 12
enc_blocksize = 16
ivsize = 16
roof = 0x10452e0 "k▒%\214\210%▒\v▒;G", '\\' <repeats 12 times>,
"\201"
cipherkey = 0x0
authkey = 0x0
#3 0x000000000044b0ab in process_encrypted_informational_ikev2 (md=0x1041380)
at
/var/tmp/portage/net-misc/libreswan-9999/work/libreswan-9999/programs/pluto/ikev2_parent.c:3183
ret = 568192611
st = 0x1043ff0
prole = O_RESPONDER
__FUNCTION__ = "process_encrypted_informational_ikev2"
#4 0x0000000000442227 in process_v2_packet (mdp=0x7fff21ddf020)
at
/var/tmp/portage/net-misc/libreswan-9999/work/libreswan-9999/programs/pluto/ikev2.c:793
md = 0x1041380
st = 0x1043ff0
from_state = STATE_PARENT_R1
svm = 0x4dd520 <v2_state_microcode_table+480>
ix = ISAKMP_v2_INFORMATIONAL
#5 0x0000000000467d62 in process_packet (mdp=0x7fff21ddf020)
at
/var/tmp/portage/net-misc/libreswan-9999/work/libreswan-9999/programs/pluto/demux.c:177
---Type <return> to continue, or q <return> to quit---
md = 0x1041380
vmaj = 2
vmin = 0
#6 0x0000000000467df2 in comm_handle (ifp=0x103ab80)
at
/var/tmp/portage/net-misc/libreswan-9999/work/libreswan-9999/programs/pluto/demux.c:225
md = 0x1041380
#7 0x0000000000420fb1 in call_server () at
/var/tmp/portage/net-misc/libreswan-9999/work/libreswan-9999/programs/pluto/server.c:743
readfds = {__osfds_bits = {65536, 0 <repeats 127 times>}}
writefds = {__osfds_bits = {0 <repeats 128 times>}}
ndes = 1
ifp = 0x103ab80
#8 0x000000000041d9a3 in main (argc=4, argv=0x7fff21de0b78)
at
/var/tmp/portage/net-misc/libreswan-9999/work/libreswan-9999/programs/pluto/plutomain.c:1387
lockfd = 3
log_to_stderr_desired = 0
log_to_file_desired = 0
keep_alive = 0
virtual_private = 0x101c520
"%v4:10.0.0.0/8,%v4:192.168.0.0/16,%v4:172.16.0.0/12,%v4:25.0.0.0/8,%v4:100.64.0.0/10,%v6:fd00::/8,%v6:fe80::/10"
(gdb)
The last 100 lines of pluto.log are:
| enckeylen=16, authkeylen=20, keymat_len=36
| install_ipsec_sa() for #35: inbound and outbound
| route owner of "reub.net"[4] 1.146.108.134 unrouted: NULL; eroute owner: NULL
| could_route called for reub.net (kind=CK_INSTANCE)
| looking for alg with transid: 12 keylen: 128 auth: 2
| looking for alg with transid: 12 keylen: 128 auth: 2
| add inbound eroute 192.168.6.2/32:0 --0-> 192.168.6.1/32:0 =>
tun.10000 at 106.187.48.126 (raw_eroute)
| raw_eroute result=1
| sr for #35: unrouted
| route owner of "reub.net"[4] 1.146.108.134 unrouted: NULL; eroute owner: NULL
| eroute_connection add eroute 192.168.6.1/32:0 --0-> 192.168.6.2/32:0 =>
tun.0 at 1.146.108.134 (raw_eroute)
| raw_eroute result=1
| command executing up-client
| executing up-client: PLUTO_VERB='up-client' PLUTO_VERSION='2.0'
PLUTO_CONNECTION='reub.net' PLUTO_INTERFACE='eth0'
PLUTO_NEXT_HOP='1.146.108.134' PLUTO_ME='106.187.48.126'
PLUTO_MY_ID='@lightning.reub.net' PLUTO_MY_CLIENT='192.168.6.1/32'
PLUTO_MY_CLIENT_NET='192.168.6.1' PLUTO_MY_CLIENT_MASK='255.255.255.255'
PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16388'
PLUTO_SA_TYPE='ESP' PLUTO_PEER='1.146.108.134'
PLUTO_PEER_ID='@router-2.reub.net' PLUTO_PEER_CLIENT='192.168.6.2/32'
PLUTO_PEER_CLIENT_NET='192.168.6.2' PLUTO_PEER_CLIENT_MASK='255.255.255.255'
PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''
PLUTO_STACK='netkey' PLUTO_MTU=1438 PLUTO_ADDTIME='1414109047'
PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW'
PLUTO_CONN_ADDRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_MY_SOURCEIP='192.168.6.1'
PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO=''
PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0' PLUTO_INBYTES='0' PLUTO
| popen cmd is 1031 chars long
| cmd( 0):PLUTO_VERB='up-client' PLUTO_VERSION='2.0'
PLUTO_CONNECTION='reub.net' PLUTO_INT:
| cmd( 80):ERFACE='eth0' PLUTO_NEXT_HOP='1.146.108.134'
PLUTO_ME='106.187.48.126' PLUTO_MY_:
| cmd( 160):ID='@lightning.reub.net' PLUTO_MY_CLIENT='192.168.6.1/32'
PLUTO_MY_CLIENT_NET='1:
| cmd( 240):92.168.6.1' PLUTO_MY_CLIENT_MASK='255.255.255.255'
PLUTO_MY_PORT='0' PLUTO_MY_PR:
| cmd( 320):OTOCOL='0' PLUTO_SA_REQID='16388' PLUTO_SA_TYPE='ESP'
PLUTO_PEER='1.146.108.134':
| cmd( 400): PLUTO_PEER_ID='@router-2.reub.net'
PLUTO_PEER_CLIENT='192.168.6.2/32' PLUTO_PEE:
| cmd( 480):R_CLIENT_NET='192.168.6.2' PLUTO_PEER_CLIENT_MASK='255.255.255.255'
PLUTO_PEER_P:
| cmd( 560):ORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''
PLUTO_STACK='netkey' PLUTO_MTU=:
| cmd( 640):1438 PLUTO_ADDTIME='1414109047'
PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+IKEV1_:
| cmd( 720):DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW'
PLUTO_CONN_ADDRFAM:
| cmd( 800):ILY='ipv4' XAUTH_FAILED=0 PLUTO_MY_SOURCEIP='192.168.6.1'
PLUTO_IS_PEER_CISCO='0:
| cmd( 880):' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO=''
PLUTO_PEER_BANNER='' PLUTO_NM:
| cmd( 960):_CONFIGURED='0' PLUTO_INBYTES='0' PLUTO_OUTBYTES='0' ipsec _updown
2>&1:
| route_and_eroute: firewall_notified: true
| command executing prepare-client
| executing prepare-client: PLUTO_VERB='prepare-client' PLUTO_VERSION='2.0'
PLUTO_CONNECTION='reub.net' PLUTO_INTERFACE='eth0'
PLUTO_NEXT_HOP='1.146.108.134' PLUTO_ME='106.187.48.126'
PLUTO_MY_ID='@lightning.reub.net' PLUTO_MY_CLIENT='192.168.6.1/32'
PLUTO_MY_CLIENT_NET='192.168.6.1' PLUTO_MY_CLIENT_MASK='255.255.255.255'
PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16388'
PLUTO_SA_TYPE='ESP' PLUTO_PEER='1.146.108.134'
PLUTO_PEER_ID='@router-2.reub.net' PLUTO_PEER_CLIENT='192.168.6.2/32'
PLUTO_PEER_CLIENT_NET='192.168.6.2' PLUTO_PEER_CLIENT_MASK='255.255.255.255'
PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''
PLUTO_STACK='netkey' PLUTO_MTU=1438 PLUTO_ADDTIME='1414109047'
PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW'
PLUTO_CONN_ADDRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_MY_SOURCEIP='192.168.6.1'
PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO=''
PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0' PLUTO_INBYTES
| popen cmd is 1036 chars long
| cmd( 0):PLUTO_VERB='prepare-client' PLUTO_VERSION='2.0'
PLUTO_CONNECTION='reub.net' PLUT:
| cmd( 80):O_INTERFACE='eth0' PLUTO_NEXT_HOP='1.146.108.134'
PLUTO_ME='106.187.48.126' PLUT:
| cmd( 160):O_MY_ID='@lightning.reub.net' PLUTO_MY_CLIENT='192.168.6.1/32'
PLUTO_MY_CLIENT_N:
| cmd( 240):ET='192.168.6.1' PLUTO_MY_CLIENT_MASK='255.255.255.255'
PLUTO_MY_PORT='0' PLUTO_:
| cmd( 320):MY_PROTOCOL='0' PLUTO_SA_REQID='16388' PLUTO_SA_TYPE='ESP'
PLUTO_PEER='1.146.108:
| cmd( 400):.134' PLUTO_PEER_ID='@router-2.reub.net'
PLUTO_PEER_CLIENT='192.168.6.2/32' PLUT:
| cmd( 480):O_PEER_CLIENT_NET='192.168.6.2'
PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_P:
| cmd( 560):EER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''
PLUTO_STACK='netkey' PLUTO:
| cmd( 640):_MTU=1438 PLUTO_ADDTIME='1414109047'
PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+I:
| cmd( 720):KEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW'
PLUTO_CONN_AD:
| cmd( 800):DRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_MY_SOURCEIP='192.168.6.1'
PLUTO_IS_PEER_CIS:
| cmd( 880):CO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO=''
PLUTO_PEER_BANNER='' PLU:
| cmd( 960):TO_NM_CONFIGURED='0' PLUTO_INBYTES='0' PLUTO_OUTBYTES='0' ipsec
_updown 2>&1:
| command executing route-client
| executing route-client: PLUTO_VERB='route-client' PLUTO_VERSION='2.0'
PLUTO_CONNECTION='reub.net' PLUTO_INTERFACE='eth0'
PLUTO_NEXT_HOP='1.146.108.134' PLUTO_ME='106.187.48.126'
PLUTO_MY_ID='@lightning.reub.net' PLUTO_MY_CLIENT='192.168.6.1/32'
PLUTO_MY_CLIENT_NET='192.168.6.1' PLUTO_MY_CLIENT_MASK='255.255.255.255'
PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16388'
PLUTO_SA_TYPE='ESP' PLUTO_PEER='1.146.108.134'
PLUTO_PEER_ID='@router-2.reub.net' PLUTO_PEER_CLIENT='192.168.6.2/32'
PLUTO_PEER_CLIENT_NET='192.168.6.2' PLUTO_PEER_CLIENT_MASK='255.255.255.255'
PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''
PLUTO_STACK='netkey' PLUTO_MTU=1438 PLUTO_ADDTIME='1414109047'
PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW'
PLUTO_CONN_ADDRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_MY_SOURCEIP='192.168.6.1'
PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO=''
PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0' PLUTO_INBYTES='0'
| popen cmd is 1034 chars long
| cmd( 0):PLUTO_VERB='route-client' PLUTO_VERSION='2.0'
PLUTO_CONNECTION='reub.net' PLUTO_:
| cmd( 80):INTERFACE='eth0' PLUTO_NEXT_HOP='1.146.108.134'
PLUTO_ME='106.187.48.126' PLUTO_:
| cmd( 160):MY_ID='@lightning.reub.net' PLUTO_MY_CLIENT='192.168.6.1/32'
PLUTO_MY_CLIENT_NET:
| cmd( 240):='192.168.6.1' PLUTO_MY_CLIENT_MASK='255.255.255.255'
PLUTO_MY_PORT='0' PLUTO_MY:
| cmd( 320):_PROTOCOL='0' PLUTO_SA_REQID='16388' PLUTO_SA_TYPE='ESP'
PLUTO_PEER='1.146.108.1:
| cmd( 400):34' PLUTO_PEER_ID='@router-2.reub.net'
PLUTO_PEER_CLIENT='192.168.6.2/32' PLUTO_:
| cmd( 480):PEER_CLIENT_NET='192.168.6.2'
PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEE:
| cmd( 560):R_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=''
PLUTO_STACK='netkey' PLUTO_M:
| cmd( 640):TU=1438 PLUTO_ADDTIME='1414109047'
PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+IKE:
| cmd( 720):V1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW'
PLUTO_CONN_ADDR:
| cmd( 800):FAMILY='ipv4' XAUTH_FAILED=0 PLUTO_MY_SOURCEIP='192.168.6.1'
PLUTO_IS_PEER_CISCO:
| cmd( 880):='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO=''
PLUTO_PEER_BANNER='' PLUTO:
| cmd( 960):_NM_CONFIGURED='0' PLUTO_INBYTES='0' PLUTO_OUTBYTES='0' ipsec
_updown 2>&1:
| route_and_eroute: instance "reub.net"[4] 1.146.108.134, setting eroute_owner
{spd=0x1048c28,sr=0x1048c28} to #35 (was #0) (newest_ipsec_sa=#0)
| complete v2 state transition from STATE_UNDEFINED with STF_OK
"reub.net"[4] 1.146.108.134 #35: transition from state STATE_PARENT_R1 to state
STATE_PARENT_R2
"reub.net"[4] 1.146.108.134 #35: negotiated tunnel
[192.168.6.1,192.168.6.1:0-65535 0] -> [192.168.6.2,192.168.6.2:0-65535 0]
"reub.net"[4] 1.146.108.134 #35: STATE_PARENT_R2: received v2I2, PARENT SA
established tunnel mode {ESP/NAT=>0x21fa7d4e <0x83426a39 xfrm=AES_128-HMAC_SHA1
NATOA=none NATD=1.146.108.134:4500 DPD=active}
| sending reply packet to 1.146.108.134:4500 (from port 4500)
| sending 224 bytes for STATE_PARENT_R1 through eth0:4500 to 1.146.108.134:4500
(using #35)
| releasing whack for #35 (sock=-1)
| releasing whack and unpending for parent #33
| inserting event EVENT_SA_REPLACE, timeout in 1530 seconds for #35
| inserting event EVENT_v2_LIVENESS, timeout in 15 seconds for #35
| * processed 1 messages from cryptographic helpers
| next event EVENT_v2_LIVENESS in 15 seconds for #35
| next event EVENT_v2_LIVENESS in 15 seconds for #35
|
| next event EVENT_v2_LIVENESS in 0 seconds for #35
| *time to handle event
| handling event EVENT_v2_LIVENESS
| event after this is EVENT_PENDING_DDNS in 9 seconds
| processing connection reub.net[4] 1.146.108.134
| liveness_check - peer is ok
| inserting event EVENT_v2_LIVENESS, timeout in 15 seconds for #35
| next event EVENT_PENDING_DDNS in 9 seconds
|
| *received 76 bytes from 1.146.108.134:4500 on eth0 (port=4500)
| processing version=2.0 packet with exchange type=ISAKMP_v2_INFORMATIONAL
(37)
| I am receiving an IKE Request
| I am the IKE SA Original Responder
| ICOOKIE: e7 04 91 43 3a ab eb 94
| RCOOKIE: 50 25 3c 7e 51 39 ff de
| state hash entry 15
| parent v2 peer and cookies match on #34
| v2 state object #34 found, in STATE_PARENT_R1
| state found and its state is STATE_PARENT_R1
| selected state microcode R1: process INFORMATIONAL
| processing connection reub.net[4] 1.146.108.134
| Now let's proceed with payload (ISAKMP_NEXT_v2E)
| Now lets proceed with state specific processing
| calling processor R1: process INFORMATIONAL
<end>
Thanks,
Reuben
More information about the Swan-dev
mailing list