Enable Security Profile 3 (TLS with Client Side Certificates)

In PR #22, we created a one-line demo that allowed us to test end to end charging with OCPP 2.0.1. However it only supports Basic Auth

This issue will track the changes required to change it to support Security Profile 3 (2 in MaEVe since it starts with 0), using a client certificate for authentication.
It will temporarily use a forked version of MaEVe that has hardcoded certificates from an adversarial PKI testing event. Eventually, we will want to have the demo use an open CA and non-proprietary certificates, but make it easy to configure so that testers can easily use proprietary certificates or implementations.
@jhoshiko @sahabulh @crr-snl for visibility

First decision: Do we try for profile 1 or just go ahead with profile 2? Given the time left, I am going to try directly for profile 2, but will fall back to profile 1 if I run into glitches.

The fork () has several hardcoded certificates, which are the ones passed in to the maeve command line.
      - "--tls-server-cert"
      - "/certificates/csms.pem"
      - "--tls-server-key"
      - "/certificates/csms.key"
      - "--tls-trust-cert"
      - "/certificates/trust.pem"

Compared to the list of certificates created by the Makefile from ((cd config/certificates && make)), which, in turn calls the [get-ca-cert.sh](https://github.com/thoughtworks/maeve-csms/blob/main/scripts/get-ca-cert.sh) script, we have:

[ ] cpo_sub_ca1.pem
[x] cpo_sub_ca2.pem
[x] root-V2G-cert.pem

It certainly seems like the checked in cpo_sub_ca2 inherits directly from the root
$ openssl verify -show_chain -CAfile config/certificates/MORootCACert.pem config/certificates/cpo_sub_ca2.pem
config/certificates/cpo_sub_ca2.pem: OK
Chain:
depth=0: C = US, O = EV Charging PKI, OU = TEST MO Sub-CA, CN = P-256 TEST Tier 1 MO Sub-CA (untrusted)
depth=1: C = US, O = EV Charging PKI, DC = EVCPKI, OU = TEST Root CA, CN = P-256 TEST Root CA

So I am not sure why it is not just named cpo_sub_ca2. As an aside, I wonder if the PKI testing event should include an intermediate certificate just to make things more complex.

Moving along, I see a new start-maeve.sh. This essentially runs the same docker-compose as always, but has a couple of other lines to register tokens. However, there is no command to register a station with a client certificate. In the spirit of working to working, let's see if this starts properly and we can add the station at the basic auth level.

checking EVerest, it is consistent with OCPP and not with MaEVe. We might want to file an issue against MaEVe to make it consistent with the OCPP standard.
https://github.com/EVerest/EVerest/blob/4ae3884d65a5a0011bb26a59a0b59c18e83c79f6/docs/tutorials/how_to_ocpp/index.rst#L189
The same 201 configuration that we used earlier has the securityProfile. if we just change this to wss:// and securityProfile:2, will it Just Work with the CSMS configuration?
                    "Actual": "[{\"configurationSlot\": 1, \"connectionData\": {\"messageTimeout\": 30, \"ocppCsmsUrl\": \"ws://localhost:9000/cp001\", \"ocppInterface\": \"Wired0\", \"ocppTransport\": \"JSON\", \"ocppVersion\": \"OCPP20\", \"securityProfile\": 1}}]"

so it is in fact easier to try with OCPP SP 2 (Maeve: 1) first and we will do it.

~The constant that we are looking for is TLS_WITH_CLIENT_SIDE_CERTIFICATES. Let's see how we handle certificates in that case.~ That only seems to be used for the websocket connection.
It looks like this would be specified in the SecurityCtrl

Forked Maeve is finally up.

Let's make sure that the existing connections (with basic auth, unencrypted SP) still work. Bingo

everest-demo-manager-1      | 2024-03-10 21:05:42.976901 [INFO] ocpp:OCPP201     :: OCPP client successfully connected to plain websocket server
everest-demo-manager-1      | 2024-03-10 21:05:42.987001 [INFO] ocpp:OCPP201     :: Received BootNotificationResponse: {
everest-demo-manager-1      |     "currentTime": "2024-03-10T21:05:42.000Z",
everest-demo-manager-1      |     "interval": 300,
everest-demo-manager-1      |     "status": "Accepted"
everest-demo-manager-1      | }
everest-demo-manager-1      | with messageId: 3f4d42a2-d961-428d-be19-818f11b95857

Now, let's add a new station with a higher security profile and the same password

 curl http://localhost:9410/api/v0/cs/cp002 -H 'content-type: application/json' \
> -d '{"securityProfile": 1, "base64SHA256Password": "3oGi4B5I+Y9iEkYtL7xvuUxrvGOXM/X2LQrsCwf/knA="}'

Now let's change the connection to wss, the station to cp002 and the security profile to 2
sqlite> update VARIABLE_ATTRIBUTE set "VALUE" = '[{"configurationSlot": 1, "connectionData": {"messageTimeout": 30, "ocppCsmsUrl": "wss://host.docker.internal/ws/cp002", "ocppInterface": "Wired0", "ocppTransport": "JSON", "ocppVersion": "OCPP20", "securityProfile": 2}}]' where VARIABLE_ID == 19;
sqlite> select * from VARIABLE_ATTRIBUTE where VARIABLE_ID == 19;
19|19|2|1|0|0|[{"configurationSlot": 1, "connectionData": {"messageTimeout": 30, "ocppCsmsUrl": "wss://host.docker.internal/ws/cp002", "ocppInterface": "Wired0", "ocppTransport": "JSON", "ocppVersion": "OCPP20", "securityProfile": 2}}]

Now we try to make a CSMS connection, but fail because we don't have the CSMS root installed correctly. Ha! figuring out code through log statements!
2024-03-10 21:27:31.928547 [INFO] ocpp:OCPP201     :: All EVSE ready. Starting OCPP2.0.1 service
2024-03-10 21:27:32.032225 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp002 with profile 2
2024-03-10 21:27:32.198246 [INFO] evse_security:E  :: Requesting certificate file: CSMS
2024-03-10 21:27:32.139004 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-10 21:27:32.310501 [INFO] evse_security:E  :: Requesting certificate file: CSMS
2024-03-10 21:27:32.425798 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl

Checking the mailing list, we also get (from https://lists.lfenergy.org/g/everest/message/1255)
 csms_leaf_cert_directory:
description: Directory where CSMS leaf certificates are stored. If relative will be prefixed with everest prefix + etc/everest/certs. Otherwise absolute file path is used.
type: string
default: client/csms
csms_leaf_key_directory:
description: Directory where CSMS private keys are stored. If relative will be prefixed with everest prefix + etc/everest/certs. Otherwise absolute file path is used.
type: string
default: client/csms

and
 csms_ca_bundle:
description: Path to csms_ca_bundle file. If relative will be prefixed with everest prefix + etc/everest/certs. Otherwise absolute file path is used.
type: string
default: ca/v2g/V2G_ROOT_CA.pem

For the record, these are parameters to the EVSE security module https://github.com/EVerest/everest-core/blob/55416be6d11fc85bf1943ecb3c57b267f24ccdaf/modules/EvseSecurity/manifest.yaml#L37 (as one might have guessed) and would be overridden here in our demo: https://github.com/EVerest/everest-core/blob/55416be6d11fc85bf1943ecb3c57b267f24ccdaf/config/config-sil-ocpp201.yaml#L134 (like the private_key_password curently is)

While copying the root V2G cert that is required, i wondered whether I should copy the root-V2G-cert.pem or MORootCACert.pem, before discovering that they are, in fact, the same
$ diff config/certificates/root-V2G-cert.pem config/certificates/MORootCACert.pem

(I originally found this by trying to verify the csms certificate against both roots and finding that it validated in both cases!!)
$ openssl verify -show_chain -CAfile config/certificates/root-V2G-cert.pem -untrusted config/certificates/cpo_sub_ca2.pem config/certificates/csms.pem
config/certificates/csms.pem: OK
Chain:
depth=0: C = US, O = Sandia, OU = EV Department, CN = USEMAC00000004 (untrusted)
depth=1: C = US, O = EV Charging PKI, OU = TEST MO Sub-CA, CN = P-256 TEST Tier 1 MO Sub-CA (untrusted)
depth=2: C = US, O = EV Charging PKI, DC = EVCPKI, OU = TEST Root CA, CN = P-256 TEST Root CA

After manually copying the root CA, the
$ docker cp ~/joet-everest/maeve-csms/config/certificates/root-V2G-cert.pem everest-demo-manager-1:/workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
Successfully copied 3.58kB to everest-demo-manager-1:/workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem

The handshake is still failing. Given that we are at security profile 2 (TLS with basic auth), with the following diagram from the spec, I would assume that as long as we had the root certificate installed in the CSMS, we would not need the CSMS certificate to be preinstalled.

But I'm still getting the same failure
2024-03-10 22:07:54.385075 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp002 with profile 2
2024-03-10 22:07:54.535828 [INFO] evse_security:E  :: Requesting certificate file: CSMS
2024-03-10 22:07:54.475198 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-10 22:07:54.648244 [INFO] evse_security:E  :: Requesting certificate file: CSMS
2024-03-10 22:07:54.757161 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl

even though the root cert is installed
# ls -al /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
-rw-r--r--    1 19017117 dialout        814 Mar 10 18:47 /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem

Maybe we have to copy in the entire bundle and not only the root? Do we also need to copy over the leaves in that case?
Let's check the code...

From the code, it looks like there are multiple bundles and several of them seem to have the same name.
Although the
    ocpp::SecurityConfiguration secConfig;
    secConfig.csms_ca_bundle = fs::path("/tmp/certs/ca/v2g/V2G_CA_BUNDLE.pem");
    secConfig.mf_ca_bundle = fs::path("/tmp/certs/ca/v2g/V2G_CA_BUNDLE.pem");
    secConfig.v2g_ca_bundle = fs::path("/tmp/certs/ca/v2g/V2G_CA_BUNDLE.pem");
    secConfig.mo_ca_bundle = fs::path("/tmp/certs/ca/mo/MO_CA_BUNDLE.pem");

I found the mapping code but it looks like it has changed since the previous EVerest version.
    X509CertificateBundle verify_file(this->ca_bundle_path_map.at(certificate_type), EncodingFormat::PEM);

    EVLOG_debug << "Requesting certificate file: [" << conversions::ca_certificate_type_to_string(certificate_type)
                << "] file:" << verify_file.get_path();

But it looks like we do expect it to be a bundle, so let's copy over the bundle and see if it works.

Aha! It turns out that EVerest autogenerates CSMS keys if it doesn't find them
# openssl verify --show_chain /workspace/dist/etc/everest/certs/ca/csms/CPO_SUB_CA1.pem
CN = CPOSubCA1, O = EVerest, C = DE, DC = V2G
error 20 at 0 depth lookup: unable to get local issuer certificate
error /workspace/dist/etc/everest/certs/ca/csms/CPO_SUB_CA1.pem: verification failed

Let's delete all the certs and retry

Here is the full list of certs that EVerest currently has installed
# find /workspace/dist/etc/everest/certs
/workspace/dist/etc/everest/certs
/workspace/dist/etc/everest/certs/client
/workspace/dist/etc/everest/certs/client/cps
/workspace/dist/etc/everest/certs/client/cps/CPS_SUB_CA2.key
/workspace/dist/etc/everest/certs/client/cps/CPS_CERT_CHAIN.p12
/workspace/dist/etc/everest/certs/client/cps/CPS_SUB_CA1.key
/workspace/dist/etc/everest/certs/client/cps/CPS_LEAF.key
/workspace/dist/etc/everest/certs/client/cps/CPS_LEAF.pem
/workspace/dist/etc/everest/certs/client/cps/CPS_LEAF.der
/workspace/dist/etc/everest/certs/client/cps/CPS_LEAF_PASSWORD.txt
/workspace/dist/etc/everest/certs/client/mf
/workspace/dist/etc/everest/certs/client/cso
/workspace/dist/etc/everest/certs/client/cso/CPO_CERT_CHAIN.pem
/workspace/dist/etc/everest/certs/client/cso/SECC_LEAF.pem
/workspace/dist/etc/everest/certs/client/cso/SECC_LEAF.key
/workspace/dist/etc/everest/certs/client/cso/SECC_LEAF_PASSWORD.txt
/workspace/dist/etc/everest/certs/client/cso/SECC_LEAF.der
/workspace/dist/etc/everest/certs/client/csms
/workspace/dist/etc/everest/certs/client/csms/CPO_SUB_CA1.key
/workspace/dist/etc/everest/certs/client/csms/CPO_SUB_CA2.key
/workspace/dist/etc/everest/certs/client/mo
/workspace/dist/etc/everest/certs/client/mo/MO_LEAF.key
/workspace/dist/etc/everest/certs/client/mo/MO_LEAF.der
/workspace/dist/etc/everest/certs/client/mo/MO_ROOT_CA.key
/workspace/dist/etc/everest/certs/client/mo/MO_SUB_CA1.key
/workspace/dist/etc/everest/certs/client/mo/MO_LEAF_PASSWORD.txt
/workspace/dist/etc/everest/certs/client/mo/MO_CERT_CHAIN.p12
/workspace/dist/etc/everest/certs/client/mo/MO_LEAF.pem
/workspace/dist/etc/everest/certs/client/mo/MO_SUB_CA2.pkcs8.der
/workspace/dist/etc/everest/certs/client/mo/MO_SUB_CA2_LEAF_PASSWORD.txt
/workspace/dist/etc/everest/certs/client/mo/MO_SUB_CA2.key
/workspace/dist/etc/everest/certs/client/oem
/workspace/dist/etc/everest/certs/client/oem/EVCC_KEYSTORE.jks
/workspace/dist/etc/everest/certs/client/oem/EVCC_TRUSTSTORE.jks
/workspace/dist/etc/everest/certs/client/oem/OEM_CERT_CHAIN.p12
/workspace/dist/etc/everest/certs/client/oem/OEM_LEAF.der
/workspace/dist/etc/everest/certs/client/oem/OEM_LEAF_PASSWORD.txt
/workspace/dist/etc/everest/certs/client/oem/OEM_SUB_CA1.key
/workspace/dist/etc/everest/certs/client/oem/OEM_SUB_CA2.key
/workspace/dist/etc/everest/certs/client/oem/OEM_LEAF.pem
/workspace/dist/etc/everest/certs/client/oem/OEM_LEAF.key
/workspace/dist/etc/everest/certs/client/oem/OEM_ROOT_CA.key
/workspace/dist/etc/everest/certs/ca
/workspace/dist/etc/everest/certs/ca/cps
/workspace/dist/etc/everest/certs/ca/cps/CPS_SUB_CA2.der
/workspace/dist/etc/everest/certs/ca/cps/CPS_SUB_CA1.der
/workspace/dist/etc/everest/certs/ca/cps/CPS_SUB_CA1.pem
/workspace/dist/etc/everest/certs/ca/cps/INTERMEDIATE_CPS_CA_CERTS.pem
/workspace/dist/etc/everest/certs/ca/cps/CPS_SUB_CA2.pem
/workspace/dist/etc/everest/certs/ca/v2g
/workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
/workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.der
/workspace/dist/etc/everest/certs/ca/mf
/workspace/dist/etc/everest/certs/ca/mf/MF_ROOT_CA.pem
/workspace/dist/etc/everest/certs/ca/cso
/workspace/dist/etc/everest/certs/ca/cso/CPO_SUB_CA2.pem
/workspace/dist/etc/everest/certs/ca/cso/CPO_SUB_CA1.pem
/workspace/dist/etc/everest/certs/ca/cso/CPO_SUB_CA1_LEAF.der
/workspace/dist/etc/everest/certs/ca/cso/CPO_SUB_CA2_LEAF.der
/workspace/dist/etc/everest/certs/ca/csms
/workspace/dist/etc/everest/certs/ca/csms/CPO_SUB_CA2.pem
/workspace/dist/etc/everest/certs/ca/csms/CPO_SUB_CA1.pem
/workspace/dist/etc/everest/certs/ca/csms/CPO_SUB_CA1_LEAF.der
/workspace/dist/etc/everest/certs/ca/csms/CPO_SUB_CA2_LEAF.der
/workspace/dist/etc/everest/certs/ca/mo
/workspace/dist/etc/everest/certs/ca/mo/MO_SUB_CA1.der
/workspace/dist/etc/everest/certs/ca/mo/MO_ROOT_CA.pem
/workspace/dist/etc/everest/certs/ca/mo/MO_ROOT_CA.der
/workspace/dist/etc/everest/certs/ca/mo/MO_SUB_CA2.der
/workspace/dist/etc/everest/certs/ca/mo/MO_SUB_CA2.pem
/workspace/dist/etc/everest/certs/ca/mo/INTERMEDIATE_MO_CA_CERTS.pem
/workspace/dist/etc/everest/certs/ca/mo/MO_SUB_CA1.pem
/workspace/dist/etc/everest/certs/ca/oem
/workspace/dist/etc/everest/certs/ca/oem/OEM_SUB_CA2.pem
/workspace/dist/etc/everest/certs/ca/oem/OEM_SUB_CA1.der
/workspace/dist/etc/everest/certs/ca/oem/INTERMEDIATE_OEM_CA.pem
/workspace/dist/etc/everest/certs/ca/oem/OEM_ROOT_CA.pem
/workspace/dist/etc/everest/certs/ca/oem/OEM_SUB_CA1.pem
/workspace/dist/etc/everest/certs/ca/oem/OEM_SUB_CA2.der
/workspace/dist/etc/everest/certs/ca/oem/OEM_CERT_CHAIN.pem
/workspace/dist/etc/everest/certs/ca/oem/OEM_ROOT_CA.der
56c4a608a93c:/workspace#

Deleting all of them and only recreating the V2G bundle...

Checking the generate_test_certs.sh, we need to:

have the V2G root CA
have the CPO cert(s) in the CSMS path
have the V2G bundle as $CA_V2G_PATH/V2G_CA_BUNDLE.pem

Let's get all of them in place and see if it works. We then need to ask the EVerest team to clean this up

I've tried the bundle and the root in various places and they all fail. Concretely, this is really confusing - this is supposed to be the bundle, but the default is set to ROOT_CA.pem. if we make this be the bundle, then where is the root for it to verify against?
csms_ca_bundle:
description: Path to csms_ca_bundle file. If relative will be prefixed with everest prefix + etc/everest/certs. Otherwise absolute file path is used.
type: string
default: ca/v2g/V2G_ROOT_CA.pem

Next steps:

will try to put in the root as root and the leaf in the directory
will try to upgrade to the most recent version of EVerest (in case there are code fixes)
will poke through the code some more
will ask the EVerest community to clarify

Ok so now the container has all the certs needed for validation
# openssl verify --show_chain -CAfile /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem -untrusted /workspace/dist/etc/everest/certs/ca/csms/CPO_SUB_CA2.pem /workspace/dist/etc/everest/certs/ca/csms/csms.pem
/workspace/dist/etc/everest/certs/ca/csms/csms.pem: OK
Chain:
depth=0: C = US, O = Sandia, OU = EV Department, CN = USEMAC00000004 (untrusted)
depth=1: C = US, O = EV Charging PKI, OU = TEST MO Sub-CA, CN = P-256 TEST Tier 1 MO Sub-CA (untrusted)
depth=2: C = US, O = EV Charging PKI, DC = EVCPKI, OU = TEST Root CA, CN = P-256 TEST Root CA

Does it work?

Nope, failed
2024-03-10 23:20:52.072019 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp002 with profile 2
2024-03-10 23:20:52.230144 [INFO] evse_security:E  :: Requesting certificate file: CSMS
2024-03-10 23:20:52.172485 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-10 23:20:52.393411 [INFO] evse_security:E  :: Requesting certificate file: CSMS
2024-03-10 23:20:52.501315 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl

Before I upgrade, I am going to try one more thing: Take the certs from EVerest and put them into MaEVe and see if we can get that to work. Then it is just certificate wrangling, after an update to make sure that everything works properly.

Checking the current version of the script, it generates keys directly via openssl - e.g.
/ext/cache/cpm/libevse-security/4f93b8e3adbd827ed9b21a75891dbe39c13101a2/libevse-security/tests

openssl ecparam -genkey -name "$EC_CURVE" | openssl ec "$SYMMETRIC_CIPHER" -passout pass:"$password" -out "$CLIENT_CSO_PATH/SECC_LEAF.key"
openssl req -new -key "$CLIENT_CSO_PATH/SECC_LEAF.key" -passin pass:"$password" -config configs/seccLeafCert.cnf -out "$CSR_PATH/SECC_LEAF.csr"
openssl x509 -req -in "$CSR_PATH/SECC_LEAF.csr" -extfile configs/seccLeafCert.cnf -extensions ext -CA "$CA_CSMS_PATH/CPO_SUB_CA2.pem" -CAkey "$CLIENT_CSMS_PATH/CPO_SUB_CA2.key" -passin pass:"$password" -set_serial 12348 -days "$VALIDITY" -out "$CLIENT_CSO_PATH/SECC_LEAF.pem"

And then the SECC key is copied over as the CSMS key
cp "$CLIENT_CSO_PATH/SECC_LEAF.key" "$CLIENT_CSMS_PATH/CSMS_LEAF.key"

# assume CSO and CSMS are same authority
cp -r $CA_CSMS_PATH/* $CA_CSO_PATH
cp "$CLIENT_CSO_PATH/SECC_LEAF.pem" "$CLIENT_CSMS_PATH/CSMS_LEAF.pem"

Copied over, the new chain in the CSMS is now valid
$ openssl verify -show_chain -CAfile config/certificates/root-V2G-cert.pem -untrusted config/certificates/cpo_sub_ca1.pem -untrusted config/certificates/cpo_sub_ca2.pem config/certificates/csms.pem
config/certificates/csms.pem: OK
Chain:
depth=0: CN = SECCCert, O = EVerest, C = DE, DC = CPO (untrusted)
depth=1: CN = CPOSubCA2, O = EVerest, C = DE, DC = V2G (untrusted)
depth=2: CN = CPOSubCA1, O = EVerest, C = DE, DC = V2G (untrusted)
depth=3: CN = V2GRootCA, O = EVerest, C = DE, DC = V2G

The MaEVe certificate generation has the following
cat "${script_dir}"/../config/certificates/cpo_sub_ca1.pem "${script_dir}"/../config/certificates/cpo_sub_ca2.pem > "${script_dir}"/../config/certificates/trust.pem

But the trust.pem that is checked into the fork is not a concatenation but directly derived from the root
openssl verify -show_chain -CAfile config/certificates/MORootCACert.pem config/certificates/trust.pem
config/certificates/trust.pem: OK
Chain:
depth=0: C = US, O = EV Charging PKI, OU = TEST MO Sub-CA, CN = P-256 TEST Tier 1 MO Sub-CA (untrusted)
depth=1: C = US, O = EV Charging PKI, DC = EVCPKI, OU = TEST Root CA, CN = P-256 TEST Root CA

Since we have replaced the certs, let's replace the trust as well.

I'm still getting the same error. Aha! the error is in MaEVe and was masked because we started with -d
$ docker logs maeve-csms-gateway-1
Error: processing tls key pair: tls: failed to parse private key
Usage:

All the keys are valid, but are EC (not RSA) and have a password
openssl ec -in config/certificates/cpo_sub_ca1.key
read EC key
Enter pass phrase for config/certificates/cpo_sub_ca1.key:
writing EC key
-----BEGIN EC PRIVATE KEY-----
...
-----END EC PRIVATE KEY-----

This is thrown from
            tlsCert, err := tls.X509KeyPair(cb, kb)
            if err != nil {
                return fmt.Errorf("processing tls key pair: %v", err)
            }

Verified, by testing with the sample code in the go X509 code, that the cpo_sub_ca1 keypair generates the same error.
Wait was this the error all along?
Do the certs checked in to the fork actually work?! csms.key and csms.pem work
https://github.com/EVerest/everest-demo/assets/2423263/da315b6e-ab50-4239-b943-00210123c13b
BUT, cpo_sub_ca2.pem and cpo_sub_ca2.key (as checked in right now) DO NOT WORK @sahabulh @crr-snl for visibility.

https://github.com/EVerest/everest-demo/assets/2423263/77052d17-8f01-4529-ba0c-283e317c9562

However, the CSMS keypair is still fine, so the gateway starts up properly from the fork.
$ git status
On branch current_fork
nothing to commit, working tree clean

maeve-csms-manager-1    | time=2024-03-11T01:24:37.283Z level=INFO msg="checking for pending charge station certificates changes"
maeve-csms-manager-1    | time=2024-03-11T01:24:37.283Z level=INFO msg="checking for pending charge station settings changes"
maeve-csms-manager-1    | time=2024-03-11T01:24:37.283Z level=INFO msg="sync triggers" duration=565.422794ms sync.trigger.previous="" sync.trigger.count=0

Regenerated keys after removing encryption + password (nuked all references to SYMMETRIC_CIPHER and PASSWORD) and re-ran
Checked the resulting key + cert combo in the go interactive coder (WORKS!)
Copying everything out and re-creating the cert chain in the CSMS

CSMS now starts successfully

Launch the station

Failed again!!
CSMS error: maeve-csms-gateway-1    | 2024/03/11 01:48:41 http: TLS handshake error from <IP_ADDRESS>:39520: local error: tls: bad record MAC

tls: bad record MAC just means that the incoming packet is corrupted in some way. Potential fixes include:

checking the TLS/encryption versions OR
using the full chain as the key instead of the leaf

This is where the python version would be helpful - it would allow us have an inspectable working version which we can then use to compare against the non-working versions. I should also be able to inspect the network but not sure what I can see with an encrypted connection.

Tried turning off the load balancer
Added a station with unencrypted security profile (curl http://localhost:9410/api/v0/cs/cp001 -H 'content-type: application/json' -d '{"securityProfile": 0, "base64SHA256Password": "3oGi4B5I+Y9iEkYtL7xvuUxrvGOXM/X2LQrsCwf/knA="}'
Changed the connection URL to ws://host.docker.internal:9310/ws/cp001 (update VARIABLE_ATTRIBUTE set "VALUE" = '[{"configurationSlot": 1, "connectionData": {"messageTimeout": 30, "ocppCsmsUrl": "ws://host.docker.internal:9310/ws/cp001", "ocppInterface": "Wired0", "ocppTransport": "JSON", "ocppVersion": "OCPP20", "securityProfile": 1}}]' where VARIABLE_ID == 19;)
Connection successful
Added a station with encrypted security profile (curl http://localhost:9410/api/v0/cs/cp002 -H 'content-type: application/json' -d '{"securityProfile": 1, "base64SHA256Password": "3oGi4B5I+Y9iEkYtL7xvuUxrvGOXM/X2LQrsCwf/knA="}')
Changed the connection settings (update VARIABLE_ATTRIBUTE set "VALUE" = '[{"configurationSlot": 1, "connectionData": {"messageTimeout": 30, "ocppCsmsUrl": "ws://host.docker.internal:9311/ws/cp002", "ocppInterface": "Wired0", "ocppTransport": "JSON", "ocppVersion": "OCPP20", "securityProfile": 2}}]' where VARIABLE_ID == 19;)

TLS handshake error from <IP_ADDRESS>:19797: local error: tls: bad record MAC

My next step will be to write a simple python program that we can run in the same docker container and make the same connection. This is an alternative to getting access to the python-based EVSE implementation. However, I am going to upgrade to the most recent release since there have been several changes to the security code since then. I will then create an example of a broken docker-compose and send it out to the community in parallel with my own investigation.

The fork () has several hardcoded certificates, which are the ones passed in to the maeve command line.
      - "--tls-server-cert"
      - "/certificates/csms.pem"
      - "--tls-server-key"
      - "/certificates/csms.key"
      - "--tls-trust-cert"
      - "/certificates/trust.pem"

Compared to the list of certificates created by the Makefile from ((cd config/certificates && make)), which, in turn calls the [get-ca-cert.sh](https://github.com/thoughtworks/maeve-csms/blob/main/scripts/get-ca-cert.sh) script, we have:

[ ]  cpo_sub_ca1.pem
[x]  cpo_sub_ca2.pem
[x]  root-V2G-cert.pem

It certainly seems like the checked in cpo_sub_ca2 inherits directly from the root
$ openssl verify -show_chain -CAfile config/certificates/MORootCACert.pem config/certificates/cpo_sub_ca2.pem
config/certificates/cpo_sub_ca2.pem: OK
Chain:
depth=0: C = US, O = EV Charging PKI, OU = TEST MO Sub-CA, CN = P-256 TEST Tier 1 MO Sub-CA (untrusted)
depth=1: C = US, O = EV Charging PKI, DC = EVCPKI, OU = TEST Root CA, CN = P-256 TEST Root CA

So I am not sure why it is not just named cpo_sub_ca1. As an aside, I wonder if the PKI testing event should include an intermediate certificate just to make things more complex.

ISO 15118 states that if only 1 SubCA/ICA is present, it has to use the profile of SubCA 2. That's why I names it that way to avoid confusion.

While copying the root V2G cert that is required, i wondered whether I should copy the root-V2G-cert.pem or MORootCACert.pem, before discovering that they are, in fact, the same
$ diff config/certificates/root-V2G-cert.pem config/certificates/MORootCACert.pem

(I originally found this by trying to verify the csms certificate against both roots and finding that it validated in both cases!!)
$ openssl verify -show_chain -CAfile config/certificates/root-V2G-cert.pem -untrusted config/certificates/cpo_sub_ca2.pem config/certificates/csms.pem
config/certificates/csms.pem: OK
Chain:
depth=0: C = US, O = Sandia, OU = EV Department, CN = USEMAC00000004 (untrusted)
depth=1: C = US, O = EV Charging PKI, OU = TEST MO Sub-CA, CN = P-256 TEST Tier 1 MO Sub-CA (untrusted)
depth=2: C = US, O = EV Charging PKI, DC = EVCPKI, OU = TEST Root CA, CN = P-256 TEST Root CA

Again, for the sake for simplicity, I used the same root, same SubCA and same leaf everywhere. That means all the cryptography related files for MO, OEM, CPO/CSO, V2G are same. We can of course use different certs and keys for different chains.

After manually copying the root CA, the
$ docker cp ~/joet-everest/maeve-csms/config/certificates/root-V2G-cert.pem everest-demo-manager-1:/workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
Successfully copied 3.58kB to everest-demo-manager-1:/workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem

The handshake is still failing. Given that we are at security profile 2 (TLS with basic auth), with the following diagram from the spec, I would assume that as long as we had the root certificate installed in the CSMS, we would not need the CSMS certificate to be preinstalled.

But I'm still getting the same failure
2024-03-10 22:07:54.385075 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp002 with profile 2
2024-03-10 22:07:54.535828 [INFO] evse_security:E  :: Requesting certificate file: CSMS
2024-03-10 22:07:54.475198 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-10 22:07:54.648244 [INFO] evse_security:E  :: Requesting certificate file: CSMS
2024-03-10 22:07:54.757161 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl

even though the root cert is installed
# ls -al /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
-rw-r--r--    1 19017117 dialout        814 Mar 10 18:47 /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem

Maybe we have to copy in the entire bundle and not only the root? Do we also need to copy over the leaves in that case? Let's check the code...

Why do we need the CSMS key to be present in EVerest? It should be a private property of the CSMS, which is an external entity.

V2G_CA_BUNDLE

What certs makes up a bundle? RootCA and SubCAs? Only SubCAs? What is the order?

Bumped up the everest version
https://github.com/EVerest/everest-demo/pull/26
Will wait for clean images to build before retrying the SSL connection.

Why do we need the CSMS key to be present in EVerest? It should be a private property of the CSMS, which is an external entity.

As I said:

The handshake is still failing. Given that we are at security profile 2 (TLS with basic auth), with the following diagram from the spec, I would assume that as long as we had the root certificate installed in the CSMS, we would not need the CSMS certificate to be preinstalled.

However, given that the TLS handshake was failing, it could be that the EVerest implementation was incorrect. As you can see from the history, there are configuration parameters to the security module that refer to the CSMS certificate and key.

What certs makes up a bundle? RootCA and SubCAs? Only SubCAs? What is the order?

Please see my comment around the code in the generate scripts shell script that generates the bundle.

I've tried the bundle and the root in various places and they all fail. Concretely, this is really confusing - this is supposed to be the bundle, but the default is set to ROOT_CA.pem. if we make this be the bundle, then where is the root for it to verify against?
csms_ca_bundle:
description: Path to csms_ca_bundle file. If relative will be prefixed with everest prefix + etc/everest/certs. Otherwise absolute file path is used.
type: string
default: ca/v2g/V2G_ROOT_CA.pem

Next steps:

will try to put in the root as root and the leaf in the directory
will try to upgrade to the most recent version of EVerest (in case there are code fixes)
will poke through the code some more
will ask the EVerest community to clarify

This is really confusing. There should be a consistent way to organize all the certs. Also, I see CA keys inside the client folder. For example: /etc/everest/certs/client/csms folder contains CPO_SUB_CA1.key and CPO_SUB_CA2.key.

V2G_CA_BUNDLE

What certs makes up a bundle? RootCA and SubCAs? Only SubCAs? What is the order?

We should be using the bundles that EonTI has made available on Google Drive for use during the PKI test event at NREL. Keysight and Hubject have provided similar cert bundles for CharIn Testivals, but they're not in scope for April event.

We should be using the bundles that EonTI has made available on Google Drive for use during the PKI test event at NREL. Keysight and Hubject have provided similar cert bundles for CharIn Testivals, but they're not in scope for April event.

At least from Sahabul's fork, there are no certificate bundles in the certs provided by Eonti. By "bundles", I mean a full certificate chain, concatenated into a single pem file. Each pem file checked in contains a single cert. It is not clear where EVerest and/or MaEVe expect the chain. I do note the comment in the mailing list: https://lists.lfenergy.org/g/everest/message/1255
"Make sure to include all intermediate certs in the certificate chain file in the correct order."

V2G_CA_BUNDLE

If the CPO SubCA 2 key and cert doesn't match, that means the key is not needed of any authorization, which, I think, is true. The python OCPP client works fine without it so I didn't even notice that they were wrong.
And the certs in my MaEVe fork work because I can see it working. And like I mentioned above, the CPO SubCA 2 key is not needed for, at least, the authorization req/res pair.

After bumping up the version https://github.com/EVerest/everest-demo/pull/26, and https://github.com/EVerest/everest-demo/pull/28, we get a different error, which is more insightful
2024-03-11 16:35:35.667213 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-11 16:35:35.888409 [WARN] ocpp:OCPP201    bool ocpp::WebsocketTLS::verify_csms_cn(const std::string&, bool, boost::asio::ssl::verify_context&) :: Invalid certificate error 'unable to get local issuer certificate' (at chain depth '0')
2024-03-11 16:35:35.888709 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl

So it looks like we do need a full bundle there (Invalid certificate error 'unable to get local issuer certificate' (at chain depth '0')) One final try: copy over the bundle with debug logging before I give up.

Also, if we want more logging, we can edit dist/etc/everest/default_logging.cfg and set the filter to
Filter="%Severity% >= INFO or (%Process% contains OCPP201 and %Severity% >= DEBG)"

The second error comes from
std::string X509Wrapper::get_issuer_key_hash() const {
    if (is_selfsigned()) {
        return get_key_hash();
    } else {
        throw std::logic_error("get_issuer_key_hash must only be used on self-signed certs");
    }
}

Let's see where this is called, and with which cert

@shankari I am also testing in parallel to you and my findings are similar to yours. That's why I'm not adding any additional info here. I didn't try bumping up the version though. I was trying to make it work with 2023.10.0 as that is what currently supported by the hardware. But of course we can use the latest version for software testing.

I re-generated the certificates to have the correct FQDN for the CSMS certificate. The FQDN error is gone
2024-03-12 15:21:30.149417 [DEBG] ocpp:OCPP201    bool ocpp::WebsocketTLS::verify_csms_cn(const std::string&, bool, boost::asio::ssl::verify_context&) :: FQDN matches CN of server certificate: host.docker.internal

But I still see
2024-03-12 15:21:30.171826 [DEBG] ocpp:OCPP201    void Everest::MQTTAbstractionImpl::on_mqtt_message(std::shared_ptr<Everest::Message>) :: topic everest/evse_security/main/cmd starts with everest/
terminate called after throwing an instance of 'std::logic_error'
  what():  get_issuer_key_hash must only be used on self-signed certs
2024-03-12 15:21:30.214575 [CRIT] manager         int boot(const boost::program_options::variables_map&) :: Module evse_security (pid: 2192) exited with status: 6. Terminating all modules.

This seems like it might need to come from the CSMS
2024-03-12 15:21:30.171112 [DEBG] ocpp:OCPP201    Everest::Everest::subscribe_var(const Requirement&, const std::string&, const JsonCallback&)::<lambda(const Everest::json&)> :: Incoming evse_manager_2:EvseManager->evse:evse_manager->session_event
2024-03-12 15:21:30.171169 [DEBG] ocpp:OCPP201    void Everest::MQTTAbstractionImpl::on_mqtt_message(std::shared_ptr<Everest::Message>) :: topic everest/evse_manager_2/evse/var starts with everest/
2024-03-12 15:21:30.171347 [DEBG] ocpp:OCPP201    Everest::Everest::subscribe_var(const Requirement&, const std::string&, const JsonCallback&)::<lambda(const Everest::json&)> :: Incoming evse_manager_2:EvseManager->evse:evse_manager->session_event
2024-03-12 15:21:30.171664 [DEBG] ocpp:OCPP201    void Everest::MQTTAbstractionImpl::on_mqtt_message(std::shared_ptr<Everest::Message>) :: topic everest/evse_manager_1/evse/var starts with everest/
2024-03-12 15:21:30.171826 [DEBG] ocpp:OCPP201    void Everest::MQTTAbstractionImpl::on_mqtt_message(std::shared_ptr<Everest::Message>) :: topic everest/evse_security/main/cmd starts with everest/

I bet that the issue is that EVerest assumes that the CSMS certificate is also a bundle.
Tried to create a bundle
$ cp csms.pem csms_leaf.pem
$ cat csms_leaf.pem cpo_sub_ca2.pem cpo_sub_ca1.pem root-V2G-cert.pem > csms.pem

At this point, we are close - will create an MRE so that we can get support and then finish this up

Created MRE. The MRE doesn't have debug logging turned on, so without the log spew, we can see that the connection actually succeeds.
2024-03-12 17:23:41.145898 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp001 with security-profile 2
2024-03-12 17:23:41.193596 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-12 17:23:41.379596 [INFO] ocpp:OCPP201     :: OCPP client successfully connected to TLS websocket server
2024-03-12 17:23:41.396522 [INFO] ocpp:OCPP201     :: Received BootNotificationResponse: {
    "currentTime": "2024-03-12T17:23:41.000Z",
    "interval": 300,
    "status": "Accepted"
}
with messageId: 74cd331d-a8cd-4810-b689-9072a5b638cc

Before the process terminates
terminate called after throwing an instance of 'std::logic_error'
  what():  get_issuer_key_hash must only be used on self-signed certs
2024-03-12 17:23:41.446046 [CRIT] manager         int boot(const boost::program_options::variables_map&) :: Module evse_security (pid: 605) exited with status: 6.  EVerest up and running [64730ms] 🚙🚙🚙
2024-03-12 17:58:56.922870 [INFO] ocpp:OCPP201     :: OCPP certificates path: /workspace/dist/etc/everest/certs
2024-03-12 17:58:57.217506 [INFO] ocpp:OCPP201     :: Established connection to device model database successfully: "/workspace/dist/share/everest/modules/OCPP201/device_model_storage.db"
2024-03-12 17:58:57.411682 [INFO] evse_manager_1:  :: Ignoring BSP Event, BSP is not enabled yet.
2024-03-12 17:58:57.536353 [INFO] evse_manager_2:  :: Ignoring BSP Event, BSP is not enabled yet.
2024-03-12 17:58:57.606853 [INFO] ocpp:OCPP201     :: Successfully retrieved Device Model from DeviceModelStorage
2024-03-12 17:58:58.549811 [INFO] evse_manager_1:  :: Max AC hardware capabilities: 32A/3ph
2024-03-12 17:58:58.644214 [INFO] evse_manager_2:  :: Max AC hardware capabilities: 32A/3ph
2024-03-12 17:58:58.912208 [INFO] evse_manager_1:  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
2024-03-12 17:58:58.961224 [INFO] evse_manager_2:  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
2024-03-12 17:58:58.964518 [INFO] ocpp:OCPP201     :: EVSE 2 ready.
2024-03-12 17:58:59.005317 [INFO] ocpp:OCPP201     :: EVSE 1 ready.
2024-03-12 17:58:59.151124 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 17:58:59.153532 [INFO] evse_manager_1:  :: All errors cleared
2024-03-12 17:58:59.165069 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 17:58:59.175330 [INFO] evse_manager_1:  :: All errors cleared
2024-03-12 17:58:59.205398 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 17:58:59.209861 [INFO] evse_manager_2:  :: All errors cleared
2024-03-12 17:58:59.304952 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 17:58:59.308599 [INFO] evse_manager_2:  :: All errors cleared
2024-03-12 17:58:59.310812 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 17:58:59.313803 [INFO] evse_manager_1:  :: All errors cleared
2024-03-12 17:58:59.383270 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 17:58:59.412556 [INFO] evse_manager_2:  :: All errors cleared
2024-03-12 17:59:00.567705 [INFO] ocpp:OCPP201     :: Logging OCPP messages to log file: /tmp/everest_ocpp_logs/2024-03-12T17:59:00.562Z.log
2024-03-12 17:59:00.568020 [INFO] ocpp:OCPP201     :: Logging OCPP messages to html file: /tmp/everest_ocpp_logs/2024-03-12T17:59:00.562Z.html
2024-03-12 17:59:00.568179 [INFO] ocpp:OCPP201     :: Logging SecurityEvents to file
2024-03-12 17:59:00.571749 [INFO] ocpp:OCPP201     :: TxStartPoint from device model: PowerPathClosed
2024-03-12 17:59:00.850416 [INFO] ocpp:OCPP201     :: All EVSE ready. Starting OCPP2.0.1 service
2024-03-12 17:59:01.025656 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp001 with security-profile 2
2024-03-12 17:59:01.826316 [INFO] ocpp:OCPP201     :: libocpp: Updating OCSP cache on 0 certificates
2024-03-12 17:59:01.826524 [INFO] ocpp:OCPP201     :: libocpp: Done updating OCSP cache
2024-03-12 17:59:02.593761 [WARN] ocpp:OCPP201    bool ocpp::WebsocketTLS::verify_csms_cn(const std::string&, bool, boost::asio::ssl::verify_context&) :: Invalid certificate error 'unable to get
local issuer certificate' (at chain depth '0')
2024-03-12 17:59:02.643375 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl
2024-03-12 17:59:02.643561 [INFO] ocpp:OCPP201     :: Reconnecting in: 1000ms, attempt: 1
2024-03-12 17:59:03.643987 [INFO] ocpp:OCPP201     :: Reconnecting to TLS websocket at uri: wss://host.docker.internal/ws/cp001 with security profile: 2
2024-03-12 17:59:04.204201 [WARN] ocpp:OCPP201    bool ocpp::WebsocketTLS::verify_csms_cn(const std::string&, bool, boost::asio::ssl::verify_context&) :: Invalid certificate error 'unable to get
local issuer certificate' (at chain depth '0')
2024-03-12 17:59:04.205129 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl
2024-03-12 17:59:04.205263 [INFO] ocpp:OCPP201     :: Reconnecting in: 2000ms, attempt: 2
2024-03-12 17:59:06.206007 [INFO] ocpp:OCPP201     :: Reconnecting to TLS websocket at uri: wss://host.docker.internal/ws/cp001 with security profile: 2
2024-03-12 17:59:06.455355 [WARN] ocpp:OCPP201    bool ocpp::WebsocketTLS::verify_csms_cn(const std::string&, bool, boost::asio::ssl::verify_context&) :: Invalid certificate error 'unable to get
local issuer certificate' (at chain depth '0')
2024-03-12 17:59:06.456122 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl
2024-03-12 17:59:06.456267 [INFO] ocpp:OCPP201     :: Reconnecting in: 5000ms, attempt: 3
2024-03-12 17:59:11.458703 [INFO] ocpp:OCPP201     :: Reconnecting to TLS websocket at uri: wss://host.docker.internal/ws/cp001 with security profile: 2
2024-03-12 17:59:11.704236 [WARN] ocpp:OCPP201    bool ocpp::WebsocketTLS::verify_csms_cn(const std::string&, bool, boost::asio::ssl::verify_context&) :: Invalid certificate error 'unable to get
local issuer certificate' (at chain depth '0')
2024-03-12 17:59:11.704829 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl
2024-03-12 17:59:11.704948 [INFO] ocpp:OCPP201     :: Closing TLS websocket.
2024-03-12 17:59:11.704990 [ERRO] ocpp:OCPP201    virtual void ocpp::WebsocketTLS::close(websocketpp::close::status::value, const std::string&) :: Error initiating close of TLS websocket: invalid state
2024-03-12 17:59:11.705024 [WARN] ocpp:OCPP201    ocpp::v201::ChargePoint::init_websocket()::<lambda(websocketpp::close::status::value)> :: Closed websocket of NetworkConfigurationPriority: 1 which is configurationSlot: 1
2024-03-12 17:59:13.711964 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp001 with security-profile 2
2024-03-12 17:59:13.968023 [WARN] ocpp:OCPP201    bool ocpp::WebsocketTLS::verify_csms_cn(const std::string&, bool, boost::asio::ssl::verify_context&) :: Invalid certificate error 'unable to get
local issuer certificate' (at chain depth '0')
2024-03-12 17:59:13.968730 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl
2024-03-12 17:59:13.969005 [INFO] ocpp:OCPP201     :: Reconnecting in: 3000ms, attempt: 1
2024-03-12 17:59:16.971604 [INFO] ocpp:OCPP201     :: Reconnecting to TLS websocket at uri: wss://host.docker.internal/ws/cp001 with security profile: 2
2024-03-12 17:59:17.318541 [WARN] ocpp:OCPP201    bool ocpp::WebsocketTLS::verify_csms_cn(const std::string&, bool, boost::asio::ssl::verify_context&) :: Invalid certificate error 'unable to get
local issuer certificate' (at chain depth '0')
2024-03-12 17:59:17.319287 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl
2024-03-12 17:59:17.319460 [INFO] ocpp:OCPP201     :: Reconnecting in: 7000ms, attempt: 2
2024-03-12 17:59:24.325726 [INFO] ocpp:OCPP201     :: Reconnecting to TLS websocket at uri: wss://host.docker.internal/ws/cp001 with security profile: 2
2024-03-12 17:59:24.748868 [WARN] ocpp:OCPP201    bool ocpp::WebsocketTLS::verify_csms_cn(const std::string&, bool, boost::asio::ssl::verify_context&) :: Invalid certificate error 'unable to get
local issuer certificate' (at chain depth '0')
2024-03-12 17:59:24.749586 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 8, reason: TLS handshake failed, HTTP response code: 0, category: websocketpp.transport.asio.socket, transport error code: 167772567, Transport error category: asio.ssl
2024-03-12 17:59:24.749740 [INFO] ocpp:OCPP201     :: Reconnecting in: 14000ms, attempt: 3

Looks like I get an Invalid certificate error: unable to get local issuer certificate repeatedly

@jhoshiko please look at the script, and the step that copies over the bundle.
Is that running successfully?

@shankari Ok, looks like there was issue finding bash that caused issues copying the bundle over.  EVerest up and running [15992ms] 🚙🚙🚙
2024-03-12 19:05:02.079011 [INFO] ocpp:OCPP201     :: OCPP certificates path: /workspace/dist/etc/everest/certs
2024-03-12 19:05:02.093518 [INFO] ocpp:OCPP201     :: Established connection to device model database successfully: "/workspace/dist/share/everest/modules/OCPP201/device_model_storage.db"
2024-03-12 19:05:02.102334 [INFO] ocpp:OCPP201     :: Successfully retrieved Device Model from DeviceModelStorage
2024-03-12 19:05:02.387529 [INFO] evse_manager_1:  :: Ignoring BSP Event, BSP is not enabled yet.
2024-03-12 19:05:02.389945 [INFO] evse_manager_2:  :: Ignoring BSP Event, BSP is not enabled yet.
2024-03-12 19:05:02.507306 [INFO] evse_manager_1:  :: Max AC hardware capabilities: 32A/3ph
2024-03-12 19:05:02.607328 [INFO] evse_manager_2:  :: Max AC hardware capabilities: 32A/3ph
2024-03-12 19:05:02.694109 [INFO] evse_manager_1:  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
2024-03-12 19:05:02.697054 [INFO] ocpp:OCPP201     :: EVSE 1 ready.
2024-03-12 19:05:02.748391 [INFO] evse_manager_2:  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
2024-03-12 19:05:02.748929 [INFO] ocpp:OCPP201     :: EVSE 2 ready.
2024-03-12 19:05:02.792222 [INFO] ocpp:OCPP201     :: Logging OCPP messages to log file: /tmp/everest_ocpp_logs/2024-03-12T19:05:02.792Z.log
2024-03-12 19:05:02.792483 [INFO] ocpp:OCPP201     :: Logging OCPP messages to html file: /tmp/everest_ocpp_logs/2024-03-12T19:05:02.792Z.html
2024-03-12 19:05:02.792721 [INFO] ocpp:OCPP201     :: Logging SecurityEvents to file
2024-03-12 19:05:02.800424 [INFO] ocpp:OCPP201     :: TxStartPoint from device model: PowerPathClosed
2024-03-12 19:05:02.841584 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 19:05:02.842456 [INFO] evse_manager_1:  :: All errors cleared
2024-03-12 19:05:02.846145 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 19:05:02.847376 [INFO] evse_manager_1:  :: All errors cleared
2024-03-12 19:05:02.859865 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 19:05:02.861283 [INFO] evse_manager_1:  :: All errors cleared
2024-03-12 19:05:02.862541 [INFO] ocpp:OCPP201     :: All EVSE ready. Starting OCPP2.0.1 service
2024-03-12 19:05:02.905817 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 19:05:02.908198 [INFO] evse_manager_2:  :: All errors cleared
2024-03-12 19:05:02.915920 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 19:05:02.966756 [INFO] evse_manager_2:  :: All errors cleared
2024-03-12 19:05:02.975283 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 19:05:02.986624 [INFO] evse_manager_2:  :: All errors cleared
2024-03-12 19:05:03.050221 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp001 with security-profile 2
2024-03-12 19:05:03.064346 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
terminate called after throwing an instance of 'std::logic_error'
  what():  get_issuer_key_hash must only be used on self-signed certs
2024-03-12 19:05:03.174541 [CRIT] manager         int boot(const boost::program_options::variables_map&) :: Module evse_security (pid: 153) exited with status: 6.

Unable to find bash error for reference:
OCI runtime exec failed: exec failed: unable to start container process: exec: "C:/Program Files/Git/usr/bin/bash": stat C:/Program Files/Git/usr/bin/bash: no such file or directory: unknown

@jhoshiko this seems to be an issue with running on windows. This is very weird because docker exec is supposed to run the command in the container. And I run docker exec /bin/bash multiple times before (e.g. docker exec everest-ac-demo-manager-1 /bin/bash -c "tar xzvf cached_certs_correct_name.tar.gz"
Would be interesting to understand how those worked, and this did not. What did you have to do to fix it?

@shankari I'm still not sure why the issue is occuring, but it seems to be specifically an issue with using bash on windows. The only time the error occurs is when /bin/bash is used on lined 83, 86, and 88 in demo-iso15118-2-ac-plus-ocpp201.sp2.sh. I was able to get to work by not using a bash shell on windows and using WSL instead, but it also looks like replacing /bin/bash with bash also works.

 EVerest up and running [13938ms] 🚙🚙🚙
2024-03-12 23:18:33.805561 [INFO] ocpp:OCPP201     :: OCPP certificates path: /workspace/dist/etc/everest/certs
2024-03-12 23:18:33.895208 [INFO] ocpp:OCPP201     :: Established connection to device model database successfully: "/workspace/dist/share/everest/modules/OCPP201/device_model_storage.db"
2024-03-12 23:18:33.944823 [INFO] ocpp:OCPP201     :: Successfully retrieved Device Model from DeviceModelStorage
2024-03-12 23:18:33.974097 [INFO] ocpp:OCPP201     :: Logging OCPP messages to log file: /tmp/everest_ocpp_logs/2024-03-12T23:18:33.974Z.log
2024-03-12 23:18:33.974166 [INFO] ocpp:OCPP201     :: Logging OCPP messages to html file: /tmp/everest_ocpp_logs/2024-03-12T23:18:33.974Z.html
2024-03-12 23:18:33.974194 [INFO] ocpp:OCPP201     :: Logging SecurityEvents to file
2024-03-12 23:18:33.974737 [INFO] ocpp:OCPP201     :: TxStartPoint from device model: PowerPathClosed
2024-03-12 23:18:33.994417 [INFO] evse_manager_1:  :: Max AC hardware capabilities: 32A/3ph
2024-03-12 23:18:33.998476 [INFO] evse_manager_2:  :: Max AC hardware capabilities: 32A/3ph
2024-03-12 23:18:34.083000 [INFO] evse_manager_1:  :: Ignoring BSP Event, BSP is not enabled yet.
2024-03-12 23:18:34.095005 [INFO] evse_manager_2:  :: Ignoring BSP Event, BSP is not enabled yet.
2024-03-12 23:18:34.175255 [INFO] evse_manager_1:  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
2024-03-12 23:18:34.187388 [INFO] evse_manager_2:  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
2024-03-12 23:18:34.219070 [INFO] ocpp:OCPP201     :: EVSE 1 ready.
2024-03-12 23:18:34.235009 [INFO] ocpp:OCPP201     :: EVSE 2 ready.
2024-03-12 23:18:34.235085 [INFO] ocpp:OCPP201     :: All EVSE ready. Starting OCPP2.0.1 service
2024-03-12 23:18:34.458459 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp001 with security-profile 2
2024-03-12 23:18:34.499157 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 23:18:34.543228 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 23:18:34.543423 [INFO] evse_manager_1:  :: All errors cleared
2024-03-12 23:18:34.544224 [INFO] evse_manager_2:  :: All errors cleared
2024-03-12 23:18:34.633805 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 23:18:34.635233 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 23:18:34.637199 [INFO] evse_manager_1:  :: All errors cleared
2024-03-12 23:18:34.547223 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-12 23:18:34.679384 [INFO] evse_manager_2:  :: All errors cleared
2024-03-12 23:18:34.714463 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 2, reason: Underlying Transport Error, HTTP response code: 0, category: websocketpp.transport, transport error code: 167772436, Transport error category: asio.ssl
2024-03-12 23:18:34.714526 [INFO] ocpp:OCPP201     :: Reconnecting in: 3000ms, attempt: 1
2024-03-12 23:18:34.731561 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
terminate called after throwing an instance of 'std::logic_error'
what():  get_issuer_key_hash must only be used on self-signed certs
2024-03-12 23:18:34.775039 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-12 23:18:34.775090 [INFO] evse_manager_1:  :: All errors cleared
2024-03-12 23:18:34.819128 [INFO] evse_manager_2:  :: All errors cleared
2024-03-12 23:18:34.850798 [CRIT] manager         int boot(const boost::program_options::variables_map&) :: Module evse_security (pid: 146) exited with status: 134.  I was able to make it work for both security profile 2 and 3 for release 2023.10.0.
It is to be noted that I didn't use the one liner which is giving the same error.

As it is working for 2023.10.0 built from scratch, we might want to bump down to that and try again.

Glad to see the discussion around cert structures. The single line MRE will obviously not work unless you change the script; have you tried after changing the script?

I changed the MaEVe cert generation script.

As it is working for 2023.10.0 built from scratch, we might want to bump down to that and try again.

@shankari , can we try this? For some reason, I can't pull the old release. I cloned the repo, changed the scripts, .env and the dockerfile, but when I run it, it still pulls the 0.0.12 images.

@sahabulh

can we try this? For some reason, I can't pull the old release. I cloned the repo, changed the scripts, .env and the dockerfile, but when I run it, it still pulls the 0.0.12 images.

Changed the scripts in which way? What are the messages that you get when you run?
The docker-compose reads the version from the TAG environment variable, which is set in .env Is it in the correct directory? Have you checked the docker compose documentation? (e.g. docker compose config)

I would also like to understand how this worked with the Mobility OpenHouse python based implementation.
It is general best practice to have a bundled certificate chain while using SSL with webservers, and I have encountered it earlier. So I flagged the bundling as an issue earlier https://github.com/EVerest/everest-demo/issues/25#issuecomment-1987500724 and https://github.com/EVerest/everest-demo/issues/25#issuecomment-1987625942
but I assumed that the changes (if any) would need to be on the EVSE side since the same CSMS was working with a different client.
Action items:

We need to understand what MaEVe expects wrt bundling and whether bundling is the recommended best practice for all clients (it should be)
At least for EVerest, the CSMS cert should have the FQDN of the CSMS host (which is also the norm in SSL for webservers). I am not sure how the Eonti/SAE certs will work for this, since they appear to have a hardcoded CN of USEMAC00000004. We need to follow up with SAE about this, unless there are other certificates that we are not using.
https://github.com/EVerest/everest-demo/issues/25#issuecomment-1987376078

$ openssl verify -show_chain -CAfile config/certificates/root-V2G-cert.pem -untrusted config/certificates/cpo_sub_ca2.pem config/certificates/csms.pem
config/certificates/csms.pem: OK
Chain:
depth=0: C = US, O = Sandia, OU = EV Department, CN = USEMAC00000004 (untrusted)
depth=1: C = US, O = EV Charging PKI, OU = TEST MO Sub-CA, CN = P-256 TEST Tier 1 MO Sub-CA (untrusted)
depth=2: C = US, O = EV Charging PKI, DC = EVCPKI, OU = TEST Root CA, CN = P-256 TEST Root CA

@sahabulh Great! Can you submit that as a PR? That would make it easier for others to reproduce/build on this work

I will submit a PR but I am afraid I will not be able to do that before Friday night. I need to work on my PhD study. Sorry! But I will give some written description below.

Changed the scripts in which way? What are the messages that you get when you run?

For the script demo-iso15118-2-ac-plus-ocpp201.sp2.sh, I just edited it to turn off the load balancer. I don't think it matters as the problem is that I can't pull release 2023.10.0.

The docker-compose reads the version from the TAG environment variable, which is set in .env Is it in the correct directory? Have you checked the docker compose documentation? (e.g. docker compose config)

I have changed the tag to 0.0.11 in the .env file. I have also changed the Everest version in the manager/Dockerfile to 2023.10.0. But it is still pulling 0.0.12.

@sahabulh

I have changed the tag to 0.0.11 in the .env file. I have also changed the Everest version in the manager/Dockerfile to 2023.10.0. But it is still pulling 0.0.12.

Where did you change the tag? Note that the script checks out another copy of the everest-demo repo -  it is a single-line demo because it does not require the everest-demo code to be checked out.

I would also like to understand how this worked with the Mobility OpenHouse python based implementation.

I figured it out. The reason the python code was working although MaEVe wasn't sending the intermediate CAs is that the certificate verification wasn't turned on for the client. So, the although the CSMS was verifying the charger's certs, the charger wasn't verifying the csms's certs. And that's why it didn't throw the error. After I turned the certificate verification on for the OCPP client (charger), it is working perfectly with the chain (leaf + ca2 + ca1) and doesn't work with the single leaf.

It is general best practice to have a bundled certificate chain while using SSL with webservers, and I have encountered it earlier. So I flagged the bundling as an issue earlier https://github.com/EVerest/everest-demo/issues/25#issuecomment-1987500724 and https://github.com/EVerest/everest-demo/issues/25#issuecomment-1987625942

Yeah, the best practice is that both the client and the server send their respective chains.

but I assumed that the changes (if any) would need to be on the EVSE side since the same CSMS was working with a different client.

As mentioned before, there was in the python code.

We need to understand what MaEVe expects wrt bundling and whether bundling is the recommended best practice for all clients (it should be)

I agree. But in both cases (Mobility House and Everest), the client is sending only the leaf. I think the server assumes that the subca's for the charger chain and it's own chain is the same? In reality, they can be different. Only the root is required to be the same. What is your thought on this?

At least for EVerest, the CSMS cert should have the FQDN of the CSMS host (which is also the norm in SSL for webservers). I am not sure how the Eonti/SAE certs will work for this, since they appear to have a hardcoded CN of USEMAC00000004. We need to follow up with SAE about this, unless there are other certificates that we are not using.

They actually didn't hard code that. I did that when I issued the cert myself. Remember, that certificate is actually the Contract Certificate (I used same cert everywhere for simplicity) and they are required to have the EMAID as their CN. But in reality, the OCPP server will have a different certificate and it can contain the suitable FQDN. But we will have to make sure that the testers generate their certs properly.

@sahabulh

I have changed the tag to 0.0.11 in the .env file. I have also changed the Everest version in the manager/Dockerfile to 2023.10.0. But it is still pulling 0.0.12.

Where did you change the tag? Note that the script checks out another copy of the everest-demo repo - it is a single-line demo because it does not require the everest-demo code to be checked out before it is run. So changing the local .env file won't accomplish anything

I figured this out also. I forked the demo repo and made a commit with those changes. Now, the one liner correctly pulls the 0.0.11 images. But, now I have another issue.  But it doesn't always freeze at the same point. I think I will have to create a PR for this.

https://github.com/EVerest/everest-demo/pull/28 You need to use an even older tag

I've managed to get past all the above errors based on the advise from both this issue and the related Zulip chats. Now I end up in an endless loop of failed websocket connection attempts. They seem to be different errors than what @jhoshiko was seeing regarding websocket errors.
2024-03-15 23:07:55.424126 [INFO] manager          :: 🚙🚙🚙 All modules are initialized. EVerest up and running [9743ms] 🚙🚙🚙
2024-03-15 23:07:55.425043 [INFO] ocpp:OCPP201     :: OCPP certificates path: /workspace/dist/etc/everest/certs
2024-03-15 23:07:55.628672 [INFO] ocpp:OCPP201     :: Established connection to device model database successfully: "/workspace/dist/share/everest/modules/OCPP201/device_model_storage.db"
2024-03-15 23:07:55.632904 [INFO] ocpp:OCPP201     :: Successfully retrieved Device Model from DeviceModelStorage
2024-03-15 23:07:55.655301 [INFO] ocpp:OCPP201     :: Logging OCPP messages to log file: /tmp/everest_ocpp_logs/2024-03-15T23:07:55.655Z.log
2024-03-15 23:07:55.655381 [INFO] ocpp:OCPP201     :: Logging OCPP messages to html file: /tmp/everest_ocpp_logs/2024-03-15T23:07:55.655Z.html
2024-03-15 23:07:55.655419 [INFO] ocpp:OCPP201     :: Logging SecurityEvents to file
2024-03-15 23:07:55.655960 [INFO] ocpp:OCPP201     :: TxStartPoint from device model: PowerPathClosed
2024-03-15 23:07:55.659610 [INFO] evse_manager_1:  :: Max AC hardware capabilities: 32A/3ph
2024-03-15 23:07:55.698466 [INFO] evse_manager_2:  :: Ignoring BSP Event, BSP is not enabled yet.
2024-03-15 23:07:55.701660 [INFO] evse_manager_2:  :: Max AC hardware capabilities: 32A/3ph
2024-03-15 23:07:55.704230 [INFO] evse_manager_1:  :: Ignoring BSP Event, BSP is not enabled yet.
2024-03-15 23:07:55.829815 [INFO] evse_manager_1:  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
2024-03-15 23:07:55.871536 [INFO] ocpp:OCPP201     :: EVSE 1 ready.
2024-03-15 23:07:55.872005 [INFO] evse_manager_2:  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
2024-03-15 23:07:55.913433 [INFO] ocpp:OCPP201     :: EVSE 2 ready.
2024-03-15 23:07:55.913498 [INFO] ocpp:OCPP201     :: All EVSE ready. Starting OCPP2.0.1 service
2024-03-15 23:07:56.078295 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp001 with security-profile 2
2024-03-15 23:07:56.096913 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-15 23:07:56.137454 [INFO] evse_manager_2:  :: All errors cleared
2024-03-15 23:07:56.138284 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-15 23:07:56.177670 [INFO] evse_manager_1:  :: All errors cleared
2024-03-15 23:07:56.163789 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-15 23:07:56.220836 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-15 23:07:56.261620 [INFO] evse_manager_2:  :: All errors cleared
2024-03-15 23:07:56.270576 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 2, reason: Underlying Transport Error, HTTP response code: 0, category: websocketpp.transport, transport error code: 167772436, Transport error category: asio.ssl
2024-03-15 23:07:56.270639 [INFO] ocpp:OCPP201     :: Reconnecting in: 2000ms, attempt: 1
2024-03-15 23:07:56.270955 [WARN] evse_security:E static std::string evse_security::OpenSSLSupplier::x509_get_responder_url(evse_security::X509Handle*) :: Could not retrieve OCSP Responder URL from certificate
2024-03-15 23:07:56.302740 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-15 23:07:56.312518 [INFO] ocpp:OCPP201     :: libocpp: Updating OCSP cache on 0 certificates
2024-03-15 23:07:56.312578 [INFO] ocpp:OCPP201     :: libocpp: Done updating OCSP cache
2024-03-15 23:07:56.343737 [INFO] evse_manager_1:  :: All errors cleared
2024-03-15 23:07:56.345695 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-15 23:07:56.386635 [INFO] evse_manager_2:  :: All errors cleared
2024-03-15 23:07:56.426806 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-15 23:07:56.467655 [INFO] evse_manager_1:  :: All errors cleared
2024-03-15 23:07:58.272277 [INFO] ocpp:OCPP201     :: Reconnecting to TLS websocket at uri: wss://host.docker.internal/ws/cp001 with security profile: 2
2024-03-15 23:07:58.355700 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-15 23:07:58.460303 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 2, reason: Underlying Transport Error, HTTP response code: 0, category: websocketpp.transport, transport error code: 167772436, Transport error category: asio.ssl
2024-03-15 23:07:58.460361 [INFO] ocpp:OCPP201     :: Reconnecting in: 4000ms, attempt: 2
2024-03-15 23:08:02.464155 [INFO] ocpp:OCPP201     :: Reconnecting to TLS websocket at uri: wss://host.docker.internal/ws/cp001 with security profile: 2
2024-03-15 23:08:02.547640 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-15 23:08:02.694339 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 2, reason: Underlying Transport Error, HTTP response code: 0, category: websocketpp.transport, transport error code: 167772436, Transport error category: asio.ssl
2024-03-15 23:08:02.694407 [INFO] ocpp:OCPP201     :: Reconnecting in: 8000ms, attempt: 3
2024-03-15 23:08:10.702122 [INFO] ocpp:OCPP201     :: Reconnecting to TLS websocket at uri: wss://host.docker.internal/ws/cp001 with security profile: 2
2024-03-15 23:08:10.745746 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-15 23:08:10.851100 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 2, reason: Underlying Transport Error, HTTP response code: 0, category: websocketpp.transport, transport error code: 167772436, Transport error category: asio.ssl
2024-03-15 23:08:10.851144 [INFO] ocpp:OCPP201     :: Closing TLS websocket.
2024-03-15 23:08:10.851158 [ERRO] ocpp:OCPP201    virtual void ocpp::WebsocketTLS::close(websocketpp::close::status::value, const std::string&) :: Error initiating close of TLS websocket: invalid state
2024-03-15 23:08:10.851173 [WARN] ocpp:OCPP201    ocpp::v201::ChargePoint::init_websocket()::<lambda(websocketpp::close::status::value)> :: Closed websocket of NetworkConfigurationPriority: 1 which is configurationSlot: 1
2024-03-15 23:08:12.853934 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp001 with security-profile 2
2024-03-15 23:08:12.936590 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-15 23:08:13.042483 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect to websocket server, error_code: 2, reason: Underlying Transport Error, HTTP response code: 0, category: websocketpp.transport, transport error code: 167772436, Transport error category: asio.ssl
2024-03-15 23:08:13.042573 [INFO] ocpp:OCPP201     :: Reconnecting in: 2000ms, attempt: 1

I made a few adjustments to the demo script to get past all the other errors in order to get to this one.
diff --git a/demo-iso15118-2-ac-plus-ocpp201.sp2.sh b/demo-iso15118-2-ac-plus-ocpp201.sp2.sh
index 88934dc..4b2d793 100755
--- a/demo-iso15118-2-ac-plus-ocpp201.sp2.sh
+++ b/demo-iso15118-2-ac-plus-ocpp201.sp2.sh
@@ -42,18 +42,19 @@ cp everest-demo/manager/cached_certs_correct_name.tar.gz maeve-csms
 pushd maeve-csms

 echo "Copying certs into ${DEMO_DIR}/maeve-csms/config/certificates"
-tar xzvf cached_certs_correct_name.tar.gz
-cp dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem config/certificates/root-V2G-cert.pem
-cp dist/etc/everest/certs/ca/csms/CPO_SUB_CA1.pem config/certificates/cpo_sub_ca1.pem
-cp dist/etc/everest/certs/ca/csms/CPO_SUB_CA2.pem config/certificates/cpo_sub_ca2.pem
-cp dist/etc/everest/certs/client/csms/CSMS_LEAF.pem config/certificates/csms.pem
+tar xf cached_certs_correct_name.tar.gz
+cat dist/etc/everest/certs/client/csms/CSMS_LEAF.pem \
+    dist/etc/everest/certs/ca/csms/CPO_SUB_CA2.pem \
+    dist/etc/everest/certs/ca/csms/CPO_SUB_CA1.pem \
+  > config/certificates/csms.pem
 cp dist/etc/everest/certs/client/csms/CSMS_LEAF.key config/certificates/csms.key
-cp dist/etc/everest/certs/client/csms/CPO_SUB_CA1.key config/certificates/cpo_sub_ca1.key
-cp dist/etc/everest/certs/client/csms/CPO_SUB_CA2.key config/certificates/cpo_sub_ca2.key
-cat config/certificates/cpo_sub_ca1.pem config/certificates/cpo_sub_ca2.pem > config/certificates/trust.pem
+cp dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem config/certificates/root-V2G-cert.pem

 echo "Validating that the certificates are set up correctly"
-openssl verify -show_chain -CAfile config/certificates/root-V2G-cert.pem -untrusted config/certificates/trust.pem config/certificates/csms.pem
+openssl verify -show_chain \
+  -CAfile config/certificates/root-V2G-cert.pem \
+  -untrusted config/certificates/csms.pem \
+  config/certificates/csms.pem

 echo "Starting the CSMS"
 docker compose up -d
@@ -84,8 +85,8 @@ docker exec everest-ac-demo-manager-1 /bin/bash -c "tar xzvf cached_certs_correc

 echo "Configured everest certs, validating that the chain is set up correctly"
 docker exec everest-ac-demo-manager-1 /bin/bash -c "openssl verify -show_chain -CAfile dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem --untrusted dist/etc/everest/certs/ca/csms/CPO_SUB_CA1.pem --untrusted dist/etc/everest/certs/ca/csms/CPO_SUB_CA2.pem dist/etc/everest/certs/client/csms/CSMS_LEAF.pem"
-echo "Copying bundle over to root (confusing!) https://github.com/EVerest/everest-demo/issues/25#issuecomment-1988895630"
-docker exec everest-ac-demo-manager-1 /bin/bash -c "cp dist/etc/everest/certs/ca/v2g/V2G_CA_BUNDLE.pem dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem"
+# echo "Copying bundle over to root (confusing!) https://github.com/EVerest/everest-demo/issues/25#issuecomment-1988895630"
+# docker exec everest-ac-demo-manager-1 /bin/bash -c "cp dist/etc/everest/certs/ca/v2g/V2G_CA_BUNDLE.pem dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem"

 echo "Copying device DB, configured to SecurityProfile: 2"
 docker cp manager/device_model_storage_maeve_sp2.db everest-ac-demo-manager-1:/workspace/dist/share/everest/modules/OCPP201/device_model_storage.db

Has anyone else experienced the endless loop of WebSocket "Underlying Transport Error" errors?
/cc @shankari @sahabulh

Now that I think about it more, perhaps it's the same cert CN / DNS issue mentioned previously, having to do with the host.docker.internal domain name.
I'll do some digging later to better orient myself with how the charger's occp client knows what address to use to connect to the csms. For example, is that a config option or does it use the CN from the csms server cert?

@activeshadow

Has anyone else experienced the endless loop of WebSocket "Underlying Transport Error" errors?

The current MRE does not have this error. Maybe you could generate an alternate MRE that outlines how you are getting this error. As you can see from the updates here, the difference between success and failure is the way that the certificates are configured, and it is hard to reproduce/debug without knowing that information.

I'll do some digging later to better orient myself with how the charger's occp client knows what address to use to connect to the csms. For example, is that a config option or does it use the CN from the csms server cert?

Please see prior issue comments on how the csmsURL is set in the device DB using SQL update

@sahabulh wrt https://github.com/EVerest/everest-demo/issues/25#issuecomment-1987464746, where did you get the sub_ca pair from?
I originally thought that they were from EonTI, but I just got access to the certs there and their sub CA cert does not match the checked in values. I note from https://github.com/EVerest/everest-demo/issues/25#issuecomment-1998085952 that you issued some of the certs yourself.
Are the versions that are checked in certs that you issued, or the ones from EonTI? And if from EonTI, for which test case?

The current MRE does not have this error. Maybe you could generate an alternate MRE that outlines how you are getting this error. As you can see from the updates here, the difference between success and failure is the way that the certificates are configured, and it is hard to reproduce/debug without knowing that information.

@shankari I've done some additional digging and see some service connections I had missed. I'll make a couple of additional changes to my local configs to get this demo example working further. More to come ASAP.

@activeshadow sounds good. I hope you saw the existing MRE https://github.com/EVerest/everest-demo/pull/29 and the fixes outlined after that in both the Zulip Chat and the issue. @sahabulh has the setup working on his laptop and plans to update the MRE to actually work today, so you might want to coordinate with him as well.

@activeshadow sounds good. I hope you saw the existing MRE https://github.com/EVerest/everest-demo/pull/29 and the fixes outlined after that in both the Zulip Chat and the issue. @sahabulh has the setup working on his laptop and plans to update the MRE to actually work today, so you might want to coordinate with him as well.

Yes @shankari that's the one I've been working from, thank you! @sahabulh and I are already coordinating so we should be good. 👍🏻

@shankari please see this commit on my fork of the everest-demo repo for a new MRE.
@sahabulh and I have both confirmed that it seems to be working, though we're both wondering why no OCPP logs are being generated when a car charging session is initiated in the Node-RED UI.
I will submit a PR for the MRE once I'm back on my laptop later. In the meantime I wanted you to be able to test it as well if you're interested in doing so.
Note that this MRE is using my fork of Maeve with the load balancer removed. It was giving me some trouble and I wanted to remove it from the equation since it's not part of what we were debugging here anyway. I know that @sahabulh has a fork of Maeve also that he's made some necessary changes to so at some point we'll just need to switch over to that one.
Also note that @sahabulh is now going to work on testing security profile 3 since this one is using security profile 2 (at least we think it is anyway).

@activeshadow @shankari I have submitted the pull request (#31) . Issues remaining are described there. But the server-client connection is good and the EV is able to charge using EIM.

@sahabulh thank you for the PR! I have added my comments to it. Can you also respond to my earlier comment about the provenance of the EonTI certs? https://github.com/EVerest/everest-demo/issues/25#issuecomment-2001084426
EonTI wanted to know which keypair was invalid. I think it is critical to understand how the currently generated EonTI certificates work or don't work, so that we can provide them with feedback in time.

@jhoshiko I just merged PRs to enable security profiles 2 and 3 (thanks to @activeshadow and @sahabulh for the MRE). Please try to run them and verify that they work for you as well.

@shankari Ok, I've tested both demo-iso15118-2-ac-plus-ocpp201.sp2.sh and demo-iso15118-2-ac-plus-ocpp201.sp3.sh. Security profile 2 is working, but I am having some issues with security profile 3. Looks like the device DB is being copied correctly and the cert chain was validated:
Successfully copied 28.7kB to everest-ac-demo-manager-1:/workspace/
Configured everest certs, validating that the chain is set up correctly
dist/etc/everest/certs/client/csms/CSMS_LEAF.pem: OK
Chain:
depth=0: CN = host.docker.internal, O = EVerest, C = DE, DC = CPO (untrusted)
depth=1: CN = CPOSubCA2, O = EVerest, C = DE, DC = V2G (untrusted)
depth=2: CN = CPOSubCA1, O = EVerest, C = DE, DC = V2G (untrusted)
depth=3: CN = V2GRootCA, O = EVerest, C = DE, DC = V2G
Copying device DB, configured to SecurityProfile: 3
Successfully copied 83.5kB to everest-ac-demo-manager-1:/workspace/dist/share/everest/modules/OCPP201/device_model_storage.db
Starting software in the loop simulation

However, it looks like I'm getting a connection error due to an invalid http status and the warning CSMS leaf requires full bundle, but full bundle not found at path: "/workspace/dist/etc/everest/certs/client/csms"

Full Log
2024-03-19 22:57:34.131767 [INFO] manager          ::   ________      __                _
2024-03-19 22:57:34.132224 [INFO] manager          ::  |  ____\ \    / /               | |
2024-03-19 22:57:34.132244 [INFO] manager          ::  | |__   \ \  / /__ _ __ ___  ___| |_
2024-03-19 22:57:34.132255 [INFO] manager          ::  |  __|   \ \/ / _ \ '__/ _ \/ __| __|
2024-03-19 22:57:34.132265 [INFO] manager          ::  | |____   \  /  __/ | |  __/\__ \ |_
2024-03-19 22:57:34.132275 [INFO] manager          ::  |______|   \/ \___|_|  \___||___/\__|
2024-03-19 22:57:34.132303 [INFO] manager          ::
2024-03-19 22:57:34.132333 [INFO] manager          :: Using MQTT broker mqtt-server:1883
2024-03-19 22:57:34.150961 [INFO] everest_ctrl     :: Launching controller service on port 8849
2024-03-19 22:57:34.164936 [INFO] manager          :: Loading config file at: /ext/source/config/config-sil-ocpp201.yaml
2024-03-19 22:57:34.625108 [INFO] manager          :: Config loading completed in 492ms
2024-03-19 22:57:42.259389 [INFO] system:System    :: Module system initialized [6892ms]
2024-03-19 22:57:42.459028 [INFO] energy_manager:  :: Module energy_manager initialized [7692ms]

2024-03-19 22:57:43.463513 [INFO] iso15118_charge  :: TCP server on eth0 is listening on port [fe80::42:acff:fe16:3%127]:61341

2024-03-19 22:57:43.463657 [INFO] iso15118_charge  :: TLS server on eth0 is listening on port [fe80::42:acff:fe16:3%127]:64109

2024-03-19 22:57:43.463734 [INFO] iso15118_charge  :: SDP socket setup succeeded
2024-03-19 22:57:43.553075 [INFO] iso15118_charge  :: Module iso15118_charger initialized [7789ms]
2024-03-19 22:57:44.255394 [INFO] auth:Auth        :: Module auth initialized [9494ms]
2024-03-19 22:57:44.453316 [INFO] evse_security:E  :: Module evse_security initialized [9596ms]
2024-03-19 22:57:44.456878 [INFO] grid_connection  :: Module grid_connection_point initialized [9603ms]
2024-03-19 22:57:45.158546 [INFO] token_provider_  :: Module token_provider_1 initialized [9100ms]
2024-03-19 22:57:45.569595 [INFO] api:API          :: Module api initialized [10805ms]
2024-03-19 22:57:45.772185 [INFO] evse_manager_2:  :: Module evse_manager_2 initialized [10919ms]
2024-03-19 22:57:45.873134 [INFO] evse_manager_1:  :: Module evse_manager_1 initialized [11017ms]
2024-03-19 22:57:45.953121 [INFO] persistent_stor  :: Module persistent_store initialized [10386ms]
2024-03-19 22:57:46.653247 [INFO] ocpp:OCPP201     :: Module ocpp initialized [10388ms]
2024-03-19 22:57:53.265501 [INFO] manager          :: 🚙🚙🚙 All modules are initialized. EVerest up and running [19142ms] 🚙🚙🚙
2024-03-19 22:57:53.266974 [INFO] ocpp:OCPP201     :: OCPP certificates path: /workspace/dist/etc/everest/certs
2024-03-19 22:57:53.275657 [INFO] ocpp:OCPP201     :: Established connection to device model database successfully: "/workspace/dist/share/everest/modules/OCPP201/device_model_storage.db"
2024-03-19 22:57:53.286663 [INFO] ocpp:OCPP201     :: Successfully retrieved Device Model from DeviceModelStorage
2024-03-19 22:57:53.553773 [INFO] evse_manager_1:  :: Ignoring BSP Event, BSP is not enabled yet.
2024-03-19 22:57:53.555603 [INFO] evse_manager_2:  :: Ignoring BSP Event, BSP is not enabled yet.
2024-03-19 22:57:53.578052 [INFO] ocpp:OCPP201     :: Logging OCPP messages to log file: /tmp/everest_ocpp_logs/2024-03-19T22:57:53.577Z.log
2024-03-19 22:57:53.578278 [INFO] ocpp:OCPP201     :: Logging OCPP messages to html file: /tmp/everest_ocpp_logs/2024-03-19T22:57:53.577Z.html
2024-03-19 22:57:53.578389 [INFO] ocpp:OCPP201     :: Logging SecurityEvents to file
2024-03-19 22:57:53.580527 [INFO] ocpp:OCPP201     :: TxStartPoint from device model: PowerPathClosed
2024-03-19 22:57:53.661005 [INFO] evse_manager_2:  :: Max AC hardware capabilities: 32A/3ph
2024-03-19 22:57:53.671416 [INFO] evse_manager_1:  :: Max AC hardware capabilities: 32A/3ph
2024-03-19 22:57:53.755241 [INFO] evse_manager_2:  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
2024-03-19 22:57:53.755639 [INFO] ocpp:OCPP201     :: EVSE 2 ready.
2024-03-19 22:57:53.802605 [INFO] evse_manager_1:  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
2024-03-19 22:57:53.803340 [INFO] ocpp:OCPP201     :: EVSE 1 ready.
2024-03-19 22:57:53.803561 [INFO] ocpp:OCPP201     :: All EVSE ready. Starting OCPP2.0.1 service
2024-03-19 22:57:53.864858 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-19 22:57:53.867177 [INFO] evse_manager_2:  :: All errors cleared
2024-03-19 22:57:53.871568 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp001 with security-profile 3
2024-03-19 22:57:53.888229 [INFO] evse_security:E  :: TPM Key: false
2024-03-19 22:57:53.888991 [INFO] evse_security:E  :: TPM Key: false
2024-03-19 22:57:53.890491 [WARN] evse_security:E evse_security::GetKeyPairResult evse_security::EvseSecurity::get_key_pair_internal(evse_security::LeafCertificateType, evse_security::EncodingFormat) :: CSMS leaf requires full bundle, but full bundle not found at path: "/workspace/dist/etc/everest/certs/client/csms"
2024-03-19 22:57:53.891480 [INFO] ocpp:OCPP201     :: Using certificate: "/workspace/dist/etc/everest/certs/client/csms/CSMS_LEAF.pem"
2024-03-19 22:57:53.892270 [INFO] ocpp:OCPP201     :: Using key file: "/workspace/dist/etc/everest/certs/client/csms/CSMS_LEAF.key"
2024-03-19 22:57:53.908950 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-19 22:57:53.909877 [INFO] evse_manager_1:  :: All errors cleared
2024-03-19 22:57:53.912992 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-19 22:57:53.913896 [INFO] evse_manager_1:  :: All errors cleared
2024-03-19 22:57:53.929549 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-19 22:57:53.930387 [INFO] evse_manager_2:  :: All errors cleared
2024-03-19 22:57:53.939265 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-19 22:57:53.979072 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-19 22:57:53.979364 [ERRO] manager         void Everest::error::ErrorCommBridge::handle_request_clear_error(const json&) :: Error while clearing errors: No errors matched the request.
2024-03-19 22:57:53.980290 [INFO] evse_manager_2:  :: All errors cleared
2024-03-19 22:57:54.009023 [INFO] evse_manager_1:  :: All errors cleared
2024-03-19 22:57:54.030727 [WARN] evse_security:E static std::string evse_security::OpenSSLSupplier::x509_get_responder_url(evse_security::X509Handle*) :: Could not retrieve OCSP Responder URL from certificate
2024-03-19 22:57:54.078883 [INFO] ocpp:OCPP201     :: libocpp: Updating OCSP cache on 0 certificates
2024-03-19 22:57:54.078957 [INFO] ocpp:OCPP201     :: libocpp: Done updating OCSP cache
2024-03-19 22:57:54.197669 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect
to websocket server, error_code: 20, reason: Invalid HTTP status., HTTP response code: 401, category: websocketpp.processor, transport error code: 0, Transport error category: system
2024-03-19 22:57:54.197776 [INFO] ocpp:OCPP201     :: Reconnecting in: 2000ms, attempt: 1
2024-03-19 22:57:56.198522 [INFO] ocpp:OCPP201     :: Reconnecting to TLS websocket at uri: wss://host.docker.internal/ws/cp001 with security profile: 3
2024-03-19 22:57:56.201287 [INFO] evse_security:E  :: TPM Key: false
2024-03-19 22:57:56.201804 [INFO] evse_security:E  :: TPM Key: false
2024-03-19 22:57:56.202785 [WARN] evse_security:E evse_security::GetKeyPairResult evse_security::EvseSecurity::get_key_pair_internal(evse_security::LeafCertificateType, evse_security::EncodingFormat) :: CSMS leaf requires full bundle, but full bundle not found at path: "/workspace/dist/etc/everest/certs/client/csms"
2024-03-19 22:57:56.250271 [INFO] ocpp:OCPP201     :: Using certificate: "/workspace/dist/etc/everest/certs/client/csms/CSMS_LEAF.pem"
2024-03-19 22:57:56.251505 [INFO] ocpp:OCPP201     :: Using key file: "/workspace/dist/etc/everest/certs/client/csms/CSMS_LEAF.key"
2024-03-19 22:57:56.260011 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-19 22:57:56.309859 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect
to websocket server, error_code: 20, reason: Invalid HTTP status., HTTP response code: 401, category: websocketpp.processor, transport error code: 0, Transport error category: system
2024-03-19 22:57:56.309973 [INFO] ocpp:OCPP201     :: Reconnecting in: 6000ms, attempt: 2
2024-03-19 22:58:02.312647 [INFO] ocpp:OCPP201     :: Reconnecting to TLS websocket at uri: wss://host.docker.internal/ws/cp001 with security profile: 3
2024-03-19 22:58:02.360247 [INFO] evse_security:E  :: TPM Key: false
2024-03-19 22:58:02.360947 [INFO] evse_security:E  :: TPM Key: false
2024-03-19 22:58:02.362064 [WARN] evse_security:E evse_security::GetKeyPairResult evse_security::EvseSecurity::get_key_pair_internal(evse_security::LeafCertificateType, evse_security::EncodingFormat) :: CSMS leaf requires full bundle, but full bundle not found at path: "/workspace/dist/etc/everest/certs/client/csms"
2024-03-19 22:58:02.363170 [INFO] ocpp:OCPP201     :: Using certificate: "/workspace/dist/etc/everest/certs/client/csms/CSMS_LEAF.pem"
2024-03-19 22:58:02.363721 [INFO] ocpp:OCPP201     :: Using key file: "/workspace/dist/etc/everest/certs/client/csms/CSMS_LEAF.key"
2024-03-19 22:58:02.368203 [DEBG] ocpp:OCPP201     :: Loading ca csms bundle to verify server certificate: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem
2024-03-19 22:58:02.473193 [ERRO] ocpp:OCPP201    void ocpp::WebsocketBase::log_on_fail(const std::error_code&, const boost::system::error_code&, int) :: Failed to connect
to websocket server, error_code: 20, reason: Invalid HTTP status., HTTP response code: 401, category: websocketpp.processor, transport error code: 0, Transport error category: system
2024-03-19 22:58:02.473319 [INFO] ocpp:OCPP201     :: Reconnecting in: 14000ms, attempt: 3

@jhoshiko The warning should not matter here. We are all getting this warning.
Can you please check what's happening on the MaEVe side? Like check logs of MaEVe gateway and manager?

@sahabulh @activeshadow the goal of the MRE is to have a script that showcases the steps needed to enable the functionality that you are interested in. It should run without requiring any changes. If we need to add an EVerest organization to MaEVe, let's do so with a patch, indicating that the change is required. We can then follow up with the MaEVe community to discuss whether the list of orgs should be in the source code or whether it can be pulled out to a config file for easier customization.

@sahabulh if you need an example of how to use a patch, you can see the example in
https://github.com/EVerest/everest-demo/pull/19

@sahabulh Here are the logs from the MaEVe manager:

MaEVe manager log
2024-03-20 11:09:24 time=2024-03-20T17:09:24.685Z level=INFO msg=listening name=api addr=[::]:9410
2024-03-20 11:09:24 time=2024-03-20T17:09:24.860Z level=INFO msg=listening name=ocpi addr=[::]:9411
2024-03-20 11:09:45 time=2024-03-20T17:09:45.602Z level=INFO msg="POST /api/v0/cs/cp001" remote_addr=<IP_ADDRESS>:59502 status=201 bytes=0 duration=622.751672ms
2024-03-20 11:09:45 time=2024-03-20T17:09:45.746Z level=INFO msg="POST /api/v0/token" remote_addr=<IP_ADDRESS>:59506 status=201 bytes=0 duration=7.09604ms
2024-03-20 11:10:24 time=2024-03-20T17:10:24.684Z level=INFO msg="checking for pending charge station certificates changes"
2024-03-20 11:10:24 time=2024-03-20T17:10:24.684Z level=INFO msg="checking for pending charge station settings changes"
2024-03-20 11:10:29 time=2024-03-20T17:10:24.684Z level=INFO msg="sync triggers" duration=91.516758ms sync.trigger.previous="" sync.trigger.count=0
2024-03-20 11:11:05 time=2024-03-20T17:11:05.831Z level=INFO msg="GET /api/v0/cs/cp001/auth" remote_addr=[2001:db8:a::6]:49174 status=200 bytes=53 duration=7.79831ms
2024-03-20 11:11:09 time=2024-03-20T17:11:09.049Z level=INFO msg="GET /api/v0/cs/cp001/auth" remote_addr=[2001:db8:a::6]:49174 status=200 bytes=53 duration=3.676958ms
2024-03-20 11:11:16 time=2024-03-20T17:11:16.278Z level=INFO msg="GET /api/v0/cs/cp001/auth" remote_addr=[2001:db8:a::6]:49174 status=200 bytes=53 duration=3.184878ms
2024-03-20 11:11:24 time=2024-03-20T17:11:24.773Z level=INFO msg="checking for pending charge station certificates changes"
2024-03-20 11:11:24 time=2024-03-20T17:11:24.773Z level=INFO msg="checking for pending charge station settings changes"
2024-03-20 11:11:29 time=2024-03-20T17:11:24.773Z level=INFO msg="sync triggers" duration=31.36846ms sync.trigger.previous="" sync.trigger.count=0
2024-03-20 11:11:32 time=2024-03-20T17:11:32.486Z level=INFO msg="GET /api/v0/cs/cp001/auth" remote_addr=[2001:db8:a::6]:49174 status=200 bytes=53 duration=5.203985ms
2024-03-20 11:11:34 time=2024-03-20T17:11:34.633Z level=INFO msg="GET /api/v0/cs/cp001/auth" remote_addr=[2001:db8:a::6]:49174 status=200 bytes=53 duration=4.812048ms
2024-03-20 11:11:35 time=2024-03-20T17:11:35.741Z level=INFO msg="GET /api/v0/cs/cp001/auth" remote_addr=[2001:db8:a::6]:49174 status=200 bytes=53 duration=5.840972ms
2024-03-20 11:11:39 time=2024-03-20T17:11:39.904Z level=INFO msg="GET /api/v0/cs/cp001/auth" remote_addr=[2001:db8:a::6]:49174 status=200 bytes=53 duration=3.137003ms
2024-03-20 11:11:48 time=2024-03-20T17:11:48.172Z level=INFO msg="GET /api/v0/cs/cp001/auth" remote_addr=[2001:db8:a::6]:49174 status=200 bytes=53 duration=2.802441ms
2024-03-20 11:11:50 time=2024-03-20T17:11:50.381Z level=INFO msg="GET /api/v0/cs/cp001/auth" remote_addr=[2001:db8:a::6]:49174 status=200 bytes=53 duration=3.603156ms

and here are the logs from the MaEVe gateway:

MaEVe gateway log
2024-03-20 11:09:34 2024/03/20 17:09:34 INFO listening name=ws addr=[::]:9310
2024-03-20 11:09:34 2024/03/20 17:09:34 INFO listening name=wss addr=[::]:9311
2024-03-20 11:09:34 2024/03/20 17:09:34 INFO listening name=status addr=[::]:9312
2024-03-20 11:11:05 2024/03/20 17:11:05 INFO websocket connection received path=/ws/cp001 method=GET
2024-03-20 11:11:05 2024/03/20 17:11:05 INFO processing connection uri=/ws/cp001
2024-03-20 11:11:09 2024/03/20 17:11:09 INFO websocket connection received path=/ws/cp001 method=GET
2024-03-20 11:11:09 2024/03/20 17:11:09 INFO processing connection uri=/ws/cp001
2024-03-20 11:11:09 2024/03/20 17:11:09 ERROR GET /ws/{id} duration=10.097273ms http.scheme=wss http.method=GET http.url=/ws/cp001 csId=cp001 ocpp.security_profile=2 auth.organization=[EVerest] auth.common_name=host.docker.internal auth.failure_reason="bad organization" http.status_code=401 http.route=/ws/{id}
2024-03-20 11:11:09 2024/03/20 17:11:09 ERROR GET /ws/{id} duration=4.365253ms http.scheme=wss http.method=GET http.url=/ws/cp001 csId=cp001 ocpp.security_profile=2 auth.organization=[EVerest] auth.common_name=host.docker.internal auth.failure_reason="bad organization" http.status_code=401 http.route=/ws/{id}
2024-03-20 11:11:16 2024/03/20 17:11:16 INFO websocket connection received path=/ws/cp001 method=GET
2024-03-20 11:11:16 2024/03/20 17:11:16 INFO processing connection uri=/ws/cp001
2024-03-20 11:11:19 2024/03/20 17:11:19 ERROR GET /ws/{id} duration=3.706381ms http.scheme=wss http.method=GET http.url=/ws/cp001 csId=cp001 ocpp.security_profile=2 auth.organization=[EVerest] auth.common_name=host.docker.internal auth.failure_reason="bad organization" http.status_code=401 http.route=/ws/{id}
2024-03-20 11:11:32 2024/03/20 17:11:32 INFO websocket connection received path=/ws/cp001 method=GET
2024-03-20 11:11:32 2024/03/20 17:11:32 INFO processing connection uri=/ws/cp001
2024-03-20 11:11:34 2024/03/20 17:11:34 ERROR GET /ws/{id} duration=6.362641ms http.scheme=wss http.method=GET http.url=/ws/cp001 csId=cp001 ocpp.security_profile=2 auth.organization=[EVerest] auth.common_name=host.docker.internal auth.failure_reason="bad organization" http.status_code=401 http.route=/ws/{id}
2024-03-20 11:11:34 2024/03/20 17:11:34 INFO websocket connection received path=/ws/cp001 method=GET
2024-03-20 11:11:34 2024/03/20 17:11:34 INFO processing connection uri=/ws/cp001
2024-03-20 11:11:35 2024/03/20 17:11:35 INFO websocket connection received path=/ws/cp001 method=GET
2024-03-20 11:11:35 2024/03/20 17:11:35 INFO processing connection uri=/ws/cp001
2024-03-20 11:11:39 2024/03/20 17:11:39 ERROR GET /ws/{id} duration=5.665514ms http.scheme=wss http.method=GET http.url=/ws/cp001 csId=cp001 ocpp.security_profile=2 auth.organization=[EVerest] auth.common_name=host.docker.internal auth.failure_reason="bad organization" http.status_code=401 http.route=/ws/{id}
2024-03-20 11:11:39 2024/03/20 17:11:39 ERROR GET /ws/{id} duration=6.445951ms http.scheme=wss http.method=GET http.url=/ws/cp001 csId=cp001 ocpp.security_profile=2 auth.organization=[EVerest] auth.common_name=host.docker.internal auth.failure_reason="bad organization" http.status_code=401 http.route=/ws/{id}
2024-03-20 11:11:39 2024/03/20 17:11:39 INFO websocket connection received path=/ws/cp001 method=GET
2024-03-20 11:11:39 2024/03/20 17:11:39 INFO processing connection uri=/ws/cp001
2024-03-20 11:11:44 2024/03/20 17:11:44 ERROR GET /ws/{id} duration=4.144878ms http.scheme=wss http.method=GET http.url=/ws/cp001 csId=cp001 ocpp.security_profile=2 auth.organization=[EVerest] auth.common_name=host.docker.internal auth.failure_reason="bad organization" http.status_code=401 http.route=/ws/{id}
2024-03-20 11:11:48 2024/03/20 17:11:48 INFO websocket connection received path=/ws/cp001 method=GET
2024-03-20 11:11:48 2024/03/20 17:11:48 INFO processing connection uri=/ws/cp001
2024-03-20 11:11:49 2024/03/20 17:11:49 ERROR GET /ws/{id} duration=3.682693ms http.scheme=wss http.method=GET http.url=/ws/cp001 csId=cp001 ocpp.security_profile=2 auth.organization=[EVerest] auth.common_name=host.docker.internal auth.failure_reason="bad organization" http.status_code=401 http.route=/ws/{id}
2024-03-20 11:11:50 2024/03/20 17:11:50 INFO websocket connection received path=/ws/cp001 method=GET
2024-03-20 11:11:50 2024/03/20 17:11:50 INFO processing connection uri=/ws/cp001
2024-03-20 11:11:54 2024/03/20 17:11:54 ERROR GET /ws/{id} duration=4.201889ms http.scheme=wss http.method=GET http.url=/ws/cp001 csId=cp001 ocpp.security_profile=2 auth.organization=[EVerest] auth.common_name=host.docker.internal auth.failure_reason="bad organization" http.status_code=401 http.route=/ws/{id}

Looks like you are correct, I am getting a bad organization error.

If we need to add an EVerest organization to MaEVe, let's do so with a patch, indicating that the change is required.

@sahabulh if you need an example of how to use a patch, you can see the example in #19

@shankari I know how to use a patch. The reason it worked for me is that I used my own MaEVe fork which had the OrgName added already. I couldn't use the original repo as the load balancer doesn't work for me. Later, just before submitting the PR, I linked the original repo as you suggested doing so. But I forgot to add the changes needed in the original repo.

I can submit another PR with the patch file and related command added to the one-liner.

I can submit another PR with the patch file and related command added to the one-liner.

@sahabulh I'm working on this right now so don't worry about spending time on it.

Marking this as done since all the changes have been merged