{"action":"opened","issue":{"url":"https://api.github.com/repos/arangodb/arangodb/issues/2209","repository_url":"https://api.github.com/repos/arangodb/arangodb","labels_url":"https://api.github.com/repos/arangodb/arangodb/issues/2209/labels{/name}","comments_url":"https://api.github.com/repos/arangodb/arangodb/issues/2209/comments","events_url":"https://api.github.com/repos/arangodb/arangodb/issues/2209/events","html_url":"https://github.com/arangodb/arangodb/issues/2209","id":193892351,"number":2209,"title":"Query time 0.000000 in log with too many open connections","user":{"login":"razvanphp","id":4599319,"avatar_url":"https://avatars.githubusercontent.com/u/4599319?v=3","gravatar_id":"","url":"https://api.github.com/users/razvanphp","html_url":"https://github.com/razvanphp","followers_url":"https://api.github.com/users/razvanphp/followers","following_url":"https://api.github.com/users/razvanphp/following{/other_user}","gists_url":"https://api.github.com/users/razvanphp/gists{/gist_id}","starred_url":"https://api.github.com/users/razvanphp/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/razvanphp/subscriptions","organizations_url":"https://api.github.com/users/razvanphp/orgs","repos_url":"https://api.github.com/users/razvanphp/repos","events_url":"https://api.github.com/users/razvanphp/events{/privacy}","received_events_url":"https://api.github.com/users/razvanphp/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":0,"created_at":"2016-12-06T21:38:18Z","updated_at":"2016-12-06T21:38:18Z","closed_at":null,"body":"I'm using ArangoDB 2.8.11, I also noticed this in the past, but it seems to be fixed after the server restarts, but somehow reappears.\r\n\r\n```\r\n2016-12-06T22:28:30 [51782] INFO \"http-request-end\",\"0x368f84dc0\",\"10.107.141.88\",\"GET\",\"HTTP/1.1\",200,0,3117,\"/sorter-api-ch/products/1977042/scores\",0.000000\r\n2016-12-06T22:28:30 [51782] INFO \"http-request-end\",\"0x358e483c0\",\"10.107.61.41\",\"GET\",\"HTTP/1.1\",200,0,3105,\"/sorter-api-edited/products/1799328/scores\",0.000000\r\n2016-12-06T22:28:30 [51782] INFO \"http-request-end\",\"0x36bc8a580\",\"10.107.141.88\",\"GET\",\"HTTP/1.1\",200,0,1706,\"/sorter-api-ch/products/2188765/scores\",0.000000\r\n2016-12-06T22:28:30 [51782] INFO \"http-request-end\",\"0x3740d0940\",\"10.107.141.88\",\"GET\",\"HTTP/1.1\",200,0,163,\"/sorter-api-ch/products/2053765/scores\",0.000000\r\n2016-12-06T22:28:30 [51782] INFO \"http-request-end\",\"0x358e483c0\",\"10.107.61.41\",\"GET\",\"HTTP/1.1\",200,0,159,\"/sorter-api-edited/products/1799330/scores\",0.000000\r\n2016-12-06T22:28:30 [51782] INFO \"http-request-end\",\"0x358e483c0\",\"10.107.61.41\",\"GET\",\"HTTP/1.1\",200,0,159,\"/sorter-api-edited/products/1799332/scores\",0.000000\r\n```\r\n\r\nAs a side effect, it seems that the web interface also does not show anything anymore in the first part of the graphs, here is the API response:\r\n```\r\n{\"times\":[1481060071.001472],\"avgTotalTime\":[0],\"avgRequestTime\":[0],\"avgQueueTime\":[0],\"avgIoTime\":[0],\"bytesSentPerSecond\":[0],\"bytesReceivedPerSecond\":[0],\"asyncPerSecond\":[0],\"optionsPerSecond\":[0],\"putsPerSecond\":[0],\"headsPerSecond\":[0],\"postsPerSecond\":[0],\"getsPerSecond\":[0],\"deletesPerSecond\":[0],\"othersPerSecond\":[0],\"patchesPerSecond\":[0],\"systemTimePerSecond\":[0.04199827773481849],\"userTimePerSecond\":[0.5379779386035236],\"majorPageFaultsPerSecond\":[0],\"minorPageFaultsPerSecond\":[3618.0516309546174],\"totalTimeDistributionPercent\":{\"values\":[0,0,0,0,0,0,0],\"cuts\":[0.01,0.05,0.1,0.2,0.5,1]},\"requestTimeDistributionPercent\":{\"values\":[0,0,0,0,0,0,0],\"cuts\":[0.01,0.05,0.1,0.2,0.5,1]},\"queueTimeDistributionPercent\":{\"values\":[0,0,0,0,0,0,0],\"cuts\":[0.01,0.05,0.1,0.2,0.5,1]},\"bytesSentDistributionPercent\":{\"values\":[0,0,0,0,0,0],\"cuts\":[250,1000,2000,5000,10000]},\"bytesReceivedDistributionPercent\":{\"values\":[0,0,0,0,0,0],\"cuts\":[250,1000,2000,5000,10000]},\"numberOfThreadsCurrent\":40,\"numberOfThreadsPercentChange\":0,\"virtualSizeCurrent\":29724635136,\"virtualSizePercentChange\":0.00031455431224050476,\"residentSizeCurrent\":25894342656,\"residentSizePercent\":0.3834003641716429,\"asyncPerSecondCurrent\":0,\"asyncPerSecondPercentChange\":0,\"syncPerSecondCurrent\":0,\"syncPerSecondPercentChange\":0,\"clientConnectionsCurrent\":1000,\"clientConnectionsPercentChange\":0,\"physicalMemory\":67538649088,\"nextStart\":1481060071.001472,\"waitFor\":6.969300031661987,\"numberOfThreads15M\":40,\"numberOfThreads15MPercentChange\":0,\"virtualSize15M\":29374102907.685394,\"virtualSize15MPercentChange\":0.0002356930559135715,\"asyncPerSecond15M\":0,\"asyncPerSecond15MPercentChange\":0,\"syncPerSecond15M\":0,\"syncPerSecond15MPercentChange\":0,\"clientConnections15M\":1000,\"clientConnections15MPercentChange\":0}\r\n```\r\n\r\nThe only strange this that happens with the server during this time is the high number of ESTABLISHED connections (around 2000), which we are still investigating, seems to be cause by some VPN connection or a bad client not closing the connections, not really sure if related.\r\n\r\nIf you need a stack trace when this happens, let me know, I saved it.\r\n\r\nThank you!"}}
{"actor":{"display_login":"razvanphp"}}