galera_server role failed to (re)start mysql in M->N upgrade

[Qin Wang]

M->N(master) upgrade in an AIO environment.

From galera_server_error.log:

160921 16:14:09 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
160921 16:14:09 mysqld_safe WSREP: Running position recovery with --log_error='/var/lib/mysql/wsrep_recovery.2dL2zZ' --pid-file='/var/lib/mysql/aio1-galera-container-cf83b90d-recover.pid'
160921 16:14:09 [Note] /usr/sbin/mysqld (mysqld 10.0.27-MariaDB-1~trusty-wsrep) starting as process 19358 ...
160921 16:14:12 mysqld_safe WSREP: Recovered position de194b29-7f64-11e6-bbad-375984386117:5811
160921 16:14:12 [Note] /usr/sbin/mysqld (mysqld 10.0.27-MariaDB-1~trusty-wsrep) starting as process 19400 ...
160921 16:14:12 [Note] WSREP: Read nil XID from storage engines, skipping position init
160921 16:14:12 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
160921 16:14:12 [Note] WSREP: wsrep_load(): Galera 25.3.17(r3619) by Codership Oy <email address hidden> loaded successfully.
160921 16:14:12 [Note] WSREP: CRC-32C: using hardware acceleration.
160921 16:14:12 [Note] WSREP: Found saved state: de194b29-7f64-11e6-bbad-375984386117:-1
160921 16:14:12 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 172.29.236.148; base_port = 4567; cert.log_conflicts = no; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.size = 32M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc.ignore_quorum = false
160921 16:14:12 [Note] WSREP: Service thread queue flushed.
160921 16:14:12 [Note] WSREP: Assign initial position for certification: 5811, protocol version: -1
160921 16:14:12 [Note] WSREP: wsrep_sst_grab()
160921 16:14:12 [Note] WSREP: Start replication
160921 16:14:12 [Note] WSREP: Setting initial position to de194b29-7f64-11e6-bbad-375984386117:5811
160921 16:14:12 [Note] WSREP: protonet asio version 0
160921 16:14:12 [Note] WSREP: Using CRC-32C for message checksums.
160921 16:14:12 [Note] WSREP: backend: asio
160921 16:14:12 [Note] WSREP: gcomm thread scheduling priority set to other:0
160921 16:14:12 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
160921 16:14:12 [Note] WSREP: restore pc from disk failed
160921 16:14:12 [Note] WSREP: GMCast version 0
160921 16:14:12 [Note] WSREP: (6f29235f, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
160921 16:14:12 [Note] WSREP: (6f29235f, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
160921 16:14:12 [Note] WSREP: EVS version 0
160921 16:14:12 [Note] WSREP: gcomm: connecting to group 'openstack_galera_cluster', peer '172.29.236.148:'
160921 16:14:12 [Note] WSREP: (6f29235f, 'tcp://0.0.0.0:4567') connection established to 6f29235f tcp://172.29.236.148:4567
160921 16:14:12 [Warning] WSREP: (6f29235f, 'tcp://0.0.0.0:4567') address 'tcp://172.29.236.148:4567' points to own listening address, blacklisting
160921 16:14:12 [Note] WSREP: (6f29235f, 'tcp://0.0.0.0:4567') connection established to 6f29235f tcp://172.29.236.148:4567
160921 16:14:15 [Warning] WSREP: no nodes coming from prim view, prim not possible
160921 16:14:15 [Note] WSREP: view(view_id(NON_PRIM,6f29235f,1) memb {
        6f29235f,0
} joined {
} left {
} partitioned {
})
160921 16:14:15 [Warning] WSREP: last inactive check more than PT1.5S ago (PT3.50168S), skipping check
160921 16:14:45 [Note] WSREP: view((empty))
160921 16:14:45 [ERROR] WSREP: failed to open gcomm backend connection: 110: failed to reach primary view: 110 (Connection timed out)
         at gcomm/src/pc.cpp:connect():162
160921 16:14:45 [ERROR] WSREP: gcs/src/gcs_core.cpp:gcs_core_open():208: Failed to open backend connection: -110 (Connection timed out)
160921 16:14:45 [ERROR] WSREP: gcs/src/gcs.cpp:gcs_open():1380: Failed to open channel 'openstack_galera_cluster' at 'gcomm://172.29.236.148': -110 (Connection timed out)
160921 16:14:45 [ERROR] WSREP: gcs connect failed: Connection timed out
160921 16:14:45 [ERROR] WSREP: wsrep::connect(gcomm://172.29.236.148) failed: 7
160921 16:14:45 [ERROR] Aborting

160921 16:14:45 [Note] WSREP: Service disconnected.
160921 16:14:46 [Note] WSREP: Some threads may fail to exit.
160921 16:14:46 [Note] /usr/sbin/mysqld: Shutdown complete

160921 16:14:46 mysqld_safe mysqld from pid file /var/lib/mysql/aio1-galera-container-cf83b90d.pid ended

[SHASHANK TAVILDAR (shasha.tavil)]

Workaround: http://paste.openstack.org/show/582280/

[Jean-Philippe Evrard (jean-philippe-evrard)]

Duplicate of this:
https://bugs.launchpad.net/openstack-ansible/+bug/1624327