SoftEther VPN User Forum

Posted: **Wed Jun 14, 2017 8:42 am**

こんにちは
現在AWSでLinuxインスタンスにSoftEther VPN Serverをインストールして使用中にあります。
そして一般的なユーザーは、WindowsとMAC環境でOpenVPNを介してサーバーに接続をしています。

この間からサーバー接続時、以下のようなログが表示され、サーバへの接続ができない現象があります。

Wed Jun 14 16:38:34 2017 SENT CONTROL [vpn * .softether.net]：「PUSH_REQUEST」（status = 1）
Wed Jun 14 16:38:39 2017 SENT CONTROL [vpn * .softether.net]：「PUSH_REQUEST」（status = 1）
Wed Jun 14 16:38:44 2017 SENT CONTROL [vpn * .softether.net]：「PUSH_REQUEST」（status = 1）
Wed Jun 14 16:38:50 2017 SENT CONTROL [vpn * .softether.net]：「PUSH_REQUEST」（status = 1）
Wed Jun 14 16:38:51 2017 AUTH：Received control message：AUTH_FAILED
Wed Jun 14 16:38:51 2017 SIGUSR1 [soft、auth-failure] received、process restarting
Wed Jun 14 16:38:51 2017 MANAGEMENT：> STATE：1497425931、RECONNECTING、auth-failure ,,,,,
Wed Jun 14 16:38:51 2017 Restart pause、5 second（s）

アカウントのID/ PWは正常なのに、上記のような現象が出ており、SoftEther VPN Serverを再起動する場合は、再接続がされます。

このような原因と解決方法は何ですか？

Posted: **Wed Jun 14, 2017 9:21 am**

サーバー側のログではどのようなエラーになっているでしょうか。

Posted: **Fri Jun 16, 2017 12:27 am**

cedar wrote:
> サーバー側のログではどのようなエラーになっているでしょうか。

2017-06-14 05:16:38.120 [HUB "devvpn"] SecureNAT: The UDP session 354537 has been deleted.
2017-06-14 05:16:38.505 [HUB "devvpn"] SecureNAT: The UDP session 354702 has been created. Connection source 165.50.30.105:53860, Connection destination 165.50.30.1:53
2017-06-14 05:16:38.505 [HUB "devvpn"] SecureNAT: The UDP session 354538 has been deleted.
2017-06-14 05:16:38.515 [HUB "devvpn"] SecureNAT: The UDP session 354703 has been created. Connection source 165.50.30.149:53643, Connection destination 165.50.30.1:53
2017-06-14 05:16:38.525 [HUB "devvpn"] SecureNAT: The UDP session 354539 has been deleted.
2017-06-14 05:16:38.545 [HUB "devvpn"] SecureNAT: The UDP session 354704 has been created. Connection source 165.50.30.149:55638, Connection destination 165.50.30.1:53
2017-06-14 05:16:38.850 [HUB "devvpn"] SecureNAT: The UDP session 354540 has been deleted.
2017-06-14 05:16:39.376 [HUB "devvpn"] SecureNAT: The UDP session 354705 has been created. Connection source 165.50.30.145:59113, Connection destination 165.50.30.1:53
2017-06-14 05:16:39.386 [HUB "devvpn"] SecureNAT: The UDP session 354706 has been created. Connection source 165.50.30.145:58335, Connection destination 165.50.30.1:53
2017-06-14 05:16:39.873 [HUB "devvpn"] SecureNAT: The UDP session 354707 has been created. Connection source 165.50.30.129:53507, Connection destination 165.50.30.1:53
2017-06-14 05:16:40.015 [HUB "devvpn"] SecureNAT: The UDP session 354708 has been created. Connection source 165.50.30.100:55950, Connection destination 165.50.30.1:53
2017-06-14 05:16:40.177 [HUB "devvpn"] SecureNAT: The UDP session 354709 has been created. Connection source 165.50.30.129:63504, Connection destination 165.50.30.1:53
2017-06-14 05:16:40.177 [HUB "devvpn"] SecureNAT: The UDP session 354541 has been deleted.
2017-06-14 05:16:40.886 [HUB "devvpn"] SecureNAT: The UDP session 354542 has been deleted.
2017-06-14 05:16:41.018 [HUB "devvpn"] SecureNAT: The UDP session 354543 has been deleted.
2017-06-14 05:16:42.254 [HUB "devvpn"] SecureNAT: The UDP session 354544 has been deleted.
2017-06-14 05:16:42.781 [HUB "devvpn"] SecureNAT: The UDP session 354710 has been created. Connection source 165.50.30.149:52076, Connection destination 165.50.30.1:53
2017-06-14 05:16:42.791 [HUB "devvpn"] SecureNAT: The UDP session 354711 has been created. Connection source 165.50.30.149:57507, Connection destination 165.50.30.1:53
2017-06-14 05:16:42.882 [HUB "devvpn"] SecureNAT: The UDP session 354712 has been created. Connection source 165.50.30.149:63234, Connection destination 165.50.30.1:53
2017-06-14 05:16:43.065 [HUB "devvpn"] SecureNAT: The UDP session 354545 has been deleted.
2017-06-14 05:16:43.125 [HUB "devvpn"] SecureNAT: The UDP session 354546 has been deleted.
2017-06-14 05:16:43.379 [HUB "devvpn"] SecureNAT: The UDP session 354547 has been deleted.
2017-06-14 05:16:44.665 [HUB "devvpn"] SecureNAT: The UDP session 354549 has been deleted.
2017-06-14 05:16:44.665 [HUB "devvpn"] SecureNAT: The UDP session 354551 has been deleted.
2017-06-14 05:16:44.706 [HUB "devvpn"] SecureNAT: The UDP session 354550 has been deleted.
2017-06-14 05:16:44.706 [HUB "devvpn"] SecureNAT: The UDP session 354548 has been deleted.
2017-06-14 05:16:45.273 OpenVPN Session 1 (211.155.223.46:56542 -> 165.50.110.75:6939) Channel 4: A new channel is created.
2017-06-14 05:16:45.283 [HUB "devvpn"] SecureNAT: The UDP session 354713 has been created. Connection source 165.50.30.193:62467, Connection destination 165.50.30.1:53
2017-06-14 05:16:45.364 OpenVPN Session 1 (211.155.223.46:56542 -> 165.50.110.75:6939) Channel 4: Option Strings Received: "V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_CLIENT,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client"
2017-06-14 05:16:45.364 OpenVPN Session 1 (211.155.223.46:56542 -> 165.50.110.75:6939) Channel 4: Option Strings to Send: "V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_SERVER,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server"
2017-06-14 05:16:45.364 OpenVPN Session 1 (211.155.223.46:56542 -> 165.50.110.75:6939) Channel 4: The channel is established. (Trigger: Re-key completion.)
2017-06-14 05:16:45.648 [HUB "devvpn"] SecureNAT: The UDP session 354714 has been created. Connection source 165.50.30.105:62863, Connection destination 165.50.30.1:53
2017-06-14 05:16:45.648 [HUB "devvpn"] SecureNAT: The TCP session 350102 has been deleted.
2017-06-14 05:16:46.114 [HUB "devvpn"] SecureNAT: The UDP session 354553 has been deleted.
2017-06-14 05:16:46.114 [HUB "devvpn"] SecureNAT: The UDP session 354552 has been deleted.
2017-06-14 05:16:46.215 [HUB "devvpn"] SecureNAT: The UDP session 354554 has been deleted.
2017-06-14 05:16:46.469 [HUB "devvpn"] SecureNAT: The UDP session 354715 has been created. Connection source 165.50.30.100:53984, Connection destination 165.50.30.1:53
2017-06-14 05:16:46.986 [HUB "devvpn"] SecureNAT: The UDP session 354555 has been deleted.
2017-06-14 05:16:47.745 [HUB "devvpn"] SecureNAT: The UDP session 354559 has been deleted.
2017-06-14 05:16:47.745 [HUB "devvpn"] SecureNAT: The UDP session 354561 has been deleted.
2017-06-14 05:16:47.745 [HUB "devvpn"] SecureNAT: The UDP session 354558 has been deleted.
2017-06-14 05:16:47.755 [HUB "devvpn"] SecureNAT: The UDP session 354560 has been deleted.
2017-06-14 05:16:47.755 [HUB "devvpn"] SecureNAT: The UDP session 354557 has been deleted.
2017-06-14 05:16:47.917 [HUB "devvpn"] SecureNAT: The UDP session 354556 has been deleted.
2017-06-14 05:16:47.937 [HUB "devvpn"] SecureNAT: The UDP session 354716 has been created. Connection source 165.50.30.169:53402, Connection destination 165.50.30.1:53
2017-06-14 05:16:49.275 [HUB "devvpn"] SecureNAT: The UDP session 354563 has been deleted.
2017-06-14 05:16:49.275 [HUB "devvpn"] SecureNAT: The UDP session 354562 has been deleted.
2017-06-14 05:16:49.660 [HUB "devvpn"] SecureNAT: The UDP session 354717 has been created. Connection source 165.50.30.177:64757, Connection destination 165.50.30.1:53
2017-06-14 05:16:49.660 [HUB "devvpn"] SecureNAT: The TCP session 350109 has been deleted.
2017-06-14 05:16:49.660 [HUB "devvpn"] SecureNAT: The UDP session 354564 has been deleted.
2017-06-14 05:16:50.136 [HUB "devvpn"] SecureNAT: The UDP session 354718 has been created. Connection source 165.50.30.145:56951, Connection destination 165.50.30.1:53
2017-06-14 05:16:50.359 [HUB "devvpn"] SecureNAT: The UDP session 354565 has been deleted.
2017-06-14 05:16:50.379 [HUB "devvpn"] SecureNAT: The UDP session 354566 has been deleted.
2017-06-14 05:16:50.460 [HUB "devvpn"] SecureNAT: The UDP session 354719 has been created. Connection source 165.50.30.125:55679, Connection destination 165.50.30.1:53
2017-06-14 05:16:50.551 [HUB "devvpn"] SecureNAT: The UDP session 354720 has been created. Connection source 165.50.30.157:51276, Connection destination 165.50.30.1:53
2017-06-14 05:16:50.551 [HUB "devvpn"] SecureNAT: The UDP session 354721 has been created. Connection source 165.50.30.157:54125, Connection destination 165.50.30.1:53
2017-06-14 05:16:50.612 [HUB "devvpn"] SecureNAT: The TCP session 350108 has been deleted.
2017-06-14 05:16:50.805 [HUB "devvpn"] SecureNAT: The UDP session 354722 has been created. Connection source 165.50.30.121:60071, Connection destination 165.50.30.1:53
2017-06-14 05:16:52.567 [HUB "devvpn"] SecureNAT: The UDP session 354567 has been deleted.
2017-06-14 05:16:52.578 [HUB "devvpn"] SecureNAT: The UDP session 354568 has been deleted.
2017-06-14 05:16:52.902 [HUB "devvpn"] SecureNAT: The UDP session 354723 has been created. Connection source 165.50.30.165:55467, Connection destination 165.50.30.1:53
2017-06-14 05:16:53.023 [HUB "devvpn"] SecureNAT: The UDP session 354569 has been deleted.
2017-06-14 05:16:53.064 [HUB "devvpn"] SecureNAT: The UDP session 354572 has been deleted.
2017-06-14 05:16:53.064 [HUB "devvpn"] SecureNAT: The UDP session 354575 has been deleted.
2017-06-14 05:16:53.064 [HUB "devvpn"] SecureNAT: The UDP session 354574 has been deleted.
2017-06-14 05:16:53.064 [HUB "devvpn"] SecureNAT: The UDP session 354573 has been deleted.
2017-06-14 05:16:53.064 [HUB "devvpn"] SecureNAT: The UDP session 354571 has been deleted.
2017-06-14 05:16:53.064 [HUB "devvpn"] SecureNAT: The TCP session 350106 has been deleted.
2017-06-14 05:16:53.104 [HUB "devvpn"] SecureNAT: The UDP session 354724 has been created. Connection source 165.50.30.165:56613, Connection destination 165.50.30.1:53
2017-06-14 05:16:53.114 [HUB "devvpn"] SecureNAT: The UDP session 354577 has been deleted.
2017-06-14 05:16:53.114 [HUB "devvpn"] SecureNAT: The UDP session 354576 has been deleted.
2017-06-14 05:16:53.114 [HUB "devvpn"] SecureNAT: The UDP session 354725 has been created. Connection source 165.50.30.165:55373, Connection destination 165.50.30.1:53
2017-06-14 05:16:53.175 [HUB "devvpn"] SecureNAT: The UDP session 354570 has been deleted.
2017-06-14 05:16:53.266 OpenVPN Session 1 (211.155.223.46:65143 -> 165.50.110.75:6939) Channel 4: A new channel is created.
2017-06-14 05:16:53.297 [HUB "devvpn"] SecureNAT: The UDP session 354726 has been created. Connection source 165.50.30.157:55162, Connection destination 165.50.30.1:53
2017-06-14 05:16:53.297 [HUB "devvpn"] SecureNAT: The UDP session 354727 has been created. Connection source 165.50.30.157:64873, Connection destination 165.50.30.1:53
2017-06-14 05:16:53.357 OpenVPN Session 1 (211.155.223.46:65143 -> 165.50.110.75:6939) Channel 4: Option Strings Received: "V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_CLIENT,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client"
2017-06-14 05:16:53.357 OpenVPN Session 1 (211.155.223.46:65143 -> 165.50.110.75:6939) Channel 4: Option Strings to Send: "V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_SERVER,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server"
2017-06-14 05:16:53.357 OpenVPN Session 1 (211.155.223.46:65143 -> 165.50.110.75:6939) Channel 4: The channel is established. (Trigger: Re-key completion.)
2017-06-14 05:16:54.391 [HUB "devvpn"] SecureNAT: The DHCP entry 2799 has been created. MAC address: CA-4F-78-A8-5D-7E, IP address: 165.50.30.189, host name: , expiration span: 7200 seconds
2017-06-14 05:16:55.384 [HUB "devvpn"] SecureNAT: The UDP session 354579 has been deleted.
2017-06-14 05:16:55.384 [HUB "devvpn"] SecureNAT: The UDP session 354578 has been deleted.

