Merge branch 'Z3' of https://github.com/skysql/MaxScale into Z3

log_manager/log_manager.cc

@@ -45,6 +45,12 @@
 extern char *program_invocation_name;
 extern char *program_invocation_short_name;
 
+#if defined(SS_DEBUG) 
+static int write_index;
+static int block_start_index;
+static int prevval;
+static simple_mutex_t msg_mutex;
+#endif
 /**
  * Variable holding the enabled logfiles information.
  * Used from log users to check enabled logs prior calling
@@ -113,7 +119,7 @@ typedef struct blockbuf_st {
         skygw_chk_t    bb_chk_top;
 #endif
         logfile_id_t   bb_fileid;
-        bool           bb_isfull;   /**< closed for disk write */
+  blockbuf_state_t bb_state; /**State of the block buffer*/
         simple_mutex_t bb_mutex;    /**< bb_buf_used, bb_isfull */
         int            bb_refcount; /**< protected by list mutex. #of clients */
 //        int            bb_blankcount; /**< # of blanks used btw strings */
@@ -333,6 +339,10 @@ static bool logmanager_init_nomutex(
 #if defined(SS_DEBUG)
         lm->lm_chk_top   = CHK_NUM_LOGMANAGER;
         lm->lm_chk_tail  = CHK_NUM_LOGMANAGER;
+	write_index = 0;
+	block_start_index = 0;
+	prevval = -1;
+	simple_mutex_init(&msg_mutex, "Message mutex");
 #endif
         lm->lm_clientmes = skygw_message_init();
         lm->lm_logmes    = skygw_message_init();
@@ -652,27 +662,73 @@ static int logmanager_write_log(
                 
                 /** Findout how much can be safely written with current block size */
                 if (timestamp_len-1+str_len > lf->lf_buf_size)
-                {
+		  {
-                        safe_str_len = lf->lf_buf_size;
+		    safe_str_len = lf->lf_buf_size;
-                }
+		  }
                 else
-                {
+		  {
-                        safe_str_len = timestamp_len-1+str_len;
+		    safe_str_len = timestamp_len-1+str_len;
-                }
+		  }
+
                 /**
                  * Seek write position and register to block buffer.
                  * Then print formatted string to write position.
                  */
+
+#if defined (SS_LOG_DEBUG)
+		{
+		 
+		  char *copy,*tok;
+		  int tokval;
+
+		  simple_mutex_lock(&msg_mutex,true);
+
+		  copy = strdup(str);
+
+		  tok = strtok(copy,"|");
+
+		  tok = strtok(NULL,"|");
+
+		  if(strstr(str,"message|") && tok){
+
+		    tokval = atoi(tok);
+
+		    if(prevval > 0){
+		      ss_dassert(tokval == (prevval + 1));
+		    }
+
+		    prevval = tokval;
+		  }	  
+
+		  free(copy);
+		  simple_mutex_unlock(&msg_mutex);
+
+		}
+#endif
+
                 wp = blockbuf_get_writepos(&bb,
                                            id,
                                            safe_str_len,
                                            flush);
+
+
+#if defined (SS_LOG_DEBUG)
+		{
+		  sprintf(wp,"[msg:%d]",atomic_add(&write_index,1));
+		  safe_str_len -= strlen(wp);
+		  wp += strlen(wp);
+		}
+#endif
+
                 /**
                  * Write timestamp with at most <timestamp_len> characters
                  * to wp.
                  * Returned timestamp_len doesn't include terminating null.
                  */
                 timestamp_len = snprint_timestamp(wp, timestamp_len);
+		
+
+
                 /**
                  * Write next string to overwrite terminating null character
                  * of the timestamp string.
@@ -753,7 +809,7 @@ static int logmanager_write_log(
                                 wp_c[timestamp_len-1+str_len-1]='\n';
                             
                                 /** lock-free unregistration, includes flush if
-                                 * bb_isfull */
+                                 * bb_state == BB_FULL */
                                 blockbuf_unregister(bb_c);
                         }
                 } /* if (spread_down) */
