GVM-CLI [ Remote closed the connection | Failed to parse client XML: Error ]

Hello, I’m using gvm-cli, everything is fine, until I start start_task
Thanks for the suggestions

Note: I worked, only once [ LOG ]

Error:

<start_task task_id Remote closed the connection
/var/log/gvm/gvmd.log Failed to parse client XML: Error

Version product

gvm-cli --version
gvm-cli 2.0.0.beta1. API version 1.0.0.beta2

Linux localhost.localdomain 3.10.0-957.10.1.el7.x86_64 #1 SMP Mon Mar 18 15:06:45 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
CentOS Linux release 7.6.1810 (Core)

GVM-9-

Ok

​gvm-cli socket --socketpath /run/gvmd.sock --xml " <get_version/> "


Ok

gvm-cli socket --socketpath /run/gvmd.sock --xml “<commands><authenticate><credentials><username>MyUser</username><password>MyPassword</password></credentials></authenticate> <get_tasks/> </commands>”


Ok

gvm-cli socket --socketpath /run/gvmd.sock --xml “<commands><authenticate><credentials><username>MyUser</username><password>Mypassword</password></credentials></authenticate> <get_configs/> </commands>”


Ok

gvm-cli socket --socketpath /run/gvmd.sock --xml “<commands><authenticate><credentials><username>MyUser</username><password>MyPassword</password></credentials></authenticate> <get_report_formats/> </commands>”


Ok

[root@localhost ~]# gvm-cli socket --socketpath /run/gvmd.sock --xml "<commands><authenticate><credentials><username>MyUser</username><password>MyPassword</password></credentials></authenticate> <create_target><name>PC User</name><hosts>192.168.1.13</hosts></create_target></commands> "

Resultado Ok

Preformatted text<commands_response status=“200” status_text=“OK”><authenticate_response status=“200” status_text=“OK”><role>Admin</role><timezone>UTC</timezone><severity>nist</severity></authenticate_response><create_target_response status=“201” status_text="OK, resource created" id="8b705063-a0a0-4ccd-9815-52daf1efc9a0 "/></commands_response>

​​------
Ok

[root@localhost ~]# gvm-cli socket --socketpath /run/gvmd.sock --xml “<commands><authenticate><credentials><username>MyUser</username><password>MyPassword</password></credentials><My/authenticate><create_task><name>Task Scan PC User</name><target id="8b705063-a0a0-4ccd-9815-52daf1efc9a0”/>< config id =" 74db13d6-7489-11df-91b9-002264764cea “/><scanner id=“08b69003-5fc2-4037-a479-93b440211c73”/></create_task></commands>”

Resultado Ok

<commands_response status=“200” status_text=“OK”><authenticate_response status=“200” status_text=“OK”><role>Admin</role><timezone>UTC</timezone><severity>nist</severity></authenticate_response><create_task_response status=“201” status_text="OK, resource created" id="798cd269-316a-44c5-abb3-f19d7270079e "/></commands_response>

**ERROR**

[root@localhost ~]# gvm-cli socket --socketpath /run/gvmd.sock --xml “<commands><authenticate><credentials><username>MyUser</username><password>MyPassword</password></credentials></authenticate> <start_task task_id=“798cd269-316a-44c5-abb3-f19d7270079e”/> </commands>”

Remote closed the connection

[root@localhost ~]# tail /var/log/gvm/gvmd.log

md gmp: INFO:2019-04-25 17h01.29 utc:16266: Failed to parse client XML: Error


Log

