search

EVerest / everest-demo

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

Fix EVerest Testing Environment #30

Closed jhoshiko closed 1 month ago

jhoshiko commented 3 months ago

When trying to run the automated testing demo, the tests fail to run because pytest is not installed:

mqtt-server-1  | 1710442039: mosquitto version 2.0.10 starting
mqtt-server-1  | 1710442039: Config loaded from /mosquitto/config/mosquitto.conf.
mqtt-server-1  | 1710442039: Opening ipv4 listen socket on port 1883.
mqtt-server-1  | 1710442039: Opening websockets listen socket on port 9001.
mqtt-server-1  | 1710442039: mosquitto version 2.0.10 running
manager-1      | ./run-test.sh: line 3: pytest: not found
manager-1 exited with code 127

However, after installing pytest (specifically pytest-asyncio), the tests still fail because the everest.testing module is missing:

__________________________________________________________________ ERROR collecting core_tests/startup_tests.py ___________________________________________________________________ImportError while importing test module '/ext/source/tests/core_tests/startup_tests.py'.
Hint: make sure your test modules/packages have valid Python names.
Traceback:
/usr/lib/python3.10/importlib/__init__.py:126: in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
core_tests/startup_tests.py:12: in <module>
    from everest.testing.core_utils.everest_core import EverestCore, Requirement
E   ModuleNotFoundError: No module named 'everest.testing'
============================================================================= short test summary info =============================================================================ERROR core_tests/startup_tests.py
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Interrupted: 1 error during collection !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!================================================================================ 1 error in 0.14s =================================================================================

I can see that everestpy and edm_tool are both installed, and I can import everest.

jhoshiko commented 3 months ago

Using the pkgutil package, I can confirm that everest.framework exists, but I still do not see everest.testing

jhoshiko commented 3 months ago

@couryrr-afs Shankari recommended reaching out to you for assistance. Do you know what might be happening?

jhoshiko commented 3 months ago

Looks like others have had issues with the everestpy package missing but nothing mentioning everest.testing missing. They were able to fix it by rebuilding with an updated bullseye-toolchain.tgz. Not sure what we used, but this might be why everest.testing is missing.

couryrr-afs commented 3 months ago

@jhoshiko that looks to be a missing python dependency. I am attempting to rebuild the docker image calling pip install to verify if that is the missing step.

couryrr-afs commented 3 months ago

Update on the status of the issue. There was a missing step for installing pytest which solves the initial problem outline here. There is a branch on the US-JOET fork that provides the needed updates couryrr/updating-dockerfile-for-testing. However, as we attempt to run the test there appears to have been a breaking change in a new release of everest. Currently, attempting to track down the breaking change.

shankari commented 3 months ago

@couryrr-afs the UI-based tests are running (or will be running after I make push some changes). You might want to try replicating them in the automated tests.

couryrr-afs commented 3 months ago

Just wanted to give a quick status update. To get by the pytest issue described here it was simply adding the package along with pytest-asyncio via pip. After making this change there were issues with the packages that were being pulled in via the build-kit image and what we had been building. I moved the version up for the everest tag which appears to have solved all of the pytest issue from what I can tell. Unfortunately, when testing the full process with the bash script I am running into a new issue below. I am working to track down the cause of this.

DEBUG    root:everest_core.py:208   Syscall pipe2() failed (Invalid argument), exiting
manager-1      | DEBUG    root:everest_core.py:208   
manager-1      | WARNING  root:everest_core.py:215 EVerest stopped with return code: 1
manager-1      | DEBUG    root:everest_core.py:217 EVerest output stopped
shankari commented 3 months ago

@couryrr-afs have you tried any of the existing demos as a template? I am able to run most of the existing demos and certainly the scenarios being tested in these tests through the UI. The only tests that are failing are ISO 15118-2 + OCPP 201.

docker compose -f docker-compose.yml up works, for example, shows the full MREC UI and is able to charge.

After making this change there were issues with the packages that were being pulled in via the build-kit image and what we had been building.

It would be helpful to understand what these changes were and how they are different from the script currently in the Dockerfile.

I have (today morning) updated the demo images to the RC1 tag. I would suggest sticking to that tag for easier reproducibility and coordination within the community

couryrr-afs commented 3 months ago

Currently we are able to install pytest so the initial reported issue was a fairly simple fix. However, we cannot successfully get the test to run at this point in the docker container. I was able to replicate the setup in the devcontainer here: https://github.com/EVerest/everest-utils/tree/main/docker/everest-playground. Inside this devcontainer we are able to successfully run the test on the 2024.3.0-rc2 tag.

When moving this back over to the docker container for the test we receive a failure as outline above. There is a zulip thread here around getting more details from the manager https://lfenergy.zulipchat.com/#narrow/stream/417679-EVerest.3A-Testing-.26-CI/topic/Verbose.20Manager.20Error.20Output/near/430684671. At the moment this has been unsuccessful.

At this point we are considering this blocked by this issue: https://github.com/EVerest/everest-framework/issues/180

couryrr-afs commented 2 months ago

Per a comment on the issue https://github.com/EVerest/everest-framework/issues/180 I have attempted to rebuild and run the container in a proper linux environment. Currently, the build process is using a high amount of resource that my system cannot sustain. I am attempting to find an alternative to verify the solution.

couryrr-afs commented 2 months ago

The demo was successfully ran in docker on a PopOS host per the details here: https://github.com/EVerest/everest-framework/issues/180#issuecomment-2066536204

It appear we were communicating in multiple github issues. I will keep this one up-to-date going forward.

couryrr-afs commented 2 months ago

@shankari

Moving conversation for the demo work here. This is in response to https://github.com/EVerest/everest-framework/issues/180#issuecomment-2077869878

@couryrr-afs I do not plan to run the demo to test this out until I know the exact scenario in which it passes. I don't want to spend my time working through various configurations.

Can you please list out the known working configuration (host OS/VM OS/docker OS...) so that I can start there and try to go from working to working?

For the issue opened here tests could not be ran because pytest was not installed. This issue was resolved with the updated install.sh

The manager however was booting but then dying with a cryptic error:

[ERRO] manager int main(int, char**) :: Main manager process exits because of caught exception: DEBUG root:everest_core.py:208 Syscall pipe2() failed (Invalid argument), exiting

A successful build of the image and running container using Docker CE was completed on:

To Reproduce

Run

folkengine commented 1 month ago

Here's what I am seeing:

Clone https://github.com/US-JOET/everest-demo

$> cd everest-demo
$> git checkout couryrr/updating-dockerfile-for-testing
$> docker compose up mqtt-server 
$> cd manager
$> docker build -t ghcr.io/everest/everest-demo/manager:test .
$> docker run -it --network infranet_network -e MQTT_SERVER_ADDRESS=mqtt-server --entrypoint bash ghcr.io/everest/everest-demo/manager:test
#> cd /ext/source/tests
#> pytest --everest-prefix ../build/dist core_tests/startup_tests.py

Resulting logs:

================================================================ test session starts ================================================================
platform linux -- Python 3.10.13, pytest-8.1.1, pluggy-1.4.0
rootdir: /ext/source/tests
configfile: pytest.ini
plugins: asyncio-0.23.6
asyncio: mode=strict
collected 2 items                                                                                                                                   

core_tests/startup_tests.py::test_000_startup_check 
------------------------------------------------------------------ live log setup -------------------------------------------------------------------
INFO     root:everest_environment_setup.py:153 temp ocpp config files directory: /tmp/pytest-of-root/pytest-2/test_000_startup_check0/ocpp_config
INFO     root:everest_core.py:124 everest uuid: adab54fd7411406e9cc44eeaa95a3620
INFO     root:everest_core.py:125 temp everest config: /tmp/pytest-of-root/pytest-2/test_000_startup_check0/everest_config/everest_config.yaml based on ../build/dist/etc/everest/config-sil.yaml
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
------------------------------------------------------------------- live log call -------------------------------------------------------------------
INFO     root:startup_tests.py:20 >>>>>>>>> test_000_startup_check <<<<<<<<<
INFO     root:everest_core.py:164 config: /tmp/pytest-of-root/pytest-2/test_000_startup_check0/everest_config/everest_config.yaml
INFO     root:everest_core.py:171 /tmp/pytest-of-root/pytest-2/test_000_startup_check0/status.fifo
INFO     root:everest_core.py:183 /ext/source/build/dist/bin/manager --config /tmp/pytest-of-root/pytest-2/test_000_startup_check0/everest_config/everest_config.yaml --status-fifo /tmp/pytest-of-root/pytest-2/test_000_startup_check0/status.fifo
INFO     root:everest_core.py:185 Starting EVerest...
INFO     root:everest_core.py:186 /ext/source/build/dist/bin/manager  --config  /tmp/pytest-of-root/pytest-2/test_000_startup_check0/everest_config/everest_config.yaml  --status-fifo  /tmp/pytest-of-root/pytest-2/test_000_startup_check0/status.fifo
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332490 [INFO] manager          ::   ________      __                _   
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332557 [INFO] manager          ::  |  ____\ \    / /               | |  
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332572 [INFO] manager          ::  | |__   \ \  / /__ _ __ ___  ___| |_ 
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332589 [INFO] manager          ::  |  __|   \ \/ / _ \ '__/ _ \/ __| __|
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332601 [INFO] manager          ::  | |____   \  /  __/ | |  __/\__ \ |_ 
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332612 [INFO] manager          ::  |______|   \/ \___|_|  \___||___/\__|
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332622 [INFO] manager          ::
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332631 [INFO] manager          :: Using MQTT broker mqtt-server:1883
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/src/CMakeFiles/manager.dir/manager.cpp.gcda:Merge mismatch for function 1944
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/lib/CMakeFiles/framework.dir/error/error_type_map.cpp.gcda:Merge mismatch for function 1238
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.366446 [INFO] everest_ctrl     :: Launching controller service on port 0
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.398677 [INFO] manager          :: Loading config file at: /tmp/pytest-of-root/pytest-2/test_000_startup_check0/everest_config/everest_config.yaml
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.742970 [INFO] manager          :: Config loading completed in 380ms
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.794319 [ERRO] manager         bool Everest::MQTTAbstractionImpl::connectBroker(const char*, const char*) :: Failed to open socket: Invalid argument
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.794414 [ERRO] manager         int boot(const boost::program_options::variables_map&) :: Cannot connect to MQTT broker at mqtt-server:1883
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/src/CMakeFiles/manager.dir/manager.cpp.gcda:Merge mismatch for function 1944
FAILED                                                                                                                                        [ 50%]
----------------------------------------------------------------- live log teardown -----------------------------------------------------------------
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
DEBUG    root:everest_core.py:222 CONTROLLER stop() function called...
DEBUG    root:everest_core.py:208   
INFO     root:everest_core.py:213 EVerest stopped by signal SIGINT
DEBUG    root:everest_core.py:217 EVerest output stopped

