One tentacle instance is extremely slow to execute each step

Hi there,

We have one Octopus tentacle that is extremely slow – orders of magnitude slower than other tentacles on other machines. Deployments that take only a minute or two on the other server take over an hour on that one. And the slowdown seems to be at the beginning of each step, the initial response and deployment of the package takes 2-4 minutes; after that, the commands in the step execute fairly rapidly. But for any project with a large number of steps, that delay adds up quickly.

Deploying to a normal server:
(Ignore that the packages aren’t the same; the timing differences between the two servers was about the same each deployment)

09:40:48 Verbose Octopus Server version: 3.2.8+Branch.master.Sha.ec2c87850589f7276bfcba17a2ed24b9326e745b
09:40:48 Info Deploying package ‘C:\Octopus\Files\XXXX.XXXXXXXX.1.1.1.25801-XXXXX-XXXXXXXX.nupkg-8c5d5601-978c-4661-94ab-33072ccbdfa1’ to machine 'https://XXX-test-01:10933/'
09:40:49 Verbose Octopus Deploy: Calamari version 3.1.19+Branch.master.Sha.04312b777a821034d6278af5b5f9c696eade99c5
09:40:49 Info Deploying package: C:\Octopus\Files\XXXX.XXXXXXXX.1.1.1.25801-XXXXX-XXXXXXXX.nupkg-8c5d5601-978c-4661-94ab-33072ccbdfa1
09:40:50 Verbose Extracting package to: C:\Octopus\Applications\XXXTest\XXXX.XXXXXXXX\1.1.1.25801-XXXXX-XXXXXXXX
09:40:55 Verbose Extracted 89 files
09:40:55 …

Deploying the the super-slow server:

10:16:28 Verbose Octopus Server version: 3.2.8+Branch.master.Sha.ec2c87850589f7276bfcba17a2ed24b9326e745b
10:16:28 Info Deploying package ‘C:\Octopus\Files\XXXX.XXXXXXXX.1.1.1.26087-XXXXX-XXXXXXXX.nupkg-a6577468-7ecc-478a-b965-8795643304b1’ to machine 'https://XXX-dev-01:10933/'
10:18:35 Verbose Octopus Deploy: Calamari version 3.1.19+Branch.master.Sha.04312b777a821034d6278af5b5f9c696eade99c5
10:19:00 Info Deploying package: C:\Octopus\Files\XXXX.XXXXXXXX.1.1.1.26087-XXXXX-XXXXXXXX.nupkg-a6577468-7ecc-478a-b965-8795643304b1
10:19:10 Verbose Extracting package to: C:\Octopus\Applications\XXXDev\XXXX.XXXXXXXX\1.1.1.26087-XXXXX-XXXXXXXX_1
10:19:15 …

Things we’ve checked:

  • The server connectivity is fine on both of them. TentaclePing reports about the same numbers.
  • No unusual disk or CPU load on the afflicted tentacle
  • Antivirus configuration is the same on both machines
  • Powershell prompts start up quickly enough (< 1s)
  • Downloading latest Tentacle installer and reinstalling
  • generating a new certificate and deleting, setting up a new Tentacle instance

It seems like tentacle.exe itself is unusually slow on the one machine.

PS> Measure-Command { cmd.exe /c “"c:\Program Files\Octopus Deploy\Tentacle\Tentacle.exe” help" }
TotalSeconds:
On good machine: 1.3
On bad machine: 18.8

Any suggestions?
Thanks!

The OS is Windows Server 2012 R2 on all machines. Nothing relevant shows up on the diagnostics page.
Attached is a sanitized deployment log from the slow machine.

I tried the Hello World from the management console diagnostic suggested in another discussion thread, and the results were similar: from the good server, ~2s to execute.
From the bad server:

Task ID: ServerTasks-7046
Task status: Success
Task queued: Tuesday, May 24, 2016 1:49 PM
Task started: Tuesday, May 24, 2016 1:49 PM
Task duration: 4 minutes
Server version: 3.2.8+Branch.master.Sha.ec2c87850589f7276bfcba17a2ed24b9326e745b

                | == Success: Script run from management console ==
                | 
                |   == Success: Run script on: XXX-DEV-01 ==

13:49:27 Verbose | Octopus Deploy: Calamari version 3.1.19+Branch.master.Sha.04312b777a821034d6278af5b5f9c696eade99c5
13:53:22 Verbose | Name Value
13:53:22 Verbose | ---- -----
13:53:22 Verbose | PSVersion 4.0
13:53:22 Verbose | WSManStackVersion 3.0
13:53:22 Verbose | SerializationVersion 1.1.0.1
13:53:22 Verbose | CLRVersion 4.0.30319.42000
13:53:22 Verbose | BuildVersion 6.3.9600.17400
13:53:22 Verbose | PSCompatibleVersions {1.0, 2.0, 3.0, 4.0}
13:53:22 Verbose | PSRemotingProtocolVersion 2.2
13:53:22 Info | hello world from XXX-DEV-01
13:53:22 Info | Exit code: 0

octopus_slow_deployment_log.txt (36 KB)

Hi Nolan,

Wow, that really is slow. We have never seen that before.

Could you possibly also supply the Tentacle logs for a relevant time period. This are located by default at C:\Octopus\Logs\OctopusTentacle.txt.

Regards,
Michael

Thanks, Michael,

Here is the Octopus tentacle log from that day.

Yes, there are recurring IOException timeouts, however:

  • The errors don’t particularly coincide with the slowdowns in the deployment or my diagnostic activities
  • All of the tentacles in our system have the same pattern of timeout errors, so something’s obviously not quite right with our Octopus server, but it shouldn’t be behind the issues with this tentacle

OctopusTentacle.txt (59 KB)

Thanks Nolan.
I examined your logs, and I agree with you. Those errors, while a little concerning, don’t seem to explain what your are seeing. I would guess those errors correspond with Health Checks triggered by the Octopus Server.

I discussed your issue with our team, and we’re rather baffled. The best guess we could produce is possibly a delay caused by checking the Certificate Revocation List. Is it possible the affected machine doesn’t have internet access? Keep in mind, this is a complete Hail-Mary-Guess.

You may already have, but it is probably worth checking the Windows Event logs too, to see if there are any red flags.

Other than that, all I can suggest is to try re-installing the Tentacle service on that machine.

I wish I had a better answer for you. Please keep me updated, and let us know if there’s anything we can do to help.

Regards,
Michael