OpenVAS Scanner : Error 503 service temporarily down when a task is starting

Archive Greenbone Community Edition
1

Hi,

We have a OpenVAS scanner 9 running on Ubuntu 16.04. After a power outage, ou OpenVAS VM shut down improperly and after a normal boot the scanner shows a 503 error when we start a task

# systemctl status openvas-*
● openvas-manager.service - LSB: remote network security auditor - manager
   Loaded: loaded (/etc/init.d/openvas-manager; bad; vendor preset: enabled)
   Active: active (running) since Mon 2019-02-04 15:37:27 EST; 2 weeks 6 days ago
     Docs: man:systemd-sysv-generator(8)
    Tasks: 4
   Memory: 314.0M
      CPU: 7min 49.743s
   CGroup: /system.slice/openvas-manager.service
           ├─ 1362 openvasmd
           ├─ 9836 openvasmd: Reloadin
           ├─ 9837 openvasmd: Updating
           └─10854 gpg-agent --homedir /var/lib/openvas/openvasmd/gnupg --use-standard-socket --daemon

Feb 04 15:37:27  systemd[1]: Starting LSB: remote network security auditor - manager...
Feb 04 15:37:27  systemd[1]: Started LSB: remote network security auditor - manager.

● openvas-scanner.service - LSB: remote network security auditor - scanner
   Loaded: loaded (/etc/init.d/openvas-scanner; **bad**; vendor preset: enabled)
   Active: **failed** (Result: timeout) since Mon 2019-02-25 13:43:32 EST; 18min ago
     Docs: man:systemd-sysv-generator(8)
  Process: 29373 ExecStart=/etc/init.d/openvas-scanner start (code=killed, signal=TERM)
    Tasks: 10
   Memory: 15.5M
      CPU: 224ms
   CGroup: /system.slice/openvas-scanner.service
           ├─ 1261 /usr/sbin/openvassd
           ├─ 2336 /usr/sbin/openvassd
           ├─12081 /usr/sbin/openvassd
           ├─12424 /usr/sbin/openvassd
           ├─19387 /usr/sbin/openvassd
           ├─25853 /usr/sbin/openvassd
           ├─28355 /usr/sbin/openvassd
           ├─28800 /usr/sbin/openvassd
           ├─29379 /usr/sbin/openvassd
           └─32712 /usr/sbin/openvassd

Feb 25 13:38:32  systemd[1]: Starting LSB: remote network security auditor - scanner...
Feb 25 13:38:32  openvas-scanner[29373]: (openvassd:29379): lib  kb_redis-CRITICAL **: fetch_max_db_index: cannot retrieve max DB number: LOADING Redis is loading the
Feb 25 13:43:32  systemd[1]: openvas-scanner.service: Start operation timed out. Terminating.
Feb 25 13:43:32  systemd[1]: Failed to start LSB: remote network security auditor - scanner.
Feb 25 13:43:32  systemd[1]: openvas-scanner.service: Unit entered failed state.
Feb 25 13:43:32  systemd[1]: openvas-scanner.service: Failed with result 'timeout'.

● openvas-gsa.service - LSB: remote network security auditor - gsa
   Loaded: loaded (/etc/init.d/openvas-gsa; bad; vendor preset: enabled)
   Active: active (running) since Mon 2019-02-04 15:37:27 EST; 2 weeks 6 days ago
     Docs: man:systemd-sysv-generator(8)
    Tasks: 8
   Memory: 29.2M
      CPU: 34.337s
   CGroup: /system.slice/openvas-gsa.service
           └─1355 /usr/sbin/gsad --port=4000 --no-redirect

Logs

