ory / kratos

The most scalable and customizable identity server on the market. Replace your Homegrown, Auth0, Okta, Firebase with better UX and DX. Has all the tablestakes: Passkeys, Social Sign In, Multi-Factor Auth, SMS, SAML, TOTP, and more. Written in Go, cloud native, headless, API-first. Available as a service on Ory Network and for self-hosters.
https://www.ory.sh/?utm_source=github&utm_medium=banner&utm_campaign=kratos
Apache License 2.0
11.2k stars 959 forks source link

Unable to send verification SMS on registration flow when set custom http port #4099

Closed eyoboue closed 1 month ago

eyoboue commented 1 month ago

Preflight checklist

Ory Network Project

No response

Describe the bug

I configured phone & password registration flow with SMS verification MFA on custom HTTPS SMS gateway. When submitted registration, It's unable to send SMS after max attempts reached. Hint: My SMS gateway has custom port for instance 9443. I get success sms sending when I tried on other endpoints with default https port. But I get failed with custom https ports like 8843, etc.

Reproducing the bug

  1. Run on docker compose
  2. Init password registration flow

Relevant log output

2024-09-13T19:56:12.813255688Z DBG audience=application file=/project/selfservice/flow/registration/hook.go:226 flow_method=password func=github.com/ory/kratos/selfservice/flow/registration.(*HookExecutor).PostRegistrationHook http_request={"headers":{"accept":"*/*","accept-encoding":"gzip, deflate, br","content-length":"99","content-type":"application/json","postman-token":"52fc1fa1-c123-48b8-969e-96d3f3383c8b","user-agent":"PostmanRuntime/7.42.0","x-forwarded-for":"10.0.0.2","x-forwarded-host":"id-service.my-custom-domain.com:9943","x-forwarded-port":"9943","x-forwarded-proto":"https","x-forwarded-server":"57a9ebf92fbf","x-real-ip":"10.0.0.2"},"host":"id-service.my-custom-domain.com:9943","method":"POST","path":"/self-service/registration","query":"flow=44f3e81f-b7f6-42f3-99fc-1fd974a1f282","remote":"10.0.1.3:43090","scheme":"http"} identity_id=4678c09f-782f-441a-ae7b-05a4f3751059 msg=Running PostRegistrationPostPersistHooks. service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:56:12.818565493Z INF audience=audit email_address=+2250100000000 file=/project/selfservice/strategy/code/code_sender.go:350 func=github.com/ory/kratos/selfservice/strategy/code.(*Sender).SendVerificationCodeTo identity_id=4678c09f-782f-441a-ae7b-05a4f3751059 msg=Sending out verification email with verification code. service_name=Ory Kratos service_version=v1.2.0 verification_code_id=33077005-2545-457c-b7e3-0fdc97f3f6d7 verification_link_token=616754 via=sms
2024-09-13T19:56:12.826987094Z DBG audience=application executor=*hook.Verifier executor_position=0 executors=["*hook.Verifier","*hook.SessionIssuer"] file=/project/selfservice/flow/registration/hook.go:266 flow_method=password func=github.com/ory/kratos/selfservice/flow/registration.(*HookExecutor).PostRegistrationHook http_request={"headers":{"accept":"*/*","accept-encoding":"gzip, deflate, br","content-length":"99","content-type":"application/json","postman-token":"52fc1fa1-c123-48b8-969e-96d3f3383c8b","user-agent":"PostmanRuntime/7.42.0","x-forwarded-for":"10.0.0.2","x-forwarded-host":"id-service.my-custom-domain.com:9943","x-forwarded-port":"9943","x-forwarded-proto":"https","x-forwarded-server":"57a9ebf92fbf","x-real-ip":"10.0.0.2"},"host":"id-service.my-custom-domain.com:9943","method":"POST","path":"/self-service/registration","query":"flow=44f3e81f-b7f6-42f3-99fc-1fd974a1f282","remote":"10.0.1.3:43090","scheme":"http"} identity_id=4678c09f-782f-441a-ae7b-05a4f3751059 msg=ExecutePostRegistrationPostPersistHook completed successfully. service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:56:12.827893246Z DBG audience=application executor=*hook.SessionIssuer executor_position=1 executors=["*hook.Verifier","*hook.SessionIssuer"] file=/project/selfservice/flow/registration/hook.go:237 flow_method=password func=github.com/ory/kratos/selfservice/flow/registration.(*HookExecutor).PostRegistrationHook http_request={"headers":{"accept":"*/*","accept-encoding":"gzip, deflate, br","content-length":"99","content-type":"application/json","postman-token":"52fc1fa1-c123-48b8-969e-96d3f3383c8b","user-agent":"PostmanRuntime/7.42.0","x-forwarded-for":"10.0.0.2","x-forwarded-host":"id-service.my-custom-domain.com:9943","x-forwarded-port":"9943","x-forwarded-proto":"https","x-forwarded-server":"57a9ebf92fbf","x-real-ip":"10.0.0.2"},"host":"id-service.my-custom-domain.com:9943","method":"POST","path":"/self-service/registration","query":"flow=44f3e81f-b7f6-42f3-99fc-1fd974a1f282","remote":"10.0.1.3:43090","scheme":"http"} identity_id=4678c09f-782f-441a-ae7b-05a4f3751059 msg=A ExecutePostRegistrationPostPersistHook hook aborted early. service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:56:12.828231553Z INF file=/go/pkg/mod/github.com/ory/x@v0.0.623/reqlog/middleware.go:146 func=github.com/ory/x/reqlog.(*Middleware).ServeHTTP http_request={"headers":{"accept":"*/*","accept-encoding":"gzip, deflate, br","content-length":"99","content-type":"application/json","postman-token":"52fc1fa1-c123-48b8-969e-96d3f3383c8b","user-agent":"PostmanRuntime/7.42.0","x-forwarded-for":"10.0.0.2","x-forwarded-host":"id-service.my-custom-domain.com:9943","x-forwarded-port":"9943","x-forwarded-proto":"https","x-forwarded-server":"57a9ebf92fbf","x-real-ip":"10.0.0.2"},"host":"id-service.my-custom-domain.com:9943","method":"POST","path":"/self-service/registration","query":"flow=44f3e81f-b7f6-42f3-99fc-1fd974a1f282","remote":"10.0.1.3:43090","scheme":"http"} http_response={"headers":{"cache-control":"private, no-cache, no-store, must-revalidate","content-type":"application/json; charset=utf-8","vary":"Origin"},"size":2037,"status":200,"text_status":"OK","took":360509206} msg=completed handling request
2024-09-13T19:56:13.156846296Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[DEBUG] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:56:43.174737516Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[ERR] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms request failed: Post "https://sms-gateway.my-custom-domain.com:9943/api/send-sms": context deadline exceeded (Client.Timeout exceeded while awaiting headers) service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:56:43.187090903Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[DEBUG] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms: retrying in 1s (2 left) service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:57:14.205058365Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[ERR] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms request failed: Post "https://sms-gateway.my-custom-domain.com:9943/api/send-sms": dial tcp 10.0.0.0:9943: i/o timeout (Client.Timeout exceeded while awaiting headers) service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:57:14.213209462Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[DEBUG] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms: retrying in 2s (1 left) service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:57:46.22363921Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[ERR] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms request failed: Post "https://sms-gateway.my-custom-domain.com:9943/api/send-sms": context deadline exceeded (Client.Timeout exceeded while awaiting headers) service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:57:47.321883171Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[DEBUG] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:58:17.330555907Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[ERR] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms request failed: Post "https://sms-gateway.my-custom-domain.com:9943/api/send-sms": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers) service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:58:17.336882569Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[DEBUG] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms: retrying in 1s (2 left) service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:58:48.346367465Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[ERR] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms request failed: Post "https://sms-gateway.my-custom-domain.com:9943/api/send-sms": context deadline exceeded (Client.Timeout exceeded while awaiting headers) service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:58:48.355564875Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[DEBUG] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms: retrying in 2s (1 left) service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:59:20.365019606Z INF audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf msg=[ERR] POST https://sms-gateway.my-custom-domain.com:9943/api/send-sms request failed: Post "https://sms-gateway.my-custom-domain.com:9943/api/send-sms": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers) service_name=Ory Kratos service_version=v1.2.0
2024-09-13T19:59:21.43234645Z warning audience=application file=/go/pkg/mod/github.com/ory/x@v0.0.623/logrusx/helper.go:125 func=github.com/ory/x/logrusx.(*Logger).Logf message_id=505f87be-3950-4f76-8392-9a378e66f988 message_nid=dbedfc41-a116-4d23-a87b-6568659f67b3 message_subject= message_template_type=verification_code_valid message_type=sms msg=Message was abandoned because it did not deliver after 2 attempts service_name=Ory Kratos service_version=v1.2.0

