search

haugene / docker-transmission-openvpn

Docker container running Transmission torrent client with WebUI over an OpenVPN tunnel
GNU General Public License v3.0
4.13k stars 1.21k forks source link

ERROR, unable to obtain tunnel address #1260

Closed zachg99 closed 4 years ago

zachg99 commented 4 years ago

Describe the problem When attempting to launch the container the container keeps restarting with the error: ERROR, unable to obtain tunnel address.

This container used to work great. I actually hadn't used it for about a week so shut it down. Recently I had reason to use it and I updated the image to the latest cleared the container then went to run it it just keeps restarting with the above error.

Here are my two images, old one that used to work (haven't figured out how to revert to that just yet) and latest created 5 days ago:

REPOSITORY TAG IMAGE ID CREATED SIZE haugene/transmission-openvpn latest 9e98b1502bd6 9 days ago 416MB haugene/transmission-openvpn 34e9c84b8f29 5 weeks ago 332MB

Add your docker run command (I blanked out the username/password) docker run --name=transmission-openvpn --hostname=transmission-openvpn --env=PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin --env=DEBIAN_FRONTEND=noninteractive --env=OPENVPN_USERNAME=* --env=OPENVPN_PASSWORD= --env=OPENVPN_PROVIDER=PUREVPN --env=GLOBAL_APPLY_PERMISSIONS=true --env=TRANSMISSION_ALT_SPEED_DOWN=50 --env=TRANSMISSION_ALT_SPEED_ENABLED=false --env=TRANSMISSION_ALT_SPEED_TIME_BEGIN=540 --env=TRANSMISSION_ALT_SPEED_TIME_DAY=127 --env=TRANSMISSION_ALT_SPEED_TIME_ENABLED=false --env=TRANSMISSION_ALT_SPEED_TIME_END=1020 --env=TRANSMISSION_ALT_SPEED_UP=50 --env=TRANSMISSION_BIND_ADDRESS_IPV4=0.0.0.0 --env=TRANSMISSION_BIND_ADDRESS_IPV6=:: --env=TRANSMISSION_BLOCKLIST_ENABLED=false --env=TRANSMISSION_BLOCKLIST_URL=http://www.example.com/blocklist --env=TRANSMISSION_CACHE_SIZE_MB=4 --env=TRANSMISSION_DHT_ENABLED=true --env=TRANSMISSION_DOWNLOAD_DIR=/data/completed --env=TRANSMISSION_DOWNLOAD_LIMIT=100 --env=TRANSMISSION_DOWNLOAD_LIMIT_ENABLED=0 --env=TRANSMISSION_DOWNLOAD_QUEUE_ENABLED=true --env=TRANSMISSION_DOWNLOAD_QUEUE_SIZE=5 --env=TRANSMISSION_ENCRYPTION=1 --env=TRANSMISSION_IDLE_SEEDING_LIMIT=30 --env=TRANSMISSION_IDLE_SEEDING_LIMIT_ENABLED=false --env=TRANSMISSION_INCOMPLETE_DIR=/data/incomplete --env=TRANSMISSION_INCOMPLETE_DIR_ENABLED=true --env=TRANSMISSION_LPD_ENABLED=false --env=TRANSMISSION_MAX_PEERS_GLOBAL=200 --env=TRANSMISSION_MESSAGE_LEVEL=2 --env=TRANSMISSION_PEER_CONGESTION_ALGORITHM= --env=TRANSMISSION_PEER_ID_TTL_HOURS=6 --env=TRANSMISSION_PEER_LIMIT_GLOBAL=200 --env=TRANSMISSION_PEER_LIMIT_PER_TORRENT=50 --env=TRANSMISSION_PEER_PORT=51413 --env=TRANSMISSION_PEER_PORT_RANDOM_HIGH=65535 --env=TRANSMISSION_PEER_PORT_RANDOM_LOW=49152 --env=TRANSMISSION_PEER_PORT_RANDOM_ON_START=false --env=TRANSMISSION_PEER_SOCKET_TOS=default --env=TRANSMISSION_PEX_ENABLED=true --env=TRANSMISSION_PORT_FORWARDING_ENABLED=false --env=TRANSMISSION_PREALLOCATION=1 --env=TRANSMISSION_PREFETCH_ENABLED=1 --env=TRANSMISSION_QUEUE_STALLED_ENABLED=true --env=TRANSMISSION_QUEUE_STALLED_MINUTES=30 --env=TRANSMISSION_RATIO_LIMIT=2 --env=TRANSMISSION_RATIO_LIMIT_ENABLED=false --env=TRANSMISSION_RENAME_PARTIAL_FILES=true --env=TRANSMISSION_RPC_AUTHENTICATION_REQUIRED=false --env=TRANSMISSION_RPC_BIND_ADDRESS=0.0.0.0 --env=TRANSMISSION_RPC_ENABLED=true --env=TRANSMISSION_RPC_HOST_WHITELIST= --env=TRANSMISSION_RPC_HOST_WHITELIST_ENABLED=false --env=TRANSMISSION_RPC_PASSWORD=password --env=TRANSMISSION_RPC_PORT=9091 --env=TRANSMISSION_RPC_URL=/transmission/ --env=TRANSMISSION_RPC_USERNAME=username --env=TRANSMISSION_RPC_WHITELIST=127.0.0.1 --env=TRANSMISSION_RPC_WHITELIST_ENABLED=false --env=TRANSMISSION_SCRAPE_PAUSED_TORRENTS_ENABLED=true --env=TRANSMISSION_SCRIPT_TORRENT_DONE_ENABLED=false --env=TRANSMISSION_SCRIPT_TORRENT_DONE_FILENAME= --env=TRANSMISSION_SEED_QUEUE_ENABLED=false --env=TRANSMISSION_SEED_QUEUE_SIZE=10 --env=TRANSMISSION_SPEED_LIMIT_DOWN=100 --env=TRANSMISSION_SPEED_LIMIT_DOWN_ENABLED=false --env=TRANSMISSION_SPEED_LIMIT_UP=100 --env=TRANSMISSION_SPEED_LIMIT_UP_ENABLED=false --env=TRANSMISSION_START_ADDED_TORRENTS=true --env=TRANSMISSION_TRASH_ORIGINAL_TORRENT_FILES=false --env=TRANSMISSION_UMASK=2 --env=TRANSMISSION_UPLOAD_LIMIT=100 --env=TRANSMISSION_UPLOAD_LIMIT_ENABLED=0 --env=TRANSMISSION_UPLOAD_SLOTS_PER_TORRENT=14 --env=TRANSMISSION_UTP_ENABLED=true --env=TRANSMISSION_WATCH_DIR=/data/watch --env=TRANSMISSION_WATCH_DIR_ENABLED=true --env=TRANSMISSION_HOME=/data/transmission-home --env=TRANSMISSION_WATCH_DIR_FORCE_GENERIC=false --env=ENABLE_UFW=false --env=UFW_ALLOW_GW_NET=false --env=UFW_EXTRA_PORTS= --env=UFW_DISABLE_IPTABLES_REJECT=false --env=TRANSMISSION_WEB_UI=transmission-web-control --env=PUID=1034 --env=PGID=100 --env=TRANSMISSION_WEB_HOME= --env=DROP_DEFAULT_ROUTE= --env=WEBPROXY_ENABLED=false --env=WEBPROXY_PORT=8888 --env=WEBPROXY_USERNAME= --env=WEBPROXY_PASSWORD= --env=HEALTH_CHECK_HOST=google.com --env=DOCKER_LOG=false --env=--cap-add=NET_ADMIN --env='--device=/dev/net/tun -d \' --env='OPENVPN_OPTS=--inactive 3600 --ping 10 --ping-exit 60' --env=LOCAL_NETWORK=192.168.2.0/24 --volume=/volume1/docker/transmission/config/resolv.conf:/etc/resolv.conf:rw --volume=/volume1/docker/transmission/data:/data:rw --volume=/volume1/docker/transmission/config:/config:rw --volume=/config --volume=/data --network=bridge --privileged -p 0.0.0.0:8888:8888 -p 0.0.0.0:9091:9091 --restart=always --log-driver=db --detach=true -t haugene/transmission-openvpn:latest dumb-init /etc/openvpn/start.sh

Logs

Sat Jun 20 22:40:47 2020 TUN/TAP device tun0 opened

Sat Jun 20 22:40:47 2020 TUN/TAP TX queue length set to 100 Sat Jun 20 22:40:47 2020 /etc/openvpn/tunnelUp.sh tun0 1500 1555   init Up script executed with tun0 1500 1555   init ERROR, unable to obtain tunnel address killing 18 Sat Jun 20 22:40:47 2020 WARNING: Failed running command (--up/--down): external program did not exit normally Sat Jun 20 22:40:47 2020 Exiting due to fatal error

Host system: Docker on Synology Nas DS918+ Docker version 18.09.8, build bfed4f5

zachg99 commented 4 years ago

FYI, i figured out how to use the tag option to switch between images the container uses. I switched images, did a clear, and tried yet am getting the same error.

madcowGit commented 4 years ago

I have the exact same issue. I was running an old version of the image (can't remember which one though) and got the exact same issue. I update the image to the most recent one, but the issue remains.

I am also

zachg99 commented 4 years ago

Hm, I wonder if it's an issue with PureVPN. It's hard for me to troubleshoot as the container keeps restarting.

zachg99 commented 4 years ago

Ok, the issue is with PureVPN. Add a configuration option to change the default openvpn configuration. The default points to norway, point it somewhere else. For example add this to environmental variables:

OPENVPN_CONFIG=de2-ovpn-tcp

To change from Norway to Germany and suddenly the connection works.

pkishino commented 4 years ago

the default is just a default, depending on vpn provider these might or might not work properly over time.. I recommend not using default and actually check which server works best for you

madcowGit commented 4 years ago

I confirm, changing the openvpn_config worked for me as well

canzone commented 4 years ago

Hello, I know this issue was closed, but I'm having exactly the same issue and could not solve it by changing OPENVPN_CONFIG. I also tried downloading new config files from PureVPN and updating the ones in the /etc/openvpn/purevpn directory, with no success. I've pulled the newest image version. Any ideas on how to solve this? Thanks.

zachg99 commented 4 years ago

What I did was to run the ping test in the MacOS client to find locations that had good pings from my location. Then I went through the purevpn folder and tried them in the OPENVPN_CONFIG env setting. Basically you're looking for a location that lets you connect. I'm not sure if it was an issue with the Norway servers or with the network between me and them but by switching to a different server I was able to find one that worked.

I think you should only choose from the TCP files but I'm not clear on that subject.

madcowGit commented 4 years ago

which alternative server did you try? Did you try de2-ovpn-tcp? that worked for me right away. I did not test any of the other servers actually

pkishino commented 4 years ago

For torrenting usually udp is better than tcp

On Sat, Jun 27, 2020 at 2:12 madcowGit notifications@github.com wrote:

which alternative server did you try? Did you try de2-ovpn-tcp? that worked for me right away. I did not test any of the other servers actually

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/haugene/docker-transmission-openvpn/issues/1260#issuecomment-650293825, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA7OFYWGNVIZWVH2ZJSG65LRYTJGNANCNFSM4OD4EF5Q .

zachg99 commented 4 years ago

Oh sweet, thanks for the info!

canzone commented 4 years ago

Hi Everyone. Thanks for the insights! I've tried de2-ovpn-tcp, de2-ovpn-udp, es2-ovpn-udp (one that I usually use and works fine and really fast in my Macbook). None worked. Also tried to update the config files for all these locations, downloading those from PureVPN website, and it did not work as well. Any debugging ideas? Logs don't give much information to dig into.

madcowGit commented 4 years ago

I actually have 2 containers. When 1 works fine on the de2-ovpn-tcp the other seemed to fail. Then I rebooted and the other container failed, whilst the first one connected just fine. I guess it's just a matter of finding a stable server

canzone commented 4 years ago

Hi, I dug a little bit more. Maybe the info here helps to identify what is happening. This worked flawlessly for a long, long time, until last week, when it suddenly stopped working.

I'm running docker in a Synology system. Downloaded the latest container version.

TUN seems to be alright, as lsmod returns: tun 18784 0

By inspecting the container I cannot find any issue: [ { "Id": "c659e4bf43cc3fe6e095c176258fd0054f09ce8c8b4aeaa64f505070aef75850", "Created": "2020-06-29T18:44:59.953057275Z", "Path": "dumb-init", "Args": [ "/etc/openvpn/start.sh" ], "State": { "Status": "exited", "Running": false, "Paused": false, "Restarting": false, "OOMKilled": false, "Dead": false, "Pid": 0, "ExitCode": 1, "Error": "", "StartedAt": "2020-06-29T18:45:03.626157624Z", "FinishedAt": "2020-06-29T18:45:06.452405847Z", "Health": { "Status": "unhealthy", "FailingStreak": 0, "Log": [] }, "StartedTs": 1593456303, "FinishedTs": 1593456306 }, "Image": "sha256:9e98b1502bd6220fac60f86c072f25b7172f2c719e6c425a418a542e352742e1", "ResolvConfPath": "/volume1/@docker/containers/c659e4bf43cc3fe6e095c176258fd0054f09ce8c8b4aeaa64f505070aef75850/resolv.conf", "HostnamePath": "/volume1/@docker/containers/c659e4bf43cc3fe6e095c176258fd0054f09ce8c8b4aeaa64f505070aef75850/hostname", "HostsPath": "/volume1/@docker/containers/c659e4bf43cc3fe6e095c176258fd0054f09ce8c8b4aeaa64f505070aef75850/hosts", "LogPath": "/volume1/@docker/containers/c659e4bf43cc3fe6e095c176258fd0054f09ce8c8b4aeaa64f505070aef75850/log.db", "Name": "/transmission-openvpn-syno", "RestartCount": 0, "Driver": "aufs", "Platform": "linux", "MountLabel": "", "ProcessLabel": "", "AppArmorProfile": "docker-default", "ExecIDs": null, "HostConfig": { "Binds": [ "/volume2/Media/Zoned/incomplete/:/data" ], "ContainerIDFile": "", "LogConfig": { "Type": "db", "Config": {} }, "NetworkMode": "default", "PortBindings": { "9091/tcp": [ { "HostIp": "", "HostPort": "9091" } ] }, "RestartPolicy": { "Name": "no", "MaximumRetryCount": 0 }, "AutoRemove": false, "VolumeDriver": "", "VolumesFrom": null, "CapAdd": [ "NET_ADMIN" ], "CapDrop": null, "Dns": [ "8.8.8.8", "8.8.4.4" ], "DnsOptions": [], "DnsSearch": [], "ExtraHosts": null, "GroupAdd": null, "IpcMode": "shareable", "Cgroup": "", "Links": null, "OomScoreAdj": 0, "PidMode": "", "Privileged": false, "PublishAllPorts": false, "ReadonlyRootfs": false, "SecurityOpt": null, "UTSMode": "", "UsernsMode": "", "ShmSize": 67108864, "Sysctls": { "net.ipv6.conf.all.disable_ipv6": "0" }, "Runtime": "runc", "Env": [ "PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "DEBIAN_FRONTEND=noninteractive", "OPENVPN_USERNAME=******", "OPENVPN_PASSWORD=******", "OPENVPN_PROVIDER=PUREVPN", "GLOBAL_APPLY_PERMISSIONS=true", "TRANSMISSION_ALT_SPEED_DOWN=50", "TRANSMISSION_ALT_SPEED_ENABLED=false", "TRANSMISSION_ALT_SPEED_TIME_BEGIN=540", "TRANSMISSION_ALT_SPEED_TIME_DAY=127", "TRANSMISSION_ALT_SPEED_TIME_ENABLED=false", "TRANSMISSION_ALT_SPEED_TIME_END=1020", "TRANSMISSION_ALT_SPEED_UP=50", "TRANSMISSION_BIND_ADDRESS_IPV4=0.0.0.0", "TRANSMISSION_BIND_ADDRESS_IPV6=::", "TRANSMISSION_BLOCKLIST_ENABLED=false", "TRANSMISSION_BLOCKLIST_URL=http://www.example.com/blocklist", "TRANSMISSION_CACHE_SIZE_MB=4", "TRANSMISSION_DHT_ENABLED=true", "TRANSMISSION_DOWNLOAD_DIR=/data/completed", "TRANSMISSION_DOWNLOAD_LIMIT=100", "TRANSMISSION_DOWNLOAD_LIMIT_ENABLED=0", "TRANSMISSION_DOWNLOAD_QUEUE_ENABLED=true", "TRANSMISSION_DOWNLOAD_QUEUE_SIZE=5", "TRANSMISSION_ENCRYPTION=1", "TRANSMISSION_IDLE_SEEDING_LIMIT=30", "TRANSMISSION_IDLE_SEEDING_LIMIT_ENABLED=false", "TRANSMISSION_INCOMPLETE_DIR=/data/incomplete", "TRANSMISSION_INCOMPLETE_DIR_ENABLED=true", "TRANSMISSION_LPD_ENABLED=false", "TRANSMISSION_MAX_PEERS_GLOBAL=200", "TRANSMISSION_MESSAGE_LEVEL=2", "TRANSMISSION_PEER_CONGESTION_ALGORITHM=", "TRANSMISSION_PEER_ID_TTL_HOURS=6", "TRANSMISSION_PEER_LIMIT_GLOBAL=200", "TRANSMISSION_PEER_LIMIT_PER_TORRENT=50", "TRANSMISSION_PEER_PORT=51413", "TRANSMISSION_PEER_PORT_RANDOM_HIGH=65535", "TRANSMISSION_PEER_PORT_RANDOM_LOW=49152", "TRANSMISSION_PEER_PORT_RANDOM_ON_START=false", "TRANSMISSION_PEER_SOCKET_TOS=default", "TRANSMISSION_PEX_ENABLED=true", "TRANSMISSION_PORT_FORWARDING_ENABLED=false", "TRANSMISSION_PREALLOCATION=1", "TRANSMISSION_PREFETCH_ENABLED=1", "TRANSMISSION_QUEUE_STALLED_ENABLED=true", "TRANSMISSION_QUEUE_STALLED_MINUTES=30", "TRANSMISSION_RATIO_LIMIT=2", "TRANSMISSION_RATIO_LIMIT_ENABLED=false", "TRANSMISSION_RENAME_PARTIAL_FILES=true", "TRANSMISSION_RPC_AUTHENTICATION_REQUIRED=false", "TRANSMISSION_RPC_BIND_ADDRESS=0.0.0.0", "TRANSMISSION_RPC_ENABLED=true", "TRANSMISSION_RPC_HOST_WHITELIST=", "TRANSMISSION_RPC_HOST_WHITELIST_ENABLED=false", "TRANSMISSION_RPC_PASSWORD=password", "TRANSMISSION_RPC_PORT=9091", "TRANSMISSION_RPC_URL=/transmission/", "TRANSMISSION_RPC_USERNAME=username", "TRANSMISSION_RPC_WHITELIST=127.0.0.1", "TRANSMISSION_RPC_WHITELIST_ENABLED=false", "TRANSMISSION_SCRAPE_PAUSED_TORRENTS_ENABLED=true", "TRANSMISSION_SCRIPT_TORRENT_DONE_ENABLED=false", "TRANSMISSION_SCRIPT_TORRENT_DONE_FILENAME=", "TRANSMISSION_SEED_QUEUE_ENABLED=false", "TRANSMISSION_SEED_QUEUE_SIZE=10", "TRANSMISSION_SPEED_LIMIT_DOWN=100", "TRANSMISSION_SPEED_LIMIT_DOWN_ENABLED=false", "TRANSMISSION_SPEED_LIMIT_UP=100", "TRANSMISSION_SPEED_LIMIT_UP_ENABLED=false", "TRANSMISSION_START_ADDED_TORRENTS=true", "TRANSMISSION_TRASH_ORIGINAL_TORRENT_FILES=false", "TRANSMISSION_UMASK=2", "TRANSMISSION_UPLOAD_LIMIT=100", "TRANSMISSION_UPLOAD_LIMIT_ENABLED=0", "TRANSMISSION_UPLOAD_SLOTS_PER_TORRENT=14", "TRANSMISSION_UTP_ENABLED=false", "TRANSMISSION_WATCH_DIR=/data/watch", "TRANSMISSION_WATCH_DIR_ENABLED=true", "TRANSMISSION_HOME=/data/transmission-home", "TRANSMISSION_WATCH_DIR_FORCE_GENERIC=false", "ENABLE_UFW=false", "UFW_ALLOW_GW_NET=false", "UFW_EXTRA_PORTS=", "UFW_DISABLE_IPTABLES_REJECT=false", "TRANSMISSION_WEB_UI=", "PUID=1026", "PGID=100", "TRANSMISSION_WEB_HOME=", "DROP_DEFAULT_ROUTE=", "WEBPROXY_ENABLED=false", "WEBPROXY_PORT=8888", "WEBPROXY_USERNAME=", "WEBPROXY_PASSWORD=", "HEALTH_CHECK_HOST=google.com", "DOCKER_LOG=false", "CREATE_TUN_DEVICE=false", "OPENVPN_CONFIG=de2-ovpn-tcp", "LOCAL_NETWORK=192.168.46.0/24", "OPENVPN_OPTS=--inactive 3600 --ping 10 --ping-exit 60" ], "ConsoleSize": [ 0, 0 ], "Isolation": "", "CpuShares": 0, "Memory": 0, "NanoCpus": 0, "CgroupParent": "", "BlkioWeight": 0, "BlkioWeightDevice": [], "BlkioDeviceReadBps": null, "BlkioDeviceWriteBps": null, "BlkioDeviceReadIOps": null, "BlkioDeviceWriteIOps": null, "CpuPeriod": 0, "CpuQuota": 0, "CpuRealtimePeriod": 0, "CpuRealtimeRuntime": 0, "CpusetCpus": "", "CpusetMems": "", "Devices": [ { "PathOnHost": "/dev/net/tun", "PathInContainer": "/dev/net/tun", "CgroupPermissions": "rwm" } ], "DeviceCgroupRules": null, "DiskQuota": 0, "KernelMemory": 0, "MemoryReservation": 0, "MemorySwap": 0, "MemorySwappiness": null, "OomKillDisable": false, "PidsLimit": 0, "Ulimits": null, "CpuCount": 0, "CpuPercent": 0, "IOMaximumIOps": 0, "IOMaximumBandwidth": 0, "MaskedPaths": [ "/proc/asound", "/proc/acpi", "/proc/kcore", "/proc/keys", "/proc/latency_stats", "/proc/timer_list", "/proc/timer_stats", "/proc/sched_debug", "/proc/scsi", "/sys/firmware" ], "ReadonlyPaths": [ "/proc/bus", "/proc/fs", "/proc/irq", "/proc/sys", "/proc/sysrq-trigger" ] }, "GraphDriver": { "Data": null, "Name": "aufs" }, "Mounts": [ { "Type": "bind", "Source": "/volume2/Media/Zoned/incomplete", "Destination": "/data", "Mode": "", "RW": true, "Propagation": "rprivate" }, { "Type": "volume", "Name": "98e550a1a4a32b6a21039e2a04a4eee3ac9ba3f76e16fdbe15fa75c72a6f05fc", "Source": "/volume1/@docker/volumes/98e550a1a4a32b6a21039e2a04a4eee3ac9ba3f76e16fdbe15fa75c72a6f05fc/_data", "Destination": "/config", "Driver": "local", "Mode": "", "RW": true, "Propagation": "" } ], "Config": { "Hostname": "c659e4bf43cc", "Domainname": "", "User": "", "AttachStdin": false, "AttachStdout": true, "AttachStderr": true, "ExposedPorts": { "8888/tcp": {}, "9091/tcp": {} }, "Tty": false, "OpenStdin": false, "StdinOnce": false, "Env": [ "PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "DEBIAN_FRONTEND=noninteractive", "OPENVPN_USERNAME=******", "OPENVPN_PASSWORD=******", "OPENVPN_PROVIDER=PUREVPN", "GLOBAL_APPLY_PERMISSIONS=true", "TRANSMISSION_ALT_SPEED_DOWN=50", "TRANSMISSION_ALT_SPEED_ENABLED=false", "TRANSMISSION_ALT_SPEED_TIME_BEGIN=540", "TRANSMISSION_ALT_SPEED_TIME_DAY=127", "TRANSMISSION_ALT_SPEED_TIME_ENABLED=false", "TRANSMISSION_ALT_SPEED_TIME_END=1020", "TRANSMISSION_ALT_SPEED_UP=50", "TRANSMISSION_BIND_ADDRESS_IPV4=0.0.0.0", "TRANSMISSION_BIND_ADDRESS_IPV6=::", "TRANSMISSION_BLOCKLIST_ENABLED=false", "TRANSMISSION_BLOCKLIST_URL=http://www.example.com/blocklist", "TRANSMISSION_CACHE_SIZE_MB=4", "TRANSMISSION_DHT_ENABLED=true", "TRANSMISSION_DOWNLOAD_DIR=/data/completed", "TRANSMISSION_DOWNLOAD_LIMIT=100", "TRANSMISSION_DOWNLOAD_LIMIT_ENABLED=0", "TRANSMISSION_DOWNLOAD_QUEUE_ENABLED=true", "TRANSMISSION_DOWNLOAD_QUEUE_SIZE=5", "TRANSMISSION_ENCRYPTION=1", "TRANSMISSION_IDLE_SEEDING_LIMIT=30", "TRANSMISSION_IDLE_SEEDING_LIMIT_ENABLED=false", "TRANSMISSION_INCOMPLETE_DIR=/data/incomplete", "TRANSMISSION_INCOMPLETE_DIR_ENABLED=true", "TRANSMISSION_LPD_ENABLED=false", "TRANSMISSION_MAX_PEERS_GLOBAL=200", "TRANSMISSION_MESSAGE_LEVEL=2", "TRANSMISSION_PEER_CONGESTION_ALGORITHM=", "TRANSMISSION_PEER_ID_TTL_HOURS=6", "TRANSMISSION_PEER_LIMIT_GLOBAL=200", "TRANSMISSION_PEER_LIMIT_PER_TORRENT=50", "TRANSMISSION_PEER_PORT=51413", "TRANSMISSION_PEER_PORT_RANDOM_HIGH=65535", "TRANSMISSION_PEER_PORT_RANDOM_LOW=49152", "TRANSMISSION_PEER_PORT_RANDOM_ON_START=false", "TRANSMISSION_PEER_SOCKET_TOS=default", "TRANSMISSION_PEX_ENABLED=true", "TRANSMISSION_PORT_FORWARDING_ENABLED=false", "TRANSMISSION_PREALLOCATION=1", "TRANSMISSION_PREFETCH_ENABLED=1", "TRANSMISSION_QUEUE_STALLED_ENABLED=true", "TRANSMISSION_QUEUE_STALLED_MINUTES=30", "TRANSMISSION_RATIO_LIMIT=2", "TRANSMISSION_RATIO_LIMIT_ENABLED=false", "TRANSMISSION_RENAME_PARTIAL_FILES=true", "TRANSMISSION_RPC_AUTHENTICATION_REQUIRED=false", "TRANSMISSION_RPC_BIND_ADDRESS=0.0.0.0", "TRANSMISSION_RPC_ENABLED=true", "TRANSMISSION_RPC_HOST_WHITELIST=", "TRANSMISSION_RPC_HOST_WHITELIST_ENABLED=false", "TRANSMISSION_RPC_PASSWORD=password", "TRANSMISSION_RPC_PORT=9091", "TRANSMISSION_RPC_URL=/transmission/", "TRANSMISSION_RPC_USERNAME=username", "TRANSMISSION_RPC_WHITELIST=127.0.0.1", "TRANSMISSION_RPC_WHITELIST_ENABLED=false", "TRANSMISSION_SCRAPE_PAUSED_TORRENTS_ENABLED=true", "TRANSMISSION_SCRIPT_TORRENT_DONE_ENABLED=false", "TRANSMISSION_SCRIPT_TORRENT_DONE_FILENAME=", "TRANSMISSION_SEED_QUEUE_ENABLED=false", "TRANSMISSION_SEED_QUEUE_SIZE=10", "TRANSMISSION_SPEED_LIMIT_DOWN=100", "TRANSMISSION_SPEED_LIMIT_DOWN_ENABLED=false", "TRANSMISSION_SPEED_LIMIT_UP=100", "TRANSMISSION_SPEED_LIMIT_UP_ENABLED=false", "TRANSMISSION_START_ADDED_TORRENTS=true", "TRANSMISSION_TRASH_ORIGINAL_TORRENT_FILES=false", "TRANSMISSION_UMASK=2", "TRANSMISSION_UPLOAD_LIMIT=100", "TRANSMISSION_UPLOAD_LIMIT_ENABLED=0", "TRANSMISSION_UPLOAD_SLOTS_PER_TORRENT=14", "TRANSMISSION_UTP_ENABLED=false", "TRANSMISSION_WATCH_DIR=/data/watch", "TRANSMISSION_WATCH_DIR_ENABLED=true", "TRANSMISSION_HOME=/data/transmission-home", "TRANSMISSION_WATCH_DIR_FORCE_GENERIC=false", "ENABLE_UFW=false", "UFW_ALLOW_GW_NET=false", "UFW_EXTRA_PORTS=", "UFW_DISABLE_IPTABLES_REJECT=false", "TRANSMISSION_WEB_UI=", "PUID=1026", "PGID=100", "TRANSMISSION_WEB_HOME=", "DROP_DEFAULT_ROUTE=", "WEBPROXY_ENABLED=false", "WEBPROXY_PORT=8888", "WEBPROXY_USERNAME=", "WEBPROXY_PASSWORD=", "HEALTH_CHECK_HOST=google.com", "DOCKER_LOG=false", "CREATE_TUN_DEVICE=false", "OPENVPN_CONFIG=de2-ovpn-tcp", "LOCAL_NETWORK=192.168.46.0/24", "OPENVPN_OPTS=--inactive 3600 --ping 10 --ping-exit 60" ], "Cmd": [ "dumb-init", "/etc/openvpn/start.sh" ], "Healthcheck": { "Test": [ "CMD-SHELL", "/etc/scripts/healthcheck.sh" ], "Interval": 300000000000 }, "ArgsEscaped": true, "Image": "haugene/transmission-openvpn:latest", "Volumes": { "/config": {}, "/data": {} }, "WorkingDir": "", "Entrypoint": null, "OnBuild": null, "Labels": {}, "DDSM": false }, "NetworkSettings": { "Bridge": "", "SandboxID": "0dcc42bd55902085f12b94c450c8a9fc108810da67ecc21ccab77c60760a9957", "HairpinMode": false, "LinkLocalIPv6Address": "", "LinkLocalIPv6PrefixLen": 0, "Ports": {}, "SandboxKey": "/var/run/docker/netns/0dcc42bd5590", "SecondaryIPAddresses": null, "SecondaryIPv6Addresses": null, "EndpointID": "", "Gateway": "", "GlobalIPv6Address": "", "GlobalIPv6PrefixLen": 0, "IPAddress": "", "IPPrefixLen": 0, "IPv6Gateway": "", "MacAddress": "", "Networks": { "bridge": { "IPAMConfig": null, "Links": null, "Aliases": null, "NetworkID": "c73028ebb970cb6a83855b52a438fd471e1a9025bc558f71210093fd1db1de18", "EndpointID": "", "Gateway": "", "IPAddress": "", "IPPrefixLen": 0, "IPv6Gateway": "", "GlobalIPv6Address": "", "GlobalIPv6PrefixLen": 0, "MacAddress": "", "DriverOpts": null } } } } ]

And the last log: 2020-06-29T18:45:03.616713198Z Using OpenVPN provider: PUREVPN 2020-06-29T18:45:03.616999774Z Starting OpenVPN using config de2-ovpn-tcp.ovpn 2020-06-29T18:45:03.617039926Z Setting OPENVPN credentials... 2020-06-29T18:45:03.627983842Z adding route to local network 192.168.46.0/24 via 172.17.0.1 dev eth0 2020-06-29T18:45:03.632328444Z Mon Jun 29 18:45:03 2020 OpenVPN 2.4.7 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Sep 5 2019 2020-06-29T18:45:03.632437461Z Mon Jun 29 18:45:03 2020 library versions: OpenSSL 1.1.1c 28 May 2019, LZO 2.10 2020-06-29T18:45:03.632642531Z Mon Jun 29 18:45:03 2020 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts 2020-06-29T18:45:03.633209621Z Mon Jun 29 18:45:03 2020 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication 2020-06-29T18:45:03.633266684Z Mon Jun 29 18:45:03 2020 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication 2020-06-29T18:45:03.673876628Z Mon Jun 29 18:45:03 2020 TCP/UDP: Preserving recently used remote address: [AF_INET]172.94.11.4:80 2020-06-29T18:45:03.673966260Z Mon Jun 29 18:45:03 2020 Socket Buffers: R=[87380->87380] S=[16384->16384] 2020-06-29T18:45:03.674028401Z Mon Jun 29 18:45:03 2020 Attempting to establish TCP connection with [AF_INET]172.94.11.4:80 [nonblock] 2020-06-29T18:45:04.674088549Z Mon Jun 29 18:45:04 2020 TCP connection established with [AF_INET]172.94.11.4:80 2020-06-29T18:45:04.674178355Z Mon Jun 29 18:45:04 2020 TCP_CLIENT link local: (not bound) 2020-06-29T18:45:04.674207947Z Mon Jun 29 18:45:04 2020 TCP_CLIENT link remote: [AF_INET]172.94.11.4:80 2020-06-29T18:45:04.719127592Z Mon Jun 29 18:45:04 2020 TLS: Initial packet from [AF_INET]172.94.11.4:80, sid=5d73a74a 83d6dd2b 2020-06-29T18:45:04.893849689Z Mon Jun 29 18:45:04 2020 VERIFY OK: depth=1, C=HK, ST=Central, L=HK, O=Secure-ServerCA, OU=IT, CN=Secure-ServerCA, name=Secure-ServerCA, emailAddress=mail@host.domain 2020-06-29T18:45:04.894006529Z Mon Jun 29 18:45:04 2020 VERIFY KU OK 2020-06-29T18:45:04.894040269Z Mon Jun 29 18:45:04 2020 Validating certificate extended key usage 2020-06-29T18:45:04.894062187Z Mon Jun 29 18:45:04 2020 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication 2020-06-29T18:45:04.894084690Z Mon Jun 29 18:45:04 2020 VERIFY EKU OK 2020-06-29T18:45:04.894099897Z Mon Jun 29 18:45:04 2020 VERIFY OK: depth=0, C=HK, ST=Central, L=HK, O=Secure-Server, OU=IT, CN=Secure-Server, name=changeme, emailAddress=mail@host.domain 2020-06-29T18:45:05.110033866Z Mon Jun 29 18:45:05 2020 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1560', remote='link-mtu 1552' 2020-06-29T18:45:05.110119513Z Mon Jun 29 18:45:05 2020 WARNING: 'cipher' is used inconsistently, local='cipher AES-256-CBC', remote='cipher AES-256-GCM' 2020-06-29T18:45:05.110147326Z Mon Jun 29 18:45:05 2020 WARNING: 'auth' is used inconsistently, local='auth SHA1', remote='auth [null-digest]' 2020-06-29T18:45:05.110200220Z Mon Jun 29 18:45:05 2020 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA 2020-06-29T18:45:05.110252086Z Mon Jun 29 18:45:05 2020 [Secure-Server] Peer Connection Initiated with [AF_INET]172.94.11.4:80 2020-06-29T18:45:06.303977106Z Mon Jun 29 18:45:06 2020 SENT CONTROL [Secure-Server]: 'PUSH_REQUEST' (status=1) 2020-06-29T18:45:06.432045108Z Mon Jun 29 18:45:06 2020 PUSH: Received control message: 'PUSH_REPLY,redirect-gateway def1,dhcp-option DNS 172.94.11.3,dhcp-option DNS 172.94.11.5,sndbuf 393216,rcvbuf 393216,comp-lzo no,route-gateway 172.94.11.65,topology subnet,ping 10,ping-restart 120,peer-id 0,cipher AES-256-GCM' 2020-06-29T18:45:06.432253970Z Mon Jun 29 18:45:06 2020 OPTIONS IMPORT: timers and/or timeouts modified 2020-06-29T18:45:06.432298844Z Mon Jun 29 18:45:06 2020 OPTIONS IMPORT: compression parms modified 2020-06-29T18:45:06.432325323Z Mon Jun 29 18:45:06 2020 OPTIONS IMPORT: --sndbuf/--rcvbuf options modified 2020-06-29T18:45:06.432345143Z Mon Jun 29 18:45:06 2020 Socket Buffers: R=[87380->425984] S=[22600->425984] 2020-06-29T18:45:06.432370498Z Mon Jun 29 18:45:06 2020 OPTIONS IMPORT: --ifconfig/up options modified 2020-06-29T18:45:06.432390189Z Mon Jun 29 18:45:06 2020 OPTIONS IMPORT: route options modified 2020-06-29T18:45:06.432407485Z Mon Jun 29 18:45:06 2020 OPTIONS IMPORT: route-related options modified 2020-06-29T18:45:06.432424884Z Mon Jun 29 18:45:06 2020 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified 2020-06-29T18:45:06.432443137Z Mon Jun 29 18:45:06 2020 OPTIONS IMPORT: peer-id set 2020-06-29T18:45:06.432459618Z Mon Jun 29 18:45:06 2020 OPTIONS IMPORT: adjusting link_mtu to 1627 2020-06-29T18:45:06.432477762Z Mon Jun 29 18:45:06 2020 OPTIONS IMPORT: data channel crypto options modified 2020-06-29T18:45:06.432496220Z Mon Jun 29 18:45:06 2020 Data Channel: using negotiated cipher 'AES-256-GCM' 2020-06-29T18:45:06.432552025Z Mon Jun 29 18:45:06 2020 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key 2020-06-29T18:45:06.432585646Z Mon Jun 29 18:45:06 2020 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key 2020-06-29T18:45:06.432604630Z Mon Jun 29 18:45:06 2020 ROUTE_GATEWAY 172.17.0.1/255.255.0.0 IFACE=eth0 HWADDR=02:42:ac:11:00:02 2020-06-29T18:45:06.432866727Z Mon Jun 29 18:45:06 2020 TUN/TAP device tun0 opened 2020-06-29T18:45:06.432915345Z Mon Jun 29 18:45:06 2020 TUN/TAP TX queue length set to 100 2020-06-29T18:45:06.432971795Z Mon Jun 29 18:45:06 2020 /etc/openvpn/tunnelUp.sh tun0 1500 1555 init 2020-06-29T18:45:06.435905445Z Up script executed with tun0 1500 1555 init 2020-06-29T18:45:06.435983107Z ERROR, unable to obtain tunnel address 2020-06-29T18:45:06.436022125Z killing 19 2020-06-29T18:45:06.436214585Z Mon Jun 29 18:45:06 2020 WARNING: Failed running command (--up/--down): external program did not exit normally 2020-06-29T18:45:06.436272860Z Mon Jun 29 18:45:06 2020 Exiting due to fatal error

Any ideas on how I can find what is wrong?

Thanks a lot!

canzone commented 4 years ago

Hello Everyone,

I've changed the OVPN verbosity to its max (verb 11) in order to get extra info (below). This error started just after the PureVPN files were updated.

In time: I'm running Docker 18.09.0.0513 in a Synology NAS.

 Using OpenVPN provider: PUREVPN
 Starting OpenVPN using config pl2-ovpn-udp.ovpn
 Setting OPENVPN credentials...
 adding route to local network 192.168.46.0/24 via 172.17.0.1 dev eth0
 Tue Jun 30 15:38:04 2020 us=218022 Current Parameter Settings:
 Tue Jun 30 15:38:04 2020 us=218117   config = '/etc/openvpn/purevpn/pl2-ovpn-udp.ovpn'
 Tue Jun 30 15:38:04 2020 us=218137   mode = 0
 Tue Jun 30 15:38:04 2020 us=218147   persist_config = DISABLED
 Tue Jun 30 15:38:04 2020 us=218161   persist_mode = 1
 Tue Jun 30 15:38:04 2020 us=218168   show_ciphers = DISABLED
 Tue Jun 30 15:38:04 2020 us=218175   show_digests = DISABLED
 Tue Jun 30 15:38:04 2020 us=218182   show_engines = DISABLED
 Tue Jun 30 15:38:04 2020 us=218189   genkey = DISABLED
 Tue Jun 30 15:38:04 2020 us=218196   key_pass_file = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218203   show_tls_ciphers = DISABLED
 Tue Jun 30 15:38:04 2020 us=218218   connect_retry_max = 3
 Tue Jun 30 15:38:04 2020 us=218225 Connection profiles [0]:
 Tue Jun 30 15:38:04 2020 us=218232   proto = udp
 Tue Jun 30 15:38:04 2020 us=218239   local = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218246   local_port = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218253   remote = 'pl2-ovpn.pointtoserver.com'
 Tue Jun 30 15:38:04 2020 us=218260   remote_port = '53'
 Tue Jun 30 15:38:04 2020 us=218267   remote_float = DISABLED
 Tue Jun 30 15:38:04 2020 us=218274   bind_defined = DISABLED
 Tue Jun 30 15:38:04 2020 us=218284   bind_local = DISABLED
 Tue Jun 30 15:38:04 2020 us=218292   bind_ipv6_only = DISABLED
 Tue Jun 30 15:38:04 2020 us=218298   connect_retry_seconds = 3
 Tue Jun 30 15:38:04 2020 us=218305   connect_timeout = 120
 Tue Jun 30 15:38:04 2020 us=218320   socks_proxy_server = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218327   socks_proxy_port = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218334   tun_mtu = 1500
 Tue Jun 30 15:38:04 2020 us=218342   tun_mtu_defined = ENABLED
 Tue Jun 30 15:38:04 2020 us=218349   link_mtu = 1500
 Tue Jun 30 15:38:04 2020 us=218361   link_mtu_defined = DISABLED
 Tue Jun 30 15:38:04 2020 us=218369   tun_mtu_extra = 0
 Tue Jun 30 15:38:04 2020 us=218375   tun_mtu_extra_defined = DISABLED
 Tue Jun 30 15:38:04 2020 us=218383   mtu_discover_type = -1
 Tue Jun 30 15:38:04 2020 us=218389   fragment = 0
 Tue Jun 30 15:38:04 2020 us=218396   mssfix = 1450
 Tue Jun 30 15:38:04 2020 us=218404   explicit_exit_notification = 1
 Tue Jun 30 15:38:04 2020 us=218413 Connection profiles END
 Tue Jun 30 15:38:04 2020 us=218420   remote_random = DISABLED
 Tue Jun 30 15:38:04 2020 us=218431   ipchange = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218438   dev = 'tun'
 Tue Jun 30 15:38:04 2020 us=218445   dev_type = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218451   dev_node = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218458   lladdr = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218465   topology = 1
 Tue Jun 30 15:38:04 2020 us=218472   ifconfig_local = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218479   ifconfig_remote_netmask = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218485   ifconfig_noexec = DISABLED
 Tue Jun 30 15:38:04 2020 us=218492   ifconfig_nowarn = DISABLED
 Tue Jun 30 15:38:04 2020 us=218502   ifconfig_ipv6_local = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218510   ifconfig_ipv6_netbits = 0
 Tue Jun 30 15:38:04 2020 us=218517   ifconfig_ipv6_remote = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218523   shaper = 0
 Tue Jun 30 15:38:04 2020 us=218530   mtu_test = 0
 Tue Jun 30 15:38:04 2020 us=218537   mlock = DISABLED
 Tue Jun 30 15:38:04 2020 us=218544   keepalive_ping = 0
 Tue Jun 30 15:38:04 2020 us=218551   keepalive_timeout = 0
 Tue Jun 30 15:38:04 2020 us=218558   inactivity_timeout = 3600
 Tue Jun 30 15:38:04 2020 us=218565   ping_send_timeout = 10
 Tue Jun 30 15:38:04 2020 us=218575   ping_rec_timeout = 60
 Tue Jun 30 15:38:04 2020 us=218582   ping_rec_timeout_action = 1
 Tue Jun 30 15:38:04 2020 us=218589   ping_timer_remote = DISABLED
 Tue Jun 30 15:38:04 2020 us=218595   remap_sigusr1 = 0
 Tue Jun 30 15:38:04 2020 us=218602   persist_tun = ENABLED
 Tue Jun 30 15:38:04 2020 us=218609   persist_local_ip = DISABLED
 Tue Jun 30 15:38:04 2020 us=218616   persist_remote_ip = DISABLED
 Tue Jun 30 15:38:04 2020 us=218623   persist_key = ENABLED
 Tue Jun 30 15:38:04 2020 us=218629   passtos = DISABLED
 Tue Jun 30 15:38:04 2020 us=218636   resolve_retry_seconds = 15
 Tue Jun 30 15:38:04 2020 us=218646   resolve_in_advance = DISABLED
 Tue Jun 30 15:38:04 2020 us=218654   username = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218660   groupname = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218667   chroot_dir = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218674   cd_dir = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218680   writepid = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218687   up_script = '/etc/openvpn/tunnelUp.sh'
 Tue Jun 30 15:38:04 2020 us=218694   down_script = '/etc/openvpn/tunnelDown.sh'
 Tue Jun 30 15:38:04 2020 us=218701   down_pre = DISABLED
 Tue Jun 30 15:38:04 2020 us=218707   up_restart = DISABLED
 Tue Jun 30 15:38:04 2020 us=218714   up_delay = ENABLED
 Tue Jun 30 15:38:04 2020 us=218740   daemon = DISABLED
 Tue Jun 30 15:38:04 2020 us=218755   inetd = 0
 Tue Jun 30 15:38:04 2020 us=218768   log = DISABLED
 Tue Jun 30 15:38:04 2020 us=218781   suppress_timestamps = DISABLED
 Tue Jun 30 15:38:04 2020 us=218802   machine_readable_output = DISABLED
 Tue Jun 30 15:38:04 2020 us=218819   nice = 0
 Tue Jun 30 15:38:04 2020 us=218832   verbosity = 11
 Tue Jun 30 15:38:04 2020 us=218845   mute = 0
 Tue Jun 30 15:38:04 2020 us=218858   gremlin = 0
 Tue Jun 30 15:38:04 2020 us=218871   status_file = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=218884   status_file_version = 1
 Tue Jun 30 15:38:04 2020 us=218902   status_file_update_freq = 60
 Tue Jun 30 15:38:04 2020 us=218916   occ = ENABLED
 Tue Jun 30 15:38:04 2020 us=218929   rcvbuf = 0
 Tue Jun 30 15:38:04 2020 us=218942   sndbuf = 0
 Tue Jun 30 15:38:04 2020 us=218955   mark = 0
 Tue Jun 30 15:38:04 2020 us=218969   sockflags = 0
 Tue Jun 30 15:38:04 2020 us=218987   fast_io = DISABLED
 Tue Jun 30 15:38:04 2020 us=219000   comp.alg = 2
 Tue Jun 30 15:38:04 2020 us=219013   comp.flags = 1
 Tue Jun 30 15:38:04 2020 us=219027   route_script = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219044   route_default_gateway = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219060   route_default_metric = 0
 Tue Jun 30 15:38:04 2020 us=219069   route_noexec = DISABLED
 Tue Jun 30 15:38:04 2020 us=219080   route_delay = 2
 Tue Jun 30 15:38:04 2020 us=219087   route_delay_window = 30
 Tue Jun 30 15:38:04 2020 us=219094   route_delay_defined = ENABLED
 Tue Jun 30 15:38:04 2020 us=219101   route_nopull = DISABLED
 Tue Jun 30 15:38:04 2020 us=219109   route_gateway_via_dhcp = DISABLED
 Tue Jun 30 15:38:04 2020 us=219116   allow_pull_fqdn = DISABLED
 Tue Jun 30 15:38:04 2020 us=219123   management_addr = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219130   management_port = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219138   management_user_pass = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219145   management_log_history_cache = 250
 Tue Jun 30 15:38:04 2020 us=219157   management_echo_buffer_size = 100
 Tue Jun 30 15:38:04 2020 us=219168   management_write_peer_info_file = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219175   management_client_user = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219182   management_client_group = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219189   management_flags = 0
 Tue Jun 30 15:38:04 2020 us=219197   shared_secret_file = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219206   key_direction = 1
 Tue Jun 30 15:38:04 2020 us=219213   ciphername = 'AES-256-CBC'
 Tue Jun 30 15:38:04 2020 us=219229   ncp_enabled = ENABLED
 Tue Jun 30 15:38:04 2020 us=219248   ncp_ciphers = 'AES-256-GCM:AES-128-GCM'
 Tue Jun 30 15:38:04 2020 us=219257   authname = 'SHA1'
 Tue Jun 30 15:38:04 2020 us=219264   prng_hash = 'SHA1'
 Tue Jun 30 15:38:04 2020 us=219271   prng_nonce_secret_len = 16
 Tue Jun 30 15:38:04 2020 us=219278   keysize = 0
 Tue Jun 30 15:38:04 2020 us=219286   engine = DISABLED
 Tue Jun 30 15:38:04 2020 us=219293   replay = ENABLED
 Tue Jun 30 15:38:04 2020 us=219300   mute_replay_warnings = DISABLED
 Tue Jun 30 15:38:04 2020 us=219308   replay_window = 64
 Tue Jun 30 15:38:04 2020 us=219319   replay_time = 15
 Tue Jun 30 15:38:04 2020 us=219330   packet_id_file = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219338   use_iv = ENABLED
 Tue Jun 30 15:38:04 2020 us=219345   test_crypto = DISABLED
 Tue Jun 30 15:38:04 2020 us=219354   tls_server = DISABLED
 Tue Jun 30 15:38:04 2020 us=219362   tls_client = ENABLED
 Tue Jun 30 15:38:04 2020 us=219369   key_method = 2
 Tue Jun 30 15:38:04 2020 us=219376   ca_file = '[[INLINE]]'
 Tue Jun 30 15:38:04 2020 us=219384   ca_path = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219391   dh_file = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219403   cert_file = '[[INLINE]]'
 Tue Jun 30 15:38:04 2020 us=219410   extra_certs_file = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219417   priv_key_file = '[[INLINE]]'
 Tue Jun 30 15:38:04 2020 us=219425   pkcs12_file = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219433   cipher_list = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219440   cipher_list_tls13 = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219447   tls_cert_profile = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219455   tls_verify = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219462   tls_export_cert = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219473   verify_x509_type = 0
 Tue Jun 30 15:38:04 2020 us=219484   verify_x509_name = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219491   crl_file = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219498   ns_cert_type = 0
 Tue Jun 30 15:38:04 2020 us=219505   remote_cert_ku[i] = 65535
 Tue Jun 30 15:38:04 2020 us=219513   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219520   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219527   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219534   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219541   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219548   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219558   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219570   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219577   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219584   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219592   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219599   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219606   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219613   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219620   remote_cert_ku[i] = 0
 Tue Jun 30 15:38:04 2020 us=219628   remote_cert_eku = 'TLS Web Server Authentication'
 Tue Jun 30 15:38:04 2020 us=219640   ssl_flags = 0
 Tue Jun 30 15:38:04 2020 us=219651   tls_timeout = 2
 Tue Jun 30 15:38:04 2020 us=219658   renegotiate_bytes = -1
 Tue Jun 30 15:38:04 2020 us=219666   renegotiate_packets = 0
 Tue Jun 30 15:38:04 2020 us=219673   renegotiate_seconds = 3600
 Tue Jun 30 15:38:04 2020 us=219680   handshake_window = 60
 Tue Jun 30 15:38:04 2020 us=219688   transition_window = 3600
 Tue Jun 30 15:38:04 2020 us=219695   single_session = DISABLED
 Tue Jun 30 15:38:04 2020 us=219703   push_peer_info = DISABLED
 Tue Jun 30 15:38:04 2020 us=219711   tls_exit = DISABLED
 Tue Jun 30 15:38:04 2020 us=219721   tls_auth_file = '[[INLINE]]'
 Tue Jun 30 15:38:04 2020 us=219733   tls_crypt_file = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=219740   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219747   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219754   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219761   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219768   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219775   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219782   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219814   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219835   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219843   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219850   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219857   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219864   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219871   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219878   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219890   pkcs11_protected_authentication = DISABLED
 Tue Jun 30 15:38:04 2020 us=219901   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219908   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219916   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219923   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219930   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219938   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219945   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219952   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219959   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219966   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219977   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219984   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219992   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=219999   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=220007   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=220014   pkcs11_private_mode = 00000000
 Tue Jun 30 15:38:04 2020 us=220021   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220028   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220035   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220046   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220057   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220064   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220071   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220079   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220087   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220094   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220101   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220108   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220115   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220126   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220136   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220144   pkcs11_cert_private = DISABLED
 Tue Jun 30 15:38:04 2020 us=220151   pkcs11_pin_cache_period = -1
 Tue Jun 30 15:38:04 2020 us=220159   pkcs11_id = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=220175   pkcs11_id_management = DISABLED
 Tue Jun 30 15:38:04 2020 us=220196   server_network = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220216   server_netmask = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220227   server_network_ipv6 = ::
 Tue Jun 30 15:38:04 2020 us=220234   server_netbits_ipv6 = 0
 Tue Jun 30 15:38:04 2020 us=220253   server_bridge_ip = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220262   server_bridge_netmask = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220270   server_bridge_pool_start = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220278   server_bridge_pool_end = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220286   ifconfig_pool_defined = DISABLED
 Tue Jun 30 15:38:04 2020 us=220294   ifconfig_pool_start = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220301   ifconfig_pool_end = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220310   ifconfig_pool_netmask = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220328   ifconfig_pool_persist_filename = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=220336   ifconfig_pool_persist_refresh_freq = 600
 Tue Jun 30 15:38:04 2020 us=220344   ifconfig_ipv6_pool_defined = DISABLED
 Tue Jun 30 15:38:04 2020 us=220352   ifconfig_ipv6_pool_base = ::
 Tue Jun 30 15:38:04 2020 us=220360   ifconfig_ipv6_pool_netbits = 0
 Tue Jun 30 15:38:04 2020 us=220367   n_bcast_buf = 256
 Tue Jun 30 15:38:04 2020 us=220375   tcp_queue_limit = 64
 Tue Jun 30 15:38:04 2020 us=220383   real_hash_size = 256
 Tue Jun 30 15:38:04 2020 us=220390   virtual_hash_size = 256
 Tue Jun 30 15:38:04 2020 us=220397   client_connect_script = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=220406   learn_address_script = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=220414   client_disconnect_script = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=220422   client_config_dir = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=220430   ccd_exclusive = DISABLED
 Tue Jun 30 15:38:04 2020 us=220438   tmp_dir = '/tmp'
 Tue Jun 30 15:38:04 2020 us=220446   push_ifconfig_defined = DISABLED
 Tue Jun 30 15:38:04 2020 us=220454   push_ifconfig_local = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220464   push_ifconfig_remote_netmask = 0.0.0.0
 Tue Jun 30 15:38:04 2020 us=220483   push_ifconfig_ipv6_defined = DISABLED
 Tue Jun 30 15:38:04 2020 us=220491   push_ifconfig_ipv6_local = ::/0
 Tue Jun 30 15:38:04 2020 us=220499   push_ifconfig_ipv6_remote = ::
 Tue Jun 30 15:38:04 2020 us=220507   enable_c2c = DISABLED
 Tue Jun 30 15:38:04 2020 us=220514   duplicate_cn = DISABLED
 Tue Jun 30 15:38:04 2020 us=220521   cf_max = 0
 Tue Jun 30 15:38:04 2020 us=220535   cf_per = 0
 Tue Jun 30 15:38:04 2020 us=220555   max_clients = 1024
 Tue Jun 30 15:38:04 2020 us=220563   max_routes_per_client = 256
 Tue Jun 30 15:38:04 2020 us=220571   auth_user_pass_verify_script = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=220578   auth_user_pass_verify_script_via_file = DISABLED
 Tue Jun 30 15:38:04 2020 us=220585   auth_token_generate = DISABLED
 Tue Jun 30 15:38:04 2020 us=220592   auth_token_lifetime = 0
 Tue Jun 30 15:38:04 2020 us=220599   port_share_host = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=220606   port_share_port = '[UNDEF]'
 Tue Jun 30 15:38:04 2020 us=220614   client = ENABLED
 Tue Jun 30 15:38:04 2020 us=220621   pull = ENABLED
 Tue Jun 30 15:38:04 2020 us=220629   auth_user_pass_file = '/config/openvpn-credentials.txt'
 Tue Jun 30 15:38:04 2020 us=220638 OpenVPN 2.4.7 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Sep  5 2019
 Tue Jun 30 15:38:04 2020 us=220651 library versions: OpenSSL 1.1.1c  28 May 2019, LZO 2.10
 Tue Jun 30 15:38:04 2020 us=221889 PKCS#11: pkcs11_initialize - entered
 Tue Jun 30 15:38:04 2020 us=221983 PKCS#11: pkcs11_initialize - return 0-'CKR_OK'
 Tue Jun 30 15:38:04 2020 us=222031 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
 Tue Jun 30 15:38:04 2020 us=222043 PO_INIT maxevents=4 flags=0x00000002
 Tue Jun 30 15:38:04 2020 us=222609 PRNG init md=SHA1 size=36
 Tue Jun 30 15:38:04 2020 us=222683 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
 Tue Jun 30 15:38:04 2020 us=222695 Outgoing Control Channel Authentication: HMAC KEY: 19438a46 54663cad 975e138f 5bc5af89 c737ad82
 Tue Jun 30 15:38:04 2020 us=222702 Outgoing Control Channel Authentication: HMAC size=20 block_size=20
 Tue Jun 30 15:38:04 2020 us=222711 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication
 Tue Jun 30 15:38:04 2020 us=222720 Incoming Control Channel Authentication: HMAC KEY: 1352379c df74952b 588fb161 a93e13df 9135b2b2
 Tue Jun 30 15:38:04 2020 us=222727 Incoming Control Channel Authentication: HMAC size=20 block_size=20
 Tue Jun 30 15:38:04 2020 us=222734 crypto_adjust_frame_parameters: Adjusting frame parameters for crypto by 28 bytes
 Tue Jun 30 15:38:04 2020 us=222746 LZO compression initializing
 Tue Jun 30 15:38:04 2020 us=222766 TLS: tls_session_init: entry
 Tue Jun 30 15:38:04 2020 us=222781 PID packet_id_init seq_backtrack=64 time_backtrack=15
 Tue Jun 30 15:38:04 2020 us=222823 PID packet_id_init seq_backtrack=64 time_backtrack=15
 Tue Jun 30 15:38:04 2020 us=222843 TLS: tls_session_init: new session object, sid=e5c51a9b ae9eea75
 Tue Jun 30 15:38:04 2020 us=222850 TLS: tls_session_init: entry
 Tue Jun 30 15:38:04 2020 us=222858 PID packet_id_init seq_backtrack=64 time_backtrack=15
 Tue Jun 30 15:38:04 2020 us=222882 PID packet_id_init seq_backtrack=64 time_backtrack=15
 Tue Jun 30 15:38:04 2020 us=222890 TLS: tls_session_init: new session object, sid=d5cff653 95528da5
 Tue Jun 30 15:38:04 2020 us=222898 Control Channel MTU parms [ L:1622 D:1184 EF:66 EB:0 ET:0 EL:3 ]
 Tue Jun 30 15:38:04 2020 us=222937 MTU DYNAMIC mtu=1450, flags=2, 1622 -> 1450
 Tue Jun 30 15:38:04 2020 us=223041 GETADDRINFO flags=0x0901 ai_family=0 ai_socktype=2
 Tue Jun 30 15:38:04 2020 us=336229 PO_WAIT[0,0] fd=4 rev=0x00000001 rwflags=0x0001 arg=0x7f44adb05198 
 Tue Jun 30 15:38:04 2020 us=336265  event_wait returned 1
 Tue Jun 30 15:38:04 2020 us=336322 UDP READ [54] from [AF_INET]5.253.206.251:53: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 sid=103cf4f1 9bf1fd29 tls_hmac=06e835d7 773ffb3f 17184399 8dd45d44 e593f109 pid=[ #1 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ 0 sid=e5c51a9b ae9eea75 ] pid=0 DATA 
 Tue Jun 30 15:38:04 2020 us=336333 TLS: control channel, op=P_CONTROL_HARD_RESET_SERVER_V2, IP=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:04 2020 us=336544 ENCRYPT HMAC: e089ecd2 77f3afec 8765dd2d ec943ae8 870ee37e
 Tue Jun 30 15:38:04 2020 us=336559 ENCRYPT TO: e089ecd2 77f3afec 8765dd2d ec943ae8 870ee37e 00000002 5efb5c5c 28e5c51[more...]
 Tue Jun 30 15:38:04 2020 us=336566 Dedicated ACK -> TCP/UDP
 Tue Jun 30 15:38:04 2020 us=336580 TLS: tls_process: timeout set to 60
 Tue Jun 30 15:38:04 2020 us=336590 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=d5cff653 95528da5, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:04 2020 us=336609 PO_CTL rwflags=0x0003 ev=4 arg=0x7f44adb05198
 Tue Jun 30 15:38:04 2020 us=336618 I/O WAIT T?|T?|SR|SW [1/249371]
 Tue Jun 30 15:38:04 2020 us=336640 I/O WAIT status=0x0002
 Tue Jun 30 15:38:04 2020 us=336661 UDP WRITE [50] to [AF_INET]5.253.206.251:53: P_ACK_V1 kid=0 sid=e5c51a9b ae9eea75 tls_hmac=e089ecd2 77f3afec 8765dd2d ec943ae8 870ee37e pid=[ #2 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ 0 sid=103cf4f1 9bf1fd29 ]
 Tue Jun 30 15:38:04 2020 us=336697 TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=e5c51a9b ae9eea75, stored-sid=103cf4f1 9bf1fd29, stored-ip=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:04 2020 us=336705 TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
 Tue Jun 30 15:38:04 2020 us=336722 ACK reliable_can_send active=0 current=0 : [1]
 Tue Jun 30 15:38:04 2020 us=336754 STATE S_SENT_KEY
 Tue Jun 30 15:38:04 2020 us=336772 ACK mark active outgoing ID 1
 Tue Jun 30 15:38:04 2020 us=336779 Outgoing Ciphertext -> Reliable
 Tue Jun 30 15:38:04 2020 us=336800 ACK reliable_can_send active=1 current=1 : [2] 1
 Tue Jun 30 15:38:04 2020 us=336807 ACK reliable_send ID 1 (size=281 to=2)
 Tue Jun 30 15:38:04 2020 us=336872 ENCRYPT TO: 85eac03f 23bbb371 0295019a 0644bd04 d67c9c78 00000003 5efb5c5c 20e5c51[more...]
 Tue Jun 30 15:38:04 2020 us=336879 Reliable -> TCP/UDP
 Tue Jun 30 15:38:04 2020 us=336893 TLS: tls_process: timeout set to 2
 Tue Jun 30 15:38:04 2020 us=336902 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=d5cff653 95528da5, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:04 2020 us=336912 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:04 2020 us=336920 PO_CTL rwflags=0x0003 ev=4 arg=0x7f44adb05198
 Tue Jun 30 15:38:04 2020 us=336936 PO_WAIT[0,0] fd=4 rev=0x00000004 rwflags=0x0002 arg=0x7f44adb05198 
 Tue Jun 30 15:38:04 2020 us=336944  event_wait returned 1
 Tue Jun 30 15:38:04 2020 us=337009 UDP WRITE [319] to [AF_INET]5.253.206.251:53: P_CONTROL_V1 kid=0 sid=e5c51a9b ae9eea75 tls_hmac=85eac03f 23bbb371 0295019a 0644bd04 d67c9c78 pid=[ #3 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ ] pid=1 DATA 16030101 10010001 0c03034d 3cbc3d97 2c4de7e7 cc279a39 27f1ce75 a3afd0a[more...]
 Tue Jun 30 15:38:04 2020 us=337027 UDP write returned 319
 Tue Jun 30 15:38:04 2020 us=337039 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=e5c51a9b ae9eea75, stored-sid=103cf4f1 9bf1fd29, stored-ip=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:04 2020 us=337046 TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
 Tue Jun 30 15:38:04 2020 us=337053 ACK reliable_can_send active=1 current=0 : [2] 1
 Tue Jun 30 15:38:04 2020 us=337070 TLS: tls_process: timeout set to 2
 Tue Jun 30 15:38:04 2020 us=337082 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=d5cff653 95528da5, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:04 2020 us=337099 PO_CTL rwflags=0x0001 ev=4 arg=0x7f44adb05198
 Tue Jun 30 15:38:04 2020 us=337106 I/O WAIT T?|T?|SR|Sw [1/249371]
 Tue Jun 30 15:38:04 2020 us=407629 PO_WAIT[0,0] fd=4 rev=0x00000001 rwflags=0x0001 arg=0x7f44adb05198 
 Tue Jun 30 15:38:04 2020 us=407672  event_wait returned 1
 Tue Jun 30 15:38:04 2020 us=407886 UDP READ [1172] from [AF_INET]5.253.206.251:53: P_CONTROL_V1 kid=0 sid=103cf4f1 9bf1fd29 tls_hmac=3b4ecac9 cbbaf555 bba67c96 5b6583f3 1c6c667a pid=[ #2 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ 1 sid=e5c51a9b ae9eea75 ] pid=1 DATA 16030300 39020000 350303af 3dc781db fdc46793 e9802a80 a4ec78c3 
 Tue Jun 30 15:38:04 2020 us=407898 TLS: control channel, op=P_CONTROL_V1, IP=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:04 2020 us=408099 DECRYPT FROM: 3b4ecac9 cbbaf555 bba67c96 5b6583f3 1c6c667a 00000002 5efb5c5c 20103cf[more...]
 Tue Jun 30 15:38:04 2020 us=408122 PID_TEST [0] [TLS_WRAP-0] [0] 1593531484:1 1593531484:2 t=1593531484[0] r=[0,64,15,0,1] sl=[63,1,64,528]
 Tue Jun 30 15:38:04 2020 us=408132 TLS: received control channel packet s#=0 sid=103cf4f1 9bf1fd29
 Tue Jun 30 15:38:04 2020 us=408168 ACK acknowledge ID 1 (ack->len=1)
 Tue Jun 30 15:38:04 2020 us=408182 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=e5c51a9b ae9eea75, stored-sid=103cf4f1 9bf1fd29, stored-ip=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:04 2020 us=408356 I/O WAIT T?|T?|SR|SW [1/249371]
 Tue Jun 30 15:38:04 2020 us=408366 PO_WAIT[0,0] fd=4 rev=0x00000005 rwflags=0x0003 arg=0x7f44adb05198 
 Tue Jun 30 15:38:04 2020 us=408906 DECRYPT FROM: fe5e51de 86315082 9cbca2ac 4bf295a3 d204611c 00000003 5efb5c5c 20103cf[more...]
 Tue Jun 30 15:38:04 2020 us=408919 PID_TEST [0] [TLS_WRAP-0] [00] 1593531484:2 1593531484:3 t=1593531484[0] r=[0,64,15,0,1] sl=[62,2,64,528]
 Tue Jun 30 15:38:04 2020 us=409594 DECRYPT FROM: a6e8ffc0 0f0f1138 b2ee61cf e2865921 22047ffd 00000004 5efb5c5c 20103cf[more...]
 Tue Jun 30 15:38:04 2020 us=409641 PID_TEST [0] [TLS_WRAP-0] [000] 1593531484:3 1593531484:4 t=1593531484[0] r=[0,64,15,0,1] sl=[61,3,64,528]
 Tue Jun 30 15:38:04 2020 us=410628 SSL state (connect): SSLv3/TLS read server key exchange
 Tue Jun 30 15:38:04 2020 us=410652 SSL state (connect): SSLv3/TLS read server done
 Tue Jun 30 15:38:04 2020 us=411015 SSL state (connect): SSLv3/TLS write change cipher spec
 Tue Jun 30 15:38:04 2020 us=411068 SSL state (connect): SSLv3/TLS write finished
 Tue Jun 30 15:38:04 2020 us=411110 ACK mark active outgoing ID 2
 Tue Jun 30 15:38:04 2020 us=411126 Outgoing Ciphertext -> Reliable
 Tue Jun 30 15:38:04 2020 us=411202 ENCRYPT HMAC: 0c964c0a 798551d6 10f1efaa c2014041 434c0a82
 Tue Jun 30 15:38:04 2020 us=411244 ENCRYPT TO: 0c964c0a 798551d6 10f1efaa c2014041 434c0a82 00000006 5efb5c5c 20e5c51[more...]
 Tue Jun 30 15:38:04 2020 us=411347 TLS: tls_process: timeout set to 2
 Tue Jun 30 15:38:04 2020 us=411375 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=d5cff653 95528da5, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:04 2020 us=411427 I/O WAIT T?|T?|SR|SW [1/249371]
 Tue Jun 30 15:38:04 2020 us=411448 PO_WAIT[0,0] fd=4 rev=0x00000004 rwflags=0x0002 arg=0x7f44adb05198 
 Tue Jun 30 15:38:04 2020 us=411528 UDP WRITE [180] to [AF_INET]5.253.206.251:53: P_CONTROL_V1 kid=0 sid=e5c51a9b ae9eea75 tls_hmac=0c964c0a 798551d6 10f1efaa c2014041 434c0a82 pid=[ #6 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ 3 sid=103cf4f1 9bf1fd29 ] pid=2 DATA 16030300 46100000 424104cc 812ab5b7 a3cfa889 aff07245 5f69d4aa 
 Tue Jun 30 15:38:04 2020 us=411568 UDP write returned 180
 Tue Jun 30 15:38:04 2020 us=411630 ACK reliable_can_send active=1 current=0 : [3] 2
 Tue Jun 30 15:38:04 2020 us=411650 ACK reliable_send_timeout 2 [3] 2
 Tue Jun 30 15:38:04 2020 us=411667 TLS: tls_process: timeout set to 2
 Tue Jun 30 15:38:04 2020 us=411691 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=d5cff653 95528da5, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:04 2020 us=481326 PO_WAIT[0,0] fd=4 rev=0x00000001 rwflags=0x0001 arg=0x7f44adb05198 
 Tue Jun 30 15:38:04 2020 us=481358  event_wait returned 1
 Tue Jun 30 15:38:04 2020 us=481424 UDP READ [105] from [AF_INET]5.253.206.251:53: P_CONTROL_V1 kid=0 sid=103cf4f1 9bf1fd29 tls_hmac=f84f5923 d9395877 bdb572b5 0c14dc0b 9c877e71 pid=[ #5 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ 2 sid=e5c51a9b ae9eea75 ] pid=4 DATA 14030300 01011603 030028ac 5edd735e 4167a981 2a000062 ee3deafb 
 Tue Jun 30 15:38:04 2020 us=481446 TLS: control channel, op=P_CONTROL_V1, IP=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:04 2020 us=481594 ACK read ID 4 (buf->len=51)
 Tue Jun 30 15:38:04 2020 us=481664 ACK RWBS rel->size=8 rel->packet_id=00000004 id=00000004 ret=1

 Tue Jun 30 15:38:04 2020 us=482032 ACK mark active outgoing ID 3
 Tue Jun 30 15:38:04 2020 us=482052 Outgoing Ciphertext -> Reliable
 Tue Jun 30 15:38:04 2020 us=482516 UDP WRITE [501] to [AF_INET]5.253.206.251:53: P_CONTROL_V1 kid=0 sid=e5c51a9b ae9eea75 tls_hmac=12d0c992 e9443ecd 19b802c0 df00830d 204b23f2 pid=[ #7 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ 4 sid=103cf4f1 9bf1fd29 ] pid=3 DATA 17030301 ba4bf990 b62e7280 9cc9246e 97c8098b dd7c9556 c97da94d 
 Tue Jun 30 15:38:04 2020 us=482557 UDP write returned 501
 Tue Jun 30 15:38:04 2020 us=657072 PO_WAIT[0,0] fd=4 rev=0x00000001 rwflags=0x0001 arg=0x7f44adb05198 
 Tue Jun 30 15:38:04 2020 us=657104  event_wait returned 1
 Tue Jun 30 15:38:04 2020 us=657200 UDP READ [316] from [AF_INET]5.253.206.251:53: P_CONTROL_V1 kid=0 sid=103cf4f1 9bf1fd29 tls_hmac=cc836a04 2d188112 a3cf3343 94db63d1 c109d92a pid=[ #6 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ 3 sid=e5c51a9b ae9eea75 ] pid=5 DATA 17030301 01ac5edd 735e4167 aa7dfe25 2e4797cc a1486df6 8d14d878 
 Tue Jun 30 15:38:04 2020 us=657233 TLS: control channel, op=P_CONTROL_V1, IP=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:04 2020 us=657466 ACK acknowledge ID 5 (ack->len=1)
 Tue Jun 30 15:38:04 2020 us=657489 TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=e5c51a9b ae9eea75, stored-sid=103cf4f1 9bf1fd29, stored-ip=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:04 2020 us=657885 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=d5cff653 95528da5, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:04 2020 us=657908 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:04 2020 us=657923 PO_CTL rwflags=0x0003 ev=4 arg=0x7f44adb05198
 Tue Jun 30 15:38:04 2020 us=657969 I/O WAIT T?|T?|SR|SW [1/249371]
 Tue Jun 30 15:38:04 2020 us=657990 PO_WAIT[0,0] fd=4 rev=0x00000004 rwflags=0x0002 arg=0x7f44adb05198 
 Tue Jun 30 15:38:04 2020 us=658003  event_wait returned 1
 Tue Jun 30 15:38:04 2020 us=658021 I/O WAIT status=0x0002
 Tue Jun 30 15:38:04 2020 us=658122 UDP WRITE [50] to [AF_INET]5.253.206.251:53: P_ACK_V1 kid=0 sid=e5c51a9b ae9eea75 tls_hmac=ead379de 9719dedf 4922235f 19e100cb ba9f4bb6 pid=[ #8 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ 5 sid=103cf4f1 9bf1fd29 ]
 Tue Jun 30 15:38:04 2020 us=658155 UDP write returned 50
 Tue Jun 30 15:38:04 2020 us=658184 TLS: tls_multi_process: i=0 state=S_GOT_KEY, mysid=e5c51a9b ae9eea75, stored-sid=103cf4f1 9bf1fd29, stored-ip=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:04 2020 us=658202 TLS: tls_process: chg=0 ks=S_GOT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
 Tue Jun 30 15:38:04 2020 us=658215 STATE S_ACTIVE
 Tue Jun 30 15:38:04 2020 us=658232 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
 Tue Jun 30 15:38:04 2020 us=658260 [Secure-Server] Peer Connection Initiated with [AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:04 2020 us=658278 ACK reliable_can_send active=0 current=0 : [4]
 Tue Jun 30 15:38:04 2020 us=658296 TLS: tls_process: chg=1 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=604800
 Tue Jun 30 15:38:04 2020 us=658310 ACK reliable_can_send active=0 current=0 : [4]
 Tue Jun 30 15:38:04 2020 us=658328 ACK reliable_send_timeout 604800 [4]
 Tue Jun 30 15:38:04 2020 us=658344 TLS: tls_process: timeout set to 60
 Tue Jun 30 15:38:04 2020 us=658360 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=d5cff653 95528da5, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:04 2020 us=658376 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:04 2020 us=658390 PO_CTL rwflags=0x0001 ev=4 arg=0x7f44adb05198
 Tue Jun 30 15:38:04 2020 us=658412 I/O WAIT T?|T?|SR|Sw [1/249371]
 Tue Jun 30 15:38:05 2020 us=908716  event_wait returned 0
 Tue Jun 30 15:38:05 2020 us=908752 I/O WAIT status=0x0020
 Tue Jun 30 15:38:05 2020 us=908795 BIO write tls_write_plaintext_const 13 bytes
 Tue Jun 30 15:38:05 2020 us=908902 TLS: tls_multi_process: i=0 state=S_ACTIVE, mysid=e5c51a9b ae9eea75, stored-sid=103cf4f1 9bf1fd29, stored-ip=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:05 2020 us=908927 TLS: tls_process: chg=0 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=604800
 Tue Jun 30 15:38:05 2020 us=909032 ACK reliable_send ID 4 (size=46 to=2)
 Tue Jun 30 15:38:05 2020 us=909055 ENCRYPT HMAC: 3e3944d4 a4f2aedd dfdce486 6fffc0b7 951fc766
 Tue Jun 30 15:38:05 2020 us=909234 I/O WAIT status=0x0002
 Tue Jun 30 15:38:05 2020 us=909274 UDP WRITE [84] to [AF_INET]5.253.206.251:53: P_CONTROL_V1 kid=0 sid=e5c51a9b ae9eea75 tls_hmac=3e3944d4 a4f2aedd dfdce486 6fffc0b7 951fc766 pid=[ #9 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ ] pid=4 DATA 17030300 254bf990 b62e7280 9d9ec6c2 db4b2236 4a9eee54 1266eea7 03a8a71[more...]
 Tue Jun 30 15:38:05 2020 us=909313 UDP write returned 84
 Tue Jun 30 15:38:05 2020 us=909332 TIMER: coarse timer wakeup 5 seconds
 Tue Jun 30 15:38:05 2020 us=909373 TLS: tls_process: chg=0 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=604800
 Tue Jun 30 15:38:05 2020 us=909387 ACK reliable_can_send active=1 current=0 : [5] 4
 Tue Jun 30 15:38:05 2020 us=909403 ACK reliable_send_timeout 2 [5] 4
 Tue Jun 30 15:38:05 2020 us=909416 TLS: tls_process: timeout set to 2
 Tue Jun 30 15:38:05 2020 us=979358 PO_WAIT[0,0] fd=4 rev=0x00000001 rwflags=0x0001 arg=0x7f44adb05198 
 Tue Jun 30 15:38:05 2020 us=979391  event_wait returned 1
 Tue Jun 30 15:38:05 2020 us=979449 UDP READ [50] from [AF_INET]5.253.206.251:53: P_ACK_V1 kid=0 sid=103cf4f1 9bf1fd29 tls_hmac=548c3181 5250ab43 486ccfd0 6e459a59 6e1edfb8 pid=[ #7 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ 4 sid=e5c51a9b ae9eea75 ]
 Tue Jun 30 15:38:05 2020 us=979459 TLS: control channel, op=P_ACK_V1, IP=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:05 2020 us=979472 TLS: initial packet test, i=0 state=S_ACTIVE, mysid=e5c51a9b ae9eea75, rec-sid=103cf4f1 9bf1fd29, rec-ip=[AF_INET]5.253.206.251:53, stored-sid=103cf4f1 9bf1fd29, stored-ip=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:05 2020 us=979480 TLS: found match, session[0], sid=103cf4f1 9bf1fd29
 Tue Jun 30 15:38:05 2020 us=979502 DECRYPT FROM: 548c3181 5250ab43 486ccfd0 6e459a59 6e1edfb8 00000007 5efb5c5c 28103cf[more...]
 Tue Jun 30 15:38:05 2020 us=979517 PID_TEST [0] [TLS_WRAP-0] [111111] 1593531484:6 1593531484:7 t=1593531485[0] r=[-1,64,15,0,1] sl=[58,6,64,528]
 Tue Jun 30 15:38:05 2020 us=979526 TLS: received control channel packet s#=0 sid=103cf4f1 9bf1fd29
 Tue Jun 30 15:38:05 2020 us=979533 ACK received for pid 4, deleting from send buffer
 Tue Jun 30 15:38:05 2020 us=979546 TLS: tls_multi_process: i=0 state=S_ACTIVE, mysid=e5c51a9b ae9eea75, stored-sid=103cf4f1 9bf1fd29, stored-ip=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:05 2020 us=979554 TLS: tls_process: chg=0 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=604800
 Tue Jun 30 15:38:05 2020 us=979562 ACK reliable_can_send active=0 current=0 : [5]
 Tue Jun 30 15:38:05 2020 us=979575 ACK reliable_send_timeout 604800 [5]
 Tue Jun 30 15:38:05 2020 us=979582 TLS: tls_process: timeout set to 59
 Tue Jun 30 15:38:05 2020 us=979592 TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=d5cff653 95528da5, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:05 2020 us=979601 TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
 Tue Jun 30 15:38:05 2020 us=979610 PO_CTL rwflags=0x0001 ev=4 arg=0x7f44adb05198
 Tue Jun 30 15:38:05 2020 us=979619 I/O WAIT T?|T?|SR|Sw [5/249371]
 Tue Jun 30 15:38:05 2020 us=980184 PO_WAIT[0,0] fd=4 rev=0x00000001 rwflags=0x0001 arg=0x7f44adb05198 
 Tue Jun 30 15:38:05 2020 us=980213  event_wait returned 1
 Tue Jun 30 15:38:05 2020 us=980227 I/O WAIT status=0x0001
 Tue Jun 30 15:38:05 2020 us=980249 UDP read returned 294
 Tue Jun 30 15:38:05 2020 us=980319 UDP READ [294] from [AF_INET]5.253.206.251:53: P_CONTROL_V1 kid=0 sid=103cf4f1 9bf1fd29 tls_hmac=1be69d52 d39bdfb4 b23cf364 47ffe86b 64c2c292 pid=[ #8 / time = (1593531484) Tue Jun 30 15:38:04 2020 ] [ ] pid=6 DATA 17030300 f7ac5edd 735e4167 ab2f93c7 95ef241d 1925307a 0d9bf289 5b39184[more...]
 Tue Jun 30 15:38:05 2020 us=980338 TLS: control channel, op=P_CONTROL_V1, IP=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:05 2020 us=980359 TLS: initial packet test, i=0 state=S_ACTIVE, mysid=e5c51a9b ae9eea75, rec-sid=103cf4f1 9bf1fd29, rec-ip=[AF_INET]5.253.206.251:53, stored-sid=103cf4f1 9bf1fd29, stored-ip=[AF_INET]5.253.206.251:53
 Tue Jun 30 15:38:05 2020 us=980377 TLS: found match, session[0], sid=103cf4f1 9bf1fd29
 Tue Jun 30 15:38:05 2020 us=980435 DECRYPT FROM: 1be69d52 d39bdfb4 b23cf364 47ffe86b 64c2c292 00000008 5efb5c5c 20103cf[more...]
 Tue Jun 30 15:38:05 2020 us=980457 PID_TEST [0] [TLS_WRAP-0] [0111111] 1593531484:7 1593531484:8 t=1593531485[0] r=[-1,64,15,0,1] sl=[57,7,64,528]
 Tue Jun 30 15:38:05 2020 us=980513 ACK mark active incoming ID 6
 Tue Jun 30 15:38:05 2020 us=980531 ACK acknowledge ID 6 (ack->len=1)
 Tue Jun 30 15:38:05 2020 us=980649 TLS -> Incoming Plaintext
 Tue Jun 30 15:38:05 2020 us=980662 TLS: tls_process: chg=1 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=0
 Tue Jun 30 15:38:05 2020 us=980843 PUSH: Received control message: 'PUSH_REPLY,redirect-gateway def1,dhcp-option DNS 45.74.45.3,dhcp-option DNS 45.74.45.5,sndbuf 393216,rcvbuf 393216,comp-lzo no,route-gateway 45.74.45.97,topology subnet,ping 10,ping-restart 120,peer-id 7,cipher AES-256-GCM'
 Tue Jun 30 15:38:05 2020 us=980936 OPTIONS IMPORT: timers and/or timeouts modified
 Tue Jun 30 15:38:05 2020 us=981093 OPTIONS IMPORT: data channel crypto options modified
 Tue Jun 30 15:38:05 2020 us=981110 Data Channel: using negotiated cipher 'AES-256-GCM'
 Tue Jun 30 15:38:05 2020 us=981422 tls1_P_hash out: 51884f6a 710bdd41 8869b2be 08b09fa2 a8c3b130 38928765 a3435873 240fd248 0b2c2f49 fa6b8332 3d1aa17d a02f599b
 Tue Jun 30 15:38:05 2020 us=981445 tls1_PRF out[48]: 77304595 0d6601ed a54dfc15 3b6bf07d a10c5edc 25978f40 a8947895 284065b7 4a24be8a 9366dec5 29d2992a 74e4d4e3
 Tue Jun 30 15:38:05 2020 us=981462 tls1_P_hash sec: 77304595 0d6601ed a54dfc15 3b6bf07d a10c5edc 25978f40
 Tue Jun 30 15:38:05 2020 us=981492 tls1_P_hash seed: 4f70656e 56504e20 6b657920 65787061 6e73696f 6eb2ba05 7b70eb09 170a7117 b49b1add 3475e504 4f74f0b9 a1d5c453 18e43c32 2160a199 559a9ac1 56ef0411 4b33c355 ed5209c9 009dc587 ad117f89 d33ea23b 91e5c51a 9bae9eea 75103cf4 f19bf1fd 29
 Tue Jun 30 15:38:05 2020 us=981556 tls1_P_hash out: 1084aec4 2c8ef7d8 85372c55 ffd17249 8ff27c8a c797bcde e2601afa 2c1232f2 c5b851b7 1b7e7ac0 16dec2d1 15bb8800 7b2cc990 261b51cc af5edff3 ffab5233 3ef84f05 46fc3ef5 2329f583 17e96139 fd968ba6 a1a39337 9571d206 34e6f403 0a0792c9 dad761c2 02aace18 ff6cc198 28d29bde a03c43af f8402445 702df620 b0fb67e9 d1370408 71d45d4e 93b5919c 761f6cf6 a4222f03 f8896352 5c967e1f 704c756a 4f05bb5a f2e68209 c52f9136 eaee82ed 852e56a4 ebc10544 83410bdb b57327fb bd6cb632 bf16eb62 a899ff7b 711bc120 86742c5d deb38afc be673904 94ec1008 e1313075 ac21f8d0 ead1e289 39a8f1f5 b9fe87d5 8a4eafa6 56a3d8ad
 Tue Jun 30 15:38:05 2020 us=981573 tls1_P_hash sec: a8947895 284065b7 4a24be8a 9366dec5 29d2992a 74e4d4e3
 Tue Jun 30 15:38:05 2020 us=981603 tls1_P_hash seed: 4f70656e 56504e20 6b657920 65787061 6e73696f 6eb2ba05 7b70eb09 170a7117 b49b1add 3475e504 4f74f0b9 a1d5c453 18e43c32 2160a199 559a9ac1 56ef0411 4b33c355 ed5209c9 009dc587 ad117f89 d33ea23b 91e5c51a 9bae9eea 75103cf4 f19bf1fd 29
 Tue Jun 30 15:38:05 2020 us=981668 tls1_P_hash out: 2e4ff721 4d18b139 316a9610 730c942f 450d281f 1b7f1cbb fbd4be90 90deedd8 7e0dd203 7306dc19 2ce85960 03246f1d 04e82452 2f3107f2 8ba2049c 6652b22f 6599c290 36d5e29c a0178c31 f4837049 e8a2f4e7 81f97e6f cefbd0eb d665aa15 88c93974 6dec2746 02e03274 df08ad07 4c5a98b1 1fd5a073 14210683 443e102e 65ff106d 42f6c893 a8a6b363 257c017b ea9bd90b d174541c e79c6f67 7daff3bf 83c5c76f 45f951a1 8a139093 de8a333a 87cb5744 79de25b8 6c664fa8 9a046932 41a2f2d7 3f6be1b5 e80d91a2 312dd621 bcde9a28 0146fb46 0d3ebe0b 8d86cbfe 5f2f3156 ae4040a8 acdc1106 1a90fcc4 aefb61e9 26ba19e1 69107dbc b590cd6a
 Tue Jun 30 15:38:05 2020 us=981715 tls1_PRF out[256]: 3ecb59e5 619646e1 b45dba45 8cdde666 caff5495 dce8a065 19b4a46a bcccdf2a bbb583b4 6878a6d9 3a369bb1 169fe71d 7fc4edc2 092a563e 24fcdb6f 99f9e01c 5b618d95 7029dc69 833e79b2 e36a1170 15347f41 205aed58 5b8a02ed e2835e16 82ceabbd b73b4684 004afc6c 20646c9f 6488036f bfe9e3dc ec6122c6 3413e60e d5047784 93c1cc9b d972ee2d b6c990e7 9c84b5fd 75567b1f 1f150c35 21398da0 f389b205 0afceafb 78f5129a 1ba5a20c 6d25d5a9 fcf0731c 87a74aec 194562e9 f4d1d52c 82075787 571b7ac0 99b4295a cdc55b08 8732d71b d38d34f7 33e1f2fa cbc3215e 4f7170dd 00fde9d6 f0411e4d 9753901c 9f449e34 e35ed21a e33315c7
 Tue Jun 30 15:38:05 2020 us=981733 Master Encrypt (cipher): 3ecb59e5 619646e1 b45dba45 8cdde666 caff5495 dce8a065 19b4a46a bcccdf2a
 Tue Jun 30 15:38:05 2020 us=981746 Master Encrypt (hmac): 
 Tue Jun 30 15:38:05 2020 us=981767 Master Decrypt (cipher): d5047784 93c1cc9b d972ee2d b6c990e7 9c84b5fd 75567b1f 1f150c35 21398da0
 Tue Jun 30 15:38:05 2020 us=981781 Master Decrypt (hmac): 
 Tue Jun 30 15:38:05 2020 us=981801 CRYPTO INFO: n_DES_cblocks=0
 Tue Jun 30 15:38:05 2020 us=981817 CRYPTO INFO: n_DES_cblocks=0
 Tue Jun 30 15:38:05 2020 us=981830 CRYPTO INFO: n_DES_cblocks=0
 Tue Jun 30 15:38:05 2020 us=981843 CRYPTO INFO: n_DES_cblocks=0
 Tue Jun 30 15:38:05 2020 us=981859 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
 Tue Jun 30 15:38:05 2020 us=981877 Outgoing Data Channel: CIPHER KEY: 3ecb59e5 619646e1 b45dba45 8cdde666 caff5495 dce8a065 19b4a46a bcccdf2a
 Tue Jun 30 15:38:05 2020 us=981895 Outgoing Data Channel: CIPHER block_size=16 iv_size=12
 Tue Jun 30 15:38:05 2020 us=981913 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
 Tue Jun 30 15:38:05 2020 us=981932 Incoming Data Channel: CIPHER KEY: d5047784 93c1cc9b d972ee2d b6c990e7 9c84b5fd 75567b1f 1f150c35 21398da0
 Tue Jun 30 15:38:05 2020 us=981946 Incoming Data Channel: CIPHER block_size=16 iv_size=12
 Tue Jun 30 15:38:05 2020 us=982050 ROUTE_GATEWAY 172.17.0.1/255.255.0.0 IFACE=eth0 HWADDR=02:42:ac:11:00:02
 Tue Jun 30 15:38:05 2020 us=982437 TUN/TAP device tun0 opened
 Tue Jun 30 15:38:05 2020 us=982489 TUN/TAP TX queue length set to 100
 Tue Jun 30 15:38:05 2020 us=982533 /etc/openvpn/tunnelUp.sh tun0 1500 1553   init
 **Up script executed with tun0 1500 1553   init
 ERROR, unable to obtain tunnel address**
 killing 18
 Tue Jun 30 15:38:05 2020 us=986149 WARNING: Failed running command (--up/--down): external program did not exit normally
 Tue Jun 30 15:38:05 2020 us=986195 Exiting due to fatal error
pkishino commented 4 years ago

your not receiving an ip..look at the code in tunnelUp.sh.. it calls the transmission start.sh script which will print all args, hence the ** Up script executed line. the 4th parameter should be the ip, but in your case it is empty, hence it kills the script..

canzone commented 4 years ago

Hi @pkishino Thanks a lot for the reply. Indeed, I noticed that. I ran openvpn with maximum verbosity, hoping that it would show me where the issue is. Looks like it is not connecting to the VPN. I tried to download up-to-date ovpn files from PureVPN, tried to use old ones from previous versions in the container, even tried to debug the shell scripts, but the issue happens during opnevpn execution, and there is no much I can look there. Any other ideas? This Docker solution is amazing, I'd love to help troubleshooting it.

madcowGit commented 4 years ago

Actually I keep having the error as well on 1 of my containers, whereas the other is going fine. Even when they are set to the same server, 1 if fine and the other crashes. And it is not consistently 1 of them that crashes.

So that makes me assume it is a purevpn issue, serverside

I just keep trying new servers until 1 of them works. Cumbersome, yes (i use dk2-ovpn-udp right now)

canzone commented 4 years ago

Hello Everyone,

First of all, thank you all for your insights and support. Today, out of the blue, everything started working again. Seems that there were some glitch in PureVPN servers, anyway. Strange thing: since this issue started, I tested PureVPN access in several ways and all worked fine. I even built an Ubuntu VM with PureVPN and Transmission as a "backup". Well, I don't need it anymore :-D Back to business with this awesome Docker container!

theerror commented 4 years ago

I do have this issue as well (Synology 218+) and looks, it's happening because some time the network is somehow a bit slow or something. When I run the same command for starting VPN inside container, it's working fine, but during whole container start, it just some time failed - around 50 / 50. Really annoying.

theerror commented 4 years ago

Hmm, for me, give it some small time helped to me...

sed -i '0,/exec openvpn/s/exec openvpn/sleep 2\n&/' /etc/openvpn/start.sh

this will add sleep 2 before running the openvpn and it helped to me...

@pkishino do you think you can add this small "postpone" as configurable option?