Second scan stuck at 0% after 24 hours

nickmcopenvas · December 20, 2023, 8:37am

Hi all, I appreciate your help in advance.

My environment:
Kali 2023.3 (16vCPUs, 32GB RAM, 66% free space on /)
openvas-scanner 22.7.7-1 (amd64)
gvm-libs 22.7.3
Notus Scanner 22.6.2
gvmd 23.1.0
greenbone-security-assistant 22.9.0-1
Feeds are updated every morning (greenbone-feed-sync --type=ALL) thanks to crontab

I scanned a machine for the 1st time a few weeks ago and while it took a while (a few hours) it completed without issue. It found a lot of flaws which related to outdated software which the administrator took care of with an upgrade so I relaunched the same scan to hopefully notice an improvement in security, however the second time around the scan never gets past 0%, it stays stuck at 0% for up to 24 hours.

I can prove with tcpdumps that the Greenbone machine and the target machine can talk and services are discovered (SYN > SYN, ACKs responses between the two). I even created a separate task pointed to the same target and its the same - 0% for hours and hours.

I’ve performed “sudo gvm-stop/start”, I’ve run only successful “sudo gvm-check-setup” and still this scan remains stuck at 0% for up to 24 hours (its the second time around which is typically a lot quicker).

Logs
(the task id that is problematic is 82cc212d-5a7d-4643-abb5-bba77cd2e802):

==> /var/log/gvm/gsad.log <==

==> /var/log/gvm/gvmd.log <==

md manage:MESSAGE:2023-12-20 06h39.10 UTC:1899623: get_nvt_preference_by_id: name of preference 1.3.6.1.4.1.25623.1.0.100509:6 has changed from 'Report vulnerabilities of inactive Linux Kernel(s) separately' to 'Report vulnerabilities of inactive Linux Kernel(s) separately (only for GOS 21.04 and older)'.
md manage:MESSAGE:2023-12-20 06h39.10 UTC:1899623: get_nvt_preference_by_id: name of preference 1.3.6.1.4.1.25623.1.0.111091:1 has changed from 'Report NVT debug logs' to 'Report VT debug logs'.
md manage:MESSAGE:2023-12-20 06h39.13 UTC:1899623: get_nvt_preference_by_id: name of preference 1.3.6.1.4.1.25623.1.0.100509:6 has changed from 'Report vulnerabilities of inactive Linux Kernel(s) separately' to 'Report vulnerabilities of inactive Linux Kernel(s) separately (only for GOS 21.04 and older)'.
md manage:MESSAGE:2023-12-20 06h39.13 UTC:1899623: get_nvt_preference_by_id: name of preference 1.3.6.1.4.1.25623.1.0.111091:1 has changed from 'Report NVT debug logs' to 'Report VT debug logs'.
md manage:MESSAGE:2023-12-20 06h39.15 UTC:1899623: get_nvt_preference_by_id: name of preference 1.3.6.1.4.1.25623.1.0.100509:6 has changed from 'Report vulnerabilities of inactive Linux Kernel(s) separately' to 'Report vulnerabilities of inactive Linux Kernel(s) separately (only for GOS 21.04 and older)'.
md manage:MESSAGE:2023-12-20 06h39.15 UTC:1899623: get_nvt_preference_by_id: name of preference 1.3.6.1.4.1.25623.1.0.111091:1 has changed from 'Report NVT debug logs' to 'Report VT debug logs'.
md manage:MESSAGE:2023-12-20 06h39.16 UTC:1899623: get_nvt_preference_by_id: name of preference 1.3.6.1.4.1.25623.1.0.111091:1 has changed from 'Report NVT debug logs' to 'Report VT debug logs'.
md manage:MESSAGE:2023-12-20 06h39.16 UTC:1899623: get_nvt_preference_by_id: name of preference 1.3.6.1.4.1.25623.1.0.100509:6 has changed from 'Report vulnerabilities of inactive Linux Kernel(s) separately' to 'Report vulnerabilities of inactive Linux Kernel(s) separately (only for GOS 21.04 and older)'.
md manage:MESSAGE:2023-12-20 06h39.17 UTC:1899623: get_nvt_preference_by_id: name of preference 1.3.6.1.4.1.25623.1.0.100509:6 has changed from 'Report vulnerabilities of inactive Linux Kernel(s) separately' to 'Report vulnerabilities of inactive Linux Kernel(s) separately (only for GOS 21.04 and older)'.
md manage:MESSAGE:2023-12-20 06h39.17 UTC:1899623: get_nvt_preference_by_id: name of preference 1.3.6.1.4.1.25623.1.0.111091:1 has changed from 'Report NVT debug logs' to 'Report VT debug logs'.

==> /var/log/gvm/openvas.log <==

sd   main:WARNING:2023-12-20 08h00.15 utc:2049086:82cc212d-5a7d-4643-abb5-bba77cd2e802: There was a problem trying to load secpod_asterisk_detect.nasl, a dependency of Asterisk DoS Vulnerability (AST-2018-007). This may be due to a parse error, or it failed to find the dependency. Please check the path to the file.
sd   main:WARNING:2023-12-20 08h00.15 utc:2049086:82cc212d-5a7d-4643-abb5-bba77cd2e802: There was a problem trying to load secpod_asterisk_detect.nasl, a dependency of Asterisk DoS Vulnerability. This may be due to a parse error, or it failed to find the dependency. Please check the path to the file.
sd   main:WARNING:2023-12-20 08h00.15 utc:2049086:82cc212d-5a7d-4643-abb5-bba77cd2e802: There was a problem trying to load secpod_asterisk_detect.nasl, a dependency of Asterisk DoS Vulnerability. This may be due to a parse error, or it failed to find the dependency. Please check the path to the file.
sd   main:WARNING:2023-12-20 08h00.15 utc:2049086:82cc212d-5a7d-4643-abb5-bba77cd2e802: There was a problem trying to load secpod_asterisk_detect.nasl, a dependency of Asterisk DoS Vulnerability. This may be due to a parse error, or it failed to find the dependency. Please check the path to the file.
sd   main:WARNING:2023-12-20 08h00.15 utc:2049086:82cc212d-5a7d-4643-abb5-bba77cd2e802: There was a problem trying to load secpod_asterisk_detect.nasl, a dependency of Asterisk Audio Transcoding DoS Vulnerability (AST-2019-005). This may be due to a parse error, or it failed to find the dependency. Please check the path to the file.
sd   main:WARNING:2023-12-20 08h00.15 utc:2049086:82cc212d-5a7d-4643-abb5-bba77cd2e802: There was a problem trying to load secpod_asterisk_detect.nasl, a dependency of Asterisk 'CVE-2017-14098' DoS Vulnerability. This may be due to a parse error, or it failed to find the dependency. Please check the path to the file.
sd   main:MESSAGE:2023-12-20 08h00.16 utc:2049086:82cc212d-5a7d-4643-abb5-bba77cd2e802: Vulnerability scan 82cc212d-5a7d-4643-abb5-bba77cd2e802 started: Target has 1 hosts: 159.X.X.238, with max_hosts = 20 and max_checks = 10
libgvm boreas:MESSAGE:2023-12-20 08h00.16 utc:2049086:82cc212d-5a7d-4643-abb5-bba77cd2e802: Alive scan 82cc212d-5a7d-4643-abb5-bba77cd2e802 started: Target has 1 hosts
libgvm boreas:MESSAGE:2023-12-20 08h00.16 utc:2049086:82cc212d-5a7d-4643-abb5-bba77cd2e802: Alive scan 82cc212d-5a7d-4643-abb5-bba77cd2e802 finished in 0 seconds: 1 alive hosts of 1.
sd   main:MESSAGE:2023-12-20 08h00.17 utc:2054395:82cc212d-5a7d-4643-abb5-bba77cd2e802: Vulnerability scan 82cc212d-5a7d-4643-abb5-bba77cd2e802 started for host: 159.X.X.238 (Vhosts: X.X.X)

==> /var/log/gvm/ospd-openvas.log <==

OSPD[1779674] 2023-12-20 07:42:00,004: INFO: (ospd.ospd) Currently 1 queued scans.
OSPD[1779674] 2023-12-20 07:42:00,178: INFO: (ospd.ospd) Starting scan cdee2021-a6a3-4132-adaf-c6313b70cba1.
OSPD[1779674] 2023-12-20 07:42:50,085: WARNING: (ospd_openvas.daemon) Invalid VT oid  for a result
OSPD[1779674] 2023-12-20 07:56:49,388: INFO: (ospd.ospd) cdee2021-a6a3-4132-adaf-c6313b70cba1: Stopping Scan with the PID 1908871.
OSPD[1779674] 2023-12-20 07:56:49,389: INFO: (ospd.ospd) cdee2021-a6a3-4132-adaf-c6313b70cba1: Scan stopped.
OSPD[1779674] 2023-12-20 07:56:50,948: INFO: (ospd.ospd) cdee2021-a6a3-4132-adaf-c6313b70cba1: Host scan finished.
OSPD[1779674] 2023-12-20 07:59:14,655: INFO: (ospd.command.command) Scan 82cc212d-5a7d-4643-abb5-bba77cd2e802 added to the queue in position 2.
OSPD[1779674] 2023-12-20 07:59:20,347: INFO: (ospd.ospd) Currently 1 queued scans.
OSPD[1779674] 2023-12-20 07:59:20,511: INFO: (ospd.ospd) Starting scan 82cc212d-5a7d-4643-abb5-bba77cd2e802.
OSPD[1779674] 2023-12-20 08:00:13,376: WARNING: (ospd_openvas.daemon) Invalid VT oid  for a result

