[SR-Users] Kamailio V 2.4.2 Dialog_ng crash and IMS_USRLOC_SCSCF doc
ycaner
yasin.caner at netgsm.com.tr
Wed Apr 8 13:22:23 CEST 2015
Hello,
i got 2 trace. when u have time ,take a look please
************************************************
1ST*****************************
5(18286) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp
list (nil)
5(18286) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg:
cleaning up
4(18284) DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request:
4(18284) DEBUG: <core> [parser/msg_parser.c:625]: parse_msg(): method:
<INVITE>
4(18284) DEBUG: <core> [parser/msg_parser.c:627]: parse_msg(): uri:
<sip:NUMBER at ip;transport=UDP>
4(18284) DEBUG: <core> [parser/msg_parser.c:629]: parse_msg(): version:
<SIP/2.0>
4(18284) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found
param type 232, <branch> = <z9hG4bK-d8754z-25c91a7ec68e5790-1---d8754z->;
state=6
4(18284) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found
param type 235, <rport> = <n/a>; state=17
4(18284) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of
header reached, state=5
4(18284) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers():
parse_headers: Via found, flags=2
4(18284) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers():
parse_headers: this is the first via
4(18284) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...
4(18284) DEBUG: <core> [receive.c:197]: receive_msg(): preparing to run
routing scripts...
4(18284) DEBUG: <core> [sruid.c:178]: sruid_next(): new sruid is
[srid-552509d3-476c-1] (1 / 20)
4(18284) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70
4(18284) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec():
end of header reached, state=10
4(18284) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG:
get_hdr_field: <To> [46]; uri=[sip:NUMBER at ip;transport=UDP]
4(18284) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG:
to body [<sip:NUMBER at ip;transport=UDP>
]
4(18284) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field():
get_hdr_field: cseq <CSeq>: <2> <INVITE>
4(18284) DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG:
get_hdr_body : content_length=241
4(18284) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found
end of header
4(18284) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param():
DEBUG: add_param: tag=5f3bbe07
4(18284) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec():
end of header reached, state=29
4(18284) DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks
result: 1
4(18284) DEBUG: <core> [msg_translator.c:206]: check_via_address():
check_via_address(192.168.0.223, 192.168.0.223, 0)
4(18284) DEBUG: siputils [checks.c:103]: has_totag(): no totag
4(18284) DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg:
msg id=1 global id=0 T start=0xffffffffffffffff
4(18284) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request:
start searching: hash=34067, isACK=0
4(18284) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261
transaction matching failed
4(18284) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG:
t_lookup_request: no transaction found
4(18284) DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg:
msg id=1 global id=1 T end=(nil)
4(18284) DEBUG: auth_db [authorize.c:498]: auth_check(): realm [ip] table
[subscriber] flags [0]
4(18284) DEBUG: auth [api.c:96]: pre_auth(): auth: digest-algo: MD5 parsed
value: 1
4(18284) DEBUG: <core> [db_res.c:118]: db_new_result(): allocate 56 bytes
for result set at 0x7f86dd8b23d8
4(18284) DEBUG: db_mysql [km_res.c:68]: db_mysql_get_columns(): 3 columns
returned from the query
4(18284) DEBUG: <core> [db_res.c:156]: db_allocate_columns(): allocate 24
bytes for result names at 0x7f86dd8b2448
4(18284) DEBUG: <core> [db_res.c:167]: db_allocate_columns(): allocate 12
bytes for result types at 0x7f86dd8b2498
4(18284) DEBUG: db_mysql [km_res.c:86]: db_mysql_get_columns(): allocate 16
bytes for RES_NAMES[0] at 0x7f86dd8b24e0
4(18284) DEBUG: db_mysql [km_res.c:93]: db_mysql_get_columns():
RES_NAMES(0x7f86dd8b24e0)[0]=[sippasswd]
4(18284) DEBUG: db_mysql [km_res.c:137]: db_mysql_get_columns(): use
DB1_STRING result type
4(18284) DEBUG: db_mysql [km_res.c:86]: db_mysql_get_columns(): allocate 16
bytes for RES_NAMES[1] at 0x7f86dd8b2528
4(18284) DEBUG: db_mysql [km_res.c:93]: db_mysql_get_columns():
RES_NAMES(0x7f86dd8b2528)[1]=[userid]
4(18284) DEBUG: db_mysql [km_res.c:101]: db_mysql_get_columns(): use
DB1_INT result type
4(18284) DEBUG: db_mysql [km_res.c:86]: db_mysql_get_columns(): allocate 16
bytes for RES_NAMES[2] at 0x7f86dd8b2570
4(18284) DEBUG: db_mysql [km_res.c:93]: db_mysql_get_columns():
RES_NAMES(0x7f86dd8b2570)[2]=[permit_ip]
4(18284) DEBUG: db_mysql [km_res.c:137]: db_mysql_get_columns(): use
DB1_STRING result type
4(18284) DEBUG: <core> [db_res.c:186]: db_allocate_rows(): allocate 16
bytes for rows at 0x7f86dd8b25b8
4(18284) DEBUG: <core> [db_row.c:119]: db_allocate_row(): allocate 96 bytes
for row values at 0x7f86dd8b2600
4(18284) DEBUG: <core> [db_val.c:117]: db_str2val(): converting STRING
[850302342301]
4(18284) DEBUG: <core> [db_val.c:73]: db_str2val(): converting INT [155982]
4(18284) DEBUG: <core> [db_val.c:117]: db_str2val(): converting STRING
[0.0.0.0]
4(18284) DEBUG: auth_db [authorize.c:208]: get_ha1(): HA1 string
calculated: f8a3d19f99daa1f9b6e063b74c390a02
4(18284) DEBUG: auth [api.c:211]: auth_check_response(): check_response:
Our result = 'fbd5b3b9148128721fd224940fad2a50'
4(18284) DEBUG: auth [api.c:218]: auth_check_response(): check_response:
Authorization is OK
4(18284) DEBUG: <core> [db_res.c:81]: db_free_columns(): freeing 3 columns
4(18284) DEBUG: <core> [db_res.c:85]: db_free_columns(): freeing
RES_NAMES[0] at 0x7f86dd8b24e0
4(18284) DEBUG: <core> [db_res.c:85]: db_free_columns(): freeing
RES_NAMES[1] at 0x7f86dd8b2528
4(18284) DEBUG: <core> [db_res.c:85]: db_free_columns(): freeing
RES_NAMES[2] at 0x7f86dd8b2570
4(18284) DEBUG: <core> [db_res.c:94]: db_free_columns(): freeing result
names at 0x7f86dd8b2448
4(18284) DEBUG: <core> [db_res.c:99]: db_free_columns(): freeing result
types at 0x7f86dd8b2498
4(18284) DEBUG: <core> [db_res.c:54]: db_free_rows(): freeing 1 rows
4(18284) DEBUG: <core> [db_row.c:97]: db_free_row(): freeing row values at
0x7f86dd8b2600
4(18284) DEBUG: <core> [db_res.c:62]: db_free_rows(): freeing rows at
0x7f86dd8b25b8
4(18284) DEBUG: <core> [db_res.c:136]: db_free_result(): freeing result set
at 0x7f86dd8b23d8
4(18284) DEBUG: rr [record.c:115]: get_custom_user(): invalid AVP value,
using default user from RURI
4(18284) DEBUG: <core> [socket_info.c:583]: grep_sock_info():
grep_sock_info - checking if host==us: 13==13 && [ip] == [ip]
4(18284) DEBUG: <core> [socket_info.c:587]: grep_sock_info():
grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
4(18284) DEBUG: registrar [lookup.c:198]: lookup_helper(): contact for
[NUMBER] found by address
4(18284) DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg
id=1 , global msg id=1 , T on entrance=(nil)
4(18284) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request:
start searching: hash=34067, isACK=0
4(18284) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261
transaction matching failed
4(18284) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG:
t_lookup_request: no transaction found
4(18284) DEBUG: tm [t_hooks.c:380]: run_reqin_callbacks_internal(): DBG:
trans=0x7f86d39fb8a8, callback type 1, id 0 entered
4(18284) DEBUG: dialog_ng [dlg_handlers.c:855]: dlg_new_dialog(): starting
dlg_new_dialog and method is [INVITE]
4(18284) DEBUG: dialog_ng [dlg_hash.c:924]: get_dlg(): no dialog
callid='M2Q3YzdhMzIzYTAwNjVmZjU4YWI0ODEwNjE4ZjBhYmY.' found
4(18284) DEBUG: dialog_ng [dlg_handlers.c:908]: dlg_new_dialog(): Building
new Dialog for call-id M2Q3YzdhMzIzYTAwNjVmZjU4YWI0ODEwNjE4ZjBhYmY.
4(18284) DEBUG: dialog_ng [dlg_handlers.c:909]: dlg_new_dialog(): SIP
Method: INVITE
4(18284) DEBUG: dialog_ng [dlg_hash.c:324]: build_new_dlg(): new dialog on
hash 1247
4(18284) DEBUG: dialog_ng [dlg_handlers.c:249]: populate_leg_info():
route_set , contact sip:8503023423 at 192.168.0.223:58288;transport=UDP, cseq 2
and bind_addr udp:ip:5060
4(18284) DEBUG: dialog_ng [dlg_hash.c:970]: link_dlg(): Linking new dialog
with h_entry: 1247 4(18284) DEBUG: dialog_ng [dlg_hash.c:984]: link_dlg():
ref dlg 0x7f86d39fcec8 with 1 -> 1
4(18284) DEBUG: dialog_ng [dlg_cb.c:250]: run_create_callbacks():
dialog=0x7f86d39fcec8
4(18284) DEBUG: acc [acc_cdr.c:726]: cdr_on_create(): dialog
'0x7f86d39fcec8' created! 1(18280) DEBUG: <core> [parser/msg_parser.c:623]:
parse_msg(): SIP Request:
1(18280) DEBUG: <core> [parser/msg_parser.c:625]: parse_msg(): method:
<OPTIONS>
1(18280) DEBUG: <core> [parser/msg_parser.c:627]: parse_msg(): uri:
<sip:ip>
1(18280) DEBUG: <core> [parser/msg_parser.c:629]: parse_msg(): version:
<SIP/2.0>
1(18280) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found
param type 232, <branch> = <z9hG4bK3ad4ae72>; state=6
1(18280) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found
param type 235, <rport> = <n/a>; state=17
1(18280) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of
header reached, state=5
1(18280) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers():
parse_headers: Via found, flags=2
1(18280) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers():
parse_headers: this is the first via
1(18280) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...
1(18280) DEBUG: <core> [receive.c:197]: receive_msg(): preparing to run
routing scripts...
1(18280) DEBUG: <core> [sruid.c:178]: sruid_next(): new sruid is
[srid-552509d3-4768-1] (1 / 20)
1(18280) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70
1(18280) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec():
end of header reached, state=10
1(18280) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG:
get_hdr_field: <To> [21]; uri=[sip:ip]
1(18280) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG:
to body [<sip:ip>
]
1(18280) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field():
get_hdr_field: cseq <CSeq>: <102> <OPTIONS>
1(18280) DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG:
get_hdr_body : content_length=0
1(18280) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found
end of header
1(18280) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param():
DEBUG: add_param: tag=as1276ecb6
1(18280) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec():
end of header reached, state=29
1(18280) DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks
result: 1
1(18280) DEBUG: <core> [msg_translator.c:206]: check_via_address():
check_via_address(212.175.81.71, 212.175.81.71, 0)
1(18280) DEBUG: siputils [checks.c:103]: has_totag(): no totag
1(18280) DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg:
msg id=1 global id=0 T start=0xffffffffffffffff
1(18280) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request:
start searching: hash=20665, isACK=0
1(18280) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261
transaction matching failed
1(18280) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG:
t_lookup_request: no transaction found
1(18280) DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg:
msg id=1 global id=1 T end=(nil)
1(18280) DEBUG: <core> [socket_info.c:583]: grep_sock_info():
grep_sock_info - checking if host==us: 13==13 && [ip] == [ip]
1(18280) DEBUG: <core> [socket_info.c:587]: grep_sock_info():
grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
1(18280) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list 0x7f86d39fd928
1(18280) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
1(18280) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
1(18280) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
1(18280) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
1(18280) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
1(18280) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp
list (nil)
1(18280) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg:
cleaning up
0(18271) ALERT: <core> [main.c:784]: handle_sigs(): child process 18284
exited by a signal 11
14(18312) CRITICAL: <core> [pass_fd.c:293]: receive_fd(): EOF on 11
0(18271) ALERT: <core> [main.c:787]: handle_sigs(): core was generated
14(18312) DEBUG: <core> [tcp_main.c:3537]: handle_ser_child(): DBG:
handle_ser_child: dead child 4, pid 18284 (shutting down?)
0(18271) INFO: <core> [main.c:799]: handle_sigs(): terminating due to
SIGCHLD
14(18312) DEBUG: <core> [io_wait.h:610]: io_watch_del(): DBG: io_watch_del
(0x9e70a0, 11, -1, 0x0) fd_no=13 called
14(18312) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
13(18308) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
9(18291) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
11(18297) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
2(18281) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
12(18307) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
5(18286) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
8(18289) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
1(18280) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
7(18288) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
6(18287) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
3(18282) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
10(18292) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
0(18271) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7f86d39e5058
0(18271) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7f86d39e5060
0(18271) DEBUG: <core> [dtrie.c:93]: dtrie_delete(): free node at
0x7f86d39e5e18
0(18271) DEBUG: <core> [dtrie.c:93]: dtrie_delete(): free node at
0x7f86d39e5d48
0(18271) DEBUG: <core> [dtrie.c:93]: dtrie_delete(): free node at
0x7f86d39e5c78
0(18271) DEBUG: <core> [dtrie.c:93]: dtrie_delete(): free node at
0x7f86d39e5ba8
0(18271) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7f86d39e5958
0(18271) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7f86d39e5960
0(18271) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7f86d39e54d8
0(18271) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7f86d39e54e0
0(18271) DEBUG: dialog_ng [dlg_hash.c:175]: destroy_dlg(): destroying
dialog 0x7f86d39fcec8
0(18271) DEBUG: dialog_ng [dlg_hash.c:190]: destroy_dlg(): removed timer
for dlg 0x7f86d39fcec8 [1247:1565] with clid
'M2Q3YzdhMzIzYTAwNjVmZjU4YWI0ODEwNjE4ZjBhYmY.' and tags '5f3bbe07'
0(18271) DEBUG: dialog_ng [dlg_hash.c:197]: destroy_dlg(): About to run dlg
callback for destroy
0(18271) DEBUG: dialog_ng [dlg_cb.c:276]: run_dlg_callbacks():
dialog=0x7f86d39fcec8, type=8192
0(18271) DEBUG: acc [acc_cdr.c:671]: cdr_on_destroy(): dialog
'0x7f86d39fcec8' destroyed!
0(18271) DEBUG: dialog_ng [dlg_hash.c:199]: destroy_dlg(): DONE: About to
run dlg callback for destroy
0(18271) DEBUG: dialog_ng [dlg_hash.c:135]: destroy_entry_out(): Destroy
dialog entry out
0(18271) DEBUG: <core> [db_pool.c:102]: pool_remove(): removing connection
from the pool
0(18271) DEBUG: tm [t_funcs.c:119]: tm_shutdown(): DEBUG: tm_shutdown :
start
0(18271) DEBUG: tm [t_funcs.c:122]: tm_shutdown(): DEBUG: tm_shutdown :
emptying hash table
0(18271) DEBUG: tm [t_funcs.c:124]: tm_shutdown(): DEBUG: tm_shutdown :
removing semaphores
0(18271) DEBUG: tm [t_funcs.c:126]: tm_shutdown(): DEBUG: tm_shutdown :
destroying tmcb lists
0(18271) DEBUG: tm [t_funcs.c:129]: tm_shutdown(): DEBUG: tm_shutdown :
done
0(18271) DEBUG: <core> [mem/shm_mem.c:242]: shm_mem_destroy():
shm_mem_destroy
0(18271) DEBUG: <core> [mem/shm_mem.c:245]: shm_mem_destroy(): destroying
the shared memory lock
0(18271) DEBUG: <core> [main.c:803]: handle_sigs(): terminating due to
SIGCHLD
************************************************
1ST****************************
************************************************
2ND****************************
4(18366) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp
list (nil)
4(18366) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg:
cleaning up
3(18364) DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request:
3(18364) DEBUG: <core> [parser/msg_parser.c:625]: parse_msg(): method:
<INVITE>
3(18364) DEBUG: <core> [parser/msg_parser.c:627]: parse_msg(): uri:
<sip:NUMBER at ip;transport=UDP>
3(18364) DEBUG: <core> [parser/msg_parser.c:629]: parse_msg(): version:
<SIP/2.0>
3(18364) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found
param type 232, <branch> = <z9hG4bK-d8754z-157f210acf9f5910-1---d8754z->;
state=6
3(18364) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found
param type 235, <rport> = <n/a>; state=17
3(18364) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of
header reached, state=5
3(18364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers():
parse_headers: Via found, flags=2
3(18364) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers():
parse_headers: this is the first via
3(18364) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...
3(18364) DEBUG: <core> [receive.c:197]: receive_msg(): preparing to run
routing scripts...
3(18364) DEBUG: <core> [sruid.c:178]: sruid_next(): new sruid is
[srid-55250af6-47bc-1] (1 / 20)
3(18364) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70
3(18364) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec():
end of header reached, state=10
3(18364) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG:
get_hdr_field: <To> [46]; uri=[sip:NUMBER at ip;transport=UDP]
3(18364) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG:
to body [<sip:NUMBER at ip;transport=UDP>
]
3(18364) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field():
get_hdr_field: cseq <CSeq>: <1> <INVITE>
3(18364) DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG:
get_hdr_body : content_length=241
3(18364) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found
end of header
3(18364) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param():
DEBUG: add_param: tag=cb564567
3(18364) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec():
end of header reached, state=29
3(18364) DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks
result: 1
3(18364) DEBUG: <core> [msg_translator.c:206]: check_via_address():
check_via_address(192.168.0.223, 192.168.0.223, 0)
3(18364) DEBUG: siputils [checks.c:103]: has_totag(): no totag
3(18364) DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg:
msg id=1 global id=0 T start=0xffffffffffffffff
3(18364) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request:
start searching: hash=9191, isACK=0
3(18364) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261
transaction matching failed
3(18364) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG:
t_lookup_request: no transaction found
3(18364) DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg:
msg id=1 global id=1 T end=(nil)
3(18364) DEBUG: auth_db [authorize.c:498]: auth_check(): realm [ip] table
[subscriber] flags [0]
3(18364) DEBUG: auth [api.c:86]: pre_auth(): auth:pre_auth: Credentials
with realm 'ip' not found
3(18364) DEBUG: auth_db [authorize.c:264]: digest_authenticate_hdr(): no
credentials
3(18364) DEBUG: auth [challenge.c:127]: get_challenge_hf():
build_challenge_hf: realm='ip'
3(18364) DEBUG: auth [challenge.c:269]: get_challenge_hf(): auth:
'Proxy-Authenticate: Digest realm="ip",
nonce="VSUMK1UlCv9P7aSE5k6Zyrv9CjPNlHFg"
'
3(18364) DEBUG: sl [sl.c:296]: send_reply(): reply in stateless mode (sl)
3(18364) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list 0x7ffcc777ce50
3(18364) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
3(18364) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
3(18364) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
3(18364) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
3(18364) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
3(18364) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp
list (nil)
3(18364) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg:
cleaning up
8(18371) DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request:
8(18371) DEBUG: <core> [parser/msg_parser.c:625]: parse_msg(): method:
<ACK>
8(18371) DEBUG: <core> [parser/msg_parser.c:627]: parse_msg(): uri:
<sip:NUMBER at ip;transport=UDP>
8(18371) DEBUG: <core> [parser/msg_parser.c:629]: parse_msg(): version:
<SIP/2.0>
8(18371) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found
param type 232, <branch> = <z9hG4bK-d8754z-157f210acf9f5910-1---d8754z->;
state=6
8(18371) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found
param type 235, <rport> = <n/a>; state=17
8(18371) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of
header reached, state=5
8(18371) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers():
parse_headers: Via found, flags=2
8(18371) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers():
parse_headers: this is the first via
8(18371) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...
8(18371) DEBUG: <core> [receive.c:197]: receive_msg(): preparing to run
routing scripts...
8(18371) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param():
DEBUG: add_param: tag=51626b8ee4d53f3609fb0fb075d9873e.d813
8(18371) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec():
end of header reached, state=29
8(18371) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG:
get_hdr_field: <To> [88]; uri=[sip:NUMBER at ip;transport=UDP]
8(18371) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG:
to body [<sip:NUMBER at ip;transport=UDP>]
8(18371) DEBUG: sl [sl_funcs.c:431]: sl_filter_ACK(): SL local ACK found ->
dropping it!
8(18371) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
8(18371) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
8(18371) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
8(18371) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
8(18371) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
8(18371) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
8(18371) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp
list (nil)
8(18371) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg:
cleaning up
5(18368) DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request:
5(18368) DEBUG: <core> [parser/msg_parser.c:625]: parse_msg(): method:
<INVITE>
5(18368) DEBUG: <core> [parser/msg_parser.c:627]: parse_msg(): uri:
<sip:NUMBER at ip;transport=UDP>
5(18368) DEBUG: <core> [parser/msg_parser.c:629]: parse_msg(): version:
<SIP/2.0>
5(18368) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found
param type 232, <branch> = <z9hG4bK-d8754z-2329b210f27fbe46-1---d8754z->;
state=6
5(18368) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found
param type 235, <rport> = <n/a>; state=17
5(18368) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of
header reached, state=5
5(18368) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers():
parse_headers: Via found, flags=2
5(18368) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers():
parse_headers: this is the first via
5(18368) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...
5(18368) DEBUG: <core> [receive.c:197]: receive_msg(): preparing to run
routing scripts...
5(18368) DEBUG: <core> [sruid.c:178]: sruid_next(): new sruid is
[srid-55250af6-47c0-1] (1 / 20)
5(18368) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70
5(18368) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec():
end of header reached, state=10
5(18368) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG:
get_hdr_field: <To> [46]; uri=[sip:NUMBER at ip;transport=UDP]
5(18368) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG:
to body [<sip:NUMBER at ip;transport=UDP>
]
5(18368) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field():
get_hdr_field: cseq <CSeq>: <2> <INVITE>
5(18368) DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG:
get_hdr_body : content_length=241
5(18368) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found
end of header
5(18368) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param():
DEBUG: add_param: tag=cb564567
5(18368) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec():
end of header reached, state=29
5(18368) DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks
result: 1
5(18368) DEBUG: <core> [msg_translator.c:206]: check_via_address():
check_via_address(192.168.0.223, 192.168.0.223, 0)
5(18368) DEBUG: siputils [checks.c:103]: has_totag(): no totag
5(18368) DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg:
msg id=1 global id=0 T start=0xffffffffffffffff
5(18368) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request:
start searching: hash=9188, isACK=0
5(18368) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261
transaction matching failed
5(18368) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG:
t_lookup_request: no transaction found
5(18368) DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg:
msg id=1 global id=1 T end=(nil)
5(18368) DEBUG: auth_db [authorize.c:498]: auth_check(): realm [ip] table
[subscriber] flags [0]
5(18368) DEBUG: auth [api.c:96]: pre_auth(): auth: digest-algo: MD5 parsed
value: 1
5(18368) DEBUG: <core> [db_res.c:118]: db_new_result(): allocate 56 bytes
for result set at 0x7ffcd16373d8
5(18368) DEBUG: db_mysql [km_res.c:68]: db_mysql_get_columns(): 3 columns
returned from the query
5(18368) DEBUG: <core> [db_res.c:156]: db_allocate_columns(): allocate 24
bytes for result names at 0x7ffcd1637448
5(18368) DEBUG: <core> [db_res.c:167]: db_allocate_columns(): allocate 12
bytes for result types at 0x7ffcd1637498
5(18368) DEBUG: db_mysql [km_res.c:86]: db_mysql_get_columns(): allocate 16
bytes for RES_NAMES[0] at 0x7ffcd16374e0
5(18368) DEBUG: db_mysql [km_res.c:93]: db_mysql_get_columns():
RES_NAMES(0x7ffcd16374e0)[0]=[sippasswd]
5(18368) DEBUG: db_mysql [km_res.c:137]: db_mysql_get_columns(): use
DB1_STRING result type
5(18368) DEBUG: db_mysql [km_res.c:86]: db_mysql_get_columns(): allocate 16
bytes for RES_NAMES[1] at 0x7ffcd1637528
5(18368) DEBUG: db_mysql [km_res.c:93]: db_mysql_get_columns():
RES_NAMES(0x7ffcd1637528)[1]=[userid]
5(18368) DEBUG: db_mysql [km_res.c:101]: db_mysql_get_columns(): use
DB1_INT result type
5(18368) DEBUG: db_mysql [km_res.c:86]: db_mysql_get_columns(): allocate 16
bytes for RES_NAMES[2] at 0x7ffcd1637570
5(18368) DEBUG: db_mysql [km_res.c:93]: db_mysql_get_columns():
RES_NAMES(0x7ffcd1637570)[2]=[permit_ip]
5(18368) DEBUG: db_mysql [km_res.c:137]: db_mysql_get_columns(): use
DB1_STRING result type
5(18368) DEBUG: <core> [db_res.c:186]: db_allocate_rows(): allocate 16
bytes for rows at 0x7ffcd16375b8
5(18368) DEBUG: <core> [db_row.c:119]: db_allocate_row(): allocate 96 bytes
for row values at 0x7ffcd1637600
5(18368) DEBUG: <core> [db_val.c:117]: db_str2val(): converting STRING
[NUMBERCALLER01]
5(18368) DEBUG: <core> [db_val.c:73]: db_str2val(): converting INT [155982]
5(18368) DEBUG: <core> [db_val.c:117]: db_str2val(): converting STRING
[0.0.0.0]
5(18368) DEBUG: auth_db [authorize.c:208]: get_ha1(): HA1 string
calculated: f8a3d19f99daa1f9b6e063b74c390a02
5(18368) DEBUG: auth [api.c:211]: auth_check_response(): check_response:
Our result = 'c16c53e4f1dae97a33ad26aab1ba55bd'
5(18368) DEBUG: auth [api.c:218]: auth_check_response(): check_response:
Authorization is OK
5(18368) DEBUG: <core> [db_res.c:81]: db_free_columns(): freeing 3 columns
5(18368) DEBUG: <core> [db_res.c:85]: db_free_columns(): freeing
RES_NAMES[0] at 0x7ffcd16374e0
5(18368) DEBUG: <core> [db_res.c:85]: db_free_columns(): freeing
RES_NAMES[1] at 0x7ffcd1637528
5(18368) DEBUG: <core> [db_res.c:85]: db_free_columns(): freeing
RES_NAMES[2] at 0x7ffcd1637570
5(18368) DEBUG: <core> [db_res.c:94]: db_free_columns(): freeing result
names at 0x7ffcd1637448
5(18368) DEBUG: <core> [db_res.c:99]: db_free_columns(): freeing result
types at 0x7ffcd1637498
5(18368) DEBUG: <core> [db_res.c:54]: db_free_rows(): freeing 1 rows
5(18368) DEBUG: <core> [db_row.c:97]: db_free_row(): freeing row values at
0x7ffcd1637600
5(18368) DEBUG: <core> [db_res.c:62]: db_free_rows(): freeing rows at
0x7ffcd16375b8
5(18368) DEBUG: <core> [db_res.c:136]: db_free_result(): freeing result set
at 0x7ffcd16373d8
5(18368) DEBUG: rr [record.c:115]: get_custom_user(): invalid AVP value,
using default user from RURI
5(18368) DEBUG: <core> [socket_info.c:583]: grep_sock_info():
grep_sock_info - checking if host==us: 13==13 && [ip] == [ip]
5(18368) DEBUG: <core> [socket_info.c:587]: grep_sock_info():
grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
5(18368) DEBUG: registrar [lookup.c:198]: lookup_helper(): contact for
[NUMBER] found by address
5(18368) DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg
id=1 , global msg id=1 , T on entrance=(nil)
5(18368) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request:
start searching: hash=9188, isACK=0
5(18368) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261
transaction matching failed
5(18368) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG:
t_lookup_request: no transaction found
5(18368) DEBUG: tm [t_hooks.c:380]: run_reqin_callbacks_internal(): DBG:
trans=0x7ffcc777d910, callback type 1, id 0 entered
5(18368) DEBUG: dialog_ng [dlg_handlers.c:855]: dlg_new_dialog(): starting
dlg_new_dialog and method is [INVITE]
5(18368) DEBUG: dialog_ng [dlg_hash.c:924]: get_dlg(): no dialog
callid='NDMyMTRiNjYzODQzMjU4ZGE3OTBlY2JmNTQyMzgzZTQ.' found
5(18368) DEBUG: dialog_ng [dlg_handlers.c:908]: dlg_new_dialog(): Building
new Dialog for call-id NDMyMTRiNjYzODQzMjU4ZGE3OTBlY2JmNTQyMzgzZTQ.
5(18368) DEBUG: dialog_ng [dlg_handlers.c:909]: dlg_new_dialog(): SIP
Method: INVITE
5(18368) DEBUG: dialog_ng [dlg_hash.c:324]: build_new_dlg(): new dialog on
hash 944
5(18368) DEBUG: dialog_ng [dlg_handlers.c:249]: populate_leg_info():
route_set , contact sip:NUMBERCALLER at 192.168.0.223:58288;transport=UDP, cseq
2 and bind_addr udp:ip:5060
5(18368) DEBUG: dialog_ng [dlg_hash.c:970]: link_dlg(): Linking new dialog
with h_entry: 944 5(18368) DEBUG: dialog_ng [dlg_hash.c:984]: link_dlg():
ref dlg 0x7ffcc77802b8 with 1 -> 1
5(18368) DEBUG: dialog_ng [dlg_cb.c:250]: run_create_callbacks():
dialog=0x7ffcc77802b8
5(18368) DEBUG: acc [acc_cdr.c:726]: cdr_on_create(): dialog
'0x7ffcc77802b8' created! 0(18353) ALERT: <core> [main.c:784]:
handle_sigs(): child process 18368 exited by a signal 11
14(18391) CRITICAL: <core> [pass_fd.c:293]: receive_fd(): EOF on 12
0(18353) ALERT: <core> [main.c:787]: handle_sigs(): core was generated
14(18391) DEBUG: <core> [tcp_main.c:3537]: handle_ser_child(): DBG:
handle_ser_child: dead child 5, pid 18368 (shutting down?)
0(18353) INFO: <core> [main.c:799]: handle_sigs(): terminating due to
SIGCHLD
14(18391) DEBUG: <core> [io_wait.h:610]: io_watch_del(): DBG: io_watch_del
(0x9e70a0, 12, -1, 0x0) fd_no=13 called
14(18391) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
8(18371) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
13(18390) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
6(18369) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
1(18362) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
11(18374) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
7(18370) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
4(18366) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
3(18364) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
9(18372) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
2(18363) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
10(18373) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
12(18389) INFO: <core> [main.c:850]: sig_usr(): signal 15 received
0(18353) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7ffcc776a058
0(18353) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7ffcc776a060
0(18353) DEBUG: <core> [dtrie.c:93]: dtrie_delete(): free node at
0x7ffcc776ae18
0(18353) DEBUG: <core> [dtrie.c:93]: dtrie_delete(): free node at
0x7ffcc776ad48
0(18353) DEBUG: <core> [dtrie.c:93]: dtrie_delete(): free node at
0x7ffcc776ac78
0(18353) DEBUG: <core> [dtrie.c:93]: dtrie_delete(): free node at
0x7ffcc776aba8
0(18353) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7ffcc776a958
0(18353) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7ffcc776a960
0(18353) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7ffcc776a4d8
0(18353) DEBUG: <core> [dtrie.c:105]: dtrie_destroy(): free root at
0x7ffcc776a4e0
0(18353) DEBUG: dialog_ng [dlg_hash.c:175]: destroy_dlg(): destroying
dialog 0x7ffcc77802b8
0(18353) DEBUG: dialog_ng [dlg_hash.c:190]: destroy_dlg(): removed timer
for dlg 0x7ffcc77802b8 [944:2323] with clid
'NDMyMTRiNjYzODQzMjU4ZGE3OTBlY2JmNTQyMzgzZTQ.' and tags 'cb564567'
0(18353) DEBUG: dialog_ng [dlg_hash.c:197]: destroy_dlg(): About to run dlg
callback for destroy
0(18353) DEBUG: dialog_ng [dlg_cb.c:276]: run_dlg_callbacks():
dialog=0x7ffcc77802b8, type=8192
0(18353) DEBUG: acc [acc_cdr.c:671]: cdr_on_destroy(): dialog
'0x7ffcc77802b8' destroyed!
0(18353) DEBUG: dialog_ng [dlg_hash.c:199]: destroy_dlg(): DONE: About to
run dlg callback for destroy
0(18353) DEBUG: dialog_ng [dlg_hash.c:135]: destroy_entry_out(): Destroy
dialog entry out
0(18353) DEBUG: usrloc [ucontact.c:957]: db_update_ucontact_ruid():
ruid:uloc-55250628-45ab-1
0(18353) DEBUG: usrloc [ucontact.c:1068]: db_update_ucontact_ruid():
contact:sip:NUMBER at 192.168.0.223:58288;rinstance=b11aa314960a5941;transport=UDP
0(18353) DEBUG: <core> [db_pool.c:102]: pool_remove(): removing connection
from the pool
0(18353) DEBUG: tm [t_funcs.c:119]: tm_shutdown(): DEBUG: tm_shutdown :
start
0(18353) DEBUG: tm [t_funcs.c:122]: tm_shutdown(): DEBUG: tm_shutdown :
emptying hash table
0(18353) DEBUG: tm [t_funcs.c:124]: tm_shutdown(): DEBUG: tm_shutdown :
removing semaphores
0(18353) DEBUG: tm [t_funcs.c:126]: tm_shutdown(): DEBUG: tm_shutdown :
destroying tmcb lists
0(18353) DEBUG: tm [t_funcs.c:129]: tm_shutdown(): DEBUG: tm_shutdown :
done
0(18353) DEBUG: <core> [mem/shm_mem.c:242]: shm_mem_destroy():
shm_mem_destroy
0(18353) DEBUG: <core> [mem/shm_mem.c:245]: shm_mem_destroy(): destroying
the shared memory lock
0(18353) DEBUG: <core> [main.c:803]: handle_sigs(): terminating due to
SIGCHLD
^C
************************************************
2ND****************************
--
View this message in context: http://sip-router.1086192.n5.nabble.com/Kamailio-V-2-4-2-Dialog-ng-crash-and-IMS-USRLOC-SCSCF-doc-tp136786p136820.html
Sent from the Users mailing list archive at Nabble.com.
More information about the sr-users
mailing list