May 29 14:05:13 cacofonix /sbin/kamailio[7885]: DBG:core:db_do_init: connection 0x67b6b0 found in pool
May 29 14:05:13 cacofonix /sbin/kamailio[7897]: DBG:core:db_do_init: connection 0x67b6b0 found in pool
May 29 14:05:13 cacofonix /sbin/kamailio[7895]: DBG:core:init_mod_child: type=CHILD, rank=10, module=alias_db
May 29 14:05:13 cacofonix /sbin/kamailio[7885]: DBG:core:init_mod_child: type=CHILD, rank=5, module=domain
May 29 14:05:13 cacofonix /sbin/kamailio[7897]: DBG:core:init_mod_child: type=CHILD, rank=12, module=domain
May 29 14:05:13 cacofonix /sbin/kamailio[7895]: DBG:core:db_do_init: connection 0x67b6b0 found in pool
May 29 14:05:13 cacofonix /sbin/kamailio[7895]: DBG:core:init_mod_child: type=CHILD, rank=10, module=domain
May 29 14:05:13 cacofonix /sbin/kamailio[7897]: DBG:core:io_watch_add: io_watch_add(0x62d760, 26, 1, (nil)), fd_no=0
May 29 14:05:13 cacofonix /sbin/kamailio[7895]: DBG:core:io_watch_add: io_watch_add(0x62d760, 22, 1, (nil)), fd_no=0
May 29 14:05:15 cacofonix /sbin/kamailio[7886]: DBG:core:udp_rcv_loop: probing packet received from 10.10.10.2 50195
May 29 14:05:23 cacofonix /sbin/kamailio[7887]: DBG:core:udp_rcv_loop: probing packet received from 10.10.10.3 50195
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:udp_rcv_loop: probing packet received from 10.10.10.2 50195
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_msg: SIP Request:
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_msg:  method:  <INVITE>
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_msg:  uri:     <sip:2109558353@10.10.10.1>
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_msg:  version: <SIP/2.0>
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: flags=2
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK922E579CA9FE416C85D258AA48A53F66>; state=16
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_via: end of header reached, state=5
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: via found, flags=2
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: this is the first via
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:receive_msg: After parse_msg...
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:receive_msg: preparing to run routing scripts...
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: flags=100
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_to: end of header reached, state=10
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_to: display={}, ruri={sip:2109558353@10.10.10.1}
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:get_hdr_field: <To> [30]; uri=[sip:2109558353@10.10.10.1] 
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:get_hdr_field: to body [<sip:2109558353@10.10.10.1>  ]
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:get_hdr_field: cseq <CSeq>: <40369> <INVITE>
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:maxfwd:is_maxfwd_present: value = 70 
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: flags=200
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:get_hdr_field: content_length=200
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:get_hdr_field: found end of header
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:rr:find_first_route: No Route headers found
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:rr:loose_route: There is no Route HF
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_to_param: tag=4019420419
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_to: end of header reached, state=29
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_to: display={1000}, ruri={sip:1000@10.10.10.1}
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: flags=10000
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:auth:pre_auth: credentials with given realm not found
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:auth:reserve_nonce_index: second= 12, sec_monit= -1,  index= 0
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:auth:build_auth_hf: nonce index= 0
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest realm="10.10.10.1", nonce="4a1fc2a20000000068765cb99b6b87c240bf07ca3cd82c2b", qop="auth"  '
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: flags=ffffffffffffffff
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:check_via_address: params 10.10.10.2, 10.10.10.2, 0
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:destroy_avp_list: destroying list (nil)
May 29 14:05:26 cacofonix /sbin/kamailio[7885]: DBG:core:receive_msg: cleaning up
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_msg: SIP Request:
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_msg:  method:  <ACK>
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_msg:  uri:     <sip:2109558353@10.10.10.1>
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_msg:  version: <SIP/2.0>
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: flags=2
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_msg: SIP Request:
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_msg:  method:  <INVITE>
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_msg:  uri:     <sip:2109558353@10.10.10.1>
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_msg:  version: <SIP/2.0>
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_headers: flags=2
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKFDFB9856E9FA4AF3B3FC0E502BF03396>; state=16
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_via: end of header reached, state=5
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_headers: via found, flags=2
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_headers: this is the first via
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:receive_msg: After parse_msg...
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:receive_msg: preparing to run routing scripts...
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_headers: flags=100
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_to: end of header reached, state=10
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_to: display={}, ruri={sip:2109558353@10.10.10.1}
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:get_hdr_field: <To> [30]; uri=[sip:2109558353@10.10.10.1] 
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:get_hdr_field: to body [<sip:2109558353@10.10.10.1>  ]
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:get_hdr_field: cseq <CSeq>: <40370> <INVITE>
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:maxfwd:is_maxfwd_present: value = 70 
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_headers: flags=200
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:get_hdr_field: content_length=200
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:get_hdr_field: found end of header
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:rr:find_first_route: No Route headers found
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:rr:loose_route: There is no Route HF
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_to_param: tag=4019420419
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_to: end of header reached, state=29
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_to: display={1000}, ruri={sip:1000@10.10.10.1}
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:auth:check_nonce: comparing [4a1fc2a20000000068765cb99b6b87c240bf07ca3cd82c2b] and [4a1fc2a20000000068765cb99b6b87c240bf07ca3cd82c2b]
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK922E579CA9FE416C85D258AA48A53F66>; state=16
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_via: end of header reached, state=5
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: via found, flags=2
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: this is the first via
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:receive_msg: After parse_msg...
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:receive_msg: preparing to run routing scripts...
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: flags=8
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_to_param: tag=f8f2ab2c1295e90ed7dbb499b30f44b2.acab
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_to: end of header reached, state=29
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:parse_to: display={}, ruri={sip:2109558353@10.10.10.1}
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:get_hdr_field: <To> [72]; uri=[sip:2109558353@10.10.10.1] 
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:get_hdr_field: to body [<sip:2109558353@10.10.10.1>]
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:sl:sl_filter_ACK: local ACK found -> dropping it!
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_new_result: allocate 48 bytes for result set at 0x67e9e0
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:db_mysql:db_mysql_get_columns: 1 columns returned from the query
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_allocate_columns: allocate 8 bytes for result names at 0x67ea20
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_allocate_columns: allocate 4 bytes for result types at 0x67ea38
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:db_mysql:db_mysql_get_columns: allocate 16 bytes for RES_NAMES[0] at 0x67ea50
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:destroy_avp_list: destroying list (nil)
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x67ea50)[0]=[password]
May 29 14:05:26 cacofonix /sbin/kamailio[7887]: DBG:core:receive_msg: cleaning up
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:db_mysql:db_mysql_convert_rows: allocate 16 bytes for rows at 0x67ea70
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:db_mysql:db_mysql_convert_row: allocate 32 bytes for row values at 0x67ea90
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:db_mysql:db_mysql_str2val: converting STRING [1234]
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:auth_db:get_ha1: HA1 string calculated: b58b19cd7ec8f67671261ace34df3352
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:auth:check_response: our result = 'b6844cdf0cd709b959844e75aa3d206e'
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:auth:check_response: authorization is OK
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:auth:post_auth: nonce index= 0
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_free_columns: freeing 1 columns
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_free_columns: freeing RES_NAMES[0] at 0x67ea50
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_free_columns: freeing result names at 0x67ea20
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_free_columns: freeing result types at 0x67ea38
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_free_rows: freeing 1 rows
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_free_row: freeing row values at 0x67ea90
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_free_rows: freeing rows at 0x67ea70
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:db_free_result: freeing result set at 0x67e9e0
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:uri_db:check_username: Digest username and URI username match
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:registrar:lookup: '2109558353' Not found in usrloc
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_headers: flags=ffffffffffffffff
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_headers: flags=ffffffffffffffff
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:registrar:lookup: '2109558353' Not found in usrloc
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:parse_headers: flags=ffffffffffffffff
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:check_via_address: params 10.10.10.2, 10.10.10.2, 0
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:destroy_avp_list: destroying list (nil)
May 29 14:05:26 cacofonix /sbin/kamailio[7888]: DBG:core:receive_msg: cleaning up
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_msg: SIP Request:
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_msg:  method:  <ACK>
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_msg:  uri:     <sip:2109558353@10.10.10.1>
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_msg:  version: <SIP/2.0>
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_headers: flags=2
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKFDFB9856E9FA4AF3B3FC0E502BF03396>; state=16
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_via: end of header reached, state=5
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_headers: via found, flags=2
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_headers: this is the first via
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:receive_msg: After parse_msg...
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:receive_msg: preparing to run routing scripts...
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_headers: flags=8
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_to_param: tag=f8f2ab2c1295e90ed7dbb499b30f44b2.4410
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_to: end of header reached, state=29
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:parse_to: display={}, ruri={sip:2109558353@10.10.10.1}
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:get_hdr_field: <To> [72]; uri=[sip:2109558353@10.10.10.1] 
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:get_hdr_field: to body [<sip:2109558353@10.10.10.1>]
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:sl:sl_filter_ACK: local ACK found -> dropping it!
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:destroy_avp_list: destroying list (nil)
May 29 14:05:26 cacofonix /sbin/kamailio[7886]: DBG:core:receive_msg: cleaning up
May 29 14:05:33 cacofonix /sbin/kamailio[7887]: DBG:core:udp_rcv_loop: probing packet received from 10.10.10.3 50195
May 29 14:05:36 cacofonix /sbin/kamailio[7888]: DBG:core:udp_rcv_loop: probing packet received from 10.10.10.2 50195
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_msg: SIP Request:
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_msg:  method:  <REGISTER>
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_msg:  uri:     <sip:10.10.10.1>
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_msg:  version: <SIP/2.0>
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: flags=2
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK2F79CABEA0A7425C85C5A73A6CFC20D9>; state=16
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_via: end of header reached, state=5
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: via found, flags=2
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: this is the first via
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:receive_msg: After parse_msg...
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:receive_msg: preparing to run routing scripts...
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: flags=100
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_to: end of header reached, state=10
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_to: display={1000}, ruri={sip:1000@10.10.10.1}
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:get_hdr_field: <To> [29]; uri=[sip:1000@10.10.10.1] 
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:get_hdr_field: to body [1000 <sip:1000@10.10.10.1>  ]
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:get_hdr_field: cseq <CSeq>: <52298> <REGISTER>
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:maxfwd:is_maxfwd_present: value = 70 
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: flags=200
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:get_hdr_field: content_length=0
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:get_hdr_field: found end of header
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:rr:find_first_route: No Route headers found
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:rr:loose_route: There is no Route HF
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: flags=4000
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:auth:pre_auth: credentials with given realm not found
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:auth:reserve_nonce_index: second= 26, sec_monit= -1,  index= 1
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:auth:build_auth_hf: nonce index= 1
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:auth:build_auth_hf: 'WWW-Authenticate: Digest realm="cacofonix.egreta.gr", nonce="4a1fc2b000000001a3e397db4e141e53da30ad0696760da3", qop="auth"  '
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:parse_headers: flags=ffffffffffffffff
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:check_via_address: params 10.10.10.2, 10.10.10.2, 0
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:destroy_avp_list: destroying list (nil)
May 29 14:05:40 cacofonix /sbin/kamailio[7885]: DBG:core:receive_msg: cleaning up
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_msg: SIP Request:
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_msg:  method:  <REGISTER>
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_msg:  uri:     <sip:10.10.10.1>
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_msg:  version: <SIP/2.0>
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: flags=2
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK0C47C5EB2E1247FEA747BFFB4FD915A8>; state=16
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_via: end of header reached, state=5
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: via found, flags=2
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: this is the first via
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:receive_msg: After parse_msg...
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:receive_msg: preparing to run routing scripts...
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: flags=100
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_to: end of header reached, state=10
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_to: display={1000}, ruri={sip:1000@10.10.10.1}
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:get_hdr_field: <To> [29]; uri=[sip:1000@10.10.10.1] 
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:get_hdr_field: to body [1000 <sip:1000@10.10.10.1>  ]
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:get_hdr_field: cseq <CSeq>: <52299> <REGISTER>
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:maxfwd:is_maxfwd_present: value = 70 
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: flags=200
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:get_hdr_field: content_length=0
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:get_hdr_field: found end of header
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:rr:find_first_route: No Route headers found
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:rr:loose_route: There is no Route HF
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:auth:check_nonce: comparing [4a1fc2b000000001a3e397db4e141e53da30ad0696760da3] and [4a1fc2b000000001a3e397db4e141e53da30ad0696760da3]
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_new_result: allocate 48 bytes for result set at 0x67d960
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:db_mysql:db_mysql_get_columns: 1 columns returned from the query
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_allocate_columns: allocate 8 bytes for result names at 0x67da90
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_allocate_columns: allocate 4 bytes for result types at 0x67daa8
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:db_mysql:db_mysql_get_columns: allocate 16 bytes for RES_NAMES[0] at 0x67dac0
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x67dac0)[0]=[password]
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:db_mysql:db_mysql_convert_rows: allocate 16 bytes for rows at 0x67dae0
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:db_mysql:db_mysql_convert_row: allocate 32 bytes for row values at 0x67db00
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:db_mysql:db_mysql_str2val: converting STRING [1234]
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:auth_db:get_ha1: HA1 string calculated: 90c30e48e987fd2d0ae77d90094407a5
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:auth:check_response: our result = 'd5513fb342bbfd2d4090a9ebcc4038fe'
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:auth:check_response: authorization is OK
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:auth:post_auth: nonce index= 1
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_free_columns: freeing 1 columns
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_free_columns: freeing RES_NAMES[0] at 0x67dac0
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_free_columns: freeing result names at 0x67da90
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_free_columns: freeing result types at 0x67daa8
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_free_rows: freeing 1 rows
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_free_row: freeing row values at 0x67db00
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_free_rows: freeing rows at 0x67dae0
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:db_free_result: freeing result set at 0x67d960
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:uri_db:check_username: Digest username and URI username match
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: flags=ffffffffffffffff
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: flags=8000000
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:parse_headers: flags=ffffffffffffffff
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:check_via_address: params 10.10.10.2, 10.10.10.2, 0
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:destroy_avp_list: destroying list (nil)
May 29 14:05:40 cacofonix /sbin/kamailio[7887]: DBG:core:receive_msg: cleaning up
May 29 14:05:44 cacofonix /sbin/kamailio[7885]: DBG:core:udp_rcv_loop: probing packet received from 10.10.10.3 50195






