Program invoked with PATH/start.sh spi1.sh

Starting UML PATH/start.sh
spawn PATH single
tracing thread pid = XXXXX
Linux version XXXX
On node 0 totalpages: 8192
zone(0): 0 pages.
zone(1): 8192 pages.
zone(2): 0 pages.
Kernel command line:
Calibrating delay loop... XXXX bogomips
Memory: 32244k available
Dentry-cache hash table entries: 4096 (order: 3, 32768 bytes)
Inode-cache hash table entries: 2048 (order: 2, 16384 bytes)
Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
Buffer-cache hash table entries: 1024 (order: 0, 4096 bytes)
Page-cache hash table entries: 8192 (order: 3, 32768 bytes)
POSIX conformance testing by UNIFIX
Linux NET4.0 for Linux 2.4
Based upon Swansea University Computer Society NET3.039
Initializing RT netlink socket
Starting kswapd
VFS: Diskquotas version dquot_6.4.0 initialized
devfs: VERSION Richard Gooch (rgooch@atnf.csiro.au)
devfs: boot_options Q
pty: 256 Unix98 ptys configured
block: slots and queues
RAMDISK driver initialized: 16 RAM disks of 4096K size 1024 blocksize
Netdevice 0 : daemon backend- ethernet address = 10:0:0:dc:bc:ff

Netdevice 1 : daemon backend- ethernet address = 10:0:0:64:64:23

SLIP: version 0.8.4-NET3.019-NEWTTY (dynamic channels, max=256).
loop: loaded (max 8 devices)
PPP generic driver version 2.4.1
Universal TUN/TAP device driver 1.4 (C)1999-2001 Maxim Krasnyansky
NET4: Linux TCP/IP 1.0 for NET4.0
IP Protocols: ICMP, UDP, TCP
IP: routing cache hash table of 512 buckets, 4Kbytes
TCP: Hash tables configured (established 2048 bind 2048)
IPv4 over IPv4 tunneling driver
GRE over IPv4 tunneling driver
klips_info:ipsec_init: KLIPS startup, FreeS/WAN IPSec version: XXXX
NET4: Unix domain sockets 1.0/SMP for Linux NET4.0.
Initializing stdio console driver
Initializing software serial port version 1
mconsole initialized on PATH
Mounted devfs on /dev
INIT: version 2.78 booting
Activating swap...
Calculating module dependancies
done.
Loading modules: LIST

Checking all file systems...
Parallelizing fsck version 1.18 (11-Nov-1999)
Setting kernel variables.
Mounting local filesystems...
/dev/ubd/1 on /usr/share type hostfs (ro,/usr/share)
/dev/shm on /tmp type tmpfs (rw)
/dev/shm on /var/run type tmpfs (rw)
devpts on /dev/pts type devpts (rw,mode=0622)
Enabling packet forwarding: done.
Configuring network interfaces: done.
Cleaning: /tmp /var/lock /var/run.
Initializing random number generator... done.
Recovering nvi editor sessions... done.
Give root password for maintenance
(or type Control-D for normal startup): 
east:~# TZ=GMT export TZ
east:~# ipsec spi --clear
east:~# ipsec eroute --clear
east:~# ipsec klipsdebug --set pfkey
klips_debug:pfkey_x_debug_process: set
klips_debug:pfkey_msg_interp: parsing message type 16 with msg_parser ABCDABCD
klips_debug:pfkey_x_msg_debug_parse: .
klips_debug:pfkey_release: sock=ABCDABCD sk=ABCDABCD
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_remove_socket: .
klips_debug:pfkey_remove_socket: succeeded.
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_release: succeeded.
east:~# ipsec klipsdebug --set verbose
klips_debug:pfkey_create: sock=ABCDABCD type:3 state:1 flags:0 protocol:2
klips_debug:pfkey_create: sock->fasync_list=00000000 sk->sleep=ABCDABCD
klips_debug:pfkey_insert_socket: sk=ABCDABCD
klips_debug:pfkey_list_insert_socket: socketp=ABCDABCD
klips_debug:pfkey_create: Socket sock=ABCDABCD sk=ABCDABCD initialised.
klips_debug:pfkey_sendmsg: .
klips_debug:pfkey_sendmsg: msg sent for parsing.
klips_debug:pfkey_msg_interp: parsing message ver=2, type=16, errno=0, satype=0(UNKNOWN), len=9, res=0, seq=1, pid=987.
klips_debug:pfkey_alloc_ipsec_sa: allocated tdb struct=ABDCABCD
klips_debug:pfkey_msg_interp: allocated extr->tdb=ABCDABCD
klips_debug:pfkey_msg_interp: processing ext 25 ABCDABCD with processor ABCDABCD
klips_debug:pfkey_x_debug_process: .
klips_debug:pfkey_x_debug_process: set
klips_debug:pfkey_msg_interp: parsing message type 16 with msg_parser ABCDABCD
klips_debug:pfkey_x_msg_debug_parse: .
klips_debug:pfkey_release: sock=ABCDABCD sk=ABCDABCD
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_remove_socket: .
klips_debug:pfkey_remove_socket: succeeded.
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_release: succeeded.
east:~# ipsec eroute --add --eraf inet --src 192.0.2.0/24 --dst 192.0.1.0/24 --s aid %trap
klips_debug:pfkey_create: sock=ABCDABCD type:3 state:1 flags:0 protocol:2
klips_debug:pfkey_create: sock->fasync_list=00000000 sk->sleep=ABCDABCD
klips_debug:pfkey_insert_socket: sk=ABCDABCD
klips_debug:pfkey_list_insert_socket: socketp=ABCDABCD
klips_debug:pfkey_create: Socket sock=ABCDABCD sk=ABCDABCD initialised.
klips_debug:pfkey_sendmsg: .
klips_debug:pfkey_sendmsg: msg sent for parsing.
klips_debug:pfkey_msg_interp: parsing message ver=2, type=14, errno=0, satype=11(INT), len=22, res=0, seq=1, pid=987.
klips_debug:pfkey_alloc_ipsec_sa: allocated tdb struct=ABDCABCD
klips_debug:pfkey_msg_interp: allocated extr->tdb=ABCDABCD
klips_debug:pfkey_msg_interp: satype 11 lookups to proto=61.
klips_debug:pfkey_msg_interp: processing ext 1 ABCDABCD with processor ABCDABCD
klips_debug:pfkey_sa_process: .
klips_debug:pfkey_msg_interp: processing ext 5 ABCDABCD with processor ABCDABCD
klips_debug:pfkey_address_process:
klips_debug:pfkey_address_process: found address family=2, AF_INET, 0.0.0.0.
klips_debug:pfkey_address_process: found src address.
klips_debug:pfkey_address_process: successful.
klips_debug:pfkey_msg_interp: processing ext 6 ABCDABCD with processor ABCDABCD
klips_debug:pfkey_address_process:
klips_debug:pfkey_address_process: found address family=2, AF_INET, 0.0.0.0.
klips_debug:pfkey_address_process: found dst address.
klips_debug:pfkey_address_process: tdb_said.dst set to 0.0.0.0.
klips_debug:pfkey_address_process: successful.
klips_debug:pfkey_msg_interp: processing ext 21 ABCDABCD with processor ABCDABCD
klips_debug:pfkey_address_process:
klips_debug:pfkey_address_process: found address family=2, AF_INET, 192.0.2.0.
klips_debug:pfkey_address_process: found src flow address.
klips_debug:pfkey_alloc_eroute: allocated eroute struct=ABCDABCD
klips_debug:pfkey_address_parse: extr->eroute set to 192.0.2.0/0->0.0.0.0/0
klips_debug:pfkey_address_process: successful.
klips_debug:pfkey_msg_interp: processing ext 22 ABCDABCD with processor ABCDABCD
klips_debug:pfkey_address_process:
klips_debug:pfkey_address_process: found address family=2, AF_INET, 192.0.1.0.
klips_debug:pfkey_address_process: found dst flow address.
klips_debug:pfkey_alloc_eroute: eroute struct already allocated
klips_debug:pfkey_address_parse: extr->eroute set to 192.0.2.0/0->192.0.1.0/0
klips_debug:pfkey_address_process: successful.
klips_debug:pfkey_msg_interp: processing ext 23 ABCDABCD with processor ABCDABCD
klips_debug:pfkey_address_process:
klips_debug:pfkey_address_process: found address family=2, AF_INET, 255.255.255.0.
klips_debug:pfkey_address_process: found src mask address.
klips_debug:pfkey_alloc_eroute: eroute struct already allocated
klips_debug:pfkey_address_parse: extr->eroute set to 192.0.2.0/24->192.0.1.0/0
klips_debug:pfkey_address_process: successful.
klips_debug:pfkey_msg_interp: processing ext 24 ABCDABCD with processor ABCDABCD
klips_debug:pfkey_address_process:
klips_debug:pfkey_address_process: found address family=2, AF_INET, 255.255.255.0.
klips_debug:pfkey_address_process: found dst mask address.
klips_debug:pfkey_alloc_eroute: eroute struct already allocated
klips_debug:pfkey_address_parse: extr->eroute set to 192.0.2.0/24->192.0.1.0/24
klips_debug:pfkey_address_process: successful.
klips_debug:pfkey_msg_interp: parsing message type 14 with msg_parser ABCDABCD
klips_debug:pfkey_x_addflow_parse: .
klips_debug:pfkey_x_addflow_parse: calling breakeroute and/or makeroute for 192.0.2.0/24->192.0.1.0/24
klips_debug:pfkey_x_addflow_parse: calling makeroute.
klips_debug:pfkey_x_addflow_parse: makeroute call successful.
klips_debug:pfkey_msg_hdr_build:
klips_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_sa_build: spi=00000104 replay=0 sa_state=0 auth=0 encrypt=0 flags=0
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_address_build: exttype=5 proto=0 prefixlen=0
klips_debug:pfkey_address_build: found address family AF_INET.
klips_debug:pfkey_address_build: found address=0.0.0.0:0.
klips_debug:pfkey_address_build: successful.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_address_build: exttype=6 proto=0 prefixlen=0
klips_debug:pfkey_address_build: found address family AF_INET.
klips_debug:pfkey_address_build: found address=0.0.0.0:0.
klips_debug:pfkey_address_build: successful.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_address_build: exttype=21 proto=0 prefixlen=0
klips_debug:pfkey_address_build: found address family AF_INET.
klips_debug:pfkey_address_build: found address=192.0.2.0:0.
klips_debug:pfkey_address_build: successful.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_address_build: exttype=22 proto=0 prefixlen=0
klips_debug:pfkey_address_build: found address family AF_INET.
klips_debug:pfkey_address_build: found address=192.0.1.0:0.
klips_debug:pfkey_address_build: successful.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_address_build: exttype=23 proto=0 prefixlen=0
klips_debug:pfkey_address_build: found address family AF_INET.
klips_debug:pfkey_address_build: found address=255.255.255.0:0.
klips_debug:pfkey_address_build: successful.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_address_build: exttype=24 proto=0 prefixlen=0
klips_debug:pfkey_address_build: found address family AF_INET.
klips_debug:pfkey_address_build: found address=255.255.255.0:0.
klips_debug:pfkey_address_build: successful.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_msg_build: pfkey_msg=ABCDABCD allocated 176 bytes, &(extensions[0])=ABCDABCD
klips_debug:pfkey_msg_build: copying 16 bytes from extensions[1]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: copying 24 bytes from extensions[5]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: copying 24 bytes from extensions[6]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: copying 24 bytes from extensions[21]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: copying 24 bytes from extensions[22]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: copying 24 bytes from extensions[23]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: copying 24 bytes from extensions[24]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: extensions permitted=01e00063, seen=01e00063, required=01e00043.
klips_debug:pfkey_upmsg: allocating 176 bytes...
klips_debug:pfkey_upmsg: ...allocated at ABCDABCD
klips_debug:pfkey_x_addflow_parse: sending up x_addflow reply message for satype=11(INT) (proto=61) to socket=ABCDABCD succeeded.
klips_debug:pfkey_x_addflow_parse: extr->tdb cleaned up and freed.
klips_debug:pfkey_release: sock=ABCDABCD sk=ABCDABCD
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_remove_socket: .
klips_debug:pfkey_remove_socket: succeeded.
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_destroy_socket: STUFF
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_list_remove_socket: removing sock=ABCDABCD
klips_debug:pfkey_release: succeeded.
east:~# ipsec tncfg --attach --virtual ipsec0 --physical eth1
east:~# ifconfig ipsec0 inet 192.1.2.23 netmask 0xffffff00 broadcast 192.1.2.255  up
east:~# arp -s 192.1.2.45 10:00:00:64:64:45
east:~# arp -s 192.1.2.254 10:00:00:64:64:45
east:~# ipsec look
east NOW
192.0.2.0/24       -> 192.0.1.0/24       => %trap (0)
ipsec0->eth1 mtu=16260(1500)->1500
Destination     Gateway         Genmask         Flags   MSS Window  irtt Iface
east:~# route add -host 192.0.1.1 gw 192.1.2.45 dev ipsec0
east:~# ipsec pf_key 
klips_debug:pfkey_create: sock=ABCDABCD type:3 state:1 flags:0 protocol:2
klips_debug:pfkey_create: sock->fasync_list=00000000 sk->sleep=ABCDABCD
klips_debug:pfkey_insert_socket: sk=ABCDABCD
klips_debug:pfkey_list_insert_socket: socketp=ABCDABCD
klips_debug:pfkey_create: Socket sock=ABCDABCD sk=ABCDABCD initialised.
klips_debug:pfkey_sendmsg: .
klips_debug:pfkey_sendmsg: msg sent for parsing.
klips_debug:pfkey_msg_interp: parsing message ver=2, type=7, errno=0, satype=2(AH), len=2, res=0, seq=1, pid=987.
klips_debug:pfkey_alloc_ipsec_sa: allocated tdb struct=ABDCABCD
klips_debug:pfkey_msg_interp: allocated extr->tdb=ABCDABCD
klips_debug:pfkey_msg_interp: parsing message type 7 with msg_parser ABCDABCD
klips_debug:pfkey_register_parse: .
klips_debug:pfkey_list_insert_socket: socketp=ABCDABCD
klips_debug:pfkey_register_parse: SATYPE=02(AH) successfully registered by KMd (pid=130).
klips_debug:pfkey_register_parse: pfkey_supported_list[2]=a0884480
klips_debug:pfkey_register_parse: checking supported=a0884480
klips_debug:pfkey_register_parse: adding auth alg.
klips_debug:pfkey_register_parse: checking supported=a0884460
klips_debug:pfkey_register_parse: adding auth alg.
klips_debug:pfkey_register_parse: adding auth=ABCDABCD
klips_debug:pfkey_register_parse: found satype=2(AH) exttype=14 id=3 ivlen=0 minbits=160 maxbits=160.
klips_debug:pfkey_register_parse: adding auth=ABCDABCD
klips_debug:pfkey_register_parse: found satype=2(AH) exttype=14 id=2 ivlen=0 minbits=128 maxbits=128.
klips_debug:pfkey_msg_hdr_build:
klips_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_msg_build: pfkey_msg=ABCDABCD allocated 40 bytes, &(extensions[0])=ABCDABCD
klips_debug:pfkey_msg_build: copying 24 bytes from extensions[14]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: extensions permitted=0000c001, seen=00004001, required=00000001.
klips_debug:pfkey_upmsg: allocating 40 bytes...
klips_debug:pfkey_upmsg: ...allocated at ABCDABCD
klips_debug:pfkey_register_parse: sending up register reply message for satype=2(AH) to socket=ABCDABCD succeeded.
klips_debug:pfkey_sendmsg: .
klips_debug:pfkey_sendmsg: msg sent for parsing.
klips_debug:pfkey_msg_interp: parsing message ver=2, type=7, errno=0, satype=3(ESP), len=2, res=0, seq=2, pid=987.
klips_debug:pfkey_alloc_ipsec_sa: allocated tdb struct=ABDCABCD
klips_debug:pfkey_msg_interp: allocated extr->tdb=ABCDABCD
klips_debug:pfkey_msg_interp: parsing message type 7 with msg_parser ABCDABCD
klips_debug:pfkey_register_parse: .
klips_debug:pfkey_list_insert_socket: socketp=ABCDABCD
klips_debug:pfkey_register_parse: SATYPE=03(ESP) successfully registered by KMd (pid=130).
klips_debug:pfkey_register_parse: pfkey_supported_list[3]=a08844e0
klips_debug:pfkey_register_parse: checking supported=a08844e0
klips_debug:pfkey_register_parse: adding encrypt alg.
klips_debug:pfkey_register_parse: checking supported=a08844c0
klips_debug:pfkey_register_parse: adding auth alg.
klips_debug:pfkey_register_parse: checking supported=a08844a0
klips_debug:pfkey_register_parse: adding auth alg.
klips_debug:pfkey_register_parse: adding encrypt=ABCDABCD
klips_debug:pfkey_register_parse: found satype=3(ESP) exttype=15 id=3 ivlen=128 minbits=168 maxbits=168.
klips_debug:pfkey_register_parse: adding auth=ABCDABCD
klips_debug:pfkey_register_parse: found satype=3(ESP) exttype=14 id=3 ivlen=0 minbits=160 maxbits=160.
klips_debug:pfkey_register_parse: adding auth=ABCDABCD
klips_debug:pfkey_register_parse: found satype=3(ESP) exttype=14 id=2 ivlen=0 minbits=128 maxbits=128.
klips_debug:pfkey_msg_hdr_build:
klips_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_msg_build: pfkey_msg=ABCDABCD allocated 56 bytes, &(extensions[0])=ABCDABCD
klips_debug:pfkey_msg_build: copying 24 bytes from extensions[14]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: copying 16 bytes from extensions[15]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: extensions permitted=0000c001, seen=0000c001, required=00000001.
klips_debug:pfkey_upmsg: allocating 56 bytes...
klips_debug:pfkey_upmsg: ...allocated at ABCDABCD
klips_debug:pfkey_register_parse: sending up register reply message for satype=3(ESP) to socket=ABCDABCD succeeded.
klips_debug:pfkey_sendmsg: .
klips_debug:pfkey_sendmsg: msg sent for parsing.
klips_debug:pfkey_msg_interp: parsing message ver=2, type=7, errno=0, satype=9(IPIP), len=2, res=0, seq=3, pid=987.
klips_debug:pfkey_alloc_ipsec_sa: allocated tdb struct=ABDCABCD
klips_debug:pfkey_msg_interp: allocated extr->tdb=ABCDABCD
klips_debug:pfkey_msg_interp: parsing message type 7 with msg_parser ABCDABCD
klips_debug:pfkey_register_parse: .
klips_debug:pfkey_list_insert_socket: socketp=ABCDABCD
klips_debug:pfkey_register_parse: SATYPE=09(IPIP) successfully registered by KMd (pid=130).
klips_debug:pfkey_register_parse: pfkey_supported_list[9]=a0884520
klips_debug:pfkey_register_parse: checking supported=a0884520
klips_debug:pfkey_register_parse: adding encrypt alg.
klips_debug:pfkey_register_parse: adding encrypt=ABCDABCD
klips_debug:pfkey_register_parse: found satype=9(IPIP) exttype=15 id=1 ivlen=0 minbits=32 maxbits=32.
klips_debug:pfkey_msg_hdr_build:
klips_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_msg_build: pfkey_msg=ABCDABCD allocated 32 bytes, &(extensions[0])=ABCDABCD
klips_debug:pfkey_msg_build: copying 16 bytes from extensions[15]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: extensions permitted=0000c001, seen=00008001, required=00000001.
klips_debug:pfkey_upmsg: allocating 32 bytes...
klips_debug:pfkey_upmsg: ...allocated at ABCDABCD
klips_debug:pfkey_register_parse: sending up register reply message for satype=9(IPIP) to socket=ABCDABCD succeeded.
klips_debug:pfkey_sendmsg: .
klips_debug:pfkey_sendmsg: msg sent for parsing.
klips_debug:pfkey_msg_interp: parsing message ver=2, type=7, errno=0, satype=10(COMP), len=2, res=0, seq=4, pid=987.
klips_debug:pfkey_alloc_ipsec_sa: allocated tdb struct=ABDCABCD
klips_debug:pfkey_msg_interp: allocated extr->tdb=ABCDABCD
klips_debug:pfkey_msg_interp: parsing message type 7 with msg_parser ABCDABCD
klips_debug:pfkey_register_parse: .
klips_debug:pfkey_list_insert_socket: socketp=ABCDABCD
klips_debug:pfkey_register_parse: SATYPE=10(COMP) successfully registered by KMd (pid=130).
klips_debug:pfkey_register_parse: pfkey_supported_list[10]=a0884500
klips_debug:pfkey_register_parse: checking supported=a0884500
klips_debug:pfkey_register_parse: adding encrypt alg.
klips_debug:pfkey_register_parse: adding encrypt=ABCDABCD
klips_debug:pfkey_register_parse: found satype=10(COMP) exttype=15 id=2 ivlen=0 minbits=1 maxbits=1.
klips_debug:pfkey_msg_hdr_build:
klips_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_msg_build: pfkey_msg=ABCDABCD allocated 32 bytes, &(extensions[0])=ABCDABCD
klips_debug:pfkey_msg_build: copying 16 bytes from extensions[15]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: extensions permitted=0000c001, seen=00008001, required=00000001.
klips_debug:pfkey_upmsg: allocating 32 bytes...
klips_debug:pfkey_upmsg: ...allocated at ABCDABCD
klips_debug:pfkey_register_parse: sending up register reply message for satype=10(COMP) to socket=ABCDABCD succeeded.
klips_debug:pfkey_recvmsg: sock=ABCDABCD sk=ABCDABCD msg=ABCDABCD size=256.

pfkey v2 msg. type=7 seq=1 len=5 pid=130 errno=0 satype=2
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2, type=7(register), errno=0, satype=2(AH), len=5, res=0, seq=1, pid=987.
pfkey_lib_debug:pfkey_msg_parse: remain=3, ext_type=14(supported-auth), ext_len=3.
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=0000c001, required=00000001.
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=14 remain=3.
pfkey_lib_debug:pfkey_msg_parse: About to parse extension 14 0xABCDABCD with parser pfkey_supported_parse.
pfkey_lib_debug:pfkey_msg_parse: Extension 14 parsed.
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=0000c001, seen=00004001, required=00000001.
pf_key: parseable PF_KEY message.
klips_debug:pfkey_recvmsg: sock=ABCDABCD sk=ABCDABCD msg=ABCDABCD size=256.

pfkey v2 msg. type=7 seq=2 len=7 pid=130 errno=0 satype=3
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2, type=7(register), errno=0, satype=3(ESP), len=7, res=0, seq=2, pid=987.
pfkey_lib_debug:pfkey_msg_parse: remain=5, ext_type=14(supported-auth), ext_len=3.
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=0000c001, required=00000001.
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=14 remain=5.
pfkey_lib_debug:pfkey_msg_parse: About to parse extension 14 0xABCDABCD with parser pfkey_supported_parse.
pfkey_lib_debug:pfkey_msg_parse: Extension 14 parsed.
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=15 remain=2.
pfkey_lib_debug:pfkey_msg_parse: About to parse extension 15 0xABCDABCD with parser pfkey_supported_parse.
pfkey_lib_debug:pfkey_msg_parse: Extension 15 parsed.
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=0000c001, seen=0000c001, required=00000001.
pf_key: parseable PF_KEY message.
klips_debug:pfkey_recvmsg: sock=ABCDABCD sk=ABCDABCD msg=ABCDABCD size=256.

pfkey v2 msg. type=7 seq=3 len=4 pid=130 errno=0 satype=9
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2, type=7(register), errno=0, satype=9(IPIP), len=4, res=0, seq=3, pid=987.
pfkey_lib_debug:pfkey_msg_parse: remain=2, ext_type=15(supported-cipher), ext_len=2.
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=0000c001, required=00000001.
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=15 remain=2.
pfkey_lib_debug:pfkey_msg_parse: About to parse extension 15 0xABCDABCD with parser pfkey_supported_parse.
pfkey_lib_debug:pfkey_msg_parse: Extension 15 parsed.
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=0000c001, seen=00008001, required=00000001.
pf_key: parseable PF_KEY message.
klips_debug:pfkey_recvmsg: sock=ABCDABCD sk=ABCDABCD msg=ABCDABCD size=256.

pfkey v2 msg. type=7 seq=4 len=4 pid=130 errno=0 satype=10
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2, type=7(register), errno=0, satype=10(COMP), len=4, res=0, seq=4, pid=987.
pfkey_lib_debug:pfkey_msg_parse: remain=2, ext_type=15(supported-cipher), ext_len=2.
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=0000c001, required=00000001.
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=15 remain=2.
pfkey_lib_debug:pfkey_msg_parse: About to parse extension 15 0xABCDABCD with parser pfkey_supported_parse.
pfkey_lib_debug:pfkey_msg_parse: Extension 15 parsed.
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=0000c001, seen=00008001, required=00000001.
pf_key: parseable PF_KEY message.
klips_debug:pfkey_recvmsg: sock=ABCDABCD sk=ABCDABCD msg=ABCDABCD size=256.
klips_debug:pfkey_msg_hdr_build:
klips_debug:pfkey_msg_hdr_build: on_entry &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_msg_hdr_build: on_exit &pfkey_ext=ABCDABCD pfkey_ext=ABCDABCD *pfkey_ext=ABCDABCD
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_address_build: exttype=5 proto=1 prefixlen=0
klips_debug:pfkey_address_build: found address family AF_INET.
klips_debug:pfkey_address_build: found address=192.0.2.1:0.
klips_debug:pfkey_address_build: successful.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_address_build: exttype=6 proto=1 prefixlen=0
klips_debug:pfkey_address_build: found address family AF_INET.
klips_debug:pfkey_address_build: found address=192.0.1.1:0.
klips_debug:pfkey_address_build: successful.
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_prop_build:
klips_debug:pfkey_safe_build: error=0
klips_debug:pfkey_safe_build:success.
klips_debug:pfkey_msg_build: pfkey_msg=ABCDABCD allocated 232 bytes, &(extensions[0])=ABCDABCD
klips_debug:pfkey_msg_build: copying 24 bytes from extensions[5]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: copying 24 bytes from extensions[6]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: copying 168 bytes from extensions[13]=ABCDABCD to=ABCDABCD
klips_debug:pfkey_msg_build: extensions permitted=00003ce1, seen=00002061, required=00002061.
klips_debug:pfkey_upmsg: allocating 232 bytes...
klips_debug:pfkey_upmsg: ...allocated at ABCDABCD
klips_debug:pfkey_acquire: sending up acquire message for satype=3(ESP) to socket=a267f720 succeeded.
klips_debug:ipsec_tunnel_start_xmit: calling breakeroute and makeroute for 192.0.2.1/32->192.0.1.1/32 HOLD eroute.
klips_debug:ipsec_tunnel_start_xmit: breakeroute should have failed.  first=00000000, last=00000000
klips_debug:ipsec_tunnel_start_xmit: HOLD makeroute call successful.

pfkey v2 msg. type=6 seq=1 len=29 pid=0 errno=0 satype=3
pfkey_lib_debug:pfkey_msg_parse: parsing message ver=2, type=6(acquire), errno=0, satype=3(ESP), len=29, res=0, seq=1, pid=987.
pfkey_lib_debug:pfkey_msg_parse: remain=27, ext_type=5(source-address), ext_len=3.
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=00003ce1, required=00002061.
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=5 remain=27.
pfkey_lib_debug:pfkey_msg_parse: About to parse extension 5 0xABCDABCD with parser pfkey_address_parse.
pfkey_lib_debug:pfkey_address_parse: found address family=2, AF_INET.
pfkey_lib_debug:pfkey_address_parse: found address=192.0.2.1.
pfkey_lib_debug:pfkey_msg_parse: Extension 5 parsed.
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=6 remain=24.
pfkey_lib_debug:pfkey_msg_parse: About to parse extension 6 0xABCDABCD with parser pfkey_address_parse.
pfkey_lib_debug:pfkey_address_parse: found address family=2, AF_INET.
pfkey_lib_debug:pfkey_address_parse: found address=192.0.1.1.
pfkey_lib_debug:pfkey_msg_parse: Extension 6 parsed.
pfkey_lib_debug:pfkey_msg_parse: parsing ext type=13 remain=21.
pfkey_lib_debug:pfkey_msg_parse: About to parse extension 13 0xABCDABCD with parser pfkey_prop_parse.
pfkey_lib_debug:pfkey_msg_parse: Extension 13 parsed.
pfkey_lib_debug:pfkey_msg_parse: extensions permitted=00003ce1, seen=00002061, required=00002061.
pf_key: parseable PF_KEY message.
klips_debug:pfkey_recvmsg: sock=ABCDABCD sk=ABCDABCD msg=ABCDABCD size=256.
nbd: module cleaned up.