[strongSwan] preparing sqlite statement failed: library routine called out of sequence

divya mohan m.divya.mohan at zoho.com
Fri Apr 10 12:02:24 CEST 2015


Hi,

I am using strongswan's charon to setup remote access IPSec tunnel
with DB-based (sqlite3) server-side virtual IP pool.
I am facing an issue at the server side that, if two clients try to
establish connection simultaneously, virtual ip assignment is failing.
Following is the error:

    13[LIB] preparing sqlite statement failed: library routine called
out of sequence
    13[LIB] no available address found in pool 'bigpool'
    14[IKE] no virtual IP found, sending INTERNAL_ADDRESS_FAILURE

This issue is not observed if the clients connect one by one, in that
case virtual ip assignment is happening properly.

Is this some known limitation that clients cannot connect at the same
time? Can any change in configuration help?

Providing logs below:

==========================
Server side configuration
==========================

# ipsec pool --status
no dns servers found.
no nbns servers found.
    name           start             end  timeout   size      online       usage
 bigpool        90.0.0.1      90.0.0.100   static    100     0 ( 0%)     2 ( 2%)


# cat /etc/strongswan.conf
libstrongswan {
  plugins {
    attr-sql {
      database = sqlite:///etc/ipsec.d/ipsec.db
    }
  }
}

pool {
  load = sqlite
}
charon {
reuse_ikesa=no
install_routes=no
block_threshold=50
cookie_threshold=100
load = openssl random pem x509 pubkey pkcs1 hmac xcbc stroke
kernel-netlink sqlite attr-sql
}


# cat /etc/ipsec.conf

config setup
        charonstart=yes
        plutostart=no
        uniqueids=no
        charondebug="knl 0,ike 2,mgr 2,enc 0,net 2,lib 2"
conn %default
        auto=route
        keyexchange=ikev2
        reauth=no
conn ruleRW~vpnRW
        rekeymargin=1000
        rekeyfuzz=100%
        left=10.10.10.4
        right=%any
        leftsubnet=50.50.50.6/32
        rightsourceip=%bigpool
        authby=secret
        leftid=10.10.10.4
        rightid=%any
        ike=aes128-sha1-modp768!
        esp=aes128-sha1!
        type=tunnel
        ikelifetime=16000s
        keylife=10000s
        dpdaction=clear
        dpddelay=25
        mobike=no
        auto=add
        reauth=no
        encapdscp=yes


=============================================
Logs when two clients connect simultaneously
=============================================

Starting strongSwan 4.3.6 IPsec [starter]...
00[DMN] Starting IKEv2 charon daemon (strongSwan 4.3.6)
00[LIB] plugin 'openssl': loaded successfully
00[LIB] plugin 'random': loaded successfully
00[LIB] plugin 'pem': loaded successfully
00[LIB] plugin 'x509': loaded successfully
00[LIB] plugin 'pubkey': loaded successfully
00[LIB] plugin 'pkcs1': loaded successfully
00[LIB] plugin 'hmac': loaded successfully
00[LIB] plugin 'xcbc': loaded successfully
00[CFG] loading ca certificates from '/etc/ipsec/certs/ipsec.d/cacerts'
00[CFG] loading aa certificates from '/etc/ipsec/certs/ipsec.d/aacerts'
00[CFG] loading ocsp signer certificates from
'/etc/ipsec/certs/ipsec.d/ocspcerts'
00[CFG] loading attribute certificates from '/etc/ipsec/certs/ipsec.d/acerts'
00[CFG] loading crls from '/etc/ipsec/certs/ipsec.d/crls'
00[CFG] loading secrets from '/etc/ipsec.secrets'
00[CFG]   loaded IKE secret for %any
00[LIB] plugin 'stroke': loaded successfully
00[LIB] plugin 'kernel-netlink': loaded successfully
00[LIB] plugin 'sqlite': loaded successfully
00[LIB] plugin 'attr-sql': loaded successfully
00[DMN] loaded plugins: openssl random pem x509 pubkey pkcs1 hmac xcbc
stroke kernel-netlink sqlite attr-sql
00[JOB] spawning 16 worker threads
06[NET] waiting for data on sockets
charon (15687) started after 180 ms
07[CFG] received stroke: add connection 'ruleRW~vpnRW'
07[CFG] added configuration 'ruleRW~vpnRW'
09[CFG] rereading secrets
09[CFG] loading secrets from '/etc/ipsec.secrets'
09[CFG]   loaded IKE secret for %any
09[CFG] rereading ca certificates from '/etc/ipsec/certs/ipsec.d/cacerts'
09[CFG] rereading ocsp signer certificates from
'/etc/ipsec/certs/ipsec.d/ocspcerts'
09[CFG] rereading aa certificates from '/etc/ipsec/certs/ipsec.d/aacerts'
09[CFG] rereading attribute certificates from '/etc/ipsec/certs/ipsec.d/acerts'
09[CFG] rereading crls from '/etc/ipsec/certs/ipsec.d/crls'


06[NET] received packet: from (vr3)[5000] to (vr3)[500]
06[NET] waiting for data on sockets
11[MGR] checkout IKE_SA by message
11[MGR] created IKE_SA
11[NET] received packet: from (vr3)[5000] to (vr3)[500]
11[IKE] (vr3)90.90.90.9 is initiating an IKE_SA
11[IKE] IKE_SA (unnamed)[1] state change: CREATED => CONNECTING
11[LIB] size of DH secret exponent: 767 bits
06[NET] received packet: from (vr3)[5051] to (vr3)[500]
06[NET] waiting for data on sockets
12[MGR] checkout IKE_SA by message
12[MGR] created IKE_SA
12[NET] received packet: from (vr3)[5051] to (vr3)[500]
12[IKE] (vr3)90.90.90.9 is initiating an IKE_SA
12[IKE] IKE_SA (unnamed)[2] state change: CREATED => CONNECTING
11[IKE] local host is behind NAT, sending keep alives
11[IKE] remote host is behind NAT
11[NET] sending packet: from (vr3)[500] to (vr3)[5000]
11[MGR] checkin IKE_SA
05[NET] sending packet: from (vr3)[500] to (vr3)[5000]
11[MGR] check-in of IKE_SA successful.
12[LIB] size of DH secret exponent: 767 bits
12[IKE] local host is behind NAT, sending keep alives
12[IKE] remote host is behind NAT
12[NET] sending packet: from (vr3)[500] to (vr3)[5051]
12[MGR] checkin IKE_SA
05[NET] sending packet: from (vr3)[500] to (vr3)[5051]
12[MGR] check-in of IKE_SA successful.
06[NET] received packet: from (vr3)[5000] to (vr3)[4500]
06[NET] waiting for data on sockets
13[MGR] checkout IKE_SA by message
13[MGR] IKE_SA successfully checked out
13[NET] received packet: from (vr3)[5000] to (vr3)[4500]
13[CFG] looking for peer configs matching
(vr3)10.10.10.4[(vr*)%any]...(vr3)90.90.90.9[(vr*)30.30.30.3]
13[CFG] selected peer config 'ruleRW~vpnRW'
13[IKE] authentication of '(vr*)30.30.30.3' with pre-shared key successful
13[IKE] processing INTERNAL_IP4_ADDRESS attribute
13[IKE] authentication of '(vr*)10.10.10.4' (myself) with pre-shared key
13[IKE] successfully created shared key MAC
13[IKE] IKE_SA ruleRW~vpnRW[1] established between
(vr3)10.10.10.4[(vr*)10.10.10.4]...(vr3)90.90.90.9[(vr*)30.30.30.3]
13[IKE] IKE_SA ruleRW~vpnRW[1] state change: CONNECTING => ESTABLISHED
13[IKE] scheduling rekeying in 14808s
13[IKE] maximum IKE_SA lifetime 15808s
13[IKE] peer requested virtual IP (vr*)%any
06[NET] received packet: from (vr3)[5051] to (vr3)[4500]
06[NET] waiting for data on sockets
14[MGR] checkout IKE_SA by message
14[MGR] IKE_SA successfully checked out

14[NET] received packet: from (vr3)[5051] to (vr3)[4500]
14[CFG] looking for peer configs matching
(vr3)10.10.10.4[(vr*)%any]...(vr3)90.90.90.9[(vr*)40.40.40.3]
14[CFG] selected peer config 'ruleRW~vpnRW'
14[IKE] authentication of '(vr*)40.40.40.3' with pre-shared key successful
14[IKE] processing INTERNAL_IP4_ADDRESS attribute
14[IKE] authentication of '(vr*)10.10.10.4' (myself) with pre-shared key
14[IKE] successfully created shared key MAC
14[IKE] IKE_SA ruleRW~vpnRW[2] established between
(vr3)10.10.10.4[(vr*)10.10.10.4]...(vr3)90.90.90.9[(vr*)40.40.40.3]
14[IKE] IKE_SA ruleRW~vpnRW[2] state change: CONNECTING => ESTABLISHED
14[IKE] scheduling rekeying in 14461s
14[IKE] maximum IKE_SA lifetime 15461s
14[IKE] peer requested virtual IP (vr*)%any
14[LIB] preparing sqlite statement failed: library routine called out
of sequence
13[LIB] sqlite execute failed: library routine called out of sequence
13[LIB] preparing sqlite statement failed: library routine called out
of sequence
14[LIB] preparing sqlite statement failed: library routine called out
of sequence
14[LIB] acquiring address from pool 'bigpool' failed
13[LIB] preparing sqlite statement failed: library routine called out
of sequence
13[LIB] no available address found in pool 'bigpool'
14[IKE] no virtual IP found, sending INTERNAL_ADDRESS_FAILURE
13[LIB] acquiring address from pool 'bigpool' failed
13[IKE] no virtual IP found, sending INTERNAL_ADDRESS_FAILURE
14[IKE] configuration payload negotation failed, no CHILD_SA built
13[IKE] configuration payload negotation failed, no CHILD_SA built
14[NET] sending packet: from (vr3)[4500] to (vr3)[5051]
14[MGR] checkin IKE_SA
14[MGR] check-in of IKE_SA successful.
05[NET] sending packet: from (vr3)[4500] to (vr3)[5051]
13[NET] sending packet: from (vr3)[4500] to (vr3)[5000]
05[NET] sending packet: from (vr3)[4500] to (vr3)[5000]
13[MGR] checkin IKE_SA
13[MGR] check-in of IKE_SA successful.

=====================================
Logs when clients connect one by one
=====================================
Starting strongSwan 4.3.6 IPsec [starter]...
00[DMN] Starting IKEv2 charon daemon (strongSwan 4.3.6)
00[LIB] plugin 'openssl': loaded successfully
00[LIB] plugin 'random': loaded successfully
00[LIB] plugin 'pem': loaded successfully
00[LIB] plugin 'x509': loaded successfully
00[LIB] plugin 'pubkey': loaded successfully
00[LIB] plugin 'pkcs1': loaded successfully
00[LIB] plugin 'hmac': loaded successfully
00[LIB] plugin 'xcbc': loaded successfully
00[CFG] loading ca certificates from '/etc/ipsec/certs/ipsec.d/cacerts'
00[CFG] loading aa certificates from '/etc/ipsec/certs/ipsec.d/aacerts'
00[CFG] loading ocsp signer certificates from
'/etc/ipsec/certs/ipsec.d/ocspcerts'
00[CFG] loading attribute certificates from '/etc/ipsec/certs/ipsec.d/acerts'
00[CFG] loading crls from '/etc/ipsec/certs/ipsec.d/crls'
00[CFG] loading secrets from '/etc/ipsec.secrets'
00[CFG]   loaded IKE secret for %any
00[LIB] plugin 'stroke': loaded successfully
00[LIB] plugin 'kernel-netlink': loaded successfully
00[LIB] plugin 'sqlite': loaded successfully
00[LIB] plugin 'attr-sql': loaded successfully
00[DMN] loaded plugins: openssl random pem x509 pubkey pkcs1 hmac xcbc
stroke kernel-netlink sqlite attr-sql
00[JOB] spawning 16 worker threads
06[NET] waiting for data on sockets
charon (15632) started after 160 ms
07[CFG] received stroke: add connection 'ruleRW~vpnRW'
07[CFG] added configuration 'ruleRW~vpnRW'
09[CFG] rereading secrets
09[CFG] loading secrets from '/etc/ipsec.secrets'
09[CFG]   loaded IKE secret for %any
09[CFG] rereading ca certificates from '/etc/ipsec/certs/ipsec.d/cacerts'
09[CFG] rereading ocsp signer certificates from
'/etc/ipsec/certs/ipsec.d/ocspcerts'
09[CFG] rereading aa certificates from '/etc/ipsec/certs/ipsec.d/aacerts'
09[CFG] rereading attribute certificates from '/etc/ipsec/certs/ipsec.d/acerts'
09[CFG] rereading crls from '/etc/ipsec/certs/ipsec.d/crls'

