IPsec(Openswan)を使用して、L2TPトンネル構築をしてる時に出力されたエラーログについて対処方法をまとめておきたいと思います。
L2TPトンネルを張っている状態でIPsecを停止したり、IPsecが起動していない状態でL2TPトンネルを張ると以下のエラーが出力されます。
エラーログ:/var/log/message
Dec 12 17:56:14 ip-10-31-1-185 xl2tpd[6426]: udp_xmit failed to 172.16.10.202:1701 with err=-1:Operation not permitted
対処方法:
# IPsecを再起動する ipsec auto --down vpn xl2tpd-control disconnect l2tp1 ipsec auto --up vpn # L2TPトンネルリングを再接続 xl2tpd-control connect l2tp1
対応時のログ:
/var/log/secure
# IPsecトンネル切断時のログ(ipsec auto --down vpn) Dec 12 19:29:45 ip-10-31-1-185 pluto[7984]: "vpn": terminating SAs using this connection Dec 12 19:29:45 ip-10-31-1-185 pluto[7984]: "vpn" #103: deleting state (STATE_QUICK_I2) Dec 12 19:29:45 ip-10-31-1-185 pluto[7984]: "vpn" #102: deleting state (STATE_MAIN_I4) # IPsecトンネル切断時のログ (ipsec auto --up vpn) Dec 12 19:32:35 ip-10-31-1-185 pluto[7984]: "vpn" #104: initiating Main Mode Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #104: received Vendor ID payload [RFC 3947] method set to=109 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #104: enabling possible NAT-traversal with method 4 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #104: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #104: STATE_MAIN_I2: sent MI2, expecting MR2 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #104: NAT-Traversal: Result using RFC 3947 (NAT-Traversal): no NAT detected Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #104: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #104: STATE_MAIN_I3: sent MI3, expecting MR3 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #104: Main mode peer ID is ID_IPV4_ADDR: '172.16.10.202' Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #104: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #104: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp1024} Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: initiating Quick Mode PSK+ENCRYPT+UP+IKEv2ALLOW+SAREFTRACK {using isakmp#104 msgid:072873ed proposal=AES(12)_128-SHA1(2)_160 pfsgroup=no-pfs} Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: our client peer returned protocol id does not match my proposal - us17 vs them: 0 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: Allowing questionable proposal anyway [ALLOW_MICROSOFT_BAD_PROPOSAL] Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: our client peer returned port doesn't match my proposal - us:1701 vs them:0 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: Allowing bad L2TP/IPsec proposal (see bug #849) anyway Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: peer client peer returned protocol id does not match my proposal - us17 vs them: 0 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: Allowing questionable proposal anyway [ALLOW_MICROSOFT_BAD_PROPOSAL] Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: peer client peer returned port doesn't match my proposal - us:1701 vs them:0 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: Allowing bad L2TP/IPsec proposal (see bug #849) anyway Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2 Dec 12 19:32:36 ip-10-31-1-185 pluto[7984]: "vpn" #105: STATE_QUICK_I2: sent QI2, IPsec SA established transport mode {ESP=>0x7900d24c <0x74188154 xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=none}
/var/log/message
# L2TPトンネル切断時 Dec 12 19:36:53 ip-10-31-1-185 xl2tpd[6426]: Disconnecting from 172.16.10.202, Local: 22170, Remote: 57731 Dec 12 19:36:53 ip-10-31-1-185 xl2tpd[6426]: Connection 57731 closed to 172.16.10.202, port 1701 (Goodbye!) Dec 12 19:36:53 ip-10-31-1-185 pppd[9477]: Terminating on signal 15 Dec 12 19:36:53 ip-10-31-1-185 pppd[9477]: Modem hangup Dec 12 19:36:53 ip-10-31-1-185 pppd[9477]: Connect time 0.3 minutes. Dec 12 19:36:53 ip-10-31-1-185 pppd[9477]: Sent 16 bytes, received 0 bytes. Dec 12 19:36:53 ip-10-31-1-185 pppd[9477]: Connection terminated. Dec 12 19:36:54 ip-10-31-1-185 pppd[9477]: Exit. # L2TPトンネル接続時 Dec 12 19:41:17 ip-10-31-1-185 xl2tpd[6426]: Connecting to host 172.16.10.202, port 1701 Dec 12 19:41:17 ip-10-31-1-185 xl2tpd[6426]: Connection established to 172.16.10.202, 1701. Local: 2252, Remote: 54113 (ref=0/0). Dec 12 19:41:17 ip-10-31-1-185 xl2tpd[6426]: Calling on tunnel 2252 Dec 12 19:41:17 ip-10-31-1-185 xl2tpd[6426]: Call established with 172.16.10.202, Local: 55934, Remote: 26565, Serial: 20 (ref=0/0) Dec 12 19:41:17 ip-10-31-1-185 pppd[9622]: pppd 2.4.5 started by ec2-user, uid 0 Dec 12 19:41:17 ip-10-31-1-185 pppd[9622]: Using interface ppp0 Dec 12 19:41:17 ip-10-31-1-185 pppd[9622]: Connect: ppp0 <--> /dev/pts/4 Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: CHAP authentication succeeded: Authentication succeeded. Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: CHAP authentication succeeded Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: Unsupported protocol 'IPv6 Control Protocol' (0x8057) received Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: Cannot determine ethernet address for proxy ARP Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: local IP address 172.16.10.50 Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: remote IP address 10.47.10.1
# L2TPトンネル切断時 Dec 12 19:36:53 ip-10-31-1-185 xl2tpd[6426]: Disconnecting from 172.16.10.202, Local: 22170, Remote: 57731 Dec 12 19:36:53 ip-10-31-1-185 xl2tpd[6426]: Connection 57731 closed to 172.16.10.202, port 1701 (Goodbye!) Dec 12 19:36:53 ip-10-31-1-185 pppd[9477]: Terminating on signal 15 Dec 12 19:36:53 ip-10-31-1-185 pppd[9477]: Modem hangup Dec 12 19:36:53 ip-10-31-1-185 pppd[9477]: Connect time 0.3 minutes. Dec 12 19:36:53 ip-10-31-1-185 pppd[9477]: Sent 16 bytes, received 0 bytes. Dec 12 19:36:53 ip-10-31-1-185 pppd[9477]: Connection terminated. Dec 12 19:36:54 ip-10-31-1-185 pppd[9477]: Exit. # L2TPトンネル接続時 Dec 12 19:41:17 ip-10-31-1-185 xl2tpd[6426]: Connecting to host 172.16.10.202, port 1701 Dec 12 19:41:17 ip-10-31-1-185 xl2tpd[6426]: Connection established to 172.16.10.202, 1701. Local: 2252, Remote: 54113 (ref=0/0). Dec 12 19:41:17 ip-10-31-1-185 xl2tpd[6426]: Calling on tunnel 2252 Dec 12 19:41:17 ip-10-31-1-185 xl2tpd[6426]: Call established with 172.16.10.202, Local: 55934, Remote: 26565, Serial: 20 (ref=0/0) Dec 12 19:41:17 ip-10-31-1-185 pppd[9622]: pppd 2.4.5 started by ec2-user, uid 0 Dec 12 19:41:17 ip-10-31-1-185 pppd[9622]: Using interface ppp0 Dec 12 19:41:17 ip-10-31-1-185 pppd[9622]: Connect: ppp0 <--> /dev/pts/4 Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: CHAP authentication succeeded: Authentication succeeded. Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: CHAP authentication succeeded Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: Unsupported protocol 'IPv6 Control Protocol' (0x8057) received Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: Cannot determine ethernet address for proxy ARP Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: local IP address 172.16.10.50 Dec 12 19:41:18 ip-10-31-1-185 pppd[9622]: remote IP address 10.47.10.1