[Project Clearwater] issue in Registering Users

[asra.baneamoon]

 Hi Chris


Thanks for your response


Thanks Tahir


Till now i can’t  register the user in Zoiper softphone .
I have checked all the logs for Sprout, Bono and Homestead. please see the 
attachments.

Also

-The status of  Chronos process in Sprout and Ralf = chronos is not running! 
How can i activate it?
-The file var/lib/snmp/Homestead is missing even after i restart the 
Clearwater_infrastructure.! How can  i restore it?
-About Setting up S-CSCF configuration

{

   "s-cscfs" : [

       {   "server" : 
"sip:scscf.<sprout_domain>:5054;transport=TCP<sip:scscf.%3csprout_domain%3e:5054;transport=TCP>",

           "priority" : 0,

           "weight" : 100,

           "capabilities" : [<comma separated capabilities>]

       }

   ]

}

 I don't know what to write in Capabilities .Could someone give me an example, 
please

Thanks in advance

Thanks for your time

Regards

Asra







_________________________________________________________________________________________________________________________

Ce message et ses pieces jointes peuvent contenir des informations 
confidentielles ou privilegiees et ne doivent donc
pas etre diffuses, exploites ou copies sans autorisation. Si vous avez recu ce 
message par erreur, veuillez le signaler
a l'expediteur et le detruire ainsi que les pieces jointes. Les messages 
electroniques etant susceptibles d'alteration,
Orange decline toute responsabilite si ce message a ete altere, deforme ou 
falsifie. Merci.

This message and its attachments may contain confidential or privileged 
information that may be protected by law;
they should not be distributed, used or copied without authorisation.
If you have received this email in error, please notify the sender and delete 
this message and its attachments.
As emails may be altered, Orange is not liable for messages that have been 
modified, changed or falsified.
Thank you.


02-05-2016 11:58:40.606 UTC Verbose sproutletproxy.cpp:534: Sproutlet Proxy 
transaction (0x7fc474040d30) destroyed
02-05-2016 11:58:40.606 UTC Debug basicproxy.cpp:467: BasicProxy::UASTsx 
destructor (0x7fc474040d30)
02-05-2016 11:58:40.606 UTC Debug basicproxy.cpp:484: Disconnect UAC 
transactions from UAS transaction
02-05-2016 11:58:40.606 UTC Debug basicproxy.cpp:498: Free original request
02-05-2016 11:58:40.606 UTC Debug pjsip: tdta0x7fc4740e Destroying txdata 
Request msg REGISTER/cseq=2 (tdta0x7fc4740e2160)
02-05-2016 11:58:40.606 UTC Debug basicproxy.cpp:507: Free un-used best response
02-05-2016 11:58:40.606 UTC Debug pjsip: tdta0x7fc4742d Destroying txdata 
Response msg 408/REGISTER/cseq=2 (tdta0x7fc4742d5f70)
02-05-2016 11:58:40.606 UTC Debug basicproxy.cpp:528: BasicProxy::UASTsx 
destructor completed
02-05-2016 11:58:40.606 UTC Debug pjsip: tdta0x7fc4742b Destroying txdata 
Response msg 404/REGISTER/cseq=2 (tdta0x7fc4742bacc0)
02-05-2016 11:58:40.606 UTC Debug pjsip: tsx0x7fc4742da Transaction destroyed!
02-05-2016 11:58:58.662 UTC Debug pjsip: sip_endpoint.c Processing incoming 
message: Request msg REGISTER/cseq=1 (rdata0x7fc4582bb3b0)
02-05-2016 11:58:58.662 UTC Verbose common_sip_processing.cpp:120: RX 973 bytes 
Request msg REGISTER/cseq=1 (rdata0x7fc4582bb3b0) from TCP 84.39.45.34:37304:
--start msg--

REGISTER sip:reflexion.net;transport=UDP SIP/2.0
Via: SIP/2.0/TCP 
192.168.0.4:37304;rport;branch=z9hG4bKPjHM54OLfnQtTOM.RWf5az9ARHQxDziPtD
Path: <sip:LSljFDd4Lc@192.168.0.4:5058;transport=TCP;lr;ob>
Via: SIP/2.0/UDP 
90.32.83.18:63250;received=90.32.83.18;branch=z9hG4bK-524287-1---68789300f9591a16
Max-Forwards: 70
Contact: 
<sip:6505550898@90.32.83.18:63250;transport=UDP;rinstance=123abe236c050689>
To: "6505550...@reflexion.net" <sip:6505550...@reflexion.net>
From: "6505550...@reflexion.net" <sip:6505550...@reflexion.net>;tag=190fde64
Call-ID: uFWppiG31L9INSavTJ3DVA..
CSeq: 1 REGISTER
Expires: 3600
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, 
SUBSCRIBE
Supported: replaces, norefersub, extended-refer, timer, outbound, path, 
X-cisco-serviceuri
User-Agent: Z 3.9.32144 r32121
Allow-Events: presence, kpml
P-Visited-Network-ID: reflexion.net
Route: <sip:sprout.reflexion.net:5054;transport=TCP;lr;orig>
Content-Length:  0


--end msg--
02-05-2016 11:58:58.662 UTC Debug pjutils.cpp:1662: Logging SAS Call-ID marker, 
Call-ID uFWppiG31L9INSavTJ3DVA..
02-05-2016 11:58:58.662 UTC Debug thread_dispatcher.cpp:253: Queuing cloned 
received message 0x7fc4582a3908 for worker threads
02-05-2016 11:58:58.662 UTC Debug thread_dispatcher.cpp:149: Worker thread 
dequeue message 0x7fc4582a3908
02-05-2016 11:58:58.663 UTC Debug pjsip: sip_endpoint.c Distributing rdata to 
modules: Request msg REGISTER/cseq=1 (rdata0x7fc4582a3908)
02-05-2016 11:58:58.663 UTC Debug uri_classifier.cpp:167: home domain: true, 
local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: 
true, treat_number_as_phone: false
02-05-2016 11:58:58.663 UTC Debug uri_classifier.cpp:197: Classified URI as 4
02-05-2016 11:58:58.663 UTC Debug authentication.cpp:775: Authentication module 
invoked
02-05-2016 11:58:58.663 UTC Debug authentication.cpp:789: Request needs 
authentication
02-05-2016 11:58:58.663 UTC Debug acr.cpp:1765: Create RalfACR for node type 
S-CSCF with role Originating
02-05-2016 11:58:58.663 UTC Debug acr.cpp:49: Created ACR (0x7fc47c2049a0)
02-05-2016 11:58:58.663 UTC Debug acr.cpp:177: Created S-CSCF Ralf ACR
02-05-2016 11:58:58.663 UTC Debug acr.cpp:216: Set record type for P/S-CSCF
02-05-2016 11:58:58.663 UTC Debug acr.cpp:224: Non-dialog message => 
EVENT_RECORD
02-05-2016 11:58:58.663 UTC Debug acr.cpp:1493: Stored 0 subscription 
identifiers
02-05-2016 11:58:58.663 UTC Debug authentication.cpp:1091: No authentication 
information in request or stale nonce, so reject with challenge
02-05-2016 11:58:58.663 UTC Debug pjsip:       endpoint Response msg 
401/REGISTER/cseq=1 (tdta0x7fc47c20ff30) created
02-05-2016 11:58:58.663 UTC Debug pjutils.cpp:423: Private identity defaulted 
from public identity = 6505550...@reflexion.net
02-05-2016 11:58:58.663 UTC Debug httpresolver.cpp:71: HttpResolver::resolve 
for host 84.39.41.226, port 8888, family 2
02-05-2016 11:58:58.663 UTC Debug baseresolver.cpp:513: Attempt to parse 
84.39.41.226 as IP address
02-05-2016 11:58:58.663 UTC Debug httpresolver.cpp:79: Target is an IP address
02-05-2016 11:58:58.663 UTC Debug httpconnection.cpp:623: Sending HTTP request 
: 
http://84.39.41.226:8888/impi/6505550898%40reflexion.net/av?impu=sip%3A6505550898%40reflexion.net
 (trying 84.39.41.226) on new connection
02-05-2016 11:58:58.672 UTC Debug httpconnection.cpp:638: Received HTTP 
response: status=200, 
doc={"digest":{"ha1":"64c53536d6c05353f8ebfc537561dd18","realm":"reflexion.net","qop":"auth"}}
02-05-2016 11:58:58.672 UTC Debug communicationmonitor.cpp:82: Checking 
communication changes - successful attempts 2, failures 0
02-05-2016 11:58:58.672 UTC Debug authentication.cpp:197: Verifying AV: 
{"digest":{"ha1":"64c53536d6c05353f8ebfc537561dd18","realm":"reflexion.net","qop":"auth"}}
02-05-2016 11:58:58.672 UTC Debug authentication.cpp:224: Digest specified
02-05-2016 11:58:58.672 UTC Debug authentication.cpp:386: Valid AV - generate 
challenge
02-05-2016 11:58:58.672 UTC Debug authentication.cpp:395: Create 
WWW-Authenticate header
02-05-2016 11:58:58.672 UTC Debug authentication.cpp:478: Add Digest information
02-05-2016 11:58:58.672 UTC Debug authentication.cpp:533: Write authentication 
challenge to IMPI store
02-05-2016 11:58:58.672 UTC Debug memcachedstore.cpp:195: Key 
impi\\6505550...@reflexion.net hashes to vbucket 82 via hash 0x5da703d2
02-05-2016 11:58:58.673 UTC Debug memcachedstore.cpp:367: 1 read replicas for 
key impi\\6505550...@reflexion.net
02-05-2016 11:58:58.673 UTC Debug memcachedstore.cpp:402: Attempt to read from 
replica 0 (connection 0x7fc47c12d0e0)
02-05-2016 11:58:58.673 UTC Debug memcachedstore.cpp:780: Fetch result
02-05-2016 11:58:58.673 UTC Debug memcachedstore.cpp:788: Found record on 
replica
02-05-2016 11:58:58.673 UTC Debug memcachedstore.cpp:410: Read for 
impi\\6505550...@reflexion.net on replica 0 returned SUCCESS
02-05-2016 11:58:58.673 UTC Debug memcachedstore.cpp:453: Read 436 bytes from 
table impi key 6505550...@reflexion.net, CAS = 708
02-05-2016 11:58:58.673 UTC Debug communicationmonitor.cpp:82: Checking 
communication changes - successful attempts 4, failures 0
02-05-2016 11:58:58.673 UTC Debug impistore.cpp:786: Retrieved IMPI for 
6505550...@reflexion.net
{"authChallenges":[{"type":"digest","nonce":"486b11875e455bd2","nc":2,"expires":1462190328,"correlator":"z9hG4bKPji2dnKALvPVZ4jOFslLlNoBGHNJc4HfJf","realm":"reflexion.net","qop":"auth","ha1":"64c53536d6c05353f8ebfc537561dd18"},{"type":"digest","nonce":"59befec44c393425","nc":2,"expires":1462190360,"correlator":"z9hG4bKPjiIZNq6vOtwCltpNKAhVMOBFxPu8Jj2ns","realm":"reflexion.net","qop":"auth","ha1":"64c53536d6c05353f8ebfc537561dd18"}]}
02-05-2016 11:58:58.673 UTC Debug impistore.cpp:194: Expires in past - dropping
02-05-2016 11:58:58.673 UTC Debug impistore.cpp:648: Storing IMPI for 
6505550...@reflexion.net
{"authChallenges":[{"type":"digest","nonce":"59befec44c393425","nc":2,"expires":1462190360,"correlator":"z9hG4bKPjiIZNq6vOtwCltpNKAhVMOBFxPu8Jj2ns","realm":"reflexion.net","qop":"auth","ha1":"64c53536d6c05353f8ebfc537561dd18"},{"type":"digest","nonce":"1112f2f47c2ad9a7","nc":1,"expires":1462190378,"correlator":"z9hG4bKPjHM54OLfnQtTOM.RWf5az9ARHQxDziPtD","realm":"reflexion.net","qop":"auth","ha1":"64c53536d6c05353f8ebfc537561dd18"}]}
02-05-2016 11:58:58.673 UTC Debug memcachedstore.cpp:542: Writing 436 bytes to 
table impi key 6505550...@reflexion.net, CAS = 708, expiry = 40
02-05-2016 11:58:58.673 UTC Debug memcachedstore.cpp:195: Key 
impi\\6505550...@reflexion.net hashes to vbucket 82 via hash 0x5da703d2
02-05-2016 11:58:58.673 UTC Debug memcachedstore.cpp:562: 1 write replicas for 
key impi\\6505550...@reflexion.net
02-05-2016 11:58:58.673 UTC Debug memcachedstore.cpp:616: Attempt conditional 
write to vbucket 82 on replica 0 (connection 0x7fc47c12d0e0), CAS = 708, expiry 
= 40
02-05-2016 11:58:58.674 UTC Debug memcachedstore.cpp:657: Conditional write 
succeeded to replica 0
02-05-2016 11:58:58.674 UTC Debug authentication.cpp:605: Sending {"impi": 
"6505550...@reflexion.net", "impu": "sip:6505550...@reflexion.net", "nonce": 
"1112f2f47c2ad9a7"} to Chronos to set AV timer
02-05-2016 11:58:58.674 UTC Debug httpresolver.cpp:71: HttpResolver::resolve 
for host 192.168.0.3, port 7253, family 2
02-05-2016 11:58:58.674 UTC Debug baseresolver.cpp:513: Attempt to parse 
192.168.0.3 as IP address
02-05-2016 11:58:58.674 UTC Debug httpresolver.cpp:79: Target is an IP address
02-05-2016 11:58:58.674 UTC Debug httpconnection.cpp:623: Sending HTTP request 
: http://192.168.0.3:7253/timers (trying 192.168.0.3) on new connection
02-05-2016 11:58:58.674 UTC Error httpconnection.cpp:643: 
http://192.168.0.3:7253/timers failed at server 192.168.0.3 : Couldn't connect 
to server (7) : fatal
02-05-2016 11:58:58.674 UTC Debug baseresolver.cpp:473: Add 192.168.0.3:7253 
transport 6 to blacklist for 30 seconds
02-05-2016 11:58:58.674 UTC Debug httpconnection.cpp:623: Sending HTTP request 
: http://192.168.0.3:7253/timers (trying 192.168.0.3) on new connection
02-05-2016 11:58:58.674 UTC Error httpconnection.cpp:643: 
http://192.168.0.3:7253/timers failed at server 192.168.0.3 : Couldn't connect 
to server (7) : fatal
02-05-2016 11:58:58.674 UTC Debug baseresolver.cpp:473: Add 192.168.0.3:7253 
transport 6 to blacklist for 30 seconds
02-05-2016 11:58:58.674 UTC Error httpconnection.cpp:762: cURL failure with 
cURL error code 7 (see man 3 libcurl-errors) and HTTP error code 404
02-05-2016 11:58:58.674 UTC Debug pjsip: tsx0x7fc47c308 Transaction created for 
Request msg REGISTER/cseq=1 (rdata0x7fc4582a3908)
02-05-2016 11:58:58.674 UTC Debug pjsip: tsx0x7fc47c308 Incoming Request msg 
REGISTER/cseq=1 (rdata0x7fc4582a3908) in state Null
02-05-2016 11:58:58.674 UTC Debug pjsip: tsx0x7fc47c308 State changed from Null 
to Trying, event=RX_MSG
02-05-2016 11:58:58.674 UTC Debug pjsip: tsx0x7fc47c308 Sending Response msg 
401/REGISTER/cseq=1 (tdta0x7fc47c20ff30) in state Trying
02-05-2016 11:58:58.674 UTC Verbose common_sip_processing.cpp:136: TX 631 bytes 
Response msg 401/REGISTER/cseq=1 (tdta0x7fc47c20ff30) to TCP 84.39.45.34:37304:
--start msg--

SIP/2.0 401 Unauthorized
Via: SIP/2.0/TCP 
192.168.0.4:37304;rport=37304;received=84.39.45.34;branch=z9hG4bKPjHM54OLfnQtTOM.RWf5az9ARHQxDziPtD
Via: SIP/2.0/UDP 
90.32.83.18:63250;received=90.32.83.18;branch=z9hG4bK-524287-1---68789300f9591a16
Call-ID: uFWppiG31L9INSavTJ3DVA..
From: "6505550...@reflexion.net" <sip:6505550...@reflexion.net>;tag=190fde64
To: "6505550...@reflexion.net" 
<sip:6505550...@reflexion.net>;tag=z9hG4bKPjHM54OLfnQtTOM.RWf5az9ARHQxDziPtD
CSeq: 1 REGISTER
WWW-Authenticate: Digest  
realm="reflexion.net",nonce="1112f2f47c2ad9a7",opaque="6a4421c507b6c49d",algorithm=MD5,qop="auth"
Content-Length:  0


--end msg--
02-05-2016 11:58:58.675 UTC Debug pjsip: tsx0x7fc47c308 State changed from 
Trying to Completed, event=TX_MSG
02-05-2016 11:58:58.675 UTC Info acr.cpp:660: No CCF or ECF to send ACR for 
session uFWppiG31L9INSavTJ3DVA.. to - dropping!
02-05-2016 11:58:58.675 UTC Debug acr.cpp:54: Destroyed ACR (0x7fc47c2049a0)
02-05-2016 11:58:58.675 UTC Debug thread_dispatcher.cpp:193: Worker thread 
completed processing message 0x7fc4582a3908
02-05-2016 11:58:58.675 UTC Debug thread_dispatcher.cpp:199: Request latency = 
12339us
02-05-2016 11:58:58.675 UTC Debug pjsip: tsx0x7fc47c308 Timeout timer event
02-05-2016 11:58:58.675 UTC Debug pjsip: tsx0x7fc47c308 State changed from 
Completed to Terminated, event=TIMER
02-05-2016 11:58:58.675 UTC Debug pjsip: tsx0x7fc47c308 Timeout timer event
02-05-2016 11:58:58.675 UTC Debug pjsip: tsx0x7fc47c308 State changed from 
Terminated to Destroyed, event=TIMER
02-05-2016 11:58:58.675 UTC Debug pjsip: tdta0x7fc47c20 Destroying txdata 
Response msg 401/REGISTER/cseq=1 (tdta0x7fc47c20ff30)
02-05-2016 11:58:58.675 UTC Debug pjsip: tsx0x7fc47c308 Transaction destroyed!
02-05-2016 11:58:58.721 UTC Debug pjsip: sip_endpoint.c Processing incoming 
message: Request msg REGISTER/cseq=2 (rdata0x7fc458055bf0)
02-05-2016 11:58:58.721 UTC Verbose common_sip_processing.cpp:120: RX 1310 
bytes Request msg REGISTER/cseq=2 (rdata0x7fc458055bf0) from TCP 
84.39.45.34:47687:
--start msg--

REGISTER sip:reflexion.net;transport=UDP SIP/2.0
Via: SIP/2.0/TCP 
192.168.0.4:47687;rport;branch=z9hG4bKPjxMJXg1bFrdDzoG2BtjaYgg6MGcDRl5Si
Path: <sip:LSljFDd4Lc@192.168.0.4:5058;transport=TCP;lr;ob>
Via: SIP/2.0/UDP 
90.32.83.18:63250;received=90.32.83.18;branch=z9hG4bK-524287-1---6b6f48d5cc3582e4
Max-Forwards: 70
Contact: 
<sip:6505550898@90.32.83.18:63250;transport=UDP;rinstance=123abe236c050689>
To: "6505550...@reflexion.net" <sip:6505550...@reflexion.net>
From: "6505550...@reflexion.net" <sip:6505550...@reflexion.net>;tag=190fde64
Call-ID: uFWppiG31L9INSavTJ3DVA..
CSeq: 2 REGISTER
Expires: 3600
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, 
SUBSCRIBE
Supported: replaces, norefersub, extended-refer, timer, outbound, path, 
X-cisco-serviceuri
User-Agent: Z 3.9.32144 r32121
Authorization: Digest response="7971e617777aa93a01c37e9e41cd1693", 
username="6505550...@reflexion.net", realm="reflexion.net", 
nonce="1112f2f47c2ad9a7", uri="sip:reflexion.net;transport=UDP", algorithm=MD5, 
cnonce="1780cea5d7607cf4cb98a2ddccc24972", opaque="6a4421c507b6c49d", qop=auth, 
nc=00000001,integrity-protected=ip-assoc-pending
Allow-Events: presence, kpml
P-Visited-Network-ID: reflexion.net
Route: <sip:sprout.reflexion.net:5054;transport=TCP;lr;orig>
Content-Length:  0


