Cron: Restart IPsec service does stop but not start the service
Important notices
Before you add a new report, we ask you kindly to acknowledge the following:
- [X] I have read the contributing guide lines at https://github.com/opnsense/core/blob/master/CONTRIBUTING.md
- [X] I am convinced that my issue is new after having checked both open and closed issues at https://github.com/opnsense/core/issues?q=is%3Aissue
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:
- Go to System-> Settings-> Cron
- Add a cron job to "Restart IPsec service" and try to use that cut-off drop-down while doing that...
- 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
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)
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.
Found a work around...
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...
This issue has been automatically timed-out (after 180 days of inactivity).
For more information about the policies for this repository, please read https://github.com/opnsense/core/blob/master/CONTRIBUTING.md for further details.
If someone wants to step up and work on this issue, just let us know, so we can reopen the issue and assign an owner to it.