search

immauss / openvas

Containers for running the Greenbone Vulnerability Manager. Run as a single container with all services or separate single applications containers via docker-compose.
GNU Affero General Public License v3.0
353 stars 102 forks source link

Gathering the reports is incredibly slow #31

Closed mflage closed 3 years ago

mflage commented 3 years ago

When trying to browse through the reports generated it's very slow to retrieve the results. Just sorting the Severity from high to low takes 30+ seconds to complete and during this process I can see that postgres is running at 100 % CPU. I believe this is not an issue related to this dockerization of OpenVAS, but maybe something related to OpenVAS itself? Do you see the same?

immauss commented 3 years ago

Actually, I noticed the same on my production recently. I attributed it to the performance on the node running my container, but maybe I need to look into it more. If I find something, I'll let you know.

Thanks, Scott

mflage commented 3 years ago

I see the same thing happens when running the non-docker version of OpenVAS. It's incredibly slow. It's like some indices are missing in the database. Gathering the results from a report takes 30+ seconds. So I think it's related to OpenVAS and not the container.

immauss commented 3 years ago

I took a closer look at my production box. What I saw was that postgres seems to peg the CPU at 100% for a while when you first open a report. If you wait until it's done, CPU drops, then you can go through the report, re-sort, filter, etc .. and it's pretty snappy. I'm not going to pretend to fully understand the internals of gvm, but I do know that the build process includes some modules that are used by postgres. I suspect that those are indexing the report when you first open it, but not maintaining those indexes for later use. I could be wrong, I'll ask in the GVM communty forums and see if I can get some confirmation and maybe an answer on how to improve the performance.

Thanks, Scott

immauss commented 3 years ago

So .... I've done a little researching. It seems GVM 20.08 has some issues with postgresql 12. :/ This was not apparent when I started out with this version. The recommendation is to use postgresql 11. Unfortunately, that means converting an old DB may be a pain. Additionally, if someone who is already using the container with 12, and I switch it to 11, then it could cause some unexpected issues for them if they pull the latest container ....

All that to say ... I'm working on a version with 11, but I have to be careful how it's deployed if it improves the performance.

If you want to help test, please let me know.

Thanks, Scott

gareth-johnstone commented 3 years ago

So .... I've done a little researching. It seems GVM 20.08 has some issues with postgresql 12. :/ This was not apparent when I started out with this version. The recommendation is to use postgresql 11. Unfortunately, that means converting an old DB may be a pain. Additionally, if someone who is already using the container with 12, and I switch it to 11, then it could cause some unexpected issues for them if they pull the latest container ....

All that to say ... I'm working on a version with 11, but I have to be careful how it's deployed if it improves the performance.

If you want to help test, please let me know.

Thanks, Scott

We have a bunch of boxes we could stick a copy on to help test as well

immauss commented 3 years ago

OK ... so I have been doing some testing with 21.04 and postgres 12. It seems to be much better. But I dont' have that big of a network to test on.
NOW.... I have NOT done any testing with upgrading an existing DB. That's on the list for later this week, maybe this weekend. I know it will be tricky because there is bug already found regarding upgrades/migrations. So .... if you want to test it, I'll push it up with the 21.04-beta tag. But make sure you dont' try to upgrade an existing DB with it as I'm pretty sure it will crash and might even wipe your current DB.

larsnaesbye commented 3 years ago

I tried it briefly 10 minutes ago, and when I went to /login it automatically logged me in (could be an old session), but a lot of menu items were missing.

immauss commented 3 years ago

@larsnaesbye Can you give me more detail? How did you start it? If it was a new container, it should not have just logged you in unless you have an auto password filler for admin/admin ... What menu options were missing? How long after start did you try to login? Was the login page drastically different? (It should be.)

larsnaesbye commented 3 years ago

@immauss apparently I just had to wait longer before trying. It looks good now :)

larsnaesbye commented 3 years ago

Scanning in progress looks good ... but viewing the results gives an error:

image

larsnaesbye commented 3 years ago

Looks suspiciously like this : https://community.greenbone.net/t/gvm20-08-reports-page-doensnt-work-shows-error-typeerror-s-is-undefined-typeerror-cannot-read-property-scan-run-status-of-undefined/6562

larsnaesbye commented 3 years ago

Possibly a permissions issue on the reports :)

immauss commented 3 years ago

That should have been fixed long ago based on following the thread. I ran a few scans on it last night and didn't have any issues with the reports. Is there anything unusual about your docker setup? More specifically, are you using a persistent volume that is on a partition mounted with the "noexec" option?

larsnaesbye commented 3 years ago

No, I'm not using a persistent volume. Maybe that's a better option.

cybermcm commented 3 years ago

testing latest 21.04-beta. There seems to be more speed (fine) and settings are working now without issues (do not worked correctly before) but I've got the same error with the results image

started with a "fresh" container

openvas:
  container_name: openvas
  environment:
   - PASSWORD=xxx
   - RELAYHOST=exchange.xxx
   - SKIPSYNC=true
  hostname: openvas.xxx
  image: immauss/openvas:21.04-beta
  labels:
   - com.centurylinklabs.watchtower.enable=true
  ports:
   - 8083:9392
  restart: always
  volumes:
   - /opt/docker/openvas:/data
immauss commented 3 years ago

