Merge branch '2.3' into 2.4

include/maxscale/session.hh

@@ -602,6 +602,16 @@ void session_dump_statements(MXS_SESSION* pSession);
  */
 void session_set_dump_statements(session_dump_statements_t value);
 
+void session_set_session_trace(uint32_t value);
+
+uint32_t session_get_session_trace();
+
+std::string session_get_session_log(MXS_SESSION* pSession);
+
+void session_append_log(MXS_SESSION* pSession, std::string log);
+
+void session_dump_log(MXS_SESSION* pSession);
+
 /**
  * @brief Returns in what contexts statements should be dumped.
  *

maxctrl/lib/common.js

@@ -144,7 +144,7 @@ module.exports = function() {
             str = str.replace( /\x1B\[[(?);]{0,2}(;?\d)*./g, '')
 
             // Trim trailing whitespace that cli-table generates
-            str = str.split(os.EOL).map(s => s.split('\t').map(s => s.trimEnd()).join('\t')).join(os.EOL)
+            str = str.split(os.EOL).map(s => s.split('\t').map(s => s.trim()).join('\t')).join(os.EOL)
         }
         return str
     }

maxctrl/lib/show.js

@@ -59,7 +59,8 @@ const session_fields = [
     {'Idle': 'attributes.idle'},
     {'Connections': 'attributes.connections[].server'},
     {'Connection IDs': 'attributes.connections[].protocol_diagnostics.connection_id'},
-    {'Queries': 'attributes.queries[].statement'}
+    {'Queries': 'attributes.queries[].statement'},
+    {'Log': 'attributes.log'}
 ]
 
 const filter_fields = [

maxscale-system-test/mysqlmon_multimaster.cpp

@@ -56,7 +56,7 @@ json_t* get_json_data(TestConnections& test, const char* query)
     char* output = test.maxscales->ssh_node_output(0, query, true, &exit_code);
     if (output == NULL)
     {
-        test.add_result(1, "Query '%s' execution error, no output.\ni", output);
+        test.add_result(1, "Query '%s' execution error, no output.", query);
     }
     else
     {

maxutils/maxbase/include/maxbase/log.h

@@ -85,6 +85,8 @@ typedef struct MXB_LOG_THROTTLING
  */
 typedef size_t (* mxb_log_context_provider_t)(char* buffer, size_t len);
 
+typedef void (* mxb_in_memory_log_t)(const char* buffer, size_t len);
+
 /**
  * @brief Initialize the log
  *
@@ -105,7 +107,8 @@ bool mxb_log_init(const char* ident,
                   const char* logdir,
                   const char* filename,
                   mxb_log_target_t target,
-                  mxb_log_context_provider_t context_provider);
+                  mxb_log_context_provider_t context_provider,
+                  mxb_in_memory_log_t in_memory_log);
 
 /**
  * @brief Finalize the log
@@ -150,6 +153,8 @@ const char* mxb_log_get_filename();
  */
 bool mxb_log_set_priority_enabled(int priority, bool enabled);
 
+bool mxb_log_get_session_trace();
+
 /**
  * Query whether a particular syslog priority is enabled.
  *
@@ -233,6 +238,14 @@ void mxb_log_get_throttling(MXB_LOG_THROTTLING* throttling);
  */
 void mxs_log_redirect_stdout(bool redirect);
 
+/**
+ * Set session specific in-memory log
+ *
+ * @param enabled True or false to enable or disable session in-memory logging
+ */
+void mxb_log_set_session_trace(bool enabled);
+
+
 /**
  * Log a message of a particular priority.
  *
@@ -278,7 +291,7 @@ int mxb_log_oom(const char* message);
  *            MXB_ERROR, MXB_WARNING, etc. macros instead.
  */
 #define MXB_LOG_MESSAGE(priority, format, ...) \
-    (mxb_log_is_priority_enabled(priority)   \
+    (mxb_log_is_priority_enabled(priority) || mxb_log_get_session_trace()  \
      ? mxb_log_message(priority, MXB_MODULE_NAME, __FILE__, __LINE__, __func__, format, ##__VA_ARGS__)  \
      : 0)
 

maxutils/maxbase/include/maxbase/log.hh

@@ -30,7 +30,7 @@
  */
 inline bool mxb_log_init(mxb_log_target_t target = MXB_LOG_TARGET_FS)
 {
-    return mxb_log_init(nullptr, ".", nullptr, target, nullptr);
+    return mxb_log_init(nullptr, ".", nullptr, target, nullptr, nullptr);
 }
 
 namespace maxbase
@@ -52,16 +52,17 @@ public:
         const char* logdir,
         const char* filename,
         mxb_log_target_t target,
-        mxb_log_context_provider_t context_provider)
+        mxb_log_context_provider_t context_provider,
+        mxb_in_memory_log_t in_memory_log)
     {
-        if (!mxb_log_init(ident, logdir, filename, target, context_provider))
+        if (!mxb_log_init(ident, logdir, filename, target, context_provider, in_memory_log))
         {
             throw std::runtime_error("Failed to initialize the log.");
         }
     }
 
     Log(mxb_log_target_t target = MXB_LOG_TARGET_FS)
-        : Log(nullptr, ".", nullptr, target, nullptr)
+        : Log(nullptr, ".", nullptr, target, nullptr, nullptr)
     {
     }
 

maxutils/maxbase/include/maxbase/maxbase.hh

@@ -78,7 +78,8 @@ public:
             const char* zLogdir,
             const char* zFilename,
             mxb_log_target_t target,
-            mxb_log_context_provider_t context_provider);
+            mxb_log_context_provider_t context_provider,
+            mxb_in_memory_log_t in_memory_log);
 
     /**
      * @brief Initializes MaxBase and the MaxBase log.
@@ -88,7 +89,7 @@ public:
      * @throws std::runtime_error if the initialization failed.
      */
     MaxBase(mxb_log_target_t target)
-        : MaxBase(nullptr, ".", nullptr, target, nullptr)
+        : MaxBase(nullptr, ".", nullptr, target, nullptr, nullptr)
     {
     }
 

maxutils/maxbase/src/log.cc

@@ -386,10 +386,12 @@ struct this_unit
     bool                             do_syslog;         // Can change during the lifetime of log_manager.
     bool                             do_maxlog;         // Can change during the lifetime of log_manager.
     bool                             redirect_stdout;
+    bool                             session_trace;
     MXB_LOG_THROTTLING               throttling;        // Can change during the lifetime of log_manager.
     std::unique_ptr<mxb::Logger>     sLogger;
     std::unique_ptr<MessageRegistry> sMessage_registry;
     size_t                           (* context_provider)(char* buffer, size_t len);
+    void                             (* in_memory_log)(const char* buffer, size_t len);
 } this_unit =
 {
     DEFAULT_LOG_AUGMENTATION,   // augmentation
@@ -397,6 +399,7 @@ struct this_unit
     true,                       // do_syslog
     true,                       // do_maxlog
     false,                      // redirect_stdout
+    false,                      // session_trace
     DEFAULT_LOG_THROTTLING,     // throttling
 };
 
@@ -449,7 +452,8 @@ bool mxb_log_init(const char* ident,
                   const char* logdir,
                   const char* filename,
                   mxb_log_target_t target,
-                  mxb_log_context_provider_t context_provider)
+                  mxb_log_context_provider_t context_provider,
+                  mxb_in_memory_log_t in_memory_log)
 {
     assert(!this_unit.sLogger && !this_unit.sMessage_registry);
 
@@ -511,6 +515,7 @@ bool mxb_log_init(const char* ident,
     if (this_unit.sLogger && this_unit.sMessage_registry)
     {
         this_unit.context_provider = context_provider;
+        this_unit.in_memory_log = in_memory_log;
 
         openlog(ident, LOG_PID | LOG_ODELAY, LOG_USER);
     }
@@ -614,6 +619,16 @@ void mxs_log_redirect_stdout(bool redirect)
     this_unit.redirect_stdout = redirect;
 }
 
+void mxb_log_set_session_trace(bool enabled)
+{
+    this_unit.session_trace = enabled;
+}
+
+bool mxb_log_get_session_trace()
+{
+    return this_unit.session_trace;
+}
+
 bool mxb_log_rotate()
 {
     bool rval = this_unit.sLogger->rotate();
@@ -874,7 +889,19 @@ int mxb_log_message(int priority,
                 // Add a final newline into the message
                 msg.push_back('\n');
 
-                err = this_unit.sLogger->write(msg.c_str(), msg.length()) ? 0 : -1;
+                if (this_unit.session_trace)
+                {
+                    this_unit.in_memory_log(msg.c_str(), msg.length());
+                }
+
+                if (mxb_log_is_priority_enabled(priority))
+                {
+                    err = this_unit.sLogger->write(msg.c_str(), msg.length()) ? 0 : -1;
+                }
+                else
+                {
+                    err = 0;
+                }
             }
         }
     }

maxutils/maxbase/src/maxbase.cc

