Beego框架的一条神秘日志引发的思考

公司目前的后台是用Beego框架搭的，并且为了服务的不中断升级，我们开启了Beego的Grace模块，用于热升级支持。一切都跑井然有序，直到有一天，领导甩出一些服务日志，告知程序一直报错：

2018/03/08 17:49:34 20848 Received SIGINT.
2018/03/08 17:49:34 20848 [::]:5490 Listener closed.
2018/03/08 17:49:34 20848 Waiting for connections to finish...
2018/03/08 17:49:34 [C] [asm_amd64.s:2337] ListenAndServe:  accept tcp [::]:5490: use of closed network connection 20848

问题出在第4行，每次服务关闭时，都会报出use of closed network connection。按理说这时候网络连接应该关闭了啊，进程都退出了，怎么还Accept 5490端口？到Beego的Issues列表里一搜，已经有人问过这个问题了(issue2809)，下面还没有人回答，搜也搜索不到，只剩最后一个工具了：看源码。

1. Grace模式

首先可以肯定，不开Grace模式的话，是没有这些日志打出来的，而是直接结束。因此我们先要对Beego的Grace模式有一些了解。Beego官网对此一定的介绍：Grace模块。大致是说他们参照：Grace_restart_in_golang这篇文章的思路实现的热升级功能，文章很长，讲述的思路很清晰，大体过程如下：

开源中国翻译-GracefulRestart 这篇中文翻译说明的更通俗易懂。明白了热升级的原理，我们就可以进入代码中详细寻找了。一切都从beego.Run()开始。

beego.Run()创建好了BeeApp对象，并且调用BeeApp.Run()执行。Run方法有不同的启动模式，在此，我们只关注Grace部分。

func (app *App) Run() {
    addr := BConfig.Listen.HTTPAddr
    ...

    // run graceful mode
    if BConfig.Listen.Graceful {
        ...
        if BConfig.Listen.EnableHTTP {
            go func() {
                // 创建了GraceServer 是对http.Server的一层封装
                server := grace.NewServer(addr, app.Handlers)
                ...
                if err := server.ListenAndServe(); err != nil {
                    logs.Critical("ListenAndServe: ", err, fmt.Sprintf("%d", os.Getpid()))
                    endRunning <- true
                }
            }()
        }
        <-endRunning
        return
    }
    ...
}

代码里可以看到，logs.Critical("ListenAndServe: ", err, fmt.Sprintf("%d", os.Getpid()))正是打出上述日志的源头：

2018/03/08 17:49:34 [C] [asm_amd64.s:2337] ListenAndServe:  accept tcp [::]:5490: use of closed network connection 20848

那么为什么会返回use of closed network connection这个错误呢？跟进ListenAndServe()方法中查看：

func (srv *Server) ListenAndServe() (err error) {
    ...
    // 处理上图中的热升级信号(fork子进程)，SIGINT、SIGTERM信号（进程结束信号）
    go srv.handleSignals()

    ...
    // 如果是子进程执行，Getppid()拿到父进程pid，并且Kill
    if srv.isChild {
        process, err := os.FindProcess(os.Getppid())
        if err != nil {
            log.Println(err)
            return err
        }
        err = process.Kill()
        if err != nil {
            return err
        }
    }

    log.Println(os.Getpid(), srv.Addr)
    return srv.Serve()
}

跟进Serve()方法：

func (srv *Server) Serve() (err error) {
    srv.state = StateRunning
    //这里我们传入了一个GraceListener，对net.Listener做了封装，在后面会用到。
    err = srv.Server.Serve(srv.GraceListener)
    log.Println(syscall.Getpid(), "Waiting for connections to finish...")
    //此处会等待所有连接处理完成，对应图中的父进程结束流程。
    srv.wg.Wait()
    srv.state = StateTerminate
    return
}

还是调回了http.Server.Serve()方法，看这个方法：

 func (srv *Server) Serve(l net.Listener) error {
    defer l.Close()
    ...

    for {
        //代码在这里阻塞，如果没有连接进来的话。
        rw, e := l.Accept()
        if e != nil {
            select {
            //正常的结束流程
            case <-srv.getDoneChan():
                return ErrServerClosed
            default:
            }
            ...

            //不正常的结束流程
            return e
        }

        //开启一个go程处理新连接
        c := srv.newConn(rw)
        go c.serve(ctx)
    }
}

如果是正常结束，我们应该会收到ErrServerClosed，这虽然是个Error，但是类似于io.EOF，是一个正常的结束流程，问题在于，我们收到的并不是ServerClosed，而是use of closed connection，由l.Accept()方法返回，那我们进到Accept()一探究竟。

2.Accept家族

前面说了，l.Accept()中l是一个GraceListener，那我们直接去看它的Accept()方法。

func (gl *graceListener) Accept() (c net.Conn, err error) {
    //调AcceptTCP()
    tc, err := gl.Listener.(*net.TCPListener).AcceptTCP()
    if err != nil {
        return
    }

    ...

    //每次新来一个连接+1，当连接处理完成时-1。 前面wg.Wait()等的就是这个值减为0。
    gl.server.wg.Add(1)
    return
}

还是调回了net.TCPListener的AcceptTCP()，去TCPListener下看看它的AcceptTCP()：

func (l *TCPListener) AcceptTCP() (*TCPConn, error) {
    ...
    c, err := l.accept()
    if err != nil {
        return nil, &OpError{Op: