[strongSwan-dev] Charon crashed on sending CA certs in specific scenario

Ballu ballu devel.tech1 at gmail.com
Mon Apr 11 17:59:43 CEST 2016


Hi all,


I am facing strange issue in strongswan (strongSwan 4.5.3).

Established smart card based IKEv2 tunnel successfully between two devices.
I have attached syslog for successful which shows the established tunnel
between devices.


*However, If IPSEC is started/restarted on any one devices it will create
charon to crash on the remote device.*

Running IPSEC with gdb shows a segmentation fault. Attached are two log
files;
*One is backtrace logs from device where charon was crashed because of
IPSEC restart at remote device.
*Second one are the logs from one of the device when tunnel was
successfully established.

Problem is observed only in smart card based tunnels.

*passphrase based tunnels have no such issue.*



*As per attached gdb back trace, it is stuck some where C_sign() function
of opensc.  I am not sure about this and  why tunnel established in 1st
attempt.*

*Please help and guide.*

*System details.*

*Strongswan (4.5.3) on debian 8.*


*Regards*
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/dev/attachments/20160411/b3285941/attachment.html>
-------------- next part --------------
 sending cert request for "CN=TEST-12345 Certificate Authority"
07[ENC] generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) V ]
07[NET] sending packet: from 10.0.2.1[500] to 10.0.1.1[500]
06[NET] received packet: from 10.0.1.1[4500] to 10.0.2.1[4500]
06[ENC] parsed IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH SA TSi TSr N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
06[IKE] received cert request for "CN=TEST-12345 Certificate Authority"
06[IKE] received end entity cert "CN=device-1, OU=strongswan"
06[CFG] looking for peer configs matching 10.0.2.1[CN=device-3, OU=strongswan]...10.0.1.1[CN=device-1, OU=strongswan]
06[CFG] selected peer config 'AtoE'
06[CFG]   using certificate "CN=device-1, OU=strongswan"
06[CFG]   using trusted ca certificate "CN=TEST-12345 Certificate Authority"
06[CFG] checking certificate status of "CN=device-1, OU=strongswan"
06[CFG]   fetching crl from 'http://test.ca/ca_crl.filel' ...
06[LIB] unable to fetch from http://test.ca/ca_crl.filel, no capable fetcher found
06[CFG] crl fetching failed
06[CFG] certificate status is not available
06[CFG]   reached self-signed root ca with a path length of 0
06[IKE] authentication of 'CN=device-1, OU=strongswan' with RSA signature successful
06[IKE] peer supports MOBIKE

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x2e4b84b0 (LWP 2556)]
0x2acf0298 in strlen () from /lib/libc.so.6
(gdb) bt
#0  0x2acf0298 in strlen () from /lib/libc.so.6
#1  0x2acb0d0c in vfprintf () from /lib/libc.so.6
#2  0x2acd59d0 in vsnprintf () from /lib/libc.so.6
#3  0x2acb8b50 in snprintf () from /lib/libc.so.6
#4  0x2aae3a44 in enum_printf_hook (dst=0x2e4b2b8c "", len=8192, 
    spec=<value optimized out>, args=<value optimized out>) at enum.c:77
#5  0x2aae6b20 in custom_print (stream=0x2e4b5828, info=<value optimized out>, 
    args=<value optimized out>) at printf_hook.c:98
#6  0x2acadf9c in vfprintf () from /lib/libc.so.6
#7  0x2acd59d0 in vsnprintf () from /lib/libc.so.6
#8  0x2ab3cd50 in log_ (this=0x4189b8, group=DBG_LIB, 
    level=<value optimized out>, thread=6, ike_sa=0x44cd60, 
    format=0x2b1cc3c4 "C_Sign() failed: %N", args=0x2e4b7ba4)
    at bus/listeners/file_logger.c:92
#9  0x2ab3c730 in log_cb (entry=0x418a40, data=<value optimized out>)
    at bus/bus.c:223
#10 0x2ab050a0 in remove_ (this=0x417fb0, item=0x2e4b7b38, 
    compare=0x2ab3c6b4 <log_cb>) at utils/linked_list.c:362
#11 0x2ab3c64c in vlog (this=0x417f50, group=<value optimized out>, 
    level=<value optimized out>, format=<value optimized out>, args=0x2e4b7ba4)
    at bus/bus.c:260
#12 0x2ab437a0 in dbg_bus (group=2136286244, level=-16843009, 
    fmt=0x270 <Address 0x270 out of bounds>) at daemon.c:92
---Type <return> to continue, or q <return> to quit---
#13 0x2b1c7aec in sign (this=0x43e048, scheme=<value optimized out>, data=..., 
    signature=0x2e4b7c18) at pkcs11_private_key.c:211
#14 0x2ab58a0c in build (this=0x450f30, message=0x450bd8)
    at sa/authenticators/pubkey_authenticator.c:116
#15 0x2ab70830 in build_r (this=0x44a6b8, message=0x450bd8)
    at sa/tasks/ike_auth.c:772
#16 0x2ab661f4 in build_response (this=0x44ea10, msg=0x4434e8)
    at sa/task_manager.c:620
#17 process_request (this=0x44ea10, msg=0x4434e8) at sa/task_manager.c:884
#18 process_message (this=0x44ea10, msg=0x4434e8) at sa/task_manager.c:915
#19 0x2ab5f23c in process_message (this=0x44cd60, message=0x4434e8)
    at sa/ike_sa.c:1310
#20 0x2ab52a40 in execute (this=0x446b50)
    at processing/jobs/process_message_job.c:74
#21 0x2aafc294 in process_jobs (this=0x417538) at processing/processor.c:188
#22 0x2aaff474 in thread_main (this=0x43f5b0) at threading/thread.c:291
#23 0x2ac2e0a8 in start_thread () from /lib/libpthread.so.0
#24 0x2ad5b738 in ?? () from /lib/libc.so.6
warning: GDB can't find the start of the function at 0x2ad5b737.

    GDB is unable to find the start of the function at 0x2ad5b737
and thus can't determine the size of that function's stack frame.
This means that GDB may be unable to access that stack frame, or
the frames below it.
---Type <return> to continue, or q <return> to quit---
    This problem is most likely caused by an invalid program counter or
stack pointer.

-------------- next part --------------


Dec  4 03:55:02 localhost /USR/SBIN/CRON[11133]: (CRON) info (No MTA installed, discarding output)
Dec  4 03:55:07 localhost charon: 00[DMN] Starting IKEv2 charon daemon (strongSwan 4.5.3)
Dec  4 03:55:08 localhost charon: 00[CFG] loaded PKCS#11 v2.20 library 'opensc' (/usr/local/lib/opensc-pkcs11.so)
Dec  4 03:55:08 localhost charon: 00[CFG]   OpenSC (www.opensc-project.org): Smart card PKCS#11 API v0.0
Dec  4 03:55:08 localhost charon: 00[CFG]   found token in slot 'opensc':1 (xxxxxxxxxxxxx)
Dec  4 03:55:08 localhost charon: 00[CFG]     loaded untrusted cert '/CN=device-1/OU=strongswan'
Dec  4 03:55:08 localhost charon: 00[CFG]     loaded trusted cert '/CN=TEST-12345 Certificate Authority'
Dec  4 03:55:08 localhost charon: 00[KNL] listening on interfaces:
Dec  4 03:55:08 localhost charon: 00[KNL]   eth0
Dec  4 03:55:08 localhost charon: 00[KNL]     10.0.1.1
Dec  4 03:55:08 localhost charon: 00[KNL]     fe80::76fe:48ff:fe0e:51cd
Dec  4 03:55:08 localhost charon: 00[CFG] loading ca certificates from '//etc/ipsec.d/cacerts'
Dec  4 03:55:08 localhost charon: 00[CFG] loading aa certificates from '//etc/ipsec.d/aacerts'
Dec  4 03:55:08 localhost charon: 00[CFG] loading ocsp signer certificates from '//etc/ipsec.d/ocspcerts'
Dec  4 03:55:08 localhost charon: 00[CFG] loading attribute certificates from '//etc/ipsec.d/acerts'
Dec  4 03:55:08 localhost charon: 00[CFG] loading crls from '//etc/ipsec.d/crls'
Dec  4 03:55:08 localhost charon: 00[CFG] loading secrets from '//etc/ipsec.secrets'
Dec  4 03:55:08 localhost charon: 00[CFG] found key on PKCS#11 token 'opensc':1
Dec  4 03:55:08 localhost charon: 00[CFG]   loaded private key from %smartcard:49
Dec  4 03:55:08 localhost charon: 00[DMN] loaded plugins: test-vectors aes des sha1 sha2 md5 random x509 revocation constraints pubkey pkcs1 pgp pem openssl fips-prf gmp pkcs11 xcbc hmac ctr ccm gcm attr kernel-netlink resolve socket-default socket-raw socket-dynamic stroke updown 
Dec  4 03:55:08 localhost charon: 00[JOB] spawning 16 worker threads
Dec  4 03:55:09 localhost charon: 02[CFG] module 'opensc' does not support hot-plugging, cancelled
Dec  4 03:55:09 localhost charon: 07[CFG] received stroke: add connection 'AtoE'
Dec  4 03:55:09 localhost charon: 07[CFG] added configuration 'AtoE'
Dec  4 03:55:09 localhost charon: 07[NET] received packet: from 10.0.2.1[500] to 10.0.1.1[500]
Dec  4 03:55:09 localhost charon: 07[ENC] parsed IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) V ]
Dec  4 03:55:09 localhost charon: 08[CFG] received stroke: initiate 'AtoE'
Dec  4 03:55:09 localhost charon: 07[IKE] received strongSwan vendor id
Dec  4 03:55:09 localhost charon: 07[IKE] 10.0.2.1 is initiating an IKE_SA
Dec  4 03:55:09 localhost charon: 07[IKE] sending cert request for "CN=TEST-12345 Certificate Authority"
Dec  4 03:55:09 localhost charon: 07[ENC] generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) V ]
Dec  4 03:55:09 localhost charon: 07[NET] sending packet: from 10.0.1.1[500] to 10.0.2.1[500]
Dec  4 03:55:09 localhost charon: 08[IKE] initiating IKE_SA AtoE[2] to 10.0.2.1
Dec  4 03:55:09 localhost charon: 08[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) V ]
Dec  4 03:55:09 localhost charon: 08[NET] sending packet: from 10.0.1.1[500] to 10.0.2.1[500]
Dec  4 03:55:09 localhost charon: 09[NET] received packet: from 10.0.2.1[500] to 10.0.1.1[500]
Dec  4 03:55:09 localhost charon: 09[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) V ]
Dec  4 03:55:09 localhost charon: 09[IKE] received strongSwan vendor id
Dec  4 03:55:09 localhost charon: 09[IKE] received cert request for "CN=TEST-12345 Certificate Authority"
Dec  4 03:55:09 localhost charon: 09[IKE] sending cert request for "CN=TEST-12345 Certificate Authority"
Dec  4 03:55:10 localhost charon: 10[NET] received packet: from 10.0.2.1[4500] to 10.0.1.1[4500]
Dec  4 03:55:10 localhost charon: 10[ENC] parsed IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH SA TSi TSr N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
Dec  4 03:55:10 localhost charon: 10[IKE] received cert request for "CN=TEST-12345 Certificate Authority"
Dec  4 03:55:10 localhost charon: 10[IKE] received end entity cert "CN=device-3, OU=strongswan"
Dec  4 03:55:10 localhost charon: 10[CFG] looking for peer configs matching 10.0.1.1[CN=device-1, OU=strongswan]...10.0.2.1[CN=device-3, OU=strongswan]
Dec  4 03:55:10 localhost charon: 10[CFG] selected peer config 'AtoE'
Dec  4 03:55:10 localhost charon: 10[CFG]   using certificate "CN=device-3, OU=strongswan"
Dec  4 03:55:10 localhost charon: 10[CFG]   using trusted ca certificate "CN=TEST-12345 Certificate Authority"
Dec  4 03:55:10 localhost charon: 10[CFG] checking certificate status of "CN=device-3, OU=strongswan"
Dec  4 03:55:10 localhost charon: 10[CFG]   fetching crl from 'http://test.ca/ca_crl.filel' ...
Dec  4 03:55:10 localhost charon: 10[LIB] unable to fetch from http://test.ca/ca_crl.filel, no capable fetcher found
Dec  4 03:55:10 localhost charon: 10[CFG] crl fetching failed
Dec  4 03:55:10 localhost charon: 10[CFG] certificate status is not available
Dec  4 03:55:10 localhost charon: 10[CFG]   reached self-signed root ca with a path length of 0
Dec  4 03:55:10 localhost charon: 10[IKE] authentication of 'CN=device-3, OU=strongswan' with RSA signature successful
Dec  4 03:55:10 localhost charon: 10[IKE] peer supports MOBIKE
Dec  4 03:55:10 localhost charon: 09[IKE] authentication of 'CN=device-1, OU=strongswan' (myself) with RSA signature successful
Dec  4 03:55:10 localhost charon: 09[IKE] sending end entity cert "CN=device-1, OU=strongswan"
Dec  4 03:55:10 localhost charon: 09[IKE] establishing CHILD_SA AtoE
Dec  4 03:55:10 localhost charon: 09[KNL] 
Dec  4 03:55:10 localhost charon: 09[KNL] 

