Project

General

Profile

Actions
Copy link

Bug #14840

open

OpenVPN Uncaught Exception log error: Uncaught Exception: Can't parse time from string

Added by Phil Wardt 7 months ago. Updated 7 months ago.

Status:
Incomplete
Priority:
Normal
Assignee:
-
Category:
Certificates
Target version:
-
Start date:
Due date:
% Done:

0%

Estimated time:
Plus Target Version:
Release Notes:
Default
Affected Version:
Affected Architecture:

Description

I received the below notification about an error when pfsense was booted:

7:51:21 PHP ERROR: Type: 1, File: /usr/local/share/openssl_x509_crl/ASN1_GENERALTIME.php, Line: 73, Message: Uncaught Exception: Can't parse time from string '211029094223Z' in /usr/local/share/openssl_x509_crl/ASN1_GENERALTIME.php:73
Stack trace:
#0 /usr/local/share/openssl_x509_crl/ASN1.php(136): Ukrbublik\openssl_x509_crl\ASN1_GENERALTIME->decodeSimple('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...', 167, 13)
#1 /usr/local/share/openssl_x509_crl/ASN1.php(314): Ukrbublik\openssl_x509_crl\ASN1->decode('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...', 167, 13)
#2 /usr/local/share/openssl_x509_crl/ASN1.php(138): Ukrbublik\openssl_x509_crl\ASN1->decodeConstructed('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...', 165, 30)
#3 /usr/local/share/openssl_x509_crl/ASN1.php(314): Ukrbublik\openssl_x509_crl\ASN1->decode('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...', 165, 30)
#4 /usr/local/share/openssl_x509_crl/ASN1.php(138): Ukrbublik\openssl_x509_crl\ASN1->decodeConstructed('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...', 8, 1101)
#5 /usr/local/share/openssl_x509_crl/ASN1.php(314): Ukrbublik\openssl_x509_crl\ASN1->decode('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...', 8, 1101)
#6 /usr/local/share/openssl_x509_crl/ASN1.php(138): Ukrbublik\openssl_x509_crl\ASN1->decodeConstructed('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...', 4, 1637)
#7 /usr/local/share/openssl_x509_crl/ASN1.php(314): Ukrbublik\openssl_x509_crl\ASN1->decode('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...', 4, 1637)
#8 /usr/local/share/openssl_x509_crl/ASN1.php(138): Ukrbublik\openssl_x509_crl\ASN1->decodeConstructed('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...', 0, 1641)
#9 /usr/local/share/openssl_x509_crl/X509_CERT.php(44): Ukrbublik\openssl_x509_crl\ASN1->decode('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...', 0, 1641)
#10 /usr/local/share/openssl_x509_crl/X509_CRL.php(60): Ukrbublik\openssl_x509_crl\X509_CERT::decode('0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...')
#11 /etc/inc/certs.inc(1071): Ukrbublik\openssl_x509_crl\X509_CRL::create(Array, Object(OpenSSLAsymmetricKey), '0\x82\x06e0\x82\x04M\xA0\x03\x02\x01\x02\x02\x08...')
#12 /etc/inc/openvpn.inc(1353): crl_update(Array)
#13 /etc/inc/openvpn.inc(1576): openvpn_reconfigure('server', Array)
#14 /etc/inc/openvpn.inc(1865): openvpn_restart('server', Array)
#15 /etc/inc/openvpn.inc(1907): openvpn_resync('server', Array)
#16 /etc/rc.newwanip(261): openvpn_resync_all('wan', 'inet')
#17 {main}
  thrown

It is the first time and never sent again !

Actions
Copy link
 #1

Updated by Jim Pingle 7 months ago

  • Status changed from New to Incomplete

What version of pfSense software are you running now?

