all actors already log the trigger call
Using the example from svensson/bes!6.
Before this MR the python actor output is logged twice
2024-07-06 23:37:57,280 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] ['/home/denolf/projects/bes/src/bes/bin/run_ppf_json.py', '--inData', '{"a": 10}', 'test_graph']
2024-07-06 23:37:57,281 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] ********************************************************************************
2024-07-06 23:37:57,281 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] Before json file search
2024-07-06 23:37:57,282 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] After json file search
2024-07-06 23:37:57,282 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] Path graph file: /home/denolf/projects/bes/src/bes/flows/test_graph.json
2024-07-06 23:37:57,282 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] Time last modified json file: 2024-07-06 23:37:56
2024-07-06 23:37:57,282 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] Before load_graph
2024-07-06 23:37:57,282 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] Graph has no "schema_version": assume version "1.0"
2024-07-06 23:37:57,283 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] After load_graph
2024-07-06 23:37:57,283 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] Writing graph to path: /var/log/bes/pypushflow/test_graph.pickle
2024-07-06 23:37:57,283 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] ********************************************************************************
2024-07-06 23:37:57,283 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] Before execute_graph
2024-07-06 23:37:57,283 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [job '85a3671b-3772-44b5-8b33-fa3d4346d8ab'] job started
2024-07-06 23:37:57,283 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph]
Instantiate new workflow 'test_graph'
2024-07-06 23:37:57,283 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] add reference to actor 'Start'
2024-07-06 23:37:57,283 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] add reference to actor 'Stop'
2024-07-06 23:37:57,283 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] add reference to actor 'Stop on error'
2024-07-06 23:37:57,283 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<ErrorHandler> Stop on error] connect to actor 'Stop'
2024-07-06 23:37:57,283 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] add reference to actor '1'
2024-07-06 23:37:57,283 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<EwoksPythonActor> 1] connect to error handler 'Stop on error'
2024-07-06 23:37:57,284 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<StartActor> Start] connect to actor '1'
2024-07-06 23:37:57,284 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<EwoksPythonActor> 1] connect to actor 'Stop'
2024-07-06 23:37:57,284 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [job '85a3671b-3772-44b5-8b33-fa3d4346d8ab'] [workflow 'test_graph'] workflow started
2024-07-06 23:37:57,284 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] pypushflow concurrency: scaling
2024-07-06 23:37:57,284 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] Execution pool ScalingPool ({'max_workers': None, 'pool_type': None})
2024-07-06 23:37:57,284 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] Thread started for 'Start' (1 threads running)
2024-07-06 23:37:57,284 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<StartActor> Start] triggered with inData =
{'_noinput': {'execinfo': {'contexts': {'job': ['85a3671b-3772-44b5-8b33-fa3d4346d8ab'],
'workflow': ['test_graph']},
'engine': 'ppf',
'host_name': 'ideapad3',
'job_id': '85a3671b-3772-44b5-8b33-fa3d4346d8ab',
'process_id': 72724,
'user_name': 'denolf',
'workflow_id': 'test_graph'},
'varinfo': None},
'a': 10}
2024-07-06 23:37:57,284 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<StartActor> Start] started
2024-07-06 23:37:57,284 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<StartActor> Start] finished
2024-07-06 23:37:57,284 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] Thread started for '1' (2 threads running)
2024-07-06 23:37:57,285 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<EwoksPythonActor> 1] triggered with inData =
{'_noinput': {'execinfo': {'contexts': {'job': ['85a3671b-3772-44b5-8b33-fa3d4346d8ab'],
'workflow': ['test_graph']},
'engine': 'ppf',
'host_name': 'ideapad3',
'job_id': '85a3671b-3772-44b5-8b33-fa3d4346d8ab',
'process_id': 72724,
'user_name': 'denolf',
'workflow_id': 'test_graph'},
'node_attrs': {'task_identifier': 'test.run',
'task_type': 'ppfmethod'},
'node_id': '1',
'varinfo': None},
'a': 10}
2024-07-06 23:37:57,285 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<EwoksPythonActor> 1] started
2024-07-06 23:37:57,285 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<EwoksPythonActor> 1] asynchronous execution of 'ewoksppf.ppfrunscript.run'
2024-07-06 23:37:57,285 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] pypushflow concurrency: process
2024-07-06 23:37:57,285 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] pypushflow process pool context: 'NoneType'
2024-07-06 23:37:57,289 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] Thread ended for 'Start' (1 threads running)
2024-07-06 23:37:57,289 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<StopActor> Stop] wait for scheduler threads to be finished
2024-07-06 23:37:57,290 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [job '85a3671b-3772-44b5-8b33-fa3d4346d8ab'] [workflow 'test_graph'] [node '1'] [task 'test.run'] task started
2024-07-06 23:37:57,361 ERROR [85a3671b-3772-44b5-8b33-fa3d4346d8ab] THIS IS AN ERROR LOG
2024-07-06 23:37:57,361 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] THIS IS AN INFO LOG
2024-07-06 23:37:57,361 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] THIS IS AN DEBUG LOG
2024-07-06 23:37:57,363 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [job '85a3671b-3772-44b5-8b33-fa3d4346d8ab'] [workflow 'test_graph'] [node '1'] [task 'test.run'] task finished
2024-07-06 23:37:57,364 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<EwoksPythonActor> 1] finished
2024-07-06 23:37:57,364 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<EwoksPythonActor> 1] trigger actor 'Stop' with inData =
{'_noinput': {'execinfo': {'contexts': {'job': ['85a3671b-3772-44b5-8b33-fa3d4346d8ab'],
'workflow': ['test_graph']},
'engine': 'ppf',
'host_name': 'ideapad3',
'job_id': '85a3671b-3772-44b5-8b33-fa3d4346d8ab',
'process_id': 72724,
'user_name': 'denolf',
'workflow_id': 'test_graph'},
'node_attrs': {'task_identifier': 'test.run',
'task_type': 'ppfmethod'},
'node_id': '1',
'varinfo': None},
'_ppfdict': {'a': 10, 'b': 20}}
2024-07-06 23:37:57,364 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] Thread started for 'Stop' (2 threads running)
2024-07-06 23:37:57,365 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<StopActor> Stop] triggered with inData =
{'_noinput': {'execinfo': {'contexts': {'job': ['85a3671b-3772-44b5-8b33-fa3d4346d8ab'],
'workflow': ['test_graph']},
'engine': 'ppf',
'host_name': 'ideapad3',
'job_id': '85a3671b-3772-44b5-8b33-fa3d4346d8ab',
'process_id': 72724,
'user_name': 'denolf',
'workflow_id': 'test_graph'},
'node_attrs': {'task_identifier': 'test.run',
'task_type': 'ppfmethod'},
'node_id': '1',
'varinfo': None},
'_ppfdict': {'a': 10, 'b': 20}}
2024-07-06 23:37:57,365 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] Thread ended for 'Stop' (1 threads running)
2024-07-06 23:37:57,365 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] Thread ended for '1' (0 threads running)
2024-07-06 23:37:57,365 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<StopActor> Stop] scheduler threads are finished
2024-07-06 23:37:57,365 DEBUG [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [test_graph] [<StopActor> Stop] finished
2024-07-06 23:37:57,371 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [job '85a3671b-3772-44b5-8b33-fa3d4346d8ab'] [workflow 'test_graph'] workflow finished
2024-07-06 23:37:57,371 INFO [85a3671b-3772-44b5-8b33-fa3d4346d8ab] [job '85a3671b-3772-44b5-8b33-fa3d4346d8ab'] job finishedAfter this MR you only get one message per actor trigger
2024-07-06 23:35:33,649 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] ['/home/denolf/projects/bes/src/bes/bin/run_ppf_json.py', '--inData', '{"a": 10}', 'test_graph']
2024-07-06 23:35:33,650 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] ********************************************************************************
2024-07-06 23:35:33,650 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] Before json file search
2024-07-06 23:35:33,651 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] After json file search
2024-07-06 23:35:33,651 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] Path graph file: /home/denolf/projects/bes/src/bes/flows/test_graph.json
2024-07-06 23:35:33,651 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] Time last modified json file: 2024-07-06 23:35:33
2024-07-06 23:35:33,651 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] Before load_graph
2024-07-06 23:35:33,651 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] Graph has no "schema_version": assume version "1.0"
2024-07-06 23:35:33,652 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] After load_graph
2024-07-06 23:35:33,652 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] Writing graph to path: /var/log/bes/pypushflow/test_graph.pickle
2024-07-06 23:35:33,652 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] ********************************************************************************
2024-07-06 23:35:33,652 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] Before execute_graph
2024-07-06 23:35:33,652 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [job '2be80f44-d6c8-4188-9af6-4aacbe0e72bf'] job started
2024-07-06 23:35:33,652 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph]
Instantiate new workflow 'test_graph'
2024-07-06 23:35:33,652 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] add reference to actor 'Start'
2024-07-06 23:35:33,652 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] add reference to actor 'Stop'
2024-07-06 23:35:33,652 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] add reference to actor 'Stop on error'
2024-07-06 23:35:33,652 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<ErrorHandler> Stop on error] connect to actor 'Stop'
2024-07-06 23:35:33,652 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] add reference to actor '1'
2024-07-06 23:35:33,653 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<EwoksPythonActor> 1] connect to error handler 'Stop on error'
2024-07-06 23:35:33,653 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<StartActor> Start] connect to actor '1'
2024-07-06 23:35:33,653 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<EwoksPythonActor> 1] connect to actor 'Stop'
2024-07-06 23:35:33,653 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [job '2be80f44-d6c8-4188-9af6-4aacbe0e72bf'] [workflow 'test_graph'] workflow started
2024-07-06 23:35:33,653 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] pypushflow concurrency: scaling
2024-07-06 23:35:33,653 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] Execution pool ScalingPool ({'max_workers': None, 'pool_type': None})
2024-07-06 23:35:33,653 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] Thread started for 'Start' (1 threads running)
2024-07-06 23:35:33,653 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<StartActor> Start] triggered with inData =
{'_noinput': {'execinfo': {'contexts': {'job': ['2be80f44-d6c8-4188-9af6-4aacbe0e72bf'],
'workflow': ['test_graph']},
'engine': 'ppf',
'host_name': 'ideapad3',
'job_id': '2be80f44-d6c8-4188-9af6-4aacbe0e72bf',
'process_id': 72479,
'user_name': 'denolf',
'workflow_id': 'test_graph'},
'varinfo': None},
'a': 10}
2024-07-06 23:35:33,653 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<StartActor> Start] started
2024-07-06 23:35:33,653 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<StartActor> Start] finished
2024-07-06 23:35:33,653 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] Thread started for '1' (2 threads running)
2024-07-06 23:35:33,654 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<EwoksPythonActor> 1] triggered with inData =
{'_noinput': {'execinfo': {'contexts': {'job': ['2be80f44-d6c8-4188-9af6-4aacbe0e72bf'],
'workflow': ['test_graph']},
'engine': 'ppf',
'host_name': 'ideapad3',
'job_id': '2be80f44-d6c8-4188-9af6-4aacbe0e72bf',
'process_id': 72479,
'user_name': 'denolf',
'workflow_id': 'test_graph'},
'node_attrs': {'task_identifier': 'test.run',
'task_type': 'ppfmethod'},
'node_id': '1',
'varinfo': None},
'a': 10}
2024-07-06 23:35:33,654 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<EwoksPythonActor> 1] started
2024-07-06 23:35:33,654 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<EwoksPythonActor> 1] asynchronous execution of 'ewoksppf.ppfrunscript.run'
2024-07-06 23:35:33,654 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] pypushflow concurrency: process
2024-07-06 23:35:33,654 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] pypushflow process pool context: 'NoneType'
2024-07-06 23:35:33,657 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] Thread ended for 'Start' (1 threads running)
2024-07-06 23:35:33,658 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<StopActor> Stop] wait for scheduler threads to be finished
2024-07-06 23:35:33,659 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [job '2be80f44-d6c8-4188-9af6-4aacbe0e72bf'] [workflow 'test_graph'] [node '1'] [task 'test.run'] task started
2024-07-06 23:35:33,727 ERROR [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] THIS IS AN ERROR LOG
2024-07-06 23:35:33,727 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] THIS IS AN INFO LOG
2024-07-06 23:35:33,727 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] THIS IS AN DEBUG LOG
2024-07-06 23:35:33,730 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [job '2be80f44-d6c8-4188-9af6-4aacbe0e72bf'] [workflow 'test_graph'] [node '1'] [task 'test.run'] task finished
2024-07-06 23:35:33,730 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<EwoksPythonActor> 1] finished
2024-07-06 23:35:33,730 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] Thread started for 'Stop' (2 threads running)
2024-07-06 23:35:33,731 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<StopActor> Stop] triggered with inData =
{'_noinput': {'execinfo': {'contexts': {'job': ['2be80f44-d6c8-4188-9af6-4aacbe0e72bf'],
'workflow': ['test_graph']},
'engine': 'ppf',
'host_name': 'ideapad3',
'job_id': '2be80f44-d6c8-4188-9af6-4aacbe0e72bf',
'process_id': 72479,
'user_name': 'denolf',
'workflow_id': 'test_graph'},
'node_attrs': {'task_identifier': 'test.run',
'task_type': 'ppfmethod'},
'node_id': '1',
'varinfo': None},
'_ppfdict': {'a': 10, 'b': 20}}
2024-07-06 23:35:33,731 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] Thread ended for 'Stop' (1 threads running)
2024-07-06 23:35:33,731 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] Thread ended for '1' (0 threads running)
2024-07-06 23:35:33,731 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<StopActor> Stop] scheduler threads are finished
2024-07-06 23:35:33,731 DEBUG [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [test_graph] [<StopActor> Stop] finished
2024-07-06 23:35:33,737 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [job '2be80f44-d6c8-4188-9af6-4aacbe0e72bf'] [workflow 'test_graph'] workflow finished
2024-07-06 23:35:33,737 INFO [2be80f44-d6c8-4188-9af6-4aacbe0e72bf] [job '2be80f44-d6c8-4188-9af6-4aacbe0e72bf'] job finishedEdited by Wout De Nolf