Scans stopping immediately

I’m running community containers using the docker compose file from the docs.
I’ve made some small changes to expose ssh sock and postfix mail.

I’m having some scans run completely fine and through to completion, and other scans stopping at 0%.
Discovery scans run without issue - only the normal/full-and-fast scans are having issues.

Here is an example of one of the scans that is failing:

gvmd_1                 | event task:MESSAGE:2023-05-01 14h26.12 AEST:262: Status of task <redacted> (9d3fb795-88b8-40a8-b759-69d36462cbff) has changed to Requested
gvmd_1                 | event task:MESSAGE:2023-05-01 14h26.12 AEST:262: Task <redacted> (9d3fb795-88b8-40a8-b759-69d36462cbff) has been requested to start by admin
ospd-openvas_1         | OSPD[7] 2023-05-01 04:26:20,718: INFO: (ospd.command.command) Scan c76953ba-af16-49dc-903a-8607833d5265 added to the queue in position 1.
ospd-openvas_1         | OSPD[7] 2023-05-01 04:26:20,959: INFO: (ospd.ospd) Currently 1 queued scans.
ospd-openvas_1         | OSPD[7] 2023-05-01 04:26:21,033: INFO: (ospd.ospd) Starting scan c76953ba-af16-49dc-903a-8607833d5265.
gvmd_1                 | event task:MESSAGE:2023-05-01 14h26.20 AEST:264: Status of <redacted> (9d3fb795-88b8-40a8-b759-69d36462cbff) has changed to Queued
ospd-openvas_1         | OSPD[7] 2023-05-01 04:26:24,241: INFO: (ospd.ospd) c76953ba-af16-49dc-903a-8607833d5265: Stopping Scan with the PID 83.
ospd-openvas_1         | OSPD[7] 2023-05-01 04:26:24,242: INFO: (ospd.ospd) c76953ba-af16-49dc-903a-8607833d5265: Scan stopped.
ospd-openvas_1         | OSPD[7] 2023-05-01 04:26:24,282: INFO: (ospd.ospd) c76953ba-af16-49dc-903a-8607833d5265: Host scan finished.
gvmd_1                 | event task:MESSAGE:2023-05-01 14h26.24 AEST:292: Status of task <redacted> (9d3fb795-88b8-40a8-b759-69d36462cbff) has changed to Stop Requested
gvmd_1                 | event task:MESSAGE:2023-05-01 14h26.24 AEST:292: Status of task <redacted> (9d3fb795-88b8-40a8-b759-69d36462cbff) has changed to Stopped
gvmd_1                 | event task:MESSAGE:2023-05-01 14h26.24 AEST:292: Task <redacted> (9d3fb795-88b8-40a8-b759-69d36462cbff) has been stopped by admin

I have another host exhibiting similar issues, though slightly different:

gvmd_1                 | event task:MESSAGE:2023-05-01 14h24.20 AEST:256: Status of task <redacted> (f89d2708-0463-439e-939c-39d53c0c82fa) has changed to Requested
gvmd_1                 | event task:MESSAGE:2023-05-01 14h24.20 AEST:256: Task <redacted> (f89d2708-0463-439e-939c-39d53c0c82fa) has been requested to start by admin
gvmd_1                 | event task:MESSAGE:2023-05-01 14h24.29 AEST:281: Status of task <redacted> (f89d2708-0463-439e-939c-39d53c0c82fa) has changed to Stopped

OSPD logs are only showing the following:

user@host:~/greenbone-community-container$ docker exec greenbone-community-edition_ospd-openvas_1 cat /var/log/gvm/openvas.log
libgvm util:MESSAGE:2023-05-01 04h24.01 utc:31: Updated NVT cache from version 0 to 202304281209

I tried a rollback from gvmd:stable to gvmd:22.4.1 as was suggested in another post from some time ago and didn’t see any improvement.

Feed status is up to date according to the console, however I’ve also tried deleting all of the containers, removing all volumes except psql_data and firing up the containers again. Also without improvement.

Anyone have any thoughts?

I’ve switched back to gvmd:22.4.2, and found that the scan is saying that it’s stopped, but it’s very clearly running in the background.

I’ve seen mention in forum posts and some older issues in github talking about GSA and GVMD losing sync and seeing the scans differently. Not sure if this is the same thing or not:

gvmd_1           | event task:MESSAGE:2023-05-01 15h42.42 AEST:602: Status of task <redacted> (f89d2708-0463-439e-939c-39d53c0c82fa) has changed to Requested
gvmd_1           | event task:MESSAGE:2023-05-01 15h42.42 AEST:602: Task <redacted> (f89d2708-0463-439e-939c-39d53c0c82fa) has been requested to start by admin
gvmd_1           | event task:MESSAGE:2023-05-01 15h42.54 AEST:634: Status of task <redacted> (f89d2708-0463-439e-939c-39d53c0c82fa) has changed to Stopped
ospd-openvas_1   | OSPD[8] 2023-05-01 05:43:09,882: INFO: (ospd.command.command) Scan 7f0b65a6-e690-482a-b7ce-4b115d624fbc added to the queue in position 2.
ospd-openvas_1   | OSPD[8] 2023-05-01 05:43:13,060: INFO: (ospd.ospd) Currently 1 queued scans.
ospd-openvas_1   | OSPD[8] 2023-05-01 05:43:13,261: INFO: (ospd.ospd) Starting scan 7f0b65a6-e690-482a-b7ce-4b115d624fbc.
mqtt-broker_1    | 1682919823: New connection from 172.27.0.4:41600 on port 1883.
mqtt-broker_1    | 1682919823: New client connected from 172.27.0.4:41600 as 7209b463-587d-4797-bd52-5d0dd5261043 (p5, c1, k0).

Greenbone Vulnerability Manager 22.4.2
Greenbone Security Assistant 22.04.0
OSPd OpenVAS: 22.4.6

And after a whole day of troubleshooting, numerous docker-composing and lots of deleted volumes… A simple reboot has solved the issue.

Ok. It’s come back again.

greenbone-community-edition-gvmd-1                 | event task:MESSAGE:2023-05-02 11h25.49 AEST:330: Status of task <redacted> (9d3fb795-88b8-40a8-b759-69d36462cbff) has changed to Requested
greenbone-community-edition-gvmd-1                 | event task:MESSAGE:2023-05-02 11h25.49 AEST:330: Task <redacted> (9d3fb795-88b8-40a8-b759-69d36462cbff) has been requested to start by admin
greenbone-community-edition-gvmd-1                 | event task:MESSAGE:2023-05-02 11h26.01 AEST:362: Status of task <redacted> (9d3fb795-88b8-40a8-b759-69d36462cbff) has changed to Stopped
greenbone-community-edition-ospd-openvas-1         | OSPD[7] 2023-05-02 01:26:10,773: INFO: (ospd.command.command) Scan 4316b248-eef6-40f4-8ad6-7306541b53c5 added to the queue in position 1.
greenbone-community-edition-ospd-openvas-1         | OSPD[7] 2023-05-02 01:26:18,430: INFO: (ospd.ospd) Currently 1 queued scans.
greenbone-community-edition-ospd-openvas-1         | OSPD[7] 2023-05-02 01:26:18,629: INFO: (ospd.ospd) Starting scan 4316b248-eef6-40f4-8ad6-7306541b53c5.
greenbone-community-edition-mqtt-broker-1          | 1682990801: New connection from 172.18.0.7:58866 on port 1883.
greenbone-community-edition-mqtt-broker-1          | 1682990801: New client connected from 172.18.0.7:58866 as 5e82308a-0eca-41db-9a79-e73eedae9b3f (p5, c1, k0).

Could this be related to https://github.com/greenbone/gvmd/issues/1668 ?

I’ve done a full rebuild on a different machine and still facing the same issue.
I’m waiting for all of the feeds to update before I start a scan, i.e. VT cache update, VT database update, SCAP CERT, scan config, etc.

I’ve found that running a discovery scan works fine and completes successfully, and a scan out to the internet also works fine.

So this issue only appears when scanning the local subnet of the scanner.
When scanning the local network I’m getting scan interrupted at 0%.

I’ve narrowed down the issue to be related to using a custom schedule, where the schedule repeats on the nth day of the month.
If I remove the schedule from the task, or change the schedule to be something other than custom (such as daily, or weekly), the scan runs successfully.
If I put the schedule back on and attempt to run the scan manually again, the scan will fail at 0%.

I’ve raised this as an issue - https://github.com/greenbone/gvmd/issues/1976