Octo deployment hangs with tentacle log errors

Legacy Uncategorised
1

Hi,

We were doing a production maintenance yesterday and had the deployment hang while deploying the packages. We canceled the first deployment and rebooted the octo machine, then triggered the deployment again but had it also hung while deploying packages. Here’s some additional detail:

  • The deployment consists of 26 packages that total about 2G.
  • The deployment targets 37 machines and deploys each package to all of them.
  • octo was under less load than it usually is from a running tasks/deployments perpective.
  • Both times the deployment hung while deploying one of the packages. In both deployments the multiple packages had already been deployed successfully to all nodes before the deployment hangs.
  • In the first deployment, things were progressing but at significantly slower speed than usual.
  • We saw this exception in tentacle logs on several machines for both deployments:
2015-12-05 01:09:29.5954      6  INFO  listen://0.0.0.0:10933/           6  Accepted TCP client: 172.21.230.12:58896
2015-12-05 01:09:29.5954     46  INFO  listen://0.0.0.0:10933/          46  Performing TLS server handshake
2015-12-05 01:09:29.6266     46  INFO  listen://0.0.0.0:10933/          46  Secure connection established, client is not yet authenticated, client connected with Tls12
2015-12-05 01:09:29.8294     46  INFO  listen://0.0.0.0:10933/          46  Client at 172.21.230.12:58896 authenticated as AAAAAAA
2015-12-05 01:17:48.6244      6  INFO  listen://0.0.0.0:10933/           6  Accepted TCP client: 172.21.230.12:59713
2015-12-05 01:17:48.6244     10  INFO  listen://0.0.0.0:10933/          10  Performing TLS server handshake
2015-12-05 01:18:03.7414     10  INFO  listen://0.0.0.0:10933/          10  Secure connection established, client is not yet authenticated, client connected with Tls12
2015-12-05 01:18:03.7414     10  INFO  listen://0.0.0.0:10933/          10  Client at 172.21.230.12:59713 authenticated as AAAAAAA
2015-12-05 01:19:30.4808     46  INFO  listen://0.0.0.0:10933/          46  Unhandled error when handling request from client: 172.21.230.12:58896
System.IO.IOException: Unable to read data from the transport connection: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   --- End of inner exception stack trace ---
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   at System.Net.FixedSizeReader.ReadPacket(Byte[] buffer, Int32 offset, Int32 count)
   at System.Net.Security._SslStream.StartFrameHeader(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   at System.Net.Security._SslStream.StartReading(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   at System.Net.Security._SslStream.ProcessRead(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   at System.Net.Security.SslStream.Read(Byte[] buffer, Int32 offset, Int32 count)
   at System.IO.StreamReader.ReadBuffer()
   at System.IO.StreamReader.ReadLine()
   at Halibut.Transport.Protocol.MessageExchangeStream.ReadLine() in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeStream.cs:line 94
   at Halibut.Transport.Protocol.MessageExchangeStream.ExpectNextOrEnd() in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeStream.cs:line 65
   at Halibut.Transport.Protocol.MessageExchangeProtocol.ProcessClientRequests(Func`2 incomingRequestProcessor) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeProtocol.cs:line 110
   at Halibut.Transport.Protocol.MessageExchangeProtocol.ExchangeAsServer(Func`2 incomingRequestProcessor, Func`2 pendingRequests) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeProtocol.cs:line 90
   at Halibut.Transport.SecureListener.ExecuteRequest(TcpClient client) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\SecureListener.cs:line 122
2

“Octopus.Version”: “3.1.5”,
“System.ClrVersion”: “4.0.30319.18408”,
“System.OSVersion”: “Microsoft Windows NT 6.1.7601 Service Pack 1”

3

Some more information around this. The job that was canceled is still shown as running

The deployment looks like it is in a really weird state

image
image2868×486

4

The first deployment also had this error around the same time the deployment became unresponsive.

2015-12-05 00:29:44.6864    464 ERROR  Unhandled exception from web server: The semaphore timeout period has expired
System.Net.HttpListenerException (0x80004005): The semaphore timeout period has expired
   at System.Net.HttpResponseStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at System.IO.Compression.DeflateStream.WriteDeflaterOutput(Boolean isAsync)
   at System.IO.Compression.DeflateStream.Write(Byte[] array, Int32 offset, Int32 count)
   at System.IO.Compression.GZipStream.Write(Byte[] array, Int32 offset, Int32 count)
   at Nancy.IO.UnclosableStreamWrapper.Write(Byte[] buffer, Int32 offset, Int32 count)
   at System.IO.StreamWriter.Flush(Boolean flushStream, Boolean flushEncoder)
   at System.IO.StreamWriter.Write(String value)
   at Newtonsoft.Json.Utilities.JavaScriptUtils.WriteEscapedJavaScriptString(TextWriter writer, String s, Char delimiter, Boolean appendDelimiters, Boolean[] charEscapeFlags, StringEscapeHandling stringEscapeHandling, Char[]& writeBuffer)
   at Newtonsoft.Json.JsonTextWriter.WriteEscapedString(String value, Boolean quote)
   at Newtonsoft.Json.JsonWriter.WriteValue(JsonWriter writer, PrimitiveTypeCode typeCode, Object value)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(JsonWriter writer, Object value, JsonObjectContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeList(JsonWriter writer, IEnumerable values, JsonArrayContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(JsonWriter writer, Object value, JsonObjectContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeList(JsonWriter writer, IEnumerable values, JsonArrayContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(JsonWriter writer, Object value, JsonObjectContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeList(JsonWriter writer, IEnumerable values, JsonArrayContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(JsonWriter writer, Object value, JsonObjectContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeList(JsonWriter writer, IEnumerable values, JsonArrayContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(JsonWriter writer, Object value, JsonObjectContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(JsonWriter writer, Object value, JsonObjectContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.Serialize(JsonWriter jsonWriter, Object value, Type objectType)
   at Newtonsoft.Json.JsonSerializer.SerializeInternal(JsonWriter jsonWriter, Object value, Type objectType)
   at Nancy.Serialization.JsonNet.JsonNetSerializer.Serialize[TModel](String contentType, TModel model, Stream outputStream)
   at Octopus.Server.Web.Infrastructure.NancyCompression.<>c__DisplayClass3_0.<CompressResponse>b__0(Stream responseStream) in Y:\work\refs\tags\3.1.5\source\Octopus.Server\Web\Infrastructure\NancyCompression.cs:line 99
   at Octopus.Server.Web.OctopusNancyHost.OutputWithDefaultTransferEncoding(Response nancyResponse, HttpListenerResponse response) in Y:\work\refs\tags\3.1.5\source\Octopus.Server\Web\OctopusNancyHost.cs:line 353
   at Octopus.Server.Web.OctopusNancyHost.ConvertNancyResponseToResponse(NancyContext nancyRequest, Response nancyResponse, HttpListenerResponse response) in Y:\work\refs\tags\3.1.5\source\Octopus.Server\Web\OctopusNancyHost.cs:line 339
   at Octopus.Server.Web.OctopusNancyHost.Process(HttpListenerContext ctx) in Y:\work\refs\tags\3.1.5\source\Octopus.Server\Web\OctopusNancyHost.cs:line 447

We canceled the task and then restarted the service, once we restarted the service we got a few of these errors. The server task id correlates to the same image above that is currently in a weird state.

2015-12-05 01:09:29.2562   1489 ERROR  Failed to append the following log entry:
CorrelationId: ServerTasks-19084_DEV9KH9DUW/fd19e55d209d4e228cfed8eaa2207c4f/82205eae57f04e649e131639ddf61942
Message: XML Transformation warnings will be suppressed.
System.NullReferenceException: Object reference not set to an instance of an object.
   at Octopus.Server.Orchestration.Logging.Processors.Caching.SynchronizedCache`1.GetOrCreate(String id, Func`1 factory) in Y:\work\refs\tags\3.1.5\source\Octopus.Server\Orchestration\Logging\Processors\Caching\SynchronizedCache.cs:line 48
   at Octopus.Server.Orchestration.Logging.ServerLogStorage.ProcessLogEntry(String correlationId, ActivityLogEntry entry) in Y:\work\refs\tags\3.1.5\source\Octopus.Server\Orchestration\Logging\ServerLogStorage.cs:line 81
   at Octopus.Shared.TransientFaultHandling.RetryPolicy.<>c__DisplayClass26_0.<ExecuteAction>b__0() in Y:\work\refs\tags\3.1.5\source\Octopus.Shared\TransientFaultHandling\RetryPolicy.cs:line 171
   at Octopus.Shared.TransientFaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func) in Y:\work\refs\tags\3.1.5\source\Octopus.Shared\TransientFaultHandling\RetryPolicy.cs:line 215
   at Octopus.Server.Orchestration.Logging.ServerLogStorage.SafelyAppend(String correlationId, ActivityLogEntry entry) in Y:\work\refs\tags\3.1.5\source\Octopus.Server\Orchestration\Logging\ServerLogStorage.cs:line 63

There were no more errors in the logs after these entries and when the second deployment started erroring so I am not sure what caused it to hang the second time however there were other tasks for other environments and when I canceled some of them the logs started populating again. I am not 100% sure where else to look

5

Hi Brent and R,

Are you able to provide the corresponding tentacle logs for the same time of the deployment. We are hoping they provide more of the puzzle.
You have had that error happen once before in 2.5 http://help.octopusdeploy.com/discussions/problems/28198-after-upgrade-to-2512666-problems-with-stuck-tasks
It doesn’t appear that we had any specific ideas of what caused it, but it shows its across both versions.

Vanessa

6

So the first exception is from the tentacle. The only thing we really see is this

2015-12-05 00:44:30.2223      5  INFO  listen://0.0.0.0:10933/           5  Unhandled error when handling request from client: 172.21.230.12:55726
System.IO.IOException: Unable to read data from the transport connection: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   --- End of inner exception stack trace ---
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   at System.Net.FixedSizeReader.ReadPacket(Byte[] buffer, Int32 offset, Int32 count)
   at System.Net.Security._SslStream.StartFrameHeader(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   at System.Net.Security._SslStream.StartReading(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   at System.Net.Security._SslStream.ProcessRead(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   at System.Net.Security.SslStream.Read(Byte[] buffer, Int32 offset, Int32 count)
   at System.IO.StreamReader.ReadBuffer()
   at System.IO.StreamReader.ReadLine()
   at Halibut.Transport.Protocol.MessageExchangeStream.ReadLine() in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeStream.cs:line 91
   at Halibut.Transport.Protocol.MessageExchangeStream.ExpectNextOrEnd() in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeStream.cs:line 65
   at Halibut.Transport.Protocol.MessageExchangeProtocol.ProcessClientRequests(Func`2 incomingRequestProcessor) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeProtocol.cs:line 110
   at Halibut.Transport.Protocol.MessageExchangeProtocol.ExchangeAsServer(Func`2 incomingRequestProcessor, Func`2 pendingRequests) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeProtocol.cs:line 90
   at Halibut.Transport.SecureListener.ExecuteRequest(TcpClient client) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\SecureListener.cs:line 122