write TCPv4_CLIENT: Permission Denied on OpenVPN client 24.03 RC
-
No outbound blocking rule
-
Do you see any blocked traffic in the firewall logs for whatever port that connection is using?
Permission denied like that pretty much has to be something blocking it locally.
-
Hi Steve,
In addition to the OvenVPN TCP Client issue "write TCPv4_CLIENT: Permission denied (fd=5,code=13)",
Few things I noticed after migrating to 24.03 are
- Frequent WAN disconnect issues
- Not able to login through GUI using Firefox
For the time being, I have reverted to 23.09.1. All the above issues are gone.
I will change back to 24.03 and share the firewall logs for any blocking info.
Thanks.
-
Hi Steve,
I see the below WAN IP address changes. I have dual WAN with static IP for each WAN. Is the below contributing towards the TCP write error on 24.03? I could not find any block messages in the System Logs.Apr 25 20:38:37 trail2 php-fpm[59831]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.35.
Apr 25 20:37:36 trail2 php-fpm[31573]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.3.
Apr 25 20:36:25 trail2 php-fpm[59831]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.36.
Apr 25 20:35:25 trail2 php-fpm[556]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.2.
Apr 25 20:34:35 trail2 php-fpm[94728]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.7.7.4.
Apr 25 20:34:14 trail2 php-fpm[60193]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.35.
Apr 25 20:33:13 trail2 php-fpm[60193]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.3.
Apr 25 20:32:04 trail2 php-fpm[60193]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.36.
Apr 25 20:31:03 trail2 php-fpm[59831]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.2.
Apr 25 20:30:10 trail2 php-fpm[555]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.7.7.5.
Apr 25 20:29:53 trail2 php-fpm[59831]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.35.
Apr 25 20:28:52 trail2 php-fpm[23512]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.3.
Apr 25 20:27:42 trail2 php-fpm[23512]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.36.
Apr 25 20:26:58 trail2 php-fpm[60193]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.7.7.9.
Apr 25 20:26:40 trail2 php-fpm[555]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.2.
Apr 25 20:25:30 trail2 php-fpm[556]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.35.
Apr 25 20:24:29 trail2 php-fpm[60193]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.4.
Apr 25 20:23:38 trail2 php-fpm[60193]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.15.19.6.
Apr 25 20:23:20 trail2 php-fpm[555]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.36.
Apr 25 20:22:31 trail2 php-fpm[555]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.7.7.7.
Apr 25 20:22:18 trail2 php-fpm[556]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.2.
Apr 25 20:21:09 trail2 php-fpm[60193]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.35.
Apr 25 20:20:07 trail2 php-fpm[59831]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.3.
Apr 25 20:19:18 trail2 php-fpm[23512]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.7.7.2.
Apr 25 20:18:58 trail2 php-fpm[60193]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.36.
Apr 25 20:17:55 trail2 php-fpm[555]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.2.
Apr 25 20:16:47 trail2 php-fpm[31573]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.35.
Apr 25 20:15:45 trail2 php-fpm[59831]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.4.
Apr 25 20:14:49 trail2 php-fpm[31573]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.7.7.9.
Apr 25 20:14:36 trail2 php-fpm[31573]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.36.
Apr 25 20:13:34 trail2 php-fpm[31573]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.2.
Apr 25 20:12:24 trail2 php-fpm[94728]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.35.
Apr 25 20:11:36 trail2 php-fpm[555]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.7.7.3.
Apr 25 20:11:23 trail2 php-fpm[60193]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.3.
Apr 25 20:10:14 trail2 php-fpm[59831]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.36.
Apr 25 20:09:12 trail2 php-fpm[23512]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.6.
Apr 25 20:08:03 trail2 php-fpm[31573]: /rc.newwanip: IP Address has changed, killing states on former IP Address 10.59.74.35. -
More logs
Apr 25 20:58:35 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:35 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:35 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:35 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:35 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:35 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:35 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:35 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:34 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:34 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:34 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:34 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:34 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:34 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:34 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:34 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:33 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:33 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:33 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:33 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:33 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:33 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:32 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:32 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:32 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:32 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:32 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:32 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:32 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:31 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:31 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:31 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:31 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:31 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:31 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:31 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:31 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:30 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:30 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:30 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:30 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:30 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:30 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:30 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:30 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:29 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:29 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:29 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:29 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:29 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:29 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:29 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:29 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:28 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:28 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:28 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:28 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:28 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:28 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:28 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:28 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:27 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:27 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:27 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:27 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:27 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:27 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:27 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:27 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:26 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:26 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:26 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:26 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:26 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:26 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:26 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:26 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:25 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:25 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:25 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:25 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:25 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:25 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:25 trail2 openvpn[78077]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:25 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:25 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:25 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:24 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:24 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:24 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:24 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:23 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:23 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:23 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:23 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:23 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:23 trail2 openvpn[78077]: Timers: ping 10, ping-restart 60
Apr 25 20:58:23 trail2 openvpn[78077]: Data Channel: cipher 'AES-256-GCM', peer-id: 0, compression: 'stub'
Apr 25 20:58:23 trail2 openvpn[78077]: Initialization Sequence Completed
Apr 25 20:58:23 trail2 openvpn[78077]: /usr/local/sbin/ovpn-dnslinkup ovpnc24 1500 0 10.10.19.6 255.255.255.0 init
Apr 25 20:58:23 trail2 openvpn[78077]: /sbin/ifconfig ovpnc24 10.10.19.6/24 mtu 1500 up
Apr 25 20:58:23 trail2 openvpn[78077]: TUN/TAP device /dev/tun24 opened
Apr 25 20:58:23 trail2 openvpn[78077]: TUN/TAP device ovpnc24 exists previously, keep at program end
Apr 25 20:58:23 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:22 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:22 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:22 trail2 openvpn[59303]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:22 trail2 openvpn[97905]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:22 trail2 openvpn[8512]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 20:58:22 trail2 openvpn[50289]: Flushing states on OpenVPN interface ovpnc24 (Link Down) -
Yes it could be if the states are being killed after opening it will not be able to send anything but new TCP connections.
Something there is flapping badly! Is one or both of those WANs actually losing link?
I suggest disabling one of those WANs as a test. If the other WAN stays up and is stable check that OpenVPN is them able to connect.
-
Hi Steve,
I switched the interface of each of the OpenVPN TCP client to WAN1 and noted the results. After few mins, switched the interface of each to WAN2. The TCP write errors were noted on each WAN.
I noted the following errors under OpenVPN logs.
Apr 25 21:17:17 trail2 nginx: 2024/04/25 21:17:17 [crit] 16359#107235: *1037 SSL_write() failed (13: Permission denied) while processing HTTP/2 connection, client: 10.7.7.10, server: 0.0.0.0:8443
Apr 25 21:17:13 trail2 nginx: 2024/04/25 21:17:13 [crit] 16359#107235: *1026 SSL_write() failed (13: Permission denied) while processing HTTP/2 connection, client: 10.7.7.10, server: 0.0.0.0:8443
Apr 25 21:16:54 trail2 vnstatd[14999]: Data retention: 48 5MinuteHours, 4 HourlyDays, 62 DailyDays, 25 MonthlyMonths, -1 YearlyYears, 20 TopDayEntries
Apr 25 21:16:54 trail2 vnstatd[14999]: vnStat daemon 2.11 (pid:14999 uid:0 gid:0, SQLite 3.44.0)
Apr 25 21:16:54 trail2 vnstatd[15228]: Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Apr 25 21:16:54 trail2 vnstatd[29151]: SIGTERM received, exiting.
Apr 25 21:16:51 trail2 php-fpm[59831]: /rc.filter_configure_sync: GW States: One or more gateways is down, flushing all states: CLIENT_A_VPNV4
Apr 25 21:16:50 trail2 php-fpm[555]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use CLIENT_B_VPNV4.
Apr 25 21:16:50 trail2 php-fpm[555]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Apr 25 21:16:49 trail2 check_reload_status[607]: Reloading filter
Apr 25 21:16:49 trail2 check_reload_status[607]: Restarting OpenVPN tunnels/interfaces
Apr 25 21:16:49 trail2 check_reload_status[607]: Restarting IPsec tunnels
Apr 25 21:16:49 trail2 check_reload_status[607]: updating dyndns CLIENT_B_VPNV4 -
But are the WANs still reloading continually during that test?
Any time it kills the states on the WAN TCP connections will fail and have to be re-established. UDP connections would not though which seems to match what you're seeing.
-
Hi Steve,
I didn't notice any issue with the WAN. Also why there are no TCP write errors on 23.09.1?
I am sharing some more logs. This time from a given specific TCP client.
Apr 25 21:44:36 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:36 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:35 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:35 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:34 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:34 trail2 openvpn[88426]: MANAGEMENT: Client disconnected
Apr 25 21:44:34 trail2 openvpn[88426]: MANAGEMENT: CMD 'status 2'
Apr 25 21:44:34 trail2 openvpn[88426]: MANAGEMENT: CMD 'state 1'
Apr 25 21:44:34 trail2 openvpn[88426]: MANAGEMENT: Client connected from /var/etc/openvpn/client6/sock
Apr 25 21:44:34 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:33 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:33 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:32 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:32 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:31 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:31 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:30 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:30 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:29 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:29 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:28 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:28 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:27 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:27 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:26 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:25 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:25 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:24 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:24 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:23 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:23 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:22 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:22 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:21 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:21 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:20 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:20 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:19 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:19 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:18 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:18 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:17 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:17 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:16 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:16 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:15 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:15 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:14 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:14 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:13 trail2 openvpn[88426]: write TCPv4_CLIENT: Permission denied (fd=5,code=13)
Apr 25 21:44:11 trail2 openvpn[88426]: Timers: ping 10, ping-restart 120
Apr 25 21:44:11 trail2 openvpn[88426]: Data Channel: cipher 'AES-256-GCM', peer-id: 0, compression: 'stub'
Apr 25 21:44:11 trail2 openvpn[88426]: Initialization Sequence Completed
Apr 25 21:44:11 trail2 openvpn[88426]: /usr/local/sbin/ovpn-dnslinkup ovpnc6 1500 0 10.59.74.40 255.255.255.224 init
Apr 25 21:44:11 trail2 openvpn[88426]: /sbin/ifconfig ovpnc6 10.59.74.40/27 mtu 1500 up
Apr 25 21:44:11 trail2 openvpn[88426]: TUN/TAP device /dev/tun6 opened
Apr 25 21:44:11 trail2 openvpn[88426]: TUN/TAP device ovpnc6 exists previously, keep at program end
Apr 25 21:44:11 trail2 openvpn[88426]: Using peer cipher 'AES-256-GCM'
Apr 25 21:44:11 trail2 openvpn[88426]: OPTIONS IMPORT: route-related options modified
Apr 25 21:44:11 trail2 openvpn[88426]: OPTIONS IMPORT: --ifconfig/up options modified
Apr 25 21:44:11 trail2 openvpn[88426]: Socket Buffers: R=[65700->393216] S=[65700->393216]
Apr 25 21:44:11 trail2 openvpn[88426]: OPTIONS IMPORT: --sndbuf/--rcvbuf options modified
Apr 25 21:44:11 trail2 openvpn[88426]: Options error: option 'dhcp-option' cannot be used in this context ([PUSH-OPTIONS])
Apr 25 21:44:11 trail2 openvpn[88426]: Options error: option 'dhcp-option' cannot be used in this context ([PUSH-OPTIONS])
Apr 25 21:44:11 trail2 openvpn[88426]: Options error: option 'redirect-gateway' cannot be used in this context ([PUSH-OPTIONS])
Apr 25 21:44:11 trail2 openvpn[88426]: PUSH: Received control message: 'PUSH_REPLY,redirect-gateway def1,dhcp-option DNS 206.123.151.129,dhcp-option DNS 206.123.151.131,sndbuf 393216,rcvbuf 393216,comp-lzo no,route-gateway 10.59.74.33,topology subnet,ping 10,ping-restart 120,ifconfig 10.59.74.40 255.255.255.224,peer-id 0'
Apr 25 21:44:11 trail2 openvpn[88426]: SENT CONTROL [Secure-Server]: 'PUSH_REQUEST' (status=1)
Apr 25 21:44:10 trail2 openvpn[88426]: TLS: tls_multi_process: initial untrusted session promoted to trusted
Apr 25 21:44:10 trail2 openvpn[88426]: TLS: move_session: dest=TM_ACTIVE src=TM_INITIAL reinit_src=1
Apr 25 21:44:10 trail2 openvpn[88426]: [Secure-Server] Peer Connection Initiated with [AF_INET]138.199.60.100:443 -
Are the WANs flapping like that in 23.09.1?
-
Hi Steve,
On 23.09.1, based on system logs, the WAN IP Address does change too but the TCP clients are more resilient and do not have the write / permission denied issue.
I am not sure how to fix the issue. I plan to change to a different ISP and test. I am not certain if changing to 24.03 aggravated the TCP issue.
Any suggestion on how to get the issue resolved?
Thx.
-
But are they what I would 'flapping' in the same way? In the logs from 24.03 it's pulling a new IP address every minute which cannot be right. And it logs killing the states on the interface every time that happens.
-
Hi Steve,
Whether WAN flapping was observed on 23.09.1, I didn't make a note. The next time I change the boot environment to 23.09.1, I will extract the WAN logs.
On 24.03, I extracted the WAN logs
Apr 26 21:32:54 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.39 -> 10.59.74.36 - Restarting packages.
Apr 26 21:32:03 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.7.7.7 -> 10.7.7.12 - Restarting packages.
Apr 26 21:31:14 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.36 -> 10.59.74.39 - Restarting packages.
Apr 26 21:30:43 trail2 php-fpm[30768]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.2 -> 10.59.74.3 - Restarting packages.
Apr 26 21:29:03 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.3 -> 10.59.74.2 - Restarting packages.
Apr 26 21:28:32 trail2 php-fpm[45205]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.39 -> 10.59.74.36 - Restarting packages.
Apr 26 21:27:38 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.7.7.5 -> 10.7.7.7 - Restarting packages.
Apr 26 21:26:46 trail2 php-fpm[67201]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.36 -> 10.59.74.39 - Restarting packages.
Apr 26 21:26:21 trail2 php-fpm[45205]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.2 -> 10.59.74.3 - Restarting packages.
Apr 26 21:24:55 trail2 php-fpm[45205]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.7.7.6 -> 10.7.7.5 - Restarting packages.
Apr 26 21:24:24 trail2 php-fpm[30768]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.39 -> 10.59.74.36 - Restarting packages.
Apr 26 21:24:10 trail2 php-fpm[67201]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.3 -> 10.59.74.2 - Restarting packages.
Apr 26 21:22:30 trail2 php-fpm[30768]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.36 -> 10.59.74.39 - Restarting packages.
Apr 26 21:21:59 trail2 php-fpm[10821]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.2 -> 10.59.74.3 - Restarting packages.
Apr 26 21:21:11 trail2 php-fpm[10821]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.7.7.5 -> 10.7.7.6 - Restarting packages.
Apr 26 21:20:19 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.3 -> 10.59.74.2 - Restarting packages.
Apr 26 21:19:48 trail2 php-fpm[85785]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.39 -> 10.59.74.36 - Restarting packages.
Apr 26 21:18:08 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.36 -> 10.59.74.39 - Restarting packages.
Apr 26 21:17:37 trail2 php-fpm[85785]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.2 -> 10.59.74.3 - Restarting packages.
Apr 26 21:16:48 trail2 php-fpm[85783]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.7.7.3 -> 10.7.7.5 - Restarting packages.
Apr 26 21:15:57 trail2 php-fpm[85785]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.39 -> 10.59.74.36 - Restarting packages.
Apr 26 21:15:26 trail2 php-fpm[10821]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.3 -> 10.59.74.2 - Restarting packages.
Apr 26 21:13:46 trail2 php-fpm[10821]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.2 -> 10.59.74.3 - Restarting packages.
Apr 26 21:13:23 trail2 php-fpm[85783]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use WAN_DHCP.
Apr 26 21:13:22 trail2 check_reload_status[594]: updating dyndns WAN_DHCP
Apr 26 21:13:22 trail2 rc.gateway_alarm[51512]: >>> Gateway alarm: WAN_DHCP (Addr:1.1.1.1 Alarm:0 RTT:2.146ms RTTsd:.236ms Loss:0%)
Apr 26 21:13:15 trail2 php-fpm[30768]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.36 -> 10.59.74.39 - Restarting packages.
Apr 26 21:13:12 trail2 check_reload_status[594]: updating dyndns WAN_DHCP
Apr 26 21:13:12 trail2 rc.gateway_alarm[59627]: >>> Gateway alarm: WAN_DHCP (Addr:1.1.1.1 Alarm:1 RTT:2.244ms RTTsd:.080ms Loss:33%)
Apr 26 21:12:24 trail2 php-fpm[45205]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.7.7.6 -> 10.7.7.3 - Restarting packages.
Apr 26 21:11:03 trail2 php-fpm[85783]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.40 -> 10.59.74.36 - Restarting packages.
Apr 26 21:09:53 trail2 php-fpm[67201]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.3 -> 10.59.74.2 - Restarting packages.
Apr 26 21:08:52 trail2 php-fpm[85783]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.36 -> 10.59.74.40 - Restarting packages.
Apr 26 21:07:42 trail2 php-fpm[45205]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.2 -> 10.59.74.3 - Restarting packages.
Apr 26 21:07:16 trail2 php-fpm[30768]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.15.19.6 -> 10.14.19.7 - Restarting packages.
Apr 26 21:06:52 trail2 php-fpm[85783]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.7.7.3 -> 10.7.7.6 - Restarting packages.
Apr 26 21:06:41 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.39 -> 10.59.74.36 - Restarting packages.
Apr 26 21:05:31 trail2 php-fpm[45205]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.3 -> 10.59.74.2 - Restarting packages.
Apr 26 21:04:30 trail2 php-fpm[85785]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.36 -> 10.59.74.39 - Restarting packages.
Apr 26 21:03:37 trail2 php-fpm[67201]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.7.7.11 -> 10.7.7.3 - Restarting packages.
Apr 26 21:03:20 trail2 php-fpm[85783]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.2 -> 10.59.74.3 - Restarting packages.
Apr 26 21:02:19 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.39 -> 10.59.74.36 - Restarting packages.
Apr 26 21:01:08 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.7 -> 10.59.74.2 - Restarting packages.
Apr 26 21:00:08 trail2 php-fpm[85783]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.36 -> 10.59.74.39 - Restarting packages.
Apr 26 20:59:13 trail2 php-fpm[67201]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.7.7.8 -> 10.7.7.11 - Restarting packages.
Apr 26 20:58:57 trail2 php-fpm[45205]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.3 -> 10.59.74.7 - Restarting packages.
Apr 26 20:57:57 trail2 php-fpm[9587]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.39 -> 10.59.74.36 - Restarting packages.
Apr 26 20:56:46 trail2 php-fpm[30768]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.2 -> 10.59.74.3 - Restarting packages.
Apr 26 20:56:01 trail2 php-fpm[10821]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.7.7.3 -> 10.7.7.8 - Restarting packages.
Apr 26 20:55:46 trail2 php-fpm[45205]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.36 -> 10.59.74.39 - Restarting packages.
Apr 26 20:54:41 trail2 php-fpm[67201]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use WAN_DHCP.
Apr 26 20:54:40 trail2 check_reload_status[594]: updating dyndns WAN_DHCP
Apr 26 20:54:40 trail2 rc.gateway_alarm[3697]: >>> Gateway alarm: WAN_DHCP (Addr:1.1.1.1 Alarm:0 RTT:2.072ms RTTsd:.203ms Loss:0%)
Apr 26 20:54:35 trail2 php-fpm[10821]: /rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 10.59.74.3 -> 10.59.74.2 - Restarting packages.
Apr 26 20:54:31 trail2 php-fpm[30768]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use WAN_DHCP.
Apr 26 20:54:30 trail2 check_reload_status[594]: updating dyndns WAN_DHCP
Apr 26 20:54:30 trail2 rc.gateway_alarm[33313]: >>> Gateway alarm: WAN_DHCP (Addr:1.1.1.1 Alarm:1 RTT:2.087ms RTTsd:.010ms Loss:33%)Thx
-
Ok are those IPs we see changing there, 10.59.74.X, the WAN IPs ? Or is that a VPN interface perhaps?
Edit: Yes it is.
-
Ok so that's probably a symptom not a cause then.
Permission denied like that pretty much MUST be a local firewall rule blocking it.
If you have no dynamic packages adding rules and no custom block rules I have to go back the Interface Binding state change in 24.03.
But you didn't see any blocked traffic in the firewall logs?
-
10.59.74.X, -> VPN Interface
I don't have any custom block rules; only the default deny rules. I have changed back the Firewall State Policy to Interface Bound States.
-
On 23.09.1 too, the WAN IPs are flapping the same way.
-
Hmm, still the openvpn clients changing address every minute? That sounds like it would be unusable if so.
-
I deleted the TCP clients as I couldn't get rid of the errors. Looks okay now w/o the TCP clients.