What were you doing before the reboot? (e.g. if it was a reboot from an upgrade, it's possible the error was from old code)

If it was an upgrade, what was the older version?

I tried feeding the time string you quoted through the code in the function where the error was and it seemed to parse OK here, it wouldn't have reached the code that produced the error you received.

Actions
Copy link
 #2

Updated by Phil Wardt 7 months ago

I use pfsense CE 2.7.0
The upgrade was done a month ago and many rebbots happened since then
I noticed the error through a notification email and I did not notice any other issues. I just did not test the OpenVPN setup on that day

If there are any other logs I can send, let me know

Actions
Copy link
 #3

Updated by Jim Pingle 7 months ago

  • Category changed from OpenVPN to Certificates

Phil Wardt wrote in #note-2:

I use pfsense CE 2.7.0
The upgrade was done a month ago and many rebbots happened since then
I noticed the error through a notification email and I did not notice any other issues. I just did not test the OpenVPN setup on that day

If there are any other logs I can send, let me know

So this just happened on one boot and didn't happen before and hasn't happened again since?

I still haven't been able to hit the error condition here that you hit there even with the same string. It parses as expected here when I step through the code.

The strings it is parsing at that point are timestamps out of the CA and so on, so I would expect it to be happening every time not just randomly.

Actions
Copy link
 #4

Updated by Phil Wardt 7 months ago

I did not make any changes in the config between 16 sept and today
The pfsense box is rebooted nightly
The email notification error was received on 3 oct 7:51 am during boot process based on the email time stamp

3 october OpenVPN log:
I notice that it doesn't end with "Initialization Sequence Completed" like all the other days
Not sure also about all these fatal errors

Oct 3 07:51:06    openvpn    96541    Flushing states on OpenVPN interface ovpns1 (Link Down)
Oct 3 07:51:06    openvpn    93497    /usr/local/sbin/ovpn-linkdown ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 3 07:51:06    openvpn    93497    /sbin/ifconfig ovpns1 10.3.3.1 -alias
Oct 3 07:51:06    openvpn    93497    Exiting due to fatal error
Oct 3 07:51:06    openvpn    93497    TCP/UDP: Socket bind failed on local address [AF_INET]192.168.100.12:41573: Can't assign requested address (errno=49)
Oct 3 07:51:06    openvpn    93497    /usr/local/sbin/ovpn-linkup ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 3 07:51:06    openvpn    93497    /sbin/ifconfig ovpns1 10.3.3.1/24 mtu 1500 up
Oct 3 07:51:06    openvpn    93497    TUN/TAP device /dev/tun1 opened
Oct 3 07:51:06    openvpn    93497    TUN/TAP device ovpns1 exists previously, keep at program end
Oct 3 07:51:06    openvpn    93497    WARNING: experimental option --capath /var/etc/openvpn/server1/ca
Oct 3 07:51:06    openvpn    93497    Initializing OpenSSL support for engine 'rdrand'
Oct 3 07:51:06    openvpn    93497    NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Oct 3 07:51:06    openvpn    93497    GDG: problem writing to routing socket
Oct 3 07:51:06    openvpn    93190    DCO version: FreeBSD 14.0-CURRENT #1 RELENG_2_7_0-n255866-686c8d3c1f0: Wed Jun 28 04:21:19 UTC 2023 root@freebsd:/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/obj/amd64/LwYAddCr/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/sources/FreeBSD-src-REL
Oct 3 07:51:06    openvpn    93190    library versions: OpenSSL 1.1.1t-freebsd 7 Feb 2023, LZO 2.10
Oct 3 07:51:06    openvpn    93190    OpenVPN 2.6.4 amd64-portbld-freebsd14.0 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [MH/RECVDA] [AEAD] [DCO]
Oct 3 07:50:03    openvpn    20468    Flushing states on OpenVPN interface ovpns1 (Link Down)
Oct 3 07:50:03    openvpn    17242    /usr/local/sbin/ovpn-linkdown ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 3 07:50:03    openvpn    17242    /sbin/ifconfig ovpns1 10.3.3.1 -alias
Oct 3 07:50:03    openvpn    17242    Exiting due to fatal error
Oct 3 07:50:03    openvpn    17242    TCP/UDP: Socket bind failed on local address [AF_INET]192.168.100.12:41573: Can't assign requested address (errno=49)
Oct 3 07:50:03    openvpn    17242    /usr/local/sbin/ovpn-linkup ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 3 07:50:03    openvpn    17242    /sbin/ifconfig ovpns1 10.3.3.1/24 mtu 1500 up
Oct 3 07:50:03    openvpn    17242    TUN/TAP device /dev/tun1 opened
Oct 3 07:50:03    openvpn    17242    TUN/TAP device ovpns1 exists previously, keep at program end
Oct 3 07:50:03    openvpn    17242    WARNING: experimental option --capath /var/etc/openvpn/server1/ca
Oct 3 07:50:03    openvpn    17242    Initializing OpenSSL support for engine 'rdrand'
Oct 3 07:50:03    openvpn    17242    NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Oct 3 07:50:03    openvpn    17242    GDG: problem writing to routing socket
Oct 3 07:50:03    openvpn    17230    DCO version: FreeBSD 14.0-CURRENT #1 RELENG_2_7_0-n255866-686c8d3c1f0: Wed Jun 28 04:21:19 UTC 2023 root@freebsd:/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/obj/amd64/LwYAddCr/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/sources/FreeBSD-src-REL
Oct 3 07:50:03    openvpn    17230    library versions: OpenSSL 1.1.1t-freebsd 7 Feb 2023, LZO 2.10
Oct 3 07:50:03    openvpn    17230    OpenVPN 2.6.4 amd64-portbld-freebsd14.0 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [MH/RECVDA] [AEAD] [DCO]
Oct 3 07:49:23    openvpn    80560    Flushing states on OpenVPN interface ovpns1 (Link Down)
Oct 3 07:49:23    openvpn    77734    /usr/local/sbin/ovpn-linkdown ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 3 07:49:23    openvpn    77734    /sbin/ifconfig ovpns1 10.3.3.1 -alias
Oct 3 07:49:23    openvpn    77734    Exiting due to fatal error
Oct 3 07:49:23    openvpn    77734    TCP/UDP: Socket bind failed on local address [AF_INET]192.168.100.12:41573: Can't assign requested address (errno=49)
Oct 3 07:49:23    openvpn    77734    /usr/local/sbin/ovpn-linkup ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 3 07:49:23    openvpn    77734    /sbin/ifconfig ovpns1 10.3.3.1/24 mtu 1500 up
Oct 3 07:49:23    openvpn    77734    TUN/TAP device /dev/tun1 opened
Oct 3 07:49:23    openvpn    77734    TUN/TAP device ovpns1 exists previously, keep at program end
Oct 3 07:49:23    openvpn    77734    WARNING: experimental option --capath /var/etc/openvpn/server1/ca
Oct 3 07:49:23    openvpn    77734    Initializing OpenSSL support for engine 'rdrand'
Oct 3 07:49:23    openvpn    77734    NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Oct 3 07:49:23    openvpn    77734    GDG: problem writing to routing socket
Oct 3 07:49:23    openvpn    77730    DCO version: FreeBSD 14.0-CURRENT #1 RELENG_2_7_0-n255866-686c8d3c1f0: Wed Jun 28 04:21:19 UTC 2023 root@freebsd:/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/obj/amd64/LwYAddCr/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/sources/FreeBSD-src-REL
Oct 3 07:49:23    openvpn    77730    library versions: OpenSSL 1.1.1t-freebsd 7 Feb 2023, LZO 2.10
Oct 3 07:49:23    openvpn    77730    OpenVPN 2.6.4 amd64-portbld-freebsd14.0 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [MH/RECVDA] [AEAD] [DCO]
Oct 3 07:49:22    openvpn    46380    SIGTERM[hard,] received, process exiting
Oct 3 07:49:22    openvpn    71392    Flushing states on OpenVPN interface ovpns1 (Link Down)
Oct 3 07:49:22    openvpn    46380    /usr/local/sbin/ovpn-linkdown ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 3 07:49:22    openvpn    46380    /sbin/ifconfig ovpns1 10.3.3.1 -alias
Oct 3 07:49:20    openvpn    46380    event_wait : Interrupted system call (fd=-1,code=4)
Oct 3 07:47:43    openvpn    46380    Initialization Sequence Completed
Oct 3 07:47:43    openvpn    46380    UDPv4 link remote: [AF_UNSPEC]
Oct 3 07:47:43    openvpn    46380    UDPv4 link local (bound): [AF_INET][undef]:41573
Oct 3 07:47:43    openvpn    46380    /usr/local/sbin/ovpn-linkup ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 3 07:47:43    openvpn    46380    /sbin/ifconfig ovpns1 10.3.3.1/24 mtu 1500 up
Oct 3 07:47:43    openvpn    46380    TUN/TAP device /dev/tun1 opened
Oct 3 07:47:43    openvpn    46380    TUN/TAP device ovpns1 exists previously, keep at program end
Oct 3 07:47:43    openvpn    46380    WARNING: experimental option --capath /var/etc/openvpn/server1/ca
Oct 3 07:47:43    openvpn    46380    Initializing OpenSSL support for engine 'rdrand'
Oct 3 07:47:43    openvpn    46380    NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Oct 3 07:47:43    openvpn    46380    GDG: problem writing to routing socket
Oct 3 07:47:43    openvpn    46192    DCO version: FreeBSD 14.0-CURRENT #1 RELENG_2_7_0-n255866-686c8d3c1f0: Wed Jun 28 04:21:19 UTC 2023 root@freebsd:/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/obj/amd64/LwYAddCr/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/sources/FreeBSD-src-REL
Oct 3 07:47:43    openvpn    46192    library versions: OpenSSL 1.1.1t-freebsd 7 Feb 2023, LZO 2.10
Oct 3 07:47:43    openvpn    46192    OpenVPN 2.6.4 amd64-portbld-freebsd14.0 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [MH/RECVDA] [AEAD] [DCO]

Other days OpenVPN init log:

Oct 2 08:00:25    openvpn    98324    Initialization Sequence Completed
Oct 2 08:00:25    openvpn    98324    UDPv4 link remote: [AF_UNSPEC]
Oct 2 08:00:25    openvpn    98324    UDPv4 link local (bound): [AF_INET]77.56.224.255:41573
Oct 2 08:00:25    openvpn    98324    /usr/local/sbin/ovpn-linkup ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 2 08:00:25    openvpn    98324    /sbin/ifconfig ovpns1 10.3.3.1/24 mtu 1500 up
Oct 2 08:00:25    openvpn    98324    TUN/TAP device /dev/tun1 opened
Oct 2 08:00:25    openvpn    98324    TUN/TAP device ovpns1 exists previously, keep at program end
Oct 2 08:00:25    openvpn    98324    WARNING: experimental option --capath /var/etc/openvpn/server1/ca
Oct 2 08:00:25    openvpn    98324    Initializing OpenSSL support for engine 'rdrand'
Oct 2 08:00:25    openvpn    98324    NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Oct 2 08:00:25    openvpn    98321    DCO version: FreeBSD 14.0-CURRENT #1 RELENG_2_7_0-n255866-686c8d3c1f0: Wed Jun 28 04:21:19 UTC 2023 root@freebsd:/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/obj/amd64/LwYAddCr/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/sources/FreeBSD-src-REL
Oct 2 08:00:25    openvpn    98321    library versions: OpenSSL 1.1.1t-freebsd 7 Feb 2023, LZO 2.10
Oct 2 08:00:25    openvpn    98321    OpenVPN 2.6.4 amd64-portbld-freebsd14.0 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [MH/RECVDA] [AEAD] [DCO]
Oct 2 07:59:59    openvpn    10243    Flushing states on OpenVPN interface ovpns1 (Link Down)
Oct 2 07:59:59    openvpn    6767    /usr/local/sbin/ovpn-linkdown ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 2 07:59:59    openvpn    6767    /sbin/ifconfig ovpns1 10.3.3.1 -alias
Oct 2 07:59:59    openvpn    6767    Exiting due to fatal error
Oct 2 07:59:59    openvpn    6767    TCP/UDP: Socket bind failed on local address [AF_INET]192.168.100.12:41573: Can't assign requested address (errno=49)
Oct 2 07:59:59    openvpn    6767    /usr/local/sbin/ovpn-linkup ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 2 07:59:59    openvpn    6767    /sbin/ifconfig ovpns1 10.3.3.1/24 mtu 1500 up
Oct 2 07:59:59    openvpn    6767    TUN/TAP device /dev/tun1 opened
Oct 2 07:59:59    openvpn    6767    TUN/TAP device ovpns1 exists previously, keep at program end
Oct 2 07:59:59    openvpn    6767    WARNING: experimental option --capath /var/etc/openvpn/server1/ca
Oct 2 07:59:59    openvpn    6767    Initializing OpenSSL support for engine 'rdrand'
Oct 2 07:59:59    openvpn    6767    NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Oct 2 07:59:59    openvpn    6767    GDG: problem writing to routing socket
Oct 2 07:59:59    openvpn    6470    DCO version: FreeBSD 14.0-CURRENT #1 RELENG_2_7_0-n255866-686c8d3c1f0: Wed Jun 28 04:21:19 UTC 2023 root@freebsd:/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/obj/amd64/LwYAddCr/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/sources/FreeBSD-src-REL
Oct 2 07:59:59    openvpn    6470    library versions: OpenSSL 1.1.1t-freebsd 7 Feb 2023, LZO 2.10
Oct 2 07:59:59    openvpn    6470    OpenVPN 2.6.4 amd64-portbld-freebsd14.0 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [MH/RECVDA] [AEAD] [DCO]
Oct 2 07:59:59    openvpn    45631    SIGTERM[hard,] received, process exiting
Oct 2 07:59:59    openvpn    337    Flushing states on OpenVPN interface ovpns1 (Link Down)
Oct 2 07:59:59    openvpn    45631    /usr/local/sbin/ovpn-linkdown ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 2 07:59:59    openvpn    45631    /sbin/ifconfig ovpns1 10.3.3.1 -alias
Oct 2 07:59:57    openvpn    45631    event_wait : Interrupted system call (fd=-1,code=4)
Oct 2 07:58:13    openvpn    45631    Initialization Sequence Completed
Oct 2 07:58:13    openvpn    45631    UDPv4 link remote: [AF_UNSPEC]
Oct 2 07:58:13    openvpn    45631    UDPv4 link local (bound): [AF_INET][undef]:41573
Oct 2 07:58:13    openvpn    45631    /usr/local/sbin/ovpn-linkup ovpns1 1500 0 10.3.3.1 255.255.255.0 init
Oct 2 07:58:13    openvpn    45631    /sbin/ifconfig ovpns1 10.3.3.1/24 mtu 1500 up
Oct 2 07:58:13    openvpn    45631    TUN/TAP device /dev/tun1 opened
Oct 2 07:58:13    openvpn    45631    TUN/TAP device ovpns1 exists previously, keep at program end
Oct 2 07:58:13    openvpn    45631    WARNING: experimental option --capath /var/etc/openvpn/server1/ca
Oct 2 07:58:13    openvpn    45631    Initializing OpenSSL support for engine 'rdrand'
Oct 2 07:58:13    openvpn    45631    NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Oct 2 07:58:13    openvpn    45631    GDG: problem writing to routing socket
Oct 2 07:58:13    openvpn    45345    DCO version: FreeBSD 14.0-CURRENT #1 RELENG_2_7_0-n255866-686c8d3c1f0: Wed Jun 28 04:21:19 UTC 2023 root@freebsd:/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/obj/amd64/LwYAddCr/var/jenkins/workspace/pfSense-CE-snapshots-2_7_0-main/sources/FreeBSD-src-REL
Oct 2 07:58:13    openvpn    45345    library versions: OpenSSL 1.1.1t-freebsd 7 Feb 2023, LZO 2.10
Oct 2 07:58:13    openvpn    45345    OpenVPN 2.6.4 amd64-portbld-freebsd14.0 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [MH/RECVDA] [AEAD] [DCO]

Actions
Copy link
 #5

Updated by Marcos M 7 months ago

This has happened previously on 23.01 when the OpenVPN server is set to use a gateway group and the tier1 gateway is unplugged (rather than simply packet loss). Show


If using a gateway group, try binding to localhost and using port forwards instead.

Actions
Copy link
 #6

Updated by Phil Wardt 7 months ago

I never configured a gateway group, just setting an IPv4 Tunnel Network 10.50.62.0/24

However, I did not set any IPv6 Tunnel Network (left empty), and I checked the options
- Redirect IPv6 Gateway: checked
- Gateway creation: Both

This setup is unchanged since 18 months now and it is the first time I got this error, and never again...

Actions
Copy link

Also available in: Atom PDF