On upgrade to v1.6.8, running /bin/indexcontacts.sh generates an error

[sai-mike]

Prerequisites

• [X] I have searched for duplicate or closed issues
• [ ] I can recreate the issue with all plugins disabled

Describe the issue

I upgraded from v1.6.5 to v1.6.8 this morning and attempted to run indexcontacts.sh as instructed in UPGRADING. When I run that script, it generates an error:

ERROR: SQLSTATE[HY000] [1045] Access denied for user 'roundcube'@'localhost' (using password: NO) ERROR: Failed to connect to database

Roundcube is working correctly and I verified the db connection string in config.inc.php:

$config['db_dsnw'] = 'mysql://roundcube:@localhost/roundcube';

The MariaDB error message states "using password: NO" but my connection string has the correct password.

What browser(s) are you seeing the problem on?

Other

What version of PHP are you using?

PHP 8.2.20

What version of Roundcube are you using?

v1.6.8

JavaScript errors

No response

PHP errors

No response

[alecpl]

That db_dsnw does not contain a password.

[sai-mike]

Sorry I removed it for posting, here is the actual string with a changed password:

$config['db_dsnw'] = 'mysql://roundcube:ro1111MT22WB@localhost/roundcube';

[alecpl]

I'm guessing that it could not read config.inc.php file. Maybe the user you executed the script with does not have permissions. Indeed if the file isn't readable no warning is printed.

ps. in master we trigger a warning in such cases.

[sai-mike]

Permissions in the extraction /bin folder:

drwxr-xr-x 2 mike mike 4.0K Aug 4 03:45 . drwxr-xr-x 13 mike mike 4.0K Aug 4 03:45 .. -rwxr-xr-x 1 mike mike 1.3K Aug 4 03:45 cleandb.sh -rwxr-xr-x 1 mike mike 947 Aug 4 03:45 cssshrink.sh -rwxr-xr-x 1 mike mike 2.7K Aug 4 03:45 decrypt.sh -rwxr-xr-x 1 mike mike 4.7K Aug 4 03:45 deluser.sh -rwxr-xr-x 1 mike mike 1.7K Aug 4 03:45 gc.sh -rwxr-xr-x 1 mike mike 1.4K Aug 4 03:45 indexcontacts.sh -rwxr-xr-x 1 mike mike 2.0K Aug 4 03:45 initdb.sh -rwxr-xr-x 1 mike mike 6.3K Aug 4 03:45 installto.sh

Permissions in the roundcube/config directory:

drwxr-xr-x 2 www-data www-data 4.0K Aug 5 14:37 . drwxr-xr-x 12 www-data www-data 4.0K Aug 5 14:56 .. -rw-r--r-- 1 www-data www-data 4.4K Jan 24 2024 config.inc.php -rw-r--r-- 1 www-data www-data 2.9K Jan 13 2024 config.inc.php.sample -rw-r--r-- 1 www-data www-data 64K Aug 4 03:45 defaults.inc.php -rw-r--r-- 1 www-data www-data 164 Jan 13 2024 .htaccess -rw-r--r-- 1 www-data www-data 2.8K Jan 13 2024 mimetypes.php

Run script from the extraction folder using sudo:

mike@sai-web:~/Downloads/roundcubemail-1.6.8$ sudo bin/indexcontacts.sh [sudo] password for mike: ERROR: SQLSTATE[HY000] [1045] Access denied for user 'roundcube'@'localhost' (using password: NO) ERROR: Failed to connect to database

[alecpl]

How about cat config/defaults.inc.php config/config.inc.php | grep db_?

[sai-mike]

Here is the output minus the comments containing db_ in both files. As you can see, I commented out the db_dsnw in defaults.inc.php to see if that fixed the problem and it did not - same error.

// $config['db_dsnw'] = 'mysql://roundcube:@localhost/roundcubemail'; $config['db_dsnr'] = ''; $config['db_dsnw_noread'] = false; $config['db_persistent'] = false; $config['db_prefix'] = ''; $config['db_table_dsn'] = [ $config['db_max_allowed_packet'] = null;

$config['db_dsnw'] = 'mysql://roundcube:ro12345TizWB@localhost/roundcube';

[pabzm]

