Starting UML /mara6/sandboxes/UMLPOOL/klipsng/road/start.sh spawn /mara6/sandboxes/UMLPOOL/klipsng/road/start.sh single Checking PROT_EXEC mmap in /tmp...OK Checking for the skas3 patch in the host: - /proc/mm...not found - PTRACE_FAULTINFO...not found - PTRACE_LDT...not found UML running in SKAS0 mode Checking that ptrace can change system call numbers...OK Checking syscall emulation patch for ptrace...missing Linux version 2.6.15-rc3-gref: ref (mcr@marajade.sandelman.ca) (gcc version 3.3.5 (Debian 1:3.3.5-13)) #27 Tue Feb 28 15:32:36 EST 2006 Built 1 zonelists Kernel command line: initrd=/mara6/sandboxes/UMLPOOL/klipsng/initrd.uml umlroot=/mara6/sandboxes/UMLPOOL/klipsng/road/root root=/dev/root rw ssl=pty eth0=daemon,10:00:00:ab:cd:02,unix,/tmp/umlXfE180.d/northpublic/ctl,/tmp/umlXfE180.d/northpublic/data single PID hash table entries: 256 (order: 8, 4096 bytes) Dentry cache hash table entries: 8192 (order: 3, 32768 bytes) Inode-cache hash table entries: 4096 (order: 2, 16384 bytes) Memory: 26928k available Mount-cache hash table entries: 512 Checking for host processor cmov support...Yes Checking for host processor xmm support...No Checking that host ptys support output SIGIO...Yes Checking that host ptys support SIGIO on close...No, enabling workaround Checking for /dev/anon on the host...Not available (open failed with errno 2) checking if image is initramfs...it isn't (bad gzip magic numbers); looks like an initrd Freeing initrd memory: 1228k freed Using 2.6 host AIO NET: Registered protocol family 16 daemon_setup : Ignoring data socket specification Netdevice 0 (10:00:00:ab:cd:02) : daemon backend (uml_switch version 3) - unix:/tmp/umlXfE180.d/northpublic/ctl mconsole (version 2) initialized on /home/mcr/.uml/road/mconsole VFS: Disk quotas dquot_6.5.1 Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) Initializing Cryptographic API io scheduler noop registered io scheduler anticipatory registered io scheduler deadline registered io scheduler cfq registered RAMDISK driver initialized: 16 RAM disks of 4096K size 1024 blocksize loop: loaded (max 8 devices) nbd: registered device at major 43 PPP generic driver version 2.4.2 PPP Deflate Compression module registered PPP BSD Compression module registered PPP MPPE Compression module registered NET: Registered protocol family 24 SLIP: version 0.8.4-NET3.019-NEWTTY (dynamic channels, max=256). tun: Universal TUN/TAP device driver, 1.6 tun: (C) 1999-2004 Max Krasnyansky NET: Registered protocol family 2 IP route cache hash table entries: 512 (order: -1, 2048 bytes) TCP established hash table entries: 2048 (order: 1, 8192 bytes) TCP bind hash table entries: 2048 (order: 1, 8192 bytes) TCP: Hash tables configured (established 2048 bind 2048) TCP reno registered klips_info:ipsec_init: KLIPS startup, Libreswan KLIPS IPsec stack version: 2.git NET: Registered protocol family 15 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 IPv4 over IPv4 tunneling driver GRE over IPv4 tunneling driver ip_conntrack version 2.4 (211 buckets, 1688 max) - 212 bytes per conntrack ip_tables: (C) 2000-2002 Netfilter core team ipt_recent v0.3.1: Stephen Frost . http://snowman.net/projects/ipt_recent/ arp_tables: (C) 2002 David S. Miller TCP bic registered TCP westwood registered TCP highspeed registered TCP hybla registered TCP htcp registered TCP vegas registered TCP scalable registered NET: Registered protocol family 1 NET: Registered protocol family 17 Initialized stdio console driver Console initialized on /dev/tty0 Initializing software serial port version 1 Failed to open 'root_fs', errno = 2 RAMDISK: cramfs filesystem found at block 0 RAMDISK: Loading 1228KiB [1 disk] into ram disk... |/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|done. VFS: Mounted root (cramfs filesystem) readonly. MOUNTING /mara6/sandboxes/UMLPOOL/klipsng/road/root for UML testing root. Mounting a tmpfs over /dev...done. Creating initial device nodes...done. udev requires hotplug support, not started. crw-r--r-- 1 root root 5, 1 Feb 28 20:56 /dev/console line_ioctl: tty0: ioctl KDSIGACCEPT called INIT: version 2.78 booting /dev/root on / type hostfs (rw) proc on /proc type proc (rw) devpts on /dev/pts type devpts (rw,gid=5,mode=620) /dev/shm on /tmp type tmpfs (rw) /dev/shm on /var/run type tmpfs (rw) none on /usr/share type hostfs (ro) none on /testing type hostfs (ro,/mara6/libreswan/klipsng.git/testing) none on /usr/src type hostfs (ro,/mara6/libreswan/klipsng.git) none on /usr/obj type hostfs (ro,/mara6/libreswan/klipsng.git/OBJ.linux.i386) none on /usr/local type hostfs (rw,/mara6/sandboxes/UMLPOOL/klipsng/road/root/usr/local) none on /var/tmp type hostfs (rw,/mara6/sandboxes/UMLPOOL/klipsng/road/root/var/tmp) /testing/pluto/l2tp-01 on /etc/ppp type none (rw,bind) none on /proc type proc (rw) crw-r--r-- 1 root root 5, 1 Feb 28 20:56 /dev/console mount: proc already mounted Activating swap... Checking all file systems... Parallelizing fsck version 1.18 (11-Nov-1999) Setting kernel variables. Mounting local filesystems... mount: devpts already mounted on /dev/pts /dev/shm on /tmp type tmpfs (rw) /dev/shm on /var/run type tmpfs (rw) none on /usr/share type hostfs (ro) none on /testing type hostfs (ro,/mara6/libreswan/klipsng.git/testing) none on /usr/src type hostfs (ro,/mara6/libreswan/klipsng.git) none on /usr/obj type hostfs (ro,/mara6/libreswan/klipsng.git/OBJ.linux.i386) none on /usr/local type hostfs (rw,/mara6/sandboxes/UMLPOOL/klipsng/road/root/usr/local) none on /var/tmp type hostfs (rw,/mara6/sandboxes/UMLPOOL/klipsng/road/root/var/tmp) 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): road:~# echo Starting loading module Starting loading module road:~# exec bash --noediting road:~# ulimit -c unlimited road:~# echo Finished loading module Finished loading module road:~# klogd -c 4 -x -f /tmp/klog.log road:~# : ==== start ==== road:~# TESTNAME=l2tp-03 road:~# source /testing/pluto/bin/roadlocal.sh road:~# if [ -f /var/run/l2tpd.pid ]; then kill `cat /var/run/l2tpd.pid`; fi road:~# iptables -F INPUT road:~# iptables -F OUTPUT road:~# ipsec setup stop ipsec_setup: Stopping Libreswan IPsec... ipsec_setup: stop ordered, but IPsec does not appear to be running! ipsec_setup: doing cleanup anyway... road:~# iptables -A INPUT -i eth1 -s 192.1.2.23 -p udp --sport 1701 -j REJECT road:~# iptables -A OUTPUT -o eth1 -d 192.1.2.23 -p udp --dport 1701 -j REJECT road:~# ipsec setup restart ipsec_setup: Stopping Libreswan IPsec... ipsec_setup: stop ordered, but IPsec does not appear to be running! ipsec_setup: doing cleanup anyway... ipsec_setup: Starting Libreswan IPsec U2.klipsng-g416ec5f3-dirty/K2.git... road:~# ipsec auto --add road--east-l2tp road:~# /testing/pluto/bin/wait-until-pluto-started road:~# ipsec whack --debug-control --debug-controlmore --debug-natt road:~# if [ ! -f /etc/ppp/chap-secrets ]; then mount --bind /testing/pluto/l2tp-01 /etc/ppp; fi road:~# (cd /tmp && l2tpd -c /testing/pluto/l2tp-03/road.l2tpd.conf -D 2>/tmp/l2tpd.log ) & [1] 365 road:~# ipsec auto --route road--east-l2tp road:~# echo done done road:~# : === NETJIG start of NORTH ../l2tp-01/northrun.sh road:~# : === NETJIG start of ROAD ../l2tp-03/roadrun.sh road:~# ipsec auto --replace road--east-l2tp road:~# ipsec auto --up road--east-l2tp 104 "road--east-l2tp" #1: STATE_MAIN_I1: initiate 003 "road--east-l2tp" #1: received Vendor ID payload [Libreswan (this version) 2.klipsng-g416ec5f3-dirty X.509-1.5.4 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR] 003 "road--east-l2tp" #1: received Vendor ID payload [Dead Peer Detection] 003 "road--east-l2tp" #1: received Vendor ID payload [RFC 3947] method set to=109 106 "road--east-l2tp" #1: STATE_MAIN_I2: sent MI2, expecting MR2 003 "road--east-l2tp" #1: NAT-Traversal: Result using RFC 3947 (NAT-Traversal): both are NATed 108 "road--east-l2tp" #1: STATE_MAIN_I3: sent MI3, expecting MR3 004 "road--east-l2tp" #1: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_RSA_SIG cipher=oakley_3des_cbc_192 prf=oakley_md5 group=modp1536} 117 "road--east-l2tp" #2: STATE_QUICK_I1: initiate 004 "road--east-l2tp" #2: STATE_QUICK_I2: sent QI2, IPsec SA established transport mode {ESP=>0xae595bac <0x76d53c54 xfrm=3DES_0-HMAC_MD5 ref=2 refhim=1 NATD=192.1.2.23:4500 DPD=none} road:~# echo "c server" >/var/run/l2tp-control road:~# ipsec look road Tue Feb 28 20:57:28 GMT 2006 192.1.3.209/32:1701 -> 192.1.2.23/32:1701 => esp0xae595bac@192.1.2.23:17 (0) ipsec0->eth0 mtu=16260(1500)->1500 esp0x76d53c54@192.1.3.209 ESP_3DES_HMAC_MD5: dir=in src=192.1.2.23 iv_bits=64bits iv=0x0415cf7b2a768be0 ooowin=64 alen=128 aklen=128 eklen=192 life(c,s,h)=addtime(0,0,0) natencap=nonesp natsport=4500 natdport=4500 refcount=2 ref=2 refhim=1 esp0xae595bac@192.1.2.23 ESP_3DES_HMAC_MD5: dir=out src=192.1.3.209 iv_bits=64bits iv=0xfe7aa27b3937c852 ooowin=64 alen=128 aklen=128 eklen=192 life(c,s,h)=addtime(0,0,0) natencap=nonesp natsport=4500 natdport=4500 refcount=2 ref=1 refhim=0 IPSEC TABLE iptables: Table does not exist (do you need to insmod?) ROUTING TABLE 192.1.2.23 dev ipsec0 scope link 192.1.3.0/24 dev eth0 proto kernel scope link src 192.1.3.209 192.1.3.0/24 dev ipsec0 proto kernel scope link src 192.1.3.209 default via 192.1.3.254 dev eth0 road:~# sleep 5 road:~# telnet 192.0.2.254 2 | wc -l Connection closed by foreign host. 834 road:~# ifconfig ppp0 | grep 'inet addr' inet addr:192.0.2.129 P-t-P:192.0.2.254 Mask:255.255.255.255 road:~# echo done done road:~# road:~# : ==== cut ==== road:~# ipsec auto --status 000 interface ipsec0/eth0 192.1.3.209 000 interface ipsec0/eth0 192.1.3.209 000 %myid = (none) 000 debug control+controlmore+nattraversal 000 000 algorithm ESP encrypt: id=3, name=ESP_3DES, ivlen=64, keysizemin=192, keysizemax=192 000 algorithm ESP encrypt: id=12, name=ESP_AES, ivlen=128, keysizemin=128, keysizemax=256 000 algorithm ESP auth attr: id=1, name=AUTH_ALGORITHM_HMAC_MD5, keysizemin=128, keysizemax=128 000 algorithm ESP auth attr: id=2, name=AUTH_ALGORITHM_HMAC_SHA1, keysizemin=160, keysizemax=160 000 algorithm ESP auth attr: id=9, name=AUTH_ALGORITHM_AES_CBC, keysizemin=128, keysizemax=128 000 000 algorithm IKE encrypt: id=1, name=OAKLEY_DES_CBC, blocksize=8, keydeflen=64 000 algorithm IKE encrypt: id=3, name=OAKLEY_BLOWFISH_CBC, blocksize=8, keydeflen=128 000 algorithm IKE encrypt: id=5, name=OAKLEY_3DES_CBC, blocksize=8, keydeflen=192 000 algorithm IKE encrypt: id=7, name=OAKLEY_AES_CBC, blocksize=16, keydeflen=128 000 algorithm IKE encrypt: id=65004, name=OAKLEY_SERPENT_CBC, blocksize=16, keydeflen=128 000 algorithm IKE encrypt: id=65005, name=OAKLEY_TWOFISH_CBC, blocksize=16, keydeflen=128 000 algorithm IKE encrypt: id=65289, name=OAKLEY_TWOFISH_CBC_SSH, blocksize=16, keydeflen=128 000 algorithm IKE hash: id=1, name=OAKLEY_MD5, hashsize=16 000 algorithm IKE hash: id=2, name=OAKLEY_SHA1, hashsize=20 000 algorithm IKE hash: id=4, name=OAKLEY_SHA2_256, hashsize=32 000 algorithm IKE hash: id=6, name=OAKLEY_SHA2_512, hashsize=64 000 algorithm IKE dh group: id=1, name=OAKLEY_GROUP_MODP768, bits=768 000 algorithm IKE dh group: id=2, name=OAKLEY_GROUP_MODP1024, bits=1024 000 algorithm IKE dh group: id=5, name=OAKLEY_GROUP_MODP1536, bits=1536 000 algorithm IKE dh group: id=14, name=OAKLEY_GROUP_MODP2048, bits=2048 000 algorithm IKE dh group: id=15, name=OAKLEY_GROUP_MODP3072, bits=3072 000 algorithm IKE dh group: id=16, name=OAKLEY_GROUP_MODP4096, bits=4096 000 algorithm IKE dh group: id=17, name=OAKLEY_GROUP_MODP6144, bits=6144 000 algorithm IKE dh group: id=18, name=OAKLEY_GROUP_MODP8192, bits=8192 000 000 stats db_ops: {curr_cnt, total_cnt, maxsz} :context={0,2,36} trans={0,2,108} attrs={0,2,72} 000 000 "road--east-l2tp": 192.1.3.209[@road]:17/1701...192.1.2.254---192.1.2.23[@east]:17/1701; erouted; eroute owner: #2 000 "road--east-l2tp": srcip=unset; dstip=unset; srcup=ipsec _updown; dstup=ipsec _updown; 000 "road--east-l2tp": ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0 000 "road--east-l2tp": policy: RSASIG+ENCRYPT+PFS+UP; prio: 32,32; interface: eth0; 000 "road--east-l2tp": newest ISAKMP SA: #1; newest IPsec SA: #2; 000 "road--east-l2tp": IKE algorithm newest: 3DES_CBC_192-MD5-MODP1536 000 "road--east-l2tp": ESP algorithms wanted: 3_000-1, flags=-strict 000 "road--east-l2tp": ESP algorithms loaded: 3_000-1, flags=-strict 000 "road--east-l2tp": ESP algorithm newest: 3DES_0-HMAC_MD5; pfsgroup= 000 000 #2: "road--east-l2tp":4500 STATE_QUICK_I2 (sent QI2, IPsec SA established); EVENT_SA_REPLACE in 28175s; newest IPSEC; eroute owner 000 #2: "road--east-l2tp" esp.ae595bac@192.1.2.23 esp.76d53c54@192.1.3.209 000 #1: "road--east-l2tp":4500 STATE_MAIN_I4 (ISAKMP SA established); EVENT_SA_REPLACE in 2922s; newest ISAKMP; lastdpd=-1s(seq in:0 out:0) 000 road:~# cat /tmp/pluto.log Plutorun started on Tue Feb 28 20:57:11 GMT 2006 Starting Pluto (Libreswan Version 2.klipsng-g416ec5f3-dirty X.509-1.5.4 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR; Vendor ID OEfKI^HvvF~Y) WARNING: 1DES is enabled Setting NAT-Traversal port-4500 floating to on port floating activation criteria nat_t=1/port_float=1 including NAT-Traversal patch (Version 0.6c) WARNING: open of /dev/hw_random failed: No such file or directory using /dev/urandom as source of random entropy ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0) ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC: Ok (ret=0) ike_alg_register_enc(): Activating OAKLEY_SERPENT_CBC: Ok (ret=0) ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0) ike_alg_register_enc(): Activating OAKLEY_BLOWFISH_CBC: Ok (ret=0) ike_alg_register_hash(): Activating OAKLEY_SHA2_512: Ok (ret=0) ike_alg_register_hash(): Activating OAKLEY_SHA2_256: Ok (ret=0) starting up 1 cryptographic helpers WARNING: open of /dev/hw_random failed: No such file or directory using /dev/urandom as source of random entropy started helper pid=305 (fd:6) Using KLIPS IPsec interface code on 2.6.15-rc3-gref: ref Changing to directory '/tmp/l2tp-03/ipsec.d/cacerts' Could not change to directory '/tmp/l2tp-03/ipsec.d/aacerts' Could not change to directory '/tmp/l2tp-03/ipsec.d/ocspcerts' Changing to directory '/tmp/l2tp-03/ipsec.d/crls' Warning: empty directory added connection description "road--east-l2tp" listening for IKE messages adding interface ipsec0/eth0 192.1.3.209:500 adding interface ipsec0/eth0 192.1.3.209:4500 loading secrets from "/tmp/l2tp-03/ipsec.secrets" | base debugging = control+controlmore+nattraversal | next event EVENT_SHUNT_SCAN in 118 seconds | | *received whack message | processing connection road--east-l2tp | route owner of "road--east-l2tp" unrouted: NULL; eroute owner: NULL | could_route called for road--east-l2tp (kind=CK_PERMANENT) | route owner of "road--east-l2tp" unrouted: NULL; eroute owner: NULL | route_and_eroute with c: road--east-l2tp (next: none) ero:null esr:{(nil)} ro:null rosr:{(nil)} and state: 0 | route_and_eroute: firewall_notified: true | command executing prepare-host | trusted_ca called with a=(empty) b=(empty) | executing prepare-host: 2>&1 PLUTO_VERB='prepare-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='road--east-l2tp' PLUTO_INTERFACE='ipsec0' PLUTO_ME='192.1.3.209' PLUTO_MY_ID='@road' PLUTO_MY_CLIENT='192.1.3.209/32' PLUTO_MY_CLIENT_NET='192.1.3.209' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' PLUTO_MY_PROTOCOL='17' PLUTO_PEER='192.1.2.23' PLUTO_PEER_ID='@east' PLUTO_PEER_CLIENT='192.1.2.23/32' PLUTO_PEER_CLIENT_NET='192.1.2.23' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' PLUTO_PEER_PROTOCOL='17' PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+PFS' ipsec _updown | command executing route-host | trusted_ca called with a=(empty) b=(empty) | executing route-host: 2>&1 PLUTO_VERB='route-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='road--east-l2tp' PLUTO_INTERFACE='ipsec0' PLUTO_ME='192.1.3.209' PLUTO_MY_ID='@road' PLUTO_MY_CLIENT='192.1.3.209/32' PLUTO_MY_CLIENT_NET='192.1.3.209' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' PLUTO_MY_PROTOCOL='17' PLUTO_PEER='192.1.2.23' PLUTO_PEER_ID='@east' PLUTO_PEER_CLIENT='192.1.2.23/32' PLUTO_PEER_CLIENT_NET='192.1.2.23' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' PLUTO_PEER_PROTOCOL='17' PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+PFS' ipsec _updown | next event EVENT_SHUNT_SCAN in 118 seconds | | *received whack message listening for IKE messages | found eth0 with address 192.1.3.209 | found lo with address 127.0.0.1 | found ipsec0 with address 192.1.3.209 | IP interface lo 127.0.0.1 has no matching ipsec* interface -- ignored | could not open /proc/net/if_inet6 forgetting secrets loading secrets from "/tmp/l2tp-03/ipsec.secrets" | loaded private key for keyid: PPK_RSA:AQNxbOBmD | next event EVENT_SHUNT_SCAN in 118 seconds | | *received whack message | unreference key: 0x8126070 @road cnt 1-- | next event EVENT_SHUNT_SCAN in 105 seconds | | *received whack message | unreference key: 0x81262e8 @east cnt 1-- | next event EVENT_SHUNT_SCAN in 105 seconds | | *received whack message | processing connection road--east-l2tp "road--east-l2tp": deleting connection | route owner of "road--east-l2tp" unrouted: NULL | command executing unroute-host | trusted_ca called with a=(empty) b=(empty) | executing unroute-host: 2>&1 PLUTO_VERB='unroute-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='road--east-l2tp' PLUTO_INTERFACE='ipsec0' PLUTO_ME='192.1.3.209' PLUTO_MY_ID='@road' PLUTO_MY_CLIENT='192.1.3.209/32' PLUTO_MY_CLIENT_NET='192.1.3.209' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' PLUTO_MY_PROTOCOL='17' PLUTO_PEER='192.1.2.23' PLUTO_PEER_ID='@east' PLUTO_PEER_CLIENT='192.1.2.23/32' PLUTO_PEER_CLIENT_NET='192.1.2.23' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' PLUTO_PEER_PROTOCOL='17' PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+PFS' ipsec _updown | alg_info_delref(0x8126730) alg_info->ref_cnt=2 | Added new connection road--east-l2tp with policy RSASIG+ENCRYPT+PFS | from whack: got --esp=3des-md5 | esp string values: 3_000-1, flags=-strict | counting wild cards for @road is 0 | counting wild cards for @east is 0 | alg_info_addref() alg_info->ref_cnt=1 | alg_info_addref() alg_info->ref_cnt=2 | connect_to_host_pair: 192.1.3.209:500 192.1.2.23:500 -> hp:none added connection description "road--east-l2tp" | 192.1.3.209[@road]:17/1701...192.1.2.254---192.1.2.23[@east]:17/1701 | ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: RSASIG+ENCRYPT+PFS | next event EVENT_SHUNT_SCAN in 104 seconds | | *received whack message | processing connection road--east-l2tp | kernel_alg_db_new() will return p_new->protoid=3, p_new->trans_cnt=1 | kernel_alg_db_new() trans[0]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1 | returning new proposal from esp_info | creating state object #1 at 0x8127a10 | processing connection road--east-l2tp | ICOOKIE: f8 db f5 3b dd 92 0b d1 | RCOOKIE: 00 00 00 00 00 00 00 00 | peer: c0 01 02 17 | state hash entry 22 | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1 | Queuing pending Quick Mode with 192.1.2.23 "road--east-l2tp" "road--east-l2tp" #1: initiating Main Mode | nat traversal enabled: 1 | nat add vid. port: 1 nonike: 1 | sending 292 bytes for main_outI1 through eth0:500 to 192.1.2.23:500: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1 | next event EVENT_RETRANSMIT in 10 seconds for #1 | | *received 136 bytes from 192.1.2.23:500 on eth0 (port=500) | processing packet with exchange type=ISAKMP_XCHG_IDPROT (2) | ICOOKIE: f8 db f5 3b dd 92 0b d1 | RCOOKIE: 5b 75 e3 29 54 c0 15 8c | peer: c0 01 02 17 | state hash entry 17 | state object not found | ICOOKIE: f8 db f5 3b dd 92 0b d1 | RCOOKIE: 00 00 00 00 00 00 00 00 | peer: c0 01 02 17 | state hash entry 22 | peer and cookies match on #1, provided msgid 00000000 vs 00000000 | state object #1 found, in STATE_MAIN_I1 | processing connection road--east-l2tp "road--east-l2tp" #1: received Vendor ID payload [Libreswan (this version) 2.klipsng-g416ec5f3-dirty X.509-1.5.4 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR] "road--east-l2tp" #1: received Vendor ID payload [Dead Peer Detection] "road--east-l2tp" #1: received Vendor ID payload [RFC 3947] method set to=109 | sender checking NAT-t: 1 and 109 "road--east-l2tp" #1: enabling possible NAT-traversal with method RFC 3947 (NAT-Traversal) | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1 | asking helper 0 to do build_kenonce op on seq: 1 | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1 | complete state transition with STF_SUSPEND | next event EVENT_SHUNT_SCAN in 104 seconds | main inR1_outI2: calculated ke+nonce, sending I2 | processing connection road--east-l2tp | _natd_hash: hasher=0x810d2e0(16) | _natd_hash: icookie= | f8 db f5 3b dd 92 0b d1 | _natd_hash: rcookie= | 5b 75 e3 29 54 c0 15 8c | _natd_hash: ip= c0 01 02 17 | _natd_hash: port=62465 | _natd_hash: hash= da 29 e2 b8 f9 78 28 06 00 07 9b 9d 41 9b e0 35 | _natd_hash: hasher=0x810d2e0(16) | _natd_hash: icookie= | f8 db f5 3b dd 92 0b d1 | _natd_hash: rcookie= | 5b 75 e3 29 54 c0 15 8c | _natd_hash: ip= c0 01 03 d1 | _natd_hash: port=62465 | _natd_hash: hash= 3f 53 8b e2 6f f3 aa ae 09 a0 a8 81 7f be df aa | ICOOKIE: f8 db f5 3b dd 92 0b d1 | RCOOKIE: 00 00 00 00 00 00 00 00 | peer: c0 01 02 17 | state hash entry 22 | ICOOKIE: f8 db f5 3b dd 92 0b d1 | RCOOKIE: 5b 75 e3 29 54 c0 15 8c | peer: c0 01 02 17 | state hash entry 17 | complete state transition with STF_OK "road--east-l2tp" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2 | sending reply packet to 192.1.2.23:500 (from port 500) | sending 284 bytes for STATE_MAIN_I1 through eth0:500 to 192.1.2.23:500: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1 "road--east-l2tp" #1: STATE_MAIN_I2: sent MI2, expecting MR2 | modecfg pull: noquirk policy:push not-client | phase 1 is done, looking for phase 1 to unpend | next event EVENT_RETRANSMIT in 10 seconds for #1 | | *received 284 bytes from 192.1.2.23:500 on eth0 (port=500) | processing packet with exchange type=ISAKMP_XCHG_IDPROT (2) | ICOOKIE: f8 db f5 3b dd 92 0b d1 | RCOOKIE: 5b 75 e3 29 54 c0 15 8c | peer: c0 01 02 17 | state hash entry 17 | peer and cookies match on #1, provided msgid 00000000 vs 00000000 | state object #1 found, in STATE_MAIN_I2 | processing connection road--east-l2tp | thinking about whether to send my certificate: | I have RSA key: OAKLEY_RSA_SIG cert.type: CERT_NONE | sendcert: CERT_ALWAYSSEND and I did not get a certificate request | so do not send cert. "road--east-l2tp" #1: I did not send a certificate because I do not have one. | I am not sending a certificate request | started looking for secret for @road->@east of kind PPK_PSK | actually looking for secret for @road->@east of kind PPK_PSK | concluding with best_match=0 best=(nil) (lineno=-1) | _natd_hash: hasher=0x810d2e0(16) | _natd_hash: icookie= | f8 db f5 3b dd 92 0b d1 | _natd_hash: rcookie= | 5b 75 e3 29 54 c0 15 8c | _natd_hash: ip= c0 01 03 d1 | _natd_hash: port=62465 | _natd_hash: hash= 3f 53 8b e2 6f f3 aa ae 09 a0 a8 81 7f be df aa | _natd_hash: hasher=0x810d2e0(16) | _natd_hash: icookie= | f8 db f5 3b dd 92 0b d1 | _natd_hash: rcookie= | 5b 75 e3 29 54 c0 15 8c | _natd_hash: ip= c0 01 02 17 | _natd_hash: port=62465 | _natd_hash: hash= da 29 e2 b8 f9 78 28 06 00 07 9b 9d 41 9b e0 35 | NAT_TRAVERSAL hash=0 (me:0) (him:0) | expected NAT-D(me): 3f 53 8b e2 6f f3 aa ae 09 a0 a8 81 7f be df aa | expected NAT-D(him): | da 29 e2 b8 f9 78 28 06 00 07 9b 9d 41 9b e0 35 | received NAT-D: 35 a7 4d 91 65 ca 72 fd fd 7e 49 5f ca b8 5c 6c | NAT_TRAVERSAL hash=1 (me:0) (him:0) | expected NAT-D(me): 3f 53 8b e2 6f f3 aa ae 09 a0 a8 81 7f be df aa | expected NAT-D(him): | da 29 e2 b8 f9 78 28 06 00 07 9b 9d 41 9b e0 35 | received NAT-D: b2 b4 37 bc f5 9f 08 71 43 0e ff 30 2b e1 a3 b7 | NAT_TRAVERSAL hash=2 (me:0) (him:0) "road--east-l2tp" #1: NAT-Traversal: Result using RFC 3947 (NAT-Traversal): both are NATed | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds | started looking for secret for @road->@east of kind PPK_RSA | actually looking for secret for @road->@east of kind PPK_RSA | best_match 0>1 best=0x8126f28 (line=1) | concluding with best_match=1 best=0x8126f28 (lineno=1) | signing hash with RSA Key *AQNxbOBmD | complete state transition with STF_OK "road--east-l2tp" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3 | NAT-T: floating to port 4500 | NAT-T connection has wrong interface definition 192.1.3.209:4500 vs 192.1.3.209:500 | NAT-T: using interface eth0:4500 | sending reply packet to 192.1.2.23:4500 (from port 4500) | sending 324 bytes for STATE_MAIN_I2 through eth0:4500 to 192.1.2.23:4500: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1 "road--east-l2tp" #1: STATE_MAIN_I3: sent MI3, expecting MR3 | modecfg pull: noquirk policy:push not-client | phase 1 is done, looking for phase 1 to unpend | next event EVENT_RETRANSMIT in 10 seconds for #1 | | *received 300 bytes from 192.1.2.23:4500 on eth0 (port=4500) | processing packet with exchange type=ISAKMP_XCHG_IDPROT (2) | ICOOKIE: f8 db f5 3b dd 92 0b d1 | RCOOKIE: 5b 75 e3 29 54 c0 15 8c | peer: c0 01 02 17 | state hash entry 17 | peer and cookies match on #1, provided msgid 00000000 vs 00000000 | state object #1 found, in STATE_MAIN_I3 | processing connection road--east-l2tp "road--east-l2tp" #1: Main mode peer ID is ID_FQDN: '@east' | required CA is '%any' | trusted_ca called with a=(empty) b=(empty) | key issuer CA is '%any' | an RSA Sig check passed with *AQN3cn11F [preloaded key] | complete state transition with STF_OK "road--east-l2tp" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4 | inserting event EVENT_SA_REPLACE, timeout in 2946 seconds for #1 "road--east-l2tp" #1: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_RSA_SIG cipher=oakley_3des_cbc_192 prf=oakley_md5 group=modp1536} | modecfg pull: noquirk policy:push not-client | phase 1 is done, looking for phase 1 to unpend | unqueuing pending Quick Mode with 192.1.2.23 "road--east-l2tp" | duplicating state object #1 | creating state object #2 at 0x8129c18 | processing connection road--east-l2tp | ICOOKIE: f8 db f5 3b dd 92 0b d1 | RCOOKIE: 5b 75 e3 29 54 c0 15 8c | peer: c0 01 02 17 | state hash entry 17 | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2 "road--east-l2tp" #2: initiating Quick Mode RSASIG+ENCRYPT+PFS+UP {using isakmp#1} | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1 | asking helper 0 to do build_kenonce op on seq: 2 | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #2 | next event EVENT_NAT_T_KEEPALIVE in 20 seconds | quick outI1: calculated ke+nonce, sending I1 | processing connection road--east-l2tp | kernel_alg_db_new() will return p_new->protoid=3, p_new->trans_cnt=1 | kernel_alg_db_new() trans[0]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1 | returning new proposal from esp_info | generate SPI: 76 d5 3c 54 | NAT-OA (S): c0 01 03 d1 | sending 356 bytes for quick_outI1 through eth0:4500 to 192.1.2.23:4500: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #2 | next event EVENT_RETRANSMIT in 10 seconds for #2 | | *received 340 bytes from 192.1.2.23:4500 on eth0 (port=4500) | processing packet with exchange type=ISAKMP_XCHG_QUICK (32) | ICOOKIE: f8 db f5 3b dd 92 0b d1 | RCOOKIE: 5b 75 e3 29 54 c0 15 8c | peer: c0 01 02 17 | state hash entry 17 | peer and cookies match on #2, provided msgid cc4f9c1d vs cc4f9c1d | state object #2 found, in STATE_QUICK_I1 | processing connection road--east-l2tp | started looking for secret for @road->@east of kind PPK_PSK | actually looking for secret for @road->@east of kind PPK_PSK | concluding with best_match=0 best=(nil) (lineno=-1) | NAT-Traversal: received 0 NAT-OA. | our client is 192.1.3.209 | our client protocol/port is 17/1701 | peer client is 192.1.2.23 | peer client protocol/port is 17/1701 | install_ipsec_sa() for #2: inbound and outbound | route owner of "road--east-l2tp" unrouted: NULL; eroute owner: NULL | could_route called for road--east-l2tp (kind=CK_PERMANENT) | outif = -1 | outif = -1 | sr for #2: unrouted | route owner of "road--east-l2tp" unrouted: NULL; eroute owner: NULL | route_and_eroute with c: road--east-l2tp (next: none) ero:null esr:{(nil)} ro:null rosr:{(nil)} and state: 2 | eroute_connection add eroute 192.1.3.209/32:1701 --17-> 192.1.2.23/32:1701 => esp.ae595bac@192.1.2.23 (raw_eroute) | command executing up-host | trusted_ca called with a=(empty) b=(empty) | executing up-host: 2>&1 PLUTO_VERB='up-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='road--east-l2tp' PLUTO_INTERFACE='ipsec0' PLUTO_ME='192.1.3.209' PLUTO_MY_ID='@road' PLUTO_MY_CLIENT='192.1.3.209/32' PLUTO_MY_CLIENT_NET='192.1.3.209' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' PLUTO_MY_PROTOCOL='17' PLUTO_PEER='192.1.2.23' PLUTO_PEER_ID='@east' PLUTO_PEER_CLIENT='192.1.2.23/32' PLUTO_PEER_CLIENT_NET='192.1.2.23' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' PLUTO_PEER_PROTOCOL='17' PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+PFS+UP' ipsec _updown | route_and_eroute: firewall_notified: true | command executing prepare-host | trusted_ca called with a=(empty) b=(empty) | executing prepare-host: 2>&1 PLUTO_VERB='prepare-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='road--east-l2tp' PLUTO_INTERFACE='ipsec0' PLUTO_ME='192.1.3.209' PLUTO_MY_ID='@road' PLUTO_MY_CLIENT='192.1.3.209/32' PLUTO_MY_CLIENT_NET='192.1.3.209' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' PLUTO_MY_PROTOCOL='17' PLUTO_PEER='192.1.2.23' PLUTO_PEER_ID='@east' PLUTO_PEER_CLIENT='192.1.2.23/32' PLUTO_PEER_CLIENT_NET='192.1.2.23' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' PLUTO_PEER_PROTOCOL='17' PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+PFS+UP' ipsec _updown | command executing route-host | trusted_ca called with a=(empty) b=(empty) | executing route-host: 2>&1 PLUTO_VERB='route-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='road--east-l2tp' PLUTO_INTERFACE='ipsec0' PLUTO_ME='192.1.3.209' PLUTO_MY_ID='@road' PLUTO_MY_CLIENT='192.1.3.209/32' PLUTO_MY_CLIENT_NET='192.1.3.209' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' PLUTO_MY_PROTOCOL='17' PLUTO_PEER='192.1.2.23' PLUTO_PEER_ID='@east' PLUTO_PEER_CLIENT='192.1.2.23/32' PLUTO_PEER_CLIENT_NET='192.1.2.23' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' PLUTO_PEER_PROTOCOL='17' PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='RSASIG+ENCRYPT+PFS+UP' ipsec _updown | route_and_eroute: instance "road--east-l2tp", setting eroute_owner {spd=0x81264c4,sr=0x81264c4} to #2 (was #0) (newest_ipsec_sa=#0) | inR1_outI2: instance road--east-l2tp[0], setting newest_ipsec_sa to #2 (was #0) (spd.eroute=#2) | complete state transition with STF_OK "road--east-l2tp" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2 | sending reply packet to 192.1.2.23:4500 (from port 4500) | sending 52 bytes for STATE_QUICK_I1 through eth0:4500 to 192.1.2.23:4500: | inserting event EVENT_SA_REPLACE, timeout in 28199 seconds for #2 "road--east-l2tp" #2: STATE_QUICK_I2: sent QI2, IPsec SA established transport mode {ESP=>0xae595bac <0x76d53c54 xfrm=3DES_0-HMAC_MD5 ref=2 refhim=1 NATD=192.1.2.23:4500 DPD=none} | modecfg pull: noquirk policy:push not-client | phase 1 is done, looking for phase 1 to unpend | next event EVENT_NAT_T_KEEPALIVE in 20 seconds | | *received whack message | next event EVENT_NAT_T_KEEPALIVE in -4 seconds | | *time to handle event | handling event EVENT_NAT_T_KEEPALIVE | event after this is EVENT_SHUNT_SCAN in 80 seconds | processing connection road--east-l2tp | processing connection road--east-l2tp | processing connection road--east-l2tp | ka_event: send NAT-KA to 192.1.2.23:4500 (state=#1) | sending 1 bytes for NAT-T Keep Alive through eth0:4500 to 192.1.2.23:4500: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds | next event EVENT_NAT_T_KEEPALIVE in 20 seconds road:~# : ==== tuc ==== road:~# grep 'Result using RFC 3947' /tmp/pluto.log "road--east-l2tp" #1: NAT-Traversal: Result using RFC 3947 (NAT-Traversal): both are NATed road:~# : ==== end ==== road:~# ipsec setup stop ipsec_setup: Stopping Libreswan IPsec... road:~# kill `cat /var/run/klogd.pid`; cat /tmp/klog.log klogd 1.3-3#33.1, log source = /proc/kmsg started. <4>Checking that ptrace can change system call numbers...OK <4>Checking syscall emulation patch for ptrace...missing <5>Linux version 2.6.15-rc3-gref: ref (mcr@marajade.sandelman.ca) (gcc version 3.3.5 (Debian 1:3.3.5-13)) #27 Tue Feb 28 15:32:36 EST 2006 <7>On node 0 totalpages: 8192 <7> DMA zone: 8192 pages, LIFO batch:4 <7> DMA32 zone: 0 pages, LIFO batch:2 <7> Normal zone: 0 pages, LIFO batch:2 <7> HighMem zone: 0 pages, LIFO batch:2 <4>Built 1 zonelists <5>Kernel command line: initrd=/mara6/sandboxes/UMLPOOL/klipsng/initrd.uml umlroot=/mara6/sandboxes/UMLPOOL/klipsng/road/root root=/dev/root rw ssl=pty eth0=daemon,10:00:00:ab:cd:02,unix,/tmp/umlXfE180.d/northpublic/ctl,/tmp/umlXfE180.d/northpublic/data single <4>PID hash table entries: 256 (order: 8, 4096 bytes) <4>Dentry cache hash table entries: 8192 (order: 3, 32768 bytes) <4>Inode-cache hash table entries: 4096 (order: 2, 16384 bytes) <6>Memory: 26928k available <7>Calibrating delay loop... 3473.40 BogoMIPS (lpj=17367040) <4>Mount-cache hash table entries: 512 <4>Checking for host processor cmov support...Yes <4>Checking for host processor xmm support...No <4>Checking that host ptys support output SIGIO...Yes <4>Checking that host ptys support SIGIO on close...No, enabling workaround <4>Checking for /dev/anon on the host...Not available (open failed with errno 2) <6>checking if image is initramfs...it isn't (bad gzip magic numbers); looks like an initrd <4>Freeing initrd memory: 1228k freed <4>Using 2.6 host AIO <6>NET: Registered protocol family 16 <4>daemon_setup : Ignoring data socket specification <6>Netdevice 0 (10:00:00:ab:cd:02) : daemon backend (uml_switch version 3) - unix:/tmp/umlXfE180.d/northpublic/ctl <4>mconsole (version 2) initialized on /home/mcr/.uml/road/mconsole <5>VFS: Disk quotas dquot_6.5.1 <4>Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) <6>Initializing Cryptographic API <6>io scheduler noop registered <6>io scheduler anticipatory registered <6>io scheduler deadline registered <6>io scheduler cfq registered <4>RAMDISK driver initialized: 16 RAM disks of 4096K size 1024 blocksize <6>loop: loaded (max 8 devices) <6>nbd: registered device at major 43 <6>PPP generic driver version 2.4.2 <6>PPP Deflate Compression module registered <6>PPP BSD Compression module registered <6>PPP MPPE Compression module registered <6>NET: Registered protocol family 24 <6>SLIP: version 0.8.4-NET3.019-NEWTTY (dynamic channels, max=256). <6>tun: Universal TUN/TAP device driver, 1.6 <6>tun: (C) 1999-2004 Max Krasnyansky <6>NET: Registered protocol family 2 <4>IP route cache hash table entries: 512 (order: -1, 2048 bytes) <4>TCP established hash table entries: 2048 (order: 1, 8192 bytes) <4>TCP bind hash table entries: 2048 (order: 1, 8192 bytes) <6>TCP: Hash tables configured (established 2048 bind 2048) <6>TCP reno registered <6>klips_info:ipsec_init: KLIPS startup, Libreswan KLIPS IPsec stack version: 2.git <6>NET: Registered protocol family 15 <6>klips_info:ipsec_alg_init: KLIPS alg v=0.8.1-0 (EALG_MAX=255, AALG_MAX=251) <6>klips_info:ipsec_alg_init: calling ipsec_alg_static_init() <4>ipsec_aes_init(alg_type=15 alg_id=12 name=aes): ret=0 <4>ipsec_aes_init(alg_type=14 alg_id=9 name=aes_mac): ret=0 <4>ipsec_3des_init(alg_type=15 alg_id=3 name=3des): ret=0 <6>IPv4 over IPv4 tunneling driver <6>GRE over IPv4 tunneling driver <4>ip_conntrack version 2.4 (211 buckets, 1688 max) - 212 bytes per conntrack <4>ip_tables: (C) 2000-2002 Netfilter core team <6>ipt_recent v0.3.1: Stephen Frost . http://snowman.net/projects/ipt_recent/ <4>arp_tables: (C) 2002 David S. Miller <6>TCP bic registered <6>TCP westwood registered <6>TCP highspeed registered <6>TCP hybla registered <6>TCP htcp registered <6>TCP vegas registered <6>TCP scalable registered <6>NET: Registered protocol family 1 <6>NET: Registered protocol family 17 <6>Initialized stdio console driver <4>Console initialized on /dev/tty0 <6>Initializing software serial port version 1 <4>Failed to open 'root_fs', errno = 2 <5>RAMDISK: cramfs filesystem found at block 0 <5>RAMDISK: Loading 1228KiB [1 disk] into ram disk... |/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|/-\|done. <4>VFS: Mounted root (cramfs filesystem) readonly. <6>line_ioctl: tty0: ioctl KDSIGACCEPT called <4> <4> <4> <4> Kernel logging (proc) stopped. Kernel log daemon terminating. road:~# halt -p -f Power down.