From fd8b19af1713f2800af743d851706b96ca15d9ec Mon Sep 17 00:00:00 2001 From: Raghavendra Bhat Date: Wed, 14 Nov 2012 19:25:14 +0530 Subject: debug/trace: save the recent fops received in the event-history * Make use of event-history in debug/trace xlator to dump the recent fops, when statedump is given. trace xlator saves the fop it received along with the time in the event-history and upon statedump signal, dumps its history. The size of the event-history can be given as a xlator option. * Make changes in trace to take logging into log-file or logging to history as an option. By default both are off. Change-Id: I12baee5805c6efb55735cead4e2093fb94d7a6a0 BUG: 797171 Signed-off-by: Raghavendra Bhat Reviewed-on: http://review.gluster.org/4088 Tested-by: Gluster Build System Reviewed-by: Anand Avati --- xlators/debug/trace/src/Makefile.am | 1 + xlators/debug/trace/src/trace-mem-types.h | 21 + xlators/debug/trace/src/trace.c | 2848 +++++++++++++++++++---------- xlators/debug/trace/src/trace.h | 98 + 4 files changed, 1993 insertions(+), 975 deletions(-) create mode 100644 xlators/debug/trace/src/trace-mem-types.h create mode 100644 xlators/debug/trace/src/trace.h (limited to 'xlators/debug/trace') diff --git a/xlators/debug/trace/src/Makefile.am b/xlators/debug/trace/src/Makefile.am index eb6434a7d..ed970cac0 100644 --- a/xlators/debug/trace/src/Makefile.am +++ b/xlators/debug/trace/src/Makefile.am @@ -7,6 +7,7 @@ trace_la_LDFLAGS = -module -avoidversion trace_la_SOURCES = trace.c trace_la_LIBADD = $(top_builddir)/libglusterfs/src/libglusterfs.la +noinst_HEADERS = trace.h trace-mem-types.h AM_CPPFLAGS = $(GF_CPPFLAGS) -I$(top_srcdir)/libglusterfs/src AM_CFLAGS = -Wall $(GF_CFLAGS) diff --git a/xlators/debug/trace/src/trace-mem-types.h b/xlators/debug/trace/src/trace-mem-types.h new file mode 100644 index 000000000..9fa7d97c2 --- /dev/null +++ b/xlators/debug/trace/src/trace-mem-types.h @@ -0,0 +1,21 @@ +/* + Copyright (c) 2006-2012 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 __TRACE_MEM_TYPES_H__ +#define __TRACE_MEM_TYPES_H__ + +#include "mem-types.h" + +enum gf_trace_mem_types_ { + gf_trace_mt_trace_conf_t = gf_common_mt_end + 1, + gf_trace_mt_end +}; +#endif diff --git a/xlators/debug/trace/src/trace.c b/xlators/debug/trace/src/trace.c index f122498c8..1215dd614 100644 --- a/xlators/debug/trace/src/trace.c +++ b/xlators/debug/trace/src/trace.c @@ -1,16 +1,15 @@ /* - Copyright (c) 2006-2012 Red Hat, Inc. - This file is part of GlusterFS. + Copyright (c) 2006-2012 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. + 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 _CONFIG_H -#define _CONFIG_H -#include "config.h" -#endif + +#include "trace.h" +#include "trace-mem-types.h" /** * xlators/debug/trace : @@ -19,858 +18,977 @@ * Very helpful translator for debugging. */ -#include -#include -#include "glusterfs.h" -#include "xlator.h" -#include "common-utils.h" - - -struct { - char *name; - int enabled; -} trace_fop_names[GF_FOP_MAXVALUE]; - -int trace_log_level = GF_LOG_INFO; - -static char * -trace_stat_to_str (struct iatt *buf) +int +dump_history_trace (circular_buffer_t *cb, void *data) { - char *statstr = NULL; - char atime_buf[64] = {0,}; - char mtime_buf[64] = {0,}; - char ctime_buf[64] = {0,}; - int asprint_ret_value = 0; + char *string = NULL; + struct tm *tm = NULL; + char timestr[256] = {0,}; - if (!buf) { - statstr = NULL; - goto out; - } + string = (char *)cb->data; + tm = localtime (&cb->tv.tv_sec); - gf_time_fmt (atime_buf, sizeof atime_buf, buf->ia_atime, gf_timefmt_bdT); - gf_time_fmt (mtime_buf, sizeof mtime_buf, buf->ia_mtime, gf_timefmt_bdT); - gf_time_fmt (ctime_buf, sizeof ctime_buf, buf->ia_ctime, gf_timefmt_bdT); - asprint_ret_value = gf_asprintf (&statstr, - "gfid=%s ino=%"PRIu64", mode=%o, " - "nlink=%"GF_PRI_NLINK", uid=%u, " - "gid=%u, size=%"PRIu64", " - "blocks=%"PRIu64", atime=%s, " - "mtime=%s, ctime=%s", - uuid_utoa (buf->ia_gfid), buf->ia_ino, - st_mode_from_ia (buf->ia_prot, - buf->ia_type), - buf->ia_nlink, buf->ia_uid, - buf->ia_gid, buf->ia_size, - buf->ia_blocks, atime_buf, - mtime_buf, ctime_buf); + /* Since we are continuing with adding entries to the buffer even when + gettimeofday () fails, it's safe to check tm and then dump the time + at which the entry was added to the buffer */ + if (tm) { + strftime (timestr, 256, "%Y-%m-%d %H:%M:%S", tm); + snprintf (timestr + strlen (timestr), 256 - strlen (timestr), + ".%"GF_PRI_SUSECONDS, cb->tv.tv_usec); + gf_proc_dump_write ("TIME", "%s", timestr); + } - if (asprint_ret_value < 0) - statstr = NULL; + gf_proc_dump_write ("FOP", "%s\n", string); -out: - return statstr; + return 0; } - int trace_create_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, fd_t *fd, inode_t *inode, struct iatt *buf, - struct iatt *preparent, struct iatt *postparent, dict_t *xdata) + struct iatt *preparent, struct iatt *postparent, + dict_t *xdata) { - char *statstr = NULL; - char *preparentstr = NULL; - char *postparentstr = NULL; + char statstr[4096] = {0, }; + char preparentstr[4096] = {0, }; + char postparentstr[4096] = {0, }; + trace_conf_t *conf = NULL; + + conf = this->private; + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_CREATE].enabled) { + char string[4096] = {0,}; if (op_ret >= 0) { - statstr = trace_stat_to_str (buf); - preparentstr = trace_stat_to_str (preparent); - postparentstr = trace_stat_to_str (postparent); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s (op_ret=%d, fd=%p" - "*stbuf {%s}, *preparent {%s}, *postparent = " - "{%s})", frame->root->unique, - uuid_utoa (inode->gfid), op_ret, fd, - statstr, preparentstr, postparentstr); - - GF_FREE (statstr); - GF_FREE (preparentstr); - GF_FREE (postparentstr); + trace_stat_to_str (buf, statstr); + trace_stat_to_str (preparent, preparentstr); + trace_stat_to_str (postparent, postparentstr); + + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s (op_ret=%d, fd=%p" + "*stbuf {%s}, *preparent {%s}, " + "*postparent = {%s})", + frame->root->unique, + uuid_utoa (inode->gfid), op_ret, fd, + statstr, preparentstr, postparentstr); /* for 'release' log */ fd_ctx_set (fd, this, 0); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, op_errno=%d)", - frame->root->unique, op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, op_errno=%d)", + frame->root->unique, op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (create, frame, op_ret, op_errno, fd, inode, buf, - preparent, postparent, xdata); +out: + TRACE_STACK_UNWIND (create, frame, op_ret, op_errno, fd, inode, buf, + preparent, postparent, xdata); return 0; } - int trace_open_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, fd_t *fd, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_OPEN].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d, *fd=%p", - frame->root->unique, uuid_utoa (frame->local), op_ret, op_errno, fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d, " + "*fd=%p", frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno, + fd); + + LOG_ELEMENT (conf, string); } +out: /* for 'release' log */ if (op_ret >= 0) fd_ctx_set (fd, this, 0); - frame->local = NULL; - STACK_UNWIND_STRICT (open, frame, op_ret, op_errno, fd, xdata); + TRACE_STACK_UNWIND (open, frame, op_ret, op_errno, fd, xdata); return 0; } - int trace_stat_cbk (call_frame_t *frame, void *cookie, xlator_t *this, - int32_t op_ret, int32_t op_errno, struct iatt *buf, dict_t *xdata) + int32_t op_ret, int32_t op_errno, struct iatt *buf, + dict_t *xdata) { - char *statstr = NULL; - if (trace_fop_names[GF_FOP_STAT].enabled) { - if (op_ret >= 0) { - statstr = trace_stat_to_str (buf); - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d buf=%s", - frame->root->unique, uuid_utoa (frame->local), - op_ret, statstr); + char statstr[4096] = {0, }; + trace_conf_t *conf = NULL; + + conf = this->private; - GF_FREE (statstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_STAT].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (buf, statstr); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d buf=%s", + frame->root->unique, + uuid_utoa (frame->local), op_ret, + statstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d)", - frame->root->unique, uuid_utoa (frame->local), op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d)", + frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (stat, frame, op_ret, op_errno, buf, xdata); +out: + TRACE_STACK_UNWIND (stat, frame, op_ret, op_errno, buf, xdata); return 0; } - int trace_readv_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iovec *vector, - int32_t count, struct iatt *buf, struct iobref *iobref, dict_t *xdata) + int32_t count, struct iatt *buf, struct iobref *iobref, + dict_t *xdata) { - char *statstr = NULL; + char statstr[4096] = {0, }; + trace_conf_t *conf = NULL; + + conf = this->private; + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_READ].enabled) { + char string[4096] = {0,}; if (op_ret >= 0) { - statstr = trace_stat_to_str (buf); - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d buf=%s", - frame->root->unique, uuid_utoa (frame->local), - op_ret, statstr); - - GF_FREE (statstr); + trace_stat_to_str (buf, statstr); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d buf=%s", + frame->root->unique, + uuid_utoa (frame->local), op_ret, + statstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d)", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d)", + frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (readv, frame, op_ret, op_errno, vector, count, - buf, iobref, xdata); +out: + TRACE_STACK_UNWIND (readv, frame, op_ret, op_errno, vector, count, + buf, iobref, xdata); return 0; } - int trace_writev_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iatt *prebuf, struct iatt *postbuf, dict_t *xdata) { - char *preopstr = NULL; - char *postopstr = NULL; + char preopstr[4096] = {0, }; + char postopstr[4096] = {0, }; + trace_conf_t *conf = NULL; + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_WRITE].enabled) { + char string[4096] = {0,}; if (op_ret >= 0) { - preopstr = trace_stat_to_str (prebuf); - postopstr = trace_stat_to_str (postbuf); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, *prebuf = {%s}, " - "*postbuf = {%s})", - frame->root->unique, op_ret, - preopstr, postopstr); - - GF_FREE (preopstr); - - GF_FREE (postopstr); + trace_stat_to_str (prebuf, preopstr); + trace_stat_to_str (postbuf, postopstr); + + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, " + "*prebuf = {%s}, *postbuf = {%s})", + frame->root->unique, op_ret, + preopstr, postopstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d", frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (writev, frame, op_ret, op_errno, prebuf, postbuf, xdata); +out: + TRACE_STACK_UNWIND (writev, frame, op_ret, op_errno, prebuf, postbuf, + xdata); return 0; } - - int trace_readdir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, - int32_t op_ret, int32_t op_errno, gf_dirent_t *buf, dict_t *xdata) + int32_t op_ret, int32_t op_errno, gf_dirent_t *buf, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_READDIR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64" : gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64" : gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, uuid_utoa (frame->local), + op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (readdir, frame, op_ret, op_errno, buf, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (readdir, frame, op_ret, op_errno, buf, xdata); return 0; } - int trace_readdirp_cbk (call_frame_t *frame, void *cookie, xlator_t *this, - int32_t op_ret, int32_t op_errno, gf_dirent_t *buf, dict_t *xdata) + int32_t op_ret, int32_t op_errno, gf_dirent_t *buf, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_READDIRP].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64" : gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64" : gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, uuid_utoa (frame->local), + op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (readdirp, frame, op_ret, op_errno, buf, xdata); + LOG_ELEMENT (conf, string); + } + TRACE_STACK_UNWIND (readdirp, frame, op_ret, op_errno, buf, xdata); +out: return 0; } - int trace_fsync_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iatt *prebuf, struct iatt *postbuf, dict_t *xdata) { - char *preopstr = NULL; - char *postopstr = NULL; - - if (trace_fop_names[GF_FOP_FSYNC].enabled) { - if (op_ret >= 0) { - preopstr = trace_stat_to_str (prebuf); - postopstr = trace_stat_to_str (postbuf); + char preopstr[4096] = {0, }; + char postopstr[4096] = {0, }; + trace_conf_t *conf = NULL; - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, *prebuf = {%s}, " - "*postbuf = {%s}", - frame->root->unique, op_ret, - preopstr, postopstr); + conf = this->private; - GF_FREE (preopstr); - - GF_FREE (postopstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_FSYNC].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (prebuf, preopstr); + trace_stat_to_str (postbuf, postopstr); + + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, " + "*prebuf = {%s}, *postbuf = {%s}", + frame->root->unique, op_ret, + preopstr, postopstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d", frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); + } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (fsync, frame, op_ret, op_errno, prebuf, postbuf, xdata); +out: + TRACE_STACK_UNWIND (fsync, frame, op_ret, op_errno, prebuf, postbuf, + xdata); return 0; } - int trace_setattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iatt *statpre, struct iatt *statpost, dict_t *xdata) { - char *preopstr = NULL; - char *postopstr = NULL; - - if (trace_fop_names[GF_FOP_SETATTR].enabled) { - if (op_ret >= 0) { - preopstr = trace_stat_to_str (statpre); - postopstr = trace_stat_to_str (statpost); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, *prebuf = {%s}, " - "*postbuf = {%s})", - frame->root->unique, op_ret, - preopstr, postopstr); + char preopstr[4096] = {0, }; + char postopstr[4096] = {0, }; + trace_conf_t *conf = NULL; - GF_FREE (preopstr); + conf = this->private; - GF_FREE (postopstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_SETATTR].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (statpre, preopstr); + trace_stat_to_str (statpost, postopstr); + + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, " + "*prebuf = {%s}, *postbuf = {%s})", + frame->root->unique, op_ret, + preopstr, postopstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d)", - frame->root->unique, uuid_utoa (frame->local), op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d)", frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (setattr, frame, op_ret, op_errno, statpre, statpost, xdata); +out: + TRACE_STACK_UNWIND (setattr, frame, op_ret, op_errno, statpre, + statpost, xdata); return 0; } - int trace_fsetattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iatt *statpre, struct iatt *statpost, dict_t *xdata) { - char *preopstr = NULL; - char *postopstr = NULL; - - if (trace_fop_names[GF_FOP_FSETATTR].enabled) { - if (op_ret >= 0) { - preopstr = trace_stat_to_str (statpre); - postopstr = trace_stat_to_str (statpost); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, *prebuf = {%s}, " - "*postbuf = {%s})", - frame->root->unique, op_ret, - preopstr, postopstr); + char preopstr[4096] = {0, }; + char postopstr[4096] = {0, }; + trace_conf_t *conf = NULL; - GF_FREE (preopstr); + conf = this->private; - GF_FREE (postopstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_FSETATTR].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (statpre, preopstr); + trace_stat_to_str (statpost, postopstr); + + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, " + "*prebuf = {%s}, *postbuf = {%s})", + frame->root->unique, op_ret, + preopstr, postopstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d)", - frame->root->unique, uuid_utoa (frame->local), op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d)", + frame->root->unique, uuid_utoa (frame->local), + op_ret, op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (fsetattr, frame, op_ret, op_errno, - statpre, statpost, xdata); +out: + TRACE_STACK_UNWIND (fsetattr, frame, op_ret, op_errno, + statpre, statpost, xdata); return 0; } - int trace_unlink_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, - struct iatt *preparent, struct iatt *postparent, dict_t *xdata) + struct iatt *preparent, struct iatt *postparent, + dict_t *xdata) { - char *preparentstr = NULL; - char *postparentstr = NULL; - - if (trace_fop_names[GF_FOP_UNLINK].enabled) { - if (op_ret >= 0) { - preparentstr = trace_stat_to_str (preparent); - postparentstr = trace_stat_to_str (postparent); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, *preparent = {%s}, " - "*postparent = {%s})", - frame->root->unique, uuid_utoa (frame->local), op_ret, preparentstr, - postparentstr); + char preparentstr[4096] = {0, }; + char postparentstr[4096] = {0, }; + trace_conf_t *conf = NULL; - GF_FREE (preparentstr); + conf = this->private; - GF_FREE (postparentstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_UNLINK].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (preparent, preparentstr); + trace_stat_to_str (postparent, postparentstr); + + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + " *preparent = {%s}, " + "*postparent = {%s})", + frame->root->unique, + uuid_utoa (frame->local), + op_ret, preparentstr, + postparentstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d)", - frame->root->unique, uuid_utoa (frame->local), op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d)", + frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (unlink, frame, op_ret, op_errno, - preparent, postparent, xdata); +out: + TRACE_STACK_UNWIND (unlink, frame, op_ret, op_errno, + preparent, postparent, xdata); return 0; } - int trace_rename_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iatt *buf, struct iatt *preoldparent, struct iatt *postoldparent, - struct iatt *prenewparent, struct iatt *postnewparent, dict_t *xdata) + struct iatt *prenewparent, struct iatt *postnewparent, + dict_t *xdata) { - char *statstr = NULL; - char *preoldparentstr = NULL; - char *postoldparentstr = NULL; - char *prenewparentstr = NULL; - char *postnewparentstr = NULL; + char statstr[4096] = {0, }; + char preoldparentstr[4096] = {0, }; + char postoldparentstr[4096] = {0, }; + char prenewparentstr[4096] = {0, }; + char postnewparentstr[4096] = {0, }; + trace_conf_t *conf = NULL; - if (trace_fop_names[GF_FOP_RENAME].enabled) { - if (op_ret >= 0) { - statstr = trace_stat_to_str (buf); - preoldparentstr = trace_stat_to_str (preoldparent); - postoldparentstr = trace_stat_to_str (postoldparent); - - prenewparentstr = trace_stat_to_str (prenewparent); - postnewparentstr = trace_stat_to_str (postnewparent); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, *stbuf = {%s}, " - "*preoldparent = {%s}, *postoldparent = {%s}" - " *prenewparent = {%s}, *postnewparent = {%s})", - frame->root->unique, op_ret, statstr, - preoldparentstr, postoldparentstr, - prenewparentstr, postnewparentstr); - - GF_FREE (statstr); - - GF_FREE (preoldparentstr); + conf = this->private; - GF_FREE (postoldparentstr); - - GF_FREE (prenewparentstr); - - GF_FREE (postnewparentstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_RENAME].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (buf, statstr); + trace_stat_to_str (preoldparent, preoldparentstr); + trace_stat_to_str (postoldparent, postoldparentstr); + trace_stat_to_str (prenewparent, prenewparentstr); + trace_stat_to_str (postnewparent, postnewparentstr); + + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, " + "*stbuf = {%s}, *preoldparent = {%s}," + " *postoldparent = {%s}" + " *prenewparent = {%s}, " + "*postnewparent = {%s})", + frame->root->unique, op_ret, statstr, + preoldparentstr, postoldparentstr, + prenewparentstr, postnewparentstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d", frame->root->unique, + uuid_utoa (frame->local), + op_ret, op_errno); + } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (rename, frame, op_ret, op_errno, buf, - preoldparent, postoldparent, - prenewparent, postnewparent, xdata); +out: + TRACE_STACK_UNWIND (rename, frame, op_ret, op_errno, buf, + preoldparent, postoldparent, + prenewparent, postnewparent, xdata); return 0; } - int trace_readlink_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, const char *buf, struct iatt *stbuf, dict_t *xdata) { - char *statstr = NULL; + char statstr[4096] = {0, }; + trace_conf_t *conf = NULL; - if (trace_fop_names[GF_FOP_READLINK].enabled) { + conf = this->private; + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_READLINK].enabled) { + char string[4096] = {0,}; if (op_ret == 0) { - statstr = trace_stat_to_str (stbuf); - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, op_errno=%d, buf=%s, " - "stbuf = { %s })", - frame->root->unique, op_ret, op_errno, buf, - statstr); - } else - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + trace_stat_to_str (stbuf, statstr); + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, op_errno=%d," + "buf=%s, stbuf = { %s })", + frame->root->unique, op_ret, op_errno, + buf, statstr); + } else { + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); + } - GF_FREE (statstr); + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (readlink, frame, op_ret, op_errno, buf, stbuf, xdata); +out: + TRACE_STACK_UNWIND (readlink, frame, op_ret, op_errno, buf, stbuf, + xdata); return 0; } - int trace_lookup_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, inode_t *inode, struct iatt *buf, dict_t *xdata, struct iatt *postparent) { - char *statstr = NULL; - char *postparentstr = NULL; - - if (trace_fop_names[GF_FOP_LOOKUP].enabled) { - if (op_ret >= 0) { - statstr = trace_stat_to_str (buf); - postparentstr = trace_stat_to_str (postparent); + char statstr[4096] = {0, }; + char postparentstr[4096] = {0, }; + trace_conf_t *conf = NULL; - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s (op_ret=%d " - "*buf {%s}, *postparent {%s}", - frame->root->unique, uuid_utoa (inode->gfid), - op_ret, statstr, postparentstr); + conf = this->private; - GF_FREE (statstr); - GF_FREE (postparentstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_LOOKUP].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (buf, statstr); + trace_stat_to_str (postparent, postparentstr); + /* print buf->ia_gfid instead of inode->gfid, + * since if the inode is not yet linked to the + * inode table (fresh lookup) then null gfid + * will be printed. + */ + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s (op_ret=%d " + "*buf {%s}, *postparent {%s}", + frame->root->unique, + uuid_utoa (buf->ia_gfid), + op_ret, statstr, postparentstr); /* For 'forget' */ inode_ctx_put (inode, this, 0); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d)", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d)", + frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (lookup, frame, op_ret, op_errno, inode, buf, - xdata, postparent); +out: + TRACE_STACK_UNWIND (lookup, frame, op_ret, op_errno, inode, buf, + xdata, postparent); return 0; } - int trace_symlink_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, inode_t *inode, struct iatt *buf, - struct iatt *preparent, struct iatt *postparent, dict_t *xdata) + struct iatt *preparent, struct iatt *postparent, + dict_t *xdata) { - char *statstr = NULL; - char *preparentstr = NULL; - char *postparentstr = NULL; - - if (trace_fop_names[GF_FOP_SYMLINK].enabled) { - if (op_ret >= 0) { - statstr = trace_stat_to_str (buf); - preparentstr = trace_stat_to_str (preparent); - postparentstr = trace_stat_to_str (postparent); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s (op_ret=%d " - "*stbuf = {%s}, *preparent = {%s}, " - "*postparent = {%s})", - frame->root->unique, uuid_utoa (inode->gfid), - op_ret, statstr, preparentstr, postparentstr); - - GF_FREE (statstr); - - GF_FREE (preparentstr); + char statstr[4096] = {0, }; + char preparentstr[4096] = {0, }; + char postparentstr[4096] = {0, }; + trace_conf_t *conf = NULL; - GF_FREE (postparentstr); + conf = this->private; + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_SYMLINK].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (buf, statstr); + trace_stat_to_str (preparent, preparentstr); + trace_stat_to_str (postparent, postparentstr); + + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s (op_ret=%d " + "*stbuf = {%s}, *preparent = {%s}, " + "*postparent = {%s})", + frame->root->unique, + uuid_utoa (inode->gfid), + op_ret, statstr, preparentstr, + postparentstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": op_ret=%d, op_errno=%d", - frame->root->unique, op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": op_ret=%d, op_errno=%d", + frame->root->unique, op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (symlink, frame, op_ret, op_errno, inode, buf, - preparent, postparent, xdata); +out: + TRACE_STACK_UNWIND (symlink, frame, op_ret, op_errno, inode, buf, + preparent, postparent, xdata); return 0; } - int trace_mknod_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, inode_t *inode, struct iatt *buf, struct iatt *preparent, struct iatt *postparent, dict_t *xdata) { - char *statstr = NULL; - char *preparentstr = NULL; - char *postparentstr = NULL; + char statstr[4096] = {0, }; + char preparentstr[4096] = {0, }; + char postparentstr[4096] = {0, }; + trace_conf_t *conf = NULL; - if (trace_fop_names[GF_FOP_MKNOD].enabled) { - if (op_ret >= 0) { - statstr = trace_stat_to_str (buf); - preparentstr = trace_stat_to_str (preparent); - postparentstr = trace_stat_to_str (postparent); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s (op_ret=%d " - "*stbuf = {%s}, *preparent = {%s}, " - "*postparent = {%s})", - frame->root->unique, uuid_utoa (inode->gfid), - op_ret, statstr, preparentstr, postparentstr); - - GF_FREE (statstr); + conf = this->private; - GF_FREE (preparentstr); - - GF_FREE (postparentstr); + if (!conf->log_file && !conf->log_history) + goto out; + char string[4096] = {0,}; + if (trace_fop_names[GF_FOP_MKNOD].enabled) { + if (op_ret == 0) { + trace_stat_to_str (buf, statstr); + trace_stat_to_str (preparent, preparentstr); + trace_stat_to_str (postparent, postparentstr); + + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s (op_ret=%d " + "*stbuf = {%s}, *preparent = {%s}, " + "*postparent = {%s})", + frame->root->unique, + uuid_utoa (inode->gfid), + op_ret, statstr, preparentstr, + postparentstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, op_errno=%d)", - frame->root->unique, op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, op_errno=%d)", + frame->root->unique, op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (mknod, frame, op_ret, op_errno, inode, buf, - preparent, postparent, xdata); +out: + TRACE_STACK_UNWIND (mknod, frame, op_ret, op_errno, inode, buf, + preparent, postparent, xdata); return 0; } - int trace_mkdir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, inode_t *inode, struct iatt *buf, struct iatt *preparent, struct iatt *postparent, dict_t *xdata) { - char *statstr = NULL; - char *preparentstr = NULL; - char *postparentstr = NULL; - - if (trace_fop_names[GF_FOP_MKDIR].enabled) { - if (op_ret >= 0) { - statstr = trace_stat_to_str (buf); - preparentstr = trace_stat_to_str (preparent); - postparentstr = trace_stat_to_str (postparent); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s (op_ret=%d " - ", *stbuf = {%s}, *prebuf = {%s}, " - "*postbuf = {%s} )", - frame->root->unique, uuid_utoa (inode->gfid), - op_ret, statstr, preparentstr, postparentstr); - - GF_FREE (statstr); + char statstr[4096] = {0, }; + char preparentstr[4096] = {0, }; + char postparentstr[4096] = {0, }; + trace_conf_t *conf = NULL; - GF_FREE (preparentstr); + conf = this->private; - GF_FREE (postparentstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_MKDIR].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (buf, statstr); + trace_stat_to_str (preparent, preparentstr); + trace_stat_to_str (postparent, postparentstr); + + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s (op_ret=%d " + ", *stbuf = {%s}, *prebuf = {%s}, " + "*postbuf = {%s} )", + frame->root->unique, + uuid_utoa (inode->gfid), + op_ret, statstr, preparentstr, + postparentstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, op_errno=%d)", - frame->root->unique, op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, op_errno=%d)", + frame->root->unique, op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (mkdir, frame, op_ret, op_errno, inode, buf, - preparent, postparent, xdata); +out: + TRACE_STACK_UNWIND (mkdir, frame, op_ret, op_errno, inode, buf, + preparent, postparent, xdata); return 0; } - int trace_link_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, inode_t *inode, struct iatt *buf, struct iatt *preparent, struct iatt *postparent, dict_t *xdata) { - char *statstr = NULL; - char *preparentstr = NULL; - char *postparentstr = NULL; - - if (trace_fop_names[GF_FOP_LINK].enabled) { - if (op_ret >= 0) { - statstr = trace_stat_to_str (buf); - preparentstr = trace_stat_to_str (preparent); - postparentstr = trace_stat_to_str (postparent); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, *stbuf = {%s}, " - " *prebuf = {%s}, *postbuf = {%s})", - frame->root->unique, op_ret, - statstr, preparentstr, postparentstr); + char statstr[4096] = {0, }; + char preparentstr[4096] = {0, }; + char postparentstr[4096] = {0, }; + trace_conf_t *conf = NULL; - GF_FREE (statstr); + conf = this->private; - GF_FREE (preparentstr); - - GF_FREE (postparentstr); + if (!conf->log_file && !conf->log_history) + goto out; + char string[4096] = {0,}; + if (trace_fop_names[GF_FOP_LINK].enabled) { + if (op_ret == 0) { + trace_stat_to_str (buf, statstr); + trace_stat_to_str (preparent, preparentstr); + trace_stat_to_str (postparent, postparentstr); + + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, " + "*stbuf = {%s}, *prebuf = {%s}," + " *postbuf = {%s})", + frame->root->unique, op_ret, + statstr, preparentstr, postparentstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), + op_ret, op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (link, frame, op_ret, op_errno, inode, buf, - preparent, postparent, xdata); +out: + TRACE_STACK_UNWIND (link, frame, op_ret, op_errno, inode, buf, + preparent, postparent, xdata); return 0; } - int trace_flush_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; + char string[4096] = {0,}; if (trace_fop_names[GF_FOP_FLUSH].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); - } + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, uuid_utoa (frame->local), + op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (flush, frame, op_ret, op_errno, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (flush, frame, op_ret, op_errno, xdata); return 0; } - int trace_opendir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, fd_t *fd, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; + char string[4096] = {0,}; if (trace_fop_names[GF_FOP_OPENDIR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d, fd=%p", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno, fd); - } + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d," + " fd=%p", + frame->root->unique, uuid_utoa (frame->local), + op_ret, op_errno, fd); + LOG_ELEMENT (conf, string); + } +out: /* for 'releasedir' log */ if (op_ret >= 0) fd_ctx_set (fd, this, 0); - frame->local = NULL; - STACK_UNWIND_STRICT (opendir, frame, op_ret, op_errno, fd, xdata); + TRACE_STACK_UNWIND (opendir, frame, op_ret, op_errno, fd, xdata); return 0; } - int trace_rmdir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iatt *preparent, struct iatt *postparent, dict_t *xdata) { - char *preparentstr = NULL; - char *postparentstr = NULL; - - if (trace_fop_names[GF_FOP_RMDIR].enabled) { - if (op_ret >= 0) { - preparentstr = trace_stat_to_str (preparent); - postparentstr = trace_stat_to_str (postparent); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, *prebuf = {%s}, " - "*postbuf = {%s}", - frame->root->unique, uuid_utoa (frame->local), - op_ret, preparentstr, postparentstr); + char preparentstr[4096] = {0, }; + char postparentstr[4096] = {0, }; + trace_conf_t *conf = NULL; - GF_FREE (preparentstr); + conf = this->private; - GF_FREE (postparentstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_RMDIR].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (preparent, preparentstr); + trace_stat_to_str (postparent, postparentstr); + + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "*prebuf={%s}, *postbuf={%s}", + frame->root->unique, + uuid_utoa (frame->local), + op_ret, preparentstr, postparentstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d", frame->root->unique, + uuid_utoa (frame->local), + op_ret, op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (rmdir, frame, op_ret, op_errno, - preparent, postparent, xdata); +out: + TRACE_STACK_UNWIND (rmdir, frame, op_ret, op_errno, + preparent, postparent, xdata); return 0; } - int trace_truncate_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iatt *prebuf, struct iatt *postbuf, dict_t *xdata) { - char *preopstr = NULL; - char *postopstr = NULL; + char preopstr[4096] = {0, }; + char postopstr[4096] = {0, }; + trace_conf_t *conf = NULL; - if (trace_fop_names[GF_FOP_TRUNCATE].enabled) { - if (op_ret >= 0) { - preopstr = trace_stat_to_str (prebuf); - postopstr = trace_stat_to_str (postbuf); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, *prebuf = {%s}, " - "*postbuf = {%s} )", - frame->root->unique, op_ret, preopstr, - postopstr); - - GF_FREE (preopstr); + conf = this->private; - GF_FREE (postopstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_TRUNCATE].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (prebuf, preopstr); + trace_stat_to_str (postbuf, postopstr); + + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, " + "*prebuf = {%s}, *postbuf = {%s} )", + frame->root->unique, op_ret, + preopstr, postopstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d", frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (truncate, frame, op_ret, op_errno, prebuf, postbuf, xdata); +out: + TRACE_STACK_UNWIND (truncate, frame, op_ret, op_errno, prebuf, + postbuf, xdata); return 0; } - int trace_statfs_cbk (call_frame_t *frame, void *cookie, xlator_t *this, - int32_t op_ret, int32_t op_errno, struct statvfs *buf, dict_t *xdata) + int32_t op_ret, int32_t op_errno, struct statvfs *buf, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_STATFS].enabled) { - if (op_ret >= 0) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": ({f_bsize=%lu, f_frsize=%lu, f_blocks=%"GF_PRI_FSBLK - ", f_bfree=%"GF_PRI_FSBLK", f_bavail=%"GF_PRI_FSBLK", " - "f_files=%"GF_PRI_FSBLK", f_ffree=%"GF_PRI_FSBLK", f_favail=%" - GF_PRI_FSBLK", f_fsid=%lu, f_flag=%lu, f_namemax=%lu}) => ret=%d", - frame->root->unique, buf->f_bsize, buf->f_frsize, buf->f_blocks, - buf->f_bfree, buf->f_bavail, buf->f_files, buf->f_ffree, - buf->f_favail, buf->f_fsid, buf->f_flag, buf->f_namemax, op_ret); + char string[4096] = {0,}; + if (op_ret == 0) { + snprintf (string, sizeof (string), + "%"PRId64": ({f_bsize=%lu, " + "f_frsize=%lu, " + "f_blocks=%"GF_PRI_FSBLK + ", f_bfree=%"GF_PRI_FSBLK", " + "f_bavail=%"GF_PRI_FSBLK", " + "f_files=%"GF_PRI_FSBLK", " + "f_ffree=%"GF_PRI_FSBLK", " + "f_favail=%"GF_PRI_FSBLK", " + "f_fsid=%lu, f_flag=%lu, " + "f_namemax=%lu}) => ret=%d", + frame->root->unique, buf->f_bsize, + buf->f_frsize, buf->f_blocks, + buf->f_bfree, buf->f_bavail, + buf->f_files, buf->f_ffree, + buf->f_favail, buf->f_fsid, + buf->f_flag, buf->f_namemax, op_ret); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": (op_ret=%d, op_errno=%d)", - frame->root->unique, op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": (op_ret=%d, " + "op_errno=%d)", + frame->root->unique, op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (statfs, frame, op_ret, op_errno, buf, xdata); +out: + TRACE_STACK_UNWIND (statfs, frame, op_ret, op_errno, buf, xdata); return 0; } - int trace_setxattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_SETXATTR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (setxattr, frame, op_ret, op_errno, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (setxattr, frame, op_ret, op_errno, xdata); return 0; } - int trace_getxattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, - int32_t op_ret, int32_t op_errno, dict_t *dict, dict_t *xdata) + int32_t op_ret, int32_t op_errno, dict_t *dict, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_GETXATTR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d, dict=%p", - frame->root->unique, uuid_utoa (frame->local), op_ret, - op_errno, dict); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d," + " dict=%p", frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno, + dict); - frame->local = NULL; - STACK_UNWIND_STRICT (getxattr, frame, op_ret, op_errno, dict, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (getxattr, frame, op_ret, op_errno, dict, xdata); return 0; } @@ -879,32 +997,49 @@ int trace_fsetxattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FSETXATTR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), op_ret, - op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (fsetxattr, frame, op_ret, op_errno, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (fsetxattr, frame, op_ret, op_errno, xdata); return 0; } - int trace_fgetxattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, - int32_t op_ret, int32_t op_errno, dict_t *dict, dict_t *xdata) + int32_t op_ret, int32_t op_errno, dict_t *dict, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FGETXATTR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d, dict=%p", - frame->root->unique, uuid_utoa (frame->local), op_ret, - op_errno, dict); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d," + " dict=%p", frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno, + dict); - frame->local = NULL; - STACK_UNWIND_STRICT (fgetxattr, frame, op_ret, op_errno, dict, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (fgetxattr, frame, op_ret, op_errno, dict, xdata); return 0; } @@ -913,160 +1048,208 @@ int trace_removexattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_REMOVEXATTR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (removexattr, frame, op_ret, op_errno, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (removexattr, frame, op_ret, op_errno, xdata); return 0; } - int trace_fsyncdir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FSYNCDIR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (fsyncdir, frame, op_ret, op_errno, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (fsyncdir, frame, op_ret, op_errno, xdata); return 0; } - int trace_access_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_ACCESS].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d)", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d)", frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (access, frame, op_ret, op_errno, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (access, frame, op_ret, op_errno, xdata); return 0; } - int trace_ftruncate_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iatt *prebuf, struct iatt *postbuf, dict_t *xdata) { - char *prebufstr = NULL; - char *postbufstr = NULL; + char prebufstr[4096] = {0, }; + char postbufstr[4096] = {0, }; + trace_conf_t *conf = NULL; - if (trace_fop_names[GF_FOP_FTRUNCATE].enabled) { - if (op_ret >= 0) { - prebufstr = trace_stat_to_str (prebuf); - postbufstr = trace_stat_to_str (postbuf); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": op_ret=%d, *prebuf = {%s}, " - "*postbuf = {%s} )", - frame->root->unique, op_ret, - prebufstr, postbufstr); - - GF_FREE (prebufstr); - - GF_FREE (postbufstr); + conf = this->private; + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_FTRUNCATE].enabled) { + char string[4096] = {0,}; + if (op_ret == 0) { + trace_stat_to_str (prebuf, prebufstr); + trace_stat_to_str (postbuf, postbufstr); + + snprintf (string, sizeof (string), + "%"PRId64": op_ret=%d, " + "*prebuf = {%s}, *postbuf = {%s} )", + frame->root->unique, op_ret, + prebufstr, postbufstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d", frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (ftruncate, frame, op_ret, op_errno, prebuf, postbuf, xdata); +out: + TRACE_STACK_UNWIND (ftruncate, frame, op_ret, op_errno, prebuf, postbuf, + xdata); return 0; } - int trace_fstat_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, struct iatt *buf, dict_t *xdata) { - char *statstr = NULL; + char statstr[4096] = {0, }; + trace_conf_t *conf = NULL; - if (trace_fop_names[GF_FOP_FSTAT].enabled) { - if (op_ret >= 0) { - statstr = trace_stat_to_str (buf); - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d buf=%s", - frame->root->unique, uuid_utoa (frame->local), - op_ret, statstr); + conf = this->private; - GF_FREE (statstr); + if (!conf->log_file && !conf->log_history) + goto out; + if (trace_fop_names[GF_FOP_FSTAT].enabled) { + char string[4096] = {0.}; + if (op_ret == 0) { + trace_stat_to_str (buf, statstr); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d " + "buf=%s", frame->root->unique, + uuid_utoa (frame->local), op_ret, + statstr); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d", frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); } + LOG_ELEMENT (conf, string); } - - frame->local = NULL; - STACK_UNWIND_STRICT (fstat, frame, op_ret, op_errno, buf, xdata); +out: + TRACE_STACK_UNWIND (fstat, frame, op_ret, op_errno, buf, xdata); return 0; } - int trace_lk_cbk (call_frame_t *frame, void *cookie, xlator_t *this, - int32_t op_ret, int32_t op_errno, struct gf_flock *lock, dict_t *xdata) + int32_t op_ret, int32_t op_errno, struct gf_flock *lock, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_LK].enabled) { - if (op_ret >= 0) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, {l_type=%d, l_whence=%d, " - "l_start=%"PRId64", l_len=%"PRId64", l_pid=%u})", - frame->root->unique, uuid_utoa (frame->local), - op_ret, lock->l_type, lock->l_whence, - lock->l_start, lock->l_len, lock->l_pid); + char string[4096] = {0,}; + if (op_ret == 0) { + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "{l_type=%d, l_whence=%d, " + "l_start=%"PRId64", " + "l_len=%"PRId64", l_pid=%u})", + frame->root->unique, + uuid_utoa (frame->local), + op_ret, lock->l_type, lock->l_whence, + lock->l_start, lock->l_len, + lock->l_pid); } else { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d)", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, " + "op_errno=%d)", frame->root->unique, + uuid_utoa (frame->local), op_ret, + op_errno); } - } - frame->local = NULL; - STACK_UNWIND_STRICT (lk, frame, op_ret, op_errno, lock, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (lk, frame, op_ret, op_errno, lock, xdata); return 0; } - - int trace_entrylk_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_ENTRYLK].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (entrylk, frame, op_ret, op_errno, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (entrylk, frame, op_ret, op_errno, xdata); return 0; } @@ -1074,66 +1257,97 @@ int trace_fentrylk_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FENTRYLK].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (fentrylk, frame, op_ret, op_errno, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (fentrylk, frame, op_ret, op_errno, xdata); return 0; } - int trace_xattrop_cbk (call_frame_t *frame, void *cookie, xlator_t *this, - int32_t op_ret, int32_t op_errno, dict_t *dict, dict_t *xdata) + int32_t op_ret, int32_t op_errno, dict_t *dict, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_XATTROP].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (xattrop, frame, op_ret, op_errno, dict, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (xattrop, frame, op_ret, op_errno, dict, xdata); return 0; } - int trace_fxattrop_cbk (call_frame_t *frame, void *cookie, xlator_t *this, - int32_t op_ret, int32_t op_errno, dict_t *dict, dict_t *xdata) + int32_t op_ret, int32_t op_errno, dict_t *dict, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FXATTROP].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (fxattrop, frame, op_ret, op_errno, dict, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (fxattrop, frame, op_ret, op_errno, dict, xdata); return 0; } - int trace_inodelk_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_INODELK].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), - op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local),op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (inodelk, frame, op_ret, op_errno, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (inodelk, frame, op_ret, op_errno, xdata); return 0; } @@ -1141,32 +1355,51 @@ int trace_finodelk_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FINODELK].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), op_ret, op_errno); - } + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d, op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno); - frame->local = NULL; - STACK_UNWIND_STRICT (finodelk, frame, op_ret, op_errno, xdata); + LOG_ELEMENT (conf, string); + } +out: + TRACE_STACK_UNWIND (finodelk, frame, op_ret, op_errno, xdata); return 0; } - int trace_rchecksum_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int32_t op_ret, int32_t op_errno, - uint32_t weak_checksum, uint8_t *strong_checksum, dict_t *xdata) + uint32_t weak_checksum, uint8_t *strong_checksum, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_RCHECKSUM].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s op_ret=%d op_errno=%d", - frame->root->unique, uuid_utoa (frame->local), op_ret, op_errno); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s op_ret=%d op_errno=%d", + frame->root->unique, + uuid_utoa (frame->local), op_ret, op_errno); + + LOG_ELEMENT (conf, string); } - frame->local = NULL; - STACK_UNWIND_STRICT (rchecksum, frame, op_ret, op_errno, weak_checksum, - strong_checksum, xdata); +out: + TRACE_STACK_UNWIND (rchecksum, frame, op_ret, op_errno, weak_checksum, + strong_checksum, xdata); return 0; } @@ -1178,17 +1411,31 @@ trace_entrylk (call_frame_t *frame, xlator_t *this, const char *volume, loc_t *loc, const char *basename, entrylk_cmd cmd, entrylk_type type, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_ENTRYLK].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s volume=%s, (path=%s basename=%s, " - "cmd=%s, type=%s)", - frame->root->unique, uuid_utoa (loc->inode->gfid), - volume, loc->path, basename, - ((cmd == ENTRYLK_LOCK) ? "ENTRYLK_LOCK" : "ENTRYLK_UNLOCK"), - ((type == ENTRYLK_RDLCK) ? "ENTRYLK_RDLCK" : "ENTRYLK_WRLCK")); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s volume=%s, (path=%s " + "basename=%s, cmd=%s, type=%s)", + frame->root->unique, + uuid_utoa (loc->inode->gfid), + volume, loc->path, basename, + ((cmd == ENTRYLK_LOCK) ? "ENTRYLK_LOCK" : + "ENTRYLK_UNLOCK"), + ((type == ENTRYLK_RDLCK) ? "ENTRYLK_RDLCK" : + "ENTRYLK_WRLCK")); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_entrylk_cbk, FIRST_CHILD (this), FIRST_CHILD (this)->fops->entrylk, @@ -1196,15 +1443,20 @@ trace_entrylk (call_frame_t *frame, xlator_t *this, return 0; } - int trace_inodelk (call_frame_t *frame, xlator_t *this, const char *volume, loc_t *loc, int32_t cmd, struct gf_flock *flock, dict_t *xdata) { - char *cmd_str = NULL; - char *type_str = NULL; + char *cmd_str = NULL; + char *type_str = NULL; + trace_conf_t *conf = NULL; + + conf = this->private; + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_INODELK].enabled) { + char string[4096] = {0,}; switch (cmd) { #if F_GETLK != F_GETLK64 case F_GETLK64: @@ -1247,17 +1499,22 @@ trace_inodelk (call_frame_t *frame, xlator_t *this, const char *volume, break; } - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s volume=%s, (path=%s " - "cmd=%s, type=%s, start=%llu, len=%llu, pid=%llu)", - frame->root->unique, uuid_utoa (loc->inode->gfid), - volume, loc->path, - cmd_str, type_str, (unsigned long long) flock->l_start, - (unsigned long long) flock->l_len, - (unsigned long long) flock->l_pid); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s volume=%s, (path=%s " + "cmd=%s, type=%s, start=%llu, len=%llu, " + "pid=%llu)", frame->root->unique, + uuid_utoa (loc->inode->gfid), volume, + loc->path, cmd_str, type_str, + (unsigned long long)flock->l_start, + (unsigned long long) flock->l_len, + (unsigned long long) flock->l_pid); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_inodelk_cbk, FIRST_CHILD (this), FIRST_CHILD (this)->fops->inodelk, @@ -1265,14 +1522,20 @@ trace_inodelk (call_frame_t *frame, xlator_t *this, const char *volume, return 0; } - int trace_finodelk (call_frame_t *frame, xlator_t *this, const char *volume, fd_t *fd, int32_t cmd, struct gf_flock *flock, dict_t *xdata) { - char *cmd_str = NULL, *type_str = NULL; + char *cmd_str = NULL; + char *type_str = NULL; + trace_conf_t *conf = NULL; + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FINODELK].enabled) { + char string[4096] = {0,}; switch (cmd) { #if F_GETLK != F_GETLK64 case F_GETLK64: @@ -1315,16 +1578,21 @@ trace_finodelk (call_frame_t *frame, xlator_t *this, const char *volume, break; } - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s volume=%s, (fd =%p " - "cmd=%s, type=%s, start=%llu, len=%llu, pid=%llu)", - frame->root->unique, uuid_utoa (fd->inode->gfid), volume, fd, - cmd_str, type_str, (unsigned long long) flock->l_start, - (unsigned long long) flock->l_len, - (unsigned long long) flock->l_pid); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s volume=%s, (fd =%p " + "cmd=%s, type=%s, start=%llu, len=%llu, " + "pid=%llu)", frame->root->unique, + uuid_utoa (fd->inode->gfid), volume, fd, + cmd_str, type_str, + (unsigned long long) flock->l_start, + (unsigned long long) flock->l_len, + (unsigned long long) flock->l_pid); + frame->local = fd->inode->gfid; - } + LOG_ELEMENT (conf, string); + } +out: STACK_WIND (frame, trace_finodelk_cbk, FIRST_CHILD (this), FIRST_CHILD (this)->fops->finodelk, @@ -1332,19 +1600,30 @@ trace_finodelk (call_frame_t *frame, xlator_t *this, const char *volume, return 0; } - int trace_xattrop (call_frame_t *frame, xlator_t *this, loc_t *loc, gf_xattrop_flags_t flags, dict_t *dict, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_XATTROP].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s (path=%s flags=%d)", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, flags); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s (path=%s flags=%d)", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + flags); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_xattrop_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->xattrop, @@ -1353,19 +1632,29 @@ trace_xattrop (call_frame_t *frame, xlator_t *this, loc_t *loc, return 0; } - int trace_fxattrop (call_frame_t *frame, xlator_t *this, fd_t *fd, gf_xattrop_flags_t flags, dict_t *dict, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FXATTROP].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p, flags=%d", - frame->root->unique, uuid_utoa (fd->inode->gfid), - fd, flags); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p, flags=%d", + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd, flags); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_fxattrop_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->fxattrop, @@ -1374,20 +1663,30 @@ trace_fxattrop (call_frame_t *frame, xlator_t *this, fd_t *fd, return 0; } - int trace_lookup (call_frame_t *frame, xlator_t *this, loc_t *loc, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_LOOKUP].enabled) { + char string[4096] = {0,}; /* TODO: print all the keys mentioned in xattr_req */ - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_lookup_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->lookup, @@ -1396,18 +1695,28 @@ trace_lookup (call_frame_t *frame, xlator_t *this, return 0; } - int trace_stat (call_frame_t *frame, xlator_t *this, loc_t *loc, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_STAT].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_stat_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->stat, @@ -1416,18 +1725,30 @@ trace_stat (call_frame_t *frame, xlator_t *this, loc_t *loc, dict_t *xdata) return 0; } - int -trace_readlink (call_frame_t *frame, xlator_t *this, loc_t *loc, size_t size, dict_t *xdata) +trace_readlink (call_frame_t *frame, xlator_t *this, loc_t *loc, size_t size, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_READLINK].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s, size=%"GF_PRI_SIZET")", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, size); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s, " + "size=%"GF_PRI_SIZET")", frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + size); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_readlink_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->readlink, @@ -1436,19 +1757,29 @@ trace_readlink (call_frame_t *frame, xlator_t *this, loc_t *loc, size_t size, di return 0; } - int trace_mknod (call_frame_t *frame, xlator_t *this, loc_t *loc, mode_t mode, dev_t dev, mode_t umask, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_MKNOD].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s mode=0%o umask=0%o " - "dev=%"GF_PRI_DEV")", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, mode, umask, dev); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s mode=%d " + "umask=0%o, dev=%"GF_PRI_DEV")", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + mode, umask, dev); + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_mknod_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->mknod, @@ -1457,18 +1788,28 @@ trace_mknod (call_frame_t *frame, xlator_t *this, loc_t *loc, return 0; } - int trace_mkdir (call_frame_t *frame, xlator_t *this, loc_t *loc, mode_t mode, mode_t umask, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_MKDIR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s mode=0%o umask=0%o", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, mode, umask); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s mode=%d" + " umask=0%o", frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + mode, umask); + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_mkdir_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->mkdir, @@ -1476,19 +1817,29 @@ trace_mkdir (call_frame_t *frame, xlator_t *this, loc_t *loc, mode_t mode, return 0; } - int trace_unlink (call_frame_t *frame, xlator_t *this, loc_t *loc, int xflag, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_UNLINK].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s flag=%d", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, xflag); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s flag=%d", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + xflag); + frame->local = loc->inode->gfid; - } + LOG_ELEMENT (conf, string); + } +out: STACK_WIND (frame, trace_unlink_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->unlink, @@ -1496,19 +1847,30 @@ trace_unlink (call_frame_t *frame, xlator_t *this, loc_t *loc, int xflag, return 0; } - int trace_rmdir (call_frame_t *frame, xlator_t *this, loc_t *loc, int flags, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_RMDIR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s flags=%d", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, flags); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s flags=%d", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + flags); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_rmdir_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->rmdir, @@ -1517,18 +1879,28 @@ trace_rmdir (call_frame_t *frame, xlator_t *this, loc_t *loc, int flags, return 0; } - int trace_symlink (call_frame_t *frame, xlator_t *this, const char *linkpath, loc_t *loc, mode_t umask, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_SYMLINK].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s linkpath=%s, path=%s umask=0%o", - frame->root->unique, uuid_utoa (loc->inode->gfid), - linkpath, loc->path, umask); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s linkpath=%s, path=%s" + " umask=0%o", frame->root->unique, + uuid_utoa (loc->inode->gfid), linkpath, + loc->path, umask); + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_symlink_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->symlink, @@ -1537,15 +1909,20 @@ trace_symlink (call_frame_t *frame, xlator_t *this, const char *linkpath, return 0; } - int trace_rename (call_frame_t *frame, xlator_t *this, loc_t *oldloc, loc_t *newloc, dict_t *xdata) { - char oldgfid[50] = {0,}; - char newgfid[50] = {0,}; + char oldgfid[50] = {0,}; + char newgfid[50] = {0,}; + trace_conf_t *conf = NULL; + + conf = this->private; + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_RENAME].enabled) { + char string[4096] = {0,}; if (newloc->inode) uuid_utoa_r (newloc->inode->gfid, newgfid); else @@ -1553,13 +1930,18 @@ trace_rename (call_frame_t *frame, xlator_t *this, loc_t *oldloc, loc_t *newloc, uuid_utoa_r (oldloc->inode->gfid, oldgfid); - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": oldgfid=%s oldpath=%s --> newgfid=%s newpath=%s", - frame->root->unique, oldgfid, oldloc->path, newgfid, newloc->path); + snprintf (string, sizeof (string), + "%"PRId64": oldgfid=%s oldpath=%s --> " + "newgfid=%s newpath=%s", + frame->root->unique, oldgfid, + oldloc->path, newgfid, newloc->path); frame->local = oldloc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_rename_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->rename, @@ -1568,15 +1950,20 @@ trace_rename (call_frame_t *frame, xlator_t *this, loc_t *oldloc, loc_t *newloc, return 0; } - int trace_link (call_frame_t *frame, xlator_t *this, loc_t *oldloc, loc_t *newloc, dict_t *xdata) { - char oldgfid[50] = {0,}; - char newgfid[50] = {0,}; + char oldgfid[50] = {0,}; + char newgfid[50] = {0,}; + trace_conf_t *conf = NULL; + + conf = this->private; + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_LINK].enabled) { + char string[4096] = {0,}; if (newloc->inode) uuid_utoa_r (newloc->inode->gfid, newgfid); else @@ -1584,13 +1971,18 @@ trace_link (call_frame_t *frame, xlator_t *this, loc_t *oldloc, loc_t *newloc, uuid_utoa_r (oldloc->inode->gfid, oldgfid); - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": oldgfid=%s oldpath=%s --> newgfid=%s newpath=%s", - frame->root->unique, oldgfid, oldloc->path, - newgfid, newloc->path); + snprintf (string, sizeof (string), + "%"PRId64": oldgfid=%s oldpath=%s --> " + "newgfid=%s newpath=%s", frame->root->unique, + oldgfid, oldloc->path, newgfid, + newloc->path); + frame->local = oldloc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_link_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->link, @@ -1598,43 +1990,69 @@ trace_link (call_frame_t *frame, xlator_t *this, loc_t *oldloc, loc_t *newloc, return 0; } - int trace_setattr (call_frame_t *frame, xlator_t *this, loc_t *loc, struct iatt *stbuf, int32_t valid, dict_t *xdata) { - char actime_str[64] = {0,}; - char modtime_str[64] = {0,}; + uint64_t ia_time = 0; + char actime_str[256] = {0,}; + char modtime_str[256] = {0,}; + trace_conf_t *conf = NULL; + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_SETATTR].enabled) { + char string[4096] = {0,}; if (valid & GF_SET_ATTR_MODE) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s mode=%o)", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, st_mode_from_ia (stbuf->ia_prot, stbuf->ia_type)); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s mode=%o)", + frame->root->unique, + uuid_utoa (loc->inode->gfid), + loc->path, + st_mode_from_ia (stbuf->ia_prot, + stbuf->ia_type)); + + LOG_ELEMENT (conf, string); + memset (string, 0 , sizeof (string)); } if (valid & (GF_SET_ATTR_UID | GF_SET_ATTR_GID)) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s uid=%o, gid=%o", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, stbuf->ia_uid, stbuf->ia_gid); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s uid=%o," + " gid=%o", frame->root->unique, + uuid_utoa (loc->inode->gfid), + loc->path, stbuf->ia_uid, + stbuf->ia_gid); + + LOG_ELEMENT (conf, string); + memset (string, 0 , sizeof (string)); } if (valid & (GF_SET_ATTR_ATIME | GF_SET_ATTR_MTIME)) { - gf_time_fmt (actime_str, sizeof actime_str, - stbuf->ia_atime, gf_timefmt_bdT); - gf_time_fmt (modtime_str, sizeof modtime_str, - stbuf->ia_mtime, gf_timefmt_bdT); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s ia_atime=%s, ia_mtime=%s", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, actime_str, modtime_str); + ia_time = stbuf->ia_atime; + strftime (actime_str, 256, "[%b %d %H:%M:%S]", + localtime ((time_t *)&ia_time)); + + ia_time = stbuf->ia_mtime; + strftime (modtime_str, 256, "[%b %d %H:%M:%S]", + localtime ((time_t *)&ia_time)); + + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s " + "ia_atime=%s, ia_mtime=%s", + frame->root->unique, + uuid_utoa (loc->inode->gfid), + loc->path, actime_str, modtime_str); + + LOG_ELEMENT (conf, string); + memset (string, 0 , sizeof (string)); } frame->local = loc->inode->gfid; } +out: STACK_WIND (frame, trace_setattr_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->setattr, @@ -1643,43 +2061,67 @@ trace_setattr (call_frame_t *frame, xlator_t *this, loc_t *loc, return 0; } - int trace_fsetattr (call_frame_t *frame, xlator_t *this, fd_t *fd, struct iatt *stbuf, int32_t valid, dict_t *xdata) { - char actime_str[64] = {0,}; - char modtime_str[64] = {0,}; + uint64_t ia_time = 0; + char actime_str[256] = {0,}; + char modtime_str[256] = {0,}; + trace_conf_t *conf = NULL; + + conf = this->private; + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FSETATTR].enabled) { + char string[4096] = {0,}; if (valid & GF_SET_ATTR_MODE) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p, mode=%o", - frame->root->unique, uuid_utoa (fd->inode->gfid), fd, - st_mode_from_ia (stbuf->ia_prot, stbuf->ia_type)); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p, mode=%o", + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd, + st_mode_from_ia (stbuf->ia_prot, + stbuf->ia_type)); + + LOG_ELEMENT (conf, string); + memset (string, 0, sizeof (string)); } if (valid & (GF_SET_ATTR_UID | GF_SET_ATTR_GID)) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p, uid=%o, gid=%o", - frame->root->unique, uuid_utoa (fd->inode->gfid), - fd, stbuf->ia_uid, stbuf->ia_gid); + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p, uid=%o, " + "gid=%o", frame->root->unique, + uuid_utoa (fd->inode->gfid), + fd, stbuf->ia_uid, stbuf->ia_gid); + + LOG_ELEMENT (conf, string); + memset (string, 0, sizeof (string)); } if (valid & (GF_SET_ATTR_ATIME | GF_SET_ATTR_MTIME)) { - gf_time_fmt (actime_str, sizeof actime_str, - stbuf->ia_atime, gf_timefmt_bdT); - gf_time_fmt (modtime_str, sizeof modtime_str, - stbuf->ia_mtime, gf_timefmt_bdT); - - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p ia_atime=%s, ia_mtime=%s", - frame->root->unique, uuid_utoa (fd->inode->gfid), - fd, actime_str, modtime_str); + ia_time = stbuf->ia_atime; + strftime (actime_str, 256, "[%b %d %H:%M:%S]", + localtime ((time_t *)&ia_time)); + + ia_time = stbuf->ia_mtime; + strftime (modtime_str, 256, "[%b %d %H:%M:%S]", + localtime ((time_t *)&ia_time)); + + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p " + "ia_atime=%s, ia_mtime=%s", + frame->root->unique, + uuid_utoa (fd->inode->gfid), + fd, actime_str, modtime_str); + + LOG_ELEMENT (conf, string); + memset (string, 0, sizeof (string)); } frame->local = fd->inode->gfid; } +out: STACK_WIND (frame, trace_fsetattr_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->fsetattr, @@ -1688,19 +2130,30 @@ trace_fsetattr (call_frame_t *frame, xlator_t *this, fd_t *fd, return 0; } - int trace_truncate (call_frame_t *frame, xlator_t *this, loc_t *loc, off_t offset, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_TRUNCATE].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s, offset=%"PRId64"", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, offset); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s, " + "offset=%"PRId64"", frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + offset); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_truncate_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->truncate, @@ -1709,19 +2162,30 @@ trace_truncate (call_frame_t *frame, xlator_t *this, loc_t *loc, return 0; } - int trace_open (call_frame_t *frame, xlator_t *this, loc_t *loc, int32_t flags, fd_t *fd, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_OPEN].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s flags=%d fd=%p", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, flags, fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s flags=%d fd=%p", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + flags, fd); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_open_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->open, @@ -1729,42 +2193,62 @@ trace_open (call_frame_t *frame, xlator_t *this, loc_t *loc, return 0; } - int trace_create (call_frame_t *frame, xlator_t *this, loc_t *loc, int32_t flags, mode_t mode, mode_t umask, fd_t *fd, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_CREATE].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s fd=%p flags=0%o mode=0%o " - "umask=0%o", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, fd, flags, mode, umask); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s, fd=%p, " + "flags=0%o mode=0%o umask=0%o", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + fd, flags, mode, umask); + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_create_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->create, loc, flags, mode, umask, fd, xdata); - return 0; } - int trace_readv (call_frame_t *frame, xlator_t *this, fd_t *fd, size_t size, off_t offset, uint32_t flags, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_READ].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p, size=%"GF_PRI_SIZET", " - "offset=%"PRId64" flags=0%x)", - frame->root->unique, uuid_utoa (fd->inode->gfid), - fd, size, offset, flags); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p, size=%" + GF_PRI_SIZET"offset=%"PRId64" flags=0%x)", + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd, size, + offset, flags); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_readv_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->readv, @@ -1772,21 +2256,32 @@ trace_readv (call_frame_t *frame, xlator_t *this, fd_t *fd, return 0; } - int trace_writev (call_frame_t *frame, xlator_t *this, fd_t *fd, struct iovec *vector, int32_t count, off_t offset, uint32_t flags, struct iobref *iobref, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_WRITE].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p, count=%d, offset=%"PRId64 - " flag=0%x)", - frame->root->unique, uuid_utoa (fd->inode->gfid), - fd, count, offset, flags); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p, count=%d, " + " offset=%"PRId64" flags=0%x)", + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd, count, + offset, flags); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_writev_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->writev, @@ -1794,17 +2289,26 @@ trace_writev (call_frame_t *frame, xlator_t *this, fd_t *fd, return 0; } - int trace_statfs (call_frame_t *frame, xlator_t *this, loc_t *loc, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_STATFS].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s", - frame->root->unique, (loc->inode)? - uuid_utoa (loc->inode->gfid):"0", loc->path); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s", + frame->root->unique, (loc->inode)? + uuid_utoa (loc->inode->gfid):"0", loc->path); + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_statfs_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->statfs, @@ -1812,17 +2316,28 @@ trace_statfs (call_frame_t *frame, xlator_t *this, loc_t *loc, dict_t *xdata) return 0; } - int trace_flush (call_frame_t *frame, xlator_t *this, fd_t *fd, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FLUSH].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p", - frame->root->unique, uuid_utoa (fd->inode->gfid), fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p", + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_flush_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->flush, @@ -1830,17 +2345,29 @@ trace_flush (call_frame_t *frame, xlator_t *this, fd_t *fd, dict_t *xdata) return 0; } - int -trace_fsync (call_frame_t *frame, xlator_t *this, fd_t *fd, int32_t flags, dict_t *xdata) +trace_fsync (call_frame_t *frame, xlator_t *this, fd_t *fd, int32_t flags, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FSYNC].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s flags=%d fd=%p", - frame->root->unique, uuid_utoa (fd->inode->gfid), flags, fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s flags=%d fd=%p", + frame->root->unique, + uuid_utoa (fd->inode->gfid), flags, fd); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_fsync_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->fsync, @@ -1848,19 +2375,30 @@ trace_fsync (call_frame_t *frame, xlator_t *this, fd_t *fd, int32_t flags, dict_ return 0; } - int trace_setxattr (call_frame_t *frame, xlator_t *this, loc_t *loc, dict_t *dict, int32_t flags, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_SETXATTR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s flags=%d", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, flags); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s flags=%d", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + flags); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_setxattr_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->setxattr, @@ -1868,19 +2406,30 @@ trace_setxattr (call_frame_t *frame, xlator_t *this, return 0; } - int trace_getxattr (call_frame_t *frame, xlator_t *this, loc_t *loc, const char *name, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_GETXATTR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s name=%s", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, name); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s name=%s", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + name); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_getxattr_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->getxattr, @@ -1888,19 +2437,30 @@ trace_getxattr (call_frame_t *frame, xlator_t *this, return 0; } - int trace_removexattr (call_frame_t *frame, xlator_t *this, loc_t *loc, const char *name, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_REMOVEXATTR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s name=%s", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, name); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s name=%s", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, + name); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_removexattr_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->removexattr, @@ -1909,18 +2469,29 @@ trace_removexattr (call_frame_t *frame, xlator_t *this, return 0; } - int -trace_opendir (call_frame_t *frame, xlator_t *this, loc_t *loc, fd_t *fd, dict_t *xdata) +trace_opendir (call_frame_t *frame, xlator_t *this, loc_t *loc, fd_t *fd, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_OPENDIR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s fd=%p", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s fd=%p", + frame->root->unique, + uuid_utoa (loc->inode->gfid), loc->path, fd); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_opendir_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->opendir, @@ -1932,15 +2503,27 @@ int trace_readdirp (call_frame_t *frame, xlator_t *this, fd_t *fd, size_t size, off_t offset, dict_t *dict) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_READDIRP].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p, size=%"GF_PRI_SIZET", " - "offset=%"PRId64" dict=%p", - frame->root->unique, uuid_utoa (fd->inode->gfid), - fd, size, offset, dict); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p, size=%"GF_PRI_SIZET + ", offset=%"PRId64" dict=%p", + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd, size, + offset, dict); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_readdirp_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->readdirp, @@ -1949,19 +2532,31 @@ trace_readdirp (call_frame_t *frame, xlator_t *this, fd_t *fd, size_t size, return 0; } - int trace_readdir (call_frame_t *frame, xlator_t *this, fd_t *fd, size_t size, off_t offset, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_READDIR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p, size=%"GF_PRI_SIZET", offset=%"PRId64, - frame->root->unique, uuid_utoa (fd->inode->gfid), - fd, size, offset); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p, size=%"GF_PRI_SIZET + ", offset=%"PRId64, + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd, size, + offset); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_readdir_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->readdir, @@ -1970,19 +2565,29 @@ trace_readdir (call_frame_t *frame, xlator_t *this, fd_t *fd, return 0; } - int trace_fsyncdir (call_frame_t *frame, xlator_t *this, fd_t *fd, int32_t datasync, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FSYNCDIR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s datasync=%d fd=%p", - frame->root->unique, uuid_utoa (fd->inode->gfid), - datasync, fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s datasync=%d fd=%p", + frame->root->unique, + uuid_utoa (fd->inode->gfid), datasync, fd); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_fsyncdir_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->fsyncdir, @@ -1990,18 +2595,30 @@ trace_fsyncdir (call_frame_t *frame, xlator_t *this, return 0; } - int -trace_access (call_frame_t *frame, xlator_t *this, loc_t *loc, int32_t mask, dict_t *xdata) +trace_access (call_frame_t *frame, xlator_t *this, loc_t *loc, int32_t mask, + dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_ACCESS].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s path=%s mask=0%o", - frame->root->unique, uuid_utoa (loc->inode->gfid), - loc->path, mask); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s path=%s mask=0%o", + frame->root->unique, + uuid_utoa (loc->inode->gfid), + loc->path, mask); + frame->local = loc->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_access_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->access, @@ -2009,19 +2626,30 @@ trace_access (call_frame_t *frame, xlator_t *this, loc_t *loc, int32_t mask, dic return 0; } - int32_t trace_rchecksum (call_frame_t *frame, xlator_t *this, fd_t *fd, off_t offset, int32_t len, dict_t *xdata) { + + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_RCHECKSUM].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s offset=%"PRId64" len=%u fd=%p", - frame->root->unique, uuid_utoa (fd->inode->gfid), - offset, len, fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s offset=%"PRId64 + "len=%u fd=%p", frame->root->unique, + uuid_utoa (fd->inode->gfid), offset, len, fd); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_rchecksum_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->rchecksum, @@ -2036,17 +2664,31 @@ trace_fentrylk (call_frame_t *frame, xlator_t *this, const char *volume, fd_t *fd, const char *basename, entrylk_cmd cmd, entrylk_type type, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FENTRYLK].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s volume=%s, (fd=%p basename=%s, " - "cmd=%s, type=%s)", - frame->root->unique, uuid_utoa (fd->inode->gfid), - volume, fd, basename, - ((cmd == ENTRYLK_LOCK) ? "ENTRYLK_LOCK" : "ENTRYLK_UNLOCK"), - ((type == ENTRYLK_RDLCK) ? "ENTRYLK_RDLCK" : "ENTRYLK_WRLCK")); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s volume=%s, (fd=%p " + "basename=%s, cmd=%s, type=%s)", + frame->root->unique, + uuid_utoa (fd->inode->gfid), volume, fd, + basename, + ((cmd == ENTRYLK_LOCK) ? "ENTRYLK_LOCK" : + "ENTRYLK_UNLOCK"), + ((type == ENTRYLK_RDLCK) ? "ENTRYLK_RDLCK" : + "ENTRYLK_WRLCK")); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_fentrylk_cbk, FIRST_CHILD (this), FIRST_CHILD (this)->fops->fentrylk, @@ -2059,14 +2701,25 @@ int32_t trace_fgetxattr (call_frame_t *frame, xlator_t *this, fd_t *fd, const char *name, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FGETXATTR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p name=%s", - frame->root->unique, uuid_utoa (fd->inode->gfid), - fd, name); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p name=%s", + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd, name); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_fgetxattr_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->fgetxattr, @@ -2078,14 +2731,25 @@ int32_t trace_fsetxattr (call_frame_t *frame, xlator_t *this, fd_t *fd, dict_t *dict, int32_t flags, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FSETXATTR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p flags=%d", - frame->root->unique, uuid_utoa (fd->inode->gfid), - fd, flags); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p flags=%d", + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd, flags); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_fsetxattr_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->fsetxattr, @@ -2097,14 +2761,25 @@ int trace_ftruncate (call_frame_t *frame, xlator_t *this, fd_t *fd, off_t offset, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FTRUNCATE].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s offset=%"PRId64" fd=%p", - frame->root->unique, uuid_utoa (fd->inode->gfid), - offset, fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s offset=%"PRId64" fd=%p", + frame->root->unique, + uuid_utoa (fd->inode->gfid), offset, fd); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_ftruncate_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->ftruncate, @@ -2113,17 +2788,28 @@ trace_ftruncate (call_frame_t *frame, xlator_t *this, return 0; } - int trace_fstat (call_frame_t *frame, xlator_t *this, fd_t *fd, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_FSTAT].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p", - frame->root->unique, uuid_utoa (fd->inode->gfid), fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p", + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_fstat_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->fstat, @@ -2131,21 +2817,34 @@ trace_fstat (call_frame_t *frame, xlator_t *this, fd_t *fd, dict_t *xdata) return 0; } - int trace_lk (call_frame_t *frame, xlator_t *this, fd_t *fd, int32_t cmd, struct gf_flock *lock, dict_t *xdata) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_LK].enabled) { - gf_log (this->name, GF_LOG_INFO, - "%"PRId64": gfid=%s fd=%p, cmd=%d, lock {l_type=%d, l_whence=%d, " - "l_start=%"PRId64", l_len=%"PRId64", l_pid=%u})", - frame->root->unique, uuid_utoa (fd->inode->gfid), fd, - cmd, lock->l_type, lock->l_whence, - lock->l_start, lock->l_len, lock->l_pid); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "%"PRId64": gfid=%s fd=%p, cmd=%d, " + "lock {l_type=%d, " + "l_whence=%d, l_start=%"PRId64", " + "l_len=%"PRId64", l_pid=%u})", + frame->root->unique, + uuid_utoa (fd->inode->gfid), fd, cmd, + lock->l_type, lock->l_whence, + lock->l_start, lock->l_len, lock->l_pid); + frame->local = fd->inode->gfid; + + LOG_ELEMENT (conf, string); } +out: STACK_WIND (frame, trace_lk_cbk, FIRST_CHILD(this), FIRST_CHILD(this)->fops->lk, @@ -2156,40 +2855,71 @@ trace_lk (call_frame_t *frame, xlator_t *this, fd_t *fd, int32_t trace_forget (xlator_t *this, inode_t *inode) { + trace_conf_t *conf = NULL; + + conf = this->private; /* If user want to understand when a lookup happens, he should know about 'forget' too */ + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_LOOKUP].enabled) { - gf_log (this->name, GF_LOG_INFO, - "gfid=%s", uuid_utoa (inode->gfid)); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "gfid=%s", uuid_utoa (inode->gfid)); + + LOG_ELEMENT (conf, string); } + +out: return 0; } - int32_t trace_releasedir (xlator_t *this, fd_t *fd) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_OPENDIR].enabled) { - gf_log (this->name, GF_LOG_INFO, - "gfid=%s fd=%p", uuid_utoa (fd->inode->gfid), fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "gfid=%s fd=%p", + uuid_utoa (fd->inode->gfid), fd); + + LOG_ELEMENT (conf, string); } +out: return 0; } int32_t trace_release (xlator_t *this, fd_t *fd) { + trace_conf_t *conf = NULL; + + conf = this->private; + + if (!conf->log_file && !conf->log_history) + goto out; if (trace_fop_names[GF_FOP_OPEN].enabled || trace_fop_names[GF_FOP_CREATE].enabled) { - gf_log (this->name, GF_LOG_INFO, - "gfid=%s fd=%p", uuid_utoa (fd->inode->gfid), fd); + char string[4096] = {0,}; + snprintf (string, sizeof (string), + "gfid=%s fd=%p", + uuid_utoa (fd->inode->gfid), fd); + + LOG_ELEMENT (conf, string); } + +out: return 0; } - void enable_all_calls (int enabled) { @@ -2199,7 +2929,6 @@ enable_all_calls (int enabled) trace_fop_names[i].enabled = enabled; } - void enable_call (const char *name, int enabled) { @@ -2227,6 +2956,105 @@ process_call_list (const char *list, int include) } } +int32_t +trace_dump_history (xlator_t *this) +{ + int ret = -1; + char key_prefix[GF_DUMP_MAX_BUF_LEN] = {0,}; + trace_conf_t *conf = NULL; + + GF_VALIDATE_OR_GOTO ("trace", this, out); + GF_VALIDATE_OR_GOTO (this->name, this->history, out); + + conf = this->private; + // Is it ok to return silently if log-history option his off? + if (conf && conf->log_history == _gf_true) { + gf_proc_dump_build_key (key_prefix, "xlator.debug.trace", + "history"); + gf_proc_dump_add_section (key_prefix); + eh_dump (this->history, NULL, dump_history_trace); + } + ret = 0; + +out: + return ret; +} + +int32_t +mem_acct_init (xlator_t *this) +{ + int ret = -1; + + if (!this) + return ret; + + ret = xlator_mem_acct_init (this, gf_trace_mt_end + 1); + + if (ret != 0) { + gf_log (this->name, GF_LOG_ERROR, "Memory accounting init" + " failed"); + return ret; + } + + return ret; +} + +int +reconfigure (xlator_t *this, dict_t *options) +{ + int32_t ret = -1; + trace_conf_t *conf = NULL; + char *includes = NULL, *excludes = NULL; + + GF_VALIDATE_OR_GOTO ("quick-read", this, out); + GF_VALIDATE_OR_GOTO (this->name, this->private, out); + GF_VALIDATE_OR_GOTO (this->name, options, out); + + conf = this->private; + + includes = data_to_str (dict_get (options, "include-ops")); + excludes = data_to_str (dict_get (options, "exclude-ops")); + + { + int i; + for (i = 0; i < GF_FOP_MAXVALUE; i++) { + if (gf_fop_list[i]) + strncpy (trace_fop_names[i].name, + gf_fop_list[i], + strlen (gf_fop_list[i])); + else + strncpy (trace_fop_names[i].name, ":O", + strlen (":O")); + trace_fop_names[i].enabled = 1; + } + } + + if (includes && excludes) { + gf_log (this->name, + GF_LOG_ERROR, + "must specify only one of 'include-ops' and " + "'exclude-ops'"); + goto out; + } + + if (includes) + process_call_list (includes, 1); + if (excludes) + process_call_list (excludes, 0); + + /* Should resizing of the event-history be allowed in reconfigure? + * for which a new event_history might have to be allocated and the + * older history has to be freed. + */ + GF_OPTION_RECONF ("log-file", conf->log_file, options, bool, out); + + GF_OPTION_RECONF ("log-history", conf->log_history, options, bool, out); + + ret = 0; + +out: + return ret; +} int32_t init (xlator_t *this) @@ -2234,6 +3062,10 @@ init (xlator_t *this) dict_t *options = NULL; char *includes = NULL, *excludes = NULL; char *forced_loglevel = NULL; + eh_t *history = NULL; + int ret = -1; + size_t history_size = TRACE_DEFAULT_HISTORY_SIZE; + trace_conf_t *conf = NULL; if (!this) return -1; @@ -2248,6 +3080,12 @@ init (xlator_t *this) "dangling volume. check volfile "); } + conf = GF_CALLOC (1, sizeof (trace_conf_t), gf_trace_mt_trace_conf_t); + if (!conf) { + gf_log (this->name, GF_LOG_ERROR, "cannot allocate " + "xl->private"); + return -1; + } options = this->options; includes = data_to_str (dict_get (options, "include-ops")); @@ -2256,9 +3094,13 @@ init (xlator_t *this) { int i; for (i = 0; i < GF_FOP_MAXVALUE; i++) { - trace_fop_names[i].name = (gf_fop_list[i] ? - (char *)gf_fop_list[i] : - ":O"); + if (gf_fop_list[i]) + strncpy (trace_fop_names[i].name, + gf_fop_list[i], + strlen (gf_fop_list[i])); + else + strncpy (trace_fop_names[i].name, ":O", + strlen (":O")); trace_fop_names[i].enabled = 1; } } @@ -2266,14 +3108,43 @@ init (xlator_t *this) if (includes && excludes) { gf_log (this->name, GF_LOG_ERROR, - "must specify only one of 'include-ops' and 'exclude-ops'"); + "must specify only one of 'include-ops' and " + "'exclude-ops'"); return -1; } + if (includes) process_call_list (includes, 1); if (excludes) process_call_list (excludes, 0); + + GF_OPTION_INIT ("history-size", conf->history_size, size, out); + + gf_log (this->name, GF_LOG_INFO, "history size %"GF_PRI_SIZET, + history_size); + + GF_OPTION_INIT ("log-file", conf->log_file, bool, out); + + gf_log (this->name, GF_LOG_INFO, "logging to file %s", + (conf->log_file == _gf_true)?"enabled":"disabled"); + + GF_OPTION_INIT ("log-history", conf->log_history, bool, out); + + gf_log (this->name, GF_LOG_DEBUG, "logging to history %s", + (conf->log_history == _gf_true)?"enabled":"disabled"); + + history = eh_new (history_size, _gf_false); + if (!history) { + gf_log (this->name, GF_LOG_ERROR, "event history cannot be " + "initialized"); + return -1; + } + + this->history = history; + + conf->trace_log_level = GF_LOG_INFO; + if (dict_get (options, "force-log-level")) { forced_loglevel = data_to_str (dict_get (options, "force-log-level")); @@ -2281,25 +3152,34 @@ init (xlator_t *this) goto setloglevel; if (strcmp (forced_loglevel, "INFO") == 0) - trace_log_level = GF_LOG_INFO; + conf->trace_log_level = GF_LOG_INFO; else if (strcmp (forced_loglevel, "TRACE") == 0) - trace_log_level = GF_LOG_TRACE; + conf->trace_log_level = GF_LOG_TRACE; else if (strcmp (forced_loglevel, "ERROR") == 0) - trace_log_level = GF_LOG_ERROR; + conf->trace_log_level = GF_LOG_ERROR; else if (strcmp (forced_loglevel, "DEBUG") == 0) - trace_log_level = GF_LOG_DEBUG; + conf->trace_log_level = GF_LOG_DEBUG; else if (strcmp (forced_loglevel, "WARNING") == 0) - trace_log_level = GF_LOG_WARNING; + conf->trace_log_level = GF_LOG_WARNING; else if (strcmp (forced_loglevel, "CRITICAL") == 0) - trace_log_level = GF_LOG_CRITICAL; + conf->trace_log_level = GF_LOG_CRITICAL; else if (strcmp (forced_loglevel, "NONE") == 0) - trace_log_level = GF_LOG_NONE; + conf->trace_log_level = GF_LOG_NONE; } setloglevel: - gf_log_set_loglevel (trace_log_level); + gf_log_set_loglevel (conf->trace_log_level); + this->private = conf; + ret = 0; +out: + if (ret == -1) { + if (history) + GF_FREE (history); + if (conf) + GF_FREE (conf); + } - return 0; + return ret; } void @@ -2308,6 +3188,9 @@ fini (xlator_t *this) if (!this) return; + if (this->history) + eh_destroy (this->history); + gf_log (this->name, GF_LOG_INFO, "trace translator unloaded"); return; @@ -2356,7 +3239,6 @@ struct xlator_fops fops = { .fsetattr = trace_fsetattr, }; - struct xlator_cbks cbks = { .release = trace_release, .releasedir = trace_releasedir, @@ -2372,5 +3254,21 @@ struct volume_options options[] = { .type = GF_OPTION_TYPE_STR /*.value = { ""} */ }, + { .key = {"history-size"}, + .type = GF_OPTION_TYPE_SIZET, + .default_value = "1024", + }, + { .key = {"log-file"}, + .type = GF_OPTION_TYPE_BOOL, + .default_value = "no", + }, + { .key = {"log-history"}, + .type = GF_OPTION_TYPE_BOOL, + .default_value = "no", + }, { .key = {NULL} }, }; + +struct xlator_dumpops dumpops = { + .history = trace_dump_history +}; diff --git a/xlators/debug/trace/src/trace.h b/xlators/debug/trace/src/trace.h new file mode 100644 index 000000000..045eefb36 --- /dev/null +++ b/xlators/debug/trace/src/trace.h @@ -0,0 +1,98 @@ +/* + Copyright (c) 2006-2012 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 _CONFIG_H +#define _CONFIG_H +#include "config.h" +#endif + +#include +#include +#include "glusterfs.h" +#include "xlator.h" +#include "common-utils.h" +#include "event-history.h" +#include "logging.h" +#include "circ-buff.h" +#include "statedump.h" +#include "options.h" + +#define TRACE_DEFAULT_HISTORY_SIZE 1024 + +typedef struct { + /* Since the longest fop name is fremovexattr i.e 12 characters, array size + * is kept 24, i.e double of the maximum. + */ + char name[24]; + int enabled; +} trace_fop_name_t; + +trace_fop_name_t trace_fop_names[GF_FOP_MAXVALUE]; + +typedef struct { + gf_boolean_t log_file; + gf_boolean_t log_history; + size_t history_size; + int trace_log_level; +} trace_conf_t; + +#define TRACE_STACK_UNWIND(op, frame, params ...) \ + do { \ + frame->local = NULL; \ + STACK_UNWIND_STRICT (op, frame, params); \ + } while (0); + +#define LOG_ELEMENT(_conf, _string) \ + do { \ + if (_conf) { \ + if ((_conf->log_history) == _gf_true) \ + gf_log_eh ("%s", _string); \ + if ((_conf->log_file) == _gf_true) \ + gf_log (THIS->name, _conf->trace_log_level, \ + "%s", _string); \ + } \ + } while (0); + +#define trace_stat_to_str(buf, statstr) \ + do { \ + char atime_buf[256] = {0,}; \ + char mtime_buf[256] = {0,}; \ + char ctime_buf[256] = {0,}; \ + uint64_t ia_time = 0; \ + \ + if (!buf) \ + break; \ + \ + ia_time = buf->ia_atime; \ + strftime (atime_buf, 256, "[%b %d %H:%M:%S]", \ + localtime ((time_t *)&ia_time)); \ + \ + ia_time = buf->ia_mtime; \ + strftime (mtime_buf, 256, "[%b %d %H:%M:%S]", \ + localtime ((time_t *)&ia_time)); \ + \ + ia_time = buf->ia_ctime; \ + strftime (ctime_buf, 256, "[%b %d %H:%M:%S]", \ + localtime ((time_t *)&ia_time)); \ + \ + snprintf (statstr, sizeof (statstr), \ + "gfid=%s ino=%"PRIu64", mode=%o, " \ + "nlink=%"GF_PRI_NLINK", uid=%u, " \ + "gid=%u, size=%"PRIu64", " \ + "blocks=%"PRIu64", atime=%s, " \ + "mtime=%s, ctime=%s", \ + uuid_utoa (buf->ia_gfid), buf->ia_ino, \ + st_mode_from_ia (buf->ia_prot, \ + buf->ia_type), \ + buf->ia_nlink, buf->ia_uid, \ + buf->ia_gid, buf->ia_size, \ + buf->ia_blocks, atime_buf, \ + mtime_buf, ctime_buf); \ + } while (0); -- cgit