FortiGate AntiVirus Proxy-Based FTPs issue

[zoriax]

Hello

I activated AV in WAN to LAN in Proxy-Based mode. When I tried to reach an FTPs server, my connect failed... If I disabled AV in rule all works fine.

Nothing blocked in log (all is logged and I can see the allow log in FortiGate). But that's strange because the "result" is empty. Like there is no traffic... 

Here my AV config

What is this behaviour and why my queries is "blocked" without any apparent reason and now explicit logs ? 

[zoriax]

After some search, It seems to be related to SSL/SSH Inspection Profile.... I don't wanted to do any SSL insecption. So what should I configure as profile for that ? 

If I do something like that, it doesn't work :

I I do "Full SSL Insepction" like that. It works (my FTPs connect works...)

[zoriax]

Why when I enabled FTPS in SSL pofile

I have the FortiGate certificate (expected behaviour, from winscp for exemple)

And I disabled it, my querie failed without any logs : 

[zoriax]

Hi ! 

Someone can help me ? It seems to be a "bug" or a mistake in configuration... 

[zoriax]

Hi again ! I founded the culprit. It was related to protocol options... 

If I setted FTPs works perfectly.

Someone can help me and give me more information about protocol options ? I'm not sure  I totally understand this feature :)

[seshuganesh]

Hi Team,

If you enable the protocol option field, scanning will be taking place on that port.

If you disable the protocol options field, scanning will not be taking place on that port.

For example, lets say you have blocked specific web page and in the protocol options you have disabled HTTP, in this case, scanning will not be taking place on HTTP and so firewall cannot block the website.

For your scenario, could you please get the working and non working flow filter logs.

Flow filter debug:

diag debug reset

diag debug disable

diag debug flow filter addr FTP_server_IP

diag debug flow show function-name enable

diag debug flow trace start 10000

diag debug enable

Once you get the output, you can stop debug by executing this command:

diag debug disable

I suspect, session helper which is required for FTP traffic is not getting initiated.

But we need to check debug flow for the same

[zoriax]

Hi ! 

Thanks for your return.

Please fin here debug logs

