标签 垃圾回收 下的文章

Go语言回顾:从Go 1.0到Go 1.13

Go 1.13版本在2019.9.3正式发布!国外的Gopher Vincent Blanchon发表了一篇文章《Go: Retrospective》(科学上网阅读),对Go从1.0版本到1.13版本做了简要的回顾,这里是那篇文章的译文。

img{512x368}

对于每一位Go开发者来说,Go语言的演化历程是必须要知道的事情。了解这些横跨年份发布的大版本的主要变化将有助于Gopher理解Go语言的发展理念以及该语言每个版本的优势与不足。更多关于特定版本的变更细节,可以参考每个版本对应的Changelog

Go 1.0 – 2012.3月

伴随着Go语言的第一个版本,Go的缔造者还发布了一份兼容性文档。该文档保证未来的Go版本将保持向后兼容性(backward-compatible),即始终兼容已有的代码,保证已有代码在Go新版本下编译和运行的正确性。

Go 1.0版本还包含了go tool pprof命令,这是一个Google pprof C++ profiler的变体。Go 1.0还提供了go vet命令(之前的go tool vet),用于报告Go package中可能的错误。

Go 1.1 – 2013.5月

该版本主要专注于语言改善和性能提升(编译器、垃圾回收、map、goroutine调度)。这里是一个改善后的效果示意图:

img{512x368}
图来自https://dave.cheney.net/2013/05/21/go-11-performance-improvements

这个版本同时还嵌入了一个竞态探测器(race detector),这个工具对于Go这种原生并发的语言是十分必要的。在《Race Detector with ThreadSanitizer”》一文中,你可以找到有关race detector的更多详细信息。

在这个版本中的一个重点变动是Goroutine调度器被重写了,重写后的调度器性能大幅提升。

重写后的Go调度器的设计如下图:

img{512x368}
图来自 https://rakyll.org/scheduler/

M对应的是操作系统的线程。P表示一个处理器(P的数量不能超过GOMAXPROCS),每个P拥有一个本地goroutine队列。在1.1版本之前,P这个抽象并不存在。所有goroutine的调度通过全局互斥锁进行全局级别的管理。这次改进实现了”work-stealing”算法,允许某个P从其他P的队列中”偷goroutine”:

img{512x368}
图来自 https://rakyll.org/scheduler/

更多关于Go调度器调度原理以及”work-stealing”算法的信息,可以查看Jaana B. Dogan的文章《Go’s work-stealing scheduler》

Go 1.2 – 2013.12

在该版本中,Go test命令开始支持代码测试覆盖率统计了,并且通过go提供的新子命令: go tool cover可以查看代码测试覆盖率统计信息:

img{512x368}
图来自 https://blog.golang.org/cover

它还能提供代码覆盖信息:

img{512x368}
图来自 https://blog.golang.org/cover

Go 1.3 – 2014.6

该版本包含了栈管理的一个重要改进。在该版本中,栈内存分配采用连续段(contiguous segment)的分配模式以提升内存分配效率。这将为下一个版本将栈size降到2KB奠定基础。之前的分割栈分配方式(segment stack)存在频繁分配/释放栈段导致栈内存分配性能不稳定(较低)的问题,引入新机制后,分配稳定性和性能都有较大改善。

这里是一个json包的例子,图中显示json包对栈size的敏感度:

img{512x368}
图来自 contiguous stack

使用连续段的栈内存分配管理模式解决了一些程序性能低下的问题。下面是html/template包的性能对stack size的敏感度图:

img{512x368}

