Extend script_xref logging on unexpected data / input.

[cfi-gb]

What:

Previously to this change we had the following log entry:

OSPD[9960] 2021-01-23 10:39:35,939: ERROR: (ospd_openvas.daemon) Not possible to parse xref Protocols and Services Are Running for VT 1.3.6.1.4.1.25623.1.0.150070

which had two issues:

1. There was no clear separation between the text of the log message and the text of the malformed xref.
2. The exception info was missing.

After this PR we now have:

OSPD[15404] 2021-01-25 09:02:42,784: ERROR: (ospd_openvas.daemon) Not possible to parse xref "Protocols and Services Are Running" for VT 1.3.6.1.4.1.25623.1.0.150070: not enough values to unpack (expected 2, got 1)

Why:

Better / more consistent logging.

How:

Startup ospd-openvas against the current feed with a VT that has the following script_xref:

script_xref(name:"Policy", value:"CIS Controls Version 7: 9.2 Ensure Only Approved Ports, Protocols and Services Are Running");

Checklist:

• Tests
• CHANGELOG Entry

[codecov]

Codecov Report

Merging #374 (0060051) into ospd-openvas-20.08 (a0675db) will decrease coverage by 0.86%.
The diff coverage is 59.78%.

@@                  Coverage Diff                   @@
##           ospd-openvas-20.08     #374      +/-   ##
======================================================
- Coverage               82.71%   81.84%   -0.87%     
======================================================
  Files                       9        9              
  Lines                    1481     1526      +45     
======================================================
+ Hits                     1225     1249      +24     
- Misses                    256      277      +21     

Impacted Files	Coverage Δ
ospd_openvas/errors.py	100.00% <ø> (ø)
ospd_openvas/vthelper.py	86.61% <0.00%> (-2.10%)	⬇️
ospd_openvas/daemon.py	62.24% <44.44%> (-0.66%)	⬇️
ospd_openvas/db.py	96.24% <57.14%> (-3.36%)	⬇️
ospd_openvas/preferencehandler.py	87.93% <86.95%> (+0.82%)	⬆️
ospd_openvas/__version__.py	100.00% <100.00%> (ø)
ospd_openvas/lock.py	85.96% <100.00%> (+0.25%)	⬆️
ospd_openvas/nvticache.py	98.49% <100.00%> (+0.01%)	⬆️
ospd_openvas/openvas.py	100.00% <100.00%> (ø)

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 4779bff...0060051. Read the comment docs.

[romaaw]

@cfi-gb, can you please clarify if such a log record is an error?

OSPD[15404] 2021-01-25 09:02:42,784: ERROR: (ospd_openvas.daemon) Not possible to parse xref "Protocols and Services Are Running" for VT 1.3.6.1.4.1.25623.1.0.150070: not enough values to unpack (expected 2, got 1)

What should I do to get rid of it?
Thanks.

[jjnicola]

Hi @romaaw,
The problem is the usage of ',' (comma) in the xref's value string, which is currently not supported, and will be fixed soon in the script. Once the script is fixed, after a feed update, the message will disappear.
Regards,
Juan

[cfi-gb]

Note that the topic above is / was completely unrelated and this PR just had extended the logging of this.

The related PR to extend openvas-nasl-lint to check for such currently unsupported chars is currently open at greenbone/openvas-scanner#650 which will prevent that VTs using these are arriving in the feed.