1741867 – key derivation for pre-shared key failed when md5 is used after updating openssl to 1.1.1c-2

Bug 1741867 - key derivation for pre-shared key failed when md5 is used after updating openssl to 1.1.1c-2

Summary: key derivation for pre-shared key failed when md5 is used after updating open...

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Fedora
Classification:	Fedora
Component:	strongswan
Sub Component:
Version:	31
Hardware:	x86_64
OS:	Linux
Priority:	unspecified
Severity:	medium
Target Milestone:	---
Assignee:	Pavel Šimerda
QA Contact:	Fedora Extras Quality Assurance
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2019-08-16 09:52 UTC by Artur
Modified:	2020-02-27 15:26 UTC (History)
CC List:	3 users (show)
Fixed In Version:
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2020-02-27 15:26:25 UTC
Type:	Bug
Dependent Products:

Attachments	(Terms of Use)
Add an attachment (proposed patch, testcase, etc.)

Description Artur 2019-08-16 09:52:27 UTC

Description of problem:

After updating from openssl-1.1.1b-5 to openssl-1.1.1c-2 strongswan fails to verify pre-shared keys, when using md5 hash (ike and esp set to 3des-md5-modp1024). The error message is "key derivation for pre-shared key failed".

Version-Release number of selected component (if applicable):

strongswan-5.7.2-1
openssl-1.1.1c-2


Steps to Reproduce:

1. update openssl from openssl-1.1.1b-5 to openssl-1.1.1c-2
2. try to establish vpn tunnel with ike=3des-md5-modp1024, esp=3des-md5-modp1024


Actual results (with openssl-1.1.1c-2):

initiating Main Mode IKE_SA testconnection[139] to x.x.x.x
generating ID_PROT request 0 [ SA V V V V V ]
sending packet: from y.y.y.y[500] to x.x.x.x[500] (236 bytes)
received packet: from x.x.x.x[500] to y.y.y.y[500] (120 bytes)
parsed ID_PROT response 0 [ SA V V ]
received FRAGMENTATION vendor ID
received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
selected proposal: IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024
generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
sending packet: from y.y.y.y[500] to x.x.x.x[500] (236 bytes)
received packet: from x.x.x.x[500] to y.y.y.y[500] (224 bytes)
parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
key derivation for pre-shared key failed
generating INFORMATIONAL_V1 request 2960542307 [ N(INVAL_KE) ]
sending packet: from y.y.y.y[500] to x.x.x.x[500] (56 bytes)
establishing connection 'testconnection' failed


Expected results (like with openssl-1.1.1b-5):

initiating Main Mode IKE_SA testconnection[75] to x.x.x.x
generating ID_PROT request 0 [ SA V V V V V ]
sending packet: from y.y.y.y[500] to x.x.x.x[500] (236 bytes)
received packet: from x.x.x.x[500] to y.y.y.y[500] (120 bytes)
parsed ID_PROT response 0 [ SA V V ]
received FRAGMENTATION vendor ID
received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
selected proposal: IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024
generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
sending packet: from y.y.y.y[500] to x.x.x.x[500] (236 bytes)
received packet: from x.x.x.x[500] to y.y.y.y[500] (224 bytes)
parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
sending packet: from y.y.y.y[500] to x.x.x.x[500] (92 bytes)
received packet: from x.x.x.x[500] to y.y.y.y[500] (84 bytes)
parsed ID_PROT response 0 [ ID HASH V ]
received DPD vendor ID
IKE_SA testconnection[75] established between y.y.y.y[y.y.y.y]...x.x.x.x[x.x.x.x]
scheduling reauthentication in 14205s
maximum IKE_SA lifetime 14385s
generating QUICK_MODE request 3081198018 [ HASH SA No KE ID ID ]
sending packet: from y.y.y.y[500] to x.x.x.x[500] (308 bytes)
received packet: from x.x.x.x[500] to y.y.y.y[500] (292 bytes)
parsed QUICK_MODE response 3081198018 [ HASH SA No KE ID ID ]
selected proposal: ESP:3DES_CBC/HMAC_MD5_96/MODP_1024/NO_EXT_SEQ
CHILD_SA testconnection{219} established with SPIs qqqqqqqq_i pppppppp_o and TS s.s.s.s/24 === t.t.t.t/24
connection 'testconnection' established successfully


