Skip to content

Conversation

@J0WI
Copy link
Contributor

@J0WI J0WI commented Jul 9, 2019

Should be merged before #6236


# Make sure that Apache is listening and ready
. "$dir/../../retry.sh" --tries 30 '_request GET / --output /dev/null'
. "$dir/../../retry.sh" --tries 50 --sleep 5 '_request GET / --output /dev/null'
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

From 1 minute to over 4; that seems excessive with 4 tests on each of up to 18 distinct images (5 tests, but only 4 are used on each specific image).

@tianon
Copy link
Member

tianon commented Aug 9, 2019

Looking at the output from a build test of #6438, it appears the installation is completing successfully but something else is preventing the tests from passing:

$ test/run.sh nextcloud:15.0.10-apache
testing nextcloud:15.0.10-apache
	'utc' [1/8]...passed
	'cve-2014--shellshock' [2/8]...passed
	'no-hard-coded-passwords' [3/8]...passed
	'override-cmd' [4/8]...passed
	'nextcloud-cli-mysql' [5/8]..............passed
	'nextcloud-cli-postgres' [6/8]................................the container failed to accept connections in a reasonable amount of time!
++ docker logs 06b1ca675dd119c46cd4430a69a8705eea0104dd6ad6c626de2c946bc11aad4a
Initializing nextcloud 15.0.10.0 ...
Initializing finished
New nextcloud instance
Installing with PostgreSQL database
starting nextcloud installation
Error while trying to create admin user: Failed to connect to the database: An exception occured in driver: SQLSTATE[08006] [7] could not connect to server: Connection refused
	Is the server running on host "postgres" (172.17.0.5) and accepting
	TCP/IP connections on port 5432?
 -> 
retrying install...
Error while trying to create admin user: Failed to connect to the database: An exception occured in driver: SQLSTATE[08006] [7] could not connect to server: Connection refused
	Is the server running on host "postgres" (172.17.0.5) and accepting
	TCP/IP connections on port 5432?
 -> 
retrying install...
Error while trying to create admin user: Failed to connect to the database: An exception occured in driver: SQLSTATE[08006] [7] could not connect to server: Connection refused
	Is the server running on host "postgres" (172.17.0.5) and accepting
	TCP/IP connections on port 5432?
 -> 
retrying install...
Nextcloud was successfully installed
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.17.0.6. Set the 'ServerName' directive globally to suppress this message
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.17.0.6. Set the 'ServerName' directive globally to suppress this message
[Fri Aug 09 21:31:41.492853 2019] [mpm_prefork:notice] [pid 1] AH00163: Apache/2.4.38 (Debian) PHP/7.3.8 configured -- resuming normal operations
[Fri Aug 09 21:31:41.492883 2019] [core:notice] [pid 1] AH00094: Command line: 'apache2 -D FOREGROUND'
failed
	'nextcloud-cli-sqlite' [7/8]....passed
	'nextcloud-apache-run' [8/8]....passed

In testing, it seems to typically finish in ~10 retries, so I really don't think bumping the retries is the right fix here. I think there's something else going on to make this not work sometimes.

@tianon
Copy link
Member

tianon commented Aug 9, 2019

Managed to reproduce via loop:

$ while ./test/tests/nextcloud-cli-postgres/run.sh nextcloud:15.0.10-apache; do echo; done; echo
..........
.............................the container failed to accept connections in a reasonable amount of time!
++ docker logs ce318efb3f289a638ce76a562f9e8b9ce4c3b0dfbb83530de7d20749e6b93b58
Initializing nextcloud 15.0.10.0 ...
Initializing finished
New nextcloud instance
Installing with PostgreSQL database
starting nextcloud installation
Error while trying to create admin user: Failed to connect to the database: An exception occured in driver: SQLSTATE[08006] [7] could not connect to server: Connection refused
	Is the server running on host "postgres" (172.17.0.4) and accepting
	TCP/IP connections on port 5432?
 -> 
retrying install...
Nextcloud was successfully installed
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.17.0.5. Set the 'ServerName' directive globally to suppress this message
AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.17.0.5. Set the 'ServerName' directive globally to suppress this message
[Fri Aug 09 22:58:26.283069 2019] [mpm_prefork:notice] [pid 1] AH00163: Apache/2.4.38 (Debian) PHP/7.3.8 configured -- resuming normal operations
[Fri Aug 09 22:58:26.283096 2019] [core:notice] [pid 1] AH00094: Command line: 'apache2 -D FOREGROUND'