@@ -784,7 +840,7 @@ static void blockbuf_unregister(
         /**
          * if this is the last client in a full buffer, send write request.
          */
-        if (atomic_add(&bb->bb_refcount, -1) == 1 && bb->bb_isfull) {
+        if (atomic_add(&bb->bb_refcount, -1) == 1 && bb->bb_state == BB_FULL) {
             skygw_message_send(lf->lf_logmes);
         }
         ss_dassert(bb->bb_refcount >= 0);
@@ -816,12 +872,12 @@ static char* blockbuf_get_writepos(
         size_t       str_len,
         bool         flush)
 {
-        logfile_t*     lf;
+  logfile_t*     lf;
-        mlist_t*       bb_list;
+  mlist_t*       bb_list;
-        char*          pos = NULL;
+  char*          pos = NULL;
-        mlist_node_t*  node;
+  mlist_node_t*  node;
-        blockbuf_t*    bb;
+  blockbuf_t*    bb;
-        ss_debug(bool  succp;)
+  ss_debug(bool  succp;)
 
             
         CHK_LOGMANAGER(lm);
@@ -839,6 +895,7 @@ static char* blockbuf_get_writepos(
              */
             node = bb_list->mlist_first;
 	    
+            
             /** Loop over blockbuf list to find write position */
             while (true) {
                 CHK_MLIST_NODE(node);
@@ -852,21 +909,24 @@ static char* blockbuf_get_writepos(
                 /** Lock buffer */
                 simple_mutex_lock(&bb->bb_mutex, true);
                 
-                if (bb->bb_isfull || bb->bb_buf_left < str_len) {
+                if (bb->bb_state == BB_FULL || bb->bb_buf_left < str_len) {
                     /**
                      * This block buffer is too full.
                      * Send flush request to file writer thread. This causes
                      * flushing all buffers, and (eventually) frees buffer space.
                      */
-                    blockbuf_register(bb);
+		  blockbuf_register(bb);
-                    bb->bb_isfull = true;
-                    blockbuf_unregister(bb);
 		  
-                    /** Unlock buffer */
+		  bb->bb_state = BB_FULL;
-                    simple_mutex_unlock(&bb->bb_mutex);
+
+		  blockbuf_unregister(bb);
+		  
+		  /** Unlock buffer */
+		  simple_mutex_unlock(&bb->bb_mutex);
+
+		  /** Lock list */
+		    simple_mutex_lock(&bb_list->mlist_mutex, true);
 
-                    /** Lock list */
-                    simple_mutex_lock(&bb_list->mlist_mutex, true);
 
                     /**
                      * If next node exists move forward. Else check if there is
@@ -916,7 +976,28 @@ static char* blockbuf_get_writepos(
                         node = bb_list->mlist_first;
                         continue;
                     }
-                } else {
+		 
+
+		}else if(bb->bb_state == BB_CLEARED){
+
+		  /**
+		   *Move the full buffer to the end of the list
+		   */
+
+		      simple_mutex_unlock(&bb->bb_mutex);
+		      simple_mutex_lock(&bb_list->mlist_mutex, true);
+		      
+		      if(node->mlnode_next){
+			bb_list->mlist_first = node->mlnode_next;
+			bb_list->mlist_last->mlnode_next = node;
+			node->mlnode_next = NULL;
+			bb_list->mlist_last = node;
+			node = bb_list->mlist_first;
+		      }
+
+		      bb->bb_state = BB_READY;
+
+		    }else if (bb->bb_state == BB_READY){
                     /**
                      * There is space for new log string.
                      */
@@ -924,9 +1005,11 @@ static char* blockbuf_get_writepos(
                 }
             } /** while (true) */
         } else {
+
             /**
              * Create the first block buffer to logfile's blockbuf list.
              */
+
             bb = blockbuf_init(id);
             CHK_BLOCKBUF(bb);
 
@@ -952,7 +1035,7 @@ static char* blockbuf_get_writepos(
         } /* if (bb_list->mlist_nodecount > 0) */
         
         ss_dassert(pos == NULL);
-        ss_dassert(!(bb->bb_isfull || bb->bb_buf_left < str_len));
+        ss_dassert(!(bb->bb_state == BB_FULL || bb->bb_buf_left < str_len));
         ss_dassert(bb_list->mlist_nodecount <= bb_list->mlist_nodecount_max);
 
         /**
@@ -991,7 +1074,7 @@ static char* blockbuf_get_writepos(
          * If flush flag is set, set buffer full. As a consequence, no-one
          * can write to it before it is flushed to disk.
          */
-        bb->bb_isfull = (flush == true ? true : bb->bb_isfull);
+        bb->bb_state = (flush == true ? BB_FULL : bb->bb_state);
         
         /** Unlock buffer */
         simple_mutex_unlock(&bb->bb_mutex);
@@ -1021,6 +1104,12 @@ static blockbuf_t* blockbuf_init(
         bb->bb_buf_left = MAX_LOGSTRLEN;
         bb->bb_buf_size = MAX_LOGSTRLEN;
 
+#if defined(SS_LOG_DEBUG)
+	sprintf(bb->bb_buf,"[block:%d]",atomic_add(&block_start_index,1));
+	bb->bb_buf_used += strlen(bb->bb_buf);
+	bb->bb_buf_left -= strlen(bb->bb_buf);
+#endif
+
         CHK_BLOCKBUF(bb);
         return bb;
 }
@@ -1170,6 +1259,9 @@ int skygw_log_write_flush(
         /**
          * Find out the length of log string (to be formatted str).
          */
+
+
+
         va_start(valist, str);
         len = vsnprintf(NULL, 0, str, valist);
         va_end(valist);
@@ -1220,6 +1312,9 @@ int skygw_log_write(
                 err = 1;
                 goto return_unregister;
         }
+
+
+
         /**
          * Find out the length of log string (to be formatted str).
          */
@@ -1233,6 +1328,7 @@ int skygw_log_write(
         /**
          * Write log string to buffer and add to file write list.
          */
+
         va_start(valist, str);
         err = logmanager_write_log(id, false, true, true, len, str, valist);
         va_end(valist);
@@ -2257,7 +2353,7 @@ static void filewriter_done(
  * lists of each logfile object.
  *
  * Block buffer is written to log file if
- * 1. bb_isfull == true,
+ * 1. bb_state == true,
  * 2. logfile object's lf_flushflag == true, or
  * 3. skygw_thread_must_exit returns true.
  * 
@@ -2297,7 +2393,7 @@ static void* thr_filewriter_fun(
         blockbuf_t*   bb;
         mlist_node_t* node;
         int           i;
-        bool          flush_blockbuf;   /**< flush single block buffer. */
+        blockbuf_state_t          flush_blockbuf;   /**< flush single block buffer. */
         bool          flush_logfile;    /**< flush logfile */
         bool          flushall_logfiles;/**< flush all logfiles */
         size_t        vn1;
@@ -2356,10 +2452,10 @@ static void* thr_filewriter_fun(
                                 /** Lock block buffer */
                                 simple_mutex_lock(&bb->bb_mutex, true);
 
-                                flush_blockbuf = bb->bb_isfull;
+                                flush_blockbuf = bb->bb_state;
                     
                                 if (bb->bb_buf_used != 0 &&
-                                    (flush_blockbuf ||
+                                    (flush_blockbuf == BB_FULL ||
                                      flush_logfile ||
                                      flushall_logfiles))
                                 {
@@ -2387,7 +2483,13 @@ static void* thr_filewriter_fun(
                                         bb->bb_buf_left = bb->bb_buf_size;
                                         bb->bb_buf_used = 0;
                                         memset(bb->bb_buf, 0, bb->bb_buf_size);
-                                        bb->bb_isfull = false;
+                                        bb->bb_state = BB_CLEARED;
+#if defined(SS_LOG_DEBUG)
+					sprintf(bb->bb_buf,"[block:%d]",atomic_add(&block_start_index,1));
+					bb->bb_buf_used += strlen(bb->bb_buf);
+					bb->bb_buf_left -= strlen(bb->bb_buf);
+#endif
+
                                 }
                                 /** Release lock to block buffer */
                                 simple_mutex_unlock(&bb->bb_mutex);

log_manager/log_manager.h

@@ -22,6 +22,12 @@ typedef struct logfile_st     logfile_t;
 typedef struct fnames_conf_st fnames_conf_t;
 typedef struct logmanager_st  logmanager_t;
 
+typedef enum {
+  BB_READY = 0x00,
+  BB_FULL,
+  BB_CLEARED
+} blockbuf_state_t;
+
 typedef enum {
     LOGFILE_ERROR = 1,
     LOGFILE_FIRST = LOGFILE_ERROR,

log_manager/makefile

@@ -8,6 +8,11 @@ SRCS 		:= log_manager.cc
 UTILS_PATH	:= $(ROOT_PATH)/utils
 CUR_DIR 	:= $(shell pwd)
 
+ifeq ($(ADD_DEBUG_TAGS),Y)
+CFLAGS += -DSS_LOG_DEBUG
+endif
+
+
 makeall: clean all
 
 clean:

log_manager/test/logorder.sh

@@ -0,0 +1,61 @@
+#! /bin/bash
+
+if [[ $# -lt 4 ]]
+then
+    echo "Usage: logorder.sh <iterations> <frequency of flushes> <message size>"
+    echo "To disable log flushing, use 0 for flush frequency"
+    exit
+fi
+
+rm *.log
+
+#Create large messages
+$PWD/testorder $1 $2 $3
+
+TESTLOG=$4
+MCOUNT=$1
+
+BLOCKS=`cat skygw_err1.log |tr -s ' '|grep -o 'block:[[:digit:]]\+'|cut -d ':' -f 2`
+MESSAGES=`cat skygw_err1.log |tr -s ' '|grep -o 'message|[[:digit:]]\+'|cut -d '|' -f 2`
+
+prev=0
+error=0
+
+for i in $BLOCKS
+do
+
+    if [[ $i -le $prev ]]
+    then
+	error=1
+	echo "block mismatch: $i was after $prev."  >> $TESTLOG
+    fi
+    prev=$i
+done
+
+if [[ error -eq 0 ]]
+then
+    echo "Block buffers were in order"  >> $TESTLOG
+else
+    echo "Error: block buffers were written in the wrong order"  >> $TESTLOG
+fi
+
+prev=0
+error=0
+
+for i in $MESSAGES
+do
+
+    if [[ $i -ne $(( prev + 1 )) ]]
+    then
+	error=1
+	echo "message mismatch: $i was after $prev."  >> $TESTLOG
+    fi
+    prev=$i
+done
+
+if [[ error -eq 0 ]]
+then
+    echo "Block buffer messages were in order" >> $TESTLOG
+else
+    echo "Error: block buffer messages were written in the wrong order"  >> $TESTLOG
+fi

log_manager/test/makefile

@@ -28,10 +28,13 @@ testall:
 
 cleantests:
 	- $(DEL) *.o 
+	- $(DEL) *.log 
 	- $(DEL) testlog
+	- $(DEL) testorder	
 	- $(DEL) *~
 
 buildtests:
+	$(MAKE) -C $(LOG_MANAGER_PATH) ADD_DEBUG_TAGS=Y
 	$(CC) $(CFLAGS)	 \
 	-L$(LOG_MANAGER_PATH) \
 	-Wl,-rpath,$(DEST)/lib \
@@ -41,6 +44,17 @@ buildtests:
 	-I$(LOG_MANAGER_PATH) -I$(UTILS_PATH) testlog.c \
 	-lstdc++ -llog_manager $(LDLIBS) \
 	$(UTILS_PATH)/skygw_utils.o
+	$(CC) $(CFLAGS)	 \
+	-L$(LOG_MANAGER_PATH) \
+	-Wl,-rpath,$(DEST)/lib \
+	-Wl,-rpath,$(LOG_MANAGER_PATH)/ \
+	-o testorder \
+	-I$(MARIADB_SRC_PATH)/include \
+	-I$(LOG_MANAGER_PATH) -I$(UTILS_PATH) testorder.c \
+	-lstdc++ -llog_manager $(LDLIBS) \
+	$(UTILS_PATH)/skygw_utils.o
+
+
 
 
 runtests: 
@@ -61,6 +75,10 @@ runtests:
 	@echo "Use 16 threads"			>> $(TESTLOG)
 	@echo ""				>> $(TESTLOG)
 	@-$(LAUNCH_DEBUGGER) $(TESTAPP) "-t 16"	2>>$(TESTLOG)
+	@echo ""				>>  $(TEST_MAXSCALE_LOG)
+	@echo "Test Message Order"  >> $(TEST_MAXSCALE_LOG)
+	@echo ""				>>  $(TEST_MAXSCALE_LOG)
+	./logorder.sh 500 0 500 $(TEST_MAXSCALE_LOG)
 	@echo "Log Manager PASSED"		>> $(TESTLOG)
 	@echo ""				>> $(TESTLOG)
 

log_manager/test/testorder.c

@@ -0,0 +1,105 @@
+/*
+ * This file is distributed as part of the SkySQL Gateway.  It is free
+ * software: you can redistribute it and/or modify it under the terms of the
+ * GNU General Public License as published by the Free Software Foundation,
+ * version 2.
+ *
+ * This program is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
+ * FOR A PARTICULAR PURPOSE.  See the GNU General Public License for more
+ * details.
+ *
+ * You should have received a copy of the GNU General Public License along with
+ * this program; if not, write to the Free Software Foundation, Inc., 51
+ * Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Copyright SkySQL Ab 2013
+ */
+
+#include <unistd.h>
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <skygw_utils.h>
+#include <log_manager.h>
+
+int main(int argc, char** argv)
+{
+  int iterations = 0, i, interval = 10;
+  int block_size;
+  int succp = 0, err = 0;
+  char cwd[1024];
+  char tmp[2048];
+  char *message;
+  char** optstr;
+  long msg_index = 1;
+
+  
+  memset(cwd,0,1024);
+  if( argc <4){
+    fprintf(stderr,
+	    "Log Manager Log Order Test\n"
+	    "Writes an ascending number into the error log to determine if log writes are in order.\n"
+	    "Usage:\t	testorder <iterations> <frequency of log flushes> <size of message in bytes>\n");
+    return 1;
+  }
+  
+  block_size = atoi(argv[3]);
+  if(block_size < 1){
+    fprintf(stderr,"Message size too small, must be at least 1 byte long.");
+  }
+
+
+  if(getcwd(cwd,sizeof(cwd)) == NULL ||
+     (optstr = (char**)malloc(sizeof(char*)*4)) == NULL || 
+     (message = (char*)malloc(sizeof(char)*block_size))== NULL){
+    fprintf(stderr,"Fatal Error, exiting...");
+    return 1;
+  }
+  
+  memset(tmp,0,1024);
+
+  sprintf(tmp,"%s",cwd);
+  optstr[0] = strdup("log_manager");
+  optstr[1] = strdup("-j");
+  optstr[2] = strdup(tmp);
+  optstr[3] = NULL;
+
+  iterations = atoi(argv[1]);
+  interval = atoi(argv[2]);
+  
+  succp = skygw_logmanager_init( 3, optstr);
+  ss_dassert(succp);
+
+  skygw_log_disable(LOGFILE_TRACE);
+  skygw_log_disable(LOGFILE_MESSAGE);
+  skygw_log_disable(LOGFILE_DEBUG);
+
+  for(i = 0;i<iterations;i++){
+
+    sprintf(message,"message|%ld",msg_index++);
+    memset(message + strlen(message),' ',block_size - strlen(message));
+    memset(message + block_size - 1,'\0',1);
+    if(interval > 0 && i % interval == 0){
+      err = skygw_log_write_flush(LOGFILE_ERROR, message);
+    }else{
+      err = skygw_log_write(LOGFILE_ERROR, message);
+    }
+    if(err){
+      fprintf(stderr,"Error: log_manager returned %d",err);
+      break;
+    }
+    usleep(100);
+    //printf("%s\n",message);
+  }
+
+  skygw_log_flush(LOGFILE_ERROR);
+  skygw_logmanager_done();
+  free(message);
+  free(optstr[0]);
+  free(optstr[1]);
+  free(optstr[2]);
+  free(optstr[3]);
+  free(optstr);
+  return 0;
+}

server/modules/filter/hint/hintparser.c

@@ -261,6 +261,11 @@ HINT_MODE	mode = HM_EXECUTE;
 				hint_pop(session);
 				state = HS_INIT;
 				break;
+			case TOK_START:
+				hintname = NULL;
+				mode = HM_START;
+				state = HS_INIT;
+				break;
 			default:
 				/* Error: expected hint, name or STOP */
                                 LOGIF(LT, (skygw_log_write(
@@ -441,7 +446,7 @@ HINT_MODE	mode = HM_EXECUTE;
 		/*
 		 * We are starting either a predefined set of hints,
 		 * creating a new set of hints and starting in a single
-		 * operation or starting an annonymous block of hints.
+		 * operation or starting an anonymous block of hints.
 		 */
 		if (hintname == NULL && rval != NULL)
 		{
@@ -523,6 +528,7 @@ hint_next_token(GWBUF **buf, char **ptr)
 {
 char		word[100], *dest;
 int		inword = 0;
+ int		endtag = 0;
 char		inquote = '\0';
 int		i, found;
 HINT_TOKEN	*tok;
@@ -553,6 +559,18 @@ HINT_TOKEN	*tok;
 		else if (**ptr == '\'')
 			inquote = **ptr;
                 /** Any other character which belongs to the word, move ahead */
+
+		else if(**ptr == '/' && endtag)
+		{
+		/** Comment end tag found, rewind the pointer back and return the token */
+		  inword = 0;
+		  (*ptr)--;
+		  break;		  
+		}
+		else if(**ptr == '*' && !endtag)
+		{
+		        endtag = 1;
+		}
 		else if (inword || (isspace(**ptr) == 0))
 		{
 			*dest++ = **ptr;
@@ -574,7 +592,7 @@ HINT_TOKEN	*tok;
 	/* We now have a word in the local word, check to see if it is a
 	 * token we recognise.
 	 */
-	if (word[0] == '\0')
+	if (word[0] == '\0' || (word[0] == '*' && word[1] == '/'))
 	{
 		tok->token = TOK_EOL;
 		return tok;