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