Hi,

I have a manual deployment of Clearwater on OpenStack using 6 VMs in the
same private network.
I can successfully create private identities on Ellis and register them
using Jitsi clients on two laptops.
And I can even make calls from one client to another.
But Jitsi clients logout automatically after a while because of
authentication error. When this happens, I need to re-login.
Another weird thing is even when the two clients are both online, I get
call fails sometimes. But this problem can be solved by logout and re-login
both clients.
Then I checked the log information on each node. See below.
It seems like Bono and Sprout pop errors when using curl to fetch
information from Ralf (unexpected response).

Bono (192.168.1.11)
log_20140722_0000.txt
22-07-2014 00:12:37.518 Call-Disconnected:
CALL_ID=6a18ab56531a8f8d468cb14bd5e322ae@0:0:0:0:0:0:0:0 REASON=401
22-07-2014 00:21:37.690 Call-Disconnected:
CALL_ID=6a18ab56531a8f8d468cb14bd5e322ae@0:0:0:0:0:0:0:0 REASON=401
22-07-2014 00:30:37.813 Call-Disconnected:
CALL_ID=6a18ab56531a8f8d468cb14bd5e322ae@0:0:0:0:0:0:0:0 REASON=401
22-07-2014 00:39:37.970 Call-Disconnected:
CALL_ID=6a18ab56531a8f8d468cb14bd5e322ae@0:0:0:0:0:0:0:0 REASON=401
22-07-2014 00:48:38.156 Call-Disconnected:
CALL_ID=6a18ab56531a8f8d468cb14bd5e322ae@0:0:0:0:0:0:0:0 REASON=401
22-07-2014 00:57:38.317 Call-Disconnected:
CALL_ID=6a18ab56531a8f8d468cb14bd5e322ae@0:0:0:0:0:0:0:0 REASON=401

bono_20140722_0000.txt
22-07-2014 00:31:05.112 Status connection_pool.cpp:453: Recycle TCP
connection slot 26
22-07-2014 00:31:09.817 Error httpconnection.cpp:561:
http://192.168.1.51:10888/call-id/6a18ab56531a8f8d468cb14bd5e322ae%400%3A0%3A0%3A0%3A0%3A0%3A0%3A0
failed
at server 192.168.1.51 : HTTP response code said error (22 400) : fatal
22-07-2014 00:31:09.817 Error httpconnection.cpp:659: cURL failure with
cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 400
22-07-2014 00:31:09.817 Warning acr.cpp:656: Failed to send Ralf ACR
message (0x7f560c003f50), rc = 400
22-07-2014 00:31:09.830 Error httpconnection.cpp:561:
http://192.168.1.51:10888/call-id/6a18ab56531a8f8d468cb14bd5e322ae%400%3A0%3A0%3A0%3A0%3A0%3A0%3A0
failed
at server 192.168.1.51 : HTTP response code said error (22 400) : fatal
22-07-2014 00:31:09.830 Error httpconnection.cpp:659: cURL failure with
cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 400
22-07-2014 00:31:09.830 Warning acr.cpp:656: Failed to send Ralf ACR
message (0x7f560c045770), rc = 400
22-07-2014 00:31:10.113 Status connection_pool.cpp:453: Recycle TCP
connection slot 14
22-07-2014 00:31:13.113 Status connection_pool.cpp:453: Recycle TCP
connection slot 5
22-07-2014 00:31:17.114 Status connection_pool.cpp:453: Recycle TCP
connection slot 28
...
22-07-2014 04:05:49.861 Warning pjsip: tsx0x7f560c06b Temporary failure in
sending Request msg SUBSCRIBE/cseq=1 (tdta0x7f560c068440), will try next
server: Unsuitable transport selected (PJSIP_ETPNOTSUITABLE)
22-07-2014 04:05:49.963 Error httpconnection.cpp:561:
http://192.168.1.51:10888/call-id/33254c923cefaa4649ca98e46956abd5%400%3A0%3A0%3A0%3A0%3A0%3A0%3A0
failed
at server 192.168.1.51 : HTTP response code said error (22 400) : fatal
22-07-2014 04:05:49.963 Error httpconnection.cpp:659: cURL failure with
cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 400
22-07-2014 04:05:49.963 Warning acr.cpp:656: Failed to send Ralf ACR
message (0x7f560c0543f0), rc = 400
22-07-2014 04:05:52.748 Status connection_pool.cpp:453: Recycle TCP
connection slot 10
22-07-2014 04:05:59.750 Status connection_pool.cpp:453: Recycle TCP
connection slot 11
...
22-07-2014 04:30:36.720 Error hssconnection.cpp:395: Could not get
subscriber data from HSS