@@ -92,14 +92,15 @@ MaxBase::MaxBase(const char* zIdent,
                  const char* zLogdir,
                  const char* zFilename,
                  mxb_log_target_t target,
-                 mxb_log_context_provider_t context_provider)
+                 mxb_log_context_provider_t context_provider,
+                 mxb_in_memory_log_t in_memory_log)
     : m_log_inited(false)
 {
     const char* zMessage = nullptr;
 
     if (maxbase::init())
     {
-        m_log_inited = mxb_log_init(zIdent, zLogdir, zFilename, target, context_provider);
+        m_log_inited = mxb_log_init(zIdent, zLogdir, zFilename, target, context_provider, in_memory_log);
 
         if (!m_log_inited)
         {

server/core/config.cc

@@ -172,6 +172,7 @@ const char CN_SERVER[] = "server";
 const char CN_SERVICES[] = "services";
 const char CN_SERVICE[] = "service";
 const char CN_SESSIONS[] = "sessions";
+const char CN_SESSION_TRACE[] = "session_trace";
 const char CN_SESSION_TRACK_TRX_STATE[] = "session_track_trx_state";
 const char CN_SKIP_PERMISSION_CHECKS[] = "skip_permission_checks";
 const char CN_SOCKET[] = "socket";
@@ -393,6 +394,11 @@ const MXS_MODULE_PARAM config_service_params[] =
         MXS_MODULE_PARAM_INT,
         "-1"
     },
+    {
+        CN_SESSION_TRACE,
+        MXS_MODULE_PARAM_BOOL,
+        "false"
+    },
     {
         CN_CLUSTER,
         MXS_MODULE_PARAM_STRING
@@ -2729,6 +2735,21 @@ static int handle_global_item(const char* name, const char* value)
             return 0;
         }
     }
+    else if (strcmp(name, CN_SESSION_TRACE) == 0)
+    {
+        char* endptr;
+        int intval = strtol(value, &endptr, 0);
+        if (*endptr == '\0' && intval >= 0)
+        {
+            session_set_session_trace(intval);
+            mxb_log_set_session_trace(true);
+        }
+        else
+        {
+            MXS_ERROR("Invalid value for '%s': %s", CN_SESSION_TRACE, value);
+            return 0;
+        }
+    }
     else if (strcmp(name, CN_LOAD_PERSISTED_CONFIGS) == 0)
     {
         int b = config_truth_value(value);

server/core/gateway.cc

@@ -433,6 +433,7 @@ static void sigfatal_handler(int i)
         if (dcb->session)
         {
             session_dump_statements(dcb->session);
+            session_dump_log(dcb->session);
         }
     }
 

server/core/internal/session.hh

@@ -160,7 +160,7 @@ public:
     };
 
     typedef std::deque<QueryInfo> QueryInfos;
-
+    using Log = std::deque<std::string>;
     using FilterList = std::vector<SessionFilter>;
 
     Session(const SListener& listener);
@@ -187,8 +187,11 @@ public:
     void book_server_response(SERVER* pServer, bool final_response);
     void book_last_as_complete();
     void reset_server_bookkeeping();
+    void append_session_log(std::string);
+    void dump_session_log();
 
     json_t* queries_as_json() const;
+    json_t* log_as_json() const;
 
     void link_backend_dcb(DCB* dcb)
     {
@@ -214,6 +217,7 @@ private:
     int               m_current_query = -1;     /*< The index of the current query */
     DCBSet            m_dcb_set;                /*< Set of associated backend DCBs */
     uint32_t          m_retain_last_statements; /*< How many statements be retained */
+    Log               m_log;                    /*< Session specific in-memory log */
 };
 }
 

server/core/log.cc

@@ -54,13 +54,22 @@ size_t mxs_get_context(char* buffer, size_t len)
 
     return len;
 }
+
+void mxs_log_in_memory(const char* msg, size_t len)
+{
+    MXS_SESSION* session = session_get_current();
+    if (session)
+    {
+        session_append_log(session, msg);
+    }
+}
 }
 
 bool mxs_log_init(const char* ident, const char* logdir, mxs_log_target_t target)
 {
     mxb::Logger::set_ident("MariaDB MaxScale");
 
-    return mxb_log_init(ident, logdir, LOGFILE_NAME, target, mxs_get_context);
+    return mxb_log_init(ident, logdir, LOGFILE_NAME, target, mxs_get_context, mxs_log_in_memory);
 }
 
 namespace

server/core/session.cc

