Exception during upgrade of polling tentacle over VPN connection

Legacy Uncategorised
1

Hi,

We are just starting to use Octopus 3 (server version 3.0.19.2485).

For security reasons, our IT people require us to use polling tentacles for deploys to production and to our DR site. We’ve set up polling tentacles for production and they’re working fine.

Our Octopus server is in Vancouver; our DR site is in the UK, connected via VPN.

Health checks are failing consistently for some tentacles at the DR site. The server attempts to upload a new Calamari package, which takes some time. After exactly 12 minutes (to the second), it fails with a NullReferenceException reported in the task output. The server log file shows an ObjectDisposedException accessing a file stream. (See log excerpts below, with sensitive bits redacted.)

I’m not seeing anything related to the upgrade in the tentacle log, only in the server log. The tentacle log says the tentacle version is “3.0.19 / 16713d9a/refs/heads/master”.

I will check with IT tomorrow to rule out firewall timeouts on our VPN connection.

If the problem only happens due to the slowness of shipping the new Calamari package over the VPN, I’m wondering if it’s possible for me to either disable tentacle upgrades, or do the upgrade manually rather than having it pushed from the Octopus server. (I’m not sure why it’s trying to upgrade… I thought I had installed the tentacle version that matches the server version.)

Thanks for your help!
Richard

Here is the task output:

Task ID:       ServerTasks-3882
Task status:   Failed
Task queued:   Tuesday, September 08, 2015 7:48 PM
Task started:  Tuesday, September 08, 2015 7:48 PM
Task duration: 12 minutes

                    | == Running: Check <machine> health ==
19:48:45   Info     |   Starting health check for a limited set of deployment targets
19:48:45   Info     |   The following deployment targets will be checked:
19:48:45   Info     |   - <machine> at poll://4h8kvrz4uhczb2edk9cx/
20:00:49   Trace    |   Health check complete, storing results.
20:00:49   Error    |   The health check failed. One or more deployment targets were not available.
                    | 
                    |   == Failed: Check deployment target: <machine> ==
19:48:45   Info     |     Running health check on <machine>
19:48:45   Info     |     Sending health check request to <machine> at poll://4h8kvrz4uhczb2edk9cx/...
19:48:48   Info     |     This server does not have version 3.0.19.456 of the Calamari package. It will be pushed automatically.
20:00:48   Trace    |     Deployment Target health check failed.
20:00:48   Fatal    |     Object reference not set to an instance of an object.
                    |   
                    |   Failed: Health results: 
20:00:49   Info     |     - OFFLINE: <machine> at poll://4h8kvrz4uhczb2edk9cx/
20:00:49   Fatal    |     One or more Agents were not online. Please see the output log for details.

Here is the server log OctopusServer.txt:

2015-09-08 19:48:40.1944    214  INFO  listen://0.0.0.0:10943/         214  Accepted TCP client: <ip-address>:60829
2015-09-08 19:48:40.2101     84  INFO  listen://0.0.0.0:10943/          84  Performing SSL (TLS 1.0) server handshake
2015-09-08 19:48:40.4132     84  INFO  listen://0.0.0.0:10943/          84  Secure connection established, client is not yet authenticated
2015-09-08 19:48:40.6007     84  INFO  listen://0.0.0.0:10943/          84  Client at <ip-address>:60829 authenticated as <redacted>
2015-09-08 19:48:45.7568    563  INFO  poll://4h8kvrz4uhczb2edk9cx/    563  Request IScriptService::StartScript[1] / bc5f7ebe-ce10-4e24-b43f-37c095e54675 was queued
2015-09-08 19:48:46.9287    563  INFO  poll://4h8kvrz4uhczb2edk9cx/    563  Request IScriptService::StartScript[1] / bc5f7ebe-ce10-4e24-b43f-37c095e54675 was collected by the polling endpoint
2015-09-08 19:48:47.4287    563  INFO  poll://4h8kvrz4uhczb2edk9cx/    563  Request IScriptService::GetStatus[2] / 4397c863-23f8-4b1f-b9b7-58d999d6492b was queued
2015-09-08 19:48:47.9287    563  INFO  poll://4h8kvrz4uhczb2edk9cx/    563  Request IScriptService::GetStatus[2] / 4397c863-23f8-4b1f-b9b7-58d999d6492b was collected by the polling endpoint
2015-09-08 19:48:47.9287    563  INFO  poll://4h8kvrz4uhczb2edk9cx/    563  Request IScriptService::CompleteScript[3] / 6da495cb-447b-4dd1-96a6-368760876ee8 was queued
2015-09-08 19:48:48.8818    563  INFO  poll://4h8kvrz4uhczb2edk9cx/    563  Request IScriptService::CompleteScript[3] / 6da495cb-447b-4dd1-96a6-368760876ee8 was collected by the polling endpoint
2015-09-08 19:48:48.9130    563  INFO  poll://4h8kvrz4uhczb2edk9cx/    563  Request IScriptService::StartScript[4] / 49754f30-4fe3-4dd2-87a6-853556833aca was queued
2015-09-08 19:48:50.3192    164  INFO  System dashboard loaded in: 50.9805ms
2015-09-08 19:49:02.8815     84  INFO  Uploading Calamari package
2015-09-08 19:49:15.9750     84  INFO  Uploading Calamari package

