Baike.dev
Log in
Back to tool/Back to issues
#542·openvpn

The OpenVPN process exits unexpectedly when using the DCO kernel module

Author: kEu3lWPoZ8XRv1O3hEt5xSQQJM0TvH2kCreated Apr 23, 2024Updated Aug 5, 2026
LabelsbugDCOlinux

Describe the bug

Good afternoon!

We encountered such a problem on our installation of an OpenVPN server using the DCO core module. The problem causes the OpenVPN process to crash with disconnecting of all clients connected to OpenVPN. The problem is critical in the conditions of production.

Initial issue's comment inside the ovpn-dco repository: https://github.com/OpenVPN/ovpn-dco/issues/50#issuecomment-2071953786

To Reproduce

  • Occurrence: varies (ranging from "very rare" to several cases per day).
  • Steps to reproduce: unknown. The problem manifests itself on the OpenVPN cluster, each node of which simultaneously serves 500-1500 clients around the clock.

Expected behavior The OpenVPN process does not crash due to a single client's key context initialization error.

Version information (please complete the following information):

  • OpenVPN service version: 2.6.3-1 (deb12u2).
  • The Linux distribution used: Debian Bookworm (v12.5).
  • OpenVPN DCO module version: compiled from the source code (master from 2024.04.16).

Additional context

