[SOLVED] Upgrade 5.0.19 > 6.0.6 hangs on "starting mysql..."

Discuss your pilot or production implementation with other Zimbra admins or our engineers.
Post Reply
Jay2k1
Posts: 22
Joined: Sat Sep 13, 2014 12:29 am

[SOLVED] Upgrade 5.0.19 > 6.0.6 hangs on "starting mysql..."

Post by Jay2k1 »

Hello.
So I started the upgrade grom 5.0.19 to 6.0.6 Network Edition on CentOS 5 x64. Everything ran smoothly so far, but now it hangs at "starting mysql...".
I had a look into /opt/zimbra/log/mysql-error.log:



100424 16:57:48 [Note] /opt/zimbra/mysql/libexec/mysqld: Normal shutdown
100424 16:57:49 InnoDB: Starting shutdown...

100424 16:57:55 InnoDB: Shutdown completed; log sequence number 4 1415862554

100424 16:57:55 [Note] /opt/zimbra/mysql/libexec/mysqld: Shutdown complete
100424 16:57:55 mysqld ended
100424 17:20:46 mysqld started

100424 17:20:51 InnoDB: Started; log sequence number 4 1415862554

100424 17:20:51 [Note] /opt/zimbra/mysql/libexec/mysqld: ready for connections.

Version: '5.0.51a-log' socket: '/opt/zimbra/db/mysql.sock' port: 7306 Source distribution

100424 17:44:40 [Note] /opt/zimbra/mysql/libexec/mysqld: Normal shutdown
100424 17:44:40 InnoDB: Starting shutdown...

100424 17:44:42 InnoDB: Shutdown completed; log sequence number 4 1416207138

100424 17:44:42 [Note] /opt/zimbra/mysql/libexec/mysqld: Shutdown complete
100424 17:44:42 mysqld ended
100424 17:46:46 mysqld started

InnoDB: The first specified data file ./ibdata1 did not exist:

InnoDB: a new database to be created!

100424 17:46:46 InnoDB: Setting file ./ibdata1 size to 10 MB

InnoDB: Database physically writes the file full: wait...

100424 17:46:46 InnoDB: Log file ./ib_logfile0 did not exist: new to be created

InnoDB: Setting log file ./ib_logfile0 size to 100 MB

InnoDB: Database physically writes the file full: wait...

InnoDB: Progress in MB: 100

100424 17:46:49 InnoDB: Log file ./ib_logfile1 did not exist: new to be created

InnoDB: Setting log file ./ib_logfile1 size to 100 MB

InnoDB: Database physically writes the file full: wait...

InnoDB: Progress in MB: 100

InnoDB: Doublewrite buffer not found: creating new

InnoDB: Doublewrite buffer created

InnoDB: Creating foreign key constraint system tables

InnoDB: Foreign key constraint system tables created

100424 17:46:52 InnoDB: Started; log sequence number 0 0

100424 17:46:52 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.host' doesn't exist

100424 17:46:52 mysqld ended
100424 17:46:56 mysqld started

InnoDB: Log scan progressed past the checkpoint lsn 0 36808

100424 17:46:57 InnoDB: Database was not shut down normally!

InnoDB: Starting crash recovery.

InnoDB: Reading tablespace information from the .ibd files...

InnoDB: Restoring possible half-written data pages from the doublewrite

InnoDB: buffer...

InnoDB: Doing recovery: scanned up to log sequence number 0 43655

100424 17:46:57 InnoDB: Starting an apply batch of log records to the database...

InnoDB: Progress in percents: 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99

InnoDB: Apply batch completed

100424 17:46:58 InnoDB: Started; log sequence number 0 43655

100424 17:46:58 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.host' doesn't exist

100424 17:46:58 mysqld ended
100424 17:47:07 mysqld started

InnoDB: Log scan progressed past the checkpoint lsn 0 36808

100424 17:47:12 InnoDB: Database was not shut down normally!

InnoDB: Starting crash recovery.

InnoDB: Reading tablespace information from the .ibd files...

InnoDB: Restoring possible half-written data pages from the doublewrite

InnoDB: buffer...

InnoDB: Doing recovery: scanned up to log sequence number 0 43655

100424 17:47:14 InnoDB: Starting an apply batch of log records to the database...

InnoDB: Progress in percents: 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99

InnoDB: Apply batch completed

100424 17:47:14 InnoDB: Started; log sequence number 0 43655

100424 17:47:14 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.host' doesn't exist

100424 17:47:14 mysqld ended
100424 17:47:18 mysqld started

InnoDB: Log scan progressed past the checkpoint lsn 0 36808

100424 17:47:18 InnoDB: Database was not shut down normally!

InnoDB: Starting crash recovery.

InnoDB: Reading tablespace information from the .ibd files...

InnoDB: Restoring possible half-written data pages from the doublewrite

InnoDB: buffer...

InnoDB: Doing recovery: scanned up to log sequence number 0 43655

100424 17:47:18 InnoDB: Starting an apply batch of log records to the database...

InnoDB: Progress in percents: 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99

InnoDB: Apply batch completed

100424 17:47:19 InnoDB: Started; log sequence number 0 43655

100424 17:47:19 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.host' doesn't exist

100424 17:47:19 mysqld ended
Here I cut it because the last parts keep repeating.
This makes me kind of nervous... any suggestions?
Edit: Now the install script added a "done" after "starting mysql" and then said "UPGRADE FAILED - exiting". :S
Jay2k1
Posts: 22
Joined: Sat Sep 13, 2014 12:29 am

[SOLVED] Upgrade 5.0.19 > 6.0.6 hangs on "starting mysql..."

Post by Jay2k1 »

So it turns out this problem is bigger than I thought. I opened a support ticket and was helped only a few minutes after.
Thanks Rick from Zimbra Support for your great help!
phoenix
Ambassador
Ambassador
Posts: 27278
Joined: Fri Sep 12, 2014 9:56 pm
Location: Liverpool, England

[SOLVED] Upgrade 5.0.19 > 6.0.6 hangs on "starting mysql..."

Post by phoenix »

[quote user="Jay2k1"]So it turns out this problem is bigger than I thought. I opened a support ticket and was helped only a few minutes after[/QUOTE]How about posting the solution for other members to see?
Regards

Bill

Rspamd: A high performance spamassassin replacement

Per ardua ad astra
Jay2k1
Posts: 22
Joined: Sat Sep 13, 2014 12:29 am

[SOLVED] Upgrade 5.0.19 > 6.0.6 hangs on "starting mysql..."

Post by Jay2k1 »

I don't really know what was wrong. He said somehow there was no LDAP data, and that he imported it manually, re-running the install.sh afterwards. But I have absolutely no clue what he did in detail.
StefanFN
Posts: 22
Joined: Sat Sep 13, 2014 1:08 am

[SOLVED] Upgrade 5.0.19 > 6.0.6 hangs on "starting mysql..."

Post by StefanFN »

Hi,
having the solution or at least a hint in this thread, would have been great as I just ran into the very same issue with our FOSS on Ubuntu 8.04.

We are basically suffering a Production Down and I'm trying to resolve it now. I figured out that there's something not quite right with LDAP, since nothing authenticates as the ldap_root_password is not accepted anymore ..even for a simple ldapsearch -x -h ldapi:/// .
/Stefan
Jay2k1
Posts: 22
Joined: Sat Sep 13, 2014 12:29 am

[SOLVED] Upgrade 5.0.19 > 6.0.6 hangs on "starting mysql..."

Post by Jay2k1 »

Sorry for the late reply, it was 3:39 am here, I was asleep.
Thing is, I don't really have a clue about LDAP. We're just using Zimbra for mail and for the ability to have calendar and contacts in sync. Also, I didn't get a detailed report or log about what the support guy did (he ssh'ed into the server). All I can do is quote his mail:

[QUOTE]The first thing I noticed was that ldap had NO data in it. I managed to import ldap data, and copied the mysql data direct from the /zimbra directory; probably a good thing you copied that data. :) After the data was copied, I reran the installer. [/QUOTE]

It took him two and a half hours from logging in the first time until he fixed it. After telling me that he's done and that I should try if things work, I asked him for what was wrong, and he replied with the quoted text above.
I'm afraid this is all I can do to help here :(
Hope this helps,
Jay
StefanFN
Posts: 22
Joined: Sat Sep 13, 2014 1:08 am

[SOLVED] Upgrade 5.0.19 > 6.0.6 hangs on "starting mysql..."

Post by StefanFN »

Hi Jay2k1,
well, now that I managed to get our services back up and running, I'd like to bring up the solution here:

We have /opt/zimbra/db and /opt/zimbra/data symlinked to a faster drive (RAID10).

The update process apparently exports /opt/zimbra/data (or parts of it) and then deletes it (don't know why, but it's the case). I guess this happens because it is symlinked.
I figured that out after running the installer a second time.
Somewhere in the script it then recreates the directory with a new/or empty ldap database. Now of couse none of the services can retrieve their settings from LDAP and therefore fail to start.
Solution in my case was to

root@host#mount --bind /path/to/zimbra/data /opt/zimbra/data
which leads in /etc/fstab to

/path/to/zimbra/data /opt/zimbra/data none rw,bind 0 0
I did the same for the symlinked /opt/zimbra/db directory.
Now our store has all its data in it and the mailboxes are current.
The time consuming thing was learning why it failed and not the solution itself.

Afterall it's been quite frustrating but I'm glad we didn't lose any data.
/Stefan
Post Reply