"OSP get_scan uuid: Couldn't send get_scans command to scanner" break scan task

wisukind commented 4 years ago

Environment:

Ubuntu 18.04
Greenbone Vulnerability Manager 9.0.1~git-e250176b-gvmd-9.0
GIT revision e250176b-gvmd-9.0
Manager DB revision 221
gvm@ov-master-eqi:~$ gsad --version
Greenbone Security Assistant 9.0.1~git-9fb2e63cd-gsa-9.0
gvm@ov-master-eqi:~$ openvas --version
OpenVAS 7.0.1
gvm-libs 11.0.1

Expected behavior

Scans would finish correctly. Occasional (and short) stream communication error shouldn't break the scan task as a whole, and shouldn't break resuming capability either. ospd-openvas & gvmd should be able to resume sync once the communication channel is up again; while currently once the communication drop once, gvmd consider the task done while ospd-openvas / openvas continue the scan task.

Actual behavior

Hello,

Under GVM-11, latest release build, I’m experimenting sometimes communication bugs between gvmd and ospd-openvas. I occurs on large target scans (around 5000 IP in this case, with many IPs dead). The occurence is not systematic, but seems to happens when there is a connection issue between gvmd and ospd-openvas.

On Gvmd log I had the following message in my logs when this happened:

md manage:WARNING:2020-04-26 04h14.40 CEST:13463: OSP get_scan 4831aff1-58b0-490f-88ca-9d056cee3239: Couldn’t send get_scans command to scanner
event task:MESSAGE:2020-04-26 04h14.51 CEST:13463: Status of task Test1 (a1d72543-539c-49ca-8429-d5452bf9560b) has changed to Stopped

While on ospd-openvas side, I had the following logs:

2020-04-25 10:47:39,107 OSPD - openvas: ERROR: (ospd.server) Error sending data to the client. EOF occurred in violation of protocol (_ssl.c:2162)

Which occasionally repeat:

2020-04-25 12:20:51,067 OSPD - openvas: ERROR: (ospd.server) Error sending data to the client. EOF occurred in violation of protocol (_ssl.c:2162)

At this point if I try to resume the scan from the manager, I get the following errors:

On gvmd:

event task:MESSAGE:2020-04-26 10h27.05 CEST:13352: Status of task Test1 (a1d72543-539c-49ca-8429-d5452bf9560b) has changed to Requested event task:MESSAGE:2020-04-26 10h27.05 CEST:13352: Test1 (a1d72543-539c-49ca-8429-d5452bf9560b) has been resumed by admin md manage:WARNING:2020-04-26 10h27.17 CEST:13355: OSP start_scan 4831aff1-58b0-490f-88ca-9d056cee3239: Couldn’t send stop_scan command to scanner event task:MESSAGE:2020-04-26 10h27.17 CEST:13355: Status of task Test1 (a1d72543-539c-49ca-8429-d5452bf9560b) has changed to Done

And on ospd-openvas side:

2020-04-26 07:49:49,640 OSPD - openvas: DEBUG: (ospd.ospd) Empty client stream
2020-04-26 07:50:00,850 OSPD - openvas: DEBUG: (ospd.ospd) Command error: Scan in progress

Obviously in the background openvas continue to run, and can’t be stopped unless you send kill signals.

Thanks

Steps to reproduce

1) Setup a working gvmd installation with latest revision 2) Setup a remote network OpenVAS scanner with ospd-openvas and register it to gvmd 3) Setup a task using that remote scanner 4) Start task, and wait for it to run normally 5) After a couple of minutes of scan run, simulate a network problem 6) Look at the logs on gvmd, and you may eventually have the same problem. But in all case gvmd will put the task as "Done" while ospd-openvas will continue to run the scan, and you can't resume afterward. It may also put gvmd in a defunct state, which will stop responding to tasks requests.

mrod23 commented 4 years ago

Getting this error also

wisukind commented 3 years ago

Still happens with gvm-20.08.1

y0urself commented 3 years ago

As this issue is really outdated. I will close it for now. If any related bugs occur please create a new issue.

greenbone / gvmd