dani-garcia / vaultwarden

Unofficial Bitwarden compatible server written in Rust, formerly known as bitwarden_rs
GNU Affero General Public License v3.0
38.77k stars 1.88k forks source link

Mobile Client push notification: error sending request for url (https://push.bitwarden.com/push/send) #4973

Closed acotor closed 1 month ago

acotor commented 1 month ago

Vaultwarden Support String

Your environment (Generated via diagnostics page)

Config (Generated via diagnostics page)

Show Running Config **Environment settings which are overridden:** SIGNUPS_ALLOWED, ADMIN_TOKEN ```json { "_duo_akey": null, "_enable_duo": true, "_enable_email_2fa": false, "_enable_smtp": true, "_enable_yubico": true, "_icon_service_csp": "", "_icon_service_url": "", "_ip_header_enabled": true, "_max_note_size": 10000, "_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_context_purge_schedule": "30 * * * * *", "duo_host": null, "duo_ikey": null, "duo_skey": null, "duo_use_iframe": false, "email_2fa_auto_fallback": false, "email_2fa_enforce_on_verified_invite": false, "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, "enable_websocket": 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, "http_request_block_non_global_ips": true, "http_request_block_regex": 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, "increase_note_size_limit": false, "invitation_expiration_hours": 120, "invitation_org_name": "Vaultwarden", "invitations_allowed": true, "ip_header": "X-Real-IP", "job_poll_interval_ms": 30000, "log_file": null, "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": false, "signups_domains_whitelist": "", "signups_verify": true, "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": 465, "smtp_security": "force_tls", "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/", "yubico_client_id": null, "yubico_secret_key": null, "yubico_server": null } ```

Vaultwarden Build Version

v1.32.0

Deployment method

Official Container Image

Custom deployment method

No response

Reverse Proxy

openresty 1.21.4.3-3-3-focal

Host/Server Operating System

Linux

Operating System Version

Debian 12

Clients

iOS

Client Version

No response

Steps To Reproduce

  1. Followed Enabling Mobile Client push notification get my INSTALLATION ID and KEY and set Environment Variables in docker-compose.yml
  2. Reinstall Bitwarden iOS App and connect to my instance again.
  3. Create a folder called test in web vault.

Expected Result

Folder test appears in BitWarden iOS App in a few minutes

Actual Result

  1. Folder test does not appear in BitWarden iOS App in a few minutes, auto sync is not triggered.
  2. vault in web browser add-on is auto synced, websocket works fine.

Logs

Right after I create the folder, the log of the container shows these:

[2024-09-20 23:45:28.291][response][INFO] (delete_folder) DELETE /api/folders/<uuid> => 200 OK
[2024-09-20 23:45:38.293][vaultwarden::api::push][ERROR] An error occurred while sending a send update to the push relay: error sending request for url (https://push.bitwarden.com/push/send)

Screenshots or Videos

No response

Additional Context

No response

BlackDex commented 1 month ago

Please try to enable LOG_LEVEL=debug and check again to see what happens. Also, check if there were no other error messages regarding push in the logs.

acotor commented 1 month ago

Logs after the folder creation are like this and I can't figure out what is wrong.

[2024-09-21 00:53:41.620][request][INFO] POST /api/folders
[2024-09-21 00:53:41.621][response][INFO] (post_folders) POST /api/folders => 200 OK
[2024-09-21 00:53:41.668][reqwest::connect][DEBUG] starting new connection: https://identity.bitwarden.com/
[2024-09-21 00:53:41.668][hickory_proto::xfer::dns_handle][DEBUG] querying: identity.bitwarden.com A
[2024-09-21 00:53:41.668][hickory_resolver::name_server::name_server_pool][DEBUG] sending request: [Query { name: Name("identity.bitwarden.com"), query_type: A, query_class: IN }]
[2024-09-21 00:53:41.668][hickory_resolver::name_server::name_server][DEBUG] reconnecting: NameServerConfig { socket_addr: 127.0.0.11:53, protocol: Udp, tls_dns_name: None, trust_negative_responses: false, bind_addr: None }
[2024-09-21 00:53:41.668][hickory_proto::xfer][DEBUG] enqueueing message:QUERY:[Query { name: Name("identity.bitwarden.com"), query_type: A, query_class: IN }]
[2024-09-21 00:53:41.668][hickory_proto::udp::udp_client_stream][DEBUG] final message: ; header 54288:QUERY:RD:NoError:QUERY:0/0/0
; query
;; identity.bitwarden.com. IN A

[2024-09-21 00:53:41.668][hickory_proto::udp::udp_stream][DEBUG] created socket successfully
[2024-09-21 00:53:42.656][hickory_proto::udp::udp_client_stream][DEBUG] received message id: 54288
[2024-09-21 00:53:42.656][hickory_resolver::error][DEBUG] Response:; header 54288:RESPONSE:RD,RA:NoError:QUERY:2/0/0
; query
;; identity.bitwarden.com. IN A
; answers 2
identity.bitwarden.com. 300 IN CNAME n.sni.global.fastly.net.
n.sni.global.fastly.net. 60 IN A 151.101.109.91
; nameservers 0
; additionals 0

[2024-09-21 00:53:42.656][hickory_resolver::error][DEBUG] Response:; header 54288:RESPONSE:RD,RA:NoError:QUERY:2/0/0
; query
;; identity.bitwarden.com. IN A
; answers 2
identity.bitwarden.com. 300 IN CNAME n.sni.global.fastly.net.
n.sni.global.fastly.net. 60 IN A 151.101.109.91
; nameservers 0
; additionals 0

[2024-09-21 00:53:42.656][hyper_util::client::legacy::connect::http][DEBUG] connecting to 151.101.109.91:443
[2024-09-21 00:53:42.843][hyper_util::client::legacy::connect::http][DEBUG] connected to 151.101.109.91:443
[2024-09-21 00:53:44.173][h2::client][DEBUG] binding client connection
[2024-09-21 00:53:44.173][h2::client][DEBUG] client connection bound
[2024-09-21 00:53:44.173][h2::codec::framed_write][DEBUG] send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[2024-09-21 00:53:44.173][h2::proto::connection][DEBUG] Connection; peer=Client
[2024-09-21 00:53:44.173][hyper_util::client::legacy::pool][DEBUG] pooling idle connection for ("https", identity.bitwarden.com)
[2024-09-21 00:53:44.173][h2::codec::framed_write][DEBUG] send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
[2024-09-21 00:53:44.173][h2::codec::framed_write][DEBUG] send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[2024-09-21 00:53:44.173][h2::codec::framed_write][DEBUG] send frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[2024-09-21 00:53:44.347][h2::codec::framed_read][DEBUG] received frame=Settings { flags: (0x0), max_concurrent_streams: 100 }
[2024-09-21 00:53:44.347][h2::codec::framed_write][DEBUG] send frame=Settings { flags: (0x1: ACK) }
[2024-09-21 00:53:44.347][h2::codec::framed_read][DEBUG] received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 16711681 }
[2024-09-21 00:53:44.347][h2::codec::framed_read][DEBUG] received frame=Settings { flags: (0x1: ACK) }
[2024-09-21 00:53:44.347][h2::proto::settings][DEBUG] received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[2024-09-21 00:53:45.054][h2::codec::framed_read][DEBUG] received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[2024-09-21 00:53:45.056][h2::codec::framed_read][DEBUG] received frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[2024-09-21 00:53:45.056][vaultwarden::api::push][DEBUG] Token still valid for 43199
[2024-09-21 00:53:45.056][reqwest::connect][DEBUG] starting new connection: https://push.bitwarden.com/
[2024-09-21 00:53:45.056][hickory_proto::xfer::dns_handle][DEBUG] querying: push.bitwarden.com A
[2024-09-21 00:53:45.056][hickory_resolver::name_server::name_server_pool][DEBUG] sending request: [Query { name: Name("push.bitwarden.com"), query_type: A, query_class: IN }]
[2024-09-21 00:53:45.056][hickory_resolver::name_server::name_server][DEBUG] existing connection: NameServerConfig { socket_addr: 127.0.0.11:53, protocol: Udp, tls_dns_name: None, trust_negative_responses: false, bind_addr: None }
[2024-09-21 00:53:45.056][hickory_proto::xfer][DEBUG] enqueueing message:QUERY:[Query { name: Name("push.bitwarden.com"), query_type: A, query_class: IN }]
[2024-09-21 00:53:45.056][hickory_proto::udp::udp_client_stream][DEBUG] final message: ; header 25827:QUERY:RD:NoError:QUERY:0/0/0
; query
;; push.bitwarden.com. IN A

[2024-09-21 00:53:45.056][hickory_proto::udp::udp_stream][DEBUG] created socket successfully
[2024-09-21 00:53:46.806][hickory_proto::udp::udp_client_stream][DEBUG] received message id: 25827
[2024-09-21 00:53:46.806][hickory_resolver::error][DEBUG] Response:; header 25827:RESPONSE:RD,RA:NoError:QUERY:2/0/0
; query
;; push.bitwarden.com. IN A
; answers 2
push.bitwarden.com. 300 IN CNAME n.sni.global.fastly.net.
n.sni.global.fastly.net. 60 IN A 146.75.113.91
; nameservers 0
; additionals 0

[2024-09-21 00:53:46.806][hickory_resolver::error][DEBUG] Response:; header 25827:RESPONSE:RD,RA:NoError:QUERY:2/0/0
; query
;; push.bitwarden.com. IN A
; answers 2
push.bitwarden.com. 300 IN CNAME n.sni.global.fastly.net.
n.sni.global.fastly.net. 60 IN A 146.75.113.91
; nameservers 0
; additionals 0

[2024-09-21 00:53:46.806][hyper_util::client::legacy::connect::http][DEBUG] connecting to 146.75.113.91:443
[2024-09-21 00:53:46.997][hyper_util::client::legacy::connect::http][DEBUG] connected to 146.75.113.91:443
[2024-09-21 00:53:48.365][h2::client][DEBUG] binding client connection
[2024-09-21 00:53:48.365][h2::client][DEBUG] client connection bound
[2024-09-21 00:53:48.365][h2::codec::framed_write][DEBUG] send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[2024-09-21 00:53:48.365][h2::proto::connection][DEBUG] Connection; peer=Client
[2024-09-21 00:53:48.366][h2::codec::framed_write][DEBUG] send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
[2024-09-21 00:53:48.366][hyper_util::client::legacy::pool][DEBUG] pooling idle connection for ("https", push.bitwarden.com)
[2024-09-21 00:53:48.366][h2::codec::framed_write][DEBUG] send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
[2024-09-21 00:53:48.366][h2::codec::framed_write][DEBUG] send frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
[2024-09-21 00:53:50.117][h2::codec::framed_read][DEBUG] received frame=Settings { flags: (0x0), max_concurrent_streams: 100 }
[2024-09-21 00:53:50.117][h2::codec::framed_write][DEBUG] send frame=Settings { flags: (0x1: ACK) }
[2024-09-21 00:53:50.117][h2::codec::framed_read][DEBUG] received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 16711681 }
[2024-09-21 00:53:50.117][h2::codec::framed_read][DEBUG] received frame=Settings { flags: (0x1: ACK) }
[2024-09-21 00:53:50.117][h2::proto::settings][DEBUG] received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384, max_header_list_size: 16384 }
[2024-09-21 00:53:55.057][vaultwarden::api::push][ERROR] An error occurred while sending a send update to the push relay: error sending request for url (https://push.bitwarden.com/push/send)
[2024-09-21 00:53:55.057][h2::codec::framed_write][DEBUG] send frame=Reset { stream_id: StreamId(1), error_code: CANCEL }
[2024-09-21 00:54:00.098][h2::codec::framed_read][DEBUG] received frame=Headers { stream_id: StreamId(1), flags: (0x5: END_HEADERS | END_STREAM) }
BlackDex commented 1 month ago

I'm not able to reproduce the same error. While for me the mobile client also does not get updated, but that is probably the issue with the new native clients as far as i know. There were some issues there.

I have not yet validated if all still works as before, or if there were some changes done on the Bitwarden side.

BlackDex commented 1 month ago

I'm not sure how to help here. I can send the request to push.bitwarden.com without any issue at all. My mobile will not update though, because of possible Bitwarden/Mobile Client issues which are not resolved yet.

But i'm able to send data just fine. I even tried to use the same IP address as your system seems to resolve, but that also works for me.

Since i do not think this is a Vaultwarden issue it self, i'm going to move this to a discussion.