summaryrefslogtreecommitdiffstats
path: root/sal/osl/all/log.cxx
blob: 405d5599ccae165b06f72a49e1a4cbec32506564 (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
/* -*- Mode: C++; tab-width: 4; indent-tabs-mode: nil; c-basic-offset: 4 -*- */
/*
 * This file is part of the LibreOffice project.
 *
 * This Source Code Form is subject to the terms of the Mozilla Public
 * License, v. 2.0. If a copy of the MPL was not distributed with this
 * file, You can obtain one at http://mozilla.org/MPL/2.0/.
 */

#include <sal/config.h>

#include <cassert>
#include <cstdarg>
#include <cstddef>
#include <cstdio>
#include <cstdlib>
#include <cstring>
#include <sstream>

#include <stdio.h>
#include <string.h>
#include <fstream>

#include <config_global.h>
#include <osl/thread.hxx>
#include <rtl/string.h>
#include <sal/detail/log.h>
#include <sal/log.hxx>
#include <sal/types.h>
#include <backtraceasstring.hxx>
#include <salusesyslog.hxx>

#if defined ANDROID
#include <android/log.h>
#elif defined _WIN32
#include <process.h>
#include <windows.h>
#define OSL_DETAIL_GETPID _getpid()
#else
#include <unistd.h>
#define OSL_DETAIL_GETPID getpid()
#endif

#if HAVE_SYSLOG_H
#include <syslog.h>
// sal/osl/unx/salinit.cxx::sal_detail_initialize updates this:
bool sal_use_syslog;
#else
bool const sal_use_syslog = false;
#endif

// Avoid the use of other sal code in this file as much as possible, so that
// this code can be called from other sal code without causing endless
// recursion.

namespace {

struct TimeContainer
{
    TimeValue aTime;
    TimeContainer()
    {
        osl_getSystemTime(&aTime);
    }
};

TimeContainer aStartTime;

bool equalStrings(
    char const * string1, std::size_t length1, char const * string2,
    std::size_t length2)
{
    return length1 == length2 && std::memcmp(string1, string2, length1) == 0;
}

#if !defined ANDROID
char const * toString(sal_detail_LogLevel level) {
    switch (level) {
    case SAL_DETAIL_LOG_LEVEL_INFO:
        return "info";
    case SAL_DETAIL_LOG_LEVEL_WARN:
        return "warn";
    case SAL_DETAIL_LOG_LEVEL_DEBUG:
        return "debug";
    default:
        assert(false); // this cannot happen
        return "broken";
    }
}
#endif

#ifdef _WIN32

char const* setEnvFromLoggingIniFile(const char* env, const char* key)
{
    char const* sResult = nullptr;
    wchar_t buffer[MAX_PATH];
    GetModuleFileNameW(nullptr, buffer, MAX_PATH);
    std::wstring sProgramDirectory(buffer);
    std::wstring::size_type pos = sProgramDirectory.find_last_of(L"\\/");
    sProgramDirectory = sProgramDirectory.substr(0, pos+1);
    sProgramDirectory += L"logging.ini";

    std::ifstream logFileStream(sProgramDirectory);
    if (!logFileStream.good())
        return sResult;

    std::size_t n;
    std::string aKey;
    std::string sWantedKey(key);
    std::string sLine;
    while (std::getline(logFileStream, sLine)) {
        if (sLine.find('#') == 0)
            continue;
        if ( ( n = sLine.find('=') ) != std::string::npos) {
            aKey = sLine.substr(0, n);
            if (aKey != sWantedKey)
                continue;
            _putenv_s(env, sLine.substr(n+1, sLine.length()).c_str());
            sResult = std::getenv(env);
            break;
        }
    }
    return sResult;
}
#endif

char const* pLogSelector = nullptr;

char const* getLogLevelEnvVar() {
    static char const* const pLevel = [] {
        char const* pResult = nullptr;

        // First check the environment variable, then the setting in logging.ini
        char const* env = std::getenv("SAL_LOG");

#ifdef _WIN32
        if (!env)
            env = setEnvFromLoggingIniFile("SAL_LOG", "LogLevel");
#endif

        if (env)
        {
            // Make a copy from the string in environment block
            static std::string sLevel(env);
            pResult = sLevel.c_str();
        }
        return pResult;
    }();

    return pLevel;
}

#if !defined ANDROID

std::ofstream * getLogFile() {
    static std::ofstream* const pFile = [] {
        std::ofstream* pResult = nullptr;

        // First check the environment variable, then the setting in logging.ini
        char const* logFile = std::getenv("SAL_LOG_FILE");

#ifdef _WIN32
        if (!logFile)
            logFile = setEnvFromLoggingIniFile("SAL_LOG_FILE", "LogFilePath");
#endif

        if (logFile)
        {
            // stays until process exits
            static std::ofstream file(logFile, std::ios::app | std::ios::out);
            pResult = &file;
        }

        return pResult;
    }();

    return pFile;
}


std::pair<bool, bool> getTimestampFlags(char const *selector)
{
    bool outputTimestamp = false;
    bool outputRelativeTimer = false;
    for (char const* p = selector; p && *p;)
    {
            if (*p++ == '+')
            {
                char const * p1 = p;
                while (*p1 != '.' && *p1 != '+' && *p1 != '-' && *p1 != '\0') {
                    ++p1;
                }
                if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("TIMESTAMP")))
                    outputTimestamp = true;
                else if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("RELATIVETIMER")))
                    outputRelativeTimer = true;
                char const * p2 = p1;
                while (*p2 != '+' && *p2 != '-' && *p2 != '\0') {
                    ++p2;
                }
                p = p2;
            }
    }
    return std::pair(outputTimestamp, outputRelativeTimer);
}

void maybeOutputTimestamp(std::ostringstream &s) {
    static const std::pair<bool, bool> aEnvFlags = getTimestampFlags(getLogLevelEnvVar());
    const auto& [outputTimestamp, outputRelativeTimer] = (pLogSelector == nullptr ? aEnvFlags : getTimestampFlags(pLogSelector));

    if (outputTimestamp)
    {
        char ts[100];
        TimeValue systemTime;
        osl_getSystemTime(&systemTime);
        TimeValue localTime;
        osl_getLocalTimeFromSystemTime(&systemTime, &localTime);
        oslDateTime dateTime;
        osl_getDateTimeFromTimeValue(&localTime, &dateTime);
        struct tm tm;
        tm.tm_sec = dateTime.Seconds;
        tm.tm_min = dateTime.Minutes;
        tm.tm_hour = dateTime.Hours;
        tm.tm_mday = dateTime.Day;
        tm.tm_wday = dateTime.DayOfWeek;
        tm.tm_mon = dateTime.Month - 1;
        tm.tm_year = dateTime.Year - 1900;
        tm.tm_yday = 0;
        strftime(ts, sizeof(ts), "%Y-%m-%d:%H:%M:%S", &tm);
        char milliSecs[11];
        snprintf(milliSecs, sizeof(milliSecs), "%03u",
                 static_cast<unsigned>(dateTime.NanoSeconds / 1000000));
        s << ts << '.' << milliSecs << ':';
    }
    if (!outputRelativeTimer)
        return;

    TimeValue now;
    osl_getSystemTime(&now);
    int seconds = now.Seconds - aStartTime.aTime.Seconds;
    int milliSeconds;
    if (now.Nanosec < aStartTime.aTime.Nanosec)
    {
        seconds--;
        milliSeconds = 1000 - (aStartTime.aTime.Nanosec - now.Nanosec) / 1000000;
    }
    else
        milliSeconds = (now.Nanosec - aStartTime.aTime.Nanosec) / 1000000;
    char relativeTimestamp[100];
    snprintf(relativeTimestamp, sizeof(relativeTimestamp), "%d.%03d", seconds, milliSeconds);
    s << relativeTimestamp << ':';
}