nickmcopenvas · December 20, 2023, 10:04am

I restarted my Kali, did a greenbone sync manually, gvm-check-setup with no errors and then a gvm-stop and start to see if there were any malfunctioning services - none whatsoever.

In doing a tail on the logs I noticed this in starting a new scan of my problematic target.

==> /var/log/gvm/openvas.log <==

sd   main:MESSAGE:2023-12-20 09h59.48 utc:30776:a74a3041-9b16-4adc-9516-6d592de67c00: openvas 22.7.7 started
libgvm util:CRITICAL:2023-12-20 10h00.18 utc:30776:a74a3041-9b16-4adc-9516-6d592de67c00: mqtt_connect: mqtt connection error to localhost:1883: Failure
libgvm util:WARNING:2023-12-20 10h00.18 utc:30776:a74a3041-9b16-4adc-9516-6d592de67c00: mqtt_init: Unable to connect to MQTT broker.
sd   main:MESSAGE:2023-12-20 10h00.18 utc:30776:a74a3041-9b16-4adc-9516-6d592de67c00: attack_network_init: INIT MQTT: FAIL

==> /var/log/gvm/ospd-openvas.log <==
OSPD[6675] 2023-12-20 10:00:19,763: WARNING: (ospd_openvas.daemon) Invalid VT oid for a result

rippledj · December 21, 2023, 1:58pm

Looks like the Mosquito MQTT service is not running. You could have network-related issues such as firewall (see this post) settings blocking the port on localhost, but Kali doesn’t ship with a firewall installed or enabled so unless you installed one, it’s more likely that Mosquitto MQTT service/process is being killed by the OOM Killer.

Unfortunately sudo gvm-check-setup command does not check for the MQTT broker service. You can check it manually like so:

Check the service is running and start it if its not running:

sudo systemctl status mosquito
sudo systemctl start mosquitto

Check it is listening on correct port using netstat (or ss):

$ netstat -tuln | grep 1883
tcp   LISTEN 0      100        127.0.0.1:1883      0.0.0.0:*          
tcp   LISTEN 0      100            [::1]:1883         [::]:*

Check for open connections:

sudo lsof -i :1883
COMMAND    PID      USER   FD   TYPE DEVICE SIZE/OFF NODE NAME
mosquitto 2210 mosquitto    5u  IPv4  19261      0t0  TCP localhost:1883 (LISTEN)
mosquitto 2210 mosquitto    6u  IPv6  19262      0t0  TCP localhost:1883 (LISTEN)
mosquitto 2210 mosquitto    8u  IPv6  19278      0t0  TCP localhost:1883->localhost:55493 (ESTABLISHED)
mosquitto 2210 mosquitto    9u  IPv6  32599      0t0  TCP localhost:1883->localhost:53661 (ESTABLISHED)
notus-sca 2226      _gvm    4u  IPv6  27009      0t0  TCP localhost:55493->localhost:1883 (ESTABLISHED)
ospd-open 2232      _gvm    6u  IPv6  24542      0t0  TCP localhost:53661->localhost:1883 (ESTABLISHED)
ospd-open 2236      _gvm    6u  IPv6  24542      0t0  TCP localhost:53661->localhost:1883 (ESTABLISHED)

Check the logs to look for any errors

sudo tail -100 /var/log/mosquitto/mosquitto.log

To check if the Out-Of-Memory (OOM) Killer has terminated the Mosquitto process on a Linux system, you can inspect the system logs.

sudo grep -i 'oom' /var/log/syslog | grep -i 'mosquitto'

nickmcopenvas · January 8, 2024, 3:26pm

Should have replied to this quite a while back but I was a very busy person at that moment. So for the MQTT service, I implemented iptables rules to protect the Kali machine in a dodgy exposed network and it turned out that they blocked localhost traffic by default so after adding a rule to allow all localhost traffic, MQTT was no longer an issue.

After that I left the job go for around 17 hours and it completed without issues, but bizarrely stayed at 0% for, no joke, 11 to 12 hours which is what made me really feel like it was going nowhere. Turns out I just needed a heap more patience.

Thanks for all your help rippledj. SOLVED.