Relevant configuration

selfservice:
  methods:
    code:
      enabled: true
      mfa_enabled: true
    password:
      config:
        min_password_length: 6
        haveibeenpwned_enabled: false
      enabled: true
    verification:
      enabled: true
      use: code
courier:
  channels:
    - id: sms
      type: http
      request_config:
        url: https://sms-gateway.my-custom-domain.com:9943/api/send-sms
        method: POST
        body: base64://xxx=
        headers:
          'Content-Type': 'application/json'
        auth:
          type: basic_auth
          config:
            user: username
            password: mypassword

Version

v1.2.0

On which operating system are you observing this issue?

Linux

In which environment are you deploying?

Docker Compose

Additional Context

No response

aeneasr commented 1 month ago

The timeout looks like an issue on your end and not ours - especially if it works on another port! Closing as we don’t believe this is an issue in our code (according to the logs) but feel free to object if you find evidence to the contrary.

eyoboue commented 1 month ago

The timeout looks like an issue on your end and not ours - especially if it works on another port! Closing as we don’t believe this is an issue in our code (according to the logs) but feel free to object if you find evidence to the contrary.

@aeneasr, I think you should take a look. It works only with https default port (443). My sms gateway works fine and I have not timeout when make request with Postman or from other deployed services. So I tried Ory Kratos SMS sending on other services which have custom ports other than 443 and it doesn't work (same timeout issue). I'm unable to explain why that happened.

Many companies have own SMS gateway exposed on custom https port and I think that's real issue.

aeneasr commented 1 month ago

It‘s probably a firewall issue. If it works with one port it works with all ports, we don’t discriminate on ports ;) Also, we‘re using random ports in our tests.

eyoboue commented 1 month ago

Thanks, you are probably right.

But I disable all firewall and the issue still persists.

I have another service (write with Golang) in the same docker-compose file, deployed on same stack and It's able to send successful SMS where the Kratos service fails.

I will use another SMS gateway exposed on 443 https port for now and I will keep looking.