2018年6月

APScheduler 产生missed 问题,可以使用BlockingScheduler带入参数
job_defaults = {

'coalesce': False,
'max_instances': 3,
'misfire_grace_time': 30

}
BackgroundScheduler(job_defaults=job_defaults)解决

1.coalesce:当由于某种原因导致某个job积攒了好几次没有实际运行(比如说系统挂了5分钟后恢复,有一个任务是每分钟跑一次的,按道理说这5分钟内本来是“计划”运行5次的,但实际没有执行),如果coalesce为True,下次这个job被submit给executor时,只会执行1次,也就是最后这次,如果为False,那么会执行5次(不一定,因为还有其他条件,看后面misfire_grace_time的解释)
2.max_instance: 就是说同一个job同一时间最多有几个实例再跑,比如一个耗时10分钟的job,被指定每分钟运行1次,如果我们max_instance值为5,那么在第6~10分钟上,新的运行实例不会被执行,因为已经有5个实例在跑了
3.misfire_grace_time:设想和上述coalesce类似的场景,如果一个job本来14:00有一次执行,但是由于某种原因没有被调度上,现在14:01了,这个14:00的运行实例被提交时,会检查它预订运行的时间和当下时间的差值(这里是1分钟),大于我们设置的30秒限制,那么这个运行实例不会被执行。

介绍
官网文档:http://apscheduler.readthedoc...
API:http://apscheduler.readthedoc...

APScheduler是一个python的第三方库,用来提供python的后台程序。包含四个组件,分别是:

triggers: 任务触发器组件,提供任务触发方式

job stores: 任务商店组件,提供任务保存方式

executors: 任务调度组件,提供任务调度方式

schedulers: 任务调度组件,提供任务工作方式

安装
pip 安装

$ pip install apscheduler
源码安装

$ python setup.py install
简单的实例
from apscheduler.schedulers.blocking import BlockingScheduler
import time

实例化一个调度器

scheduler = BlockingScheduler()

def job1():

print "%s: 执行任务"  % time.asctime()

添加任务并设置触发方式为3s一次

scheduler.add_job(job1, 'interval', seconds=3)

开始运行调度器

scheduler.start()
输出:

$ python first.py
Fri Sep 8 20:41:55 2017: 执行任务
Fri Sep 8 20:41:58 2017: 执行任务
...
各组件功能
trigger组件
trigger提供任务的触发方式,共三种方式:

date:只在某个时间点执行一次run_date(datetime|str)

scheduler.add_job(my_job, 'date', run_date=date(2017, 9, 8), args=[])
scheduler.add_job(my_job, 'date', run_date=datetime(2017, 9, 8, 21, 30, 5), args=[])
scheduler.add_job(my_job, 'date', run_date='2017-9-08 21:30:05', args=[])

The 'date' trigger and datetime.now() as run_date are implicit

sched.add_job(my_job, args=[[])
interval: 每隔一段时间执行一次weeks=0 | days=0 | hours=0 | minutes=0 | seconds=0, start_date=None, end_date=None, timezone=None

scheduler.add_job(my_job, 'interval', hours=2)
scheduler.add_job(my_job, 'interval', hours=2, start_date='2017-9-8 21:30:00', end_date='2018-06-15 21:30:00)

@scheduler.scheduled_job('interval', id='my_job_id', hours=2)
def my_job():

print("Hello World")

cron: 使用同linux下crontab的方式(year=None, month=None, day=None, week=None, day_of_week=None, hour=None, minute=None, second=None, start_date=None, end_date=None, timezone=None)

sched.add_job(my_job, 'cron', hour=3, minute=30)
sched.add_job(my_job, 'cron', day_of_week='mon-fri', hour=5, minute=30, end_date='2017-10-30')

@sched.scheduled_job('cron', id='my_job_id', day='last sun')
def some_decorated_task():

print("I am printed at 00:00:00 on the last Sunday of every month!")

scheduler组件
scheduler组件提供执行的方式,在不同的运用环境中选择合适的方式

BlockingScheduler: 进程中只运行调度器时的方式

from apscheduler.schedulers.blocking import BlockingScheduler
import time

scheduler = BlockingScheduler()

def job1():

print "%s: 执行任务"  % time.asctime()

scheduler.add_job(job1, 'interval', seconds=3)
scheduler.start()
BackgroundScheduler: 不想使用任何框架时的方式

from apscheduler.schedulers.background import BackgroundScheduler
import time

scheduler = BackgroundScheduler()

def job1():

print "%s: 执行任务"  % time.asctime()

scheduler.add_job(job1, 'interval', seconds=3)
scheduler.start()

while True:

pass

AsyncIOScheduler: asyncio module的方式(Python3)

from apscheduler.schedulers.asyncio import AsyncIOScheduler
try:

import asyncio

except ImportError:

import trollius as asyncio

...
...

while True:pass

try:

asyncio.get_event_loop().run_forever()

except (KeyboardInterrupt, SystemExit):

pass

GeventScheduler: gevent方式

from apscheduler.schedulers.gevent import GeventScheduler

...
...

g = scheduler.start()

while True:pass

try:

g.join()

except (KeyboardInterrupt, SystemExit):

pass

TornadoScheduler: Tornado方式

from tornado.ioloop import IOLoop
from apscheduler.schedulers.tornado import TornadoScheduler

...
...

while True:pass

try:

IOLoop.instance().start()

except (KeyboardInterrupt, SystemExit):

pass

TwistedScheduler: Twisted方式

from twisted.internet import reactor
from apscheduler.schedulers.twisted import TwistedScheduler

...
...

while True:pass

try:

reactor.run()

except (KeyboardInterrupt, SystemExit):

pass

QtScheduler: Qt方式

executors组件
executors组件提供任务的调度方式

base

debug

gevent

pool(max_workers=10)

twisted

jobstore组件
jobstore提供任务的各种持久化方式

base

memory

mongodb
scheduler.add_jobstore('mongodb', collection='example_jobs')

redis
scheduler.add_jobstore('redis', jobs_key='example.jobs', run_times_key='example.run_times')

rethinkdb
scheduler.add_jobstore('rethinkdb', database='apscheduler_example')

sqlalchemy
scheduler.add_jobstore('sqlalchemy', url=url)

zookeeper
scheduler.add_jobstore('zookeeper', path='/example_jobs')

任务操作
添加任务add_job(如上)
如果使用了任务的存储,开启时最好添加replace_existing=True,否则每次开启都会创建任务的副本
开启后任务不会马上启动,可修改trigger参数

删除任务remove_job

根据任务实例删除

job = scheduler.add_job(myfunc, 'interval', minutes=2)
job.remove()

根据任务id删除

scheduler.add_job(myfunc, 'interval', minutes=2, id='my_job_id')
scheduler.remove_job('my_job_id')
任务的暂停pause_job和继续resume_job
job = scheduler.add_job(myfunc, 'interval', minutes=2)

根据任务实例

job.pause()
job.resume()

根据任务id暂停

scheduler.add_job(myfunc, 'interval', minutes=2, id='my_job_id')
scheduler.pause_job('my_job_id')
scheduler.resume_job('my_job_id')
任务的修饰modify和重设reschedule_job
修饰:job.modify(max_instances=6, name='Alternate name')
重设:scheduler.reschedule_job('my_job_id', trigger='cron', minute='*/5')

调度器操作
开启 scheduler.start()

关闭 scheduler.shotdown(wait=True | False)

暂停 scheduler.pause()

继续 scheduler.resume()

监听 http://apscheduler.readthedoc...

def my_listener(event):

if event.exception:
    print('The job crashed :(')
else:
    print('The job worked :)')

scheduler.add_listener(my_listener, EVENT_JOB_EXECUTED | EVENT_JOB_ERROR)
官方实例
from pytz import utc

from apscheduler.schedulers.background import BackgroundScheduler
from apscheduler.jobstores.mongodb import MongoDBJobStore
from apscheduler.jobstores.sqlalchemy import SQLAlchemyJobStore
from apscheduler.executors.pool import ThreadPoolExecutor, ProcessPoolExecutor

jobstores = {

'mongo': MongoDBJobStore(),
'default': SQLAlchemyJobStore(url='sqlite:///jobs.sqlite')

}
executors = {

'default': ThreadPoolExecutor(20),
'processpool': ProcessPoolExecutor(5)

}
job_defaults = {

'coalesce': False,
'max_instances': 3

}
scheduler = BackgroundScheduler(jobstores=jobstores, executors=executors, job_defaults=job_defaults, timezone=utc)

一、更新pip版本
1.下载最新pip
新建packages文件夹放在目录中:d:python27packages。

Unofficial Windows Binaries for Python Extension Packages
从该网站提供的编译好的包下载最新版本pip-8.1.2-py2.py3-none-any.whl和wheel-0.29.0-py2.py3-none-any.whl,在packages文件夹中。

离线安装pip时,这两个包需要准备好。

2.安装下载好的pip
进入python27目录(目录下有python.exe),也放在该目录。

pip文档下载get-pip.py

get-pip下载链接

cmd窗口执行

python.exe get-pip.py --no-index --find-links=d:python27packages
PS:如果你可以联网,那么安装pip就方便多了,执行python get-pip.py。

方案
1.在可以联网的开发机器上安装好需要的包
例如:

pip install numpy
pip install pandas
2.打包已安装的包
在D:python27目录下新建packages文件夹用来存储下载下来的所需安装包。

在 D:Python27Scripts下启动cmd窗口。

pip list #查看安装的包
pip freeze >requirements.txt
pip install --download d:python27packages -r requirements.txt
3.离线情况安装打包好的包
将packages文件夹和requirement.txt拷贝至离线机器上目录下,packages文件夹放在D:Python27下,requirement.txt放在D:Python27Scripts下。

requirements.txt文件放在pip.exe目录下。

pip install --no-index --find-index=d:python27packages -r requirements.txt
补充
1.下载指定的包到指定文件夹

pip install --download d:python27packs pandas(-r requirements.txt)
2.安装指定的离线包

pip install --no-index --find-links=d:python27packs pandas (-r requirements.txt)

昨天无意看到群里讨论一个名为 MicroChat 基于Mars的微信Android通讯协议客户端代码!!
Github地址:https://github.com/InfiniteTsukuyomi/MicroChat/ (已消失)
声明:
本文仅提供Mars学习交流参考,请勿用于非法用途,否则后果自负!!!
本人才疏学浅,文章参考了部分资料,欢迎各位指正,共同交流学习!
感谢原作者:原作2位大神的神作

编译准备:
开发环境:Visual Studio 2015 及以上版本,部分测试VS13编译通过
抓包工具 Wireshark
分析工具 tcpdump
依赖:Mars / Duilib / SQLite3
主要项目 MicroChatSDK.dll
UI层 MicroChat (DUILIB)
使用前的准备配置
/MicroChatSDK/Business/define.h
//测试请手动修改登录设备信息
//登录设备硬件信息

define DEVICE_INFO_GUID "A31d2152a33d83e7" //GUID

define DEVICE_INFO_CLIENT_SEQID "A31cc712ad2d83e6_1512965043210" //GUID_LOCATION地址

define DEVICE_INFO_CLIENT_SEQID_SIGN "e89b238e77cf988ebd09eb65f5378e99" //MD5

define DEVICE_INFO_IMEI "865167123366678" //手机IMEI

define DEVICE_INFO_ANDROID_ID "eabe1f220561a49f" //设备ID

define DEVICE_INFO_ANDROID_VER "android-26" //安卓版本

define DEVICE_INFO_MANUFACTURER CStringA2Utf8("iPhone") //设备名称 随便填

define DEVICE_INFO_MODELNAME CStringA2Utf8("X") //型号名称 随便填

define DEVICE_INFO_MOBILE_WIFI_MAC_ADDRESS "01:67:33:56:78:11" //WIFI MAC地址

define DEVICE_INFO_AP_BSSID "41:25:99:22:3f:14" //手机信号基站 MAC地址

define DEVICE_INFO_LANGUAGE "zh_CN" //语言

//下面2个是设备 com.tencent.mm 包信息 及 设备信息(使用上面宏)

define DEVICE_INFO_SOFTINFO "<softtype><lctmoc>0</lctmoc><level>1</level><k1>ARMv7 processor rev 1 (v7l) </k1><k2></k2><k3>5.1.1</k3><k4>%s</k4><k5>460007337766541</k5><k6>89860012221746527381</k6><k7>%s</k7><k8>unknown</k8><k9>%s</k9><k10>2</k10><k11>placeholder</k11><k12>0001</k12><k13>0000000000000001</k13><k14>%s</k14><k15></k15><k16>neon vfp swp half thumb fastmult edsp vfpv3 idiva idivt</k16><k18>%s</k18><k21>"wireless"</k21><k22></k22><k24>%s</k24><k26>0</k26><k30>"wireless"</k30><k33>com.tencent.mm</k33><k34>Android-x86/android_x86/x86:5.1.1/LMY48Z/denglibo08021647:userdebug/test-keys</k34><k35>vivo v3</k35><k36>unknown</k36><k37>%s</k37><k38>x86</k38><k39>android_x86</k39><k40>%s</k40><k41>1</k41><k42>%s</k42><k43>null</k43><k44>0</k44><k45></k45><k46></k46><k47>wifi</k47><k48>%s</k48><k49>/data/data/com.tencent.mm/</k49><k52>0</k52><k53>0</k53><k57>1080</k57><k58></k58><k59>0</k59></softtype>"

define DEVICE_INFO_DEVICEINFO "<deviceinfo><MANUFACTURER name="%s"><MODEL name=%s"><VERSION_RELEASE name="5.1.1"><VERSION_INCREMENTAL name="eng.denglibo.20171224.164708"><DISPLAY name="android_x86-userdebug 5.1.1 LMY48Z eng.denglibo.20171224.164708 test-keys"></DISPLAY></VERSION_INCREMENTAL></VERSION_RELEASE></MODEL></MANUFACTURER></deviceinfo>"

LOGIN_RSA_VER //秘钥版本
LOGIN_RSA_VER158_KEY_E //秘钥加密
LOGIN_RSA_VER158_KEY_N //混淆后??

微信功能请求

define CGI_NEWSYNC "/cgi-bin/micromsg-bin/newsync" //同步服务端最新消息

define CGI_MANUALAUTH "/cgi-bin/micromsg-bin/manualauth" //登录

define CGI_NEWSENDMSG "/cgi-bin/micromsg-bin/newsendmsg" //发送文字消息

define CGI_NEWINIT "/cgi-bin/micromsg-bin/newinit" //首次登录,初始化数据库

define CGI_GETPROFILE "/cgi-bin/micromsg-bin/getprofile" //获取个人信息

define CGI_SEARCHCONTACT "/cgi-bin/micromsg-bin/searchcontact" //搜索新朋友

define CGI_GETCONTACT "/cgi-bin/micromsg-bin/getcontact" //查找新朋友

define CGI_VERIFYUSER "/cgi-bin/micromsg-bin/verifyuser" //添加好友

define CGI_BIND "/cgi-bin/micromsg-bin/bindopmobileforreg" //首次登录短信授权

比如可以添加
findnearby , getmoment , 等~

/MicroChatSDK/Business/AuthInfo.h

pragma once

include <string>

include "db/db.h"

class CAuthInfo
{
public:

CAuthInfo()
{
    InitializeCriticalSection(&m_cs_syncKey);
}

string    m_UserName; //昵称
string    m_WxId;  //wxid 或 老微信号
DWORD   m_uin = 0;   //uin 唯一标识
string    m_Alias;     //微信号
string    m_Session;    //SessionKey
DWORD   m_ClientVersion;   //客户端版本
string  m_guid_15;    //guid 15位
string  m_guid;       //guid
string  m_androidVer;  //安卓版本
string  m_launguage;   //lang
string  m_cookie;      //置入浏览器的Cookie

string GetSyncKey();
void SetSyncKey(string strSyncKey);
static CAuthInfo *GetInstance();

//获取短信验证码凭据
string m_mobilecode_authticket;
//接受短信号码(当前默认使用登录账号)
string m_mobileNum;

private:

static CAuthInfo * m_Instance;

CRITICAL_SECTION   m_cs_syncKey;

};

define pAuthInfo (CAuthInfo::GetInstance())

编译常见错误:
BOOST错误 重新引用 mars/boost
MARS 的引用错误,重新引用 mars mars/comm mars/boost 等文件夹
DUILIB编译错误 参考 github.com/duilib
SQLITE3编译 需要修改一次 编译为 DLL & LIB
LIB缺失 手动引用..
VS13及以下版本会有部分语法错误!!请使用VS15及以上版本!!!

一.微信协议概览

OK,我们言归正传。先看下对微信通讯的研究
远程端口有: 80 443 8080 5222 5223 5228 这几个
特定域名:
support.weixin.qq.com 80/8080
short.weixin.qq.com 443/8080
long.weixin.qq.com 80/443
wx.qlogo.cn 80

微信网络行为

1.程序启动后,优先尝试DNS解析特定域名(support.weixin.qq.com,short.weixin.qq.com,long.weixin.qq.com,wx.qlogo.cn);
2.如果DNS查询不可用,程序转为使用hardcode的ip链接服务;
3.如果dns可用,返回的ip为根据ISP智能解析的结果,程序使用返回的ip链接服务;
4.程序仅在注册阶段使用https链接,内容不详;
5.程序使用tcp 80/8080链接服务器,其中80为http协议,8080为未知协议;
6.80/8080两个端口同时或任何单独一个,均可提供服务;
7.80端口为短链接,8080为长链接, 程序会优先使用8080端口;
8.没有使用udp传输数据;
9.当1-2次发送失败时,客户端会弹出提示“当前网络状况不好,是否提交反馈数据”,确认后客户端试图通过web提交反馈数据;

dns查询
dns.weixin.qq.com
返回一组IP地址long.weixin.qq.com
返回一组IP地址,本次通信中,微信使用了最后一个IP作为TCP长连接的连接地址。
http://dns.weixin.qq.com/cgi-bin/micromsg-bin/newgetdns?uin=0&clientversion=620888113&scene=0&net=1
用于请求服务器获得最优IP路径。服务器通过结算返回一个xml定义了域名:IP对应列表。
仔细阅读,可看到微信已经开始了国际化的步伐:香港、加拿大、韩国等。
具体文本,请参考:https://gist.github.com/yongboy/9341884
获取到long.weixin.qq.com最优IP,然后建立到101.227.131.105的TCP长连接
POST http://short.weixin.qq.com/cgi-bin/micromsg-bin/getprofile HTTP/1.1 (application/octet-stream)
返回一个名为“micromsgresp.dat”的附件,估计是未阅读的离线消息
POST http://short.weixin.qq.com/cgi-bin/micromsg-bin/whatsnews HTTP/1.1 (application/octet-stream)
大概是资讯、订阅更新等
GET http://wx.qlogo.cn/mmhead/Q3auHgzwzM7NR4TYFcoNjbxZpfO9aiaE7RU5lXGUw13SMicL6iacWIf2A/96
图片等一些静态资源都会被分配到wx.qlogo.cn域名下面
下载缓存
POST http://short.weixin.qq.com/cgi-bin/micromsg-bin/downloadpackage HTTP/1.1 (application/octet-stream)
输出为micromsgresp.dat文件
GET http://support.weixin.qq.com/cgi-bin/mmsupport-bin/reportdevice?channel=34&deviceid=A952001f7a840c2a&clientversion=620888113&platform=0&lang=zh_CN&installtype=0 HTTP/1.1
返回chunked分块数据
POST http://short.weixin.qq.com/cgi-bin/micromsg-bin/reportstrategy HTTP/1.1 (application/octet-stream)

  1. 心跳频率约为5分钟
    上次使用Wireshark分析有误(得出18分钟结论),再次重新分析,心跳频率在5分钟左右。
  2. 登陆之后,会建立一个长连接,端口号为8080
    简单目测为HTTP,初始以为是双通道HTTP,难道是自定义的用于双通道通信的HTTP协议吗,网络上可见资料都是模棱两可、语焉不详。

具体查看长连接初始数据通信,没有发现任何包含"HTTP"字样的数据,以为是微信自定义的TCP/HTTP通信格式。据分析,用于可能用于获取数据、心跳交换消息等用途吧。这个后面会详谈微信是如何做到的。

2.0 初始消息传输
个人资料、离线未阅读消息部分等通过 POST HTTP短连接单独获取。

2.1 二进制简单分析
抽取微信某次HTTP协议方式通信数据,16进制表示,每两个靠近的数字为一个byte字节:

二.微信协议分析

微信协议可能如下:

一个消息包 = 消息头 + 消息体
消息头固定16字节长度,消息包长度定义在消息头前4个字节中。

单纯摘取第0000行为例,共16个字节的头部:

00 00 00 10 00 10 00 01 00 00 00 06 00 00 00 0f
16进制表示,每两个紧挨着数字代表一个byte字节。

微信消息包格式: 1. 前4字节表示数据包长度,可变 值为16时,意味着一个仅仅包含头部的完整的数据包(可能表示着预先定义好的业务意义),后面可能还有会别的消息包 2. 2个字节表示头部长度,固定值,0x10 = 16 3. 2个字节表示谢意版本,固定值,0x01 = 1 4. 4个字节操作说明数字,可变 5. 序列号,可变 6. 头部后面紧跟着消息体,非明文,加密形式 7. 一个消息包,最小16 byte字节

通过上图(以及其它数据多次采样)分析:

0000 - 0040为单独的数据包
0050行为下一个数据包的头部,前四个字节值为0xca = 202,表示包含了从0050-0110共202个字节数据
一次数据发送,可能包含若干子数据包
换行符n,16进制表示为0x0a,在00f0行,包含了两个换行符号
一个数据体换行符号用于更细粒度的业务数据分割 是否蒙对,需要问问做微信协议的同学
所有被标记为HTTP协议通信所发送数据都包含换行符号
2.2 动手试试猜想,模拟微信TCP长连接
开始很不解为什么会出现如此怪异的HTTP双通道长连接请求,难道基于TCP通信,然后做了一些手脚?很常规的TCP长连接,传输数据时(不是所有数据传输),被wireshark误认为HTTP长连接。这个需要做一个实验证实一下自己想法,设想如下:

写一个Ping-Pong客户端、服务器端程序,然后使用Wireshark看一下结果,是否符合判断。

2014-03-03_15h07_30_thumb.png
服务端:https://gist.githubusercontent.com/yongboy/9341037/raw/pong_server.c

/**
  • nieyong@youku.com
  • how to compile it:
  • gcc pong_server.c -o pong_server /usr/local/lib/libev.a -lm
    */

include <arpa/inet.h>

include <stdlib.h>

include <stdio.h>

include <string.h>

include <fcntl.h>

include <errno.h>

include <err.h>

include <unistd.h>

include "../include/ev.h"

static int server_port = 8080;

struct ev_loop *loop;
typedef struct {

int fd;
ev_io ev_read;

} client_t;

ev_io ev_accept;

static void free_res(struct ev_loop loop, ev_io ws);

int setnonblock(int fd) {

int flags = fcntl(fd, F_GETFL);
if (flags < 0)
    return flags;

flags |= O_NONBLOCK;
if (fcntl(fd, F_SETFL, flags) < 0)
    return -1;

return 0;

}

static void read_cb(struct ev_loop loop, ev_io w, int revents) {

client_t *client = w->data;
int r = 0;
char rbuff[1024];
if (revents & EV_READ) {
    r = read(client->fd, &rbuff, 1024);
}

if (EV_ERROR & revents) {
    fprintf(stderr, "error event in read\n");
    free_res(loop, w);
    return ;
}

if (r < 0) {
    fprintf(stderr, "read error\n");
    ev_io_stop(EV_A_ w);
    free_res(loop, w);
    return;
}

if (r == 0) {
    fprintf(stderr, "client disconnected.\n");
    ev_io_stop(EV_A_ w);
    free_res(loop, w);
    return;
}

send(client->fd, rbuff, r, 0);

}

static void accept_cb(struct ev_loop loop, ev_io w, int revents) {

struct sockaddr_in client_addr;
socklen_t client_len = sizeof(client_addr);
int client_fd = accept(w->fd, (struct sockaddr *) &client_addr, &client_len);
if (client_fd == -1) {
    fprintf(stderr, "the client_fd is  NULL !\n");
    return;
}

client_t *client = malloc(sizeof(client_t));
client->fd = client_fd;
if (setnonblock(client->fd) < 0)
    err(1, "failed to set client socket to non-blocking");

client->ev_read.data = client;

ev_io_init(&client->ev_read, read_cb, client->fd, EV_READ);
ev_io_start(loop, &client->ev_read);

}

int main(int argc, char const *argv[]) {

int ch;
while ((ch = getopt(argc, argv, "p:")) != -1) {
    switch (ch) {
    case 'p':
        server_port = atoi(optarg);
        break;
    }
}

loop = ev_default_loop(0);
struct sockaddr_in listen_addr;
int reuseaddr_on = 1;
int listen_fd = socket(AF_INET, SOCK_STREAM, 0);
if (listen_fd < 0)
    err(1, "listen failed");
if (setsockopt(listen_fd, SOL_SOCKET, SO_REUSEADDR, &reuseaddr_on, sizeof(reuseaddr_on)) == -1)
    err(1, "setsockopt failed");

memset(&listen_addr, 0, sizeof(listen_addr));
listen_addr.sin_family = AF_INET;
listen_addr.sin_addr.s_addr = INADDR_ANY;
listen_addr.sin_port = htons(server_port);

if (bind(listen_fd, (struct sockaddr *) &listen_addr, sizeof(listen_addr)) < 0)
    err(1, "bind failed");
if (listen(listen_fd, 5) < 0)
    err(1, "listen failed");
if (setnonblock(listen_fd) < 0)
    err(1, "failed to set server socket to non-blocking");

ev_io_init(&ev_accept, accept_cb, listen_fd, EV_READ);
ev_io_start(loop, &ev_accept);
ev_loop(loop, 0);

return 0;

}

static void free_res(struct ev_loop loop, ev_io w) {

client_t *client = w->data;
if (client == NULL) {
    fprintf(stderr, "the client is NULL !!!!!!");
    return;
}

ev_io_stop(loop, &client->ev_read);
close(client->fd);
free(client);

}

客户端代码 : https://gist.githubusercontent.com/yongboy/9319660/raw/PingClient.java

/**
  • Ping Client
  • @author nieyong
    */

package com.learn;

import io.netty.bootstrap.Bootstrap;
import io.netty.buffer.ByteBuf;
import io.netty.buffer.PooledByteBufAllocator;
import io.netty.channel.ChannelFuture;
import io.netty.channel.ChannelHandlerContext;
import io.netty.channel.ChannelInboundHandlerAdapter;
import io.netty.channel.ChannelInitializer;
import io.netty.channel.ChannelOption;
import io.netty.channel.EventLoopGroup;
import io.netty.channel.nio.NioEventLoopGroup;
import io.netty.channel.socket.SocketChannel;
import io.netty.channel.socket.nio.NioSocketChannel;

import java.util.concurrent.TimeUnit;

class PingClientHandler extends ChannelInboundHandlerAdapter {

private final ByteBuf firstMessage;

public PingClientHandler() {
    firstMessage = PooledByteBufAllocator.DEFAULT.buffer(22);

    // weixin 16 byte's header
    firstMessage.writeByte(0);
    firstMessage.writeByte(0);
    firstMessage.writeByte(0);
    firstMessage.writeByte(16);

    firstMessage.writeByte(0);
    firstMessage.writeByte(16);

    firstMessage.writeByte(0);
    firstMessage.writeByte(1);

    firstMessage.writeByte(0);
    firstMessage.writeByte(0);
    firstMessage.writeByte(0);
    firstMessage.writeByte(6);

    firstMessage.writeByte(0);
    firstMessage.writeByte(0);
    firstMessage.writeByte(0);
    firstMessage.writeByte(1);

    // just for /n
    firstMessage.writeByte('\n'); // 1 byte

    // footer 16 byte
    String welcome = "hello"; // 5 byte
    firstMessage.writeBytes(welcome.getBytes());
}

@Override
public void channelActive(ChannelHandlerContext ctx) {
    ctx.writeAndFlush(firstMessage);
}

@Override
public void channelRead(final ChannelHandlerContext ctx, final Object msg)
        throws Exception {
    ctx.executor().schedule(new Runnable() {
        @Override
        public void run() {
            ctx.channel().writeAndFlush(msg);
        }
    }, 1, TimeUnit.SECONDS);
}

@Override
public void channelReadComplete(ChannelHandlerContext ctx) throws Exception {
    ctx.flush();
}

@Override
public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) {
    System.err.println("Unexpected exception from downstream :"
            + cause.getMessage());
    ctx.close();
}

}

public class PingClient {

private final String host;
private final int port;

public PingClient(String host, int port) {
    this.host = host;
    this.port = port;
}

public void run() throws Exception {
    EventLoopGroup group = new NioEventLoopGroup();
    try {
        Bootstrap b = new Bootstrap();
        b.group(group).channel(NioSocketChannel.class)
                .option(ChannelOption.TCP_NODELAY, true)
                .handler(new ChannelInitializer<SocketChannel>() {
                    @Override
                    public void initChannel(SocketChannel ch)
                            throws Exception {
                        ch.pipeline().addLast(new PingClientHandler());
                    }
                });

        ChannelFuture f = b.connect(host, port).sync();

        f.channel().closeFuture().sync();
    } finally {
        // Shut down the event loop to terminate all threads.
        group.shutdownGracefully();
    }
}

public static void main(String[] args) throws Exception {
    String host = "127.0.0.1";
    int port = 8080;

    if (args.length == 3) {
        host = args[0];
        port = Integer.parseInt(args[1]);
    }

    new PingClient(host, port).run();
}

}

2014-03-03_14h53_19_thumb.png
结论是什么呢?
若使用原始TCP进行双向通信,则需要满足以下条件,可以被类似于Wireshark协议拦截器误认为是HTTP长连接:

1.使用80/8080端口(81/3128/8000经测试无效) 也许8080一般被作为WEB代理服务端口,微信才会享用这个红利吧。
输出的内容中,一定要包含换行字符"n"
2.因此,可以定性为微信使用了基于8080端口TCP长连接,一旦数据包中含有换行"n"符号,就会被Wireshark误认为HTTP协议。可能微信是无心为之吧。

  1. 新消息获取方式
    1.TCP长连接接收到服务器通知有新消息需要获取

    1. APP发起一个HTTP POST请求获取新状态消息,会带上当前SyncKey 地址为:http://short.weixin.qq.com/cgi-bin/micromsg-bin/reportstrategy HTTP/1.1,看不到明文
      3.APP获取到新的消息,会再次发起一次HTTP POST请求,告诉服务器已确认收到,同时获取最新SyncKey 地址为:http://short.weixin.qq.com/cgi-bin/micromsg-bin/kvreport,看不到明文

4.接受一个消息,TCP长连接至少交互两次,客户端发起两次HTTP POST请求 具体每次交互内容是什么,有些模糊
服务器需要支持:状态消息获取标记,状态消息确认收取标记。只有被确认收到,此状态消息才算是被正确消费掉
5.多个不同设备同一账号同时使用微信,同一个状态消息会会被同时分发到多个设备上
此时消息请求截图如下:
2014-03-03_15h58_15_thumb.png

  1. 发送消息方式
    发送消息走已经建立的TCP长连接通道,发送消息到服务器,然后接受确认信息等,产生一次交互。

小伙伴接收到信息阅读也都会收到服务器端通知,产生一次交互等。

可以确定,微信发送消息走TCP长连接方式,因为不对自身状态数据产生影响,应该不交换SyncKey。

在低速网络下,大概会看到消息发送中的提示,属于消息重发机制
网络不好有时客户端会出现发送失败的红色感叹号
已发送到服务器但未收到确认的消息,客户端显示红色感叹号,再次重发,服务器作为重复消息处理,反馈确认
上传图片,会根据图片大小,分割成若干部分(大概1.5K被划分为一部分),同一时间点,客户端会发起若干次POST请求,各自上传成功之后,服务器大概会合并成一个完整图片,返回一个缩略图,显示在APP聊天窗口内。APP作为常规的文字消息发送到服务器端
上传音频,则单独走TCP通道,一个两秒的录制音频,客户端录制完毕,分为两块传输,一块最大1.5K左右,服务端响应一条数据通知确认收到。共三次数据传输。音频和纯文字信息一致,都是走TCP长连接,客户端发送,服务器端确认。

四.微信协议小结

1.发布的消息对应一个ID(只要单个方向唯一即可,服务器端可能会根ID判断重复接收),消息重传机制确保有限次的重试,重试失败给予用户提示,发送成功会反馈确认,客户端只有收到确认信息才知道发送成功。发送消息可能不会产生新SyncKey。
2.基于版本号(SynKey)的状态消息同步机制,增量、有序传输需求水到渠成。长连接通知/短连接获取、确认等,交互方式简单,确保了消息可靠谱、准确无误到达。
3.客户端/服务器端都会存储消息ID处理记录,避免被重复消费客户端获取最新消息,但未确认,服务器端不会认为该消息被消费掉。下次客户端会重新获取,会查询当前消息是否被处理过。根据一些现象猜测。
4.总体上看,微信协议跨平台(TCP或HTPP都可呈现,处理方式可统一),通过“握手”同步,很可靠,无论哪一个平台都可以支持的很好
5.微信协议最小成本为16字节,大部分时间若干个消息包和在一起,批量传输。微信协议说不上最简洁,也不是最节省流量,但是非常成功的。
6.若服务器检测到一些不确定因素,可能会导致微启用安全套接层SSL协议进行常规的TCP长连接传输。短连接都没有发生变化

以上,根据有限资料和数据拦截观察总结得出,啰啰嗦嗦,勉强凑成一篇,会存在一些不正确之处,欢迎给予纠正。在多次

五.附录

Microsoft Exchange Active Sync协议,简称EAS,分为folderrsync(同步文件夹目录,即邮箱内有哪几个文件夹)和sync(每个文件夹内有哪些文档)两部分。

某网友总结的协议一次回话大致示范:
Client: synckey=0 //第一次key为0
Server: newsynckey=1235434 //第一次返回新key
Client: synckey=1235434 //使用新key查询
Server: newsynckey=1647645,data=*//第一次查询,得到新key和数据
Client: synckey=1647645
Server: newsynckey=5637535,data=null //第二次查询,无新消息
Client: synckey=5637535
Server: newsynckey=8654542, data=**//第三次查询,增量同步
上页中的相邻请求都是隔固定时间的,如两分钟
客户端每次使用旧key标记自己的状态,服务端每次将新key和增量数据一起返回。
key是递增的,但不要求连续
请求的某个参数决定服务器是否立即返回

1.编译问题,如果还没有编译成功的同学可以参考我分享的这个Release版本 (为防止黑产泛滥 不便公开修正过的代码 需要的可以问群里其他同学要)
MicroChat Release_vc141d
2.编译过程中需要安装ATL boost库支持
3.mars 依赖编译顺序 > MicroChatSDK > MicroChat
需要设置 VC++目录
..mars
..marscomm
..marscommwindows
..marsopensslinclude
..marsopensslincludeopenssl
..sqlite3
protoprotobuf

或填写附加包含目录
$(ProjectDir);$(ProjectDir)WTL;$(ProjectDir)../;$(ProjectDir)../mars;$(ProjectDir)../mars/comm/windows;$(ProjectDir)../mars/comm;$(ProjectDir)proto/protobuf
测试登录,手机版也可以看到设备 假iphoneX (android 26)
20180111172743.jpg
20180111172802.jpg
登录后,手机客户端就提示掉线了
20180111172814.jpg
20180111172823.jpg
发消息测试
20180111172832-768x326.png
收消息测试
20180111172842.png
其他类型消息 以XML方式发送,需要下载可通过 res.wx.qq.com / qpic.cn /wx.qlogo.cn 等下载...
20180111172850.png
测试加载好友列表
20180111172900-1024x677.png
20180111172909-1024x579.png
登录验证
20180111172946.png
登录
20180111172957-768x503.jpg
20180111173002.jpg

error:1366, “Incorrect string value: ‘xF0x9Fx98x81’

是因为mysql不能识别4个字节的utf8编码的字符,抛出了异常,这应该也是问题的根源。☺、��、类似于这种4个字节,将对应字符类型换成将对应的数据类型改为utf8mb4类型,同时连接类型也要改成utf8mb4_general_ci

20170806144652420.png
python 代码形式(3.6)
conn=pymysql.connect(
host=’127.0.0.1’,
port=3306,
user=’root’,
passwd=’343434’,
db=’kmind8’,
charset=’utf8mb4’,
)

本节内容
日志相关概念
logging模块简介
使用logging提供的模块级别的函数记录日志
logging模块日志流处理流程
使用logging四大组件记录日志
配置logging的几种方式
向日志输出中添加上下文信息

一、日志相关概念
日志是一种可以追踪某些软件运行时所发生事件的方法。软件开发人员可以向他们的代码中调用日志记录相关的方法来表明发生了某些事情。一个事件可以用一个可包含可选变量数据的消息来描述。此外,事件也有重要性的概念,这个重要性也可以被称为严重性级别(level)。

1.日志的作用
通过log的分析,可以方便用户了解系统或软件、应用的运行情况;如果你的应用log足够丰富,也可以分析以往用户的操作行为、类型喜好、地域分布或其他更多信息;如果一个应用的log同时也分了多个级别,那么可以很轻易地分析得到该应用的健康状况,及时发现问题并快速定位、解决问题,补救损失。
简单来讲就是,我们通过记录和分析日志可以了解一个系统或软件程序运行情况是否正常,也可以在应用程序出现故障时快速定位问题。比如,做运维的同学,在接收到报警或各种问题反馈后,进行问题排查时通常都会先去看各种日志,大部分问题都可以在日志中找到答案。再比如,做开发的同学,可以通过IDE控制台上输出的各种日志进行程序调试。对于运维老司机或者有经验的开发人员,可以快速的通过日志定位到问题的根源。可见,日志的重要性不可小觑。日志的作用可以简单总结为以下3点:

程序调试
了解软件程序运行情况,是否正常
软件程序运行故障分析与问题定位
如果应用的日志信息足够详细和丰富,还可以用来做用户行为分析,如:分析用户的操作行为、类型洗好、地域分布以及其它更多的信息,由此可以实现改进业务、提高商业利益。

2.日志的等级
我们先来思考下下面的两个问题:

作为开发人员,在开发一个应用程序时需要什么日志信息?在应用程序正式上线后需要什么日志信息?
作为应用运维人员,在部署开发环境时需要什么日志信息?在部署生产环境时需要什么日志信息?
在软件开发阶段或部署开发环境时,为了尽可能详细的查看应用程序的运行状态来保证上线后的稳定性,我们可能需要把该应用程序所有的运行日志全部记录下来进行分析,这是非常耗费机器性能的。当应用程序正式发布或在生产环境部署应用程序时,我们通常只需要记录应用程序的异常信息、错误信息等,这样既可以减小服务器的I/O压力,也可以避免我们在排查故障时被淹没在日志的海洋里。那么,怎样才能在不改动应用程序代码的情况下实现在不同的环境记录不同详细程度的日志呢?这就是日志等级的作用了,我们通过配置文件指定我们需要的日志等级就可以了。

不同的应用程序所定义的日志等级可能会有所差别,分的详细点的会包含以下几个等级:

DEBUG
INFO
NOTICE
WARNING
ERROR
CRITICAL
ALERT
EMERGENCY
3.日志字段信息与日志格式
本节开始问题提到过,一条日志信息对应的是一个事件的发生,而一个事件通常需要包括以下几个内容:

事件发生时间
事件发生位置
事件的严重程度--日志级别
事件内容
上面这些都是一条日志记录中可能包含的字段信息,当然还可以包括一些其他信息,如进程ID、进程名称、线程ID、线程名称等。日志格式就是用来定义一条日志记录中包含那些字段的,且日志格式通常都是可以自定义的。

说明:

输出一条日志时,日志内容和日志级别是需要开发人员明确指定的。对于而其它字段信息,只需要是否显示在日志中就可以了。

4.日志功能的实现
几乎所有开发语言都会内置日志相关功能,或者会有比较优秀的第三方库来提供日志操作功能,比如:log4j,log4php等。它们功能强大、使用简单。Python自身也提供了一个用于记录日志的标准库模块--logging。

二、logging模块简介
logging模块定义的函数和类为应用程序和库的开发实现了一个灵活的事件日志系统。logging模块是Python的一个标准库模块,由标准库模块提供日志记录API的关键好处是所有Python模块都可以使用这个日志记录功能。所以,你的应用日志可以将你自己的日志信息与来自第三方模块的信息整合起来。

  1. logging模块的日志级别
    logging模块默认定义了以下几个日志等级,它允许开发人员自定义其他日志级别,但是这是不被推荐的,尤其是在开发供别人使用的库时,因为这会导致日志级别的混乱。

日志等级(level) 描述
DEBUG 最详细的日志信息,典型应用场景是 问题诊断
INFO 信息详细程度仅次于DEBUG,通常只记录关键节点信息,用于确认一切都是按照我们预期的那样进行工作
WARNING 当某些不期望的事情发生时记录的信息(如,磁盘可用空间较低),但是此时应用程序还是正常运行的
ERROR 由于一个更严重的问题导致某些功能不能正常运行时记录的信息
CRITICAL 当发生严重错误,导致应用程序不能继续运行时记录的信息
开发应用程序或部署开发环境时,可以使用DEBUG或INFO级别的日志获取尽可能详细的日志信息来进行开发或部署调试;应用上线或部署生产环境时,应该使用WARNING或ERROR或CRITICAL级别的日志来降低机器的I/O压力和提高获取错误日志信息的效率。日志级别的指定通常都是在应用程序的配置文件中进行指定的。

说明:

上面列表中的日志等级是从上到下依次升高的,即:DEBUG < INFO < WARNING < ERROR < CRITICAL,而日志的信息量是依次减少的;
当为某个应用程序指定一个日志级别后,应用程序会记录所有日志级别大于或等于指定日志级别的日志信息,而不是仅仅记录指定级别的日志信息,nginx、php等应用程序以及这里要提高的python的logging模块都是这样的。同样,logging模块也可以指定日志记录器的日志级别,只有级别大于或等于该指定日志级别的日志记录才会被输出,小于该等级的日志记录将会被丢弃。

  1. logging模块的使用方式介绍
    logging模块提供了两种记录日志的方式:

第一种方式是使用logging提供的模块级别的函数
第二种方式是使用Logging日志系统的四大组件
其实,logging所提供的模块级别的日志记录函数也是对logging日志系统相关类的封装而已。

logging模块定义的模块级别的常用函数
函数 说明
logging.debug(msg, args, *kwargs) 创建一条严重级别为DEBUG的日志记录
logging.info(msg, args, *kwargs) 创建一条严重级别为INFO的日志记录
logging.warning(msg, args, *kwargs) 创建一条严重级别为WARNING的日志记录
logging.error(msg, args, *kwargs) 创建一条严重级别为ERROR的日志记录
logging.critical(msg, args, *kwargs) 创建一条严重级别为CRITICAL的日志记录
logging.log(level, args, *kwargs) 创建一条严重级别为level的日志记录
logging.basicConfig(**kwargs) 对root logger进行一次性配置
其中logging.basicConfig(**kwargs)函数用于指定“要记录的日志级别”、“日志格式”、“日志输出位置”、“日志文件的打开模式”等信息,其他几个都是用于记录各个级别日志的函数。

logging模块的四大组件
组件 说明
loggers 提供应用程序代码直接使用的接口
handlers 用于将日志记录发送到指定的目的位置
filters 提供更细粒度的日志过滤功能,用于决定哪些日志记录将会被输出(其它的日志记录将会被忽略)
formatters 用于控制日志信息的最终输出格式
说明: logging模块提供的模块级别的那些函数实际上也是通过这几个组件的相关实现类来记录日志的,只是在创建这些类的实例时设置了一些默认值。

三、使用logging提供的模块级别的函数记录日志
回顾下前面提到的几个重要信息:

可以通过logging模块定义的模块级别的方法去完成简单的日志记录
只有级别大于或等于日志记录器指定级别的日志记录才会被输出,小于该级别的日志记录将会被丢弃。
1.最简单的日志输出
先来试着分别输出一条不同日志级别的日志记录:

import logging

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This is a warning log.")
logging.error("This is a error log.")
logging.critical("This is a critical log.")
也可以这样写:

logging.log(logging.DEBUG, "This is a debug log.")
logging.log(logging.INFO, "This is a info log.")
logging.log(logging.WARNING, "This is a warning log.")
logging.log(logging.ERROR, "This is a error log.")
logging.log(logging.CRITICAL, "This is a critical log.")
输出结果:

WARNING:root:This is a warning log.
ERROR:root:This is a error log.
CRITICAL:root:This is a critical log.

  1. 那么问题来了
    问题1:为什么前面两条日志没有被打印出来?

这是因为logging模块提供的日志记录函数所使用的日志器设置的日志级别是WARNING,因此只有WARNING级别的日志记录以及大于它的ERROR和CRITICAL级别的日志记录被输出了,而小于它的DEBUG和INFO级别的日志记录被丢弃了。

问题2:打印出来的日志信息中各字段表示什么意思?为什么会这样输出?
上面输出结果中每行日志记录的各个字段含义分别是:

日志级别:日志器名称:日志内容
之所以会这样输出,是因为logging模块提供的日志记录函数所使用的日志器设置的日志格式默认是BASIC_FORMAT,其值为:

"%(levelname)s:%(name)s:%(message)s"
问题3:如果将日志记录输出到文件中,而不是打印到控制台?
因为在logging模块提供的日志记录函数所使用的日志器设置的处理器所指定的日志输出位置默认为:
sys.stderr。

问题4:我是怎么知道这些的?
查看这些日志记录函数的实现代码,可以发现:当我们没有提供任何配置信息的时候,这些函数都会去调用logging.basicConfig(**kwargs)方法,且不会向该方法传递任何参数。继续查看basicConfig()方法的代码就可以找到上面这些问题的答案了。

问题5:怎么修改这些默认设置呢?
其实很简单,在我们调用上面这些日志记录函数之前,手动调用一下basicConfig()方法,把我们想设置的内容以参数的形式传递进去就可以了。

  1. logging.basicConfig()函数说明
    该方法用于为logging日志系统做一些基本配置,方法定义如下:

logging.basicConfig(**kwargs)
该函数可接收的关键字参数如下:

参数名称 描述
filename 指定日志输出目标文件的文件名,指定该设置项后日志信心就不会被输出到控制台了
filemode 指定日志文件的打开模式,默认为'a'。需要注意的是,该选项要在filename指定时才有效
format 指定日志格式字符串,即指定日志输出时所包含的字段信息以及它们的顺序。logging模块定义的格式字段下面会列出。
datefmt 指定日期/时间格式。需要注意的是,该选项要在format中包含时间字段%(asctime)s时才有效
level 指定日志器的日志级别
stream 指定日志输出目标stream,如sys.stdout、sys.stderr以及网络stream。需要说明的是,stream和filename不能同时提供,否则会引发 ValueError异常
style Python 3.2中新添加的配置项。指定format格式字符串的风格,可取值为'%'、'{'和'$',默认为'%'
handlers Python 3.3中新添加的配置项。该选项如果被指定,它应该是一个创建了多个Handler的可迭代对象,这些handler将会被添加到root logger。需要说明的是:filename、stream和handlers这三个配置项只能有一个存在,不能同时出现2个或3个,否则会引发ValueError异常。

  1. logging模块定义的格式字符串字段
    我们来列举一下logging模块中定义好的可以用于format格式字符串中字段有哪些:

字段/属性名称 使用格式 描述
asctime %(asctime)s 日志事件发生的时间--人类可读时间,如:2003-07-08 16:49:45,896
created %(created)f 日志事件发生的时间--时间戳,就是当时调用time.time()函数返回的值
relativeCreated %(relativeCreated)d 日志事件发生的时间相对于logging模块加载时间的相对毫秒数(目前还不知道干嘛用的)
msecs %(msecs)d 日志事件发生事件的毫秒部分
levelname %(levelname)s 该日志记录的文字形式的日志级别('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL')
levelno %(levelno)s 该日志记录的数字形式的日志级别(10, 20, 30, 40, 50)
name %(name)s 所使用的日志器名称,默认是'root',因为默认使用的是 rootLogger
message %(message)s 日志记录的文本内容,通过 msg % args计算得到的
pathname %(pathname)s 调用日志记录函数的源码文件的全路径
filename %(filename)s pathname的文件名部分,包含文件后缀
module %(module)s filename的名称部分,不包含后缀
lineno %(lineno)d 调用日志记录函数的源代码所在的行号
funcName %(funcName)s 调用日志记录函数的函数名
process %(process)d 进程ID
processName %(processName)s 进程名称,Python 3.1新增
thread %(thread)d 线程ID
threadName %(thread)s 线程名称
5.经过配置的日志输出
先简单配置下日志器的日志级别
logging.basicConfig(level=logging.DEBUG)

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This is a warning log.")
logging.error("This is a error log.")
logging.critical("This is a critical log.")
输出结果:

DEBUG:root:This is a debug log.
INFO:root:This is a info log.
WARNING:root:This is a warning log.
ERROR:root:This is a error log.
CRITICAL:root:This is a critical log.
所有等级的日志信息都被输出了,说明配置生效了。

在配置日志器日志级别的基础上,在配置下日志输出目标文件和日志格式
LOG_FORMAT = "%(asctime)s - %(levelname)s - %(message)s"
logging.basicConfig(filename='my.log', level=logging.DEBUG, format=LOG_FORMAT)

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This is a warning log.")
logging.error("This is a error log.")
logging.critical("This is a critical log.")
此时会发现控制台中已经没有输出日志内容了,但是在python代码文件的相同目录下会生成一个名为'my.log'的日志文件,该文件中的内容为:

2017-05-08 14:29:53,783 - DEBUG - This is a debug log.
2017-05-08 14:29:53,784 - INFO - This is a info log.
2017-05-08 14:29:53,784 - WARNING - This is a warning log.
2017-05-08 14:29:53,784 - ERROR - This is a error log.
2017-05-08 14:29:53,784 - CRITICAL - This is a critical log.
在上面的基础上,我们再来设置下日期/时间格式
LOG_FORMAT = "%(asctime)s - %(levelname)s - %(message)s"
DATE_FORMAT = "%m/%d/%Y %H:%M:%S %p"

logging.basicConfig(filename='my.log', level=logging.DEBUG, format=LOG_FORMAT, datefmt=DATE_FORMAT)

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This is a warning log.")
logging.error("This is a error log.")
logging.critical("This is a critical log.")
此时会在my.log日志文件中看到如下输出内容:

05/08/2017 14:29:04 PM - DEBUG - This is a debug log.
05/08/2017 14:29:04 PM - INFO - This is a info log.
05/08/2017 14:29:04 PM - WARNING - This is a warning log.
05/08/2017 14:29:04 PM - ERROR - This is a error log.
05/08/2017 14:29:04 PM - CRITICAL - This is a critical log.
掌握了上面的内容之后,已经能够满足我们平时开发中需要的日志记录功能。

  1. 其他说明
    几个要说明的内容:

logging.basicConfig()函数是一个一次性的简单配置工具使,也就是说只有在第一次调用该函数时会起作用,后续再次调用该函数时完全不会产生任何操作的,多次调用的设置并不是累加操作。
日志器(Logger)是有层级关系的,上面调用的logging模块级别的函数所使用的日志器是RootLogger类的实例,其名称为'root',它是处于日志器层级关系最顶层的日志器,且该实例是以单例模式存在的。
如果要记录的日志中包含变量数据,可使用一个格式字符串作为这个事件的描述消息(logging.debug、logging.info等函数的第一个参数),然后将变量数据作为第二个参数*args的值进行传递,如:logging.warning('%s is %d years old.', 'Tom', 10),输出内容为WARNING:root:Tom is 10 years old.
logging.debug(), logging.info()等方法的定义中,除了msg和args参数外,还有一个**kwargs参数。它们支持3个关键字参数: exc_info, stack_info, extra,下面对这几个关键字参数作个说明。
关于exc_info, stack_info, extra关键词参数的说明:
exc_info: 其值为布尔值,如果该参数的值设置为True,则会将异常异常信息添加到日志消息中。如果没有异常信息则添加None到日志信息中。
stack_info: 其值也为布尔值,默认值为False。如果该参数的值设置为True,栈信息将会被添加到日志信息中。
extra: 这是一个字典(dict)参数,它可以用来自定义消息格式中所包含的字段,但是它的key不能与logging模块定义的字段冲突。
一个例子:
在日志消息中添加exc_info和stack_info信息,并添加两个自定义的字端 ip和user

LOG_FORMAT = "%(asctime)s - %(levelname)s - %(user)s[%(ip)s] - %(message)s"
DATE_FORMAT = "%m/%d/%Y %H:%M:%S %p"

logging.basicConfig(format=LOG_FORMAT, datefmt=DATE_FORMAT)
logging.warning("Some one delete the log file.", exc_info=True, stack_info=True, extra={'user': 'Tom', 'ip':'47.98.53.222'})
输出结果:

05/08/2017 16:35:00 PM - WARNING - Tom[47.98.53.222] - Some one delete the log file.
NoneType
Stack (most recent call last):
File "C:/Users/wader/PycharmProjects/LearnPython/day06/log.py", line 45, in <module>

logging.warning("Some one delete the log file.", exc_info=True, stack_info=True, extra={'user': 'Tom', 'ip':'47.98.53.222'})

四、logging模块日志流处理流程
在介绍logging模块的高级用法之前,很有必要对logging模块所包含的重要组件以及其工作流程做个全面、简要的介绍,这有助于我们更好的理解我们所写的代码(将会触发什么样的操作)。

  1. logging日志模块四大组件
    在介绍logging模块的日志流处理流程之前,我们先来介绍下logging模块的四大组件:

组件名称 对应类名 功能描述
日志器 Logger 提供了应用程序可一直使用的接口
处理器 Handler 将logger创建的日志记录发送到合适的目的输出
过滤器 Filter 提供了更细粒度的控制工具来决定输出哪条日志记录,丢弃哪条日志记录
格式器 Formatter 决定日志记录的最终输出格式
logging模块就是通过这些组件来完成日志处理的,上面所使用的logging模块级别的函数也是通过这些组件对应的类来实现的。

这些组件之间的关系描述:
日志器(logger)需要通过处理器(handler)将日志信息输出到目标位置,如:文件、sys.stdout、网络等;
不同的处理器(handler)可以将日志输出到不同的位置;
日志器(logger)可以设置多个处理器(handler)将同一条日志记录输出到不同的位置;
每个处理器(handler)都可以设置自己的过滤器(filter)实现日志过滤,从而只保留感兴趣的日志;
每个处理器(handler)都可以设置自己的格式器(formatter)实现同一条日志以不同的格式输出到不同的地方。
简单点说就是:日志器(logger)是入口,真正干活儿的是处理器(handler),处理器(handler)还可以通过过滤器(filter)和格式器(formatter)对要输出的日志内容做过滤和格式化等处理操作。

  1. logging日志模块相关类及其常用方法介绍
    下面介绍下与logging四大组件相关的类:Logger, Handler, Filter, Formatter。

Logger类
Logger对象有3个任务要做:

1)向应用程序代码暴露几个方法,使应用程序可以在运行时记录日志消息;
2)基于日志严重等级(默认的过滤设施)或filter对象来决定要对哪些日志进行后续处理;
3)将日志消息传送给所有感兴趣的日志handlers。
Logger对象最常用的方法分为两类:配置方法 和 消息发送方法

最常用的配置方法如下:

方法 描述
Logger.setLevel() 设置日志器将会处理的日志消息的最低严重级别
Logger.addHandler() 和 Logger.removeHandler() 为该logger对象添加 和 移除一个handler对象
Logger.addFilter() 和 Logger.removeFilter() 为该logger对象添加 和 移除一个filter对象
关于Logger.setLevel()方法的说明:

内建等级中,级别最低的是DEBUG,级别最高的是CRITICAL。例如setLevel(logging.INFO),此时函数参数为INFO,那么该logger将只会处理INFO、WARNING、ERROR和CRITICAL级别的日志,而DEBUG级别的消息将会被忽略/丢弃。

logger对象配置完成后,可以使用下面的方法来创建日志记录:

方法 描述
Logger.debug(), Logger.info(), Logger.warning(), Logger.error(), Logger.critical() 创建一个与它们的方法名对应等级的日志记录
Logger.exception() 创建一个类似于Logger.error()的日志消息
Logger.log() 需要获取一个明确的日志level参数来创建一个日志记录
说明:

Logger.exception()与Logger.error()的区别在于:Logger.exception()将会输出堆栈追踪信息,另外通常只是在一个exception handler中调用该方法。
Logger.log()与Logger.debug()、Logger.info()等方法相比,虽然需要多传一个level参数,显得不是那么方便,但是当需要记录自定义level的日志时还是需要该方法来完成。
那么,怎样得到一个Logger对象呢?一种方式是通过Logger类的实例化方法创建一个Logger类的实例,但是我们通常都是用第二种方式--logging.getLogger()方法。

logging.getLogger()方法有一个可选参数name,该参数表示将要返回的日志器的名称标识,如果不提供该参数,则其值为'root'。若以相同的name参数值多次调用getLogger()方法,将会返回指向同一个logger对象的引用。

关于logger的层级结构与有效等级的说明:

logger的名称是一个以'.'分割的层级结构,每个'.'后面的logger都是'.'前面的logger的children,例如,有一个名称为 foo 的logger,其它名称分别为 foo.bar, foo.bar.baz 和 foo.bam都是 foo 的后代。
logger有一个"有效等级(effective level)"的概念。如果一个logger上没有被明确设置一个level,那么该logger就是使用它parent的level;如果它的parent也没有明确设置level则继续向上查找parent的parent的有效level,依次类推,直到找到个一个明确设置了level的祖先为止。需要说明的是,root logger总是会有一个明确的level设置(默认为 WARNING)。当决定是否去处理一个已发生的事件时,logger的有效等级将会被用来决定是否将该事件传递给该logger的handlers进行处理。
child loggers在完成对日志消息的处理后,默认会将日志消息传递给与它们的祖先loggers相关的handlers。因此,我们不必为一个应用程序中所使用的所有loggers定义和配置handlers,只需要为一个顶层的logger配置handlers,然后按照需要创建child loggers就可足够了。我们也可以通过将一个logger的propagate属性设置为False来关闭这种传递机制。
Handler类
Handler对象的作用是(基于日志消息的level)将消息分发到handler指定的位置(文件、网络、邮件等)。Logger对象可以通过addHandler()方法为自己添加0个或者更多个handler对象。比如,一个应用程序可能想要实现以下几个日志需求:

1)把所有日志都发送到一个日志文件中;
2)把所有严重级别大于等于error的日志发送到stdout(标准输出);
3)把所有严重级别为critical的日志发送到一个email邮件地址。
这种场景就需要3个不同的handlers,每个handler复杂发送一个特定严重级别的日志到一个特定的位置。
一个handler中只有非常少数的方法是需要应用开发人员去关心的。对于使用内建handler对象的应用开发人员来说,似乎唯一相关的handler方法就是下面这几个配置方法:

方法 描述
Handler.setLevel() 设置handler将会处理的日志消息的最低严重级别
Handler.setFormatter() 为handler设置一个格式器对象
Handler.addFilter() 和 Handler.removeFilter() 为handler添加 和 删除一个过滤器对象
需要说明的是,应用程序代码不应该直接实例化和使用Handler实例。因为Handler是一个基类,它只定义了素有handlers都应该有的接口,同时提供了一些子类可以直接使用或覆盖的默认行为。下面是一些常用的Handler:

Handler 描述
logging.StreamHandler 将日志消息发送到输出到Stream,如std.out, std.err或任何file-like对象。
logging.FileHandler 将日志消息发送到磁盘文件,默认情况下文件大小会无限增长
logging.handlers.RotatingFileHandler 将日志消息发送到磁盘文件,并支持日志文件按大小切割
logging.hanlders.TimedRotatingFileHandler 将日志消息发送到磁盘文件,并支持日志文件按时间切割
logging.handlers.HTTPHandler 将日志消息以GET或POST的方式发送给一个HTTP服务器
logging.handlers.SMTPHandler 将日志消息发送给一个指定的email地址
logging.NullHandler 该Handler实例会忽略error messages,通常被想使用logging的library开发者使用来避免'No handlers could be found for logger XXX'信息的出现。
Formater类
Formater对象用于配置日志信息的最终顺序、结构和内容。与logging.Handler基类不同的是,应用代码可以直接实例化Formatter类。另外,如果你的应用程序需要一些特殊的处理行为,也可以实现一个Formatter的子类来完成。

Formatter类的构造方法定义如下:

logging.Formatter.__init__(fmt=None, datefmt=None, style='%')
可见,该构造方法接收3个可选参数:

fmt:指定消息格式化字符串,如果不指定该参数则默认使用message的原始值
datefmt:指定日期格式字符串,如果不指定该参数则默认使用"%Y-%m-%d %H:%M:%S"
style:Python 3.2新增的参数,可取值为 '%', '{'和 '$',如果不指定该参数则默认使用'%'
Filter类
Filter可以被Handler和Logger用来做比level更细粒度的、更复杂的过滤功能。Filter是一个过滤器基类,它只允许某个logger层级下的日志事件通过过滤。该类定义如下:

class logging.Filter(name='')

filter(record)

比如,一个filter实例化时传递的name参数值为'A.B',那么该filter实例将只允许名称为类似如下规则的loggers产生的日志记录通过过滤:'A.B','A.B,C','A.B.C.D','A.B.D',而名称为'A.BB', 'B.A.B'的loggers产生的日志则会被过滤掉。如果name的值为空字符串,则允许所有的日志事件通过过滤。

filter方法用于具体控制传递的record记录是否能通过过滤,如果该方法返回值为0表示不能通过过滤,返回值为非0表示可以通过过滤。

说明:

如果有需要,也可以在filter(record)方法内部改变该record,比如添加、删除或修改一些属性。
我们还可以通过filter做一些统计工作,比如可以计算下被一个特殊的logger或handler所处理的record数量等。

  1. logging日志流处理流程
    下面这个图描述了日志流的处理流程:

1063221-20170511145312144-488305597.png

我们来描述下上面这个图的日志流处理流程:

1)(在用户代码中进行)日志记录函数调用,如:logger.info(...),logger.debug(...)等;
2)判断要记录的日志级别是否满足日志器设置的级别要求(要记录的日志级别要大于或等于日志器设置的级别才算满足要求),如果不满足则该日志记录会被丢弃并终止后续的操作,如果满足则继续下一步操作;
3)根据日志记录函数调用时掺入的参数,创建一个日志记录(LogRecord类)对象;
4)判断日志记录器上设置的过滤器是否拒绝这条日志记录,如果日志记录器上的某个过滤器拒绝,则该日志记录会被丢弃并终止后续的操作,如果日志记录器上设置的过滤器不拒绝这条日志记录或者日志记录器上没有设置过滤器则继续下一步操作--将日志记录分别交给该日志器上添加的各个处理器;
5)判断要记录的日志级别是否满足处理器设置的级别要求(要记录的日志级别要大于或等于该处理器设置的日志级别才算满足要求),如果不满足记录将会被该处理器丢弃并终止后续的操作,如果满足则继续下一步操作;
6)判断该处理器上设置的过滤器是否拒绝这条日志记录,如果该处理器上的某个过滤器拒绝,则该日志记录会被当前处理器丢弃并终止后续的操作,如果当前处理器上设置的过滤器不拒绝这条日志记录或当前处理器上没有设置过滤器测继续下一步操作;
7)如果能到这一步,说明这条日志记录经过了层层关卡允许被输出了,此时当前处理器会根据自身被设置的格式器(如果没有设置则使用默认格式)将这条日志记录进行格式化,最后将格式化后的结果输出到指定位置(文件、网络、类文件的Stream等);
8)如果日志器被设置了多个处理器的话,上面的第5-8步会执行多次;
9)这里才是完整流程的最后一步:判断该日志器输出的日志消息是否需要传递给上一级logger(之前提到过,日志器是有层级关系的)的处理器,如果propagate属性值为1则表示日志消息将会被输出到处理器指定的位置,同时还会被传递给parent日志器的handlers进行处理直到当前日志器的propagate属性为0停止,如果propagate值为0则表示不向parent日志器的handlers传递该消息,到此结束。
可见,一条日志信息要想被最终输出需要依次经过以下几次过滤:

日志器等级过滤;
日志器的过滤器过滤;
日志器的处理器等级过滤;
日志器的处理器的过滤器过滤;
需要说明的是: 关于上面第9个步骤,如果propagate值为1,那么日志消息会直接传递交给上一级logger的handlers进行处理,此时上一级logger的日志等级并不会对该日志消息进行等级过滤。

五、使用logging四大组件记录日志
现在,我们对logging模块的重要组件及整个日志流处理流程都应该有了一个比较全面的了解,下面我们来看一个例子。

  1. 需求
    现在有以下几个日志记录的需求:

1)要求将所有级别的所有日志都写入磁盘文件中
2)all.log文件中记录所有的日志信息,日志格式为:日期和时间 - 日志级别 - 日志信息
3)error.log文件中单独记录error及以上级别的日志信息,日志格式为:日期和时间 - 日志级别 - 文件名[:行号] - 日志信息
4)要求all.log在每天凌晨进行日志切割

  1. 分析
    1)要记录所有级别的日志,因此日志器的有效level需要设置为最低级别--DEBUG;

2)日志需要被发送到两个不同的目的地,因此需要为日志器设置两个handler;另外,两个目的地都是磁盘文件,因此这两个handler都是与FileHandler相关的;
3)all.log要求按照时间进行日志切割,因此他需要用logging.handlers.TimedRotatingFileHandler; 而error.log没有要求日志切割,因此可以使用FileHandler;
4)两个日志文件的格式不同,因此需要对这两个handler分别设置格式器;

  1. 代码实现
  2. logging

import logging.handlers
import datetime

logger = logging.getLogger('mylogger')
logger.setLevel(logging.DEBUG)

rf_handler = logging.handlers.TimedRotatingFileHandler('all.log', when='midnight', interval=1, backupCount=7, atTime=datetime.time(0, 0, 0, 0))
rf_handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(message)s"))

f_handler = logging.FileHandler('error.log')
f_handler.setLevel(logging.ERROR)
f_handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(filename)s[:%(lineno)d] - %(message)s"))

logger.addHandler(rf_handler)
logger.addHandler(f_handler)

logger.debug('debug message')
logger.info('info message')
logger.warning('warning message')
logger.error('error message')
logger.critical('critical message')
all.log文件输出

2017-05-13 16:12:40,612 - DEBUG - debug message
2017-05-13 16:12:40,612 - INFO - info message
2017-05-13 16:12:40,612 - WARNING - warning message
2017-05-13 16:12:40,612 - ERROR - error message
2017-05-13 16:12:40,613 - CRITICAL - critical message
error.log文件输出

2017-05-13 16:12:40,612 - ERROR - log.py[:81] - error message
2017-05-13 16:12:40,613 - CRITICAL - log.py[:82] - critical message
六、配置logging的几种方式
作为开发者,我们可以通过以下3中方式来配置logging:

1)使用Python代码显式的创建loggers, handlers和formatters并分别调用它们的配置函数;
2)创建一个日志配置文件,然后使用fileConfig()函数来读取该文件的内容;
3)创建一个包含配置信息的dict,然后把它传递个dictConfig()函数;
具体说明请参考另一篇博文《python之配置日志的几种方式》

七、向日志输出中添加上下文信息
除了传递给日志记录函数的参数外,有时候我们还想在日志输出中包含一些额外的上下文信息。比如,在一个网络应用中,可能希望在日志中记录客户端的特定信息,如:远程客户端的IP地址和用户名。这里我们来介绍以下几种实现方式:

通过向日志记录函数传递一个extra参数引入上下文信息
使用LoggerAdapters引入上下文信息
使用Filters引入上下文信息