Dear all,



I have deployed the Clearwater IMS on OpenStack using the Clearwater heat 
templates, I have registered the users in homestead successfully using the bulk 
create method. when I try to register the user using X-lite or zoiper it gives 
error 403 or sometimes 504 and unable to register 




when I looked into the logs it shows that it is unable to get the 
authentication vector it appears in homestead and sprout. I have enabled the 
debug_level=5 and captured the log files for:

bono


sprout


homestead 


users registered in homestead_cache “impi”





your help is required to solve this issue I have done the deployment multiple 
times but the error remains the same.

waiting for your kind response 




thanks 

Tahir






Sent from Windows Mail
 private_id                   | digest_ha1                       | digest_qop | 
                                           digest_realm
------------------------------+----------------------------------+------------+-
                                           ------------------
 [email protected] | 1013fe3f0697f5bcc21a8e31884a24ac |       null | 
                                           xflowresearch.com
 [email protected] | 8ee93ba3ed5b4ed4e8a73dc4557fe529 |       null | 
                                           xflowresearch.com
 [email protected] | 8205240279ad4afd7a4c07392cc99c96 |       null | 
                                           xflowresearch.com
 [email protected] | 2c478859076b7d6ad0ad6e97ee88e1b5 |       null | 
                                           xflowresearch.com
 [email protected] | 2c422aa54c2619add55c62e36f47ae47 |       null | 
                                           xflowresearch.com
 [email protected] | 75fae6a5677270dbf7312cff6c7c73fe |       null | 
                                           xflowresearch.com
 [email protected] | 4ffea7cf8506bedeaab82529c67a9e58 |       null | 
                                           xflowresearch.com
 [email protected] | 50bc2a0434f3bfa384631c2f44fc8be5 |       null | 
                                           xflowresearch.com
 [email protected] | add744304661e9ca8f3cb6df9fe52fdd |       null | 
                                           xflowresearch.com
 [email protected] | 14a776643151b0c04e6de49198dee16f |       null | 
                                           xflowresearch.com
 [email protected] | f9e97367933ecaa64736f713192ee2c6 |       null | 
                                           xflowresearch.com
 [email protected] | 03bf2e5d7c8a353ab0ec6446385e5ea0 |       null | 
                                           xflowresearch.com
 [email protected] | c79cec1db8e7c445feb6094aea140e9e |       null | 
                                           xflowresearch.com
 [email protected] | 22c2c550110e205520a9bd068694e887 |       null | 
                                           xflowresearch.com
 [email protected] | 6d8b6f1d94f08b0b96d38fc3cc0bdd4f |       null | 
                                           xflowresearch.com
 [email protected] | 9c1f55e93b0342e3b4acef06ab215e0e |       null | 
                                           xflowresearch.com
 [email protected] | 59b25a52641592d9e28b411e140da7a9 |       null | 
                                           xflowresearch.com
 [email protected] | d28033e7c0f398f245a87a05528d705f |       null | 
                                           xflowresearch.com
 [email protected] | 15afda1e657483bc6bd018ae35d14136 |       null | 
                                           xflowresearch.com
 [email protected] | e2a5ab5d526391f536d4d38f21dd1ee9 |       null | 
                                           xflowresearch.com
 [email protected] | e222d0775aecac04e0abf9292d9a816b |       null | 
                                           xflowresearch.com
 [email protected] | a4f77e28a3c6216455e1091c41b5e292 |       null | 
                                           xflowresearch.com
 [email protected] | 0d003c5de998d310a613f59f922876aa |       null | 
                                           xflowresearch.com
 [email protected] | 915853456718dae6a86b6801965ee2d2 |       null | 
                                           xflowresearch.com
 [email protected] | c4839404bbb553b4bfaccefa9e6b03bc |       null | 
                                           xflowresearch.com
 [email protected] | 6f9703a2629d9d030f8d4517a9d0e75b |       null | 
                                           xflowresearch.com
 [email protected] | 4223ff54a7d3d839f0e003e7b73a8b4f |       null | 
                                           xflowresearch.com
 [email protected] | 8bb33b8ecb07f870f36e3adf1bc58e97 |       null | 
                                           xflowresearch.com
 [email protected] | 33694e60fd7b39ab2c4cc375eca08476 |       null | 
                                           xflowresearch.com
 [email protected] | 9d5b1e6f695af256160b0bd854667d64 |       null | 
                                           xflowresearch.com
 [email protected] | 0a36e1bf4c3aae6dc302728a0f470cbf |       null | 
                                           xflowresearch.com
 [email protected] | 4316aa54c887af214c4389aed8f17adb |       null | 
                                           xflowresearch.com
 [email protected] | 5192917b38f06059e2d2baa5cdd8c5a4 |       null | 
                                           xflowresearch.com
 [email protected] | 166553ed80d7e9ec9aa1d64bd88a6780 |       null | 
                                           xflowresearch.com
 [email protected] | 1a83faa207e5645f6d79b696add1b3a7 |       null | 
                                           xflowresearch.com
 [email protected] | c8078aa34fa2ca4bff7bb3421b8c44e9 |       null | 
                                           xflowresearch.com
 [email protected] | 1ab24ca7b82c3eebb6e4f0d0fe607e6c |       null | 
                                           xflowresearch.com
 [email protected] | 70f7e38d35922775415e1063cf1d42aa |       null | 
                                           xflowresearch.com
 [email protected] | 1b500ed9b981f2e13eac808b9af7cf6c |       null | 
                                           xflowresearch.com
 [email protected] | 564aa391908da3332cbe78c9fc832ed4 |       null | 
                                           xflowresearch.com
 [email protected] | 4fd94d23e213c9fa6b2c5abe84fa4dd3 |       null | 
                                           xflowresearch.com
 [email protected] | 13a7ed1f470334b7681acd558569c022 |       null | 
                                           xflowresearch.com
 [email protected] | 10c97ec4c9d22233cb955ef10396c465 |       null | 
                                           xflowresearch.com
 [email protected] | 11217915571300454ea2eee0d22d7d1c |       null | 
                                           xflowresearch.com
 [email protected] | cf4992a8f3d2abac119faa5bc25b2d15 |       null | 
                                           xflowresearch.com
 [email protected] | ba4464f544242e3c48e1d79cfd7694d1 |       null | 
                                           xflowresearch.com
 [email protected] | 7d867b3ce015b54bac4cc8c62814fdbc |       null | 
                                           xflowresearch.com
 [email protected] | 743d31e29158b17d3e2224ac66fc8269 |       null | 
                                           xflowresearch.com
 [email protected] | d6c742030878bc1b6745cf1d4f2bfb4c |       null | 
                                           xflowresearch.com
 [email protected] | cb148ea0681e572c097332440c9e76e2 |       null | 
                                           xflowresearch.com
 [email protected] | fb1fd66fbca434a6ba31c69d5af6dac0 |       null | 
                                           xflowresearch.com
15-04-2016 11:00:06.698 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1460718006698954
15-04-2016 11:00:06.698 UTC Debug cache.cpp:347: Issuing get for key 
sip:[email protected]
15-04-2016 11:00:06.700 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
15-04-2016 11:00:06.705 UTC Debug cache.cpp:367: Retrieved XML column with TTL 
0 and value <?xml version='1.0' encoding='UTF-8'?><IMSSubscription 
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; 
xsi:noNamespaceSchemaLocation="CxDataType.xsd"><PrivateID>[email protected]</PrivateID><ServiceProfile><InitialFilterCriteria><TriggerPoint><ConditionTypeCNF>0</ConditionTypeCNF><SPT><ConditionNegated>0</ConditionNegated><Group>0</Group><Method>INVITE</Method><Extension
 