Additional info:
I'm not sure if it can/should be fixed in strongswan or openssl.

Comment 1 Ben Cotton 2019-10-31 18:53:19 UTC

This message is a reminder that Fedora 29 is nearing its end of life.
Fedora will stop maintaining and issuing updates for Fedora 29 on 2019-11-26.
It is Fedora's policy to close all bug reports from releases that are no longer
maintained. At that time this bug will be closed as EOL if it remains open with a
Fedora 'version' of '29'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 29 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 2 Ben Cotton 2019-11-27 23:20:57 UTC

Fedora 29 changed to end-of-life (EOL) status on 2019-11-26. Fedora 29 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.

Comment 3 Artur 2020-01-20 10:05:41 UTC

Re-opening as it still does not work in Fedora 31.
I'd like at least to see the statement, that this is not going to be fixed.

Again - exemplary strongswan connection config and the effect in log

conn testconn
    left=192.168.1.65
    leftid=192.168.1.65
    leftsubnet=192.168.2.0/24
    right=192.168.1.99
    rightid=192.168.1.99
    rightsubnet=192.168.3.0/24
    auto=route
    authby=secret
    ike=3des-md5-modp1024
    esp=3des-md5-modp1024
    lifetime=3600s
    ikelifetime=14400s
    margintime = 3m
    dpdaction=restart
    dpddelay=30s
    dpdtimeout=120s
    keyexchange=ikev1


