PVA: Client logs server info at FINE level

kasemir · kasemir · commit bb05d995d580 · 2025-06-04T12:54:28.000-04:00
diff --git a/core/pva/TLS.md b/core/pva/TLS.md
@@ -34,7 +34,7 @@ This is an example recipe for getting started.
 2) Start `pvacms -v`. It will create several files, including
 
  * `~/.config/pva/1.3/admin.p12`: Certificate for the `admin` user
- 
+
 3) For an IOC, request a hybrid server and client certificate.
    Note its "Certificate identifier":
 
@@ -52,17 +52,17 @@ This is an example recipe for getting started.
    Approve ==> CERT:STATUS:e53ed409:15273288300286014953 ==> Completed Successfully
    ```
 
- * `~/.config/pva/1.3/server.p12`: Our server certificate (hybrid, for IOC) 
+ * `~/.config/pva/1.3/server.p12`: Our server certificate (hybrid, for IOC)
 
 4) Request a client certificate, note its identifier:
 
    ```
-   $ authnstd 
+   $ authnstd
    Keychain file created   : /home/user/.config/pva/1.3/client.p12
    Certificate identifier  : e53ed409:11521018863975115478
    ```
 
-   Accept that certificate: 
+   Accept that certificate:
 
    ```
    $ EPICS_PVA_TLS_KEYCHAIN=~/.config/pva/1.3/admin.p12  \
@@ -94,13 +94,20 @@ To list certificate details:
 keytool -list -v -keystore ~/.config/pva/1.3/client.p12 -storepass ""
 ```
 
+Following the `pvacms` and `authnstd` messages, you will notice that secure PVA
+maintains files in two locations.
+If you need to start over, stop `pvacms`, delete those files, and then start `pvacms` again:
+
+```
+$ rm -rf  ~/.config/pva  ~/.local/share/pva
+```
+
 For a test setup, all the above can be executed by a single user on one host.
 In a production setup, however, each human user should only have access to their own `client.p12` file.
 Pseudo-users running IOCs would have a `server.p12` file.
 Only an admin user on a designated host would have access to the remaining `pvacms` files,
 including the `admin.p12` file that permits accepting and revoking certificates.
 
-
 Secure IOC
 ==========
 
@@ -240,7 +247,7 @@ For lower level encryption information, add `-Djavax.net.debug=all`.
 
 For example, when receiving subscription updates for a string PV with status and timestamp,
 the log messages indicate that the encrypted data size of 74 bytes is almost twice the size
-of the decrypted payload of 41 bytes: 
+of the decrypted payload of 41 bytes:
 
 ```
 javax.net.ssl|DEBUG|91|TCP receiver /127.0.0.1|2023-05-05 15:57:37.299 EDT|SSLSocketInputRecord.java:214|READ: TLSv1.2 application_data, length = 74
@@ -400,24 +407,24 @@ In total, we now have the following:
    Keystore with public and private key of our Certification Authority (CA).
    This file needs to be guarded because it allows creating new IOC
    and client keystores.
-   
+
  * `myca.cer`:
    Public certificate of the CA.
    Imported into any `*.p12` that needs to trust the CA.
-   
+
  * `trust_ca.p12`:
    Truststore with public certificate of the CA.
    Equivalent to `myca.cer`, and some tools might directly use `myca.cer`,
-   but `trust_ca.p12` presents it in the commonly used  PKCS12 `*.p12` file format. 
+   but `trust_ca.p12` presents it in the commonly used  PKCS12 `*.p12` file format.
    Clients can set their `EPICS_PVA_TLS_KEYCHAIN` to this file to
    communicate with IOCs, resulting in encryption and "ca" authentication.
-   
+
  * `ioc.p12`:
    Keystore with public and private key of an IOC.
    The public key certificate is signed by the CA so that clients
    will trust it.
    To be used with `EPICS_PVAS_TLS_KEYCHAIN` of IOCs.
-   
+
  * `myioc.cer`, `myioc.csr`: Public IOC certificate and certificate signing request.
    Intermediate files used to sign the IOC certificate.
    May be deleted.
diff --git a/core/pva/src/main/java/org/epics/pva/client/ClientTCPHandler.java b/core/pva/src/main/java/org/epics/pva/client/ClientTCPHandler.java
@@ -1,5 +1,5 @@
 /*******************************************************************************
- * Copyright (c) 2019-2023 Oak Ridge National Laboratory.
+ * Copyright (c) 2019-2025 Oak Ridge National Laboratory.
  * All rights reserved. This program and the accompanying materials
  * are made available under the terms of the Eclipse Public License v1.0
  * which accompanies this distribution, and is available at
@@ -117,7 +117,7 @@ public ClientTCPHandler(final PVAClient client, final InetSocketAddress address,
         this.guid = guid;
 
         // For TLS, check if the socket has a name that's used to authenticate
-        x509_name = tls ? SecureSockets.getLocalPrincipalName((SSLSocket) socket) : null;
+        x509_name = tls ? SecureSockets.getPrincipalCN(((SSLSocket) socket).getSession().getLocalPrincipal()) : null;
 
         // For default EPICS_CA_CONN_TMO: 30 sec, send echo at ~15 sec:
         // Check every ~3 seconds
diff --git a/core/pva/src/main/java/org/epics/pva/common/SecureSockets.java b/core/pva/src/main/java/org/epics/pva/common/SecureSockets.java
@@ -1,5 +1,5 @@
 /*******************************************************************************
- * Copyright (c) 2023 Oak Ridge National Laboratory.
+ * Copyright (c) 2023-2025 Oak Ridge National Laboratory.
  * All rights reserved. This program and the accompanying materials
  * are made available under the terms of the Eclipse Public License v1.0
  * which accompanies this distribution, and is available at
@@ -14,6 +14,9 @@
 import java.net.ServerSocket;
 import java.net.Socket;
 import java.security.KeyStore;
+import java.security.Principal;
+import java.security.cert.Certificate;
+import java.security.cert.X509Certificate;
 import java.util.logging.Level;
 
 import javax.naming.ldap.LdapName;
@@ -22,6 +25,7 @@
 import javax.net.ssl.SSLContext;
 import javax.net.ssl.SSLServerSocket;
 import javax.net.ssl.SSLServerSocketFactory;
+import javax.net.ssl.SSLSession;
 import javax.net.ssl.SSLSocket;
 import javax.net.ssl.SSLSocketFactory;
 import javax.net.ssl.TrustManagerFactory;
@@ -175,19 +179,84 @@ public static Socket createClientSocket(final InetSocketAddress address, final b
         socket.setEnabledProtocols(PROTOCOLS);
         // Handshake starts when first writing, but that might delay SSL errors, so force handshake before we use the socket
         socket.startHandshake();
+
+        if (logger.isLoggable(Level.FINE))
+        {
+            try
+            {   // Key sections of example server certificate chain:
+                //
+                // Certificate[1]:
+                // Owner: O=xxx.site.org, C=US, CN=ioc
+                // Issuer: OU=EPICS Certificate Authority, O=ca.epics.org, C=US, CN=EPICS Root CA
+                //
+                // #1: ObjectId: 1.3.6.1.4.1.37427.1 Criticality=false
+                // 0000: 43 45 52 54 3A 53 54 41   54 55 53 3A 64 30 62 62  CERT:STATUS:d0bb...
+               //
+                // Certificate[2]:
+                // Owner: OU=EPICS Certificate Authority, O=ca.epics.org, C=US, CN=EPICS Root CA
+                // Issuer: OU=EPICS Certificate Authority, O=ca.epics.org, C=US, CN=EPICS Root CA
+                //
+                // #1: ObjectId: 1.3.6.1.4.1.37427.1 Criticality=false
+                // 0000: 43 45 52 54 3A 53 54 41   54 55 53 3A 64 30 62 62  CERT:STATUS:d0bb...
+                final SSLSession session = socket.getSession();
+                logger.log(Level.FINE, "Server name: '" + getPrincipalCN(session.getPeerPrincipal()) + "'");
+                for (Certificate cert : session.getPeerCertificates())
+                    if (cert instanceof X509Certificate x509)
+                    {
+                        logger.log(Level.FINE, "* " + x509.getSubjectX500Principal());
+                        if (session.getPeerPrincipal().equals(x509.getSubjectX500Principal()))
+                            logger.log(Level.FINE, "  - Server/IOC CN");
+                        if (x509.getBasicConstraints() >= 0)
+                            logger.log(Level.FINE, "  - Certificate Authority");
+                        logger.log(Level.FINE, "  - Expires " + x509.getNotAfter());
+                        if (x509.getSubjectX500Principal().equals(x509.getIssuerX500Principal()))
+                            logger.log(Level.FINE, "  - Self-signed");
+
+                        byte[] value = x509.getExtensionValue("1.3.6.1.4.1.37427.1");
+                        logger.log(Level.FINE, "  - Status PV: " + decodeDERString(value));
+                    }
+            }
+            catch (Exception ex)
+            {
+                logger.log(Level.WARNING, "Error while logging result of handshake with server", ex);
+            }
+        }
+
         return socket;
     }
 
-    /** Get name from local principal
+    /** Decode DER String
+     *  @param der_value
+     *  @return
+     *  @throws Exception on error
+     */
+    public static String decodeDERString(final byte[] der_value) throws Exception
+    {
+        if (der_value == null)
+            return null;
+        // https://en.wikipedia.org/wiki/X.690#DER_encoding:
+        // Type 4, length 0..127, characters
+        if (der_value.length < 2)
+            throw new Exception("Need DER type and size, only received " + der_value.length + " bytes");
+        if (der_value[0] != 0x04)
+            throw new Exception(String.format("Expected DER Octet String 0x04, got 0x%02X", der_value[0]));
+        if (der_value[1] < 0)
+            throw new Exception("Can only handle strings of length 0-127, got " + der_value[1]);
+        if (der_value[1] != der_value.length-2)
+            throw new Exception("DER string length " + der_value[1] + " but " + (der_value.length-2) + " data items");
+        return new String(der_value, 2, der_value[1]);
+    }
+
+    /** Get CN from principal
      *
-     *  @param socket {@link SSLSocket} that may have local principal
-     *  @return Name (without "CN=..") if socket has certificate to authenticate or <code>null</code>
+     *  @param principal {@link Principal} that may have a CN
+     *  @return CN value (without "CN=..") or <code>null</code>
      */
