search

cloudfoundry / credhub-cli

CredHub CLI provides a command line interface to interact with CredHub servers
Apache License 2.0
39 stars 44 forks source link

Taking 10-20 seconds to do anything. #88

Closed mboldt closed 4 years ago

mboldt commented 4 years ago

What version of the credhub server you are using?

Server Version: 2.3.0

What version of the credhub cli you are using?

CLI Version: 2.6.2 on darwin

If you were attempting to accomplish a task, what was it you were attempting to do?

credhub --version (or anything else beyond --help)

What did you expect to happen?

See results on the order of 1 second

What was the actual behavior?

See results in 10-20 seconds.

Please confirm where necessary:

If you are a PCF customer with an Operation Manager (PCF Ops Manager) please direct your questions to support (https://support.pivotal.io/)

When I use the latest darwin CLI release, any operation seems to take 10-20 seconds. I've rebuilt the CLI locally, both with the latest on master and with the tag from the 2.6.2 release, and the results come back quickly.

mboldt@mboldt-pivotal:~/Downloads/$ time ./credhub --version
CLI Version: 2.6.2
Server Version: 2.3.0

real    0m15.131s
user    0m0.648s
sys 0m1.249s

mboldt@mboldt-pivotal:~/Downloads/$ time credhub --version
CLI Version: 
Server Version: 2.3.0

real    0m0.827s
user    0m0.154s
sys 0m0.047s

The only changes I see is the golang version and perhaps go module updates. I imagine just cutting a new release would fix whatever is going on.

FWIW, I'm on MacOS Catalina 10.15.3 on a MacBook Pro (Retina, 15-inch, Mid 2015).

cf-gitbot commented 4 years ago

We have created an issue in Pivotal Tracker to manage this:

https://www.pivotaltracker.com/story/show/171085072

The labels on this github issue will be updated when the story is started.

ankeesler commented 4 years ago

@mboldt fascinating. Thank you very much for reporting this.

I'm having trouble reproducing locally, but I'm not on your same version of Darwin (I'm on 10.14.6 Mojave):

ankeesler:credhub-deployments ankeesler$ time ./credhub --version
CLI Version: 2.6.2
Server Version: 2.5.6

real    0m2.405s
user    0m0.176s
sys     0m0.111s
ankeesler:credhub-deployments ankeesler$ shasum -a 256 credhub
aec46e513a99fdeadc8fcd1532194c2e85764e937e0a68f7f0373981b169ca2f  credhub

How would you feel about using go tool pprof to send us a SVG call trace so we could potentially see where the bottleneck is visually? Judging by the time output, I would assume we are hanging somewhere.

mboldt commented 4 years ago

@ankeesler Yes, it is strange.

I don't believe I can profile, because if I recompile the issue goes away. I also discovered that if I sudo it goes away.

I fired it up an a debugger, and Ctrl-Ced it after several seconds and viewed a backtrace. Here's the output, suggesting it's taking its sweet time with certificates:

mboldt@mboldt-pivotal:~/Downloads/$  lldb ./credhub
(lldb) target create "./credhub"
Current executable set to './credhub' (x86_64).
(lldb) run --version
Process 91093 launched: '/Users/mboldt/Downloads/credhub' (x86_64)
CLI Version: 2.6.2
Process 91093 stopped
* thread #1, stop reason = signal SIGSTOP
    frame #0: 0x00007fff65ecd58e
->  0x7fff65ecd58e: jae    0x7fff65ecd598
    0x7fff65ecd590: movq   %rax, %rdi
    0x7fff65ecd593: jmp    0x7fff65ec4a89
    0x7fff65ecd598: retq   
Target 0: (credhub) stopped.
(lldb) bt
* thread #1, stop reason = signal SIGSTOP
  * frame #0: 0x00007fff65ecd58e
    frame #1: 0x0000000001058b00 credhub`runtime.asmcgocall + 112
    frame #2: 0x0000000001049e21 credhub`syscall.syscall6 + 81
    frame #3: 0x00000000010a5967 credhub`syscall.wait4 + 135
    frame #4: 0x00000000010a2921 credhub`syscall.Wait4 + 81
    frame #5: 0x00000000010c55db credhub`os.(*Process).wait + 123
    frame #6: 0x0000000001193f90 credhub`os/exec.(*Cmd).Wait + 96
    frame #7: 0x000000000119342c credhub`os/exec.(*Cmd).Run + 92
    frame #8: 0x00000000011f6550 credhub`crypto/x509.verifyCertWithSystem + 1152
    frame #9: 0x0000000001203d80 credhub`crypto/x509.execSecurityRoots.func1 + 672
    frame #10: 0x00000000010591e1 credhub`runtime.goexit + 1
    frame #11: 0x00000000010a5967 credhub`syscall.wait4 + 135
    frame #12: 0x00000000010a2921 credhub`syscall.Wait4 + 81
    frame #13: 0x00000000010c55db credhub`os.(*Process).wait + 123
    frame #14: 0x0000000001193f90 credhub`os/exec.(*Cmd).Wait + 96
    frame #15: 0x000000000119342c credhub`os/exec.(*Cmd).Run + 92
    frame #16: 0x00000000011f6550 credhub`crypto/x509.verifyCertWithSystem + 1152
    frame #17: 0x0000000001203d80 credhub`crypto/x509.execSecurityRoots.func1 + 672
    frame #18: 0x00000000010591e1 credhub`runtime.goexit + 1
    frame #19: 0x00000000010a2921 credhub`syscall.Wait4 + 81
    frame #20: 0x00000000010c55db credhub`os.(*Process).wait + 123
    frame #21: 0x0000000001193f90 credhub`os/exec.(*Cmd).Wait + 96
    frame #22: 0x000000000119342c credhub`os/exec.(*Cmd).Run + 92
    frame #23: 0x00000000011f6550 credhub`crypto/x509.verifyCertWithSystem + 1152
    frame #24: 0x0000000001203d80 credhub`crypto/x509.execSecurityRoots.func1 + 672
    frame #25: 0x00000000010591e1 credhub`runtime.goexit + 1
    frame #26: 0x00000000010c55db credhub`os.(*Process).wait + 123
    frame #27: 0x0000000001193f90 credhub`os/exec.(*Cmd).Wait + 96
    frame #28: 0x000000000119342c credhub`os/exec.(*Cmd).Run + 92
    frame #29: 0x00000000011f6550 credhub`crypto/x509.verifyCertWithSystem + 1152
    frame #30: 0x0000000001203d80 credhub`crypto/x509.execSecurityRoots.func1 + 672
    frame #31: 0x00000000010591e1 credhub`runtime.goexit + 1
    frame #32: 0x0000000001193f90 credhub`os/exec.(*Cmd).Wait + 96
    frame #33: 0x000000000119342c credhub`os/exec.(*Cmd).Run + 92
    frame #34: 0x00000000011f6550 credhub`crypto/x509.verifyCertWithSystem + 1152
    frame #35: 0x0000000001203d80 credhub`crypto/x509.execSecurityRoots.func1 + 672
    frame #36: 0x00000000010591e1 credhub`runtime.goexit + 1
    frame #37: 0x000000000119342c credhub`os/exec.(*Cmd).Run + 92
    frame #38: 0x00000000011f6550 credhub`crypto/x509.verifyCertWithSystem + 1152
    frame #39: 0x0000000001203d80 credhub`crypto/x509.execSecurityRoots.func1 + 672
    frame #40: 0x00000000010591e1 credhub`runtime.goexit + 1
    frame #41: 0x00000000011f6550 credhub`crypto/x509.verifyCertWithSystem + 1152
    frame #42: 0x0000000001203d80 credhub`crypto/x509.execSecurityRoots.func1 + 672
    frame #43: 0x00000000010591e1 credhub`runtime.goexit + 1
    frame #44: 0x0000000001203d80 credhub`crypto/x509.execSecurityRoots.func1 + 672
    frame #45: 0x00000000010591e1 credhub`runtime.goexit + 1
    frame #46: 0x00000000010591e1 credhub`runtime.goexit + 1
mboldt commented 4 years ago

Guessing it's getting stuck here: https://github.com/golang/go/blob/3eab754cd061bf90ee7b540546bc0863f3ad1d85/src/crypto/x509/root_darwin.go#L201

When I get some time, I'll try to see if the /usr/bin/security command takes a long time on its own.

ankeesler commented 4 years ago

Wow, I love these kinds of bugs.

Per some poking around online, it looks like this is an Apple issue and other people are running into it.

Are you running into this issue on other machines? Do you have a ton of stuff in your keychain? I would be interested if you do get time to profile /usr/bin/security. Fascinating.

mboldt commented 4 years ago

I haven't seen any other machines that hit it. Tried with the GODEBUG flag in the golang source I linked above and the issue you linked, and looks like I have 75 certs per the output below. Eyeballing the output as it comes out, there is a noticeable (but short) delay between each verify-cert line, so probably the cause.

CLI Version: 2.6.2
crypto/x509: 41 certs have a trust policy
crypto/x509: verify-cert approved CN=Pivotal Labs JSS Built-in Certificate Authority
crypto/x509: verify-cert approved CN=Pivotal Root CA,OU=Root Certificate Authority,O=Pivotal,L=San Francisco,ST=CA,C=US
crypto/x509: verify-cert approved CN=PivotalManagementCA,O=Pivotal Software,C=US
crypto/x509: verify-cert approved CN=Pivotal PEZ Compat CA
crypto/x509: verify-cert approved CN=Pivotal Software Root Certification Authority
crypto/x509: verify-cert rejected CN=dlv-cert: "Cert Verify Result: Invalid Extended Key Usage for policy"
crypto/x509: verify-cert approved CN=Pivotal Root CA,OU=IOPS,O=Pivotal Software Inc.,C=US
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=concourse.cfplatformeng.com,O=Cloud Foundry,C=USA: "Cert Verify Result: CSSMERR_TP_CERT_EXPIRED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_CERT_EXPIRED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=*.cfapps.io: "Cert Verify Result: CSSMERR_TP_CERT_EXPIRED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=pcf-east-router.east.paas.nga.mil,OU=DoD+OU=PKI+OU=NGA,O=U.S.Government,C=US: "Cert Verify Result: CSSMERR_TP_CERT_EXPIRED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=*.system.52.170.194.60.cf.pcfazure.com,O=Pivotal,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert approved CN=*.orangecove.cf-app.com,O=Pivotal,C=US
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=concourse.cfplatformeng.com,O=Cloud Foundry,C=USA: "Cert Verify Result: CSSMERR_TP_CERT_EXPIRED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_CERT_EXPIRED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=*.cfapps.io: "Cert Verify Result: CSSMERR_TP_CERT_EXPIRED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=pcf-east-router.east.paas.nga.mil,OU=DoD+OU=PKI+OU=NGA,O=U.S.Government,C=US: "Cert Verify Result: CSSMERR_TP_CERT_EXPIRED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=*.system.52.170.194.60.cf.pcfazure.com,O=Pivotal,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert rejected CN=Tempest,OU=CloudFoundry,O=Pivotal Inc.,L=San Francisco,ST=California,C=US: "Cert Verify Result: CSSMERR_TP_NOT_TRUSTED"
crypto/x509: verify-cert approved CN=*.orangecove.cf-app.com,O=Pivotal,C=US
crypto/x509: ran security verify-cert 75 times
Server Version: 2.3.0

Running the same thing on my newly-compiled CLI (which runs fast, per time in original issue). The crypto/x509 lines come out instantaneously.

mboldt@mboldt-pivotal:~/Downloads/$ GODEBUG=x509roots=1 credhub --version
CLI Version: 
crypto/x509: kSecTrustSettingsResultInvalid = 0
crypto/x509: kSecTrustSettingsResultTrustRoot = 1
crypto/x509: kSecTrustSettingsResultTrustAsRoot = 2
crypto/x509: kSecTrustSettingsResultDeny = 3
crypto/x509: kSecTrustSettingsResultUnspecified = 4
crypto/x509: Pivotal Labs JSS Built-in Certificate Authority returned 1
crypto/x509: Pivotal Root CA returned 1
crypto/x509: PivotalManagementCA returned 1
crypto/x509: Pivotal PEZ Compat CA returned 1
crypto/x509: Pivotal Software Root Certification Authority returned 1
crypto/x509: dlv-cert returned 1
crypto/x509: Pivotal Root CA returned 1
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: concourse.cfplatformeng.com returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: *.cfapps.io returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: pcf-east-router.east.paas.nga.mil returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: *.system.52.170.194.60.cf.pcfazure.com returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: Tempest returned 4
crypto/x509: *.orangecove.cf-app.com returned 2
Server Version: 2.3.0
mboldt commented 4 years ago

Sure, enough, deleted all the random Ops Manager Tempest certs, and now it runs fine:

mboldt@mboldt-pivotal:~/Downloads/$ time ./credhub --version
CLI Version: 2.6.2
Server Version: 2.3.0

real    0m1.153s
user    0m0.200s
sys 0m0.296s

I think what had happened was I used Safari for a while, and when I accepted the self-signed certs it must have added them to my keychain.