letheanVPN / lthn-app-vpn

Client/Server dVPN
https://www.lt.hn
European Union Public License 1.2
36 stars 16 forks source link

lthnvpnd.service restart loop v3.1.0 #65

Closed ronnylov closed 5 years ago

ronnylov commented 5 years ago

Hi!

EDIT: This is not only for the Raspberry Pi, see latest comment. Tried to upgrade my LetherPi (raspberry Pi 3B+) to lethean-vpn v.3.1.0

Trying to connect from GUI wallet getting "The proxy may not work or the service is Unavailable." message. After some debugging I checked the output from lthnvpnd.service

sudo journalctl -u lthnvpnd.service -fe

Mar 08 08:36:09 raspberrypi systemd[1]: lthnvpnd.service: Main process exited, code=exited, status=1/FAILURE
Mar 08 08:36:09 raspberrypi systemd[1]: lthnvpnd.service: Unit entered failed state.
Mar 08 08:36:09 raspberrypi systemd[1]: lthnvpnd.service: Failed with result 'exit-code'.
Mar 08 08:36:09 raspberrypi systemd[1]: lthnvpnd.service: Service hold-off time over, scheduling restart.
Mar 08 08:36:09 raspberrypi systemd[1]: Stopped LTHN VPN dispatcher.
Mar 08 08:36:09 raspberrypi systemd[1]: Started LTHN VPN dispatcher.
Mar 08 08:36:10 raspberrypi lthnvpnd[3431]: INFO:audit:type=SERVICE,obj=lthnvpnd,action=START,
Mar 08 08:36:10 raspberrypi lthnvpnd[3431]: WARNING:lthnvpnd:Unknown parameter enabled for service 1A
Mar 08 08:36:10 raspberrypi lthnvpnd[3431]: INFO:audit:serviceid=1A,type=SERVICE,cmd='/usr/sbin/haproxy -Ds -p /opt/lthn/var/proxy_1A/pid -f /opt/lthn/var/proxy_1A/cfg',action=START,
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]: Traceback (most recent call last):
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:   File "/opt/lthn/bin/lthnvpnd", line 176, in <module>
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:     main(sys.argv[1:])
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:   File "/opt/lthn/bin/lthnvpnd", line 144, in main
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:     services.SERVICES.orchestrate()
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:   File "/opt/lthn/lib/services.py", line 104, in orchestrate
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:     o = s.orchestrate()
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:   File "/opt/lthn/lib/service_ha.py", line 118, in orchestrate
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:     return(self.isAlive())
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:   File "/opt/lthn/lib/service_ha.py", line 83, in isAlive
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:     os.kill(self.pid, 0)
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]: TypeError: an integer is required (got type NoneType)
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]: Error in atexit._run_exitfuncs:
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]: Traceback (most recent call last):
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:   File "/opt/lthn/lib/service_ha.py", line 83, in isAlive
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]:     os.kill(self.pid, 0)
Mar 08 08:36:11 raspberrypi lthnvpnd[3431]: TypeError: an integer is required (got type NoneType)
Mar 08 08:36:11 raspberrypi systemd[1]: lthnvpnd.service: Main process exited, code=exited, status=1/FAILURE
Mar 08 08:36:11 raspberrypi systemd[1]: lthnvpnd.service: Unit entered failed state.
Mar 08 08:36:11 raspberrypi systemd[1]: lthnvpnd.service: Failed with result 'exit-code'.
Mar 08 08:36:12 raspberrypi systemd[1]: lthnvpnd.service: Service hold-off time over, scheduling restart.
Mar 08 08:36:12 raspberrypi systemd[1]: Stopped LTHN VPN dispatcher.
Mar 08 08:36:12 raspberrypi systemd[1]: Started LTHN VPN dispatcher.

These messages repeats over and over again.

ronnylov commented 5 years ago

I tried to start it manually in debug mode and got error:

vpnuser@raspberrypi:~ $ /opt/lthn/bin/lthnvpnd -l DEBUG
INFO:audit:obj=lthnvpnd,action=START,type=SERVICE,
DEBUG:lthnvpnd:Setting service 1A parameter max_connections to default (2000)
DEBUG:lthnvpnd:Setting service 1A parameter name to Browser VPN on Raspberry Pi
DEBUG:lthnvpnd:Setting service 1A parameter crt to /opt/lthn/etc/ca/certs/ha.cert.pem
DEBUG:lthnvpnd:Setting service 1A parameter connect_timeout to default (5s)
DEBUG:lthnvpnd:Setting service 1A parameter dispatcher_http_port to default (8188)
DEBUG:lthnvpnd:Setting service 1A parameter conns_period to default (10s)
DEBUG:lthnvpnd:Setting service 1A parameter bind_addr to default (0.0.0.0)
DEBUG:lthnvpnd:Setting service 1A parameter crtkey to /opt/lthn/etc/ca/certs/ha.both.pem
DEBUG:lthnvpnd:Setting service 1A parameter track_sessions to default (True)
DEBUG:lthnvpnd:Setting service 1A parameter key to /opt/lthn/etc/ca/private/ha.key.pem
DEBUG:lthnvpnd:Setting service 1A parameter uniqueid to default (abcd1234)
DEBUG:lthnvpnd:Setting service 1A parameter dispatcher_http_host to default (127.0.0.1)
DEBUG:lthnvpnd:Setting service 1A parameter max_conns_per_ip to default (10000)
DEBUG:lthnvpnd:Setting service 1A parameter paymentid to default (authid1)
DEBUG:lthnvpnd:Setting service 1A parameter timeout to default (30s)
DEBUG:lthnvpnd:Setting service 1A parameter max_conns_per_period to default (10000)
DEBUG:lthnvpnd:Setting service 1A parameter status_port to default (8181)
DEBUG:lthnvpnd:Setting service 1A parameter max_requests_per_period to default (10000)
DEBUG:lthnvpnd:Setting service 1A parameter backend_proxy_server to localhost:3128
WARNING:lthnvpnd:Unknown parameter enabled for service 1A
DEBUG:lthnvpnd:Setting service SS parameter enabled to default (True)
DEBUG:lthnvpnd:Setting service MS parameter enabled to default (True)
DEBUG:lthnvpnd:Setting service HS parameter name to default (HTTP status)
DEBUG:lthnvpnd:Setting service HS parameter bind_addr to default (127.0.0.1)
DEBUG:lthnvpnd:Setting service HS parameter port to default (8188)
INFO:lthnvpnd:Service Browser VPN on Raspberry Pi (proxy), id 1A
INFO:lthnvpnd:Starting service Syslog server[SS]
INFO:lthnvpnd:Starting service Management server[MS]
INFO:lthnvpnd:Starting service HTTP server[HS]
INFO:lthnvpnd:Created haproxy config file /opt/lthn/var/proxy_1A/cfg
INFO:audit:cmd='/usr/sbin/haproxy -Ds -p /opt/lthn/var/proxy_1A/pid -f /opt/lthn/var/proxy_1A/cfg',serviceid=1A,action=START,type=SERVICE,
INFO:lthnvpnd:Waiting for pid
INFO:lthnvpnd:Service 1A: [pid=None]
INFO:lthnvpnd:Starting service Browser VPN on Raspberry Pi[1A]
DEBUG:lthnvpnd:Calling wallet RPC http://127.0.0.1:14660/json_rpc
DEBUG:lthnvpnd:Calling wallet RPC http://127.0.0.1:14660/json_rpc
INFO:lthnvpnd:No new payments in wallet
DEBUG:lthnvpnd:syslog: 'Proxy ssltunnel started.\n'
DEBUG:lthnvpnd:Spawning new http process with pid 7272
Traceback (most recent call last):
  File "/opt/lthn/bin/lthnvpnd", line 176, in <module>
    main(sys.argv[1:])
  File "/opt/lthn/bin/lthnvpnd", line 144, in main
    services.SERVICES.orchestrate()
  File "/opt/lthn/lib/services.py", line 104, in orchestrate
    o = s.orchestrate()
  File "/opt/lthn/lib/service_ha.py", line 118, in orchestrate
    return(self.isAlive())
  File "/opt/lthn/lib/service_ha.py", line 83, in isAlive
    os.kill(self.pid, 0)
TypeError: an integer is required (got type NoneType)
Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File "/opt/lthn/lib/service_ha.py", line 83, in isAlive
    os.kill(self.pid, 0)
TypeError: an integer is required (got type NoneType)
INFO:lthnvpnd:Stopped service HTTP server[HS]
vpnuser@raspberrypi:~ $
ronnylov commented 5 years ago

Tested on Lethernet US.

Upgrade procedure was: First I replaced wallet binaries in /opt/lthn/bin to version 3.1

Then I did as follows:

cd lethean-vpn
git pull
git checkout v3.1.0
./configure.sh --easy
make install
rm -f /opt/lthn/var/authids.db
sudo systemctl daemon-reload
sudo systemctl restart lthnvpnd

Got the same lthnvpnd.service restart loop as on the raspberry pi. This is a debian Linux x86_64 machine. Tried to start it manually in debug mode (note this one have 3 services).

lethe@us01:~/lethean-vpn$ /opt/lthn/bin/lthnvpnd -l DEBUG
INFO:audit:type=SERVICE,obj=lthnvpnd,action=START,
DEBUG:lthnvpnd:Setting service 1A parameter max_connections to default (2000)
DEBUG:lthnvpnd:Setting service 1A parameter backend_proxy_server to 127.0.0.1:3128
DEBUG:lthnvpnd:Setting service 1A parameter bind_addr to default (0.0.0.0)
DEBUG:lthnvpnd:Setting service 1A parameter max_conns_per_ip to default (10000)
DEBUG:lthnvpnd:Setting service 1A parameter crtkey to /opt/lthn/etc/ca/certs/ha.both.pem
DEBUG:lthnvpnd:Setting service 1A parameter timeout to default (30s)
DEBUG:lthnvpnd:Setting service 1A parameter dispatcher_http_port to default (8188)
DEBUG:lthnvpnd:Setting service 1A parameter conns_period to default (10s)
DEBUG:lthnvpnd:Setting service 1A parameter uniqueid to default (abcd1234)
DEBUG:lthnvpnd:Setting service 1A parameter connect_timeout to default (5s)
DEBUG:lthnvpnd:Setting service 1A parameter track_sessions to default (True)
DEBUG:lthnvpnd:Setting service 1A parameter paymentid to default (authid1)
DEBUG:lthnvpnd:Setting service 1A parameter max_requests_per_period to default (10000)
DEBUG:lthnvpnd:Setting service 1A parameter max_conns_per_period to default (10000)
DEBUG:lthnvpnd:Setting service 1A parameter crt to /opt/lthn/etc/ca/certs/ha.cert.pem
DEBUG:lthnvpnd:Setting service 1A parameter dispatcher_http_host to default (127.0.0.1)
DEBUG:lthnvpnd:Setting service 1A parameter status_port to default (8181)
DEBUG:lthnvpnd:Setting service 1A parameter name to FREEDOM
DEBUG:lthnvpnd:Setting service 1A parameter key to /opt/lthn/etc/ca/private/ha.key.pem
WARNING:lthnvpnd:Unknown parameter enabled for service 1A
DEBUG:lthnvpnd:Setting service 1B parameter max_connections to default (2000)
DEBUG:lthnvpnd:Setting service 1B parameter backend_proxy_server to 127.0.0.1:3628
DEBUG:lthnvpnd:Setting service 1B parameter bind_addr to default (0.0.0.0)
DEBUG:lthnvpnd:Setting service 1B parameter max_conns_per_ip to default (10000)
DEBUG:lthnvpnd:Setting service 1B parameter crtkey to /opt/lthn/etc/ca/certs/ha.both.pem
DEBUG:lthnvpnd:Setting service 1B parameter timeout to default (30s)
DEBUG:lthnvpnd:Setting service 1B parameter dispatcher_http_port to default (8188)
DEBUG:lthnvpnd:Setting service 1B parameter conns_period to default (10s)
DEBUG:lthnvpnd:Setting service 1B parameter uniqueid to default (abcd1234)
DEBUG:lthnvpnd:Setting service 1B parameter connect_timeout to default (5s)
DEBUG:lthnvpnd:Setting service 1B parameter track_sessions to default (True)
DEBUG:lthnvpnd:Setting service 1B parameter paymentid to default (authid1)
DEBUG:lthnvpnd:Setting service 1B parameter max_requests_per_period to default (10000)
DEBUG:lthnvpnd:Setting service 1B parameter max_conns_per_period to default (10000)
DEBUG:lthnvpnd:Setting service 1B parameter crt to /opt/lthn/etc/ca/certs/ha.cert.pem
DEBUG:lthnvpnd:Setting service 1B parameter dispatcher_http_host to default (127.0.0.1)
DEBUG:lthnvpnd:Setting service 1B parameter status_port to default (8181)
DEBUG:lthnvpnd:Setting service 1B parameter name to SAFE
DEBUG:lthnvpnd:Setting service 1B parameter key to /opt/lthn/etc/ca/private/ha.key.pem
WARNING:lthnvpnd:Unknown parameter enabled for service 1B
DEBUG:lthnvpnd:Setting service 1C parameter max_connections to default (2000)
DEBUG:lthnvpnd:Setting service 1C parameter backend_proxy_server to 127.0.0.1:3828
DEBUG:lthnvpnd:Setting service 1C parameter bind_addr to default (0.0.0.0)
DEBUG:lthnvpnd:Setting service 1C parameter max_conns_per_ip to default (10000)
DEBUG:lthnvpnd:Setting service 1C parameter crtkey to /opt/lthn/etc/ca/certs/ha.both.pem
DEBUG:lthnvpnd:Setting service 1C parameter timeout to default (30s)
DEBUG:lthnvpnd:Setting service 1C parameter dispatcher_http_port to default (8188)
DEBUG:lthnvpnd:Setting service 1C parameter conns_period to default (10s)
DEBUG:lthnvpnd:Setting service 1C parameter uniqueid to default (abcd1234)
DEBUG:lthnvpnd:Setting service 1C parameter connect_timeout to default (5s)
DEBUG:lthnvpnd:Setting service 1C parameter track_sessions to default (True)
DEBUG:lthnvpnd:Setting service 1C parameter paymentid to default (authid1)
DEBUG:lthnvpnd:Setting service 1C parameter max_requests_per_period to default (10000)
DEBUG:lthnvpnd:Setting service 1C parameter max_conns_per_period to default (10000)
DEBUG:lthnvpnd:Setting service 1C parameter crt to /opt/lthn/etc/ca/certs/ha.cert.pem
DEBUG:lthnvpnd:Setting service 1C parameter dispatcher_http_host to default (127.0.0.1)
DEBUG:lthnvpnd:Setting service 1C parameter status_port to default (8181)
DEBUG:lthnvpnd:Setting service 1C parameter name to SAFEST
DEBUG:lthnvpnd:Setting service 1C parameter key to /opt/lthn/etc/ca/private/ha.key.pem
WARNING:lthnvpnd:Unknown parameter enabled for service 1C
DEBUG:lthnvpnd:Setting service SS parameter enabled to default (True)
DEBUG:lthnvpnd:Setting service MS parameter enabled to default (True)
DEBUG:lthnvpnd:Setting service HS parameter name to default (HTTP status)
DEBUG:lthnvpnd:Setting service HS parameter port to default (8188)
DEBUG:lthnvpnd:Setting service HS parameter bind_addr to default (127.0.0.1)
INFO:lthnvpnd:Service SAFEST no adult, malware and ads (proxy), id 1C
INFO:lthnvpnd:Service SAFE no malware and ads (proxy), id 1B
INFO:lthnvpnd:Service FREEDOM no cencorship (proxy), id 1A
INFO:lthnvpnd:Starting service Syslog server[SS]
INFO:lthnvpnd:Starting service Management server[MS]
INFO:lthnvpnd:Starting service HTTP server[HS]
INFO:lthnvpnd:Created haproxy config file /opt/lthn/var/proxy_1C/cfg
INFO:audit:type=SERVICE,serviceid=1C,action=START,cmd='/usr/sbin/haproxy -Ds -p /opt/lthn/var/proxy_1C/pid -f /opt/lthn/var/proxy_1C/cfg',
INFO:lthnvpnd:Waiting for pid
INFO:lthnvpnd:Service 1C: [pid=None]
INFO:lthnvpnd:Starting service SAFEST no adult, malware and ads[1C]
INFO:lthnvpnd:Created haproxy config file /opt/lthn/var/proxy_1B/cfg
INFO:audit:type=SERVICE,serviceid=1B,action=START,cmd='/usr/sbin/haproxy -Ds -p /opt/lthn/var/proxy_1B/pid -f /opt/lthn/var/proxy_1B/cfg',
INFO:lthnvpnd:Waiting for pid
INFO:lthnvpnd:Service 1B: [pid=None]
INFO:lthnvpnd:Starting service SAFE no malware and ads[1B]
INFO:lthnvpnd:Created haproxy config file /opt/lthn/var/proxy_1A/cfg
INFO:audit:type=SERVICE,serviceid=1A,action=START,cmd='/usr/sbin/haproxy -Ds -p /opt/lthn/var/proxy_1A/pid -f /opt/lthn/var/proxy_1A/cfg',
INFO:lthnvpnd:Waiting for pid
INFO:lthnvpnd:Service 1A: [pid=None]
INFO:lthnvpnd:Starting service FREEDOM no cencorship[1A]
DEBUG:lthnvpnd:Calling wallet RPC http://127.0.0.1:14660/json_rpc
DEBUG:lthnvpnd:Calling wallet RPC http://127.0.0.1:14660/json_rpc
INFO:lthnvpnd:No new payments in wallet
DEBUG:lthnvpnd:syslog: 'Proxy ssltunnel started.\n'
DEBUG:lthnvpnd:syslog: 'Proxy ssltunnel started.\n'
DEBUG:lthnvpnd:syslog: 'Proxy ssltunnel started.\n'
DEBUG:lthnvpnd:Spawning new http process with pid 31300
Traceback (most recent call last):
  File "/opt/lthn/bin/lthnvpnd", line 176, in <module>
    main(sys.argv[1:])
  File "/opt/lthn/bin/lthnvpnd", line 144, in main
    services.SERVICES.orchestrate()
  File "/opt/lthn/lib/services.py", line 104, in orchestrate
    o = s.orchestrate()
  File "/opt/lthn/lib/service_ha.py", line 118, in orchestrate
    return(self.isAlive())
  File "/opt/lthn/lib/service_ha.py", line 83, in isAlive
    os.kill(self.pid, 0)
TypeError: an integer is required (got type NoneType)
Error in atexit._run_exitfuncs:
Traceback (most recent call last):
  File "/opt/lthn/lib/service_ha.py", line 83, in isAlive
    os.kill(self.pid, 0)
TypeError: an integer is required (got type NoneType)
INFO:lthnvpnd:Stopped service HTTP server[HS]
lethe@us01:~/lethean-vpn$
ronnylov commented 5 years ago

Got same error when using easy-deploy-node.sh on ubuntu 16.04. So I have tried 3 different machines both upgrade and fresh install. I don't know how to get around this.

ronnylov commented 5 years ago

Tested https://github.com/LetheanMovement/lethean-vpn/commit/9139a81594cd8949ade32efbdcce1f6f5d1a7881

And it works now on the Raspberry Pi! Thanks for your qick solution of this problem!

valiant1x commented 5 years ago

fixed in #66