id=20085 trace_id=39 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 192.168.1.3:58377->18.137.181.55:21) tun_id=0.0.0.0 from lan. flag [S], seq 543784087, ack 0, win 64240"
id=20085 trace_id=39 func=init_ip_session_common line=6003 msg="allocate a new session-00009d07, tun_id=0.0.0.0"
id=20085 trace_id=39 func=rpdb_srv_match_input line=1028 msg="Match policy routing id=2130838504: to 18.137.181.55 via ifindex-24"
id=20085 trace_id=39 func=vf_ip_route_input_common line=2604 msg="find a route: flag=04000000 gw-213.3.210.43 via ppp2"
id=20085 trace_id=39 func=get_new_addr line=1227 msg="find SNAT: IP-45.68.11.199(from IPPOOL), port-58377"
id=20085 trace_id=39 func=fw_forward_handler line=874 msg="Allowed by Policy-1071741915: AV SNAT"
id=20085 trace_id=39 func=ids_receive line=328 msg="send to ips"
id=20085 trace_id=39 func=av_receive line=344 msg="send to application layer"
id=20085 trace_id=40 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 18.137.181.55:21->192.168.1.3:58377) tun_id=0.0.0.0 from local. flag [S.], seq 4026102881, ack 543784088, win 14600"
id=20085 trace_id=40 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, reply direction"
id=20085 trace_id=40 func=ip_session_output line=540 msg="send to ips"
id=20085 trace_id=40 func=__ip_session_run_tuple line=3542 msg="run helper-ftp(dir=reply)"
id=20085 trace_id=41 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 192.168.1.3:58377->18.137.181.55:21) tun_id=0.0.0.0 from lan. flag [.], seq 543784088, ack 4026102882, win 8212"
id=20085 trace_id=41 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, original direction"
id=20085 trace_id=41 func=npu_handle_session44 line=1162 msg="Trying to offloading session from lan to ppp2, skb.npu_flag=00000400 ses.state=00042302 ses.npu_state=0x00041008"
id=20085 trace_id=41 func=fw_forward_dirty_handler line=410 msg="state=00042302, state2=00000000, npu_state=00041008"
id=20085 trace_id=41 func=ids_receive line=328 msg="send to ips"
id=20085 trace_id=41 func=av_receive line=344 msg="send to application layer"
id=20085 trace_id=42 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 192.168.1.3:58377->18.137.181.55:21) tun_id=0.0.0.0 from local. flag [S], seq 1793108977, ack 0, win 65535"
id=20085 trace_id=42 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, original direction"
id=20085 trace_id=42 func=__ip_session_run_tuple line=3489 msg="SNAT 192.168.1.3->45.68.11.199:58377"
id=20085 trace_id=42 func=__ip_session_run_tuple line=3542 msg="run helper-ftp(dir=original)"
id=20085 trace_id=43 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 18.137.181.55:21->45.68.11.199:58377) tun_id=0.0.0.0 from ppp2. flag [S.], seq 1651724853, ack 1793108978, win 28960"
id=20085 trace_id=43 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, reply direction"
id=20085 trace_id=43 func=__ip_session_run_tuple line=3502 msg="DNAT 45.68.11.199:58377->192.168.1.3:58377"
id=20085 trace_id=43 func=vf_ip_route_input_common line=2604 msg="find a route: flag=00000000 gw-192.168.1.3 via lan"
id=20085 trace_id=43 func=npu_handle_session44 line=1162 msg="Trying to offloading session from ppp2 to lan, skb.npu_flag=00000400 ses.state=00042302 ses.npu_state=0x00041108"
id=20085 trace_id=43 func=fw_forward_dirty_handler line=410 msg="state=00042302, state2=00000000, npu_state=00041108"
id=20085 trace_id=43 func=av_receive line=344 msg="send to application layer"
id=20085 trace_id=44 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 192.168.1.3:58377->18.137.181.55:21) tun_id=0.0.0.0 from local. flag [.], seq 1793108978, ack 1651724854, win 11"
id=20085 trace_id=44 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, original direction"
id=20085 trace_id=44 func=__ip_session_run_tuple line=3489 msg="SNAT 192.168.1.3->45.68.11.199:58377"
id=20085 trace_id=45 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 18.137.181.55:21->45.68.11.199:58377) tun_id=0.0.0.0 from ppp2. flag [.], seq 1651724854, ack 1793108978, win 227"
id=20085 trace_id=45 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, reply direction"
id=20085 trace_id=45 func=__ip_session_run_tuple line=3502 msg="DNAT 45.68.11.199:58377->192.168.1.3:58377"
id=20085 trace_id=45 func=npu_handle_session44 line=1162 msg="Trying to offloading session from ppp2 to lan, skb.npu_flag=00000400 ses.state=00042302 ses.npu_state=0x00041108"
id=20085 trace_id=45 func=fw_forward_dirty_handler line=410 msg="state=00042302, state2=00000000, npu_state=00041108"
id=20085 trace_id=45 func=av_receive line=344 msg="send to application layer"
id=20085 trace_id=46 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 192.168.1.3:58377->18.137.181.55:21) tun_id=0.0.0.0 from local. flag [.], seq 1793108978, ack 1651724890, win 11"
id=20085 trace_id=46 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, original direction"
id=20085 trace_id=46 func=__ip_session_run_tuple line=3489 msg="SNAT 192.168.1.3->45.68.11.199:58377"
id=20085 trace_id=47 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 18.137.181.55:21->192.168.1.3:58377) tun_id=0.0.0.0 from local. flag [.], seq 4026102882, ack 543784088, win 115"
id=20085 trace_id=47 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, reply direction"
id=20085 trace_id=47 func=ip_session_output line=540 msg="send to ips"
id=20085 trace_id=48 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 192.168.1.3:58377->18.137.181.55:21) tun_id=0.0.0.0 from lan. flag [.], seq 543784088, ack 4026102918, win 8212"
id=20085 trace_id=48 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, original direction"
id=20085 trace_id=48 func=npu_handle_session44 line=1162 msg="Trying to offloading session from lan to ppp2, skb.npu_flag=00000400 ses.state=00042302 ses.npu_state=0x00041108"
id=20085 trace_id=48 func=fw_forward_dirty_handler line=410 msg="state=00042302, state2=00000000, npu_state=00041108"
id=20085 trace_id=48 func=ids_receive line=328 msg="send to ips"
id=20085 trace_id=48 func=av_receive line=344 msg="send to application layer"
id=20085 trace_id=49 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 18.137.181.55:21->192.168.1.3:58377) tun_id=0.0.0.0 from local. flag [.], seq 4026102918, ack 543784098, win 115"
id=20085 trace_id=49 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, reply direction"
id=20085 trace_id=49 func=ip_session_output line=540 msg="send to ips"
id=20085 trace_id=50 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 18.137.181.55:21->192.168.1.3:58377) tun_id=0.0.0.0 from local. flag [.], seq 4026102918, ack 543784098, win 115"
id=20085 trace_id=50 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, reply direction"
id=20085 trace_id=50 func=ip_session_output line=540 msg="send to ips"
id=20085 trace_id=51 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 192.168.1.3:58377->18.137.181.55:21) tun_id=0.0.0.0 from lan. flag [.], seq 543784098, ack 4026103030, win 8211"
id=20085 trace_id=51 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-00009d07, original direction"
id=20085 trace_id=51 func=npu_handle_session44 line=1162 msg="Trying to offloading session from lan to ppp2, skb.npu_flag=00000400 ses.state=00002302 ses.npu_state=0x00041108"
id=20085 trace_id=51 func=fw_forward_dirty_handler line=410 msg="state=00002302, state2=00000000, npu_state=00041108"
id=20085 trace_id=51 func=ids_receive line=328 msg="send to ips"
id=20085 trace_id=51 func=av_receive line=344 msg="send to application layer"