Sprout (192.168.1.21)
sprout_20140722_0000.txt
22-07-2014 00:30:37.801 Warning authentication.cpp:205: Received an
authentication request for [email protected] with nonce
44a1c71056b9268f, but no matching AV found
22-07-2014 00:30:37.815 Error httpconnection.cpp:561:
http://192.168.1.51:10888/call-id/6a18ab56531a8f8d468cb14bd5e322ae%400%3A0%3A0%3A0%3A0%3A0%3A0%3A0
failed
at server 192.168.1.51 : HTTP response code said error (22 400) : fatal
22-07-2014 00:30:37.815 Error httpconnection.cpp:659: cURL failure with
cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 400
22-07-2014 00:30:37.815 Warning acr.cpp:656: Failed to send Ralf ACR
message (0x7f217c473920), rc = 400
22-07-2014 00:30:37.829 Error httpconnection.cpp:561:
http://192.168.1.51:10888/call-id/6a18ab56531a8f8d468cb14bd5e322ae%400%3A0%3A0%3A0%3A0%3A0%3A0%3A0
failed
at server 192.168.1.51 : HTTP response code said error (22 400) : fatal
22-07-2014 00:30:37.829 Error httpconnection.cpp:659: cURL failure with
cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 400
22-07-2014 00:30:37.829 Warning acr.cpp:656: Failed to send Ralf ACR
message (0x7f21a8391710), rc = 400
22-07-2014 00:39:37.954 Warning authentication.cpp:205: Received an
authentication request for [email protected] with nonce
5190a6f7596e9d29, but no matching AV found
22-07-2014 00:39:37.972 Error httpconnection.cpp:561:
http://192.168.1.51:10888/call-id/6a18ab56531a8f8d468cb14bd5e322ae%400%3A0%3A0%3A0%3A0%3A0%3A0%3A0
failed
at server 192.168.1.51 : HTTP response code said error (22 400) : fatal
22-07-2014 00:39:37.972 Error httpconnection.cpp:659: cURL failure with
cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 400
22-07-2014 00:39:37.972 Warning acr.cpp:656: Failed to send Ralf ACR
message (0x7f21744bc930), rc = 400
22-07-2014 00:39:37.985 Error httpconnection.cpp:561:
http://192.168.1.51:10888/call-id/6a18ab56531a8f8d468cb14bd5e322ae%400%3A0%3A0%3A0%3A0%3A0%3A0%3A0
failed
at server 192.168.1.51 : HTTP response code said error (22 400) : fatal
22-07-2014 00:39:37.985 Error httpconnection.cpp:659: cURL failure with
cURL error code 22 (see man 3 libcurl-errors) and HTTP error code 400
22-07-2014 00:39:37.985 Warning acr.cpp:656: Failed to send Ralf ACR
message (0x7f217c377c70), rc = 400

homestead (192.168.1.41)
homestead_20140722_0000.txt
22-07-2014 00:42:06.722 Status freeDiameter: [dbg_monitor] Dumping queues
statistics
22-07-2014 00:42:06.723 Status freeDiameter: Global 'Local delivery':
cur:0/25, h:0, T:0 in 0.000000s (-NANitems/s), blocked:0.000000s, last
processing:0.000000s
22-07-2014 00:42:06.723 Status freeDiameter: Global 'Total received':
cur:0/20, h:0, T:0 in 0.000000s (-NANitems/s), blocked:0.000000s, last
processing:0.000000s
22-07-2014 00:42:06.723 Status freeDiameter: Global 'Total sending':
cur:0/30, h:0, T:0 in 0.000000s (-NANitems/s), blocked:0.000000s, last
processing:0.000000s
22-07-2014 00:42:06.723 Status freeDiameter: [dbg_monitor] Dumping servers
information
22-07-2014 00:42:06.723 Status freeDiameter: {server}(@0x25dd5b0)'{----}
SCTP srv :3868 (26)': SCTP, NotSecur(0), Thread running'pending
connections'(@0x25dd610): items:0,0,5 threads:5,0
stats:0/0.000000,0.000000,0.000000 thresholds:0,0,0,(nil),(nil),(nil)
{server}(@0x25de030)'{----} SCTP srv :5658 (27)': SCTP, Secur(2), Thread
running'pending connections'(@0x25de090): items:0,0,5 threads:5,0
stats:0/0.000000,0.000000,0.000000 thresholds:0,0,0,(nil),(nil),(nil)
{server}(@0x25deab0)'{----} TCP srv [0.0.0.0]:3868 (28)': TCP, NotSecur(0),
Thread running'pending connections'(@0x25deb10): items:0,0,5 threads:5,0
stats:0/0.000000,0.000000,0.000000 thresholds:0,0,0,(nil),(nil),(nil)
{server}(@0x25df530)'{----} TCP srv [0.0.0.0]:5658 (29)': TCP, Secur(1),
Thread running'pending connections'(@0x25df590): items:0,0,5 threads:5,0
stats:0/0.000000,0.000000,0.000000 thresholds:0,0,0,(nil),(nil),(nil)
{server}(@0x25dffb0)'{----} TCP srv [::]:3868 (30)': TCP, NotSecur(0),
Thread running'pending connections'(@0x25e0010): items:0,0,5 threads:5,0
stats:0/0.000000,0.000000,0.000000 thresholds:0,0,0,(nil),(nil),(nil)
{server}(@0x25e0a30)'{----} TCP srv [::]:5658 (31)': TCP, Secur(1), Thread
running'pending connections'(@0x25e0a90): items:0,0,5 threads:5,0
stats:0/0.000000,0.000000,0.000000 thresholds:0,0,0,(nil),(nil),(nil)


Ralf (192.168.1.51)
ralf_20140722_0000.txt
22-07-2014 00:30:37.814 Error handlers.cpp:200: JSON lacked a 'peers'
object (mandatory for START/EVENT)
22-07-2014 00:30:37.829 Error handlers.cpp:200: JSON lacked a 'peers'
object (mandatory for START/EVENT)
22-07-2014 00:31:09.816 Error handlers.cpp:200: JSON lacked a 'peers'
object (mandatory for START/EVENT)
22-07-2014 00:31:09.830 Error handlers.cpp:200: JSON lacked a 'peers'
object (mandatory for START/EVENT)

No much log on Homer node.


I tried to run curl manually from Sprout node. I got output like this:

[sprout]cw@sprout:~$ curl
http://192.168.1.51:10888/call-id/a91f88b220f925c3e29d5ed56ad5b7d1%400%3A0%3A0%3A0%3A0%3A0%3A0%3A0
 -v
* About to connect() to 192.168.1.51 port 10888 (#0)
*   Trying 192.168.1.51... connected
> GET
/call-id/a91f88b220f925c3e29d5ed56ad5b7d1%400%3A0%3A0%3A0%3A0%3A0%3A0%3A0
HTTP/1.1
> User-Agent: curl/7.22.0 (x86_64-pc-linux-gnu) libcurl/7.22.0
OpenSSL/1.0.1 zlib/1.2.3.4 libidn/1.23 librtmp/2.3
> Host: 192.168.1.51:10888
> Accept: */*
>
< HTTP/1.1 405 Not Allowed
< Content-Length: 0
<
* Connection #0 to host 192.168.1.51 left intact
* Closing connection #0


Is this somehow due to configuration problem or long-lived states are not
correctly maintained?

Thanks.
Lianjie
_______________________________________________
Clearwater mailing list
[email protected]
http://lists.projectclearwater.org/listinfo/clearwater

Reply via email to