core_tests/startup_tests.py::test_001_start_test_module 
------------------------------------------------------------------ live log setup -------------------------------------------------------------------
INFO     root:everest_environment_setup.py:153 temp ocpp config files directory: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/ocpp_config
INFO     root:everest_core.py:124 everest uuid: 53a3023e5068450198fde2e3bcd77fbc
INFO     root:everest_core.py:125 temp everest config: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/everest_config.yaml based on ../build/dist/etc/everest/config-sil.yaml
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
------------------------------------------------------------------- live log call -------------------------------------------------------------------
INFO     root:startup_tests.py:83 >>>>>>>>> test_001_start_test_module <<<<<<<<<
INFO     root:everest_core.py:164 config: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/everest_config.yaml
INFO     root:everest_core.py:241 temp everest user-config: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/user-config/everest_config.yaml
INFO     root:everest_core.py:244 Adding test control module(s) to user-config: None
INFO     root:everest_core.py:171 /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/status.fifo
INFO     root:everest_core.py:177 Standalone module probe was specified
INFO     root:everest_core.py:183 /ext/source/build/dist/bin/manager --config /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/everest_config.yaml --status-fifo /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/status.fifo --standalone probe
INFO     root:everest_core.py:185 Starting EVerest...
INFO     root:everest_core.py:186 /ext/source/build/dist/bin/manager  --config  /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/everest_config.yaml  --status-fifo  /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/status.fifo  --standalone  probe
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.904915 [INFO] manager          ::   ________      __                _   
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.904985 [INFO] manager          ::  |  ____\ \    / /               | |  
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905001 [INFO] manager          ::  | |__   \ \  / /__ _ __ ___  ___| |_ 
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905019 [INFO] manager          ::  |  __|   \ \/ / _ \ '__/ _ \/ __| __|
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905031 [INFO] manager          ::  | |____   \  /  __/ | |  __/\__ \ |_ 
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905042 [INFO] manager          ::  |______|   \/ \___|_|  \___||___/\__|
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905054 [INFO] manager          ::
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905063 [INFO] manager          :: Using MQTT broker mqtt-server:1883
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/src/CMakeFiles/manager.dir/manager.cpp.gcda:Merge mismatch for function 1944
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/lib/CMakeFiles/framework.dir/error/error_type_map.cpp.gcda:Merge mismatch for function 1238
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.939812 [INFO] everest_ctrl     :: Launching controller service on port 0
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.971756 [INFO] manager          :: Loading config file at: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/everest_config.yaml
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.977315 [INFO] manager          :: Loading user-config file at: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/user-config/everest_config.yaml
DEBUG    root:everest_core.py:208   2024-05-21 16:48:23.320558 [INFO] manager          :: Config loading completed in 384ms
DEBUG    root:everest_core.py:208   2024-05-21 16:48:23.373036 [ERRO] manager         bool Everest::MQTTAbstractionImpl::connectBroker(const char*, const char*) :: Failed to open socket: Resource temporarily unavailable
DEBUG    root:everest_core.py:208   2024-05-21 16:48:23.373137 [ERRO] manager         int boot(const boost::program_options::variables_map&) :: Cannot connect to MQTT broker at mqtt-server:1883
FAILED                                                                                                                                        [100%]
----------------------------------------------------------------- live log teardown -----------------------------------------------------------------
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/src/CMakeFiles/manager.dir/manager.cpp.gcda:Merge mismatch for function 1944
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
DEBUG    root:everest_core.py:222 CONTROLLER stop() function called...
DEBUG    root:everest_core.py:208   
INFO     root:everest_core.py:213 EVerest stopped by signal SIGINT
DEBUG    root:everest_core.py:217 EVerest output stopped

===================================================================== FAILURES ======================================================================
______________________________________________________________ test_000_startup_check _______________________________________________________________

everest_core = <everest.testing.core_utils.everest_core.EverestCore object at 0x7e920d7f9c90>

    @pytest.mark.asyncio
    async def test_000_startup_check(everest_core: EverestCore):
        logging.info(">>>>>>>>> test_000_startup_check <<<<<<<<<")
>       everest_core.start()

core_tests/startup_tests.py:21: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <everest.testing.core_utils.everest_core.EverestCore object at 0x7e920d7f9c90>, standalone_module = None, test_connections = None

    def start(self, standalone_module: Optional[Union[str, List[str]]] = None, test_connections: Connections = None):
        """Starts everest-core in a subprocess

        Args:
            standalone_module (str, optional): If set, a submodule can be started separately. EVerest will then wait for the submodule to be started.
             Defaults to None.
        """

        standalone_module = standalone_module if standalone_module is not None else self._standalone_module

        manager_path = self.prefix_path / 'bin/manager'

        logging.info(f'config: {self.everest_config_path}')

        # FIXME (aw): clean up passing of modules_to_test
        self.test_connections = test_connections if test_connections != None else {}
        self._create_testing_user_config()

        self.status_listener = StatusFifoListener(self._status_fifo_path)
        logging.info(self._status_fifo_path)

        args = [str(manager_path.resolve()), '--config', str(self.everest_config_path),
                '--status-fifo', str(self._status_fifo_path)]

        if standalone_module:
            logging.info(f"Standalone module {standalone_module} was specified")
            if not isinstance(standalone_module, list):
                standalone_module = [standalone_module]
            for s in standalone_module:
                args.extend(['--standalone', s])

        logging.info(" ".join(args))

        logging.info('Starting EVerest...')
        logging.info('  '.join(args))

        self.process = subprocess.Popen(
            args, cwd=self.prefix_path, stdout=subprocess.PIPE, stderr=subprocess.PIPE)

        self.log_reader_thread = Thread(target=self.read_everest_log)
        self.log_reader_thread.start()

        expected_status = 'ALL_MODULES_STARTED' if standalone_module == None else 'WAITING_FOR_STANDALONE_MODULES'

        status = self.status_listener.wait_for_status(STARTUP_TIMEOUT, [expected_status])
        if status == None or len(status) == 0:
>           raise TimeoutError("Timeout while waiting for EVerest to start")
E           TimeoutError: Timeout while waiting for EVerest to start

/usr/lib/python3.10/site-packages/everest/testing/core_utils/everest_core.py:198: TimeoutError
---------------------------------------------------------------- Captured log setup -----------------------------------------------------------------
INFO     root:everest_environment_setup.py:153 temp ocpp config files directory: /tmp/pytest-of-root/pytest-2/test_000_startup_check0/ocpp_config
INFO     root:everest_core.py:124 everest uuid: adab54fd7411406e9cc44eeaa95a3620
INFO     root:everest_core.py:125 temp everest config: /tmp/pytest-of-root/pytest-2/test_000_startup_check0/everest_config/everest_config.yaml based on ../build/dist/etc/everest/config-sil.yaml
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
----------------------------------------------------------------- Captured log call -----------------------------------------------------------------
INFO     root:startup_tests.py:20 >>>>>>>>> test_000_startup_check <<<<<<<<<
INFO     root:everest_core.py:164 config: /tmp/pytest-of-root/pytest-2/test_000_startup_check0/everest_config/everest_config.yaml
INFO     root:everest_core.py:171 /tmp/pytest-of-root/pytest-2/test_000_startup_check0/status.fifo
INFO     root:everest_core.py:183 /ext/source/build/dist/bin/manager --config /tmp/pytest-of-root/pytest-2/test_000_startup_check0/everest_config/everest_config.yaml --status-fifo /tmp/pytest-of-root/pytest-2/test_000_startup_check0/status.fifo
INFO     root:everest_core.py:185 Starting EVerest...
INFO     root:everest_core.py:186 /ext/source/build/dist/bin/manager  --config  /tmp/pytest-of-root/pytest-2/test_000_startup_check0/everest_config/everest_config.yaml  --status-fifo  /tmp/pytest-of-root/pytest-2/test_000_startup_check0/status.fifo
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332490 [INFO] manager          ::   ________      __                _   
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332557 [INFO] manager          ::  |  ____\ \    / /               | |  
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332572 [INFO] manager          ::  | |__   \ \  / /__ _ __ ___  ___| |_ 
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332589 [INFO] manager          ::  |  __|   \ \/ / _ \ '__/ _ \/ __| __|
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332601 [INFO] manager          ::  | |____   \  /  __/ | |  __/\__ \ |_ 
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332612 [INFO] manager          ::  |______|   \/ \___|_|  \___||___/\__|
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332622 [INFO] manager          ::
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.332631 [INFO] manager          :: Using MQTT broker mqtt-server:1883
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/src/CMakeFiles/manager.dir/manager.cpp.gcda:Merge mismatch for function 1944
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/lib/CMakeFiles/framework.dir/error/error_type_map.cpp.gcda:Merge mismatch for function 1238
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.366446 [INFO] everest_ctrl     :: Launching controller service on port 0
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.398677 [INFO] manager          :: Loading config file at: /tmp/pytest-of-root/pytest-2/test_000_startup_check0/everest_config/everest_config.yaml
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.742970 [INFO] manager          :: Config loading completed in 380ms
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.794319 [ERRO] manager         bool Everest::MQTTAbstractionImpl::connectBroker(const char*, const char*) :: Failed to open socket: Invalid argument
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.794414 [ERRO] manager         int boot(const boost::program_options::variables_map&) :: Cannot connect to MQTT broker at mqtt-server:1883
--------------------------------------------------------------- Captured log teardown ---------------------------------------------------------------
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
DEBUG    root:everest_core.py:222 CONTROLLER stop() function called...
DEBUG    root:everest_core.py:208   
INFO     root:everest_core.py:213 EVerest stopped by signal SIGINT
DEBUG    root:everest_core.py:217 EVerest output stopped
____________________________________________________________ test_001_start_test_module _____________________________________________________________

