Fixes for stalling scenery downloads.

- handle closed connections equivalent to IDLE, for timeout purposes
- if the server closes the socket in WAITING_FOR_RESPONSE state, fail
  the first sent request when restoring.

Note this does not explain why the server sometimes closes the socket
in this way, but at least it now causes a detectable failure.
This commit is contained in:
James Turner
2016-01-03 11:58:22 -06:00
parent ef7a0dc5a3
commit be0447d4c0
4 changed files with 93 additions and 29 deletions

View File

@@ -106,10 +106,11 @@ public:
class Connection : public NetChat
{
public:
Connection(Client* pr) :
Connection(Client* pr, const std::string& conId) :
client(pr),
state(STATE_CLOSED),
port(DEFAULT_HTTP_PORT)
port(DEFAULT_HTTP_PORT),
connectionId(conId)
{
}
@@ -140,6 +141,11 @@ public:
virtual void handleError(int error)
{
const char* errStr = strerror(error);
SG_LOG(SG_IO, SG_WARN, "HTTP Connection handleError:" << error << " ("
<< errStr << ")");
debugDumpRequests();
if (!activeRequest)
{
// connection level failure, eg name lookup or routing
@@ -168,6 +174,11 @@ public:
state = STATE_SOCKET_ERROR;
}
void handleTimeout()
{
handleError(ETIMEDOUT);
}
virtual void handleClose()
{
NetChat::handleClose();
@@ -180,6 +191,13 @@ public:
state = STATE_CLOSED;
responseComplete();
} else {
if (state == STATE_WAITING_FOR_RESPONSE) {
assert(!sentRequests.empty());
sentRequests.front()->setFailure(500, "server closed connection unexpectedly");
// no active request, but don't restore the front sent one
sentRequests.erase(sentRequests.begin());
}
if (activeRequest) {
activeRequest->setFailure(500, "server closed connection");
// remove the failed request from sentRequests, so it does
@@ -207,19 +225,6 @@ public:
sentRequests.clear();
}
void handleTimeout()
{
NetChat::handleError(ETIMEDOUT);
if (activeRequest) {
SG_LOG(SG_IO, SG_DEBUG, "HTTP socket timeout");
activeRequest->setFailure(ETIMEDOUT, "socket timeout");
activeRequest = NULL;
_contentDecoder.reset();
}
state = STATE_SOCKET_ERROR;
}
void queueRequest(const Request_ptr& r)
{
queuedRequests.push_back(r);
@@ -356,9 +361,7 @@ public:
}
}
// SG_LOG(SG_IO, SG_INFO, "did start request:" << r->url() <<
// "\n\t @ " << reinterpret_cast<void*>(r.ptr()) <<
// "\n\t on connection " << this);
SG_LOG(SG_IO, SG_DEBUG, "con:" << connectionId << " did start request:" << r->url());
// successfully sent, remove from queue, and maybe send the next
queuedRequests.pop_front();
sentRequests.push_back(r);
@@ -423,21 +426,23 @@ public:
bool hasIdleTimeout() const
{
if (state != STATE_IDLE) {
if ((state != STATE_IDLE) && (state != STATE_CLOSED)) {
return false;
}
assert(sentRequests.empty());
return idleTime.elapsedMSec() > 1000 * 10; // ten seconds
bool isTimedOut = (idleTime.elapsedMSec() > (1000 * 10)); // 10 seconds
return isTimedOut;
}
bool hasErrorTimeout() const
{
if (state == STATE_IDLE) {
if ((state == STATE_IDLE) || (state == STATE_CLOSED)) {
return false;
}
return idleTime.elapsedMSec() > (1000 * 30); // 30 seconds
bool isTimedOut = (idleTime.elapsedMSec() > (1000 * 30)); // 30 seconds
return isTimedOut;
}
bool hasError() const
@@ -454,17 +459,37 @@ public:
{
return !queuedRequests.empty() || !sentRequests.empty();
}
void debugDumpRequests() const
{
SG_LOG(SG_IO, SG_DEBUG, "requests for:" << host << ":" << port << " (conId=" << connectionId
<< "; state=" << state << ")");
if (activeRequest) {
SG_LOG(SG_IO, SG_DEBUG, "\tactive:" << activeRequest->url());
} else {
SG_LOG(SG_IO, SG_DEBUG, "\tNo active request");
}
BOOST_FOREACH(Request_ptr req, sentRequests) {
SG_LOG(SG_IO, SG_DEBUG, "\tsent:" << req->url());
}
BOOST_FOREACH(Request_ptr req, queuedRequests) {
SG_LOG(SG_IO, SG_DEBUG, "\tqueued:" << req->url());
}
}
private:
bool connectToHost()
{
SG_LOG(SG_IO, SG_DEBUG, "HTTP connecting to " << host << ":" << port);
if (!open()) {
SG_LOG(SG_ALL, SG_WARN, "HTTP::Connection: connectToHost: open() failed");
SG_LOG(SG_IO, SG_WARN, "HTTP::Connection: connectToHost: open() failed");
return false;
}
if (connect(host.c_str(), port) != 0) {
SG_LOG(SG_IO, SG_WARN, "HTTP::Connection: connectToHost: connect() failed");
return false;
}
@@ -605,7 +630,6 @@ private:
// notify request after we change state, so this connection is idle
// if completion triggers other requests (which is likely)
// SG_LOG(SG_IO, SG_INFO, "*** responseComplete:" << activeRequest->url());
completedRequest->responseComplete();
client->requestFinished(this);
@@ -639,6 +663,7 @@ private:
RequestList sentRequests;
ContentDecoder _contentDecoder;
std::string connectionId;
};
#endif // of !ENABLE_CURL
@@ -910,7 +935,7 @@ void Client::makeRequest(const Request_ptr& r)
// allocate a new connection object
if (!con) {
con = new Connection(this);
con = new Connection(this, connectionId);
con->setServer(host, port);
d->poller.addChannel(con);
d->connections.insert(d->connections.end(),
@@ -1080,6 +1105,20 @@ size_t Client::requestHeaderCallback(char *rawBuffer, size_t size, size_t nitems
return byteSize;
}
void Client::debugDumpRequests()
{
#if defined(ENABLE_CURL)
#else
SG_LOG(SG_IO, SG_INFO, "== HTTP connection dump");
ConnectionDict::iterator it = d->connections.begin();
for (; it != d->connections.end(); ++it) {
it->second->debugDumpRequests();
}
SG_LOG(SG_IO, SG_INFO, "==");
#endif
}
} // of namespace HTTP
} // of namespace simgear

View File

@@ -98,6 +98,8 @@ public:
* monitoring
*/
uint64_t totalBytesDownloaded() const;
void debugDumpRequests();
private:
// libCurl callbacks
static size_t requestWriteCallback(char *ptr, size_t size, size_t nmemb, void *userdata);

View File

@@ -227,6 +227,13 @@ void NetChannel::handleAccept (void) {
void NetChannel::handleError (int error)
{
if (error == EINPROGRESS) {
// this shoudl never happen, because we should use isNonBlocking to check
// such error codes.
SG_LOG(SG_IO, SG_WARN, "Got EINPROGRESS at NetChannel::handleError: suggests broken logic somewhere else");
return; // not an actual error, don't warn
}
// warn about address lookup failures seperately, don't warn again.
// (and we (ab-)use ENOENT to mean 'name not found'.
if (error != ENOENT) {

View File

@@ -293,6 +293,12 @@ public:
d << contentStr;
push(d.str().c_str());
closeAfterSending();
} else if (path == "/test_abrupt_close") {
// simulate server doing socket close before sending any
// response - this used to cause a TerraSync failure since we
// would get stuck restarting the request
closeAfterSending();
} else if (path == "/test_args") {
if ((args["foo"] != "abc") || (args["bar"] != "1234") || (args["username"] != "johndoe")) {
sendErrorResponse(400, true, "bad arguments");
@@ -654,15 +660,25 @@ int main(int argc, char* argv[])
}
cout << "done3" << endl;
// test connectToHost failure
/*
{
TestRequest* tr = new TestRequest("http://not.found/something");
HTTP::Request_ptr own(tr);
cl.makeRequest(tr);
waitForFailed(tr);
COMPARE(tr->responseCode(), -1);
waitForFailed(&cl, tr);
COMPARE(tr->responseCode(), ENOENT);
}
*/
// test server-side abrupt close
{
TestRequest* tr = new TestRequest("http://localhost:2000/test_abrupt_close");
HTTP::Request_ptr own(tr);
cl.makeRequest(tr);
waitForFailed(&cl, tr);
COMPARE(tr->responseCode(), 500);
}
// test proxy
{
cl.setProxy("localhost", 2000);