GNS3 / gns3-server

GNS3 server
GNU General Public License v3.0
811 stars 263 forks source link

Error 500 on PUT /v3/projects/{project_id}/nodes/{node_id} #2426

Open nielsek opened 1 month ago

nielsek commented 1 month ago

GNS3 version: 3.0.0rc1

Error messages

2024-10-15 10:40:26 DEBUG gns3server.controller.compute:528 Attempting request to compute: PUT ServerProtocol.http://127.0.0.1:3080/v3/compute/projects/7e68a138-0d42-4b42-b45c-e9bf6e17ffe3/nat/nodes/9c88b000-2ea4-4030-9f54-b1852fcb5e04 {'content-type': 'application/json'}
2024-10-15 10:40:26 INFO gns3server.compute.base_node:246 Builtin: NAT1 [9c88b000-2ea4-4030-9f54-b1852fcb5e04] renamed to STAG_WAN
2024-10-15 10:40:26 INFO uvicorn.access:477 127.0.0.1:36250 - "PUT /v3/compute/projects/7e68a138-0d42-4b42-b45c-e9bf6e17ffe3/nat/nodes/9c88b000-2ea4-4030-9f54-b1852fcb5e04 HTTP/1.1" 500
2024-10-15 10:40:26 ERROR uvicorn.error:412 Exception in ASGI application
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/dist-packages/uvicorn/protocols/http/h11_impl.py", line 407, in run_asgi
    result = await app(  # type: ignore[func-returns-value]
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/uvicorn/middleware/proxy_headers.py", line 69, in __call__
    return await self.app(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/fastapi/applications.py", line 1054, in __call__
    await super().__call__(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/applications.py", line 123, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/middleware/errors.py", line 186, in __call__
    raise exc
  File "/usr/local/lib/python3.12/dist-packages/starlette/middleware/errors.py", line 164, in __call__
    await self.app(scope, receive, _send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/middleware/cors.py", line 85, in __call__
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/middleware/exceptions.py", line 65, in __call__
    await wrap_app_handling_exceptions(self.app, conn)(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/_exception_handler.py", line 64, in wrapped_app
    raise exc
  File "/usr/local/lib/python3.12/dist-packages/starlette/_exception_handler.py", line 53, in wrapped_app
    await app(scope, receive, sender)
  File "/usr/local/lib/python3.12/dist-packages/starlette/routing.py", line 756, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/routing.py", line 776, in app
    await route.handle(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/routing.py", line 485, in handle
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/fastapi/applications.py", line 1054, in __call__
    await super().__call__(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/applications.py", line 123, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/middleware/errors.py", line 186, in __call__
    raise exc
  File "/usr/local/lib/python3.12/dist-packages/starlette/middleware/errors.py", line 164, in __call__
    await self.app(scope, receive, _send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/middleware/exceptions.py", line 65, in __call__
    await wrap_app_handling_exceptions(self.app, conn)(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/_exception_handler.py", line 64, in wrapped_app
    raise exc
  File "/usr/local/lib/python3.12/dist-packages/starlette/_exception_handler.py", line 53, in wrapped_app
    await app(scope, receive, sender)
  File "/usr/local/lib/python3.12/dist-packages/starlette/routing.py", line 756, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/routing.py", line 776, in app
    await route.handle(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/routing.py", line 297, in handle
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/routing.py", line 77, in app
    await wrap_app_handling_exceptions(app, request)(scope, receive, send)
  File "/usr/local/lib/python3.12/dist-packages/starlette/_exception_handler.py", line 64, in wrapped_app
    raise exc
  File "/usr/local/lib/python3.12/dist-packages/starlette/_exception_handler.py", line 53, in wrapped_app
    await app(scope, receive, sender)
  File "/usr/local/lib/python3.12/dist-packages/starlette/routing.py", line 72, in app
    response = await func(request)
               ^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/fastapi/routing.py", line 278, in app
    raw_response = await run_endpoint_function(
                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/fastapi/routing.py", line 193, in run_endpoint_function
    return await run_in_threadpool(dependant.call, **values)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/starlette/concurrency.py", line 42, in run_in_threadpool
    return await anyio.to_thread.run_sync(func, *args)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/anyio/to_thread.py", line 56, in run_sync
    return await get_async_backend().run_sync_in_worker_thread(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/anyio/_backends/_asyncio.py", line 2177, in run_sync_in_worker_thread
    return await future
           ^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/anyio/_backends/_asyncio.py", line 859, in run
    result = context.run(func, *args)
             ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/dist-packages/gns3server/api/routes/compute/nat_nodes.py", line 92, in update_nat_node
    node.updated()
  File "/usr/local/lib/python3.12/dist-packages/gns3server/compute/base_node.py", line 203, in updated
    self.project.emit("node.updated", self)
  File "/usr/local/lib/python3.12/dist-packages/gns3server/compute/project.py", line 394, in emit
    NotificationManager.instance().emit(action, event, project_id=self.id)
  File "/usr/local/lib/python3.12/dist-packages/gns3server/compute/notification_manager.py", line 57, in emit
    listener.put_nowait((action, event, kwargs))
  File "/usr/lib/python3.12/asyncio/queues.py", line 147, in put_nowait
    self._wakeup_next(self._getters)
  File "/usr/lib/python3.12/asyncio/queues.py", line 63, in _wakeup_next
    waiter.set_result(None)
  File "/usr/lib/python3.12/asyncio/base_events.py", line 797, in call_soon
    self._check_thread()
  File "/usr/lib/python3.12/asyncio/base_events.py", line 834, in _check_thread
    raise RuntimeError(
RuntimeError: Non-thread-safe operation invoked on an event loop other than the current one
2024-10-15 10:40:26 DEBUG aiosqlite:114 executing functools.partial(<built-in method rollback of sqlite3.Connection object at 0x7fce94315d50>)
2024-10-15 10:40:26 DEBUG aiosqlite:116 operation functools.partial(<built-in method rollback of sqlite3.Connection object at 0x7fce94315d50>) completed
2024-10-15 10:40:26 DEBUG aiosqlite:114 executing functools.partial(<built-in method rollback of sqlite3.Connection object at 0x7fce94315d50>)
2024-10-15 10:40:26 DEBUG aiosqlite:116 operation functools.partial(<built-in method rollback of sqlite3.Connection object at 0x7fce94315d50>) completed
2024-10-15 10:40:26 DEBUG aiosqlite:114 executing functools.partial(<built-in method close of sqlite3.Connection object at 0x7fce94315d50>)
2024-10-15 10:40:26 DEBUG aiosqlite:116 operation functools.partial(<built-in method close of sqlite3.Connection object at 0x7fce94315d50>) completed
2024-10-15 10:40:26 INFO uvicorn.access:477 10.254.0.199:6115 - "PUT /v3/projects/7e68a138-0d42-4b42-b45c-e9bf6e17ffe3/nodes/9c88b000-2ea4-4030-9f54-b1852fcb5e04 HTTP/1.1" 500

Background

I am not sure if this is only related to PUT /v3/projects/{project_id}/nodes/{node_id}, but the above example is from such an occasion.

Afterwards the API seems to still operate normally, so it is able to create new QEMU VMs and start them and so on.

For GNS3 clients, these new VMs will appear however it will look like they are turned off even though they are not.

That seems to be because the GNS3 server is only sending out ping events on the notifications websocket after the error, so no more compute.update events, which usually comes as the second event when connecting a new client.

Example from a "client" that prints all events:

ws-recv.py "ws://localhost:3080/v3/notifications/ws?token=$(gns3-token.sh)" 30
{"action": "ping", "event": {"cpu_usage_percent": 19.8, "disk_usage_percent": 68.7, "memory_usage_percent": 44.3}}
{"action": "ping", "event": {"cpu_usage_percent": 18.8, "disk_usage_percent": 68.7, "memory_usage_percent": 44.3}}
{"action": "ping", "event": {"cpu_usage_percent": 19.6, "disk_usage_percent": 68.7, "memory_usage_percent": 44.3}}
{"action": "ping", "event": {"cpu_usage_percent": 19.9, "disk_usage_percent": 68.7, "memory_usage_percent": 44.3}}
{"action": "ping", "event": {"cpu_usage_percent": 18.3, "disk_usage_percent": 68.7, "memory_usage_percent": 44.3}}

If I try to shut down GNS3, then it will just wait for background tasks to complete:

2024-10-15 11:47:48 INFO uvicorn.error:303 Waiting for background tasks to complete. (CTRL+C to force quit)
nielsek commented 1 day ago

@grossmj this doesn't seem to be an issue when utilizing the latest from Git :smile:

Maybe due to the update of FastAPI in https://github.com/GNS3/gns3-server/commit/a7da814b851e5b5470da9d98b8128a589c05b896 ?

nielsek commented 1 day ago

Guess I was a bit too fast. Still having the issue sometimes