search

golemfactory / dapp-runner

GNU Lesser General Public License v3.0
5 stars 6 forks source link

Runner terminates application stack after encountering an issue #57

Closed VanDavv closed 1 year ago

VanDavv commented 1 year ago

log.txt

https://github.com/golemfactory/dapp-experiments/blob/todo_react/01_todo_app/golem-compose.yml

Log:

$ YAGNA_APPKEY=55359a3e7afb4525be26fff47accc41f dapp-runner start --config golem-config.yml golem-compose.yml 
[2022-11-07T13:20:51.912+0100 INFO dapp_runner.log] Using log file `/home/vandavv/.local/share/dapp_runner/zF5agJ_20221107_13:20:51/log`
yapapi version: 0.10.0.dev0
Using subnet: devnet-beta, payment driver: erc20, and network: rinkeby

Starting app: ToDo List App

[2022-11-07T13:20:52.074+0100 INFO yapapi.network] Created network: Network { id: 472029488c1c4b9f8048087b1165be3d, ip: 192.168.0.0, mask: 255.255.255.0}
[2022-11-07T13:20:52.555+0100 INFO dapp_runner.runner] Starting app: ToDo List App, startup timeout: 0:04:00, maximum running time: None
{"db": {"0": "pending"}}
[2022-11-07T13:20:54.579+0100 INFO yapapi.summary] [Job 1] Agreement proposed to provider 'imapp1019' (0x1fa0f36acd01befd28acab35e36149d90e581e0a)
[2022-11-07T13:20:54.914+0100 INFO yapapi.summary] Received proposals from 19 providers so far
[2022-11-07T13:20:54.915+0100 INFO yapapi.summary] [Job 1] Agreement confirmed by provider 'imapp1019'
[2022-11-07T13:20:55.809+0100 INFO yapapi.services.service_runner] <DappService-db starting on imapp1019 [ 0x1fa0f36acd01befd28acab35e36149d90e581e0a ] @ 192.168.0.2> commissioned
{"db": {"0": "starting"}}
[2022-11-07T13:20:57.915+0100 INFO yapapi.summary] Received proposals from 21 providers so far
[2022-11-07T13:21:00.916+0100 INFO yapapi.summary] Received proposals from 22 providers so far
{"db": {"0": [{"command": {"run": {"entry_point": "/bin/run_rqlite.sh", "args": [], "capture": {"stdout": {"stream": {}}, "stderr": {"stream": {}}}}}, "success": true, "stdout": null, "stderr": null}]}}
{"db": {"0": "running"}}
{"db": {"0": "running"}, "api": {"0": "pending"}}
[2022-11-07T13:21:08.589+0100 INFO yapapi.summary] [Job 2] Agreement proposed to provider 'mf' (0xff5cfa82220b2a394b561f6cb7e7c4a76d12ffd7)
[2022-11-07T13:21:08.912+0100 INFO yapapi.summary] [Job 2] Agreement confirmed by provider 'mf'
[2022-11-07T13:21:09.818+0100 INFO yapapi.services.service_runner] <DappService-api starting on mf [ 0xff5cfa82220b2a394b561f6cb7e7c4a76d12ffd7 ] @ 192.168.0.3> commissioned
{"db": {"0": "running"}, "api": {"0": "starting"}}
{"api": {"0": [{"command": {"run": {"entry_point": "/bin/bash", "args": ["-c", "cd /webapp && python app.py --db-address 192.168.0.2 --db-port 4001 initdb"], "capture": {"stdout": {"stream": {}}, "stderr": {"stream": {}}}}}, "success": true, "stdout": "2022-11-07 12:21:11,973 INFO sqlalchemy.engine.Engine BEGIN (implicit)\n2022-11-07 12:21:11,974 INFO sqlalchemy.engine.Engine PRAGMA main.table_info(\"to_do\")\n2022-11-07 12:21:11,975 INFO sqlalchemy.engine.Engine [raw sql] ()\n2022-11-07 12:21:12,232 INFO sqlalchemy.engine.Engine PRAGMA temp.table_info(\"to_do\")\n2022-11-07 12:21:12,232 INFO sqlalchemy.engine.Engine [raw sql] ()\n2022-11-07 12:21:12,447 INFO sqlalchemy.engine.Engine \nCREATE TABLE to_do (\n\tid INTEGER NOT NULL, \n\ttext VARCHAR(255), \n\tstatus VARCHAR(255), \n\tPRIMARY KEY (id)\n)\n\n\n2022-11-07 12:21:12,448 INFO sqlalchemy.engine.Engine [no key 0.00014s] ()\n2022-11-07 12:21:12,667 INFO sqlalchemy.engine.Engine COMMIT\n", "stderr": null}, {"command": {"run": {"entry_point": "/bin/bash", "args": ["-c", "cd /webapp && python app.py --db-address 192.168.0.2 --db-port 4001 run > /webapp/out 2> /webapp/err &"], "capture": {"stdout": {"stream": {}}, "stderr": {"stream": {}}}}}, "success": true, "stdout": null, "stderr": null}]}}
{"db": {"0": "running"}, "api": {"0": "running"}}
{"db": {"0": "running"}, "api": {"0": "running"}, "web": {"0": "pending"}}
[2022-11-07T13:21:16.605+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider '1nxt4s2' (0x170b2cb5ee5d1d3e172fd6c00d656a1637f4a015)
[2022-11-07T13:21:16.963+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider '1nxt4s2'
[2022-11-07T13:21:17.847+0100 INFO yapapi.services.service_runner] <DappService-web starting on 1nxt4s2 [ 0x170b2cb5ee5d1d3e172fd6c00d656a1637f4a015 ] @ 192.168.0.4> commissioned
{"db": {"0": "running"}, "api": {"0": "running"}, "web": {"0": "starting"}}
[2022-11-07T13:21:37.243+0100 WARNING yapapi.services.service_runner] Unhandled exception in service
Traceback (most recent call last):
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/services/service_runner.py", line 271, in _run_instance
    batch = batch_task.result()
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/dapp_runner/runner/service.py", line 70, in start
    init_output = yield script
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/services/service_runner.py", line 287, in _run_instance
    fut_result = yield batch
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/engine.py", line 721, in process_batches
    results = await get_batch_results()
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/engine.py", line 702, in get_batch_results
    event = script.process_batch_event(event_class, event_kwargs)
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/script/__init__.py", line 85, in process_batch_event
    raise CommandExecutionError(str(command), event.message, event.stderr)
yapapi.rest.activity.CommandExecutionError: Command 'Run /bin/run_web.sh 192.168.0.3 ()' failed on provider; message: 'Runtime error: Error { code: Internal, message: "Running process failed, exit code: 2", context: {} }'
[2022-11-07T13:21:37.247+0100 INFO yapapi.services.service_runner] <DappService-web terminated on 1nxt4s2 [ 0x170b2cb5ee5d1d3e172fd6c00d656a1637f4a015 ] @ 192.168.0.4> decommissioned
[2022-11-07T13:21:37.351+0100 INFO yapapi.summary] [Job 3] Terminated agreement with 1nxt4s2
[2022-11-07T13:21:37.439+0100 INFO yapapi.services.service_runner] Restarting service <DappService-web terminated on 1nxt4s2 [ 0x170b2cb5ee5d1d3e172fd6c00d656a1637f4a015 ] @ 192.168.0.4>
/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/services/service.py:377: DeprecationWarning: Default implementation of Service.reset will raise NotImplementedError starting from 0.10.0. You should implement this method on <class 'abc.DappService-web'>
  warn_deprecated_msg(msg)
{"db": {"0": "running"}, "api": {"0": "running"}, "web": {"0": "pending"}}
[2022-11-07T13:21:38.243+0100 INFO yapapi.summary] [Job 3] Accepted invoice from '1nxt4s2', amount: 0.001244576540100000
[2022-11-07T13:21:38.458+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider 'office_8_200' (0x13508b3cf7ab1d620870b4d2416fa46f0dcc7143)
[2022-11-07T13:21:38.858+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider 'office_8_200'
{"db": {"0": "running"}, "api": {"0": "running"}, "web": {"0": "starting"}}
[2022-11-07T13:21:43.843+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider 'office_8_80' (0xd9a4a6ba9e1800e4f61cd88dc23f082527f4ee28)
[2022-11-07T13:21:44.154+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider 'office_8_80'
[2022-11-07T13:21:44.694+0100 INFO yapapi.summary] [Job 3] Terminated agreement with office_8_200
[2022-11-07T13:21:45.614+0100 INFO dapp_runner.runner] Application started.
{"web": {"local_proxy_address": "http://localhost:8080"}}
{"db": {"0": "running"}, "api": {"0": "running"}, "web": {"0": "running"}}
[2022-11-07T13:21:50.648+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider 'sycamore' (0xa0cf793e2bb1764067cd4126cba444f901fd1b41)
[2022-11-07T13:21:50.957+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider 'sycamore'
[2022-11-07T13:21:51.073+0100 INFO yapapi.summary] [Job 3] Terminated agreement with office_8_80
[2022-11-07T13:21:51.563+0100 INFO yapapi.contrib.service.http_proxy] Received a local HTTP request: GET /
[2022-11-07T13:21:51.563+0100 INFO yapapi.contrib.service.http_proxy] Sending request: `GET /` to <DappService-web running on office_8_80 [ 0xd9a4a6ba9e1800e4f61cd88dc23f082527f4ee28 ] @ 192.168.0.4>
[2022-11-07T13:21:56.570+0100 ERROR aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 433, in _handle_request
    resp = await request_handler(request)
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/contrib/service/http_proxy.py", line 255, in _request_handler
    return await instance.handle_request(request)
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/contrib/service/http_proxy.py", line 147, in handle_request
    async with ws_session.ws_connect(
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/aiohttp/client.py", line 1141, in __aenter__
    self._resp = await self._coro
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/aiohttp/client.py", line 795, in _ws_connect
    raise WSServerHandshakeError(
aiohttp.client_exceptions.WSServerHandshakeError: 504, message='Invalid response status', url=URL('ws://127.0.0.1:7465/net-api/v1/net/472029488c1c4b9f8048087b1165be3d/tcp/192.168.0.4/80')
[2022-11-07T13:21:56.575+0100 INFO aiohttp.access] ::1 [07/Nov/2022:12:21:51 +0000] "GET / HTTP/1.1" 500 334 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
[2022-11-07T13:21:56.576+0100 ERROR asyncio] Unclosed client session
client_session: <aiohttp.client.ClientSession object at 0x7fab3c1f9d00>
[2022-11-07T13:21:56.576+0100 ERROR asyncio] Unclosed connector
connections: ['[(<aiohttp.client_proto.ResponseHandler object at 0x7fab3c242ca0>, 877033.762602052)]']
connector: <aiohttp.connector.TCPConnector object at 0x7fab3c1f9d60>
[2022-11-07T13:21:56.819+0100 INFO yapapi.contrib.service.http_proxy] Received a local HTTP request: GET /favicon.ico
[2022-11-07T13:21:56.819+0100 INFO yapapi.contrib.service.http_proxy] Sending request: `GET /favicon.ico` to <DappService-web running on office_8_80 [ 0xd9a4a6ba9e1800e4f61cd88dc23f082527f4ee28 ] @ 192.168.0.4>
[2022-11-07T13:21:57.158+0100 INFO yapapi.summary] [Job 3] Terminated agreement with sycamore
[2022-11-07T13:21:57.171+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider 'qbam' (0x9c80870ca1b4a2bd91d8c27ef1318018bcf53a6e)
[2022-11-07T13:21:57.583+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider 'qbam'
[2022-11-07T13:21:58.628+0100 INFO dapp_runner.runner] Stopping the application...
{"db": {"0": "running"}, "api": {"0": "running"}, "web": {"0": "stopping"}}
[2022-11-07T13:22:01.139+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider 'golem2005' (0x7803bb53dc04b333c80931aef447dec958ac6c4e)
[2022-11-07T13:22:01.455+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider 'golem2005'
[2022-11-07T13:22:01.674+0100 INFO yapapi.summary] [Job 3] Terminated agreement with qbam
[2022-11-07T13:22:01.825+0100 ERROR aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 433, in _handle_request
    resp = await request_handler(request)
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/contrib/service/http_proxy.py", line 255, in _request_handler
    return await instance.handle_request(request)
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/contrib/service/http_proxy.py", line 147, in handle_request
    async with ws_session.ws_connect(
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/aiohttp/client.py", line 1141, in __aenter__
    self._resp = await self._coro
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/aiohttp/client.py", line 795, in _ws_connect
    raise WSServerHandshakeError(
aiohttp.client_exceptions.WSServerHandshakeError: 504, message='Invalid response status', url=URL('ws://127.0.0.1:7465/net-api/v1/net/472029488c1c4b9f8048087b1165be3d/tcp/192.168.0.4/80')
[2022-11-07T13:22:01.825+0100 INFO aiohttp.access] ::1 [07/Nov/2022:12:21:56 +0000] "GET /favicon.ico HTTP/1.1" 500 244 "http://localhost:8080/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
[2022-11-07T13:22:01.826+0100 ERROR asyncio] Unclosed client session
client_session: <aiohttp.client.ClientSession object at 0x7fab3c1f9b20>
[2022-11-07T13:22:01.826+0100 ERROR asyncio] Unclosed connector
connections: ['[(<aiohttp.client_proto.ResponseHandler object at 0x7fab3c1b7040>, 877039.016899449)]']
connector: <aiohttp.connector.TCPConnector object at 0x7fab3c1f9850>
{"db": {"0": "stopping"}, "api": {"0": "stopping"}, "web": {"0": "stopping"}}
{"db": {"0": "stopping"}, "api": {"0": "stopping"}, "web": {"0": "stopping"}}
[2022-11-07T13:22:01.836+0100 INFO yapapi.network] Removed network: Network { id: 472029488c1c4b9f8048087b1165be3d, ip: 192.168.0.0, mask: 255.255.255.0}
[2022-11-07T13:22:02.110+0100 INFO yapapi.services.service_runner] <DappService-api terminated on mf [ 0xff5cfa82220b2a394b561f6cb7e7c4a76d12ffd7 ] @ 192.168.0.3> decommissioned
[2022-11-07T13:22:02.210+0100 INFO yapapi.services.service_runner] <DappService-db terminated on imapp1019 [ 0x1fa0f36acd01befd28acab35e36149d90e581e0a ] @ 192.168.0.2> decommissioned
[2022-11-07T13:22:02.259+0100 INFO yapapi.summary] [Job 2] Terminated agreement with mf
[2022-11-07T13:22:02.383+0100 INFO yapapi.summary] [Job 1] Terminated agreement with imapp1019
{"db": {"0": "terminated"}, "api": {"0": "terminated"}, "web": {"0": "terminated"}}
{"db": {"0": "terminated"}, "api": {"0": "terminated"}, "web": {"0": "terminated"}}
{"db": {"0": "terminated"}, "api": {"0": "terminated"}, "web": {"0": "terminated"}}
[2022-11-07T13:22:03.427+0100 INFO yapapi.summary] [Job 2] Accepted invoice from 'mf', amount: 0.002701381498000000
[2022-11-07T13:22:03.548+0100 INFO yapapi.summary] [Job 1] Accepted invoice from 'imapp1019', amount: 0.003497478960800000
[2022-11-07T13:22:05.634+0100 INFO yapapi.summary] [Job 3] Job finished in 51.1s
[2022-11-07T13:22:05.635+0100 INFO yapapi.summary] [Job 3] Negotiated 6 agreements with 6 providers
[2022-11-07T13:22:05.635+0100 INFO yapapi.summary] [Job 3] Provider 'office_8_80' did not compute any tasks
[2022-11-07T13:22:05.635+0100 INFO yapapi.summary] [Job 3] Provider 'office_8_200' did not compute any tasks
[2022-11-07T13:22:05.635+0100 INFO yapapi.summary] [Job 3] Provider 'qbam' did not compute any tasks
[2022-11-07T13:22:05.635+0100 INFO yapapi.summary] [Job 3] Provider 'golem2005' did not compute any tasks
[2022-11-07T13:22:05.635+0100 INFO yapapi.summary] [Job 3] Provider 'sycamore' did not compute any tasks
[2022-11-07T13:22:05.638+0100 INFO yapapi.summary] [Job 2] Job finished in 59.1s
[2022-11-07T13:22:05.638+0100 INFO yapapi.summary] [Job 2] Negotiated 1 agreements with 1 provider
[2022-11-07T13:22:05.640+0100 INFO yapapi.executor] Golem is shutting down...
[2022-11-07T13:22:05.640+0100 INFO yapapi.summary] [Job 1] Job finished in 73.1s
[2022-11-07T13:22:05.640+0100 INFO yapapi.summary] [Job 1] Negotiated 1 agreements with 1 provider
[2022-11-07T13:22:05.640+0100 INFO yapapi.executor] All jobs have finished
[2022-11-07T13:22:05.640+0100 INFO yapapi.executor] Waiting for Golem services to finish...
[2022-11-07T13:22:05.647+0100 INFO yapapi.summary] Total cost: 0.0074434369989
[2022-11-07T13:22:05.647+0100 INFO yapapi.summary] Golem engine has shut down
VanDavv commented 1 year ago 
[2022-11-07T13:41:43.569+0100 INFO dapp_runner.log] Using log file `/home/vandavv/.local/share/dapp_runner/49AUoP_20221107_13:41:43/log`
yapapi version: 0.10.0a0
Using subnet: devnet-beta, payment driver: erc20, and network: rinkeby

Starting app: ToDo List App

[2022-11-07T13:41:43.717+0100 INFO yapapi.network] Created network: Network { id: 79b37df061354e529f1395690b0da185, ip: 192.168.0.0, mask: 255.255.255.0}
[2022-11-07T13:41:43.941+0100 INFO dapp_runner.runner] Starting app: ToDo List App, startup timeout: 0:04:00, maximum running time: None
{"db": {"0": "pending"}}
[2022-11-07T13:41:45.949+0100 INFO yapapi.summary] [Job 1] Agreement proposed to provider 'office_8_80' (0xd9a4a6ba9e1800e4f61cd88dc23f082527f4ee28)
[2022-11-07T13:41:46.254+0100 INFO yapapi.summary] [Job 1] Agreement confirmed by provider 'office_8_80'
[2022-11-07T13:41:46.571+0100 INFO yapapi.summary] Received proposals from 9 providers so far
[2022-11-07T13:41:47.107+0100 INFO yapapi.services.service_runner] <DappService-db starting on office_8_80 [ 0xd9a4a6ba9e1800e4f61cd88dc23f082527f4ee28 ] @ 192.168.0.2> commissioned
{"db": {"0": "starting"}}
[2022-11-07T13:41:49.572+0100 INFO yapapi.summary] Received proposals from 11 providers so far
{"db": {"0": [{"command": {"run": {"entry_point": "/bin/run_rqlite.sh", "args": [], "capture": {"stdout": {"stream": {}}, "stderr": {"stream": {}}}}}, "success": true, "stdout": null, "stderr": null}]}}
{"db": {"0": "running"}}
{"db": {"0": "running"}, "api": {"0": "pending"}}
[2022-11-07T13:42:01.964+0100 INFO yapapi.summary] [Job 2] Agreement proposed to provider 'golem2005' (0x7803bb53dc04b333c80931aef447dec958ac6c4e)
[2022-11-07T13:42:02.283+0100 INFO yapapi.summary] [Job 2] Agreement confirmed by provider 'golem2005'
[2022-11-07T13:42:03.165+0100 INFO yapapi.services.service_runner] <DappService-api starting on golem2005 [ 0x7803bb53dc04b333c80931aef447dec958ac6c4e ] @ 192.168.0.3> commissioned
{"db": {"0": "running"}, "api": {"0": "starting"}}
{"api": {"0": [{"command": {"run": {"entry_point": "/bin/bash", "args": ["-c", "cd /webapp && python app.py --db-address 192.168.0.2 --db-port 4001 initdb"], "capture": {"stdout": {"stream": {}}, "stderr": {"stream": {}}}}}, "success": true, "stdout": "2022-11-07 12:42:20,939 INFO sqlalchemy.engine.Engine BEGIN (implicit)\n2022-11-07 12:42:20,941 INFO sqlalchemy.engine.Engine PRAGMA main.table_info(\"to_do\")\n2022-11-07 12:42:20,943 INFO sqlalchemy.engine.Engine [raw sql] ()\n2022-11-07 12:42:21,125 INFO sqlalchemy.engine.Engine PRAGMA temp.table_info(\"to_do\")\n2022-11-07 12:42:21,125 INFO sqlalchemy.engine.Engine [raw sql] ()\n2022-11-07 12:42:21,360 INFO sqlalchemy.engine.Engine \nCREATE TABLE to_do (\n\tid INTEGER NOT NULL, \n\ttext VARCHAR(255), \n\tstatus VARCHAR(255), \n\tPRIMARY KEY (id)\n)\n\n\n2022-11-07 12:42:21,360 INFO sqlalchemy.engine.Engine [no key 0.00041s] ()\n2022-11-07 12:42:21,589 INFO sqlalchemy.engine.Engine COMMIT\n", "stderr": null}, {"command": {"run": {"entry_point": "/bin/bash", "args": ["-c", "cd /webapp && python app.py --db-address 192.168.0.2 --db-port 4001 run > /webapp/out 2> /webapp/err &"], "capture": {"stdout": {"stream": {}}, "stderr": {"stream": {}}}}}, "success": true, "stdout": null, "stderr": null}]}}
{"db": {"0": "running"}, "api": {"0": "running"}}
{"db": {"0": "running"}, "api": {"0": "running"}, "web": {"0": "pending"}}
[2022-11-07T13:42:24.985+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider 'office_8_230' (0xee8993fe1dcff6b131d3fd759c6b3ddcb82d1655)
[2022-11-07T13:42:25.338+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider 'office_8_230'
[2022-11-07T13:42:26.190+0100 INFO yapapi.services.service_runner] <DappService-web starting on office_8_230 [ 0xee8993fe1dcff6b131d3fd759c6b3ddcb82d1655 ] @ 192.168.0.4> commissioned
{"db": {"0": "running"}, "api": {"0": "running"}, "web": {"0": "starting"}}
[2022-11-07T13:42:46.975+0100 WARNING yapapi.services.service_runner] Unhandled exception in service
Traceback (most recent call last):
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/services/service_runner.py", line 318, in _run_instance
    batch = batch_task.result()
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/dapp_runner/runner/service.py", line 70, in start
    init_output = yield script
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/services/service_runner.py", line 334, in _run_instance
    fut_result = yield batch
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/engine.py", line 720, in process_batches
    results = await get_batch_results()
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/engine.py", line 701, in get_batch_results
    event = script.process_batch_event(event_class, event_kwargs)
  File "/home/vandavv/dev/dapps/venv/lib/python3.9/site-packages/yapapi/script/__init__.py", line 95, in process_batch_event
    raise CommandExecutionError(str(command), event.message, event.stderr)
yapapi.rest.activity.CommandExecutionError: Command 'Run /bin/run_web.sh 192.168.0.3 ()' failed on provider; message: 'Runtime error: Error { code: Internal, message: "Running process failed, exit code: 2", context: {} }'
[2022-11-07T13:42:46.975+0100 INFO yapapi.services.service_runner] <DappService-web terminated on office_8_230 [ 0xee8993fe1dcff6b131d3fd759c6b3ddcb82d1655 ] @ 192.168.0.4> decommissioned
[2022-11-07T13:42:47.133+0100 INFO yapapi.summary] [Job 3] Terminated agreement with office_8_230
{"db": {"0": "running"}, "api": {"0": "running"}, "web": {"0": "terminated"}}
[2022-11-07T13:42:47.236+0100 INFO yapapi.services.service_runner] Restarting service <DappService-web terminated on office_8_230 [ 0xee8993fe1dcff6b131d3fd759c6b3ddcb82d1655 ] @ 192.168.0.4>
[2022-11-07T13:42:47.888+0100 INFO yapapi.summary] [Job 3] Accepted invoice from 'office_8_230', amount: 0.001342386593250000
[2022-11-07T13:42:48.253+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider 'q53' (0x44df807cd832393b254378ec33efb65adee837b8)
[2022-11-07T13:42:51.488+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider 'q53'
[2022-11-07T13:42:57.100+0100 INFO yapapi.summary] [Job 3] Terminated agreement with q53
[2022-11-07T13:42:57.595+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider 'office_8_67' (0xc6871fbc0f552a8b7ba0f2f777ca40026286bc56)
[2022-11-07T13:42:58.040+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider 'office_8_67'
[2022-11-07T13:43:05.228+0100 INFO yapapi.summary] [Job 3] Terminated agreement with office_8_67
[2022-11-07T13:43:05.271+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider 'office_10_216' (0xccf5d4e9f6dcfc553e7a4ba6a08b8b3e4fd785a2)
[2022-11-07T13:43:05.667+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider 'office_10_216'
[2022-11-07T13:43:07.016+0100 INFO dapp_runner.runner] Application started.
{"web": {"local_proxy_address": "http://localhost:8080"}}
[2022-11-07T13:43:11.413+0100 INFO yapapi.summary] [Job 3] Terminated agreement with office_10_216
[2022-11-07T13:43:12.171+0100 INFO yapapi.summary] [Job 3] Agreement proposed to provider 'office_8_67' (0xc6871fbc0f552a8b7ba0f2f777ca40026286bc56)
[2022-11-07T13:43:12.528+0100 INFO yapapi.summary] [Job 3] Agreement confirmed by provider 'office_8_67'
[2022-11-07T13:43:14.023+0100 INFO dapp_runner.runner] Stopping the application...
{"db": {"0": "stopping"}, "api": {"0": "stopping"}, "web": {"0": "stopping"}}
{"db": {"0": "stopping"}, "api": {"0": "stopping"}, "web": {"0": "stopping"}}
[2022-11-07T13:43:14.030+0100 INFO yapapi.network] Removed network: Network { id: 79b37df061354e529f1395690b0da185, ip: 192.168.0.0, mask: 255.255.255.0}
[2022-11-07T13:43:14.279+0100 INFO yapapi.services.service_runner] <DappService-db terminated on office_8_80 [ 0xd9a4a6ba9e1800e4f61cd88dc23f082527f4ee28 ] @ 192.168.0.2> decommissioned
[2022-11-07T13:43:14.351+0100 INFO yapapi.services.service_runner] <DappService-api terminated on golem2005 [ 0x7803bb53dc04b333c80931aef447dec958ac6c4e ] @ 192.168.0.3> decommissioned
[2022-11-07T13:43:14.410+0100 INFO yapapi.summary] [Job 1] Terminated agreement with office_8_80
[2022-11-07T13:43:14.465+0100 INFO yapapi.summary] [Job 2] Terminated agreement with golem2005
[2022-11-07T13:43:15.040+0100 INFO yapapi.summary] [Job 1] Accepted invoice from 'office_8_80', amount: 0.004650492203849999
[2022-11-07T13:43:15.136+0100 INFO yapapi.summary] [Job 2] Accepted invoice from 'golem2005', amount: 0.004039792135350001
{"db": {"0": "terminated"}, "api": {"0": "terminated"}, "web": {"0": "stopping"}}
{"db": {"0": "terminated"}, "api": {"0": "terminated"}, "web": {"0": "stopping"}}
[2022-11-07T13:43:16.584+0100 INFO yapapi.summary] [Job 3] Job finished in 53.6s
[2022-11-07T13:43:16.584+0100 INFO yapapi.summary] [Job 3] Negotiated 5 agreements with 4 providers
[2022-11-07T13:43:16.585+0100 INFO yapapi.summary] [Job 3] Provider 'q53' did not compute any tasks
[2022-11-07T13:43:16.585+0100 INFO yapapi.summary] [Job 3] Provider 'office_8_67' did not compute any tasks
[2022-11-07T13:43:16.585+0100 INFO yapapi.summary] [Job 3] Provider 'office_10_216' did not compute any tasks
[2022-11-07T13:43:16.585+0100 INFO yapapi.summary] [Job 3] Provider 'office_8_67' did not compute any tasks
[2022-11-07T13:43:16.588+0100 INFO yapapi.summary] [Job 2] Job finished in 76.6s
[2022-11-07T13:43:16.589+0100 INFO yapapi.summary] [Job 2] Negotiated 1 agreements with 1 provider
[2022-11-07T13:43:16.592+0100 INFO yapapi.executor] Golem is shutting down...
[2022-11-07T13:43:16.592+0100 INFO yapapi.summary] [Job 1] Job finished in 92.6s
[2022-11-07T13:43:16.592+0100 INFO yapapi.summary] [Job 1] Negotiated 1 agreements with 1 provider
[2022-11-07T13:43:16.593+0100 INFO yapapi.executor] All jobs have finished
[2022-11-07T13:43:16.593+0100 INFO yapapi.executor] Waiting for Golem services to finish...
[2022-11-07T13:43:16.604+0100 INFO yapapi.summary] Total cost: 0.01003267093245
[2022-11-07T13:43:16.604+0100 INFO yapapi.summary] Golem engine has shut down

log.txt

shadeofblue commented 1 year ago

most likely due to: https://github.com/golemfactory/yapapi/issues/614

shadeofblue commented 1 year ago

let's try to reproduce and reassess this after https://github.com/golemfactory/yapapi/pull/1054 is merged and dapp-runner updated to use the newest yapapi

shadeofblue commented 1 year ago

actually, that still happens anyway:

{"mongo": {"0": "running"}, "backend": {"0": "running"}, "frontend": {"0": "running"}}
[2022-12-08T08:46:20.496+0100 INFO dapp_runner.runner] Application started.
{"frontend": {"local_proxy_address": "http://localhost:8082"}}
[2022-12-08T08:46:37.710+0100 WARNING yapapi.services.service_runner] Unhandled exception in service
Traceback (most recent call last):
  File "/home/blue/.envs/dapp-runner/lib/python3.9/site-packages/yapapi/services/service_runner.py", line 318, in _run_instance
    batch = batch_task.result()
  File "/home/blue/PycharmProjects/dapp-runner/dapp_runner/runner/service.py", line 91, in run
    out = yield script
  File "/home/blue/.envs/dapp-runner/lib/python3.9/site-packages/yapapi/services/service_runner.py", line 334, in _run_instance
    fut_result = yield batch
  File "/home/blue/.envs/dapp-runner/lib/python3.9/site-packages/yapapi/engine.py", line 720, in process_batches
    results = await get_batch_results()
  File "/home/blue/.envs/dapp-runner/lib/python3.9/site-packages/yapapi/engine.py", line 701, in get_batch_results
    event = script.process_batch_event(event_class, event_kwargs)
  File "/home/blue/.envs/dapp-runner/lib/python3.9/site-packages/yapapi/script/__init__.py", line 95, in process_batch_event
    raise CommandExecutionError(str(command), event.message, event.stderr)
yapapi.rest.activity.CommandExecutionError: Command 'Run /bin/bash ('-c', 'cat /watchdog_stderr')' failed on provider; message: 'ExeScript command exited with code 1'; stderr: 'cat: /watchdog_stderr: No such file or directory
'
{"mongo": {"0": "running"}, "backend": {"0": "stopping"}, "frontend": {"0": "running"}}
[2022-12-08T08:46:37.898+0100 INFO yapapi.services.service_runner] <DappService-backend terminated on sharkoon_378.h [ 0x6e53d47fa38d9e768fabc0b6ad42910148ffbc4b ] @ 192.168.0.3> decommissioned
[2022-12-08T08:46:38.014+0100 INFO yapapi.summary] [Job 2] Terminated agreement with sharkoon_378.h
[2022-12-08T08:46:38.518+0100 INFO dapp_runner.runner] Stopping the application...
[2022-12-08T08:46:38.519+0100 INFO yapapi.contrib.service.socket_proxy] Stopping socket proxy...
[2022-12-08T08:46:38.520+0100 INFO yapapi.contrib.service.socket_proxy] Socket proxy stopped.
[2022-12-08T08:46:38.529+0100 INFO yapapi.network] Removed network: Network { id: 53ad6478c3c8480f8237334b55a09d1c, ip: 192.168.0.0, mask: 255.255.255.0}
{"mongo": {"0": "stopping"}, "backend": {"0": "terminated"}, "frontend": {"0": "stopping"}}
{"mongo": {"0": "stopping"}, "backend": {"0": "terminated"}, "frontend": {"0": "stopping"}}
[2022-12-08T08:46:38.574+0100 INFO yapapi.summary] [Job 2] Accepted invoice from 'sharkoon_378.h', amount: 0.01250105083840000
{"mongo": {"0": "stopping"}, "backend": {"0": "terminated"}, "frontend": {"0": "stopping"}}
[2022-12-08T08:46:38.695+0100 INFO yapapi.services.service_runner] <DappService-mongo terminated on mf.h [ 0x0704f0a658f644a5c6f5a4b7b9bbcedac30078ff ] @ 192.168.0.2> decommissioned
[2022-12-08T08:46:38.702+0100 INFO yapapi.services.service_runner] <DappService-frontend terminated on imapp2025.h [ 0x7a66c99526899f9e01c275e0cefc18e011238497 ] @ 192.168.0.4> decommissioned
{"mongo": {"0": "terminated"}, "backend": {"0": "terminated"}, "frontend": {"0": "terminated"}}
{"mongo": {"0": "terminated"}, "backend": {"0": "terminated"}, "frontend": {"0": "terminated"}}
[2022-12-08T08:46:40.384+0100 INFO yapapi.summary] [Job 3] Job finished in 24.9s
[2022-12-08T08:46:40.384+0100 INFO yapapi.summary] [Job 3] Negotiated 1 agreements with 1 provider
[2022-12-08T08:46:40.391+0100 INFO yapapi.summary] [Job 2] Job finished in 193.1s
[2022-12-08T08:46:40.392+0100 INFO yapapi.summary] [Job 2] Negotiated 1 agreements with 1 provider
[2022-12-08T08:46:40.502+0100 INFO yapapi.summary] [Job 1] Terminated agreement with mf.h
[2022-12-08T08:46:40.552+0100 INFO yapapi.summary] [Job 1] Agreement proposed to provider 'jiuzhang.h' (0xed827a418ddd23ead600ce8c4d1fed662a330fdf)
[2022-12-08T08:46:40.629+0100 INFO yapapi.summary] [Job 1] Agreement confirmed by provider 'jiuzhang.h'
[2022-12-08T08:46:40.669+0100 INFO yapapi.summary] [Job 3] Accepted invoice from 'imapp2025.h', amount: 0.001245993087300000
[2022-12-08T08:46:40.760+0100 INFO yapapi.summary] [Job 1] Accepted invoice from 'mf.h', amount: 0.01410003223270000
[2022-12-08T08:46:41.422+0100 WARNING yapapi.summary] [Job 1] Worker for provider 'jiuzhang.h' failed; reason: Can't add_node when in removed.
[2022-12-08T08:46:42.999+0100 INFO yapapi.executor] Golem is shutting down...
[2022-12-08T08:46:43.000+0100 INFO yapapi.summary] [Job 1] Job finished in 258.8s
[2022-12-08T08:46:43.000+0100 INFO yapapi.summary] [Job 1] Negotiated 2 agreements with 2 providers
[2022-12-08T08:46:43.001+0100 INFO yapapi.summary] [Job 1] Provider 'jiuzhang.h' did not compute any tasks
[2022-12-08T08:46:43.001+0100 INFO yapapi.summary] [Job 1] Activity failed 1 time on provider 'jiuzhang.h'
[2022-12-08T08:46:43.001+0100 INFO yapapi.executor] All jobs have finished
[2022-12-08T08:46:43.002+0100 INFO yapapi.executor] Waiting for Golem services to finish...
[2022-12-08T08:46:43.020+0100 INFO yapapi.summary] Total cost: 0.0278470761584
[2022-12-08T08:46:43.021+0100 INFO yapapi.summary] Golem engine has shut down
shadeofblue commented 1 year ago

okay, this works as intended - at least for now

a failure of any service after it reaches the "running" state means that the integrity of the whole app cannot be guaranteed and the only sensible solution is to treat the whole app as defunct.

if we want to change the behavior here, we need to design a process which determines the plan of updates of services and possible options of algorithms governing the app at the "supervise" stage (as opposed to the "deploy" stage implemented now).