openvpn 2.6.3-1+deb12u1: Arithmetic exception when using --fragment

[darkbasic]

Describe the bug
openvpn server crashes with message Floating point exception on Debian Bookworm 12:

2023-09-26 03:11:53 us=211476 TLS: Initial packet from [AF_INET]94.102.61.34:42523, sid=12121212 12121212
2023-09-26 03:11:53 us=211574 TLS Error: Early negotiation malformed packet
2023-09-26 03:11:53 us=211594 TLS Error: TLS handshake failed

Program received signal SIGFPE, Arithmetic exception.
0x000055555557b698 in optimal_fragment_size (max_frag_size=0, len=156) at ./src/openvpn/fragment.c:307
307     ./src/openvpn/fragment.c: No such file or directory.
(gdb) backtrace
#0  0x000055555557b698 in optimal_fragment_size (max_frag_size=0, len=156) at ./src/openvpn/fragment.c:307
#1  fragment_outgoing (f=0x5555556941e0, buf=buf@entry=0x7fffffffe458, frame=frame@entry=0x7fffffffe1c0) at ./src/openvpn/fragment.c:340
#2  0x0000555555576e5a in encrypt_sign (c=c@entry=0x7fffffffd350, comp_frag=comp_frag@entry=true) at ./src/openvpn/forward.c:641
#3  0x0000555555578355 in process_incoming_tun (c=c@entry=0x7fffffffd350) at ./src/openvpn/forward.c:1462
#4  0x000055555557ab21 in process_io (c=c@entry=0x7fffffffd350) at ./src/openvpn/forward.c:2277
#5  0x00005555555a434c in tunnel_point_to_point (c=0x7fffffffd350) at ./src/openvpn/openvpn.c:94
#6  openvpn_main (argc=2, argv=0x7fffffffe748) at ./src/openvpn/openvpn.c:315
#7  0x00007ffff77531ca in __libc_start_call_main (main=main@entry=0x555555561da0 <main>, argc=argc@entry=2, argv=argv@entry=0x7fffffffe748) at ../sysdeps/nptl/libc_start_call_main.h:58
#8  0x00007ffff7753285 in __libc_start_main_impl (main=0x555555561da0 <main>, argc=2, argv=0x7fffffffe748, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffffffe738) at ../csu/libc-start.c:360
#9  0x0000555555561dd1 in _start ()

Package source code: https://packages.debian.org/source/bookworm/openvpn

To Reproduce
Server config:

fragment 1300
mssfix
port 1194
proto udp
dev tapvpn
ca /etc/openvpn/server/ca.crt
cert /etc/openvpn/server/server.crt
key /etc/openvpn/server/server.key  # This file should be kept secret
dh none
keepalive 10 120
tls-server
tls-version-min 1.2
tls-cipher TLS-ECDHE-ECDSA-WITH-AES-256-GCM-SHA384
cipher AES-256-CBC
persist-key
persist-tun
status /var/log/openvpn/openvpn-status.log
verb 4
explicit-exit-notify 1

Client config:

fragment 1300
mssfix
client
dev tapvpn
proto udp
remote SERVER_IP 1194
resolv-retry infinite
nobind
persist-key
persist-tun
ca /etc/openvpn/client/ca.crt
cert /etc/openvpn/client/niko-casa.crt
key /etc/openvpn/client/niko-casa.key
remote-cert-tls server
cipher AES-256-CBC
verb 4

Expected behavior
Should not crash.

Version information (please complete the following information):

• OS: Debian Bookworm 12
• OpenVPN server version: 2.6.3-1+deb12u1
• OpenVPN client version: 2.6.6-1 (Arch Linux)

Additional context
Happens VERY often.

[darkbasic]

I would like to clarify that 94.102.61.34 is NOT an IP of any authorized client I've created a certificate for. In fact I've issued only a single client certificate and its IP is static. I do not recognize this IP.

[darkbasic]

Since we're at it I also find this warning confusing:

WARNING: if you use --mssfix and --fragment, you should use the "mtu" flag for both or none of of them.

[schwabe]

The warning is valid. the mtu keyword is default when you use mssfix without options but is not for fragment.

[darkbasic]

@schwabe too bad that I cannot set the mtu parameter for fragment in NetworkManager :(

[schwabe]

This not trivial to reproduce. Could you try to reproduce the crash with a higher verboisity? Like with verb 4? I wonder if that is something that is trigger by us getting a PMTU value of zero.

[darkbasic]

As you can see from my configs I'm already using verb 4. If you want I can try to dump the rogue packet which triggers the Early negotiation malformed packet so you can use it to reproduce the issue.

[schwabe]

Can you provide full logs that contain the crash? It seems to be quite easy for you to reproduce while I cannot reproduce it at all. I still stumble quite in the dark what is happening here. Maybe even with do logs withverb 7. You can also provide them to me via email or similar if you don't want to post them on Github.

[darkbasic]

Can you provide full logs that contain the crash?

I already did: everything else was minutes prior to the crash and completely unrelated.

Maybe even with do logs withverb 7. You can also provide them to me via email or similar if you don't want to post them on Github.

I will try with verb 7 to see if things improve. I can also provide the full log since the server has been started, but it will be easier to mail it because I can't bother removing all personal data. I will also provide a dump of the rogue packet which triggers the issue, I think that will be key to reproduce it. My email address is niccolo.belli at linuxsystems.it, ping me there.

[schwabe]

@darkbasic have a you received my ping to your email address? It should have come from my arne@rfc2549.org addresss

[darkbasic]

@schwabe I'm sorry but I had completely missed your email. I've sent you all the logs with verb 7 and a dump of the packet which triggers the floating point exception.

[schwabe]

Thanks for sending hte log with verb 7. That helps to figure out in what state OpenVPN is when the crash happens. This part of the log is interesting:

2023-10-14 20:19:48 us=343163 TLS: tls_pre_encrypt: key_id=4
2023-10-14 20:19:48 us=343221 UDPv4 WRITE [85] to [AF_INET]217.133.41.222:59823: P_DATA_V1 kid=4 DATA len=84
2023-10-14 20:19:48 us=666481 UDPv4 READ [18] from [AF_INET]71.6.134.235:59292: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=4
2023-10-14 20:19:48 us=666537 TLS: Initial packet from [AF_INET]71.6.134.235:59292, sid=12121212 12121212
2023-10-14 20:19:48 us=666575 TLS Error: Early negotiation malformed packet
2023-10-14 20:19:48 us=666593 TLS Error: TLS handshake failed
2023-10-14 20:19:48 us=666608 PID packet_id_free
2023-10-14 20:19:48 us=666647 PID packet_id_free
2023-10-14 20:19:48 us=666663 PID packet_id_free
2023-10-14 20:19:48 us=666699 PID packet_id_init seq_backtrack=64 time_backtrack=15
2023-10-14 20:19:48 us=666738 PID packet_id_init seq_backtrack=64 time_backtrack=15
2023-10-14 20:19:48 us=666764 UDPv4 WRITE [26] to [AF_INET]71.6.134.235:59292: P_??? kid=0 [ ] pid=0 DATA len=12

Somehow after receiving the malformed TLS_RESET_V2 we send a broken packet of 26 bytes.

[flichtenheld]

This was fixed in 2.6.7 but not closed