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>