[Swan] Help needed: STATE_MAIN_I3: 60 second timeout exceeded after 7 retransmits. Possible authentication failure: no acceptable response to our first encrypted message
Mathieu Rossignol
mathieu.rossignol at hurence.com
Tue Apr 16 16:10:07 UTC 2019
Hi there,
I'm aVPN noob and i'm stuck with this problem:
---------------------------------------------------------------------
[root at xxxxxx ipsec.d]# ipsec auto --verbose --up mysubnet
002 "mysubnet" #6: initiating Main Mode
104 "mysubnet" #6: STATE_MAIN_I1: initiate
003 "mysubnet" #6: ignoring unknown Vendor ID payload
[92d37bd4c2ddfdacbbc732ccaaccedba]
106 "mysubnet" #6: STATE_MAIN_I2: sent MI2, expecting MR2
108 "mysubnet" #6: STATE_MAIN_I3: sent MI3, expecting MR3
010 "mysubnet" #6: STATE_MAIN_I3: retransmission; will wait 0.5 seconds
for response
010 "mysubnet" #6: STATE_MAIN_I3: retransmission; will wait 1 seconds
for response
010 "mysubnet" #6: STATE_MAIN_I3: retransmission; will wait 2 seconds
for response
010 "mysubnet" #6: STATE_MAIN_I3: retransmission; will wait 4 seconds
for response
010 "mysubnet" #6: STATE_MAIN_I3: retransmission; will wait 8 seconds
for response
010 "mysubnet" #6: STATE_MAIN_I3: retransmission; will wait 16 seconds
for response
010 "mysubnet" #6: STATE_MAIN_I3: retransmission; will wait 32 seconds
for response
031 "mysubnet" #6: STATE_MAIN_I3: 60 second timeout exceeded after 7
retransmits. Possible authentication failure: no acceptable response to
our first encrypted message
000 "mysubnet" #6: starting keying attempt 2 of an unlimited number, but
releasing whack
-------------------------------------------------------------------
configuration (xxx.conf file):
config setup
protostack=netkey
nat_traversal=no
conn mysubnet
also=mytunnel
leftsubnet=10.100.105.0/24
leftsourceip=10.100.105.254
rightsubnet=192.168.41.0/24
rightsourceip=192.168.41.254
auto=start
conn mytunnel
type=tunnel
authby=secret
ike=aes128-sha1;modp1024
salifetime=3600s
ikelifetime=21600s
phase2alg=aes128-sha1;modp1024
left=149.202.66.102
right=92.103.11.11
-------------------------------------------------------------------
xxx.secrets file:
92.103.11.11 149.202.66.102 : PSK "OfCourseNotTheRealOne"
-------------------------------------------------------------------
tail -f /var/log/secure|grep mysbunet:
Apr 16 17:53:13 ns3007941 pluto[12687]: | conn mysubnet mark
0/00000000, 0/00000000
Apr 16 17:53:13 ns3007941 pluto[12687]: | conn mysubnet mark
0/00000000, 0/00000000
Apr 16 17:53:19 ns3007941 pluto[12687]: "mysubnet" #6: initiating Main Mode
Apr 16 17:53:19 ns3007941 pluto[12687]: "mysubnet" #6: ignoring unknown
Vendor ID payload [92d37bd4c2ddfdacbbc732ccaaccedba]
Apr 16 17:53:19 ns3007941 pluto[12687]: "mysubnet" #6: STATE_MAIN_I2:
sent MI2, expecting MR2
Apr 16 17:53:19 ns3007941 pluto[12687]: "mysubnet" #6: STATE_MAIN_I3:
sent MI3, expecting MR3
Apr 16 17:53:19 ns3007941 pluto[12687]: "mysubnet" #6: STATE_MAIN_I3:
retransmission; will wait 0.5 seconds for response
Apr 16 17:53:20 ns3007941 pluto[12687]: "mysubnet" #6: STATE_MAIN_I3:
retransmission; will wait 1 seconds for response
Apr 16 17:53:21 ns3007941 pluto[12687]: "mysubnet" #6: STATE_MAIN_I3:
retransmission; will wait 2 seconds for response
Apr 16 17:53:23 ns3007941 pluto[12687]: "mysubnet" #6: STATE_MAIN_I3:
retransmission; will wait 4 seconds for response
Apr 16 17:53:27 ns3007941 pluto[12687]: "mysubnet" #6: STATE_MAIN_I3:
retransmission; will wait 8 seconds for response
Apr 16 17:53:29 ns3007941 pluto[12687]: | processing: start state #6
connection "mysubnet" 92.103.11.11 (in process_v1_packet() at ikev1.c:1096)
Apr 16 17:53:29 ns3007941 pluto[12687]: | "mysubnet" #6: discarding
duplicate packet; already STATE_MAIN_I3
Apr 16 17:53:29 ns3007941 pluto[12687]: | processing: stop state #6
connection "mysubnet" 92.103.11.11 (in process_md() at demux.c:396)
Apr 16 17:53:35 ns3007941 pluto[12687]: | processing: start state #6
connection "mysubnet" 92.103.11.11 (in timer_event_cb() at timer.c:319)
Apr 16 17:53:35 ns3007941 pluto[12687]: | processing: [RE]START state #6
connection "mysubnet" 92.103.11.11 (in retransmit_v1_msg() at retry.c:60)
Apr 16 17:53:35 ns3007941 pluto[12687]: | handling event
EVENT_v1_RETRANSMIT for 92.103.11.11 "mysubnet" #6 keying attempt 1 of
0; retransmit 6
Apr 16 17:53:35 ns3007941 pluto[12687]: "mysubnet" #6: STATE_MAIN_I3:
retransmission; will wait 16 seconds for response
Apr 16 17:53:35 ns3007941 pluto[12687]: | processing: stop state #6
connection "mysubnet" 92.103.11.11 (in timer_event_cb() at timer.c:664)
Apr 16 17:53:39 ns3007941 pluto[12687]: | processing: start state #6
connection "mysubnet" 92.103.11.11 (in process_v1_packet() at ikev1.c:1096)
Apr 16 17:53:39 ns3007941 pluto[12687]: | "mysubnet" #6: discarding
duplicate packet; already STATE_MAIN_I3
Apr 16 17:53:39 ns3007941 pluto[12687]: | processing: stop state #6
connection "mysubnet" 92.103.11.11 (in process_md() at demux.c:396)
Apr 16 17:53:39 ns3007941 pluto[12687]: | processing: start state #6
connection "mysubnet" 92.103.11.11 (in for_each_state() at state.c:1614)
Apr 16 17:53:39 ns3007941 pluto[12687]: | processing: stop state #6
connection "mysubnet" 92.103.11.11 (in for_each_state() at state.c:1614)
Apr 16 17:53:49 ns3007941 pluto[12687]: | processing: start state #6
connection "mysubnet" 92.103.11.11 (in process_v1_packet() at ikev1.c:1096)
Apr 16 17:53:49 ns3007941 pluto[12687]: | "mysubnet" #6: discarding
duplicate packet; already STATE_MAIN_I3
Apr 16 17:53:49 ns3007941 pluto[12687]: | processing: stop state #6
connection "mysubnet" 92.103.11.11 (in process_md() at demux.c:396)
Apr 16 17:53:51 ns3007941 pluto[12687]: | processing: start state #6
connection "mysubnet" 92.103.11.11 (in timer_event_cb() at timer.c:319)
Apr 16 17:53:51 ns3007941 pluto[12687]: | processing: [RE]START state #6
connection "mysubnet" 92.103.11.11 (in retransmit_v1_msg() at retry.c:60)
Apr 16 17:53:51 ns3007941 pluto[12687]: | handling event
EVENT_v1_RETRANSMIT for 92.103.11.11 "mysubnet" #6 keying attempt 1 of
0; retransmit 7
Apr 16 17:53:51 ns3007941 pluto[12687]: "mysubnet" #6: STATE_MAIN_I3:
retransmission; will wait 32 seconds for response
Apr 16 17:53:51 ns3007941 pluto[12687]: | processing: stop state #6
connection "mysubnet" 92.103.11.11 (in timer_event_cb() at timer.c:664)
Apr 16 17:53:59 ns3007941 pluto[12687]: | processing: start state #6
connection "mysubnet" 92.103.11.11 (in process_v1_packet() at ikev1.c:1096)
Apr 16 17:53:59 ns3007941 pluto[12687]: | "mysubnet" #6: discarding
duplicate packet; already STATE_MAIN_I3
Apr 16 17:53:59 ns3007941 pluto[12687]: | processing: stop state #6
connection "mysubnet" 92.103.11.11 (in process_md() at demux.c:396)
Apr 16 17:54:23 ns3007941 pluto[12687]: | processing: start state #6
connection "mysubnet" 92.103.11.11 (in timer_event_cb() at timer.c:319)
Apr 16 17:54:23 ns3007941 pluto[12687]: | processing: [RE]START state #6
connection "mysubnet" 92.103.11.11 (in retransmit_v1_msg() at retry.c:60)
Apr 16 17:54:23 ns3007941 pluto[12687]: | handling event
EVENT_v1_RETRANSMIT for 92.103.11.11 "mysubnet" #6 keying attempt 1 of
0; retransmit 8
Apr 16 17:54:23 ns3007941 pluto[12687]: "mysubnet" #6: STATE_MAIN_I3: 60
second timeout exceeded after 7 retransmits. Possible authentication
failure: no acceptable response to our first encrypted message
Apr 16 17:54:23 ns3007941 pluto[12687]: "mysubnet" #6: starting keying
attempt 2 of an unlimited number, but releasing whack
Apr 16 17:54:23 ns3007941 pluto[12687]: | processing: suspend state #6
connection "mysubnet" 92.103.11.11 (in initialize_new_state() at
ipsec_doi.c:490)
Apr 16 17:54:23 ns3007941 pluto[12687]: | processing: start state #7
connection "mysubnet" 92.103.11.11 (in initialize_new_state() at
ipsec_doi.c:490)
Apr 16 17:54:23 ns3007941 pluto[12687]: | processing: [RE]START state #7
connection "mysubnet" 92.103.11.11 (in initialize_new_state() at
ipsec_doi.c:510)
Apr 16 17:54:23 ns3007941 pluto[12687]: "mysubnet" #7: initiating Main
Mode to replace #6
-------------------------------------------------------------------
iptables:
ACCEPT udp -- 92.103.11.11 0.0.0.0/0 udp
dpt:500 ctstate NEW,RELATED,ESTABLISHED
ACCEPT ah -- 92.103.11.11 0.0.0.0/0 ctstate
NEW,RELATED,ESTABLISHED
ACCEPT esp -- 92.103.11.11 0.0.0.0/0 ctstate
NEW,RELATED,ESTABLISHED
-------------------------------------------------------------------
ifconfig:
eth0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500
inet 149.202.66.102 netmask 255.255.255.0 broadcast
149.202.66.255
ether 0c:c4:7a:55:84:32 txqueuelen 1000 (Ethernet)
RX packets 24435652157 bytes 21473727284485 (19.5 TiB)
RX errors 0 dropped 0 overruns 2755 frame 0
TX packets 22028813578 bytes 19416650994448 (17.6 TiB)
TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0
device memory 0xdf920000-df93ffff
-------------------------------------------------------------------
ipsec version:
Linux Libreswan 3.25 (netkey) on 3.14.32-xxxx-grs-ipv6-64
-------------------------------------------------------------------
It's like the PSK authentication (I guess) is was valid but in fact if I
remove the xxx.secrets file, the same problem occurs...
Thanks for any help!
More information about the Swan
mailing list