diff options
author | ShyamsundarR <srangana@redhat.com> | 2013-12-20 13:19:00 +0530 |
---|---|---|
committer | Vijay Bellur <vbellur@redhat.com> | 2014-03-28 04:53:37 -0700 |
commit | 31e34cfd72712c76c127509d14d50eb008743fd5 (patch) | |
tree | 9d70b7768cb705215f7054df6069cb626ce4b189 | |
parent | 326b77695f15444f79cea9822e35361e6bd167d5 (diff) |
log: enhance gluster log format with message ID and standardize errno reporting
Currently there are quite a slew of logs in Gluster that do not
lend themselves to trivial analysis by various tools that help
collect and monitor logs, due to the textual nature of the logs.
This FEAT is to make this better by giving logs message IDs so
that the tools do not have to do complex log parsing to break
it down to problem areas and suggest troubleshooting options.
With this patch, a new set of logging APIs are introduced that
take additionally a message ID and an error number, so as to
print the message ID and the descriptive string for the error.
New APIs:
- gf_msg, gf_msg_debug/trace, gf_msg_nomem, gf_msg_callingfn
These APIs follow the functionality of the previous gf_log*
counterparts, and hence are 1:1 replacements, with the delta
that, gf_msg, gf_msg_callingfn take additional parameters as
specified above.
Defining the log messages:
Each invocation of gf_msg/gf_msg_callingfn, should provide an ID
and an errnum (if available). Towards this, a common message id
file is provided, which contains defines to various messages and
their respective strings. As other messages are changed to the
new infrastructure APIs, it is intended that this file is edited
to add these messages as well.
Framework enhanced:
The logging framework is also enhanced to be able to support
different logging backends in the future. Hence new configuration
options for logging framework and logging formats are introduced.
Backward compatibility:
Currently the framework supports logging in the traditional
format, with the inclusion of an error string based on the errnum
passed in. Hence the shift to these new APIs would retain the log
file names, locations, and format with the exception of an
additional error string where applicable.
Testing done:
Tested the new APIs with different messages in normal code paths
Tested with configurations set to gluster logs (syslog pending)
Tested nomem variants, inducing the message in normal code paths
Tested ident generation for normal code paths (other paths
pending)
Tested with sample gfapi program for gfapi messages
Test code is stripped from the commit
Pending work (not to be addressed in this patch (future)):
- Logging framework should be configurable
- Logging format should be configurable
- Once all messages move to the new APIs deprecate/delete older
APIs to prevent misuse/abuse using the same
- Repeated log messages should be suppressed (as a configurable
option)
- Logging framework assumes that only one init is possible, but
there is no protection around the same (in existing code)
- gf_log_fini is not invoked anywhere and does very little
cleanup (in existing code)
- DOxygen comments to message id headers for each message
Change-Id: Ia043fda99a1c6cf7817517ef9e279bfcf35dcc24
BUG: 1075611
Signed-off-by: ShyamsundarR <srangana@redhat.com>
Reviewed-on: http://review.gluster.org/6547
Reviewed-by: Krutika Dhananjay <kdhananj@redhat.com>
Tested-by: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: Raghavendra G <rgowdapp@redhat.com>
Reviewed-by: Pranith Kumar Karampuri <pkarampu@redhat.com>
Reviewed-by: Vijay Bellur <vbellur@redhat.com>
-rw-r--r-- | api/src/glfs.c | 11 | ||||
-rw-r--r-- | glusterfsd/src/Makefile.am | 2 | ||||
-rw-r--r-- | glusterfsd/src/glusterfsd-messages.h | 111 | ||||
-rw-r--r-- | glusterfsd/src/glusterfsd.c | 275 | ||||
-rw-r--r-- | libglusterfs/src/Makefile.am | 3 | ||||
-rw-r--r-- | libglusterfs/src/common-utils.c | 241 | ||||
-rw-r--r-- | libglusterfs/src/common-utils.h | 1 | ||||
-rw-r--r-- | libglusterfs/src/glfs-message-id.h | 48 | ||||
-rw-r--r-- | libglusterfs/src/glusterfs.h | 1 | ||||
-rw-r--r-- | libglusterfs/src/logging.c | 1074 | ||||
-rw-r--r-- | libglusterfs/src/logging.h | 129 | ||||
-rw-r--r-- | libglusterfs/src/mem-pool.c | 6 | ||||
-rw-r--r-- | libglusterfs/src/mem-pool.h | 6 | ||||
-rw-r--r-- | libglusterfs/src/template-component-messages.h | 55 | ||||
-rw-r--r-- | libglusterfs/src/unittest/log_mock.c | 7 | ||||
-rw-r--r-- | rpc/rpc-transport/rdma/src/rdma.c | 2 | ||||
-rw-r--r-- | tests/basic/logchecks-messages.h | 84 | ||||
-rw-r--r-- | tests/basic/logchecks.c | 208 |
18 files changed, 1762 insertions, 502 deletions
diff --git a/api/src/glfs.c b/api/src/glfs.c index 9e9a55ccb65..d09c737f6d6 100644 --- a/api/src/glfs.c +++ b/api/src/glfs.c @@ -486,7 +486,7 @@ glfs_set_volfile_server (struct glfs *fs, const char *transport, int glfs_set_logging (struct glfs *fs, const char *logfile, int loglevel) { - int ret = 0; + int ret = 0; char *tmplog = NULL; if (!logfile) { @@ -498,15 +498,16 @@ glfs_set_logging (struct glfs *fs, const char *logfile, int loglevel) tmplog = (char *)logfile; } + /* finish log set parameters before init */ + if (loglevel >= 0) + gf_log_set_loglevel (loglevel); + ret = gf_log_init (fs->ctx, tmplog, NULL); if (ret) goto out; - if (loglevel >= 0) - gf_log_set_loglevel (loglevel); - out: - return ret; + return ret; } diff --git a/glusterfsd/src/Makefile.am b/glusterfsd/src/Makefile.am index 05a10dee328..1797c32be35 100644 --- a/glusterfsd/src/Makefile.am +++ b/glusterfsd/src/Makefile.am @@ -6,7 +6,7 @@ glusterfsd_LDADD = $(top_builddir)/libglusterfs/src/libglusterfs.la \ $(top_builddir)/rpc/xdr/src/libgfxdr.la \ $(GF_LDADD) $(GF_GLUSTERFS_LIBS) glusterfsd_LDFLAGS = $(GF_LDFLAGS) -noinst_HEADERS = glusterfsd.h glusterfsd-mem-types.h +noinst_HEADERS = glusterfsd.h glusterfsd-mem-types.h glusterfsd-messages.h AM_CPPFLAGS = $(GF_CPPFLAGS) \ -I$(top_srcdir)/libglusterfs/src -DDATADIR=\"$(localstatedir)\" \ diff --git a/glusterfsd/src/glusterfsd-messages.h b/glusterfsd/src/glusterfsd-messages.h new file mode 100644 index 00000000000..48a0b17f6fb --- /dev/null +++ b/glusterfsd/src/glusterfsd-messages.h @@ -0,0 +1,111 @@ +/* + Copyright (c) 2013 Red Hat, Inc. <http://www.redhat.com> + 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 _GLUSTERFSD_MESSAGES_H_ +#define _GLUSTERFSD_MESSAGES_H_ + +#ifndef _CONFIG_H +#define _CONFIG_H +#include "config.h" +#endif + +#include "glfs-message-id.h" + +/* NOTE: Rules for message additions + * 1) Each instance of a message is _better_ left with a unique message ID, even + * if the message format is the same. Reasoning is that, if the message + * format needs to change in one instance, the other instances are not + * impacted or the new change does not change the ID of the instance being + * modified. + * 2) Addition of a message, + * - Should increment the GLFS_NUM_MESSAGES + * - Append to the list of messages defined, towards the end + * - Retain macro naming as glfs_msg_X (for redability across developers) + * NOTE: Rules for message format modifications + * 3) Check acorss the code if the message ID macro in question is reused + * anywhere. If reused then then the modifications should ensure correctness + * everywhere, or needs a new message ID as (1) above was not adhered to. If + * not used anywhere, proceed with the required modification. + * NOTE: Rules for message deletion + * 4) Check (3) and if used anywhere else, then cannot be deleted. If not used + * anywhere, then can be deleted, but will leave a hole by design, as + * addition rules specify modification to the end of the list and not filling + * holes. + */ + +#define GLFS_COMP_BASE GLFS_MSGID_COMP_GLUSTERFSD +#define GLFS_NUM_MESSAGES 33 +#define GLFS_MSGID_END (GLFS_COMP_BASE + GLFS_NUM_MESSAGES + 1) +/* Messaged with message IDs */ +#define glfs_msg_start_x GLFS_COMP_BASE, "Invalid: Start of messages" +/*------------*/ +#define glusterfsd_msg_1 (GLFS_COMP_BASE + 1), "Could not create absolute" \ + " mountpoint path" +#define glusterfsd_msg_2 (GLFS_COMP_BASE + 2), "Could not get current " \ + "working directory" +#define glusterfsd_msg_3 (GLFS_COMP_BASE + 3), "failed to set mount-point" \ + " to options dictionary" +#define glusterfsd_msg_4 (GLFS_COMP_BASE + 4), "failed to set dict value" \ + " for key %s" +#define glusterfsd_msg_5 (GLFS_COMP_BASE + 5), "failed to set 'disable'" \ + " for key %s" +#define glusterfsd_msg_6 (GLFS_COMP_BASE + 6), "failed to set 'enable'" \ + " for key %s" +#define glusterfsd_msg_7 (GLFS_COMP_BASE + 7), "Not a client process, not" \ + " performing mount operation" +#define glusterfsd_msg_8 (GLFS_COMP_BASE + 8), "MOUNT-POINT %s" \ + " initialization failed" +#define glusterfsd_msg_9 (GLFS_COMP_BASE + 9), "loading volume file %s" \ + " failed" +#define glusterfsd_msg_10 (GLFS_COMP_BASE + 10), "xlator option %s is" \ + " invalid" +#define glusterfsd_msg_11 (GLFS_COMP_BASE + 11), "Fetching the volume" \ + " file from server..." +#define glusterfsd_msg_12 (GLFS_COMP_BASE + 12), "volume initialization" \ + " failed." +#define glusterfsd_msg_13 (GLFS_COMP_BASE + 13), "ERROR: glusterfs uuid" \ + " generation failed" +#define glusterfsd_msg_14 (GLFS_COMP_BASE + 14), "ERROR: glusterfs %s" \ + " pool creation failed" +#define glusterfsd_msg_15 (GLFS_COMP_BASE + 15), "ERROR: '--volfile-id' is" \ + " mandatory if '-s' OR '--volfile-server'" \ + " option is given" +#define glusterfsd_msg_16 (GLFS_COMP_BASE + 16), "ERROR: parsing the" \ + " volfile failed" +#define glusterfsd_msg_17 (GLFS_COMP_BASE + 17), "pidfile %s open failed" +#define glusterfsd_msg_18 (GLFS_COMP_BASE + 18), "pidfile %s lock failed" +#define glusterfsd_msg_19 (GLFS_COMP_BASE + 19), "pidfile %s unlock failed" +#define glusterfsd_msg_20 (GLFS_COMP_BASE + 20), "pidfile %s truncation" \ + " failed" +#define glusterfsd_msg_21 (GLFS_COMP_BASE + 21), "pidfile %s write failed" +#define glusterfsd_msg_22 (GLFS_COMP_BASE + 22), "failed to execute" \ + " pthread_sigmask" +#define glusterfsd_msg_23 (GLFS_COMP_BASE + 23), "failed to create pthread" +#define glusterfsd_msg_24 (GLFS_COMP_BASE + 24), "daemonization failed" +#define glusterfsd_msg_25 (GLFS_COMP_BASE + 25), "mount failed" +#define glusterfsd_msg_26 (GLFS_COMP_BASE + 26), "failed to construct" \ + " the graph" +#define glusterfsd_msg_27 (GLFS_COMP_BASE + 27), "fuse xlator cannot be" \ + " specified in volume file" +#define glusterfsd_msg_28 (GLFS_COMP_BASE + 28), "Cannot reach volume" \ + " specification file" +#define glusterfsd_msg_29 (GLFS_COMP_BASE + 29), "ERROR: glusterfs context" \ + " not initialized" +#define glusterfsd_msg_30 (GLFS_COMP_BASE + 30), "Started running %s" \ + " version %s (args: %s)" +#define glusterfsd_msg_31 (GLFS_COMP_BASE + 31), "Could not create new" \ + " sync-environment" +#define glusterfsd_msg_32 (GLFS_COMP_BASE + 32), "received signum (%d)," \ + " shutting down" +/*------------*/ +#define glfs_msg_end_x GLFS_MSGID_END, "Invalid: End of messages" + + +#endif /* !_GLUSTERFSD_MESSAGES_H_ */ diff --git a/glusterfsd/src/glusterfsd.c b/glusterfsd/src/glusterfsd.c index 6a4655fc6fb..449fadda60d 100644 --- a/glusterfsd/src/glusterfsd.c +++ b/glusterfsd/src/glusterfsd.c @@ -50,6 +50,7 @@ #include "glusterfs.h" #include "compat.h" #include "logging.h" +#include "glusterfsd-messages.h" #include "dict.h" #include "list.h" #include "timer.h" @@ -240,14 +241,13 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = gf_asprintf (&mount_point, "%s/%s", cwd, cmd_args->mount_point); if (ret == -1) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "Could not create absolute mountpoint " - "path"); + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, + glusterfsd_msg_1); goto err; } } else { - gf_log ("glusterfsd", GF_LOG_ERROR, - "Could not get current working directory"); + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, + glusterfsd_msg_2); goto err; } } else @@ -255,8 +255,7 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_dynstr (options, ZR_MOUNTPOINT_OPT, mount_point); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set mount-point to options dictionary"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_3); goto err; } @@ -265,9 +264,8 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) cmd_args->fuse_attribute_timeout); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key %s", - ZR_ATTR_TIMEOUT_OPT); + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, + glusterfsd_msg_4, ZR_ATTR_TIMEOUT_OPT); goto err; } } @@ -276,8 +274,7 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_double (options, ZR_ENTRY_TIMEOUT_OPT, cmd_args->fuse_entry_timeout); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key %s", + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, ZR_ENTRY_TIMEOUT_OPT); goto err; } @@ -287,8 +284,7 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_double (options, ZR_NEGATIVE_TIMEOUT_OPT, cmd_args->fuse_negative_timeout); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key %s", + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, ZR_NEGATIVE_TIMEOUT_OPT); goto err; } @@ -298,8 +294,7 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_int32 (options, "client-pid", cmd_args->client_pid); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key %s", + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, "client-pid"); goto err; } @@ -309,8 +304,7 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_int32 (options, "uid-map-root", cmd_args->uid_map_root); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key %s", + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, "uid-map-root"); goto err; } @@ -320,8 +314,7 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_int32 (options, ZR_STRICT_VOLFILE_CHECK, cmd_args->volfile_check); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key %s", + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, ZR_STRICT_VOLFILE_CHECK); goto err; } @@ -331,8 +324,7 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_static_ptr (options, ZR_DUMP_FUSE, cmd_args->dump_fuse); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key %s", + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, ZR_DUMP_FUSE); goto err; } @@ -341,8 +333,8 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) if (cmd_args->acl) { ret = dict_set_static_ptr (options, "acl", "on"); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key acl"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, + "acl"); goto err; } } @@ -350,8 +342,8 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) if (cmd_args->selinux) { ret = dict_set_static_ptr (options, "selinux", "on"); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key selinux"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, + "selinux"); goto err; } } @@ -360,8 +352,7 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_static_ptr (options, "virtual-gfid-access", "on"); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key " + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, "aux-gfid-mount"); goto err; } @@ -370,8 +361,8 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) if (cmd_args->enable_ino32) { ret = dict_set_static_ptr (options, "enable-ino32", "on"); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key enable-ino32"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, + "enable-ino32"); goto err; } } @@ -379,8 +370,8 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) if (cmd_args->read_only) { ret = dict_set_static_ptr (options, "read-only", "on"); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key read-only"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, + "read-only"); goto err; } } @@ -390,8 +381,7 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_static_ptr(options, "fopen-keep-cache", "on"); if (ret < 0) { - gf_log("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key " + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, "fopen-keep-cache"); goto err; } @@ -400,17 +390,15 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_static_ptr(options, "fopen-keep-cache", "off"); if (ret < 0) { - gf_log("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key " + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, "fopen-keep-cache"); goto err; } break; case GF_OPTION_DEFERRED: /* default */ default: - gf_log ("glusterfsd", GF_LOG_DEBUG, - "fopen-keep-cache mode %d", - cmd_args->fopen_keep_cache); + gf_msg_debug ("glusterfsd", 0, "fopen-keep-cache mode %d", + cmd_args->fopen_keep_cache); break; } @@ -418,8 +406,8 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_int32(options, "gid-timeout", cmd_args->gid_timeout); if (ret < 0) { - gf_log("glusterfsd", GF_LOG_ERROR, "failed to set dict " - "value for key gid-timeout"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, + "gid-timeout"); goto err; } } @@ -427,8 +415,8 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_int32 (options, "background-qlen", cmd_args->background_qlen); if (ret < 0) { - gf_log("glusterfsd", GF_LOG_ERROR, "failed to set dict " - "value for key background-qlen"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, + "background-qlen"); goto err; } } @@ -436,8 +424,8 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_int32 (options, "congestion-threshold", cmd_args->congestion_threshold); if (ret < 0) { - gf_log("glusterfsd", GF_LOG_ERROR, "failed to set dict " - "value for key congestion-threshold"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, + "congestion-threshold"); goto err; } } @@ -447,8 +435,7 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_static_ptr (options, ZR_DIRECT_IO_OPT, "disable"); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set 'disable' for key %s", + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_5, ZR_DIRECT_IO_OPT); goto err; } @@ -457,16 +444,15 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_static_ptr (options, ZR_DIRECT_IO_OPT, "enable"); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set 'enable' for key %s", + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_6, ZR_DIRECT_IO_OPT); goto err; } break; case GF_OPTION_DEFERRED: /* default */ default: - gf_log ("", GF_LOG_DEBUG, "fuse direct io type %d", - cmd_args->fuse_direct_io_mode); + gf_msg_debug ("glusterfsd", 0, "fuse direct io type %d", + cmd_args->fuse_direct_io_mode); break; } @@ -500,8 +486,8 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_static_ptr (options, "sync-to-mount", "enable"); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key sync-mtab"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, + "sync-mtab"); goto err; } } @@ -510,8 +496,8 @@ set_fuse_mount_options (glusterfs_ctx_t *ctx, dict_t *options) ret = dict_set_str (options, "use-readdirp", cmd_args->use_readdirp); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, "failed to set dict" - " value for key use-readdirp"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, + "use-readdirp"); goto err; } } @@ -530,14 +516,13 @@ create_fuse_mount (glusterfs_ctx_t *ctx) cmd_args = &ctx->cmd_args; if (!cmd_args->mount_point) { - gf_log ("", GF_LOG_TRACE, - "mount point not found, not a client process"); + gf_msg_trace ("glusterfsd", 0, + "mount point not found, not a client process"); return 0; } if (ctx->process_mode != GF_CLIENT_PROCESS) { - gf_log("glusterfsd", GF_LOG_ERROR, - "Not a client process, not performing mount operation"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_7); return -1; } @@ -551,8 +536,7 @@ create_fuse_mount (glusterfs_ctx_t *ctx) goto err; if (xlator_set_type (master, "mount/fuse") == -1) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "MOUNT-POINT %s initialization failed", + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, glusterfsd_msg_8, cmd_args->mount_point); goto err; } @@ -570,8 +554,7 @@ create_fuse_mount (glusterfs_ctx_t *ctx) ret = dict_set_static_ptr (master->options, ZR_FUSE_MOUNTOPTS, cmd_args->fuse_mountopts); if (ret < 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "failed to set dict value for key %s", + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_4, ZR_FUSE_MOUNTOPTS); goto err; } @@ -579,7 +562,8 @@ create_fuse_mount (glusterfs_ctx_t *ctx) ret = xlator_init (master); if (ret) { - gf_log ("", GF_LOG_DEBUG, "failed to initialize fuse translator"); + gf_msg_debug ("glusterfsd", 0, + "failed to initialize fuse translator"); goto err; } @@ -608,21 +592,19 @@ get_volfp (glusterfs_ctx_t *ctx) ret = sys_lstat (cmd_args->volfile, &statbuf); if (ret == -1) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "%s: %s", cmd_args->volfile, strerror (errno)); + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, glusterfsd_msg_9, + cmd_args->volfile); return NULL; } if ((specfp = fopen (cmd_args->volfile, "r")) == NULL) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "volume file %s: %s", - cmd_args->volfile, - strerror (errno)); + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, glusterfsd_msg_9, + cmd_args->volfile); return NULL; } - gf_log ("glusterfsd", GF_LOG_DEBUG, - "loading volume file %s", cmd_args->volfile); + gf_msg_debug ("glusterfsd", 0, "loading volume file %s", + cmd_args->volfile); return specfp; } @@ -658,8 +640,8 @@ gf_remember_backup_volfile_server (char *arg) } if (!server->volfile_server) { - gf_log ("", GF_LOG_WARNING, - "xlator option %s is invalid", arg); + gf_msg ("glusterfsd", GF_LOG_WARNING, 0, glusterfsd_msg_10, + arg); goto out; } @@ -700,8 +682,7 @@ gf_remember_xlator_option (char *arg) dot = strchr (arg, '.'); if (!dot) { - gf_log ("", GF_LOG_WARNING, - "xlator option %s is invalid", arg); + gf_msg ("", GF_LOG_WARNING, 0, glusterfsd_msg_10, arg); goto out; } @@ -714,8 +695,7 @@ gf_remember_xlator_option (char *arg) equals = strchr (arg, '='); if (!equals) { - gf_log ("", GF_LOG_WARNING, - "xlator option %s is invalid", arg); + gf_msg ("", GF_LOG_WARNING, 0, glusterfsd_msg_10, arg); goto out; } @@ -727,8 +707,7 @@ gf_remember_xlator_option (char *arg) strncpy (option->key, dot + 1, (equals - dot - 1)); if (!*(equals + 1)) { - gf_log ("", GF_LOG_WARNING, - "xlator option %s is invalid", arg); + gf_msg ("", GF_LOG_WARNING, 0, glusterfsd_msg_10, arg); goto out; } @@ -1124,8 +1103,7 @@ cleanup_and_exit (int signum) if (!ctx) return; - gf_log_callingfn ("", GF_LOG_WARNING, - "received signum (%d), shutting down", signum); + gf_msg_callingfn ("", GF_LOG_WARNING, 0, glusterfsd_msg_32, signum); if (ctx->cleanup_started) return; @@ -1190,20 +1168,19 @@ reincarnate (int signum) cmd_args = &ctx->cmd_args; if (cmd_args->volfile_server) { - gf_log ("glusterfsd", GF_LOG_INFO, - "Fetching the volume file from server..."); + gf_msg ("glusterfsd", GF_LOG_INFO, 0, glusterfsd_msg_11); ret = glusterfs_volfile_fetch (ctx); } else { - gf_log ("glusterfsd", GF_LOG_DEBUG, - "Not reloading volume specification file on SIGHUP"); + gf_msg_debug ("glusterfsd", 0, + "Not reloading volume specification file" + " on SIGHUP"); } /* Also, SIGHUP should do logrotate */ gf_log_logrotate (1); if (ret < 0) - gf_log ("glusterfsd", GF_LOG_ERROR, - "volume initialization failed."); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_12); return; } @@ -1253,8 +1230,7 @@ glusterfs_ctx_defaults_init (glusterfs_ctx_t *ctx) ctx->process_uuid = generate_glusterfs_ctx_id (); if (!ctx->process_uuid) { - gf_log ("", GF_LOG_CRITICAL, - "ERROR: glusterfs uuid generation failed"); + gf_msg ("", GF_LOG_CRITICAL, 0, glusterfsd_msg_13); goto out; } @@ -1262,22 +1238,19 @@ glusterfs_ctx_defaults_init (glusterfs_ctx_t *ctx) ctx->iobuf_pool = iobuf_pool_new (); if (!ctx->iobuf_pool) { - gf_log ("", GF_LOG_CRITICAL, - "ERROR: glusterfs iobuf pool creation failed"); + gf_msg ("", GF_LOG_CRITICAL, 0, glusterfsd_msg_14, "iobuf"); goto out; } ctx->event_pool = event_pool_new (DEFAULT_EVENT_POOL_SIZE); if (!ctx->event_pool) { - gf_log ("", GF_LOG_CRITICAL, - "ERROR: glusterfs event pool creation failed"); + gf_msg ("", GF_LOG_CRITICAL, 0, glusterfsd_msg_14, "event"); goto out; } ctx->pool = GF_CALLOC (1, sizeof (call_pool_t), gfd_mt_call_pool_t); if (!ctx->pool) { - gf_log ("", GF_LOG_CRITICAL, - "ERROR: glusterfs call pool creation failed"); + gf_msg ("", GF_LOG_CRITICAL, 0, glusterfsd_msg_14, "call"); goto out; } @@ -1287,22 +1260,19 @@ glusterfs_ctx_defaults_init (glusterfs_ctx_t *ctx) /* frame_mem_pool size 112 * 4k */ ctx->pool->frame_mem_pool = mem_pool_new (call_frame_t, 4096); if (!ctx->pool->frame_mem_pool) { - gf_log ("", GF_LOG_CRITICAL, - "ERROR: glusterfs frame pool creation failed"); + gf_msg ("", GF_LOG_CRITICAL, 0, glusterfsd_msg_14, "frame"); goto out; } /* stack_mem_pool size 256 * 1024 */ ctx->pool->stack_mem_pool = mem_pool_new (call_stack_t, 1024); if (!ctx->pool->stack_mem_pool) { - gf_log ("", GF_LOG_CRITICAL, - "ERROR: glusterfs stack pool creation failed"); + gf_msg ("", GF_LOG_CRITICAL, 0, glusterfsd_msg_14, "stack"); goto out; } ctx->stub_mem_pool = mem_pool_new (call_stub_t, 1024); if (!ctx->stub_mem_pool) { - gf_log ("", GF_LOG_CRITICAL, - "ERROR: glusterfs stub pool creation failed"); + gf_msg ("", GF_LOG_CRITICAL, 0, glusterfsd_msg_14, "stub"); goto out; } @@ -1373,43 +1343,36 @@ logging_init (glusterfs_ctx_t *ctx, const char *progpath) { cmd_args_t *cmd_args = NULL; int ret = 0; - char ident[1024] = {0,}; - char *progname = NULL; - char *ptr = NULL; cmd_args = &ctx->cmd_args; if (cmd_args->log_file == NULL) { ret = gf_set_log_file_path (cmd_args); if (ret == -1) { - fprintf (stderr, "ERROR: failed to set the log file path\n"); + fprintf (stderr, "ERROR: failed to set the log file " + "path\n"); return -1; } } -#ifdef GF_USE_SYSLOG - progname = gf_strdup (progpath); - snprintf (ident, 1024, "%s_%s", basename(progname), - basename(cmd_args->log_file)); - GF_FREE (progname); - /* remove .log suffix */ - if (NULL != (ptr = strrchr(ident, '.'))) { - if (strcmp(ptr, ".log") == 0) { - /* note: ptr points to location in ident only */ - ptr[0] = '\0'; + if (cmd_args->log_ident == NULL) { + ret = gf_set_log_ident (cmd_args); + if (ret == -1) { + fprintf (stderr, "ERROR: failed to set the log " + "identity\n"); + return -1; } } - ptr = ident; -#endif - if (gf_log_init (ctx, cmd_args->log_file, ptr) == -1) { + /* finish log set parameters before init */ + gf_log_set_loglevel (cmd_args->log_level); + + if (gf_log_init (ctx, cmd_args->log_file, cmd_args->log_ident) == -1) { fprintf (stderr, "ERROR: failed to open logfile %s\n", cmd_args->log_file); return -1; } - gf_log_set_loglevel (cmd_args->log_level); - return 0; } @@ -1453,9 +1416,7 @@ parse_cmdline (int argc, char *argv[], glusterfs_ctx_t *ctx) /* Make sure after the parsing cli, if '--volfile-server' option is given, then '--volfile-id' is mandatory */ if (cmd_args->volfile_server && !cmd_args->volfile_id) { - gf_log ("glusterfs", GF_LOG_CRITICAL, - "ERROR: '--volfile-id' is mandatory if '-s' OR " - "'--volfile-server' option is given"); + gf_msg ("glusterfs", GF_LOG_CRITICAL, 0, glusterfsd_msg_15); ret = -1; goto out; } @@ -1473,9 +1434,8 @@ parse_cmdline (int argc, char *argv[], glusterfs_ctx_t *ctx) and exit */ ret = stat (cmd_args->volfile, &stbuf); if (ret) { - gf_log ("glusterfs", GF_LOG_CRITICAL, - "ERROR: parsing the volfile failed (%s)\n", - strerror (errno)); + gf_msg ("glusterfs", GF_LOG_CRITICAL, errno, + glusterfsd_msg_16); /* argp_usage (argp.) */ fprintf (stderr, "USAGE: %s [options] [mountpoint]\n", argv[0]); @@ -1551,9 +1511,8 @@ glusterfs_pidfile_setup (glusterfs_ctx_t *ctx) pidfp = fopen (cmd_args->pid_file, "a+"); if (!pidfp) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "pidfile %s error (%s)", - cmd_args->pid_file, strerror (errno)); + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, glusterfsd_msg_17, + cmd_args->pid_file); goto out; } @@ -1576,9 +1535,8 @@ glusterfs_pidfile_cleanup (glusterfs_ctx_t *ctx) if (!ctx->pidfp) return 0; - gf_log ("glusterfsd", GF_LOG_TRACE, - "pidfile %s cleanup", - cmd_args->pid_file); + gf_msg_trace ("glusterfsd", 0, "pidfile %s cleanup", + cmd_args->pid_file); if (ctx->cmd_args.pid_file) { unlink (ctx->cmd_args.pid_file); @@ -1607,39 +1565,34 @@ glusterfs_pidfile_update (glusterfs_ctx_t *ctx) ret = lockf (fileno (pidfp), F_TLOCK, 0); if (ret) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "pidfile %s lock failed", + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, glusterfsd_msg_18, cmd_args->pid_file); return ret; } ret = ftruncate (fileno (pidfp), 0); if (ret) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "pidfile %s truncation failed", + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, glusterfsd_msg_20, cmd_args->pid_file); return ret; } ret = fprintf (pidfp, "%d\n", getpid ()); if (ret <= 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "pidfile %s write failed", + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, glusterfsd_msg_21, cmd_args->pid_file); return ret; } ret = fflush (pidfp); if (ret) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "pidfile %s write failed", + gf_msg ("glusterfsd", GF_LOG_ERROR, errno, glusterfsd_msg_21, cmd_args->pid_file); return ret; } - gf_log ("glusterfsd", GF_LOG_DEBUG, - "pidfile %s updated with pid %d", - cmd_args->pid_file, getpid ()); + gf_msg_debug ("glusterfsd", 0, "pidfile %s updated with pid %d", + cmd_args->pid_file, getpid ()); return 0; } @@ -1723,9 +1676,7 @@ glusterfs_signals_setup (glusterfs_ctx_t *ctx) ret = pthread_sigmask (SIG_BLOCK, &set, NULL); if (ret) { - gf_log ("glusterfsd", GF_LOG_WARNING, - "failed to execute pthread_signmask %s", - strerror (errno)); + gf_msg ("glusterfsd", GF_LOG_WARNING, errno, glusterfsd_msg_22); return ret; } @@ -1737,9 +1688,7 @@ glusterfs_signals_setup (glusterfs_ctx_t *ctx) fallback to signals getting handled by other threads. setup the signal handlers */ - gf_log ("glusterfsd", GF_LOG_WARNING, - "failed to create pthread %s", - strerror (errno)); + gf_msg ("glusterfsd", GF_LOG_WARNING, errno, glusterfsd_msg_23); return ret; } @@ -1784,8 +1733,7 @@ daemonize (glusterfs_ctx_t *ctx) close (ctx->daemon_pipe[1]); } - gf_log ("daemonize", GF_LOG_ERROR, - "Daemonization failed: %s", strerror(errno)); + gf_msg ("daemonize", GF_LOG_ERROR, errno, glusterfsd_msg_24); goto out; case 0: /* child */ @@ -1800,8 +1748,8 @@ daemonize (glusterfs_ctx_t *ctx) if (ctx->mnt_pid > 0) { ret = waitpid (ctx->mnt_pid, &cstatus, 0); if (!(ret == ctx->mnt_pid && cstatus == 0)) { - gf_log ("daemonize", GF_LOG_ERROR, - "mount failed"); + gf_msg ("daemonize", GF_LOG_ERROR, 0, + glusterfsd_msg_25); exit (1); } } @@ -1831,15 +1779,14 @@ glusterfs_process_volfp (glusterfs_ctx_t *ctx, FILE *fp) graph = glusterfs_graph_construct (fp); if (!graph) { - gf_log ("", GF_LOG_ERROR, "failed to construct the graph"); + gf_msg ("", GF_LOG_ERROR, 0, glusterfsd_msg_26); goto out; } for (trav = graph->first; trav; trav = trav->next) { if (strcmp (trav->type, "mount/fuse") == 0) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "fuse xlator cannot be specified " - "in volume file"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, + glusterfsd_msg_27); goto out; } } @@ -1897,8 +1844,7 @@ glusterfs_volumes_init (glusterfs_ctx_t *ctx) fp = get_volfp (ctx); if (!fp) { - gf_log ("glusterfsd", GF_LOG_ERROR, - "Cannot reach volume specification file"); + gf_msg ("glusterfsd", GF_LOG_ERROR, 0, glusterfsd_msg_28); ret = -1; goto out; } @@ -1925,8 +1871,7 @@ main (int argc, char *argv[]) ctx = glusterfs_ctx_new (); if (!ctx) { - gf_log ("glusterfs", GF_LOG_CRITICAL, - "ERROR: glusterfs context not initialized"); + gf_msg ("glusterfs", GF_LOG_CRITICAL, 0, glusterfsd_msg_29); return ENOMEM; } glusterfsd_ctx = ctx; @@ -1965,8 +1910,7 @@ main (int argc, char *argv[]) strcat (cmdlinestr, " "); strcat (cmdlinestr, argv[i]); } - gf_log (argv[0], GF_LOG_INFO, - "Started running %s version %s (%s)", + gf_msg (argv[0], GF_LOG_INFO, 0, glusterfsd_msg_30, argv[0], PACKAGE_VERSION, cmdlinestr); } @@ -1982,8 +1926,7 @@ main (int argc, char *argv[]) ctx->env = syncenv_new (0, 0, 0); if (!ctx->env) { - gf_log ("", GF_LOG_ERROR, - "Could not create new sync-environment"); + gf_msg ("", GF_LOG_ERROR, 0, glusterfsd_msg_31); goto out; } diff --git a/libglusterfs/src/Makefile.am b/libglusterfs/src/Makefile.am index 634e217ed4d..b1a8536877d 100644 --- a/libglusterfs/src/Makefile.am +++ b/libglusterfs/src/Makefile.am @@ -42,7 +42,8 @@ noinst_HEADERS = common-utils.h defaults.h dict.h glusterfs.h hashfn.h timespec. $(CONTRIBDIR)/uuid/uuid.h $(CONTRIBDIR)/uuid/uuidP.h \ $(CONTRIB_BUILDDIR)/uuid/uuid_types.h syncop.h graph-utils.h trie.h \ run.h options.h lkowner.h fd-lk.h circ-buff.h event-history.h \ - gidcache.h client_t.h glusterfs-acl.h + gidcache.h client_t.h glusterfs-acl.h glfs-message-id.h \ + template-component-messages.h EXTRA_DIST = graph.l graph.y diff --git a/libglusterfs/src/common-utils.c b/libglusterfs/src/common-utils.c index 1dfb418e4a8..1ccb27d164c 100644 --- a/libglusterfs/src/common-utils.c +++ b/libglusterfs/src/common-utils.c @@ -281,26 +281,37 @@ err: struct xldump { int lineno; - FILE *logfp; }; - +/* to catch any format discrepencies that may arise in code */ +static int nprintf (struct xldump *dump, const char *fmt, ...) + __attribute__ ((__format__ (__printf__, 2, 3))); static int nprintf (struct xldump *dump, const char *fmt, ...) { - va_list ap; - int ret = 0; - + va_list ap; + char *msg = NULL; + char header[32]; + int ret = 0; - ret += fprintf (dump->logfp, "%3d: ", ++dump->lineno); + ret = snprintf (header, 32, "%3d:", ++dump->lineno); + if (ret < 0) + goto out; - va_start (ap, fmt); - ret += vfprintf (dump->logfp, fmt, ap); - va_end (ap); + va_start (ap, fmt); + ret = vasprintf (&msg, fmt, ap); + va_end (ap); + if (-1 == ret) + goto out; - ret += fprintf (dump->logfp, "\n"); + /* NOTE: No ret value from gf_msg_plain, so unable to compute printed + * characters. The return value from nprintf is not used, so for now + * living with it */ + gf_msg_plain (GF_LOG_WARNING, "%s %s", header, msg); - return ret; +out: + FREE (msg); + return 0; } @@ -349,175 +360,125 @@ xldump (xlator_t *each, void *d) xldump_subvolumes (each, d); nprintf (d, "end-volume"); - nprintf (d, ""); + nprintf (d, " "); } void gf_log_dump_graph (FILE *specfp, glusterfs_graph_t *graph) { - glusterfs_ctx_t *ctx; struct xldump xld = {0, }; - - ctx = THIS->ctx; - xld.logfp = ctx->log.gf_log_logfile; - - fprintf (ctx->log.gf_log_logfile, "Final graph:\n"); - fprintf (ctx->log.gf_log_logfile, - "+---------------------------------------" - "---------------------------------------+\n"); + gf_msg_plain (GF_LOG_WARNING, "Final graph:"); + gf_msg_plain (GF_LOG_WARNING, + "+---------------------------------------" + "---------------------------------------+"); xlator_foreach_depth_first (graph->top, xldump, &xld); - fprintf (ctx->log.gf_log_logfile, - "+---------------------------------------" - "---------------------------------------+\n"); - fflush (ctx->log.gf_log_logfile); + gf_msg_plain (GF_LOG_WARNING, + "+---------------------------------------" + "---------------------------------------+"); } static void -gf_dump_config_flags (int fd) +gf_dump_config_flags () { - int ret = 0; - - ret = write (fd, "configuration details:\n", 23); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "configuration details:"); /* have argp */ #ifdef HAVE_ARGP - ret = write (fd, "argp 1\n", 7); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "argp 1"); #endif /* ifdef if found backtrace */ #ifdef HAVE_BACKTRACE - ret = write (fd, "backtrace 1\n", 12); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "backtrace 1"); #endif /* Berkeley-DB version has cursor->get() */ #ifdef HAVE_BDB_CURSOR_GET - ret = write (fd, "bdb->cursor->get 1\n", 19); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "bdb->cursor->get 1"); #endif /* Define to 1 if you have the <db.h> header file. */ #ifdef HAVE_DB_H - ret = write (fd, "db.h 1\n", 7); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "db.h 1"); #endif /* Define to 1 if you have the <dlfcn.h> header file. */ #ifdef HAVE_DLFCN_H - ret = write (fd, "dlfcn 1\n", 8); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "dlfcn 1"); #endif /* define if fdatasync exists */ #ifdef HAVE_FDATASYNC - ret = write (fd, "fdatasync 1\n", 12); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "fdatasync 1"); #endif /* Define to 1 if you have the `pthread' library (-lpthread). */ #ifdef HAVE_LIBPTHREAD - ret = write (fd, "libpthread 1\n", 13); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "libpthread 1"); #endif /* define if llistxattr exists */ #ifdef HAVE_LLISTXATTR - ret = write (fd, "llistxattr 1\n", 13); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "llistxattr 1"); #endif /* define if found setfsuid setfsgid */ #ifdef HAVE_SET_FSID - ret = write (fd, "setfsid 1\n", 10); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "setfsid 1"); #endif /* define if found spinlock */ #ifdef HAVE_SPINLOCK - ret = write (fd, "spinlock 1\n", 11); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "spinlock 1"); #endif /* Define to 1 if you have the <sys/epoll.h> header file. */ #ifdef HAVE_SYS_EPOLL_H - ret = write (fd, "epoll.h 1\n", 10); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "epoll.h 1"); #endif /* Define to 1 if you have the <sys/extattr.h> header file. */ #ifdef HAVE_SYS_EXTATTR_H - ret = write (fd, "extattr.h 1\n", 12); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "extattr.h 1"); #endif /* Define to 1 if you have the <sys/xattr.h> header file. */ #ifdef HAVE_SYS_XATTR_H - ret = write (fd, "xattr.h 1\n", 10); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "xattr.h 1"); #endif /* define if found st_atim.tv_nsec */ #ifdef HAVE_STRUCT_STAT_ST_ATIM_TV_NSEC - ret = write (fd, "st_atim.tv_nsec 1\n", 18); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "st_atim.tv_nsec 1"); #endif /* define if found st_atimespec.tv_nsec */ #ifdef HAVE_STRUCT_STAT_ST_ATIMESPEC_TV_NSEC - ret = write (fd, "st_atimespec.tv_nsec 1\n",23); - if (ret == -1) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, "st_atimespec.tv_nsec 1"); #endif /* Define to the full name and version of this package. */ #ifdef PACKAGE_STRING { char msg[128]; - sprintf (msg, "package-string: %s\n", PACKAGE_STRING); - ret = write (fd, msg, strlen (msg)); - if (ret == -1) - goto out; + sprintf (msg, "package-string: %s", PACKAGE_STRING); + gf_msg_plain_nomem (GF_LOG_ALERT, msg); } #endif -out: return; } -/* Obtain a backtrace and print it to stdout. */ -/* TODO: It looks like backtrace_symbols allocates memory, - it may be problem because mostly memory allocation/free causes 'sigsegv' */ - +/* Obtain a backtrace and print it to the log */ void gf_print_trace (int32_t signum, glusterfs_ctx_t *ctx) { char msg[1024] = {0,}; char timestr[64] = {0,}; - int ret = 0; - int fd = 0; - - fd = fileno (ctx->log.gf_log_logfile); /* Now every gf_log call will just write to a buffer and when the * buffer becomes full, its written to the log-file. Suppose the process @@ -526,75 +487,51 @@ gf_print_trace (int32_t signum, glusterfs_ctx_t *ctx) * contents of the buffer to the log file before printing the backtrace * which helps in debugging. */ - fflush (ctx->log.gf_log_logfile); + gf_log_flush(); /* Pending frames, (if any), list them in order */ - ret = write (fd, "pending frames:\n", 16); - if (ret < 0) - goto out; - + gf_msg_plain_nomem (GF_LOG_ALERT, "pending frames:"); { - struct list_head *trav = ((call_pool_t *)ctx->pool)->all_frames.next; + struct list_head *trav = + ((call_pool_t *)ctx->pool)->all_frames.next; while (trav != (&((call_pool_t *)ctx->pool)->all_frames)) { - call_frame_t *tmp = (call_frame_t *)(&((call_stack_t *)trav)->frames); + call_frame_t *tmp = + (call_frame_t *)(&((call_stack_t *)trav)->frames); if (tmp->root->type == GF_OP_TYPE_FOP) - sprintf (msg,"frame : type(%d) op(%s)\n", + sprintf (msg,"frame : type(%d) op(%s)", tmp->root->type, gf_fop_list[tmp->root->op]); else - sprintf (msg,"frame : type(%d) op(%d)\n", + sprintf (msg,"frame : type(%d) op(%d)", tmp->root->type, tmp->root->op); - ret = write (fd, msg, strlen (msg)); - if (ret < 0) - goto out; + gf_msg_plain_nomem (GF_LOG_ALERT, msg); trav = trav->next; } - ret = write (fd, "\n", 1); - if (ret < 0) - goto out; } - sprintf (msg, "patchset: %s\n", GLUSTERFS_REPOSITORY_REVISION); - ret = write (fd, msg, strlen (msg)); - if (ret < 0) - goto out; - - sprintf (msg, "signal received: %d\n", signum); - ret = write (fd, msg, strlen (msg)); - if (ret < 0) - goto out; + sprintf (msg, "patchset: %s", GLUSTERFS_REPOSITORY_REVISION); + gf_msg_plain_nomem (GF_LOG_ALERT, msg); + sprintf (msg, "signal received: %d", signum); + gf_msg_plain_nomem (GF_LOG_ALERT, msg); { /* Dump the timestamp of the crash too, so the previous logs can be related */ - gf_time_fmt (timestr, sizeof timestr, time (NULL), gf_timefmt_FT); - ret = write (fd, "time of crash: ", 15); - if (ret < 0) - goto out; - ret = write (fd, timestr, strlen (timestr)); - if (ret < 0) - goto out; + gf_time_fmt (timestr, sizeof timestr, time (NULL), + gf_timefmt_FT); + gf_msg_plain_nomem (GF_LOG_ALERT, "time of crash: "); + gf_msg_plain_nomem (GF_LOG_ALERT, timestr); } - gf_dump_config_flags (fd); + gf_dump_config_flags (); #if HAVE_BACKTRACE - /* Print 'backtrace' */ - { - void *array[200]; - size_t size; - - size = backtrace (array, 200); - backtrace_symbols_fd (&array[1], size-1, fd); - sprintf (msg, "---------\n"); - ret = write (fd, msg, strlen (msg)); - if (ret < 0) - goto out; - } + gf_msg_backtrace_nomem (GF_LOG_ALERT, 200); + sprintf (msg, "---------"); + gf_msg_plain_nomem (GF_LOG_ALERT, msg); #endif /* HAVE_BACKTRACE */ -out: /* Send a signal to terminate the process */ signal (signum, SIG_DFL); raise (signum); @@ -2919,6 +2856,42 @@ done: } int +gf_set_log_ident (cmd_args_t *cmd_args) +{ + int ret = 0; + char *ptr = NULL; + + if (cmd_args->log_file == NULL) { + /* no ident source */ + return 0; + } + + /* TODO: Some idents would look like, etc-glusterfs-glusterd.vol, which + * seems ugly and can be bettered? */ + /* just get the filename as the ident */ + if (NULL != (ptr = strrchr (cmd_args->log_file, '/'))) { + ret = gf_asprintf (&cmd_args->log_ident, "%s", ptr + 1); + } else { + ret = gf_asprintf (&cmd_args->log_ident, "%s", + cmd_args->log_file); + } + + if (ret > 0) + ret = 0; + else + return ret; + + /* remove .log suffix */ + if (NULL != (ptr = strrchr (cmd_args->log_ident, '.'))) { + if (strcmp (ptr, ".log") == 0) { + ptr[0] = '\0'; + } + } + + return ret; +} + +int gf_thread_create (pthread_t *thread, const pthread_attr_t *attr, void *(*start_routine)(void *), void *arg) { diff --git a/libglusterfs/src/common-utils.h b/libglusterfs/src/common-utils.h index f877590f4ca..ee4e5b7e6ee 100644 --- a/libglusterfs/src/common-utils.h +++ b/libglusterfs/src/common-utils.h @@ -121,6 +121,7 @@ int32_t gf_resolve_ip6 (const char *hostname, uint16_t port, int family, void gf_log_dump_graph (FILE *specfp, glusterfs_graph_t *graph); void gf_print_trace (int32_t signal, glusterfs_ctx_t *ctx); int gf_set_log_file_path (cmd_args_t *cmd_args); +int gf_set_log_ident (cmd_args_t *cmd_args); #define VECTORSIZE(count) (count * (sizeof (struct iovec))) diff --git a/libglusterfs/src/glfs-message-id.h b/libglusterfs/src/glfs-message-id.h new file mode 100644 index 00000000000..42c16f12d91 --- /dev/null +++ b/libglusterfs/src/glfs-message-id.h @@ -0,0 +1,48 @@ +/* + Copyright (c) 2013 Red Hat, Inc. <http://www.redhat.com> + 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 _GLFS_MESSAGE_ID_H_ +#define _GLFS_MESSAGE_ID_H_ + +#ifndef _CONFIG_H +#define _CONFIG_H +#include "config.h" +#endif + +/* Base of all message IDs, all message IDs would be + * greater than this */ +#define GLFS_MSGID_BASE 100000 + +/* Segment size of allocated range. Any component needing more than this + * segment size should take multiple segments (at times non contiguous, + * if extensions are being made post the next segment already allocated) */ +#define GLFS_MSGID_SEGMENT 1000 + +/* Per module message segments allocated */ +/* NOTE: For any new module add to the end the modules */ +#define GLFS_MSGID_COMP_GLUSTERFSD GLFS_MSGID_BASE +#define GLFS_MSGID_COMP_LIBGLUSTERFS GLFS_MSGID_COMP_GLUSTERFSD + \ + GLFS_MSGID_SEGMENT +#define GLFS_MSGID_COMP_RPC_LIB GLFS_MSGID_COMP_LIBGLUSTERFS + \ + GLFS_MSGID_SEGMENT +#define GLFS_MSGID_COMP_RPC_TRANSPORT GLFS_MSGID_COMP_RPC_LIB + \ + GLFS_MSGID_SEGMENT +#define GLFS_MSGID_COMP_API GLFS_MSGID_COMP_RPC_TRANSPORT + \ + GLFS_MSGID_SEGMENT +#define GLFS_MSGID_COMP_CLI GLFS_MSGID_COMP_API + \ + GLFS_MSGID_SEGMENT +/* glusterd has a lot of messages, taking 2 segments for the same */ +#define GLFS_MSGID_GLUSTERD GLFS_MSGID_COMP_CLI + \ + GLFS_MSGID_SEGMENT + \ + GLFS_MSGID_SEGMENT + +/* --- new segments for messages goes above this line --- */ + +#endif /* !_GLFS_MESSAGE_ID_H_ */ diff --git a/libglusterfs/src/glusterfs.h b/libglusterfs/src/glusterfs.h index 5ce0d6e70bb..852d686c13c 100644 --- a/libglusterfs/src/glusterfs.h +++ b/libglusterfs/src/glusterfs.h @@ -342,6 +342,7 @@ struct _cmd_args { char *log_server; gf_loglevel_t log_level; char *log_file; + char *log_ident; int32_t max_connect_attempts; /* advanced options */ uint32_t volfile_server_port; diff --git a/libglusterfs/src/logging.c b/libglusterfs/src/logging.c index 2bd40b2c2d6..f343731c7f4 100644 --- a/libglusterfs/src/logging.c +++ b/libglusterfs/src/logging.c @@ -22,7 +22,6 @@ #include <string.h> #include <stdlib.h> -#ifdef GF_USE_SYSLOG #include <libintl.h> #include <syslog.h> #include <sys/stat.h> @@ -32,7 +31,9 @@ #define GF_SYSLOG_CEE_FORMAT \ "@cee: {\"msg\": \"%s\", \"gf_code\": \"%u\", \"gf_message\": \"%s\"}" #define GF_LOG_CONTROL_FILE "/etc/glusterfs/logger.conf" -#endif /* GF_USE_SYSLOG */ +#define GF_LOG_BACKTRACE_DEPTH 5 +#define GF_LOG_BACKTRACE_SIZE 4096 +#define GF_LOG_TIMESTR_SIZE 256 #include "xlator.h" #include "logging.h" @@ -47,6 +48,19 @@ #include <execinfo.h> #endif +static char *gf_level_strings[] = {"", /* NONE */ + "M", /* EMERGENCY */ + "A", /* ALERT */ + "C", /* CRITICAL */ + "E", /* ERROR */ + "W", /* WARNING */ + "N", /* NOTICE */ + "I", /* INFO */ + "D", /* DEBUG */ + "T", /* TRACE */ + "" +}; + /* Ideally this should get moved to logging.h */ struct _msg_queue { struct list_head msgs; @@ -60,41 +74,77 @@ struct _log_msg { void gf_log_logrotate (int signum) { - THIS->ctx->log.logrotate = 1; + glusterfs_ctx_t *ctx = NULL; + + ctx = THIS->ctx; + + if (ctx) + ctx->log.logrotate = 1; } void gf_log_enable_syslog (void) { - THIS->ctx->log.gf_log_syslog = 1; + glusterfs_ctx_t *ctx = NULL; + + ctx = THIS->ctx; + + if (ctx) + ctx->log.gf_log_syslog = 1; } void gf_log_disable_syslog (void) { - THIS->ctx->log.gf_log_syslog = 0; + glusterfs_ctx_t *ctx = NULL; + + ctx = THIS->ctx; + + if (ctx) + ctx->log.gf_log_syslog = 0; } gf_loglevel_t gf_log_get_loglevel (void) { - return THIS->ctx->log.loglevel; + glusterfs_ctx_t *ctx = NULL; + + ctx = THIS->ctx; + + if (ctx) + return ctx->log.loglevel; + else + /* return global defaluts (see gf_log_globals_init) */ + return GF_LOG_INFO; } void gf_log_set_loglevel (gf_loglevel_t level) { - THIS->ctx->log.loglevel = level; -} + glusterfs_ctx_t *ctx = NULL; + ctx = THIS->ctx; -gf_loglevel_t -gf_log_get_xl_loglevel (void *this) + if (ctx) + ctx->log.loglevel = level; +} + +void +gf_log_flush (void) { - xlator_t *xl = this; - if (!xl) - return 0; - return xl->loglevel; + xlator_t *this = NULL; + glusterfs_ctx_t *ctx = NULL; + + this = THIS; + ctx = this->ctx; + + if (ctx && ctx->log.logger == gf_logger_glusterlog) { + pthread_mutex_lock (&ctx->log.logfile_mutex); + fflush (ctx->log.gf_log_logfile); + pthread_mutex_unlock (&ctx->log.logfile_mutex); + } + + return; } void @@ -107,9 +157,142 @@ gf_log_set_xl_loglevel (void *this, gf_loglevel_t level) xl->loglevel = level; } +/* TODO: The following get/set functions are yet not invoked from anywhere + * in the code. The _intention_ is to pass CLI arguments to various daemons + * that are started, which would then invoke these set APIs as required. + * + * glusterd would read the defaults from its .vol file configuration shipped + * as a part of the packages distributed. + * + * For any gluster* daemon that is started the shipped configuration becomes the + * default, if a volume has to change its logging format or logger, then a + * gluster CLI is invoked to set this property for the volume in question. + * + * The property is maintained by glusterd, and passed to the daemon as a CLI + * option, IOW persistence of the option is maintained by glusterd persistent + * storage (i.e .vol file) only + * + * care needs to be taken to configure and start daemons based on the versions + * that supports these features */ +gf_log_format_t +gf_log_get_logformat (void) +{ + glusterfs_ctx_t *ctx = NULL; + + ctx = THIS->ctx; + + if (ctx) + return ctx->log.logformat; + else + /* return global defaluts (see gf_log_globals_init) */ + return gf_logformat_withmsgid; +} + +void +gf_log_set_logformat (gf_log_format_t format) +{ + glusterfs_ctx_t *ctx = NULL; + + ctx = THIS->ctx; + + if (ctx) + ctx->log.logformat = format; +} + +gf_log_logger_t +gf_log_get_logger (void) +{ + glusterfs_ctx_t *ctx = NULL; + + ctx = THIS->ctx; + + if (ctx) + return ctx->log.logger; + else + /* return global defaluts (see gf_log_globals_init) */ + return gf_logger_glusterlog; +} + +void +gf_log_set_logger (gf_log_logger_t logger) +{ + glusterfs_ctx_t *ctx = NULL; + + ctx = THIS->ctx; + + if (ctx) + ctx->log.logger = logger; +} + +gf_loglevel_t +gf_log_get_xl_loglevel (void *this) +{ + xlator_t *xl = this; + if (!xl) + return 0; + return xl->loglevel; +} + +static void +gf_log_rotate(glusterfs_ctx_t *ctx) +{ + int fd = -1; + FILE *new_logfile = NULL; + FILE *old_logfile = NULL; + + /* not involving locks on initial check to speed it up */ + if (ctx->log.logrotate) { + /* let only one winner through on races */ + pthread_mutex_lock (&ctx->log.logfile_mutex); + + if (!ctx->log.logrotate) { + pthread_mutex_unlock (&ctx->log.logfile_mutex); + return; + } else { + ctx->log.logrotate = 0; + pthread_mutex_unlock (&ctx->log.logfile_mutex); + } + + fd = open (ctx->log.filename, + O_CREAT | O_RDONLY, S_IRUSR | S_IWUSR); + if (fd < 0) { + gf_log ("logrotate", GF_LOG_ERROR, + "%s", strerror (errno)); + return; + } + close (fd); + + new_logfile = fopen (ctx->log.filename, "a"); + if (!new_logfile) { + gf_log ("logrotate", GF_LOG_CRITICAL, + "failed to open logfile %s (%s)", + ctx->log.filename, strerror (errno)); + return; + } + + pthread_mutex_lock (&ctx->log.logfile_mutex); + { + if (ctx->log.logfile) + old_logfile = ctx->log.logfile; + + ctx->log.gf_log_logfile = ctx->log.logfile = + new_logfile; + } + pthread_mutex_unlock (&ctx->log.logfile_mutex); + + if (old_logfile != NULL) + fclose (old_logfile); + } + + return; +} + void gf_log_globals_fini (void) { + /* TODO: Nobody is invoking the fini, but cleanup needs to happen here, + * needs cleanup for, log.ident, log.filename, closelog, log file close + * rotate state, possibly under a lock */ pthread_mutex_destroy (&THIS->ctx->log.logfile_mutex); } @@ -122,7 +305,8 @@ int gf_log_fini (void *data) { glusterfs_ctx_t *ctx = data; - int ret = 0; + int ret = 0; + FILE *old_logfile = NULL; if (ctx == NULL) { ret = -1; @@ -132,8 +316,8 @@ gf_log_fini (void *data) pthread_mutex_lock (&ctx->log.logfile_mutex); { if (ctx->log.logfile) { - if (fclose (ctx->log.logfile) != 0) - ret = -1; + old_logfile = ctx->log.logfile; + /* Logfile needs to be set to NULL, so that any call to gf_log after calling gf_log_fini, will log the message to stderr. @@ -144,11 +328,13 @@ gf_log_fini (void *data) } pthread_mutex_unlock (&ctx->log.logfile_mutex); + if (old_logfile && (fclose (old_logfile) != 0)) + ret = -1; + out: return ret; } -#ifdef GF_USE_SYSLOG /** * gf_get_error_message -function to get error message for given error code * @error_code: error code defined by log book @@ -186,10 +372,13 @@ gf_openlog (const char *ident, int option, int facility) _facility = LOG_LOCAL1; } + /* TODO: Should check for errors here and return appropriately */ setlocale(LC_ALL, ""); bindtextdomain("gluster", "/usr/share/locale"); textdomain("gluster"); + /* close the previous syslog if open as we are changing settings */ + closelog (); openlog(ident, _option, _facility); } @@ -347,7 +536,6 @@ gf_syslog (int error_code, int facility_priority, char *format, ...) } va_end (ap); } -#endif /* GF_USE_SYSLOG */ void gf_log_globals_init (void *data) @@ -359,47 +547,45 @@ gf_log_globals_init (void *data) ctx->log.loglevel = GF_LOG_INFO; ctx->log.gf_log_syslog = 1; ctx->log.sys_log_level = GF_LOG_CRITICAL; + ctx->log.logger = gf_logger_glusterlog; + ctx->log.logformat = gf_logformat_withmsgid; -#ifndef GF_USE_SYSLOG #ifdef GF_LINUX_HOST_OS /* For the 'syslog' output. one can grep 'GlusterFS' in syslog for serious logs */ openlog ("GlusterFS", LOG_PID, LOG_DAEMON); #endif -#endif + } int gf_log_init (void *data, const char *file, const char *ident) { glusterfs_ctx_t *ctx = NULL; - int fd = -1; + int fd = -1; + struct stat buf; ctx = data; -#if defined(GF_USE_SYSLOG) - { - /* use default ident and option */ - /* TODO: make FACILITY configurable than LOG_DAEMON */ - struct stat buf; - - if (stat (GF_LOG_CONTROL_FILE, &buf) == 0) { - /* use syslog logging */ - ctx->log.log_control_file_found = 1; - if (ident) { - /* we need to keep this value as */ - /* syslog uses it on every logging */ - ctx->log.ident = gf_strdup (ident); - gf_openlog (ctx->log.ident, -1, LOG_DAEMON); - } else { - gf_openlog (NULL, -1, LOG_DAEMON); - } - } else { - /* use old style logging */ - ctx->log.log_control_file_found = 0; - } + if (ident) { + ctx->log.ident = gf_strdup (ident); + } + + /* we keep the files and the syslog open, so that on logger change, we + * are ready to log anywhere, that the new value specifies */ + if (ctx->log.ident) { + gf_openlog (ctx->log.ident, -1, LOG_DAEMON); + } else { + gf_openlog (NULL, -1, LOG_DAEMON); + } + /* TODO: make FACILITY configurable than LOG_DAEMON */ + if (stat (GF_LOG_CONTROL_FILE, &buf) == 0) { + /* use syslog logging */ + ctx->log.log_control_file_found = 1; + } else { + /* use old style logging */ + ctx->log.log_control_file_found = 0; } -#endif if (!file){ fprintf (stderr, "ERROR: no filename specified\n"); @@ -407,7 +593,7 @@ gf_log_init (void *data, const char *file, const char *ident) } if (strcmp (file, "-") == 0) { - file = "/dev/stderr"; + file = "/dev/stderr"; } ctx->log.filename = gf_strdup (file); @@ -419,8 +605,8 @@ gf_log_init (void *data, const char *file, const char *ident) fd = open (file, O_CREAT | O_RDONLY, S_IRUSR | S_IWUSR); if (fd < 0) { - fprintf (stderr, "ERROR: failed to create logfile \"%s\" (%s)\n", - file, strerror (errno)); + fprintf (stderr, "ERROR: failed to create logfile" + " \"%s\" (%s)\n", file, strerror (errno)); return -1; } close (fd); @@ -440,21 +626,29 @@ gf_log_init (void *data, const char *file, const char *ident) void set_sys_log_level (gf_loglevel_t level) { - THIS->ctx->log.sys_log_level = level; + glusterfs_ctx_t *ctx = NULL; + + ctx = THIS->ctx; + + if (ctx) + ctx->log.sys_log_level = level; } int -_gf_log_nomem (const char *domain, const char *file, - const char *function, int line, gf_loglevel_t level, - size_t size) +_gf_log_callingfn (const char *domain, const char *file, const char *function, + int line, gf_loglevel_t level, const char *fmt, ...) { const char *basename = NULL; xlator_t *this = NULL; - struct timeval tv = {0,}; - int ret = 0; - char msg[8092] = {0,}; + char *str1 = NULL; + char *str2 = NULL; + char *msg = NULL; char timestr[256] = {0,}; char callstr[4096] = {0,}; + struct timeval tv = {0,}; + size_t len = 0; + int ret = 0; + va_list ap; glusterfs_ctx_t *ctx = NULL; this = THIS; @@ -479,7 +673,7 @@ _gf_log_nomem (const char *domain, const char *file, "T", /* TRACE */ ""}; - if (!domain || !file || !function) { + if (!domain || !file || !function || !fmt) { fprintf (stderr, "logging: %s:%s():%d: invalid argument\n", __FILE__, __PRETTY_FUNCTION__, __LINE__); @@ -497,28 +691,27 @@ _gf_log_nomem (const char *domain, const char *file, do { void *array[5]; char **callingfn = NULL; - size_t bt_size = 0; + size_t size = 0; - bt_size = backtrace (array, 5); - if (bt_size) - callingfn = backtrace_symbols (&array[2], bt_size-2); + size = backtrace (array, 5); + if (size) + callingfn = backtrace_symbols (&array[2], size-2); if (!callingfn) break; - if (bt_size == 5) + if (size == 5) snprintf (callstr, 4096, "(-->%s (-->%s (-->%s)))", callingfn[2], callingfn[1], callingfn[0]); - if (bt_size == 4) + if (size == 4) snprintf (callstr, 4096, "(-->%s (-->%s))", callingfn[1], callingfn[0]); - if (bt_size == 3) + if (size == 3) snprintf (callstr, 4096, "(-->%s)", callingfn[0]); free (callingfn); } while (0); #endif /* HAVE_BACKTRACE */ -#if defined(GF_USE_SYSLOG) if (ctx->log.log_control_file_found) { int priority; @@ -529,30 +722,50 @@ _gf_log_nomem (const char *domain, const char *file, } else { priority = level - 1; } + + va_start (ap, fmt); + vasprintf (&str2, fmt, ap); + va_end (ap); + gf_syslog (GF_ERR_DEV, priority, - "[%s:%d:%s] %s %s: no memory " - "available for size (%"GF_PRI_SIZET")", - basename, line, function, callstr, domain, - size); + "[%s:%d:%s] %s %d-%s: %s", + basename, line, function, + callstr, + ((this->graph) ? this->graph->id:0), domain, + str2); + goto out; } -#endif /* GF_USE_SYSLOG */ + ret = gettimeofday (&tv, NULL); if (-1 == ret) goto out; + va_start (ap, fmt); gf_time_fmt (timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT); snprintf (timestr + strlen (timestr), sizeof timestr - strlen (timestr), ".%"GF_PRI_SUSECONDS, tv.tv_usec); - ret = sprintf (msg, "[%s] %s [%s:%d:%s] %s %s: no memory " - "available for size (%"GF_PRI_SIZET")", - timestr, level_strings[level], - basename, line, function, callstr, - domain, size); + ret = gf_asprintf (&str1, "[%s] %s [%s:%d:%s] %s %d-%s: ", + timestr, level_strings[level], + basename, line, function, callstr, + ((this->graph) ? this->graph->id:0), domain); + if (-1 == ret) { + goto out; + } + + ret = vasprintf (&str2, fmt, ap); if (-1 == ret) { goto out; } + va_end (ap); + + len = strlen (str1); + msg = GF_MALLOC (len + strlen (str2) + 1, gf_common_mt_char); + + strcpy (msg, str1); + strcpy (msg + len, str2); + pthread_mutex_lock (&ctx->log.logfile_mutex); { if (ctx->log.logfile) { @@ -571,30 +784,82 @@ _gf_log_nomem (const char *domain, const char *file, } pthread_mutex_unlock (&ctx->log.logfile_mutex); + out: + GF_FREE (msg); + + GF_FREE (str1); + + FREE (str2); + return ret; - } +} int -_gf_log_callingfn (const char *domain, const char *file, const char *function, - int line, gf_loglevel_t level, const char *fmt, ...) +_gf_msg_plain_internal (gf_loglevel_t level, const char *msg) { - const char *basename = NULL; - xlator_t *this = NULL; - char *str1 = NULL; - char *str2 = NULL; - char *msg = NULL; - char timestr[256] = {0,}; - char callstr[4096] = {0,}; - struct timeval tv = {0,}; - size_t len = 0; - int ret = 0; - va_list ap; + xlator_t *this = NULL; + glusterfs_ctx_t *ctx = NULL; + int priority; + + this = THIS; + ctx = this->ctx; + + /* log to the configured logging service */ + switch (ctx->log.logger) { + case gf_logger_syslog: + if (ctx->log.log_control_file_found && ctx->log.gf_log_syslog) { + SET_LOG_PRIO (level, priority); + + syslog (priority, "%s", msg); + break; + } + /* NOTE: If syslog control file is absent, which is another + * way to control logging to syslog, then we will fall through + * to the gluster log. The ideal way to do things would be to + * not have the extra control file check */ + case gf_logger_glusterlog: + pthread_mutex_lock (&ctx->log.logfile_mutex); + { + if (ctx->log.logfile) { + fprintf (ctx->log.logfile, "%s\n", msg); + fflush (ctx->log.logfile); + } else { + fprintf (stderr, "%s\n", msg); + fflush (stderr); + } + +#ifdef GF_LINUX_HOST_OS + /* We want only serious logs in 'syslog', not our debug + * and trace logs */ + if (ctx->log.gf_log_syslog && level && + (level <= ctx->log.sys_log_level)) + syslog ((level-1), "%s\n", msg); +#endif + } + pthread_mutex_unlock (&ctx->log.logfile_mutex); + + break; + } + + return 0; +} + +int +_gf_msg_plain (gf_loglevel_t level, const char *fmt, ...) +{ + xlator_t *this = NULL; + int ret = 0; + va_list ap; + char *msg = NULL; glusterfs_ctx_t *ctx = NULL; this = THIS; ctx = this->ctx; + if (!ctx) + goto out; + if (ctx->log.gf_log_xl_log_set) { if (this->loglevel && (level > this->loglevel)) goto out; @@ -602,141 +867,604 @@ _gf_log_callingfn (const char *domain, const char *file, const char *function, if (level > ctx->log.loglevel) goto out; - static char *level_strings[] = {"", /* NONE */ - "M", /* EMERGENCY */ - "A", /* ALERT */ - "C", /* CRITICAL */ - "E", /* ERROR */ - "W", /* WARNING */ - "N", /* NOTICE */ - "I", /* INFO */ - "D", /* DEBUG */ - "T", /* TRACE */ - ""}; + va_start (ap, fmt); + ret = vasprintf (&msg, fmt, ap); + va_end (ap); + if (-1 == ret) { + goto out; + } - if (!domain || !file || !function || !fmt) { - fprintf (stderr, - "logging: %s:%s():%d: invalid argument\n", - __FILE__, __PRETTY_FUNCTION__, __LINE__); - return -1; + ret = _gf_msg_plain_internal (level, msg); + + FREE (msg); + +out: + return ret; +} + +int +_gf_msg_vplain (gf_loglevel_t level, const char *fmt, va_list ap) +{ + xlator_t *this = NULL; + int ret = 0; + char *msg = NULL; + glusterfs_ctx_t *ctx = NULL; + + this = THIS; + ctx = this->ctx; + + if (!ctx) + goto out; + + if (ctx->log.gf_log_xl_log_set) { + if (this->loglevel && (level > this->loglevel)) + goto out; } + if (level > ctx->log.loglevel) + goto out; - basename = strrchr (file, '/'); - if (basename) - basename++; - else - basename = file; + ret = vasprintf (&msg, fmt, ap); + if (-1 == ret) { + goto out; + } + + ret = _gf_msg_plain_internal (level, msg); + + FREE (msg); +out: + return ret; +} + +int +_gf_msg_plain_nomem (gf_loglevel_t level, const char *msg) +{ + xlator_t *this = NULL; + int ret = 0; + glusterfs_ctx_t *ctx = NULL; + + this = THIS; + ctx = this->ctx; + + if (!ctx) + goto out; + + if (ctx->log.gf_log_xl_log_set) { + if (this->loglevel && (level > this->loglevel)) + goto out; + } + if (level > ctx->log.loglevel) + goto out; + + ret = _gf_msg_plain_internal (level, msg); + +out: + return ret; +} #if HAVE_BACKTRACE - /* Print 'calling function' */ - do { - void *array[5]; - char **callingfn = NULL; - size_t size = 0; +void +_gf_msg_backtrace_nomem (gf_loglevel_t level, int stacksize) +{ + xlator_t *this = NULL; + glusterfs_ctx_t *ctx = NULL; + void *array[200]; + size_t bt_size = 0; + int fd = -1; - size = backtrace (array, 5); - if (size) - callingfn = backtrace_symbols (&array[2], size-2); - if (!callingfn) - break; + this = THIS; + ctx = this->ctx; - if (size == 5) - snprintf (callstr, 4096, "(-->%s (-->%s (-->%s)))", - callingfn[2], callingfn[1], callingfn[0]); - if (size == 4) - snprintf (callstr, 4096, "(-->%s (-->%s))", - callingfn[1], callingfn[0]); - if (size == 3) - snprintf (callstr, 4096, "(-->%s)", callingfn[0]); + if (!ctx) + goto out; - free (callingfn); - } while (0); -#endif /* HAVE_BACKTRACE */ + /* syslog does not have fd support, hence no no-mem variant */ + if (ctx->log.logger != gf_logger_glusterlog) + goto out; -#if defined(GF_USE_SYSLOG) - if (ctx->log.log_control_file_found) + if (ctx->log.gf_log_xl_log_set) { + if (this->loglevel && (level > this->loglevel)) + goto out; + } + if (level > ctx->log.loglevel) + goto out; + + bt_size = backtrace (array, ((stacksize <= 200)? stacksize : 200)); + pthread_mutex_lock (&ctx->log.logfile_mutex); { - int priority; - /* treat GF_LOG_TRACE and GF_LOG_NONE as LOG_DEBUG and - other level as is */ - if (GF_LOG_TRACE == level || GF_LOG_NONE == level) { - priority = LOG_DEBUG; - } else { - priority = level - 1; + fd = ctx->log.logfile? + fileno (ctx->log.logfile) : + fileno (stderr); + if (bt_size && (fd != -1)) { + /* print to the file fd, to prevent any + * allocations from backtrace_symbols */ + backtrace_symbols_fd (&array[0], bt_size, fd); } + } + pthread_mutex_unlock (&ctx->log.logfile_mutex); - va_start (ap, fmt); - vasprintf (&str2, fmt, ap); - va_end (ap); +out: + return; +} - gf_syslog (GF_ERR_DEV, priority, - "[%s:%d:%s] %s %d-%s: %s", - basename, line, function, - callstr, - ((this->graph) ? this->graph->id:0), domain, - str2); +int +_gf_msg_backtrace (int stacksize, char *callstr, size_t strsize) +{ + int ret = -1; + int i = 0; + int size = 0; + int savstrsize = strsize; + void *array[200]; + char **callingfn = NULL; + + /* We chop off last 2 anyway, so if request is less than tolerance + * nothing to do */ + if (stacksize < 3) + goto out; + size = backtrace (array, ((stacksize <= 200)? stacksize : 200)); + if ((size - 3) < 0) + goto out; + if (size) + callingfn = backtrace_symbols (&array[2], size - 2); + if (!callingfn) goto out; + + ret = snprintf (callstr, strsize, "("); + PRINT_SIZE_CHECK (ret, out, strsize); + + for ((i = size - 3); i >= 0; i--) { + ret = snprintf (callstr + savstrsize - strsize, strsize, + "-->%s ", callingfn[i]); + PRINT_SIZE_CHECK (ret, out, strsize); } -#endif /* GF_USE_SYSLOG */ + + ret = snprintf (callstr + savstrsize - strsize, strsize, ")"); + PRINT_SIZE_CHECK (ret, out, strsize); +out: + FREE (callingfn); + return ret; +} +#endif /* HAVE_BACKTRACE */ + +int +_gf_msg_nomem (const char *domain, const char *file, + const char *function, int line, gf_loglevel_t level, + size_t size) +{ + const char *basename = NULL; + xlator_t *this = NULL; + struct timeval tv = {0,}; + int ret = 0; + int fd = -1; + char msg[2048] = {0,}; + char timestr[GF_LOG_TIMESTR_SIZE] = {0,}; + glusterfs_ctx_t *ctx = NULL; + int wlen = 0; + int priority; + + this = THIS; + ctx = this->ctx; + + if (!ctx) + goto out; + + if (ctx->log.gf_log_xl_log_set) { + if (this->loglevel && (level > this->loglevel)) + goto out; + } + if (level > ctx->log.loglevel) + goto out; + + if (!domain || !file || !function) { + fprintf (stderr, + "logging: %s:%s():%d: invalid argument\n", + __FILE__, __PRETTY_FUNCTION__, __LINE__); + return -1; + } + + GET_FILE_NAME_TO_LOG (file, basename); + ret = gettimeofday (&tv, NULL); if (-1 == ret) goto out; - va_start (ap, fmt); gf_time_fmt (timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT); - snprintf (timestr + strlen (timestr), sizeof timestr - strlen (timestr), - ".%"GF_PRI_SUSECONDS, tv.tv_usec); - - ret = gf_asprintf (&str1, "[%s] %s [%s:%d:%s] %s %d-%s: ", - timestr, level_strings[level], - basename, line, function, callstr, - ((this->graph) ? this->graph->id:0), domain); + ret = snprintf (timestr + strlen (timestr), + sizeof timestr - strlen (timestr), + ".%"GF_PRI_SUSECONDS, tv.tv_usec); if (-1 == ret) { goto out; } - ret = vasprintf (&str2, fmt, ap); + /* TODO: Currently we print in the enhanced format, with a message ID + * of 0. Need to enhance this to support format as configured */ + ret = snprintf (msg, sizeof msg, "[%s] %s [MSGID: %"PRIu64"]" + " [%s:%d:%s] %s: no memory " + "available for size (%"GF_PRI_SIZET")" + " [call stack follows]\n", + timestr, gf_level_strings[level], (uint64_t) 0, + basename, line, function, domain, size); if (-1 == ret) { goto out; } - va_end (ap); + /* log to the configured logging service */ + switch (ctx->log.logger) { + case gf_logger_syslog: + if (ctx->log.log_control_file_found && ctx->log.gf_log_syslog) { + SET_LOG_PRIO (level, priority); - len = strlen (str1); - msg = GF_MALLOC (len + strlen (str2) + 1, gf_common_mt_char); + /* if syslog allocates, then this may fail, but we + * cannot do much about it at the moment */ + /* There is no fd for syslog, hence no stack printed */ + syslog (priority, "%s", msg); + break; + } + /* NOTE: If syslog control file is absent, which is another + * way to control logging to syslog, then we will fall through + * to the gluster log. The ideal way to do things would be to + * not have the extra control file check */ + case gf_logger_glusterlog: + pthread_mutex_lock (&ctx->log.logfile_mutex); + { + fd = ctx->log.logfile? fileno (ctx->log.logfile) : + fileno (stderr); + if (fd == -1) { + pthread_mutex_unlock (&ctx->log.logfile_mutex); + goto out; + } - strcpy (msg, str1); - strcpy (msg + len, str2); + wlen = strlen (msg); + + /* write directly to the fd to prevent out of order + * message and stack */ + ret = write (fd, msg, wlen); + if (ret == -1) { + pthread_mutex_unlock (&ctx->log.logfile_mutex); + goto out; + } +#ifdef GF_LINUX_HOST_OS + /* We want only serious log in 'syslog', not our debug + * and trace logs */ + if (ctx->log.gf_log_syslog && level && + (level <= ctx->log.sys_log_level)) + syslog ((level-1), "%s\n", msg); +#endif + } + pthread_mutex_unlock (&ctx->log.logfile_mutex); + +#ifdef HAVE_BACKTRACE + _gf_msg_backtrace_nomem (level, GF_LOG_BACKTRACE_DEPTH); +#endif + + break; + } + +out: + return ret; +} + +static int +gf_log_syslog (const char *domain, const char *file, const char *function, + int32_t line, gf_loglevel_t level, int errnum, + uint64_t msgid, char **appmsgstr, char *callstr) +{ + int priority; + xlator_t *this = NULL; + glusterfs_ctx_t *ctx = NULL; + + this = THIS; + ctx = this->ctx; + + SET_LOG_PRIO (level, priority); + + /* log with appropriate format */ + if (ctx->log.logformat == gf_logformat_traditional) { + if (!callstr) { + if (errnum) { + syslog (priority, "[%s:%d:%s] %d-%s: %s [%s]", + file, line, function, + ((this->graph)?this->graph->id:0), + domain, *appmsgstr, strerror(errnum)); + } else { + syslog (priority, "[%s:%d:%s] %d-%s: %s", + file, line, function, + ((this->graph)?this->graph->id:0), + domain, *appmsgstr); + } + } else { + if (errnum) { + syslog (priority, "[%s:%d:%s] %s %d-%s:" + " %s [%s]", + file, line, function, callstr, + ((this->graph)?this->graph->id:0), + domain, *appmsgstr, strerror(errnum)); + } else { + syslog (priority, "[%s:%d:%s] %s %d-%s: %s", + file, line, function, callstr, + ((this->graph)?this->graph->id:0), + domain, *appmsgstr); + } + } + } else if (ctx->log.logformat == gf_logformat_withmsgid) { + if (!callstr) { + if (errnum) { + syslog (priority, "[MSGID: %"PRIu64"]" + " [%s:%d:%s] %d-%s: %s [%s]", + msgid, file, line, function, + ((this->graph)?this->graph->id:0), + domain, *appmsgstr, strerror(errnum)); + } else { + syslog (priority, "[MSGID: %"PRIu64"]" + " [%s:%d:%s] %d-%s: %s", + msgid, file, line, function, + ((this->graph)?this->graph->id:0), + domain, *appmsgstr); + } + } else { + if (errnum) { + syslog (priority, "[MSGID: %"PRIu64"]" + " [%s:%d:%s] %s %d-%s: %s [%s]", + msgid, file, line, function, callstr, + ((this->graph)?this->graph->id:0), + domain, *appmsgstr, strerror(errnum)); + } else { + syslog (priority, "[MSGID: %"PRIu64"]" + " [%s:%d:%s] %s %d-%s: %s", + msgid, file, line, function, callstr, + ((this->graph)?this->graph->id:0), + domain, *appmsgstr); + } + } + } else if (ctx->log.logformat == gf_logformat_cee) { + /* TODO: Enhance CEE with additional parameters */ + gf_syslog (GF_ERR_DEV, priority, + "[%s:%d:%s] %d-%s: %s", + file, line, function, + ((this->graph) ? this->graph->id:0), + domain, *appmsgstr); + } else { + /* NOTE: should not get here without logging */ + } + + /* TODO: There can be no errors from gf_syslog? */ + return 0; +} + +static int +gf_log_glusterlog (const char *domain, const char *file, const char *function, + int32_t line, gf_loglevel_t level, int errnum, + uint64_t msgid, char **appmsgstr, char *callstr) +{ + char timestr[GF_LOG_TIMESTR_SIZE] = {0,}; + struct timeval tv = {0,}; + char *header = NULL; + char *footer = NULL; + char *msg = NULL; + size_t hlen = 0, flen = 0, mlen = 0; + int ret = 0; + xlator_t *this = NULL; + glusterfs_ctx_t *ctx = NULL; + + this = THIS; + ctx = this->ctx; + + /* rotate if required */ + gf_log_rotate(ctx); + + /* format the time stanp */ + ret = gettimeofday (&tv, NULL); + if (-1 == ret) + goto out; + gf_time_fmt (timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT); + snprintf (timestr + strlen (timestr), sizeof timestr - strlen (timestr), + ".%"GF_PRI_SUSECONDS, tv.tv_usec); + + /* generate header and footer */ + if (ctx->log.logformat == gf_logformat_traditional) { + if (!callstr) { + ret = gf_asprintf (&header, "[%s] %s [%s:%d:%s]" + " %d-%s: ", + timestr, gf_level_strings[level], + file, line, function, + ((this->graph)?this->graph->id:0), + domain); + } else { + ret = gf_asprintf (&header, "[%s] %s [%s:%d:%s] %s" + " %d-%s: ", + timestr, gf_level_strings[level], + file, line, function, callstr, + ((this->graph)?this->graph->id:0), + domain); + } + if (-1 == ret) { + goto err; + } + } else { /* gf_logformat_withmsgid */ + /* CEE log format unsupported in logger_glusterlog, so just + * print enhanced log format */ + if (!callstr) { + ret = gf_asprintf (&header, "[%s] %s [MSGID: %"PRIu64"]" + " [%s:%d:%s] %d-%s: ", + timestr, gf_level_strings[level], + msgid, file, line, function, + ((this->graph)?this->graph->id:0), + domain); + } else { + ret = gf_asprintf (&header, "[%s] %s [MSGID: %"PRIu64"]" + " [%s:%d:%s] %s %d-%s: ", + timestr, gf_level_strings[level], + msgid, file, line, function, callstr, + ((this->graph)?this->graph->id:0), + domain); + } + if (-1 == ret) { + goto err; + } + } + + if (errnum) { + ret = gf_asprintf (&footer, " [%s]",strerror(errnum)); + if (-1 == ret) { + goto err; + } + } + + /* generate the full message to log */ + hlen = strlen (header); + flen = footer? strlen (footer) : 0; + mlen = strlen (*appmsgstr); + msg = GF_MALLOC (hlen + flen + mlen + 1, gf_common_mt_char); + + strcpy (msg, header); + strcpy (msg + hlen, *appmsgstr); + if (footer) + strcpy (msg + hlen + mlen, footer); pthread_mutex_lock (&ctx->log.logfile_mutex); { if (ctx->log.logfile) { fprintf (ctx->log.logfile, "%s\n", msg); + fflush (ctx->log.logfile); } else if (ctx->log.loglevel >= level) { fprintf (stderr, "%s\n", msg); + fflush (stderr); } #ifdef GF_LINUX_HOST_OS - /* We want only serious log in 'syslog', not our debug - and trace logs */ + /* We want only serious logs in 'syslog', not our debug + * and trace logs */ if (ctx->log.gf_log_syslog && level && - (level <= ctx->log.sys_log_level)) + (level <= ctx->log.sys_log_level)) syslog ((level-1), "%s\n", msg); #endif } + /* TODO: Plugin in memory log buffer retention here. For logs not + * flushed during cores, it would be useful to retain some of the last + * few messages in memory */ pthread_mutex_unlock (&ctx->log.logfile_mutex); -out: +err: GF_FREE (msg); + GF_FREE (header); + GF_FREE (footer); - GF_FREE (str1); +out: + return ret; +} - FREE (str2); +static int +_gf_msg_internal (const char *domain, const char *file, const char *function, + int32_t line, gf_loglevel_t level, int errnum, uint64_t msgid, + char **appmsgstr, char *callstr) +{ + const char *basename = NULL; + int ret = -1; + xlator_t *this = NULL; + glusterfs_ctx_t *ctx = NULL; + + this = THIS; + ctx = this->ctx; + + GET_FILE_NAME_TO_LOG (file, basename); + + /* TODO: Plug in repeated message suppression for gluster logs here. + * Comparison of last few messages stored based on, appmsgstr, errnum + * msgid. */ + /* log to the configured logging service */ + switch (ctx->log.logger) { + case gf_logger_syslog: + if (ctx->log.log_control_file_found && ctx->log.gf_log_syslog) { + ret = gf_log_syslog (domain, basename, function, line, + level, errnum, msgid, appmsgstr, + callstr); + break; + } + /* NOTE: If syslog control file is absent, which is another + * way to control logging to syslog, then we will fall through + * to the gluster log. The ideal way to do things would be to + * not have the extra control file check */ + case gf_logger_glusterlog: + ret = gf_log_glusterlog (domain, basename, function, line, + level, errnum, msgid, appmsgstr, + callstr); + break; + } + + return ret; +} + +int +_gf_msg (const char *domain, const char *file, const char *function, + int32_t line, gf_loglevel_t level, int errnum, int trace, + uint64_t msgid, const char *fmt, ...) +{ + int ret = 0; + char *msgstr = NULL; + va_list ap; + xlator_t *this = NULL; + glusterfs_ctx_t *ctx = NULL; + char callstr[GF_LOG_BACKTRACE_SIZE] = {0,}; + int passcallstr = 0; + + /* in args check */ + if (!domain || !file || !function || !fmt) { + fprintf (stderr, + "logging: %s:%s():%d: invalid argument\n", + __FILE__, __PRETTY_FUNCTION__, __LINE__); + return -1; + } + + this = THIS; + ctx = this->ctx; + if (ctx == NULL) { + /* messages before context initialization are ignored */ + return -1; + } + + /* check if we should be logging */ + if (ctx->log.gf_log_xl_log_set) { + if (this->loglevel && (level > this->loglevel)) + goto out; + } + if (level > ctx->log.loglevel) + goto out; + +#if HAVE_BACKTRACE + if (trace) { + ret = _gf_msg_backtrace (GF_LOG_BACKTRACE_DEPTH, callstr, + GF_LOG_BACKTRACE_DEPTH); + if (ret >= 0) + passcallstr = 1; + else + ret = 0; + } +#endif /* HAVE_BACKTRACE */ + + /* form the message */ + va_start (ap, fmt); + ret = vasprintf (&msgstr, fmt, ap); + va_end (ap); + + /* log */ + if (ret != -1) + ret = _gf_msg_internal(domain, file, function, line, level, + errnum, msgid, &msgstr, + (passcallstr? callstr : NULL)); + else + /* man (3) vasprintf states on error strp contents + * are undefined, be safe */ + msgstr = NULL; + + FREE (msgstr); + +out: return ret; } +/* TODO: Deprecate (delete) _gf_log, _gf_log_callingfn, + * once messages are changed to use _gf_msgXXX APIs for logging */ int _gf_log (const char *domain, const char *file, const char *function, int line, gf_loglevel_t level, const char *fmt, ...) @@ -744,7 +1472,7 @@ _gf_log (const char *domain, const char *file, const char *function, int line, const char *basename = NULL; FILE *new_logfile = NULL; va_list ap; - char timestr[256] = {0,}; + char timestr[GF_LOG_TIMESTR_SIZE] = {0,}; struct timeval tv = {0,}; char *str1 = NULL; char *str2 = NULL; @@ -790,7 +1518,6 @@ _gf_log (const char *domain, const char *file, const char *function, int line, else basename = file; -#if defined(GF_USE_SYSLOG) if (ctx->log.log_control_file_found) { int priority; @@ -812,7 +1539,6 @@ _gf_log (const char *domain, const char *file, const char *function, int line, ((this->graph) ? this->graph->id:0), domain, str2); goto err; } -#endif /* GF_USE_SYSLOG */ if (ctx->log.logrotate) { ctx->log.logrotate = 0; @@ -839,7 +1565,8 @@ _gf_log (const char *domain, const char *file, const char *function, int line, if (ctx->log.logfile) fclose (ctx->log.logfile); - ctx->log.gf_log_logfile = ctx->log.logfile = new_logfile; + ctx->log.gf_log_logfile = + ctx->log.logfile = new_logfile; } pthread_mutex_unlock (&ctx->log.logfile_mutex); @@ -1033,7 +1760,8 @@ gf_cmd_log (const char *domain, const char *fmt, ...) goto out; va_start (ap, fmt); gf_time_fmt (timestr, sizeof timestr, tv.tv_sec, gf_timefmt_FT); - snprintf (timestr + strlen (timestr), 256 - strlen (timestr), + snprintf (timestr + strlen (timestr), + GF_LOG_TIMESTR_SIZE - strlen (timestr), ".%"GF_PRI_SUSECONDS, tv.tv_usec); ret = gf_asprintf (&str1, "[%s] %s : ", diff --git a/libglusterfs/src/logging.h b/libglusterfs/src/logging.h index e2b7e664d0f..b6b13fbd02a 100644 --- a/libglusterfs/src/logging.h +++ b/libglusterfs/src/logging.h @@ -61,6 +61,20 @@ typedef enum { GF_LOG_TRACE, /* full trace of operation */ } gf_loglevel_t; +/* format for the logs */ +typedef enum { + gf_logformat_traditional = 0, /* Format as in gluster 3.5 */ + gf_logformat_withmsgid, /* Format enhanced with MsgID, ident, errstr */ + gf_logformat_cee /* log enhanced format in cee */ +} gf_log_format_t; + +/* log infrastructure to log to */ +typedef enum { + gf_logger_glusterlog = 0, /* locations and files as in gluster 3.5 */ + gf_logger_syslog /* log to (r)syslog, based on (r)syslog conf */ + /* NOTE: In the future journald, lumberjack, next new thing here */ +} gf_log_logger_t; + #define DEFAULT_LOG_FILE_DIRECTORY DATADIR "/log/glusterfs" #define DEFAULT_LOG_LEVEL GF_LOG_INFO @@ -76,11 +90,10 @@ typedef struct gf_log_handle_ { FILE *gf_log_logfile; char *cmd_log_filename; FILE *cmdlogfile; -#ifdef GF_USE_SYSLOG - int log_control_file_found; + gf_log_logger_t logger; + gf_log_format_t logformat; char *ident; -#endif /* GF_USE_SYSLOG */ - + int log_control_file_found; } gf_log_handle_t; void gf_log_globals_init (void *ctx); @@ -90,25 +103,117 @@ void gf_log_logrotate (int signum); void gf_log_cleanup (void); +/* Internal interfaces to log messages with message IDs */ +int _gf_msg (const char *domain, const char *file, + const char *function, int32_t line, gf_loglevel_t level, + int errnum, int trace, uint64_t msgid, const char *fmt, ...) + __attribute__ ((__format__ (__printf__, 9, 10))); + +void _gf_msg_backtrace_nomem (gf_loglevel_t level, int stacksize); + +int _gf_msg_plain (gf_loglevel_t level, const char *fmt, ...) + __attribute__ ((__format__ (__printf__, 2, 3))); + +int _gf_msg_plain_nomem (gf_loglevel_t level, const char *msg); + +int _gf_msg_vplain (gf_loglevel_t level, const char *fmt, va_list ap); + +int _gf_msg_nomem (const char *domain, const char *file, + const char *function, int line, gf_loglevel_t level, + size_t size); + int _gf_log (const char *domain, const char *file, const char *function, int32_t line, gf_loglevel_t level, const char *fmt, ...) __attribute__ ((__format__ (__printf__, 6, 7))); + int _gf_log_callingfn (const char *domain, const char *file, const char *function, int32_t line, gf_loglevel_t level, const char *fmt, ...) __attribute__ ((__format__ (__printf__, 6, 7))); -int _gf_log_nomem (const char *domain, const char *file, - const char *function, int line, gf_loglevel_t level, - size_t size); - int _gf_log_eh (const char *function, const char *fmt, ...); +/* treat GF_LOG_TRACE and GF_LOG_NONE as LOG_DEBUG and + * other level as is */ +#define SET_LOG_PRIO(level, priority) do { \ + if (GF_LOG_TRACE == (level) || GF_LOG_NONE == (level)) { \ + priority = LOG_DEBUG; \ + } else { \ + priority = (level) - 1; \ + } \ + } while (0) + +/* extract just the file name from the path */ +#define GET_FILE_NAME_TO_LOG(file, basename) do { \ + basename = strrchr ((file), '/'); \ + if (basename) \ + basename++; \ + else \ + basename = (file); \ + } while (0) + +#define PRINT_SIZE_CHECK(ret, label, strsize) do { \ + if (ret < 0) \ + goto label; \ + if ((strsize - ret) > 0) { \ + strsize -= ret; \ + } else { \ + ret = 0; \ + goto label; \ + } \ + } while (0) + #define FMT_WARN(fmt...) do { if (0) printf (fmt); } while (0) +/* Interface to log messages with message IDs */ +#define gf_msg(dom, levl, errnum, msgid, fmt...) do { \ + _gf_msg (dom, __FILE__, __FUNCTION__, __LINE__, \ + levl, errnum, 0, msgid, ##fmt); \ + } while (0) + +/* no frills, no thrills, just a vanilla message, used to print the graph */ +#define gf_msg_plain(levl, fmt...) do { \ + _gf_msg_plain (levl, ##fmt); \ + } while (0) + +#define gf_msg_plain_nomem(levl, msg) do { \ + _gf_msg_plain_nomem (levl, msg); \ + } while (0) + +#define gf_msg_vplain(levl, fmt, va) do { \ + _gf_msg_vplain (levl, fmt, va); \ + } while (0) + +#define gf_msg_backtrace_nomem(level, stacksize) do { \ + _gf_msg_backtrace_nomem (level, stacksize); \ + } while (0) + +#define gf_msg_callingfn(dom, levl, errnum, msgid, fmt...) do { \ + _gf_msg (dom, __FILE__, __FUNCTION__, __LINE__, \ + levl, errnum, 1, msgid, ##fmt); \ + } while (0) + +/* No malloc or calloc should be called in this function */ +#define gf_msg_nomem(dom, levl, size) do { \ + _gf_msg_nomem (dom, __FILE__, __FUNCTION__, __LINE__, \ + levl, size); \ + } while (0) + +/* Debug or trace messages do not need message IDs as these are more developer + * related. Hence, the following abstractions are provided for the same */ +#define gf_msg_debug(dom, errnum, fmt...) do { \ + _gf_msg (dom, __FILE__, __FUNCTION__, __LINE__, \ + GF_LOG_DEBUG, errnum, 0, 0, ##fmt); \ + } while (0) + +#define gf_msg_trace(dom, errnum, fmt...) do { \ + _gf_msg (dom, __FILE__, __FUNCTION__, __LINE__, \ + GF_LOG_TRACE, errnum, 0, 0, ##fmt); \ + } while (0) + #define gf_log(dom, levl, fmt...) do { \ FMT_WARN (fmt); \ _gf_log (dom, __FILE__, __FUNCTION__, __LINE__, \ @@ -127,13 +232,6 @@ int _gf_log_eh (const char *function, const char *fmt, ...); } while (0) -/* No malloc or calloc should be called in this function */ -#define gf_log_nomem(dom, levl, size) do { \ - _gf_log_nomem (dom, __FILE__, __FUNCTION__, __LINE__, \ - levl, size); \ - } while (0) - - /* Log once in GF_UNIVERSAL_ANSWER times */ #define GF_LOG_OCCASIONALLY(var, args...) if (!(var++%GF_UNIVERSAL_ANSWER)) { \ gf_log (args); \ @@ -143,6 +241,7 @@ void gf_log_disable_syslog (void); void gf_log_enable_syslog (void); gf_loglevel_t gf_log_get_loglevel (void); void gf_log_set_loglevel (gf_loglevel_t level); +void gf_log_flush (void); gf_loglevel_t gf_log_get_xl_loglevel (void *xl); void gf_log_set_xl_loglevel (void *xl, gf_loglevel_t level); diff --git a/libglusterfs/src/mem-pool.c b/libglusterfs/src/mem-pool.c index b92803d4d3d..c5ff58f4f1b 100644 --- a/libglusterfs/src/mem-pool.c +++ b/libglusterfs/src/mem-pool.c @@ -105,7 +105,7 @@ __gf_calloc (size_t nmemb, size_t size, uint32_t type) ptr = calloc (1, tot_size); if (!ptr) { - gf_log_nomem ("", GF_LOG_ALERT, tot_size); + gf_msg_nomem ("", GF_LOG_ALERT, tot_size); return NULL; } gf_mem_set_acct_info (xl, &ptr, req_size, type); @@ -129,7 +129,7 @@ __gf_malloc (size_t size, uint32_t type) ptr = malloc (tot_size); if (!ptr) { - gf_log_nomem ("", GF_LOG_ALERT, tot_size); + gf_msg_nomem ("", GF_LOG_ALERT, tot_size); return NULL; } gf_mem_set_acct_info (xl, &ptr, size, type); @@ -163,7 +163,7 @@ __gf_realloc (void *ptr, size_t size) new_ptr = realloc (orig_ptr, tot_size); if (!new_ptr) { - gf_log_nomem ("", GF_LOG_ALERT, tot_size); + gf_msg_nomem ("", GF_LOG_ALERT, tot_size); return NULL; } diff --git a/libglusterfs/src/mem-pool.h b/libglusterfs/src/mem-pool.h index aa6bf784363..9ffeef4da30 100644 --- a/libglusterfs/src/mem-pool.h +++ b/libglusterfs/src/mem-pool.h @@ -75,7 +75,7 @@ void* __gf_default_malloc (size_t size) ptr = malloc (size); if (!ptr) - gf_log_nomem ("", GF_LOG_ALERT, size); + gf_msg_nomem ("", GF_LOG_ALERT, size); return ptr; } @@ -87,7 +87,7 @@ void* __gf_default_calloc (int cnt, size_t size) ptr = calloc (cnt, size); if (!ptr) - gf_log_nomem ("", GF_LOG_ALERT, (cnt * size)); + gf_msg_nomem ("", GF_LOG_ALERT, (cnt * size)); return ptr; } @@ -99,7 +99,7 @@ void* __gf_default_realloc (void *oldptr, size_t size) ptr = realloc (oldptr, size); if (!ptr) - gf_log_nomem ("", GF_LOG_ALERT, size); + gf_msg_nomem ("", GF_LOG_ALERT, size); return ptr; } diff --git a/libglusterfs/src/template-component-messages.h b/libglusterfs/src/template-component-messages.h new file mode 100644 index 00000000000..c1ea38cf770 --- /dev/null +++ b/libglusterfs/src/template-component-messages.h @@ -0,0 +1,55 @@ +/* + Copyright (c) 2013 Red Hat, Inc. <http://www.redhat.com> + 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 _component_MESSAGES_H_ +#define _component_MESSAGES_H_ + +#ifndef _CONFIG_H +#define _CONFIG_H +#include "config.h" +#endif + +#include "glfs-message-id.h" + +/* NOTE: Rules for message additions + * 1) Each instance of a message is _better_ left with a unique message ID, even + * if the message format is the same. Reasoning is that, if the message + * format needs to change in one instance, the other instances are not + * impacted or the new change does not change the ID of the instance being + * modified. + * 2) Addition of a message, + * - Should increment the GLFS_NUM_MESSAGES + * - Append to the list of messages defined, towards the end + * - Retain macro naming as glfs_msg_X (for redability across developers) + * NOTE: Rules for message format modifications + * 3) Check acorss the code if the message ID macro in question is reused + * anywhere. If reused then then the modifications should ensure correctness + * everywhere, or needs a new message ID as (1) above was not adhered to. If + * not used anywhere, proceed with the required modification. + * NOTE: Rules for message deletion + * 4) Check (3) and if used anywhere else, then cannot be deleted. If not used + * anywhere, then can be deleted, but will leave a hole by design, as + * addition rules specify modification to the end of the list and not filling + * holes. + */ + +#define GLFS_COMP_BASE GLFS_MSGID_COMP_<component> +#define GLFS_NUM_MESSAGES 1 +#define GLFS_MSGID_END (GLFS_COMP_BASE + GLFS_NUM_MESSAGES + 1) +/* Messaged with message IDs */ +#define glfs_msg_start_x GLFS_COMP_BASE, "Invalid: Start of messages" +/*------------*/ +#define <component>_msg_1 (GLFS_COMP_BASE + 1), "Test message, replace with"\ + " original when using the template" + +/*------------*/ +#define glfs_msg_end_x GLFS_MSGID_END, "Invalid: End of messages" + +#endif /* !_component_MESSAGES_H_ */
\ No newline at end of file diff --git a/libglusterfs/src/unittest/log_mock.c b/libglusterfs/src/unittest/log_mock.c index 676df7cfdad..fec48bafc19 100644 --- a/libglusterfs/src/unittest/log_mock.c +++ b/libglusterfs/src/unittest/log_mock.c @@ -39,5 +39,12 @@ int _gf_log_nomem (const char *domain, const char *file, return 0; } +int _gf_msg_nomem (const char *domain, const char *file, + const char *function, int line, gf_loglevel_t level, + size_t size) +{ + return 0; +} + void gf_log_globals_init (void *data) {} diff --git a/rpc/rpc-transport/rdma/src/rdma.c b/rpc/rpc-transport/rdma/src/rdma.c index 6e6099a9854..c09067230a3 100644 --- a/rpc/rpc-transport/rdma/src/rdma.c +++ b/rpc/rpc-transport/rdma/src/rdma.c @@ -104,7 +104,7 @@ gf_rdma_new_post (rpc_transport_t *this, gf_rdma_device_t *device, int32_t len, post->buf = valloc (len); if (!post->buf) { - gf_log_nomem (GF_RDMA_LOG_NAME, GF_LOG_ERROR, len); + gf_msg_nomem (GF_RDMA_LOG_NAME, GF_LOG_ERROR, len); goto out; } diff --git a/tests/basic/logchecks-messages.h b/tests/basic/logchecks-messages.h new file mode 100644 index 00000000000..50efe9dfadd --- /dev/null +++ b/tests/basic/logchecks-messages.h @@ -0,0 +1,84 @@ +/* + Copyright (c) 2013 Red Hat, Inc. <http://www.redhat.com> + 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 _LOGCHECKS_MESSAGES_H_ +#define _LOGCHECKS_MESSAGES_H_ + +#ifndef _CONFIG_H +#define _CONFIG_H +#include "config.h" +#endif + +#include "glfs-message-id.h" + +/* NOTE: Rules for message additions + * 1) Each instance of a message is _better_ left with a unique message ID, even + * if the message format is the same. Reasoning is that, if the message + * format needs to change in one instance, the other instances are not + * impacted or the new change does not change the ID of the instance being + * modified. + * 2) Addition of a message, + * - Should increment the GLFS_NUM_MESSAGES + * - Append to the list of messages defined, towards the end + * - Retain macro naming as glfs_msg_X (for redability across developers) + * NOTE: Rules for message format modifications + * 3) Check acorss the code if the message ID macro in question is reused + * anywhere. If reused then then the modifications should ensure correctness + * everywhere, or needs a new message ID as (1) above was not adhered to. If + * not used anywhere, proceed with the required modification. + * NOTE: Rules for message deletion + * 4) Check (3) and if used anywhere else, then cannot be deleted. If not used + * anywhere, then can be deleted, but will leave a hole by design, as + * addition rules specify modification to the end of the list and not filling + * holes. + */ + +#define GLFS_COMP_BASE 1000 +#define GLFS_NUM_MESSAGES 19 +#define GLFS_MSGID_END (GLFS_COMP_BASE + GLFS_NUM_MESSAGES + 1) +/* Messaged with message IDs */ +#define glfs_msg_start_x GLFS_COMP_BASE, "Invalid: Start of messages" +/*------------*/ +#define logchecks_msg_1 (GLFS_COMP_BASE + 1), "Informational: Testing logging" \ + " in gluster" +#define logchecks_msg_2 (GLFS_COMP_BASE + 2), "Informational: Format testing:" \ + " %d:%s:%x" +#define logchecks_msg_3 (GLFS_COMP_BASE + 3), "Critical: Testing logging" \ + " in gluster" +#define logchecks_msg_4 (GLFS_COMP_BASE + 4), "Critical: Format testing:" \ + " %d:%s:%x" +#define logchecks_msg_5 (GLFS_COMP_BASE + 5), "Critical: Rotated the log" +#define logchecks_msg_6 (GLFS_COMP_BASE + 6), "Critical: Flushed the log" +#define logchecks_msg_7 (GLFS_COMP_BASE + 7), "Informational: gf_msg_callingfn" +#define logchecks_msg_8 (GLFS_COMP_BASE + 8), "Informational: " \ + "gf_msg_callingfn: Format testing: %d:%s:%x" +#define logchecks_msg_9 (GLFS_COMP_BASE + 9), "Critical: gf_msg_callingfn" +#define logchecks_msg_10 (GLFS_COMP_BASE + 10), "Critical: " \ + "gf_msg_callingfn: Format testing: %d:%s:%x" +#define logchecks_msg_11 (GLFS_COMP_BASE + 11), "==========================" +#define logchecks_msg_12 (GLFS_COMP_BASE + 12), "Test 1: Only stderr and" \ + " partial syslog" +#define logchecks_msg_13 (GLFS_COMP_BASE + 13), "Test 2: Only checklog and" \ + " partial syslog" +#define logchecks_msg_14 (GLFS_COMP_BASE + 14), "Test 5: Changing to" \ + " traditional format" +#define logchecks_msg_15 (GLFS_COMP_BASE + 15), "Test 6: Changing log level" \ + " to critical and above" +#define logchecks_msg_16 (GLFS_COMP_BASE + 16), "Test 7: Only to syslog" +#define logchecks_msg_17 (GLFS_COMP_BASE + 17), "Test 8: Only to syslog," \ + " traditional format" +#define logchecks_msg_18 (GLFS_COMP_BASE + 18), "Test 9: Only to syslog," \ + " only critical and above" +#define logchecks_msg_19 (GLFS_COMP_BASE + 19), "Pre init message, not to be" \ + " seen in logs" +/*------------*/ +#define glfs_msg_end_x GLFS_MSGID_END, "Invalid: End of messages" + +#endif /* !_component_MESSAGES_H_ */
\ No newline at end of file diff --git a/tests/basic/logchecks.c b/tests/basic/logchecks.c new file mode 100644 index 00000000000..4f858a7fc07 --- /dev/null +++ b/tests/basic/logchecks.c @@ -0,0 +1,208 @@ +/* + * Copyright (c) 2013 Red Hat, Inc. <http://www.redhat.com> + * 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. + */ + +#include <stdio.h> +#include <unistd.h> + +#include "glusterfs.h" +#include "globals.h" +#include "logging.h" + +#include "logchecks-messages.h" +#include "../../libglusterfs/src/logging.h" + +glusterfs_ctx_t *ctx = NULL; + +#define TEST_FILENAME "/tmp/logchecks.log" +#define GF_LOG_CONTROL_FILE "/etc/glusterfs/logger.conf" + +int +go_log_vargs(gf_loglevel_t level, const char *fmt, ...) +{ + va_list ap; + + va_start (ap, fmt); + gf_msg_vplain (level, fmt, ap); + va_end (ap); + + return 0; +} + +int +go_log (void) +{ + /*** gf_msg ***/ + gf_msg ("logchecks", GF_LOG_INFO, 0, logchecks_msg_1); + gf_msg ("logchecks", GF_LOG_INFO, 22, logchecks_msg_2, 42, "Forty-Two", + 42); + /* change criticality */ + gf_msg ("logchecks", GF_LOG_CRITICAL, 0, logchecks_msg_3); + gf_msg ("logchecks", GF_LOG_CRITICAL, 22, logchecks_msg_4, 42, + "Forty-Two", 42); + + /*** msg_nomem ***/ + gf_msg_nomem ("logchecks", GF_LOG_ALERT, 555); + gf_msg_nomem ("logchecks", GF_LOG_INFO, 555); + + /*** msg_plain ***/ + gf_msg_plain (GF_LOG_INFO, "Informational: gf_msg_plain with" + " args %d:%s:%x", 42, "Forty-Two", 42); + gf_msg_plain (GF_LOG_ALERT, "Alert: gf_msg_plain with" + " args %d:%s:%x", 42, "Forty-Two", 42); + + /*** msg_vplain ***/ + go_log_vargs (GF_LOG_INFO, "Informational: gf_msg_vplain: No args!!!"); + go_log_vargs (GF_LOG_INFO, "Informational: gf_msg_vplain: Some" + " args %d:%s:%x", 42, "Forty-Two", 42); + go_log_vargs (GF_LOG_INFO, "Critical: gf_msg_vplain: No args!!!"); + go_log_vargs (GF_LOG_INFO, "Critical: gf_msg_vplain: Some" + " args %d:%s:%x", 42, "Forty-Two", 42); + + /*** msg_plain_nomem ***/ + gf_msg_plain_nomem (GF_LOG_INFO, "Informational: gf_msg_plain_nomem"); + gf_msg_plain_nomem (GF_LOG_ALERT, "Alert: gf_msg_plain_nomem"); + + /*** msg_backtrace_nomem ***/ + // TODO: Need to create a stack depth and then call + gf_msg_backtrace_nomem (GF_LOG_INFO, 5); + gf_msg_backtrace_nomem (GF_LOG_ALERT, 5); + + /*** gf_msg_callingfn ***/ + // TODO: Need to create a stack depth and then call + gf_msg_callingfn ("logchecks", GF_LOG_INFO, 0, logchecks_msg_7); + gf_msg_callingfn ("logchecks", GF_LOG_INFO, 0, logchecks_msg_8, 42, + "Forty-Two", 42); + gf_msg_callingfn ("logchecks", GF_LOG_CRITICAL, 0, logchecks_msg_9); + gf_msg_callingfn ("logchecks", GF_LOG_CRITICAL, 0, logchecks_msg_10, 42, + "Forty-Two", 42); + + /*** gf_msg_debug ***/ + gf_msg_debug ("logchecks", 0, "Debug: Hello World!!!"); + gf_msg_debug ("logchecks", 22, "Debug: With args %d:%s:%x", 42, + "Forty-Two", 42); + + /*** gf_msg_trace ***/ + gf_msg_trace ("logchecks", 0, "Trace: Hello World!!!"); + gf_msg_trace ("logchecks", 22, "Trace: With args %d:%s:%x", 42, + "Forty-Two", 42); + + /*** gf_msg_backtrace ***/ + // TODO: Test with lower callstr values to check truncation + + return 0; +} + +int +main (int argc, char *argv[]) +{ + int ret = -1; + + unlink (GF_LOG_CONTROL_FILE); + creat (GF_LOG_CONTROL_FILE, O_RDONLY); + ctx = glusterfs_ctx_new (); + if (!ctx) + return -1; + + ret = glusterfs_globals_init (ctx); + if (ret) { + printf ("Error from glusterfs_globals_init [%s]\n", + strerror (errno)); + return ret; + } + + /* Pre init test, message should not be printed */ + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_19); + + THIS->ctx = ctx; + + /* TEST 1: messages before initializing the log, goes to stderr + * and syslog based on criticality */ + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_12); + go_log (); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + + /* TEST 2: messages post initialization, goes to glusterlog and + * syslog based on severity */ + ret = gf_log_init(ctx, TEST_FILENAME, "logchecks"); + if (ret != 0) { + printf ("Error from gf_log_init [%s]\n", strerror (errno)); + return -1; + } + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_13); + go_log (); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + + /* TEST 3: Test rotation */ + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + gf_log_logrotate (0); + gf_msg ("logchecks", GF_LOG_CRITICAL, 0, logchecks_msg_5); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + + /* TEST 4: Check flush, nothing noticable should occur :) */ + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + gf_log_flush (); + gf_msg ("logchecks", GF_LOG_CRITICAL, 0, logchecks_msg_6); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + + /* TEST 5: Change format */ + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + gf_log_set_logformat (gf_logformat_traditional); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_14); + go_log (); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + + /* TEST 6: Change level */ + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + gf_log_set_loglevel (GF_LOG_CRITICAL); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_15); + go_log (); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + + /* Reset to run with syslog */ + gf_log_set_logformat (gf_logformat_withmsgid); + gf_log_set_loglevel (GF_LOG_INFO); + + /* Run tests with logger changed to syslog */ + /* TEST 7: No more gluster logs */ + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + gf_log_set_logger (gf_logger_syslog); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_16); + go_log (); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + + /* TEST 8: Change format */ + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + gf_log_set_logformat (gf_logformat_traditional); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_14); + go_log (); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + + /* TEST 9: Change level */ + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + gf_log_set_loglevel (GF_LOG_CRITICAL); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_15); + go_log (); + gf_msg ("logchecks", GF_LOG_ALERT, 0, logchecks_msg_11); + + // TODO: signal crash prints, but not yet feasible here + // TODO: Graph printing + // TODO: Multi threaded logging + + /* Close out the logging */ + gf_log_fini (ctx); + gf_log_globals_fini (); + + unlink (GF_LOG_CONTROL_FILE); + unlink (TEST_FILENAME); + + return 0; +}
\ No newline at end of file |