更多信息可参见[《How Does the Goroutine Stack Size Evolve?”》(https://medium.com/@blanchon.vincent/go-how-does-the-goroutine-stack-size-evolve-447fc02085e5)]。

这个版本还发布了sync.Pool。这个组件允许我们后面重用结构体,减少内存分配的次数。它也将成为Go生态圈中许多性能提升的源头,比如:标准库中的encoding/json、net/http或是Go社区中的zap等。

关于sync.Pool的更多信息,可以参考文章《Understand the Design of Sync.Pool》

Go开发组在该版本中对channel进行了优化改善,使其性能获得提升。下面是channel在Go 1.2和Go 1.3版本中的基准测试数据对比:

img{512x368}

Go 1.4 – 2014.12

在该版本中,Go提供了对Android的官方支持。使用golang.org/x/mobile包,gopher们可以使用Go编写简单的Android应用。

同时,之前版本中大量用C语言和汇编语言实现的运行时已经被翻译为Go,一个更为精确的垃圾回收器让堆内存分配减少了10~30%。

和版本自身无关的是,Go工程在本次发布后已经从Mercurial迁移到Git,从Google code迁移到github。

Go还发布了go generate命令,该命令可以通过扫码代码中的//go:generate指示器来生成代码,可以帮助Gopher简化代码生成工作。

更多关于这方面的信息可以参考Go blog和这篇文章《Generating code》

Go 1.5 – 2015.8

这个新版本推迟了两个月发布,目的是适应Go新的开发发布周期:每年二月和八月进行发布:

img{512x368}
图来自:https://github.com/golang/go/wiki/Go-Release-Cycle

在该版本中,垃圾回收器全面重构。由于引入并发回收器,回收阶段带来的延迟大幅减少。下面是来自一个生产环境服务器上的延迟数据,我们看到延迟从300ms降到了30ms:

img{512x368}
图片来自 https://blog.golang.org/ismmkeynote

这个版本还发布go tool trace命令,通过该命令我们可以实现执行器的跟踪(trace)。这些跟踪是在test执行、运行时生成的,跟踪信息可以通过浏览器呈现:

img{512x368}
图片来自原始Go Execution Tracer文档

Go 1.6 – 2016.2

这个版本的最显著变化是当使用HTTPS时,将默认支持HTTP/2。

垃圾回收器的延迟在该版本中进一步降低:

img{512x368}
图片来自https://blog.golang.org/ismmkeynote

Go 1.7 – 2016.8

这个版本发布了context包。该包用于处理timeout和取消任务。

更多关于context包的信息,可参考文章:《Context and Cancellation by Propagation》

编译器工具链的性能得到了较大幅度优化,编译速度更快,二进制文件size更小,有些时候幅度可达20~30%。

Go 1.8 – 2017.2

垃圾回收器的延迟在该版本中进一步改善,延迟时间已经全面降到毫秒级别以下:

img{512x368}
图片来自https://blog.golang.org/ismmkeynote

对延迟的优化还将继续。接下来版本的目标是将延迟降到100微秒左右。

这个版本还大幅提升了defer的性能:

img{512x368}
图片来自 https://medium.com/@blanchon.vincent/go-how-does-defer-statement-work-1a9492689b6e

更多关于defer的信息,可以参考文章How Does Defer statement Work?

Go 1.9 – 2017.8

该版本引入了alias语法。

type byte = uint8

这里byte是unit8的一个alias。

sync包增加了Map类型,该类型支持并发访问(原生map类型不支持)。

关于map的更多信息,参考文章“Concurrency Access with Maps”

Go 1.10 – 2018.2

在该版本中,test包引入了一个新的缓存机制,所有通过测试的结果都将被缓存下来。当test没有变化时,重复执行test会节省大量运行test的时间。

first run:
ok      /go/src/retro 0.027s
second run:
ok      /go/src/retro (cached)

go build命令也维护了一个已构建的包的缓存以加速构建性能。

该版本中垃圾回收器并没有显著性能提升。但是Go team为垃圾回收定义了一个新的SLO(Service-Level Objective):

img{512x368}
图片来自https://blog.golang.org/ismmkeynote

Go 1.11 – 2018.8

Go 1.11引入了一个重要的新功能:Go modules。Go module的引入是为了应对过去几年官方调查问卷结果中Go社区反馈的几个主要挑战:

img{512x368}
图片来自 https://blog.golang.org/survey2018-results

另外一个重要功能是一个试验功能:支持WebAssembly。允许开发人员将Go源码编译成一个兼容四个主流浏览器的二进制格式文件。

Go 1.12 – 2019.2

该版本中,go vet基于analysis包进行了重写,使得go vet更为灵活并支持Go开发人员编写自己的checker。

更多关于analyzer的信息可以参考文章《How to Build Your Own Analyzer》

Go 1.13 – 2019.8

在该版本中,sync.Pool得到了改善:当垃圾回收时,pool中对象不会被完全清理掉。它引入了一个cache,用于在两次GC之前清理pool中未使用的对象实例。

逃逸分析(escape analysis)被重新实现了,在该版本中,Go得意更少地在堆上分配内存了。下面是新旧逃逸分析的基准测试对比:

img{512x368}
图片来自 https://github.com/golang/go/issues/23109


我的网课“Kubernetes实战:高可用集群搭建、配置、运维与应用”在慕课网上线了,感谢小伙伴们学习支持!

我爱发短信:企业级短信平台定制开发专家 https://tonybai.com/
smspush : 可部署在企业内部的定制化短信平台,三网覆盖,不惧大并发接入,可定制扩展; 短信内容你来定,不再受约束, 接口丰富,支持长短信,签名可选。

著名云主机服务厂商DigitalOcean发布最新的主机计划,入门级Droplet配置升级为:1 core CPU、1G内存、25G高速SSD,价格5$/月。有使用DigitalOcean需求的朋友,可以打开这个链接地址:https://m.do.co/c/bff6eed92687 开启你的DO主机之路。

我的联系方式:

微博:https://weibo.com/bigwhite20xx
微信公众号:iamtonybai
博客:tonybai.com
github: https://github.com/bigwhite

微信赞赏:
img{512x368}

商务合作方式:撰稿、出书、培训、在线课程、合伙创业、咨询、广告合作。

写Go代码时遇到的那些问题[第3期]

我有一个习惯,那就是随时记录下编程过程中遇到的问题(包括问题现场、问题起因以及对问题的分析),并喜欢阶段性的对一段时间内的编码过程的得与失进行回顾和总结。内容可以包括:对编程语法的新认知、遇坑填坑的经历、一些让自己豁然开朗的小tip/小实践等。记录和总结的多了,感觉有价值的,就成文发在博客上的;一些小的点,或是还没有想清楚的事情,或思路没法结构化统一的,就放在资料库里备用。“写Go代码时遇到的那些问题”这个系列也是基于这个思路做的。

在这一篇中,我把“所遇到的问题”划分为三类:语言类、库与工具类、实践类,这样应该更便于大家分类阅读和理解。另外借这篇文章,我们先来看一下Go语言当前的State,资料来自于twitter、redditgolang-dev forum、github上golang项目的issue/cl以及各种gophercon的talk资料。

零. Go语言当前状态

1. vgo

Go 1.10在中国农历春节期间正式发布。随后Go team进入了Go 1.11的开发周期

在2017年的Go语言用户调查报告结果中,缺少良好的包管理工具以及Generics依然是Gopher面临的最为棘手的挑战和难题的Top2,Go team也终于开始认真对待这两个问题了,尤其是包依赖管理的问题。在今年2月末,Russ Cox在自己的博客上连续发表了七篇博文,详细阐述了vgo – 带版本感知和支持的Go命令行工具的设计思路和实现方案,并在3月末正式提交了”versioned-go proposal“。

目前相对成熟的包管理方案是:

"语义化版本"
+manifest文件(手工维护的依赖约束描述文件)
+lock文件(工具自动生成的传递依赖描述文件)
+版本选择引擎工具(比如dep中的gps - Go Packaging Solver)

与之相比,vgo既有继承,更有创新。继承的是对语义化版本的支持,创新的则是semantic import versioning最小版本选择minimal version selection等新机制,不变的则是对Go1语法的兼容。按照Russ Cox的计划,Go 1.11很可能会提供一个试验性的vgo实现(当然vgo所呈现的形式估计是merge到go tools中),让广大gopher试用和反馈,然后会像vendor机制那样,在后续Go版本中逐渐成为默认选项。

2. wasm porting

知名开源项目gopherjs的作者Richard Musiol上个月提交了一个proposal: WebAssembly architecture for Go,主旨在于让Gopher也可以用Go编写前端代码,让Go编写的代码可以在浏览器中运行。当然这并不是真的让Go能像js那样直接运行于浏览器或nodejs上,而是将Go编译为WebAssembly,wasm中间字节码,再在浏览器或nodejs初始化的运行环境中运行。这里根据自己的理解粗略画了一幅二进制机器码的go app与中间码的wasm的运行层次对比图,希望对大家有用:

img{512x368}

wasm porting已经完成了第一次commit ,很大可能会随着go1.11一并发布第一个版本。

3. 非协作式的goroutine抢占式调度

当前goroutine“抢占式”调度依靠的是compiler在函数中自动插入的“cooperative preemption point”来实现的,但这种方式在使用过程中依然有各种各样的问题,比如:检查点的性能损耗、诡异的全面延迟问题以及调试上的困难。近期负责go runtime gc设计与实现的Austin Clements提出了一个proposal:non-cooperative goroutine preemption ,该proposal将去除cooperative preemption point,而改为利用构建和记录每条指令的stack和register map的方式实现goroutine的抢占, 该proposal预计将在go 1.12中实现。

4. Go的历史与未来

GopherConRu 2018大会上,来自Go team的核心成员Brad Fitzpatrick做了“Go的历史与未来”的主题演讲 ,Bradfitz“爆料”了关于Go2的几个可能,考虑到Bradfitz在Go team中的位置,这些可能性还是具有很大可信度的:

1). 绝不像Perl6和Python3那样分裂社区
2). Go1的包可以import Go2的package
3). Go2很可能加入Generics,Ian Lance Taylor应该在主导该Proposal
4). Go2在error handling方面会有改进,但不会是try--catch那种形式
5). 相比于Go1,Go2仅会在1-3个方面做出重大变化
6). Go2可能会有一个新的标准库,并且该标准库会比现有的标准库更小,很多功能放到标准库外面
7). 但Go2会在标准库外面给出最流行、推荐的、可能认证的常用包列表,这些在标准库外面的包可以持续更新,而不像那些在标准库中的包,只能半年更新一次。

