Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-10004

Galera's pc.recovery process fails in 10.1 with systemd

    Details

    • Sprint:
      10.2.1-3, 10.2.1-4

      Description

      Galera's pc.recovery process allows a cluster to automatically recover after a crash without bootstrapping.

      When I try to test this recovery process in MariaDB 10.1 on CentOS/RHEL 7, automatic recovery always fails with a vague "Operation not permitted" error.

      To reproduce, let's say that we have a two node cluster.

      First bootstrap the first node:

      sudo galera_new_cluster
      

      Then start mysqld on the second node,

      sudo systemctl start mariadb
      

      Now to simulate a crash, let's kill mysqld on both nodes:

      sudo kill -9 `pidof mysqld`
      

      Now let's verify that both grastate.dat and gvwstate.dat have meaningful information:

      $ sudo cat /var/lib/mysql/gvwstate.dat
      my_uuid: 4384a074-0cb7-11e6-af78-070fdb4f5393
      #vwbeg
      view_id: 3 4384a074-0cb7-11e6-af78-070fdb4f5393 2
      bootstrap: 0
      member: 4384a074-0cb7-11e6-af78-070fdb4f5393 0
      member: 4856263a-0cb7-11e6-a78f-0787aa9d1a09 0
      #vwend
      $ sudo cat /var/lib/mysql/grastate.dat
      # GALERA saved state
      version: 2.1
      uuid:    43850bb2-0cb7-11e6-a4f3-76531c9a59eb
      seqno:   -1
      cert_index:
      

      Now, start mysqld both nodes normally. We are not bootstrapping the first node here because we would like automatic recovery to take place:

      sudo systemctl start mariadb
      

      When this happens, you will likely see that the saved state is initially restored:

      2016-04-27 16:34:55 140359035238528 [Note] WSREP: restore pc from disk successfully
      2016-04-27 16:34:55 140359035238528 [Note] WSREP: GMCast version 0
      2016-04-27 16:34:55 140359035238528 [Note] WSREP: (4384a074, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
      2016-04-27 16:34:55 140359035238528 [Note] WSREP: (4384a074, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
      2016-04-27 16:34:55 140359035238528 [Note] WSREP: EVS version 0
      2016-04-27 16:34:55 140359035238528 [Note] WSREP: gcomm: connecting to group 'my_wsrep_cluster', peer '172.31.22.174:'
      2016-04-27 16:34:55 140359035238528 [Note] WSREP: (4384a074, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 
      2016-04-27 16:34:56 140359035238528 [Note] WSREP: declaring 4856263a at tcp://172.31.22.174:4567 stable
      2016-04-27 16:34:56 140359035238528 [Warning] WSREP: no nodes coming from prim view, prim not possible
      2016-04-27 16:34:56 140359035238528 [Note] WSREP: view(view_id(NON_PRIM,4384a074,4) memb {
      	4384a074,0
      	4856263a,0
      } joined {
      } left {
      } partitioned {
      })
      2016-04-27 16:34:56 140359035238528 [Note] WSREP: promote to primary component
      2016-04-27 16:34:56 140359035238528 [Note] WSREP: view(view_id(PRIM,4384a074,4) memb {
      	4384a074,0
      	4856263a,0
      } joined {
      } left {
      } partitioned {
      })
      2016-04-27 16:34:56 140359035238528 [Note] WSREP: save pc into disk
      

      But eventually, mysqld will abort when it supposedly attempts to SST, but fails:

      2016-04-27 16:34:56 140359035238528 [Note] WSREP: Waiting for SST to complete.
      2016-04-27 16:34:56 140358755280640 [Note] WSREP: STATE EXCHANGE: sent state msg: 8104c0a0-0cb7-11e6-8d89-32b3ced6c311
      2016-04-27 16:34:56 140358755280640 [Note] WSREP: STATE EXCHANGE: got state msg: 8104c0a0-0cb7-11e6-8d89-32b3ced6c311 from 0 ()
      2016-04-27 16:34:56 140358755280640 [Note] WSREP: STATE EXCHANGE: got state msg: 8104c0a0-0cb7-11e6-8d89-32b3ced6c311 from 1 ()
      2016-04-27 16:34:56 140358755280640 [Warning] WSREP: Quorum: No node with complete state:
       
       
      	Version      : 3
      	Flags        : 0x5
      	Protocols    : 0 / 7 / 3
      	State        : NON-PRIMARY
      	Prim state   : NON-PRIMARY
      	Prim UUID    : 00000000-0000-0000-0000-000000000000
      	Prim  seqno  : -1
      	First seqno  : -1
      	Last  seqno  : -1
      	Prim JOINED  : 0
      	State UUID   : 8104c0a0-0cb7-11e6-8d89-32b3ced6c311
      	Group UUID   : 00000000-0000-0000-0000-000000000000
      	Name         : ''
      	Incoming addr: '172.31.19.192:3306'
       
      	Version      : 3
      	Flags        : 0x4
      	Protocols    : 0 / 7 / 3
      	State        : NON-PRIMARY
      	Prim state   : NON-PRIMARY
      	Prim UUID    : 00000000-0000-0000-0000-000000000000
      	Prim  seqno  : -1
      	First seqno  : -1
      	Last  seqno  : -1
      	Prim JOINED  : 0
      	State UUID   : 8104c0a0-0cb7-11e6-8d89-32b3ced6c311
      	Group UUID   : 00000000-0000-0000-0000-000000000000
      	Name         : ''
      	Incoming addr: '172.31.22.174:3306'
       
      2016-04-27 16:34:56 140358755280640 [Warning] WSREP: No re-merged primary component found.
      2016-04-27 16:34:56 140358755280640 [Note] WSREP: Bootstrapped primary 00000000-0000-0000-0000-000000000000 found: 2.
      2016-04-27 16:34:56 140358755280640 [Note] WSREP: Quorum results:
      	version    = 3,
      	component  = PRIMARY,
      	conf_id    = -1,
      	members    = 2/2 (joined/total),
      	act_id     = -1,
      	last_appl. = -1,
      	protocols  = 0/7/3 (gcs/repl/appl),
      	group UUID = 00000000-0000-0000-0000-000000000000
      2016-04-27 16:34:56 140358755280640 [Note] WSREP: Flow-control interval: [23, 23]
      2016-04-27 16:34:56 140358755280640 [Note] WSREP: Restored state OPEN -> JOINED (-1)
      2016-04-27 16:34:56 140359034923776 [Note] WSREP: New cluster view: global state: :-1, view# 0: Primary, number of nodes: 2, my index: 0, protocol version 3
      2016-04-27 16:34:56 140359035238528 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
      2016-04-27 16:34:56 140359035238528 [ERROR] Aborting
       
      Error in my_thread_global_end(): 1 threads didn't exit
      

      I suspect the failure might be caused because Group UUID is 00000000-0000-0000-0000-000000000000, even though grastate.dat and gvwstate.dat both seem to have valid values. It seems as though the server is ignoring the valid Group UUID, or it is not being transmitted or received properly.

      When the server SSTs during a normal startup in which automatic recovery is not attempted, everything works fine. This only seems to happen during recovery.

      The configuration files for these nodes look like this:

      [mariadb-10.1]
      log_bin=mariadb-bin
      binlog_format=row
      gtid_domain_id=1
      server_id=1
      gtid_strict_mode=ON
      log_error=mysqld.err
      log_slave_updates
      wsrep_on=ON
      wsrep_provider=/usr/lib64/galera/libgalera_smm.so
      wsrep_cluster_address="gcomm://172.31.22.174"
      wsrep_gtid_domain_id=3
      wsrep_gtid_mode=ON
      default_storage_engine=InnoDB
      innodb_autoinc_lock_mode=2
      query_cache_size=0
      wsrep_sst_method=rsync
      

      The galera provider being used is 25.3.15.

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                nirbhay_c Nirbhay Choubey
                Reporter:
                GeoffMontee Geoff Montee
              • Votes:
                1 Vote for this issue
                Watchers:
                5 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: