client-sdk-flutter icon indicating copy to clipboard operation
client-sdk-flutter copied to clipboard

"ConnectException Failed to connect to server" ONLY on iOS with 4G/5G

Open rokk4 opened this issue 2 years ago • 3 comments

First I want to thank you for the dev expierence with livekit, it is really awesome. This project is going to huge. :)

My issue is, It just won't connect on iOS with celluar, works fine in every other scenario.

Very strange is that, there is a small chance for it to work, but only after a fresh start of the app. But this happend only 2 or 3 times out of 50-60 trails.

At first I thought that it was an issue withe the celluar provider (telekom) doing IPv6 only, but changing to regular dual-stack did not solve the issue, and also everything was fine when the IPv6 only uplink was used by other devices via hotspot.

Versions: flutter_client 0.5.9 iOS 15.4.1

What did I test:

LiveKit Connection Test is fine on all devices under all circumstances.

React Example App in Safari on the iPhone with 4G/5G connection ---> OK React Example App in Safari on the iPhone with Wifi ---- OK

Flutter Example App on Android Mi A2 with Wifi but from the 4G/5G iPhone hotspot --> OK Flutter Example App on Android Mi A2 Wifi --> OK Flutter Example App on MacOS with Wifi or Ethernet -> OK Flutter Example App on MacOS with Wifi but from the 4G/5G iPhone hotspot -> OK

Flutter Example App on iPhone with Wifi --> OK Flutter Example App on iPhone with Wifi but 4G uplink from another Androids phone hotspot --> OK Flutter Example App on iPhone with 4G/5G --> ConnectException Failed to connect to server :(

Steps to reproduce: use example app on iphone with 4G/5G server URLwss://live. txxhexxraxxpy-lxxixxft.net (without the xxs because SEO ...) token: eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJleHAiOjE2NTQ3ODY4NTAsImlzcyI6IkFQSWFlb0JFeENOdG5CUyIsIm5iZiI6MTY1MjE5NDg1MCwic3ViIjoic2wiLCJ2aWRlbyI6eyJyb29tIjoidGVzdDAxIiwicm9vbUpvaW4iOnRydWV9fQ.7m6xVj3UFXIZfAucgqLjziZEefuX8ZLmgAMPYnEAWVE

I have attached server and flutter logs, for success and failure cases. flutter_FAIL.txt flutter_SUCCESS.txt server_FAIL.txt server_SUCCESS.txt

rokk4 avatar May 11 '22 20:05 rokk4

@rokk4 thank you for the detailed bug report. which version of the server are you running? Do you have a TURN server set up as well?

davidzhao avatar May 16 '22 05:05 davidzhao

@davidzhao thanks for the reply. :)

LiveKit-Server Version is 0.15.7. Yes, it is using the integrated TURN server.

What I find especially strange is, that the React Example App is working perfectly, so I have the feeling that this is not a issue coming from the server, but something in the the native iOS part of the client.

rokk4 avatar May 16 '22 06:05 rokk4

I am seeing the same when I am connecting via flutter client on 4G as well as wifi on Android. The server says

2022-07-20T07:14:00.600Z ERROR livekit.turn [email protected]/server.go:184error when handling datagram: failed to handle Allocate-request from 152.57.213.227:44386: integrity check failed github.com/pion/turn/v2.(*Server).readLoop /go/pkg/mod/github.com/pion/turn/[email protected]/server.go:184 github.com/pion/turn/v2.NewServer.func1 /go/pkg/mod/github.com/pion/turn/[email protected]/server.go:85

And yes, the react app works good and also the mobile apps work good too but I am seeing this frequently on mobile connection. It just doesn't connect

vishal-android-freak avatar Jul 20 '22 07:07 vishal-android-freak

The issue is still there in Server Version 1.2.5 and flutter-client-sdk Version 1.1.7

Now I have seen the following in the logs. caddy_1 | {"level":"error","ts":1666775017.8042235,"logger":"layer4","msg":"handling connection","error":"remote error: tls: unknown certificate authority"} during the iOS Mobile connection scenario.

Also this looks interesting:

