Bitmask tries to use services from different providers
Apparently Bitmask is trying to login with one provider and starting the VPN with another, or (most likely) starting services with a user from demo.bitmask.net on riseup.net
We need to figure out where this scenario is created to prevent to happening.
NOTE: I've changed the original username to 'original_username_removed'.
Contents of @~/.config/leap/leap.conf@:
[General] SkipFirstRun=true RememberUserAndPass=true Provider=riseup.net User=original_username_removed@demo.bitmask.net AutoStartEIP=true DefaultProvider=riseup.net [riseup.net] Services=openvpn [demo.bitmask.net] Services=openvpn
logs:
[2015-12-14 14:08:09] DEBUG - L#None : None:None - Checking requirements... [2015-12-14 14:08:09] DEBUG - L#None : None:None - requests>=1.1.0 ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - srp>=1.0.2 ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - pyopenssl ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - psutil ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - ipaddr ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - python-daemon # this should not be needed for Windows. ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - keyring ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - zope.proxy ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - pyzmq ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - txzmq ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - oauth ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - logbook>=0.7.0 ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - leap.soledad.client>=0.6.0 ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - leap.keymanager>=0.4.0 ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - leap.mail>=0.4.0 ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - leap.common>=0.4.0 ... OK [2015-12-14 14:08:09] DEBUG - L#None : None:None - Done [2015-12-14 14:08:09] INFO - L#None : None:None - ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ [2015-12-14 14:08:09] INFO - L#None : None:None - Bitmask version 0.9.1 [2015-12-14 14:08:09] INFO - L#None : None:None - leap.mail version 0.4.0 [2015-12-14 14:08:09] INFO - L#None : None:None - LSB Release info: [2015-12-14 14:08:09] INFO - L#None : None:None - Distributor ID: Debian [2015-12-14 14:08:09] INFO - L#None : None:None - Description: Debian GNU/Linux 8.2 (jessie) [2015-12-14 14:08:09] INFO - L#None : None:None - Release: 8.2 [2015-12-14 14:08:09] INFO - L#None : None:None - Codename: jessie [2015-12-14 14:08:09] INFO - L#None : None:None - ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ [2015-12-14 14:08:09] INFO - L#None : None:None - Starting app [2015-12-14 14:08:09] DEBUG - L#None : None:None - Setting up ZMQ connection to server... [2015-12-14 14:08:09] DEBUG - L#None : None:None - Checking whether backend is online... [2015-12-14 14:08:09] WARNING - L#None : None:None - Backend is offline! [2015-12-14 14:08:09] DEBUG - L#None : None:None - Backend online: False [2015-12-14 14:08:09] DEBUG - L#None : None:None - Connecting to signaling server... [2015-12-14 14:08:09] DEBUG - L#None : None:None - Starting Twisted reactor. [2015-12-14 14:08:10] DEBUG - L#None : None:None - Setting up ZMQ connection to server... [2015-12-14 14:08:10] DEBUG - L#None : None:None - Starting backend proxy... [2015-12-14 14:08:10] DEBUG - L#None : None:None - Starting ZMQ loop. [2015-12-14 14:08:10] DEBUG - L#None : None:None - Checking whether backend is online... [2015-12-14 14:08:10] WARNING - L#None : None:None - Backend is offline! [2015-12-14 14:08:10] DEBUG - L#None : None:None - Running SignalerQt loop [2015-12-14 14:08:10] DEBUG - L#None : None:None - Selected keyring: [2015-12-14 14:08:10] DEBUG - L#None : None:None - Selected keyring: [2015-12-14 14:08:10] DEBUG - L#None : None:None - Running initializer for Linux [2015-12-14 14:08:10] DEBUG - L#None : None:None - eip machine started [2015-12-14 14:08:10] DEBUG - L#None : None:None - Starting mail state machine... [2015-12-14 14:08:10] DEBUG - L#None : None:None - State Encrypted Internet::off entered. Emitting signal ... [2015-12-14 14:08:10] DEBUG - L#None : None:None - State Mail::off entered. Emitting signal ... [2015-12-14 14:08:10] DEBUG - L#None : None:None - State IMAP::off entered. Emitting signal ... [2015-12-14 14:08:10] DEBUG - L#None : None:None - State IMAP::off entered. Emitting signal ... [2015-12-14 14:08:11] DEBUG - L#None : None:None - Showing EIP start button [2015-12-14 14:08:11] DEBUG - L#None : None:None - [2015-12-14 14:08:11] DEBUG - L#None : None:None - Showing EIP start button [2015-12-14 14:08:11] DEBUG - L#None : None:None - Starting... [2015-12-14 14:08:11] DEBUG - L#None : None:None - Downloading EIP config for riseup.net [2015-12-14 14:08:11] DEBUG - L#None : None:None - Downloading EIP config from: https://api.black.riseup.net:443/1/config/eip-service.json [2015-12-14 14:08:11] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/riseup.net/keys/ca/cacert.pem [2015-12-14 14:08:11] DEBUG - L#None : None:None - EIP definition has not been modified [2015-12-14 14:08:11] DEBUG - L#None : None:None - Downloading EIP client certificate for riseup.net [2015-12-14 14:08:11] DEBUG - L#None : None:None - State Encrypted Internet::connecting entered. Emitting signal ... [2015-12-14 14:08:11] DEBUG - L#None : None:None - VPN: start [2015-12-14 14:08:11] DEBUG - L#None : None:None - Using gateways (ip, port): [(u'199.254.238.128', '443'), (u'199.58.81.145', '443'), (u'1.209.122.29', '443'), (u'5.79.86.180', '443')] [2015-12-14 14:08:11] DEBUG - L#None : None:None - Using gateways (ip, port): [(u'199.254.238.128', '443'), (u'199.58.81.145', '443'), (u'1.209.122.29', '443'), (u'5.79.86.180', '443')] [2015-12-14 14:08:11] DEBUG - L#None : None:None - Using OpenVPN cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem [2015-12-14 14:08:11] DEBUG - L#None : None:None - Using OpenVPN cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem [2015-12-14 14:08:11] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/riseup.net/keys/ca/cacert.pem [2015-12-14 14:08:11] DEBUG - L#None : None:None - Running VPN with command: [2015-12-14 14:08:11] DEBUG - L#None : None:None - /usr/bin/pkexec /usr/sbin/bitmask-root openvpn start /usr/sbin/openvpn --setenv LEAPOPENVPN 1 --nobind --remote 199.254.238.128 443 udp --remote 199.58.81.145 443 udp --remote 1.209.122.29 443 udp --remote 5.79.86.180 443 udp --client --dev tun --persist-key --tls-client --remote-cert-tls server --tls-cipher DHE-RSA-AES128-SHA --cipher AES-128-CBC --auth SHA1 --management-client-user username --management-signal --management /tmp/leap-tmp4ZABs7/openvpn.socket unix --script-security 2 --cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem --key /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem --ca /home/username/.config/leap/providers/riseup.net/keys/ca/cacert.pem --ping 10 --ping-restart 30 [2015-12-14 14:08:11] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:08:11] WARNING - L#None : None:None - Could not connect to OpenVPN yet: MissingSocketError() [2015-12-14 14:08:11] DEBUG - L#None : None:None - Cannot connect to management... [2015-12-14 14:08:11] DEBUG - L#None : None:None - EIP: no errors [2015-12-14 14:08:11] INFO - L#None : None:None - Mon Dec 14 06:08:11 2015 OpenVPN 2.3.4 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Dec 1 2014 Mon Dec 14 06:08:11 2015 library versions: OpenSSL 1.0.1k 8 Jan 2015, LZO 2.08 [2015-12-14 14:08:11] INFO - L#None : None:None - Mon Dec 14 06:08:11 2015 WARNING: you are using user/group/chroot/setcon without persist-tun -- this may cause restarts to fail Mon Dec 14 06:08:11 2015 WARNING: you are using user/group/chroot/setcon without persist-key -- this may cause restarts to fail [2015-12-14 14:08:11] INFO - L#None : None:None - Mon Dec 14 06:08:11 2015 Deprecated TLS cipher name 'DHE-RSA-AES128-SHA', please use IANA name 'TLS-DHE-RSA-WITH-AES-128-CBC-SHA' [2015-12-14 14:08:11] INFO - L#None : None:None - Mon Dec 14 06:08:11 2015 NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay Mon Dec 14 06:08:11 2015 UDPv4 link local: [undef] [2015-12-14 14:08:11] INFO - L#None : None:None - Mon Dec 14 06:08:11 2015 UDPv4 link remote: [AF_INET]199.254.238.128:443 [2015-12-14 14:08:12] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:08:12] INFO - L#None : None:None - Connected to management [2015-12-14 14:08:12] DEBUG - L#None : None:None - Waiting to start... [2015-12-14 14:08:13] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:08:14] DEBUG - L#None : None:None - Stopping services... [2015-12-14 14:08:14] DEBUG - L#None : None:None - Stopping mail services [2015-12-14 14:08:14] DEBUG - L#None : None:None - Mail services not started. [2015-12-14 14:08:14] DEBUG - L#None : None:None - Doing logout [2015-12-14 14:08:14] DEBUG - L#None : None:None - Not logged in. [2015-12-14 14:08:14] DEBUG - L#None : None:None - Terminating vpn [2015-12-14 14:08:14] INFO - L#None : None:None - Mon Dec 14 06:08:14 2015 SIGTERM[hard,] received, process exiting [2015-12-14 14:08:14] DEBUG - L#None : None:None - Could not read from socket. Assuming it died. [2015-12-14 14:08:14] DEBUG - L#None : None:None - cleaning socket file temp folder [2015-12-14 14:08:14] DEBUG - L#None : None:None - processExited, status 0 [2015-12-14 14:08:14] DEBUG - L#None : None:None - processEnded, status 0 [2015-12-14 14:08:14] INFO - L#None : None:None - VPN process finished with exitCode 0... [2015-12-14 14:08:14] ERROR - L#None : None:None - Encrypted Internet finished in an unexpected manner! [2015-12-14 14:08:14] DEBUG - L#None : None:None - Bitmask is blocking unencrypted traffic. [2015-12-14 14:08:14] DEBUG - L#None : None:None - State Encrypted Internet::off entered. Emitting signal ... [2015-12-14 14:08:14] DEBUG - L#None : None:None - Firewall down [2015-12-14 14:08:14] DEBUG - L#None : None:None - Removing service: eip [2015-12-14 14:08:14] DEBUG - L#None : None:None - Showing EIP start button [2015-12-14 14:08:14] DEBUG - L#None : None:None - [2015-12-14 14:08:15] DEBUG - L#None : None:None - Process has been happily terminated. [2015-12-14 14:08:15] DEBUG - L#None : None:None - Firewall down [2015-12-14 14:08:18] INFO - L#455 : twisted.python.log:emit - Setting up provider demo.bitmask.net... [2015-12-14 14:08:18] DEBUG - L#None : None:None - Checking name resolution for u'demo.bitmask.net' [2015-12-14 14:08:18] DEBUG - L#None : None:None - Checking https for u'demo.bitmask.net' [2015-12-14 14:08:19] DEBUG - L#None : None:None - Downloading provider info for u'demo.bitmask.net' [2015-12-14 14:08:19] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem [2015-12-14 14:08:19] DEBUG - L#None : None:None - Requesting for provider.json... uri: https://api.demo.bitmask.net:4430/provider.json, verify: /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem, headers: {'if-modified-since': 'Thu Jul 30 18:43:25 2015 GMT'} [2015-12-14 14:08:19] DEBUG - L#None : None:None - Request status code: 200 [2015-12-14 14:08:19] DEBUG - L#None : None:None - Provider definition has been modified [2015-12-14 14:08:43] DEBUG - L#None : None:None - Post to uri: https://api.demo.bitmask.net:4430/1/users [2015-12-14 14:08:43] DEBUG - L#None : None:None - Will try to register user = original_username_removed [2015-12-14 14:08:43] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem [2015-12-14 14:08:44] DEBUG - L#None : None:None - Status code is: 201 [2015-12-14 14:08:44] DEBUG - L#None : None:None - Selected keyring: [2015-12-14 14:08:47] DEBUG - L#None : None:None - Selected keyring: [2015-12-14 14:08:47] DEBUG - L#None : None:None - Selected keyring: [2015-12-14 14:08:47] DEBUG - L#None : None:None - Selected keyring: [2015-12-14 14:08:47] INFO - L#455 : twisted.python.log:emit - Setting up provider demo.bitmask.net... [2015-12-14 14:08:47] DEBUG - L#None : None:None - Checking name resolution for u'demo.bitmask.net' [2015-12-14 14:08:47] DEBUG - L#None : None:None - Checking https for u'demo.bitmask.net' [2015-12-14 14:08:48] DEBUG - L#None : None:None - Showing EIP start button [2015-12-14 14:08:48] DEBUG - L#None : None:None - [2015-12-14 14:08:49] DEBUG - L#None : None:None - Downloading provider info for u'demo.bitmask.net' [2015-12-14 14:08:49] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem [2015-12-14 14:08:49] DEBUG - L#None : None:None - Requesting for provider.json... uri: https://api.demo.bitmask.net:4430/provider.json, verify: /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem, headers: {'if-modified-since': 'Thu Jul 30 18:43:25 2015 GMT'} [2015-12-14 14:08:52] DEBUG - L#None : None:None - Request status code: 200 [2015-12-14 14:08:52] DEBUG - L#None : None:None - Provider definition has been modified [2015-12-14 14:08:52] DEBUG - L#None : None:None - Downloading ca cert for u'demo.bitmask.net' at u'https://demo.bitmask.net/ca.crt' [2015-12-14 14:08:52] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem [2015-12-14 14:08:52] DEBUG - L#None : None:None - Checking ca fingerprint for u'demo.bitmask.net' and cert '/home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem' [2015-12-14 14:08:52] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem [2015-12-14 14:08:52] DEBUG - L#None : None:None - Checking api certificate for https://api.demo.bitmask.net:4430 and cert /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem [2015-12-14 14:08:52] DEBUG - L#None : None:None - Authentication preprocessing... [2015-12-14 14:08:52] DEBUG - L#None : None:None - Starting authentication process... [2015-12-14 14:08:52] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem [2015-12-14 14:08:53] DEBUG - L#None : None:None - Processing challenge... [2015-12-14 14:08:53] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem [2015-12-14 14:08:53] DEBUG - L#None : None:None - Verifying session... [2015-12-14 14:08:53] DEBUG - L#None : None:None - Session verified. [2015-12-14 14:08:53] DEBUG - L#None : None:None - SUCCESS LOGIN [2015-12-14 14:08:53] DEBUG - L#None : None:None - Successful login! [2015-12-14 14:08:53] DEBUG - L#None : None:None - Provider does not offer MX, but it is enabled. [2015-12-14 14:08:54] DEBUG - L#None : None:None - State Encrypted Internet::connecting entered. Emitting signal ... [2015-12-14 14:08:54] DEBUG - L#None : None:None - VPN: start [2015-12-14 14:08:54] DEBUG - L#None : None:None - Using gateways (ip, port): [(u'199.254.238.128', '443'), (u'199.58.81.145', '443'), (u'1.209.122.29', '443'), (u'5.79.86.180', '443')] [2015-12-14 14:08:54] DEBUG - L#None : None:None - Using gateways (ip, port): [(u'199.254.238.128', '443'), (u'199.58.81.145', '443'), (u'1.209.122.29', '443'), (u'5.79.86.180', '443')] [2015-12-14 14:08:54] DEBUG - L#None : None:None - Using OpenVPN cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem [2015-12-14 14:08:54] DEBUG - L#None : None:None - Using OpenVPN cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem [2015-12-14 14:08:54] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/riseup.net/keys/ca/cacert.pem [2015-12-14 14:08:55] DEBUG - L#None : None:None - Running VPN with command: [2015-12-14 14:08:55] DEBUG - L#None : None:None - /usr/bin/pkexec /usr/sbin/bitmask-root openvpn start /usr/sbin/openvpn --setenv LEAPOPENVPN 1 --nobind --remote 199.254.238.128 443 udp --remote 199.58.81.145 443 udp --remote 1.209.122.29 443 udp --remote 5.79.86.180 443 udp --client --dev tun --persist-key --tls-client --remote-cert-tls server --tls-cipher DHE-RSA-AES128-SHA --cipher AES-128-CBC --auth SHA1 --management-client-user username --management-signal --management /tmp/leap-tmp1aA_Hs/openvpn.socket unix --script-security 2 --cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem --key /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem --ca /home/username/.config/leap/providers/riseup.net/keys/ca/cacert.pem --ping 10 --ping-restart 30 [2015-12-14 14:08:55] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:08:55] WARNING - L#None : None:None - Could not connect to OpenVPN yet: MissingSocketError() [2015-12-14 14:08:55] DEBUG - L#None : None:None - Cannot connect to management... [2015-12-14 14:08:55] DEBUG - L#None : None:None - EIP: no errors [2015-12-14 14:08:55] INFO - L#None : None:None - Mon Dec 14 06:08:55 2015 OpenVPN 2.3.4 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Dec 1 2014 Mon Dec 14 06:08:55 2015 library versions: OpenSSL 1.0.1k 8 Jan 2015, LZO 2.08 [2015-12-14 14:08:55] INFO - L#None : None:None - Mon Dec 14 06:08:55 2015 WARNING: you are using user/group/chroot/setcon without persist-tun -- this may cause restarts to fail Mon Dec 14 06:08:55 2015 WARNING: you are using user/group/chroot/setcon without persist-key -- this may cause restarts to fail [2015-12-14 14:08:55] INFO - L#None : None:None - Mon Dec 14 06:08:55 2015 Deprecated TLS cipher name 'DHE-RSA-AES128-SHA', please use IANA name 'TLS-DHE-RSA-WITH-AES-128-CBC-SHA' [2015-12-14 14:08:55] INFO - L#None : None:None - Mon Dec 14 06:08:55 2015 NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay Mon Dec 14 06:08:55 2015 UDPv4 link local: [undef] Mon Dec 14 06:08:55 2015 UDPv4 link remote: [AF_INET]199.254.238.128:443 [2015-12-14 14:08:56] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:08:56] INFO - L#None : None:None - Connected to management [2015-12-14 14:08:56] DEBUG - L#None : None:None - Waiting to start... [2015-12-14 14:08:57] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:09:11] DEBUG - L#None : None:None - Provider does not offer MX, but it is enabled. [2015-12-14 14:09:55] INFO - L#None : None:None - Mon Dec 14 06:09:55 2015 TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity) Mon Dec 14 06:09:55 2015 TLS Error: TLS handshake failed Mon Dec 14 06:09:55 2015 SIGTERM[soft,tls-error] received, process exiting [2015-12-14 14:09:55] DEBUG - L#None : None:None - pattern matched! SIGTERM[soft,tls-error] [2015-12-14 14:09:55] WARNING - L#None : None:None - socket error (command was: "state") [2015-12-14 14:09:55] DEBUG - L#None : None:None - closing socket [2015-12-14 14:09:55] DEBUG - L#None : None:None - trying to connect to management again [2015-12-14 14:09:55] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:09:55] WARNING - L#None : None:None - Could not connect to OpenVPN yet: MissingSocketError() [2015-12-14 14:09:55] DEBUG - L#None : None:None - Cannot connect to management... [2015-12-14 14:09:55] DEBUG - L#None : None:None - processExited, status 0 [2015-12-14 14:09:55] DEBUG - L#None : None:None - processEnded, status 0 [2015-12-14 14:09:55] DEBUG - L#None : None:None - TLS Error: eip_stop (failed) [2015-12-14 14:09:55] DEBUG - L#None : None:None - State Encrypted Internet::off entered. Emitting signal ... [2015-12-14 14:09:55] INFO - L#None : None:None - VPN process finished with exitCode 0... [2015-12-14 14:09:55] ERROR - L#None : None:None - Encrypted Internet finished in an unexpected manner! [2015-12-14 14:09:55] DEBUG - L#None : None:None - Bitmask is blocking unencrypted traffic. [2015-12-14 14:09:56] DEBUG - L#None : None:None - Tried to connect to management but process is not alive. [2015-12-14 14:09:56] DEBUG - L#None : None:None - Bitmask is blocking unencrypted traffic. [2015-12-14 14:10:22] DEBUG - L#None : None:None - [2015-12-14 14:10:25] DEBUG - L#None : None:None - State Encrypted Internet::connecting entered. Emitting signal ... [2015-12-14 14:10:26] DEBUG - L#None : None:None - VPN: start [2015-12-14 14:10:26] DEBUG - L#None : None:None - Using gateways (ip, port): [(u'199.254.238.128', '443'), (u'199.58.81.145', '443'), (u'1.209.122.29', '443'), (u'5.79.86.180', '443')] [2015-12-14 14:10:26] DEBUG - L#None : None:None - Using gateways (ip, port): [(u'199.254.238.128', '443'), (u'199.58.81.145', '443'), (u'1.209.122.29', '443'), (u'5.79.86.180', '443')] [2015-12-14 14:10:26] DEBUG - L#None : None:None - Using OpenVPN cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem [2015-12-14 14:10:26] DEBUG - L#None : None:None - Using OpenVPN cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem [2015-12-14 14:10:26] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/riseup.net/keys/ca/cacert.pem [2015-12-14 14:10:26] DEBUG - L#None : None:None - Running VPN with command: [2015-12-14 14:10:26] DEBUG - L#None : None:None - /usr/bin/pkexec /usr/sbin/bitmask-root openvpn start /usr/sbin/openvpn --setenv LEAPOPENVPN 1 --nobind --remote 199.254.238.128 443 udp --remote 199.58.81.145 443 udp --remote 1.209.122.29 443 udp --remote 5.79.86.180 443 udp --client --dev tun --persist-key --tls-client --remote-cert-tls server --tls-cipher DHE-RSA-AES128-SHA --cipher AES-128-CBC --auth SHA1 --management-client-user username --management-signal --management /tmp/leap-tmpfwThMH/openvpn.socket unix --script-security 2 --cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem --key /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem --ca /home/username/.config/leap/providers/riseup.net/keys/ca/cacert.pem --ping 10 --ping-restart 30 [2015-12-14 14:10:26] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:10:26] WARNING - L#None : None:None - Could not connect to OpenVPN yet: MissingSocketError() [2015-12-14 14:10:26] DEBUG - L#None : None:None - Cannot connect to management... [2015-12-14 14:10:26] DEBUG - L#None : None:None - EIP: no errors [2015-12-14 14:10:26] INFO - L#None : None:None - Mon Dec 14 06:10:26 2015 OpenVPN 2.3.4 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Dec 1 2014 Mon Dec 14 06:10:26 2015 library versions: OpenSSL 1.0.1k 8 Jan 2015, LZO 2.08 [2015-12-14 14:10:26] INFO - L#None : None:None - Mon Dec 14 06:10:26 2015 WARNING: you are using user/group/chroot/setcon without persist-tun -- this may cause restarts to fail Mon Dec 14 06:10:26 2015 WARNING: you are using user/group/chroot/setcon without persist-key -- this may cause restarts to fail [2015-12-14 14:10:26] INFO - L#None : None:None - Mon Dec 14 06:10:26 2015 Deprecated TLS cipher name 'DHE-RSA-AES128-SHA', please use IANA name 'TLS-DHE-RSA-WITH-AES-128-CBC-SHA' [2015-12-14 14:10:26] INFO - L#None : None:None - Mon Dec 14 06:10:26 2015 NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay Mon Dec 14 06:10:26 2015 UDPv4 link local: [undef] [2015-12-14 14:10:26] INFO - L#None : None:None - Mon Dec 14 06:10:26 2015 UDPv4 link remote: [AF_INET]199.254.238.128:443 [2015-12-14 14:10:27] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:10:27] INFO - L#None : None:None - Connected to management [2015-12-14 14:10:27] DEBUG - L#None : None:None - Waiting to start... [2015-12-14 14:10:28] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:10:38] DEBUG - L#None : None:None - Stopping services... [2015-12-14 14:10:38] DEBUG - L#None : None:None - Stopping mail services [2015-12-14 14:10:38] DEBUG - L#None : None:None - Mail services not started. [2015-12-14 14:10:38] DEBUG - L#None : None:None - Doing logout [2015-12-14 14:10:38] DEBUG - L#None : None:None - Terminating vpn [2015-12-14 14:10:38] DEBUG - L#None : None:None - Starting logout... [2015-12-14 14:10:38] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem [2015-12-14 14:10:38] INFO - L#None : None:None - Mon Dec 14 06:10:38 2015 SIGTERM[hard,] received, process exiting [2015-12-14 14:10:38] DEBUG - L#None : None:None - Could not read from socket. Assuming it died. [2015-12-14 14:10:38] DEBUG - L#None : None:None - cleaning socket file temp folder [2015-12-14 14:10:38] DEBUG - L#None : None:None - processExited, status 0 [2015-12-14 14:10:38] DEBUG - L#None : None:None - processEnded, status 0 [2015-12-14 14:10:38] INFO - L#None : None:None - VPN process finished with exitCode 0... [2015-12-14 14:10:38] ERROR - L#None : None:None - Encrypted Internet finished in an unexpected manner! [2015-12-14 14:10:38] DEBUG - L#None : None:None - Bitmask is blocking unencrypted traffic. [2015-12-14 14:10:38] DEBUG - L#None : None:None - State Encrypted Internet::off entered. Emitting signal ... [2015-12-14 14:10:38] DEBUG - L#None : None:None - Firewall down [2015-12-14 14:10:38] DEBUG - L#None : None:None - Showing EIP start button [2015-12-14 14:10:38] DEBUG - L#None : None:None - [2015-12-14 14:10:38] DEBUG - L#None : None:None - Removing service: eip [2015-12-14 14:10:38] DEBUG - L#None : None:None - Removing service: eip [2015-12-14 14:10:39] DEBUG - L#None : None:None - Process has been happily terminated. [2015-12-14 14:10:39] DEBUG - L#None : None:None - Firewall down [2015-12-14 14:10:41] DEBUG - L#None : None:None - State Encrypted Internet::connecting entered. Emitting signal ... [2015-12-14 14:10:41] DEBUG - L#None : None:None - VPN: start [2015-12-14 14:10:41] DEBUG - L#None : None:None - Using gateways (ip, port): [(u'199.254.238.128', '443'), (u'199.58.81.145', '443'), (u'1.209.122.29', '443'), (u'5.79.86.180', '443')] [2015-12-14 14:10:41] DEBUG - L#None : None:None - Using gateways (ip, port): [(u'199.254.238.128', '443'), (u'199.58.81.145', '443'), (u'1.209.122.29', '443'), (u'5.79.86.180', '443')] [2015-12-14 14:10:41] DEBUG - L#None : None:None - Using OpenVPN cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem [2015-12-14 14:10:41] DEBUG - L#None : None:None - Using OpenVPN cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem [2015-12-14 14:10:41] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/riseup.net/keys/ca/cacert.pem [2015-12-14 14:10:42] DEBUG - L#None : None:None - Running VPN with command: [2015-12-14 14:10:42] DEBUG - L#None : None:None - /usr/bin/pkexec /usr/sbin/bitmask-root openvpn start /usr/sbin/openvpn --setenv LEAPOPENVPN 1 --nobind --remote 199.254.238.128 443 udp --remote 199.58.81.145 443 udp --remote 1.209.122.29 443 udp --remote 5.79.86.180 443 udp --client --dev tun --persist-key --tls-client --remote-cert-tls server --tls-cipher DHE-RSA-AES128-SHA --cipher AES-128-CBC --auth SHA1 --management-client-user username --management-signal --management /tmp/leap-tmpGnXNu5/openvpn.socket unix --script-security 2 --cert /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem --key /home/username/.config/leap/providers/riseup.net/keys/client/openvpn.pem --ca /home/username/.config/leap/providers/riseup.net/keys/ca/cacert.pem --ping 10 --ping-restart 30 [2015-12-14 14:10:42] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:10:42] WARNING - L#None : None:None - Could not connect to OpenVPN yet: MissingSocketError() [2015-12-14 14:10:42] DEBUG - L#None : None:None - Cannot connect to management... [2015-12-14 14:10:42] DEBUG - L#None : None:None - EIP: no errors [2015-12-14 14:10:42] INFO - L#None : None:None - Mon Dec 14 06:10:42 2015 OpenVPN 2.3.4 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH] [IPv6] built on Dec 1 2014 Mon Dec 14 06:10:42 2015 library versions: OpenSSL 1.0.1k 8 Jan 2015, LZO 2.08 [2015-12-14 14:10:42] INFO - L#None : None:None - Mon Dec 14 06:10:42 2015 WARNING: you are using user/group/chroot/setcon without persist-tun -- this may cause restarts to fail Mon Dec 14 06:10:42 2015 WARNING: you are using user/group/chroot/setcon without persist-key -- this may cause restarts to fail [2015-12-14 14:10:42] INFO - L#None : None:None - Mon Dec 14 06:10:42 2015 Deprecated TLS cipher name 'DHE-RSA-AES128-SHA', please use IANA name 'TLS-DHE-RSA-WITH-AES-128-CBC-SHA' [2015-12-14 14:10:42] INFO - L#None : None:None - Mon Dec 14 06:10:42 2015 NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay Mon Dec 14 06:10:42 2015 UDPv4 link local: [undef] [2015-12-14 14:10:42] INFO - L#None : None:None - Mon Dec 14 06:10:42 2015 UDPv4 link remote: [AF_INET]199.254.238.128:443 [2015-12-14 14:10:43] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:10:43] INFO - L#None : None:None - Connected to management [2015-12-14 14:10:43] DEBUG - L#None : None:None - Waiting to start... [2015-12-14 14:10:44] DEBUG - L#None : None:None - trying to connect to management [2015-12-14 14:10:50] DEBUG - L#None : None:None - Quitting... [2015-12-14 14:10:50] DEBUG - L#None : None:None - Stopping services... [2015-12-14 14:10:50] DEBUG - L#None : None:None - Stopping mail services [2015-12-14 14:10:50] DEBUG - L#None : None:None - Mail services not started. [2015-12-14 14:10:50] DEBUG - L#None : None:None - Doing logout [2015-12-14 14:10:50] DEBUG - L#None : None:None - Terminating vpn [2015-12-14 14:10:50] DEBUG - L#None : None:None - Starting logout... [2015-12-14 14:10:50] DEBUG - L#None : None:None - Going to verify SSL against /home/username/.config/leap/providers/demo.bitmask.net/keys/ca/cacert.pem [2015-12-14 14:10:50] INFO - L#None : None:None - Mon Dec 14 06:10:50 2015 SIGTERM[hard,] received, process exiting [2015-12-14 14:10:50] DEBUG - L#None : None:None - Could not read from socket. Assuming it died. [2015-12-14 14:10:50] DEBUG - L#None : None:None - cleaning socket file temp folder [2015-12-14 14:10:50] DEBUG - L#None : None:None - processExited, status 0 [2015-12-14 14:10:50] DEBUG - L#None : None:None - processEnded, status 0 [2015-12-14 14:10:50] INFO - L#None : None:None - VPN process finished with exitCode 0... [2015-12-14 14:10:50] ERROR - L#None : None:None - Encrypted Internet finished in an unexpected manner! [2015-12-14 14:10:50] DEBUG - L#None : None:None - Bitmask is blocking unencrypted traffic. [2015-12-14 14:10:50] DEBUG - L#None : None:None - State Encrypted Internet::off entered. Emitting signal ... [2015-12-14 14:10:50] DEBUG - L#None : None:None - Firewall down [2015-12-14 14:10:50] DEBUG - L#None : None:None - Removing service: eip [2015-12-14 14:10:50] DEBUG - L#None : None:None - Removing service: eip [2015-12-14 14:10:50] DEBUG - L#None : None:None - Removing service: eip [2015-12-14 14:10:51] DEBUG - L#None : None:None - Process has been happily terminated. [2015-12-14 14:10:51] DEBUG - L#None : None:None - Firewall down [2015-12-14 14:10:53] DEBUG - L#None : None:None - Final quit... [2015-12-14 14:10:53] DEBUG - L#None : None:None - Closing soledad... [2015-12-14 14:10:53] DEBUG - L#None : None:None - SignalerQt thread stopped. [2015-12-14 14:10:53] DEBUG - L#None : None:None - BackendProxy worker stopped. [2015-12-14 14:10:53] DEBUG - L#None : None:None - Finished ZMQ loop. [2015-12-14 14:10:53] DEBUG - L#None : None:None - Cleaning pidfiles [2015-12-14 14:10:53] INFO - L#455 : twisted.python.log:emit - Received SIGTERM, shutting down. [2015-12-14 14:10:55] DEBUG - L#None : None:None - Successfully logged out. [2015-12-14 14:10:55] DEBUG - L#None : None:None - Logout success [2015-12-14 14:10:57] WARNING - L#None : None:None - Retrying receive... 1/500 [2015-12-14 14:10:59] WARNING - L#None : None:None - Retrying receive... 2/500 [2015-12-14 14:11:01] WARNING - L#None : None:None - Retrying receive... 3/500 [2015-12-14 14:11:03] WARNING - L#None : None:None - Retrying receive... 4/500 [2015-12-14 14:11:05] WARNING - L#None : None:None - Retrying receive... 5/500 [2015-12-14 14:11:06] WARNING - L#None : None:None - Something went wrong with the logout: ConnectionError(ProtocolError('Connection aborted.', gaierror(-2, 'Name or service not known')),) [2015-12-14 14:11:06] DEBUG - L#None : None:None - Logout error: ConnectionError(ProtocolError('Connection aborted.', gaierror(-2, 'Name or service not known')),) [2015-12-14 14:11:06] INFO - L#455 : twisted.python.log:emit - Main loop terminated. [2015-12-14 14:11:06] DEBUG - L#None : None:None - Finished Twisted reactor.
(from redmine: created on 2015-12-14, relates #7497 (closed))