@sai-mike Please apply this patch, try again (take care to execute the script as user www-data, and show us the content of logs/debug.log.

diff --git a/program/lib/Roundcube/rcube_db.php b/program/lib/Roundcube/rcube_db.php
index dfb19bd8a..9e408dcc5 100644
--- a/program/lib/Roundcube/rcube_db.php
+++ b/program/lib/Roundcube/rcube_db.php
@@ -74,6 +74,7 @@ class rcube_db
     public static function factory($db_dsnw, $db_dsnr = '', $pconn = false)
     {
         $db_dsnw = (string) $db_dsnw;
+        rcube::write_log("debug.log", ['db_dsnw in db factory' => $db_dsnw]);
         $driver = strtolower(substr($db_dsnw, 0, strpos($db_dsnw, ':')));
         $driver_map = [
             'sqlite2' => 'sqlite',

[sai-mike]

I added the debug logging and ran the script again as www-data:

www-data@sai-web:/tmp/roundcubemail-1.6.9$ bin/indexcontacts.sh ERROR: SQLSTATE[HY000] [1045] Access denied for user 'roundcube'@'localhost' (using password: NO) ERROR: Failed to connect to database

I now have a number of errors logged in /logs/errors.log. These appear as single errors or a group with the same timestamp:

[16-Sep-2024 17:53:00 UTC] PHP Warning: file_put_contents(/var/www/mail.sierraai.com/logs/debug.log.log): Failed to open stream: Permission denied in /var/www/mail.sierraai.com/program/lib/Roundcube/rcube.php on line 1380 [16-Sep-2024 17:53:04 UTC] PHP Warning: file_put_contents(/var/www/mail.sierraai.com/logs/debug.log.log): Failed to open stream: Permission denied in /var/www/mail.sierraai.com/program/lib/Roundcube/rcube.php on line 1380 [16-Sep-2024 17:53:04 UTC] PHP Warning: file_put_contents(/var/www/mail.sierraai.com/logs/debug.log.log): Failed to open stream: Permission denied in /var/www/mail.sierraai.com/program/lib/Roundcube/rcube.php on line 1380 [16-Sep-2024 17:53:04 UTC] PHP Warning: file_put_contents(/var/www/mail.sierraai.com/logs/debug.log.log): Failed to open stream: Permission denied in /var/www/mail.sierraai.com/program/lib/Roundcube/rcube.php on line 1380

This is logged in /logs/debug.log.log. These seem to be logged once per minute (password obfuscated):

[16-Sep-2024 17:57:01 +0000]: array ( 'db_dsnw in db factory' => 'mysql://roundcube:roxxxxxxxxxx@localhost/roundcube', ) [16-Sep-2024 17:58:01 +0000]: array ( 'db_dsnw in db factory' => 'mysql://roundcube:roxxxxxxxxxx@localhost/roundcube', ) [16-Sep-2024 17:59:01 +0000]: array ( 'db_dsnw in db factory' => 'mysql://roundcube:roxxxxxxxxxx@localhost/roundcube', )

[pabzm]

'db_dsnw in db factory' => 'mysql://roundcube:roxxxxxxxxxx@localhost/roundcube',

Are these details from the log correct?

Please show uns the output of ls -la logs/debug.log.log.

This looks a little bit like you're the user running Roundcube is a different one than the user executing the script.

[sai-mike]

The username & password in debug.log.log matches my config file line: $config['db_dsnw'] =

The debug.log.log file was owned by root:root. I changed this to www-data:www-data, re-ran the script, and now the errors have stopped in errors.log:

root@sai-web:/var/www/mail.sierraai.com/logs# ls -la debug.log.log -rw-r--r-- 1 www-data www-data 8610 Sep 17 15:20 debug.log.log

The current logging in debug.log.log is the same as above.

I am using 'sudo su - www-data -s /bin/bash' to run the script.

The output of Apache2 mod_status shows the Roundcube virtualhost is also being run by www-data:

From Apache mod_status: Srv PID VHost 12-0 3406175 mail.sierraai.com:443

root@sai-web:~# pgrep -u www-data 919581 919582 3406148 3406149 3406150 3406151 3406152 3406158 3406165 3406174 3406175 3406176

[pabzm]

The debug.log.log file was owned by root:root

That means you at least once executed the script as root, after applying the patch.

Could you please remove logs/debug.log.log, stop Roundcube for a moment, then execute sudo -u www-data ./bin/indexcontacts.sh, then read logs/debug.log.log and paste it here? (Just to be sure we're actually looking at the logging statements from the script here.)

Also I noticed that in the grep output you posted this line:

$config['db_table_dsn'] = [

Can you please double-check if that line as actually present exactly like this in your config file or if this is a copy&paste error?

[sai-mike]

Here is the output when I run the script with Roundcube temporarily disabled:

mike@sai-web:/tmp/roundcubemail-1.6.9$ sudo -u www-data ./bin/indexcontacts.sh ERROR: SQLSTATE[HY000] [1045] Access denied for user 'roundcube'@'localhost' (using password: NO) ERROR: Failed to connect to database

If I run ls -la on the logs directory right after executing the script, the debug.log.log file is owned by root, not www-data:

drwxr-xr-x 2 www-data www-data 4.0K Sep 22 15:54 . drwxr-xr-x 12 www-data www-data 4.0K Sep 2 19:18 .. -rw-r--r-- 1 root root 369 Sep 22 15:56 debug.log.log -rw-r--r-- 1 www-data www-data 92K Sep 22 15:05 errors.log -rw-r--r-- 1 www-data www-data 164 Jan 13 2024 .htaccess -rw-r--r-- 1 www-data www-data 14K Aug 8 15:19 sql.log

I have to run chown and change the ownership to www-data:www-data to prevent errors being logged to errors.log

Here are the contents of debug.log.log prior to restarting Roundcube (passwords redacted):

mike@sai-web:/var/www/mail.sierraai.com/logs$ cat debug.log.log '[22-Sep-2024 21:54:01 +0000]: array ( 'db_dsnw in db factory' => 'mysql://roundcube:roxxxxxxxxxx@localhost/roundcube', ) [22-Sep-2024 21:55:01 +0000]: array ( 'db_dsnw in db factory' => 'mysql://roundcube:roxxxxxxxxxx@localhost/roundcube', ) [22-Sep-2024 21:56:01 +0000]: array ( 'db_dsnw in db factory' => 'mysql://roundcube:roxxxxxxxxxx@localhost/roundcube', ) [22-Sep-2024 21:57:01 +0000]: array ( 'db_dsnw in db factory' => 'mysql://roundcube:roxxxxxxxxxx@localhost/roundcube', )

The $config['db_table_dsn'] string in the config file is exactly the same as the string in debug.log.log:

'db_dsnw in db factory' => 'mysql://roundcube:roxxxxxxxxxx@localhost/roundcube', $config['db_dsnw'] = 'mysql://roundcube:roxxxxxxxxxx@localhost/roundcube';

[pabzm]

I'm sorry but I have currently no further idea what the problem in your case might be. Since you're the only one reporting this problem, I'm assuming it has to do with your local setup and is not a bug in Roundcube. Please let us know if you have any indication of the opposite.

Also, if you find (or already found) the cause, please note it here, as a reference for the future (and to my enlightenment, I'm curious).