--end msg--
02-05-2016 11:58:58.721 UTC Debug pjutils.cpp:1662: Logging SAS Call-ID marker, 
Call-ID uFWppiG31L9INSavTJ3DVA..
02-05-2016 11:58:58.721 UTC Debug thread_dispatcher.cpp:253: Queuing cloned 
received message 0x7fc4582a3908 for worker threads
02-05-2016 11:58:58.721 UTC Debug thread_dispatcher.cpp:149: Worker thread 
dequeue message 0x7fc4582a3908
02-05-2016 11:58:58.721 UTC Debug pjsip: sip_endpoint.c Distributing rdata to 
modules: Request msg REGISTER/cseq=2 (rdata0x7fc4582a3908)
02-05-2016 11:58:58.721 UTC Debug uri_classifier.cpp:167: home domain: true, 
local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: 
true, treat_number_as_phone: false
02-05-2016 11:58:58.721 UTC Debug uri_classifier.cpp:197: Classified URI as 4
02-05-2016 11:58:58.721 UTC Debug authentication.cpp:775: Authentication module 
invoked
02-05-2016 11:58:58.722 UTC Debug authentication.cpp:683: Authorization header 
in request
02-05-2016 11:58:58.722 UTC Debug authentication.cpp:789: Request needs 
authentication
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:195: Key 
impi\\6505550...@reflexion.net hashes to vbucket 82 via hash 0x5da703d2
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:367: 1 read replicas for 
key impi\\6505550...@reflexion.net
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:402: Attempt to read from 
replica 0 (connection 0x7fc490169570)
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:780: Fetch result
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:788: Found record on 
replica
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:410: Read for 
impi\\6505550...@reflexion.net on replica 0 returned SUCCESS
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:453: Read 436 bytes from 
table impi key 6505550...@reflexion.net, CAS = 709
02-05-2016 11:58:58.722 UTC Debug impistore.cpp:786: Retrieved IMPI for 
6505550...@reflexion.net
{"authChallenges":[{"type":"digest","nonce":"59befec44c393425","nc":2,"expires":1462190360,"correlator":"z9hG4bKPjiIZNq6vOtwCltpNKAhVMOBFxPu8Jj2ns","realm":"reflexion.net","qop":"auth","ha1":"64c53536d6c05353f8ebfc537561dd18"},{"type":"digest","nonce":"1112f2f47c2ad9a7","nc":1,"expires":1462190378,"correlator":"z9hG4bKPjHM54OLfnQtTOM.RWf5az9ARHQxDziPtD","realm":"reflexion.net","qop":"auth","ha1":"64c53536d6c05353f8ebfc537561dd18"}]}
02-05-2016 11:58:58.722 UTC Debug authentication.cpp:908: Verify authentication 
information in request
02-05-2016 11:58:58.722 UTC Debug authentication.cpp:325: Found Digest HA1 = 
64c53536d6c05353f8ebfc537561dd18
02-05-2016 11:58:58.722 UTC Debug authentication.cpp:917: Request authenticated 
successfully
02-05-2016 11:58:58.722 UTC Debug impistore.cpp:648: Storing IMPI for 
6505550...@reflexion.net
{"authChallenges":[{"type":"digest","nonce":"59befec44c393425","nc":2,"expires":1462190360,"correlator":"z9hG4bKPjiIZNq6vOtwCltpNKAhVMOBFxPu8Jj2ns","realm":"reflexion.net","qop":"auth","ha1":"64c53536d6c05353f8ebfc537561dd18"},{"type":"digest","nonce":"1112f2f47c2ad9a7","nc":2,"expires":1462190378,"correlator":"z9hG4bKPjHM54OLfnQtTOM.RWf5az9ARHQxDziPtD","realm":"reflexion.net","qop":"auth","ha1":"64c53536d6c05353f8ebfc537561dd18"}]}
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:542: Writing 436 bytes to 
table impi key 6505550...@reflexion.net, CAS = 709, expiry = 40
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:195: Key 
impi\\6505550...@reflexion.net hashes to vbucket 82 via hash 0x5da703d2
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:562: 1 write replicas for 
key impi\\6505550...@reflexion.net
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:616: Attempt conditional 
write to vbucket 82 on replica 0 (connection 0x7fc490169570), CAS = 709, expiry 
= 40
02-05-2016 11:58:58.722 UTC Debug memcachedstore.cpp:657: Conditional write 
succeeded to replica 0
02-05-2016 11:58:58.722 UTC Debug uri_classifier.cpp:167: home domain: true, 
local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: 
true, treat_number_as_phone: false
02-05-2016 11:58:58.722 UTC Debug uri_classifier.cpp:197: Classified URI as 4
02-05-2016 11:58:58.722 UTC Debug uri_classifier.cpp:167: home domain: false, 
local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: 
true, treat_number_as_phone: false
02-05-2016 11:58:58.722 UTC Debug uri_classifier.cpp:197: Classified URI as 5
02-05-2016 11:58:58.722 UTC Debug basicproxy.cpp:92: Process REGISTER request
02-05-2016 11:58:58.723 UTC Verbose sproutletproxy.cpp:503: Sproutlet Proxy 
transaction (0x7fc49026bcd0) created
02-05-2016 11:58:58.723 UTC Debug basicproxy.cpp:1271: Report SAS start marker 
- trail (1c0)
02-05-2016 11:58:58.723 UTC Debug pjutils.cpp:674: Cloned Request msg 
REGISTER/cseq=2 (rdata0x7fc4582a3908) to tdta0x7fc490276560
02-05-2016 11:58:58.723 UTC Debug pjsip: tsx0x7fc49022f Transaction created for 
Request msg REGISTER/cseq=2 (rdata0x7fc4582a3908)
02-05-2016 11:58:58.723 UTC Debug pjsip: tsx0x7fc49022f Incoming Request msg 
REGISTER/cseq=2 (rdata0x7fc4582a3908) in state Null
02-05-2016 11:58:58.723 UTC Debug pjsip: tsx0x7fc49022f State changed from Null 
to Trying, event=RX_MSG
02-05-2016 11:58:58.723 UTC Debug basicproxy.cpp:213: tsx0x7fc49022faa8 - 
tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying
02-05-2016 11:58:58.723 UTC Debug pjsip:       endpoint Response msg 
408/REGISTER/cseq=2 (tdta0x7fc490230210) created
02-05-2016 11:58:58.723 UTC Debug sproutletproxy.cpp:124: Find target Sproutlet 
for request
02-05-2016 11:58:58.723 UTC Debug sproutletproxy.cpp:163: Found next routable 
URI: sip:sprout.reflexion.net:5054;transport=TCP;lr;orig
02-05-2016 11:58:58.723 UTC Debug sproutletproxy.cpp:334: Possible service name 
- sprout
02-05-2016 11:58:58.723 UTC Debug sproutletproxy.cpp:340: Hostname - 
reflexion.net
02-05-2016 11:58:58.723 UTC Debug sproutletproxy.cpp:334: Possible service name 
- sprout
02-05-2016 11:58:58.723 UTC Debug sproutletproxy.cpp:340: Hostname - 
reflexion.net
02-05-2016 11:58:58.723 UTC Debug sproutletproxy.cpp:334: Possible service name 
- sprout
02-05-2016 11:58:58.723 UTC Debug sproutletproxy.cpp:340: Hostname - 
reflexion.net
02-05-2016 11:58:58.723 UTC Debug sproutletproxy.cpp:195: No Sproutlet found 
using service name or host
02-05-2016 11:58:58.723 UTC Debug sproutletproxy.cpp:201: Find default service 
for port 5054
02-05-2016 11:58:58.723 UTC Debug scscfsproutlet.cpp:372: S-CSCF Transaction 
(0x7fc49017d7e0) created
02-05-2016 11:58:58.723 UTC Verbose sproutletproxy.cpp:1159: Created Sproutlet 
scscf-0x7fc49017d7e0 for Request msg REGISTER/cseq=2 (tdta0x7fc490276560)
02-05-2016 11:58:58.723 UTC Verbose sproutletproxy.cpp:2067: Routing Request 
msg REGISTER/cseq=2 (tdta0x7fc490276560) (1337 bytes) to downstream sproutlet 
scscf:

02-05-2016 11:53:19.632 UTC Debug baseresolver.cpp:361: Found 1 A/AAAA records, 
randomizing
02-05-2016 11:53:19.632 UTC Debug baseresolver.cpp:503: 84.39.45.7:5054 
transport 6 is not blacklisted
02-05-2016 11:53:19.632 UTC Debug baseresolver.cpp:382: Added a server, now 
have 1 of 1
02-05-2016 11:53:19.632 UTC Debug baseresolver.cpp:394: Have enough targets
02-05-2016 11:53:19.632 UTC Debug connection_pool.cpp:178: Successfully 
resolved sprout.reflexion.net to IPv4 address
02-05-2016 11:53:19.632 UTC Verbose pjsip: tcpc0x7f66f402 TCP client transport 
created
02-05-2016 11:53:19.632 UTC Verbose pjsip: tcpc0x7f66f402 TCP transport 
192.168.0.4:44110 is connecting to 84.39.45.7:5054...
02-05-2016 11:53:19.632 UTC Debug connection_pool.cpp:248: Created transport 
tcpc0x7f66f402ed88 in slot 5 (192.168.0.4:44110 to 84.39.45.7:5054)
02-05-2016 11:53:19.635 UTC Verbose pjsip: tcpc0x7f66f402 TCP transport 
192.168.0.4:44110 is connected to 84.39.45.7:5054
02-05-2016 11:53:19.635 UTC Debug connection_pool.cpp:336: Transport 
tcpc0x7f66f402ed88 in slot 5 has connected
02-05-2016 11:53:23.069 UTC Verbose pjsip:    tcplis:5058 TCP listener 
192.168.0.4:5058: got incoming TCP connection from 192.168.0.4:47870, sock=171
02-05-2016 11:53:23.069 UTC Verbose pjsip: tcps0x7f66fc01 TCP server transport 
created
02-05-2016 11:53:23.069 UTC Debug pjsip: sip_endpoint.c Processing incoming 
message: Request msg OPTIONS/cseq=852584 (rdata0x7f66fc012850)
02-05-2016 11:53:23.069 UTC Verbose common_sip_processing.cpp:120: RX 346 bytes 
Request msg OPTIONS/cseq=852584 (rdata0x7f66fc012850) from TCP 
192.168.0.4:47870:
--start msg--

OPTIONS sip:poll-sip@192.168.0.4:5058 SIP/2.0
Via: SIP/2.0/TCP 192.168.0.4;rport;branch=z9hG4bK-852584
Max-Forwards: 2
To: <sip:poll-sip@192.168.0.4:5058>
From: poll-sip <sip:poll-sip@192.168.0.4>;tag=852584
Call-ID: poll-sip-852584
CSeq: 852584 OPTIONS
Contact: <sip:192.168.0.4>
Accept: application/sdp
Content-Length: 0
User-Agent: poll-sip


--end msg--
02-05-2016 11:53:23.069 UTC Debug uri_classifier.cpp:167: home domain: false, 
local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: 
true, treat_number_as_phone: false
02-05-2016 11:53:23.069 UTC Debug uri_classifier.cpp:197: Classified URI as 3
02-05-2016 11:53:23.069 UTC Debug common_sip_processing.cpp:212: Skipping SAS 
logging for OPTIONS request
02-05-2016 11:53:23.069 UTC Debug thread_dispatcher.cpp:253: Queuing cloned 
received message 0x7f66fc46cb08 for worker threads
02-05-2016 11:53:23.069 UTC Debug thread_dispatcher.cpp:149: Worker thread 
dequeue message 0x7f66fc46cb08
02-05-2016 11:53:23.069 UTC Debug pjsip: sip_endpoint.c Distributing rdata to 
modules: Request msg OPTIONS/cseq=852584 (rdata0x7f66fc46cb08)
02-05-2016 11:53:23.069 UTC Debug uri_classifier.cpp:167: home domain: false, 
local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: 
true, treat_number_as_phone: false
02-05-2016 11:53:23.069 UTC Debug uri_classifier.cpp:197: Classified URI as 3
02-05-2016 11:53:23.069 UTC Debug pjsip:       endpoint Response msg 
200/OPTIONS/cseq=852584 (tdta0x7f6700287cf0) created
02-05-2016 11:53:23.069 UTC Verbose common_sip_processing.cpp:136: TX 278 bytes 
Response msg 200/OPTIONS/cseq=852584 (tdta0x7f6700287cf0) to TCP 
192.168.0.4:47870:
--start msg--

SIP/2.0 200 OK
Via: SIP/2.0/TCP 
192.168.0.4;rport=47870;received=192.168.0.4;branch=z9hG4bK-852584
Call-ID: poll-sip-852584
From: "poll-sip" <sip:poll-sip@192.168.0.4>;tag=852584
To: <sip:poll-sip@192.168.0.4>;tag=z9hG4bK-852584
CSeq: 852584 OPTIONS
Content-Length:  0


