（2017-06-25 銀河統計）
前言
程序中日志文件（log文件）一般有兩個目的：查詢歷史操作發現問題和顯示程序運行狀態。好的日志記錄方式可以提供我們足夠多定位問題的依據。日志記錄大家都會認為簡單，但如何通過日志可以高效定位問題並不是簡單的事情。這里以R語言的logging包為例，先介紹相關知識點，然后輔以代碼示例，介紹logging包的相關應用，總結如何用R語言寫好日志，希望對自己和大家有所啟發和幫助。
目錄
1. logging相關知識點
2. logging應用
1. logging相關知識點
##***********************************************************************
## this program is free software: you can redistribute it and/or
## modify it under the terms of the GNU General Public License as
## published by the Free Software Foundation, either version 3 of the
## License, or (at your option) any later version.
##
## this program is distributed in the hope that it will be useful, but
## WITHOUT ANY WARRANTY; without even the implied warranty of
## MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
## General Public License for more details.
##
## You should have received a copy of the GNU General Public License
## along with the this program. If not, see
## <http://www.gnu.org/licenses/>.
##
## $Id: the_basics.R 27 2010-04-08 15:05:52Z mariotomo $
##***********************************************************************
library(logging)
basicConfig()
ls(getLogger())
with(getLogger(), level)
with(getLogger(), names(handlers))
loginfo('does it work?')
logwarn('%s %d', 'my name is', 5)
logdebug('I am a silent child')
addHandler(writeToConsole)
with(getLogger(), names(handlers))
loginfo('test')
logwarn('test')
removeHandler('writeToConsole')
logwarn('test')
addHandler(writeToConsole)
setLevel(30, getHandler('basic.stdout'))
loginfo('test')
logwarn('test')
with(getHandler('basic.stdout'), level)
##***********************************************************************
## this program is free software: you can redistribute it and/or
## modify it under the terms of the GNU General Public License as
## published by the Free Software Foundation, either version 3 of the
## License, or (at your option) any later version.
##
## this program is distributed in the hope that it will be useful, but
## WITHOUT ANY WARRANTY; without even the implied warranty of
## MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
## General Public License for more details.
##
## You should have received a copy of the GNU General Public License
## along with this program. If not, see
## <http://www.gnu.org/licenses/>.
##
## $Id: hierarchical_loggers.R 27 2010-04-08 15:05:52Z mariotomo $
##***********************************************************************
library(logging)
basicConfig()
with(getLogger(logger=''), names(handlers))
with(getLogger('libro'), names(handlers))
logReset()
addHandler(writeToConsole, logger='libro.romanzo')
loginfo('chiarastella', logger='libro.romanzo.campanile')
loginfo('memories of a survivor', logger='libro.romanzo.lessing')
logwarn('talking to a upper level logger', logger='libro')
logerror('talking to an unrelated logger', logger='rivista.cucina')
##***********************************************************************
## this program is free software: you can redistribute it and/or
## modify it under the terms of the GNU General Public License as
## published by the Free Software Foundation, either version 3 of the
## License, or (at your option) any later version.
##
## this program is distributed in the hope that it will be useful, but
## WITHOUT ANY WARRANTY; without even the implied warranty of
## MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
## General Public License for more details.
##
## You should have received a copy of the GNU General Public License
## along with this program. If not, see
## <http://www.gnu.org/licenses/>.
##
## $Id: logging_to_file.R 27 2010-04-08 15:05:52Z mariotomo $
##***********************************************************************
library(logging)
logReset()
basicConfig(level='FINEST')
addHandler(writeToFile, file="~/testing.log", level='DEBUG')
with(getLogger(), names(handlers))
loginfo('test %d', 1)
logdebug('test %d', 2)
logwarn('test %d', 3)
logfinest('test %d', 4)
##***********************************************************************
formatting your log records
in this session we are going to see how to generate a diagnostics file for a system that organizes logrecords in a different way than Python. let's jump into the implementation, if you can write R you surely won't need more explaination but will want to tell me how to make this function faster, more readable, shorter...
##***********************************************************************
formatter.fewsdiagnostics <- function(record) {
if(record$level <= loglevels[['INFO']])
level <- 3
else if(record$level <= loglevels[['WARNING']])
level <- 2
else if(record$level <= loglevels[['ERROR']])
level <- 1
else
level <- 0
sprintf(' <line level="%d" description="LizardScripter :: %s :: %s"/>\n', level, record$timestamp, record$msg)
}
notice that the field $msg of a record is already "formatted", as we have seen with logwarn('my %s is %d', 'name', 5). that part can be used but not undone any more.
when you add a handler to a logger, you can use the formatter parameter to associate to the handler a function that takes a logrecord and returns a string. the above example function is such a function.
the formatter you can associate to a handler can combine the tags in the logrecord to produce a string. the tags that are available in a logrecord are: $logger (the name of the logger which produced the record), $msg, $timestamp, $level (numeric), $levelname (character).
if you don't specify the formatter parameter, the default formatter is used, which looks like this:
defaultFormat <- function(record) {
text <- paste(record$timestamp, paste(record$levelname, record$logger, record$msg, sep=':'))
}
the rest of the code, just slightly simplified, showing how we (me at my company) actually use this capability is given here.
notice that the 'diagnostics' handler we add will not handle DEBUG logrecords.
setup.fewsdiagnostics <- function(filename) {
cat('<?xml version="1.0" encoding="UTF-8" standalone="yes"?>\n', file=filename, append=FALSE)
cat('<Diag version="1.2" xmlns="..." xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="...">\n', file=filename, append=FALSE)
addHandler('diagnostics',
writeToFile, file=filename,
logger='fews.diagnostics',
formatter=formatter.fewsdiagnostics)
}
teardown.fewsdiagnostics <- function(filename) {
cat('</Diag>\n'', file=filename, append=TRUE)
removeHandler('diagnostics', logger='fews.diagnostics')
}
writing your own handlers
differently than in the logging library in Python and in Java, handlers in this logging library aren't objects: they are environments stored in one of the loggers. the principal characteristic property of a handler is its action. a action is a function that specifies what the handler should do with a logrecord that, based on all that we have seen above, must be handled. the two commodity functions we have seen in the first two sessions, writeToConsole and writeToFile are action functions.
a look at writeToFile will help understand the idea implemented in this library.
writeToFile <- function(msg, handler)
{
if (!exists('file', envir=handler))
stop("handler with writeToFile 'action' must have a 'file' element.\n")
cat(paste(msg, '\n', sep=''), file=with(handler, file), append=TRUE)
}
an action is invoked if a record must be handled. its result code is ignored and all its output goes to the console. it receives exactly two arguments, the formatted message that must be output (the string returned by the formatter of the handler) and the handler owning the action. recall that a handler is an environment: in the action you can inspect the handler environment to perform the desired behaviour.
imagine you want a handler to send its messages to a xmlrpc server or to a password protected ftp server, you would add these properties in the call to addHandler. addHandler would store them in the new handler environment. your action function would retrieve the values from the handler and use them to connect to your hypothetical external server.
the structure of your solution might be something like this:
sendToFtpServer <- function(msg, handler)
{
proxy <- connectToServer(with(handler, server), with(handler, user), with(handler, passwd))
do_the_rest()
}
addHandler(sendToFptServer, user='', server='', passwd='',logger="deep.deeper.deepest")
2. logging應用
在實際應用場景中，R日志輸出主要會用到loginfo函數和logerror函數，loginfo主要輸出正常程序流信息，而logerror主要是為了捕捉錯誤信息。這些日子函數大多時候會與R語言異常或錯誤處理函數tryCatch一起使用。具體使用如下：
#----------------------------
library(logging)
logReset()
basicConfig(level='FINEST')
addHandler(writeToFile, file="~/testing.log", level='DEBUG')
# with(getLogger(), names(handlers))
loginfo('test %d', 1, logger='hello')
logerror('talking to an unrelated logger', logger='start')
loginfo('test %d %s', 1, '!!!ok!!!', logger='hello')
logerror('logger %s', 'Program End', logger='start')
logwarn('test %d', 3, logger='hello')
logdebug('test %d', 2, logger='hello')
#----------------------------
#----------------------------
library(logging)
logReset()
# setwd(getwd()) # 設置默認路徑
basicConfig(level='FINEST')
addHandler(writeToFile, file="~/testing.log", level='DEBUG')
result = tryCatch({
# 正常的邏輯
# expr
logging::loginfo('test %d', 1, logger='hello')
}, warning = function(w) {
# 出現warning的處理邏輯
# warning-handler-code
# 如果從這里輸出警告日志，程序會中斷，為了保證程序繼續運行，應用中會刪除 warning 模塊。
logging::logwarn('test %d', 3, logger='hello')
}, error = function(e) {
# 出現error的處理邏輯
# error-handler-code
logging::logerror('talking to an unrelated logger', logger='start')
}, finally = {
# 不管出現異常還是正常都會執行的代碼模塊，
# 一般用來處理清理操作，例如關閉連接資源等。
# cleanup-code
}
#----------------------------