一. 语言篇

1. len(channel)的使用

len是Go语言的一个built-in函数,它支持接受array、slice、map、string、channel类型的参数,并返回对应类型的”长度” – 一个整型值:

len(s)   

如果s是string,len(s)返回字符串中的字节个数
如何s是[n]T, *[n]T的数组类型,len(s)返回数组的长度n
如果s是[]T的Slice类型,len(s)返回slice的当前长度
如果s是map[K]T的map类型,len(s)返回map中的已定义的key的个数
如果s是chan T类型,那么len(s)返回当前在buffered channel中排队(尚未读取)的元素个数

不过我们在代码经常见到的是len函数针对数组、slice、string类型的调用,而len与channel的联合使用却很少。那是不是说len(channel)就不可用了呢?我们先来看看len(channel)的语义。

  • 当channel为unbuffered channel时,len(channel)总是返回0;
  • 当channel为buffered channel时,len(channel)返回当前channel中尚未被读取的元素个数。

这样一来,所谓len(channel)中的channel就是针对buffered channel。len(channel)从语义上来说一般会被用来做“判满”、”判有”和”判空”逻辑:

// 判空

if len(channel) == 0 {
    // 这时:channel 空了 ?
}

// 判有

if len(channel) > 0 {
    // 这时:channel 有数据了 ?
}

// 判满
if len(channel) == cap(channel) {
    // 这时:   channel 满了 ?
}

大家看到了,我在上面代码中注释:“空了”、“有数据了”和“满了”的后面打上了问号!channel多用于多个goroutine间的通讯,一旦多个goroutine共同读写channel,len(channel)就会在多个goroutine间形成”竞态条件”,单存的依靠len(channel)来判断队列状态,不能保证在后续真正读写channel的时候channel状态是不变的。以判空为例:

img{512x368}

从上图可以看到,当goroutine1使用len(channel)判空后,便尝试从channel中读取数据。但在真正从Channel读数据前,另外一个goroutine2已经将数据读了出去,goroutine1后面的读取将阻塞在channel上,导致后面逻辑的失效。因此,为了不阻塞在channel上,常见的方法是将“判空与读取”放在一起做、将”判满与写入”一起做,通过select实现操作的“事务性”:

//writing-go-code-issues/3rd-issue/channel_len.go/channel_len.go.go
func readFromChan(ch <-chan int) (int, bool) {
    select {
    case i := <-ch:
        return i, true
    default:
        return 0, false // channel is empty
    }
}

func writeToChan(ch chan<- int, i int) bool {
    select {
    case ch <- i:
        return true
    default:
        return false // channel is full
    }
}

