VOIP provider after schedule not registering debug help required

4o4rh

@stephenw10 Hi Steve, so I am back to this. Refreshing the memory;

reboot pfsense
all three voip providers register
schedule to block from midnight to 6am kicks in and blocks all.
6am only one provider re-registers.
checked the state tables in diagnostics for the vlan and found voiptalk still registered. (but not on the voip phone)
deleted the state table and voiptalk immediately registered successfully.

It appears after some period of time or event, the voip will re-register, but it is random and i guess is triggered by my wan falling over, or something.

This never happened under 2.5.2. it is only happening since 2.6x

stephenw10

Did you check the state table after the schedule reopens the rules for and states to the other providers?

Also check the states from mynetfone. Are they incoming or outgoing states?

You appear to be forwarding traffic on the Pri WAN but I wouldn't expect that to be necessary for a phone behind the firewall.

Steve

4o4rh

@stephenw10 I disabled the forwards and checked this morning.
mynetfone is self registered after the schedule re-opens

As for the States status after schedule opens:

WAN
udp WAN (ipfone) ->mynetphone
VLAN
udp sipgate -> ipfone
udp voiptalk -> ipfone
udp ipfone -> mynetphone

delete VLAN voiptalk state - immediate registration results with the notable difference in the state

WAN
udp WAN (ipfone) ->mynetphone
udp WAN (ipfone) ->voiptalk
VLAN
udp ipfone -> voiptalk
udp ipfone -> mynetphone
udp sipgate -> ipfone

delete VLAN sipgate state - immediate registration results with the notable difference in the state

WAN
udp WAN (ipfone) ->mynetphone
udp WAN (ipfone) ->voiptalk
udp WAN (ipfone) ->sipgate
VLAN
udp ipfone -> voiptalk
udp ipfone -> mynetphone
udp ipfone -> sipgate

stephenw10

Hmm, so it appears to be the existing incoming states on the internal VLAN interface.

That's interesting for a number of reasons.
It must be the port forward that was allowing those states to be created from the provider to the phone.
They seem to exist only on the VLAN and not the WAN even though they must have come through the WAN initially. So it appears the states were removes or timed out on WAN but somehow not the VLAN.

However without the port forward all opened states should be outbound so it should not be possible to get into the situation.

4o4rh

@stephenw10 said in VOIP provider after schedule not registering debug help required:

Hmm, so it appears to be the existing incoming states on the internal VLAN interface.

That's interesting for a number of reasons.
It must be the port forward that was allowing those states to be created from the provider to the phone.
They seem to exist only on the VLAN and not the WAN even though they must have come through the WAN initially. So it appears the states were removes or timed out on WAN but somehow not the VLAN.

However without the port forward all opened states should be outbound so it should not be possible to get into the situation.

I disabled the forwards and rebooted for this test. They were the results of the first schedule re-open event after. What is particularly interesting is;
the below state does not exist before the schedule block, but only after the re-open.

VLAN
udp sipgate -> ipfone
udp voiptalk -> ipfone

The working ones are in the other direction. Just rebooted again and checked these states. Just rebooted and doubled checked. These states are not created after a fresh reboot and there are no forwards and services are registered. Will check again in the morning to see if it is repeated

4o4rh

@stephenw10 hi steve, so checking this morning after the schedule reopened, and the states are showing voiptalk and gigaset in the wrong direction on the vlan segment again.

They were in the right direction before the schedule kicked in last night. Forwarding was deleted, and the unit rebooted last night.

So two things seem strange to me;

why do only these two and not all 3 states switch to the wrong direction after the schedule re-opens
this behaviour is obviously new in 2.6 because notwithstanding the forwarding, it was working since 2.4.x through upgrades to 2.5.2 without problems

The question is, is this a defect, or is there something I can do as a workaround?

stephenw10

Hmm. I can't see how those states could be opened and remain open in that direction on the internal interface without also coming in on another interface. Which I expect to be WAN.

Are you sure they are opened in that direction?

You could try adding floating block rules to prevent those states being opened.

Steve

4o4rh

@stephenw10 i have checked and rechecked.

no NAT forward rules
no WAN forward rules
only VLAN outgoing rules to VOIP servers/ports

I will check tonight when the schedule kicks in, if the states are being created after the schedule kicks in, or re-opens

stephenw10

Well one thing you can do is look at the state table from the CLI to see what rule opened the state:

pfctl -vvss

Then you can look at the rules to see what rule number that is:

pfctl -vvsr

So for example on a local test device:

