In order to debug the flow processing in SRX platforms, it is necessary to configure traceoptions.
Flow traceoptions are configured under the "security flow traceoptions" stanza. It requires a configuration change instead of just an operational command as parameters need to be specified. For detailed information about traceoptions, also check
KB16108.
This article discusses the following:
- Traceoption
- Security datapath-debug
Traceoption Feature (all SRX platforms)For all SRX platforms running all JUNOS versions, flow traceoptions are configured under "security flow traceoptions" stanza.
The configuration can be done by specifying three components:
- Trace file, fize size, number of files:
It is necessary to specify the file to which the trace will be logged. It is also possible to choose the file size and how many files will be saved, in case the output goes over the file size:
set security flow traceoptions file flow-trace size 1m files 2 world-readable
- Trace flags:
The flags indicate the level of tracing required. For flow traceoptions, the "basic-datapath" flag is recommended:
set security flow traceoptions flag basic-datapath
- Packet filters:
By default, flow traceoptions logs all packets processed by the system. The recommendation is to configure packet filters to capture only the desired traffic. This is to avoid system overload as traffic load can be very high. It is not necessary to configure filters for both directions because reverse traffic matches the same filter. Packet filters can be configured with source and destination prefix and port (including ranges), interface and protocol.
set security flow traceoptions packet-filter c2s source-prefix 1.1.1.10/32
Below is a configuration example:
{primary:node1}[edit security flow traceoptions]
root@cumin# show
file flow-trace size 1m files 2 world-readable;
flag basic-datapath;
packet-filter client {
source-prefix 8.8.8.0/24;
destination-prefix 1.1.1.0/24;
}
inactive: packet-filter outgoing {
source-prefix 4.4.4.0/24;
destination-prefix 1.1.1.0/23;
}
Note that part of the configuration is inactive. This can be very useful as the configuration doesn't need to be deleted, the user can activate it whenever needed.
Below are the corresponding configuration commands:
set security flow traceoptions file flow-trace
set security flow traceoptions file size 1m
set security flow traceoptions file files 2
set security flow traceoptions file world-readable
set security flow traceoptions flag basic-datapath
set security flow traceoptions packet-filter client source-prefix 8.8.8.0/24
set security flow traceoptions packet-filter client destination-prefix 1.1.1.0/24
set security flow traceoptions packet-filter outgoing source-prefix 4.4.4.0/24
set security flow traceoptions packet-filter outgoing destination-prefix 1.1.1.0/23
deactivate set security flow traceoptions packet-filter outgoing
In order to see the trace, use the command "show log <filename>". Match, trim and other show options can be used to help read the output; refer to
KB16108.
Security datapath-debug Feature (SRX3000 and SRX5000 platforms)
Specifically for SRX5000 and SRX3000 platforms, flow traceoptions can also be configured using "security datapath-debug" stanza. This advanced feature includes both trace (debug) and packet capture capabilities.
This stanza replaces "security flow traceoptions" with the objective of providing tracing capability for packet’s entire life cycle in datapath, from ingress to egress (not only flow processing). It augments the tracing capabilities with the following features:
- End-to-end debug:
Ingress IOC:
- mac-ingress (only SRX3000)
- np-ingress *
Ingress flow (lbt) *
Flow processing *
Route lookup (jexec)
Egress flow (pot) *
Egress IOC:
- np-egress *
- mac-egress (only SRX3000)
- Packet Dump: captures the first 100bytes of the packets including internal headers used by the system
- Packet Summary: prints a summary of the packet, including the following headers: *
Meta header (used internally by the system)
Flow header (used internally by the system)
IP header of the actual packet
- Trace: specific debugging messages for product engineering use *
- preserve-trace-order: due to multi-threaded processing, traces can be written to the trace file out of order. This option adds an extra debug header with a sequence number that can be used by routing engine (RE) to keep trace order.
- record-pic-history: adds an extra debug header to record each PIC through which the packets are processed
* "security datapath-debug" is supported starting from JUNOS 9.6; however only items marked with "*" are supported. All items are supported in JUNOS 10.0 and later.
Configuration
The configuration is also done in 3 steps:
- Trace file, fize size, number of files:
It is necessary to specify the file to which the trace will be logged. It is also possible to choose the file size and how many files will be saved in case the output goes over the file size:
set security datapath-debug traceoptions file e2e-trace size 10m files 3 world-readable
- Action profile:
With a custom action profile, it is strongly recommended to configure the following. All are optional, it depends on the type of trace desired.
- Specify the type of events to be traced and the action for each of them.
set security datapath-debug action-profile custom-profile event np-egress count
- Enable preserve-trace-order, record-pic-history options:
set security datapath-debug action-profile custom-profile preserve-trace-order
- Configure capture file if packet-dump option is used:
set security datapath-debug capture-file e2e-packet-dump
- Enable flow module trace:
set security datapath-debug action-profile custom-profile module flow flag all
- Packet filters:
If the default action is deny, that means no packets are captured if a packet filter is not configured. The recommendation is to configure the filter as specific as possible in order to avoid system overload as traffic load can be very high. It is necessary to configure filters for both directions. Packet filters can be configured with source and destination prefix and port (including ranges), and protocol.
set security datapath-debug packet-filter from-internal action-profile custom-profile
set security datapath-debug packet-filter from-internal source-prefix 1.1.1.0/24
set security datapath-debug packet-filter from-internal destination-prefix 4.4.4.0/24NOTE: If "security datapath-debug" is configured and active, "security flow traceoptions" should be either deactivated or deleted, as no traces will be logged to the file specified under "security flow traceoptions".
Configuration Example: Below is an example of the configuration commands:
set security datapath-debug traceoptions file e2e-trace
set security datapath-debug traceoptions file size 10m
set security datapath-debug traceoptions file files 3
set security datapath-debug traceoptions file world-readable
set security datapath-debug capture-file e2e-packet-dump
set security datapath-debug action-profile custom-profile preserve-trace-order
set security datapath-debug action-profile custom-profile record-pic-history
set security datapath-debug action-profile custom-profile event np-ingress count
set security datapath-debug action-profile custom-profile event np-egress count
set security datapath-debug action-profile custom-profile event jexec trace
set security datapath-debug action-profile custom-profile event lbt packet-dump
set security datapath-debug action-profile custom-profile event pot packet-summary
set security datapath-debug action-profile custom-profile module flow flag all
set security datapath-debug packet-filter from-internal action-profile custom-profile
set security datapath-debug packet-filter from-internal source-prefix 1.1.1.0/24
set security datapath-debug packet-filter from-internal destination-prefix 4.4.4.0/24
set security datapath-debug packet-filter from-external action-profile custom-profile
set security datapath-debug packet-filter from-external source-prefix 4.4.4.0/24
set security datapath-debug packet-filter from-external destination-prefix 1.1.1.0/24
NOTE: If "security datapath-debug" is configured and active, "security flow traceoptions" should be either deactivated or deleted, as no traces will be logged to the file specified under "security flow traceoptions".
Verify Configuration:Use "show security datapath-debug action-profile" command to see the active action-profiles. The output below shows an example with two packet filters:
root@cumin> show security datapath-debug action-profile
End to end debug action profile
Packet Filter from-internal: Profile name: custom-profile
np-ingress: packet-summary,count,record-history
np-egress: record-history
lbt: record-history
Packet Filter from-external: Profile name: custom-profile
np-ingress: packet-summary,count,record-history
np-egress: record-history
lbt: record-history
Display Trace Output:In order to see the flow module trace, use the command "show log <filename>". Match, trim and other show options can be used to help read the output; refer to
KB16108. Below is an example with the preserve-trace-order and record-pic-history options enabled. Note that the output was filtered with "except" option to remove the PIC history and thread id information. This is very usefull if the objective is to check only the flow processing:
root@cumin> sh log e2e-trace | except "thread_id" | except "pic history"
Dec 22 13:39:03 cumin clear-log[8981]: logfile cleared
CP flow starts, mbuf=0x78c02400, ifl_idx=72, ctxt_type=0xd
cp_flow_fast_lookup
cp_flow_first_sanity_check: in <reth0.0>, out <N/A>
cp_flow_first_create_session
CP allocates a CP session
CP couldn't find session, creates a pending session 624
CP fwd pkt to SPU ==*21*==, iif: 84, flag: 0x00000100
SPU received an event, type 80
SPU received pak with event message from CP, cp_sess_id=00000270 a
in_ifp <client:reth0.0>
flow_process_pkt_exception: setting rtt in lpak to 2f5c48a8
flow_process_pkt_exception: local_flag: 0x00000100
reth0.0:1.1.1.11->4.4.4.10, icmp, (8/0)
find flow: table 0x5e15e4a0, hash 247136(0x7ffff), sa 1.1.1.11, da 4.4.4.10, sp 52992, dp 512, proto 1, tok 512
no session found, start first path. in_tunnel - 0, from_cp_flag - 2048
flow_first_create_session
flow_first_in_dst_nat: in <reth0.0>, out <N/A> dst_adr 4.4.4.10, sp 52992, dp 512
chose interface reth0.0 as incoming nat if.
flow_first_rule_dst_xlate: DST no-xlate: 0.0.0.0(0) to 4.4.4.10(512)
flow_first_routing: call flow_route_lookup(): src_ip 1.1.1.11, x_dst_ip 4.4.4.10, in ifp reth0.0, out ifp N/A sp 52992, dp 512,
ip_proto 1, tos 0
Doing DESTINATION addr route-lookup
routed (x_dst_ip 4.4.4.10) from client (reth0.0 in 1) to reth3.0, Next-hop: 4.4.4.10
policy search from zone client-> zone vpn-ssg
app 0, timeout 60s, curr ageout 60s
flow_first_src_xlate: 1.1.1.11/52992 -> 4.4.4.10/512 | 4.4.4.10/512 -> 0.0.0.0/52992: nat_src_xlated: False,
nat_src_xlate_failed: False
flow_first_src_xlate: src nat 0.0.0.0(52992) to 4.4.4.10(512) returns status: 0, rule/pool id: 0/0, pst_nat: False.
dip id = 0/0, 1.1.1.11/52992->1.1.1.11/52992
flow_first_get_out_ifp: 1000 -> cone nat test
choose interface reth3.0 as outgoing phy if
is_loop_pak: No loop: on ifp: reth3.0, addr: 4.4.4.10, rtt_idx:0
check nsrp pak fwd: in_tun=0x0, VSD 1 for out ifp reth3.0
vsd 1 is active
policy is NULL (wx/pim scenario)
sm_flow_interest_check: app_id 0, policy 6, app_svc_en 0, flags 0x2. not interested
flow_first_service_lookup(): natp(0x3802d3b0): app_id, 0(0).
service lookup identified service 0.
flow_first_final_check: in <reth0.0>, out <reth3.0>
install vector flow_fast_ha_fwd_check_vector
install vector flow_ttl_vector
install vector flow_icmp_info_process_vector
install vector flow_frag_list_vector
install vector flow_send_vector
install vector NULL
create new vector list 220-135a83c8.
Session (id:279) created for first pak 220
flow_first_install_session======> 0x3802d3b0
nsp 0x3802d3b0, nsp2 0x3802d42c
make_nsp_ready_no_resolve()
route lookup: dest-ip 1.1.1.11 orig ifp reth0.0 output_ifp reth0.0 orig-zone 8 out-zone 8 vsd 1
route to 1.1.1.11
SPU send install sess to CP cp_sess_id=00000270, spu_sess_id=00000117, natp=0x3802d3b0
flow found or created a pending session.
flow_process_pkt_exception: Freeing lpak 2f95a710 associated with mbuf 0xe6a3a00
----- flow_process_pkt rc 0xf (fp rc 0)
flow process pak fast ifl 69 in_ifp reth3.0
flow_np_session_id2nsp: NP hdr: session id - 279, Flag - 0
flow session id 279
vsd 1 is active
mbuf 0xe707600, exit nh 0x982f3c2
----- flow_process_pkt rc 0x0 (fp rc 0)
For packet summary and trace actions, use also "show log <filename>". Below is an example with "packet-summary" and "record-pic-history" options enabled. This information is useful when debugging packet loss inside the system. The recommendation is to use np-egress event with packet-summary action, together with record-pic-history option; this is because logging on the egress side shows the complete path the packet had through the system.
{primary:node1}
root@cumin> show log e2e-trace
Dec 22 12:42:29 cumin clear-log[5294]: logfile cleared
Dec 22 12:42:37 12:42:07.877927:CID-01:FPC-03:PIC-02:THREAD_ID-00:FINDEX:0:SEQ:185:TC:1
PIC History: ->C1/F3/P1->C1/F4/P0->C1/F4/P1->C1/F3/P2
Meta: Src: F4/P1 Dst: F3/P2
IP: saddr 1.1.1.11 daddr 4.4.4.10 proto 1 len 60
Dec 22 12:42:39 (Timeout): 12:42:07.878300:CID-01:FPC-03:PIC-01:THREAD_ID-00:FINDEX:1:SEQ:185:TC:1
PIC History: ->C1/F3/P2->C1/F4/P1->C1/F3/P1
Meta: Src: F4/P1 Dst: F3/P1
IP: saddr 4.4.4.10 daddr 1.1.1.11 proto 1 len 60
Check
KB16118 for detail about meta header output.