In this blog we will look at log entries via the cli along with some more debugging.
We will be trying to ssh from VDOM1 IP 192.168.250.50 to a device in the root VDOM on IP 192.168.100.220.
The connection is failing. Below are a few things to look at in regards troubleshooting this scenario.
CHECK DEBUG FLOW FILTER.
FG1 (VDOM1) # diagnose debug flow filter saddr 192.168.250.50
FG1 (VDOM1) # diagnose debug flow filter daddr 192.168.100.220
FG1 (VDOM1) # diagnose debug enable
FG1 (VDOM1) # diagnose debug flow trace start
FG1 (VDOM1) # id=20085 trace_id=1 func=print_pkt_detail line=5517 msg="vd-VDOM1:0 received a packet(proto=6, 192.168.250.50:49988->192.168.100.220:22) from port4. flag [S], seq 2872570577, ack 0, win 64240"
id=20085 trace_id=1 func=init_ip_session_common line=5682 msg="allocate a new session-00018033"
id=20085 trace_id=1 func=vf_ip_route_input_common line=2591 msg="find a route: flag=04000000 gw-10.1.1.1 via IVL_VDOM1"
id=20085 trace_id=1 func=fw_forward_handler line=753 msg="Allowed by Policy-3:"
FG1 (VDOM1) #
Looks good from a routing and policy perspective in VDOM1.
EXAMINE THE POLICY
FG1 (VDOM1) # sh firewall policy 3
config firewall policy
edit 3
set name "Ubuntu_SSH_ACCESS"
set uuid f3330ca0-a2ed-51ea-9e5e-ee96897bc657
set srcintf "port4"
set dstintf "IVL_VDOM1"
set srcaddr "H_192.168.250.50_WIN10.1"
set dstaddr "H_192.168.100.220_UBUNTU"
set action accept
set schedule "always"
set service "SSH"
set logtraffic all
set logtraffic-start enable
set fsso disable
next
end
FG1 (VDOM1) #
CHECK FIREWALL LOGS
Clear any log filter.
FG1 (VDOM1) # execute log filter reset
FG1 (VDOM1) # execute log filter dump
category: traffic
device: disk
start-line: 1
view-lines: 10
max-checklines: 0
HA member:
Filter:
Oftp search string:
FG1 (VDOM1) #
Set a new filter and check its status.
FG1 (VDOM1) # execute log filter field dstport 22
FG1 (VDOM1) # execute log filter dump
category: traffic
device: disk
start-line: 1
view-lines: 10
max-checklines: 0
HA member:
Filter: ( dstport "22" )
Oftp search string: (and (or dstport==22))
FG1 (VDOM1) #
Check the logs
FG1 (VDOM1) # execute log display
14 logs found.
10 logs returned.
1: date=2020-05-31 time=13:54:25 logid="0000000013" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590897265 srcip=192.168.250.50 srcport=50053 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=120927 proto=6 action="timeout" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=26 sentbyte=260 rcvdbyte=0 sentpkt=5 rcvdpkt=0 appcat="unscanned" crscore=5 craction=262144 crlevel="low"
:
snip
:
10: date=2020-05-31 time=13:36:51 logid="0000000015" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590896211 srcip=192.168.250.50 srcport=50003 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=104117 proto=6 action="start" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=0 sentbyte=0 rcvdbyte=0 sentpkt=0 appcat="unscanned"
FG1 (VDOM1) #
We can see there are 14 logs matching our filter and it showed us the newest 10 by default.
If we wanted to see the oldest 5 (5 is the minimum you can set) logs we could do this in relation to what our log shold at the time.
FG1 (VDOM1) # execute log filter view-lines 5
FG1 (VDOM1) # execute log filter start-line 10
FG1 (VDOM1) # execute log filter dump
category: traffic
device: disk
start-line: 10
view-lines: 5
max-checklines: 0
HA member:
Filter: ( dstport "22" )
Oftp search string: (and (or dstport==22))
FG1 (VDOM1) # execute log display
14 logs found.
5 logs returned.
10: date=2020-05-31 time=13:36:51 logid="0000000015" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590896211 srcip=192.168.250.50 srcport=50003 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=104117 proto=6 action="start" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=0 sentbyte=0 rcvdbyte=0 sentpkt=0 appcat="unscanned"
:
snip
:
14: date=2020-05-31 time=13:29:46 logid="0000000015" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590895786 srcip=192.168.250.50 srcport=49984 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=96973 proto=6 action="start" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=0 sentbyte=0 rcvdbyte=0 sentpkt=0 appcat="unscanned"
FG1 (VDOM1) #
Similarly, just to see the 5 newest logs rather than 10, set the display filters like so:
FG1 (VDOM1) # execute log filter start-line 1
FG1 (VDOM1) # execute log filter view-lines 5
FG1 (VDOM1) # execute log filter dump
category: traffic
device: disk
start-line: 1
view-lines: 5
max-checklines: 0
HA member:
Filter: ( dstport "22" )
Oftp search string: (and (or dstport==22))
FG1 (VDOM1) #
FG1 (VDOM1) # execute log display
14 logs found.
5 logs returned.
1: date=2020-05-31 time=13:54:25 logid="0000000013" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590897265 srcip=192.168.250.50 srcport=50053 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=120927 proto=6 action="timeout" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=26 sentbyte=260 rcvdbyte=0 sentpkt=5 rcvdpkt=0 appcat="unscanned" crscore=5 craction=262144 crlevel="low"
:
snip
:
5: date=2020-05-31 time=13:37:30 logid="0000000013" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590896249 srcip=192.168.250.50 srcport=50006 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=104479 proto=6 action="timeout" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=18 sentbyte=208 rcvdbyte=0 sentpkt=4 rcvdpkt=0 appcat="unscanned" crscore=5 craction=262144 crlevel="low"
FG1 (VDOM1) #
We can also add other fields to the search.
FG1 (VDOM1) # execute log filter field action timeout
FG1 (VDOM1) # execute log filter dump
category: traffic
device: disk
start-line: 6
view-lines: 5
max-checklines: 0
HA member:
Filter: ( action "timeout" ) AND ( dstport "22" )
Oftp search string: (and (or action==timeout not-exact) (or dstport==22))
FG1 (VDOM1) #
FG1 (VDOM1) # execute log display
7 logs found.
5 logs returned.
1: date=2020-05-31 time=13:54:25 logid="0000000013" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590897265 srcip=192.168.250.50 srcport=50053 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=120927 proto=6 action="timeout" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=26 sentbyte=260 rcvdbyte=0 sentpkt=5 rcvdpkt=0 appcat="unscanned" crscore=5 craction=262144 crlevel="low"
2: date=2020-05-31 time=13:51:53 logid="0000000013" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590897113 srcip=192.168.250.50 srcport=50046 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=118282 proto=6 action="timeout" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=26 sentbyte=260 rcvdbyte=0 sentpkt=5 rcvdpkt=0 appcat="unscanned" crscore=5 craction=262144 crlevel="low"
3: date=2020-05-31 time=13:37:30 logid="0000000013" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590896249 srcip=192.168.250.50 srcport=50006 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=104479 proto=6 action="timeout" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=18 sentbyte=208 rcvdbyte=0 sentpkt=4 rcvdpkt=0 appcat="unscanned" crscore=5 craction=262144 crlevel="low"
4: date=2020-05-31 time=13:37:17 logid="0000000013" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590896237 srcip=192.168.250.50 srcport=50004 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=104255 proto=6 action="timeout" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=18 sentbyte=208 rcvdbyte=0 sentpkt=4 rcvdpkt=0 appcat="unscanned" crscore=5 craction=262144 crlevel="low"
5: date=2020-05-31 time=13:37:05 logid="0000000013" type="traffic" subtype="forward" level="notice" vd="VDOM1" eventtime=1590896225 srcip=192.168.250.50 srcport=50003 srcintf="port4" srcintfrole="undefined" dstip=192.168.100.220 dstport=22 dstintf="IVL_VDOM1" dstintfrole="undefined" poluuid="f3330ca0-a2ed-51ea-9e5e-ee96897bc657" sessionid=104117 proto=6 action="timeout" policyid=3 policytype="policy" service="SSH" dstcountry="Reserved" srccountry="Reserved" trandisp="noop" duration=14 sentbyte=156 rcvdbyte=0 sentpkt=3 rcvdpkt=0 appcat="unscanned" crscore=5 craction=262144 crlevel="low"
FG1 (VDOM1) #
So the flow is permitted but timing out. Lets quickly check the flow again and see how root VDOM is handling the flow.
FG1 (VDOM1) # diagnose debug flow filter saddr 192.168.250.50
FG1 (VDOM1) # diagnose debug flow filter daddr 192.168.100.220
Determine the VDOM index.
FG1 (root) # sudo global diagnose sys vd list | grep root
name=root/root index=0 enabled use=124 rt_num=46 asym_rt=0 sip_helper=0, sip_nat_trace=1, mc_fwd=1, mc_ttl_nc=0, tpmc_sk_pl=0
FG1 (VDOM1) # diagnose debug flow filter vd 0
FG1 (VDOM1) # diagnose debug enable
FG1 (VDOM1) # diagnose debug flow trace start
FG1 (VDOM1) # id=20085 trace_id=9 func=print_pkt_detail line=5517 msg="vd-root:0 received a packet(proto=6, 192.168.250.50:50193->192.168.100.220:22) from IVL_VDOM0. flag [S], seq 2940179787, ack 0, win 64240"
id=20085 trace_id=9 func=init_ip_session_common line=5682 msg="allocate a new session-00028be2"
id=20085 trace_id=9 func=vf_ip_route_input_common line=2591 msg="find a route: flag=00000000 gw-192.168.100.220 via port2"
id=20085 trace_id=9 func=fw_forward_handler line=601 msg="Denied by forward policy check (policy 0)"
FG1 (VDOM1) #
We can see what the issue is, root VDOM see the SYN passed from VDOM1 but there is no policy.
After we add the policy all is good and the flow works.
FG1 (VDOM1) # id=20085 trace_id=10 func=print_pkt_detail line=5517 msg="vd-root:0 received a packet(proto=6, 192.168.250.50:50214->192.168.100.220:22) from IVL_VDOM0. flag [S], seq 2958070702, ack 0, win 64240"
id=20085 trace_id=10 func=init_ip_session_common line=5682 msg="allocate a new session-0002ad34"
id=20085 trace_id=10 func=vf_ip_route_input_common line=2591 msg="find a route: flag=00000000 gw-192.168.100.220 via port2"
id=20085 trace_id=10 func=fw_forward_handler line=753 msg="Allowed by Policy-4:"
FG1 (VDOM1) #
Finally, this page suggests that if we use -1 for the VDOM index we might get both VDOMS in one filter as -1 matches all VDOMs but it doesn't work.
https://kb.fortinet.com/kb/viewContent.do?externalId=FD32291&sliceId=1
FG1 (VDOM1) # diagnose debug flow filter vd -1
values must be in range 0-65535
Command fail. Return code -61
FG1 (VDOM1) # get system status | grep Version
Version: FortiGate-VM64 v6.0.9,build0335,200121 (GA)
Release Version Information: G
No comments:
New comments are not allowed.