search

opnsense / core

OPNsense GUI, API and systems backend
https://opnsense.org/
BSD 2-Clause "Simplified" License
3.28k stars 727 forks source link

Cron: Restart IPsec service does stop but not start the service #7518

Open stumbaumr opened 3 months ago

stumbaumr commented 3 months ago

Important notices

Before you add a new report, we ask you kindly to acknowledge the following:

Describe the bug

I use the System-> Settings-> Cron funktionality to restart the IPsec service everyday at 01:05 to empty the virtual pools. The restart just only stops the IPsec service - the start does not work and I end up with a stopped IPsec service and no VPN functionality.

Since I upgraded from 22.7.11 to 24.1.8 in one go (as soon as the new way of doing IPsec was usable to me) using opnsense-revert to identify at what point it broke is rather impossible. So I deleted the cron config and rebuilt it and it is still broken in 24.1.8.

Tip: to validate your setup was working with the previous version, use opnsense-revert (https://docs.opnsense.org/manual/opnsense_tools.html#opnsense-revert)

To Reproduce

Steps to reproduce the behavior:

  1. Go to System-> Settings-> Cron
  2. Add a cron job to "Restart IPsec service" and try to use that cut-off drop-down while doing that...
  3. Set the time to 01:05 and stay up at night to watch it happen - then start IPsec manually

Expected behavior

Restart just restart and not stop and not start the IPsec service

Describe alternatives you considered

I turned that cron job off now and to a manual restart in the morning or evening with informing my users beforehand...

Screenshots

grafik

Relevant log files

Service being shutdown but not started again - then at 07:11 doing a manual start...

<30>1 2024-06-08T00:46:22+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 15[CFG] <943dd117-0378-487e-8a3f-ce64ce7f212a|541> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_521/NO_EXT_SEQ
<30>1 2024-06-08T00:48:09+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 09[CFG] <fedba488-6e95-ipsec_20240608.log...skipping...
<30>1 2024-06-08T00:00:05+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 14[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|542> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ
<30>1 2024-06-08T00:08:25+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 11[CFG] <943dd117-0378-487e-8a3f-ce64ce7f212a|541> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_521/NO_EXT_SEQ
<30>1 2024-06-08T00:17:53+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 13[CFG] <943dd117-0378-487e-8a3f-ce64ce7f212a|541> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_521/NO_EXT_SEQ
<30>1 2024-06-08T00:23:55+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 06[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|542> selected proposal: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/ECP_256
<30>1 2024-06-08T00:24:09+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="2"] 07[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|543> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ
<30>1 2024-06-08T00:27:26+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 11[CFG] <943dd117-0378-487e-8a3f-ce64ce7f212a|541> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_521/NO_EXT_SEQ
<30>1 2024-06-08T00:31:33+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 06[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|539> selected proposal: ESP:AES_GCM_16_256/ECP_384/NO_EXT_SEQ
<30>1 2024-06-08T00:32:34+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 13[CFG] <545> selected proposal: IKE:AES_CBC_256/HMAC_SHA2_512_256/PRF_HMAC_SHA2_512/ECP_384
<30>1 2024-06-08T00:33:04+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="2"] 09[JOB] <545> deleting half open IKE_SA with 43.157.64.235 after timeout
<30>1 2024-06-08T00:36:55+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 09[CFG] <943dd117-0378-487e-8a3f-ce64ce7f212a|541> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_521/NO_EXT_SEQ
<30>1 2024-06-08T00:39:16+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 08[CFG] <548> selected proposal: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_3072
<30>1 2024-06-08T00:39:16+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="2"] 08[CFG] <549> selected proposal: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_3072
<30>1 2024-06-08T00:39:16+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="3"] 08[LIB] <549> DH public value is malformed
<30>1 2024-06-08T00:46:22+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 15[CFG] <943dd117-0378-487e-8a3f-ce64ce7f212a|541> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_521/NO_EXT_SEQ
<30>1 2024-06-08T00:48:09+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 09[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|543> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ
<30>1 2024-06-08T00:55:52+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 10[CFG] <943dd117-0378-487e-8a3f-ce64ce7f212a|541> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_521/NO_EXT_SEQ
<30>1 2024-06-08T01:05:00+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="1"] 00[DMN] SIGTERM received, shutting down
<30>1 2024-06-08T01:05:00+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="2"] 00[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|543> sending RADIUS Accounting-Request to server 'server1'
<30>1 2024-06-08T01:05:00+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="3"] 00[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|543> received RADIUS Accounting-Response from server 'server1'
<30>1 2024-06-08T01:05:02+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="4"] 00[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|543> lease 2a01:138:9004:2032::25 by 'twaibel' went offline
<30>1 2024-06-08T01:05:02+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="5"] 00[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|543> lease 10.20.32.37 by 'twaibel' went offline
<30>1 2024-06-08T01:05:02+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="6"] 00[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|539> sending RADIUS Accounting-Request to server 'server1'
<30>1 2024-06-08T01:05:02+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="7"] 00[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|539> received RADIUS Accounting-Response from server 'server1'
<30>1 2024-06-08T01:05:03+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="8"] 00[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|539> lease 2a01:138:9004:2032::29 by 'jjaeger' went offline
<30>1 2024-06-08T01:05:03+02:00 opnsense01.muc.boerse-go.de charon 51742 - [meta sequenceId="9"] 00[CFG] <fedba488-6e95-4bda-8485-8ca06267dba0|539> lease 10.20.32.41 by 'jjaeger' went offline
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="1"] 00[DMN] Starting IKE charon daemon (strongSwan 5.9.14, FreeBSD 13.2-RELEASE-p11, amd64)
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="2"] 00[LIB] providers loaded by OpenSSL: default legacy
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="3"] 00[CFG] using '/sbin/resolvconf' to install DNS servers
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="4"] 00[CFG] loading ca certificates from '/usr/local/etc/ipsec.d/cacerts'
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="5"] 00[CFG] loading aa certificates from '/usr/local/etc/ipsec.d/aacerts'
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="6"] 00[CFG] loading ocsp signer certificates from '/usr/local/etc/ipsec.d/ocspcerts'
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="7"] 00[CFG] loading attribute certificates from '/usr/local/etc/ipsec.d/acerts'
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="8"] 00[CFG] loading crls from '/usr/local/etc/ipsec.d/crls'
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="9"] 00[CFG] loading secrets from '/usr/local/etc/ipsec.secrets'
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="10"] 00[CFG] loaded 1 RADIUS server configuration
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="11"] 00[LIB] loaded plugins: charon aes des blowfish rc2 sha2 sha1 md4 md5 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs12 pgp dnskey sshkey pem openssl pkcs8 fips-prf curve25519 xcbc cmac hmac kdf gcm drbg curl attr kernel-pfkey kernel-pfroute resolve socket-default stroke vici updown eap-identity eap-md5 eap-mschapv2 eap-radius eap-tls eap-ttls eap-peap xauth-generic xauth-eap xauth-pam whitelist addrblock counters
<30>1 2024-06-08T07:11:26+02:00 opnsense01.muc.boerse-go.de charon 93898 - [meta sequenceId="12"] 00[JOB] spawning 16 worker threads

Additional context

Environment

Software version used and hardware type if relevant, e.g.:

OPNsense 24.1.8-amd64 FreeBSD 13.2-RELEASE-p11 OpenSSL 3.0.13 Intel(R) Xeon(R) Silver 4110 CPU @ 2.10GHz (8 cores, 16 threads)

AdSchellevis commented 3 months ago

restart executes this:

https://github.com/opnsense/core/blob/ff0e772b5ba2877c4ea925c86957900ad70a7774/src/opnsense/service/conf/actions.d/actions_ipsec.conf#L80

should be the same from the gui restart button if I'm not mistaken, could help you further analyse your problem.

It might make sense to open another ticket for the dropdown, it's more or less logical that it tries to stick to the dialog, but doesn't look very nice when the item is at the bottom of the form.

stumbaumr commented 3 months ago

Found a work around... grafik

Just doing the restart 3 minutes later again starts the service again...

Maybe that onestop command does not wait till the service is completey stopped - so the -c ipsec can not start it yet...