2.6.52-dev1 segfault twice per day

[AnatoliChe]

Hi! I'm biting with sigfaults.

openswan 2.6.53-dev1
kernel: : pluto[5028]: segfault at 2f4 ip 000055baaf962800 sp 00007ffe73c97e30 error 4 in pluto[55baaf925000+a3000]

gdb OBJ.linux.x86_64/programs/pluto/pluto -c core-pluto.18393
Core was generated by /usr/local/libexec/ipsec/pluto --nofork --secretsfile /etc/ipsec.secrets --ipse.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 setup_half_ipsec_sa (parent_st=parent_st@entry=0x0, st=st@entry=0x557936554bd0, sr=sr@entry=0x7ffd638d9620, inbound=inbound@entry=1)
at programs/pluto/kernel.c:1718
1718 const char *inbound_str = inbound ? "inbound" : "outbound";

(gdb) bt
#0 setup_half_ipsec_sa (parent_st=parent_st@entry=0x0, st=st@entry=0x557936554bd0, sr=sr@entry=0x7ffd638d9620, inbound=inbound@entry=1)
at programs/pluto/kernel.c:1718
#1 0x0000557935cc6f58 in install_ipsec_sa (parent_st=0x0, st=st@entry=0x557936554bd0, inbound_also=inbound_also@entry=1)
at programs/pluto/kernel.c:3020
#2 0x0000557935cac4f7 in quick_inR1_outI2_cryptotail (r=r@entry=0x7ffd638d9ad0, dh=) at programs/pluto/ikev1_quick.c:2642
#3 0x0000557935cac7be in quick_inR1_outI2_continue (pcrc=0x5579365bbc40, r=0x7ffd638d9ad0, ugh=0x0) at programs/pluto/ikev1_quick.c:2475
#4 0x0000557935cd76af in handle_helper_comm (w=w@entry=0x55793643e3f0) at programs/pluto/pluto_crypt.c:827
#5 0x0000557935cd84bb in pluto_crypto_helper_ready (readfds=readfds@entry=0x7ffd638db180) at programs/pluto/pluto_crypt.c:1101
#6 0x0000557935c9a989 in call_server () at programs/pluto/server.c:798
#7 0x0000557935c84faf in main (argc=, argv=) at programs/pluto/plutomain.c:1134

(gdb) frame 0
#0 setup_half_ipsec_sa (parent_st=parent_st@entry=0x0, st=st@entry=0x557936554bd0, sr=sr@entry=0x7ffd638d9620, inbound=inbound@entry=1)
at programs/pluto/kernel.c:1718
1718 const char *inbound_str = inbound ? "inbound" : "outbound";
(gdb) list
1713 bool outgoing_ref_set = FALSE;
1714 bool incoming_ref_set = FALSE;
1715 IPsecSAref_t refhim = st->st_refhim;
1716 IPsecSAref_t new_refhim = IPSEC_SAREF_NULL;
1717
1718 const char inbound_str = inbound ? "inbound" : "outbound";
1719
1720 / SPIs, saved for spigrouping or undoing, if necessary */
1721 struct kernel_sa
1722 said[EM_MAXRELSPIS],

(gdb) print inbound
$1 = 1

