Issue with Result/Report Fetch Times from GVM

Environment

Operating system: Ubuntu 22.04.3 LTS
Kernel: Linux 5.15.0-107-generic

GVM Versions

gsa: Greenbone Security Assistant 22.06.0
gvm: Greenbone Vulnerability Manager 22.9.0

PostgreSQL Version

PostgreSQL: PostgreSQL 16.0 (Ubuntu 16.0-1.pgdg22.04+1)

Problem

We have observed a problem with the result fetch times from GVM. Whether using the gvm-cli command to get_results (Eg: gvm-cli --gmp-username $GmpUsername --gmp-password $GmpPassword --timeout $current_timeout socket --xml "<get_results filter='rows=$rows first=$offset' task_id=$taskId />") directly or using the GSA, the results page takes a long time to load and sometimes does not load at all, resulting in session timeouts. To test the results fetch time, we wrote scripts to fetch 3378 records present in a scan with 50 records per page and a timeout of 1800 seconds. Initially, it took several hours to fetch all the records.

After researching the forum to find answers, we came across a discussion here which mentioned a potential fix: editing the postgresql.conf file and changing the parameter #jit = on to jit = off. After doing this and restarting the PostgreSQL service, the result fetch worked very quickly, and the GSA UI was loading the results page much faster.

However, after leaving the system idle for a day, we conducted the same test again, and the results fetch time reverted to being slow. This led us to believe that it wasn’t the configuration change that improved the fetch time, but rather the restart of the PostgreSQL service. To test this theory, we restarted the PostgreSQL service and conducted the same test again. This confirmed our hypothesis, as the results fetch was once again very fast.

Below are the logs of both test scenarios (slow and fast before and after the PostgreSQL restart, respectively), showing execution times for each page of the first 10 pages (50 records per page).

Slow Execution Logs (Before PostgreSQL restart):

Completed execution for page 1 in 14 seconds with timeout 1800 seconds.
Completed execution for page 2 in 27 seconds with timeout 1800 seconds.
Completed execution for page 3 in 39 seconds with timeout 1800 seconds.
Completed execution for page 4 in 51 seconds with timeout 1800 seconds.
Completed execution for page 5 in 63 seconds with timeout 1800 seconds.
Completed execution for page 6 in 76 seconds with timeout 1800 seconds.
Completed execution for page 7 in 89 seconds with timeout 1800 seconds.
Completed execution for page 8 in 100 seconds with timeout 1800 seconds.
Completed execution for page 9 in 112 seconds with timeout 1800 seconds.
Completed execution for page 10 in 123 seconds with timeout 1800 seconds.
Fast Execution Logs (After PostgreSQL restart):

Completed execution for page 1 in 1 seconds with timeout 1800 seconds.
Completed execution for page 2 in 0 seconds with timeout 1800 seconds.
Completed execution for page 3 in 1 seconds with timeout 1800 seconds.
Completed execution for page 4 in 1 seconds with timeout 1800 seconds.
Completed execution for page 5 in 0 seconds with timeout 1800 seconds.
Completed execution for page 6 in 1 seconds with timeout 1800 seconds.
Completed execution for page 7 in 1 seconds with timeout 1800 seconds.
Completed execution for page 8 in 1 seconds with timeout 1800 seconds.
Completed execution for page 9 in 0 seconds with timeout 1800 seconds.
Completed execution for page 10 in 1 seconds with timeout 1800 seconds.

This raises the question: what could be going wrong with PostgreSQL after it has been idle for some time? Any suggestions or recommendations are highly appreciated!

Thank you!

Update:

Another observation is that some indexes are dropped from PostgreSQL when the system slows down. The indexes listed below are present when the system is fast but are missing when the system slows down:

public | nvts_by_creation_time | ind
public | nvts_by_cvss_base | ind
public | nvts_by_family | ind
public | nvts_by_modification_time | ind
public | nvts_by_name | ind
public | nvts_by_solution_type | ind
public | vt_refs_by_vt_oid | ind
public | vt_severities_by_vt_oid | inde

Could this be a contributing factor to the slow result fetch times? Any insights or recommendations would be greatly appreciated.

Update:

To test the hypothesis that system performance degrades when specific indexes are dropped, we conducted experiments by intentionally removing the indexes and then restoring them to compare execution times in both scenarios. The results confirmed the hypothesis: execution times increased significantly when the indexes were dropped and returned to optimal levels when the indexes were re-added.

During further analysis, we observed that the ospd-openvas.log contained the following errors when the execution times were slow:

OSPD[1050] 2024-05-31 08:49:41,052: ERROR: (ospd.xmlvt) Not possible to add dependency gb_orangehrm_http_detect.nasl for VT 1.3.6.1.4.1.25623.1.0.100851
OSPD[1050] 2024-05-31 08:49:41,056: ERROR: (ospd.xmlvt) Not possible to add dependency gb_orangehrm_http_detect.nasl for VT 1.3.6.1.4.1.25623.1.0.103132
OSPD[1050] 2024-05-31 08:49:41,065: ERROR: (ospd.xmlvt) Not possible to add dependency gb_orangehrm_http_detect.nasl for VT 1.3.6.1.4.1.25623.1.0.113416
OSPD[1050] 2024-05-31 08:49:41,109: ERROR: (ospd.xmlvt) Not possible to add dependency gb_orangehrm_http_detect.nasl for VT 1.3.6.1.4.1.25623.1.0.902367

Upon further investigation, we discovered that these errors occurred during feed updates. This suggests that the indexes might potentially be getting dropped as a result of the feed updates.

Any suggestions or ideas about why this might be happening would be really helpful in digging deeper towards a potential fix.

Hi Greenbone Community,

Any help or suggestions to tackle this would be highly appreciated!

Thanks!

Hi,

we created an internal ticket and are going to look at this issue.

3 Likes

Update:

Hi Greenbone Community,

After doing some digging, we have identified the root cause of why the indexes are dropping. Below are the details -

Identified Root Cause:
We’ve traced the problem to the feed synchronization process. Here’s a detailed explanation of what’s happening:

  1. Feed Sync Process: The feed sync updates the local VT (Vulnerability Tests) files by copying them from a remote location. The metadata for these VT files is stored in a PostgreSQL database.

  2. Discrepancy in Metadata : When the VT files are updated via feed sync, there’s often a mismatch between the metadata and the actual files. This occurs because the updated files have different hashes than those stored in the database. The logs show errors like this:

update_nvts_from_vts: SHA-256 hash of the VTs in the database (78b6eac1cbda45ff8376397a92a5386369f111965b4a428b0ea9c3689c99b32a) does not match the one from the scanner (e99f1d1979e8ea2e8870bc657db517e2e6c9b298b9e69bd39fab06e4e36bbb80
  1. Internal Process Triggered: Once the VTs are refreshed, an asynchronous internal process is triggered to handle the VT files and update the metadata in the PostgreSQL DB. If a hash mismatch is detected, the process drops the entire VT table, which is where the problem starts.

  2. Dropping and Recreating Tables: When the VT tables are dropped, they are then recreated and populated with fresh metadata from the current VT files. Here’s where the process goes wrong:

Critical Issue
During the table recreation process, the indexes are not being created. This oversight is causing significant performance issues and data retrieval problems, as the indexes are crucial for efficient database operations.

Requesting to please look into this.

Thank you!

2 Likes

Hi Greenbone Community,

Just wanted to check if anyone had a chance to look into this issue yet? Any updates or potential solutions would be greatly appreciated.

Thanks!

Indeed, our developers had a look at it and have prepared a PR: Fix: Also create NVT indexes after rebuild by timopollmeier · Pull Request #2247 · greenbone/gvmd · GitHub

It is not yet merged, and I cannot say when it will be included in a gvmd release, but feel free to try it out!

1 Like

Hey @Martin would be great if you could help us know when this change can potentially get merged.

Meanwhile we will try out the patch/fix internally.

Thanks!

is merged :slight_smile: and available for our products in the next release

greetings
Benjamin

1 Like

Thanks @benjamin.hoener for the update! It is great to know that it is merged.

I was just wondering when is the next release planned. If you could help us with the ETA and the version of the release where this feature would be included it would be a great help!

Thanks
Swapnil

will be available in September.

Benjamin

4 Likes

Hey @benjamin.hoener, could you please let me know the version of Greenbone release in which this fix is available? I need to upgrade and test it in my environment.

Thanks!