[Openswan dev] 2.6.34rc3 broke 6in4 ?

Tue May 24 11:29:58 EDT 2011

Well, it seems my klips ipv6 from behind nat-t broke...

This is was klipsdebug told me

klips_info:ipsec_init: KLIPS startup, Openswan KLIPS IPsec stack version: 2.6.34rc3-2-g49e9ea1
NET: Registered protocol family 15
registered KLIPS /proc/sys/net
klips_info:ipsec_alg_init: KLIPS alg v=0.8.1-0 (EALG_MAX=255, AALG_MAX=251)
klips_info:ipsec_alg_init: calling ipsec_alg_static_init()
ipsec_aes_init(alg_type=15 alg_id=12 name=aes): ret=0
ipsec_aes_init(alg_type=14 alg_id=9 name=aes_mac): ret=0
ipsec_3des_init(alg_type=15 alg_id=3 name=3des): ret=0
KLIPS cryptoapi interface: alg_type=15 alg_id=12 name=cbc(aes) keyminbits=128 keymaxbits=256, found(0)
KLIPS cryptoapi interface: alg_type=15 alg_id=253 name=cbc(twofish) keyminbits=128 keymaxbits=256, found(0)
KLIPS cryptoapi interface: alg_type=15 alg_id=252 name=cbc(serpent) keyminbits=128 keymaxbits=256, found(0)
KLIPS cryptoapi interface: alg_type=15 alg_id=6 name=cbc(cast5) keyminbits=128 keymaxbits=128, found(0)
KLIPS cryptoapi interface: alg_type=15 alg_id=7 name=cbc(blowfish) keyminbits=96 keymaxbits=448, found(0)
KLIPS cryptoapi interface: alg_type=15 alg_id=3 name=cbc(des3_ede) keyminbits=192 keymaxbits=192, found(0)

device ipsec0 entered promiscuous mode
device ipsec0 left promiscuous mode
device eth0 entered promiscuous mode
device eth0 left promiscuous mode
klips_debug:pfkey_x_debug_process: set
klips_debug:pfkey_msg_interp: parsing message type 16(x-debug) with msg_parser 0pffffffffa0596e38.
klips_debug:pfkey_x_msg_debug_parse: .
ipsec_sa_put: ipsec_sa ffff880015643400 SA:unk0:0@<invalid>, ref:0 reference count (1--) decremented by pfkey_msg_interp:3145.
ipsec_sa_put: freeing ffff880015643400
klips_debug:ipsec_sa_wipe: removing SA=unk0:0@<invalid>(0pffff880015643400), SAref=0, table=0(0pffff8800141a4000), entry=0 from the refTable.
klips_debug:pfkey_release: sock=0pffff8800080a84c0 sk=0pffff880015643000
klips_debug:pfkey_destroy_socket: 0pffff880015643000
klips_debug:pfkey_remove_socket: 0pffff880015643000
klips_debug:pfkey_destroy_socket: pfkey_remove_socket called, sk=0pffff880015643000
klips_debug:pfkey_destroy_socket: sk(0pffff880015643000)->(&0pffff880015643070)receive_queue.{next=0pffff880015643070,prev=0pffff880015643070}.
klips_debug:pfkey_destroy_socket: destroyed.
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_list_remove_socket: removing sock=0pffff8800080a84c0
klips_debug:pfkey_release: succeeded.