md main:MESSAGE:2019-04-24 15h18.14 utc:10405: Greenbone Vulnerability Manager version 8.0.0 (DB revision 205)
md main:MESSAGE:2019-04-24 15h18.14 utc:10407: Greenbone Vulnerability Manager version 8.0.0 (DB revision 205)
md main:WARNING:2019-04-24 15h18.14 utc:10407: main: Another process is busy starting up
md manage:WARNING:2019-04-24 15h18.14 utc:10406: sql_prepare_internal: sqlite3_prepare failed: no such table: main.meta
md manage:WARNING:2019-04-24 15h18.14 utc:10406: sql_x_internal: sql_prepare failed
md manage:WARNING:2019-04-24 15h18.14 utc:10406: database must be initialised from scanner
md manage:MESSAGE:2019-04-24 15h18.14 utc:10406: No SCAP database found
md manage:MESSAGE:2019-04-24 15h18.14 utc:10406: No CERT database found
util gpgme:MESSAGE:2019-04-24 15h18.15 utc:10406: Setting GnuPG dir to ‘/var/lib/gvm/gvmd/gnupg’
util gpgme:MESSAGE:2019-04-24 15h18.15 utc:10406: Created GnuPG dir ‘/var/lib/gvm/gvmd/gnupg’
util gpgme:MESSAGE:2019-04-24 15h18.15 utc:10406: Using OpenPGP engine version ‘2.0.22’
util gpgme: INFO:2019-04-24 15h18.15 utc:10406: starting key generation …
util gpgme: INFO:2019-04-24 15h18.15 utc:10406: OpenPGP key ‘GVM Credential Encryption’ has been generated
md manage: INFO:2019-04-24 15h18.15 utc:10430: sync_scap: Initializing SCAP database
md manage:MESSAGE:2019-04-24 15h18.15 utc:10431: No SCAP database found
md manage:MESSAGE:2019-04-24 15h18.15 utc:10431: No CERT database found
md manage:WARNING:2019-04-24 15h18.15 utc:10432: sql_prepare_internal: sqlite3_prepare failed: no such table: scap.ovaldefs
md manage:WARNING:2019-04-24 15h18.15 utc:10432: sqlv: sql_prepare_internal failed
md otp:MESSAGE:2019-04-24 15h18.15 utc:10431: Waiting for scanner to load NVTs: 4600 / 51212
md manage: INFO:2019-04-24 15h18.15 utc:10430: sync_scap: Updating data from feed
md manage: INFO:2019-04-24 15h18.15 utc:10430: Updating CPEs
md manage: INFO:2019-04-24 15h18.25 utc:10435: Initializing CERT database
md manage:MESSAGE:2019-04-24 15h18.25 utc:10436: No CERT database found
md otp:MESSAGE:2019-04-24 15h18.25 utc:10436: Waiting for scanner to load NVTs: 5500 / 51212
md manage: INFO:2019-04-24 15h18.25 utc:10435: sync_cert: Updating data from feed
md manage: INFO:2019-04-24 15h18.25 utc:10435: update_dfn_xml: dfn-cert-2008.xml
md manage: INFO:2019-04-24 15h18.25 utc:10435: Updating /var/lib/gvm/cert-data/dfn-cert-2008.xml
.
.
.
md manage: INFO:2019-04-24 15h18.43 utc:10435: Updating /var/lib/gvm/cert-data/dfn-cert-2018.xml
md otp:MESSAGE:2019-04-24 15h18.45 utc:10445: Waiting for scanner to load NVTs: 7100 / 51212
md manage: INFO:2019-04-24 15h18.46 utc:10435: update_dfn_xml: dfn-cert-2019.xml
md manage: INFO:2019-04-24 15h18.46 utc:10435: Updating /var/lib/gvm/cert-data/dfn-cert-2019.xml
md manage: INFO:2019-04-24 15h18.47 utc:10435: Updating /var/lib/gvm/cert-data/CB-K13.xml
md manage: INFO:2019-04-24 15h18.48 utc:10435: Updating /var/lib/gvm/cert-data/CB-K14.xml
md manage: INFO:2019-04-24 15h18.50 utc:10435: Updating /var/lib/gvm/cert-data/CB-K15.xml
md main:MESSAGE:2019-04-24 15h18.52 utc:10449: Greenbone Vulnerability Manager version 8.0.0 (DB revision 205)
md manage: INFO:2019-04-24 15h18.52 utc:10449: Creating user.
md manage:WARNING:2019-04-24 15h18.52 utc:10449: database must be initialised from scanner
md manage: INFO:2019-04-24 15h18.53 utc:10435: Updating /var/lib/gvm/cert-data/CB-K16.xml
md main:MESSAGE:2019-04-24 15h18.53 utc:10450: Greenbone Vulnerability Manager version 8.0.0 (DB revision 205)
md manage: INFO:2019-04-24 15h18.53 utc:10450: Modifying user password.
md manage:WARNING:2019-04-24 15h18.53 utc:10450: database must be initialised from scanner
md otp:MESSAGE:2019-04-24 15h18.56 utc:10493: Waiting for scanner to load NVTs: 7700 / 51212
md manage: INFO:2019-04-24 15h18.57 utc:10435: Updating /var/lib/gvm/cert-data/CB-K17.xml
md manage: INFO:2019-04-24 15h19.01 utc:10435: Updating /var/lib/gvm/cert-data/CB-K18.xml
md manage: INFO:2019-04-24 15h19.03 utc:10435: Updating /var/lib/gvm/cert-data/CB-K19.xml
md manage: INFO:2019-04-24 15h19.03 utc:10435: Updating Max CVSS for DFN-CERT
md manage: INFO:2019-04-24 15h19.06 utc:10435: Updating DFN-CERT CVSS max succeeded.
md manage: INFO:2019-04-24 15h19.06 utc:10435: Updating Max CVSS for CERT-Bund
md otp:MESSAGE:2019-04-24 15h19.06 utc:10533: Waiting for scanner to load NVTs: 8500 / 51212
md manage: INFO:2019-04-24 15h19.07 utc:10435: Updating CERT-Bund CVSS max succeeded.
md manage: INFO:2019-04-24 15h19.08 utc:10435: sync_cert: Updating CERT info succeeded.
md otp:MESSAGE:2019-04-24 15h19.16 utc:10535: Waiting for scanner to load NVTs: 9550 / 51212
.
.
.
md otp:MESSAGE:2019-04-24 15h26.52 utc:10807: Waiting for scanner to load NVTs: 50800 / 51212
md otp: INFO:2019-04-24 15h27.02 utc:10811: Updating NVT cache
md manage: INFO:2019-04-24 15h30.49 utc:10811: Updating NVT cache… done (50088 NVTs).
md manage: INFO:2019-04-24 15h36.52 utc:10430: Updating /var/lib/gvm/scap-data/nvdcve-2.0-2002.xml
.
.
.
md manage: INFO:2019-04-24 16h05.48 utc:10430: Updating /var/lib/gvm/scap-data/nvdcve-2.0-2019.xml
.
.
.
md manage: INFO:2019-04-24 16h18.46 utc:10430: Updating user OVAL definitions.
md manage: INFO:2019-04-24 16h18.46 utc:10430: Updating CVSS scores and CVE counts for CPEs
md manage: INFO:2019-04-24 16h52.54 utc:10430: Updating CVSS scores for OVAL definitions
md manage: INFO:2019-04-24 16h53.06 utc:10430: Updating placeholder CPEs
md manage: INFO:2019-04-24 16h53.23 utc:10430: sync_scap: Updating SCAP info succeeded
md manage:WARNING:2019-04-24 16h53.29 utc:10430: sql_prepare_internal: sqlite3_prepare failed: no such table: cert.sqlite_master
md manage:WARNING:2019-04-24 16h53.29 utc:10430: sqlv: sql_prepare_internal failed
md gmp: INFO:2019-04-24 19h32.01 utc:34073: Failed to parse client XML: Must authenticate first.
md gmp:WARNING:2019-04-24 19h36.21 utc:34410: Authentication failure for ‘’ from unix_socket
md gmp: INFO:2019-04-24 20h14.34 utc:37477: Failed to parse client XML: Must authenticate first.
md gmp: INFO:2019-04-24 20h19.06 utc:37858: Failed to parse client XML: Must authenticate first.
event target:MESSAGE:2019-04-24 20h20.17 UTC:37953: Target Pc User (53226f41-fc4c-451f-8452-812956ce2d59) has been created by MyUser
event target:MESSAGE:2019-04-24 20h51.35 UTC:40438: Target Tlf Pc User (9dca3797-270d-4ed0-942e-621580739e1d) has been created by MyUser
event task:MESSAGE:2019-04-24 20h53.57 UTC:40620: Status of task (6953c257-0269-4a6d-9f2b-25d53de0d3ce) has changed to New
event task:MESSAGE:2019-04-24 20h53.57 UTC:40620: Task Scan Suspect Host (6953c257-0269-4a6d-9f2b-25d53de0d3ce) has been created by MyUser
event task:MESSAGE:2019-04-24 21h01.11 UTC:41214: Status of task Scan Suspect Host (6953c257-0269-4a6d-9f2b-25d53de0d3ce) has changed to Requested
event task:MESSAGE:2019-04-24 21h01.11 UTC:41214: Task Scan Suspect Host (6953c257-0269-4a6d-9f2b-25d53de0d3ce) has been requested to start by MyUser
event task:MESSAGE:2019-04-24 21h01.22 UTC:41218: Status of task Scan Suspect Host (6953c257-0269-4a6d-9f2b-25d53de0d3ce) has changed to Running
md manage:WARNING:2019-04-24 21h02.53 utc:41343: sql_prepare_internal: sqlite3_prepare failed: interrupted
md manage:WARNING:2019-04-24 21h02.53 utc:41343: sqlv: sql_prepare_internal failed
event task:MESSAGE:2019-04-24 21h03.02 UTC:41218: Status of task Scan Suspect Host (6953c257-0269-4a6d-9f2b-25d53de0d3ce) has changed to Done
event task:MESSAGE:2019-04-25 15h01.03 UTC:11264: Task Task Scan PC User(798cd269-316a-44c5-abb3-f19d7270079e) has been created by MyUser
md gmp: INFO:2019-04-25 15h08.20 utc:11937: Failed to parse client XML: Error
md gmp: INFO:2019-04-25 15h08.43 utc:11972: Failed to parse client XML: Error
event task:MESSAGE:2019-04-25 15h09.04 UTC:12007: Status of task (9825054b-78ce-4a28-b196-173b906d7337) has changed to New

