Skip to content

Ewoks events: sqlite3 bugs #344

Description

@woutdenolf

PR ewoks-kit/ewoksserver#247 revealed sqlite3 bugs in ewoksjob and ewoksutils related to concurrent reading and writing

ewokserver: test_get_execution_events_parallel - sqlite3 database is locked on the publishing side (error absorbed)
2026-07-14T05:37:39.0653139Z _______________ test_get_execution_events_parallel[/api/v1_1_0] _______________
2026-07-14T05:37:39.0653688Z 
2026-07-14T05:37:39.0655552Z local_exec_client = (<starlette.testclient.TestClient object at 0x0000013FFF08D210>, <ewoksserver.tests.socketio_test.SocketIOTestClient object at 0x0000013FFF08CB20>)
2026-07-14T05:37:39.0656847Z api_root = '/api/v1_1_0'
2026-07-14T05:37:39.0657152Z 
2026-07-14T05:37:39.0657480Z     def test_get_execution_events_parallel(local_exec_client, api_root):
2026-07-14T05:37:39.0658133Z         client, sclient = local_exec_client
2026-07-14T05:37:39.0658585Z     
2026-07-14T05:37:39.0658944Z         _, expected = get_graph("demo")
2026-07-14T05:37:39.0659417Z         nevents = 0
2026-07-14T05:37:39.0659835Z         nevents_per_exec = 2 * (len(expected) + 2)
2026-07-14T05:37:39.0660357Z     
2026-07-14T05:37:39.0660727Z         # Test no events (nothing has been executed)
2026-07-14T05:37:39.0661663Z         jobs = client.get(f"{api_root}/execution/events").json()["jobs"]
2026-07-14T05:37:39.0662535Z         assert not jobs
2026-07-14T05:37:39.0662909Z     
2026-07-14T05:37:39.0663314Z         # Execute workflows in parallel
2026-07-14T05:37:39.0663806Z         nruns = 3
2026-07-14T05:37:39.0664068Z         for _ in range(nruns):
2026-07-14T05:37:39.0664350Z             response = client.post(
2026-07-14T05:37:39.0664657Z                 f"{api_root}/execute/demo",
2026-07-14T05:37:39.0665105Z                 json={"execute_arguments": {"inputs": [{"name": "delay", "value": 0.1}]}},
2026-07-14T05:37:39.0665507Z             )
2026-07-14T05:37:39.0665746Z             data = response.json()
2026-07-14T05:37:39.0666069Z             assert response.status_code == 200, data
2026-07-14T05:37:39.0666393Z             nevents += nevents_per_exec
2026-07-14T05:37:39.0666694Z     
2026-07-14T05:37:39.0666937Z         # Get events from Socket.IO and REST API
2026-07-14T05:37:39.0667320Z >       events_socketio = get_events(api_root, sclient, nevents)
2026-07-14T05:37:39.0667603Z 
2026-07-14T05:37:39.0667831Z src\ewoksserver\tests\test_events.py:126: 
2026-07-14T05:37:39.0668226Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2026-07-14T05:37:39.0668460Z 
2026-07-14T05:37:39.0668589Z api_root = '/api/v1_1_0'
2026-07-14T05:37:39.0669033Z sclient = <ewoksserver.tests.socketio_test.SocketIOTestClient object at 0x0000013FFF08CB20>
2026-07-14T05:37:39.0669514Z nevents = 54, timeout = 10
2026-07-14T05:37:39.0669692Z 
2026-07-14T05:37:39.0669867Z     def get_events(api_root, sclient, nevents, timeout=10):
2026-07-14T05:37:39.0670214Z         t0 = time.time()
2026-07-14T05:37:39.0670469Z         events = list()
2026-07-14T05:37:39.0670716Z         while True:
2026-07-14T05:37:39.0670977Z             for event in sclient.get_events():
2026-07-14T05:37:39.0671514Z                 if "/v1" in api_root and "engine" in event_utils.FIELD_TYPES:
2026-07-14T05:37:39.0672145Z                     event["binding"] = event.pop("engine")
2026-07-14T05:37:39.0672499Z                 events.append(event)
2026-07-14T05:37:39.0672794Z             if len(events) == nevents:
2026-07-14T05:37:39.0673087Z                 break
2026-07-14T05:37:39.0673368Z             time.sleep(0.1)
2026-07-14T05:37:39.0673873Z             if time.time() - t0 > timeout:
2026-07-14T05:37:39.0674252Z                 received = "\n".join(_event_summary(event) for event in events)
2026-07-14T05:37:39.0674639Z >               raise TimeoutError(
2026-07-14T05:37:39.0675050Z                     f"Received {len(events)} instead of {nevents} events:\n{received}"
2026-07-14T05:37:39.0675434Z                 )
2026-07-14T05:37:39.0675727Z E               TimeoutError: Received 41 instead of 54 events:
2026-07-14T05:37:39.0676065Z E               job start
2026-07-14T05:37:39.0676334Z E               workflow start
2026-07-14T05:37:39.0676635Z E               node start (task0)
2026-07-14T05:37:39.0676920Z E               node end (task0)
2026-07-14T05:37:39.0677203Z E               node start (task2)
2026-07-14T05:37:39.0677486Z E               job start
2026-07-14T05:37:39.0677898Z E               job start
2026-07-14T05:37:39.0678191Z E               workflow start
2026-07-14T05:37:39.0678456Z E               workflow start
2026-07-14T05:37:39.0678724Z E               node start (task0)
2026-07-14T05:37:39.0678998Z E               node start (task0)
2026-07-14T05:37:39.0679259Z E               node end (task0)
2026-07-14T05:37:39.0679560Z E               node start (task2)
2026-07-14T05:37:39.0679835Z E               node end (task0)
2026-07-14T05:37:39.0680133Z E               node start (task2)
2026-07-14T05:37:39.0680598Z E               node end (task2)
2026-07-14T05:37:39.0680876Z E               node start (task1)
2026-07-14T05:37:39.0681582Z E               node end (task1)
2026-07-14T05:37:39.0681851Z E               node start (task4)
2026-07-14T05:37:39.0682125Z E               node end (task4)
2026-07-14T05:37:39.0682552Z E               node start (task3)
2026-07-14T05:37:39.0682826Z E               node end (task3)
2026-07-14T05:37:39.0683104Z E               node start (task5)
2026-07-14T05:37:39.0683381Z E               node end (task5)
2026-07-14T05:37:39.0683651Z E               node start (task6)
2026-07-14T05:37:39.0683933Z E               node end (task6)
2026-07-14T05:37:39.0684189Z E               workflow end
2026-07-14T05:37:39.0684455Z E               job end
2026-07-14T05:37:39.0684736Z E               node end (task2)
2026-07-14T05:37:39.0685322Z E               node start (task1)
2026-07-14T05:37:39.0685738Z E               node end (task1)
2026-07-14T05:37:39.0686163Z E               node start (task4)
2026-07-14T05:37:39.0686604Z E               node end (task4)
2026-07-14T05:37:39.0687061Z E               node start (task3)
2026-07-14T05:37:39.0687525Z E               node end (task3)
2026-07-14T05:37:39.0687915Z E               node start (task5)
2026-07-14T05:37:39.0688384Z E               node end (task5)
2026-07-14T05:37:39.0688767Z E               node start (task6)
2026-07-14T05:37:39.0689046Z E               node end (task6)
2026-07-14T05:37:39.0689313Z E               workflow end
2026-07-14T05:37:39.0689563Z E               job end
2026-07-14T05:37:39.0689732Z 
2026-07-14T05:37:39.0689881Z src\ewoksserver\tests\test_execute.py:204: TimeoutError
2026-07-14T05:37:39.0690319Z ----------------------------- Captured log setup ------------------------------
2026-07-14T05:37:39.0690869Z WARNING  ewoksserver.app.lifespan:lifespan.py:84 Discovered workflows not used yet
2026-07-14T05:37:39.0691399Z ---------------------------- Captured stderr call -----------------------------
2026-07-14T05:37:39.0691782Z --- Logging error ---
2026-07-14T05:37:39.0691952Z 
2026-07-14T05:37:39.0692062Z Traceback (most recent call last):
2026-07-14T05:37:39.0692250Z 
2026-07-14T05:37:39.0698318Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoksutils\logging_utils\sqlite3.py", line 74, in _sql_query
2026-07-14T05:37:39.0699453Z 
2026-07-14T05:37:39.0699578Z     conn.execute(sql, parameters)
2026-07-14T05:37:39.0699797Z 
2026-07-14T05:37:39.0699955Z sqlite3.OperationalError: database is locked
2026-07-14T05:37:39.0700162Z 
2026-07-14T05:37:39.0700166Z 
2026-07-14T05:37:39.0700171Z 
2026-07-14T05:37:39.0700377Z The above exception was the direct cause of the following exception:
2026-07-14T05:37:39.0700676Z 
2026-07-14T05:37:39.0700681Z 
2026-07-14T05:37:39.0700685Z 
2026-07-14T05:37:39.0700787Z Traceback (most recent call last):
2026-07-14T05:37:39.0700982Z 
2026-07-14T05:37:39.0701413Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoksutils\logging_utils\connection.py", line 78, in emit
2026-07-14T05:37:39.0701859Z 
2026-07-14T05:37:39.0701990Z     self._send_serialized_record(s)
2026-07-14T05:37:39.0702178Z 
2026-07-14T05:37:39.0702608Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoksutils\logging_utils\sqlite3.py", line 52, in _send_serialized_record
2026-07-14T05:37:39.0703144Z 
2026-07-14T05:37:39.0703299Z     self._sql_query(self._insert_row_query, values)
2026-07-14T05:37:39.0703700Z 
2026-07-14T05:37:39.0704114Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoksutils\logging_utils\sqlite3.py", line 80, in _sql_query
2026-07-14T05:37:39.0704648Z 
2026-07-14T05:37:39.0704923Z     raise TimeoutError("cannot execute SQL query") from exception
2026-07-14T05:37:39.0705341Z 
2026-07-14T05:37:39.0705482Z TimeoutError: cannot execute SQL query
2026-07-14T05:37:39.0705663Z 
2026-07-14T05:37:39.0705775Z Call stack:
2026-07-14T05:37:39.0705889Z 
2026-07-14T05:37:39.0706053Z   File "<string>", line 1, in <module>
2026-07-14T05:37:39.0706257Z 
2026-07-14T05:37:39.0706594Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\multiprocessing\spawn.py", line 116, in spawn_main
2026-07-14T05:37:39.0706962Z 
2026-07-14T05:37:39.0707222Z     exitcode = _main(fd, parent_sentinel)
2026-07-14T05:37:39.0707439Z 
2026-07-14T05:37:39.0707736Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\multiprocessing\spawn.py", line 129, in _main
2026-07-14T05:37:39.0708123Z 
2026-07-14T05:37:39.0708265Z     return self._bootstrap(parent_sentinel)
2026-07-14T05:37:39.0708458Z 
2026-07-14T05:37:39.0708785Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\multiprocessing\process.py", line 314, in _bootstrap
2026-07-14T05:37:39.0709195Z 
2026-07-14T05:37:39.0709282Z     self.run()
2026-07-14T05:37:39.0709427Z 
2026-07-14T05:37:39.0709742Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\multiprocessing\process.py", line 108, in run
2026-07-14T05:37:39.0710103Z 
2026-07-14T05:37:39.0710250Z     self._target(*self._args, **self._kwargs)
2026-07-14T05:37:39.0710477Z 
2026-07-14T05:37:39.0710813Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\concurrent\futures\process.py", line 246, in _process_worker
2026-07-14T05:37:39.0711243Z 
2026-07-14T05:37:39.0711412Z     r = call_item.fn(*call_item.args, **call_item.kwargs)
2026-07-14T05:37:39.0711633Z 
2026-07-14T05:37:39.0712153Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoks\bindings.py", line 80, in execute_graph
2026-07-14T05:37:39.0712587Z 
2026-07-14T05:37:39.0712697Z     result = engine_api.execute_graph(
2026-07-14T05:37:39.0712909Z 
2026-07-14T05:37:39.0713284Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\engine.py", line 33, in execute_graph
2026-07-14T05:37:39.0713706Z 
2026-07-14T05:37:39.0713843Z     return bindings.execute_graph(
2026-07-14T05:37:39.0714038Z 
2026-07-14T05:37:39.0714371Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\events\contexts.py", line 26, in wrapper
2026-07-14T05:37:39.0714811Z 
2026-07-14T05:37:39.0714967Z     return method(*args, execinfo=execinfo, **kw)
2026-07-14T05:37:39.0715180Z 
2026-07-14T05:37:39.0715558Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\bindings.py", line 92, in execute_graph
2026-07-14T05:37:39.0716001Z 
2026-07-14T05:37:39.0716116Z     return sequential.execute_graph(
2026-07-14T05:37:39.0716326Z 
2026-07-14T05:37:39.0716752Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\graph\execute\sequential.py", line 136, in execute_graph
2026-07-14T05:37:39.0717226Z 
2026-07-14T05:37:39.0717344Z     task.execute(
2026-07-14T05:37:39.0717500Z 
2026-07-14T05:37:39.0717806Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\task.py", line 742, in execute
2026-07-14T05:37:39.0718220Z 
2026-07-14T05:37:39.0718349Z     with ExitStack() as stack:
2026-07-14T05:37:39.0718561Z 
2026-07-14T05:37:39.0718986Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\contextlib.py", line 561, in __exit__
2026-07-14T05:37:39.0719831Z 
2026-07-14T05:37:39.0719974Z     if cb(*exc_details):
2026-07-14T05:37:39.0720168Z 
2026-07-14T05:37:39.0720475Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\contextlib.py", line 142, in __exit__
2026-07-14T05:37:39.0720810Z 
2026-07-14T05:37:39.0721068Z     next(self.gen)
2026-07-14T05:37:39.0721232Z 
2026-07-14T05:37:39.0721577Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\task.py", line 806, in _send_task_events
2026-07-14T05:37:39.0722019Z 
2026-07-14T05:37:39.0722145Z     self._send_send_event()
2026-07-14T05:37:39.0722298Z 
2026-07-14T05:37:39.0722664Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\task.py", line 833, in _send_send_event
2026-07-14T05:37:39.0723098Z 
2026-07-14T05:37:39.0723250Z     self._send_event(event="end", exception=self.exception)
2026-07-14T05:37:39.0723514Z 
2026-07-14T05:37:39.0723892Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\task.py", line 811, in _send_event
2026-07-14T05:37:39.0724289Z 
2026-07-14T05:37:39.0724582Z     events.send_task_event(execinfo=self.__execinfo, **kwargs)
2026-07-14T05:37:39.0724851Z 
2026-07-14T05:37:39.0725235Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\events\send_events.py", line 32, in send_task_event
2026-07-14T05:37:39.0725718Z 
2026-07-14T05:37:39.0725856Z     _send_event(*logargs, **logkwargs)
2026-07-14T05:37:39.0726040Z 
2026-07-14T05:37:39.0726439Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\events\send_events.py", line 251, in _send_event
2026-07-14T05:37:39.0726899Z 
2026-07-14T05:37:39.0727035Z     global_state.send(msg, *args, extra=extra, **kw)
2026-07-14T05:37:39.0727277Z 
2026-07-14T05:37:39.0727642Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\events\global_state.py", line 40, in send
2026-07-14T05:37:39.0728087Z 
2026-07-14T05:37:39.0728191Z     logger.log(level, *args, **kw)
2026-07-14T05:37:39.0728392Z 
2026-07-14T05:37:39.0728666Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\logging\__init__.py", line 1547, in log
2026-07-14T05:37:39.0729044Z 
2026-07-14T05:37:39.0729189Z     self._log(level, msg, args, **kwargs)
2026-07-14T05:37:39.0729379Z 
2026-07-14T05:37:39.0729697Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\logging\__init__.py", line 1624, in _log
2026-07-14T05:37:39.0730065Z 
2026-07-14T05:37:39.0730162Z     self.handle(record)
2026-07-14T05:37:39.0730337Z 
2026-07-14T05:37:39.0730640Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\logging\__init__.py", line 1634, in handle
2026-07-14T05:37:39.0730979Z 
2026-07-14T05:37:39.0731105Z     self.callHandlers(record)
2026-07-14T05:37:39.0731297Z 
2026-07-14T05:37:39.0731587Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\logging\__init__.py", line 1696, in callHandlers
2026-07-14T05:37:39.0731976Z 
2026-07-14T05:37:39.0732096Z     hdlr.handle(record)
2026-07-14T05:37:39.0732230Z 
2026-07-14T05:37:39.0732523Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\logging\__init__.py", line 968, in handle
2026-07-14T05:37:39.0732893Z 
2026-07-14T05:37:39.0732982Z     self.emit(record)
2026-07-14T05:37:39.0733149Z 
2026-07-14T05:37:39.0733550Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoksutils\logging_utils\connection.py", line 80, in emit
2026-07-14T05:37:39.0734185Z 
2026-07-14T05:37:39.0734369Z     self.handleError(record)
2026-07-14T05:37:39.0734598Z 
2026-07-14T05:37:39.0734750Z Message: '[job %r] [workflow %r] [node %r] [task %r] %s'
2026-07-14T05:37:39.0734996Z 
2026-07-14T05:37:39.0735428Z Arguments: ('1abb750b-2e2a-4251-9c01-691d763df266', 'demo', 'task2', 'ewokscore.tests.examples.tasks.sumtask.SumTask', 'task finished')
2026-07-14T05:37:39.0735903Z 
2026-07-14T05:37:39.0736007Z --- Logging error ---
2026-07-14T05:37:39.0736147Z 
2026-07-14T05:37:39.0736283Z Traceback (most recent call last):
2026-07-14T05:37:39.0736483Z 
2026-07-14T05:37:39.0736871Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoksutils\logging_utils\sqlite3.py", line 74, in _sql_query
2026-07-14T05:37:39.0737350Z 
2026-07-14T05:37:39.0737484Z     conn.execute(sql, parameters)
2026-07-14T05:37:39.0737815Z 
2026-07-14T05:37:39.0737971Z sqlite3.OperationalError: database is locked
2026-07-14T05:37:39.0738200Z 
2026-07-14T05:37:39.0738204Z 
2026-07-14T05:37:39.0738208Z 
2026-07-14T05:37:39.0738395Z The above exception was the direct cause of the following exception:
2026-07-14T05:37:39.0738698Z 
2026-07-14T05:37:39.0738702Z 
2026-07-14T05:37:39.0738706Z 
2026-07-14T05:37:39.0738841Z Traceback (most recent call last):
2026-07-14T05:37:39.0739010Z 
2026-07-14T05:37:39.0739705Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoksutils\logging_utils\connection.py", line 78, in emit
2026-07-14T05:37:39.0740186Z 
2026-07-14T05:37:39.0740296Z     self._send_serialized_record(s)
2026-07-14T05:37:39.0740498Z 
2026-07-14T05:37:39.0740949Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoksutils\logging_utils\sqlite3.py", line 52, in _send_serialized_record
2026-07-14T05:37:39.0741542Z 
2026-07-14T05:37:39.0741709Z     self._sql_query(self._insert_row_query, values)
2026-07-14T05:37:39.0741957Z 
2026-07-14T05:37:39.0742330Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoksutils\logging_utils\sqlite3.py", line 80, in _sql_query
2026-07-14T05:37:39.0742808Z 
2026-07-14T05:37:39.0743002Z     raise TimeoutError("cannot execute SQL query") from exception
2026-07-14T05:37:39.0743250Z 
2026-07-14T05:37:39.0743384Z TimeoutError: cannot execute SQL query
2026-07-14T05:37:39.0743588Z 
2026-07-14T05:37:39.0743676Z Call stack:
2026-07-14T05:37:39.0743821Z 
2026-07-14T05:37:39.0743969Z   File "<string>", line 1, in <module>
2026-07-14T05:37:39.0744144Z 
2026-07-14T05:37:39.0744483Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\multiprocessing\spawn.py", line 116, in spawn_main
2026-07-14T05:37:39.0744892Z 
2026-07-14T05:37:39.0744999Z     exitcode = _main(fd, parent_sentinel)
2026-07-14T05:37:39.0745224Z 
2026-07-14T05:37:39.0745540Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\multiprocessing\spawn.py", line 129, in _main
2026-07-14T05:37:39.0745899Z 
2026-07-14T05:37:39.0746044Z     return self._bootstrap(parent_sentinel)
2026-07-14T05:37:39.0746268Z 
2026-07-14T05:37:39.0746578Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\multiprocessing\process.py", line 314, in _bootstrap
2026-07-14T05:37:39.0746992Z 
2026-07-14T05:37:39.0747105Z     self.run()
2026-07-14T05:37:39.0747230Z 
2026-07-14T05:37:39.0747540Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\multiprocessing\process.py", line 108, in run
2026-07-14T05:37:39.0747908Z 
2026-07-14T05:37:39.0748014Z     self._target(*self._args, **self._kwargs)
2026-07-14T05:37:39.0748221Z 
2026-07-14T05:37:39.0748579Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\concurrent\futures\process.py", line 246, in _process_worker
2026-07-14T05:37:39.0748981Z 
2026-07-14T05:37:39.0749252Z     r = call_item.fn(*call_item.args, **call_item.kwargs)
2026-07-14T05:37:39.0749644Z 
2026-07-14T05:37:39.0749999Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoks\bindings.py", line 80, in execute_graph
2026-07-14T05:37:39.0750446Z 
2026-07-14T05:37:39.0750579Z     result = engine_api.execute_graph(
2026-07-14T05:37:39.0750758Z 
2026-07-14T05:37:39.0751123Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\engine.py", line 33, in execute_graph
2026-07-14T05:37:39.0751585Z 
2026-07-14T05:37:39.0751718Z     return bindings.execute_graph(
2026-07-14T05:37:39.0751958Z 
2026-07-14T05:37:39.0752301Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\events\contexts.py", line 26, in wrapper
2026-07-14T05:37:39.0752747Z 
2026-07-14T05:37:39.0752888Z     return method(*args, execinfo=execinfo, **kw)
2026-07-14T05:37:39.0753099Z 
2026-07-14T05:37:39.0753472Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\bindings.py", line 92, in execute_graph
2026-07-14T05:37:39.0753920Z 
2026-07-14T05:37:39.0754149Z     return sequential.execute_graph(
2026-07-14T05:37:39.0754367Z 
2026-07-14T05:37:39.0754791Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\graph\execute\sequential.py", line 136, in execute_graph
2026-07-14T05:37:39.0755261Z 
2026-07-14T05:37:39.0755378Z     task.execute(
2026-07-14T05:37:39.0755531Z 
2026-07-14T05:37:39.0755835Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\task.py", line 754, in execute
2026-07-14T05:37:39.0756246Z 
2026-07-14T05:37:39.0756381Z     _ = stack.enter_context(ctx)
2026-07-14T05:37:39.0756549Z 
2026-07-14T05:37:39.0756850Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\contextlib.py", line 492, in enter_context
2026-07-14T05:37:39.0757224Z 
2026-07-14T05:37:39.0757408Z     result = _cm_type.__enter__(cm)
2026-07-14T05:37:39.0757606Z 
2026-07-14T05:37:39.0757908Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\contextlib.py", line 135, in __enter__
2026-07-14T05:37:39.0758243Z 
2026-07-14T05:37:39.0758372Z     return next(self.gen)
2026-07-14T05:37:39.0758551Z 
2026-07-14T05:37:39.0758889Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\task.py", line 802, in _send_task_events
2026-07-14T05:37:39.0759326Z 
2026-07-14T05:37:39.0759769Z     self._send_start_event()
2026-07-14T05:37:39.0759935Z 
2026-07-14T05:37:39.0760309Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\task.py", line 825, in _send_start_event
2026-07-14T05:37:39.0760746Z 
2026-07-14T05:37:39.0760838Z     self._send_event(
2026-07-14T05:37:39.0760998Z 
2026-07-14T05:37:39.0761339Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\task.py", line 811, in _send_event
2026-07-14T05:37:39.0761741Z 
2026-07-14T05:37:39.0761929Z     events.send_task_event(execinfo=self.__execinfo, **kwargs)
2026-07-14T05:37:39.0762196Z 
2026-07-14T05:37:39.0762577Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\events\send_events.py", line 32, in send_task_event
2026-07-14T05:37:39.0763050Z 
2026-07-14T05:37:39.0763178Z     _send_event(*logargs, **logkwargs)
2026-07-14T05:37:39.0763477Z 
2026-07-14T05:37:39.0764008Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\events\send_events.py", line 251, in _send_event
2026-07-14T05:37:39.0764485Z 
2026-07-14T05:37:39.0764627Z     global_state.send(msg, *args, extra=extra, **kw)
2026-07-14T05:37:39.0764874Z 
2026-07-14T05:37:39.0765249Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewokscore\events\global_state.py", line 40, in send
2026-07-14T05:37:39.0765697Z 
2026-07-14T05:37:39.0765801Z     logger.log(level, *args, **kw)
2026-07-14T05:37:39.0766004Z 
2026-07-14T05:37:39.0766274Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\logging\__init__.py", line 1547, in log
2026-07-14T05:37:39.0766642Z 
2026-07-14T05:37:39.0766776Z     self._log(level, msg, args, **kwargs)
2026-07-14T05:37:39.0766962Z 
2026-07-14T05:37:39.0767256Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\logging\__init__.py", line 1624, in _log
2026-07-14T05:37:39.0767616Z 
2026-07-14T05:37:39.0767710Z     self.handle(record)
2026-07-14T05:37:39.0767876Z 
2026-07-14T05:37:39.0768174Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\logging\__init__.py", line 1634, in handle
2026-07-14T05:37:39.0768517Z 
2026-07-14T05:37:39.0768651Z     self.callHandlers(record)
2026-07-14T05:37:39.0768843Z 
2026-07-14T05:37:39.0769133Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\logging\__init__.py", line 1696, in callHandlers
2026-07-14T05:37:39.0769517Z 
2026-07-14T05:37:39.0769637Z     hdlr.handle(record)
2026-07-14T05:37:39.0769773Z 
2026-07-14T05:37:39.0770086Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\logging\__init__.py", line 968, in handle
2026-07-14T05:37:39.0770452Z 
2026-07-14T05:37:39.0770542Z     self.emit(record)
2026-07-14T05:37:39.0770822Z 
2026-07-14T05:37:39.0771218Z   File "C:\hostedtoolcache\windows\Python\3.10.11\x64\lib\site-packages\ewoksutils\logging_utils\connection.py", line 80, in emit
2026-07-14T05:37:39.0771673Z 
2026-07-14T05:37:39.0771816Z     self.handleError(record)
2026-07-14T05:37:39.0772000Z 
2026-07-14T05:37:39.0772143Z Message: '[job %r] [workflow %r] [node %r] [task %r] %s'
2026-07-14T05:37:39.0772393Z 
2026-07-14T05:37:39.2210447Z Arguments: ('1abb750b-2e2a-4251-9c01-691d763df266', 'demo', 'task1', 'ewokscore.tests.examples.tasks.sumtask.SumTask', 'task started')
2026-07-14T05:37:39.2211543Z 
ewokserver: test_new_client_new_events - sqlite3 database is locked on the client side
2026-07-14T05:37:39.2211823Z ___________________ test_new_client_new_events[/api/v1_1_0] ___________________
2026-07-14T05:37:39.2212114Z 
2026-07-14T05:37:39.2212623Z local_exec_client = (<starlette.testclient.TestClient object at 0x0000013F8181FD60>, <ewoksserver.tests.socketio_test.SocketIOTestClient object at 0x0000013F815AE500>)
2026-07-14T05:37:39.2213565Z api_root = '/api/v1_1_0'
2026-07-14T05:37:39.2213724Z 
2026-07-14T05:37:39.2213875Z     def test_new_client_new_events(local_exec_client, api_root):
2026-07-14T05:37:39.2214224Z         client, sclient = local_exec_client
2026-07-14T05:37:39.2214515Z >       _test_execute(api_root, client, sclient)
2026-07-14T05:37:39.2214702Z 
2026-07-14T05:37:39.2214819Z src\ewoksserver\tests\test_execute.py:19: 
2026-07-14T05:37:39.2215130Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2026-07-14T05:37:39.2215497Z src\ewoksserver\tests\test_execute.py:178: in _test_execute
2026-07-14T05:37:39.2215846Z     events = get_events(api_root, sclient, n)
2026-07-14T05:37:39.2216155Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2026-07-14T05:37:39.2216376Z 
2026-07-14T05:37:39.2216462Z api_root = '/api/v1_1_0'
2026-07-14T05:37:39.2216846Z sclient = <ewoksserver.tests.socketio_test.SocketIOTestClient object at 0x0000013F815AE500>
2026-07-14T05:37:39.2217286Z nevents = 16, timeout = 10
2026-07-14T05:37:39.2217432Z 
2026-07-14T05:37:39.2217579Z     def get_events(api_root, sclient, nevents, timeout=10):
2026-07-14T05:37:39.2217876Z         t0 = time.time()
2026-07-14T05:37:39.2218090Z         events = list()
2026-07-14T05:37:39.2218310Z         while True:
2026-07-14T05:37:39.2218531Z             for event in sclient.get_events():
2026-07-14T05:37:39.2218879Z                 if "/v1" in api_root and "engine" in event_utils.FIELD_TYPES:
2026-07-14T05:37:39.2219239Z                     event["binding"] = event.pop("engine")
2026-07-14T05:37:39.2219535Z                 events.append(event)
2026-07-14T05:37:39.2219804Z             if len(events) == nevents:
2026-07-14T05:37:39.2220045Z                 break
2026-07-14T05:37:39.2220250Z             time.sleep(0.1)
2026-07-14T05:37:39.2220498Z             if time.time() - t0 > timeout:
2026-07-14T05:37:39.2220829Z                 received = "\n".join(_event_summary(event) for event in events)
2026-07-14T05:37:39.2221202Z >               raise TimeoutError(
2026-07-14T05:37:39.2221543Z                     f"Received {len(events)} instead of {nevents} events:\n{received}"
2026-07-14T05:37:39.2221883Z                 )
2026-07-14T05:37:39.2222132Z E               TimeoutError: Received 11 instead of 16 events:
2026-07-14T05:37:39.2222440Z E               job start
2026-07-14T05:37:39.2222654Z E               workflow start
2026-07-14T05:37:39.2222885Z E               node start (task1)
2026-07-14T05:37:39.2223122Z E               node end (task1)
2026-07-14T05:37:39.2223359Z E               node start (task2)
2026-07-14T05:37:39.2223595Z E               node end (task2)
2026-07-14T05:37:39.2223820Z E               node start (task3)
2026-07-14T05:37:39.2224052Z E               node end (task3)
2026-07-14T05:37:39.2224275Z E               node start (task4)
2026-07-14T05:37:39.2224505Z E               node end (task4)
2026-07-14T05:37:39.2224735Z E               node start (task5)
2026-07-14T05:37:39.2224876Z 
2026-07-14T05:37:39.2225189Z src\ewoksserver\tests\test_execute.py:204: TimeoutError

So both projects require fixes for concurrent reading/writing of sqlite db. And ewokscore as well because the base ewoks event handler needs changes.

Metadata

Metadata

Assignees

Labels

bugSomething isn't working

Type

No type

Fields

No fields configured for issues without a type.

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions