Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[Bug]: cloudKMS connects to IPs and fails #2001

Open
GBBx opened this issue Sep 16, 2024 · 6 comments
Open

[Bug]: cloudKMS connects to IPs and fails #2001

GBBx opened this issue Sep 16, 2024 · 6 comments
Assignees
@hslatman
Labels
bug needs triage Waiting for discussion / prioritization by team

Comments

@GBBx
Copy link

GBBx commented Sep 16, 2024

Steps to Reproduce

  1. start step-ca
step-ca ...ca.json --password-file ...password
  1. get error message
context deadline exceeded
cloudKMS GetPublicKey failed
go.step.sm/crypto/kms/cloudkms.(*Signer).preloadKey
        go.step.sm/[email protected]/kms/cloudkms/signer.go:46
go.step.sm/crypto/kms/cloudkms.NewSigner
        go.step.sm/[email protected]/kms/cloudkms/signer.go:31
go.step.sm/crypto/kms/cloudkms.(*CloudKMS).CreateSigner
        go.step.sm/[email protected]/kms/cloudkms/cloudkms.go:162
github.com/smallstep/certificates/authority.(*instrumentedKeyManager).CreateSigner
        github.com/smallstep/certificates/authority/meter.go:86
github.com/smallstep/certificates/authority.(*Authority).init
        github.com/smallstep/certificates/authority/authority.go:426
github.com/smallstep/certificates/authority.New
        github.com/smallstep/certificates/authority/authority.go:149
github.com/smallstep/certificates/ca.(*CA).Init
        github.com/smallstep/certificates/ca/ca.go:200
github.com/smallstep/certificates/ca.New
        github.com/smallstep/certificates/ca/ca.go:162
github.com/smallstep/certificates/commands.appAction
        github.com/smallstep/certificates/commands/app.go:254
github.com/urfave/cli.HandleAction
        github.com/urfave/[email protected]/app.go:524
github.com/urfave/cli.Command.Run
        github.com/urfave/[email protected]/command.go:175
main.main.func3
        ./main.go:202
github.com/urfave/cli.HandleAction
        github.com/urfave/[email protected]/app.go:524
github.com/urfave/cli.(*App).Run
        github.com/urfave/[email protected]/app.go:286
main.main
        ./main.go:205
runtime.main
        runtime/proc.go:272
runtime.goexit
        runtime/asm_amd64.s:1700

Your Environment

  • OS - Linux
  • step-ca Version - 0.27.4

Expected Behavior

step-ca should start

Actual Behavior

step-ca crashes

Additional Context

I use a corporate proxy. Step-ca runs as a systemd service and the HTTPS_PROXY variable is set in the unit file.
On the proxy, the necessary KMS URLs are whitelisted, e.g. cloudkms.googleapis.com.

Since an update from 0.27.2 to 0.27.4 I see in the proxy logs that step-ca is trying to connect to IPs instead of the URL. I.e. if I do nslookup cloudkms.googleapis.com - these are the IPs I see in the proxy logs.

Contributing

Vote on this issue by adding a 👍 reaction.
To contribute a fix for this issue, leave a comment (and link to your pull request, if you've opened one already).
@GBBx GBBx added bug needs triage Waiting for discussion / prioritization by team labels Sep 16, 2024
@GBBx
Copy link
Author

GBBx commented Sep 16, 2024 •
edited
Loading

My kms plugin was also updated from 0.11.4 to 0.11.5 at the same time as step-ca.

Edit: kms plugin 0.11.5 with step-ca 0.27.2 works.

@hslatman hslatman self-assigned this Sep 17, 2024
@hslatman
Copy link
Member

Hey @GBBx, thank you for opening the issue.

Do you have example logs of your proxy? Based on some quick triage our verdict was that we didn't change code related to handling HTTP with or without proxies directly, at least not knowingly. It's possible that a dependency upgrade in a lower level has changed the behavior, though.

I did a quick test with both the CA as well as the KMS plugin, but I didn't hit your problem. Note that the KMS plugin isn't used by the CA, but it does use shared code from our crypto package for communicating with GCP Cloud KMS, so they should behave fairly similar.

Is it possible your usage of the KMS plugin doesn't go through the proxy? Are you executing the CA and the KMS from the same machine, using the same user and the same GCP credentials?

@GBBx
Copy link
Author

GBBx commented Sep 17, 2024

Hi @hslatman,

thanks for your questions.

Do you have example logs of your proxy?

Yes. Here's what I see on the proxy using step-ca 0.27.2 - a single line when step-ca is started:

1726603815.040 118996 X.X.X.X TCP_TUNNEL/200 5831 CONNECT cloudkms.googleapis.com:443 - HIER_DIRECT/216.58.212.138 -

And here's what I get with step-ca 0.27.4:

...
1726603992.985    390 X.X.X.X TCP_DENIED/403 3877 CONNECT 142.250.186.74:443 - HIER_NONE/- text/html
1726603993.149    162 X.X.X.X TCP_DENIED/403 3877 CONNECT 172.217.18.106:443 - HIER_NONE/- text/html
1726603993.232     82 X.X.X.X TCP_DENIED/403 3877 CONNECT 142.250.185.74:443 - HIER_NONE/- text/html
1726603993.272     39 X.X.X.X TCP_DENIED/403 3880 CONNECT 142.250.185.106:443 - HIER_NONE/- text/html
1726603993.347     74 X.X.X.X TCP_DENIED/403 3880 CONNECT 142.250.185.138:443 - HIER_NONE/- text/html
1726603993.393     44 X.X.X.X TCP_DENIED/403 3880 CONNECT 142.250.185.170:443 - HIER_NONE/- text/html
1726603995.330   1936 X.X.X.X TCP_DENIED/403 3874 CONNECT 216.58.206.42:443 - HIER_NONE/- text/html
...

Is it possible your usage of the KMS plugin doesn't go through the proxy? Are you executing the CA and the KMS from the same machine, using the same user and the same GCP credentials?

It definitely goes through the proxy. I cannot connect to GCP if it is not through the proxy.
I think I have a quite simple setup: step-ca and the kms plugin installed on the same machine, there's only one service account in use. I just followed https://smallstep.com/docs/step-ca/cryptographic-protection/#google-cloud-kms step by step and didn't add anything. Note, the same setup works if I downgrade to 0.27.2.

@hslatman
Copy link
Member

hslatman commented Sep 17, 2024 •
edited
Loading

Can you run the CA and KMS with GODEBUG=http2debug=2 set?

E.g. for KMS: GODEBUG=http2debug=2 step kms key --kms cloudkms <key>

@GBBx
Copy link
Author

GBBx commented Sep 18, 2024

@hslatman

GODEBUG=http2debug=2 /usr/bin/step-ca /........ --password-file /.....
badger 2024/09/18 12:52:04 INFO: All 3 tables opened in 10ms
badger 2024/09/18 12:52:04 INFO: Replaying file id: 1 at offset: 336061984
badger 2024/09/18 12:52:04 INFO: Replay took: 332.121µs
cloudKMS GetPublicKey failed: context deadline exceeded

I guess the badger... lines are not relevant.

If I add STEPDEBUG=1 it says:

context deadline exceeded
cloudKMS GetPublicKey failed
go.step.sm/crypto/kms/cloudkms.(*Signer).preloadKey
        go.step.sm/[email protected]/kms/cloudkms/signer.go:46
go.step.sm/crypto/kms/cloudkms.NewSigner
        go.step.sm/[email protected]/kms/cloudkms/signer.go:31
go.step.sm/crypto/kms/cloudkms.(*CloudKMS).CreateSigner
        go.step.sm/[email protected]/kms/cloudkms/cloudkms.go:162
github.com/smallstep/certificates/authority.(*instrumentedKeyManager).CreateSigner
        github.com/smallstep/certificates/authority/meter.go:86
github.com/smallstep/certificates/authority.(*Authority).init
        github.com/smallstep/certificates/authority/authority.go:426
github.com/smallstep/certificates/authority.New
        github.com/smallstep/certificates/authority/authority.go:149
github.com/smallstep/certificates/ca.(*CA).Init
        github.com/smallstep/certificates/ca/ca.go:200
github.com/smallstep/certificates/ca.New
        github.com/smallstep/certificates/ca/ca.go:162
github.com/smallstep/certificates/commands.appAction
        github.com/smallstep/certificates/commands/app.go:254
github.com/urfave/cli.HandleAction
        github.com/urfave/[email protected]/app.go:524
github.com/urfave/cli.Command.Run
        github.com/urfave/[email protected]/command.go:175
main.main.func3
        ./main.go:202
github.com/urfave/cli.HandleAction
        github.com/urfave/[email protected]/app.go:524
github.com/urfave/cli.(*App).Run
        github.com/urfave/[email protected]/app.go:286
main.main
        ./main.go:205
runtime.main
        runtime/proc.go:272
runtime.goexit
        runtime/asm_amd64.s:1700

The KMS command works:

GODEBUG=http2debug=2 step kms key --kms cloudkms <key>
2024/09/18 12:03:25 http2: Framer 0x.........: wrote SETTINGS len=0
2024/09/18 12:03:25 http2: Framer 0x.........: read SETTINGS len=18, settings: MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=65536
2024/09/18 12:03:25 http2: Framer 0x.........: read WINDOW_UPDATE len=4 (conn) incr=983041
2024/09/18 12:03:25 http2: Framer 0x.........: wrote SETTINGS flags=ACK len=0
2024/09/18 12:03:25 http2: Framer 0x.........: read SETTINGS flags=ACK len=0
2024/09/18 12:03:25 http2: Framer 0x.........: wrote HEADERS flags=END_HEADERS stream=1 len=1038
2024/09/18 12:03:25 http2: Framer 0x.........: wrote DATA flags=END_STREAM stream=1 len=158 data=".........................."
2024/09/18 12:03:26 http2: Framer 0x.........: read HEADERS flags=END_HEADERS stream=1 len=126
2024/09/18 12:03:26 http2: decoded hpack field header field ":status" = "200"
2024/09/18 12:03:26 http2: decoded hpack field header field "content-type" = "application/grpc"
2024/09/18 12:03:26 http2: decoded hpack field header field "grpc-accept-encoding" = "identity, deflate, gzip"
2024/09/18 12:03:26 http2: decoded hpack field header field "content-disposition" = "attachment"
2024/09/18 12:03:26 http2: decoded hpack field header field "date" = "Wed, 18 Sep 2024 10:03:25 GMT"
2024/09/18 12:03:26 http2: decoded hpack field header field "alt-svc" = "h3=\":443\"; ma=2592000,h3-29=\":443\"; ma=2592000"
2024/09/18 12:03:26 http2: Framer 0x.........: read DATA stream=1 len=351 data="\x........-----BEGIN PUBLIC KEY-----......-----END PUBLIC KEY-----........." (95 bytes omitted)
2024/09/18 12:03:26 http2: Framer 0x.........: read HEADERS flags=END_STREAM|END_HEADERS stream=1 len=113
2024/09/18 12:03:26 http2: decoded hpack field header field "grpc-status" = "0"
2024/09/18 12:03:26 http2: decoded hpack field header field "endpoint-load-metrics-bin" = "..........."
2024/09/18 12:03:26 http2: decoded hpack field header field "grpc-server-stats-bin" = "..........."
2024/09/18 12:03:26 http2: decoded hpack field header field "pc-high-bwd-bin" = "................"
2024/09/18 12:03:26 http2: Framer 0x.........: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x021"
2024/09/18 12:03:26 http2: Framer 0x.........: wrote WINDOW_UPDATE len=4 (conn) incr=351
2024/09/18 12:03:26 http2: Framer 0x.........: wrote PING len=8 ping="\x.........."
2024/09/18 12:03:26 http2: Framer 0x.........: wrote PING flags=ACK len=8 ping="\x........"
2024/09/18 12:03:26 http2: Framer 0x.........: wrote GOAWAY len=33 LastStreamID=1 ErrCode=NO_ERROR Debug="client transport shutdown"
-----BEGIN PUBLIC KEY-----
.............
.............
-----END PUBLIC KEY-----

@GBBx
Copy link
Author

GBBx commented Oct 22, 2024

The issue persists with Step CA 0.27.5.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@hslatman hslatman

Labels
bug needs triage Waiting for discussion / prioritization by team
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@hslatman @GBBx