Jan 20 10:58:57 somehost charon[3889]: 10[NET] received packet: from 192.168.1.99[500] to 192.168.1.65[500] (284 bytes)
Jan 20 10:58:57 somehost charon[3889]: 10[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V V V ]
Jan 20 10:58:57 somehost charon[3889]: 10[IKE] received NAT-T (RFC 3947) vendor ID
Jan 20 10:58:57 somehost charon[3889]: 10[IKE] received draft-ietf-ipsec-nat-t-ike-03 vendor ID
Jan 20 10:58:57 somehost charon[3889]: 10[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID
Jan 20 10:58:57 somehost charon[3889]: 10[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Jan 20 10:58:57 somehost charon[3889]: 10[ENC] received unknown vendor ID: 16:f6:ca:16:e4:a4:06:6d:83:82:1a:0f:0a:ea:a8:62
Jan 20 10:58:57 somehost charon[3889]: 10[IKE] received draft-ietf-ipsec-nat-t-ike-00 vendor ID
Jan 20 10:58:57 somehost charon[3889]: 10[IKE] received DPD vendor ID
Jan 20 10:58:57 somehost charon[3889]: 10[IKE] received FRAGMENTATION vendor ID
Jan 20 10:58:57 somehost charon[3889]: 10[IKE] received FRAGMENTATION vendor ID
Jan 20 10:58:57 somehost charon[3889]: 10[ENC] received unknown vendor ID: 82:99:03:17:57:a3:60:82:c6:a6:21:de:00:00:00:00
Jan 20 10:58:57 somehost charon[3889]: 10[IKE] 192.168.1.99 is initiating a Main Mode IKE_SA
Jan 20 10:58:57 somehost charon[3889]: 10[CFG] selected proposal: IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024
Jan 20 10:58:57 somehost charon[3889]: 10[ENC] generating ID_PROT response 0 [ SA V V V V ]
Jan 20 10:58:57 somehost charon[3889]: 10[NET] sending packet: from 192.168.1.65[500] to 192.168.1.99[500] (156 bytes)
Jan 20 10:58:57 somehost charon[3889]: 09[NET] received packet: from 192.168.1.99[500] to 192.168.1.65[500] (220 bytes)
Jan 20 10:58:57 somehost charon[3889]: 09[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Jan 20 10:58:57 somehost charon[3889]: 09[IKE] key derivation for pre-shared key failed
Jan 20 10:58:57 somehost charon[3889]: 09[ENC] generating INFORMATIONAL_V1 request 3884519587 [ N(INVAL_KE) ]
Jan 20 10:58:57 somehost charon[3889]: 09[NET] sending packet: from 192.168.1.65[500] to 192.168.1.99[500] (56 bytes)

Comment 4 Artur 2020-01-20 10:21:22 UTC

More detailed log output from IKE, maybe helpful:

Jan 20 11:07:13 somehost charon[3889]: 14[NET] received packet: from 192.168.1.99[500] to 192.168.1.65[500] (284 bytes)
Jan 20 11:07:13 somehost charon[3889]: 14[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V V V ]
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received NAT-T (RFC 3947) vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received draft-ietf-ipsec-nat-t-ike-03 vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[ENC] received unknown vendor ID: 16:f6:ca:16:e4:a4:06:6d:83:82:1a:0f:0a:ea:a8:62
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received draft-ietf-ipsec-nat-t-ike-00 vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received DPD vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received FRAGMENTATION vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received FRAGMENTATION vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[ENC] received unknown vendor ID: 82:99:03:17:57:a3:60:82:c6:a6:21:de:00:00:00:00
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] 192.168.1.99 is initiating a Main Mode IKE_SA
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] IKE_SA (unnamed)[94] state change: CREATED => CONNECTING
Jan 20 11:07:13 somehost charon[3889]: 14[CFG] selected proposal: IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] sending XAuth vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] sending DPD vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] sending FRAGMENTATION vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] sending NAT-T (RFC 3947) vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[ENC] generating ID_PROT response 0 [ SA V V V V ]
Jan 20 11:07:13 somehost charon[3889]: 14[NET] sending packet: from 192.168.1.65[500] to 192.168.1.99[500] (156 bytes)
Jan 20 11:07:13 somehost charon[3889]: 15[NET] received packet: from 192.168.1.99[500] to 192.168.1.65[500] (220 bytes)
Jan 20 11:07:13 somehost charon[Jan 20 11:07:13 somehost charon[3889]: 14[NET] received packet: from 192.168.1.99[500] to 192.168.1.65[500] (284 bytes)
Jan 20 11:07:13 somehost charon[3889]: 14[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V V V ]
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received NAT-T (RFC 3947) vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received draft-ietf-ipsec-nat-t-ike-03 vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[ENC] received unknown vendor ID: 16:f6:ca:16:e4:a4:06:6d:83:82:1a:0f:0a:ea:a8:62
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received draft-ietf-ipsec-nat-t-ike-00 vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received DPD vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received FRAGMENTATION vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] received FRAGMENTATION vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[ENC] received unknown vendor ID: 82:99:03:17:57:a3:60:82:c6:a6:21:de:00:00:00:00
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] 192.168.1.99 is initiating a Main Mode IKE_SA
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] IKE_SA (unnamed)[94] state change: CREATED => CONNECTING
Jan 20 11:07:13 somehost charon[3889]: 14[CFG] selected proposal: IKE:3DES_CBC/HMAC_MD5_96/PRF_HMAC_MD5/MODP_1024
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] sending XAuth vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] sending DPD vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] sending FRAGMENTATION vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[IKE] sending NAT-T (RFC 3947) vendor ID
Jan 20 11:07:13 somehost charon[3889]: 14[ENC] generating ID_PROT response 0 [ SA V V V V ]
Jan 20 11:07:13 somehost charon[3889]: 14[NET] sending packet: from 192.168.1.65[500] to 192.168.1.99[500] (156 bytes)
Jan 20 11:07:13 somehost charon[3889]: 15[NET] received packet: from 192.168.1.99[500] to 192.168.1.65[500] (220 bytes)
Jan 20 11:07:13 somehost charon[3889]: 15[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] natd_chunk => 22 bytes @ 0x7ff683a16b50
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]    0: B4 06 39 50 C4 7A 63 BF C6 C0 7D 80 8B CD 2B 6F  ..9P.zc...}...+o
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]   16: C0 A8 01 41 01 F4                                ...A..
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] natd_hash => 16 bytes @ 0x7ff644004dc0
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]    0: AC 22 BD 73 84 F1 04 D9 83 91 78 63 66 5C CC E1  .".s......xcf\..
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] natd_chunk => 22 bytes @ 0x7ff683a16b50
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]    0: B4 06 39 50 C4 7A 63 BF C6 C0 7D 80 8B CD 2B 6F  ..9P.zc...}...+o
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]   16: C0 A8 01 63 01 F4                                ...c..
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] natd_hash => 16 bytes @ 0x7ff644008a50
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]    0: 5A 34 CA 5B 6C 66 B1 22 74 13 AA D9 E6 B4 A4 71  Z4.[lf."t......q
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] precalculated src_hash => 16 bytes @ 0x7ff644008a50
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]    0: 5A 34 CA 5B 6C 66 B1 22 74 13 AA D9 E6 B4 A4 71  Z4.[lf."t......q
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] precalculated dst_hash => 16 bytes @ 0x7ff644004dc0
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]    0: AC 22 BD 73 84 F1 04 D9 83 91 78 63 66 5C CC E1  .".s......xcf\..
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] received dst_hash => 16 bytes @ 0x7ff644005f50
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]    0: AC 22 BD 73 84 F1 04 D9 83 91 78 63 66 5C CC E1  .".s......xcf\..
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] received src_hash => 16 bytes @ 0x7ff644008b10
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]    0: 5A 34 CA 5B 6C 66 B1 22 74 13 AA D9 E6 B4 A4 71  Z4.[lf."t......q
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] shared Diffie Hellman secret => 128 bytes @ 0x7ff644003ae0
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]    0: 45 CE 54 9D C8 6D 5E D5 86 13 55 92 67 28 9D 32  E.T..m^...U.g(.2
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]   16: 14 80 D4 42 0E 54 FE 2B 67 6D 0A 11 8F 23 10 31  ...B.T.+gm...#.1
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]   32: D2 70 75 64 9D C9 4F 97 81 93 B5 81 F2 24 09 4B  .pud..O......$.K
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]   48: 19 93 5B 58 91 4E 55 F8 A6 7F 6F 3B 77 F1 2F F5  ..[X.NU...o;w./.
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]   64: 05 87 ED 08 47 6D 1E 19 A7 62 31 BD 58 AE 3A B8  ....Gm...b1.X.:.
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]   80: BD 4E D7 B6 32 72 1F 33 ED D4 89 B2 4B 3A BF C6  .N..2r.3....K:..
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]   96: D7 1B 5B F2 70 D3 95 B4 2C E2 43 DF D5 19 17 8A  ..[.p...,.C.....
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]  112: 04 D5 59 93 A5 A8 17 39 38 8A 8A 60 42 04 0C 85  ..Y....98..`B...
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] key derivation for pre-shared key failed
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] queueing INFORMATIONAL task
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] activating new tasks
Jan 20 11:07:13 somehost charon[3889]: 15[IKE]   activating INFORMATIONAL task
Jan 20 11:07:13 somehost charon[3889]: 15[ENC] generating INFORMATIONAL_V1 request 4075161683 [ N(INVAL_KE) ]
Jan 20 11:07:13 somehost charon[3889]: 15[NET] sending packet: from 192.168.1.65[500] to 192.168.1.99[500] (56 bytes)
Jan 20 11:07:13 somehost charon[3889]: 15[IKE] IKE_SA (unnamed)[94] state change: CONNECTING => DESTROYING

Comment 5 Artur 2020-02-06 16:25:28 UTC

It looks like it will be resolved in strongswan 5.8.2. I will check again and close this bug when 5.8.2 is pushed to the official dnf repository.

Comment 6 Artur 2020-02-27 15:25:20 UTC

Works with strongswan 5.8.2. Closing this.

Note You need to log in before you can comment on or make changes to this bug.