sal/osl/all/log.cxx

   1 /* -*- Mode: C++; tab-width: 4; indent-tabs-mode: nil; c-basic-offset: 4 -*- */
   2 /*
   3  * This file is part of the LibreOffice project.
   4  *
   5  * This Source Code Form is subject to the terms of the Mozilla Public
   6  * License, v. 2.0. If a copy of the MPL was not distributed with this
   7  * file, You can obtain one at http://mozilla.org/MPL/2.0/.
   8  */
   9
  10 #include <sal/config.h>
  11
  12 #include <cassert>
  13 #include <cstdarg>
  14 #include <cstddef>
  15 #include <cstdio>
  16 #include <cstdlib>
  17 #include <cstring>
  18 #include <sstream>
  19
  20 #include <stdio.h>
  21 #include <string.h>
  22 #include <fstream>
  23
  24 #include <config_global.h>
  25 #include <config_options.h>
  26 #include <osl/thread.hxx>
  27 #include <rtl/string.h>
  28 #include <sal/detail/log.h>
  29 #include <sal/log.hxx>
  30 #include <sal/types.h>
  31 #include <backtraceasstring.hxx>
  32 #include <salusesyslog.hxx>
  33
  34 #if defined ANDROID
  35 #include <android/log.h>
  36 #elif defined WNT
  37 #include <process.h>
  38 #include <windows.h>
  39 #define OSL_DETAIL_GETPID _getpid()
  40 #else
  41 #include <unistd.h>
  42 #define OSL_DETAIL_GETPID getpid()
  43 #endif
  44
  45 #if HAVE_SYSLOG_H
  46 #include <syslog.h>
  47 // sal/osl/unx/salinit.cxx::sal_detail_initialize updates this:
  48 bool sal_use_syslog;
  49 #else
  50 bool const sal_use_syslog = false;
  51 #endif
  52
  53 // Avoid the use of other sal code in this file as much as possible, so that
  54 // this code can be called from other sal code without causing endless
  55 // recursion.
  56
  57 namespace {
  58
  59 bool equalStrings(
  60     char const * string1, std::size_t length1, char const * string2,
  61     std::size_t length2)
  62 {
  63     return length1 == length2 && std::memcmp(string1, string2, length1) == 0;
  64 }
  65
  66 #if !defined ANDROID
  67 char const * toString(sal_detail_LogLevel level) {
  68     switch (level) {
  69     case SAL_DETAIL_LOG_LEVEL_INFO:
  70         return "info";
  71     case SAL_DETAIL_LOG_LEVEL_WARN:
  72         return "warn";
  73     case SAL_DETAIL_LOG_LEVEL_DEBUG:
  74         return "debug";
  75     default:
  76         assert(false); // this cannot happen
  77         return "broken";
  78     }
  79 }
  80 #endif
  81
  82 // getenv is not thread safe, so minimize use of result; except on Android, see
  83 // 60628799633ffde502cb105b98d3f254f93115aa "Notice if SAL_LOG is changed while
  84 // the process is running":
  85 #if defined ANDROID
  86
  87 char const * getLogLevel() {
  88     return std::getenv("SAL_LOG");
  89 }
  90
  91 #else
  92
  93 char const * getEnvironmentVariable(const char* env) {
  94     char const * p1 = std::getenv(env);
  95     if (p1 == nullptr) {
  96         return nullptr;
  97     }
  98     char const * p2 = strdup(p1); // leaked
  99     if (p2 == nullptr) {
 100         std::abort(); // cannot do much here
 101     }
 102     return p2;
 103 }
 104
 105 #ifdef WNT
 106 # define INI_STRINGBUF_SIZE 1024
 107
 108 bool getValueFromLoggingIniFile(const char* key, char* value) {
 109     char buffer[MAX_PATH];
 110     GetModuleFileName(nullptr, buffer, MAX_PATH);
 111     std::string sProgramDirectory = std::string(buffer);
 112     std::string::size_type pos = sProgramDirectory.find_last_of( "\\/" );
 113     sProgramDirectory = sProgramDirectory.substr(0, pos+1);
 114     sProgramDirectory += "logging.ini";
 115
 116     std::ifstream logFileStream(sProgramDirectory);
 117     if (!logFileStream.good())
 118         return false;
 119
 120     std::size_t n;
 121     std::string aKey;
 122     std::string aValue;
 123     std::string sWantedKey(key);
 124     std::string sLine;
 125     while (std::getline(logFileStream, sLine)) {
 126         if (sLine.find('#') == 0)
 127             continue;
 128         if ( ( n = sLine.find('=') ) != std::string::npos) {
 129             aKey = sLine.substr(0, n);
 130             if (aKey != sWantedKey)
 131                 continue;
 132             aValue = sLine.substr(n+1, sLine.length());
 133             snprintf(value, INI_STRINGBUF_SIZE, "%s", aValue.c_str());
 134             return true;
 135         }
 136     }
 137     return false;
 138 }
 139 #endif
 140
 141 char const * getLogLevel() {
 142     // First check the environment variable, then the setting in logging.ini
 143     static char const * env = getEnvironmentVariable("SAL_LOG");
 144
 145     if (env != nullptr)
 146         return env;
 147
 148 #ifdef WNT
 149     static char logLevel[INI_STRINGBUF_SIZE];
 150     if (getValueFromLoggingIniFile("LogLevel", logLevel))
 151         return logLevel;
 152 #endif
 153
 154     return nullptr;
 155 }
 156
 157 std::ofstream * getLogFile() {
 158     // First check the environment variable, then the setting in logging.ini
 159     static char const * logFile = getEnvironmentVariable("SAL_LOG_FILE");
 160     if (!logFile)
 161         return nullptr;
 162
 163 #ifdef WNT
 164     static char logFilePath[INI_STRINGBUF_SIZE];
 165     if (getValueFromLoggingIniFile("LogFilePath", logFilePath))
 166         logFile = logFilePath;
 167 #endif
 168
 169     // stays until process exits
 170     static std::ofstream file(logFile, std::ios::app | std::ios::out);
 171
 172     return &file;
 173 }
 174
 175 void maybeOutputTimestamp(std::ostringstream &s) {
 176     static char const * env = getLogLevel();
 177     if (env == nullptr)
 178         return;
 179     bool outputTimestamp = false;
 180     bool outputRelativeTimer = false;
 181     for (char const * p = env;;) {
 182         switch (*p++) {
 183         case '\0':
 184             if (outputTimestamp) {
 185                 char ts[100];
 186                 TimeValue systemTime;
 187                 osl_getSystemTime(&systemTime);
 188                 TimeValue localTime;
 189                 osl_getLocalTimeFromSystemTime(&systemTime, &localTime);
 190                 oslDateTime dateTime;
 191                 osl_getDateTimeFromTimeValue(&localTime, &dateTime);
 192                 struct tm tm;
 193                 tm.tm_sec = dateTime.Seconds;
 194                 tm.tm_min = dateTime.Minutes;
 195                 tm.tm_hour = dateTime.Hours;
 196                 tm.tm_mday = dateTime.Day;
 197                 tm.tm_mon = dateTime.Month - 1;
 198                 tm.tm_year = dateTime.Year - 1900;
 199                 strftime(ts, sizeof(ts), "%Y-%m-%d:%H:%M:%S", &tm);
 200                 char milliSecs[11];
 201                 snprintf(milliSecs, sizeof(milliSecs), "%03u", static_cast<unsigned>(dateTime.NanoSeconds/1000000));
 202                 s << ts << '.' << milliSecs << ':';
 203             }
 204             if (outputRelativeTimer) {
 205                 static bool beenHere = false;
 206                 static TimeValue first;
 207                 if (!beenHere) {
 208                     osl_getSystemTime(&first);
 209                     beenHere = true;
 210                 }
 211                 TimeValue now;
 212                 osl_getSystemTime(&now);
 213                 int seconds = now.Seconds - first.Seconds;
 214                 int milliSeconds;
 215                 if (now.Nanosec < first.Nanosec) {
 216                     seconds--;
 217                     milliSeconds = 1000-(first.Nanosec-now.Nanosec)/1000000;
 218                 }
 219                 else
 220                     milliSeconds = (now.Nanosec-first.Nanosec)/1000000;
 221                 char relativeTimestamp[100];
 222                 snprintf(relativeTimestamp, sizeof(relativeTimestamp), "%d.%03d", seconds, milliSeconds);
 223                 s << relativeTimestamp << ':';
 224             }
 225             return;
 226         case '+':
 227             {
 228                 char const * p1 = p;
 229                 while (*p1 != '.' && *p1 != '+' && *p1 != '-' && *p1 != '\0') {
 230                     ++p1;
 231                 }
 232                 if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("TIMESTAMP")))
 233                     outputTimestamp = true;
 234                 else if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("RELATIVETIMER")))
 235                     outputRelativeTimer = true;
 236                 char const * p2 = p1;
 237                 while (*p2 != '+' && *p2 != '-' && *p2 != '\0') {
 238                     ++p2;
 239                 }
 240                 p = p2;
 241             }
 242             break;
 243         default:
 244             ; // nothing
 245         }
 246     }
 247 }
 248
 249 #endif
 250
 251 }
 252
 253 void sal_detail_log(
 254     sal_detail_LogLevel level, char const * area, char const * where,
 255     char const * message, sal_uInt32 backtraceDepth)
 256 {
 257     std::ostringstream s;
 258 #if !defined ANDROID
 259     // On Android, the area will be used as the "tag," and log info already
 260     // contains timestamp and PID.
 261     if (!sal_use_syslog) {
 262         maybeOutputTimestamp(s);
 263         s << toString(level) << ':';
 264     }
 265     if (level != SAL_DETAIL_LOG_LEVEL_DEBUG) {
 266         s << area << ':';
 267     }
 268     s << OSL_DETAIL_GETPID << ':';
 269 #endif
 270     s << osl::Thread::getCurrentIdentifier() << ':';
 271     if (level == SAL_DETAIL_LOG_LEVEL_DEBUG) {
 272         s << ' ';
 273     } else {
 274         const size_t nStrLen(std::strlen(SRCDIR "/"));
 275         s << (where
 276               + (std::strncmp(where, SRCDIR "/", nStrLen) == 0
 277                  ? nStrLen : 0));
 278     }
 279     s << message;
 280     if (backtraceDepth != 0) {
 281         s << " at:\n" << osl::detail::backtraceAsString(backtraceDepth);
 282     }
 283
 284 #if defined ANDROID
 285     int android_log_level;
 286     switch (level) {
 287     case SAL_DETAIL_LOG_LEVEL_INFO:
 288         android_log_level = ANDROID_LOG_INFO;
 289         break;
 290     case SAL_DETAIL_LOG_LEVEL_WARN:
 291         android_log_level = ANDROID_LOG_WARN;
 292         break;
 293     case SAL_DETAIL_LOG_LEVEL_DEBUG:
 294         android_log_level = ANDROID_LOG_DEBUG;
 295         break;
 296     default:
 297         android_log_level = ANDROID_LOG_INFO;
 298         break;
 299     }
 300     __android_log_print(
 301         android_log_level, area == 0 ? "LibreOffice" : area, "%s",
 302         s.str().c_str());
 303 #else
 304     if (sal_use_syslog) {
 305 #if HAVE_SYSLOG_H
 306         int prio;
 307         switch (level) {
 308         case SAL_DETAIL_LOG_LEVEL_INFO:
 309             prio = LOG_INFO;
 310             break;
 311         case SAL_DETAIL_LOG_LEVEL_WARN:
 312             prio = LOG_WARNING;
 313             break;
 314         case SAL_DETAIL_LOG_LEVEL_DEBUG:
 315             prio = LOG_DEBUG;
 316             break;
 317         default:
 318             assert(false); // this cannot happen
 319             prio = LOG_WARNING;
 320         }
 321         syslog(prio, "%s", s.str().c_str());
 322 #endif
 323     } else {
 324         // avoid calling getLogFile() more than once
 325         static std::ofstream * logFile = getLogFile();
 326         if (logFile) {
 327             *logFile << s.str() << std::endl;
 328         }
 329         else {
 330 #ifdef WNT
 331             // write to Windows debugger console, too
 332             OutputDebugStringA(s.str().c_str());
 333 #endif
 334 #if ! (defined(WNT) && ENABLE_RELEASE_BUILD)
 335             // on Windows deployments, no one reads console output
 336             s << '\n';
 337             std::fputs(s.str().c_str(), stderr);
 338             std::fflush(stderr);
 339 #endif
 340         }
 341     }
 342 #endif
 343 }
 344
 345 void sal_detail_logFormat(
 346     sal_detail_LogLevel level, char const * area, char const * where,
 347     char const * format, ...)
 348 {
 349     if (sal_detail_log_report(level, area)) {
 350         std::va_list args;
 351         va_start(args, format);
 352         char buf[1024];
 353         int const len = sizeof buf - RTL_CONSTASCII_LENGTH("...");
 354         int n = vsnprintf(buf, len, format, args);
 355         if (n < 0) {
 356             std::strcpy(buf, "???");
 357         } else if (n >= len) {
 358             std::strcpy(buf + len - 1, "...");
 359         }
 360         sal_detail_log(level, area, where, buf, 0);
 361         va_end(args);
 362     }
 363 }
 364
 365 sal_Bool sal_detail_log_report(sal_detail_LogLevel level, char const * area) {
 366     if (level == SAL_DETAIL_LOG_LEVEL_DEBUG) {
 367         return true;
 368     }
 369     assert(area != nullptr);
 370     static char const * env = getLogLevel();
 371     if (env == nullptr) {
 372         env = "+WARN";
 373     }
 374     std::size_t areaLen = std::strlen(area);
 375     enum Sense { POSITIVE = 0, NEGATIVE = 1 };
 376     std::size_t senseLen[2] = { 0, 1 };
 377         // initial senseLen[POSITIVE] < senseLen[NEGATIVE], so that if there are
 378         // no matching switches at all, the result will be negative (and
 379         // initializing with 1 is safe as the length of a valid switch, even
 380         // without the "+"/"-" prefix, will always be > 1)
 381     bool seenWarn = false;
 382     for (char const * p = env;;) {
 383         Sense sense;
 384         switch (*p++) {
 385         case '\0':
 386             if (level == SAL_DETAIL_LOG_LEVEL_WARN && !seenWarn)
 387                 return sal_detail_log_report(SAL_DETAIL_LOG_LEVEL_INFO, area);
 388             return senseLen[POSITIVE] >= senseLen[NEGATIVE];
 389                 // if a specific item is both positive and negative
 390                 // (senseLen[POSITIVE] == senseLen[NEGATIVE]), default to
 391                 // positive
 392         case '+':
 393             sense = POSITIVE;
 394             break;
 395         case '-':
 396             sense = NEGATIVE;
 397             break;
 398         default:
 399             return true; // upon an illegal SAL_LOG value, enable everything
 400         }
 401         char const * p1 = p;
 402         while (*p1 != '.' && *p1 != '+' && *p1 != '-' && *p1 != '\0') {
 403             ++p1;
 404         }
 405         bool match;
 406         if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("INFO"))) {
 407             match = level == SAL_DETAIL_LOG_LEVEL_INFO;
 408         } else if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("WARN")))
 409         {
 410             match = level == SAL_DETAIL_LOG_LEVEL_WARN;
 411             seenWarn = true;
 412         } else if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("TIMESTAMP")) ||
 413                    equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("RELATIVETIMER")))
 414         {
 415             // handled later
 416             match = false;
 417         } else {
 418             return true;
 419                 // upon an illegal SAL_LOG value, everything is considered
 420                 // positive
 421         }
 422         char const * p2 = p1;
 423         while (*p2 != '+' && *p2 != '-' && *p2 != '\0') {
 424             ++p2;
 425         }
 426         if (match) {
 427             if (*p1 == '.') {
 428                 ++p1;
 429                 std::size_t n = p2 - p1;
 430                 if ((n == areaLen && equalStrings(p1, n, area, areaLen))
 431                     || (n < areaLen && area[n] == '.'
 432                         && equalStrings(p1, n, area, n)))
 433                 {
 434                     senseLen[sense] = p2 - p;
 435                 }
 436             } else {
 437                 senseLen[sense] = p1 - p;
 438             }
 439         }
 440         p = p2;
 441     }
 442 }
 443
 444 /* vim:set shiftwidth=4 softtabstop=4 expandtab: */