diff options
Diffstat (limited to 'src/VBox/Runtime/common/log')
| -rw-r--r-- | src/VBox/Runtime/common/log/Makefile.kup | 0 | ||||
| -rw-r--r-- | src/VBox/Runtime/common/log/log.cpp | 4126 | ||||
| -rw-r--r-- | src/VBox/Runtime/common/log/logcom.cpp | 146 | ||||
| -rw-r--r-- | src/VBox/Runtime/common/log/logellipsis.cpp | 105 | ||||
| -rw-r--r-- | src/VBox/Runtime/common/log/logformat.cpp | 100 | ||||
| -rw-r--r-- | src/VBox/Runtime/common/log/logrel.cpp | 185 | ||||
| -rw-r--r-- | src/VBox/Runtime/common/log/logrelellipsis.cpp | 78 | ||||
| -rw-r--r-- | src/VBox/Runtime/common/log/tracebuf.cpp | 688 | ||||
| -rw-r--r-- | src/VBox/Runtime/common/log/tracedefault.cpp | 82 | ||||
| -rw-r--r-- | src/VBox/Runtime/common/log/tracelogreader.cpp | 1747 | ||||
| -rw-r--r-- | src/VBox/Runtime/common/log/tracelogwriter.cpp | 953 |
11 files changed, 8210 insertions, 0 deletions
diff --git a/src/VBox/Runtime/common/log/Makefile.kup b/src/VBox/Runtime/common/log/Makefile.kup new file mode 100644 index 00000000..e69de29b --- /dev/null +++ b/src/VBox/Runtime/common/log/Makefile.kup diff --git a/src/VBox/Runtime/common/log/log.cpp b/src/VBox/Runtime/common/log/log.cpp new file mode 100644 index 00000000..f71ed866 --- /dev/null +++ b/src/VBox/Runtime/common/log/log.cpp @@ -0,0 +1,4126 @@ +/* $Id: log.cpp $ */ +/** @file + * Runtime VBox - Logger. + */ + +/* + * Copyright (C) 2006-2020 Oracle Corporation + * + * This file is part of VirtualBox Open Source Edition (OSE), as + * available from http://www.virtualbox.org. This file is free software; + * you can redistribute it and/or modify it under the terms of the GNU + * General Public License (GPL) as published by the Free Software + * Foundation, in version 2 as it comes in the "COPYING" file of the + * VirtualBox OSE distribution. VirtualBox OSE is distributed in the + * hope that it will be useful, but WITHOUT ANY WARRANTY of any kind. + * + * The contents of this file may alternatively be used under the terms + * of the Common Development and Distribution License Version 1.0 + * (CDDL) only, as it comes in the "COPYING.CDDL" file of the + * VirtualBox OSE distribution, in which case the provisions of the + * CDDL are applicable instead of those of the GPL. + * + * You may elect to license modified versions of this file under the + * terms and conditions of either the GPL or the CDDL or both. + */ + + +/********************************************************************************************************************************* +* Header Files * +*********************************************************************************************************************************/ +#include <iprt/log.h> +#include "internal/iprt.h" + +#ifndef IN_RC +# include <iprt/alloc.h> +# include <iprt/process.h> +# include <iprt/semaphore.h> +# include <iprt/thread.h> +# include <iprt/mp.h> +#endif +#ifdef IN_RING3 +# include <iprt/env.h> +# include <iprt/file.h> +# include <iprt/lockvalidator.h> +# include <iprt/path.h> +#endif +#include <iprt/time.h> +#include <iprt/asm.h> +#if defined(RT_ARCH_AMD64) || defined(RT_ARCH_X86) +# include <iprt/asm-amd64-x86.h> +#endif +#include <iprt/assert.h> +#include <iprt/err.h> +#include <iprt/param.h> + +#include <iprt/stdarg.h> +#include <iprt/string.h> +#include <iprt/ctype.h> +#ifdef IN_RING3 +# include <iprt/alloca.h> +# include <stdio.h> +#endif + + +/********************************************************************************************************************************* +* Defined Constants And Macros * +*********************************************************************************************************************************/ +/** @def RTLOG_RINGBUF_DEFAULT_SIZE + * The default ring buffer size. */ +/** @def RTLOG_RINGBUF_MAX_SIZE + * The max ring buffer size. */ +/** @def RTLOG_RINGBUF_MIN_SIZE + * The min ring buffer size. */ +#ifdef IN_RING0 +# define RTLOG_RINGBUF_DEFAULT_SIZE _64K +# define RTLOG_RINGBUF_MAX_SIZE _4M +# define RTLOG_RINGBUF_MIN_SIZE _1K +#elif defined(IN_RING3) || defined(DOXYGEN_RUNNING) +# define RTLOG_RINGBUF_DEFAULT_SIZE _512K +# define RTLOG_RINGBUF_MAX_SIZE _1G +# define RTLOG_RINGBUF_MIN_SIZE _4K +#endif +/** The start of ring buffer eye catcher (16 bytes). */ +#define RTLOG_RINGBUF_EYE_CATCHER "START RING BUF\0" +AssertCompile(sizeof(RTLOG_RINGBUF_EYE_CATCHER) == 16); +/** The end of ring buffer eye catcher (16 bytes). This also ensures that the ring buffer + * forms are properly terminated C string (leading zero chars). */ +#define RTLOG_RINGBUF_EYE_CATCHER_END "\0\0\0END RING BUF" +AssertCompile(sizeof(RTLOG_RINGBUF_EYE_CATCHER_END) == 16); + + +/********************************************************************************************************************************* +* Structures and Typedefs * +*********************************************************************************************************************************/ +/** + * Arguments passed to the output function. + */ +typedef struct RTLOGOUTPUTPREFIXEDARGS +{ + /** The logger instance. */ + PRTLOGGER pLogger; + /** The flags. (used for prefixing.) */ + unsigned fFlags; + /** The group. (used for prefixing.) */ + unsigned iGroup; +} RTLOGOUTPUTPREFIXEDARGS, *PRTLOGOUTPUTPREFIXEDARGS; + +#ifndef IN_RC + +/** + * Internal logger data. + * + * @remarks Don't make casual changes to this structure. + */ +typedef struct RTLOGGERINTERNAL +{ + /** The structure revision (RTLOGGERINTERNAL_REV). */ + uint32_t uRevision; + /** The size of the internal logger structure. */ + uint32_t cbSelf; + + /** Spinning mutex semaphore. Can be NIL. */ + RTSEMSPINMUTEX hSpinMtx; + /** Pointer to the flush function. */ + PFNRTLOGFLUSH pfnFlush; + + /** Custom prefix callback. */ + PFNRTLOGPREFIX pfnPrefix; + /** Prefix callback argument. */ + void *pvPrefixUserArg; + /** This is set if a prefix is pending. */ + bool fPendingPrefix; + /** Alignment padding. */ + bool afPadding1[2]; + /** Set if fully created. Used to avoid confusing in a few functions used to + * parse logger settings from environment variables. */ + bool fCreated; + + /** The max number of groups that there is room for in afGroups and papszGroups. + * Used by RTLogCopyGroupAndFlags(). */ + uint32_t cMaxGroups; + /** Pointer to the group name array. + * (The data is readonly and provided by the user.) */ + const char * const *papszGroups; + + /** The number of log entries per group. NULL if + * RTLOGFLAGS_RESTRICT_GROUPS is not specified. */ + uint32_t *pacEntriesPerGroup; + /** The max number of entries per group. */ + uint32_t cMaxEntriesPerGroup; + + /** @name Ring buffer logging + * The ring buffer records the last cbRingBuf - 1 of log output. The + * other configured log destinations are not touched until someone calls + * RTLogFlush(), when the ring buffer content is written to them all. + * + * The aim here is a fast logging destination, that avoids wasting storage + * space saving disk space when dealing with huge log volumes where the + * interesting bits usually are found near the end of the log. This is + * typically the case for scenarios that crashes or hits assertions. + * + * RTLogFlush() is called implicitly when hitting an assertion. While on a + * crash the most debuggers are able to make calls these days, it's usually + * possible to view the ring buffer memory. + * + * @{ */ + /** Ring buffer size (including both eye catchers). */ + uint32_t cbRingBuf; + /** Number of bytes passing thru the ring buffer since last RTLogFlush call. + * (This is used to avoid writing out the same bytes twice.) */ + uint64_t volatile cbRingBufUnflushed; + /** Ring buffer pointer (points at RTLOG_RINGBUF_EYE_CATCHER). */ + char *pszRingBuf; + /** Current ring buffer position (where to write the next char). */ + char * volatile pchRingBufCur; + /** @} */ + + /** Program time base for ring-0 (copy of g_u64ProgramStartNanoTS). */ + uint64_t nsR0ProgramStart; + /** Thread name for use in ring-0 with RTLOGFLAGS_PREFIX_THREAD. */ + char szR0ThreadName[16]; + +# ifdef IN_RING3 /* Note! Must be at the end! */ + /** @name File logging bits for the logger. + * @{ */ + /** Pointer to the function called when starting logging, and when + * ending or starting a new log file as part of history rotation. + * This can be NULL. */ + PFNRTLOGPHASE pfnPhase; + + /** Handle to log file (if open). */ + RTFILE hFile; + /** Log file history settings: maximum amount of data to put in a file. */ + uint64_t cbHistoryFileMax; + /** Log file history settings: current amount of data in a file. */ + uint64_t cbHistoryFileWritten; + /** Log file history settings: maximum time to use a file (in seconds). */ + uint32_t cSecsHistoryTimeSlot; + /** Log file history settings: in what time slot was the file created. */ + uint32_t uHistoryTimeSlotStart; + /** Log file history settings: number of older files to keep. + * 0 means no history. */ + uint32_t cHistory; + /** Pointer to filename. */ + char szFilename[RTPATH_MAX]; + /** @} */ +# endif /* IN_RING3 */ +} RTLOGGERINTERNAL; + +/** The revision of the internal logger structure. */ +# define RTLOGGERINTERNAL_REV UINT32_C(11) + +# ifdef IN_RING3 +/** The size of the RTLOGGERINTERNAL structure in ring-0. */ +# define RTLOGGERINTERNAL_R0_SIZE RT_UOFFSETOF(RTLOGGERINTERNAL, pfnPhase) +AssertCompileMemberAlignment(RTLOGGERINTERNAL, hFile, sizeof(void *)); +AssertCompileMemberAlignment(RTLOGGERINTERNAL, cbHistoryFileMax, sizeof(uint64_t)); +# endif +AssertCompileMemberAlignment(RTLOGGERINTERNAL, cbRingBufUnflushed, sizeof(uint64_t)); + +#endif /* !IN_RC */ + + +/********************************************************************************************************************************* +* Internal Functions * +*********************************************************************************************************************************/ +#ifndef IN_RC +static unsigned rtlogGroupFlags(const char *psz); +#endif +#ifdef IN_RING0 +static void rtR0LogLoggerExFallback(uint32_t fDestFlags, uint32_t fFlags, PRTLOGGERINTERNAL pInt, + const char *pszFormat, va_list va); +#endif +#ifdef IN_RING3 +static int rtR3LogOpenFileDestination(PRTLOGGER pLogger, PRTERRINFO pErrInfo); +#endif +#ifndef IN_RC +static void rtLogRingBufFlush(PRTLOGGER pLogger); +#endif +static void rtlogFlush(PRTLOGGER pLogger, bool fNeedSpace); +static DECLCALLBACK(size_t) rtLogOutput(void *pv, const char *pachChars, size_t cbChars); +static DECLCALLBACK(size_t) rtLogOutputPrefixed(void *pv, const char *pachChars, size_t cbChars); +static void rtlogLoggerExVLocked(PRTLOGGER pLogger, unsigned fFlags, unsigned iGroup, const char *pszFormat, va_list args); +#ifndef IN_RC +static void rtlogLoggerExFLocked(PRTLOGGER pLogger, unsigned fFlags, unsigned iGroup, const char *pszFormat, ...); +#endif + + +/********************************************************************************************************************************* +* Global Variables * +*********************************************************************************************************************************/ +#ifdef IN_RC +/** Default logger instance. Make it weak because our RC module loader does not + * necessarily resolve this symbol and the compiler _must_ check if this is + * the case or not. That doesn't work for Darwin (``incompatible feature used: + * .weak_reference (must specify "-dynamic" to be used'') */ +# ifdef RT_OS_DARWIN +extern "C" DECLIMPORT(RTLOGGERRC) g_Logger; +# else +extern "C" DECLWEAK(DECLIMPORT(RTLOGGERRC)) g_Logger; +# endif +#else /* !IN_RC */ +/** Default logger instance. */ +static PRTLOGGER g_pLogger; +#endif /* !IN_RC */ +#ifdef IN_RING3 +/** The RTThreadGetWriteLockCount() change caused by the logger mutex semaphore. */ +static uint32_t volatile g_cLoggerLockCount; +#endif + +#ifdef IN_RING0 +/** Number of per-thread loggers. */ +static int32_t volatile g_cPerThreadLoggers; +/** Per-thread loggers. + * This is just a quick TLS hack suitable for debug logging only. + * If we run out of entries, just unload and reload the driver. */ +static struct RTLOGGERPERTHREAD +{ + /** The thread. */ + RTNATIVETHREAD volatile NativeThread; + /** The (process / session) key. */ + uintptr_t volatile uKey; + /** The logger instance.*/ + PRTLOGGER volatile pLogger; +} g_aPerThreadLoggers[8] = +{ + { NIL_RTNATIVETHREAD, 0, 0}, + { NIL_RTNATIVETHREAD, 0, 0}, + { NIL_RTNATIVETHREAD, 0, 0}, + { NIL_RTNATIVETHREAD, 0, 0}, + { NIL_RTNATIVETHREAD, 0, 0}, + { NIL_RTNATIVETHREAD, 0, 0}, + { NIL_RTNATIVETHREAD, 0, 0}, + { NIL_RTNATIVETHREAD, 0, 0} +}; +#endif /* IN_RING0 */ + +/** + * Logger flags instructions. + */ +static struct +{ + const char *pszInstr; /**< The name */ + size_t cchInstr; /**< The size of the name. */ + uint32_t fFlag; /**< The flag value. */ + bool fInverted; /**< Inverse meaning? */ + uint32_t fFixedDest; /**< RTLOGDEST_FIXED_XXX flags blocking this. */ +} const g_aLogFlags[] = +{ + { "disabled", sizeof("disabled" ) - 1, RTLOGFLAGS_DISABLED, false, 0 }, + { "enabled", sizeof("enabled" ) - 1, RTLOGFLAGS_DISABLED, true, 0 }, + { "buffered", sizeof("buffered" ) - 1, RTLOGFLAGS_BUFFERED, false, 0 }, + { "unbuffered", sizeof("unbuffered" ) - 1, RTLOGFLAGS_BUFFERED, true, 0 }, + { "usecrlf", sizeof("usecrlf" ) - 1, RTLOGFLAGS_USECRLF, false, 0 }, + { "uself", sizeof("uself" ) - 1, RTLOGFLAGS_USECRLF, true, 0 }, + { "append", sizeof("append" ) - 1, RTLOGFLAGS_APPEND, false, RTLOGDEST_FIXED_FILE }, + { "overwrite", sizeof("overwrite" ) - 1, RTLOGFLAGS_APPEND, true, RTLOGDEST_FIXED_FILE }, + { "rel", sizeof("rel" ) - 1, RTLOGFLAGS_REL_TS, false, 0 }, + { "abs", sizeof("abs" ) - 1, RTLOGFLAGS_REL_TS, true, 0 }, + { "dec", sizeof("dec" ) - 1, RTLOGFLAGS_DECIMAL_TS, false, 0 }, + { "hex", sizeof("hex" ) - 1, RTLOGFLAGS_DECIMAL_TS, true, 0 }, + { "writethru", sizeof("writethru" ) - 1, RTLOGFLAGS_WRITE_THROUGH, false, 0 }, + { "writethrough", sizeof("writethrough") - 1, RTLOGFLAGS_WRITE_THROUGH, false, 0 }, + { "flush", sizeof("flush" ) - 1, RTLOGFLAGS_FLUSH, false, 0 }, + { "lockcnts", sizeof("lockcnts" ) - 1, RTLOGFLAGS_PREFIX_LOCK_COUNTS, false, 0 }, + { "cpuid", sizeof("cpuid" ) - 1, RTLOGFLAGS_PREFIX_CPUID, false, 0 }, + { "pid", sizeof("pid" ) - 1, RTLOGFLAGS_PREFIX_PID, false, 0 }, + { "flagno", sizeof("flagno" ) - 1, RTLOGFLAGS_PREFIX_FLAG_NO, false, 0 }, + { "flag", sizeof("flag" ) - 1, RTLOGFLAGS_PREFIX_FLAG, false, 0 }, + { "groupno", sizeof("groupno" ) - 1, RTLOGFLAGS_PREFIX_GROUP_NO, false, 0 }, + { "group", sizeof("group" ) - 1, RTLOGFLAGS_PREFIX_GROUP, false, 0 }, + { "tid", sizeof("tid" ) - 1, RTLOGFLAGS_PREFIX_TID, false, 0 }, + { "thread", sizeof("thread" ) - 1, RTLOGFLAGS_PREFIX_THREAD, false, 0 }, + { "custom", sizeof("custom" ) - 1, RTLOGFLAGS_PREFIX_CUSTOM, false, 0 }, + { "timeprog", sizeof("timeprog" ) - 1, RTLOGFLAGS_PREFIX_TIME_PROG, false, 0 }, + { "time", sizeof("time" ) - 1, RTLOGFLAGS_PREFIX_TIME, false, 0 }, + { "msprog", sizeof("msprog" ) - 1, RTLOGFLAGS_PREFIX_MS_PROG, false, 0 }, + { "tsc", sizeof("tsc" ) - 1, RTLOGFLAGS_PREFIX_TSC, false, 0 }, /* before ts! */ + { "ts", sizeof("ts" ) - 1, RTLOGFLAGS_PREFIX_TS, false, 0 }, + /* We intentionally omit RTLOGFLAGS_RESTRICT_GROUPS. */ +}; + +/** + * Logger destination instructions. + */ +static struct +{ + const char *pszInstr; /**< The name. */ + size_t cchInstr; /**< The size of the name. */ + uint32_t fFlag; /**< The corresponding destination flag. */ +} const g_aLogDst[] = +{ + { RT_STR_TUPLE("file"), RTLOGDEST_FILE }, /* Must be 1st! */ + { RT_STR_TUPLE("dir"), RTLOGDEST_FILE }, /* Must be 2nd! */ + { RT_STR_TUPLE("history"), 0 }, /* Must be 3rd! */ + { RT_STR_TUPLE("histsize"), 0 }, /* Must be 4th! */ + { RT_STR_TUPLE("histtime"), 0 }, /* Must be 5th! */ + { RT_STR_TUPLE("ringbuf"), RTLOGDEST_RINGBUF }, /* Must be 6th! */ + { RT_STR_TUPLE("stdout"), RTLOGDEST_STDOUT }, + { RT_STR_TUPLE("stderr"), RTLOGDEST_STDERR }, + { RT_STR_TUPLE("debugger"), RTLOGDEST_DEBUGGER }, + { RT_STR_TUPLE("com"), RTLOGDEST_COM }, + { RT_STR_TUPLE("nodeny"), RTLOGDEST_F_NO_DENY }, + { RT_STR_TUPLE("user"), RTLOGDEST_USER }, + /* The RTLOGDEST_FIXED_XXX flags are omitted on purpose. */ +}; + +#ifdef IN_RING3 +/** Log rotation backoff table - millisecond sleep intervals. + * Important on Windows host, especially for VBoxSVC release logging. Only a + * medium term solution, until a proper fix for log file handling is available. + * 10 seconds total. + */ +static const uint32_t g_acMsLogBackoff[] = +{ 10, 10, 10, 20, 50, 100, 200, 200, 200, 200, 500, 500, 500, 500, 1000, 1000, 1000, 1000, 1000, 1000, 1000 }; +#endif + + +/** + * Locks the logger instance. + * + * @returns See RTSemSpinMutexRequest(). + * @param pLogger The logger instance. + */ +DECLINLINE(int) rtlogLock(PRTLOGGER pLogger) +{ +#ifndef IN_RC + PRTLOGGERINTERNAL pInt = pLogger->pInt; + AssertMsgReturn(pInt->uRevision == RTLOGGERINTERNAL_REV, ("%#x != %#x\n", pInt->uRevision, RTLOGGERINTERNAL_REV), + VERR_LOG_REVISION_MISMATCH); + AssertMsgReturn(pInt->cbSelf == sizeof(*pInt), ("%#x != %#x\n", pInt->cbSelf, sizeof(*pInt)), + VERR_LOG_REVISION_MISMATCH); + if (pInt->hSpinMtx != NIL_RTSEMSPINMUTEX) + { + int rc = RTSemSpinMutexRequest(pInt->hSpinMtx); + if (RT_FAILURE(rc)) + return rc; + } +#else + NOREF(pLogger); +#endif + return VINF_SUCCESS; +} + + +/** + * Unlocks the logger instance. + * @param pLogger The logger instance. + */ +DECLINLINE(void) rtlogUnlock(PRTLOGGER pLogger) +{ +#ifndef IN_RC + if (pLogger->pInt->hSpinMtx != NIL_RTSEMSPINMUTEX) + RTSemSpinMutexRelease(pLogger->pInt->hSpinMtx); +#else + NOREF(pLogger); +#endif + return; +} + +#ifndef IN_RC +# ifdef IN_RING3 + +# ifdef SOME_UNUSED_FUNCTION +/** + * Logging to file, output callback. + * + * @param pvArg User argument. + * @param pachChars Pointer to an array of utf-8 characters. + * @param cbChars Number of bytes in the character array pointed to by pachChars. + */ +static DECLCALLBACK(size_t) rtlogPhaseWrite(void *pvArg, const char *pachChars, size_t cbChars) +{ + PRTLOGGER pLogger = (PRTLOGGER)pvArg; + RTFileWrite(pLogger->pInt->hFile, pachChars, cbChars, NULL); + return cbChars; +} + + +/** + * Callback to format VBox formatting extentions. + * See @ref pg_rt_str_format for a reference on the format types. + * + * @returns The number of bytes formatted. + * @param pvArg Formatter argument. + * @param pfnOutput Pointer to output function. + * @param pvArgOutput Argument for the output function. + * @param ppszFormat Pointer to the format string pointer. Advance this till the char + * after the format specifier. + * @param pArgs Pointer to the argument list. Use this to fetch the arguments. + * @param cchWidth Format Width. -1 if not specified. + * @param cchPrecision Format Precision. -1 if not specified. + * @param fFlags Flags (RTSTR_NTFS_*). + * @param chArgSize The argument size specifier, 'l' or 'L'. + */ +static DECLCALLBACK(size_t) rtlogPhaseFormatStr(void *pvArg, PFNRTSTROUTPUT pfnOutput, void *pvArgOutput, + const char **ppszFormat, va_list *pArgs, int cchWidth, + int cchPrecision, unsigned fFlags, char chArgSize) +{ + char ch = *(*ppszFormat)++; + + AssertMsgFailed(("Invalid logger phase format type '%%%c%.10s'!\n", ch, *ppszFormat)); NOREF(ch); + + return 0; +} + +# endif /* SOME_UNUSED_FUNCTION */ + + +/** + * Log phase callback function, assumes the lock is already held + * + * @param pLogger The logger instance. + * @param pszFormat Format string. + * @param ... Optional arguments as specified in the format string. + */ +static DECLCALLBACK(void) rtlogPhaseMsgLocked(PRTLOGGER pLogger, const char *pszFormat, ...) +{ + va_list args; + AssertPtrReturnVoid(pLogger); + AssertPtrReturnVoid(pLogger->pInt); + Assert(pLogger->pInt->hSpinMtx != NIL_RTSEMSPINMUTEX); + + va_start(args, pszFormat); + rtlogLoggerExVLocked(pLogger, 0, ~0U, pszFormat, args); + va_end(args); +} + + +/** + * Log phase callback function, assumes the lock is not held. + * + * @param pLogger The logger instance. + * @param pszFormat Format string. + * @param ... Optional arguments as specified in the format string. + */ +static DECLCALLBACK(void) rtlogPhaseMsgNormal(PRTLOGGER pLogger, const char *pszFormat, ...) +{ + va_list args; + AssertPtrReturnVoid(pLogger); + AssertPtrReturnVoid(pLogger->pInt); + Assert(pLogger->pInt->hSpinMtx != NIL_RTSEMSPINMUTEX); + + va_start(args, pszFormat); + RTLogLoggerExV(pLogger, 0, ~0U, pszFormat, args); + va_end(args); +} + +# endif /* IN_RING3 */ + +/** + * Adjusts the ring buffer. + * + * @returns IPRT status code. + * @param pLogger The logger instance. + * @param cbNewSize The new ring buffer size (0 == default). + * @param fForce Whether to do this even if the logger instance hasn't + * really been fully created yet (i.e. during RTLogCreate). + */ +static int rtLogRingBufAdjust(PRTLOGGER pLogger, uint32_t cbNewSize, bool fForce) +{ + /* + * If this is early logger init, don't do anything. + */ + if (!pLogger->pInt->fCreated && !fForce) + return VINF_SUCCESS; + + /* + * Lock the logger and make the necessary changes. + */ + int rc = rtlogLock(pLogger); + if (RT_SUCCESS(rc)) + { + if (cbNewSize == 0) + cbNewSize = RTLOG_RINGBUF_DEFAULT_SIZE; + if ( pLogger->pInt->cbRingBuf != cbNewSize + || !pLogger->pInt->pchRingBufCur) + { + uintptr_t offOld = pLogger->pInt->pchRingBufCur - pLogger->pInt->pszRingBuf; + if (offOld < sizeof(RTLOG_RINGBUF_EYE_CATCHER)) + offOld = sizeof(RTLOG_RINGBUF_EYE_CATCHER); + else if (offOld >= cbNewSize) + { + memmove(pLogger->pInt->pszRingBuf, &pLogger->pInt->pszRingBuf[offOld - cbNewSize], cbNewSize); + offOld = sizeof(RTLOG_RINGBUF_EYE_CATCHER); + } + + void *pvNew = RTMemRealloc(pLogger->pInt->pchRingBufCur, cbNewSize); + if (pvNew) + { + pLogger->pInt->pszRingBuf = (char *)pvNew; + pLogger->pInt->pchRingBufCur = (char *)pvNew + offOld; + pLogger->pInt->cbRingBuf = cbNewSize; + memcpy(pvNew, RTLOG_RINGBUF_EYE_CATCHER, sizeof(RTLOG_RINGBUF_EYE_CATCHER)); + memcpy((char *)pvNew + cbNewSize - sizeof(RTLOG_RINGBUF_EYE_CATCHER_END), + RTLOG_RINGBUF_EYE_CATCHER_END, sizeof(RTLOG_RINGBUF_EYE_CATCHER_END)); + rc = VINF_SUCCESS; + } + else + rc = VERR_NO_MEMORY; + } + rtlogUnlock(pLogger); + } + + return rc; +} + + +/** + * Writes text to the ring buffer. + * + * @param pInt The internal logger data structure. + * @param pachText The text to write. + * @param cchText The number of chars (bytes) to write. + */ +static void rtLogRingBufWrite(PRTLOGGERINTERNAL pInt, const char *pachText, size_t cchText) +{ + /* + * Get the ring buffer data, adjusting it to only describe the writable + * part of the buffer. + */ + char * const pchStart = &pInt->pszRingBuf[sizeof(RTLOG_RINGBUF_EYE_CATCHER)]; + size_t const cchBuf = pInt->cbRingBuf - sizeof(RTLOG_RINGBUF_EYE_CATCHER) - sizeof(RTLOG_RINGBUF_EYE_CATCHER_END); + char *pchCur = pInt->pchRingBufCur; + size_t cchLeft = pchCur - pchStart; + if (RT_LIKELY(cchLeft < cchBuf)) + cchLeft = cchBuf - cchLeft; + else + { + /* May happen in ring-0 where a thread or two went ahead without getting the lock. */ + pchCur = pchStart; + cchLeft = cchBuf; + } + Assert(cchBuf < pInt->cbRingBuf); + + if (cchText < cchLeft) + { + /* + * The text fits in the remaining space. + */ + memcpy(pchCur, pachText, cchText); + pchCur[cchText] = '\0'; + pInt->pchRingBufCur = &pchCur[cchText]; + pInt->cbRingBufUnflushed += cchText; + } + else + { + /* + * The text wraps around. Taking the simple but inefficient approach + * to input texts that are longer than the ring buffer since that + * is unlikely to the be a frequent case. + */ + /* Fill to the end of the buffer. */ + memcpy(pchCur, pachText, cchLeft); + pachText += cchLeft; + cchText -= cchLeft; + pInt->cbRingBufUnflushed += cchLeft; + pInt->pchRingBufCur = pchStart; + + /* Ring buffer overflows (the plainly inefficient bit). */ + while (cchText >= cchBuf) + { + memcpy(pchStart, pachText, cchBuf); + pachText += cchBuf; + cchText -= cchBuf; + pInt->cbRingBufUnflushed += cchBuf; + } + + /* The final bit, if any. */ + if (cchText > 0) + { + memcpy(pchStart, pachText, cchText); + pInt->cbRingBufUnflushed += cchText; + } + pchStart[cchText] = '\0'; + pInt->pchRingBufCur = &pchStart[cchText]; + } +} + + +/** + * Flushes the ring buffer to all the other log destinations. + * + * @param pLogger The logger instance which ring buffer should be flushed. + */ +static void rtLogRingBufFlush(PRTLOGGER pLogger) +{ + const char *pszPreamble; + size_t cchPreamble; + const char *pszFirst; + size_t cchFirst; + const char *pszSecond; + size_t cchSecond; + + /* + * Get the ring buffer data, adjusting it to only describe the writable + * part of the buffer. + */ + uint64_t cchUnflushed = pLogger->pInt->cbRingBufUnflushed; + char * const pszBuf = &pLogger->pInt->pszRingBuf[sizeof(RTLOG_RINGBUF_EYE_CATCHER)]; + size_t const cchBuf = pLogger->pInt->cbRingBuf - sizeof(RTLOG_RINGBUF_EYE_CATCHER) - sizeof(RTLOG_RINGBUF_EYE_CATCHER_END); + size_t offCur = pLogger->pInt->pchRingBufCur - pszBuf; + size_t cchAfter; + if (RT_LIKELY(offCur < cchBuf)) + cchAfter = cchBuf - offCur; + else /* May happen in ring-0 where a thread or two went ahead without getting the lock. */ + { + offCur = 0; + cchAfter = cchBuf; + } + + pLogger->pInt->cbRingBufUnflushed = 0; + + /* + * Figure out whether there are one or two segments that needs writing, + * making the last segment is terminated. (The first is always + * terminated because of the eye-catcher at the end of the buffer.) + */ + if (cchUnflushed == 0) + return; + pszBuf[offCur] = '\0'; + if (cchUnflushed >= cchBuf) + { + pszFirst = &pszBuf[offCur + 1]; + cchFirst = cchAfter ? cchAfter - 1 : 0; + pszSecond = pszBuf; + cchSecond = offCur; + pszPreamble = "\n*FLUSH RING BUF*\n"; + cchPreamble = sizeof("\n*FLUSH RING BUF*\n") - 1; + } + else if ((size_t)cchUnflushed <= offCur) + { + cchFirst = (size_t)cchUnflushed; + pszFirst = &pszBuf[offCur - cchFirst]; + pszSecond = ""; + cchSecond = 0; + pszPreamble = ""; + cchPreamble = 0; + } + else + { + cchFirst = (size_t)cchUnflushed - offCur; + pszFirst = &pszBuf[cchBuf - cchFirst]; + pszSecond = pszBuf; + cchSecond = offCur; + pszPreamble = ""; + cchPreamble = 0; + } + + /* + * Write the ring buffer to all other destiations. + */ + if (pLogger->fDestFlags & RTLOGDEST_USER) + { + if (cchPreamble) + RTLogWriteUser(pszPreamble, cchPreamble); + if (cchFirst) + RTLogWriteUser(pszFirst, cchFirst); + if (cchSecond) + RTLogWriteUser(pszSecond, cchSecond); + } + + if (pLogger->fDestFlags & RTLOGDEST_DEBUGGER) + { + if (cchPreamble) + RTLogWriteDebugger(pszPreamble, cchPreamble); + if (cchFirst) + RTLogWriteDebugger(pszFirst, cchFirst); + if (cchSecond) + RTLogWriteDebugger(pszSecond, cchSecond); + } + +# ifdef IN_RING3 + if (pLogger->fDestFlags & RTLOGDEST_FILE) + { + if (pLogger->pInt->hFile != NIL_RTFILE) + { + if (cchPreamble) + RTFileWrite(pLogger->pInt->hFile, pszPreamble, cchPreamble, NULL); + if (cchFirst) + RTFileWrite(pLogger->pInt->hFile, pszFirst, cchFirst, NULL); + if (cchSecond) + RTFileWrite(pLogger->pInt->hFile, pszSecond, cchSecond, NULL); + if (pLogger->fFlags & RTLOGFLAGS_FLUSH) + RTFileFlush(pLogger->pInt->hFile); + } + if (pLogger->pInt->cHistory) + pLogger->pInt->cbHistoryFileWritten += cchFirst + cchSecond; + } +# endif + + if (pLogger->fDestFlags & RTLOGDEST_STDOUT) + { + if (cchPreamble) + RTLogWriteStdOut(pszPreamble, cchPreamble); + if (cchFirst) + RTLogWriteStdOut(pszFirst, cchFirst); + if (cchSecond) + RTLogWriteStdOut(pszSecond, cchSecond); + } + + if (pLogger->fDestFlags & RTLOGDEST_STDERR) + { + if (cchPreamble) + RTLogWriteStdErr(pszPreamble, cchPreamble); + if (cchFirst) + RTLogWriteStdErr(pszFirst, cchFirst); + if (cchSecond) + RTLogWriteStdErr(pszSecond, cchSecond); + } + +# if defined(IN_RING0) && !defined(LOG_NO_COM) + if (pLogger->fDestFlags & RTLOGDEST_COM) + { + if (cchPreamble) + RTLogWriteCom(pszPreamble, cchPreamble); + if (cchFirst) + RTLogWriteCom(pszFirst, cchFirst); + if (cchSecond) + RTLogWriteCom(pszSecond, cchSecond); + } +# endif +} + + +RTDECL(int) RTLogCreateExV(PRTLOGGER *ppLogger, uint32_t fFlags, const char *pszGroupSettings, const char *pszEnvVarBase, + unsigned cGroups, const char * const *papszGroups, uint32_t cMaxEntriesPerGroup, + uint32_t fDestFlags, PFNRTLOGPHASE pfnPhase, uint32_t cHistory, + uint64_t cbHistoryFileMax, uint32_t cSecsHistoryTimeSlot, + PRTERRINFO pErrInfo, const char *pszFilenameFmt, va_list args) +{ + int rc; + size_t offInternal; + size_t cbLogger; + PRTLOGGER pLogger; + + /* + * Validate input. + */ + if ( (cGroups && !papszGroups) + || !VALID_PTR(ppLogger) ) + { + AssertMsgFailed(("Invalid parameters!\n")); + return VERR_INVALID_PARAMETER; + } + *ppLogger = NULL; + + AssertMsgReturn(cHistory < _1M, ("%#x", cHistory), VERR_OUT_OF_RANGE); + + /* + * Allocate a logger instance. + */ + offInternal = RT_UOFFSETOF_DYN(RTLOGGER, afGroups[cGroups]); + offInternal = RT_ALIGN_Z(offInternal, sizeof(uint64_t)); + cbLogger = offInternal + sizeof(RTLOGGERINTERNAL); + if (fFlags & RTLOGFLAGS_RESTRICT_GROUPS) + cbLogger += cGroups * sizeof(uint32_t); + pLogger = (PRTLOGGER)RTMemAllocZVarTag(cbLogger, "may-leak:log-instance"); + if (pLogger) + { +# if defined(RT_ARCH_X86) && (!defined(LOG_USE_C99) || !defined(RT_WITHOUT_EXEC_ALLOC)) + uint8_t *pu8Code; +# endif + pLogger->u32Magic = RTLOGGER_MAGIC; + pLogger->cGroups = cGroups; + pLogger->fFlags = fFlags; + pLogger->fDestFlags = fDestFlags; + pLogger->pInt = (PRTLOGGERINTERNAL)((uintptr_t)pLogger + offInternal); + pLogger->pInt->uRevision = RTLOGGERINTERNAL_REV; + pLogger->pInt->cbSelf = sizeof(RTLOGGERINTERNAL); + pLogger->pInt->hSpinMtx = NIL_RTSEMSPINMUTEX; + pLogger->pInt->pfnFlush = NULL; + pLogger->pInt->pfnPrefix = NULL; + pLogger->pInt->pvPrefixUserArg = NULL; + pLogger->pInt->fPendingPrefix = true; + pLogger->pInt->fCreated = false; + pLogger->pInt->nsR0ProgramStart = 0; + RT_ZERO(pLogger->pInt->szR0ThreadName); + pLogger->pInt->cMaxGroups = cGroups; + pLogger->pInt->papszGroups = papszGroups; + if (fFlags & RTLOGFLAGS_RESTRICT_GROUPS) + pLogger->pInt->pacEntriesPerGroup = (uint32_t *)(pLogger->pInt + 1); + else + pLogger->pInt->pacEntriesPerGroup = NULL; + pLogger->pInt->cMaxEntriesPerGroup = cMaxEntriesPerGroup ? cMaxEntriesPerGroup : UINT32_MAX; +# ifdef IN_RING3 + pLogger->pInt->pfnPhase = pfnPhase; + pLogger->pInt->hFile = NIL_RTFILE; + pLogger->pInt->cHistory = cHistory; + if (cbHistoryFileMax == 0) + pLogger->pInt->cbHistoryFileMax = UINT64_MAX; + else + pLogger->pInt->cbHistoryFileMax = cbHistoryFileMax; + if (cSecsHistoryTimeSlot == 0) + pLogger->pInt->cSecsHistoryTimeSlot = UINT32_MAX; + else + pLogger->pInt->cSecsHistoryTimeSlot = cSecsHistoryTimeSlot; +# else /* !IN_RING3 */ + RT_NOREF_PV(pfnPhase); RT_NOREF_PV(cHistory); RT_NOREF_PV(cbHistoryFileMax); RT_NOREF_PV(cSecsHistoryTimeSlot); +# endif /* !IN_RING3 */ + if (pszGroupSettings) + RTLogGroupSettings(pLogger, pszGroupSettings); + +# if defined(RT_ARCH_X86) && (!defined(LOG_USE_C99) || !defined(RT_WITHOUT_EXEC_ALLOC)) + /* + * Emit wrapper code. + */ + pu8Code = (uint8_t *)RTMemExecAlloc(64); + if (pu8Code) + { + pLogger->pfnLogger = *(PFNRTLOGGER*)&pu8Code; + *pu8Code++ = 0x68; /* push imm32 */ + *(void **)pu8Code = pLogger; + pu8Code += sizeof(void *); + *pu8Code++ = 0xe8; /* call rel32 */ + *(uint32_t *)pu8Code = (uintptr_t)RTLogLogger - ((uintptr_t)pu8Code + sizeof(uint32_t)); + pu8Code += sizeof(uint32_t); + *pu8Code++ = 0x8d; /* lea esp, [esp + 4] */ + *pu8Code++ = 0x64; + *pu8Code++ = 0x24; + *pu8Code++ = 0x04; + *pu8Code++ = 0xc3; /* ret near */ + AssertMsg((uintptr_t)pu8Code - (uintptr_t)pLogger->pfnLogger <= 64, + ("Wrapper assembly is too big! %d bytes\n", (uintptr_t)pu8Code - (uintptr_t)pLogger->pfnLogger)); + rc = VINF_SUCCESS; + } + else + { + rc = VERR_NO_MEMORY; +# ifdef RT_OS_LINUX + /* Most probably SELinux causing trouble since the larger RTMemAlloc succeeded. */ + RTErrInfoSet(pErrInfo, rc, N_("mmap(PROT_WRITE | PROT_EXEC) failed -- SELinux?")); +# endif + } + if (RT_SUCCESS(rc)) +# endif /* X86 wrapper code*/ + { +# ifdef IN_RING3 /* files and env.vars. are only accessible when in R3 at the present time. */ + /* + * Format the filename. + */ + if (pszFilenameFmt) + { + /** @todo validate the length, fail on overflow. */ + RTStrPrintfV(pLogger->pInt->szFilename, sizeof(pLogger->pInt->szFilename), pszFilenameFmt, args); + if (pLogger->pInt->szFilename[0]) + pLogger->fDestFlags |= RTLOGDEST_FILE; + } + + /* + * Parse the environment variables. + */ + if (pszEnvVarBase) + { + /* make temp copy of environment variable base. */ + size_t cchEnvVarBase = strlen(pszEnvVarBase); + char *pszEnvVar = (char *)alloca(cchEnvVarBase + 16); + memcpy(pszEnvVar, pszEnvVarBase, cchEnvVarBase); + + /* + * Destination. + */ + strcpy(pszEnvVar + cchEnvVarBase, "_DEST"); + const char *pszValue = RTEnvGet(pszEnvVar); + if (pszValue) + RTLogDestinations(pLogger, pszValue); + + /* + * The flags. + */ + strcpy(pszEnvVar + cchEnvVarBase, "_FLAGS"); + pszValue = RTEnvGet(pszEnvVar); + if (pszValue) + RTLogFlags(pLogger, pszValue); + + /* + * The group settings. + */ + pszEnvVar[cchEnvVarBase] = '\0'; + pszValue = RTEnvGet(pszEnvVar); + if (pszValue) + RTLogGroupSettings(pLogger, pszValue); + + /* + * Group limit. + */ + strcpy(pszEnvVar + cchEnvVarBase, "_MAX_PER_GROUP"); + pszValue = RTEnvGet(pszEnvVar); + if (pszValue) + { + uint32_t cMax; + rc = RTStrToUInt32Full(pszValue, 0, &cMax); + if (RT_SUCCESS(rc)) + pLogger->pInt->cMaxEntriesPerGroup = cMax ? cMax : UINT32_MAX; + else + AssertMsgFailed(("Invalid group limit! %s=%s\n", pszEnvVar, pszValue)); + } + + } +# else /* !IN_RING3 */ + RT_NOREF_PV(pszEnvVarBase); RT_NOREF_PV(pszFilenameFmt); RT_NOREF_PV(args); +# endif /* !IN_RING3 */ + + /* + * Open the destination(s). + */ + rc = VINF_SUCCESS; + if ((pLogger->fDestFlags & (RTLOGDEST_F_DELAY_FILE | RTLOGDEST_FILE)) == RTLOGDEST_F_DELAY_FILE) + pLogger->fDestFlags &= ~RTLOGDEST_F_DELAY_FILE; +# ifdef IN_RING3 + if ((pLogger->fDestFlags & (RTLOGDEST_FILE | RTLOGDEST_F_DELAY_FILE)) == RTLOGDEST_FILE) + rc = rtR3LogOpenFileDestination(pLogger, pErrInfo); +# endif + + if ((pLogger->fDestFlags & RTLOGDEST_RINGBUF) && RT_SUCCESS(rc)) + rc = rtLogRingBufAdjust(pLogger, pLogger->pInt->cbRingBuf, true /*fForce*/); + + /* + * Create mutex and check how much it counts when entering the lock + * so that we can report the values for RTLOGFLAGS_PREFIX_LOCK_COUNTS. + */ + if (RT_SUCCESS(rc)) + { + rc = RTSemSpinMutexCreate(&pLogger->pInt->hSpinMtx, RTSEMSPINMUTEX_FLAGS_IRQ_SAFE); + if (RT_SUCCESS(rc)) + { +# ifdef IN_RING3 /** @todo do counters in ring-0 too? */ + RTTHREAD Thread = RTThreadSelf(); + if (Thread != NIL_RTTHREAD) + { + int32_t c = RTLockValidatorWriteLockGetCount(Thread); + RTSemSpinMutexRequest(pLogger->pInt->hSpinMtx); + c = RTLockValidatorWriteLockGetCount(Thread) - c; + RTSemSpinMutexRelease(pLogger->pInt->hSpinMtx); + ASMAtomicWriteU32(&g_cLoggerLockCount, c); + } + + /* Use the callback to generate some initial log contents. */ + Assert(VALID_PTR(pLogger->pInt->pfnPhase) || pLogger->pInt->pfnPhase == NULL); + if (pLogger->pInt->pfnPhase) + pLogger->pInt->pfnPhase(pLogger, RTLOGPHASE_BEGIN, rtlogPhaseMsgNormal); +# endif + pLogger->pInt->fCreated = true; + *ppLogger = pLogger; + return VINF_SUCCESS; + } + + RTErrInfoSet(pErrInfo, rc, N_("failed to create semaphore")); + } +# ifdef IN_RING3 + RTFileClose(pLogger->pInt->hFile); +# endif +# if defined(LOG_USE_C99) && defined(RT_WITHOUT_EXEC_ALLOC) + RTMemFree(*(void **)&pLogger->pfnLogger); +# else + RTMemExecFree(*(void **)&pLogger->pfnLogger, 64); +# endif + } + RTMemFree(pLogger); + } + else + rc = VERR_NO_MEMORY; + + return rc; +} +RT_EXPORT_SYMBOL(RTLogCreateExV); + + +RTDECL(int) RTLogCreate(PRTLOGGER *ppLogger, uint32_t fFlags, const char *pszGroupSettings, + const char *pszEnvVarBase, unsigned cGroups, const char * const * papszGroups, + uint32_t fDestFlags, const char *pszFilenameFmt, ...) +{ + va_list args; + int rc; + + va_start(args, pszFilenameFmt); + rc = RTLogCreateExV(ppLogger, fFlags, pszGroupSettings, pszEnvVarBase, + cGroups, papszGroups, UINT32_MAX /*cMaxEntriesPerGroup*/, fDestFlags, + NULL /*pfnPhase*/, 0 /*cHistory*/, 0 /*cbHistoryFileMax*/, 0 /*cSecsHistoryTimeSlot*/, + NULL /*pErrInfo*/, pszFilenameFmt, args); + va_end(args); + return rc; +} +RT_EXPORT_SYMBOL(RTLogCreate); + + +RTDECL(int) RTLogCreateEx(PRTLOGGER *ppLogger, uint32_t fFlags, const char *pszGroupSettings, const char *pszEnvVarBase, + unsigned cGroups, const char * const *papszGroups, uint32_t cMaxEntriesPerGroup, + uint32_t fDestFlags, PFNRTLOGPHASE pfnPhase, uint32_t cHistory, + uint64_t cbHistoryFileMax, uint32_t cSecsHistoryTimeSlot, + PRTERRINFO pErrInfo, const char *pszFilenameFmt, ...) +{ + va_list args; + int rc; + + va_start(args, pszFilenameFmt); + rc = RTLogCreateExV(ppLogger, fFlags, pszGroupSettings, pszEnvVarBase, cGroups, papszGroups, cMaxEntriesPerGroup, + fDestFlags, pfnPhase, cHistory, cbHistoryFileMax, cSecsHistoryTimeSlot, + pErrInfo, pszFilenameFmt, args); + va_end(args); + return rc; +} +RT_EXPORT_SYMBOL(RTLogCreateEx); + + +/** + * Destroys a logger instance. + * + * The instance is flushed and all output destinations closed (where applicable). + * + * @returns iprt status code. + * @param pLogger The logger instance which close destroyed. NULL is fine. + */ +RTDECL(int) RTLogDestroy(PRTLOGGER pLogger) +{ + int rc; + uint32_t iGroup; + RTSEMSPINMUTEX hSpinMtx; + + /* + * Validate input. + */ + if (!pLogger) + return VINF_SUCCESS; + AssertPtrReturn(pLogger, VERR_INVALID_POINTER); + AssertReturn(pLogger->u32Magic == RTLOGGER_MAGIC, VERR_INVALID_MAGIC); + AssertPtrReturn(pLogger->pInt, VERR_INVALID_POINTER); + + /* + * Acquire logger instance sem and disable all logging. (paranoia) + */ + rc = rtlogLock(pLogger); + AssertMsgRCReturn(rc, ("%Rrc\n", rc), rc); + + pLogger->fFlags |= RTLOGFLAGS_DISABLED; + iGroup = pLogger->cGroups; + while (iGroup-- > 0) + pLogger->afGroups[iGroup] = 0; + + /* + * Flush it. + */ + rtlogFlush(pLogger, false /*fNeedSpace*/); + +# ifdef IN_RING3 + /* + * Add end of logging message. + */ + if ( (pLogger->fDestFlags & RTLOGDEST_FILE) + && pLogger->pInt->hFile != NIL_RTFILE) + pLogger->pInt->pfnPhase(pLogger, RTLOGPHASE_END, rtlogPhaseMsgLocked); + + /* + * Close output stuffs. + */ + if (pLogger->pInt->hFile != NIL_RTFILE) + { + int rc2 = RTFileClose(pLogger->pInt->hFile); + AssertRC(rc2); + if (RT_FAILURE(rc2) && RT_SUCCESS(rc)) + rc = rc2; + pLogger->pInt->hFile = NIL_RTFILE; + } +# endif + + /* + * Free the mutex, the wrapper and the instance memory. + */ + hSpinMtx = pLogger->pInt->hSpinMtx; + pLogger->pInt->hSpinMtx = NIL_RTSEMSPINMUTEX; + if (hSpinMtx != NIL_RTSEMSPINMUTEX) + { + int rc2; + RTSemSpinMutexRelease(hSpinMtx); + rc2 = RTSemSpinMutexDestroy(hSpinMtx); + AssertRC(rc2); + if (RT_FAILURE(rc2) && RT_SUCCESS(rc)) + rc = rc2; + } + + if (pLogger->pfnLogger) + { +# if defined(LOG_USE_C99) && defined(RT_WITHOUT_EXEC_ALLOC) + RTMemFree(*(void **)&pLogger->pfnLogger); +# else + RTMemExecFree(*(void **)&pLogger->pfnLogger, 64); +# endif + pLogger->pfnLogger = NULL; + } + RTMemFree(pLogger); + + return rc; +} +RT_EXPORT_SYMBOL(RTLogDestroy); + + +/** + * Create a logger instance clone for RC usage. + * + * @returns iprt status code. + * + * @param pLogger The logger instance to be cloned. + * @param pLoggerRC Where to create the RC logger instance. + * @param cbLoggerRC Amount of memory allocated to for the RC logger + * instance clone. + * @param pfnLoggerRCPtr Pointer to logger wrapper function for this + * instance (RC Ptr). + * @param pfnFlushRCPtr Pointer to flush function (RC Ptr). + * @param fFlags Logger instance flags, a combination of the RTLOGFLAGS_* values. + */ +RTDECL(int) RTLogCloneRC(PRTLOGGER pLogger, PRTLOGGERRC pLoggerRC, size_t cbLoggerRC, + RTRCPTR pfnLoggerRCPtr, RTRCPTR pfnFlushRCPtr, uint32_t fFlags) +{ + /* + * Validate input. + */ + if ( !pLoggerRC + || !pfnFlushRCPtr + || !pfnLoggerRCPtr) + { + AssertMsgFailed(("Invalid parameters!\n")); + return VERR_INVALID_PARAMETER; + } + if (cbLoggerRC < sizeof(*pLoggerRC)) + { + AssertMsgFailed(("%d min=%d\n", cbLoggerRC, sizeof(*pLoggerRC))); + return VERR_INVALID_PARAMETER; + } + + /* + * Initialize GC instance. + */ + pLoggerRC->offScratch = 0; + pLoggerRC->fPendingPrefix = false; + pLoggerRC->pfnLogger = pfnLoggerRCPtr; + pLoggerRC->pfnFlush = pfnFlushRCPtr; + pLoggerRC->u32Magic = RTLOGGERRC_MAGIC; + pLoggerRC->fFlags = fFlags | RTLOGFLAGS_DISABLED; + pLoggerRC->cGroups = 1; + pLoggerRC->afGroups[0] = 0; + + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + return VINF_SUCCESS; + } + + /* + * Check if there's enough space for the groups. + */ + if (cbLoggerRC < (size_t)RT_UOFFSETOF_DYN(RTLOGGERRC, afGroups[pLogger->cGroups])) + { + AssertMsgFailed(("%zu req=%zu cGroups=%d\n", cbLoggerRC, RT_UOFFSETOF_DYN(RTLOGGERRC, afGroups[pLogger->cGroups]), pLogger->cGroups)); + return VERR_BUFFER_OVERFLOW; + } + memcpy(&pLoggerRC->afGroups[0], &pLogger->afGroups[0], pLogger->cGroups * sizeof(pLoggerRC->afGroups[0])); + pLoggerRC->cGroups = pLogger->cGroups; + + /* + * Copy bits from the HC instance. + */ + pLoggerRC->fPendingPrefix = pLogger->pInt->fPendingPrefix; + pLoggerRC->fFlags |= pLogger->fFlags; + + /* + * Check if we can remove the disabled flag. + */ + if ( pLogger->fDestFlags + && !((pLogger->fFlags | fFlags) & RTLOGFLAGS_DISABLED)) + pLoggerRC->fFlags &= ~RTLOGFLAGS_DISABLED; + + return VINF_SUCCESS; +} +RT_EXPORT_SYMBOL(RTLogCloneRC); + + +/** + * Flushes a RC logger instance to a R3 logger. + * + * + * @returns iprt status code. + * @param pLogger The R3 logger instance to flush pLoggerRC to. If NULL + * the default logger is used. + * @param pLoggerRC The RC logger instance to flush. + */ +RTDECL(void) RTLogFlushRC(PRTLOGGER pLogger, PRTLOGGERRC pLoggerRC) +{ + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + { + pLoggerRC->offScratch = 0; + return; + } + } + + /* + * Any thing to flush? + */ + if ( pLogger->offScratch + || pLoggerRC->offScratch) + { + /* + * Acquire logger instance sem. + */ + int rc = rtlogLock(pLogger); + if (RT_FAILURE(rc)) + return; + + /* + * Write whatever the GC instance contains to the HC one, and then + * flush the HC instance. + */ + if (pLoggerRC->offScratch) + { + rtLogOutput(pLogger, pLoggerRC->achScratch, pLoggerRC->offScratch); + rtLogOutput(pLogger, NULL, 0); + pLoggerRC->offScratch = 0; + } + + /* + * Release the semaphore. + */ + rtlogUnlock(pLogger); + } +} +RT_EXPORT_SYMBOL(RTLogFlushRC); + +# ifdef IN_RING3 + +RTDECL(int) RTLogCreateForR0(PRTLOGGER pLogger, size_t cbLogger, + RTR0PTR pLoggerR0Ptr, RTR0PTR pfnLoggerR0Ptr, RTR0PTR pfnFlushR0Ptr, + uint32_t fFlags, uint32_t fDestFlags, char const *pszThreadName) +{ + /* + * Validate input. + */ + AssertPtrReturn(pLogger, VERR_INVALID_PARAMETER); + size_t const cbRequired = sizeof(*pLogger) + RTLOGGERINTERNAL_R0_SIZE; + AssertReturn(cbLogger >= cbRequired, VERR_BUFFER_OVERFLOW); + AssertReturn(pLoggerR0Ptr != NIL_RTR0PTR, VERR_INVALID_PARAMETER); + AssertReturn(pfnLoggerR0Ptr != NIL_RTR0PTR, VERR_INVALID_PARAMETER); + size_t const cchThreadName = pszThreadName ? strlen(pszThreadName) : 0; + AssertReturn(cchThreadName < sizeof(pLogger->pInt->szR0ThreadName), VERR_INVALID_NAME); + + /* + * Initialize the ring-0 instance. + */ + pLogger->achScratch[0] = 0; + pLogger->offScratch = 0; + pLogger->pfnLogger = (PFNRTLOGGER)pfnLoggerR0Ptr; + pLogger->fFlags = fFlags; + pLogger->fDestFlags = fDestFlags & ~RTLOGDEST_FILE; + pLogger->pInt = NULL; + pLogger->cGroups = 1; + pLogger->afGroups[0] = 0; + + uint32_t cMaxGroups = (uint32_t)((cbLogger - cbRequired) / sizeof(pLogger->afGroups[0])); + if (fFlags & RTLOGFLAGS_RESTRICT_GROUPS) + cMaxGroups /= 2; + PRTLOGGERINTERNAL pInt; + for (;;) + { + AssertReturn(cMaxGroups > 0, VERR_BUFFER_OVERFLOW); + pInt = (PRTLOGGERINTERNAL)&pLogger->afGroups[cMaxGroups]; + if (!((uintptr_t)pInt & (sizeof(uint64_t) - 1))) + break; + cMaxGroups--; + } + pLogger->pInt = (PRTLOGGERINTERNAL)(pLoggerR0Ptr + (uintptr_t)pInt - (uintptr_t)pLogger); + pInt->uRevision = RTLOGGERINTERNAL_REV; + pInt->cbSelf = RTLOGGERINTERNAL_R0_SIZE; + pInt->hSpinMtx = NIL_RTSEMSPINMUTEX; /* Not serialized. */ + pInt->pfnFlush = (PFNRTLOGFLUSH)pfnFlushR0Ptr; + pInt->pfnPrefix = NULL; + pInt->pvPrefixUserArg = NULL; + pInt->fPendingPrefix = true; + pInt->cMaxGroups = cMaxGroups; + pInt->papszGroups = NULL; + pInt->cMaxEntriesPerGroup = UINT32_MAX; + if (fFlags & RTLOGFLAGS_RESTRICT_GROUPS) + { + memset(pInt + 1, 0, sizeof(uint32_t) * cMaxGroups); + pInt->pacEntriesPerGroup= (uint32_t *)(pLogger->pInt + 1); + } + else + pInt->pacEntriesPerGroup= NULL; + pInt->nsR0ProgramStart = RTTimeProgramStartNanoTS(); + RT_ZERO(pInt->szR0ThreadName); + if (cchThreadName) + memcpy(pInt->szR0ThreadName, pszThreadName, cchThreadName); + + pInt->fCreated = true; + pLogger->u32Magic = RTLOGGER_MAGIC; + return VINF_SUCCESS; +} +RT_EXPORT_SYMBOL(RTLogCreateForR0); + + +RTDECL(size_t) RTLogCalcSizeForR0(uint32_t cGroups, uint32_t fFlags) +{ + size_t cb = RT_UOFFSETOF_DYN(RTLOGGER, afGroups[cGroups]); + cb = RT_ALIGN_Z(cb, sizeof(uint64_t)); + cb += sizeof(RTLOGGERINTERNAL); + if (fFlags & RTLOGFLAGS_RESTRICT_GROUPS) + cb += sizeof(uint32_t) * cGroups; + return cb; +} +RT_EXPORT_SYMBOL(RTLogCalcSizeForR0); + + +RTDECL(int) RTLogCopyGroupsAndFlagsForR0(PRTLOGGER pDstLogger, RTR0PTR pDstLoggerR0Ptr, + PCRTLOGGER pSrcLogger, uint32_t fFlagsOr, uint32_t fFlagsAnd) +{ + /* + * Validate input. + */ + AssertPtrReturn(pDstLogger, VERR_INVALID_PARAMETER); + AssertPtrNullReturn(pSrcLogger, VERR_INVALID_PARAMETER); + + /* + * Resolve defaults. + */ + if (!pSrcLogger) + { + pSrcLogger = RTLogDefaultInstance(); + if (!pSrcLogger) + { + pDstLogger->fFlags |= RTLOGFLAGS_DISABLED | fFlagsOr; + pDstLogger->cGroups = 1; + pDstLogger->afGroups[0] = 0; + return VINF_SUCCESS; + } + } + + /* + * Copy flags and group settings. + */ + pDstLogger->fFlags = (pSrcLogger->fFlags & fFlagsAnd & ~RTLOGFLAGS_RESTRICT_GROUPS) | fFlagsOr; + + PRTLOGGERINTERNAL pDstInt = (PRTLOGGERINTERNAL)((uintptr_t)pDstLogger->pInt - pDstLoggerR0Ptr + (uintptr_t)pDstLogger); + int rc = VINF_SUCCESS; + uint32_t cGroups = pSrcLogger->cGroups; + if (cGroups > pDstInt->cMaxGroups) + { + AssertMsgFailed(("cMaxGroups=%zd cGroups=%zd (min size %d)\n", pDstInt->cMaxGroups, + pSrcLogger->cGroups, RT_UOFFSETOF_DYN(RTLOGGER, afGroups[pSrcLogger->cGroups]) + RTLOGGERINTERNAL_R0_SIZE)); + rc = VERR_INVALID_PARAMETER; + cGroups = pDstInt->cMaxGroups; + } + memcpy(&pDstLogger->afGroups[0], &pSrcLogger->afGroups[0], cGroups * sizeof(pDstLogger->afGroups[0])); + pDstLogger->cGroups = cGroups; + + return rc; +} +RT_EXPORT_SYMBOL(RTLogCopyGroupsAndFlagsForR0); + + +RTDECL(void) RTLogFlushR0(PRTLOGGER pLogger, PRTLOGGER pLoggerR0) +{ + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + { + /* flushing to "/dev/null". */ + if (pLoggerR0->offScratch) + pLoggerR0->offScratch = 0; + return; + } + } + + /* + * Anything to flush? + */ + if ( pLoggerR0->offScratch + || pLogger->offScratch) + { + /* + * Acquire logger semaphores. + */ + int rc = rtlogLock(pLogger); + if (RT_FAILURE(rc)) + return; + if (RT_SUCCESS(rc)) + { + /* + * Write whatever the GC instance contains to the HC one, and then + * flush the HC instance. + */ + if (pLoggerR0->offScratch) + { + rtLogOutput(pLogger, pLoggerR0->achScratch, pLoggerR0->offScratch); + rtLogOutput(pLogger, NULL, 0); + pLoggerR0->offScratch = 0; + } + } + rtlogUnlock(pLogger); + } +} +RT_EXPORT_SYMBOL(RTLogFlushR0); + +# endif /* IN_RING3 */ + + +/** + * Flushes the buffer in one logger instance onto another logger. + * + * @returns iprt status code. + * + * @param pSrcLogger The logger instance to flush. + * @param pDstLogger The logger instance to flush onto. + * If NULL the default logger will be used. + */ +RTDECL(void) RTLogFlushToLogger(PRTLOGGER pSrcLogger, PRTLOGGER pDstLogger) +{ + /* + * Resolve defaults. + */ + if (!pDstLogger) + { + pDstLogger = RTLogDefaultInstance(); + if (!pDstLogger) + { + /* flushing to "/dev/null". */ + if (pSrcLogger->offScratch) + { + int rc = rtlogLock(pSrcLogger); + if (RT_SUCCESS(rc)) + { + pSrcLogger->offScratch = 0; + rtlogUnlock(pSrcLogger); + } + } + return; + } + } + + /* + * Any thing to flush? + */ + if ( pSrcLogger->offScratch + || pDstLogger->offScratch) + { + /* + * Acquire logger semaphores. + */ + int rc = rtlogLock(pDstLogger); + if (RT_FAILURE(rc)) + return; + rc = rtlogLock(pSrcLogger); + if (RT_SUCCESS(rc)) + { + /* + * Write whatever the GC instance contains to the HC one, and then + * flush the HC instance. + */ + if (pSrcLogger->offScratch) + { + rtLogOutput(pDstLogger, pSrcLogger->achScratch, pSrcLogger->offScratch); + rtLogOutput(pDstLogger, NULL, 0); + pSrcLogger->offScratch = 0; + } + + /* + * Release the semaphores. + */ + rtlogUnlock(pSrcLogger); + } + rtlogUnlock(pDstLogger); + } +} +RT_EXPORT_SYMBOL(RTLogFlushToLogger); + + +/** + * Sets the custom prefix callback. + * + * @returns IPRT status code. + * @param pLogger The logger instance. + * @param pfnCallback The callback. + * @param pvUser The user argument for the callback. + * */ +RTDECL(int) RTLogSetCustomPrefixCallback(PRTLOGGER pLogger, PFNRTLOGPREFIX pfnCallback, void *pvUser) +{ + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + return VINF_SUCCESS; + } + AssertReturn(pLogger->u32Magic == RTLOGGER_MAGIC, VERR_INVALID_MAGIC); + + /* + * Do the work. + */ + rtlogLock(pLogger); + pLogger->pInt->pvPrefixUserArg = pvUser; + pLogger->pInt->pfnPrefix = pfnCallback; + rtlogUnlock(pLogger); + + return VINF_SUCCESS; +} +RT_EXPORT_SYMBOL(RTLogSetCustomPrefixCallback); + + +/** + * Matches a group name with a pattern mask in an case insensitive manner (ASCII). + * + * @returns true if matching and *ppachMask set to the end of the pattern. + * @returns false if no match. + * @param pszGrp The group name. + * @param ppachMask Pointer to the pointer to the mask. Only wildcard supported is '*'. + * @param cchMask The length of the mask, including modifiers. The modifiers is why + * we update *ppachMask on match. + */ +static bool rtlogIsGroupMatching(const char *pszGrp, const char **ppachMask, size_t cchMask) +{ + const char *pachMask; + + if (!pszGrp || !*pszGrp) + return false; + pachMask = *ppachMask; + for (;;) + { + if (RT_C_TO_LOWER(*pszGrp) != RT_C_TO_LOWER(*pachMask)) + { + const char *pszTmp; + + /* + * Check for wildcard and do a minimal match if found. + */ + if (*pachMask != '*') + return false; + + /* eat '*'s. */ + do pachMask++; + while (--cchMask && *pachMask == '*'); + + /* is there more to match? */ + if ( !cchMask + || *pachMask == '.' + || *pachMask == '=') + break; /* we're good */ + + /* do extremely minimal matching (fixme) */ + pszTmp = strchr(pszGrp, RT_C_TO_LOWER(*pachMask)); + if (!pszTmp) + pszTmp = strchr(pszGrp, RT_C_TO_UPPER(*pachMask)); + if (!pszTmp) + return false; + pszGrp = pszTmp; + continue; + } + + /* done? */ + if (!*++pszGrp) + { + /* trailing wildcard is ok. */ + do + { + pachMask++; + cchMask--; + } while (cchMask && *pachMask == '*'); + if ( !cchMask + || *pachMask == '.' + || *pachMask == '=') + break; /* we're good */ + return false; + } + + if (!--cchMask) + return false; + pachMask++; + } + + /* match */ + *ppachMask = pachMask; + return true; +} + + +/** + * Updates the group settings for the logger instance using the specified + * specification string. + * + * @returns iprt status code. + * Failures can safely be ignored. + * @param pLogger Logger instance. + * @param pszValue Value to parse. + */ +RTDECL(int) RTLogGroupSettings(PRTLOGGER pLogger, const char *pszValue) +{ + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + return VINF_SUCCESS; + } + + /* + * Iterate the string. + */ + while (*pszValue) + { + /* + * Skip prefixes (blanks, ;, + and -). + */ + bool fEnabled = true; + char ch; + const char *pszStart; + unsigned i; + size_t cch; + + while ((ch = *pszValue) == '+' || ch == '-' || ch == ' ' || ch == '\t' || ch == '\n' || ch == ';') + { + if (ch == '+' || ch == '-' || ch == ';') + fEnabled = ch != '-'; + pszValue++; + } + if (!*pszValue) + break; + + /* + * Find end. + */ + pszStart = pszValue; + while ((ch = *pszValue) != '\0' && ch != '+' && ch != '-' && ch != ' ' && ch != '\t') + pszValue++; + + /* + * Find the group (ascii case insensitive search). + * Special group 'all'. + */ + cch = pszValue - pszStart; + if ( cch >= 3 + && (pszStart[0] == 'a' || pszStart[0] == 'A') + && (pszStart[1] == 'l' || pszStart[1] == 'L') + && (pszStart[2] == 'l' || pszStart[2] == 'L') + && (cch == 3 || pszStart[3] == '.' || pszStart[3] == '=')) + { + /* + * All. + */ + unsigned fFlags = cch == 3 + ? RTLOGGRPFLAGS_ENABLED | RTLOGGRPFLAGS_LEVEL_1 + : rtlogGroupFlags(&pszStart[3]); + for (i = 0; i < pLogger->cGroups; i++) + { + if (fEnabled) + pLogger->afGroups[i] |= fFlags; + else + pLogger->afGroups[i] &= ~fFlags; + } + } + else + { + /* + * Specific group(s). + */ + for (i = 0; i < pLogger->cGroups; i++) + { + const char *psz2 = (const char*)pszStart; + if (rtlogIsGroupMatching(pLogger->pInt->papszGroups[i], &psz2, cch)) + { + unsigned fFlags = RTLOGGRPFLAGS_ENABLED | RTLOGGRPFLAGS_LEVEL_1; + if (*psz2 == '.' || *psz2 == '=') + fFlags = rtlogGroupFlags(psz2); + if (fEnabled) + pLogger->afGroups[i] |= fFlags; + else + pLogger->afGroups[i] &= ~fFlags; + } + } /* for each group */ + } + + } /* parse specification */ + + return VINF_SUCCESS; +} +RT_EXPORT_SYMBOL(RTLogGroupSettings); + + +/** + * Interprets the group flags suffix. + * + * @returns Flags specified. (0 is possible!) + * @param psz Start of Suffix. (Either dot or equal sign.) + */ +static unsigned rtlogGroupFlags(const char *psz) +{ + unsigned fFlags = 0; + + /* + * Literal flags. + */ + while (*psz == '.') + { + static struct + { + const char *pszFlag; /* lowercase!! */ + unsigned fFlag; + } aFlags[] = + { + { "eo", RTLOGGRPFLAGS_ENABLED }, + { "enabledonly",RTLOGGRPFLAGS_ENABLED }, + { "e", RTLOGGRPFLAGS_ENABLED | RTLOGGRPFLAGS_LEVEL_1 | RTLOGGRPFLAGS_WARN }, + { "enabled", RTLOGGRPFLAGS_ENABLED | RTLOGGRPFLAGS_LEVEL_1 | RTLOGGRPFLAGS_WARN }, + { "l1", RTLOGGRPFLAGS_LEVEL_1 }, + { "level1", RTLOGGRPFLAGS_LEVEL_1 }, + { "l", RTLOGGRPFLAGS_LEVEL_2 }, + { "l2", RTLOGGRPFLAGS_LEVEL_2 }, + { "level2", RTLOGGRPFLAGS_LEVEL_2 }, + { "l3", RTLOGGRPFLAGS_LEVEL_3 }, + { "level3", RTLOGGRPFLAGS_LEVEL_3 }, + { "l4", RTLOGGRPFLAGS_LEVEL_4 }, + { "level4", RTLOGGRPFLAGS_LEVEL_4 }, + { "l5", RTLOGGRPFLAGS_LEVEL_5 }, + { "level5", RTLOGGRPFLAGS_LEVEL_5 }, + { "l6", RTLOGGRPFLAGS_LEVEL_6 }, + { "level6", RTLOGGRPFLAGS_LEVEL_6 }, + { "l7", RTLOGGRPFLAGS_LEVEL_7 }, + { "level7", RTLOGGRPFLAGS_LEVEL_7 }, + { "l8", RTLOGGRPFLAGS_LEVEL_8 }, + { "level8", RTLOGGRPFLAGS_LEVEL_8 }, + { "l9", RTLOGGRPFLAGS_LEVEL_9 }, + { "level9", RTLOGGRPFLAGS_LEVEL_9 }, + { "l10", RTLOGGRPFLAGS_LEVEL_10 }, + { "level10", RTLOGGRPFLAGS_LEVEL_10 }, + { "l11", RTLOGGRPFLAGS_LEVEL_11 }, + { "level11", RTLOGGRPFLAGS_LEVEL_11 }, + { "l12", RTLOGGRPFLAGS_LEVEL_12 }, + { "level12", RTLOGGRPFLAGS_LEVEL_12 }, + { "f", RTLOGGRPFLAGS_FLOW }, + { "flow", RTLOGGRPFLAGS_FLOW }, + { "w", RTLOGGRPFLAGS_WARN }, + { "warn", RTLOGGRPFLAGS_WARN }, + { "warning", RTLOGGRPFLAGS_WARN }, + { "restrict", RTLOGGRPFLAGS_RESTRICT }, + + }; + unsigned i; + bool fFound = false; + psz++; + for (i = 0; i < RT_ELEMENTS(aFlags) && !fFound; i++) + { + const char *psz1 = aFlags[i].pszFlag; + const char *psz2 = psz; + while (*psz1 == RT_C_TO_LOWER(*psz2)) + { + psz1++; + psz2++; + if (!*psz1) + { + if ( (*psz2 >= 'a' && *psz2 <= 'z') + || (*psz2 >= 'A' && *psz2 <= 'Z') + || (*psz2 >= '0' && *psz2 <= '9') ) + break; + fFlags |= aFlags[i].fFlag; + fFound = true; + psz = psz2; + break; + } + } /* strincmp */ + } /* for each flags */ + AssertMsg(fFound, ("%.15s...", psz)); + } + + /* + * Flag value. + */ + if (*psz == '=') + { + psz++; + if (*psz == '~') + fFlags = ~RTStrToInt32(psz + 1); + else + fFlags = RTStrToInt32(psz); + } + + return fFlags; +} + +/** + * Helper for RTLogGetGroupSettings. + */ +static int rtLogGetGroupSettingsAddOne(const char *pszName, uint32_t fGroup, char **ppszBuf, size_t *pcchBuf, bool *pfNotFirst) +{ +# define APPEND_PSZ(psz,cch) do { memcpy(*ppszBuf, (psz), (cch)); *ppszBuf += (cch); *pcchBuf -= (cch); } while (0) +# define APPEND_SZ(sz) APPEND_PSZ(sz, sizeof(sz) - 1) +# define APPEND_CH(ch) do { **ppszBuf = (ch); *ppszBuf += 1; *pcchBuf -= 1; } while (0) + + /* + * Add the name. + */ + size_t cchName = strlen(pszName); + if (cchName + 1 + *pfNotFirst > *pcchBuf) + return VERR_BUFFER_OVERFLOW; + if (*pfNotFirst) + APPEND_CH(' '); + else + *pfNotFirst = true; + APPEND_PSZ(pszName, cchName); + + /* + * Only generate mnemonics for the simple+common bits. + */ + if (fGroup == (RTLOGGRPFLAGS_ENABLED | RTLOGGRPFLAGS_LEVEL_1)) + /* nothing */; + else if ( fGroup == (RTLOGGRPFLAGS_ENABLED | RTLOGGRPFLAGS_LEVEL_1 | RTLOGGRPFLAGS_LEVEL_2 | RTLOGGRPFLAGS_FLOW) + && *pcchBuf >= sizeof(".e.l.f")) + APPEND_SZ(".e.l.f"); + else if ( fGroup == (RTLOGGRPFLAGS_ENABLED | RTLOGGRPFLAGS_LEVEL_1 | RTLOGGRPFLAGS_FLOW) + && *pcchBuf >= sizeof(".e.f")) + APPEND_SZ(".e.f"); + else if (*pcchBuf >= 1 + 10 + 1) + { + size_t cch; + APPEND_CH('='); + cch = RTStrFormatNumber(*ppszBuf, fGroup, 16, 0, 0, RTSTR_F_SPECIAL | RTSTR_F_32BIT); + *ppszBuf += cch; + *pcchBuf -= cch; + } + else + return VERR_BUFFER_OVERFLOW; + +# undef APPEND_PSZ +# undef APPEND_SZ +# undef APPEND_CH + return VINF_SUCCESS; +} + + +/** + * Get the current log group settings as a string. + * + * @returns VINF_SUCCESS or VERR_BUFFER_OVERFLOW. + * @param pLogger Logger instance (NULL for default logger). + * @param pszBuf The output buffer. + * @param cchBuf The size of the output buffer. Must be greater + * than zero. + */ +RTDECL(int) RTLogGetGroupSettings(PRTLOGGER pLogger, char *pszBuf, size_t cchBuf) +{ + bool fNotFirst = false; + int rc = VINF_SUCCESS; + uint32_t cGroups; + uint32_t fGroup; + uint32_t i; + + Assert(cchBuf); + + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + { + *pszBuf = '\0'; + return VINF_SUCCESS; + } + } + + cGroups = pLogger->cGroups; + + /* + * Check if all are the same. + */ + fGroup = pLogger->afGroups[0]; + for (i = 1; i < cGroups; i++) + if (pLogger->afGroups[i] != fGroup) + break; + if (i >= cGroups) + rc = rtLogGetGroupSettingsAddOne("all", fGroup, &pszBuf, &cchBuf, &fNotFirst); + else + { + + /* + * Iterate all the groups and print all that are enabled. + */ + for (i = 0; i < cGroups; i++) + { + fGroup = pLogger->afGroups[i]; + if (fGroup) + { + const char *pszName = pLogger->pInt->papszGroups[i]; + if (pszName) + { + rc = rtLogGetGroupSettingsAddOne(pszName, fGroup, &pszBuf, &cchBuf, &fNotFirst); + if (rc) + break; + } + } + } + } + + *pszBuf = '\0'; + return rc; +} +RT_EXPORT_SYMBOL(RTLogGetGroupSettings); + +#endif /* !IN_RC */ + +/** + * Updates the flags for the logger instance using the specified + * specification string. + * + * @returns iprt status code. + * Failures can safely be ignored. + * @param pLogger Logger instance (NULL for default logger). + * @param pszValue Value to parse. + */ +RTDECL(int) RTLogFlags(PRTLOGGER pLogger, const char *pszValue) +{ + int rc = VINF_SUCCESS; + + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + return VINF_SUCCESS; + } + + /* + * Iterate the string. + */ + while (*pszValue) + { + /* check no prefix. */ + bool fNo = false; + char ch; + unsigned i; + + /* skip blanks. */ + while (RT_C_IS_SPACE(*pszValue)) + pszValue++; + if (!*pszValue) + return rc; + + while ((ch = *pszValue) != '\0') + { + if (ch == 'n' && pszValue[1] == 'o') + { + pszValue += 2; + fNo = !fNo; + } + else if (ch == '+') + { + pszValue++; + fNo = true; + } + else if (ch == '-' || ch == '!' || ch == '~') + { + pszValue++; + fNo = !fNo; + } + else + break; + } + + /* instruction. */ + for (i = 0; i < RT_ELEMENTS(g_aLogFlags); i++) + { + if (!strncmp(pszValue, g_aLogFlags[i].pszInstr, g_aLogFlags[i].cchInstr)) + { + if (!(g_aLogFlags[i].fFixedDest & pLogger->fDestFlags)) + { + if (fNo == g_aLogFlags[i].fInverted) + pLogger->fFlags |= g_aLogFlags[i].fFlag; + else + pLogger->fFlags &= ~g_aLogFlags[i].fFlag; + } + pszValue += g_aLogFlags[i].cchInstr; + break; + } + } + + /* unknown instruction? */ + if (i >= RT_ELEMENTS(g_aLogFlags)) + { + AssertMsgFailed(("Invalid flags! unknown instruction %.20s\n", pszValue)); + pszValue++; + } + + /* skip blanks and delimiters. */ + while (RT_C_IS_SPACE(*pszValue) || *pszValue == ';') + pszValue++; + } /* while more environment variable value left */ + + return rc; +} +RT_EXPORT_SYMBOL(RTLogFlags); + + +/** + * Changes the buffering setting of the specified logger. + * + * This can be used for optimizing longish logging sequences. + * + * @returns The old state. + * @param pLogger The logger instance (NULL is an alias for the + * default logger). + * @param fBuffered The new state. + */ +RTDECL(bool) RTLogSetBuffering(PRTLOGGER pLogger, bool fBuffered) +{ + bool fOld; + + /* + * Resolve the logger instance. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + return false; + } + + rtlogLock(pLogger); + fOld = !!(pLogger->fFlags & RTLOGFLAGS_BUFFERED); + if (fBuffered) + pLogger->fFlags |= RTLOGFLAGS_BUFFERED; + else + pLogger->fFlags &= ~RTLOGFLAGS_BUFFERED; + rtlogUnlock(pLogger); + + return fOld; +} +RT_EXPORT_SYMBOL(RTLogSetBuffering); + + +#ifdef IN_RING3 +RTDECL(uint32_t) RTLogSetGroupLimit(PRTLOGGER pLogger, uint32_t cMaxEntriesPerGroup) +{ + /* + * Resolve the logger instance. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + return UINT32_MAX; + } + + rtlogLock(pLogger); + uint32_t cOld = pLogger->pInt->cMaxEntriesPerGroup; + pLogger->pInt->cMaxEntriesPerGroup = cMaxEntriesPerGroup; + rtlogUnlock(pLogger); + + return cOld; +} +#endif + +#ifndef IN_RC + +/** + * Get the current log flags as a string. + * + * @returns VINF_SUCCESS or VERR_BUFFER_OVERFLOW. + * @param pLogger Logger instance (NULL for default logger). + * @param pszBuf The output buffer. + * @param cchBuf The size of the output buffer. Must be greater + * than zero. + */ +RTDECL(int) RTLogGetFlags(PRTLOGGER pLogger, char *pszBuf, size_t cchBuf) +{ + bool fNotFirst = false; + int rc = VINF_SUCCESS; + uint32_t fFlags; + unsigned i; + + Assert(cchBuf); + + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + { + *pszBuf = '\0'; + return VINF_SUCCESS; + } + } + + /* + * Add the flags in the list. + */ + fFlags = pLogger->fFlags; + for (i = 0; i < RT_ELEMENTS(g_aLogFlags); i++) + if ( !g_aLogFlags[i].fInverted + ? (g_aLogFlags[i].fFlag & fFlags) + : !(g_aLogFlags[i].fFlag & fFlags)) + { + size_t cchInstr = g_aLogFlags[i].cchInstr; + if (cchInstr + fNotFirst + 1 > cchBuf) + { + rc = VERR_BUFFER_OVERFLOW; + break; + } + if (fNotFirst) + { + *pszBuf++ = ' '; + cchBuf--; + } + memcpy(pszBuf, g_aLogFlags[i].pszInstr, cchInstr); + pszBuf += cchInstr; + cchBuf -= cchInstr; + fNotFirst = true; + } + *pszBuf = '\0'; + return rc; +} +RT_EXPORT_SYMBOL(RTLogGetFlags); + + +/** + * Finds the end of a destination value. + * + * The value ends when we counter a ';' or a free standing word (space on both + * from the g_aLogDst table. (If this is problematic for someone, we could + * always do quoting and escaping.) + * + * @returns Value length in chars. + * @param pszValue The first char after '=' or ':'. + */ +static size_t rtLogDestFindValueLength(const char *pszValue) +{ + size_t off = 0; + char ch; + while ((ch = pszValue[off]) != '\0' && ch != ';') + { + if (!RT_C_IS_SPACE(ch)) + off++; + else + { + unsigned i; + size_t cchThusFar = off; + do + off++; + while ((ch = pszValue[off]) != '\0' && RT_C_IS_SPACE(ch)); + if (ch == ';') + return cchThusFar; + + if (ch == 'n' && pszValue[off + 1] == 'o') + off += 2; + for (i = 0; i < RT_ELEMENTS(g_aLogDst); i++) + if (!strncmp(&pszValue[off], g_aLogDst[i].pszInstr, g_aLogDst[i].cchInstr)) + { + ch = pszValue[off + g_aLogDst[i].cchInstr]; + if (ch == '\0' || RT_C_IS_SPACE(ch) || ch == '=' || ch == ':' || ch == ';') + return cchThusFar; + } + } + } + return off; +} + + +/** + * Updates the logger destination using the specified string. + * + * @returns VINF_SUCCESS or VERR_BUFFER_OVERFLOW. + * @param pLogger Logger instance (NULL for default logger). + * @param pszValue The value to parse. + */ +RTDECL(int) RTLogDestinations(PRTLOGGER pLogger, char const *pszValue) +{ + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + return VINF_SUCCESS; + } + + /* + * Do the parsing. + */ + while (*pszValue) + { + bool fNo; + unsigned i; + + /* skip blanks. */ + while (RT_C_IS_SPACE(*pszValue)) + pszValue++; + if (!*pszValue) + break; + + /* check no prefix. */ + fNo = false; + if ( pszValue[0] == 'n' + && pszValue[1] == 'o' + && ( pszValue[2] != 'd' + || pszValue[3] != 'e' + || pszValue[4] != 'n' + || pszValue[5] != 'y')) + { + fNo = true; + pszValue += 2; + } + + /* instruction. */ + for (i = 0; i < RT_ELEMENTS(g_aLogDst); i++) + { + size_t cchInstr = strlen(g_aLogDst[i].pszInstr); + if (!strncmp(pszValue, g_aLogDst[i].pszInstr, cchInstr)) + { + if (!fNo) + pLogger->fDestFlags |= g_aLogDst[i].fFlag; + else + pLogger->fDestFlags &= ~g_aLogDst[i].fFlag; + pszValue += cchInstr; + + /* check for value. */ + while (RT_C_IS_SPACE(*pszValue)) + pszValue++; + if (*pszValue == '=' || *pszValue == ':') + { + pszValue++; + size_t cch = rtLogDestFindValueLength(pszValue); + const char *pszEnd = pszValue + cch; + +# ifdef IN_RING3 + char szTmp[sizeof(pLogger->pInt->szFilename)]; +# else + char szTmp[32]; +# endif + if (0) + { /* nothing */ } +#ifdef IN_RING3 + + /* log file name */ + else if (i == 0 /* file */ && !fNo) + { + if (!(pLogger->fDestFlags & RTLOGDEST_FIXED_FILE)) + { + AssertReturn(cch < sizeof(pLogger->pInt->szFilename), VERR_OUT_OF_RANGE); + memcpy(pLogger->pInt->szFilename, pszValue, cch); + pLogger->pInt->szFilename[cch] = '\0'; + /** @todo reopen log file if pLogger->pInt->fCreated is true ... */ + } + } + /* log directory */ + else if (i == 1 /* dir */ && !fNo) + { + if (!(pLogger->fDestFlags & RTLOGDEST_FIXED_DIR)) + { + const char *pszFile = RTPathFilename(pLogger->pInt->szFilename); + size_t cchFile = pszFile ? strlen(pszFile) : 0; + AssertReturn(cchFile + cch + 1 < sizeof(pLogger->pInt->szFilename), VERR_OUT_OF_RANGE); + memcpy(szTmp, cchFile ? pszFile : "", cchFile + 1); + + memcpy(pLogger->pInt->szFilename, pszValue, cch); + pLogger->pInt->szFilename[cch] = '\0'; + RTPathStripTrailingSlash(pLogger->pInt->szFilename); + + cch = strlen(pLogger->pInt->szFilename); + pLogger->pInt->szFilename[cch++] = '/'; + memcpy(&pLogger->pInt->szFilename[cch], szTmp, cchFile); + pLogger->pInt->szFilename[cch + cchFile] = '\0'; + /** @todo reopen log file if pLogger->pInt->fCreated is true ... */ + } + } + else if (i == 2 /* history */) + { + if (!fNo) + { + uint32_t cHistory = 0; + int rc = RTStrCopyEx(szTmp, sizeof(szTmp), pszValue, cch); + if (RT_SUCCESS(rc)) + rc = RTStrToUInt32Full(szTmp, 0, &cHistory); + AssertMsgReturn(RT_SUCCESS(rc) && cHistory < _1M, ("Invalid history value %s (%Rrc)!\n", szTmp, rc), rc); + pLogger->pInt->cHistory = cHistory; + } + else + pLogger->pInt->cHistory = 0; + } + else if (i == 3 /* histsize */) + { + if (!fNo) + { + int rc = RTStrCopyEx(szTmp, sizeof(szTmp), pszValue, cch); + if (RT_SUCCESS(rc)) + rc = RTStrToUInt64Full(szTmp, 0, &pLogger->pInt->cbHistoryFileMax); + AssertMsgRCReturn(rc, ("Invalid history file size value %s (%Rrc)!\n", szTmp, rc), rc); + if (pLogger->pInt->cbHistoryFileMax == 0) + pLogger->pInt->cbHistoryFileMax = UINT64_MAX; + } + else + pLogger->pInt->cbHistoryFileMax = UINT64_MAX; + } + else if (i == 4 /* histtime */) + { + if (!fNo) + { + int rc = RTStrCopyEx(szTmp, sizeof(szTmp), pszValue, cch); + if (RT_SUCCESS(rc)) + rc = RTStrToUInt32Full(szTmp, 0, &pLogger->pInt->cSecsHistoryTimeSlot); + AssertMsgRCReturn(rc, ("Invalid history time slot value %s (%Rrc)!\n", szTmp, rc), rc); + if (pLogger->pInt->cSecsHistoryTimeSlot == 0) + pLogger->pInt->cSecsHistoryTimeSlot = UINT32_MAX; + } + else + pLogger->pInt->cSecsHistoryTimeSlot = UINT32_MAX; + } +# endif /* IN_RING3 */ + else if (i == 5 /* ringbuf */ && !fNo) + { + int rc = RTStrCopyEx(szTmp, sizeof(szTmp), pszValue, cch); + uint32_t cbRingBuf = 0; + if (RT_SUCCESS(rc)) + rc = RTStrToUInt32Full(szTmp, 0, &cbRingBuf); + AssertMsgRCReturn(rc, ("Invalid ring buffer size value '%s' (%Rrc)!\n", szTmp, rc), rc); + + if (cbRingBuf == 0) + cbRingBuf = RTLOG_RINGBUF_DEFAULT_SIZE; + else if (cbRingBuf < RTLOG_RINGBUF_MIN_SIZE) + cbRingBuf = RTLOG_RINGBUF_MIN_SIZE; + else if (cbRingBuf > RTLOG_RINGBUF_MAX_SIZE) + cbRingBuf = RTLOG_RINGBUF_MAX_SIZE; + else + cbRingBuf = RT_ALIGN_32(cbRingBuf, 64); + rc = rtLogRingBufAdjust(pLogger, cbRingBuf, false /*fForce*/); + if (RT_FAILURE(rc)) + return rc; + } + else + AssertMsgFailedReturn(("Invalid destination value! %s%s doesn't take a value!\n", + fNo ? "no" : "", g_aLogDst[i].pszInstr), + VERR_INVALID_PARAMETER); + + pszValue = pszEnd + (*pszEnd != '\0'); + } + else if (i == 5 /* ringbuf */ && !fNo && !pLogger->pInt->pszRingBuf) + { + int rc = rtLogRingBufAdjust(pLogger, pLogger->pInt->cbRingBuf, false /*fForce*/); + if (RT_FAILURE(rc)) + return rc; + } + break; + } + } + + /* assert known instruction */ + AssertMsgReturn(i < RT_ELEMENTS(g_aLogDst), + ("Invalid destination value! unknown instruction %.20s\n", pszValue), + VERR_INVALID_PARAMETER); + + /* skip blanks and delimiters. */ + while (RT_C_IS_SPACE(*pszValue) || *pszValue == ';') + pszValue++; + } /* while more environment variable value left */ + + return VINF_SUCCESS; +} +RT_EXPORT_SYMBOL(RTLogDestinations); + + +/** + * Clear the file delay flag if set, opening the destination and flushing. + * + * @returns IPRT status code. + * @param pLogger Logger instance (NULL for default logger). + * @param pszValue The value to parse. + * @param pErrInfo Where to return extended error info. Optional. + */ +RTDECL(int) RTLogClearFileDelayFlag(PRTLOGGER pLogger, PRTERRINFO pErrInfo) +{ + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + return VINF_SUCCESS; + } + + /* + * Do the work. + */ + int rc = rtlogLock(pLogger); + if (RT_SUCCESS(rc)) + { + if (pLogger->fDestFlags & RTLOGDEST_F_DELAY_FILE) + { + pLogger->fDestFlags &= ~RTLOGDEST_F_DELAY_FILE; +# ifdef IN_RING3 + if ( pLogger->fDestFlags & RTLOGDEST_FILE + && pLogger->pInt->hFile == NIL_RTFILE) + { + rc = rtR3LogOpenFileDestination(pLogger, pErrInfo); + if (RT_SUCCESS(rc)) + rtlogFlush(pLogger, false /*fNeedSpace*/); + } +# endif + RT_NOREF(pErrInfo); /** @todo fix create API to use RTErrInfo */ + } + rtlogUnlock(pLogger); + } + return VINF_SUCCESS; +} +RT_EXPORT_SYMBOL(RTLogClearFileDelayFlag); + + +/** + * Get the current log destinations as a string. + * + * @returns VINF_SUCCESS or VERR_BUFFER_OVERFLOW. + * @param pLogger Logger instance (NULL for default logger). + * @param pszBuf The output buffer. + * @param cchBuf The size of the output buffer. Must be greater + * than 0. + */ +RTDECL(int) RTLogGetDestinations(PRTLOGGER pLogger, char *pszBuf, size_t cchBuf) +{ + bool fNotFirst = false; + int rc = VINF_SUCCESS; + uint32_t fDestFlags; + unsigned i; + + AssertReturn(cchBuf, VERR_INVALID_PARAMETER); + *pszBuf = '\0'; + + /* + * Resolve defaults. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + return VINF_SUCCESS; + } + + /* + * Add the flags in the list. + */ + fDestFlags = pLogger->fDestFlags; + for (i = 6; i < RT_ELEMENTS(g_aLogDst); i++) + if (g_aLogDst[i].fFlag & fDestFlags) + { + if (fNotFirst) + { + rc = RTStrCopyP(&pszBuf, &cchBuf, " "); + if (RT_FAILURE(rc)) + return rc; + } + rc = RTStrCopyP(&pszBuf, &cchBuf, g_aLogDst[i].pszInstr); + if (RT_FAILURE(rc)) + return rc; + fNotFirst = true; + } + + char szNum[32]; + +# ifdef IN_RING3 + /* + * Add the filename. + */ + if (fDestFlags & RTLOGDEST_FILE) + { + rc = RTStrCopyP(&pszBuf, &cchBuf, fNotFirst ? " file=" : "file="); + if (RT_FAILURE(rc)) + return rc; + rc = RTStrCopyP(&pszBuf, &cchBuf, pLogger->pInt->szFilename); + if (RT_FAILURE(rc)) + return rc; + fNotFirst = true; + + if (pLogger->pInt->cHistory) + { + RTStrPrintf(szNum, sizeof(szNum), fNotFirst ? " history=%u" : "history=%u", pLogger->pInt->cHistory); + rc = RTStrCopyP(&pszBuf, &cchBuf, szNum); + if (RT_FAILURE(rc)) + return rc; + fNotFirst = true; + } + if (pLogger->pInt->cbHistoryFileMax != UINT64_MAX) + { + RTStrPrintf(szNum, sizeof(szNum), fNotFirst ? " histsize=%llu" : "histsize=%llu", pLogger->pInt->cbHistoryFileMax); + rc = RTStrCopyP(&pszBuf, &cchBuf, szNum); + if (RT_FAILURE(rc)) + return rc; + fNotFirst = true; + } + if (pLogger->pInt->cSecsHistoryTimeSlot != UINT32_MAX) + { + RTStrPrintf(szNum, sizeof(szNum), fNotFirst ? " histtime=%llu" : "histtime=%llu", pLogger->pInt->cSecsHistoryTimeSlot); + rc = RTStrCopyP(&pszBuf, &cchBuf, szNum); + if (RT_FAILURE(rc)) + return rc; + fNotFirst = true; + } + } +# endif /* IN_RING3 */ + + /* + * Add the ring buffer. + */ + if (fDestFlags & RTLOGDEST_RINGBUF) + { + if (pLogger->pInt->cbRingBuf == RTLOG_RINGBUF_DEFAULT_SIZE) + rc = RTStrCopyP(&pszBuf, &cchBuf, fNotFirst ? " ringbuf" : "ringbuf"); + else + { + RTStrPrintf(szNum, sizeof(szNum), fNotFirst ? " ringbuf=%#x" : "ringbuf=%#x", pLogger->pInt->cbRingBuf); + rc = RTStrCopyP(&pszBuf, &cchBuf, szNum); + } + if (RT_FAILURE(rc)) + return rc; + fNotFirst = true; + } + + return VINF_SUCCESS; +} +RT_EXPORT_SYMBOL(RTLogGetDestinations); + +#endif /* !IN_RC */ + +/** + * Flushes the specified logger. + * + * @param pLogger The logger instance to flush. + * If NULL the default instance is used. The default instance + * will not be initialized by this call. + */ +RTDECL(void) RTLogFlush(PRTLOGGER pLogger) +{ + /* + * Resolve defaults. + */ + if (!pLogger) + { +#ifdef IN_RC + pLogger = &g_Logger; +#else + pLogger = g_pLogger; +#endif + if (!pLogger) + return; + } + + /* + * Any thing to flush? + */ + if ( pLogger->offScratch +#ifndef IN_RC + || (pLogger->fDestFlags & RTLOGDEST_RINGBUF) +#endif + ) + { +#ifndef IN_RC + /* + * Acquire logger instance sem. + */ + int rc = rtlogLock(pLogger); + if (RT_FAILURE(rc)) + return; +#endif + /* + * Call worker. + */ + rtlogFlush(pLogger, false /*fNeedSpace*/); + +#ifndef IN_RC + /* + * Since this is an explicit flush call, the ring buffer content should + * be flushed to the other destinations if active. + */ + if ( (pLogger->fDestFlags & RTLOGDEST_RINGBUF) + && pLogger->pInt->pszRingBuf /* paranoia */) + rtLogRingBufFlush(pLogger); + + /* + * Release the semaphore. + */ + rtlogUnlock(pLogger); +#endif + } +} +RT_EXPORT_SYMBOL(RTLogFlush); + + +/** + * Common worker for RTLogDefaultInstance and RTLogDefaultInstanceEx. + */ +DECL_FORCE_INLINE(PRTLOGGER) rtLogDefaultInstanceCommon(void) +{ +#ifdef IN_RC + return &g_Logger; + +#else /* !IN_RC */ +# ifdef IN_RING0 + /* + * Check per thread loggers first. + */ + if (g_cPerThreadLoggers) + { + const RTNATIVETHREAD Self = RTThreadNativeSelf(); + int32_t i = RT_ELEMENTS(g_aPerThreadLoggers); + while (i-- > 0) + if (g_aPerThreadLoggers[i].NativeThread == Self) + return g_aPerThreadLoggers[i].pLogger; + } +# endif /* IN_RING0 */ + + /* + * If no per thread logger, use the default one. + */ + if (!g_pLogger) + g_pLogger = RTLogDefaultInit(); + return g_pLogger; +#endif /* !IN_RC */ +} + + +RTDECL(PRTLOGGER) RTLogDefaultInstance(void) +{ + return rtLogDefaultInstanceCommon(); +} +RT_EXPORT_SYMBOL(RTLogDefaultInstance); + + +RTDECL(PRTLOGGER) RTLogDefaultInstanceEx(uint32_t fFlagsAndGroup) +{ + PRTLOGGER pLogger = rtLogDefaultInstanceCommon(); + if (pLogger) + { + if (pLogger->fFlags & RTLOGFLAGS_DISABLED) + pLogger = NULL; + else + { + uint16_t const fFlags = RT_LO_U16(fFlagsAndGroup); + uint16_t const iGroup = RT_HI_U16(fFlagsAndGroup); + if ( iGroup != UINT16_MAX + && ( (pLogger->afGroups[iGroup < pLogger->cGroups ? iGroup : 0] & (fFlags | (uint32_t)RTLOGGRPFLAGS_ENABLED)) + != (fFlags | (uint32_t)RTLOGGRPFLAGS_ENABLED))) + pLogger = NULL; + } + } + return pLogger; +} +RT_EXPORT_SYMBOL(RTLogDefaultInstanceEx); + + +/** + * Common worker for RTLogGetDefaultInstance and RTLogGetDefaultInstanceEx. + */ +DECL_FORCE_INLINE(PRTLOGGER) rtLogGetDefaultInstanceCommon(void) +{ +#ifdef IN_RC + return &g_Logger; +#else +# ifdef IN_RING0 + /* + * Check per thread loggers first. + */ + if (g_cPerThreadLoggers) + { + const RTNATIVETHREAD Self = RTThreadNativeSelf(); + int32_t i = RT_ELEMENTS(g_aPerThreadLoggers); + while (i-- > 0) + if (g_aPerThreadLoggers[i].NativeThread == Self) + return g_aPerThreadLoggers[i].pLogger; + } +# endif /* IN_RING0 */ + + return g_pLogger; +#endif +} + + +RTDECL(PRTLOGGER) RTLogGetDefaultInstance(void) +{ + return rtLogGetDefaultInstanceCommon(); +} +RT_EXPORT_SYMBOL(RTLogGetDefaultInstance); + + +RTDECL(PRTLOGGER) RTLogGetDefaultInstanceEx(uint32_t fFlagsAndGroup) +{ + PRTLOGGER pLogger = rtLogGetDefaultInstanceCommon(); + if (pLogger) + { + if (pLogger->fFlags & RTLOGFLAGS_DISABLED) + pLogger = NULL; + else + { + uint32_t const fFlags = RT_LO_U16(fFlagsAndGroup); + uint16_t const iGroup = RT_HI_U16(fFlagsAndGroup); + if ( iGroup != UINT16_MAX + && ( (pLogger->afGroups[iGroup < pLogger->cGroups ? iGroup : 0] & (fFlags | RTLOGGRPFLAGS_ENABLED)) + != (fFlags | RTLOGGRPFLAGS_ENABLED))) + pLogger = NULL; + } + } + return pLogger; +} +RT_EXPORT_SYMBOL(RTLogGetDefaultInstanceEx); + + +#ifndef IN_RC +/** + * Sets the default logger instance. + * + * @returns iprt status code. + * @param pLogger The new default logger instance. + */ +RTDECL(PRTLOGGER) RTLogSetDefaultInstance(PRTLOGGER pLogger) +{ + return ASMAtomicXchgPtrT(&g_pLogger, pLogger, PRTLOGGER); +} +RT_EXPORT_SYMBOL(RTLogSetDefaultInstance); +#endif /* !IN_RC */ + + +#ifdef IN_RING0 +/** + * Changes the default logger instance for the current thread. + * + * @returns IPRT status code. + * @param pLogger The logger instance. Pass NULL for deregistration. + * @param uKey Associated key for cleanup purposes. If pLogger is NULL, + * all instances with this key will be deregistered. So in + * order to only deregister the instance associated with the + * current thread use 0. + */ +RTDECL(int) RTLogSetDefaultInstanceThread(PRTLOGGER pLogger, uintptr_t uKey) +{ + int rc; + RTNATIVETHREAD Self = RTThreadNativeSelf(); + if (pLogger) + { + int32_t i; + unsigned j; + + AssertReturn(pLogger->u32Magic == RTLOGGER_MAGIC, VERR_INVALID_MAGIC); + + /* + * Iterate the table to see if there is already an entry for this thread. + */ + i = RT_ELEMENTS(g_aPerThreadLoggers); + while (i-- > 0) + if (g_aPerThreadLoggers[i].NativeThread == Self) + { + ASMAtomicWritePtr((void * volatile *)&g_aPerThreadLoggers[i].uKey, (void *)uKey); + g_aPerThreadLoggers[i].pLogger = pLogger; + return VINF_SUCCESS; + } + + /* + * Allocate a new table entry. + */ + i = ASMAtomicIncS32(&g_cPerThreadLoggers); + if (i > (int32_t)RT_ELEMENTS(g_aPerThreadLoggers)) + { + ASMAtomicDecS32(&g_cPerThreadLoggers); + return VERR_BUFFER_OVERFLOW; /* horrible error code! */ + } + + for (j = 0; j < 10; j++) + { + i = RT_ELEMENTS(g_aPerThreadLoggers); + while (i-- > 0) + { + AssertCompile(sizeof(RTNATIVETHREAD) == sizeof(void*)); + if ( g_aPerThreadLoggers[i].NativeThread == NIL_RTNATIVETHREAD + && ASMAtomicCmpXchgPtr((void * volatile *)&g_aPerThreadLoggers[i].NativeThread, (void *)Self, (void *)NIL_RTNATIVETHREAD)) + { + ASMAtomicWritePtr((void * volatile *)&g_aPerThreadLoggers[i].uKey, (void *)uKey); + ASMAtomicWritePtr(&g_aPerThreadLoggers[i].pLogger, pLogger); + return VINF_SUCCESS; + } + } + } + + ASMAtomicDecS32(&g_cPerThreadLoggers); + rc = VERR_INTERNAL_ERROR; + } + else + { + /* + * Search the array for the current thread. + */ + int32_t i = RT_ELEMENTS(g_aPerThreadLoggers); + while (i-- > 0) + if ( g_aPerThreadLoggers[i].NativeThread == Self + || g_aPerThreadLoggers[i].uKey == uKey) + { + ASMAtomicWriteNullPtr((void * volatile *)&g_aPerThreadLoggers[i].uKey); + ASMAtomicWriteNullPtr(&g_aPerThreadLoggers[i].pLogger); + ASMAtomicWriteHandle(&g_aPerThreadLoggers[i].NativeThread, NIL_RTNATIVETHREAD); + ASMAtomicDecS32(&g_cPerThreadLoggers); + } + + rc = VINF_SUCCESS; + } + return rc; +} +RT_EXPORT_SYMBOL(RTLogSetDefaultInstanceThread); +#endif /* IN_RING0 */ + + +/** + * Write to a logger instance. + * + * @param pLogger Pointer to logger instance. + * @param pszFormat Format string. + * @param args Format arguments. + */ +RTDECL(void) RTLogLoggerV(PRTLOGGER pLogger, const char *pszFormat, va_list args) +{ + RTLogLoggerExV(pLogger, 0, ~0U, pszFormat, args); +} +RT_EXPORT_SYMBOL(RTLogLoggerV); + + +/** + * Write to a logger instance. + * + * This function will check whether the instance, group and flags makes up a + * logging kind which is currently enabled before writing anything to the log. + * + * @param pLogger Pointer to logger instance. If NULL the default logger instance will be attempted. + * @param fFlags The logging flags. + * @param iGroup The group. + * The value ~0U is reserved for compatibility with RTLogLogger[V] and is + * only for internal usage! + * @param pszFormat Format string. + * @param args Format arguments. + */ +RTDECL(void) RTLogLoggerExV(PRTLOGGER pLogger, unsigned fFlags, unsigned iGroup, const char *pszFormat, va_list args) +{ + int rc; + + /* + * A NULL logger means default instance. + */ + if (!pLogger) + { + pLogger = RTLogDefaultInstance(); + if (!pLogger) + return; + } + + /* + * Validate and correct iGroup. + */ + if (iGroup != ~0U && iGroup >= pLogger->cGroups) + iGroup = 0; + + /* + * If no output, then just skip it. + */ + if ( (pLogger->fFlags & RTLOGFLAGS_DISABLED) +#ifndef IN_RC + || !pLogger->fDestFlags +#endif + || !pszFormat || !*pszFormat) + return; + if ( iGroup != ~0U + && (pLogger->afGroups[iGroup] & (fFlags | RTLOGGRPFLAGS_ENABLED)) != (fFlags | RTLOGGRPFLAGS_ENABLED)) + return; + + /* + * Acquire logger instance sem. + */ + rc = rtlogLock(pLogger); + if (RT_FAILURE(rc)) + { +#ifdef IN_RING0 + if (pLogger->fDestFlags & ~RTLOGDEST_FILE) + rtR0LogLoggerExFallback(pLogger->fDestFlags, pLogger->fFlags, pLogger->pInt, pszFormat, args); +#endif + return; + } + + /* + * Check restrictions and call worker. + */ +#ifndef IN_RC + if (RT_UNLIKELY( (pLogger->fFlags & RTLOGFLAGS_RESTRICT_GROUPS) + && iGroup < pLogger->cGroups + && (pLogger->afGroups[iGroup] & RTLOGGRPFLAGS_RESTRICT) + && ++pLogger->pInt->pacEntriesPerGroup[iGroup] >= pLogger->pInt->cMaxEntriesPerGroup )) + { + uint32_t cEntries = pLogger->pInt->pacEntriesPerGroup[iGroup]; + if (cEntries > pLogger->pInt->cMaxEntriesPerGroup) + pLogger->pInt->pacEntriesPerGroup[iGroup] = cEntries - 1; + else + { + rtlogLoggerExVLocked(pLogger, fFlags, iGroup, pszFormat, args); + if ( pLogger->pInt->papszGroups + && pLogger->pInt->papszGroups[iGroup]) + rtlogLoggerExFLocked(pLogger, fFlags, iGroup, "%u messages from group %s (#%u), muting it.\n", + cEntries, pLogger->pInt->papszGroups[iGroup], iGroup); + else + rtlogLoggerExFLocked(pLogger, fFlags, iGroup, "%u messages from group #%u, muting it.\n", + cEntries, iGroup); + } + } + else +#endif + rtlogLoggerExVLocked(pLogger, fFlags, iGroup, pszFormat, args); + + /* + * Release the semaphore. + */ + rtlogUnlock(pLogger); +} +RT_EXPORT_SYMBOL(RTLogLoggerExV); + + +#ifdef IN_RING0 +/** + * For rtR0LogLoggerExFallbackOutput and rtR0LogLoggerExFallbackFlush. + */ +typedef struct RTR0LOGLOGGERFALLBACK +{ + /** The current scratch buffer offset. */ + uint32_t offScratch; + /** The destination flags. */ + uint32_t fDestFlags; + /** For ring buffer output. */ + PRTLOGGERINTERNAL pInt; + /** The scratch buffer. */ + char achScratch[80]; +} RTR0LOGLOGGERFALLBACK; +/** Pointer to RTR0LOGLOGGERFALLBACK which is used by + * rtR0LogLoggerExFallbackOutput. */ +typedef RTR0LOGLOGGERFALLBACK *PRTR0LOGLOGGERFALLBACK; + + +/** + * Flushes the fallback buffer. + * + * @param pThis The scratch buffer. + */ +static void rtR0LogLoggerExFallbackFlush(PRTR0LOGLOGGERFALLBACK pThis) +{ + if (!pThis->offScratch) + return; + + if ( (pThis->fDestFlags & RTLOGDEST_RINGBUF) + && pThis->pInt + && pThis->pInt->pszRingBuf /* paranoia */) + rtLogRingBufWrite(pThis->pInt, pThis->achScratch, pThis->offScratch); + else + { + if (pThis->fDestFlags & RTLOGDEST_USER) + RTLogWriteUser(pThis->achScratch, pThis->offScratch); + + if (pThis->fDestFlags & RTLOGDEST_DEBUGGER) + RTLogWriteDebugger(pThis->achScratch, pThis->offScratch); + + if (pThis->fDestFlags & RTLOGDEST_STDOUT) + RTLogWriteStdOut(pThis->achScratch, pThis->offScratch); + + if (pThis->fDestFlags & RTLOGDEST_STDERR) + RTLogWriteStdErr(pThis->achScratch, pThis->offScratch); + +# ifndef LOG_NO_COM + if (pThis->fDestFlags & RTLOGDEST_COM) + RTLogWriteCom(pThis->achScratch, pThis->offScratch); +# endif + } + + /* empty the buffer. */ + pThis->offScratch = 0; +} + + +/** + * Callback for RTLogFormatV used by rtR0LogLoggerExFallback. + * See PFNLOGOUTPUT() for details. + */ +static DECLCALLBACK(size_t) rtR0LogLoggerExFallbackOutput(void *pv, const char *pachChars, size_t cbChars) +{ + PRTR0LOGLOGGERFALLBACK pThis = (PRTR0LOGLOGGERFALLBACK)pv; + if (cbChars) + { + size_t cbRet = 0; + for (;;) + { + /* how much */ + uint32_t cb = sizeof(pThis->achScratch) - pThis->offScratch - 1; /* minus 1 - for the string terminator. */ + if (cb > cbChars) + cb = (uint32_t)cbChars; + + /* copy */ + memcpy(&pThis->achScratch[pThis->offScratch], pachChars, cb); + + /* advance */ + pThis->offScratch += cb; + cbRet += cb; + cbChars -= cb; + + /* done? */ + if (cbChars <= 0) + return cbRet; + + pachChars += cb; + + /* flush */ + pThis->achScratch[pThis->offScratch] = '\0'; + rtR0LogLoggerExFallbackFlush(pThis); + } + + /* won't ever get here! */ + } + else + { + /* + * Termination call, flush the log. + */ + pThis->achScratch[pThis->offScratch] = '\0'; + rtR0LogLoggerExFallbackFlush(pThis); + return 0; + } +} + + +/** + * Ring-0 fallback for cases where we're unable to grab the lock. + * + * This will happen when we're at a too high IRQL on Windows for instance and + * needs to be dealt with or we'll drop a lot of log output. This fallback will + * only output to some of the log destinations as a few of them may be doing + * dangerous things. We won't be doing any prefixing here either, at least not + * for the present, because it's too much hassle. + * + * @param fDestFlags The destination flags. + * @param fFlags The logger flags. + * @param pInt The internal logger data, for ring buffer output. + * @param pszFormat The format string. + * @param va The format arguments. + */ +static void rtR0LogLoggerExFallback(uint32_t fDestFlags, uint32_t fFlags, PRTLOGGERINTERNAL pInt, + const char *pszFormat, va_list va) +{ + RTR0LOGLOGGERFALLBACK This; + This.fDestFlags = fDestFlags; + This.pInt = pInt; + + /* fallback indicator. */ + This.offScratch = 2; + This.achScratch[0] = '['; + This.achScratch[1] = 'F'; + + /* selected prefixes */ + if (fFlags & RTLOGFLAGS_PREFIX_PID) + { + RTPROCESS Process = RTProcSelf(); + This.achScratch[This.offScratch++] = ' '; + This.offScratch += RTStrFormatNumber(&This.achScratch[This.offScratch], Process, 16, sizeof(RTPROCESS) * 2, 0, RTSTR_F_ZEROPAD); + } + if (fFlags & RTLOGFLAGS_PREFIX_TID) + { + RTNATIVETHREAD Thread = RTThreadNativeSelf(); + This.achScratch[This.offScratch++] = ' '; + This.offScratch += RTStrFormatNumber(&This.achScratch[This.offScratch], Thread, 16, sizeof(RTNATIVETHREAD) * 2, 0, RTSTR_F_ZEROPAD); + } + + This.achScratch[This.offScratch++] = ']'; + This.achScratch[This.offScratch++] = ' '; + + RTLogFormatV(rtR0LogLoggerExFallbackOutput, &This, pszFormat, va); +} +#endif /* IN_RING0 */ + + +/** + * vprintf like function for writing to the default log. + * + * @param pszFormat Printf like format string. + * @param va Optional arguments as specified in pszFormat. + * + * @remark The API doesn't support formatting of floating point numbers at the moment. + */ +RTDECL(void) RTLogPrintfV(const char *pszFormat, va_list va) +{ + RTLogLoggerV(NULL, pszFormat, va); +} +RT_EXPORT_SYMBOL(RTLogPrintfV); + + +/** + * Dumper vprintf-like function outputting to a logger. + * + * @param pvUser Pointer to the logger instance to use, NULL for + * default instance. + * @param pszFormat Format string. + * @param va Format arguments. + */ +RTDECL(void) RTLogDumpPrintfV(void *pvUser, const char *pszFormat, va_list va) +{ + RTLogLoggerV((PRTLOGGER)pvUser, pszFormat, va); +} +RT_EXPORT_SYMBOL(RTLogDumpPrintfV); + + +#ifdef IN_RING3 + +/** + * Opens/creates the log file. + * + * @param pLogger The logger instance to update. NULL is not allowed! + * @param pErrInfo Where to return extended error information. + * Optional. + */ +static int rtlogFileOpen(PRTLOGGER pLogger, PRTERRINFO pErrInfo) +{ + uint32_t fOpen = RTFILE_O_WRITE | RTFILE_O_DENY_NONE; + if (pLogger->fFlags & RTLOGFLAGS_APPEND) + fOpen |= RTFILE_O_OPEN_CREATE | RTFILE_O_APPEND; + else + { + RTFileDelete(pLogger->pInt->szFilename); + fOpen |= RTFILE_O_CREATE; + } + if (pLogger->fFlags & RTLOGFLAGS_WRITE_THROUGH) + fOpen |= RTFILE_O_WRITE_THROUGH; + if (pLogger->fDestFlags & RTLOGDEST_F_NO_DENY) + fOpen = (fOpen & ~RTFILE_O_DENY_NONE) | RTFILE_O_DENY_NOT_DELETE; + + unsigned cBackoff = 0; + int rc = RTFileOpen(&pLogger->pInt->hFile, pLogger->pInt->szFilename, fOpen); + while ( ( rc == VERR_SHARING_VIOLATION + || (rc == VERR_ALREADY_EXISTS && !(pLogger->fFlags & RTLOGFLAGS_APPEND))) + && cBackoff < RT_ELEMENTS(g_acMsLogBackoff)) + { + RTThreadSleep(g_acMsLogBackoff[cBackoff++]); + if (!(pLogger->fFlags & RTLOGFLAGS_APPEND)) + RTFileDelete(pLogger->pInt->szFilename); + rc = RTFileOpen(&pLogger->pInt->hFile, pLogger->pInt->szFilename, fOpen); + } + if (RT_SUCCESS(rc)) + { + rc = RTFileQuerySize(pLogger->pInt->hFile, &pLogger->pInt->cbHistoryFileWritten); + if (RT_FAILURE(rc)) + { + /* Don't complain if this fails, assume the file is empty. */ + pLogger->pInt->cbHistoryFileWritten = 0; + rc = VINF_SUCCESS; + } + } + else + { + pLogger->pInt->hFile = NIL_RTFILE; + RTErrInfoSetF(pErrInfo, rc, N_("could not open file '%s' (fOpen=%#x)"), pLogger->pInt->szFilename, fOpen); + } + return rc; +} + + +/** + * Closes, rotates and opens the log files if necessary. + * + * Used by the rtlogFlush() function as well as RTLogCreateExV. + * + * @param pLogger The logger instance to update. NULL is not allowed! + * @param uTimeSlot Current time slot (for tikme based rotation). + * @param fFirst Flag whether this is the beginning of logging, i.e. + * called from RTLogCreateExV. Prevents pfnPhase from + * being called. + * @param pErrInfo Where to return extended error information. Optional. + */ +static void rtlogRotate(PRTLOGGER pLogger, uint32_t uTimeSlot, bool fFirst, PRTERRINFO pErrInfo) +{ + /* Suppress rotating empty log files simply because the time elapsed. */ + if (RT_UNLIKELY(!pLogger->pInt->cbHistoryFileWritten)) + pLogger->pInt->uHistoryTimeSlotStart = uTimeSlot; + + /* Check rotation condition: file still small enough and not too old? */ + if (RT_LIKELY( pLogger->pInt->cbHistoryFileWritten < pLogger->pInt->cbHistoryFileMax + && uTimeSlot == pLogger->pInt->uHistoryTimeSlotStart)) + return; + + /* + * Save "disabled" log flag and make sure logging is disabled. + * The logging in the functions called during log file history + * rotation would cause severe trouble otherwise. + */ + uint32_t const fSavedFlags = pLogger->fFlags; + pLogger->fFlags |= RTLOGFLAGS_DISABLED; + + /* + * Disable log rotation temporarily, otherwise with extreme settings and + * chatty phase logging we could run into endless rotation. + */ + uint32_t const cSavedHistory = pLogger->pInt->cHistory; + pLogger->pInt->cHistory = 0; + + /* + * Close the old log file. + */ + if (pLogger->pInt->hFile != NIL_RTFILE) + { + /* Use the callback to generate some final log contents, but only if + * this is a rotation with a fully set up logger. Leave the other case + * to the RTLogCreateExV function. */ + if (pLogger->pInt->pfnPhase && !fFirst) + { + uint32_t fODestFlags = pLogger->fDestFlags; + pLogger->fDestFlags &= RTLOGDEST_FILE; + pLogger->pInt->pfnPhase(pLogger, RTLOGPHASE_PREROTATE, rtlogPhaseMsgLocked); + pLogger->fDestFlags = fODestFlags; + } + RTFileClose(pLogger->pInt->hFile); + pLogger->pInt->hFile = NIL_RTFILE; + } + + if (cSavedHistory) + { + /* + * Rotate the log files. + */ + for (uint32_t i = cSavedHistory - 1; i + 1 > 0; i--) + { + char szOldName[sizeof(pLogger->pInt->szFilename) + 32]; + if (i > 0) + RTStrPrintf(szOldName, sizeof(szOldName), "%s.%u", pLogger->pInt->szFilename, i); + else + RTStrCopy(szOldName, sizeof(szOldName), pLogger->pInt->szFilename); + + char szNewName[sizeof(pLogger->pInt->szFilename) + 32]; + RTStrPrintf(szNewName, sizeof(szNewName), "%s.%u", pLogger->pInt->szFilename, i + 1); + + unsigned cBackoff = 0; + int rc = RTFileRename(szOldName, szNewName, RTFILEMOVE_FLAGS_REPLACE); + while ( rc == VERR_SHARING_VIOLATION + && cBackoff < RT_ELEMENTS(g_acMsLogBackoff)) + { + RTThreadSleep(g_acMsLogBackoff[cBackoff++]); + rc = RTFileRename(szOldName, szNewName, RTFILEMOVE_FLAGS_REPLACE); + } + + if (rc == VERR_FILE_NOT_FOUND) + RTFileDelete(szNewName); + } + + /* + * Delete excess log files. + */ + for (uint32_t i = cSavedHistory + 1; ; i++) + { + char szExcessName[sizeof(pLogger->pInt->szFilename) + 32]; + RTStrPrintf(szExcessName, sizeof(szExcessName), "%s.%u", pLogger->pInt->szFilename, i); + int rc = RTFileDelete(szExcessName); + if (RT_FAILURE(rc)) + break; + } + } + + /* + * Update logger state and create new log file. + */ + pLogger->pInt->cbHistoryFileWritten = 0; + pLogger->pInt->uHistoryTimeSlotStart = uTimeSlot; + rtlogFileOpen(pLogger, pErrInfo); + + /* + * Use the callback to generate some initial log contents, but only if this + * is a rotation with a fully set up logger. Leave the other case to the + * RTLogCreateExV function. + */ + if (pLogger->pInt->pfnPhase && !fFirst) + { + uint32_t const fSavedDestFlags = pLogger->fDestFlags; + pLogger->fDestFlags &= RTLOGDEST_FILE; + pLogger->pInt->pfnPhase(pLogger, RTLOGPHASE_POSTROTATE, rtlogPhaseMsgLocked); + pLogger->fDestFlags = fSavedDestFlags; + } + + /* Restore saved values. */ + pLogger->pInt->cHistory = cSavedHistory; + pLogger->fFlags = fSavedFlags; +} + + +/** + * Worker for RTLogCreateExV and RTLogClearFileDelayFlag. + * + * This will later be used to reopen the file by RTLogDestinations. + * + * @returns IPRT status code. + * @param pLogger The logger. + * @param pErrInfo Where to return extended error information. + * Optional. + */ +static int rtR3LogOpenFileDestination(PRTLOGGER pLogger, PRTERRINFO pErrInfo) +{ + int rc; + if (pLogger->fFlags & RTLOGFLAGS_APPEND) + { + rc = rtlogFileOpen(pLogger, pErrInfo); + + /* Rotate in case of appending to a too big log file, + otherwise this simply doesn't do anything. */ + rtlogRotate(pLogger, 0, true /* fFirst */, pErrInfo); + } + else + { + /* Force rotation if it is configured. */ + pLogger->pInt->cbHistoryFileWritten = UINT64_MAX; + rtlogRotate(pLogger, 0, true /* fFirst */, pErrInfo); + + /* If the file is not open then rotation is not set up. */ + if (pLogger->pInt->hFile == NIL_RTFILE) + { + pLogger->pInt->cbHistoryFileWritten = 0; + rc = rtlogFileOpen(pLogger, pErrInfo); + } + else + rc = VINF_SUCCESS; + } + return rc; +} + +#endif /* IN_RING3 */ + + +/** + * Writes the buffer to the given log device without checking for buffered + * data or anything. + * + * Used by the RTLogFlush() function. + * + * @param pLogger The logger instance to write to. NULL is not allowed! + * @param fNeedSpace Set if the caller assumes space will be made available. + */ +static void rtlogFlush(PRTLOGGER pLogger, bool fNeedSpace) +{ + uint32_t const cchScratch = pLogger->offScratch; + if (cchScratch == 0) + return; /* nothing to flush. */ + NOREF(fNeedSpace); + +#ifndef IN_RC + /* + * If the ring buffer is active, the other destinations are only written + * to when the ring buffer is flushed by RTLogFlush(). + */ + if ( (pLogger->fDestFlags & RTLOGDEST_RINGBUF) + && pLogger->pInt + && pLogger->pInt->pszRingBuf /* paraoia */) + { + rtLogRingBufWrite(pLogger->pInt, pLogger->achScratch, pLogger->offScratch); + pLogger->offScratch = 0; /* empty the buffer. */ + } + /* + * In file delay mode, we ignore flush requests except when we're full + * and the caller really needs some scratch space to get work done. + */ + else +# ifdef IN_RING3 + if (!(pLogger->fDestFlags & RTLOGDEST_F_DELAY_FILE)) +# endif +#endif + { + /* Make sure the string is terminated. On Windows, RTLogWriteDebugger + will get upset if it isn't. */ + if (RT_LIKELY(cchScratch < sizeof(pLogger->achScratch))) + pLogger->achScratch[cchScratch] = '\0'; + else + AssertFailed(); + +#ifndef IN_RC + if (pLogger->fDestFlags & RTLOGDEST_USER) + RTLogWriteUser(pLogger->achScratch, cchScratch); + + if (pLogger->fDestFlags & RTLOGDEST_DEBUGGER) + RTLogWriteDebugger(pLogger->achScratch, cchScratch); + +# ifdef IN_RING3 + if ((pLogger->fDestFlags & (RTLOGDEST_FILE | RTLOGDEST_RINGBUF)) == RTLOGDEST_FILE) + { + if (pLogger->pInt->hFile != NIL_RTFILE) + { + RTFileWrite(pLogger->pInt->hFile, pLogger->achScratch, cchScratch, NULL); + if (pLogger->fFlags & RTLOGFLAGS_FLUSH) + RTFileFlush(pLogger->pInt->hFile); + } + if (pLogger->pInt->cHistory) + pLogger->pInt->cbHistoryFileWritten += cchScratch; + } +# endif + + if (pLogger->fDestFlags & RTLOGDEST_STDOUT) + RTLogWriteStdOut(pLogger->achScratch, cchScratch); + + if (pLogger->fDestFlags & RTLOGDEST_STDERR) + RTLogWriteStdErr(pLogger->achScratch, cchScratch); + +# if (defined(IN_RING0) || defined(IN_RC)) && !defined(LOG_NO_COM) + if (pLogger->fDestFlags & RTLOGDEST_COM) + RTLogWriteCom(pLogger->achScratch, cchScratch); +# endif +#endif /* !IN_RC */ + +#ifdef IN_RC + if (pLogger->pfnFlush) + pLogger->pfnFlush(pLogger); +#else + if (pLogger->pInt->pfnFlush) + pLogger->pInt->pfnFlush(pLogger); +#endif + + /* empty the buffer. */ + pLogger->offScratch = 0; + +#ifdef IN_RING3 + /* + * Rotate the log file if configured. Must be done after everything is + * flushed, since this will also use logging/flushing to write the header + * and footer messages. + */ + if ( (pLogger->fDestFlags & RTLOGDEST_FILE) + && pLogger->pInt->cHistory) + rtlogRotate(pLogger, RTTimeProgramSecTS() / pLogger->pInt->cSecsHistoryTimeSlot, false /*fFirst*/, NULL /*pErrInfo*/); +#endif + } +#ifdef IN_RING3 + else + { + /* + * Delay file open but the caller really need some space. So, give him half a + * buffer and insert a message indicating that we've dropped output. + */ + uint32_t offHalf = sizeof(pLogger->achScratch) / 2; + if (cchScratch > offHalf) + { + if (pLogger->fFlags & RTLOGFLAGS_USECRLF) + pLogger->achScratch[offHalf++] = '\r'; + static const char s_szDropMsg[] = "\n[DROP DROP DROP]"; + memcpy(&pLogger->achScratch[offHalf], RT_STR_TUPLE(s_szDropMsg)); + offHalf += sizeof(s_szDropMsg) - 1; + if (pLogger->fFlags & RTLOGFLAGS_USECRLF) + pLogger->achScratch[offHalf++] = '\r'; + pLogger->achScratch[offHalf++] = '\n'; + + pLogger->offScratch = offHalf; + } + } +#endif +} + + +/** + * Callback for RTLogFormatV which writes to the com port. + * See PFNLOGOUTPUT() for details. + */ +static DECLCALLBACK(size_t) rtLogOutput(void *pv, const char *pachChars, size_t cbChars) +{ + PRTLOGGER pLogger = (PRTLOGGER)pv; + if (cbChars) + { + size_t cbRet = 0; + for (;;) + { +#if defined(DEBUG) && defined(IN_RING3) + /* sanity */ + if (pLogger->offScratch >= sizeof(pLogger->achScratch)) + { + fprintf(stderr, "pLogger->offScratch >= sizeof(pLogger->achScratch) (%#x >= %#x)\n", + pLogger->offScratch, (unsigned)sizeof(pLogger->achScratch)); + AssertBreakpoint(); AssertBreakpoint(); + } +#endif + + /* how much */ + size_t cb = sizeof(pLogger->achScratch) - pLogger->offScratch - 1; + if (cb > cbChars) + cb = cbChars; + + /* copy */ + memcpy(&pLogger->achScratch[pLogger->offScratch], pachChars, cb); + + /* advance */ + pLogger->offScratch += (uint32_t)cb; + cbRet += cb; + cbChars -= cb; + + /* done? */ + if (cbChars <= 0) + return cbRet; + + pachChars += cb; + + /* flush */ + rtlogFlush(pLogger, true /*fNeedSpace*/); + } + + /* won't ever get here! */ + } + else + { + /* + * Termination call. + * There's always space for a terminator, and it's not counted. + */ + pLogger->achScratch[pLogger->offScratch] = '\0'; + return 0; + } +} + + +/** + * stpncpy implementation for use in rtLogOutputPrefixed w/ padding. + * + * @returns Pointer to the destination buffer byte following the copied string. + * @param pszDst The destination buffer. + * @param pszSrc The source string. + * @param cchSrcMax The maximum number of characters to copy from + * the string. + * @param cchMinWidth The minimum field with, padd with spaces to + * reach this. + */ +DECLINLINE(char *) rtLogStPNCpyPad(char *pszDst, const char *pszSrc, size_t cchSrcMax, size_t cchMinWidth) +{ + size_t cchSrc = 0; + if (pszSrc) + { + cchSrc = strlen(pszSrc); + if (cchSrc > cchSrcMax) + cchSrc = cchSrcMax; + + memcpy(pszDst, pszSrc, cchSrc); + pszDst += cchSrc; + } + do + *pszDst++ = ' '; + while (cchSrc++ < cchMinWidth); + + return pszDst; +} + + +/** + * stpncpy implementation for use in rtLogOutputPrefixed w/ padding. + * + * @returns Pointer to the destination buffer byte following the copied string. + * @param pszDst The destination buffer. + * @param pszSrc The source string. + * @param cchSrc The number of characters to copy from the + * source. Equal or less than string length. + * @param cchMinWidth The minimum field with, padd with spaces to + * reach this. + */ +DECLINLINE(char *) rtLogStPNCpyPad2(char *pszDst, const char *pszSrc, size_t cchSrc, size_t cchMinWidth) +{ + Assert(pszSrc); + Assert(strlen(pszSrc) >= cchSrc); + + memcpy(pszDst, pszSrc, cchSrc); + pszDst += cchSrc; + do + *pszDst++ = ' '; + while (cchSrc++ < cchMinWidth); + + return pszDst; +} + + + +/** + * Callback for RTLogFormatV which writes to the logger instance. + * This version supports prefixes. + * + * See PFNLOGOUTPUT() for details. + */ +static DECLCALLBACK(size_t) rtLogOutputPrefixed(void *pv, const char *pachChars, size_t cbChars) +{ + PRTLOGOUTPUTPREFIXEDARGS pArgs = (PRTLOGOUTPUTPREFIXEDARGS)pv; + PRTLOGGER pLogger = pArgs->pLogger; + if (cbChars) + { + size_t cbRet = 0; + for (;;) + { + uint32_t offScratch = pLogger->offScratch; + size_t cb = sizeof(pLogger->achScratch) - offScratch - 1; + const char *pszNewLine; + char *psz; +#ifdef IN_RC + bool *pfPendingPrefix = &pLogger->fPendingPrefix; +#else + bool *pfPendingPrefix = &pLogger->pInt->fPendingPrefix; +#endif + + /* + * Pending prefix? + */ + if (*pfPendingPrefix) + { + *pfPendingPrefix = false; + +#if defined(DEBUG) && defined(IN_RING3) + /* sanity */ + if (offScratch >= sizeof(pLogger->achScratch)) + { + fprintf(stderr, "offScratch >= sizeof(pLogger->achScratch) (%#x >= %#x)\n", + offScratch, (unsigned)sizeof(pLogger->achScratch)); + AssertBreakpoint(); AssertBreakpoint(); + } +#endif + + /* + * Flush the buffer if there isn't enough room for the maximum prefix config. + * Max is 256, add a couple of extra bytes. See CCH_PREFIX check way below. + */ + if (cb < 256 + 16) + { + rtlogFlush(pLogger, true /*fNeedSpace*/); + offScratch = pLogger->offScratch; + cb = sizeof(pLogger->achScratch) - offScratch - 1; + } + + /* + * Write the prefixes. + * psz is pointing to the current position. + */ + psz = &pLogger->achScratch[offScratch]; + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_TS) + { + uint64_t u64 = RTTimeNanoTS(); + int iBase = 16; + unsigned int fFlags = RTSTR_F_ZEROPAD; + if (pLogger->fFlags & RTLOGFLAGS_DECIMAL_TS) + { + iBase = 10; + fFlags = 0; + } + if (pLogger->fFlags & RTLOGFLAGS_REL_TS) + { + static volatile uint64_t s_u64LastTs; + uint64_t u64DiffTs = u64 - s_u64LastTs; + s_u64LastTs = u64; + /* We could have been preempted just before reading of s_u64LastTs by + * another thread which wrote s_u64LastTs. In that case the difference + * is negative which we simply ignore. */ + u64 = (int64_t)u64DiffTs < 0 ? 0 : u64DiffTs; + } + /* 1E15 nanoseconds = 11 days */ + psz += RTStrFormatNumber(psz, u64, iBase, 16, 0, fFlags); + *psz++ = ' '; + } +#define CCH_PREFIX_01 0 + 17 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_TSC) + { +#if defined(RT_ARCH_AMD64) || defined(RT_ARCH_X86) + uint64_t u64 = ASMReadTSC(); +#else + uint64_t u64 = RTTimeNanoTS(); +#endif + int iBase = 16; + unsigned int fFlags = RTSTR_F_ZEROPAD; + if (pLogger->fFlags & RTLOGFLAGS_DECIMAL_TS) + { + iBase = 10; + fFlags = 0; + } + if (pLogger->fFlags & RTLOGFLAGS_REL_TS) + { + static volatile uint64_t s_u64LastTsc; + int64_t i64DiffTsc = u64 - s_u64LastTsc; + s_u64LastTsc = u64; + /* We could have been preempted just before reading of s_u64LastTsc by + * another thread which wrote s_u64LastTsc. In that case the difference + * is negative which we simply ignore. */ + u64 = i64DiffTsc < 0 ? 0 : i64DiffTsc; + } + /* 1E15 ticks at 4GHz = 69 hours */ + psz += RTStrFormatNumber(psz, u64, iBase, 16, 0, fFlags); + *psz++ = ' '; + } +#define CCH_PREFIX_02 CCH_PREFIX_01 + 17 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_MS_PROG) + { +#if defined(IN_RING3) || defined(IN_RC) + uint64_t u64 = RTTimeProgramMilliTS(); +#else + uint64_t u64 = (RTTimeNanoTS() - pLogger->pInt->nsR0ProgramStart) / RT_NS_1MS; +#endif + /* 1E8 milliseconds = 27 hours */ + psz += RTStrFormatNumber(psz, u64, 10, 9, 0, RTSTR_F_ZEROPAD); + *psz++ = ' '; + } +#define CCH_PREFIX_03 CCH_PREFIX_02 + 21 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_TIME) + { +#if defined(IN_RING3) || defined(IN_RING0) + RTTIMESPEC TimeSpec; + RTTIME Time; + RTTimeExplode(&Time, RTTimeNow(&TimeSpec)); + psz += RTStrFormatNumber(psz, Time.u8Hour, 10, 2, 0, RTSTR_F_ZEROPAD); + *psz++ = ':'; + psz += RTStrFormatNumber(psz, Time.u8Minute, 10, 2, 0, RTSTR_F_ZEROPAD); + *psz++ = ':'; + psz += RTStrFormatNumber(psz, Time.u8Second, 10, 2, 0, RTSTR_F_ZEROPAD); + *psz++ = '.'; + psz += RTStrFormatNumber(psz, Time.u32Nanosecond / 1000, 10, 6, 0, RTSTR_F_ZEROPAD); + *psz++ = ' '; +#else + memset(psz, ' ', 16); + psz += 16; +#endif + } +#define CCH_PREFIX_04 CCH_PREFIX_03 + (3+1+3+1+3+1+7+1) + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_TIME_PROG) + { + +#if defined(IN_RING3) || defined(IN_RC) + uint64_t u64 = RTTimeProgramMicroTS(); +#else + uint64_t u64 = (RTTimeNanoTS() - pLogger->pInt->nsR0ProgramStart) / RT_NS_1US; + +#endif + psz += RTStrFormatNumber(psz, (uint32_t)(u64 / RT_US_1HOUR), 10, 2, 0, RTSTR_F_ZEROPAD); + *psz++ = ':'; + uint32_t u32 = (uint32_t)(u64 % RT_US_1HOUR); + psz += RTStrFormatNumber(psz, u32 / RT_US_1MIN, 10, 2, 0, RTSTR_F_ZEROPAD); + *psz++ = ':'; + u32 %= RT_US_1MIN; + + psz += RTStrFormatNumber(psz, u32 / RT_US_1SEC, 10, 2, 0, RTSTR_F_ZEROPAD); + *psz++ = '.'; + psz += RTStrFormatNumber(psz, u32 % RT_US_1SEC, 10, 6, 0, RTSTR_F_ZEROPAD); + *psz++ = ' '; + } +#define CCH_PREFIX_05 CCH_PREFIX_04 + (9+1+2+1+2+1+6+1) + +# if 0 + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_DATETIME) + { + char szDate[32]; + RTTIMESPEC Time; + RTTimeSpecToString(RTTimeNow(&Time), szDate, sizeof(szDate)); + size_t cch = strlen(szDate); + memcpy(psz, szDate, cch); + psz += cch; + *psz++ = ' '; + } +# define CCH_PREFIX_06 CCH_PREFIX_05 + 32 +# else +# define CCH_PREFIX_06 CCH_PREFIX_05 + 0 +# endif + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_PID) + { +#ifndef IN_RC + RTPROCESS Process = RTProcSelf(); +#else + RTPROCESS Process = NIL_RTPROCESS; +#endif + psz += RTStrFormatNumber(psz, Process, 16, sizeof(RTPROCESS) * 2, 0, RTSTR_F_ZEROPAD); + *psz++ = ' '; + } +#define CCH_PREFIX_07 CCH_PREFIX_06 + 9 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_TID) + { +#ifndef IN_RC + RTNATIVETHREAD Thread = RTThreadNativeSelf(); +#else + RTNATIVETHREAD Thread = NIL_RTNATIVETHREAD; +#endif + psz += RTStrFormatNumber(psz, Thread, 16, sizeof(RTNATIVETHREAD) * 2, 0, RTSTR_F_ZEROPAD); + *psz++ = ' '; + } +#define CCH_PREFIX_08 CCH_PREFIX_07 + 17 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_THREAD) + { +#ifdef IN_RING3 + const char *pszName = RTThreadSelfName(); +#elif defined IN_RC + const char *pszName = "EMT-RC"; +#else + const char *pszName = pLogger->pInt->szR0ThreadName[0] ? pLogger->pInt->szR0ThreadName : "R0"; +#endif + psz = rtLogStPNCpyPad(psz, pszName, 16, 8); + } +#define CCH_PREFIX_09 CCH_PREFIX_08 + 17 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_CPUID) + { +#if defined(RT_ARCH_AMD64) || defined(RT_ARCH_X86) + const uint8_t idCpu = ASMGetApicId(); +#else + const RTCPUID idCpu = RTMpCpuId(); +#endif + psz += RTStrFormatNumber(psz, idCpu, 16, sizeof(idCpu) * 2, 0, RTSTR_F_ZEROPAD); + *psz++ = ' '; + } +#define CCH_PREFIX_10 CCH_PREFIX_09 + 17 + +#ifndef IN_RC + if ( (pLogger->fFlags & RTLOGFLAGS_PREFIX_CUSTOM) + && pLogger->pInt->pfnPrefix) + { + psz += pLogger->pInt->pfnPrefix(pLogger, psz, 31, pLogger->pInt->pvPrefixUserArg); + *psz++ = ' '; /* +32 */ + } +#endif +#define CCH_PREFIX_11 CCH_PREFIX_10 + 32 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_LOCK_COUNTS) + { +#ifdef IN_RING3 /** @todo implement these counters in ring-0 too? */ + RTTHREAD Thread = RTThreadSelf(); + if (Thread != NIL_RTTHREAD) + { + uint32_t cReadLocks = RTLockValidatorReadLockGetCount(Thread); + uint32_t cWriteLocks = RTLockValidatorWriteLockGetCount(Thread) - g_cLoggerLockCount; + cReadLocks = RT_MIN(0xfff, cReadLocks); + cWriteLocks = RT_MIN(0xfff, cWriteLocks); + psz += RTStrFormatNumber(psz, cReadLocks, 16, 1, 0, RTSTR_F_ZEROPAD); + *psz++ = '/'; + psz += RTStrFormatNumber(psz, cWriteLocks, 16, 1, 0, RTSTR_F_ZEROPAD); + } + else +#endif + { + *psz++ = '?'; + *psz++ = '/'; + *psz++ = '?'; + } + *psz++ = ' '; + } +#define CCH_PREFIX_12 CCH_PREFIX_11 + 8 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_FLAG_NO) + { + psz += RTStrFormatNumber(psz, pArgs->fFlags, 16, 8, 0, RTSTR_F_ZEROPAD); + *psz++ = ' '; + } +#define CCH_PREFIX_13 CCH_PREFIX_12 + 9 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_FLAG) + { +#ifdef IN_RING3 + const char *pszGroup = pArgs->iGroup != ~0U ? pLogger->pInt->papszGroups[pArgs->iGroup] : NULL; +#else + const char *pszGroup = NULL; +#endif + psz = rtLogStPNCpyPad(psz, pszGroup, 16, 8); + } +#define CCH_PREFIX_14 CCH_PREFIX_13 + 17 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_GROUP_NO) + { + if (pArgs->iGroup != ~0U) + { + psz += RTStrFormatNumber(psz, pArgs->iGroup, 16, 3, 0, RTSTR_F_ZEROPAD); + *psz++ = ' '; + } + else + { + memcpy(psz, "-1 ", sizeof("-1 ") - 1); + psz += sizeof("-1 ") - 1; + } /* +9 */ + } +#define CCH_PREFIX_15 CCH_PREFIX_14 + 9 + + if (pLogger->fFlags & RTLOGFLAGS_PREFIX_GROUP) + { + const unsigned fGrp = pLogger->afGroups[pArgs->iGroup != ~0U ? pArgs->iGroup : 0]; + const char *pszGroup; + size_t cchGroup; + switch (pArgs->fFlags & fGrp) + { + case 0: pszGroup = "--------"; cchGroup = sizeof("--------") - 1; break; + case RTLOGGRPFLAGS_ENABLED: pszGroup = "enabled" ; cchGroup = sizeof("enabled" ) - 1; break; + case RTLOGGRPFLAGS_LEVEL_1: pszGroup = "level 1" ; cchGroup = sizeof("level 1" ) - 1; break; + case RTLOGGRPFLAGS_LEVEL_2: pszGroup = "level 2" ; cchGroup = sizeof("level 2" ) - 1; break; + case RTLOGGRPFLAGS_LEVEL_3: pszGroup = "level 3" ; cchGroup = sizeof("level 3" ) - 1; break; + case RTLOGGRPFLAGS_LEVEL_4: pszGroup = "level 4" ; cchGroup = sizeof("level 4" ) - 1; break; + case RTLOGGRPFLAGS_LEVEL_5: pszGroup = "level 5" ; cchGroup = sizeof("level 5" ) - 1; break; + case RTLOGGRPFLAGS_LEVEL_6: pszGroup = "level 6" ; cchGroup = sizeof("level 6" ) - 1; break; + case RTLOGGRPFLAGS_LEVEL_7: pszGroup = "level 7" ; cchGroup = sizeof("level 7" ) - 1; break; + case RTLOGGRPFLAGS_LEVEL_8: pszGroup = "level 8" ; cchGroup = sizeof("level 8" ) - 1; break; + case RTLOGGRPFLAGS_LEVEL_9: pszGroup = "level 9" ; cchGroup = sizeof("level 9" ) - 1; break; + case RTLOGGRPFLAGS_LEVEL_10: pszGroup = "level 10"; cchGroup = sizeof("level 10") - 1; break; + case RTLOGGRPFLAGS_LEVEL_11: pszGroup = "level 11"; cchGroup = sizeof("level 11") - 1; break; + case RTLOGGRPFLAGS_LEVEL_12: pszGroup = "level 12"; cchGroup = sizeof("level 12") - 1; break; + case RTLOGGRPFLAGS_FLOW: pszGroup = "flow" ; cchGroup = sizeof("flow" ) - 1; break; + case RTLOGGRPFLAGS_WARN: pszGroup = "warn" ; cchGroup = sizeof("warn" ) - 1; break; + default: pszGroup = "????????"; cchGroup = sizeof("????????") - 1; break; + } + psz = rtLogStPNCpyPad2(psz, pszGroup, RT_MIN(cchGroup, 16), 8); + } +#define CCH_PREFIX_16 CCH_PREFIX_15 + 17 + +#define CCH_PREFIX ( CCH_PREFIX_16 ) + { AssertCompile(CCH_PREFIX < 256); } + + /* + * Done, figure what we've used and advance the buffer and free size. + */ + cb = psz - &pLogger->achScratch[offScratch]; + AssertMsg(cb <= 223, ("%#zx (%zd) - fFlags=%#x\n", cb, cb, pLogger->fFlags)); + pLogger->offScratch = offScratch += (uint32_t)cb; + cb = sizeof(pLogger->achScratch) - offScratch - 1; + } + else if (cb <= 0) + { + rtlogFlush(pLogger, true /*fNeedSpace*/); + offScratch = pLogger->offScratch; + cb = sizeof(pLogger->achScratch) - offScratch - 1; + } + +#if defined(DEBUG) && defined(IN_RING3) + /* sanity */ + if (offScratch >= sizeof(pLogger->achScratch)) + { + fprintf(stderr, "offScratch >= sizeof(pLogger->achScratch) (%#x >= %#x)\n", + offScratch, (unsigned)sizeof(pLogger->achScratch)); + AssertBreakpoint(); AssertBreakpoint(); + } +#endif + + /* how much */ + if (cb > cbChars) + cb = cbChars; + + /* have newline? */ + pszNewLine = (const char *)memchr(pachChars, '\n', cb); + if (pszNewLine) + { + if (pLogger->fFlags & RTLOGFLAGS_USECRLF) + cb = pszNewLine - pachChars; + else + { + cb = pszNewLine - pachChars + 1; + *pfPendingPrefix = true; + } + } + + /* copy */ + memcpy(&pLogger->achScratch[offScratch], pachChars, cb); + + /* advance */ + pLogger->offScratch = offScratch += (uint32_t)cb; + cbRet += cb; + cbChars -= cb; + + if ( pszNewLine + && (pLogger->fFlags & RTLOGFLAGS_USECRLF) + && offScratch + 2 < sizeof(pLogger->achScratch)) + { + memcpy(&pLogger->achScratch[offScratch], "\r\n", 2); + pLogger->offScratch = offScratch += 2; + cbRet++; + cbChars--; + cb++; + *pfPendingPrefix = true; + } + + /* done? */ + if (cbChars <= 0) + return cbRet; + pachChars += cb; + } + + /* won't ever get here! */ + } + else + { + /* + * Termination call. + * There's always space for a terminator, and it's not counted. + */ + pLogger->achScratch[pLogger->offScratch] = '\0'; + return 0; + } +} + + +/** + * Write to a logger instance (worker function). + * + * This function will check whether the instance, group and flags makes up a + * logging kind which is currently enabled before writing anything to the log. + * + * @param pLogger Pointer to logger instance. Must be non-NULL. + * @param fFlags The logging flags. + * @param iGroup The group. + * The value ~0U is reserved for compatibility with RTLogLogger[V] and is + * only for internal usage! + * @param pszFormat Format string. + * @param args Format arguments. + */ +static void rtlogLoggerExVLocked(PRTLOGGER pLogger, unsigned fFlags, unsigned iGroup, const char *pszFormat, va_list args) +{ + /* + * Format the message and perhaps flush it. + */ + if (pLogger->fFlags & (RTLOGFLAGS_PREFIX_MASK | RTLOGFLAGS_USECRLF)) + { + RTLOGOUTPUTPREFIXEDARGS OutputArgs; + OutputArgs.pLogger = pLogger; + OutputArgs.iGroup = iGroup; + OutputArgs.fFlags = fFlags; + RTLogFormatV(rtLogOutputPrefixed, &OutputArgs, pszFormat, args); + } + else + RTLogFormatV(rtLogOutput, pLogger, pszFormat, args); + if ( !(pLogger->fFlags & RTLOGFLAGS_BUFFERED) + && pLogger->offScratch) + rtlogFlush(pLogger, false /*fNeedSpace*/); +} + + +#ifndef IN_RC +/** + * For calling rtlogLoggerExVLocked. + * + * @param pLogger The logger. + * @param fFlags The logging flags. + * @param iGroup The group. + * The value ~0U is reserved for compatibility with RTLogLogger[V] and is + * only for internal usage! + * @param pszFormat Format string. + * @param ... Format arguments. + */ +static void rtlogLoggerExFLocked(PRTLOGGER pLogger, unsigned fFlags, unsigned iGroup, const char *pszFormat, ...) +{ + va_list va; + va_start(va, pszFormat); + rtlogLoggerExVLocked(pLogger, fFlags, iGroup, pszFormat, va); + va_end(va); +} +#endif /* !IN_RC */ + diff --git a/src/VBox/Runtime/common/log/logcom.cpp b/src/VBox/Runtime/common/log/logcom.cpp new file mode 100644 index 00000000..ecf2bbcb --- /dev/null +++ b/src/VBox/Runtime/common/log/logcom.cpp @@ -0,0 +1,146 @@ +/* $Id: logcom.cpp $ */ +/** @file + * IPRT - Logging to Serial Port. + */ + +/* + * Copyright (C) 2006-2020 Oracle Corporation + * + * This file is part of VirtualBox Open Source Edition (OSE), as + * available from http://www.virtualbox.org. This file is free software; + * you can redistribute it and/or modify it under the terms of the GNU + * General Public License (GPL) as published by the Free Software + * Foundation, in version 2 as it comes in the "COPYING" file of the + * VirtualBox OSE distribution. VirtualBox OSE is distributed in the + * hope that it will be useful, but WITHOUT ANY WARRANTY of any kind. + * + * The contents of this file may alternatively be used under the terms + * of the Common Development and Distribution License Version 1.0 + * (CDDL) only, as it comes in the "COPYING.CDDL" file of the + * VirtualBox OSE distribution, in which case the provisions of the + * CDDL are applicable instead of those of the GPL. + * + * You may elect to license modified versions of this file under the + * terms and conditions of either the GPL or the CDDL or both. + */ + + +/********************************************************************************************************************************* +* Defined Constants And Macros * +*********************************************************************************************************************************/ +#ifndef IPRT_UART_BASE +/** The port address of the COM port to log to. + * + * To override the default (COM1) append IPRT_UART_BASE=0xWXYZ to DEFS in your + * LocalConfig.kmk. Alternatively you can edit this file, but the don't forget + * to also update the default found in VBox/asmdefs.h. + * + * Standard port assignments are: COM1=0x3f8, COM2=0x2f8, COM3=0x3e8, COM4=0x2e8. + */ +# define IPRT_UART_BASE 0x3f8 +#endif + + +/********************************************************************************************************************************* +* Header Files * +*********************************************************************************************************************************/ +#include <iprt/log.h> +#include "internal/iprt.h" + +#include <iprt/asm.h> +#if defined(RT_ARCH_AMD64) || defined(RT_ARCH_X86) /** @todo consider fixing the config instead. */ +# include <iprt/asm-amd64-x86.h> +#endif +#include <iprt/stdarg.h> +#include <iprt/string.h> + + +/********************************************************************************************************************************* +* Internal Functions * +*********************************************************************************************************************************/ +static DECLCALLBACK(size_t) rtLogComOutput(void *pv, const char *pachChars, size_t cbChars); + + +/** + * Prints a formatted string to the serial port used for logging. + * + * @returns Number of bytes written. + * @param pszFormat Format string. + * @param ... Optional arguments specified in the format string. + */ +RTDECL(size_t) RTLogComPrintf(const char *pszFormat, ...) +{ + va_list args; + size_t cb; + va_start(args, pszFormat); + cb = RTLogComPrintfV(pszFormat, args); + va_end(args); + + return cb; +} +RT_EXPORT_SYMBOL(RTLogComPrintf); + + +/** + * Prints a formatted string to the serial port used for logging. + * + * @returns Number of bytes written. + * @param pszFormat Format string. + * @param args Optional arguments specified in the format string. + */ +RTDECL(size_t) RTLogComPrintfV(const char *pszFormat, va_list args) +{ + return RTLogFormatV(rtLogComOutput, NULL, pszFormat, args); +} +RT_EXPORT_SYMBOL(RTLogComPrintfV); + + +/** + * Callback for RTLogFormatV which writes to the com port. + * See PFNLOGOUTPUT() for details. + */ +static DECLCALLBACK(size_t) rtLogComOutput(void *pv, const char *pachChars, size_t cbChars) +{ + NOREF(pv); + if (cbChars) + RTLogWriteCom(pachChars, cbChars); + return cbChars; +} + + +/** + * Write log buffer to COM port. + * + * @param pach Pointer to the buffer to write. + * @param cb Number of bytes to write. + */ +RTDECL(void) RTLogWriteCom(const char *pach, size_t cb) +{ +#if defined(RT_ARCH_AMD64) || defined(RT_ARCH_X86) + const uint8_t *pu8; + for (pu8 = (const uint8_t *)pach; cb-- > 0; pu8++) + { + unsigned cMaxWait; + uint8_t u8; + + /* expand \n -> \r\n */ + if (*pu8 == '\n') + RTLogWriteCom("\r", 1); + + /* Check if port is ready. */ + cMaxWait = ~0U; + do + { + u8 = ASMInU8(IPRT_UART_BASE + 5); + cMaxWait--; + } while (!(u8 & 0x20) && u8 != 0xff && cMaxWait); + + /* write */ + ASMOutU8(IPRT_UART_BASE, *pu8); + } +#else + /* PORTME? */ +#endif +} +RT_EXPORT_SYMBOL(RTLogWriteCom); + diff --git a/src/VBox/Runtime/common/log/logellipsis.cpp b/src/VBox/Runtime/common/log/logellipsis.cpp new file mode 100644 index 00000000..936baf0c --- /dev/null +++ b/src/VBox/Runtime/common/log/logellipsis.cpp @@ -0,0 +1,105 @@ +/* $Id: logellipsis.cpp $ */ +/** @file + * Runtime VBox - Logger, the ellipsis variants. + */ + +/* + * Copyright (C) 2006-2020 Oracle Corporation + * + * This file is part of VirtualBox Open Source Edition (OSE), as + * available from http://www.virtualbox.org. This file is free software; + * you can redistribute it and/or modify it under the terms of the GNU + * General Public License (GPL) as published by the Free Software + * Foundation, in version 2 as it comes in the "COPYING" file of the + * VirtualBox OSE distribution. VirtualBox OSE is distributed in the + * hope that it will be useful, but WITHOUT ANY WARRANTY of any kind. + * + * The contents of this file may alternatively be used under the terms + * of the Common Development and Distribution License Version 1.0 + * (CDDL) only, as it comes in the "COPYING.CDDL" file of the + * VirtualBox OSE distribution, in which case the provisions of the + * CDDL are applicable instead of those of the GPL. + * + * You may elect to license modified versions of this file under the + * terms and conditions of either the GPL or the CDDL or both. + */ + + +/********************************************************************************************************************************* +* Header Files * +*********************************************************************************************************************************/ +#include <iprt/log.h> +#include "internal/iprt.h" + +#include <iprt/asm.h> +#include <iprt/stdarg.h> + + +/** + * Write to a logger instance. + * + * @param pLogger Pointer to logger instance. + * @param pvCallerRet Ignored. + * @param pszFormat Format string. + * @param ... Format arguments. + */ +RTDECL(void) RTLogLogger(PRTLOGGER pLogger, void *pvCallerRet, const char *pszFormat, ...) +{ + va_list args; + va_start(args, pszFormat); +#if defined(RT_OS_DARWIN) && defined(RT_ARCH_X86) && defined(IN_RING3) + /* manually align the stack before doing the call. + * We boldly assume that there is a stack frame here! */ + __asm__ __volatile__("andl $-32, %%esp\t\n" ::: "%esp"); + RTLogLoggerExV(pLogger, 0, ~0U, pszFormat, args); +#else + RTLogLoggerExV(pLogger, 0, ~0U, pszFormat, args); +#endif + va_end(args); + NOREF(pvCallerRet); +} +RT_EXPORT_SYMBOL(RTLogLogger); + + +/** + * Write to a logger instance. + * + * This function will check whether the instance, group and flags makes up a + * logging kind which is currently enabled before writing anything to the log. + * + * @param pLogger Pointer to logger instance. If NULL the default logger instance will be attempted. + * @param fFlags The logging flags. + * @param iGroup The group. + * The value ~0U is reserved for compatibility with RTLogLogger[V] and is + * only for internal usage! + * @param pszFormat Format string. + * @param ... Format arguments. + * @remark This is a worker function of LogIt. + */ +RTDECL(void) RTLogLoggerEx(PRTLOGGER pLogger, unsigned fFlags, unsigned iGroup, const char *pszFormat, ...) +{ + va_list args; + va_start(args, pszFormat); + RTLogLoggerExV(pLogger, fFlags, iGroup, pszFormat, args); + va_end(args); +} +RT_EXPORT_SYMBOL(RTLogLoggerEx); + + +/** + * printf like function for writing to the default log. + * + * @param pszFormat Printf like format string. + * @param ... Optional arguments as specified in pszFormat. + * + * @remark The API doesn't support formatting of floating point numbers at the moment. + */ +RTDECL(void) RTLogPrintf(const char *pszFormat, ...) +{ + va_list args; + va_start(args, pszFormat); + RTLogPrintfV(pszFormat, args); + va_end(args); +} +RT_EXPORT_SYMBOL(RTLogPrintf); + diff --git a/src/VBox/Runtime/common/log/logformat.cpp b/src/VBox/Runtime/common/log/logformat.cpp new file mode 100644 index 00000000..73792109 --- /dev/null +++ b/src/VBox/Runtime/common/log/logformat.cpp @@ -0,0 +1,100 @@ +/* $Id: logformat.cpp $ */ +/** @file + * IPRT - Log Formatter. + */ + +/* + * Copyright (C) 2006-2020 Oracle Corporation + * + * This file is part of VirtualBox Open Source Edition (OSE), as + * available from http://www.virtualbox.org. This file is free software; + * you can redistribute it and/or modify it under the terms of the GNU + * General Public License (GPL) as published by the Free Software + * Foundation, in version 2 as it comes in the "COPYING" file of the + * VirtualBox OSE distribution. VirtualBox OSE is distributed in the + * hope that it will be useful, but WITHOUT ANY WARRANTY of any kind. + * + * The contents of this file may alternatively be used under the terms + * of the Common Development and Distribution License Version 1.0 + * (CDDL) only, as it comes in the "COPYING.CDDL" file of the + * VirtualBox OSE distribution, in which case the provisions of the + * CDDL are applicable instead of those of the GPL. + * + * You may elect to license modified versions of this file under the + * terms and conditions of either the GPL or the CDDL or both. + */ + + +/********************************************************************************************************************************* +* Header Files * +*********************************************************************************************************************************/ +#include <iprt/log.h> +#include "internal/iprt.h" + +#include <iprt/string.h> +#include <iprt/assert.h> +#ifdef IN_RING3 +# include <iprt/thread.h> +# include <iprt/errcore.h> +#endif + +#include <iprt/stdarg.h> +#include <iprt/string.h> + + +/********************************************************************************************************************************* +* Internal Functions * +*********************************************************************************************************************************/ +static DECLCALLBACK(size_t) rtlogFormatStr(void *pvArg, PFNRTSTROUTPUT pfnOutput, + void *pvArgOutput, const char **ppszFormat, + va_list *pArgs, int cchWidth, int cchPrecision, + unsigned fFlags, char chArgSize); + + +/** + * Partial vsprintf worker implementation. + * + * @returns number of bytes formatted. + * @param pfnOutput Output worker. + * Called in two ways. Normally with a string an it's length. + * For termination, it's called with NULL for string, 0 for length. + * @param pvArg Argument to output worker. + * @param pszFormat Format string. + * @param args Argument list. + */ +RTDECL(size_t) RTLogFormatV(PFNRTSTROUTPUT pfnOutput, void *pvArg, const char *pszFormat, va_list args) +{ + return RTStrFormatV(pfnOutput, pvArg, rtlogFormatStr, NULL, pszFormat, args); +} +RT_EXPORT_SYMBOL(RTLogFormatV); + + +/** + * Callback to format VBox formatting extentions. + * See @ref pg_rt_str_format for a reference on the format types. + * + * @returns The number of bytes formatted. + * @param pvArg Formatter argument. + * @param pfnOutput Pointer to output function. + * @param pvArgOutput Argument for the output function. + * @param ppszFormat Pointer to the format string pointer. Advance this till the char + * after the format specifier. + * @param pArgs Pointer to the argument list. Use this to fetch the arguments. + * @param cchWidth Format Width. -1 if not specified. + * @param cchPrecision Format Precision. -1 if not specified. + * @param fFlags Flags (RTSTR_NTFS_*). + * @param chArgSize The argument size specifier, 'l' or 'L'. + */ +static DECLCALLBACK(size_t) rtlogFormatStr(void *pvArg, PFNRTSTROUTPUT pfnOutput, void *pvArgOutput, + const char **ppszFormat, va_list *pArgs, int cchWidth, + int cchPrecision, unsigned fFlags, char chArgSize) +{ + char ch = *(*ppszFormat)++; + + AssertMsgFailed(("Invalid logger format type '%%%c%.10s'!\n", ch, *ppszFormat)); NOREF(ch); + + NOREF(pvArg); NOREF(pfnOutput); NOREF(pvArgOutput); NOREF(pArgs); NOREF(cchWidth); + NOREF(cchPrecision); NOREF(fFlags); NOREF(chArgSize); + return 0; +} + diff --git a/src/VBox/Runtime/common/log/logrel.cpp b/src/VBox/Runtime/common/log/logrel.cpp new file mode 100644 index 00000000..db1f2388 --- /dev/null +++ b/src/VBox/Runtime/common/log/logrel.cpp @@ -0,0 +1,185 @@ +/* $Id: logrel.cpp $ */ +/** @file + * Runtime VBox - Release Logger. + */ + +/* + * Copyright (C) 2006-2020 Oracle Corporation + * + * This file is part of VirtualBox Open Source Edition (OSE), as + * available from http://www.virtualbox.org. This file is free software; + * you can redistribute it and/or modify it under the terms of the GNU + * General Public License (GPL) as published by the Free Software + * Foundation, in version 2 as it comes in the "COPYING" file of the + * VirtualBox OSE distribution. VirtualBox OSE is distributed in the + * hope that it will be useful, but WITHOUT ANY WARRANTY of any kind. + * + * The contents of this file may alternatively be used under the terms + * of the Common Development and Distribution License Version 1.0 + * (CDDL) only, as it comes in the "COPYING.CDDL" file of the + * VirtualBox OSE distribution, in which case the provisions of the + * CDDL are applicable instead of those of the GPL. + * + * You may elect to license modified versions of this file under the + * terms and conditions of either the GPL or the CDDL or both. + */ + + +/********************************************************************************************************************************* +* Header Files * +*********************************************************************************************************************************/ +#include <iprt/log.h> +#include "internal/iprt.h" + +#ifndef IN_RC +# include <iprt/alloc.h> +# include <iprt/process.h> +# include <iprt/semaphore.h> +# include <iprt/thread.h> +# include <iprt/mp.h> +#endif +#ifdef IN_RING3 +# include <iprt/file.h> +# include <iprt/path.h> +#endif +#include <iprt/time.h> +#include <iprt/asm.h> +#include <iprt/assert.h> +#include <iprt/errcore.h> +#include <iprt/param.h> + +#include <iprt/stdarg.h> +#include <iprt/string.h> +#include <iprt/ctype.h> +#ifdef IN_RING3 +# include <iprt/alloca.h> +# include <stdio.h> +#endif + + +/********************************************************************************************************************************* +* Global Variables * +*********************************************************************************************************************************/ +#ifdef IN_RC +/** Default release logger instance. */ +extern "C" DECLIMPORT(RTLOGGERRC) g_RelLogger; +#else /* !IN_RC */ +/** Default release logger instance. */ +static PRTLOGGER g_pRelLogger; +#endif /* !IN_RC */ + + +RTDECL(PRTLOGGER) RTLogRelGetDefaultInstance(void) +{ +#ifdef IN_RC + return &g_RelLogger; +#else /* !IN_RC */ + return g_pRelLogger; +#endif /* !IN_RC */ +} +RT_EXPORT_SYMBOL(RTLogRelGetDefaultInstance); + + +RTDECL(PRTLOGGER) RTLogRelGetDefaultInstanceEx(uint32_t fFlagsAndGroup) +{ +#ifdef IN_RC + PRTLOGGER pLogger = &g_RelLogger; +#else /* !IN_RC */ + PRTLOGGER pLogger = g_pRelLogger; +#endif /* !IN_RC */ + if (pLogger) + { + if (pLogger->fFlags & RTLOGFLAGS_DISABLED) + pLogger = NULL; + else + { + uint16_t const fFlags = RT_LO_U16(fFlagsAndGroup); + uint16_t const iGroup = RT_HI_U16(fFlagsAndGroup); + if ( iGroup != UINT16_MAX + && ( (pLogger->afGroups[iGroup < pLogger->cGroups ? iGroup : 0] & (fFlags | (uint32_t)RTLOGGRPFLAGS_ENABLED)) + != (fFlags | (uint32_t)RTLOGGRPFLAGS_ENABLED))) + pLogger = NULL; + } + } + return pLogger; +} +RT_EXPORT_SYMBOL(RTLogRelGetDefaultInstanceEx); + + +#ifndef IN_RC +/** + * Sets the default logger instance. + * + * @returns iprt status code. + * @param pLogger The new default release logger instance. + */ +RTDECL(PRTLOGGER) RTLogRelSetDefaultInstance(PRTLOGGER pLogger) +{ + return ASMAtomicXchgPtrT(&g_pRelLogger, pLogger, PRTLOGGER); +} +RT_EXPORT_SYMBOL(RTLogRelSetDefaultInstance); +#endif /* !IN_RC */ + + +/** + * Write to a logger instance, defaulting to the release one. + * + * This function will check whether the instance, group and flags makes up a + * logging kind which is currently enabled before writing anything to the log. + * + * @param pLogger Pointer to logger instance. If NULL the default release instance is attempted. + * @param fFlags The logging flags. + * @param iGroup The group. + * The value ~0U is reserved for compatibility with RTLogLogger[V] and is + * only for internal usage! + * @param pszFormat Format string. + * @param args Format arguments. + */ +RTDECL(void) RTLogRelLoggerV(PRTLOGGER pLogger, unsigned fFlags, unsigned iGroup, const char *pszFormat, va_list args) +{ + /* + * A NULL logger means default instance. + */ + if (!pLogger) + { + pLogger = RTLogRelGetDefaultInstance(); + if (!pLogger) + return; + } + RTLogLoggerExV(pLogger, fFlags, iGroup, pszFormat, args); +} +RT_EXPORT_SYMBOL(RTLogRelLoggerV); + + +/** + * vprintf like function for writing to the default release log. + * + * @param pszFormat Printf like format string. + * @param args Optional arguments as specified in pszFormat. + * + * @remark The API doesn't support formatting of floating point numbers at the moment. + */ +RTDECL(void) RTLogRelPrintfV(const char *pszFormat, va_list args) +{ + RTLogRelLoggerV(NULL, 0, ~0U, pszFormat, args); +} +RT_EXPORT_SYMBOL(RTLogRelPrintfV); + + +/** + * Changes the buffering setting of the default release logger. + * + * This can be used for optimizing longish logging sequences. + * + * @returns The old state. + * @param fBuffered The new state. + */ +RTDECL(bool) RTLogRelSetBuffering(bool fBuffered) +{ + PRTLOGGER pLogger = RTLogRelGetDefaultInstance(); + if (pLogger) + return RTLogSetBuffering(pLogger, fBuffered); + return false; +} +RT_EXPORT_SYMBOL(RTLogRelSetBuffering); + diff --git a/src/VBox/Runtime/common/log/logrelellipsis.cpp b/src/VBox/Runtime/common/log/logrelellipsis.cpp new file mode 100644 index 00000000..478d1179 --- /dev/null +++ b/src/VBox/Runtime/common/log/logrelellipsis.cpp @@ -0,0 +1,78 @@ +/* $Id: logrelellipsis.cpp $ */ +/** @file + * Runtime VBox - Logger, the release ellipsis variants. + */ + +/* + * Copyright (C) 2006-2020 Oracle Corporation + * + * This file is part of VirtualBox Open Source Edition (OSE), as + * available from http://www.virtualbox.org. This file is free software; + * you can redistribute it and/or modify it under the terms of the GNU + * General Public License (GPL) as published by the Free Software + * Foundation, in version 2 as it comes in the "COPYING" file of the + * VirtualBox OSE distribution. VirtualBox OSE is distributed in the + * hope that it will be useful, but WITHOUT ANY WARRANTY of any kind. + * + * The contents of this file may alternatively be used under the terms + * of the Common Development and Distribution License Version 1.0 + * (CDDL) only, as it comes in the "COPYING.CDDL" file of the + * VirtualBox OSE distribution, in which case the provisions of the + * CDDL are applicable instead of those of the GPL. + * + * You may elect to license modified versions of this file under the + * terms and conditions of either the GPL or the CDDL or both. + */ + + +/********************************************************************************************************************************* +* Header Files * +*********************************************************************************************************************************/ +#include <iprt/log.h> +#include "internal/iprt.h" + +#include <iprt/stdarg.h> + + +/** + * Write to a logger instance, defaulting to the release one. + * + * This function will check whether the instance, group and flags makes up a + * logging kind which is currently enabled before writing anything to the log. + * + * @param pLogger Pointer to logger instance. + * @param fFlags The logging flags. + * @param iGroup The group. + * The value ~0U is reserved for compatibility with RTLogLogger[V] and is + * only for internal usage! + * @param pszFormat Format string. + * @param ... Format arguments. + * @remark This is a worker function for LogRelIt. + */ +RTDECL(void) RTLogRelLogger(PRTLOGGER pLogger, unsigned fFlags, unsigned iGroup, const char *pszFormat, ...) +{ + va_list args; + va_start(args, pszFormat); + RTLogRelLoggerV(pLogger, fFlags, iGroup, pszFormat, args); + va_end(args); +} +RT_EXPORT_SYMBOL(RTLogRelLogger); + + +/** + * printf like function for writing to the default release log. + * + * @param pszFormat Printf like format string. + * @param ... Optional arguments as specified in pszFormat. + * + * @remark The API doesn't support formatting of floating point numbers at the moment. + */ +RTDECL(void) RTLogRelPrintf(const char *pszFormat, ...) +{ + va_list args; + va_start(args, pszFormat); + RTLogRelPrintfV(pszFormat, args); + va_end(args); +} +RT_EXPORT_SYMBOL(RTLogRelPrintf); + diff --git a/src/VBox/Runtime/common/log/tracebuf.cpp b/src/VBox/Runtime/common/log/tracebuf.cpp new file mode 100644 index 00000000..601f7e4d --- /dev/null +++ b/src/VBox/Runtime/common/log/tracebuf.cpp @@ -0,0 +1,688 @@ +/* $Id: tracebuf.cpp $ */ +/** @file + * IPRT - Tracebuffer common functions. + */ + +/* + * Copyright (C) 2011-2020 Oracle Corporation + * + * This file is part of VirtualBox Open Source Edition (OSE), as + * available from http://www.virtualbox.org. This file is free software; + * you can redistribute it and/or modify it under the terms of the GNU + * General Public License (GPL) as published by the Free Software + * Foundation, in version 2 as it comes in the "COPYING" file of the + * VirtualBox OSE distribution. VirtualBox OSE is distributed in the + * hope that it will be useful, but WITHOUT ANY WARRANTY of any kind. + * + * The contents of this file may alternatively be used under the terms + * of the Common Development and Distribution License Version 1.0 + * (CDDL) only, as it comes in the "COPYING.CDDL" file of the + * VirtualBox OSE distribution, in which case the provisions of the + * CDDL are applicable instead of those of the GPL. + * + * You may elect to license modified versions of this file under the + * terms and conditions of either the GPL or the CDDL or both. + */ + + +/********************************************************************************************************************************* +* Header Files * +*********************************************************************************************************************************/ +#include "internal/iprt.h" +#include <iprt/trace.h> + + +#include <iprt/assert.h> +#include <iprt/asm.h> +#include <iprt/errcore.h> +#include <iprt/log.h> +#ifndef IN_RC +# include <iprt/mem.h> +#endif +#include <iprt/mp.h> +#if defined(RT_ARCH_AMD64) || defined(RT_ARCH_X86) +# include <iprt/asm-amd64-x86.h> +#endif +#include <iprt/path.h> +#include <iprt/string.h> +#include <iprt/time.h> + +#include "internal/magics.h" + + +/********************************************************************************************************************************* +* Structures and Typedefs * +*********************************************************************************************************************************/ +/** Alignment used to place the trace buffer members, this should be a multiple + * of the cache line size if possible. (We should dynamically determine it.) */ +#define RTTRACEBUF_ALIGNMENT 64 +AssertCompile(RTTRACEBUF_ALIGNMENT >= sizeof(uint64_t) * 2); + +/** The maximum number of entries. */ +#define RTTRACEBUF_MAX_ENTRIES _64K +/** The minimum number of entries. */ +#define RTTRACEBUF_MIN_ENTRIES 4 +/** The default number of entries. */ +#define RTTRACEBUF_DEF_ENTRIES 256 + +/** The maximum entry size. */ +#define RTTRACEBUF_MAX_ENTRY_SIZE _1M +/** The minimum entry size. */ +#define RTTRACEBUF_MIN_ENTRY_SIZE RTTRACEBUF_ALIGNMENT +/** The default entry size. */ +#define RTTRACEBUF_DEF_ENTRY_SIZE 256 +AssertCompile(!(RTTRACEBUF_DEF_ENTRY_SIZE & (RTTRACEBUF_DEF_ENTRY_SIZE - 1))); + +/** + * The volatile trace buffer members. + */ +typedef struct RTTRACEBUFVOLATILE +{ + /** Reference counter. */ + uint32_t volatile cRefs; + /** The next entry to make use of. */ + uint32_t volatile iEntry; +} RTTRACEBUFVOLATILE; +/** Pointer to the volatile parts of a trace buffer. */ +typedef RTTRACEBUFVOLATILE *PRTTRACEBUFVOLATILE; + + +/** + * Trace buffer entry. + */ +typedef struct RTTRACEBUFENTRY +{ + /** The nano second entry time stamp. */ + uint64_t NanoTS; + /** The ID of the CPU the event was recorded. */ + RTCPUID idCpu; + /** The message. */ + char szMsg[RTTRACEBUF_ALIGNMENT - sizeof(uint64_t) - sizeof(RTCPUID)]; +} RTTRACEBUFENTRY; +AssertCompile(sizeof(RTTRACEBUFENTRY) <= RTTRACEBUF_ALIGNMENT); +/** Pointer to a trace buffer entry. */ +typedef RTTRACEBUFENTRY *PRTTRACEBUFENTRY; + + + +/** + * Trace buffer structure. + * + * @remarks This structure must be context agnostic, i.e. no pointers or + * other types that may differ between contexts (R3/R0/RC). + */ +typedef struct RTTRACEBUFINT +{ + /** Magic value (RTTRACEBUF_MAGIC). */ + uint32_t u32Magic; + /** The entry size. */ + uint32_t cbEntry; + /** The number of entries. */ + uint32_t cEntries; + /** Flags (always zero for now). */ + uint32_t fFlags; + /** The offset to the volatile members (RTTRACEBUFVOLATILE) (relative to + * the start of this structure). */ + uint32_t offVolatile; + /** The offset to the entries (relative to the start of this structure). */ + uint32_t offEntries; + /** Reserved entries. */ + uint32_t au32Reserved[2]; +} RTTRACEBUFINT; +/** Pointer to a const trace buffer. */ +typedef RTTRACEBUFINT const *PCRTTRACEBUFINT; + + +/********************************************************************************************************************************* +* Defined Constants And Macros * +*********************************************************************************************************************************/ +/** + * Get the current CPU Id. + */ +#if defined(IN_RING0) \ + || defined(RT_OS_WINDOWS) \ + || (!defined(RT_ARCH_AMD64) && !defined(RT_ARCH_X86)) +# define RTTRACEBUF_CUR_CPU() RTMpCpuId() +#else +# define RTTRACEBUF_CUR_CPU() ASMGetApicId() /** @todo this isn't good enough for big boxes with lots of CPUs/cores. */ +#endif + +/** Calculates the address of the volatile trace buffer members. */ +#define RTTRACEBUF_TO_VOLATILE(a_pThis) ((PRTTRACEBUFVOLATILE)((uint8_t *)(a_pThis) + (a_pThis)->offVolatile)) + +/** Calculates the address of a trace buffer entry. */ +#define RTTRACEBUF_TO_ENTRY(a_pThis, a_iEntry) \ + ((PRTTRACEBUFENTRY)( (uint8_t *)(a_pThis) + (a_pThis)->offEntries + (a_iEntry) * (a_pThis)->cbEntry )) + +/** Validates a trace buffer handle and returns rc if not valid. */ +#define RTTRACEBUF_VALID_RETURN_RC(a_pThis, a_rc) \ + do { \ + AssertPtrReturn((a_pThis), (a_rc)); \ + AssertReturn((a_pThis)->u32Magic == RTTRACEBUF_MAGIC, (a_rc)); \ + AssertReturn((a_pThis)->offVolatile < RTTRACEBUF_ALIGNMENT * 2, (a_rc)); \ + AssertReturn(RTTRACEBUF_TO_VOLATILE(a_pThis)->cRefs > 0, (a_rc)); \ + } while (0) + +/** + * Resolves and validates a trace buffer handle and returns rc if not valid. + * + * @param a_hTraceBuf The trace buffer handle passed by the user. + * @param a_pThis Where to store the trace buffer pointer. + */ +#define RTTRACEBUF_RESOLVE_VALIDATE_RETAIN_RETURN(a_hTraceBuf, a_pThis) \ + do { \ + uint32_t cRefs; \ + if ((a_hTraceBuf) == RTTRACEBUF_DEFAULT) \ + { \ + (a_pThis) = RTTraceGetDefaultBuf(); \ + if (!RT_VALID_PTR(a_pThis)) \ + return VERR_NOT_FOUND; \ + } \ + else \ + { \ + (a_pThis) = (a_hTraceBuf); \ + AssertPtrReturn((a_pThis), VERR_INVALID_HANDLE); \ + } \ + AssertReturn((a_pThis)->u32Magic == RTTRACEBUF_MAGIC, VERR_INVALID_HANDLE); \ + AssertReturn((a_pThis)->offVolatile < RTTRACEBUF_ALIGNMENT * 2, VERR_INVALID_HANDLE); \ + \ + cRefs = ASMAtomicIncU32(&RTTRACEBUF_TO_VOLATILE(a_pThis)->cRefs); \ + if (RT_UNLIKELY(cRefs < 1 || cRefs >= _1M)) \ + { \ + ASMAtomicDecU32(&RTTRACEBUF_TO_VOLATILE(a_pThis)->cRefs); \ + AssertFailedReturn(VERR_INVALID_HANDLE); \ + } \ + } while (0) + + +/** + * Drops a trace buffer reference. + * + * @param a_pThis Pointer to the trace buffer. + */ +#define RTTRACEBUF_DROP_REFERENCE(a_pThis) \ + do { \ + uint32_t cRefs = ASMAtomicDecU32(&RTTRACEBUF_TO_VOLATILE(a_pThis)->cRefs); \ + if (!cRefs) \ + rtTraceBufDestroy((RTTRACEBUFINT *)a_pThis); \ + } while (0) + + +/** + * The prologue code for a RTTraceAddSomething function. + * + * Resolves a trace buffer handle, grabs a reference to it and allocates the + * next entry. Return with an appropriate error status on failure. + * + * @param a_hTraceBuf The trace buffer handle passed by the user. + * + * @remarks This is kind of ugly, sorry. + */ +#define RTTRACEBUF_ADD_PROLOGUE(a_hTraceBuf) \ + int rc; \ + uint32_t cRefs; \ + uint32_t iEntry; \ + PCRTTRACEBUFINT pThis; \ + PRTTRACEBUFVOLATILE pVolatile; \ + PRTTRACEBUFENTRY pEntry; \ + char *pszBuf; \ + size_t cchBuf; \ + \ + /* Resolve and validate the handle. */ \ + if ((a_hTraceBuf) == RTTRACEBUF_DEFAULT) \ + { \ + pThis = RTTraceGetDefaultBuf(); \ + if (!RT_VALID_PTR(pThis)) \ + return VERR_NOT_FOUND; \ + } \ + else if ((a_hTraceBuf) != NIL_RTTRACEBUF) \ + { \ + pThis = (a_hTraceBuf); \ + AssertPtrReturn(pThis, VERR_INVALID_HANDLE); \ + } \ + else \ + return VERR_INVALID_HANDLE; \ + \ + AssertReturn(pThis->u32Magic == RTTRACEBUF_MAGIC, VERR_INVALID_HANDLE); \ + if (pThis->fFlags & RTTRACEBUF_FLAGS_DISABLED) \ + return VINF_SUCCESS; \ + AssertReturn(pThis->offVolatile < RTTRACEBUF_ALIGNMENT * 2, VERR_INVALID_HANDLE); \ + pVolatile = RTTRACEBUF_TO_VOLATILE(pThis); \ + \ + /* Grab a reference. */ \ + cRefs = ASMAtomicIncU32(&pVolatile->cRefs); \ + if (RT_UNLIKELY(cRefs < 1 || cRefs >= _1M)) \ + { \ + ASMAtomicDecU32(&pVolatile->cRefs); \ + AssertFailedReturn(VERR_INVALID_HANDLE); \ + } \ + \ + /* Grab the next entry and set the time stamp. */ \ + iEntry = ASMAtomicIncU32(&pVolatile->iEntry) - 1; \ + iEntry %= pThis->cEntries; \ + pEntry = RTTRACEBUF_TO_ENTRY(pThis, iEntry); \ + pEntry->NanoTS = RTTimeNanoTS(); \ + pEntry->idCpu = RTTRACEBUF_CUR_CPU(); \ + pszBuf = &pEntry->szMsg[0]; \ + *pszBuf = '\0'; \ + cchBuf = pThis->cbEntry - RT_UOFFSETOF(RTTRACEBUFENTRY, szMsg) - 1; \ + rc = VINF_SUCCESS + + +/** + * Used by a RTTraceAddPosSomething to store the source position in the entry + * prior to adding the actual trace message text. + * + * Both pszBuf and cchBuf will be adjusted such that pszBuf points and the zero + * terminator after the source position part. + */ +#define RTTRACEBUF_ADD_STORE_SRC_POS() \ + do { \ + /* file(line): - no path */ \ + size_t cchPos = RTStrPrintf(pszBuf, cchBuf, "%s(%d): ", RTPathFilename(pszFile), iLine); \ + pszBuf += cchPos; \ + cchBuf -= cchPos; \ + NOREF(pszFunction); \ + } while (0) + + +/** + * The epilogue code for a RTTraceAddSomething function. + * + * This will release the trace buffer reference. + */ +#define RTTRACEBUF_ADD_EPILOGUE() \ + cRefs = ASMAtomicDecU32(&pVolatile->cRefs); \ + if (!cRefs) \ + rtTraceBufDestroy((RTTRACEBUFINT *)pThis); \ + return rc + + +#ifndef IN_RC /* Drop this in RC context (too lazy to split the file). */ + +RTDECL(int) RTTraceBufCreate(PRTTRACEBUF phTraceBuf, uint32_t cEntries, uint32_t cbEntry, uint32_t fFlags) +{ + AssertPtrReturn(phTraceBuf, VERR_INVALID_POINTER); + AssertReturn(!(fFlags & ~(RTTRACEBUF_FLAGS_MASK & ~ RTTRACEBUF_FLAGS_FREE_ME)), VERR_INVALID_PARAMETER); + AssertMsgReturn(cbEntry <= RTTRACEBUF_MAX_ENTRIES, ("%#x\n", cbEntry), VERR_OUT_OF_RANGE); + AssertMsgReturn(cEntries <= RTTRACEBUF_MAX_ENTRY_SIZE, ("%#x\n", cEntries), VERR_OUT_OF_RANGE); + + /* + * Apply default and alignment adjustments. + */ + if (!cbEntry) + cbEntry = RTTRACEBUF_DEF_ENTRY_SIZE; + else + cbEntry = RT_ALIGN_32(cbEntry, RTTRACEBUF_ALIGNMENT); + + if (!cEntries) + cEntries = RTTRACEBUF_DEF_ENTRIES; + else if (cEntries < RTTRACEBUF_MIN_ENTRIES) + cEntries = RTTRACEBUF_MIN_ENTRIES; + + /* + * Calculate the required buffer size, allocte it and hand it on to the + * carver API. + */ + size_t cbBlock = cbEntry * cEntries + + RT_ALIGN_Z(sizeof(RTTRACEBUFINT), RTTRACEBUF_ALIGNMENT) + + RT_ALIGN_Z(sizeof(RTTRACEBUFVOLATILE), RTTRACEBUF_ALIGNMENT); + void *pvBlock = RTMemAlloc(cbBlock); + if (!((uintptr_t)pvBlock & (RTTRACEBUF_ALIGNMENT - 1))) + { + RTMemFree(pvBlock); + cbBlock += RTTRACEBUF_ALIGNMENT - 1; + pvBlock = RTMemAlloc(cbBlock); + } + int rc; + if (pvBlock) + { + rc = RTTraceBufCarve(phTraceBuf, cEntries, cbEntry, fFlags, pvBlock, &cbBlock); + if (RT_FAILURE(rc)) + RTMemFree(pvBlock); + } + else + rc = VERR_NO_MEMORY; + return rc; +} + + +RTDECL(int) RTTraceBufCarve(PRTTRACEBUF phTraceBuf, uint32_t cEntries, uint32_t cbEntry, uint32_t fFlags, + void *pvBlock, size_t *pcbBlock) +{ + AssertPtrReturn(phTraceBuf, VERR_INVALID_POINTER); + AssertReturn(!(fFlags & ~RTTRACEBUF_FLAGS_MASK), VERR_INVALID_PARAMETER); + AssertMsgReturn(cbEntry <= RTTRACEBUF_MAX_ENTRIES, ("%#x\n", cbEntry), VERR_OUT_OF_RANGE); + AssertMsgReturn(cEntries <= RTTRACEBUF_MAX_ENTRY_SIZE, ("%#x\n", cEntries), VERR_OUT_OF_RANGE); + AssertPtrReturn(pcbBlock, VERR_INVALID_POINTER); + size_t const cbBlock = *pcbBlock; + AssertReturn(RT_VALID_PTR(pvBlock) || !cbBlock, VERR_INVALID_POINTER); + + /* + * Apply defaults, align sizes and check against available buffer space. + * This code can be made a bit more clever, if someone feels like it. + */ + size_t const cbHdr = RT_ALIGN_Z(sizeof(RTTRACEBUFINT), RTTRACEBUF_ALIGNMENT) + + RT_ALIGN_Z(sizeof(RTTRACEBUFVOLATILE), RTTRACEBUF_ALIGNMENT); + size_t const cbEntryBuf = cbBlock > cbHdr ? cbBlock - cbHdr : 0; + if (cbEntry) + cbEntry = RT_ALIGN_32(cbEntry, RTTRACEBUF_ALIGNMENT); + else + { + if (!cbEntryBuf) + { + cbEntry = RTTRACEBUF_DEF_ENTRY_SIZE; + cEntries = RTTRACEBUF_DEF_ENTRIES; + } + else if (cEntries) + { + size_t cbEntryZ = cbBlock / cEntries; + cbEntryZ &= ~(RTTRACEBUF_ALIGNMENT - 1); + if (cbEntryZ > RTTRACEBUF_MAX_ENTRIES) + cbEntryZ = RTTRACEBUF_MAX_ENTRIES; + cbEntry = (uint32_t)cbEntryZ; + } + else if (cbBlock >= RT_ALIGN_32(512, RTTRACEBUF_ALIGNMENT) * 256) + cbEntry = RT_ALIGN_32(512, RTTRACEBUF_ALIGNMENT); + else if (cbBlock >= RT_ALIGN_32(256, RTTRACEBUF_ALIGNMENT) * 64) + cbEntry = RT_ALIGN_32(256, RTTRACEBUF_ALIGNMENT); + else if (cbBlock >= RT_ALIGN_32(128, RTTRACEBUF_ALIGNMENT) * 32) + cbEntry = RT_ALIGN_32(128, RTTRACEBUF_ALIGNMENT); + else + cbEntry = sizeof(RTTRACEBUFENTRY); + } + Assert(RT_ALIGN_32(cbEntry, RTTRACEBUF_ALIGNMENT) == cbEntry); + + if (!cEntries) + { + size_t cEntriesZ = cbEntryBuf / cbEntry; + if (cEntriesZ > RTTRACEBUF_MAX_ENTRIES) + cEntriesZ = RTTRACEBUF_MAX_ENTRIES; + cEntries = (uint32_t)cEntriesZ; + } + if (cEntries < RTTRACEBUF_MIN_ENTRIES) + cEntries = RTTRACEBUF_MIN_ENTRIES; + + uint32_t offVolatile = RTTRACEBUF_ALIGNMENT - ((uintptr_t)pvBlock & (RTTRACEBUF_ALIGNMENT - 1)); + if (offVolatile < sizeof(RTTRACEBUFINT)) + offVolatile += RTTRACEBUF_ALIGNMENT; + size_t cbReqBlock = offVolatile + + RT_ALIGN_Z(sizeof(RTTRACEBUFVOLATILE), RTTRACEBUF_ALIGNMENT) + + cbEntry * cEntries; + if (*pcbBlock < cbReqBlock) + { + *pcbBlock = cbReqBlock; + return VERR_BUFFER_OVERFLOW; + } + + /* + * Do the carving. + */ + memset(pvBlock, 0, cbBlock); + + RTTRACEBUFINT *pThis = (RTTRACEBUFINT *)pvBlock; + pThis->u32Magic = RTTRACEBUF_MAGIC; + pThis->cbEntry = cbEntry; + pThis->cEntries = cEntries; + pThis->fFlags = fFlags; + pThis->offVolatile = offVolatile; + pThis->offEntries = offVolatile + RT_ALIGN_Z(sizeof(RTTRACEBUFVOLATILE), RTTRACEBUF_ALIGNMENT); + + PRTTRACEBUFVOLATILE pVolatile = (PRTTRACEBUFVOLATILE)((uint8_t *)pThis + offVolatile); + pVolatile->cRefs = 1; + pVolatile->iEntry = 0; + + *pcbBlock = cbBlock - cbReqBlock; + *phTraceBuf = pThis; + return VINF_SUCCESS; +} + +#endif /* !IN_RC */ + + +/** + * Destructor. + * + * @param pThis The trace buffer to destroy. + */ +static void rtTraceBufDestroy(RTTRACEBUFINT *pThis) +{ + AssertReturnVoid(ASMAtomicCmpXchgU32(&pThis->u32Magic, RTTRACEBUF_MAGIC_DEAD, RTTRACEBUF_MAGIC)); + if (pThis->fFlags & RTTRACEBUF_FLAGS_FREE_ME) + { +#ifdef IN_RC + AssertReleaseFailed(); +#else + RTMemFree(pThis); +#endif + } +} + + +RTDECL(uint32_t) RTTraceBufRetain(RTTRACEBUF hTraceBuf) +{ + PCRTTRACEBUFINT pThis = hTraceBuf; + RTTRACEBUF_VALID_RETURN_RC(pThis, UINT32_MAX); + return ASMAtomicIncU32(&RTTRACEBUF_TO_VOLATILE(pThis)->cRefs); +} + + +RTDECL(uint32_t) RTTraceBufRelease(RTTRACEBUF hTraceBuf) +{ + if (hTraceBuf == NIL_RTTRACEBUF) + return 0; + + PCRTTRACEBUFINT pThis = hTraceBuf; + RTTRACEBUF_VALID_RETURN_RC(pThis, UINT32_MAX); + + uint32_t cRefs = ASMAtomicDecU32(&RTTRACEBUF_TO_VOLATILE(pThis)->cRefs); + if (!cRefs) + rtTraceBufDestroy((RTTRACEBUFINT *)pThis); + return cRefs; +} + + +RTDECL(int) RTTraceBufAddMsg(RTTRACEBUF hTraceBuf, const char *pszMsg) +{ + RTTRACEBUF_ADD_PROLOGUE(hTraceBuf); + RTStrCopy(pszBuf, cchBuf, pszMsg); + RTTRACEBUF_ADD_EPILOGUE(); +} + + +RTDECL(int) RTTraceBufAddMsgEx( RTTRACEBUF hTraceBuf, const char *pszMsg, size_t cbMaxMsg) +{ + RTTRACEBUF_ADD_PROLOGUE(hTraceBuf); + RTStrCopyEx(pszBuf, cchBuf, pszMsg, cbMaxMsg); + RTTRACEBUF_ADD_EPILOGUE(); +} + + +RTDECL(int) RTTraceBufAddMsgF(RTTRACEBUF hTraceBuf, const char *pszMsgFmt, ...) +{ + int rc; + va_list va; + va_start(va, pszMsgFmt); + rc = RTTraceBufAddMsgV(hTraceBuf, pszMsgFmt, va); + va_end(va); + return rc; +} + + +RTDECL(int) RTTraceBufAddMsgV(RTTRACEBUF hTraceBuf, const char *pszMsgFmt, va_list va) +{ + RTTRACEBUF_ADD_PROLOGUE(hTraceBuf); + RTStrPrintfV(pszBuf, cchBuf, pszMsgFmt, va); + RTTRACEBUF_ADD_EPILOGUE(); +} + + +RTDECL(int) RTTraceBufAddPos(RTTRACEBUF hTraceBuf, RT_SRC_POS_DECL) +{ + RTTRACEBUF_ADD_PROLOGUE(hTraceBuf); + RTTRACEBUF_ADD_STORE_SRC_POS(); + RTTRACEBUF_ADD_EPILOGUE(); +} + + +RTDECL(int) RTTraceBufAddPosMsg(RTTRACEBUF hTraceBuf, RT_SRC_POS_DECL, const char *pszMsg) +{ + RTTRACEBUF_ADD_PROLOGUE(hTraceBuf); + RTTRACEBUF_ADD_STORE_SRC_POS(); + RTStrCopy(pszBuf, cchBuf, pszMsg); + RTTRACEBUF_ADD_EPILOGUE(); +} + + +RTDECL(int) RTTraceBufAddPosMsgEx(RTTRACEBUF hTraceBuf, RT_SRC_POS_DECL, const char *pszMsg, size_t cbMaxMsg) +{ + RTTRACEBUF_ADD_PROLOGUE(hTraceBuf); + RTTRACEBUF_ADD_STORE_SRC_POS(); + RTStrCopyEx(pszBuf, cchBuf, pszMsg, cbMaxMsg); + RTTRACEBUF_ADD_EPILOGUE(); +} + + +RTDECL(int) RTTraceBufAddPosMsgF(RTTRACEBUF hTraceBuf, RT_SRC_POS_DECL, const char *pszMsgFmt, ...) +{ + int rc; + va_list va; + va_start(va, pszMsgFmt); + rc = RTTraceBufAddPosMsgV(hTraceBuf, RT_SRC_POS_ARGS, pszMsgFmt, va); + va_end(va); + return rc; +} + + +RTDECL(int) RTTraceBufAddPosMsgV(RTTRACEBUF hTraceBuf, RT_SRC_POS_DECL, const char *pszMsgFmt, va_list va) +{ + RTTRACEBUF_ADD_PROLOGUE(hTraceBuf); + RTTRACEBUF_ADD_STORE_SRC_POS(); + RTStrPrintfV(pszBuf, cchBuf, pszMsgFmt, va); + RTTRACEBUF_ADD_EPILOGUE(); +} + + +RTDECL(int) RTTraceBufEnumEntries(RTTRACEBUF hTraceBuf, PFNRTTRACEBUFCALLBACK pfnCallback, void *pvUser) +{ + int rc = VINF_SUCCESS; + uint32_t iBase; + uint32_t cLeft; + PCRTTRACEBUFINT pThis; + RTTRACEBUF_RESOLVE_VALIDATE_RETAIN_RETURN(hTraceBuf, pThis); + + iBase = ASMAtomicReadU32(&RTTRACEBUF_TO_VOLATILE(pThis)->iEntry); + cLeft = pThis->cEntries; + while (cLeft--) + { + PRTTRACEBUFENTRY pEntry; + + iBase %= pThis->cEntries; + pEntry = RTTRACEBUF_TO_ENTRY(pThis, iBase); + if (pEntry->NanoTS) + { + rc = pfnCallback((RTTRACEBUF)pThis, cLeft, pEntry->NanoTS, pEntry->idCpu, pEntry->szMsg, pvUser); + if (rc != VINF_SUCCESS) + break; + } + + /* next */ + iBase += 1; + } + + RTTRACEBUF_DROP_REFERENCE(pThis); + return rc; +} + + +RTDECL(uint32_t) RTTraceBufGetEntrySize(RTTRACEBUF hTraceBuf) +{ + PCRTTRACEBUFINT pThis = hTraceBuf; + RTTRACEBUF_VALID_RETURN_RC(pThis, 0); + return pThis->cbEntry; +} + + +RTDECL(uint32_t) RTTraceBufGetEntryCount(RTTRACEBUF hTraceBuf) +{ + PCRTTRACEBUFINT pThis = hTraceBuf; + RTTRACEBUF_VALID_RETURN_RC(pThis, 0); + return pThis->cEntries; +} + + +RTDECL(bool) RTTraceBufDisable(RTTRACEBUF hTraceBuf) +{ + PCRTTRACEBUFINT pThis = hTraceBuf; + RTTRACEBUF_VALID_RETURN_RC(pThis, false); + return !ASMAtomicBitTestAndSet((void volatile *)&pThis->fFlags, RTTRACEBUF_FLAGS_DISABLED_BIT); +} + + +RTDECL(bool) RTTraceBufEnable(RTTRACEBUF hTraceBuf) +{ + PCRTTRACEBUFINT pThis = hTraceBuf; + RTTRACEBUF_VALID_RETURN_RC(pThis, false); + return !ASMAtomicBitTestAndClear((void volatile *)&pThis->fFlags, RTTRACEBUF_FLAGS_DISABLED_BIT); +} + + +/* + * + * Move the following to a separate file, consider using the enumerator. + * + */ + +RTDECL(int) RTTraceBufDumpToLog(RTTRACEBUF hTraceBuf) +{ + uint32_t iBase; + uint32_t cLeft; + PCRTTRACEBUFINT pThis; + RTTRACEBUF_RESOLVE_VALIDATE_RETAIN_RETURN(hTraceBuf, pThis); + + iBase = ASMAtomicReadU32(&RTTRACEBUF_TO_VOLATILE(pThis)->iEntry); + cLeft = pThis->cEntries; + while (cLeft--) + { + PRTTRACEBUFENTRY pEntry; + + iBase %= pThis->cEntries; + pEntry = RTTRACEBUF_TO_ENTRY(pThis, iBase); + if (pEntry->NanoTS) + RTLogPrintf("%04u/%'llu/%02x: %s\n", cLeft, pEntry->NanoTS, pEntry->idCpu, pEntry->szMsg); + + /* next */ + iBase += 1; + } + + RTTRACEBUF_DROP_REFERENCE(pThis); + return VINF_SUCCESS; +} + + +RTDECL(int) RTTraceBufDumpToAssert(RTTRACEBUF hTraceBuf) +{ + uint32_t iBase; + uint32_t cLeft; + PCRTTRACEBUFINT pThis; + RTTRACEBUF_RESOLVE_VALIDATE_RETAIN_RETURN(hTraceBuf, pThis); + + iBase = ASMAtomicReadU32(&RTTRACEBUF_TO_VOLATILE(pThis)->iEntry); + cLeft = pThis->cEntries; + while (cLeft--) + { + PRTTRACEBUFENTRY pEntry; + + iBase %= pThis->cEntries; + pEntry = RTTRACEBUF_TO_ENTRY(pThis, iBase); + if (pEntry->NanoTS) + RTAssertMsg2AddWeak("%u/%'llu/%02x: %s\n", cLeft, pEntry->NanoTS, pEntry->idCpu, pEntry->szMsg); + + /* next */ + iBase += 1; + } + + RTTRACEBUF_DROP_REFERENCE(pThis); + return VINF_SUCCESS; +} + diff --git a/src/VBox/Runtime/common/log/tracedefault.cpp b/src/VBox/Runtime/common/log/tracedefault.cpp new file mode 100644 index 00000000..12fce63a --- /dev/null +++ b/src/VBox/Runtime/common/log/tracedefault.cpp @@ -0,0 +1,82 @@ +/* $Id: tracedefault.cpp $ */ +/** @file + * IPRT - Tracebuffer common functions. + */ + +/* + * Copyright (C) 2011-2020 Oracle Corporation + * + * This file is part of VirtualBox Open Source Edition (OSE), as + * available from http://www.virtualbox.org. This file is free software; + * you can redistribute it and/or modify it under the terms of the GNU + * General Public License (GPL) as published by the Free Software + * Foundation, in version 2 as it comes in the "COPYING" file of the + * VirtualBox OSE distribution. VirtualBox OSE is distributed in the + * hope that it will be useful, but WITHOUT ANY WARRANTY of any kind. + * + * The contents of this file may alternatively be used under the terms + * of the Common Development and Distribution License Version 1.0 + * (CDDL) only, as it comes in the "COPYING.CDDL" file of the + * VirtualBox OSE distribution, in which case the provisions of the + * CDDL are applicable instead of those of the GPL. + * + * You may elect to license modified versions of this file under the + * terms and conditions of either the GPL or the CDDL or both. + */ + + +/********************************************************************************************************************************* +* Header Files * +*********************************************************************************************************************************/ +#include "internal/iprt.h" +#include <iprt/trace.h> + +#include <iprt/asm.h> +#include <iprt/errcore.h> +#include <iprt/thread.h> + + +/********************************************************************************************************************************* +* Global Variables * +*********************************************************************************************************************************/ +/** The default trace buffer handle. */ +static RTTRACEBUF g_hDefaultTraceBuf = NIL_RTTRACEBUF; + + + +RTDECL(int) RTTraceSetDefaultBuf(RTTRACEBUF hTraceBuf) +{ + /* Retain the new buffer. */ + if (hTraceBuf != NIL_RTTRACEBUF) + { + uint32_t cRefs = RTTraceBufRetain(hTraceBuf); + if (cRefs >= _1M) + return VERR_INVALID_HANDLE; + } + + RTTRACEBUF hOldTraceBuf; +#ifdef IN_RC + hOldTraceBuf = (RTTRACEBUF)ASMAtomicXchgPtr((void **)&g_hDefaultTraceBuf, hTraceBuf); +#else + ASMAtomicXchgHandle(&g_hDefaultTraceBuf, hTraceBuf, &hOldTraceBuf); +#endif + + if ( hOldTraceBuf != NIL_RTTRACEBUF + && hOldTraceBuf != hTraceBuf) + { + /* Race prevention kludge. */ +#ifndef IN_RC + RTThreadSleep(33); +#endif + RTTraceBufRelease(hOldTraceBuf); + } + + return VINF_SUCCESS; +} + + +RTDECL(RTTRACEBUF) RTTraceGetDefaultBuf(void) +{ + return g_hDefaultTraceBuf; +} + diff --git a/src/VBox/Runtime/common/log/tracelogreader.cpp b/src/VBox/Runtime/common/log/tracelogreader.cpp new file mode 100644 index 00000000..9bddce14 --- /dev/null +++ b/src/VBox/Runtime/common/log/tracelogreader.cpp @@ -0,0 +1,1747 @@ +/* $Id: tracelogreader.cpp $ */ +/** @file + * IPRT - Trace log reader. + */ + +/* + * Copyright (C) 2018-2020 Oracle Corporation + * + * This file is part of VirtualBox Open Source Edition (OSE), as + * available from http://www.virtualbox.org. This file is free software; + * you can redistribute it and/or modify it under the terms of the GNU + * General Public License (GPL) as published by the Free Software + * Foundation, in version 2 as it comes in the "COPYING" file of the + * VirtualBox OSE distribution. VirtualBox OSE is distributed in the + * hope that it will be useful, but WITHOUT ANY WARRANTY of any kind. + * + * The contents of this file may alternatively be used under the terms + * of the Common Development and Distribution License Version 1.0 + * (CDDL) only, as it comes in the "COPYING.CDDL" file of the + * VirtualBox OSE distribution, in which case the provisions of the + * CDDL are applicable instead of those of the GPL. + * + * You may elect to license modified versions of this file under the + * terms and conditions of either the GPL or the CDDL or both. + */ + + +/********************************************************************************************************************************* +* Header Files * +*********************************************************************************************************************************/ +#include "internal/iprt.h" +#include <iprt/formats/tracelog.h> +#include <iprt/tracelog.h> + + +#include <iprt/asm.h> +#include <iprt/assert.h> +#include <iprt/err.h> +#include <iprt/file.h> +#include <iprt/list.h> +#include <iprt/log.h> +#include <iprt/mem.h> +#include <iprt/semaphore.h> +#include <iprt/string.h> +#include <iprt/strcache.h> +#include <iprt/time.h> + +#include "internal/magics.h" + + +/********************************************************************************************************************************* +* Structures and Typedefs * +*********************************************************************************************************************************/ + +/** The trace log is malformed. */ +#define VERR_TRACELOG_READER_MALFORMED_LOG (-25700) +/** The trace log version is not supported. */ +#define VERR_TRACELOG_READER_LOG_UNSUPPORTED (-25701) +/** The trace log reader iterator reached the end of the event list. */ +#define VERR_TRACELOG_READER_ITERATOR_END (-25702) + +/** Pointer to a trace log reader instance. */ +typedef struct RTTRACELOGRDRINT *PRTTRACELOGRDRINT; + +/** + * State enums the trace log reader can be in. + */ +typedef enum RTTRACELOGRDRSTATE +{ + /** Invalid state. */ + RTTRACELOGRDRSTATE_INVALID = 0, + /** The header is currently being received. */ + RTTRACELOGRDRSTATE_RECV_HDR, + /** The header description is being received (if available). */ + RTTRACELOGRDRSTATE_RECV_HDR_DESC, + /** the magic is being received to decide what to do next. */ + RTTRACELOGRDRSTATE_RECV_MAGIC, + /** The event descriptor is being received. */ + RTTRACELOGRDRSTATE_RECV_EVT_DESC, + /** The event descriptor ID is being received. */ + RTTRACELOGRDRSTATE_RECV_EVT_DESC_ID, + /** The event descriptor description is being received. */ + RTTRACELOGRDRSTATE_RECV_EVT_DESC_DESC, + /** The event item descriptor is being received. */ + RTTRACELOGRDRSTATE_RECV_EVT_ITEM_DESC, + /** The event item descriptor name is being received. */ + RTTRACELOGRDRSTATE_RECV_EVT_ITEM_DESC_NAME, + /** The event item descriptor description is being received. */ + RTTRACELOGRDRSTATE_RECV_EVT_ITEM_DESC_DESC, + /** The event marker is being received. */ + RTTRACELOGRDRSTATE_RECV_EVT_MARKER, + /** The event data is being received. */ + RTTRACELOGRDRSTATE_RECV_EVT_DATA, + /** 32bit hack. */ + RTTRACELOGRDRSTATE_32BIT_HACK = 0x7fffffff +} RTTRACELOGRDRSTATE; + + +/** Pointer to internal trace log reader event descriptor. */ +typedef struct RTTRACELOGRDREVTDESC *PRTTRACELOGRDREVTDESC; +/** Pointer to const internal trace log reader event descriptor. */ +typedef const RTTRACELOGRDREVTDESC *PCRTTRACELOGRDREVTDESC; + + +/** + * Trace log reader event. + */ +typedef struct RTTRACELOGRDREVTINT +{ + /** List node for the global list of events. */ + RTLISTANCHOR NdGlob; + /** The trace log reader instance the event belongs to. */ + PRTTRACELOGRDRINT pRdr; + /** Trace log sequence number. */ + uint64_t u64SeqNo; + /** Marker time stamp. */ + uint64_t u64Ts; + /** Pointer to the event descriptor, describing the data layout. */ + PCRTTRACELOGRDREVTDESC pEvtDesc; + /** Parent group ID if assigned. */ + RTTRACELOGEVTGRPID idGrpParent; + /** Group ID this event belongs to. */ + RTTRACELOGEVTGRPID idGrp; + /** Pointer to the array holding the non static raw data size values. */ + size_t *pacbRawData; + /** Overall event data size in bytes, including non static data. */ + size_t cbEvtData; + /** Event data, variable in size. */ + uint8_t abEvtData[1]; +} RTTRACELOGRDREVTINT; +/** Pointer to a trace log reader event. */ +typedef RTTRACELOGRDREVTINT *PRTTRACELOGRDREVTINT; +/** Pointer to a const trace log reader event. */ +typedef const RTTRACELOGRDREVTINT *PCRTTRACELOGRDREVTINT; + + +/** + * Trace log reader internal event descriptor. + */ +typedef struct RTTRACELOGRDREVTDESC +{ + /** Overall size of the event data not counting variable raw data items. */ + size_t cbEvtData; + /** Number of non static raw binary items in the descriptor. */ + uint32_t cRawDataNonStatic; + /** Current event item descriptor to work on. */ + uint32_t idxEvtItemCur; + /** Size of the name of the current item to work on. */ + size_t cbStrItemName; + /** Size of the description of the current item to work on. */ + size_t cbStrItemDesc; + /** Size of the ID in bytes including the terminator. */ + size_t cbStrId; + /** Size of the description in bytes including the terminator. */ + size_t cbStrDesc; + /** Embedded event descriptor. */ + RTTRACELOGEVTDESC EvtDesc; + /** Array of event item descriptors, variable in size. */ + RTTRACELOGEVTITEMDESC aEvtItemDesc[1]; +} RTTRACELOGRDREVTDESC; + + +/** + * Trace log reader instance data. + */ +typedef struct RTTRACELOGRDRINT +{ + /** Magic for identification. */ + uint32_t u32Magic; + /** Stream out callback. */ + PFNRTTRACELOGRDRSTREAM pfnStreamIn; + /** Stream close callback .*/ + PFNRTTRACELOGSTREAMCLOSE pfnStreamClose; + /** Opaque user data passed to the stream callback. */ + void *pvUser; + /** Mutex protecting the structure. */ + RTSEMMUTEX hMtx; + /** Current state the reader is in. */ + RTTRACELOGRDRSTATE enmState; + /** Flag whether to convert all inputs to the host endianess. */ + bool fConvEndianess; + /** String cache for descriptions and IDs. */ + RTSTRCACHE hStrCache; + /** Size of the description in characters. */ + size_t cchDesc; + /** Pointer to the description if set. */ + const char *pszDesc; + /** List of received events. */ + RTLISTANCHOR LstEvts; + /** Number of event descriptors known. */ + uint32_t cEvtDescsCur; + /** Maximum number of event descriptors currently fitting into the array. */ + uint32_t cEvtDescsMax; + /** Pointer to the array of event descriptor pointers. */ + PRTTRACELOGRDREVTDESC *papEvtDescs; + /** Current event descriptor being initialised. */ + PRTTRACELOGRDREVTDESC pEvtDescCur; + /** The current event being received. */ + PRTTRACELOGRDREVTINT pEvtCur; + /** Last seen sequence number. */ + uint64_t u64SeqNoLast; + /** Size of the scratch buffer holding the received data. */ + size_t cbScratch; + /** Pointer to the scratch buffer. */ + uint8_t *pbScratch; + /** Current offset into the scratch buffer to write fetched data to. */ + uint32_t offScratch; + /** Number of bytes left to receive until processing the data. */ + size_t cbRecvLeft; + /** Starting timestamp fetched from the header. */ + uint64_t u64TsStart; + /** Size of the pointer type in the trace log. */ + size_t cbTypePtr; + /** Size of the size_t type in the trace log. */ + size_t cbTypeSize; +} RTTRACELOGRDRINT; + + +/** + * Internal reader iterator instance data. + */ +typedef struct RTTRACELOGRDRITINT +{ + /** The reader instance this iterator belongs to. */ + PRTTRACELOGRDRINT pRdr; + /** The current event. */ + PRTTRACELOGRDREVTINT pEvt; +} RTTRACELOGRDRITINT; +/** Pointer to an internal reader iterator instance. */ +typedef RTTRACELOGRDRITINT *PRTTRACELOGRDRITINT; + + +/** + * Trace log handler state callback. + * + * @returns IPRT status code. + * @param pThis The trace log reader instance. + * @param penmEvt Where to store the event indicator if a user visible event happened. + * @param pfContinuePoll Where to store the flag whether to continue polling. + */ +typedef DECLCALLBACK(int) FNRTTRACELOGRDRSTATEHANDLER(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll); +/** Pointer to a trace log reader state handler. */ +typedef FNRTTRACELOGRDRSTATEHANDLER *PFNRTTRACELOGRDRSTATEHANDLER; + + +/********************************************************************************************************************************* +* Defined Constants And Macros * +*********************************************************************************************************************************/ + +static DECLCALLBACK(int) rtTraceLogRdrHdrRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); +static DECLCALLBACK(int) rtTraceLogRdrHdrDescRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); +static DECLCALLBACK(int) rtTraceLogRdrMagicRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); +static DECLCALLBACK(int) rtTraceLogRdrEvtDescRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); +static DECLCALLBACK(int) rtTraceLogRdrEvtDescIdRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); +static DECLCALLBACK(int) rtTraceLogRdrEvtDescDescriptionRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); +static DECLCALLBACK(int) rtTraceLogRdrEvtItemDescRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); +static DECLCALLBACK(int) rtTraceLogRdrEvtItemDescNameRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); +static DECLCALLBACK(int) rtTraceLogRdrEvtItemDescDescriptionRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); +static DECLCALLBACK(int) rtTraceLogRdrEvtMarkerRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); +static DECLCALLBACK(int) rtTraceLogRdrEvtDataRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, bool *pfContinuePoll); + +/** + * State handlers. + */ +static PFNRTTRACELOGRDRSTATEHANDLER g_apfnStateHandlers[] = +{ + NULL, + rtTraceLogRdrHdrRecvd, + rtTraceLogRdrHdrDescRecvd, + rtTraceLogRdrMagicRecvd, + rtTraceLogRdrEvtDescRecvd, + rtTraceLogRdrEvtDescIdRecvd, + rtTraceLogRdrEvtDescDescriptionRecvd, + rtTraceLogRdrEvtItemDescRecvd, + rtTraceLogRdrEvtItemDescNameRecvd, + rtTraceLogRdrEvtItemDescDescriptionRecvd, + rtTraceLogRdrEvtMarkerRecvd, + rtTraceLogRdrEvtDataRecvd, + NULL +}; + +/** + * Wrapper around the stream in callback. + * + * @returns IPRT status code returned by the stream callback. + * @param pThis The trace log reader instance. + * @param pvBuf The data to stream. + * @param cbBuf Number of bytes to read in. + * @param pcbRead Where to store the amount of data read. + * @param cMsTimeout How long to wait for something to arrive. + */ +DECLINLINE(int) rtTraceLogRdrStreamRead(PRTTRACELOGRDRINT pThis, void *pvBuf, size_t cbBuf, + size_t *pcbRead, RTMSINTERVAL cMsTimeout) +{ + return pThis->pfnStreamIn(pThis->pvUser, pvBuf, cbBuf, pcbRead, cMsTimeout); +} + + +/** + * Converts the header endianess to the host endianess. + * + * @returns nothing. + * @param pHdr The trace log header to convert. + */ +static void rtTraceLogRdrHdrEndianessConv(PTRACELOGHDR pHdr) +{ + pHdr->u32Endianess = RT_BSWAP_U32(pHdr->u32Endianess); + pHdr->u32Version = RT_BSWAP_U32(pHdr->u32Version); + pHdr->fFlags = RT_BSWAP_U32(pHdr->fFlags); + pHdr->cbStrDesc = RT_BSWAP_U32(pHdr->cbStrDesc); + pHdr->u64TsStart = RT_BSWAP_U64(pHdr->u64TsStart); +} + + +/** + * Converts the event descriptor endianess to the host endianess. + * + * @returns nothing. + * @param pEvtDesc The trace log event descriptor to convert. + */ +static void rtTraceLogRdrEvtDescEndianessConv(PTRACELOGEVTDESC pEvtDesc) +{ + pEvtDesc->u32Id = RT_BSWAP_U32(pEvtDesc->u32Id); + pEvtDesc->u32Severity = RT_BSWAP_U32(pEvtDesc->u32Severity); + pEvtDesc->cbStrId = RT_BSWAP_U32(pEvtDesc->cbStrId); + pEvtDesc->cbStrDesc = RT_BSWAP_U32(pEvtDesc->cbStrDesc); + pEvtDesc->cEvtItems = RT_BSWAP_U32(pEvtDesc->cEvtItems); +} + + +/** + * Converts the event item descriptor endianess to host endianess. + * + * @returns nothing. + * @param pEvtItemDesc The trace log event item descriptor to convert. + */ +static void rtTraceLogRdrEvtItemDescEndianessConv(PTRACELOGEVTITEMDESC pEvtItemDesc) +{ + pEvtItemDesc->cbStrName = RT_BSWAP_U32(pEvtItemDesc->cbStrName); + pEvtItemDesc->cbStrDesc = RT_BSWAP_U32(pEvtItemDesc->cbStrDesc); + pEvtItemDesc->u32Type = RT_BSWAP_U32(pEvtItemDesc->u32Type); + pEvtItemDesc->cbRawData = RT_BSWAP_U32(pEvtItemDesc->cbRawData); +} + + +/** + * Converts the event marker endianess to host endianess. + * + * @returns nothing. + * @param pEvt The trace log event marker to convert. + */ +static void rtTraceLogRdrEvtEndianessConv(PTRACELOGEVT pEvt) +{ + pEvt->u64SeqNo = RT_BSWAP_U64(pEvt->u64SeqNo); + pEvt->u64Ts = RT_BSWAP_U64(pEvt->u64Ts); + pEvt->u64EvtGrpId = RT_BSWAP_U64(pEvt->u64EvtGrpId); + pEvt->u64EvtParentGrpId = RT_BSWAP_U64(pEvt->u64EvtParentGrpId); + pEvt->fFlags = RT_BSWAP_U32(pEvt->fFlags); + pEvt->u32EvtDescId = RT_BSWAP_U32(pEvt->u32EvtDescId); + pEvt->cbEvtData = RT_BSWAP_U32(pEvt->cbEvtData); + pEvt->cRawEvtDataSz = RT_BSWAP_U32(pEvt->cRawEvtDataSz); +} + + +/** + * Converts severity field from stream to API value. + * + * @returns API severity enum, RTTRACELOGEVTSEVERITY_INVALID if the supplied stream value + * is invalid. + * @param u32Severity The severity value from the stream. + */ +static RTTRACELOGEVTSEVERITY rtTraceLogRdrConvSeverity(uint32_t u32Severity) +{ + RTTRACELOGEVTSEVERITY enmSeverity = RTTRACELOGEVTSEVERITY_INVALID; + + switch (u32Severity) + { + case TRACELOG_EVTDESC_SEVERITY_INFO: + enmSeverity = RTTRACELOGEVTSEVERITY_INFO; + break; + case TRACELOG_EVTDESC_SEVERITY_WARNING: + enmSeverity = RTTRACELOGEVTSEVERITY_WARNING; + break; + case TRACELOG_EVTDESC_SEVERITY_ERROR: + enmSeverity = RTTRACELOGEVTSEVERITY_ERROR; + break; + case TRACELOG_EVTDESC_SEVERITY_FATAL: + enmSeverity = RTTRACELOGEVTSEVERITY_FATAL; + break; + case TRACELOG_EVTDESC_SEVERITY_DEBUG: + enmSeverity = RTTRACELOGEVTSEVERITY_DEBUG; + break; + default: + enmSeverity = RTTRACELOGEVTSEVERITY_INVALID; + } + + return enmSeverity; +} + + +/** + * Converts type field from stream to API value. + * + * @returns API type enum, RTTRACELOGTYPE_INVALID if the supplied stream value + * is invalid. + * @param u32Type The type value from the stream. + */ +static RTTRACELOGTYPE rtTraceLogRdrConvType(uint32_t u32Type) +{ + RTTRACELOGTYPE enmType = RTTRACELOGTYPE_INVALID; + + switch (u32Type) + { + case TRACELOG_EVTITEMDESC_TYPE_BOOL: + enmType = RTTRACELOGTYPE_BOOL; + break; + case TRACELOG_EVTITEMDESC_TYPE_UINT8: + enmType = RTTRACELOGTYPE_UINT8; + break; + case TRACELOG_EVTITEMDESC_TYPE_INT8: + enmType = RTTRACELOGTYPE_INT8; + break; + case TRACELOG_EVTITEMDESC_TYPE_UINT16: + enmType = RTTRACELOGTYPE_UINT16; + break; + case TRACELOG_EVTITEMDESC_TYPE_INT16: + enmType = RTTRACELOGTYPE_INT16; + break; + case TRACELOG_EVTITEMDESC_TYPE_UINT32: + enmType = RTTRACELOGTYPE_UINT32; + break; + case TRACELOG_EVTITEMDESC_TYPE_INT32: + enmType = RTTRACELOGTYPE_INT32; + break; + case TRACELOG_EVTITEMDESC_TYPE_UINT64: + enmType = RTTRACELOGTYPE_UINT64; + break; + case TRACELOG_EVTITEMDESC_TYPE_INT64: + enmType = RTTRACELOGTYPE_INT64; + break; + case TRACELOG_EVTITEMDESC_TYPE_FLOAT32: + enmType = RTTRACELOGTYPE_FLOAT32; + break; + case TRACELOG_EVTITEMDESC_TYPE_FLOAT64: + enmType = RTTRACELOGTYPE_FLOAT64; + break; + case TRACELOG_EVTITEMDESC_TYPE_RAWDATA: + enmType = RTTRACELOGTYPE_RAWDATA; + break; + case TRACELOG_EVTITEMDESC_TYPE_POINTER: + enmType = RTTRACELOGTYPE_POINTER; + break; + case TRACELOG_EVTITEMDESC_TYPE_SIZE: + enmType = RTTRACELOGTYPE_SIZE; + break; + default: + enmType = RTTRACELOGTYPE_INVALID; + } + + return enmType; +} + + +/** + * Converts the type enum to the size of the the event item data in bytes. + * + * @returns Event item data size in bytes. + * @param pThis The trace log reader instance. + * @param pEvtItemDesc The event item descriptor. + */ +static size_t rtTraceLogRdrGetEvtItemDataSz(PRTTRACELOGRDRINT pThis, PCRTTRACELOGEVTITEMDESC pEvtItemDesc) +{ + size_t cb = 0; + + switch (pEvtItemDesc->enmType) + { + case RTTRACELOGTYPE_BOOL: + case RTTRACELOGTYPE_UINT8: + case RTTRACELOGTYPE_INT8: + { + cb = 1; + break; + } + case RTTRACELOGTYPE_UINT16: + case RTTRACELOGTYPE_INT16: + { + cb = 2; + break; + } + case RTTRACELOGTYPE_UINT32: + case RTTRACELOGTYPE_INT32: + case RTTRACELOGTYPE_FLOAT32: + { + cb = 4; + break; + } + case RTTRACELOGTYPE_UINT64: + case RTTRACELOGTYPE_INT64: + case RTTRACELOGTYPE_FLOAT64: + { + cb = 8; + break; + } + case RTTRACELOGTYPE_RAWDATA: + { + cb = pEvtItemDesc->cbRawData; + break; + } + case RTTRACELOGTYPE_POINTER: + { + cb = pThis->cbTypePtr; + break; + } + case RTTRACELOGTYPE_SIZE: + { + cb = pThis->cbTypeSize; + break; + } + default: + AssertMsgFailed(("Invalid type %d\n", pEvtItemDesc->enmType)); + } + + return cb; +} + + +/** + * Calculates the overall event data size from the items in the event descriptor. + * + * @returns nothing. + * @param pThis The trace log reader instance. + * @param pEvtDesc The event descriptor. + */ +static void rtTraceLogRdrEvtCalcEvtDataSz(PRTTRACELOGRDRINT pThis, PRTTRACELOGRDREVTDESC pEvtDesc) +{ + pEvtDesc->cbEvtData = 0; + pEvtDesc->cRawDataNonStatic = 0; + + for (unsigned i = 0; i < pEvtDesc->EvtDesc.cEvtItems; i++) + { + PCRTTRACELOGEVTITEMDESC pEvtItemDesc = &pEvtDesc->aEvtItemDesc[i]; + + pEvtDesc->cbEvtData += rtTraceLogRdrGetEvtItemDataSz(pThis, pEvtItemDesc); + if ( pEvtItemDesc->enmType == RTTRACELOGTYPE_RAWDATA + && pEvtItemDesc->cbRawData == 0) + pEvtDesc->cRawDataNonStatic++; + } +} + + +/** + * Ensures that the scratch buffer can hold at least the given amount of data. + * + * @returns IPRT status code. + * @param pThis The trace log reader instance. + * @param cbScratch New size of the scratch buffer in bytes. + */ +static int rtTraceLogRdrScratchEnsureSz(PRTTRACELOGRDRINT pThis, size_t cbScratch) +{ + int rc = VINF_SUCCESS; + + if (pThis->cbScratch < cbScratch) + { + cbScratch = RT_ALIGN_Z(cbScratch, 64); + uint8_t *pbScratchNew = (uint8_t *)RTMemRealloc(pThis->pbScratch, cbScratch); + if (RT_LIKELY(pbScratchNew)) + { + pThis->cbScratch = cbScratch; + pThis->pbScratch = pbScratchNew; + } + else + rc = VERR_NO_MEMORY; + } + + return rc; +} + + +/** + * Advances to the next state resetting the scratch/receive buffers to the given state. + * + * @returns IPRT status. + * @param pThis The trace log reader instance. + * @param enmState The next state. + * @param cbRecv How much to receive before processing the new data. + * @param offScratch Offset to set the receive buffer to (used + * when the magic was received which should still be saved). + */ +static int rtTraceLogRdrStateAdvanceEx(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRSTATE enmState, size_t cbRecv, + uint32_t offScratch) +{ + Assert(cbRecv >= offScratch); + + pThis->enmState = enmState; + pThis->cbRecvLeft = cbRecv - offScratch; + pThis->offScratch = offScratch; + int rc = rtTraceLogRdrScratchEnsureSz(pThis, cbRecv); + + /* Zero out scratch buffer (don't care whether growing it failed, the old buffer is still there). */ + memset(pThis->pbScratch + offScratch, 0, pThis->cbScratch - offScratch); + + return rc; +} + + +/** + * Advances to the next state resetting the scratch/receive buffers. + * + * @returns IPRT status. + * @param pThis The trace log reader instance. + * @param enmState The next state. + * @param cbRecv How much to receive before processing the new data. + */ +static int rtTraceLogRdrStateAdvance(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRSTATE enmState, size_t cbRecv) +{ + return rtTraceLogRdrStateAdvanceEx(pThis, enmState, cbRecv, 0); +} + + +/** + * Marks a received event descriptor as completed and adds it to the array of known descriptors. + * + * @returns IPRT status code. + * @param pThis The trace log reader instance. + * @param pEvtDesc The event descriptor which completed. + */ +static int rtTraceLogRdrEvtDescComplete(PRTTRACELOGRDRINT pThis, PRTTRACELOGRDREVTDESC pEvtDesc) +{ + int rc = VINF_SUCCESS; + + rtTraceLogRdrEvtCalcEvtDataSz(pThis, pEvtDesc); + /* Insert into array of known event descriptors. */ + if (pThis->cEvtDescsCur == pThis->cEvtDescsMax) + { + uint32_t cEvtDescsNew = pThis->cEvtDescsMax + 10; + size_t cbNew = cEvtDescsNew * sizeof(PRTTRACELOGRDREVTDESC *); + PRTTRACELOGRDREVTDESC *papEvtDescsNew = (PRTTRACELOGRDREVTDESC *)RTMemRealloc(pThis->papEvtDescs, cbNew); + if (RT_LIKELY(papEvtDescsNew)) + { + pThis->papEvtDescs = papEvtDescsNew; + pThis->cEvtDescsMax = cEvtDescsNew; + } + else + rc = VERR_NO_MEMORY; + } + + if (RT_SUCCESS(rc)) + { + pThis->papEvtDescs[pThis->cEvtDescsCur++] = pEvtDesc; + pThis->pEvtDescCur = NULL; + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_MAGIC, TRACELOG_MAGIC_SZ); + } + + return rc; +} + + +/** + * Decides which state to enter next after one event item descriptor was completed successfully. + * + * @returns IPRT status code. + * @param pThis The trace log reader instance. + * @param penmEvt Where to store the event indicator if a user visible event happened. + * @param pfContinuePoll Where to store the flag whether to continue polling. + */ +static int rtTraceLogRdrEvtItemDescComplete(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + RT_NOREF(penmEvt, pfContinuePoll); + + int rc = VINF_SUCCESS; + PRTTRACELOGRDREVTDESC pEvtDesc = pThis->pEvtDescCur; + pEvtDesc->idxEvtItemCur++; + + /* If this event descriptor is complete add it to the array of known descriptors. */ + if (pEvtDesc->idxEvtItemCur == pEvtDesc->EvtDesc.cEvtItems) + rc = rtTraceLogRdrEvtDescComplete(pThis, pEvtDesc); + else + { + /* Not done yet. */ + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_EVT_ITEM_DESC, sizeof(TRACELOGEVTITEMDESC)); + } + + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles a received header.} + */ +static DECLCALLBACK(int) rtTraceLogRdrHdrRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + RT_NOREF(penmEvt, pfContinuePoll); + int rc = VINF_SUCCESS; + PTRACELOGHDR pHdr = (PTRACELOGHDR)pThis->pbScratch; + + /* Verify magic. */ + if (!memcmp(&pHdr->szMagic[0], TRACELOG_HDR_MAGIC, sizeof(pHdr->szMagic))) + { + /* Check endianess. */ + if (pHdr->u32Endianess == TRACELOG_HDR_ENDIANESS) + pThis->fConvEndianess = false; + else if (RT_BSWAP_U32(pHdr->u32Endianess) == TRACELOG_HDR_ENDIANESS) + { + pThis->fConvEndianess = true; + rtTraceLogRdrHdrEndianessConv(pHdr); + } + else + rc = VERR_TRACELOG_READER_MALFORMED_LOG; + + if (RT_SUCCESS(rc)) + { + Assert(pHdr->u32Endianess == TRACELOG_HDR_ENDIANESS); + + /* Enforce strict limits to avoid exhausting memory. */ + if ( pHdr->u32Version == TRACELOG_VERSION + && pHdr->cbStrDesc < _1K + && pHdr->cbTypePtr <= 8 + && (pHdr->cbTypeSize == 8 || pHdr->cbTypeSize == 4)) + { + pThis->u64TsStart = pHdr->u64TsStart; + pThis->cbTypePtr = pHdr->cbTypePtr; + pThis->cbTypeSize = pHdr->cbTypeSize; + pThis->cchDesc = pHdr->cbStrDesc; + pThis->cEvtDescsMax = 10; + + /* Allocate array to hold event descriptors later on. */ + pThis->papEvtDescs = (PRTTRACELOGRDREVTDESC *)RTMemAllocZ(pThis->cEvtDescsMax * sizeof(PRTTRACELOGRDREVTDESC)); + if (RT_LIKELY(pThis->papEvtDescs)) + { + /* Switch to the next state. */ + if (pHdr->cbStrDesc) + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_HDR_DESC, pHdr->cbStrDesc); + else + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_MAGIC, TRACELOG_MAGIC_SZ); + + if (RT_SUCCESS(rc)) + { + *penmEvt = RTTRACELOGRDRPOLLEVT_HDR_RECVD; + *pfContinuePoll = false; + } + } + else + rc = VERR_NO_MEMORY; + } + else + rc = VERR_TRACELOG_READER_LOG_UNSUPPORTED; + } + } + else + rc = VERR_TRACELOG_READER_MALFORMED_LOG; + + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles a received log description.} + */ +static DECLCALLBACK(int) rtTraceLogRdrHdrDescRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + RT_NOREF(penmEvt, pfContinuePoll); + int rc = VINF_SUCCESS; + char *pszDesc = (char *)pThis->pbScratch; + + RTStrPurgeEncoding(pszDesc); + pThis->pszDesc = RTStrCacheEnterN(pThis->hStrCache, pszDesc, pThis->cchDesc); + if (pThis->pszDesc) + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_MAGIC, TRACELOG_MAGIC_SZ); + else + rc = VERR_NO_STR_MEMORY; + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles a received magic.} + */ +static DECLCALLBACK(int) rtTraceLogRdrMagicRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + RT_NOREF(penmEvt, pfContinuePoll); + int rc = VINF_SUCCESS; + char *pszMagic = (char *)pThis->pbScratch; + + if (!memcmp(pszMagic, TRACELOG_EVTDESC_MAGIC, TRACELOG_MAGIC_SZ)) + rc = rtTraceLogRdrStateAdvanceEx(pThis, RTTRACELOGRDRSTATE_RECV_EVT_DESC, + sizeof(TRACELOGEVTDESC), TRACELOG_MAGIC_SZ); + else if (!memcmp(pszMagic, TRACELOG_EVT_MAGIC, TRACELOG_MAGIC_SZ)) + rc = rtTraceLogRdrStateAdvanceEx(pThis, RTTRACELOGRDRSTATE_RECV_EVT_MARKER, + sizeof(TRACELOGEVT), TRACELOG_MAGIC_SZ); + + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles a received event descriptor.} + */ +static DECLCALLBACK(int) rtTraceLogRdrEvtDescRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + RT_NOREF(penmEvt, pfContinuePoll); + int rc = VINF_SUCCESS; + PTRACELOGEVTDESC pEvtDesc = (PTRACELOGEVTDESC)pThis->pbScratch; + if (pThis->fConvEndianess) + rtTraceLogRdrEvtDescEndianessConv(pEvtDesc); + + if ( !memcmp(&pEvtDesc->szMagic[0], TRACELOG_EVTDESC_MAGIC, sizeof(pEvtDesc->szMagic)) + && pEvtDesc->u32Id == pThis->cEvtDescsCur + && (pEvtDesc->cbStrId >= 1 && pEvtDesc->cbStrId < 128) + && pEvtDesc->cbStrDesc < _1K + && pEvtDesc->cEvtItems < 128) + { + RTTRACELOGEVTSEVERITY enmSeverity = rtTraceLogRdrConvSeverity(pEvtDesc->u32Severity); + if (RT_LIKELY(enmSeverity != RTTRACELOGEVTSEVERITY_INVALID)) + { + /* Allocate new internal event descriptor state. */ + size_t cbEvtDesc = RT_UOFFSETOF_DYN(RTTRACELOGRDREVTDESC, aEvtItemDesc[pEvtDesc->cEvtItems]); + PRTTRACELOGRDREVTDESC pEvtDescInt = (PRTTRACELOGRDREVTDESC)RTMemAllocZ(cbEvtDesc); + if (RT_LIKELY(pEvtDesc)) + { + pEvtDescInt->cbStrId = pEvtDesc->cbStrId; + pEvtDescInt->cbStrDesc = pEvtDesc->cbStrDesc; + pEvtDescInt->EvtDesc.enmSeverity = enmSeverity; + pEvtDescInt->EvtDesc.cEvtItems = pEvtDesc->cEvtItems; + pEvtDescInt->EvtDesc.paEvtItemDesc = &pEvtDescInt->aEvtItemDesc[0]; + + pThis->pEvtDescCur = pEvtDescInt; + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_EVT_DESC_ID, pEvtDescInt->cbStrId); + } + else + rc = VERR_NO_MEMORY; + } + else + rc = VERR_TRACELOG_READER_MALFORMED_LOG; + } + else + rc = VERR_TRACELOG_READER_MALFORMED_LOG; + + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles a received event descriptor ID.} + */ +static DECLCALLBACK(int) rtTraceLogRdrEvtDescIdRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + RT_NOREF(penmEvt, pfContinuePoll); + + int rc = VINF_SUCCESS; + pThis->pEvtDescCur->EvtDesc.pszId = RTStrCacheEnterN(pThis->hStrCache, (const char *)pThis->pbScratch, + pThis->pEvtDescCur->cbStrId); + if (RT_LIKELY(pThis->pEvtDescCur->EvtDesc.pszId)) + { + if (pThis->pEvtDescCur->cbStrDesc) + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_EVT_DESC_DESC, pThis->pEvtDescCur->cbStrDesc); + else if (pThis->pEvtDescCur->EvtDesc.cEvtItems > 0) + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_EVT_ITEM_DESC, sizeof(TRACELOGEVTITEMDESC)); + else + rc = rtTraceLogRdrEvtDescComplete(pThis, pThis->pEvtDescCur); + } + else + rc = VERR_NO_STR_MEMORY; + + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles a received event descriptor description.} + */ +static DECLCALLBACK(int) rtTraceLogRdrEvtDescDescriptionRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + RT_NOREF(penmEvt, pfContinuePoll); + int rc = VINF_SUCCESS; + pThis->pEvtDescCur->EvtDesc.pszDesc = RTStrCacheEnterN(pThis->hStrCache, (const char *)pThis->pbScratch, + pThis->pEvtDescCur->cbStrDesc); + if (RT_LIKELY(pThis->pEvtDescCur->EvtDesc.pszDesc)) + { + if (pThis->pEvtDescCur->EvtDesc.cEvtItems > 0) + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_EVT_ITEM_DESC, sizeof(TRACELOGEVTITEMDESC)); + else + rc = rtTraceLogRdrEvtDescComplete(pThis, pThis->pEvtDescCur); + } + else + rc = VERR_NO_STR_MEMORY; + + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles a received event item descriptor.} + */ +static DECLCALLBACK(int) rtTraceLogRdrEvtItemDescRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + RT_NOREF(penmEvt, pfContinuePoll); + int rc = VINF_SUCCESS; + PTRACELOGEVTITEMDESC pEvtItemDesc = (PTRACELOGEVTITEMDESC)pThis->pbScratch; + if (pThis->fConvEndianess) + rtTraceLogRdrEvtItemDescEndianessConv(pEvtItemDesc); + + if ( !memcmp(&pEvtItemDesc->szMagic[0], TRACELOG_EVTITEMDESC_MAGIC, sizeof(pEvtItemDesc->szMagic)) + && (pEvtItemDesc->cbStrName >= 1 && pEvtItemDesc->cbStrName < 128) + && pEvtItemDesc->cbStrDesc < _1K + && pEvtItemDesc->cbRawData < _1M) + { + RTTRACELOGTYPE enmType = rtTraceLogRdrConvType(pEvtItemDesc->u32Type); + if (RT_LIKELY(enmType != RTTRACELOGTYPE_INVALID)) + { + PRTTRACELOGEVTITEMDESC pEvtDesc = &pThis->pEvtDescCur->aEvtItemDesc[pThis->pEvtDescCur->idxEvtItemCur]; + + pThis->pEvtDescCur->cbStrItemName = pEvtItemDesc->cbStrName; + pThis->pEvtDescCur->cbStrItemDesc = pEvtItemDesc->cbStrDesc; + + pEvtDesc->enmType = enmType; + pEvtDesc->cbRawData = pEvtItemDesc->cbRawData; + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_EVT_ITEM_DESC_NAME, pEvtItemDesc->cbStrName); + } + else + rc = VERR_TRACELOG_READER_MALFORMED_LOG; + } + else + rc = VERR_TRACELOG_READER_MALFORMED_LOG; + + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles a received event item descriptor name.} + */ +static DECLCALLBACK(int) rtTraceLogRdrEvtItemDescNameRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + int rc = VINF_SUCCESS; + PRTTRACELOGEVTITEMDESC pEvtDesc = &pThis->pEvtDescCur->aEvtItemDesc[pThis->pEvtDescCur->idxEvtItemCur]; + pEvtDesc->pszName = RTStrCacheEnterN(pThis->hStrCache, (const char *)pThis->pbScratch, pThis->pEvtDescCur->cbStrItemName); + if (RT_LIKELY(pEvtDesc->pszName)) + { + if (pThis->pEvtDescCur->cbStrItemDesc) + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_EVT_ITEM_DESC_DESC, pThis->pEvtDescCur->cbStrItemDesc); + else + rc = rtTraceLogRdrEvtItemDescComplete(pThis, penmEvt, pfContinuePoll); + } + else + rc = VERR_NO_STR_MEMORY; + + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles a received event item description.} + */ +static DECLCALLBACK(int) rtTraceLogRdrEvtItemDescDescriptionRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + int rc = VINF_SUCCESS; + PRTTRACELOGEVTITEMDESC pEvtDesc = &pThis->pEvtDescCur->aEvtItemDesc[pThis->pEvtDescCur->idxEvtItemCur]; + pEvtDesc->pszDesc = RTStrCacheEnterN(pThis->hStrCache, (const char *)pThis->pbScratch, pThis->pEvtDescCur->cbStrItemDesc); + if (RT_LIKELY(pEvtDesc->pszDesc)) + rc = rtTraceLogRdrEvtItemDescComplete(pThis, penmEvt, pfContinuePoll); + else + rc = VERR_NO_STR_MEMORY; + + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles a received event marker.} + */ +static DECLCALLBACK(int) rtTraceLogRdrEvtMarkerRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + int rc = VINF_SUCCESS; + PTRACELOGEVT pEvtStrm = (PTRACELOGEVT)pThis->pbScratch; + if (pThis->fConvEndianess) + rtTraceLogRdrEvtEndianessConv(pEvtStrm); + + if ( (pEvtStrm->u64SeqNo == pThis->u64SeqNoLast + 1) + && !(pEvtStrm->fFlags & ~TRACELOG_EVT_F_VALID) + && pEvtStrm->u32EvtDescId < pThis->cEvtDescsCur) + { + PRTTRACELOGRDREVTDESC pEvtDesc = pThis->papEvtDescs[pEvtStrm->u32EvtDescId]; + if ( ( !pEvtDesc->cRawDataNonStatic + && pEvtStrm->cbEvtData == pEvtDesc->cbEvtData) + || ( pEvtDesc->cRawDataNonStatic + && pEvtStrm->cbEvtData >= pEvtDesc->cbEvtData + && pEvtStrm->cRawEvtDataSz == pEvtDesc->cRawDataNonStatic)) + { + size_t cbEvt = RT_UOFFSETOF_DYN(RTTRACELOGRDREVTINT, abEvtData[pEvtStrm->cbEvtData]); + cbEvt += pEvtDesc->cRawDataNonStatic * sizeof(size_t); + PRTTRACELOGRDREVTINT pEvt = (PRTTRACELOGRDREVTINT)RTMemAllocZ(cbEvt); + if (RT_LIKELY(pEvt)) + { + pEvt->pRdr = pThis; + pEvt->u64SeqNo = pEvtStrm->u64SeqNo; + pEvt->u64Ts = pEvtStrm->u64Ts; + pEvt->pEvtDesc = pEvtDesc; + pEvt->cbEvtData = pEvtStrm->cbEvtData; + pEvt->pacbRawData = pEvtDesc->cRawDataNonStatic ? (size_t *)&pEvt->abEvtData[pEvtStrm->cbEvtData] : NULL; + /** @todo Group handling and parenting. */ + + pThis->pEvtCur = pEvt; + size_t cbEvtDataRecv = pEvtStrm->cRawEvtDataSz * pThis->cbTypeSize + pEvtStrm->cbEvtData; + if (cbEvtDataRecv) + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_EVT_DATA, cbEvtDataRecv); + else + { + pThis->pEvtCur = NULL; + RTSemMutexRequest(pThis->hMtx, RT_INDEFINITE_WAIT); + pThis->u64SeqNoLast = pEvt->u64SeqNo; + RTListAppend(&pThis->LstEvts, &pEvt->NdGlob); + RTSemMutexRelease(pThis->hMtx); + *penmEvt = RTTRACELOGRDRPOLLEVT_TRACE_EVENT_RECVD; + *pfContinuePoll = false; + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_MAGIC, TRACELOG_MAGIC_SZ); + } + } + else + rc = VERR_NO_MEMORY; + } + else + rc = VERR_TRACELOG_READER_MALFORMED_LOG; + } + else + rc = VERR_TRACELOG_READER_MALFORMED_LOG; + + return rc; +} + + +/** + * @callback_method_impl{FNRTTRACELOGRDRSTATEHANDLER, Handles received event data.} + */ +static DECLCALLBACK(int) rtTraceLogRdrEvtDataRecvd(PRTTRACELOGRDRINT pThis, RTTRACELOGRDRPOLLEVT *penmEvt, + bool *pfContinuePoll) +{ + RT_NOREF(penmEvt, pfContinuePoll); + + int rc = VINF_SUCCESS; + PRTTRACELOGRDREVTINT pEvt = pThis->pEvtCur; + PCRTTRACELOGRDREVTDESC pEvtDesc = pEvt->pEvtDesc; + uint8_t *pbData = pThis->pbScratch; + size_t cbRawDataNonStatic = 0; + + /* Retrieve any raw data size indicators first. */ + for (unsigned i = 0; i < pEvtDesc->cRawDataNonStatic; i++) + { + size_t cb = 0; + if (pThis->cbTypeSize == 4) + { + cb = RT_BSWAP_U32(*(uint32_t *)pbData); + pbData += 4; + } + else if (pThis->cbTypeSize == 8) + { + cb = RT_BSWAP_U64(*(uint64_t *)pbData); + pbData += 8; + } + else + AssertMsgFailed(("Invalid size_t size %u\n", pThis->cbTypeSize)); + + pEvt->pacbRawData[i] = cb; + cbRawDataNonStatic += cb; + } + + /* Verify that sizes add up. */ + if (pEvt->cbEvtData == pEvtDesc->cbEvtData + cbRawDataNonStatic) + { + /* Copy the data over. */ + memcpy(&pEvt->abEvtData[0], pbData, pEvt->cbEvtData); + + /* Done add event to global list and generate event. */ + pThis->pEvtCur = NULL; + RTSemMutexRequest(pThis->hMtx, RT_INDEFINITE_WAIT); + pThis->u64SeqNoLast = pEvt->u64SeqNo; + RTListAppend(&pThis->LstEvts, &pEvt->NdGlob); + RTSemMutexRelease(pThis->hMtx); + *penmEvt = RTTRACELOGRDRPOLLEVT_TRACE_EVENT_RECVD; + *pfContinuePoll = false; + rc = rtTraceLogRdrStateAdvance(pThis, RTTRACELOGRDRSTATE_RECV_MAGIC, TRACELOG_MAGIC_SZ); + } + else + rc = VERR_TRACELOG_READER_MALFORMED_LOG; + + return rc; +} + + +/** + * @copydoc FNRTTRACELOGRDRSTREAM + */ +static DECLCALLBACK(int) rtTraceLogRdrFileStream(void *pvUser, void *pvBuf, size_t cbBuf, size_t *pcbRead, + RTMSINTERVAL cMsTimeout) +{ + RT_NOREF(cMsTimeout); + RTFILE hFile = (RTFILE)pvUser; + return RTFileRead(hFile, pvBuf, cbBuf, pcbRead); +} + + +/** + * @copydoc FNRTTRACELOGSTREAMCLOSE + */ +static DECLCALLBACK(int) rtTraceLogRdrFileStreamClose(void *pvUser) +{ + RTFILE hFile = (RTFILE)pvUser; + return RTFileClose(hFile); +} + + +/** + * Returns the size of the data for the given event item descriptor. + * + * @returns Size in bytes for the given event item descriptor. + * @param pThis The trace log rader instance. + * @param pEvtItemDesc The event item descriptor. + * @param pacbRawData The raw data size array for he associated event to get the size for non static raw data items. + * @param pidxRawData The index into the raw data size array for the next item to use. + */ +static size_t rtTraceLogRdrEvtItemGetSz(PRTTRACELOGRDRINT pThis, PCRTTRACELOGEVTITEMDESC pEvtItemDesc, + size_t *pacbRawData, unsigned *pidxRawData) +{ + size_t cbRet = 0; + + switch (pEvtItemDesc->enmType) + { + case RTTRACELOGTYPE_BOOL: + cbRet = sizeof(bool); + break; + case RTTRACELOGTYPE_UINT8: + cbRet = sizeof(uint8_t); + break; + case RTTRACELOGTYPE_INT8: + cbRet = sizeof(int8_t); + break; + case RTTRACELOGTYPE_UINT16: + cbRet = sizeof(uint16_t); + break; + case RTTRACELOGTYPE_INT16: + cbRet = sizeof(int16_t); + break; + case RTTRACELOGTYPE_UINT32: + cbRet = sizeof(uint32_t); + break; + case RTTRACELOGTYPE_INT32: + cbRet = sizeof(int32_t); + break; + case RTTRACELOGTYPE_UINT64: + cbRet = sizeof(uint64_t); + break; + case RTTRACELOGTYPE_INT64: + cbRet = sizeof(int64_t); + break; + case RTTRACELOGTYPE_FLOAT32: + cbRet = sizeof(float); + break; + case RTTRACELOGTYPE_FLOAT64: + cbRet = sizeof(double); + break; + case RTTRACELOGTYPE_RAWDATA: + if (pEvtItemDesc->cbRawData == 0) + { + cbRet = pacbRawData[*pidxRawData]; + *pidxRawData++; + } + else + cbRet = pEvtItemDesc->cbRawData; + break; + case RTTRACELOGTYPE_POINTER: + cbRet = pThis->cbTypePtr; + break; + case RTTRACELOGTYPE_SIZE: + cbRet = pThis->cbTypeSize; + break; + default: + AssertMsgFailed(("Invalid type given %d\n", pEvtItemDesc->enmType)); + } + + return cbRet; +} + + +/** + * Resolves the offset of the field with the given name returning the offset and data type. + * + * @returns IPRT status code. + * @param pEvt The event to fetch the data for. + * @param pszName The field to fetch. + * @param poffData Where to store the offset to the data on success. + * @param pcbEvtData Where to store the size of the size of the event data. + * @param ppEvtItemDesc Where to store the event item descriptor. + */ +static int rtTraceLogRdrEvtResolveData(PRTTRACELOGRDREVTINT pEvt, const char *pszName, uint32_t *poffData, + size_t *pcbEvtData, PPCRTTRACELOGEVTITEMDESC ppEvtItemDesc) +{ + PCRTTRACELOGRDREVTDESC pEvtDesc = pEvt->pEvtDesc; + uint32_t offData = 0; + unsigned idxRawData = 0; + + for (unsigned i = 0; i < pEvtDesc->EvtDesc.cEvtItems; i++) + { + PCRTTRACELOGEVTITEMDESC pEvtItemDesc = &pEvtDesc->aEvtItemDesc[i]; + + if (!RTStrCmp(pszName, pEvtItemDesc->pszName)) + { + *poffData = offData; + *pcbEvtData = rtTraceLogRdrEvtItemGetSz(pEvt->pRdr, pEvtItemDesc, pEvt->pacbRawData, &idxRawData); + *ppEvtItemDesc = pEvtItemDesc; + return VINF_SUCCESS; + } + + offData += (uint32_t)rtTraceLogRdrEvtItemGetSz(pEvt->pRdr, pEvtItemDesc, pEvt->pacbRawData, &idxRawData); + } + + return VERR_NOT_FOUND; +} + + +/** + * Fills a value with the given event data. + * + * @returns IPRT status code. + * @param pEvt The event to fetch the data for. + * @param offData Offset the data is located in the event. + * @param cbData Number of bytes for the data. + * @param pEvtItemDesc The event item descriptor. + * @param pVal The value to fill. + */ +static int rtTraceLogRdrEvtFillVal(PRTTRACELOGRDREVTINT pEvt, uint32_t offData, size_t cbData, PCRTTRACELOGEVTITEMDESC pEvtItemDesc, + PRTTRACELOGEVTVAL pVal) +{ + PRTTRACELOGRDRINT pThis = pEvt->pRdr; + uint8_t *pbData = &pEvt->abEvtData[offData]; + + pVal->pItemDesc = pEvtItemDesc; + switch (pEvtItemDesc->enmType) + { + case RTTRACELOGTYPE_BOOL: + pVal->u.f = *(bool *)pbData; + break; + case RTTRACELOGTYPE_UINT8: + pVal->u.u8 = *pbData; + break; + case RTTRACELOGTYPE_INT8: + pVal->u.i8 = *(int8_t *)pbData; + break; + case RTTRACELOGTYPE_UINT16: + { + uint16_t u16Tmp = *(uint16_t *)pbData; + if (pThis->fConvEndianess) + pVal->u.u16 = RT_BSWAP_U16(u16Tmp); + else + pVal->u.u16 = u16Tmp; + break; + } + case RTTRACELOGTYPE_INT16: + { + uint8_t abData[2]; + if (pThis->fConvEndianess) + { + abData[0] = pbData[1]; + abData[1] = pbData[0]; + } + else + { + abData[0] = pbData[0]; + abData[1] = pbData[1]; + } + + pVal->u.i16 = *(int16_t *)&abData[0]; + break; + } + case RTTRACELOGTYPE_UINT32: + { + uint32_t u32Tmp = *(uint32_t *)pbData; + if (pThis->fConvEndianess) + pVal->u.u32 = RT_BSWAP_U32(u32Tmp); + else + pVal->u.u32 = u32Tmp; + break; + } + case RTTRACELOGTYPE_INT32: + { + uint8_t abData[4]; + if (pThis->fConvEndianess) + { + abData[0] = pbData[3]; + abData[1] = pbData[2]; + abData[2] = pbData[1]; + abData[3] = pbData[0]; + } + else + { + abData[0] = pbData[0]; + abData[1] = pbData[1]; + abData[2] = pbData[2]; + abData[3] = pbData[3]; + } + + pVal->u.i32 = *(int32_t *)&abData[0]; + break; + } + case RTTRACELOGTYPE_UINT64: + { + uint64_t u64Tmp = *(uint64_t *)pbData; + if (pThis->fConvEndianess) + pVal->u.u64 = RT_BSWAP_U64(u64Tmp); + else + pVal->u.u64 = u64Tmp; + break; + } + case RTTRACELOGTYPE_INT64: + { + uint8_t abData[8]; + if (pThis->fConvEndianess) + { + abData[0] = pbData[7]; + abData[1] = pbData[6]; + abData[2] = pbData[5]; + abData[3] = pbData[4]; + abData[4] = pbData[3]; + abData[5] = pbData[2]; + abData[6] = pbData[1]; + abData[7] = pbData[0]; + } + else + { + abData[0] = pbData[0]; + abData[1] = pbData[1]; + abData[2] = pbData[2]; + abData[3] = pbData[3]; + abData[4] = pbData[4]; + abData[5] = pbData[5]; + abData[6] = pbData[6]; + abData[7] = pbData[7]; + } + + pVal->u.i32 = *(int64_t *)&abData[0]; + break; + } + case RTTRACELOGTYPE_FLOAT32: + { + uint8_t abData[4]; + if (pThis->fConvEndianess) + { + abData[0] = pbData[3]; + abData[1] = pbData[2]; + abData[2] = pbData[1]; + abData[3] = pbData[0]; + } + else + { + abData[0] = pbData[0]; + abData[1] = pbData[1]; + abData[2] = pbData[2]; + abData[3] = pbData[3]; + } + + pVal->u.f32 = *(float *)&abData[0]; + break; + } + case RTTRACELOGTYPE_FLOAT64: + { + uint8_t abData[8]; + if (pThis->fConvEndianess) + { + abData[0] = pbData[7]; + abData[1] = pbData[6]; + abData[2] = pbData[5]; + abData[3] = pbData[4]; + abData[4] = pbData[3]; + abData[5] = pbData[2]; + abData[6] = pbData[1]; + abData[7] = pbData[0]; + } + else + { + abData[0] = pbData[0]; + abData[1] = pbData[1]; + abData[2] = pbData[2]; + abData[3] = pbData[3]; + abData[4] = pbData[4]; + abData[5] = pbData[5]; + abData[6] = pbData[6]; + abData[7] = pbData[7]; + } + + pVal->u.f64 = *(double *)&abData[0]; + break; + } + case RTTRACELOGTYPE_RAWDATA: + pVal->u.RawData.pb = pbData; + if (pEvtItemDesc->cbRawData == 0) + pVal->u.RawData.cb = cbData; + else + pVal->u.RawData.cb = pEvtItemDesc->cbRawData; + break; + case RTTRACELOGTYPE_POINTER: + { + if (pThis->cbTypePtr == 4) + { + if (pThis->fConvEndianess) + pVal->u.uPtr = RT_BSWAP_U32(*(uint32_t *)pbData); + else + pVal->u.uPtr = *(uint32_t *)pbData; + } + else if (pThis->cbTypePtr == 8) + { + if (pThis->fConvEndianess) + pVal->u.uPtr = RT_BSWAP_U64(*(uint64_t *)pbData); + else + pVal->u.uPtr = *(uint64_t *)pbData; + } + else + AssertMsgFailed(("Invalid pointer size %d, should not happen!\n", pThis->cbTypePtr)); + break; + } + case RTTRACELOGTYPE_SIZE: + { + if (pThis->cbTypeSize == 4) + { + if (pThis->fConvEndianess) + pVal->u.sz = RT_BSWAP_U32(*(uint32_t *)pbData); + else + pVal->u.sz = *(uint32_t *)pbData; + } + else if (pThis->cbTypeSize == 8) + { + if (pThis->fConvEndianess) + pVal->u.sz = RT_BSWAP_U64(*(uint64_t *)pbData); + else + pVal->u.sz = *(uint64_t *)pbData; + } + else + AssertMsgFailed(("Invalid size_t size %d, should not happen!\n", pThis->cbTypeSize)); + break; + } + default: + AssertMsgFailed(("Invalid type given %d\n", pEvtItemDesc->enmType)); + } + + return VINF_SUCCESS; +} + + +RTDECL(int) RTTraceLogRdrCreate(PRTTRACELOGRDR phTraceLogRdr, PFNRTTRACELOGRDRSTREAM pfnStreamIn, + PFNRTTRACELOGSTREAMCLOSE pfnStreamClose, void *pvUser) +{ + AssertPtrReturn(phTraceLogRdr, VERR_INVALID_POINTER); + AssertPtrReturn(pfnStreamIn, VERR_INVALID_POINTER); + AssertPtrReturn(pfnStreamClose, VERR_INVALID_POINTER); + int rc = VINF_SUCCESS; + PRTTRACELOGRDRINT pThis = (PRTTRACELOGRDRINT)RTMemAllocZ(sizeof(*pThis)); + if (pThis) + { + rc = RTSemMutexCreate(&pThis->hMtx); + if (RT_SUCCESS(rc)) + { + rc = RTStrCacheCreate(&pThis->hStrCache, "TRACELOGRDR"); + if (RT_SUCCESS(rc)) + { + RTListInit(&pThis->LstEvts); + pThis->u32Magic = RTTRACELOGRDR_MAGIC; + pThis->pfnStreamIn = pfnStreamIn; + pThis->pfnStreamClose = pfnStreamClose; + pThis->pvUser = pvUser; + pThis->enmState = RTTRACELOGRDRSTATE_RECV_HDR; + pThis->fConvEndianess = false; + pThis->pszDesc = NULL; + pThis->cEvtDescsCur = 0; + pThis->cEvtDescsMax = 0; + pThis->papEvtDescs = NULL; + pThis->pEvtDescCur = NULL; + pThis->u64SeqNoLast = 0; + pThis->cbScratch = sizeof(TRACELOGHDR); + pThis->offScratch = 0; + pThis->cbRecvLeft = sizeof(TRACELOGHDR); + pThis->pbScratch = (uint8_t *)RTMemAllocZ(pThis->cbScratch); + if (RT_LIKELY(pThis->pbScratch)) + { + *phTraceLogRdr = pThis; + return VINF_SUCCESS; + } + else + rc = VERR_NO_MEMORY; + + RTStrCacheDestroy(pThis->hStrCache); + } + + RTSemMutexDestroy(pThis->hMtx); + } + RTMemFree(pThis); + } + else + rc = VERR_NO_MEMORY; + + return rc; +} + + +RTDECL(int) RTTraceLogRdrCreateFromFile(PRTTRACELOGRDR phTraceLogRdr, const char *pszFilename) +{ + AssertPtrReturn(phTraceLogRdr, VERR_INVALID_POINTER); + AssertPtrReturn(pszFilename, VERR_INVALID_POINTER); + + RTFILE hFile = NIL_RTFILE; + int rc = RTFileOpen(&hFile, pszFilename, RTFILE_O_OPEN | RTFILE_O_READ | RTFILE_O_DENY_NONE); + if (RT_SUCCESS(rc)) + { + rc = RTTraceLogRdrCreate(phTraceLogRdr, rtTraceLogRdrFileStream, rtTraceLogRdrFileStreamClose, hFile); + if (RT_FAILURE(rc)) + { + RTFileClose(hFile); + RTFileDelete(pszFilename); + } + } + + return rc; +} + + +RTDECL(int) RTTraceLogRdrDestroy(RTTRACELOGRDR hTraceLogRdr) +{ + PRTTRACELOGRDRINT pThis = hTraceLogRdr; + AssertPtrReturn(pThis, VERR_INVALID_HANDLE); + + pThis->u32Magic = RTTRACELOGRDR_MAGIC_DEAD; + pThis->pfnStreamClose(pThis->pvUser); + for (unsigned i = 0; i < pThis->cEvtDescsCur; i++) + RTMemFree(pThis->papEvtDescs[i]); + if (pThis->papEvtDescs) + RTMemFree(pThis->papEvtDescs); + RTSemMutexDestroy(pThis->hMtx); + RTMemFree(pThis->pbScratch); + RTStrCacheDestroy(pThis->hStrCache); + RTMemFree(pThis); + return VINF_SUCCESS; +} + + +RTDECL(int) RTTraceLogRdrEvtPoll(RTTRACELOGRDR hTraceLogRdr, RTTRACELOGRDRPOLLEVT *penmEvt, RTMSINTERVAL cMsTimeout) +{ + PRTTRACELOGRDRINT pThis = hTraceLogRdr; + AssertPtrReturn(pThis, VERR_INVALID_HANDLE); + AssertPtrReturn(penmEvt, VERR_INVALID_POINTER); + + int rc = VINF_SUCCESS; + bool fContinue = true; + while ( RT_SUCCESS(rc) + && fContinue) + { + size_t cbRecvd = 0; + + rc = rtTraceLogRdrStreamRead(pThis, &pThis->pbScratch[pThis->offScratch], + pThis->cbRecvLeft, &cbRecvd, cMsTimeout); + if (RT_SUCCESS(rc)) + { + if (cbRecvd == pThis->cbRecvLeft) + { + /* Act according to the current state. */ + rc = g_apfnStateHandlers[pThis->enmState](pThis, penmEvt, &fContinue); + } + else + pThis->cbRecvLeft -= cbRecvd; + } + } + + return rc; +} + + +RTDECL(int) RTTraceLogRdrQueryLastEvt(RTTRACELOGRDR hTraceLogRdr, PRTTRACELOGRDREVT phRdrEvt) +{ + PRTTRACELOGRDRINT pThis = hTraceLogRdr; + AssertPtrReturn(pThis, VERR_INVALID_HANDLE); + AssertPtrReturn(phRdrEvt, VERR_INVALID_POINTER); + + int rc = VINF_SUCCESS; + RTSemMutexRequest(pThis->hMtx, RT_INDEFINITE_WAIT); + PRTTRACELOGRDREVTINT pEvt = RTListGetLast(&pThis->LstEvts, RTTRACELOGRDREVTINT, NdGlob); + *phRdrEvt = pEvt; + if (!pEvt) + rc = VERR_NOT_FOUND; + RTSemMutexRelease(pThis->hMtx); + + return rc; +} + + +RTDECL(int) RTTraceLogRdrQueryIterator(RTTRACELOGRDR hTraceLogRdr, PRTTRACELOGRDRIT phIt) +{ + PRTTRACELOGRDRINT pThis = hTraceLogRdr; + AssertPtrReturn(pThis, VERR_INVALID_HANDLE); + AssertPtrReturn(phIt, VERR_INVALID_POINTER); + + int rc = VINF_SUCCESS; + PRTTRACELOGRDRITINT pIt = (PRTTRACELOGRDRITINT)RTMemAllocZ(sizeof(*pIt)); + if (RT_LIKELY(pIt)) + { + pIt->pRdr = pThis; + pIt->pEvt = RTListGetFirst(&pThis->LstEvts, RTTRACELOGRDREVTINT, NdGlob); + } + else + rc = VERR_NO_MEMORY; + + return rc; +} + + +RTDECL(void) RTTraceLogRdrIteratorFree(RTTRACELOGRDRIT hIt) +{ + PRTTRACELOGRDRITINT pIt = hIt; + AssertPtrReturnVoid(pIt); + + RTMemFree(pIt); +} + + +RTDECL(int) RTTraceLogRdrIteratorNext(RTTRACELOGRDRIT hIt) +{ + PRTTRACELOGRDRITINT pIt = hIt; + AssertPtrReturn(pIt, VERR_INVALID_HANDLE); + + if (!pIt->pEvt) + return VERR_TRACELOG_READER_ITERATOR_END; + + int rc = VINF_SUCCESS; + PRTTRACELOGRDREVTINT pEvtNext = RTListGetNext(&pIt->pRdr->LstEvts, pIt->pEvt, RTTRACELOGRDREVTINT, NdGlob); + + if (pEvtNext) + pIt->pEvt = pEvtNext; + else + rc = VERR_TRACELOG_READER_ITERATOR_END; + + return rc; +} + + +RTDECL(int) RTTraceLogRdrIteratorQueryEvent(RTTRACELOGRDRIT hIt, PRTTRACELOGRDREVT phRdrEvt) +{ + PRTTRACELOGRDRITINT pIt = hIt; + AssertPtrReturn(pIt, VERR_INVALID_HANDLE); + AssertPtrReturn(phRdrEvt, VERR_INVALID_POINTER); + + *phRdrEvt = pIt->pEvt; + return VINF_SUCCESS; +} + + +RTDECL(uint64_t) RTTraceLogRdrEvtGetSeqNo(RTTRACELOGRDREVT hRdrEvt) +{ + PRTTRACELOGRDREVTINT pEvt = hRdrEvt; + AssertPtrReturn(pEvt, 0); + + return pEvt->u64SeqNo; +} + + +RTDECL(uint64_t) RTTraceLogRdrEvtGetTs(RTTRACELOGRDREVT hRdrEvt) +{ + PRTTRACELOGRDREVTINT pEvt = hRdrEvt; + AssertPtrReturn(pEvt, 0); + + return pEvt->u64Ts; +} + + +RTDECL(bool) RTTraceLogRdrEvtIsGrouped(RTTRACELOGRDREVT hRdrEvt) +{ + PRTTRACELOGRDREVTINT pEvt = hRdrEvt; + AssertPtrReturn(pEvt, false); + + return pEvt->idGrp != 0; +} + + +RTDECL(PCRTTRACELOGEVTDESC) RTTraceLogRdrEvtGetDesc(RTTRACELOGRDREVT hRdrEvt) +{ + PRTTRACELOGRDREVTINT pEvt = hRdrEvt; + AssertPtrReturn(pEvt, NULL); + + return &pEvt->pEvtDesc->EvtDesc; +} + + +RTDECL(int) RTTraceLogRdrEvtQueryVal(RTTRACELOGRDREVT hRdrEvt, const char *pszName, PRTTRACELOGEVTVAL pVal) +{ + PRTTRACELOGRDREVTINT pEvt = hRdrEvt; + AssertPtrReturn(pEvt, VERR_INVALID_HANDLE); + + uint32_t offData = 0; + size_t cbData = 0; + PCRTTRACELOGEVTITEMDESC pEvtItemDesc = NULL; + int rc = rtTraceLogRdrEvtResolveData(pEvt, pszName, &offData, &cbData, &pEvtItemDesc); + if (RT_SUCCESS(rc)) + rc = rtTraceLogRdrEvtFillVal(pEvt, offData, cbData, pEvtItemDesc, pVal); + return rc; +} + + +RTDECL(int) RTTraceLogRdrEvtFillVals(RTTRACELOGRDREVT hRdrEvt, unsigned idxItemStart, PRTTRACELOGEVTVAL paVals, + unsigned cVals, unsigned *pcVals) +{ + PRTTRACELOGRDREVTINT pEvt = hRdrEvt; + AssertPtrReturn(pEvt, VERR_INVALID_HANDLE); + + PCRTTRACELOGRDREVTDESC pEvtDesc = pEvt->pEvtDesc; + AssertReturn(idxItemStart < pEvtDesc->EvtDesc.cEvtItems, VERR_INVALID_PARAMETER); + + /* Advance to the item the caller wants to fill in. */ + uint32_t offData = 0; + unsigned idxRawData = 0; + + for (unsigned i = 0; i < idxItemStart; i++) + { + PCRTTRACELOGEVTITEMDESC pEvtItemDesc = &pEvtDesc->aEvtItemDesc[i]; + offData += (uint32_t)rtTraceLogRdrEvtItemGetSz(pEvt->pRdr, pEvtItemDesc, pEvt->pacbRawData, &idxRawData); + } + + int rc = VINF_SUCCESS; + unsigned idxItemEnd = RT_MIN(idxItemStart + cVals, pEvtDesc->EvtDesc.cEvtItems); + for (unsigned i = idxItemStart; i < idxItemEnd && RT_SUCCESS(rc); i++) + { + PCRTTRACELOGEVTITEMDESC pEvtItemDesc = &pEvtDesc->aEvtItemDesc[i]; + size_t cbData = rtTraceLogRdrEvtItemGetSz(pEvt->pRdr, pEvtItemDesc, pEvt->pacbRawData, &idxRawData); + + rc = rtTraceLogRdrEvtFillVal(pEvt, offData, cbData, pEvtItemDesc, &paVals[i - idxItemStart]); + offData += (uint32_t)cbData; + } + + *pcVals = idxItemEnd - idxItemStart; + + return rc; +} + diff --git a/src/VBox/Runtime/common/log/tracelogwriter.cpp b/src/VBox/Runtime/common/log/tracelogwriter.cpp new file mode 100644 index 00000000..35d6e0d3 --- /dev/null +++ b/src/VBox/Runtime/common/log/tracelogwriter.cpp @@ -0,0 +1,953 @@ +/* $Id: tracelogwriter.cpp $ */ +/** @file + * IPRT - Trace log writer. + */ + +/* + * Copyright (C) 2018-2020 Oracle Corporation + * + * This file is part of VirtualBox Open Source Edition (OSE), as + * available from http://www.virtualbox.org. This file is free software; + * you can redistribute it and/or modify it under the terms of the GNU + * General Public License (GPL) as published by the Free Software + * Foundation, in version 2 as it comes in the "COPYING" file of the + * VirtualBox OSE distribution. VirtualBox OSE is distributed in the + * hope that it will be useful, but WITHOUT ANY WARRANTY of any kind. + * + * The contents of this file may alternatively be used under the terms + * of the Common Development and Distribution License Version 1.0 + * (CDDL) only, as it comes in the "COPYING.CDDL" file of the + * VirtualBox OSE distribution, in which case the provisions of the + * CDDL are applicable instead of those of the GPL. + * + * You may elect to license modified versions of this file under the + * terms and conditions of either the GPL or the CDDL or both. + */ + + +/********************************************************************************************************************************* +* Header Files * +*********************************************************************************************************************************/ +#include "internal/iprt.h" +#include <iprt/formats/tracelog.h> +#include <iprt/tracelog.h> + + +#include <iprt/avl.h> +#include <iprt/asm.h> +#include <iprt/assert.h> +#include <iprt/err.h> +#include <iprt/file.h> +#include <iprt/log.h> +#include <iprt/mem.h> +#include <iprt/semaphore.h> +#include <iprt/string.h> +#include <iprt/tcp.h> +#include <iprt/time.h> + +#include "internal/magics.h" + + +/********************************************************************************************************************************* +* Structures and Typedefs * +*********************************************************************************************************************************/ + + +/** + * Trace log writer internal event descriptor. + */ +typedef struct RTTRACELOGWREVTDESC +{ + /** AVL node core data */ + AVLPVNODECORE Core; + /** The ID associated with this event descriptor. */ + uint32_t u32Id; + /** Overall size of the event data not counting variable raw data items. */ + size_t cbEvtData; + /** Number of non static raw binary items in the descriptor. */ + uint32_t cRawDataNonStatic; + /** Pointer to the scratch event data buffer when adding events. */ + uint8_t *pbEvt; + /** Embedded event descriptor. */ + RTTRACELOGEVTDESC EvtDesc; + /** Array of event item descriptors, variable in size. */ + RTTRACELOGEVTITEMDESC aEvtItemDesc[1]; +} RTTRACELOGWREVTDESC; +/** Pointer to internal trace log writer event descriptor. */ +typedef RTTRACELOGWREVTDESC *PRTTRACELOGWREVTDESC; +/** Pointer to const internal trace log writer event descriptor. */ +typedef const RTTRACELOGWREVTDESC *PCRTTRACELOGWREVTDESC; + + +/** + * Trace log writer instance data. + */ +typedef struct RTTRACELOGWRINT +{ + /** Magic for identification. */ + uint32_t u32Magic; + /** Stream out callback. */ + PFNRTTRACELOGWRSTREAM pfnStreamOut; + /** Stream close callback .*/ + PFNRTTRACELOGSTREAMCLOSE pfnStreamClose; + /** Opaque user data passed to the stream callback. */ + void *pvUser; + /** Mutex protecting the structure. */ + RTSEMMUTEX hMtx; + /** Next sequence number to use. */ + volatile uint64_t u64SeqNoNext; + /** AVL tree root for event descriptor lookups. */ + AVLPVTREE pTreeEvtDescs; + /** Number of event descriptors known. */ + uint32_t cEvtDescs; +} RTTRACELOGWRINT; +/** Pointer to a trace log writer instance. */ +typedef RTTRACELOGWRINT *PRTTRACELOGWRINT; + + +/** + * The TCP server/client state. + */ +typedef struct RTTRACELOGWRTCP +{ + /** Flag whether this is a server or client instance. */ + bool fIsServer; + /** The TCP socket handle for the connection. */ + RTSOCKET hSock; + /** The TCP server. */ + PRTTCPSERVER pTcpSrv; +} RTTRACELOGWRTCP; +/** Pointer to a TCP server/client state. */ +typedef RTTRACELOGWRTCP *PRTTRACELOGWRTCP; + + +/********************************************************************************************************************************* +* Defined Constants And Macros * +*********************************************************************************************************************************/ + + +/** + * Returns the size required for the internal event descriptor representation. + * + * @returns Number of bytes required. + * @param pEvtDesc Pointer to the external descriptor. + */ +static size_t rtTraceLogWrtEvtDescGetSz(PCRTTRACELOGEVTDESC pEvtDesc) +{ + size_t cbAlloc = RT_UOFFSETOF_DYN(RTTRACELOGWREVTDESC, aEvtItemDesc[pEvtDesc->cEvtItems]); + + cbAlloc += strlen(pEvtDesc->pszId) + 1; + if (pEvtDesc->pszDesc) + cbAlloc += strlen(pEvtDesc->pszDesc) + 1; + for (unsigned i = 0; i < pEvtDesc->cEvtItems; i++) + { + PCRTTRACELOGEVTITEMDESC pEvtItemDesc = &pEvtDesc->paEvtItemDesc[i]; + + cbAlloc += strlen(pEvtItemDesc->pszName) + 1; + if (pEvtItemDesc->pszDesc) + cbAlloc += strlen(pEvtItemDesc->pszDesc) + 1; + } + + return cbAlloc; +} + + +/** + * Copies a string into a supplied buffer assigning the start to the given string pointer. + * + * @returns Pointer to the memory after the destination buffer holding the string. + * @param ppsz Where to store the pointer to the start of the string. + * @param pszTo Where to copy the string including the temrinator to. + * @param pszFrom The string to copy. + */ +DECLINLINE(char *) rtTraceLogWrCopyStr(const char **ppsz, char *pszTo, const char *pszFrom) +{ + *ppsz = pszTo; + size_t cchCopy = strlen(pszFrom) + 1; + memcpy(pszTo, pszFrom, cchCopy); + + return pszTo + cchCopy; +} + + +/** + * Converts the type enum to the size of the the event item data in bytes. + * + * @returns Event item data size in bytes. + * @param pEvtItemDesc The event item descriptor. + */ +static size_t rtTraceLogWrGetEvtItemDataSz(PCRTTRACELOGEVTITEMDESC pEvtItemDesc) +{ + size_t cb = 0; + + switch (pEvtItemDesc->enmType) + { + case RTTRACELOGTYPE_BOOL: + case RTTRACELOGTYPE_UINT8: + case RTTRACELOGTYPE_INT8: + { + cb = 1; + break; + } + case RTTRACELOGTYPE_UINT16: + case RTTRACELOGTYPE_INT16: + { + cb = 2; + break; + } + case RTTRACELOGTYPE_UINT32: + case RTTRACELOGTYPE_INT32: + case RTTRACELOGTYPE_FLOAT32: + { + cb = 4; + break; + } + case RTTRACELOGTYPE_UINT64: + case RTTRACELOGTYPE_INT64: + case RTTRACELOGTYPE_FLOAT64: + { + cb = 8; + break; + } + case RTTRACELOGTYPE_RAWDATA: + { + cb = pEvtItemDesc->cbRawData; + break; + } + case RTTRACELOGTYPE_POINTER: + { + cb = sizeof(uintptr_t); + break; + } + case RTTRACELOGTYPE_SIZE: + { + cb = sizeof(size_t); + break; + } + default: + AssertMsgFailed(("Invalid type %d\n", pEvtItemDesc->enmType)); + } + + return cb; +} + + +/** + * Converts API severity enum to the stream representation. + * + * @returns Stream representation of the severity. + * @param enmSeverity The API severity. + */ +static uint32_t rtTraceLogWrConvSeverityToStream(RTTRACELOGEVTSEVERITY enmSeverity) +{ + switch (enmSeverity) + { + case RTTRACELOGEVTSEVERITY_INFO: + return TRACELOG_EVTDESC_SEVERITY_INFO; + case RTTRACELOGEVTSEVERITY_WARNING: + return TRACELOG_EVTDESC_SEVERITY_WARNING; + case RTTRACELOGEVTSEVERITY_ERROR: + return TRACELOG_EVTDESC_SEVERITY_ERROR; + case RTTRACELOGEVTSEVERITY_FATAL: + return TRACELOG_EVTDESC_SEVERITY_FATAL; + case RTTRACELOGEVTSEVERITY_DEBUG: + return TRACELOG_EVTDESC_SEVERITY_DEBUG; + default: + AssertMsgFailed(("Invalid severity %d\n", enmSeverity)); + } + + /* Should not happen. */ + return TRACELOG_EVTDESC_SEVERITY_FATAL; +} + + +/** + * Converts API type enum to the stream representation. + * + * @returns Stream representation of the type. + * @param enmType The API type. + */ +static uint32_t rtTraceLogWrConvTypeToStream(RTTRACELOGTYPE enmType) +{ + switch (enmType) + { + case RTTRACELOGTYPE_BOOL: + return TRACELOG_EVTITEMDESC_TYPE_BOOL; + case RTTRACELOGTYPE_UINT8: + return TRACELOG_EVTITEMDESC_TYPE_UINT8; + case RTTRACELOGTYPE_INT8: + return TRACELOG_EVTITEMDESC_TYPE_INT8; + case RTTRACELOGTYPE_UINT16: + return TRACELOG_EVTITEMDESC_TYPE_UINT16; + case RTTRACELOGTYPE_INT16: + return TRACELOG_EVTITEMDESC_TYPE_INT16; + case RTTRACELOGTYPE_UINT32: + return TRACELOG_EVTITEMDESC_TYPE_UINT32; + case RTTRACELOGTYPE_INT32: + return TRACELOG_EVTITEMDESC_TYPE_INT32; + case RTTRACELOGTYPE_UINT64: + return TRACELOG_EVTITEMDESC_TYPE_UINT64; + case RTTRACELOGTYPE_INT64: + return TRACELOG_EVTITEMDESC_TYPE_INT64; + case RTTRACELOGTYPE_FLOAT32: + return TRACELOG_EVTITEMDESC_TYPE_FLOAT32; + case RTTRACELOGTYPE_FLOAT64: + return TRACELOG_EVTITEMDESC_TYPE_FLOAT64; + case RTTRACELOGTYPE_RAWDATA: + return TRACELOG_EVTITEMDESC_TYPE_RAWDATA; + case RTTRACELOGTYPE_POINTER: + return TRACELOG_EVTITEMDESC_TYPE_POINTER; + case RTTRACELOGTYPE_SIZE: + return TRACELOG_EVTITEMDESC_TYPE_SIZE; + default: + AssertMsgFailed(("Invalid type %d\n", enmType)); + } + + /* Should not happen. */ + return RTTRACELOGTYPE_RAWDATA; +} + + +/** + * Initializes the internal representation of the event descriptor from the given one. + * + * @returns Pointer to the internal instance of the event descriptor. + * NULL if out of memory. + * @param pEvtDesc Pointer to the external descriptor. + */ +static PRTTRACELOGWREVTDESC rtTraceLogWrEvtDescInit(PCRTTRACELOGEVTDESC pEvtDesc) +{ + size_t cbAlloc = rtTraceLogWrtEvtDescGetSz(pEvtDesc); + size_t cbEvtData = 0; + PRTTRACELOGWREVTDESC pEvtDescInt = (PRTTRACELOGWREVTDESC)RTMemAllocZ(cbAlloc); + if (RT_LIKELY(pEvtDescInt)) + { + char *pszStrSpace = (char *)&pEvtDescInt->aEvtItemDesc[pEvtDesc->cEvtItems]; /* Get space for strings after the descriptor. */ + + pEvtDescInt->EvtDesc.enmSeverity = pEvtDesc->enmSeverity; + pEvtDescInt->EvtDesc.cEvtItems = pEvtDesc->cEvtItems; + pEvtDescInt->EvtDesc.paEvtItemDesc = &pEvtDescInt->aEvtItemDesc[0]; + + /* Copy ID and optional description over. */ + pszStrSpace = rtTraceLogWrCopyStr(&pEvtDescInt->EvtDesc.pszId, pszStrSpace, pEvtDesc->pszId); + if (pEvtDesc->pszDesc) + pszStrSpace = rtTraceLogWrCopyStr(&pEvtDescInt->EvtDesc.pszDesc, pszStrSpace, pEvtDesc->pszDesc); + + /* Go through the event item descriptors and initialize them too. */ + for (unsigned i = 0; i < pEvtDesc->cEvtItems; i++) + { + PCRTTRACELOGEVTITEMDESC pEvtItemDescFrom = &pEvtDesc->paEvtItemDesc[i]; + PRTTRACELOGEVTITEMDESC pEvtItemDescTo = &pEvtDescInt->aEvtItemDesc[i]; + + pEvtItemDescTo->enmType = pEvtItemDescFrom->enmType; + pEvtItemDescTo->cbRawData = pEvtItemDescFrom->cbRawData; + + cbEvtData += rtTraceLogWrGetEvtItemDataSz(pEvtItemDescFrom); + if ( pEvtItemDescTo->enmType == RTTRACELOGTYPE_RAWDATA + && !pEvtItemDescFrom->cbRawData) + pEvtDescInt->cRawDataNonStatic++; + + pszStrSpace = rtTraceLogWrCopyStr(&pEvtItemDescTo->pszName, pszStrSpace, pEvtItemDescFrom->pszName); + if (pEvtItemDescFrom->pszDesc) + pszStrSpace = rtTraceLogWrCopyStr(&pEvtItemDescTo->pszDesc, pszStrSpace, pEvtItemDescFrom->pszDesc); + } + + pEvtDescInt->cbEvtData = cbEvtData; + if (cbEvtData) + { + pEvtDescInt->pbEvt = (uint8_t *)RTMemAllocZ(cbEvtData); + if (!pEvtDescInt->pbEvt) + { + RTMemFree(pEvtDescInt); + pEvtDescInt = NULL; + } + } + } + + return pEvtDescInt; +} + + +/** + * Wrapper around the stream callback. + * + * @returns IPRT status code returned by the stream callback. + * @param pThis The trace log writer instance. + * @param pvBuf The data to stream. + * @param cbBuf Number of bytes to stream. + */ +DECLINLINE(int) rtTraceLogWrStream(PRTTRACELOGWRINT pThis, const void *pvBuf, size_t cbBuf) +{ + return pThis->pfnStreamOut(pThis->pvUser, pvBuf, cbBuf, NULL); +} + + +/** + * Initializes a given event structure. + * + * @returns Total number of bytes for the event data associated with this event. + * @param pEvt Pointer to the event structure to initialise. + * @param pEvtDescInt The internal event descriptor to format the data accordingly to. + * @param fFlags Flags to use for this event. + * @param uGrpId The group ID to identify grouped events. + * @param uParentGrpId The parent group ID. + * @param pacbRawData Array of raw data size indicators. + */ +DECLINLINE(size_t) rtTraceLogWrEvtInit(PTRACELOGEVT pEvt, + PRTTRACELOGWREVTDESC pEvtDescInt, uint32_t fFlags, + RTTRACELOGEVTGRPID uGrpId, RTTRACELOGEVTGRPID uParentGrpId, + size_t *pacbRawData) +{ + uint32_t cbEvtData = (uint32_t)pEvtDescInt->cbEvtData; + for (unsigned i = 0; i < pEvtDescInt->cRawDataNonStatic; i++) + cbEvtData += (uint32_t)pacbRawData[i]; + + uint32_t fEvtFlags = 0; + if (fFlags & RTTRACELOG_WR_ADD_EVT_F_GRP_START) + fEvtFlags |= TRACELOG_EVT_F_GRP_START; + if (fFlags & RTTRACELOG_WR_ADD_EVT_F_GRP_FINISH) + fEvtFlags |= TRACELOG_EVT_F_GRP_END; + + memcpy(&pEvt->szMagic[0], TRACELOG_EVT_MAGIC, sizeof(pEvt->szMagic)); + pEvt->u64Ts = RTTimeNanoTS(); + pEvt->u64EvtGrpId = uGrpId; + pEvt->u64EvtParentGrpId = uParentGrpId; + pEvt->fFlags = fEvtFlags; + pEvt->u32EvtDescId = pEvtDescInt->u32Id; + pEvt->cbEvtData = cbEvtData; + pEvt->cRawEvtDataSz = pEvtDescInt->cRawDataNonStatic; + + return cbEvtData; +} + + +/** + * Streams the whole event including associated data. + * + * @returns IPRT status code. + * @param pThis The trace log writer instance. + * @param pEvt Pointer to the initialised event structure. + * @param pvEvtData The raw event data. + * @param cbEvtData Size of the event data. + * @param pacbRawData Pointer to the array of size indicators for non static + * raw data in the event data stream. + */ +DECLINLINE(int) rtTraceLogWrEvtStream(PRTTRACELOGWRINT pThis, PTRACELOGEVT pEvt, const void *pvEvtData, + size_t cbEvtData, size_t *pacbRawData) +{ + /** @todo Get rid of locking. */ + int rc = RTSemMutexRequest(pThis->hMtx, RT_INDEFINITE_WAIT); + if (RT_SUCCESS(rc)) + { + pEvt->u64SeqNo = ASMAtomicIncU64(&pThis->u64SeqNoNext); + + /* Write the data out. */ + rc = rtTraceLogWrStream(pThis, pEvt, sizeof(TRACELOGEVT)); + if ( RT_SUCCESS(rc) + && pEvt->cRawEvtDataSz) + rc = rtTraceLogWrStream(pThis, pacbRawData, pEvt->cRawEvtDataSz * sizeof(size_t)); + if ( RT_SUCCESS(rc) + && cbEvtData) + rc = rtTraceLogWrStream(pThis, pvEvtData, cbEvtData); + RTSemMutexRelease(pThis->hMtx); + } + + return rc; +} + + +/** + * Returns the intenral event descriptor for the given event descriptor. + * + * @returns Pointer to the internal event descriptor or NULL if not found. + * @param pThis The trace log writer instance. + * @param pEvtDesc The event descriptor to search for. + */ +DECLINLINE(PRTTRACELOGWREVTDESC) rtTraceLogWrEvtDescGetInternal(PRTTRACELOGWRINT pThis, + PCRTTRACELOGEVTDESC pEvtDesc) +{ + int rc = RTSemMutexRequest(pThis->hMtx, RT_INDEFINITE_WAIT); + if (RT_SUCCESS(rc)) + { + PRTTRACELOGWREVTDESC pEvtDescInt = (PRTTRACELOGWREVTDESC)RTAvlPVGet(&pThis->pTreeEvtDescs, (void *)pEvtDesc); + RTSemMutexRelease(pThis->hMtx); + return pEvtDescInt; + } + + return NULL; +} + + +/** + * Initializes the trace log. + * + * @returns IPRT status code. + * @param pThis The trace log writer instance. + * @param pszDesc The description to use. + */ +static int rtTraceLogWrInit(PRTTRACELOGWRINT pThis, const char *pszDesc) +{ + /* Start by assembling the header. */ + TRACELOGHDR Hdr; + + RT_ZERO(Hdr); + memcpy(&Hdr.szMagic[0], TRACELOG_HDR_MAGIC, sizeof(Hdr.szMagic)); + Hdr.u32Endianess = TRACELOG_HDR_ENDIANESS; /* Endianess marker. */ + Hdr.u32Version = TRACELOG_VERSION; + Hdr.fFlags = 0; + Hdr.cbStrDesc = pszDesc ? (uint32_t)strlen(pszDesc) : 0; + Hdr.cbTypePtr = sizeof(uintptr_t); + Hdr.cbTypeSize = sizeof(size_t); + Hdr.u64TsStart = RTTimeNanoTS(); + int rc = rtTraceLogWrStream(pThis, &Hdr, sizeof(Hdr)); + if ( RT_SUCCESS(rc) + && pszDesc) + rc = rtTraceLogWrStream(pThis, pszDesc, Hdr.cbStrDesc); + + return rc; +} + + +static DECLCALLBACK(int) rtTraceLogWrCheckForOverlappingIds(PAVLPVNODECORE pCore, void *pvParam) +{ + PCRTTRACELOGEVTDESC pEvtDesc = (PCRTTRACELOGEVTDESC)pvParam; + PRTTRACELOGWREVTDESC pEvtDescInt = (PRTTRACELOGWREVTDESC)pCore; + + if (!RTStrCmp(pEvtDesc->pszId, pEvtDescInt->EvtDesc.pszId)) + return VERR_ALREADY_EXISTS; + + return VINF_SUCCESS; +} + + +static DECLCALLBACK(int) rtTraceLogWrEvtDescsDestroy(PAVLPVNODECORE pCore, void *pvParam) +{ + PRTTRACELOGWREVTDESC pEvtDesc = (PRTTRACELOGWREVTDESC)pCore; + RT_NOREF(pvParam); + + RTMemFree(pEvtDesc->pbEvt); + RTMemFree(pEvtDesc); + return VINF_SUCCESS; +} + + +/** + * Adds a new event descriptor to the trace log. + * + * @returns IPRT status code. + * @param pThis The trace log writer instance. + * @param pEvtDesc The event descriptor to add. + * @param ppEvtDescInt Where to store the pointer to the internal + * event descriptor - optional. + */ +static int rtTraceLogWrEvtDescAdd(PRTTRACELOGWRINT pThis, PCRTTRACELOGEVTDESC pEvtDesc, + PRTTRACELOGWREVTDESC *ppEvtDescInt) +{ + int rc = RTSemMutexRequest(pThis->hMtx, RT_INDEFINITE_WAIT); + if (RT_SUCCESS(rc)) + { + PRTTRACELOGWREVTDESC pEvtDescInt = (PRTTRACELOGWREVTDESC)RTAvlPVGet(&pThis->pTreeEvtDescs, (void *)pEvtDesc); + if (!pEvtDescInt) + { + rc = RTAvlPVDoWithAll(&pThis->pTreeEvtDescs, true, rtTraceLogWrCheckForOverlappingIds, (void *)pEvtDesc); + if (RT_SUCCESS(rc)) + { + pEvtDescInt = rtTraceLogWrEvtDescInit(pEvtDesc); + if (RT_LIKELY(pEvtDescInt)) + { + pEvtDescInt->Core.Key = (void *)pEvtDesc; + pEvtDescInt->u32Id = pThis->cEvtDescs++; + bool fIns = RTAvlPVInsert(&pThis->pTreeEvtDescs, &pEvtDescInt->Core); + Assert(fIns); RT_NOREF(fIns); + } + else + rc = VERR_NO_MEMORY; + + if (RT_SUCCESS(rc)) + { + TRACELOGEVTDESC EvtDesc; + + RT_ZERO(EvtDesc); + memcpy(&EvtDesc.szMagic[0], TRACELOG_EVTDESC_MAGIC, sizeof(EvtDesc.szMagic)); + EvtDesc.u32Id = pEvtDescInt->u32Id; + EvtDesc.u32Severity = rtTraceLogWrConvSeverityToStream(pEvtDescInt->EvtDesc.enmSeverity); + EvtDesc.cbStrId = (uint32_t)strlen(pEvtDescInt->EvtDesc.pszId); + EvtDesc.cbStrDesc = pEvtDescInt->EvtDesc.pszDesc ? (uint32_t)strlen(pEvtDescInt->EvtDesc.pszDesc) : 0; + EvtDesc.cEvtItems = pEvtDescInt->EvtDesc.cEvtItems; + rc = rtTraceLogWrStream(pThis, &EvtDesc, sizeof(EvtDesc)); + if (RT_SUCCESS(rc)) + rc = rtTraceLogWrStream(pThis, pEvtDescInt->EvtDesc.pszId, EvtDesc.cbStrId); + if ( RT_SUCCESS(rc) + && pEvtDescInt->EvtDesc.pszDesc) + rc = rtTraceLogWrStream(pThis, pEvtDescInt->EvtDesc.pszDesc, EvtDesc.cbStrDesc); + if (RT_SUCCESS(rc)) + { + /* Go through the event items. */ + for (unsigned idxEvtItem = 0; idxEvtItem < EvtDesc.cEvtItems && RT_SUCCESS(rc); idxEvtItem++) + { + PCRTTRACELOGEVTITEMDESC pEvtItemDesc = &pEvtDescInt->EvtDesc.paEvtItemDesc[idxEvtItem]; + TRACELOGEVTITEMDESC EvtItemDesc; + + RT_ZERO(EvtItemDesc); + memcpy(&EvtItemDesc.szMagic[0], TRACELOG_EVTITEMDESC_MAGIC, sizeof(EvtItemDesc.szMagic)); + EvtItemDesc.cbStrName = (uint32_t)strlen(pEvtItemDesc->pszName); + EvtItemDesc.cbStrDesc = pEvtItemDesc->pszDesc ? (uint32_t)strlen(pEvtItemDesc->pszDesc) : 0; + EvtItemDesc.u32Type = rtTraceLogWrConvTypeToStream(pEvtItemDesc->enmType); + EvtItemDesc.cbRawData = (uint32_t)pEvtItemDesc->cbRawData; + rc = rtTraceLogWrStream(pThis, &EvtItemDesc, sizeof(EvtItemDesc)); + if (RT_SUCCESS(rc)) + rc = rtTraceLogWrStream(pThis, pEvtItemDesc->pszName, EvtItemDesc.cbStrName); + if ( RT_SUCCESS(rc) + && pEvtItemDesc->pszDesc) + rc = rtTraceLogWrStream(pThis, pEvtItemDesc->pszDesc, EvtItemDesc.cbStrDesc); + } + } + } + } + + if ( RT_SUCCESS(rc) + && ppEvtDescInt) + *ppEvtDescInt = pEvtDescInt; + } + else + rc = VERR_ALREADY_EXISTS; + RTSemMutexRelease(pThis->hMtx); + } + + return rc; +} + + +/** + * Fills a given buffer with the given event data as described in the given descriptor. + * + * @returns IPRT status code. + * @param pThis The trace log writer instance. + * @param pEvtDescInt Pointer to the internal event descriptor. + * @param pb The byte buffer to fill. + * @param va The event data. + */ +static int rtTraceLogWrEvtFill(PRTTRACELOGWRINT pThis, PRTTRACELOGWREVTDESC pEvtDescInt, uint8_t *pb, va_list va) +{ + int rc = VINF_SUCCESS; + uint8_t *pbCur = pb; + + RT_NOREF(pThis); + + for (unsigned i = 0; i < pEvtDescInt->EvtDesc.cEvtItems; i++) + { + PCRTTRACELOGEVTITEMDESC pEvtItemDesc = &pEvtDescInt->EvtDesc.paEvtItemDesc[i]; + + size_t cbItem = rtTraceLogWrGetEvtItemDataSz(pEvtItemDesc); + switch (cbItem) + { + case sizeof(uint8_t): + *pbCur++ = va_arg(va, /*uint8_t*/ unsigned); + break; + case sizeof(uint16_t): + *(uint16_t *)pbCur = va_arg(va, /*uint16_t*/ unsigned); + pbCur += sizeof(uint16_t); + break; + case sizeof(uint32_t): + *(uint32_t *)pbCur = va_arg(va, uint32_t); + pbCur += sizeof(uint32_t); + break; + case sizeof(uint64_t): + *(uint64_t *)pbCur = va_arg(va, uint64_t); + pbCur += sizeof(uint64_t); + break; + default: + /* Some raw data item. */ + Assert(pEvtItemDesc->enmType == RTTRACELOGTYPE_RAWDATA); + if (cbItem != 0) + { + /* Static raw data. */ + void *pvSrc = va_arg(va, void *); + memcpy(pbCur, pvSrc, cbItem); + pbCur += cbItem; + } + else + { + AssertMsgFailed(("Not implemented!\n")); + rc = VERR_NOT_IMPLEMENTED; + } + } + } + + return rc; +} + + +/** + * @copydoc FNRTTRACELOGWRSTREAM + */ +static DECLCALLBACK(int) rtTraceLogWrFileStream(void *pvUser, const void *pvBuf, size_t cbBuf, size_t *pcbWritten) +{ + RTFILE hFile = (RTFILE)pvUser; + return RTFileWrite(hFile, pvBuf, cbBuf, pcbWritten); +} + + +/** + * @copydoc FNRTTRACELOGSTREAMCLOSE + */ +static DECLCALLBACK(int) rtTraceLogWrFileStreamClose(void *pvUser) +{ + RTFILE hFile = (RTFILE)pvUser; + return RTFileClose(hFile); +} + + +RTDECL(int) RTTraceLogWrCreate(PRTTRACELOGWR phTraceLogWr, const char *pszDesc, + PFNRTTRACELOGWRSTREAM pfnStreamOut, + PFNRTTRACELOGSTREAMCLOSE pfnStreamClose, void *pvUser) +{ + AssertPtrReturn(phTraceLogWr, VERR_INVALID_POINTER); + AssertPtrReturn(pfnStreamOut, VERR_INVALID_POINTER); + AssertPtrReturn(pfnStreamClose, VERR_INVALID_POINTER); + int rc = VINF_SUCCESS; + PRTTRACELOGWRINT pThis = (PRTTRACELOGWRINT)RTMemAllocZ(sizeof(*pThis)); + if (pThis) + { + rc = RTSemMutexCreate(&pThis->hMtx); + if (RT_SUCCESS(rc)) + { + pThis->u32Magic = RTTRACELOGWR_MAGIC; + pThis->pfnStreamOut = pfnStreamOut; + pThis->pfnStreamClose = pfnStreamClose; + pThis->pvUser = pvUser; + pThis->u64SeqNoNext = 0; + pThis->pTreeEvtDescs = NULL; + pThis->cEvtDescs = 0; + rc = rtTraceLogWrInit(pThis, pszDesc); + if (RT_SUCCESS(rc)) + { + *phTraceLogWr = pThis; + return VINF_SUCCESS; + } + } + RTMemFree(pThis); + } + else + rc = VERR_NO_MEMORY; + + return rc; +} + + +RTDECL(int) RTTraceLogWrCreateFile(PRTTRACELOGWR phTraceLogWr, const char *pszDesc, + const char *pszFilename) +{ + AssertPtrReturn(phTraceLogWr, VERR_INVALID_POINTER); + AssertPtrReturn(pszFilename, VERR_INVALID_POINTER); + + RTFILE hFile = NIL_RTFILE; + int rc = RTFileOpen(&hFile, pszFilename, RTFILE_O_CREATE | RTFILE_O_WRITE | RTFILE_O_DENY_NONE); + if (RT_SUCCESS(rc)) + { + rc = RTTraceLogWrCreate(phTraceLogWr, pszDesc, rtTraceLogWrFileStream, + rtTraceLogWrFileStreamClose, hFile); + if (RT_FAILURE(rc)) + { + RTFileClose(hFile); + RTFileDelete(pszFilename); + } + } + + return rc; +} + + +/** + * @copydoc FNRTTRACELOGWRSTREAM + */ +static DECLCALLBACK(int) rtTraceLogWrTcpStream(void *pvUser, const void *pvBuf, size_t cbBuf, size_t *pcbWritten) +{ + PRTTRACELOGWRTCP pTraceLogTcp = (PRTTRACELOGWRTCP)pvUser; + int rc = RTTcpWrite(pTraceLogTcp->hSock, pvBuf, cbBuf); + if ( RT_SUCCESS(rc) + && pcbWritten) + *pcbWritten = cbBuf; + + return rc; +} + + +/** + * @copydoc FNRTTRACELOGSTREAMCLOSE + */ +static DECLCALLBACK(int) rtTraceLogWrTcpStreamClose(void *pvUser) +{ + PRTTRACELOGWRTCP pTraceLogTcp = (PRTTRACELOGWRTCP)pvUser; + if (pTraceLogTcp->fIsServer) + { + RTTcpServerDisconnectClient2(pTraceLogTcp->hSock); + RTTcpServerDestroy(pTraceLogTcp->pTcpSrv); + } + else + RTTcpClientClose(pTraceLogTcp->hSock); + + RTMemFree(pTraceLogTcp); + return VINF_SUCCESS; +} + + +RTDECL(int) RTTraceLogWrCreateTcpServer(PRTTRACELOGWR phTraceLogWr, const char *pszDesc, + const char *pszListen, unsigned uPort) +{ + int rc = VINF_SUCCESS; + PRTTRACELOGWRTCP pTraceLogTcp = (PRTTRACELOGWRTCP)RTMemAllocZ(sizeof(*pTraceLogTcp)); + if (RT_LIKELY(pTraceLogTcp)) + { + pTraceLogTcp->fIsServer = true; + + rc = RTTcpServerCreateEx(pszListen, uPort, &pTraceLogTcp->pTcpSrv); + if (RT_SUCCESS(rc)) + { + rc = RTTcpServerListen2(pTraceLogTcp->pTcpSrv, &pTraceLogTcp->hSock); + if (RT_SUCCESS(rc)) + { + rc = RTTraceLogWrCreate(phTraceLogWr, pszDesc, rtTraceLogWrTcpStream, + rtTraceLogWrTcpStreamClose, pTraceLogTcp); + if (RT_SUCCESS(rc)) + return VINF_SUCCESS; + + RTTcpServerDisconnectClient2(pTraceLogTcp->hSock); + } + + RTTcpServerDestroy(pTraceLogTcp->pTcpSrv); + } + + RTMemFree(pTraceLogTcp); + } + else + rc = VERR_NO_MEMORY; + + return rc; +} + + +RTDECL(int) RTTraceLogWrCreateTcpClient(PRTTRACELOGWR phTraceLogWr, const char *pszDesc, + const char *pszAddress, unsigned uPort) +{ + int rc = VINF_SUCCESS; + PRTTRACELOGWRTCP pTraceLogTcp = (PRTTRACELOGWRTCP)RTMemAllocZ(sizeof(*pTraceLogTcp)); + if (RT_LIKELY(pTraceLogTcp)) + { + pTraceLogTcp->fIsServer = false; + + rc = RTTcpClientConnect(pszAddress, uPort, &pTraceLogTcp->hSock); + if (RT_SUCCESS(rc)) + { + rc = RTTraceLogWrCreate(phTraceLogWr, pszDesc, rtTraceLogWrTcpStream, + rtTraceLogWrTcpStreamClose, pTraceLogTcp); + if (RT_SUCCESS(rc)) + return VINF_SUCCESS; + + RTTcpClientClose(pTraceLogTcp->hSock); + } + + RTMemFree(pTraceLogTcp); + } + else + rc = VERR_NO_MEMORY; + + return rc; +} + + +RTDECL(int) RTTraceLogWrDestroy(RTTRACELOGWR hTraceLogWr) +{ + PRTTRACELOGWRINT pThis = hTraceLogWr; + AssertPtrReturn(pThis, VERR_INVALID_HANDLE); + + pThis->u32Magic = RTTRACELOGWR_MAGIC_DEAD; + pThis->pfnStreamClose(pThis->pvUser); + RTAvlPVDestroy(&pThis->pTreeEvtDescs, rtTraceLogWrEvtDescsDestroy, NULL); + RTSemMutexDestroy(pThis->hMtx); + RTMemFree(pThis); + return VINF_SUCCESS; +} + + +RTDECL(int) RTTraceLogWrAddEvtDesc(RTTRACELOGWR hTraceLogWr, PCRTTRACELOGEVTDESC pEvtDesc) +{ + PRTTRACELOGWRINT pThis = hTraceLogWr; + AssertPtrReturn(pThis, VERR_INVALID_HANDLE); + AssertPtrReturn(pEvtDesc, VERR_INVALID_POINTER); + + return rtTraceLogWrEvtDescAdd(pThis, pEvtDesc, NULL); +} + + +RTDECL(int) RTTraceLogWrEvtAdd(RTTRACELOGWR hTraceLogWr, PCRTTRACELOGEVTDESC pEvtDesc, uint32_t fFlags, + RTTRACELOGEVTGRPID uGrpId, RTTRACELOGEVTGRPID uParentGrpId, + const void *pvEvtData, size_t *pacbRawData) +{ + PRTTRACELOGWRINT pThis = hTraceLogWr; + AssertPtrReturn(pThis, VERR_INVALID_HANDLE); + + int rc = VINF_SUCCESS; + PRTTRACELOGWREVTDESC pEvtDescInt = rtTraceLogWrEvtDescGetInternal(pThis, pEvtDesc); + if (RT_UNLIKELY(!pEvtDescInt)) + rc = rtTraceLogWrEvtDescAdd(pThis, pEvtDesc, &pEvtDescInt); + + if ( RT_SUCCESS(rc) + && VALID_PTR(pEvtDescInt)) + { + TRACELOGEVT Evt; + size_t cbEvtData = rtTraceLogWrEvtInit(&Evt, pEvtDescInt, fFlags, uGrpId, uParentGrpId, pacbRawData); + + rc = rtTraceLogWrEvtStream(pThis, &Evt, pvEvtData, cbEvtData, pacbRawData); + } + + return rc; +} + + +RTDECL(int) RTTraceLogWrEvtAddSg(RTTRACELOGWR hTraceLogWr, PCRTTRACELOGEVTDESC pEvtDesc, uint32_t fFlags, + RTTRACELOGEVTGRPID uGrpId, RTTRACELOGEVTGRPID uParentGrpId, + PRTSGBUF *pSgBufEvtData, size_t *pacbRawData) +{ + RT_NOREF(hTraceLogWr, pEvtDesc, fFlags, uGrpId, uParentGrpId, pSgBufEvtData, pacbRawData); + return VERR_NOT_IMPLEMENTED; +} + + +RTDECL(int) RTTraceLogWrEvtAddLV(RTTRACELOGWR hTraceLogWr, PCRTTRACELOGEVTDESC pEvtDesc, uint32_t fFlags, + RTTRACELOGEVTGRPID uGrpId, RTTRACELOGEVTGRPID uParentGrpId, va_list va) +{ + PRTTRACELOGWRINT pThis = hTraceLogWr; + AssertPtrReturn(pThis, VERR_INVALID_HANDLE); + + int rc = VINF_SUCCESS; + PRTTRACELOGWREVTDESC pEvtDescInt = rtTraceLogWrEvtDescGetInternal(pThis, pEvtDesc); + if (RT_UNLIKELY(!pEvtDescInt)) + rc = rtTraceLogWrEvtDescAdd(pThis, pEvtDesc, &pEvtDescInt); + + if ( RT_SUCCESS(rc) + && VALID_PTR(pEvtDescInt)) + { + TRACELOGEVT Evt; + size_t cbEvtData = rtTraceLogWrEvtInit(&Evt, pEvtDescInt, fFlags, uGrpId, uParentGrpId, NULL); + + if (cbEvtData) + rc = rtTraceLogWrEvtFill(pThis, pEvtDescInt, pEvtDescInt->pbEvt, va); + if (RT_SUCCESS(rc)) + rc = rtTraceLogWrEvtStream(pThis, &Evt, pEvtDescInt->pbEvt, cbEvtData, NULL); + } + + return rc; +} + + +RTDECL(int) RTTraceLogWrEvtAddL(RTTRACELOGWR hTraceLogWr, PCRTTRACELOGEVTDESC pEvtDesc, uint32_t fFlags, + RTTRACELOGEVTGRPID uGrpId, RTTRACELOGEVTGRPID uParentGrpId, ...) +{ + va_list va; + va_start(va, uParentGrpId); + int rc = RTTraceLogWrEvtAddLV(hTraceLogWr, pEvtDesc, fFlags, uGrpId, uParentGrpId, va); + va_end(va); + return rc; +} + |