EVerest / everest-demo

EVerest demo: Dockerized demo with software in the loop simulation
Apache License 2.0
11 stars 13 forks source link

Enable Security Profile 3 (TLS with Client Side Certificates) #25

Closed shankari closed 3 months ago

shankari commented 4 months ago

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

Screenshot 2024-03-10 at 11 21 37 AM

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

shankari commented 4 months ago

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.

shankari commented 4 months ago

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:

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.

shankari commented 4 months ago

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.

shankari commented 4 months ago

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.

shankari commented 4 months ago

~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

shankari commented 4 months ago

Forked Maeve is finally up.

  1. 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
  1. 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
shankari commented 4 months ago

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)

For now, we are going to copy the files to the correct locations.

shankari commented 4 months ago

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
shankari commented 4 months ago

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.

Screenshot 2024-03-10 at 3 06 46 PM

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...

shankari commented 4 months ago

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.

shankari commented 4 months ago

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

shankari commented 4 months ago
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...

shankari commented 4 months ago

Checking the generate_test_certs.sh, we need to:

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

shankari commented 4 months ago

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:

  1. will try to put in the root as root and the leaf in the directory
  2. will try to upgrade to the most recent version of EVerest (in case there are code fixes)
  3. will poke through the code some more
  4. will ask the EVerest community to clarify
shankari commented 4 months ago

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?

shankari commented 4 months ago

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
shankari commented 4 months ago

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.

shankari commented 4 months ago

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"

But we don't see the CSMS files although the SECC files exist

a8a8b1400059:/workspace/dist/etc/everest/certs# find . -name \*CSMS\*
a8a8b1400059:/workspace/dist/etc/everest/certs# find . -name \*SECC\*
./client/cso/SECC_LEAF.pem
./client/cso/SECC_LEAF.key
./client/cso/SECC_LEAF_PASSWORD.txt
./client/cso/SECC_LEAF.der

Rerunning the script after tweaking the path, we get

# find . -name \*CSMS\*
./client/csms/CSMS_LEAF.key
./client/csms/CSMS_LEAF.pem
./client/invalid/INVALID_CSMS.pem
./client/invalid/INVALID_CSMS.key

And the cert chain is vald

# openssl verify -show_chain -CAfile ca/v2g/V2G_ROOT_CA.pem --untrusted ca/csms/CPO_SUB_CA1.pem --untrusted ca/csms/CPO_SUB_CA2.pem client/csms/CSMS_LEAF.pem
client/csms/CSMS_LEAF.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

Let's copy this over to the CSMS and see if we can get it to work. Note also a doh moment in that the path for the CSMS pem is client/csms and not ca/csms

shankari commented 4 months ago

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
shankari commented 4 months ago

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.

$ cat config/certificates/cpo_sub_ca1.pem config/certificates/cpo_sub_ca2.pem > config/certificates/trust.pem
$ openssl verify -show_chain -CAfile config/certificates/root-V2G-cert.pem -untrusted config/certificates/trust.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

Now, let's restart everything!

shankari commented 4 months ago

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:
shankari commented 4 months ago

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-----
shankari commented 4 months ago

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. It complains that the private key does not match the public key.

Screenshot 2024-03-10 at 6 16 03 PM

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

shankari commented 4 months ago

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
shankari commented 4 months ago
shankari commented 4 months ago

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

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.

shankari commented 4 months ago

Tried turning off the load balancer

shankari commented 4 months ago

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.

sahabulh commented 4 months ago

The fork () has several hardcoded certificates, which are the ones passed in to the maeve command line. 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 named it that way to avoid confusion.

sahabulh commented 4 months ago

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

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.

sahabulh commented 4 months ago

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

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.

sahabulh commented 4 months ago

V2G_CA_BUNDLE

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

shankari commented 4 months ago

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.

shankari commented 4 months ago

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.

sahabulh commented 4 months ago

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? Next steps:

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.

CRR-SNL commented 4 months ago

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.

shankari commented 4 months ago

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."

sahabulh commented 4 months ago

Do the certs checked in to the fork actually work?!

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.

shankari commented 4 months ago

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 generate the MRE and hand it over to others. (cp dist/etc/everest/certs/ca/v2g/V2G_CA_BUNDLE.pem dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem)

Aha!

2024-03-11 16:42:41.838334 [INFO] ocpp:OCPP201     :: Connecting TLS websocket to uri: wss://host.docker.internal/ws/cp001 with security-profile 2
2024-03-11 16:42:41.887152 [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:42:42.069517 [WARN] ocpp:OCPP201    bool ocpp::WebsocketTLS::verify_csms_cn(const std::string&, bool, boost::asio::ssl::verify_context&) :: FQDN 'host.docker.internal' does not match CN 'SECCCert' or any alternative names
2024-03-11 16:42:42.073916 [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-11 16:42:42.074029 [INFO] ocpp:OCPP201     :: Reconnecting in: 2000ms, attempt: 1
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-11 16:42:42.123560 [CRIT] manager         int boot(const boost::program_options::variables_map&) :: Module evse_security (pid: 678) exited with status: 6. Terminating all modules.
2024-03-11 16:42:42.125019 [INFO] manager          :: SIGTERM of child: api (pid: 671) succeeded.
2024-03-11 16:42:42.125193 [INFO] manager          :: SIGTERM of child: auth (pid: 672) succeeded.
2024-03-11 16:42:42.125247 [INFO] manager          :: SIGTERM of child: car_simulator_1 (pid: 673) succeeded.
2024-03-11 16:42:42.125289 [INFO] manager          :: SIGTERM of child: car_simulator_2 (pid: 674) succeeded.
2024-03-11 16:42:42.125347 [INFO] manager          :: SIGTERM of child: energy_manager (pid: 675) succeeded.
2024-03-11 16:42:42.125579 [INFO] manager          :: SIGTERM of child: evse_manager_1 (pid: 676) succeeded.
2024-03-11 16:42:42.125818 [INFO] manager          :: SIGTERM of child: evse_manager_2 (pid: 677) succeeded.
2024-03-11 16:42:42.125917 [INFO] manager          :: SIGTERM of child: grid_connection_point (pid: 679) succeeded.
2024-03-11 16:42:42.125973 [INFO] manager          :: SIGTERM of child: iso15118_car (pid: 690) succeeded.
2024-03-11 16:42:42.126060 [INFO] manager          :: SIGTERM of child: iso15118_charger (pid: 692) succeeded.
2024-03-11 16:42:42.126234 [INFO] manager          :: SIGTERM of child: ocpp (pid: 693) succeeded.
2024-03-11 16:42:42.126410 [INFO] manager          :: SIGTERM of child: persistent_store (pid: 695) succeeded.
2024-03-11 16:42:42.126594 [INFO] manager          :: SIGTERM of child: slac (pid: 696) succeeded.
2024-03-11 16:42:42.126656 [INFO] manager          :: SIGTERM of child: system (pid: 697) succeeded.
2024-03-11 16:42:42.126696 [INFO] manager          :: SIGTERM of child: token_provider_1 (pid: 698) succeeded.
2024-03-11 16:42:42.126727 [INFO] manager          :: SIGTERM of child: yeti_driver_1 (pid: 700) succeeded.
2024-03-11 16:42:42.126760 [INFO] manager          :: SIGTERM of child: yeti_driver_2 (pid: 705) succeeded.
2024-03-11 16:42:42.126788 [CRIT] manager         int boot(const boost::program_options::variables_map&) :: Exiting manager.

I see at least two errors:

Fixing the first is trivial, the second needs more work to debug. But there is a trace and a pointer to the module with the error, so we should be able to figure out what that does.

shankari commented 4 months ago

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)"
shankari commented 4 months ago

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

It is used to check for certificate equality, right after the issuer name.

    bool operator==(const CertificateHashData& other) const {
        return get_issuer_name_hash() == other.issuer_name_hash && get_issuer_key_hash() == other.issuer_key_hash &&
               get_serial_number() == other.serial_number;
    }

Here's where that check happens. We should fix the cert name and then maybe add additional logs to figure out which certs are being verified. https://github.com/EVerest/libocpp/blob/51b3a62f598f7f093193ab2af67ec7966f0dcc79/lib/ocpp/common/websocket/websocket_tls.cpp#L307

sahabulh commented 4 months ago

@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.

shankari commented 4 months ago

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 - I bet this is just a configuration issue where we are not setting up the certs correctlly. Will create an MRE so that we can get support and then finish this up

shankari commented 4 months ago

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. Terminating all modules.
jhoshiko commented 4 months ago

@shankari I ran your MRE and got the following outputs:

Log ``` $ docker exec -it everest-ac-demo-manager-1 bash 878f6de253d6:/workspace# sh ./build/run-scripts/run-sil-ocpp201.sh 2024-03-12 17:57:52.259984 [INFO] manager :: ________ __ _ 2024-03-12 17:57:52.262298 [INFO] manager :: | ____\ \ / / | | 2024-03-12 17:57:52.262585 [INFO] manager :: | |__ \ \ / /__ _ __ ___ ___| |_ 2024-03-12 17:57:52.263673 [INFO] manager :: | __| \ \/ / _ \ '__/ _ \/ __| __| 2024-03-12 17:57:52.263734 [INFO] manager :: | |____ \ / __/ | | __/\__ \ |_ 2024-03-12 17:57:52.263792 [INFO] manager :: |______| \/ \___|_| \___||___/\__| 2024-03-12 17:57:52.263880 [INFO] manager :: 2024-03-12 17:57:52.263943 [INFO] manager :: Using MQTT broker mqtt-server:1883 2024-03-12 17:57:52.708889 [INFO] everest_ctrl :: Launching controller service on port 8849 2024-03-12 17:57:52.773946 [INFO] manager :: Loading config file at: /ext/source/config/config-sil-ocpp201.yaml 2024-03-12 17:57:55.678300 [INFO] manager :: Config loading completed in 3400ms 2024-03-12 17:58:16.930624 [INFO] api:API :: Module api initialized [20025ms] 2024-03-12 17:58:17.414058 [INFO] energy_manager: :: Module energy_manager initialized [19802ms] 2024-03-12 17:58:17.913958 [INFO] grid_connection :: Module grid_connection_point initialized [17295ms] 2024-03-12 17:58:23.908707 [INFO] auth:Auth :: Module auth initialized [26800ms] 2024-03-12 17:58:29.718644 [INFO] iso15118_charge :: TCP server on eth0 is listening on port [fe80::42:acff:fe13:3%24]:61341 2024-03-12 17:58:29.720732 [INFO] iso15118_charge :: TLS server on eth0 is listening on port [fe80::42:acff:fe13:3%24]:64109 2024-03-12 17:58:29.720917 [INFO] iso15118_charge :: SDP socket setup succeeded 2024-03-12 17:58:29.817369 [INFO] iso15118_charge :: Module iso15118_charger initialized [24310ms] 2024-03-12 17:58:31.307451 [INFO] system:System :: Module system initialized [21398ms] 2024-03-12 17:58:32.205795 [INFO] persistent_stor :: Module persistent_store initialized [27888ms] 2024-03-12 17:58:33.705264 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional >&, const std::optional&, const std::optional&, const std::optional >&, const std::optional >&) :: Could not find configured V2G bundle file at: /workspace/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem, creating default! 2024-03-12 17:58:33.708940 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional >&, const std::optional&, const std::optional&, const std::optional >&, const std::optional >&) :: Could not find configured MO bundle file at: /workspace/dist/etc/everest/certs/ca/mo/MO_ROOT_CA.pem, creating default! 2024-03-12 17:58:33.710114 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional >&, const std::optional&, const std::optional&, const std::optional >&, const std::optional >&) :: Could not find configured MF bundle file at: /workspace/dist/etc/everest/certs/ca/mf/MF_ROOT_CA.pem, creating default! 2024-03-12 17:58:33.905005 [INFO] evse_security:E :: Module evse_security initialized [33493ms] 2024-03-12 17:58:37.108644 [INFO] evse_manager_1: :: Module evse_manager_1 initialized [34503ms] 2024-03-12 17:58:37.124750 [INFO] token_provider_ :: Module token_provider_1 initialized [28104ms] 2024-03-12 17:58:37.615108 [INFO] ocpp:OCPP201 :: Module ocpp initialized [27607ms] 2024-03-12 17:58:40.606419 [INFO] evse_manager_2: :: Module evse_manager_2 initialized [37901ms] 2024-03-12 17:58:56.906358 [INFO] manager :: 🚙🚙🚙 All modules are initialized. 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():: :: 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

shankari commented 4 months ago

@jhoshiko please look at the script, and the step that copies over the bundle. You can also look through the issue for that error and the step that is supposed to resolve it. Is that running successfully?

jhoshiko commented 4 months ago

@shankari Ok, looks like there was issue finding bash that caused issues copying the bundle over. I fixed those and am now getting the same error in this comment

Log ``` $ docker exec -it everest-ac-demo-manager-1 bash 1b64afe1dbfe:/workspace# sh ./build/run-scripts/run-sil-ocpp201.sh 2024-03-12 19:04:46.090488 [INFO] manager :: ________ __ _ 2024-03-12 19:04:46.090598 [INFO] manager :: | ____\ \ / / | | 2024-03-12 19:04:46.090624 [INFO] manager :: | |__ \ \ / /__ _ __ ___ ___| |_ 2024-03-12 19:04:46.090634 [INFO] manager :: | __| \ \/ / _ \ '__/ _ \/ __| __| 2024-03-12 19:04:46.090643 [INFO] manager :: | |____ \ / __/ | | __/\__ \ |_ 2024-03-12 19:04:46.090651 [INFO] manager :: |______| \/ \___|_| \___||___/\__| 2024-03-12 19:04:46.090660 [INFO] manager :: 2024-03-12 19:04:46.090669 [INFO] manager :: Using MQTT broker mqtt-server:1883 2024-03-12 19:04:46.095109 [INFO] everest_ctrl :: Launching controller service on port 8849 2024-03-12 19:04:46.116883 [INFO] manager :: Loading config file at: /ext/source/config/config-sil-ocpp201.yaml 2024-03-12 19:04:46.439887 [INFO] manager :: Config loading completed in 348ms 2024-03-12 19:04:52.286405 [INFO] evse_manager_1: :: Module evse_manager_1 initialized [5688ms] 2024-03-12 19:04:53.486347 [INFO] api:API :: Module api initialized [6978ms] 2024-03-12 19:04:53.889762 [INFO] token_provider_ :: Module token_provider_1 initialized [6600ms] 2024-03-12 19:04:54.386295 [INFO] evse_manager_2: :: Module evse_manager_2 initialized [7592ms] 2024-03-12 19:04:54.491627 [INFO] grid_connection :: Module grid_connection_point initialized [7804ms] 2024-03-12 19:04:55.089966 [INFO] auth:Auth :: Module auth initialized [8496ms] 2024-03-12 19:04:55.186895 [INFO] ocpp:OCPP201 :: Module ocpp initialized [7790ms] 2024-03-12 19:04:56.186197 [INFO] evse_security:E :: Module evse_security initialized [9582ms] 2024-03-12 19:04:56.201006 [INFO] persistent_stor :: Module persistent_store initialized [8909ms] 2024-03-12 19:04:56.489750 [INFO] energy_manager: :: Module energy_manager initialized [9699ms] 2024-03-12 19:04:56.494869 [INFO] iso15118_charge :: TCP server on eth0 is listening on port [fe80::42:acff:fe17:3%68]:61341 2024-03-12 19:04:56.495303 [INFO] iso15118_charge :: TLS server on eth0 is listening on port [fe80::42:acff:fe17:3%68]:64109 2024-03-12 19:04:56.495404 [INFO] iso15118_charge :: SDP socket setup succeeded 2024-03-12 19:04:56.585959 [INFO] iso15118_charge :: Module iso15118_charger initialized [9498ms] 2024-03-12 19:04:56.593804 [INFO] system:System :: Module system initialized [9491ms] 2024-03-12 19:05:02.077780 [INFO] manager :: 🚙🚙🚙 All modules are initialized. 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. Terminating all modules. 2024-03-12 19:05:03.176413 [INFO] manager :: SIGTERM of child: api (pid: 146) succeeded. 2024-03-12 19:05:03.176732 [INFO] manager :: SIGTERM of child: auth (pid: 147) succeeded. 2024-03-12 19:05:03.176817 [INFO] manager :: SIGTERM of child: car_simulator_1 (pid: 148) succeeded. 2024-03-12 19:05:03.178634 [INFO] manager :: SIGTERM of child: car_simulator_2 (pid: 149) succeeded. 2024-03-12 19:05:03.178856 [INFO] manager :: SIGTERM of child: energy_manager (pid: 150) succeeded. 2024-03-12 19:05:03.180871 [INFO] manager :: SIGTERM of child: evse_manager_1 (pid: 151) succeeded. 2024-03-12 19:05:03.181616 [INFO] manager :: SIGTERM of child: evse_manager_2 (pid: 152) succeeded. 2024-03-12 19:05:03.181729 [INFO] manager :: SIGTERM of child: grid_connection_point (pid: 154) succeeded. 2024-03-12 19:05:03.181799 [INFO] manager :: SIGTERM of child: iso15118_car (pid: 155) succeeded. 2024-03-12 19:05:03.181871 [INFO] manager :: SIGTERM of child: iso15118_charger (pid: 156) succeeded. 2024-03-12 19:05:03.185693 [INFO] manager :: SIGTERM of child: ocpp (pid: 157) succeeded. 2024-03-12 19:05:03.185835 [INFO] manager :: SIGTERM of child: persistent_store (pid: 158) succeeded. 2024-03-12 19:05:03.185879 [INFO] manager :: SIGTERM of child: slac (pid: 159) succeeded. 2024-03-12 19:05:03.185928 [INFO] manager :: SIGTERM of child: system (pid: 160) succeeded. 2024-03-12 19:05:03.185961 [INFO] manager :: SIGTERM of child: token_provider_1 (pid: 161) succeeded. 2024-03-12 19:05:03.185980 [INFO] manager :: SIGTERM of child: yeti_driver_1 (pid: 162) succeeded. 2024-03-12 19:05:03.186019 [INFO] manager :: SIGTERM of child: yeti_driver_2 (pid: 163) succeeded. 2024-03-12 19:05:03.186061 [CRIT] manager int boot(const boost::program_options::variables_map&) :: Exiting manager. ```

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
shankari commented 4 months ago

@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?

jhoshiko commented 4 months ago

@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 it 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.

sahabulh commented 4 months ago

This is my output for the MRE:

Log ``` 2024-03-12 23:18:19.869288 [INFO] manager :: ________ __ _ 2024-03-12 23:18:19.869336 [INFO] manager :: | ____\ \ / / | | 2024-03-12 23:18:19.869346 [INFO] manager :: | |__ \ \ / /__ _ __ ___ ___| |_ 2024-03-12 23:18:19.869353 [INFO] manager :: | __| \ \/ / _ \ '__/ _ \/ __| __| 2024-03-12 23:18:19.869360 [INFO] manager :: | |____ \ / __/ | | __/\__ \ |_ 2024-03-12 23:18:19.869367 [INFO] manager :: |______| \/ \___|_| \___||___/\__| 2024-03-12 23:18:19.869375 [INFO] manager :: 2024-03-12 23:18:19.869382 [INFO] manager :: Using MQTT broker mqtt-server:1883 2024-03-12 23:18:19.872003 [INFO] everest_ctrl :: Launching controller service on port 8849 2024-03-12 23:18:19.888420 [INFO] manager :: Loading config file at: /ext/source/config/config-sil-ocpp201.yaml 2024-03-12 23:18:20.093399 [INFO] manager :: Config loading completed in 223ms 2024-03-12 23:18:29.544010 [INFO] token_provider_ :: Module token_provider_1 initialized [8695ms] 2024-03-12 23:18:29.645654 [INFO] system:System :: Module system initialized [8993ms] 2024-03-12 23:18:29.748614 [INFO] auth:Auth :: Module auth initialized [9637ms] 2024-03-12 23:18:29.847790 [INFO] api:API :: Module api initialized [9697ms] 2024-03-12 23:18:30.047092 [INFO] persistent_stor :: Module persistent_store initialized [9796ms] 2024-03-12 23:18:31.344110 [INFO] ocpp:OCPP201 :: Module ocpp initialized [10900ms] 2024-03-12 23:18:31.945580 [INFO] evse_manager_2: :: Module evse_manager_2 initialized [11700ms] 2024-03-12 23:18:32.043771 [INFO] energy_manager: :: Module energy_manager initialized [11897ms] 2024-03-12 23:18:32.344608 [INFO] grid_connection :: Module grid_connection_point initialized [11500ms] 2024-03-12 23:18:32.449422 [INFO] iso15118_charge :: TCP server on eth0 is listening on port [fe80::42:c0ff:fea8:d003%1764]:61341 2024-03-12 23:18:32.449682 [INFO] iso15118_charge :: TLS server on eth0 is listening on port [fe80::42:c0ff:fea8:d003%1764]:64109 2024-03-12 23:18:32.449856 [INFO] iso15118_charge :: SDP socket setup succeeded 2024-03-12 23:18:32.450537 [INFO] iso15118_charge :: Module iso15118_charger initialized [12204ms] 2024-03-12 23:18:32.846132 [INFO] evse_security:E :: Module evse_security initialized [12696ms] 2024-03-12 23:18:32.951669 [INFO] evse_manager_1: :: Module evse_manager_1 initialized [12802ms] 2024-03-12 23:18:33.805182 [INFO] manager :: 🚙🚙🚙 All modules are initialized. 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. Terminating all modules. 2024-03-12 23:18:34.851160 [INFO] manager :: SIGTERM of child: api (pid: 139) succeeded. 2024-03-12 23:18:34.851244 [INFO] manager :: SIGTERM of child: auth (pid: 140) succeeded. 2024-03-12 23:18:34.851262 [INFO] manager :: SIGTERM of child: car_simulator_1 (pid: 141) succeeded. 2024-03-12 23:18:34.851277 [INFO] manager :: SIGTERM of child: car_simulator_2 (pid: 142) succeeded. 2024-03-12 23:18:34.851302 [INFO] manager :: SIGTERM of child: energy_manager (pid: 143) succeeded. 2024-03-12 23:18:34.851537 [INFO] manager :: SIGTERM of child: evse_manager_1 (pid: 144) succeeded. 2024-03-12 23:18:34.851685 [INFO] manager :: SIGTERM of child: evse_manager_2 (pid: 145) succeeded. 2024-03-12 23:18:34.851720 [INFO] manager :: SIGTERM of child: grid_connection_point (pid: 147) succeeded. 2024-03-12 23:18:34.851749 [INFO] manager :: SIGTERM of child: iso15118_car (pid: 148) succeeded. 2024-03-12 23:18:34.851786 [INFO] manager :: SIGTERM of child: iso15118_charger (pid: 149) succeeded. 2024-03-12 23:18:34.851858 [INFO] manager :: SIGTERM of child: ocpp (pid: 150) succeeded. 2024-03-12 23:18:34.851887 [INFO] manager :: SIGTERM of child: persistent_store (pid: 151) succeeded. 2024-03-12 23:18:34.851904 [INFO] manager :: SIGTERM of child: slac (pid: 152) succeeded. 2024-03-12 23:18:34.851937 [INFO] manager :: SIGTERM of child: system (pid: 163) succeeded. 2024-03-12 23:18:34.852018 [INFO] manager :: SIGTERM of child: token_provider_1 (pid: 164) succeeded. 2024-03-12 23:18:34.852126 [INFO] manager :: SIGTERM of child: yeti_driver_1 (pid: 165) succeeded. 2024-03-12 23:18:34.852151 [INFO] manager :: SIGTERM of child: yeti_driver_2 (pid: 168) succeeded. 2024-03-12 23:18:34.852166 [CRIT] manager int boot(const boost::program_options::variables_map&) :: Exiting manager. ```