[Openvpn-devel] show extra info for OpenSSL errors

Message ID 20230707185811.30132-1-arne@rfc2549.org
State Superseded
Headers show
Series [Openvpn-devel] show extra info for OpenSSL errors | expand

Commit Message

Arne Schwabe July 7, 2023, 6:58 p.m. UTC
This also shows the extra data from the OpenSSL error function that
can contain extra information. For example, the command

    openvpn --providers vollbit

will print out (on macOS):

     OpenSSLerror:12800067:DSO support routines::could not load the shared library:filename(/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib): dlopen(/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib, 0x0002): tried: '/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib' (no such file), '/System/Volumes/Preboot/Cryptexes/OS/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib' (no such file), '/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib' (no such file)

Change-Id: Ic2ee89937dcd85721bcacd1b700a20c640364f80
Signed-off-by: Arne Schwabe <arne@rfc2549.org>
---
 src/openvpn/crypto_openssl.c | 20 ++++++++++++++++++--
 src/openvpn/openssl_compat.h | 12 ++++++++++++
 2 files changed, 30 insertions(+), 2 deletions(-)

Comments

Gert Doering July 10, 2023, 3:56 p.m. UTC | #1
Hi,

On Fri, Jul 07, 2023 at 08:58:11PM +0200, Arne Schwabe wrote:
> This also shows the extra data from the OpenSSL error function that
> can contain extra information. For example, the command
> 
>     openvpn --providers vollbit
> 
> will print out (on macOS):
> 
>      OpenSSLerror:12800067:DSO support routines::could not load the shared library:filename(/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib): dlopen(/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib, 0x0002): tried: '/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib' (no such file), '/System/Volumes/Preboot/Cryptexes/OS/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib' (no such file), '/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib' (no such file)

Feature-ACK on providing more detail, because otherwise these errors
can get really hard to track down.

Your example above is somewhat excessive on repeating paths, but I do
not see this on my FreeBSD test case

$ src/openvpn/openvpn --providers legacyXX default --show-tls
2023-07-10 17:44:27 OpenSSLerror:12800067:DSO support routines::could not load the shared library:filename(/usr/lib/ossl-modules/legacyXX.so): /usr/lib/ossl-modules/legacyXX.so: Undefined symbol "ossl_md4_functions"
2023-07-10 17:44:27 OpenSSLerror:12800067:DSO support routines::could not load the shared library:
2023-07-10 17:44:27 OpenSSLerror:07880025:common libcrypto routines::reason(524325):name=legacyXX

"this is just the right amount of details" :-) - for something that
does not exist, I get

2023-07-10 17:45:17 OpenSSLerror:12800067:DSO support routines::could not load the shared library:filename(/usr/lib/ossl-modules/legacyYY.so): Cannot open "/usr/lib/ossl-modules/legacyYY.so"


Code-wise, I would prefer to have someone who understands OpenSSL give
this another look...  Selva, Antonio?  Thanks :-)

gert
Selva Nair July 12, 2023, 6:03 p.m. UTC | #2
Hi,

This looks good except that the format of the log could be kept closer to
the current one:

On Fri, Jul 7, 2023 at 2:59 PM Arne Schwabe <arne@rfc2549.org> wrote:

> This also shows the extra data from the OpenSSL error function that
> can contain extra information. For example, the command
>
>     openvpn --providers vollbit
>
> will print out (on macOS):
>
>      OpenSSLerror:12800067:DSO support routines::could not load the shared
> library:filename(/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib):
> dlopen(/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib,
> 0x0002): tried: '/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib'
> (no such file),
> '/System/Volumes/Preboot/Cryptexes/OS/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib'
> (no such file), '/opt/homebrew/Cellar/openssl@3/3.1.1_1/lib/ossl-modules/vollbit.dylib'
> (no such file)
>
> Change-Id: Ic2ee89937dcd85721bcacd1b700a20c640364f80
> Signed-off-by: Arne Schwabe <arne@rfc2549.org>
> ---
>  src/openvpn/crypto_openssl.c | 20 ++++++++++++++++++--
>  src/openvpn/openssl_compat.h | 12 ++++++++++++
>  2 files changed, 30 insertions(+), 2 deletions(-)
>
> diff --git a/src/openvpn/crypto_openssl.c b/src/openvpn/crypto_openssl.c
> index b043bb95e..d6916fc9b 100644
> --- a/src/openvpn/crypto_openssl.c
> +++ b/src/openvpn/crypto_openssl.c
> @@ -238,9 +238,16 @@ void
>  crypto_print_openssl_errors(const unsigned int flags)
>  {
>      unsigned long err = 0;
> +    int line, errflags;
> +    const char *file, *data, *func;
>
> -    while ((err = ERR_get_error()))
> +    while ((err = ERR_get_error_all(&file, &line, &func, &data,
> &errflags)) != 0)
>      {
> +        if (!(errflags & ERR_TXT_STRING))
> +        {
> +            data = "";
> +        }
> +
>          /* Be more clear about frequently occurring "no shared cipher"
> error */
>          if (ERR_GET_REASON(err) == SSL_R_NO_SHARED_CIPHER)
>          {
> @@ -258,7 +265,16 @@ crypto_print_openssl_errors(const unsigned int flags)
>                  "tls-version-min 1.0 to the client configuration to use
> TLS 1.0+ "
>                  "instead of TLS 1.0 only");
>          }
> -        msg(flags, "OpenSSL: %s", ERR_error_string(err, NULL));
> +
> +        /* print file and line if verb >=8 */
> +        if (!check_debug_level(D_TLS_DEBUG_MED))
> +        {
> +            msg(flags, "OpenSSL%s:%s", ERR_error_string(err, NULL), data);
>

Better to retain the ':" after "OpenSSL" in case anyone is parsing the logs

msg(flags, "OpenSSL: %s:%s, ERR_error_string(err, NULL), data);


> +        }
> +        else
> +        {
> +            msg(flags, "OpenSSL (%s:%d %s): %s:%s", file, line, func,
> ERR_error_string(err, NULL), data);
>

Again, I think we could keep the same order as above with additional info
(file:line:func) moved to the end with a consistent use of the delimiter ':'

msg(flags, "OpenSSL: %s:%s:%s:%s:%s, ERR_error_string(err, NULL), data,
file, line, func);


> +        }
>      }
>  }
>
> diff --git a/src/openvpn/openssl_compat.h b/src/openvpn/openssl_compat.h
> index ffb64adf6..736ce1bd5 100644
> --- a/src/openvpn/openssl_compat.h
> +++ b/src/openvpn/openssl_compat.h
> @@ -43,6 +43,7 @@
>  #include <openssl/rsa.h>
>  #include <openssl/ssl.h>
>  #include <openssl/x509.h>
> +#include <openssl/err.h>
>
>  /* Functionality missing in 1.1.0 */
>  #if OPENSSL_VERSION_NUMBER < 0x10101000L &&
> !defined(ENABLE_CRYPTO_WOLFSSL)
> @@ -799,6 +800,17 @@ EVP_MD_free(const EVP_MD *md)
>      /* OpenSSL 1.1.1 and lower use only const EVP_MD, nothing to free */
>  }
>
> +static inline unsigned long
> +ERR_get_error_all(const char **file, int *line,
> +                  const char **func,
> +                  const char **data, int *flags)
> +{
> +    static const char *empty = "";
> +    *func = empty;
> +    long err = ERR_get_error_line_data(file, line, data, flags);
>

unsigned long err = ....


> +    return err;
> +}
> +
>  #endif /* OPENSSL_VERSION_NUMBER < 0x30000000L */
>
>  #endif /* OPENSSL_COMPAT_H_ */
> --
>
> https://lists.sourceforge.net/lists/listinfo/openvpn-devel
>

Patch

diff --git a/src/openvpn/crypto_openssl.c b/src/openvpn/crypto_openssl.c
index b043bb95e..d6916fc9b 100644
--- a/src/openvpn/crypto_openssl.c
+++ b/src/openvpn/crypto_openssl.c
@@ -238,9 +238,16 @@  void
 crypto_print_openssl_errors(const unsigned int flags)
 {
     unsigned long err = 0;
+    int line, errflags;
+    const char *file, *data, *func;
 
-    while ((err = ERR_get_error()))
+    while ((err = ERR_get_error_all(&file, &line, &func, &data, &errflags)) != 0)
     {
+        if (!(errflags & ERR_TXT_STRING))
+        {
+            data = "";
+        }
+
         /* Be more clear about frequently occurring "no shared cipher" error */
         if (ERR_GET_REASON(err) == SSL_R_NO_SHARED_CIPHER)
         {
@@ -258,7 +265,16 @@  crypto_print_openssl_errors(const unsigned int flags)
                 "tls-version-min 1.0 to the client configuration to use TLS 1.0+ "
                 "instead of TLS 1.0 only");
         }
-        msg(flags, "OpenSSL: %s", ERR_error_string(err, NULL));
+
+        /* print file and line if verb >=8 */
+        if (!check_debug_level(D_TLS_DEBUG_MED))
+        {
+            msg(flags, "OpenSSL%s:%s", ERR_error_string(err, NULL), data);
+        }
+        else
+        {
+            msg(flags, "OpenSSL (%s:%d %s): %s:%s", file, line, func, ERR_error_string(err, NULL), data);
+        }
     }
 }
 
diff --git a/src/openvpn/openssl_compat.h b/src/openvpn/openssl_compat.h
index ffb64adf6..736ce1bd5 100644
--- a/src/openvpn/openssl_compat.h
+++ b/src/openvpn/openssl_compat.h
@@ -43,6 +43,7 @@ 
 #include <openssl/rsa.h>
 #include <openssl/ssl.h>
 #include <openssl/x509.h>
+#include <openssl/err.h>
 
 /* Functionality missing in 1.1.0 */
 #if OPENSSL_VERSION_NUMBER < 0x10101000L && !defined(ENABLE_CRYPTO_WOLFSSL)
@@ -799,6 +800,17 @@  EVP_MD_free(const EVP_MD *md)
     /* OpenSSL 1.1.1 and lower use only const EVP_MD, nothing to free */
 }
 
+static inline unsigned long
+ERR_get_error_all(const char **file, int *line,
+                  const char **func,
+                  const char **data, int *flags)
+{
+    static const char *empty = "";
+    *func = empty;
+    long err = ERR_get_error_line_data(file, line, data, flags);
+    return err;
+}
+
 #endif /* OPENSSL_VERSION_NUMBER < 0x30000000L */
 
 #endif /* OPENSSL_COMPAT_H_ */