alexbelgium / hassio-addons

My homeassistant addons
MIT License
1.36k stars 193 forks source link

🐛 [qbittorrent] Since last update no longer starts up #1351

Closed jdumeez closed 1 month ago

jdumeez commented 2 months ago

Description

Since the last qBittorrent update, the add-on no longer boots up

Reproduction steps

1. Start the add-on  (with the VPN option)

Addon Logs

2024-04-23 13:14:23 OpenSSL: error:0A000086:SSL routines::certificate verify failed:
2024-04-23 13:14:23 TLS_ERROR: BIO read tls_read_plaintext error
2024-04-23 13:14:23 TLS Error: TLS object -> incoming plaintext read error
2024-04-23 13:14:23 TLS Error: TLS handshake failed
2024-04-23 13:14:23 SIGUSR1[soft,tls-error] received, process restarting
crond: USER root pid 72771 cmd run-parts /etc/periodic/15min
2024-04-23 13:19:23 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2024-04-23 13:19:23 TCP/UDP: Preserving recently used remote address: [AF_INET]192.XXX.XXX.XX:1198
2024-04-23 13:19:23 UDPv4 link local: (not bound)
2024-04-23 13:19:23 UDPv4 link remote: [AF_INET]191.XX.XXX.XX:1198
2024-04-23 13:19:24 VERIFY ERROR: CRL not loaded

Architecture

amd64

OS

Virtual Machine

alexbelgium commented 2 months ago

Hi, sorry I had not much time to check - indeed it seems to be an issue with time perceptions in latest openvpn version but I didn't had time to check further yet

relyef commented 2 months ago

Looks like recent Home Assistant update broke qBittorrent, here's an excerpt from restart log (not very much data there):

2024-04-27 22:13:35 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:80 2024-04-27 22:13:35 Socket Buffers: R=[212992->212992] S=[212992->212992] 2024-04-27 22:13:35 UDPv4 link local: (not bound) 2024-04-27 22:13:35 UDPv4 link remote: [AF_INET]XXX.XXX.XXX.XXX:80 2024-04-27 22:13:35 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:13:37 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:13:41 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:13:49 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:14:05 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:14:35 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity) 2024-04-27 22:14:35 TLS Error: TLS handshake failed 2024-04-27 22:14:35 SIGUSR1[soft,tls-error] received, process restarting 2024-04-27 22:14:35 Restart pause, 1 second(s) 2024-04-27 22:14:36 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts 2024-04-27 22:14:36 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:51820 2024-04-27 22:14:36 Socket Buffers: R=[212992->212992] S=[212992->212992] 2024-04-27 22:14:36 UDPv4 link local: (not bound) 2024-04-27 22:14:36 UDPv4 link remote: [AF_INET]XXX.XXX.XXX.XXX:51820 2024-04-27 22:14:36 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:14:38 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:14:42 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:14:50 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) crond: USER root pid 1427 cmd run-parts /etc/periodic/15min 2024-04-27 22:15:06 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111)

alexbelgium commented 2 months ago

Looks like recent Home Assistant update broke qBittorrent, here's an excerpt from restart log (not very much data there):

2024-04-27 22:13:35 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:80 2024-04-27 22:13:35 Socket Buffers: R=[212992->212992] S=[212992->212992] 2024-04-27 22:13:35 UDPv4 link local: (not bound) 2024-04-27 22:13:35 UDPv4 link remote: [AF_INET]XXX.XXX.XXX.XXX:80 2024-04-27 22:13:35 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:13:37 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:13:41 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:13:49 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:14:05 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:14:35 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity) 2024-04-27 22:14:35 TLS Error: TLS handshake failed 2024-04-27 22:14:35 SIGUSR1[soft,tls-error] received, process restarting 2024-04-27 22:14:35 Restart pause, 1 second(s) 2024-04-27 22:14:36 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts 2024-04-27 22:14:36 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:51820 2024-04-27 22:14:36 Socket Buffers: R=[212992->212992] S=[212992->212992] 2024-04-27 22:14:36 UDPv4 link local: (not bound) 2024-04-27 22:14:36 UDPv4 link remote: [AF_INET]XXX.XXX.XXX.XXX:51820 2024-04-27 22:14:36 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:14:38 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:14:42 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) 2024-04-27 22:14:50 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111) crond: USER root pid 1427 cmd run-parts /etc/periodic/15min 2024-04-27 22:15:06 read UDPv4 [ECONNREFUSED]: Connection refused (fd=4,code=111)