# -------------------------  request routing logic -------------------

# main routing logic

route{

        # initial sanity checks -- messages with
        # max_forwards==0, or excessively long requests
        if (!mf_process_maxfwd_header("10")) {
                sl_send_reply("483","Too Many Hops");
                exit;
        };

        if (msg:len >=  2048 ) {
                sl_send_reply("513", "Message too big");
                exit;
        };

        # we record-route all messages -- to make sure that
        # subsequent messages will go through our proxy; that's
        # particularly good if upstream and downstream entities
        # use different transport protocol
        if (!method=="REGISTER")
                record_route();

        # subsequent messages withing a dialog should take the
        # path determined by record-routing
        if (loose_route()) {
                # mark routing logic in request
                append_hf("P-hint: rr-enforced\r\n"); 
                route(1);
        };

        #CANCEL processing
        if (is_method("CANCEL")) {
                if (t_check_trans()) t_relay();
                exit;
        }
        if (method=="REGISTER") {
                route(2);
        } else {
                route(3);
        };
}

route[1] {
        # send it out now; use stateful forwarding as it works
        # reliably even for UDP2TCP
        if (!t_relay()) {
                sl_reply_error();
        };
        exit;
}

route[2] {
        #
        # -- Register request handler --
        #
        if (is_uri_host_local()) {
                if (!www_authorize("", "subscriber")) {
                        www_challenge("", "1");
                        exit;
                };
                if (!check_to()) {
                        sl_send_reply("401", "Unauthorized");
                        exit;
                };
                save("location");
                exit;
        } else if {
                sl_send_reply("401", "Unauthorized");
        };
}

route[3] {
        #
        # -- non-register requests handler --
        #
        # Verify the source (FROM)
        if (is_from_local()){
        # From an internal domain -> check the credentials and the FROM
                if (!proxy_authorize("","subscriber")) {
                        proxy_challenge("","1");
                        exit;
                } else if (!check_from()) {
                        sl_send_reply("403", "Forbidden, use From=ID");
                        exit;
                };
                consume_credentials();
                # Verify aliases
                lookup("aliases");
                # Verify the destination (URI)
                if (is_uri_host_local()) {
                        # -- Inbound to Inbound
                        route(10);
                } else {
                        # -- Inbound to outbound
                        route(11);
                };
        } else {
                #Verify aliases, if found replace R-URI.
                lookup("aliases");
                # Verify the destination (URI)
                if (is_uri_host_local()) {
                        #-- Outbound to inbound
                                route(12);
                } else {
                        # -- Outbound to outbound
                        route(13);
                };
        };
}

route[4] {
        # routing to the public network
        if (!load_gws()) {
                sl_send_reply("503", "Unable to load gateways");
                exit;
        }
        if(!next_gw()){
                sl_send_reply("503", "Unable to find a gateway");
                exit;
        }
        route(1);
        exit;
}

route[10] {
        append_hf("P-hint: inbound->inbound \r\n");
        if (uri=~"^sip:[0-9]*@") {
                if (is_user_in("credentials","outgoing")) {
                        route(4);
                        exit;
                } else {
                        sl_send_reply("403", "No permissions for outgoing calls");
                        exit;
                };
        };

        #Native SIP destinations are handled using the location table
        append_hf("P-hint: inbound->inbound \r\n");
        if (!lookup("location")) {
                sl_send_reply("404", "Not Found  this is where the outgoing call fails"); 
                exit;
        };
        route(1);
}