/></SPT></TriggerPoint><ApplicationServer><ServerName>sip:mmtel.xflowresearch.com</ServerName><DefaultHandling>0</DefaultHandling></ApplicationServer></InitialFilterCriteria><PublicIdentity><BarringIndication>1</BarringIndication><Identity>sip:[email protected]</Identity></PublicIdentity></ServiceProfile></IMSSubscription>
15-04-2016 11:00:06.705 UTC Debug cache.cpp:435: Found stored XML for 
subscriber, treating as UNREGISTERED state
15-04-2016 11:00:06.705 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
15-04-2016 11:00:06.705 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is not empty, registration state is 
UNREGISTERED, and the charging addresses are empty
15-04-2016 11:00:06.705 UTC Debug handlers.cpp:1163: Subscriber registering 
with new binding
15-04-2016 11:00:06.705 UTC Debug handlers.cpp:1396: Handling authentication 
failure/timeout
15-04-2016 11:00:06.705 UTC Debug handlers.cpp:1443: Sending 200 response (body 
was {"reqtype": "dereg-auth-timeout"})
15-04-2016 11:00:06.705 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impu/sip%3A2010000006%40xflowresearch.com/reg-data, args 
private_id=2010000006%40xflowresearch.com
15-04-2016 11:00:06.709 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:06.709 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:06.709 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:06.709 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:06.709 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:06.709 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:06.709 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:06.710 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:06.711 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:06.711 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:06.732 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:06.732 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:06.732 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:06.732 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:06.732 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:06.732 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:06.732 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:06.733 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:06.733 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:06.733 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:06.774 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:06.775 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:06.775 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:06.775 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:06.775 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:06.775 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:06.775 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:06.775 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:06.777 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:06.777 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:07.016 UTC Verbose httpstack.cpp:293: Process request for URL 
/impu/sip%3A2010000006%40xflowresearch.com/reg-data, args 
private_id=2010000006%40xflowresearch.com
15-04-2016 11:00:07.016 UTC Debug handlers.cpp:1054: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected]
15-04-2016 11:00:07.016 UTC Debug handlers.cpp:998: Determining request type 
from '{"reqtype": "dereg-auth-timeout"}'
15-04-2016 11:00:07.016 UTC Debug handlers.cpp:1042: New value of _type is 7
15-04-2016 11:00:07.016 UTC Debug handlers.cpp:1092: Try to find IMS 
Subscription information in the cache
15-04-2016 11:00:07.016 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:07.016 UTC Debug cassandra_store.cpp:129: Generated Cassandra 
timestamp 1460718007016334
15-04-2016 11:00:07.016 UTC Debug cache.cpp:347: Issuing get for key 
sip:[email protected]
15-04-2016 11:00:07.016 UTC Debug cassandra_store.cpp:755: Failed TWO read for 
get_row. Try ONE
15-04-2016 11:00:07.017 UTC Debug cache.cpp:367: Retrieved XML column with TTL 
0 and value <?xml version='1.0' encoding='UTF-8'?><IMSSubscription 
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; 
xsi:noNamespaceSchemaLocation="CxDataType.xsd"><PrivateID>[email protected]</PrivateID><ServiceProfile><InitialFilterCriteria><TriggerPoint><ConditionTypeCNF>0</ConditionTypeCNF><SPT><ConditionNegated>0</ConditionNegated><Group>0</Group><Method>INVITE</Method><Extension
 
/></SPT></TriggerPoint><ApplicationServer><ServerName>sip:mmtel.xflowresearch.com</ServerName><DefaultHandling>0</DefaultHandling></ApplicationServer></InitialFilterCriteria><PublicIdentity><BarringIndication>1</BarringIndication><Identity>sip:[email protected]</Identity></PublicIdentity></ServiceProfile></IMSSubscription>
15-04-2016 11:00:07.017 UTC Debug cache.cpp:435: Found stored XML for 
subscriber, treating as UNREGISTERED state
15-04-2016 11:00:07.017 UTC Debug handlers.cpp:1121: Got IMS subscription from 
cache
15-04-2016 11:00:07.017 UTC Debug handlers.cpp:1137: TTL for this database 
record is 0, IMS Subscription XML is not empty, registration state is 
UNREGISTERED, and the charging addresses are empty
15-04-2016 11:00:07.017 UTC Debug handlers.cpp:1163: Subscriber registering 
with new binding
15-04-2016 11:00:07.017 UTC Debug handlers.cpp:1396: Handling authentication 
failure/timeout
15-04-2016 11:00:07.018 UTC Debug handlers.cpp:1443: Sending 200 response (body 
was {"reqtype": "dereg-auth-timeout"})
15-04-2016 11:00:07.018 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impu/sip%3A2010000006%40xflowresearch.com/reg-data, args 
private_id=2010000006%40xflowresearch.com
15-04-2016 11:00:08.554 UTC Warning (Net-SNMP): Warning: Failed to connect to 
the agentx master agent ([NIL]): 
15-04-2016 11:00:09.442 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:09.442 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:09.442 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:09.442 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:09.442 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:09.442 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:09.442 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:09.443 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:09.445 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:09.445 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:09.475 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:09.475 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:09.475 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:09.475 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:09.475 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:09.475 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:09.475 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:09.476 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:09.477 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:09.477 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:10.520 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
15-04-2016 11:00:10.521 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
15-04-2016 11:00:12.754 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.754 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:12.754 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:12.754 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:12.754 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:12.754 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:12.754 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:12.755 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:12.758 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:12.758 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.759 UTC Info load_monitor.cpp:212: Accepted 100.000000% of 
requests, latency error = -0.972870, overload responses = 0
15-04-2016 11:00:12.759 UTC Status load_monitor.cpp:260: Maximum incoming 
request rate/second unchanged - only handled 21 requests in last 6436ms, 
minimum threshold for a change is 129.324173
15-04-2016 11:00:12.797 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.797 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:12.797 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:12.797 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:12.797 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:12.797 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:12.797 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:12.798 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:12.800 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:12.800 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.833 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.833 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:12.833 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:12.834 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:12.834 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:12.834 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:12.834 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:12.834 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:12.835 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:12.835 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.875 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.875 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:12.875 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:12.875 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:12.875 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:12.875 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:12.875 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:12.876 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:12.877 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:12.877 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.913 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.913 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:12.913 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:12.913 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:12.913 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:12.913 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:12.913 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:12.914 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:12.916 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:12.916 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.948 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.948 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:12.948 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:12.948 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:12.948 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:12.948 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:12.948 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:12.949 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:12.950 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:12.950 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.992 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:12.992 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:12.992 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:12.992 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:12.992 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:12.992 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:12.992 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:12.993 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:12.994 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:12.994 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.024 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.024 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:13.024 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:13.024 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:13.024 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:13.024 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:13.024 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:13.025 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:13.026 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:13.026 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.057 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.057 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:13.057 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:13.057 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:13.057 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:13.057 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:13.057 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:13.058 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:13.059 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:13.059 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.088 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.088 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:13.088 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:13.088 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:13.088 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:13.088 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:13.088 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:13.089 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:13.090 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:13.090 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.122 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.122 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:13.122 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:13.122 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:13.122 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:13.122 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:13.122 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:13.123 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:13.124 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:13.124 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.153 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.153 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:13.153 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:13.153 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:13.153 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:13.153 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:13.153 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:13.153 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:13.154 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:13.154 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.195 UTC Verbose httpstack.cpp:293: Process request for URL 
/impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:13.195 UTC Debug handlers.cpp:148: Parsed HTTP request: 
private ID [email protected], public ID 
sip:[email protected], scheme Unknown, authorization 
15-04-2016 11:00:13.195 UTC Debug handlers.cpp:174: Querying cache for 
authentication vector for 
[email protected]/sip:[email protected]
15-04-2016 11:00:13.195 UTC Debug cassandra_store.cpp:284: Getting thread-local 
Client
15-04-2016 11:00:13.195 UTC Debug cache.cpp:670: Looking for authentication 
vector for [email protected]
15-04-2016 11:00:13.195 UTC Debug cache.cpp:682: Checking public ID 
sip:[email protected]
15-04-2016 11:00:13.195 UTC Debug cache.cpp:692: Issuing cache query
15-04-2016 11:00:13.196 UTC Debug cassandra_store.cpp:724: Failed TWO read for 
get_columns. Try ONE
15-04-2016 11:00:13.197 UTC Debug handlers.cpp:194: Got authentication vector 
with digest 915853456718dae6a86b6801965ee2d2 from cache
15-04-2016 11:00:13.197 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /impi/2010000006%40xflowresearch.com/av, args 
impu=sip%3A2010000006%40xflowresearch.com
15-04-2016 11:00:20.534 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
15-04-2016 11:00:20.534 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
15-04-2016 11:00:23.549 UTC Warning (Net-SNMP): Warning: Failed to connect to 
the agentx master agent ([NIL]): 
15-04-2016 11:00:28.946 UTC Debug alarm.cpp:254: Reraising alarms
15-04-2016 11:00:28.948 UTC Debug alarm.cpp:360: AlarmReqAgent: queue overflowed
15-04-2016 11:00:28.949 UTC Status alarm.cpp:72: homestead issued 1501.1 alarm
15-04-2016 11:00:31.188 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
15-04-2016 11:00:31.189 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
15-04-2016 11:00:38.552 UTC Warning (Net-SNMP): Warning: Failed to connect to 
the agentx master agent ([NIL]): 
15-04-2016 11:00:42.924 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
15-04-2016 11:00:42.924 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
15-04-2016 11:00:53.979 UTC Warning (Net-SNMP): Warning: Failed to connect to 
the agentx master agent ([NIL]): 
15-04-2016 11:00:54.077 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
15-04-2016 11:00:54.077 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
15-04-2016 11:00:58.945 UTC Debug alarm.cpp:254: Reraising alarms
15-04-2016 11:00:58.945 UTC Debug alarm.cpp:360: AlarmReqAgent: queue overflowed
15-04-2016 11:00:58.945 UTC Status alarm.cpp:72: homestead issued 1501.1 alarm
15-04-2016 11:01:05.644 UTC Verbose httpstack.cpp:293: Process request for URL 
/ping, args (null)
15-04-2016 11:01:05.644 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /ping, args (null)
15-04-2016 11:00:02.551 UTC Debug pjutils.cpp:1662: Logging SAS Call-ID marker, 
Call-ID 79961MWJjMTUyZTBmZWJkOTg0ZDUyYzdhMDlhOWM0NWY3ZTE
15-04-2016 11:00:02.552 UTC Debug thread_dispatcher.cpp:253: Queuing cloned 
received message 0x7ff1283e4f28 for worker threads
15-04-2016 11:00:02.552 UTC Debug pjsip: sip_endpoint.c Processing incoming 
message: Request msg REGISTER/cseq=29 (rdata0x1f1a258)
15-04-2016 11:00:02.552 UTC Verbose common_sip_processing.cpp:120: RX 862 bytes 
Request msg REGISTER/cseq=29 (rdata0x1f1a258) from UDP 192.168.2.68:53600:
--start msg--

REGISTER sip:xflowresearch.com SIP/2.0
Via: SIP/2.0/UDP 
10.8.0.10:53600;branch=z9hG4bK-524287-1---eeac0c31cc2a924a;rport
Max-Forwards: 70
Contact: <sip:[email protected]:53600;rinstance=a0d8ff408c456a20>
To: "2010000006"<sip:[email protected]>
From: "2010000006"<sip:[email protected]>;tag=d82ac43d
Call-ID: 79961MWJjMTUyZTBmZWJkOTg0ZDUyYzdhMDlhOWM0NWY3ZTE
CSeq: 29 REGISTER
Expires: 3600
Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, 
MESSAGE
User-Agent: X-Lite release 4.9.3 stamp 79961
Authorization: Digest 
username="[email protected]",realm="xflowresearch.com",nonce="54e6a1d54699ac12",uri="sip:xflowresearch.com",response="04635638dce6a1a49245bec4fd1a9ea0",cnonce="171e868096416ff353524d04a24f3e6f",nc=00000001,qop=auth,algorithm=MD5,opaque="5a5d7a2065d36796"
Content-Length: 0


--end msg--
15-04-2016 11:00:02.552 UTC Debug pjutils.cpp:1662: Logging SAS Call-ID marker, 
Call-ID 79961MWJjMTUyZTBmZWJkOTg0ZDUyYzdhMDlhOWM0NWY3ZTE
15-04-2016 11:00:02.552 UTC Debug thread_dispatcher.cpp:253: Queuing cloned 
received message 0x7ff1283d0a58 for worker threads
15-04-2016 11:00:02.552 UTC Debug thread_dispatcher.cpp:149: Worker thread 
dequeue message 0x7ff1283e4f28
15-04-2016 11:00:02.552 UTC Debug pjsip: sip_endpoint.c Distributing rdata to 
modules: Response msg 401/REGISTER/cseq=29 (rdata0x7ff1283e4f28)
15-04-2016 11:00:02.552 UTC Debug pjsip: tsx0x7ff1201f8 Incoming Response msg 
401/REGISTER/cseq=29 (rdata0x7ff1283e4f28) in state Calling
15-04-2016 11:00:02.552 UTC Debug pjsip: tsx0x7ff1201f8 State changed from 
Calling to Completed, event=RX_MSG
15-04-2016 11:00:02.552 UTC Debug bono.cpp:383: tsx0x7ff1201f8348 - 
tu_on_tsx_state UAC, TSX_STATE RX_MSG state=Completed
15-04-2016 11:00:02.552 UTC Debug bono.cpp:2947: tsx0x7ff1201f8348 - uac_data = 
0x7ff120436e30, uas_data = 0x7ff120436f90
15-04-2016 11:00:02.552 UTC Debug bono.cpp:2986: tsx0x7ff1201f8348 - RX_MSG on 
active UAC transaction
15-04-2016 11:00:02.552 UTC Debug trustboundary.cpp:57: Strip trusted headers
15-04-2016 11:00:02.552 UTC Debug bono.cpp:2179: tsx0x7ff1201f8348 - Final 
response, so disconnect UAS and UAC transactions
15-04-2016 11:00:02.552 UTC Debug pjsip: tdta0x7ff1201f Destroying txdata 
Response msg 408/REGISTER/cseq=29 (tdta0x7ff1201f40a0)
15-04-2016 11:00:02.552 UTC Debug bono.cpp:2614: Dissociate UAC transaction 
0x7ff120436e30 (0)
15-04-2016 11:00:02.552 UTC Debug pjsip: tsx0x7ff1201f3 Sending Response msg 
401/REGISTER/cseq=29 (tdta0x7ff1201faa00) in state Trying
15-04-2016 11:00:02.552 UTC Verbose common_sip_processing.cpp:136: TX 780 bytes 
Response msg 401/REGISTER/cseq=29 (tdta0x7ff1201faa00) to UDP 
192.168.2.110:5054:
--start msg--

SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 
192.168.0.8:5054;rport=5054;received=192.168.2.110;branch=z9hG4bKPjBKfJBHbikh85jg4f3ObRa5t.rxRXH8so
Via: SIP/2.0/TCP 
192.168.0.3:52595;rport=52595;received=192.168.0.3;branch=z9hG4bKPjwrNvrtnkFH2MwxLDOt7G7gCNTqe2Ovym
Via: SIP/2.0/UDP 
10.8.0.10:53600;rport=53600;received=192.168.2.68;branch=z9hG4bK-524287-1---eeac0c31cc2a924a
Call-ID: 79961MWJjMTUyZTBmZWJkOTg0ZDUyYzdhMDlhOWM0NWY3ZTE
From: "2010000006" <sip:[email protected]>;tag=d82ac43d
To: "2010000006" 
<sip:[email protected]>;tag=z9hG4bKPja8EcUn3GqfshC9sH-UQlHBgdVsybsZtO
CSeq: 29 REGISTER
WWW-Authenticate: Digest  
realm="xflowresearch.com",nonce="1ed834cc2c14404e",opaque="3c089b0a27f67534",stale=true,algorithm=MD5,qop="auth"
Content-Length:  0


--end msg--
15-04-2016 11:00:02.552 UTC Debug pjsip: tsx0x7ff1201f3 State changed from 
Trying to Completed, event=TX_MSG
15-04-2016 11:00:02.552 UTC Debug bono.cpp:383: tsx0x7ff1201f3938 - 
tu_on_tsx_state UAS, TSX_STATE TX_MSG state=Completed
15-04-2016 11:00:02.552 UTC Debug bono.cpp:803: Request received on non-trusted 
port 5060
15-04-2016 11:00:02.552 UTC Debug bono.cpp:2412: Report SAS end marker - trail 
(a5f)
15-04-2016 11:00:02.552 UTC Debug thread_dispatcher.cpp:193: Worker thread 
completed processing message 0x7ff1283e4f28
15-04-2016 11:00:02.552 UTC Debug thread_dispatcher.cpp:199: Request latency = 
846us
15-04-2016 11:00:02.552 UTC Debug thread_dispatcher.cpp:149: Worker thread 
dequeue message 0x7ff1283d0a58
15-04-2016 11:00:02.552 UTC Debug pjsip: sip_endpoint.c Distributing rdata to 
modules: Request msg REGISTER/cseq=29 (rdata0x7ff1283d0a58)
15-04-2016 11:00:02.552 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
15-04-2016 11:00:02.552 UTC Debug uri_classifier.cpp:197: Classified URI as 4
15-04-2016 11:00:02.552 UTC Debug pjsip: tsx0x7ff1181be Incoming Request msg 
REGISTER/cseq=29 (rdata0x7ff1283d0a58) in state Trying
15-04-2016 11:00:02.552 UTC Debug thread_dispatcher.cpp:193: Worker thread 
completed processing message 0x7ff1283d0a58
15-04-2016 11:00:02.552 UTC Debug thread_dispatcher.cpp:199: Request latency = 
692us
15-04-2016 11:00:02.552 UTC Debug pjsip: sip_endpoint.c Processing incoming 
message: Request msg REGISTER/cseq=29 (rdata0x1f1a258)
15-04-2016 11:00:02.553 UTC Verbose common_sip_processing.cpp:120: RX 1249 
bytes Request msg REGISTER/cseq=29 (rdata0x1f1a258) from UDP 192.168.2.110:5054:
--start msg--

REGISTER sip:xflowresearch.com SIP/2.0
Via: SIP/2.0/UDP 
192.168.0.8:5054;rport;branch=z9hG4bKPjBKfJBHbikh85jg4f3ObRa5t.rxRXH8so
Via: SIP/2.0/TCP 
192.168.0.3:52595;rport=52595;received=192.168.0.3;branch=z9hG4bKPjwrNvrtnkFH2MwxLDOt7G7gCNTqe2Ovym
Path: <sip:[email protected]:5058;transport=TCP;lr;ob>
Via: SIP/2.0/UDP 
10.8.0.10:53600;rport=53600;received=192.168.2.68;branch=z9hG4bK-524287-1---eeac0c31cc2a924a
Max-Forwards: 69
Contact: <sip:[email protected]:53600;rinstance=a0d8ff408c456a20>
To: "2010000006" <sip:[email protected]>
From: "2010000006" <sip:[email protected]>;tag=d82ac43d
Call-ID: 79961MWJjMTUyZTBmZWJkOTg0ZDUyYzdhMDlhOWM0NWY3ZTE
CSeq: 29 REGISTER
Expires: 3600
Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, 
MESSAGE
User-Agent: X-Lite release 4.9.3 stamp 79961
Authorization: Digest response="04635638dce6a1a49245bec4fd1a9ea0", 
username="[email protected]", realm="xflowresearch.com", 
nonce="54e6a1d54699ac12", uri="sip:xflowresearch.com", algorithm=MD5, 
cnonce="171e868096416ff353524d04a24f3e6f", opaque="5a5d7a2065d36796", qop=auth, 
nc=00000001,integrity-protected=ip-assoc-pending
P-Visited-Network-ID: xflowresearch.com
Content-Length:  0


--end msg--
15-04-2016 11:00:02.553 UTC Debug pjutils.cpp:1662: Logging SAS Call-ID marker, 
Call-ID 79961MWJjMTUyZTBmZWJkOTg0ZDUyYzdhMDlhOWM0NWY3ZTE
15-04-2016 11:00:02.553 UTC Debug thread_dispatcher.cpp:253: Queuing cloned 
received message 0x7ff1283e4f28 for worker threads
15-04-2016 11:00:02.553 UTC Debug thread_dispatcher.cpp:149: Worker thread 
dequeue message 0x7ff1283e4f28
15-04-2016 11:00:02.553 UTC Debug pjsip: sip_endpoint.c Distributing rdata to 
modules: Request msg REGISTER/cseq=29 (rdata0x7ff1283e4f28)
15-04-2016 11:00:02.553 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
15-04-2016 11:00:02.553 UTC Debug uri_classifier.cpp:197: Classified URI as 4
15-04-2016 11:00:02.553 UTC Debug pjsip: tsx0x7ff1201f3 Incoming Request msg 
REGISTER/cseq=29 (rdata0x7ff1283e4f28) in state Completed
15-04-2016 11:00:02.553 UTC Debug pjsip: tsx0x7ff1201f3 Retransmiting Response 
msg 401/REGISTER/cseq=29 (tdta0x7ff1201faa00), count=0, restart?=0
15-04-2016 11:00:02.553 UTC Verbose common_sip_processing.cpp:136: TX 780 bytes 
Response msg 401/REGISTER/cseq=29 (tdta0x7ff1201faa00) to UDP 
192.168.2.110:5054:
--start msg--

SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 
192.168.0.8:5054;rport=5054;received=192.168.2.110;branch=z9hG4bKPjBKfJBHbikh85jg4f3ObRa5t.rxRXH8so
Via: SIP/2.0/TCP 
192.168.0.3:52595;rport=52595;received=192.168.0.3;branch=z9hG4bKPjwrNvrtnkFH2MwxLDOt7G7gCNTqe2Ovym
Via: SIP/2.0/UDP 
10.8.0.10:53600;rport=53600;received=192.168.2.68;branch=z9hG4bK-524287-1---eeac0c31cc2a924a
Call-ID: 79961MWJjMTUyZTBmZWJkOTg0ZDUyYzdhMDlhOWM0NWY3ZTE
From: "2010000006" <sip:[email protected]>;tag=d82ac43d
To: "2010000006" 
<sip:[email protected]>;tag=z9hG4bKPja8EcUn3GqfshC9sH-UQlHBgdVsybsZtO
CSeq: 29 REGISTER
WWW-Authenticate: Digest  
realm="xflowresearch.com",nonce="1ed834cc2c14404e",opaque="3c089b0a27f67534",stale=true,algorithm=MD5,qop="auth"
Content-Length:  0


--end msg--
15-04-2016 11:00:02.553 UTC Debug thread_dispatcher.cpp:193: Worker thread 
completed processing message 0x7ff1283e4f28
15-04-2016 11:00:02.553 UTC Debug thread_dispatcher.cpp:199: Request latency = 
225us
15-04-2016 11:00:02.553 UTC Debug pjsip: tsx0x7ff1201f8 Timeout timer event
15-04-2016 11:00:02.553 UTC Debug pjsip: tsx0x7ff1201f8 State changed from 
Completed to Terminated, event=TIMER
15-04-2016 11:00:02.553 UTC Debug bono.cpp:383: tsx0x7ff1201f8348 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Terminated
15-04-2016 11:00:02.553 UTC Debug bono.cpp:2947: tsx0x7ff1201f8348 - uac_data = 
0x7ff120436e30, uas_data = (nil)
15-04-2016 11:00:02.553 UTC Debug pjsip: tsx0x7ff1201f8 Timeout timer event
15-04-2016 11:00:02.553 UTC Debug pjsip: tsx0x7ff1201f8 State changed from 
Terminated to Destroyed, event=TIMER
15-04-2016 11:00:02.553 UTC Debug bono.cpp:383: tsx0x7ff1201f8348 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Destroyed
15-04-2016 11:00:02.553 UTC Debug bono.cpp:2947: tsx0x7ff1201f8348 - uac_data = 
0x7ff120436e30, uas_data = (nil)
15-04-2016 11:00:02.553 UTC Debug bono.cpp:3034: tsx0x7ff1201f8348 - UAC tsx 
destroyed
15-04-2016 11:00:02.553 UTC Debug pjsip: tdta0x7ff1201f Destroying txdata 
Request msg REGISTER/cseq=29 (tdta0x7ff1201f5330)
15-04-2016 11:00:03.492 UTC Debug pjsip: tsx0x7ff118002 Timeout timer event
15-04-2016 11:00:03.492 UTC Debug pjsip: tsx0x7ff118002 State changed from 
Completed to Terminated, event=TIMER
15-04-2016 11:00:03.492 UTC Debug bono.cpp:383: tsx0x7ff118002d18 - 
tu_on_tsx_state UAS, TSX_STATE TIMER state=Terminated
15-04-2016 11:00:03.492 UTC Debug pjsip: tsx0x7ff118002 Timeout timer event
15-04-2016 11:00:03.492 UTC Debug pjsip: tsx0x7ff118002 State changed from 
Terminated to Destroyed, event=TIMER
15-04-2016 11:00:03.492 UTC Debug bono.cpp:383: tsx0x7ff118002d18 - 
tu_on_tsx_state UAS, TSX_STATE TIMER state=Destroyed
Retransmiting Request msg REGISTER/cseq=29 (tdta0x1fa68d0), count=1, restart?=1
15-04-2016 11:00:00.747 UTC Verbose common_sip_processing.cpp:136: TX 1249 
bytes Request msg REGISTER/cseq=29 (tdta0x1fa68d0) to UDP 192.168.2.107:5060:
--start msg--

REGISTER sip:xflowresearch.com SIP/2.0
Via: SIP/2.0/UDP 
192.168.0.8:5054;rport;branch=z9hG4bKPjBKfJBHbikh85jg4f3ObRa5t.rxRXH8so
Via: SIP/2.0/TCP 
192.168.0.3:52595;rport=52595;received=192.168.0.3;branch=z9hG4bKPjwrNvrtnkFH2MwxLDOt7G7gCNTqe2Ovym
Path: <sip:[email protected]:5058;transport=TCP;lr;ob>
Via: SIP/2.0/UDP 
10.8.0.10:53600;rport=53600;received=192.168.2.68;branch=z9hG4bK-524287-1---eeac0c31cc2a924a
Max-Forwards: 69
Contact: <sip:[email protected]:53600;rinstance=a0d8ff408c456a20>
To: "2010000006" <sip:[email protected]>
From: "2010000006" <sip:[email protected]>;tag=d82ac43d
Call-ID: 79961MWJjMTUyZTBmZWJkOTg0ZDUyYzdhMDlhOWM0NWY3ZTE
CSeq: 29 REGISTER
Expires: 3600
Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, 
MESSAGE
User-Agent: X-Lite release 4.9.3 stamp 79961
Authorization: Digest response="04635638dce6a1a49245bec4fd1a9ea0", 
username="[email protected]", realm="xflowresearch.com", 
nonce="54e6a1d54699ac12", uri="sip:xflowresearch.com", algorithm=MD5, 
cnonce="171e868096416ff353524d04a24f3e6f", opaque="5a5d7a2065d36796", qop=auth, 
nc=00000001,integrity-protected=ip-assoc-pending
P-Visited-Network-ID: xflowresearch.com
Content-Length:  0


--end msg--
15-04-2016 11:00:01.499 UTC Verbose httpstack.cpp:293: Process request for URL 
/authentication-timeout, args (null)
15-04-2016 11:00:01.500 UTC Debug memcachedstore.cpp:195: Key 
impi\\[email protected] hashes to vbucket 77 via hash 0x326094cd
15-04-2016 11:00:01.500 UTC Debug memcachedstore.cpp:367: 1 read replicas for 
key impi\\[email protected]
15-04-2016 11:00:01.500 UTC Debug memcachedstore.cpp:402: Attempt to read from 
replica 0 (connection 0x25bf4e0)
15-04-2016 11:00:01.500 UTC Debug memcachedstore.cpp:780: Fetch result
15-04-2016 11:00:01.500 UTC Debug memcachedstore.cpp:788: Found record on 
replica
15-04-2016 11:00:01.500 UTC Debug memcachedstore.cpp:410: Read for 
impi\\[email protected] on replica 0 returned SUCCESS
15-04-2016 11:00:01.500 UTC Debug memcachedstore.cpp:453: Read 23976 bytes from 
table impi key [email protected], CAS = 2102
15-04-2016 11:00:01.500 UTC Debug impistore.cpp:754: Retrieved IMPI for 
[email protected]
{"authChallenges":[{"type":"digest","nonce":"4358cc39032b496c","nc":2,"expires":1460718011,"correlator":"z9hG4bKPjQTc8JtYPma.arD9xUebTmV4zA5PCqjky","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4b68593b6d072be4","nc":2,"expires":1460718011,"correlator":"z9hG4bKPjVU8wIsY2IRKfc.VeOD1BG5VOBGneCIsT","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"39a711d42cea85d3","nc":2,"expires":1460718011,"correlator":"z9hG4bKPjnfLjnk1tnVrnO.ZpVAZU15WZxbzjqUDY","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"7f0a06595eb5e44c","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjWS7M68EZ2Xu1SrlqVjpQ4CumH2oxFT61","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4ca3d7902b7e926f","nc":2,"expires":1460718014,"correlator":"z9hG4bKPj.IhZIt-3cBpA2Gd4khsy3bHRuVG5MFlm","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"227c81e45b1a4684","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjWq2Z4J0oW55ip138nNOGcFOzutIv-6ju","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"30d1c85b76da5308","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjFuCiS6Zx8zy42tmLR9G1bzrMPKNekqvH","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"6ea273bb57f243ef","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjz5oTnmOsHe636.Dr5LJ0FS3VuJ-C9yqL","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"38e8578d7173fae0","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjUbq1ImXj8v8rYxDpTXvJiyBls0ezpnSW","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"49913bd6176df9ab","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjsu80AwNi8idk-IlN4MCDMYTRAFKZmWEq","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"34bf3dbd53822bec","nc":2,"expires":1460718015,"correlator":"z9hG4bKPjfc4RNcKSYDfExxH0aUvNeN3.cFyBanuR","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"34fe5a0155292e12","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjvapDia.jTq8-8HApLliQyuH6cq2aE.9A","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"1f1b6df238db97f3","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjC4txptGEoYP5v39FT4HJ9mL-UI8ZyX0M","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"05d0d2e96e9875b7","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjXY5hFGRAxioPS3Ip5wlE5RN2JH-Q73Xx","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"62ca94db04da363b","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjzu1XY4PzfhxMgsMTXtgYKLSq0kN76cXc","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"29daac01688eae4c","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjNYd5as4b8U2jbAyBXQ4qbFPBbV1j50Yl","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"5f281e3c0da5230e","nc":2,"expires":1460718016,"correlator":"z9hG4bKPj4p.baCOclOjzMJcdcpc8N-1j9.8FwIEL","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"373d75f937fc5613","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjiuNuFNaEh.wbXRoPaVqDddEplD8KiN2d","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"308ebdfc43570ba9","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjLXEhSuPnkHzZ490RVQi9V2yLEsumYFEe","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"34823dc775d6dbd1","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjPds6-NMvvh8WRnl4.KW6U5iqzPE9IUs5","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"5d1f7ade5dfec228","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjdGCgDK7Pz2My2.hL-LtB6VUuzGqM-mFk","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"2f6834a57a98a806","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjAoS.P1EDLpBu11IP..1sXGcUJcOmZYHo","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"66520a07144ff26c","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjQU3GO.0WZf5qgCQvuf6sfWwok-SogJEB","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"422cdd3d0a626aa2","nc":1,"expires":1460718016,"correlator":"z9hG4bKPj68DKHviso15GX7vR24xS.DvuPWQ1r.NH","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"2cf16f1e5fe771fe","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjQ7Q.D-V-El7xqxIAZTXFyl8SpblVE1Na","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"29d057fa78023c94","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjyYRXccnMpIFzM1HQfGV31Ctqa2K2BkPt","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4aa226972ab95f6e","nc":2,"expires":1460718016,"correlator":"z9hG4bKPj-BF2vmzuD4meq2nLtOEc34W3rf7b.G0E","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"798ae762300c5222","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjU5yuWAQTaX5dWHMB0K.o0Ci3ORT2TQ40","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"64098e7a076ba358","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjzAbE9-E4DN68FnsfOnNKLTAetHTbT.Hq","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"6f590a33580083b4","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjL0FJw2vw.HxK3RtEK1PQvuauTto764jp","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"225b6c1f75ad19f3","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjGYtZ1fJrOnCc2VRfITwgaiv1HxWiTpqK","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"12301bbd2eeb494d","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjq0M2OWDuAUdNeHfAycqKA-1kgjeAKu82","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"551265374112df8e","nc":1,"expires":1460718017,"correlator":"z9hG4bKPjA3j28N3HN-QrRhSPtQtQWGdNJ354OlDI","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"57db2f4458f23e1e","nc":2,"expires":1460718017,"correlator":"z9hG4bKPj3tCFJsqQlwwO8K2e7sBR7R7HEeEWH7mx","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"136a11be099122c7","nc":2,"expires":1460718017,"correlator":"z9hG4bKPjFJb.SSh9ecEE9vbbYuvbiUgrSuxxpanw","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"7c72fca765af6d50","nc":2,"expires":1460718017,"correlator":"z9hG4bKPjXkeIMtcitnU4yi3f21ntl8p9I8ZCOOXS","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"24c5643c1241b3ff","nc":2,"expires":1460718017,"correlator":"z9hG4bKPjlGgbTMAzVZLtQwJnhsfiybAQJwwGPpPV","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"784e2dfb0cd5c980","nc":2,"expires":1460718026,"correlator":"z9hG4bKPjv6HJ-d2ca-jYfJtPSvcA0z-Q0fcB7mMo","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4f9ddb0137040fa15-04-2016
 11:00:01.501 UTC Previous log was truncated by 15859 characters
15-04-2016 11:00:01.501 UTC Debug handlers.cpp:678: Tombstone record indicates 
Authentication Vector has been used successfully - ignoring timer pop
15-04-2016 11:00:01.501 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /authentication-timeout, args (null)
15-04-2016 11:00:01.545 UTC Verbose httpstack.cpp:293: Process request for URL 
/authentication-timeout, args (null)
15-04-2016 11:00:01.545 UTC Debug memcachedstore.cpp:195: Key 
impi\\[email protected] hashes to vbucket 77 via hash 0x326094cd
15-04-2016 11:00:01.545 UTC Debug memcachedstore.cpp:367: 1 read replicas for 
key impi\\[email protected]
15-04-2016 11:00:01.545 UTC Debug memcachedstore.cpp:402: Attempt to read from 
replica 0 (connection 0x7f279c0012a0)
15-04-2016 11:00:01.545 UTC Debug memcachedstore.cpp:780: Fetch result
15-04-2016 11:00:01.546 UTC Debug memcachedstore.cpp:788: Found record on 
replica
15-04-2016 11:00:01.546 UTC Debug memcachedstore.cpp:410: Read for 
impi\\[email protected] on replica 0 returned SUCCESS
15-04-2016 11:00:01.546 UTC Debug memcachedstore.cpp:453: Read 23976 bytes from 
table impi key [email protected], CAS = 2102
15-04-2016 11:00:01.546 UTC Debug impistore.cpp:754: Retrieved IMPI for 
[email protected]
{"authChallenges":[{"type":"digest","nonce":"4358cc39032b496c","nc":2,"expires":1460718011,"correlator":"z9hG4bKPjQTc8JtYPma.arD9xUebTmV4zA5PCqjky","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4b68593b6d072be4","nc":2,"expires":1460718011,"correlator":"z9hG4bKPjVU8wIsY2IRKfc.VeOD1BG5VOBGneCIsT","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"39a711d42cea85d3","nc":2,"expires":1460718011,"correlator":"z9hG4bKPjnfLjnk1tnVrnO.ZpVAZU15WZxbzjqUDY","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"7f0a06595eb5e44c","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjWS7M68EZ2Xu1SrlqVjpQ4CumH2oxFT61","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4ca3d7902b7e926f","nc":2,"expires":1460718014,"correlator":"z9hG4bKPj.IhZIt-3cBpA2Gd4khsy3bHRuVG5MFlm","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"227c81e45b1a4684","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjWq2Z4J0oW55ip138nNOGcFOzutIv-6ju","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"30d1c85b76da5308","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjFuCiS6Zx8zy42tmLR9G1bzrMPKNekqvH","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"6ea273bb57f243ef","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjz5oTnmOsHe636.Dr5LJ0FS3VuJ-C9yqL","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"38e8578d7173fae0","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjUbq1ImXj8v8rYxDpTXvJiyBls0ezpnSW","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"49913bd6176df9ab","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjsu80AwNi8idk-IlN4MCDMYTRAFKZmWEq","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"34bf3dbd53822bec","nc":2,"expires":1460718015,"correlator":"z9hG4bKPjfc4RNcKSYDfExxH0aUvNeN3.cFyBanuR","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"34fe5a0155292e12","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjvapDia.jTq8-8HApLliQyuH6cq2aE.9A","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"1f1b6df238db97f3","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjC4txptGEoYP5v39FT4HJ9mL-UI8ZyX0M","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"05d0d2e96e9875b7","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjXY5hFGRAxioPS3Ip5wlE5RN2JH-Q73Xx","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"62ca94db04da363b","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjzu1XY4PzfhxMgsMTXtgYKLSq0kN76cXc","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"29daac01688eae4c","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjNYd5as4b8U2jbAyBXQ4qbFPBbV1j50Yl","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"5f281e3c0da5230e","nc":2,"expires":1460718016,"correlator":"z9hG4bKPj4p.baCOclOjzMJcdcpc8N-1j9.8FwIEL","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"373d75f937fc5613","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjiuNuFNaEh.wbXRoPaVqDddEplD8KiN2d","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"308ebdfc43570ba9","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjLXEhSuPnkHzZ490RVQi9V2yLEsumYFEe","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"34823dc775d6dbd1","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjPds6-NMvvh8WRnl4.KW6U5iqzPE9IUs5","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"5d1f7ade5dfec228","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjdGCgDK7Pz2My2.hL-LtB6VUuzGqM-mFk","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"2f6834a57a98a806","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjAoS.P1EDLpBu11IP..1sXGcUJcOmZYHo","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"66520a07144ff26c","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjQU3GO.0WZf5qgCQvuf6sfWwok-SogJEB","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"422cdd3d0a626aa2","nc":1,"expires":1460718016,"correlator":"z9hG4bKPj68DKHviso15GX7vR24xS.DvuPWQ1r.NH","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"2cf16f1e5fe771fe","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjQ7Q.D-V-El7xqxIAZTXFyl8SpblVE1Na","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"29d057fa78023c94","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjyYRXccnMpIFzM1HQfGV31Ctqa2K2BkPt","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4aa226972ab95f6e","nc":2,"expires":1460718016,"correlator":"z9hG4bKPj-BF2vmzuD4meq2nLtOEc34W3rf7b.G0E","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"798ae762300c5222","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjU5yuWAQTaX5dWHMB0K.o0Ci3ORT2TQ40","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"64098e7a076ba358","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjzAbE9-E4DN68FnsfOnNKLTAetHTbT.Hq","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"6f590a33580083b4","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjL0FJw2vw.HxK3RtEK1PQvuauTto764jp","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"225b6c1f75ad19f3","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjGYtZ1fJrOnCc2VRfITwgaiv1HxWiTpqK","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"12301bbd2eeb494d","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjq0M2OWDuAUdNeHfAycqKA-1kgjeAKu82","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"551265374112df8e","nc":1,"expires":1460718017,"correlator":"z9hG4bKPjA3j28N3HN-QrRhSPtQtQWGdNJ354OlDI","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"57db2f4458f23e1e","nc":2,"expires":1460718017,"correlator":"z9hG4bKPj3tCFJsqQlwwO8K2e7sBR7R7HEeEWH7mx","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"136a11be099122c7","nc":2,"expires":1460718017,"correlator":"z9hG4bKPjFJb.SSh9ecEE9vbbYuvbiUgrSuxxpanw","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"7c72fca765af6d50","nc":2,"expires":1460718017,"correlator":"z9hG4bKPjXkeIMtcitnU4yi3f21ntl8p9I8ZCOOXS","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"24c5643c1241b3ff","nc":2,"expires":1460718017,"correlator":"z9hG4bKPjlGgbTMAzVZLtQwJnhsfiybAQJwwGPpPV","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"784e2dfb0cd5c980","nc":2,"expires":1460718026,"correlator":"z9hG4bKPjv6HJ-d2ca-jYfJtPSvcA0z-Q0fcB7mMo","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4f9ddb0137040fa15-04-2016
 11:00:01.546 UTC Previous log was truncated by 15859 characters
15-04-2016 11:00:01.546 UTC Debug handlers.cpp:678: Tombstone record indicates 
Authentication Vector has been used successfully - ignoring timer pop
15-04-2016 11:00:01.546 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /authentication-timeout, args (null)
15-04-2016 11:00:01.577 UTC Verbose httpstack.cpp:293: Process request for URL 
/authentication-timeout, args (null)
15-04-2016 11:00:01.577 UTC Debug memcachedstore.cpp:195: Key 
impi\\[email protected] hashes to vbucket 77 via hash 0x326094cd
15-04-2016 11:00:01.577 UTC Debug memcachedstore.cpp:367: 1 read replicas for 
key impi\\[email protected]
15-04-2016 11:00:01.577 UTC Debug memcachedstore.cpp:402: Attempt to read from 
replica 0 (connection 0x7f2794005b40)
15-04-2016 11:00:01.577 UTC Debug memcachedstore.cpp:780: Fetch result
15-04-2016 11:00:01.578 UTC Debug memcachedstore.cpp:788: Found record on 
replica
15-04-2016 11:00:01.578 UTC Debug memcachedstore.cpp:410: Read for 
impi\\[email protected] on replica 0 returned SUCCESS
15-04-2016 11:00:01.578 UTC Debug memcachedstore.cpp:453: Read 23976 bytes from 
table impi key [email protected], CAS = 2102
15-04-2016 11:00:01.578 UTC Debug impistore.cpp:754: Retrieved IMPI for 
[email protected]
{"authChallenges":[{"type":"digest","nonce":"4358cc39032b496c","nc":2,"expires":1460718011,"correlator":"z9hG4bKPjQTc8JtYPma.arD9xUebTmV4zA5PCqjky","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4b68593b6d072be4","nc":2,"expires":1460718011,"correlator":"z9hG4bKPjVU8wIsY2IRKfc.VeOD1BG5VOBGneCIsT","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"39a711d42cea85d3","nc":2,"expires":1460718011,"correlator":"z9hG4bKPjnfLjnk1tnVrnO.ZpVAZU15WZxbzjqUDY","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"7f0a06595eb5e44c","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjWS7M68EZ2Xu1SrlqVjpQ4CumH2oxFT61","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4ca3d7902b7e926f","nc":2,"expires":1460718014,"correlator":"z9hG4bKPj.IhZIt-3cBpA2Gd4khsy3bHRuVG5MFlm","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"227c81e45b1a4684","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjWq2Z4J0oW55ip138nNOGcFOzutIv-6ju","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"30d1c85b76da5308","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjFuCiS6Zx8zy42tmLR9G1bzrMPKNekqvH","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"6ea273bb57f243ef","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjz5oTnmOsHe636.Dr5LJ0FS3VuJ-C9yqL","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"38e8578d7173fae0","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjUbq1ImXj8v8rYxDpTXvJiyBls0ezpnSW","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"49913bd6176df9ab","nc":2,"expires":1460718014,"correlator":"z9hG4bKPjsu80AwNi8idk-IlN4MCDMYTRAFKZmWEq","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"34bf3dbd53822bec","nc":2,"expires":1460718015,"correlator":"z9hG4bKPjfc4RNcKSYDfExxH0aUvNeN3.cFyBanuR","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"34fe5a0155292e12","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjvapDia.jTq8-8HApLliQyuH6cq2aE.9A","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"1f1b6df238db97f3","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjC4txptGEoYP5v39FT4HJ9mL-UI8ZyX0M","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"05d0d2e96e9875b7","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjXY5hFGRAxioPS3Ip5wlE5RN2JH-Q73Xx","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"62ca94db04da363b","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjzu1XY4PzfhxMgsMTXtgYKLSq0kN76cXc","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"29daac01688eae4c","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjNYd5as4b8U2jbAyBXQ4qbFPBbV1j50Yl","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"5f281e3c0da5230e","nc":2,"expires":1460718016,"correlator":"z9hG4bKPj4p.baCOclOjzMJcdcpc8N-1j9.8FwIEL","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"373d75f937fc5613","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjiuNuFNaEh.wbXRoPaVqDddEplD8KiN2d","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"308ebdfc43570ba9","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjLXEhSuPnkHzZ490RVQi9V2yLEsumYFEe","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"34823dc775d6dbd1","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjPds6-NMvvh8WRnl4.KW6U5iqzPE9IUs5","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"5d1f7ade5dfec228","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjdGCgDK7Pz2My2.hL-LtB6VUuzGqM-mFk","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"2f6834a57a98a806","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjAoS.P1EDLpBu11IP..1sXGcUJcOmZYHo","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"66520a07144ff26c","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjQU3GO.0WZf5qgCQvuf6sfWwok-SogJEB","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"422cdd3d0a626aa2","nc":1,"expires":1460718016,"correlator":"z9hG4bKPj68DKHviso15GX7vR24xS.DvuPWQ1r.NH","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"2cf16f1e5fe771fe","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjQ7Q.D-V-El7xqxIAZTXFyl8SpblVE1Na","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"29d057fa78023c94","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjyYRXccnMpIFzM1HQfGV31Ctqa2K2BkPt","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4aa226972ab95f6e","nc":2,"expires":1460718016,"correlator":"z9hG4bKPj-BF2vmzuD4meq2nLtOEc34W3rf7b.G0E","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"798ae762300c5222","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjU5yuWAQTaX5dWHMB0K.o0Ci3ORT2TQ40","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"64098e7a076ba358","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjzAbE9-E4DN68FnsfOnNKLTAetHTbT.Hq","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"6f590a33580083b4","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjL0FJw2vw.HxK3RtEK1PQvuauTto764jp","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"225b6c1f75ad19f3","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjGYtZ1fJrOnCc2VRfITwgaiv1HxWiTpqK","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"12301bbd2eeb494d","nc":2,"expires":1460718016,"correlator":"z9hG4bKPjq0M2OWDuAUdNeHfAycqKA-1kgjeAKu82","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"551265374112df8e","nc":1,"expires":1460718017,"correlator":"z9hG4bKPjA3j28N3HN-QrRhSPtQtQWGdNJ354OlDI","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"57db2f4458f23e1e","nc":2,"expires":1460718017,"correlator":"z9hG4bKPj3tCFJsqQlwwO8K2e7sBR7R7HEeEWH7mx","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"136a11be099122c7","nc":2,"expires":1460718017,"correlator":"z9hG4bKPjFJb.SSh9ecEE9vbbYuvbiUgrSuxxpanw","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"7c72fca765af6d50","nc":2,"expires":1460718017,"correlator":"z9hG4bKPjXkeIMtcitnU4yi3f21ntl8p9I8ZCOOXS","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"24c5643c1241b3ff","nc":2,"expires":1460718017,"correlator":"z9hG4bKPjlGgbTMAzVZLtQwJnhsfiybAQJwwGPpPV","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"784e2dfb0cd5c980","nc":2,"expires":1460718026,"correlator":"z9hG4bKPjv6HJ-d2ca-jYfJtPSvcA0z-Q0fcB7mMo","realm":"xflowresearch.com","qop":"auth","ha1":"915853456718dae6a86b6801965ee2d2"},{"type":"digest","nonce":"4f9ddb0137040fa15-04-2016
 11:00:01.578 UTC Previous log was truncated by 15859 characters
15-04-2016 11:00:01.578 UTC Debug handlers.cpp:678: Tombstone record indicates 
Authentication Vector has been used successfully - ignoring timer pop
15-04-2016 11:00:01.579 UTC Verbose httpstack.cpp:69: Sending response 200 to 
request for URL /authentication-timeout, args (null)
15-04-2016 11:00:01.881 UTC Debug pjsip: tsx0x7f27b8409 Timeout timer event
15-04-2016 11:00:01.882 UTC Debug pjsip: tsx0x7f27b8409 State changed from 
Completed to Terminated, event=TIMER
15-04-2016 11:00:01.882 UTC Debug basicproxy.cpp:213: tsx0x7f27b8409168 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Terminated
15-04-2016 11:00:01.882 UTC Debug basicproxy.cpp:1813: tsx0x7f27b8409168 - 
uac_tsx = 0x7f27b81d8ff0, uas_tsx = (nil)
15-04-2016 11:00:01.883 UTC Debug pjsip: tsx0x7f27b8409 Timeout timer event
15-04-2016 11:00:01.883 UTC Debug pjsip: tsx0x7f27b8409 State changed from 
Terminated to Destroyed, event=TIMER
15-04-2016 11:00:01.883 UTC Debug basicproxy.cpp:213: tsx0x7f27b8409168 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Destroyed
15-04-2016 11:00:01.883 UTC Debug basicproxy.cpp:1813: tsx0x7f27b8409168 - 
uac_tsx = 0x7f27b81d8ff0, uas_tsx = (nil)
15-04-2016 11:00:01.883 UTC Debug basicproxy.cpp:1985: tsx0x7f27b8409168 - UAC 
tsx destroyed
15-04-2016 11:00:01.883 UTC Debug basicproxy.cpp:1535: BasicProxy::UACTsx 
destructor (0x7f27b81d8ff0)
15-04-2016 11:00:01.883 UTC Debug pjsip: tdta0x7f27b843 Destroying txdata 
Request msg REGISTER/cseq=21 (tdta0x7f27b843c770)
15-04-2016 11:00:01.883 UTC Debug pjsip: tsx0x7f27b8413 Transaction destroyed!
15-04-2016 11:00:01.883 UTC Debug pjsip: tsx0x7f27b8409 Transaction destroyed!
15-04-2016 11:00:01.919 UTC Debug pjsip: tsx0x7f2810368 Timeout timer event
15-04-2016 11:00:01.919 UTC Debug pjsip: tsx0x7f2810368 State changed from 
Completed to Terminated, event=TIMER
15-04-2016 11:00:01.919 UTC Debug basicproxy.cpp:213: tsx0x7f2810368b88 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Terminated
15-04-2016 11:00:01.919 UTC Debug basicproxy.cpp:1813: tsx0x7f2810368b88 - 
uac_tsx = 0x7f28103b2cf0, uas_tsx = (nil)
15-04-2016 11:00:01.919 UTC Debug pjsip: tsx0x7f2810368 Timeout timer event
15-04-2016 11:00:01.919 UTC Debug pjsip: tsx0x7f2810368 State changed from 
Terminated to Destroyed, event=TIMER
15-04-2016 11:00:01.919 UTC Debug basicproxy.cpp:213: tsx0x7f2810368b88 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Destroyed
15-04-2016 11:00:01.919 UTC Debug basicproxy.cpp:1813: tsx0x7f2810368b88 - 
uac_tsx = 0x7f28103b2cf0, uas_tsx = (nil)
15-04-2016 11:00:01.919 UTC Debug basicproxy.cpp:1985: tsx0x7f2810368b88 - UAC 
tsx destroyed
15-04-2016 11:00:01.919 UTC Debug basicproxy.cpp:1535: BasicProxy::UACTsx 
destructor (0x7f28103b2cf0)
15-04-2016 11:00:01.919 UTC Debug pjsip: tdta0x7f281030 Destroying txdata 
Request msg REGISTER/cseq=22 (tdta0x7f281030b8c0)
15-04-2016 11:00:01.919 UTC Debug pjsip: tsx0x7f281030a Transaction destroyed!
15-04-2016 11:00:01.919 UTC Debug pjsip: tsx0x7f2810368 Transaction destroyed!
15-04-2016 11:00:01.944 UTC Debug pjsip:   tsx0x273a9b8 Timeout timer event
15-04-2016 11:00:01.944 UTC Debug pjsip:   tsx0x273a9b8 State changed from 
Completed to Terminated, event=TIMER
15-04-2016 11:00:01.944 UTC Debug basicproxy.cpp:213: tsx0x273a9b8 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Terminated
15-04-2016 11:00:01.944 UTC Debug basicproxy.cpp:1813: tsx0x273a9b8 - uac_tsx = 
0x25218d0, uas_tsx = (nil)
15-04-2016 11:00:01.944 UTC Debug pjsip:   tsx0x273a9b8 Timeout timer event
15-04-2016 11:00:01.944 UTC Debug pjsip:   tsx0x273a9b8 State changed from 
Terminated to Destroyed, event=TIMER
15-04-2016 11:00:01.944 UTC Debug basicproxy.cpp:213: tsx0x273a9b8 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Destroyed
15-04-2016 11:00:01.944 UTC Debug basicproxy.cpp:1813: tsx0x273a9b8 - uac_tsx = 
0x25218d0, uas_tsx = (nil)
15-04-2016 11:00:01.944 UTC Debug basicproxy.cpp:1985: tsx0x273a9b8 - UAC tsx 
destroyed
15-04-2016 11:00:01.944 UTC Debug basicproxy.cpp:1535: BasicProxy::UACTsx 
destructor (0x25218d0)
15-04-2016 11:00:01.944 UTC Debug pjsip:  tdta0x26e0d20 Destroying txdata 
Request msg REGISTER/cseq=23 (tdta0x26e0d20)
15-04-2016 11:00:01.944 UTC Debug pjsip:   tsx0x272c9f8 Transaction destroyed!
15-04-2016 11:00:01.944 UTC Debug pjsip:   tsx0x273a9b8 Transaction destroyed!
15-04-2016 11:00:01.974 UTC Debug pjsip: tsx0x7f27b841c Timeout timer event
15-04-2016 11:00:01.975 UTC Debug pjsip: tsx0x7f27b841c State changed from 
Completed to Terminated, event=TIMER
15-04-2016 11:00:01.975 UTC Debug basicproxy.cpp:213: tsx0x7f27b841c0b8 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Terminated
15-04-2016 11:00:01.975 UTC Debug basicproxy.cpp:1813: tsx0x7f27b841c0b8 - 
uac_tsx = 0x7f27b8443df0, uas_tsx = (nil)
15-04-2016 11:00:01.976 UTC Debug pjsip: tsx0x7f27b841c Timeout timer event
15-04-2016 11:00:01.976 UTC Debug pjsip: tsx0x7f27b841c State changed from 
Terminated to Destroyed, event=TIMER
15-04-2016 11:00:01.976 UTC Debug basicproxy.cpp:213: tsx0x7f27b841c0b8 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Destroyed
15-04-2016 11:00:01.976 UTC Debug basicproxy.cpp:1813: tsx0x7f27b841c0b8 - 
uac_tsx = 0x7f27b8443df0, uas_tsx = (nil)
15-04-2016 11:00:01.976 UTC Debug basicproxy.cpp:1985: tsx0x7f27b841c0b8 - UAC 
tsx destroyed
15-04-2016 11:00:01.976 UTC Debug basicproxy.cpp:1535: BasicProxy::UACTsx 
destructor (0x7f27b8443df0)
15-04-2016 11:00:01.976 UTC Debug pjsip: tdta0x7f27b840 Destroying txdata 
Request msg REGISTER/cseq=24 (tdta0x7f27b8405fb0)
15-04-2016 11:00:01.976 UTC Debug pjsip: tsx0x7f27b843d Transaction destroyed!
15-04-2016 11:00:01.976 UTC Debug pjsip: tsx0x7f27b841c Transaction destroyed!
15-04-2016 11:00:02.005 UTC Debug pjsip: tsx0x7f2794425 Timeout timer event
15-04-2016 11:00:02.005 UTC Debug pjsip: tsx0x7f2794425 State changed from 
Completed to Terminated, event=TIMER
15-04-2016 11:00:02.005 UTC Debug basicproxy.cpp:213: tsx0x7f2794425d88 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Terminated
15-04-2016 11:00:02.005 UTC Debug basicproxy.cpp:1813: tsx0x7f2794425d88 - 
uac_tsx = 0x7f27942b64f0, uas_tsx = (nil)
15-04-2016 11:00:02.005 UTC Debug pjsip: tsx0x7f2794425 Timeout timer event
15-04-2016 11:00:02.005 UTC Debug pjsip: tsx0x7f2794425 State changed from 
Terminated to Destroyed, event=TIMER
15-04-2016 11:00:02.005 UTC Debug basicproxy.cpp:213: tsx0x7f2794425d88 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Destroyed
15-04-2016 11:00:02.005 UTC Debug basicproxy.cpp:1813: tsx0x7f2794425d88 - 
uac_tsx = 0x7f27942b64f0, uas_tsx = (nil)
15-04-2016 11:00:02.005 UTC Debug basicproxy.cpp:1985: tsx0x7f2794425d88 - UAC 
tsx destroyed
15-04-2016 11:00:02.005 UTC Debug basicproxy.cpp:1535: BasicProxy::UACTsx 
destructor (0x7f27942b64f0)
15-04-2016 11:00:02.005 UTC Debug pjsip: tdta0x7f279441 Destroying txdata 
Request msg REGISTER/cseq=25 (tdta0x7f2794419890)
15-04-2016 11:00:02.005 UTC Debug pjsip: tsx0x7f279449f Transaction destroyed!
15-04-2016 11:00:02.005 UTC Debug pjsip: tsx0x7f2794425 Transaction destroyed!
15-04-2016 11:00:02.035 UTC Debug pjsip: tsx0x7f27a83a4 Timeout timer event
15-04-2016 11:00:02.035 UTC Debug pjsip: tsx0x7f27a83a4 State changed from 
Completed to Terminated, event=TIMER
15-04-2016 11:00:02.035 UTC Debug basicproxy.cpp:213: tsx0x7f27a83a4dc8 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Terminated
15-04-2016 11:00:02.035 UTC Debug basicproxy.cpp:1813: tsx0x7f27a83a4dc8 - 
uac_tsx = 0x7f27a831a380, uas_tsx = (nil)
15-04-2016 11:00:02.035 UTC Debug pjsip: tsx0x7f27a83a4 Timeout timer event
15-04-2016 11:00:02.035 UTC Debug pjsip: tsx0x7f27a83a4 State changed from 
Terminated to Destroyed, event=TIMER
15-04-2016 11:00:02.035 UTC Debug basicproxy.cpp:213: tsx0x7f27a83a4dc8 - 
tu_on_tsx_state UAC, TSX_STATE TIMER state=Destroyed
15-04-2016 11:00:02.035 UTC Debug basicproxy.cpp:1813: tsx0x7f27a83a4dc8 - 
uac_tsx = 0x7f27a831a380, uas_tsx = (nil)
15-04-2016 11:00:02.035 UTC Debug basicproxy.cpp:1985: tsx0x7f27a83a4dc8 - UAC 
tsx destroyed
15-04-2016 11:00:02.035 UTC Debug basicproxy.cpp:1535: BasicProxy::UACTsx 
destructor (0x7f27a831a380)
15-04-2016 11:00:02.035 UTC Debug pjsip: tdta0x7f27a831 Destroying txdata 
Request msg REGISTER/cseq=26 (tdta0x7f27a831f070)
15-04-2016 11:00:02.035 UTC Debug pjsip: tsx0x7f27a831a Transaction destroyed!
15-04-2016 11:00:02.035 UTC Debug pjsip: tsx0x7f27a83a4 Transaction destroyed!
15-04-2016 11:00:02.064 UTC Debug pjsip: tsx0x7f27b02a4 Timeout timer event
15-04-2016 11:00:16.190 UTC Debug impistore.cpp:194: Expires in past - dropping
15-04-2016 11:00:16.190 UTC Debug impistore.cpp:194: Expires in past - dropping
15-04-2016 11:00:16.190 UTC Debug impistore.cpp:194: Expires in past - dropping
15-04-2016 11:00:16.190 UTC Debug impistore.cpp:194: Expires in past - dropping
15-04-2016 11:00:16.190 UTC Debug impistore.cpp:194: Expires in past - dropping
15-04-2016 11:00:16.190 UTC Debug impistore.cpp:194: Expires in past - dropping
15-04-2016 11:00:16.190 UTC Debug impistore.cpp:194: Expires in past - dropping
15-04-2016 11:00:16.190 UTC Debug impistore.cpp:194: Expires in past - dropping
15-04-2016 11:00:16.190 UTC Info authentication.cpp:860: Nonce count 1 supplied 
but nonce counts are not enabled - ignore it
15-04-2016 11:00:16.190 UTC Debug acr.cpp:1765: Create RalfACR for node type 
S-CSCF with role Originating
15-04-2016 11:00:16.190 UTC Debug acr.cpp:49: Created ACR (0x7f27a036eef0)
15-04-2016 11:00:16.190 UTC Debug acr.cpp:177: Created S-CSCF Ralf ACR
15-04-2016 11:00:16.190 UTC Debug acr.cpp:216: Set record type for P/S-CSCF
15-04-2016 11:00:16.190 UTC Debug acr.cpp:224: Non-dialog message => 
EVENT_RECORD
15-04-2016 11:00:16.190 UTC Debug acr.cpp:1493: Stored 0 subscription 
identifiers
15-04-2016 11:00:16.190 UTC Debug authentication.cpp:1091: No authentication 
information in request or stale nonce, so reject with challenge
15-04-2016 11:00:16.190 UTC Debug pjsip:       endpoint Response msg 
401/REGISTER/cseq=61 (tdta0x7f27a036f620) created
15-04-2016 11:00:16.190 UTC Debug pjutils.cpp:417: Private identity from 
authorization header = [email protected]
15-04-2016 11:00:16.190 UTC Debug httpresolver.cpp:71: HttpResolver::resolve 
for host hs.xflowresearch.com, port 8888, family 2
15-04-2016 11:00:16.191 UTC Debug baseresolver.cpp:513: Attempt to parse 
hs.xflowresearch.com as IP address
15-04-2016 11:00:16.191 UTC Verbose dnscachedresolver.cpp:240: Check cache for 
hs.xflowresearch.com type 1
15-04-2016 11:00:16.191 UTC Debug dnscachedresolver.cpp:326: Pulling 1 records 
from cache for hs.xflowresearch.com A
15-04-2016 11:00:16.191 UTC Debug baseresolver.cpp:361: Found 1 A/AAAA records, 
randomizing
15-04-2016 11:00:16.191 UTC Debug baseresolver.cpp:503: 192.168.0.6:8888 
transport 6 is blacklisted
15-04-2016 11:00:16.191 UTC Debug baseresolver.cpp:420: Adding 1 servers from 
blacklist
15-04-2016 11:00:16.191 UTC Debug httpconnection.cpp:623: Sending HTTP request 
: 
http://hs.xflowresearch.com:8888/impi/2010000006%40xflowresearch.com/av?impu=sip%3A2010000006%40xflowresearch.com
 (trying 192.168.0.6) on new connection
15-04-2016 11:00:16.241 UTC Error httpconnection.cpp:643: 
http://hs.xflowresearch.com:8888/impi/2010000006%40xflowresearch.com/av?impu=sip%3A2010000006%40xflowresearch.com
 failed at server 192.168.0.6 : Timeout was reached (28) : fatal
15-04-2016 11:00:16.241 UTC Debug baseresolver.cpp:473: Add 192.168.0.6:8888 
transport 6 to blacklist for 30 seconds
15-04-2016 11:00:16.241 UTC Debug httpconnection.cpp:623: Sending HTTP request 
: 
http://hs.xflowresearch.com:8888/impi/2010000006%40xflowresearch.com/av?impu=sip%3A2010000006%40xflowresearch.com
 (trying 192.168.0.6) on new connection
15-04-2016 11:00:16.292 UTC Error httpconnection.cpp:643: 
http://hs.xflowresearch.com:8888/impi/2010000006%40xflowresearch.com/av?impu=sip%3A2010000006%40xflowresearch.com
 failed at server 192.168.0.6 : Timeout was reached (28) : fatal
15-04-2016 11:00:16.292 UTC Debug baseresolver.cpp:473: Add 192.168.0.6:8888 
transport 6 to blacklist for 30 seconds
15-04-2016 11:00:16.292 UTC Error httpconnection.cpp:762: cURL failure with 
cURL error code 28 (see man 3 libcurl-errors) and HTTP error code 500
15-04-2016 11:00:16.292 UTC Error hssconnection.cpp:147: Failed to get 
Authentication Vector for [email protected]
15-04-2016 11:00:16.292 UTC Debug authentication.cpp:625: Failed to get 
Authentication vector
_______________________________________________
Clearwater mailing list
[email protected]
http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org

Reply via email to