I am installing clearwater in 3 different machines and i am facing a
problem when trying to register using zoiper when trying to register i
received internal server error (500).
I don't know where is the problem i tired to access logs and attached it
to email.
14-03-2017 13:15:22.355 UTC Debug baseresolver.cpp:830: Successful response
from 127.0.0.1:9160 transport 6
14-03-2017 13:15:22.355 UTC Debug connection_pool.h:267: Release connection to
IP: 127.0.0.1, port: 9160 to pool
14-03-2017 13:15:22.355 UTC Debug handlers.cpp:201: Got authentication vector
with digest 61ea8247adb95f7074d14b9cca86df99 from cache
14-03-2017 13:15:22.355 UTC Verbose httpstack.cpp:93: Sending response 200 to
request for URL /impi/6505550525%40ims.cw.4gtss.com/av, args
impu=sip%3A6505550525%40ims.cw.4gtss.com
14-03-2017 13:15:38.450 UTC Debug alarm.cpp:253: Reraising all alarms with a
known state
14-03-2017 13:15:38.450 UTC Status alarm.cpp:62: homestead issued 1501.1 alarm
14-03-2017 13:16:00.583 UTC Verbose httpstack.cpp:345: Process request for URL
/ping, args (null)
14-03-2017 13:16:00.583 UTC Verbose httpstack.cpp:93: Sending response 200 to
request for URL /ping, args (null)
14-03-2017 13:16:08.450 UTC Debug alarm.cpp:253: Reraising all alarms with a
known state
14-03-2017 13:16:08.450 UTC Status alarm.cpp:62: homestead issued 1501.1 alarm
14-03-2017 13:16:30.642 UTC Verbose httpstack.cpp:345: Process request for URL
/impi/6505550525%40ims.cw.4gtss.com/registration-status, args
impu=sip%3A6505550525%40ims.cw.4gtss.com&visited-network=ims.cw.4gtss.com&auth-type=REG
14-03-2017 13:16:30.642 UTC Debug handlers.cpp:647: No HSS configured - fake
response if subscriber exists
14-03-2017 13:16:30.642 UTC Verbose httpstack.cpp:93: Sending response 200 to
request for URL /impi/6505550525%40ims.cw.4gtss.com/registration-status, args
impu=sip%3A6505550525%40ims.cw.4gtss.com&visited-network=ims.cw.4gtss.com&auth-type=REG
14-03-2017 13:16:30.683 UTC Verbose httpstack.cpp:345: Process request for URL
/impi/6505550525%40ims.cw.4gtss.com/av, args
impu=sip%3A6505550525%40ims.cw.4gtss.com
14-03-2017 13:16:30.683 UTC Debug handlers.cpp:155: Parsed HTTP request:
private ID [email protected], public ID
sip:[email protected], scheme Unknown, authorization
14-03-2017 13:16:30.683 UTC Debug handlers.cpp:181: Querying cache for
authentication vector for
[email protected]/sip:[email protected]
14-03-2017 13:16:30.683 UTC Debug a_record_resolver.cpp:80:
ARecordResolver::resolve_iter for host 127.0.0.1, port 9160, family 2
14-03-2017 13:16:30.683 UTC Debug baseresolver.cpp:425: Attempt to parse
127.0.0.1 as IP address
14-03-2017 13:16:30.683 UTC Debug a_record_resolver.cpp:88: Target is an IP
address
14-03-2017 13:16:30.683 UTC Debug connection_pool.h:231: Request for connection
to IP: 127.0.0.1, port: 9160
14-03-2017 13:16:30.683 UTC Debug connection_pool.h:244: Found existing
connection 0x7efe80007860 in pool
14-03-2017 13:16:30.683 UTC Debug cache.cpp:673: Looking for authentication
vector for [email protected]
14-03-2017 13:16:30.683 UTC Debug cache.cpp:685: Checking public ID
sip:[email protected]
14-03-2017 13:16:30.683 UTC Debug cache.cpp:695: Issuing cache query
14-03-2017 13:16:30.684 UTC Debug cassandra_store.cpp:700: Failed TWO read for
get_columns. Try ONE
14-03-2017 13:16:30.686 UTC Debug baseresolver.cpp:830: Successful response
from 127.0.0.1:9160 transport 6
14-03-2017 13:16:30.686 UTC Debug connection_pool.h:267: Release connection to
IP: 127.0.0.1, port: 9160 to pool
14-03-2017 13:16:30.686 UTC Debug communicationmonitor.cpp:82: Checking
communication changes - successful attempts 2, failures 0
14-03-2017 13:16:30.686 UTC Debug handlers.cpp:201: Got authentication vector
with digest 61ea8247adb95f7074d14b9cca86df99 from cache
14-03-2017 13:16:30.686 UTC Verbose httpstack.cpp:93: Sending response 200 to
request for URL /impi/6505550525%40ims.cw.4gtss.com/av, args
impu=sip%3A6505550525%40ims.cw.4gtss.com
14-03-2017 13:16:33.263 UTC Verbose httpstack.cpp:345: Process request for URL
/impi/6505550525%40ims.cw.4gtss.com/registration-status, args
impu=sip%3A6505550525%40ims.cw.4gtss.com&visited-network=ims.cw.4gtss.com&auth-type=REG
14-03-2017 13:16:33.263 UTC Debug handlers.cpp:647: No HSS configured - fake
response if subscriber exists
14-03-2017 13:16:33.263 UTC Verbose httpstack.cpp:93: Sending response 200 to
request for URL /impi/6505550525%40ims.cw.4gtss.com/registration-status, args
impu=sip%3A6505550525%40ims.cw.4gtss.com&visited-network=ims.cw.4gtss.com&auth-type=REG
14-03-2017 13:16:33.279 UTC Verbose httpstack.cpp:345: Process request for URL
/impi/6505550525%40ims.cw.4gtss.com/av, args
impu=sip%3A6505550525%40ims.cw.4gtss.com
14-03-2017 13:16:33.279 UTC Debug handlers.cpp:155: Parsed HTTP request:
private ID [email protected], public ID
sip:[email protected], scheme Unknown, authorization
14-03-2017 13:16:33.279 UTC Debug handlers.cpp:181: Querying cache for
authentication vector for
[email protected]/sip:[email protected]
14-03-2017 13:16:33.279 UTC Debug a_record_resolver.cpp:80:
ARecordResolver::resolve_iter for host 127.0.0.1, port 9160, family 2
14-03-2017 13:16:33.279 UTC Debug baseresolver.cpp:425: Attempt to parse
127.0.0.1 as IP address
14-03-2017 13:16:33.279 UTC Debug a_record_resolver.cpp:88: Target is an IP
address
14-03-2017 13:16:33.279 UTC Debug connection_pool.h:231: Request for connection
to IP: 127.0.0.1, port: 9160
14-03-2017 13:16:33.279 UTC Debug connection_pool.h:244: Found existing
connection 0x7efe80007860 in pool
14-03-2017 13:16:33.279 UTC Debug cache.cpp:673: Looking for authentication
vector for [email protected]
14-03-2017 13:16:33.279 UTC Debug cache.cpp:685: Checking public ID
sip:[email protected]
14-03-2017 13:16:33.279 UTC Debug cache.cpp:695: Issuing cache query
14-03-2017 13:16:33.280 UTC Debug cassandra_store.cpp:700: Failed TWO read for
get_columns. Try ONE
14-03-2017 13:16:33.282 UTC Debug baseresolver.cpp:830: Successful response
from 127.0.0.1:9160 transport 6
14-03-2017 13:16:33.282 UTC Debug connection_pool.h:267: Release connection to
IP: 127.0.0.1, port: 9160 to pool
14-03-2017 13:16:33.282 UTC Debug handlers.cpp:201: Got authentication vector
with digest 61ea8247adb95f7074d14b9cca86df99 from cache
14-03-2017 13:16:33.282 UTC Verbose httpstack.cpp:93: Sending response 200 to
request for URL /impi/6505550525%40ims.cw.4gtss.com/av, args
impu=sip%3A6505550525%40ims.cw.4gtss.com
^C[homestead-sprout]deeb@sprout:~$
[homestead-sprout]deeb@sprout:~$ sudo tailf
/var/log/homestead/homestead_current.txt
14-03-2017 13:16:37.833 UTC Debug cache.cpp:695: Issuing cache query
14-03-2017 13:16:37.835 UTC Debug cassandra_store.cpp:700: Failed TWO read for
get_columns. Try ONE
14-03-2017 13:16:37.837 UTC Debug baseresolver.cpp:830: Successful response
from 127.0.0.1:9160 transport 6
14-03-2017 13:16:37.837 UTC Debug connection_pool.h:267: Release connection to
IP: 127.0.0.1, port: 9160 to pool
14-03-2017 13:16:37.837 UTC Debug handlers.cpp:201: Got authentication vector
with digest 61ea8247adb95f7074d14b9cca86df99 from cache
14-03-2017 13:16:37.837 UTC Verbose httpstack.cpp:93: Sending response 200 to
request for URL /impi/6505550525%40ims.cw.4gtss.com/av, args
impu=sip%3A6505550525%40ims.cw.4gtss.com
14-03-2017 13:16:37.837 UTC Info load_monitor.cpp:232: Accepted 100.000000% of
requests, latency error = -0.978120, overload responses = 0
14-03-2017 13:16:37.837 UTC Status load_monitor.cpp:285: Maximum incoming
request rate/second unchanged - only handled 22 requests in last 109256ms,
minimum threshold for a change is 4552.333008
14-03-2017 13:16:38.451 UTC Debug alarm.cpp:253: Reraising all alarms with a
known state
14-03-2017 13:16:38.451 UTC Status alarm.cpp:62: homestead issued 1501.1 alarm
14-03-2017 13:16:42.019 UTC Verbose httpstack.cpp:345: Process request for URL
/impi/6505550525%40ims.cw.4gtss.com/registration-status, args
impu=sip%3A6505550525%40ims.cw.4gtss.com&visited-network=ims.cw.4gtss.com&auth-type=REG
14-03-2017 13:16:42.019 UTC Debug handlers.cpp:647: No HSS configured - fake
response if subscriber exists
14-03-2017 13:16:42.019 UTC Verbose httpstack.cpp:93: Sending response 200 to
request for URL /impi/6505550525%40ims.cw.4gtss.com/registration-status, args
impu=sip%3A6505550525%40ims.cw.4gtss.com&visited-network=ims.cw.4gtss.com&auth-type=REG
14-03-2017 13:16:42.039 UTC Verbose httpstack.cpp:345: Process request for URL
/impi/6505550525%40ims.cw.4gtss.com/av, args
impu=sip%3A6505550525%40ims.cw.4gtss.com
14-03-2017 13:16:42.039 UTC Debug handlers.cpp:155: Parsed HTTP request:
private ID [email protected], public ID
sip:[email protected], scheme Unknown, authorization
14-03-2017 13:16:42.039 UTC Debug handlers.cpp:181: Querying cache for
authentication vector for
[email protected]/sip:[email protected]
14-03-2017 13:16:42.039 UTC Debug a_record_resolver.cpp:80:
ARecordResolver::resolve_iter for host 127.0.0.1, port 9160, family 2
14-03-2017 13:16:42.039 UTC Debug baseresolver.cpp:425: Attempt to parse
127.0.0.1 as IP address
14-03-2017 13:16:42.040 UTC Debug a_record_resolver.cpp:88: Target is an IP
address
14-03-2017 13:16:42.040 UTC Debug connection_pool.h:231: Request for connection
to IP: 127.0.0.1, port: 9160
14-03-2017 13:16:42.040 UTC Debug connection_pool.h:244: Found existing
connection 0x7efe80007860 in pool
14-03-2017 13:16:42.040 UTC Debug cache.cpp:673: Looking for authentication
vector for [email protected]
14-03-2017 13:16:42.040 UTC Debug cache.cpp:685: Checking public ID
sip:[email protected]
14-03-2017 13:16:42.040 UTC Debug cache.cpp:695: Issuing cache query
14-03-2017 13:16:42.041 UTC Debug cassandra_store.cpp:700: Failed TWO read for
get_columns. Try ONE
14-03-2017 13:16:42.042 UTC Debug baseresolver.cpp:830: Successful response
from 127.0.0.1:9160 transport 6
14-03-2017 13:16:42.042 UTC Debug connection_pool.h:267: Release connection to
IP: 127.0.0.1, port: 9160 to pool
14-03-2017 13:16:42.043 UTC Debug handlers.cpp:201: Got authentication vector
with digest 61ea8247adb95f7074d14b9cca86df99 from cache
14-03-2017 13:16:42.043 UTC Verbose httpstack.cpp:93: Sending response 200 to
request for URL /impi/6505550525%40ims.cw.4gtss.com/av, args
impu=sip%3A6505550525%40ims.cw.4gtss.com
Monit 5.18.1 uptime: 1h 17m
Process 'sprout_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 1499
parent pid 1
uid 998
effective uid 998
gid 998
uptime 1h 17m
threads 148
children 0
cpu 0.7%
cpu total 0.7%
memory 0.2% [3.1 MB]
memory total 0.2% [3.1 MB]
data collected Tue, 14 Mar 2017 15:11:54
Program 'sprout_uptime'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output zmq_msg_recv: Resource temporarily unavailable
data collected Tue, 14 Mar 2017 15:11:54
Program 'poll_sprout_sip'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output -
data collected Tue, 14 Mar 2017 15:11:54
Program 'poll_sprout_http'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output -
data collected Tue, 14 Mar 2017 15:11:54
Process 'snmpd_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 1589
parent pid 1
uid 120
effective uid 120
gid 131
uptime 1h 17m
threads 1
children 0
cpu 0.0%
cpu total 0.0%
memory 0.1% [2.7 MB]
memory total 0.1% [2.7 MB]
data collected Tue, 14 Mar 2017 15:11:54
Process 'ntp_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 2087
parent pid 1
uid 116
effective uid 116
gid 127
uptime 1h 17m
threads 1
children 0
cpu 0.0%
cpu total 0.0%
memory 0.1% [2.8 MB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:54
System 'node-sprout'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
load average [0.00] [0.21] [0.34]
cpu 2.4%us 2.5%sy 1.1%wa
memory usage 1.6 GB [83.1%]
swap usage 496.6 MB [48.5%]
uptime 1h 17m
boot time Tue, 14 Mar 2017 13:54:10
data collected Tue, 14 Mar 2017 15:11:54
Process 'nginx_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 1583
parent pid 1
uid 0
effective uid 0
gid 0
uptime 1h 17m
threads 1
children 0
cpu 0.0%
cpu total 0.0%
memory 0.1% [1.1 MB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:54
Program 'nginx_ping'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output % Total % Received % Xferd Average Speed
Time Time Time Current
Dload Upload
Total Spent Left Speed
0 0 0 0 0 0 0 0
--:--:-- --:--:-- --:--:-- 0100 193 100 193 0 0 16146 0
--:--:-- --:--:-- --:--:-- 188k
<html>
<head><title>301 Moved Permanently</title></head>
<body bgcolor="white">
<center><h1>301 Moved Permanently</h1></center>
<hr><center>nginx/1.4.6 (Ubuntu)</center>
</body>
</html>
data collected Tue, 14 Mar 2017 15:11:54
Program 'nginx_uptime'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output zmq_msg_recv: Resource temporarily unavailable
data collected Tue, 14 Mar 2017 15:11:54
Program 'monit_uptime'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output zmq_msg_recv: Resource temporarily unavailable
data collected Tue, 14 Mar 2017 15:11:54
Process 'memento_process'
status Execution failed | Does not exist
monitoring status Monitored
monitoring mode active
on reboot start
data collected Tue, 14 Mar 2017 15:11:13
Program 'memento_uptime'
status Wait parent
monitoring status Wait parent
monitoring mode active
on reboot start
data collected Tue, 14 Mar 2017 13:56:18
Program 'poll_memento'
status Wait parent
monitoring status Wait parent
monitoring mode active
on reboot start
data collected Tue, 14 Mar 2017 13:56:18
Program 'poll_memento_https'
status Wait parent
monitoring status Wait parent
monitoring mode active
on reboot start
data collected Tue, 14 Mar 2017 13:56:18
Process 'memcached_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 3169
parent pid 1
uid 119
effective uid 119
gid 130
uptime 1h 15m
threads 6
children 0
cpu 0.0%
cpu total 0.0%
memory 0.1% [1.6 MB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:13
Program 'memcached_uptime'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output zmq_msg_recv: Resource temporarily unavailable
data collected Tue, 14 Mar 2017 15:11:13
Program 'poll_memcached'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output -
data collected Tue, 14 Mar 2017 15:11:13
Process 'homestead_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 3208
parent pid 1
uid 989
effective uid 989
gid 989
uptime 1h 15m
threads 121
children 0
cpu 0.0%
cpu total 0.0%
memory 0.0% [0 B]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:13
Program 'homestead_uptime'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output zmq_msg_recv: Resource temporarily unavailable
data collected Tue, 14 Mar 2017 15:11:13
Program 'poll_homestead'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output -
data collected Tue, 14 Mar 2017 15:11:13
Program 'check_cx_health'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 1
last output Traceback (most recent call last):
File
"/usr/share/clearwater/bin/check_cx_health.py", line 64, in <module>
import netsnmp
ImportError: No module named netsnmp
data collected Tue, 14 Mar 2017 15:11:13
Process 'homestead-prov_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 13588
parent pid 1
uid 0
effective uid 0
gid 0
uptime 38m
threads 6
children 0
cpu 0.0%
cpu total 0.0%
memory 1.1% [22.9 MB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:13
Program 'poll_homestead-prov'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output -
data collected Tue, 14 Mar 2017 15:11:13
Process 'clearwater_queue_manager_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 2678
parent pid 1
uid 0
effective uid 0
gid 0
uptime 1h 15m
threads 10
children 0
cpu 0.0%
cpu total 0.0%
memory 0.5% [10.2 MB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:13
Program 'clearwater_queue_manager_uptime'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output zmq_msg_recv: Resource temporarily unavailable
data collected Tue, 14 Mar 2017 15:11:13
Process 'etcd_process'
status Execution failed | Does not exist
monitoring status Monitored
monitoring mode active
on reboot start
data collected Tue, 14 Mar 2017 15:11:44
Program 'etcd_uptime'
status Wait parent
monitoring status Wait parent
monitoring mode active
on reboot start
data collected Tue, 14 Mar 2017 13:56:18
Program 'poll_etcd_cluster'
status Wait parent
monitoring status Wait parent
monitoring mode active
on reboot start
data collected Tue, 14 Mar 2017 13:56:18
Program 'poll_etcd'
status Wait parent
monitoring status Wait parent
monitoring mode active
on reboot start
data collected Tue, 14 Mar 2017 13:56:18
Process 'clearwater_diags_monitor_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 1488
parent pid 1
uid 0
effective uid 0
gid 0
uptime 1h 16m
threads 1
children 0
cpu 0.0%
cpu total 0.0%
memory 0.1% [2.1 MB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:44
Process 'clearwater_config_manager_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 2606
parent pid 1
uid 0
effective uid 0
gid 0
uptime 1h 15m
threads 8
children 0
cpu 0.0%
cpu total 0.0%
memory 0.5% [10.7 MB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:44
Process 'clearwater_cluster_manager_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 2565
parent pid 1
uid 0
effective uid 0
gid 0
uptime 1h 15m
threads 5
children 0
cpu 0.0%
cpu total 0.0%
memory 0.3% [5.1 MB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:44
Process 'cassandra_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 2580
parent pid 1
uid 117
effective uid 117
gid 128
uptime 1h 15m
threads 99
children 0
cpu 0.0%
cpu total 0.0%
memory 67.1% [1.3 GB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:44
Program 'cassandra_uptime'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output zmq_msg_recv: Resource temporarily unavailable
data collected Tue, 14 Mar 2017 15:11:44
Program 'poll_cassandra'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output -
data collected Tue, 14 Mar 2017 15:11:44
Program 'poll_cqlsh'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output -
data collected Tue, 14 Mar 2017 15:11:44
Process 'chronos_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 2764
parent pid 1
uid 992
effective uid 992
gid 992
uptime 1h 15m
threads 235
children 0
cpu 0.0%
cpu total 0.0%
memory 0.0% [764 kB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:44
Program 'chronos_uptime'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output zmq_msg_recv: Resource temporarily unavailable
data collected Tue, 14 Mar 2017 15:11:44
Program 'poll_chronos'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output -
data collected Tue, 14 Mar 2017 15:11:44
Process 'astaire_process'
status Running
monitoring status Monitored
monitoring mode active
on reboot start
pid 2478
parent pid 1
uid 996
effective uid 996
gid 996
uptime 1h 15m
threads 19
children 0
cpu 0.0%
cpu total 0.0%
memory 0.2% [4.7 MB]
memory total 0.0% [0 B]
data collected Tue, 14 Mar 2017 15:11:44
Program 'astaire_uptime'
status Status ok
monitoring status Monitored
monitoring mode active
on reboot start
last exit value 0
last output zmq_msg_recv: Resource temporarily unavailable
data collected Tue, 14 Mar 2017 15:11:44
Monit 5.18.1 uptime: 1h 17m
Service Name Status Type
node-sprout Running System
sprout_process Running Process
snmpd_process Running Process
ntp_process Running Process
nginx_process Running Process
memento_process Execution failed | Does... Process
memcached_process Running Process
homestead_process Running Process
homestead-prov_process Running Process
clearwater_queue_manager_pro... Running Process
etcd_process Execution failed | Does... Process
clearwater_diags_monitor_pro... Running Process
clearwater_config_manager_pr... Running Process
clearwater_cluster_manager_p... Running Process
cassandra_process Running Process
chronos_process Running Process
astaire_process Running Process
sprout_uptime Status ok Program
poll_sprout_sip Status ok Program
poll_sprout_http Status ok Program
nginx_ping Status ok Program
nginx_uptime Status ok Program
monit_uptime Status ok Program
memento_uptime Wait parent Program
poll_memento Wait parent Program
poll_memento_https Wait parent Program
memcached_uptime Status ok Program
poll_memcached Status ok Program
homestead_uptime Status ok Program
poll_homestead Status ok Program
check_cx_health Status ok Program
poll_homestead-prov Status ok Program
clearwater_queue_manager_uptime Status ok Program
etcd_uptime Wait parent Program
poll_etcd_cluster Wait parent Program
poll_etcd Wait parent Program
cassandra_uptime Status ok Program
poll_cassandra Status ok Program
poll_cqlsh Status ok Program
chronos_uptime Status ok Program
poll_chronos Status ok Program
astaire_uptime Status ok Program
14-03-2017 13:14:22.991 UTC Debug pjsip: tdta0x7fb00802 Destroying txdata
Request msg REGISTER/cseq=1 (tdta0x7fb008022760)
14-03-2017 13:14:22.991 UTC Debug basicproxy.cpp:534: Free un-used best response
14-03-2017 13:14:22.991 UTC Debug pjsip: tdta0x7fb00803 Destroying txdata
Response msg 408/REGISTER/cseq=1 (tdta0x7fb008030a50)
14-03-2017 13:14:22.991 UTC Debug basicproxy.cpp:555: BasicProxy::UASTsx
destructor completed
14-03-2017 13:14:22.991 UTC Debug pjsip: tdta0x7fb00806 Destroying txdata
Response msg 500/REGISTER/cseq=1 (tdta0x7fb00806e960)
14-03-2017 13:14:22.992 UTC Debug pjsip: tsx0x7fb00800f Transaction destroyed!
14-03-2017 13:14:24.412 UTC Verbose pjsip: tcps0x7fb00c04 TCP transport
destroyed normally
14-03-2017 13:14:24.663 UTC Verbose pjsip: tcplis:5052 TCP listener
192.168.0.212:5052: got incoming TCP connection from 192.168.0.210:46941,
sock=196
14-03-2017 13:14:24.664 UTC Verbose pjsip: tcps0x7fb00c02 tcp->base.local_name:
192.168.0.212
14-03-2017 13:14:24.664 UTC Verbose pjsip: tcps0x7fb00c02 TCP server transport
created
14-03-2017 13:14:26.513 UTC Debug pjsip: sip_endpoint.c Processing incoming
message: Request msg REGISTER/cseq=1 (rdata0x7fb00c033730)
14-03-2017 13:14:26.513 UTC Verbose common_sip_processing.cpp:120: RX 789 bytes
Request msg REGISTER/cseq=1 (rdata0x7fb00c033730) from TCP 192.168.0.210:45333:
--start msg--
REGISTER sip:ims.cw.4gtss.com;transport=UDP SIP/2.0
Via: SIP/2.0/TCP
192.168.0.210:5058;rport;branch=z9hG4bKPjxt2aG60D4lt04G2ED2a3NEeUND3o7Pwk
Path: <sip:[email protected]:5058;transport=TCP;lr;ob>
Via: SIP/2.0/UDP
192.168.0.209:52124;rport=52124;received=192.168.0.209;branch=z9hG4bK-524287-1---f7dc3c756b6f3896
Max-Forwards: 70
Contact:
<sip:[email protected]:52124;transport=UDP;rinstance=283ff0dd3b564291>
To: <sip:[email protected]>
From: <sip:[email protected]>;tag=1959ab22
Call-ID: qq0DpjcQWNRPGQUHa87JrQ..
CSeq: 1 REGISTER
Expires: 6000
User-Agent: Zoiper rv2.8.30
Allow-Events: presence, kpml, talk
P-Visited-Network-ID: ims.cw.4gtss.com
Route: <sip:icscf.sprout.ims.cw.4gtss.com:5052;transport=TCP;lr;orig>
Content-Length: 0
--end msg--
14-03-2017 13:14:26.513 UTC Debug pjutils.cpp:1689: Logging SAS Call-ID marker,
Call-ID qq0DpjcQWNRPGQUHa87JrQ..
14-03-2017 13:14:26.513 UTC Debug thread_dispatcher.cpp:264: Queuing cloned
received message 0x7fb00c0dc838 for worker threads
14-03-2017 13:14:26.513 UTC Debug thread_dispatcher.cpp:150: Worker thread
dequeue message 0x7fb00c0dc838
14-03-2017 13:14:26.513 UTC Debug pjsip: sip_endpoint.c Distributing rdata to
modules: Request msg REGISTER/cseq=1 (rdata0x7fb00c0dc838)
14-03-2017 13:14:26.513 UTC Debug uri_classifier.cpp:174: home domain: true,
local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip:
true, treat_number_as_phone: false
14-03-2017 13:14:26.513 UTC Debug uri_classifier.cpp:204: Classified URI as 4
14-03-2017 13:14:26.514 UTC Debug basicproxy.cpp:92: Process REGISTER request
14-03-2017 13:14:26.514 UTC Verbose sproutletproxy.cpp:507: Sproutlet Proxy
transaction (0x7fb004020bc0) created
14-03-2017 13:14:26.514 UTC Debug basicproxy.cpp:1298: Report SAS start marker
- trail (7a)
14-03-2017 13:14:26.514 UTC Debug pjutils.cpp:699: Cloned Request msg
REGISTER/cseq=1 (rdata0x7fb00c0dc838) to tdta0x7fb004042010
14-03-2017 13:14:26.514 UTC Debug pjsip: tsx0x7fb00408d Transaction created for
Request msg REGISTER/cseq=1 (rdata0x7fb00c0dc838)
14-03-2017 13:14:26.514 UTC Debug pjsip: tsx0x7fb00408d Incoming Request msg
REGISTER/cseq=1 (rdata0x7fb00c0dc838) in state Null
14-03-2017 13:14:26.514 UTC Debug pjsip: tsx0x7fb00408d State changed from Null
to Trying, event=RX_MSG
14-03-2017 13:14:26.514 UTC Debug basicproxy.cpp:213: tsx0x7fb00408de18 -
tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying
14-03-2017 13:14:26.514 UTC Debug pjsip: endpoint Response msg
408/REGISTER/cseq=1 (tdta0x7fb004010500) created
14-03-2017 13:14:26.514 UTC Debug sproutletproxy.cpp:119: Find target Sproutlet
for request
14-03-2017 13:14:26.514 UTC Debug sproutletproxy.cpp:154: Found next routable
URI: sip:icscf.sprout.ims.cw.4gtss.com:5052;transport=TCP;lr;orig
14-03-2017 13:14:26.514 UTC Debug sproutletproxy.cpp:289: Possible service name
icscf will be used if sprout.ims.cw.4gtss.com is a local hostname
14-03-2017 13:14:26.514 UTC Debug sproutletproxy.cpp:293: Adding possible
service name icscf based on domain
14-03-2017 13:14:26.514 UTC Debug sproutletproxy.cpp:289: Possible service name
icscf will be used if sprout.ims.cw.4gtss.com is a local hostname
14-03-2017 13:14:26.514 UTC Debug sproutletproxy.cpp:293: Adding possible
service name icscf based on domain
14-03-2017 13:14:26.514 UTC Debug sproutletproxy.cpp:289: Possible service name
icscf will be used if sprout.ims.cw.4gtss.com is a local hostname
14-03-2017 13:14:26.514 UTC Debug sproutletproxy.cpp:293: Adding possible
service name icscf based on domain
14-03-2017 13:14:26.514 UTC Verbose sproutletproxy.cpp:1163: Created Sproutlet
icscf-0x7fb004020750 for Request msg REGISTER/cseq=1 (tdta0x7fb004042010)
14-03-2017 13:14:26.514 UTC Verbose sproutletproxy.cpp:2095: Routing Request
msg REGISTER/cseq=1 (tdta0x7fb004042010) (818 bytes) to downstream sproutlet
icscf:
--start msg--
REGISTER sip:ims.cw.4gtss.com;transport=UDP SIP/2.0
Via: SIP/2.0/TCP
192.168.0.210:5058;rport=45333;received=192.168.0.210;branch=z9hG4bKPjxt2aG60D4lt04G2ED2a3NEeUND3o7Pwk
Path: <sip:[email protected]:5058;transport=TCP;lr;ob>
Via: SIP/2.0/UDP
192.168.0.209:52124;rport=52124;received=192.168.0.209;branch=z9hG4bK-524287-1---f7dc3c756b6f3896
Max-Forwards: 70
Contact:
<sip:[email protected]:52124;transport=UDP;rinstance=283ff0dd3b564291>
To: <sip:[email protected]>
From: <sip:[email protected]>;tag=1959ab22
Call-ID: qq0DpjcQWNRPGQUHa87JrQ..
CSeq: 1 REGISTER
Expires: 6000
User-Agent: Zoiper rv2.8.30
Allow-Events: presence, kpml, talk
P-Visited-Network-ID: ims.cw.4gtss.com
Route: <sip:icscf.sprout.ims.cw.4gtss.com:5052;transport=TCP;lr;orig>
Content-Length: 0
--end msg--
14-03-2017 13:14:26.514 UTC Debug pjutils.cpp:716: Cloned tdta0x7fb004042010 to
tdta0x7fb004011510
14-03-2017 13:14:26.514 UTC Debug sproutletproxy.cpp:1224: Remove top Route
header Route: <sip:icscf.sprout.ims.cw.4gtss.com:5052;transport=TCP;lr;orig>
14-03-2017 13:14:26.514 UTC Debug sproutletproxy.cpp:1768: Adding message
0x7fb004011b20 => txdata 0x7fb0040115b8 mapping
14-03-2017 13:14:26.514 UTC Verbose sproutletproxy.cpp:1613:
icscf-0x7fb004020750 pass initial request Request msg REGISTER/cseq=1
(tdta0x7fb004011510) to Sproutlet
14-03-2017 13:14:26.514 UTC Debug acr.cpp:1812: Create RalfACR for node type
I-CSCF with role Terminating
14-03-2017 13:14:26.514 UTC Debug acr.cpp:49: Created ACR (0x7fb00408ce10)
14-03-2017 13:14:26.514 UTC Debug acr.cpp:189: Created I-CSCF Ralf ACR
14-03-2017 13:14:26.514 UTC Debug acr.cpp:269: Set record type for I-CSCF,
BGCF, IBCF, AS to EVENT_RECORD
14-03-2017 13:14:26.514 UTC Debug icscfsproutlet.cpp:193: I-CSCF initialize
transaction for REGISTER request
14-03-2017 13:14:26.514 UTC Debug icscfrouter.cpp:345: Perform UAR - impi
[email protected], impu sip:[email protected], vn
ims.cw.4gtss.com, auth_type REG
14-03-2017 13:14:26.516 UTC Debug a_record_resolver.cpp:80:
ARecordResolver::resolve_iter for host hs.ims.cw.4gtss.com, port 8888, family 2
14-03-2017 13:14:26.516 UTC Debug baseresolver.cpp:425: Attempt to parse
hs.ims.cw.4gtss.com as IP address
14-03-2017 13:14:26.516 UTC Verbose dnscachedresolver.cpp:486: Check cache for
hs.ims.cw.4gtss.com type 1
14-03-2017 13:14:26.517 UTC Debug dnscachedresolver.cpp:588: Pulling 1 records
from cache for hs.ims.cw.4gtss.com A
14-03-2017 13:14:26.517 UTC Debug baseresolver.cpp:366: Found 1 A/AAAA records,
creating iterator
14-03-2017 13:14:26.517 UTC Debug baseresolver.cpp:425: Attempt to parse
hs.ims.cw.4gtss.com as IP address
14-03-2017 13:14:26.517 UTC Debug baseresolver.cpp:819: 192.168.0.212:8888
transport 6 has state: WHITE
14-03-2017 13:14:26.517 UTC Debug baseresolver.cpp:819: 192.168.0.212:8888
transport 6 has state: WHITE
14-03-2017 13:14:26.517 UTC Debug baseresolver.cpp:1004: Added a whitelisted
server, now have 1 of 1
14-03-2017 13:14:26.517 UTC Debug connection_pool.h:231: Request for connection
to IP: 192.168.0.212, port: 8888
14-03-2017 13:14:26.517 UTC Debug connection_pool.h:244: Found existing
connection 0x7fb004021830 in pool
14-03-2017 13:14:26.517 UTC Debug httpclient.cpp:478: Set CURLOPT_RESOLVE:
hs.ims.cw.4gtss.com:8888:192.168.0.212
14-03-2017 13:14:26.517 UTC Debug httpclient.cpp:505: Sending HTTP request :
http://hs.ims.cw.4gtss.com:8888/impi/6505550525%40ims.cw.4gtss.com/registration-status?impu=sip%3A6505550525%40ims.cw.4gtss.com&visited-network=ims.cw.4gtss.com&auth-type=REG
(trying 192.168.0.212)
14-03-2017 13:14:26.518 UTC Debug httpclient.cpp:832: Received header
http/1.1200ok with value
14-03-2017 13:14:26.518 UTC Debug httpclient.cpp:833: Header pointer:
0x7fb020d1e350
14-03-2017 13:14:26.518 UTC Debug httpclient.cpp:832: Received header
content-length with value 83
14-03-2017 13:14:26.518 UTC Debug httpclient.cpp:833: Header pointer:
0x7fb020d1e350
14-03-2017 13:14:26.518 UTC Debug httpclient.cpp:832: Received header
content-type with value text/plain
14-03-2017 13:14:26.518 UTC Debug httpclient.cpp:833: Header pointer:
0x7fb020d1e350
14-03-2017 13:14:26.518 UTC Debug httpclient.cpp:832: Received header with
value
14-03-2017 13:14:26.518 UTC Debug httpclient.cpp:833: Header pointer:
0x7fb020d1e350
14-03-2017 13:14:26.518 UTC Debug httpclient.cpp:538: Received HTTP response:
status=200,
doc={"result-code":2001,"scscf":"sip:scscf.sprout.ims.cw.4gtss.com:5054;transport=TCP"}
14-03-2017 13:14:26.518 UTC Debug baseresolver.cpp:830: Successful response
from 192.168.0.212:8888 transport 6
14-03-2017 13:14:26.518 UTC Debug connection_pool.h:267: Release connection to
IP: 192.168.0.212, port: 8888 to pool
14-03-2017 13:14:26.518 UTC Debug icscfrouter.cpp:237: HSS returned S-CSCF
sip:scscf.sprout.ims.cw.4gtss.com:5054;transport=TCP as target
14-03-2017 13:14:26.518 UTC Debug acr.cpp:653: Storing Server-Capabilities
14-03-2017 13:14:26.518 UTC Debug icscfrouter.cpp:113: SCSCF specified by HSS:
sip:scscf.sprout.ims.cw.4gtss.com:5054;transport=TCP
14-03-2017 13:14:26.518 UTC Debug uri_classifier.cpp:174: home domain: false,
local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip:
true, treat_number_as_phone: false
14-03-2017 13:14:26.518 UTC Debug uri_classifier.cpp:204: Classified URI as 3
14-03-2017 13:14:26.519 UTC Debug icscfsproutlet.cpp:279: Found SCSCF for
REGISTER
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:1364: Sproutlet
send_request 0x7fb004011b20
14-03-2017 13:14:26.519 UTC Verbose sproutletproxy.cpp:1400:
icscf-0x7fb004020750 sending Request msg REGISTER/cseq=1 (tdta0x7fb004011510)
on fork 0
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:1783: Processing actions
from sproutlet - 0 responses, 1 requests, 0 timers
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:1823: Processing request
0x7fb0040115b8, fork = 0
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:1947: icscf-0x7fb004020750
transmitting request on fork 0
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:1961: icscf-0x7fb004020750
store reference to non-ACK request Request msg REGISTER/cseq=1
(tdta0x7fb004011510) on fork 0
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:1775: Removing message
0x7fb004011b20 => txdata 0x7fb0040115b8 mapping
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:119: Find target Sproutlet
for request
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:154: Found next routable
URI: sip:scscf.sprout.ims.cw.4gtss.com:5054;transport=TCP
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:289: Possible service name
scscf will be used if sprout.ims.cw.4gtss.com is a local hostname
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:293: Adding possible
service name scscf based on domain
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:289: Possible service name
scscf will be used if sprout.ims.cw.4gtss.com is a local hostname
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:293: Adding possible
service name scscf based on domain
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:289: Possible service name
scscf will be used if sprout.ims.cw.4gtss.com is a local hostname
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:293: Adding possible
service name scscf based on domain
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:289: Possible service name
scscf will be used if sprout.ims.cw.4gtss.com is a local hostname
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:293: Adding possible
service name scscf based on domain
14-03-2017 13:14:26.519 UTC Verbose sproutletproxy.cpp:1163: Created Sproutlet
authentication-0x7fb00408bc60 for Request msg REGISTER/cseq=1
(tdta0x7fb004011510)
14-03-2017 13:14:26.519 UTC Verbose sproutletproxy.cpp:2095: Routing Request
msg REGISTER/cseq=1 (tdta0x7fb004011510) (765 bytes) to downstream sproutlet
authentication:
--start msg--
REGISTER sip:scscf.sprout.ims.cw.4gtss.com:5054;transport=TCP SIP/2.0
Via: SIP/2.0/TCP
192.168.0.210:5058;rport=45333;received=192.168.0.210;branch=z9hG4bKPjxt2aG60D4lt04G2ED2a3NEeUND3o7Pwk
Path: <sip:[email protected]:5058;transport=TCP;lr;ob>
Via: SIP/2.0/UDP
192.168.0.209:52124;rport=52124;received=192.168.0.209;branch=z9hG4bK-524287-1---f7dc3c756b6f3896
Max-Forwards: 69
Contact:
<sip:[email protected]:52124;transport=UDP;rinstance=283ff0dd3b564291>
To: <sip:[email protected]>
From: <sip:[email protected]>;tag=1959ab22
Call-ID: qq0DpjcQWNRPGQUHa87JrQ..
CSeq: 1 REGISTER
Expires: 6000
User-Agent: Zoiper rv2.8.30
Allow-Events: presence, kpml, talk
P-Visited-Network-ID: ims.cw.4gtss.com
Content-Length: 0
--end msg--
14-03-2017 13:14:26.519 UTC Debug pjutils.cpp:716: Cloned tdta0x7fb004011510 to
tdta0x7fb0040abd00
14-03-2017 13:14:26.519 UTC Debug sproutletproxy.cpp:1768: Adding message
0x7fb0040ac310 => txdata 0x7fb0040abda8 mapping
14-03-2017 13:14:26.519 UTC Verbose sproutletproxy.cpp:1613:
authentication-0x7fb00408bc60 pass initial request Request msg REGISTER/cseq=1
(tdta0x7fb0040abd00) to Sproutlet
14-03-2017 13:14:26.519 UTC Debug authenticationsproutlet.cpp:829:
Authentication module invoked
14-03-2017 13:14:26.519 UTC Debug authenticationsproutlet.cpp:841: Request
needs authentication
14-03-2017 13:14:26.519 UTC Debug acr.cpp:1812: Create RalfACR for node type
S-CSCF with role Originating
14-03-2017 13:14:26.519 UTC Debug acr.cpp:49: Created ACR (0x7fb004020e60)
14-03-2017 13:14:26.520 UTC Debug acr.cpp:189: Created S-CSCF Ralf ACR
14-03-2017 13:14:26.520 UTC Debug acr.cpp:229: Set record type for P/S-CSCF
14-03-2017 13:14:26.520 UTC Debug acr.cpp:237: Non-dialog message =>
EVENT_RECORD
14-03-2017 13:14:26.520 UTC Debug acr.cpp:1540: Stored 0 subscription
identifiers
14-03-2017 13:14:26.520 UTC Debug authenticationsproutlet.cpp:1150: No
authentication information in request or stale nonce, so reject with challenge
14-03-2017 13:14:26.520 UTC Debug sproutletproxy.cpp:1768: Adding message
0x7fb0040ae2d0 => txdata 0x7fb0040add68 mapping
14-03-2017 13:14:26.520 UTC Debug pjutils.cpp:423: Private identity defaulted
from public identity = [email protected]
14-03-2017 13:14:26.520 UTC Debug a_record_resolver.cpp:80:
ARecordResolver::resolve_iter for host hs.ims.cw.4gtss.com, port 8888, family 2
14-03-2017 13:14:26.520 UTC Debug baseresolver.cpp:425: Attempt to parse
hs.ims.cw.4gtss.com as IP address
14-03-2017 13:14:26.520 UTC Verbose dnscachedresolver.cpp:486: Check cache for
hs.ims.cw.4gtss.com type 1
14-03-2017 13:14:26.520 UTC Debug dnscachedresolver.cpp:588: Pulling 1 records
from cache for hs.ims.cw.4gtss.com A
14-03-2017 13:14:26.520 UTC Debug baseresolver.cpp:366: Found 1 A/AAAA records,
creating iterator
14-03-2017 13:14:26.520 UTC Debug baseresolver.cpp:425: Attempt to parse
hs.ims.cw.4gtss.com as IP address
14-03-2017 13:14:26.520 UTC Debug baseresolver.cpp:819: 192.168.0.212:8888
transport 6 has state: WHITE
14-03-2017 13:14:26.520 UTC Debug baseresolver.cpp:819: 192.168.0.212:8888
transport 6 has state: WHITE
14-03-2017 13:14:26.520 UTC Debug baseresolver.cpp:1004: Added a whitelisted
server, now have 1 of 1
14-03-2017 13:14:26.520 UTC Debug connection_pool.h:231: Request for connection
to IP: 192.168.0.212, port: 8888
14-03-2017 13:14:26.520 UTC Debug connection_pool.h:244: Found existing
connection 0x7fb004021830 in pool
14-03-2017 13:14:26.520 UTC Debug httpclient.cpp:478: Set CURLOPT_RESOLVE:
hs.ims.cw.4gtss.com:8888:192.168.0.212
14-03-2017 13:14:26.520 UTC Debug httpclient.cpp:505: Sending HTTP request :
http://hs.ims.cw.4gtss.com:8888/impi/6505550525%40ims.cw.4gtss.com/av?impu=sip%3A6505550525%40ims.cw.4gtss.com
(trying 192.168.0.212)
14-03-2017 13:14:26.524 UTC Debug httpclient.cpp:832: Received header
http/1.1200ok with value
14-03-2017 13:14:26.525 UTC Debug httpclient.cpp:833: Header pointer:
0x7fb020d1e060
14-03-2017 13:14:26.525 UTC Debug httpclient.cpp:832: Received header
content-length with value 93
14-03-2017 13:14:26.525 UTC Debug httpclient.cpp:833: Header pointer:
0x7fb020d1e060
14-03-2017 13:14:26.525 UTC Debug httpclient.cpp:832: Received header
content-type with value text/plain
14-03-2017 13:14:26.525 UTC Debug httpclient.cpp:833: Header pointer:
0x7fb020d1e060
14-03-2017 13:14:26.525 UTC Debug httpclient.cpp:832: Received header with
value
14-03-2017 13:14:26.525 UTC Debug httpclient.cpp:833: Header pointer:
0x7fb020d1e060
14-03-2017 13:14:26.525 UTC Debug httpclient.cpp:538: Received HTTP response:
status=200,
doc={"digest":{"ha1":"61ea8247adb95f7074d14b9cca86df99","realm":"ims.cw.4gtss.com","qop":"auth"}}
14-03-2017 13:14:26.528 UTC Debug baseresolver.cpp:830: Successful response
from 192.168.0.212:8888 transport 6
14-03-2017 13:14:26.528 UTC Debug connection_pool.h:267: Release connection to
IP: 192.168.0.212, port: 8888 to pool
14-03-2017 13:14:26.528 UTC Debug authenticationsproutlet.cpp:219: Verifying
AV:
{"digest":{"ha1":"61ea8247adb95f7074d14b9cca86df99","realm":"ims.cw.4gtss.com","qop":"auth"}}
14-03-2017 13:14:26.528 UTC Debug authenticationsproutlet.cpp:246: Digest
specified
14-03-2017 13:14:26.528 UTC Debug authenticationsproutlet.cpp:411: Valid AV -
generate challenge
14-03-2017 13:14:26.528 UTC Debug authenticationsproutlet.cpp:420: Create
WWW-Authenticate header
14-03-2017 13:14:26.528 UTC Debug authenticationsproutlet.cpp:536: Add Digest
information
14-03-2017 13:14:26.528 UTC Debug authenticationsproutlet.cpp:591: Write
authentication challenge to IMPI store
14-03-2017 13:14:26.528 UTC Debug memcachedstore.cpp:1128: Start GET from table
impi for key [email protected]
14-03-2017 13:14:26.528 UTC Debug astaire_resolver.cpp:72:
AstaireResolver::resolve for host sprout.ims.cw.4gtss.com, family 2
14-03-2017 13:14:26.528 UTC Debug utils.cpp:352: Malformed host/port
sprout.ims.cw.4gtss.com
14-03-2017 13:14:26.528 UTC Debug baseresolver.cpp:425: Attempt to parse
sprout.ims.cw.4gtss.com as IP address
14-03-2017 13:14:26.528 UTC Verbose dnscachedresolver.cpp:486: Check cache for
sprout.ims.cw.4gtss.com type 1
14-03-2017 13:14:26.528 UTC Debug dnscachedresolver.cpp:588: Pulling 1 records
from cache for sprout.ims.cw.4gtss.com A
14-03-2017 13:14:26.528 UTC Debug baseresolver.cpp:366: Found 1 A/AAAA records,
creating iterator
14-03-2017 13:14:26.528 UTC Debug baseresolver.cpp:819: 192.168.0.212:11311
transport 6 has state: BLACK
14-03-2017 13:14:26.528 UTC Debug baseresolver.cpp:819: 192.168.0.212:11311
transport 6 has state: BLACK
14-03-2017 13:14:26.528 UTC Debug baseresolver.cpp:1032: Added an unhealthy
server, now have 1 of 2
14-03-2017 13:14:26.528 UTC Debug memcachedstore.cpp:1469: Found 1 targets for
sprout.ims.cw.4gtss.com
14-03-2017 13:14:26.528 UTC Debug memcachedstore.cpp:1494: Duplicate target
IP=192.168.0.212, port= 11311 as it is the only target
14-03-2017 13:14:26.528 UTC Debug memcachedstore.cpp:1082: Try server IP
192.168.0.212, port 11311
14-03-2017 13:14:26.528 UTC Debug connection_pool.h:231: Request for connection
to IP: 192.168.0.212, port: 11311
14-03-2017 13:14:26.528 UTC Debug connection_pool.h:244: Found existing
connection 0x7faffc00b4c0 in pool
14-03-2017 13:14:26.533 UTC Debug memcachedstore.cpp:107: Fetch result
14-03-2017 13:14:26.681 UTC Debug memcachedstore.cpp:1093: libmemcached
returned 16
14-03-2017 13:14:26.681 UTC Debug memcachedstore.cpp:1103: Return code means
the request should not be retried
14-03-2017 13:14:26.681 UTC Debug connection_pool.h:267: Release connection to
IP: 192.168.0.212, port: 11311 to pool
14-03-2017 13:14:26.681 UTC Debug memcachedstore.cpp:1200: Key not found
14-03-2017 13:14:26.681 UTC Debug impistore.cpp:648: Storing IMPI for
[email protected]
{"authChallenges":[{"type":"digest","nonce":"3a83e7ee39475262","nc":1,"expires":1489497306,"correlator":"z9hG4bKPjxt2aG60D4lt04G2ED2a3NEeUND3o7Pwk","realm":"ims.cw.4gtss.com","qop":"auth","ha1":"61ea8247adb95f7074d14b9cca86df99"}]}
14-03-2017 13:14:26.681 UTC Debug memcachedstore.cpp:1251: Writing 231 bytes to
table impi key [email protected], CAS = 0, expiry = 40
14-03-2017 13:14:26.681 UTC Debug astaire_resolver.cpp:72:
AstaireResolver::resolve for host sprout.ims.cw.4gtss.com, family 2
14-03-2017 13:14:26.681 UTC Debug utils.cpp:352: Malformed host/port
sprout.ims.cw.4gtss.com
14-03-2017 13:14:26.681 UTC Debug baseresolver.cpp:425: Attempt to parse
sprout.ims.cw.4gtss.com as IP address
14-03-2017 13:14:26.681 UTC Verbose dnscachedresolver.cpp:486: Check cache for
sprout.ims.cw.4gtss.com type 1
14-03-2017 13:14:26.681 UTC Debug dnscachedresolver.cpp:588: Pulling 1 records
from cache for sprout.ims.cw.4gtss.com A
14-03-2017 13:14:26.681 UTC Debug baseresolver.cpp:366: Found 1 A/AAAA records,
creating iterator
14-03-2017 13:14:26.681 UTC Debug baseresolver.cpp:819: 192.168.0.212:11311
transport 6 has state: BLACK
14-03-2017 13:14:26.681 UTC Debug baseresolver.cpp:819: 192.168.0.212:11311
transport 6 has state: BLACK
14-03-2017 13:14:26.681 UTC Debug baseresolver.cpp:1032: Added an unhealthy
server, now have 1 of 2
14-03-2017 13:14:26.681 UTC Debug memcachedstore.cpp:1469: Found 1 targets for
sprout.ims.cw.4gtss.com
14-03-2017 13:14:26.681 UTC Debug memcachedstore.cpp:1494: Duplicate target
IP=192.168.0.212, port= 11311 as it is the only target
14-03-2017 13:14:26.681 UTC Debug memcachedstore.cpp:1082: Try server IP
192.168.0.212, port 11311
14-03-2017 13:14:26.681 UTC Debug connection_pool.h:231: Request for connection
to IP: 192.168.0.212, port: 11311
14-03-2017 13:14:26.681 UTC Debug connection_pool.h:244: Found existing
connection 0x7faffc00b4c0 in pool
14-03-2017 13:14:26.681 UTC Debug memcachedstore.cpp:144: Attempting to add
data for key impi\\[email protected]
14-03-2017 13:14:26.681 UTC Debug memcachedstore.cpp:154: Attempting memcached
ADD command
14-03-2017 13:14:26.834 UTC Debug memcachedstore.cpp:244: ADD/CAS returned rc =
7 (UNKNOWN READ FAILURE)
(140393823939040) UNKNOWN READ FAILURE, host: 192.168.0.212:11311 ->
libmemcached/response.cc:782
14-03-2017 13:14:26.834 UTC Debug memcachedstore.cpp:1093: libmemcached
returned 7
14-03-2017 13:14:26.834 UTC Debug memcachedstore.cpp:1110: Blacklisting target
14-03-2017 13:14:26.834 UTC Debug baseresolver.cpp:400: Add 192.168.0.212:11311
transport 6 to blacklist for 30 seconds, graylist for 0 seconds
14-03-2017 13:14:26.834 UTC Debug connection_pool.h:267: Release connection to
IP: 192.168.0.212, port: 11311 to pool
14-03-2017 13:14:26.834 UTC Debug memcachedstore.cpp:1082: Try server IP
192.168.0.212, port 11311
14-03-2017 13:14:26.834 UTC Debug connection_pool.h:231: Request for connection
to IP: 192.168.0.212, port: 11311
14-03-2017 13:14:26.834 UTC Debug connection_pool.h:244: Found existing
connection 0x7faffc00b4c0 in pool
14-03-2017 13:14:26.834 UTC Debug memcachedstore.cpp:144: Attempting to add
data for key impi\\[email protected]
14-03-2017 13:14:26.834 UTC Debug memcachedstore.cpp:154: Attempting memcached
ADD command
14-03-2017 13:14:26.986 UTC Debug memcachedstore.cpp:244: ADD/CAS returned rc =
7 (UNKNOWN READ FAILURE)
(140393823939040) UNKNOWN READ FAILURE, host: 192.168.0.212:11311 ->
libmemcached/response.cc:782
14-03-2017 13:14:26.986 UTC Debug memcachedstore.cpp:1093: libmemcached
returned 7
14-03-2017 13:14:26.986 UTC Debug memcachedstore.cpp:1110: Blacklisting target
14-03-2017 13:14:26.986 UTC Debug baseresolver.cpp:400: Add 192.168.0.212:11311
transport 6 to blacklist for 30 seconds, graylist for 0 seconds
14-03-2017 13:14:26.986 UTC Debug connection_pool.h:267: Release connection to
IP: 192.168.0.212, port: 11311 to pool
14-03-2017 13:14:26.986 UTC Debug memcachedstore.cpp:1366: Failed to write data
for impi\\[email protected] to store with error UNKNOWN READ FAILURE
14-03-2017 13:14:26.986 UTC Error impistore.cpp:664: Failed to write IMPI for
private_id [email protected]
14-03-2017 13:14:26.986 UTC Debug authenticationsproutlet.cpp:675: Failed to
store nonce in memcached
14-03-2017 13:14:26.986 UTC Info acr.cpp:690: No CCF or ECF to send ACR for
session qq0DpjcQWNRPGQUHa87JrQ.. to - dropping!
14-03-2017 13:14:26.986 UTC Verbose sproutletproxy.cpp:1427:
authentication-0x7fb00408bc60 sending Response msg 500/REGISTER/cseq=1
(tdta0x7fb0040adcc0)
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1775: Removing message
0x7fb0040ac310 => txdata 0x7fb0040abda8 mapping
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1504: Free message
tdta0x7fb0040abd00
14-03-2017 13:14:26.986 UTC Debug pjsip: tdta0x7fb0040a Destroying txdata
Request msg REGISTER/cseq=1 (tdta0x7fb0040abd00)
14-03-2017 13:14:26.986 UTC Debug acr.cpp:54: Destroyed ACR (0x7fb004020e60)
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1783: Processing actions
from sproutlet - 1 responses, 0 requests, 0 timers
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1869: Aggregating response
with status code 500
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1919: 3xx/4xx/5xx/6xx
response
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1923: Best 3xx/4xx/5xx/6xx
response so far
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1810: All UAC responded
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1775: Removing message
0x7fb0040ae2d0 => txdata 0x7fb0040add68 mapping
14-03-2017 13:14:26.986 UTC Verbose sproutletproxy.cpp:2095: Routing Response
msg 500/REGISTER/cseq=1 (tdta0x7fb0040adcc0) (614 bytes) to upstream sproutlet
icscf:
--start msg--
SIP/2.0 500 Internal Server Error
Via: SIP/2.0/TCP
192.168.0.210:5058;rport=45333;received=192.168.0.210;branch=z9hG4bKPjxt2aG60D4lt04G2ED2a3NEeUND3o7Pwk
Via: SIP/2.0/UDP
192.168.0.209:52124;rport=52124;received=192.168.0.209;branch=z9hG4bK-524287-1---f7dc3c756b6f3896
Call-ID: qq0DpjcQWNRPGQUHa87JrQ..
From: <sip:[email protected]>;tag=1959ab22
To:
<sip:[email protected]>;tag=z9hG4bKPjxt2aG60D4lt04G2ED2a3NEeUND3o7Pwk
CSeq: 1 REGISTER
WWW-Authenticate: Digest
realm="ims.cw.4gtss.com",nonce="3a83e7ee39475262",opaque="33312013558f3894",algorithm=MD5,qop="auth"
Content-Length: 0
--end msg--
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1768: Adding message
0x7fb0040ae2d0 => txdata 0x7fb0040add68 mapping
14-03-2017 13:14:26.986 UTC Verbose sproutletproxy.cpp:1666:
icscf-0x7fb004020750 received final response Response msg 500/REGISTER/cseq=1
(tdta0x7fb0040adcc0) on fork 0, state = Terminated
14-03-2017 13:14:26.986 UTC Debug acr.cpp:1540: Stored 1 subscription
identifiers
14-03-2017 13:14:26.986 UTC Debug icscfsproutlet.cpp:329: Check retry
conditions for REGISTER, status = 500, S-CSCF responsive
14-03-2017 13:14:26.986 UTC Verbose sproutletproxy.cpp:1427:
icscf-0x7fb004020750 sending Response msg 500/REGISTER/cseq=1
(tdta0x7fb0040adcc0)
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1783: Processing actions
from sproutlet - 1 responses, 0 requests, 0 timers
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1869: Aggregating response
with status code 500
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1919: 3xx/4xx/5xx/6xx
response
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1923: Best 3xx/4xx/5xx/6xx
response so far
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1810: All UAC responded
14-03-2017 13:14:26.986 UTC Debug sproutletproxy.cpp:1775: Removing message
0x7fb0040ae2d0 => txdata 0x7fb0040add68 mapping
14-03-2017 13:14:26.986 UTC Debug pjsip: tsx0x7fb00408d Sending Response msg
500/REGISTER/cseq=1 (tdta0x7fb0040adcc0) in state Trying
14-03-2017 13:14:26.986 UTC Verbose common_sip_processing.cpp:136: TX 614 bytes
Response msg 500/REGISTER/cseq=1 (tdta0x7fb0040adcc0) to TCP
192.168.0.210:45333:
--start msg--
SIP/2.0 500 Internal Server Error
Via: SIP/2.0/TCP
192.168.0.210:5058;rport=45333;received=192.168.0.210;branch=z9hG4bKPjxt2aG60D4lt04G2ED2a3NEeUND3o7Pwk
Via: SIP/2.0/UDP
192.168.0.209:52124;rport=52124;received=192.168.0.209;branch=z9hG4bK-524287-1---f7dc3c756b6f3896
Call-ID: qq0DpjcQWNRPGQUHa87JrQ..
From: <sip:[email protected]>;tag=1959ab22
To:
<sip:[email protected]>;tag=z9hG4bKPjxt2aG60D4lt04G2ED2a3NEeUND3o7Pwk
CSeq: 1 REGISTER
WWW-Authenticate: Digest
realm="ims.cw.4gtss.com",nonce="3a83e7ee39475262",opaque="33312013558f3894",algorithm=MD5,qop="auth"
Content-Length: 0
--end msg--
14-03-2017 13:14:26.987 UTC Debug pjsip: tsx0x7fb00408d State changed from
Trying to Completed, event=TX_MSG
14-03-2017 13:14:26.987 UTC Debug basicproxy.cpp:213: tsx0x7fb00408de18 -
tu_on_tsx_state UAS, TSX_STATE TX_MSG state=Completed
14-03-2017 13:14:26.987 UTC Verbose sproutletproxy.cpp:1861:
icscf-0x7fb004020750 suiciding
14-03-2017 13:14:26.987 UTC Debug sproutletproxy.cpp:1169: Destroying
SproutletWrapper 0x7fb0040214c0
14-03-2017 13:14:26.987 UTC Info acr.cpp:690: No CCF or ECF to send ACR for
session qq0DpjcQWNRPGQUHa87JrQ.. to - dropping!
14-03-2017 13:14:26.987 UTC Debug acr.cpp:54: Destroyed ACR (0x7fb00408ce10)
14-03-2017 13:14:26.987 UTC Debug sproutletproxy.cpp:1178: Free original
request Request msg REGISTER/cseq=1 (tdta0x7fb004042010) (tdta0x7fb004042010)
14-03-2017 13:14:26.987 UTC Verbose sproutletproxy.cpp:1861:
authentication-0x7fb00408bc60 suiciding
14-03-2017 13:14:26.987 UTC Debug sproutletproxy.cpp:1169: Destroying
SproutletWrapper 0x7fb00408b770
14-03-2017 13:14:26.987 UTC Debug sproutletproxy.cpp:1178: Free original
request Request msg REGISTER/cseq=1 (tdta0x7fb004011510) (tdta0x7fb004011510)
14-03-2017 13:14:26.987 UTC Debug pjsip: tdta0x7fb00401 Destroying txdata
Request msg REGISTER/cseq=1 (tdta0x7fb004011510)
14-03-2017 13:14:26.987 UTC Debug thread_dispatcher.cpp:200: Worker thread
completed processing message 0x7fb00c0dc838
14-03-2017 13:14:26.987 UTC Debug thread_dispatcher.cpp:206: Request latency =
473226us
14-03-2017 13:14:26.993 UTC Debug pjsip: tsx0x7fb00408d Timeout timer event
14-03-2017 13:14:26.993 UTC Debug pjsip: tsx0x7fb00408d State changed from
Completed to Terminated, event=TIMER
14-03-2017 13:14:26.993 UTC Debug basicproxy.cpp:213: tsx0x7fb00408de18 -
tu_on_tsx_state UAS, TSX_STATE TIMER state=Terminated
14-03-2017 13:14:26.993 UTC Debug basicproxy.cpp:1308: Report SAS end marker -
trail (7a)
14-03-2017 13:14:26.993 UTC Debug pjsip: tsx0x7fb00408d Timeout timer event
14-03-2017 13:14:26.993 UTC Debug pjsip: tsx0x7fb00408d State changed from
Terminated to Destroyed, event=TIMER
14-03-2017 13:14:26.993 UTC Debug basicproxy.cpp:213: tsx0x7fb00408de18 -
tu_on_tsx_state UAS, TSX_STATE TIMER state=Destroyed
14-03-2017 13:14:26.993 UTC Debug sproutletproxy.cpp:750: tsx0x7fb00408de18 -
UAS tsx destroyed
14-03-2017 13:14:26.993 UTC Debug sproutletproxy.cpp:1090: Safe for UASTsx to
suicide
14-03-2017 13:14:26.993 UTC Debug basicproxy.cpp:1483: Transaction ((nil))
suiciding
14-03-2017 13:14:26.993 UTC Verbose sproutletproxy.cpp:538: Sproutlet Proxy
transaction (0x7fb004020bc0) destroyed
14-03-2017 13:14:26.993 UTC Debug basicproxy.cpp:494: BasicProxy::UASTsx
destructor (0x7fb004020bc0)
14-03-2017 13:14:26.993 UTC Debug basicproxy.cpp:511: Disconnect UAC
transactions from UAS transaction
14-03-2017 13:14:26.993 UTC Debug basicproxy.cpp:525: Free original request
14-03-2017 13:14:26.993 UTC Debug pjsip: tdta0x7fb00404 Destroying txdata
Request msg REGISTER/cseq=1 (tdta0x7fb004042010)
14-03-2017 13:14:26.993 UTC Debug basicproxy.cpp:534: Free un-used best response
14-03-2017 13:14:26.993 UTC Debug pjsip: tdta0x7fb00401 Destroying txdata
Response msg 408/REGISTER/cseq=1 (tdta0x7fb004010500)
14-03-2017 13:14:26.993 UTC Debug basicproxy.cpp:555: BasicProxy::UASTsx
destructor completed
14-03-2017 13:14:26.993 UTC Debug pjsip: tdta0x7fb0040a Destroying txdata
Response msg 500/REGISTER/cseq=1 (tdta0x7fb0040adcc0)
14-03-2017 13:14:26.993 UTC Debug pjsip: tsx0x7fb00408d Transaction destroyed!
_______________________________________________
Clearwater mailing list
[email protected]
http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org
