python

折腾 Python logging 的一些记录

Python 自己有成熟的日志模块 logging,使用中遇到一些原生组件无法满足的功能,或有一些使用方式上的坑,记录一下

0. 复习一下 logging 的实现

Python 官网对 logger flow 的定义如下图(来源 https://docs.python.org/3/howto/logging.html

Python logging flow

源码在 python 自己的 lib/logging/ 下,主要内容都在 __init__.py 里,先注意下几个定义

  • Logger,可以挂载若干个 Handler,可以挂载若干个 Filter,定义要响应的命名空间,和日志级别 (1)
  • Handler,可以挂载一个 Formatter,可以挂载若干个 Filter,定义了要响应日志级别 (2),和输出方式(流、文件等)
  • Filter,过滤器(其实也可以在里面搞更多事情)
  • Formatter,最终日志的格式化字符串
  • LogRecord,单条日志的结构体,所有信息都会存在这里

然后对着流程图来说,主流程如下

  1. 日志打印请求到 Logger 后,先判当前 Logger 是否要处理这个级别,不处理的直接扔掉(级别控制 1)
  2. 生成一条 LogRecord,会把包括调用来源等信息都一起打包好,传给 Logger 挂载的 Filter 挨个过滤
  3. 如果有 Filter 返回是 False,则丢弃这条日志
  4. 否则传给 Logger 挂载的 Handler 挨个处理(右上角子图)
  5. 如果开启了日志往上传递(propagate,不知道怎么翻译更精准),则判断当前 Logger 是否有父 Logger,如果有的话,直接将当前 LogRecord 传给父 Logger 从 4 开始处理(跳过 1/2/3,注意此处级别控制 1 会不生效,绑定在父 Logger 上的 Filter 也不执行)

右上角的子图是 Handler 内部的流程

  1. 判当前 Handler 是否要处理这个级别,不处理的直接扔掉(级别控制 2)
  2. 把收到的 LogRecord 交给挂载的 Filter 挨个过滤
  3. 如果 Filter 没有阻止,按挂载的 Formatter 格式化输出

这里面有一些比较好玩的地方

0.1 LogRecord 的生成

在生成之前其实 Logger 先干了两件事,一是找到原始的调用源(文件名 filename,方法名 funcName,行号 lineno),二是根据参数决定是否需要获取运行信息 exc_info

找原始调用源就是在 Python 的调用栈里一层一层往上找,直到找到调用文件不是当前文件(**/lib/logging/__init__.py)退出。印象中 C/C++ 的日志是直接编译时把当前的 __line__ 什么的展开得到,在 Python 里这么做应该还是因为 Python 是解析性语言。另外可能要注意的是这里的 filename 其实是文件绝对路径,传到 LogRecord 里后会变成 pathname,再分割得到文件名 filename 和模块名 module(这个就是 filename 去掉后缀)

生成好 LogRecord 后还会把传入的 extra 字典也挂上去,这里会限制 extra 里的字段不能和 LogRecord 原生字段冲突,否则会直接报错

0.2 不要被名字骗了的 Filter

从名字上看,Filter 应该就是一个过滤器,对输入的 LogRecord 做判断,返回 True/False 来决定挂载的 LoggerHandler 是否要处理当前日志,但是,这个东西不仅可以读 LogRecord,还可以改写,这里就有很多好玩的事情发生了(后面的很多事情都是在这里做的),而且只要被 Filter 改过的 LogRecord,都还会继续往后传递给其他的 Filter/Handler/Logger

0.3 没有被提到过的 adapter

在 Python 官方的 logging Cookbook 里,提到加上下文信息已开始推荐的是用 logging.LoggerAdapter 来做,这个东西其实是对 Logger 多了层封装,多包了一个 extra 字典进去,并且接管了 Loggerprocess 方法,实际用起来这个东西并不好用,所以在前面定义部分没说这个,官方的图也没提这块

0.4 为什么 log 还是要用 % 来格式化

Python 新一点的版本都支持 {} 格式化字符串,到 Python3.6 里更是有 literal template 这种不要太方便的字符串输出,那为什么 log 里还是坚持要用 % 加 args 的方式来处理呢?而且 pylint 等也都会对其他格式化方法报警告

没有太细究,大概想了下可能是因为这一整套 Logger 机制其实不仅仅是 Python 在用,其他语言也有在用,那么保持一致性是一个原因。另外还有查到说法是如果这条日志的等级不需要被处理,或者 Filter 直接就拦掉了,那么就不会走到 Formatter 那一步,可以减少格式化开销,不过这个原因也有站不住脚的地方,如果某条日志确定要被多个 Handler 处理,在用户端格式化就只用做一次,在 Formatter 里格式化就每个 Handler 都要重复做一次了

1. 对 logging 增加功能

1.1 增加相对路径

原生 LogRecord 里只有 filename (文件名)和 pathname (绝对路径),然而 filename 太短,我们可能在不同的目录下都有同名文件,而绝对路径又太长,把一堆有的没的都带上来,所以我们想打印出相对于项目的相对路径

一开始用了各种人肉魔改,包括接管整个 Logger 来自己做,后来发现可以简单加一个 logging.Filter 来解决。前面提到过 Filter 不仅可以过滤决定是否要输出日志,还可以改传入的 LogRecord,这样就很简单了,在我们的 Filter 里,记录下项目的根路径(这个很容易通过当前文件的 __file__ 往上指定层推出来),然后在 LogRecord 添加一个 relpath 的属性,取 LogRecord.pathname 截断掉前面非项目的部分就行了

1.2 自定义的 Filter 进配置

有了自定义 Filter 后,还需要能挂载到对应的 HandlerLogger

这里略坑的是 logging.config.fileConfig 这样的文件配置并不支持自定义 Filter,只能用 dictConfig。那么配置要么写 Python 变成原生 dict,要么用 json 写,在初始化配置的地方 json.load 读进来变成 dict。从「配置文件归配置文件」的角度说,用 json 会更合适,如果考虑到不同的环境用不同配置,用基类加继承微调的方式,可能写 Python 原生字典会更方便

1.3 保证 Formatter 匹配 Filter

增加的 relpath 可以直接在 Formatter 里用 %(relpath)s 的方式输出,但是这里也得保证,有 relpathFormatter 拿到的一定是被处理过的 LogRecord,不然就崩了

考虑到 Formatter 是一一绑定在 Handler 上的,所以我个人认为比较好的方法是在 Handler 里配置 Filter,保证如果用了自定义字段的 Formatter,一定要加上对应的 Filter,就算这个 Filter 在多个 Handler 上被多次执行,最多增加点性能开销,并不会对结果产生改变

1.4 打印 Flask 请求 ID

对于 Flask 应用,我们希望对一次请求所打的日志能有一个统一的 request_id 把所有日志串起来,方便追查。那么在 Web 请求的 app.before_request 里先加了个 g.request_id,把 request.path 拼上一个随机串记到上下文 g 里,然后在 logging.Filter 里判断是否有 app 上下文,有的话去取这个字段,并追加到 LogRecord 里,后面在 Formatter 里直接写 %(request_id)s 就可以输出了

5. 打印 celery task id

同上,对于异步任务,celery task 自己就有个 request.id 字段,直接判断是否存在上下文,摸出来挂到 LogRecord 上就行了

2. 增加易用性

2.1 log_decorator

很多时候我们希望知道一个方法的入参和返回值,如果在每个需要处理的方法前后都人肉写,未免太不 Pythonic,很自然就想到对方法调用加上装饰器,自动打调用参数和返回结果

对于怎么写装饰器,怎么摸被修饰方法的参数名和值等,之前写的几篇关于 Python 装饰器的 blog 已经写的很详细了,此处不重复

唯一需要注意的是如果不做特殊处理,打印的日志里,文件名、行号、方法都是 log_decorator 里打日志的那行,而不是原始方法。所以在这里需要先摸到原始方法的文件路径、方法名、行号,写到 log 的参数 extra 里用于构建 LogRecord,这里还特别注意因为 MakeRecord 的时候限制了不允许覆盖 LogRecord 已有的字段,所以这里必须改个名字,等到 Filter 里再去尝试看有没有自己加的字段,如果有则替换已有的

我们在实际工程中还对这里做了一些优化,支持传入方法来对入参和返回做处理后输出,特别是对复杂结构很有必要,另外对过长的 tuple/list/set/dict 也做了截断处理

2.2 before_request / after_request

有了 log_decorator 可以对方法的入参和返回很容易记录,那么对于 Web 请求,应该也可以更容易的做调用参数和返回值的记录。对于 Flask 应用,可以在 appblueprint 上往 before_requestafter_request 里增加打日志的方法来记录入参和返回

此处暂时没有很好解决的是文件路径、方法名和行号还是记录的打日志这个方法里调 log 语句时的数据,并不是最终处理 route 的方法,暂时还没去研究是否有办法可以实现,有 request.path 可以根据路由表去查,其实也还好

2.3 sentryHandler

对于用了 sentry 的项目,除了抛异常,某些时候也希望有一些错误信息能被记录到 sentry 上。最土的方法就是生成一个 raven_client 实例,然后 captureMessagecaptureException

其实 sentry 有提供 sentryHandler,就是一个 logging.Handler,直接配到 logging 的配置里,挂载到 rootLogger 上,初始化的时候就可以自动挂载上去,后面要用的时候直接 logger.error 打日志就是(什么?你需要只打 sentry 不打 log?你都打 sentry 了这么大的事情都不打条日志?也不是不可以,单独配个 logger 只挂 sentryHandler 就是,但还是不建议这么做)

如果需要打调用信息,在 log 时加上参数 exc_info=True,需要打堆栈就加 extra={"stack": True},比自己人肉搞不知道高到哪里去了

更详细的请见官方文档:https://docs.sentry.io/clients/python/integrations/logging/

3. 关于 Sentry 的补充

3.1 flask to sentry

在 Flask 应用里用 Sentry 可以参考官方文档 https://docs.sentry.io/clients/python/integrations/flask/ ,从 raven.contrib.flask 里 import 一个 Sentry 过来就行,实例化后在 init_app 的时候指定上对应的 sentry_dsn,这样就可以用这个 sentry 实例来 captureMessagecaptureException

其实这里配置好了更大的意义是在 Flask 应用抛了没有人接的异常时能往 sentry 打异常报告,这个地方一开始我配置好 sentryHandlerlogging.rootLogger 后得意忘形的把初始化 Sentry 给去掉了,然后就捕获不到异常了,弄明白怎么回事后老老实实加回来,最后异常捕获走 raven.contrib.flask.Sentry,日志走 rootLogger.sentryHandler,各行其是

这里还发现了个特别浪的操作,既然我们在 logging.rootLogger 上已经配好了 sentry_dsn,那是不是就有现成的 raven_client 可以用呢?实际上是可以的… 参考下方代码,初始化的时候直接写 Sentry(app, client) 就行,里面会自动完成 init_app 的操作的

def getRavenClient():
    _logger = logging.getLogger()
    for handler in _logger.handlers:
        if isinstance(handler, SentryHandler) and handler.client.is_enabled():
            return handler.client
    return None

3.2 celery to sentry

同样,对于 celery 异步任务,也可以参考官方文档 https://docs.sentry.io/clients/python/integrations/celery/ 来配置往 Sentry 打日志或捕获异常,因为我们已经在 logging.rootLogger 上配过 sentryHandler,所以官方文档里的 register_logger_signal 可以忽略,只要从 ravan.contrib.celery 里 import 这个 register_signal 方法并初始化就行,初始化 client 一样可以参考上面从 rootLogger 里去摸

Python decorator 库和 gevent 冲突的情况

去年写了两篇分析 decorator 的 blog:

在线上项目里一直也没有用 pypi 的 decorator 库去替换自己的实现,最近替换后撞上了一些问题,整个问题追查过程也各种艰辛,记录一下

我们线上用的 flask 0.11.1 + celery 3.1.25 + gevent 1.2.2 在跑任务队列,broken 用的阿里云 redis 2.8,某个周末突然发现 worker 工作不正常,有大量的 db 连接报错,在简短排查后没找到原因,重启整个服务,暂时跳过这个问题,其实后面还在有其他错误,但也没有解决思路

等周一到公司,团队的人对比了下问题现场和思路,只能发现是 celery worker 会莫名卡死,跑到我们的 k8s 集群上看,对应的 pod 是 running,但是 flower 上看监控是 offline,直接切进 pod 看日志,好几个最后都断在 requests 发请求出去的地方,N 脸懵逼,我们又没升级系统又没动依赖,怎么就会冒出来这个问题

既然最后死在 requests 那,虽然看后面的 Changelog 没发现有跟我们直接习惯的,但还是先把 requests 版本从 2.19.0 升到 2.21.0,并把依赖的库也同步升级。然而并没有解决问题,还是一样的死,还是一样的错

后面多看了几个问题现场,只能协助定位还可能会卡死在 db 读写的地方,这个时候开始怀疑 gevent,因为这货帮忙做了 IO 异步优化,强行协程化,而且这个版本也有点老,期间看也有一些可能相关的 Issue,升级 1.4.0 后发现服务起不来,查了下看需要把 celery 升级到 4.x,但 4.x 的 celery 参数序列化从 pickle 改成 json,还要改挺多代码的,只能先搁置

后面还查了下 celery 的版本问题,我们用的 3.x 是有点老了,但 4.x 那个参数结构该动那个有大所以一直没动,另外也查用 redis 做 broken 的锅,没有任何有效的相关信息

出问题前我在代码里替换了一版 lock 的实现,以及 lock_decorator 的实现,但是往这边怀疑也不对,因为有的出错的地方并没有用到锁,而且看日志和报错也跟锁没有关系

等过了一周,第二个周末的时候开脑洞说好像现在有问题的方法都有修饰器包着,而且这些修饰器都用了 decorator 库,也许这里可能有问题?我们的 decorator 用的是 4.3.0,最新的版本是 4.3.2,大致看了下 Changelog,似乎提到有修复协程问题,但是是 python 3.5 的,不过反正不用改代码,先升了再说

升完后问题真的消失了,那么就来看看到底哪里可能有问题吧。对比期间的变更记录 https://github.com/micheles/decorator/compare/4.3.0…4.3.2,除了一些文档变化和对 py3.5 的协程修复,比较值得怀疑的是 https://github.com/micheles/decorator/commit/eb890d98739196b83f1ecb5cb7bcfe9739a9502c 这个提交,decorator 的原理是在内存里新建一个虚拟文件,把要修饰的方法的相关属性写到这个虚拟文件里,然后通过虚拟文件里的同名方法调装饰器逻辑,装饰器方法里再去调到最终的方法,而这个虚拟文件如果只用 itertools.count(),在 gevent 的协程调度下可能会重名,然后整个代码体系就崩了

Python decorator 库

上个月关于 Python 的 Decorator 写过一篇 Python 多层 decorator 内获取原始函数参数字典,后来熊提醒这种比较通用的东西应该都会有现成的库,搜了下果然有 个库就叫 Decorator

相关的项目地址在

看了下源码,他比之前我的做法更进一步,直接把要修饰的原方法的名字和参数,都扫代码解析出来,再到一个解析器的临时文件里原样写一个新的方法,并把相关需要复制的参数属性等都直接复制给这个新方法,这个新方法再调修饰方法,就可以更完美的实现对外界透明

例如这样的代码

def foo(x, y=2, *args, **kw):
  print(x)

def dec(func):
  def wrapper(*args, **kw):
    print("called %s with %s, %s" % (func.__name__, args, kw))
    return func(*args, **kw)
  return wrapper

foo = dec(foo)

在经过了 @decorator 后会变成

_func = foo
_caller = wrapper

foo = def foo(x, y=2, *args, **kw):
  return _caller(_func)(x, y, *args, **kw)

只有一些涉及到 func_code 内存地址的地方才可以发现不一样

果然还是有库用库,绝大部分情况人家还是实现得更好,就是原理能不能看懂了。自己折腾的好处是正向推过去,坑和原理都比较了解,而反向看别人的代码,有很多奇妙的地方先想明白为什么要考虑这个情况,以及这个情况为什么要这样处理,都需要花很久

最后小吐槽一下,在 decorator 库里,如果是 py3,replace('return', 'return await') 真的没问题?如果有人逗比写了个 returnVal = xxx 不就崩了

做了个人人网的备份工具

总感觉哪天人人可能就不运营了,趁还能抓,先把能抓的抓到本地来,那些不管是牛逼还是傻逼抑或二逼的的过往,留着吧,偶尔看看也挺有意思的

项目在 GitHub 上:https://github.com/whusnoopy/renrenBackup,有问题可以在这里留言,或直接在 GitHub 上发 Issue 或 Pull Request

抓了状态、留言、相册和日志,以及对应的评论、点赞

其中点赞只有总数和最近的 8 个人的名单,受限没找到拿全量的接口,只能这样,翻状态发现 2014 年的时候就吐槽过只能看 8 个人点赞,当时还说有改版计划会看到全部,后来随着人人慢慢没落转型,应该也没人提这事了

评论看起来是人人本身就丢了一些,或者奇怪的隐私策略或怎样,总感觉漏掉一点,不过也尽力把人人按 API 给的对应评论和全站评论都保存了下来

状态应该漏掉早期的一部分,我只能抓到 2008 年左右的,更早的忘了是没有状态这个产品,还是就是数据丢了。状态有些是带图或带地理信息的,这部分都没抓,通过对于的 API 似乎也没拿到这些信息

分享的类型太杂,没有 json 接口,裸解析页面太伤了,暂时不打算做,后期如果有人一起或想起来再说

人人的图片大部分不允许跨域调,索性也爬到本地来,主要是照片和头像,然后照片的失真度比较大,有 EXIF 信息什么的也懒得爬了,毕竟这些不是重点

我的数据量应该只算一般,爬起来还没太大问题,那些量大类杂的,可能还会遇到新的坑,只能遇坑填坑

Python 多层 decorator 内获取原始函数参数字典

0. 在 decorator 里获取原始函数的参数值

项目里做了一个通用锁,使用 decorator 来方便的包住某些需要限制并发的函数。因为并发不是函数级别的,而是根据参数来限制,所以需要把参数传到通用锁的 decorator 里,代码大致如下

def lock_decorator(key=None):
    def _lock_func(func):
        @functools.wraps(func)
        def wrapper(*args, **kwargs):
            # TODO: get lock_key
            lock_key = kwargs.get(key, '')
            with LockContext(key=lock_key):
                return func(*args, **kwargs)
        return wrapper
    return _lock_func

@lock_decorator(key='uid')
def apply_recharge(uid, amount):
    # ...

考虑到函数调用不一定都是带着参数名的,就是说调用时不一定所有参数都会进 **kwargs,那就需要从 **args 里面按参数名捞参数

怎么能知道原函数的参数名列表,翻各种手册的得知可以用 inspect.getargspec(func) 来搞到,那么上面的 TODO 部分就可以改写如下

            args_name = inspect.getargspec(func)[0]
            key_index = args_name.index(key)
            if len(args) > key_index:
                lock_key = args[key_index]
            else:
                lock_key = kwargs.get(key, '')

自此,一切都很美好

1. 在 decorator 里获取原始函数的调用参数字典

项目里又做了个通用的 Logger,也做成 decorator 往目标函数一套,就可以打印出调用时的入参和结果,大致如下

def log_decorator():
    def _log_func(func):
        @functools.wraps(func)
        def wrapper(*args, **kwargs):
            # TODO: get full args
            print('call func [{}] with args [{}] and kwargs [{}]'.format(func.__name__, args, kwargs))
            ret = func(*args, **kwargs)
            print('func [{}] return [{}]'.format(func.__name__, ret))
            return ret
        return wrapper
    return _log_func

@log_decorator()
def apply_recharge(uid, amount):
    # ...

看起来也还好,不过因为函数可能带默认参数,而且也希望看到 **args 到底传到哪个参数上,还是希望把所有参数按 Key-Value 的形式打印出来,跟处理通用锁一样,用 inspect.getargspec(func) 把参数名和默认值都摸出来,再考虑一下可变参数的情况,对上面的 TODO 部分改写如下

            args_name, _, _, func_defaults = inspect.getargspec(func)
            parsed_kwargs = dict()
            # default args
            default_args = dict()
            default_start = len(args_name, func_defaults)
            for idx, d in enumerate(func_defaults):
                default_args[args_name[default_start + idx]] = d
            parsed_kwargs.update(default_args)
            # args with name
            varargs_start = len(args_name)
            for idx, a in enumerate(args[:varargs_start]):
                parsed_kwargs[args_name[idx]] = a
            # varargs
            if len(args) > varargs_start:
                parsed_kwargs['varargs'] = args[varargs_start:]
            # kwargs
            parsed_kwargs.update(kwargs)
            print('call func [{}] with args [{}]'.format(func.__name__, parsed_kwargs))

到这里,还是很美好

2. 多层 decorator 怎么拿到最原始函数的参数表

注意到上面两个例子里,apply_recharge 都只套了一个 decorator,如果两个一起用会发生什么?

根据 PEP318 里对 decorator 的定义

@dec2
@dec1
def func(arg1, arg2, ...):
    pass

等价于

def func(arg1, arg2, ...):
    pass
func = dec2(dec1(func))

这里就出问题了,dec2 拿到的传入函数其实是 dec1 而不是 func。不过在把 lock_decoratorlog_decorator 混用时,不管谁写前面,func.__name__ 都是原始的函数名,说明也还是有神器的地方做了穿透,但是 inspect.getargspec 又拿不到最底层函数的参数表,导致不管谁前谁后,都有问题

注意到每个 decorator 构建的时候都又封了一个 @functools.wraps(func),这个是干嘛的呢?以前都是无脑用,也没想过为啥要包一层这个,去掉会怎样?

去掉这个 @functools.wraps(func) 后,inspect.getargspec 还是一样的只能拿到最近一层的信息,而之前本来可以拿到底层的 func.__name__ 也变成最近一层的函数名了,说明这里做了穿透。那么去看看代码吧

# functools.py

from _functools import partial, reduce

# update_wrapper() and wraps() are tools to help write
# wrapper functions that can handle naive introspection

WRAPPER_ASSIGNMENTS = ('__module__', '__name__', '__doc__')
WRAPPER_UPDATES = ('__dict__',)
def update_wrapper(wrapper,
                   wrapped,
                   assigned = WRAPPER_ASSIGNMENTS,
                   updated = WRAPPER_UPDATES):
    """Update a wrapper function to look like the wrapped function

       wrapper is the function to be updated
       wrapped is the original function
       assigned is a tuple naming the attributes assigned directly
       from the wrapped function to the wrapper function (defaults to
       functools.WRAPPER_ASSIGNMENTS)
       updated is a tuple naming the attributes of the wrapper that
       are updated with the corresponding attribute from the wrapped
       function (defaults to functools.WRAPPER_UPDATES)
    """
    for attr in assigned:
        setattr(wrapper, attr, getattr(wrapped, attr))
    for attr in updated:
        getattr(wrapper, attr).update(getattr(wrapped, attr, {}))
    # Return the wrapper so this can be used as a decorator via partial()
    return wrapper

def wraps(wrapped,
          assigned = WRAPPER_ASSIGNMENTS,
          updated = WRAPPER_UPDATES):
    """Decorator factory to apply update_wrapper() to a wrapper function

       Returns a decorator that invokes update_wrapper() with the decorated
       function as the wrapper argument and the arguments to wraps() as the
       remaining arguments. Default arguments are as for update_wrapper().
       This is a convenience function to simplify applying partial() to
       update_wrapper().
    """
    return partial(update_wrapper, wrapped=wrapped,
                   assigned=assigned, updated=updated)

原来就是这里耍花样了,把底层函数的 ('__module__', '__name__', '__doc__') 都赋给了 decorator 封起来的这一层,欺骗更上层用 __name__ 去判断时就当我是底层

那我也学这个,把 inspect.getargspec 的地方也处理下不就完了,去看看这个地方是怎么拿参数表的

# inspect.py

def getargspec(func):
    """Get the names and default values of a function's arguments.

    A tuple of four things is returned: (args, varargs, varkw, defaults).
    'args' is a list of the argument names (it may contain nested lists).
    'varargs' and 'varkw' are the names of the * and ** arguments or None.
    'defaults' is an n-tuple of the default values of the last n arguments.
    """

    if ismethod(func):
        func = func.im_func
    if not isfunction(func):
        raise TypeError('{!r} is not a Python function'.format(func))
    args, varargs, varkw = getargs(func.func_code)
    return ArgSpec(args, varargs, varkw, func.func_defaults)

看了下用到了 func.func_codefunc.func_defaults,按 Python 官方文档 https://docs.python.org/2/library/inspect.html 的解释,func_code 是运行时的字节码,从这里面捞参数表果然可行,那是不是我把这两个属性也传递上去就行了呢?改用自己的 wraps 如下

WRAPPER_ASSIGNMENTS = functools.WRAPPER_ASSGNMENTS + ('func_code', 'func_defaults')
def my_wraps(wrapped,
             assigned = WRAPPER_ASSIGNMENTS,
             updated = WRAPPER_UPDATES):
    return _functool.partial(functools.update_wrapper, wrapped=wrapped,
                             assigned=assigned, updated=updated)

运行时报错,看了下错误提示,func_code 不可覆盖,这也对,都是运行时的字节码了,这个覆盖掉那包的这层 decorator 到底还有没有自己的逻辑部分

还是自己动手丰衣足食,既然 func_code 不可覆盖,我自己另外弄一个总可以了吧,而且当前需求是拿到参数表和默认参数,那就直接解出来穿透,也懒得最后再解一次。修改 my_wraps 如下

WRAPPER_ASSIGNMENTS = functools.WRAPPER_ASSIGNMENTS + ('__func_args_name__', '__func_default_args__')

def my_wraps(wrapped,
             assigned = WRAPPER_ASSIGNMENTS,
             updated = functools.WRAPPER_UPDATES):
    if getattr(wrapped, '__func_args_name__', None) is None:
        setattr(wrapped, '__func_args_name__', inspect.getargs(wrapped.func_code)[0])
        func_defaults = getattr(wrapped, 'func_defaults') or ()
        default_args = dict()
        default_start = len(wrapped.__func_args_name__) - len(func_defaults)
        for idx, d in enumerate(func_defaults):
            default_args[wrapped.__func_args_name__[default_start + idx]] = d
        setattr(wrapped, '__func_default_args__', default_args)
    return _functools.partial(functools.update_wrapper, wrapped=wrapped,
                              assigned=assigned, updated=updated)

同时在运行时解参数表,也用一个通用函数来实现

def parse_func(func, *args, **kwargs):
    parsed_kwargs = dict()
    # default args
    parsed_kwargs.update(func.__func_default_args__)
    # args with name
    varargs_start = len(func.__func_args_name__)
    for idx, a in enumerate(args[:varargs_start]):
        parsed_kwargs[func.__func_args_name__[idx]] = a
    # varargs
    if len(args) > varargs_start:
        parsed_kwargs['varargs'] = args[varargs_start:]
    # kwargs
    parsed_kwargs.update(kwargs)

    return parsed_kwargs

这样在 lock_decoratorlog_decorator 里,用 my_wraps 来封装处理,同时在里面用 parse_func 来解析参数,就能拿到完整的参数表了

完整的测试代码见 https://gist.github.com/whusnoopy/9081544f7eaf4e9ceeaa9eba46ff28da

wtforms 的 StringField 里设置 default 无效

在项目里使用 wtforms,设置了一个带默认值的 StringField,但提交表单如果没有这项或值是空的,则返回为空,并不会使用 default 里的值

例如定义如下表单

def ListForm(Form):
    status = StringField("status", validators=[Optional()], default="all")

提交一个空请求,返回的 status 是空而不是 all。去跟代码并看了下 GitHub 上的 issue 讨论,按 wtforms 官方的说法,这是故意设计成这样的,参考如下内容

大意是,如果用户设置了一个 Field,那么他就应该有值,不然我们就强行设置为空

但是这个逻辑狗屁不通,因为除了 StringField 其他的类型域就没这个问题,比如 IntegerField 就是可以这么用而且能返回正确的 default

def ListForm(Form):
    status = StringField("status", validators=[Optional()], default="all")
    x = IntegerField("x", validators=[Optional()], default=9)

没办法自己新增了一个 StringFieldWithDefault 的类来解决这个问题(被覆盖的代码可以看上面 GitHub Issue 里的讨论)

class StringFieldWithDefault(StringField):
    def process_formdata(self, valuelist):
        if valuelist:
            self.data = valuelist[0]
        else:
            self.data = self.object_data

而且 wtforms 的数据校验也是谜一般的逻辑,比如设置如下

def ListForm(Form):
    status = StringField("status", validators=[Optional(), AnyOf(["all", "visible"])], default="all")
    x = IntegerField("x", validators=[DataRequired()])

这里会出现两个问题

一是 Optional 如果发现没有值或空,是能通过这个校验的,这里逻辑也没错,但是特喵的 Optional 如果遇到值为空的时候,会把之前的所有错误都清空,并且停止检查后面的 validator。这个迷一般的逻辑会导致如果传的空字段,即没有按正常人预期的拿到 default,也没有去执行 AnyOf 的校验,而是直接通过了。这个官方无解,也不打算修,只说在 3.x 的时候考虑加配置参数,不过看进度上一个版本已经是 2015 年发布的 2.1,而且 GitHub 仓库并不活跃,那么只能呵呵呵呵,然后换自己的 StringFieldWithDefault 吧

二是 DataRequired 不是检查 if field.name in formdata,而是检查 if field.data,这就意味着,如果传了一个 0 的整型参数给 IntegerField,是通不过 DataRequired 的验证的,同理还有空字符串。这个可以改用 InputRequired 来解决,还算是官方给了条活路

Python 的对象模型到底是怎样的?

今天写个小工具, 中间调的欲仙欲死, 直接上图, 大家看看这个程序会输出啥? 环境是 Python 2.7.2, 某 Linux 发行版 (服务器, 我也不知道具体是啥, 可能是 CentOS)

我的理解是如果我的写法有问题, 那应该两个 print m1 的时候的结果都跟 print m2 一样, 要不两个结果应该都不一样, 所以我确认了 model_path 都正确赋值后, 就认为 model_dict 也都被正确赋值了. 但是调试的时候发现两个 model_dict 调用的结果居然一模一样, 然后带的 model_path 还不一致 (当然, 我中间做了很多别的操作, 一开始没验证两个 model_dict 里面的内容). 后面把 model_dict 的内容也打出来就傻眼了, 这俩为啥都一样呢? 就因为一个是字符串一个是 dict? 跑到万能的 PUZZLES 群去问了下, 立马有人说你这个初始化不是应该在 __init__ 里做才对么? 于是将代码改成这样就 OK 了:

后来跟 @runnery@LeeMars 讨论了下, 终于明白是怎么回事了, 先上一张 @runnery 给我的解释图

按这个理解, 我的两次操作都是在操作类属性, 最后的输出应该都是 m2.reload() 后的值. 而实际上第一份代码的里, 两个实例初始化时, model_dictmodel_path 都还是类属性, 而调用 reload() 的过程中, 我做了一个 self.model_path = path 的操作, 而正是这个操作, 让两个实例分别将 model_path 变成了实例属性, 而 model_dict, 对不起, 我从来没修改过他具体的指向, 做的 clear() 操作什么的都还是在原来的 dict 上在操作, 所以一直是类属性.

总结: 这就是一个坑, 对语言不熟的坑

杂而不精

今晚调模型调郁闷了, 发现没个顺手的工具确实不行, 于是把拖了很久, 本来指派给别人但一直没完成的 debug 工具给完成了大半.

很早写过一个 python 脚本, 在命令行下调用, 但是不方便输入和构造数据, 看起来也不是很方便, 但一直也有别的事情, 觉得这事优先级不高就一直搁着. 后来要做不同数据下的对比, 除了自己还是没人写这个, 于是把 python 脚本完善了下, 支持多输入, 多输出带对比, 还是没去写界面或数据构造. 再后来在做别的事情的时候, 顺便把这个 python 脚本也做了一次简单重构, 使其兼容线上配置, 逻辑也保持完全一致, 并将其作为一个 daemon, 用 php 写了个界面, 一堆参数可以简单的用 html 表单 (选择框, 下拉菜单什么的) 来生成, 默认值也好指定, 输出还是把原 python 输出到命令行的东西原封不动输出到网页, 但是不支持多输入. 最后就是今天实在忍不了土鳖的开两个窗口去调试对比 (顺带吐槽下其实是某从的显示器不够大, 开两个窗口并排放不开), 把那个 daemon 改的支持多输入, 并将输出做了一些简单的格式化, 还是裸文本但是看起来有条理多了, 并且把模型/数据/配置等支持在线重载, 免得换个数据就去 kill daemon 然后重启时又提示端口号还没释放.

晚上回来的时候看到汤永程在写他去参加天天向上的事, 说到语言学习, 就突然想回忆下, 自己到底一天都在用哪些语言, 好像我也会挺多, 但是都杂而不精. (前面那句话里两个语言指代不一样, 显然笨狗只会程序设计语言…) 按接触/学习的时间排序如下, 记录兼娱乐, 其中一些自己觉得好的书和资料给了链接, 希望对别人有帮助. 写完回头看, 怎么看都是一部扭曲的非主流码农成长史, 而且发现这都能当简历了 -.-|

PASCAL
– 第一个正式去学的语言, 高中玩 OI 竞赛时学的, 也仅仅用于竞赛而已
– 可以应对 03 年 NOIp 高中组级别的题, 没做过实用化工作, 竞赛中用过两年多, 现在应该忘的差不多了

C
– 大学入学前跟着去玩 ACM 开始去学, 一直到现在还在学, 大一作为必修课马马虎虎学过去了, 到大三大四时通读 C 程序设计语言 并完成所有例题和习题, 很薄的一本真的认真看完花了好久, 这本书真的非常赞, 后面就在工作中一直作为主力高级语言在用了
– 可以应对一般的 ACM 水题, 能独立完成计算机专业 C 语言大作业, 看过/实现过一些简单库函数, 结合 APUE (Unix 环境高级编程) 将其和 *nix 底层对接学习了下, 学习/实习/工作中将其混着一点点 C++ 用了几年, 参考别人的开源项目完成过一个 Online Judge 的内核, 这些年代码量加起来我猜应该够十万行了, 但是大部分还是在已有框架下写策略细节, 没做过大项目整体框架比较遗憾

C++
– 单独从 C 里列出来是想说明我真的不会 C++… 曾经在玩 ACM 的时候用过一点点 vector 什么的, 但是这种应该不叫去学 C++ 吧, 大四实习时因为工作需要时翻了下 C++ Primer Plus, 翻了几章后发现买错书了, 本来应该是买 C++ Primer 的… 刚好那段时间的实习也都在做偏策略的东西, 一直没去看工程细节, 结果就一直不会工程了
– 能看懂简单的 C++ 代码, 能将简单的 C++ 写成 C, 剩下的, 我真的不会 C++…

HTML
– 忘了啥时候开始学的了, 反正成天看网页, 看人源代码, 抄抄改改, 从学校图书馆借过很土鳖的类似 xx 天入门的书学过下后就再没系统的学习过, 倒是折腾过很多地方, WHUACM 那现在还有不少页面是我写的或是基于我写的改的, 后来做 RA 和工作时发现很多需要可视化的结果还是用 HTML 来的爽, 零零碎碎写过一些在行家眼里看来就是三岁小孩折腾的小站
– 能看懂简单的 HTML 框架, 能写简单的 HTML, 比如 yewen.us 这样的 (blog 是 WordPress, 特此说明)

CSS
– 这算语言么? 经历/水平同 HTML

Java
– 大学的选修课, 也仅仅到大学的选修课, 考试过后就没再写过了, 买过 Thinking in Java 但是从来没看完过
– 能完成几年前 Java 1.4 时代的课程大作业水平, 仅此而已, 我真的也不会 Java (猎头问你是 Java 程序员还是 C++ 程序员的时候是最伤人的时候, 我回答都不会后对面口气立马就变的很鄙夷, 连猎头都 bs… 这码农当的太失败了)

JSP
– 本来是想去接手第一版的 woj 然后做第二版的, 后来还没开始正儿八经学就发现不如推倒换 php 重来
– 不会, 曾经还会在 Eclipse 里开个新工程的, 也仅仅会开个新工程, 现在啥也不会了

Linux Shell
– ACM 比赛会用到, 同时本着 “一个合格的计算机专业学生应该会 Linux” 这样的想法自己去折腾过, 选修课上迷迷糊糊学过, 实习的时候开始天天用, 一直都在抄别人的来改, 到现在还是三脚猫功夫, 一直没去找系统学习的方法, 也懒得去系统的学, 觉得是工具用的时候能捡起来就行了, 目前计划在可预见的未来系统的去学学 Shell 脚本学习指南
– 日常工作使用语言, 能写简单的控制脚本, 有若干脚本还在线上系统应用

awk
– 第一次实习的时候因工作关系开始用, 也是从那个时候开始领悟 Linux 的设计哲学, 就是用一堆合适的工具去干一件超酷的事情, 而不要想着为了做一件大事情而去发明一个万能工具 (所以我不是 Emacs 党么?), 一直也还是抄抄改改, 没去系统去学, 有 sed 与 awk 这本书, 但还是只想当工具书用不想系统去学
– 日常工作使用的简单脚本, 能写比较简单的文件级 awk

sed
– 同 awk, 用的更少, 几乎忘光了, 用的时候查 Google/Baidu/参考书

C#
– 某年为了贪一次微软夏令营的机会答应了别人的坑蒙拐骗去当武大微软技术俱乐部主席 (结果那年居然没办夏令营, 真是… 动机不纯必无善果), 一看自己会都跟微软特色没关系, 还是学点啥吧. 瞄上 C#, 从 MSDN 上下了个视频教程对着写完过, 然后, 然后就没有然后了. 在 MSRA 的时候修改的那个原型到底用的 C# 还是 C++ 都忘记了
– 不会, 但是真心觉得比 Java 优美, 特别是现在还在持续改进中

Python
– 好奇心强显然会对各种东西感兴趣, 从研究生开始将 python 作为主力思考/原型实现语言, 写起来确实快, 而且喜欢用缩进来控制语法, 从根本上杜绝了把代码写的很难看或读到很难看的代码 (当然, 有人炫技也还是可以很变态的…). 从 A Byte of Python (中文版) 入门, 再通过 Dive into Python (中文版) 略提高, 再又是抄抄改改了, 成天拿来做系统原型和算法/策略调研和实现, 压根没做 Web 框架什么的 (Django 什么的继续不会). 手头有一本 Python Cookbook, 无奈此书奇技淫巧过多, 只敢将其当工具书偶尔翻看
– 日常工作使用的主力语言, 若干自己的小系统, 若干系统原型 (还有一些一直懒得改和没人改的在线上用)

PHP
– 既然会 HTML 了总该会门动态语言来做交互吧, JSP 看起来就很重那就玩比较好上手的 PHP 咯, 又是一门通过抄抄改改入门的语言, 到现在还是抄抄改改的水平, 手里常备PHP官方手册做参考, 反正也不是项目必须语言, 做点调试工具什么的还是够了
– 菜鸟入门水平, 有一些小原型和调试工具

JavaScript
– 没学过, 不会, 会抄简单的样例连蒙带猜的改, 还是比如 yewen.us 的导航栏效果, 比如会知道怎么改参数用 HighCharts 的简单功能

Perl
– 一直觉得 Perl 是很神奇很牛逼的语言, 但是由于此语言装逼者众多, 且语言本身设计初衷很大一部分就是为了装逼, 而且本来很多不想装逼的因为语言特性又很容易将代码写的巨扭曲, 所以一直没能像别的那样连蒙带猜拆拆改改的去入门乃至提高. 为了使用和改动迪生大神的某 perl 脚本时下决心去学学, 去年换工作前利用平常和周末不加班省出来的时间完整的学了一遍 Perl 语言入门 (小骆驼书), 感觉确实很精妙很方便, 但一直没实际用过, 有需要的时候大部分时间都顺手用 python 解决了, 现在恐怕又忘光了, 但是要捡起来应该比较快, 但要估计这辈子都不打算达到装逼级的熟悉和精通了, 打酱油的 3P 党就好 (Perl/PHP/Python)
– 系统入门过的语言, 从来没实战过的语言

果然都是杂而不精, 同笨狗一贯性格, 甚至现在都还有兴趣去看看 Go 和 Lua, 前者是因为 Google 和设计者名身在外想看看是不是能从中看出点什么未来趋势, 同时悟点以前没悟出来的本质性东西, 后者是听说游戏领域用的很多 (这个应该是受云风影响), 而且很方便实现 robots 做模拟测试, 想看看以后工作中是不是能用的上 (实在不知道 robots 翻译成什么好, 总感觉用 机器人 这个词怪怪的). 如果闲的蛋疼, 还想去看看 ruby 和 lisp, 一个是经常拿来跟 python 对比的语言, 自己一直用 python, 也想看看他山之石, 另一个好歹也活了这么久, 是跟计算机科学和人工智能一起萌芽发展起来的东西, 膜拜下也好, 而且随着多核架构和并行架构越来越普遍, 据说会更有优势?

不过, 要专注, 要做事, 要带人, 而且参考一贯的光说不练的风格, 估计也就这样了… 偶尔打酱油插科打诨还可以.

nginx/php/检索折腾记

仅仅是想实现一个查询接口, 后台每天凌晨更新一份数据, 按存储. web 端可以查询所有 key1 对应的记录, 或者 key1 + key3 的记录, key2 不管, 但是也是个 key, 而且结果要按 key1, key2, key3 来排序. 这里有个问题是只按 key1+key3 查, value 有多个

只会很土鳖的 php 和 python, 于是考虑 php 做 web, 后面用 python 来做查询

机器上没有 web server 和 php, 于是先装. 没有 root 权限, 所以尽可能简单的搞, 把 nginx, pcre, php 都下到 /home/yewen/soft, 解压备用. pcre 是一个库, nginx 需要这个库的支持才能读取跟 php 连起来的部分配置

# 编译安装 nginx
cd ~/soft/nginx-1.1.1
./configure --prefix=/home/yewen/nginx --with-pcre=/home/yewen/soft/pcre-8.13
make
make install

# 改配置
cd ~/nginx
vim conf/nginx.conf

# 此处修改端口号 (http/server/listen)
# 修改 php 支持 (去掉 http/server/location ~.php 那一大段的注释, 不是 proxy)
# 修改 php 支持的路径fastcgi_param SCRIPT_FILENAME /home/yewen/nginx/html$fastcgi_script_name;
# 直接启动
./sbin/nginx

# 编译安装 php, 必须启用 fpm
cd ~/soft/php-5.3.8
./configure --prefix=/home/yewen/php --enable-fastcgi --enable-fpm
make
make install

# 改配置
cp php.ini-production ~/php/etc/php.ini
cd ~/php/etc
cp php-fpm.conf.default php-fpm.conf
vim etc/php-fpm.conf

# 将 user/group 改为本地用户
# 去掉 pm.min_spare_servers和 pm.max_spare_servers前面的注释并设置合理值

# 启动
cd ..
./sbin/php-fpm

写了个很简单的 php, 就是接受一个输入 key, 然后把这个 key 作为参数, system 调用 python 处理, 输出到某临时文件, 然后 php 再读这个文件输出, python 处理是用的最土鳖的扫描文件的方式, 而且由于文件里是按 key1, key2, key3 的顺序排序, 我们的查找有按 key1+key3 来的, 所以必须扫描整个文件, 后来发现这么搞实在不靠谱, 一次检索太慢了, 要数据规模稍微大点, 并发多点, 那就崩溃了

于是考虑把所有数据都加载到内存里来, 用 python 做一个 daemon, 然后 php 通过本机 socket 跟这个 daemon 互动. 不会搞 socket, 于是先学 php 和 python 的 socket 使用, 很简单, 只是因为我为了省事 php 编译的太简单, 居然不支持 socket 方法, 问了下 felix021, 改用fsockopen搞定.

这时候 python 是把所有数据 load 到内存, 用一个以 key1 为 key 的 dict 存储, dict 的每条记录是一个 list, 存储了所有 key1 对应的记录. 如果查询是只有 key1 的, 把这个 list 做下格式化返回就行了, 如果是 key1 + key3 的查询, 则把 key1 的 list 取出来, 做一次遍历, 看 key3 是否就是我们要的, 如果是, 加入结果 list, 最后把这个结果 list 做格式化返回. 因为每个 key1 对应的记录撑死也就几万条, 查询速度完全没有问题, 内存占用 3.2G.

后来发现这台机器没法提供对外服务 (这么坑爹的事情这么晚才得到确认), 换用一台台式机来处理, 这时候内存显然不能这么乱搞, 优化一下, 开始写人肉索引. 内存里还是一个以 key1 为 key 的 dict, 只是 value 改成 key1 在原始文件里的偏移量. 查询的时候, 打开文件跳到 key1 对应的偏移量挨条扫描, 直到到达 key1 结束的地方. 速度还是很好, 因为文件操作毕竟不算多, 至少人肉感觉不出来有迟钝, 内存占用 10M.

把这个问题泛化下, 貌似就可以做面试题了, 一个简单的查询系统. 只要按某个 key 有序, 一开始可以全内存搞, 扩大数据规模后就必须内存索引 + 磁盘文件, 再大就要多级索引, 再大就分库. (我决定今年面试我一定要问这个问题, 如果看过我 blog 的, 那就现场写实现, 如果不考虑做 list 格式化, 整个程序不超过 50 行)

碎叨

0x00 周六几个本科同学来我家吃饭, 感慨本科毕业就过去快三年了
0x01 小白领跟 IT 民工的外形差异还是能很明显看出来的
0x02 把班里的人都过了几遍, 嗯, 整体来看大家混的都挺好
0x03 谁第一个结婚?
0x04 周日去射箭, 挺有意思, 感觉对我这种喜欢速度的人每一轮箭太少了
0x05 各种瞄不准, 最后一把 RP 爆发, 把四根箭射到一个半径不超过 1cm 的分布范围内
0x06 虽然没在靶心, 但是也没差太远
0x07 感觉自己还是配不上鹿港小镇这个级别的地方, 觉得自己太土太穷
0x08 组里喊了两周的真人 CS 还没成行 -___-|
0x09 又喊了一圈跑卡丁车, 各种时间不合适
0x0a 真情呼唤 building
0x0b 去郊游吧? 植物园? 香山?
0x0c 工作各种诡异依赖问题, hadoop 的 cacheFile 分发时间不一致, 非得打包成一个 cacheArchive
0x0d 自己 SB 用 python 的 list 来存一个标记数组判断是否存在, 还想这程序怎么跑这么慢
0x0e 回家后才想起来 python 的 list 查找应该是 O(n) 复杂度的, 不慢才怪
0x0f 自己想到的实现是用有序数组二分查找做到 O(log(n)), 一想到这个就想起来 list 不是这么实现的, 反应慢
0x10 换 dict 后好像内存还在可接受范围, 速度提升了… er, 从无穷慢到五分钟, 这个性能提升怎么算?
0x11 无穷慢只是因为我没有一次跑完数据来评估以前的程序到底有多慢, 就是所谓的在可预见的未来, 换小数据那个程序也跑不完
0x12 上周参加 UT 培训最后一次课, 发现自己跟不上课的主要问题不在 UT, 而是 C++
0x13 C++ 各种不会啊, 真的什么都不会, 我除了会写 C++ 风格的注释好像不会任何 C++
0x14 昨天那个问题本来是打算用 C/C++ 实现模拟器的, 写了个开头发现自己不会用 STL 的 map
0x15 总不能什么东西都自己发明个轮子吧, 还是悻悻的回到 python
0x16 是不是应该去蓝翔技校或北大青鸟回炉重炼下, 这水平, 怎么好意思跟人说是攻城师啊, 撑死就是个掏洞偷鸡的