Did you ever resolve this? I’m getting a VERY similar issue.

Same error here, did you guys resolved it?

Hi.

when all your errors are related to this, you need to know that you can’ t use raw " within a string quoted with " itself.
Use a combination of ' and " or escape the inner " by \".
The parser only parses the first part of the XML:

“<commands><authenticate><credentials><username>MyUser</username><password>MyPassword</password></credentials></authenticate> **<start_task task_id=“

And this is indeed invalid XML …

@robert What versions of out software are you using, and what is the command you want to pass?
Some more information would be helpful.

1 Like

Sorry for not providing enough information. I am using gvmd & openvas-scanner & gvm-libs 20.08. The problem is that, after 10-15 mins into a running scan, I am getting Only command GET_VERSION is allowed before AUTHENTICATE (so I am de-authenticated - is that a word?).

Yeah. I guess you will need to adjust your timeout or reconnect to the server … the connection will be closed after a while …

In specific: You are trying to request an answer from the server but you are not authenticated (logged in) anymore, so you are forbidden to request that information …
I am not sure how you are connected to the server … what are you using?

1 Like

The gvm stays inside a docker and I am connecting to it through this method. After I start a task, I am calling get_report() after each 10 seconds. There are some things that are pretty strange:

  • a simple get_report() doesn’t give any exceptions, but the problem is that I get just a small percentage of the results shown on GSA. Meanwhile, get_report() with filters (filter="levels=hml min_qod=70 apply_overrides=0 rows=-1") gives better results, but after 10-15 mins it crashes with the exception I mentioned in my last posts
  • before each get_report() I check is_connected() and is_authenticated() and both return every time true, even before the last get_report() call that throws Only command GET_VERSION is allowed before AUTHENTICATE

