9.4.4. ON VPNGW Logs
Within the VPNGW node we can find a large number of logs that can help us understand or detect errors that may arise during system operation.
9.4.4.1. WireGuard Logs
This log contains information related to each of the WireGuard type VPNs created in the VPN Gateway node. Each VPN will have its own log.
Path:
/var/log/opennac/wireguard/wireguard.log
Example:
September 13 23:01:42 [wg_purge_peers] [10.21.65.42] Disconnection notification sent to opennac node. [IP: 172.16.120.7, MAC: C8:D3:FF:42:14:40, UserName: user1, Dynamic zone: vpnusr, Latest handshake: 185 seconds ago, Public Key: MQG1E/xLa8yhmp4F2vTaRiEIthJVfOkYGAYX+AUHzFs=]
Sep 14 15:37:16 vpngwqa1 api: Agent user connected (VPN IP: 172.16.120.8; Username: user1; Dynamic Zone: vpnusr)
Sep 14 15:40:23 vpngwqa1 api: User disconnected from Opennac (VPN IP: 172.16.120.8; Username: user1; Dynamic Zone: vpnusr)
Sep 14 17:18:32 vpngwqa1 api: Agent user connected (VPN IP: 172.16.120.9; Username: user1; Dynamic Zone: vpnusr)
Sep 14 17:19:13 vpngwqa1 api: User disconnected from Opennac (VPN IP: 172.16.120.9; Username: user1; Dynamic Zone: vpnusr)
Sep 15 09:14:59 vpngwqa1 api: Agent user connected (VPN IP: 172.16.120.10; Username: user1; Dynamic Zone: vpnusr)
Sep 15 09:16:30 vpngwqa1 api: User disconnected from Opennac (VPN IP: 172.16.120.10; Username: user1; Dynamic Zone: vpnusr)
Sep 21 12:26:11 vpngwqa1 api: Agent user connected (VPN IP: 172.16.120.1; Username: inigo.zarandona; Dynamic Zone: vpnusr)
Sep 21 12:28:56 vpngwqa1 api: User disconnected from Opennac (VPN IP: 172.16.120.1; Username: inigo.zarandona; Dynamic Zone: vpnusr)
Sep 26 16:08:07 vpngwqa1 api: Agent user connected (VPN IP: 172.16.120.2; Username: user1; Dynamic Zone: vpnusr)
September 26 16:08:20 [wg_purge_peers] Trying to disconnect peer: [IP: 172.16.120.2, Latest handshake: NO latest handshake yet, Public Key: RZ4bsBdcrA8A4hRK1W6JQQeWCzaOvK9F7r5Wouy6Sng=]. Reason: Latest handshake is not valid
September 26 16:08:20 [wg_purge_peers] [10.21.65.43] Disconnection notification sent to opennac node. [IP: 172.16.120.2, MAC: A4:D1:8C:D6:7F:F6, UserName: user1, Dynamic zone: vpnusr, Latest handshake: NO latest handshake yet, Public Key: RZ4bsBdcrA8A4hRK1W6JQQeWCzaOvK9F7r5Wouy6Sng=]
Sep 28 12:13:07 vpngwqa1 api: Agent user connected (VPN IP: 172.16.120.1; Username: user1; Dynamic Zone: vpnusr)
Sep 28 12:13:23 vpngwqa1 api: User disconnected from Opennac Toggle Port (VPN IP: 172.16.120.1; Username: user1; Dynamic Zone: vpnusr)
Sep 28 16:07:49 vpngwqa1 api: Agent user connected (VPN IP: 172.16.120.2; Username: user1; Dynamic Zone: vpnusr)
September 28 16:08:03 [wg_purge_peers] Trying to disconnect peer: [IP: 172.16.120.2, Latest handshake: NO latest handshake yet, Public Key: gFDhtZroLD2CwoywKZMNT7aFtFIE9YPOzzbNgEhCY0w=]. Reason: Latest handshake is not valid
September 28 16:08:04 [wg_purge_peers] [10.21.65.42] Disconnection notification sent to opennac node. [IP: 172.16.120.2, MAC: CA:FE:CA:FE:CA:FE, UserName: user1, Dynamic zone: vpnusr, Latest handshake: NO latest handshake yet, Public Key: gFDhtZroLD2CwoywKZMNT7aFtFIE9YPOzzbNgEhCY0w=]
Sep 28 17:30:23 vpngwqa1 api: Agent user connected (VPN IP: 172.16.120.3; Username: user1; Dynamic Zone: vpnusr)
September 28 17:30:37 [wg_purge_peers] Trying to disconnect peer: [IP: 172.16.120.3, Latest handshake: NO latest handshake yet, Public Key: bftf3cZskHfVimTj832J9xzYR/RAdrhFNzX7BUt38mE=]. Reason: Latest handshake is not valid
September 28 17:30:38 [wg_purge_peers] [10.21.65.42] Disconnection notification sent to opennac node. [IP: 172.16.120.3, MAC: F8:FF:C2:5A:4E:B5, UserName: user1, Dynamic zone: vpnusr, Latest handshake: NO latest handshake yet, Public Key: bftf3cZskHfVimTj832J9xzYR/RAdrhFNzX7BUt38mE=]
Sep 28 21:20:41 vpngwqa1 api: Agent user connected (VPN IP: 172.16.120.4; Username: user1; Dynamic Zone: vpnusr)
September 28 21:21:01 [wg_purge_peers] Trying to disconnect peer: [IP: 172.16.120.4, Latest handshake: NO latest handshake yet, Public Key: xFvTNjtlJ4ujPCP5lTnTCXtr3PHfIXbNd3rlOUV72U8=]. Reason: Latest handshake is not valid
September 28 21:21:02 [wg_purge_peers] [10.21.65.42] Disconnection notification sent to opennac node. [IP: 172.16.120.4, MAC: F8:FF:C2:5A:4E:B5, UserName: user1, Dynamic zone: vpnusr, Latest handshake: NO latest handshake yet, Public Key: xFvTNjtlJ4ujPCP5lTnTCXtr3PHfIXbNd3rlOUV72U8=]
9.4.4.2. opennac-delay.log
This log calculates the time it takes to establish a new connection and disconnect a VPN user using the WireGuard protocol.
Note
It is necessary to uncomment the line //define(‘DUMP_PERF_DATA’,true) in vim /usr/share/opennac/api/public/index.php to enable this log.
Path:
/var/log/opennac/opennac-delay.log
Example:
Sep 18 13:50:45 onprincipal opennac-delay[83182]: [wg-peer][wg-plugin][User: ] Send curl to firewall in disconnect: 0.298 seconds
Sep 18 13:50:45 onprincipal opennac-delay[83182]: [wg-peer][wg-plugin] TOTAL Disconnect wireguard: 0.304 seconds
Sep 18 13:51:50 onprincipal opennac-delay[83197]: [wg-peer][wg-plugin][User: emmaabs] Send curl to firewall in connect: 0.354 seconds
Sep 18 13:51:50 onprincipal opennac-delay[83197]: [wg-peer][wg-plugin] TOTAL Connect wireguard: 0.366 seconds
Sep 18 13:57:11 onprincipal opennac-delay[83206]: [wg-peer][wg-plugin][User: ] Send curl to firewall in disconnect: 0.298 seconds
Sep 18 13:57:11 onprincipal opennac-delay[83206]: [wg-peer][wg-plugin] TOTAL Disconnect wireguard: 0.303 seconds
Sep 18 13:57:22 onprincipal opennac-delay[83207]: [wg-peer][wg-plugin][User: emmaabs] Send curl to firewall in connect: 0.373 seconds
Sep 18 13:57:22 onprincipal opennac-delay[83207]: [wg-peer][wg-plugin] TOTAL Connect wireguard: 0.389 seconds
9.4.4.3. messages.log
This log contains global system messages such as the system error messages, system startups and shutdowns, change in the network configuration, etc.
Path:
/var/log/messages
Example:
Mar 8 06:26:01 LAB0oncore auditd[1432]: Audit daemon rotating log files
Mar 8 06:40:09 LAB0oncore named[1531]: managed-keys-zone ./IN/registry: Failed to create fetch for DNSKEY update
9.4.4.4. firewall.log
This log contains information related to the firewall rules matched.
Path:
/var/log/firewall.log
Example:
534 DF PROTO=TCP SPT=36196 DPT=443 WINDOW=29200 RES=0x00 SYN URGP=0
Oct 9 19:27:46 fwqa001 kernel: FW: fw-FWCorp ACCEPT IN= OUT=eth0 SRC=10.250.102.104 DST=10.10.36.43 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=6611 DF PROTO=TCP SPT=36198 DPT=443 WINDOW=29200 RES=0x00 SYN URGP=0
Oct 9 19:27:46 fwqa001 kernel: FW: fw-FWCorp ACCEPT IN= OUT=eth0 SRC=10.250.102.104 DST=10.10.36.43 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=58176 DF PROTO=TCP SPT=36200 DPT=443 WINDOW=29200 RES=0x00 SYN URGP=0
Oct 9 19:27:47 fwqa001 kernel: FW: fw-FWCorp ACCEPT IN= OUT=eth0 SRC=10.250.102.104 DST=10.250.102.103 LEN=943 TOS=0x00 PREC=0x00 TTL=128 ID=42218 DF PROTO=UDP SPT=58809 DPT=2003 LEN=923
Oct 9 19:27:47 fwqa001 kernel: FW: fw-FWCorp ACCEPT IN= OUT=eth0 SRC=10.250.102.104 DST=10.250.102.103 LEN=910 TOS=0x00 PREC=0x00 TTL=128 ID=42219 DF PROTO=UDP SPT=58809 DPT=2003 LEN=890
9.4.4.5. yum.log
This log contains information related to the update process.
Path:
/var/log/yum.log
May 26 16:31:35 Updated: 1:java-1.8.0-openjdk-devel-1.8.0.332.b09-1.el7_9.x86_64
May 26 16:31:36 Updated: 32:bind-export-libs-9.11.4-26.P2.el7_9.9.x86_64
May 26 16:31:36 Updated: gtk-update-icon-cache-3.22.30-8.el7_9.x86_64
May 26 16:31:36 Updated: python-perf-3.10.0-1160.66.1.el7.x86_64
May 26 16:31:36 Updated: 14:libpcap-1.5.3-13.el7_9.x86_64
May 26 16:31:37 Updated: gzip-1.5-11.el7_9.x86_64
May 26 16:31:43 Installed: kernel-3.10.0-1160.66.1.el7.x86_64