root> show log debug01 | no-more May 29 01:27:00 clear-log[1370]: logfile cleared May 29 01:27:27 traceoptions flag May 29 01:27:27 Read [security flow traceoptions config] = 1 May 29 01:27:27 trace flag 0x2 May 29 01:27:27 Going to read [security flow traceoptions packet-filter] config] May 29 01:27:27 Read flow packet-filter f0 May 29 01:27:27 Read [security flow pending-sess-queue-length] = 5 May 29 01:27:27 Read [security flow tcp-sessionsyn-flood-protection-mode] = 1 May 29 01:27:27 [security flow] config read successfully May 29 01:27:27 [security flow] config read successfully May 29 01:27:27 Using default security forwarding-options May 29 01:27:27 Forwarding options: inet 2, inet6 3, mpls 3, iso 3 May 29 01:27:27 Using default security policy violation May 29 01:27:27 flow_ssam_sync_config: FLOW SSAM config sync'ing - started May 29 01:27:27 Getting [flow main] config blob from ssam May 29 01:27:27 flow_ssam_get_obj_config: Config blob [flow main] fetched May 29 01:27:27 Getting [flow tcp-mss] config blob from ssam May 29 01:27:27 flow_ssam_get_obj_config: Config blob [flow tcp-mss] fetched May 29 01:27:27 Getting [flow tcp-session] config blob from ssam May 29 01:27:27 flow_ssam_get_obj_config: Config blob [flow tcp-session] fetched May 29 01:27:27 Getting [flow flow-mode] config blob from ssam May 29 01:27:27 flow_ssam_get_obj_config: Config blob [flow flow-mode] fetched May 29 01:27:27 Getting [flow traceoptions] config blob from ssam May 29 01:27:27 flow_ssam_get_obj_config: Config blob [flow traceoptions] fetched May 29 01:27:27 Pushing updated [flow traceoptions] config blob into ssam, type: 2147483671, size: 24 May 29 01:27:27 Changed [flow traceoptions] blob into ssam type 2147483671, len 24 May 29 01:27:27 Getting [flow aging] config blob from ssam May 29 01:27:27 flow_ssam_get_obj_config: Config blob [flow aging] fetched May 29 01:27:27 Getting [flow bridge] config blob from ssam May 29 01:27:27 flow_ssam_get_obj_config: Config blob [flow bridge] fetched May 29 01:27:27 Getting [flow filter] config blob from ssam May 29 01:27:27 Pushing updated [flow filter] config blob into ssam. type: 2147483673. May 29 01:27:27 flow_ssam_add_filter_config: add filter blob: size 200, count 1 May 29 01:27:27 Getting [flow policy-violation] config blob from ssam May 29 01:27:27 flow_ssam_get_obj_config: Config blob [flow policy-violation] fetched May 29 01:27:27 Pushing updated [flow sess-dist-mode] config blob into ssam, type: 2147483749, size: 4 May 29 01:27:27 Changed [flow sess-dist-mode] blob into ssam type 2147483749, len 4 May 29 01:27:27 Flow SSAM Config sync'ing - completed May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow0: Rate limit changed to 0 May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow0: Destination ID set to 2 May 29 01:27:27 01:27:27.774979:CID-0:RT:flow_filter_config_ssam_handler: Received a Config request op=1 for flow filter May 29 01:27:27 01:27:27.774979:CID-0:RT:flow_filter_config_ssam_handler: received GENCFG_OP_ADD for flow_filter May 29 01:27:27 01:27:27.774979:CID-0:RT:filter 0 name f0 is set May 29 01:27:27 01:27:27.775111:CID-0:RT:flow_spu_hash_config_ssam_handler: Received a Config request op=2 for flow spu hash May 29 01:27:27 01:27:27.775111:CID-0:RT:flow_spu_hash_config_ssam_handler: received GENCFG_OP_ADD for flow_spu_hash May 29 01:27:27 01:27:27.775207:CID-0:RT:avt_config_ssam_handler: for lsys id 0 May 29 01:27:27 01:27:27.775296:CID-0:RT:avt_config_ssam_handler: for lsys id 0 May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow1: Rate limit changed to 0 May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow1: Destination ID set to 2 May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow2: Rate limit changed to 0 May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow2: Destination ID set to 2 May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow3: Rate limit changed to 0 May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow3: Destination ID set to 2 May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow4: Rate limit changed to 0 May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow4: Destination ID set to 2 May 29 01:27:27 01:27:27.774002:CID-0:CTRL:flow5: Rate limit changed to 0 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow5: Destination ID set to 2 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow6: Rate limit changed to 0 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow6: Destination ID set to 2 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow7: Rate limit changed to 0 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow7: Destination ID set to 2 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow8: Rate limit changed to 0 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow8: Destination ID set to 2 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow9: Rate limit changed to 0 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow9: Destination ID set to 2 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow10: Rate limit changed to 0 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow10: Destination ID set to 2 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow11: Rate limit changed to 0 May 29 01:27:27 01:27:27.774477:CID-0:CTRL:flow11: Destination ID set to 2 May 29 01:27:34 01:27:34.625499:CID-0:RT:<10.10.10.1/34172->10.10.10.2/33434;17> matched filter f0: May 29 01:27:34 01:27:34.625499:CID-0:RT:packet [40] ipid = 34173, @430814d2 May 29 01:27:34 01:27:34.625499:CID-0:RT:---- flow_process_pkt: (thd 1): flow_ctxt type 0, common flag 0x0, mbuf 0x43081280, rtbl_idx = 5 May 29 01:27:34 01:27:34.625499:CID-0:RT: flow process pak fast ifl 75 in_ifp lt-0/0/0.101 May 29 01:27:34 01:27:34.625499:CID-0:RT: find flow: table 0x47cb0cf8, hash 39580(0xffff), sa 10.10.10.1, da 10.10.10.2, sp 34172, dp 33434, proto 17, tok 20489 May 29 01:27:34 01:27:34.625499:CID-0:RT:check self-traffic on lt-0/0/0.101, in_tunnel 0x0 May 29 01:27:34 01:27:34.625499:CID-0:RT:retcode: 0x4 May 29 01:27:34 01:27:34.625499:CID-0:RT:pak_for_self : proto 17, dst port 33434, action 0x4 May 29 01:27:34 01:27:34.625499:CID-0:RT: flow_first_create_session May 29 01:27:34 01:27:34.625499:CID-0:RT:(flow_first_create_session) usp_tagged set session as mng session May 29 01:27:34 01:27:34.625499:CID-0:RT:Installing pending sess (5) in ager May 29 01:27:34 01:27:34.625499:CID-0:RT:First path alloc and instl pending session, natp=0x4ab478e8, id=5 May 29 01:27:34 01:27:34.625499:CID-0:RT: flow_first_in_dst_nat: in , out dst_adr 10.10.10.2, sp 34172, dp 33434 May 29 01:27:34 01:27:34.625499:CID-0:RT: chose interface lt-0/0/0.101 as incoming nat if. May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_first_rule_dst_xlate: DST no-xlate: 0.0.0.0(0) to 10.10.10.2(33434) May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_first_routing: vr_id 5, call flow_route_lookup(): src_ip 10.10.10.1, x_dst_ip 10.10.10.2, in ifp lt-0/0/0.101, out ifp N/A sp 34172, dp 33434, ip_proto 17, tos 0 May 29 01:27:34 01:27:34.625499:CID-0:RT:Doing DESTINATION addr route-lookup May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_rt_lkup in VR-id: 5 May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_rt_lkup: Found route entry 0x0x4dc1d110,nh id 0x253, out if 0x0 May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_rt_lkup: get NH in local route May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_rt_lkup: nh word 0xfffb0006 May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_ipv4_rt_lkup success 10.10.10.2, iifl 0x4b, oifl 0x0 May 29 01:27:34 01:27:34.625499:CID-0:RT: routed (x_dst_ip 10.10.10.2) from TR2 (lt-0/0/0.101 in 0) to .local..5, Next-hop: 10.10.10.2 May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_first_policy_search: policy search from zone TR2-> zone junos-host (0x0,0x857c829a,0x829a) May 29 01:27:34 01:27:34.625499:CID-0:RT: app 0, timeout 60s, curr ageout 60s May 29 01:27:34 01:27:34.625499:CID-0:RT: permitted by policy self-traffic-policy(1) May 29 01:27:34 01:27:34.625499:CID-0:RT: packet passed, Permitted by policy. May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_first_src_xlate: nat_src_xlated: False, nat_src_xlate_failed: False May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_first_src_xlate: src nat returns status: 0, rule/pool id: 0/0, pst_nat: False. May 29 01:27:34 01:27:34.625499:CID-0:RT: dip id = 0/0, 10.10.10.1/34172->10.10.10.1/34172 protocol 0 May 29 01:27:34 01:27:34.625499:CID-0:RT: choose interface .local..5 as outgoing phy if May 29 01:27:34 01:27:34.625499:CID-0:RT:is_loop_pak: No loop: ifp doesnt match .local..5 vs looked-up: lt-0/0/0.101, addr: 10.10.10.2, rtt_idx: 5, addr_type:0x3 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf : Alloc sess plugin info for session 5 May 29 01:27:34 01:27:34.625499:CID-0:RT:[JSF]Normal interest check. regd plugins 18, enabled impl mask 0x0 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 2, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 3, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 5, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 6, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 7, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 8, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 14, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:+++++++++++jsf_test_plugin_data_evh: 3 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 15, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 21, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 22, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 25, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 26, svc_req 0x0, impl mask 0x0. rc 2 May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf int check: plugin id 27, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:34 01:27:34.625499:CID-0:RT:[JSF]Plugins(0x0, count 0) enabled for session = 168430081, impli mask(0x0), post_nat cnt 5 svc req(0x0) May 29 01:27:34 01:27:34.625499:CID-0:RT:-jsf : no plugin interested for session 5, free sess plugin info May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_first_service_lookup(): natp(0x4ab478e8): app_id, 0(0). May 29 01:27:34 01:27:34.625499:CID-0:RT: service lookup identified service 0. May 29 01:27:34 01:27:34.625499:CID-0:RT: flow_first_final_check: in , out <.local..5> May 29 01:27:34 01:27:34.625499:CID-0:RT:In flow_first_complete_session May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_first_complete_session, pak_ptr: 0x47d31cd8, nsp: 0x4ab478e8, in_tunnel: 0x0 May 29 01:27:34 01:27:34.625499:CID-0:RT:construct v4 vector for nsp2 May 29 01:27:34 01:27:34.625499:CID-0:RT: existing vector list 0-45870e60. May 29 01:27:34 01:27:34.625499:CID-0:RT: Session (id:5) created for first pak 0 May 29 01:27:34 01:27:34.625499:CID-0:RT:first pak processing successful May 29 01:27:34 01:27:34.625499:CID-0:RT: flow_first_install_session======> 0x4ab478e8 May 29 01:27:34 01:27:34.625499:CID-0:RT: nsp 0x4ab478e8, nsp2 0x4ab47968 May 29 01:27:34 01:27:34.625499:CID-0:RT: make_nsp_ready_no_resolve() May 29 01:27:34 01:27:34.625499:CID-0:RT:make_nsp_ready_no_resolve: Route Lookup for dest route. Src_ip 10.10.10.2 Dst_ip 10.10.10.1 protocal 17 if_id 1304475412 May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_rt_lkup in VR-id: 5 May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_rt_lkup: Found route entry 0x0x4dc1cdb0,nh id 0x25a, out if 0x4b May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_rt_lkup: nh word 0x80010 May 29 01:27:34 01:27:34.625499:CID-0:RT:flow_ipv4_rt_lkup success 10.10.10.1, iifl 0x4b, oifl 0x4b May 29 01:27:34 01:27:34.625499:CID-0:RT: route lookup: dest-ip 10.10.10.1 orig ifp lt-0/0/0.101 output_ifp lt-0/0/0.101 orig-zone 9 out-zone 9 vsd 0 May 29 01:27:34 01:27:34.625499:CID-0:RT: route to 10.10.10.1 May 29 01:27:34 01:27:34.625499:CID-0:RT:no need update ha May 29 01:27:34 01:27:34.625499:CID-0:RT:Installing c2s NP session wing May 29 01:27:34 01:27:34.625499:CID-0:RT: flow_spu_install_np_session: FLOW STUB May 29 01:27:34 01:27:34.625499:CID-0:RT:Installing s2c NP session wing May 29 01:27:34 01:27:34.625499:CID-0:RT: flow_spu_install_np_session: FLOW STUB May 29 01:27:34 01:27:34.625499:CID-0:RT:updating pending sess (5) in ager May 29 01:27:34 01:27:34.625499:CID-0:RT:first path session installation succeeded May 29 01:27:34 01:27:34.625499:CID-0:RT: flow got session. May 29 01:27:34 01:27:34.625499:CID-0:RT: flow fast tcp/udp session id 5 May 29 01:27:34 01:27:34.625499:CID-0:RT: vector bits 0x0 vector 0x45870e60 May 29 01:27:34 01:27:34.625499:CID-0:RT:insert usp tag for vpn apps May 29 01:27:34 01:27:34.625499:CID-0:RT:mbuf 0x43081280, exit nh 0xfffb0006 May 29 01:27:34 01:27:34.625499:CID-0:RT: ----- flow_process_pkt rc 0x0 (fp rc 0) May 29 01:27:34 01:27:34.628569:CID-0:RT:<10.10.10.2/1->10.10.10.1/1;1> matched filter f0: May 29 01:27:34 01:27:34.628569:CID-0:RT:packet [56] ipid = 4717, @43080bd2 May 29 01:27:34 01:27:34.628569:CID-0:RT:---- flow_process_pkt: (thd 1): flow_ctxt type 0, common flag 0x0, mbuf 0x43080980, rtbl_idx = 4 May 29 01:27:34 01:27:34.628569:CID-0:RT: flow process pak fast ifl 74 in_ifp lt-0/0/0.100 May 29 01:27:34 01:27:34.628569:CID-0:RT: lt-0/0/0.100:10.10.10.2->10.10.10.1, icmp, (3/3) May 29 01:27:34 01:27:34.628569:CID-0:RT: find flow: table 0x47cb0cf8, hash 9245(0xffff), sa 10.10.10.2, da 10.10.10.1, sp 33434, dp 34172, proto 17, tok 16392 May 29 01:27:34 01:27:34.628569:CID-0:RT: packet dropped, no session found for embedded icmp pak May 29 01:27:34 01:27:34.628569:CID-0:RT: flow find session returns error. May 29 01:27:34 01:27:34.628569:CID-0:RT: ----- flow_process_pkt rc 0x7 (fp rc -1) May 29 01:27:39 01:27:39.696026:CID-0:RT:<10.10.10.1/34172->10.10.10.2/33435;17> matched filter f0: May 29 01:27:39 01:27:39.696026:CID-0:RT:packet [40] ipid = 34174, @430814d2 May 29 01:27:39 01:27:39.696026:CID-0:RT:---- flow_process_pkt: (thd 1): flow_ctxt type 0, common flag 0x0, mbuf 0x43081280, rtbl_idx = 5 May 29 01:27:39 01:27:39.696026:CID-0:RT: flow process pak fast ifl 75 in_ifp lt-0/0/0.101 May 29 01:27:39 01:27:39.696026:CID-0:RT: find flow: table 0x47cb0cf8, hash 39581(0xffff), sa 10.10.10.1, da 10.10.10.2, sp 34172, dp 33435, proto 17, tok 20489 May 29 01:27:39 01:27:39.696026:CID-0:RT:check self-traffic on lt-0/0/0.101, in_tunnel 0x0 May 29 01:27:39 01:27:39.696026:CID-0:RT:retcode: 0x4 May 29 01:27:39 01:27:39.696026:CID-0:RT:pak_for_self : proto 17, dst port 33435, action 0x4 May 29 01:27:39 01:27:39.696026:CID-0:RT: flow_first_create_session May 29 01:27:39 01:27:39.696026:CID-0:RT:(flow_first_create_session) usp_tagged set session as mng session May 29 01:27:39 01:27:39.696026:CID-0:RT:Installing pending sess (6) in ager May 29 01:27:39 01:27:39.696026:CID-0:RT:First path alloc and instl pending session, natp=0x4ab47aa8, id=6 May 29 01:27:39 01:27:39.696026:CID-0:RT: flow_first_in_dst_nat: in , out dst_adr 10.10.10.2, sp 34172, dp 33435 May 29 01:27:39 01:27:39.696026:CID-0:RT: chose interface lt-0/0/0.101 as incoming nat if. May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_first_rule_dst_xlate: DST no-xlate: 0.0.0.0(0) to 10.10.10.2(33435) May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_first_routing: vr_id 5, call flow_route_lookup(): src_ip 10.10.10.1, x_dst_ip 10.10.10.2, in ifp lt-0/0/0.101, out ifp N/A sp 34172, dp 33435, ip_proto 17, tos 0 May 29 01:27:39 01:27:39.696026:CID-0:RT:Doing DESTINATION addr route-lookup May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_rt_lkup in VR-id: 5 May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_rt_lkup: Found route entry 0x0x4dc1d110,nh id 0x253, out if 0x0 May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_rt_lkup: get NH in local route May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_rt_lkup: nh word 0xfffb0006 May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_ipv4_rt_lkup success 10.10.10.2, iifl 0x4b, oifl 0x0 May 29 01:27:39 01:27:39.696026:CID-0:RT: routed (x_dst_ip 10.10.10.2) from TR2 (lt-0/0/0.101 in 0) to .local..5, Next-hop: 10.10.10.2 May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_first_policy_search: policy search from zone TR2-> zone junos-host (0x0,0x857c829b,0x829b) May 29 01:27:39 01:27:39.696026:CID-0:RT: app 0, timeout 60s, curr ageout 60s May 29 01:27:39 01:27:39.696026:CID-0:RT: permitted by policy self-traffic-policy(1) May 29 01:27:39 01:27:39.696026:CID-0:RT: packet passed, Permitted by policy. May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_first_src_xlate: nat_src_xlated: False, nat_src_xlate_failed: False May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_first_src_xlate: src nat returns status: 0, rule/pool id: 0/0, pst_nat: False. May 29 01:27:39 01:27:39.696026:CID-0:RT: dip id = 0/0, 10.10.10.1/34172->10.10.10.1/34172 protocol 0 May 29 01:27:39 01:27:39.696026:CID-0:RT: choose interface .local..5 as outgoing phy if May 29 01:27:39 01:27:39.696026:CID-0:RT:is_loop_pak: No loop: ifp doesnt match .local..5 vs looked-up: lt-0/0/0.101, addr: 10.10.10.2, rtt_idx: 5, addr_type:0x3 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf : Alloc sess plugin info for session 6 May 29 01:27:39 01:27:39.696026:CID-0:RT:[JSF]Normal interest check. regd plugins 18, enabled impl mask 0x0 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 2, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 3, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 5, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 6, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 7, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 8, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 14, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:+++++++++++jsf_test_plugin_data_evh: 3 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 15, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 21, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 22, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 25, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 26, svc_req 0x0, impl mask 0x0. rc 2 May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf int check: plugin id 27, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:39 01:27:39.696026:CID-0:RT:[JSF]Plugins(0x0, count 0) enabled for session = 168430081, impli mask(0x0), post_nat cnt 6 svc req(0x0) May 29 01:27:39 01:27:39.696026:CID-0:RT:-jsf : no plugin interested for session 6, free sess plugin info May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_first_service_lookup(): natp(0x4ab47aa8): app_id, 0(0). May 29 01:27:39 01:27:39.696026:CID-0:RT: service lookup identified service 0. May 29 01:27:39 01:27:39.696026:CID-0:RT: flow_first_final_check: in , out <.local..5> May 29 01:27:39 01:27:39.696026:CID-0:RT:In flow_first_complete_session May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_first_complete_session, pak_ptr: 0x47d31cd8, nsp: 0x4ab47aa8, in_tunnel: 0x0 May 29 01:27:39 01:27:39.696026:CID-0:RT:construct v4 vector for nsp2 May 29 01:27:39 01:27:39.696026:CID-0:RT: existing vector list 0-45870e60. May 29 01:27:39 01:27:39.696026:CID-0:RT: Session (id:6) created for first pak 0 May 29 01:27:39 01:27:39.696026:CID-0:RT:first pak processing successful May 29 01:27:39 01:27:39.696026:CID-0:RT: flow_first_install_session======> 0x4ab47aa8 May 29 01:27:39 01:27:39.696026:CID-0:RT: nsp 0x4ab47aa8, nsp2 0x4ab47b28 May 29 01:27:39 01:27:39.696026:CID-0:RT: make_nsp_ready_no_resolve() May 29 01:27:39 01:27:39.696026:CID-0:RT:make_nsp_ready_no_resolve: Route Lookup for dest route. Src_ip 10.10.10.2 Dst_ip 10.10.10.1 protocal 17 if_id 1304475412 May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_rt_lkup in VR-id: 5 May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_rt_lkup: Found route entry 0x0x4dc1cdb0,nh id 0x25a, out if 0x4b May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_rt_lkup: nh word 0x80010 May 29 01:27:39 01:27:39.696026:CID-0:RT:flow_ipv4_rt_lkup success 10.10.10.1, iifl 0x4b, oifl 0x4b May 29 01:27:39 01:27:39.696026:CID-0:RT: route lookup: dest-ip 10.10.10.1 orig ifp lt-0/0/0.101 output_ifp lt-0/0/0.101 orig-zone 9 out-zone 9 vsd 0 May 29 01:27:39 01:27:39.696026:CID-0:RT: route to 10.10.10.1 May 29 01:27:39 01:27:39.696026:CID-0:RT:no need update ha May 29 01:27:39 01:27:39.696026:CID-0:RT:Installing c2s NP session wing May 29 01:27:39 01:27:39.696026:CID-0:RT: flow_spu_install_np_session: FLOW STUB May 29 01:27:39 01:27:39.696026:CID-0:RT:Installing s2c NP session wing May 29 01:27:39 01:27:39.696026:CID-0:RT: flow_spu_install_np_session: FLOW STUB May 29 01:27:39 01:27:39.696026:CID-0:RT:updating pending sess (6) in ager May 29 01:27:39 01:27:39.696026:CID-0:RT:first path session installation succeeded May 29 01:27:39 01:27:39.696026:CID-0:RT: flow got session. May 29 01:27:39 01:27:39.696026:CID-0:RT: flow fast tcp/udp session id 6 May 29 01:27:39 01:27:39.696026:CID-0:RT: vector bits 0x0 vector 0x45870e60 May 29 01:27:39 01:27:39.696026:CID-0:RT:insert usp tag for vpn apps May 29 01:27:39 01:27:39.696026:CID-0:RT:mbuf 0x43081280, exit nh 0xfffb0006 May 29 01:27:39 01:27:39.696026:CID-0:RT: ----- flow_process_pkt rc 0x0 (fp rc 0) May 29 01:27:39 01:27:39.699312:CID-0:RT:<10.10.10.2/1->10.10.10.1/1;1> matched filter f0: May 29 01:27:39 01:27:39.699312:CID-0:RT:packet [56] ipid = 4724, @43080bd2 May 29 01:27:39 01:27:39.699312:CID-0:RT:---- flow_process_pkt: (thd 1): flow_ctxt type 0, common flag 0x0, mbuf 0x43080980, rtbl_idx = 4 May 29 01:27:39 01:27:39.699312:CID-0:RT: flow process pak fast ifl 74 in_ifp lt-0/0/0.100 May 29 01:27:39 01:27:39.699312:CID-0:RT: lt-0/0/0.100:10.10.10.2->10.10.10.1, icmp, (3/3) May 29 01:27:39 01:27:39.699312:CID-0:RT: find flow: table 0x47cb0cf8, hash 17709(0xffff), sa 10.10.10.2, da 10.10.10.1, sp 33435, dp 34172, proto 17, tok 16392 May 29 01:27:39 01:27:39.699312:CID-0:RT: packet dropped, no session found for embedded icmp pak May 29 01:27:39 01:27:39.699312:CID-0:RT: flow find session returns error. May 29 01:27:39 01:27:39.699312:CID-0:RT: ----- flow_process_pkt rc 0x7 (fp rc -1) May 29 01:27:44 01:27:44.763955:CID-0:RT:<10.10.10.1/34172->10.10.10.2/33436;17> matched filter f0: May 29 01:27:44 01:27:44.763955:CID-0:RT:packet [40] ipid = 34175, @430814d2 May 29 01:27:44 01:27:44.763955:CID-0:RT:---- flow_process_pkt: (thd 1): flow_ctxt type 0, common flag 0x0, mbuf 0x43081280, rtbl_idx = 5 May 29 01:27:44 01:27:44.763955:CID-0:RT: flow process pak fast ifl 75 in_ifp lt-0/0/0.101 May 29 01:27:44 01:27:44.763955:CID-0:RT: find flow: table 0x47cb0cf8, hash 39582(0xffff), sa 10.10.10.1, da 10.10.10.2, sp 34172, dp 33436, proto 17, tok 20489 May 29 01:27:44 01:27:44.763955:CID-0:RT:check self-traffic on lt-0/0/0.101, in_tunnel 0x0 May 29 01:27:44 01:27:44.763955:CID-0:RT:retcode: 0x4 May 29 01:27:44 01:27:44.763955:CID-0:RT:pak_for_self : proto 17, dst port 33436, action 0x4 May 29 01:27:44 01:27:44.763955:CID-0:RT: flow_first_create_session May 29 01:27:44 01:27:44.763955:CID-0:RT:(flow_first_create_session) usp_tagged set session as mng session May 29 01:27:44 01:27:44.763955:CID-0:RT:Installing pending sess (7) in ager May 29 01:27:44 01:27:44.763955:CID-0:RT:First path alloc and instl pending session, natp=0x4ab47c68, id=7 May 29 01:27:44 01:27:44.763955:CID-0:RT: flow_first_in_dst_nat: in , out dst_adr 10.10.10.2, sp 34172, dp 33436 May 29 01:27:44 01:27:44.763955:CID-0:RT: chose interface lt-0/0/0.101 as incoming nat if. May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_first_rule_dst_xlate: DST no-xlate: 0.0.0.0(0) to 10.10.10.2(33436) May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_first_routing: vr_id 5, call flow_route_lookup(): src_ip 10.10.10.1, x_dst_ip 10.10.10.2, in ifp lt-0/0/0.101, out ifp N/A sp 34172, dp 33436, ip_proto 17, tos 0 May 29 01:27:44 01:27:44.763955:CID-0:RT:Doing DESTINATION addr route-lookup May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_rt_lkup in VR-id: 5 May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_rt_lkup: Found route entry 0x0x4dc1d110,nh id 0x253, out if 0x0 May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_rt_lkup: get NH in local route May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_rt_lkup: nh word 0xfffb0006 May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_ipv4_rt_lkup success 10.10.10.2, iifl 0x4b, oifl 0x0 May 29 01:27:44 01:27:44.763955:CID-0:RT: routed (x_dst_ip 10.10.10.2) from TR2 (lt-0/0/0.101 in 0) to .local..5, Next-hop: 10.10.10.2 May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_first_policy_search: policy search from zone TR2-> zone junos-host (0x0,0x857c829c,0x829c) May 29 01:27:44 01:27:44.763955:CID-0:RT: app 0, timeout 60s, curr ageout 60s May 29 01:27:44 01:27:44.763955:CID-0:RT: permitted by policy self-traffic-policy(1) May 29 01:27:44 01:27:44.763955:CID-0:RT: packet passed, Permitted by policy. May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_first_src_xlate: nat_src_xlated: False, nat_src_xlate_failed: False May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_first_src_xlate: src nat returns status: 0, rule/pool id: 0/0, pst_nat: False. May 29 01:27:44 01:27:44.763955:CID-0:RT: dip id = 0/0, 10.10.10.1/34172->10.10.10.1/34172 protocol 0 May 29 01:27:44 01:27:44.763955:CID-0:RT: choose interface .local..5 as outgoing phy if May 29 01:27:44 01:27:44.763955:CID-0:RT:is_loop_pak: No loop: ifp doesnt match .local..5 vs looked-up: lt-0/0/0.101, addr: 10.10.10.2, rtt_idx: 5, addr_type:0x3 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf : Alloc sess plugin info for session 7 May 29 01:27:44 01:27:44.763955:CID-0:RT:[JSF]Normal interest check. regd plugins 18, enabled impl mask 0x0 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 2, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 3, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 5, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 6, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 7, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 8, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 14, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:+++++++++++jsf_test_plugin_data_evh: 3 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 15, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 21, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 22, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 25, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 26, svc_req 0x0, impl mask 0x0. rc 2 May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf int check: plugin id 27, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:44 01:27:44.763955:CID-0:RT:[JSF]Plugins(0x0, count 0) enabled for session = 168430081, impli mask(0x0), post_nat cnt 7 svc req(0x0) May 29 01:27:44 01:27:44.763955:CID-0:RT:-jsf : no plugin interested for session 7, free sess plugin info May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_first_service_lookup(): natp(0x4ab47c68): app_id, 0(0). May 29 01:27:44 01:27:44.763955:CID-0:RT: service lookup identified service 0. May 29 01:27:44 01:27:44.763955:CID-0:RT: flow_first_final_check: in , out <.local..5> May 29 01:27:44 01:27:44.763955:CID-0:RT:In flow_first_complete_session May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_first_complete_session, pak_ptr: 0x47d31cd8, nsp: 0x4ab47c68, in_tunnel: 0x0 May 29 01:27:44 01:27:44.763955:CID-0:RT:construct v4 vector for nsp2 May 29 01:27:44 01:27:44.763955:CID-0:RT: existing vector list 0-45870e60. May 29 01:27:44 01:27:44.763955:CID-0:RT: Session (id:7) created for first pak 0 May 29 01:27:44 01:27:44.763955:CID-0:RT:first pak processing successful May 29 01:27:44 01:27:44.763955:CID-0:RT: flow_first_install_session======> 0x4ab47c68 May 29 01:27:44 01:27:44.763955:CID-0:RT: nsp 0x4ab47c68, nsp2 0x4ab47ce8 May 29 01:27:44 01:27:44.763955:CID-0:RT: make_nsp_ready_no_resolve() May 29 01:27:44 01:27:44.763955:CID-0:RT:make_nsp_ready_no_resolve: Route Lookup for dest route. Src_ip 10.10.10.2 Dst_ip 10.10.10.1 protocal 17 if_id 1304475412 May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_rt_lkup in VR-id: 5 May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_rt_lkup: Found route entry 0x0x4dc1cdb0,nh id 0x25a, out if 0x4b May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_rt_lkup: nh word 0x80010 May 29 01:27:44 01:27:44.763955:CID-0:RT:flow_ipv4_rt_lkup success 10.10.10.1, iifl 0x4b, oifl 0x4b May 29 01:27:44 01:27:44.763955:CID-0:RT: route lookup: dest-ip 10.10.10.1 orig ifp lt-0/0/0.101 output_ifp lt-0/0/0.101 orig-zone 9 out-zone 9 vsd 0 May 29 01:27:44 01:27:44.763955:CID-0:RT: route to 10.10.10.1 May 29 01:27:44 01:27:44.763955:CID-0:RT:no need update ha May 29 01:27:44 01:27:44.763955:CID-0:RT:Installing c2s NP session wing May 29 01:27:44 01:27:44.763955:CID-0:RT: flow_spu_install_np_session: FLOW STUB May 29 01:27:44 01:27:44.763955:CID-0:RT:Installing s2c NP session wing May 29 01:27:44 01:27:44.763955:CID-0:RT: flow_spu_install_np_session: FLOW STUB May 29 01:27:44 01:27:44.763955:CID-0:RT:updating pending sess (7) in ager May 29 01:27:44 01:27:44.763955:CID-0:RT:first path session installation succeeded May 29 01:27:44 01:27:44.763955:CID-0:RT: flow got session. May 29 01:27:44 01:27:44.763955:CID-0:RT: flow fast tcp/udp session id 7 May 29 01:27:44 01:27:44.763955:CID-0:RT: vector bits 0x0 vector 0x45870e60 May 29 01:27:44 01:27:44.763955:CID-0:RT:insert usp tag for vpn apps May 29 01:27:44 01:27:44.763955:CID-0:RT:mbuf 0x43081280, exit nh 0xfffb0006 May 29 01:27:44 01:27:44.763955:CID-0:RT: ----- flow_process_pkt rc 0x0 (fp rc 0) May 29 01:27:44 01:27:44.784066:CID-0:RT:<10.10.10.2/1->10.10.10.1/1;1> matched filter f0: May 29 01:27:44 01:27:44.784066:CID-0:RT:packet [56] ipid = 4729, @43080bd2 May 29 01:27:44 01:27:44.784066:CID-0:RT:---- flow_process_pkt: (thd 1): flow_ctxt type 0, common flag 0x0, mbuf 0x43080980, rtbl_idx = 4 May 29 01:27:44 01:27:44.784066:CID-0:RT: flow process pak fast ifl 74 in_ifp lt-0/0/0.100 May 29 01:27:44 01:27:44.784066:CID-0:RT: lt-0/0/0.100:10.10.10.2->10.10.10.1, icmp, (3/3) May 29 01:27:44 01:27:44.784066:CID-0:RT: find flow: table 0x47cb0cf8, hash 55677(0xffff), sa 10.10.10.2, da 10.10.10.1, sp 33436, dp 34172, proto 17, tok 16392 May 29 01:27:44 01:27:44.784066:CID-0:RT: packet dropped, no session found for embedded icmp pak May 29 01:27:44 01:27:44.784066:CID-0:RT: flow find session returns error. May 29 01:27:44 01:27:44.784066:CID-0:RT: ----- flow_process_pkt rc 0x7 (fp rc -1) May 29 01:27:49 01:27:49.844466:CID-0:RT:<10.10.10.1/34172->10.10.10.2/33437;17> matched filter f0: May 29 01:27:49 01:27:49.844466:CID-0:RT:packet [40] ipid = 34176, @430814d2 May 29 01:27:49 01:27:49.844466:CID-0:RT:---- flow_process_pkt: (thd 1): flow_ctxt type 0, common flag 0x0, mbuf 0x43081280, rtbl_idx = 5 May 29 01:27:49 01:27:49.844466:CID-0:RT: flow process pak fast ifl 75 in_ifp lt-0/0/0.101 May 29 01:27:49 01:27:49.844466:CID-0:RT: find flow: table 0x47cb0cf8, hash 39583(0xffff), sa 10.10.10.1, da 10.10.10.2, sp 34172, dp 33437, proto 17, tok 20489 May 29 01:27:49 01:27:49.844466:CID-0:RT:check self-traffic on lt-0/0/0.101, in_tunnel 0x0 May 29 01:27:49 01:27:49.844466:CID-0:RT:retcode: 0x4 May 29 01:27:49 01:27:49.844466:CID-0:RT:pak_for_self : proto 17, dst port 33437, action 0x4 May 29 01:27:49 01:27:49.844466:CID-0:RT: flow_first_create_session May 29 01:27:49 01:27:49.844466:CID-0:RT:(flow_first_create_session) usp_tagged set session as mng session May 29 01:27:49 01:27:49.844466:CID-0:RT:Installing pending sess (8) in ager May 29 01:27:49 01:27:49.844466:CID-0:RT:First path alloc and instl pending session, natp=0x4ab47e28, id=8 May 29 01:27:49 01:27:49.844466:CID-0:RT: flow_first_in_dst_nat: in , out dst_adr 10.10.10.2, sp 34172, dp 33437 May 29 01:27:49 01:27:49.844466:CID-0:RT: chose interface lt-0/0/0.101 as incoming nat if. May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_first_rule_dst_xlate: DST no-xlate: 0.0.0.0(0) to 10.10.10.2(33437) May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_first_routing: vr_id 5, call flow_route_lookup(): src_ip 10.10.10.1, x_dst_ip 10.10.10.2, in ifp lt-0/0/0.101, out ifp N/A sp 34172, dp 33437, ip_proto 17, tos 0 May 29 01:27:49 01:27:49.844466:CID-0:RT:Doing DESTINATION addr route-lookup May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_rt_lkup in VR-id: 5 May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_rt_lkup: Found route entry 0x0x4dc1d110,nh id 0x253, out if 0x0 May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_rt_lkup: get NH in local route May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_rt_lkup: nh word 0xfffb0006 May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_ipv4_rt_lkup success 10.10.10.2, iifl 0x4b, oifl 0x0 May 29 01:27:49 01:27:49.844466:CID-0:RT: routed (x_dst_ip 10.10.10.2) from TR2 (lt-0/0/0.101 in 0) to .local..5, Next-hop: 10.10.10.2 May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_first_policy_search: policy search from zone TR2-> zone junos-host (0x0,0x857c829d,0x829d) May 29 01:27:49 01:27:49.844466:CID-0:RT: app 0, timeout 60s, curr ageout 60s May 29 01:27:49 01:27:49.844466:CID-0:RT: permitted by policy self-traffic-policy(1) May 29 01:27:49 01:27:49.844466:CID-0:RT: packet passed, Permitted by policy. May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_first_src_xlate: nat_src_xlated: False, nat_src_xlate_failed: False May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_first_src_xlate: src nat returns status: 0, rule/pool id: 0/0, pst_nat: False. May 29 01:27:49 01:27:49.844466:CID-0:RT: dip id = 0/0, 10.10.10.1/34172->10.10.10.1/34172 protocol 0 May 29 01:27:49 01:27:49.844466:CID-0:RT: choose interface .local..5 as outgoing phy if May 29 01:27:49 01:27:49.844466:CID-0:RT:is_loop_pak: No loop: ifp doesnt match .local..5 vs looked-up: lt-0/0/0.101, addr: 10.10.10.2, rtt_idx: 5, addr_type:0x3 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf : Alloc sess plugin info for session 8 May 29 01:27:49 01:27:49.844466:CID-0:RT:[JSF]Normal interest check. regd plugins 18, enabled impl mask 0x0 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 2, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 3, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 5, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 6, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 7, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 8, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 14, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:+++++++++++jsf_test_plugin_data_evh: 3 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 15, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 21, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 22, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 25, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 26, svc_req 0x0, impl mask 0x0. rc 2 May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf int check: plugin id 27, svc_req 0x0, impl mask 0x0. rc 4 May 29 01:27:49 01:27:49.844466:CID-0:RT:[JSF]Plugins(0x0, count 0) enabled for session = 168430081, impli mask(0x0), post_nat cnt 8 svc req(0x0) May 29 01:27:49 01:27:49.844466:CID-0:RT:-jsf : no plugin interested for session 8, free sess plugin info May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_first_service_lookup(): natp(0x4ab47e28): app_id, 0(0). May 29 01:27:49 01:27:49.844466:CID-0:RT: service lookup identified service 0. May 29 01:27:49 01:27:49.844466:CID-0:RT: flow_first_final_check: in , out <.local..5> May 29 01:27:49 01:27:49.844466:CID-0:RT:In flow_first_complete_session May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_first_complete_session, pak_ptr: 0x47d31cd8, nsp: 0x4ab47e28, in_tunnel: 0x0 May 29 01:27:49 01:27:49.844466:CID-0:RT:construct v4 vector for nsp2 May 29 01:27:49 01:27:49.844466:CID-0:RT: existing vector list 0-45870e60. May 29 01:27:49 01:27:49.844466:CID-0:RT: Session (id:8) created for first pak 0 May 29 01:27:49 01:27:49.844466:CID-0:RT:first pak processing successful May 29 01:27:49 01:27:49.844466:CID-0:RT: flow_first_install_session======> 0x4ab47e28 May 29 01:27:49 01:27:49.844466:CID-0:RT: nsp 0x4ab47e28, nsp2 0x4ab47ea8 May 29 01:27:49 01:27:49.844466:CID-0:RT: make_nsp_ready_no_resolve() May 29 01:27:49 01:27:49.844466:CID-0:RT:make_nsp_ready_no_resolve: Route Lookup for dest route. Src_ip 10.10.10.2 Dst_ip 10.10.10.1 protocal 17 if_id 1304475412 May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_rt_lkup in VR-id: 5 May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_rt_lkup: Found route entry 0x0x4dc1cdb0,nh id 0x25a, out if 0x4b May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_rt_lkup: nh word 0x80010 May 29 01:27:49 01:27:49.844466:CID-0:RT:flow_ipv4_rt_lkup success 10.10.10.1, iifl 0x4b, oifl 0x4b May 29 01:27:49 01:27:49.844466:CID-0:RT: route lookup: dest-ip 10.10.10.1 orig ifp lt-0/0/0.101 output_ifp lt-0/0/0.101 orig-zone 9 out-zone 9 vsd 0 May 29 01:27:49 01:27:49.844466:CID-0:RT: route to 10.10.10.1 May 29 01:27:49 01:27:49.844466:CID-0:RT:no need update ha May 29 01:27:49 01:27:49.844466:CID-0:RT:Installing c2s NP session wing May 29 01:27:49 01:27:49.844466:CID-0:RT: flow_spu_install_np_session: FLOW STUB May 29 01:27:49 01:27:49.844466:CID-0:RT:Installing s2c NP session wing May 29 01:27:49 01:27:49.844466:CID-0:RT: flow_spu_install_np_session: FLOW STUB May 29 01:27:49 01:27:49.844466:CID-0:RT:updating pending sess (8) in ager May 29 01:27:49 01:27:49.844466:CID-0:RT:first path session installation succeeded May 29 01:27:49 01:27:49.844466:CID-0:RT: flow got session. May 29 01:27:49 01:27:49.844466:CID-0:RT: flow fast tcp/udp session id 8 May 29 01:27:49 01:27:49.844466:CID-0:RT: vector bits 0x0 vector 0x45870e60 May 29 01:27:49 01:27:49.844466:CID-0:RT:insert usp tag for vpn apps May 29 01:27:49 01:27:49.844466:CID-0:RT:mbuf 0x43081280, exit nh 0xfffb0006 May 29 01:27:49 01:27:49.844466:CID-0:RT: ----- flow_process_pkt rc 0x0 (fp rc 0) May 29 01:27:49 01:27:49.847509:CID-0:RT:<10.10.10.2/1->10.10.10.1/1;1> matched filter f0: May 29 01:27:49 01:27:49.847509:CID-0:RT:packet [56] ipid = 4736, @43080bd2 May 29 01:27:49 01:27:49.847509:CID-0:RT:---- flow_process_pkt: (thd 1): flow_ctxt type 0, common flag 0x0, mbuf 0x43080980, rtbl_idx = 4 May 29 01:27:49 01:27:49.847509:CID-0:RT: flow process pak fast ifl 74 in_ifp lt-0/0/0.100 May 29 01:27:49 01:27:49.847509:CID-0:RT: lt-0/0/0.100:10.10.10.2->10.10.10.1, icmp, (3/3) May 29 01:27:49 01:27:49.847509:CID-0:RT: find flow: table 0x47cb0cf8, hash 14349(0xffff), sa 10.10.10.2, da 10.10.10.1, sp 33437, dp 34172, proto 17, tok 16392 May 29 01:27:49 01:27:49.847509:CID-0:RT: packet dropped, no session found for embedded icmp pak May 29 01:27:49 01:27:49.847509:CID-0:RT: flow find session returns error. May 29 01:27:49 01:27:49.847509:CID-0:RT: ----- flow_process_pkt rc 0x7 (fp rc -1) May 29 01:28:09 No [security flow] config found May 29 01:28:09 Copying in default flow config May 29 01:28:09 Using default security forwarding-options May 29 01:28:09 Forwarding options: inet 2, inet6 3, mpls 3, iso 3 May 29 01:28:09 Using default security policy violation May 29 01:28:09 flow_ssam_sync_config: FLOW SSAM config sync'ing - started May 29 01:28:09 Getting [flow main] config blob from ssam May 29 01:28:09 flow_ssam_get_obj_config: Config blob [flow main] fetched May 29 01:28:09 Getting [flow tcp-mss] config blob from ssam May 29 01:28:09 flow_ssam_get_obj_config: Config blob [flow tcp-mss] fetched May 29 01:28:09 Getting [flow tcp-session] config blob from ssam May 29 01:28:09 flow_ssam_get_obj_config: Config blob [flow tcp-session] fetched May 29 01:28:09 Getting [flow flow-mode] config blob from ssam May 29 01:28:09 flow_ssam_get_obj_config: Config blob [flow flow-mode] fetched May 29 01:28:09 Getting [flow traceoptions] config blob from ssam May 29 01:28:09 flow_ssam_get_obj_config: Config blob [flow traceoptions] fetched May 29 01:28:09 Pushing updated [flow traceoptions] config blob into ssam, type: 2147483671, size: 24 May 29 01:28:09 Changed [flow traceoptions] blob into ssam type 2147483671, len 24 May 29 01:28:09 Getting [flow aging] config blob from ssam May 29 01:28:09 flow_ssam_get_obj_config: Config blob [flow aging] fetched May 29 01:28:09 Getting [flow bridge] config blob from ssam May 29 01:28:09 flow_ssam_get_obj_config: Config blob [flow bridge] fetched May 29 01:28:09 Getting [flow filter] config blob from ssam May 29 01:28:09 flow_ssam_get_obj_config: Config blob [flow filter] fetched May 29 01:28:09 Pushing updated [flow filter] config blob into ssam. type: 2147483673. May 29 01:28:09 Getting [flow policy-violation] config blob from ssam May 29 01:28:09 flow_ssam_get_obj_config: Config blob [flow policy-violation] fetched May 29 01:28:09 Pushing updated [flow sess-dist-mode] config blob into ssam, type: 2147483749, size: 4 May 29 01:28:09 Changed [flow sess-dist-mode] blob into ssam type 2147483749, len 4 May 29 01:28:09 Flow SSAM Config sync'ing - completed