… you probably use python-gvm?

So without a rows filter, you will only get 10 Rows … thats default.
How big is your report? How many results are in it?

1 Like

Yes, I am using python-gvm. My report is about 300 findings. I tried with filter="levels=hml min_qod=70 apply_overrides=0") and I am getting the same error.

I took a look on the openvas.log file and it seems to be a problem regarding some time-out. Do you have any recommendations?

sd   main:MESSAGE:2021-02-15 15h46.30 utc:793: Vulnerability scan 1220b51f-ba34-4d77-9e29-7d4fc7961cbf started for host: xyz (Vhosts: xyz)
lib  misc:MESSAGE:2021-02-15 16h05.38 utc:25039: open_sock_tcp: xyz:8000 time-out.
lib  misc:MESSAGE:2021-02-15 16h05.38 utc:25075: open_sock_tcp: xyz:8082 time-out.
lib  misc:MESSAGE:2021-02-15 16h05.48 utc:25094: open_sock_tcp: xyz:3306 time-out.
lib  misc:MESSAGE:2021-02-15 16h05.58 utc:24789: open_sock_tcp: xyz:8000 time-out.
lib  misc:MESSAGE:2021-02-15 16h06.18 utc:25039: open_sock_tcp: xyz:8000 time-out.
lib  misc:MESSAGE:2021-02-15 16h06.18 utc:25075: open_sock_tcp: xyz:8082 time-out.
lib  misc:MESSAGE:2021-02-15 16h06.58 utc:25075: open_sock_tcp: xyz:8082 time-out.
lib  misc:MESSAGE:2021-02-15 16h09.39 utc:25484: open_sock_tcp: xyz:8081 time-out.
lib  misc:MESSAGE:2021-02-15 16h10.19 utc:25484: open_sock_tcp: xyz:8081 time-out.
lib  misc:MESSAGE:2021-02-15 16h10.59 utc:25484: open_sock_tcp: xyz:8081 time-out.
sd   main:MESSAGE:2021-02-15 16h29.52 utc:793: Vulnerability scan 1220b51f-ba34-4d77-9e29-7d4fc7961cbf finished for host xyz in 2602.39 seconds
sd   main:MESSAGE:2021-02-15 16h29.52 utc:782: Vulnerability scan 1220b51f-ba34-4d77-9e29-7d4fc7961cbf finished in 2606 seconds: 1 hosts

Messages from the scanner (openvas is the name of the scanner component only) have nothing to do with the behavior of the gvm-tools. You need to look at the gvmd.log file to see some output.

GMP is a request/response protocol just like HTTP. The connection is closed if an error happens. Until an error occurs you might issue several commands over the connection. But it has never been used for a stable long term connection and it seems this isn’t working well with the authentication. Therefore I would strongly suggest to re-create the connection for long term queries.

To get all results in one response for a report you need to use the ignore_pagination=1 filter keyword like here

2 Likes

The gvmd.log throws a lot of Failed to parse client XML: Must authenticate first. when the problem I have mentioned before occurs. The problem is that, even if I re-create the connection (close it, open it again, with various is_connected() is_authenticated() called in-between), the problem still persists.

I completed a scan with the ignore_pagination=1 filter keyword and I got fewer results, but it didn’t crash.

get_report(report_id=report_id, filter="levels=hml min_qod=70 apply_overrides=0 rows=-1") -> more vulnerabilities reported, but it crashes.

get_report(report_id=report_id, filter="levels=hml min_qod=70 apply_overrides=0 ignore_pagination=1") -> less vulnerabilities reported, doesn’t crash.

You will need to post the actual script you run.
We can’t suggest you any help, if we don’t know, what you are actually doing.
It looks like you mix things up here …
Otherwise I recommend you using gvm-tools, that uses the python-gvm API.
We provide example scripts and different options to connect to the gvmd.

1 Like

Well, I resolved the problem:

  • First, I was ssh-ing to a remote machine, where the script was deployed together with gvm docker. The problem was that I was creating a remote tunnel so I can connect to the gvm from the docker, and that connection was closed automagically after some minutes. Adding ServerAliveInterval 10 to my ssh config did the job.
  • Second, getting the report was taking a lot (most probably due to rows=-1) and that resulted in some time-outs. Increasing the timeout from the default 60s did the job (UnixSocketConnection(path_to_gvmd, timeout=600)).

Now I am experimenting with getting the most of a scan. Right now, get_report(report_id=report_id, filter="levels=hmlg apply_overrides=0 rows=-1") (I am ok with the default min_qod=70) seems to be the best, but if you guys would have some input on this, it would be great. As a use case, I am querying get_report each 10 seconds to show the evolution of the scan results (and the results, of course).

Thank you guys for all the support.

1 Like