livekit_1  | 2022-10-26T09:04:26.997Z   INFO    livekit rtc/participant.go:521  participant closing     {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "sendLeave": true, "reason": "PEER_CONNECTION_DISCONNECTED"}
livekit_1  | 2022-10-26T09:04:26.997Z   INFO    livekit rtc/participant_signal.go:180   could not send message to participant   {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "message": "*livekit.SignalResponse_Leave", "error": "no response sink"}
livekit_1  | 2022-10-26T09:04:26.998Z   DEBUG   livekit rtc/participant.go:1091 updating participant state      {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "state": "DISCONNECTED"}
livekit_1  | 2022-10-26T09:04:26.999Z   DEBUG   livekit rtc/room.go:246 participant state changed       {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "state": "DISCONNECTED", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "oldState": "JOINED"}
livekit_1  | 2022-10-26T09:04:26.999Z   INFO    livekit rtc/room.go:403 closing participant for removal {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "pID": "PA_SPA9S9V6sHUK", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc"}
livekit_1  | 2022-10-26T09:04:26.999Z   INFO    livekit rtc/participant.go:521  participant closing     {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "sendLeave": true, "reason": "STATE_DISCONNECTED"}
livekit_1  | 2022-10-26T09:04:27.000Z   DEBUG   livekit rtc/transport.go:1203   leaving events processor        {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER"}
livekit_1  | 2022-10-26T09:04:27.000Z   INFO    livekit.ice     [email protected]/agent.go:562 Setting new connection state: Closed    {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER"}
livekit_1  | 2022-10-26T09:04:27.000Z   INFO    livekit rtc/transport.go:438    ice gathering state change      {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER", "state": "closed"}
livekit_1  | 2022-10-26T09:04:27.000Z   INFO    livekit.pc      [email protected]/peerconnection.go:490        peer connection state changed: closed   {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER"}
livekit_1  | 2022-10-26T09:04:27.000Z   INFO    livekit.pc      [email protected]/peerconnection.go:476        ICE connection state changed: closed    {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER"}
livekit_1  | 2022-10-26T09:04:27.000Z   INFO    livekit rtc/transport.go:472    ice connection state change     {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER", "state": "closed"}
livekit_1  | 2022-10-26T09:04:27.000Z   INFO    livekit.pc      [email protected]/peerconnection.go:2223       Failed to start manager: connecting canceled by caller  {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER"}
livekit_1  | 2022-10-26T09:04:27.001Z   INFO    livekit.pc      [email protected]/peerconnection.go:1456       Failed to start SCTP: DTLS not established      {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER"}
livekit_1  | 2022-10-26T09:04:27.001Z   INFO    livekit.pc      [email protected]/peerconnection.go:1653       undeclaredMediaProcessor failed to open SrtcpSession: the DTLS transport has not started yet    {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER"}
livekit_1  | 2022-10-26T09:04:27.001Z   INFO    livekit rtc/transport.go:485    peer connection state change    {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER", "state": "closed"}
livekit_1  | 2022-10-26T09:04:27.001Z   DEBUG   livekit rtc/transport.go:1203   leaving events processor        {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER"}
livekit_1  | 2022-10-26T09:04:27.001Z   INFO    livekit.ice     [email protected]/agent.go:562 Setting new connection state: Closed    {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER"}
livekit_1  | 2022-10-26T09:04:27.001Z   INFO    livekit rtc/transport.go:438    ice gathering state change      {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER", "state": "closed"}
livekit_1  | 2022-10-26T09:04:27.001Z   INFO    livekit.pc      [email protected]/peerconnection.go:490        peer connection state changed: closed   {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER"}
livekit_1  | 2022-10-26T09:04:27.001Z   INFO    livekit rtc/transport.go:485    peer connection state change    {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER", "state": "closed"}
livekit_1  | 2022-10-26T09:04:27.002Z   INFO    livekit.pc      [email protected]/peerconnection.go:1615       undeclaredMediaProcessor failed to open SrtpSession: the DTLS transport has not started yet     {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "PUBLISHER"}
livekit_1  | 2022-10-26T09:04:27.002Z   INFO    livekit.pc      [email protected]/peerconnection.go:476        ICE connection state changed: closed    {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER"}
livekit_1  | 2022-10-26T09:04:27.002Z   INFO    livekit rtc/transport.go:472    ice connection state change     {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER", "state": "closed"}
livekit_1  | 2022-10-26T09:04:27.002Z   INFO    livekit.pc      [email protected]/peerconnection.go:2223       Failed to start manager: connecting canceled by caller  {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER"}
livekit_1  | 2022-10-26T09:04:27.002Z   INFO    livekit.pc      [email protected]/peerconnection.go:1456       Failed to start SCTP: DTLS not established      {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER"}
livekit_1  | 2022-10-26T09:04:27.002Z   INFO    livekit.pc      [email protected]/peerconnection.go:1653       undeclaredMediaProcessor failed to open SrtcpSession: the DTLS transport has not started yet    {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER"}
livekit_1  | 2022-10-26T09:04:27.002Z   INFO    livekit.pc      [email protected]/peerconnection.go:1615       undeclaredMediaProcessor failed to open SrtpSession: the DTLS transport has not started yet     {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH", "participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "remote": false, "transport": "SUBSCRIBER"}
livekit_1  | 2022-10-26T09:04:27.046Z   INFO    livekit service/roommanager.go:437      RTC session finishing   {"participant": "3e53752e-16d1-4434-9afb-69327a5175cc", "pID": "PA_SPA9S9V6sHUK", "room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH"}
livekit_1  | 2022-10-26T09:04:55.644Z   INFO    livekit rtc/room.go:556 closing room    {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH"}
livekit_1  | 2022-10-26T09:04:55.644Z   INFO    livekit service/roommanager.go:110      deleting room state     {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc"}
livekit_1  | 2022-10-26T09:04:55.645Z   INFO    livekit service/roommanager.go:405      room closed     {"room": "1054ad53-b186-4bce-881b-57c80ac457a4-3e53752e-16d1-4434-9afb-69327a5175cc", "roomID": "RM_tgHrWpBeyjGH"

So all of this seems to be point into TLS problems. I am using the normal an most up to date configuration for VM-Deployments for Caddy and everything else works fine.

I have stumbled upon some information that iOS can be strange if no full-chain.pem of LE-Certs is served, i think live-kit-caddy does not serve it this way, or does it?

Does somebody have a idea and/or any suggestions how I can debug/investigate this further?

Any more logs I could provide or something? @davidzhao

rokk4 avatar Oct 26 '22 09:10 rokk4

@vishal-android-freak Did you solve the issue?

@cloudwebrtc Do you have any idea what could be going on?

rokk4 avatar Nov 22 '22 13:11 rokk4

@rokk4 When you connect to the client under 4G/5G, have you configured the turn/stun server, and what is the local ice candidate? According to the log, it should be that ice is not connected successfully

cloudwebrtc avatar Dec 05 '22 01:12 cloudwebrtc

@cloudwebrtc Sorry for the late reply, I was on a longer vacation.

The Issue was caused by Lets Encrypt Certs, there seem to be the same problems over at Matrix and Jitisi. I switched to using ZeroSSL Certs and now the Problem is not occuring anymore. Here are some ressources:

  • https://github.com/vector-im/element-android/issues/1533
  • https://github.com/coturn/coturn/issues/240
  • https://github.com/jitsi/jitsi-meet/issues/6383
  • https://bugs.chromium.org/p/webrtc/issues/detail?id=11710
  • https://github.com/vector-im/element-ios/issues/5354 [/quote]

I would recommend to add a hint about LE-Cert issues and the ZeroSSL workaround to the LiveKit docs. @davidzhao

This is the Caddy Config to make it work:

logging:
  logs:
    default:
      level: INFO
storage:
  "module": "file_system"
  "root": "/data"
apps:
  tls:
    certificates:
      automate:
        - live.my.tld
        - live-turn..my.tld
    automation:
      policies:
        - issuers:
            - module: zerossl
              api_key: 
              apikey:  SUPERSECRETZEROSSLAPIKEY 

  layer4:
    servers:
      main:
        listen: [":443"]
        routes:
          - match:
              - tls:
                  sni:
                    - "live-turn..my.tld
            handle:
              - handler: tls
              - handler: proxy
                upstreams:
                  - dial: ["xxx.xxx.xxx.xxx:5349"]
          - match:
              - tls:
                  sni:
                    - "live.my.tldt"
            handle:
              - handler: tls
                connection_policies:
                  - alpn: ["http/1.1"]
              - handler: proxy
                upstreams:
                  - dial: ["localhost:7880"]

Thank you a lot for your support. LiveKit is an amazing project.

rokk4 avatar Feb 02 '23 11:02 rokk4

@rokk4 Thanks for pointing this out. we'll include a note with our generated configs. and perhaps make ZeroSSL an option

davidzhao avatar Apr 02 '23 04:04 davidzhao

hi @rokk4, I have similar issue like you when call with 4G IOS. I try to use ZeroSSL but some errors below make me confused, can you take a look? Thank you!

{"level":"info","ts":1717154425.775762,"msg":"using provided configuration","config_file":"/etc/caddy.yaml","config_adapter":"yaml"}
{"level":"info","ts":1717154425.7809727,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]}
{"level":"info","ts":1717154425.781958,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc0008bacb0"}
{"level":"info","ts":1717154425.7833536,"logger":"tls","msg":"cleaning storage unit","description":"FileStorage:/data"}
{"level":"info","ts":1717154425.7837512,"msg":"autosaved config (load with --resume flag)","file":"/root/.config/caddy/autosave.json"}
{"level":"info","ts":1717154425.7837746,"msg":"serving initial configuration"}
{"level":"info","ts":1717154425.7843382,"logger":"tls","msg":"finished cleaning storage units"}
{"level":"info","ts":1717154425.7854617,"logger":"tls.obtain","msg":"acquiring lock","identifier":"my-domain.com"}
{"level":"info","ts":1717154425.7921257,"logger":"tls.obtain","msg":"lock acquired","identifier":"my-domain.com"}
{"level":"info","ts":1717154425.7926617,"logger":"tls.obtain","msg":"obtaining certificate","identifier":"my-domain.com"}
{"level":"info","ts":1717154425.7945986,"logger":"tls.issuance.zerossl","msg":"waiting on internal rate limiter","identifiers":["my-domain.com"],"ca":"https://acme.zerossl.com/v2/DV90","account":""}
{"level":"info","ts":1717154425.794646,"logger":"tls.issuance.zerossl","msg":"done waiting on internal rate limiter","identifiers":["my-domain.com"],"ca":"https://acme.zerossl.com/v2/DV90","account":""}
{"level":"info","ts":1717154427.9022255,"logger":"tls.issuance.zerossl.acme_client","msg":"trying to solve challenge","identifier":"my-domain.com","challenge_type":"http-01","ca":"https://acme.zerossl.com/v2/DV90"}

thaidmfinnick avatar May 31 '24 11:05 thaidmfinnick

hi @rokk4, I have similar issue like you when call with 4G IOS. I try to use ZeroSSL but some errors below make me confused, can you take a look? Thank you!

{"level":"info","ts":1717154425.775762,"msg":"using provided configuration","config_file":"/etc/caddy.yaml","config_adapter":"yaml"}
{"level":"info","ts":1717154425.7809727,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]}
{"level":"info","ts":1717154425.781958,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc0008bacb0"}
{"level":"info","ts":1717154425.7833536,"logger":"tls","msg":"cleaning storage unit","description":"FileStorage:/data"}
{"level":"info","ts":1717154425.7837512,"msg":"autosaved config (load with --resume flag)","file":"/root/.config/caddy/autosave.json"}
{"level":"info","ts":1717154425.7837746,"msg":"serving initial configuration"}
{"level":"info","ts":1717154425.7843382,"logger":"tls","msg":"finished cleaning storage units"}
{"level":"info","ts":1717154425.7854617,"logger":"tls.obtain","msg":"acquiring lock","identifier":"my-domain.com"}
{"level":"info","ts":1717154425.7921257,"logger":"tls.obtain","msg":"lock acquired","identifier":"my-domain.com"}
{"level":"info","ts":1717154425.7926617,"logger":"tls.obtain","msg":"obtaining certificate","identifier":"my-domain.com"}
{"level":"info","ts":1717154425.7945986,"logger":"tls.issuance.zerossl","msg":"waiting on internal rate limiter","identifiers":["my-domain.com"],"ca":"https://acme.zerossl.com/v2/DV90","account":""}
{"level":"info","ts":1717154425.794646,"logger":"tls.issuance.zerossl","msg":"done waiting on internal rate limiter","identifiers":["my-domain.com"],"ca":"https://acme.zerossl.com/v2/DV90","account":""}
{"level":"info","ts":1717154427.9022255,"logger":"tls.issuance.zerossl.acme_client","msg":"trying to solve challenge","identifier":"my-domain.com","challenge_type":"http-01","ca":"https://acme.zerossl.com/v2/DV90"}

Looks normal to me. What happens after the challange? Did you replace my-domain.com or is this the actual output? Because that would say the the domain is not set correctly I guess.

rokk4 avatar Jun 07 '24 12:06 rokk4

Thanks for your response! my-domain.com in above logs I have replaced. I have updated to newer version of caddy (v2.8.1). And new errors come:

{"level":"info","ts":1717412941.6063242,"logger":"tls.obtain","msg":"obtaining certificate","identifier":"turnchat.pancake.vn"}
{"level":"info","ts":1717412941.6072705,"logger":"tls.issuance.zerossl","msg":"creating certificate","identifiers":["turnchat.pancake.vn"]}
{"level":"info","ts":1717412942.9589767,"logger":"tls.obtain","msg":"obtaining certificate","identifier":"video.pancake.vn"}
{"level":"info","ts":1717412942.9598875,"logger":"tls.issuance.zerossl","msg":"creating certificate","identifiers":["video.pancake.vn"]}
{"level":"info","ts":1717412944.5642345,"logger":"tls.issuance.zerossl","msg":"created certificate","identifiers":["turnchat.pancake.vn"],"cert_id":"bd60abc3077f80f689d93b32d315023d"}
{"level":"info","ts":1717412944.5652514,"logger":"tls.issuance.zerossl","msg":"validating identifiers","identifiers":["turnchat.pancake.vn"],"cert_id":"bd60abc3077f80f689d93b32d315023d","verification_method":"HTTP_CSR_HASH"}
{"level":"info","ts":1717412944.8363333,"logger":"tls.issuance.zerossl","msg":"created certificate","identifiers":["video.pancake.vn"],"cert_id":"17423b951963093e86c274f8483f9af5"}
{"level":"info","ts":1717412944.8373754,"logger":"tls.issuance.zerossl","msg":"validating identifiers","identifiers":["video.pancake.vn"],"cert_id":"17423b951963093e86c274f8483f9af5","verification_method":"HTTP_CSR_HASH"}
{"level":"info","ts":1717412945.828761,"logger":"tls.issuance.zerossl","msg":"canceled certificate","identifiers":["turnchat.pancake.vn"],"cert_id":"bd60abc3077f80f689d93b32d315023d","verification_method":"HTTP_CSR_HASH"}
{"level":"error","ts":1717412945.8288171,"logger":"tls.obtain","msg":"could not get certificate from issuer","identifier":"turnchat.pancake.vn","issuer":"zerossl","error":"verifying identifiers: POST https://api.zerossl.com/certificates/bd60abc3077f80f689d93b32d315023d/challenges?access_key=redacted: HTTP 200: API error 0: domain_control_validation_failed (details=map[turnchat.pancake.vn:map[http://turnchat.pancake.vn/.well-known/pki-validation/EEB6CD0CAA256FB76E4BCB825059E916.txt:{{0 0   } {0 true bad_response_code Server responded with status code: 404 (200 expected)}}]]) (raw={\"success\":false,\"error\":{\"code\":0,\"type\":\"domain_control_validation_failed\",\"details\":{\"turnchat.pancake.vn\":{\"http:\\/\\/turnchat.pancake.vn\\/.well-known\\/pki-validation\\/EEB6CD0CAA256FB76E4BCB825059E916.txt\":{\"file_found\":0,\"error\":true,\"error_slug\":\"bad_response_code\",\"error_info\":\"Server responded with status code: 404 (200 expected)\"}}}}} decode_error=json: unknown field \"success\")"}
{"level":"error","ts":1717412945.828925,"logger":"tls.obtain","msg":"will retry","error":"[turnchat.pancake.vn] Obtain: verifying identifiers: POST https://api.zerossl.com/certificates/bd60abc3077f80f689d93b32d315023d/challenges?access_key=redacted: HTTP 200: API error 0: domain_control_validation_failed (details=map[turnchat.pancake.vn:map[http://turnchat.pancake.vn/.well-known/pki-validation/EEB6CD0CAA256FB76E4BCB825059E916.txt:{{0 0   } {0 true bad_response_code Server responded with status code: 404 (200 expected)}}]]) (raw={\"success\":false,\"error\":{\"code\":0,\"type\":\"domain_control_validation_failed\",\"details\":{\"turnchat.pancake.vn\":{\"http:\\/\\/turnchat.pancake.vn\\/.well-known\\/pki-validation\\/EEB6CD0CAA256FB76E4BCB825059E916.txt\":{\"file_found\":0,\"error\":true,\"error_slug\":\"bad_response_code\",\"error_info\":\"Server responded with status code: 404 (200 expected)\"}}}}} decode_error=json: unknown field \"success\")","attempt":5,"retrying_in":600,"elapsed":619.307460524,"max_duration":2592000}
{"level":"info","ts":1717412946.8676581,"logger":"tls.issuance.zerossl","msg":"canceled certificate","identifiers":["video.pancake.vn"],"cert_id":"17423b951963093e86c274f8483f9af5","verification_method":"HTTP_CSR_HASH"}
{"level":"error","ts":1717412946.8677192,"logger":"tls.obtain","msg":"could not get certificate from issuer","identifier":"video.pancake.vn","issuer":"zerossl","error":"verifying identifiers: POST https://api.zerossl.com/certificates/17423b951963093e86c274f8483f9af5/challenges?access_key=redacted: HTTP 200: API error 0: domain_control_validation_failed (details=map[video.pancake.vn:map[http://video.pancake.vn/.well-known/pki-validation/2F5B7B85C16297392C6803FA6C94BE35.txt:{{0 0   } {0 true bad_response_code Server responded with status code: 404 (200 expected)}}]]) (raw={\"success\":false,\"error\":{\"code\":0,\"type\":\"domain_control_validation_failed\",\"details\":{\"video.pancake.vn\":{\"http:\\/\\/video.pancake.vn\\/.well-known\\/pki-validation\\/2F5B7B85C16297392C6803FA6C94BE35.txt\":{\"file_found\":0,\"error\":true,\"error_slug\":\"bad_response_code\",\"error_info\":\"Server responded with status code: 404 (200 expected)\"}}}}} decode_error=json: unknown field \"success\")"}
{"level":"error","ts":1717412946.8678486,"logger":"tls.obtain","msg":"will retry","error":"[video.pancake.vn] Obtain: verifying identifiers: POST https://api.zerossl.com/certificates/17423b951963093e86c274f8483f9af5/challenges?access_key=redacted: HTTP 200: API error 0: domain_control_validation_failed (details=map[video.pancake.vn:map[http://video.pancake.vn/.well-known/pki-validation/2F5B7B85C16297392C6803FA6C94BE35.txt:{{0 0   } {0 true bad_response_code Server responded with status code: 404 (200 expected)}}]]) (raw={\"success\":false,\"error\":{\"code\":0,\"type\":\"domain_control_validation_failed\",\"details\":{\"video.pancake.vn\":{\"http:\\/\\/video.pancake.vn\\/.well-known\\/pki-validation\\/2F5B7B85C16297392C6803FA6C94BE35.txt\":{\"file_found\":0,\"error\":true,\"error_slug\":\"bad_response_code\",\"error_info\":\"Server responded with status code: 404 (200 expected)\"}}}}} decode_error=json: unknown field \"success\")","attempt":5,"retrying_in":600,"elapsed":620.346353915,"max_duration":2592000}

It seems auto create and new certificate for me, but I have set up for my domain. I have posted details my configuration in Caddy. Can you take a look?

thaidmfinnick avatar Jun 07 '24 14:06 thaidmfinnick