[SOLVED] Konnectd.service won't start (binary works though)
-
Hi,
On a recent build I am having a problem getting konnectd to start via it’s systemd unit file. In particular, starting the service or the binscript results in the following output:
[konnect@archlinux sbin]$ kopano-konnectd serve INFO[0000] serve start INFO[0000] loading encryption secret from file file=/etc/kopano/konnectd-encryption-secret.key INFO[0000] loading signing key path=/etc/kopano/konnectd-signing-private-key.pem INFO[0000] loading validation keys path=/etc/kopano/konnectkeys INFO[0000] encryption set up with 32 key size WARN[0000] limiting access token duration to 240 seconds because of lower KOPANO_SERVER_SESSION_TIMEOUT INFO[0000] kc server identifier backend connection set up client="KCC(file:///run/kopano/server.sock)" panic: assignment to entry in nil map goroutine 1 [running]: stash.kopano.io/kc/konnect/identifier/meta/scopes.(*Scopes).Extend(0xc0000fc670, 0xed8da0, 0xafaf40, 0xc000056660) kopano-konnect-git/.gopath/src/stash.kopano.io/kc/konnect/identifier/meta/scopes/scopes.go:150 +0xde stash.kopano.io/kc/konnect/identifier.NewIdentifier(0xc000056fc0, 0xc000056fc0, 0xc0000ce900, 0x0) kopano-konnect-git/.gopath/src/stash.kopano.io/kc/konnect/identifier/identifier.go:117 +0x5e9 main.newKCIdentityManager(0xc0000ee1c0, 0x30f285f518e306bb, 0x20, 0x20, 0xc00000d640) src/stash.kopano.io/kc/konnect/cmd/konnectd/bootstrap_kc.go:95 +0x508 main.(*bootstrap).setupIdentity(0xc0000ee1c0, 0xaefc80, 0xc0000220b0, 0xc00000e588, 0x0, 0x0, 0x80) src/stash.kopano.io/kc/konnect/cmd/konnectd/bootstrap.go:351 +0x514 main.(*bootstrap).setup(0xc0000ee1c0, 0xaefc80, 0xc0000220b0, 0x1, 0xc000056660) src/stash.kopano.io/kc/konnect/cmd/konnectd/bootstrap.go:300 +0xa5 main.serve(0xc000085400, 0xc0000ce300, 0x1, 0x8, 0x4, 0xa13f3a) src/stash.kopano.io/kc/konnect/cmd/konnectd/serve.go:100 +0x332 main.commandServe.func1(0xc000085400, 0xc0000ce300, 0x1, 0x8) src/stash.kopano.io/kc/konnect/cmd/konnectd/serve.go:46 +0x53 stash.kopano.io/kc/konnect/vendor/github.com/spf13/cobra.(*Command).execute(0xc000085400, 0xc0000ce280, 0x8, 0x8, 0xc000085400, 0xc0000ce280) kopano-konnect-git/.gopath/src/stash.kopano.io/kc/konnect/vendor/github.com/spf13/cobra/command.go:766 +0x2ae stash.kopano.io/kc/konnect/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0xed12e0, 0xc00004bf70, 0x1, 0x1) kopano-konnect-git/.gopath/src/stash.kopano.io/kc/konnect/vendor/github.com/spf13/cobra/command.go:852 +0x2c0 stash.kopano.io/kc/konnect/vendor/github.com/spf13/cobra.(*Command).Execute(...) kopano-konnect-git/.gopath/src/stash.kopano.io/kc/konnect/vendor/github.com/spf13/cobra/command.go:800 main.main() src/stash.kopano.io/kc/konnect/cmd/konnectd/main.go:31 +0xb8 Mai 20 01:06:37 archlinux systemd[1]: kopano-konnectd.service: Main process exited, code=exited, status=2/INVALIDARGUMENT Mai 20 01:06:37 archlinux systemd[1]: kopano-konnectd.service: Failed with result 'exit-code'.
By now I have tried reinstalling the base system (Arch Linux) multiple times but even with just Nginx, Konnect, Grapi, Kapi and Core installed, this error always appears. It’s a bit frustrating since my other test system with an older build of the entire suite works fine and the error message above doesn’t really tell me anything about the problem.
What’s even more confusing is that calling the go binary for konnectd directly “works”, both with root or the konnect user:[root@archlinux kopano]# ./konnectd serve --listen=127.0.0.1:8777 --iss=https://meet.maerzlab.de --signing-private-key=/etc/ssl/kopano/secrets/konnectd-signing-private-key.pem --signing-kid=k20190320-1 --signing-method=PS256 --identifier-client-path=/usr/share/webapps/kopano-konnect/identifier-webapp --log-level=debug kc INFO[0000] serve start WARN[0000] missing --encryption-secret parameter, using random encyption secret with 32 bytes INFO[0000] loading signing key path=/etc/ssl/kopano/secrets/konnectd-signing-private-key.pem DEBU[0000] loaded signer key kid=konnectd-signing-private-key path=/etc/ssl/kopano/secrets/konnectd-signing-private-key.pem DEBU[0000] loaded signer key kid=k20190320-1 path=/etc/ssl/kopano/secrets/konnectd-signing-private-key.pem INFO[0000] encryption set up with 32 key size WARN[0000] limiting access token duration to 240 seconds because of lower KOPANO_SERVER_SESSION_TIMEOUT INFO[0000] kc server identifier backend connection set up client="KCC(file:///run/kopano/server.sock)" INFO[0000] identifier set up security="A256GCM:A256GCMKW" INFO[0000] using identifier backed identity manager INFO[0000] identity manager set up claims="[name family_name given_name email email_verified]" name=kc scopes="[offline_access kopano/gc profile email konnect/id konnect/uuid konnect/raw_sub]" INFO[0000] set provider signing alg alg=PS256 INFO[0000] set provider signing key id=konnectd-signing-private-key method="*jwt.SigningMethodRSAPSS" type="*rsa.PrivateKey" INFO[0000] set provider validation key id=konnectd-signing-private-key type="*rsa.PublicKey" INFO[0000] set provider signing key id=k20190320-1 method="*jwt.SigningMethodRSAPSS" type="*rsa.PrivateKey" INFO[0000] set provider validation key id=k20190320-1 type="*rsa.PublicKey" INFO[0000] set provider validation key id=default type="*rsa.PublicKey" INFO[0000] oidc token signing default set up alg=PS256 id=k20190320-1 method="*jwt.SigningMethodRSAPSS" INFO[0000] serve started INFO[0000] starting http listener listenAddr="127.0.0.1:8777" INFO[0000] ready to handle requests
When konnectd is called directly however, kopano-server never establishes a connection to the OIDC and hence crashes after the configured wait time. Is this related? I can access
https://<iss>/.well-known/openid-configuration
just fine from a webbrowser with the following output:{ "issuer": "https://meet.maerzlab.de", "authorization_endpoint": "https://meet.maerzlab.de/signin/v1/identifier/_/authorize", "token_endpoint": "https://meet.maerzlab.de/konnect/v1/token", "userinfo_endpoint": "https://meet.maerzlab.de/konnect/v1/userinfo", "end_session_endpoint": "https://meet.maerzlab.de/signin/v1/identifier/_/endsession", "check_session_iframe": "https://meet.maerzlab.de/konnect/v1/session/check-session.html", "jwks_uri": "https://meet.maerzlab.de/konnect/v1/jwks.json", "scopes_supported": [ "openid", "offline_access", "profile", "email", "konnect/id", "konnect/uuid", "konnect/raw_sub", "kopano/gc" ], "response_types_supported": [ "id_token token", "id_token", "code id_token", "code id_token token" ], "subject_types_supported": [ "public" ], "id_token_signing_alg_values_supported": [ "ES256", "ES384", "ES512", "RS256", "RS384", "RS512", "PS256", "PS384", "PS512" ], "claims_supported": [ "iss", "sub", "aud", "exp", "iat", "name", "family_name", "given_name", "email", "email_verified" ], "request_parameter_supported": true, "request_uri_parameter_supported": false }
I need help understanding the following two problems, please:
- Why isn’t konnect starting via it’s service file?
- Why isn’t kopano-server discovering konnect when the latter is started directly?
Whilst kopano-server waits for konnect, I am also unable to create any users using the cli tool. After a long while of hoing nothing, it comes back with
"HrLogon server "default:" user "SYSTEM": network error
Any help you can provide is greatly appreciated. Thank you!
-
You found a startup bug which prevents startup if using a
scopes.yaml
with empty definitions. The problem has been solved in commit https://github.com/Kopano-dev/konnect/commit/8cb23647f8814e3808eaae654bc2226c0b75fcac - thanks for reporting!As a workaround with the current release, either do not pass a scopes.yaml file (–identifier-scopes-conf) when starting, or make sure it includes at least one scope definition.
Best regards
-
@longsleep Thank you very much for getting back this quickly! :)
Seems like I have found something useful for once. :D
I’ll test this tonight and report back. Hopefully this also solves the server-not-discovering-konnect issue.
-
:+1: Kopano server delays its startup until Konnect becomes available. Thus clients will eventually time out since the server is (not yet) started. The behavior can be controlled by setting the
kcoidc_initialize_timeout
configuration variable in server.cfg. -
@longsleep
I can confirm that the change you suggested regarding scopes makes konnect’s service file work again.The issue that kopano-server never discovers the OIDC provider however persists. It’s even worse than I feared actually as digging around revealed that none of the other services discover konnect either. Here are some example outputs of kapi and kwmserver:
[root@mx1 kopano]# KOPANO_GRAPI_SOCKETS=/run/kopano-grapi /usr/lib/kopano/kapid serve --listen 127.0.0.1:8039 --plugins-path=/usr/lib/kopano/kapi-plugins --plugins=grapi --iss=https://meet.maerz.cc INFO[0000] serve start INFO[0000] loading plugins from /usr/lib/kopano/kapi-plugins INFO[0000] registered plugin: /usr/lib/kopano/kapi-plugins/grapi.so build= plugin=grapi version=0.0.0-no-proper-build INFO[0000] serve started INFO[0000] grapi: access requirements set up required_scopes="[profile email kopano/gc]" WARN[0010] failed to initialize OIDC provider error="Timeout (:0x105)" iss="https://meet.maerz.cc" INFO[0010] starting http listener listenAddr="127.0.0.1:8039" INFO[0010] ready to handle requests 2019/05/21 02:43:49 http: panic serving 127.0.0.1:35538: runtime error: invalid memory address or nil pointer dereference goroutine 130 [running]: net/http.(*conn).serve.func1(0xc0000ade00) /usr/lib/go/src/net/http/server.go:1769 +0x139 panic(0x9c86c0, 0xd90b00) /usr/lib/go/src/runtime/panic.go:522 +0x1b5 stash.kopano.io/kc/kapi/vendor/stash.kopano.io/kc/libkcoidc.(*Provider).ValidateTokenString(0xc000096540, 0xad8660, 0xc0000697c0, 0xc000292e07, 0x62c, 0x1, 0xc000278720, 0x2, 0x2, 0x692b9496, ...) kopano-kapi-git/.gopath/src/stash.kopano.io/kc/kapi/vendor/stash.kopano.io/kc/libkcoidc/provider.go:174 +0x53 stash.kopano.io/kc/kapi/vendor/stash.kopano.io/kc/kapi/server.(*Server).AccessTokenRequired.func1(0xad7460, 0xc000150540, 0xc000395b00) kopano-kapi-git/.gopath/src/stash.kopano.io/kc/kapi/vendor/stash.kopano.io/kc/kapi/server/handlers.go:56 +0x15a net/http.HandlerFunc.ServeHTTP(0xc000069800, 0xad7460, 0xc000150540, 0xc000395b00) /usr/lib/go/src/net/http/server.go:1995 +0x44 stash.kopano.io/kc/kapi/plugins/grapi.(*KopanoGroupwareCorePlugin).ServeHTTP(0xc00009bf10, 0xad7460, 0xc000150540, 0xc000395b00, 0x9dbce0, 0xad0001, 0xc0002b86f0) src/stash.kopano.io/kc/kapi/plugins/grapi/plugin.go:182 +0xf1 stash.kopano.io/kc/kapi/vendor/stash.kopano.io/kc/kapi/server.(*Server).ServeHTTP(0xc00009a0e0, 0xad7460, 0xc000150540, 0xc000395b00) kopano-kapi-git/.gopath/src/stash.kopano.io/kc/kapi/vendor/stash.kopano.io/kc/kapi/server/server.go:111 +0xd4 stash.kopano.io/kc/kapi/vendor/stash.kopano.io/kc/kapi/server.(*Server).AddContext.func1(0xad7460, 0xc000150540, 0xc000395900) kopano-kapi-git/.gopath/src/stash.kopano.io/kc/kapi/vendor/stash.kopano.io/kc/kapi/server/server.go:158 +0x171 net/http.HandlerFunc.ServeHTTP(0xc0003bc480, 0xad7460, 0xc000150540, 0xc000395900) /usr/lib/go/src/net/http/server.go:1995 +0x44 net/http.serverHandler.ServeHTTP(0xc00008a820, 0xad7460, 0xc000150540, 0xc000395900) /usr/lib/go/src/net/http/server.go:2774 +0xa8 net/http.(*conn).serve(0xc0000ade00, 0xad8660, 0xc000069640) /usr/lib/go/src/net/http/server.go:1878 +0x851 created by net/http.(*Server).Serve /usr/lib/go/src/net/http/server.go:2884 +0x2f4
[root@mx1 kopano]# /usr/lib/kopano/kwmserverd serve --log-timestamp=false --listen=127.0.0.1:8778 --log-level=debug --iss=https://meet.maerz.cc --enable-rtm-api --enable-mcu-api --enable-guest-api --admin-tokens-key=/etc/ssl/kopano/secrets/kwmserverd-admin-tokens-secret.key --turn-service-url= --turn-server-shared-secret=/etc/ssl/kopano/secrets/kwmserverd.secret --turn-uri=turn:mx1.maerz.cc:5349?transport=tcp --public-guest-access-regexp=^group/public/.* INFO serve start INFO serve started WARN failed to initialize OIDC provider error="Timeout (:0x105)" iss="https://meet.maerz.cc" DEBU TURN credentials support enabled uris="[turn:mx1.maerz.cc:5349?transport=tcp]" INFO admin: API endpoint enabled INFO mcu: API endpoint enabled INFO pattern ^group/public/.* public guest rooms enabled manager=guest INFO guest: API endpoint enabled INFO rtm: API endpoint enabled INFO starting http listener listenAddr="127.0.0.1:8778" INFO ready to handle requests 2019/05/21 02:17:06 http: panic serving 127.0.0.1:34278: runtime error: invalid memory address or nil pointer dereference goroutine 97 [running]: net/http.(*conn).serve.func1(0xc00009cf00) /usr/lib/go/src/net/http/server.go:1769 +0x13b panic(0x55def8ac2480, 0x55def8e8aaf0) /usr/lib/go/src/runtime/panic.go:522 +0x1b9 stash.kopano.io/kwm/kwmserver/vendor/stash.kopano.io/kc/libkcoidc.(*Provider).ValidateTokenString(0xc000061260, 0x55def8b5bdc0, 0xc00005e740, 0xc0001e0007, 0x62c, 0x1, 0xc000318b40, 0x2, 0x2, 0x0, ...) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/vendor/stash.kopano.io/kc/libkcoidc/provider.go:174 +0x55 stash.kopano.io/kwm/kwmserver/signaling/rtm.(*Manager).isRequestWithValidAuth(0xc0000a1300, 0xc0000a1a00, 0x0, 0x10) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/signaling/rtm/http.go:63 +0x153 stash.kopano.io/kwm/kwmserver/signaling/rtm.(*Manager).MakeHTTPConnectHandler.func1(0x55def8b5a980, 0xc00008a460, 0xc0000a1a00) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/signaling/rtm/http.go:171 +0x90 net/http.HandlerFunc.ServeHTTP(0xc0001e92c0, 0x55def8b5a980, 0xc00008a460, 0xc0000a1a00) /usr/lib/go/src/net/http/server.go:1995 +0x46 stash.kopano.io/kwm/kwmserver/vendor/github.com/rs/cors.(*Cors).Handler.func1(0x55def8b5a980, 0xc00008a460, 0xc0000a1a00) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/vendor/github.com/rs/cors/cors.go:207 +0x1b1 net/http.HandlerFunc.ServeHTTP(0xc0002e3120, 0x55def8b5a980, 0xc00008a460, 0xc0000a1a00) /usr/lib/go/src/net/http/server.go:1995 +0x46 stash.kopano.io/kwm/kwmserver/signaling/server.(*Server).WithMetrics.func1(0x55def8b5a980, 0xc00008a460, 0xc0000a1900) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/signaling/server/server.go:102 +0x189 net/http.HandlerFunc.ServeHTTP(0xc0002e3140, 0x55def8b5a980, 0xc00008a460, 0xc0000a1900) /usr/lib/go/src/net/http/server.go:1995 +0x46 stash.kopano.io/kwm/kwmserver/vendor/github.com/gorilla/mux.(*Router).ServeHTTP(0xc0001b0240, 0x55def8b5a980, 0xc00008a460, 0xc0000a1500) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/vendor/github.com/gorilla/mux/mux.go:212 +0xe5 stash.kopano.io/kwm/kwmserver/signaling/server.(*Server).AddContext.func1(0x55def8b5a980, 0xc00008a460, 0xc0000a0b00) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/signaling/server/server.go:113 +0xf9 net/http.HandlerFunc.ServeHTTP(0xc000520300, 0x55def8b5a980, 0xc00008a460, 0xc0000a0b00) /usr/lib/go/src/net/http/server.go:1995 +0x46 net/http.serverHandler.ServeHTTP(0xc000106000, 0x55def8b5a980, 0xc00008a460, 0xc0000a0b00) /usr/lib/go/src/net/http/server.go:2774 +0xaa net/http.(*conn).serve(0xc00009cf00, 0x55def8b5bdc0, 0xc00005e500) /usr/lib/go/src/net/http/server.go:1878 +0x853 created by net/http.(*Server).Serve /usr/lib/go/src/net/http/server.go:2884 +0x2f6 2019/05/21 02:17:07 http: panic serving 127.0.0.1:34286: runtime error: invalid memory address or nil pointer dereference goroutine 99 [running]: net/http.(*conn).serve.func1(0xc00009d0e0) /usr/lib/go/src/net/http/server.go:1769 +0x13b panic(0x55def8ac2480, 0x55def8e8aaf0) /usr/lib/go/src/runtime/panic.go:522 +0x1b9 stash.kopano.io/kwm/kwmserver/vendor/stash.kopano.io/kc/libkcoidc.(*Provider).ValidateTokenString(0xc000061260, 0x55def8b5bdc0, 0xc0000b11c0, 0xc000136307, 0x62c, 0x1, 0xc000332880, 0x2, 0x2, 0x0, ...) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/vendor/stash.kopano.io/kc/libkcoidc/provider.go:174 +0x55 stash.kopano.io/kwm/kwmserver/signaling/rtm.(*Manager).isRequestWithValidAuth(0xc0000a1300, 0xc00028c800, 0x0, 0x10) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/signaling/rtm/http.go:63 +0x153 stash.kopano.io/kwm/kwmserver/signaling/rtm.(*Manager).MakeHTTPConnectHandler.func1(0x55def8b5a980, 0xc0002cd0a0, 0xc00028c800) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/signaling/rtm/http.go:171 +0x90 net/http.HandlerFunc.ServeHTTP(0xc0001e92c0, 0x55def8b5a980, 0xc0002cd0a0, 0xc00028c800) /usr/lib/go/src/net/http/server.go:1995 +0x46 stash.kopano.io/kwm/kwmserver/vendor/github.com/rs/cors.(*Cors).Handler.func1(0x55def8b5a980, 0xc0002cd0a0, 0xc00028c800) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/vendor/github.com/rs/cors/cors.go:207 +0x1b1 net/http.HandlerFunc.ServeHTTP(0xc0002e3120, 0x55def8b5a980, 0xc0002cd0a0, 0xc00028c800) /usr/lib/go/src/net/http/server.go:1995 +0x46 stash.kopano.io/kwm/kwmserver/signaling/server.(*Server).WithMetrics.func1(0x55def8b5a980, 0xc0002cd0a0, 0xc00028c700) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/signaling/server/server.go:102 +0x189 net/http.HandlerFunc.ServeHTTP(0xc0002e3140, 0x55def8b5a980, 0xc0002cd0a0, 0xc00028c700) /usr/lib/go/src/net/http/server.go:1995 +0x46 stash.kopano.io/kwm/kwmserver/vendor/github.com/gorilla/mux.(*Router).ServeHTTP(0xc0001b0240, 0x55def8b5a980, 0xc0002cd0a0, 0xc00028c500) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/vendor/github.com/gorilla/mux/mux.go:212 +0xe5 stash.kopano.io/kwm/kwmserver/signaling/server.(*Server).AddContext.func1(0x55def8b5a980, 0xc0002cd0a0, 0xc00028c400) kopano-kwmserver-git/.gopath/src/stash.kopano.io/kwm/kwmserver/signaling/server/server.go:113 +0xf9 net/http.HandlerFunc.ServeHTTP(0xc000520300, 0x55def8b5a980, 0xc0002cd0a0, 0xc00028c400) /usr/lib/go/src/net/http/server.go:1995 +0x46 net/http.serverHandler.ServeHTTP(0xc000106000, 0x55def8b5a980, 0xc0002cd0a0, 0xc00028c400) /usr/lib/go/src/net/http/server.go:2774 +0xaa net/http.(*conn).serve(0xc00009d0e0, 0x55def8b5bdc0, 0xc0000b1040) /usr/lib/go/src/net/http/server.go:1878 +0x853 created by net/http.(*Server).Serve /usr/lib/go/src/net/http/server.go:2884 +0x2f6 2019/05/21 02:17:09 http: panic serving 127.0.0.1:34288: runtime error: invalid memory address or nil pointer dereference
I am starting to wonder whether I am missing any other requirements that make konnect work, like file/folder permissions etc. I have compared everything I could think of to my other DEV machine though and they appear the same. As can be seen above, both kapi and kwmserver fail in a similar way as konnect used to, but I can’t find any config parameters that might be causing this.
-
Well, both services fail OIDC initialization with a timeout (
WARN[0010] failed to initialize OIDC provider error="Timeout (:0x105)" iss="https://meet.maerz.cc"
). This means that they cannot load the OIDC discovery document or the key set.You might want to run any of the services in debug mode (which might give more information on the why).
From my experience these are the likely root causes of this issue:
- TLS certificate is not trusted (All services validate TLS by default, look at the
--insecure
parameter to turn this off for testing) - DNS lookup error
- Firewall prevents access
- Web server not running or configuration problem
From your log messages of the services i also see that the particular detection does not work correctly and instead of logging the error
OIDC not initialized
again, it panics. The corresponding check will be be improved.Thanks for reporting back and i hope the above list helps to resolves the issue.
- TLS certificate is not trusted (All services validate TLS by default, look at the
-
@longsleep thank you. I’ll work through your list and see if I can find the issue - will report back.
A stupid question regarding the OIDC discovery document: what URL are the services trying to access for that? I seem to remember it’s this one:
https://meet.maerz.cc/.well-known/openid-configuration
Thanks again!
-
@longsleep
Your suspicion regarding TLS validation was spot on. Using insecure mode, things started working right away, so I looked into it and sorted out my SSL certificates. Thank you! :)