我们看到由于用到了Select-default的trick,当channel空的时候,readFromChan不会阻塞;当channel满的时候,writeToChan也不会阻塞。这种方法也许适合大多数的场合,但是这种方法有一个“问题”,那就是“改变了channel的状态”:读出了一个元素或写入了一个元素。有些时候,我们不想这么做,我们想在不改变channel状态下单纯地侦测channel状态!很遗憾,目前没有哪种方法可以适用于所有场合。但是在特定的场景下,我们可以用len(channel)实现。比如下面这个场景:

img{512x368}

这是一个“多producer + 1 consumer”的场景。controller是一个总控协程,初始情况下,它来判断channel中是否有消息。如果有消息,它本身不消费“消息”,而是创建一个consumer来消费消息,直到consumer因某种情况退出,控制权再回到controller,controller不会立即创建new consumer,而是等待channel下一次有消息时才创建。在这样一个场景中,我们就可以使用len(channel)来判断是否有消息。

2. 时间的格式化输出

时间的格式化输出是日常编程中经常遇到的“题目”。以前使用C语言编程时,用的是strftime。我们来回忆一下c的代码:

// writing-go-code-issues/3rd-issue/time-format/strftime_in_c.c
#include <stdio.h>
#include <time.h>

int main() {
        time_t now = time(NULL);

        struct tm *localTm;
        localTm = localtime(&now);

        char strTime[100];
        strftime(strTime, sizeof(strTime),  "%Y-%m-%d %H:%M:%S", localTm);
        printf("%s\n", strTime);

        return 0;
}

这段c代码输出结果是:

2018-04-04 16:07:00

我们看到strftime采用“字符化”的占位符(诸如:%Y、%m等)“拼”出时间的目标输出格式布局(如:”%Y-%m-%d %H:%M:%S”),这种方式不仅在C中采用,很多其他主流编程语言也采用了该方案,比如:shell、pythonrubyjava等,这似乎已经成为了各种编程语言在时间格式化输出的标准。这些占位符对应的字符(比如Y、M、H)是对应英文单词的头母,因此相对来说较为容易记忆。

但是如果你在Go中使用strftime的这套“标准”,看到输出结果的那一刻,你肯定要“骂娘”!

// writing-go-code-issues/3rd-issue/time-format/timeformat_in_c_way.go
package main

import (
    "fmt"
    "time"
)

func main() {
    fmt.Println(time.Now().Format("%Y-%m-%d %H:%M:%S"))
}

上述go代码输出结果如下:

%Y-%m-%d %H:%M:%S

Go居然将“时间格式占位符字符串”原封不动的输出了!

这是因为Go另辟了蹊径,采用了不同于strftime的时间格式化输出的方案。Go的设计者主要出于这样的考虑:虽然strftime的单个占位符使用了对应单词的首字母的形式,但是但真正写起代码来,不打开strftime函数的manual或查看网页版的strftime助记符说明,很难真的拼出一个复杂的时间格式。并且对于一个”%Y-%m-%d %H:%M:%S”的格式串,不对照文档,很难在大脑中准确给出格式化后的时间结果,比如%Y和%y有何不同、%M和%m又有何差别呢?

Go语言采用了更为直观的“参考时间(reference time)”替代strftime的各种标准占位符,使用“参考时间”构造出来的“时间格式串”与最终输出串是“一模一样”的,这就省去了程序员再次在大脑中对格式串进行解析的过程:

格式串:"2006年01月02日 15时04分05秒"

=>

输出结果:2018年04月04日 18时13分08秒

标准的参考时间如下:

2006-01-02 15:04:05 PM -07:00 Jan Mon MST

这个绝对时间本身并没有什么实际意义,仅是出于“好记”的考虑,我们将这个参考时间换为另外一种时间输出格式:

01/02 03:04:05PM '06 -0700

