From 0ef87e3cc133a9d1f4214b50152ff1a7bdbaa8f2 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Tue, 30 Sep 2014 13:25:45 +0100 Subject: [PATCH 01/22] Updates to slave catchup mode to use fake events Addition of fake EPOLLOUT event mechanism New memlog feature for debugging purposes --- server/core/CMakeLists.txt | 5 +- server/core/Makefile | 6 +- server/core/gateway.c | 4 +- server/core/memlog.c | 209 +++++++++++ server/core/poll.c | 44 +++ server/core/test/CMakeLists.txt | 3 + server/core/test/testmemlog.c | 404 +++++++++++++++++++++ server/include/memlog.h | 51 +++ server/include/spinlock.h | 2 +- server/modules/include/blr.h | 57 ++- server/modules/routing/binlog/blr.c | 123 ++++++- server/modules/routing/binlog/blr_master.c | 50 +-- server/modules/routing/binlog/blr_slave.c | 246 ++++--------- 13 files changed, 951 insertions(+), 253 deletions(-) create mode 100644 server/core/memlog.c create mode 100644 server/core/test/testmemlog.c create mode 100644 server/include/memlog.h diff --git a/server/core/CMakeLists.txt b/server/core/CMakeLists.txt index 2c7854de3..00c072b1d 100644 --- a/server/core/CMakeLists.txt +++ b/server/core/CMakeLists.txt @@ -5,7 +5,8 @@ target_link_libraries(fullcore log_manager utils pthread ${EMBEDDED_LIB} ssl aio add_executable(maxscale atomic.c buffer.c spinlock.c gateway.c gw_utils.c utils.c dcb.c load_utils.c session.c service.c server.c poll.c config.c users.c hashtable.c dbusers.c thread.c gwbitmask.c - monitor.c adminusers.c secrets.c filter.c modutil.c hint.c housekeeper.c) + monitor.c adminusers.c secrets.c filter.c modutil.c hint.c + housekeeper.c memlog.c) target_link_libraries(maxscale ${EMBEDDED_LIB} log_manager utils ssl aio pthread crypt dl crypto inih z rt m stdc++) install(TARGETS maxscale DESTINATION bin) @@ -19,4 +20,4 @@ install(TARGETS maxpasswd DESTINATION bin) if(BUILD_TESTS) add_subdirectory(test) -endif() \ No newline at end of file +endif() diff --git a/server/core/Makefile b/server/core/Makefile index 7ad4e1b01..e82204589 100644 --- a/server/core/Makefile +++ b/server/core/Makefile @@ -65,7 +65,8 @@ include ../../makefile.inc SRCS= atomic.c buffer.c spinlock.c gateway.c \ gw_utils.c utils.c dcb.c load_utils.c session.c service.c server.c \ poll.c config.c users.c hashtable.c dbusers.c thread.c gwbitmask.c \ - monitor.c adminusers.c secrets.c filter.c modutil.c hint.c housekeeper.c + monitor.c adminusers.c secrets.c filter.c modutil.c hint.c \ + housekeeper.c memlog.c HDRS= ../include/atomic.h ../include/buffer.h ../include/dcb.h \ ../include/gw.h ../modules/include/mysql_client_server_protocol.h \ @@ -73,7 +74,8 @@ HDRS= ../include/atomic.h ../include/buffer.h ../include/dcb.h \ ../include/modules.h ../include/poll.h ../include/config.h \ ../include/users.h ../include/hashtable.h ../include/gwbitmask.h \ ../include/adminusers.h ../include/version.h ../include/maxscale.h \ - ../include/filter.h ../include/modutil.h ../hint.h ../include/housekeeper.h + ../include/filter.h ../include/modutil.h ../hint.h \ + ../include/housekeeper.h ../include/memlog.h OBJ=$(SRCS:.c=.o) diff --git a/server/core/gateway.c b/server/core/gateway.c index f2c1eefb2..1d67d362f 100644 --- a/server/core/gateway.c +++ b/server/core/gateway.c @@ -53,6 +53,7 @@ #include #include #include +#include #include #include @@ -1643,10 +1644,11 @@ return_main: * Shutdown MaxScale server */ void - shutdown_server() +shutdown_server() { poll_shutdown(); hkshutdown(); + memlog_flush_all(); log_flush_shutdown(); } diff --git a/server/core/memlog.c b/server/core/memlog.c new file mode 100644 index 000000000..989950828 --- /dev/null +++ b/server/core/memlog.c @@ -0,0 +1,209 @@ +/* + * This file is distributed as part of the MariaDB MaxScale. 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 MariaDB Ab 2014 + */ + +/** + * @file memlog.c - Implementation of memory logging mechanism for debug purposes + * + * @verbatim + * Revision History + * + * Date Who Description + * 26/09/14 Mark Riddoch Initial implementation + * + * @endverbatim + */ +#include +#include + +static MEMLOG *memlogs = NULL; +static SPINLOCK *memlock = SPINLOCK_INIT; + +static void memlog_flush(MEMLOG *); + +/** + * Create a new instance of a memory logger. + * + * @param name The name of the memory log + * @param type The type of item being logged + * @param size The number of items to store in memory before flushign to disk + * + * @return MEMLOG* A memory log handle + */ +MEMLOG * +memlog_create(char *name, MEMLOGTYPE type, int size) +{ +MEMLOG *log; + + if ((log = (MEMLOG *)malloc(sizeof(MEMLOG))) == NULL) + { + return NULL; + } + + log->name = strdup(name); + spinlock_init(&log->lock); + log->type = type; + log->offset = 0; + log->size = size; + switch (type) + { + case ML_INT: + log->values = malloc(sizeof(int) * size); + break; + case ML_LONG: + log->values = malloc(sizeof(long) * size); + break; + case ML_LONGLONG: + log->values = malloc(sizeof(long long) * size); + break; + case ML_STRING: + log->values = malloc(sizeof(char *) * size); + break; + } + if (log->values == NULL) + { + free(log); + return NULL; + } + spinlock_acquire(&memlock); + log->next = memlogs; + memlogs = log; + spinlock_release(&memlock); + + return log; +} + +/** + * Destroy a memory logger any unwritten data will be flushed to disk + * + * @param log The memory log to destroy + */ +void +memlog_destroy(MEMLOG *log) +{ +MEMLOG *ptr; + + memlog_flush(log); + free(log->values); + + spinlock_acquire(&memlock); + if (memlogs == log) + memlogs = log->next; + else + { + ptr = memlogs; + while (ptr && ptr->next != log) + ptr = ptr->next; + if (ptr) + ptr->next = log->next; + } + spinlock_release(&memlock); + free(log->name); + free(log); +} + +/** + * Log a data item to the memory logger + * + * @param log The memory logger + * @param value The value to log + */ +void +memlog_log(MEMLOG *log, void *value) +{ + spinlock_acquire(&log->lock); + switch (log->type) + { + case ML_INT: + ((int *)(log->values))[log->offset] = (int)value; + break; + case ML_LONG: + ((long *)(log->values))[log->offset] = (long)value; + break; + case ML_LONGLONG: + ((long long *)(log->values))[log->offset] = (long long)value; + break; + case ML_STRING: + ((char **)(log->values))[log->offset] = (char *)value; + break; + } + log->offset++; + if (log->offset == log->size) + { + memlog_flush(log); + log->offset = 0; + } + spinlock_release(&log->lock); +} + +/** + * Flush all memlogs to disk, called during shutdown + * + */ +void +memlog_flush_all() +{ +MEMLOG *log; + + spinlock_acquire(&memlock); + log = memlogs; + while (log) + { + spinlock_acquire(&log->lock); + memlog_flush(log); + spinlock_release(&log->lock); + log = log->next; + } + spinlock_release(&memlock); +} + + +/** + * Flush a memory log to disk + * + * Assumes the the log->lock has been acquired by the caller + * + * @param log The memory log to flush + */ +static void +memlog_flush(MEMLOG *log) +{ +FILE *fp; +int i; + + if ((fp = fopen(log->name, "a")) == NULL) + return; + for (i = 0; i < log->offset; i++) + { + switch (log->type) + { + case ML_INT: + fprintf(fp, "%d\n", ((int *)(log->values))[i]); + break; + case ML_LONG: + fprintf(fp, "%ld\n", ((long *)(log->values))[i]); + break; + case ML_LONGLONG: + fprintf(fp, "%lld\n", ((long long *)(log->values))[i]); + break; + case ML_STRING: + fprintf(fp, "%s\n", ((char **)(log->values))[i]); + break; + } + } + fclose(fp); +} diff --git a/server/core/poll.c b/server/core/poll.c index 12cb1d69d..b245b79c0 100644 --- a/server/core/poll.c +++ b/server/core/poll.c @@ -1109,3 +1109,47 @@ int new_samples, new_nfds; if (next_sample >= n_avg_samples) next_sample = 0; } + +/** + * Insert a fake write completion event for a DCB into the polling + * queue. + * + * This is used to trigger transmission activity on another DCB from + * within the event processing routine of a DCB. + * + * @param dcb DCB to emulate an EPOLLOUT event for + */ +void +poll_fake_write_event(DCB *dcb) +{ +uint32_t ev = EPOLLOUT; + + spinlock_acquire(&pollqlock); + if (DCB_POLL_BUSY(dcb)) + { + dcb->evq.pending_events |= ev; + } + else + { + dcb->evq.pending_events = ev; + if (eventq) + { + dcb->evq.prev = eventq->evq.prev; + eventq->evq.prev->evq.next = dcb; + eventq->evq.prev = dcb; + dcb->evq.next = eventq; + } + else + { + eventq = dcb; + dcb->evq.prev = dcb; + dcb->evq.next = dcb; + } + pollStats.evq_length++; + if (pollStats.evq_length > pollStats.evq_max) + { + pollStats.evq_max = pollStats.evq_length; + } + } + spinlock_release(&pollqlock); +} diff --git a/server/core/test/CMakeLists.txt b/server/core/test/CMakeLists.txt index 914fe277e..a0b6002db 100644 --- a/server/core/test/CMakeLists.txt +++ b/server/core/test/CMakeLists.txt @@ -2,12 +2,15 @@ add_executable(test_hash testhash.c) add_executable(test_spinlock testspinlock.c) add_executable(test_filter testfilter.c) add_executable(test_adminusers testadminusers.c) +add_executable(testmemlog testmemlog.c) target_link_libraries(test_hash fullcore) target_link_libraries(test_spinlock fullcore) target_link_libraries(test_filter fullcore) target_link_libraries(test_adminusers fullcore) +target_link_libraries(testmemlog fullcore) add_test(TestHash test_hash) add_test(TestSpinlock test_spinlock) add_test(TestFilter test_filter) add_test(TestAdminUsers test_adminusers) +add_test(TestMemlog testmemlog) diff --git a/server/core/test/testmemlog.c b/server/core/test/testmemlog.c new file mode 100644 index 000000000..1523ec8ec --- /dev/null +++ b/server/core/test/testmemlog.c @@ -0,0 +1,404 @@ +/* + * This file is distributed as part of MaxScale from MariaDB. 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 MariaDB Corporation 2014 + */ + +/** + * + * @verbatim + * Revision History + * + * Date Who Description + * 30/09/2014 Mark Riddoch Initial implementation + * + * @endverbatim + */ + +#include +#include +#include +#include +#include + +/** + * Count the number of lines in a file + * + * @param file The name of the file + * @return -1 if the file could not be opened or the numebr of lines + */ +int +linecount(char *file) +{ +FILE *fp; +int i = 0; +char buffer[180]; + + if ((fp = fopen(file, "r")) == NULL) + return -1; + while (fgets(buffer, 180, fp) != NULL) + i++; + fclose(fp); + return i; +} + +/* Some strings to log */ +char *strings[] = { + "First log entry", + "Second entry", + "Third", + "The fourth thing to log", + "Add a final 5th item" +}; + +int +main() +{ +MEMLOG *log, *log2; +int i; +long j; +long long k; +int failures = 0; + + unlink("memlog1"); + if ((log = memlog_create("memlog1", ML_INT, 100)) == NULL) + { + printf("Memlog Creation: Failed\n"); + failures++; + } + else + { + printf("Memlog Creation: Passed\n"); + if (access("memlog1",R_OK) == 0) + { + printf("File existance 1: Failed\n"); + failures++; + } + else + printf("File existance 1: Passed\n"); + for (i = 0; i < 50; i++) + memlog_log(log, (void *)i); + if (access("memlog1",R_OK) == 0) + { + printf("File existance 2: Failed\n"); + failures++; + } + else + printf("File existance 2: Passed\n"); + for (i = 0; i < 50; i++) + memlog_log(log, (void *)i); + if (access("memlog1",R_OK) != 0) + { + printf("File existance 3: Failed\n"); + failures++; + } + else + printf("File existance 3: Passed\n"); + if (linecount("memlog1") != 100) + { + printf("Incorrect entry count: Failed\n"); + failures++; + } + else + printf("Incorrect entry count: Passed\n"); + for (i = 0; i < 50; i++) + memlog_log(log, (void *)i); + if (linecount("memlog1") != 100) + { + printf("Premature Flushing: Failed\n"); + failures++; + } + else + printf("Premature Flushing: Passed\n"); + memlog_destroy(log); + if (linecount("memlog1") != 150) + { + printf("Flush on destroy: Failed\n"); + failures++; + } + else + printf("Flush on destroy: Passed\n"); + } + + unlink("memlog2"); + if ((log = memlog_create("memlog2", ML_LONG, 100)) == NULL) + { + printf("Memlog Creation: Failed\n"); + failures++; + } + else + { + printf("Memlog Creation: Passed\n"); + if (access("memlog2",R_OK) == 0) + { + printf("File existance 1: Failed\n"); + failures++; + } + else + printf("File existance 1: Passed\n"); + for (j = 0; j < 50; j++) + memlog_log(log, (void *)j); + if (access("memlog2",R_OK) == 0) + { + printf("File existance 2: Failed\n"); + failures++; + } + else + printf("File existance 2: Passed\n"); + for (j = 0; j < 50; j++) + memlog_log(log, (void *)j); + if (access("memlog2",R_OK) != 0) + { + printf("File existance 3: Failed\n"); + failures++; + } + else + printf("File existance 3: Passed\n"); + if (linecount("memlog2") != 100) + { + printf("Incorrect entry count: Failed\n"); + failures++; + } + else + printf("Incorrect entry count: Passed\n"); + for (j = 0; j < 50; j++) + memlog_log(log, (void *)j); + if (linecount("memlog2") != 100) + { + printf("Premature Flushing: Failed\n"); + failures++; + } + else + printf("Premature Flushing: Passed\n"); + memlog_destroy(log); + if (linecount("memlog2") != 150) + { + printf("Flush on destroy: Failed\n"); + failures++; + } + else + printf("Flush on destroy: Passed\n"); + } + + unlink("memlog3"); + if ((log = memlog_create("memlog3", ML_LONGLONG, 100)) == NULL) + { + printf("Memlog Creation: Failed\n"); + failures++; + } + else + { + printf("Memlog Creation: Passed\n"); + if (access("memlog3",R_OK) == 0) + { + printf("File existance 1: Failed\n"); + failures++; + } + else + printf("File existance 1: Passed\n"); + for (k = 0; k < 50; k++) + memlog_log(log, (void *)k); + if (access("memlog3",R_OK) == 0) + { + printf("File existance 2: Failed\n"); + failures++; + } + else + printf("File existance 2: Passed\n"); + for (k = 0; k < 50; k++) + memlog_log(log, (void *)k); + if (access("memlog3",R_OK) != 0) + { + printf("File existance 3: Failed\n"); + failures++; + } + else + printf("File existance 3: Passed\n"); + if (linecount("memlog3") != 100) + { + printf("Incorrect entry count: Failed\n"); + failures++; + } + else + printf("Incorrect entry count: Passed\n"); + for (k = 0; k < 50; k++) + memlog_log(log, (void *)k); + if (linecount("memlog3") != 100) + { + printf("Premature Flushing: Failed\n"); + failures++; + } + else + printf("Premature Flushing: Passed\n"); + memlog_destroy(log); + if (linecount("memlog3") != 150) + { + printf("Flush on destroy: Failed\n"); + failures++; + } + else + printf("Flush on destroy: Passed\n"); + } + + unlink("memlog4"); + if ((log = memlog_create("memlog4", ML_STRING, 100)) == NULL) + { + printf("Memlog Creation: Failed\n"); + failures++; + } + else + { + printf("Memlog Creation: Passed\n"); + if (access("memlog4",R_OK) == 0) + { + printf("File existance 1: Failed\n"); + failures++; + } + else + printf("File existance 1: Passed\n"); + for (i = 0; i < 50; i++) + memlog_log(log, strings[i%5]); + if (access("memlog4",R_OK) == 0) + { + printf("File existance 2: Failed\n"); + failures++; + } + else + printf("File existance 2: Passed\n"); + for (i = 0; i < 50; i++) + memlog_log(log, strings[i%5]); + if (access("memlog4",R_OK) != 0) + { + printf("File existance 3: Failed\n"); + failures++; + } + else + printf("File existance 3: Passed\n"); + if (linecount("memlog4") != 100) + { + printf("Incorrect entry count: Failed\n"); + failures++; + } + else + printf("Incorrect entry count: Passed\n"); + for (i = 0; i < 50; i++) + memlog_log(log, strings[i%5]); + if (linecount("memlog4") != 100) + { + printf("Premature Flushing: Failed\n"); + failures++; + } + else + printf("Premature Flushing: Passed\n"); + memlog_destroy(log); + if (linecount("memlog4") != 150) + { + printf("Flush on destroy: Failed\n"); + failures++; + } + else + printf("Flush on destroy: Passed\n"); + } + + unlink("memlog5"); + unlink("memlog6"); + if ((log = memlog_create("memlog5", ML_INT, 100)) == NULL) + { + printf("Memlog Creation: Failed\n"); + failures++; + } + else + { + printf("Memlog Creation: Passed\n"); + if ((log2 = memlog_create("memlog6", ML_INT, 100)) == NULL) + { + printf("Memlog Creation: Failed\n"); + failures++; + } + else + { + printf("Memlog Creation: Passed\n"); + for (i = 0; i < 40; i++) + memlog_log(log, (void *)i); + for (i = 0; i < 30; i++) + memlog_log(log2, (void *)i); + memlog_flush_all(); + if (linecount("memlog5") != 40 || + linecount("memlog6") != 30) + { + printf( + "Memlog flush all: Failed\n"); + failures++; + } + else + printf( + "Memlog flush all: Passed\n"); + } + } + + unlink("memlog7"); + if ((log = memlog_create("memlog7", ML_INT, 100)) == NULL) + { + printf("Memlog Creation: Failed\n"); + failures++; + } + else + { + printf("Memlog Creation: Passed\n"); + if (access("memlog7",R_OK) == 0) + { + printf("File existance 1: Failed\n"); + failures++; + } + else + printf("File existance 1: Passed\n"); + for (i = 0; i < 5050; i++) + memlog_log(log, (void *)i); + if (access("memlog7",R_OK) != 0) + { + printf("File existance 3: Failed\n"); + failures++; + } + else + printf("File existance 3: Passed\n"); + if (linecount("memlog7") != 5000) + { + printf("Incorrect entry count: Failed\n"); + failures++; + } + else + printf("Incorrect entry count: Passed\n"); + for (i = 0; i < 50; i++) + memlog_log(log, (void *)i); + if (linecount("memlog7") != 5100) + { + printf("Residual flushing: Failed\n"); + failures++; + } + else + printf("Premature Flushing: Passed\n"); + for (i = 0; i < 10120; i++) + memlog_log(log, (void *)i); + memlog_destroy(log); + if (linecount("memlog7") != 15220) + { + printf("Flush on destroy: Failed\n"); + failures++; + } + else + printf("Flush on destroy: Passed\n"); + } + exit(failures); +} diff --git a/server/include/memlog.h b/server/include/memlog.h new file mode 100644 index 000000000..032348e38 --- /dev/null +++ b/server/include/memlog.h @@ -0,0 +1,51 @@ +#ifndef _MEMLOG_H +#define _MEMLOG_H +/* + * This file is distributed as part of MariaDB MaxScale. 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 MariaDB Ab 2014 + */ + +/** + * @file memlog.h The memory logging mechanism + * + * @verbatim + * Revision History + * + * Date Who Description + * 26/09/14 Mark Riddoch Initial implementation + * + * @endverbatim + */ +#include + +typedef enum { ML_INT, ML_LONG, ML_LONGLONG, ML_STRING } MEMLOGTYPE; + +typedef struct memlog { + char *name; + SPINLOCK lock; + void *values; + int offset; + int size; + MEMLOGTYPE type; + struct memlog *next; +} MEMLOG; + + +extern MEMLOG *memlog_create(char *, MEMLOGTYPE, int); +extern void memlog_destroy(MEMLOG *); +extern void memlog_log(MEMLOG *, void *); +extern void memlog_flush_all(); +#endif diff --git a/server/include/spinlock.h b/server/include/spinlock.h index 43192da3f..e5f938815 100644 --- a/server/include/spinlock.h +++ b/server/include/spinlock.h @@ -31,7 +31,7 @@ #include #include -#define SPINLOCK_PROFILE 1 +#define SPINLOCK_PROFILE 0 /** * The spinlock structure. diff --git a/server/modules/include/blr.h b/server/modules/include/blr.h index 6e151d923..1ba575d49 100644 --- a/server/modules/include/blr.h +++ b/server/modules/include/blr.h @@ -39,12 +39,22 @@ #define BINLOG_NAMEFMT "%s.%06d" #define BINLOG_NAME_ROOT "mysql-bin" +/* How often to call the binlog status function (seconds) */ +#define BLR_STATS_FREQ 60 +#define BLR_NSTATS_MINUTES 30 + /** * High and Low water marks for the slave dcb. These values can be overriden * by the router options highwater and lowwater. */ -#define DEF_LOW_WATER 2000 -#define DEF_HIGH_WATER 30000 +#define DEF_LOW_WATER 1000 +#define DEF_HIGH_WATER 10000 + +/** + * Default burst sizes for slave catchup + */ +#define DEF_SHORT_BURST 15 +#define DEF_LONG_BURST 2000 /** * Some useful macros for examining the MySQL Response packets @@ -60,20 +70,23 @@ * Slave statistics */ typedef struct { - int n_events; /*< Number of events sent */ - int n_bursts; /*< Number of bursts sent */ - int n_requests; /*< Number of requests received */ - int n_flows; /*< Number of flow control restarts */ - int n_catchupnr; /*< No. of times catchup resulted in not entering loop */ - int n_alreadyupd; - int n_upd; - int n_cb; - int n_cbna; - int n_dcb; - int n_above; - int n_failed_read; - int n_overrun; - int n_actions[3]; + int n_events; /*< Number of events sent */ + int n_bursts; /*< Number of bursts sent */ + int n_requests; /*< Number of requests received */ + int n_flows; /*< Number of flow control restarts */ + int n_catchupnr; /*< No. of times catchup resulted in not entering loop */ + int n_alreadyupd; + int n_upd; + int n_cb; + int n_cbna; + int n_dcb; + int n_above; + int n_failed_read; + int n_overrun; + int n_actions[3]; + uint64_t lastsample; + int minno; + int minavgs[BLR_NSTATS_MINUTES]; } SLAVE_STATS; /** @@ -132,6 +145,9 @@ typedef struct { uint64_t n_fakeevents; /*< Fake events not written to disk */ uint64_t n_artificial; /*< Artificial events not written to disk */ uint64_t events[0x24]; /*< Per event counters */ + uint64_t lastsample; + int minno; + int minavgs[BLR_NSTATS_MINUTES]; } ROUTER_STATS; /** @@ -214,6 +230,8 @@ typedef struct router_instance { */ unsigned int low_water; /*< Low water mark for client DCB */ unsigned int high_water; /*< High water mark for client DCB */ + unsigned int short_burst; /*< Short burst for slave catchup */ + unsigned int long_burst; /*< Long burst for slave catchup */ BLCACHE *cache[2]; ROUTER_STATS stats; /*< Statistics for this router */ int active_logs; @@ -279,12 +297,13 @@ static char *blrs_states[] = { "Created", "Unregistered", "Registered", /** * Slave catch-up status */ -#define CS_READING 0x0001 -#define CS_INNERLOOP 0x0002 #define CS_UPTODATE 0x0004 #define CS_EXPECTCB 0x0008 #define CS_DIST 0x0010 #define CS_DISTLATCH 0x0020 +#define CS_THRDWAIT 0x0040 +#define CS_BUSY 0x0100 +#define CS_HOLD 0x0200 /** * MySQL protocol OpCodes needed for replication @@ -356,7 +375,7 @@ extern void blr_master_reconnect(ROUTER_INSTANCE *); extern int blr_slave_request(ROUTER_INSTANCE *, ROUTER_SLAVE *, GWBUF *); extern void blr_slave_rotate(ROUTER_SLAVE *slave, uint8_t *ptr); -extern int blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave); +extern int blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, bool large); extern void blr_init_cache(ROUTER_INSTANCE *); extern void blr_file_init(ROUTER_INSTANCE *); diff --git a/server/modules/routing/binlog/blr.c b/server/modules/routing/binlog/blr.c index d92f03c10..1d4a9d8ff 100644 --- a/server/modules/routing/binlog/blr.c +++ b/server/modules/routing/binlog/blr.c @@ -48,6 +48,7 @@ #include #include #include +#include #include #include @@ -95,6 +96,8 @@ static ROUTER_OBJECT MyObject = { getCapabilities }; +static void stats_func(void *); + static bool rses_begin_locked_router_action(ROUTER_SLAVE *); static void rses_end_locked_router_action(ROUTER_SLAVE *); @@ -173,6 +176,8 @@ int i; inst->low_water = DEF_LOW_WATER; inst->high_water = DEF_HIGH_WATER; inst->initbinlog = 0; + inst->short_burst = DEF_SHORT_BURST; + inst->long_burst = DEF_LONG_BURST; /* * We only support one server behind this router, since the server is @@ -249,6 +254,10 @@ int i; { inst->initbinlog = atoi(value); } + else if (strcmp(options[i], "file") == 0) + { + inst->initbinlog = atoi(value); + } else if (strcmp(options[i], "lowwater") == 0) { inst->low_water = atoi(value); @@ -257,6 +266,14 @@ int i; { inst->high_water = atoi(value); } + else if (strcmp(options[i], "shortburst") == 0) + { + inst->short_burst = atoi(value); + } + else if (strcmp(options[i], "longburst") == 0) + { + inst->long_burst = atoi(value); + } else { LOGIF(LE, (skygw_log_write( @@ -302,6 +319,8 @@ int i; */ blr_init_cache(inst); + hktask_add("Binlog Router", stats_func, inst, BLR_STATS_FREQ); + /* * Now start the replication from the master to MaxScale */ @@ -541,7 +560,9 @@ diagnostics(ROUTER *router, DCB *dcb) { ROUTER_INSTANCE *router_inst = (ROUTER_INSTANCE *)router; ROUTER_SLAVE *session; -int i = 0; +int i = 0, j; +int minno = 0; +double min5, min10, min15, min30; char buf[40]; struct tm tm; @@ -554,6 +575,30 @@ struct tm tm; } spinlock_release(&router_inst->lock); + minno = router_inst->stats.minno; + min30 = 0.0; + min15 = 0.0; + min10 = 0.0; + min5 = 0.0; + for (j = 0; j < 30; j++) + { + minno--; + if (minno < 0) + minno += 30; + min30 += router_inst->stats.minavgs[minno]; + if (j < 15) + min15 += router_inst->stats.minavgs[minno]; + if (j < 10) + min10 += router_inst->stats.minavgs[minno]; + if (j < 5) + min5 += router_inst->stats.minavgs[minno]; + } + min30 /= 30.0; + min15 /= 15.0; + min10 /= 10.0; + min5 /= 5.0; + + dcb_printf(dcb, "\tMaster connection DCB: %p\n", router_inst->master); dcb_printf(dcb, "\tMaster connection state: %s\n", @@ -574,6 +619,13 @@ struct tm tm; router_inst->stats.n_slaves); dcb_printf(dcb, "\tNumber of binlog events received: %u\n", router_inst->stats.n_binlogs); + minno = router_inst->stats.minno - 1; + if (minno == -1) + minno = 30; + dcb_printf(dcb, "\tNumber of binlog events per minute\n"); + dcb_printf(dcb, "\tCurrent 5 10 15 30 Min Avg\n"); + dcb_printf(dcb, "\t %6d %8.1f %8.1f %8.1f %8.1f\n", + router_inst->stats.minavgs[minno], min5, min10, min15, min30); dcb_printf(dcb, "\tNumber of fake binlog events: %u\n", router_inst->stats.n_fakeevents); dcb_printf(dcb, "\tNumber of artificial binlog events: %u\n", @@ -582,10 +634,6 @@ struct tm tm; router_inst->stats.n_binlog_errors); dcb_printf(dcb, "\tNumber of binlog rotate events: %u\n", router_inst->stats.n_rotates); - dcb_printf(dcb, "\tNumber of binlog cache hits: %u\n", - router_inst->stats.n_cachehits); - dcb_printf(dcb, "\tNumber of binlog cache misses: %u\n", - router_inst->stats.n_cachemisses); dcb_printf(dcb, "\tNumber of heartbeat events: %u\n", router_inst->stats.n_heartbeats); dcb_printf(dcb, "\tNumber of packets received: %u\n", @@ -624,6 +672,29 @@ struct tm tm; session = router_inst->slaves; while (session) { + + minno = session->stats.minno; + min30 = 0.0; + min15 = 0.0; + min10 = 0.0; + min5 = 0.0; + for (j = 0; j < 30; j++) + { + minno--; + if (minno < 0) + minno += 30; + min30 += session->stats.minavgs[minno]; + if (j < 15) + min15 += session->stats.minavgs[minno]; + if (j < 10) + min10 += session->stats.minavgs[minno]; + if (j < 5) + min5 += session->stats.minavgs[minno]; + } + min30 /= 30.0; + min15 /= 15.0; + min10 /= 10.0; + min5 /= 5.0; dcb_printf(dcb, "\t\tServer-id: %d\n", session->serverid); if (session->hostname) dcb_printf(dcb, "\t\tHostname: %s\n", session->hostname); @@ -637,14 +708,20 @@ struct tm tm; dcb_printf(dcb, "\t\tNo. requests: %u\n", session->stats.n_requests); dcb_printf(dcb, "\t\tNo. events sent: %u\n", session->stats.n_events); dcb_printf(dcb, "\t\tNo. bursts sent: %u\n", session->stats.n_bursts); + minno = session->stats.minno - 1; + if (minno == -1) + minno = 30; + dcb_printf(dcb, "\t\tNumber of binlog events per minute\n"); + dcb_printf(dcb, "\t\tCurrent 5 10 15 30 Min Avg\n"); + dcb_printf(dcb, "\t\t %6d %8.1f %8.1f %8.1f %8.1f\n", + session->stats.minavgs[minno], min5, min10, + min15, min30); dcb_printf(dcb, "\t\tNo. flow control: %u\n", session->stats.n_flows); dcb_printf(dcb, "\t\tNo. catchup NRs: %u\n", session->stats.n_catchupnr); dcb_printf(dcb, "\t\tNo. already up to date: %u\n", session->stats.n_alreadyupd); dcb_printf(dcb, "\t\tNo. up to date: %u\n", session->stats.n_upd); - dcb_printf(dcb, "\t\tNo. of low water cbs %u\n", session->stats.n_cb); dcb_printf(dcb, "\t\tNo. of drained cbs %u\n", session->stats.n_dcb); dcb_printf(dcb, "\t\tNo. of low water cbs N/A %u\n", session->stats.n_cbna); - dcb_printf(dcb, "\t\tNo. of events > high water %u\n", session->stats.n_above); dcb_printf(dcb, "\t\tNo. of failed reads %u\n", session->stats.n_failed_read); dcb_printf(dcb, "\t\tNo. of nested distribute events %u\n", session->stats.n_overrun); dcb_printf(dcb, "\t\tNo. of distribute action 1 %u\n", session->stats.n_actions[0]); @@ -776,3 +853,35 @@ static uint8_t getCapabilities(ROUTER *inst, void *router_session) { return 0; } + +/** + * The stats gathering function called from the housekeeper so that we + * can get timed averages of binlog records shippped + * + * @param inst The router instance + */ +static void +stats_func(void *inst) +{ +ROUTER_INSTANCE *router = (ROUTER_INSTANCE *)inst; +ROUTER_SLAVE *slave; + + router->stats.minavgs[router->stats.minno++] + = router->stats.n_binlogs - router->stats.lastsample; + router->stats.lastsample = router->stats.n_binlogs; + if (router->stats.minno == BLR_NSTATS_MINUTES) + router->stats.minno = 0; + + spinlock_acquire(&router->lock); + slave = router->slaves; + while (slave) + { + slave->stats.minavgs[slave->stats.minno++] + = slave->stats.n_events - slave->stats.lastsample; + slave->stats.lastsample = slave->stats.n_events; + if (slave->stats.minno == BLR_NSTATS_MINUTES) + slave->stats.minno = 0; + slave = slave->next; + } + spinlock_release(&router->lock); +} diff --git a/server/modules/routing/binlog/blr_master.c b/server/modules/routing/binlog/blr_master.c index ee14cec4c..6f92d193d 100644 --- a/server/modules/routing/binlog/blr_master.c +++ b/server/modules/routing/binlog/blr_master.c @@ -60,39 +60,6 @@ /* Temporary requirement for auth data */ #include -#define SAMPLE_COUNT 10000 -CYCLES samples[10][SAMPLE_COUNT]; -int sample_index[10] = { 0, 0, 0 }; - -#define LOGD_SLAVE_CATCHUP1 0 -#define LOGD_SLAVE_CATCHUP2 1 -#define LOGD_DISTRIBUTE 2 -#define LOGD_FILE_FLUSH 3 - -SPINLOCK logspin = SPINLOCK_INIT; - -void -log_duration(int sample, CYCLES duration) -{ -char fname[100]; -int i; -FILE *fp; - - spinlock_acquire(&logspin); - samples[sample][sample_index[sample]++] = duration; - if (sample_index[sample] == SAMPLE_COUNT) - { - sprintf(fname, "binlog_profile.%d", sample); - if ((fp = fopen(fname, "a")) != NULL) - { - for (i = 0; i < SAMPLE_COUNT; i++) - fprintf(fp, "%ld\n", samples[sample][i]); - fclose(fp); - } - sample_index[sample] = 0; - } - spinlock_release(&logspin); -} extern int lm_enabled_logfiles_bitmask; @@ -802,9 +769,7 @@ static REP_HEADER phdr; { ss_dassert(pkt_length == 0); } -{ CYCLES start = rdtsc(); blr_file_flush(router); -log_duration(LOGD_FILE_FLUSH, rdtsc() - start); } } /** @@ -929,9 +894,7 @@ GWBUF *pkt; uint8_t *buf; ROUTER_SLAVE *slave; int action; -CYCLES entry; - entry = rdtsc(); spinlock_acquire(&router->lock); slave = router->slaves; while (slave) @@ -985,16 +948,12 @@ CYCLES entry; spinlock_acquire(&slave->catch_lock); if (slave->overrun) { -CYCLES cycle_start, cycles; slave->stats.n_overrun++; slave->overrun = 0; spinlock_release(&router->lock); slave->cstate &= ~(CS_UPTODATE|CS_DIST); spinlock_release(&slave->catch_lock); -cycle_start = rdtsc(); - blr_slave_catchup(router, slave); -cycles = rdtsc() - cycle_start; -log_duration(LOGD_SLAVE_CATCHUP2, cycles); + blr_slave_catchup(router, slave, false); spinlock_acquire(&router->lock); slave = router->slaves; if (slave) @@ -1027,7 +986,6 @@ log_duration(LOGD_SLAVE_CATCHUP2, cycles); */ if (slave->cstate & CS_UPTODATE) { -CYCLES cycle_start, cycles; spinlock_release(&router->lock); LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, "Force slave %d into catchup mode %s@%d\n", @@ -1036,10 +994,7 @@ CYCLES cycle_start, cycles; spinlock_acquire(&slave->catch_lock); slave->cstate &= ~(CS_UPTODATE|CS_DIST); spinlock_release(&slave->catch_lock); -cycle_start = rdtsc(); - blr_slave_catchup(router, slave); -cycles = rdtsc() - cycle_start; -log_duration(LOGD_SLAVE_CATCHUP1, cycles); + blr_slave_catchup(router, slave, false); spinlock_acquire(&router->lock); slave = router->slaves; if (slave) @@ -1053,7 +1008,6 @@ log_duration(LOGD_SLAVE_CATCHUP1, cycles); slave = slave->next; } spinlock_release(&router->lock); - log_duration(LOGD_DISTRIBUTE, rdtsc() - entry); } static void diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index 5d7a16475..0ed3618c9 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -52,7 +52,6 @@ #include #include - static uint32_t extract_field(uint8_t *src, int bits); static void encode_value(unsigned char *data, unsigned int value, int len); static int blr_slave_query(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue); @@ -61,7 +60,7 @@ static void blr_slave_send_error(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, c static int blr_slave_send_timestamp(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave); static int blr_slave_register(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue); static int blr_slave_binlog_dump(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue); -int blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave); +int blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, bool large); static uint8_t *blr_build_header(GWBUF *pkt, REP_HEADER *hdr); static int blr_slave_callback(DCB *dcb, DCB_REASON reason, void *data); @@ -567,7 +566,7 @@ uint32_t chksum; slave->dcb->low_water = router->low_water; slave->dcb->high_water = router->high_water; - dcb_add_callback(slave->dcb, DCB_REASON_LOW_WATER, blr_slave_callback, slave); +// dcb_add_callback(slave->dcb, DCB_REASON_LOW_WATER, blr_slave_callback, slave); dcb_add_callback(slave->dcb, DCB_REASON_DRAINED, blr_slave_callback, slave); if (slave->binlog_pos != router->binlog_position || @@ -576,7 +575,7 @@ uint32_t chksum; spinlock_acquire(&slave->catch_lock); slave->cstate &= ~CS_UPTODATE; spinlock_release(&slave->catch_lock); - rval = blr_slave_catchup(router, slave); + rval = blr_slave_catchup(router, slave, true); } return rval; @@ -660,187 +659,107 @@ uint8_t *ptr; * We have a registered slave that is behind the current leading edge of the * binlog. We must replay the log entries to bring this node up to speed. * - * There may be a large numebr of records to send to the slave, the process + * There may be a large number of records to send to the slave, the process * is triggered by the slave COM_BINLOG_DUMP message and all the events must * be sent without receiving any new event. This measn there is no trigger into * MaxScale other than this initial message. However, if we simply send all the - * events we end up with an extremely long write queue on the DCB and risk running - * the server out of resources. + * events we end up with an extremely long write queue on the DCB and risk + * running the server out of resources. * - * To resolve this the concept of high and low water marks within the DCB has been - * added, with the ability for the DCB code to call user defined callbacks when the - * write queue is completely drained, when it crosses above the high water mark and - * when it crosses below the low water mark. - * - * The blr_slave_catchup routine will send binlog events to the slave until the high - * water mark is reached, at which point it will return. Later, when a low water mark - * callback is generated by the code that drains the DCB of data the blr_slave_catchup - * routine will again be called to write more events. The process is repeated until - * the slave has caught up with the master. + * The slave catchup routine will send a burst of replication events per single + * call. The paramter "long" control the number of events in the burst. The + * short burst is intended to be used when the master receive an event and + * needs to put the slave into catchup mode. This prevents the slave taking + * too much tiem away from the thread that is processing the master events. * - * Note: an additional check that the DCB is still above the low water mark is done - * prior to the return from this function to allow for any delays due to the call to - * the close system call, since this may cause thread rescheduling. + * At the end ofthe burst a fake EPOLLOUT event is added to the poll event + * queue. This ensures that the slave callback for processing DCB write drain + * will be called and future catchup requests will be handle on another thread. * * @param router The binlog router * @param slave The slave that is behind + * @param large Send a long or short burst of events * @return The number of bytes written */ int -blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave) +blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, bool large) { GWBUF *head, *record; REP_HEADER hdr; -int written, fd, rval = 1, burst = 0; +int written, fd, rval = 1, burst; uint8_t *ptr; struct timespec req; - + if (large) + burst = router->long_burst; + else + burst = router->short_burst; spinlock_acquire(&slave->catch_lock); - slave->cstate &= ~CS_EXPECTCB; - spinlock_release(&slave->catch_lock); -doitagain: - /* - * We have a slightly complex syncronisation mechansim here, - * we need to make sure that we do not have multiple threads - * running the catchup loop, but we need to be very careful - * that we do not loose a call that is coming via a callback - * call as this will stall the binlog catchup process. - * - * We don't want to simply use a traditional mutex here for - * the loop, since this would block a MaxScale thread for - * an unacceptable length of time. - * - * We have two status bits, the CS_READING that says we are - * in the outer loop and the CS_INNERLOOP, to say we are in - * the inner loop. - * - * If just CS_READING is set the other thread may be about to - * enter the inner loop or may be about to exit the function - * completely. Therefore we have to wait to see if CS_READING - * is cleared or CS_INNERLOOP is set. - * - * If CS_READING gets cleared then this thread should proceed - * into the loop. - * - * If CS_INNERLOOP get's set then this thread does not need to - * proceed. - * - * If CS_READING is not set then this thread simply enters the - * loop. - */ - req.tv_sec = 0; - req.tv_nsec = 1000; - spinlock_acquire(&slave->catch_lock); - if (slave->cstate & CS_UPTODATE) + while ((slave->cstate & (CS_HOLD|CS_BUSY)) == (CS_HOLD|CS_BUSY)) { - LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, - "blr_slave_catchup called with up to date slave %d at " - "%s@%d. Reading position %s@%d\n", - slave->serverid, slave->binlogfile, - slave->binlog_pos, router->binlog_name, - router->binlog_position))); - slave->stats.n_alreadyupd++; - spinlock_release(&slave->catch_lock); - return 1; - } - while (slave->cstate & CS_READING) - { - // Wait until we know what the other thread is doing - while ((slave->cstate & (CS_READING|CS_INNERLOOP)) == CS_READING) - { - spinlock_release(&slave->catch_lock); - nanosleep(&req, NULL); - spinlock_acquire(&slave->catch_lock); - } - // Other thread is in the innerloop - if ((slave->cstate & (CS_READING|CS_INNERLOOP)) == (CS_READING|CS_INNERLOOP)) - { - spinlock_release(&slave->catch_lock); - LOGIF(LM, (skygw_log_write( - LOGFILE_MESSAGE, - "blr_slave_catchup thread returning due to " - "lock being held by another thread. %s@%d\n", - slave->binlogfile, - slave->binlog_pos))); - slave->stats.n_catchupnr++; - return 1; // We cheat here and return 1 because otherwise - // an error would be sent and we do not want that - } - - /* Release the lock for a short time to allow the other - * thread to exit the outer reading loop. - */ spinlock_release(&slave->catch_lock); + req.tv_sec = 0; + req.tv_nsec = 100; nanosleep(&req, NULL); spinlock_acquire(&slave->catch_lock); } - if (slave->pthread) - LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, "Multiple threads sending to same thread.\n"))); - slave->pthread = pthread_self(); - slave->cstate |= CS_READING; + slave->cstate |= (CS_HOLD|CS_BUSY); spinlock_release(&slave->catch_lock); - if (DCB_ABOVE_HIGH_WATER(slave->dcb)) - LOGIF(LT, (skygw_log_write(LOGFILE_TRACE, "blr_slave_catchup above high water on entry.\n"))); - - do { - if ((fd = blr_open_binlog(router, slave->binlogfile)) == -1) + if ((fd = blr_open_binlog(router, slave->binlogfile)) == -1) + { + LOGIF(LE, (skygw_log_write( + LOGFILE_ERROR, + "blr_slave_catchup failed to open binlog file %s\n", + slave->binlogfile))); + return 0; + } + slave->stats.n_bursts++; + while (burst-- && + (record = blr_read_binlog(fd, slave->binlog_pos, &hdr)) != NULL) + { + spinlock_acquire(&slave->catch_lock); + slave->cstate &= ~CS_HOLD; + spinlock_release(&slave->catch_lock); + head = gwbuf_alloc(5); + ptr = GWBUF_DATA(head); + encode_value(ptr, hdr.event_size + 1, 24); + ptr += 3; + *ptr++ = slave->seqno++; + *ptr++ = 0; // OK + head = gwbuf_append(head, record); + if (hdr.event_type == ROTATE_EVENT) { - spinlock_acquire(&slave->catch_lock); - slave->cstate &= ~CS_READING; - spinlock_release(&slave->catch_lock); - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "blr_slave_catchup failed to open binlog file %s\n", + close(fd); + blr_slave_rotate(slave, GWBUF_DATA(record)); + if ((fd = blr_open_binlog(router, slave->binlogfile)) == -1) + { + LOGIF(LE, (skygw_log_write( + LOGFILE_ERROR, + "blr_slave_catchup failed to open binlog file %s\n", slave->binlogfile))); - return 0; + break; + } } - slave->stats.n_bursts++; spinlock_acquire(&slave->catch_lock); - slave->cstate |= CS_INNERLOOP; + slave->cstate |= CS_HOLD; spinlock_release(&slave->catch_lock); - while ((!DCB_ABOVE_HIGH_WATER(slave->dcb)) && - (record = blr_read_binlog(fd, slave->binlog_pos, &hdr)) != NULL) + written = slave->dcb->func.write(slave->dcb, head); + if (written && hdr.event_type != ROTATE_EVENT) { -if (hdr.event_size > DEF_HIGH_WATER) slave->stats.n_above++; - head = gwbuf_alloc(5); - ptr = GWBUF_DATA(head); - encode_value(ptr, hdr.event_size + 1, 24); - ptr += 3; - *ptr++ = slave->seqno++; - *ptr++ = 0; // OK - head = gwbuf_append(head, record); - if (hdr.event_type == ROTATE_EVENT) - { - close(fd); - blr_slave_rotate(slave, GWBUF_DATA(record)); - if ((fd = blr_open_binlog(router, slave->binlogfile)) == -1) - { - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "blr_slave_catchup failed to open binlog file %s\n", - slave->binlogfile))); - break; - } - } - written = slave->dcb->func.write(slave->dcb, head); - if (written && hdr.event_type != ROTATE_EVENT) - { - slave->binlog_pos = hdr.next_pos; - } - rval = written; - slave->stats.n_events++; - burst++; + slave->binlog_pos = hdr.next_pos; } - if (record == NULL) - slave->stats.n_failed_read++; - spinlock_acquire(&slave->catch_lock); - slave->cstate &= ~CS_INNERLOOP; - spinlock_release(&slave->catch_lock); + rval = written; + slave->stats.n_events++; + } + if (record == NULL) + slave->stats.n_failed_read++; + spinlock_acquire(&slave->catch_lock); + slave->cstate &= ~CS_BUSY; + spinlock_release(&slave->catch_lock); - close(fd); - } while (record && DCB_BELOW_LOW_WATER(slave->dcb)); + close(fd); + poll_fake_write_event(slave->dcb); if (record) { slave->stats.n_flows++; @@ -864,25 +783,6 @@ if (hdr.event_size > DEF_HIGH_WATER) slave->stats.n_above++; "blr_slave_catchup slave is up to date %s, %u\n", slave->binlogfile, slave->binlog_pos))); } - spinlock_acquire(&slave->catch_lock); -#if 0 -if (slave->pthread != pthread_self()) -{ - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Multple threads in catchup for same slave: %x and %x\n", slave->pthread, pthread_self()))); -abort(); -} -#endif - slave->pthread = 0; -#if 0 -if (DCB_BELOW_LOW_WATER(slave->dcb) && slave->binlog_pos != router->binlog_position) abort(); -#endif - slave->cstate &= ~CS_READING; - spinlock_release(&slave->catch_lock); -if (DCB_BELOW_LOW_WATER(slave->dcb) && slave->binlog_pos != router->binlog_position) -{ - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Expected to be above low water\n"))); -goto doitagain; -} return rval; } @@ -908,7 +808,7 @@ ROUTER_INSTANCE *router = slave->router; slave->binlog_pos != router->binlog_position) { slave->stats.n_dcb++; - blr_slave_catchup(router, slave); + blr_slave_catchup(router, slave, true); } } @@ -917,7 +817,7 @@ ROUTER_INSTANCE *router = slave->router; if (slave->state == BLRS_DUMPING) { slave->stats.n_cb++; - blr_slave_catchup(router, slave); + blr_slave_catchup(router, slave, true); } else { From 9186d3fa90c5cac029d325316d40072280555361 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Wed, 1 Oct 2014 18:30:13 +0100 Subject: [PATCH 02/22] Fixes for blr_salve performanc issues, linking of embedded library, housekeeper heartbeat addition and unloading of modules to allow profiling of modules using LD_PROFILE environment variable and sprof --- server/core/gateway.c | 1 + server/core/housekeeper.c | 12 +++-- server/core/load_utils.c | 15 ++++++ server/core/memlog.c | 2 + server/core/poll.c | 54 ++++++++++++++++++-- server/core/test/makefile | 9 +++- server/include/dcb.h | 12 +++++ server/include/modules.h | 3 ++ server/modules/include/blr.h | 22 +++++++- server/modules/routing/binlog/CMakeLists.txt | 2 +- server/modules/routing/binlog/Makefile | 8 ++- server/modules/routing/binlog/blr.c | 4 +- server/modules/routing/binlog/blr_file.c | 19 +++++-- server/modules/routing/binlog/blr_master.c | 45 ++++++++++------ server/modules/routing/binlog/blr_slave.c | 24 ++++++--- 15 files changed, 193 insertions(+), 39 deletions(-) diff --git a/server/core/gateway.c b/server/core/gateway.c index 1d67d362f..c8651fe2b 100644 --- a/server/core/gateway.c +++ b/server/core/gateway.c @@ -1633,6 +1633,7 @@ int main(int argc, char **argv) LOGFILE_MESSAGE, "MaxScale shutdown completed."))); + unload_all_modules(); /* Remove Pidfile */ unlink_pidfile(); diff --git a/server/core/housekeeper.c b/server/core/housekeeper.c index fe6cb9047..318ca8fde 100644 --- a/server/core/housekeeper.c +++ b/server/core/housekeeper.c @@ -43,6 +43,7 @@ static HKTASK *tasks = NULL; static SPINLOCK tasklock = SPINLOCK_INIT; static int do_shutdown = 0; +unsigned long hkheartbeat = 0; static void hkthread(void *); @@ -171,12 +172,17 @@ HKTASK *ptr; time_t now; void (*taskfn)(void *); void *taskdata; +int i; for (;;) { - if (do_shutdown) - return; - thread_millisleep(1000); + for (i = 0; i < 10; i++) + { + if (do_shutdown) + return; + thread_millisleep(100); + hkheartbeat++; + } now = time(0); spinlock_acquire(&tasklock); ptr = tasks; diff --git a/server/core/load_utils.c b/server/core/load_utils.c index cba0c6533..a17a04225 100644 --- a/server/core/load_utils.c +++ b/server/core/load_utils.c @@ -332,6 +332,21 @@ MODULES *ptr; free(mod); } +/** + * Unload all modules + * + * Remove all the modules from the system, called during shutdown + * to allow termination hooks to be called. + */ +void +unload_all_modules() +{ + while (registered) + { + unregister_module(registered->module); + } +} + /** * Print Modules * diff --git a/server/core/memlog.c b/server/core/memlog.c index 989950828..73f0af387 100644 --- a/server/core/memlog.c +++ b/server/core/memlog.c @@ -125,6 +125,8 @@ MEMLOG *ptr; void memlog_log(MEMLOG *log, void *value) { + if (!log) + return; spinlock_acquire(&log->lock); switch (log->type) { diff --git a/server/core/poll.c b/server/core/poll.c index b245b79c0..03ced1bfa 100644 --- a/server/core/poll.c +++ b/server/core/poll.c @@ -32,10 +32,14 @@ #include #include -#define PROFILE_POLL 1 +#define PROFILE_POLL 0 #if PROFILE_POLL #include +#include + +extern unsigned long hkheartbeat; +MEMLOG *plog; #endif extern int lm_enabled_logfiles_bitmask; @@ -143,7 +147,9 @@ static struct { int n_fds[MAXNFDS]; /*< Number of wakeups with particular n_fds value */ int evq_length; /*< Event queue length */ + int evq_pending; /*< Number of pending descriptors in event queue */ int evq_max; /*< Maximum event queue length */ + int wake_evqpending;/*< Woken from epoll_wait with pending events in queue */ } pollStats; /** @@ -194,6 +200,9 @@ int i; for (i = 0; i < n_avg_samples; i++) avg_samples[i] = 0.0; +#if PROFILE_POLL + plog = memlog_create("EventQueueWaitTime", ML_LONG, 10000); +#endif } /** @@ -396,6 +405,8 @@ DCB *zombies = NULL; if (thread_data) thread_data[thread_id].state = THREAD_ZPROCESSING; zombies = dcb_process_zombies(thread_id); + if (thread_data) + thread_data[thread_id].state = THREAD_IDLE; } atomic_add(&n_waiting, 1); @@ -423,6 +434,7 @@ DCB *zombies = NULL; pthread_self(), nfds, eno))); + atomic_add(&n_waiting, -1); } /* * If there are no new descriptors from the non-blocking call @@ -431,11 +443,12 @@ DCB *zombies = NULL; */ else if (nfds == 0 && process_pollq(thread_id) == 0) { - atomic_add(&n_waiting, 1); nfds = epoll_wait(epoll_fd, events, MAX_EVENTS, EPOLL_TIMEOUT); + if (nfds == 0 && pollStats.evq_pending) + atomic_add(&pollStats.wake_evqpending, 1); } else { @@ -474,7 +487,7 @@ DCB *zombies = NULL; /* * Process every DCB that has a new event and add * it to the poll queue. - * If the DCB is currently beign processed then we + * If the DCB is currently being processed then we * or in the new eent bits to the pending event bits * and leave it in the queue. * If the DCB was not already in the queue then it was @@ -489,6 +502,13 @@ DCB *zombies = NULL; spinlock_acquire(&pollqlock); if (DCB_POLL_BUSY(dcb)) { + if (dcb->evq.pending_events == 0) + { + pollStats.evq_pending++; +#if PROFILE_POLL + dcb->evq.inserted = hkheartbeat; +#endif + } dcb->evq.pending_events |= ev; } else @@ -508,6 +528,10 @@ DCB *zombies = NULL; dcb->evq.next = dcb; } pollStats.evq_length++; + pollStats.evq_pending++; +#if PROFILE_POLL + dcb->evq.inserted = hkheartbeat; +#endif if (pollStats.evq_length > pollStats.evq_max) { pollStats.evq_max = pollStats.evq_length; @@ -527,6 +551,10 @@ DCB *zombies = NULL; thread_data[thread_id].state = THREAD_ZPROCESSING; } zombies = dcb_process_zombies(thread_id); + if (thread_data) + { + thread_data[thread_id].state = THREAD_IDLE; + } } if (do_shutdown) @@ -608,12 +636,17 @@ uint32_t ev; { ev = dcb->evq.pending_events; dcb->evq.pending_events = 0; + pollStats.evq_pending--; } spinlock_release(&pollqlock); if (found == 0) return 0; +#if PROFILE_POLL + memlog_log(plog, hkheartbeat - dcb->evq.inserted); +#endif + CHK_DCB(dcb); if (thread_data) @@ -927,6 +960,10 @@ int i; pollStats.evq_length); dcb_printf(dcb, "Maximum event queue length: %d\n", pollStats.evq_max); + dcb_printf(dcb, "Number of DCBs with pending events: %d\n", + pollStats.evq_pending); + dcb_printf(dcb, "Number of wakeups with pending queue: %d\n", + pollStats.wake_evqpending); dcb_printf(dcb, "No of poll completions with descriptors\n"); dcb_printf(dcb, "\tNo. of descriptors\tNo. of poll completions.\n"); @@ -1127,6 +1164,13 @@ uint32_t ev = EPOLLOUT; spinlock_acquire(&pollqlock); if (DCB_POLL_BUSY(dcb)) { + if (dcb->evq.pending_events == 0) + { + pollStats.evq_pending++; +#if PROFILE_POLL + dcb->evq.inserted = hkheartbeat; +#endif + } dcb->evq.pending_events |= ev; } else @@ -1146,6 +1190,10 @@ uint32_t ev = EPOLLOUT; dcb->evq.next = dcb; } pollStats.evq_length++; + pollStats.evq_pending++; +#if PROFILE_POLL + dcb->evq.inserted = hkheartbeat; +#endif if (pollStats.evq_length > pollStats.evq_max) { pollStats.evq_max = pollStats.evq_length; diff --git a/server/core/test/makefile b/server/core/test/makefile index 14f2828f2..651254476 100644 --- a/server/core/test/makefile +++ b/server/core/test/makefile @@ -21,7 +21,7 @@ LDFLAGS=-rdynamic -L$(LOGPATH) -L$(EMBEDDED_LIB) \ LIBS= -lz -lm -lcrypt -lcrypto -ldl -laio -lrt -pthread -llog_manager \ -L../../inih/extra -linih -lssl -lstdc++ -lmysqld -TESTS=testhash testspinlock testfilter testadminusers +TESTS=testhash testspinlock testfilter testadminusers testmemlog cleantests: - $(DEL) *.o @@ -59,6 +59,13 @@ testadminusers: testadminusers.c libcore.a -I$(ROOT_PATH)/utils \ testadminusers.c libcore.a $(UTILSPATH)/skygw_utils.o $(LIBS) -o testadminusers +testmemlog: testmemlog.c libcore.a + $(CC) $(CFLAGS) $(LDFLAGS) \ + -I$(ROOT_PATH)/server/include \ + -I$(ROOT_PATH)/utils \ + testmemlog.c libcore.a $(UTILSPATH)/skygw_utils.o $(LIBS) -o testmemlog + + libcore.a: ../*.o ar rv libcore.a ../*.o diff --git a/server/include/dcb.h b/server/include/dcb.h index 72686b7b7..11061bb8f 100644 --- a/server/include/dcb.h +++ b/server/include/dcb.h @@ -98,12 +98,24 @@ typedef struct gw_protocol { int (*session)(struct dcb *, void *); } GWPROTOCOL; +/** + * The event queue structure used in the polling loop to maintain a queue + * of events that need to be processed for the DCB. + * + * next The next DCB in the event queue + * prev The previous DCB in the event queue + * pending_events The events that are pending processing + * processing Flag to indicate the processing status of the DCB + * eventqlock Spinlock to protect this structure + * inserted Insertion time for logging purposes + */ typedef struct { struct dcb *next; struct dcb *prev; uint32_t pending_events; int processing; SPINLOCK eventqlock; + unsigned long inserted; } DCBEVENTQ; /** diff --git a/server/include/modules.h b/server/include/modules.h index 199e3a24b..3dff0e2e5 100644 --- a/server/include/modules.h +++ b/server/include/modules.h @@ -32,6 +32,8 @@ * 13/06/13 Mark Riddoch Initial implementation * 08/07/13 Mark Riddoch Addition of monitor modules * 29/05/14 Mark Riddoch Addition of filter modules + * 01/10/14 Mark Riddoch Addition of call to unload all modules on + * shutdown * @endverbatim */ @@ -58,6 +60,7 @@ typedef struct modules { extern void *load_module(const char *module, const char *type); extern void unload_module(const char *module); +extern void unload_all_modules(); extern void printModules(); extern void dprintAllModules(DCB *); char* get_maxscale_home(void); diff --git a/server/modules/include/blr.h b/server/modules/include/blr.h index 1ba575d49..a6973593e 100644 --- a/server/modules/include/blr.h +++ b/server/modules/include/blr.h @@ -54,7 +54,7 @@ * Default burst sizes for slave catchup */ #define DEF_SHORT_BURST 15 -#define DEF_LONG_BURST 2000 +#define DEF_LONG_BURST 500 /** * Some useful macros for examining the MySQL Response packets @@ -366,6 +366,26 @@ static char *blrs_states[] = { "Created", "Unregistered", "Registered", #define LOG_EVENT_NO_FILTER_F 0x0100 #define LOG_EVENT_MTS_ISOLATE_F 0x0200 +/** + * Macros to extract common fields + */ +#define INLINE_EXTRACT 1 /* Set to 0 for debug purposes */ + +#if INLINE_EXTRACT +#define EXTRACT16(x) (*(uint8_t *)(x) | (*((uint8_t *)(x) + 1) << 8)) +#define EXTRACT24(x) (*(uint8_t *)(x) | \ + (*((uint8_t *)(x) + 1) << 8) | \ + (*((uint8_t *)(x) + 2) << 16)) +#define EXTRACT32(x) (*(uint8_t *)(x) | \ + (*((uint8_t *)(x) + 1) << 8) | \ + (*((uint8_t *)(x) + 2) << 16) | \ + (*((uint8_t *)(x) + 3) << 24)) +#else +#define EXTRACT16(x) extract_field((x), 16) +#define EXTRACT24(x) extract_field((x), 24) +#define EXTRACT32(x) extract_field((x), 32) +#endif + /* * Externals within the router */ diff --git a/server/modules/routing/binlog/CMakeLists.txt b/server/modules/routing/binlog/CMakeLists.txt index 071901b70..4de2a35b4 100644 --- a/server/modules/routing/binlog/CMakeLists.txt +++ b/server/modules/routing/binlog/CMakeLists.txt @@ -1,4 +1,4 @@ add_library(binlogrouter SHARED blr.c blr_master.c blr_cache.c blr_slave.c blr_file.c) set_target_properties(binlogrouter PROPERTIES INSTALL_RPATH ${CMAKE_INSTALL_RPATH}:${CMAKE_INSTALL_PREFIX}/lib) -target_link_libraries(binlogrouter ssl pthread log_manager ${EMBEDDED_LIB}) +target_link_libraries(binlogrouter ssl pthread log_manager) install(TARGETS binlogrouter DESTINATION modules) diff --git a/server/modules/routing/binlog/Makefile b/server/modules/routing/binlog/Makefile index 6e9282ea1..0d665d264 100644 --- a/server/modules/routing/binlog/Makefile +++ b/server/modules/routing/binlog/Makefile @@ -31,10 +31,14 @@ CFLAGS=-c -fPIC -I/usr/include -I../../include -I../../../include \ include ../../../../makefile.inc +#LDFLAGS=-shared -L$(LOGPATH) -L$(QCLASSPATH) -L$(EMBEDDED_LIB) \ +# -Wl,-rpath,$(DEST)/lib \ +# -Wl,-rpath,$(LOGPATH) -Wl,-rpath,$(UTILSPATH) -Wl,-rpath,$(QCLASSPATH) \ +# -Wl,-rpath,$(EMBEDDED_LIB) LDFLAGS=-shared -L$(LOGPATH) -L$(QCLASSPATH) -L$(EMBEDDED_LIB) \ -Wl,-rpath,$(DEST)/lib \ - -Wl,-rpath,$(LOGPATH) -Wl,-rpath,$(UTILSPATH) -Wl,-rpath,$(QCLASSPATH) \ - -Wl,-rpath,$(EMBEDDED_LIB) + -Wl,-rpath,$(LOGPATH) -Wl,-rpath,$(UTILSPATH) + SRCS=blr.c blr_master.c blr_cache.c blr_slave.c blr_file.c OBJ=$(SRCS:.c=.o) diff --git a/server/modules/routing/binlog/blr.c b/server/modules/routing/binlog/blr.c index 1d4a9d8ff..f41462468 100644 --- a/server/modules/routing/binlog/blr.c +++ b/server/modules/routing/binlog/blr.c @@ -173,6 +173,8 @@ int i; inst->service = service; spinlock_init(&inst->lock); + inst->binlog_fd = -1; + inst->low_water = DEF_LOW_WATER; inst->high_water = DEF_HIGH_WATER; inst->initbinlog = 0; @@ -749,7 +751,7 @@ struct tm tm; dcb_printf(dcb, "\tSpinlock statistics (rses_lock):\n"); spinlock_stats(&session->rses_lock, spin_reporter, dcb); #endif - + dcb_printf(dcb, "\n"); session = session->next; } spinlock_release(&router_inst->lock); diff --git a/server/modules/routing/binlog/blr_file.c b/server/modules/routing/binlog/blr_file.c index 7a44033fe..aad5fea45 100644 --- a/server/modules/routing/binlog/blr_file.c +++ b/server/modules/routing/binlog/blr_file.c @@ -290,14 +290,25 @@ int n; /* Read the header information from the file */ if ((n = read(fd, hdbuf, 19)) != 19) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to read header for binlog entry, " - "at %d (%s).\n", pos, strerror(errno)))); - if (n> 0 && n < 19) + switch (n) + { + case 0: + LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, + "Reached end of binlog file at %d.\n", + pos))); + break; + case -1: + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Failed to read binlog file at position %d" + " (%s).\n", pos, strerror(errno)))); + break; + default: LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Short read when reading the header. " "Expected 19 bytes got %d bytes.\n", n))); + break; + } return NULL; } hdr->timestamp = extract_field(hdbuf, 32); diff --git a/server/modules/routing/binlog/blr_master.c b/server/modules/routing/binlog/blr_master.c index 6f92d193d..ad030359d 100644 --- a/server/modules/routing/binlog/blr_master.c +++ b/server/modules/routing/binlog/blr_master.c @@ -515,23 +515,23 @@ static REP_HEADER phdr; /* Get the length of the packet from the residual and new packet */ if (reslen >= 3) { - len = extract_field(pdata, 24); + len = EXTRACT24(pdata); } else if (reslen == 2) { - len = extract_field(pdata, 16); - len |= (extract_field(GWBUF_DATA(pkt->next), 8) << 16); + len = EXTRACT16(pdata); + len |= (*(uint8_t *)GWBUF_DATA(pkt->next) << 16); } else if (reslen == 1) { - len = extract_field(pdata, 8); - len |= (extract_field(GWBUF_DATA(pkt->next), 16) << 8); + len = *pdata; + len |= (EXTRACT16(GWBUF_DATA(pkt->next)) << 8); } len += 4; // Allow space for the header } else { - len = extract_field(pdata, 24) + 4; + len = EXTRACT24(pdata) + 4; } if (reslen < len && pkt_length >= len) @@ -779,18 +779,18 @@ static REP_HEADER phdr; * @param hdr The packet header to populate */ void -blr_extract_header(uint8_t *ptr, REP_HEADER *hdr) +blr_extract_header(register uint8_t *ptr, register REP_HEADER *hdr) { - hdr->payload_len = extract_field(ptr, 24); + hdr->payload_len = EXTRACT24(ptr); hdr->seqno = ptr[3]; hdr->ok = ptr[4]; - hdr->timestamp = extract_field(&ptr[5], 32); + hdr->timestamp = EXTRACT32(&ptr[5]); hdr->event_type = ptr[9]; - hdr->serverid = extract_field(&ptr[10], 32); - hdr->event_size = extract_field(&ptr[14], 32); - hdr->next_pos = extract_field(&ptr[18], 32); - hdr->flags = extract_field(&ptr[22], 16); + hdr->serverid = EXTRACT32(&ptr[10]); + hdr->event_size = EXTRACT32(&ptr[14]); + hdr->next_pos = EXTRACT32(&ptr[18]); + hdr->flags = EXTRACT16(&ptr[22]); } /** @@ -892,13 +892,18 @@ blr_distribute_binlog_record(ROUTER_INSTANCE *router, REP_HEADER *hdr, uint8_t * { GWBUF *pkt; uint8_t *buf; -ROUTER_SLAVE *slave; +ROUTER_SLAVE *slave, *nextslave; int action; spinlock_acquire(&router->lock); slave = router->slaves; while (slave) { + if (slave->state != BLRS_DUMPING) + { + slave = slave->next; + continue; + } spinlock_acquire(&slave->catch_lock); if ((slave->cstate & (CS_UPTODATE|CS_DIST)) == CS_UPTODATE) { @@ -986,6 +991,7 @@ int action; */ if (slave->cstate & CS_UPTODATE) { + nextslave = slave->next; spinlock_release(&router->lock); LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, "Force slave %d into catchup mode %s@%d\n", @@ -998,9 +1004,18 @@ int action; spinlock_acquire(&router->lock); slave = router->slaves; if (slave) - continue; + { + while (slave && slave != nextslave) + slave = slave->next; + if (slave) + continue; + else + break; + } else + { break; + } } } } diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index 0ed3618c9..2afcda7cf 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -473,12 +473,13 @@ blr_slave_binlog_dump(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue { GWBUF *resp; uint8_t *ptr; -int len, flags, serverid, rval; +int len, flags, serverid, rval, binlognamelen; REP_HEADER hdr; uint32_t chksum; ptr = GWBUF_DATA(queue); len = extract_field(ptr, 24); + binlognamelen = len - 11; ptr += 4; // Skip length and sequence number if (*ptr++ != COM_BINLOG_DUMP) { @@ -495,15 +496,16 @@ uint32_t chksum; ptr += 2; serverid = extract_field(ptr, 32); ptr += 4; - strncpy(slave->binlogfile, (char *)ptr, BINLOG_FNAMELEN); + strncpy(slave->binlogfile, (char *)ptr, binlognamelen); + slave->binlogfile[binlognamelen] = 0; slave->state = BLRS_DUMPING; slave->seqno = 1; if (slave->nocrc) - len = 0x2b; + len = 19 + 8 + binlognamelen; else - len = 0x2f; + len = 19 + 8 + 4 + binlognamelen; // Build a fake rotate event resp = gwbuf_alloc(len + 5); @@ -758,7 +760,8 @@ struct timespec req; slave->cstate &= ~CS_BUSY; spinlock_release(&slave->catch_lock); - close(fd); + if (fd != -1) + close(fd); poll_fake_write_event(slave->dcb); if (record) { @@ -831,14 +834,19 @@ ROUTER_INSTANCE *router = slave->router; * Rotate the slave to the new binlog file * * @param slave The slave instance - * @param ptr The rotate event (minux header and OK byte) + * @param ptr The rotate event (minus header and OK byte) */ void blr_slave_rotate(ROUTER_SLAVE *slave, uint8_t *ptr) { +int len = EXTRACT24(ptr + 9); // Extract the event length + + len = len - (19 + 8 + 4); // Remove length of header, checksum and position + if (len > BINLOG_FNAMELEN) + len = BINLOG_FNAMELEN; ptr += 19; // Skip header slave->binlog_pos = extract_field(ptr, 32); slave->binlog_pos += (extract_field(ptr+4, 32) << 32); - memcpy(slave->binlogfile, ptr + 8, BINLOG_FNAMELEN); - slave->binlogfile[BINLOG_FNAMELEN] = 0; + memcpy(slave->binlogfile, ptr + 8, len); + slave->binlogfile[len] = 0; } From 3d7e17d4478c72306e241cb99909a11922027aa3 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Thu, 2 Oct 2014 11:07:47 +0100 Subject: [PATCH 03/22] Add back in the quoting mechanism that was lost when the long argument handling was added. This allow for commands like maxadmin show service "Binlog Service" to work on the command line --- client/maxadmin.c | 17 ++++++++++++++--- 1 file changed, 14 insertions(+), 3 deletions(-) diff --git a/client/maxadmin.c b/client/maxadmin.c index 97459171e..e3c39afee 100644 --- a/client/maxadmin.c +++ b/client/maxadmin.c @@ -183,11 +183,22 @@ char c; len += strlen(argv[i]) + 1; } - cmd = malloc(len); + cmd = malloc(len + (2 * argc)); // Allow for quotes strcpy(cmd, argv[optind]); - for (i = optind +1; i < argc; i++) { + for (i = optind +1; i < argc; i++) + { strcat(cmd, " "); - strcat(cmd, argv[i]); + /* Arguments after the seconf are quoted to allow for names + * that contain white space + */ + if (i - optind > 1) + { + strcat(cmd, "\""); + strcat(cmd, argv[i]); + strcat(cmd, "\""); + } + else + strcat(cmd, argv[i]); } if (access(cmd, R_OK) == 0) From 0bc47b90ff72c81adda8e8c9863422ce3d9b6f76 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Thu, 2 Oct 2014 13:22:00 +0100 Subject: [PATCH 04/22] Move datadir passed to embedded library down one level so that $MAXSCALE_HOME may be read only --- server/core/gateway.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/server/core/gateway.c b/server/core/gateway.c index c8651fe2b..3e5a63a27 100644 --- a/server/core/gateway.c +++ b/server/core/gateway.c @@ -1430,7 +1430,9 @@ int main(int argc, char **argv) * instances of the gateway are beign run on the same * machine. */ - sprintf(datadir, "%s/data%d", home_dir, getpid()); + sprintf(datadir, "%s/data", home_dir); + mkdir(datadir, 0777); + sprintf(datadir, "%s/data/data%d", home_dir, getpid()); mkdir(datadir, 0777); if (!daemon_mode) From 829a4bcbfa38fa026fbe10c764194a3ebdd33c71 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Thu, 2 Oct 2014 17:19:18 +0100 Subject: [PATCH 05/22] Refinement of polling process --- server/core/poll.c | 69 +++++++++++++++++++++++++++++----------------- 1 file changed, 44 insertions(+), 25 deletions(-) diff --git a/server/core/poll.c b/server/core/poll.c index 03ced1bfa..9f39ee50b 100644 --- a/server/core/poll.c +++ b/server/core/poll.c @@ -377,13 +377,30 @@ return_rc: * events at a high rate will not block the execution of events for other DCB's and * should result in a fairer polling strategy. * + * The introduction of the ability to inject "fake" write events into the event queue meant + * that there was a possibility to "starve" new events sicne the polling loop would + * consume the event queue before lookign for new events. If the DCB that inject + * the fake event then injected another fake event as a result of the first it meant + * that new events did not get added to the queue. The strategy has been updated to + * not consume the entire event queue, but process one event before doing a non-blocking + * call to add any new events before processing any more events. A blocking call to + * collect events is only made if there are no pending events to be processed on the + * event queue. + * + * Also introduced a "timeout bias" mechanism. This mechansim control the length of + * of timeout passed to epoll_wait in blocking calls based on previous behaviour. + * The initial call will block for 10% of the define timeout peroid, this will be + * increased in increments of 10% until the full timeout value is used. If at any + * point there is an event to be processed then the value will be reduced to 10% again + * for the next blocking call. + * * @param arg The thread ID passed as a void * to satisfy the threading package */ void poll_waitevents(void *arg) { struct epoll_event events[MAX_EVENTS]; -int i, nfds; +int i, nfds, timeout_bias = 1; int thread_id = (int)arg; DCB *zombies = NULL; @@ -399,14 +416,9 @@ DCB *zombies = NULL; while (1) { - /* Process of the queue of waiting requests */ - while (do_shutdown == 0 && process_pollq(thread_id)) + if (pollStats.evq_pending == 0 && timeout_bias < 10) { - if (thread_data) - thread_data[thread_id].state = THREAD_ZPROCESSING; - zombies = dcb_process_zombies(thread_id); - if (thread_data) - thread_data[thread_id].state = THREAD_IDLE; + timeout_bias++; } atomic_add(&n_waiting, 1); @@ -440,13 +452,16 @@ DCB *zombies = NULL; * If there are no new descriptors from the non-blocking call * and nothing to proces on the event queue then for do a * blocking call to epoll_wait. + * + * We calculate a timeout bias to alter the length of the blocking + * call based on the time since we last received an event to process */ - else if (nfds == 0 && process_pollq(thread_id) == 0) + else if (nfds == 0 && pollStats.evq_pending > 0) { nfds = epoll_wait(epoll_fd, events, MAX_EVENTS, - EPOLL_TIMEOUT); + (EPOLL_TIMEOUT * timeout_bias) / 10); if (nfds == 0 && pollStats.evq_pending) atomic_add(&pollStats.wake_evqpending, 1); } @@ -463,6 +478,7 @@ DCB *zombies = NULL; #endif /* BLOCKINGPOLL */ if (nfds > 0) { + timeout_bias = 1; LOGIF(LD, (skygw_log_write( LOGFILE_DEBUG, "%lu [poll_waitevents] epoll_wait found %d fds", @@ -542,21 +558,20 @@ DCB *zombies = NULL; } /* - * If there was nothing to process then process the zombie queue + * Process of the queue of waiting requests + * This is done without checking the evq_pending count as a + * precautionary measure to avoid issues if the house keeping + * of the count goes wrong. */ - if (process_pollq(thread_id) == 0) - { - if (thread_data) - { - thread_data[thread_id].state = THREAD_ZPROCESSING; - } - zombies = dcb_process_zombies(thread_id); - if (thread_data) - { - thread_data[thread_id].state = THREAD_IDLE; - } - } - + if (process_pollq(thread_id)) + timeout_bias = 1; + + if (thread_data) + thread_data[thread_id].state = THREAD_ZPROCESSING; + zombies = dcb_process_zombies(thread_id); + if (thread_data) + thread_data[thread_id].state = THREAD_IDLE; + if (do_shutdown) { /*< @@ -1152,7 +1167,11 @@ int new_samples, new_nfds; * queue. * * This is used to trigger transmission activity on another DCB from - * within the event processing routine of a DCB. + * within the event processing routine of a DCB. or to allow a DCB + * to defer some further output processing, to allow for other DCBs + * to receive a slice of the processing time. Fake events are added + * to the tail of the event queue, in the same way that real events + * are, so maintain the "fairness" of processing. * * @param dcb DCB to emulate an EPOLLOUT event for */ From 501d0bcae6f8d8ec5fefc28e9ef0257ada07f903 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Thu, 2 Oct 2014 17:19:43 +0100 Subject: [PATCH 06/22] Reconnect to master on error Refine locking in blr_slave_catchup and add tracing --- server/modules/routing/binlog/blr.c | 6 ++++- server/modules/routing/binlog/blr_slave.c | 29 +++++++++++++++++------ 2 files changed, 27 insertions(+), 8 deletions(-) diff --git a/server/modules/routing/binlog/blr.c b/server/modules/routing/binlog/blr.c index f41462468..6dcff344a 100644 --- a/server/modules/routing/binlog/blr.c +++ b/server/modules/routing/binlog/blr.c @@ -797,9 +797,13 @@ ROUTER_INSTANCE *router = (ROUTER_INSTANCE *)instance; static void errorReply(ROUTER *instance, void *router_session, GWBUF *message, DCB *backend_dcb, error_action_t action, bool *succp) { +ROUTER_INSTANCE *router = (ROUTER_INSTANCE *)instance; + LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, "Erorr Reply '%s'", message))); + LOGFILE_ERROR, "Erorr Reply '%s', attempting reconnect to master", + message))); *succp = false; + blr_master_reconnect(router); } /** to be inline'd */ diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index 2afcda7cf..01e39739e 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -674,9 +674,9 @@ uint8_t *ptr; * needs to put the slave into catchup mode. This prevents the slave taking * too much tiem away from the thread that is processing the master events. * - * At the end ofthe burst a fake EPOLLOUT event is added to the poll event + * At the end of the burst a fake EPOLLOUT event is added to the poll event * queue. This ensures that the slave callback for processing DCB write drain - * will be called and future catchup requests will be handle on another thread. + * will be called and future catchup requests will be handled on another thread. * * @param router The binlog router * @param slave The slave that is behind @@ -692,6 +692,10 @@ int written, fd, rval = 1, burst; uint8_t *ptr; struct timespec req; +extern unsigned long hkheartbeat; +unsigned long beat; + beat = hkheartbeat; + if (large) burst = router->long_burst; else @@ -705,8 +709,19 @@ struct timespec req; nanosleep(&req, NULL); spinlock_acquire(&slave->catch_lock); } - slave->cstate |= (CS_HOLD|CS_BUSY); + if (slave->cstate & CS_BUSY) + { + spinlock_release(&slave->catch_lock); +if (hkheartbeat - beat > 5) LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Long wait in blr_salve_catchup %ld00ms with %s burst, return without write records.\n", +hkheartbeat - beat, large ? "long" : "short"))); + return 0; + } + slave->cstate |= CS_BUSY; spinlock_release(&slave->catch_lock); +if (hkheartbeat - beat > 5) LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Long wait in blr_salve_catchup %ld00ms with %s burst.\n", +hkheartbeat - beat, large ? "long" : "short"))); if ((fd = blr_open_binlog(router, slave->binlogfile)) == -1) { @@ -743,9 +758,6 @@ struct timespec req; break; } } - spinlock_acquire(&slave->catch_lock); - slave->cstate |= CS_HOLD; - spinlock_release(&slave->catch_lock); written = slave->dcb->func.write(slave->dcb, head); if (written && hdr.event_type != ROTATE_EVENT) { @@ -753,6 +765,9 @@ struct timespec req; } rval = written; slave->stats.n_events++; + spinlock_acquire(&slave->catch_lock); + slave->cstate |= CS_HOLD; + spinlock_release(&slave->catch_lock); } if (record == NULL) slave->stats.n_failed_read++; @@ -762,13 +777,13 @@ struct timespec req; if (fd != -1) close(fd); - poll_fake_write_event(slave->dcb); if (record) { slave->stats.n_flows++; spinlock_acquire(&slave->catch_lock); slave->cstate |= CS_EXPECTCB; spinlock_release(&slave->catch_lock); + poll_fake_write_event(slave->dcb); } else { From fd1154b9445976811c87d6e65cd371a6c29dc3bd Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Fri, 3 Oct 2014 14:33:28 +0100 Subject: [PATCH 07/22] Change of distribution mechanism to use fake events exclusively and avoid complex locking mechanism and blocking the master DCB eent processign thread Addition of shared BLFILE mechanism to reduce open/close overhead --- server/modules/include/blr.h | 106 +++++++-------- server/modules/routing/binlog/blr.c | 8 +- server/modules/routing/binlog/blr_file.c | 142 ++++++++++++++------- server/modules/routing/binlog/blr_master.c | 8 ++ server/modules/routing/binlog/blr_slave.c | 60 ++++++--- 5 files changed, 205 insertions(+), 119 deletions(-) diff --git a/server/modules/include/blr.h b/server/modules/include/blr.h index a6973593e..84240675e 100644 --- a/server/modules/include/blr.h +++ b/server/modules/include/blr.h @@ -43,6 +43,8 @@ #define BLR_STATS_FREQ 60 #define BLR_NSTATS_MINUTES 30 +#define QUEUE_SLAVE 1 + /** * High and Low water marks for the slave dcb. These values can be overriden * by the router options highwater and lowwater. @@ -66,6 +68,52 @@ #define MYSQL_ERROR_MSG(buf) ((uint8_t *)GWBUF_DATA(buf) + 6) #define MYSQL_COMMAND(buf) (*((uint8_t *)GWBUF_DATA(buf) + 4)) + +/** + * Packet header for replication messages + */ +typedef struct rep_header { + int payload_len; /*< Payload length (24 bits) */ + uint8_t seqno; /*< Response sequence number */ + uint8_t ok; /*< OK Byte from packet */ + uint32_t timestamp; /*< Timestamp - start of binlog record */ + uint8_t event_type; /*< Binlog event type */ + uint32_t serverid; /*< Server id of master */ + uint32_t event_size; /*< Size of header, post-header and body */ + uint32_t next_pos; /*< Position of next event */ + uint16_t flags; /*< Event flags */ +} REP_HEADER; + +/** + * The binlog record structure. This contains the actual packet read from the binlog + * file. + */ +typedef struct { + unsigned long position; /*< binlog record position for this cache entry */ + GWBUF *pkt; /*< The packet received from the master */ + REP_HEADER hdr; /*< The packet header */ +} BLCACHE_RECORD; + +/** + * The binlog cache. A cache exists for each file that hold cached bin log records. + * Caches will be used for all files being read by more than 1 slave. + */ +typedef struct { + BLCACHE_RECORD **records; /*< The actual binlog records */ + int current; /*< The next record that will be inserted */ + int cnt; /*< The number of records in the cache */ + SPINLOCK lock; /*< The spinlock for the cache */ +} BLCACHE; + +typedef struct blfile { + char binlogname[BINLOG_FNAMELEN+1]; /*< Name of the binlog file */ + int fd; /*< Actual file descriptor */ + int refcnt; /*< Reference count for file */ + BLCACHE *cache; /*< Record cache for this file */ + SPINLOCK lock; /*< The file lock */ + struct blfile *next; /*< Next file in list */ +} BLFILE; + /** * Slave statistics */ @@ -74,8 +122,6 @@ typedef struct { int n_bursts; /*< Number of bursts sent */ int n_requests; /*< Number of requests received */ int n_flows; /*< Number of flow control restarts */ - int n_catchupnr; /*< No. of times catchup resulted in not entering loop */ - int n_alreadyupd; int n_upd; int n_cb; int n_cbna; @@ -102,6 +148,7 @@ typedef struct router_slave { int binlog_pos; /*< Binlog position for this slave */ char binlogfile[BINLOG_FNAMELEN+1]; /*< Current binlog file for this slave */ + BLFILE *file; /*< Currently open binlog file */ int serverid; /*< Server-id of the slave */ char *hostname; /*< Hostname of the slave, if known */ char *user; /*< Username if given */ @@ -169,37 +216,6 @@ typedef struct { int fde_len; /*< Length of fde_event */ } MASTER_RESPONSES; -/** - * The binlog record structure. This contains the actual packet received from the - * master, the binlog position of the data in the packet, a point to the data and - * the length of the binlog record. - * - * This allows requests for binlog records in the cache to be serviced by simply - * sending the exact same packet as was received by MaxScale from the master. - * Items are written to the backing file as soon as they are received. The binlog - * cache is flushed of old records periodically, releasing the GWBUF's back to the - * free memory pool. - */ -typedef struct { - unsigned long position; /*< binlog record position for this cache entry */ - GWBUF *pkt; /*< The packet received from the master */ - unsigned char *data; /*< Pointer to the data within the packet */ - unsigned int record_len; /*< Binlog record length */ -} BLCACHE_RECORD; - -/** - * The binlog cache. A cache exists for each file that hold cached bin log records. - * Typically the router will hold two binlog caches, one for the current file and one - * for the previous file. - */ -typedef struct { - char filename[BINLOG_FNAMELEN+1]; - BLCACHE_RECORD *first; - BLCACHE_RECORD *current; - int cnt; -} BLCACHE; - - /** * The per instance data for the router. */ @@ -221,6 +237,7 @@ typedef struct router_instance { uint8_t lastEventReceived; GWBUF *residual; /*< Any residual binlog event */ MASTER_RESPONSES saved_master; /*< Saved master responses */ + char *binlogdir; /*< The directory with the binlog files */ char binlog_name[BINLOG_FNAMELEN+1]; /*< Name of the current binlog file */ uint64_t binlog_position; @@ -228,11 +245,12 @@ typedef struct router_instance { int binlog_fd; /*< File descriptor of the binlog * file being written */ + BLFILE *files; /*< Files used by the slaves */ + SPINLOCK fileslock; /*< Lock for the files queue above */ unsigned int low_water; /*< Low water mark for client DCB */ unsigned int high_water; /*< High water mark for client DCB */ unsigned int short_burst; /*< Short burst for slave catchup */ unsigned int long_burst; /*< Long burst for slave catchup */ - BLCACHE *cache[2]; ROUTER_STATS stats; /*< Statistics for this router */ int active_logs; int reconnect_pending; @@ -241,21 +259,6 @@ typedef struct router_instance { *next; } ROUTER_INSTANCE; -/** - * Packet header for replication messages - */ -typedef struct rep_header { - int payload_len; /*< Payload length (24 bits) */ - uint8_t seqno; /*< Response sequence number */ - uint8_t ok; /*< OK Byte from packet */ - uint32_t timestamp; /*< Timestamp - start of binlog record */ - uint8_t event_type; /*< Binlog event type */ - uint32_t serverid; /*< Server id of master */ - uint32_t event_size; /*< Size of header, post-header and body */ - uint32_t next_pos; /*< Position of next event */ - uint16_t flags; /*< Event flags */ -} REP_HEADER; - /** * State machine for the master to MaxScale replication */ @@ -399,9 +402,10 @@ extern int blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, bool extern void blr_init_cache(ROUTER_INSTANCE *); extern void blr_file_init(ROUTER_INSTANCE *); -extern int blr_open_binlog(ROUTER_INSTANCE *, char *); extern void blr_write_binlog_record(ROUTER_INSTANCE *, REP_HEADER *,uint8_t *); extern void blr_file_rotate(ROUTER_INSTANCE *, char *, uint64_t); extern void blr_file_flush(ROUTER_INSTANCE *); -extern GWBUF *blr_read_binlog(int, unsigned int, REP_HEADER *); +extern BLFILE *blr_open_binlog(ROUTER_INSTANCE *, char *); +extern GWBUF *blr_read_binlog(BLFILE *, unsigned int, REP_HEADER *); +extern void blr_close_binlog(ROUTER_INSTANCE *, BLFILE *); #endif diff --git a/server/modules/routing/binlog/blr.c b/server/modules/routing/binlog/blr.c index 6dcff344a..d9659ddd2 100644 --- a/server/modules/routing/binlog/blr.c +++ b/server/modules/routing/binlog/blr.c @@ -172,6 +172,8 @@ int i; inst->service = service; spinlock_init(&inst->lock); + inst->files = NULL; + spinlock_init(&inst->fileslock); inst->binlog_fd = -1; @@ -379,6 +381,7 @@ ROUTER_SLAVE *slave; spinlock_init(&slave->catch_lock); slave->dcb = session->client; slave->router = inst; + slave->file = NULL; /** * Add this session to the list of active sessions. @@ -498,6 +501,9 @@ ROUTER_SLAVE *slave = (ROUTER_SLAVE *)router_session; */ slave->state = BLRS_UNREGISTERED; + if (slave->file) + blr_close_binlog(router, slave->file); + /* Unlock */ rses_end_locked_router_action(slave); } @@ -719,8 +725,6 @@ struct tm tm; session->stats.minavgs[minno], min5, min10, min15, min30); dcb_printf(dcb, "\t\tNo. flow control: %u\n", session->stats.n_flows); - dcb_printf(dcb, "\t\tNo. catchup NRs: %u\n", session->stats.n_catchupnr); - dcb_printf(dcb, "\t\tNo. already up to date: %u\n", session->stats.n_alreadyupd); dcb_printf(dcb, "\t\tNo. up to date: %u\n", session->stats.n_upd); dcb_printf(dcb, "\t\tNo. of drained cbs %u\n", session->stats.n_dcb); dcb_printf(dcb, "\t\tNo. of low water cbs N/A %u\n", session->stats.n_cbna); diff --git a/server/modules/routing/binlog/blr_file.c b/server/modules/routing/binlog/blr_file.c index aad5fea45..8bab32fae 100644 --- a/server/modules/routing/binlog/blr_file.c +++ b/server/modules/routing/binlog/blr_file.c @@ -50,9 +50,9 @@ #include #include - extern int lm_enabled_logfiles_bitmask; + static void blr_file_create(ROUTER_INSTANCE *router, char *file); static void blr_file_append(ROUTER_INSTANCE *router, char *file); static uint32_t extract_field(uint8_t *src, int bits); @@ -85,6 +85,8 @@ struct dirent *dp; if (access(path, R_OK) == -1) mkdir(path, 0777); + router->binlogdir = strdup(path); + /* First try to find a binlog file number by reading the directory */ root_len = strlen(router->fileroot); dirp = opendir(path); @@ -146,17 +148,11 @@ blr_file_rotate(ROUTER_INSTANCE *router, char *file, uint64_t pos) static void blr_file_create(ROUTER_INSTANCE *router, char *file) { -char *ptr, path[1024]; +char path[1024]; int fd; unsigned char magic[] = BINLOG_MAGIC; - strcpy(path, "/usr/local/skysql/MaxScale"); - if ((ptr = getenv("MAXSCALE_HOME")) != NULL) - { - strcpy(path, ptr); - } - strcat(path, "/"); - strcat(path, router->service->name); + strcpy(path, router->binlogdir); strcat(path, "/"); strcat(path, file); @@ -186,16 +182,10 @@ unsigned char magic[] = BINLOG_MAGIC; static void blr_file_append(ROUTER_INSTANCE *router, char *file) { -char *ptr, path[1024]; +char path[1024]; int fd; - strcpy(path, "/usr/local/skysql/MaxScale"); - if ((ptr = getenv("MAXSCALE_HOME")) != NULL) - { - strcpy(path, ptr); - } - strcat(path, "/"); - strcat(path, router->service->name); + strcpy(path, router->binlogdir); strcat(path, "/"); strcat(path, file); @@ -238,57 +228,79 @@ blr_file_flush(ROUTER_INSTANCE *router) fsync(router->binlog_fd); } -int +/** + * Open a binlog file for reading binlog records + * + * @param router The router instance + * @param binlog The binlog filename + * @return a binlog file record + */ +BLFILE * blr_open_binlog(ROUTER_INSTANCE *router, char *binlog) { char *ptr, path[1024]; -int rval; +BLFILE *file; - strcpy(path, "/usr/local/skysql/MaxScale"); - if ((ptr = getenv("MAXSCALE_HOME")) != NULL) + spinlock_acquire(&router->fileslock); + file = router->files; + while (file && strcmp(file->binlogname, binlog) != 0) + file = file->next; + + if (file) { - strcpy(path, ptr); + file->refcnt++; + spinlock_release(&router->fileslock); + return file; } - strcat(path, "/"); - strcat(path, router->service->name); + + if ((file = (BLFILE *)malloc(sizeof(BLFILE))) == NULL) + { + spinlock_release(&router->fileslock); + return NULL; + } + strcpy(file->binlogname, binlog); + file->refcnt = 1; + file->cache = 0; + spinlock_init(&file->lock); + + strcpy(path, router->binlogdir); strcat(path, "/"); strcat(path, binlog); - if ((rval = open(path, O_RDONLY, 0666)) == -1) + if ((file->fd = open(path, O_RDONLY, 0666)) == -1) { LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Failed to open binlog file %s\n", path))); + free(file); + spinlock_release(&router->fileslock); + return NULL; } - return rval; + file->next = router->files; + router->files = file; + spinlock_release(&router->fileslock); + + return file; } /** * Read a replication event into a GWBUF structure. * - * @param fd File descriptor of the binlog file + * @param file File record * @param pos Position of binlog record to read * @param hdr Binlog header to populate * @return The binlog record wrapped in a GWBUF structure */ GWBUF * -blr_read_binlog(int fd, unsigned int pos, REP_HEADER *hdr) +blr_read_binlog(BLFILE *file, unsigned int pos, REP_HEADER *hdr) { uint8_t hdbuf[19]; GWBUF *result; unsigned char *data; int n; - if (lseek(fd, pos, SEEK_SET) != pos) - { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to seek for binlog entry, " - "at %d.\n", pos))); - return NULL; - } - /* Read the header information from the file */ - if ((n = read(fd, hdbuf, 19)) != 19) + if ((n = pread(file->fd, hdbuf, 19, pos)) != 19) { switch (n) { @@ -299,24 +311,26 @@ int n; break; case -1: LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to read binlog file at position %d" - " (%s).\n", pos, strerror(errno)))); + "Failed to read binlog file %s at position %d" + " (%s).\n", file->binlogname, + pos, strerror(errno)))); break; default: LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Short read when reading the header. " - "Expected 19 bytes got %d bytes.\n", - n))); + "Expected 19 bytes got %d bytes." + "Binlog file is %s, position %d\n", + file->binlogname, pos, n))); break; } return NULL; } - hdr->timestamp = extract_field(hdbuf, 32); + hdr->timestamp = EXTRACT32(hdbuf); hdr->event_type = hdbuf[4]; - hdr->serverid = extract_field(&hdbuf[5], 32); - hdr->event_size = extract_field(&hdbuf[9], 32); - hdr->next_pos = extract_field(&hdbuf[13], 32); - hdr->flags = extract_field(&hdbuf[17], 16); + hdr->serverid = EXTRACT32(&hdbuf[5]); + hdr->event_size = EXTRACT32(&hdbuf[9]); + hdr->next_pos = EXTRACT32(&hdbuf[13]); + hdr->flags = EXTRACT16(&hdbuf[17]); if ((result = gwbuf_alloc(hdr->event_size)) == NULL) { LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, @@ -327,7 +341,7 @@ int n; } data = GWBUF_DATA(result); memcpy(data, hdbuf, 19); // Copy the header in - if ((n = read(fd, &data[19], hdr->event_size - 19)) + if ((n = pread(file->fd, &data[19], hdr->event_size - 19, pos + 19)) != hdr->event_size - 19) // Read the balance { LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, @@ -340,6 +354,40 @@ int n; return result; } +/** + * Close a binlog file that has been opened to read binlog records + * + * The open binlog files are shared between multiple slaves that are + * reading the same binlog file. + * + * @param router The router instance + * @param file The file to close + */ +void +blr_close_binlog(ROUTER_INSTANCE *router, BLFILE *file) +{ + spinlock_acquire(&file->lock); + file->refcnt--; + if (file->refcnt == 0) + { + spinlock_acquire(&router->fileslock); + if (router->files == file) + router->files = file; + else + { + BLFILE *ptr = router->files; + while (ptr && ptr->next != file) + ptr = ptr->next; + if (ptr) + ptr->next = file->next; + } + spinlock_release(&router->fileslock); + + close(file->fd); + } + spinlock_release(&file->lock); +} + /** * Extract a numeric field from a packet of the specified number of bits * diff --git a/server/modules/routing/binlog/blr_master.c b/server/modules/routing/binlog/blr_master.c index ad030359d..395d10ba3 100644 --- a/server/modules/routing/binlog/blr_master.c +++ b/server/modules/routing/binlog/blr_master.c @@ -955,6 +955,9 @@ int action; { slave->stats.n_overrun++; slave->overrun = 0; +#if QUEUE_SLAVE + poll_fake_write_event(slave->dcb); +#else spinlock_release(&router->lock); slave->cstate &= ~(CS_UPTODATE|CS_DIST); spinlock_release(&slave->catch_lock); @@ -965,6 +968,7 @@ int action; continue; else break; +#endif } else { @@ -991,6 +995,9 @@ int action; */ if (slave->cstate & CS_UPTODATE) { +#if QUEUE_SLAVE + poll_fake_write_event(slave->dcb); +#else nextslave = slave->next; spinlock_release(&router->lock); LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, @@ -1016,6 +1023,7 @@ int action; { break; } +#endif } } } diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index 01e39739e..d7c691892 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -61,8 +61,8 @@ static int blr_slave_send_timestamp(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave static int blr_slave_register(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue); static int blr_slave_binlog_dump(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue); int blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, bool large); -static uint8_t *blr_build_header(GWBUF *pkt, REP_HEADER *hdr); -static int blr_slave_callback(DCB *dcb, DCB_REASON reason, void *data); +uint8_t *blr_build_header(GWBUF *pkt, REP_HEADER *hdr); +int blr_slave_callback(DCB *dcb, DCB_REASON reason, void *data); extern int lm_enabled_logfiles_bitmask; @@ -577,7 +577,11 @@ uint32_t chksum; spinlock_acquire(&slave->catch_lock); slave->cstate &= ~CS_UPTODATE; spinlock_release(&slave->catch_lock); +#if QUEUE_SLAVE + poll_fake_write_event(slave->dcb); +#else rval = blr_slave_catchup(router, slave, true); +#endif } return rval; @@ -631,7 +635,7 @@ encode_value(unsigned char *data, unsigned int value, int len) * @param hdr The packet header to populate * @return A pointer to the first byte following the event header */ -static uint8_t * +uint8_t * blr_build_header(GWBUF *pkt, REP_HEADER *hdr) { uint8_t *ptr; @@ -688,7 +692,7 @@ blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, bool large) { GWBUF *head, *record; REP_HEADER hdr; -int written, fd, rval = 1, burst; +int written, rval = 1, burst; uint8_t *ptr; struct timespec req; @@ -701,6 +705,12 @@ unsigned long beat; else burst = router->short_burst; spinlock_acquire(&slave->catch_lock); +#if QUEUE_SLAVE + if (slave->cstate & CS_BUSY) + return 0; + slave->cstate = CS_BUSY; + spinlock_release(&slave->catch_lock); +#else while ((slave->cstate & (CS_HOLD|CS_BUSY)) == (CS_HOLD|CS_BUSY)) { spinlock_release(&slave->catch_lock); @@ -715,29 +725,36 @@ unsigned long beat; if (hkheartbeat - beat > 5) LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Long wait in blr_salve_catchup %ld00ms with %s burst, return without write records.\n", hkheartbeat - beat, large ? "long" : "short"))); - return 0; + return; } slave->cstate |= CS_BUSY; spinlock_release(&slave->catch_lock); if (hkheartbeat - beat > 5) LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Long wait in blr_salve_catchup %ld00ms with %s burst.\n", + "Long wait in blr_slave_catchup %ld00ms with %s burst.\n", hkheartbeat - beat, large ? "long" : "short"))); +#endif - if ((fd = blr_open_binlog(router, slave->binlogfile)) == -1) + if (slave->file == NULL) { - LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, - "blr_slave_catchup failed to open binlog file %s\n", - slave->binlogfile))); - return 0; + if ((slave->file = blr_open_binlog(router, slave->binlogfile)) == NULL) + { + LOGIF(LE, (skygw_log_write( + LOGFILE_ERROR, + "blr_slave_catchup failed to open binlog file %s\n", + slave->binlogfile))); + return 0; + } } slave->stats.n_bursts++; while (burst-- && - (record = blr_read_binlog(fd, slave->binlog_pos, &hdr)) != NULL) + (record = blr_read_binlog(slave->file, slave->binlog_pos, &hdr)) != NULL) { +#if QUEUE_SLAVE +#else spinlock_acquire(&slave->catch_lock); slave->cstate &= ~CS_HOLD; spinlock_release(&slave->catch_lock); +#endif head = gwbuf_alloc(5); ptr = GWBUF_DATA(head); encode_value(ptr, hdr.event_size + 1, 24); @@ -747,9 +764,9 @@ hkheartbeat - beat, large ? "long" : "short"))); head = gwbuf_append(head, record); if (hdr.event_type == ROTATE_EVENT) { - close(fd); + blr_close_binlog(router, slave->file); blr_slave_rotate(slave, GWBUF_DATA(record)); - if ((fd = blr_open_binlog(router, slave->binlogfile)) == -1) + if ((slave->file = blr_open_binlog(router, slave->binlogfile)) == NULL) { LOGIF(LE, (skygw_log_write( LOGFILE_ERROR, @@ -765,9 +782,12 @@ hkheartbeat - beat, large ? "long" : "short"))); } rval = written; slave->stats.n_events++; +#if QUEUE_SLAVE +#else spinlock_acquire(&slave->catch_lock); slave->cstate |= CS_HOLD; spinlock_release(&slave->catch_lock); +#endif } if (record == NULL) slave->stats.n_failed_read++; @@ -775,8 +795,6 @@ hkheartbeat - beat, large ? "long" : "short"))); slave->cstate &= ~CS_BUSY; spinlock_release(&slave->catch_lock); - if (fd != -1) - close(fd); if (record) { slave->stats.n_flows++; @@ -814,7 +832,7 @@ hkheartbeat - beat, large ? "long" : "short"))); * @param reason The reason the callback was called * @param data The user data, in this case the server structure */ -static int +int blr_slave_callback(DCB *dcb, DCB_REASON reason, void *data) { ROUTER_SLAVE *slave = (ROUTER_SLAVE *)data; @@ -823,8 +841,12 @@ ROUTER_INSTANCE *router = slave->router; if (reason == DCB_REASON_DRAINED) { if (slave->state == BLRS_DUMPING && - slave->binlog_pos != router->binlog_position) + (slave->binlog_pos != router->binlog_position + || strcmp(slave->binlogfile, router->binlog_name))) { + spinlock_acquire(&slave->catch_lock); + slave->cstate &= ~CS_UPTODATE; + spinlock_release(&slave->catch_lock); slave->stats.n_dcb++; blr_slave_catchup(router, slave, true); } From d5947a0922220fd49a76c92376ca0f821e1c14a2 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Fri, 3 Oct 2014 14:34:46 +0100 Subject: [PATCH 08/22] Add dlclose so that shared libraries get shutdown correctly --- server/core/load_utils.c | 1 + 1 file changed, 1 insertion(+) diff --git a/server/core/load_utils.c b/server/core/load_utils.c index a17a04225..e81d473e7 100644 --- a/server/core/load_utils.c +++ b/server/core/load_utils.c @@ -326,6 +326,7 @@ MODULES *ptr; * The module is now not in the linked list and all * memory related to it can be freed */ + dlclose(mod->handle); free(mod->module); free(mod->type); free(mod->version); From 8986a8042eb200d55ae55681c9c0fc590e72315d Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Fri, 3 Oct 2014 14:35:19 +0100 Subject: [PATCH 09/22] Addition of averages for event queue pending events --- server/core/poll.c | 23 ++++++++++++++++++++++- 1 file changed, 22 insertions(+), 1 deletion(-) diff --git a/server/core/poll.c b/server/core/poll.c index 9f39ee50b..9bd11c3fb 100644 --- a/server/core/poll.c +++ b/server/core/poll.c @@ -96,6 +96,7 @@ static int load_samples = 0; static int load_nfds = 0; static double current_avg = 0.0; static double *avg_samples = NULL; +static int *evqp_samples = NULL; static int next_sample = 0; static int n_avg_samples; @@ -196,9 +197,12 @@ int i; hktask_add("Load Average", poll_loadav, NULL, POLL_LOAD_FREQ); n_avg_samples = 15 * 60 / POLL_LOAD_FREQ; - avg_samples = (double *)malloc(sizeof(double *) * n_avg_samples); + avg_samples = (double *)malloc(sizeof(double) * n_avg_samples); for (i = 0; i < n_avg_samples; i++) avg_samples[i] = 0.0; + evqp_samples = (int *)malloc(sizeof(int) * n_avg_samples); + for (i = 0; i < n_avg_samples; i++) + evqp_samples[i] = 0.0; #if PROFILE_POLL plog = memlog_create("EventQueueWaitTime", ML_LONG, 10000); @@ -1055,6 +1059,7 @@ dShowThreads(DCB *dcb) int i, j, n; char *state; double avg1 = 0.0, avg5 = 0.0, avg15 = 0.0; +double qavg1 = 0.0, qavg5 = 0.0, qavg15 = 0.0; dcb_printf(dcb, "Polling Threads.\n\n"); @@ -1063,8 +1068,12 @@ double avg1 = 0.0, avg5 = 0.0, avg15 = 0.0; /* Average all the samples to get the 15 minute average */ for (i = 0; i < n_avg_samples; i++) + { avg15 += avg_samples[i]; + qavg15 += evqp_samples[i]; + } avg15 = avg15 / n_avg_samples; + qavg15 = qavg15 / n_avg_samples; /* Average the last third of the samples to get the 5 minute average */ n = 5 * 60 / POLL_LOAD_FREQ; @@ -1072,8 +1081,12 @@ double avg1 = 0.0, avg5 = 0.0, avg15 = 0.0; if (i < 0) i += n_avg_samples; for (j = i; j < i + n; j++) + { avg5 += avg_samples[j % n_avg_samples]; + qavg5 += evqp_samples[j % n_avg_samples]; + } avg5 = (3 * avg5) / (n_avg_samples); + qavg5 = (3 * qavg5) / (n_avg_samples); /* Average the last 15th of the samples to get the 1 minute average */ n = 60 / POLL_LOAD_FREQ; @@ -1081,11 +1094,18 @@ double avg1 = 0.0, avg5 = 0.0, avg15 = 0.0; if (i < 0) i += n_avg_samples; for (j = i; j < i + n; j++) + { avg1 += avg_samples[j % n_avg_samples]; + qavg1 += evqp_samples[j % n_avg_samples]; + } avg1 = (15 * avg1) / (n_avg_samples); + qavg1 = (15 * qavg1) / (n_avg_samples); dcb_printf(dcb, "15 Minute Average: %.2f, 5 Minute Average: %.2f, " "1 Minute Average: %.2f\n\n", avg15, avg5, avg1); + dcb_printf(dcb, "Pending event queue length averages:\n"); + dcb_printf(dcb, "15 Minute Average: %.2f, 5 Minute Average: %.2f, " + "1 Minute Average: %.2f\n\n", qavg15, qavg5, qavg1); if (thread_data == NULL) return; @@ -1157,6 +1177,7 @@ int new_samples, new_nfds; else current_avg = 0.0; avg_samples[next_sample] = current_avg; + evqp_samples[next_sample] = pollStats.evq_pending; next_sample++; if (next_sample >= n_avg_samples) next_sample = 0; From 52e8b3342299b5a02dcdbfc3ff92bc067cfa32f7 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Tue, 14 Oct 2014 11:40:23 +0100 Subject: [PATCH 10/22] Added the ability to have a non-auto-flushing memlog. Flush is then a manual process. Useful for triggering the dumping of the circular buffer when an error is detected. --- server/core/memlog.c | 81 +++++++++++++++++++++++++++++++---------- server/include/memlog.h | 14 +++++++ 2 files changed, 76 insertions(+), 19 deletions(-) diff --git a/server/core/memlog.c b/server/core/memlog.c index 73f0af387..43df8c5da 100644 --- a/server/core/memlog.c +++ b/server/core/memlog.c @@ -33,8 +33,6 @@ static MEMLOG *memlogs = NULL; static SPINLOCK *memlock = SPINLOCK_INIT; -static void memlog_flush(MEMLOG *); - /** * Create a new instance of a memory logger. * @@ -59,6 +57,7 @@ MEMLOG *log; log->type = type; log->offset = 0; log->size = size; + log->flags = 0; switch (type) { case ML_INT: @@ -97,7 +96,8 @@ memlog_destroy(MEMLOG *log) { MEMLOG *ptr; - memlog_flush(log); + if ((log->flags & MLNOAUTOFLUSH) == 0) + memlog_flush(log); free(log->values); spinlock_acquire(&memlock); @@ -146,8 +146,10 @@ memlog_log(MEMLOG *log, void *value) log->offset++; if (log->offset == log->size) { - memlog_flush(log); + if ((log->flags & MLNOAUTOFLUSH) == 0) + memlog_flush(log); log->offset = 0; + log->iflags = MLWRAPPED; } spinlock_release(&log->lock); } @@ -173,6 +175,17 @@ MEMLOG *log; spinlock_release(&memlock); } +/** + * Set the flags for a memlog + * + * @param log The memlog to set the flags for + * @param flags The new flags values + */ +void +memlog_set(MEMLOG *log, unsigned int flags) +{ + log->flags = flags; +} /** * Flush a memory log to disk @@ -181,7 +194,7 @@ MEMLOG *log; * * @param log The memory log to flush */ -static void +void memlog_flush(MEMLOG *log) { FILE *fp; @@ -189,23 +202,53 @@ int i; if ((fp = fopen(log->name, "a")) == NULL) return; - for (i = 0; i < log->offset; i++) + if ((log->flags & MLNOAUTOFLUSH) && (log->iflags & MLWRAPPED)) { - switch (log->type) + for (i = 0; i < log->size; i++) { - case ML_INT: - fprintf(fp, "%d\n", ((int *)(log->values))[i]); - break; - case ML_LONG: - fprintf(fp, "%ld\n", ((long *)(log->values))[i]); - break; - case ML_LONGLONG: - fprintf(fp, "%lld\n", ((long long *)(log->values))[i]); - break; - case ML_STRING: - fprintf(fp, "%s\n", ((char **)(log->values))[i]); - break; + int ind = (i + log->offset) % log->size; + switch (log->type) + { + case ML_INT: + fprintf(fp, "%d\n", + ((int *)(log->values))[ind]); + break; + case ML_LONG: + fprintf(fp, "%ld\n", + ((long *)(log->values))[ind]); + break; + case ML_LONGLONG: + fprintf(fp, "%lld\n", + ((long long *)(log->values))[ind]); + break; + case ML_STRING: + fprintf(fp, "%s\n", + ((char **)(log->values))[ind]); + break; + } } } + else + { + for (i = 0; i < log->offset; i++) + { + switch (log->type) + { + case ML_INT: + fprintf(fp, "%d\n", ((int *)(log->values))[i]); + break; + case ML_LONG: + fprintf(fp, "%ld\n", ((long *)(log->values))[i]); + break; + case ML_LONGLONG: + fprintf(fp, "%lld\n", ((long long *)(log->values))[i]); + break; + case ML_STRING: + fprintf(fp, "%s\n", ((char **)(log->values))[i]); + break; + } + } + } + log->offset = 0; fclose(fp); } diff --git a/server/include/memlog.h b/server/include/memlog.h index 032348e38..de183a48d 100644 --- a/server/include/memlog.h +++ b/server/include/memlog.h @@ -40,12 +40,26 @@ typedef struct memlog { int offset; int size; MEMLOGTYPE type; + unsigned int flags; + unsigned int iflags; struct memlog *next; } MEMLOG; +/* + * MEMLOG flag bits + */ +#define MLNOAUTOFLUSH 0x0001 + +/* + * MEMLOG internal flags + */ +#define MLWRAPPED 0x0001 + extern MEMLOG *memlog_create(char *, MEMLOGTYPE, int); extern void memlog_destroy(MEMLOG *); +extern void memlog_set(MEMLOG *, unsigned int); extern void memlog_log(MEMLOG *, void *); extern void memlog_flush_all(); +extern void memlog_flush(MEMLOG *); #endif From fe0e7c74d050c33104efb3302eca04d4529a87f1 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Tue, 14 Oct 2014 11:43:08 +0100 Subject: [PATCH 11/22] Resolve transition from catchup to follow mode. --- server/modules/include/blr.h | 14 +- server/modules/routing/binlog/blr.c | 8 + server/modules/routing/binlog/blr_file.c | 160 +++++++++++++++++--- server/modules/routing/binlog/blr_master.c | 163 +++++++++++---------- server/modules/routing/binlog/blr_slave.c | 144 ++++++++++-------- 5 files changed, 325 insertions(+), 164 deletions(-) diff --git a/server/modules/include/blr.h b/server/modules/include/blr.h index 84240675e..8715e1e13 100644 --- a/server/modules/include/blr.h +++ b/server/modules/include/blr.h @@ -33,6 +33,8 @@ #include #include +#include + #define BINLOG_FNAMELEN 16 #define BLR_PROTOCOL "MySQLBackend" #define BINLOG_MAGIC { 0xfe, 0x62, 0x69, 0x6e } @@ -43,8 +45,6 @@ #define BLR_STATS_FREQ 60 #define BLR_NSTATS_MINUTES 30 -#define QUEUE_SLAVE 1 - /** * High and Low water marks for the slave dcb. These values can be overriden * by the router options highwater and lowwater. @@ -166,6 +166,7 @@ typedef struct router_slave { *router; /*< Pointer to the owning router */ struct router_slave *next; SLAVE_STATS stats; /*< Slave statistics */ + MEMLOG *clog; #if defined(SS_DEBUG) skygw_chk_t rses_chk_tail; #endif @@ -245,6 +246,8 @@ typedef struct router_instance { int binlog_fd; /*< File descriptor of the binlog * file being written */ + uint64_t last_written; /*< Position of last event written */ + char prevbinlog[BINLOG_FNAMELEN+1]; BLFILE *files; /*< Files used by the slaves */ SPINLOCK fileslock; /*< Lock for the files queue above */ unsigned int low_water; /*< Low water mark for client DCB */ @@ -291,11 +294,12 @@ static char *blrm_states[] = { "Unconnected", "Authenticated", "Timestamp retrie #define BLRS_UNREGISTERED 0x0001 #define BLRS_REGISTERED 0x0002 #define BLRS_DUMPING 0x0003 +#define BLRS_ERRORED 0x0004 -#define BLRS_MAXSTATE 0x0003 +#define BLRS_MAXSTATE 0x0004 static char *blrs_states[] = { "Created", "Unregistered", "Registered", - "Sending binlogs" }; + "Sending binlogs", "Errored" }; /** * Slave catch-up status @@ -406,6 +410,6 @@ extern void blr_write_binlog_record(ROUTER_INSTANCE *, REP_HEADER *,uint8_t *); extern void blr_file_rotate(ROUTER_INSTANCE *, char *, uint64_t); extern void blr_file_flush(ROUTER_INSTANCE *); extern BLFILE *blr_open_binlog(ROUTER_INSTANCE *, char *); -extern GWBUF *blr_read_binlog(BLFILE *, unsigned int, REP_HEADER *); +extern GWBUF *blr_read_binlog(ROUTER_INSTANCE *, BLFILE *, unsigned int, REP_HEADER *); extern void blr_close_binlog(ROUTER_INSTANCE *, BLFILE *); #endif diff --git a/server/modules/routing/binlog/blr.c b/server/modules/routing/binlog/blr.c index d9659ddd2..c088c89d8 100644 --- a/server/modules/routing/binlog/blr.c +++ b/server/modules/routing/binlog/blr.c @@ -382,6 +382,14 @@ ROUTER_SLAVE *slave; slave->dcb = session->client; slave->router = inst; slave->file = NULL; + strcpy(slave->binlogfile, "unassigned"); + { + char buf[1000]; + sprintf(buf, "Slave History %x", slave); + slave->clog = memlog_create(buf, ML_INT, 2000); + if (slave->clog) + memlog_set(slave->clog, MLNOAUTOFLUSH); + } /** * Add this session to the list of active sessions. diff --git a/server/modules/routing/binlog/blr_file.c b/server/modules/routing/binlog/blr_file.c index 8bab32fae..1ef52968a 100644 --- a/server/modules/routing/binlog/blr_file.c +++ b/server/modules/routing/binlog/blr_file.c @@ -56,6 +56,7 @@ extern int lm_enabled_logfiles_bitmask; static void blr_file_create(ROUTER_INSTANCE *router, char *file); static void blr_file_append(ROUTER_INSTANCE *router, char *file); static uint32_t extract_field(uint8_t *src, int bits); +static void blr_log_header(logfile_id_t file, char *msg, uint8_t *ptr); /** * Initialise the binlog file for this instance. MaxScale will look @@ -163,7 +164,7 @@ unsigned char magic[] = BINLOG_MAGIC; else { LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to create binlog file %s\n", path))); + "Failed to create binlog file %s", path))); } fsync(fd); close(router->binlog_fd); @@ -192,7 +193,7 @@ int fd; if ((fd = open(path, O_RDWR|O_APPEND, 0666)) == -1) { LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to open binlog file %s for append.\n", + "Failed to open binlog file %s for append.", path))); return; } @@ -215,6 +216,7 @@ blr_write_binlog_record(ROUTER_INSTANCE *router, REP_HEADER *hdr, uint8_t *buf) { pwrite(router->binlog_fd, buf, hdr->event_size, hdr->next_pos - hdr->event_size); router->binlog_position = hdr->next_pos; + router->last_written = hdr->next_pos - hdr->event_size; } /** @@ -270,7 +272,7 @@ BLFILE *file; if ((file->fd = open(path, O_RDONLY, 0666)) == -1) { LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to open binlog file %s\n", path))); + "Failed to open binlog file %s", path))); free(file); spinlock_release(&router->fileslock); return NULL; @@ -286,18 +288,38 @@ BLFILE *file; /** * Read a replication event into a GWBUF structure. * - * @param file File record - * @param pos Position of binlog record to read - * @param hdr Binlog header to populate - * @return The binlog record wrapped in a GWBUF structure + * @param router The router instance + * @param file File record + * @param pos Position of binlog record to read + * @param hdr Binlog header to populate + * @return The binlog record wrapped in a GWBUF structure */ GWBUF * -blr_read_binlog(BLFILE *file, unsigned int pos, REP_HEADER *hdr) +blr_read_binlog(ROUTER_INSTANCE *router, BLFILE *file, unsigned int pos, REP_HEADER *hdr) { uint8_t hdbuf[19]; GWBUF *result; unsigned char *data; int n; +unsigned long filelen = 0; +struct stat statb; + + if (fstat(file->fd, &statb) == 0) + filelen = statb.st_size; + if (pos >= filelen) + { + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Attempting to read off the end of the binlog file %s, " + "event at %lu.", file->binlogname, pos))); + return NULL; + } + + if (strcmp(router->binlog_name, file->binlogname) == 0 && + pos >= router->binlog_position) + { + return NULL; + } + /* Read the header information from the file */ if ((n = pread(file->fd, hdbuf, 19, pos)) != 19) @@ -306,20 +328,25 @@ int n; { case 0: LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, - "Reached end of binlog file at %d.\n", + "Reached end of binlog file at %d.", pos))); break; case -1: LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Failed to read binlog file %s at position %d" - " (%s).\n", file->binlogname, + " (%s).", file->binlogname, pos, strerror(errno)))); + if (errno == EBADF) + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Bad file descriptor in read binlog for file %s" + ", reference count is %d, descriptor %d.", + file->binlogname, file->refcnt, file->fd))); break; default: LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Short read when reading the header. " - "Expected 19 bytes got %d bytes." - "Binlog file is %s, position %d\n", + "Expected 19 bytes but got %d bytes. " + "Binlog file is %s, position %d", file->binlogname, pos, n))); break; } @@ -328,14 +355,73 @@ int n; hdr->timestamp = EXTRACT32(hdbuf); hdr->event_type = hdbuf[4]; hdr->serverid = EXTRACT32(&hdbuf[5]); - hdr->event_size = EXTRACT32(&hdbuf[9]); + hdr->event_size = extract_field(&hdbuf[9], 32); hdr->next_pos = EXTRACT32(&hdbuf[13]); hdr->flags = EXTRACT16(&hdbuf[17]); + if (hdr->next_pos < pos && hdr->event_type != ROTATE_EVENT) + { + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Next position in header appears to be incorrect " + "rereading event header at pos %ul in file %s, " + "file size is %ul. Master will write %ul in %s next.", + pos, file->binlogname, filelen, router->binlog_position, + router->binlog_name))); + if ((n = pread(file->fd, hdbuf, 19, pos)) != 19) + { + switch (n) + { + case 0: + LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, + "Reached end of binlog file at %d.", + pos))); + break; + case -1: + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Failed to read binlog file %s at position %d" + " (%s).", file->binlogname, + pos, strerror(errno)))); + if (errno == EBADF) + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Bad file descriptor in read binlog for file %s" + ", reference count is %d, descriptor %d.", + file->binlogname, file->refcnt, file->fd))); + break; + default: + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Short read when reading the header. " + "Expected 19 bytes but got %d bytes. " + "Binlog file is %s, position %d", + file->binlogname, pos, n))); + break; + } + return NULL; + } + hdr->timestamp = EXTRACT32(hdbuf); + hdr->event_type = hdbuf[4]; + hdr->serverid = EXTRACT32(&hdbuf[5]); + hdr->event_size = extract_field(&hdbuf[9], 32); + hdr->next_pos = EXTRACT32(&hdbuf[13]); + hdr->flags = EXTRACT16(&hdbuf[17]); + + if (hdr->next_pos < pos && hdr->event_type != ROTATE_EVENT) + { + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Next position still incorrect after " + "rereading"))); + return NULL; + } + else + { + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Next position corrected by " + "rereading"))); + } + } if ((result = gwbuf_alloc(hdr->event_size)) == NULL) { LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Failed to allocate memory for binlog entry, " - "size %d at %d.\n", + "size %d at %d.", hdr->event_size, pos))); return NULL; } @@ -344,10 +430,29 @@ int n; if ((n = pread(file->fd, &data[19], hdr->event_size - 19, pos + 19)) != hdr->event_size - 19) // Read the balance { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Short read when reading the event at %d. " - "Expected %d bytes got %d bytes.\n", - pos, n))); + if (n == -1) + { + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Error reading the event at %ld in %s. " + "%s, expected %d bytes.", + pos, file->binlogname, + strerror(errno), hdr->event_size - 19))); + } + else + { + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Short read when reading the event at %ld in %s. " + "Expected %d bytes got %d bytes.", + pos, file->binlogname, hdr->event_size - 19, n))); + if (filelen != 0 && filelen - pos < hdr->event_size) + { + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Binlog event is close to the end of the binlog file, " + "current file size is %u.", + filelen))); + } + blr_log_header(LOGFILE_ERROR, "Possible malformed event header", hdbuf); + } gwbuf_consume(result, hdr->event_size); return NULL; } @@ -372,7 +477,7 @@ blr_close_binlog(ROUTER_INSTANCE *router, BLFILE *file) { spinlock_acquire(&router->fileslock); if (router->files == file) - router->files = file; + router->files = file->next; else { BLFILE *ptr = router->files; @@ -384,8 +489,11 @@ blr_close_binlog(ROUTER_INSTANCE *router, BLFILE *file) spinlock_release(&router->fileslock); close(file->fd); + file->fd = -1; } spinlock_release(&file->lock); + if (file->refcnt == 0) + free(file); } /** @@ -407,3 +515,17 @@ uint32_t rval = 0, shift = 0; } return rval; } + +static void +blr_log_header(logfile_id_t file, char *msg, uint8_t *ptr) +{ +char buf[400], *bufp; +int i; + + bufp = buf; + bufp += sprintf(bufp, "%s: ", msg); + for (i = 0; i < 19; i++) + bufp += sprintf(bufp, "0x%02x ", ptr[i]); + skygw_log_write_flush(file, "%s", buf); + +} diff --git a/server/modules/routing/binlog/blr_master.c b/server/modules/routing/binlog/blr_master.c index 395d10ba3..6d1d7edfd 100644 --- a/server/modules/routing/binlog/blr_master.c +++ b/server/modules/routing/binlog/blr_master.c @@ -93,7 +93,7 @@ GWBUF *buf; if ((client = dcb_alloc(DCB_ROLE_INTERNAL)) == NULL) { LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Binlog router: failed to create DCB for dummy client\n"))); + "Binlog router: failed to create DCB for dummy client"))); return; } router->client = client; @@ -101,14 +101,14 @@ GWBUF *buf; if ((router->session = session_alloc(router->service, client)) == NULL) { LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Binlog router: failed to create session for connection to master\n"))); + "Binlog router: failed to create session for connection to master"))); return; } client->session = router->session; if ((router->master = dcb_connect(router->service->databases, router->session, BLR_PROTOCOL)) == NULL) { LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, - "Binlog router: failed to connect to master server '%s'\n", + "Binlog router: failed to connect to master server '%s'", router->service->databases->unique_name))); return; } @@ -219,7 +219,7 @@ char query[128]; if (router->master_state < 0 || router->master_state > BLRM_MAXSTATE) { LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, "Invalid master state machine state (%d) for binlog router.\n", + LOGFILE_ERROR, "Invalid master state machine state (%d) for binlog router.", router->master_state))); gwbuf_consume(buf, gwbuf_length(buf)); spinlock_acquire(&router->lock); @@ -241,7 +241,7 @@ char query[128]; { LOGIF(LE, (skygw_log_write( LOGFILE_ERROR, - "Received error: %d, %s from master during %s phase of the master state machine.\n", + "Received error: %d, %s from master during %s phase of the master state machine.", MYSQL_ERROR_CODE(buf), MYSQL_ERROR_MSG(buf), blrm_states[router->master_state] ))); gwbuf_consume(buf, gwbuf_length(buf)); @@ -552,7 +552,7 @@ static REP_HEADER phdr; LOGIF(LE,(skygw_log_write( LOGFILE_ERROR, "Insufficient memory to buffer event " - "of %d bytes. Binlog %s @ %d\n.", + "of %d bytes. Binlog %s @ %d.", len, router->binlog_name, router->binlog_position))); break; @@ -577,7 +577,7 @@ static REP_HEADER phdr; LOGFILE_ERROR, "Expected entire message in buffer " "chain, but failed to create complete " - "message as expected. %s @ %d\n", + "message as expected. %s @ %d", router->binlog_name, router->binlog_position))); free(msg); @@ -598,7 +598,7 @@ static REP_HEADER phdr; router->stats.n_residuals++; LOGIF(LD,(skygw_log_write( LOGFILE_DEBUG, - "Residual data left after %d records. %s @ %d\n", + "Residual data left after %d records. %s @ %d", router->stats.n_binlogs, router->binlog_name, router->binlog_position))); break; @@ -650,7 +650,7 @@ static REP_HEADER phdr; // #define SHOW_EVENTS #ifdef SHOW_EVENTS - printf("blr: event type 0x%02x, flags 0x%04x, event size %d\n", hdr.event_type, hdr.flags, hdr.event_size); + printf("blr: event type 0x%02x, flags 0x%04x, event size %d", hdr.event_type, hdr.flags, hdr.event_size); #endif if (hdr.event_type >= 0 && hdr.event_type < 0x24) router->stats.events[hdr.event_type]++; @@ -659,7 +659,7 @@ static REP_HEADER phdr; // Fake format description message LOGIF(LD,(skygw_log_write(LOGFILE_DEBUG, "Replication fake event. " - "Binlog %s @ %d.\n", + "Binlog %s @ %d.", router->binlog_name, router->binlog_position))); router->stats.n_fakeevents++; @@ -688,7 +688,7 @@ static REP_HEADER phdr; LOGIF(LD,(skygw_log_write( LOGFILE_DEBUG, "Replication heartbeat. " - "Binlog %s @ %d.\n", + "Binlog %s @ %d.", router->binlog_name, router->binlog_position))); router->stats.n_heartbeats++; @@ -712,7 +712,7 @@ static REP_HEADER phdr; "Artificial event not written " "to disk or distributed. " "Type 0x%x, Length %d, Binlog " - "%s @ %d\n.", + "%s @ %d.", hdr.event_type, hdr.event_size, router->binlog_name, @@ -729,7 +729,7 @@ static REP_HEADER phdr; { printf("Binlog router error: %s\n", &ptr[7]); LOGIF(LE,(skygw_log_write(LOGFILE_ERROR, - "Error packet in binlog stream.%s @ %d\n.", + "Error packet in binlog stream.%s @ %d.", router->binlog_name, router->binlog_position))); blr_log_packet(LOGFILE_ERROR, "Error Packet:", @@ -846,6 +846,7 @@ char file[BINLOG_FNAMELEN+1]; printf("New file: %s @ %ld\n", file, pos); #endif + strcpy(router->prevbinlog, router->binlog_name); if (strncmp(router->binlog_name, file, slen) != 0) { router->stats.n_rotates++; @@ -905,18 +906,22 @@ int action; continue; } spinlock_acquire(&slave->catch_lock); - if ((slave->cstate & (CS_UPTODATE|CS_DIST)) == CS_UPTODATE) + if ((slave->cstate & (CS_UPTODATE|CS_BUSY)) == CS_UPTODATE) { - /* Slave is up to date with the binlog and no distribute is - * running on this slave. + /* + * This slave is reporting it is to date with the binlog of the + * master running on this slave. + * It has no thread running currently that is sending binlog + * events. */ action = 1; - slave->cstate |= CS_DIST; + slave->cstate |= CS_BUSY; } - else if ((slave->cstate & (CS_UPTODATE|CS_DIST)) == (CS_UPTODATE|CS_DIST)) + else if ((slave->cstate & (CS_UPTODATE|CS_BUSY)) == (CS_UPTODATE|CS_BUSY)) { - /* Slave is up to date with the binlog and a distribute is - * running on this slave. + /* + * The slave is up to date with the binlog and a process is + * running on this slave to send binlog events. */ slave->overrun = 1; action = 2; @@ -928,12 +933,20 @@ int action; } slave->stats.n_actions[action-1]++; spinlock_release(&slave->catch_lock); + if (action == 1) { - if ((slave->binlog_pos == hdr->next_pos - hdr->event_size) - && (strcmp(slave->binlogfile, router->binlog_name) == 0 || - hdr->event_type == ROTATE_EVENT)) + if (slave->binlog_pos == router->last_written && + (strcmp(slave->binlogfile, router->binlog_name) == 0 || + (hdr->event_type == ROTATE_EVENT && + strcmp(slave->binlogfile, router->prevbinlog)))) { + /* + * The slave should be up to date, check that the binlog + * position matches the event we have to distribute or this + * is a rotate event. Send the event directly from memory to + * the slave. + */ pkt = gwbuf_alloc(hdr->event_size + 5); buf = GWBUF_DATA(pkt); encode_value(buf, hdr->event_size + 1, 24); @@ -955,84 +968,82 @@ int action; { slave->stats.n_overrun++; slave->overrun = 0; -#if QUEUE_SLAVE poll_fake_write_event(slave->dcb); -#else - spinlock_release(&router->lock); - slave->cstate &= ~(CS_UPTODATE|CS_DIST); - spinlock_release(&slave->catch_lock); - blr_slave_catchup(router, slave, false); - spinlock_acquire(&router->lock); - slave = router->slaves; - if (slave) - continue; - else - break; -#endif } else { - slave->cstate &= ~CS_DIST; + slave->cstate &= ~CS_BUSY; } spinlock_release(&slave->catch_lock); } else if ((slave->binlog_pos > hdr->next_pos - hdr->event_size) && strcmp(slave->binlogfile, router->binlog_name) == 0) { + /* + * The slave is ahead of the master, this should never + * happen. Force the slave to catchup mode in order to + * try to resolve the issue. + */ LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "Slave %d is ahead of expected position %s@%d. " "Expected position %d", slave->serverid, slave->binlogfile, slave->binlog_pos, hdr->next_pos - hdr->event_size))); + spinlock_acquire(&slave->catch_lock); + slave->cstate &= ~(CS_UPTODATE|CS_BUSY); + slave->cstate |= CS_EXPECTCB; + spinlock_release(&slave->catch_lock); + memlog_log(slave->clog, 22); + memlog_flush(slave->clog); + poll_fake_write_event(slave->dcb); } - else if ((hdr->event_type != ROTATE_EVENT) - && (slave->binlog_pos != hdr->next_pos - hdr->event_size || - strcmp(slave->binlogfile, router->binlog_name) != 0)) + else { - /* Check slave is in catchup mode and if not - * force it to go into catchup mode. + /* + * The slave is not at the position it should be. Force it into + * catchup mode rather than send this event. */ - if (slave->cstate & CS_UPTODATE) - { -#if QUEUE_SLAVE - poll_fake_write_event(slave->dcb); -#else - nextslave = slave->next; - spinlock_release(&router->lock); - LOGIF(LD, (skygw_log_write_flush(LOGFILE_DEBUG, - "Force slave %d into catchup mode %s@%d\n", - slave->serverid, slave->binlogfile, - slave->binlog_pos))); - spinlock_acquire(&slave->catch_lock); - slave->cstate &= ~(CS_UPTODATE|CS_DIST); - spinlock_release(&slave->catch_lock); - blr_slave_catchup(router, slave, false); - spinlock_acquire(&router->lock); - slave = router->slaves; - if (slave) - { - while (slave && slave != nextslave) - slave = slave->next; - if (slave) - continue; - else - break; - } - else - { - break; - } -#endif - } + spinlock_acquire(&slave->catch_lock); + slave->cstate &= ~(CS_UPTODATE|CS_BUSY); + slave->cstate |= CS_EXPECTCB; + spinlock_release(&slave->catch_lock); + memlog_log(slave->clog, 21); + memlog_flush(slave->clog); + poll_fake_write_event(slave->dcb); } } + else if (action == 3) + { + /* Slave is not up to date + * Check if it is either expecting a callback or + * is busy processing a callback + */ + spinlock_acquire(&slave->catch_lock); + if ((slave->cstate & (CS_EXPECTCB|CS_BUSY)) == 0) + { + slave->cstate |= CS_EXPECTCB; + spinlock_release(&slave->catch_lock); + memlog_log(slave->clog, 20); + poll_fake_write_event(slave->dcb); + } + else + spinlock_release(&slave->catch_lock); + } slave = slave->next; } spinlock_release(&router->lock); } +/** + * Write a raw event (the first 40 bytes at most) to a log file + * + * @param file The logfile to write to + * @param msg A textual message to write before the packet + * @param ptr Pointer to the message buffer + * @param len Length of message packet + */ static void blr_log_packet(logfile_id_t file, char *msg, uint8_t *ptr, int len) { @@ -1044,8 +1055,8 @@ int i; for (i = 0; i < len && i < 40; i++) bufp += sprintf(bufp, "0x%02x ", ptr[i]); if (i < len) - skygw_log_write_flush(file, "%s...\n", buf); + skygw_log_write_flush(file, "%s...", buf); else - skygw_log_write_flush(file, "%s\n", buf); + skygw_log_write_flush(file, "%s", buf); } diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index d7c691892..487661596 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -88,7 +88,7 @@ blr_slave_request(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue) if (slave->state < 0 || slave->state > BLRS_MAXSTATE) { LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, "Invalid slave state machine state (%d) for binlog router.\n", + LOGFILE_ERROR, "Invalid slave state machine state (%d) for binlog router.", slave->state))); gwbuf_consume(queue, gwbuf_length(queue)); return 0; @@ -108,13 +108,13 @@ blr_slave_request(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, GWBUF *queue) break; case COM_QUIT: LOGIF(LD, (skygw_log_write(LOGFILE_DEBUG, - "COM_QUIT received from slave with server_id %d\n", + "COM_QUIT received from slave with server_id %d", slave->serverid))); break; default: LOGIF(LE, (skygw_log_write( LOGFILE_ERROR, - "Unexpected MySQL Command (%d) received from slave\n", + "Unexpected MySQL Command (%d) received from slave", MYSQL_COMMAND(queue)))); break; } @@ -165,7 +165,7 @@ int query_len; query_text = strndup(qtext, query_len); LOGIF(LT, (skygw_log_write( - LOGFILE_TRACE, "Execute statement from the slave '%s'\n", query_text))); + LOGFILE_TRACE, "Execute statement from the slave '%s'", query_text))); /* * Implement a very rudimental "parsing" of the query text by extarcting the * words from the statement and matchng them against the subset of queries we @@ -268,7 +268,7 @@ int query_len; query_text = strndup(qtext, query_len); LOGIF(LE, (skygw_log_write( - LOGFILE_ERROR, "Unexpected query from slave server %s\n", query_text))); + LOGFILE_ERROR, "Unexpected query from slave server %s", query_text))); free(query_text); blr_slave_send_error(router, slave, "Unexpected SQL query received from slave."); return 0; @@ -299,7 +299,7 @@ GWBUF *clone; else { LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Failed to clone server response to send to slave.\n"))); + "Failed to clone server response to send to slave."))); return 0; } } @@ -485,7 +485,7 @@ uint32_t chksum; { LOGIF(LE, (skygw_log_write( LOGFILE_ERROR, - "blr_slave_binlog_dump expected a COM_BINLOG_DUMP but received %d\n", + "blr_slave_binlog_dump expected a COM_BINLOG_DUMP but received %d", *(ptr-1)))); return 0; } @@ -499,7 +499,6 @@ uint32_t chksum; strncpy(slave->binlogfile, (char *)ptr, binlognamelen); slave->binlogfile[binlognamelen] = 0; - slave->state = BLRS_DUMPING; slave->seqno = 1; if (slave->nocrc) @@ -521,8 +520,8 @@ uint32_t chksum; ptr = blr_build_header(resp, &hdr); encode_value(ptr, slave->binlog_pos, 64); ptr += 8; - memcpy(ptr, slave->binlogfile, BINLOG_FNAMELEN); - ptr += BINLOG_FNAMELEN; + memcpy(ptr, slave->binlogfile, binlognamelen); + ptr += binlognamelen; if (!slave->nocrc) { @@ -568,22 +567,18 @@ uint32_t chksum; slave->dcb->low_water = router->low_water; slave->dcb->high_water = router->high_water; -// dcb_add_callback(slave->dcb, DCB_REASON_LOW_WATER, blr_slave_callback, slave); dcb_add_callback(slave->dcb, DCB_REASON_DRAINED, blr_slave_callback, slave); + slave->state = BLRS_DUMPING; if (slave->binlog_pos != router->binlog_position || strcmp(slave->binlogfile, router->binlog_name) != 0) { spinlock_acquire(&slave->catch_lock); slave->cstate &= ~CS_UPTODATE; + slave->cstate |= CS_EXPECTCB; spinlock_release(&slave->catch_lock); -#if QUEUE_SLAVE poll_fake_write_event(slave->dcb); -#else - rval = blr_slave_catchup(router, slave, true); -#endif } - return rval; } @@ -705,34 +700,14 @@ unsigned long beat; else burst = router->short_burst; spinlock_acquire(&slave->catch_lock); -#if QUEUE_SLAVE if (slave->cstate & CS_BUSY) + { + spinlock_release(&slave->catch_lock); + memlog_log(slave->clog, 1); return 0; - slave->cstate = CS_BUSY; - spinlock_release(&slave->catch_lock); -#else - while ((slave->cstate & (CS_HOLD|CS_BUSY)) == (CS_HOLD|CS_BUSY)) - { - spinlock_release(&slave->catch_lock); - req.tv_sec = 0; - req.tv_nsec = 100; - nanosleep(&req, NULL); - spinlock_acquire(&slave->catch_lock); - } - if (slave->cstate & CS_BUSY) - { - spinlock_release(&slave->catch_lock); -if (hkheartbeat - beat > 5) LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Long wait in blr_salve_catchup %ld00ms with %s burst, return without write records.\n", -hkheartbeat - beat, large ? "long" : "short"))); - return; } slave->cstate |= CS_BUSY; spinlock_release(&slave->catch_lock); -if (hkheartbeat - beat > 5) LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Long wait in blr_slave_catchup %ld00ms with %s burst.\n", -hkheartbeat - beat, large ? "long" : "short"))); -#endif if (slave->file == NULL) { @@ -740,21 +715,18 @@ hkheartbeat - beat, large ? "long" : "short"))); { LOGIF(LE, (skygw_log_write( LOGFILE_ERROR, - "blr_slave_catchup failed to open binlog file %s\n", + "blr_slave_catchup failed to open binlog file %s", slave->binlogfile))); + slave->cstate &= ~CS_BUSY; + slave->state = BLRS_ERRORED; + memlog_log(slave->clog, 2); return 0; } } slave->stats.n_bursts++; while (burst-- && - (record = blr_read_binlog(slave->file, slave->binlog_pos, &hdr)) != NULL) + (record = blr_read_binlog(router, slave->file, slave->binlog_pos, &hdr)) != NULL) { -#if QUEUE_SLAVE -#else - spinlock_acquire(&slave->catch_lock); - slave->cstate &= ~CS_HOLD; - spinlock_release(&slave->catch_lock); -#endif head = gwbuf_alloc(5); ptr = GWBUF_DATA(head); encode_value(ptr, hdr.event_size + 1, 24); @@ -770,8 +742,9 @@ hkheartbeat - beat, large ? "long" : "short"))); { LOGIF(LE, (skygw_log_write( LOGFILE_ERROR, - "blr_slave_catchup failed to open binlog file %s\n", + "blr_slave_catchup failed to open binlog file %s", slave->binlogfile))); + slave->state = BLRS_ERRORED; break; } } @@ -782,12 +755,6 @@ hkheartbeat - beat, large ? "long" : "short"))); } rval = written; slave->stats.n_events++; -#if QUEUE_SLAVE -#else - spinlock_acquire(&slave->catch_lock); - slave->cstate |= CS_HOLD; - spinlock_release(&slave->catch_lock); -#endif } if (record == NULL) slave->stats.n_failed_read++; @@ -801,23 +768,67 @@ hkheartbeat - beat, large ? "long" : "short"))); spinlock_acquire(&slave->catch_lock); slave->cstate |= CS_EXPECTCB; spinlock_release(&slave->catch_lock); + memlog_log(slave->clog, 3); poll_fake_write_event(slave->dcb); } - else + else if (slave->binlog_pos == router->binlog_position && + strcmp(slave->binlogfile, router->binlog_name) == 0) { int state_change = 0; spinlock_acquire(&slave->catch_lock); - if ((slave->cstate & CS_UPTODATE) == 0) + + /* Now check again since we hold the slave->catch_lock. */ + if (slave->binlog_pos != router->binlog_position || + strcmp(slave->binlogfile, router->binlog_name) != 0) { - slave->stats.n_upd++; - slave->cstate |= CS_UPTODATE; - state_change = 1; + slave->cstate &= ~CS_UPTODATE; + slave->cstate |= CS_EXPECTCB; + memlog_log(slave->clog, 30); + poll_fake_write_event(slave->dcb); + } + else + { + if ((slave->cstate & CS_UPTODATE) == 0) + { + slave->stats.n_upd++; + slave->cstate |= CS_UPTODATE; + state_change = 1; + memlog_log(slave->clog, 4); + } + else + memlog_log(slave->clog, 5); } spinlock_release(&slave->catch_lock); + if (state_change) + { LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, - "blr_slave_catchup slave is up to date %s, %u\n", + "blr_slave_catchup slave is up to date %s, %u.", slave->binlogfile, slave->binlog_pos))); + } + } + else + { + if (strcmp(router->binlog_name, slave->binlogfile) != 0) + { + /* We may have reached the end of file of a non-current + * binlog file. + */ + LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + "Slave reached end of file for binlong file %s " + "which is not the file currently being downloaded.", + slave->binlogfile))); + slave->state = BLRS_ERRORED; + memlog_log(slave->clog, 6); + } + else + { + spinlock_acquire(&slave->catch_lock); + slave->cstate |= CS_EXPECTCB; + spinlock_release(&slave->catch_lock); + memlog_log(slave->clog, 7); + poll_fake_write_event(slave->dcb); + } } return rval; } @@ -840,16 +851,21 @@ ROUTER_INSTANCE *router = slave->router; if (reason == DCB_REASON_DRAINED) { - if (slave->state == BLRS_DUMPING && - (slave->binlog_pos != router->binlog_position - || strcmp(slave->binlogfile, router->binlog_name))) + if (slave->state == BLRS_DUMPING) { spinlock_acquire(&slave->catch_lock); - slave->cstate &= ~CS_UPTODATE; + slave->cstate &= ~(CS_UPTODATE|CS_EXPECTCB); spinlock_release(&slave->catch_lock); slave->stats.n_dcb++; blr_slave_catchup(router, slave, true); } + else + { + LOGIF(LM, (skygw_log_write( + LOGFILE_MESSAGE, "Ignored callback due to slave state %s", + blrs_states[slave->state]))); + memlog_log(slave->clog, 8); + } } if (reason == DCB_REASON_LOW_WATER) From f459bdfe04da1886f7a151f1d340eb8451cb7d54 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Fri, 17 Oct 2014 08:36:32 +0100 Subject: [PATCH 12/22] Add new command to view the event queue Fixes to fake poll events to improve fairness --- server/core/dcb.c | 6 ++++ server/core/poll.c | 54 +++++++++++++++++++++++++++---- server/include/poll.h | 1 + server/modules/routing/debugcmd.c | 5 +++ 4 files changed, 59 insertions(+), 7 deletions(-) diff --git a/server/core/dcb.c b/server/core/dcb.c index 0b2b038e7..8c6c83799 100644 --- a/server/core/dcb.c +++ b/server/core/dcb.c @@ -1389,6 +1389,12 @@ dprintDCB(DCB *pdcb, DCB *dcb) dcb->stats.n_high_water); dcb_printf(pdcb, "\t\tNo. of Low Water Events: %d\n", dcb->stats.n_low_water); + if (DCB_POLL_BUSY(dcb)) + { + dcb_printf(pdcb, "\t\tPending events in the queue: %x %s\n", + dcb->evq.pending_events, dcb->evq.processing ? "(processing)" : ""); + + } if (dcb->flags & DCBF_CLONE) dcb_printf(pdcb, "\t\tDCB is a clone.\n"); #if SPINLOCK_PROFILE diff --git a/server/core/poll.c b/server/core/poll.c index 9bd11c3fb..d4cdde67e 100644 --- a/server/core/poll.c +++ b/server/core/poll.c @@ -1202,15 +1202,24 @@ poll_fake_write_event(DCB *dcb) uint32_t ev = EPOLLOUT; spinlock_acquire(&pollqlock); + /* + * If the DCB is already on the queue, there are no pending events and + * there are other events on the queue, then + * take it off the queue. This stops the DCB hogging the threads. + */ + if (DCB_POLL_BUSY(dcb) && dcb->evq.pending_events == 0 && dcb->evq.prev != dcb) + { + dcb->evq.prev->evq.next = dcb->evq.next; + dcb->evq.next->evq.prev = dcb->evq.prev; + if (eventq == dcb) + eventq = dcb->evq.next; + dcb->evq.next = NULL; + dcb->evq.prev = NULL; + pollStats.evq_length--; + } + if (DCB_POLL_BUSY(dcb)) { - if (dcb->evq.pending_events == 0) - { - pollStats.evq_pending++; -#if PROFILE_POLL - dcb->evq.inserted = hkheartbeat; -#endif - } dcb->evq.pending_events |= ev; } else @@ -1241,3 +1250,34 @@ uint32_t ev = EPOLLOUT; } spinlock_release(&pollqlock); } + +/** + * Print the event queue contents + * + * @param pdcb The DCB to print the event queue to + */ +void +dShowEventQ(DCB *pdcb) +{ +DCB *dcb; +int found = 0; +uint32_t ev; + + spinlock_acquire(&pollqlock); + if (eventq == NULL) + { + /* Nothing to process */ + spinlock_release(&pollqlock); + return 0; + } + dcb = eventq; + dcb_printf(pdcb, "%16s | %10s | %s\n", "DCB", "Status", "Events"); + dcb_printf(pdcb, "-----------------+------------+--------------------\n"); + do { + dcb_printf(pdcb, "%16p | %10s | %s\n", dcb, + dcb->evq.processing ? "Processing" : "Pending", + event_to_string(dcb->evq.pending_events)); + dcb = dcb->evq.next; + } while (dcb != eventq); + spinlock_release(&pollqlock); +} diff --git a/server/include/poll.h b/server/include/poll.h index 6524f1bbb..45959830f 100644 --- a/server/include/poll.h +++ b/server/include/poll.h @@ -42,4 +42,5 @@ extern void poll_shutdown(); extern GWBITMASK *poll_bitmask(); extern void dprintPollStats(DCB *); extern void dShowThreads(DCB *dcb); +extern void dShowEventQ(DCB *dcb); #endif diff --git a/server/modules/routing/debugcmd.c b/server/modules/routing/debugcmd.c index f238e16e6..86c18389e 100644 --- a/server/modules/routing/debugcmd.c +++ b/server/modules/routing/debugcmd.c @@ -41,6 +41,7 @@ * than simply addresses * 23/05/14 Mark Riddoch Added support for developer and user modes * 29/05/14 Mark Riddoch Add Filter support + * 16/10/14 Mark Riddoch Add show eventq * * @endverbatim */ @@ -116,6 +117,10 @@ struct subcommand showoptions[] = { "Show the poll statistics", "Show the poll statistics", {0, 0, 0} }, + { "eventq", 0, dShowEventQ, + "Show the queue of events waiting to be processed", + "Show the queue of events waiting to be processed", + {0, 0, 0} }, { "filter", 1, dprintFilter, "Show details of a filter, called with a filter name", "Show details of a filter, called with the address of a filter", From 9b3dfc86fe6e8bb980dd7f2f5d740a6c92616b7f Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Fri, 17 Oct 2014 08:38:58 +0100 Subject: [PATCH 13/22] Binlog router performance improvements --- server/modules/include/blr.h | 2 ++ server/modules/routing/binlog/blr.c | 12 +++++++++--- server/modules/routing/binlog/blr_file.c | 8 +++++++- server/modules/routing/binlog/blr_master.c | 20 +++++++++++++++++--- server/modules/routing/binlog/blr_slave.c | 14 ++++++++++++-- 5 files changed, 47 insertions(+), 9 deletions(-) diff --git a/server/modules/include/blr.h b/server/modules/include/blr.h index 8715e1e13..1e0b3de5d 100644 --- a/server/modules/include/blr.h +++ b/server/modules/include/blr.h @@ -239,6 +239,7 @@ typedef struct router_instance { GWBUF *residual; /*< Any residual binlog event */ MASTER_RESPONSES saved_master; /*< Saved master responses */ char *binlogdir; /*< The directory with the binlog files */ + SPINLOCK binlog_lock; /*< Lock to control update of the binlog position */ char binlog_name[BINLOG_FNAMELEN+1]; /*< Name of the current binlog file */ uint64_t binlog_position; @@ -248,6 +249,7 @@ typedef struct router_instance { */ uint64_t last_written; /*< Position of last event written */ char prevbinlog[BINLOG_FNAMELEN+1]; + int rotating; /*< Rotation in progress flag */ BLFILE *files; /*< Files used by the slaves */ SPINLOCK fileslock; /*< Lock for the files queue above */ unsigned int low_water; /*< Low water mark for client DCB */ diff --git a/server/modules/routing/binlog/blr.c b/server/modules/routing/binlog/blr.c index c088c89d8..ce1860aac 100644 --- a/server/modules/routing/binlog/blr.c +++ b/server/modules/routing/binlog/blr.c @@ -174,6 +174,7 @@ int i; spinlock_init(&inst->lock); inst->files = NULL; spinlock_init(&inst->fileslock); + spinlock_init(&inst->binlog_lock); inst->binlog_fd = -1; @@ -305,6 +306,7 @@ int i; inst->active_logs = 0; inst->reconnect_pending = 0; inst->handling_threads = 0; + inst->rotating = 0; inst->residual = NULL; inst->slaves = NULL; inst->next = NULL; @@ -679,6 +681,8 @@ struct tm tm; spinlock_stats(&instlock, spin_reporter, dcb); dcb_printf(dcb, "\tSpinlock statistics (instance lock):\n"); spinlock_stats(&router_inst->lock, spin_reporter, dcb); + dcb_printf(dcb, "\tSpinlock statistics (binlog position lock):\n"); + spinlock_stats(&router_inst->binlog_lock, spin_reporter, dcb); #endif if (router_inst->slaves) @@ -743,9 +747,11 @@ struct tm tm; dcb_printf(dcb, "\t\tNo. of distribute action 3 %u\n", session->stats.n_actions[2]); if ((session->cstate & CS_UPTODATE) == 0) { - dcb_printf(dcb, "\t\tSlave is in catchup mode. %s\n", - ((session->cstate & CS_EXPECTCB) == 0 ? "" : - "Waiting for DCB queue to drain.")); + dcb_printf(dcb, "\t\tSlave is in catchup mode. %s%s\n", + ((session->cstate & CS_EXPECTCB) == 0 ? "" : + "Waiting for DCB queue to drain."), + ((session->cstate & CS_BUSY) == 0 ? "" : + " Busy in slave catchup.")); } else diff --git a/server/modules/routing/binlog/blr_file.c b/server/modules/routing/binlog/blr_file.c index 1ef52968a..5c4f81cb3 100644 --- a/server/modules/routing/binlog/blr_file.c +++ b/server/modules/routing/binlog/blr_file.c @@ -168,8 +168,10 @@ unsigned char magic[] = BINLOG_MAGIC; } fsync(fd); close(router->binlog_fd); + spinlock_acquire(&router->binlog_lock); strcpy(router->binlog_name, file); router->binlog_position = 4; /* Initial position after the magic number */ + spinlock_release(&router->binlog_lock); router->binlog_fd = fd; } @@ -199,8 +201,10 @@ int fd; } fsync(fd); close(router->binlog_fd); + spinlock_acquire(&router->binlog_lock); strcpy(router->binlog_name, file); router->binlog_position = lseek(fd, 0L, SEEK_END); + spinlock_release(&router->binlog_lock); router->binlog_fd = fd; } @@ -215,8 +219,10 @@ void blr_write_binlog_record(ROUTER_INSTANCE *router, REP_HEADER *hdr, uint8_t *buf) { pwrite(router->binlog_fd, buf, hdr->event_size, hdr->next_pos - hdr->event_size); + spinlock_acquire(&router->binlog_lock); router->binlog_position = hdr->next_pos; router->last_written = hdr->next_pos - hdr->event_size; + spinlock_release(&router->binlog_lock); } /** @@ -308,7 +314,7 @@ struct stat statb; filelen = statb.st_size; if (pos >= filelen) { - LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, + LOGIF(LD, (skygw_log_write(LOGFILE_ERROR, "Attempting to read off the end of the binlog file %s, " "event at %lu.", file->binlogname, pos))); return NULL; diff --git a/server/modules/routing/binlog/blr_master.c b/server/modules/routing/binlog/blr_master.c index 6d1d7edfd..241364373 100644 --- a/server/modules/routing/binlog/blr_master.c +++ b/server/modules/routing/binlog/blr_master.c @@ -695,6 +695,7 @@ static REP_HEADER phdr; } else if (hdr.flags != LOG_EVENT_ARTIFICIAL_F) { + router->rotating = 1; ptr = ptr + 5; // We don't put the first byte of the payload // into the binlog file blr_write_binlog_record(router, &hdr, ptr); @@ -717,6 +718,7 @@ static REP_HEADER phdr; hdr.event_size, router->binlog_name, router->binlog_position))); + router->rotating = 1; ptr += 5; if (hdr.event_type == ROTATE_EVENT) { @@ -852,6 +854,7 @@ char file[BINLOG_FNAMELEN+1]; router->stats.n_rotates++; blr_file_rotate(router, file, pos); } + router->rotating = 0; } /** @@ -943,9 +946,9 @@ int action; { /* * The slave should be up to date, check that the binlog - * position matches the event we have to distribute or this - * is a rotate event. Send the event directly from memory to - * the slave. + * position matches the event we have to distribute or + * this is a rotate event. Send the event directly from + * memory to the slave. */ pkt = gwbuf_alloc(hdr->event_size + 5); buf = GWBUF_DATA(pkt); @@ -976,6 +979,17 @@ int action; } spinlock_release(&slave->catch_lock); } + else if (slave->binlog_pos == hdr->next_pos + && strcmp(slave->binlogfile, router->binlog_name) == 0) + { + /* + * Slave has already read record from file, no + * need to distrbute this event + */ + spinlock_acquire(&slave->catch_lock); + slave->cstate &= ~CS_BUSY; + spinlock_release(&slave->catch_lock); + } else if ((slave->binlog_pos > hdr->next_pos - hdr->event_size) && strcmp(slave->binlogfile, router->binlog_name) == 0) { diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index 487661596..880d2879f 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -775,9 +775,13 @@ unsigned long beat; strcmp(slave->binlogfile, router->binlog_name) == 0) { int state_change = 0; + spinlock_acquire(&router->binlog_lock); spinlock_acquire(&slave->catch_lock); - /* Now check again since we hold the slave->catch_lock. */ + /* + * Now check again since we hold the router->binlog_lock + * and slave->catch_lock. + */ if (slave->binlog_pos != router->binlog_position || strcmp(slave->binlogfile, router->binlog_name) != 0) { @@ -799,6 +803,7 @@ unsigned long beat; memlog_log(slave->clog, 5); } spinlock_release(&slave->catch_lock); + spinlock_release(&router->binlog_lock); if (state_change) { @@ -809,10 +814,15 @@ unsigned long beat; } else { - if (strcmp(router->binlog_name, slave->binlogfile) != 0) + if (router->rotating != 0 && strcmp(router->binlog_name, slave->binlogfile) != 0) { /* We may have reached the end of file of a non-current * binlog file. + * + * Note if the master is rotating there is a window during + * whch the rotate event has been written to the old binlog + * but the new binlog file has not yet been created. Therefore + * we ignore these issues during the rotate processing. */ LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, "Slave reached end of file for binlong file %s " From 81b5ad76a23c3fa6aedccfbcde78426ac37d9940 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Fri, 17 Oct 2014 08:40:06 +0100 Subject: [PATCH 14/22] Deal with ._ files --- rabbitmq_consumer/inih/._LICENSE.txt | Bin 212 -> 0 bytes rabbitmq_consumer/inih/._README.txt | Bin 212 -> 0 bytes rabbitmq_consumer/inih/._cpp | Bin 212 -> 0 bytes rabbitmq_consumer/inih/._examples | Bin 212 -> 0 bytes rabbitmq_consumer/inih/._extra | Bin 212 -> 0 bytes rabbitmq_consumer/inih/._ini.c | Bin 212 -> 0 bytes rabbitmq_consumer/inih/._ini.h | Bin 212 -> 0 bytes rabbitmq_consumer/inih/._tests | Bin 212 -> 0 bytes rabbitmq_consumer/inih/cpp/._INIReader.cpp | Bin 212 -> 0 bytes rabbitmq_consumer/inih/cpp/._INIReader.h | Bin 212 -> 0 bytes rabbitmq_consumer/inih/cpp/._INIReaderTest.cpp | Bin 212 -> 0 bytes rabbitmq_consumer/inih/examples/._config.def | Bin 212 -> 0 bytes rabbitmq_consumer/inih/examples/._ini_dump.c | Bin 212 -> 0 bytes rabbitmq_consumer/inih/examples/._ini_example.c | Bin 212 -> 0 bytes rabbitmq_consumer/inih/examples/._ini_xmacros.c | Bin 212 -> 0 bytes rabbitmq_consumer/inih/examples/._test.ini | Bin 212 -> 0 bytes rabbitmq_consumer/inih/extra/._Makefile.static | Bin 212 -> 0 bytes rabbitmq_consumer/inih/tests/._bad_comment.ini | Bin 212 -> 0 bytes rabbitmq_consumer/inih/tests/._bad_multi.ini | Bin 212 -> 0 bytes rabbitmq_consumer/inih/tests/._bad_section.ini | Bin 212 -> 0 bytes rabbitmq_consumer/inih/tests/._baseline_multi.txt | Bin 212 -> 0 bytes .../inih/tests/._baseline_single.txt | Bin 212 -> 0 bytes rabbitmq_consumer/inih/tests/._bom.ini | Bin 212 -> 0 bytes rabbitmq_consumer/inih/tests/._multi_line.ini | Bin 212 -> 0 bytes rabbitmq_consumer/inih/tests/._normal.ini | Bin 212 -> 0 bytes rabbitmq_consumer/inih/tests/._unittest.bat | Bin 212 -> 0 bytes rabbitmq_consumer/inih/tests/._unittest.c | Bin 212 -> 0 bytes rabbitmq_consumer/inih/tests/._user_error.ini | Bin 212 -> 0 bytes server/inih/._LICENSE.txt | Bin 212 -> 0 bytes server/inih/._README.txt | Bin 212 -> 0 bytes server/inih/._cpp | Bin 212 -> 0 bytes server/inih/._examples | Bin 212 -> 0 bytes server/inih/._extra | Bin 212 -> 0 bytes server/inih/._ini.c | Bin 212 -> 0 bytes server/inih/._ini.h | Bin 212 -> 0 bytes server/inih/._tests | Bin 212 -> 0 bytes server/inih/cpp/._INIReader.cpp | Bin 212 -> 0 bytes server/inih/cpp/._INIReader.h | Bin 212 -> 0 bytes server/inih/cpp/._INIReaderTest.cpp | Bin 212 -> 0 bytes server/inih/examples/._config.def | Bin 212 -> 0 bytes server/inih/examples/._ini_dump.c | Bin 212 -> 0 bytes server/inih/examples/._ini_example.c | Bin 212 -> 0 bytes server/inih/examples/._ini_xmacros.c | Bin 212 -> 0 bytes server/inih/examples/._test.ini | Bin 212 -> 0 bytes server/inih/extra/._Makefile.static | Bin 212 -> 0 bytes server/inih/tests/._bad_comment.ini | Bin 212 -> 0 bytes server/inih/tests/._bad_multi.ini | Bin 212 -> 0 bytes server/inih/tests/._bad_section.ini | Bin 212 -> 0 bytes server/inih/tests/._baseline_multi.txt | Bin 212 -> 0 bytes server/inih/tests/._baseline_single.txt | Bin 212 -> 0 bytes server/inih/tests/._bom.ini | Bin 212 -> 0 bytes server/inih/tests/._multi_line.ini | Bin 212 -> 0 bytes server/inih/tests/._normal.ini | Bin 212 -> 0 bytes server/inih/tests/._unittest.bat | Bin 212 -> 0 bytes server/inih/tests/._unittest.c | Bin 212 -> 0 bytes server/inih/tests/._user_error.ini | Bin 212 -> 0 bytes 56 files changed, 0 insertions(+), 0 deletions(-) delete mode 100755 rabbitmq_consumer/inih/._LICENSE.txt delete mode 100755 rabbitmq_consumer/inih/._README.txt delete mode 100755 rabbitmq_consumer/inih/._cpp delete mode 100755 rabbitmq_consumer/inih/._examples delete mode 100755 rabbitmq_consumer/inih/._extra delete mode 100755 rabbitmq_consumer/inih/._ini.c delete mode 100755 rabbitmq_consumer/inih/._ini.h delete mode 100755 rabbitmq_consumer/inih/._tests delete mode 100755 rabbitmq_consumer/inih/cpp/._INIReader.cpp delete mode 100755 rabbitmq_consumer/inih/cpp/._INIReader.h delete mode 100755 rabbitmq_consumer/inih/cpp/._INIReaderTest.cpp delete mode 100755 rabbitmq_consumer/inih/examples/._config.def delete mode 100755 rabbitmq_consumer/inih/examples/._ini_dump.c delete mode 100755 rabbitmq_consumer/inih/examples/._ini_example.c delete mode 100755 rabbitmq_consumer/inih/examples/._ini_xmacros.c delete mode 100755 rabbitmq_consumer/inih/examples/._test.ini delete mode 100755 rabbitmq_consumer/inih/extra/._Makefile.static delete mode 100755 rabbitmq_consumer/inih/tests/._bad_comment.ini delete mode 100755 rabbitmq_consumer/inih/tests/._bad_multi.ini delete mode 100755 rabbitmq_consumer/inih/tests/._bad_section.ini delete mode 100755 rabbitmq_consumer/inih/tests/._baseline_multi.txt delete mode 100755 rabbitmq_consumer/inih/tests/._baseline_single.txt delete mode 100755 rabbitmq_consumer/inih/tests/._bom.ini delete mode 100755 rabbitmq_consumer/inih/tests/._multi_line.ini delete mode 100755 rabbitmq_consumer/inih/tests/._normal.ini delete mode 100755 rabbitmq_consumer/inih/tests/._unittest.bat delete mode 100755 rabbitmq_consumer/inih/tests/._unittest.c delete mode 100755 rabbitmq_consumer/inih/tests/._user_error.ini delete mode 100755 server/inih/._LICENSE.txt delete mode 100755 server/inih/._README.txt delete mode 100755 server/inih/._cpp delete mode 100755 server/inih/._examples delete mode 100755 server/inih/._extra delete mode 100755 server/inih/._ini.c delete mode 100755 server/inih/._ini.h delete mode 100755 server/inih/._tests delete mode 100755 server/inih/cpp/._INIReader.cpp delete mode 100755 server/inih/cpp/._INIReader.h delete mode 100755 server/inih/cpp/._INIReaderTest.cpp delete mode 100755 server/inih/examples/._config.def delete mode 100755 server/inih/examples/._ini_dump.c delete mode 100755 server/inih/examples/._ini_example.c delete mode 100755 server/inih/examples/._ini_xmacros.c delete mode 100755 server/inih/examples/._test.ini delete mode 100755 server/inih/extra/._Makefile.static delete mode 100755 server/inih/tests/._bad_comment.ini delete mode 100755 server/inih/tests/._bad_multi.ini delete mode 100755 server/inih/tests/._bad_section.ini delete mode 100755 server/inih/tests/._baseline_multi.txt delete mode 100755 server/inih/tests/._baseline_single.txt delete mode 100755 server/inih/tests/._bom.ini delete mode 100755 server/inih/tests/._multi_line.ini delete mode 100755 server/inih/tests/._normal.ini delete mode 100755 server/inih/tests/._unittest.bat delete mode 100755 server/inih/tests/._unittest.c delete mode 100755 server/inih/tests/._user_error.ini diff --git a/rabbitmq_consumer/inih/._LICENSE.txt b/rabbitmq_consumer/inih/._LICENSE.txt deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/._README.txt b/rabbitmq_consumer/inih/._README.txt deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/._cpp b/rabbitmq_consumer/inih/._cpp deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/._examples b/rabbitmq_consumer/inih/._examples deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/._extra b/rabbitmq_consumer/inih/._extra deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/._ini.c b/rabbitmq_consumer/inih/._ini.c deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/._ini.h b/rabbitmq_consumer/inih/._ini.h deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/._tests b/rabbitmq_consumer/inih/._tests deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/cpp/._INIReader.cpp b/rabbitmq_consumer/inih/cpp/._INIReader.cpp deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/cpp/._INIReader.h b/rabbitmq_consumer/inih/cpp/._INIReader.h deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/cpp/._INIReaderTest.cpp b/rabbitmq_consumer/inih/cpp/._INIReaderTest.cpp deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/examples/._config.def b/rabbitmq_consumer/inih/examples/._config.def deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/examples/._ini_dump.c b/rabbitmq_consumer/inih/examples/._ini_dump.c deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/examples/._ini_example.c b/rabbitmq_consumer/inih/examples/._ini_example.c deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/examples/._ini_xmacros.c b/rabbitmq_consumer/inih/examples/._ini_xmacros.c deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/examples/._test.ini b/rabbitmq_consumer/inih/examples/._test.ini deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/extra/._Makefile.static b/rabbitmq_consumer/inih/extra/._Makefile.static deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/rabbitmq_consumer/inih/tests/._bad_comment.ini b/rabbitmq_consumer/inih/tests/._bad_comment.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/tests/._bad_multi.ini b/rabbitmq_consumer/inih/tests/._bad_multi.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/tests/._bad_section.ini b/rabbitmq_consumer/inih/tests/._bad_section.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/tests/._baseline_multi.txt b/rabbitmq_consumer/inih/tests/._baseline_multi.txt deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/tests/._baseline_single.txt b/rabbitmq_consumer/inih/tests/._baseline_single.txt deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/tests/._bom.ini b/rabbitmq_consumer/inih/tests/._bom.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/tests/._multi_line.ini b/rabbitmq_consumer/inih/tests/._multi_line.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/tests/._normal.ini b/rabbitmq_consumer/inih/tests/._normal.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/tests/._unittest.bat b/rabbitmq_consumer/inih/tests/._unittest.bat deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/tests/._unittest.c b/rabbitmq_consumer/inih/tests/._unittest.c deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/rabbitmq_consumer/inih/tests/._user_error.ini b/rabbitmq_consumer/inih/tests/._user_error.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/._LICENSE.txt b/server/inih/._LICENSE.txt deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/._README.txt b/server/inih/._README.txt deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/._cpp b/server/inih/._cpp deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/._examples b/server/inih/._examples deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/._extra b/server/inih/._extra deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/._ini.c b/server/inih/._ini.c deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/._ini.h b/server/inih/._ini.h deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/._tests b/server/inih/._tests deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/cpp/._INIReader.cpp b/server/inih/cpp/._INIReader.cpp deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/cpp/._INIReader.h b/server/inih/cpp/._INIReader.h deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/cpp/._INIReaderTest.cpp b/server/inih/cpp/._INIReaderTest.cpp deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/examples/._config.def b/server/inih/examples/._config.def deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/examples/._ini_dump.c b/server/inih/examples/._ini_dump.c deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/examples/._ini_example.c b/server/inih/examples/._ini_example.c deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/examples/._ini_xmacros.c b/server/inih/examples/._ini_xmacros.c deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/examples/._test.ini b/server/inih/examples/._test.ini deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/extra/._Makefile.static b/server/inih/extra/._Makefile.static deleted file mode 100755 index 17b8574a41eb3852d574972f6f70e928759648f5..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>*z*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=y(A720f diff --git a/server/inih/tests/._bad_comment.ini b/server/inih/tests/._bad_comment.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/tests/._bad_multi.ini b/server/inih/tests/._bad_multi.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/tests/._bad_section.ini b/server/inih/tests/._bad_section.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/tests/._baseline_multi.txt b/server/inih/tests/._baseline_multi.txt deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/tests/._baseline_single.txt b/server/inih/tests/._baseline_single.txt deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/tests/._bom.ini b/server/inih/tests/._bom.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/tests/._multi_line.ini b/server/inih/tests/._multi_line.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/tests/._normal.ini b/server/inih/tests/._normal.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/tests/._unittest.bat b/server/inih/tests/._unittest.bat deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/tests/._unittest.c b/server/inih/tests/._unittest.c deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g diff --git a/server/inih/tests/._user_error.ini b/server/inih/tests/._user_error.ini deleted file mode 100755 index 7fa6eb8a60820e42dc1aba46a86861309c18c3db..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 212 zcmZQz6=P>$Vqox1Ojhs@R)|o50+1L3Cj$e65d#CmA_fL9{|W<9z%e8w2&xdIV+I2Q zgAJ4qqZk<&7@*>!$@#f@i3J5Ysd|N_iA9NdC7F4t42Ajz1_nmfriRHThQ>)|*1?Hs tiA9;#u4b;5mS(0dx-Nz;uDT}9j?TK4=7tu!hNdP?PDaj#W=>8{3;=zSA7B6g From 2edab598b2cd07ba5a97fdced1a4774150399b06 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Fri, 17 Oct 2014 11:14:10 +0100 Subject: [PATCH 15/22] Remove memlog diagnostics used to find issues with transistion between catchup and follow mode. --- server/modules/routing/binlog/blr.c | 7 ------- server/modules/routing/binlog/blr_master.c | 5 ----- server/modules/routing/binlog/blr_slave.c | 10 ---------- 3 files changed, 22 deletions(-) diff --git a/server/modules/routing/binlog/blr.c b/server/modules/routing/binlog/blr.c index ce1860aac..c232a4825 100644 --- a/server/modules/routing/binlog/blr.c +++ b/server/modules/routing/binlog/blr.c @@ -385,13 +385,6 @@ ROUTER_SLAVE *slave; slave->router = inst; slave->file = NULL; strcpy(slave->binlogfile, "unassigned"); - { - char buf[1000]; - sprintf(buf, "Slave History %x", slave); - slave->clog = memlog_create(buf, ML_INT, 2000); - if (slave->clog) - memlog_set(slave->clog, MLNOAUTOFLUSH); - } /** * Add this session to the list of active sessions. diff --git a/server/modules/routing/binlog/blr_master.c b/server/modules/routing/binlog/blr_master.c index 241364373..25f9c0ac0 100644 --- a/server/modules/routing/binlog/blr_master.c +++ b/server/modules/routing/binlog/blr_master.c @@ -1008,8 +1008,6 @@ int action; slave->cstate &= ~(CS_UPTODATE|CS_BUSY); slave->cstate |= CS_EXPECTCB; spinlock_release(&slave->catch_lock); - memlog_log(slave->clog, 22); - memlog_flush(slave->clog); poll_fake_write_event(slave->dcb); } else @@ -1022,8 +1020,6 @@ int action; slave->cstate &= ~(CS_UPTODATE|CS_BUSY); slave->cstate |= CS_EXPECTCB; spinlock_release(&slave->catch_lock); - memlog_log(slave->clog, 21); - memlog_flush(slave->clog); poll_fake_write_event(slave->dcb); } } @@ -1038,7 +1034,6 @@ int action; { slave->cstate |= CS_EXPECTCB; spinlock_release(&slave->catch_lock); - memlog_log(slave->clog, 20); poll_fake_write_event(slave->dcb); } else diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index 880d2879f..72346e972 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -703,7 +703,6 @@ unsigned long beat; if (slave->cstate & CS_BUSY) { spinlock_release(&slave->catch_lock); - memlog_log(slave->clog, 1); return 0; } slave->cstate |= CS_BUSY; @@ -719,7 +718,6 @@ unsigned long beat; slave->binlogfile))); slave->cstate &= ~CS_BUSY; slave->state = BLRS_ERRORED; - memlog_log(slave->clog, 2); return 0; } } @@ -768,7 +766,6 @@ unsigned long beat; spinlock_acquire(&slave->catch_lock); slave->cstate |= CS_EXPECTCB; spinlock_release(&slave->catch_lock); - memlog_log(slave->clog, 3); poll_fake_write_event(slave->dcb); } else if (slave->binlog_pos == router->binlog_position && @@ -787,7 +784,6 @@ unsigned long beat; { slave->cstate &= ~CS_UPTODATE; slave->cstate |= CS_EXPECTCB; - memlog_log(slave->clog, 30); poll_fake_write_event(slave->dcb); } else @@ -797,10 +793,7 @@ unsigned long beat; slave->stats.n_upd++; slave->cstate |= CS_UPTODATE; state_change = 1; - memlog_log(slave->clog, 4); } - else - memlog_log(slave->clog, 5); } spinlock_release(&slave->catch_lock); spinlock_release(&router->binlog_lock); @@ -829,14 +822,12 @@ unsigned long beat; "which is not the file currently being downloaded.", slave->binlogfile))); slave->state = BLRS_ERRORED; - memlog_log(slave->clog, 6); } else { spinlock_acquire(&slave->catch_lock); slave->cstate |= CS_EXPECTCB; spinlock_release(&slave->catch_lock); - memlog_log(slave->clog, 7); poll_fake_write_event(slave->dcb); } } @@ -874,7 +865,6 @@ ROUTER_INSTANCE *router = slave->router; LOGIF(LM, (skygw_log_write( LOGFILE_MESSAGE, "Ignored callback due to slave state %s", blrs_states[slave->state]))); - memlog_log(slave->clog, 8); } } From e729a17fd43b8277c95c7e68b92bb01f4c1d4235 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Fri, 17 Oct 2014 12:28:27 +0100 Subject: [PATCH 16/22] Addition of new tuning parameters for epoll spins and wait time --- server/core/config.c | 42 +++++++++++++++++++- server/core/poll.c | 66 +++++++++++++++++++++++++++---- server/include/config.h | 7 ++++ server/include/dcb.h | 14 ++++--- server/include/poll.h | 3 +- server/modules/routing/debugcmd.c | 47 ++++++++++++++++++++++ 6 files changed, 162 insertions(+), 17 deletions(-) diff --git a/server/core/config.c b/server/core/config.c index 995e0e0f4..2da468e7e 100644 --- a/server/core/config.c +++ b/server/core/config.c @@ -1106,6 +1106,31 @@ config_threadcount() return gateway.n_threads; } +/** + * Return the number of non-blocking polls to be done before a blocking poll + * is issued. + * + * @return The number of blocking poll calls to make before a blocking call + */ +unsigned int +config_nbpolls() +{ + return gateway.n_nbpoll; +} + +/** + * Return the configured number of milliseconds for which we wait when we do + * a blocking poll call. + * + * @return The number of milliseconds to sleep in a blocking poll call + */ +unsigned int +config_pollsleep() +{ + return gateway.pollsleep; +} + + static struct { char *logname; logfile_id_t logfile; @@ -1126,9 +1151,20 @@ static int handle_global_item(const char *name, const char *value) { int i; - if (strcmp(name, "threads") == 0) { + if (strcmp(name, "threads") == 0) + { gateway.n_threads = atoi(value); - } else { + } + else if (strcmp(name, "non_blocking_polls") == 0) + { + gateway.n_nbpoll = atoi(value); + } + else if (strcmp(name, "poll_sleep") == 0) + { + gateway.pollsleep = atoi(value); + } + else + { for (i = 0; lognames[i].logname; i++) { if (strcasecmp(name, lognames[i].logname) == 0) @@ -1150,6 +1186,8 @@ static void global_defaults() { gateway.n_threads = 1; + gateway.n_nbpoll = DEFAULT_NBPOLLS; + gateway.pollsleep = DEFAULT_POLLSLEEP; if (version_string != NULL) gateway.version_string = strdup(version_string); else diff --git a/server/core/poll.c b/server/core/poll.c index d4cdde67e..991ef49e3 100644 --- a/server/core/poll.c +++ b/server/core/poll.c @@ -44,6 +44,9 @@ MEMLOG *plog; extern int lm_enabled_logfiles_bitmask; +int number_poll_spins; +int max_poll_sleep; + /** * @file poll.c - Abstraction of the epoll functionality * @@ -70,7 +73,7 @@ extern int lm_enabled_logfiles_bitmask; /** * Control the use of mutexes for the epoll_wait call. Setting to 1 will * cause the epoll_wait calls to be moved under a mutex. This may be useful - * for debuggign purposes but should be avoided in general use. + * for debugging purposes but should be avoided in general use. */ #define MUTEX_EPOLL 0 @@ -151,6 +154,7 @@ static struct { int evq_pending; /*< Number of pending descriptors in event queue */ int evq_max; /*< Maximum event queue length */ int wake_evqpending;/*< Woken from epoll_wait with pending events in queue */ + int blockingpolls; /*< Number of epoll_waits with a timeout specified */ } pollStats; /** @@ -204,6 +208,9 @@ int i; for (i = 0; i < n_avg_samples; i++) evqp_samples[i] = 0.0; + number_poll_spins = config_nbpolls(); + max_poll_sleep = config_pollsleep(); + #if PROFILE_POLL plog = memlog_create("EventQueueWaitTime", ML_LONG, 10000); #endif @@ -370,7 +377,7 @@ return_rc: * deschedule a process if a timeout is included, but will not do this if a 0 timeout * value is given. this improves performance when the gateway is under heavy load. * - * In order to provide a fairer means of sharign the threads between the different + * In order to provide a fairer means of sharing the threads between the different * DCB's the poll mechanism has been decoupled from the processing of the events. * The events are now recieved via the epoll_wait call, a queue of DCB's that have * events pending is maintained and as new events arrive the DCB is added to the end @@ -383,7 +390,7 @@ return_rc: * * The introduction of the ability to inject "fake" write events into the event queue meant * that there was a possibility to "starve" new events sicne the polling loop would - * consume the event queue before lookign for new events. If the DCB that inject + * consume the event queue before looking for new events. If the DCB that inject * the fake event then injected another fake event as a result of the first it meant * that new events did not get added to the queue. The strategy has been updated to * not consume the entire event queue, but process one event before doing a non-blocking @@ -407,6 +414,7 @@ struct epoll_event events[MAX_EVENTS]; int i, nfds, timeout_bias = 1; int thread_id = (int)arg; DCB *zombies = NULL; +int poll_spins = 0; /** Add this thread to the bitmask of running polling threads */ bitmask_set(&poll_mask, thread_id); @@ -460,14 +468,18 @@ DCB *zombies = NULL; * We calculate a timeout bias to alter the length of the blocking * call based on the time since we last received an event to process */ - else if (nfds == 0 && pollStats.evq_pending > 0) + else if (nfds == 0 && pollStats.evq_pending == 0 && poll_spins++ > number_poll_spins) { + atomic_add(&pollStats.blockingpolls, 1); nfds = epoll_wait(epoll_fd, events, MAX_EVENTS, - (EPOLL_TIMEOUT * timeout_bias) / 10); + (max_poll_sleep * timeout_bias) / 10); if (nfds == 0 && pollStats.evq_pending) + { atomic_add(&pollStats.wake_evqpending, 1); + poll_spins = 0; + } } else { @@ -483,6 +495,7 @@ DCB *zombies = NULL; if (nfds > 0) { timeout_bias = 1; + poll_spins = 0; LOGIF(LD, (skygw_log_write( LOGFILE_DEBUG, "%lu [poll_waitevents] epoll_wait found %d fds", @@ -598,6 +611,34 @@ DCB *zombies = NULL; } /*< while(1) */ } +/** + * Set the number of non-blocking poll cycles that will be done before + * a blocking poll will take place. Whenever an event arrives on a thread + * or the thread sees a pending event to execute it will reset it's + * poll_spin coutn to zero and will then poll with a 0 timeout until the + * poll_spin value is greater than the value set here. + * + * @param nbpolls Number of non-block polls to perform before blocking + */ +void +poll_set_nonblocking_polls(unsigned int nbpolls) +{ + number_poll_spins = nbpolls; +} + +/** + * Set the maximum amount of time, in milliseconds, the polling thread + * will block before it will wake and check the event queue for work + * that may have been added by another thread. + * + * @param maxwait Maximum wait time in milliseconds + */ +void +poll_set_maxwait(unsigned int maxwait) +{ + max_poll_sleep = maxwait; +} + /** * Process of the queue of DCB's that have outstanding events * @@ -654,6 +695,7 @@ uint32_t ev; if (found) { ev = dcb->evq.pending_events; + dcb->evq.processing_events = ev; dcb->evq.pending_events = 0; pollStats.evq_pending--; } @@ -869,6 +911,8 @@ uint32_t ev; #endif spinlock_acquire(&pollqlock); + dcb->evq.processing_events = 0; + if (dcb->evq.pending_events == 0) { /* No pending events so remove from the queue */ @@ -963,6 +1007,8 @@ int i; dcb_printf(dcb, "Number of epoll cycles: %d\n", pollStats.n_polls); + dcb_printf(dcb, "Number of epoll cycles with wait: %d\n", + pollStats.blockingpolls); dcb_printf(dcb, "Number of read events: %d\n", pollStats.n_read); dcb_printf(dcb, "Number of write events: %d\n", @@ -1220,6 +1266,8 @@ uint32_t ev = EPOLLOUT; if (DCB_POLL_BUSY(dcb)) { + if (dcb->evq.pending_events == 0) + pollStats.evq_pending++; dcb->evq.pending_events |= ev; } else @@ -1271,11 +1319,13 @@ uint32_t ev; return 0; } dcb = eventq; - dcb_printf(pdcb, "%16s | %10s | %s\n", "DCB", "Status", "Events"); - dcb_printf(pdcb, "-----------------+------------+--------------------\n"); + dcb_printf(pdcb, "%-16s | %-10s | %-18s | %s\n", "DCB", "Status", "Processing Events", + "Pending Events"); + dcb_printf(pdcb, "-----------------+------------+--------------------+-------------------\n"); do { - dcb_printf(pdcb, "%16p | %10s | %s\n", dcb, + dcb_printf(pdcb, "%-16p | %-10s | %-18s | %-18s\n", dcb, dcb->evq.processing ? "Processing" : "Pending", + event_to_string(dcb->evq.processing_events), event_to_string(dcb->evq.pending_events)); dcb = dcb->evq.next; } while (dcb != eventq); diff --git a/server/include/config.h b/server/include/config.h index 659fb6378..6e8e9dffb 100644 --- a/server/include/config.h +++ b/server/include/config.h @@ -29,10 +29,13 @@ * 21/06/13 Mark Riddoch Initial implementation * 07/05/14 Massimiliano Pinto Added version_string to global configuration * 23/05/14 Massimiliano Pinto Added id to global configuration + * 17/10/14 Mark Riddoch Added poll tuning configuration parameters * * @endverbatim */ +#define DEFAULT_NBPOLLS 3 /**< Default number of non block polls before we block */ +#define DEFAULT_POLLSLEEP 1000 /**< Default poll wait time (milliseconds) */ /** * Maximum length for configuration parameter value. */ @@ -92,11 +95,15 @@ typedef struct { int n_threads; /**< Number of polling threads */ char *version_string; /**< The version string of embedded database library */ unsigned long id; /**< MaxScale ID */ + unsigned int n_nbpoll; /**< Tune number of non-blocking polls */ + unsigned int pollsleep; /**< Wait time in blocking polls */ } GATEWAY_CONF; extern int config_load(char *); extern int config_reload(); extern int config_threadcount(); +extern unsigned int config_nbpolls(); +extern unsigned int config_pollsleep(); CONFIG_PARAMETER* config_get_param(CONFIG_PARAMETER* params, const char* name); config_param_type_t config_get_paramtype(CONFIG_PARAMETER* param); CONFIG_PARAMETER* config_clone_param(CONFIG_PARAMETER* param); diff --git a/server/include/dcb.h b/server/include/dcb.h index 11061bb8f..723838151 100644 --- a/server/include/dcb.h +++ b/server/include/dcb.h @@ -102,17 +102,19 @@ typedef struct gw_protocol { * The event queue structure used in the polling loop to maintain a queue * of events that need to be processed for the DCB. * - * next The next DCB in the event queue - * prev The previous DCB in the event queue - * pending_events The events that are pending processing - * processing Flag to indicate the processing status of the DCB - * eventqlock Spinlock to protect this structure - * inserted Insertion time for logging purposes + * next The next DCB in the event queue + * prev The previous DCB in the event queue + * pending_events The events that are pending processing + * processing_events The evets currently being processed + * processing Flag to indicate the processing status of the DCB + * eventqlock Spinlock to protect this structure + * inserted Insertion time for logging purposes */ typedef struct { struct dcb *next; struct dcb *prev; uint32_t pending_events; + uint32_t processing_events; int processing; SPINLOCK eventqlock; unsigned long inserted; diff --git a/server/include/poll.h b/server/include/poll.h index 45959830f..f4d9f4aa8 100644 --- a/server/include/poll.h +++ b/server/include/poll.h @@ -32,7 +32,6 @@ * @endverbatim */ #define MAX_EVENTS 1000 -#define EPOLL_TIMEOUT 1000 /**< The epoll timeout in milliseconds */ extern void poll_init(); extern int poll_add_dcb(DCB *); @@ -40,6 +39,8 @@ extern int poll_remove_dcb(DCB *); extern void poll_waitevents(void *); extern void poll_shutdown(); extern GWBITMASK *poll_bitmask(); +extern void poll_set_maxwait(unsigned int); +extern void poll_set_nonblocking_polls(unsigned int); extern void dprintPollStats(DCB *); extern void dShowThreads(DCB *dcb); extern void dShowEventQ(DCB *dcb); diff --git a/server/modules/routing/debugcmd.c b/server/modules/routing/debugcmd.c index 86c18389e..2466b606a 100644 --- a/server/modules/routing/debugcmd.c +++ b/server/modules/routing/debugcmd.c @@ -66,6 +66,7 @@ #include #include #include +#include #include #include @@ -81,6 +82,7 @@ #define ARG_TYPE_DCB 7 #define ARG_TYPE_MONITOR 8 #define ARG_TYPE_FILTER 9 +#define ARG_TYPE_NUMERIC 10 /** * The subcommand structure @@ -286,6 +288,8 @@ struct subcommand restartoptions[] = { }; static void set_server(DCB *dcb, SERVER *server, char *bit); +static void set_pollsleep(DCB *dcb, int); +static void set_nbpoll(DCB *dcb, int); /** * The subcommands of the set command */ @@ -294,6 +298,15 @@ struct subcommand setoptions[] = { "Set the status of a server. E.g. set server dbnode4 master", "Set the status of a server. E.g. set server 0x4838320 master", {ARG_TYPE_SERVER, ARG_TYPE_STRING, 0} }, + { "pollsleep", 1, set_pollsleep, + "Set the maximum poll sleep period in milliseconds", + "Set the maximum poll sleep period in milliseconds", + {ARG_TYPE_NUMERIC, 0, 0} }, + { "nbpolls", 1, set_nbpoll, + "Set the number of non-blocking polls", + "Set the number of non-blocking polls", + {ARG_TYPE_NUMERIC, 0, 0} }, + { NULL, 0, NULL, NULL, NULL, {0, 0, 0} } }; @@ -577,6 +590,16 @@ SERVICE *service; if (mode == CLIM_USER || (rval = (unsigned long)strtol(arg, NULL, 0)) == 0) rval = (unsigned long)filter_find(arg); return rval; + case ARG_TYPE_NUMERIC: + { + int i; + for (i = 0; arg[i]; i++) + { + if (arg[i] < '0' || arg[i] > '9') + return 0; + } + return atoi(arg); + } } return 0; } @@ -1117,6 +1140,30 @@ static void disable_log_action(DCB *dcb, char *arg1) { skygw_log_disable(type); } +/** + * Set the duration of the sleep passed to the poll wait + * + * @param dcb DCB for output + * @param sleeptime Sleep time in milliseconds + */ +static void +set_pollsleep(DCB *dcb, int sleeptime) +{ + poll_set_maxwait(sleeptime); +} + +/** + * Set the number of non-blockign spins to make + * + * @param dcb DCB for output + * @param nb Number of spins + */ +static void +set_nbpoll(DCB *dcb, int nb) +{ + poll_set_nonblocking_polls(nb); +} + #if defined(SS_DEBUG) static void fail_backendfd(void) { From 554a054e18beb69e308f3e60fa7990271edf6a5b Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Fri, 17 Oct 2014 12:29:29 +0100 Subject: [PATCH 17/22] Improve logging support --- server/modules/include/blr.h | 1 - server/modules/routing/binlog/blr_slave.c | 19 +++++++++++-------- 2 files changed, 11 insertions(+), 9 deletions(-) diff --git a/server/modules/include/blr.h b/server/modules/include/blr.h index 1e0b3de5d..208e425cd 100644 --- a/server/modules/include/blr.h +++ b/server/modules/include/blr.h @@ -166,7 +166,6 @@ typedef struct router_slave { *router; /*< Pointer to the owning router */ struct router_slave *next; SLAVE_STATS stats; /*< Slave statistics */ - MEMLOG *clog; #if defined(SS_DEBUG) skygw_chk_t rses_chk_tail; #endif diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index 72346e972..57746e485 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -570,6 +570,12 @@ uint32_t chksum; dcb_add_callback(slave->dcb, DCB_REASON_DRAINED, blr_slave_callback, slave); slave->state = BLRS_DUMPING; + LOGIF(LM, (skygw_log_write( + LOGFILE_MESSAGE, + "%s: New slave %s requested binlog file %s from position %lu", + router->service->name, slave->dcb->remote, + slave->binlogfile, slave->binlog_pos))); + if (slave->binlog_pos != router->binlog_position || strcmp(slave->binlogfile, router->binlog_name) != 0) { @@ -689,11 +695,6 @@ GWBUF *head, *record; REP_HEADER hdr; int written, rval = 1, burst; uint8_t *ptr; -struct timespec req; - -extern unsigned long hkheartbeat; -unsigned long beat; - beat = hkheartbeat; if (large) burst = router->long_burst; @@ -801,7 +802,9 @@ unsigned long beat; if (state_change) { LOGIF(LM, (skygw_log_write(LOGFILE_MESSAGE, - "blr_slave_catchup slave is up to date %s, %u.", + "%s: Slave %s is up to date %s, %u.", + router->service->name, + slave->dcb->remote, slave->binlogfile, slave->binlog_pos))); } } @@ -862,8 +865,8 @@ ROUTER_INSTANCE *router = slave->router; } else { - LOGIF(LM, (skygw_log_write( - LOGFILE_MESSAGE, "Ignored callback due to slave state %s", + LOGIF(LD, (skygw_log_write( + LOGFILE_DEBUG, "Ignored callback due to slave state %s", blrs_states[slave->state]))); } } From 932fc5dc2cbbbdf214a29d18ce142a26e1c9dfe0 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Tue, 21 Oct 2014 14:31:05 +0100 Subject: [PATCH 18/22] Resolve issue with icorrectly markign slave connection as errored --- server/modules/include/blr.h | 2 ++ server/modules/routing/binlog/blr.c | 15 ++++++++++++-- server/modules/routing/binlog/blr_file.c | 23 ++++++++++++++++++++++ server/modules/routing/binlog/blr_master.c | 14 +++++++++++++ server/modules/routing/binlog/blr_slave.c | 13 ++++++++---- 5 files changed, 61 insertions(+), 6 deletions(-) diff --git a/server/modules/include/blr.h b/server/modules/include/blr.h index 208e425cd..8b25ea11d 100644 --- a/server/modules/include/blr.h +++ b/server/modules/include/blr.h @@ -400,6 +400,7 @@ static char *blrs_states[] = { "Created", "Unregistered", "Registered", extern void blr_start_master(ROUTER_INSTANCE *); extern void blr_master_response(ROUTER_INSTANCE *, GWBUF *); extern void blr_master_reconnect(ROUTER_INSTANCE *); +extern int blr_master_connected(ROUTER_INSTANCE *); extern int blr_slave_request(ROUTER_INSTANCE *, ROUTER_SLAVE *, GWBUF *); extern void blr_slave_rotate(ROUTER_SLAVE *slave, uint8_t *ptr); @@ -413,4 +414,5 @@ extern void blr_file_flush(ROUTER_INSTANCE *); extern BLFILE *blr_open_binlog(ROUTER_INSTANCE *, char *); extern GWBUF *blr_read_binlog(ROUTER_INSTANCE *, BLFILE *, unsigned int, REP_HEADER *); extern void blr_close_binlog(ROUTER_INSTANCE *, BLFILE *); +extern unsigned long blr_file_size(BLFILE *); #endif diff --git a/server/modules/routing/binlog/blr.c b/server/modules/routing/binlog/blr.c index c232a4825..7bace29ad 100644 --- a/server/modules/routing/binlog/blr.c +++ b/server/modules/routing/binlog/blr.c @@ -809,10 +809,21 @@ static void errorReply(ROUTER *instance, void *router_session, GWBUF *message, DCB *backend_dcb, error_action_t action, bool *succp) { ROUTER_INSTANCE *router = (ROUTER_INSTANCE *)instance; +int error, len; +char msg[85]; + + len = sizeof(error); + if (getsockopt(router->master->fd, SOL_SOCKET, SO_ERROR, &error, &len) != 0) + { + strerror_r(error, msg, 80); + strcat(msg, " "); + } + else + strcpy(msg, ""); LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, "Erorr Reply '%s', attempting reconnect to master", - message))); + LOGFILE_ERROR, "Erorr Reply '%s', %sattempting reconnect to master", + message, msg))); *succp = false; blr_master_reconnect(router); } diff --git a/server/modules/routing/binlog/blr_file.c b/server/modules/routing/binlog/blr_file.c index 5c4f81cb3..f4b2b82c4 100644 --- a/server/modules/routing/binlog/blr_file.c +++ b/server/modules/routing/binlog/blr_file.c @@ -522,6 +522,13 @@ uint32_t rval = 0, shift = 0; return rval; } +/** + * Log the event header of binlog event + * + * @param file The log file into which to write the entry + * @param msg A message strign to preceed the header with + * @param ptr The event header raw data + */ static void blr_log_header(logfile_id_t file, char *msg, uint8_t *ptr) { @@ -535,3 +542,19 @@ int i; skygw_log_write_flush(file, "%s", buf); } + +/** + * Return the size of the current binlog file + * + * @param file The binlog file + * @return The current size of the binlog file + */ +unsigned long +blr_file_size(BLFILE *file) +{ +struct stat statb; + + if (fstat(file->fd, &statb) == 0) + return statb.st_size; + return 0; +} diff --git a/server/modules/routing/binlog/blr_master.c b/server/modules/routing/binlog/blr_master.c index 25f9c0ac0..c50751f7a 100644 --- a/server/modules/routing/binlog/blr_master.c +++ b/server/modules/routing/binlog/blr_master.c @@ -138,6 +138,7 @@ blr_restart_master(ROUTER_INSTANCE *router) GWBUF *ptr; dcb_close(router->master); + dcb_close(router->client); dcb_free(router->master); dcb_free(router->client); @@ -1069,3 +1070,16 @@ int i; skygw_log_write_flush(file, "%s", buf); } + +/** + * Check if the master connection is in place and we + * are downlaoding binlogs + * + * @param router The router instance + * @return non-zero if we are recivign binlog records + */ +int +blr_master_connected(ROUTER_INSTANCE *router) +{ + return router->master_state == BLRM_BINLOGDUMP; +} diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index 57746e485..83c940963 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -810,7 +810,10 @@ uint8_t *ptr; } else { - if (router->rotating != 0 && strcmp(router->binlog_name, slave->binlogfile) != 0) + if (slave->binlog_pos >= blr_file_size(slave->file) + && router->rotating == 0 + && strcmp(router->binlog_name, slave->binlogfile) != 0 + && blr_master_connected(router)) { /* We may have reached the end of file of a non-current * binlog file. @@ -821,9 +824,11 @@ uint8_t *ptr; * we ignore these issues during the rotate processing. */ LOGIF(LE, (skygw_log_write(LOGFILE_ERROR, - "Slave reached end of file for binlong file %s " - "which is not the file currently being downloaded.", - slave->binlogfile))); + "Slave reached end of file for binlong file %s at %u " + "which is not the file currently being downloaded. " + "Master binlog is %s, %lu.", + slave->binlogfile, slave->binlog_pos, + router->binlog_name, router->binlog_position))); slave->state = BLRS_ERRORED; } else From 70672e43a15c3128d53795577d275e6eab9cac2b Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Thu, 23 Oct 2014 10:46:55 +0100 Subject: [PATCH 19/22] Addition of backoff process for master reconnect Housekeeper task display --- server/core/dcb.c | 1 + server/core/housekeeper.c | 99 +++++++++++++++- server/core/poll.c | 37 +++--- server/include/housekeeper.h | 16 +++ server/modules/include/blr.h | 11 ++ server/modules/routing/binlog/blr.c | 39 ++++++- server/modules/routing/binlog/blr_master.c | 18 ++- server/modules/routing/binlog/blr_slave.c | 130 ++++++++++++++++++++- server/modules/routing/debugcmd.c | 5 + 9 files changed, 326 insertions(+), 30 deletions(-) diff --git a/server/core/dcb.c b/server/core/dcb.c index 8c6c83799..25cd5b526 100644 --- a/server/core/dcb.c +++ b/server/core/dcb.c @@ -150,6 +150,7 @@ DCB *rval; rval->low_water = 0; rval->next = NULL; rval->callbacks = NULL; + rval->data = NULL; rval->remote = NULL; rval->user = NULL; diff --git a/server/core/housekeeper.c b/server/core/housekeeper.c index 318ca8fde..7cc3d5f4b 100644 --- a/server/core/housekeeper.c +++ b/server/core/housekeeper.c @@ -24,11 +24,21 @@ /** * @file housekeeper.c Provide a mechanism to run periodic tasks * + * The housekeeper provides a mechanism to allow for tasks, function + * calls basically, to be run on a tiem basis. A task may be run + * repeatedly, with a given frequency (in seconds), or may be a one + * shot task that will only be run once after a specified number of + * seconds. + * + * The housekeeper also maintains a global variable, hkheartbeat, that + * is incremented every 100ms. + * * @verbatim * Revision History * * Date Who Description * 29/08/14 Mark Riddoch Initial implementation + * 22/10/14 Mark Riddoch Addition of one-shot tasks * * @endverbatim */ @@ -70,7 +80,7 @@ hkinit() * @param taskfn The function to call for the task * @param data Data to pass to the task function * @param frequency How often to run the task, expressed in seconds - * @return Return the tiem in seconds when the task will be first run if the task was added, otherwise 0 + * @return Return the time in seconds when the task will be first run if the task was added, otherwise 0 */ int hktask_add(char *name, void (*taskfn)(void *), void *data, int frequency) @@ -89,6 +99,7 @@ HKTASK *task, *ptr; task->task = taskfn; task->data = data; task->frequency = frequency; + task->type = HK_REPEATED; task->nextdue = time(0) + frequency; task->next = NULL; spinlock_acquire(&tasklock); @@ -113,6 +124,61 @@ HKTASK *task, *ptr; return task->nextdue; } +/** + * Add a one-shot task to the housekeeper task list + * + * Task names must be unique. + * + * @param name The unique name for this housekeeper task + * @param taskfn The function to call for the task + * @param data Data to pass to the task function + * @param when How many second until the task is executed + * @return Return the time in seconds when the task will be first run if the task was added, otherwise 0 + * + */ +int +hktask_oneshot(char *name, void (*taskfn)(void *), void *data, int when) +{ +HKTASK *task, *ptr; + + if ((task = (HKTASK *)malloc(sizeof(HKTASK))) == NULL) + { + return 0; + } + if ((task->name = strdup(name)) == NULL) + { + free(task); + return 0; + } + task->task = taskfn; + task->data = data; + task->frequency = 0; + task->type = HK_ONESHOT; + task->nextdue = time(0) + when; + task->next = NULL; + spinlock_acquire(&tasklock); + ptr = tasks; + while (ptr && ptr->next) + { + if (strcmp(ptr->name, name) == 0) + { + spinlock_release(&tasklock); + free(task->name); + free(task); + return 0; + } + ptr = ptr->next; + } + if (ptr) + ptr->next = task; + else + tasks = task; + spinlock_release(&tasklock); + + return task->nextdue; +} + + /** * Remove a named task from the housekeepers task list * @@ -195,6 +261,8 @@ int i; taskdata = ptr->data; spinlock_release(&tasklock); (*taskfn)(taskdata); + if (ptr->type == HK_ONESHOT) + hktask_remove(ptr->name); spinlock_acquire(&tasklock); ptr = tasks; } @@ -214,3 +282,32 @@ hkshutdown() { do_shutdown = 1; } + +/** + * Show the tasks that are scheduled for the house keeper + * + * @param pdcb The DCB to send to output + */ +void +hkshow_tasks(DCB *pdcb) +{ +HKTASK *ptr; +struct tm tm; +char buf[40]; + + dcb_printf(pdcb, "%-25s | Type | Frequency | Next Due\n", "Name"); + dcb_printf(pdcb, "--------------------------+----------+-----------+-----------------------\n"); + spinlock_acquire(&tasklock); + ptr = tasks; + while (ptr) + { + localtime_r(&ptr->nextdue, &tm); + asctime_r(&tm, buf); + dcb_printf(pdcb, "%-25s | %-8s | %-9d | %s", + ptr->name, + ptr->type == HK_REPEATED ? "Repeated" : "One-Shot", + ptr->frequency, + buf); + ptr = ptr->next; + } +} diff --git a/server/core/poll.c b/server/core/poll.c index 991ef49e3..e614c7ba6 100644 --- a/server/core/poll.c +++ b/server/core/poll.c @@ -147,6 +147,8 @@ static struct { int n_hup; /*< Number of hangup events */ int n_accept; /*< Number of accept events */ int n_polls; /*< Number of poll cycles */ + int n_pollev; /*< Number of polls returnign events */ + int n_nbpollev; /*< Number of polls returnign events */ int n_nothreads; /*< Number of times no threads are polling */ int n_fds[MAXNFDS]; /*< Number of wakeups with particular n_fds value */ @@ -446,6 +448,7 @@ int poll_spins = 0; thread_data[thread_id].state = THREAD_POLLING; } + atomic_add(&pollStats.n_polls, 1); if ((nfds = epoll_wait(epoll_fd, events, MAX_EVENTS, 0)) == -1) { atomic_add(&n_waiting, -1); @@ -462,7 +465,7 @@ int poll_spins = 0; } /* * If there are no new descriptors from the non-blocking call - * and nothing to proces on the event queue then for do a + * and nothing to process on the event queue then for do a * blocking call to epoll_wait. * * We calculate a timeout bias to alter the length of the blocking @@ -495,13 +498,15 @@ int poll_spins = 0; if (nfds > 0) { timeout_bias = 1; + if (poll_spins <= number_poll_spins + 1) + atomic_add(&pollStats.n_nbpollev, 1); poll_spins = 0; LOGIF(LD, (skygw_log_write( LOGFILE_DEBUG, "%lu [poll_waitevents] epoll_wait found %d fds", pthread_self(), nfds))); - atomic_add(&pollStats.n_polls, 1); + atomic_add(&pollStats.n_pollev, 1); if (thread_data) { thread_data[thread_id].n_fds = nfds; @@ -1005,29 +1010,33 @@ dprintPollStats(DCB *dcb) { int i; - dcb_printf(dcb, "Number of epoll cycles: %d\n", + dcb_printf(dcb, "No. of epoll cycles: %d\n", pollStats.n_polls); - dcb_printf(dcb, "Number of epoll cycles with wait: %d\n", + dcb_printf(dcb, "No. of epoll cycles with wait: %d\n", pollStats.blockingpolls); - dcb_printf(dcb, "Number of read events: %d\n", + dcb_printf(dcb, "No. of epoll calls returning events: %d\n", + pollStats.n_pollev); + dcb_printf(dcb, "No. of non-blocking calls returning events: %d\n", + pollStats.n_nbpollev); + dcb_printf(dcb, "No. of read events: %d\n", pollStats.n_read); - dcb_printf(dcb, "Number of write events: %d\n", + dcb_printf(dcb, "No. of write events: %d\n", pollStats.n_write); - dcb_printf(dcb, "Number of error events: %d\n", + dcb_printf(dcb, "No. of error events: %d\n", pollStats.n_error); - dcb_printf(dcb, "Number of hangup events: %d\n", + dcb_printf(dcb, "No. of hangup events: %d\n", pollStats.n_hup); - dcb_printf(dcb, "Number of accept events: %d\n", + dcb_printf(dcb, "No. of accept events: %d\n", pollStats.n_accept); - dcb_printf(dcb, "Number of times no threads polling: %d\n", + dcb_printf(dcb, "No. of times no threads polling: %d\n", pollStats.n_nothreads); - dcb_printf(dcb, "Current event queue length: %d\n", + dcb_printf(dcb, "Current event queue length: %d\n", pollStats.evq_length); - dcb_printf(dcb, "Maximum event queue length: %d\n", + dcb_printf(dcb, "Maximum event queue length: %d\n", pollStats.evq_max); - dcb_printf(dcb, "Number of DCBs with pending events: %d\n", + dcb_printf(dcb, "No. of DCBs with pending events: %d\n", pollStats.evq_pending); - dcb_printf(dcb, "Number of wakeups with pending queue: %d\n", + dcb_printf(dcb, "No. of wakeups with pending queue: %d\n", pollStats.wake_evqpending); dcb_printf(dcb, "No of poll completions with descriptors\n"); diff --git a/server/include/housekeeper.h b/server/include/housekeeper.h index 35e76e80d..09d87daaa 100644 --- a/server/include/housekeeper.h +++ b/server/include/housekeeper.h @@ -18,6 +18,7 @@ * Copyright SkySQL Ab 2014 */ #include +#include /** * @file housekeeper.h A mechanism to have task run periodically @@ -31,6 +32,11 @@ * @endverbatim */ +typedef enum { + HK_REPEATED = 1, + HK_ONESHOT +} HKTASK_TYPE; + /** * The housekeeper task list */ @@ -40,12 +46,22 @@ typedef struct hktask { void *data; /*< Data to pass the task */ int frequency; /*< How often to call the tasks (seconds) */ time_t nextdue; /*< When the task should be next run */ + HKTASK_TYPE + type; /*< The task type */ struct hktask *next; /*< Next task in the list */ } HKTASK; +/** + * The global housekeeper heartbeat value. This value is increamente + * every 100ms and may be used for crude timing etc. + */ +extern unsigned long hkheartbeat; + extern void hkinit(); extern int hktask_add(char *name, void (*task)(void *), void *data, int frequency); +extern int hktask_oneshot(char *name, void (*task)(void *), void *data, int when); extern int hktask_remove(char *name); extern void hkshutdown(); +extern void hkshow_tasks(DCB *pdcb); #endif diff --git a/server/modules/include/blr.h b/server/modules/include/blr.h index 8b25ea11d..028e45d26 100644 --- a/server/modules/include/blr.h +++ b/server/modules/include/blr.h @@ -57,7 +57,16 @@ */ #define DEF_SHORT_BURST 15 #define DEF_LONG_BURST 500 +#define DEF_BURST_SIZE 1024000 /* 1 Mb */ +/** + * master reconnect backoff constants + * BLR_MASTER_BACKOFF_TIME The increments of the back off time (seconds) + * BLR_MAX_BACKOFF Maximum number of increments to backoff to + */ + +#define BLR_MASTER_BACKOFF_TIME 5 +#define BLR_MAX_BACKOFF 60 /** * Some useful macros for examining the MySQL Response packets */ @@ -255,9 +264,11 @@ typedef struct router_instance { unsigned int high_water; /*< High water mark for client DCB */ unsigned int short_burst; /*< Short burst for slave catchup */ unsigned int long_burst; /*< Long burst for slave catchup */ + unsigned long burst_size; /*< Maximum size of burst to send */ ROUTER_STATS stats; /*< Statistics for this router */ int active_logs; int reconnect_pending; + int retry_backoff; int handling_threads; struct router_instance *next; diff --git a/server/modules/routing/binlog/blr.c b/server/modules/routing/binlog/blr.c index 7bace29ad..2766052e9 100644 --- a/server/modules/routing/binlog/blr.c +++ b/server/modules/routing/binlog/blr.c @@ -39,6 +39,7 @@ #include #include #include +#include #include #include #include @@ -160,7 +161,7 @@ static ROUTER * createInstance(SERVICE *service, char **options) { ROUTER_INSTANCE *inst; -char *value; +char *value, *name; int i; if ((inst = calloc(1, sizeof(ROUTER_INSTANCE))) == NULL) { @@ -183,6 +184,8 @@ int i; inst->initbinlog = 0; inst->short_burst = DEF_SHORT_BURST; inst->long_burst = DEF_LONG_BURST; + inst->burst_size = DEF_BURST_SIZE; + inst->retry_backoff = 1; /* * We only support one server behind this router, since the server is @@ -279,6 +282,30 @@ int i; { inst->long_burst = atoi(value); } + else if (strcmp(options[i], "burstsize") == 0) + { + unsigned long size = atoi(value); + char *ptr = value; + while (*ptr && isdigit(*ptr)) + ptr++; + switch (*ptr) + { + case 'G': + case 'g': + size = size * 1024 * 1000 * 1000; + break; + case 'M': + case 'm': + size = size * 1024 * 1000; + break; + case 'K': + case 'k': + size = size * 1024; + break; + } + inst->burst_size = size; + + } else { LOGIF(LE, (skygw_log_write( @@ -325,7 +352,11 @@ int i; */ blr_init_cache(inst); - hktask_add("Binlog Router", stats_func, inst, BLR_STATS_FREQ); + if ((name = (char *)malloc(80)) != NULL) + { + sprintf(name, "%s stats", service->name); + hktask_add(name, stats_func, inst, BLR_STATS_FREQ); + } /* * Now start the replication from the master to MaxScale @@ -822,9 +853,9 @@ char msg[85]; strcpy(msg, ""); LOGIF(LE, (skygw_log_write_flush( - LOGFILE_ERROR, "Erorr Reply '%s', %sattempting reconnect to master", + LOGFILE_ERROR, "Master connection '%s', %sattempting reconnect to master", message, msg))); - *succp = false; + *succp = true; blr_master_reconnect(router); } diff --git a/server/modules/routing/binlog/blr_master.c b/server/modules/routing/binlog/blr_master.c index c50751f7a..2e0ad008a 100644 --- a/server/modules/routing/binlog/blr_master.c +++ b/server/modules/routing/binlog/blr_master.c @@ -47,6 +47,7 @@ #include #include #include +#include #include #include @@ -107,6 +108,12 @@ GWBUF *buf; client->session = router->session; if ((router->master = dcb_connect(router->service->databases, router->session, BLR_PROTOCOL)) == NULL) { + char *name = malloc(strlen(router->service->name) + strlen(" Master") + 1); + sprintf(name, "%s Master", router->service->name); + hktask_oneshot(name, blr_start_master, router, + BLR_MASTER_BACKOFF_TIME * router->retry_backoff++); + if (router->retry_backoff > BLR_MAX_BACKOFF) + router->retry_backoff = 1; LOGIF(LE, (skygw_log_write_flush(LOGFILE_ERROR, "Binlog router: failed to connect to master server '%s'", router->service->databases->unique_name))); @@ -122,6 +129,7 @@ perror("setsockopt"); router->master_state = BLRM_TIMESTAMP; router->stats.n_masterstarts++; + router->retry_backoff = 1; } /** @@ -137,10 +145,7 @@ blr_restart_master(ROUTER_INSTANCE *router) { GWBUF *ptr; - dcb_close(router->master); dcb_close(router->client); - dcb_free(router->master); - dcb_free(router->client); /* Discard the queued residual data */ ptr = router->residual; @@ -696,9 +701,10 @@ static REP_HEADER phdr; } else if (hdr.flags != LOG_EVENT_ARTIFICIAL_F) { - router->rotating = 1; ptr = ptr + 5; // We don't put the first byte of the payload // into the binlog file + if (hdr.event_type == ROTATE_EVENT) + router->rotating = 1; blr_write_binlog_record(router, &hdr, ptr); if (hdr.event_type == ROTATE_EVENT) { @@ -719,10 +725,10 @@ static REP_HEADER phdr; hdr.event_size, router->binlog_name, router->binlog_position))); - router->rotating = 1; ptr += 5; if (hdr.event_type == ROTATE_EVENT) { + router->rotating = 1; blr_rotate_event(router, ptr, &hdr); } } @@ -800,7 +806,7 @@ blr_extract_header(register uint8_t *ptr, register REP_HEADER *hdr) * Extract a numeric field from a packet of the specified number of bits * * @param src The raw packet source - * @param birs The number of bits to extract (multiple of 8) + * @param bits The number of bits to extract (multiple of 8) */ inline uint32_t extract_field(register uint8_t *src, int bits) diff --git a/server/modules/routing/binlog/blr_slave.c b/server/modules/routing/binlog/blr_slave.c index 83c940963..89e18bd8e 100644 --- a/server/modules/routing/binlog/blr_slave.c +++ b/server/modules/routing/binlog/blr_slave.c @@ -47,6 +47,7 @@ #include #include #include +#include #include #include @@ -63,6 +64,7 @@ static int blr_slave_binlog_dump(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, G int blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, bool large); uint8_t *blr_build_header(GWBUF *pkt, REP_HEADER *hdr); int blr_slave_callback(DCB *dcb, DCB_REASON reason, void *data); +static int blr_slave_fake_rotate(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave); extern int lm_enabled_logfiles_bitmask; @@ -501,6 +503,7 @@ uint32_t chksum; slave->seqno = 1; + if (slave->nocrc) len = 19 + 8 + binlognamelen; else @@ -694,12 +697,15 @@ blr_slave_catchup(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave, bool large) GWBUF *head, *record; REP_HEADER hdr; int written, rval = 1, burst; +int rotating; +unsigned long burst_size; uint8_t *ptr; if (large) burst = router->long_burst; else burst = router->short_burst; + burst_size = router->burst_size; spinlock_acquire(&slave->catch_lock); if (slave->cstate & CS_BUSY) { @@ -711,19 +717,30 @@ uint8_t *ptr; if (slave->file == NULL) { + rotating = router->rotating; if ((slave->file = blr_open_binlog(router, slave->binlogfile)) == NULL) { + if (rotating) + { + spinlock_acquire(&slave->catch_lock); + slave->cstate |= CS_EXPECTCB; + slave->cstate &= ~CS_BUSY; + spinlock_release(&slave->catch_lock); + poll_fake_write_event(slave->dcb); + return rval; + } LOGIF(LE, (skygw_log_write( LOGFILE_ERROR, "blr_slave_catchup failed to open binlog file %s", slave->binlogfile))); slave->cstate &= ~CS_BUSY; slave->state = BLRS_ERRORED; + dcb_close(slave->dcb); return 0; } } slave->stats.n_bursts++; - while (burst-- && + while (burst-- && burst_size > 0 && (record = blr_read_binlog(router, slave->file, slave->binlog_pos, &hdr)) != NULL) { head = gwbuf_alloc(5); @@ -735,17 +752,35 @@ uint8_t *ptr; head = gwbuf_append(head, record); if (hdr.event_type == ROTATE_EVENT) { +unsigned long beat1 = hkheartbeat; blr_close_binlog(router, slave->file); +if (hkheartbeat - beat1 > 1) LOGIF(LE, (skygw_log_write( + LOGFILE_ERROR, "blr_close_binlog took %d beats", + hkheartbeat - beat1))); blr_slave_rotate(slave, GWBUF_DATA(record)); +beat1 = hkheartbeat; if ((slave->file = blr_open_binlog(router, slave->binlogfile)) == NULL) { + if (rotating) + { + spinlock_acquire(&slave->catch_lock); + slave->cstate |= CS_EXPECTCB; + slave->cstate &= ~CS_BUSY; + spinlock_release(&slave->catch_lock); + poll_fake_write_event(slave->dcb); + return rval; + } LOGIF(LE, (skygw_log_write( LOGFILE_ERROR, "blr_slave_catchup failed to open binlog file %s", slave->binlogfile))); slave->state = BLRS_ERRORED; + dcb_close(slave->dcb); break; } +if (hkheartbeat - beat1 > 1) LOGIF(LE, (skygw_log_write( + LOGFILE_ERROR, "blr_open_binlog took %d beats", + hkheartbeat - beat1))); } written = slave->dcb->func.write(slave->dcb, head); if (written && hdr.event_type != ROTATE_EVENT) @@ -754,6 +789,7 @@ uint8_t *ptr; } rval = written; slave->stats.n_events++; + burst_size -= hdr.event_size; } if (record == NULL) slave->stats.n_failed_read++; @@ -785,6 +821,8 @@ uint8_t *ptr; { slave->cstate &= ~CS_UPTODATE; slave->cstate |= CS_EXPECTCB; + spinlock_release(&slave->catch_lock); + spinlock_release(&router->binlog_lock); poll_fake_write_event(slave->dcb); } else @@ -793,11 +831,11 @@ uint8_t *ptr; { slave->stats.n_upd++; slave->cstate |= CS_UPTODATE; + spinlock_release(&slave->catch_lock); + spinlock_release(&router->binlog_lock); state_change = 1; } } - spinlock_release(&slave->catch_lock); - spinlock_release(&router->binlog_lock); if (state_change) { @@ -819,7 +857,7 @@ uint8_t *ptr; * binlog file. * * Note if the master is rotating there is a window during - * whch the rotate event has been written to the old binlog + * which the rotate event has been written to the old binlog * but the new binlog file has not yet been created. Therefore * we ignore these issues during the rotate processing. */ @@ -829,7 +867,18 @@ uint8_t *ptr; "Master binlog is %s, %lu.", slave->binlogfile, slave->binlog_pos, router->binlog_name, router->binlog_position))); - slave->state = BLRS_ERRORED; + if (blr_slave_fake_rotate(router, slave)) + { + spinlock_acquire(&slave->catch_lock); + slave->cstate |= CS_EXPECTCB; + spinlock_release(&slave->catch_lock); + poll_fake_write_event(slave->dcb); + } + else + { + slave->state = BLRS_ERRORED; + dcb_close(slave->dcb); + } } else { @@ -911,3 +960,74 @@ int len = EXTRACT24(ptr + 9); // Extract the event length memcpy(slave->binlogfile, ptr + 8, len); slave->binlogfile[len] = 0; } + +/** + * Generate an internal rotate event that we can use to cause the slave to move beyond + * a binlog file that is misisng the rotate eent at the end. + * + * @param router The router instance + * @param slave The slave to rotate + * @return Non-zero if the rotate took place + */ +static int +blr_slave_fake_rotate(ROUTER_INSTANCE *router, ROUTER_SLAVE *slave) +{ +char *sptr; +int filenum; +GWBUF *resp; +uint8_t *ptr; +int len, binlognamelen; +REP_HEADER hdr; +uint32_t chksum; + + if ((sptr = strrchr(slave->binlogfile, '.')) == NULL) + return 0; + blr_close_binlog(router, slave->file); + filenum = atoi(sptr + 1); + sprintf(slave->binlogfile, BINLOG_NAMEFMT, router->fileroot, filenum + 1); + slave->binlog_pos = 4; + if ((slave->file = blr_open_binlog(router, slave->binlogfile)) == NULL) + return 0; + + binlognamelen = strlen(slave->binlogfile); + + if (slave->nocrc) + len = 19 + 8 + binlognamelen; + else + len = 19 + 8 + 4 + binlognamelen; + + // Build a fake rotate event + resp = gwbuf_alloc(len + 5); + hdr.payload_len = len + 1; + hdr.seqno = slave->seqno++; + hdr.ok = 0; + hdr.timestamp = 0L; + hdr.event_type = ROTATE_EVENT; + hdr.serverid = router->masterid; + hdr.event_size = len; + hdr.next_pos = 0; + hdr.flags = 0x20; + ptr = blr_build_header(resp, &hdr); + encode_value(ptr, slave->binlog_pos, 64); + ptr += 8; + memcpy(ptr, slave->binlogfile, binlognamelen); + ptr += binlognamelen; + + if (!slave->nocrc) + { + /* + * Now add the CRC to the fake binlog rotate event. + * + * The algorithm is first to compute the checksum of an empty buffer + * and then the checksum of the event portion of the message, ie we do not + * include the length, sequence number and ok byte that makes up the first + * 5 bytes of the message. We also do not include the 4 byte checksum itself. + */ + chksum = crc32(0L, NULL, 0); + chksum = crc32(chksum, GWBUF_DATA(resp) + 5, hdr.event_size - 4); + encode_value(ptr, chksum, 32); + } + + slave->dcb->func.write(slave->dcb, resp); + return 1; +} diff --git a/server/modules/routing/debugcmd.c b/server/modules/routing/debugcmd.c index 2466b606a..db309c671 100644 --- a/server/modules/routing/debugcmd.c +++ b/server/modules/routing/debugcmd.c @@ -67,6 +67,7 @@ #include #include #include +#include #include #include @@ -167,6 +168,10 @@ struct subcommand showoptions[] = { "Show all active sessions in MaxScale", "Show all active sessions in MaxScale", {0, 0, 0} }, + { "tasks", 0, hkshow_tasks, + "Show all active housekeeper tasks in MaxScale", + "Show all active housekeeper tasks in MaxScale", + {0, 0, 0} }, { "threads", 0, dShowThreads, "Show the status of the polling threads in MaxScale", "Show the status of the polling threads in MaxScale", From 9e0a8a0eeecc6fa58fca98692f39950a1ea40a6b Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Thu, 23 Oct 2014 13:38:46 +0100 Subject: [PATCH 20/22] Addition of show eventstats --- server/core/housekeeper.c | 2 +- server/core/poll.c | 87 +++++++++++++++++++++++++------ server/include/dcb.h | 2 + server/include/poll.h | 1 + server/modules/routing/debugcmd.c | 4 ++ 5 files changed, 80 insertions(+), 16 deletions(-) diff --git a/server/core/housekeeper.c b/server/core/housekeeper.c index 7cc3d5f4b..520fe97f4 100644 --- a/server/core/housekeeper.c +++ b/server/core/housekeeper.c @@ -296,7 +296,7 @@ struct tm tm; char buf[40]; dcb_printf(pdcb, "%-25s | Type | Frequency | Next Due\n", "Name"); - dcb_printf(pdcb, "--------------------------+----------+-----------+-----------------------\n"); + dcb_printf(pdcb, "--------------------------+----------+-----------+-------------------------\n"); spinlock_acquire(&tasklock); ptr = tasks; while (ptr) diff --git a/server/core/poll.c b/server/core/poll.c index e614c7ba6..d5f5830ca 100644 --- a/server/core/poll.c +++ b/server/core/poll.c @@ -159,6 +159,17 @@ static struct { int blockingpolls; /*< Number of epoll_waits with a timeout specified */ } pollStats; +#define N_QUEUE_TIMES 30 +/** + * The event queue statistics + */ +static struct { + unsigned int qtimes[N_QUEUE_TIMES+1]; + unsigned int exectimes[N_QUEUE_TIMES+1]; + unsigned long maxqtime; + unsigned long maxexectime; +} queueStats; + /** * How frequently to call the poll_loadav function used to monitor the load * average of the poll subsystem. @@ -187,6 +198,7 @@ int i; exit(-1); } memset(&pollStats, 0, sizeof(pollStats)); + memset(&queueStats, 0, sizeof(queueStats)); bitmask_init(&poll_mask); n_threads = config_threadcount(); if ((thread_data = @@ -543,9 +555,7 @@ int poll_spins = 0; if (dcb->evq.pending_events == 0) { pollStats.evq_pending++; -#if PROFILE_POLL dcb->evq.inserted = hkheartbeat; -#endif } dcb->evq.pending_events |= ev; } @@ -567,9 +577,7 @@ int poll_spins = 0; } pollStats.evq_length++; pollStats.evq_pending++; -#if PROFILE_POLL dcb->evq.inserted = hkheartbeat; -#endif if (pollStats.evq_length > pollStats.evq_max) { pollStats.evq_max = pollStats.evq_length; @@ -664,6 +672,7 @@ process_pollq(int thread_id) DCB *dcb; int found = 0; uint32_t ev; +unsigned long qtime; spinlock_acquire(&pollqlock); if (eventq == NULL) @@ -712,6 +721,15 @@ uint32_t ev; #if PROFILE_POLL memlog_log(plog, hkheartbeat - dcb->evq.inserted); #endif + qtime = hkheartbeat - dcb->evq.inserted; + dcb->evq.started = hkheartbeat; + + if (qtime > N_QUEUE_TIMES) + queueStats.qtimes[N_QUEUE_TIMES]++; + else + queueStats.qtimes[qtime]++; + if (qtime > queueStats.maxqtime) + queueStats.maxqtime = qtime; CHK_DCB(dcb); @@ -914,6 +932,14 @@ uint32_t ev; spinlock_release(&dcb->dcb_initlock); } #endif + qtime = hkheartbeat - dcb->evq.started; + + if (qtime > N_QUEUE_TIMES) + queueStats.exectimes[N_QUEUE_TIMES]++; + else + queueStats.exectimes[qtime % N_QUEUE_TIMES]++; + if (qtime > queueStats.maxexectime) + queueStats.maxexectime = qtime; spinlock_acquire(&pollqlock); dcb->evq.processing_events = 0; @@ -1010,6 +1036,7 @@ dprintPollStats(DCB *dcb) { int i; + dcb_printf(dcb, "\nPoll Statistics.\n\n"); dcb_printf(dcb, "No. of epoll cycles: %d\n", pollStats.n_polls); dcb_printf(dcb, "No. of epoll cycles with wait: %d\n", @@ -1164,8 +1191,8 @@ double qavg1 = 0.0, qavg5 = 0.0, qavg15 = 0.0; if (thread_data == NULL) return; - dcb_printf(dcb, " ID | State | # fds | Descriptor | Event\n"); - dcb_printf(dcb, "----+------------+--------+------------------+---------------\n"); + dcb_printf(dcb, " ID | State | # fds | Descriptor | Running | Event\n"); + dcb_printf(dcb, "----+------------+--------+------------------+----------+---------------\n"); for (i = 0; i < n_threads; i++) { switch (thread_data[i].state) @@ -1188,11 +1215,11 @@ double qavg1 = 0.0, qavg5 = 0.0, qavg15 = 0.0; } if (thread_data[i].state != THREAD_PROCESSING) dcb_printf(dcb, - " %2d | %-10s | | |\n", + " %2d | %-10s | | | |\n", i, state); else if (thread_data[i].cur_dcb == NULL) dcb_printf(dcb, - " %2d | %-10s | %6d | |\n", + " %2d | %-10s | %6d | | |\n", i, state, thread_data[i].n_fds); else { @@ -1201,9 +1228,10 @@ double qavg1 = 0.0, qavg5 = 0.0, qavg15 = 0.0; if (event_string == NULL) event_string = "??"; dcb_printf(dcb, - " %2d | %-10s | %6d | %-16p | %s\n", + " %2d | %-10s | %6d | %-16p | <%3d00ms | %s\n", i, state, thread_data[i].n_fds, - thread_data[i].cur_dcb, event_string); + thread_data[i].cur_dcb, 1 + hkheartbeat - dcb->evq.started, + event_string); free(event_string); } } @@ -1282,6 +1310,7 @@ uint32_t ev = EPOLLOUT; else { dcb->evq.pending_events = ev; + dcb->evq.inserted = hkheartbeat; if (eventq) { dcb->evq.prev = eventq->evq.prev; @@ -1297,9 +1326,7 @@ uint32_t ev = EPOLLOUT; } pollStats.evq_length++; pollStats.evq_pending++; -#if PROFILE_POLL dcb->evq.inserted = hkheartbeat; -#endif if (pollStats.evq_length > pollStats.evq_max) { pollStats.evq_max = pollStats.evq_length; @@ -1317,17 +1344,16 @@ void dShowEventQ(DCB *pdcb) { DCB *dcb; -int found = 0; -uint32_t ev; spinlock_acquire(&pollqlock); if (eventq == NULL) { /* Nothing to process */ spinlock_release(&pollqlock); - return 0; + return; } dcb = eventq; + dcb_printf(pdcb, "\nEvent Queue.\n"); dcb_printf(pdcb, "%-16s | %-10s | %-18s | %s\n", "DCB", "Status", "Processing Events", "Pending Events"); dcb_printf(pdcb, "-----------------+------------+--------------------+-------------------\n"); @@ -1340,3 +1366,34 @@ uint32_t ev; } while (dcb != eventq); spinlock_release(&pollqlock); } + + +/** + * Print the event queue statistics + * + * @param pdcb The DCB to print the event queue to + */ +void +dShowEventStats(DCB *pdcb) +{ +int i; + + dcb_printf(pdcb, "\nEvent statistics.\n"); + dcb_printf(pdcb, "Maximum queue time: %3d00ms\n", queueStats.maxqtime); + dcb_printf(pdcb, "Maximum execution time: %3d00ms\n", queueStats.maxexectime); + dcb_printf(pdcb, "Maximum event queue length: %3d\n", pollStats.evq_max); + dcb_printf(pdcb, "Current event queue length: %3d\n", pollStats.evq_length); + dcb_printf(pdcb, "\n"); + dcb_printf(pdcb, " | Number of events\n"); + dcb_printf(pdcb, "Duration | Queued | Executed\n"); + dcb_printf(pdcb, "---------------+------------+-----------\n"); + dcb_printf(pdcb, " < 100ms | %-10d | %-10d\n", + queueStats.qtimes[0], queueStats.exectimes[0]); + for (i = 1; i < N_QUEUE_TIMES; i++) + { + dcb_printf(pdcb, " %2d00 - %2d00ms | %-10d | %-10d\n", i, i + 1, + queueStats.qtimes[i], queueStats.exectimes[i]); + } + dcb_printf(pdcb, " > %2d00ms | %-10d | %-10d\n", N_QUEUE_TIMES, + queueStats.qtimes[N_QUEUE_TIMES], queueStats.exectimes[N_QUEUE_TIMES]); +} diff --git a/server/include/dcb.h b/server/include/dcb.h index 723838151..8c29ec265 100644 --- a/server/include/dcb.h +++ b/server/include/dcb.h @@ -109,6 +109,7 @@ typedef struct gw_protocol { * processing Flag to indicate the processing status of the DCB * eventqlock Spinlock to protect this structure * inserted Insertion time for logging purposes + * started Time that the processign started */ typedef struct { struct dcb *next; @@ -118,6 +119,7 @@ typedef struct { int processing; SPINLOCK eventqlock; unsigned long inserted; + unsigned long started; } DCBEVENTQ; /** diff --git a/server/include/poll.h b/server/include/poll.h index f4d9f4aa8..eae895a1b 100644 --- a/server/include/poll.h +++ b/server/include/poll.h @@ -44,4 +44,5 @@ extern void poll_set_nonblocking_polls(unsigned int); extern void dprintPollStats(DCB *); extern void dShowThreads(DCB *dcb); extern void dShowEventQ(DCB *dcb); +extern void dShowEventStats(DCB *dcb); #endif diff --git a/server/modules/routing/debugcmd.c b/server/modules/routing/debugcmd.c index db309c671..c89ba048e 100644 --- a/server/modules/routing/debugcmd.c +++ b/server/modules/routing/debugcmd.c @@ -124,6 +124,10 @@ struct subcommand showoptions[] = { "Show the queue of events waiting to be processed", "Show the queue of events waiting to be processed", {0, 0, 0} }, + { "eventstats", 0, dShowEventStats, + "Show the event statistics", + "Show the event statistics", + {0, 0, 0} }, { "filter", 1, dprintFilter, "Show details of a filter, called with a filter name", "Show details of a filter, called with the address of a filter", From 67a0f65b74dc6ece8fd0ed211907207f13c494da Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Mon, 17 Nov 2014 11:56:41 +0000 Subject: [PATCH 21/22] Fixed issue with not releasing the spinlock in show tasks --- server/core/housekeeper.c | 1 + 1 file changed, 1 insertion(+) diff --git a/server/core/housekeeper.c b/server/core/housekeeper.c index 520fe97f4..57fbbccda 100644 --- a/server/core/housekeeper.c +++ b/server/core/housekeeper.c @@ -310,4 +310,5 @@ char buf[40]; buf); ptr = ptr->next; } + spinlock_release(&tasklock); } From 6cbbf7260ff78732fc9ec2c41f8c32b688874f21 Mon Sep 17 00:00:00 2001 From: Mark Riddoch Date: Wed, 19 Nov 2014 10:49:40 +0000 Subject: [PATCH 22/22] Improved logging and diagnostics --- server/core/dcb.c | 19 ++++++++++--- server/modules/protocol/mysql_backend.c | 38 +++++++++++++++++++++++++ 2 files changed, 53 insertions(+), 4 deletions(-) diff --git a/server/core/dcb.c b/server/core/dcb.c index 25cd5b526..b8d2c9762 100644 --- a/server/core/dcb.c +++ b/server/core/dcb.c @@ -185,7 +185,7 @@ dcb_free(DCB *dcb) { LOGIF(LE, (skygw_log_write_flush( LOGFILE_ERROR, - "Error : Attempt to free a DCB via dcb_fee " + "Error : Attempt to free a DCB via dcb_free " "that has been associated with a descriptor."))); } } @@ -287,6 +287,15 @@ DCB_CALLBACK *cb; dcb->state == DCB_STATE_ALLOC, "dcb not in DCB_STATE_DISCONNECTED not in DCB_STATE_ALLOC state."); + if (DCB_POLL_BUSY(dcb)) + { + /* Check if DCB has outstanding poll events */ + LOGIF(LE, (skygw_log_write_flush( + LOGFILE_ERROR, + "dcb_final_free: DCB %p has outstanding events", + dcb))); + } + /*< First remove this DCB from the chain */ spinlock_acquire(&dcbspin); if (allDCBs == dcb) @@ -358,6 +367,7 @@ DCB_CALLBACK *cb; } spinlock_release(&dcb->cb_lock); + bitmask_free(&dcb->memdata.bitmask); free(dcb); } @@ -1140,7 +1150,8 @@ dcb_close(DCB *dcb) /*< * Stop dcb's listening and modify state accordingly. */ - rc = poll_remove_dcb(dcb); + if (dcb->fd != -1) + rc = poll_remove_dcb(dcb); ss_dassert(dcb->state == DCB_STATE_NOPOLLING || dcb->state == DCB_STATE_ZOMBIE); @@ -1203,9 +1214,9 @@ printDCB(DCB *dcb) dcb->stats.n_buffered); printf("\t\tNo. of Accepts: %d\n", dcb->stats.n_accepts); - printf("\t\tNo. of High Water Events: %d\n", + printf("\t\tNo. of High Water Events: %d\n", dcb->stats.n_high_water); - printf("\t\tNo. of Low Water Events: %d\n", + printf("\t\tNo. of Low Water Events: %d\n", dcb->stats.n_low_water); } /** diff --git a/server/modules/protocol/mysql_backend.c b/server/modules/protocol/mysql_backend.c index 2772e8e7b..2c2939a40 100644 --- a/server/modules/protocol/mysql_backend.c +++ b/server/modules/protocol/mysql_backend.c @@ -785,6 +785,19 @@ static int gw_error_backend_event(DCB *dcb) */ if (dcb->state != DCB_STATE_POLLING) { + int error, len; + char buf[100]; + + len = sizeof(error); + if (getsockopt(dcb->fd, SOL_SOCKET, SO_ERROR, &error, &len) == 0) + { + strerror_r(error, buf, 100); + LOGIF(LE, (skygw_log_write_flush( + LOGFILE_ERROR, + "DCB in state %s got error '%s'.", + gw_dcb_state2string(dcb->state), + buf))); + } return 1; } errbuf = mysql_create_custom_error( @@ -811,6 +824,18 @@ static int gw_error_backend_event(DCB *dcb) if (ses_state != SESSION_STATE_ROUTER_READY) { + int error, len; + char buf[100]; + + len = sizeof(error); + if (getsockopt(dcb->fd, SOL_SOCKET, SO_ERROR, &error, &len) == 0) + { + strerror_r(error, buf, 100); + LOGIF(LE, (skygw_log_write_flush( + LOGFILE_ERROR, + "Error '%s' in session that is not ready for routing.", + buf))); + } gwbuf_free(errbuf); goto retblock; } @@ -989,6 +1014,19 @@ gw_backend_hangup(DCB *dcb) if (ses_state != SESSION_STATE_ROUTER_READY) { + int error, len; + char buf[100]; + + len = sizeof(error); + if (getsockopt(dcb->fd, SOL_SOCKET, SO_ERROR, &error, &len) == 0) + { + strerror_r(error, buf, 100); + LOGIF(LE, (skygw_log_write_flush( + LOGFILE_ERROR, + "Hangup in session that is not ready for routing, " + "Error reported is '%s'.", + buf))); + } gwbuf_free(errbuf); goto retblock; }