Golang中使用注释注解打印日志

　　背景
　　前一段时间线上出现了一个问题：在压测后偶尔会出现一台机器查询数据无结果但是没有返回err的情况，导致后续处理都出错。由于当时我们仅在最外层打印了err，没有打印入参和出参，所以导致很难排查问题到底出现在哪一环节。
　　经过艰难地排查出问题后，感觉需要在代码里添加打印关键函数的入参和出参数，但这个逻辑都是重复的，也不想将这一逻辑侵入开发流程，所以就想到了代码生成方式的注释注解。即我们提前定义好一个注释注解（例如：Log（）），并且在Docker中编译前运行代码生成的逻辑，将所有拥有该注释注解的函数进行修改，在函数体前面添加打印入参和出参的逻辑。这样就不需要让日志打印侵入到业务代码中，并且后续可以很方便替换成其他的打印逻辑（例如根据Log内的参数或者返回值等自定义日志级别）。编写代码
　　我们可以使用AST的方式去解析、识别并修改代码，goast已经提供了相应的功能，我们查看我们关心的节点部分及其相关的信息结构，可以使用goastviewer直接查看AST，当然也可以本地进行调试。遍历。go文件
　　首先需要使用filepath。Walk函数遍历指定文件夹下的所有文件，对每一个文件都会执行传入的walkFn函数。walkFn函数会将。go文件解析成AST，将其交由注释注解的处理器处理，然后根据是否修改了AST决定是否生成新的代码。walkFn函数会对每个。go文件处理，并调用注解处理器funcwalkFn（pathstring，infoos。FileInfo，errerror）error｛如果是文件夹，或者不是。go文件，则直接返回不处理ifinfo。IsDir（）！strings。HasSuffix（info。Name（），。go）｛returnnil｝将。go文件解析成ASTfileSet，file，err：parseFile（path）如果注解修改了内容，则需要生成新的代码iflogannotation。Overwrite（path，fileSet，file）｛buf：bytes。Buffer｛｝iferr：format。Node（buf，fileSet，file）；err！nil｛panic（err）｝如果不需要替换，则生成到另一个文件if！replace｛lastSlashIndex：strings。LastIndex（path，）genDirPath：path〔：lastSlashIndex〕geniferr：os。Mkdir（genDirPath，0755）；err！nilos。IsNotExist（err）｛panic（err）｝pathgenDirPathpath〔lastSlashIndex1：〕｝iferr：ioutil。WriteFile（path，buf。Bytes（），info。Mode（））；err！nil｛panic（err）｝｝returnnil｝遍历AST
　　当注释注解处理器拿到AST后，就需要使用astutil。Apply函数遍历整颗AST，并对每个节点进行处理，同时为了方便修改时添加import，我们包一层函数供内部调用，并把一些关键信息打包在一起。Overwrite会对每个file处理，运行注册的注解handler，并返回其是否被修改funcOverwrite（filepathstring，fileSettoken。FileSet，fileast。File）（modifiedbool）｛初始化处理本次文件所需的信息对象info：Info｛Filepath：filepath，NamedImportAdder：func（namestring，pathstring）bool｛returnastutil。AddNamedImport（fileSet，file，name，path）｝，｝遍历当前文件ast上的所有节点astutil。Apply（file，nil，func（cursorastutil。Cursor）bool｛处理log注解info。Nodecursor。Node（）nodeModified，err：Handler。Handle（info）iferr！nil｛panic（err）｝ifnodeModified｛modifiednodeModified｝returntrue｝）return｝识别注释注解
　　接下来我们就需要识别注释注解，跳过不相关的节点，示例中不做额外处理，仅当注释为Log（）才认为需要处理，可以根据需要添加相应的逻辑。func（hhandler）Handle（infoInfo）（modifiedbool，errerror）｛log注解只用于函数funcDecl，ok：info。Node。（ast。FuncDecl）if！ok｛return｝如果没有注释，则直接处理下一个iffuncDecl。Docnil｛return｝如果不是可以处理的注解，则直接返回doc：strings。Trim（funcDecl。Doc。Text（），）ifdoc！Log（）｛return｝。。。｝获取函数入参和出参
　　首先我们需要获取函数的入参和出参，这里我们以出参举例。出参定义在funcDecl。Type。Results，并且可能没有指定名称，所以需要先为以0，1，。。。这样的形式为没有名称的变量设置默认名称，然后按照顺序获取所有变量的名称列表。SetDefaultNames给没有名字的Field设置默认的名称默认名称格式：0，1，。。。true：表示至少设置了一个名称false：表示未设置过名称funcSetDefaultNames（fields。。。ast。Field）bool｛index：0for，field：rangefields｛iffield。Namesnil｛field。NamesNewIdents（fmt。Sprintf（v，index））index｝｝returnindex0｝获取打印语句
　　假设我们所需的打印语句为：log。Logger。WithContext（ctx）。WithField（filepath，filepath）。Infof（format，arg0，arg1），那么函数选择器的表达式可以直接使用parser。ParseExpr函数生成，其中的参数（format，arg0，arg1）手动拼接即可。NewCallExpr产生一个调用表达式待产生表达式：log。Logger。WithContext（ctx）。Infof（arg0，arg1）其中：funcSelectorlog。Logger。WithContext（ctx）。Infofargs（arg0，arg1）调用语句：NewCallExpr（log。Logger。WithContext（ctx）。Infof，arg0，arg1）funcNewCallExpr（funcSelectorstring，args。。。string）（ast。CallExpr，error）｛获取函数对应的表达式funcExpr，err：parser。ParseExpr（funcSelector）iferr！nil｛returnnil，err｝组装参数列表argsExpr：make（〔〕ast。Expr，len（args））fori，arg：rangeargs｛argsExpr〔i〕ast。NewIdent（arg）｝returnast。CallExpr｛Fun：funcExpr，Args：argsExpr，｝，nil｝
　　由于出参需要等函数执行完毕后执行，所以打印出参的语句还需要放在defer函数内执行。NewFuncLitDefer产生一个defer语句，运行一个匿名函数，函数体是入参语句列表funcNewFuncLitDefer（funcStmts。。。ast。Stmt）ast。DeferStmt｛returnast。DeferStmt｛Call：ast。CallExpr｛Fun：NewFuncLit（ast。FuncType｛｝，funcStmts。。。），｝，｝｝修改函数体
　　至此我们已经获得了打印入参和出参的语句，接下来就是把他们放在原本函数体的最前面，保证开始和结束时执行。toBeAddedStmts：〔〕ast。Stmt｛ast。ExprStmt｛X：beforeExpr｝，离开函数时的语句使用defer调用NewFuncLitDefer（ast。ExprStmt｛X：afterExpr｝），｝我们将添加的语句放在函数体最前面funcDecl。Body。Listappend（toBeAddedStmts，funcDecl。Body。List。。。）运行
　　为了测试我们的注释注解是否工作正确，我们使用如下代码进行测试：packagemainimport（contextlogannotationtestdatalog）funcmain（）｛fn（context。Background（），1，2，3，true）｝Log（）funcfn（ctxcontext。Context，aint，b，cstring，dbool）（int，string，string）｛log。Logger。WithContext（ctx）。Infof（fnexecuting。。。）returna，b，c｝
　　运行gorunlogannotationcmdgeneratorUsersidealismWorkspacesGogolanglogannotationtestdata执行代码生成，在UsersidealismWorkspacesGogolanglogannotationtestdatagen下可找到生成的代码：packagemainimport（contextlogannotationtestdatalog）funcmain（）｛fn（context。Background（），1，2，3，true）｝funcfn（ctxcontext。Context，aint，b，cstring，dbool）（0int，1string，2string）｛log。Logger。WithContext（ctx）。WithField（filepath，UsersidealismWorkspacesGogolanglogannotationtestdatamain。go）。Infof（fnstart，params：v，v，v，v，a，b，c，d）deferfunc（）｛log。Logger。WithContext（ctx）。WithField（filepath，UsersidealismWorkspacesGogolanglogannotationtestdatamain。go）。Infof（fnend，results：v，v，v，0，1，2）｝（）log。Logger。WithContext（ctx）。Infof（fnexecuting。。。）returna，b，c｝
　　可以看到已经按照我们的想法正确生成了代码，并且运行后能按照正确的顺序打印正确的入参和出参。实际使用时会在ctx中加入apm的traceId，并且在logrus的Hooks中将其在打印前放入到Fields中，这样搜索的时候可以将同一请求的所有日志聚合在一起。INFO〔0000〕fnstart，params：1，2，3，truefilepathUsersidealismWorkspacesGogolanglogannotationtestdatamain。goINFO〔0000〕fnexecuting。。。INFO〔0000〕fnend，results：1，2，3filepathUsersidealismWorkspacesGogolanglogannotationtestdatamain。go扩展
　　以上代码是一种简单方式地定制化处理注解，仅处理了打印日志这一逻辑，当然还存在更多扩展的可能性和优化。注册自定义注解（这样可以把更多重复逻辑抽出来，例如：参数校验、缓存等逻辑）同时使用多个注解注解解析成语法树，支持注解参数生成的代码仅在需要时换行
　　相关Demo可以在golanglogannotation找到。