Hi Gabriella, here’s my comments: You’re on the right track with the separate log messages for different levels. This enables us to conditionally compile the code such that, for example, only LOG_ERR_MSG and LOG_WARNING_MSG messages are generated for production code, while all levels are generated for non-debug.
I’d keep the log level macros (LOG_ERR etc) as integers though, with errors as 0 and increasing by 1 from there. The reason for using integers instead of strings for log levels is so you can say “anything less than log level <n>”, i.e. maybe you want all information except debugging info (level < LOG_DEBUG), or all notice messages and anything more serious (level <= LOG_INFO). That is, the levels have an explicit ordering to them, and the choice of what is displayed is based on a numeric comparison. You asked in your previous mail about how much time is being saved. In general it will be very minimal, though it’s possible if for some reason a logging message is added to a function that is executed lots of times, or information that is passed to the log message takes a non-trivial amount of time to compute (for example if a log contained a call to a function that computed the total number of nodes in a document), then the saving would be worth it. In general, you should avoid fixed-length buffers for strings like log_filename, logging_dir, and log_symlink. It’s better to dynamically allocate memory for things like this where necessary, using e.g. malloc/strdup/DFFormatString or whatever. For example inside set_log_dir, you would call strdup to make a copy of the parameters, and then assign those copies logging_dir and log_symlink, which would have the type char * instead of being arrays. When specifying functions in a header like set_log_dir, include the parameter names. These help to clarify what the function does to someone who is just looking through the header, without having to look at the c file as well (e.g. there are two parameters to that function, and just from the header I don’t know which one is dir and which one is sdir. — Dr Peter M. Kelly pmke...@apache.org PGP key: http://www.kellypmk.net/pgp-key <http://www.kellypmk.net/pgp-key> (fingerprint 5435 6718 59F0 DD1F BFA0 5E46 2523 BAA1 44AE 2966) > On 23 Aug 2015, at 6:54 am, g...@apache.org wrote: > > Repository: incubator-corinthia > Updated Branches: > refs/heads/master 2daa00087 -> e1dc6c9ab > > > Logging feature update > > Add dedicated general logging macros, set a symlink 'current.log', and > allow local custom log macros with dedicated names for the log file. > Remove the tar file and use snprintf instead strncat and strdup. > > Todo: plug in user defined output function pointer mechanism. > > * Makefile: > > Temporary way to compile the logger. Usage: > $ make; ./logMaker > > * log_maker.c: > > Code for the logging functions. > > (#define): Add _GNU_SOURCE. > > (#include): Add "log_maker.h". > Add <assert.h>. > Add <error.h>. > Add <libgen.h>. > Add <stdarg.h>. > Add <stdio.h>. > Add <stdlib.h>. > Add <string.h>. > Add <time.h>. > Add <unistd.h>. > Add <errno.h>. > Add <dirent.h>. > Add <sys/types.h>. > Add <sys/stat.h>. > Add <fcntl.h>. > These are probably not all needed. > > (get_time_string): New function. > > (set_log_output_function): New function. This is a stub. > > (log_init): New function. Create the logfile name with host, time > and program name. Set a symlink 'current.log' into > ~/../incubator/. > > (set_log_dir): New function. Set the directory in which to write > the individual logfiles and the location where the symlonk > should be created. > > (close_log): New function. Close the file descriptor and inform > user about the location and name of the generated file. > > (log_msg_prefix): New function. Create the prefix containing the > name of the log level, the file, line number and function name. > > (log_msg): New function. Write the log prefix and log message to > file. > > * log_maker.h: > > Header file for general inclusion so log_maker.c can be used. > > (#ifndef): Add LOG_MAKER_H. > Header guard. Somehow #pragma once does not work for me. > > (#if): Add _MSC_VER. Picked this up in the docs, apparently MSC > uses _sprintf instead. > > (#define): Add LOG_ERR. > Add LOG_WARNING. > Add LOG_NOTICE. > Add LOG_INFO. > Add LOG_DEBUG. > These are all strings for now. I can change it back to numbers, but > currently those strings are used to print out the log message titles. > > Global variables: > > (char): Add log_filename[filename_len]. > > (int): Add log_file_fd. File descriptor for log file. > > (static int log_level_initialised): Guard to prevent log_init from > being called twise. > > (char): Add logging_dir[filename_len]. > > (char): Add log_symlink[filename_len]. > > (LOG_THIS): New function. Basic macro, called by every custom macro. > > Basic log macros for general usage: > > (LOG_ERROR_MSG): New function. > > (LOG_WARNING_MSG): New function. > > (LOG_NOTICE_MSG): New function. > > (LOG_INFO_MSG): New function. > > (LOG_DEBUG_MSG): New function. > > Prototypes for logmaker.c: > > (set_log_output_function): New function. > > (log_init): New function. > > (set_log_dir): New function. > > (set_log_level): New function. > > (close_log): New function. > > (log_msg_prefix): New function. > > * useLogmaker.c: > > Test code for log_maker.c > > (#include): Add "log_maker.h". > Add <stdio.h>. > Add <unistd.h>. > > (LOG_USE_LOGMAKER_MSG): New function. This is a custom log macro > that only works for the local file. > > (function_one): New function. Test every general macro. > > (function_two): New function. Test base macro 'LOG_THIS' and test > locally defined macro. > > (main): New function. Run tests. > > > Project: http://git-wip-us.apache.org/repos/asf/incubator-corinthia/repo > Commit: > http://git-wip-us.apache.org/repos/asf/incubator-corinthia/commit/a507ec58 > Tree: http://git-wip-us.apache.org/repos/asf/incubator-corinthia/tree/a507ec58 > Diff: http://git-wip-us.apache.org/repos/asf/incubator-corinthia/diff/a507ec58 > > Branch: refs/heads/master > Commit: a507ec5880d19f1ea09e328a8f19a98a419c0f17 > Parents: a24455b > Author: Gabriela Gibson <g...@apache.org> > Authored: Sun Aug 23 00:53:55 2015 +0100 > Committer: Gabriela Gibson <g...@apache.org> > Committed: Sun Aug 23 00:53:55 2015 +0100 > > ---------------------------------------------------------------------- > experiments/logger/Makefile | 14 +++ > experiments/logger/log_maker.c | 155 ++++++++++++++++++++++++++++++++++ > experiments/logger/log_maker.h | 47 +++++++++++ > experiments/logger/log_maker.tar | Bin 2321 -> 0 bytes > experiments/logger/useLogmaker.c | 40 +++++++++ > 5 files changed, 256 insertions(+) > ---------------------------------------------------------------------- > > > http://git-wip-us.apache.org/repos/asf/incubator-corinthia/blob/a507ec58/experiments/logger/Makefile > ---------------------------------------------------------------------- > diff --git a/experiments/logger/Makefile b/experiments/logger/Makefile > new file mode 100644 > index 0000000..9369702 > --- /dev/null > +++ b/experiments/logger/Makefile > @@ -0,0 +1,14 @@ > +objects = useLogmaker.o log_maker.o > +CC = gcc > +CFLAGS = -ggdb -std=c99 -Wall > + > +logger: $(objects) > + $(CC) $(CFLAGS) -o logMaker $(objects) > + > +useLogmaker.o: log_maker.h > + > +log_maker.o: log_maker.h > + > +.PHONY : clean > +clean : > + rm logMaker $(objects) > > http://git-wip-us.apache.org/repos/asf/incubator-corinthia/blob/a507ec58/experiments/logger/log_maker.c > ---------------------------------------------------------------------- > diff --git a/experiments/logger/log_maker.c b/experiments/logger/log_maker.c > new file mode 100644 > index 0000000..4e39ee5 > --- /dev/null > +++ b/experiments/logger/log_maker.c > @@ -0,0 +1,155 @@ > +#define _GNU_SOURCE 1 > + > +#include "log_maker.h" > +#include <assert.h> > +#include <error.h> > +#include <libgen.h> > +#include <stdarg.h> > +#include <stdio.h> > +#include <stdlib.h> > +#include <string.h> > +#include <time.h> > +#include <unistd.h> > +#include <errno.h> > +#include <dirent.h> > +#include <sys/types.h> > +#include <sys/stat.h> > +#include <fcntl.h> > + > + > +int get_time_string(char** time_buf, int time_buf_len) > +{ > + time_t t; > + struct tm *tm_tmp; > + > + memset(*time_buf, 0, time_buf_len); > + > + t = time(NULL); > + tm_tmp = localtime(&t); > + if (NULL == tm_tmp) { > + // FIXME: there is 'utassrt' but I'm not sure how to get ahold of > it right now. > + perror("localtime error"); > + abort(); > + } > + > + strftime(*time_buf, time_buf_len, "%Y%m%d-%H%M%S", tm_tmp); > + > + return strlen(*time_buf); > +} > + > +void set_log_output_function(char* func) > +{ > + // TODO > +} > + > +/* The format of file name is > + <binary_name>.<hostname>.<date_string> > + Note: Open question: is it worth also adding username to this > + string? > +*/ > + > + > +void log_init(void) > +{ > + if (log_level_initialised) > + return; > + > + int hostname_len = 80; > + char hostname_buf[hostname_len]; > + gethostname((char*)hostname_buf, hostname_len); > + > + char* progname = basename(getenv("_")); > + > + int time_buf_len = 16; > + char *time_buf = malloc(time_buf_len); > + > + get_time_string(&time_buf, time_buf_len); > + > + /* FIXME: > + > + Take DFFormatString and copy it into your code, adapting it as > + necessary. > + > + */ > + snprintf(log_filename, filename_len, "%s%s.%s.%s", > + logging_dir,progname,hostname_buf,time_buf); > + > + log_file_fd = open(log_filename, > + O_CREAT | O_TRUNC | O_WRONLY, > + S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH); > + > + if (log_file_fd == -1) { > + fprintf(stderr, "FATAL: couldn't open file descriptor\n"); > + abort(); > + } > + > + symlink(log_filename, log_symlink); > + > + free(time_buf); > + log_level_initialised = 1; > +} > + > + > +void set_log_dir(const char* dir, const char *sdir) > +{ > + if (log_level_initialised) { > + fprintf(stderr, "Cannot reset logging level after initialisation\n"); > + abort(); > + } > + > + errno = 0; > + > + DIR* has_dir = opendir(dir); > + > + int this_error = errno; > + > + // check the actual log file dir > + if (has_dir) { > + closedir(has_dir); > + snprintf(logging_dir, filename_len, "%s", dir); > + } > + else { > + // FIXME > + perror(strerror(this_error)); > + abort(); > + return; > + } > + > + // check the symlink, remove if it exists > + snprintf(log_symlink, filename_len, "%scurrent.log", sdir); > + > + struct stat statbuf; > + > + if (-1 == lstat(log_symlink, &statbuf)) > + return; > + else > + unlink(log_symlink); > + > + return; > +} > + > +void close_log(void) > +{ > + close(log_file_fd); > + printf("Logfile created in %s\nSee %s to view it\n", log_filename, > log_symlink); > +} > + > +void log_msg_prefix(char *level, char* filename, int linenum, const char* > function) > +{ > + if (! log_level_initialised) { > + fprintf(stderr, "ERROR: Trying to log before initialisation is > complete.\n"); > + exit(1); > + } > + dprintf(log_file_fd, "%-15s %s:%d %s() ", level, filename, linenum, > function); > +} > + > + > +void log_msg(char *level, char *fmt, ...) > +{ > + va_list argp; > + va_start(argp, fmt); > + assert(log_file_fd > -1); > + vdprintf(log_file_fd, fmt, argp); > + va_end(argp); > + } > + > > http://git-wip-us.apache.org/repos/asf/incubator-corinthia/blob/a507ec58/experiments/logger/log_maker.h > ---------------------------------------------------------------------- > diff --git a/experiments/logger/log_maker.h b/experiments/logger/log_maker.h > new file mode 100644 > index 0000000..624120a > --- /dev/null > +++ b/experiments/logger/log_maker.h > @@ -0,0 +1,47 @@ > +#ifndef LOG_MAKER_H > +#define LOG_MAKER_H > + > +#if _MSC_VER > +#define snprintf _snprintf > +#endif > + > +#define LOG_ERR "ERROR" > +#define LOG_WARNING "WARN" > +#define LOG_NOTICE "NOTICE" > +#define LOG_INFO "INFO" > +#define LOG_DEBUG "DEBUG" > + > + > +// TODO > +void set_log_output_function(char* func); > + > +void log_init(void); > +void set_log_dir(const char*, const char*); > +void set_log_level(int level); > +void close_log(void); > + > +void log_msg_prefix(char* level, char* filename, int linenum, const char* > function); > +void log_msg(char* level, char *msg, ...); > + > +#define filename_len 1024 > +char log_filename[filename_len]; > +int log_file_fd; > + > +static int log_level_initialised = 0; > + > +char logging_dir[filename_len]; > +char log_symlink[filename_len]; > + > +#define LOG_THIS(level, msg, ...) do { \ > + log_msg_prefix(level, __FILE__, __LINE__, __FUNCTION__); \ > + log_msg(level, msg, __VA_ARGS__); \ > + } while (0) > + > + > +#define LOG_ERROR_MSG(msg, ...) LOG_THIS(LOG_ERR, msg, __VA_ARGS__); > +#define LOG_WARNING_MSG(msg, ...) LOG_THIS(LOG_WARNING, msg, __VA_ARGS__); > +#define LOG_NOTICE_MSG(msg, ...) LOG_THIS(LOG_NOTICE, msg, __VA_ARGS__); > +#define LOG_INFO_MSG(msg, ...) LOG_THIS(LOG_INFO, msg, __VA_ARGS__); > +#define LOG_DEBUG_MSG(msg, ...) LOG_THIS(LOG_DEBUG, msg, __VA_ARGS__); > + > +#endif /* LOG_MAKER_H_H */ > > http://git-wip-us.apache.org/repos/asf/incubator-corinthia/blob/a507ec58/experiments/logger/log_maker.tar > ---------------------------------------------------------------------- > diff --git a/experiments/logger/log_maker.tar > b/experiments/logger/log_maker.tar > deleted file mode 100644 > index b53154e..0000000 > Binary files a/experiments/logger/log_maker.tar and /dev/null differ > > http://git-wip-us.apache.org/repos/asf/incubator-corinthia/blob/a507ec58/experiments/logger/useLogmaker.c > ---------------------------------------------------------------------- > diff --git a/experiments/logger/useLogmaker.c > b/experiments/logger/useLogmaker.c > new file mode 100644 > index 0000000..a9e2c3b > --- /dev/null > +++ b/experiments/logger/useLogmaker.c > @@ -0,0 +1,40 @@ > +#include "log_maker.h" > +#include <stdio.h> > +#include <unistd.h> > + > +#define LOG_USE_LOGMAKER_MSG(msg, ...) LOG_THIS("LOG_MAKER", msg, > __VA_ARGS__); > + > +void function_one(void) > +{ > + LOG_THIS(LOG_WARNING,"LOG_THIS = %d, %d, %d,%d, %d, %d, %d, %d, %d, > %d\n", > + 1,2,3,4,5,6,7,8,9,10); > + LOG_ERROR_MSG("this is a LOG_ERROR_MSG = %d\n",1); > + LOG_WARNING_MSG("this is a LOG_WARNING_MSG = %d\n",2); > + LOG_NOTICE_MSG("this is a LOG_NOTICE_MSG = %d\n",3); > + LOG_INFO_MSG("this is a LOG_INFO_MSG = %d\n",4); > + LOG_DEBUG_MSG("this is a LOG_DEBUG_MSG = %d\n",5); > + return; > +} > + > +void function_two(void) > +{ > + LOG_THIS(LOG_NOTICE,"variable two = %d, %d, %d,%d, %d, %d, %d, %d, %d, > %d " > + "%d, %d, %d,%d, %d, %d, %d, %d, %d, %d\n", > + 1,2,3,4,5,6,7,8,9,10, > + 1,2,3,4,5,6,7,8,9,10); > + LOG_USE_LOGMAKER_MSG("this is a LOG_USE_LOGMAKER_MSG = > %s\n","LOG_MAKER"); > + return; > +} > + > +int main(int argc, char *argv[]) > +{ > + // set_log_level(LOG_DEBUG); > + > set_log_dir("/tmp/foo/bar/","/home/g/cor-logs/incubator-corinthia/experiments/logger/"); > + log_init(); > + > + function_one(); > + function_two(); > + > + close_log(); > + return 0; > +} >