当時のサーバーログです。
これらのログのほか、特別に他のログはありません。

回答お願いいたします。

Posted: **Fri Jun 16, 2017 9:36 am**

サーバーのログにはユーザー認証に関する記録が残っていないので、ID/Passwordの問題ではないようです。
サーバー側からは特にエラーは認識されていないようです。

クライアント側の設定ファイルは SoftEther VPN で生成したものでしょうか。
また、ovpn設定ファイル中の「verb」オプションのログレベルを上げてみると、より詳細な情報が分かるかもしれません。

Posted: **Tue Jun 20, 2017 7:58 am**

cedar wrote:
> サーバーのログにはユーザー認証に関する記録が残っていないので、ID/Passwordの問題ではないようです。
> サーバー側からは特にエラーは認識されていないようです。
>
> クライアント側の設定ファイルは SoftEther VPN で生成したものでしょうか。
> また、ovpn設定ファイル中の「verb」オプションのログレベルを上げてみると、より詳細な情報が分かるかもしれません。

回答をいただきありがとうございます。

言われた通りにOpenVPN Clientでverb値を6に変更し、これに対する接続失敗のログを登録します。

code32というアカウントのユーザーがSoftEther VPN Server（152.79.105.11:6937）に接続しようとしたが、接続に失敗したログです。

以前のようにID/ Passwordは正常な状態です。