I'm not seeing this with the most recent. I just pushed it to docker.hub.
I'm scanning 10 hosts, and the results are snappy and I'm not getting the same error you are. Let me know.

Thanks, Scott

cybermcm commented 3 years ago

Just tried from scratch with the current 21.04-beta image, still the same error with the reports page. Any log/config I should provide?

immauss commented 3 years ago

Hmmm What are you scanning? I've scanned a few real hosts and I've also scanned 20+ containers using my "scannable" container, and I'm still not seeing that. What browser are you using and what is the host distribution? I feel like this is an internal GVM thing though, and not related to the container itself, but I want to try to isolate as much as possible.

Can you send the outputs from:

docker logs

mount

docker version

cat /proc/meminfo

cybermcm commented 3 years ago

scanning a real host (for the time being currently only one, log redacted) browser: FF and Chrome (same error) Host: Debian 10.9 (all updates in place) docker logs:

docker logs openvas
8:C 02 May 2021 08:33:49.571 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
8:C 02 May 2021 08:33:49.571 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=8, just started
8:C 02 May 2021 08:33:49.571 # Configuration loaded
Wait for redis socket to be created...
Testing redis status...
Redis ready.
Creating Data and database folder...
Fixing Database folder...
Fixing local/var/lib ...
Fixing local/share ...
Creating postgresql.conf and pg_hba.conf
Starting PostgreSQL...
waiting for server to start....2021-05-02 06:33:57.989 GMT [37] LOG:  starting PostgreSQL 12.6 (Ubuntu 12.6-1.pgdg20.04+1) on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 9.3.0-17ubuntu1~20.04) 9.3.0, 64-bit
2021-05-02 06:33:57.990 GMT [37] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2021-05-02 06:33:57.990 GMT [37] LOG:  listening on IPv6 address "::", port 5432
2021-05-02 06:33:57.993 GMT [37] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2021-05-02 06:33:58.005 GMT [37] LOG:  could not open usermap file "/data/database/pg_ident.conf": No such file or directory
2021-05-02 06:33:58.007 GMT [38] LOG:  database system was shut down at 2021-04-30 23:56:21 GMT
2021-05-02 06:33:58.015 GMT [37] LOG:  database system is ready to accept connections
 done
server started
Running first start configuration...
Adding gvm user
Fixing feed rsync options
Generating certs...
Generated private key in /tmp/tmp.DwuRPAZh8Q/cakey.pem.
Generated self signed certificate in /tmp/tmp.DwuRPAZh8Q/cacert.pem.
Installed private key to /usr/local/var/lib/gvm/private/CA/cakey.pem.
Installed certificate to /usr/local/var/lib/gvm/CA/cacert.pem.
Generated private key in /tmp/tmp.DwuRPAZh8Q/serverkey.pem.
Generated certificate request in /tmp/tmp.DwuRPAZh8Q/serverrequest.pem.
Signed certificate request in /tmp/tmp.DwuRPAZh8Q/serverrequest.pem with CA certificate in /usr/local/var/lib/gvm/CA/cacert.pem to generate certificate in /tmp/tmp.DwuRPAZh8Q/servercert.pem
Installed private key to /usr/local/var/lib/gvm/private/CA/serverkey.pem.
Installed certificate to /usr/local/var/lib/gvm/CA/servercert.pem.
Generated private key in /tmp/tmp.DwuRPAZh8Q/clientkey.pem.
Generated certificate request in /tmp/tmp.DwuRPAZh8Q/clientrequest.pem.
Signed certificate request in /tmp/tmp.DwuRPAZh8Q/clientrequest.pem with CA certificate in /usr/local/var/lib/gvm/CA/cacert.pem to generate certificate in /tmp/tmp.DwuRPAZh8Q/clientcert.pem
Installed private key to /usr/local/var/lib/gvm/private/CA/clientkey.pem.
Installed certificate to /usr/local/var/lib/gvm/CA/clientcert.pem.
Removing temporary directory /tmp/tmp.DwuRPAZh8Q.
########################################
Creating a base DB from /usr/lib/base-db.xz
base data from:
Mon Apr  5 11:07:16 UTC 2021
########################################
2021-05-02 06:34:39.442 GMT [111] ERROR:  canceling autovacuum task
2021-05-02 06:34:39.442 GMT [111] CONTEXT:  automatic analyze of table "gvmd.scap.affected_products"
2021-05-02 06:34:43.454 GMT [111] ERROR:  canceling autovacuum task
2021-05-02 06:34:43.454 GMT [111] CONTEXT:  automatic analyze of table "gvmd.scap.cpes"
Unpacking base feeds data from /usr/lib/var-lib.tar.xz
Migrating the database to the latest version if needed.
2021-05-02 06:46:27.152 GMT [235] ERROR:  canceling autovacuum task
2021-05-02 06:46:27.152 GMT [235] CONTEXT:  automatic vacuum of table "gvmd.scap.ovaldefs"
2021-05-02 06:47:24.258 GMT [238] WARNING:  skipping "pg_toast_1260" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_1260_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_1262" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_1262_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_2964" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_2964_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_1136" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_1136_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_6000" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_6000_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_2396" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_2396_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_3592" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_3592_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_6100" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_6100_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_1213" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_toast_1213_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_authid_rolname_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_authid_oid_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_auth_members_role_member_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_auth_members_member_role_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_database_datname_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_database_oid_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_shdescription_o_c_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_pltemplate_name_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_shdepend_depender_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_shdepend_reference_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_tablespace_oid_index" --- only superuser can analyze it
2021-05-02 06:47:24.259 GMT [238] WARNING:  skipping "pg_tablespace_spcname_index" --- only superuser can analyze it
2021-05-02 06:47:24.260 GMT [238] WARNING:  skipping "pg_db_role_setting_databaseid_rol_index" --- only superuser can analyze it
2021-05-02 06:47:24.260 GMT [238] WARNING:  skipping "pg_shseclabel_object_index" --- only superuser can analyze it
2021-05-02 06:47:24.260 GMT [238] WARNING:  skipping "pg_replication_origin_roiident_index" --- only superuser can analyze it
2021-05-02 06:47:24.260 GMT [238] WARNING:  skipping "pg_replication_origin_roname_index" --- only superuser can analyze it
2021-05-02 06:47:24.260 GMT [238] WARNING:  skipping "pg_subscription_oid_index" --- only superuser can analyze it
2021-05-02 06:47:24.260 GMT [238] WARNING:  skipping "pg_subscription_subname_index" --- only superuser can analyze it
2021-05-02 06:47:24.260 GMT [238] WARNING:  skipping "pg_authid" --- only superuser can analyze it
2021-05-02 06:47:24.260 GMT [238] WARNING:  skipping "pg_subscription" --- only superuser can analyze it
2021-05-02 06:47:24.261 GMT [238] WARNING:  skipping "pg_database" --- only superuser can analyze it
2021-05-02 06:47:24.261 GMT [238] WARNING:  skipping "pg_db_role_setting" --- only superuser can analyze it
2021-05-02 06:47:24.261 GMT [238] WARNING:  skipping "pg_tablespace" --- only superuser can analyze it
2021-05-02 06:47:24.261 GMT [238] WARNING:  skipping "pg_pltemplate" --- only superuser can analyze it
2021-05-02 06:47:24.261 GMT [238] WARNING:  skipping "pg_auth_members" --- only superuser can analyze it
2021-05-02 06:47:24.261 GMT [238] WARNING:  skipping "pg_shdepend" --- only superuser can analyze it
2021-05-02 06:47:24.261 GMT [238] WARNING:  skipping "pg_shdescription" --- only superuser can analyze it
2021-05-02 06:47:24.261 GMT [238] WARNING:  skipping "pg_replication_origin" --- only superuser can analyze it
2021-05-02 06:47:24.261 GMT [238] WARNING:  skipping "pg_shseclabel" --- only superuser can analyze it
2021-05-02 06:47:29.021 GMT [239] ERROR:  canceling autovacuum task
2021-05-02 06:47:29.021 GMT [239] CONTEXT:  automatic vacuum of table "gvmd.scap.ovaldefs"
Removing feed-update.lock
Starting Greenbone Vulnerability Manager...
Waiting for gvmd
Waiting for gvmd
admin
Setting admin password
reset
Starting Postfix for report delivery by email
 * Starting Postfix Mail Transport Agent postfix
   ...done.