... lots more of this ...

2015-09-08 20:00:32.6807     84  INFO  Uploading Calamari package
2015-09-08 20:00:41.7743     84  INFO  Uploading Calamari package
2015-09-08 20:00:48.9148    563  INFO  poll://4h8kvrz4uhczb2edk9cx/    563  Request IScriptService::StartScript[4] / 49754f30-4fe3-4dd2-87a6-853556833aca was eventually collected by the polling endpoint
2015-09-08 20:00:49.6179     84  INFO  listen://0.0.0.0:10943/          84  Unhandled error when handling request from client: <ip-address>:60829
System.ObjectDisposedException: Cannot access a closed file.
   at System.IO.FileStream.Read(Byte[] array, Int32 offset, Int32 count)
   at Halibut.DataStream.StreamingDataStream.CopyAndReportProgress(Stream destination) in y:\work\7ab39c94136bc5c6\source\Halibut\DataStream.cs:line 127
   at Halibut.Transport.Protocol.MessageExchangeStream.WriteEachStream(IEnumerable`1 streams) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeStream.cs:line 272
   at Halibut.Transport.Protocol.MessageExchangeStream.Send[T](T message) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeStream.cs:line 142
   at Halibut.Transport.Protocol.MessageExchangeProtocol.ProcessSubscriber(IPendingRequestQueue pendingRequests) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeProtocol.cs:line 123
   at Halibut.Transport.Protocol.MessageExchangeProtocol.ExchangeAsServer(Func`2 incomingRequestProcessor, Func`2 pendingRequests) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\Protocol\MessageExchangeProtocol.cs:line 95
   at Halibut.Transport.SecureListener.ExecuteRequest(TcpClient client) in y:\work\7ab39c94136bc5c6\source\Halibut\Transport\SecureListener.cs:line 122
2015-09-08 20:00:50.2429    526  INFO  System dashboard loaded in: 48.7737ms
2

Hi Richard,

It does sound like a timeout. To my knowledge we don’t have any time restraints on pushing packages, you may have a similar problem when you are deploying your packages?

Some good news: we have shrunk Calamari in 3.1 so the problem should go away in future. What’s happening is that Tentacles do not contain Calamari, it gets pushed to the Tentacle by the server. That way we avoid having to update Tentacles every time the Octopus Server is updated, any Calamari updates are just pushed to the Tentacle instead.

You can work around the issue by putting the Calamari package on each of the Tentacles. If you use a working Tentacle as an example, Calamari is located in the Calamari folder under the Tentacle home directory (usually C:\Octopus\Calamari). There should be a sub-directory with a version number. Copy that directory to each of the Tentacles and you should be back in business.

Hope this helps.

Cheers,
Shane

3

Thanks Shane… this worked great. I copied in the Calamari folder and the health check passed right away.

I will do some test deploys of our own packages to see if we run into similar issues when deploying to DR. We haven’t had problems before (we were running on an old Octopus version), but maybe something has changed on our network.

Thanks again,
Richard