Very slow multiple add/delete operations

[epiniguin]

Subject of the issue

I installed Vaultwarden and Bitwarden Unified Beta for testing and comparing.
Both are installed as Docker containers on the same Debian VM(It is 8 cores Intel Xeon with 4GB RAM. So it is not a slow server).
Both vaults use a shared Postgresql installed on the same VM as Docker container.

Both vaults are empty before testing.
Both are behind the same Nginx proxy installed on the router.

I use the web vault, the Firefox official Bitwarden extension and the Android official Bitwarden app.

The clients and the servers are in the same LAN.

For a testing purpose I exported 427 passwords from Firefox to CSV.
I imported and after some pause deleted these items. After that I emptied the recycle bin.
I tried to import from web vaults and a Firefox extension - the results were the same, so I guess it is not a client issue.
Deleting and recycle bin emptying are possible only from the web vaults.

The results are in the table below.
When testing Vaultwarden with enabled push notifications it was difficult to measure the times precise because of web vault 60s timeout errors. Besides, after these timeouts the data in the Vaultwarden web vault stopped to refresh and it needed to renew the page and to unlock the vault.

Operation	Vaultwarden(disabled push)	Vaultwarden(enabled push)	Bitwarden(enabled push)
Import 427 items	24s	24s	12s
Delete 427 items	14s	130-150s	3s
Empty recycle bin(427 items)	41s	130-150s	3s

Deployment environment

Your environment (Generated via diagnostics page)

