22 Apr
2015
22 Apr
'15
3 a.m.
Hello,
First, thank you for your quick answer!
When you say it’s a password problem, do you talk about the password of the user that
kamailio use to connect my database?
Because it doesn’t seem to be a connection problem between PostgreSQL and Kamailio. I
think the connection is established between those two because I’m able to see the result
of my “kamctl db show subscriber” command. Indeed, I saw what sip contacts are registered
in the database. They are the ones I added with the kamctl add command. (By the way, if I
finally make my configuration working, sip phones will be seeable in this command
results?)
If you talk about sip phones password, I know that when I add manually a new sip contact
with kamctl add (and it’s registered in the database), I have to set a password. But
before I change the basic config of Kamailio, when sip-phones registered on it (and
they’ve been in its cache), no password was needed (at least, this was what I thought).
Is it still wright with my new configuration?
So, I follow your advice and set debug=3. In Kamailio log, I can see that the REGISTER is
correctly received and parse. But I can see this line and I don’t really know what to
think about it:
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: tm [t_lookup.c:485]:
matching_3261(): DEBUG: RFC3261 transaction matching failed
And this line inquires me too :
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: auth_db [authorize.c:196]:
get_ha1(): no result for user '1001@'
“1001” is the ID of one of my sip-phones. And I don’t understand why there is nothing
after the @...
I did the same test with a jitsi client and I still have the sale “ID@” and nothing
after.
Here is a more complete extract of the Kamailio log, if it helps:
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26614]: DEBUG: <core> [xavp.c:448]:
xavp_destroy_list(): destroying xavp list (nil)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26614]: DEBUG: <core> [receive.c:298]:
receive_msg(): receive_msg: cleaning up
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:623]: parse_msg(): SIP Request:
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:625]: parse_msg(): method: <REGISTER>
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:627]: parse_msg(): uri: <sip:sipr.domain>
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:629]: parse_msg(): version: <SIP/2.0>
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> =
<z9hG4bK-8141f9e3>; state=16
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/parse_via.c:2672]: parse_via(): end of header reached, state=5
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [receive.c:154]:
receive_msg(): After parse_msg...
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [receive.c:197]:
receive_msg(): preparing to run routing scripts...
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=10
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [26];
uri=[sip:1001@sipr.domain]
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body
[<sip:1001@sipr.domain>#015#012]
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>:
<53896> <REGISTER>
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: maxfwd [mf_funcs.c:85]:
is_maxfwd_present(): value = 70
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/msg_parser.c:106]: get_hdr_field(): found end of header
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param:
tag=f10d25c01b845303o0
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=29
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: sanity [mod_sanity.c:255]:
w_sanity_check(): sanity checks result: 1
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: siputils [checks.c:103]:
has_totag(): no totag
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: tm [t_lookup.c:1072]:
t_check_msg(): DEBUG: t_check_msg: msg id=2 global id=1 T start=(nil)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: tm [t_lookup.c:527]:
t_lookup_request(): t_lookup_request: start searching: hash=51997, isACK=0
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: tm [t_lookup.c:485]:
matching_3261(): DEBUG: RFC3261 transaction matching failed
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: tm [t_lookup.c:709]:
t_lookup_request(): DEBUG: t_lookup_request: no transaction found
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: tm [t_lookup.c:1141]:
t_check_msg(): DEBUG: t_check_msg: msg id=2 global id=2 T end=(nil)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [select.c:429]:
run_select(): Calling SELECT 0x7fc256a21030
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: auth_db [authorize.c:498]:
auth_check(): realm [sipr.domain] table [subscriber] flags [1]
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: auth [api.c:96]: pre_auth():
auth: digest-algo: MD5 parsed value: 1
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: db_postgres [km_val.c:163]:
db_postgres_val2str(): PQescapeStringConn: in: 4 chars, out: 4 chars
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: db_postgres [km_dbase.c:230]:
db_postgres_submit_query(): sending query ok: 0x7fc2569d69e8 (2) - [select password from
subscriber where username='1001']
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [db_res.c:118]:
db_new_result(): allocate 56 bytes for result set at 0x7fc256a42698
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: db_postgres [km_dbase.c:509]:
db_postgres_store_result(): 0x7fc2569d69e8 PQresultStatus(PGRES_TUPLES_OK)
PQgetResult(0x1d85300)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: db_postgres [km_res.c:108]:
db_postgres_get_columns(): 1 columns returned from the query
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [db_res.c:156]:
db_allocate_columns(): allocate 8 bytes for result names at 0x7fc256a23088
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [db_res.c:167]:
db_allocate_columns(): allocate 4 bytes for result types at 0x7fc256a21418
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: db_postgres [km_res.c:126]:
db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fc256a37478
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: db_postgres [km_res.c:133]:
db_postgres_get_columns(): RES_NAMES(0x7fc256a37478)[0]=[password]
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: db_postgres [km_res.c:166]:
db_postgres_get_columns(): use DB1_STRING result type
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: db_postgres [km_res.c:211]:
db_postgres_convert_rows(): no rows returned from the query
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: db_postgres [km_dbase.c:390]:
db_postgres_free_query(): PQclear(0x1d85300) result set
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: auth_db [authorize.c:196]:
get_ha1(): no result for user '1001@'
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [db_res.c:81]:
db_free_columns(): freeing 1 columns
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [db_res.c:85]:
db_free_columns(): freeing RES_NAMES[0] at 0x7fc256a37478
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [db_res.c:94]:
db_free_columns(): freeing result names at 0x7fc256a23088
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [db_res.c:99]:
db_free_columns(): freeing result types at 0x7fc256a21418
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [db_res.c:136]:
db_free_result(): freeing result set at 0x7fc256a42698
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: auth [challenge.c:127]:
get_challenge_hf(): build_challenge_hf: realm='sipr.domain'
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: auth [challenge.c:269]:
get_challenge_hf(): auth: 'WWW-Authenticate: Digest realm="sipr.domain",
nonce="VTc+2FU3PawuhZiUHLXCW5khAX+Oueek"#015#012'
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: sl [sl.c:296]: send_reply():
reply in stateless mode (sl)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core>
[msg_translator.c:206]: check_via_address(): check_via_address(192.168.254.12,
192.168.254.12, 0)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [usr_avp.c:643]:
destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [usr_avp.c:643]:
destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [usr_avp.c:643]:
destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [usr_avp.c:643]:
destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [usr_avp.c:643]:
destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [usr_avp.c:643]:
destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [xavp.c:448]:
xavp_destroy_list(): destroying xavp list (nil)
Apr 22 08:20:28 host-sipr /usr/sbin/kamailio[26616]: DEBUG: <core> [receive.c:298]:
receive_msg(): receive_msg: cleaning up
After this last line, I’ve got, these lines, constantly repeated :
Apr 22 08:22:20 host-sipr /usr/sbin/kamailio[26617]: DEBUG: <core> [db_res.c:118]:
db_new_result(): allocate 56 bytes for result set at 0x7fc256a37298
Apr 22 08:22:20 host-sipr /usr/sbin/kamailio[26617]: DEBUG: db_postgres [km_dbase.c:509]:
db_postgres_store_result(): 0x7fc256a1be10 PQresultStatus(PGRES_COMMAND_OK)
PQgetResult(0x1d85300)
Apr 22 08:22:20 host-sipr /usr/sbin/kamailio[26617]: DEBUG: db_postgres [km_dbase.c:390]:
db_postgres_free_query(): PQclear(0x1d85300) result set
Apr 22 08:22:20 host-sipr /usr/sbin/kamailio[26617]: DEBUG: <core> [db_res.c:81]:
db_free_columns(): freeing 0 columns
Apr 22 08:22:20 host-sipr /usr/sbin/kamailio[26617]: DEBUG: <core> [db_res.c:136]:
db_free_result(): freeing result set at 0x7fc256a37298
Apr 22 08:23:20 host-sipr /usr/sbin/kamailio[26617]: DEBUG: db_postgres [km_dbase.c:230]:
db_postgres_submit_query(): sending query ok: 0x7fc256a1be10 (1) - [delete from location
where expires<'2015-04-22 08:23:21' AND expires!='1970-01-01
01:00:00']
Thanks again for your help,
Gab