Discussion:
[SR-Users] Auth problem with Jitsi on current kamailio stable
flow27-e/dTfH9dK1RSkp3S+
2014-10-17 12:57:27 UTC
Permalink
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-***@public.gmane.org]
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-***@public.gmane.org>#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

Loading...