Starting Open Scanner Protocol daemon for OpenVAS...
Fixing the ospd socket ...
Starting Greenbone Security Assistant...
Oops, secure memory pool already initialized
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
+ Your GVM/openvas/postgresql container is now ready to use! +
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

gvmd --version
Greenbone Vulnerability Manager 21.4.0
Manager DB revision 242
Copyright (C) 2009-2021 Greenbone Networks GmbH
License: AGPL-3.0-or-later
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

++++++++++++++++
+ Tailing logs +
++++++++++++++++
==> /usr/local/var/log/gvm/gsad.log <==
gsad main:MESSAGE:2021-05-02 06h47.45 utc:942: Starting GSAD version 21.04.0

==> /usr/local/var/log/gvm/gvmd.log <==
md   main:   INFO:2021-05-02 06h47.36 utc:172:    Migration succeeded.
md   main:MESSAGE:2021-05-02 06h47.36 utc:244:    Greenbone Vulnerability Manager version 21.4.0 (DB revision 242)
md   main:MESSAGE:2021-05-02 06h47.36 utc:249:    Greenbone Vulnerability Manager version 21.4.0 (DB revision 242)
md   main:WARNING:2021-05-02 06h47.36 utc:249: gvmd: Another process is busy starting up
md   main:MESSAGE:2021-05-02 06h47.37 utc:269:    Greenbone Vulnerability Manager version 21.4.0 (DB revision 242)
md   main:WARNING:2021-05-02 06h47.37 utc:269: gvmd: Another process is busy starting up
md   main:MESSAGE:2021-05-02 06h47.38 utc:276:    Greenbone Vulnerability Manager version 21.4.0 (DB revision 242)
md manage:   INFO:2021-05-02 06h47.38 utc:276:    Getting users.
md   main:MESSAGE:2021-05-02 06h47.39 utc:281:    Greenbone Vulnerability Manager version 21.4.0 (DB revision 242)
md manage:   INFO:2021-05-02 06h47.39 utc:281:    Modifying user password.

==> /usr/local/var/log/gvm/openvas.log <==

==> /usr/local/var/log/gvm/ospd-openvas.log <==
OSPD[925] 2021-05-02 08:47:45,815: INFO: (ospd.main) Starting OSPd OpenVAS version 21.4.0.

==> /usr/local/var/log/gvm/openvas.log <==
lib  nvticache:MESSAGE:2021-05-02 06h48.55 utc:954: Updated NVT cache from version 0 to 202104231026

==> /usr/local/var/log/gvm/gsad.log <==
gsad  gmp:MESSAGE:2021-05-02 06h50.46 utc:944: Authentication success for 'admin' from 192.168.10.1

==> /usr/local/var/log/gvm/gvmd.log <==
event target:MESSAGE:2021-05-02 08h51.11 CEST:1111: Target xxx.com (8863a806-b0a4-46c8-9fae-dc9d9a8aa8f4) has been created by admin
event task:MESSAGE:2021-05-02 08h51.36 CEST:1222: Status of task  (c44ae960-ef03-4b59-b462-603175b6a183) has changed to New
event task:MESSAGE:2021-05-02 08h51.36 CEST:1222: Task xxx.com (c44ae960-ef03-4b59-b462-603175b6a183) has been created by admin
event task:MESSAGE:2021-05-02 08h51.40 CEST:1256: Status of task xxx.com (c44ae960-ef03-4b59-b462-603175b6a183) has changed to Requested
event task:MESSAGE:2021-05-02 08h51.40 CEST:1256: Task xxx.com (c44ae960-ef03-4b59-b462-603175b6a183) has been requested to start by admin
event task:MESSAGE:2021-05-02 08h51.42 CEST:1262: Status of task xxx.com (c44ae960-ef03-4b59-b462-603175b6a183) has changed to Queued

==> /usr/local/var/log/gvm/ospd-openvas.log <==
OSPD[925] 2021-05-02 08:51:42,868: INFO: (ospd.command.command) Scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0 added to the queue in position 1.
OSPD[925] 2021-05-02 08:51:52,246: INFO: (ospd.ospd) Currently 1 queued scans.
OSPD[925] 2021-05-02 08:51:52,261: INFO: (ospd.ospd) Starting scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0.

==> /usr/local/var/log/gvm/gvmd.log <==
event task:MESSAGE:2021-05-02 08h51.52 CEST:1262: Status of task xxx.com (c44ae960-ef03-4b59-b462-603175b6a183) has changed to Running
event filter:MESSAGE:2021-05-02 08h52.03 CEST:1444: Filter Tasks0 (75a70ca8-5bae-4d13-9708-29ebb6d6bada) has been created by admin

==> /usr/local/var/log/gvm/openvas.log <==
sd   main:MESSAGE:2021-05-02 06h52.07 utc:1544: openvas 21.4.0 started
sd   main:MESSAGE:2021-05-02 06h52.12 utc:1544: Vulnerability scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0 started: Target has 1 hosts: xxx.com, with max_hosts = 20 and max_checks = 4
sd   main:MESSAGE:2021-05-02 06h52.12 utc:1573: Vulnerability scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0 started for host: 194.36.147.165 (Vhosts: mail.xxx.com, xxx.com)

==> /usr/local/var/log/gvm/gvmd.log <==
event filter:MESSAGE:2021-05-02 08h52.18 CEST:1621: Filter Reports0 (20843e69-180f-4cce-ac95-457dfc410ca6) has been created by admin
event filter:MESSAGE:2021-05-02 08h52.38 CEST:1738: Filter Results0 (9720df89-04a1-444d-84fe-3c00ed2fd183) has been created by admin

==> /usr/local/var/log/gvm/openvas.log <==
lib  misc:WARNING:2021-05-02 07h08.12 utc:4749: check_duplicated_vhost: Value 'imap.xxx.com' exists already
lib  misc:WARNING:2021-05-02 07h08.12 utc:4749: check_duplicated_vhost: Value 'mail.xxx.com' exists already
lib  misc:WARNING:2021-05-02 07h08.12 utc:4749: check_duplicated_vhost: Value 'pop3.xxx.com' exists already
lib  misc:WARNING:2021-05-02 07h08.12 utc:4749: check_duplicated_vhost: Value 'smtp.xxx.com' exists already
sd   main:MESSAGE:2021-05-02 08h44.08 utc:1573: Vulnerability scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0 finished for host 194.36.147.165 in 6716.64 seconds
sd   main:MESSAGE:2021-05-02 08h44.09 utc:1544: Vulnerability scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0 finished in 6722 seconds: 1 hosts

==> /usr/local/var/log/gvm/ospd-openvas.log <==
OSPD[925] 2021-05-02 10:44:10,042: INFO: (ospd.ospd) 388008ee-95ce-4b7e-ad6d-8320d6fca3d0: Host scan finished.
OSPD[925] 2021-05-02 10:44:10,044: INFO: (ospd.ospd) 388008ee-95ce-4b7e-ad6d-8320d6fca3d0: Scan finished.

==> /usr/local/var/log/gvm/gvmd.log <==
event task:MESSAGE:2021-05-02 10h44.39 CEST:1262: Status of task xxx.com (c44ae960-ef03-4b59-b462-603175b6a183) has changed to Done

==> /usr/local/var/log/gvm/gsad.log <==
gsad  gmp:MESSAGE:2021-05-02 12h19.09 CEST:944: Authentication success for 'admin' from 192.168.10.1
gsad  gmp:MESSAGE:2021-05-02 14h47.52 CEST:944: Authentication success for 'admin' from 192.168.10.1
gsad  gmp:MESSAGE:2021-05-02 16h41.48 CEST:944: Authentication success for 'admin' from 192.168.10.1
Container stopped, performing shutdown
2021-05-02 14:45:05.563 GMT [37] LOG:  received fast shutdown request
waiting for server to shut down....2021-05-02 14:45:05.570 GMT [37] LOG:  aborting any active transactions
2021-05-02 14:45:05.570 GMT [271] FATAL:  terminating connection due to administrator command
2021-05-02 14:45:05.594 GMT [37] LOG:  background worker "logical replication launcher" (PID 44) exited with exit code 1
2021-05-02 14:45:05.595 GMT [39] LOG:  shutting down
2021-05-02 14:45:05.626 GMT [37] LOG:  database system is shut down
 done
server stopped
9:C 02 May 2021 16:45:09.102 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
9:C 02 May 2021 16:45:09.102 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=9, just started
9:C 02 May 2021 16:45:09.102 # Configuration loaded
Wait for redis socket to be created...
Testing redis status...
Redis ready.
Starting PostgreSQL...
waiting for server to start....2021-05-02 14:45:10.171 GMT [20] LOG:  starting PostgreSQL 12.6 (Ubuntu 12.6-1.pgdg20.04+1) on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 9.3.0-17ubuntu1~20.04) 9.3.0, 64-bit
2021-05-02 14:45:10.172 GMT [20] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2021-05-02 14:45:10.172 GMT [20] LOG:  listening on IPv6 address "::", port 5432
2021-05-02 14:45:10.174 GMT [20] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2021-05-02 14:45:10.187 GMT [20] LOG:  could not open usermap file "/data/database/pg_ident.conf": No such file or directory
2021-05-02 14:45:10.190 GMT [21] LOG:  database system was shut down at 2021-05-02 14:45:05 GMT
2021-05-02 14:45:10.197 GMT [20] LOG:  database system is ready to accept connections
 done
server started
Running first start configuration...
Migrating the database to the latest version if needed.
Starting Greenbone Vulnerability Manager...
Waiting for gvmd
Waiting for gvmd
admin
Setting admin password
reset
Starting Postfix for report delivery by email
 * Starting Postfix Mail Transport Agent postfix
   ...done.
Starting Open Scanner Protocol daemon for OpenVAS...
Starting Greenbone Security Assistant...
Oops, secure memory pool already initialized
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
+ Your GVM/openvas/postgresql container is now ready to use! +
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

gvmd --version
Greenbone Vulnerability Manager 21.4.0
Manager DB revision 242
Copyright (C) 2009-2021 Greenbone Networks GmbH
License: AGPL-3.0-or-later
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

++++++++++++++++
+ Tailing logs +
++++++++++++++++
==> /usr/local/var/log/gvm/gsad.log <==
gsad main:MESSAGE:2021-05-02 06h47.45 utc:942: Starting GSAD version 21.04.0
gsad  gmp:MESSAGE:2021-05-02 06h50.46 utc:944: Authentication success for 'admin' from 192.168.10.1
gsad  gmp:MESSAGE:2021-05-02 12h19.09 CEST:944: Authentication success for 'admin' from 192.168.10.1
gsad  gmp:MESSAGE:2021-05-02 14h47.52 CEST:944: Authentication success for 'admin' from 192.168.10.1
gsad  gmp:MESSAGE:2021-05-02 16h41.48 CEST:944: Authentication success for 'admin' from 192.168.10.1
gsad main:MESSAGE:2021-05-02 14h45.20 utc:735: Starting GSAD version 21.04.0

==> /usr/local/var/log/gvm/gvmd.log <==
md   main:WARNING:2021-05-02 14h45.11 utc:39: gvmd: databases are already at the supported version
md   main:MESSAGE:2021-05-02 14h45.11 utc:45:    Greenbone Vulnerability Manager version 21.4.0 (DB revision 242)
md   main:MESSAGE:2021-05-02 14h45.11 utc:50:    Greenbone Vulnerability Manager version 21.4.0 (DB revision 242)
md   main:WARNING:2021-05-02 14h45.11 utc:50: gvmd: Another process is busy starting up
md   main:MESSAGE:2021-05-02 14h45.12 utc:70:    Greenbone Vulnerability Manager version 21.4.0 (DB revision 242)
md   main:WARNING:2021-05-02 14h45.12 utc:70: gvmd: Another process is busy starting up
md   main:MESSAGE:2021-05-02 14h45.13 utc:77:    Greenbone Vulnerability Manager version 21.4.0 (DB revision 242)
md manage:   INFO:2021-05-02 14h45.13 utc:77:    Getting users.
md   main:MESSAGE:2021-05-02 14h45.14 utc:82:    Greenbone Vulnerability Manager version 21.4.0 (DB revision 242)
md manage:   INFO:2021-05-02 14h45.14 utc:82:    Modifying user password.

==> /usr/local/var/log/gvm/openvas.log <==
lib  nvticache:MESSAGE:2021-05-02 06h48.55 utc:954: Updated NVT cache from version 0 to 202104231026
sd   main:MESSAGE:2021-05-02 06h52.07 utc:1544: openvas 21.4.0 started
sd   main:MESSAGE:2021-05-02 06h52.12 utc:1544: Vulnerability scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0 started: Target has 1 hosts: xxx.com, with max_hosts = 20 and max_checks = 4
sd   main:MESSAGE:2021-05-02 06h52.12 utc:1573: Vulnerability scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0 started for host: 194.36.147.165 (Vhosts: mail.xxx.com, xxx.com)
lib  misc:WARNING:2021-05-02 07h08.12 utc:4749: check_duplicated_vhost: Value 'imap.xxx.com' exists already
lib  misc:WARNING:2021-05-02 07h08.12 utc:4749: check_duplicated_vhost: Value 'mail.xxx.com' exists already
lib  misc:WARNING:2021-05-02 07h08.12 utc:4749: check_duplicated_vhost: Value 'pop3.xxx.com' exists already
lib  misc:WARNING:2021-05-02 07h08.12 utc:4749: check_duplicated_vhost: Value 'smtp.xxx.com' exists already
sd   main:MESSAGE:2021-05-02 08h44.08 utc:1573: Vulnerability scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0 finished for host 194.36.147.165 in 6716.64 seconds
sd   main:MESSAGE:2021-05-02 08h44.09 utc:1544: Vulnerability scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0 finished in 6722 seconds: 1 hosts

==> /usr/local/var/log/gvm/ospd-openvas.log <==
OSPD[925] 2021-05-02 08:47:45,815: INFO: (ospd.main) Starting OSPd OpenVAS version 21.4.0.
OSPD[925] 2021-05-02 08:51:42,868: INFO: (ospd.command.command) Scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0 added to the queue in position 1.
OSPD[925] 2021-05-02 08:51:52,246: INFO: (ospd.ospd) Currently 1 queued scans.
OSPD[925] 2021-05-02 08:51:52,261: INFO: (ospd.ospd) Starting scan 388008ee-95ce-4b7e-ad6d-8320d6fca3d0.
OSPD[925] 2021-05-02 10:44:10,042: INFO: (ospd.ospd) 388008ee-95ce-4b7e-ad6d-8320d6fca3d0: Host scan finished.
OSPD[925] 2021-05-02 10:44:10,044: INFO: (ospd.ospd) 388008ee-95ce-4b7e-ad6d-8320d6fca3d0: Scan finished.
OSPD[722] 2021-05-02 16:45:20,681: INFO: (ospd.main) Starting OSPd OpenVAS version 21.4.0.

==> /usr/local/var/log/gvm/openvas.log <==
lib  nvticache:MESSAGE:2021-05-02 14h46.29 utc:747: Updated NVT cache from version 0 to 202104231026

mount:

