From 5c68782050f961185fe96487069db9cb0300a366 Mon Sep 17 00:00:00 2001
From: Markus Makela <markus.makela@mariadb.com>
Date: Tue, 24 Mar 2015 21:28:03 +0200
Subject: [PATCH] Added more trace logging to readcounnroute, schemarouter and
 tee.

---
 server/modules/filter/tee.c                   |  7 ++++
 server/modules/routing/readconnroute.c        | 32 +++++++++++++++++--
 .../routing/schemarouter/schemarouter.c       |  8 +++++
 3 files changed, 45 insertions(+), 2 deletions(-)

diff --git a/server/modules/filter/tee.c b/server/modules/filter/tee.c
index 8ea2dcc00..e337df726 100644
--- a/server/modules/filter/tee.c
+++ b/server/modules/filter/tee.c
@@ -1063,6 +1063,7 @@ clientReply (FILTER* instance, void *session, GWBUF *reply)
 
   if(!my_session->active)
   {
+      skygw_log_write(LOGFILE_TRACE,"Tee: Failed to return reply, session is closed");
       gwbuf_free(reply);
       rc = 0;
       if(my_session->waiting[PARENT])
@@ -1104,6 +1105,7 @@ clientReply (FILTER* instance, void *session, GWBUF *reply)
     
     if(my_session->replies[branch] == 0)
     {
+	skygw_log_write(LOGFILE_TRACE,"Tee: First reply to a query for [%s].",branch == PARENT ? "PARENT":"CHILD");
       /* Reply is in a single packet if it is an OK, ERR or LOCAL_INFILE packet.
        * Otherwise the reply is a result set and the amount of packets is unknown.
        */            
@@ -1116,6 +1118,11 @@ clientReply (FILTER* instance, void *session, GWBUF *reply)
 	  {
 	      flags = get_response_flags(ptr,true);
 	      more_results = (flags & 0x08) && my_session->client_multistatement;
+	      if(more_results)
+	      {
+		  skygw_log_write(LOGFILE_TRACE,
+			   "Tee: [%s] waiting for more results.",branch == PARENT ? "PARENT":"CHILD");
+	      }
 	  }
 	}
 #ifdef SS_DEBUG
diff --git a/server/modules/routing/readconnroute.c b/server/modules/routing/readconnroute.c
index f9d12c512..16aa637ca 100644
--- a/server/modules/routing/readconnroute.c
+++ b/server/modules/routing/readconnroute.c
@@ -89,6 +89,8 @@
 
 #include <mysql_client_server_protocol.h>
 
+#include "modutil.h"
+
 /** Defined in log_manager.cc */
 extern int            lm_enabled_logfiles_bitmask;
 extern size_t         log_ses_count[];
@@ -535,6 +537,7 @@ BACKEND *master_host = NULL;
                 pthread_self(),
                 candidate->server->port,
                 candidate->current_connection_count)));
+
         /*
 	 * Open a backend connection, putting the DCB for this
 	 * connection in the client_rses->backend_dcb
@@ -564,7 +567,13 @@ BACKEND *master_host = NULL;
 	spinlock_release(&inst->lock);
 
         CHK_CLIENT_RSES(client_rses);
-                
+
+	skygw_log_write(
+                LOGFILE_TRACE,
+		 "Readconnroute: New session for server %s. "
+                "Connections : %d",
+		 candidate->server->unique_name,
+		 candidate->current_connection_count);
 	return (void *)client_rses;
 }
 
@@ -718,10 +727,19 @@ routeQuery(ROUTER *instance, void *router_session, GWBUF *queue)
                         "Error : Failed to route MySQL command %d to backend "
                         "server.",
                         mysql_command)));
+		skygw_log_write(
+                        LOGFILE_ERROR,
+			 "Error : Failed to route MySQL command %d to backend "
+                        "server %s.",
+			 mysql_command,
+			 router_cli_ses->backend->server->unique_name);
 		rc = 0;
                 goto return_rc;
+
         }
 
+	char* trc = NULL;
+
         switch(mysql_command) {
 		case MYSQL_COM_CHANGE_USER:
 			rc = backend_dcb->func.auth(
@@ -730,7 +748,8 @@ routeQuery(ROUTER *instance, void *router_session, GWBUF *queue)
 				backend_dcb->session,
 				queue);
 			break;
-		
+		case MYSQL_COM_QUERY:
+		    trc = modutil_get_SQL(queue);
 		default:
 			rc = backend_dcb->func.write(backend_dcb, queue);
 			break;
@@ -745,6 +764,15 @@ routeQuery(ROUTER *instance, void *router_session, GWBUF *queue)
                 mysql_command,
                 backend_dcb,
                 rc)));
+
+	skygw_log_write(
+                LOGFILE_TRACE,
+		 "Routed command [%#x] to '%s'%s%s",
+		 mysql_command,
+		 backend_dcb->server->unique_name,
+		 trc?": ":".",
+		 trc?trc:"");
+	free(trc);
 return_rc:
         return rc;
 }
diff --git a/server/modules/routing/schemarouter/schemarouter.c b/server/modules/routing/schemarouter/schemarouter.c
index a386cebe4..9587f3bc4 100644
--- a/server/modules/routing/schemarouter/schemarouter.c
+++ b/server/modules/routing/schemarouter/schemarouter.c
@@ -514,6 +514,10 @@ char* get_shard_target_name(ROUTER_INSTANCE* router, ROUTER_CLIENT_SES* client,
          */
 
         rval = (char*) hashtable_fetch(ht, client->rses_mysql_session->db);
+	if(rval)
+	{
+	    skygw_log_write(LOGFILE_TRACE,"schemarouter: Using active database '%s'",client->rses_mysql_session->db);
+	}
     }
    
 	return rval;
@@ -1932,6 +1936,7 @@ static int routeQuery(
 			 */
                     
 			route_target = TARGET_ANY;
+			skygw_log_write(LOGFILE_TRACE,"schemarouter: Routing query to first available backend.");
 
 		}
 		else
@@ -2008,6 +2013,9 @@ static int routeQuery(
 
 			/**No valid backends alive*/
                         skygw_log_write(LOGFILE_TRACE,"schemarouter: No backends are running");
+			skygw_log_write(LOGFILE_ERROR,
+				 "Error: Schemarouter: Failed to route query, "
+				"no backends are available.");
 			rses_end_locked_router_action(router_cli_ses);
 			ret = 0;
 			goto retblock;