Opened 3 years ago

Last modified 3 years ago

#915 new Bug / Defect

--cipher setting should be "what is in the config", not "what was negotiated in a previous connect"

Reported by: tincantech Owned by:
Priority: major Milestone:
Component: Generic / unclassified Version: OpenVPN 2.4.0 (Community Ed)
Severity: Not set (select this one, unless your'e a OpenVPN developer) Keywords:
Cc:

Attachments (2)

srvlog.txt (44.5 KB) - added by tincantech 3 years ago.
clilog.txt (24.9 KB) - added by tincantech 3 years ago.

Download all attachments as: .zip

Change History (4)

comment:1 Changed 3 years ago by Steffan Karger

Thanks for creating a separate ticket for this. Now that I re-read your description, I think this is the same problem as #906 (sorry...).

If that is the case, this has been resolved as part of that ticket. Could you maybe re-test this with current master or release/2.4 ?

comment:2 Changed 3 years ago by tincantech

Replying to syzzer:

Thanks for creating a separate ticket for this. Now that I re-read your description, I think this is the same problem as #906 (sorry...).

No problem ;-)

Testing confirms the problem still exists.
(using fully up-to-date binary)

Method:

Start default settings server and client with cipher negotiation enabled.

Connection established and cipher negotiated to AES-256-GCM

Edit server.conf enable --ncp-disable (disable cipher negotiation)

Restart server (kill -1 $server.pid)

Watch the implosion ;-)

Notes:

--proto tcp
Time is slightly out of sync between srv & cli but these logs are real
Full logs appended as attachments

This is slightly different to the original email as --cipher is not defined
in either config so BF-CBC is used by default.


Server config (git_master built today, full details in log file)

# Start like so, then uncomment ncp-disable and restart server 
;ncp-disable

persist-key
persist-tun
client-to-client
verb 4

cd /etc/openvpn
dev tuns108
port 11948
proto tcp

server 10.8.0.0 255.255.255.0
server-ipv6 12fc:1918::10:8:0:0/112

keepalive 10 30
comp-lzo no
push "comp-lzo no"

client-config-dir defaults/ccd
ccd-exclusive

tls-auth defaults/ta.key 0
dh defaults/dh-4096b.pem
ca defaults/ca.crt
cert defaults/defaults.crt
key defaults/defaults.key  # This file should be kept secret

Client config (git_master built today, full details in log file)

dev tun108
nobind
client
remote-cert-tls server
remote *** 11948 tcp
verb 4

Server log (Snippet)

Fri Jul 14 13:15:33 2017 us=742089 OpenVPN 2.5_git [git:master/f9ebfe1b5a011e55] x86_64-unknown-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Jul 14 2017
Fri Jul 14 13:15:33 2017 us=742174 library versions: OpenSSL 1.0.1f 6 Jan 2014, LZO 2.06

..

Fri Jul 14 13:16:13 2017 us=601035 defaultc03/CLI-IP:4666 SENT CONTROL [defaultc03]: 'PUSH_REPLY,comp-lzo no,tun-ipv6,route 10.8.0.0 255.255.255.0,topology net30,ping 10,ping-restart 30,ifconfig-ipv6 12fc:1918::10:8:0:226/112 12fc:1918::10:8:0:1,ifconfig 10.8.0.6 10.8.0.5,peer-id 0,cipher AES-256-GCM' (status=1)
Fri Jul 14 13:16:13 2017 us=601090 defaultc03/CLI-IP:4666 Data Channel: using negotiated cipher 'AES-256-GCM'
Fri Jul 14 13:16:13 2017 us=601156 defaultc03/CLI-IP:4666 Data Channel MTU parms [ L:1552 D:1450 EF:52 EB:406 ET:0 EL:3 ]
Fri Jul 14 13:16:13 2017 us=601391 defaultc03/CLI-IP:4666 Data Channel Encrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
Fri Jul 14 13:16:13 2017 us=601430 defaultc03/CLI-IP:4666 Data Channel Decrypt: Cipher 'AES-256-GCM' initialized with 256 bit key


*** Now edit server.conf to include --ncp-disable && kill -1 $server.pid ***


Fri Jul 14 13:16:47 2017 us=198077 TCP/UDP: Closing socket
Fri Jul 14 13:16:47 2017 us=198629 TCP/UDP: Closing socket
Fri Jul 14 13:16:47 2017 us=198764 /sbin/route del -net 10.8.0.0 netmask 255.255.255.0
Fri Jul 14 13:16:47 2017 us=201283 Closing TUN/TAP interface
Fri Jul 14 13:16:47 2017 us=201386 /sbin/ifconfig tuns108 0.0.0.0
Fri Jul 14 13:16:47 2017 us=204207 /sbin/ifconfig tuns108 del 12fc:1918::10:8:0:1/112
Fri Jul 14 13:16:47 2017 us=243402 SIGHUP[hard,] received, process restarting


*** Client reconnects still using AES-256-GCM ***


Fri Jul 14 13:16:53 2017 us=325961 CLI-IP:2352 peer info: IV_VER=2.5_git
Fri Jul 14 13:16:53 2017 us=326085 CLI-IP:2352 peer info: IV_PLAT=linux
Fri Jul 14 13:16:53 2017 us=326118 CLI-IP:2352 peer info: IV_PROTO=2
Fri Jul 14 13:16:53 2017 us=326151 CLI-IP:2352 peer info: IV_NCP=2
Fri Jul 14 13:16:53 2017 us=326182 CLI-IP:2352 peer info: IV_LZ4=1
Fri Jul 14 13:16:53 2017 us=326213 CLI-IP:2352 peer info: IV_LZ4v2=1
Fri Jul 14 13:16:53 2017 us=326243 CLI-IP:2352 peer info: IV_LZO=1
Fri Jul 14 13:16:53 2017 us=326266 CLI-IP:2352 peer info: IV_COMP_STUB=1
Fri Jul 14 13:16:53 2017 us=326289 CLI-IP:2352 peer info: IV_COMP_STUBv2=1
Fri Jul 14 13:16:53 2017 us=326311 CLI-IP:2352 peer info: IV_TCPNL=1
Fri Jul 14 13:16:53 2017 us=326439 CLI-IP:2352 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1544', remote='link-mtu 1552'
Fri Jul 14 13:16:53 2017 us=326482 CLI-IP:2352 WARNING: 'cipher' is used inconsistently, local='cipher BF-CBC', remote='cipher AES-256-GCM'
Fri Jul 14 13:16:53 2017 us=326512 CLI-IP:2352 WARNING: 'auth' is used inconsistently, local='auth SHA1', remote='auth [null-digest]'
Fri Jul 14 13:16:53 2017 us=326541 CLI-IP:2352 WARNING: 'keysize' is used inconsistently, local='keysize 128', remote='keysize 256'
Fri Jul 14 13:16:53 2017 us=326832 CLI-IP:2352 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Fri Jul 14 13:16:53 2017 us=326861 CLI-IP:2352 WARNING: INSECURE cipher with block size less than 128 bit (64 bit).  This allows attacks like SWEET32.  Mitigate by using a --cipher with a larger block size (e.g. AES-256-CBC).
Fri Jul 14 13:16:53 2017 us=326888 CLI-IP:2352 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Fri Jul 14 13:16:53 2017 us=326977 CLI-IP:2352 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Fri Jul 14 13:16:53 2017 us=327003 CLI-IP:2352 WARNING: INSECURE cipher with block size less than 128 bit (64 bit).  This allows attacks like SWEET32.  Mitigate by using a --cipher with a larger block size (e.g. AES-256-CBC).
Fri Jul 14 13:16:53 2017 us=327028 CLI-IP:2352 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Fri Jul 14 13:16:53 2017 us=327052 CLI-IP:2352 WARNING: cipher with small block size in use, reducing reneg-bytes to 64MB to mitigate SWEET32 attacks.
Fri Jul 14 13:16:53 2017 us=329010 CLI-IP:2352 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Fri Jul 14 13:16:53 2017 us=329088 CLI-IP:2352 [defaultc03] Peer Connection Initiated with [AF_INET]CLI-IP:2352
Fri Jul 14 13:16:53 2017 us=329195 defaultc03/CLI-IP:2352 OPTIONS IMPORT: reading client specific options from: defaults/ccd/defaultc03
Fri Jul 14 13:16:53 2017 us=329369 defaultc03/CLI-IP:2352 MULTI_sva: pool returned IPv4=10.8.0.6, IPv6=12fc:1918::10:8:0:1000
Fri Jul 14 13:16:53 2017 us=329418 defaultc03/CLI-IP:2352 MULTI_sva: push_ifconfig_ipv6 12fc:1918::10:8:0:226/112
Fri Jul 14 13:16:53 2017 us=329568 defaultc03/CLI-IP:2352 MULTI: Learn: 10.8.0.6 -> defaultc03/CLI-IP:2352
Fri Jul 14 13:16:53 2017 us=329597 defaultc03/CLI-IP:2352 MULTI: primary virtual IP for defaultc03/CLI-IP:2352: 10.8.0.6
Fri Jul 14 13:16:53 2017 us=329629 defaultc03/CLI-IP:2352 MULTI: Learn: 12fc:1918::10:8:0:226 -> defaultc03/CLI-IP:2352
Fri Jul 14 13:16:53 2017 us=329657 defaultc03/CLI-IP:2352 MULTI: primary virtual IPv6 for defaultc03/CLI-IP:2352: 12fc:1918::10:8:0:226
Fri Jul 14 13:16:54 2017 us=480650 defaultc03/CLI-IP:2352 PUSH: Received control message: 'PUSH_REQUEST'
Fri Jul 14 13:16:54 2017 us=480894 defaultc03/CLI-IP:2352 SENT CONTROL [defaultc03]: 'PUSH_REPLY,comp-lzo no,tun-ipv6,route 10.8.0.0 255.255.255.0,topology net30,ping 10,ping-restart 30,ifconfig-ipv6 12fc:1918::10:8:0:226/112 12fc:1918::10:8:0:1,ifconfig 10.8.0.6 10.8.0.5,peer-id 0' (status=1)
Fri Jul 14 13:16:54 2017 us=568385 defaultc03/CLI-IP:2352 Authenticate/Decrypt packet error: packet HMAC authentication failed
Fri Jul 14 13:16:54 2017 us=568533 defaultc03/CLI-IP:2352 Fatal decryption error (process_incoming_link), restarting
Fri Jul 14 13:16:54 2017 us=568584 defaultc03/CLI-IP:2352 SIGUSR1[soft,decryption-error] received, client-instance restarting
Fri Jul 14 13:16:54 2017 us=568961 TCP/UDP: Closing socket

