open-rmf/rmf-web

exception in api-server

youliangtan opened this issue · 8 comments

Getting this exception error in api-server

INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
ERROR:    Exception in ASGI application
Traceback (most recent call last):
  File "asyncpg/protocol/prepared_stmt.pyx", line 155, in asyncpg.protocol.protocol.PreparedStatementState._encode_bind_msg
  File "asyncpg/protocol/codecs/base.pyx", line 193, in asyncpg.protocol.protocol.Codec.encode
  File "asyncpg/protocol/codecs/base.pyx", line 104, in asyncpg.protocol.protocol.Codec.encode_scalar
  File "asyncpg/pgproto/./codecs/int.pyx", line 60, in asyncpg.pgproto.pgproto.int4_encode
OverflowError: value out of int32 range

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/tortoise/backends/asyncpg/client.py", line 36, in translate_exceptions_
    return await func(self, *args)
  File "/usr/local/lib/python3.8/dist-packages/tortoise/backends/asyncpg/client.py", line 150, in execute_insert
    return await connection.fetchrow(query, *values)
  File "/usr/local/lib/python3.8/dist-packages/asyncpg/connection.py", line 641, in fetchrow
    data = await self._execute(
  File "/usr/local/lib/python3.8/dist-packages/asyncpg/connection.py", line 1625, in _execute
    result, _ = await self.__execute(
  File "/usr/local/lib/python3.8/dist-packages/asyncpg/connection.py", line 1650, in __execute
    return await self._do_execute(
  File "/usr/local/lib/python3.8/dist-packages/asyncpg/connection.py", line 1697, in _do_execute
    result = await executor(stmt, None)
  File "asyncpg/protocol/protocol.pyx", line 181, in bind_execute
  File "asyncpg/protocol/prepared_stmt.pyx", line 171, in asyncpg.protocol.protocol.PreparedStatementState._encode_bind_msg
asyncpg.exceptions.DataError: invalid input for query argument $2: 1650534798523 (value out of int32 range)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/uvicorn/protocols/websockets/websockets_impl.py", line 162, in run_asgi
    result = await self.app(self.scope, self.asgi_receive, self.asgi_send)
  File "/usr/local/lib/python3.8/dist-packages/uvicorn/middleware/proxy_headers.py", line 45, in __call__
    return await self.app(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/fastapi/applications.py", line 199, in __call__
    await super().__call__(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/applications.py", line 112, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/middleware/errors.py", line 146, in __call__
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/exceptions.py", line 58, in __call__
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/routing.py", line 580, in __call__
    await route.handle(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/routing.py", line 297, in handle
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/routing.py", line 68, in app
    await func(session)
  File "/usr/local/lib/python3.8/dist-packages/fastapi/routing.py", line 262, in app
    await dependant.call(**values)
  File "/usr/local/lib/python3.8/dist-packages/api_server/rmf_gateway_app.py", line 48, in rmf_gateway
    await process_msg(msg)
  File "/usr/local/lib/python3.8/dist-packages/api_server/rmf_gateway_app.py", line 30, in process_msg
    await task_repo.save_task_log(task_log)
  File "/usr/local/lib/python3.8/dist-packages/api_server/repositories/tasks.py", line 161, in save_task_log
    await self._savePhaseLogs(db_task_log, task_log.phases)
  File "/usr/local/lib/python3.8/dist-packages/api_server/repositories/tasks.py", line 138, in _savePhaseLogs
    await self._saveEventLogs(db_phase, phase.events)
  File "/usr/local/lib/python3.8/dist-packages/api_server/repositories/tasks.py", line 118, in _saveEventLogs
    await ttm.TaskEventLogPhasesEventsLog.create(
  File "/usr/local/lib/python3.8/dist-packages/tortoise/models.py", line 1109, in create
    await instance.save(using_db=db, force_create=True)
  File "/usr/local/lib/python3.8/dist-packages/tortoise/models.py", line 930, in save
    await executor.execute_insert(self)
  File "/usr/local/lib/python3.8/dist-packages/tortoise/backends/base/executor.py", line 220, in execute_insert
    insert_result = await self.db.execute_insert(self.insert_query, values)
  File "/usr/local/lib/python3.8/dist-packages/tortoise/backends/asyncpg/client.py", line 38, in translate_exceptions_
    raise OperationalError(exc)
tortoise.exceptions.OperationalError: invalid input for query argument $2: 1650534798523 (value out of int32 range)
INFO:     ('127.0.0.1', 42362) - "WebSocket /rmf/api/v1/" [accepted]
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/dispensers HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/ingestors HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/fleets HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
ERROR:    Exception in ASGI application
Traceback (most recent call last):
  File "asyncpg/protocol/prepared_stmt.pyx", line 155, in asyncpg.protocol.protocol.PreparedStatementState._encode_bind_msg
  File "asyncpg/protocol/codecs/base.pyx", line 193, in asyncpg.protocol.protocol.Codec.encode
  File "asyncpg/protocol/codecs/base.pyx", line 104, in asyncpg.protocol.protocol.Codec.encode_scalar
  File "asyncpg/pgproto/./codecs/int.pyx", line 60, in asyncpg.pgproto.pgproto.int4_encode
OverflowError: value out of int32 range

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/tortoise/backends/asyncpg/client.py", line 36, in translate_exceptions_
    return await func(self, *args)
  File "/usr/local/lib/python3.8/dist-packages/tortoise/backends/asyncpg/client.py", line 150, in execute_insert
    return await connection.fetchrow(query, *values)
  File "/usr/local/lib/python3.8/dist-packages/asyncpg/connection.py", line 641, in fetchrow
    data = await self._execute(
  File "/usr/local/lib/python3.8/dist-packages/asyncpg/connection.py", line 1625, in _execute
    result, _ = await self.__execute(
  File "/usr/local/lib/python3.8/dist-packages/asyncpg/connection.py", line 1650, in __execute
    return await self._do_execute(
  File "/usr/local/lib/python3.8/dist-packages/asyncpg/connection.py", line 1697, in _do_execute
    result = await executor(stmt, None)
  File "asyncpg/protocol/protocol.pyx", line 181, in bind_execute
  File "asyncpg/protocol/prepared_stmt.pyx", line 171, in asyncpg.protocol.protocol.PreparedStatementState._encode_bind_msg
asyncpg.exceptions.DataError: invalid input for query argument $2: 1650534798526 (value out of int32 range)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/uvicorn/protocols/websockets/websockets_impl.py", line 162, in run_asgi
    result = await self.app(self.scope, self.asgi_receive, self.asgi_send)
  File "/usr/local/lib/python3.8/dist-packages/uvicorn/middleware/proxy_headers.py", line 45, in __call__
    return await self.app(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/fastapi/applications.py", line 199, in __call__
    await super().__call__(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/applications.py", line 112, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/middleware/errors.py", line 146, in __call__
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/exceptions.py", line 58, in __call__
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/routing.py", line 580, in __call__
    await route.handle(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/routing.py", line 297, in handle
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.8/dist-packages/starlette/routing.py", line 68, in app
    await func(session)
  File "/usr/local/lib/python3.8/dist-packages/fastapi/routing.py", line 262, in app
    await dependant.call(**values)
  File "/usr/local/lib/python3.8/dist-packages/api_server/rmf_gateway_app.py", line 48, in rmf_gateway
    await process_msg(msg)
  File "/usr/local/lib/python3.8/dist-packages/api_server/rmf_gateway_app.py", line 30, in process_msg
    await task_repo.save_task_log(task_log)
  File "/usr/local/lib/python3.8/dist-packages/api_server/repositories/tasks.py", line 161, in save_task_log
    await self._savePhaseLogs(db_task_log, task_log.phases)
  File "/usr/local/lib/python3.8/dist-packages/api_server/repositories/tasks.py", line 138, in _savePhaseLogs
    await self._saveEventLogs(db_phase, phase.events)
  File "/usr/local/lib/python3.8/dist-packages/api_server/repositories/tasks.py", line 118, in _saveEventLogs
    await ttm.TaskEventLogPhasesEventsLog.create(
  File "/usr/local/lib/python3.8/dist-packages/tortoise/models.py", line 1109, in create
    await instance.save(using_db=db, force_create=True)
  File "/usr/local/lib/python3.8/dist-packages/tortoise/models.py", line 930, in save
    await executor.execute_insert(self)
  File "/usr/local/lib/python3.8/dist-packages/tortoise/backends/base/executor.py", line 220, in execute_insert
    insert_result = await self.db.execute_insert(self.insert_query, values)
  File "/usr/local/lib/python3.8/dist-packages/tortoise/backends/asyncpg/client.py", line 38, in translate_exceptions_
    raise OperationalError(exc)
tortoise.exceptions.OperationalError: invalid input for query argument $2: 1650534798526 (value out of int32 range)
INFO:     ('127.0.0.1', 42416) - "WebSocket /rmf/api/v1/" [accepted]
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/dispensers HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/ingestors HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/fleets HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/dispensers HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/ingestors HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/fleets HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks/compose.dispatch-53/state HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/dispensers HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/ingestors HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/fleets HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks/compose.dispatch-53/state HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks?limit=11&offset=0&order_by=-unix_millis_start_time HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/dispensers HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/ingestors HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/fleets HTTP/1.1" 200 OK
INFO:     10.42.0.123:58980 - "GET /rmf/api/v1/tasks/compose.dispatch-53/

This is due to #604, it looks like it maxes out at int32, while ts maxes out at int64. In the future, let's test it out more before merging it in.

@youliangtan Could you revert that particular PR?

@aaronchongth this error is without the fix in #604

oh that's good news at least, how can this be replicated?

I will revisit this issue again next week as this is hard to replicate and requires further investigation. I added the question tag as further information is required from me.

Yup, thanks! I will keep a lookout if we face this on our side as well

Not sure if it is related to the IntField here. I will test it out again with a 64bit BigIntField, see if it happens again

unix_millis_time = IntField(null=False, index=True)

I believe #618 fixes this