Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

📝 ❇️ Test all SIL/HIL Demos #84

Open
2 of 3 tasks
the-bay-kay opened this issue Nov 14, 2024 · 57 comments
Open
2 of 3 tasks

📝 ❇️ Test all SIL/HIL Demos #84

the-bay-kay opened this issue Nov 14, 2024 · 57 comments

Comments

@the-bay-kay
Copy link

the-bay-kay commented Nov 14, 2024

Goals

In the final stages of prep for CharIN, we want to exhaustively test a variety of Software-In-the-Loop (SIL) and Hardware-In-the-Loop (HIL) demos that we have developed, to ensure that everything is running smoothly prior to the event. These tests will include (but are not limited to):

  • All existing demo scripts within the repository
    • Note The ReadMe needs to be updated, as the SIL script names have changed! Once the scripts are tested, we should update the "one-line" demos to reflect these changes.
  • The ISO15118 + IEM + OCPP201 SP-1 Renegotiation demo described in Simulator improvements #74
  • Testing the latest demos on a Yocto build in QEMU, as in Build Yocto with recent EVerest release #76

@shankari ,@Abby-Wheelis , @catarial : Tagging for visibility!

@the-bay-kay
Copy link
Author

the-bay-kay commented Nov 14, 2024

Renegotiation Demo

I will be handling this portion of the tests. For this, we will test the following scenarios:

  • Base case: Charge with no DepartureTime or Grid Clamp

    Base Case Aside: we should disable the powercurve visualizations in the non-DT demos, as we do not use it.
    BaseCase.-.Compressed.mp4
  • OCPP Grid Clamp only

    • Pre Session Grid Clamp

      Pre Grid 10A4Hrs
      OCPP.Control.1.mp4
    • Clamp sent mid-session

      Mid Charge 10A4Hrs Aside: the power is successfully adjusted, but this does not seem to trigger an ISO15118-2 Renegotiation -- I believe this is as intended, correct me if I'm wrong. Please see video for additional details.
      OCPP.Mid_Session.1.mp4
    • Profile becomes active during charging

      10A4Hrs Activates During Session
      OCPP.ActivateDuringSession.1.mp4
  • DepartureTimeOnly

  • DepartureTime + OCPP Grid Clamp

    • We will test a few permutations of this!

For each of these, we should test

  • Simulator Speed 1x, and 25x (or another, just to confirm speed up is working)
  • Both Curve options (e.g., "Smooth / Aggressive" curve)
  • Fluctuate EAmount (default is 60, try 30, 80, etc.) *

@catarial
Copy link
Contributor

catarial commented Nov 14, 2024

I can't get the demoes in the main branch to run since they're not compatible with aarch64

"EVerest Demos are currently NOT supported on M1 chips"

Oh I see. I guess I just use my personal laptop

@Abby-Wheelis
Copy link
Contributor

Abby-Wheelis commented Nov 14, 2024

On my nrel laptop (2017 MacBook Pro with Intel chip):
curl https://raw.githubusercontent.com/everest/everest-demo/main/demo-iso15118-2-ocpp-201.sh | bash -s -- -1

After purging docker to free up space, runs until it gets the know error: ERROR [manager builder 6/8] RUN go mod download

I'll take a quick look over at #78 to see if there's a known fix I can try...

Also - draft readME PR #85

@catarial
Copy link
Contributor

catarial commented Nov 14, 2024

I don't see anything for the nodered ui when running demo-ac.sh

image

image

@shankari
Copy link
Collaborator

I'll take a quick look over at #78 to see if there's a known fix I can try...

Ah good to see that it is not just my laptop. There is no fix (I tried several options from the issue). We just have to pre-build and change the demo script accordingly. The good news is that I can now pre-build through a CI. I am actively refactoring the demo to use them now, gimme ~ 30 mins more.

@catarial
Copy link
Contributor

#84 (comment)

It looks like I'm getting this error because nodered isn't up to date.

node-red-1     | 14 Nov 19:28:47 - [warn] [node-red-node-ui-table] Node module cannot be loaded on this version. Requires: >=3.0.0

@shankari
Copy link
Collaborator

Are you able to run from Katie's fork? She has updated node-red. I am updating it more formally in #85 but that is blocked on the maeve CSMS

@catarial
Copy link
Contributor

Are you able to run from Katie's fork? She has updated node-red. I am updating it more formally in #85 but that is blocked on the maeve CSMS

No I wasn't. I thought I was supposed to be testing the main branch, but I guess I should the use the fork for now.

@shankari
Copy link
Collaborator

Yeah, the main branch is WiP

@the-bay-kay
Copy link
Author

the-bay-kay commented Nov 14, 2024

Made a quick change to the node-red flows to fix a bug where we failed during an initial empty DT charging session, but changes are working and pushed! Will update this list with videos of my demo tests, as to not clog this issue with lots of posts.

EDIT: Oops, iso_server.cpp expects a "no-entry" version of DT to be 0, not 86400 -- my bad, let's tweak that so we correctly use the default params...

@shankari
Copy link
Collaborator

once we are done, we should set up a meeting to demo to the rest of the team

@shankari
Copy link
Collaborator

@the-bay-kay ready to schedule a meeting tomorrow?

@the-bay-kay
Copy link
Author

ready to schedule a meeting tomorrow?

I still have some cleanup to do, let me see how the next 12 hours go. Where I'm at now:

  • I killed a few hours this evening fixing the renegotiation process (see the latest commit to my branch)
  • As of writing, we are correctly adjusting the ChargingProfile to reflect DepartureTime, EAmount, and combinations of the two. Likewise, the renegotiation occurs without a hitch. The issue is, we are not seeing these values reflected on the power gauge, as we are with the OCPP clamps (see video for example). Am going to spend some time digging into this: my thought is, we will need to find where we receive the ChargingProfile in iso_server.cpp, and adjust it to call the same mechanism that reduces power when the OCPP profile begins.
ChargingProfile Changes
Renegotiation.w_o.power.change.1.mp4

@the-bay-kay
Copy link
Author

the-bay-kay commented Nov 15, 2024

Will be putting my debug findings below a cut for now, as to not clog this issue for others. We can move & format this documentation once the dust settles (to avoid the "under-the-cut" issues).

Piping through ISO15118-2 Charging Profile based Power Modulation

Let's use the OCPP cases as an example for how to modify the power draw. Looking at the following logs:

2024-11-15 14:31:21.432878 [INFO] evse_manager_1:  :: EVSE IEC Soft overcurrent event (L1:15.90207, L2:15.90207, L3:15.90207, limit 11.55), starting timer.
2024-11-15 14:31:25.137269 [INFO] evse_manager_1:  :: EVSE IEC Set PWM On (16.66666716337204%) took 0 ms
  • The soft overcurrent logs occur within EvseManager/Charger.cpp's check_soft_over_current, and the limit is fetched via the class's get_max_current_signalled_to_ev_internal (which itself is an abstraction of get_max_current_internal).
  • The IEC PWM logs come from the Charger's's update_pwm_now, Calling IEC State machine's set_pwm, which in tern calls the board_support module's call_pwm_on(). Looking at the config, we know the EVSE's board_support is JsYetiSimulator. I don't think we need to get as granular as dissecting this, so let's take a step back and look for where we receive the 15118-2 Charging Profiles

Checking for where the charging profiles are processed...

  • We are at least checking the validity of these profiles...
    • It seems that we are checking the values to make sure that they comply with SECC constraints (e.g., ocpp clamps), but are not passing these values on at any point (the check is the only reference to the profiles in this file, anyway).

Trying to wrap my head around the interaction between these files: TL;DR, we need to somehow fetch the profile data from EvseV2G (iso15118_charger), and correctly create events for the EvseManager to delegate to the JsYetiSimulator (evse_board_support). Mapping these out visually for my own sanity...
image


So, I think the best place to pass through the ChargingProfile has to be within iso_server.cpp's handle_iso_power_delivery... Let's see how we can propagate these details up to the EvseManager.

@Abby-Wheelis
Copy link
Contributor

Abby-Wheelis commented Nov 15, 2024

@Abby-Wheelis, you should be able to test the AC, ISO 15118-2 DC and the ISO 15118 + OCPP 201 demos now.

  • AC demo - loaded, nodered flow and ui showing, "plugged in" - auth, preparing charging, clicked grid events, - paused and unpaused car, clicked to pause and unpause car, stopped and unplugged all without major issues.