all tcp 172.21.16.220:443 <- 172.21.16.8:38730       ESTABLISHED:ESTABLISHED
   [3316238557 + 4286908416] wscale 7  [1246366926 + 65792] wscale 7
   age 00:00:33, expires in 23:59:59, 205:428 pkts, 17217:487318 bytes, rule 85
   id: 252e1b6300000001 creatorid: 3f804604 gateway: 0.0.0.0
   origif: mvneta0

@85 pass in quick on mvneta0 inet proto tcp from 172.21.16.0/24 to 172.21.16.220 flags S/SA keep state label "USER_RULE: Allow access from WAN" label "id:1661983132" ridentifier 1661983132
  [ Evaluations: 2004      Packets: 1315      Bytes: 633672      States: 1     ]
  [ Inserted: uid 0 pid 89931 State Creations: 1     ]
  [ Last Active Time: Fri Sep  9 15:33:33 2022 ]

Steve

4o4rh

@stephenw10 cool. I'll give that a bash tonight once the schedule kicks in and again in the morning when it re-opens. Thanks man

4o4rh

@stephenw10 I can confirm, it is 3min past the activation of the schedule and the states on the vlan are;

ipfone -> mynetfone
sipgate -> ipfone
voiptalk -> ipfone

So it is being caused by the schedule turning on. i've masked some of the IPs

pfctl -vvsr

all udp 217.61.x.x:15777 (192.168.22.6:5160) -> 125.213.x.x:5060       MULTIPLE:MULTIPLE
   age 18:08:26, expires in 00:04:24, 1497:776 pkts, 477198:389009 bytes, rule 123
   id: 6ba41a6300000003 creatorid: 5f2a04ac gateway: 185.29.x.x
   origif: pppoe0

all udp 217.61.x.x:26167 (192.168.22.6:5160) -> 217.10.x.x:5060       MULTIPLE:MULTIPLE
   age 17:07:50, expires in 00:10:21, 3396:4706 pkts, 363541:343808 bytes, rule 123
   id: 82af1a6300000003 creatorid: 5f2a04ac gateway: 185.29.x.x
   origif: pppoe0

all udp 217.61.x.x:14782 (192.168.22.6:5160) -> 77.240.x.x:5065       MULTIPLE:MULTIPLE
   age 17:10:46, expires in 00:14:53, 5808:3018 pkts, 1960523:1098668 bytes, rule 123
   id: 62db1a6300000001 creatorid: 5f2a04ac gateway: 185.29.x.x
   origif: pppoe0

all udp 217.10.x.x:5060 -> 192.168.22.6:5160       MULTIPLE:MULTIPLE
   age 00:09:53, expires in 00:14:50, 23:62 pkts, 736:29737 bytes, rule 122
   id: a89b1b6300000003 creatorid: 5f2a04ac gateway: 0.0.0.0
   origif: igb2.22

all udp 77.240.x.x:5065 -> 192.168.22.6:5160       MULTIPLE:MULTIPLE
   age 00:09:37, expires in 00:14:53, 20:88 pkts, 5760:43859 bytes, rule 122
   id: b09b1b6300000003 creatorid: 5f2a04ac gateway: 0.0.0.0
   origif: igb2.22
   
all udp 192.168.22.5:53 <- 192.168.22.6:32978       MULTIPLE:MULTIPLE
   age 00:07:14, expires in 00:14:44, 6:6 pkts, 408:504 bytes, rule 467
   id: f49b1b6300000003 creatorid: 5f2a04ac gateway: 0.0.0.0
   origif: igb2.22

pfctl -vvsr

@37 pass in quick on igb2.22 inet proto udp from any port = bootpc to 192.168.22.5 port = bootps keep state label "allow access to DHCP server" ridentifier 1000003592
  [ Evaluations: 31        Packets: 62        Bytes: 20832       States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @38 pass out quick on igb2.22 inet proto udp from 192.168.22.5 port = bootps to any port = bootpc keep state label "allow access to DHCP server" ridentifier 1000003593
  [ Evaluations: 305       Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

@462 pass in quick on igb2.22 inet proto tcp from any to 192.168.22.5 port = domain flags S/SA keep state label "USER_RULE: Core Network Services (DNS/DHCP/BOOTP/etc)"   label "id:1610264176" ridentifier 1610264176
  [ Evaluations: 331137    Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

@463 pass in quick on igb2.22 inet proto tcp from any to 192.168.22.5 port = ntp flags S/SA keep state label "USER_RULE: Core Network Services (DNS/DHCP/BOOTP/etc)" label "id:1610264176" ridentifier 1610264176
  [ Evaluations: 0         Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

@464 pass in quick on igb2.22 inet proto tcp from any to 192.168.22.5 port 67:68 flags S/SA keep state label "USER_RULE: Core Network Services (DNS/DHCP/BOOTP/etc)" label "id:1610264176" ridentifier 1610264176
  [ Evaluations: 0         Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @465 pass in quick on igb2.22 inet proto tcp from any to 192.168.22.5 port = time flags S/SA keep state label "USER_RULE: Core Network Services (DNS/DHCP/BOOTP/etc)" label "id:1610264176" ridentifier 1610264176
  [ Evaluations: 0         Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @466 pass in quick on igb2.22 inet proto tcp from any to 192.168.22.5 port 5351:5357 flags S/SA keep state label "USER_RULE: Core Network Services (DNS/DHCP/BOOTP/etc)" label "id:1610264176" ridentifier 1610264176
  [ Evaluations: 0         Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @467 pass in quick on igb2.22 inet proto udp from any to 192.168.22.5 port = domain keep state label "USER_RULE: Core Network Services (DNS/DHCP/BOOTP/etc)" label "id:1610264176" ridentifier 1610264176
  [ Evaluations: 218       Packets: 466       Bytes: 40867       States: 1     ]
  [ Inserted: uid 0 pid 86711 State Creations: 1     ]
  [ Last Active Time: Sat Sep 10 00:09:41 2022 ]

  @468 pass in quick on igb2.22 inet proto udp from any to 192.168.22.5 port = ntp keep state label "USER_RULE: Core Network Services (DNS/DHCP/BOOTP/etc)" label "id:1610264176" ridentifier 1610264176
  [ Evaluations: 1         Packets: 2         Bytes: 152         States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @469 pass in quick on igb2.22 inet proto udp from any to 192.168.22.5 port 67:68 keep state label "USER_RULE: Core Network Services (DNS/DHCP/BOOTP/etc)" label "id:1610264176" ridentifier 1610264176
  [ Evaluations: 0         Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @470 pass in quick on igb2.22 inet proto udp from any to 192.168.22.5 port = time keep state label "USER_RULE: Core Network Services (DNS/DHCP/BOOTP/etc)" label "id:1610264176" ridentifier 1610264176
  [ Evaluations: 0         Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @471 pass in quick on igb2.22 inet proto udp from any to 192.168.22.5 port 5351:5357 keep state label "USER_RULE: Core Network Services (DNS/DHCP/BOOTP/etc)" label "id:1610264176" ridentifier 1610264176
  [ Evaluations: 0         Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @472 block drop in quick on igb2.22 inet proto tcp from any to ! (self:18) port = domain label "USER_RULE: Trap External: Core Network Services (DNS/DHCP/BO..." label "id:1610264228" ridentifier 1610264228
  [ Evaluations: 260       Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @473 block drop in quick on igb2.22 inet proto tcp from any to ! (self:18) port = ntp label "USER_RULE: Trap External: Core Network Services (DNS/DHCP/BO..." label "id:1610264228" ridentifier 1610264228
  [ Evaluations: 95        Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @474 block drop in quick on igb2.22 inet proto tcp from any to ! (self:18) port 67:68 label "USER_RULE: Trap External: Core Network Services (DNS/DHCP/BO..." label "id:1610264228" ridentifier 1610264228
  [ Evaluations: 95        Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @475 block drop in quick on igb2.22 inet proto tcp from any to ! (self:18) port = time label "USER_RULE: Trap External: Core Network Services (DNS/DHCP/BO..." label "id:1610264228" ridentifier 1610264228
  [ Evaluations: 95        Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @476 block drop in quick on igb2.22 inet proto tcp from any to ! (self:18) port 5351:5357 label "USER_RULE: Trap External: Core Network Services (DNS/DHCP/BO..." label "id:1610264228" ridentifier 1610264228
  [ Evaluations: 95        Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @477 block drop in quick on igb2.22 inet proto udp from any to ! (self:18) port = domain label "USER_RULE: Trap External: Core Network Services (DNS/DHCP/BO..." label "id:1610264228" ridentifier 1610264228
  [ Evaluations: 260       Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @478 block drop in quick on igb2.22 inet proto udp from any to ! (self:18) port = ntp label "USER_RULE: Trap External: Core Network Services (DNS/DHCP/BO..." label "id:1610264228" ridentifier 1610264228
  [ Evaluations: 165       Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @479 block drop in quick on igb2.22 inet proto udp from any to ! (self:18) port 67:68 label "USER_RULE: Trap External: Core Network Services (DNS/DHCP/BO..." label "id:1610264228" ridentifier 1610264228
  [ Evaluations: 165       Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @480 block drop in quick on igb2.22 inet proto udp from any to ! (self:18) port = time label "USER_RULE: Trap External: Core Network Services (DNS/DHCP/BO..." label "id:1610264228" ridentifier 1610264228
  [ Evaluations: 165       Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @481 block drop in quick on igb2.22 inet proto udp from any to ! (self:18) port 5351:5357 label "USER_RULE: Trap External: Core Network Services (DNS/DHCP/BO..." label "id:1610264228" ridentifier 1610264228
  [ Evaluations: 165       Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

  @482 block return in log quick on igb2.22 inet all label "USER_RULE: Default Block VOIP IPv4+IPv6" label "id:1610264385" ridentifier 1610264385
  [ Evaluations: 186       Packets: 186       Bytes: 80780       States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: Sat Sep 10 00:09:41 2022 ]

  @483 block return in log quick on igb2.22 inet6 all label "USER_RULE: Default Block VOIP IPv4+IPv6" label "id:1610264385" ridentifier 1610264385
  [ Evaluations: 0         Packets: 0         Bytes: 0           States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

stephenw10

So what are rules 122 and 123?

I suspect those will be the default allow out rules.

When the schedule stops and the pass rule no longer apply it's likely killing the states that are opened by it. That means the inbound states on igb2.22. But the States on WAN remain, you can see the age of the states there, and that allows replies from the provider to come back in and open new states outbound on igb2.22. Hence what you see. Unclear why those states cause an issue but the tests you did prove they do. Also unclear why the upgrade to 22.0x would behave any differently. It does kill the states more precisely which was not previously possible so it could be it was killing all the states in 2.5.2 preventing this happening.

So you should be able to prevent this by adding rules to stop those states being created.
You could create with the schedule but since you should never need those outbound states on the VoIP VLAN I would just add floating outbound block rules on there as specifically as possible.
So from the HOST_SVR_VOIP alias to the phone on port 5160.

Steve

4o4rh

@stephenw10 I don't know how you resolve the rule number, but looking at the states that are passing, the rules would be;

I'll add that floating rule now, and check it tonight when the schedule kicks in. (I renamed HOST_SVR_VOIP to HOST_CLN_VOIP to better reflect what is actually is)

HOST_SVR_VOIP

4o4rh

@stephenw10 hi steve, similarly, thanks to your test, i have also identified something that shouldn't be happening.

I have a nat forward rule to intercept port 53 and use pfsense as the dns server which forwards to 1.1.1.1 port 853

But I see an android device is able to get a connection to google port 53.
How is this possible?

all udp 192.168.40.5:53 (8.8.8.8:53) <- 192.168.40.81:53992       SINGLE:MULTIPLE
   age 00:00:36, expires in 00:01:54, 1:1 pkts, 60:106 bytes, rule 1173
   id: a5851b6300000002 creatorid: 5f2a04ac gateway: 0.0.0.0
   origif: bridge1
all udp 192.168.40.5:53 (8.8.4.4:53) <- 192.168.40.81:41940       SINGLE:MULTIPLE
   age 00:00:36, expires in 00:01:54, 1:1 pkts, 60:106 bytes, rule 1173
   id: a6851b6300000002 creatorid: 5f2a04ac gateway: 0.0.0.0
   origif: bridge1

stephenw10

It isn't. That state shows the destination is translated to 192.168.40.5 for both 8.8.8.8 and 8.8.4.4 which I imagine is what you want.

The rule number is shown at the beginning of the entry, so this is rule 37:

@37 pass in quick on igb2.22 inet proto udp from any port = bootpc to 192.168.22.5 port = bootps keep state label "allow access to DHCP server" ridentifier 1000003592
  [ Evaluations: 31        Packets: 62        Bytes: 20832       States: 0     ]
  [ Inserted: uid 0 pid 86711 State Creations: 0     ]
  [ Last Active Time: N/A ]

Those rogue states are almost certainly being passe by one of the internal 'allow out' rules not a user rule. That's why you will need to use a floating outbound rule to block it.

I would change that floating rule to be on the VoIP VLAN only since those are the only states actually causing an issue and being more precise there is less likely to cause problems later.
Though it looks like you understood what I meant since I used the wrong alias there and you have used the correct ones!

Steve

4o4rh

@stephenw10 Yes, that is what I want. Thanks for the clarification.
Made the change. Let you know tomorrow how it goes.

Thanks again. Couldn't have got this far without your help.

4o4rh

@stephenw10 worked liked a charm. Thanks so much for all the help. Very much appreciated

stephenw10

Nice result!