Hi Robert, It's not the SIP server that has the issue (Sprout can handle the load :) ) - it's the Ellis UI that is causing you problems here (note that we don't typically stress test Ellis, and we don't expect it to be used for bulk provisioning/managing of subscribers - particularly since if you integrate with a HSS, you don't use Ellis).
As background, the load monitor in homestead-prov will admit a request if there are available tokens in its token bucket (at the cost of one token). It also replenishes the number of tokens based on what the token rate is, and how long it's been since the token bucket was last replenished. Every 20 requests, it gets the latency of the requests (as a smoothed mean), and compares this to the target latency (100ms). If it is less, then the token rate is increased. How much it's increased by depends on how far below the average latency is to the target latency. This means that if you're going from a cold start (such as after a reboot), then there is a slow start where the load monitor ramps up the token replacement rate (as there is a limit as to how fast the token rate can rise). When Ellis tries to populate the dashboard, it's hitting homestead-prov with a large number of requests, some of which are rejected due to the slow start of the load monitor. Ellis is unable to display the dashboard unless every single request succeeds - https://github.com/Metaswitch/ellis/issues/83 is tracking fixing this up. You can use the homestead-prov API to manage your subscribers directly from homestead-prov - you can find details of it here: https://github.com/Metaswitch/crest/blob/master/docs/homestead_api.md. Alternatively, you could make the load monitor have a higher number of tokens/larger token rate when it starts up. You can do this by changing the settings in the file https://github.com/Metaswitch/crest/blob/master/src/metaswitch/crest/api/base.py#L197, where you want to increase the third parameter (the initial token rate). This file is installed to /usr/share/clearwater/homestead/env/lib/python2.7/site-packages/crest-0.1-py2.7.egg/metaswitch/crest/api/base.py on your all-in-one node, and you'll need to run 'sudo service homestead-prov stop' to pick up the changes. We’re also planning on making the load monitor options configurable in a later release - https://github.com/Metaswitch/cpp-common/issues/199. Finally, just using Ellis/homestead-prov (i.e. using the homestead-prov API for a time) will naturally increase homestead-prov's token rate so that Ellis will be able to succeed on every request. Ellie -----Original Message----- From: Robert Chen [mailto:[email protected]] Sent: 05 December 2014 21:24 To: Eleanor Merry; [email protected] Subject: RE: [Clearwater] Ellis error: Failed to update the server Ellis, I need to keep those numbers. A sip server should be able to handle a lot of load. This is just a few tens of numbers and the system cannot handle? There is something wrong. One thing I am not quite understand is, why the those phone numbers generate 503 are not always the same. Sometimes have good response and sometimes they have bad response. If those are created by error in the past, they should always with bad response. Do I miss something? Robert -----Original Message----- From: Eleanor Merry [mailto:[email protected]] Sent: 2014年12月5日 9:37 To: China Mobile - Robert Chen; [email protected] Subject: RE: [Clearwater] Ellis error: Failed to update the server Hi Robert, The homestead-prov logs show that virtually every request gets a successful response, but there are so many that some get rejected with a 503 due to homestead-prov being overloaded. What I think has happened here is that there was a previous issue with homestead-prov (such as a time jump) that had been fixed up by the reboot you did. While there was this issue though, many numbers were created (all with different private identities). Now, when Ellis tries to populate the dashboard, it makes a GET to homestead for each number - this then overloads homestead-prov, meaning that it rejects some requests with a 503. If Ellis doesn't get a positive response to every GET request, it displays an error. I've raised an issue to make Ellis deal with this situation better (https://github.com/Metaswitch/ellis/issues/83). In the meantime, can you please delete the created numbers, and see if this works? To delete all the numbers, run: sudo mysql USE ellis UPDATE numbers SET owner_id=NULL; Then, cqlsh -3 USE homestead_provisioning; TRUNCATE public; TRUNCATE private; TRUNCATE service_profiles; TRUNCATE implicit_registration_sets; USE homestead_cache; TRUNCATE impi; TRUNCATE impu; TRUNCATE impi_mapping; Ellie -----Original Message----- From: Robert Chen [mailto:[email protected]] Sent: 02 December 2014 21:04 To: Eleanor Merry; [email protected] Subject: RE: [Clearwater] Ellis error: Failed to update the server Ellie, I tried to reboot the node as well as stop the homestead-prov and still experience the same problem. Here are the logs. Homestead-prov-err.log Unhandled error in Deferred: Unhandled Error Traceback (most recent call last): Failure: twisted.internet.error.ConnectionRefusedError: Connection was refused by other side: 111: Connection refused. Unhandled error in Deferred: Unhandled Error Traceback (most recent call last): Failure: twisted.internet.error.ConnectionRefusedError: Connection was refused by other side: 111: Connection refused. homestead-prov-0.log (tail) 2014-12-02 20:49:12,366 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550019%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,371 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550594%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,374 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550078%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,378 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550612%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,380 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550127%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,384 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550637%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,400 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550168%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,405 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550249%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,410 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550671%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,411 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550676%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,412 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550321%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,416 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550714%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,421 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550354%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,424 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550751%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,427 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550402%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,430 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550764%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,432 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550430%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,437 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550829%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,438 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550468%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,466 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550852%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,526 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550594%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,530 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550886%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,532 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550612%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,609 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550637%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,609 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550912%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,615 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550671%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,619 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550915%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,620 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550925%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,626 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550676%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,630 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550714%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,688 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550944%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,688 W base:247 1505:140700897568512] Rejecting request because of overload 2014-12-02 20:49:12,690 I base:258 1505:140700897568512] Sending 503 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550944%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,743 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550751%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,749 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550990%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,777 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550764%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,781 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550829%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,781 I base:179 1505:140700897568512] Accepted 96.153846 requests, latency error = 1.181901, HSS overloads = 0, decrease rate 10.000000 to 10.000000 2014-12-02 20:49:12,785 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550852%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,832 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550886%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,836 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550912%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,840 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550915%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,845 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550925%40example.com/associated_p rivate_ids 2014-12-02 20:49:12,874 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550990%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,221 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550019%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,228 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550078%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,229 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550127%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,230 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550168%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,231 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550249%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,231 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550321%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,257 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550354%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,257 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550402%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,258 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550430%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,259 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550468%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,261 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550019%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,268 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550594%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,324 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550078%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,356 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550127%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,361 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550168%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,364 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550249%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,366 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550321%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,369 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550354%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,371 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550402%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,374 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550430%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,414 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550468%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,416 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550612%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,420 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550594%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,421 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550637%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,448 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550671%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,449 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550676%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,450 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550714%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,450 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550751%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,451 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550764%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,452 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550829%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,452 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550852%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,497 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550886%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,511 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550612%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,514 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550912%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,516 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550637%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,519 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550915%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,519 W base:247 1505:140700897568512] Rejecting request because of overload 2014-12-02 20:49:17,545 I base:258 1505:140700897568512] Sending 503 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550915%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,546 I base:179 1505:140700897568512] Accepted 95.652174 requests, latency error = 0.225422, HSS overloads = 0, decrease rate 10.000000 to 10.000000 2014-12-02 20:49:17,549 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550671%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,554 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550925%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,556 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550944%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,557 W base:247 1505:140700897568512] Rejecting request because of overload 2014-12-02 20:49:17,557 I base:258 1505:140700897568512] Sending 503 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550944%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,558 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550676%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,564 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550714%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,565 I base:245 1505:140700897568512] Received request from 172.31.44.185 - GET http://172.31.44.185:8889/public/sip%3A6505550990%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,565 W base:247 1505:140700897568512] Rejecting request because of overload 2014-12-02 20:49:17,565 I base:258 1505:140700897568512] Sending 503 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550990%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,593 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550751%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,596 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550764%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,598 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550829%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,601 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550852%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,612 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550886%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,649 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550912%40example.com/associated_p rivate_ids 2014-12-02 20:49:17,653 I base:258 1505:140700897568512] Sending 200 response to 172.31.44.185 for GET http://172.31.44.185:8889/public/sip%3A6505550925%40example.com/associated_p rivate_ids -----Original Message----- From: [email protected] [mailto:[email protected]] On Behalf Of Robert Chen Sent: 2014年12月2日 11:28 To: 'Eleanor Merry'; [email protected] Subject: Re: [Clearwater] Ellis error: Failed to update the server Ellie, Thanks. I will try both. Looks like those logs are very big. Is there a better way to send logs? Robert -----Original Message----- From: Eleanor Merry [mailto:[email protected]] Sent: 2014年12月2日 9:34 To: China Mobile - Robert Chen; [email protected] Subject: RE: [Clearwater] Ellis error: Failed to update the server Hi Robert, I can't be sure, but it sounds like the homestead component of Clearwater (the subscriber store) might not be running, or might have locked up. We currently have an open issue (https://github.com/Metaswitch/crest/issues/162) that if NTP corrects the system time by a large amount, homestead may reject all requests sent to it. This can be cleared by rebooting the all-in-one node (log into the node and run `sudo reboot`). If that doesn't fix the problem the next thing I would try is restarting homestead-prov. Log into the node and run `sudo service homestead-prov stop`. This will stop the process, and monit (our monitoring layer) will automatically restart it. If that doesn't work, can you please send the homestead-prov.logs across? These are in /var/log/homestead-prov/homestead-prov*.log Also, can you please check for me that the homestead schema has installed correctly? You can check this by running "cqlsh -3", then "use homestead_cache;", and finally "describe tables;" - this should report the impu, impi and impi_mapping tables. If any of these steps fail (for example, because the homestead_cache keyspace is missing), then you'll need to recreate the keyspace. You can do this most simply by removing and reinstalling the homestead package. Thanks, Ellie -----Original Message----- From: [email protected] [mailto:[email protected]] On Behalf Of Robert Chen Sent: 01 December 2014 05:27 To: [email protected] Subject: Re: [Clearwater] Ellis error: Failed to update the server Looks like the mailing list does not like the attachment. Here is the log: 2014-12-01 03:51:02,827 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.42ms 2014-12-01 03:51:12,550 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.72ms 2014-12-01 03:51:43,219 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.34ms 2014-12-01 03:52:03,389 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.33ms 2014-12-01 03:52:23,289 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.32ms 2014-12-01 03:52:43,802 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.32ms 2014-12-01 03:53:04,043 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.32ms 2014-12-01 03:53:14,089 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.34ms 2014-12-01 03:53:24,181 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.46ms 2014-12-01 03:53:54,437 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.32ms 2014-12-01 03:54:14,812 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.37ms 2014-12-01 03:54:34,967 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.32ms 2014-12-01 03:54:55,173 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.32ms 2014-12-01 03:55:05,397 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.34ms 2014-12-01 03:55:15,257 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.32ms 2014-12-01 03:55:35,683 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.32ms 2014-12-01 03:55:55,743 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.32ms 2014-12-01 03:56:16,007 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.33ms 2014-12-01 03:56:31,159 D static:80 25511:140048494843648] Checking if addressbook.html is allowed 2014-12-01 03:56:31,162 I web:1447 25511:140048494843648] 200 GET /addressbook.html (73.189.53.119) 3.06ms 2014-12-01 03:56:31,268 D static:80 25511:140048494843648] Checking if addressbook.html is allowed 2014-12-01 03:56:31,271 I web:1447 25511:140048494843648] 200 GET /addressbook.html (73.189.53.119) 2.94ms 2014-12-01 03:56:31,502 I web:1447 25511:140048494843648] 304 GET /gab (73.189.53.119) 2.43ms 2014-12-01 03:57:06,669 I web:1447 25511:140048494843648] 200 GET /ping (172.31.44.185) 0.33ms 2014-12-01 03:57:09,453 D static:80 25511:140048494843648] Checking if is allowed 2014-12-01 03:57:09,458 I web:1447 25511:140048494843648] 200 GET / (73.189. 53.119) 4.71ms 2014-12-01 03:57:09,625 D static:80 25511:140048494843648] Checking if is allowed 2014-12-01 03:57:09,630 I web:1447 25511:140048494843648] 200 GET / (73.189. 53.119) 5.18ms 2014-12-01 03:57:10,260 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,261 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,262 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,263 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,264 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,266 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,267 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,268 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,268 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,269 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,270 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,270 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 1 queued requests. 2014-12-01 03:57:10,271 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,271 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 2 queued requests. 2014-12-01 03:57:10,271 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,271 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 3 queued requests. 2014-12-01 03:57:10,272 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,272 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 4 queued requests. 2014-12-01 03:57:10,272 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,273 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 5 queued requests. 2014-12-01 03:57:10,273 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,273 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 6 queued requests. 2014-12-01 03:57:10,274 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,274 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 7 queued requests. 2014-12-01 03:57:10,274 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,274 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 8 queued requests. 2014-12-01 03:57:10,275 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,275 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 9 queued requests. 2014-12-01 03:57:10,275 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,275 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 10 queued requests. 2014-12-01 03:57:10,276 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,276 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 11 queued requests. 2014-12-01 03:57:10,276 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,277 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 12 queued requests. 2014-12-01 03:57:10,277 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,277 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 13 queued requests. 2014-12-01 03:57:10,277 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,278 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 14 queued requests. 2014-12-01 03:57:10,278 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,278 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 15 queued requests. 2014-12-01 03:57:10,279 W homestead:237 25511:140048494843648] Passing SIP password in the clear over http 2014-12-01 03:57:10,279 D simple_httpclient:107 25511:140048494843648] max_clients limit reached, request queued. 10 active, 16 queued requests. 2014-12-01 03:57:10,279 W iostream:507 25511:140048494843648] Connect error on fd 17: ECONNREFUSED 2014-12-01 03:57:10,279 W iostream:507 25511:140048494843648] Connect error on fd 18: ECONNREFUSED 2014-12-01 03:57:10,279 W iostream:507 25511:140048494843648] Connect error on fd 19: ECONNREFUSED 2014-12-01 03:57:10,280 W iostream:507 25511:140048494843648] Connect error on fd 20: ECONNREFUSED 2014-12-01 03:57:10,280 W iostream:507 25511:140048494843648] Connect error on fd 21: ECONNREFUSED 2014-12-01 03:57:10,280 W iostream:507 25511:140048494843648] Connect error on fd 22: ECONNREFUSED 2014-12-01 03:57:10,280 W iostream:507 25511:140048494843648] Connect error on fd 23: ECONNREFUSED 2014-12-01 03:57:10,281 W iostream:507 25511:140048494843648] Connect error on fd 24: ECONNREFUSED 2014-12-01 03:57:10,281 W iostream:507 25511:140048494843648] Connect error on fd 25: ECONNREFUSED 2014-12-01 03:57:10,281 W iostream:507 25511:140048494843648] Connect error on fd 26: ECONNREFUSED 2014-12-01 03:57:10,282 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.020529985427856445,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b16990>,effective_url='http://localhost:8889/public/sip%3A6505550019% 0x2b16990>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,282 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,283 E web:1447 25511:140048494843648] 502 GET /accounts/robertchen%40chinamobile.com/numbers/?cb=12d0c395f9V0 (73.189.53.119) 27.00ms 2014-12-01 03:57:10,283 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,283 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.021397113800048828,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b24e10>,effective_url='http://localhost:8889/public/sip%3A6505550078% 0x2b24e10>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,284 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,284 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,284 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,284 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.021451950073242188,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b241d0>,effective_url='http://localhost:8889/public/sip%3A6505550127% 0x2b241d0>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,285 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,285 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,285 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,286 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.021663904190063477,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b24290>,effective_url='http://localhost:8889/public/sip%3A6505550168% 0x2b24290>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,286 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,286 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,286 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,311 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.021754980087280273,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b1c390>,effective_url='http://localhost:8889/public/sip%3A6505550249% 0x2b1c390>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,311 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,311 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,311 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,312 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.04528999328613281,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b16210>, effective_url='http://localhost:8889/public/sip%3A6505550321%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,312 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,312 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,312 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,313 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.04555702209472656,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b16550>, effective_url='http://localhost:8889/public/sip%3A6505550354%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,313 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,313 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,313 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,314 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.04580497741699219,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b16190>, effective_url='http://localhost:8889/public/sip%3A6505550402%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,314 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,314 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,314 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,315 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.04603719711303711,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b16790>, effective_url='http://localhost:8889/public/sip%3A6505550430%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,315 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,315 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,315 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,316 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.04622912406921387,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b160d0>, effective_url='http://localhost:8889/public/sip%3A6505550468%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,316 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,316 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,316 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,317 W iostream:507 25511:140048494843648] Connect error on fd 17: ECONNREFUSED 2014-12-01 03:57:10,317 W iostream:507 25511:140048494843648] Connect error on fd 18: ECONNREFUSED 2014-12-01 03:57:10,317 W iostream:507 25511:140048494843648] Connect error on fd 19: ECONNREFUSED 2014-12-01 03:57:10,317 W iostream:507 25511:140048494843648] Connect error on fd 20: ECONNREFUSED 2014-12-01 03:57:10,317 W iostream:507 25511:140048494843648] Connect error on fd 21: ECONNREFUSED 2014-12-01 03:57:10,318 W iostream:507 25511:140048494843648] Connect error on fd 22: ECONNREFUSED 2014-12-01 03:57:10,318 W iostream:507 25511:140048494843648] Connect error on fd 23: ECONNREFUSED 2014-12-01 03:57:10,318 W iostream:507 25511:140048494843648] Connect error on fd 24: ECONNREFUSED 2014-12-01 03:57:10,318 W iostream:507 25511:140048494843648] Connect error on fd 25: ECONNREFUSED 2014-12-01 03:57:10,318 W iostream:507 25511:140048494843648] Connect error on fd 26: ECONNREFUSED 2014-12-01 03:57:10,319 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.0373990535736084,buffer=None, _body=None,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b16dd0>,effective_url='http://localhost:8889/public/sip%3A6505550594% 0x2b16dd0>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,319 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,319 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,320 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,320 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.03661990165710449,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29d10>, effective_url='http://localhost:8889/public/sip%3A6505550612%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,320 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,320 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,321 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,321 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.03674006462097168,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29ed0>, effective_url='http://localhost:8889/public/sip%3A6505550637%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,321 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,322 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,322 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,322 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.03672003746032715,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29a90>, effective_url='http://localhost:8889/public/sip%3A6505550671%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,322 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,323 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,323 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,323 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.03683805465698242,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29d50>, effective_url='http://localhost:8889/public/sip%3A6505550676%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,324 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,324 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,324 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,325 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.01263880729675293,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29e50>, effective_url='http://localhost:8889/public/sip%3A6505550714%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,325 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,325 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,325 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,325 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.01265406608581543,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29c10>, effective_url='http://localhost:8889/public/sip%3A6505550751%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,325 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,326 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,326 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,326 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.01233220100402832,buffer=None,_body=Non e,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29250>, effective_url='http://localhost:8889/public/sip%3A6505550764%40example.com/a ssociated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,326 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,326 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,326 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,327 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.011998891830444336,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b294d0>,effective_url='http://localhost:8889/public/sip%3A6505550829% 0x2b294d0>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,327 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,327 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,327 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,327 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.011666059494018555,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29c90>,effective_url='http://localhost:8889/public/sip%3A6505550852% 0x2b29c90>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,328 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,328 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,328 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,328 W iostream:507 25511:140048494843648] Connect error on fd 17: ECONNREFUSED 2014-12-01 03:57:10,328 W iostream:507 25511:140048494843648] Connect error on fd 18: ECONNREFUSED 2014-12-01 03:57:10,328 W iostream:507 25511:140048494843648] Connect error on fd 19: ECONNREFUSED 2014-12-01 03:57:10,329 W iostream:507 25511:140048494843648] Connect error on fd 20: ECONNREFUSED 2014-12-01 03:57:10,329 W iostream:507 25511:140048494843648] Connect error on fd 21: ECONNREFUSED 2014-12-01 03:57:10,329 W iostream:507 25511:140048494843648] Connect error on fd 22: ECONNREFUSED 2014-12-01 03:57:10,329 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.010533809661865234,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b290d0>,effective_url='http://localhost:8889/public/sip%3A6505550886% 0x2b290d0>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,329 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,330 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,330 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,330 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.0102081298828125,buffer=None, _body=None,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29bd0>,effective_url='http://localhost:8889/public/sip%3A6505550912% 0x2b29bd0>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,330 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,330 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,330 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,331 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.009733915328979492,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29990>,effective_url='http://localhost:8889/public/sip%3A6505550915% 0x2b29990>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,331 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,331 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,331 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,331 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.009505987167358398,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29650>,effective_url='http://localhost:8889/public/sip%3A6505550925% 0x2b29650>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,332 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,332 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,332 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,332 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.009031057357788086,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b29ad0>,effective_url='http://localhost:8889/public/sip%3A6505550944% 0x2b29ad0>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,332 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,333 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,333 D utils:89 25511:140048494843648] Still expecting 0 callbacks 2014-12-01 03:57:10,333 W utils:73 25511:140048494843648] Non-OK HTTP response. HTTPResponse(code=599,request_time=0.008651971817016602,buffer=None,_body=No ne,time_info={},request=<tornado.httpclient.HTTPRequest object at 0x2b292d0>,effective_url='http://localhost:8889/public/sip%3A6505550990% 0x2b292d0>40ex ample.com/associated_private_ids',headers={},error=HTTPError('HTTP 599: Connection closed',)) 2014-12-01 03:57:10,333 W numbers:113 25511:140048494843648] Failed to fetch private identities from homestead 2014-12-01 03:57:10,333 E web:718 25511:140048494843648] Cannot send error response after headers written 2014-12-01 03:57:10,333 D util -----Original Message----- From: [email protected] [mailto:[email protected]] On Behalf Of Robert Chen Sent: 2014年11月30日 21:13 To: [email protected] Subject: [Clearwater] Ellis error: Failed to update the server I have been testing Clearwater on AWS AIO for a while, but lately, I got this error and cannot create or update the numbers. The tail of ellis-0.log is attached. Looks like ellis cannot get the private id from homestead. But I checked homestead and its database. All seems OK. Can someone give me some suggestions? Thanks. Robert Chen _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
