Project

General

Profile

Actions

Bug #70304

closed

Database connection fails at install tool step 4

Added by Oliver Eglseder about 9 years ago. Updated about 8 years ago.

Status:
Closed
Priority:
Should have
Assignee:
-
Category:
-
Target version:
-
Start date:
2015-10-02
Due date:
% Done:

0%

Estimated time:
TYPO3 Version:
7
PHP Version:
5.6
Tags:
Complexity:
no-brainer
Is Regression:
No
Sprint Focus:

Description

Steps:
Clone the current master
Create FIRST_INSTALL
Database credentials: root, no password, socket
Select an existing empty database ("temp.vxvr")
Enter username and password for admin user
Get exception:

#1270853884: TYPO3 Fatal Error: The current username, password or host was not accepted when the connection to the database was attempted to be established!

Analysis:
The first DatabaseConnection is established in \TYPO3\CMS\Install\Controller\Action\Step\DatabaseData::importDatabaseData
Neither $GLOBALS['TYPO3_DB'] is used nor gets the resulting connection (line 129) written to the global var.

After that, in \TYPO3\CMS\Install\Service\SqlSchemaMigrationService::getCollationForCharset@158, the connection gets established again, but $GLOBALS['TYPO3_DB'] is used. The DatabaseConnection in the global var has no established connection. This leads to a second try to establish the database connection, which fails.

Solution: Always use $GLOBALS['TYPO3_DB'] for database connections

Actions #1

Updated by Gerrit Code Review about 9 years ago

  • Status changed from New to Under Review

Patch set 2 for branch master of project Packages/TYPO3.CMS has been pushed to the review server.
It is available at http://review.typo3.org/43738

Actions #2

Updated by Gerrit Code Review about 9 years ago

Patch set 3 for branch master of project Packages/TYPO3.CMS has been pushed to the review server.
It is available at http://review.typo3.org/43738

Actions #3

Updated by Gerrit Code Review about 9 years ago

Patch set 4 for branch master of project Packages/TYPO3.CMS has been pushed to the review server.
It is available at http://review.typo3.org/43738

Actions #4

Updated by Gerrit Code Review about 9 years ago

Patch set 5 for branch master of project Packages/TYPO3.CMS has been pushed to the review server.
It is available at http://review.typo3.org/43738

Actions #5

Updated by Oliver Eglseder about 9 years ago

Information about my system:

Mac OS X 10.9.5
PHP 5.6.12 (via Homebrew)
mysqld Ver 5.6.26 for osx10.9 on x86_64 (Homebrew)
apache: native apache shipped with OS X (i think it's 2.2.11)

Tested with TYPO3 Versions: 6.2, 7.0, 7.4, 7.5

ANY FOLLOWING INFORMATION IS COLLECTED AFTER THE FIRST EXCEPTION WAS THROWN.

Original error:

MySQL server has gone away

Strange: MySQL server uptime after the server has apparently gone away: 49 min 56 sec (time the machine was running) <- MySQL did not really break...

The MySQL error log gets flooded with

151016 17:31:08 mysqld_safe mysqld from pid file /usr/local/var/mysql/vertexair.fritz.box.pid ended
151016 17:31:08 mysqld_safe Starting mysqld daemon with databases from /usr/local/var/mysql
2015-10-16 17:31:08 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2015-10-16 17:31:08 0 [Note] /usr/local/Cellar/mysql/5.6.26/bin/mysqld (mysqld 5.6.26) starting as process 7837 ...
2015-10-16 17:31:08 7837 [Note] Plugin 'FEDERATED' is disabled.
2015-10-16 17:31:08 7837 [Note] InnoDB: Using atomics to ref count buffer pool pages
2015-10-16 17:31:08 7837 [Note] InnoDB: The InnoDB memory heap is disabled
2015-10-16 17:31:08 7837 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-10-16 17:31:08 7837 [Note] InnoDB: Memory barrier is not used
2015-10-16 17:31:08 7837 [Note] InnoDB: Compressed tables use zlib 1.2.3
2015-10-16 17:31:08 7837 [Note] InnoDB: Using CPU crc32 instructions
2015-10-16 17:31:08 7837 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2015-10-16 17:31:08 7837 [Note] InnoDB: Completed initialization of buffer pool
2015-10-16 17:31:08 7837 [ERROR] InnoDB: Unable to lock ./ibdata1, error: 35
2015-10-16 17:31:08 7837 [Note] InnoDB: Check that you do not already have another mysqld process using the same InnoDB data or log files.
2015-10-16 17:31:08 7837 [Note] InnoDB: Retrying to lock the first data file
2015-10-16 17:31:09 7837 [ERROR] InnoDB: Unable to lock ./ibdata1, error: 35
2015-10-16 17:31:09 7837 [Note] InnoDB: Check that you do not already have another mysqld process using the same InnoDB data or log files.

[...] the two lines above are repeated exactly 100 times

2015-10-16 17:32:48 7837 [Note] InnoDB: Unable to open the first data file
2015-10-16 17:32:48 7fff77ff6310  InnoDB: Operating system error number 35 in a file operation.
InnoDB: Error number 35 means 'Resource temporarily unavailable'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
2015-10-16 17:32:48 7837 [ERROR] InnoDB: Can't open './ibdata1'
2015-10-16 17:32:48 7837 [ERROR] InnoDB: Could not open or create the system tablespace. If you tried to add new data files to the system tablespace, and it failed here, you should now edit innodb_data_file_path in my.cnf back to what it was, and remove the new ibdata files InnoDB created in this failed attempt. InnoDB only wrote those files full of zeros, but did not yet use them in any way. But be careful: do not remove old data files which contain your precious data!
2015-10-16 17:32:48 7837 [ERROR] Plugin 'InnoDB' init function returned error.
2015-10-16 17:32:48 7837 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2015-10-16 17:32:48 7837 [ERROR] Unknown/unsupported storage engine: InnoDB
2015-10-16 17:32:48 7837 [ERROR] Aborting

2015-10-16 17:32:48 7837 [Note] Binlog end
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'partition'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_METRICS'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_CMPMEM'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_CMP'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_LOCKS'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'INNODB_TRX'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'BLACKHOLE'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'ARCHIVE'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'MRG_MYISAM'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'MyISAM'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'MEMORY'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'CSV'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'sha256_password'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'mysql_old_password'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'mysql_native_password'
2015-10-16 17:32:48 7837 [Note] Shutting down plugin 'binlog'
2015-10-16 17:32:48 7837 [Note] /usr/local/Cellar/mysql/5.6.26/bin/mysqld: Shutdown complete

output of lsof:

mysqld    6583 vertexvaar    3u     REG                1,4  79691776 36954167 /usr/local/var/mysql/ibdata1
mysqld    7605 vertexvaar    3u     REG                1,4  79691776 36954167 /usr/local/var/mysql/ibdata1
strange behaviour to mention:
  • mysql.server status state: "MySQL is not running"
  • the processlist shows 4 processes with mysql
 8514 ??         0:00.02 /bin/sh /usr/local/opt/mysql/bin/mysqld_safe --bind-address=127.0.0.1 --datadir=/usr/local/var/mysql
 8612 ??         0:00.39 /usr/local/Cellar/mysql/5.6.26/bin/mysqld --basedir=/usr/local/Cellar/mysql/5.6.26 --datadir=/usr/local/var/mysql --plugin-dir=/usr/local/Cellar/mysql/5.6.26/lib/plugin --bind-address=127.0.0.1 --log-error=/usr/local/var/mysql/vertexair.fritz.box.err --pid-file=/usr/local/var/mysql/vertexair.fritz.box.pid
 6403 ttys000    0:00.02 /bin/sh /usr/local/Cellar/mysql/5.6.26/bin/mysqld_safe --datadir=/usr/local/var/mysql --pid-file=/usr/local/var/mysql/vertexair.fritz.box.pid
 6583 ttys000    0:01.62 /usr/local/Cellar/mysql/5.6.26/bin/mysqld --basedir=/usr/local/Cellar/mysql/5.6.26 --datadir=/usr/local/var/mysql --plugin-dir=/usr/local/Cellar/mysql/5.6.26/lib/plugin --log-error=/usr/local/var/mysql/vertexair.fritz.box.err --pid-file=/usr/local/var/mysql/vertexair.fritz.box.pid
  • mysqld wont start again
i googled a lot and found following hints:
  • it's a deadlock. both processes lock each others access to ibdata1
  • there might be a
possible errors i can exclude:
  • ibdata1 is not corrupt
  • it's NOT that putative PHP Bug introduced with 5.3 someone mentioned, because it occurs in other languages like C and Phyton
  • PHP settings mysqli.allow_persistent, mysqli.max_persistent, mysqli.max_links, mysqli.cache_size, mysqli.reconnect

ultra strange:
i killed all mysql-related processes but there are still messages written to the error log...
lsof is not reporting any process writing to the error log

After killing all processes and try to start mysql.server:

. ERROR! The server quit without updating PID file (/usr/local/var/mysql/vertexair.fritz.box.pid).

Actions #6

Updated by Marcus Schwemer about 9 years ago

I am struggeling with the same issue right now, installing a 6.2.15.

The setup ist quite similar:

  • MacOS 10.11
  • homebrew apache 2.2.14
  • homebrew php 5.5 and 5.6 (no difference)
  • homebrew mysql 5.6.27

Changing the mentioned lines of the patch make 6.2.15 work on the local install.

Btw. I have several other installations running in parallel that are not affected. Maybe sth. homebrew related?

Actions #7

Updated by Marcus Schwemer about 9 years ago

I re-checked it on a domainfactory managed server with a clean install using the tar.gz version 6.2.15 ... there has been no problem ... everything worked as expected

Actions #8

Updated by Marcus Schwemer about 9 years ago

I think, we should abandon the patch, but leave this issue open.

I think, that is an MacOS X and homebrew specific issue. In my blogpost [1] I mentioned a resource [2] that solved it in yosemite. Currently I am already on ElCapitan, but still (again) suffering from this issue. Currently not only in fresh installs, but also with existing installations.

Weird ...

Cheers,
Marcus

[1] http://typo3worx.eu/2015/01/flexible-php-development-setup-on-macos-x/
[2] http://docs.basho.com/riak/latest/ops/tuning/open-files-limit/#Mac-OS-X

Actions #9

Updated by Wouter Wolters about 9 years ago

  • Status changed from Under Review to On Hold
Actions #10

Updated by Morton Jonuschat about 8 years ago

  • Status changed from On Hold to Closed
  • Assignee deleted (Oliver Eglseder)
  • Target version deleted (7 LTS)

The usage if different database connections in the install tool has been solved with the migration to Doctrine in TYPO3 8.
The MySQL setup problems are a system configuration problem unrelated to TYPO3, so this issue can be closed.

Actions

Also available in: Atom PDF