Dec  4 03:55:10 localhost charon: 09[KNL] 
Dec  4 03:55:10 localhost charon: 09[ENC] generating IKE_AUTH request 1 [ IDi CERT CERTREQ IDr AUTH SA TSi TSr N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
Dec  4 03:55:10 localhost charon: 09[NET] sending packet: from 10.0.1.1[4500] to 10.0.2.1[4500]
Dec  4 03:55:11 localhost charon: 10[IKE] authentication of 'CN=device-1, OU=strongswan' (myself) with RSA signature successful
Dec  4 03:55:11 localhost charon: 10[IKE] IKE_SA AtoE[1] established between 10.0.1.1[CN=device-1, OU=strongswan]...10.0.2.1[CN=device-3, OU=strongswan]
Dec  4 03:55:11 localhost charon: 10[IKE] scheduling reauthentication in 85544s
Dec  4 03:55:11 localhost charon: 10[IKE] maximum IKE_SA lifetime 86084s
Dec  4 03:55:11 localhost charon: 10[IKE] sending end entity cert "CN=device-1, OU=strongswan"

Dec  4 03:55:11 localhost charon: 11[NET] received packet: from 10.0.2.1[4500] to 10.0.1.1[4500]
Dec  4 03:55:11 localhost charon: 11[ENC] parsed IKE_AUTH response 1 [ IDr CERT AUTH SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) N(NO_ADD_ADDR) ]
Dec  4 03:55:11 localhost charon: 11[IKE] received end entity cert "CN=device-3, OU=strongswan"
Dec  4 03:55:11 localhost charon: 11[CFG]   using certificate "CN=device-3, OU=strongswan"
Dec  4 03:55:11 localhost charon: 11[CFG]   using trusted ca certificate "CN=TEST-12345 Certificate Authority"
Dec  4 03:55:11 localhost charon: 11[CFG] checking certificate status of "CN=device-3, OU=strongswan"
Dec  4 03:55:11 localhost charon: 11[CFG]   fetching crl from 'http://test.ca/ca_crl.filel' ...
Dec  4 03:55:11 localhost charon: 11[LIB] unable to fetch from http://test.ca/ca_crl.filel, no capable fetcher found
Dec  4 03:55:11 localhost charon: 11[CFG] crl fetching failed
Dec  4 03:55:11 localhost charon: 11[CFG] certificate status is not available
Dec  4 03:55:11 localhost charon: 11[CFG]   reached self-signed root ca with a path length of 0
Dec  4 03:55:11 localhost charon: 11[IKE] authentication of 'CN=device-3, OU=strongswan' with RSA signature successful

Dec  4 03:55:11 localhost charon: 11[IKE] IKE_SA AtoE[2] established between 10.0.1.1[CN=device-1, OU=strongswan]...10.0.2.1[CN=device-3, OU=strongswan]
Dec  4 03:55:11 localhost charon: 11[IKE] scheduling reauthentication in 85517s
Dec  4 03:55:11 localhost charon: 11[IKE] maximum IKE_SA lifetime 86057s
Dec  4 03:55:11 localhost charon: 11[KNL] 

