Still having to delete entries from the state table

divsys

I know this isn't the ultimate fix for your issue, but could you not institute your own rule within pfSense to disallow the sip device->wan ip connection that causes trouble?

You probably will need to be fairly specific with rule as the sip device may need some wan access but not others. At worst you should be able to nail down what ports/protocols the sip device uses to establish the state you don't want until the VPN comes up.

Definitely a bit of a kludge, but it could save you some time until a readier fix is available.

firewalluser

Ok, so the ISP has reset the ip address and this is whats in the states table.
LAN udp 217.10.79.23:5060 <- 192.168.10.15:5080 MULTIPLE:MULTIPLE
WAN udp 92.24.128.212:3258 (192.168.10.15:5080) -> 217.10.79.23:5060 SINGLE:NO_TRAFFIC
LAN udp 85.10.243.100:5060 <- 192.168.10.15:5080 MULTIPLE:MULTIPLE
WAN udp 92.24.182.121:44670 (192.168.10.15:5080) -> 85.10.243.100:5060 MULTIPLE:MULTIPLE

I suspect if I delete the bold entry, the sip server will start working again.

The volp service provided on 85.10.243.100 works fine after the IP address change, but this is only a single phone number they provide, the 217.10.79.23 voip provider (which has a few numbers on it) cant not reregister.

If its of any interest, I have to add the below to the Snort Wan suppress list for the voip provider on 217.10.79.23
#(spp_sip) Maximum dialogs within a session reached
suppress gen_id 140, sig_id 27

Is there anything else I can look up and post to add to the above?

TIA.

Edit.
So I deleted the single bold entry and the sip server registers on the next retry automatically with the sip provider and everything works.

The sip server reports registration attempts are failing at the time, so its attempting to register but it appears to stop at the firewall.

In case this is a multiple account issue, I'm moving one of the voip accounts onto a separate machine to see if that will present different outcomes in the state table when the ISP changes the ip address.

cmb

@firewalluser:

Ok, so the ISP has reset the ip address and this is whats in the states table.
LAN udp 217.10.79.23:5060 <- 192.168.10.15:5080 MULTIPLE:MULTIPLE
WAN udp 92.24.128.212:3258 (192.168.10.15:5080) -> 217.10.79.23:5060 SINGLE:NO_TRAFFIC
LAN udp 85.10.243.100:5060 <- 192.168.10.15:5080 MULTIPLE:MULTIPLE
WAN udp 92.24.182.121:44670 (192.168.10.15:5080) -> 85.10.243.100:5060 MULTIPLE:MULTIPLE

Is 92.24.128.212 your former or new WAN IP? Did you see "IP has changed, killing states on former IP" in your system log?

firewalluser

Short answer is Former & Yes

Jan 2 17:12:08 php-fpm[31247]: /rc.newwanip: IP has changed, killing states on former IP 92.28.250.34.
Jan 3 06:36:10 php-fpm[87818]: /rc.newwanip: IP has changed, killing states on former IP 92.24.128.212. Failed here
Jan 3 06:36:25 php-fpm[17691]: /rc.newwanip: IP has changed, killing states on former IP 92.28.242.57.
Jan 3 18:56:24 php-fpm[42040]: /rc.newwanip: IP has changed, killing states on former IP 2.97.222.24.
Jan 3 18:56:40 php-fpm[84711]: /rc.newwanip: IP has changed, killing states on former IP 92.17.178.12. Spotted & Reported problem
Jan 5 02:12:57 php-fpm[96364]: /rc.newwanip: IP has changed, killing states on former IP 92.24.182.121.
Jan 5 02:13:09 php-fpm[12639]: /rc.newwanip: IP has changed, killing states on former IP 92.29.124.51.
Jan 5 03:56:58 php-fpm[85763]: /rc.newwanip: IP has changed, killing states on former IP 92.20.232.219.
Jan 5 03:57:11 php-fpm[544]: /rc.newwanip: IP has changed, killing states on former IP 2.96.100.212.
Jan 6 04:45:25 php-fpm[26469]: /rc.newwanip: IP has changed, killing states on former IP 92.20.232.219.

Could the time difference between the ISP forcing an ip address change be a factor, like 15 seconds apart?
The single account sip provider worked perfectly throughout, but the multi account sip provider failed as there are 6 incoming phone lines.

Jan 3 06:36:10 php-fpm[87818]: /rc.newwanip: IP has changed, killing states on former IP 92.24.128.212. Failed here
Jan 3 06:36:25 php-fpm[17691]: /rc.newwanip: IP has changed, killing states on former IP 92.28.242.57.

The SIP server has been working fine since I deleted the state table entry and contrary to what I suggested in an earlier post, I'm still on the version which hilighted the problem namely…
2.2-RC (amd64)
built on Wed Dec 24 14:16:30 CST 2014
FreeBSD 10.1-RELEASE-p3

If I had to bet at this stage, I'd go for the 15second ip address which caused the problem with the state table.

Anything else you need checked or logged? I can run one of these http://williamknowles.co.uk/?p=16 hooked up to a 2Tb external drive between the modem and pfsense wan interface if need be to get as much data as possible.

cmb

Yeah that definitely looks like why, though it's not obvious to me why it'd fail in that circumstance. If it gets to that spot, it runs the appropriate kill command, but maybe if it happens that quickly something else occurs.

If you enable killing of all states, I suspect that will at least work around the issue (or if it doesn't, it should make it more clear where it may be). Go to Diagnostics>Command and paste the following in the PHP Execute box.

global $config;

$config = parse_config(true);

$config['system']['ip_change_kill_states'] = true;
write_config("Enable kill all states");

That'll set the hidden config option to wipe all states rather than just your former IP's states. Let us know how that goes.

firewalluser

I'll try that.

firewalluser

At the moment I'm executing the code below every time I upgrade, is this something I can add to the system tunables section and if so, would this then be backed up and restored?

global $config;

$config = parse_config(true);

$config['system']['ip_change_kill_states'] = true;
write_config("Enable kill all states");

cmb

It sets a config setting, it's not necessary to ever run it again unless you restore a config from before setting it.

firewalluser

Ok, thanks for the info. I had another 10sec IP address last night and all the states deleted and worked as expected, so I'll keep this thread handy.

Is this config option you supplied the same as System,Advanced, Miscellaneous tab?

State Killing on Gateway Failure
The monitoring process will flush states for a gateway that goes down if this box is not checked. Check this box to disable this behavior.

cmb

no, that's a different setting, IP change vs. gateway failure.

gerdesj

@xbipin:

the isp uses very expensive hardware to block any sort of unencrypted as well as encrypted VoIP. changing port numbers etc is useless, even customizing the sip packets to something not standard also gets filtered, they are very aggressive at blocking and it gets harder and harder to make VoIP work, although sip communication within the country is legal. VPN is the only known way to get it to work but they also block vpn services and proxies.

Sorry for the late reply halfway through a thread and somewhat off topic but have you tried OpenVPN listening on 443/tcp for a VPN?

It makes OVPN look pretty much like an https web server.

firewalluser

Spoke too soon.

IP change occurred

Jan 14 22:42:22 php-fpm[43221]: /rc.newwanip: IP has changed, killing states on former IP 92.20.234.88.
Jan 14 22:33:11 php-fpm[30555]: /rc.newwanip: IP has changed, killing states on former IP 92.24.140.87.

LAN udp 217.10.79.23:5060 <- 192.168.10.2:5080 NO_TRAFFIC:SINGLE
WAN udp 92.20.234.88:48050 (192.168.10.2:5080) -> 217.10.79.23:5060 SINGLE:NO_TRAFFIC

Its not reset the states as its still showing the old ip address as seen from the 1st entry in the log.

Any other info needed?

firewalluser

And had another instance where the sip server connections went down.

Between 01:52:33 through to 01:57:45 the sip connections went down but the only info in pf's system log is
Jan 15 01:57:25 check_reload_status: Rewriting resolv.conf
Jan 15 01:51:29 check_reload_status: Rewriting resolv.conf

There was a problem with a sip connection going down at 01:30:05 but it reconnected again at 01:30:37.

In the dhcp log I see this.
Jan 15 01:32:38 dhcpd: DHCPINFORM from 192.168.10.3 via em0
Jan 15 01:31:38 dhcpd: DHCPACK to 192.168.10.3 (99:88:77:66:55:44) via em0
Jan 15 01:31:38 dhcpd: DHCPINFORM from 192.168.10.3 via em0
Jan 15 01:31:20 dhcpd: Sending on Socket/fallback/fallback-net
Jan 15 01:31:20 dhcpd: Sending on BPF/em0/11:22:33:44:55:66/192.168.10.0/24
Jan 15 01:31:20 dhcpd: Listening on BPF/em0/11:22:33:44:55:66/192.168.10.0/24
Jan 15 01:31:20 dhcpd: Wrote 2 leases to leases file.
Jan 15 01:31:20 dhcpd: Wrote 0 new dynamic host decls to leases file.
Jan 15 01:31:20 dhcpd: Wrote 0 deleted host decls to leases file.
Jan 15 01:31:20 dhcpd: For info, please visit https://www.isc.org/software/dhcp/
Jan 15 01:31:20 dhcpd: All rights reserved.
Jan 15 01:31:20 dhcpd: Copyright 2004-2014 Internet Systems Consortium.
Jan 15 01:31:20 dhcpd: Internet Systems Consortium DHCP Server 4.2.6
Jan 15 01:31:20 dhcpd: For info, please visit https://www.isc.org/software/dhcp/
Jan 15 01:31:20 dhcpd: All rights reserved.
Jan 15 01:31:20 dhcpd: Copyright 2004-2014 Internet Systems Consortium.
Jan 15 01:31:20 dhcpd: Internet Systems Consortium DHCP Server 4.2.6
Jan 15 01:31:19 dhcpd: Disabling input on BPF/em0/11:22:33:44:55:66/192.168.10.0/24
Jan 15 01:31:19 dhcpd: Disabling output on BPF/em0/11:22:33:44:55:66/192.168.10.0/24
Jan 15 01:31:19 dhcpd: Received signal 15, initiating shutdown.
Jan 15 01:30:38 dhcpd: DHCPACK to 192.168.10.3 (99:88:77:66:55:44) via em0
Jan 15 01:30:38 dhcpd: DHCPINFORM from 192.168.10.3 via em0
Jan 15 01:29:38 dhcpd: DHCPACK to 192.168.10.3 (99:88:77:66:55:44) via em0
Jan 15 01:29:38 dhcpd: DHCPINFORM from 192.168.10.3 via em0

I dont know what the Recieved signal 15 is, but no one here did anything as we were asleep, although the ppp log (see attached) suggests the lcp went down.

Checking the snort log, the last entry was at 01/15/15 01:28:11, but interestingly the firewall log is only showing
Last 765 firewall log entries.Max(2000)

The log has been set to 2000 entries for ages, and I didnt delete anything from the log, but its only showing entries from Jan 15 08:02:28 through to Jan 15 05:38:02.

Now I dont know if this is related to my post about the system logs not working https://forum.pfsense.org/index.php?topic=86397.0
but I would have expected to have seen more than 765 entries in the firewall log going beyond 05:38:02.

Between the last snort alert at 01:28:11 and the first firewall log at 05:38:02 I dont have much of a record of whats been going on, although I can see from the mailserver, it has had one dodgy email in at 00:14:27 and again at 02:19:58 becuase from 02:19:58 the same ip 190:18:153:148 was initiating communications and then forcibly closing them, before what looks like normal email resumed at 03:13 when an email from pfsense.org arrived, and there on after email come through ever hour after that. So I know emails been recieved but cant tell why the firewall log only has 765 entries out of a possible 2000.

This is build
2.2-RC (amd64)
built on Sat Jan 10 03:54:06 CST 2015
FreeBSD 10.1-RELEASE-p3
which has been up for 4 Days 11 Hours 31 Minutes 57 Seconds.

Any other info needed as its looking like something interesting has been going on over night.

Edit. Attached ppp_log

Edit2. Unbound log attached. This also started and stopped during this time as well, dont know if its connected.

Edit3. NTP log attached. As its got entries in like waking up resolver/unbound so added this to help tie stuff up.

ppp_log.txt
unbound_log1.txt
ntp_log.txt

firewalluser

The firewall states are still not being reset properly in the version pfSense-memstick-2.2-RC-amd64-20150116-1153.img.