[Openswan dev] ip_hdr discrepancies

Tue Feb 17 05:10:12 EST 2009

>>>> klips_debug:ipsec_xmit_send: ip_route_output failed with error code
>>>> -22,
>>>> dropped
>>
>> I am not an expert, but from the logs I would assume that the packed
>> gets encrypted, but cannot be output because ip_route_output_key fails.
>> I have confirmed that I have the correct route ("ip route ls") and that
>> the packet destination address matches rightsubnet. I have tried pinging
>> from inside network as well as from gateway itself (by setting
>> leftsourceip or by manually assigning IP to ipsec0). I've tried to
>> create routes manually. Yet, nothing helps. If I change to netkey, all
>> these scenarios work (meaning I can see ESP packet being sent with
>> tcpdump).
> 
> Let me know if this is still a problem with openswan 2.6.20.
> 
> Paul

Unfortunately, the problem is still there with openswan 2.6.20.

Here is the log from klipsdebug --all. It seems to me like the one
before. Let me know if you need anything else.

Feb 15 07:26:21 centos kernel: ipsec_tunnel_start_xmit:
STARTING<6>klips_debug:ipsec_xmit_strip_hard_header: >>> skb->len=98
hard_header_len:14 00:0c:29:dd:65:bb:00:0c:29:dd:65:bb:08:00
Feb 15 07:26:21 centos kernel: klips_debug:   IP: ihl:20 ver:4 tos:0
tlen:84 id:0 DF frag_off:0 ttl:64 proto:1 (ICMP) chk:9889 saddr:10.1.0.1
daddr:10.2.0.5 type:code=8:0
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_strip_hard_header:
Original head,tailroom: 2,28
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_findroute:
10.1.0.1:0->10.2.0.5:0 1
Feb 15 07:26:21 centos kernel: klips_debug:rj_match: * See if we match
exactly as a host destination
Feb 15 07:26:21 centos kernel: klips_debug:rj_match: ** try to match a
leaf, t=0pe16e35c0
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_SAlookup: checking
for local udp/500 IKE packet saddr=a010001, er=0pe16e35c0,
daddr=a020005, er_dst=c0a80248, proto=1 sport=0 dport=0
Feb 15 07:26:21 centos kernel: ipsec_sa_getbyid: linked entry in
ipsec_sa table for hash=226 of SA:tun.1005 at 192.168.2.72 requested.
Feb 15 07:26:21 centos kernel: ipsec_sa_get: ipsec_sa e4eb8800
SA:tun.1005 at 192.168.2.72, ref:9 reference count (2++) incremented by
ipsec_sa_getbyid:552.
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_init2: found
ipsec_sa -- SA:<IPIP> tun.1005 at 192.168.2.72
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_init2: calling
room for <IPIP>, SA:tun.1005 at 192.168.2.72
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_init2: Required
head,tailroom: 20,0
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_init2: calling
room for <ESP_AES_HMAC_SHA1>, SA:esp.adf6fadd at 192.168.2.72
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_init2: Required
head,tailroom: 24,24
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_init2: existing
head,tailroom: 2,28 before applying xforms with head,tailroom: 44,24 .
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_init2: mtu:1500
physmtu:1500 tothr:44 tottr:24 mtudiff:68 ippkttotlen:84
Feb 15 07:26:21 centos kernel: klips_info:ipsec_xmit_init2: dev ipsec0
mtu of 1500 decreased by 73 to 1427
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_init2: allocating
14 bytes for hardheader.
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_init2:
head,tailroom: 16,28 after hard_header stripped.
Feb 15 07:26:21 centos kernel: klips_debug:   IP: ihl:20 ver:4 tos:0
tlen:84 id:0 DF frag_off:0 ttl:64 proto:1 (ICMP) chk:9889 saddr:10.1.0.1
daddr:10.2.0.5 type:code=8:0
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_init2:
head,tailroom: 76,96 after allocation
Feb 15 07:26:21 centos kernel: klips_debug:   IP: ihl:20 ver:4 tos:0
tlen:84 id:0 DF frag_off:0 ttl:64 proto:1 (ICMP) chk:9889 saddr:10.1.0.1
daddr:10.2.0.5 type:code=8:0
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_encap_once:
calling output for <IPIP>, SA:tun.1005 at 192.168.2.72
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_encap_once:
pushing 20 bytes, putting 0, proto 4.
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_encap_once:
head,tailroom: 56,96 before xform.
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_encap_once: after
<IPIP>, SA:tun.1005 at 192.168.2.72:
Feb 15 07:26:21 centos kernel: klips_debug:   IP: ihl:20 ver:4 tos:0
tlen:104 id:11966 frag_off:0 ttl:64 proto:4 chk:50665 saddr:192.168.2.82
daddr:192.168.2.72
Feb 15 07:26:21 centos kernel: ipsec_sa_put: ipsec_sa e4eb8800
SA:tun.1005 at 192.168.2.72, ref:9 reference count (3--) decremented by
ipsec_xmit_cont:1096.
Feb 15 07:26:21 centos kernel: ipsec_sa_get: ipsec_sa e01ea000
SA:esp.adf6fadd at 192.168.2.72, ref:10 reference count (3++) incremented
by ipsec_xmit_cont:1101.
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_encap_once:
calling output for <ESP_AES_HMAC_SHA1>, SA:esp.adf6fadd at 192.168.2.72
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_encap_once:
pushing 24 bytes, putting 24, proto 50.
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_encap_once:
head,tailroom: 32,72 before xform.
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_alg_esp_encrypt:
entering with encalg=12, ixt_e=e8ee5720
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_alg_esp_encrypt:
calling cbc_encrypt encalg=12 ips_key_e=dfd18c00 idat=c169c44c ilen=96
iv=c169c43c, encrypt=1
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_alg_esp_encrypt:
returned ret=96
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_encap_once: after
<ESP_AES_HMAC_SHA1>, SA:esp.adf6fadd at 192.168.2.72:
Feb 15 07:26:21 centos kernel: klips_debug:   IP: ihl:20 ver:4 tos:0
tlen:152 id:11966 frag_off:0 ttl:64 proto:50 (ESP) chk:50571
saddr:192.168.2.82 daddr:192.168.2.72
Feb 15 07:26:21 centos kernel: ipsec_sa_put: ipsec_sa e01ea000
SA:esp.adf6fadd at 192.168.2.72, ref:10 reference count (4--) decremented
by ipsec_xmit_cont:1096.
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_findroute:
192.168.2.82:0->192.168.2.72:0 50
Feb 15 07:26:21 centos kernel: klips_debug:rj_match: * See if we match
exactly as a host destination
Feb 15 07:26:21 centos kernel: klips_debug:rj_match: ** try to match a
leaf, t=0pe16e35c0
Feb 15 07:26:21 centos kernel: klips_debug:rj_match: *** start searching
up the tree, t=0pe16e35c0
Feb 15 07:26:21 centos kernel: klips_debug:rj_match: **** t=0pe16e35d8
Feb 15 07:26:21 centos kernel: klips_debug:rj_match: **** t=0pe4508700
Feb 15 07:26:21 centos kernel: klips_debug:rj_match: *****
cp2=0pe7b8cca8 cp3=0pe5a23770
Feb 15 07:26:21 centos kernel: klips_debug:rj_match: ***** not found.
Feb 15 07:26:21 centos kernel:
klips_debug:ipsec_xmit_restore_hard_header: After recursive xforms --
head,tailroom: 32,72
Feb 15 07:26:21 centos kernel:
klips_debug:ipsec_xmit_restore_hard_header: With hard_header, final
head,tailroom: 18,72
Feb 15 07:26:21 centos kernel: klips_debug:ipsec_xmit_send:
ip_route_output failed with error code -22, dropped

Best regards,

S