everest_core = <everest.testing.core_utils.everest_core.EverestCore object at 0x7e920b97b940>

    @pytest.mark.everest_core_config('config-sil.yaml')
    @pytest.mark.asyncio
    async def test_001_start_test_module(everest_core: EverestCore):
        logging.info(">>>>>>>>> test_001_start_test_module <<<<<<<<<")

        test_connections = {
            'test_control': [Requirement('car_simulator', 'main')],
            'connector_1': [Requirement('connector_1', 'evse')]
        }

>       everest_core.start(standalone_module='probe', test_connections=test_connections)

core_tests/startup_tests.py:90: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <everest.testing.core_utils.everest_core.EverestCore object at 0x7e920b97b940>, standalone_module = ['probe']
test_connections = {'connector_1': [<everest.testing.core_utils.common.Requirement object at 0x7e920b9db2e0>], 'test_control': [<everest.testing.core_utils.common.Requirement object at 0x7e920b9db9d0>]}

    def start(self, standalone_module: Optional[Union[str, List[str]]] = None, test_connections: Connections = None):
        """Starts everest-core in a subprocess

        Args:
            standalone_module (str, optional): If set, a submodule can be started separately. EVerest will then wait for the submodule to be started.
             Defaults to None.
        """

        standalone_module = standalone_module if standalone_module is not None else self._standalone_module

        manager_path = self.prefix_path / 'bin/manager'

        logging.info(f'config: {self.everest_config_path}')

        # FIXME (aw): clean up passing of modules_to_test
        self.test_connections = test_connections if test_connections != None else {}
        self._create_testing_user_config()

        self.status_listener = StatusFifoListener(self._status_fifo_path)
        logging.info(self._status_fifo_path)

        args = [str(manager_path.resolve()), '--config', str(self.everest_config_path),
                '--status-fifo', str(self._status_fifo_path)]

        if standalone_module:
            logging.info(f"Standalone module {standalone_module} was specified")
            if not isinstance(standalone_module, list):
                standalone_module = [standalone_module]
            for s in standalone_module:
                args.extend(['--standalone', s])

        logging.info(" ".join(args))

        logging.info('Starting EVerest...')
        logging.info('  '.join(args))

        self.process = subprocess.Popen(
            args, cwd=self.prefix_path, stdout=subprocess.PIPE, stderr=subprocess.PIPE)

        self.log_reader_thread = Thread(target=self.read_everest_log)
        self.log_reader_thread.start()

        expected_status = 'ALL_MODULES_STARTED' if standalone_module == None else 'WAITING_FOR_STANDALONE_MODULES'

        status = self.status_listener.wait_for_status(STARTUP_TIMEOUT, [expected_status])
        if status == None or len(status) == 0:
>           raise TimeoutError("Timeout while waiting for EVerest to start")
E           TimeoutError: Timeout while waiting for EVerest to start

/usr/lib/python3.10/site-packages/everest/testing/core_utils/everest_core.py:198: TimeoutError
---------------------------------------------------------------- Captured log setup -----------------------------------------------------------------
INFO     root:everest_environment_setup.py:153 temp ocpp config files directory: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/ocpp_config
INFO     root:everest_core.py:124 everest uuid: 53a3023e5068450198fde2e3bcd77fbc
INFO     root:everest_core.py:125 temp everest config: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/everest_config.yaml based on ../build/dist/etc/everest/config-sil.yaml
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
----------------------------------------------------------------- Captured log call -----------------------------------------------------------------
INFO     root:startup_tests.py:83 >>>>>>>>> test_001_start_test_module <<<<<<<<<
INFO     root:everest_core.py:164 config: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/everest_config.yaml
INFO     root:everest_core.py:241 temp everest user-config: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/user-config/everest_config.yaml
INFO     root:everest_core.py:244 Adding test control module(s) to user-config: None
INFO     root:everest_core.py:171 /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/status.fifo
INFO     root:everest_core.py:177 Standalone module probe was specified
INFO     root:everest_core.py:183 /ext/source/build/dist/bin/manager --config /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/everest_config.yaml --status-fifo /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/status.fifo --standalone probe
INFO     root:everest_core.py:185 Starting EVerest...
INFO     root:everest_core.py:186 /ext/source/build/dist/bin/manager  --config  /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/everest_config.yaml  --status-fifo  /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/status.fifo  --standalone  probe
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.904915 [INFO] manager          ::   ________      __                _   
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.904985 [INFO] manager          ::  |  ____\ \    / /               | |  
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905001 [INFO] manager          ::  | |__   \ \  / /__ _ __ ___  ___| |_ 
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905019 [INFO] manager          ::  |  __|   \ \/ / _ \ '__/ _ \/ __| __|
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905031 [INFO] manager          ::  | |____   \  /  __/ | |  __/\__ \ |_ 
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905042 [INFO] manager          ::  |______|   \/ \___|_|  \___||___/\__|
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905054 [INFO] manager          ::
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.905063 [INFO] manager          :: Using MQTT broker mqtt-server:1883
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/src/CMakeFiles/manager.dir/manager.cpp.gcda:Merge mismatch for function 1944
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/lib/CMakeFiles/framework.dir/error/error_type_map.cpp.gcda:Merge mismatch for function 1238
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.939812 [INFO] everest_ctrl     :: Launching controller service on port 0
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.971756 [INFO] manager          :: Loading config file at: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/everest_config.yaml
DEBUG    root:everest_core.py:208   2024-05-21 16:48:22.977315 [INFO] manager          :: Loading user-config file at: /tmp/pytest-of-root/pytest-2/test_001_start_test_module0/everest_config/user-config/everest_config.yaml
DEBUG    root:everest_core.py:208   2024-05-21 16:48:23.320558 [INFO] manager          :: Config loading completed in 384ms
DEBUG    root:everest_core.py:208   2024-05-21 16:48:23.373036 [ERRO] manager         bool Everest::MQTTAbstractionImpl::connectBroker(const char*, const char*) :: Failed to open socket: Resource temporarily unavailable
DEBUG    root:everest_core.py:208   2024-05-21 16:48:23.373137 [ERRO] manager         int boot(const boost::program_options::variables_map&) :: Cannot connect to MQTT broker at mqtt-server:1883
--------------------------------------------------------------- Captured log teardown ---------------------------------------------------------------
DEBUG    root:everest_core.py:208   libgcov profiling error:/ext/source/build/_deps/everest-framework-build/src/CMakeFiles/manager.dir/manager.cpp.gcda:Merge mismatch for function 1944
DEBUG    asyncio:selector_events.py:54 Using selector: EpollSelector
DEBUG    root:everest_core.py:222 CONTROLLER stop() function called...
DEBUG    root:everest_core.py:208   
INFO     root:everest_core.py:213 EVerest stopped by signal SIGINT
DEBUG    root:everest_core.py:217 EVerest output stopped
============================================================== short test summary info ==============================================================
FAILED core_tests/startup_tests.py::test_000_startup_check - TimeoutError: Timeout while waiting for EVerest to start
FAILED core_tests/startup_tests.py::test_001_start_test_module - TimeoutError: Timeout while waiting for EVerest to start
================================================================= 2 failed in 1.26s =================================================================
libgcov profiling error:/ext/source/build/_deps/everest-framework-build/lib/CMakeFiles/framework.dir/error/error_type_map.cpp.gcda:Merge mismatch for function 1238