#endif

}

void sal_detail_log(
    sal_detail_LogLevel level, char const * area, char const * where,
    char const * message, sal_uInt32 backtraceDepth)
{
    std::ostringstream s;
#if !defined ANDROID
    // On Android, the area will be used as the "tag," and log info already
    // contains timestamp and PID.
    if (!sal_use_syslog) {
        maybeOutputTimestamp(s);
        s << toString(level) << ':';
    }
    if (level != SAL_DETAIL_LOG_LEVEL_DEBUG) {
        s << area << ':';
    }
    s << OSL_DETAIL_GETPID << ':';
#endif
    s << osl::Thread::getCurrentIdentifier() << ':';
    if (level == SAL_DETAIL_LOG_LEVEL_DEBUG) {
        s << ' ';
    } else {
        const size_t nStrLen(std::strlen(SRCDIR "/"));
        s << (where
              + (std::strncmp(where, SRCDIR "/", nStrLen) == 0
                 ? nStrLen : 0));
    }
    s << message;
    if (backtraceDepth != 0) {
        s << " at:\n" << osl::detail::backtraceAsString(backtraceDepth);
    }

#if defined ANDROID
    int android_log_level;
    switch (level) {
    case SAL_DETAIL_LOG_LEVEL_INFO:
        android_log_level = ANDROID_LOG_INFO;
        break;
    case SAL_DETAIL_LOG_LEVEL_WARN:
        android_log_level = ANDROID_LOG_WARN;
        break;
    case SAL_DETAIL_LOG_LEVEL_DEBUG:
        android_log_level = ANDROID_LOG_DEBUG;
        break;
    default:
        android_log_level = ANDROID_LOG_INFO;
        break;
    }
    __android_log_print(
        android_log_level, area == 0 ? "LibreOffice" : area, "%s",
        s.str().c_str());
#else
    if (sal_use_syslog) {
#if HAVE_SYSLOG_H
        int prio;
        switch (level) {
        case SAL_DETAIL_LOG_LEVEL_INFO:
            prio = LOG_INFO;
            break;
        case SAL_DETAIL_LOG_LEVEL_WARN:
            prio = LOG_WARNING;
            break;
        case SAL_DETAIL_LOG_LEVEL_DEBUG:
            prio = LOG_DEBUG;
            break;
        default:
            assert(false); // this cannot happen
            prio = LOG_WARNING;
        }
        syslog(prio, "%s", s.str().c_str());
#endif
    } else {
        // avoid calling getLogFile() more than once
        static std::ofstream * logFile = getLogFile();
        if (logFile) {
            *logFile << s.str() << std::endl;
        }
        else {
            s << '\n';
#ifdef _WIN32
            // write to Windows debugger console, too
            OutputDebugStringA(s.str().c_str());
#endif
            std::fputs(s.str().c_str(), stderr);
            std::fflush(stderr);
        }
    }
#endif
}

void sal_detail_set_log_selector(char const *logSelector)
{
    pLogSelector = logSelector;
}

void sal_detail_logFormat(
    sal_detail_LogLevel level, char const * area, char const * where,
    char const * format, ...)
{
    const sal_detail_LogAction eAction
        = static_cast<sal_detail_LogAction>(sal_detail_log_report(level, area));
    if (eAction == SAL_DETAIL_LOG_ACTION_IGNORE)
        return;

    std::va_list args;
    va_start(args, format);
    char buf[1024];
    int const len = sizeof buf - RTL_CONSTASCII_LENGTH("...");
    int n = vsnprintf(buf, len, format, args);
    if (n < 0) {
        std::strcpy(buf, "???");
    } else if (n >= len) {
        std::strcpy(buf + len - 1, "...");
    }
    sal_detail_log(level, area, where, buf, 0);
    va_end(args);

    if (eAction == SAL_DETAIL_LOG_ACTION_FATAL)
        std::abort();
}

