Hi
Kindly help me to resolve this issue,
we have upgraded one of our Cluster standby member R80.30 to R81.10 enabling "MVC"
topology configuration, Access rules, NAT rules configured according to R81.10 VoIP admin Guide, also enabled Strict SIP enforcement in inspection also.
what we understood is return SIP not passing thorough CP firewall, we have initiated TCPDUMP in voice Gateway voice gateway response to request SIP packet. and also once failover to R80.30 (using admin down) gateway voice SIP connected and working as fine.
No fw ctl zdebug output reported.
I have enabled KDebug for analysis and found this but cannot understand how to read this for in depth.
Kindly note below IP not real IP address.
SIP calls coming from : 150.1.49.7
Voice Gateway Original IP : 192.168.209.40
Voice Gateway private IP One to One Object static NAT Public IP: 123.123.123.215
[-- Stateful VM inbound: Entering (1683416517) --];
@;184930; 7May2023 5:11:57.061781;[cpu_0];[fw4_1];Before VM: <dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17> (len=627) (ifn=36) (first seen) (looked up) ;
@;184930; 7May2023 5:11:57.061783;[cpu_0];[fw4_1];fw_filter_chain: fwconn_chain_conn_exists returned 0 (conn=<dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17>, is new 0), chain 0xffffc90099106030;
@;184930; 7May2023 5:11:57.061784;[cpu_0];[fw4_1];fw_cluster_ttl_anti_spoofing: conn=<dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17>;
@;184930; 7May2023 5:11:57.061787;[cpu_0];[fw4_1];fwdrv_open_conn_from_template: no matched template for conn=<dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17>;
@;184930; 7May2023 5:11:57.061790;[cpu_0];[fw4_1];we need to consider the data conn;
@;184930; 7May2023 5:11:57.061791;[cpu_0];[fw4_1];fwx_get_original_conn_key_ex: Conn = dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17;
@;184930; 7May2023 5:11:57.061793;[cpu_0];[fw4_1];fwconnoxid_msg_get_cliconn: No connoxid message on <dir 1, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17>;
@;184930; 7May2023 5:11:57.061794;[cpu_0];[fw4_1];fwx_chain_get_xlconn_ex: no kbuf;
@;184930; 7May2023 5:11:57.061795;[cpu_0];[fw4_1];fwx_get_original_conn_key_ex returns orig_conn: <dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17> ;
@;184930; 7May2023 5:11:57.061797;[cpu_0];[fw4_1];==>fwxlate_nat_rulematch conn=<dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17>;
@;184930; 7May2023 5:11:57.061811;[cpu_0];[fw4_1];fwxlate_nat_rulematch: Matched first rule: 82, second: 0;
@;184930; 7May2023 5:11:57.061811;[cpu_0];[fw4_1];rule_to_xlentry: rule:;
@;184930; 7May2023 5:11:57.061811;[cpu_0];[fw4_1];TCP LIST index: 0 ;
@;184930; 7May2023 5:11:57.061812;[cpu_0];[fw4_1];UDP LIST index: 0 ;
@;184930; 7May2023 5:11:57.061814;[cpu_0];[fw4_1];SOURCE: ff000002, 0, 192.168.209.40, 192.168.209.40, 0, 123.123.123.215, 0.0.0.0, ;
@;184930; 7May2023 5:11:57.061815;[cpu_0];[fw4_1];DESTINATION: 0, 0, 0.0.0.0, 0.0.0.0, 0, 0.0.0.0, ;
@;184930; 7May2023 5:11:57.061816;[cpu_0];[fw4_1];SERVICE: 0, 0, 0, ;
@;184930; 7May2023 5:11:57.061816;[cpu_0];[fw4_1];flags: 21, ;
@;184930; 7May2023 5:11:57.061817;[cpu_0];[fw4_1];rule_to_xlentry: < 0;
@;184930; 7May2023 5:11:57.061817;[cpu_0];[fw4_1];xlation type: ff000002,;
@;184930; 7May2023 5:11:57.061818;[cpu_0];[fw4_1];192.168.209.40, 192.168.209.40, 123.123.123.215,;
@;184930; 7May2023 5:11:57.061819;[cpu_0];[fw4_1];xlation type: 0,;
@;184930; 7May2023 5:11:57.061820;[cpu_0];[fw4_1];0.0.0.0, 0.0.0.0, 0.0.0.0,;
@;184930; 7May2023 5:11:57.061820;[cpu_0];[fw4_1];xlation type: 0,;
@;184930; 7May2023 5:11:57.061821;[cpu_0];[fw4_1];0.0.0.0, 0.0.0.0, 0.0.0.0,;
@;184930; 7May2023 5:11:57.061821;[cpu_0];[fw4_1];xlation type: 0,;
@;184930; 7May2023 5:11:57.061822;[cpu_0];[fw4_1];0.0.0.0, 0.0.0.0, 0.0.0.0>;
@;184930; 7May2023 5:11:57.061824;[cpu_0];[fw4_1];<==fwxlate_nat_rulematch rc=0 ret=1;
@;184930; 7May2023 5:11:57.061825;[cpu_0];[fw4_1];==>fwxlate_calaculate_by_nat_rulematch conn=<dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17>;
@;184930; 7May2023 5:11:57.061827;[cpu_0];[fw4_1];<==fwxlate_calaculate_by_nat_rulematch rc=0, xconn=<dir 0, 123.123.123.215:54825 -> 150.1.49.7:5060 IPP 17>;
@;184930; 7May2023 5:11:57.061877;[cpu_0];[fw4_1];we need to consider the data conn;
@;184930; 7May2023 5:11:57.061878;[cpu_0];[fw4_1];fwx_get_original_conn_key_ex: Conn = dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17;
@;184930; 7May2023 5:11:57.061880;[cpu_0];[fw4_1];fwconnoxid_msg_get_cliconn: No connoxid message on <dir 1, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17>;
@;184930; 7May2023 5:11:57.061880;[cpu_0];[fw4_1];fwx_chain_get_xlconn_ex: no kbuf;
@;184930; 7May2023 5:11:57.061881;[cpu_0];[fw4_1];fwx_get_original_conn_key_ex returns orig_conn: <dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17> ;
@;184930; 7May2023 5:11:57.061891;[cpu_0];[fw4_1];we need to consider the data conn;
@;184930; 7May2023 5:11:57.061892;[cpu_0];[fw4_1];fwx_get_original_conn_key_ex: Conn = dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17;
@;184930; 7May2023 5:11:57.061893;[cpu_0];[fw4_1];fwconnoxid_msg_get_cliconn: No connoxid message on <dir 1, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17>;
@;184930; 7May2023 5:11:57.061894;[cpu_0];[fw4_1];fwx_chain_get_xlconn_ex: no kbuf;
@;184930; 7May2023 5:11:57.061895;[cpu_0];[fw4_1];fwx_get_original_conn_key_ex returns orig_conn: <dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17> ;
@;184930; 7May2023 5:11:57.061913;[cpu_0];[fw4_1];we need to consider the data conn;
@;184930; 7May2023 5:11:57.061914;[cpu_0];[fw4_1];fwx_get_original_conn_key_ex: Conn = dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17;
@;184930; 7May2023 5:11:57.061916;[cpu_0];[fw4_1];fwconnoxid_msg_get_cliconn: No connoxid message on <dir 1, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17>;
@;184930; 7May2023 5:11:57.061916;[cpu_0];[fw4_1];fwx_chain_get_xlconn_ex: no kbuf;
@;184930; 7May2023 5:11:57.061917;[cpu_0];[fw4_1];fwx_get_original_conn_key_ex returns orig_conn: <dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17> ;
@;184930; 7May2023 5:11:57.061936;[cpu_0];[fw4_1];fwx_cntl_dyn_tbl_key_get: called fwx_dyn_lookup;
@;184930; 7May2023 5:11:57.061937;[cpu_0];[fw4_1];fwx_cntl_dyn_tbl_key_get: record was not found. kiss ret=-1;
@;184930; 7May2023 5:11:57.061981;[cpu_0];[fw4_1];fwconn_key_lookup_app_opaque: conn <dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17> not found in connections table (id=4);
@;184930; 7May2023 5:11:57.061983;[cpu_0];[fw4_1];fwconn_key_lookup_app_opaque: conn <dir 1, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17> not found in connections table (id=4);
@;184930; 7May2023 5:11:57.061986;[cpu_0];[fw4_1];fwconn_key_lookup_app_opaque: conn <dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17> not found in connections table (id=4);
@;184930; 7May2023 5:11:57.061987;[cpu_0];[fw4_1];fwconn_key_lookup_app_opaque: conn <dir 1, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17> not found in connections table (id=4);
@;184930; 7May2023 5:11:57.061991;[cpu_0];[fw4_1];fwconn_lookup_other_ex__legacy__: conn <dir 0, 150.1.49.7:5060 -> 192.168.209.40:54825 IPP 17>
not found in connections table;
@;184930; 7May2023 5:11:57.061993;[cpu_0];[fw4_1];fwconn_key_lookup_ex: conn <dir 0, 150.1.49.7:5060 -> 192.168.209.40:54825 IPP 17> not found in connections table.;
@;184930; 7May2023 5:11:57.061993;[cpu_0];[fw4_1];fwx_chain_get_xlconn_ex: no kbuf;
@;184930; 7May2023 5:11:57.061995;[cpu_0];[fw4_1];fwconn_lookup_other_ex__legacy__: conn <dir 0, 150.1.49.7:5060 -> 192.168.209.40:54825 IPP 17>
not found in connections table;
@;184930; 7May2023 5:11:57.061996;[cpu_0];[fw4_1];fwconn_key_lookup_ex: conn <dir 0, 150.1.49.7:5060 -> 192.168.209.40:54825 IPP 17> not found in connections table.;
@;184930; 7May2023 5:11:57.061997;[cpu_0];[fw4_1];fwx_chain_get_xlconn_ex: no kbuf;
@;184930; 7May2023 5:11:57.061999;[cpu_0];[fw4_1];fwconn_get_app_opaque: connection not found;
@;184930; 7May2023 5:11:57.062011;[cpu_0];[fw4_1];fw_handle_first_packet: Unified Rulebase returned DROP;
@;184930; 7May2023 5:11:57.062014;[cpu_0];[fw4_1];fw_log_drop_ex: Packet proto=17 192.168.209.40:54825 -> 150.1.49.7:5060 dropped by fw_send_log_drop Reason: Rulebase drop - on layer "Scicom-Policy-Package-0306201" rule 138;
@;184930; 7May2023 5:11:57.062019;[cpu_0];[fw4_1];fw_try_to_match_template: handle_first_packet returned action DROP for new conn=<dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17>;
@;184930; 7May2023 5:11:57.062019;[cpu_0];[fw4_1];fw_filter_chain: Final switch, action=DROP;
@;184930; 7May2023 5:11:57.062021;[cpu_0];[fw4_1];After VM: <dir 0, 192.168.209.40:54825 -> 150.1.49.7:5060 IPP 17> (len=627) ;
@;184930; 7May2023 5:11:57.062022;[cpu_0];[fw4_1];VM Final action=DROP;
@;184930; 7May2023 5:11:57.062022;[cpu_0];[fw4_1]; ----- Stateful VM inbound Completed -----
Anyone please advice any possibility for this matter,
Thank you,
Duminda.