NethServer Version: NS8B2 on Debian12 minimal install Module: Roundcube
VirtualBox 7.0.10 rt158379 (QT5.15.3)
DISK: 60GB on SSD
RAM 16GB // 2 CPU
vendor_id : GenuineIntel
cpu family : 6
model : 26
model name : Intel(R) Xeon(R) CPU W3520 @ 2.67GHz
stepping : 5
cpu MHz : 2666.672
cache size : 8192 KB
...
bogomips : 5333.34
It happened to me many time before.
2023-09-26T11:18:04-04:00 [1:roundcubemail1:roundcubemail-app] No security vulnerability advisories found
2023-09-26T11:18:04-04:00 [1:roundcubemail1:roundcubemail-app] wait-for-it.sh: waiting 30 seconds for 127.0.0.1:3306
2023-09-26T11:18:04-04:00 [1:roundcubemail1:mariadb-app] 2023-09-26 15:18:04 4 [Warning] Aborted connection 4 to db: 'unconnected' user: 'unauthenticated' host: '127.0.0.1' (This connection closed normally without authentication)
2023-09-26T11:18:04-04:00 [1:roundcubemail1:roundcubemail-app] wait-for-it.sh: 127.0.0.1:3306 is available after 0 seconds
2023-09-26T11:18:04-04:00 [1:roundcubemail1:roundcubemail-app] Write Docker config to /var/www/html/config/config.docker.inc.php
2023-09-26T11:18:04-04:00 [1:roundcubemail1:roundcubemail-app] Checking for database schema updates...
2023-09-26T11:18:04-04:00 [1:roundcubemail1:roundcubemail-app] Updating database schema (2013061000)... [FAILED]
2023-09-26T11:18:04-04:00 [1:roundcubemail1:roundcubemail-app] ERROR: Error in DDL upgrade 2013061000: [1146] Table 'roundcubemail.cache' doesn't exist
2023-09-26T11:18:04-04:00 [1:roundcubemail1:roundcubemail-app] Failed to initialize/update the database. Please start with an empty database and restart the container.
2023-09-26T11:18:04-04:00 [1:roundcubemail1:roundcubemail-app] Generating locales (this might take a while)...
2023-09-26T11:18:06-04:00 [1:roundcubemail1:roundcubemail-app] en_US.UTF-8... done
2023-09-26T11:18:06-04:00 [1:roundcubemail1:roundcubemail-app] Generation complete.
2023-09-26T11:18:06-04:00 [1:roundcubemail1:roundcubemail-app] AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 10.0.2.100. Set the 'ServerName' directive globally to suppress this message
2023-09-26T11:18:06-04:00 [1:roundcubemail1:roundcubemail-app] AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 10.0.2.100. Set the 'ServerName' directive globally to suppress this message
2023-09-26T11:18:06-04:00 [1:roundcubemail1:roundcubemail-app] [Tue Sep 26 15:18:06.656174 2023] [mpm_prefork:notice] [pid 1] AH00163: Apache/2.4.57 (Debian) PHP/8.1.22 configured -- resuming normal operations
2023-09-26T11:18:06-04:00 [1:roundcubemail1:roundcubemail-app] [Tue Sep 26 15:18:06.656350 2023] [core:notice] [pid 1] AH00094: Command line: 'apache2 -D FOREGROUND'
2023-09-26T11:20:48-04:00 [1:roundcubemail1:agent@roundcubemail1] task/module/roundcubemail1/2a27df48-1bc9-4d47-aad3-81781d9424f1: get-name/50get_name is starting
2023-09-26T11:20:48-04:00 [1:roundcubemail1:agent@roundcubemail1] task/module/roundcubemail1/d98f0641-d487-4c25-a7e6-5922bd255902: get-status/20read is starting
2023-09-26T11:20:48-04:00 [1:roundcubemail1:agent@roundcubemail1] task/module/roundcubemail1/2a27df48-1bc9-4d47-aad3-81781d9424f1: action "get-name" status is "completed" (0) at step 50get_name
2023-09-26T11:20:49-04:00 [1:roundcubemail1:agent@roundcubemail1] task/module/roundcubemail1/d98f0641-d487-4c25-a7e6-5922bd255902: action "get-status" status is "completed" (0) at step validate-output.json
2023-09-26T11:20:50-04:00 [1:roundcubemail1:agent@roundcubemail1] task/module/roundcubemail1/a16a9296-9a28-4bed-ba8e-8e748785909a: get-configuration/20read is starting
2023-09-26T11:20:51-04:00 [1:roundcubemail1:agent@roundcubemail1] task/module/roundcubemail1/a16a9296-9a28-4bed-ba8e-8e748785909a: action "get-configuration" status is "completed" (0) at step validate-output.json
2023-09-26T11:21:00-04:00 [1:roundcubemail1:roundcubemail-app] errors: <c32777d0> DB Error: [1146] Table 'roundcubemail.session' doesn't exist (SQL Query: SELECT `vars`, `ip`, `changed`, now() AS ts, CASE WHEN `changed` < now() - INTERVAL 600 SECOND THEN 1 ELSE 0 END AS expired FROM `session` WHERE `sess_id` = 'c32777d05f00dff4e19d54f6feee1d90') in /var/www/html/program/lib/Roundcube/rcube_db.php on line 567 (GET /)
2023-09-26T11:21:00-04:00 [1:roundcubemail1:roundcubemail-app] errors: <c32777d0> DB Error: [1146] Table 'roundcubemail.session' doesn't exist (SQL Query: INSERT INTO `session` (`sess_id`, `vars`, `ip`, `changed`) VALUES ('c32777d05f00dff4e19d54f6feee1d90', 'dGVtcHxiOjE7bGFuZ3VhZ2V8czo1OiJmcl9GUiI7dGFza3xzOjU6ImxvZ2luIjtza2luX2NvbmZpZ3xhOjc6e3M6MTc6InN1cHBvcnRlZF9sYXlvdXRzIjthOjE6e2k6MDtzOjEwOiJ3aWRlc2NyZWVuIjt9czoyMjoianF1ZXJ5X3VpX2NvbG9yc190aGVtZSI7czo5OiJib290c3RyYXAiO3M6MTg6ImVtYmVkX2Nzc19sb2NhdGlvbiI7czoxNzoiL3N0eWxlcy9lbWJlZC5jc3MiO3M6MTk6ImVkaXRvcl9jc3NfbG9jYXRpb24iO3M6MTc6Ii9zdHlsZXMvZW1iZWQuY3NzIjtzOjE3OiJkYXJrX21vZGVfc3VwcG9ydCI7YjoxO3M6MjY6Im1lZGlhX2Jyb3dzZXJfY3NzX2xvY2F0aW9uIjtzOjQ6Im5vbmUiO3M6MjE6ImFkZGl0aW9uYWxfbG9nb190eXBlcyI7YTozOntpOjA7czo0OiJkYXJrIjtpOjE7czo1OiJzbWFsbCI7aToyO3M6MTA6InNtYWxsLWRhcmsiO319', '10.0.2.100', now())) in /var/www/html/program/lib/Roundcube/rcube_db.php on line 567 (GET /)
2023-09-26T11:21:00-04:00 [1:roundcubemail1:roundcubemail-app] 10.0.2.100 - - [26/Sep/2023:15:21:00 +0000] "GET / HTTP/1.1" 200 950 "-" "Mozilla/5.0 (Windows NT 6.3; Win64; x64; rv:109.0) Gecko/20100101 Firefox/115.0"
2023-09-26T11:21:00-04:00 [1:roundcubemail1:roundcubemail-app] 10.0.2.100 - - [26/Sep/2023:15:21:00 +0000] "GET /favicon.ico HTTP/1.1" 200 1991 "https://roundcubemail.debian.toto-dev.org/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64; rv:109.0) Gecko/20100101 Firefox/115.0"
Intel(R) Xeon(R) CPU W3520 release date of the processor Q01/2009
probably a slow processor and roundcubemail is starting to request to mariadb before this one has not finished to start. We need to implement a check I think
This works as expected.
In the log one can see that the connection to the database re-checked until it finally becomes operational.
This seems to solve the race condition.