Comments (15)
mlsmaycon
commented on August 17, 2024
3
Thanks, @max06 ; from your logs, it takes around 24s to get 200 users from the keycloak instance. This might give us around 96s for 4 requests, assuming 720 entries.
relevant logs:
# start log
2023-12-14T17:05:24Z INFO management/cmd/management.go:282: running HTTP server and gRPC server on the same port: [::]:443
# cache warm up log
2023-12-14T17:05:48Z INFO management/server/account.go:1009: 1 entries received from IdP management
We will discuss this option and get back to you. In the mean time, it seems that there was a progress with a PR fixing this from keycloak side: keycloak/keycloak#19342
from netbird.
mlsmaycon
commented on August 17, 2024
1
Hello @max06 , thanks for sharing the results of your test.
Keycloak has an issue open because of a similar case: keycloak/keycloak#10005
The problem seems to be related to keycloak issuing a ldap search when we call the /users API.
We can increase the timeout and possibly make the API calls use pagination, but we need to evaluate that.
As we don't have a testing environment with such scale and you already built a custom version. Would run some tests for us?
from netbird.
surik
commented on August 17, 2024
1
@max06 could you please use this branch to perform some tests? https://github.com/netbirdio/netbird/commits/debug-keycloak-idp/
You need to have the flag --log-level debug set when running the management service. Please share the duration you'll get in Keycloak totalUsersCount took %d ms to handle debug log message
from netbird.
surik
commented on August 17, 2024
Hi @max06, can you share a bit more about the size of your Keycloak user directory? Additionally, for your tests, you can disable IDP Manager, you won't have email and name information for the users but you will be able to log. To do so in management.json set IdpManagerConfig.ManagerType to none.
from netbird.
max06
commented on August 17, 2024
Good morning @surik, thank you for your reply.
Roughly estimating... I'd say around 1000-1200 entries, including inactive users. All in ldap, keycloak has no local users.
We just tested another build with higher timeout (2 minutes). It takes roughly 30-35 seconds till
infrastructure_files-management-1 | 2023-12-14T10:58:54Z INFO management/server/account.go:1009: 1 entries received from IdP management
infrastructure_files-management-1 | 2023-12-14T10:58:54Z INFO management/server/account.go:1038: warmed up IDP cache with 1 entries
Once that happened, the login is fast and works. I'll also test disabling the idp manager this afternoon.
(... I'm currently a little bit lost about the why and how things are related. Just a matter of time and coffee...)
from netbird.
max06
commented on August 17, 2024
Hello @mlsmaycon!
I think you're right - and we're currently also looking into options limiting the scope of user searches to improve that process.
I currently have a dedicated testing setup up and running - happy to run test all day long!
from netbird.
max06
commented on August 17, 2024
I'm sorry for the delay - too many meetings...
My colleague who created the version I tested with the increased timeout already left ... I can build a new version (your branch is currently running), I just don't know where to increase the timeout... if you could give me a filepath maybe? 🙈
from netbird.
surik
commented on August 17, 2024
@max06 the branch above already includes a timeout increase.
from netbird.
max06
commented on August 17, 2024
Hum... then it's not what you're currently looking at. Your branch causes timeout errors again.
from netbird.
mlsmaycon
commented on August 17, 2024
@max06 can you pull the latest changes from the debug-keycloak-idp branch? I've increased the timeout to 2 minutes and updated the log level to info
from netbird.
max06
commented on August 17, 2024
Okay, it's the correct timeout.
All the logs!
2023-12-14T15:26:14Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/users took 0 ms and finished with status 204
2023-12-14T15:26:14Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:26:14Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:26:14Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:26:14Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:26:14Z DEBG management/server/file_store.go:285: took 411ns to acquire global lock
2023-12-14T15:26:14Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:26:14Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:26:14Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:26:14Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:26:14Z DEBG management/server/account.go:1148: account cltdvho8aioc73abje9g not found in cache, reloading
2023-12-14T15:26:14Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:26:14Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:26:14Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:26:14Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:26:14Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:26:14Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:26:14Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:26:14Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:26:14Z INFO management/server/idp/keycloak.go:420: Keycloak totalUsersCount took 7 ms to handle
2023-12-14T15:27:14Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/users took 0 ms and finished with status 204
2023-12-14T15:27:14Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/users took 0 ms and finished with status 204
2023-12-14T15:27:14Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/groups took 0 ms and finished with status 204
2023-12-14T15:27:14Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:14Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:20Z INFO management/server/account.go:1009: 1 entries received from IdP management
2023-12-14T15:27:20Z INFO management/server/account.go:1038: warmed up IDP cache with 1 entries
2023-12-14T15:27:34Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:34Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:34Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:34Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/account.go:1160: 720 entries received from IdP management
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 1m29.41322561s
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 330ns to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 1m29.41378273s to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 551.771µs
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 1m29.413943537s to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 1m29.414282232s
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 1m29.413496085s to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 1m29.41434392s
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 1m29.413750809s to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 876.35µs
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 1m29.413878343s
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 1m29.41410247s
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 1m29.414043647s to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 1m29.414288715s to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 1m29.414365932s
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 28.993856344s to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 1m29.414777756s
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 8.981899324s to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 28.994284911s
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 8.982187263s to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 8.982256676s
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 2.554637ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 8.982553831s
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 2.574576ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 2.87608ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 2.568934ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 2.89732ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 275.514µs
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 4.108µs
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.118281ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 3.014223ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/groups took 89418 ms and finished with status 200
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 3.302171ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.564751ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 2.951142ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.661797ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 3.166032ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 632.535µs
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.288735ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 3.292793ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.602343ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 3.026867ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.622341ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 3.356375ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.452838ms
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 994.554µs
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 1.43269ms
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 1.111257ms
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 297.487µs
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 790.286µs
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 3.35886ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.965906ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 3.769782ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.875254ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 2.370046ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 617.756µs
2023-12-14T15:27:43Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:43Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 193.377µs
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 4.08869ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/routes took 89422 ms and finished with status 200
2023-12-14T15:27:43Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/accounts took 89422 ms and finished with status 200
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 1.964584ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.248449ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 2.04163ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 2.475747ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 414.981µs
2023-12-14T15:27:43Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/policies took 89422 ms and finished with status 200
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 330.92µs
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 2.602518ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 5.29µs
2023-12-14T15:27:43Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/setup-keys took 89423 ms and finished with status 200
2023-12-14T15:27:43Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/dns/nameservers took 89423 ms and finished with status 200
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 2.533227ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 3.223482ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.297614ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/user.go:980: Got 0 users from ExternalCache for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/user.go:981: Got 1 users from InternalCache for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/http/users_handler.go:201: UserCount: 1
2023-12-14T15:27:43Z DEBG management/server/http/users_handler.go:214: Should include service user: false
2023-12-14T15:27:43Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/users took 89424 ms and finished with status 200
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 4.00517ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 4.107135ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:285: took 3.56404ms to acquire global lock
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 4.445569ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:43Z DEBG management/server/file_store.go:281: released global lock in 3.953142ms
2023-12-14T15:27:43Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:43Z DEBG management/server/user.go:980: Got 0 users from ExternalCache for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/user.go:981: Got 1 users from InternalCache for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/http/users_handler.go:201: UserCount: 1
2023-12-14T15:27:43Z DEBG management/server/user.go:980: Got 0 users from ExternalCache for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/users took 29004 ms and finished with status 200
2023-12-14T15:27:43Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/groups took 8992 ms and finished with status 200
2023-12-14T15:27:43Z DEBG management/server/user.go:981: Got 1 users from InternalCache for account cltdvho8aioc73abje9g
2023-12-14T15:27:43Z DEBG management/server/http/users_handler.go:201: UserCount: 1
2023-12-14T15:27:43Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/users took 8992 ms and finished with status 200
2023-12-14T15:27:44Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/peers took 0 ms and finished with status 204
2023-12-14T15:27:44Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:44Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:44Z DEBG management/server/file_store.go:285: took 240ns to acquire global lock
2023-12-14T15:27:44Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:44Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:44Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:44Z DEBG management/server/file_store.go:281: released global lock in 413.517µs
2023-12-14T15:27:44Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:44Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:44Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:44Z DEBG management/server/file_store.go:285: took 130ns to acquire global lock
2023-12-14T15:27:44Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:44Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:44Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:44Z DEBG management/server/file_store.go:281: released global lock in 377.559µs
2023-12-14T15:27:44Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:44Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T15:27:44Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 7.824µs
2023-12-14T15:27:44Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T15:27:44Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T15:27:44Z DEBG management/server/file_store.go:285: took 210ns to acquire global lock
2023-12-14T15:27:44Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T15:27:44Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:44Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T15:27:44Z DEBG management/server/file_store.go:281: released global lock in 301.885µs
2023-12-14T15:27:44Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T15:27:44Z DEBG management/server/telemetry/http_api_metrics.go:201: request GET /api/peers took 2 ms and finished with status 200
Line 32 is interesting.
2023-12-14T15:27:43Z DEBG management/server/account.go:1160: 720 entries received from IdP management
from netbird.
mlsmaycon
commented on August 17, 2024
Thanks @max06, I've pushed another version with some logs and an initial limit of 200 entries
We are just validating if pagination would improve performance and if the Link header is present in the response.
This will probably give you an error, so after running this version and getting the logs, you can rollback to the previous one.
from netbird.
max06
commented on August 17, 2024
There you go!
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/users took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/setup-keys took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/groups took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/routes took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/policies took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/dns/nameservers took 0 ms and finished with status 204
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z DEBG management/server/file_store.go:285: took 380ns to acquire global lock
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T17:05:26Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T17:05:26Z DEBG management/server/account.go:1148: account cltdvho8aioc73abje9g not found in cache, reloading
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z INFO management/server/idp/keycloak.go:412: Link header:
2023-12-14T17:05:29Z INFO management/server/idp/keycloak.go:412: Link header:
2023-12-14T17:05:48Z INFO management/server/account.go:1009: 1 entries received from IdP management
2023-12-14T17:05:48Z INFO management/server/account.go:1038: warmed up IDP cache with 1 entries
2023-12-14T17:05:51Z DEBG management/server/account.go:1160: 200 entries received from IdP management
2023-12-14T17:05:51Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T17:05:51Z DEBG management/server/file_store.go:281: released global lock in 24.969940854s
2023-12-14T17:05:51Z DEBG management/server/file_store.go:285: took 24.969926316s to acquire global lock
2023-12-14T17:05:51Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T17:05:51Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:51Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:51Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T17:05:51Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T17:05:51Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T17:05:51Z DEBG management/server/file_store.go:281: released global lock in 24.970710991s
2023-12-14T17:05:51Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T17:05:51Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:51Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:51Z DEBG management/server/file_store.go:285: took 200ns to acquire global lock
2023-12-14T17:05:51Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T17:05:51Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T17:05:51Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T17:05:51Z DEBG management/server/file_store.go:285: took 24.971138366s to acquire global lock
2023-12-14T17:05:51Z DEBG management/server/file_store.go:281: released global lock in 397.516µs
2023-12-14T17:05:51Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T17:05:51Z DEBG management/server/file_store.go:295: acquiring lock for account cltdvho8aioc73abje9g
2023-12-14T17:05:51Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T17:05:51Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T17:05:51Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T17:05:51Z DEBG management/server/file_store.go:281: released global lock in 24.971867725s
2023-12-14T17:05:51Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T17:05:51Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:51Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:51Z DEBG management/server/file_store.go:303: released lock for account cltdvho8aioc73abje9g in 224.808µs
2023-12-14T17:05:51Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:51Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:51Z DEBG management/server/file_store.go:285: took 24.97175484s to acquire global lock
2023-12-14T17:05:51Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T17:05:51Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
Looks like the 200 users are good, but no link header.
from netbird.
mlsmaycon
commented on August 17, 2024
@max06 I missed some of the startup logs. Can you get the full log from management?
from netbird.
max06
commented on August 17, 2024
Whoops, sorry. Yes, sure.
2023-12-14T17:05:24Z INFO management/cmd/management.go:422: loading OIDC configuration from the provided IDP configuration endpoint https://keycloak.somedomain/realms/somerealm/.well-known/openid-configuration
2023-12-14T17:05:24Z INFO management/cmd/management.go:427: loaded OIDC configuration from the provided IDP configuration endpoint: https://keycloak.somedomain/realms/somerealm/.well-known/openid-configuration
2023-12-14T17:05:24Z INFO management/cmd/management.go:429: overriding HttpConfig.AuthIssuer with a new value https://keycloak.somedomain/realms/somerealm, previously configured value: https://keycloak.somedomain/realms/somerealm
2023-12-14T17:05:24Z INFO management/cmd/management.go:433: overriding HttpConfig.AuthKeysLocation (JWT certs) with a new value https://keycloak.somedomain/realms/somerealm/protocol/openid-connect/certs, previously configured value: https://keycloak.somedomain/realms/somerealm/protocol/openid-connect/certs
2023-12-14T17:05:24Z INFO management/cmd/management.go:438: overriding DeviceAuthorizationFlow.TokenEndpoint with a new value: https://keycloak.somedomain/realms/somerealm/protocol/openid-connect/token, previously configured value: https://keycloak.somedomain/realms/somerealm/protocol/openid-connect/token
2023-12-14T17:05:24Z INFO management/cmd/management.go:441: overriding DeviceAuthorizationFlow.DeviceAuthEndpoint with a new value: https://keycloak.somedomain/realms/somerealm/protocol/openid-connect/auth/device, previously configured value: https://keycloak.somedomain/realms/somerealm/protocol/openid-connect/auth/device
2023-12-14T17:05:24Z INFO management/cmd/management.go:449: overriding DeviceAuthorizationFlow.ProviderConfig.Domain with a new value: keycloak.somedomain, previously configured value: keycloak.somedomain
2023-12-14T17:05:24Z INFO management/cmd/management.go:459: overriding PKCEAuthorizationFlow.TokenEndpoint with a new value: https://keycloak.somedomain/realms/somerealm/protocol/openid-connect/token, previously configured value: https://keycloak.somedomain/realms/somerealm/protocol/openid-connect/token
2023-12-14T17:05:24Z INFO management/cmd/management.go:462: overriding PKCEAuthorizationFlow.AuthorizationEndpoint with a new value: https://keycloak.somedomain/realms/somerealm/protocol/openid-connect/auth, previously configured value: https://keycloak.somedomain/realms/somerealm/protocol/openid-connect/auth
2023-12-14T17:05:24Z INFO management/server/telemetry/app_metrics.go:177: enabled application metrics and exposing on http://0.0.0.0:8081
2023-12-14T17:05:24Z INFO management/server/store.go:74: using JSON file store engine
2023-12-14T17:05:24Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T17:05:24Z DEBG management/server/activity/sqlite/sqlite.go:328: check deleted_users table version
2023-12-14T17:05:24Z INFO management/server/account.go:828: single account mode enabled, accounts number 1
2023-12-14T17:05:24Z DEBG management/server/idp/keycloak.go:125: requesting new jwt token for keycloak idp manager
2023-12-14T17:05:24Z DEBG management/server/ephemeral.go:135: loaded ephemeral peer(s): 0
2023/12/14 17:05:24 INFO: [core] [Server #1] Server created
2023-12-14T17:05:24Z INFO management/cmd/management.go:250: running gRPC backward compatibility server: [::]:33073
2023-12-14T17:05:24Z INFO management/cmd/management.go:282: running HTTP server and gRPC server on the same port: [::]:443
2023/12/14 17:05:24 INFO: [core] [Server #1 ListenSocket #2] ListenSocket created
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/accounts took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/users took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/setup-keys took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/groups took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/routes took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/policies took 0 ms and finished with status 204
2023-12-14T17:05:26Z DEBG management/server/telemetry/http_api_metrics.go:201: request OPTIONS /api/dns/nameservers took 0 ms and finished with status 204
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z DEBG management/server/file_store.go:285: took 380ns to acquire global lock
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T17:05:26Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T17:05:26Z DEBG management/server/account.go:1148: account cltdvho8aioc73abje9g not found in cache, reloading
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:26Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:26Z INFO management/server/idp/keycloak.go:412: Link header:
2023-12-14T17:05:29Z INFO management/server/idp/keycloak.go:412: Link header:
2023-12-14T17:05:48Z INFO management/server/account.go:1009: 1 entries received from IdP management
2023-12-14T17:05:48Z INFO management/server/account.go:1038: warmed up IDP cache with 1 entries
2023-12-14T17:05:51Z DEBG management/server/account.go:1160: 200 entries received from IdP management
2023-12-14T17:05:51Z DEBG management/server/account.go:1129: skipping IDP App Meta update because accountID cltdvho8aioc73abje9g has been already set for user 553f5100-0d05-4dd3-98ee-1747c5da73c0
2023-12-14T17:05:51Z DEBG management/server/file_store.go:281: released global lock in 24.969940854s
2023-12-14T17:05:51Z DEBG management/server/file_store.go:285: took 24.969926316s to acquire global lock
2023-12-14T17:05:51Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
2023-12-14T17:05:51Z INFO management/server/account.go:1524: overriding JWT Domain and DomainCategory claims since single account mode is enabled
2023-12-14T17:05:51Z DEBG management/server/file_store.go:275: acquiring global lock
2023-12-14T17:05:51Z DEBG management/server/file_store.go:269: took 0 ms to persist the FileStore
2023-12-14T17:05:51Z DEBG management/server/account.go:1210: looking up user 553f5100-0d05-4dd3-98ee-1747c5da73c0 of account cltdvho8aioc73abje9g in cache
If you're interested, I could open up a live share session for easier debugging.
from netbird.
Related Issues (20)
- Please refresh your SSL certificate as it expires today HOT 1
- getting-started-with-zitadel.sh HOT 9
- Features Request: Enhance Connectivity Troubleshooting HOT 1
- Unable to connect between peers HOT 8
- ACLs have no effects on Network Routes HOT 6
- Menu in the tray icon to list online peers HOT 1
- Connections between peers on 3 Windows LANs HOT 1
- Context Deadline Exceeded/Exception occurred. (Invalid class ) HOT 7
- How can I set up a self-hosted service on ports other than 80 and 443? HOT 7
- pfSense seems to be blocking connections HOT 4
- Possible Network Routes Conflict HOT 12
- artifacts_management_1 cant access management.json HOT 7
- Multicast not working
- proxy peers FQDN in the management server HOT 4
- Support having tags for peers for more dynamic NetworkRoutes HOT 3
- Settings to access devices behind a router with netbird client installed
- [FEATURE REQUEST] Make possible enable/disable ephemeral on setup key
- got an error while applying resolvconf configuration for wt0 interface, error: exit status 99 HOT 3
- Add support for Windows as a routing peer HOT 1
- ios app can't connect when use mobile network HOT 7
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from netbird.