R语言-日志logging包

（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
	}

	#----------------------------

参考资料

• logging_index

• logging文档