我们看出Go设计者的“用心良苦”,这个时间其实恰好是将助记符从小到大排序(从01到07)的结果,可以理解为:01对应的是%M, 02对应的是%d等等。下面这幅图形象地展示了“参考时间”、“格式串”与最终格式化的输出结果之间的关系:

img{512x368}

就我个人使用go的经历来看,我在做时间格式化输出时,尤其是构建略微复杂的时间格式输出时,也还是要go doc time包或打开time包的web手册的。从社区的反馈来看,很多Gopher也都有类似经历,尤其是那些已经用惯了strftime格式的gopher。甚至有人专门做了“Fucking Go Date Format”页面,来帮助自动将strftime使用的格式转换为go time的格式。

下面这幅cheatsheet也能提供一些帮助(由writing-go-code-issues/3rd-issue/time-format/timeformat_cheatsheet.go输出生成):

img{512x368}

二. 库与工具篇

1. golang.org/x/text/encoding/unicode遇坑一则

gocmpp这个项目中,我用到了unicode字符集转换:将utf8转换为ucs2(utf16)、ucs2转换为utf8、utf8转为GB18030等。这些转换功能,我是借助golang.org/x/text这个项目下的encoding/unicode和transform实现的。x/text是golang官方维护的text处理的工具包,其中包含了对unicode字符集的相关操作。

要实现一个utf8到ucs2(utf16)的字符集转换,只需像如下这样实现即可(这也是我的最初实现):

func Utf8ToUcs2(in string) (string, error) {
    if !utf8.ValidString(in) {
        return "", ErrInvalidUtf8Rune
    }

    r := bytes.NewReader([]byte(in))

    //UTF-16 bigendian, no-bom
    t := transform.NewReader(r, unicode.All[1].NewEncoder())
    out, err := ioutil.ReadAll(t)
    if err != nil {
        return "", err
    }
    return string(out), nil
}

这里要注意是unicode.All这个切片保存着UTF-16的所有格式:

var All = []encoding.Encoding{
    UTF16(BigEndian, UseBOM),
    UTF16(BigEndian, IgnoreBOM),
    UTF16(LittleEndian, IgnoreBOM),
}

这里我最初我用的是All[1],即UTF16(BigEndian, IgnoreBOM),一切都是正常的。

但就在年前,我将text项目更新到最新版本,然后发现单元测试无法通过:

--- FAIL: TestUtf8ToUcs2 (0.00s)
    utils_test.go:58: The first char is fe, not equal to expected 6c
FAIL
FAIL    github.com/bigwhite/gocmpp/utils    0.008s

经查找发现:text项目的golang.org/x/text/encoding/unicode包做了不兼容的修改,上面那个unicode.All切片变成了下面这个样子:

// All lists a configuration for each IANA-defined UTF-16 variant.
var All = []encoding.Encoding{
    UTF8,
    UTF16(BigEndian, UseBOM),
    UTF16(BigEndian, IgnoreBOM),
    UTF16(LittleEndian, IgnoreBOM),
}

All切片在最前面插入了一个UTF8元素,这样导致我的代码中原本使用的 UTF16(BigEndian, IgnoreBOM)变成了UTF16(BigEndian, UseBOM),test不过也就情有可原了。

如何改呢?这回儿我直接使用UTF16(BigEndian, IgnoreBOM),而不再使用All切片了:

func Utf8ToUcs2(in string) (string, error) {
    if !utf8.ValidString(in) {
        return "", ErrInvalidUtf8Rune
    }

    r := bytes.NewReader([]byte(in))
    //UTF-16 bigendian, no-bom
    t := transform.NewReader(r,
            unicode.UTF16(unicode.BigEndian, unicode.IgnoreBOM).NewEncoder())
    out, err := ioutil.ReadAll(t)
    if err != nil {
        return "", err
    }
    return string(out), nil
}

这样即便All切片再有什么变动,我的代码也不会受到什么影响了。

2. logrus的非结构化日志定制输出

在该系列的第一篇文章中,我提到过使用logrus+lumberjack来实现支持rotate的logging。

默认情况下日志的输出格式是这样的(writing-go-code-issues/3rd-issue/logrus/logrus2lumberjack_default.go):

time="2018-04-05T06:08:53+08:00" level=info msg="logrus log to lumberjack in normal text formatter"

这样相对结构化的日志比较适合后续的集中日志分析。但是日志携带的“元信息(time、level、msg)”过多,并不是所有场合都倾向于这种日志,于是我们期望以普通的非结构化的日志输出,我们定制formatter:

// writing-go-code-issues/3rd-issue/logrus/logrus2lumberjack.go
func main() {
    customFormatter := &logrus.TextFormatter{
        FullTimestamp:   true,
        TimestampFormat: "2006-01-02 15:04:05",
    }
    logger := logrus.New()
    logger.Formatter = customFormatter

    rotateLogger := &lumberjack.Logger{
        Filename: "./foo.log",
    }
    logger.Out = rotateLogger
    logger.Info("logrus log to lumberjack in normal text formatter")
}

我们使用textformatter,并定制了时间戳的格式,输出结果如下:

time="2018-04-05 06:22:57" level=info msg="logrus log to lumberjack in normal text formatter"

日志仍然不是我们想要的那种。但同样的customFormatter如果输出到terminal,结果却是我们想要的:

//writing-go-code-issues/3rd-issue/logrus/logrus2tty.go

INFO[2018-04-05 06:26:16] logrus log to tty in normal text formatter

到底如何设置TextFormatter的属性才能让我们输出到lumberjack中的日志格式是我们想要的这种呢?无奈下只能挖logrus的源码了,我们找到了这段代码:

//github.com/sirupsen/logrus/text_formatter.go

// Format renders a single log entry
func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
    ... ...
    isColored := (f.ForceColors || f.isTerminal) && !f.DisableColors

    timestampFormat := f.TimestampFormat
    if timestampFormat == "" {
        timestampFormat = defaultTimestampFormat
    }
    if isColored {
        f.printColored(b, entry, keys, timestampFormat)
    } else {
        if !f.DisableTimestamp {
            f.appendKeyValue(b, "time", entry.Time.Format(timestampFormat))
        }
        f.appendKeyValue(b, "level", entry.Level.String())
        if entry.Message != "" {
            f.appendKeyValue(b, "msg", entry.Message)
        }
        for _, key := range keys {
            f.appendKeyValue(b, key, entry.Data[key])
        }
    }

    b.WriteByte('\n')
    return b.Bytes(), nil
}

我们看到如果isColored为false,输出的就是带有time, msg, level的结构化日志;只有isColored为true才能输出我们想要的普通日志。isColored的值与三个属性有关:ForceColors 、isTerminal和DisableColors。我们按照让isColored为true的条件组合重新设置一下这三个属性,因为输出到file,因此isTerminal自动为false。

//writing-go-code-issues/3rd-issue/logrus/logrus2lumberjack_normal.go
func main() {
    //    isColored := (f.ForceColors || f.isTerminal) && !f.DisableColors
    customFormatter := &logrus.TextFormatter{
        FullTimestamp:   true,
        TimestampFormat: "2006-01-02 15:04:05",
        ForceColors:     true,
    }
    logger := logrus.New()
    logger.Formatter = customFormatter

    rotateLogger := &lumberjack.Logger{
        Filename: "./foo.log",
    }
    logger.Out = rotateLogger
    logger.Info("logrus log to lumberjack in normal text formatter")
}

我们设置ForceColors为true后,在foo.log中得到了我们期望的输出结果:

INFO[2018-04-05 06:33:22] logrus log to lumberjack in normal text formatter

三. 实践篇

1. 说说网络数据读取timeout的处理 – 以SetReadDeadline为例

Go天生适合于网络编程,但网络编程的复杂性也是有目共睹的、要写出稳定、高效的网络端程序,需要的考虑的因素有很多。比如其中之一的:从socket读取数据超时的问题。

Go语言标准网络库并没有实现epoll实现的那样的“idle timeout”,而是提供了Deadline机制,我们用一副图来对比一下两个机制的不同:

img{512x368}

看上图a)和b)展示了”idle timeout”机制,所谓idle timeout就是指这个timeout是真正在没有data ready的情况的timeout(如图中a),如果有数据ready可读(如图中b),那么timeout机制暂停,直到数据读完后,再次进入数据等待的时候,idle timeout再次启动。

而deadline(以read deadline为例)机制,则是无论是否有数据ready以及数据读取活动,都会在到达时间(deadline)后的再次read时返回timeout error,并且后续的所有network read operation也都会返回timeout(如图中d),除非重新调用SetReadDeadline(time.Time{})取消Deadline或在再次读取动作前重新重新设定deadline实现续时的目的。Go网络编程一般是“阻塞模型”,那为什么还要有SetReadDeadline呢,这是因为有时候,我们要给调用者“感知”其他“异常情况”的机会,比如是否收到了main goroutine发送过来的退出通知信息

Deadline机制在使用起来很容易出错,这里列举两个曾经遇到的出错状况:

a) 以为SetReadDeadline后,后续每次Read都可能实现idle timeout

img{512x368}

在上图中,我们看到这个流程是读取一个完整业务包的过程,业务包的读取使用了三次Read调用,但是只在第一次Read前调用了SetReadDeadline。这种使用方式仅仅在Read A时实现了足额的“idle timeout”,且仅当A数据始终未ready时会timeout;一旦A数据ready并已经被Read,当Read B和Read C时,如果还期望足额的“idle timeout”那就误解了SetReadDeadline的真正含义了。因此要想在每次Read时都实现“足额的idle timeout”,需要在每次Read前都重新设定deadline。

b) 一个完整“业务包”分多次读取的异常情况的处理

img{512x368}

在这幅图中,每个Read前都重新设定了deadline,那么这样就一定ok了么?对于在一个过程中读取一个“完整业务包”的业务逻辑来说,我们还要考虑对每次读取异常情况的处理,尤其是timeout发生。在该例子中,有三个Read位置需要考虑异常处理。

如果Read A始终没有读到数据,deadline到期,返回timeout,这里是最容易处理的,因为此时前一个完整数据包已经被读完,新的完整数据包还没有到来,外层控制逻辑收到timeout后,重启再次启动该读流程即可。

如果Read B或Read C处没有读到数据,deadline到期,这时异常处理就棘手一些,因为一个完整数据包的部分数据(A)已经从流中被读出,剩余的数据并不是一个完整的业务数据包,不能简单地再在外层控制逻辑中重新启动该过程。我们要么在Read B或Read C处尝试多次重读,直到将完整数据包读取完整后返回;要么认为在B或C处出现timeout是不合理的,返回区别于A处的错误码给外层控制逻辑,让外层逻辑决定是否是连接存在异常。

注:本文所涉及的示例代码,请到这里下载。


微博:@tonybai_cn
微信公众号:iamtonybai
github.com: https://github.com/bigwhite

微信赞赏:
img{512x368}

如发现本站页面被黑,比如:挂载广告、挖矿等恶意代码,请朋友们及时联系我。十分感谢! Go语言第一课 Go语言进阶课 AI原生开发工作流实战 Go语言精进之路1 Go语言精进之路2 Go语言第一课 Go语言编程指南
商务合作请联系bigwhite.cn AT aliyun.com
这里是 Tony Bai的个人Blog,欢迎访问、订阅和留言! 订阅Feed请点击上面图片

如果您觉得这里的文章对您有帮助,请扫描上方二维码进行捐赠 ,加油后的Tony Bai将会为您呈现更多精彩的文章,谢谢!

如果您希望通过微信捐赠,请用微信客户端扫描下方赞赏码:

如果您希望通过比特币或以太币捐赠,可以扫描下方二维码:

比特币:

以太币:

如果您喜欢通过微信浏览本站内容,可以扫描下方二维码,订阅本站官方微信订阅号“iamtonybai”;点击二维码,可直达本人官方微博主页^_^:
本站Powered by Digital Ocean VPS。
选择Digital Ocean VPS主机,即可获得10美元现金充值,可 免费使用两个月哟! 著名主机提供商Linode 10$优惠码:linode10,在 这里注册即可免费获 得。阿里云推荐码: 1WFZ0V立享9折!


View Tony Bai's profile on LinkedIn
DigitalOcean Referral Badge

文章

评论

  • 正在加载...

分类

标签

归档



View My Stats