Hello!
I have a such problem opensips1.6.4-2
There are two proxies of version 1.6.4.-2 which has been installed on the same
server.
One proxy (proxy1) using B2B “top hiding” and located in /usr/local/sbc and
using one signaling port
Another proxy (proxy2) is just SIP proxy and located in
/usr/local/opensips1.6.4/ and using another signaling port
Both proxies using the same ip address of the server
Call flow:
some UA – proxy1 – proxy2 – some gateway
When UA generate CANCEL then proxy1 does some strange things with FROM or TO
uri headers (you can see it in attachment). Because of this proxy2 cannot
parse CANCEL properly and transaction in proxy2 cannot be canceled.
Thank you for any help.
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_msg: SIP
Request:
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_msg:
method: <CANCEL>
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_msg:
uri: <sip:88123364021@1.1.1.1:5063;transport=UDP>
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_msg:
version: <SIP/2.0>
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_headers:
flags=2
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:core:parse_via_param: found param type 232, <branch> =
<z9hG4bK-d8754z-816e76605de1b275-1---d8754z->; state=6
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_via: end
of header reached, state=5
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_headers:
via found, flags=2
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_headers:
this is the first via
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:receive_msg:
After parse_msg...
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:receive_msg:
preparing to run routing scripts...
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_headers:
flags=ffffffffffffffff
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_to: end
of header reached, state=10
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_to:
display={}, ruri={sip:88123364021@1.1.1.1:5063;transport=UDP}
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:get_hdr_field:
<To> [52]; uri=[sip:88123364021@1.1.1.1:5063;transport=UDP]
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:get_hdr_field:
to body [<sip:88123364021@1.1.1.1:5063;transport=UDP>#015#012]
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:get_hdr_field:
cseq <CSeq>: <2> <CANCEL>
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:get_hdr_field:
content_length=0
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:get_hdr_field:
found end of header
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_entities:b2b_prescript_f: start - method = CANCEL
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:core:parse_to_param: tag=2e1b1846
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_to: end
of header reached, state=29
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_to:
display={}, ruri={sip:8123364079@1.1.1.1:5063;transport=UDP}
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_entities:b2b_parse_key: Does not have b2b_entities prefix
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_entities:b2bl_search_iteratively: Search for record with callid=
MzBhYzkyODA2YjEzZGEyZTFhNjAxMzBhMjI1NWU3ZmU., tag= 2e1b1846
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_entities:b2bl_search_iteratively: Found callid=
MzBhYzkyODA2YjEzZGEyZTFhNjAxMzBhMjI1NWU3ZmU., tag= 2e1b1846
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:tm:t_newtran:
transaction on entrance=0xffffffff
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_headers:
flags=ffffffffffffffff
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_headers:
flags=78
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:tm:t_lookup_request: start searching: hash=49978, isACK=0
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:tm:matching_3261:
RFC3261 transaction matching failed
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:tm:t_lookup_request: no transaction found
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_headers:
flags=ffffffffffffffff
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:core:check_ip_address: params 192.168.18.55, 192.168.18.55, 0
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:_shm_resize:
resize(0) called
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:tm:insert_timer_unsafe: [2]: 0xb6b940bc (3652)
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:tm:_reply_light:
reply sent out. buf=0x81c3590: SIP/2.0 2..., shmem=0xb6b915fc: SIP/2.0 2
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:tm:_reply_light:
finished
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:tm:t_unref_cell:
UNREF_UNSAFE: [0xb6b94074] after is 0
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_logic:b2b_logic_notify: b2b_entities notification cb for [787.2] with
entity [B2B.316.51]
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_logic:b2bl_parse_key: hash_index = [787] - local_index= [2]
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:parse_headers:
flags=ffffffffffffffff
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_logic:b2bl_search_entity: Key [B2B.316.51]
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_logic:b2b_logic_notify: b2b_entity key = B2B.316.51
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_logic:b2b_logic_notify: request received for tuple[0xb6b8e12c]->[787.2]
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_logic:b2b_logic_notify: Send request [CANCEL] to peer [B2B.275.41824]
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_entities:b2b_parse_key: hash_index = [275] - local_index= [41824]
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_entities:b2b_search_htable_dlg: searching totag
[8307a2faba1a16a4f24d72d5feb5980b]
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_entities:b2b_search_htable_dlg: Found match
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_entities:b2b_send_request: Send request [CANCEL] for entity type [1]
for dlg[0xb6b8f86c]->[B2B.275.41824]
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:b2b_entities:b2b_send_request: send cancel request
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:tm:t_lookup_ident:
REF_UNSAFE:[0xb6b8fd34] after is 2
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:tm:t_lookup_ident:
transaction found
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:core:destroy_avp_list: destroying list (nil)
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:tm:build_uac_cancel: sing FROM=<nsport=UDP>;tag=B2B.316.51#015#012From:
<sip:8123364079@1.1.1.1:5063;transport=UDP>;tag=2e1b18>, TO=<
<sip:88123364021@1.1.1.1:5063;tra>, CSEQ_N=<46#015#012Cal>
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:tm:t_uac_cancel:
UNREF_UNSAFE: [0xb6b8fd34] after is 1
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:tm:set_timer:
relative timeout is 1000000
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:tm:insert_timer_unsafe: [4]: 0xb6b95ff8 (3648400000)
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:tm:set_timer:
relative timeout is 5
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:tm:insert_timer_unsafe: [0]: 0xb6b96014 (3652)
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: B2B: b2b_request with
CANCEL activated
Jun 10 17:40:47 kam /usr/local/opensips1.6.4/sbin/opensips[31428]:
ERROR:core:parse_first_line: bad request first line
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]:
DBG:core:destroy_avp_list: destroying list (nil)
Jun 10 17:40:47 kam /usr/local/opensips1.6.4/sbin/opensips[31428]:
ERROR:core:parse_first_line: at line 0 char 11:
Jun 10 17:40:47 kam /usr/local/sbc/sbin/opensips[1814]: DBG:core:receive_msg:
cleaning up
Jun 10 17:40:47 kam /usr/local/opensips1.6.4/sbin/opensips[31428]:
ERROR:core:parse_first_line: parsed so far: CANCEL 183
Jun 10 17:40:47 kam /usr/local/opensips1.6.4/sbin/opensips[31428]:
INFO:core:parse_first_line: bad message
Jun 10 17:40:47 kam /usr/local/opensips1.6.4/sbin/opensips[31428]:
ERROR:core:parse_msg: message=<CANCEL 183 Session Progress#015#012Via:
SIP/2.0/UDP 192.168. SIP/2.0#015#012Via: SIP/2.0/UDP
1.1.1.1:5063;branch=z9hG4bKa7fb.2d9eea55.0#015#012nsport=UDP>;tag=B2B.316.51#015#012From:
<sip:8123364079@1.1.1.1:5063;transport=UDP>;tag=2e1b18hYzkyODA2YjEzZGEyZTFhNjA
<sip:88123364021@1.1.1.1:5063;tra46#015#012Cal CANCEL#015#012Max-Forwards:
70#015#012Contact: <sip:1.1.1.1:5063;transport=udp>#015#012#015#012>_______________________________________________
Users mailing list
Users@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
