Project

General

Profile

Download (38.1 KB)

Bug #7905 » openvpn-auth-script-test.log

Full server process log - partially redacted (UTC) - Phil DeMonaco, 02/23/2018 04:05 PM

 
1 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: MANAGEMENT: unix domain socket listening on /var/etc/openvpn/server2.sock
2 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
3 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: PLUGIN_INIT: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so '[/usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so] [/usr/local/sbin/ovpn_auth_verify_async] [user] [YmYwX2R1bzAw] [false] [server2] [1195]' intercepted=PLUGIN_AUTH_USER_PASS_VERIFY
4 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: Diffie-Hellman initialized with 2048 bit key
5 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: TLS-Auth MTU parms [ L:1621 D:1212 EF:38 EB:0 ET:0 EL:3 ]
6 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: TUN/TAP device ovpns2 exists previously, keep at program end
7 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: TUN/TAP device /dev/tun2 opened
8 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: do_ifconfig, tt->did_ifconfig_ipv6_setup=0
9 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: /sbin/ifconfig ovpns2 172.29.128.1 172.29.128.2 mtu 1500 netmask 255.255.255.128 up
10 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: /sbin/route add -net 172.29.128.0 172.29.128.2 255.255.255.128
11 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: /usr/local/sbin/ovpn-linkup ovpns2 1500 1621 172.29.128.1 255.255.255.128 init
12 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
13 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: Socket Buffers: R=[42080->42080] S=[57344->57344]
14 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: UDPv4 link local (bound): [AF_INET]40.142.36.20:1195
15 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: UDPv4 link remote: [AF_UNSPEC]
16 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: MULTI: multi_init called, r=256 v=256
17 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: IFCONFIG POOL: base=172.29.128.2 size=124, ipv6=0
18 
Feb 23 21:01:58 d0-nfw2533 openvpn[29675]: Initialization Sequence Completed
19 
Feb 23 21:02:03 d0-nfw2533 openvpn[29675]: MANAGEMENT: Client connected from /var/etc/openvpn/server2.sock
20 
Feb 23 21:02:03 d0-nfw2533 openvpn[29675]: MANAGEMENT: CMD 'status 2'
21 
Feb 23 21:02:03 d0-nfw2533 openvpn[29675]: MANAGEMENT: Client disconnected
22 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: MULTI: multi_create_instance called
23 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 Re-using SSL/TLS context
24 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 Control Channel MTU parms [ L:1621 D:1212 EF:38 EB:0 ET:0 EL:3 ]
25 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
26 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
27 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
28 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [14] from [AF_INET]<client-ip>:46072: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
29 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 TLS: Initial packet from [AF_INET]<client-ip>:46072, sid=8885966c 8c782160
30 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [26] to [AF_INET]<client-ip>:46072: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
31 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [22] from [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 0 ]
32 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [187] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=173
33 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [1200] to [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=1174
34 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [1188] to [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
35 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [1188] to [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=1174
36 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [510] to [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=496
37 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [22] from [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 1 ]
38 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [22] from [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 2 ]
39 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [22] from [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 3 ]
40 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [152] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ 4 ] pid=2 DATA len=126
41 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [77] to [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ 2 ] pid=5 DATA len=51
42 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [453] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ 5 ] pid=3 DATA len=427
43 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 peer info: IV_VER=2.4.4
44 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 peer info: IV_PLAT=freebsd
45 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 peer info: IV_PROTO=2
46 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 peer info: IV_NCP=2
47 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 peer info: IV_LZ4=1
48 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 peer info: IV_LZ4v2=1
49 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 peer info: IV_LZO=1
50 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 peer info: IV_COMP_STUB=1
51 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 peer info: IV_COMP_STUBv2=1
52 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 peer info: IV_TCPNL=1
53 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
54 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 TLS: Username/Password authentication deferred for username '<client-user>' [CN SET]
55 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [252] to [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ 3 ] pid=6 DATA len=226
56 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [22] from [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 6 ]
57 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384
58 
Feb 23 21:02:31 d0-nfw2533 openvpn[29675]: <client-ip>:46072 [<client-user>] Peer Connection Initiated with [AF_INET]<client-ip>:46072
59 
Feb 23 21:02:32 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [56] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=42
60 
Feb 23 21:02:32 d0-nfw2533 openvpn[29675]: <client-ip>:46072 PUSH: Received control message: 'PUSH_REQUEST'
61 
Feb 23 21:02:32 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [22] to [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 4 ]
62 
Feb 23 21:02:37 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [56] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=42
63 
Feb 23 21:02:37 d0-nfw2533 openvpn[29675]: <client-ip>:46072 PUSH: Received control message: 'PUSH_REQUEST'
64 
Feb 23 21:02:37 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [22] to [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 5 ]
65 
Feb 23 21:02:42 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [56] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=42
66 
Feb 23 21:02:42 d0-nfw2533 openvpn[29675]: <client-ip>:46072 PUSH: Received control message: 'PUSH_REQUEST'
67 
Feb 23 21:02:42 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [22] to [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 6 ]
68 
Feb 23 21:02:47 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [56] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=42
69 
Feb 23 21:02:47 d0-nfw2533 openvpn[29675]: <client-ip>:46072 PUSH: Received control message: 'PUSH_REQUEST'
70 
Feb 23 21:02:47 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [22] to [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 7 ]
71 
Feb 23 21:02:52 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [56] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=42
72 
Feb 23 21:02:52 d0-nfw2533 openvpn[29675]: <client-ip>:46072 PUSH: Received control message: 'PUSH_REQUEST'
73 
Feb 23 21:02:52 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [22] to [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 8 ]
74 
Feb 23 21:02:58 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [56] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=42
75 
Feb 23 21:02:58 d0-nfw2533 openvpn[29675]: <client-ip>:46072 PUSH: Received control message: 'PUSH_REQUEST'
76 
Feb 23 21:02:58 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [22] to [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 9 ]
77 
Feb 23 21:03:03 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 READ [56] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=42
78 
Feb 23 21:03:03 d0-nfw2533 openvpn[29675]: <client-ip>:46072 PUSH: Received control message: 'PUSH_REQUEST'
79 
Feb 23 21:03:03 d0-nfw2533 openvpn[29675]: <client-ip>:46072 UDPv4 WRITE [22] to [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 10 ]
80 
Feb 23 21:03:04 d0-nfw2533 openvpn[29675]: event_wait : Interrupted system call (code=4)
81 
Feb 23 21:03:08 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:46072 MULTI_sva: pool returned IPv4=172.29.128.2, IPv6=(Not enabled)
82 
Feb 23 21:03:08 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:46072 WARNING: Failed running command (--client-connect): external program fork failed
83 
Feb 23 21:03:08 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:46072 UDPv4 READ [56] from [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=42
84 
Feb 23 21:03:08 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:46072 PUSH: Received control message: 'PUSH_REQUEST'
85 
Feb 23 21:03:08 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:46072 Delayed exit in 5 seconds
86 
Feb 23 21:03:08 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:46072 SENT CONTROL [<client-user>]: 'AUTH_FAILED' (status=1)
87 
Feb 23 21:03:08 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:46072 UDPv4 WRITE [22] to [AF_INET]<client-ip>:46072: P_ACK_V1 kid=0 [ 11 ]
88 
Feb 23 21:03:08 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:46072 UDPv4 WRITE [55] to [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=41
89 
Feb 23 21:03:10 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:46072 UDPv4 WRITE [55] to [AF_INET]<client-ip>:46072: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=41
90 
Feb 23 21:03:13 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:46072 SIGTERM[soft,delayed-exit] received, client-instance exiting
91 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: MULTI: multi_create_instance called
92 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Re-using SSL/TLS context
93 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Control Channel MTU parms [ L:1621 D:1212 EF:38 EB:0 ET:0 EL:3 ]
94 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
95 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
96 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
97 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [14] from [AF_INET]<client-ip>:43518: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
98 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 TLS: Initial packet from [AF_INET]<client-ip>:43518, sid=793910da ae628e12
99 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [26] to [AF_INET]<client-ip>:43518: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
100 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 0 ]
101 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [187] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=173
102 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1200] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=1174
103 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1188] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
104 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1188] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=1174
105 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [510] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=496
106 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 1 ]
107 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 2 ]
108 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 3 ]
109 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [152] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 4 ] pid=2 DATA len=126
110 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [77] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 2 ] pid=5 DATA len=51
111 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [453] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 5 ] pid=3 DATA len=427
112 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_VER=2.4.4
113 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_PLAT=freebsd
114 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_PROTO=2
115 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_NCP=2
116 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZ4=1
117 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZ4v2=1
118 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZO=1
119 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_COMP_STUB=1
120 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_COMP_STUBv2=1
121 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_TCPNL=1
122 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
123 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 TLS: Username/Password authentication deferred for username '<client-user>' [CN SET]
124 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [252] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 3 ] pid=6 DATA len=226
125 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 6 ]
126 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384
127 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: <client-ip>:43518 [<client-user>] Peer Connection Initiated with [AF_INET]<client-ip>:43518
128 
Feb 23 21:09:38 d0-nfw2533 openvpn[29675]: event_wait : Interrupted system call (code=4)
129 
Feb 23 21:09:39 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=42
130 
Feb 23 21:09:39 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
131 
Feb 23 21:09:39 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Delayed exit in 5 seconds
132 
Feb 23 21:09:39 d0-nfw2533 openvpn[29675]: <client-ip>:43518 SENT CONTROL [<client-user>]: 'AUTH_FAILED' (status=1)
133 
Feb 23 21:09:39 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 4 ]
134 
Feb 23 21:09:39 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [55] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=41
135 
Feb 23 21:09:42 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [55] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=41
136 
Feb 23 21:09:44 d0-nfw2533 openvpn[29675]: <client-ip>:43518 SIGTERM[soft,delayed-exit] received, client-instance exiting
137 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: MULTI: multi_create_instance called
138 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Re-using SSL/TLS context
139 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Control Channel MTU parms [ L:1621 D:1212 EF:38 EB:0 ET:0 EL:3 ]
140 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
141 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
142 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
143 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [14] from [AF_INET]<client-ip>:43518: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
144 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 TLS: Initial packet from [AF_INET]<client-ip>:43518, sid=516cb433 68ed6f92
145 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [26] to [AF_INET]<client-ip>:43518: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
146 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 0 ]
147 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [187] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=173
148 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1200] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=1174
149 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1188] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
150 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1188] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=1174
151 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [510] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=496
152 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 1 ]
153 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 2 ]
154 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 3 ]
155 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [152] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 4 ] pid=2 DATA len=126
156 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [77] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 2 ] pid=5 DATA len=51
157 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [454] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 5 ] pid=3 DATA len=428
158 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_VER=2.4.4
159 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_PLAT=freebsd
160 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_PROTO=2
161 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_NCP=2
162 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZ4=1
163 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZ4v2=1
164 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZO=1
165 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_COMP_STUB=1
166 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_COMP_STUBv2=1
167 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_TCPNL=1
168 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
169 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 TLS: Username/Password authentication deferred for username '<client-user>' [CN SET]
170 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [252] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 3 ] pid=6 DATA len=226
171 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 6 ]
172 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384
173 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: <client-ip>:43518 [<client-user>] Peer Connection Initiated with [AF_INET]<client-ip>:43518
174 
Feb 23 21:10:06 d0-nfw2533 openvpn[29675]: event_wait : Interrupted system call (code=4)
175 
Feb 23 21:10:07 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=42
176 
Feb 23 21:10:07 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
177 
Feb 23 21:10:07 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Delayed exit in 5 seconds
178 
Feb 23 21:10:07 d0-nfw2533 openvpn[29675]: <client-ip>:43518 SENT CONTROL [<client-user>]: 'AUTH_FAILED' (status=1)
179 
Feb 23 21:10:07 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 4 ]
180 
Feb 23 21:10:07 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [55] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=41
181 
Feb 23 21:10:10 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [55] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=41
182 
Feb 23 21:10:12 d0-nfw2533 openvpn[29675]: <client-ip>:43518 SIGTERM[soft,delayed-exit] received, client-instance exiting
183 
Feb 23 21:10:14 d0-nfw2533 openvpn[29675]: MULTI: multi_create_instance called
184 
Feb 23 21:10:14 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Re-using SSL/TLS context
185 
Feb 23 21:10:14 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Control Channel MTU parms [ L:1621 D:1212 EF:38 EB:0 ET:0 EL:3 ]
186 
Feb 23 21:10:14 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
187 
Feb 23 21:10:14 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-server'
188 
Feb 23 21:10:14 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,cipher AES-128-CBC,auth SHA1,keysize 128,key-method 2,tls-client'
189 
Feb 23 21:10:14 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [14] from [AF_INET]<client-ip>:43518: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
190 
Feb 23 21:10:14 d0-nfw2533 openvpn[29675]: <client-ip>:43518 TLS: Initial packet from [AF_INET]<client-ip>:43518, sid=47e7d642 44b4b369
191 
Feb 23 21:10:14 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [26] to [AF_INET]<client-ip>:43518: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
192 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 0 ]
193 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [187] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=173
194 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1200] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=1174
195 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1188] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
196 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1188] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=1174
197 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [510] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=496
198 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 1 ]
199 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 2 ]
200 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 3 ]
201 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [152] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 4 ] pid=2 DATA len=126
202 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [77] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 2 ] pid=5 DATA len=51
203 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [453] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 5 ] pid=3 DATA len=427
204 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_VER=2.4.4
205 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_PLAT=freebsd
206 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_PROTO=2
207 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_NCP=2
208 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZ4=1
209 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZ4v2=1
210 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZO=1
211 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_COMP_STUB=1
212 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_COMP_STUBv2=1
213 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_TCPNL=1
214 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
215 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 TLS: Username/Password authentication deferred for username '<client-user>' [CN SET]
216 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [252] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 3 ] pid=6 DATA len=226
217 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 6 ]
218 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384
219 
Feb 23 21:10:15 d0-nfw2533 openvpn[29675]: <client-ip>:43518 [<client-user>] Peer Connection Initiated with [AF_INET]<client-ip>:43518
220 
Feb 23 21:10:16 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=42
221 
Feb 23 21:10:16 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
222 
Feb 23 21:10:16 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 4 ]
223 
Feb 23 21:10:21 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=42
224 
Feb 23 21:10:21 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
225 
Feb 23 21:10:21 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 5 ]
226 
Feb 23 21:10:26 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=42
227 
Feb 23 21:10:26 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
228 
Feb 23 21:10:26 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 6 ]
229 
Feb 23 21:10:31 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=42
230 
Feb 23 21:10:31 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
231 
Feb 23 21:10:31 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 7 ]
232 
Feb 23 21:10:36 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=8 DATA len=42
233 
Feb 23 21:10:36 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
234 
Feb 23 21:10:36 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 8 ]
235 
Feb 23 21:10:42 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=9 DATA len=42
236 
Feb 23 21:10:42 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
237 
Feb 23 21:10:42 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 9 ]
238 
Feb 23 21:10:47 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=10 DATA len=42
239 
Feb 23 21:10:47 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
240 
Feb 23 21:10:47 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 10 ]
241 
Feb 23 21:10:52 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=11 DATA len=42
242 
Feb 23 21:10:52 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
243 
Feb 23 21:10:52 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 11 ]
244 
Feb 23 21:10:57 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=12 DATA len=42
245 
Feb 23 21:10:57 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
246 
Feb 23 21:10:57 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 12 ]
247 
Feb 23 21:11:03 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=13 DATA len=42
248 
Feb 23 21:11:03 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
249 
Feb 23 21:11:03 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 13 ]
250 
Feb 23 21:11:08 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=14 DATA len=42
251 
Feb 23 21:11:08 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
252 
Feb 23 21:11:08 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 14 ]
253 
Feb 23 21:11:13 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=15 DATA len=42
254 
Feb 23 21:11:13 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
255 
Feb 23 21:11:13 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 15 ]
256 
Feb 23 21:11:14 d0-nfw2533 openvpn[29675]: event_wait : Interrupted system call (code=4)
257 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [14] from [AF_INET]<client-ip>:43518: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 [ ] pid=0 DATA len=0
258 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 TLS: new session incoming connection from [AF_INET]<client-ip>:43518
259 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [26] to [AF_INET]<client-ip>:43518: P_CONTROL_HARD_RESET_SERVER_V2 kid=0 [ 0 ] pid=0 DATA len=0
260 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 0 ]
261 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [187] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=1 DATA len=173
262 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1200] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 1 ] pid=1 DATA len=1174
263 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1188] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=2 DATA len=1174
264 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [1188] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=3 DATA len=1174
265 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [510] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=496
266 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 1 ]
267 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 2 ]
268 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 3 ]
269 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [152] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 4 ] pid=2 DATA len=126
270 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [77] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 2 ] pid=5 DATA len=51
271 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [453] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 5 ] pid=3 DATA len=427
272 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_VER=2.4.4
273 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_PLAT=freebsd
274 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_PROTO=2
275 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_NCP=2
276 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZ4=1
277 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZ4v2=1
278 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_LZO=1
279 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_COMP_STUB=1
280 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_COMP_STUBv2=1
281 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 peer info: IV_TCPNL=1
282 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PLUGIN_CALL: POST /usr/local/lib/openvpn/plugins/openvpn-plugin-auth-script.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
283 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 TLS: Username/Password authentication deferred for username '<client-user>' [CN SET]
284 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 TLS: move_session: dest=TM_ACTIVE src=TM_UNTRUSTED reinit_src=1
285 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 TLS: tls_multi_process: untrusted session promoted to semi-trusted
286 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [252] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ 3 ] pid=6 DATA len=226
287 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [22] from [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 6 ]
288 
Feb 23 21:11:23 d0-nfw2533 openvpn[29675]: <client-ip>:43518 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384
289 
Feb 23 21:11:24 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=4 DATA len=42
290 
Feb 23 21:11:24 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
291 
Feb 23 21:11:24 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 4 ]
292 
Feb 23 21:11:28 d0-nfw2533 openvpn[29675]: event_wait : Interrupted system call (code=4)
293 
Feb 23 21:11:29 d0-nfw2533 openvpn[29675]: <client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=5 DATA len=42
294 
Feb 23 21:11:29 d0-nfw2533 openvpn[29675]: <client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
295 
Feb 23 21:11:29 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 MULTI_sva: pool returned IPv4=172.29.128.2, IPv6=(Not enabled)
296 
Feb 23 21:11:29 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 WARNING: Failed running command (--client-connect): external program fork failed
297 
Feb 23 21:11:29 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 5 ]
298 
Feb 23 21:11:35 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 UDPv4 READ [56] from [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=6 DATA len=42
299 
Feb 23 21:11:35 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 PUSH: Received control message: 'PUSH_REQUEST'
300 
Feb 23 21:11:35 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 Delayed exit in 5 seconds
301 
Feb 23 21:11:35 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 SENT CONTROL [<client-user>]: 'AUTH_FAILED' (status=1)
302 
Feb 23 21:11:35 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 UDPv4 WRITE [22] to [AF_INET]<client-ip>:43518: P_ACK_V1 kid=0 [ 6 ]
303 
Feb 23 21:11:35 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 UDPv4 WRITE [55] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=41
304 
Feb 23 21:11:37 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 UDPv4 WRITE [55] to [AF_INET]<client-ip>:43518: P_CONTROL_V1 kid=0 [ ] pid=7 DATA len=41
305 
Feb 23 21:11:40 d0-nfw2533 openvpn[29675]: <client-user>/<client-ip>:43518 SIGTERM[soft,delayed-exit] received, client-instance exiting
(2-2/4)