Hi, Please find attached logfile. thanks
-----Original Message-----
From: Uwe Kastens [mailto:ki...@kiste.org]
Sent: 2009年6月19日 14:33
To: XIN Xiuhe
Cc: users@lists.opensips.org
Subject: Re: [OpenSIPS-Users] Basic call failed
Hi,
that looks ok. Could you please make a call with opensips at debuglevel
9 at post the logfile?
BR
uwe
XIN Xiuhe schrieb:
> mysql> select * from location;
> +----+----------+--------+------------------------------+----------+------+---------------------+-------+---------------------+------+---------------------+-------+--------+---------------------+---------------------+---------+
> | id | username | domain | contact | received | path |
> expires | q | callid | cseq | last_modified
> | flags | cflags | user_agent | socket | methods |
> +----+----------+--------+------------------------------+----------+------+---------------------+-------+---------------------+------+---------------------+-------+--------+---------------------+---------------------+---------+
> | 11 | 33330004 | NULL | sip:33330...@40.0.0.165:5060 | NULL | NULL |
> 2009-06-19 13:41:26 | -1.00 | 1569339300-27981165 | 2 | 2009-06-19
> 12:41:26 | 0 | 0 | Alcatel-Lucent ISAM | udp:40.0.0.164:7060 |
> 3199 |
> | 12 | 33330003 | NULL | sip:33330...@40.0.0.165:5060 | NULL | NULL |
> 2009-06-19 13:41:28 | -1.00 | 1570548700-27981169 | 2 | 2009-06-19
> 12:41:28 | 0 | 0 | Alcatel-Lucent ISAM | udp:40.0.0.164:7060 |
> 3199 |
> +----+----------+--------+------------------------------+----------+------+---------------------+-------+---------------------+------+---------------------+-------+--------+---------------------+---------------------+---------+
> 2 rows in set (0.00 sec)
>
> mysql>
>
>
> -----Original Message-----
> From: Uwe Kastens [mailto:ki...@kiste.org]
> Sent: 2009年6月19日 12:47
> To: XIN Xiuhe
> Cc: users@lists.opensips.org
> Subject: Re: [OpenSIPS-Users] Basic call failed
>
> Hi,
>
> Are you working with a database? So what will the location table entries look
> like? eq select * from location where user="33330004"
>
> BR
>
> Uwe
>
>
> XIN Xiuhe schrieb:
>> Hi, uwe
>>
>> Please find attached opensips.cfg.
>>
>> For this question: What will the contact from the location service show you
>> for Users?
>> I don't know what you mean, do you mean user A and B's contact info?
>>> user A: contact info is 33330...@40.0.0.165, uri is 33330...@40.0.0.164
>>> user B: contact info is 33330...@40.0.0.165 , uri is 33330...@40.0.0.164
>> Thanks for your help!
>>
>> xxh
>>
>> -----Original Message-----
>> From: Uwe Kastens [mailto:ki...@kiste.org]
>> Sent: 2009年6月19日 12:15
>> To: XIN Xiuhe
>> Cc: users@lists.opensips.org
>> Subject: Re: [OpenSIPS-Users] Basic call failed
>>
>> Hi,
>>
>> What will the contact from the location service show you for Users?
>> Could you post your opensips.cfg?
>>
>> BR
>>
>> Uwe
>>
>> XIN Xiuhe schrieb:
>>> Hi,
>>>
>>> I tried to use opensips to make a basic call, but failed.
>>>
>>> user A: 33330...@40.0.0.165
>>> user B: 33330...@40.0.0.165
>>> Both of them registered with opensips(ip address: 40.0.0.164)
>>> successfully.
>>>
>>> User A off hook and call user B, after opensips received the invite
>>> message, it should send it to 40.0.0.165, but from the trace
>>> (attached "basiccall.pcap"), it send it to 40.0.0.164.
>>>
>>> What is the root cause, can somebody give some ideas?
>>>
>>> Thanks !
>>>
>>>
>>>
>>>
>>>
>>>
>>> --------------------------------------------------------------------
>>> -
>>> -
>>> --
>>>
>>> _______________________________________________
>>> Users mailing list
>>> Users@lists.opensips.org
>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>
>
>
--
kiste lat: 54.322684, lon: 10.13586
Jun 19 14:35:44 [31807] DBG:core:parse_msg: SIP Request:
Jun 19 14:35:44 [31807] DBG:core:parse_msg: method: <INVITE>
Jun 19 14:35:44 [31807] DBG:core:parse_msg: uri:
<sip:33330...@40.0.0.164;user=phone>
Jun 19 14:35:44 [31807] DBG:core:parse_msg: version: <SIP/2.0>
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=2
Jun 19 14:35:44 [31807] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK4131910994-27980743>; state=16
Jun 19 14:35:44 [31807] DBG:core:parse_via: end of header reached, state=5
Jun 19 14:35:44 [31807] DBG:core:parse_headers: via found, flags=2
Jun 19 14:35:44 [31807] DBG:core:parse_headers: this is the first via
Jun 19 14:35:44 [31807] DBG:core:receive_msg: After parse_msg...
Jun 19 14:35:44 [31807] DBG:core:receive_msg: preparing to run routing
scripts...
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=100
Jun 19 14:35:44 [31807] DBG:maxfwd:is_maxfwd_present: value = 70
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=8
Jun 19 14:35:44 [31807] DBG:core:parse_to: end of header reached, state=10
Jun 19 14:35:44 [31807] DBG:core:parse_to: display={},
ruri={sip:33330...@40.0.0.164;user=phone}
Jun 19 14:35:44 [31807] DBG:core:get_hdr_field: <To> [38];
uri=[sip:33330...@40.0.0.164;user=phone]
Jun 19 14:35:44 [31807] DBG:core:get_hdr_field: to body
[<sip:33330...@40.0.0.164;user=phone>
]
Jun 19 14:35:44 [31807] DBG:uri:has_totag: no totag
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=78
Jun 19 14:35:44 [31807] DBG:core:get_hdr_field: cseq <CSeq>: <1> <INVITE>
Jun 19 14:35:44 [31807] DBG:tm:t_lookup_request: start searching: hash=11073,
isACK=0
Jun 19 14:35:44 [31807] DBG:tm:matching_3261: RFC3261 transaction matching
failed
Jun 19 14:35:44 [31807] DBG:tm:t_lookup_request: no transaction found
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=200
Jun 19 14:35:44 [31807] DBG:rr:is_preloaded: is_preloaded: Yes
Jun 19 14:35:44 [31807] DBG:core:grep_sock_info: checking if host==us: 10==10
&& [40.0.0.164] == [40.0.0.164]
Jun 19 14:35:44 [31807] DBG:core:grep_sock_info: checking if port 7060 matches
port 7060
Jun 19 14:35:44 [31807] DBG:rr:after_loose: Topmost route URI:
'sip:40.0.0.164:7060;lr' is me
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=200
Jun 19 14:35:44 [31807] DBG:core:get_hdr_field: content_length=168
Jun 19 14:35:44 [31807] DBG:core:get_hdr_field: found end of header
Jun 19 14:35:44 [31807] DBG:rr:find_next_route: No next Route HF found
Jun 19 14:35:44 [31807] DBG:rr:after_loose: No next URI found
Jun 19 14:35:44 [31807] DBG:core:grep_sock_info: checking if host==us: 10==10
&& [40.0.0.164] == [40.0.0.164]
Jun 19 14:35:44 [31807] DBG:core:grep_sock_info: checking if port 7060 matches
port 5060
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_submit_query: discon reset for
135853360
Jun 19 14:35:44 [31807] DBG:core:db_do_query: SYNC-DBG - SELECT successfully
executed!
Jun 19 14:35:44 [31807] DBG:core:db_new_result: allocate 28 bytes for result
set at 0x8195508
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_store_result: SYNC-DBG - SELECT
result was stored!
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_get_columns: 1 columns returned
from the query
Jun 19 14:35:44 [31807] DBG:core:db_allocate_columns: allocate 16 bytes for
result columns at 0x8195538
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_get_columns:
RES_NAMES(0x819553c)[0]=[domain]
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result
type
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_convert_rows: no rows returned
from the query
Jun 19 14:35:44 [31807] DBG:domain:is_domain_local: Realm '40.0.0.164' is not
local
Jun 19 14:35:44 [31807] DBG:core:db_free_columns: freeing result columns at
0x8195538
Jun 19 14:35:44 [31807] DBG:core:db_free_rows: freeing 0 rows
Jun 19 14:35:44 [31807] DBG:core:db_free_result: freeing result set at 0x8195508
Jun 19 14:35:44 [31807] DBG:core:db_free_result: SYNC-DBG - freeing result!
Jun 19 14:35:44 [31807] DBG:core:check_self: host != me
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_submit_query: discon reset for
135853360
Jun 19 14:35:44 [31807] DBG:core:db_do_query: SYNC-DBG - SELECT successfully
executed!
Jun 19 14:35:44 [31807] DBG:core:db_new_result: allocate 28 bytes for result
set at 0x8195508
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_store_result: SYNC-DBG - SELECT
result was stored!
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_get_columns: 1 columns returned
from the query
Jun 19 14:35:44 [31807] DBG:core:db_allocate_columns: allocate 16 bytes for
result columns at 0x8195538
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_get_columns:
RES_NAMES(0x819553c)[0]=[domain]
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result
type
Jun 19 14:35:44 [31807] DBG:db_mysql:db_mysql_convert_rows: no rows returned
from the query
Jun 19 14:35:44 [31807] DBG:domain:is_domain_local: Realm '40.0.0.164' is not
local
Jun 19 14:35:44 [31807] DBG:core:db_free_columns: freeing result columns at
0x8195538
Jun 19 14:35:44 [31807] DBG:core:db_free_rows: freeing 0 rows
Jun 19 14:35:44 [31807] DBG:core:db_free_result: freeing result set at 0x8195508
Jun 19 14:35:44 [31807] DBG:core:db_free_result: SYNC-DBG - freeing result!
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=ffffffffffffffff
Jun 19 14:35:44 [31807] DBG:tm:t_newtran: transaction on entrance=(nil)
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=ffffffffffffffff
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=78
Jun 19 14:35:44 [31807] DBG:tm:t_lookup_request: start searching: hash=11073,
isACK=0
Jun 19 14:35:44 [31807] DBG:tm:matching_3261: RFC3261 transaction matching
failed
Jun 19 14:35:44 [31807] DBG:tm:t_lookup_request: no transaction found
Jun 19 14:35:44 [31807] DBG:core:parse_to_param: tag=ICF_4131911754-27980744
Jun 19 14:35:44 [31807] DBG:core:parse_to: end of header reached, state=29
Jun 19 14:35:44 [31807] DBG:core:parse_to: display={"33330004"},
ruri={sip:33330...@40.0.0.164;user=phone}
Jun 19 14:35:44 [31807] DBG:tm:run_reqin_callbacks: trans=0xb60f9dd8, callback
type 1, id 0 entered
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=78
Jun 19 14:35:44 [31807] DBG:core:parse_headers: flags=ffffffffffffffff
Jun 19 14:35:44 [31807] DBG:core:check_via_address: params 40.0.0.165,
40.0.0.165, 0
Jun 19 14:35:44 [31807] DBG:core:_shm_resize: resize(0) called
Jun 19 14:35:44 [31807] DBG:tm:_reply_light: reply sent out. buf=0x8195698:
SIP/2.0 1..., shmem=0xb60fb898: SIP/2.0 1
Jun 19 14:35:44 [31807] DBG:tm:_reply_light: finished
new branch at sip:33330...@40.0.0.164;user=phone
Jun 19 14:35:44 [31807] DBG:core:mk_proxy: doing DNS lookup...
Jun 19 14:35:44 [31807] DBG:core:check_via_address: params 40.0.0.165,
40.0.0.165, 0
Jun 19 14:35:44 [31807] DBG:tm:set_timer: relative timeout is 500000
Jun 19 14:35:44 [31807] DBG:tm:insert_timer_unsafe: [4]: 0xb60f9f24 (14800000)
Jun 19 14:35:44 [31807] DBG:tm:set_timer: relative timeout is 30
Jun 19 14:35:44 [31807] DBG:tm:insert_timer_unsafe: [0]: 0xb60f9f40 (44)
Jun 19 14:35:44 [31807] DBG:tm:t_relay_to: new transaction fwd'ed
Jun 19 14:35:44 [31807] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Jun 19 14:35:44 [31807] DBG:core:destroy_avp_list: destroying list (nil)
Jun 19 14:35:44 [31807] DBG:core:receive_msg: cleaning up
Jun 19 14:35:44 [31811] DBG:tm:utimer_routine: timer routine:4,tl=0xb60f9f24
next=(nil), timeout=14800000
Jun 19 14:35:44 [31811] DBG:tm:retransmission_handler: retransmission_handler :
request resending (t=0xb60f9dd8, INVITE si ... )
Jun 19 14:35:44 [31811] DBG:tm:set_timer: relative timeout is 1000000
Jun 19 14:35:44 [31811] DBG:tm:insert_timer_unsafe: [5]: 0xb60f9f24 (15800000)
Jun 19 14:35:44 [31811] DBG:tm:retransmission_handler: retransmission_handler :
done
Jun 19 14:35:45 [31811] DBG:tm:utimer_routine: timer routine:5,tl=0xb60f9f24
next=(nil), timeout=15800000
Jun 19 14:35:45 [31811] DBG:tm:retransmission_handler: retransmission_handler :
request resending (t=0xb60f9dd8, INVITE si ... )
Jun 19 14:35:45 [31811] DBG:tm:set_timer: relative timeout is 2000000
Jun 19 14:35:45 [31811] DBG:tm:insert_timer_unsafe: [6]: 0xb60f9f24 (17800000)
Jun 19 14:35:45 [31811] DBG:tm:retransmission_handler: retransmission_handler :
done
Jun 19 14:35:47 [31811] DBG:tm:utimer_routine: timer routine:6,tl=0xb60f9f24
next=(nil), timeout=17800000
Jun 19 14:35:47 [31811] DBG:tm:retransmission_handler: retransmission_handler :
request resending (t=0xb60f9dd8, INVITE si ... )
Jun 19 14:35:47 [31811] DBG:tm:set_timer: relative timeout is 4000000
Jun 19 14:35:47 [31811] DBG:tm:insert_timer_unsafe: [7]: 0xb60f9f24 (21800000)
Jun 19 14:35:47 [31811] DBG:tm:retransmission_handler: retransmission_handler :
done
Jun 19 14:35:51 [31811] DBG:tm:utimer_routine: timer routine:7,tl=0xb60f9f24
next=(nil), timeout=21800000
Jun 19 14:35:51 [31811] DBG:tm:retransmission_handler: retransmission_handler :
request resending (t=0xb60f9dd8, INVITE si ... )
Jun 19 14:35:51 [31811] DBG:tm:set_timer: relative timeout is 4000000
Jun 19 14:35:51 [31811] DBG:tm:insert_timer_unsafe: [7]: 0xb60f9f24 (25800000)
Jun 19 14:35:51 [31811] DBG:tm:retransmission_handler: retransmission_handler :
done
Jun 19 14:35:55 [31811] DBG:tm:utimer_routine: timer routine:7,tl=0xb60f9f24
next=(nil), timeout=25800000
Jun 19 14:35:55 [31811] DBG:tm:retransmission_handler: retransmission_handler :
request resending (t=0xb60f9dd8, INVITE si ... )
Jun 19 14:35:55 [31811] DBG:tm:set_timer: relative timeout is 4000000
Jun 19 14:35:55 [31811] DBG:tm:insert_timer_unsafe: [7]: 0xb60f9f24 (29800000)
Jun 19 14:35:55 [31811] DBG:tm:retransmission_handler: retransmission_handler :
done
Jun 19 14:35:59 [31811] DBG:tm:utimer_routine: timer routine:7,tl=0xb60f9f24
next=(nil), timeout=29800000
Jun 19 14:35:59 [31811] DBG:tm:retransmission_handler: retransmission_handler :
request resending (t=0xb60f9dd8, INVITE si ... )
Jun 19 14:35:59 [31811] DBG:tm:set_timer: relative timeout is 4000000
Jun 19 14:35:59 [31811] DBG:tm:insert_timer_unsafe: [7]: 0xb60f9f24 (33800000)
Jun 19 14:35:59 [31811] DBG:tm:retransmission_handler: retransmission_handler :
done
Jun 19 14:36:03 [31811] DBG:tm:utimer_routine: timer routine:7,tl=0xb60f9f24
next=(nil), timeout=33800000
Jun 19 14:36:03 [31811] DBG:tm:retransmission_handler: retransmission_handler :
request resending (t=0xb60f9dd8, INVITE si ... )
Jun 19 14:36:03 [31811] DBG:tm:set_timer: relative timeout is 4000000
Jun 19 14:36:03 [31811] DBG:tm:insert_timer_unsafe: [7]: 0xb60f9f24 (37800000)
Jun 19 14:36:03 [31811] DBG:tm:retransmission_handler: retransmission_handler :
done
Jun 19 14:36:07 [31811] DBG:tm:utimer_routine: timer routine:7,tl=0xb60f9f24
next=(nil), timeout=37800000
Jun 19 14:36:07 [31811] DBG:tm:retransmission_handler: retransmission_handler :
request resending (t=0xb60f9dd8, INVITE si ... )
Jun 19 14:36:07 [31811] DBG:tm:set_timer: relative timeout is 4000000
Jun 19 14:36:07 [31811] DBG:tm:insert_timer_unsafe: [7]: 0xb60f9f24 (41800000)
Jun 19 14:36:07 [31811] DBG:tm:retransmission_handler: retransmission_handler :
done
Jun 19 14:36:11 [31807] DBG:core:parse_msg: SIP Request:
Jun 19 14:36:11 [31807] DBG:core:parse_msg: method: <OPTIONS>
Jun 19 14:36:11 [31807] DBG:core:parse_msg: uri:
<sip:40.0.0.164:7060;transport=udp>
Jun 19 14:36:11 [31807] DBG:core:parse_msg: version: <SIP/2.0>
Jun 19 14:36:11 [31807] DBG:core:parse_headers: flags=2
Jun 19 14:36:11 [31807] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK4158799234-27980746>; state=16
Jun 19 14:36:11 [31807] DBG:core:parse_via: end of header reached, state=5
Jun 19 14:36:11 [31807] DBG:core:parse_headers: via found, flags=2
Jun 19 14:36:11 [31807] DBG:core:parse_headers: this is the first via
Jun 19 14:36:11 [31807] DBG:core:receive_msg: After parse_msg...
Jun 19 14:36:11 [31807] DBG:core:receive_msg: preparing to run routing
scripts...
Jun 19 14:36:11 [31807] DBG:core:parse_headers: flags=100
Jun 19 14:36:11 [31807] DBG:maxfwd:is_maxfwd_present: value = 70
Jun 19 14:36:11 [31807] DBG:core:parse_headers: flags=8
Jun 19 14:36:11 [31807] DBG:core:parse_to: end of header reached, state=10
Jun 19 14:36:11 [31807] DBG:core:parse_to: display={},
ruri={sip:40.0.0.164:7060;transport=udp}
Jun 19 14:36:11 [31807] DBG:core:get_hdr_field: <To> [37];
uri=[sip:40.0.0.164:7060;transport=udp]
Jun 19 14:36:11 [31807] DBG:core:get_hdr_field: to body
[<sip:40.0.0.164:7060;transport=udp>
]
Jun 19 14:36:11 [31807] DBG:uri:has_totag: no totag
Jun 19 14:36:11 [31807] DBG:core:parse_headers: flags=78
Jun 19 14:36:11 [31807] DBG:core:get_hdr_field: cseq <CSeq>: <1> <OPTIONS>
Jun 19 14:36:11 [31807] DBG:tm:t_lookup_request: start searching: hash=58997,
isACK=0
Jun 19 14:36:11 [31807] DBG:tm:matching_3261: RFC3261 transaction matching
failed
Jun 19 14:36:11 [31807] DBG:tm:t_lookup_request: no transaction found
Jun 19 14:36:11 [31807] DBG:core:parse_headers: flags=200
Jun 19 14:36:11 [31807] DBG:rr:is_preloaded: is_preloaded: Yes
Jun 19 14:36:11 [31807] DBG:core:grep_sock_info: checking if host==us: 10==10
&& [40.0.0.164] == [40.0.0.164]
Jun 19 14:36:11 [31807] DBG:core:grep_sock_info: checking if port 7060 matches
port 7060
Jun 19 14:36:11 [31807] DBG:rr:after_loose: Topmost route URI:
'sip:40.0.0.164:7060;lr' is me
Jun 19 14:36:11 [31807] DBG:core:parse_headers: flags=200
Jun 19 14:36:11 [31807] DBG:core:get_hdr_field: content_length=0
Jun 19 14:36:11 [31807] DBG:core:get_hdr_field: found end of header
Jun 19 14:36:11 [31807] DBG:rr:find_next_route: No next Route HF found
Jun 19 14:36:11 [31807] DBG:rr:after_loose: No next URI found
Jun 19 14:36:11 [31807] DBG:core:grep_sock_info: checking if host==us: 10==10
&& [40.0.0.164] == [40.0.0.164]
Jun 19 14:36:11 [31807] DBG:core:grep_sock_info: checking if port 7060 matches
port 7060
Jun 19 14:36:11 [31807] DBG:core:parse_headers: flags=ffffffffffffffff
Jun 19 14:36:11 [31807] DBG:core:check_via_address: params 40.0.0.165,
40.0.0.165, 0
Jun 19 14:36:11 [31807] DBG:core:destroy_avp_list: destroying list (nil)
Jun 19 14:36:11 [31807] DBG:core:receive_msg: cleaning up
Jun 19 14:36:11 [31811] DBG:tm:utimer_routine: timer routine:7,tl=0xb60f9f24
next=(nil), timeout=41800000
Jun 19 14:36:11 [31811] DBG:tm:retransmission_handler: retransmission_handler :
request resending (t=0xb60f9dd8, INVITE si ... )
Jun 19 14:36:11 [31811] DBG:tm:set_timer: relative timeout is 4000000
Jun 19 14:36:11 [31811] DBG:tm:insert_timer_unsafe: [7]: 0xb60f9f24 (45800000)
Jun 19 14:36:11 [31811] DBG:tm:retransmission_handler: retransmission_handler :
done
Jun 19 14:36:14 [31811] DBG:tm:timer_routine: timer routine:0,tl=0xb60f9f40
next=(nil), timeout=44
Jun 19 14:36:14 [31811] DBG:tm:final_response_handler: stop retr. and send
CANCEL (0xb60f9dd8)
Jun 19 14:36:14 [31811] DBG:tm:t_should_relay_response: T_code=100, new_code=408
Jun 19 14:36:14 [31811] DBG:tm:t_pick_branch: picked branch 0, code 408
(prio=800)
Jun 19 14:36:14 [31811] DBG:tm:is_3263_failure: dns-failover test: branch=0,
last_recv=408, flags=1
Jun 19 14:36:14 [31811] DBG:tm:t_should_relay_response: trying DNS-based
failover
Jun 19 14:36:14 [31811] DBG:tm:relay_reply: branch=0, save=0, relay=0
Jun 19 14:36:14 [31811] DBG:core:parse_headers: flags=ffffffffffffffff
Jun 19 14:36:14 [31811] DBG:core:check_via_address: params 40.0.0.165,
40.0.0.165, 0
Jun 19 14:36:14 [31811] DBG:tm:set_timer: relative timeout is 500000
Jun 19 14:36:14 [31811] DBG:tm:insert_timer_unsafe: [4]: 0xb60f9ea0 (44500000)
Jun 19 14:36:14 [31811] DBG:tm:set_timer: relative timeout is 30
Jun 19 14:36:14 [31811] DBG:tm:insert_timer_unsafe: [0]: 0xb60f9ebc (74)
Jun 19 14:36:14 [31811] DBG:tm:relay_reply: sent buf=0x8190bb8: SIP/2.0 4...,
shmem=0xb60fb898: SIP/2.0 4
Jun 19 14:36:14 [31811] DBG:tm:run_trans_callbacks: trans=0xb60f9dd8, callback
type 256, id 0 entered
Jun 19 14:36:14 [31811] DBG:tm:final_response_handler: done
Jun 19 14:36:14 [31807] DBG:core:parse_msg: SIP Request:
Jun 19 14:36:14 [31807] DBG:core:parse_msg: method: <ACK>
Jun 19 14:36:14 [31807] DBG:core:parse_msg: uri:
<sip:33330...@40.0.0.164;user=phone>
Jun 19 14:36:14 [31807] DBG:core:parse_msg: version: <SIP/2.0>
Jun 19 14:36:14 [31807] DBG:core:parse_headers: flags=2
Jun 19 14:36:14 [31807] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK4131910994-27980743>; state=16
Jun 19 14:36:14 [31807] DBG:core:parse_via: end of header reached, state=5
Jun 19 14:36:14 [31807] DBG:core:parse_headers: via found, flags=2
Jun 19 14:36:14 [31807] DBG:core:parse_headers: this is the first via
Jun 19 14:36:14 [31807] DBG:core:receive_msg: After parse_msg...
Jun 19 14:36:14 [31807] DBG:core:receive_msg: preparing to run routing
scripts...
Jun 19 14:36:14 [31807] DBG:sl:sl_filter_ACK: to late to be a local ACK!
Jun 19 14:36:14 [31807] DBG:core:parse_headers: flags=100
Jun 19 14:36:14 [31807] DBG:maxfwd:is_maxfwd_present: value = 70
Jun 19 14:36:14 [31807] DBG:core:parse_headers: flags=8
Jun 19 14:36:14 [31807] DBG:core:parse_to_param:
tag=d48cb5429d75d1b1bcd850e159ef351c-a3d7
Jun 19 14:36:14 [31807] DBG:core:parse_to: end of header reached, state=29
Jun 19 14:36:14 [31807] DBG:core:parse_to: display={},
ruri={sip:33330...@40.0.0.164;user=phone}
Jun 19 14:36:14 [31807] DBG:core:get_hdr_field: <To> [80];
uri=[sip:33330...@40.0.0.164;user=phone]
Jun 19 14:36:14 [31807] DBG:core:get_hdr_field: to body
[<sip:33330...@40.0.0.164;user=phone>]
Jun 19 14:36:14 [31807] DBG:uri:has_totag: totag found
Jun 19 14:36:14 [31807] DBG:core:parse_headers: flags=200
Jun 19 14:36:14 [31807] DBG:rr:is_preloaded: is_preloaded: No
Jun 19 14:36:14 [31807] DBG:core:grep_sock_info: checking if host==us: 10==10
&& [40.0.0.164] == [40.0.0.164]
Jun 19 14:36:14 [31807] DBG:core:grep_sock_info: checking if port 7060 matches
port 5060
Jun 19 14:36:14 [31807] DBG:db_mysql:db_mysql_submit_query: discon reset for
135853360
Jun 19 14:36:14 [31807] DBG:core:db_do_query: SYNC-DBG - SELECT successfully
executed!
Jun 19 14:36:14 [31807] DBG:core:db_new_result: allocate 28 bytes for result
set at 0x8195570
Jun 19 14:36:14 [31807] DBG:db_mysql:db_mysql_store_result: SYNC-DBG - SELECT
result was stored!
Jun 19 14:36:14 [31807] DBG:db_mysql:db_mysql_get_columns: 1 columns returned
from the query
Jun 19 14:36:14 [31807] DBG:core:db_allocate_columns: allocate 16 bytes for
result columns at 0x8195538
Jun 19 14:36:14 [31807] DBG:db_mysql:db_mysql_get_columns:
RES_NAMES(0x819553c)[0]=[domain]
Jun 19 14:36:14 [31807] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result
type
Jun 19 14:36:14 [31807] DBG:db_mysql:db_mysql_convert_rows: no rows returned
from the query
Jun 19 14:36:14 [31807] DBG:domain:is_domain_local: Realm '40.0.0.164' is not
local
Jun 19 14:36:14 [31807] DBG:core:db_free_columns: freeing result columns at
0x8195538
Jun 19 14:36:14 [31807] DBG:core:db_free_rows: freeing 0 rows
Jun 19 14:36:14 [31807] DBG:core:db_free_result: freeing result set at 0x8195570
Jun 19 14:36:14 [31807] DBG:core:db_free_result: SYNC-DBG - freeing result!
Jun 19 14:36:14 [31807] DBG:core:check_self: host != me
Jun 19 14:36:14 [31807] DBG:core:grep_sock_info: checking if host==us: 10==10
&& [40.0.0.164] == [40.0.0.164]
Jun 19 14:36:14 [31807] DBG:core:grep_sock_info: checking if port 7060 matches
port 7060
Jun 19 14:36:14 [31807] DBG:rr:after_loose: Topmost route URI:
'sip:40.0.0.164:7060;lr' is me
Jun 19 14:36:14 [31807] DBG:core:parse_headers: flags=200
Jun 19 14:36:14 [31807] DBG:core:get_hdr_field: cseq <CSeq>: <1> <ACK>
Jun 19 14:36:14 [31807] DBG:core:get_hdr_field: content_length=0
Jun 19 14:36:14 [31807] DBG:core:get_hdr_field: found end of header
Jun 19 14:36:14 [31807] DBG:rr:find_next_route: No next Route HF found
Jun 19 14:36:14 [31807] DBG:rr:after_loose: No next URI found
Jun 19 14:36:14 [31807] DBG:tm:t_newtran: transaction on entrance=0xffffffff
Jun 19 14:36:14 [31807] DBG:core:parse_headers: flags=ffffffffffffffff
Jun 19 14:36:14 [31807] DBG:core:parse_headers: flags=78
Jun 19 14:36:14 [31807] DBG:tm:t_lookup_request: start searching: hash=11073,
isACK=1
Jun 19 14:36:14 [31807] DBG:tm:matching_3261: RFC3261 transaction matched,
tid=4131910994-27980743
Jun 19 14:36:14 [31807] DBG:tm:t_lookup_request: REF_UNSAFE: after is 1
Jun 19 14:36:14 [31807] DBG:tm:t_lookup_request: transaction found
(T=0xb60f9dd8)
Jun 19 14:36:14 [31807] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Jun 19 14:36:14 [31807] DBG:tm:insert_timer_unsafe: [2]: 0xb60f9e20 (49)
Jun 19 14:36:14 [31807] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Jun 19 14:36:14 [31807] DBG:core:destroy_avp_list: destroying list (nil)
Jun 19 14:36:14 [31807] DBG:core:receive_msg: cleaning up
Jun 19 14:36:14 [31811] DBG:tm:utimer_routine: timer routine:4,tl=0xb60f9ea0
next=(nil), timeout=44500000
Jun 19 14:36:15 [31811] DBG:tm:utimer_routine: timer routine:7,tl=0xb60f9f24
next=(nil), timeout=45800000
Jun 19 14:36:19 [31811] DBG:tm:timer_routine: timer routine:2,tl=0xb60f9e20
next=(nil), timeout=49
Jun 19 14:36:19 [31811] DBG:tm:wait_handler: removing 0xb60f9dd8 from table
Jun 19 14:36:19 [31811] DBG:tm:delete_cell: delete transaction 0xb60f9dd8
Jun 19 14:36:19 [31811] DBG:tm:wait_handler: done
_______________________________________________
Users mailing list
Users@lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