While it was in the "installed but not passing" state, I did the following:

$ docker exec -u www-data hardcore_fermi php occ app:list
An unhandled exception has been thrown:
PDOException: SQLSTATE[42501]: Insufficient privilege: 7 ERROR:  permission denied for table oc_appconfig in /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOConnection.php:104
Stack trace:
#0 /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOConnection.php(104): PDO->query('SELECT * FROM "...')
#1 /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(852): Doctrine\DBAL\Driver\PDOConnection->query('SELECT * FROM "...')
#2 /var/www/html/lib/private/DB/Connection.php(195): Doctrine\DBAL\Connection->executeQuery('SELECT * FROM "...', Array, Array, NULL)
#3 /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Query/QueryBuilder.php(206): OC\DB\Connection->executeQuery('SELECT * FROM "...', Array, Array)
#4 /var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php(214): Doctrine\DBAL\Query\QueryBuilder->execute()
#5 /var/www/html/lib/private/AppConfig.php(315): OC\DB\QueryBuilder\QueryBuilder->execute()
#6 /var/www/html/lib/private/AppConfig.php(94): OC\AppConfig->loadConfigValues()
#7 /var/www/html/lib/private/AppConfig.php(272): OC\AppConfig->getApps()
#8 /var/www/html/lib/private/legacy/app.php(874): OC\AppConfig->getValues(false, 'installed_versi...')
#9 /var/www/html/lib/private/Server.php(502): OC_App::getAppVersions()
#10 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\Server->OC\{closure}(Object(OC\Server))
#11 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('OC\\Memcache\\Fac...')
#12 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('OC\\Memcache\\Fac...')
#13 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(165): OC\ServerContainer->query('OC\\Memcache\\Fac...')
#14 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(114): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(OC\Server))
#15 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('MemCacheFactory')
#16 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('MemCacheFactory')
#17 /var/www/html/lib/private/Server.php(1533): OC\ServerContainer->query('MemCacheFactory')
#18 /var/www/html/lib/private/Server.php(697): OC\Server->getMemCacheFactory()
#19 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\Server->OC\{closure}(Object(OC\Server))
#20 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('OC\\App\\AppManag...')
#21 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('OC\\App\\AppManag...')
#22 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(165): OC\ServerContainer->query('OC\\App\\AppManag...')
#23 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(114): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(OC\Server))
#24 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('AppManager')
#25 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('AppManager')
#26 /var/www/html/lib/private/Server.php(1723): OC\ServerContainer->query('AppManager')
#27 /var/www/html/lib/private/legacy/app.php(342): OC\Server->getAppManager()
#28 /var/www/html/lib/private/legacy/app.php(113): OC_App::getEnabledApps()
#29 /var/www/html/lib/base.php(654): OC_App::loadApps(Array)
#30 /var/www/html/lib/base.php(1068): OC::init()
#31 /var/www/html/console.php(46): require_once('/var/www/html/l...')
#32 /var/www/html/occ(11): require_once('/var/www/html/c...')
#33 {main}

Next Doctrine\DBAL\Driver\PDOException: SQLSTATE[42501]: Insufficient privilege: 7 ERROR:  permission denied for table oc_appconfig in /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOConnection.php:106
Stack trace:
#0 /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(852): Doctrine\DBAL\Driver\PDOConnection->query('SELECT * FROM "...')
#1 /var/www/html/lib/private/DB/Connection.php(195): Doctrine\DBAL\Connection->executeQuery('SELECT * FROM "...', Array, Array, NULL)
#2 /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Query/QueryBuilder.php(206): OC\DB\Connection->executeQuery('SELECT * FROM "...', Array, Array)
#3 /var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php(214): Doctrine\DBAL\Query\QueryBuilder->execute()
#4 /var/www/html/lib/private/AppConfig.php(315): OC\DB\QueryBuilder\QueryBuilder->execute()
#5 /var/www/html/lib/private/AppConfig.php(94): OC\AppConfig->loadConfigValues()
#6 /var/www/html/lib/private/AppConfig.php(272): OC\AppConfig->getApps()
#7 /var/www/html/lib/private/legacy/app.php(874): OC\AppConfig->getValues(false, 'installed_versi...')
#8 /var/www/html/lib/private/Server.php(502): OC_App::getAppVersions()
#9 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\Server->OC\{closure}(Object(OC\Server))
#10 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('OC\\Memcache\\Fac...')
#11 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('OC\\Memcache\\Fac...')
#12 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(165): OC\ServerContainer->query('OC\\Memcache\\Fac...')
#13 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(114): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(OC\Server))
#14 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('MemCacheFactory')
#15 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('MemCacheFactory')
#16 /var/www/html/lib/private/Server.php(1533): OC\ServerContainer->query('MemCacheFactory')
#17 /var/www/html/lib/private/Server.php(697): OC\Server->getMemCacheFactory()
#18 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\Server->OC\{closure}(Object(OC\Server))
#19 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('OC\\App\\AppManag...')
#20 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('OC\\App\\AppManag...')
#21 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(165): OC\ServerContainer->query('OC\\App\\AppManag...')
#22 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(114): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(OC\Server))
#23 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('AppManager')
#24 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('AppManager')
#25 /var/www/html/lib/private/Server.php(1723): OC\ServerContainer->query('AppManager')
#26 /var/www/html/lib/private/legacy/app.php(342): OC\Server->getAppManager()
#27 /var/www/html/lib/private/legacy/app.php(113): OC_App::getEnabledApps()
#28 /var/www/html/lib/base.php(654): OC_App::loadApps(Array)
#29 /var/www/html/lib/base.php(1068): OC::init()
#30 /var/www/html/console.php(46): require_once('/var/www/html/l...')
#31 /var/www/html/occ(11): require_once('/var/www/html/c...')
#32 {main}

Next Doctrine\DBAL\Exception\DriverException: An exception occurred while executing 'SELECT * FROM "oc_appconfig"':

SQLSTATE[42501]: Insufficient privilege: 7 ERROR:  permission denied for table oc_appconfig in /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Driver/AbstractPostgreSQLDriver.php:92
Stack trace:
#0 /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/DBALException.php(128): Doctrine\DBAL\Driver\AbstractPostgreSQLDriver->convertException('An exception oc...', Object(Doctrine\DBAL\Driver\PDOException))
#1 /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(855): Doctrine\DBAL\DBALException::driverExceptionDuringQuery(Object(Doctrine\DBAL\Driver\PDOPgSql\Driver), Object(Doctrine\DBAL\Driver\PDOException), 'SELECT * FROM "...', Array)
#2 /var/www/html/lib/private/DB/Connection.php(195): Doctrine\DBAL\Connection->executeQuery('SELECT * FROM "...', Array, Array, NULL)
#3 /var/www/html/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Query/QueryBuilder.php(206): OC\DB\Connection->executeQuery('SELECT * FROM "...', Array, Array)
#4 /var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php(214): Doctrine\DBAL\Query\QueryBuilder->execute()
#5 /var/www/html/lib/private/AppConfig.php(315): OC\DB\QueryBuilder\QueryBuilder->execute()
#6 /var/www/html/lib/private/AppConfig.php(94): OC\AppConfig->loadConfigValues()
#7 /var/www/html/lib/private/AppConfig.php(272): OC\AppConfig->getApps()
#8 /var/www/html/lib/private/legacy/app.php(874): OC\AppConfig->getValues(false, 'installed_versi...')
#9 /var/www/html/lib/private/Server.php(502): OC_App::getAppVersions()
#10 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\Server->OC\{closure}(Object(OC\Server))
#11 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('OC\\Memcache\\Fac...')
#12 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('OC\\Memcache\\Fac...')
#13 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(165): OC\ServerContainer->query('OC\\Memcache\\Fac...')
#14 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(114): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(OC\Server))
#15 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('MemCacheFactory')
#16 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('MemCacheFactory')
#17 /var/www/html/lib/private/Server.php(1533): OC\ServerContainer->query('MemCacheFactory')
#18 /var/www/html/lib/private/Server.php(697): OC\Server->getMemCacheFactory()
#19 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\Server->OC\{closure}(Object(OC\Server))
#20 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('OC\\App\\AppManag...')
#21 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('OC\\App\\AppManag...')
#22 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(165): OC\ServerContainer->query('OC\\App\\AppManag...')
#23 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(114): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(OC\Server))
#24 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(117): Pimple\Container->offsetGet('AppManager')
#25 /var/www/html/lib/private/ServerContainer.php(132): OC\AppFramework\Utility\SimpleContainer->query('AppManager')
#26 /var/www/html/lib/private/Server.php(1723): OC\ServerContainer->query('AppManager')
#27 /var/www/html/lib/private/legacy/app.php(342): OC\Server->getAppManager()
#28 /var/www/html/lib/private/legacy/app.php(113): OC_App::getEnabledApps()
#29 /var/www/html/lib/base.php(654): OC_App::loadApps(Array)
#30 /var/www/html/lib/base.php(1068): OC::init()
#31 /var/www/html/console.php(46): require_once('/var/www/html/l...')
#32 /var/www/html/occ(11): require_once('/var/www/html/c...')
#33 {main}

