Troubleshooting SIP on FortiGate Firewalls

Since I replaced my lab FortiGate firewall from a 300E to a 601E, I ended up breaking my FortiVoice system.  I was getting an Unavailable on the FortiCall Trunk.

LAB-601E # dia sniffer packet any 'host 10.1.106.222 and host 66.11.10.90' 4 l 0
interfaces=[any]
filters=[host 10.1.106.222 and host 66.11.10.90]
7.650398 Server in 10.1.106.222.5060 -> 66.11.10.90.5060: udp 962
8.153128 Server in 10.1.106.222.5060 -> 66.11.10.90.5060: udp 962
9.157153 Server in 10.1.106.222.5060 -> 66.11.10.90.5060: udp 962
11.161198 Server in 10.1.106.222.5060 -> 66.11.10.90.5060: udp 962
15.165293 Server in 10.1.106.222.5060 -> 66.11.10.90.5060: udp 962
23.169456 Server in 10.1.106.222.5060 -> 66.11.10.90.5060: udp 962
39.173794 Server in 10.1.106.222.5060 -> 66.11.10.90.5060: udp 962
207.981956 Server in 10.1.106.222.5060 -> 66.11.10.90.5060: udp 595

I ran a packet capture and was not seeing the egress traffic.  I am using FortiCall as my SIP provider.  Their IP is 66.11.10.90 .  I would see it coming into the FortiGate on the Server VLAN but never see it hitting port which is my Gigapower circuit.

I disabled the offloading on the policy that corresponded to outbound calls to make sure I was not having a visibility issue due to offloading to ASICS.

Next, I made sure to turn off the SIP Session Helper

LAB-601E # config system session-helper

LAB-601E (session-helper) # show
config system session-helper
    edit 13
       set name sip
       set protocol 17
       set port 5060
   next
end

You disable it be typing delete 13​ then end

The problem continued and I was unable to bring the trunk in-service

I have a VIP created and I am using the set nat-source-vip enable option to ensure that when the mappedid initiates an outbound connection, it will use the same IP for the Source NAT that you are using for the VIP.

LAB-601E (VIP-FVE) # show
config firewall vip
    edit "VIP-FVE"
       set uuid a9b186da-224d-51eb-5c5e-0b73663d78ae
       set comment "FortiVoice VIP for SoftPhones and Voicemail"
       set extip 23.126.X.X
       set mappedip "10.1.106.222"
       set extintf "port1"
       set nat-source-vip enable
       set color 6
next
end

Now we wanted to filter the flows to identify what the packets where doing.  We want to limit the flow to the ones containing 66.11.10.90 and that are using port 5060

LAB-601E # diagnose debug flow filter addr 66.11.10.90
LAB-601E # diagnose debug flow filter port 5060
LAB-601E # diagnose debug flow show function-name enable
LAB-601E # diagnose debug flow trace start 100
LAB-601E # diagnose debug console timestamp enable
LAB-601E # diagnose debug enable

From the output, we were able to identify something strange that was going on.

2021-03-08 18:32:34 id=20085 trace_id=17 func=print_pkt_detail line=5639 msg="vd-root:0 received a packet(proto=17, 10.1.106.222:5060->66.11.10.90:5060) from Server. "
2021-03-08 18:32:34 id=20085 trace_id=17 func=resolve_ip_tuple_fast line=5720 msg="Find an existing session, id-02d71289, original direction"
2021-03-08 18:32:34 id=20085 trace_id=17 func=npu_handle_session44 line=1142 msg="Trying to offloading session from Server to port1, skb.npu_flag=00000000 ses.state=20140306 ses.npu_state=0x00000001"
2021-03-08 18:32:34 id=20085 trace_id=17 func=fw_forward_dirty_handler line=396 msg="state=20140306, state2=00000041, npu_state=00000001"
2021-03-08 18:32:34 id=20085 trace_id=17 func=av_receive line=305 msg="send to application layer"

As you can see in the last line, send to application layer this tells you the firewall is doing some ALG functions.  Pay particular attention to the session id (in my case, 02d71289).

We then wanted to view that session;

LAB-601E # diagnose sys session list | grep "02d71289" -A 5 -B 5
hook=post dir=org act=snat 10.1.106.222:5060->66.11.10.90:5060(23.126.X.X:5060)
hook=pre dir=reply act=dnat 66.11.10.90:5060->23.126.X.X:5060(10.1.106.222:5060)
hook=post dir=reply act=noop 66.11.10.90:5060->10.1.106.222:5060(0.0.0.0:0)
src_mac=1c:1b:0d:00:ea:8c
misc=0 policy_id=50 auth_info=0 chk_client_info=0 vd=0
serial=02d71289 tos=40/40 app_list=0 app=0 url_cat=0
sdwan_mbr_seq=0 sdwan_service_id=0
rpdb_link_id=00000000 rpdb_svc_id=0 ngfwid=n/a
npu_state=0x000001 no_offload
no_ofld_reason: redir-to-av mac-host-check disabled-by-policy

Here is the options we used

Usage: grep [-invfcABC] PATTERN
Options:

-i <----- Ignore case distinctions.
-n <----- Print line number with output lines.
-v <----- Select non-matching lines.
-f <----- Print fortinet config context.
-c <----- Only print count of matching lines.
-A <----- Print NUM lines of trailing context.
-B <----- Print NUM lines of leading context.
-C <----- Print NUM lines of output context.

The SIP ALG was giving us the problem.  We then did a config system settings and grep’d for sip and voip to find those sections we found that proxy-based was enabled.

With the grep output below, the proxy-based represents SIP ALG enabled.   If you want to disabled it, you will need to change it to kernel-helper-based

 

LAB-601E # config system settings

LAB-601E (settings) # show full-configuration | grep "sip"
    set sip-expectation disable
    set sip-nat-trace enable
    set sip-tcp-port 5060
    set sip-udp-port 5060
    set sip-ssl-port 5061

LAB-601E (settings) # show full-configuration | grep "voip"
   set default-voip-alg-mode proxy-based
   set gui-voip-profile disable

LAB-601E (settings) # set default-voip-alg-mode kernel-helper-based
LAB-601E (settings) # end

After we disabled the ALG, we needed to clear all the sessions from the matching firewall policy (in my case 50)

diagnose sys session filter policy 50 # To filter all sessions matching Policy 50

The to clear them,  diagnose sys session clear​

Once we did this we, my trunk came back in-service

I know it may be hard to see, but we can now see that the trunk is In-Service

Hopefully these troubleshooting tips will not only help you fix your SIP issues, but also give you some knowledge to troubleshoot connection in other scenarios.

Special thanks to Gaurav Bamania for his great help.