Client state history, fixed races in server state, logging improv

include/wsrep/client_state.hpp

@@ -582,6 +582,7 @@ namespace wsrep
             , mode_(mode)
             , toi_mode_()
             , state_(s_none)
+            , state_hist_()
             , transaction_(*this)
             , toi_meta_()
             , allow_dirty_reads_()
@@ -612,6 +613,7 @@ namespace wsrep
         enum mode mode_;
         enum mode toi_mode_;
         enum state state_;
+        std::vector<enum state> state_hist_;
         wsrep::transaction transaction_;
         wsrep::ws_meta toi_meta_;
         bool allow_dirty_reads_;

src/client_state.cpp

@@ -18,6 +18,7 @@ wsrep::provider& wsrep::client_state::provider() const
 void wsrep::client_state::open(wsrep::client_id id)
 {
     wsrep::unique_lock<wsrep::mutex> lock(mutex_);
+    assert(state_ == s_none);
     debug_log_state("open: enter");
     owning_thread_id_ = wsrep::this_thread::get_id();
     current_thread_id_ = owning_thread_id_;
@@ -302,11 +303,12 @@ void wsrep::client_state::debug_log_state(const char* context) const
 {
     if (debug_log_level() >= 1)
     {
-        wsrep::log_debug() << "client_state: " << context
+        wsrep::log_debug() << context
-                           << ": server: " << server_state_.name()
+                           << "(" << id_.get()
-                           << " client: " << id_.get()
+                           << "," << to_c_string(state_)
-                           << " state: " << to_c_string(state_)
+                           << "," << to_c_string(mode_)
-                           << " current_error: " << current_error_;
+                           << "," << wsrep::to_string(current_error_)
+                           << ")";
     }
 }
 
@@ -327,7 +329,12 @@ void wsrep::client_state::state(
         };
     if (allowed[state_][state])
     {
+        state_hist_.push_back(state_);
         state_ = state;
+        if (state_hist_.size() > 10)
+        {
+            state_hist_.erase(state_hist_.begin());
+        }
     }
     else
     {

src/server_state.cpp

@@ -388,13 +388,14 @@ int wsrep::server_state::start_sst(const std::string& sst_request,
 void wsrep::server_state::sst_sent(const wsrep::gtid& gtid, int error)
 {
     wsrep::log_info() << "SST sent: " << gtid << ": " << error;
+    wsrep::unique_lock<wsrep::mutex> lock(mutex_);
+    state(lock, s_joined);
+    lock.unlock();
     if (provider_->sst_sent(gtid, error))
     {
         server_service_.log_message(wsrep::log::warning,
                                     "SST sent returned an error");
     }
-    wsrep::unique_lock<wsrep::mutex> lock(mutex_);
-    state(lock, s_joined);
 }
 
 void wsrep::server_state::sst_transferred(const wsrep::gtid& gtid)
@@ -429,12 +430,13 @@ void wsrep::server_state::sst_transferred(const wsrep::gtid& gtid)
 void wsrep::server_state::sst_received(const wsrep::gtid& gtid, int error)
 {
     wsrep::log_info() << "SST received: " << gtid << ": " << error;
+    wsrep::unique_lock<wsrep::mutex> lock(mutex_);
+    state(lock, s_joined);
+    lock.unlock();
     if (provider_->sst_received(gtid, error))
     {
         throw wsrep::runtime_error("SST received failed");
     }
-    wsrep::unique_lock<wsrep::mutex> lock(mutex_);
-    state(lock, s_joined);
 }
 
 void wsrep::server_state::initialized()
@@ -442,6 +444,7 @@ void wsrep::server_state::initialized()
     wsrep::unique_lock<wsrep::mutex> lock(mutex_);
     wsrep::log_info() << "Server initialized";
     init_initialized_ = true;
+    state(lock, s_initialized);
     if (sst_gtid_.is_undefined() == false &&
         server_service_.sst_before_init())
     {
@@ -453,7 +456,6 @@ void wsrep::server_state::initialized()
         lock.lock();
         sst_gtid_ = wsrep::gtid::undefined();
     }
-    state(lock, s_initialized);
 }
 
 void wsrep::server_state::wait_until_state(

src/transaction.cpp

@@ -968,11 +968,11 @@ void wsrep::transaction::debug_log_state(
 {
     WSREP_TC_LOG_DEBUG(
         1, context
-        << ": server: " << client_state_.server_state().name()
+        << "(" << client_state_.id().get()
-        << " client: " << client_state_.id().get()
+        << "," << int64_t(id_.get())
-        << " trx: " << int64_t(id_.get())
+        << "," << ws_meta_.seqno().get()
-        << " seqno: " << ws_meta_.seqno().get()
+        << "," << wsrep::to_string(state_)
-        << " state: " << wsrep::to_string(state_)
+        << ","
-        << " error: "
+        << wsrep::to_string(client_state_.current_error())
-        << wsrep::to_string(client_state_.current_error()));
+        << ")");
 }