Client log initial connection (Snippet)

Fri Jul 14 13:14:51 2017 us=646995 OpenVPN 2.5_git [git:master/f9ebfe1b5a011e55] x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Jul 14 2017
Fri Jul 14 13:14:51 2017 us=647032 library versions: OpenSSL 1.1.0f  25 May 2017, LZO 2.10

..

Fri Jul 14 13:14:56 2017 us=110696 PUSH: Received control message: 'PUSH_REPLY,comp-lzo no,tun-ipv6,route 10.8.0.0 255.255.255.0,topology net30,ping 10,ping-restart 30,ifconfig-ipv6 12fc:1918::10:8:0:226/112 12fc:1918::10:8:0:1,ifconfig 10.8.0.6 10.8.0.5,peer-id 0,cipher AES-256-GCM'
Fri Jul 14 13:14:56 2017 us=110757 Note: option tun-ipv6 is ignored because modern operating systems do not need special IPv6 tun handling anymore.
Fri Jul 14 13:14:56 2017 us=110803 OPTIONS IMPORT: timers and/or timeouts modified
Fri Jul 14 13:14:56 2017 us=110809 OPTIONS IMPORT: compression parms modified
Fri Jul 14 13:14:56 2017 us=110815 OPTIONS IMPORT: --ifconfig/up options modified
Fri Jul 14 13:14:56 2017 us=110819 OPTIONS IMPORT: route options modified
Fri Jul 14 13:14:56 2017 us=110823 OPTIONS IMPORT: peer-id set
Fri Jul 14 13:14:56 2017 us=110828 OPTIONS IMPORT: adjusting link_mtu to 1626
Fri Jul 14 13:14:56 2017 us=110832 OPTIONS IMPORT: data channel crypto options modified
Fri Jul 14 13:14:56 2017 us=110838 Data Channel: using negotiated cipher 'AES-256-GCM'
Fri Jul 14 13:14:56 2017 us=110849 Data Channel MTU parms [ L:1554 D:1450 EF:54 EB:406 ET:0 EL:3 ]
Fri Jul 14 13:14:56 2017 us=110915 Data Channel Encrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
Fri Jul 14 13:14:56 2017 us=110923 Data Channel Decrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
Fri Jul 14 13:14:56 2017 us=111050 ROUTE_GATEWAY 10.10.201.1/255.255.255.0 IFACE=eth0 HWADDR=00:15:5d:48:6e:01
Fri Jul 14 13:14:56 2017 us=111253 TUN/TAP device tun108 opened
Fri Jul 14 13:14:56 2017 us=111266 TUN/TAP TX queue length set to 100
Fri Jul 14 13:14:56 2017 us=111276 do_ifconfig, tt->did_ifconfig_ipv6_setup=1
Fri Jul 14 13:14:56 2017 us=111289 /usr/bin/ifconfig tun108 10.8.0.6 pointopoint 10.8.0.5 mtu 1500
Fri Jul 14 13:14:56 2017 us=136522 /usr/bin/ifconfig tun108 add 12fc:1918::10:8:0:226/112
Fri Jul 14 13:14:56 2017 us=137451 /usr/bin/route add -net 10.8.0.0 netmask 255.255.255.0 gw 10.8.0.5
Fri Jul 14 13:14:56 2017 us=154507 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Fri Jul 14 13:14:56 2017 us=154552 Initialization Sequence Completed

Client Log reconnecting (Snippet)

Fri Jul 14 13:15:36 2017 us=990716 PUSH: Received control message: 'PUSH_REPLY,comp-lzo no,tun-ipv6,route 10.8.0.0 255.255.255.0,topology net30,ping 10,ping-restart 30,ifconfig-ipv6 12fc:1918::10:8:0:226/112 12fc:1918::10:8:0:1,ifconfig 10.8.0.6 10.8.0.5,peer-id 0'
Fri Jul 14 13:15:36 2017 us=990844 Note: option tun-ipv6 is ignored because modern operating systems do not need special IPv6 tun handling anymore.
Fri Jul 14 13:15:36 2017 us=990911 OPTIONS IMPORT: timers and/or timeouts modified
Fri Jul 14 13:15:36 2017 us=990940 OPTIONS IMPORT: compression parms modified
Fri Jul 14 13:15:36 2017 us=990965 OPTIONS IMPORT: --ifconfig/up options modified
Fri Jul 14 13:15:36 2017 us=990988 OPTIONS IMPORT: route options modified
Fri Jul 14 13:15:36 2017 us=991011 OPTIONS IMPORT: peer-id set
Fri Jul 14 13:15:36 2017 us=991033 OPTIONS IMPORT: adjusting link_mtu to 1627
Fri Jul 14 13:15:36 2017 us=991065 Data Channel MTU parms [ L:1555 D:1450 EF:55 EB:406 ET:0 EL:3 ]
Fri Jul 14 13:15:36 2017 us=991151 Data Channel Encrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
Fri Jul 14 13:15:36 2017 us=991181 Data Channel Decrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
Fri Jul 14 13:15:36 2017 us=991325 ROUTE_GATEWAY 10.10.201.1/255.255.255.0 IFACE=eth0 HWADDR=00:15:5d:48:6e:01
Fri Jul 14 13:15:36 2017 us=991980 TUN/TAP device tun108 opened
Fri Jul 14 13:15:36 2017 us=992035 TUN/TAP TX queue length set to 100
Fri Jul 14 13:15:36 2017 us=992069 do_ifconfig, tt->did_ifconfig_ipv6_setup=1
Fri Jul 14 13:15:36 2017 us=992104 /usr/bin/ifconfig tun108 10.8.0.6 pointopoint 10.8.0.5 mtu 1500
Fri Jul 14 13:15:36 2017 us=993224 /usr/bin/ifconfig tun108 add 12fc:1918::10:8:0:226/112
Fri Jul 14 13:15:36 2017 us=994103 /usr/bin/route add -net 10.8.0.0 netmask 255.255.255.0 gw 10.8.0.5
Fri Jul 14 13:15:36 2017 us=994802 Initialization Sequence Completed
Fri Jul 14 13:15:37 2017 us=35444 Connection reset, restarting [0]
Fri Jul 14 13:15:37 2017 us=35698 TCP/UDP: Closing socket
Fri Jul 14 13:15:37 2017 us=35765 /usr/bin/route del -net 10.8.0.0 netmask 255.255.255.0
Fri Jul 14 13:15:37 2017 us=36601 Closing TUN/TAP interface
Fri Jul 14 13:15:37 2017 us=36665 /usr/bin/ifconfig tun108 0.0.0.0
Fri Jul 14 13:15:37 2017 us=37803 /usr/bin/ifconfig tun108 del 12fc:1918::10:8:0:226/112
Fri Jul 14 13:15:37 2017 us=49265 SIGUSR1[soft,connection-reset] received, process restarting
Fri Jul 14 13:15:37 2017 us=49316 Restart pause, 5 second(s)
^CFri Jul 14 13:15:39 2017 us=975371 SIGINT[hard,init_instance] received, process exiting
Last edited 3 years ago by tincantech (previous) (diff)

Changed 3 years ago by tincantech

Attachment: srvlog.txt added

Changed 3 years ago by tincantech

Attachment: clilog.txt added
Note: See TracTickets for help on using tickets.