Created Logging with Boost.Log v2 (to be integrated) (markdown)

Mikhail Titov
2015-07-29 16:00:23 -05:00
parent 80a71e0fe5
commit 0f738f291a

@@ -0,0 +1,101 @@
[Boost.Log v2](http://www.boost.org/doc/libs/develop/libs/log/doc/html/index.html) provide incredible flexibility. Once the branch is merged, it would provide an extra insight into a context where log event was captured, namely, thread id, object instance id, total traffic counters, and class name (channel) in addition to existing severity level.
Logging is configured via a [primitive file used by log setup](http://www.boost.org/doc/libs/develop/libs/log/doc/html/log/detailed/utilities.html#log.detailed.utilities.setup.settings_file). Here is an example
```ini
# Comments are allowed. Comment line begins with the '#' character
# and spans until the end of the line.
# Logging core settings section. May be omitted if no parameters specified within it.
[Core]
DisableLogging=false
#Filter="%Severity% > 3"
# Sink settings sections
[Sinks.Console]
# Sink destination type
Destination=Console
# Sink-specific filter. Optional, by default no filter is applied.
#Filter="%Target% contains \"MySink1\""
#I2PControl
#
#< 1
Filter="%Channel% = \"UPnP\" or %Channel% begins_with \"SAM\" or %Channel% ends_with \"Destination\" or %Severity% = error"
# Formatter string. Optional, by default only log record message text is written.
Format="(%Severity%) %Channel% - %Message%"
# The flag shows whether the sink should be asynchronous
Asynchronous=false
# Enables automatic stream flush after each log record.
AutoFlush=true
[Sinks.File]
Destination=TextFile
FileName="C:/Users/me/Application Data/i2pd/i2p.log"
#FileName=test.log
AutoFlush=true
#{Thread=%ThreadID%}
#Format="%TimeStamp%,Thread=%ThreadID%,%Scope%,%Tag%,%Severity%,%Channel%,%Message%"
#Format="%TimeStamp%,Thread=%ThreadID%,%Tag%,%Severity%,%Channel%,%Message%"
#Format="%TimeStamp%,%ThreadID%,%Instance%,%Severity%,%Channel%,%Message%,%Sent%,%Received%"
Format="%TimeStamp%;%ThreadID%;%Instance%;%Severity%;%Channel%;%Message%;%Sent%;%Received%"
Asynchronous=false
# [Sinks.Win]
# # TODO: event mapping http://www.boost.org/doc/libs/1_56_0/libs/log/example/event_log/main.cpp & http://stackoverflow.com/a/8559295/673826
# LogName=I2Pd
# LogSource=i2pd
# # otherwise would need access to HKLM\SYSTEM\CurrentControlSet\Services\EventLog\I2Pd\i2pd
# Registration=Never
# Filter="%Tag% = \"info\""
# Destination=SimpleEventLog
# [Sinks.Lin]
# Filter="%Tag% = \"info\""
# Destination=Syslog
# [Sinks.Dbg]
# Filter="%Tag% = \"info\""
# Destination=Debugger
```
Newer flexible format allows for various post-processing. e.g., with [R](https://www.r-project.org/)
```r
library(plyr)
library(ggplot2)
library(reshape2)
library(gridExtra)
setClass('boost.time')
setAs("character", "boost.time", function(from) as.POSIXct(from, format="%Y-%b-%d %H:%M:%S"))
x <- read.csv2( file.path( Sys.getenv("APPDATA"), "i2pd", "i2p.log"), header=FALSE,
col.names=c("ts", "thread", "inst", "level", "channel", "msg", "sent", "received"),
colClasses=c(ts="boost.time", thread='factor', msg='character'))
xx <- rbind(
x[!duplicated(subset(x, select=c(sent,received))),],
tail(x,1)
)
sr <- melt(xx, 'ts', c('sent','received'))
p1 <- qplot(ts, value, color=variable, data=sr, geom='line') +
ggtitle('traffic')
q <- ddply(x, .(thread), function(xx) {
data.frame(ts=xx$ts, diff=as.double( diff(c(xx$ts,tail(x$ts,1))), units='mins' ))
})
qq <- subset(q, diff > 10)
p2 <- qplot(ts, diff, color=thread, shape=thread, data=qq) +
scale_shape_manual(values=rep(1:4, len=length(levels(qq$thread)))) +
ggtitle('at least 10 min gaps in thread logging activity')
tc <- ddply(na.omit(x), .(thread, channel), summarize, count=length(thread))
p3 <- qplot(thread, channel, size=count, data=tc) +
scale_size(trans="log10") + theme(axis.text.x=element_text(angle = -15, hjust = 0)) +
ggtitle('threads and logging channels (classes)')
grid.arrange(p1, p2, p3, ncol=1)
```
![output plot produced](http://snag.gy/fDxKU.jpg)