| 2018-03-06 02:29:54 |
Paul Collins |
description |
During an upgrade from percona-cluster ~15.04 (r52, revision-id: jorge.niedbalski@canonical.com-20150304174216-18abugmuw832gfbj) to 17.11 the upgrade-charm hook failed as follows:
2018-03-06 02:17:55 INFO upgrade-charm * Starting MySQL (Percona XtraDB Cluster) database server mysqld
2018-03-06 02:17:56 DEBUG juju.worker.uniter.filter filter.go:438 got unit change
2018-03-06 02:17:56 DEBUG juju.worker.uniter.filter filter.go:513 got leader settings change: ok=true
2018-03-06 02:17:56 DEBUG juju.worker.uniter.filter filter.go:522 not sending leader settings change (want=false)
2018-03-06 02:18:22 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:18:22 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:18:22 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:19:22.23673091 +0000 UTC
2018-03-06 02:18:22 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:18:52.23673091 +0000 UTC
2018-03-06 02:18:52 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:18:52 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:18:52 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:19:52.23716842 +0000 UTC
2018-03-06 02:18:52 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:19:22.23716842 +0000 UTC
2018-03-06 02:19:22 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:19:22 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:19:22 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:20:22.23769761 +0000 UTC
2018-03-06 02:19:22 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:19:52.23769761 +0000 UTC
2018-03-06 02:19:36 INFO upgrade-charm * The server quit without updating PID file (/var/run/mysqld/mysqld.pid).
2018-03-06 02:19:36 INFO upgrade-charm ...fail!
2018-03-06 02:19:36 INFO worker.uniter.jujuc server.go:173 running hook tool "juju-log" ["-l" "WARNING" "Failed to start mysql - retrying in 1s"]
2018-03-06 02:19:36 DEBUG worker.uniter.jujuc server.go:174 hook context id "mysql/0-upgrade-charm-5504897252941795630"; dir "/var/lib/juju/agents/unit-mysql-0/charm"
2018-03-06 02:19:36 WARNING juju-log Failed to start mysql - retrying in 1s
2018-03-06 02:19:37 INFO upgrade-charm * Starting MySQL (Percona XtraDB Cluster) database server mysqld
2018-03-06 02:19:52 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:19:52 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:19:52 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:20:52.238228586 +0000 UTC
2018-03-06 02:19:52 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:20:22.238228586 +0000 UTC
2018-03-06 02:20:22 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:20:22 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:20:22 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:21:22.238828369 +0000 UTC
2018-03-06 02:20:22 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:20:52.238828369 +0000 UTC
2018-03-06 02:20:52 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:20:52 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:20:52 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:21:52.239370418 +0000 UTC
2018-03-06 02:20:52 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:21:22.239370418 +0000 UTC
2018-03-06 02:21:18 INFO upgrade-charm * The server quit without updating PID file (/var/run/mysqld/mysqld.pid).
2018-03-06 02:21:18 INFO upgrade-charm ...fail!
2018-03-06 02:21:18 INFO worker.uniter.jujuc server.go:173 running hook tool "juju-log" ["-l" "WARNING" "Failed to start mysql - retrying in 3s"]
2018-03-06 02:21:18 DEBUG worker.uniter.jujuc server.go:174 hook context id "mysql/0-upgrade-charm-5504897252941795630"; dir "/var/lib/juju/agents/unit-mysql-0/charm"
2018-03-06 02:21:18 WARNING juju-log Failed to start mysql - retrying in 3s
This appears to be because percona-cluster now explicitly specifies pid_file, whereas previously a guessed location was used:
Mar 6 02:02:47 juju-pjdc-ps45-1711-test-machine-11 /etc/init.d/mysql[5450]: MySQL PID not found, pid_file detected/guessed: /var/lib/mysql/juju-pjdc-ps45-1711-test-machine-11.pid
However, since the charm doesn't copy the pid file to the new location, the init script can no longer control the server properly. The following, run before the upgrade, or even while the upgrade-charm hook is in the retry loop above, avoids or solves the problem:
juju run --unit mysql/0 'cp -av /var/lib/mysql/$(hostname).pid /var/run/mysqld/mysqld.pid' |
During an upgrade from percona-cluster ~15.04 (r52, revision-id: jorge.niedbalski@canonical.com-20150304174216-18abugmuw832gfbj) to 17.11 the upgrade-charm hook failed as follows:
2018-03-06 02:17:55 INFO upgrade-charm * Starting MySQL (Percona XtraDB Cluster) database server mysqld
2018-03-06 02:17:56 DEBUG juju.worker.uniter.filter filter.go:438 got unit change
2018-03-06 02:17:56 DEBUG juju.worker.uniter.filter filter.go:513 got leader settings change: ok=true
2018-03-06 02:17:56 DEBUG juju.worker.uniter.filter filter.go:522 not sending leader settings change (want=false)
2018-03-06 02:18:22 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:18:22 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:18:22 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:19:22.23673091 +0000 UTC
2018-03-06 02:18:22 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:18:52.23673091 +0000 UTC
2018-03-06 02:18:52 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:18:52 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:18:52 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:19:52.23716842 +0000 UTC
2018-03-06 02:18:52 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:19:22.23716842 +0000 UTC
2018-03-06 02:19:22 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:19:22 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:19:22 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:20:22.23769761 +0000 UTC
2018-03-06 02:19:22 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:19:52.23769761 +0000 UTC
2018-03-06 02:19:36 INFO upgrade-charm * The server quit without updating PID file (/var/run/mysqld/mysqld.pid).
2018-03-06 02:19:36 INFO upgrade-charm ...fail!
2018-03-06 02:19:36 INFO worker.uniter.jujuc server.go:173 running hook tool "juju-log" ["-l" "WARNING" "Failed to start mysql - retrying in 1s"]
2018-03-06 02:19:36 DEBUG worker.uniter.jujuc server.go:174 hook context id "mysql/0-upgrade-charm-5504897252941795630"; dir "/var/lib/juju/agents/unit-mysql-0/charm"
2018-03-06 02:19:36 WARNING juju-log Failed to start mysql - retrying in 1s
2018-03-06 02:19:37 INFO upgrade-charm * Starting MySQL (Percona XtraDB Cluster) database server mysqld
2018-03-06 02:19:52 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:19:52 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:19:52 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:20:52.238228586 +0000 UTC
2018-03-06 02:19:52 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:20:22.238228586 +0000 UTC
2018-03-06 02:20:22 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:20:22 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:20:22 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:21:22.238828369 +0000 UTC
2018-03-06 02:20:22 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:20:52.238828369 +0000 UTC
2018-03-06 02:20:52 DEBUG juju.worker.leadership tracker.go:138 mysql/0 renewing lease for mysql leadership
2018-03-06 02:20:52 DEBUG juju.worker.leadership tracker.go:165 checking mysql/0 for mysql leadership
2018-03-06 02:20:52 DEBUG juju.worker.leadership tracker.go:180 mysql/0 confirmed for mysql leadership until 2018-03-06 02:21:52.239370418 +0000 UTC
2018-03-06 02:20:52 INFO juju.worker.leadership tracker.go:182 mysql/0 will renew mysql leadership at 2018-03-06 02:21:22.239370418 +0000 UTC
2018-03-06 02:21:18 INFO upgrade-charm * The server quit without updating PID file (/var/run/mysqld/mysqld.pid).
2018-03-06 02:21:18 INFO upgrade-charm ...fail!
2018-03-06 02:21:18 INFO worker.uniter.jujuc server.go:173 running hook tool "juju-log" ["-l" "WARNING" "Failed to start mysql - retrying in 3s"]
2018-03-06 02:21:18 DEBUG worker.uniter.jujuc server.go:174 hook context id "mysql/0-upgrade-charm-5504897252941795630"; dir "/var/lib/juju/agents/unit-mysql-0/charm"
2018-03-06 02:21:18 WARNING juju-log Failed to start mysql - retrying in 3s
This appears to be because percona-cluster now explicitly specifies pid_file, whereas previously a guessed location was used:
Mar 6 02:02:47 juju-pjdc-ps45-1711-test-machine-11 /etc/init.d/mysql[5450]: MySQL PID not found, pid_file detected/guessed: /var/lib/mysql/juju-pjdc-ps45-1711-test-machine-11.pid
However, since the charm doesn't copy the pid file to the new location, the init script can no longer control the server properly. The following, run before the upgrade, avoids the problem:
juju run --unit mysql/0 'cp -av /var/lib/mysql/$(hostname).pid /var/run/mysqld/mysqld.pid' |
|