--end msg--
02-05-2016 11:53:23.069 UTC Debug common_sip_processing.cpp:254: Skipping SAS 
logging for OPTIONS response
02-05-2016 11:53:23.069 UTC Debug pjsip: tdta0x7f670028 Destroying txdata 
Response msg 200/OPTIONS/cseq=852584 (tdta0x7f6700287cf0)
02-05-2016 11:53:23.069 UTC Debug thread_dispatcher.cpp:193: Worker thread 
completed processing message 0x7f66fc46cb08
02-05-2016 11:53:23.069 UTC Debug thread_dispatcher.cpp:199: Request latency = 
91us
02-05-2016 11:53:24.070 UTC Verbose pjsip: tcps0x7f66fc01 TCP connection closed
02-05-2016 11:53:24.070 UTC Debug connection_tracker.cpp:91: Connection 
0x7f66fc012518 has been destroyed
02-05-2016 11:53:24.070 UTC Verbose pjsip: tcps0x7f66fc01 TCP transport 
destroyed with reason 70016: End of file (PJ_EEOF)
02-05-2016 11:53:25.633 UTC Status connection_pool.cpp:447: Recycle TCP 
connection slot 44
02-05-2016 11:53:25.633 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:53:25.633 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:53:25.633 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:53:25.633 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:53:25.633 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:53:25.633 UTC Debug dnscachedresolver.cpp:326: Pulling 1 records 
from cache for sprout.reflexion.net A
02-05-2016 11:53:25.633 UTC Debug baseresolver.cpp:361: Found 1 A/AAAA records, 
randomizing
02-05-2016 11:53:25.633 UTC Debug baseresolver.cpp:503: 84.39.45.7:5054 
transport 6 is not blacklisted
02-05-2016 11:53:25.633 UTC Debug baseresolver.cpp:382: Added a server, now 
have 1 of 1
02-05-2016 11:53:25.633 UTC Debug baseresolver.cpp:394: Have enough targets
02-05-2016 11:53:25.633 UTC Debug connection_pool.cpp:178: Successfully 
resolved sprout.reflexion.net to IPv4 address
02-05-2016 11:53:25.633 UTC Verbose pjsip: tcpc0x7f66f413 TCP client transport 
created
02-05-2016 11:53:25.633 UTC Verbose pjsip: tcpc0x7f66f413 TCP transport 
192.168.0.4:60402 is connecting to 84.39.45.7:5054...
02-05-2016 11:53:25.633 UTC Debug connection_pool.cpp:248: Created transport 
tcpc0x7f66f413b968 in slot 44 (192.168.0.4:60402 to 84.39.45.7:5054)
02-05-2016 11:53:25.636 UTC Verbose pjsip: tcpc0x7f66f405 TCP transport 
destroyed normally
02-05-2016 11:53:25.637 UTC Verbose pjsip: tcpc0x7f66f413 TCP transport 
192.168.0.4:60402 is connected to 84.39.45.7:5054
02-05-2016 11:53:25.637 UTC Debug connection_pool.cpp:336: Transport 
tcpc0x7f66f413b968 in slot 44 has connected
02-05-2016 11:53:28.322 UTC Verbose pjsip:    tcplis:5058 TCP listener 
192.168.0.4:5058: got incoming TCP connection from 84.39.45.7:39437, sock=148
02-05-2016 11:53:28.322 UTC Verbose pjsip: tcps0x7f66fc01 TCP server transport 
created
02-05-2016 11:53:28.322 UTC Verbose pjsip: tcps0x7f66fc01 TCP connection closed
02-05-2016 11:53:28.322 UTC Verbose pjsip: tcps0x7f66fc01 TCP transport 
destroyed with reason 70016: End of file (PJ_EEOF)
^C
root@bono:~# tail -f /var/log/bono/bono_current.txt
02-05-2016 11:58:42.716 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:42.716 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:58:42.716 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:58:42.716 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:58:42.716 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:58:42.716 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:58:42.716 UTC Debug dnscachedresolver.cpp:326: Pulling 0 records 
from cache for sprout.reflexion.net A
02-05-2016 11:58:42.716 UTC Debug baseresolver.cpp:361: Found 0 A/AAAA records, 
randomizing
02-05-2016 11:58:42.716 UTC Debug baseresolver.cpp:420: Adding 0 servers from 
blacklist
02-05-2016 11:58:42.716 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:43.716 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:58:43.716 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:58:43.717 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:58:43.717 UTC Debug dnscachedresolver.cpp:326: Pulling 0 records 
from cache for sprout.reflexion.net A
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:361: Found 0 A/AAAA records, 
randomizing
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:420: Adding 0 servers from 
blacklist
02-05-2016 11:58:43.717 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:58:43.717 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:58:43.717 UTC Debug dnscachedresolver.cpp:326: Pulling 0 records 
from cache for sprout.reflexion.net A
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:361: Found 0 A/AAAA records, 
randomizing
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:420: Adding 0 servers from 
blacklist
02-05-2016 11:58:43.717 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:58:43.717 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:58:43.717 UTC Debug dnscachedresolver.cpp:326: Pulling 0 records 
from cache for sprout.reflexion.net A
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:361: Found 0 A/AAAA records, 
randomizing
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:420: Adding 0 servers from 
blacklist
02-05-2016 11:58:43.717 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:58:43.717 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:58:43.717 UTC Debug dnscachedresolver.cpp:326: Pulling 0 records 
from cache for sprout.reflexion.net A
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:361: Found 0 A/AAAA records, 
randomizing
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:420: Adding 0 servers from 
blacklist
02-05-2016 11:58:43.717 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:58:43.717 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:58:43.717 UTC Debug dnscachedresolver.cpp:326: Pulling 0 records 
from cache for sprout.reflexion.net A
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:361: Found 0 A/AAAA records, 
randomizing
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:420: Adding 0 servers from 
blacklist
02-05-2016 11:58:43.717 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:58:43.717 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:58:43.717 UTC Debug dnscachedresolver.cpp:326: Pulling 0 records 
from cache for sprout.reflexion.net A
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:361: Found 0 A/AAAA records, 
randomizing
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:420: Adding 0 servers from 
blacklist
02-05-2016 11:58:43.717 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:58:43.717 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:58:43.717 UTC Debug dnscachedresolver.cpp:326: Pulling 0 records 
from cache for sprout.reflexion.net A
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:361: Found 0 A/AAAA records, 
randomizing
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:420: Adding 0 servers from 
blacklist
02-05-2016 11:58:43.717 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:58:43.717 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:58:43.717 UTC Debug dnscachedresolver.cpp:326: Pulling 0 records 
from cache for sprout.reflexion.net A
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:361: Found 0 A/AAAA records, 
randomizing
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:420: Adding 0 servers from 
blacklist
02-05-2016 11:58:43.717 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:86: SIPResolver::resolve for 
name sprout.reflexion.net, port 5054, transport 6, family 2
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:513: Attempt to parse 
sprout.reflexion.net as IP address
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:128: Port is specified
02-05-2016 11:58:43.717 UTC Debug sipresolver.cpp:296: Perform A/AAAA record 
lookup only, name = sprout.reflexion.net
02-05-2016 11:58:43.717 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
sprout.reflexion.net type 1
02-05-2016 11:58:43.717 UTC Debug dnscachedresolver.cpp:326: Pulling 0 records 
from cache for sprout.reflexion.net A
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:361: Found 0 A/AAAA records, 
randomizing
02-05-2016 11:58:43.717 UTC Debug baseresolver.cpp:420: Adding 0 servers from 
blacklist
02-05-2016 11:58:43.717 UTC Error connection_pool.cpp:214: Failed to resolve 
sprout.reflexion.net to an IP address - Not found (PJ_ENOTFOUND)
02-05-2016 11:58:43.729 UTC Verbose pjsip:    tcplis:5058 TCP listener 
192.168.0.4:5058: got incoming TCP connection from 192.168.0.4:48434, sock=86
02-05-2016 11:58:43.729 UTC Verbose pjsip: tcps0x7f66fc33 TCP server transport 
created
02-05-2016 11:58:43.730 UTC Debug pjsip: sip_endpoint.c Processing incoming 
message: Request msg OPTIONS/cseq=852905 (rdata0x7f66fc338370)
02-05-2016 11:58:43.730 UTC Verbose common_sip_processing.cpp:120: RX 346 bytes 
Request msg OPTIONS/cseq=852905 (rdata0x7f66fc338370) from TCP 
192.168.0.4:48434:
--start msg--

OPTIONS sip:poll-sip@192.168.0.4:5058 SIP/2.0
Via: SIP/2.0/TCP 192.168.0.4;rport;branch=z9hG4bK-852905
Max-Forwards: 2
To: <sip:poll-sip@192.168.0.4:5058>
From: poll-sip <sip:poll-sip@192.168.0.4>;tag=852905
Call-ID: poll-sip-852905
CSeq: 852905 OPTIONS
Contact: <sip:192.168.0.4>
Accept: application/sdp
Content-Length: 0
User-Agent: poll-sip



02-05-2016 11:58:08.437 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:58:10.116 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:58:10.116 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:58:17.289 UTC Debug alarm.cpp:254: Reraising alarms
02-05-2016 11:58:17.290 UTC Debug alarm.cpp:360: AlarmReqAgent: queue overflowed
02-05-2016 11:58:17.290 UTC Status alarm.cpp:72: homestead issued 1501.1 alarm
02-05-2016 11:58:20.026 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:58:20.026 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:58:30.046 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:58:30.046 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:58:40.208 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:58:40.208 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:58:40.547 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550898%40reflexion.net/av, args impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:58:40.547 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:58:40.547 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:58:40.547 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:58:40.548 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:58:40.548 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:58:40.548 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:58:40.548 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:58:40.549 UTC Debug communicationmonitor.cpp:82: Checking 
communication changes - successful attempts 2, failures 0
02-05-2016 11:58:40.549 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 64c53536d6c05353f8ebfc537561dd18 from cache
02-05-2016 11:58:40.549 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550898%40reflexion.net/av, args 
impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:58:40.596 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:58:40.596 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:58:40.596 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:58:40.596 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:58:40.596 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:58:40.596 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:58:40.596 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190320596563
02-05-2016 11:58:40.596 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:58:40.597 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:58:40.597 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:58:40.597 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:58:40.597 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:58:40.597 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:58:47.289 UTC Debug alarm.cpp:254: Reraising alarms
02-05-2016 11:58:47.290 UTC Debug alarm.cpp:360: AlarmReqAgent: queue overflowed
02-05-2016 11:58:47.290 UTC Status alarm.cpp:72: homestead issued 1501.1 alarm
02-05-2016 11:58:50.112 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:58:50.112 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:58:58.666 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550898%40reflexion.net/av, args impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:58:58.666 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:58:58.666 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:58:58.666 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:58:58.666 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:58:58.666 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:58:58.666 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:58:58.667 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:58:58.668 UTC Debug communicationmonitor.cpp:82: Checking 
communication changes - successful attempts 2, failures 0
02-05-2016 11:58:58.668 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 64c53536d6c05353f8ebfc537561dd18 from cache
02-05-2016 11:58:58.668 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550898%40reflexion.net/av, args 
impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:58:58.725 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:58:58.725 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:58:58.725 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:58:58.725 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:58:58.725 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:58:58.725 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:58:58.725 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190338725285
02-05-2016 11:58:58.725 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:58:58.725 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:58:58.726 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:58:58.726 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:58:58.726 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:58:58.726 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:00.136 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:59:00.136 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:59:05.310 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550737%40reflexion.net/av, args impu=sip%3A6505550737%40reflexion.net
02-05-2016 11:59:05.310 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:05.310 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:05.310 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:05.310 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:05.310 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:05.310 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:05.311 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:05.312 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 1969b38133774d3a63f87837ac03d3f8 from cache
02-05-2016 11:59:05.312 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550737%40reflexion.net/av, args 
impu=sip%3A6505550737%40reflexion.net
02-05-2016 11:59:05.368 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:05.368 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:05.368 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:05.368 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:05.368 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:05.368 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:05.368 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190345368766
02-05-2016 11:59:05.368 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:05.369 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:05.369 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:05.369 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:05.369 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:05.369 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:08.851 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550898%40reflexion.net/av, args impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:08.851 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:08.851 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:08.851 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:08.851 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:08.851 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:08.851 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:08.852 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:08.853 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 64c53536d6c05353f8ebfc537561dd18 from cache
02-05-2016 11:59:08.853 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550898%40reflexion.net/av, args 
impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:08.910 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:08.910 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:08.910 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:08.910 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:08.910 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:08.910 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:08.910 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190348910644
02-05-2016 11:59:08.910 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:08.911 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:08.911 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:08.911 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:08.911 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:08.911 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:08.911 UTC Info load_monitor.cpp:212: Accepted 100.000000% of 
requests, latency error = -0.984750, overload responses = 0
02-05-2016 11:59:08.911 UTC Status load_monitor.cpp:260: Maximum incoming 
request rate/second unchanged - only handled 45 requests in last 253628ms, 
minimum threshold for a change is 12681.400391
02-05-2016 11:59:10.282 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:59:10.282 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:59:12.714 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550898%40reflexion.net/av, args impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:12.714 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:12.714 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:12.714 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:12.714 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:12.714 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:12.714 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:12.714 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:12.715 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 64c53536d6c05353f8ebfc537561dd18 from cache
02-05-2016 11:59:12.715 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550898%40reflexion.net/av, args 
impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:12.770 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:12.770 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:12.770 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:12.770 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:12.770 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:12.770 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:12.770 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190352770756
02-05-2016 11:59:12.770 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:12.771 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:12.771 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:12.771 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:12.771 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:12.771 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:14.173 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550983%40reflexion.net/av, args impu=sip%3A6505550983%40reflexion.net
02-05-2016 11:59:14.173 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:14.173 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:14.173 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:14.173 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:14.173 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:14.174 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:14.174 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:14.175 UTC Debug communicationmonitor.cpp:82: Checking 
communication changes - successful attempts 8, failures 0
02-05-2016 11:59:14.175 UTC Debug handlers.cpp:194: Got authentication vector 
with digest eb451cb76c2f907b30e0acdba421dd7c from cache
02-05-2016 11:59:14.175 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550983%40reflexion.net/av, args 
impu=sip%3A6505550983%40reflexion.net
02-05-2016 11:59:14.230 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:14.230 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:14.230 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:14.230 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:14.230 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:14.230 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:14.230 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190354230351
02-05-2016 11:59:14.230 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:14.230 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:14.231 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:14.231 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:14.231 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:14.231 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:16.596 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550737%40reflexion.net/av, args impu=sip%3A6505550737%40reflexion.net
02-05-2016 11:59:16.596 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:16.596 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:16.596 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:16.596 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:16.596 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:16.596 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:16.597 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:16.598 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 1969b38133774d3a63f87837ac03d3f8 from cache
02-05-2016 11:59:16.598 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550737%40reflexion.net/av, args 
impu=sip%3A6505550737%40reflexion.net
02-05-2016 11:59:16.721 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:16.721 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:16.721 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:16.721 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:16.721 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:16.721 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:16.721 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190356721161
02-05-2016 11:59:16.721 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:16.721 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:16.722 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:16.722 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:16.722 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:16.722 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:17.290 UTC Debug alarm.cpp:254: Reraising alarms
02-05-2016 11:59:17.290 UTC Debug alarm.cpp:360: AlarmReqAgent: queue overflowed
02-05-2016 11:59:17.290 UTC Status alarm.cpp:72: homestead issued 1501.1 alarm
02-05-2016 11:59:19.710 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550898%40reflexion.net/av, args impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:19.710 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:19.710 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:19.710 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:19.710 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:19.710 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:19.710 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:19.711 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:19.711 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 64c53536d6c05353f8ebfc537561dd18 from cache
02-05-2016 11:59:19.711 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550898%40reflexion.net/av, args 
impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:19.766 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:19.766 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:19.766 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:19.766 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:19.766 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:19.766 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:19.766 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190359766537
02-05-2016 11:59:19.766 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:19.766 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:19.767 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:19.767 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:19.767 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:19.767 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:20.195 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:59:20.196 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:59:29.292 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550737%40reflexion.net/av, args impu=sip%3A6505550737%40reflexion.net
02-05-2016 11:59:29.292 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:29.292 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:29.293 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:29.293 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:29.293 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:29.293 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:29.293 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:29.294 UTC Debug communicationmonitor.cpp:82: Checking 
communication changes - successful attempts 6, failures 0
02-05-2016 11:59:29.294 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 1969b38133774d3a63f87837ac03d3f8 from cache
02-05-2016 11:59:29.294 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550737%40reflexion.net/av, args 
impu=sip%3A6505550737%40reflexion.net
02-05-2016 11:59:29.351 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:29.351 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:29.351 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:29.351 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:29.351 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:29.351 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:29.351 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190369351716
02-05-2016 11:59:29.351 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:29.352 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:29.352 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:29.352 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:29.352 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:29.352 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:30.222 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:59:30.222 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:59:30.822 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550898%40reflexion.net/av, args impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:30.822 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:30.822 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:30.822 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:30.822 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:30.822 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:30.822 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:30.823 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:30.823 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 64c53536d6c05353f8ebfc537561dd18 from cache
02-05-2016 11:59:30.823 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550898%40reflexion.net/av, args 
impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:30.878 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:30.878 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:30.878 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:30.878 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:30.878 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:30.878 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:30.878 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190370878667
02-05-2016 11:59:30.878 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:30.879 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:30.879 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:30.879 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:30.879 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:30.879 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:37.476 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550737%40reflexion.net/av, args impu=sip%3A6505550737%40reflexion.net
02-05-2016 11:59:37.476 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:37.476 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:37.476 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:37.476 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:37.476 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:37.476 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:37.477 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:37.478 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 1969b38133774d3a63f87837ac03d3f8 from cache
02-05-2016 11:59:37.478 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550737%40reflexion.net/av, args 
impu=sip%3A6505550737%40reflexion.net
02-05-2016 11:59:37.545 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:37.545 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:37.545 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:37.545 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:37.545 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:37.545 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:37.545 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190377545602
02-05-2016 11:59:37.545 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:37.545 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:37.546 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:37.546 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:37.546 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:37.546 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:40.379 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:59:40.379 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:59:41.018 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550898%40reflexion.net/av, args impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:41.018 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:41.018 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:41.018 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:41.018 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:41.018 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:41.018 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:41.019 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:41.020 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 64c53536d6c05353f8ebfc537561dd18 from cache
02-05-2016 11:59:41.020 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550898%40reflexion.net/av, args 
impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:41.074 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:41.074 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:41.074 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:41.074 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:41.074 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:41.074 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:41.074 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190381074626
02-05-2016 11:59:41.074 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:41.074 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:41.075 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:41.075 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:41.075 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:41.075 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:44.880 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550898%40reflexion.net/av, args impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:44.880 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:44.880 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:44.880 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:44.880 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:44.880 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:44.880 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:44.881 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:44.882 UTC Debug communicationmonitor.cpp:82: Checking 
communication changes - successful attempts 8, failures 0
02-05-2016 11:59:44.882 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 64c53536d6c05353f8ebfc537561dd18 from cache
02-05-2016 11:59:44.882 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550898%40reflexion.net/av, args 
impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:44.931 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:44.931 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:44.931 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:44.931 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:44.931 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:44.931 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:44.931 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190384931584
02-05-2016 11:59:44.931 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:44.931 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:44.932 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:44.932 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:44.932 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:44.932 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:46.348 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550983%40reflexion.net/av, args impu=sip%3A6505550983%40reflexion.net
02-05-2016 11:59:46.348 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:46.348 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:46.348 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:46.348 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:46.348 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:46.348 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:46.349 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:46.350 UTC Debug handlers.cpp:194: Got authentication vector 
with digest eb451cb76c2f907b30e0acdba421dd7c from cache
02-05-2016 11:59:46.350 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550983%40reflexion.net/av, args 
impu=sip%3A6505550983%40reflexion.net
02-05-2016 11:59:46.404 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:46.404 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:46.404 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:46.404 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:46.404 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:46.404 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:46.404 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190386404413
02-05-2016 11:59:46.404 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:46.404 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:46.405 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:46.405 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:46.405 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:46.405 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:46.405 UTC Info load_monitor.cpp:212: Accepted 100.000000% of 
requests, latency error = -0.986060, overload responses = 0
02-05-2016 11:59:46.405 UTC Status load_monitor.cpp:260: Maximum incoming 
request rate/second unchanged - only handled 24 requests in last 37492ms, 
minimum threshold for a change is 1874.599976
02-05-2016 11:59:47.290 UTC Debug alarm.cpp:254: Reraising alarms
02-05-2016 11:59:47.290 UTC Debug alarm.cpp:360: AlarmReqAgent: queue overflowed
02-05-2016 11:59:47.290 UTC Status alarm.cpp:72: homestead issued 1501.1 alarm
02-05-2016 11:59:48.865 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550737%40reflexion.net/av, args impu=sip%3A6505550737%40reflexion.net
02-05-2016 11:59:48.865 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:48.865 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:48.865 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:48.865 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:48.865 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:48.865 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:48.866 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:48.867 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 1969b38133774d3a63f87837ac03d3f8 from cache
02-05-2016 11:59:48.867 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550737%40reflexion.net/av, args 
impu=sip%3A6505550737%40reflexion.net
02-05-2016 11:59:48.934 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:48.934 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:48.934 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:48.934 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:48.934 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:48.934 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:48.934 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190388934706
02-05-2016 11:59:48.934 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:48.935 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:48.935 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:48.935 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:48.935 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:48.935 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:50.290 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
02-05-2016 11:59:50.290 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
02-05-2016 11:59:51.908 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/6505550898%40reflexion.net/av, args impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:51.908 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID 6505550...@reflexion.net, public ID sip:6505550...@reflexion.net, 
scheme Unknown, authorization
02-05-2016 11:59:51.908 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 6505550...@reflexion.net/sip:6505550...@reflexion.net
02-05-2016 11:59:51.908 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:51.908 UTC Debug cache.cpp:670: Looking for authentication 
vector for 6505550...@reflexion.net
02-05-2016 11:59:51.908 UTC Debug cache.cpp:682: Checking public ID 
sip:6505550...@reflexion.net
02-05-2016 11:59:51.908 UTC Debug cache.cpp:692: Issuing cache query
02-05-2016 11:59:51.909 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
02-05-2016 11:59:51.909 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 64c53536d6c05353f8ebfc537561dd18 from cache
02-05-2016 11:59:51.909 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/6505550898%40reflexion.net/av, args 
impu=sip%3A6505550898%40reflexion.net
02-05-2016 11:59:51.986 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3Areflexion.net/reg-data, args (null)
02-05-2016 11:59:51.986 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID , public ID sip:reflexion.net
02-05-2016 11:59:51.986 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "call"}'
02-05-2016 11:59:51.986 UTC Debug handlers.cpp:1042: New value of _type is 2
02-05-2016 11:59:51.986 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
02-05-2016 11:59:51.986 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
02-05-2016 11:59:51.986 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1462190391986192
02-05-2016 11:59:51.986 UTC Debug cache.cpp:347: Issuing get for key 
sip:reflexion.net
02-05-2016 11:59:51.986 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
02-05-2016 11:59:51.987 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
02-05-2016 11:59:51.987 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is empty, registration state is 
NOT_REGISTERED, and the charging addresses are empty
02-05-2016 11:59:51.987 UTC Debug handlers.cpp:1352: Handling call
02-05-2016 11:59:51.987 UTC Verbose httpstack.cpp:69: Sending response 404 to 
request for URL /impu/sip%3Areflexion.net/reg-data, args (null)

_______________________________________________
Clearwater mailing list
Clearwater@lists.projectclearwater.org
http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org