Occasionally during high-frequency queries, there may be differences between SQL statements and query results, leading to KeyError errors. Additionally, Command Out of Sync errors may also be reported during transactions #1588
Describe the bug
The application has been running normally for two years, and there have been frequent KeyError issues recently. By printing SQL and capturing packets, we discovered its specific performance, which usually occurs in SQL with frequent queries. When an error occurs, it is found that the ORM obtains the fields and result sets returned by other SQL executions before the current SQL. Even if the result set is empty, an error will still be reported. Meanwhile, Command Out of Sync will also be reported in other transactions.
To Reproduce
We spent several days trying to find a way to reproduce and a solution, but so far we have not found it. As soon as the current problem arises, it will continue to occur and can only be temporarily resolved by restarting the application
Expected behavior
Orm obtained the fields and result sets returned by other SQL statements before the current SQL statement
Additional context
2024-04-12 16:14:34.332 | INFO | aiomysql.cursors:execute:242 - SELECT `device_type`,`create_time`,`id`,`update_time`,`device_sn` FROM `device` WHERE `device_sn`='2311940457' LIMIT 2
(('device_type', 2, None, 6, 6, 0, False), ('create_time', 12, None, 26, 26, 6, False), ('id', 8, None, 20, 20, 0, False), ('update_time', 12, None, 26, 26, 6, False), ('device_sn', 253, None, 256, 256, 0, False)
()
140571523585696
2024-04-12 16:14:34.333 | INFO | aiomysql.cursors:execute:243 - %r
2024-04-12 16:14:34.374 | INFO | aiomysql.cursors:execute:242 - SELECT `password`,`update_user`,`name`FROM `account` WHERE is_deleted`=0 LIMIT 2
(('device_type', 2, None, 6, 6, 0, False), ('create_time', 12, None, 26, 26, 6, False), ('id', 8, None, 20, 20, 0, False), ('update_time', 12, None, 26, 26, 6, False), ('device_sn', 253, None, 256, 256, 0, False)
()
140571537213856
2024-04-12 16:14:34.374 | INFO | aiomysql.cursors:execute:243 - %r
2024-04-12 16:14:34.381 | INFO | aiomysql.cursors:execute:242 - SELECT `device_type`, `create_time`,`id`,`update_time`,`device_sn` FROM `device` WHERE `device_sn`='2310940295' LIMIT 2
(('device_type', 2, None, 6, 6, 0, False), ('create_time', 12, None, 26, 26, 6, False), ('id', 8, None, 20, 20, 0, False), ('update_time', 12, None, 26, 26, 6, False), ('device_sn', 253, None, 256, 256, 0, False)
()
140571523585696
2024-04-12 16:14:34.381 | INFO | aiomysql.cursors:execute:243 - %r
2024-04-12 16:14:34.452 | INFO | aiomysql.cursors:execute:242 - SELECT `device_type`,`create_time`,`id`,`update_time`,`device_sn`FROM `device` WHERE `device_sn`='2311940866'LIMIT 2
(('password', 253, None, 1020, 1020, 0, True), ('update_user', 8, None, 20, 20, 0, True), ('name', 253, None, 1020, 1020, 0, True))
(('fd85943fdb86', None, '会发达的boy'),)
140571537213856
2024-04-12 16:14:34.452 | INFO | aiomysql.cursors:execute:243 - %r
traceback:Traceback (most recent call last):
File "/user/.virtualenvs/api/lib/python3.9/site-packages/tortoise/models.py", line 725, in _init_from_db
setattr(self, model_field, kwargs[key])
KeyError: 'device_type'
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/project/base/exceptions.py", line 136, in all_exception_handler
raise exc
File "/project/base/router.py", line 20, in custom_route_handler
return await original_route_handler(request)
File "/user/.virtualenvs/api/lib/python3.9/site-packages/fastapi/routing.py", line 273, in app
raw_response = await run_endpoint_function(
File "/user/.virtualenvs/api/lib/python3.9/site-packages/fastapi/routing.py", line 190, in run_endpoint_function
return await dependant.call(**values)
File "/project/view_expand/view_class.py", line 32, in wraps
res = await func(*args, **kwargs)
File "/project/apps/socket_plat/views.py", line 208, in post
res = await Utils.get_device_bind_status(self.body.get('device_sn'), device_type=device_type)
File "/project/apps/socket_plat/device_utils/__init__.py", line 73, in get_device_bind_status
d_m = await DeviceBind.get_or_none(device_sn=device_sn)
File "/user/.virtualenvs/api/lib/python3.9/site-packages/tortoise/queryset.py", line 1006, in _execute
instance_list = await self._db.executor_class(
File "/user/.virtualenvs/api/lib/python3.9/site-packages/tortoise/backends/base/executor.py", line 138, in execute_select
instance: "Model" = self.model._init_from_db(
File "/user/.virtualenvs/api/lib/python3.9/site-packages/tortoise/models.py", line 742, in _init_from_db
setattr(self, key, meta.fields_map[key].to_python_value(value))
KeyError: 'password'
Version info:
tortoise-orm==0.18.1
aiomysql==0.0.20
Describe the bug The application has been running normally for two years, and there have been frequent KeyError issues recently. By printing SQL and capturing packets, we discovered its specific performance, which usually occurs in SQL with frequent queries. When an error occurs, it is found that the ORM obtains the fields and result sets returned by other SQL executions before the current SQL. Even if the result set is empty, an error will still be reported. Meanwhile, Command Out of Sync will also be reported in other transactions.
To Reproduce We spent several days trying to find a way to reproduce and a solution, but so far we have not found it. As soon as the current problem arises, it will continue to occur and can only be temporarily resolved by restarting the application
Expected behavior Orm obtained the fields and result sets returned by other SQL statements before the current SQL statement
Additional context
Version info: tortoise-orm==0.18.1 aiomysql==0.0.20