From: Alexey Chernobaev Date: Thu, 30 Aug 2018 17:58:15 +0000 (+0300) Subject: better logging X-Git-Tag: submit/tizen/20180911.125435~13 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=fb488f7efbe2a6bfdcfef45268cb757bf2ee295b;p=sdk%2Ftools%2Fprofctl.git better logging --- diff --git a/logging.c b/logging.c index 10beacc..642deaa 100644 --- a/logging.c +++ b/logging.c @@ -1,11 +1,19 @@ +#define _GNU_SOURCE + #include #include #include #include #include +#include +#include +#include #include "logging.h" +extern int log_pid = 0; +extern int log_tid = 0; + static FILE *log_file = NULL; static pthread_mutex_t log_lock; @@ -89,10 +97,26 @@ static void log_current_time() tm.tm_year + 1900 - 2000, tm.tm_mon + 1, tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec, millisec); } +static void log_current_data() +{ + log_current_time(); + if (log_pid) { + fprintf(log_file, "P=%ld ", (long)getpid()); + } + if (log_tid) { +#ifdef SYS_gettid + pid_t tid = syscall(SYS_gettid); +#else + #error "SYS_gettid unavailable on this system" +#endif + fprintf(log_file, "T=%ld ", (long)tid); + } +} + void log_message(const char *fmt, ...) { pthread_mutex_lock(&log_lock); - log_current_time(); + log_current_data(); va_list arg; va_start(arg, fmt); vfprintf(log_file, fmt, arg); @@ -106,7 +130,7 @@ void log_error(const char *fmt, ...) { pthread_mutex_lock(&log_lock); fputs("[ERROR] ", log_file); - log_current_time(); + log_current_data(); va_list arg; va_start(arg, fmt); vfprintf(log_file, fmt, arg); @@ -128,7 +152,7 @@ static void log_prefixed_system_error(FILE *file, int error_code, const char *pr if (prefix != NULL) { fputs(prefix, file); } - log_current_time(); + log_current_data(); vfprintf(file, fmt, arg); fprintf(file, ": %s\n", strerror(error_code)); fflush(file); diff --git a/logging.h b/logging.h index 80ce126..9d777b6 100644 --- a/logging.h +++ b/logging.h @@ -3,6 +3,9 @@ #include #include +extern int log_pid; +extern int log_tid; + int log_init(); void log_uninit(); void log_set_file(FILE *file); diff --git a/profctl.c b/profctl.c index 5cc9020..aeb24f2 100644 --- a/profctl.c +++ b/profctl.c @@ -92,7 +92,14 @@ static void *data_output_thread(void *arg) size_t lsize = 0; while (!global_stop) { if (getline(&buffer, &lsize, pipef) == -1) { - log_system_error("cannot read data from pipe"); + if (feof(pipef)) { + if (verbose) { + log_message("pipe eof"); + } + } + else { + log_system_error("cannot read data from pipe"); + } break; } ++linesRead; @@ -145,20 +152,8 @@ static void close_stdio() fclose(stderr); } -static void finish() +static void close_files_and_sockets() { - log_message("exit handler called"); -#if TIZEN - if (controlPort < 0) { - tcsetattr(0, TCSANOW, &sterm); - } -#endif /* TIZEN */ - if (pipef != NULL) { - fclose(pipef); - if (isPipeOwner) { - unlink(pname); - } - } if (ctrl_file_in != NULL && ctrl_file_in != stdin) { fclose(ctrl_file_in); } @@ -180,6 +175,23 @@ static void finish() if (stat_socket >= 0) { close(stat_socket); } +} + +static void finish() +{ + log_message("exit handler called"); +#if TIZEN + if (controlPort < 0) { + tcsetattr(0, TCSANOW, &sterm); + } +#endif /* TIZEN */ + if (pipef != NULL) { + fclose(pipef); + if (isPipeOwner) { + unlink(pname); + } + } + close_files_and_sockets(); log_message("=== finished ==="); log_uninit(); kill(getpid(), SIGKILL); @@ -289,6 +301,8 @@ static int openFileProcess() return 0; } + // --exec option used + if (access(ename, X_OK)) { log_system_error("access(%s)", ename); return -1; @@ -322,44 +336,53 @@ static int openFileProcess() } if (pid == 0) { /* Child */ - close(pipefd[0]); - if (verbose) { - log_message("CHILD close(%d)", pipefd[0]); + if (close(pipefd[0]) != 0) { + // not critical + log_system_error("CHILD close(%d)", pipefd[0]); + } + if (dup2(pipefd[1], 1) == -1) { /* stdout */ + log_system_error("CHILD dup2(%d, 1)", pipefd[1]); + return -1; + } + if (dup2(id, 0) == -1) { /* stdin */ + log_system_error("CHILD dup2(%d, 0)", id); + return -1; } - dup2(pipefd[1], 1); /* stdout */ if (verbose) { - log_message("CHILD dup2(%d, 1)", pipefd[1]); + log_message("CHILD close(%d); dup2(%d, 1); dup2(%d, 0)", pipefd[0], pipefd[1], id); } - dup2(id, 0); /* stdin */ + close_files_and_sockets(); if (verbose) { - log_message("CHILD dup2(%d, 0)", id); + log_message("CHILD closed files and sockets"); } if (verbose) { - log_message("CHILD execl(%s)", ename); + log_message("CHILD calling execl(%s)", ename); } + log_uninit(); execl(ename, ename, NULL); log_system_error("CHILD execl(%s)", ename); // execl returns only in case of error return -1; } /* Parent */ - close(pipefd[1]); - if (verbose) { - log_message("PARENT close(%d)", pipefd[1]); + if (close(pipefd[1]) != 0) { + // not critical + log_system_error("PARENT close(%d)", pipefd[1]); } - close(id); - if (verbose) { - log_message("PARENT close(%d)", id); + if (close(id) != 0) { + // not critical + log_system_error("PARENT close(%d)", id); } pipef = fdopen(pipefd[0], "r"); if (pipef == NULL) { - log_system_error("PARENT fdopen(%d, \"r\")", pipefd[0]); + log_system_error("PARENT fdopen(%d, r)", pipefd[0]); return -1; } + if (verbose) { - log_message("PARENT fdopen(%d, \"r\")", pipefd[0]); + log_message("PARENT close(%d); close(%d); fdopen(%d, r)", pipefd[1], id, pipefd[0]); } return 0; @@ -466,7 +489,14 @@ static void *command_loop_thread(void *arg) char *line = malloc(len = 16); while (!global_stop) { if ((len = getline(&line, &len, ctrl_file_in)) == -1) { - log_system_error("cannot read command"); + if (feof(ctrl_file_in)) { + if (verbose) { + log_message("command stream eof"); + } + } + else { + log_system_error("cannot read command"); + } break; } if (global_stop) { @@ -568,6 +598,9 @@ int main(int argc, char **argv) return 1; } + log_pid = 1; + log_tid = 1; + log_set_file(stderr); while (!process_option(argc, argv)); @@ -636,11 +669,11 @@ int main(int argc, char **argv) } ctrl_file_in = fdopen(control_socket, "r"); if (ctrl_file_in == NULL) { - log_system_error_and_exit("fdopen(control,r)"); + log_system_error_and_exit("fdopen(control, r)"); } ctrl_file_out = fdopen(control_socket, "w"); if (ctrl_file_out == NULL) { - log_system_error_and_exit("fdopen(control,w)"); + log_system_error_and_exit("fdopen(control, w)"); } if (fprintf(ctrl_file_out, "ready\n") < 0 || fflush(ctrl_file_out) != 0) { log_system_error_and_exit("cannot write 'ready' prompt to control stream");