GET /users.json is 100x slower than GET /resources.json (Passbolt CE 4.12.1)

Hello.

I have deployed Passbolt in a GCE virtual machine using Docker Compose (YAML is at the bottom of this post).

When I open the Passbolt app in a browser and go to /app/users, the app tries to list the users in our Passbolt instance by doing a GET request to the /users.json endpoint. This request takes about 50 seconds to complete, even though loading resources/passwords via a GET /resources.json endpoint request (when browsing the app/passwords page) takes about 0.5 seconds to complete. I see no high CPU/RAM usage when the VM is processing the GET /users.json request (the CPU usage is about 10 % and RAM usage is about 20 % - the VM has 2 vCPUs and 4 GB of RAM - e2-medium GCE instance).

I see no obvious reason that the GET /users.json endpoint should be 100x slower than the GET /resources.json endpoint. Can anyone help me fix this problem? I am using the latest Community edition Passbolt release (4.12.1), and the latest MariaDB release (11.7.2) as you can see in the Docker Compose YAML.

This is the exact slow request with all GET parameters:

GET /users.json?api-version=v2&contain%5Bprofile%5D=1&contain%5Bgpgkey%5D=0&contain%5Bgroups_users%5D=0&contain%5Bpending_account_recovery_request%5D=1&contain%5Baccount_recovery_user_setting%5D=1&contain%5BLastLoggedIn%5D=1

Sometimes the GET /users.json endpoint is not only slow, but returns a 504 (Gateway Time-out) status code:

passbolt  | 2025/04/09 11:18:13 [error] 124#124: *3525 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 172.19.0.2, server: _, request: "GET /users.json?api-version=v2&contain%5Bprofile%5D=1&contain%5Bgpgkey%5D=0&contain%5Bgroups_users%5D=0&contain%5Bpending_account_recovery_request%5D=1&contain%5Baccount_recovery_user_setting%5D=1&contain%5BLastLoggedIn%5D=1 HTTP/1.1", upstream: "fastcgi://unix:/run/php/php8.2-fpm.sock", host: "CENSORED"
passbolt  | 172.19.0.2 - - [09/Apr/2025:11:18:13 +0000] "GET /users.json?api-version=v2&contain%5Bprofile%5D=1&contain%5Bgpgkey%5D=0&contain%5Bgroups_users%5D=0&contain%5Bpending_account_recovery_request%5D=1&contain%5Baccount_recovery_user_setting%5D=1&contain%5BLastLoggedIn%5D=1 HTTP/1.1" 504 562 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36"

docker-compose.yml:

services:
  db:
    container_name: passbolt_db
    image: mariadb@sha256:310d29fbb58169dcddb384b0ff138edb081e2773d6e2eceb976b3668089f2f84 # tag 11.7.2
    env_file:
      - env/mysql.env
    volumes:
      - passbolt_database_volume:/var/lib/mysql
    # ports:
    #   - "127.0.0.1:3306:3306" # Uncomment for direct DB access from the host system
    networks:
      - database
    restart: always

  passbolt:
    container_name: passbolt
    image: passbolt/passbolt@sha256:2de4f7ce60fe05dd77b5d0e03fe7ef5e35fc2dd08b78f578d1064e019f0bc585 # tag latest-ce/4.12.1-1-ce
    tty: true
    depends_on:
      - db
    env_file:
      - env/passbolt.env
      - env/passbolt.secret.env
    volumes:
      - passbolt_gpg_volume:/etc/passbolt/gpg
      - passbolt_images_volume:/usr/share/php/passbolt/webroot/img/public
    command:
      [
        "/usr/bin/wait-for.sh",
        "-t",
        "0",
        "db:3306",
        "--",
        "/docker-entrypoint.sh"
      ]
    networks:
      - reverse_proxy
      - database
    restart: always

  caddy:
    container_name: passbolt_caddy
    image: caddy@sha256:cf1bd22f2415bc99b785ece1df2c49d32985ac4ac42d84df335be17350593693 # tag 2.9.1
    ports:
      - "80:80"
      - "443:443"
      - "443:443/udp"
    volumes:
      - ./caddy/Caddyfile:/etc/caddy/Caddyfile
      - passbolt_caddy_data:/data
      - passbolt_caddy_config:/config
    networks:
      - reverse_proxy
    restart: always

volumes:  # Must already exist - they are created with the initial_setup.sh script
  passbolt_database_volume:
    external: true
  passbolt_gpg_volume:
    external: true
  passbolt_images_volume:
    external: true
  passbolt_caddy_data:
    external: true
  passbolt_caddy_config:
    external: true

networks:
  default:
    driver: none # Disabling the default network
  reverse_proxy:
  database:

I would appreciate any solutions or debugging options.

Thanks.

Hey @FrantisekN-RevoltBI, welcome to the community forum :waving_hand:

I had a look at the problem you are facing and it’s unusual situation. We would need more info in order to help you debug the issue. Here are the some things we would need from you:

  1. Number of records in the database. Run below SQL queries into your database and share the results with us.

    SELECT COUNT(*) FROM users;
    SELECT COUNT(*) FROM groups;
    SELECT COUNT(*) FROM groups_users;
    SELECT COUNT(*) FROM action_logs;
    
  2. To know which SQL query is slow, you can enable the slow query logs. Here’s the step - https://mariadb.com/kb/en/slow-query-log-overview/

  3. Browser extension logs to know which endpoint is taking time and if any HTTP requests are blocking others. Here’s how you enable the Browser extension logs - https://www.passbolt.com/docs/hosting/troubleshooting/logs/#browser-extension

Regards,
Ishan

Hello. Thanks for the reply. Could I share these things with you privately somehow? I am not comfortable publishing entire unedited logs. I could send you an email, I guess, if you give me your address. @ishan

@ishan
Anyway, here are the row counts:

MariaDB [passbolt]> SELECT COUNT(*) FROM users;
+----------+
| COUNT(*) |
+----------+
|      214 |
+----------+
1 row in set (0.001 sec)

MariaDB [passbolt]> SELECT COUNT(*) FROM groups;
+----------+
| COUNT(*) |
+----------+
|       49 |
+----------+
1 row in set (0.016 sec)

MariaDB [passbolt]> SELECT COUNT(*) FROM groups_users;
+----------+
| COUNT(*) |
+----------+
|      279 |
+----------+
1 row in set (0.048 sec)

MariaDB [passbolt]> SELECT COUNT(*) FROM action_logs;
+----------+
| COUNT(*) |
+----------+
|  1829043 |
+----------+
1 row in set (49.161 sec)

Notably, the SELECT COUNT(*) FROM action_logs; query took almost 50 seconds to run.

Hey @FrantisekN-RevoltBI, the slow endpoint can be due to large number of data in the action_logs table. Can you use action_logs_purge command and see if it improves the performance? See more on How to purge the action logs.

When I ran it, it only deleted 100 records.

root@114115846a4c:/usr/share/php/passbolt# su -s /bin/bash -c "/usr/share/php/passbolt/bin/cake passbolt action_
logs_purge --dry-run -r 90" www-data

     ____                  __          ____  
    / __ \____  _____ ____/ /_  ____  / / /_ 
   / /_/ / __ `/ ___/ ___/ __ \/ __ \/ / __/ 
  / ____/ /_/ (__  |__  ) /_/ / /_/ / / /    
 /_/    \__,_/____/____/_.___/\____/_/\__/   

 Open source password manager for teams
-------------------------------------------------------------------------------
+------------------------------------+---------+
| Action                             | Count   |
+------------------------------------+---------+
| ResourcesIndex.index               | 602011  |
| UsersView.view                     | 219757  |
| SettingsIndex.index                | 145748  |
| GroupsIndex.index                  | 37443   |
| UsersIndex.index                   | 36552   |
| GetCsrfToken.get                   | 31042   |
| Home.apiExtApp                     | 12759   |
| AccountSettingsIndex.index         | 12240   |
| ResourceTypesIndex.index           | 11432   |
| RolesIndex.index                   | 10995   |
| FoldersIndex.index                 | 10382   |
| PasswordGeneratorSettings.index    | 7584    |
| ResourcesView.view                 | 4819    |
| Home.view                          | 3398    |
| ShareSearch.searchArosToShareWith  | 2398    |
| GpgkeysIndex.index                 | 2166    |
| Share.dryRun                       | 1166    |
| AuthVerify.verifyGet               | 658     |
| CommentsView.view                  | 311     |
| PermissionsView.viewAcoPermissions | 245     |
| GroupsView.view                    | 203     |
| Home.apiApp                        | 59      |
| NotificationOrgSettingsGet.get     | 33      |
| ThemesIndex.index                  | 29      |
| MfaOrgSettingsGet.get              | 23      |
| MfaSetupSelectProvider.get         | 12      |
| HealthcheckStatus.status           | 6       |
| TotpSetupGet.get                   | 1       |
| Total                              | 1153472 |
+------------------------------------+---------+
root@114115846a4c:/usr/share/php/passbolt# su -s /bin/bash -c "/usr/share/php/passbolt/bin/cake passbolt action_logs_purge -r 90" www-data



     ____                  __          ____  
    / __ \____  _____ ____/ /_  ____  / / /_ 
   / /_/ / __ `/ ___/ ___/ __ \/ __ \/ / __/ 
  / ____/ /_/ (__  |__  ) /_/ / /_/ / / /    
 /_/    \__,_/____/____/_.___/\____/_/\__/   

 Open source password manager for teams
-------------------------------------------------------------------------------
100 action logs entries were deleted.
root@114115846a4c:/usr/share/php/passbolt# su -s /bin/bash -c "/usr/share/php/passbolt/bin/cake passbolt action_logs_purge --dry-run -r 90" www-data

     ____                  __          ____  
    / __ \____  _____ ____/ /_  ____  / / /_ 
   / /_/ / __ `/ ___/ ___/ __ \/ __ \/ / __/ 
  / ____/ /_/ (__  |__  ) /_/ / /_/ / / /    
 /_/    \__,_/____/____/_.___/\____/_/\__/   

 Open source password manager for teams
-------------------------------------------------------------------------------
+------------------------------------+---------+
| Action                             | Count   |
+------------------------------------+---------+
| ResourcesIndex.index               | 602011  |
| UsersView.view                     | 219757  |
| SettingsIndex.index                | 145748  |
| GroupsIndex.index                  | 37443   |
| UsersIndex.index                   | 36552   |
| GetCsrfToken.get                   | 31042   |
| Home.apiExtApp                     | 12688   |
| AccountSettingsIndex.index         | 12240   |
| ResourceTypesIndex.index           | 11432   |
| RolesIndex.index                   | 10995   |
| FoldersIndex.index                 | 10382   |
| PasswordGeneratorSettings.index    | 7584    |
| ResourcesView.view                 | 4819    |
| Home.view                          | 3398    |
| ShareSearch.searchArosToShareWith  | 2398    |
| GpgkeysIndex.index                 | 2166    |
| Share.dryRun                       | 1166    |
| AuthVerify.verifyGet               | 658     |
| CommentsView.view                  | 311     |
| PermissionsView.viewAcoPermissions | 245     |
| GroupsView.view                    | 203     |
| Home.apiApp                        | 59      |
| NotificationOrgSettingsGet.get     | 33      |
| MfaOrgSettingsGet.get              | 23      |
| MfaSetupSelectProvider.get         | 12      |
| HealthcheckStatus.status           | 6       |
| TotpSetupGet.get                   | 1       |
| Total                              | 1153372 |
+------------------------------------+---------+

When I ran the count query again, it was still slow:

MariaDB [passbolt]> SELECT COUNT(*) FROM action_logs;
+----------+
| COUNT(*) |
+----------+
|  1317037 |
+----------+
1 row in set (33.045 sec)

This was from my test instance with slightly out of date data, but the behaviour is approximately the same as the production instance.

Maybe I just need different arguments for the purge command.

@ishan

There’s might a problem with the limit, can you add -l option with the command and re-run?
Example:

su -s /bin/bash -c "/usr/share/php/passbolt/bin/cake passbolt action_logs_purge -r 90 -l 1200000" www-data

You can also reduce retention days (-r option) to let’s say 30 (instead of 90) to delete more records.

Thanks. I will try to purge the action logs as you suggest and see if things improve.

In the meantime, here is the slow query log from MariaDB:

mariadbd, Version: 11.7.2-MariaDB-ubu2404-log (mariadb.org binary distribution). started with:
Tcp port: 0  Unix socket: /run/mysqld/mysqld.sock
Time                Id Command  Argument
# Time: 250423 15:25:05
# User@Host: passbolt[passbolt] @  [172.18.0.3]
# Thread_id: 56  Schema: passbolt  QC_hit: No
# Query_time: 8.381814  Lock_time: 0.000245  Rows_sent: 62  Rows_examined: 169749
# Rows_affected: 0  Bytes_sent: 26633
# Pages_accessed: 2274  Pages_read: 1733  Pages_prefetched: 0  Pages_updated: 0  Old_rows_read: 0
# Pages_read_time: 8041.0267  Engine_time: 8137.4887
# Tmp_tables: 1  Tmp_disk_tables: 0  Tmp_table_sizes: 1572800
# Full_scan: Yes  Full_join: No  Tmp_table: Yes  Tmp_table_on_disk: No
# Filesort: Yes  Filesort_on_disk: No  Merge_passes: 0  Priority_queue: No
#
# explain: id   select_type     table   type    possible_keys   key     key_len ref     rows    r_rows  filteredr_filtered      Extra
# explain: 1    PRIMARY Users   ALL     deleted NULL    NULL    NULL    187     62.00   33.69   100.00  Using where; Using filesort
# explain: 1    PRIMARY Profiles        ref     user_id user_id 36      passbolt.Users.id       1       1.00   100.00   100.00
# explain: 1    PRIMARY Avatars ref     profile_id      profile_id      36      passbolt.Profiles.id    1      0.03     100.00  100.00  Using where
# explain: 1    PRIMARY Roles   eq_ref  PRIMARY PRIMARY 36      passbolt.Users.role_id  1       1.00    100.00 100.00
# explain: 2    DEPENDENT SUBQUERY      ActionLogs      ref     status,action_id_2,user_id_2    user_id_2      37       passbolt.Users.id       252     2731.74 12.98   5.76    Using where; Using index
#
use `passbolt`;
SET timestamp=1745421905;
SELECT (SELECT (MAX(`ActionLogs`.`created`)) AS `last_logged_in` FROM `action_logs` `ActionLogs` WHERE (`ActionLogs`.`action_id` IN ('a3c19ad2-8920-5395-86d0-8567cb34f382','28c0972b-e6a2-5d44-a5cb-bc2d11799cc1') AND `ActionLogs`.`status` = 1 AND `ActionLogs`.`user_id` = `Users`.`id`) LIMIT 1) AS `last_logged_in`, `Users`.`id` AS `Users__id`, `Users`.`role_id` AS `Users__role_id`, `Users`.`username` AS `Users__username`, `Users`.`active` AS `Users__active`, `Users`.`deleted` AS `Users__deleted`, `Users`.`disabled` AS `Users__disabled`, `Users`.`created` AS `Users__created`, `Users`.`modified` AS `Users__modified`, `Roles`.`id` AS `Roles__id`, `Roles`.`name` AS `Roles__name`, `Roles`.`description` AS `Roles__description`, `Roles`.`created` AS `Roles__created`, `Roles`.`modified` AS `Roles__modified`, `Profiles`.`id` AS `Profiles__id`, `Profiles`.`user_id` AS `Profiles__user_id`, `Profiles`.`first_name` AS `Profiles__first_name`, `Profiles`.`last_name` AS `Profiles__last_name`, `Profiles`.`created` AS `Profiles__created`, `Profiles`.`modified` AS `Profiles__modified`, `Avatars`.`id` AS `Avatars__id`, `Avatars`.`profile_id` AS `Avatars__profile_id`, `Avatars`.`created` AS `Avatars__created`, `Avatars`.`modified` AS `Avatars__modified` FROM `users` `Users` INNER JOIN `roles` `Roles` ON `Roles`.`id` = `Users`.`role_id` LEFT JOIN `profiles` `Profiles` ON `Users`.`id` = `Profiles`.`user_id` LEFT JOIN `avatars` `Avatars` ON `Profiles`.`id` = `Avatars`.`profile_id` WHERE (`Users`.`deleted` = 0 AND `Users`.`role_id` <> '75628d16-27cc-4e01-8c73-b9228116a969' AND `Users`.`active` = 1) ORDER BY `Users`.`username` asc LIMIT 1000000 OFFSET 0;

It seems like due to large data inside action_logs table the query has to examine approx ~169k records which can be slow. You can try purging old records from the action_logs table and notice the improvement.

Yep. Action logs purge did solve the issue. I have also optimized the table by running:

OPTIMIZE TABLE action_logs;

inside MariaDB to defragment the table after most of its rows got deleted.

Maybe consider doing that as part of the action logs purge procedure by default. @ishan

Also consider making Passbolt run the purge by itself every once in a while.

1 Like

Thanks for the confirmation, I’m glad it got fixed.

Regarding your suggestion to add the OPTIMIZE TABLE part of action logs purge command, we can’t do that as it can have side-effects because table gets locked during the command execution and it can cause passbolt to now work properly (causing a downtime). We’ll explore it in future but we don’t have anything planned at the moment.