unit: galera-cluster/0: hook failed: "cluster-relation-changed" - _mysql_exceptions.OperationalError: (1213, 'Deadlock found when trying to get lock; try restarting transaction'

Bug #1501950 reported by Larry Michel
12
This bug affects 1 person
Affects Status Importance Assigned to Milestone
galera-cluster (Juju Charms Collection)
New
Undecided
Unassigned

Bug Description

We're hitting a failure that could be related to bug 1501947 but it's a different underlying mysql failure so opening this new bug.

From console.txt:

2015-10-01 12:45:58,026 [DEBUG] deployer.env: Delta unit: ceph/0 change:started
2015-10-01 12:46:13,653 [DEBUG] deployer.env: Delta unit: galera-cluster/2 change:started
2015-10-01 12:46:34,125 [DEBUG] deployer.env: Delta unit: galera-cluster/0 change:pending
2015-10-01 12:46:34,944 [DEBUG] deployer.env: Delta unit: galera-cluster/0 change:pending
2015-10-01 12:46:40,350 [DEBUG] deployer.env: Delta unit: galera-cluster/0 change:pending
2015-10-01 12:46:44,916 [DEBUG] deployer.env: Delta service: galera-cluster change:{u'Err': None, u'Since': u'2015-10-01T12:44:54.138067715Z', u'Current': u'unknown', u'Version': u'', u'Message': u'', u'Data': {}}
2015-10-01 12:46:44,916 [DEBUG] deployer.env: Delta unit: galera-cluster/0 change:pending
2015-10-01 12:46:45,631 [DEBUG] deployer.env: Delta unit: galera-cluster/0 change:started
2015-10-01 12:46:51,303 [DEBUG] deployer.env: Delta unit: galera-cluster/0 change:started
2015-10-01 12:46:51,947 [DEBUG] deployer.env: Delta unit: galera-cluster/1 change:started
2015-10-01 12:46:53,226 [DEBUG] deployer.env: Delta unit: galera-cluster/2 change:started
2015-10-01 12:46:57,831 [DEBUG] deployer.env: Delta unit: galera-cluster/0 change:started
2015-10-01 12:46:59,849 [DEBUG] deployer.env: Delta unit: galera-cluster/1 change:started
2015-10-01 12:47:04,585 [DEBUG] deployer.env: Delta unit: galera-cluster/2 change:started
2015-10-01 12:47:05,445 [DEBUG] deployer.env: Delta unit: galera-cluster/0 change:started
2015-10-01 12:47:10,625 [DEBUG] deployer.env: Delta service: galera-cluster change:{u'Err': None, u'Since': u'2015-10-01T12:47:05.069871671Z', u'Current': u'error', u'Version': u'', u'Message': u'hook failed: "cluster-relation-changed"', u'Data': {u'hook': u'cluster-relation-changed', u'remote-unit': u'galera-cluster/2', u'relation-id': 0}}
2015-10-01 12:47:10,625 [DEBUG] deployer.env: Delta unit: galera-cluster/0 change:error
2015-10-01 12:47:10,626 [ERROR] deployer.env: The following units had errors:
   unit: galera-cluster/0: machine: 1 agent-state: error details: hook failed: "cluster-relation-changed"
2015-10-01 12:47:10,670 [ERROR] oil_ci.deploy.oil_deployer: Deployment failed:

From all machines log:

unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO worker.uniter.jujuc server.go:158 running hook tool "juju-log" ["-l" "DEBUG" "Using existing password file '/var/lib/charm/galera-cluster/mysql.passwd'"]
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 DEBUG worker.uniter.jujuc server.go:159 hook context id "galera-cluster/0-cluster-relation-changed-3481558268807895627"; dir "/var/lib/juju/agents/unit-galera-cluster-0/charm"
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 DEBUG unit.galera-cluster/0.juju-log server.go:254 cluster:0: Using existing password file '/var/lib/charm/galera-cluster/mysql.passwd'
unit-nova-cloud-controller-0[21989]: 2015-10-01 12:47:03 INFO unit.nova-cloud-controller/0.install logger.go:40 Setting up libasan0:amd64 (4.8.4-2ubuntu1~14.04) ...
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO worker.uniter.jujuc server.go:158 running hook tool "juju-log" ["-l" "DEBUG" "Opening db connection for root@localhost"]
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 DEBUG worker.uniter.jujuc server.go:159 hook context id "galera-cluster/0-cluster-relation-changed-3481558268807895627"; dir "/var/lib/juju/agents/unit-galera-cluster-0/charm"
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 DEBUG unit.galera-cluster/0.juju-log server.go:254 cluster:0: Opening db connection for root@localhost
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 Traceback (most recent call last):
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 File "/var/lib/juju/agents/unit-galera-cluster-0/charm/hooks/cluster-relation-changed", line 455, in <module>
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 main()
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 File "/var/lib/juju/agents/unit-galera-cluster-0/charm/hooks/cluster-relation-changed", line 449, in main
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 hooks.execute(sys.argv)
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 File "/var/lib/juju/agents/unit-galera-cluster-0/charm/hooks/charmhelpers/core/hookenv.py", line 544, in execute
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 self._hooks[hook_name]()
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 File "/var/lib/juju/agents/unit-galera-cluster-0/charm/hooks/cluster-relation-changed", line 204, in cluster_changed
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 config_changed()
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 File "/var/lib/juju/agents/unit-galera-cluster-0/charm/hooks/cluster-relation-changed", line 172, in config_changed
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 change_sst_password(config('sst-password'))
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 File "/var/lib/juju/agents/unit-galera-cluster-0/charm/hooks/galera_utils.py", line 172, in change_sst_password
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 m_helper.execute(SQL_SST_USER_CHANGE_PASSWORD1.format(sst_password))
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 File "/var/lib/juju/agents/unit-galera-cluster-0/charm/hooks/charmhelpers/contrib/database/mysql.py", line 134, in execute
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 cursor.execute(sql)
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 self.errorhandler(self, exc, value)
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 raise errorclass, errorvalue
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO unit.galera-cluster/0.cluster-relation-changed logger.go:40 _mysql_exceptions.OperationalError: (1213, 'Deadlock found when trying to get lock; try restarting transaction')
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 INFO juju.worker.uniter.context context.go:543 handling reboot
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 ERROR juju.worker.uniter.operation runhook.go:103 hook "cluster-relation-changed" failed: exit status 1
unit-galera-cluster-0[22022]: 2015-10-01 12:47:03 DEBUG juju.worker.uniter modes.go:31 [AGENT-STATUS] failed: run relation-changed (0; galera-cluster/2) hook
unit-nova-compute-0[22005]: 2015-10-01 12:47:03 INFO unit.nova-compute/0.install logger.go:40 Setting up python-html5lib-whl (0.999-3~ubuntu1) ...
unit-nova-cloud-controller-0[21989]: 2015-10-01 12:47:03 INFO unit.nova-cloud-controller/0.install logger.go:40 Setting up libatomic1:amd64 (4.8.4-2ubuntu1~14.04

From juju_status.yaml:

galera-cluster:
    charm: local:trusty/galera-cluster-45
    exposed: false
    relations:
      cluster:
      - galera-cluster
    service-status:
      current: error
      message: 'hook failed: "cluster-relation-changed"'
      since: 01 Oct 2015 12:47:05Z
    units:
      galera-cluster/0:
        agent-state: error
        agent-state-info: 'hook failed: "cluster-relation-changed"'
        agent-status:
          current: idle
          since: 01 Oct 2015 12:47:05Z
          version: 1.24.6
        agent-version: 1.24.6
        machine: '1'
        open-ports:
        - 3306/tcp
        public-address: flaglervm04.oilstaging
        workload-status:
          current: error
          message: 'hook failed: "cluster-relation-changed"'
          since: 01 Oct 2015 12:47:05Z
      galera-cluster/1:
        agent-state: started
        agent-status:
          current: idle
          since: 01 Oct 2015 12:47:14Z
          version: 1.24.6
        agent-version: 1.24.6
        machine: '2'
        open-ports:
        - 3306/tcp
        public-address: flaglervm02.oilstaging
        workload-status:
          current: unknown
          since: 01 Oct 2015 12:44:54Z
      galera-cluster/2:
        agent-state: started
        agent-status:
          current: idle
          since: 01 Oct 2015 12:46:58Z
          version: 1.24.6
        agent-version: 1.24.6
        machine: '3'
        open-ports:
        - 3306/tcp
        public-address: flaglervm01.oilstaging
        workload-status:
          current: unknown
          since: 01 Oct 2015 12:45:04Z

Tags: oil
Revision history for this message
Larry Michel (lmic) wrote :
summary: - unit: galera-cluster/0: machine: 1 agent-state: error details: hook
- failed: "cluster-relation-changed"
+ unit: galera-cluster/0: hook failed: "cluster-relation-changed" -
+ _mysql_exceptions.OperationalError: (1213, 'Deadlock found when trying
+ to get lock; try restarting transaction'
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.