[77] | 1 | /* $Id: logging.c 23 2011-10-12 18:50:48Z mmamonski $ */ |
---|
| 2 | /* |
---|
| 3 | * PSNC DRMAA 2.0 utilities library |
---|
| 4 | * Copyright (C) 2012 Poznan Supercomputing and Networking Center |
---|
| 5 | * |
---|
| 6 | * This program is free software: you can redistribute it and/or modify |
---|
| 7 | * it under the terms of the GNU General Public License as published by |
---|
| 8 | * the Free Software Foundation, either version 3 of the License, or |
---|
| 9 | * (at your option) any later version. |
---|
| 10 | * |
---|
| 11 | * This program is distributed in the hope that it will be useful, |
---|
| 12 | * but WITHOUT ANY WARRANTY; without even the implied warranty of |
---|
| 13 | * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the |
---|
| 14 | * GNU General Public License for more details. |
---|
| 15 | * |
---|
| 16 | * You should have received a copy of the GNU General Public License |
---|
| 17 | * along with this program. If not, see <http://www.gnu.org/licenses/>. |
---|
| 18 | */ |
---|
| 19 | |
---|
| 20 | #ifdef HAVE_CONFIG_H |
---|
| 21 | # include <config.h> |
---|
| 22 | #endif |
---|
| 23 | |
---|
| 24 | #include <sys/time.h> |
---|
| 25 | |
---|
| 26 | #include <stdio.h> |
---|
| 27 | #include <stdlib.h> |
---|
| 28 | #include <stdarg.h> |
---|
| 29 | #include <string.h> |
---|
| 30 | #include <unistd.h> |
---|
| 31 | #ifdef HAVE_EXECINFO_H |
---|
| 32 | # include <execinfo.h> |
---|
| 33 | #endif |
---|
| 34 | |
---|
| 35 | #include <drmaa_utils/common.h> |
---|
| 36 | #include <drmaa_utils/logging.h> |
---|
| 37 | #include <drmaa_utils/lookup3.h> |
---|
| 38 | #include <drmaa_utils/thread.h> |
---|
| 39 | |
---|
| 40 | #ifndef lint |
---|
| 41 | static char rcsid[] |
---|
| 42 | # ifdef __GNUC__ |
---|
| 43 | __attribute__ ((unused)) |
---|
| 44 | # endif |
---|
| 45 | = "$Id: logging.c 23 2011-10-12 18:50:48Z mmamonski $"; |
---|
| 46 | #endif |
---|
| 47 | |
---|
| 48 | |
---|
| 49 | static int fsd_logging_output = 2; |
---|
| 50 | |
---|
| 51 | fsd_verbose_level_t fsd_verbose_level = |
---|
| 52 | #ifdef DEBUGGING |
---|
| 53 | FSD_LOG_TRACE |
---|
| 54 | #else |
---|
| 55 | FSD_LOG_FATAL |
---|
| 56 | #endif |
---|
| 57 | ; |
---|
| 58 | |
---|
| 59 | static struct timeval fsd_logging_start = {0, 0}; |
---|
| 60 | |
---|
| 61 | static void fsd_log_check_verbosity( void ); |
---|
| 62 | |
---|
| 63 | void |
---|
| 64 | fsd_set_verbosity_level( fsd_verbose_level_t level ) |
---|
| 65 | { |
---|
| 66 | fsd_verbose_level = level; |
---|
| 67 | } |
---|
| 68 | |
---|
| 69 | void |
---|
| 70 | fsd_set_logging_fd( int fd ) |
---|
| 71 | { |
---|
| 72 | fsd_logging_output = fd; |
---|
| 73 | } |
---|
| 74 | |
---|
| 75 | |
---|
| 76 | void |
---|
| 77 | fsd_color( char *output, size_t len, int n ) |
---|
| 78 | { |
---|
| 79 | uint32_t k = n; |
---|
| 80 | k = hashword( &k, 1, 0 ); |
---|
| 81 | k %= 12; |
---|
| 82 | snprintf( output, len, "\033[0;%d;%dm", k>=6, 31+k%6 ); |
---|
| 83 | } |
---|
| 84 | |
---|
| 85 | |
---|
| 86 | char |
---|
| 87 | fsd_log_level_char( int level ) |
---|
| 88 | { |
---|
| 89 | switch( level ) |
---|
| 90 | { |
---|
| 91 | case FSD_LOG_TRACE: return 't'; |
---|
| 92 | case FSD_LOG_DEBUG: return 'd'; |
---|
| 93 | case FSD_LOG_INFO: return 'I'; |
---|
| 94 | case FSD_LOG_WARNING: return 'W'; |
---|
| 95 | case FSD_LOG_ERROR: return 'E'; |
---|
| 96 | case FSD_LOG_FATAL: return 'F'; |
---|
| 97 | default: return '?'; |
---|
| 98 | } |
---|
| 99 | } |
---|
| 100 | |
---|
| 101 | |
---|
| 102 | void |
---|
| 103 | _fsd_log( int level, const char *file, const char *function, |
---|
| 104 | int kind, char *message ) |
---|
| 105 | { |
---|
| 106 | const bool color = false; |
---|
| 107 | char colorbeg[16]; |
---|
| 108 | const char *colorend; |
---|
| 109 | int tid; |
---|
| 110 | long int seconds, microseconds; |
---|
| 111 | const char *prefix; |
---|
| 112 | const char *p; |
---|
| 113 | |
---|
| 114 | if( level < (int)fsd_verbose_level ) |
---|
| 115 | return; |
---|
| 116 | |
---|
| 117 | if( message == NULL ) |
---|
| 118 | return; |
---|
| 119 | |
---|
| 120 | tid = fsd_thread_id(); |
---|
| 121 | if( color ) |
---|
| 122 | { |
---|
| 123 | fsd_color( colorbeg, sizeof(colorbeg), tid ); |
---|
| 124 | colorend = "\033[0m"; |
---|
| 125 | } |
---|
| 126 | else |
---|
| 127 | { |
---|
| 128 | colorbeg[0] = '\0'; |
---|
| 129 | colorend = ""; |
---|
| 130 | } |
---|
| 131 | |
---|
| 132 | { |
---|
| 133 | struct timeval tv; |
---|
| 134 | gettimeofday( &tv, NULL ); |
---|
| 135 | seconds = tv.tv_sec; |
---|
| 136 | microseconds = tv.tv_usec; |
---|
| 137 | } |
---|
| 138 | if( fsd_logging_start.tv_sec == 0 ) |
---|
| 139 | { |
---|
| 140 | time_t t; |
---|
| 141 | struct tm utc; |
---|
| 142 | char rep[32]; |
---|
| 143 | fsd_log_check_verbosity(); |
---|
| 144 | |
---|
| 145 | fsd_logging_start.tv_sec = seconds; |
---|
| 146 | fsd_logging_start.tv_usec = microseconds; |
---|
| 147 | t = seconds; |
---|
| 148 | gmtime_r( &t, &utc ); |
---|
| 149 | strftime( rep, sizeof(rep), "%Y-%m-%d %H:%M:%S", &utc ); |
---|
| 150 | fsd_log_info(( "logging started at: %s.%02ld Z", rep, microseconds/10000 )); |
---|
| 151 | /* recheck */ |
---|
| 152 | if( level < (int)fsd_verbose_level ) |
---|
| 153 | return; |
---|
| 154 | |
---|
| 155 | } |
---|
| 156 | if( microseconds < fsd_logging_start.tv_usec ) |
---|
| 157 | { |
---|
| 158 | seconds --; |
---|
| 159 | microseconds += 1000000; |
---|
| 160 | } |
---|
| 161 | seconds -= fsd_logging_start.tv_sec; |
---|
| 162 | microseconds -= fsd_logging_start.tv_usec; |
---|
| 163 | |
---|
| 164 | switch( kind ) |
---|
| 165 | { |
---|
| 166 | case _FSD_LOG_ENTER: prefix = "->"; break; |
---|
| 167 | case _FSD_LOG_RETURN: prefix = "<-"; break; |
---|
| 168 | default: |
---|
| 169 | prefix = " *"; |
---|
| 170 | function = ""; |
---|
| 171 | break; |
---|
| 172 | } |
---|
| 173 | |
---|
| 174 | p = message; |
---|
| 175 | do { |
---|
| 176 | if( *p == '\n' ) |
---|
| 177 | { |
---|
| 178 | prefix = " |"; |
---|
| 179 | function = ""; |
---|
| 180 | p++; |
---|
| 181 | } |
---|
| 182 | else |
---|
| 183 | { |
---|
| 184 | const char *end; |
---|
| 185 | char *line = NULL; |
---|
| 186 | int rc; |
---|
| 187 | end = strchr( p, '\n' ); |
---|
| 188 | if( end == NULL ) |
---|
| 189 | end = p + strlen(p); |
---|
| 190 | rc = asprintf( &line, "%c #%s%04x%s [%6ld.%02ld] %s %s%.*s\n", |
---|
| 191 | fsd_log_level_char(level), colorbeg, tid, colorend, |
---|
| 192 | seconds, microseconds/10000, prefix, function, (int)(end-p), p |
---|
| 193 | ); |
---|
| 194 | if( rc != -1 ) |
---|
| 195 | write( fsd_logging_output, line, strlen(line) ); |
---|
| 196 | else |
---|
| 197 | return; |
---|
| 198 | free( line ); |
---|
| 199 | p = end; |
---|
| 200 | } |
---|
| 201 | } while( *p != '\0' ); |
---|
| 202 | |
---|
| 203 | free( message ); |
---|
| 204 | } |
---|
| 205 | |
---|
| 206 | |
---|
| 207 | void |
---|
| 208 | fsd_log_check_verbosity( void ) |
---|
| 209 | { |
---|
| 210 | const char *log_level_str = getenv("DRMAA_LOG_LEVEL"); |
---|
| 211 | |
---|
| 212 | if (log_level_str == NULL) |
---|
| 213 | { |
---|
| 214 | return; |
---|
| 215 | } |
---|
| 216 | else if (strcmp(log_level_str, "TRACE") == 0) |
---|
| 217 | { |
---|
| 218 | fsd_verbose_level = FSD_LOG_TRACE; |
---|
| 219 | } |
---|
| 220 | else if (strcmp(log_level_str, "DEBUG") == 0) |
---|
| 221 | { |
---|
| 222 | fsd_verbose_level = FSD_LOG_DEBUG; |
---|
| 223 | } |
---|
| 224 | else if (strcmp(log_level_str, "INFO") == 0) |
---|
| 225 | { |
---|
| 226 | fsd_verbose_level = FSD_LOG_INFO; |
---|
| 227 | } |
---|
| 228 | else if (strcmp(log_level_str, "WARNING") == 0) |
---|
| 229 | { |
---|
| 230 | fsd_verbose_level = FSD_LOG_WARNING; |
---|
| 231 | } |
---|
| 232 | else if (strcmp(log_level_str, "ERROR") == 0) |
---|
| 233 | { |
---|
| 234 | fsd_verbose_level = FSD_LOG_ERROR; |
---|
| 235 | } |
---|
| 236 | else if (strcmp(log_level_str, "FATAL") == 0) |
---|
| 237 | { |
---|
| 238 | fsd_verbose_level = FSD_LOG_FATAL; |
---|
| 239 | } |
---|
| 240 | else |
---|
| 241 | { |
---|
| 242 | fsd_log_error(( "Illegal value of DRMAA_LOG_LEVEL=%s. Using default logging verbosity.", log_level_str)); |
---|
| 243 | } |
---|
| 244 | } |
---|
| 245 | |
---|
| 246 | |
---|
| 247 | void |
---|
| 248 | fsd_log_fmt( int level, const char *fmt, ... ) |
---|
| 249 | { |
---|
| 250 | va_list args; |
---|
| 251 | va_start( args, fmt ); |
---|
| 252 | fsd_log_fmtv( level, fmt, args ); |
---|
| 253 | va_end( args ); |
---|
| 254 | } |
---|
| 255 | |
---|
| 256 | |
---|
| 257 | void |
---|
| 258 | fsd_log_fmtv( int level, const char *fmt, va_list args ) |
---|
| 259 | { |
---|
| 260 | _fsd_log( level, NULL, NULL, _FSD_LOG_MSG, fsd_vasprintf(fmt, args) ); |
---|
| 261 | } |
---|
| 262 | |
---|
| 263 | |
---|
| 264 | #if defined(__GNUC__) && defined(HAVE_EXECINFO_H) |
---|
| 265 | #define MAX_STACKTRACE 128 |
---|
| 266 | void |
---|
| 267 | fsd_log_stacktrace( int skip, int limit ) |
---|
| 268 | { |
---|
| 269 | void **ptr_buf = NULL; |
---|
| 270 | const char **symbols = NULL; |
---|
| 271 | int i, n; |
---|
| 272 | |
---|
| 273 | if( limit == 0 ) |
---|
| 274 | limit = 128; |
---|
| 275 | skip++; /* without fsd_log_stacktrace() frame */ |
---|
| 276 | n = skip + limit; |
---|
| 277 | |
---|
| 278 | ptr_buf = (void**)calloc( n, sizeof(void*) ); |
---|
| 279 | if( ptr_buf == NULL ) |
---|
| 280 | return; |
---|
| 281 | n = backtrace( ptr_buf, n ); |
---|
| 282 | symbols = (const char**)backtrace_symbols( ptr_buf, n ); |
---|
| 283 | if( symbols != NULL ) |
---|
| 284 | { |
---|
| 285 | fsd_log_debug(( "Stacktrace (most recent call last):" )); |
---|
| 286 | for( i = n-skip; i >= 0; i-- ) |
---|
| 287 | fsd_log_debug(( "\n %s", symbols[i] )); |
---|
| 288 | free( symbols ); |
---|
| 289 | } |
---|
| 290 | } |
---|
| 291 | #else |
---|
| 292 | void fsd_log_stacktrace( int skip, int limit ) {} |
---|
| 293 | #endif |
---|
| 294 | |
---|
| 295 | |
---|
| 296 | |
---|