starred/lldap-lldap
1
0
Fork 0
mirror of https://github.com/lldap/lldap.git synced 2026-04-25 16:25:55 +03:00
Code Issues 101 Projects Releases 10 Packages Wiki Activity

[GH-ISSUE #1269] [BUG] Pools are not dropped when shutting down #447

New issue
Closed
opened 2026-02-27 08:17:20 +03:00 by kerem · 12 comments
kerem commented 2026-02-27 08:17:20 +03:00
Owner
Copy link

Originally created by @nitnelave on GitHub (Sep 3, 2025).
Original GitHub issue: https://github.com/lldap/lldap/issues/1269

Originally assigned to: @Copilot on GitHub.

Describe the bug
The DB connection pools are not dropped during clean shutdown. The DB is not aware that they are dead, and will keep them alive until TCP timeout, which can be pretty long.

Expected behavior
We need to call pool.close().await during orderly shutdown

Additional context
From sqlx docs:

Note: Drop Behavior

Due to a lack of async Drop, dropping the last Pool handle may not immediately clean up connections by itself. The connections will be dropped locally, which is sufficient for SQLite, but for client/server databases like MySQL and Postgres, that only closes the client side of the connection. The server will not know the connection is closed until potentially much later: this is usually dictated by the TCP keepalive timeout in the server settings.

Because the connection may not be cleaned up immediately on the server side, you may run into errors regarding connection limits if you are creating and dropping many pools in short order.

We recommend calling .close().await to gracefully close the pool and its connections when you are done using it. This will also wake any tasks that are waiting on an .acquire() call, so for long-lived applications it’s a good idea to call .close() during shutdown.

Originally created by @nitnelave on GitHub (Sep 3, 2025). Original GitHub issue: https://github.com/lldap/lldap/issues/1269 Originally assigned to: @Copilot on GitHub. **Describe the bug** The DB connection pools are not dropped during clean shutdown. The DB is not aware that they are dead, and will keep them alive until TCP timeout, which can be pretty long. **Expected behavior** We need to call pool.close().await during orderly shutdown **Additional context** From sqlx docs: Note: Drop Behavior Due to a lack of async Drop, dropping the last Pool handle may not immediately clean up connections by itself. The connections will be dropped locally, which is sufficient for SQLite, but for client/server databases like MySQL and Postgres, that only closes the client side of the connection. The server will not know the connection is closed until potentially much later: this is usually dictated by the TCP keepalive timeout in the server settings. Because the connection may not be cleaned up immediately on the server side, you may run into errors regarding connection limits if you are creating and dropping many pools in short order. We recommend calling .close().await to gracefully close the pool and its connections when you are done using it. This will also wake any tasks that are waiting on an .acquire() call, so for long-lived applications it’s a good idea to call .close() during shutdown.
kerem 2026-02-27 08:17:20 +03:00
  • closed this issue
  • added the
    bug
         label
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@nitnelave commented on GitHub (Sep 3, 2025):

@thielj FYI

<!-- gh-comment-id:3250998561 --> @nitnelave commented on GitHub (Sep 3, 2025): @thielj FYI
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@nitnelave commented on GitHub (Sep 3, 2025):

We can add the cleanup step in run_server_command in the main.rs

<!-- gh-comment-id:3250999524 --> @nitnelave commented on GitHub (Sep 3, 2025): We can add the cleanup step in run_server_command in the main.rs
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@thielj commented on GitHub (Sep 4, 2025):

Are you sure you don't need to implement a handler?

I've added two log statements:

    debug!("Closing database connections");
    if let Err(e) = sql_pool.close().await {
        error!("Error closing database connection pool: {}", e);
    }

    info!("LLDAP Server shutdown complete");

Result of docker stop lldap, sending a kill SIGTERM:

2025-09-04T15:52:58.943795093+00:00  INFO     ｉ [info]: SIGTERM received; starting graceful shutdown
2025-09-04T15:52:58.943866036+00:00  INFO     ｉ [info]: graceful worker shutdown; finishing 2 connections
2025-09-04T15:52:58.944291078+00:00  DEBUG    🐛 [debug]: paused accepting connections on [::]:389
2025-09-04T15:52:58.944305927+00:00  DEBUG    🐛 [debug]: paused accepting connections on 0.0.0.0:17170
2025-09-04T15:52:58.944309453+00:00  INFO     ｉ [info]: accept thread stopped

PS: here's a great example, by the way ;)

github.com/lldap/lldap@775c5c716d/server/tests/common/fixture.rs (L169)

PPS: Don't trust Copilot

<!-- gh-comment-id:3254403937 --> @thielj commented on GitHub (Sep 4, 2025): Are you sure you don't need to implement a handler? I've added two log statements: ```Rust debug!("Closing database connections"); if let Err(e) = sql_pool.close().await { error!("Error closing database connection pool: {}", e); } info!("LLDAP Server shutdown complete"); ``` Result of `docker stop lldap`, sending a kill SIGTERM: ``` 2025-09-04T15:52:58.943795093+00:00 INFO ｉ [info]: SIGTERM received; starting graceful shutdown 2025-09-04T15:52:58.943866036+00:00 INFO ｉ [info]: graceful worker shutdown; finishing 2 connections 2025-09-04T15:52:58.944291078+00:00 DEBUG 🐛 [debug]: paused accepting connections on [::]:389 2025-09-04T15:52:58.944305927+00:00 DEBUG 🐛 [debug]: paused accepting connections on 0.0.0.0:17170 2025-09-04T15:52:58.944309453+00:00 INFO ｉ [info]: accept thread stopped ``` PS: here's a great example, by the way ;) https://github.com/lldap/lldap/blob/775c5c716d31274fa0dadefbcbb879cda3cb7da4/server/tests/common/fixture.rs#L169 PPS: Don't trust Copilot
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@nitnelave commented on GitHub (Sep 4, 2025):

@thielj I'm not sure what docker stop lldap does exactly, but it's not just sending a SIGTERM, since that works fine:

2025-09-04T20:15:47.150487+00:00     INFO     ｉ [info]: DB Cleanup Cron started
2025-09-04T20:16:14.062424+00:00     INFO     ｉ [info]: SIGTERM received; starting graceful shutdown
2025-09-04T20:16:14.062634+00:00     DEBUG    🐛 [debug]: paused accepting connections on 0.0.0.0:3890
2025-09-04T20:16:14.062654+00:00     INFO     ｉ [info]: shutting down idle worker
2025-09-04T20:16:14.062720+00:00     DEBUG    🐛 [debug]: paused accepting connections on 0.0.0.0:17170
2025-09-04T20:16:14.062747+00:00     INFO     ｉ [info]: accept thread stopped
2025-09-04T20:16:14.365955+00:00     INFO     ｉ [info]: Shutting down
2025-09-04T20:16:14.366982+00:00     INFO     ｉ [info]: DB Cleanup stopped

The "Shutting down" message is one I added next to the pool close, and it prints as expected. In your case, I would expect at least "DB Cleanup stopped" to be printed during an orderly shutdown.

<!-- gh-comment-id:3255475697 --> @nitnelave commented on GitHub (Sep 4, 2025): @thielj I'm not sure what `docker stop lldap` does exactly, but it's not _just_ sending a SIGTERM, since that works fine: ``` 2025-09-04T20:15:47.150487+00:00 INFO ｉ [info]: DB Cleanup Cron started 2025-09-04T20:16:14.062424+00:00 INFO ｉ [info]: SIGTERM received; starting graceful shutdown 2025-09-04T20:16:14.062634+00:00 DEBUG 🐛 [debug]: paused accepting connections on 0.0.0.0:3890 2025-09-04T20:16:14.062654+00:00 INFO ｉ [info]: shutting down idle worker 2025-09-04T20:16:14.062720+00:00 DEBUG 🐛 [debug]: paused accepting connections on 0.0.0.0:17170 2025-09-04T20:16:14.062747+00:00 INFO ｉ [info]: accept thread stopped 2025-09-04T20:16:14.365955+00:00 INFO ｉ [info]: Shutting down 2025-09-04T20:16:14.366982+00:00 INFO ｉ [info]: DB Cleanup stopped ``` The "Shutting down" message is one I added next to the pool close, and it prints as expected. In your case, I would expect at least "DB Cleanup stopped" to be printed during an orderly shutdown.
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@nitnelave commented on GitHub (Sep 4, 2025):

And I know how far to trust Copilot, this is something I tested before, I didn't just take its word for it.

<!-- gh-comment-id:3255477138 --> @nitnelave commented on GitHub (Sep 4, 2025): And I know how far to trust Copilot, this is something I tested before, I didn't just take its word for it.
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@thielj commented on GitHub (Sep 4, 2025):

Docker is sending a SIGTERM as you can see from my log.

<!-- gh-comment-id:3255606342 --> @thielj commented on GitHub (Sep 4, 2025): Docker is sending a SIGTERM as you can see from my log.
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@thielj commented on GitHub (Sep 4, 2025):

Sorry, I can't repo the correct behaviour.

docker run --rm -v /data -e UID=1000 -e GID=1000 \
  -e LLDAP_JWT_SECRET=SECRET \
  -e LLDAP_LDAP_USER_PASS=SECRET12 \
  -e LLDAP_VERBOSE=true \
  rg.nl-ams.scw.cloud/estrella/lldap:0.6.2-pool

I then killed the process manually, just in case. Full log follows.

WARNING: A key_seed was given, we will ignore the key_file and generate one from the seed! Set key_file to an empty string in the config to silence this message.
root@infra3:/opt/estrella/docker/30-auth# more log
[entrypoint] Copying the default config to /data/lldap_config.toml
[entrypoint] Edit this file to configure LLDAP.
> Setup permissions..
> Starting lldap..

Loading configuration from /data/lldap_config.toml
Configuration: Configuration {
    ldap_host: "0.0.0.0",
    ldap_port: 3890,
    http_host: "0.0.0.0",
    http_port: 17170,
    jwt_secret: Some(
        ***SECRET***,
    ),
    ldap_base_dn: "dc=example,dc=com",
    ldap_user_dn: "admin",
    ldap_user_email: "",
    ldap_user_pass: Some(
        ***SECRET***,
    ),
    force_ldap_user_pass_reset: False,
    force_update_private_key: false,
    db_options: DbOptions {
        url: "sqlite://users.db?mode=rwc",
        min_connections: None,
        max_connections: None,
        connect_timeout: 3,
        idle_timeout: 600,
        max_lifetime: 3600,
    },
    database_url: Some(
        "sqlite:///data/users.db?mode=rwc",
    ),
    ignored_user_attributes: [],
    key_file: "server_key",
    key_seed: Some(
        ***SECRET***,
    ),
    assets_path: "./app",
    smtp_options: MailOptions {
        enable_password_reset: false,
        from: None,
        reply_to: None,
        server: "localhost",
        port: 587,
        user: "",
        password: ***SECRET***,
        smtp_encryption: Tls,
        ..
    },
    ldaps_options: LdapsOptions {
        enabled: false,
        port: 6360,
        cert_file: "cert.pem",
        key_file: "key.pem",
    },
    http_url: "http://localhost/",
    ..
}
DEPRECATED: database_url field is deprecated. You can replace it with db_options.url.
2025-09-04T21:00:47.886726406+00:00  INFO     set_up_server [ 456ms | 16.39% / 100.00% ]
2025-09-04T21:00:47.886738579+00:00  INFO     ┝━ ｉ [info]: Starting LLDAP version 0.6.2
2025-09-04T21:00:47.893724990+00:00  DEBUG    ┝━ get_schema_version [ 618µs | 0.14% ]
2025-09-04T21:00:47.894441902+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | return: None
2025-09-04T21:00:47.929567830+00:00  DEBUG    ┝━ get_schema_version [ 256µs | 0.06% ]
2025-09-04T21:00:47.929854220+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | return: Some(SchemaVersion(1))
2025-09-04T21:00:47.929858979+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema from version 1
2025-09-04T21:00:47.929859971+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 2
2025-09-04T21:00:47.973646006+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 3
2025-09-04T21:00:48.013603378+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 4
2025-09-04T21:00:48.022253337+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 5
2025-09-04T21:00:48.094326278+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 6
2025-09-04T21:00:48.096300402+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 7
2025-09-04T21:00:48.100079252+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 8
2025-09-04T21:00:48.102319407+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 9
2025-09-04T21:00:48.104377129+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 10
2025-09-04T21:00:48.141624990+00:00  DEBUG    ┝━ list_groups [ 2.12ms | 0.46% ] filters: Some(DisplayName("lldap_admin"))
2025-09-04T21:00:48.172290884+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | return: []
2025-09-04T21:00:48.172300001+00:00  WARN     ┝━ 🚧 [warn]: Could not find lldap_admin group, trying to create it
2025-09-04T21:00:48.172309749+00:00  DEBUG    ┝━ create_group [ 5.43ms | 1.19% ] request: CreateGroupRequest { display_name: "lldap_admin", attributes: [] }
2025-09-04T21:00:48.203357092+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | return: 1
2025-09-04T21:00:48.203368343+00:00  DEBUG    ┝━ list_groups [ 7.14ms | 1.57% ] filters: Some(DisplayName("lldap_password_manager"))
2025-09-04T21:00:48.218168094+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | return: []
2025-09-04T21:00:48.218189173+00:00  WARN     ┝━ 🚧 [warn]: Could not find lldap_password_manager group, trying to create it
2025-09-04T21:00:48.218193622+00:00  DEBUG    ┝━ create_group [ 5.22ms | 1.15% ] request: CreateGroupRequest { display_name: "lldap_password_manager", attributes: [] }
2025-09-04T21:00:48.228207303+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | return: 2
2025-09-04T21:00:48.228214878+00:00  DEBUG    ┝━ list_groups [ 1.90ms | 0.42% ] filters: Some(DisplayName("lldap_strict_readonly"))
2025-09-04T21:00:48.230067463+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | return: []
2025-09-04T21:00:48.230071080+00:00  WARN     ┝━ 🚧 [warn]: Could not find lldap_strict_readonly group, trying to create it
2025-09-04T21:00:48.230073725+00:00  DEBUG    ┝━ create_group [ 6.30ms | 1.38% ] request: CreateGroupRequest { display_name: "lldap_strict_readonly", attributes: [] }
2025-09-04T21:00:48.291953085+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | return: 3
2025-09-04T21:00:48.291990525+00:00  DEBUG    ┝━ list_users [ 7.80ms | 1.71% ] filters: Some(MemberOf("lldap_admin")) | _get_groups: false
2025-09-04T21:00:48.300790097+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | return: []
2025-09-04T21:00:48.300794154+00:00  WARN     ┝━ 🚧 [warn]: Could not find an admin user, trying to create the user "admin" with the config-provided password
2025-09-04T21:00:48.300806307+00:00  DEBUG    ┝━ create_user [ 8.89ms | 1.95% ] request: CreateUserRequest { user_id: "admin", email: "", display_name: Some("Administrator"), attributes: [] } | user_id: "admin"
2025-09-04T21:00:48.305949660+00:00  DEBUG    ┝━ register_password [ 332ms | 72.74% / 72.88% ] username: admin
2025-09-04T21:00:48.306037175+00:00  DEBUG    │  ┝━ registration_start [ 71.6µs | 0.02% ]
2025-09-04T21:00:48.637331395+00:00  DEBUG    │  ┕━ registration_finish [ 543µs | 0.12% ]
2025-09-04T21:00:48.640498129+00:00  INFO     │     ┕━ ｉ [info]: Successfully (re)set password for "admin"
2025-09-04T21:00:48.640516784+00:00  DEBUG    ┝━ list_groups [ 1.23ms | 0.27% ] filters: Some(DisplayName("lldap_admin"))
2025-09-04T21:00:48.642308795+00:00  DEBUG    │  ┕━ 🐛 [debug]:  | return: [Group { id: 1, display_name: "lldap_admin", creation_date: 2025-09-04T21:00:48.172310391, uuid: "0da803b3-4b6e-3e6f-b9ea-be15d94fd194", users: [], attributes: [] }]
2025-09-04T21:00:48.642326748+00:00  DEBUG    ┝━ add_user_to_group [ 1.72ms | 0.38% ] user_id: "admin"
2025-09-04T21:00:48.677762712+00:00  INFO     ┝━ ｉ [info]: Starting the LDAP server on port 3890
2025-09-04T21:00:48.678015648+00:00  DEBUG    ┝━ get_jwt_blacklist [ 325µs | 0.07% ]
2025-09-04T21:00:48.678480336+00:00  INFO     ┕━ ｉ [info]: Starting the API/web server on port 17170
2025-09-04T21:00:48.681495824+00:00  INFO     ｉ [info]: starting 1 workers
2025-09-04T21:00:48.681568522+00:00  INFO     ｉ [info]: Actix runtime found; starting in Actix runtime
2025-09-04T21:00:48.681599850+00:00  INFO     ｉ [info]: starting service: "ldap", workers: 1, listening on: 0.0.0.0:3890
2025-09-04T21:00:48.681615369+00:00  INFO     ｉ [info]: starting service: "http", workers: 1, listening on: 0.0.0.0:17170
2025-09-04T21:00:48.689707977+00:00  INFO     ｉ [info]: DB Cleanup Cron started
2025-09-04T21:01:17.355819581+00:00  INFO     ｉ [info]: LDAP session start: d0224b8e-42ba-412d-89f6-2c32c31e6f2d
2025-09-04T21:01:17.356080373+00:00  INFO     LDAP request [ 89.0µs | 100.00% ] session_id: d0224b8e-42ba-412d-89f6-2c32c31e6f2d
2025-09-04T21:01:17.356094620+00:00  DEBUG    ┝━ 🐛 [debug]:  | msg: LdapMsg { msgid: 0, op: SearchRequest(LdapSearchRequest { base: "", scope: Base, aliases: Never, sizelimit: 0, timelimit: 0, typesonly: false, filter: Present("objectClass"), attrs: ["supportedExtension"] }), ctrl: [] }
2025-09-04T21:01:17.356098036+00:00  DEBUG    ┝━ 🐛 [debug]: rootDSE request
2025-09-04T21:01:17.356112894+00:00  DEBUG    ┝━ 🐛 [debug]:  | response: SearchResultEntry(LdapSearchResultEntry { dn: "", attributes: [LdapPartialAttribute { atype: "objectClass", vals: ["top"] }, LdapPartialAttribute { atype: "vendorName", vals: ["LLDAP"] }, LdapPartialAttribute { atype: "vendorVersion", vals: ["lldap_0.1.0"] }, LdapPartialAttribute { atype: "supportedLDAPVersion", vals: ["3"] }, LdapPartialAttribute { atype: "supportedExtension", vals: ["1.3.6.1.4.1.4203.1.11.1", "1.3.6.1.4.1.4203.1.11.3"] }, LdapPartialAttribute { atype: "supportedControl", vals: [] }, LdapPartialAttribute { atype: "supportedFeatures", vals: ["1.3.6.1.4.1.4203.1.5.1"] }, LdapPartialAttribute { atype: "defaultNamingContext", vals: ["dc=example,dc=com"] }, LdapPartialAttribute { atype: "namingContexts", vals: ["dc=example,dc=com"] }, LdapPartialAttribute { atype: "isGlobalCatalogReady", vals: ["false"] }, LdapPartialAttribute { atype: "subschemaSubentry", vals: ["cn=Subschema"] }] })
2025-09-04T21:01:17.356155635+00:00  DEBUG    ┕━ 🐛 [debug]:  | response: SearchResultDone(LdapResult { code: Success, matcheddn: "", message: "", referral: [] })
2025-09-04T21:01:17.357704818+00:00  DEBUG    HTTP request [ 18.3µs | 100.00% ] method: "GET" | uri: "/health"
2025-09-04T21:01:17.357724104+00:00  DEBUG    ┕━ 🐛 [debug]:  | status_code: 200
2025-09-04T21:01:17.357754522+00:00  INFO     ｉ [info]: LDAP session end: d0224b8e-42ba-412d-89f6-2c32c31e6f2d
2025-09-04T21:01:30.958515067+00:00  INFO     ｉ [info]: SIGTERM received; starting graceful shutdown
2025-09-04T21:01:30.958564149+00:00  DEBUG    🐛 [debug]: paused accepting connections on 0.0.0.0:3890
2025-09-04T21:01:30.958572105+00:00  DEBUG    🐛 [debug]: paused accepting connections on 0.0.0.0:17170
2025-09-04T21:01:30.958574770+00:00  INFO     ｉ [info]: accept thread stopped
2025-09-04T21:01:31.260676181+00:00  INFO     ｉ [info]: DB Cleanup stopped

This was supposed to finish with:

Closing database connections
LLDAP Server shutdown complete

If you have an image somewhere that prints a shutdown message at the end of run_server_command I'm happy to test that as well.

<!-- gh-comment-id:3255700635 --> @thielj commented on GitHub (Sep 4, 2025): Sorry, I can't repo the correct behaviour. ``` docker run --rm -v /data -e UID=1000 -e GID=1000 \ -e LLDAP_JWT_SECRET=SECRET \ -e LLDAP_LDAP_USER_PASS=SECRET12 \ -e LLDAP_VERBOSE=true \ rg.nl-ams.scw.cloud/estrella/lldap:0.6.2-pool ``` I then killed the process manually, just in case. Full log follows. ``` WARNING: A key_seed was given, we will ignore the key_file and generate one from the seed! Set key_file to an empty string in the config to silence this message. root@infra3:/opt/estrella/docker/30-auth# more log [entrypoint] Copying the default config to /data/lldap_config.toml [entrypoint] Edit this file to configure LLDAP. > Setup permissions.. > Starting lldap.. Loading configuration from /data/lldap_config.toml Configuration: Configuration { ldap_host: "0.0.0.0", ldap_port: 3890, http_host: "0.0.0.0", http_port: 17170, jwt_secret: Some( ***SECRET***, ), ldap_base_dn: "dc=example,dc=com", ldap_user_dn: "admin", ldap_user_email: "", ldap_user_pass: Some( ***SECRET***, ), force_ldap_user_pass_reset: False, force_update_private_key: false, db_options: DbOptions { url: "sqlite://users.db?mode=rwc", min_connections: None, max_connections: None, connect_timeout: 3, idle_timeout: 600, max_lifetime: 3600, }, database_url: Some( "sqlite:///data/users.db?mode=rwc", ), ignored_user_attributes: [], key_file: "server_key", key_seed: Some( ***SECRET***, ), assets_path: "./app", smtp_options: MailOptions { enable_password_reset: false, from: None, reply_to: None, server: "localhost", port: 587, user: "", password: ***SECRET***, smtp_encryption: Tls, .. }, ldaps_options: LdapsOptions { enabled: false, port: 6360, cert_file: "cert.pem", key_file: "key.pem", }, http_url: "http://localhost/", .. } DEPRECATED: database_url field is deprecated. You can replace it with db_options.url. 2025-09-04T21:00:47.886726406+00:00 INFO set_up_server [ 456ms | 16.39% / 100.00% ] 2025-09-04T21:00:47.886738579+00:00 INFO ┝━ ｉ [info]: Starting LLDAP version 0.6.2 2025-09-04T21:00:47.893724990+00:00 DEBUG ┝━ get_schema_version [ 618µs | 0.14% ] 2025-09-04T21:00:47.894441902+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: None 2025-09-04T21:00:47.929567830+00:00 DEBUG ┝━ get_schema_version [ 256µs | 0.06% ] 2025-09-04T21:00:47.929854220+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: Some(SchemaVersion(1)) 2025-09-04T21:00:47.929858979+00:00 INFO ┝━ ｉ [info]: Upgrading DB schema from version 1 2025-09-04T21:00:47.929859971+00:00 INFO ┝━ ｉ [info]: Upgrading DB schema to version 2 2025-09-04T21:00:47.973646006+00:00 INFO ┝━ ｉ [info]: Upgrading DB schema to version 3 2025-09-04T21:00:48.013603378+00:00 INFO ┝━ ｉ [info]: Upgrading DB schema to version 4 2025-09-04T21:00:48.022253337+00:00 INFO ┝━ ｉ [info]: Upgrading DB schema to version 5 2025-09-04T21:00:48.094326278+00:00 INFO ┝━ ｉ [info]: Upgrading DB schema to version 6 2025-09-04T21:00:48.096300402+00:00 INFO ┝━ ｉ [info]: Upgrading DB schema to version 7 2025-09-04T21:00:48.100079252+00:00 INFO ┝━ ｉ [info]: Upgrading DB schema to version 8 2025-09-04T21:00:48.102319407+00:00 INFO ┝━ ｉ [info]: Upgrading DB schema to version 9 2025-09-04T21:00:48.104377129+00:00 INFO ┝━ ｉ [info]: Upgrading DB schema to version 10 2025-09-04T21:00:48.141624990+00:00 DEBUG ┝━ list_groups [ 2.12ms | 0.46% ] filters: Some(DisplayName("lldap_admin")) 2025-09-04T21:00:48.172290884+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: [] 2025-09-04T21:00:48.172300001+00:00 WARN ┝━ 🚧 [warn]: Could not find lldap_admin group, trying to create it 2025-09-04T21:00:48.172309749+00:00 DEBUG ┝━ create_group [ 5.43ms | 1.19% ] request: CreateGroupRequest { display_name: "lldap_admin", attributes: [] } 2025-09-04T21:00:48.203357092+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: 1 2025-09-04T21:00:48.203368343+00:00 DEBUG ┝━ list_groups [ 7.14ms | 1.57% ] filters: Some(DisplayName("lldap_password_manager")) 2025-09-04T21:00:48.218168094+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: [] 2025-09-04T21:00:48.218189173+00:00 WARN ┝━ 🚧 [warn]: Could not find lldap_password_manager group, trying to create it 2025-09-04T21:00:48.218193622+00:00 DEBUG ┝━ create_group [ 5.22ms | 1.15% ] request: CreateGroupRequest { display_name: "lldap_password_manager", attributes: [] } 2025-09-04T21:00:48.228207303+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: 2 2025-09-04T21:00:48.228214878+00:00 DEBUG ┝━ list_groups [ 1.90ms | 0.42% ] filters: Some(DisplayName("lldap_strict_readonly")) 2025-09-04T21:00:48.230067463+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: [] 2025-09-04T21:00:48.230071080+00:00 WARN ┝━ 🚧 [warn]: Could not find lldap_strict_readonly group, trying to create it 2025-09-04T21:00:48.230073725+00:00 DEBUG ┝━ create_group [ 6.30ms | 1.38% ] request: CreateGroupRequest { display_name: "lldap_strict_readonly", attributes: [] } 2025-09-04T21:00:48.291953085+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: 3 2025-09-04T21:00:48.291990525+00:00 DEBUG ┝━ list_users [ 7.80ms | 1.71% ] filters: Some(MemberOf("lldap_admin")) | _get_groups: false 2025-09-04T21:00:48.300790097+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: [] 2025-09-04T21:00:48.300794154+00:00 WARN ┝━ 🚧 [warn]: Could not find an admin user, trying to create the user "admin" with the config-provided password 2025-09-04T21:00:48.300806307+00:00 DEBUG ┝━ create_user [ 8.89ms | 1.95% ] request: CreateUserRequest { user_id: "admin", email: "", display_name: Some("Administrator"), attributes: [] } | user_id: "admin" 2025-09-04T21:00:48.305949660+00:00 DEBUG ┝━ register_password [ 332ms | 72.74% / 72.88% ] username: admin 2025-09-04T21:00:48.306037175+00:00 DEBUG │ ┝━ registration_start [ 71.6µs | 0.02% ] 2025-09-04T21:00:48.637331395+00:00 DEBUG │ ┕━ registration_finish [ 543µs | 0.12% ] 2025-09-04T21:00:48.640498129+00:00 INFO │ ┕━ ｉ [info]: Successfully (re)set password for "admin" 2025-09-04T21:00:48.640516784+00:00 DEBUG ┝━ list_groups [ 1.23ms | 0.27% ] filters: Some(DisplayName("lldap_admin")) 2025-09-04T21:00:48.642308795+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: [Group { id: 1, display_name: "lldap_admin", creation_date: 2025-09-04T21:00:48.172310391, uuid: "0da803b3-4b6e-3e6f-b9ea-be15d94fd194", users: [], attributes: [] }] 2025-09-04T21:00:48.642326748+00:00 DEBUG ┝━ add_user_to_group [ 1.72ms | 0.38% ] user_id: "admin" 2025-09-04T21:00:48.677762712+00:00 INFO ┝━ ｉ [info]: Starting the LDAP server on port 3890 2025-09-04T21:00:48.678015648+00:00 DEBUG ┝━ get_jwt_blacklist [ 325µs | 0.07% ] 2025-09-04T21:00:48.678480336+00:00 INFO ┕━ ｉ [info]: Starting the API/web server on port 17170 2025-09-04T21:00:48.681495824+00:00 INFO ｉ [info]: starting 1 workers 2025-09-04T21:00:48.681568522+00:00 INFO ｉ [info]: Actix runtime found; starting in Actix runtime 2025-09-04T21:00:48.681599850+00:00 INFO ｉ [info]: starting service: "ldap", workers: 1, listening on: 0.0.0.0:3890 2025-09-04T21:00:48.681615369+00:00 INFO ｉ [info]: starting service: "http", workers: 1, listening on: 0.0.0.0:17170 2025-09-04T21:00:48.689707977+00:00 INFO ｉ [info]: DB Cleanup Cron started 2025-09-04T21:01:17.355819581+00:00 INFO ｉ [info]: LDAP session start: d0224b8e-42ba-412d-89f6-2c32c31e6f2d 2025-09-04T21:01:17.356080373+00:00 INFO LDAP request [ 89.0µs | 100.00% ] session_id: d0224b8e-42ba-412d-89f6-2c32c31e6f2d 2025-09-04T21:01:17.356094620+00:00 DEBUG ┝━ 🐛 [debug]: | msg: LdapMsg { msgid: 0, op: SearchRequest(LdapSearchRequest { base: "", scope: Base, aliases: Never, sizelimit: 0, timelimit: 0, typesonly: false, filter: Present("objectClass"), attrs: ["supportedExtension"] }), ctrl: [] } 2025-09-04T21:01:17.356098036+00:00 DEBUG ┝━ 🐛 [debug]: rootDSE request 2025-09-04T21:01:17.356112894+00:00 DEBUG ┝━ 🐛 [debug]: | response: SearchResultEntry(LdapSearchResultEntry { dn: "", attributes: [LdapPartialAttribute { atype: "objectClass", vals: ["top"] }, LdapPartialAttribute { atype: "vendorName", vals: ["LLDAP"] }, LdapPartialAttribute { atype: "vendorVersion", vals: ["lldap_0.1.0"] }, LdapPartialAttribute { atype: "supportedLDAPVersion", vals: ["3"] }, LdapPartialAttribute { atype: "supportedExtension", vals: ["1.3.6.1.4.1.4203.1.11.1", "1.3.6.1.4.1.4203.1.11.3"] }, LdapPartialAttribute { atype: "supportedControl", vals: [] }, LdapPartialAttribute { atype: "supportedFeatures", vals: ["1.3.6.1.4.1.4203.1.5.1"] }, LdapPartialAttribute { atype: "defaultNamingContext", vals: ["dc=example,dc=com"] }, LdapPartialAttribute { atype: "namingContexts", vals: ["dc=example,dc=com"] }, LdapPartialAttribute { atype: "isGlobalCatalogReady", vals: ["false"] }, LdapPartialAttribute { atype: "subschemaSubentry", vals: ["cn=Subschema"] }] }) 2025-09-04T21:01:17.356155635+00:00 DEBUG ┕━ 🐛 [debug]: | response: SearchResultDone(LdapResult { code: Success, matcheddn: "", message: "", referral: [] }) 2025-09-04T21:01:17.357704818+00:00 DEBUG HTTP request [ 18.3µs | 100.00% ] method: "GET" | uri: "/health" 2025-09-04T21:01:17.357724104+00:00 DEBUG ┕━ 🐛 [debug]: | status_code: 200 2025-09-04T21:01:17.357754522+00:00 INFO ｉ [info]: LDAP session end: d0224b8e-42ba-412d-89f6-2c32c31e6f2d 2025-09-04T21:01:30.958515067+00:00 INFO ｉ [info]: SIGTERM received; starting graceful shutdown 2025-09-04T21:01:30.958564149+00:00 DEBUG 🐛 [debug]: paused accepting connections on 0.0.0.0:3890 2025-09-04T21:01:30.958572105+00:00 DEBUG 🐛 [debug]: paused accepting connections on 0.0.0.0:17170 2025-09-04T21:01:30.958574770+00:00 INFO ｉ [info]: accept thread stopped 2025-09-04T21:01:31.260676181+00:00 INFO ｉ [info]: DB Cleanup stopped ``` This was supposed to finish with: ``` Closing database connections LLDAP Server shutdown complete ``` If you have an image somewhere that prints a shutdown message at the end of run_server_command I'm happy to test that as well.
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@thielj commented on GitHub (Sep 4, 2025):

Same when running the debug build outside docker, i.e. LLDAP_JWT_SECRET=SECRET LLDAP_LDAP_USER_PASS=SECRET12 LLDAP_VERBOSE=true target/debug/lldap run

...
2025-09-04T21:13:22.282166076+00:00  INFO     ｉ [info]: starting 1 workers
2025-09-04T21:13:22.282199687+00:00  INFO     ｉ [info]: Actix runtime found; starting in Actix runtime
2025-09-04T21:13:22.282222940+00:00  INFO     ｉ [info]: starting service: "ldap", workers: 1, listening on: 0.0.0.0:3890
2025-09-04T21:13:22.282236955+00:00  INFO     ｉ [info]: starting service: "http", workers: 1, listening on: 0.0.0.0:17170
2025-09-04T21:13:22.283076014+00:00  ERROR    🚨 [error]: Specified path is not a directory: "./app/pkg" | log.target: "actix_files::files" | log.module_path: "actix_files::files" | log.file: "/home/jens/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/actix-files-0.6.6/src/files.rs" | log.line: 103
2025-09-04T21:13:22.285972041+00:00  INFO     ｉ [info]: DB Cleanup Cron started
2025-09-04T21:13:46.200484242+00:00  INFO     ｉ [info]: SIGTERM received; starting graceful shutdown
2025-09-04T21:13:46.200859448+00:00  DEBUG    🐛 [debug]: paused accepting connections on 0.0.0.0:3890
2025-09-04T21:13:46.200970813+00:00  DEBUG    🐛 [debug]: paused accepting connections on 0.0.0.0:17170
2025-09-04T21:13:46.201019162+00:00  INFO     ｉ [info]: accept thread stopped
2025-09-04T21:13:46.201091881+00:00  INFO     ｉ [info]: shutting down idle worker
2025-09-04T21:13:46.503132522+00:00  DEBUG    🐛 [debug]: Cryptographic service worker stopped
2025-09-04T21:13:46.503885180+00:00  INFO     ｉ [info]: DB Cleanup stopped
<!-- gh-comment-id:3255717303 --> @thielj commented on GitHub (Sep 4, 2025): Same when running the debug build outside docker, i.e. `LLDAP_JWT_SECRET=SECRET LLDAP_LDAP_USER_PASS=SECRET12 LLDAP_VERBOSE=true target/debug/lldap run` ``` ... 2025-09-04T21:13:22.282166076+00:00 INFO ｉ [info]: starting 1 workers 2025-09-04T21:13:22.282199687+00:00 INFO ｉ [info]: Actix runtime found; starting in Actix runtime 2025-09-04T21:13:22.282222940+00:00 INFO ｉ [info]: starting service: "ldap", workers: 1, listening on: 0.0.0.0:3890 2025-09-04T21:13:22.282236955+00:00 INFO ｉ [info]: starting service: "http", workers: 1, listening on: 0.0.0.0:17170 2025-09-04T21:13:22.283076014+00:00 ERROR 🚨 [error]: Specified path is not a directory: "./app/pkg" | log.target: "actix_files::files" | log.module_path: "actix_files::files" | log.file: "/home/jens/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/actix-files-0.6.6/src/files.rs" | log.line: 103 2025-09-04T21:13:22.285972041+00:00 INFO ｉ [info]: DB Cleanup Cron started 2025-09-04T21:13:46.200484242+00:00 INFO ｉ [info]: SIGTERM received; starting graceful shutdown 2025-09-04T21:13:46.200859448+00:00 DEBUG 🐛 [debug]: paused accepting connections on 0.0.0.0:3890 2025-09-04T21:13:46.200970813+00:00 DEBUG 🐛 [debug]: paused accepting connections on 0.0.0.0:17170 2025-09-04T21:13:46.201019162+00:00 INFO ｉ [info]: accept thread stopped 2025-09-04T21:13:46.201091881+00:00 INFO ｉ [info]: shutting down idle worker 2025-09-04T21:13:46.503132522+00:00 DEBUG 🐛 [debug]: Cryptographic service worker stopped 2025-09-04T21:13:46.503885180+00:00 INFO ｉ [info]: DB Cleanup stopped ```
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@nitnelave commented on GitHub (Sep 4, 2025):

Both logs seem correct, you have the "DB Cleanup stopped" message. In case I wasn't clear, the "Shutting down" message I was talking about is only in my local branch to make sure the correct path is taken, so you're not expected to get it.

<!-- gh-comment-id:3256174787 --> @nitnelave commented on GitHub (Sep 4, 2025): Both logs seem correct, you have the "DB Cleanup stopped" message. In case I wasn't clear, the "Shutting down" message I was talking about is only in my local branch to make sure the correct path is taken, so you're not expected to get it.
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@thielj commented on GitHub (Sep 5, 2025):

And I have messages in my local repo - as mentioned earlier today - right
before and after the code closing the pool. All I can say is that this code
isn't executed - and that I'm not surprised about that either.

On Fri, Sep 5, 2025, 00:03 nitnelave @.***> wrote:

nitnelave left a comment (lldap/lldap#1269)
https://github.com/lldap/lldap/issues/1269#issuecomment-3256174787

Both logs seem correct, you have the "DB Cleanup stopped" message. In case
I wasn't clear, the "Shutting down" message I was talking about is only in
my local branch to make sure the correct path is taken, so you're not
expected to get it.

—
Reply to this email directly, view it on GitHub
https://github.com/lldap/lldap/issues/1269#issuecomment-3256174787, or
unsubscribe
https://github.com/notifications/unsubscribe-auth/AA6CUVOARQMMM7GHISTLO7D3RDAMRAVCNFSM6AAAAACFSAT6Q2VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZTENJWGE3TINZYG4
.
You are receiving this because you were mentioned.Message ID:
@.***>

<!-- gh-comment-id:3256787266 --> @thielj commented on GitHub (Sep 5, 2025): And I have messages in *my* local repo - as mentioned earlier today - right before and after the code closing the pool. All I can say is that this code isn't executed - and that I'm not surprised about that either. On Fri, Sep 5, 2025, 00:03 nitnelave ***@***.***> wrote: > *nitnelave* left a comment (lldap/lldap#1269) > <https://github.com/lldap/lldap/issues/1269#issuecomment-3256174787> > > Both logs seem correct, you have the "DB Cleanup stopped" message. In case > I wasn't clear, the "Shutting down" message I was talking about is only in > my local branch to make sure the correct path is taken, so you're not > expected to get it. > > — > Reply to this email directly, view it on GitHub > <https://github.com/lldap/lldap/issues/1269#issuecomment-3256174787>, or > unsubscribe > <https://github.com/notifications/unsubscribe-auth/AA6CUVOARQMMM7GHISTLO7D3RDAMRAVCNFSM6AAAAACFSAT6Q2VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZTENJWGE3TINZYG4> > . > You are receiving this because you were mentioned.Message ID: > ***@***.***> >
kerem commented 2026-02-27 08:17:21 +03:00
Author
Owner
Copy link

@nitnelave commented on GitHub (Sep 5, 2025):

Are you sure you put the brakes in the right place? The pool closing happens in 2 different places

<!-- gh-comment-id:3257152037 --> @nitnelave commented on GitHub (Sep 5, 2025): Are you sure you put the brakes in the right place? The pool closing happens in 2 different places
kerem commented 2026-02-27 08:17:22 +03:00
Author
Owner
Copy link

@thielj commented on GitHub (Sep 5, 2025):

Yes, they are in the right place. Now that I have removed the sqlx-rqlite dependencies that I was working on, the code is indeed executed.

<!-- gh-comment-id:3258475222 --> @thielj commented on GitHub (Sep 5, 2025): Yes, they are in the right place. Now that I have removed the sqlx-rqlite dependencies that I was working on, the code is indeed executed.
Sign in to join this conversation.
No Branch/Tag specified
Branches Tags
main
dependabot/github_actions/codecov/codecov-action-6
copilot/fix-equality-filters-list-attributes
dependabot/github_actions/docker/build-push-action-7
dependabot/github_actions/docker/metadata-action-6
dependabot/github_actions/docker/setup-buildx-action-4
dependabot/github_actions/docker/login-action-4
copilot/update-download-artifact-action
copilot/fix-opensuse-warnings
copilot/fix-1268
copilot/fix-727
copilot/fix-898
copilot/fix-1256
copilot/fix-1251
copilot/fix-1249
copilot/fix-1206
user-attribute-form
user-ui
group-ui
server-user-attribute-schema
crates
haveibeenpwned
v0.6.2
v0.6.1
v0.6.0
v0.5.0
v0.4.3
v0.4.2
v0.4.1
v0.4.0
v0.3.0
v0.2.0
v0.0.1
Labels
Clear labels   
backend

   
blocked

   
bug

   
cleanup

   
dependencies

   
docker

   
documentation

   
duplicate

   
enhancement

   
enhancement

   
frontend

   
github_actions

   
good first issue

   
help wanted

   
help wanted

   
integration

   
invalid

   
ldap

   
pull-request

Mirrored from GitHub Pull Request

  
question

   
rust

   
rust

   
tests

   
wontfix
No labels
backend
blocked
bug
cleanup
dependencies
docker
documentation
duplicate
enhancement
enhancement
frontend
github_actions
good first issue
help wanted
help wanted
integration
invalid
ldap
pull-request
question
rust
rust
tests
wontfix
Milestone
Clear milestone
No items
No milestone
Projects
Clear projects
No items
No project
Assignees
Clear assignees
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/lldap-lldap#447
No description provided.