Overhaul of the Logging Infrastructure #1596
Conversation
…ace to satisfy ADL requirements.
- LogLevel is now a top level enum class. - Added a new log level Off to disable output from a specific module. - Logger::LogLevel is a deprecated alias to LogLevel. - Logger::Info, Debug, Error are deprecated aliases to LogLevel::... - Removed public "internal*" functions from Logger.Logger - Added LogSource struct to encapsulate source information. - Added shouldLog method to check if a log should be emitted for a given level and module. - Removed nonfunctional artifacts "m_LogStream" and "Logger::operator<<" - Added templated "log" functions that are friends to Logger. - Reworked PCPP_LOG macros to no longer utilize the now removed internal functions. - Added PCPP_LOG_INFO macro level. - Changed PCPP_LOG_ERROR to now check if the log should be emitted. - Fixed NetworkUtils log module name overlapping with NetworkUtils class. - Fixed missing enum value for PacketLogModuleSll2Layer.
Dimi1010
force-pushed
the
refactor/log-templates
branch
from
bd53c74 to
f21f85d
Compare
Codecov ReportAttention: Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## dev #1596 +/- ##
==========================================
- Coverage 83.15% 83.12% -0.03%
==========================================
Files 277 278 +1
Lines 48196 48307 +111
Branches 9991 10085 +94
==========================================
+ Hits 40078 40157 +79
+ Misses 7225 7040 -185
- Partials 893 1110 +217
Flags with carried forward coverage won't be shown. Click here to find out more. ☔ View full report in Codecov by Sentry. |
Dimi1010
added
breaking change
Common++/header/Logger.h
Outdated
| std::ostringstream sstream; \ | ||
| sstream << message; \ |
There was a problem hiding this comment.
Can you please check if this change affects the PcapPlusPlus binary sizes?
I made a change in this PR a couple of years ago to significantly reduce the binary sizes: #748
There was a problem hiding this comment.
This is a breakdown on the install directory for the x64 release w/npcap.
Folder1 is the new size. Folder2 is the old size.
File Folder1Size Folder2Size AbsoluteDelta RelativeDelta
---- ----------- ----------- ------------- -------------
bin\Arping.exe 714240 639488 74752 10.47%
bin\ArpSpoofing.exe 703488 631296 72192 10.26%
bin\benchmark.exe 599552 562688 36864 6.15%
bin\DisplayLiveDevices.exe 30208 30208 0 0.00%
bin\DNSResolver.exe 748032 664064 83968 11.23%
bin\DnsSpoofing.exe 747520 671232 76288 10.21%
bin\HttpAnalyzer.exe 832512 743936 88576 10.64%
bin\IcmpFileTransfer-catcher.exe 730624 658432 72192 9.88%
bin\IcmpFileTransfer-pitcher.exe 742400 666112 76288 10.28%
bin\IPDefragUtil.exe 711680 655360 56320 7.91%
bin\IPFragUtil.exe 693248 637952 55296 7.98%
bin\PcapPrinter.exe 658432 612352 46080 7.00%
bin\PcapSearch.exe 661504 618496 43008 6.50%
bin\PcapSplitter.exe 720384 667648 52736 7.32%
bin\SSLAnalyzer.exe 822272 733184 89088 10.83%
bin\TcpReassembly.exe 799232 710144 89088 11.15%
bin\TLSFingerprinting.exe 796672 712704 83968 10.54%
lib\Common++.lib 5045102 4887832 157270 3.12%
lib\Packet++.lib 19849740 18454316 1395424 7.03%
lib\Pcap++.lib 3620658 2896688 723970 20.00%
Full breakdown: npcap-x64-release.txt
There was a problem hiding this comment.
Did you test it with MSVC or MinGW? Also, did you have a chance to test on Linux also?
I don't remember in which platform the impact was the highest, but I think it was Linux 🤔
There was a problem hiding this comment.
Msvc, I dont think I have mingw setup. I should be able to test the sizes on Unix via WSL.
There was a problem hiding this comment.
@Dimi1010 I see you're still working on it. Please let me know when the changes are done and when you want me to review the PR again.
It'd be good to make sure binary sizes don't increase. I'd test at least on Windows and Linux
There was a problem hiding this comment.
@seladb Ok, ended up keeping the optimization.
As bc82caf: Release builds ended up being:
- Windows
- Static Libraries
- Common++.lib - 4.7MB -> 5MB
- Packet++.lib - 17.6MB -> 19.7MB
- Pcap++.lib - 2.8MB -> 3.3MB
- Examples
- Same binary size or <=10KB increase.
- Static Libraries
- Linux (WSL)
- Static Libraries
- libCommon++.a - 408KB -> 444KB
- libPakcet++.a - 3.1MB -> 3.3MB
- libPcap++.a - 676KB -> 748KB
- Examples
- On average ~0.1MB increase on each binary.
- Static Libraries
This reverts commit be95ab8.
- Added optional compile time elimination of log calls below set level.
- Renamed printLogMessage to emit and changed visibility to public. - Added new class LogContext to encapsulate a single emittable log message. - Added new methods createLogContext which is practically a rework of internalCreateLogStream but returns a LogContext. - Added optional use of object pooling optimization for reusing log contexts. (Enabled via preprocessor flag PCPP_LOG_USE_OBJECT_POOL)
… minimum log level set to too high severity..
…ntext pooling. - Removed preprocessor variable PCPP_LOG_USE_OBJECT_POOL. - Disabled context pooling for the unit tests as it interferes with the memory leak checker.
… time minimum log level set to too high severity..
- Added documentation to new methods and classes. - Addressed explicit constructor warnings. - Moved disable of context pooling for unit tests to the main.cpp files of the respective tests.
- Added 2 preallocated log contexts to the object pool.
…hreading and eliminate possibility of data races during log emission.
Common++/header/ObjectPool.h
Outdated
| std::size_t m_maxPoolSize; /**< The maximum number of objects in the pool */ | ||
| std::mutex m_mutex; /**< Mutex for thread safety */ | ||
| std::stack<T*> m_pool; /**< The pool of objects */ |
There was a problem hiding this comment.
nit: the convention we usually have is for members to begin with m_ and then a capital letter, for example: m_MaxPoolSize, m_Mutex, m_Pool
There was a problem hiding this comment.
Maybe add tests for this class?
In order to test it we might need to add properties like currentPoolSize() etc., but it'd be good to add tests to cover edge cases that are not covered in the logger
There was a problem hiding this comment.
Where do we keep the common tests?
There was a problem hiding this comment.
We don't have a place for it right now, so we put them under Pcap++Test
| */ | ||
| void internalPrintLogMessage(std::ostringstream* logStream, Logger::LogLevel logLevel, const char* file, | ||
| const char* method, int line); | ||
| void useContextPooling(bool enabled, std::size_t preallocate = 2) |
There was a problem hiding this comment.
We don't use this method anymore because we always use context pooling. Do we still need it?
If we decide we don't need it, we can probably remove m_UseContextPooling also
There was a problem hiding this comment.
Eh, it depends. The unit tests started having memory leak false positives again, after I added a mutex on the defaultLogPrinter to remove the possibility of data races when outputting to the console. Need to fix that before a final call can be made.
| * @param source The log source. | ||
| * @param message The object to be logged. | ||
| */ | ||
| template <class T> void logError(LogSource const& source, T const& message) |
There was a problem hiding this comment.
do we need logError(), logInfo() and logDebug()? We have the macros for that, no?
There was a problem hiding this comment.
They aren't used atm. There is the possibility of using them to if something needs to bypass the preprocessor compiler log level, but I suppose they can be safely removed if we don't want them.
There was a problem hiding this comment.
yes, I guess we can remove them and re-add them in the future if needed
|
@Dimi1010 can you address the remaining comments so we can merge this PR? |
# Conflicts: # Common++/header/IpAddress.h # Common++/header/Logger.h
| private: | ||
| bool m_LogsEnabled; | ||
| Logger::LogLevel m_LogModulesArray[NumOfLogModules]; | ||
| LogLevel m_LogModulesArray[NumOfLogModules]; | ||
| LogPrinter m_LogPrinter; | ||
| std::string m_LastError; |
There was a problem hiding this comment.
@seladb Do we absolutely need to store the last error? Because the way it works, if the logger is made to be used by more than one thread the value is completely useless as it can be changed at any time by any thread.
Overhaul of the Logging Infrastructure
Changes
LogLevelhas been updated to anenum classand moved to thepcppnamespace.Loggerretains aliases to the new enum.LogModulevalues in theLoggingModuleenum.LogSource: Encapsulates file, function, line number and module information.LogContext: Encapsulates the context of a single log message.Loggerclass into public methods with documentation.internalCreateLogStreamwithcreateLogContext.internalPrintLogMessagewithemit.log*functions toLoggerclass to allow logging, through runtime methods.LogContextto reduce allocation overhead.ObjectPool<T>class to facilitate pooling for reusable objects.useContextPooling(false)on theLoggerinstance.PCPP_LOGmacros at compile time viaPCPP_ACTIVE_LOG_LEVELpreprocessor variable.std::mutexlocking indefaultLogPrinterto eliminate possible data races during log message emission.ostream& operator<<overloads forIPAddressandMacAddressinsidepcppto satisfy ADL (Argument-Dependent Lookup).LogContext Pooling Optimization
When enabled, the pooling optimization introduces the following behavior:
Allocation on
createLogContext:createLogContextis called, the pool is queried for an availableLogContext.LogContextis found, a new one is created immediately.Releasing on
emit:emitmethod with aunique_ptr<LogContext>parameter is called, theLogContextis returned to the pool after the operation completes.LogContextis stored for reuse.LogContextis deleted.Optimization Benchmarks
Performance benchmarks highlight the impact of enabling the pooling optimization:
Windows 10 - MSVC x64 (Release Build)
WSL (Ubuntu 22.04) - GCC x64 (Release Build)
Notes
LogLeveland other enums may introduce minor compatibility issues, they align with modern C++ best practices.