@@ -62,11 +62,13 @@ struct
     uint64_t                  next_session_id;
     uint32_t                  retain_last_statements;
     session_dump_statements_t dump_statements;
+    uint32_t session_trace;
 } this_unit =
 {
     1,
     0,
-    SESSION_DUMP_STATEMENTS_NEVER
+    SESSION_DUMP_STATEMENTS_NEVER,
+    0
 };
 }
 
@@ -803,6 +805,9 @@ json_t* session_json_data(const Session* session, const char* host, bool rdns)
     json_t* queries = session->queries_as_json();
     json_object_set_new(attr, "queries", queries);
 
+    json_t* log = session->log_as_json();
+    json_object_set_new(attr, "log", log);
+
     json_object_set_new(data, CN_ATTRIBUTES, attr);
     json_object_set_new(data, CN_LINKS, mxs_json_self_link(host, CN_SESSIONS, ss.str().c_str()));
 
@@ -1012,6 +1017,28 @@ void session_dump_statements(MXS_SESSION* session)
     pSession->dump_statements();
 }
 
+void session_set_session_trace(uint32_t value)
+{
+    this_unit.session_trace = value;
+}
+
+uint32_t session_get_session_trace()
+{
+    return this_unit.session_trace;
+}
+
+void session_append_log(MXS_SESSION* pSession, std::string log)
+{
+    {
+        static_cast<Session*>(pSession)->append_session_log(log);
+    }
+}
+
+void session_dump_log(MXS_SESSION* pSession)
+{
+    static_cast<Session*>(pSession)->dump_session_log();
+}
+
 class DelayedRoutingTask
 {
     DelayedRoutingTask(const DelayedRoutingTask&) = delete;
@@ -1277,6 +1304,18 @@ json_t* Session::queries_as_json() const
     return pQueries;
 }
 
+json_t* Session::log_as_json() const
+{
+    json_t* pLog = json_array();
+
+    for (const auto& i : m_log)
+    {
+        json_array_append_new(pLog, json_string(i.c_str()));
+    }
+
+    return pLog;
+}
+
 bool Session::setup_filters(Service* service)
 {
     for (const auto& a : service->get_filters())
@@ -1635,3 +1674,28 @@ void Session::QueryInfo::reset_server_bookkeeping()
     m_completed.tv_nsec = 0;
     m_complete = false;
 }
+
+void Session::append_session_log(std::string log)
+{
+    m_log.push_front(log);
+
+    if (m_log.size() >= this_unit.session_trace)
+    {
+        m_log.pop_back();
+    }
+}
+
+void Session::dump_session_log()
+{
+    if (!(m_log.empty()))
+    {
+        std::string log;
+
+        for (const auto& s : m_log)
+        {
+            log += s;
+        }
+
+        MXS_NOTICE("Session log for session (%" PRIu64"): \n%s ", ses_id, log.c_str());
+    }
+}

server/modules/protocol/MySQL/mariadbclient/mysql_client.cc

@@ -1709,6 +1709,11 @@ static int gw_client_hangup_event(DCB* dcb)
                 session_dump_statements(session);
             }
 
+            if (session_get_session_trace())
+            {
+                session_dump_log(session);
+            }
+
             // The client did not send a COM_QUIT packet
             std::string errmsg {"Connection killed by MaxScale"};
             std::string extra {session_get_close_reason(dcb->session)};

server/modules/protocol/MySQL/rwbackend.cc

@@ -304,6 +304,7 @@ void RWBackend::process_packets(GWBUF* result)
     auto it = buffer.begin();
     MXB_AT_DEBUG(size_t total_len = buffer.length());
     MXB_AT_DEBUG(size_t used_len = 0);
+    mxb_assert(dcb()->session->service->capabilities & (RCAP_TYPE_PACKET_OUTPUT | RCAP_TYPE_STMT_OUTPUT));
 
     while (it != buffer.end())
     {

server/modules/routing/readwritesplit/rwsplit_route_stmt.cc

@@ -359,7 +359,7 @@ bool RWSplitSession::route_single_stmt(GWBUF* querybuf)
             succp = true;
             MXS_INFO("Delaying routing: %s", extract_sql(querybuf).c_str());
         }
-        else
+        else if (m_config.master_failure_mode != RW_ERROR_ON_WRITE)
         {
             MXS_ERROR("Could not find valid server for target type %s, closing "
                       "connection.", route_target_to_string(route_target));

server/modules/routing/readwritesplit/rwsplitsession.cc

@@ -366,6 +366,7 @@ static void log_unexpected_response(RWBackend* backend, GWBUF* buffer, GWBUF* cu
                   backend->current_command(),
                   sql.c_str());
         session_dump_statements(backend->dcb()->session);
+        session_dump_log(backend->dcb()->session);
         mxb_assert(false);
     }
 }
@@ -1005,7 +1006,9 @@ void RWSplitSession::handleError(GWBUF* errmsgbuf,
                 MXS_INFO("Master '%s' failed: %s", backend->name(), extract_error(errmsgbuf).c_str());
                 /** The connection to the master has failed */
 
-                if (!backend->is_waiting_result())
+                bool expected_response = backend->is_waiting_result();
+
+                if (!expected_response)
                 {
                     /** The failure of a master is not considered a critical
                      * failure as partial functionality still remains. If
@@ -1041,14 +1044,6 @@ void RWSplitSession::handleError(GWBUF* errmsgbuf,
                         can_continue = true;
                         send_readonly_error(m_client);
                     }
-
-                    // Decrement the expected response count only if we know we can continue the sesssion.
-                    // This keeps the internal logic sound even if another query is routed before the session
-                    // is closed.
-                    if (can_continue)
-                    {
-                        m_expected_responses--;
-                    }
                 }
 
                 if (session_trx_is_active(session) && m_otrx_state == OTRX_INACTIVE)
@@ -1076,6 +1071,14 @@ void RWSplitSession::handleError(GWBUF* errmsgbuf,
                     }
                 }
 
+                // Decrement the expected response count only if we know we can continue the sesssion.
+                // This keeps the internal logic sound even if another query is routed before the session
+                // is closed.
+                if (can_continue && expected_response)
+                {
+                    m_expected_responses--;
+                }
+
                 backend->close();
                 backend->set_close_reason("Master connection failed: " + extract_error(errmsgbuf));
             }

server/modules/routing/schemarouter/schemarouterinstance.cc

@@ -264,9 +264,12 @@ json_t* SchemaRouter::diagnostics_json() const
     return rval;
 }
 
+static const uint64_t CAPABILITIES = RCAP_TYPE_CONTIGUOUS_INPUT | RCAP_TYPE_PACKET_OUTPUT
+    | RCAP_TYPE_RUNTIME_CONFIG;
+
 uint64_t SchemaRouter::getCapabilities()
 {
-    return RCAP_TYPE_CONTIGUOUS_INPUT | RCAP_TYPE_RUNTIME_CONFIG;
+    return schemarouter::CAPABILITIES;
 }
 }
 
@@ -280,7 +283,6 @@ uint64_t SchemaRouter::getCapabilities()
  */
 extern "C" MXS_MODULE* MXS_CREATE_MODULE()
 {
-    static uint64_t caps = RCAP_TYPE_CONTIGUOUS_INPUT | RCAP_TYPE_RUNTIME_CONFIG;
     static auto desc = "A database sharding router for simple sharding";
     static MXS_MODULE info =
     {
@@ -289,7 +291,7 @@ extern "C" MXS_MODULE* MXS_CREATE_MODULE()
         MXS_ROUTER_VERSION,
         desc,
         "V1.0.0",
-        caps,
+        schemarouter::CAPABILITIES,
         &schemarouter::SchemaRouter::s_object,
         NULL,
         NULL,

server/modules/routing/schemarouter/schemaroutersession.cc

@@ -1192,11 +1192,13 @@ char* get_lenenc_str(void* data)
     return rval;
 }
 
+static const std::set<std::string> always_ignore = {"mysql", "information_schema", "performance_schema"};
+
 bool SchemaRouterSession::ignore_duplicate_database(const char* data)
 {
     bool rval = false;
 
-    if (m_config->ignored_dbs.find(data) != m_config->ignored_dbs.end())
+    if (m_config->ignored_dbs.count(data) || always_ignore.count(data))
     {
         rval = true;
     }
@@ -1379,8 +1381,7 @@ void SchemaRouterSession::query_databases()
                                          "LEFT JOIN information_schema.tables AS t ON s.schema_name = t.table_schema "
                                          "WHERE t.table_name IS NULL "
                                          "UNION "
-                                         "SELECT CONCAT (table_schema, '.', table_name) FROM information_schema.tables "
+                                         "SELECT CONCAT (table_schema, '.', table_name) FROM information_schema.tables");
-                                         "WHERE table_schema NOT IN ('information_schema', 'performance_schema', 'mysql');");
     gwbuf_set_type(buffer, GWBUF_TYPE_COLLECT_RESULT);
 
     for (SSRBackendList::iterator it = m_backends.begin(); it != m_backends.end(); it++)