mount
sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
udev on /dev type devtmpfs (rw,nosuid,relatime,size=1004988k,nr_inodes=251247,mode=755)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
tmpfs on /run type tmpfs (rw,nosuid,noexec,relatime,size=204200k,mode=755)
/dev/mapper/debian--vg-root on / type ext4 (rw,relatime,errors=remount-ro)
securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k)
tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755)
cgroup2 on /sys/fs/cgroup/unified type cgroup2 (rw,nosuid,nodev,noexec,relatime,nsdelegate)
cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,name=systemd)
pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime)
bpf on /sys/fs/bpf type bpf (rw,nosuid,nodev,noexec,relatime,mode=700)
cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices)
cgroup on /sys/fs/cgroup/cpuset type cgroup (rw,nosuid,nodev,noexec,relatime,cpuset)
cgroup on /sys/fs/cgroup/net_cls,net_prio type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls,net_prio)
cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpu,cpuacct)
cgroup on /sys/fs/cgroup/perf_event type cgroup (rw,nosuid,nodev,noexec,relatime,perf_event)
cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio)
cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory)
cgroup on /sys/fs/cgroup/pids type cgroup (rw,nosuid,nodev,noexec,relatime,pids)
cgroup on /sys/fs/cgroup/rdma type cgroup (rw,nosuid,nodev,noexec,relatime,rdma)
cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer)
systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=29,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=10062)
mqueue on /dev/mqueue type mqueue (rw,relatime)
debugfs on /sys/kernel/debug type debugfs (rw,relatime)
hugetlbfs on /dev/hugepages type hugetlbfs (rw,relatime,pagesize=2M)
/dev/sda1 on /boot type ext2 (rw,relatime)
tracefs on /sys/kernel/debug/tracing type tracefs (rw,relatime)
tmpfs on /run/user/0 type tmpfs (rw,nosuid,nodev,relatime,size=204196k,mode=700)
overlay on /var/lib/docker/overlay2/cabf7fb798fa9b90573f08e10e25066d32a1760bf5d01238d06e7fe0303613c8/merged type overlay (rw,relatime,lowerdir=/var/lib/docker/overlay2/l/SO6JHOMKP6FRT2GSQSQ6Z4V6OY:/var/lib/docker/overlay2/l/H43LTB3HJMOBRGJY6M4KMGKI5Z:/var/lib/docker/overlay2/l/TBGQWXPHSVHSHBVSW6XFJWW6X6:/var/lib/docker/overlay2/l/ZOGXQDFDLROLI7JB4MQCYWZMJF:/var/lib/docker/overlay2/l/63AZA3FBCOW3E6F2ROXAREPU3J:/var/lib/docker/overlay2/l/QVKHKK26YSHGAJXFK4ECA6NAH2:/var/lib/docker/overlay2/l/GQCYXPHZP66IQKLU2CQBZYERSJ:/var/lib/docker/overlay2/l/QCJYQ3EJV6MLCHD6HL3RYILBGC:/var/lib/docker/overlay2/l/KRY7PQUA2EVMUH2T26AGYSY7EB,upperdir=/var/lib/docker/overlay2/cabf7fb798fa9b90573f08e10e25066d32a1760bf5d01238d06e7fe0303613c8/diff,workdir=/var/lib/docker/overlay2/cabf7fb798fa9b90573f08e10e25066d32a1760bf5d01238d06e7fe0303613c8/work)
overlay on /var/lib/docker/overlay2/17395cb9afc85615d4415a7f4786d33aac2264b844c10c274e3e915c714d6045/merged type overlay (rw,relatime,lowerdir=/var/lib/docker/overlay2/l/SCQN5TOLFQSPGMX3KXUD6TZU7L:/var/lib/docker/overlay2/l/3XRWEMNDQLDHDNK3T3AGCNKPAC:/var/lib/docker/overlay2/l/SXWOFAKTAIHC2CNXA3ATFJUUMY:/var/lib/docker/overlay2/l/6AWZJMSVQ5SVRGJ76XZQLQKVVR,upperdir=/var/lib/docker/overlay2/17395cb9afc85615d4415a7f4786d33aac2264b844c10c274e3e915c714d6045/diff,workdir=/var/lib/docker/overlay2/17395cb9afc85615d4415a7f4786d33aac2264b844c10c274e3e915c714d6045/work)
overlay on /var/lib/docker/overlay2/983dbc8277fd722edf8074d79c9b6d333d973f49005a7c511bdd491142d80207/merged type overlay (rw,relatime,lowerdir=/var/lib/docker/overlay2/l/RG7JUFILBLEIG4ICZFEUNSFT4M:/var/lib/docker/overlay2/l/44QRVA2Y46UMGIMHFJYVCSBZTR:/var/lib/docker/overlay2/l/AIGCZX4UEB6QP3C4PQT2HK3S6A:/var/lib/docker/overlay2/l/CSF5HNMA7IAKDYEWFKTDFAV63O,upperdir=/var/lib/docker/overlay2/983dbc8277fd722edf8074d79c9b6d333d973f49005a7c511bdd491142d80207/diff,workdir=/var/lib/docker/overlay2/983dbc8277fd722edf8074d79c9b6d333d973f49005a7c511bdd491142d80207/work)
overlay on /var/lib/docker/overlay2/74b296a4ad98419be8a87fb40e68b43673cf1b6dda8520e90ab196675e7d11fc/merged type overlay (rw,relatime,lowerdir=/var/lib/docker/overlay2/l/PC3VC24KHS2OIWQXQPQWKVKR4T:/var/lib/docker/overlay2/l/2Y2RPF6KNGSP2HG3DLBMOL2LHF:/var/lib/docker/overlay2/l/4EYFT6TG6ROHFPSNDMNGX6NSGP:/var/lib/docker/overlay2/l/CTFEIGX6CMA4JQODQGEJCLLE7L:/var/lib/docker/overlay2/l/AGCHYRO7NDN75KYLNQUWRENEQV:/var/lib/docker/overlay2/l/YG2RZ554FF4W3ONP46JGTH2EPR:/var/lib/docker/overlay2/l/32XCDFWEEBW6XXF2DYJPIIRMSF:/var/lib/docker/overlay2/l/N5XRPPVYBFLAILO2KJFITISIO4,upperdir=/var/lib/docker/overlay2/74b296a4ad98419be8a87fb40e68b43673cf1b6dda8520e90ab196675e7d11fc/diff,workdir=/var/lib/docker/overlay2/74b296a4ad98419be8a87fb40e68b43673cf1b6dda8520e90ab196675e7d11fc/work)
overlay on /var/lib/docker/overlay2/ae1ac6ab8adc433d59f536d3989e8c376515db9cab990818c9c7ff6f03d50ac1/merged type overlay (rw,relatime,lowerdir=/var/lib/docker/overlay2/l/P3UWF7YSVUECNSN5WKDIHN34TC:/var/lib/docker/overlay2/l/KC7ERM2ZS6JZ6O3RYWIVEVOXOL:/var/lib/docker/overlay2/l/5FPJNAWAC3CTHXRNJK3IN6JJE2:/var/lib/docker/overlay2/l/E25PJ4VM2VPYKHNEICBP5IU3VC:/var/lib/docker/overlay2/l/QIB37XIPGB7XC66J3X4QOKQHUE:/var/lib/docker/overlay2/l/AEF2V3KXHPKUUIOMH4KYNN3QYB,upperdir=/var/lib/docker/overlay2/ae1ac6ab8adc433d59f536d3989e8c376515db9cab990818c9c7ff6f03d50ac1/diff,workdir=/var/lib/docker/overlay2/ae1ac6ab8adc433d59f536d3989e8c376515db9cab990818c9c7ff6f03d50ac1/work)
overlay on /var/lib/docker/overlay2/a454e5116f8d2e1a6985283aaa1c3ffce61f28292a3d1e8c3d279ab0331c2082/merged type overlay (rw,relatime,lowerdir=/var/lib/docker/overlay2/l/UJHNZVCE2BIXS2K5CB5HDOC4K3:/var/lib/docker/overlay2/l/OIPROINCUS6MPQ6JLKICN7E5YV:/var/lib/docker/overlay2/l/ONIKNTRZSAHUG2B7DYEQJU55WZ,upperdir=/var/lib/docker/overlay2/a454e5116f8d2e1a6985283aaa1c3ffce61f28292a3d1e8c3d279ab0331c2082/diff,workdir=/var/lib/docker/overlay2/a454e5116f8d2e1a6985283aaa1c3ffce61f28292a3d1e8c3d279ab0331c2082/work)
nsfs on /run/docker/netns/414412f4693f type nsfs (rw)
nsfs on /run/docker/netns/3785e66ff69b type nsfs (rw)
nsfs on /run/docker/netns/ece4fb181901 type nsfs (rw)
nsfs on /run/docker/netns/37142f81e8fe type nsfs (rw)
nsfs on /run/docker/netns/b2527295c155 type nsfs (rw)
nsfs on /run/docker/netns/42c4349d51f5 type nsfs (rw)

docker version:

docker version
Client: Docker Engine - Community
 Version:           20.10.6
 API version:       1.41
 Go version:        go1.13.15
 Git commit:        370c289
 Built:             Fri Apr  9 22:46:45 2021
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          20.10.6
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.13.15
  Git commit:       8728dd2
  Built:            Fri Apr  9 22:44:56 2021
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.4.4
  GitCommit:        05f951a3781f4f2c1911b05e61c160e9c30eaa8e
 runc:
  Version:          1.0.0-rc93
  GitCommit:        12644e614e25b05da6fd08a38ffa0cfe1903fdec
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0

cat /proc/meminfo
MemTotal:        2041972 kB
MemFree:          199428 kB
MemAvailable:    1208528 kB
Buffers:           88108 kB
Cached:           944320 kB
SwapCached:         6512 kB
Active:           813192 kB
Inactive:         731168 kB
Active(anon):     341664 kB
Inactive(anon):   172820 kB
Active(file):     471528 kB
Inactive(file):   558348 kB
Unevictable:          16 kB
Mlocked:              16 kB
SwapTotal:       2097148 kB
SwapFree:        2025468 kB
Dirty:                52 kB
Writeback:             0 kB
AnonPages:        510876 kB
Mapped:           175436 kB
Shmem:             14348 kB
Slab:             223296 kB
SReclaimable:     164412 kB
SUnreclaim:        58884 kB
KernelStack:        6584 kB
PageTables:         5608 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:     3118132 kB
Committed_AS:    3320800 kB
VmallocTotal:   34359738367 kB
VmallocUsed:           0 kB
VmallocChunk:          0 kB
Percpu:             2160 kB
HardwareCorrupted:     0 kB
AnonHugePages:    116736 kB
ShmemHugePages:        0 kB
ShmemPmdMapped:        0 kB
HugePages_Total:       0
HugePages_Free:        0
HugePages_Rsvd:        0
HugePages_Surp:        0
Hugepagesize:       2048 kB
Hugetlb:               0 kB
DirectMap4k:      536448 kB
DirectMap2M:     1560576 kB
DirectMap1G:           0 kB
immauss commented 3 years ago

The only thing I can think of is the "SKIPSYNC" ... I'm not starting with that. Since you're running on the existing DB, which is still based on 20.08, maybe there is something that needs get pulled in. I just tried it, and I got the same results. Can you remove that from your composer.yaml and try again.

Thanks, Scott

cybermcm commented 3 years ago

Tried it another time from scratch avoiding SKIPSYNC. Same error ;-( looked into the browser dev console, don't know if this could be relevant? image

iamjoeker commented 3 years ago

The slowness appears to be an issue with the JIT compilation. I was also experiencing it on a non-containerized version of OpenVAS running on Kali Linux with PostgreSQL 13. I found a reference to the slowness on the forums which recommended disabling JIT compilation (see here).

This resolved the slowness with loading reports there. I plan to test it with this container this evening. If it resolves the issue, I'll open a PR to correct.

immauss commented 3 years ago

@iamjoeker That's awesome! .... But for now, I'm looking more at getting 21.04 up to be the 'latest'. The performance is much better and many other internal fixes as well.

immauss commented 3 years ago

@cybermcm Can you give the latest 21.04-beta a try and let me know if you still see the same issues ?

Thanks, Scott

cybermcm commented 3 years ago

@immauss Just switched to the new image, reports are working again (fast)! Thank you very much! Can you explain the issue/solution?

immauss commented 3 years ago

@cybermcm

I rebuilt the DB from scratch with 21.04 and then rebuilt the image with the new base DB.

Now I need to make sure that's not going to bite when we upgrade from an older DB.

New Question .... can you download a PDF report? It's broken in an odd way and I'm wondering if it's just me.

Thanks, -Scott

cybermcm commented 3 years ago

just tried all sort of reports, working, including sending via email.

larsnaesbye commented 3 years ago

I can confirm that the new version of the 21.04-beta image works like a charm too.

immauss commented 3 years ago

@larsnaesbye @cybermcm @iamjoeker

Thank you for the testing and reports. I'm going to close this now. I'm planning on pushing the final 21.04 this weekend after a few more minor tweaks. If there is anything you'd like to see added, please open a new issue and I'll see if can work it in this weekend.

Thanks!! -Scott