Red Hat Bugzilla – Bug 1219049
Pluto does not handle delete message from responder site in ikev1
Last modified: 2016-11-03 17:21:05 EDT
Description of problem: Pluto does not handle delete message from Responder site in ikev1 like service ipsec stop or ipsec auto --down CONNECTION. Version-Release number of selected component (if applicable): 3.10.0-229.ael7b 3.10.0-229.el7 How reproducible: 100% Steps to Reproduce: Configuration ------------- # cat /etc/ipsec.conf config setup protostack=netkey plutodebug=all nat_traversal=yes plutostderrlog=/tmp/pluto.log conn test left=<INITIATOR> right=<RESPONDER> authby=secret phase2=esp auto=add ikev2=no # cat /etc/ipsec.secrets : PSK "redhat" Scenario -------- I: # service ipsec start # ipsec auto --status ... 000 "test": newest ISAKMP SA: #0; newest IPsec SA: #0; 000 000 Total IPsec connections: loaded 1, active 0 ... R: # service ipsec start # ipsec auto --status ... 000 "test": newest ISAKMP SA: #0; newest IPsec SA: #0; 000 000 Total IPsec connections: loaded 1, active 0 ... I: # ipsec auto --up 002 "test" #1: initiating Main Mode 104 "test" #1: STATE_MAIN_I1: initiate 003 "test" #1: received Vendor ID payload [Dead Peer Detection] 003 "test" #1: received Vendor ID payload [FRAGMENTATION] 003 "test" #1: received Vendor ID payload [RFC 3947] 002 "test" #1: enabling possible NAT-traversal with method RFC 3947 (NAT-Traversal) 002 "test" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2 106 "test" #1: STATE_MAIN_I2: sent MI2, expecting MR2 003 "test" #1: NAT-Traversal: Result using RFC 3947 (NAT-Traversal) sender port 500: no NAT detected 002 "test" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3 108 "test" #1: STATE_MAIN_I3: sent MI3, expecting MR3 002 "test" #1: Main mode peer ID is ID_IPV4_ADDR: '10.16.70.85' 002 "test" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4 004 "test" #1: STATE_MAIN_I4: ISAKMP SA established {auth=PRESHARED_KEY cipher=aes_256 integ=sha group=MODP2048} 002 "test" #2: initiating Quick Mode PSK+ENCRYPT+TUNNEL+PFS+UP+SAREF_TRACK+IKE_FRAG_ALLOW {using isakmp#1 msgid:e1473fad proposal=defaults pfsgroup=OAKLEY_GROUP_MODP2048} 117 "test" #2: STATE_QUICK_I1: initiate 002 "test" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2 004 "test" #2: STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode {ESP=>0x53c3a750 <0xaa955d4f xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=passive} # ipsec auto --status ... 000 "test": newest ISAKMP SA: #1; newest IPsec SA: #2; 000 "test": IKE algorithm newest: AES_CBC_256-SHA1-MODP2048 000 "test": ESP algorithm newest: AES_128-HMAC_SHA1; pfsgroup=<Phase1> 000 000 Total IPsec connections: loaded 1, active 1 ... R: # ipsec auto --status ... 000 "test": newest ISAKMP SA: #1; newest IPsec SA: #2; 000 "test": IKE algorithm newest: AES_CBC_256-SHA1-MODP2048 000 "test": ESP algorithm newest: AES_128-HMAC_SHA1; pfsgroup=<Phase1> 000 000 Total IPsec connections: loaded 1, active 1 ... # ipsec auto --down test 002 "test": terminating SAs using this connection 002 "test" #2: deleting state (STATE_QUICK_R2) 005 "test" #2: ESP traffic information: in=0B out=0B 002 "test" #1: deleting state (STATE_MAIN_R3) # ipsec auto --status ... 000 "test": newest ISAKMP SA: #3; newest IPsec SA: #4; 000 "test": IKE algorithm newest: AES_CBC_256-SHA1-MODP2048 000 "test": ESP algorithm newest: AES_128-HMAC_SHA1; pfsgroup=<Phase1> 000 000 Total IPsec connections: loaded 1, active 1 ... I: # ipsec auto --status ... 000 "test": newest ISAKMP SA: #3; newest IPsec SA: #4; 000 "test": IKE algorithm newest: AES_CBC_256-SHA1-MODP2048 000 "test": ESP algorithm newest: AES_128-HMAC_SHA1; pfsgroup=<Phase1> 000 000 Total IPsec connections: loaded 1, active 1 ... # service ipsec stop R: # service ipsec --status ... 000 "test": newest ISAKMP SA: #0; newest IPsec SA: #0; 000 000 Total IPsec connections: loaded 1, active 0 ... # service ipsec stop Additional information: Log are attached. ipsec auto --down CONNECTION works on INITIATOR site. If I remove plutostderrlog option from configuration file, connection on RESPONDER is deleted after ipsec auto --down CONNECTION command and on INITIATOR site is active (IPSEC SA). R: # ipsec auto --down CONNECTION # ipsec auto --status 000 "test": newest ISAKMP SA: #0; newest IPsec SA: #0; 000 000 Total IPsec connections: loaded 1, active 0 I: 000 "test": newest ISAKMP SA: #0; newest IPsec SA: #2; 000 "test": ESP algorithm newest: AES_128-HMAC_SHA1; pfsgroup=<Phase1> 000 000 Total IPsec connections: loaded 1, active 1
very strange. It seems to delete the isakmp sa but not the ipsec sa. Definitely a regression we had not noticied before. Present in current upstream git master.
I have a partial fix for this committed but the bug is actually a little different than the description here, see: https://lists.libreswan.org/pipermail/swan-dev/2016-July/001537.html So I believe there is a bug in upstream, but I want to coordinate with those developers to implement what is thought to be the actual right behaviour
Hi Paul, any conclusion in discussion? I see the same behaviour on the old and on the new version. For me, it does not seem to be fixed. Switching it to assigned state. test output: server :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::: :: [ LOG ] :: bz1315732, bz1219049 - SERVER (down) :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::: :: [ PASS ] :: Command 'service ipsec start' (Expected 0, got 0) :: [ PASS ] :: Command 'sleep 10s' (Expected 0, got 0) :: [ LOG ] :: sync: SERVER set flag SERVER_READY :: [ PASS ] :: Command 'syncSet SERVER_READY' (Expected 0, got 0) :: [ LOG ] :: sync: SERVER is waiting for flag CLIENT_READY :: [ LOG ] :: sync: SERVER got flag CLIENT_READY :: [ PASS ] :: Command 'syncExp CLIENT_READY' (Expected 0, got 0) :: [ LOG ] :: sync: SERVER is waiting for flag CLIENT_TEST_UP_DONE :: [ LOG ] :: sync: SERVER got flag CLIENT_TEST_UP_DONE :: [ PASS ] :: Command 'syncExp CLIENT_TEST_UP_DONE' (Expected 0, got 0) :: [ PASS ] :: Printing ipsec status. (Expected 0, got 0) :: [ PASS ] :: ISAKMP SA should be alive. (Expected 0, got 0) :: [ PASS ] :: IPSEC SA should be alive. (Expected 0, got 0) :: [ LOG ] :: sync: SERVER set flag SERVER_TEST_UP_DONE :: [ PASS ] :: Command 'syncSet SERVER_TEST_UP_DONE' (Expected 0, got 0) :: [ PASS ] :: Command 'ipsec auto --down test' (Expected 0, got 0) :: [ PASS ] :: Printing ipsec status. (Expected 0, got 0) :: [ PASS ] :: ISAKMP SA should be dead. (Expected 1, got 1) :: [ PASS ] :: IPSEC SA should be dead. (Expected 1, got 1) :: [ LOG ] :: sync: SERVER set flag SERVER_TEST_DOWN_DONE :: [ PASS ] :: Command 'syncSet SERVER_TEST_DOWN_DONE' (Expected 0, got 0) :: [ LOG ] :: sync: SERVER is waiting for flag CLIENT_TEST_DOWN_DONE :: [ LOG ] :: sync: SERVER got flag CLIENT_TEST_DOWN_DONE :: [ PASS ] :: Command 'syncExp CLIENT_TEST_DOWN_DONE' (Expected 0, got 0) :: [ PASS ] :: Command 'service ipsec stop' (Expected 0, got 0) :: [ PASS ] :: Command 'sleep 10s' (Expected 0, got 0) :: [ LOG ] :: sync: SERVER set flag SERVER_DONE :: [ PASS ] :: Command 'syncSet SERVER_DONE' (Expected 0, got 0) :: [ LOG ] :: sync: SERVER is waiting for flag CLIENT_DONE :: [ LOG ] :: sync: SERVER got flag CLIENT_DONE :: [ PASS ] :: Command 'syncExp CLIENT_DONE' (Expected 0, got 0) :: [ LOG ] :: Duration: 2m 19s :: [ LOG ] :: Assertions: 19 good, 0 bad :: [ PASS ] :: RESULT: bz1315732, bz1219049 - SERVER (down) client :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::: :: [ LOG ] :: bz1315732, bz1219049 - CLIENT :::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::: :: [ LOG ] :: sync: CLIENT is waiting for flag SERVER_READY :: [ LOG ] :: sync: CLIENT got flag SERVER_READY :: [ PASS ] :: Command 'syncExp SERVER_READY' (Expected 0, got 0) :: [ PASS ] :: Command 'service ipsec start' (Expected 0, got 0) :: [ PASS ] :: Command 'sleep 10s' (Expected 0, got 0) :: [ LOG ] :: sync: CLIENT set flag CLIENT_READY :: [ PASS ] :: Command 'syncSet CLIENT_READY' (Expected 0, got 0) :: [ PASS ] :: Command 'ipsec auto --up test' (Expected 0, got 0) :: [ PASS ] :: Printing ipsec status. (Expected 0, got 0) :: [ PASS ] :: ISAKMP SA should be alive. (Expected 0, got 0) :: [ PASS ] :: IPSEC SA should be alive. (Expected 0, got 0) :: [ LOG ] :: sync: CLIENT set flag CLIENT_TEST_UP_DONE :: [ PASS ] :: Command 'syncSet CLIENT_TEST_UP_DONE' (Expected 0, got 0) :: [ LOG ] :: sync: CLIENT is waiting for flag SERVER_TEST_UP_DONE :: [ LOG ] :: sync: CLIENT got flag SERVER_TEST_UP_DONE :: [ PASS ] :: Command 'syncExp SERVER_TEST_UP_DONE' (Expected 0, got 0) :: [ LOG ] :: sync: CLIENT is waiting for flag SERVER_TEST_DOWN_DONE :: [ LOG ] :: sync: CLIENT got flag SERVER_TEST_DOWN_DONE :: [ PASS ] :: Command 'syncExp SERVER_TEST_DOWN_DONE' (Expected 0, got 0) :: [ PASS ] :: Printing ipsec status. (Expected 0, got 0) :: [ PASS ] :: ISAKMP SA should be dead. (Expected 1, got 1) :: [ FAIL ] :: IPSEC SA should be dead. (Expected 1, got 0) :: [ LOG ] :: sync: CLIENT set flag CLIENT_TEST_DOWN_DONE :: [ PASS ] :: Command 'syncSet CLIENT_TEST_DOWN_DONE' (Expected 0, got 0) :: [ LOG ] :: sync: CLIENT is waiting for flag SERVER_DONE :: [ LOG ] :: sync: CLIENT got flag SERVER_DONE :: [ PASS ] :: Command 'syncExp SERVER_DONE' (Expected 0, got 0) :: [ PASS ] :: Command 'service ipsec stop' (Expected 0, got 0) :: [ PASS ] :: Command 'sleep 10s' (Expected 0, got 0) :: [ LOG ] :: sync: CLIENT set flag CLIENT_DONE :: [ PASS ] :: Command 'syncSet CLIENT_DONE' (Expected 0, got 0) :: [ LOG ] :: Duration: 2m 19s :: [ LOG ] :: Assertions: 18 good, 1 bad :: [ FAIL ] :: RESULT: bz1315732, bz1219049 - CLIENT
My guess is that you are seeing the proper behaviour now, but your test case isnt looking at the right data. In the past, we mistakenly did not send a Delete/Notify and the SA lingered. Now, we sent the Delete/Notify on the responder, but since the initiator has been started with ipse cauto --up, it will process the delete, and then immediately initiate a new tunnel because it was instructed to remain "up". (See the thread I listed above on the lists.libreswan.org swan-dev archive) the pluto logs should show if the IPsec SA re-established (expected) or that the old IPsec SA lingered (not expected)
I am proposing blocker? flag since this issue has been discussed both in upstream and between Paul and Jaroslav and the fix was tested via scratch build. However, I am not sure about the latest FailedQA, Hanns could you please shed some light on it?
(In reply to Ondrej Moriš from comment #13) ... > > However, I am not sure about the latest FailedQA, Hanns could you please > shed some light on it? . Hello Red Hat / Ondrej, hmm ... I am not aware that I have set a 'FailedQA' flag in this RHBZ ... ... I cannot 'see' such a flag in my view of this Red Hat bugzilla ... ... i.e. if you think that such a setting was done by me you can revert this flag to the 'correct' setting (whatever 'correct' is ..) ... Hope this helps. Thanks for your attention and support.
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://rhn.redhat.com/errata/RHSA-2016-2603.html