<div>Hello,</div><div> </div><div>I use latest openisps 1.8 by follow sheme:</div><div> </div><div>opensips 1 (11.22.33.44)-----> opensips 2 (77.88.100.100)</div><div> </div><div>When opensips 2 receive ACK I see follow problems:</div>
<div> </div><div>1. In trace debug 6 I see message:</div><div>" DBG:sipmsgops:sip_validate_hdrs: duplicate header 'Content-Length' "</div><div> </div><div>There is not duplicate header. </div><div> </div>
<div>2. The ACK messages not find dialog parameters.</div><div> </div><div>Here is debug 6 :</div><div> </div><div>: DBG:core:parse_msg: SIP Request:<br> : DBG:core:parse_msg: method: <ACK><br> : DBG:core:parse_msg: uri: <<a href="http://sip:15488@77.88.100.100:5060">sip:15488@77.88.100.100:5060</a>><br>
: DBG:core:parse_msg: version: <SIP/2.0><br> : DBG:core:parse_headers: flags=2<br> : DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1af6.8dfa1be2.2>; state=16<br> : DBG:core:parse_via: end of header reached, state=5<br>
: DBG:core:parse_headers: via found, flags=2<br> : DBG:core:parse_headers: this is the first via<br> : DBG:core:receive_msg: After parse_msg...<br> : DBG:core:receive_msg: preparing to run routing scripts...<br> : DBG:sl:sl_filter_ACK: to late to be a local ACK!<br>
: ++++++++++++++++++++++++++++++++++++++++++++++++++++ from <a href="http://11.22.33.44:5060">11.22.33.44:5060</a><br> : DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:core:parse_via_param: found param type 234, <received> = <66.55.44.33>; state=6<br>
: DBG:core:parse_via_param: found param type 235, <rport> = <52625>; state=6<br> : DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKPj-BqsfN5zeuwvMDMyA9q93C5tBdFaeMZg>; state=16<br>
: DBG:core:parse_via: end of header reached, state=5<br> : DBG:core:parse_headers: via found, flags=ffffffffffffffff<br> : DBG:core:parse_headers: parse_headers: this is the second via<br> : DBG:core:parse_to_param: tag=as25148399<br>
: DBG:core:parse_to: end of header reached, state=29<br> : DBG:core:parse_to: display={}, ruri={<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>}<br> : DBG:core:get_hdr_field: <To> [40]; uri=[<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>] <br>
: DBG:core:get_hdr_field: to body [<<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>>]<br> : DBG:core:get_hdr_field: cseq <CSeq>: <31391> <ACK><br> : DBG:core:get_hdr_field: content_length=0<br>
: DBG:core:get_hdr_field: found end of header<br> : DBG:core:parse_to_param: tag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj<br> : DBG:core:parse_to: end of header reached, state=29<br> : DBG:core:parse_to: display={}, ruri={<a href="mailto:sip%3A77@11.22.33.44">sip:77@11.22.33.44</a>}<br>
: DBG:sipmsgops:sip_validate_hdrs: duplicate header 'Content-Length'<br> : ASK from <a href="http://11.22.33.44:5060">11.22.33.44:5060</a><br> : DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:core:parse_headers: flags=ffffffffffffffff<br>
: DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:uri:has_totag: totag found<br> : Have to_tag <br> : DBG:core:parse_headers: flags=200<br> : DBG:rr:is_preloaded: is_preloaded: No<br> : DBG:core:grep_sock_info: checking if host==us: 14==9 && [77.88.100.100] == [127.0.0.1]<br>
: DBG:core:grep_sock_info: checking if port 5060 matches port 5060<br> : DBG:core:grep_sock_info: checking if host==us: 14==14 && [77.88.100.100] == [77.88.100.100]<br> : DBG:core:grep_sock_info: checking if port 5060 matches port 5060<br>
: DBG:rr:after_strict: Next hop: 'sip:77.88.100.100;lr;ftag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj;did=706.c142d645' is loose router<br> : DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:rr:after_strict: The last route URI: 'sip:77.88.100.100;lr;ftag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj;did=706.c142d645'<br>
: DBG:rr:run_rr_callbacks: callback id 1 entered with <><br> : DBG:dialog:dlg_onroute: Route param 'did' not found<br> : DBG:rr:run_rr_callbacks: callback id 2 entered with <><br> : DBG:uac:restore_uri: getting 'vsf' Route param<br>
: DBG:uac:restore_uri: route param 'vsf' not found<br> : DBG:uac:restore_uri: getting 'vst' Route param<br> : DBG:uac:restore_uri: route param 'vst' not found<br> : Sip Trace = <null><br> : DBG:siptrace:sip_trace: nothing to trace...<br>
: Has totag - loose route. Trace id <null><br> : DBG:tm:t_newtran: transaction on entrance=0xffffffffffffffff<br> : DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:core:parse_headers: flags=78<br> : DBG:tm:t_lookup_request: start searching: hash=28577, isACK=1<br>
: DBG:core:parse_headers: flags=38<br> : DBG:tm:t_lookup_request: REF_UNSAFE:[0x7f619a9e92f8] after is 1<br> : DBG:tm:t_lookup_request: e2e proxy ACK found<br> : DBG:tm:t_newtran: building branch for end2end ACK - flags=1<br>
: DBG:tm:t_relay_to: forwarding ACK<br> : DBG:core:mk_proxy: doing DNS lookup...<br> : DBG:core:forward_request: sending:#012ACK sip:77.88.100.100;lr;ftag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj;did=706.c142d645 SIP/2.0#015#012Via: SIP/2.0/UDP 77.88.100.100;branch=z9hG4bK1af6.7d6364b3.2#015#012Via: SIP/2.0/UDP 11.22.33.44;rport=5060;received=11.22.33.44;branch=z9hG4bK1af6.8dfa1be2.2#015#012Via: SIP/2.0/UDP 66.55.44.33:52625;received=66.55.44.33;rport=52625;branch=z9hG4bKPj-BqsfN5zeuwvMDMyA9q93C5tBdFaeMZg#015#012Max-Forwards: 67#015#012From: <<a href="mailto:sip%3A77@11.22.33.44">sip:77@11.22.33.44</a>>;tag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj#015#012To: <<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>>;tag=as25148399#015#012Call-ID: BFq2DLQKfpwA1bgpaaKLDeZJsLgtbDBA#015#012CSeq: 31391 ACK#015#012Content-Length: 0#015#012#015#012.<br>
: DBG:core:forward_request: orig. len=517, new_len=572, proto=1<br> : DBG:core:run_fwd_callbacks: FWD callback entered<br> : DBG:siptrace:trace_msg_out: trace off...<br> : Send relay.<br> : DBG:tm:t_unref_cell: UNREF_UNSAFE: [0x7f619a9e92f8] after is 0<br>
: DBG:core:destroy_avp_list: destroying list 0x7f619a9f3258<br> : DBG:core:receive_msg: cleaning up<br> : DBG:core:parse_msg: SIP Request:<br> : DBG:core:parse_msg: method: <ACK><br> : DBG:core:parse_msg: uri: <sip:77.88.100.100;lr;ftag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj;did=706.c142d645><br>
: DBG:core:parse_msg: version: <SIP/2.0><br> : DBG:core:parse_headers: flags=2<br> : DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1af6.7d6364b3.2>; state=16<br> : DBG:core:parse_via: end of header reached, state=5<br>
: DBG:core:parse_headers: via found, flags=2<br> : DBG:core:parse_headers: this is the first via<br> : DBG:core:receive_msg: After parse_msg...<br> : DBG:core:receive_msg: preparing to run routing scripts...<br> : DBG:sl:sl_filter_ACK: to late to be a local ACK!<br>
: ++++++++++++++++++++++++++++++++++++++++++++++++++++ from <a href="http://77.88.100.100:5060">77.88.100.100:5060</a><br> : DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6<br>
: DBG:core:parse_via_param: found param type 234, <received> = <11.22.33.44>; state=6<br> : DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1af6.8dfa1be2.2>; state=16<br> : DBG:core:parse_via: end of header reached, state=5<br>
: DBG:core:parse_headers: via found, flags=ffffffffffffffff<br> : DBG:core:parse_headers: parse_headers: this is the second via<br> : DBG:core:parse_via_param: found param type 234, <received> = <66.55.44.33>; state=6<br>
: DBG:core:parse_via_param: found param type 235, <rport> = <52625>; state=6<br> : DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKPj-BqsfN5zeuwvMDMyA9q93C5tBdFaeMZg>; state=16<br>
: DBG:core:parse_via: end of header reached, state=5<br> : DBG:core:parse_headers: via found, flags=ffffffffffffffff<br> : DBG:core:parse_to_param: tag=as25148399<br> : DBG:core:parse_to: end of header reached, state=29<br>
: DBG:core:parse_to: display={}, ruri={<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>}<br> : DBG:core:get_hdr_field: <To> [40]; uri=[<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>] <br>
: DBG:core:get_hdr_field: to body [<<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>>]<br> : DBG:core:get_hdr_field: cseq <CSeq>: <31391> <ACK><br> : DBG:core:get_hdr_field: content_length=0<br>
: DBG:core:get_hdr_field: found end of header<br> : DBG:core:parse_to_param: tag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj<br> : DBG:core:parse_to: end of header reached, state=29<br> : DBG:core:parse_to: display={}, ruri={<a href="mailto:sip%3A77@11.22.33.44">sip:77@11.22.33.44</a>}<br>
: DBG:sipmsgops:sip_validate_hdrs: duplicate header 'Content-Length'<br> : ASK from <a href="http://77.88.100.100:5060">77.88.100.100:5060</a><br> : DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:core:parse_headers: flags=ffffffffffffffff<br>
: DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:uri:has_totag: totag found<br> : Have to_tag <br> : DBG:core:parse_headers: flags=200<br> : DBG:rr:find_first_route: No Route headers found<br> : DBG:rr:loose_route: There is no Route HF<br>
: ASK when not loose_route.<br> : DBG:core:parse_headers: flags=78<br> : DBG:tm:t_lookup_request: start searching: hash=28577, isACK=1<br> : DBG:core:parse_headers: flags=38<br> : DBG:tm:t_lookup_request: REF_UNSAFE:[0x7f619a9e92f8] after is 1<br>
: DBG:tm:t_lookup_request: e2e proxy ACK found<br> : t_check_trans (YES).<br> : DBG:tm:t_newtran: transaction on entrance=(nil)<br> : DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:tm:t_newtran: building branch for end2end ACK - flags=1<br>
: DBG:tm:t_relay_to: forwarding ACK<br> : DBG:core:mk_proxy: doing DNS lookup...<br> : DBG:core:forward_request: sending:#012ACK sip:77.88.100.100;lr;ftag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj;did=706.c142d645 SIP/2.0#015#012Via: SIP/2.0/UDP 77.88.100.100;branch=z9hG4bK1af6.7d6364b3.2#015#012Via: SIP/2.0/UDP 77.88.100.100;rport=5060;received=77.88.100.100;branch=z9hG4bK1af6.7d6364b3.2#015#012Via: SIP/2.0/UDP 11.22.33.44;rport=5060;received=11.22.33.44;branch=z9hG4bK1af6.8dfa1be2.2#015#012Via: SIP/2.0/UDP 66.55.44.33:52625;received=66.55.44.33;rport=52625;branch=z9hG4bKPj-BqsfN5zeuwvMDMyA9q93C5tBdFaeMZg#015#012Max-Forwards: 65#015#012From: <<a href="mailto:sip%3A77@11.22.33.44">sip:77@11.22.33.44</a>>;tag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj#015#012To: <<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>>;tag=as25148399#015#012Call-ID: BFq2DLQKfpwA1bgpaaKLDeZJsLgtbDBA#015#012CSeq: 31391 ACK#015#012Content-Length: 0#015#012#015#012.<br>
: DBG:core:forward_request: orig. len=572, new_len=670, proto=1<br> : DBG:core:run_fwd_callbacks: FWD callback entered<br> : DBG:siptrace:trace_msg_out: trace off...<br> : Send relay.<br> : DBG:tm:t_unref_cell: UNREF_UNSAFE: [0x7f619a9e92f8] after is 0<br>
: DBG:core:destroy_avp_list: destroying list 0x7f619a9f3258<br> : DBG:core:receive_msg: cleaning up<br> : DBG:core:parse_msg: SIP Request:<br> : DBG:core:parse_msg: method: <ACK><br> : DBG:core:parse_msg: uri: <sip:77.88.100.100;lr;ftag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj;did=706.c142d645><br>
: DBG:core:parse_msg: version: <SIP/2.0><br> : DBG:core:parse_headers: flags=2<br> : DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1af6.7d6364b3.2>; state=16<br> : DBG:core:parse_via: end of header reached, state=5<br>
: DBG:core:parse_headers: via found, flags=2<br> : DBG:core:parse_headers: this is the first via<br> : DBG:core:receive_msg: After parse_msg...<br> : DBG:core:receive_msg: preparing to run routing scripts...<br> : DBG:sl:sl_filter_ACK: to late to be a local ACK!<br>
: ++++++++++++++++++++++++++++++++++++++++++++++++++++ from <a href="http://77.88.100.100:5060">77.88.100.100:5060</a><br> : DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6<br>
: DBG:core:parse_via_param: found param type 234, <received> = <77.88.100.100>; state=6<br> : DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1af6.7d6364b3.2>; state=16<br> : DBG:core:parse_via: end of header reached, state=5<br>
: DBG:core:parse_headers: via found, flags=ffffffffffffffff<br> : DBG:core:parse_headers: parse_headers: this is the second via<br> : DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6<br>
: DBG:core:parse_via_param: found param type 234, <received> = <11.22.33.44>; state=6<br> : DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1af6.8dfa1be2.2>; state=16<br> : DBG:core:parse_via: end of header reached, state=5<br>
: DBG:core:parse_headers: via found, flags=ffffffffffffffff<br> : DBG:core:parse_via_param: found param type 234, <received> = <66.55.44.33>; state=6<br> : DBG:core:parse_via_param: found param type 235, <rport> = <52625>; state=6<br>
: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKPj-BqsfN5zeuwvMDMyA9q93C5tBdFaeMZg>; state=16<br> : DBG:core:parse_via: end of header reached, state=5<br> : DBG:core:parse_headers: via found, flags=ffffffffffffffff<br>
: DBG:core:parse_to_param: tag=as25148399<br> : DBG:core:parse_to: end of header reached, state=29<br> : DBG:core:parse_to: display={}, ruri={<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>}<br> : DBG:core:get_hdr_field: <To> [40]; uri=[<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>] <br>
: DBG:core:get_hdr_field: to body [<<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>>]<br> : DBG:core:get_hdr_field: cseq <CSeq>: <31391> <ACK><br> : DBG:core:get_hdr_field: content_length=0<br>
: DBG:core:get_hdr_field: found end of header<br> : DBG:core:parse_to_param: tag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj<br> : DBG:core:parse_to: end of header reached, state=29<br> : DBG:core:parse_to: display={}, ruri={<a href="mailto:sip%3A77@11.22.33.44">sip:77@11.22.33.44</a>}<br>
: DBG:sipmsgops:sip_validate_hdrs: duplicate header 'Content-Length'<br> : ASK from <a href="http://77.88.100.100:5060">77.88.100.100:5060</a><br> : DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:core:parse_headers: flags=ffffffffffffffff<br>
: DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:uri:has_totag: totag found<br> : Have to_tag <br> : DBG:core:parse_headers: flags=200<br> : DBG:rr:find_first_route: No Route headers found<br> : DBG:rr:loose_route: There is no Route HF<br>
: ASK when not loose_route.<br> : DBG:core:parse_headers: flags=78<br> : DBG:tm:t_lookup_request: start searching: hash=28577, isACK=1<br> : DBG:core:parse_headers: flags=38<br> : DBG:tm:t_lookup_request: REF_UNSAFE:[0x7f619a9e92f8] after is 1<br>
: DBG:tm:t_lookup_request: e2e proxy ACK found<br> : t_check_trans (YES).<br> : DBG:tm:t_newtran: transaction on entrance=(nil)<br> : DBG:core:parse_headers: flags=ffffffffffffffff<br> : DBG:tm:t_newtran: building branch for end2end ACK - flags=1<br>
: DBG:tm:t_relay_to: forwarding ACK<br> : DBG:core:mk_proxy: doing DNS lookup...<br> : DBG:core:forward_request: sending:#012ACK sip:77.88.100.100;lr;ftag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj;did=706.c142d645 SIP/2.0#015#012Via: SIP/2.0/UDP 77.88.100.100;branch=z9hG4bK1af6.7d6364b3.2#015#012Via: SIP/2.0/UDP 77.88.100.100;rport=5060;received=77.88.100.100;branch=z9hG4bK1af6.7d6364b3.2#015#012Via: SIP/2.0/UDP 77.88.100.100;rport=5060;received=77.88.100.100;branch=z9hG4bK1af6.7d6364b3.2#015#012Via: SIP/2.0/UDP 11.22.33.44;rport=5060;received=11.22.33.44;branch=z9hG4bK1af6.8dfa1be2.2#015#012Via: SIP/2.0/UDP 66.55.44.33:52625;received=66.55.44.33;rport=52625;branch=z9hG4bKPj-BqsfN5zeuwvMDMyA9q93C5tBdFaeMZg#015#012Max-Forwards: 63#015#012From: <<a href="mailto:sip%3A77@11.22.33.44">sip:77@11.22.33.44</a>>;tag=9XfR8ZmrUUho2HYFHzJ3tYmiMp2GbOXj#015#012To: <<a href="mailto:sip%3A15488@11.22.33.44">sip:15488@11.22.33.44</a>>;tag=as25148399#015#012Call-ID: BFq2DLQKfpwA1bgpaaKLDeZJsLgtbDBA#015#012CSeq: 31391 ACK#015#012Content-Length: 0#015#012#015#012.<br>
: DBG:core:forward_request: orig. len=670, new_len=768, proto=1<br> : DBG:core:run_fwd_callbacks: FWD callback entered<br> : DBG:siptrace:trace_msg_out: trace off...<br> : Send relay.<br> : DBG:tm:t_unref_cell: UNREF_UNSAFE: [0x7f619a9e92f8] after is 0<br>
: DBG:core:destroy_avp_list: destroying list 0x7f619a9f3258<br></div><div>Best regards;</div><div>PlayMen</div>