# tail -40 /var/log/openvas/openvasmd.log
md manage:   INFO:2019-02-07 18h00.15 utc:2788:    Checking alerts.
md   main:MESSAGE:2019-02-08 18h00.13 utc:26234:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-08 18h00.13 utc:26234:    Checking alerts.
md   main:MESSAGE:2019-02-11 18h00.13 utc:28271:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-11 18h00.13 utc:28271:    Checking alerts.
md   main:MESSAGE:2019-02-12 18h00.13 utc:18539:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-12 18h00.13 utc:18539:    Checking alerts.
md   main:MESSAGE:2019-02-13 18h00.13 utc:9379:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-13 18h00.13 utc:9379:    Checking alerts.
md   main:MESSAGE:2019-02-14 18h00.13 utc:31884:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-14 18h00.13 utc:31884:    Checking alerts.
md   main:MESSAGE:2019-02-15 18h00.13 utc:21911:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-15 18h00.13 utc:21911:    Checking alerts.
md   main:MESSAGE:2019-02-16 17h18.11 utc:11496:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-16 17h18.11 utc:11496:    Checking alerts.
md   main:MESSAGE:2019-02-19 18h00.13 utc:23488:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-19 18h00.13 utc:23488:    Checking alerts.
md manage:WARNING:2019-02-20 15h25.01 UTC:10838: sql_exec_internal: sqlite3_step failed: interrupted
md manage:WARNING:2019-02-20 15h25.01 UTC:10838: next: sql_exec_internal failed
md manage:WARNING:2019-02-20 15h25.01 UTC:10838: sql_close: attempt to close db with open statement(s)
md   main:MESSAGE:2019-02-20 17h17.34 utc:13509:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-20 17h17.34 utc:13509:    Checking alerts.
md   main:MESSAGE:2019-02-20 18h00.14 utc:14333:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-20 18h00.14 utc:14333:    Checking alerts.
md   main:MESSAGE:2019-02-21 18h00.13 utc:7912:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-21 18h00.13 utc:7912:    Checking alerts.
md   main:   INFO:2019-02-25 16h00.28 utc:9836:    internal NVT cache update
md   main:   INFO:2019-02-25 16h00.28 utc:9836: rebuild_nvt_cache_retry: Reloading NVT cache
md   main:   INFO:2019-02-25 16h00.28 utc:9837: update_or_rebuild_nvt_cache: Updating NVT cache
md   main:   INFO:2019-02-25 16h00.28 utc:9837:    Updating NVT cache.
md   main:MESSAGE:2019-02-25 18h00.12 utc:12369:    OpenVAS Manager version 7.0.3 (DB revision 184)
md manage:   INFO:2019-02-25 18h00.12 utc:12369:    Checking alerts.
md manage:WARNING:2019-02-25 18h21.35 UTC:12727: sql_exec_internal: sqlite3_step failed: interrupted
md manage:WARNING:2019-02-25 18h21.35 UTC:12727: next: sql_exec_internal failed
md manage:WARNING:2019-02-25 18h21.35 UTC:12727: sql_close: attempt to close db with open statement(s)
md manage:WARNING:2019-02-25 18h21.39 UTC:12740: sql_exec_internal: sqlite3_step failed: interrupted
md manage:WARNING:2019-02-25 18h21.39 UTC:12740: next: sql_exec_internal failed
md manage:WARNING:2019-02-25 18h21.39 UTC:12740: sql_close: attempt to close db with open statement(s)
event task:MESSAGE:2019-02-25 18h21.49 UTC:12775: Task 01  (10.x.x.x) (72f306f6-2e4c-4a2a-8539-cf8bd6134b45) could not be started by admin
event task:MESSAGE:2019-02-25 18h58.25 UTC:29769: Task 01  (10.x.x.x) (72f306f6-2e4c-4a2a-8539-cf8bd6134b45) could not be started by admin

I cannot do an OpenVAS update because it fails to start the proper service.

I cannot find any answers.

Anyone can help us with this ?

Thanks

2

This has very likely the same background like discussed in the existing thread below. To avoid having multiple threads about the same problem open i’m closing this thread as a duplicate for now.

Please follow up in the linked thread below if you have further question. If its not the same problem please let me know and we can re-open this thread.