前言
對于如何優(yōu)雅的實現(xiàn)打印requestId這事情上，google了半天都沒有找到一個滿足我的需求的實現(xiàn)饶辙。唯有自己去實現(xiàn)一個轴总，整個思路我覺得還挺有趣的，值得分享出來怔檩，所以就有了這文章。
需求
我負(fù)責(zé)的子系統(tǒng)有：IP管理系統(tǒng)蓄诽，爬蟲管理系統(tǒng)薛训，爬蟲系統(tǒng)。這個只是整個系統(tǒng)的其中一部分仑氛。這個時候乙埃，如果某個請求或者某個服務(wù)出錯了，需要定位問題的原因就比較復(fù)雜了调衰。為了快速定位問題膊爪，很核心的一個點
日志規(guī)范，而日志規(guī)范中最最最重要的一點就是要有個requestId來跟蹤整個整一個請求或服務(wù)的調(diào)用鏈路嚎莉。需求來了米酬，為每一條日志都加上requestId這個參數(shù)。這個需求再抽象一下趋箩，就是為每一個日志都增加一個前綴赃额。這個前綴可以有requestId, server_name等等信息。這樣抽象之后呢叫确，如果還需要增加其他參數(shù)也方便跳芳。ps：requestId的生成可以簡單粗暴的uuid來，也可以讓它帶有信息（IP竹勉，服務(wù)名等等）飞盆，這個不是本文的重點，最好就由一個專門的函數(shù)來生成次乓，以后有變化改起來也方便吓歇。正如某名言說的那樣，用一個穩(wěn)定的東西來包裝一個不穩(wěn)定的東西以提供一個穩(wěn)定的服務(wù)票腰。
實現(xiàn)思路
不用動腦子想到的實現(xiàn)方式
- 類的初始化參數(shù)&函數(shù)參數(shù)都提供一個參數(shù)專門來傳遞log前綴
- 做一個裝飾器給需要打印業(yè)務(wù)log的方法或函數(shù)使用
對于方式1城看，這個實現(xiàn)起來巨惡心，入侵過大杏慰，偶合過大我的內(nèi)心是拒絕的测柠。對于方式2稍微好了一點，傳說當(dāng)中的切面編程缘滥，對代碼沒有入侵性轰胁，但是粒度太大，函數(shù)或者方法內(nèi)的log無法加上前綴朝扼，肯定是不行的软吐，所以只能放棄。所以此時又把目光放到方式1上吟税，此時大腦冒出了一個大膽的想法凹耙，給整個系統(tǒng)的類或函數(shù)打補(bǔ)丁。補(bǔ)丁的作用就是為類的初始化方法添加上log前綴的可選參數(shù)肠仪，函數(shù)參數(shù)添加上log前綴的可選參數(shù)肖抱。然后還居然真的有相關(guān)的模塊可以獲取方法或者類的參數(shù)信息，并修改异旧，這個高級功能只存在python3之中意述。準(zhǔn)備擼起袖子就開干的時候，還是被惡心到了吮蛹，即便實現(xiàn)了荤崇，還是需要將log前綴層層傳遞，代碼將會變得很難看潮针。前面說的層層傳遞术荤，抽象一下就是在每個調(diào)用間共享一個變量，此時大腦想起了threading模塊中的local類每篷，但是但是我們的服務(wù)部署一般是gevent的模式瓣戚，threading的local模塊并不是一個協(xié)程安全的東西。萬能的google再次拯救我焦读，在werkzeug實現(xiàn)了一個協(xié)程安全Local類子库，celery當(dāng)中也實現(xiàn)了，實現(xiàn)方式都差不多矗晃，連注釋都一毛一樣仑嗅。
最終的實現(xiàn)方式
暫時想到的最優(yōu)的實現(xiàn)方式：在服務(wù)的開頭出在local對象中設(shè)置上log的前綴，出口處刪掉张症，每條log都從Local對象處獲取前綴打印仓技。這都是由框架來做，具體的業(yè)務(wù)代碼是無感知的吠冤。這樣做的好處就是對代碼幾乎是無入侵的浑彰，擴(kuò)展性強(qiáng)，大家都開心的方式拯辙。在細(xì)化一下具體實現(xiàn)方式郭变，本質(zhì)上還是添加中間層來實現(xiàn)。對沒錯涯保，任何計算機(jī)問題均可以通過增加一個中間層來解決诉濒。
- http請求：在header處添加上requestID這參數(shù)，然后中間件來做統(tǒng)一處理
- celery異步任務(wù)：任務(wù)消息帶上log前綴夕春，任務(wù)開始前做添加上前綴未荒，任務(wù)返回后刪掉
實現(xiàn)核心過程
一點說明，代碼中有部分配置信息及志，這個我賴得改直接就粘貼復(fù)制過來了片排，不是什么重點內(nèi)容 寨腔，忽略就好。另外的率寡，必要的一下基礎(chǔ)知識 迫卢，我并沒有進(jìn)行講解，一來嘛冶共，不是重點乾蛤，二來嘛，我感覺我會寫得沒別人好捅僵，但會給出有幫助的文章鏈接家卖。
django 中間件
給application添加Local對象清理的中間件
有參考價值的文章: 關(guān)于werzeug模塊中對的Local對象的使用的中文文章
文件wsgi.py
from werkzeug.local import Local, LocalManager
local = Local()
local_manager = LocalManager([local])
# 請求結(jié)束后對當(dāng)前線程或者協(xié)程中的local對象中的變量進(jìn)行清除
application = local_manager.make_middleware(application)
自定義django的中間件
將django中間件怎么做的文章: django中間件。代碼沒啥好說的庙楚，核心點就是設(shè)置給Local對象設(shè)置上一個dict對象上荡，里面包含了需要的前綴信息。
from xxx import local
class LogPrexiMiddleware(MiddlewareMixin):
def process_request(self, request):
log_data = self._get_log_data(request)
attr_name = getattr(settings, LOCAL_LOG_ATTR_NAME, DEFAULT_LOCAL_LOG_ATTR_NAME)
setattr(local, attr_name, log_data)
def _get_log_data(self, request):
log_header_key = getattr(settings, LOG_HEADER_KEY_SETTING, None)
log_data = {}
if log_header_key and log_header_key in request.META:
log_data = {"requestId": request.META.get(log_header_key)}
if not log_data and getattr(settings, GENERATE_REQUEST_ID_IF_NOT_IN_HEADER_SETTING, False):
# 通過一個函數(shù)生成request_id
request_id = gen_request_id()
log_data = {"requestId": request_id}
return log_data
log的filter
關(guān)于python log處理模塊的文章：python log基礎(chǔ)知識醋奠。
from xxx import local
class PrefixFilter(Filter):
def filter(self, record):
log_data = getattr(local, settings.LOCAL_LOG_ATTR_NAME, {})
log_prefix = "".join(["[{}={}]".format(key, value) for key, value in log_data.items()])
# log format: [%(log_prefix)s][%(asctime)s,%(msecs)d][%(levelname)s]
record.log_prefix = log_prefix
return True
celery異步任務(wù)
這個是整個實現(xiàn)的難點所在榛臼，也是值得借鑒的地方，這部分必須嘮叨的解釋一下窜司，因為這部分網(wǎng)上沒啥好的文章給我貼出來沛善，而且有的部分被迫自己實現(xiàn)的，說來都是淚啊塞祈，差點弄我一個通宵金刁。前面所說的，任務(wù)消息帶上log前綴议薪，任務(wù)開始前做添加上前綴尤蛮，任務(wù)返回后刪掉。難點是在于如何優(yōu)雅的做到不入侵原先的代碼斯议。
任務(wù)消息帶上log前綴
馬上想到的方式在異步任務(wù)的參數(shù)上帶上产捞，但是感覺不太優(yōu)雅，直覺上celery框架應(yīng)該有提供攜帶額外信息的參數(shù)哼御。翻了一下celery官網(wǎng)文檔坯临，有一個headers的參數(shù)放出刺眼的光芒引起了我的注意，測試了一下還真的可以恋昼，這樣僅僅需要將log前綴信息放在headers中即可看靠。ps：測試的時候還順便更加理解amqp這協(xié)議，celery的一下額外的控制參數(shù)例如task_id都是存放在消息的headers中的液肌，然后在接收到消息后做統(tǒng)一的處理挟炬。
任務(wù)開始前做添加上前綴，任務(wù)返回前刪掉
直覺上celery框架是有留出有相關(guān)的接口做這事，還是去翻文檔谤祖。翻到有一個after_return的handler, 但是但是沒有一個pre_execute的handler婿滓。只找到一個task_prerun的信號，這貨是個全局性的東西泊脐，感覺上粒度太大空幻，我不好控制。這時候冒出大膽的想法容客，去翻源碼，看看怎么添加上pre_execute的handler约郁，再利用monkey_patch給celery這個包打補(bǔ)丁缩挑。直接翻源碼還是挺痛苦的，有點暈鬓梅，此時想到了pycharm是可以斷點調(diào)試的供置，斷點觀察整個調(diào)用過程+全局關(guān)鍵字搜索來找添加的入口。最后在celery/app/trace.py文件中找到了build_tracer這個函數(shù)绽快，一個任務(wù)執(zhí)行所有的流程控制都在里面芥丧。真的是牛逼啊，用一個流程控制的方法來控制整個流程坊罢，思路很好续担，值得借鑒，大神們的軟件架構(gòu)思路無比膜拜活孩。所要做的就很簡單物遇，按照里面的規(guī)則照葫蘆畫瓢的添加一個pre_execute的處理，然后mokey_patch搞起來即可憾儒。
具體的一下代碼
from xxx import local, local_manager
class BaseTask(app.Task):
def apply_async(self, args=None, kwargs=None, task_id=None, producer=None,
link=None, link_error=None, shadow=None, **options):
"""
自動根據(jù)local變量中的log相關(guān)的信息询兴，設(shè)置去message的headers中，讓異步任務(wù)根據(jù)設(shè)置的log信息設(shè)置log
"""
# 自動把log prefix 信息添加到消息的headers中
log_data = getattr(local, settings.LOCAL_LOG_ATTR_NAME, {})
headers = options.get("headers", {})
headers.update({settings.LOCAL_LOG_ATTR_NAME: json.dumps(log_data)})
options["headers"] = headers
super(BaseTask, self).apply_async(args=args, kwargs=kwargs, task_id=task_id, producer=producer,
link=link, link_error=link_error, shadow=shadow, **options)
def pre_execute(self, status, retval, task_id, args, kwargs, einfo):
# 任務(wù)開始前將headers中的log前綴信息起趾，給添加到local變量里面
log_data = {}
if hasattr(self.request, settings.LOCAL_LOG_ATTR_NAME):
try:
log_data = json.loads(getattr(self.request, settings.LOCAL_LOG_ATTR_NAME))
except ValueError as why:
sm_log.debug("異步任務(wù)設(shè)置log的出錯", exc_info=True)
setattr(local, settings.LOCAL_LOG_ATTR_NAME, log_data)
def after_return(self, status, retval, task_id, args, kwargs, einfo):
# 清理變量诗舰，其實不清理也沒什么影響，畢竟部署都是進(jìn)程池或者是協(xié)程池的训裆，不會有很多眶根。
super(BaseTask, self).after_return(status, retval, task_id, args, kwargs, einfo)
local_manager.cleanup()
# 使用說明
方式一：粒度可控的
@app.task(bind=True, base=BaseTask, max_retries=3)
def debug_t(self, a):
pass
方式二：全局的
app.Task = BaseTask
最后的嘮叨
人上了年紀(jì)，容易發(fā)出一些感慨缭保。這個東西實現(xiàn)后汛闸，總結(jié)的體會是：1. 越來越意識到抽象是一樣多么重要的事情，如果沒有去抽象出共性艺骂，我可能就被迫用最惡心的方式1來實現(xiàn)了诸老。2. 編程這工作雖然說是偏文科，以知識和經(jīng)驗為主，但是良好的分析思路卻能很好的彌補(bǔ)上知識和經(jīng)驗上的不足别伏。在分析能力的提高這部分還是要經(jīng)過有意識的訓(xùn)練才行蹄衷，這里立個flag，那天我覺得自己分析能力有了一個臺階的上升后厘肮，擼一篇如果分析的文章愧口。