確認お願いいたします。
------------------------------log--------------------------------------------------------------------------------------
Tue Jun 20 15:53:51 2017 us=88815 Current Parameter Settings:
Tue Jun 20 15:53:51 2017 us=88815 config = 'Dev.ovpn'
Tue Jun 20 15:53:51 2017 us=88815 mode = 0
Tue Jun 20 15:53:51 2017 us=88815 show_ciphers = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 show_digests = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 show_engines = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 genkey = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 key_pass_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 show_tls_ciphers = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 connect_retry_max = 0
Tue Jun 20 15:53:51 2017 us=88815 Connection profiles [0]:
Tue Jun 20 15:53:51 2017 us=88815 proto = tcp-client
Tue Jun 20 15:53:51 2017 us=88815 local = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 local_port = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 remote = 'vpn*.v4.softether.net'
Tue Jun 20 15:53:51 2017 us=88815 remote_port = '6973'
Tue Jun 20 15:53:51 2017 us=88815 remote_float = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 bind_defined = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 bind_local = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 bind_ipv6_only = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 connect_retry_seconds = 5
Tue Jun 20 15:53:51 2017 us=88815 connect_timeout = 120
Tue Jun 20 15:53:51 2017 us=88815 socks_proxy_server = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 socks_proxy_port = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 tun_mtu = 1500
Tue Jun 20 15:53:51 2017 us=88815 tun_mtu_defined = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 link_mtu = 1500
Tue Jun 20 15:53:51 2017 us=88815 link_mtu_defined = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 tun_mtu_extra = 0
Tue Jun 20 15:53:51 2017 us=88815 tun_mtu_extra_defined = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 mtu_discover_type = -1
Tue Jun 20 15:53:51 2017 us=88815 fragment = 0
Tue Jun 20 15:53:51 2017 us=88815 mssfix = 1450
Tue Jun 20 15:53:51 2017 us=88815 explicit_exit_notification = 0
Tue Jun 20 15:53:51 2017 us=88815 Connection profiles END
Tue Jun 20 15:53:51 2017 us=88815 remote_random = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 ipchange = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 dev = 'tun'
Tue Jun 20 15:53:51 2017 us=88815 dev_type = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 dev_node = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 lladdr = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 topology = 1
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_local = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_remote_netmask = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_noexec = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_nowarn = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_ipv6_local = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_ipv6_netbits = 0
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_ipv6_remote = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 shaper = 0
Tue Jun 20 15:53:51 2017 us=88815 mtu_test = 0
Tue Jun 20 15:53:51 2017 us=88815 mlock = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 keepalive_ping = 0
Tue Jun 20 15:53:51 2017 us=88815 keepalive_timeout = 0
Tue Jun 20 15:53:51 2017 us=88815 inactivity_timeout = 0
Tue Jun 20 15:53:51 2017 us=88815 ping_send_timeout = 0
Tue Jun 20 15:53:51 2017 us=88815 ping_rec_timeout = 0
Tue Jun 20 15:53:51 2017 us=88815 ping_rec_timeout_action = 0
Tue Jun 20 15:53:51 2017 us=88815 ping_timer_remote = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 remap_sigusr1 = 0
Tue Jun 20 15:53:51 2017 us=88815 persist_tun = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 persist_local_ip = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 persist_remote_ip = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 persist_key = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 passtos = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 resolve_retry_seconds = 1000000000
Tue Jun 20 15:53:51 2017 us=88815 resolve_in_advance = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 username = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 groupname = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 chroot_dir = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 cd_dir = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 writepid = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 up_script = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 down_script = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 down_pre = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 up_restart = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 up_delay = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 daemon = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 inetd = 0
Tue Jun 20 15:53:51 2017 us=88815 log = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 suppress_timestamps = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 machine_readable_output = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 nice = 0
Tue Jun 20 15:53:51 2017 us=88815 verbosity = 6
Tue Jun 20 15:53:51 2017 us=88815 mute = 0
Tue Jun 20 15:53:51 2017 us=88815 gremlin = 0
Tue Jun 20 15:53:51 2017 us=88815 status_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 status_file_version = 1
Tue Jun 20 15:53:51 2017 us=88815 status_file_update_freq = 60
Tue Jun 20 15:53:51 2017 us=88815 occ = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 rcvbuf = 0
Tue Jun 20 15:53:51 2017 us=88815 sndbuf = 0
Tue Jun 20 15:53:51 2017 us=88815 sockflags = 0
Tue Jun 20 15:53:51 2017 us=88815 fast_io = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 comp.alg = 0
Tue Jun 20 15:53:51 2017 us=88815 comp.flags = 0
Tue Jun 20 15:53:51 2017 us=88815 route_script = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 route_default_gateway = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 route_default_metric = 0
Tue Jun 20 15:53:51 2017 us=88815 route_noexec = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 route_delay = 5
Tue Jun 20 15:53:51 2017 us=88815 route_delay_window = 30
Tue Jun 20 15:53:51 2017 us=88815 route_delay_defined = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 route_nopull = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 route_gateway_via_dhcp = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 allow_pull_fqdn = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 management_addr = '127.0.0.1'
Tue Jun 20 15:53:51 2017 us=88815 management_port = '25341'
Tue Jun 20 15:53:51 2017 us=88815 management_user_pass = 'stdin'
Tue Jun 20 15:53:51 2017 us=88815 management_log_history_cache = 250
Tue Jun 20 15:53:51 2017 us=88815 management_echo_buffer_size = 100
Tue Jun 20 15:53:51 2017 us=88815 management_write_peer_info_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 management_client_user = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 management_client_group = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 management_flags = 6
Tue Jun 20 15:53:51 2017 us=88815 shared_secret_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 key_direction = 0
Tue Jun 20 15:53:51 2017 us=88815 ciphername = 'AES-128-CBC'
Tue Jun 20 15:53:51 2017 us=88815 ncp_enabled = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 ncp_ciphers = 'AES-256-GCM:AES-128-GCM'
Tue Jun 20 15:53:51 2017 us=88815 authname = 'SHA1'
Tue Jun 20 15:53:51 2017 us=88815 prng_hash = 'SHA1'
Tue Jun 20 15:53:51 2017 us=88815 prng_nonce_secret_len = 16
Tue Jun 20 15:53:51 2017 us=88815 keysize = 0
Tue Jun 20 15:53:51 2017 us=88815 engine = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 replay = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 mute_replay_warnings = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 replay_window = 64
Tue Jun 20 15:53:51 2017 us=88815 replay_time = 15
Tue Jun 20 15:53:51 2017 us=88815 packet_id_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 use_iv = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 test_crypto = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 tls_server = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 tls_client = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 key_method = 2
Tue Jun 20 15:53:51 2017 us=88815 ca_file = '[[INLINE]]'
Tue Jun 20 15:53:51 2017 us=88815 ca_path = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 dh_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 cert_file = '[[INLINE]]'
Tue Jun 20 15:53:51 2017 us=88815 extra_certs_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 priv_key_file = '[[INLINE]]'
Tue Jun 20 15:53:51 2017 us=88815 pkcs12_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 cryptoapi_cert = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 cipher_list = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 tls_verify = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 tls_export_cert = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 verify_x509_type = 0
Tue Jun 20 15:53:51 2017 us=88815 verify_x509_name = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 crl_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 ns_cert_type = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_ku[i] = 0
Tue Jun 20 15:53:51 2017 us=88815 remote_cert_eku = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 ssl_flags = 0
Tue Jun 20 15:53:51 2017 us=88815 tls_timeout = 2
Tue Jun 20 15:53:51 2017 us=88815 renegotiate_bytes = -1
Tue Jun 20 15:53:51 2017 us=88815 renegotiate_packets = 0
Tue Jun 20 15:53:51 2017 us=88815 renegotiate_seconds = 3600
Tue Jun 20 15:53:51 2017 us=88815 handshake_window = 60
Tue Jun 20 15:53:51 2017 us=88815 transition_window = 3600
Tue Jun 20 15:53:51 2017 us=88815 single_session = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 push_peer_info = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 tls_exit = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 tls_auth_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 tls_crypt_file = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_protected_authentication = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_private_mode = 00000000
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_cert_private = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_pin_cache_period = -1
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_id = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 pkcs11_id_management = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 server_network = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 server_netmask = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 server_network_ipv6 = ::
Tue Jun 20 15:53:51 2017 us=88815 server_netbits_ipv6 = 0
Tue Jun 20 15:53:51 2017 us=88815 server_bridge_ip = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 server_bridge_netmask = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 server_bridge_pool_start = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 server_bridge_pool_end = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_pool_defined = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_pool_start = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_pool_end = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_pool_netmask = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_pool_persist_filename = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_pool_persist_refresh_freq = 600
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_ipv6_pool_defined = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_ipv6_pool_base = ::
Tue Jun 20 15:53:51 2017 us=88815 ifconfig_ipv6_pool_netbits = 0
Tue Jun 20 15:53:51 2017 us=88815 n_bcast_buf = 256
Tue Jun 20 15:53:51 2017 us=88815 tcp_queue_limit = 64
Tue Jun 20 15:53:51 2017 us=88815 real_hash_size = 256
Tue Jun 20 15:53:51 2017 us=88815 virtual_hash_size = 256
Tue Jun 20 15:53:51 2017 us=88815 client_connect_script = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 learn_address_script = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 client_disconnect_script = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 client_config_dir = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 ccd_exclusive = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 tmp_dir = 'C:\Users\code\AppData\Local\Temp\'
Tue Jun 20 15:53:51 2017 us=88815 push_ifconfig_defined = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 push_ifconfig_local = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 push_ifconfig_remote_netmask = 0.0.0.0
Tue Jun 20 15:53:51 2017 us=88815 push_ifconfig_ipv6_defined = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 push_ifconfig_ipv6_local = ::/0
Tue Jun 20 15:53:51 2017 us=88815 push_ifconfig_ipv6_remote = ::
Tue Jun 20 15:53:51 2017 us=88815 enable_c2c = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 duplicate_cn = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 cf_max = 0
Tue Jun 20 15:53:51 2017 us=88815 cf_per = 0
Tue Jun 20 15:53:51 2017 us=88815 max_clients = 1024
Tue Jun 20 15:53:51 2017 us=88815 max_routes_per_client = 256
Tue Jun 20 15:53:51 2017 us=88815 auth_user_pass_verify_script = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 auth_user_pass_verify_script_via_file = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 auth_token_generate = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 auth_token_lifetime = 0
Tue Jun 20 15:53:51 2017 us=88815 client = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 pull = ENABLED
Tue Jun 20 15:53:51 2017 us=88815 auth_user_pass_file = 'stdin'
Tue Jun 20 15:53:51 2017 us=88815 show_net_up = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 route_method = 3
Tue Jun 20 15:53:51 2017 us=88815 block_outside_dns = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 ip_win32_defined = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 ip_win32_type = 3
Tue Jun 20 15:53:51 2017 us=88815 dhcp_masq_offset = 0
Tue Jun 20 15:53:51 2017 us=88815 dhcp_lease_time = 31536000
Tue Jun 20 15:53:51 2017 us=88815 tap_sleep = 0
Tue Jun 20 15:53:51 2017 us=88815 dhcp_options = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 dhcp_renew = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 dhcp_pre_release = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 domain = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 netbios_scope = '[UNDEF]'
Tue Jun 20 15:53:51 2017 us=88815 netbios_node_type = 0
Tue Jun 20 15:53:51 2017 us=88815 disable_nbt = DISABLED
Tue Jun 20 15:53:51 2017 us=88815 OpenVPN 2.4.1 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Mar 22 2017
Tue Jun 20 15:53:51 2017 us=88815 Windows version 6.2 (Windows 8 or greater) 64bit
Tue Jun 20 15:53:51 2017 us=88815 library versions: OpenSSL 1.0.2k 26 Jan 2017, LZO 2.09
Enter Management Password:
Tue Jun 20 15:53:51 2017 us=135694 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25341
Tue Jun 20 15:53:51 2017 us=135694 Need hold release from management interface, waiting...
Tue Jun 20 15:53:51 2017 us=604497 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25341
Tue Jun 20 15:53:51 2017 us=713853 MANAGEMENT: CMD 'state on'
Tue Jun 20 15:53:51 2017 us=713853 MANAGEMENT: CMD 'log all on'
Tue Jun 20 15:53:51 2017 us=870107 MANAGEMENT: CMD 'echo all on'
Tue Jun 20 15:53:51 2017 us=870107 MANAGEMENT: CMD 'hold off'
Tue Jun 20 15:53:51 2017 us=870107 MANAGEMENT: CMD 'hold release'
Tue Jun 20 15:54:16 2017 us=637026 MANAGEMENT: CMD 'username "Auth" "code32"'
Tue Jun 20 15:54:16 2017 us=637026 MANAGEMENT: CMD 'password [...]'
Tue Jun 20 15:54:16 2017 us=637026 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Tue Jun 20 15:54:16 2017 us=777659 Control Channel MTU parms [ L:1623 D:1210 EF:40 EB:0 ET:0 EL:3 ]
Tue Jun 20 15:54:16 2017 us=777659 MANAGEMENT: >STATE:1497941656,RESOLVE,,,,,,
Tue Jun 20 15:54:16 2017 us=840164 Data Channel MTU parms [ L:1623 D:1450 EF:123 EB:406 ET:0 EL:3 ]
Tue Jun 20 15:54:16 2017 us=840164 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_CLIENT,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Tue Jun 20 15:54:16 2017 us=840164 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_SERVER,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Tue Jun 20 15:54:16 2017 us=840164 TCP/UDP: Preserving recently used remote address: [AF_INET]152.79.105.11:6937
Tue Jun 20 15:54:16 2017 us=840164 Socket Buffers: R=[65536->65536] S=[65536->65536]
Tue Jun 20 15:54:16 2017 us=840164 Attempting to establish TCP connection with [AF_INET]152.79.105.11:6937 [nonblock]
Tue Jun 20 15:54:16 2017 us=840164 MANAGEMENT: >STATE:1497941656,TCP_CONNECT,,,,,,
Tue Jun 20 15:54:17 2017 us=844220 TCP connection established with [AF_INET]152.79.105.11:6937
Tue Jun 20 15:54:17 2017 us=844220 TCP_CLIENT link local: (not bound)
Tue Jun 20 15:54:17 2017 us=844220 TCP_CLIENT link remote: [AF_INET]152.79.105.11:6937
Tue Jun 20 15:54:17 2017 us=844220 MANAGEMENT: >STATE:1497941657,WAIT,,,,,,
Tue Jun 20 15:54:17 2017 us=844220 TCP_CLIENT WRITE [14] to [AF_INET]152.79.105.11:6937: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Tue Jun 20 15:54:17 2017 us=844220 TCP_CLIENT READ [26] from [AF_INET]152.79.105.11:6937: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Tue Jun 20 15:54:17 2017 us=844220 MANAGEMENT: >STATE:1497941657,AUTH,,,,,,
Tue Jun 20 15:54:17 2017 us=844220 TLS: Initial packet from [AF_INET]152.79.105.11:6937, sid=2cbe30f9 a68b2ba7
Tue Jun 20 15:54:17 2017 us=844220 TCP_CLIENT WRITE [22] to [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 0 ]
Tue Jun 20 15:54:17 2017 us=844220 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Tue Jun 20 15:54:17 2017 us=844220 TCP_CLIENT WRITE [187] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=173
Tue Jun 20 15:54:17 2017 us=891094 TCP_CLIENT READ [1226] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=1200
Tue Jun 20 15:54:17 2017 us=891094 VERIFY OK: depth=0, CN=vpn*.softether.net, O=vpn*.softether.net, OU=vpn*.softether.net, C=US
Tue Jun 20 15:54:17 2017 us=891094 TCP_CLIENT READ [297] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=283
Tue Jun 20 15:54:17 2017 us=891094 TCP_CLIENT WRITE [22] to [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 1 ]
Tue Jun 20 15:54:17 2017 us=891094 TCP_CLIENT WRITE [152] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 2 ] pid=2 DATA len=126
Tue Jun 20 15:54:17 2017 us=938001 TCP_CLIENT READ [77] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 2 ] pid=3 DATA len=51
Tue Jun 20 15:54:17 2017 us=938001 TCP_CLIENT WRITE [465] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 3 ] pid=3 DATA len=439
Tue Jun 20 15:54:17 2017 us=938001 TCP_CLIENT READ [259] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 3 ] pid=4 DATA len=233
Tue Jun 20 15:54:17 2017 us=938001 TCP_CLIENT WRITE [22] to [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 4 ]
Tue Jun 20 15:54:17 2017 us=938001 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Tue Jun 20 15:54:17 2017 us=938001 [vpn*.softether.net] Peer Connection Initiated with [AF_INET]152.79.105.11:6937
Tue Jun 20 15:54:19 2017 us=94285 MANAGEMENT: >STATE:1497941659,GET_CONFIG,,,,,,
Tue Jun 20 15:54:19 2017 us=94285 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:54:19 2017 us=94285 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=42
Tue Jun 20 15:54:19 2017 us=94285 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 4 ]
Tue Jun 20 15:54:24 2017 us=890035 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:54:24 2017 us=890035 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=42
Tue Jun 20 15:54:24 2017 us=890035 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 5 ]
Tue Jun 20 15:54:29 2017 us=359040 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:54:29 2017 us=359040 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=42
Tue Jun 20 15:54:29 2017 us=359040 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 6 ]
Tue Jun 20 15:54:34 2017 us=343647 TCP_CLIENT READ [55] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=41
Tue Jun 20 15:54:34 2017 us=343647 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:54:34 2017 us=343647 AUTH: Received control message: AUTH_FAILED
Tue Jun 20 15:54:34 2017 us=343647 TCP/UDP: Closing socket
Tue Jun 20 15:54:34 2017 us=343647 SIGUSR1[soft,auth-failure] received, process restarting
Tue Jun 20 15:54:34 2017 us=343647 MANAGEMENT: >STATE:1497941674,RECONNECTING,auth-failure,,,,,
Tue Jun 20 15:54:34 2017 us=343647 Restart pause, 5 second(s)
Tue Jun 20 15:54:59 2017 us=504117 MANAGEMENT: CMD 'username "Auth" "code32"'
Tue Jun 20 15:54:59 2017 us=535340 MANAGEMENT: CMD 'password [...]'
Tue Jun 20 15:54:59 2017 us=535340 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Tue Jun 20 15:54:59 2017 us=535340 Re-using SSL/TLS context
Tue Jun 20 15:54:59 2017 us=535340 Control Channel MTU parms [ L:1623 D:1210 EF:40 EB:0 ET:0 EL:3 ]
Tue Jun 20 15:54:59 2017 us=535340 Data Channel MTU parms [ L:1623 D:1450 EF:123 EB:406 ET:0 EL:3 ]
Tue Jun 20 15:54:59 2017 us=535340 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_CLIENT,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Tue Jun 20 15:54:59 2017 us=535340 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_SERVER,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Tue Jun 20 15:54:59 2017 us=535340 TCP/UDP: Preserving recently used remote address: [AF_INET]152.79.105.11:6937
Tue Jun 20 15:54:59 2017 us=535340 Socket Buffers: R=[65536->65536] S=[65536->65536]
Tue Jun 20 15:54:59 2017 us=535340 Attempting to establish TCP connection with [AF_INET]152.79.105.11:6937 [nonblock]
Tue Jun 20 15:54:59 2017 us=535340 MANAGEMENT: >STATE:1497941699,TCP_CONNECT,,,,,,
Tue Jun 20 15:55:00 2017 us=535420 TCP connection established with [AF_INET]152.79.105.11:6937
Tue Jun 20 15:55:00 2017 us=535420 TCP_CLIENT link local: (not bound)
Tue Jun 20 15:55:00 2017 us=535420 TCP_CLIENT link remote: [AF_INET]152.79.105.11:6937
Tue Jun 20 15:55:00 2017 us=535420 MANAGEMENT: >STATE:1497941700,WAIT,,,,,,
Tue Jun 20 15:55:00 2017 us=535420 TCP_CLIENT WRITE [14] to [AF_INET]152.79.105.11:6937: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Tue Jun 20 15:55:00 2017 us=535420 TCP_CLIENT READ [26] from [AF_INET]152.79.105.11:6937: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Tue Jun 20 15:55:00 2017 us=535420 MANAGEMENT: >STATE:1497941700,AUTH,,,,,,
Tue Jun 20 15:55:00 2017 us=535420 TLS: Initial packet from [AF_INET]152.79.105.11:6937, sid=ff028292 c6f67e3c
Tue Jun 20 15:55:00 2017 us=535420 TCP_CLIENT WRITE [22] to [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 0 ]
Tue Jun 20 15:55:00 2017 us=535420 TCP_CLIENT WRITE [187] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=173
Tue Jun 20 15:55:00 2017 us=582297 TCP_CLIENT READ [1226] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=1200
Tue Jun 20 15:55:00 2017 us=582297 VERIFY OK: depth=0, CN=vpn*.softether.net, O=vpn*.softether.net, OU=vpn*.softether.net, C=US
Tue Jun 20 15:55:00 2017 us=582297 TCP_CLIENT READ [297] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=283
Tue Jun 20 15:55:00 2017 us=582297 TCP_CLIENT WRITE [22] to [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 1 ]
Tue Jun 20 15:55:00 2017 us=582297 TCP_CLIENT WRITE [152] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 2 ] pid=2 DATA len=126
Tue Jun 20 15:55:00 2017 us=629151 TCP_CLIENT READ [77] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 2 ] pid=3 DATA len=51
Tue Jun 20 15:55:00 2017 us=629151 TCP_CLIENT WRITE [465] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 3 ] pid=3 DATA len=439
Tue Jun 20 15:55:00 2017 us=644776 TCP_CLIENT READ [259] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 3 ] pid=4 DATA len=233
Tue Jun 20 15:55:00 2017 us=644776 TCP_CLIENT WRITE [22] to [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 4 ]
Tue Jun 20 15:55:00 2017 us=644776 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Tue Jun 20 15:55:00 2017 us=644776 [vpn*.softether.net] Peer Connection Initiated with [AF_INET]152.79.105.11:6937
Tue Jun 20 15:55:01 2017 us=801088 MANAGEMENT: >STATE:1497941701,GET_CONFIG,,,,,,
Tue Jun 20 15:55:01 2017 us=801088 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:55:01 2017 us=801088 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=42
Tue Jun 20 15:55:01 2017 us=801088 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 4 ]
Tue Jun 20 15:55:06 2017 us=426324 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:55:06 2017 us=426324 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=42
Tue Jun 20 15:55:06 2017 us=426324 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 5 ]
Tue Jun 20 15:55:11 2017 us=82926 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:55:11 2017 us=82926 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=42
Tue Jun 20 15:55:11 2017 us=82926 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 6 ]
Tue Jun 20 15:55:16 2017 us=551986 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:55:16 2017 us=551986 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=42
Tue Jun 20 15:55:16 2017 us=551986 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 7 ]
Tue Jun 20 15:55:17 2017 us=833281 TCP_CLIENT READ [55] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=41
Tue Jun 20 15:55:17 2017 us=848902 AUTH: Received control message: AUTH_FAILED
Tue Jun 20 15:55:17 2017 us=848902 TCP/UDP: Closing socket
Tue Jun 20 15:55:17 2017 us=848902 SIGUSR1[soft,auth-failure] received, process restarting
Tue Jun 20 15:55:17 2017 us=848902 MANAGEMENT: >STATE:1497941717,RECONNECTING,auth-failure,,,,,
Tue Jun 20 15:55:17 2017 us=848902 Restart pause, 5 second(s)
Tue Jun 20 15:55:42 2017 us=938274 MANAGEMENT: CMD 'username "Auth" "code32"'
Tue Jun 20 15:55:42 2017 us=969515 MANAGEMENT: CMD 'password [...]'
Tue Jun 20 15:55:42 2017 us=969515 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
Tue Jun 20 15:55:42 2017 us=969515 Re-using SSL/TLS context
Tue Jun 20 15:55:42 2017 us=969515 Control Channel MTU parms [ L:1623 D:1210 EF:40 EB:0 ET:0 EL:3 ]
Tue Jun 20 15:55:42 2017 us=969515 Data Channel MTU parms [ L:1623 D:1450 EF:123 EB:406 ET:0 EL:3 ]
Tue Jun 20 15:55:42 2017 us=969515 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_CLIENT,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
Tue Jun 20 15:55:42 2017 us=969515 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_SERVER,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
Tue Jun 20 15:55:42 2017 us=969515 TCP/UDP: Preserving recently used remote address: [AF_INET]152.79.105.11:6937
Tue Jun 20 15:55:42 2017 us=969515 Socket Buffers: R=[65536->65536] S=[65536->65536]
Tue Jun 20 15:55:42 2017 us=969515 Attempting to establish TCP connection with [AF_INET]152.79.105.11:6937 [nonblock]
Tue Jun 20 15:55:42 2017 us=969515 MANAGEMENT: >STATE:1497941742,TCP_CONNECT,,,,,,
Tue Jun 20 15:55:43 2017 us=969596 TCP connection established with [AF_INET]152.79.105.11:6937
Tue Jun 20 15:55:43 2017 us=969596 TCP_CLIENT link local: (not bound)
Tue Jun 20 15:55:43 2017 us=969596 TCP_CLIENT link remote: [AF_INET]152.79.105.11:6937
Tue Jun 20 15:55:43 2017 us=969596 MANAGEMENT: >STATE:1497941743,WAIT,,,,,,
Tue Jun 20 15:55:43 2017 us=969596 TCP_CLIENT WRITE [14] to [AF_INET]152.79.105.11:6937: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
Tue Jun 20 15:55:43 2017 us=969596 TCP_CLIENT READ [26] from [AF_INET]152.79.105.11:6937: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
Tue Jun 20 15:55:43 2017 us=969596 MANAGEMENT: >STATE:1497941743,AUTH,,,,,,
Tue Jun 20 15:55:43 2017 us=969596 TLS: Initial packet from [AF_INET]152.79.105.11:6937, sid=7bb0b084 4a40d37a
Tue Jun 20 15:55:43 2017 us=969596 TCP_CLIENT WRITE [22] to [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 0 ]
Tue Jun 20 15:55:43 2017 us=969596 TCP_CLIENT WRITE [187] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=173
Tue Jun 20 15:55:44 2017 us=16448 TCP_CLIENT READ [1226] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=1200
Tue Jun 20 15:55:44 2017 us=16448 VERIFY OK: depth=0, CN=vpn*.softether.net, O=vpn*.softether.net, OU=vpn*.softether.net, C=US
Tue Jun 20 15:55:44 2017 us=16448 TCP_CLIENT READ [297] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=283
Tue Jun 20 15:55:44 2017 us=16448 TCP_CLIENT WRITE [22] to [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 1 ]
Tue Jun 20 15:55:44 2017 us=16448 TCP_CLIENT WRITE [152] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 2 ] pid=2 DATA len=126
Tue Jun 20 15:55:44 2017 us=63351 TCP_CLIENT READ [77] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 2 ] pid=3 DATA len=51
Tue Jun 20 15:55:44 2017 us=63351 TCP_CLIENT WRITE [465] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 3 ] pid=3 DATA len=439
Tue Jun 20 15:55:44 2017 us=78976 TCP_CLIENT READ [259] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ 3 ] pid=4 DATA len=233
Tue Jun 20 15:55:44 2017 us=78976 TCP_CLIENT WRITE [22] to [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 4 ]
Tue Jun 20 15:55:44 2017 us=78976 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Tue Jun 20 15:55:44 2017 us=78976 [vpn*.softether.net] Peer Connection Initiated with [AF_INET]152.79.105.11:6937
Tue Jun 20 15:55:45 2017 us=204036 MANAGEMENT: >STATE:1497941745,GET_CONFIG,,,,,,
Tue Jun 20 15:55:45 2017 us=204036 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:55:45 2017 us=204036 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=42
Tue Jun 20 15:55:45 2017 us=204036 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 4 ]
Tue Jun 20 15:55:50 2017 us=829300 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:55:50 2017 us=829300 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=42
Tue Jun 20 15:55:50 2017 us=829300 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 5 ]
Tue Jun 20 15:55:55 2017 us=380269 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:55:55 2017 us=380269 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=42
Tue Jun 20 15:55:55 2017 us=380269 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 6 ]
Tue Jun 20 15:56:00 2017 us=5531 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:56:00 2017 us=5531 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=42
Tue Jun 20 15:56:00 2017 us=5531 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 7 ]
Tue Jun 20 15:56:01 2017 us=99340 TCP_CLIENT READ [55] from [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=41
Tue Jun 20 15:56:01 2017 us=99340 AUTH: Received control message: AUTH_FAILED
Tue Jun 20 15:56:01 2017 us=99340 TCP/UDP: Closing socket
Tue Jun 20 15:56:01 2017 us=99340 SIGUSR1[soft,auth-failure] received, process restarting
Tue Jun 20 15:56:01 2017 us=99340 MANAGEMENT: >STATE:1497941761,RECONNECTING,auth-failure,,,,,
Tue Jun 20 15:56:01 2017 us=99340 Restart pause, 5 second(s)
Tue Jun 20 15:57:13 2017 us=196231 MANAGEMENT: Client disconnected
Tue Jun 20 15:57:13 2017 us=196231 ERROR: could not read Auth username/password/ok/string from management interface
Tue Jun 20 15:57:13 2017 us=196231 Exiting due to fatal error

Posted: **Tue Jun 20, 2017 9:53 am**

以前に貼っていただいた SoftEther VPN Server のログと IP アドレスが異なっているようです。
接続先ホストが正しくないということはないでしょうか。

Posted: **Tue Jun 20, 2017 10:57 am**

cedar wrote:
> 以前に貼っていただいた SoftEther VPN Server のログと IP アドレスが異なっているようです。
> 接続先ホストが正しくないということはないでしょうか。

IPアドレスは、AWS上で

private ip：165.50.110.75

public ip：152.79.105.11

SecureNATでRouting table
165.50.0.0/255.255.0.0/165.50.30.1

このように、ネットワークが構成になっています。

そしてユーザーのログでポートが異なって表示されている部分は、セキュリティ上の理由から、ポートを再書き込みしている間間違って入力された部分です。

サーバーログに記録された部分を見ると、211.155.223.46のユーザーが165.50.110.75接続を試みた部分であり、
ovpnで履歴ログはすぐ152.79.105.11で通信をしようとするとみられています。

私構成される環境は、互いに異なる2つのIP帯域では、VPNサーバーへのアクセスを試みます。

接続先ホストが違うとされた部分は、どの部分をおっしゃるのか、私は理解していませんでした。

確認お願いいたします。

Posted: **Wed Jun 21, 2017 9:37 am**

サーバーのログが一部しか見えていないように思えます。
これはサーバーのログではなく、仮想HUBのログではないかと思います。
仮想 HUB のログには、仮想 HUB が選択される前の部分が記録されません。
接続を行った時刻の server_log の方を確認してみて下さい。

Posted: **Thu Jun 22, 2017 6:47 am**

cedar wrote:
> サーバーのログが一部しか見えていないように思えます。
> これはサーバーのログではなく、仮想HUBのログではないかと思います。
> 仮想 HUB のログには、仮想 HUB が選択される前の部分が記録されません。
> 接続を行った時刻の server_log の方を確認してみて下さい。

こんにちは
サーバーログがあるパスが/ usr / local/ vpnserver/ server_logこの場合ではない？
あるいは管理ツールでManage Virtual Hub - Other Settings - Log file Listパスにあるファイルと、/ usr/ local/ vpnserver/ server_logのファイルの内容が同じです。
このパスがない場合は、サーバーのログ・パスはどこですか？

添付されたファイルは、現在のログ記録の設定です。

回答お願いいたします。

Posted: **Thu Jun 22, 2017 10:09 am**

以前のログがserver_logであれば、接続開始の部分のログを含んでいない部分だったのかもしれません。
OpenVPN で接続を開始した時点のログはないでしょうか。

Posted: **Fri Jun 23, 2017 2:09 am**

cedar wrote:
> 以前のログがserver_logであれば、接続開始の部分のログを含んでいない部分だったのかもしれません。
> OpenVPN で接続を開始した時点のログはないでしょうか。

こんにちは
6月20日に投稿したopenvpn clientログが発生した時点のサーバーのログです。

確認お願いいたします。

ありがとうございます。

Posted: **Fri Jun 23, 2017 9:51 am**

サーバーとクライアントのログを比較してみると、次の2つの行が対応しているようです。

クライアント
Tue Jun 20 15:54:19 2017 us=94285 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)
Tue Jun 20 15:54:24 2017 us=890035 TCP_CLIENT WRITE [56] to [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=42
Tue Jun 20 15:54:24 2017 us=890035 TCP_CLIENT READ [22] from [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 5 ]

サーバー
2017-06-20 15:53:39.655 OpenVPN Session 1 (211.215.123.46:49319 -> 162.30.100.75:6939) Channel 2: Option Strings Received: "V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_CLIENT,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client"

しかし、サーバーがすぐに応答しているはずの Option String をクライアント側は受信できていないようです。
2017-06-20 15:53:39.655 OpenVPN Session 1 (211.215.123.46:49319 -> 162.30.100.75:6939) Channel 2: Option Strings to Send: "V4,dev-type tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_SERVER,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server"

サーバーの応答が5秒間なかったので、クライアントは PUSH_REQUEST をリトライしていますが、サーバー側にはこれに対応するログは残っていません。
Tue Jun 20 15:54:24 2017 us=890035 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST' (status=1)

通信開始から、1 秒ほどで相互に通信できない状態になっているようです。

使用しているクライアントのプロトコルが SoftEther VPN と互換性のないものかもしれません。
試したすべての Windows と MAC で同じようなログが残っているでしょうか。

Posted: **Tue Jun 27, 2017 2:01 am**

cedar wrote:
> サーバーとクライアントのログを比較してみると、次の2つの行が対応しているようです。
>
> クライアント
> Tue Jun 20 15:54:19 2017 us=94285 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST'
> (status=1)
> Tue Jun 20 15:54:24 2017 us=890035 TCP_CLIENT WRITE [56] to
> [AF_INET]152.79.105.11:6937: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=42
> Tue Jun 20 15:54:24 2017 us=890035 TCP_CLIENT READ [22] from
> [AF_INET]152.79.105.11:6937: P_ACK_V1 kid=0 [ 5 ]
>
> サーバー
> 2017-06-20 15:53:39.655 OpenVPN Session 1 (211.215.123.46:49319 ->
> 162.30.100.75:6939) Channel 2: Option Strings Received: "V4,dev-type
> tun,link-mtu 1559,tun-mtu 1500,proto TCPv4_CLIENT,cipher AES-128-CBC,auth
> SHA1,keysize 128,key-method 2,tls-client"
>
> しかし、サーバーがすぐに応答しているはずの Option String をクライアント側は受信できていないようです。
> 2017-06-20 15:53:39.655 OpenVPN Session 1 (211.215.123.46:49319 ->
> 162.30.100.75:6939) Channel 2: Option Strings to Send: "V4,dev-type tun,link-mtu
> 1559,tun-mtu 1500,proto TCPv4_SERVER,cipher AES-128-CBC,auth SHA1,keysize
> 128,key-method 2,tls-server"
>
> サーバーの応答が5秒間なかったので、クライアントは PUSH_REQUEST をリトライしていますが、サーバー側にはこれに対応するログは残っていません。
> Tue Jun 20 15:54:24 2017 us=890035 SENT CONTROL [vpn*.softether.net]: 'PUSH_REQUEST'
> (status=1)
>
> 通信開始から、1 秒ほどで相互に通信できない状態になっているようです。
>
> 使用しているクライアントのプロトコルが SoftEther VPN と互換性のないものかもしれません。
> 試したすべての Windows と MAC で同じようなログが残っているでしょうか。

他のユーザーのPCでも同じログが発生をしています。
プロトコルが異なることもあるとましたがその後の措置は、どのように進めなければならでしょうか？

SoftEtherVPN Server Manager - OpenVPN/ MS-SSTP Settingでovpnファイルをダウンロードしてprotoのみudpでtcpへの変更をしました。

政策上udpでの使用を難しくtcpでの使用をしています。

この現象の対策案はどの部分でしょうか？

Posted: **Tue Jun 27, 2017 2:03 am**

他の OpenVPN アプリケーションに変えてみてはいかがでしょうか。

Posted: **Wed Jun 28, 2017 8:34 am**

cedar wrote:
> 他の OpenVPN アプリケーションに変えてみてはいかがでしょうか。

こんにちは
上記の事項について返信をいただきありがとうございます。

他のopenvpnを使用されるということはsoftether vpn clientのみ接続しなければならんですか？

今使用中のopenvpnとして使用案はないですか？

Posted: **Wed Jun 28, 2017 8:53 am**

いま使用している OpenVPN ソフトは何でしょうか。

Posted: **Wed Jun 28, 2017 9:01 am**

cedar wrote:
> いま使用している OpenVPN ソフトは何でしょうか。

https://openvpn.net/
ここでclientを受けて使用しています。

Posted: **Wed Jun 28, 2017 10:04 am**

そこで配布されている最新の Windows 版クライアントからは正常に接続できるようです。

VPN サーバーまたはクライアントの利用環境では、何かOpenVPNの通信を妨げる可能性のあるファイアウオールなどが設置されていないでしょうか。

SoftEther VPN User Forum

vpn接続失敗現象に関するお問合せください。

vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。

Re: vpn接続失敗現象に関するお問合せください。