unsigned char sal_detail_log_report(sal_detail_LogLevel level, char const * area)
{
    if (level == SAL_DETAIL_LOG_LEVEL_DEBUG) {
        return SAL_DETAIL_LOG_ACTION_LOG;
    }
    assert(area != nullptr);
    static char const* const envEnv = [] {
        char const* pResult =  getLogLevelEnvVar();
        if (!pResult)
            pResult = "+WARN";
        return pResult;
    }();
    char const* const env = (pLogSelector == nullptr ? envEnv : pLogSelector);
    std::size_t areaLen = std::strlen(area);
    enum Sense { POSITIVE = 0, NEGATIVE = 1 };
    std::size_t senseLen[2] = { 0, 1 };
        // initial senseLen[POSITIVE] < senseLen[NEGATIVE], so that if there are
        // no matching switches at all, the result will be negative (and
        // initializing with 1 is safe as the length of a valid switch, even
        // without the "+"/"-" prefix, will always be > 1)
    bool senseFatal[2] = { false, false };
    bool seenWarn = false;
    bool bFlagFatal = false;
    for (char const * p = env;;) {
        Sense sense;
        switch (*p++) {
        case '\0':
        {
            if (level == SAL_DETAIL_LOG_LEVEL_WARN && !seenWarn)
                return sal_detail_log_report(SAL_DETAIL_LOG_LEVEL_INFO, area);

            sal_detail_LogAction eAction = SAL_DETAIL_LOG_ACTION_IGNORE;
            // if a specific item is positive and negative (==), default to positive
            if (senseLen[POSITIVE] >= senseLen[NEGATIVE])
            {
                if (senseFatal[POSITIVE]) eAction = SAL_DETAIL_LOG_ACTION_FATAL;
                else eAction = SAL_DETAIL_LOG_ACTION_LOG;
            }
            return eAction;
        }
        case '+':
            sense = POSITIVE;
            break;
        case '-':
            sense = NEGATIVE;
            break;
        default:
            return SAL_DETAIL_LOG_ACTION_LOG; // upon an illegal SAL_LOG value, enable everything
        }
        char const * p1 = p;
        while (*p1 != '.' && *p1 != '+' && *p1 != '-' && *p1 != '\0') {
            ++p1;
        }
        bool match;
        if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("INFO"))) {
            match = level == SAL_DETAIL_LOG_LEVEL_INFO;
        } else if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("WARN")))
        {
            match = level == SAL_DETAIL_LOG_LEVEL_WARN;
            seenWarn = true;
        } else if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("FATAL")))
        {
            bFlagFatal = (sense == POSITIVE);
            match = false;
        } else if (equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("TIMESTAMP")) ||
                   equalStrings(p, p1 - p, RTL_CONSTASCII_STRINGPARAM("RELATIVETIMER")))
        {
            // handled later
            match = false;
        } else {
            return SAL_DETAIL_LOG_ACTION_LOG;
                // upon an illegal SAL_LOG value, everything is considered
                // positive
        }
        char const * p2 = p1;
        while (*p2 != '+' && *p2 != '-' && *p2 != '\0') {
            ++p2;
        }
        if (match) {
            if (*p1 == '.') {
                ++p1;
                std::size_t n = p2 - p1;
                if ((n == areaLen && equalStrings(p1, n, area, areaLen))
                    || (n < areaLen && area[n] == '.'
                        && equalStrings(p1, n, area, n)))
                {
                    senseLen[sense] = p2 - p;
                    senseFatal[sense] = bFlagFatal;
                }
            } else {
                senseLen[sense] = p1 - p;
                senseFatal[sense] = bFlagFatal;
            }
        }
        p = p2;
    }
}

/* vim:set shiftwidth=4 softtabstop=4 expandtab: */