fix(arcor2_execution): distinguishing between (just) started and runn…

…ing package

README.md

@@ -84,7 +84,7 @@ The following video by [Kinali](https://www.kinali.cz/en/) shows the use case (o
 
 [README](src/python/arcor2_execution/README.md) | [CHANGELOG](src/python/arcor2_execution/CHANGELOG.md)
 
- - 2024-06-19: [1.4.1](https://github.com/robofit/arcor2/releases/tag/arcor2_execution%2F1.4.1) ([docker](https://hub.docker.com/r/arcor2/arcor2_execution/tags?page=1&ordering=last_updated&name=1.4.1), [pypi](https://pypi.org/project/arcor2-execution/1.4.1/)).
+ - 2024-06-26: [1.4.2](https://github.com/robofit/arcor2/releases/tag/arcor2_execution%2F1.4.2) ([docker](https://hub.docker.com/r/arcor2/arcor2_execution/tags?page=1&ordering=last_updated&name=1.4.2), [pypi](https://pypi.org/project/arcor2-execution/1.4.2/)).
 
 ### arcor2_execution_data
 
@@ -96,7 +96,7 @@ The following video by [Kinali](https://www.kinali.cz/en/) shows the use case (o
 
 [README](src/python/arcor2_execution_rest_proxy/README.md) | [CHANGELOG](src/python/arcor2_execution_rest_proxy/CHANGELOG.md)
 
- - 2024-06-14: [1.2.0](https://github.com/robofit/arcor2/releases/tag/arcor2_execution_rest_proxy%2F1.2.0) ([docker](https://hub.docker.com/r/arcor2/arcor2_execution_proxy/tags?page=1&ordering=last_updated&name=1.2.0), [pypi](https://pypi.org/project/arcor2-execution-rest-proxy/1.2.0/)).
+ - 2024-06-26: [1.2.1](https://github.com/robofit/arcor2/releases/tag/arcor2_execution_rest_proxy%2F1.2.1) ([docker](https://hub.docker.com/r/arcor2/arcor2_execution_proxy/tags?page=1&ordering=last_updated&name=1.2.1), [pypi](https://pypi.org/project/arcor2-execution-rest-proxy/1.2.1/)).
 
 ### arcor2_fanuc
 

build-support/install_kinect_prerequisites.sh

@@ -10,4 +10,4 @@ export DEBIAN_FRONTEND="noninteractive"
 echo 'libk4a1.4 libk4a1.4/accepted-eula-hash string 0f5d5c5de396e4fee4c0753a21fee0c1ed726cf0316204edda484f08cb266d76' | debconf-set-selections
 echo 'libk4a1.4 libk4a1.4/accept-eula boolean true' | debconf-set-selections
 echo 'libk4abt1.1 libk4abt1.1/accepted-eula-hash string 03a13b63730639eeb6626d24fd45cf25131ee8e8e0df3f1b63f552269b176e38' | debconf-set-selections
-apt-get install -y libk4a1.4 libk4a1.4-dev libk4abt1.1 libk4abt1.1-dev
+apt-get install -y libk4a1.4=1.4.1 libk4a1.4-dev=1.4.1 libk4abt1.1 libk4abt1.1-dev

compose-files/fit-demo/docker-compose.yml

@@ -1,5 +1,3 @@
-version: '3.8'
-
 services:
   fit-demo-arserver:
     image: arcor2/arcor2_arserver:1.2.0
@@ -61,7 +59,7 @@ services:
       - fit-demo-project-network
 
   fit-demo-execution:
-    image: arcor2/arcor2_execution:1.4.1
+    image: arcor2/arcor2_execution:1.4.2
     container_name: fit-demo-execution
     networks:
       - fit-demo-execution-network
@@ -74,9 +72,11 @@ services:
       - ARCOR2_PROJECT_PATH=/root/project
     volumes:
         - fit-demo-execution:/root/project
+    ports:
+      - "6791:6790"  # only needed for debugging - to be able to connect from outside
 
   fit-demo-execution-proxy:
-    image: arcor2/arcor2_execution_proxy:1.2.0
+    image: arcor2/arcor2_execution_proxy:1.2.1
     container_name: fit-demo-execution-proxy
     networks:
       - fit-demo-execution-network

src/docker/arcor2_execution/BUILD

@@ -1 +1 @@
-docker_image(name="arcor2_execution", repository="arcor2/arcor2_execution", image_tags=["1.4.1"])
+docker_image(name="arcor2_execution", repository="arcor2/arcor2_execution", image_tags=["1.4.2"])

src/docker/arcor2_execution_proxy/BUILD

@@ -1,5 +1,5 @@
 docker_image(
     name="arcor2_execution_proxy",
     repository="arcor2/arcor2_execution_proxy",
-    image_tags=["1.2.0"],
+    image_tags=["1.2.1"],
 )

src/python/arcor2/data/events.py

@@ -72,6 +72,7 @@ class PackageState(Event):
     @dataclass
     class Data(JsonSchemaMixin):
         class StateEnum(Enum):
+            STARTED: str = "started"  # started, but not fully running yet
             RUNNING: str = "running"
             STOPPING: str = "stopping"  # it may take some time to stop the package
             STOPPED: str = "stopped"

src/python/arcor2_arserver/tests/test_linked_pose.py

@@ -183,7 +183,12 @@ def test_linked_pose(start_processes: None, ars: ARServer) -> None:
     ps = event(ars, arcor2_events.PackageState).data
     assert ps
     assert ps.package_id == package.id
-    assert ps.state == ps.state.RUNNING
+    assert ps.state == ps.state.STARTED
+
+    pr = event(ars, arcor2_events.PackageState).data
+    assert pr
+    assert pr.package_id == package.id
+    assert pr.state == ps.state.RUNNING
 
     pi = event(ars, arcor2_events.PackageInfo).data
     assert pi

src/python/arcor2_arserver/tests/test_position_param.py

@@ -142,7 +142,12 @@ def test_position_param(start_processes: None, ars: ARServer) -> None:
     ps = event(ars, arcor2_events.PackageState).data
     assert ps
     assert ps.package_id == package.id
-    assert ps.state == ps.state.RUNNING
+    assert ps.state == ps.state.STARTED
+
+    pr = event(ars, arcor2_events.PackageState).data
+    assert pr
+    assert pr.package_id == package.id
+    assert pr.state == ps.state.RUNNING
 
     pi = event(ars, arcor2_events.PackageInfo).data
     assert pi

src/python/arcor2_arserver/tests/test_project_execution.py

@@ -160,7 +160,12 @@ def test_run_simple_project(start_processes: None, ars: ARServer) -> None:
     ps = event(ars, arcor2_events.PackageState).data
     assert ps
     assert ps.package_id == package.id
-    assert ps.state == ps.state.RUNNING
+    assert ps.state == ps.state.STARTED
+
+    pr = event(ars, arcor2_events.PackageState).data
+    assert pr
+    assert pr.package_id == package.id
+    assert pr.state == ps.state.RUNNING
 
     pi = event(ars, arcor2_events.PackageInfo).data
     assert pi

src/python/arcor2_arserver/tests/testutils.py

@@ -189,14 +189,14 @@ def ars() -> Iterator[ARServer]:
 
 def event(ars: ARServer, evt_type: type[E]) -> E:
     evt = ars.get_event()
-    assert isinstance(evt, evt_type)
+    assert isinstance(evt, evt_type), f"Got {evt}, was expecting {evt_type}"
     assert evt.event == evt_type.__name__
     return evt
 
 
 def wait_for_event(ars: ARServer, evt_type: type[E]) -> E:
     evt = ars.get_event(drop_everything_until=evt_type)
-    assert isinstance(evt, evt_type)
+    assert isinstance(evt, evt_type), f"Got {evt}, was expecting {evt_type}"
     assert evt.event == evt_type.__name__
     return evt
 

src/python/arcor2_execution/CHANGELOG.md

@@ -2,6 +2,17 @@
 
 The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
 
+## [1.4.2] - 2024-06-26
+
+### Fixed
+
+- It was possible to pause or stop the package before it was actually running.
+
+### Changed
+
+- If the attempt to stop the script with SIGINT fails (after timeout configured using `ARCOR2_EXECUTION_PKG_STOP_TIMEOUT`), it is stopped with SIGKILL. This may happen e.g. when using threads without `daemon=True` (which is strongly discouraged).
+- Previously, the package state `RUNNING` was reported once the script was started. Now, `STARTED` is sent when the script starts running and `RUNNING` afterward once the `Resources` class is fully initialized (`PackageInfo` event is sent). This should be fully backwards-compatible. 
+
 ## [1.4.1] - 2024-06-19
 
 ### Fixed

src/python/arcor2_execution/README.md

@@ -5,4 +5,5 @@
 - `ARCOR2_EXECUTION_URL=ws://0.0.0.0:6790` - by default, the service listens on port 6790.
 - `ARCOR2_MAX_RPC_DURATION=0.1` - by default, a warning is emitted when any RPC call takes longer than 0.1 second.
 - `ARCOR2_EXECUTION_DEBUG=1` - switches logger to the `DEBUG` level.
-- `ARCOR2_ARSERVER_ASYNCIO_DEBUG=1` - turns on `asyncio` debug output (helpful to debug problems related to concurrency).
+- `ARCOR2_ARSERVER_ASYNCIO_DEBUG=1` - turns on `asyncio` debug output (helpful to debug problems related to concurrency).
+- `ARCOR2_EXECUTION_PKG_STOP_TIMEOUT=5.0` - configures timeout for an attempt to stop the script in the civilized way (SIGINT). After the timeout, the script is killed (SIGKILL).

src/python/arcor2_execution/VERSION

@@ -1 +1 @@
-1.4.1
+1.4.2

src/python/arcor2_execution/scripts/execution.py

@@ -50,6 +50,10 @@
 
 EVENT_MAPPING = {evt.__name__: evt for evt in EVENTS}
 
+PKG_STOP_TIMEOUT: float | None = env.get_float("ARCOR2_EXECUTION_PKG_STOP_TIMEOUT", 5.0)
+if PKG_STOP_TIMEOUT is not None and PKG_STOP_TIMEOUT <= 0:
+    PKG_STOP_TIMEOUT = None
+
 
 def process_running() -> bool:
     return PROCESS is not None and PROCESS.returncode is None
@@ -105,6 +109,11 @@ async def read_proc_stdout() -> None:
         elif isinstance(evt, PackageInfo):
             PACKAGE_INFO_EVENT = evt
 
+            # the event is sent just once, when the Resources class is fully initialized
+            await package_state(
+                PackageState(PackageState.Data(PackageState.Data.StateEnum.RUNNING, RUNNING_PACKAGE_ID))
+            )
+
         await send_to_clients(evt)
 
     PACKAGE_INFO_EVENT = None
@@ -205,7 +214,7 @@ async def _update_executed(package_id: str) -> None:
         raise Arcor2Exception("Failed to start package.")
 
     RUNNING_PACKAGE_ID = req.args.id
-    await package_state(PackageState(PackageState.Data(PackageState.Data.StateEnum.RUNNING, RUNNING_PACKAGE_ID)))
+    await package_state(PackageState(PackageState.Data(PackageState.Data.StateEnum.STARTED, RUNNING_PACKAGE_ID)))
 
     TASK = asyncio.create_task(read_proc_stdout())  # run task in background
     asyncio.create_task(_update_executed(req.args.id))
@@ -223,7 +232,15 @@ async def _terminate_task() -> None:
         PROCESS.send_signal(signal.SIGINT)  # the same as when a user presses ctrl+c
 
         logger.info("Waiting for process to finish...")
-        await asyncio.wait([TASK])
+        _, pending = await asyncio.wait([TASK], timeout=PKG_STOP_TIMEOUT)
+
+        if pending:
+            logger.info("The script refuses to stop, killing it...")
+            PROCESS.send_signal(signal.SIGKILL)
+            await asyncio.wait([TASK])
+
+        logger.info("Script was stopped.")
+
         PACKAGE_INFO_EVENT = None
         RUNNING_PACKAGE_ID = None
 

src/python/arcor2_execution_rest_proxy/CHANGELOG.md

@@ -2,6 +2,13 @@
 
 The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
 
+## [1.2.1] - 2024-06-26
+
+### Fixed
+
+- `Pending` is now correctly reported once the package is started but is not actually running yet.
+
+
 ## [1.2.0] - 2024-06-14
 
 ### Changed

src/python/arcor2_execution_rest_proxy/VERSION

@@ -1 +1 @@
-1.2.0
+1.2.1

src/python/arcor2_execution_rest_proxy/scripts/execution_rest_proxy.py

@@ -983,6 +983,7 @@ def packages_state() -> RespT:
         PackageState.Data.StateEnum.PAUSING,
         PackageState.Data.StateEnum.STOPPING,
         PackageState.Data.StateEnum.RESUMING,
+        PackageState.Data.StateEnum.STARTED,
     ):
         ret = ExecutionInfo(ExecutionState.Pending, package_state.package_id)
     elif package_state.state == PackageState.Data.StateEnum.STOPPED:

src/python/arcor2_execution_rest_proxy/scripts/manual_test.py

@@ -0,0 +1,58 @@
+from arcor2 import rest
+from arcor2_execution_rest_proxy.scripts.execution_rest_proxy import ExecutionInfo, ExecutionState
+import time
+import requests
+
+# TODO turn it into regular integration test
+
+URL = "http://localhost:5009"
+PKG = "ParTestPackage"
+
+def wait_for(what: ExecutionState | set[ExecutionState], pkg_id: str | None = None, aps: set[str] | None = None) -> None:
+
+    if isinstance(what, ExecutionState):
+        what = {what}
+
+    while True:
+
+        # ...this can't be used because case proxy uses non-standard style/case (activePackageId)
+        #ei = rest.call(rest.Method.GET, f"{URL}/packages/state", return_type=ExecutionInfo)
+        ei = ExecutionInfo.from_dict(requests.get(f"{URL}/packages/state").json())
+
+        if ei.state in what:
+            print(ei)
+
+            if pkg_id is not None:
+                assert ei.activePackageId == pkg_id, (ei.activePackageId, pkg_id)
+
+            if aps is not None:
+                assert ei.actionPointIds is not None
+                assert  aps.issubset(ei.actionPointIds), (ei.actionPointIds, aps)
+
+            break
+        else:
+            print(f"Waiting for {what}, got {ei.state}")
+        time.sleep(0.1)
+
+if __name__ == "__main__":
+
+    rest.call(rest.Method.PUT, f"{URL}/packages/{PKG}/start")
+    try:
+        rest.call(rest.Method.PUT, f"{URL}/packages/pause")
+    except rest.WebApiError as e:
+        print(f"Expected failure: {e}")
+    wait_for(ExecutionState.Running, pkg_id=PKG)
+    rest.call(rest.Method.PUT, f"{URL}/packages/pause")
+    wait_for(ExecutionState.Paused, pkg_id=PKG)
+    rest.call(rest.Method.PUT, f"{URL}/packages/stop")
+    wait_for(ExecutionState.Completed)
+
+    for breakpoint in ("r1_ap1", "r1_ap2", "r2_ap1"):
+
+        rest.call(rest.Method.PUT, f"{URL}/packages/{PKG}/breakpoints", params={"breakpoints": [breakpoint]})
+        rest.call(rest.Method.PUT, f"{URL}/packages/{PKG}/debug")
+        wait_for(ExecutionState.Paused, pkg_id=PKG, aps={breakpoint})
+        rest.call(rest.Method.PUT, f"{URL}/packages/stop")
+        wait_for(ExecutionState.Completed)
+
+

src/python/arcor2_runtime/resources.py

@@ -173,9 +173,6 @@ def __init__(
             elif isinstance(model, Mesh):
                 package_info_event.data.collision_models.meshes.append(model)
 
-        # following steps might take some time, so let UIs know about the package as a first thing
-        print_event(package_info_event)
-
         # in order to prepare a clean environment (clears all configurations and all collisions)
         if self.interact_with_scene_service:
             scene_service.stop()
@@ -225,6 +222,9 @@ def __init__(
 
         self._stream_futures: list[concurrent.futures.Future] = []
 
+        # the event indicates that the package/script is fully initialized and ready to run
+        print_event(package_info_event)
+
     def read_project_data(self, file_name: str, cls: type[T]) -> T:
         try:
             with open(os.path.join("data", file_name + ".json")) as scene_file: