OpenVPN client connections get dropped when rc.filter_configure_sync script runs (every 15min from crontab)
-
Hi there. Whenever the crontab entry rc.filter_configure_sync script runs, any currently connected OpenVPN client connections get reset. Most of the users don't notice this as the client handles it quite well, but there are a few users whose connections take a while to reconnect. Is there anything I can do with this, or is this "by-design"?
Regards, -
@dael-sutton can you post the logs to check?
-
This is the connection I was on when the connection reset;
Feb 9 14:15:33 openvpn 60630 MULTI_sva: pool returned IPv4=10.11.1.8, IPv6=(Not enabled)
Feb 9 14:15:33 openvpn 19667 user 'mis' authenticated
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 [mis] Peer Connection Initiated with [AF_INET]118.149.80.208:59617
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 WARNING: 'keysize' is used inconsistently, local='keysize 256', remote='keysize 128'
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1571', remote='link-mtu 1555'
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 peer info: IV_BS64DL=1
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 peer info: IV_SSO=webauth,openurl,crtext
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 peer info: IV_GUI_VER=OCWindows_3.3.4-2600
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305:BF-CBC
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 peer info: IV_PROTO=30
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 peer info: IV_TCPNL=1
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 peer info: IV_NCP=2
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 peer info: IV_PLAT=win
Feb 9 14:15:33 openvpn 60630 118.149.80.208:59617 peer info: IV_VER=3.git::d3f8b18b
Feb 9 14:15:32 openvpn 60630 TCP connection established with [AF_INET]118.149.80.208:59617
Feb 9 14:15:31 openvpn 60630 mis/118.149.80.208:59618 write TCPv4_SERVER: Permission denied (code=13)
Happened almost bang on 14:00 as the clock ticked.
-
Sorry, that was logs from the 14:15 one.
This is from logstash, capturing my login at 13:51, and the disconnect/reconnect at 14:00
February 9th 2022, 14:00:29.714{"@timestamp":"2022-02-09T14:00:31+13:00","@version":"1","message":" ces/123.255.47.233:56565 IP packet with unknown IP version=0 seen","sysloghost":"172.16.0.199","severity":"warning","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:29.421{"@timestamp":"2022-02-09T14:00:31+13:00","@version":"1","message":" MULTI_sva: pool returned IPv4=10.11.1.8, IPv6=(Not enabled)","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:29.405{"@timestamp":"2022-02-09T14:00:31+13:00","@version":"1","message":" 118.149.80.208:59618 [mis] Peer Connection Initiated with [AF_INET]118.149.80.208:59618","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:29.080{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" MULTI_sva: pool returned IPv4=10.11.1.7, IPv6=(Not enabled)","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:29.059{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" user 'ces' authenticated","sysloghost":"172.16.0.199","severity":"notice","facility":"auth","programname":"openvpn","procid":"72780"}
February 9th 2022, 14:00:28.933{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 [ces] Peer Connection Initiated with [AF_INET]123.255.47.233:56565","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.867{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1571', remote='link-mtu 1555'","sysloghost":"172.16.0.199","severity":"warning","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.867{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 WARNING: 'keysize' is used inconsistently, local='keysize 256', remote='keysize 128'","sysloghost":"172.16.0.199","severity":"warning","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.866{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 peer info: IV_PLAT=win","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.866{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 peer info: IV_NCP=2","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.866{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305:BF-CBC","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.866{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 peer info: IV_GUI_VER=OCWindows_3.3.1-2222","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.866{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 peer info: IV_BS64DL=1","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.866{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 peer info: IV_VER=3.git::98bf7f7f","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.866{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 peer info: IV_PROTO=30","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.866{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 peer info: IV_TCPNL=1","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.866{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 123.255.47.233:56565 peer info: IV_SSO=openurl,crtext","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.760{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" TCP connection established with [AF_INET]123.255.47.233:56565","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.605{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" user 'mis' authenticated","sysloghost":"172.16.0.199","severity":"notice","facility":"auth","programname":"openvpn","procid":"70683"}
February 9th 2022, 14:00:28.474{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" mis/118.149.80.208:59601 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.397{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 WARNING: 'keysize' is used inconsistently, local='keysize 256', remote='keysize 128'","sysloghost":"172.16.0.199","severity":"warning","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.397{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1571', remote='link-mtu 1555'","sysloghost":"172.16.0.199","severity":"warning","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.396{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 peer info: IV_PLAT=win","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.396{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 peer info: IV_VER=3.git::d3f8b18b","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.396{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305:BF-CBC","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.396{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 peer info: IV_BS64DL=1","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.396{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 peer info: IV_PROTO=30","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.396{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 peer info: IV_NCP=2","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.396{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 peer info: IV_TCPNL=1","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.396{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 peer info: IV_GUI_VER=OCWindows_3.3.4-2600","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:28.396{"@timestamp":"2022-02-09T14:00:30+13:00","@version":"1","message":" 118.149.80.208:59618 peer info: IV_SSO=webauth,openurl,crtext","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:27.876{"@timestamp":"2022-02-09T14:00:29+13:00","@version":"1","message":" ces/123.255.47.233:56458 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:26.022{"@timestamp":"2022-02-09T14:00:27+13:00","@version":"1","message":" TCP connection established with [AF_INET]118.149.80.208:59618","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:23.362{"@timestamp":"2022-02-09T14:00:25+13:00","@version":"1","message":" mis/118.149.80.208:59601 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:22.681{"@timestamp":"2022-02-09T14:00:24+13:00","@version":"1","message":" ces/123.255.47.233:56458 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:19.127{"@timestamp":"2022-02-09T14:00:20+13:00","@version":"1","message":" mis/118.149.80.208:59601 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:17.476{"@timestamp":"2022-02-09T14:00:19+13:00","@version":"1","message":" ces/123.255.47.233:56458 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:14.084{"@timestamp":"2022-02-09T14:00:15+13:00","@version":"1","message":" mis/118.149.80.208:59601 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:12.381{"@timestamp":"2022-02-09T14:00:14+13:00","@version":"1","message":" ces/123.255.47.233:56458 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:08.981{"@timestamp":"2022-02-09T14:00:10+13:00","@version":"1","message":" mis/118.149.80.208:59601 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:07.275{"@timestamp":"2022-02-09T14:00:09+13:00","@version":"1","message":" ces/123.255.47.233:56458 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:03.782{"@timestamp":"2022-02-09T14:00:05+13:00","@version":"1","message":" mis/118.149.80.208:59601 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 14:00:02.152{"@timestamp":"2022-02-09T14:00:04+13:00","@version":"1","message":" ces/123.255.47.233:56458 write TCPv4_SERVER: Permission denied (code=13)","sysloghost":"172.16.0.199","severity":"err","facility":"daemon","programname":"openvpn","procid":"60630"}
February 9th 2022, 13:51:29.782{"@timestamp":"2022-02-09T13:51:31+13:00","@version":"1","message":" 118.149.80.208:59601 [mis] Peer Connection Initiated with [AF_INET]118.149.80.208:59601","sysloghost":"172.16.0.199","severity":"notice","facility":"daemon","programname":"openvpn","procid":"60630"} -
@dael-sutton said in OpenVPN client connections get dropped when rc.filter_configure_sync script runs (every 15min from crontab):
WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1571', remote='link-mtu 1555'
1571 and 1555 ??
-
Not sure what to do about that message, to be honest. It logs when the connection establishes, but everything appears to work fine, except for the disconnects with 'Permission denied (code=13)' on the quarter hour.
-
@dael-sutton Are there any firewall logs for that endpoint?
-
@silence Nothing form the endpoint, however I was ssh'd in watching the filter.log;
Feb 9 14:44:57 firewalk3 filterlog[26048]: 135,,,1593745551,em2,match,pass,in,4,0x0,,128,37015,0,DF,6,tcp,52,192.168.2.13,172.16.0.24,51278,3050,0,S,1825821203,,64240,,mss;nop;wscale;nop;nop;sackOK
Feb 9 14:44:57 firewalk3 filterlog[26048]: 135,,,1593745551,em2,match,pass,in,4,0x0,,128,37016,0,DF,6,tcp,52,192.168.2.13,172.16.0.24,51278,3050,0,S,1825821203,,64240,,mss;nop;wscale;nop;nop;sackOK
Feb 9 14:45:00 firewalk3 filterlog[26048]: 8,,,1000000103,ovpns1,match,block,in,4,0x0,,128,37102,0,DF,6,tcp,52,10.11.1.7,172.16.0.19,56913,9191,0,S,382678354,,64240,,mss;nop;wscale;nop;nop;sackOK
Feb 9 14:45:00 firewalk3 filterlog[26048]: 8,,,1000000103,ovpns1,match,block,in,4,0x0,,128,3652,0,DF,6,tcp,52,10.11.1.7,172.16.0.18,56914,631,0,S,2428094745,,64240,,mss;nop;wscale;nop;nop;sackOKand when the clock ticked 14:45:00 those two entries flicked past and my ssh connection got disconnected.
So it's probably nothing to do with OpenVPN and more to do with the firewall/filter stopping & starting and resetting all connections on the 15min. :( -
@dael-sutton What services do you have in your pfsense?
like pfblockerng?
-
Just these;
ssh is normally disabled.
-
Could this be doing it?
-
@dael-sutton said in OpenVPN client connections get dropped when rc.filter_configure_sync script runs (every 15min from crontab):
Could this be doing it?
show you gateway !
-
No gateway groups defined.
none of the gateways should be detected as "down" when the filter reloads, but maybe I should disable that tickbox and see what happens.... -
Yee-Haa. Unticking that "flush all states" tickbox seems to have done the trick. Thankyou @Silence for your patience while I grabbed at straws until the correct one appeared. 15:15 came and went and my test openvpv connection didn't drop, and my ssh session stayed running too.
-
@dael-sutton said in OpenVPN client connections get dropped when rc.filter_configure_sync script runs (every 15min from crontab):
Yee-Haa. Unticking that "flush all states" tickbox seems to have done the trick. Thankyou @Silence for your patience while I grabbed at straws until the correct one appeared. 15:15 came and went and my test openvpv connection didn't drop, and my ssh session stayed running too.
Don't forget to like the comment that helped you.