LP #1229968: xtrabackup sst clobber clobbers error log

**Reported in Launchpad by Jay Janssen last update 12-11-2013 18:46:22

130924 22:05:24 [Note] WSREP: Requesting state transfer: success, donor: 1
WSREP_SST: [INFO] Proceeding with SST (20130924 22:05:26.055)
WSREP_SST: [INFO] Cleaning the existing datadir (20130924 22:05:26.058)
removed `/var/lib/mysql/backup-my.cnf'
removed `/var/lib/mysql/error.log'
removed `/var/lib/mysql/mysql/db.frm'
removed `/var/lib/mysql/mysql/db.MYI'
removed `/var/lib/mysql/mysql/db.MYD'
removed `/var/lib/mysql/mysql/host.frm'
removed `/var/lib/mysql/mysql/host.MYI'
removed `/var/lib/mysql/mysql/host.MYD'
removed `/var/lib/mysql/mysql/user.frm'
removed `/var/lib/mysql/mysql/user.MYI'
removed `/var/lib/mysql/mysql/user.MYD'
removed `/var/lib/mysql/mysql/func.frm'
removed `/var/lib/mysql/mysql/func.MYI'
removed `/var/lib/mysql/mysql/func.MYD'
removed `/var/lib/mysql/mysql/plugin.frm'
removed `/var/lib/mysql/mysql/plugin.MYI'
removed `/var/lib/mysql/mysql/plugin.MYD'
removed `/var/lib/mysql/mysql/servers.frm'
removed `/var/lib/mysql/mysql/servers.MYI'
removed `/var/lib/mysql/mysql/servers.MYD'
removed `/var/lib/mysql/mysql/tables_priv.frm'
removed `/var/lib/mysql/mysql/tables_priv.MYI'
removed `/var/lib/mysql/mysql/tables_priv.MYD'
removed `/var/lib/mysql/mysql/columns_priv.frm'
removed `/var/lib/mysql/mysql/columns_priv.MYI'
removed `/var/lib/mysql/mysql/columns_priv.MYD'
removed `/var/lib/mysql/mysql/help_topic.frm'
removed `/var/lib/mysql/mysql/help_topic.MYI'
removed `/var/lib/mysql/mysql/help_topic.MYD'
removed `/var/lib/mysql/mysql/help_category.frm'
removed `/var/lib/mysql/mysql/help_category.MYI'
removed `/var/lib/mysql/mysql/help_category.MYD'
removed `/var/lib/mysql/mysql/help_relation.frm'
removed `/var/lib/mysql/mysql/help_relation.MYI'
removed `/var/lib/mysql/mysql/help_relation.MYD'
removed `/var/lib/mysql/mysql/help_keyword.frm'
removed `/var/lib/mysql/mysql/help_keyword.MYI'
removed `/var/lib/mysql/mysql/help_keyword.MYD'
removed `/var/lib/mysql/mysql/time_zone_name.frm'
removed `/var/lib/mysql/mysql/time_zone_name.MYI'
removed `/var/lib/mysql/mysql/time_zone_name.MYD'
removed `/var/lib/mysql/mysql/time_zone.frm'
removed `/var/lib/mysql/mysql/time_zone.MYI'
removed `/var/lib/mysql/mysql/time_zone.MYD'
removed `/var/lib/mysql/mysql/time_zone_transition.frm'
removed `/var/lib/mysql/mysql/time_zone_transition.MYI'
removed `/var/lib/mysql/mysql/time_zone_transition.MYD'
removed `/var/lib/mysql/mysql/time_zone_transition_type.frm'
removed `/var/lib/mysql/mysql/time_zone_transition_type.MYI'
removed `/var/lib/mysql/mysql/time_zone_transition_type.MYD'
removed `/var/lib/mysql/mysql/time_zone_leap_second.frm'
removed `/var/lib/mysql/mysql/time_zone_leap_second.MYI'
removed `/var/lib/mysql/mysql/time_zone_leap_second.MYD'
removed `/var/lib/mysql/mysql/proc.frm'
removed `/var/lib/mysql/mysql/proc.MYI'
removed `/var/lib/mysql/mysql/proc.MYD'
removed `/var/lib/mysql/mysql/procs_priv.frm'
removed `/var/lib/mysql/mysql/procs_priv.MYI'
removed `/var/lib/mysql/mysql/procs_priv.MYD'
removed `/var/lib/mysql/mysql/general_log.frm'
removed `/var/lib/mysql/mysql/general_log.CSM'
removed `/var/lib/mysql/mysql/general_log.CSV'
removed `/var/lib/mysql/mysql/slow_log.frm'
removed `/var/lib/mysql/mysql/slow_log.CSM'
removed `/var/lib/mysql/mysql/slow_log.CSV'
removed `/var/lib/mysql/mysql/event.frm'
removed `/var/lib/mysql/mysql/event.MYI'
removed `/var/lib/mysql/mysql/event.MYD'
removed `/var/lib/mysql/mysql/ndb_binlog_index.frm'
removed `/var/lib/mysql/mysql/ndb_binlog_index.MYI'
removed `/var/lib/mysql/mysql/ndb_binlog_index.MYD'
removed `/var/lib/mysql/mysql/proxies_priv.frm'
removed `/var/lib/mysql/mysql/proxies_priv.MYI'
removed `/var/lib/mysql/mysql/proxies_priv.MYD'
removed directory: `/var/lib/mysql/mysql'
removed directory: `/var/lib/mysql/test'
removed `/var/lib/mysql/performance_schema/db.opt'
removed `/var/lib/mysql/performance_schema/cond_instances.frm'
removed `/var/lib/mysql/performance_schema/events_waits_current.frm'
removed `/var/lib/mysql/performance_schema/events_waits_history.frm'
removed `/var/lib/mysql/performance_schema/events_waits_history_long.frm'
removed `/var/lib/mysql/performance_schema/events_waits_summary_by_instance.frm'
removed `/var/lib/mysql/performance_schema/events_waits_summary_by_thread_by_event_name.frm'
removed `/var/lib/mysql/performance_schema/events_waits_summary_global_by_event_name.frm'
removed `/var/lib/mysql/performance_schema/file_instances.frm'
removed `/var/lib/mysql/performance_schema/file_summary_by_event_name.frm'
removed `/var/lib/mysql/performance_schema/file_summary_by_instance.frm'
removed `/var/lib/mysql/performance_schema/mutex_instances.frm'
removed `/var/lib/mysql/performance_schema/performance_timers.frm'
removed `/var/lib/mysql/performance_schema/rwlock_instances.frm'
removed `/var/lib/mysql/performance_schema/setup_consumers.frm'
removed `/var/lib/mysql/performance_schema/setup_instruments.frm'
removed `/var/lib/mysql/performance_schema/setup_timers.frm'
removed `/var/lib/mysql/performance_schema/threads.frm'
removed directory: `/var/lib/mysql/performance_schema'
removed `/var/lib/mysql/ibdata1'
removed `/var/lib/mysql/ib_logfile0'
removed `/var/lib/mysql/ib_logfile1'
removed `/var/lib/mysql/mysql.sock'
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20130924 22:05:26.405)
WSREP_SST: [ERROR] xtrabackup process ended without creating '/var/lib/mysql//xtrabackup_galera_info' (20130924 22:05:44.432)
WSREP_SST: [INFO] Contents of datadir (20130924 22:05:44.436)
130924 22:05:44 [Warning] WSREP: 1 (ip-10-238-177-207): State transfer to 0 (ip-10-141-160-44) failed: -1 (Operation not permitted)
130924 22:05:44 [ERROR] WSREP: gcs/src/gcs_group.c:gcs_group_handle_join_msg():719: Will never receive state. Need to abort.
130924 22:05:44 [Note] WSREP: gcomm: terminating thread
130924 22:05:44 [Note] WSREP: gcomm: joining thread
130924 22:05:44 [Note] WSREP: gcomm: closing backend
WSREP_SST: [INFO] rw-rw---. 1 mysql mysql 263 Sep 24 22:05 /var/lib/mysql//backup-my.cnf
rw------. 1 mysql mysql 2147484968 Sep 24 22:05 /var/lib/mysql//galera.cache
rw-rw---. 1 mysql mysql 108 Sep 24 22:05 /var/lib/mysql//grastate.dat
rw-rw---. 1 mysql mysql 0 Sep 24 22:05 /var/lib/mysql//sst_in_progress (20130924 22:05:44.444)
WSREP_SST: [ERROR] Cleanup after exit with status:32 (20130924 22:05:44.448)
WSREP_SST: [INFO] Removing the sst_in_progress file (20130924 22:05:44.452)
130924 22:05:44 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup --role 'joiner' --address '10.141.160.44' --auth 'sst:secret' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --parent '13658': 32 (Broken pipe)
130924 22:05:44 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
130924 22:05:44 [ERROR] WSREP: SST failed: 32 (Broken pipe)
130924 22:05:44 [ERROR] Aborting

130924 22:05:45 [Note] WSREP: view(view_id(NON_PRIM,67a871a1-2565-11e3-a1fe-46b4dcd8ab8f,18) memb {
67a871a1-2565-11e3-a1fe-46b4dcd8ab8f,
} joined {
} left {
} partitioned {
9275e205-255f-11e3-b2ab-36ce11b3ab07,
ba03803a-255e-11e3-bbe4-9fbeb2b4b2a4,
})
130924 22:05:45 [Note] WSREP: view((empty))
130924 22:05:45 [Note] WSREP: gcomm: closed
130924 22:05:45 [Note] WSREP: /usr/sbin/mysqld: Terminated.
^

My SST failed, and then I have this in my datadir:

[[email protected] mysql]# ls -lah
total 2.1G
drwxr-xr-x. 2 mysql mysql 80 Sep 24 22:05 .
drwxr-xr-x. 16 root root 4.0K Sep 24 21:05 ..
rw-rw---. 1 mysql mysql 263 Sep 24 22:05 backup-my.cnf
rw-r----. 1 mysql root 91 Sep 24 22:05 error.log
rw------. 1 mysql mysql 2.1G Sep 24 22:05 galera.cache
rw-rw---. 1 mysql mysql 108 Sep 24 22:05 grastate.dat

[[email protected] mysql]# cat error.log
130924 22:05:45 mysqld_safe mysqld from pid file /var/lib/mysql/ip-10-141-160-44.pid ended
130924 22:11:14 [Note] WSREP: Read nil XID from storage engines, skipping position init
130924 22:11:14 [Note] WSREP: wsrep_load(): loading provider library 'none'
130924 22:11:14 [Note] WSREP: Service disconnected.
130924 22:11:15 [Note] WSREP: Some threads may fail to exit.
130924 22:11:15 [Note] WSREP: Read nil XID from storage engines, skipping position init
130924 22:11:15 [Note] WSREP: wsrep_load(): loading provider library 'none'
130924 22:11:15 [Note] WSREP: Service disconnected.
130924 22:11:16 [Note] WSREP: Some threads may fail to exit.

This makes it very hard to diagnose the error. I caught my initial output from my terminal window, it was not clear what happened after.