A few errors in the logs
Attaching to everest-ac-demo-manager-1, everest-ac-demo-mqtt-server-1, everest-ac-demo-node-red-1
everest-ac-demo-mqtt-server-1  | 1731683942: mosquitto version 2.0.20 starting
everest-ac-demo-mqtt-server-1  | 1731683942: Config loaded from /mosquitto/config/mosquitto.conf.
everest-ac-demo-mqtt-server-1  | 1731683942: Opening ipv4 listen socket on port 1883.
everest-ac-demo-mqtt-server-1  | 1731683942: Opening websockets listen socket on port 9001.
everest-ac-demo-mqtt-server-1  | 1731683942: mosquitto version 2.0.20 running
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.596562 [INFO] manager          ::   ________      __                _   
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.600661 [INFO] manager          ::  |  ____\ \    / /               | |
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.601231 [INFO] manager          ::  | |__   \ \  / /__ _ __ ___  ___| |_
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.601340 [INFO] manager          ::  |  __|   \ \/ / _ \ '__/ _ \/ __| __|
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.601396 [INFO] manager          ::  | |____   \  /  __/ | |  __/\__ \ |_
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.601496 [INFO] manager          ::  |______|   \/ \___|_|  \___||___/\__|
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.602000 [INFO] manager          :: 
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.602076 [INFO] manager          :: everest-framework 0.17.2 @v0.17.2
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.602134 [INFO] manager          :: everest-core 2024.9.0 @2024.9.0
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.603172 [INFO] manager          :: 
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.603278 [INFO] manager          :: Using MQTT broker mqtt-server:1883
everest-ac-demo-manager-1      | 2024-11-15 15:19:05.603466 [INFO] manager          :: Telemetry enabled
everest-ac-demo-manager-1      | 2024-11-15 15:19:07.027361 [INFO] everest_ctrl     :: Launching controller service on port 8849
everest-ac-demo-manager-1      | 2024-11-15 15:19:07.121585 [INFO] manager          :: Loading config file at: /ext/source/config/config-sil.yaml
everest-ac-demo-manager-1      | 2024-11-15 15:19:10.286793 [INFO] manager          :: Config loading completed in 3432ms
everest-ac-demo-mqtt-server-1  | 1731683950: New connection from 172.18.0.4:38638 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731683950: New client connected from 172.18.0.4:38638 as auto-A2C819AD-B3E3-2854-732E-09F1BC310916 (p2, c1, k600).
everest-ac-demo-node-red-1     | 15 Nov 15:19:10 - [info] 
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | Welcome to Node-RED
everest-ac-demo-node-red-1     | ===================
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | 15 Nov 15:19:10 - [info] Node-RED version: v4.0.5
everest-ac-demo-node-red-1     | 15 Nov 15:19:10 - [info] Node.js  version: v20.18.0
everest-ac-demo-node-red-1     | 15 Nov 15:19:10 - [info] Linux 5.15.49-linuxkit-pr x64 LE
everest-ac-demo-node-red-1     | 15 Nov 15:19:12 - [info] Loading palette nodes
everest-ac-demo-node-red-1     | 15 Nov 15:19:17 - [info] Dashboard version 3.6.5 started at /ui
everest-ac-demo-node-red-1     | 15 Nov 15:19:19 - [info] Settings file  : /data/settings.js
everest-ac-demo-node-red-1     | 15 Nov 15:19:19 - [info] Context store  : 'default' [module=memory]
everest-ac-demo-node-red-1     | 15 Nov 15:19:19 - [info] User directory : /data
everest-ac-demo-node-red-1     | 15 Nov 15:19:19 - [warn] Projects disabled : editorTheme.projects.enabled=false
everest-ac-demo-node-red-1     | 15 Nov 15:19:19 - [info] Flows file     : /config/config-sil-flow.json
everest-ac-demo-node-red-1     | 15 Nov 15:19:19 - [warn] 
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | ---------------------------------------------------------------------
everest-ac-demo-node-red-1     | Your flow credentials file is encrypted using a system-generated key.
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | If the system-generated key is lost for any reason, your credentials
everest-ac-demo-node-red-1     | file will not be recoverable, you will have to delete it and re-enter
everest-ac-demo-node-red-1     | your credentials.
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | You should set your own key using the 'credentialSecret' option in
everest-ac-demo-node-red-1     | your settings file. Node-RED will then re-encrypt your credentials
everest-ac-demo-node-red-1     | file using your chosen key the next time you deploy a change.
everest-ac-demo-node-red-1     | ---------------------------------------------------------------------
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | 15 Nov 15:19:19 - [info] Server now running at http://127.0.0.1:1880/
everest-ac-demo-node-red-1     | 15 Nov 15:19:20 - [warn] Encrypted credentials not found
everest-ac-demo-node-red-1     | 15 Nov 15:19:20 - [info] Starting flows
everest-ac-demo-node-red-1     | 15 Nov 15:19:20 - [info] Started flows
everest-ac-demo-mqtt-server-1  | 1731683960: New connection from 172.18.0.3:41890 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731683960: New client connected from 172.18.0.3:41890 as nodered_f350619498f52f1a (p2, c1, k60).
everest-ac-demo-node-red-1     | 15 Nov 15:19:20 - [info] [mqtt-broker:fc8686af.48d178] Connected to broker: mqtt://mqtt-server:1883
everest-ac-demo-mqtt-server-1  | 1731683964: New connection from 172.18.0.4:40076 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:19:24.114472 [INFO] auth:Auth        :: Module auth initialized [13085ms]
everest-ac-demo-mqtt-server-1  | 1731683964: New client connected from 172.18.0.4:40076 as auto-C739733E-AA4F-4D23-2C37-775DE896AA9F (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731683969: New connection from 172.18.0.4:40078 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731683969: New client connected from 172.18.0.4:40078 as auto-5699942B-1769-4682-0B0A-EC9B4BC49FDA (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:19:29.306513 [INFO] token_provider:  :: Module token_provider initialized [6781ms]
everest-ac-demo-mqtt-server-1  | 1731683970: New connection from 172.18.0.4:38204 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731683971: New client connected from 172.18.0.4:38204 as auto-0645BA7E-E8B2-1FF4-3E5A-77159B8E9879 (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:19:31.190987 [INFO] grid_connection  :: Module grid_connection_point initialized [13813ms]
everest-ac-demo-mqtt-server-1  | 1731683972: New connection from 172.18.0.4:38220 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:19:32.997036 [INFO] setup:Setup      :: Module setup initialized [9387ms]
everest-ac-demo-mqtt-server-1  | 1731683973: New client connected from 172.18.0.4:38220 as auto-5F7D6449-0F89-8B0F-9B17-66E2CCD220E3 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731683974: New connection from 172.18.0.4:38226 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:19:34.691206 [INFO] api:API          :: Module api initialized [23585ms]
everest-ac-demo-mqtt-server-1  | 1731683974: New client connected from 172.18.0.4:38226 as auto-5EED59FA-2945-93B3-13D5-92AAE1E24A20 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731683980: New connection from 172.18.0.4:56940 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731683980: New connection from 172.18.0.4:56946 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:19:40.906756 [INFO] error_history:E  :: Resetting database
everest-ac-demo-manager-1      | 2024-11-15 15:19:41.304248 [INFO] ev_manager:EvMa  :: Module ev_manager initialized [26250ms]
everest-ac-demo-mqtt-server-1  | 1731683981: New client connected from 172.18.0.4:56946 as auto-7BEC658C-B656-47A6-2960-6ADDBBA0491A (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:19:41.605178 [INFO] error_history:E  :: Module error_history initialized [26863ms]
everest-ac-demo-mqtt-server-1  | 1731683981: New client connected from 172.18.0.4:56940 as auto-F9D68279-F943-9E2C-1046-AC6190157F29 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731683981: New connection from 172.18.0.4:56956 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:19:41.989907 [INFO] energy_manager:  :: Module energy_manager initialized [27650ms]
everest-ac-demo-mqtt-server-1  | 1731683981: New connection from 172.18.0.4:56970 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731683981: New client connected from 172.18.0.4:56956 as auto-0BBF8C03-5B2D-6279-DE3C-64C2246EC64B (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:19:42.211343 [INFO] iso15118_charge  :: Module iso15118_charger initialized [22665ms]
everest-ac-demo-mqtt-server-1  | 1731683982: New client connected from 172.18.0.4:56970 as auto-43543B6E-7EA5-5A3E-DD23-B9F6AA81328B (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731683982: New connection from 172.18.0.4:56974 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:19:42.509068 [INFO] token_validator  :: Module token_validator initialized [19296ms]
everest-ac-demo-mqtt-server-1  | 1731683982: New client connected from 172.18.0.4:56974 as auto-39F6F3A5-DD0F-1969-5CFB-55A98E4B5F0E (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731683982: New connection from 172.18.0.4:56988 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:19:42.697672 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional<std::__cxx11::basic_string<char> >&, const std::optional<long unsigned int>&, const std::optional<long unsigned int>&, const std::optional<std::chrono::duration<long int> >&, const std::optional<std::chrono::duration<long int> >&) :: Could not find configured V2G bundle file at: /ext/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem, creating default!
everest-ac-demo-manager-1      | 2024-11-15 15:19:42.703110 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional<std::__cxx11::basic_string<char> >&, const std::optional<long unsigned int>&, const std::optional<long unsigned int>&, const std::optional<std::chrono::duration<long int> >&, const std::optional<std::chrono::duration<long int> >&) :: Could not find configured MO bundle file at: /ext/dist/etc/everest/certs/ca/mo/MO_ROOT_CA.pem, creating default!
everest-ac-demo-manager-1      | 2024-11-15 15:19:42.704824 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional<std::__cxx11::basic_string<char> >&, const std::optional<long unsigned int>&, const std::optional<long unsigned int>&, const std::optional<std::chrono::duration<long int> >&, const std::optional<std::chrono::duration<long int> >&) :: Could not find configured CSMS bundle file at: /ext/dist/etc/everest/certs/ca/csms/CSMS_ROOT_CA.pem, creating default!
everest-ac-demo-manager-1      | 2024-11-15 15:19:42.706137 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional<std::__cxx11::basic_string<char> >&, const std::optional<long unsigned int>&, const std::optional<long unsigned int>&, const std::optional<std::chrono::duration<long int> >&, const std::optional<std::chrono::duration<long int> >&) :: Could not find configured MF bundle file at: /ext/dist/etc/everest/certs/ca/mf/MF_ROOT_CA.pem, creating default!
everest-ac-demo-manager-1      | 2024-11-15 15:19:42.792106 [INFO] evse_security:E  :: Module evse_security initialized [27293ms]
everest-ac-demo-mqtt-server-1  | 1731683982: New client connected from 172.18.0.4:56988 as auto-821BBD4A-E71E-2476-8C62-FAC76A9101EF (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731683983: New connection from 172.18.0.4:56998 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:19:43.506160 [INFO] connector_1:Evs  :: Module connector_1 initialized [30286ms]
everest-ac-demo-mqtt-server-1  | 1731683983: New client connected from 172.18.0.4:56998 as auto-BBC13811-DEC0-E4B8-6679-F6E259062A1C (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731683984: New connection from 172.18.0.4:57002 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731683984: New connection from 172.18.0.4:57014 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731683984: New client connected from 172.18.0.4:57014 as auto-EDAAD223-CFC3-FBF5-B5FB-668145FB7A56 (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:19:44.487168 [INFO] persistent_stor  :: Module persistent_store initialized [23262ms]
everest-ac-demo-mqtt-server-1  | 1731683984: New client connected from 172.18.0.4:57002 as auto-6055B101-554D-FA9C-2CBC-D8D70D42A630 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731683984: New connection from 172.18.0.4:57030 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:19:44.797894 [INFO] slac:SlacSimula  :: Module slac initialized [22581ms]
everest-ac-demo-mqtt-server-1  | 1731683984: New client connected from 172.18.0.4:57030 as auto-27066FFE-6462-7DB9-4A2E-EB6F7D41B118 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731683985: New connection from 172.18.0.4:57042 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731683985: New client connected from 172.18.0.4:57042 as auto-7FA4A310-35EF-A816-65A0-4500E0512088 (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:19:45.909744 [INFO] manager          :: 🚙🚙🚙 All modules are initialized. EVerest up and running [40467ms] 🚙🚙🚙
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:19:45.917624 [INFO] iso15118_charge  :: TCP server on eth0 is listening on port [fe80::42:acff:fe12:4%21]:61341
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:19:45.919228 [INFO] iso15118_charge  :: TLS server on eth0 is listening on port [fe80::42:acff:fe12:4%21]:64109
everest-ac-demo-manager-1      | 2024-11-15 15:19:45.925755 [INFO] evse_security:E  :: Requesting leaf certificate info: V2G
everest-ac-demo-manager-1      | 2024-11-15 15:19:45.926897 [WARN] evse_security:E evse_security::GetCertificateInfoResult evse_security::EvseSecurity::get_leaf_certificate_info_internal(evse_security::LeafCertificateType, evse_security::EncodingFormat, bool) :: Could not find any key pair
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:19:45.930029 [ERRO] iso15118_charge void dlog_func(dloglevel_t, const char*, int, const char*, const char*, ...) :: Failed to read cert_info! Not Accepted
everest-ac-demo-manager-1      | 2024-11-15 15:19:45.931061 [WARN] iso15118_charge void {anonymous}::log_handler(openssl::log_level_t, const std::string&) :: trusted_ca_keys support disabled
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:19:46.004046 [INFO] iso15118_charge  :: SDP socket setup succeeded
everest-ac-demo-manager-1      | 2024-11-15 15:19:46.227554 [INFO] connector_1:Evs  :: AC HLC mode enabled.
everest-ac-demo-manager-1      | 2024-11-15 15:19:46.440602 [INFO] connector_1:Evs  :: Ignoring BSP Event, BSP is not enabled yet.
everest-ac-demo-manager-1      | 2024-11-15 15:19:47.238808 [INFO] connector_1:Evs  :: Cleaning up any other transaction on start up
everest-ac-demo-manager-1      | 2024-11-15 15:19:47.398152 [INFO] connector_1:Evs  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
everest-ac-demo-manager-1      | 2024-11-15 15:19:47.635388 [INFO] connector_1:Evs  :: All errors cleared
everest-ac-demo-manager-1      | 2024-11-15 15:22:26.233976 [INFO] connector_1_pow  :: Lock connector
everest-ac-demo-manager-1      | 2024-11-15 15:22:26.397615 [INFO] connector_1:Evs  :: SYS  Session logging started.
everest-ac-demo-manager-1      | 2024-11-15 15:22:26.398223 [INFO] connector_1:Evs  :: EVSE IEC Session Started: EVConnected
everest-ac-demo-manager-1      | 2024-11-15 15:22:26.413472 [INFO] token_provider:  :: Publishing new dummy token: {
everest-ac-demo-manager-1      |     "type": "ISO14443",
everest-ac-demo-manager-1      |     "value": "DEADBEEF"
everest-ac-demo-manager-1      | } (RFID)
everest-ac-demo-manager-1      | 2024-11-15 15:22:26.478763 [INFO] auth:Auth        :: Received new token: {
everest-ac-demo-manager-1      |     "authorization_type": "RFID",
everest-ac-demo-manager-1      |     "id_token": {
everest-ac-demo-manager-1      |         "type": "ISO14443",
everest-ac-demo-manager-1      |         "value": "DEADBEEF"
everest-ac-demo-manager-1      |     }
everest-ac-demo-manager-1      | }
everest-ac-demo-manager-1      | 2024-11-15 15:22:26.687513 [INFO] token_validator  :: Got validation request for token: DEADBEEF
everest-ac-demo-manager-1      | 2024-11-15 15:22:26.983884 [INFO] token_validator  :: Returning validation status: Accepted
everest-ac-demo-manager-1      | 2024-11-15 15:22:27.101588 [INFO] auth:Auth        :: Providing authorization to connector#1
everest-ac-demo-manager-1      | 2024-11-15 15:22:27.285508 [INFO] auth:Auth        :: Result for token: DEADBEEF: ACCEPTED
everest-ac-demo-manager-1      | 2024-11-15 15:22:27.292171 [INFO] connector_1:Evs  :: EVSE IEC EIM Authorization received
everest-ac-demo-manager-1      | 2024-11-15 15:22:27.408531 [INFO] connector_1:Evs  :: EVSE IEC Transaction Started (0 kWh)
everest-ac-demo-manager-1      | 2024-11-15 15:22:27.420910 [INFO] connector_1:Evs  :: EVSE IEC AC mode, HLC enabled(X1), matching already started. We are in X1 so we can go directly to nominal PWM.
everest-ac-demo-manager-1      | 2024-11-15 15:22:27.421351 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Wait for Auth->PrepareCharging
everest-ac-demo-manager-1      | 2024-11-15 15:22:27.424023 [INFO] connector_1:Evs  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
everest-ac-demo-manager-1      | 2024-11-15 15:22:29.385540 [INFO] connector_1:Evs  ::                                     CAR IEC Event CarRequestedPower
everest-ac-demo-manager-1      | 2024-11-15 15:22:29.386809 [INFO] connector_1:Evs  :: EVSE IEC Charger state: PrepareCharging->Charging
everest-ac-demo-manager-1      | 2024-11-15 15:22:29.637859 [INFO] connector_1:Evs  :: EVSE IEC Event PowerOn
everest-ac-demo-manager-1      | 2024-11-15 15:22:35.463815 [ERRO] connector_1_pow void Everest::error::ErrorManagerImpl::raise_error(const Everest::error::Error&) :: Error raised, type: evse_board_support/BrownOut, sub_type: , message: Simulated fault event
everest-ac-demo-manager-1      | 2024-11-15 15:22:35.768975 [ERRO] connector_1:Evs void Everest::error::ErrorManagerImpl::raise_error(const Everest::error::Error&) :: Error raised, type: evse_manager/Inoperative, sub_type: , message: evse_board_support/BrownOut
everest-ac-demo-manager-1      | 2024-11-15 15:22:35.789038 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Charging->Charging
everest-ac-demo-manager-1      | 2024-11-15 15:22:35.790441 [INFO] connector_1:Evs  :: EVSE IEC Set PWM F
everest-ac-demo-manager-1      | 2024-11-15 15:22:36.205076 [INFO] connector_1:Evs  :: EVSE IEC Set PWM Off
everest-ac-demo-manager-1      | 2024-11-15 15:22:36.216944 [INFO] connector_1:Evs  :: EVSE IEC Event PowerOff
everest-ac-demo-manager-1      | 2024-11-15 15:22:36.907586 [INFO] connector_1:Evs  :: EVSE ISO SLAC UNMATCHED
everest-ac-demo-manager-1      | 2024-11-15 15:22:36.907998 [INFO] connector_1:Evs  :: EVSE ISO D-LINK_READY (false)
everest-ac-demo-manager-1      | 2024-11-15 15:22:36.924446 [INFO] connector_1:Evs  ::                                     CAR IEC Event CarRequestedStopPower
everest-ac-demo-manager-1      | 2024-11-15 15:22:36.983237 [INFO] connector_1:Evs  ::                                     CAR IEC Event BCDtoEF
everest-ac-demo-manager-1      | 2024-11-15 15:22:37.000709 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Charging->Car Paused
everest-ac-demo-manager-1      | 2024-11-15 15:22:39.008659 [INFO] connector_1_pow  :: Cleared error of type evse_board_support/BrownOut with sub_type 
everest-ac-demo-manager-1      | 2024-11-15 15:22:39.295736 [INFO] connector_1:Evs  :: Cleared error of type evse_manager/Inoperative with sub_type 
everest-ac-demo-manager-1      | 2024-11-15 15:22:39.296933 [INFO] connector_1:Evs  :: All errors cleared that prevented charging
everest-ac-demo-manager-1      | 2024-11-15 15:22:39.297223 [INFO] connector_1:Evs  :: All errors cleared
everest-ac-demo-manager-1      | 2024-11-15 15:22:39.748005 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Car Paused->Car Paused
everest-ac-demo-manager-1      | 2024-11-15 15:22:40.096595 [INFO] connector_1:Evs  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
everest-ac-demo-manager-1      | 2024-11-15 15:22:41.120200 [INFO] connector_1:Evs  ::                                     CAR IEC Event CarRequestedPower
everest-ac-demo-manager-1      | 2024-11-15 15:22:41.120829 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Car Paused->Charging
everest-ac-demo-manager-1      | 2024-11-15 15:22:41.369483 [INFO] connector_1:Evs  :: EVSE IEC Event PowerOn
everest-ac-demo-manager-1      | 2024-11-15 15:22:45.426183 [ERRO] connector_1_pow void Everest::error::ErrorManagerImpl::raise_error(const Everest::error::Error&) :: Error raised, type: evse_board_support/MREC20PartialInsertion, sub_type: , message: Simulated fault event
everest-ac-demo-manager-1      | 2024-11-15 15:22:45.484160 [ERRO] connector_1:Evs void Everest::error::ErrorManagerImpl::raise_error(const Everest::error::Error&) :: Error raised, type: evse_manager/Inoperative, sub_type: , message: evse_board_support/MREC20PartialInsertion
everest-ac-demo-manager-1      | 2024-11-15 15:22:45.519631 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Charging->Charging
everest-ac-demo-manager-1      | 2024-11-15 15:22:45.520139 [INFO] connector_1:Evs  :: EVSE IEC Set PWM F
everest-ac-demo-manager-1      | 2024-11-15 15:22:45.657205 [INFO] connector_1:Evs  :: EVSE IEC Event PowerOff
everest-ac-demo-manager-1      | 2024-11-15 15:22:45.922064 [INFO] connector_1:Evs  :: EVSE IEC Set PWM Off
everest-ac-demo-manager-1      | 2024-11-15 15:22:46.127248 [INFO] connector_1:Evs  ::                                     CAR IEC Event BCDtoEF
everest-ac-demo-manager-1      | 2024-11-15 15:22:46.623701 [INFO] connector_1:Evs  ::                                     CAR IEC Event CarRequestedStopPower
everest-ac-demo-manager-1      | 2024-11-15 15:22:46.624517 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Charging->Car Paused
everest-ac-demo-manager-1      | 2024-11-15 15:22:46.675243 [INFO] connector_1:Evs  :: EVSE ISO SLAC MATCHING
everest-ac-demo-manager-1      | 2024-11-15 15:22:46.675498 [INFO] connector_1:Evs  ::                                     CAR IEC Event EFtoBCD
everest-ac-demo-manager-1      | 2024-11-15 15:22:50.190908 [INFO] connector_1_pow  :: Cleared error of type evse_board_support/MREC20PartialInsertion with sub_type 
everest-ac-demo-manager-1      | 2024-11-15 15:22:50.201953 [INFO] connector_1:Evs  :: Cleared error of type evse_manager/Inoperative with sub_type 
everest-ac-demo-manager-1      | 2024-11-15 15:22:50.202569 [INFO] connector_1:Evs  :: All errors cleared that prevented charging
everest-ac-demo-manager-1      | 2024-11-15 15:22:50.202657 [INFO] connector_1:Evs  :: All errors cleared
everest-ac-demo-manager-1      | 2024-11-15 15:22:50.292478 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Car Paused->Car Paused
everest-ac-demo-manager-1      | 2024-11-15 15:22:50.394346 [INFO] connector_1:Evs  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
everest-ac-demo-manager-1      | 2024-11-15 15:22:51.003078 [INFO] connector_1:Evs  ::                                     CAR IEC Event CarRequestedPower
everest-ac-demo-manager-1      | 2024-11-15 15:22:51.003501 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Car Paused->Charging
everest-ac-demo-manager-1      | 2024-11-15 15:22:51.250780 [INFO] connector_1:Evs  :: EVSE IEC Event PowerOn
everest-ac-demo-manager-1      | 2024-11-15 15:22:53.901135 [ERRO] connector_1_pow void Everest::error::ErrorManagerImpl::raise_error(const Everest::error::Error&) :: Error raised, type: connector_lock/VendorError, sub_type: , message: Simulated fault event
everest-ac-demo-manager-1      | 2024-11-15 15:22:53.909749 [ERRO] connector_1:Evs void Everest::error::ErrorManagerImpl::raise_error(const Everest::error::Error&) :: Error raised, type: evse_manager/Inoperative, sub_type: , message: connector_lock/VendorError
everest-ac-demo-manager-1      | 2024-11-15 15:22:53.979116 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Charging->Charging
everest-ac-demo-manager-1      | 2024-11-15 15:22:53.979590 [INFO] connector_1:Evs  :: EVSE IEC Set PWM F
everest-ac-demo-manager-1      | 2024-11-15 15:22:54.037962 [INFO] connector_1:Evs  :: EVSE IEC Event PowerOff
everest-ac-demo-manager-1      | 2024-11-15 15:22:54.341592 [INFO] connector_1:Evs  :: EVSE IEC Set PWM Off
everest-ac-demo-manager-1      | 2024-11-15 15:22:54.584830 [INFO] connector_1:Evs  ::                                     CAR IEC Event BCDtoEF
everest-ac-demo-manager-1      | 2024-11-15 15:22:54.585326 [INFO] connector_1:Evs  :: EVSE ISO SLAC UNMATCHED
everest-ac-demo-manager-1      | 2024-11-15 15:22:54.586772 [INFO] connector_1:Evs  :: EVSE ISO D-LINK_READY (false)
everest-ac-demo-manager-1      | 2024-11-15 15:22:54.811516 [INFO] connector_1:Evs  ::                                     CAR IEC Event CarRequestedStopPower
everest-ac-demo-manager-1      | 2024-11-15 15:22:54.811952 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Charging->Car Paused
everest-ac-demo-manager-1      | 2024-11-15 15:22:55.629109 [INFO] connector_1_pow  :: Cleared error of type connector_lock/VendorError with sub_type 
everest-ac-demo-manager-1      | 2024-11-15 15:22:55.634172 [INFO] connector_1:Evs  :: Cleared error of type evse_manager/Inoperative with sub_type 
everest-ac-demo-manager-1      | 2024-11-15 15:22:55.634383 [INFO] connector_1:Evs  :: All errors cleared that prevented charging
everest-ac-demo-manager-1      | 2024-11-15 15:22:55.634497 [INFO] connector_1:Evs  :: All errors cleared
everest-ac-demo-manager-1      | 2024-11-15 15:22:55.661122 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Car Paused->Car Paused
everest-ac-demo-manager-1      | 2024-11-15 15:22:55.772890 [INFO] connector_1:Evs  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
everest-ac-demo-manager-1      | 2024-11-15 15:22:56.520452 [INFO] connector_1:Evs  ::                                     CAR IEC Event CarRequestedPower
everest-ac-demo-manager-1      | 2024-11-15 15:22:56.520743 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Car Paused->Charging
everest-ac-demo-manager-1      | 2024-11-15 15:22:56.770728 [INFO] connector_1:Evs  :: EVSE IEC Event PowerOn
everest-ac-demo-manager-1      | 2024-11-15 15:23:00.646464 [INFO] connector_1:Evs  :: EVSE IEC Event PowerOff
everest-ac-demo-manager-1      | 2024-11-15 15:23:00.719725 [INFO] connector_1:Evs  ::                                     CAR IEC Event CarRequestedStopPower
everest-ac-demo-manager-1      | 2024-11-15 15:23:00.724349 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Charging->Car Paused
everest-ac-demo-manager-1      | 2024-11-15 15:23:03.597532 [INFO] connector_1:Evs  ::                                     CAR IEC Event CarRequestedPower
everest-ac-demo-manager-1      | 2024-11-15 15:23:03.598628 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Car Paused->Charging
everest-ac-demo-manager-1      | 2024-11-15 15:23:03.847270 [INFO] connector_1:Evs  :: EVSE IEC Event PowerOn
everest-ac-demo-manager-1      | 2024-11-15 15:23:12.658284 [INFO] ev_manager:EvMa  :: Finished simulation.
everest-ac-demo-manager-1      | 2024-11-15 15:23:12.918115 [INFO] connector_1:Evs  :: EVSE IEC Event PowerOff
everest-ac-demo-manager-1      | 2024-11-15 15:23:13.021879 [INFO] connector_1_pow  :: Unlock connector
everest-ac-demo-manager-1      | 2024-11-15 15:23:13.192257 [INFO] connector_1:Evs  ::                                     CAR IEC Event CarUnplugged
everest-ac-demo-manager-1      | 2024-11-15 15:23:13.194040 [INFO] connector_1:Evs  :: EVSE IEC Charger state: Charging->StoppingCharging
everest-ac-demo-manager-1      | 2024-11-15 15:23:13.198930 [INFO] connector_1:Evs  :: EVSE IEC Set PWM Off
everest-ac-demo-manager-1      | 2024-11-15 15:23:13.279034 [INFO] connector_1:Evs  :: EVSE IEC Charger state: StoppingCharging->Finished
everest-ac-demo-manager-1      | 2024-11-15 15:23:13.301996 [INFO] connector_1:Evs  :: EVSE IEC Transaction Finished: EVDisconnected (0.073 kWh)
everest-ac-demo-manager-1      | 2024-11-15 15:23:13.344706 [INFO] connector_1:Evs  :: EVSE IEC Session Finished
everest-ac-demo-manager-1      | 2024-11-15 15:23:13.345089 [INFO] connector_1:Evs  :: SYS  Session logging stopped.
everest-ac-demo-manager-1      | 2024-11-15 15:23:13.435873 [INFO] connector_1:Evs  :: All errors cleared
^CGracefully stopping... (press Ctrl+C again to force)
- ISO 15118-2 DC - able to plug in and pause charging, crashed on "resume"
Logs!
Attaching to everest-ac-demo-manager-1, everest-ac-demo-mqtt-server-1, everest-ac-demo-node-red-1
everest-ac-demo-mqtt-server-1  | 1731684652: mosquitto version 2.0.20 starting
everest-ac-demo-mqtt-server-1  | 1731684652: Config loaded from /mosquitto/config/mosquitto.conf.
everest-ac-demo-mqtt-server-1  | 1731684652: Opening ipv4 listen socket on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684652: Opening websockets listen socket on port 9001.
everest-ac-demo-mqtt-server-1  | 1731684652: mosquitto version 2.0.20 running
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.201875 [INFO] manager          ::   ________      __                _   
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.202500 [INFO] manager          ::  |  ____\ \    / /               | |
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.202571 [INFO] manager          ::  | |__   \ \  / /__ _ __ ___  ___| |_
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.202650 [INFO] manager          ::  |  __|   \ \/ / _ \ '__/ _ \/ __| __|
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.202670 [INFO] manager          ::  | |____   \  /  __/ | |  __/\__ \ |_
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.202720 [INFO] manager          ::  |______|   \/ \___|_|  \___||___/\__|
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.202747 [INFO] manager          :: 
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.202769 [INFO] manager          :: everest-framework 0.17.2 @v0.17.2
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.202785 [INFO] manager          :: everest-core 2024.9.0 @2024.9.0
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.202799 [INFO] manager          :: 
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.202814 [INFO] manager          :: Using MQTT broker mqtt-server:1883
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.719098 [INFO] manager          :: Loading config file at: /ext/source/config/config-sil-dc.yaml
everest-ac-demo-manager-1      | 2024-11-15 15:30:54.780555 [INFO] everest_ctrl     :: Launching controller service on port 8849
everest-ac-demo-node-red-1     | 15 Nov 15:30:55 - [info] 
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | Welcome to Node-RED
everest-ac-demo-node-red-1     | ===================
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | 15 Nov 15:30:55 - [info] Node-RED version: v4.0.5
everest-ac-demo-node-red-1     | 15 Nov 15:30:55 - [info] Node.js  version: v20.18.0
everest-ac-demo-node-red-1     | 15 Nov 15:30:55 - [info] Linux 5.15.49-linuxkit-pr x64 LE
everest-ac-demo-manager-1      | 2024-11-15 15:30:55.943931 [INFO] manager          :: Config loading completed in 1383ms
everest-ac-demo-mqtt-server-1  | 1731684655: New connection from 172.18.0.3:52134 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684655: New client connected from 172.18.0.3:52134 as auto-47966910-A0BC-2BF5-6F86-36F592BCAF03 (p2, c1, k600).
everest-ac-demo-node-red-1     | 15 Nov 15:30:56 - [info] Loading palette nodes
everest-ac-demo-node-red-1     | 15 Nov 15:30:58 - [info] Dashboard version 3.6.5 started at /ui
everest-ac-demo-node-red-1     | 15 Nov 15:30:58 - [info] Settings file  : /data/settings.js
everest-ac-demo-node-red-1     | 15 Nov 15:30:58 - [info] Context store  : 'default' [module=memory]
everest-ac-demo-node-red-1     | 15 Nov 15:30:58 - [info] User directory : /data
everest-ac-demo-node-red-1     | 15 Nov 15:30:58 - [warn] Projects disabled : editorTheme.projects.enabled=false
everest-ac-demo-node-red-1     | 15 Nov 15:30:58 - [info] Flows file     : /config/config-sil-dc-flow.json
everest-ac-demo-node-red-1     | 15 Nov 15:30:59 - [warn] 
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | ---------------------------------------------------------------------
everest-ac-demo-node-red-1     | Your flow credentials file is encrypted using a system-generated key.
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | If the system-generated key is lost for any reason, your credentials
everest-ac-demo-node-red-1     | file will not be recoverable, you will have to delete it and re-enter
everest-ac-demo-node-red-1     | your credentials.
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | You should set your own key using the 'credentialSecret' option in
everest-ac-demo-node-red-1     | your settings file. Node-RED will then re-encrypt your credentials
everest-ac-demo-node-red-1     | file using your chosen key the next time you deploy a change.
everest-ac-demo-node-red-1     | ---------------------------------------------------------------------
everest-ac-demo-node-red-1     | 
everest-ac-demo-node-red-1     | 15 Nov 15:30:59 - [info] Server now running at http://127.0.0.1:1880/
everest-ac-demo-node-red-1     | 15 Nov 15:30:59 - [warn] Encrypted credentials not found
everest-ac-demo-node-red-1     | 15 Nov 15:30:59 - [info] Starting flows
everest-ac-demo-node-red-1     | 15 Nov 15:30:59 - [info] Started flows
everest-ac-demo-mqtt-server-1  | 1731684659: New connection from 172.18.0.4:53244 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684659: New client connected from 172.18.0.4:53244 as nodered_095608effade66dc (p2, c1, k60).
everest-ac-demo-node-red-1     | 15 Nov 15:30:59 - [info] [mqtt-broker:fc8686af.48d178] Connected to broker: mqtt://mqtt-server:1883
everest-ac-demo-mqtt-server-1  | 1731684667: New connection from 172.18.0.3:50790 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684668: New connection from 172.18.0.3:50796 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684668: New client connected from 172.18.0.3:50796 as auto-0D94897F-8F28-1829-2BBD-1BE87F0BF432 (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:31:08.369560 [INFO] energy_manager:  :: Module energy_manager initialized [11396ms]
everest-ac-demo-manager-1      | 2024-11-15 15:31:09.484280 [INFO] api:API          :: Module api initialized [13271ms]
everest-ac-demo-mqtt-server-1  | 1731684669: New client connected from 172.18.0.3:50790 as auto-E55481DA-F323-7985-70D2-B8A9A909AB37 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731684670: New connection from 172.18.0.3:37954 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:31:10.788638 [INFO] auth:Auth        :: Module auth initialized [14383ms]
everest-ac-demo-mqtt-server-1  | 1731684670: New client connected from 172.18.0.3:37954 as auto-B87183BB-E6BA-42E2-C1F0-D19060D4CF37 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731684672: New connection from 172.18.0.3:37962 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684672: New connection from 172.18.0.3:37974 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:31:12.280131 [INFO] error_history:E  :: Resetting database
everest-ac-demo-manager-1      | 2024-11-15 15:31:12.486264 [INFO] error_history:E  :: Module error_history initialized [15195ms]
everest-ac-demo-mqtt-server-1  | 1731684672: New client connected from 172.18.0.3:37962 as auto-5EDE6049-2F3F-971B-C577-4F8B9B9D560B (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:31:13.974750 [INFO] ev_manager:EvMa  :: Module ev_manager initialized [16386ms]
everest-ac-demo-mqtt-server-1  | 1731684673: New client connected from 172.18.0.3:37974 as auto-65DE9553-2ECC-161F-82E7-6C4CB2E8B307 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731684677: New connection from 172.18.0.3:37988 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684678: New connection from 172.18.0.3:37998 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:31:18.477587 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional<std::__cxx11::basic_string<char> >&, const std::optional<long unsigned int>&, const std::optional<long unsigned int>&, const std::optional<std::chrono::duration<long int> >&, const std::optional<std::chrono::duration<long int> >&) :: Could not find configured V2G bundle file at: /ext/dist/etc/everest/certs/ca/v2g/V2G_ROOT_CA.pem, creating default!
everest-ac-demo-manager-1      | 2024-11-15 15:31:18.569499 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional<std::__cxx11::basic_string<char> >&, const std::optional<long unsigned int>&, const std::optional<long unsigned int>&, const std::optional<std::chrono::duration<long int> >&, const std::optional<std::chrono::duration<long int> >&) :: Could not find configured MO bundle file at: /ext/dist/etc/everest/certs/ca/mo/MO_ROOT_CA.pem, creating default!
everest-ac-demo-manager-1      | 2024-11-15 15:31:18.583072 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional<std::__cxx11::basic_string<char> >&, const std::optional<long unsigned int>&, const std::optional<long unsigned int>&, const std::optional<std::chrono::duration<long int> >&, const std::optional<std::chrono::duration<long int> >&) :: Could not find configured CSMS bundle file at: /ext/dist/etc/everest/certs/ca/csms/CSMS_ROOT_CA.pem, creating default!
everest-ac-demo-manager-1      | 2024-11-15 15:31:18.587584 [WARN] evse_security:E evse_security::EvseSecurity::EvseSecurity(const evse_security::FilePaths&, const std::optional<std::__cxx11::basic_string<char> >&, const std::optional<long unsigned int>&, const std::optional<long unsigned int>&, const std::optional<std::chrono::duration<long int> >&, const std::optional<std::chrono::duration<long int> >&) :: Could not find configured MF bundle file at: /ext/dist/etc/everest/certs/ca/mf/MF_ROOT_CA.pem, creating default!
everest-ac-demo-mqtt-server-1  | 1731684678: New connection from 172.18.0.3:38002 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684678: New client connected from 172.18.0.3:37988 as auto-A2872EFB-AA03-A948-201F-86E15C7B3B40 (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:31:18.771248 [INFO] imd:IMDSimulato  :: Module imd initialized [18388ms]
everest-ac-demo-manager-1      | 2024-11-15 15:31:18.685903 [INFO] evse_security:E  :: Module evse_security initialized [19291ms]
everest-ac-demo-manager-1      | 2024-11-15 15:31:18.776103 [INFO] evse_manager:Ev  :: Module evse_manager initialized [19098ms]
everest-ac-demo-mqtt-server-1  | 1731684678: New client connected from 172.18.0.3:37998 as auto-D0A4FF72-8EAC-02F9-53F4-FAE566E5B100 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731684678: New client connected from 172.18.0.3:38002 as auto-47DEA500-6BB8-9B9A-1C3D-7FA5E30505AD (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731684679: New connection from 172.18.0.3:54106 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:31:19.868921 [INFO] grid_connection  :: Module grid_connection_point initialized [19797ms]
everest-ac-demo-mqtt-server-1  | 1731684679: New client connected from 172.18.0.3:54106 as auto-0DA9A1AF-F07A-2282-B2E0-EE41733DDFCD (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731684680: New connection from 172.18.0.3:54110 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:31:20.485479 [INFO] token_validator  :: Module token_validator initialized [13697ms]
everest-ac-demo-mqtt-server-1  | 1731684680: New client connected from 172.18.0.3:54110 as auto-943EED57-4652-DA70-A4F1-A06728A66F0C (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731684680: New connection from 172.18.0.3:54126 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:31:20.868353 [INFO] powersupply_dc:  :: Module powersupply_dc initialized [17187ms]
everest-ac-demo-mqtt-server-1  | 1731684680: New client connected from 172.18.0.3:54126 as auto-886D07F4-7593-77B0-50A6-EEA414095340 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731684681: New connection from 172.18.0.3:54136 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684681: New connection from 172.18.0.3:54138 on port 1883.
everest-ac-demo-manager-1      | 2024-11-15 15:31:21.278878 [INFO] token_provider:  :: Module token_provider initialized [15803ms]
everest-ac-demo-mqtt-server-1  | 1731684681: New client connected from 172.18.0.3:54136 as auto-AE30CA34-CE82-6747-24C7-44C4C5D92BD5 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731684681: New client connected from 172.18.0.3:54138 as auto-DEA10606-C409-C56F-724A-262320D82F20 (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:31:21.368081 [INFO] iso15118_charge  :: Module iso15118_charger initialized [17690ms]
everest-ac-demo-node-red-1     | 15 Nov 15:31:21 - [warn] Unknown context store 'memoryOnly' specified. Using default store.
everest-ac-demo-node-red-1     | 15 Nov 15:31:21 - [error] [function:Process Message & Update Flow State] TypeError: Cannot use 'in' operator to search for 'data' in true
everest-ac-demo-mqtt-server-1  | 1731684681: New connection from 172.18.0.3:54150 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684681: New client connected from 172.18.0.3:54150 as auto-9A2B2A38-F803-E98C-96FB-2B2CB6978E52 (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:31:21.694512 [INFO] slac:SlacSimula  :: Module slac initialized [17314ms]
everest-ac-demo-mqtt-server-1  | 1731684682: New connection from 172.18.0.3:54154 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684682: New client connected from 172.18.0.3:54154 as auto-1926A0F2-EF78-AA84-4AA2-8C4EE5AB6023 (p2, c1, k600).
everest-ac-demo-mqtt-server-1  | 1731684683: New connection from 172.18.0.3:54162 on port 1883.
everest-ac-demo-mqtt-server-1  | 1731684683: New client connected from 172.18.0.3:54162 as auto-1B870ED6-8C94-06FB-AAFA-726C0703C4E6 (p2, c1, k600).
everest-ac-demo-manager-1      | 2024-11-15 15:31:23.202009 [INFO] manager          :: 🚙🚙🚙 All modules are initialized. EVerest up and running [29115ms] 🚙🚙🚙
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:23.207827 [INFO] iso15118_charge  :: TCP server on eth0 is listening on port [fe80::42:acff:fe12:3%25]:61341
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:23.210136 [INFO] iso15118_charge  :: TLS server on eth0 is listening on port [fe80::42:acff:fe12:3%25]:64109
everest-ac-demo-manager-1      | 2024-11-15 15:31:23.215890 [INFO] evse_security:E  :: Requesting leaf certificate info: V2G
everest-ac-demo-manager-1      | 2024-11-15 15:31:23.221964 [WARN] evse_security:E evse_security::GetCertificateInfoResult evse_security::EvseSecurity::get_leaf_certificate_info_internal(evse_security::LeafCertificateType, evse_security::EncodingFormat, bool) :: Could not find any key pair
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:23.270897 [ERRO] iso15118_charge void dlog_func(dloglevel_t, const char*, int, const char*, const char*, ...) :: Failed to read cert_info! Not Accepted
everest-ac-demo-manager-1      | 2024-11-15 15:31:23.272527 [WARN] iso15118_charge void {anonymous}::log_handler(openssl::log_level_t, const std::string&) :: trusted_ca_keys support disabled
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:23.301638 [INFO] iso15118_charge  :: SDP socket setup succeeded
everest-ac-demo-manager-1      | 2024-11-15 15:31:23.487969 [INFO] evse_manager:Ev  :: Ignoring BSP Event, BSP is not enabled yet.
everest-ac-demo-manager-1      | 2024-11-15 15:31:24.001484 [INFO] evse_manager:Ev  :: Cleaning up any other transaction on start up
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:24.111844 [INFO] evse_manager:Ev  :: 🌀🌀🌀 Ready to start charging 🌀🌀🌀
everest-ac-demo-node-red-1     | how can I show the logs
everest-ac-demo-node-red-1     | how can I show the logs
everest-ac-demo-manager-1      | 2024-11-15 15:31:24.322604 [INFO] evse_manager:Ev  :: All errors cleared
everest-ac-demo-node-red-1     | Received totalKw message
...
everest-ac-demo-node-red-1     | how can I show the logs
everest-ac-demo-manager-1      | 2024-11-15 15:31:38.857723 [INFO] evse_manager:Ev  :: SYS  Session logging started.
everest-ac-demo-manager-1      | 2024-11-15 15:31:38.858774 [INFO] evse_manager:Ev  :: EVSE IEC Session Started: EVConnected
everest-ac-demo-manager-1      | 2024-11-15 15:31:38.862708 [INFO] token_provider:  :: Publishing new dummy token: {
everest-ac-demo-manager-1      |     "type": "ISO14443",
everest-ac-demo-manager-1      |     "value": "TOKEN1"
everest-ac-demo-manager-1      | } (RFID)
everest-ac-demo-manager-1      | 2024-11-15 15:31:38.867268 [INFO] auth:Auth        :: Received new token: {
everest-ac-demo-manager-1      |     "authorization_type": "RFID",
everest-ac-demo-manager-1      |     "id_token": {
everest-ac-demo-manager-1      |         "type": "ISO14443",
everest-ac-demo-manager-1      |         "value": "TOKEN1"
everest-ac-demo-manager-1      |     }
everest-ac-demo-manager-1      | }
everest-ac-demo-manager-1      | 2024-11-15 15:31:38.872149 [INFO] token_validator  :: Got validation request for token: TOKEN1
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:39.126421 [INFO] token_validator  :: Returning validation status: Accepted
everest-ac-demo-manager-1      | 2024-11-15 15:31:39.134304 [INFO] auth:Auth        :: Providing authorization to connector#1
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:39.862171 [INFO] evse_manager:Ev  :: EVSE IEC Set PWM On (5.000000074505806%) took 0 ms
everest-ac-demo-manager-1      | 2024-11-15 15:31:39.882166 [INFO] auth:Auth        :: Result for token: TOKEN1: ACCEPTED
everest-ac-demo-manager-1      | 2024-11-15 15:31:40.010871 [INFO] evse_manager:Ev  :: EVSE IEC EIM Authorization received
everest-ac-demo-manager-1      | 2024-11-15 15:31:40.034294 [INFO] evse_manager:Ev  :: EVSE IEC Transaction Started (0 kWh)
everest-ac-demo-manager-1      | 2024-11-15 15:31:40.080942 [INFO] evse_manager:Ev  :: EVSE IEC DC mode. We are in 5percent mode so we can continue without further action.
everest-ac-demo-manager-1      | 2024-11-15 15:31:40.083168 [INFO] evse_manager:Ev  :: EVSE IEC Charger state: Wait for Auth->PrepareCharging
everest-ac-demo-node-red-1     | how can I show the logs
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:41.098360 [INFO] evse_manager:Ev  :: EVSE ISO SLAC MATCHED
everest-ac-demo-manager-1      | 2024-11-15 15:31:41.099863 [INFO] evse_manager:Ev  :: EVSE ISO D-LINK_READY (true)
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.034542 [INFO] iso15118_charge  :: Received packet from [fe80::42:acff:fe12:3]:44298 with security 0x10 and protocol 0x00
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.034689 [INFO] iso15118_charge  :: SDP requested NO-TLS, announcing NO-TLS
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.034943 [INFO] iso15118_charge  :: sendto([fe80::42:acff:fe12:3]:44298) succeeded
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.035029 [INFO] iso15118_charge  :: Received packet from [fe80::42:acff:fe12:3]:44298 with security 0x10 and protocol 0x00
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.035067 [INFO] iso15118_charge  :: SDP requested NO-TLS, announcing NO-TLS
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.035150 [INFO] iso15118_charge  :: sendto([fe80::42:acff:fe12:3]:44298) succeeded
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.045269 [INFO] iso15118_charge  :: Incoming connection on eth0 from [a00:8d52:0:0:fe80::]:36178
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.045581 [INFO] iso15118_charge  :: Started new TCP connection thread
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.394112 [INFO] iso15118_charge  :: Handling SupportedAppProtocolReq
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.399587 [INFO] iso15118_charge  :: Protocol negotiation was successful. Selected protocol is DIN70121
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.412164 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G SupportedAppProtocolReq
everest-ac-demo-manager-1      | 2024-11-15 15:31:48.412962 [INFO] evse_manager:Ev  :: EVSE ISO V2G SupportedAppProtocolRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:50.168502 [INFO] iso15118_charge  :: SessionSetupReq.EVCCID: 02:42:AC:12:00:03
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:50.168641 [INFO] iso15118_charge  :: No session_id found. Generating random session id.
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:50.168671 [INFO] iso15118_charge  :: Created new session with id 0x16710395258914812946
everest-ac-demo-manager-1      | 2024-11-15 15:31:50.172344 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G SessionSetupReq
everest-ac-demo-manager-1      | 2024-11-15 15:31:50.306922 [INFO] evse_manager:Ev  :: EVSE ISO V2G SessionSetupRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:51.813266 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G ServiceDiscoveryReq
everest-ac-demo-manager-1      | 2024-11-15 15:31:51.879389 [INFO] evse_manager:Ev  :: EVSE ISO V2G ServiceDiscoveryRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:52.995071 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G ServicePaymentSelectionReq
everest-ac-demo-manager-1      | 2024-11-15 15:31:53.091817 [INFO] evse_manager:Ev  :: EVSE ISO V2G ServicePaymentSelectionRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:54.320861 [INFO] iso15118_charge  :: Auth-phase started
everest-ac-demo-manager-1      | 2024-11-15 15:31:54.386637 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G ContractAuthenticationReq
everest-ac-demo-manager-1      | 2024-11-15 15:31:54.434448 [INFO] evse_manager:Ev  :: EVSE ISO V2G ContractAuthenticationRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:55.303206 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G ContractAuthenticationReq
everest-ac-demo-manager-1      | 2024-11-15 15:31:55.388264 [INFO] evse_manager:Ev  :: EVSE ISO V2G ContractAuthenticationRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:56.189606 [INFO] iso15118_charge  :: Parameter-phase started
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:56.193654 [INFO] iso15118_charge  :: Selected energy transfer mode: DC_extended
everest-ac-demo-manager-1      | 2024-11-15 15:31:56.197004 [INFO] evse_manager:Ev  :: Received EV maximum limits: {
everest-ac-demo-manager-1      |     "dc_ev_maximum_current_limit": 300.0,
everest-ac-demo-manager-1      |     "dc_ev_maximum_voltage_limit": 900.0
everest-ac-demo-manager-1      | }
everest-ac-demo-manager-1      | 2024-11-15 15:31:56.201325 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G ChargeParameterDiscoveryReq
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:56.373737 [INFO] evse_manager:Ev  :: EVSE ISO V2G ChargeParameterDiscoveryRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.115281 [INFO] evse_manager:Ev  ::                                     CAR IEC Event CarRequestedPower
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.197514 [INFO] iso15118_charge  :: Isolation-phase started
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.252525 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CableCheckReq
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.254225 [INFO] evse_manager:Ev  :: EVSE ISO Start cable check...
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.260529 [INFO] evse_manager:Ev  ::                                     CAR ISO DC HLC Close contactor (in CableCheck)
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.300445 [INFO] evse_manager:Ev  :: EVSE ISO V2G CableCheckRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.402192 [INFO] evse_manager:Ev  :: EVSE IEC Event PowerOn
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.488995 [INFO] evse_manager:Ev  :: EV reports true V as maximum voltage
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.569298 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply: switch ON in export mode
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.572880 [INFO] powersupply_dc:  :: Set mode: Export ChargingPhase: CableCheck
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.578083 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply set: 900V/2A, requested was 900V/2A.
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.672219 [INFO] evse_manager:Ev  :: CableCheck: Using 900 V
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.673222 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply: switch ON called, ChargingPhase: CableCheck
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.767012 [INFO] powersupply_dc:  :: Set mode: Export ChargingPhase: CableCheck
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:57.881029 [INFO] evse_manager:Ev  :: CableCheck: IMD self test started.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:58.380748 [INFO] evse_manager:Ev  :: EVSE ISO Change HLC Limits: 22080W/200A, target_voltage 0, actual_voltage 900, hack_bpt false
everest-ac-demo-manager-1      | 2024-11-15 15:31:58.439450 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CableCheckReq
everest-ac-demo-manager-1      | 2024-11-15 15:31:58.566787 [INFO] evse_manager:Ev  :: EVSE ISO V2G CableCheckRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:31:59.631012 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CableCheckReq
everest-ac-demo-manager-1      | 2024-11-15 15:31:59.777609 [INFO] evse_manager:Ev  :: EVSE ISO V2G CableCheckRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:32:01.474949 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CableCheckReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:01.623195 [INFO] evse_manager:Ev  :: EVSE ISO V2G CableCheckRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:32:02.188499 [INFO] evse_manager:Ev  :: EVSE IEC Isolation monitor self test result: true
everest-ac-demo-manager-1      | 2024-11-15 15:32:02.193264 [INFO] imd:IMDSimulato  :: Started simulated isolation monitoring with 1000 ms interval
everest-ac-demo-manager-1      | 2024-11-15 15:32:02.236574 [INFO] evse_manager:Ev  :: CableCheck: Waiting for 1 isolation measurement sample(s)
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:32:02.590983 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CableCheckReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:02.718377 [INFO] evse_manager:Ev  :: EVSE ISO V2G CableCheckRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:32:03.269741 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-manager-1      | 2024-11-15 15:32:03.322649 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply OFF
everest-ac-demo-manager-1      | 2024-11-15 15:32:03.400260 [INFO] powersupply_dc:  :: Set mode: Off ChargingPhase: Other
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:32:03.690376 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CableCheckReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:03.790045 [INFO] evse_manager:Ev  :: EVSE ISO V2G CableCheckRes
everest-ac-demo-manager-1      | 2024-11-15 15:32:03.799045 [INFO] evse_manager:Ev  :: CableCheck done, output is below 60V
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:32:04.274711 [INFO] evse_manager:Ev  :: EVSE ISO Change HLC Limits: 22080W/200A, target_voltage 0, actual_voltage 0, hack_bpt false
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:32:04.702856 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CableCheckReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:04.799517 [INFO] evse_manager:Ev  :: EVSE ISO V2G CableCheckRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:32:05.692120 [INFO] iso15118_charge  :: Precharge-phase started
everest-ac-demo-manager-1      | 2024-11-15 15:32:05.701738 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply: switch ON in export mode
everest-ac-demo-manager-1      | 2024-11-15 15:32:05.763437 [INFO] powersupply_dc:  :: Set mode: Export ChargingPhase: PreCharge
everest-ac-demo-manager-1      | 2024-11-15 15:32:05.778198 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply set: 400V/1A, requested was 400V/0A.
everest-ac-demo-manager-1      | 2024-11-15 15:32:05.873444 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply: switch ON called, ChargingPhase: PreCharge
everest-ac-demo-manager-1      | 2024-11-15 15:32:05.883589 [INFO] powersupply_dc:  :: Set mode: Export ChargingPhase: PreCharge
everest-ac-demo-manager-1      | 2024-11-15 15:32:05.888343 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G PreChargeReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:05.889476 [INFO] evse_manager:Ev  :: EVSE ISO V2G PreChargeRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:32:06.599051 [INFO] evse_manager:Ev  :: EVSE ISO Change HLC Limits: 22080W/55.2A, target_voltage 400, actual_voltage 400, hack_bpt false
everest-ac-demo-manager-1      | 2024-11-15 15:32:06.647217 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply set: 400V/1A, requested was 400V/0A.
everest-ac-demo-manager-1      | 2024-11-15 15:32:06.718617 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G PreChargeReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:06.816689 [INFO] evse_manager:Ev  :: EVSE ISO V2G PreChargeRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:32:07.769025 [INFO] iso15118_charge  :: Charge-phase started
everest-ac-demo-manager-1      | 2024-11-15 15:32:07.869864 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G PowerDeliveryReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:07.872839 [INFO] evse_manager:Ev  :: EVSE ISO V2G PowerDeliveryRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.666199 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply: switch ON in export mode
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.678979 [INFO] powersupply_dc:  :: Set mode: Export ChargingPhase: Charging
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.684767 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply set: 400V/1A, requested was 400V/0A.
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.786833 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply set: 400V/20A, requested was 400V/20A.
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.875397 [INFO] evse_manager:Ev  :: EVSE IEC Charger state: PrepareCharging->Charging
everest-ac-demo-node-red-1     | how can I show the logs
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.880793 [INFO] evse_manager:Ev  :: Timing statistics (Plugin to CurrentDemand)
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.880880 [INFO] evse_manager:Ev  :: -------------------------------------------
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.880929 [INFO] evse_manager:Ev  :: ConnSetup | HLC_PWM_5%_ON: 1077 ms | D-LINK_READY: 1236 ms | Auth EIM Done: 13283 ms | Total: 18471 ms
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.880954 [INFO] evse_manager:Ev  :: CableCheck | <60V: 0 ms | Relay On: 228 ms | EVInfo: 80 ms | VRampUp: 203 ms | Self test: 4417 ms | Measure: 1079 ms | VRampDown: 529 ms | Total: 6606 ms
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.880970 [INFO] evse_manager:Ev  :: PrepareCharging | Charging started: 5013 ms | Total: 5013 ms
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.880985 [INFO] evse_manager:Ev  :: Total duration all phases: 30092 ms
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.973476 [INFO] evse_manager:Ev  :: Received EV maximum limits: {
everest-ac-demo-manager-1      |     "dc_ev_maximum_current_limit": 300.0,
everest-ac-demo-manager-1      |     "dc_ev_maximum_power_limit": 150000.0,
everest-ac-demo-manager-1      |     "dc_ev_maximum_voltage_limit": 900.0
everest-ac-demo-manager-1      | }
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.974842 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:08.977038 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:09.370398 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:09.567180 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:09.648968 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:10.125753 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:10.222409 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-manager-1      | 2024-11-15 15:32:10.470143 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:10.768969 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:10.866408 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:11.401676 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:11.537247 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:11.634120 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:12.345184 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:12.431660 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:12.441136 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:13.251241 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:13.351430 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-manager-1      | 2024-11-15 15:32:13.493712 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:14.000315 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:14.135871 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-manager-1      | 2024-11-15 15:32:14.478283 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:14.539596 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:14.638153 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:15.065914 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:15.170197 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-manager-1      | 2024-11-15 15:32:15.472505 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:15.744130 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:15.840712 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:16.338014 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:16.504285 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-manager-1      | 2024-11-15 15:32:16.513054 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:17.047763 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:17.143724 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-manager-1      | 2024-11-15 15:32:17.468073 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:17.821867 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:17.920994 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:18.420430 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-manager-1      | 2024-11-15 15:32:18.448820 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:18.595946 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:19.335835 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:19.421706 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-manager-1      | 2024-11-15 15:32:19.477363 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:19.967611 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:20.069150 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:20.471486 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:20.864216 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:20.962145 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:21.467067 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-manager-1      | 2024-11-15 15:32:21.540786 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:21.714861 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:22.131523 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:22.368290 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-manager-1      | 2024-11-15 15:32:22.468589 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:22.744600 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:22.843076 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:23.269377 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:23.368497 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-manager-1      | 2024-11-15 15:32:23.568026 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:23.854409 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:23.954429 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:24.421953 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:24.501708 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-manager-1      | 2024-11-15 15:32:24.601581 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:25.141573 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:25.273399 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-manager-1      | 2024-11-15 15:32:25.501600 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:25.676423 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:25.766542 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:32:26.287428 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:32:26.288486 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-manager-1      | 2024-11-15 15:32:26.502885 [INFO] evse_manager:Ev  :: EVSE IEC Isolation measurement Ok R_F 900000.
everest-ac-demo-manager-1      | 2024-11-15 15:32:26.682545 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
...
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-node-red-1     | stopping kw updates because this is annoying
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.261832 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.362473 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.476493 [INFO] evse_manager:Ev  :: EVSE IEC Event PowerOff
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.530460 [INFO] evse_manager:Ev  ::                                     CAR IEC Event CarRequestedStopPower
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.578894 [INFO] evse_manager:Ev  :: EVSE IEC CP state transition C->B at this stage violates ISO15118-2
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.579777 [INFO] evse_manager:Ev  :: EVSE IEC Charger state: Charging->Car Paused
everest-ac-demo-node-red-1     | how can I show the logs
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.639249 [INFO] evse_manager:Ev  :: EVSE IEC DC power supply OFF
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.652512 [INFO] powersupply_dc:  :: Set mode: Off ChargingPhase: Other
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.658474 [INFO] imd:IMDSimulato  :: Stopped simulated isolation monitoring
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.700664 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:33:14.817726 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:33:15.403208 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G PowerDeliveryReq
everest-ac-demo-manager-1      | 2024-11-15 15:33:15.487903 [INFO] evse_manager:Ev  :: EVSE ISO V2G PowerDeliveryRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 
everest-ac-demo-manager-1      | 2024-11-15 15:33:15.876618 [ERRO] iso15118_charge void dlog_func(dloglevel_t, const char*, int, const char*, const char*, ...) :: Failed response code detected for message "Current Demand", error: Sequence Error
everest-ac-demo-manager-1      | 2024-11-15 15:33:15.880196 [INFO] evse_manager:Ev  ::                                     CAR ISO V2G CurrentDemandReq
everest-ac-demo-manager-1      | 2024-11-15 15:33:15.977226 [INFO] evse_manager:Ev  :: EVSE ISO V2G CurrentDemandRes
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.342116 [INFO] evse_manager:Ev  :: EVSE ISO Change HLC Limits: 22080W/55.2A, target_voltage 400, actual_voltage 0, hack_bpt false
everest-ac-demo-node-red-1     | Received totalKw message
everest-ac-demo-manager-1      | terminate called after throwing an instance of 'std::invalid_argument'
everest-ac-demo-manager-1      |   what():  Command not found: iso_start_bcb_toogle
everest-ac-demo-mqtt-server-1  | 1731684796: Client auto-65DE9553-2ECC-161F-82E7-6C4CB2E8B307 closed its connection.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.858970 [CRIT] manager         int boot(const boost::program_options::variables_map&) :: Module ev_manager (pid: 32) exited with status: 6. Terminating all modules.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.882978 [INFO] manager          :: SIGTERM of child: api (pid: 28) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.883340 [INFO] manager          :: SIGTERM of child: auth (pid: 29) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.883470 [INFO] manager          :: SIGTERM of child: energy_manager (pid: 30) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.884622 [INFO] manager          :: SIGTERM of child: error_history (pid: 31) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.886665 [INFO] manager          :: SIGTERM of child: evse_manager (pid: 33) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.887024 [INFO] manager          :: SIGTERM of child: evse_security (pid: 34) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.887283 [INFO] manager          :: SIGTERM of child: grid_connection_point (pid: 35) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.887619 [INFO] manager          :: SIGTERM of child: imd (pid: 36) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.887819 [INFO] manager          :: SIGTERM of child: iso15118_car (pid: 37) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.890307 [INFO] manager          :: SIGTERM of child: iso15118_charger (pid: 38) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.890662 [INFO] manager          :: SIGTERM of child: powersupply_dc (pid: 39) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.890844 [INFO] manager          :: SIGTERM of child: slac (pid: 40) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.891104 [INFO] manager          :: SIGTERM of child: token_provider (pid: 41) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.891259 [INFO] manager          :: SIGTERM of child: token_validator (pid: 42) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.891349 [INFO] manager          :: SIGTERM of child: yeti_driver (pid: 43) succeeded.
everest-ac-demo-manager-1      | 2024-11-15 15:33:16.891401 [CRIT] manager         int boot(const boost::program_options::variables_map&) :: Exiting manager.
everest-ac-demo-mqtt-server-1  | 1731684796: Client auto-E55481DA-F323-7985-70D2-B8A9A909AB37 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-886D07F4-7593-77B0-50A6-EEA414095340 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-AE30CA34-CE82-6747-24C7-44C4C5D92BD5 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-A2872EFB-AA03-A948-201F-86E15C7B3B40 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-943EED57-4652-DA70-A4F1-A06728A66F0C closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-B87183BB-E6BA-42E2-C1F0-D19060D4CF37 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-DEA10606-C409-C56F-724A-262320D82F20 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-0D94897F-8F28-1829-2BBD-1BE87F0BF432 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-5EDE6049-2F3F-971B-C577-4F8B9B9D560B closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-9A2B2A38-F803-E98C-96FB-2B2CB6978E52 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-47DEA500-6BB8-9B9A-1C3D-7FA5E30505AD closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-0DA9A1AF-F07A-2282-B2E0-EE41733DDFCD closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-D0A4FF72-8EAC-02F9-53F4-FAE566E5B100 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-1B870ED6-8C94-06FB-AAFA-726C0703C4E6 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-1926A0F2-EF78-AA84-4AA2-8C4EE5AB6023 closed its connection.
everest-ac-demo-mqtt-server-1  | 1731684797: Client auto-47966910-A0BC-2BF5-6F86-36F592BCAF03 closed its connection.
everest-ac-demo-manager-1 exited with code 1

  • ISO 15118 + OCPP 201 - stalled during startup, trying again ...
  • Update: with option 1 unable to start charging, when I click "plug in" I just get
    2024-11-15 16:04:36.916211 [INFO] car_simulator_1 :: Unplug detected, restarting simulation.

@the-bay-kay
Copy link
Author

ISO 15118-2 DC - able to plug in and pause charging, crashed on "resume"

This looks like an old version of the simulator command iso_start_bcb_toggle is being used. Assuming these latest demos are using the latest simulator implementation (as opposed to JsEvManager), the command is registered here and processed here. If you compare the latter with the third set of commands found in the Node-RED flow, we will likely need to update the way we are formatting this command's input!

Example of looking at Node-RED commands

image

@the-bay-kay
Copy link
Author

the-bay-kay commented Nov 15, 2024

@shankari I just ran the rest of the tests, everything worked as intended except one edge case!

As for the edge case -- I once again got the default "empty DT" wrong in Node-RED it seems. If unmodified at launch, DT defaults to 0 ("empty"). But, if we enter a time, and then delete it, we default to 86400 -- not empty. Woops! With that last change to the node-red flow, we should be good to go. Will LYK when that change is pushed! It shouldn't affect any of the existing patches, just the flow.

Video of (DT + EAmount) + OCPP tests
EADTDemo.1.mp4

@shankari
Copy link
Collaborator

@the-bay-kay please let me know when that change is pushed so I can clean up your changes so far and get them into main

@the-bay-kay
Copy link
Author

the-bay-kay commented Nov 15, 2024

@shankari Changes are pushed! You can find the list of patches starting here -- some like the device_storage patch will not be relevant, as we discussed with the sed changes you've made! The flow used is config-sil-iso15118-ac-flow.json

@shankari shankari added this to the CharIN demo prep milestone Nov 15, 2024
@shankari
Copy link
Collaborator

@the-bay-kay I would like to also test something like section 2.4 of the OCPP spec; the external smart charging signal. Could you try to send two separate charging profiles, one from the CSMS and the other from the external controller, and see if that works?

@the-bay-kay
Copy link
Author

...Could you try to send two separate charging profiles, one from the CSMS and the other from the external controller...

Sure thing! Looking at OCPP 2.0.1 Part 2, Section K-2.4, I see a few different methods of external smart charging control (IEC 61850, OpenADR, etc.). I may be blanking -- is there a preferred / documented method I should test? Currently looking for some examples of how the community has tested in the past!

@shankari
Copy link
Collaborator

  1. Some local input, for example a Home Energy Management System (HEMS) or DSO, can influence the charging, for example via an External Smart Charging Control signal. See K11 - Set / Update External Charging Limit.

@the-bay-kay
Copy link
Author

the-bay-kay commented Nov 15, 2024

See K11 - Set / Update External Charging Limit.

Right! At a high level, I understand the difference between CSMS profiles and profiles from local inputs (HEMS, DSO, etc.). How I can emulate one of these schedules within EVerest. E.g., we use the script to send ChargingProfiles json's to Maeve -- what is the equivalent method for sending a DSO signal to EVerest? (As I understand Figure 97-98 and 110, EVerest should process an external signal before sending a NotifyChargingLimitReq to the CSMS). I saw this open issue for the addition of K-11, and it looks like there was a draft PR to include Section 5.2 here that was not merged. Still looking for examples of how to test this, will update if I find a methodology!

@shankari
Copy link
Collaborator

Ah if EVerest/libocpp#828 is not merged, then there will not be support for this. The PR looks pretty complete, though, and it would be a great example of composite schedules, which was the main achievement of the AFS work. Looking at the PR, where does it expect the external limit charging profile to come from? Is it from the websocket connection to the CSMS? What happens if we just send it over that link?

@shankari
Copy link
Collaborator

@the-bay-kay this will need some digging, I would suggest that you go back to the charging dial for now

@shankari
Copy link
Collaborator

@the-bay-kay I tested after incorporating all patches (#88), and ran into an issue at the end of the charge session

SAScheduleTuples are: [SAScheduleTuple(sa_schedule_tuple_id=1, p_max_schedule=PMaxSchedule(schedule_entries=[PMaxScheduleEntry(p_max=PVPMax(value=22080, multiplier=0, unit=<UnitSymbol.WATT: 'W'>), time_interval=RelativeTimeInterval(start=0, duration=3200))]), sales_tariff=None)]
Sim speed is now  25
1731783497.504498 1731783375.576895 25
Charging Session Time Elapsed...  3048.1907069683075
In ProcessSchedules
Processing SASchedules! $[]
Processing SASchedules! $3048.1907069683075
Done processing schedules...
Abt to generate Curve... 3048.1907069683075
About to generate a new schedule with a EVCC_Profile [ProfileEntryDetails(start=0, max_power=PVPMax(value=22080, multiplier=0, unit=<UnitSymbol.WATT: 'W'>), max_phases_in_use=None), ProfileEntryDetails(start=3200, max_power=PVPMax(value=0, multiplier=0, unit=<UnitSymbol.WATT: 'W'>), max_phases_in_use=None)]
Done
Returning a curve schedule of: []
New schedule of length 0 created

Not sure if you actually tested all the way to the end...

@Abby-Wheelis
Copy link
Contributor

Do we expect demo-iso15118-2-ocpp-201.sh | bash -s -- -1 to take a really really long time to pull? Maybe my wifi at home is slower than I thought but this has been going for a long time now, definitely >20 minutes.

@shankari
Copy link
Collaborator

the manager is fairly big, but we should not need to take a long time.
where is it getting stuck?

@Abby-Wheelis
Copy link
Contributor

I have been off the the VPN for a while now. I could stop it and retry off the VPN, but I worry that if my wifi is just that slow it would take this long again.

@shankari
Copy link
Collaborator

It may be that it got stuck when you got off the VPN because of the change to networking.

@Abby-Wheelis
Copy link
Contributor

Abby-Wheelis commented Nov 16, 2024

Trying again totally off VPN, but doesn't seem to be going much faster. Also trying on my personal laptop (2020 Macbook Air with M1 chip), which seems to be going at least twice as fast.

Update: work laptop took >20 mins to load Maeve services, just started on the manager/nodered/mqtt

@Abby-Wheelis
Copy link
Contributor

Abby-Wheelis commented Nov 16, 2024

Also trying on my personal laptop (2020 Macbook Air with M1 chip), which seems to be going at least twice as fast.

In <10 minutes all containers were running and the manger was trying to start up, but seems to be stalling right after loading the config file. Oh, just took a long time initialize API module? Ok yeah starting to see the rest of the modules intialized. Ready to charge with an error but no crash:

2024-11-16 21:02:31.068379 [INFO] evse_security:E  :: Requesting leaf certificate info: V2G
2024-11-16 21:02:31.069693 [WARN] evse_security:E evse_security::GetCertificateInfoResult evse_security::EvseSecurity::get_leaf_certificate_info_internal(evse_security::LeafCertificateType, evse_security::EncodingFormat, bool) :: Could not find any key pair
2024-11-16 21:02:31.070309 [ERRO] evse_security:E evse_security::OCSPRequestDataList evse_security::EvseSecurity::get_v2g_ocsp_request_data() :: Could not get key pair, for v2g ocsp request!
2024-11-16 21:02:31.108408 [INFO] ocpp:OCPP201     :: libocpp: Updating OCSP cache on 0 certificates
2024-11-16 21:02:31.109074 [INFO] ocpp:OCPP201     :: libocpp: Done updating OCSP cache
2024-11-16 21:03:31.052929 [WARN] ocpp:OCPP201    void ocpp::v201::ChargePoint::scheduled_check_v2g_certificate_expiration() :: PnC is enabled but V2G certificate installation is not, so no certificate expiration check is performed.

Selected ISO15118-2. Car plugin, swipe RFID, entered "Prepare Charging", then saw "Car Paused", seemed stuck. So unplugged. Tried again with same result, relevant logs below:

2024-11-16 21:09:04.464761 [INFO] car_simulator_1  :: Unplug detected, restarting simulation.
2024-11-16 21:09:05.376935 [INFO] car_simulator_1  :: {
  cmd: 'iso_wait_slac_matched',
  args: [],
  exec: [Function (anonymous)]
}
2024-11-16 21:09:06.039460 [INFO] evse_manager_1:  :: SYS  Session logging started.
2024-11-16 21:09:06.045196 [INFO] evse_manager_1:  :: EVSE IEC Session Started: EVConnected
2024-11-16 21:09:08.103144 [INFO] evse_manager_1:  :: EVSE ISO SLAC MATCHED
2024-11-16 21:09:08.107551 [INFO] evse_manager_1:  :: EVSE ISO D-LINK_READY (true)
2024-11-16 21:09:08.268773 [INFO] car_simulator_1  :: {
  cmd: 'iso_set_departure_time',
  args: [ 0, 60 ],
  exec: [Function (anonymous)]
}
2024-11-16 21:09:08.270247 [INFO] token_provider_  :: Publishing new dummy token: {"id_token":{"value":"DEADBEEF","type":"ISO14443"},"authorization_type":"RFID","prevalidated":false,"connectors":[1]}
2024-11-16 21:09:08.283382 [INFO] car_simulator_1  :: {
  cmd: 'iso_start_v2g_session',
  args: [ 'externalpayment', 'ac' ],
  exec: [Function (anonymous)]
}
2024-11-16 21:09:08.335874 [INFO] auth:Auth        :: Received new token: {
    "authorization_type": "RFID",
    "connectors": [
        1
    ],
    "id_token": {
        "type": "ISO14443",
        "value": "DEADBEEF"
    },
    "prevalidated": false
}
2024-11-16 21:09:08.446867 [INFO] iso15118_car     :: _handler_start_charging() args: {'DepartureTime': None, 'EAmount': 60, 'EnergyTransferMode': 'AC_three_phase_core', 'PaymentOption': 'ExternalPayment'}
2024-11-16 21:09:08.449089 [INFO] ocpp:OCPP201     :: Found valid entry in AuthCache
2024-11-16 21:09:08.534660 [INFO] car_simulator_1  :: { cmd: 'iso_wait_pwr_ready', args: [], exec: [Function (anonymous)] }
2024-11-16 21:09:08.535129 [INFO] auth:Auth        :: Providing authorization to connector#1
2024-11-16 21:09:08.633816 [INFO] evse_manager_1:  :: EVSE IEC EIM Authorization received
2024-11-16 21:09:08.736992 [INFO] auth:Auth        :: Result for token: DEADBEEF: ACCEPTED
2024-11-16 21:09:08.952993 [INFO] evse_manager_1:  :: EVSE IEC Transaction Started (0 kWh)
2024-11-16 21:09:09.147849 [INFO] evse_manager_1:  :: EVSE IEC AC mode, HLC enabled(X1), matching already started. We are in X1 so we can go directly to nominal PWM.
2024-11-16 21:09:09.151804 [INFO] evse_manager_1:  :: EVSE IEC Charger state: Wait for Auth->PrepareCharging
2024-11-16 21:09:09.336845 [INFO] evse_manager_1:  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
2024-11-16 21:09:39.334192 [INFO] evse_manager_1:  :: EVSE IEC EV did not transition to state C, trying one legacy wakeup according to IEC61851-1 A.5.3
2024-11-16 21:09:39.340144 [INFO] evse_manager_1:  :: EVSE IEC Charger state: PrepareCharging->T_step_EF
2024-11-16 21:09:39.438843 [INFO] evse_manager_1:  :: EVSE IEC Enter T_step_EF
2024-11-16 21:09:39.444219 [INFO] evse_manager_1:  :: EVSE IEC Set PWM F
2024-11-16 21:09:40.548911 [INFO] evse_manager_1:  :: EVSE ISO SLAC UNMATCHED
2024-11-16 21:09:40.645090 [INFO] evse_manager_1:  :: EVSE ISO D-LINK_READY (false)
2024-11-16 21:09:40.841448 [INFO] evse_manager_1:  ::                                     CAR IEC Event BCDtoEF
2024-11-16 21:09:43.348624 [INFO] evse_manager_1:  :: EVSE IEC Pause in X1 for EV READY regulations
2024-11-16 21:09:43.350993 [INFO] evse_manager_1:  :: EVSE IEC Set PWM Off
2024-11-16 21:09:44.141926 [INFO] evse_manager_1:  :: EVSE IEC Exit T_step_EF
2024-11-16 21:09:44.150136 [INFO] evse_manager_1:  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
2024-11-16 21:09:44.345371 [INFO] evse_manager_1:  ::                                     CAR IEC Event CarRequestedStopPower
2024-11-16 21:09:44.739096 [INFO] evse_manager_1:  :: EVSE IEC Charger state: T_step_EF->PrepareCharging
2024-11-16 21:09:45.442026 [INFO] evse_manager_1:  :: EVSE ISO SLAC MATCHING
2024-11-16 21:09:45.533411 [INFO] evse_manager_1:  ::                                     CAR IEC Event EFtoBCD
2024-11-16 21:09:54.845426 [INFO] evse_manager_1:  :: EVSE IEC Charger state: PrepareCharging->Car Paused
2024-11-16 21:09:55.233254 [WARN] ocpp:OCPP201    types::ocpp::OcppTransactionEvent module::conversions::to_everest_ocpp_transaction_event(const ocpp::v201::TransactionEventRequest&) :: Attempting to convert TransactionEventRequest that does not contain information about the EVSE. evse_id and connector default to 1.
2024-11-16 21:09:55.732979 [WARN] ocpp:OCPP201    types::ocpp::OcppTransactionEvent module::conversions::to_everest_ocpp_transaction_event(const ocpp::v201::TransactionEventRequest&) :: Attempting to convert TransactionEventRequest that does not contain information about the EVSE. evse_id and connector default to 1.
^Ccontext canceled

Going to try giving docker more than the default resource on this laptop to see if it might be a timeout issue.

@shankari
Copy link
Collaborator

shankari commented Nov 16, 2024

I wonder if this is an issue with the M1 chip. Normally, I would have said this is a problem with the payment module. But that part seems to be working

2024-11-16 21:09:08.283382 [INFO] car_simulator_1  :: {
  cmd: 'iso_start_v2g_session',
  args: [ 'externalpayment', 'ac' ],
  exec: [Function (anonymous)]
}

2024-11-16 21:09:08.446867 [INFO] iso15118_car     :: _handler_start_charging() args: {'DepartureTime': None, 'EAmount': 60, 'EnergyTransferMode': 'AC_three_phase_core', 'PaymentOption': 'ExternalPayment'}
Let me see what is expected there for a working session.
2024-11-16 21:22:06.217557 [INFO] ocpp:OCPP201     :: libocpp: Updating OCSP cache on 0 certificates
2024-11-16 21:22:06.217656 [INFO] ocpp:OCPP201     :: libocpp: Done updating OCSP cache
2024-11-16 21:22:10.603024 [INFO] car_simulator_1  :: { cmd: 'sleep', args: [ 1 ], exec: [Function (anonymous)] }
2024-11-16 21:22:10.791056 [INFO] car_simulator_1  :: Unplug detected, restarting simulation.
2024-11-16 21:22:11.709204 [INFO] car_simulator_1  :: {
  cmd: 'iso_wait_slac_matched',
  args: [],
  exec: [Function (anonymous)]
}
2024-11-16 21:22:12.391904 [INFO] evse_manager_1:  :: SYS  Session logging started.
2024-11-16 21:22:12.392314 [INFO] evse_manager_1:  :: EVSE IEC Session Started: EVConnected
2024-11-16 21:22:14.511560 [INFO] evse_manager_1:  :: EVSE ISO SLAC MATCHED
2024-11-16 21:22:14.568575 [INFO] evse_manager_1:  :: EVSE ISO D-LINK_READY (true)
2024-11-16 21:22:14.722463 [INFO] car_simulator_1  :: {
  cmd: 'iso_set_departure_time',
  args: [ 0, 60 ],
  exec: [Function (anonymous)]
}
2024-11-16 21:22:14.723214 [INFO] car_simulator_1  :: {
  cmd: 'iso_start_v2g_session',
  args: [ 'externalpayment', 'ac' ],
  exec: [Function (anonymous)]
}
2024-11-16 21:22:14.725996 [INFO] iso15118_car     :: _handler_start_charging() args: {'DepartureTime': None, 'EAmount': 60, 'EnergyTransferMode': 'AC_three_phase_core', 'PaymentOption': 'ExternalPayment'}
2024-11-16 21:22:14.766957 [INFO] car_simulator_1  :: { cmd: 'iso_wait_pwr_ready', args: [], exec: [Function (anonymous)] }
2024-11-16 21:22:16.698618 [INFO] token_provider_  :: Publishing new dummy token: {"id_token":{"value":"DEADBEEF","type":"ISO14443"},"authorization_type":"RFID","prevalidated":false,"connectors":[1]}
2024-11-16 21:22:16.699820 [INFO] auth:Auth        :: Received new token: {
    "authorization_type": "RFID",
    "connectors": [
        1
    ],
    "id_token": {
        "type": "ISO14443",
        "value": "DEADBEEF"
    },
    "prevalidated": false
}
2024-11-16 21:22:16.769090 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: EXI Codec version: 1.55
2024-11-16 21:22:16.769301 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Starting 15118 version: 0.28.3
2024-11-16 21:22:16.769439 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Communication session handler started
2024-11-16 21:22:16.769886 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Remaining SDP requests: 50
2024-11-16 21:22:16.800554 [INFO] ocpp:OCPP201     :: Found valid entry in AuthCache
2024-11-16 21:22:16.840203 [INFO] auth:Auth        :: Providing authorization to connector#1
2024-11-16 21:22:16.871356 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Sending SDPRequest: [Security: NO_TLS, Protocol: TCP]

2024-11-16 21:22:16.871747 [INFO] iso15118_charge  :: Received packet from [fe80::42:acff:fe15:3]:44213 with security 0x10 and protocol 0x00

2024-11-16 21:22:16.871854 [INFO] iso15118_charge  :: SDP requested NO-TLS, announcing NO-TLS

2024-11-16 21:22:16.872149 [INFO] iso15118_charge  :: sendto([fe80::42:acff:fe15:3]:44213) succeeded

2024-11-16 21:22:16.872236 [INFO] iso15118_charge  :: Received packet from [fe80::42:acff:fe15:3]:44213 with security 0x10 and protocol 0x00

2024-11-16 21:22:16.872262 [INFO] iso15118_charge  :: SDP requested NO-TLS, announcing NO-TLS

2024-11-16 21:22:16.872319 [INFO] iso15118_charge  :: sendto([fe80::42:acff:fe15:3]:44213) succeeded
2024-11-16 21:22:16.872319 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Received datagram from UDP server at address ('fe80::42:acff:fe15:3', 15118, 0, 33)
2024-11-16 21:22:16.872581 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Received datagram from UDP server at address ('fe80::42:acff:fe15:3', 15118, 0, 33)
2024-11-16 21:22:16.873149 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: SDPResponse received: [ IP address: fe80::42:acff:fe15:3, Port: 61341 , Security: NO_TLS , Transport: TCP ]
2024-11-16 21:22:16.873295 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Starting TCP client, trying to connect to fe80::42:acff:fe15:3 at port 61341 ...

2024-11-16 21:22:16.874842 [INFO] iso15118_charge  :: Incoming connection on eth0 from [a00:d472:0:0:fe80::]:54386

2024-11-16 21:22:16.875136 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: TCP client connected
2024-11-16 21:22:16.875194 [INFO] iso15118_charge  :: Started new TCP connection thread
2024-11-16 21:22:16.880232 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Starting a new communication session
2024-11-16 21:22:16.880476 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Entered state SupportedAppProtocol
2024-11-16 21:22:16.880910 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Message to encode (ns=Namespace.SAP): {"supportedAppProtocolReq": {"AppProtocol": [{"ProtocolNamespace": "urn:iso:15118:2:2013:MsgDef", "VersionNumberMajor": 2, "VersionNumberMinor": 0, "SchemaID": 1, "Priority": 1}]}}
2024-11-16 21:22:16.884806 [INFO] auth:Auth        :: Result for token: DEADBEEF: ACCEPTED
2024-11-16 21:22:16.884977 [INFO] evse_manager_1:  :: EVSE IEC EIM Authorization received

2024-11-16 21:22:16.916908 [INFO] iso15118_charge  :: Handling SupportedAppProtocolReq2024-11-16 21:22:16.916930 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Sent supportedAppProtocolReq


2024-11-16 21:22:16.917628 [INFO] iso15118_charge  :: Protocol negotiation was successful. Selected protocol is ISO15118
2024-11-16 21:22:16.928329 [INFO] evse_manager_1:  ::                                     CAR ISO V2G SupportedAppProtocolReq
2024-11-16 21:22:16.928547 [INFO] evse_manager_1:  :: EVSE IEC Transaction Started (0 kWh)
2024-11-16 21:22:16.929309 [INFO] evse_manager_1:  :: EVSE IEC AC mode, HLC enabled(X1), matching already started. We are in X1 so we can go directly to nominal PWM.
2024-11-16 21:22:16.929689 [INFO] evse_manager_1:  :: EVSE IEC Charger state: Wait for Auth->PrepareCharging
2024-11-16 21:22:16.957578 [INFO] evse_manager_1:  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
2024-11-16 21:22:17.000075 [INFO] evse_manager_1:  :: EVSE ISO V2G SupportedAppProtocolRes
2024-11-16 21:22:17.078994 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Decoded message (ns=Namespace.SAP): {"supportedAppProtocolRes":{"ResponseCode":"OK_SuccessfulNegotiation","SchemaID":1}}
2024-11-16 21:22:17.079225 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: supportedAppProtocolRes received
2024-11-16 21:22:17.079728 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Chosen protocol: ISO_15118_2
2024-11-16 21:22:17.080185 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Message to encode (ns=Namespace.ISO_V2_MSG_DEF): {"V2G_Message": {"Header": {"SessionID": "00"}, "Body": {"SessionSetupReq": {"EVCCID": "0242AC150003"}}}}
2024-11-16 21:22:17.891245 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Sent SessionSetupReq

2024-11-16 21:22:17.891331 [INFO] iso15118_charge  :: SessionSetupReq.EVCCID: 02:42:AC:15:00:03

2024-11-16 21:22:17.891405 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Entered state SessionSetup
2024-11-16 21:22:17.891430 [INFO] iso15118_charge  :: No session_id found or not equal to the id from the preceding v2g session. Generating random session id.

2024-11-16 21:22:17.891465 [INFO] iso15118_charge  :: Created new session with id 0x16555009991365810000
2024-11-16 21:22:17.934140 [INFO] evse_manager_1:  ::                                     CAR ISO V2G SessionSetupReq
2024-11-16 21:22:17.991353 [INFO] evse_manager_1:  :: EVSE ISO V2G SessionSetupRes

EDIT: Added logs @Abby-Wheelis
EDIT: We are seeing different logs, are you sure you cleared out the old containers and ran using the demo script @Abby-Wheelis ?

@Abby-Wheelis
Copy link
Contributor

Abby-Wheelis commented Nov 16, 2024

are you sure you cleared out the old containers and ran using the demo script

Yes, this is a fresh install of Docker on my personal computer so curl https://raw.githubusercontent.com/everest/everest-demo/main/demo-iso15118-2-ocpp-201.sh | bash -s -- -1 was the first time anything was run.

I actually got an error this time,~ I haven't gotten to exactly compare the logs yet but will do that next~:

2024-11-16 21:23:13.505095 [INFO] evse_manager_1:  :: SYS  Session logging started.
2024-11-16 21:23:13.510105 [INFO] evse_manager_1:  :: EVSE IEC Session Started: EVConnected
2024-11-16 21:23:14.514986 [INFO] token_provider_  :: Publishing new dummy token: {"id_token":{"value":"DEADBEEF","type":"ISO14443"},"authorization_type":"RFID","prevalidated":false,"connectors":[1]}
2024-11-16 21:23:14.616644 [INFO] auth:Auth        :: Received new token: {
    "authorization_type": "RFID",
    "connectors": [
        1
    ],
    "id_token": {
        "type": "ISO14443",
        "value": "DEADBEEF"
    },
    "prevalidated": false
}
2024-11-16 21:23:14.737883 [INFO] ocpp:OCPP201     :: Found valid entry in AuthCache
2024-11-16 21:23:14.760515 [INFO] auth:Auth        :: Providing authorization to connector#1
2024-11-16 21:23:14.813516 [INFO] evse_manager_1:  :: EVSE IEC EIM Authorization received
2024-11-16 21:23:14.813751 [INFO] auth:Auth        :: Result for token: DEADBEEF: ACCEPTED
2024-11-16 21:23:14.864107 [INFO] evse_manager_1:  :: EVSE IEC Transaction Started (0 kWh)
2024-11-16 21:23:14.869938 [INFO] evse_manager_1:  :: EVSE IEC AC mode, HLC enabled(X1), matching already started. We are in X1 so we can go directly to nominal PWM.
2024-11-16 21:23:14.871063 [INFO] evse_manager_1:  :: EVSE IEC Charger state: Wait for Auth->PrepareCharging
2024-11-16 21:23:14.875989 [INFO] evse_manager_1:  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
2024-11-16 21:23:15.760840 [INFO] evse_manager_1:  :: EVSE ISO SLAC MATCHED
2024-11-16 21:23:15.801897 [INFO] evse_manager_1:  :: EVSE ISO D-LINK_READY (true)
2024-11-16 21:23:15.843625 [INFO] car_simulator_1  :: {
  cmd: 'iso_set_departure_time',
  args: [ 0, 60 ],
  exec: [Function (anonymous)]
}
2024-11-16 21:23:15.848118 [INFO] car_simulator_1  :: {
  cmd: 'iso_start_v2g_session',
  args: [ 'externalpayment', 'ac' ],
  exec: [Function (anonymous)]
}
2024-11-16 21:23:15.864196 [INFO] iso15118_car     :: _handler_start_charging() args: {'DepartureTime': None, 'EAmount': 60, 'EnergyTransferMode': 'AC_three_phase_core', 'PaymentOption': 'ExternalPayment'}
2024-11-16 21:23:15.899898 [INFO] car_simulator_1  :: { cmd: 'iso_wait_pwr_ready', args: [], exec: [Function (anonymous)] }
2024-11-16 21:23:44.910364 [INFO] evse_manager_1:  :: EVSE IEC EV did not transition to state C, trying one legacy wakeup according to IEC61851-1 A.5.3
2024-11-16 21:23:45.001325 [INFO] evse_manager_1:  :: EVSE IEC Charger state: PrepareCharging->T_step_EF
2024-11-16 21:23:45.101228 [INFO] evse_manager_1:  :: EVSE IEC Enter T_step_EF
2024-11-16 21:23:45.110071 [INFO] evse_manager_1:  :: EVSE IEC Set PWM F
2024-11-16 21:23:46.798022 [INFO] evse_manager_1:  :: EVSE ISO SLAC UNMATCHED
2024-11-16 21:23:46.807656 [INFO] evse_manager_1:  :: EVSE ISO D-LINK_READY (false)
2024-11-16 21:23:46.898085 [INFO] evse_manager_1:  ::                                     CAR IEC Event BCDtoEF
2024-11-16 21:23:49.016863 [INFO] evse_manager_1:  :: EVSE IEC Pause in X1 for EV READY regulations
2024-11-16 21:23:49.019428 [INFO] evse_manager_1:  :: EVSE IEC Set PWM Off
2024-11-16 21:23:49.807982 [INFO] evse_manager_1:  :: EVSE IEC Exit T_step_EF
2024-11-16 21:23:49.810497 [INFO] evse_manager_1:  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
2024-11-16 21:23:49.905342 [INFO] evse_manager_1:  ::                                     CAR IEC Event CarRequestedStopPower
2024-11-16 21:23:50.397147 [INFO] evse_manager_1:  :: EVSE IEC Charger state: T_step_EF->PrepareCharging
2024-11-16 21:23:50.993817 [INFO] evse_manager_1:  ::                                     CAR IEC Event EFtoBCD
2024-11-16 21:23:50.995515 [INFO] evse_manager_1:  :: EVSE ISO SLAC MATCHING
2024-11-16 21:23:59.617910 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: EXI Codec version: 1.55
2024-11-16 21:23:59.623437 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Starting 15118 version: 0.28.3
2024-11-16 21:23:59.624877 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Communication session handler started
2024-11-16 21:23:59.630197 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Remaining SDP requests: 50
2024-11-16 21:23:59.647560 [ERRO] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: [Errno 92] Protocol not available
Traceback (most recent call last):
  File "/ext/dist/libexec/everest/modules/PyEvJosev/../../3rd_party/josev/iso15118/shared/utils.py", line 126, in wait_for_tasks
    done_task.result()
  File "/ext/dist/libexec/everest/modules/PyEvJosev/../../3rd_party/josev/iso15118/evcc/transport/udp_client.py", line 82, in start
    sock=self._create_socket(self.iface),
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/ext/dist/libexec/everest/modules/PyEvJosev/../../3rd_party/josev/iso15118/evcc/transport/udp_client.py", line 68, in _create_socket
    sock.setsockopt(socket.IPPROTO_IPV6, socket.IPV6_MULTICAST_IF, interface_index)
OSError: [Errno 92] Protocol not available
2024-11-16 21:24:00.432045 [INFO] evse_manager_1:  :: EVSE IEC Charger state: PrepareCharging->Car Paused
2024-11-16 21:24:00.504473 [WARN] ocpp:OCPP201    types::ocpp::OcppTransactionEvent module::conversions::to_everest_ocpp_transaction_event(const ocpp::v201::TransactionEventRequest&) :: Attempting to convert TransactionEventRequest that does not contain information about the EVSE. evse_id and connector default to 1.
2024-11-16 21:24:00.649180 [WARN] ocpp:OCPP201    types::ocpp::OcppTransactionEvent module::conversions::to_everest_ocpp_transaction_event(const ocpp::v201::TransactionEventRequest&) :: Attempting to convert TransactionEventRequest that does not contain information about the EVSE. evse_id and connector default to 1.

The logs are definitely different, but the iso15118_car logs up until where I errored out are the same:

2024-11-16 21:21:22.595116 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: EXI Codec version: 1.55
2024-11-16 21:21:22.603134 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Starting 15118 version: 0.28.3
2024-11-16 21:21:22.606730 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Communication session handler started
2024-11-16 21:21:22.631197 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Remaining SDP requests: 50
2024-11-16 21:21:22.717552 [ERRO] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: [Errno 92] Protocol not available
Traceback (most recent call last):
  File "/ext/dist/libexec/everest/modules/PyEvJosev/../../3rd_party/josev/iso15118/shared/utils.py", line 126, in wait_for_tasks
    done_task.result()
  File "/ext/dist/libexec/everest/modules/PyEvJosev/../../3rd_party/josev/iso15118/evcc/transport/udp_client.py", line 82, in start
    sock=self._create_socket(self.iface),
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/ext/dist/libexec/everest/modules/PyEvJosev/../../3rd_party/josev/iso15118/evcc/transport/udp_client.py", line 68, in _create_socket
    sock.setsockopt(socket.IPPROTO_IPV6, socket.IPV6_MULTICAST_IF, interface_index)
OSError: [Errno 92] Protocol not available

OSError sounds like it may very well be an M1 chip error. Work laptop loading off VPN 45 minutes and counting, very little progress pulling the manager so far.

@shankari
Copy link
Collaborator

We do want to be ready to run on M1 chips if possible, so could you take a look at what that error might on the M1 chip. it seems like a fairly consistent network error, not anything specific to everest

@shankari
Copy link
Collaborator

@the-bay-kay any updates on #84 (comment)

@Abby-Wheelis
Copy link
Contributor

Abby-Wheelis commented Nov 16, 2024

Work laptop loading off VPN 45 minutes and counting, very little progress pulling the manager so far.

For what it's worth, this took ~2 hours and is finally "ready to start charging"

First try got the same "retry max reached" as yesterday. I was able to unplug and replug and sucessfully start a charging session!

@Abby-Wheelis
Copy link
Contributor

We do want to be ready to run on M1 chips if possible, so could you take a look at what that error might on the M1 chip. it seems like a fairly consistent network error, not anything specific to everest

Trying to investigate, it doesn't seem like a super well known error, but finding a few things.

  1. It seems that on MacOS errors might not be handled as well as they are in other OS docs

Note On BSD systems (macOS, FreeBSD, etc.) flow control is not supported for datagram protocols, because there is no reliable way to detect send failures caused by writing too many packets.
The socket always appears ‘ready’ and excess packets are dropped. An OSError with errno set to errno.ENOBUFS may or may not be raised; if it is raised, it will be reported to DatagramProtocol.error_received() but otherwise ignored.

The error that I am seeing is an OSError

  1. This stack overflow article encounters the same error, but has very little explantation of why the accepted solution worked. The function called setsockopt is the same as what seems to be the origin of this error, so that's something but not a clear answer.

@shankari
Copy link
Collaborator

Yay! So we can confirm that x86 works, and there isn't anything fundamentally broken. So this must be an M1 issue.
You can "ssh" in with docker exec -it and try to set whatever you want to set. It may be that running an amd64 image on an M1 chip has this error because the virtualization doesn't work as expected.

@shankari
Copy link
Collaborator

Let's move this to the M1 mac issue (#63) to avoid cluttering this up.

@shankari
Copy link
Collaborator

@Abby-Wheelis let's continue testing the x86 version here, assuming it is responsive!?! I am getting an error while setting the charging profile...

@Abby-Wheelis
Copy link
Contributor

Abby-Wheelis commented Nov 17, 2024

assuming it is responsive!?!

Docker panicked again (The error message really says Docker panic:). I'll try deleting some more things and see if I can revive it... Sucess!

Stuck in EV Paused it seems. I'm really curious why we're seeing a log that says CAR IEC Event CarRequestedStopPower before charging even starts.

2024-11-17 01:32:02.259325 [INFO] auth:Auth        :: Received new token: {
    "authorization_type": "RFID",
    "connectors": [
        1
    ],
    "id_token": {
        "type": "ISO14443",
        "value": "DEADBEEF"
    },
    "prevalidated": false
}
2024-11-17 01:32:02.317866 [INFO] ocpp:OCPP201     :: Found valid entry in AuthCache
2024-11-17 01:32:02.343485 [INFO] auth:Auth        :: Providing authorization to connector#1
2024-11-17 01:32:02.394371 [INFO] auth:Auth        :: Result for token: DEADBEEF: ACCEPTED
2024-11-17 01:32:02.475544 [INFO] evse_manager_1:  :: EVSE IEC EIM Authorization received
2024-11-17 01:32:02.526922 [INFO] evse_manager_1:  :: EVSE IEC Transaction Started (0 kWh)
2024-11-17 01:32:02.528271 [INFO] evse_manager_1:  :: EVSE IEC AC mode, HLC enabled(X1), matching already started. We are in X1 so we can go directly to nominal PWM.
2024-11-17 01:32:02.528550 [INFO] evse_manager_1:  :: EVSE IEC Charger state: Wait for Auth->PrepareCharging
2024-11-17 01:32:02.533253 [INFO] evse_manager_1:  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
2024-11-17 01:32:32.621429 [INFO] evse_manager_1:  :: EVSE IEC EV did not transition to state C, trying one legacy wakeup according to IEC61851-1 A.5.3
2024-11-17 01:32:32.622551 [INFO] evse_manager_1:  :: EVSE IEC Charger state: PrepareCharging->T_step_EF
2024-11-17 01:32:32.623602 [INFO] evse_manager_1:  :: EVSE IEC Enter T_step_EF
2024-11-17 01:32:32.624065 [INFO] evse_manager_1:  :: EVSE IEC Set PWM F
2024-11-17 01:32:32.790556 [INFO] evse_manager_1:  :: EVSE ISO SLAC UNMATCHED
2024-11-17 01:32:32.790693 [INFO] evse_manager_1:  ::                                     CAR IEC Event BCDtoEF
2024-11-17 01:32:32.793577 [INFO] evse_manager_1:  :: EVSE ISO D-LINK_READY (false)
2024-11-17 01:32:36.654678 [INFO] evse_manager_1:  :: EVSE IEC Pause in X1 for EV READY regulations
2024-11-17 01:32:36.655300 [INFO] evse_manager_1:  :: EVSE IEC Set PWM Off
2024-11-17 01:32:37.248630 [INFO] evse_manager_1:  ::                                     CAR IEC Event CarRequestedStopPower
2024-11-17 01:32:37.253796 [INFO] evse_manager_1:  :: EVSE ISO SLAC MATCHING
2024-11-17 01:32:37.254390 [INFO] evse_manager_1:  ::                                     CAR IEC Event EFtoBCD
2024-11-17 01:32:37.405199 [INFO] evse_manager_1:  :: EVSE IEC Exit T_step_EF
2024-11-17 01:32:37.405680 [INFO] evse_manager_1:  :: EVSE IEC Set PWM On (53.33333611488342%) took 0 ms
2024-11-17 01:32:37.493355 [INFO] evse_manager_1:  :: EVSE IEC Charger state: T_step_EF->PrepareCharging
2024-11-17 01:32:41.791699 [WARN] ocpp:OCPP201    void ocpp::v201::ChargePoint::scheduled_check_v2g_certificate_expiration() :: PnC is enabled but V2G certificate installation is not, so no certificate expiration check is performed.
2024-11-17 01:32:47.514969 [INFO] evse_manager_1:  :: EVSE IEC Charger state: PrepareCharging->Car Paused

UPDATE - rebooted and went to charging just fine. Now I can try setting a charging profile?

@shankari
Copy link
Collaborator

I am running into issues with setting the charging profile
#79 (comment) and later

So I am not sure it will actually work. I think you can play around a bit with the departure time (without the charging profile) and then stop for the day 😄

@shankari
Copy link
Collaborator

Will wait for @Abby-Wheelis to finish testing with the final changes and then close.

@shankari
Copy link
Collaborator

@Abby-Wheelis final(?!!) changes have been checked in. Might still change some text but running out of time for that now.
LMK if you are able to play around with the demo and if it works the way you would expect.

@Abby-Wheelis
Copy link
Contributor

I just tried again tonight with a fresh copy, it still took ~2 hours to pull but I was doing work around the house so it didn't matter too much. I plugged/unplugged three times but it just timed out every time and never started charging. I can try again when I get to work tomorrow, but I probably won't be able to pull again unless it really is just the apartment wifi and it's significantly faster in the office.

@the-bay-kay
Copy link
Author

...ran into an issue at the end of the charge session.... Not sure if you actually tested all the way to the end...

I did include this test. Please see timestamp 5:28 of the attached video here. As you can see in the logs I provided, we end up using a schedule of length "2" after reaching the departure time (e.g., we default to the original SASchedule). Let me try to replicate your issues now.

I ran into a tag mismatch when pulling the changes in main -- The environment expect Tag=0.0.21, but our tagged manager images only go up to 0.0.20 (link). Building off of 0.0.20 for now, LMK if I'm missing something here.

@shankari
Copy link
Collaborator

oops! I forgot to push the 0.0.21 version of manager, which I can only build locally. you should be able to re-pull now...

@the-bay-kay
Copy link
Author

the-bay-kay commented Nov 18, 2024

Let me try to replicate your issues now.

Testing the charge parameters EA=60, DT = 3600, SimSpeed = 100x , I'm not seeing any errors...

Logs
End Of Schedule::  3416
NewClockValue::  3460.5514526367188
3416
Passed the end of the schedule!
2024-11-18 16:16:41.286374 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Message to encode (ns=Namespace.ISO_V2_MSG_DEF): {"V2G_Message": {"Header": {"SessionID": "83B7E93FEAF3D6BC"}, "Body": {"PowerDeliveryReq": {"ChargeProgress": "Renegotiate", "SAScheduleTupleID": 1}}}}
2024-11-18 16:16:41.806467 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Sent PowerDeliveryReq
2024-11-18 16:16:41.806651 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Entered state PowerDelivery
2024-11-18 16:16:41.837500 [INFO] evse_manager_1:  ::                                     CAR ISO V2G PowerDeliveryReq
2024-11-18 16:16:41.905879 [INFO] evse_manager_1:  :: EVSE ISO V2G PowerDeliveryRes
2024-11-18 16:16:41.919668 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Decoded message (ns=Namespace.ISO_V2_MSG_DEF): {"V2G_Message":{"Header":{"SessionID":"83B7E93FEAF3D6BC"},"Body":{"PowerDeliveryRes":{"ResponseCode":"OK","AC_EVSEStatus":{"NotificationMaxDelay":0,"EVSENotification":"None","RCD":false}}}}}
2024-11-18 16:16:41.919964 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: PowerDeliveryRes received
2024-11-18 16:16:41.920518 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Message to encode (ns=Namespace.ISO_V2_MSG_DEF): {"V2G_Message": {"Header": {"SessionID": "83B7E93FEAF3D6BC"}, "Body": {"ChargeParameterDiscoveryReq": {"RequestedEnergyTransferMode": "AC_three_phase_core", "AC_EVChargeParameter": {"DepartureTime": 3600, "EAmount": {"Value": 60, "Multiplier": 3, "Unit": "Wh"}, "EVMaxVoltage": {"Value": 400, "Multiplier": 0, "Unit": "V"}, "EVMaxCurrent": {"Value": 32000, "Multiplier": -3, "Unit": "A"}, "EVMinCurrent": {"Value": 10, "Multiplier": 0, "Unit": "A"}}}}}}
2024-11-18 16:16:42.435804 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Sent ChargeParameterDiscoveryReq
2024-11-18 16:16:42.436025 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Entered state ChargeParameterDiscovery

2024-11-18 16:16:42.436753 [INFO] iso15118_charge  :: Selected energy transfer mode: AC_three_phase_core

2024-11-18 16:16:42.436872 [WARN] iso15118_charge void dlog_func(dloglevel_t, const char*, int, const char*, const char*, ...) :: before adjusting for departure time, max_current 32.000000, nom_voltage 230, pmax 22080, departure_duration 3600

2024-11-18 16:16:42.436965 [WARN] iso15118_charge void dlog_func(dloglevel_t, const char*, int, const char*, const char*, ...) :: Requested departure time 3600, requested energy 60000.000000

2024-11-18 16:16:42.437023 [WARN] iso15118_charge void dlog_func(dloglevel_t, const char*, int, const char*, const char*, ...) :: Departure time specified, checking to see if we can lower requirements

2024-11-18 16:16:42.437062 [WARN] iso15118_charge void dlog_func(dloglevel_t, const char*, int, const char*, const char*, ...) :: Min hours to charge 2.717391, requested departure time in hours 0.000000, pmax is unchanged
2024-11-18 16:16:42.552451 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Decoded message (ns=Namespace.ISO_V2_MSG_DEF): {"V2G_Message":{"Header":{"SessionID":"83B7E93FEAF3D6BC"},"Body":{"ChargeParameterDiscoveryRes":{"ResponseCode":"OK","EVSEProcessing":"Finished","SAScheduleList":{"SAScheduleTuple":[{"SAScheduleTupleID":1,"PMaxSchedule":{"PMaxScheduleEntry":[{"RelativeTimeInterval":{"start":0,"duration":3600},"PMax":{"Multiplier":0,"Unit":"W","Value":22080}}]}}]},"AC_EVSEChargeParameter":{"AC_EVSEStatus":{"NotificationMaxDelay":0,"EVSENotification":"None","RCD":false},"EVSENominalVoltage":{"Multiplier":-1,"Unit":"V","Value":2300},"EVSEMaxCurrent":{"Multiplier":-1,"Unit":"A","Value":320}}}}}}
2024-11-18 16:16:42.552928 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: ChargeParameterDiscoveryRes received
SAScheduleTuples are: [SAScheduleTuple(sa_schedule_tuple_id=1, p_max_schedule=PMaxSchedule(schedule_entries=[PMaxScheduleEntry(p_max=PVPMax(value=22080, multiplier=0, unit=<UnitSymbol.WATT: 'W'>), time_interval=RelativeTimeInterval(start=0, duration=3600))]), sales_tariff=None)]
2024-11-18 16:16:42.577843 [INFO] evse_manager_1:  ::                                     CAR ISO V2G ChargeParameterDiscoveryReq
2024-11-18 16:16:42.578264 [INFO] evse_manager_1:  :: EVSE ISO V2G ChargeParameterDiscoveryRes
Sim speed is now  100
1731946602.804891 1731946566.680353 100
Charging Session Time Elapsed...  3612.4579429626465
In ProcessSchedules
Processing SASchedules! $[]
Processing SASchedules! $3612.4579429626465
Done processing schedules...
Abt to generate Curve... 3612.4579429626465
End of Profile! Defaulting to EVCC profile enteries
2024-11-18 16:16:43.059174 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Message to encode (ns=Namespace.ISO_V2_MSG_DEF): {"V2G_Message": {"Header": {"SessionID": "83B7E93FEAF3D6BC"}, "Body": {"PowerDeliveryReq": {"ChargeProgress": "Start", "SAScheduleTupleID": 1, "ChargingProfile": {"ProfileEntry": [{"ChargingProfileEntryStart": 0, "ChargingProfileEntryMaxPower": {"Value": 22080, "Multiplier": 0, "Unit": "W"}}, {"ChargingProfileEntryStart": 3600, "ChargingProfileEntryMaxPower": {"Value": 0, "Multiplier": 0, "Unit": "W"}}]}}}}}
2024-11-18 16:16:43.574402 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Sent PowerDeliveryReq
2024-11-18 16:16:43.574647 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Entered state PowerDelivery
2024-11-18 16:16:43.575605 [INFO] evse_manager_1:  ::                                     CAR ISO V2G PowerDeliveryReq
2024-11-18 16:16:43.674082 [INFO] evse_manager_1:  :: EVSE ISO V2G PowerDeliveryRes
2024-11-18 16:16:43.733843 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Decoded message (ns=Namespace.ISO_V2_MSG_DEF): {"V2G_Message":{"Header":{"SessionID":"83B7E93FEAF3D6BC"},"Body":{"PowerDeliveryRes":{"ResponseCode":"OK","AC_EVSEStatus":{"NotificationMaxDelay":0,"EVSENotification":"None","RCD":false}}}}}
2024-11-18 16:16:43.734156 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: PowerDeliveryRes received
2024-11-18 16:16:43.734385 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Message to encode (ns=Namespace.ISO_V2_MSG_DEF): {"V2G_Message": {"Header": {"SessionID": "83B7E93FEAF3D6BC"}, "Body": {"ChargingStatusReq": {}}}}
2024-11-18 16:16:44.251667 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Sent ChargingStatusReq
2024-11-18 16:16:44.251848 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Entered state ChargingStatus
2024-11-18 16:16:44.277622 [INFO] evse_manager_1:  ::                                     CAR ISO V2G ChargingStatusReq
2024-11-18 16:16:44.350017 [INFO] evse_manager_1:  :: EVSE ISO V2G ChargingStatusRes
2024-11-18 16:16:44.363358 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: Decoded message (ns=Namespace.ISO_V2_MSG_DEF): {"V2G_Message":{"Header":{"SessionID":"83B7E93FEAF3D6BC"},"Body":{"ChargingStatusRes":{"ResponseCode":"OK","EVSEID":"DE*PNX*00001","SAScheduleTupleID":1,"EVSEMaxCurrent":{"Multiplier":-1,"Unit":"A","Value":320},"MeterInfo":{"MeterID":"YETI_POWERMETER","MeterReading":100},"AC_EVSEStatus":{"NotificationMaxDelay":0,"EVSENotification":"None","RCD":false}}}}}
2024-11-18 16:16:44.363777 [DEBG] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: ChargingStatusRes received
End Of Schedule::  86400
NewClockValue::  3768.3791637420654

Let me test a few other input combinations -- It may be that we're incorrectly flagging the end of profile in some scenarios...

  • {EA: 40, DT: 4000} @ 100x: OK

@shankari
Copy link
Collaborator

@the-bay-kay you should be able to use the parameters that I used back in my logs
#84 (comment)

@the-bay-kay
Copy link
Author

...you should be able to use the parameters that I used back in my logs...

Ah, yup -- with {EA: 60, DT: 3200} @ 25x, I'm seeing the crash. Let me investigate further...

@Abby-Wheelis
Copy link
Contributor

Abby-Wheelis commented Nov 18, 2024

Took about an hour, but I just got to test - documenting and attaching logs then signing off for the week to put my head down on some code changes for other projects.

1st try - no departure time set, entered charging fine
2nd try - set 4,000 as departure time, entered charging but got an error about max number of SDP retry cycles reached, didn't seem to stop charging (by that I mean the error did not cause charging to stop, I was able to unplug just fine)
3rd try - set 3,000 as departure time, did not enter charging, timed out first and went to "car paused" state

I think it was just 3 tries, my brain is admittedly not keeping up well with me today. @catarial was looking over my shoulder so might be able to account for what happened too.

Logs: Nov18_logs.rtf.zip

@catarial
Copy link
Contributor

I'm getting these errors inconsistently with demo-iso15118-2-ocpp-201 which cause the charger to go from PrepareCharging to CarPaused.

2024-11-18 22:21:42.930580 [ERRO] iso15118_charge void dlog_func(dloglevel_t, const char*, int, const char*, const char*, ...) :: Reading from tcp-socket aborted

2024-11-18 22:21:42.931161 [ERRO] iso15118_charge void dlog_func(dloglevel_t, const char*, int, const char*, const char*, ...) :: connection_read(header) failed: connection terminated

2024-11-18 22:21:42.931414 [ERRO] iso15118_charge void dlog_func(dloglevel_t, const char*, int, const char*, const char*, ...) :: v2g_incoming_v2gtp() (previous message "Payment Service Selection") failed

2024-11-18 22:21:49.972675 [ERRO] iso15118_car    pybind11_init_everestpy(pybind11::module_&)::<lambda(const std::string&)> :: EVCC tried to initiate a V2GCommunicationSession, but maximum number of SDP retry cycles (1) is now reached. Shutting down high-level communication. Unplug and plug in the cable again if you want to start anew.
Traceback (most recent call last):
  File "/ext/dist/libexec/everest/modules/PyEvJosev/../../3rd_party/josev/iso15118/evcc/comm_session_handler.py", line 586, in get_from_rcv_queue
    await self.restart_sdp(True)
  File "/ext/dist/libexec/everest/modules/PyEvJosev/../../3rd_party/josev/iso15118/evcc/comm_session_handler.py", line 403, in restart_sdp
    raise SDPFailedError(
iso15118.shared.exceptions.SDPFailedError: EVCC tried to initiate a V2GCommunicationSession, but maximum number of SDP retry cycles (1) is now reached. Shutting down high-level communication. Unplug and plug in the cable again if you want to start anew.

@shankari
Copy link
Collaborator

@catarial they may be related to the setting that you commented out "Reading from tcp-socket aborted"
That is not necessarily a deal-breaker - it is better to work sometimes than to never work at all. But it would be interesting to see why that line was added by looking at the blame.

I also want to highlight that we could also choose to rebuild multi-platform and see if that works better. I am a bit surprised that this happened in the python code given that python is a scripted language. But it looks like the python networking stack may be a thin layer over the underlying C stack, and this flag may just be different between operating systems. Would be interesting to understand that flag in greater detail, including differences between platforms.

@shankari
Copy link
Collaborator

This still has the crashing issue, but that is not a blocker for the testival. Moving it out of the milestone.

@shankari shankari removed this from the CharIN demo prep milestone Nov 19, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants