Prevent api-server SQLite lock error

[DavidePrincipi]

During NS7 migration I got this error in logs several times:

Aug 08 21:31:47 myhost api-server[32961]: [AUDIT][STORE] error in audit file schema execute: database is locked

At the same second a Mail action failed:

Aug 08 21:31:42 myhost agent@mail2[41529]: task/module/mail2/0db2521d-c94d-43cc-9367-df53bd6d9173: configure-module/90certificate is starting
Aug 08 21:31:47 myhost agent@mail2[41529]: Traceback (most recent call last):
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/home/mail2/.config/actions/configure-module/90certificate", line 16, in <module>
Aug 08 21:31:47 myhost agent@mail2[41529]:     agent.tasks.run_nowait(
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/local/agent/pypkg/agent/tasks/run.py", line 45, in run_nowait
Aug 08 21:31:47 myhost agent@mail2[41529]:     return run(agent_id, action, data, nowait=True, **kwargs)
Aug 08 21:31:47 myhost agent@mail2[41529]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/local/agent/pypkg/agent/tasks/run.py", line 39, in run
Aug 08 21:31:47 myhost agent@mail2[41529]:     results = runp([taskrq], **kwargs)
Aug 08 21:31:47 myhost agent@mail2[41529]:               ^^^^^^^^^^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/local/agent/pypkg/agent/tasks/run.py", line 50, in runp
Aug 08 21:31:47 myhost agent@mail2[41529]:     return asyncio.run(_runp(tasks, **kwargs))
Aug 08 21:31:47 myhost agent@mail2[41529]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/lib64/python3.11/asyncio/runners.py", line 190, in run
Aug 08 21:31:47 myhost agent@mail2[41529]:     return runner.run(main)
Aug 08 21:31:47 myhost agent@mail2[41529]:            ^^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/lib64/python3.11/asyncio/runners.py", line 118, in run
Aug 08 21:31:47 myhost agent@mail2[41529]:     return self._loop.run_until_complete(task)
Aug 08 21:31:47 myhost agent@mail2[41529]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/lib64/python3.11/asyncio/base_events.py", line 653, in run_until_complete
Aug 08 21:31:47 myhost agent@mail2[41529]:     return future.result()
Aug 08 21:31:47 myhost agent@mail2[41529]:            ^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/local/agent/pypkg/agent/tasks/run.py", line 120, in _runp
Aug 08 21:31:47 myhost agent@mail2[41529]:     return await asyncio.gather(*runners, return_exceptions=(len(tasks) > 1))
Aug 08 21:31:47 myhost agent@mail2[41529]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/local/agent/pypkg/agent/tasks/run.py", line 136, in _run_with_protocol_nowait
Aug 08 21:31:47 myhost agent@mail2[41529]:     return await run_apiclient_nowait(taskrq, **pconn)
Aug 08 21:31:47 myhost agent@mail2[41529]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/local/agent/pypkg/agent/tasks/apiclient.py", line 35, in run_apiclient_nowait
Aug 08 21:31:47 myhost agent@mail2[41529]:     return await _retry_request(_apost_task, taskrq, client=client, theaders=theaders, **kwargs)
Aug 08 21:31:47 myhost agent@mail2[41529]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/local/agent/pypkg/agent/tasks/apiclient.py", line 191, in _retry_request
Aug 08 21:31:47 myhost agent@mail2[41529]:     raise exhttp
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/local/agent/pypkg/agent/tasks/apiclient.py", line 166, in _retry_request
Aug 08 21:31:47 myhost agent@mail2[41529]:     retval = await request_procedure(*args, **kwargs)
Aug 08 21:31:47 myhost agent@mail2[41529]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/local/agent/pypkg/agent/tasks/apiclient.py", line 258, in _apost_task
Aug 08 21:31:47 myhost agent@mail2[41529]:     jresp = await resp.json()
Aug 08 21:31:47 myhost agent@mail2[41529]:             ^^^^^^^^^^^^^^^^^
Aug 08 21:31:47 myhost agent@mail2[41529]:   File "/usr/local/agent/pyenv/lib64/python3.11/site-packages/aiohttp/client_reqrep.py", line 1104, in json
Aug 08 21:31:47 myhost agent@mail2[41529]:     raise ContentTypeError(
Aug 08 21:31:47 myhost agent@mail2[41529]: aiohttp.client_exceptions.ContentTypeError: 0, message='Attempt to decode JSON with unexpected mimetype: ', url=URL('http://cluster-leader:9311/api/module/traefik1/tasks')
Aug 08 21:31:47 myhost agent@mail2[41529]: task/module/mail2/0db2521d-c94d-43cc-9367-df53bd6d9173: action "configure-module" status is "aborted" (1) at step 90certificate
Aug 08 21:31:50 myhost agent@mail2[41529]: The configure-module subtask failed!
Aug 08 21:31:50 myhost agent@mail2[41529]:   File "/home/mail2/.config/actions/import-module/40configure_module", line 16, in <module>
Aug 08 21:31:50 myhost agent@mail2[41529]:     agent.assert_exp(configure_retval['exit_code'] == 0, "The configure-module subtask failed!")
Aug 08 21:31:50 myhost agent@mail2[41529]: task/module/mail2/a527fd59-2e85-4be0-a367-9f71da00f063: action "import-module" status is "aborted" (2) at step 40configure_module

Context:

• The NS8 system has a relatively slow spinning disk
• NS7 was polling api-server every two seconds from Webtop and Imapsync

Discussion

• https://mattermost.nethesis.it/nethesis/pl/4pb3bnq55idnznsgehzba14wuo
• https://mattermost.nethesis.it/nethesis/pl/ugjcjijs8p8cdm7j7xtgs6hy3h

[DavidePrincipi]

In Testing core 3.13.0-dev.3

Test case

To reproduce the bug condition a slow disk is necessary. In KVM it is possible to throttle the disk iops and simulate a slow disk with a command like:

virsh blkdeviotune rocky9 vda --read-iops-sec=10 --write-iops-sec=10 --live

Check the bug is reproducible, for example during a Mail + Webtop migration, and after update to the Testing version api-server does no longer return the locked DB error.