如何正确使用日志Log

文章首发地址:http://kingname.info

这篇文章不会教你在技术角度上使用log,而是告诉你为什么要使用log日志功能。

为什么要使用Log

使用微信控制你的电脑这篇文章中,我写好了电脑端的程序,使用py2exe生成可执行文件,并把它们发送给我的朋友让他们进行测试。但是他们把_config.ini设置好以后,运行程序就看到一个黑色窗口一闪而过。或者有些人一开始看到程序能正常登陆邮箱,但是准备执行命令的时候,窗口自动关闭。

由于没有日志记录程序的运行状态,我根据他们的描述很难定位到错误在哪个地方。于是折腾了一个下午。

这个时候,我觉得添加一个日志的功能迫在眉睫。

哪些地方应该用Log

目前网上能找到的关于如何使用日志的文章,全部都是从技术角度讲怎么使用log:在XX地方应该先imort logging,然后basicconfig设定XX内容。可是我现在的问题是:

  • 应该在程序的哪些地方添加日志的输出?
  • 输出什么内容?
  • 如何输出才能以方便我的监控程序的运行情况?

于是我只有自己摸索。因此,以下内容是我自己摸索出来的野路子,可能会有错漏。希望有经验的朋友能给我指正,非常感谢。

这些地方应该用Log

使用使用微信控制你的电脑文章中涉及到的例子

程序入口代码如下:

1
2
3
4
5
6
7
if __name__=='__main__':
init()
print u'等待接收命令'
logging.info(u'初始化完成。')
while 1:
time.sleep(int(time_limit)) #每5分钟检查一次邮箱
accp_mail()

以上代码表示程序运行以后,首先执行init()函数,于是如果init()初始化没有什么问题,成功执行完成以后,就应该在日志中输出“初始化完成”,然后进入接收邮件的循环。如果程序窗口运行以后一闪而过,而且生成的日志中没有初始化完成这样的字眼,那就说明问题出在初始化上面。

然而初始化函数里面代码也有很多,又如何知道是初始化程序里面的什么地方出问题了呢?

所以,再初始化函数里面,也应该有一定的日志记录。

再看初始化函数的代码:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
def init():
global username,password,host,boss_email,time_limit

try:
f = open('_config.ini','r')
except IOError,e:
logging.error(e)
exit()

info = f.readlines()
try:
host = re.search('host:(.*?)\n',info[0],re.S).group(1)
username = re.search('username:(.*?com)',info[1],re.S).group(1)
password = re.search('password:(.*?)\n',info[2],re.S).group(1)
boss_email = re.search('boss_email:(.*?com)',info[3],re.S).group(1)
time_limit = re.search('time_limit:(.*?)\n',info[4],re.S).group(1)
except Exception,e:
logging.error(e)

logging.info(u'打开配置文件成功。。。')


#将命令生成字典,便于查询
command_start = info.index('<command>\n')
command_end = info.index('</command>\n')
for each in info[command_start+1:command_end]:
command = each.split('=')
command_dict[command[0]] = command[1]

logging.info(command_dict)

open_start = info.index('<open_file>\n')
open_end = info.index('</open_file>\n')
for each in info[open_start+1:open_end]:
open_file = each.split('=')
open_dict[open_file[0]] = open_file[1][:-1]

logging.info(open_dict)

f.close()

在这段代码中,我使用try except命令捕获异常,如果发生异常,就使用logging.error将错误写入日志中。例如当_config.ini被改名了或者被删除的时候,程序就会报错,而通过日志就能发现这个错误。

经过上面的代码,如果在初始化的过程中出错,就可以很快确定问题出在什么地方。

初始化完成以后,进入邮件接收阶段。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
def accp_mail():
logging.info(u'开始检查邮箱')
try:
pp = poplib.POP3_SSL(host)
pp.set_debuglevel(1)
pp.user(username)
pp.pass_(password)
ret = pp.list()
logging.info(u'登录邮箱成功。')
except Exception,e:
logging.error(e)
exit()

logging.info(u'开始抓取邮件。')
try:
down = pp.retr(len(ret[1]))
logging.info(u抓取邮件成功。'')
except Exception,e:
logging.error(e)
exit()

logging.info(u'开始抓取subject和发件人')
try:
subject = re.search("Subject: (.*?)',",str(down[1]).decode('utf-8'),re.S).group(1)
sender = re.search("'X-Sender: (.*?)',",str(down[1]).decode('utf-8'),re.S).group(1)
logging.info(u'抓取subject和发件人成功')
except Exception,e:
logging.error(e)
exit()

if subject != 'pass':
if sender == boss_email:
DealCommand(subject)
pp.quit()

以上这段代码,对邮箱的登录与邮件的读取均作了监控,一旦有某个环节出了问题,就会体现在日志中。

通过在登录环节的try except返回的错误日志,发现有很多朋友无法登录邮箱,而密码用户名都没有错,从而推断是没有在新浪邮箱的账户控制里面打开客服端接收POP3和SMTP的功能。

再来看DealCommand()函数:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
def DealCommand(subject):
logging.info(u'开始处理命令。')
send_mail('pass','slave')
if subject in command_dict:
logging.info(u'执行命令')
try:
command = command_dict[subject]
os.system(command)
send_mail('Success','boss')
logging.info(u'执行命令成功')
except Exception,e:
logging.error(e)
send_mail('error','boss',e)
elif subject in open_dict:
logging.info(u'打开文件')
try:
open_file = open_dict[subject]
win32api.ShellExecute(0, 'open', open_file, '','',1)
send_mail('Success','boss')
logging.info(u'打开文件成功')
except Exception,e:
logging.error(e)
send_mail('error','boss',e)
else:
send_mail('error','boss','no such command')

执行命令的地方可能会出错,于是果断使用try except捕获错误。并使用日志记录。

最后是send_mail()函数:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
def send_mail(subject,flag,body='Success'):

msg = MIMEText(body,'plain','utf-8')#中文需参数‘utf-8’,单字节字符不需要
msg['Subject'] = subject
msg['from'] = username
logging.info('开始配置发件箱。')
try:
handle = smtplib.SMTP('smtp.sina.com', 25)
handle.login(username,password)
logging.info('发件箱配置成功')
except Exception,e:
logging.error(e)
exit()

logging.info(u'开始发送邮件'+ 'to' + flag)
if flag == 'slave':
try:
handle.sendmail(username,username, msg.as_string())
logging.info(u'发送邮件成功')
except Exception,e:
logging.error(e)
exit()
elif flag == 'boss':
try:
handle.sendmail(username,boss_email, msg.as_string())
logging.info(u'发送邮件成功')
except Exception,e:
logging.error(e)
exit()

handle.close()
logging.info(u'发送邮件结束'+flag)

这里对邮件发件的部分需要特别仔细的错误捕获,然后记录进入日志中。

完整的代码见:https://github.com/kingname/MCC.git中的auto.py

总结

需要使用日志记录的地方大致有一下几处:

  • 所有输入输出处,无论是从文件输入还是从网络等其他地方输入
  • 执行命令处
  • 调用函数处

PS

这里我对一般信息的记录使用了info,实际上,一般用作调试的话,是使用debug更多。

需要用户输入的地方,总会有想不到的错误,多小心都不为过。例如,用户可能会把time_limit设定为一个全角数字。而本文中就没有捕获这种问题到日志中。所以如果不放心的话,还可以更进一步的细化日志。