ipsec_tunnel_start_xmit: STARTING
klips_debug:ipsec_xmit_strip_hard_header: >>> skb->len=118 hard_header_len:14 52:54:00:73:49:04:52:54:00:73:49:04:86:dd 
klips_debug:   IPV6: prio:0 ver:6 flow:000000 pllen:64 hopl:64 nexthdr:58 (ICMP) saddr:2001:888:2003:1 daddr:2a00:1450:8005:
klips_debug:ipsec_xmit_strip_hard_header: Original head,tailroom: 10,0
klips_debug:ipsec_findroute: [2001:888:2003:1]:0->[2a00:1450:8005:]:0 58
klips_debug:rj_match: * See if we match exactly as a host destination
klips_debug:rj_match: ** try to match a leaf, t=0pffff88001d7fc600
klips_debug:ipsec_xmit_SAlookup: checking for local udp/500 IKE, udp/4500 NAT-T, ESP or AH packets saddr=2001:888:2003:1006::1, er=0pffff88001d7fc600, daddr=2a00:1450:8005::63, er_dst=82.94.220.195, proto=58 sport=0 dport=0
ipsec_sa_getbyid: linked entry in ipsec_sa table for hash=30 of SA:tun.1003 at 82.94.220.195 requested.
ipsec_sa_get: ipsec_sa ffff880011127c00 SA:tun.1003 at 82.94.220.195, ref:5 reference count (3++) incremented by ipsec_sa_getbyid:563.
klips_debug:ipsec_xmit_init2: found ipsec_sa -- SA:<IPIP> tun.1003 at 82.94.220.195
klips_debug:ipsec_xmit_init2: calling room for <IPIP>, SA:tun.1003 at 82.94.220.195
klips_debug:ipsec_xmit_init2: Required head,tailroom: 20,0
klips_debug:ipsec_xmit_init2: calling room for <ESP_AES_HMAC_SHA1>, SA:esp.cf0d1c46 at 82.94.220.195
klips_debug:ipsec_xmit_init2: Required head,tailroom: 24,32
klips_debug:ipsec_xmit_init2: existing head,tailroom: 10,0 before applying xforms with head,tailroom: 44,32 .
klips_debug:ipsec_xmit_init2: mtu:1500 physmtu:1500 tothr:44 tottr:32 mtudiff:76 ippkttotlen:104
klips_info:ipsec_xmit_init2: dev ipsec0 mtu of 1500 decreased by 81 to 1419
klips_debug:ipsec_xmit_init2: allocating 14 bytes for hardheader.
klips_debug:ipsec_xmit_init2: head,tailroom: 24,0 after hard_header stripped.
klips_debug:   IPV6: prio:0 ver:6 flow:000000 pllen:64 hopl:64 nexthdr:58 (ICMP) saddr:2001:888:2003:1 daddr:2a00:1450:8005:
klips_debug:ipsec_xmit_init2: head,tailroom: 76,76 after allocation
klips_debug:   IPV6: prio:0 ver:6 flow:000000 pllen:64 hopl:64 nexthdr:58 (ICMP) saddr:2001:888:2003:1 daddr:2a00:1450:8005:
klips_debug:ipsec_xmit_encap_once: calling output for <IPIP>, SA:tun.1003 at 82.94.220.195
klips_debug:ipsec_xmit_encap_once: pushing 20 bytes, putting 0, proto 4.
klips_debug:ipsec_xmit_encap_once: head,tailroom: 56,76 before xform.
klips_debug:ipsec_xmit_encap_once: after <IPIP>, SA:tun.1003 at 82.94.220.195:
klips_debug:   IP: ihl:20 ver:4 tos:0 tlen:124 id:52324 frag_off:0 ttl:64 proto:41 chk:17348 saddr:192.168.122.102 daddr:82.94.220.195
ipsec_sa_put: ipsec_sa ffff880011127c00 SA:tun.1003 at 82.94.220.195, ref:5 reference count (4--) decremented by ipsec_xmit_cont:1304.
ipsec_sa_get: ipsec_sa ffff88001d51c000 SA:esp.cf0d1c46 at 82.94.220.195, ref:6 reference count (3++) incremented by ipsec_xmit_cont:1309.
klips_debug:ipsec_xmit_encap_once: calling output for <ESP_AES_HMAC_SHA1>, SA:esp.cf0d1c46 at 82.94.220.195
klips_debug:ipsec_xmit_encap_once: pushing 24 bytes, putting 20, proto 50.
klips_debug:ipsec_xmit_encap_once: head,tailroom: 32,56 before xform.
klips_debug:ipsec_alg_esp_encrypt: entering with encalg=12, ixt_e=ffffffffa05d43d8
klips_debug:ipsec_alg_esp_encrypt: calling cbc_encrypt encalg=12 ips_key_e=ffff8800111510c0 idat=ffff88001564384c ilen=112 iv=ffff88001564383c, encrypt=1
klips_debug:ipsec_alg_esp_encrypt: returned ret=112
klips_debug:ipsec_xmit_encap_once: after <ESP_AES_HMAC_SHA1>, SA:esp.cf0d1c46 at 82.94.220.195:
klips_debug:   IP: ihl:20 ver:4 tos:0 tlen:168 id:52324 frag_off:0 ttl:64 proto:50 (ESP) chk:17348 saddr:192.168.122.102 daddr:82.94.220.195
ipsec_sa_put: ipsec_sa ffff88001d51c000 SA:esp.cf0d1c46 at 82.94.220.195, ref:6 reference count (4--) decremented by ipsec_xmit_cont:1304.
klips_debug:ipsec_findroute: 192.168.122.102:0->82.94.220.195:0 50
klips_debug:rj_match: * See if we match exactly as a host destination
klips_debug:rj_match: ** try to match a leaf, t=0pffff88001d7fc600
klips_debug:rj_match: *** start searching up the tree, t=0pffff88001d7fc600
klips_debug:rj_match: **** t=0pffff88001d7fc630
klips_debug:rj_match: **** t=0pffff88001db0c138
klips_debug:rj_match: ***** cp2=0pffff8800110de6d8 cp3=0pffff8800146c48a0
klips_debug:rj_match: ***** not found.
klips_debug:ipsec_tunnel_start_xmit: encapsuling packet into UDP (NAT-Traversal) (2 8)
klips_debug:ipsec_xmit_restore_hard_header: After recursive xforms -- head,tailroom: 32,48
klips_debug:ipsec_xmit_restore_hard_header: With hard_header, final head,tailroom: 18,48
klips_debug:ipsec_xmit_send: ip_route_output failed with no dst, dropped

I guess I should verify this is still broken before the encap changes David made....

Paul