From f6385aeb2f69b36fd02498259258f013582f706f Mon Sep 17 00:00:00 2001 From: arao Date: Mon, 22 Jun 2015 11:10:05 +0530 Subject: Logging: Porting the performance translator logs to new logging framework > Change-Id: Ie6aaf8d30bd4457bb73c48e23e6b1dea27598644 > BUG: 1194640 > Signed-off-by: arao BUG: 1217722 Change-Id: I0856c43dbf8c0a1aa084d4478c9bdf3f41dfc0b8 Signed-off-by: arao Reviewed-on: http://review.gluster.org/11442 Tested-by: NetBSD Build System Tested-by: Gluster Build System Reviewed-by: Raghavendra G --- xlators/performance/io-cache/src/Makefile.am | 6 +- .../performance/io-cache/src/io-cache-messages.h | 111 +++++++++++++++ xlators/performance/io-cache/src/io-cache.c | 150 ++++++++++++--------- xlators/performance/io-cache/src/io-cache.h | 45 ++++--- xlators/performance/io-cache/src/ioc-inode.c | 22 +-- xlators/performance/io-cache/src/page.c | 103 +++++++------- 6 files changed, 294 insertions(+), 143 deletions(-) create mode 100644 xlators/performance/io-cache/src/io-cache-messages.h (limited to 'xlators/performance/io-cache/src') diff --git a/xlators/performance/io-cache/src/Makefile.am b/xlators/performance/io-cache/src/Makefile.am index 155be9988c9..756ecacef5e 100644 --- a/xlators/performance/io-cache/src/Makefile.am +++ b/xlators/performance/io-cache/src/Makefile.am @@ -1,16 +1,16 @@ xlator_LTLIBRARIES = io-cache.la xlatordir = $(libdir)/glusterfs/$(PACKAGE_VERSION)/xlator/performance -io_cache_la_LDFLAGS = -module -avoid-version +io_cache_la_LDFLAGS = -module -avoid-version io_cache_la_SOURCES = io-cache.c page.c ioc-inode.c io_cache_la_LIBADD = $(top_builddir)/libglusterfs/src/libglusterfs.la -noinst_HEADERS = io-cache.h ioc-mem-types.h +noinst_HEADERS = io-cache.h ioc-mem-types.h io-cache-messages.h AM_CPPFLAGS = $(GF_CPPFLAGS) -I$(top_srcdir)/libglusterfs/src \ -I$(CONTRIBDIR)/rbtree AM_CFLAGS = -Wall $(GF_CFLAGS) -CLEANFILES = +CLEANFILES = diff --git a/xlators/performance/io-cache/src/io-cache-messages.h b/xlators/performance/io-cache/src/io-cache-messages.h new file mode 100644 index 00000000000..5c4fbea46fc --- /dev/null +++ b/xlators/performance/io-cache/src/io-cache-messages.h @@ -0,0 +1,111 @@ +/*Copyright (c) 2015 Red Hat, Inc. + This file is part of GlusterFS. + + This file is licensed to you under your choice of the GNU Lesser + General Public License, version 3 or any later version (LGPLv3 or + later), or the GNU General Public License, version 2 (GPLv2), in all + cases as published by the Free Software Foundation. +*/ + +#ifndef _IO_CACHE_MESSAGES_H_ +#define _IO_CACHE_MESSAGES_H_ + +#include "glfs-message-id.h" + +/*! \file io-cache-messages.h + * \brief IO_CACHE log-message IDs and their descriptions + * + */ + +/* NOTE: Rules for message additions + * 1) Each instance of a message is _better_ left with a unique message ID, even + * if the message format is the same. Reasoning is that, if the message + * format needs to change in one instance, the other instances are not + * impacted or the new change does not change the ID of the instance being + * modified. + * 2) Addition of a message, + * - Should increment the GLFS_NUM_MESSAGES + * - Append to the list of messages defined, towards the end + * - Retain macro naming as glfs_msg_X (for redability across developers) + * NOTE: Rules for message format modifications + * 3) Check acorss the code if the message ID macro in question is reused + * anywhere. If reused then then the modifications should ensure correctness + * everywhere, or needs a new message ID as (1) above was not adhered to. If + * not used anywhere, proceed with the required modification. + * NOTE: Rules for message deletion + * 4) Check (3) and if used anywhere else, then cannot be deleted. If not used + * anywhere, then can be deleted, but will leave a hole by design, as + * addition rules specify modification to the end of the list and not filling + * holes. + */ + +#define GLFS_IO_CACHE_BASE GLFS_MSGID_COMP_IO_CACHE +#define GLFS_IO_CACHE_NUM_MESSAGES 6 +#define GLFS_MSGID_END (GLFS_IO_CACHE_BASE + GLFS_IO_CACHE_NUM_MESSAGES + 1) + +/* Messages with message IDs */ +#define glfs_msg_start_x GLFS_IO_CACHE_BASE, "Invalid: Start of messages" + + + + +/*! + * @messageid + * @diagnosis + * @recommendedaction None + * + */ + +#define IO_CACHE_MSG_ENFORCEMENT_FAILED (GLFS_IO_CACHE_BASE + 1) + +/*! + * @messageid + * @diagnosis + * @recommendedaction None + * + */ + +#define IO_CACHE_MSG_INVALID_ARGUMENT (GLFS_IO_CACHE_BASE + 2) + +/*! + * @messageid + * @diagnosis + * @recommendedaction None + * + */ + +#define IO_CACHE_MSG_XLATOR_CHILD_MISCONFIGURED (GLFS_IO_CACHE_BASE + 3) + +/*! + * @messageid + * @diagnosis + * @recommendedaction None + * + */ + +#define IO_CACHE_MSG_NO_MEMORY (GLFS_IO_CACHE_BASE + 4) + +/*! + * @messageid + * @diagnosis + * @recommendedaction None + * + */ + +#define IO_CACHE_MSG_VOL_MISCONFIGURED (GLFS_IO_CACHE_BASE + 5) + +/*! + * @messageid + * @diagnosis + * @recommendedaction None + * + */ + +#define IO_CACHE_MSG_INODE_NULL (GLFS_IO_CACHE_BASE + 6) + + +/*------------*/ +#define glfs_msg_end_x GLFS_MSGID_END, "Invalid: End of messages" + + +#endif /* _IO_CACHE_MESSAGES_H_ */ diff --git a/xlators/performance/io-cache/src/io-cache.c b/xlators/performance/io-cache/src/io-cache.c index bfda85d4926..7eea867218f 100644 --- a/xlators/performance/io-cache/src/io-cache.c +++ b/xlators/performance/io-cache/src/io-cache.c @@ -22,7 +22,7 @@ #include "statedump.h" #include #include - +#include "io-cache-messages.h" int ioc_log2_page_size; uint32_t @@ -272,14 +272,16 @@ ioc_lookup (call_frame_t *frame, xlator_t *this, loc_t *loc, local = mem_get0 (this->local_pool); if (local == NULL) { op_errno = ENOMEM; - gf_log (this->name, GF_LOG_ERROR, "out of memory"); + gf_msg (this->name, GF_LOG_ERROR, 0, + IO_CACHE_MSG_NO_MEMORY, "out of memory"); goto unwind; } ret = loc_copy (&local->file_loc, loc); if (ret != 0) { op_errno = ENOMEM; - gf_log (this->name, GF_LOG_ERROR, "out of memory"); + gf_msg (this->name, GF_LOG_ERROR, 0, + IO_CACHE_MSG_NO_MEMORY, "out of memory"); goto unwind; } @@ -360,9 +362,9 @@ ioc_cache_validate_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if ((op_ret == -1) || ((op_ret >= 0) && !ioc_cache_still_valid(ioc_inode, stbuf))) { - gf_log (ioc_inode->table->xl->name, GF_LOG_DEBUG, - "cache for inode(%p) is invalid. flushing all pages", - ioc_inode); + gf_msg_debug (ioc_inode->table->xl->name, 0, + "cache for inode(%p) is invalid. flushing all pages", + ioc_inode); /* NOTE: only pages with no waiting frames are flushed by * ioc_inode_flush. page_fault will be generated for all * the pages which have waiting frames by ioc_inode_wakeup() @@ -430,7 +432,8 @@ ioc_wait_on_inode (ioc_inode_t *ioc_inode, ioc_page_t *page) waiter = GF_CALLOC (1, sizeof (ioc_waitq_t), gf_ioc_mt_ioc_waitq_t); if (waiter == NULL) { - gf_log (ioc_inode->table->xl->name, GF_LOG_ERROR, + gf_msg (ioc_inode->table->xl->name, GF_LOG_ERROR, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "out of memory"); ret = -ENOMEM; goto out; @@ -468,8 +471,8 @@ ioc_cache_validate (call_frame_t *frame, ioc_inode_t *ioc_inode, fd_t *fd, ret = -1; local->op_ret = -1; local->op_errno = ENOMEM; - gf_log (ioc_inode->table->xl->name, GF_LOG_ERROR, - "out of memory"); + gf_msg (ioc_inode->table->xl->name, GF_LOG_ERROR, + 0, IO_CACHE_MSG_NO_MEMORY, "out of memory"); goto out; } @@ -479,8 +482,8 @@ ioc_cache_validate (call_frame_t *frame, ioc_inode_t *ioc_inode, fd_t *fd, local->op_ret = -1; local->op_errno = ENOMEM; mem_put (validate_local); - gf_log (ioc_inode->table->xl->name, GF_LOG_ERROR, - "out of memory"); + gf_msg (ioc_inode->table->xl->name, GF_LOG_ERROR, + 0, IO_CACHE_MSG_NO_MEMORY, "out of memory"); goto out; } @@ -560,8 +563,10 @@ ioc_open_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, //TODO: see why inode context is NULL and handle it. if (!ioc_inode) { - gf_log (this->name, GF_LOG_ERROR, "inode context is " - "NULL (%s)", uuid_utoa (fd->inode->gfid)); + gf_msg (this->name, GF_LOG_ERROR, + EINVAL, IO_CACHE_MSG_ENFORCEMENT_FAILED, + "inode context is NULL (%s)", + uuid_utoa (fd->inode->gfid)); goto out; } @@ -660,7 +665,8 @@ ioc_create_cbk (call_frame_t *frame, void *cookie, xlator_t *this, && (table->max_file_size < ioc_inode->ia_size))) { ret = fd_ctx_set (fd, this, 1); if (ret) - gf_log (this->name, GF_LOG_WARNING, + gf_msg (this->name, GF_LOG_WARNING, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "%s: failed to set fd ctx", local->file_loc.path); } @@ -677,7 +683,8 @@ ioc_create_cbk (call_frame_t *frame, void *cookie, xlator_t *this, * as a whole */ ret = fd_ctx_set (fd, this, 1); if (ret) - gf_log (this->name, GF_LOG_WARNING, + gf_msg (this->name, GF_LOG_WARNING, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "%s: failed to set fd ctx", local->file_loc.path); } @@ -687,7 +694,8 @@ ioc_create_cbk (call_frame_t *frame, void *cookie, xlator_t *this, /* we allow a pattern-matched cache disable this way */ ret = fd_ctx_set (fd, this, 1); if (ret) - gf_log (this->name, GF_LOG_WARNING, + gf_msg (this->name, GF_LOG_WARNING, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "%s: failed to set fd ctx", local->file_loc.path); } @@ -767,14 +775,16 @@ ioc_mknod (call_frame_t *frame, xlator_t *this, loc_t *loc, mode_t mode, local = mem_get0 (this->local_pool); if (local == NULL) { op_errno = ENOMEM; - gf_log (this->name, GF_LOG_ERROR, "out of memory"); + gf_msg (this->name, GF_LOG_ERROR, + 0, IO_CACHE_MSG_NO_MEMORY, "out of memory"); goto unwind; } ret = loc_copy (&local->file_loc, loc); if (ret != 0) { op_errno = ENOMEM; - gf_log (this->name, GF_LOG_ERROR, "out of memory"); + gf_msg (this->name, GF_LOG_ERROR, + 0, IO_CACHE_MSG_NO_MEMORY, "out of memory"); goto unwind; } @@ -816,7 +826,8 @@ ioc_open (call_frame_t *frame, xlator_t *this, loc_t *loc, int32_t flags, local = mem_get0 (this->local_pool); if (local == NULL) { - gf_log (this->name, GF_LOG_ERROR, "out of memory"); + gf_msg (this->name, GF_LOG_ERROR, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "out of memory"); STACK_UNWIND_STRICT (open, frame, -1, ENOMEM, NULL, NULL); return 0; } @@ -852,7 +863,8 @@ ioc_create (call_frame_t *frame, xlator_t *this, loc_t *loc, int32_t flags, local = mem_get0 (this->local_pool); if (local == NULL) { - gf_log (this->name, GF_LOG_ERROR, "out of memory"); + gf_msg (this->name, GF_LOG_ERROR, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "out of memory"); STACK_UNWIND_STRICT (create, frame, -1, ENOMEM, NULL, NULL, NULL, NULL, NULL, NULL); return 0; @@ -991,8 +1003,9 @@ ioc_dispatch_requests (call_frame_t *frame, ioc_inode_t *ioc_inode, fd_t *fd, trav_offset); fault = 1; if (!trav) { - gf_log (frame->this->name, + gf_msg (frame->this->name, GF_LOG_CRITICAL, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "out of memory"); local->op_ret = -1; local->op_errno = ENOMEM; @@ -1008,10 +1021,13 @@ ioc_dispatch_requests (call_frame_t *frame, ioc_inode_t *ioc_inode, fd_t *fd, /* page found in cache */ if (!might_need_validate && !ioc_inode->waitq) { /* fresh enough */ - gf_log (frame->this->name, GF_LOG_TRACE, - "cache hit for trav_offset=%" - PRId64"/local_offset=%"PRId64"", - trav_offset, local_offset); + gf_msg_trace (frame->this->name, 0, + "cache hit for " + "trav_offset=%" + PRId64"/local_" + "offset=%"PRId64"", + trav_offset, + local_offset); waitq = __ioc_page_wakeup (trav, trav->op_errno); } else { @@ -1055,10 +1071,10 @@ ioc_dispatch_requests (call_frame_t *frame, ioc_inode_t *ioc_inode, fd_t *fd, if (need_validate) { need_validate = 0; - gf_log (frame->this->name, GF_LOG_TRACE, - "sending validate request for " - "inode(%s) at offset=%"PRId64"", - uuid_utoa (fd->inode->gfid), trav_offset); + gf_msg_trace (frame->this->name, 0, + "sending validate request for " + "inode(%s) at offset=%"PRId64"", + uuid_utoa (fd->inode->gfid), trav_offset); ret = ioc_cache_validate (frame, ioc_inode, fd, trav); if (ret == -1) { ioc_inode_lock (ioc_inode); @@ -1128,7 +1144,8 @@ ioc_readv (call_frame_t *frame, xlator_t *this, fd_t *fd, table = this->private; if (!table) { - gf_log (this->name, GF_LOG_ERROR, "table is null"); + gf_msg (this->name, GF_LOG_ERROR, EINVAL, + IO_CACHE_MSG_ENFORCEMENT_FAILED, "table is null"); op_errno = EINVAL; goto out; } @@ -1162,7 +1179,8 @@ ioc_readv (call_frame_t *frame, xlator_t *this, fd_t *fd, local = mem_get0 (this->local_pool); if (local == NULL) { - gf_log (this->name, GF_LOG_ERROR, "out of memory"); + gf_msg (this->name, GF_LOG_ERROR, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "out of memory"); op_errno = ENOMEM; goto out; } @@ -1176,9 +1194,10 @@ ioc_readv (call_frame_t *frame, xlator_t *this, fd_t *fd, local->size = size; local->inode = ioc_inode; - gf_log (this->name, GF_LOG_TRACE, - "NEW REQ (%p) offset = %"PRId64" && size = %"GF_PRI_SIZET"", - frame, offset, size); + gf_msg_trace (this->name, 0, + "NEW REQ (%p) offset " + "= %"PRId64" && size = %"GF_PRI_SIZET"", + frame, offset, size); weight = ioc_inode->weight; @@ -1248,7 +1267,8 @@ ioc_writev (call_frame_t *frame, xlator_t *this, fd_t *fd, local = mem_get0 (this->local_pool); if (local == NULL) { - gf_log (this->name, GF_LOG_ERROR, "out of memory"); + gf_msg (this->name, GF_LOG_ERROR, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "out of memory"); STACK_UNWIND_STRICT (writev, frame, -1, ENOMEM, NULL, NULL, NULL); return 0; @@ -1383,8 +1403,8 @@ ioc_lk (call_frame_t *frame, xlator_t *this, fd_t *fd, int32_t cmd, inode_ctx_get (fd->inode, this, &tmp_inode); ioc_inode = (ioc_inode_t *)(long)tmp_inode; if (!ioc_inode) { - gf_log (this->name, GF_LOG_DEBUG, - "inode context is NULL: returning EBADFD"); + gf_msg_debug (this->name, EBADFD, + "inode context is NULL: returning EBADFD"); STACK_UNWIND_STRICT (lk, frame, -1, EBADFD, NULL, NULL); return 0; } @@ -1537,10 +1557,9 @@ ioc_get_priority_list (const char *opt_str, struct list_head *first) goto out; } - gf_log ("io-cache", GF_LOG_TRACE, - "ioc priority : pattern %s : priority %s", - pattern, - priority); + gf_msg_trace ("io-cache", 0, + "ioc priority : pattern %s : priority %s", + pattern, priority); curr->pattern = gf_strdup (pattern); if (curr->pattern == NULL) { @@ -1588,8 +1607,9 @@ mem_acct_init (xlator_t *this) ret = xlator_mem_acct_init (this, gf_ioc_mt_end + 1); if (ret != 0) { - gf_log (this->name, GF_LOG_ERROR, "Memory accounting init" - "failed"); + gf_msg (this->name, GF_LOG_ERROR, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, + "Memory accounting init failed"); return ret; } @@ -1609,7 +1629,8 @@ check_cache_size_ok (xlator_t *this, uint64_t cache_size) opt = xlator_volume_option_get (this, "cache-size"); if (!opt) { ret = _gf_false; - gf_log (this->name, GF_LOG_ERROR, + gf_msg (this->name, GF_LOG_ERROR, + EINVAL, IO_CACHE_MSG_ENFORCEMENT_FAILED, "could not get cache-size option"); goto out; } @@ -1620,12 +1641,14 @@ check_cache_size_ok (xlator_t *this, uint64_t cache_size) else max_cache_size = total_mem; - gf_log (this->name, GF_LOG_DEBUG, "Max cache size is %"PRIu64, - max_cache_size); + gf_msg_debug (this->name, 0, "Max cache size is %"PRIu64, + max_cache_size); if (cache_size > max_cache_size) { ret = _gf_false; - gf_log (this->name, GF_LOG_ERROR, "Cache size %"PRIu64 + gf_msg (this->name, GF_LOG_ERROR, + 0, IO_CACHE_MSG_INVALID_ARGUMENT, + "Cache size %"PRIu64 " is greater than the max size of %"PRIu64, cache_size, max_cache_size); goto out; @@ -1655,8 +1678,8 @@ reconfigure (xlator_t *this, dict_t *options) if (data) { char *option_list = data_to_str (data); - gf_log (this->name, GF_LOG_TRACE, - "option path %s", option_list); + gf_msg_trace (this->name, 0, + "option path %s", option_list); /* parse the list of pattern:priority */ table->max_pri = ioc_get_priority_list (option_list, &table->priority_list); @@ -1675,7 +1698,8 @@ reconfigure (xlator_t *this, dict_t *options) if ((table->max_file_size <= UINT64_MAX) && (table->min_file_size > table->max_file_size)) { - gf_log (this->name, GF_LOG_ERROR, "minimum size (%" + gf_msg (this->name, GF_LOG_ERROR, 0, + IO_CACHE_MSG_INVALID_ARGUMENT, "minimum size (%" PRIu64") of a file that can be cached is " "greater than maximum size (%"PRIu64"). " "Hence Defaulting to old value", @@ -1687,7 +1711,8 @@ reconfigure (xlator_t *this, dict_t *options) options, size_uint64, unlock); if (!check_cache_size_ok (this, cache_size_new)) { ret = -1; - gf_log (this->name, GF_LOG_ERROR, + gf_msg (this->name, GF_LOG_ERROR, + 0, IO_CACHE_MSG_INVALID_ARGUMENT, "Not reconfiguring cache-size"); goto unlock; } @@ -1721,20 +1746,23 @@ init (xlator_t *this) xl_options = this->options; if (!this->children || this->children->next) { - gf_log (this->name, GF_LOG_ERROR, + gf_msg (this->name, GF_LOG_ERROR, 0, + IO_CACHE_MSG_XLATOR_CHILD_MISCONFIGURED, "FATAL: io-cache not configured with exactly " "one child"); goto out; } if (!this->parents) { - gf_log (this->name, GF_LOG_WARNING, + gf_msg (this->name, GF_LOG_WARNING, 0, + IO_CACHE_MSG_VOL_MISCONFIGURED, "dangling volume. check volfile "); } table = (void *) GF_CALLOC (1, sizeof (*table), gf_ioc_mt_ioc_table_t); if (table == NULL) { - gf_log (this->name, GF_LOG_ERROR, "out of memory"); + gf_msg (this->name, GF_LOG_ERROR, ENOMEM, + IO_CACHE_MSG_NO_MEMORY, "out of memory"); goto out; } @@ -1759,8 +1787,8 @@ init (xlator_t *this) data = dict_get (xl_options, "priority"); if (data) { char *option_list = data_to_str (data); - gf_log (this->name, GF_LOG_TRACE, - "option path %s", option_list); + gf_msg_trace (this->name, 0, + "option path %s", option_list); /* parse the list of pattern:priority */ table->max_pri = ioc_get_priority_list (option_list, &table->priority_list); @@ -1775,7 +1803,8 @@ init (xlator_t *this) if ((table->max_file_size <= UINT64_MAX) && (table->min_file_size > table->max_file_size)) { - gf_log ("io-cache", GF_LOG_ERROR, "minimum size (%" + gf_msg ("io-cache", GF_LOG_ERROR, 0, + IO_CACHE_MSG_INVALID_ARGUMENT, "minimum size (%" PRIu64") of a file that can be cached is " "greater than maximum size (%"PRIu64")", table->min_file_size, table->max_file_size); @@ -1795,7 +1824,8 @@ init (xlator_t *this) this->local_pool = mem_pool_new (ioc_local_t, 64); if (!this->local_pool) { ret = -1; - gf_log (this->name, GF_LOG_ERROR, + gf_msg (this->name, GF_LOG_ERROR, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "failed to create local_t's memory pool"); goto out; } @@ -1809,8 +1839,8 @@ init (xlator_t *this) table->mem_pool = mem_pool_new (rbthash_entry_t, num_pages); if (!table->mem_pool) { - gf_log (this->name, GF_LOG_ERROR, - "Unable to allocate mem_pool"); + gf_msg (this->name, GF_LOG_ERROR, ENOMEM, + IO_CACHE_MSG_NO_MEMORY, "Unable to allocate mem_pool"); goto out; } diff --git a/xlators/performance/io-cache/src/io-cache.h b/xlators/performance/io-cache/src/io-cache.h index 46d758a6608..1bdd66b99de 100644 --- a/xlators/performance/io-cache/src/io-cache.h +++ b/xlators/performance/io-cache/src/io-cache.h @@ -29,6 +29,7 @@ #include "hashfn.h" #include #include +#include "io-cache-messages.h" #define IOC_PAGE_SIZE (1024 * 128) /* 128KB */ #define IOC_CACHE_SIZE (32 * 1024 * 1024) @@ -224,64 +225,64 @@ ioc_frame_fill (ioc_page_t *page, call_frame_t *frame, off_t offset, #define ioc_inode_lock(ioc_inode) \ do { \ - gf_log (ioc_inode->table->xl->name, GF_LOG_TRACE, \ - "locked inode(%p)", ioc_inode); \ + gf_msg_trace (ioc_inode->table->xl->name, 0, \ + "locked inode(%p)", ioc_inode); \ pthread_mutex_lock (&ioc_inode->inode_lock); \ } while (0) #define ioc_inode_unlock(ioc_inode) \ do { \ - gf_log (ioc_inode->table->xl->name, GF_LOG_TRACE, \ - "unlocked inode(%p)", ioc_inode); \ + gf_msg_trace (ioc_inode->table->xl->name, 0, \ + "unlocked inode(%p)", ioc_inode); \ pthread_mutex_unlock (&ioc_inode->inode_lock); \ } while (0) -#define ioc_table_lock(table) \ - do { \ - gf_log (table->xl->name, GF_LOG_TRACE, \ - "locked table(%p)", table); \ - pthread_mutex_lock (&table->table_lock); \ +#define ioc_table_lock(table) \ + do { \ + gf_msg_trace (table->xl->name, 0, \ + "locked table(%p)", table); \ + pthread_mutex_lock (&table->table_lock); \ } while (0) -#define ioc_table_unlock(table) \ - do { \ - gf_log (table->xl->name, GF_LOG_TRACE, \ - "unlocked table(%p)", table); \ - pthread_mutex_unlock (&table->table_lock); \ +#define ioc_table_unlock(table) \ + do { \ + gf_msg_trace (table->xl->name, 0, \ + "unlocked table(%p)", table); \ + pthread_mutex_unlock (&table->table_lock); \ } while (0) #define ioc_local_lock(local) \ do { \ - gf_log (local->inode->table->xl->name, GF_LOG_TRACE, \ - "locked local(%p)", local); \ + gf_msg_trace (local->inode->table->xl->name, 0, \ + "locked local(%p)", local); \ pthread_mutex_lock (&local->local_lock); \ } while (0) #define ioc_local_unlock(local) \ do { \ - gf_log (local->inode->table->xl->name, GF_LOG_TRACE, \ - "unlocked local(%p)", local); \ + gf_msg_trace (local->inode->table->xl->name, 0, \ + "unlocked local(%p)", local); \ pthread_mutex_unlock (&local->local_lock); \ } while (0) #define ioc_page_lock(page) \ do { \ - gf_log (page->inode->table->xl->name, GF_LOG_TRACE, \ - "locked page(%p)", page); \ + gf_msg_trace (page->inode->table->xl->name, 0, \ + "locked page(%p)", page); \ pthread_mutex_lock (&page->page_lock); \ } while (0) #define ioc_page_unlock(page) \ do { \ - gf_log (page->inode->table->xl->name, GF_LOG_TRACE, \ - "unlocked page(%p)", page); \ + gf_msg_trace (page->inode->table->xl->name, 0, \ + "unlocked page(%p)", page); \ pthread_mutex_unlock (&page->page_lock); \ } while (0) diff --git a/xlators/performance/io-cache/src/ioc-inode.c b/xlators/performance/io-cache/src/ioc-inode.c index 86a54bb14ca..fcaab962b35 100644 --- a/xlators/performance/io-cache/src/ioc-inode.c +++ b/xlators/performance/io-cache/src/ioc-inode.c @@ -82,7 +82,8 @@ ioc_inode_wakeup (call_frame_t *frame, ioc_inode_t *ioc_inode, if (ioc_inode == NULL) { local->op_ret = -1; local->op_errno = EINVAL; - gf_log (frame->this->name, GF_LOG_WARNING, "ioc_inode is NULL"); + gf_msg (frame->this->name, GF_LOG_WARNING, 0, + IO_CACHE_MSG_INODE_NULL, "ioc_inode is NULL"); goto out; } @@ -130,12 +131,15 @@ ioc_inode_wakeup (call_frame_t *frame, ioc_inode_t *ioc_inode, waiter_page->ready = 0; need_fault = 1; } else { - gf_log (frame->this->name, - GF_LOG_TRACE, - "validate frame(%p) is " - "waiting for in-transit" - " page = %p", frame, - waiter_page); + gf_msg_trace (frame->this->name, + 0, + "validate " + "frame(%p) is " + "waiting for " + "in-transit" + " page = %p", + frame, + waiter_page); } } ioc_inode_unlock (ioc_inode); @@ -198,8 +202,8 @@ ioc_inode_update (ioc_table_t *table, inode_t *inode, uint32_t weight) } ioc_table_unlock (table); - gf_log (table->xl->name, GF_LOG_TRACE, - "adding to inode_lru[%d]", weight); + gf_msg_trace (table->xl->name, 0, + "adding to inode_lru[%d]", weight); out: return ioc_inode; diff --git a/xlators/performance/io-cache/src/page.c b/xlators/performance/io-cache/src/page.c index 416cd5fe44e..4019ec0a2e6 100644 --- a/xlators/performance/io-cache/src/page.c +++ b/xlators/performance/io-cache/src/page.c @@ -21,7 +21,7 @@ #include "ioc-mem-types.h" #include #include - +#include "io-cache-messages.h" char ioc_empty (struct ioc_cache *cache) { @@ -108,10 +108,10 @@ __ioc_page_destroy (ioc_page_t *page) sizeof (page->offset)); list_del (&page->page_lru); - gf_log (page->inode->table->xl->name, GF_LOG_TRACE, - "destroying page = %p, offset = %"PRId64" " - "&& inode = %p", - page, page->offset, page->inode); + gf_msg_trace (page->inode->table->xl->name, 0, + "destroying page = %p, offset = %"PRId64" " + "&& inode = %p", + page, page->offset, page->inode); if (page->vector){ iobref_unref (page->iobref); @@ -174,10 +174,11 @@ __ioc_inode_prune (ioc_inode_t *curr, uint64_t *size_pruned, if (ret != -1) table->cache_used -= ret; - gf_log (table->xl->name, GF_LOG_TRACE, - "index = %d && table->cache_used = %"PRIu64" && table->" - "cache_size = %"PRIu64, index, table->cache_used, - table->cache_size); + gf_msg_trace (table->xl->name, 0, + "index = %d && " + "table->cache_used = %"PRIu64" && table->" + "cache_size = %"PRIu64, index, table->cache_used, + table->cache_size); if ((*size_pruned) >= size_to_prune) break; @@ -284,8 +285,8 @@ __ioc_page_create (ioc_inode_t *ioc_inode, off_t offset) page = newpage; - gf_log ("io-cache", GF_LOG_TRACE, - "returning new page %p", page); + gf_msg_trace ("io-cache", 0, + "returning new page %p", page); out: return page; @@ -315,7 +316,8 @@ __ioc_wait_on_page (ioc_page_t *page, call_frame_t *frame, off_t offset, if (page == NULL) { local->op_ret = -1; local->op_errno = ENOMEM; - gf_log (frame->this->name, GF_LOG_WARNING, + gf_msg (frame->this->name, GF_LOG_WARNING, + 0, IO_CACHE_MSG_NO_MEMORY, "asked to wait on a NULL page"); goto out; } @@ -327,10 +329,10 @@ __ioc_wait_on_page (ioc_page_t *page, call_frame_t *frame, off_t offset, goto out; } - gf_log (frame->this->name, GF_LOG_TRACE, - "frame(%p) waiting on page = %p, offset=%"PRId64", " - "size=%"GF_PRI_SIZET"", - frame, page, offset, size); + gf_msg_trace (frame->this->name, 0, + "frame(%p) waiting on page = %p, offset=%"PRId64", " + "size=%"GF_PRI_SIZET"", + frame, page, offset, size); waitq->data = frame; waitq->next = page->waitq; @@ -444,9 +446,9 @@ ioc_fault_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (op_ret == -1 || !(zero_filled || ioc_cache_still_valid(ioc_inode, stbuf))) { - gf_log (ioc_inode->table->xl->name, GF_LOG_TRACE, - "cache for inode(%p) is invalid. flushing " - "all pages", ioc_inode); + gf_msg_trace (ioc_inode->table->xl->name, 0, + "cache for inode(%p) is invalid. flushing " + "all pages", ioc_inode); destroy_size = __ioc_inode_flush (ioc_inode); } @@ -464,8 +466,8 @@ ioc_fault_cbk (call_frame_t *frame, void *cookie, xlator_t *this, waitq = __ioc_page_error (page, op_ret, op_errno); } else { - gf_log (ioc_inode->table->xl->name, GF_LOG_TRACE, - "op_ret = %d", op_ret); + gf_msg_trace (ioc_inode->table->xl->name, 0, + "op_ret = %d", op_ret); page = __ioc_page_get (ioc_inode, offset); if (!page) { /* page was flushed */ @@ -500,8 +502,9 @@ ioc_fault_cbk (call_frame_t *frame, void *cookie, xlator_t *this, } else { /* TODO: we have got a response to * our request and no data */ - gf_log (frame->this->name, + gf_msg (frame->this->name, GF_LOG_CRITICAL, + ENOMEM, IO_CACHE_MSG_NO_MEMORY, "frame>root>rsp_refs is null"); } /* if(frame->root->rsp_refs) */ @@ -553,8 +556,8 @@ unlock: ioc_prune (ioc_inode->table); } - gf_log (frame->this->name, GF_LOG_TRACE, "fault frame %p returned", - frame); + gf_msg_trace (frame->this->name, 0, "fault frame %p returned", + frame); pthread_mutex_destroy (&local->local_lock); fd_unref (local->fd); @@ -588,7 +591,8 @@ ioc_page_fault (ioc_inode_t *ioc_inode, call_frame_t *frame, fd_t *fd, if (frame == NULL) { op_ret = -1; op_errno = EINVAL; - gf_log ("io-cache", GF_LOG_WARNING, + gf_msg ("io-cache", GF_LOG_WARNING, + EINVAL, IO_CACHE_MSG_ENFORCEMENT_FAILED, "page fault on a NULL frame"); goto err; } @@ -622,9 +626,9 @@ ioc_page_fault (ioc_inode_t *ioc_inode, call_frame_t *frame, fd_t *fd, fault_local->pending_size = table->page_size; fault_local->inode = ioc_inode; - gf_log (frame->this->name, GF_LOG_TRACE, - "stack winding page fault for offset = %"PRId64" with " - "frame %p", offset, fault_frame); + gf_msg_trace (frame->this->name, 0, + "stack winding page fault for offset = %"PRId64" with " + "frame %p", offset, fault_frame); STACK_WIND (fault_frame, ioc_fault_cbk, FIRST_CHILD(fault_frame->this), FIRST_CHILD(fault_frame->this)->fops->readv, fd, @@ -667,7 +671,8 @@ __ioc_frame_fill (ioc_page_t *page, call_frame_t *frame, off_t offset, GF_VALIDATE_OR_GOTO (frame->this->name, local, out); if (page == NULL) { - gf_log (frame->this->name, GF_LOG_WARNING, + gf_msg (frame->this->name, GF_LOG_WARNING, 0, + IO_CACHE_MSG_ENFORCEMENT_FAILED, "NULL page has been provided to serve read request"); local->op_ret = -1; local->op_errno = EINVAL; @@ -676,10 +681,10 @@ __ioc_frame_fill (ioc_page_t *page, call_frame_t *frame, off_t offset, ioc_inode = page->inode; - gf_log (frame->this->name, GF_LOG_TRACE, - "frame (%p) offset = %"PRId64" && size = %"GF_PRI_SIZET" " - "&& page->size = %"GF_PRI_SIZET" && wait_count = %d", - frame, offset, size, page->size, local->wait_count); + gf_msg_trace (frame->this->name, 0, + "frame (%p) offset = %"PRId64" && size = %"GF_PRI_SIZET" " + "&& page->size = %"GF_PRI_SIZET" && wait_count = %d", + frame, offset, size, page->size, local->wait_count); /* immediately move this page to the end of the page_lru list */ list_move_tail (&page->page_lru, &ioc_inode->cache.page_lru); @@ -713,10 +718,10 @@ __ioc_frame_fill (ioc_page_t *page, call_frame_t *frame, off_t offset, copy_size = src_offset = 0; } - gf_log (page->inode->table->xl->name, GF_LOG_TRACE, - "copy_size = %"GF_PRI_SIZET" && src_offset = " - "%"PRId64" && dst_offset = %"PRId64"", - copy_size, src_offset, dst_offset); + gf_msg_trace (page->inode->table->xl->name, 0, + "copy_size = %"GF_PRI_SIZET" && src_offset = " + "%"PRId64" && dst_offset = %"PRId64"", + copy_size, src_offset, dst_offset); { new = GF_CALLOC (1, sizeof (*new), @@ -814,8 +819,8 @@ ioc_frame_unwind (call_frame_t *frame) local = frame->local; if (local == NULL) { - gf_log (frame->this->name, GF_LOG_WARNING, - "local is NULL"); + gf_msg (frame->this->name, GF_LOG_WARNING, ENOMEM, + IO_CACHE_MSG_NO_MEMORY, "local is NULL"); op_ret = -1; op_errno = ENOMEM; goto unwind; @@ -835,10 +840,10 @@ ioc_frame_unwind (call_frame_t *frame) } if (list_empty (&local->fill_list)) { - gf_log (frame->this->name, GF_LOG_TRACE, - "frame(%p) has 0 entries in local->fill_list " - "(offset = %"PRId64" && size = %"GF_PRI_SIZET")", - frame, local->offset, local->size); + gf_msg_trace (frame->this->name, 0, + "frame(%p) has 0 entries in local->fill_list " + "(offset = %"PRId64" && size = %"GF_PRI_SIZET")", + frame, local->offset, local->size); } list_for_each_entry (fill, &local->fill_list, list) { @@ -876,8 +881,8 @@ ioc_frame_unwind (call_frame_t *frame) } unwind: - gf_log (frame->this->name, GF_LOG_TRACE, - "frame(%p) unwinding with op_ret=%d", frame, op_ret); + gf_msg_trace (frame->this->name, 0, + "frame(%p) unwinding with op_ret=%d", frame, op_ret); // ioc_local_unlock (local); @@ -951,8 +956,8 @@ __ioc_page_wakeup (ioc_page_t *page, int32_t op_errno) page->ready = 1; - gf_log (page->inode->table->xl->name, GF_LOG_TRACE, - "page is %p && waitq = %p", page, waitq); + gf_msg_trace (page->inode->table->xl->name, 0, + "page is %p && waitq = %p", page, waitq); for (trav = waitq; trav; trav = trav->next) { frame = trav->data; @@ -994,8 +999,8 @@ __ioc_page_error (ioc_page_t *page, int32_t op_ret, int32_t op_errno) waitq = page->waitq; page->waitq = NULL; - gf_log (page->inode->table->xl->name, GF_LOG_DEBUG, - "page error for page = %p & waitq = %p", page, waitq); + gf_msg_debug (page->inode->table->xl->name, 0, + "page error for page = %p & waitq = %p", page, waitq); for (trav = waitq; trav; trav = trav->next) { -- cgit