Hi, this is a separate issue but it reminds me a past one where udp was used for a proxy config while only tcp is supported. I think a proto tcp live in config ovpn is required.

Perhaps it is also due to the openvpn version but I hadn't time to revert openvpn version

relyef commented 2 months ago

There was no qBittorrent update on my system for a while but after the last HA update (v 2024.4.4) I started having problems with qBittorrent. There was zero changes in any QBT config, either open-vpn related or not

I could file a separate issue if you'd like

relyef commented 2 months ago

I just tried replacing openvpn config with TCP one, it still fails with timeout. The difference with UDP it now takes 2 minutes before the next cycle whereas with UDP it fails right away:

[custom-init] No custom files found, skipping... crond: crond (busybox 1.36.1) started, log level 8 2024-04-27 23:07:12 DEPRECATED OPTION: --cipher set to 'AES-256-CBC' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305). OpenVPN ignores --cipher for cipher negotiations. 2024-04-27 23:07:12 OpenVPN 2.6.10 aarch64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] 2024-04-27 23:07:12 library versions: OpenSSL 3.3.0 9 Apr 2024, LZO 2.10 2024-04-27 23:07:12 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts 2024-04-27 23:07:12 NOTE: --fast-io is disabled since we are not using UDP 2024-04-27 23:07:12 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:443 2024-04-27 23:07:12 Socket Buffers: R=[131072->131072] S=[16384->16384] 2024-04-27 23:07:12 Attempting to establish TCP connection with [AF_INET]XXX.XXX.XXX.XXX:443 2024-04-27 23:09:12 TCP: connect to [AF_INET]XXX.XXX.XXX.XXX:443 failed: Operation timed out 2024-04-27 23:09:12 SIGUSR1[connection failed(soft),connection-failed] received, process restarting 2024-04-27 23:09:12 Restart pause, 1 second(s) 2024-04-27 23:09:13 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts 2024-04-27 23:09:13 NOTE: --fast-io is disabled since we are not using UDP 2024-04-27 23:09:13 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:8443 2024-04-27 23:09:13 Socket Buffers: R=[131072->131072] S=[16384->16384] 2024-04-27 23:09:13 Attempting to establish TCP connection with [AF_INET]XXX.XXX.XXX.XXX:8443 2024-04-27 23:11:13 TCP: connect to [AF_INET]XXX.XXX.XXX.XXX:8443 failed: Operation timed out 2024-04-27 23:11:13 SIGUSR1[connection failed(soft),connection-failed] received, process restarting 2024-04-27 23:11:13 Restart pause, 1 second(s)

relyef commented 2 months ago

Sorry, I have to apologize for a false alarm; I've updated openvpn files from protonvpn and it works now, both udp and tcp files. Really strange, and again, I'm very sorry. I'll check what's changed in proton vpn config so it's stopped working

alexbelgium commented 2 months ago

Glad to read that ! Actually the issue is that openvpn standards evolve but I don't think vpn providers are super fast in keeping with them...

jdumeez commented 2 months ago

Sorry, I have to apologize for a false alarm; I've updated openvpn files from protonvpn and it works now, both udp and tcp files. Really strange, and again, I'm very sorry. I'll check what's changed in proton vpn config so it's stopped working

Hey Relyef, do you mind sharing the settings in the openvpn config + settings used to generate your file? I have been trying to regenerate different options with private internet access VPN but so far no luck.

BobbyQuantum commented 2 months ago

Also have this issue, also with PIA VPN.

Some more detail of startup. It seems like the current CRL that they are putting in their generated OpenVPN config is being rejected:

2024-04-28 11:00:31 DEPRECATED OPTION: --cipher set to 'aes-256-cbc' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305). OpenVPN ignores --cipher for cipher negotiations. 2024-04-28 11:00:31 OpenVPN 2.6.10 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] 2024-04-28 11:00:31 library versions: OpenSSL 3.3.0 9 Apr 2024, LZO 2.10 2024-04-28 11:00:31 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts 2024-04-28 11:00:31 OpenSSL: error:068000E9:asn1 encoding routines::utctime is too short: 2024-04-28 11:00:31 OpenSSL: error:0688010A:asn1 encoding routines::nested asn1 error:Field=revocationDate, Type=X509_REVOKED 2024-04-28 11:00:31 OpenSSL: error:0688010A:asn1 encoding routines::nested asn1 error:Field=revoked, Type=X509_CRL_INFO 2024-04-28 11:00:31 OpenSSL: error:0688010A:asn1 encoding routines::nested asn1 error:Field=crl, Type=X509_CRL 2024-04-28 11:00:31 OpenSSL: error:0488000D:PEM routines::ASN1 lib: 2024-04-28 11:00:31 CRL: cannot read CRL from file [[INLINE]] 2024-04-28 11:00:31 CRL: loaded 0 CRLs from file -----BEGIN X509 CRL----- MIIDWDCCAUAwDQYJKoZIhvcNAQENBQAwgegxCzAJBgNVBAYTAlVTMQswCQYDVQQI EwJDQTETMBEGA1UEBxMKTG9zQW5nZWxlczEgMB4GA1UEChMXUHJpdmF0ZSBJbnRl cm5ldCBBY2Nlc3MxIDAeBgNVBAsTF1ByaXZhdGUgSW50ZXJuZXQgQWNjZXNzMSAw HgYDVQQDExdQcml2YXRlIEludGVybmV0IEFjY2VzczEgMB4GA1UEKRMXUHJpdmF0 ZSBJbnRlcm5ldCBBY2Nlc3MxLzAtBgkqhkiG9w0BCQEWIHNlY3VyZUBwcml2YXRl aW50ZXJuZXRhY2Nlc3MuY29tFw0xNjA3MDgxOTAwNDZaFw0zNjA3MDMxOTAwNDZa MCYwEQIBARcMMTYwNzA4MTkwMDQ2MBECAQYXDDE2MDcwODE5MDA0NjANBgkqhkiG 9w0BAQ0FAAOCAgEAppFfEpGsasjB1QgJcosGpzbf2kfRhM84o2TlqY1ua+Gi5TMd KydA3LJcNTjlI9a0TYAJfeRX5IkpoglSUuHuJgXhP3nEvX10mjXDpcu/YvM8TdE5 JV2+EGqZ80kFtBeOq94WcpiVKFTR4fO+VkOK9zwspFfb1cNs9rHvgJ1QMkRUF8Pp LN6AkntHY0+6DnigtSaKqldqjKTDTv2OeH3nPoh80SGrt0oCOmYKfWTJGpggMGKv IdvU3vH9+EuILZKKIskt+1dwdfA5Bkz1GLmiQG7+9ZZBQUjBG9Dos4hfX/rwJ3eU 8oUIm4WoTz9rb71SOEuUUjP5NPy9HNx2vx+cVvLsTF4ZDZaUztW9o9JmIURDtbey qxuHN3prlPWB6aj73IIm2dsDQvs3XXwRIxs8NwLbJ6CyEuvEOVCskdM8rdADWx1J 0lRNlOJ0Z8ieLLEmYAA834VN1SboB6wJIAPxQU3rcBhXqO9y8aa2oRMg8NxZ5gr+ PnKVMqag1x0IxbIgLxtkXQvxXxQHEMSODzvcOfK/nBRBsqTj30P+R87sU8titOox NeRnBDRNhdEy/QGAqGh62ShPpQUCJdnKRiRTjnil9hMQHevoSuFKeEMO30FQL7BZ yo37GFU+q1WPCplVZgCP9hC8Rn5K2+f6KLFo5bhtowSmu+GY1yZtg+RTtsA= -----END X509 CRL-----

2024-04-28 11:00:31 TCP/UDP: Preserving recently used remote address: [AF_INET]{redacted} 2024-04-28 11:00:31 UDPv4 link local: (not bound) 2024-04-28 11:00:31 UDPv4 link remote: [AF_INET]{redacted} 2024-04-28 11:00:31 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this 2024-04-28 11:00:31 VERIFY ERROR: CRL not loaded 2024-04-28 11:00:31 OpenSSL: error:0A000086:SSL routines::certificate verify failed: 2024-04-28 11:00:31 TLS_ERROR: BIO read tls_read_plaintext error 2024-04-28 11:00:31 TLS Error: TLS object -> incoming plaintext read error 2024-04-28 11:00:31 TLS Error: TLS handshake failed 2024-04-28 11:00:31 SIGUSR1[soft,tls-error] received, process restarting

EDIT: Workaround, remove the crl-verify block until Private Internet Access sort it out and issue one without the bad times in.

relyef commented 2 months ago

Hey Relyef, do you mind sharing the settings in the openvpn config + settings used to generate your file? I have been trying to regenerate different options with private internet access VPN but so far no luck.

The config files were downloaded from Proton VPN download page, not generated. Here's an excerpt from UDP config that stopped working after the recent HA update:

client dev tun proto udp

remote XXX.XXX.XXX.XXX 51820 remote XXX.XXX.XXX.XXX 4569 remote XXX.XXX.XXX.XXX 1194 remote XXX.XXX.XXX.XXX 80 remote XXX.XXX.XXX.XXX 5060

remote-random resolv-retry infinite nobind

cipher AES-256-CBC

auth SHA512 verb 3

setenv CLIENT_CERT 0 tun-mtu 1500 tun-mtu-extra 32 mssfix 1450 persist-key persist-tun

reneg-sec 0

remote-cert-tls server auth-user-pass pull fast-io

-----BEGIN CERTIFICATE----- ...

and here's the working one:

client dev tun proto udp

remote XXX.XXX.XXX.XXX 51820 remote XXX.XXX.XXX.XXX 5060 remote XXX.XXX.XXX.XXX 80 remote XXX.XXX.XXX.XXX 1194 remote XXX.XXX.XXX.XXX 4569

remote-random resolv-retry infinite nobind

cipher AES-256-GCM

setenv CLIENT_CERT 0 tun-mtu 1500 mssfix 0 persist-key persist-tun

reneg-sec 0

remote-cert-tls server auth-user-pass

-----BEGIN CERTIFICATE-----
jdumeez commented 2 months ago

Also have this issue, also with PIA VPN.

Some more detail of startup. It seems like the current CRL that they are putting in their generated OpenVPN config is being rejected:

2024-04-28 11:00:31 DEPRECATED OPTION: --cipher set to 'aes-256-cbc' but missing in --data-ciphers (AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305). OpenVPN ignores --cipher for cipher negotiations. 2024-04-28 11:00:31 OpenVPN 2.6.10 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] 2024-04-28 11:00:31 library versions: OpenSSL 3.3.0 9 Apr 2024, LZO 2.10 2024-04-28 11:00:31 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts 2024-04-28 11:00:31 OpenSSL: error:068000E9:asn1 encoding routines::utctime is too short: 2024-04-28 11:00:31 OpenSSL: error:0688010A:asn1 encoding routines::nested asn1 error:Field=revocationDate, Type=X509_REVOKED 2024-04-28 11:00:31 OpenSSL: error:0688010A:asn1 encoding routines::nested asn1 error:Field=revoked, Type=X509_CRL_INFO 2024-04-28 11:00:31 OpenSSL: error:0688010A:asn1 encoding routines::nested asn1 error:Field=crl, Type=X509_CRL 2024-04-28 11:00:31 OpenSSL: error:0488000D:PEM routines::ASN1 lib: 2024-04-28 11:00:31 CRL: cannot read CRL from file [[INLINE]] 2024-04-28 11:00:31 CRL: loaded 0 CRLs from file -----BEGIN X509 CRL----- MIIDWDCCAUAwDQYJKoZIhvcNAQENBQAwgegxCzAJBgNVBAYTAlVTMQswCQYDVQQI EwJDQTETMBEGA1UEBxMKTG9zQW5nZWxlczEgMB4GA1UEChMXUHJpdmF0ZSBJbnRl cm5ldCBBY2Nlc3MxIDAeBgNVBAsTF1ByaXZhdGUgSW50ZXJuZXQgQWNjZXNzMSAw HgYDVQQDExdQcml2YXRlIEludGVybmV0IEFjY2VzczEgMB4GA1UEKRMXUHJpdmF0 ZSBJbnRlcm5ldCBBY2Nlc3MxLzAtBgkqhkiG9w0BCQEWIHNlY3VyZUBwcml2YXRl aW50ZXJuZXRhY2Nlc3MuY29tFw0xNjA3MDgxOTAwNDZaFw0zNjA3MDMxOTAwNDZa MCYwEQIBARcMMTYwNzA4MTkwMDQ2MBECAQYXDDE2MDcwODE5MDA0NjANBgkqhkiG 9w0BAQ0FAAOCAgEAppFfEpGsasjB1QgJcosGpzbf2kfRhM84o2TlqY1ua+Gi5TMd KydA3LJcNTjlI9a0TYAJfeRX5IkpoglSUuHuJgXhP3nEvX10mjXDpcu/YvM8TdE5 JV2+EGqZ80kFtBeOq94WcpiVKFTR4fO+VkOK9zwspFfb1cNs9rHvgJ1QMkRUF8Pp LN6AkntHY0+6DnigtSaKqldqjKTDTv2OeH3nPoh80SGrt0oCOmYKfWTJGpggMGKv IdvU3vH9+EuILZKKIskt+1dwdfA5Bkz1GLmiQG7+9ZZBQUjBG9Dos4hfX/rwJ3eU 8oUIm4WoTz9rb71SOEuUUjP5NPy9HNx2vx+cVvLsTF4ZDZaUztW9o9JmIURDtbey qxuHN3prlPWB6aj73IIm2dsDQvs3XXwRIxs8NwLbJ6CyEuvEOVCskdM8rdADWx1J 0lRNlOJ0Z8ieLLEmYAA834VN1SboB6wJIAPxQU3rcBhXqO9y8aa2oRMg8NxZ5gr+ PnKVMqag1x0IxbIgLxtkXQvxXxQHEMSODzvcOfK/nBRBsqTj30P+R87sU8titOox NeRnBDRNhdEy/QGAqGh62ShPpQUCJdnKRiRTjnil9hMQHevoSuFKeEMO30FQL7BZ yo37GFU+q1WPCplVZgCP9hC8Rn5K2+f6KLFo5bhtowSmu+GY1yZtg+RTtsA= -----END X509 CRL----- 2024-04-28 11:00:31 TCP/UDP: Preserving recently used remote address: [AF_INET]{redacted} 2024-04-28 11:00:31 UDPv4 link local: (not bound) 2024-04-28 11:00:31 UDPv4 link remote: [AF_INET]{redacted} 2024-04-28 11:00:31 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this 2024-04-28 11:00:31 VERIFY ERROR: CRL not loaded 2024-04-28 11:00:31 OpenSSL: error:0A000086:SSL routines::certificate verify failed: 2024-04-28 11:00:31 TLS_ERROR: BIO read tls_read_plaintext error 2024-04-28 11:00:31 TLS Error: TLS object -> incoming plaintext read error 2024-04-28 11:00:31 TLS Error: TLS handshake failed 2024-04-28 11:00:31 SIGUSR1[soft,tls-error] received, process restarting

EDIT: Workaround, remove the crl-verify block until Private Internet Access sort it out and issue one without the bad times in.

Thx Bobbyquantum. Removing the entire block indeed worked for PIA VPN

alexbelgium commented 2 months ago

Thanks ; given it should be temporary I guess we should let this open for the time being so other people can see it... I'm not confortable doing it by default in my code as I suppose the crl-verify line exists for some reason

github-actions[bot] commented 1 month ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.