[SR-Users] Kamailio 3.3 presence with resource lists and integrated XCAP
Sangeeta Shah
sangeeta.shah at gmail.com
Fri Sep 28 23:39:08 CEST 2012
Hello All,
I am trying to configure Kamailio v 3.3 to serve as a presence
server with resource lists and integrated XCAP.
I followed the respective module documentation and am trying to test
with the Boghe IMS client. I just can't get it to work!
I think I still don't have everything I need in the config file to
handle the xcap documents. Attached is the debug log from the server.
If someone has had luck setting up the presence server with integrated
xcap and resource lists please take a few minutes to take a look at
the log file and see if you can help me out. I am also posting the
xcap portion of the config file:
#!ifdef WITH_XCAPSRV
##!define WITH_XHTTPAUTH
event_route[xhttp:request] {
xdbg("===== xhttp: request [$rv] $rm => $hu\n");
#!ifdef WITH_XHTTPAUTH
if (!www_authorize("10.50.251.12", "subscriber"))
{
www_challenge("10.50.251.12", "0");
exit;
}
#!endif
if($hu=~"^/xcap-root/")
{
set_reply_close();
set_reply_no_connect();
# xcap ops
$xcapuri(u=>data) = $hu;
if($xcapuri(u=>xuid)=~"^sip:.+ at .+")
$var(uri) = $xcapuri(u=>xuid);
else if($xcapuri(u=>xuid)=~".+ at .+")
$var(uri) = "sip:" + $xcapuri(u=>xuid);
else
$var(uri) = "sip:"+ $xcapuri(u=>xuid) + "@" + $Ri;
xlog("===== xhttp: $xcapuri(u=>auid) : $xcapuri(u=>xuid)\n");
if($xcapuri(u=>auid)=="xcap-caps")
{
$var(xbody) =
"<?xml version='1.0' encoding='UTF-8'?>
<xcap-caps xmlns='urn:ietf:params:xml:ns:xcap-caps'>
<auids>
<auid>rls-services</auid>
<auid>pidf-manipulation</auid>
<auid>xcap-caps</auid>
<auid>pres-rules</auid>
</auids>
<extensions>
</extensions>
<namespaces>
<namespace>urn:ietf:params:xml:ns:rls-services</namespace>
<namespace>urn:ietf:params:xml:ns:pidf</namespace>
<namespace>urn:ietf:params:xml:ns:xcap-caps</namespace>
<namespace>urn:ietf:params:xml:ns:pres-rules</namespace>
</namespaces>
</xcap-caps>";
xhttp_reply("200", "ok", "application/xcap-caps+xml",
"$var(xbody)");
exit;
}
#!ifdef WITH_XHTTPAUTH
# be sure auth user access only its documents
if ($au!=$(var(uri){uri.user})) {
xhttp_reply("403", "Forbidden", "text/html",
"<html><body>$si:$sp</body></html>");
exit;
}
#!endif
switch($rm) {
case "PUT":
#xcaps_put("$var(uri)", "$hu", "$rb");
#if($xcapuri(u=>auid)=~"pres-rules")
#{
# xlog("===== xhttp put:
refreshing watchers for $var(uri)\n");
#
pres_update_watchers("$var(uri)", "presence");
#
pres_refresh_watchers("$var(uri)", "presence", 1);
#}
xcaps_put("$var(uri)", "$var(doc_uri)", "$rb");
if($xcapuri(u=>auid)=~"pres-rules") {
pres_update_watchers("$var(uri)", "presence");
pres_refresh_watchers("$var(uri)", "presence", 1);
} else if ($xcapuri(u=>auid)=~"resource-lists"
|| $xcapuri(u=>auid)=~"rls-services") {
rls_update_subs("$var(uri)",
"presence");
}
exit;
break;
case "GET":
xlog("===== xhttp: get $var(uri) => $hu\n");
xcaps_get("$var(uri)", "$hu");
exit;
break;
case "DELETE":
xcaps_del("$var(uri)", "$hu");
if($xcapuri(u=>auid)=~"pres-rules")
{
xlog("===== xhttp del:
refreshing watchers for $var(uri)\n");
pres_update_watchers("$var(uri)", "presence");
pres_refresh_watchers("$var(uri)", "presence", 1);
}
exit;
break;
}
}
# http ops
xhttp_reply("200", "ok", "text/html",
"<html><body>OK:
$si:$sp</body></html>");
exit;
}
--
Sangeeta Shah
-------------- next part --------------
Sep 28 16:25:50 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:81]: freeing 6 columns
Sep 28 16:25:50 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7f2d6288bf88
Sep 28 16:25:50 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[1] at 0x7f2d6288bfa8
Sep 28 16:25:50 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[2] at 0x7f2d6288bfc8
Sep 28 16:25:50 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[3] at 0x7f2d6288bfe8
Sep 28 16:25:50 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[4] at 0x7f2d6288c008
Sep 28 16:25:50 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[5] at 0x7f2d6288c028
Sep 28 16:25:50 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:94]: freeing result names at 0x7f2d6288bf20
Sep 28 16:25:50 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:99]: freeing result types at 0x7f2d6288bf60
Sep 28 16:25:50 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:136]: freeing result set at 0x7f2d6288bee0
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [subscribe.c:2156]: db_update timer
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [subscribe.c:1879]: update_db_subs_timer: start
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:117]: pres_uri: sip:8475551001 at 10.50.251.12
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:118]: watcher_user at watcher_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:119]: to_user at to_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:120]: from_user at from_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:121]: callid/from_tag/to_tag: 97486333-eaaa-cacf-ad9a-41002672a3cf/26643342/a6a1c5f60faecf035a1ae5b6e96e979a-2e33
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:122]: local_cseq/remote_cseq: 1/32394
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:123]: local_contact/contact: sip:10.50.251.12:5060;transport=tcp/sip:8475551001 at 10.51.2.181:55786;transport=tcp
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:124]: record_route:
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:125]: sockinfo_str: tcp:10.50.251.12:5060
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:127]: event: presence.winfo
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:128]: status: active
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:129]: reason:
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:130]: version: 1
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:131]: expires: 1348870763
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:133]: updated/updated_winfo: 0/0
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [subscribe.c:2068]: NO_UPDATEDB_FLAG
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:117]: pres_uri: sip:8475551001 at 10.50.251.12
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:118]: watcher_user at watcher_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:119]: to_user at to_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:120]: from_user at from_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:121]: callid/from_tag/to_tag: 35335218-fbe9-c8d8-f2dd-776633e29a2e/23773268/a6a1c5f60faecf035a1ae5b6e96e979a-1c90
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:122]: local_cseq/remote_cseq: 1/32394
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:123]: local_contact/contact: sip:10.50.251.12:5060;transport=tcp/sip:8475551001 at 10.51.2.181:51378;transport=tcp
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:124]: record_route:
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:125]: sockinfo_str: tcp:10.50.251.12:5060
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:127]: event: presence.winfo
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:128]: status: active
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:129]: reason:
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:130]: version: 1
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:131]: expires: 1348867894
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [notify.c:133]: updated/updated_winfo: 0/0
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: presence [subscribe.c:2068]: NO_UPDATEDB_FLAG
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:118]: allocate 48 bytes for result set at 0x7f2d6288bee0
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:68]: 6 columns returned from the query
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:155]: allocate 48 bytes for result names at 0x7f2d6288bf20
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:165]: allocate 24 bytes for result types at 0x7f2d6288bf60
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[0] at 0x7f2d6288c028
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288c028)[0]=[rlsubs_did]
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[1] at 0x7f2d6288c008
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288c008)[1]=[resource_uri]
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[2] at 0x7f2d6288bfe8
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288bfe8)[2]=[auth_state]
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:100]: use DB1_INT result type
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[3] at 0x7f2d6288bfc8
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288bfc8)[3]=[content_type]
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[4] at 0x7f2d6288bfa8
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288bfa8)[4]=[reason]
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[5] at 0x7f2d6288bf88
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288bf88)[5]=[presence_state]
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:121]: use DB1_BLOB result type
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:169]: no rows returned from the query
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:81]: freeing 6 columns
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7f2d6288c028
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[1] at 0x7f2d6288c008
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[2] at 0x7f2d6288bfe8
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[3] at 0x7f2d6288bfc8
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[4] at 0x7f2d6288bfa8
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[5] at 0x7f2d6288bf88
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:94]: freeing result names at 0x7f2d6288bf20
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:99]: freeing result types at 0x7f2d6288bf60
Sep 28 16:25:55 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:136]: freeing result set at 0x7f2d6288bee0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [ip_addr.c:247]: tcpconn_new: new tcp connection: 10.51.2.181
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:1089]: tcpconn_new: on port 56299, type 2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:1400]: tcpconn_add: hashes: 1796:1307:1784, 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x82cec0, 31, 2, 0x7f2d5c57bf38), fd_no=22
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x82cec0, 31, -1, 0x0) fd_no=23 called
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:4295]: tcp: DBG: sending to child, events 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:3966]: selected tcp worker 0 13(26660) for activity on [tcp:10.50.251.12:5060], 0x7f2d5c57bf38
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_read.c:1354]: received n=8 con=0x7f2d5c57bf38, fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_read.c:1164]: tcp_read_req: content-length= 0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:626]: method: <REGISTER>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:628]: uri: <sip:10.50.251.12>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK27058680>; state=6
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=17
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [31]; uri=[sip:8475551001 at 10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body [<sip:8475551001 at 10.50.251.12>#015#012]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <1704> <REGISTER>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=27060041
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: siputils [checks.c:103]: no totag
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=1 global id=0 T start=0xffffffffffffffff
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=55839, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=1 global id=1 T end=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:306]: realm value [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:96]: auth: digest-algo: parsed value: 0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:148]: auth:pre_auth: Invalid nonce value received
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:197]: not authenticated
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [challenge.c:128]: build_challenge_hf: realm='10.50.251.12'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [challenge.c:270]: auth: 'WWW-Authenticate: Digest realm="10.50.251.12", nonce="UGYXEFBmFeSDjhouEq7B8iHXS4K7qz9r"#015#012'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sl [sl.c:278]: reply in stateless mode (sl)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26660 (13)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57bf38 n=443 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012SIP/2.0 401 Unauthorized#015#012Via: SIP/2.0/TCP 10.51.2.181:56299;branch=z9hG4bK27058680;rport=56299#015#012From: <sip:8475551001 at 10.50.251.12>;tag=27060041#015#012To: <sip:8475551001 at 10.50.251.12>;tag=b27e1a1d33761e85846fc98f5f3a7e58.ba2e#015#012Call-ID: 0301a9cc-2376-1a27-00b0-320108825461#015#012CSeq: 1704 REGISTER#015#012WWW-Authenticate: Digest realm="10.50.251.12", nonce="UGYXEFBmFeSDjhouEq7B8iHXS4K7qz9r"#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 0#015#012#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x871120, 11, 2, 0x7f2d5c57bf38), fd_no=1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_read.c:1164]: tcp_read_req: content-length= 0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:626]: method: <REGISTER>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:628]: uri: <sip:10.50.251.12>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK27041239>; state=6
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=17
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [31]; uri=[sip:8475551001 at 10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body [<sip:8475551001 at 10.50.251.12>#015#012]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <1705> <REGISTER>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=27060041
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: siputils [checks.c:103]: no totag
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=2 global id=1 T start=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=55840, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=2 global id=2 T end=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:306]: realm value [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:96]: auth: digest-algo: MD5 parsed value: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:118]: allocate 48 bytes for result set at 0x7f2d628a0708
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:68]: 1 columns returned from the query
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:155]: allocate 8 bytes for result names at 0x7f2d628a0828
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:165]: allocate 4 bytes for result types at 0x7f2d628a0778
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[0] at 0x7f2d628a0790
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d628a0790)[0]=[password]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:184]: allocate 32 bytes for rows at 0x7f2d628a07b0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:119]: allocate 32 bytes for row values at 0x7f2d628a0848
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_val.c:117]: converting STRING [1001]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:119]: allocate 32 bytes for row values at 0x7f2d628a0878
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_val.c:117]: converting STRING [1001]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:124]: HA1 string calculated: be0eb7aaba97a43db0bedaa77060a705
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:211]: check_response: Our result = '21879ca92607b5276648a76c732ce345'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:218]: check_response: Authorization is OK
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:81]: freeing 1 columns
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7f2d628a0790
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:94]: freeing result names at 0x7f2d628a0828
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:99]: freeing result types at 0x7f2d628a0778
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:54]: freeing 2 rows
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x7f2d628a0848
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x7f2d628a0878
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:62]: freeing rows at 0x7f2d628a07b0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:136]: freeing result set at 0x7f2d628a0708
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [sruid.c:176]: new sruid is [uloc-506615cf-6824-1] (1 / 20)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: registrar [reply.c:368]: created Contact HF: Contact: <sip:8475551001 at 10.51.2.181:56299;transport=tcp>;expires=600000#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sl [sl.c:278]: reply in stateless mode (sl)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26660 (13)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57bf38 n=418 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/TCP 10.51.2.181:56299;branch=z9hG4bK27041239;rport=56299#015#012From: <sip:8475551001 at 10.50.251.12>;tag=27060041#015#012To: <sip:8475551001 at 10.50.251.12>;tag=b27e1a1d33761e85846fc98f5f3a7e58.48a0#015#012Call-ID: 0301a9cc-2376-1a27-00b0-320108825461#015#012CSeq: 1705 REGISTER#015#012Contact: <sip:8475551001 at 10.51.2.181:56299;transport=tcp>;expires=600000#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 0#015#012#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_read.c:1164]: tcp_read_req: content-length= 0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:626]: method: <SUBSCRIBE>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:628]: uri: <sip:8475551001 at 10.50.251.12>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK27035729>; state=6
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=17
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [31]; uri=[sip:8475551001 at 10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body [<sip:8475551001 at 10.50.251.12>#015#012]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <24466> <SUBSCRIBE>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=27064139
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: siputils [checks.c:103]: no totag
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=3 global id=2 T start=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=57104, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=3 global id=3 T end=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:274]: realm value [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:86]: auth:pre_auth: Credentials with realm '10.50.251.12' not found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:180]: no credentials
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [challenge.c:128]: build_challenge_hf: realm='10.50.251.12'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [challenge.c:270]: auth: 'Proxy-Authenticate: Digest realm="10.50.251.12", nonce="UGYXEFBmFeSDjhouEq7B8iHXS4K7qz9r"#015#012'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sl [sl.c:278]: reply in stateless mode (sl)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26660 (13)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57bf38 n=464 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012SIP/2.0 407 Proxy Authentication Required#015#012Via: SIP/2.0/TCP 10.51.2.181:56299;branch=z9hG4bK27035729;rport=56299#015#012From: <sip:8475551001 at 10.50.251.12>;tag=27064139#015#012To: <sip:8475551001 at 10.50.251.12>;tag=b27e1a1d33761e85846fc98f5f3a7e58.1d86#015#012Call-ID: cfc85670-bc8b-d156-4225-f8542265a997#015#012CSeq: 24466 SUBSCRIBE#015#012Proxy-Authenticate: Digest realm="10.50.251.12", nonce="UGYXEFBmFeSDjhouEq7B8iHXS4K7qz9r"#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 0#015#012#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_read.c:1164]: tcp_read_req: content-length= 0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:626]: method: <SUBSCRIBE>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:628]: uri: <sip:8475551001 at 10.50.251.12>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK27043594>; state=6
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=17
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [31]; uri=[sip:8475551001 at 10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body [<sip:8475551001 at 10.50.251.12>#015#012]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <32393> <SUBSCRIBE>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=27036475
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: siputils [checks.c:103]: no totag
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=4 global id=3 T start=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [ip_addr.c:247]: tcpconn_new: new tcp connection: 10.51.2.181
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:1089]: tcpconn_new: on port 56301, type 2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:1400]: tcpconn_add: hashes: 1794:1309:1790, 2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x82cec0, 33, 2, 0x7f2d5c57d458), fd_no=22
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=12876, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=4 global id=4 T end=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:274]: realm value [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:86]: auth:pre_auth: Credentials with realm '10.50.251.12' not found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x82cec0, 33, -1, 0x0) fd_no=23 called
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:4295]: tcp: DBG: sending to child, events 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:3966]: selected tcp worker 1 14(26661) for activity on [tcp:10.50.251.12:5060], 0x7f2d5c57d458
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:180]: no credentials
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [challenge.c:128]: build_challenge_hf: realm='10.50.251.12'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [challenge.c:270]: auth: 'Proxy-Authenticate: Digest realm="10.50.251.12", nonce="UGYXEFBmFeSDjhouEq7B8iHXS4K7qz9r"#015#012'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sl [sl.c:278]: reply in stateless mode (sl)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26660 (13)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [tcp_read.c:1354]: received n=8 con=0x7f2d5c57d458, fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57bf38 n=464 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012SIP/2.0 407 Proxy Authentication Required#015#012Via: SIP/2.0/TCP 10.51.2.181:56299;branch=z9hG4bK27043594;rport=56299#015#012From: <sip:8475551001 at 10.50.251.12>;tag=27036475#015#012To: <sip:8475551001 at 10.50.251.12>;tag=b27e1a1d33761e85846fc98f5f3a7e58.2699#015#012Call-ID: 70085615-c9a9-df0f-282a-62550735a89e#015#012CSeq: 32393 SUBSCRIBE#015#012Proxy-Authenticate: Digest realm="10.50.251.12", nonce="UGYXEFBmFeSDjhouEq7B8iHXS4K7qz9r"#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 0#015#012#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:626]: method: <GET>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:628]: uri: </xcap-root/xcap-caps/global/index>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:630]: version: <HTTP/1.1>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: xhttp [xhttp_mod.c:345]: new fake msg created (204 bytes):#012<GET /xcap-root/xcap-caps/global/index HTTP/1.1#015#012Via: SIP/2.0/TCP 10.51.2.181:56301#015#012Host: 10.50.251.12:5060#015#012Connection: Keep-Alive#015#012User-Agent: XDM-client/OMA1.1#015#012X-3GPP-Intended-Identity: 8475551001#015#012#015#012>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:626]: method: <GET>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:628]: uri: </xcap-root/xcap-caps/global/index>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:630]: version: <HTTP/1.1>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_read.c:1164]: tcp_read_req: content-length= 0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <script>: ===== xhttp: request [HTTP/1.1] GET => /xcap-root/xcap-caps/global/index
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:626]: method: <SUBSCRIBE>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:628]: uri: <sip:8475551001 at 10.50.251.12>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK27055658>; state=6
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=17
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: xcap_server [xcap_misc.c:153]: matched xcap-caps
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: xcap_server [xcap_misc.c:215]: matched global
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: ERROR: <script>: ===== xhttp: xcap-caps : <null>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [31]; uri=[sip:8475551001 at 10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body [<sip:8475551001 at 10.50.251.12>#015#012]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <24467> <SUBSCRIBE>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: sl [sl.c:278]: reply in stateless mode (sl)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26661 (14)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57d458 n=702 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012HTTP/1.1 200 ok#015#012Via: SIP/2.0/TCP 10.51.2.181:56301#015#012Content-Type: application/xcap-caps+xml#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 544#015#012#015#012<?xml version='1.0' encoding='UTF-8'?>#012<xcap-caps xmlns='urn:ietf:params:xml:ns:xcap-caps'>#012<auids>#012 <auid>rls-services</auid>#012 <auid>pidf-manipulation</auid>#012 <auid>xcap-caps</auid>#012 <auid>pres-rules</auid>#012 </auids>#012 <extensions>#012 </extensions>#012 <namespaces>#012 <namespace>urn:ietf:params:xml:ns:rls-services</namespace>#012 <namespace>urn:ietf:params:xml:ns:pidf</namespace>#012 <namespace>urn:ietf:params:xml:ns:xcap-caps</namespace>#012 <namespace>urn:ietf:params:xml:ns:pres-rules</namespace>#012 </namespaces>#012</xcap-caps>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:3617]: handle_ser_child: read response= 7f2d5c57d458, -1, fd -1 from 14 (26661)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x871120, 11, 2, 0x7f2d5c57d458), fd_no=1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x871120, 11, -1, 0x10) fd_no=2 called
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [tcp_read.c:1281]: releasing con 0x7f2d5c57d458, state -2, fd=11, id=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26661]: DEBUG: <core> [tcp_read.c:1282]: extra_data (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:3378]: handle_tcp_child: reader response= 7f2d5c57d458, -2 from 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=27064139
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: siputils [checks.c:103]: no totag
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=5 global id=4 T start=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=57105, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=5 global id=5 T end=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:274]: realm value [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:96]: auth: digest-algo: MD5 parsed value: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:118]: allocate 48 bytes for result set at 0x7f2d628a0968
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:68]: 1 columns returned from the query
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:155]: allocate 8 bytes for result names at 0x7f2d628a0790
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:165]: allocate 4 bytes for result types at 0x7f2d628a0828
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[0] at 0x7f2d628a0808
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d628a0808)[0]=[password]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:184]: allocate 32 bytes for rows at 0x7f2d628a0848
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:119]: allocate 32 bytes for row values at 0x7f2d628a0dd8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_val.c:117]: converting STRING [1001]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:119]: allocate 32 bytes for row values at 0x7f2d628a0e20
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_val.c:117]: converting STRING [1001]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:124]: HA1 string calculated: be0eb7aaba97a43db0bedaa77060a705
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:211]: check_response: Our result = '9005b7411c7c975d0bc20edd6a1bfe5c'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:218]: check_response: Authorization is OK
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:81]: freeing 1 columns
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7f2d628a0808
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:94]: freeing result names at 0x7f2d628a0790
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:99]: freeing result types at 0x7f2d628a0828
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:54]: freeing 2 rows
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x7f2d628a0dd8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x7f2d628a0e20
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:62]: freeing rows at 0x7f2d628a0848
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:136]: freeing result set at 0x7f2d628a0968
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1379]: DEBUG: t_newtran: msg id=5 , global msg id=5 , T on entrance=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=57105, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_hooks.c:374]: DBG: trans=0x7f2d5c57d458, callback type 1, id 0 entered
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [ip_addr.c:247]: tcpconn_new: new tcp connection: 10.51.2.181
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:1089]: tcpconn_new: on port 56302, type 2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:1400]: tcpconn_add: hashes: 1793:1310:1789, 3
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x82cec0, 33, 2, 0x7f2d5c57e750), fd_no=22
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x82cec0, 33, -1, 0x0) fd_no=23 called
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:4295]: tcp: DBG: sending to child, events 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:3966]: selected tcp worker 2 15(26662) for activity on [tcp:10.50.251.12:5060], 0x7f2d5c57e750
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [tcp_read.c:1354]: received n=8 con=0x7f2d5c57e750, fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: rls [subscribe.c:520]: supported header not found - not for rls
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:626]: method: <GET>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:628]: uri: </xcap-root/rls-services/users/8475551001/index>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:630]: version: <HTTP/1.1>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [event_list.c:351]: start event= [reg/0]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: xhttp [xhttp_mod.c:345]: new fake msg created (217 bytes):#012<GET /xcap-root/rls-services/users/8475551001/index HTTP/1.1#015#012Via: SIP/2.0/TCP 10.51.2.181:56302#015#012Host: 10.50.251.12:5060#015#012Connection: Keep-Alive#015#012User-Agent: XDM-client/OMA1.1#015#012X-3GPP-Intended-Identity: 8475551001#015#012#015#012>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:626]: method: <GET>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:628]: uri: </xcap-root/rls-services/users/8475551001/index>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:630]: version: <HTTP/1.1>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: ERROR: presence [subscribe.c:1001]: Unsupported event header field value reg
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=5 global id=5 T start=0x7f2d5c57d458
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1151]: DEBUG: t_check_msg: T already found!
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <script>: ===== xhttp: request [HTTP/1.1] GET => /xcap-root/rls-services/users/8475551001/index
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [mem/shm_mem.c:111]: WARNING:vqm_resize: resize(0) called
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26660 (13)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57bf38 n=410 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012SIP/2.0 489 Bad Event#015#012Via: SIP/2.0/TCP 10.51.2.181:56299;branch=z9hG4bK27055658;rport=56299#015#012From: <sip:8475551001 at 10.50.251.12>;tag=27064139#015#012To: <sip:8475551001 at 10.50.251.12>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-4155#015#012Call-ID: cfc85670-bc8b-d156-4225-f8542265a997#015#012CSeq: 24467 SUBSCRIBE#015#012Allow-Events: message-summary, presence, presence.winfo#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 0#015#012#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: xcap_server [xcap_misc.c:141]: matched rls-services
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: xcap_server [xcap_misc.c:212]: matched users
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:703]: DEBUG: reply sent out. buf=0x7f2d628a0a18: SIP/2.0 489 Bad Even..., shmem=0x7f2d5c580fd0: SIP/2.0 489 Bad Even
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:713]: DEBUG: _reply_light: finished
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sl [sl.c:273]: reply in stateful mode (tm)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: ERROR: <script>: ===== xhttp: rls-services : 8475551001
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=5 global id=5 T start=0x7f2d5c57d458
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: ERROR: <script>: ===== xhttp: get sip:8475551001 at 10.50.251.12 => /xcap-root/rls-services/users/8475551001/index
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1151]: DEBUG: t_check_msg: T already found!
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: xcap_server [xcap_misc.c:141]: matched rls-services
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: xcap_server [xcap_misc.c:212]: matched users
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [timer.c:595]: timer_add called on an active timer 0x7f2d5c57d4d8 (0x7f2d5c2bc568, 0x7f2d5c2bc568), flags 201
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_funcs.c:184]: tm: put_on_wait: transaction 0x7f2d5c57d458 already on wait
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [db_res.c:118]: allocate 48 bytes for result set at 0x7f2d628a02f8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: db_mysql [km_res.c:68]: 1 columns returned from the query
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [db_res.c:155]: allocate 8 bytes for result names at 0x7f2d628a0338
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [db_res.c:165]: allocate 4 bytes for result types at 0x7f2d628a0350
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[0] at 0x7f2d628a0368
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d628a0368)[0]=[etag]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: db_mysql [km_res.c:169]: no rows returned from the query
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: xcap_server [xcap_server.c:796]: no document
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [db_res.c:81]: freeing 1 columns
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7f2d628a0368
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [db_res.c:94]: freeing result names at 0x7f2d628a0338
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [db_res.c:99]: freeing result types at 0x7f2d628a0350
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [db_res.c:136]: freeing result set at 0x7f2d628a02f8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: sl [sl.c:278]: reply in stateless mode (sl)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_read.c:1164]: tcp_read_req: content-length= 1202
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26662 (15)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:626]: method: <PUBLISH>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:628]: uri: <sip:8475551001 at 10.50.251.12>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57e750 n=122 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012HTTP/1.1 404 Not found#015#012Via: SIP/2.0/TCP 10.51.2.181:56302#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 0#015#012#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:3617]: handle_ser_child: read response= 7f2d5c57e750, -1, fd -1 from 15 (26662)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x871120, 11, 2, 0x7f2d5c57e750), fd_no=1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x871120, 11, -1, 0x10) fd_no=2 called
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [tcp_read.c:1281]: releasing con 0x7f2d5c57e750, state -2, fd=11, id=3
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26662]: DEBUG: <core> [tcp_read.c:1282]: extra_data (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:3378]: handle_tcp_child: reader response= 7f2d5c57e750, -2 from 2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK27043771>; state=6
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=17
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [31]; uri=[sip:8475551001 at 10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body [<sip:8475551001 at 10.50.251.12>#015#012]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <21728> <PUBLISH>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=1202
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=27036492
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: siputils [checks.c:103]: no totag
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=6 global id=5 T start=0xffffffffffffffff
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=4970, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=6 global id=6 T end=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:274]: realm value [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:86]: auth:pre_auth: Credentials with realm '10.50.251.12' not found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:180]: no credentials
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [challenge.c:128]: build_challenge_hf: realm='10.50.251.12'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [challenge.c:270]: auth: 'Proxy-Authenticate: Digest realm="10.50.251.12", nonce="UGYXEFBmFeSDjhouEq7B8iHXS4K7qz9r"#015#012'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sl [sl.c:278]: reply in stateless mode (sl)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26660 (13)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57bf38 n=462 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012SIP/2.0 407 Proxy Authentication Required#015#012Via: SIP/2.0/TCP 10.51.2.181:56299;branch=z9hG4bK27043771;rport=56299#015#012From: <sip:8475551001 at 10.50.251.12>;tag=27036492#015#012To: <sip:8475551001 at 10.50.251.12>;tag=b27e1a1d33761e85846fc98f5f3a7e58.761e#015#012Call-ID: ddfffd80-2562-7cd6-e58a-9e9d02e5323f#015#012CSeq: 21728 PUBLISH#015#012Proxy-Authenticate: Digest realm="10.50.251.12", nonce="UGYXEFBmFeSDjhouEq7B8iHXS4K7qz9r"#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 0#015#012#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [ip_addr.c:247]: tcpconn_new: new tcp connection: 10.51.2.181
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:1089]: tcpconn_new: on port 56303, type 2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:1400]: tcpconn_add: hashes: 1792:1311:1788, 4
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x82cec0, 33, 2, 0x7f2d5c57e750), fd_no=22
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_read.c:1164]: tcp_read_req: content-length= 0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:626]: method: <SUBSCRIBE>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:628]: uri: <sip:8475551001 at 10.50.251.12>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x82cec0, 33, -1, 0x0) fd_no=23 called
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:4295]: tcp: DBG: sending to child, events 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:3966]: selected tcp worker 3 16(26664) for activity on [tcp:10.50.251.12:5060], 0x7f2d5c57e750
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK27035312>; state=6
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=17
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [tcp_read.c:1354]: received n=8 con=0x7f2d5c57e750, fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [tcp_read.c:1164]: tcp_read_req: content-length= 1007
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:626]: method: <PUT>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:628]: uri: </xcap-root/rls-services/users/8475551001/index>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:630]: version: <HTTP/1.1>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=1007
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [31]; uri=[sip:8475551001 at 10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body [<sip:8475551001 at 10.50.251.12>#015#012]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: xhttp [xhttp_mod.c:345]: new fake msg created (1290 bytes):#012<PUT /xcap-root/rls-services/users/8475551001/index HTTP/1.1#015#012Via: SIP/2.0/TCP 10.51.2.181:56303#015#012Host: 10.50.251.12:5060#015#012Content-Length: 1007#015#012Connection: Keep-Alive#015#012User-Agent: XDM-client/OMA1.1#015#012X-3GPP-Intended-Identity: 8475551001#015#012Content-Type: application/rls-services+xml#015#012#015#012<rls-services xmlns:rl="urn:ietf:params:xml:ns:resource-lists" xmlns="urn:ietf:params:xml:ns:rls-services">#015#012 <service uri="8475551001;pres-list=rcs">#015#012 <resource-list>http://10.50.251.12:5060/xcap-root/resource-lists/users/8475551001/index/~~/resource-lists/list%5B@name=%22rcs%22%5D</resource-list>#015#012 <packages>#015#012 <package>presence</package>#015#012 </packages>#015#012 </service>#015#012 <service uri="8475551001;pres-list=oma_buddylist">#015#012 <resource-list>http://10.50.251.12:5060/xcap-root/resource-lists/users/8475551001/index/~~/resource-lists/list%5B@name=%22oma_buddylist%22%5D</resource-list>#015#012 <packages>#015#012 <package>presence</package>#015#012 </packages>#015#012 </service>#015#012 <service uri="8475551001;pres-list=oma_pocbuddylist">#015#012 <resource-list>http://10.50.251.12:5060/xcap-root/resource-lists/users/8475551001/index/~~/resource-lists/list%5B@name=%22oma_pocbuddylist%22%5D</resource-list>#015#012 <packages>#015#012 <package>presence</package>#015#012 </packages>#015#012 </service>#015#012</rls-services>>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:626]: method: <PUT>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:628]: uri: </xcap-root/rls-services/users/8475551001/index>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:630]: version: <HTTP/1.1>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <32394> <SUBSCRIBE>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <script>: ===== xhttp: request [HTTP/1.1] PUT => /xcap-root/rls-services/users/8475551001/index
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=27036475
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: siputils [checks.c:103]: no totag
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=7 global id=6 T start=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=12873, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: xcap_server [xcap_misc.c:141]: matched rls-services
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: xcap_server [xcap_misc.c:212]: matched users
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=7 global id=7 T end=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: ERROR: <script>: ===== xhttp: rls-services : 8475551001
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:274]: realm value [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=1007
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: ERROR: xcap_server [xcap_misc.c:109]: invalid http uri - shorter than xcap-root
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: ERROR: xcap_server [xcap_server.c:560]: cannot parse xcap uri [0]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: sl [sl.c:278]: reply in stateless mode (sl)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:96]: auth: digest-algo: MD5 parsed value: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26664 (16)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57e750 n=125 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012HTTP/1.1 500 Server error#015#012Via: SIP/2.0/TCP 10.51.2.181:56303#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 0#015#012#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:3617]: handle_ser_child: read response= 7f2d5c57e750, -1, fd -1 from 16 (26664)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: rls [subscribe.c:1200]: watcher username: 8475551001, watcher domain: 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:118]: allocate 48 bytes for result set at 0x7f2d628a0968
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:68]: 1 columns returned from the query
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:155]: allocate 8 bytes for result names at 0x7f2d628a1220
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:165]: allocate 4 bytes for result types at 0x7f2d628a0778
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x871120, 11, 2, 0x7f2d5c57e750), fd_no=1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x871120, 11, -1, 0x10) fd_no=2 called
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [tcp_read.c:1281]: releasing con 0x7f2d5c57e750, state -2, fd=11, id=4
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26664]: DEBUG: <core> [tcp_read.c:1282]: extra_data (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26665]: DEBUG: <core> [tcp_main.c:3378]: handle_tcp_child: reader response= 7f2d5c57e750, -2 from 3
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[0] at 0x7f2d628a0808
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d628a0808)[0]=[password]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:184]: allocate 32 bytes for rows at 0x7f2d628a0848
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:119]: allocate 32 bytes for row values at 0x7f2d628a0878
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_val.c:117]: converting STRING [1001]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:119]: allocate 32 bytes for row values at 0x7f2d628a1528
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_val.c:117]: converting STRING [1001]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:124]: HA1 string calculated: be0eb7aaba97a43db0bedaa77060a705
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:211]: check_response: Our result = '9005b7411c7c975d0bc20edd6a1bfe5c'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:218]: check_response: Authorization is OK
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:81]: freeing 1 columns
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7f2d628a0808
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:94]: freeing result names at 0x7f2d628a1220
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:99]: freeing result types at 0x7f2d628a0778
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:54]: freeing 2 rows
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x7f2d628a0878
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x7f2d628a1528
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:62]: freeing rows at 0x7f2d628a0848
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:136]: freeing result set at 0x7f2d628a0968
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1379]: DEBUG: t_newtran: msg id=7 , global msg id=7 , T on entrance=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=12873, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_hooks.c:374]: DBG: trans=0x7f2d5c57e750, callback type 1, id 0 entered
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: rls [subscribe.c:520]: supported header not found - not for rls
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [event_list.c:351]: start event= [presence.winfo/2]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [subscribe.c:1063]: 'Expires' header found, value= 600000
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [subscribe.c:1085]: 'To' header ALREADY PARSED: <sip:8475551001 at 10.50.251.12>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [subscribe.c:1156]: generating to_tag
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sl [sl.c:327]: totag stateful mode (tm)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [subscribe.c:1216]: subs->contact= sip:8475551001 at 10.51.2.181:56299;transport=tcp - len = 46
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [subscribe.c:961]: subscription status= active - found in watcher table
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [subscribe.c:538]: update subscription
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:117]: pres_uri: sip:8475551001 at 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:118]: watcher_user at watcher_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:119]: to_user at to_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:120]: from_user at from_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:121]: callid/from_tag/to_tag: 70085615-c9a9-df0f-282a-62550735a89e/27036475/a6a1c5f60faecf035a1ae5b6e96e979a-b0f9
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:122]: local_cseq/remote_cseq: 0/32394
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:123]: local_contact/contact: sip:10.50.251.12:5060;transport=tcp/sip:8475551001 at 10.51.2.181:56299;transport=tcp
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:124]: record_route:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:125]: sockinfo_str: tcp:10.50.251.12:5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:127]: event: presence.winfo
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:128]: status: active
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:129]: reason:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:130]: version: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:131]: expires: 3600
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:133]: updated/updated_winfo: -1/-1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [subscribe.c:613]: subscription not in dialog
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [subscribe.c:618]: inserting in shtable
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=7 global id=7 T start=0x7f2d5c57e750
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1151]: DEBUG: t_check_msg: T already found!
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [mem/shm_mem.c:111]: WARNING:vqm_resize: resize(0) called
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26660 (13)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57bf38 n=409 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/TCP 10.51.2.181:56299;branch=z9hG4bK27035312;rport=56299#015#012From: <sip:8475551001 at 10.50.251.12>;tag=27036475#015#012To: <sip:8475551001 at 10.50.251.12>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-b0f9#015#012Call-ID: 70085615-c9a9-df0f-282a-62550735a89e#015#012CSeq: 32394 SUBSCRIBE#015#012Expires: 3600#015#012Contact: <sip:10.50.251.12:5060;transport=tcp>#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 0#015#012#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:703]: DEBUG: reply sent out. buf=0x7f2d628a0be8: SIP/2.0 200 OK#015#012Via:..., shmem=0x7f2d5c582a38: SIP/2.0 200 OK#015#012Via:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:713]: DEBUG: _reply_light: finished
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sl [sl.c:273]: reply in stateful mode (tm)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:1451]: dialog info:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:117]: pres_uri: sip:8475551001 at 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:118]: watcher_user at watcher_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:119]: to_user at to_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:120]: from_user at from_domain: 8475551001 at 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:121]: callid/from_tag/to_tag: 70085615-c9a9-df0f-282a-62550735a89e/27036475/a6a1c5f60faecf035a1ae5b6e96e979a-b0f9
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:122]: local_cseq/remote_cseq: 1/32394
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:123]: local_contact/contact: sip:10.50.251.12:5060;transport=tcp/sip:8475551001 at 10.51.2.181:56299;transport=tcp
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:124]: record_route:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:125]: sockinfo_str: tcp:10.50.251.12:5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:127]: event: presence.winfo
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:128]: status: active
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:129]: reason:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:130]: version: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:131]: expires: 3600
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:133]: updated/updated_winfo: -1/-1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:118]: allocate 48 bytes for result set at 0x7f2d628a0aa8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:68]: 2 columns returned from the query
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:155]: allocate 16 bytes for result names at 0x7f2d628a14e8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:165]: allocate 8 bytes for result types at 0x7f2d628a1508
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[0] at 0x7f2d628a0bc8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d628a0bc8)[0]=[watcher_username]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[1] at 0x7f2d628a0c68
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d628a0c68)[1]=[watcher_domain]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:169]: no rows returned from the query
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:1930]: The query returned no result
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:81]: freeing 2 columns
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7f2d628a0bc8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[1] at 0x7f2d628a0c68
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:94]: freeing result names at 0x7f2d628a14e8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:99]: freeing result types at 0x7f2d628a1508
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:136]: freeing result set at 0x7f2d628a0aa8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:1544]: headers:#012Max-Forwards: 70#015#012Event: presence.winfo#015#012Contact: <sip:10.50.251.12:5060;transport=tcp>#015#012Subscription-State: active;expires=3600#015#012Content-Type: application/watcherinfo+xml#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:928]: CONTACT = sip:8475551001 at 10.51.2.181:56299;transport=tcp
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:1554]: expires 3600 status 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:1707]: === 27/14/37
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [uac.c:243]: DEBUG:tm:t_uac: next_hop=<sip:8475551001 at 10.51.2.181:56299;transport=tcp>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [uac.c:182]: DEBUG: dlg2hash: 26449
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26660 (13)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57bf38 n=746 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012NOTIFY sip:8475551001 at 10.51.2.181:56299;transport=tcp SIP/2.0#015#012Via: SIP/2.0/TCP 10.50.251.12;branch=z9hG4bK1576.57b1f585.0#015#012To: sip:8475551001 at 10.50.251.12;tag=27036475#015#012From: sip:8475551001 at 10.50.251.12;tag=a6a1c5f60faecf035a1ae5b6e96e979a-b0f9#015#012CSeq: 2 NOTIFY#015#012Call-ID: 70085615-c9a9-df0f-282a-62550735a89e#015#012Content-Length: 195#015#012User-Agent: kamailio (3.3.1 (x86_64/linux))#015#012Max-Forwards: 70#015#012Event: presence.winfo#015#012Contact: <sip:10.50.251.12:5060;transport=tcp>#015#012Subscription-State: active;expires=3600#015#012Content-Type: application/watcherinfo+xml#015#012#015#012<?xml version="1.0"?>#012<watcherinfo xmlns="urn:ietf:params:xml:ns:watcherinfo" version="1" state="full">#012 <watcher-list resource="sip:8475551001 at 10.50.251.12" package="presence"/>#012</watcherinfo>#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: INFO: presence [notify.c:1581]: NOTIFY sip:8475551001 at 10.50.251.12 via sip:8475551001 at 10.51.2.181:56299;transport=tcp on behalf of sip:8475551001 at 10.50.251.12 for event presence.winfo
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=7 global id=7 T start=0x7f2d5c57e750
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1151]: DEBUG: t_check_msg: T already found!
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [timer.c:595]: timer_add called on an active timer 0x7f2d5c57e7d0 (0x7f2d5c2bc578, 0x7f2d5c2bc578), flags 201
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_funcs.c:184]: tm: put_on_wait: transaction 0x7f2d5c57e750 already on wait
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_read.c:1164]: tcp_read_req: content-length= 1202
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:626]: method: <PUBLISH>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:628]: uri: <sip:8475551001 at 10.50.251.12>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK27064761>; state=6
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=17
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [31]; uri=[sip:8475551001 at 10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body [<sip:8475551001 at 10.50.251.12>#015#012]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <21729> <PUBLISH>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=1202
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=27036492
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: siputils [checks.c:103]: no totag
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=8 global id=7 T start=0xffffffffffffffff
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=4969, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=8 global id=8 T end=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:274]: realm value [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:96]: auth: digest-algo: MD5 parsed value: 1
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:118]: allocate 48 bytes for result set at 0x7f2d628a0968
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:68]: 1 columns returned from the query
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:155]: allocate 8 bytes for result names at 0x7f2d628a0778
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:165]: allocate 4 bytes for result types at 0x7f2d628a1208
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[0] at 0x7f2d628a0828
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d628a0828)[0]=[password]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:184]: allocate 32 bytes for rows at 0x7f2d628a1528
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:119]: allocate 32 bytes for row values at 0x7f2d628a0848
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_val.c:117]: converting STRING [1001]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:119]: allocate 32 bytes for row values at 0x7f2d628a0878
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_val.c:117]: converting STRING [1001]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth_db [authorize.c:124]: HA1 string calculated: be0eb7aaba97a43db0bedaa77060a705
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:211]: check_response: Our result = '2a3657d33c3380661740050b1516147e'
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: auth [api.c:218]: check_response: Authorization is OK
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:81]: freeing 1 columns
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7f2d628a0828
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:94]: freeing result names at 0x7f2d628a0778
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:99]: freeing result types at 0x7f2d628a1208
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:54]: freeing 2 rows
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x7f2d628a0848
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x7f2d628a0878
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:62]: freeing rows at 0x7f2d628a1528
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:136]: freeing result set at 0x7f2d628a0968
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [10.50.251.12] == [127.0.0.1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [10.50.251.12] == [10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1379]: DEBUG: t_newtran: msg id=8 , global msg id=8 , T on entrance=(nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=4969, isACK=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_hooks.c:374]: DBG: trans=0x7f2d5c584358, callback type 1, id 0 entered
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [event_list.c:351]: start event= [presence/1]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [publish.c:318]: SIP-If-Match header not found
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [presentity.c:87]: etag= a.1348867535.26660.3.0 / 22#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [publish.c:327]: new etag = a.1348867535.26660.3.0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [publish.c:352]: Expires header found, value= 600000
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence_xml [xcap_auth.c:469]: [user]= 8475551001#011[domain]= 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:118]: allocate 48 bytes for result set at 0x7f2d628a0dd8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:68]: 1 columns returned from the query
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:155]: allocate 8 bytes for result names at 0x7f2d628a1208
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:165]: allocate 4 bytes for result types at 0x7f2d628a0778
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[0] at 0x7f2d628a0828
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d628a0828)[0]=[doc]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: db_mysql [km_res.c:121]: use DB1_BLOB result type
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:184]: allocate 16 bytes for rows at 0x7f2d628a0808
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:119]: allocate 32 bytes for row values at 0x7f2d628a1528
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_val.c:168]: converting BLOB [<?xml version="1.0" encoding="UTF-8" standalone="no"?><ruleset xmlns="urn:ietf:params:xml:ns:common-policy"><rule id="presence_allow"><conditions><identity><one id="sip:8475551002 at 10.50.251.12"/></identity></conditions><actions><sub-handling xmlns="urn:ietf:params:xml:ns:pres-rules">allow</sub-handling></actions><transformations><provide-devices xmlns="urn:ietf:params:xml:ns:pres-rules"><all-devices/></provide-devices><provide-persons xmlns="urn:ietf:params:xml:ns:pres-rules"><all-persons/></provide-persons><provide-services xmlns="urn:ietf:params:xml:ns:pres-rules"><all-services/></provide-services></transformations></rule></ruleset>]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence_xml [xcap_auth.c:566]: xcap document:#012<?xml version="1.0" encoding="UTF-8" standalone="no"?><ruleset xmlns="urn:ietf:params:xml:ns:common-policy"><rule id="presence_allow"><conditions><identity><one id="sip:8475551002 at 10.50.251.12"/></identity></conditions><actions><sub-handling xmlns="urn:ietf:params:xml:ns:pres-rules">allow</sub-handling></actions><transformations><provide-devices xmlns="urn:ietf:params:xml:ns:pres-rules"><all-devices/></provide-devices><provide-persons xmlns="urn:ietf:params:xml:ns:pres-rules"><all-persons/></provide-persons><provide-services xmlns="urn:ietf:params:xml:ns:pres-rules"><all-services/></provide-services></transformations></rule></ruleset>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:81]: freeing 1 columns
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7f2d628a0828
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:94]: freeing result names at 0x7f2d628a1208
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:99]: freeing result types at 0x7f2d628a0778
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:54]: freeing 1 rows
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_row.c:97]: freeing row values at 0x7f2d628a1528
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:62]: freeing rows at 0x7f2d628a0808
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [db_res.c:136]: freeing result set at 0x7f2d628a0dd8
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [hash.c:461]: pres_uri= sip:8475551001 at 10.50.251.12
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [presentity.c:398]: inserting 8 cols into table
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [presentity.c:104]: send 200OK reply
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [presentity.c:105]: etag= a.1348867535.26660.3.0 - len= 22
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=8 global id=8 T start=0x7f2d5c584358
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1151]: DEBUG: t_check_msg: T already found!
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [msg_translator.c:206]: check_via_address(10.51.2.181, 10.51.2.181, 0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [mem/shm_mem.c:111]: WARNING:vqm_resize: resize(0) called
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2313]: tcp_send: send from reader (26660 (13)), reusing fd
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2549]: tcp_send: sending...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2583]: tcp_send: after real write: c= 0x7f2d5c57bf38 n=393 fd=11
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_main.c:2584]: tcp_send: buf=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/TCP 10.51.2.181:56299;branch=z9hG4bK27064761;rport=56299#015#012From: <sip:8475551001 at 10.50.251.12>;tag=27036492#015#012To: <sip:8475551001 at 10.50.251.12>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-619b#015#012Call-ID: ddfffd80-2562-7cd6-e58a-9e9d02e5323f#015#012CSeq: 21729 PUBLISH#015#012Expires: 3600#015#012SIP-ETag: a.1348867535.26660.3.0#015#012Server: kamailio (3.3.1 (x86_64/linux))#015#012Content-Length: 0#015#012#015#012
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:703]: DEBUG: reply sent out. buf=0x7f2d628a1558: SIP/2.0 200 OK#015#012Via:..., shmem=0x7f2d5c586ff0: SIP/2.0 200 OK#015#012Via:
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:713]: DEBUG: _reply_light: finished
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: sl [sl.c:273]: reply in stateful mode (tm)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:1255]: Could not find subs_dialog
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=8 global id=8 T start=0x7f2d5c584358
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1151]: DEBUG: t_check_msg: T already found!
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [timer.c:595]: timer_add called on an active timer 0x7f2d5c5843d8 (0x7f2d5c2bc578, 0x7f2d5c57e7d0), flags 201
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_funcs.c:184]: tm: put_on_wait: transaction 0x7f2d5c584358 already on wait
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [tcp_read.c:1164]: tcp_read_req: content-length= 0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:634]: SIP Reply (status):
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:636]: version: <SIP/2.0>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:638]: status: <200>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:640]: reason: <OK>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK1576.57b1f585.0>; state=16
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:149]: After parse_msg...
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=9 global id=8 T start=0xffffffffffffffff
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=27036475
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [44]; uri=[sip:8475551001 at 10.50.251.12]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body [<sip:8475551001 at 10.50.251.12>]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <2> <NOTIFY>
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:965]: DEBUG: t_reply_matching: hash 26449 label 1482627957 branch 0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1016]: DEBUG: t_reply_matching: reply matched (T=0x7f2d5c582d68)!
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=9 global id=9 T end=0x7f2d5c582d68
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:2081]: DEBUG: reply_received: org. status uas=0, uac[0]=0 local=2 is_invite=0)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:1204]: ->>>>>>>>> T_code=0, new_code=200
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:1961]: DEBUG: local_reply: branch=0, save=0, winner=0
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:1998]: DEBUG: local transaction completed
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_hooks.c:288]: DBG: trans=0x7f2d5c582d68, callback type 1024, id 0 entered
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: presence [notify.c:1681]: completed with status 200 [to_tag:a6a1c5f60faecf035a1ae5b6e96e979a-b0f9]
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Sep 28 16:25:56 RCS-Presence /usr/local/sbin/kamailio[26660]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:118]: allocate 48 bytes for result set at 0x7f2d6288bee0
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:68]: 6 columns returned from the query
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:155]: allocate 48 bytes for result names at 0x7f2d6288bf20
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:165]: allocate 24 bytes for result types at 0x7f2d6288bf60
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[0] at 0x7f2d6288bf88
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288bf88)[0]=[rlsubs_did]
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[1] at 0x7f2d6288bfa8
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288bfa8)[1]=[resource_uri]
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[2] at 0x7f2d6288bfc8
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288bfc8)[2]=[auth_state]
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:100]: use DB1_INT result type
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[3] at 0x7f2d6288bfe8
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288bfe8)[3]=[content_type]
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[4] at 0x7f2d6288c008
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288c008)[4]=[reason]
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:136]: use DB1_STRING result type
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[5] at 0x7f2d6288c028
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:92]: RES_NAMES(0x7f2d6288c028)[5]=[presence_state]
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:121]: use DB1_BLOB result type
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: db_mysql [km_res.c:169]: no rows returned from the query
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:81]: freeing 6 columns
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7f2d6288bf88
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[1] at 0x7f2d6288bfa8
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[2] at 0x7f2d6288bfc8
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[3] at 0x7f2d6288bfe8
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[4] at 0x7f2d6288c008
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[5] at 0x7f2d6288c028
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:94]: freeing result names at 0x7f2d6288bf20
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:99]: freeing result types at 0x7f2d6288bf60
Sep 28 16:26:00 RCS-Presence /usr/local/sbin/kamailio[26649]: DEBUG: <core> [db_res.c:136]: freeing result set at 0x7f2d6288bee0
More information about the sr-users
mailing list