[seshuganesh]

Hi Team,

Please find this log:

d=20085 trace_id=42 func=__ip_session_run_tuple line=3489 msg="SNAT 192.168.1.3->45.68.11.199:58377"
id=20085 trace_id=42 func=__ip_session_run_tuple line=3542 msg="run helper-ftp(dir=original)"

I could see session helper is running for the above log, is the log taken during the working scenario or non working scenario?

please let us know

[zoriax]

Hi,

As I can see session helper is present when FTPs works 

id=20085 trace_id=10467 func=fw_forward_dirty_handler line=410 msg="state=00042200, state2=00000000, npu_state=00041108"
id=20085 trace_id=10467 func=ids_receive line=328 msg="send to ips"
id=20085 trace_id=10467 func=__ip_session_run_tuple line=3489 msg="SNAT192.168.1.3->18.137.181.55:53599"
id=20085 trace_id=10467 func=__ip_session_run_tuple line=3542 msg="run helper-ftp(dir=original)"
id=20085 trace_id=10468 func=print_pkt_detail line=5824 msg="vd-root:0 received a packet(proto=6, 45.68.11.199:21->18.137.181.55:53599) tun_id=0.0.0.0 from ppp2. flag [.], seq 1006160900, ack 1442572186, win 229"
id=20085 trace_id=10468 func=resolve_ip_tuple_fast line=5910 msg="Find an existing session, id-0001ba85, reply direction"
id=20085 trace_id=10468 func=__ip_session_run_tuple line=3502 msg="DNAT 18.137.181.55:53599->10.99.3.1:53599"

[seshuganesh]

Hi Team,

Please share the non working debug logs as well.