Dec  4 03:55:11 localhost charon: 10[KNL] 
Dec  4 03:55:11 localhost charon: 10[KNL] 
Dec  4 03:55:11 localhost charon: 10[KNL] 

Dec  4 03:55:11 localhost charon: 10[IKE] CHILD_SA AtoE{2} established with SPIs c210cfa7_i cf33bc96_o and TS 10.0.1.0/24 === 10.0.2.0/24 
Dec  4 03:55:11 localhost charon: 10[ENC] generating IKE_AUTH response 1 [ IDr CERT AUTH SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) N(NO_ADD_ADDR) ]
Dec  4 03:55:11 localhost charon: 10[NET] sending packet: from 10.0.1.1[4500] to 10.0.2.1[4500]

Dec  4 03:55:11 localhost charon: 11[IKE] CHILD_SA AtoE{1} established with SPIs cd9f2791_i c7394053_o and TS 10.0.1.0/24 === 10.0.2.0/24 
Dec  4 03:55:11 localhost charon: 11[IKE] received AUTH_LIFETIME of 85496s, scheduling reauthentication in 84956s
Dec  4 03:55:11 localhost charon: 11[IKE] peer supports MOBIKE
Dec  4 03:55:24 localhost charon: 14[KNL] 

Dec  4 03:55:40 localhost charon: 07[IKE] sending DPD request
Dec  4 03:55:40 localhost charon: 07[ENC] generating INFORMATIONAL request 0 [ ]
Dec  4 03:55:40 localhost charon: 07[NET] sending packet: from 10.0.1.1[4500] to 10.0.2.1[4500]
Dec  4 03:55:40 localhost charon: 08[NET] received packet: from 10.0.2.1[4500] to 10.0.1.1[4500]
Dec  4 03:55:40 localhost charon: 08[ENC] parsed INFORMATIONAL response 0 [ ]
Dec  4 03:55:41 localhost charon: 09[NET] received packet: from 10.0.2.1[4500] to 10.0.1.1[4500]
Dec  4 03:55:41 localhost charon: 09[ENC] parsed INFORMATIONAL request 0 [ ]
Dec  4 03:55:41 localhost charon: 09[ENC] generating INFORMATIONAL response 0 [ ]
Dec  4 03:55:41 localhost charon: 09[NET] sending packet: from 10.0.1.1[4500] to 10.0.2.1[4500]
Dec  4 03:55:41 localhost charon: 10[KNL] 
Dec  4 03:55:41 localhost charon: 10[KNL] 
Dec  4 03:55:41 localhost charon: 10[KNL] query_sa    kernel_netlink_ipsec.c    2048
Dec  4 03:55:41 localhost charon: 10[KNL] 
Dec  4 03:55:41 localhost charon: 10[KNL] 
Dec  4 03:55:51 localhost charon: 00[DMN] signal of type SIGINT received. Shutting down
Dec  4 03:55:51 localhost charon: 00[IKE] deleting IKE_SA AtoE[1] between 10.0.1.1[CN=device-1, OU=strongswan]...10.0.2.1[CN=device-3, OU=strongswan]
Dec  4 03:55:51 localhost charon: 00[IKE] sending DELETE for IKE_SA AtoE[1]
Dec  4 03:55:51 localhost charon: 00[ENC] generating INFORMATIONAL request 1 [ D ]
Dec  4 03:55:51 localhost charon: 00[NET] sending packet: from 10.0.1.1[4500] to 10.0.2.1[4500]
Dec  4 03:55:51 localhost charon: 00[IKE] deleting IKE_SA AtoE[2] between 10.0.1.1[CN=device-1, OU=strongswan]...10.0.2.1[CN=device-3, OU=strongswan]
Dec  4 03:55:51 localhost charon: 00[IKE] sending DELETE for IKE_SA AtoE[2]
Dec  4 03:55:51 localhost charon: 00[ENC] generating INFORMATIONAL request 2 [ D ]
Dec  4 03:55:51 localhost charon: 00[NET] sending packet: from 10.0.1.1[4500] to 10.0.2.1[4500]



More information about the Dev mailing list