Example of an OpenVPN logs during a crash (#1):

2024-04-17 13:58:41 us=532843 client.name123/client_source_ip_v4_address:client_source_port peer-id=321 dco_new_key: netlink reports object not found, ovpn-dco unloaded?
2024-04-17 13:58:41 us=532876 client.name123/client_source_ip_v4_address:client_source_port peer-id=321 dco_new_key: failed to send netlink message: No such file or directory (-2)
2024-04-17 13:58:41 us=532912 client.name123/client_source_ip_v4_address:client_source_port peer-id=321 Impossible to install key material in DCO: No such file or directory
2024-04-17 13:58:41 us=532936 client.name123/client_source_ip_v4_address:client_source_port peer-id=321 Exiting due to fatal error
2024-04-17 13:58:41 us=532985 client.name123/client_source_ip_v4_address:client_source_port peer-id=321 Closing DCO interface

Example of an OpenVPN logs during a crash (#2):

2024-04-17 16:05:34 us=166246 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 peer info: IV_SSL=OpenSSL_3.XXX
2024-04-17 16:05:34 us=166386 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 UDPv4 WRITE [311] to [AF_INET]client_source_ip_v4_address:client_source_port: P_CONTROL_V1 kid=1 [ ] pid=1382 DATA len=297
2024-04-17 16:05:34 us=171898 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 UDPv4 READ [74] from [AF_INET]client_source_ip_v4_address:client_source_port: P_ACK_V1 kid=1 [ ] DATA len=64
2024-04-17 16:05:34 us=172148 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 UDPv4 READ [74] from [AF_INET]client_source_ip_v4_address:client_source_port: P_ACK_V1 kid=1 [ ] DATA len=64
2024-04-17 16:05:34 us=172201 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 256 bit ED25519, signature: ED25519
2024-04-17 16:05:34 us=172294 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 dco_install_key: peer_id=465 keyid=1, currently 1 keys installed
2024-04-17 16:05:34 us=172320 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 dco_new_key: slot 1, key-id 1, peer-id 465, cipher AES-256-GCM
2024-04-17 16:05:34 us=172384 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 dco_new_key: netlink reports object not found, ovpn-dco unloaded?
2024-04-17 16:05:34 us=172408 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 dco_new_key: failed to send netlink message: No such file or directory (-2)
2024-04-17 16:05:34 us=172432 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 Impossible to install key material in DCO: No such file or directory
2024-04-17 16:05:34 us=172450 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 Exiting due to fatal error
2024-04-17 16:05:34 us=172513 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 Closing DCO interface
2024-04-17 16:05:34 us=172536 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 net_addr_v4_del: ip_v4_address dev tun0
2024-04-17 16:05:34 us=173286 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 sitnl_send: checking for received messages
2024-04-17 16:05:34 us=173351 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 sitnl_send: rtnl: received 36 bytes
2024-04-17 16:05:34 us=173384 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 net_addr_v6_del: ip_v6_address/112 dev tun0
2024-04-17 16:05:34 us=173510 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 sitnl_send: checking for received messages
2024-04-17 16:05:34 us=173532 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 sitnl_send: rtnl: received 36 bytes
2024-04-17 16:05:34 us=173551 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 close_tun_dco
2024-04-17 16:05:34 us=173581 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 net_iface_del: delete tun0
2024-04-17 16:05:34 us=370712 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 sitnl_send: checking for received messages
2024-04-17 16:05:34 us=370770 client.name123/client_source_ip_v4_address:client_source_port peer-id=465 sitnl_send: rtnl: received 36 bytes

--- OpenVPN process restart goes here

Crash reason:

https://github.com/OpenVPN/openvpn/blob/32e6586687a548174b88b64fe54bfae6c74d4c19/src/openvpn/ssl.c#L1361 ^ M_FATAL causes the process to crash after an unsuccessful attempt to install key material in the DCO module.

Confirmation:

https://github.com/OpenVPN/openvpn/blob/master/src/openvpn/error.h#L142 ^ Calling the msg() procedure with the M_FATAL flag results in an emergency (code 1) shutdown of the process.

Problem fixing scheme:

  • Replace M_FATAL flag with M_WARN in the problem source code location
  • Convert the init_key_contexts procedure into a function that returns bool
  • Return false inside init_key_context in case of failure, otherwise return true
  • Handle in all places (only one was found) using init_key_context, the case of returning false (failed initialization of the key context)
  • Monitor the correct destruction of execution contexts (in order to avoid memory leaks) in all affected code sections

Patch with fix (spot): diff.patch

Patch with fix (full): full_diff.patch

dmesg logs before fixing:

2024-04-17T16:05:27.606710+03:00 openvpn kernel: [69250.222529] ovpn_udp_encap_recv: received data from unknown peer (id: 465)
2024-04-17T16:05:27.950720+03:00 openvpn kernel: [69250.565701] ovpn_udp_encap_recv: received data from unknown peer (id: 465)
2024-04-17T16:05:27.950858+03:00 openvpn kernel: [69250.566003] ovpn_udp_encap_recv: received data from unknown peer (id: 465)
2024-04-17T16:05:28.606691+03:00 openvpn kernel: [69251.220475] ovpn_udp_encap_recv: received data from unknown peer (id: 465)
2024-04-17T16:05:28.606723+03:00 openvpn kernel: [69251.220713] ovpn_udp_encap_recv: received data from unknown peer (id: 465)
2024-04-17T16:05:30.850734+03:00 openvpn kernel: [69253.463873] tun0: deleting peer with id 670, reason 1
2024-04-17T16:05:32.674766+03:00 openvpn kernel: [69255.289142] net_ratelimit: 56 callbacks suppressed
2024-04-17T16:05:32.674919+03:00 openvpn kernel: [69255.289150] ovpn_aead_decrypt: decrypt failed: -74
2024-04-17T16:05:32.674943+03:00 openvpn kernel: [69255.289499] ovpn_decrypt_one: error during decryption for peer 611, key-id 0: -74
2024-04-17T16:05:32.694773+03:00 openvpn kernel: [69255.308232] ovpn_aead_decrypt: decrypt failed: -74
2024-04-17T16:05:32.695002+03:00 openvpn kernel: [69255.308469] ovpn_decrypt_one: error during decryption for peer 611, key-id 0: -74
2024-04-17T16:05:32.695071+03:00 openvpn kernel: [69255.308720] ovpn_aead_decrypt: decrypt failed: -74
2024-04-17T16:05:32.695118+03:00 openvpn kernel: [69255.308974] ovpn_decrypt_one: error during decryption for peer 611, key-id 0: -74
2024-04-17T16:05:32.695233+03:00 openvpn kernel: [69255.309238] ovpn_aead_decrypt: decrypt failed: -74
2024-04-17T16:05:32.695308+03:00 openvpn kernel: [69255.309506] ovpn_decrypt_one: error during decryption for peer 611, key-id 0: -74
2024-04-17T16:05:32.695348+03:00 openvpn kernel: [69255.309820] ovpn_aead_decrypt: decrypt failed: -74
2024-04-17T16:05:32.695397+03:00 openvpn kernel: [69255.310104] ovpn_decrypt_one: error during decryption for peer 611, key-id 0: -74
2024-04-17T16:05:34.190782+03:00 openvpn kernel: [69256.805266] tun0: deleting peer with id 433, reason 0
2024-04-17T16:05:34.190799+03:00 openvpn kernel: [69256.805276] tun0: deleting peer with id 447, reason 0
2024-04-17T16:05:34.190801+03:00 openvpn kernel: [69256.805286] tun0: deleting peer with id 38, reason 0
2024-04-17T16:05:34.190802+03:00 openvpn kernel: [69256.805290] tun0: deleting peer with id 463, reason 0
2024-04-17T16:05:34.190805+03:00 openvpn kernel: [69256.805297] tun0: deleting peer with id 553, reason 0
2024-04-17T16:05:34.190808+03:00 openvpn kernel: [69256.805302] tun0: deleting peer with id 530, reason 0
2024-04-17T16:05:34.190809+03:00 openvpn kernel: [69256.805305] tun0: deleting peer with id 398, reason 0
2024-04-17T16:05:34.190811+03:00 openvpn kernel: [69256.805309] tun0: deleting peer with id 389, reason 0
2024-04-17T16:05:34.190812+03:00 openvpn kernel: [69256.805315] tun0: deleting peer with id 272, reason 0
2024-04-17T16:05:34.190814+03:00 openvpn kernel: [69256.805324] tun0: deleting peer with id 569, reason 0
2024-04-17T16:05:34.190815+03:00 openvpn kernel: [69256.805331] tun0: deleting peer with id 86, reason 0
2024-04-17T16:05:34.190816+03:00 openvpn kernel: [69256.805339] tun0: deleting peer with id 202, reason 0
2024-04-17T16:05:34.190818+03:00 openvpn kernel: [69256.805345] tun0: deleting peer with id 236, reason 0
2024-04-17T16:05:34.190820+03:00 openvpn kernel: [69256.805352] tun0: deleting peer with id 391, reason 0
2024-04-17T16:05:34.190821+03:00 openvpn kernel: [69256.805356] tun0: deleting peer with id 368, reason 0
2024-04-17T16:05:34.190822+03:00 openvpn kernel: [69256.805360] tun0: deleting peer with id 208, reason 0
2024-04-17T16:05:34.190823+03:00 openvpn kernel: [69256.805369] tun0: deleting peer with id 642, reason 0
2024-04-17T16:05:34.190824+03:00 openvpn kernel: [69256.805379] tun0 (unregistering): deleting peer with id 352, reason 0
2024-04-17T16:05:34.190825+03:00 openvpn kernel: [69256.805448] tun0 (unregistering): deleting peer with id 687, reason 0
2024-04-17T16:05:34.190826+03:00 openvpn kernel: [69256.805454] tun0 (unregistering): deleting peer with id 575, reason 0

OpenVPN logs after correction:

2024-04-19 18:56:23 us=669145 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 peer info: IV_SSO=XXX
2024-04-19 18:56:23 us=669315 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 UDPv4 WRITE [315] to [AF_INET]client_source_ip_v4_address:client_source_port: P_CONTROL_V1 kid=1 [ ] pid=1638 DATA len=301
2024-04-19 18:56:23 us=674261 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 UDPv4 READ [74] from [AF_INET]client_source_ip_v4_address:client_source_port: P_ACK_V1 kid=1 [ ] DATA len=64
2024-04-19 18:56:23 us=676230 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 UDPv4 READ [78] from [AF_INET]client_source_ip_v4_address:client_source_port: P_ACK_V1 kid=1 [ ] DATA len=68
2024-04-19 18:56:23 us=676314 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 256 bit ED25519, signature: ED25519
2024-04-19 18:56:23 us=676498 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 dco_install_key: peer_id=475 keyid=1, currently 1 keys installed
2024-04-19 18:56:23 us=676538 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 dco_new_key: slot 1, key-id 1, peer-id 475, cipher AES-256-GCM
2024-04-19 18:56:23 us=676643 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 dco_new_key: netlink reports object not found, ovpn-dco unloaded?
2024-04-19 18:56:23 us=676674 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 dco_new_key: failed to send netlink message: No such file or directory (-2)
2024-04-19 18:56:23 us=676694 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 Impossible to install key material in DCO: No such file or directory
2024-04-19 18:56:23 us=676712 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 TLS Error: Could not initialize key contexts
2024-04-19 18:56:23 us=676729 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 TLS Error: generate_key_expansion failed
2024-04-19 18:56:23 us=676746 client.name123/client_source_ip_v4_address:client_source_port peer-id=475 TLS Error: generate_key_expansion failed
2024-04-19 18:56:24 us=2153 dco_get_peer_stats_multi
2024-04-19 18:56:24 us=2917 dco_parse_peer_multi: parsing message...
2024-04-19 18:56:24 us=2961 dco_update_peer_stat / dco_read_bytes: 2474690
2024-04-19 18:56:24 us=2981 dco_update_peer_stat / dco_write_bytes: 134735523
2024-04-19 18:56:24 us=2998 dco_update_peer_stat / tun_read_bytes: 1965650
2024-04-19 18:56:24 us=3015 NOTE: --mute triggered...

dmesg logs after fixing:

2024-04-19T18:56:23.002300+03:00 openvpn kernel: [81066.439726] tun0: ovpn_decrypt_one: ping receiv
ed from peer with id 320
2024-04-19T18:56:23.046312+03:00 openvpn kernel: [81066.487702] tun0: ovpn_peer_ping: sending ping to peer 310
2024-04-19T18:56:23.046326+03:00 openvpn kernel: [81066.487703] tun0: ovpn_peer_ping: sending ping to peer 9
2024-04-19T18:56:23.046330+03:00 openvpn kernel: [81066.487702] tun0: ovpn_peer_ping: sending ping to peer 84
2024-04-19T18:56:23.046333+03:00 openvpn kernel: [81066.487719] tun0: ovpn_peer_ping: sending ping to peer 14
2024-04-19T18:56:23.050288+03:00 openvpn kernel: [81066.491703] tun0: ovpn_peer_ping: sending ping to peer 311
2024-04-19T18:56:23.058293+03:00 openvpn kernel: [81066.496184] tun0: ovpn_decrypt_one: ping received from peer with id 524
2024-04-19T18:56:23.118301+03:00 openvpn kernel: [81066.556824] tun0: ovpn_decrypt_one: ping received from peer with id 653
2024-04-19T18:56:23.122283+03:00 openvpn kernel: [81066.560031] tun0: ovpn_decrypt_one: ping received from peer with id 90
2024-04-19T18:56:23.218286+03:00 openvpn kernel: [81066.658509] tun0: ovpn_decrypt_one: ping received from peer with id 212
2024-04-19T18:56:23.222284+03:00 openvpn kernel: [81066.661884] tun0: ovpn_decrypt_one: ping received from peer with id 290
2024-04-19T18:56:23.286309+03:00 openvpn kernel: [81066.725031] tun0: ovpn_decrypt_one: ping received from peer with id 651
2024-04-19T18:56:23.306312+03:00 openvpn kernel: [81066.743687] tun0: ovpn_peer_ping: sending ping to peer 370
2024-04-19T18:56:23.306323+03:00 openvpn kernel: [81066.743688] tun0: ovpn_peer_ping: sending ping to peer 277
2024-04-19T18:56:23.306328+03:00 openvpn kernel: [81066.743701] tun0: ovpn_peer_ping: sending ping to peer 628
2024-04-19T18:56:23.306330+03:00 openvpn kernel: [81066.747668] tun0: ovpn_peer_ping: sending ping to peer 653
2024-04-19T18:56:23.306331+03:00 openvpn kernel: [81066.747688] tun0: ovpn_peer_ping: sending ping to peer 290
2024-04-19T18:56:23.358302+03:00 openvpn kernel: [81066.796182] tun0: ovpn_decrypt_one: ping received from peer with id 493
2024-04-19T18:56:23.374312+03:00 openvpn kernel: [81066.814880] tun0: ovpn_decrypt_one: ping received from peer with id 96
2024-04-19T18:56:23.482285+03:00 openvpn kernel: [81066.919873] tun0: ovpn_decrypt_one: ping received from peer with id 395
2024-04-19T18:56:23.486290+03:00 openvpn kernel: [81066.925117] tun0: ovpn_decrypt_one: ping received from peer with id 361
2024-04-19T18:56:23.526293+03:00 openvpn kernel: [81066.966186] tun0: ovpn_decrypt_one: ping received from peer with id 502
2024-04-19T18:56:23.558329+03:00 openvpn kernel: [81066.999665] tun0: ovpn_peer_ping: sending ping to peer 493
2024-04-19T18:56:23.558341+03:00 openvpn kernel: [81066.999664] tun0: ovpn_peer_ping: sending ping to peer 23
2024-04-19T18:56:23.558343+03:00 openvpn kernel: [81066.999665] tun0: ovpn_peer_ping: sending ping to peer 502
2024-04-19T18:56:23.558346+03:00 openvpn kernel: [81066.999665] tun0: ovpn_peer_ping: sending ping to peer 219
2024-04-19T18:56:23.558347+03:00 openvpn kernel: [81066.999667] tun0: ovpn_peer_ping: sending ping to peer 361
2024-04-19T18:56:23.558349+03:00 openvpn kernel: [81066.999667] tun0: ovpn_peer_ping: sending ping to peer 96
2024-04-19T18:56:23.558351+03:00 openvpn kernel: [81066.999679] tun0: ovpn_peer_ping: sending ping to peer 395

Please pay attention to this problem. I will monitor this issue and respond if necessary. Thanks!

Source: OpenVPN/openvpn

View original on GitHubView discussion on GitHub