• Vaultwarden version: v1.30.5
• Web-vault version: v2024.1.2b
• OS/Arch: linux/x86_64
• Running within a container: true (Base: Debian)
• Environment settings overridden: false
• Uses a reverse proxy: true
• IP Header check: true (X-Real-IP)
• Internet access: true
• Internet access via a proxy: false
• DNS Check: true
• Browser/Server Time Check: true
• Server/NTP Time Check: true
• Domain Configuration Check: true
• HTTPS Check: true
• Database type: PostgreSQL
• Database version: PostgreSQL 16.3 (Debian 16.3-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
• Clients used:
• Reverse proxy and version:
• Other relevant information:

Config (Generated via diagnostics page)

Show Running Config

Environment settings which are overridden:

{
  "_duo_akey": null,
  "_enable_duo": true,
  "_enable_email_2fa": true,
  "_enable_smtp": true,
  "_enable_yubico": true,
  "_icon_service_csp": "",
  "_icon_service_url": "",
  "_ip_header_enabled": true,
  "_smtp_img_src": "cid:",
  "admin_ratelimit_max_burst": 3,
  "admin_ratelimit_seconds": 300,
  "admin_session_lifetime": 20,
  "admin_token": "***",
  "allowed_iframe_ancestors": "",
  "attachments_folder": "data/attachments",
  "auth_request_purge_schedule": "30 * * * * *",
  "authenticator_disable_time_drift": false,
  "data_folder": "data",
  "database_conn_init": "",
  "database_max_conns": 10,
  "database_timeout": 30,
  "database_url": "**********://**********************************************",
  "db_connection_retries": 15,
  "disable_2fa_remember": false,
  "disable_admin_token": false,
  "disable_icon_download": false,
  "domain": "*****://***************",
  "domain_origin": "*****://***************",
  "domain_path": "",
  "domain_set": true,
  "duo_host": null,
  "duo_ikey": null,
  "duo_skey": null,
  "email_attempts_limit": 3,
  "email_change_allowed": true,
  "email_expiration_time": 600,
  "email_token_size": 6,
  "emergency_access_allowed": true,
  "emergency_notification_reminder_schedule": "0 3 * * * *",
  "emergency_request_timeout_schedule": "0 7 * * * *",
  "enable_db_wal": true,
  "event_cleanup_schedule": "0 10 0 * * *",
  "events_days_retain": null,
  "experimental_client_feature_flags": "fido2-vault-credentials",
  "extended_logging": true,
  "helo_name": null,
  "hibp_api_key": null,
  "icon_blacklist_non_global_ips": true,
  "icon_blacklist_regex": null,
  "icon_cache_folder": "data/icon_cache",
  "icon_cache_negttl": 259200,
  "icon_cache_ttl": 2592000,
  "icon_download_timeout": 10,
  "icon_redirect_code": 302,
  "icon_service": "internal",
  "incomplete_2fa_schedule": "30 * * * * *",
  "incomplete_2fa_time_limit": 3,
  "invitation_expiration_hours": 120,
  "invitation_org_name": "Vaultwarden",
  "invitations_allowed": true,
  "ip_header": "X-Real-IP",
  "job_poll_interval_ms": 30000,
  "log_file": "/data/vaultwarden.log",
  "log_level": "Info",
  "log_timestamp_format": "%Y-%m-%d %H:%M:%S.%3f",
  "login_ratelimit_max_burst": 10,
  "login_ratelimit_seconds": 60,
  "org_attachment_limit": null,
  "org_creation_users": "",
  "org_events_enabled": false,
  "org_groups_enabled": false,
  "password_hints_allowed": true,
  "password_iterations": 600000,
  "push_enabled": true,
  "push_identity_uri": "https://identity.bitwarden.com",
  "push_installation_id": "***",
  "push_installation_key": "***",
  "push_relay_uri": "https://push.bitwarden.com",
  "reload_templates": false,
  "require_device_email": false,
  "rsa_key_filename": "data/rsa_key",
  "send_purge_schedule": "0 5 * * * *",
  "sendmail_command": null,
  "sends_allowed": true,
  "sends_folder": "data/sends",
  "show_password_hint": false,
  "signups_allowed": true,
  "signups_domains_whitelist": "",
  "signups_verify": false,
  "signups_verify_resend_limit": 6,
  "signups_verify_resend_time": 3600,
  "smtp_accept_invalid_certs": false,
  "smtp_accept_invalid_hostnames": false,
  "smtp_auth_mechanism": null,
  "smtp_debug": false,
  "smtp_embed_images": true,
  "smtp_explicit_tls": null,
  "smtp_from": "*************",
  "smtp_from_name": "Vaultwarden",
  "smtp_host": "*******************",
  "smtp_password": "***",
  "smtp_port": 587,
  "smtp_security": "starttls",
  "smtp_ssl": null,
  "smtp_timeout": 15,
  "smtp_username": "*************",
  "templates_folder": "data/templates",
  "tmp_folder": "data/tmp",
  "trash_auto_delete_days": null,
  "trash_purge_schedule": "0 5 0 * * *",
  "use_sendmail": false,
  "use_syslog": false,
  "user_attachment_limit": null,
  "user_send_limit": null,
  "web_vault_enabled": true,
  "web_vault_folder": "web-vault/",
  "websocket_address": "0.0.0.0",
  "websocket_enabled": false,
  "websocket_port": 3012,
  "yubico_client_id": null,
  "yubico_secret_key": null,
  "yubico_server": null
}

• vaultwarden version: 1.30.5

• Install method: Docker

• Clients used:
  web vault, firefox extension

• Reverse proxy and version:
  nginx/1.26.1 installed on the router

• MySQL/MariaDB or PostgreSQL version:
  PostgreSQL 16.3 (Debian 16.3-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit

Steps to reproduce

1. Import 300-500 items from CSV.
2. Delete these items.
3. Empty recycle bin.

Expected behaviour

Vaultwarden and Bitwarden should work at approximately the same speed.

Actual behaviour

Vaultwarden is much slower than Bitwarden particularly with enabled push notifications.

Troubleshooting data

[BlackDex]

Hmm, i thought we fixed that already in testing tagged images, but I'm not sure. Because we do not push on import, but we shouldn't do this on bulk delete/trash-clean too. But we should see if we can trigger a refresh or something else for the other clients, not sure if that is possible currently.

[BlackDex]

Also, there is a similar issue #4669.
The only way i can think of is running the notifications in there own thread, and handle the pushes outside of the web/main threads.

[epiniguin]

It is slower without enabled push also.
I guess that 427 items is not a problem at all for Postgresql. That's why Bitwarden deletes them for 3s(with https delays).

[epiniguin]

Also, there is a similar issue #4669.

In my case I don't have any delay for single operations. Only for multiple.

[stefan0xC]

I can't really reproduce your findings (with the vaultwarden/server:latest image and also using postgres 16). With 330 items each operation (in the web-vault) took about 1-1.5 seconds with Vaultwarden.

[2024-07-03 06:16:15.476][request][INFO] POST /api/ciphers/import
[2024-07-03 06:16:16.599][response][INFO] (post_ciphers_import) POST /api/ciphers/import => 200 OK
...
[2024-07-03 06:16:41.966][request][INFO] PUT /api/ciphers/delete
[2024-07-03 06:16:42.961][response][INFO] (delete_cipher_selected_put) PUT /api/ciphers/delete => 200 OK
...
[2024-07-03 06:16:53.331][request][INFO] DELETE /api/ciphers
[2024-07-03 06:16:54.417][response][INFO] (delete_cipher_selected) DELETE /api/ciphers => 200 OK

edit: even with 499 items it's 1.7-2 seconds for these requests.

[epiniguin]

It's my log.
I don't know what is the difference between our systems.
But as I wrote Bitwarden works fast on the same infrastructure.

What diagnostic could I do?

[2024-07-03 09:40:19.431][request][INFO] POST /api/ciphers/import
[2024-07-03 09:40:43.737][response][INFO] (post_ciphers_import) POST /api/ciphers/import => 200 OK
...
[2024-07-03 09:43:04.312][request][INFO] PUT /api/ciphers/delete
[2024-07-03 09:44:38.549][response][INFO] (delete_cipher_selected_put) PUT /api/ciphers/delete => 200 OK
....
[2024-07-03 09:46:49.204][request][INFO] DELETE /api/ciphers
[2024-07-03 09:48:26.149][response][INFO] (delete_cipher_selected) DELETE /api/ciphers => 200 OK

[BlackDex]

Try to enable LOG_LEVEL=debug and see if that provides more (and enough) details, else set it to trace that should give a lot details.

[stefan0xC]

Okay, I can only reproduce the issue if I enable push.

[epiniguin]

Okay, I can only reproduce the issue if I enable push.

Attached delete logs with enabled push.

delete_with_push.txt
bin_with_push.txt

[epiniguin]

This is emptying bin trace with disabled push.
I don't see anything bad, but my timing is 23s, not 1.5s as yours.

bin_wo_push_trace.txt