route[11] {
        # from an internal domain -> outbound
        # Simply route the call outbound using DNS search
        append_hf("P-hint: inbound->outbound \r\n");
        route(1);
}

route[12] {
        # From an external domain -> inbound
        # Verify aliases, if found replace R-URI.
        lookup("aliases");
        if (!lookup("location")) {
                sl_send_reply("404", "Not Found");
                exit;
        };
        route(1);
}

route[13] {
        #From an external domain outbound
        #we are not accepting these calls
        sl_send_reply("403", "Forbidden");
        exit;
}

failure_route[1] {
        if(!next_gw()) {
                t_reply("503", "Service not available, no more gateways");
                exit;
        }
        t_on_failure("1");
        t_relay();
}


................

U 10.10.10.2:5060 -> 10.10.10.1:5060
INVITE sip:2109558353@10.10.10.1 SIP/2.0.
Via: SIP/2.0/UDP 10.10.10.2:5060;rport;branch=z9hG4bK9A6FB317EAAA49239A329B7EED195972.
From: 1000 <sip:1000@10.10.10.1>;tag=2003109495.
To: <sip:2109558353@10.10.10.1>.
Contact: <sip:1000@10.10.10.2:5060>.
Call-ID: A51A866B-8E4A-463F-BAB5-9689225763BC@10.10.10.2.
CSeq: 35975 INVITE.
Max-Forwards: 70.
Content-Type: application/sdp.
User-Agent: X-PRO build 1082.
Content-Length: 200.
.
v=0.
o=1000 333892515 333892515 IN IP4 10.10.10.2.
s=X-PRO.
c=IN IP4 10.10.10.2.
t=0 0.
m=audio 8000 RTP/AVP 18 101.
a=rtpmap:18 G729/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.

U 10.10.10.1:5060 -> 10.10.10.2:5060
SIP/2.0 407 Proxy Authentication Required.
Via: SIP/2.0/UDP 10.10.10.2:5060;rport=5060;branch=z9hG4bK9A6FB317EAAA49239A329B7EED195972.
From: 1000 <sip:1000@10.10.10.1>;tag=2003109495.
To: <sip:2109558353@10.10.10.1>;tag=f8f2ab2c1295e90ed7dbb499b30f44b2.6e0d.
Call-ID: A51A866B-8E4A-463F-BAB5-9689225763BC@10.10.10.2.
CSeq: 35975 INVITE.
Proxy-Authenticate: Digest realm="10.10.10.1", nonce="4a1fc1fd0000000202d4f6f3c38c36ea4e9c7cf0e0e56c6f", qop="auth".
Server: Kamailio (1.4.1-notls (x86_64/linux)).
Content-Length: 0.
.

U 10.10.10.2:5060 -> 10.10.10.1:5060
ACK sip:2109558353@10.10.10.1 SIP/2.0.
Via: SIP/2.0/UDP 10.10.10.2:5060;rport;branch=z9hG4bK9A6FB317EAAA49239A329B7EED195972.
From: 1000 <sip:1000@10.10.10.1>;tag=2003109495.
To: <sip:2109558353@10.10.10.1>;tag=f8f2ab2c1295e90ed7dbb499b30f44b2.6e0d.
Contact: <sip:1000@10.10.10.2:5060>.
Call-ID: A51A866B-8E4A-463F-BAB5-9689225763BC@10.10.10.2.
CSeq: 35975 ACK.
Max-Forwards: 70.
Content-Length: 0.
.

U 10.10.10.2:5060 -> 10.10.10.1:5060
INVITE sip:2109558353@10.10.10.1 SIP/2.0.
Via: SIP/2.0/UDP 10.10.10.2:5060;rport;branch=z9hG4bK5E772D41ECAE40B1BCAD721D20050C3C.
From: 1000 <sip:1000@10.10.10.1>;tag=2003109495.
To: <sip:2109558353@10.10.10.1>.
Contact: <sip:1000@10.10.10.2:5060>.
Call-ID: A51A866B-8E4A-463F-BAB5-9689225763BC@10.10.10.2.
CSeq: 35976 INVITE.
Proxy-Authorization: Digest username="1000",realm="10.10.10.1",nonce="4a1fc1fd0000000202d4f6f3c38c36ea4e9c7cf0e0e56c6f",response="d
e87516ac763a1a2d81f8dfe15fea346",uri="sip:2109558353@10.10.10.1",qop=auth,cnonce="98BAD5C268804AE49A8C47628C1416C3",nc="0000032c".
Max-Forwards: 70.
Content-Type: application/sdp.
User-Agent: X-PRO build 1082.
Content-Length: 200.
.
v=0.
o=1000 333892515 333892515 IN IP4 10.10.10.2.
s=X-PRO.
c=IN IP4 10.10.10.2.
t=0 0.
m=audio 8000 RTP/AVP 18 101.
a=rtpmap:18 G729/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-15.

U 10.10.10.1:5060 -> 10.10.10.2:5060
SIP/2.0 404 Not Found.
Via: SIP/2.0/UDP 10.10.10.2:5060;rport=5060;branch=z9hG4bK5E772D41ECAE40B1BCAD721D20050C3C.
From: 1000 <sip:1000@10.10.10.1>;tag=2003109495.
To: <sip:2109558353@10.10.10.1>;tag=f8f2ab2c1295e90ed7dbb499b30f44b2.6141.
Call-ID: A51A866B-8E4A-463F-BAB5-9689225763BC@10.10.10.2.
CSeq: 35976 INVITE.
Server: Kamailio (1.4.1-notls (x86_64/linux)).
Content-Length: 0.
.

U 10.10.10.2:5060 -> 10.10.10.1:5060
ACK sip:2109558353@10.10.10.1 SIP/2.0.
Via: SIP/2.0/UDP 10.10.10.2:5060;rport;branch=z9hG4bK5E772D41ECAE40B1BCAD721D20050C3C.
From: 1000 <sip:1000@10.10.10.1>;tag=2003109495.
To: <sip:2109558353@10.10.10.1>;tag=f8f2ab2c1295e90ed7dbb499b30f44b2.6141.
Contact: <sip:1000@10.10.10.2:5060>.
Call-ID: A51A866B-8E4A-463F-BAB5-9689225763BC@10.10.10.2.
CSeq: 35976 ACK.
Max-Forwards: 70.
Content-Length: 0.
.

U 10.10.10.2:5060 -> 10.10.10.1:5060
.
................