06[NET] received packet: from (vr3)[5000] to (vr3)[500]
06[NET] waiting for data on sockets
11[MGR] checkout IKE_SA by message
11[MGR] created IKE_SA
11[NET] received packet: from (vr3)[5000] to (vr3)[500]
11[IKE] (vr3)90.90.90.9 is initiating an IKE_SA
11[IKE] IKE_SA (unnamed)[1] state change: CREATED => CONNECTING
11[LIB] size of DH secret exponent: 767 bits
11[IKE] local host is behind NAT, sending keep alives
11[IKE] remote host is behind NAT
11[NET] sending packet: from (vr3)[500] to (vr3)[5000]
05[NET] sending packet: from (vr3)[500] to (vr3)[5000]
11[MGR] checkin IKE_SA
11[MGR] check-in of IKE_SA successful.
06[NET] received packet: from (vr3)[5000] to (vr3)[4500]
06[NET] waiting for data on sockets
12[MGR] checkout IKE_SA by message
12[MGR] IKE_SA successfully checked out
12[NET] received packet: from (vr3)[5000] to (vr3)[4500]
12[CFG] looking for peer configs matching
(vr3)10.10.10.4[(vr*)%any]...(vr3)90.90.90.9[(vr*)30.30.30.3]
12[CFG] selected peer config 'ruleRW~vpnRW'
12[IKE] authentication of '(vr*)30.30.30.3' with pre-shared key successful
12[IKE] processing INTERNAL_IP4_ADDRESS attribute
12[IKE] authentication of '(vr*)10.10.10.4' (myself) with pre-shared key
12[IKE] successfully created shared key MAC
12[IKE] IKE_SA ruleRW~vpnRW[1] established between
(vr3)10.10.10.4[(vr*)10.10.10.4]...(vr3)90.90.90.9[(vr*)30.30.30.3]
12[IKE] IKE_SA ruleRW~vpnRW[1] state change: CONNECTING => ESTABLISHED
12[IKE] scheduling rekeying in 14497s
12[IKE] maximum IKE_SA lifetime 15497s
12[IKE] peer requested virtual IP (vr*)%any
12[LIB] acquired existing lease for address 90.0.0.1 in pool 'bigpool'
12[IKE] assigning virtual IP (vr3)90.0.0.1 to peer
12[IKE] CHILD_SA ruleRW~vpnRW{1} established with SPIs cfd3d7fe_i
cc8c6148_o and TS (vr3)50.50.50.6/32 === (vr3)90.0.0.1/32
12[NET] sending packet: from (vr3)[4500] to (vr3)[5000]
05[NET] sending packet: from (vr3)[4500] to (vr3)[5000]
12[MGR] checkin IKE_SA
12[MGR] check-in of IKE_SA successful.

06[NET] received packet: from (vr3)[5051] to (vr3)[500]
06[NET] waiting for data on sockets
13[MGR] checkout IKE_SA by message
13[MGR] created IKE_SA
13[NET] received packet: from (vr3)[5051] to (vr3)[500]
13[IKE] (vr3)90.90.90.9 is initiating an IKE_SA
13[IKE] IKE_SA (unnamed)[2] state change: CREATED => CONNECTING
13[LIB] size of DH secret exponent: 767 bits
13[IKE] local host is behind NAT, sending keep alives
13[IKE] remote host is behind NAT
13[NET] sending packet: from (vr3)[500] to (vr3)[5051]
05[NET] sending packet: from (vr3)[500] to (vr3)[5051]
13[MGR] checkin IKE_SA
13[MGR] check-in of IKE_SA successful.
06[NET] received packet: from (vr3)[5051] to (vr3)[4500]
06[NET] waiting for data on sockets
14[MGR] checkout IKE_SA by message
14[MGR] IKE_SA successfully checked out
14[NET] received packet: from (vr3)[5051] to (vr3)[4500]
14[CFG] looking for peer configs matching
(vr3)10.10.10.4[(vr*)%any]...(vr3)90.90.90.9[(vr*)40.40.40.3]
14[CFG] selected peer config 'ruleRW~vpnRW'
14[IKE] authentication of '(vr*)40.40.40.3' with pre-shared key successful
14[IKE] processing INTERNAL_IP4_ADDRESS attribute
14[IKE] authentication of '(vr*)10.10.10.4' (myself) with pre-shared key
14[IKE] successfully created shared key MAC
14[IKE] IKE_SA ruleRW~vpnRW[2] established between
(vr3)10.10.10.4[(vr*)10.10.10.4]...(vr3)90.90.90.9[(vr*)40.40.40.3]
14[IKE] IKE_SA ruleRW~vpnRW[2] state change: CONNECTING => ESTABLISHED
14[IKE] scheduling rekeying in 14929s
14[IKE] maximum IKE_SA lifetime 15929s
14[IKE] peer requested virtual IP (vr*)%any
14[LIB] acquired existing lease for address 90.0.0.2 in pool 'bigpool'
14[IKE] assigning virtual IP (vr3)90.0.0.2 to peer
14[IKE] CHILD_SA ruleRW~vpnRW{2} established with SPIs c6bfe501_i
cde19fb3_o and TS (vr3)50.50.50.6/32 === (vr3)90.0.0.2/32
14[NET] sending packet: from (vr3)[4500] to (vr3)[5051]
05[NET] sending packet: from (vr3)[4500] to (vr3)[5051]
14[MGR] checkin IKE_SA
14[MGR] check-in of IKE_SA successful.


- Divya


More information about the Users mailing list