Hi,
I have installed kamailio stable on Debian Wheezy from the repository, followed the main tutorial and pretty much everything looked like it was working at first. I can connect to my sip server but when I try to log in I keep getting a failed login.
In the mysql database I have the correct username and domain in the subscriber table. No typos there so then I enabled logging with debug=3 to check the logs but I am not sure how to interprete what I see.
It seems like there 2 two login procedures. The first one seems to fail, the second one seems to work since I see a "check_response: Authorization is OK" in there but still on Jitsi I keep getting told my password is incorrect. Here is the log dump of both login procedures from the same login attempt (I only tried to login once and as you see on the timestamp it all happens within the same second)
This is the first attempt where the realm is not found even though it is exactly the domain I have in the subscriber mysql table:
Oct 17 08:21:17 video /usr/sbin/kamailio[5170]: DEBUG: auth_db [authorize.c:486]: auth_check(): realm [video.mydomain.de] table [subscriber] flags [1] Oct 17 08:21:17 video /usr/sbin/kamailio[5170]: DEBUG: auth [api.c:86]: pre_auth(): auth:pre_auth: Credentials with realm 'video.mydomain.de' not found Oct 17 08:21:17 video /usr/sbin/kamailio[5170]: DEBUG: auth_db [authorize.c:252]: digest_authenticate_hdr(): no credentials Oct 17 08:21:17 video /usr/sbin/kamailio[5170]: DEBUG: auth [challenge.c:127]: get_challenge_hf(): build_challenge_hf: realm='video.mydomain.de' Oct 17 08:21:17 video /usr/sbin/kamailio[5170]: DEBUG: auth [challenge.c:269]: get_challenge_hf(): auth: 'WWW-Authenticate: Digest realm="video.mydomain.de", nonce="VEEK6VRBCb32GLPSTiKlfAo4loEn7BTY"#015#012' Oct 17 08:21:17 video /usr/sbin/kamailio[5170]: DEBUG: sl [sl.c:288]: send_reply(): reply in stateless mode (sl) Oct 17 08:21:17 video /usr/sbin/kamailio[5170]: DEBUG: <core> [msg_translator.c:204]: check_via_address(): check_via_address(79.212.239.151, 192.168.2.32, 0) Oct 17 08:21:17 video /usr/sbin/kamailio[5170]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list 0x7f2f830daa10
Then a second login attempt takes place where it looks different:
Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request: Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:625]: parse_msg(): method: <REGISTER> Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:627]: parse_msg(): uri: sip:video.mydomain.de:5188 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:629]: parse_msg(): version: <SIP/2.0> Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <2> <REGISTER> Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=10 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [46]; uri=[sip:oliver2@video.mydomain.de] Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body ["oliver2" sip:oliver2@video.mydomain.de#015#012] Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-383534-d21acd094f094ec7f76ca01734bb9c80>; state=16 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [receive.c:152]: receive_msg(): After parse_msg... Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [receive.c:193]: receive_msg(): preparing to run routing scripts... Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param: tag=f59174d Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=29 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: siputils [checks.c:103]: has_totag(): no totag Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=2 global id=1 T start=(nil) Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=60350, isACK=0 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failed Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg: msg id=2 global id=2 T end=(nil) Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: auth_db [authorize.c:486]: auth_check(): realm [video.mydomain.de] table [subscriber] flags [1] Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: auth [api.c:96]: pre_auth(): auth: digest-algo: parsed value: 0 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:118]: db_new_result(): allocate 56 bytes for result set at 0x7f2f8d09c040 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: db_mysql [km_res.c:68]: db_mysql_get_columns(): 1 columns returned from the query Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:155]: db_allocate_columns(): allocate 8 bytes for result names at 0x7f2f8d09c148 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 4 bytes for result types at 0x7f2f8d09c0d8 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: db_mysql [km_res.c:86]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7f2f8d0aa448 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: db_mysql [km_res.c:93]: db_mysql_get_columns(): RES_NAMES(0x7f2f8d0aa448)[0]=[password] Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: db_mysql [km_res.c:137]: db_mysql_get_columns(): use DB1_STRING result type Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:184]: db_allocate_rows(): allocate 16 bytes for rows at 0x7f2f8d09c288 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_row.c:119]: db_allocate_row(): allocate 32 bytes for row values at 0x7f2f8d09e480 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_val.c:117]: db_str2val(): converting STRING [xxxxxxx] Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: auth_db [authorize.c:196]: get_ha1(): HA1 string calculated: a4fe9f8e75b2cb7b19da2cbc37b33bcc Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: auth [api.c:211]: auth_check_response(): check_response: Our result = '1aab3cbf895ec5c2491135a0a6869f4e' Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: auth [api.c:218]: auth_check_response(): check_response: Authorization is OK Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:81]: db_free_columns(): freeing 1 columns Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:85]: db_free_columns(): freeing RES_NAMES[0] at 0x7f2f8d0aa448 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:94]: db_free_columns(): freeing result names at 0x7f2f8d09c148 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:99]: db_free_columns(): freeing result types at 0x7f2f8d09c0d8 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:54]: db_free_rows(): freeing 1 rows Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_row.c:97]: db_free_row(): freeing row values at 0x7f2f8d09e480 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:62]: db_free_rows(): freeing rows at 0x7f2f8d09c288 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [db_res.c:136]: db_free_result(): freeing result set at 0x7f2f8d09c040 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: auth [challenge.c:127]: get_challenge_hf(): build_challenge_hf: realm='video.mydomain.de' Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: auth [challenge.c:269]: get_challenge_hf(): auth: 'WWW-Authenticate: Digest realm="video.mydomain.de", nonce="VEEK6VRBCb32GLPSTiKlfAo4loEn7BTY"#015#012' Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: sl [sl.c:288]: send_reply(): reply in stateless mode (sl) Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [msg_translator.c:204]: check_via_address(): check_via_address(79.212.239.151, 192.168.2.32, 0) Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list 0x7f2f830daa10 Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil) Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil) Oct 17 08:21:17 video /usr/sbin/kamailio[5172]: DEBUG: <core> [receive.c:296]: receive_msg(): receive_msg: cleaning up
Any help on what I did wrong is appreciated... Best regards Oliver