Hello hive mind and fearless admins,
We’ve been having an issue where gvmd will periodically (between 15 minutes and a few hours) start throwing sqlite3 and sql_exec_internal errors the first of which is usually cannot start a transaction within a transaction
, and eventually it will cancel a bunch of running scans and restart.
Any ideas on where we can look to track down why this is happening / how to fix it?
I realize this is probably related to this question, but the underlying issue was never addressed there because the OP was in an enterprise situation.
gvmd --version yields:
Greenbone Vulnerability Manager 9.0+alpha~git-ffd53273-master
GIT revision 962e6434-master
See the excerpt below from our gvmd.log:
event target:MESSAGE:2019-05-30 17h35.10 UTC:22515: Target 1015 (86722092-478e-43f4-a3be-0a3ee3d02d00) has been created by xxxx
event task:MESSAGE:2019-05-30 17h35.11 UTC:22617: Status of task (992d9198-c2ef-4794-94a9-28fb35e87b72) has changed to New
event task:MESSAGE:2019-05-30 17h35.11 UTC:22617: Task ff-1015 (992d9198-c2ef-4794-94a9-28fb35e87b72) has been created by xxxx
event task:MESSAGE:2019-05-30 17h35.13 UTC:22686: Status of task ff-1015 (992d9198-c2ef-4794-94a9-28fb35e87b72) has changed to Requested
event task:MESSAGE:2019-05-30 17h35.13 UTC:22686: Task ff-1015 (992d9198-c2ef-4794-94a9-28fb35e87b72) has been requested to start by xxxx
event task:MESSAGE:2019-05-30 17h35.33 UTC:23208: Task ff-1015 (992d9198-c2ef-4794-94a9-28fb35e87b72) could not be started by xxxx
event task:MESSAGE:2019-05-30 17h35.41 UTC:24326: Task ff-1015 (992d9198-c2ef-4794-94a9-28fb35e87b72) could not be started by xxxx
event task:MESSAGE:2019-05-30 17h35.47 UTC:22815: Status of task ff-1015 (992d9198-c2ef-4794-94a9-28fb35e87b72) has changed to Running
event task:MESSAGE:2019-05-30 17h35.48 UTC:24791: Task ff-1015 (992d9198-c2ef-4794-94a9-28fb35e87b72) could not be started by xxxx
a few minutes pass…
md manage:WARNING:2019-05-30 17h38.13 UTC:22815: sql_exec_internal: sqlite3_step failed: cannot start a transaction within a transaction
md manage:WARNING:2019-05-30 17h38.13 UTC:22815: sqlv: sql_exec_internal failed
md manage:WARNING:2019-05-30 17h38.13 UTC:22815: manage_cleanup_process_error: Error exit, setting running task to Interrupted
event task:MESSAGE:2019-05-30 17h38.13 UTC:22815: Status of task ff-1015 (992d9198-c2ef-4794-94a9-28fb35e87b72) has changed to Interrupted
event task:MESSAGE:2019-05-30 17h38.55 UTC:4223: Status of task ff-1036 (35d05dad-5f07-4bd2-aa73-f8c715bfb51b) has changed to Done
event task:MESSAGE:2019-05-30 17h38.59 UTC:7862: Task ff-1036 (35d05dad-5f07-4bd2-aa73-f8c715bfb51b) has been stopped by xxxx
event task:MESSAGE:2019-05-30 17h38.59 UTC:7862: Task ff-1036 (35d05dad-5f07-4bd2-aa73-f8c715bfb51b) has been deleted by xxxx
event report:MESSAGE:2019-05-30 17h38.59 UTC:7862: Report 6b3a018f-9a43-4866-8461-f07074762eb3 has been deleted by xxxx
md manage:WARNING:2019-05-30 17h40.09 UTC:4250: sql_exec_internal: sqlite3_step failed: interrupted
md manage:WARNING:2019-05-30 17h40.09 UTC:4250: next: sql_exec_internal failed
md manage:WARNING:2019-05-30 17h40.09 UTC:4250: manage_cleanup_process_error: Error exit, setting running task to Interrupted
event task:MESSAGE:2019-05-30 17h40.09 UTC:4250: Status of task ff-1035 (24fddede-91e3-4826-9132-a4b6b0eecd16) has changed to Interrupted
md manage:WARNING:2019-05-30 17h40.09 UTC:31745: sql_exec_internal: sqlite3_step failed: interrupted
md manage:WARNING:2019-05-30 17h40.09 UTC:31745: sqlv: sql_exec_internal failed
md manage:WARNING:2019-05-30 17h40.09 UTC:31745: manage_cleanup_process_error: Error exit, setting running task to Interrupted
event task:MESSAGE:2019-05-30 17h40.09 UTC:31745: Status of task ff-2224 (88cd9c5d-b05d-421e-b213-2747ff5ca5bf) has changed to Interrupted
md manage:WARNING:2019-05-30 17h40.09 UTC:4224: sql_exec_internal: sqlite3_step failed: interrupted
md manage:WARNING:2019-05-30 17h40.09 UTC:4224: sqlv: sql_exec_internal failed
md manage:WARNING:2019-05-30 17h40.09 UTC:4224: manage_cleanup_process_error: Error exit, setting running task to Interrupted
event task:MESSAGE:2019-05-30 17h40.09 UTC:4224: Status of task ff-1031 (9b139864-1121-44a2-9260-cbff192b71d1) has changed to Interrupted
md manage:WARNING:2019-05-30 17h40.09 UTC:31746: sql_exec_internal: sqlite3_step failed: interrupted
md manage:WARNING:2019-05-30 17h40.09 UTC:31746: sqlv: sql_exec_internal failed
md manage:WARNING:2019-05-30 17h40.09 UTC:31746: manage_cleanup_process_error: Error exit, setting running task to Interrupted
event task:MESSAGE:2019-05-30 17h40.09 UTC:31746: Status of task ff-2172 (50f7b5f4-4841-4f6a-9fc9-fb3955f64d5f) has changed to Interrupted
md main:MESSAGE:2019-05-30 17h41.39 utc:18382: Greenbone Vulnerability Manager version 9.0+alpha~git-ffd53273-master (GIT revision ffd53273-master) (DB revision 208)
util gpgme:MESSAGE:2019-05-30 17h41.39 utc:18383: Setting GnuPG dir to '/var/lib/gvm/gvmd/gnupg'
util gpgme:MESSAGE:2019-05-30 17h41.39 utc:18383: Using OpenPGP engine version '2.2.4'