-    public static String getLocalPrincipalName(final SSLSocket socket)
+    public static String getPrincipalCN(final Principal principal)
     {
         try
         {
-            final LdapName ldn = new LdapName(socket.getSession().getLocalPrincipal().getName());
+            final LdapName ldn = new LdapName(principal.getName());
             for (Rdn rdn : ldn.getRdns())
                 if (rdn.getType().equals("CN"))
                     return (String) rdn.getValue();
@@ -229,14 +298,16 @@ public static TLSHandshakeInfo fromSocket(final SSLSocket socket) throws Excepti
             {
                 // No way to check if there is peer info (certificates, principal, ...)
                 // other then success vs. exception..
-                String name = socket.getSession().getPeerPrincipal().getName();
-                if (name.startsWith("CN="))
-                    name = name.substring(3);
-                else
-                    logger.log(Level.WARNING, "Peer " + socket.getInetAddress() + " sent '" + name + "' as principal name, expected 'CN=...'");
+                final Principal principal = socket.getSession().getPeerPrincipal();
+                String name = getPrincipalCN(principal);
+                if (name == null)
+                {
+                    logger.log(Level.WARNING, "Peer " + socket.getInetAddress() + " sent '" + principal + "' as principal name, expected 'CN=...'");
+                    name = principal.getName();
+                }
+
                 final TLSHandshakeInfo info = new TLSHandshakeInfo();
                 info.name = name;
-
                 info.hostname = socket.getInetAddress().getHostName();
 
                 return info;