(gdb) frame 1
#1 0x0000557935cc6f58 in install_ipsec_sa (parent_st=0x0, st=st@entry=0x557936554bd0, inbound_also=inbound_also@entry=1)
at programs/pluto/kernel.c:3020
3020 if(!setup_half_ipsec_sa(parent_st, st, sr, TRUE)) {
(gdb) list
3015 }
3016
3017 DBG(DBG_KLIPS, DBG_log("state #%lu: now setting up incoming SA", st->st_serialno));
3018 /* now setup inbound SA */
3019 if(st->st_ref == IPSEC_SAREF_NULL && inbound_also) {
3020 if(!setup_half_ipsec_sa(parent_st, st, sr, TRUE)) {
3021 loglog(RC_LOG_SERIOUS, "state #%lu: failed to setup incoming SA", st->st_serialno);
3022 return FALSE;
3023 }
3024 DBG(DBG_KLIPS, DBG_log("state #%lu: set up incoming SA, ref=%u/%u", st->st_serialno, st->st_ref, st->st_refhim));

(gdb) print st
$2 = (struct state *) 0x557936554bd0
(gdb) print sr
$3 = (struct spd_route *) 0x7ffd638d9620
(gdb) print parent_st
$4 = (struct state *) 0x0

I do not fully understand how
const char *inbound_str = inbound ? "inbound" : "outbound";
eg
const char *inbound_str = 1 ? "inbound" : "outbound";
can cause segfault.
Maybe I should compile with -O0?

[shussain]

@AnatoliChe Thank you for reportin git.

Can you please test with OSW 2.6.52rc1? If the issue still occurs, can you please post your ipsec.conf

[AnatoliChe]

With rc1 I have much more interesting error.
I believe it's related with problems with internet connection and corrupt packets from internet.
2.6.52dev1 from local side and segfault as you can see higher.
2.6.52-rc1 from remote side and more interesting error with segfault.
ipsec --version Linux Openswan U2.6.52rc1-5-g6f58e3037/K4.19.84-ipsec-core2-smp (netkey)

| next event EVENT_DPD in 0 seconds for #103 (2019-12-19 19:57:34) | *time to handle event | at 2019-12-19 19:57:34 handling event EVENT_DPD | event after this is EVENT_DPD in 0 seconds | processing connection KvPZCVt-dpt0 | find_phase1_state: found SA #105 for conn 'KvPZCVt-dpt0' in state STATE_PARENT_R2 | DPD: processing for state #103 ("KvPZCVt-dpt0") | get [email protected] | inserting event EVENT_DPD, timeout in 30 seconds for #103 | event added after event EVENT_DPD for #104 | DPD: scheduling timeout to 120 | state: 105 requesting event none to be deleted by dpd_sched_timeout:201 | inserting event EVENT_DPD_TIMEOUT, timeout in 120 seconds for #105 | event added after event EVENT_PENDING_PHASE2 | DPD: sending R_U_THERE 4414 to 10.10.10.10:500 (state #105) | **emit ISAKMP Message: | initiator cookie: | b2 f4 36 2e 4a 1c c5 2b | responder cookie: | df e6 42 52 69 35 7d 29 | ISAKMP version: ISAKMP Version 1.0 (rfc2407) | exchange type: ISAKMP_XCHG_INFO | flags: ISAKMP_FLAG_ENCRYPTION | message ID: d2 49 2f 5c | ***emit ISAKMP Hash Payload: | emitting 20 zero bytes of HASH into ISAKMP Hash Payload | emitting length of ISAKMP Hash Payload: 24 | ***emit ISAKMP Notification Payload: | DOI: ISAKMP_DOI_IPSEC | protocol ID: 1 | SPI size: 16 | Notify Message Type: R_U_THERE | emitting 8 raw bytes of notify icookie into ISAKMP Notification Payload | notify icookie b2 f4 36 2e 4a 1c c5 2b | emitting 8 raw bytes of notify rcookie into ISAKMP Notification Payload | notify rcookie df e6 42 52 69 35 7d 29 | emitting 4 raw bytes of notify data into ISAKMP Notification Payload | notify data 00 00 11 3e | emitting length of ISAKMP Notification Payload: 32 | HASH computed: | 77 87 dd 08 e1 8e 0d 25 e5 5d 6b e9 87 9d e2 3e | d1 ee 23 4c | last Phase 1 IV: | current Phase 1 IV: | computed Phase 2 IV: | 88 9c 1e 70 ef b5 f1 0a 84 f0 e0 f1 a0 25 89 ea | 9d f3 fd 0e | encrypting: | 0b 00 00 18 77 87 dd 08 e1 8e 0d 25 e5 5d 6b e9 | 87 9d e2 3e d1 ee 23 4c 00 00 00 20 00 00 00 01 | 01 10 8d 28 b2 f4 36 2e 4a 1c c5 2b df e6 42 52 | 69 35 7d 29 00 00 11 3e | IV: | 88 9c 1e 70 ef b5 f1 0a 84 f0 e0 f1 a0 25 89 ea | 9d f3 fd 0e | unpadded size is: 56 | emitting 8 zero bytes of encryption padding into ISAKMP Message | encrypting 64 using 12?? pluto_crypto_helper: helper [nonnss] (0) is exiting normally Segmentation fault (core dumped) pluto_crypto_helper: helper [nonnss] (1) is exiting normally pluto_crypto_helper: helper [nonnss] (2) is exiting normally

config
conn KvPZCVt-dpt0 auto=start type=transport #direction=dpt ike=aes128-sha1 esp=aes128-sha1 right=10.10.10.10 rightnexthop=80.78.38.201 [email protected] rightrsasigkey=0sAQN+ left=10.10.10.11 [email protected] leftrsasigkey=0sAQN5mECDoomDkKl+
status:
ipsec auto --status | grep KvPZCVt-dpt0 000 "KvPZCVt-dpt0": 10.10.10.11[@KvPZCVt.ipsec.tkb]...80.78.38.201---10.10.10.10[@dpt0.ipsec.tkb]; erouted; eroute owner: #251 000 "KvPZCVt-dpt0": myip=unset; hisip=unset; 000 "KvPZCVt-dpt0": keys: 1:A6E8 79CF 2403 1000 2744 DCAA 4705 5588 ED7A ABCD 2:none... 000 "KvPZCVt-dpt0": ....1:A032 6524 812B F784 4EC6 1607 40AD ADD0 911D 01D8 2:none 000 "KvPZCVt-dpt0": ike_life: 3600s; ipsec_life: 1200s; rekey_margin: 300s; rekey_fuzz: 50%; keyingtries: 0; firstmsgid: 0 000 "KvPZCVt-dpt0": policy: RSASIG+ENCRYPT+PFS+UP+IKEv2ALLOW+SAREFTRACK; prio: 32,32; interface: eth0; kind=CK_PERMANENT 000 "KvPZCVt-dpt0": dpd: action:restart; delay:30; timeout:120; 000 "KvPZCVt-dpt0": newest ISAKMP SA: #240; newest IPsec SA: #251; eroute owner: #251; 000 "KvPZCVt-dpt0": IKE algorithms wanted: AES_CBC(7)_128-SHA1(2)_000-MODP1536(5), AES_CBC(7)_128-SHA1(2)_000-MODP1024(2); flags=-strict 000 "KvPZCVt-dpt0": IKE algorithms found: AES_CBC(7)_128-SHA1(2)_160-MODP1536(5)AES_CBC(7)_128-SHA1(2)_160-MODP1024(2) 000 "KvPZCVt-dpt0": IKE algorithm newest: AES_CBC_128-SHA1-MODP1536 000 "KvPZCVt-dpt0": ESP algorithms wanted: AES(12)_128-SHA1(2)_000; flags=-strict 000 "KvPZCVt-dpt0": ESP algorithms loaded: AES(12)_128-SHA1(2)_160 000 "KvPZCVt-dpt0": ESP algorithm newest: AES_128-HMAC_SHA1; pfsgroup=<Phase1> 000 #251: "KvPZCVt-dpt0":500 IKEv1.0 STATE_QUICK_I2 (sent QI2, IPsec SA established); EVENT_SA_REPLACE in 698s; newest IPSEC; eroute owner; isakmp#240; idle; import:admin initiate 000 #251: "KvPZCVt-dpt0" [email protected] [email protected] ref=0 refhim=4294901761 000 #248: "KvPZCVt-dpt0":500 IKEv1.0 STATE_QUICK_I2 (sent QI2, IPsec SA established); EVENT_SA_EXPIRE in 234s; isakmp#240; idle; import:admin initiate 000 #248: "KvPZCVt-dpt0" [email protected] [email protected] ref=0 refhim=4294901761 000 #240: "KvPZCVt-dpt0":500 IKEv1.0 STATE_MAIN_I4 (ISAKMP SA established); EVENT_SA_REPLACE in 755s; newest ISAKMP; lastdpd=24s(seq in:21924 out:0); idle; import:admin initiate

gdb pluto -c core-pluto.16268.kvpzv.1576778254
GNU gdb (Debian 8.2.1-2+b3) 8.2.1
Core was generated by /usr/local/libexec/ipsec/pluto --nofork --secretsfile /etc/ipsec.secrets --ipse'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 aes_set_key (cx=cx@entry=0x7ffd81c5f5b0, in_key=0x0, n_bytes=0, f=f@entry=0) at lib/libcrypto/libaes/aes.c:987
987 cx->aes_e_key[0] = const_word_in(in_key );
`

(gdb) bt
#0 aes_set_key (cx=cx@entry=0x7ffd81c5f5b0, in_key=0x0, n_bytes=0, f=f@entry=0) at lib/libcrypto/libaes/aes.c:987 #1 0x000055bf86c5e957 in do_aes (buf=0x55bf86d038bc <reply_buffer+28> "\v", buf_len=64, key=<optimized out>, key_size=<optimized out>, iv=0x55bf889dcdf8 "\210\234\036p\357\265\361\n\204\360\340\361\240%\211\352\235\363\375\016", enc=1) at programs/pluto/ike_alg_aes.c:103 #2 0x000055bf86c1e0c5 in encrypt_message (pbs=pbs@entry=0x7ffd81c5f870, st=st@entry=0x55bf889dc380) at programs/pluto/ikev1_main.c:531 #3 0x000055bf86c21950 in send_isakmp_notification (st=st@entry=0x55bf889dc380, type=type@entry=36136, data=data@entry=0x7ffd81c5fc6c, len=len@entry=4) at programs/pluto/ikev1_main.c:2396 #4 0x000055bf86c08dd0 in dpd_outI (p1st=0x55bf889dc380, st=0x55bf889d64e0, eroute_care=<optimized out>, delay=30, timeout=<optimized out>) at programs/pluto/dpd.c:329 #5 0x000055bf86c14760 in handle_a_timer_event (ev=0x55bf889d28d0) at programs/pluto/timer.c:537 #6 0x000055bf86c14faa in handle_timer_event () at programs/pluto/timer.c:442 #7 0x000055bf86c139d9 in call_server () at programs/pluto/server.c:810 #8 0x000055bf86bfdfaf in main (argc=<optimized out>, argv=<optimized out>) at programs/pluto/plutomain.c:1134

(gdb) frame 0
#0 aes_set_key (cx=cx@entry=0x7ffd81c5f5b0, in_key=0x0, n_bytes=0, f=f@entry=0) at lib/libcrypto/libaes/aes.c:987 987 cx->aes_e_key[0] = const_word_in(in_key );
(gdb) list
982 break; 983 } 984 985 cx->aes_Nrnd = (cx->aes_Nkey > nc ? cx->aes_Nkey : nc) + 6; 986 987 cx->aes_e_key[0] = const_word_in(in_key ); 988 cx->aes_e_key[1] = const_word_in(in_key + 4); 989 cx->aes_e_key[2] = const_word_in(in_key + 8); 990 cx->aes_e_key[3] = const_word_in(in_key + 12);

(gdb) print in_key
$1 = (const unsigned char *) 0x0
(gdb) print cx->aes_Nrnd
$2 = 10
(gdb) print cx->aes_e_key[0]
$3 = 2261782116
(gdb) print cx->aes_Nkey
$4 = 4
(gdb) print nc
No symbol "nc" in current context.

[AnatoliChe]

disass /m
987 cx->aes_e_key[0] = const_word_in(in_key ); 0x000055bf86c7101a <+74>: mov (%rsi),%edx 0x000055bf86c7101c <+76>: lea 0x56fdd(%rip),%r14 # 0x55bf86cc8000 <rcon_tab> 0x000055bf86c71023 <+83>: lea 0x53fd6(%rip),%rax # 0x55bf86cc5000 <fl_tab> 0x000055bf86c7102a <+90>: mov %edx,0x8(%rdi) => 0x000055bf86c712a9 <+729>: mov (%rsi),%edx 0x000055bf86c712ab <+731>: lea 0x56d4e(%rip),%rbp # 0x55bf86cc8000 <rcon_tab> 0x000055bf86c712b2 <+738>: lea 0x53d47(%rip),%rax # 0x55bf86cc5000 <fl_tab> 0x000055bf86c712b9 <+745>: mov %edx,0x8(%rdi) 0x000055bf86c7135b <+907>: mov (%rsi),%edx 0x000055bf86c7135d <+909>: lea 0x56c9c(%rip),%rbp # 0x55bf86cc8000 <rcon_tab> 0x000055bf86c71364 <+916>: mov %edx,0x8(%rdi)

We have
#ifdef AES_LE_OK /* little endian processor without data alignment restrictions */ #define word_in(x) *(u_int32_t*)(x) #define const_word_in(x) *(const u_int32_t*)(x) #define word_out(x,v) *(u_int32_t*)(x) = (v) #define const_word_out(x,v) *(const u_int32_t*)(x) = (v) #else /* slower but generic big endian or with data alignment restrictions */ /* some additional "const" touches to stop "gcc -Wcast-qual" complains --jjo */ #define word_in(x) ((u_int32_t)(((unsigned char *)(x))[0])|((u_int32_t)(((unsigned char *)(x))[1])<<8)|((u_int32_t)(((unsigned char *)(x))[2])<<16)|((u_int32_t)(((unsigned char *)(x))[3 #define const_word_in(x) ((const u_int32_t)(((const unsigned char *)(x))[0])|((const u_int32_t)(((const unsigned char *)(x))[1])<<8)|((const u_int32_t)(((const unsigned char *)(x))[2])< #define word_out(x,v) ((unsigned char *)(x))[0]=(v),((unsigned char *)(x))[1]=((v)>>8),((unsigned char *)(x))[2]=((v)>>16),((unsigned char *)(x))[3]=((v)>>24) #define const_word_out(x,v) ((const unsigned char *)(x))[0]=(v),((const unsigned char *)(x))[1]=((v)>>8),((const unsigned char *)(x))[2]=((v)>>16),((const unsigned char *)(x))[3]=((v)>>24) #endif

This is like to some kind of magic :-D

[AnatoliChe]

I switched ipsec from aes128-sha1 to aes_ctr160-sha1 and do not have segfault already 3 days.

[letoams]

Do you compile with nss? Nss is an active maintained and certified crypto library, unlike the mostly abandoned openswan native crypto.

…

Sent from my iPhone

On Dec 23, 2019, at 02:36, Anatoli ***@***.***> wrote: I switched ipsec from aes128-sha1 to aes_ctr160-sha1 and do not have segfault already 3 days. — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or unsubscribe.

[AnatoliChe]

No it was without nss.
I understand nss is future.
But it's interesting, why in some cases of network problems in_key = (const unsigned char *) 0x0
Why const_word_in(0) is segfault I understand :-)

[letoams]

On Mon, 23 Dec 2019, Anatoli wrote: No it was without nss. I understand nss is future. But it's interesting, why in some cases of network problems in_key = (const unsigned char *) 0x0

I don't know. That code hasn't been maintained since the libreswan fork in 2011. libreswan at the time removed all non-nss crypto code, so I have no more experience with the openswan ancient crypto code.

[AnatoliChe]

libreswan at the time removed all non-nss crypto code

So, it's time clean up LSW from:
aes
aes.c
des
and some other?

[letoams]

On Mon, 23 Dec 2019, Anatoli wrote: libreswan at the time removed all non-nss crypto code So, it's time clean up LSW from aes aes.c

Those are part of the KLIPS kernel module, which is scheduled for removal in 3.31 (after the current code is released as 3.30) These files are not used for the userland IKE daemon. Paul