@tianon
Copy link
Member

tianon commented Aug 9, 2019

I think the root of the issue is in https://github.com/nextcloud/docker/blob/6291898c2bdf1c353a8882a186b80984500ca9b7/docker-entrypoint.sh#L104-L109 -- I understand the intent is that if the install can't connect to the database, we should try again, but I think what's happening is that the install is somehow failing and then being retried and the retry considers the partial install a successful/complete install?

As further evidence that this is not a timeout-based failure, I've been trying to reproduce again for a while, and have significantly more successful runs this time (and it still hasn't failed):

$ while ./test/tests/nextcloud-cli-postgres/run.sh nextcloud:15.0.10-apache; do echo; done; echo
........
........
........
........
........
........
........
........
........
........
........
........
........
........
...........
........
........
........
........
........
........
........
........
........
........
........
........
........
........
........
........

As seen, they're all relatively short/quick (not even the one outlier is anywhere near the 30 retries mark).

@tianon tianon mentioned this pull request Aug 9, 2019
@tianon
Copy link
Member

tianon commented Aug 9, 2019

Getting the logs of the postgres container was also useful:

2019-08-09 23:17:20.783 UTC [1] LOG:  database system is ready to accept connections
2019-08-09 23:17:23.841 UTC [54] ERROR:  syntax error at or near "-" at character 39
2019-08-09 23:17:23.841 UTC [54] STATEMENT:  REVOKE ALL PRIVILEGES ON DATABASE test-29998-db FROM PUBLIC

Looks like there's somewhere that the database name is missing some escaping/sanitization.

@tianon
Copy link
Member

tianon commented Aug 9, 2019

It seems the input sanitization woes go deeper too -- if I set NEXTCLOUD_ADMIN_USER to the same value as the nextcloud-cli-mysql test, I get this in the PostgreSQL logs:

2019-08-09 23:32:41.947 UTC [46] ERROR:  syntax error at or near "-" at character 20
2019-08-09 23:32:41.947 UTC [46] STATEMENT:  CREATE USER oc_test-24392-user CREATEDB PASSWORD 'r8ws4aoq71hnis2vkjnxwgxad5zkh1'
2019-08-09 23:32:41.948 UTC [47] FATAL:  password authentication failed for user "oc_test-24392-user"
2019-08-09 23:32:41.948 UTC [47] DETAIL:  Role "oc_test-24392-user" does not exist.

(even though POSTGRES_USER is set to a value with hyphens also, so this is an escaping issue)

Edit: and same issue with the database name:

2019-08-09 23:38:21.123 UTC [47] ERROR:  syntax error at or near "-" at character 21
2019-08-09 23:38:21.123 UTC [47] STATEMENT:  CREATE DATABASE test-5509-db OWNER oc_test_12878
2019-08-09 23:38:21.125 UTC [48] FATAL:  database "test-5509-db" does not exist
2019-08-09 23:38:23.121 UTC [49] FATAL:  database "test-5509-db" does not exist
2019-08-09 23:38:24.226 UTC [50] FATAL:  database "test-5509-db" does not exist
2019-08-09 23:38:24.239 UTC [51] ERROR:  syntax error at or near "-" at character 21
2019-08-09 23:38:24.239 UTC [51] STATEMENT:  CREATE DATABASE test-5509-db OWNER oc_test_128782
2019-08-09 23:38:24.240 UTC [52] FATAL:  database "test-5509-db" does not exist
2019-08-09 23:38:25.799 UTC [53] FATAL:  database "test-5509-db" does not exist
2019-08-09 23:38:27.342 UTC [54] FATAL:  database "test-5509-db" does not exist

@tianon
Copy link
Member

tianon commented Aug 10, 2019

Opened a PR at nextcloud/server#16708 to have a more appropriate place to discuss addslashes upstream. 👍

@J0WI
Copy link
Contributor Author

J0WI commented Aug 12, 2019

Nice finding, thanks for reporting this!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants