ngx_lua与waitpid() failed错误

lancelijade · 2012-09-05T15:29:30+00:00

Hello! 2012/9/4 smallfish <small...@gmail.com>: > 恩，已经测试通过。多谢春&...

ngx_lua与waitpid() failed错误

lancelijade

hi agentzh,

发现一个报错，应该与ngx_lua中执行os.execute有关，以下是相关配置

nginx.conf:
---------
user nobody;
worker_processes 8;
worker_rlimit_nofile 65535;

error_log /data/logs/error.log;
pid        /data/logs/nginx.pid;

events {
    use epoll;
    worker_connections 4096;
}

http {
    access_log /data/logs/ngx_access.log combined;
    error_log /data/logs/ngx_error.log notice;

    lua_code_cache off;

    server
    {
        listen 80 default backlog=8192;

        location /w {
            content_by_lua_file "conf/w.lua";
        }
    }
}

========================

w.lua 只有两行:

os.execute("/bin/mkdir -p /tmp/xx")
ngx.exit(ngx.HTTP_OK)

每次请求 /usr/bin/curl "http://localhost/w/x"，在 /data/logs/error.log 里会多一条错误日志
2012/09/05 15:25:10 [alert] 13215#0: waitpid() failed (10: No child processes)

这时目标目录已经创建成功了
drwxrwxrwx 2 nobody nobody 4096 Sep 5 15:20 xx

有一个奇怪之处是这个日志写在了全局的 error.log 里，而不是http段的 ngx_error.log里，应该是个bug？

Lance

fengmo.q

hi,

这个不是bug，这条错误日志打印的上下文是信号处理的上下文，此上下文和任何连接/请求都无关，当然也不会使用http模块当中设置的error log，实际上使用的是ngx_cycle->log，这里ngx_cycle为全局变量，在信号处理上下文中是可以访问到的。

而ngx_cycle->log就是你在main conf中设置的error_log指令指定的文件 /data/logs/error.log。

在 2012年9月5日下午3:29，Lance <lance...@gmail.com>写道：

hi agentzh,

发现一个报错，应该与ngx_lua中执行os.execute有关，以下是相关配置

nginx.conf:
---------
user nobody;
worker_processes 8;
worker_rlimit_nofile 65535;

error_log /data/logs/error.log;
pid        /data/logs/nginx.pid;

events {
    use epoll;
    worker_connections 4096;
}

http {
    access_log /data/logs/ngx_access.log combined;
    error_log /data/logs/ngx_error.log notice;

    lua_code_cache off;

    server
    {
        listen 80 default backlog=8192;

        location /w {
            content_by_lua_file "conf/w.lua";
        }
    }
}

========================

w.lua 只有两行:

os.execute("/bin/mkdir -p /tmp/xx")
ngx.exit(ngx.HTTP_OK)

每次请求 /usr/bin/curl "http://localhost/w/x"，在 /data/logs/error.log 里会多一条错误日志
2012/09/05 15:25:10 [alert] 13215#0: waitpid() failed (10: No child processes)

这时目标目录已经创建成功了
drwxrwxrwx 2 nobody nobody 4096 Sep 5 15:20 xx

有一个奇怪之处是这个日志写在了全局的 error.log 里，而不是http段的 ngx_error.log里，应该是个bug？

Lance

Jinglong
Software Engineer
Server Platforms Team at Taobao

lancelijade

那这样一条操作为什么打出错误日志呢？而且mkdir本身也已经成功了啊

On Wednesday, September 5, 2012 12:59:09 AM UTC-7, jinglong wrote:

hi,

这个不是bug，这条错误日志打印的上下文是信号处理的上下文，此上下文和任何连接/请求都无关，当然也不会使用http模块当中设置的error log，实际上使用的是ngx_cycle->log，这里ngx_cycle为全局变量，在信号处理上下文中是可以访问到的。
而ngx_cycle->log就是你在main conf中设置的error_log指令指定的文件 /data/logs/error.log。

在 2012年9月5日下午3:29，Lance <lance...@gmail.com>写道：
hi agentzh,

发现一个报错，应该与ngx_lua中执行os.execute有关，以下是相关配置

nginx.conf:
---------
user nobody;
worker_processes 8;
worker_rlimit_nofile 65535;

error_log /data/logs/error.log;
pid        /data/logs/nginx.pid;

events {
    use epoll;
    worker_connections 4096;
}

http {
    access_log /data/logs/ngx_access.log combined;
    error_log /data/logs/ngx_error.log notice;

    lua_code_cache off;

    server
    {
        listen 80 default backlog=8192;

        location /w {
            content_by_lua_file "conf/w.lua";
        }
    }
}

========================

w.lua 只有两行:

os.execute("/bin/mkdir -p /tmp/xx")
ngx.exit(ngx.HTTP_OK)

每次请求 /usr/bin/curl "http://localhost/w/x"，在 /data/logs/error.log 里会多一条错误日志
2012/09/05 15:25:10 [alert] 13215#0: waitpid() failed (10: No child processes)

这时目标目录已经创建成功了
drwxrwxrwx 2 nobody nobody 4096 Sep 5 15:20 xx

有一个奇怪之处是这个日志写在了全局的 error.log 里，而不是http段的 ngx_error.log里，应该是个bug？

Lance

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

lancelijade

哦，我明白了，是我表述不太清楚。我想强调的是lua操作成功了但还是打出一条错误日志，这个可能是bug，至于日志打在哪里，说实在的我不太在乎 :)

On Wednesday, September 5, 2012 12:59:09 AM UTC-7, jinglong wrote:

hi,

这个不是bug，这条错误日志打印的上下文是信号处理的上下文，此上下文和任何连接/请求都无关，当然也不会使用http模块当中设置的error log，实际上使用的是ngx_cycle->log，这里ngx_cycle为全局变量，在信号处理上下文中是可以访问到的。
而ngx_cycle->log就是你在main conf中设置的error_log指令指定的文件 /data/logs/error.log。

在 2012年9月5日下午3:29，Lance <lance...@gmail.com>写道：
hi agentzh,

发现一个报错，应该与ngx_lua中执行os.execute有关，以下是相关配置

nginx.conf:
---------
user nobody;
worker_processes 8;
worker_rlimit_nofile 65535;

error_log /data/logs/error.log;
pid        /data/logs/nginx.pid;

events {
    use epoll;
    worker_connections 4096;
}

http {
    access_log /data/logs/ngx_access.log combined;
    error_log /data/logs/ngx_error.log notice;

    lua_code_cache off;

    server
    {
        listen 80 default backlog=8192;

        location /w {
            content_by_lua_file "conf/w.lua";
        }
    }
}

========================

w.lua 只有两行:

os.execute("/bin/mkdir -p /tmp/xx")
ngx.exit(ngx.HTTP_OK)

每次请求 /usr/bin/curl "http://localhost/w/x"，在 /data/logs/error.log 里会多一条错误日志
2012/09/05 15:25:10 [alert] 13215#0: waitpid() failed (10: No child processes)

这时目标目录已经创建成功了
drwxrwxrwx 2 nobody nobody 4096 Sep 5 15:20 xx

有一个奇怪之处是这个日志写在了全局的 error.log 里，而不是http段的 ngx_error.log里，应该是个bug？

Lance

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

fengmo.q

hi，

关于在woker中执行os.execute()为什么会打印 No child processes 这条错误日志，之前我在邮件列表里面就回答过相同的问题。

os.execute()调用的是c里面的system()函数，system函数先fork()子进程执行shell，然后显式调用waitpid()阻塞等待子进程退出，当子进程退出时，回收之。

但是子进程退出会发出SIGCHLD信号，而worker实际上是设置了对该信号的处理函数，所以会捕捉到该信号，在信号处理函数中又会调用waitpid()函数来回收，但是实际上子进程之前已经被回收了，而且该worker又没有其他子进程，此时waitpid返回-1，errno为ECHILD，这时就会打印相关的日志了。

详细的可以看ngx_process_get_status()函数。

在 2012年9月5日下午4:00，Lance Li <lance...@gmail.com>写道：

那这样一条操作为什么打出错误日志呢？而且mkdir本身也已经成功了啊

On Wednesday, September 5, 2012 12:59:09 AM UTC-7, jinglong wrote:

hi,

这个不是bug，这条错误日志打印的上下文是信号处理的上下文，此上下文和任何连接/请求都无关，当然也不会使用http模块当中设置的error log，实际上使用的是ngx_cycle->log，这里ngx_cycle为全局变量，在信号处理上下文中是可以访问到的。

而ngx_cycle->log就是你在main conf中设置的error_log指令指定的文件 /data/logs/error.log。

在 2012年9月5日下午3:29，Lance <lance...@gmail.com>写道：

hi agentzh,

发现一个报错，应该与ngx_lua中执行os.execute有关，以下是相关配置

nginx.conf:
---------
user nobody;
worker_processes 8;
worker_rlimit_nofile 65535;

error_log /data/logs/error.log;
pid        /data/logs/nginx.pid;

events {
    use epoll;
    worker_connections 4096;
}

http {
    access_log /data/logs/ngx_access.log combined;
    error_log /data/logs/ngx_error.log notice;

    lua_code_cache off;

    server
    {
        listen 80 default backlog=8192;

        location /w {
            content_by_lua_file "conf/w.lua";
        }
    }
}

========================

w.lua 只有两行:

os.execute("/bin/mkdir -p /tmp/xx")
ngx.exit(ngx.HTTP_OK)

每次请求 /usr/bin/curl "http://localhost/w/x"，在 /data/logs/error.log 里会多一条错误日志
2012/09/05 15:25:10 [alert] 13215#0: waitpid() failed (10: No child processes)

这时目标目录已经创建成功了
drwxrwxrwx 2 nobody nobody 4096 Sep 5 15:20 xx

有一个奇怪之处是这个日志写在了全局的 error.log 里，而不是http段的 ngx_error.log里，应该是个bug？

Lance

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

Jinglong
Software Engineer
Server Platforms Team at Taobao

fengmo.q

os.execute调用shell的代价很大，而且会阻塞worker，所以建议使用luaposix这一段库来创建目录

在 2012年9月5日下午4:09，pengqi <fen...@gmail.com>写道：

hi，

关于在woker中执行os.execute()为什么会打印 No child processes 这条错误日志，之前我在邮件列表里面就回答过相同的问题。

os.execute()调用的是c里面的system()函数，system函数先fork()子进程执行shell，然后显式调用waitpid()阻塞等待子进程退出，当子进程退出时，回收之。

但是子进程退出会发出SIGCHLD信号，而worker实际上是设置了对该信号的处理函数，所以会捕捉到该信号，在信号处理函数中又会调用waitpid()函数来回收，但是实际上子进程之前已经被回收了，而且该worker又没有其他子进程，此时waitpid返回-1，errno为ECHILD，这时就会打印相关的日志了。

详细的可以看ngx_process_get_status()函数。

在 2012年9月5日下午4:00，Lance Li <lance...@gmail.com>写道：

那这样一条操作为什么打出错误日志呢？而且mkdir本身也已经成功了啊

On Wednesday, September 5, 2012 12:59:09 AM UTC-7, jinglong wrote:

hi,

这个不是bug，这条错误日志打印的上下文是信号处理的上下文，此上下文和任何连接/请求都无关，当然也不会使用http模块当中设置的error log，实际上使用的是ngx_cycle->log，这里ngx_cycle为全局变量，在信号处理上下文中是可以访问到的。

而ngx_cycle->log就是你在main conf中设置的error_log指令指定的文件 /data/logs/error.log。

在 2012年9月5日下午3:29，Lance <lance...@gmail.com>写道：

hi agentzh,

发现一个报错，应该与ngx_lua中执行os.execute有关，以下是相关配置

nginx.conf:
---------
user nobody;
worker_processes 8;
worker_rlimit_nofile 65535;

error_log /data/logs/error.log;
pid        /data/logs/nginx.pid;

events {
    use epoll;
    worker_connections 4096;
}

http {
    access_log /data/logs/ngx_access.log combined;
    error_log /data/logs/ngx_error.log notice;

    lua_code_cache off;

    server
    {
        listen 80 default backlog=8192;

        location /w {
            content_by_lua_file "conf/w.lua";
        }
    }
}

========================

w.lua 只有两行:

os.execute("/bin/mkdir -p /tmp/xx")
ngx.exit(ngx.HTTP_OK)

每次请求 /usr/bin/curl "http://localhost/w/x"，在 /data/logs/error.log 里会多一条错误日志
2012/09/05 15:25:10 [alert] 13215#0: waitpid() failed (10: No child processes)

这时目标目录已经创建成功了
drwxrwxrwx 2 nobody nobody 4096 Sep 5 15:20 xx

有一个奇怪之处是这个日志写在了全局的 error.log 里，而不是http段的 ngx_error.log里，应该是个bug？

Lance

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

Jinglong
Software Engineer
Server Platforms Team at Taobao

lancelijade

明白了，非常感谢，我再研究一下

On Wednesday, September 5, 2012 1:15:32 AM UTC-7, jinglong wrote:

os.execute调用shell的代价很大，而且会阻塞worker，所以建议使用luaposix这一段库来创建目录

在 2012年9月5日下午4:09，pengqi <feng...@gmail.com>写道：

hi，

关于在woker中执行os.execute()为什么会打印 No child processes 这条错误日志，之前我在邮件列表里面就回答过相同的问题。

os.execute()调用的是c里面的system()函数，system函数先fork()子进程执行shell，然后显式调用waitpid()阻塞等待子进程退出，当子进程退出时，回收之。

但是子进程退出会发出SIGCHLD信号，而worker实际上是设置了对该信号的处理函数，所以会捕捉到该信号，在信号处理函数中又会调用waitpid()函数来回收，但是实际上子进程之前已经被回收了，而且该worker又没有其他子进程，此时waitpid返回-1，errno为ECHILD，这时就会打印相关的日志了。

详细的可以看ngx_process_get_status()函数。

在 2012年9月5日下午4:00，Lance Li <lance...@gmail.com>写道：

那这样一条操作为什么打出错误日志呢？而且mkdir本身也已经成功了啊

On Wednesday, September 5, 2012 12:59:09 AM UTC-7, jinglong wrote:

hi,

这个不是bug，这条错误日志打印的上下文是信号处理的上下文，此上下文和任何连接/请求都无关，当然也不会使用http模块当中设置的error log，实际上使用的是ngx_cycle->log，这里ngx_cycle为全局变量，在信号处理上下文中是可以访问到的。

而ngx_cycle->log就是你在main conf中设置的error_log指令指定的文件 /data/logs/error.log。

在 2012年9月5日下午3:29，Lance <lance...@gmail.com>写道：

hi agentzh,

发现一个报错，应该与ngx_lua中执行os.execute有关，以下是相关配置

nginx.conf:
---------
user nobody;
worker_processes 8;
worker_rlimit_nofile 65535;

error_log /data/logs/error.log;
pid        /data/logs/nginx.pid;

events {
    use epoll;
    worker_connections 4096;
}

http {
    access_log /data/logs/ngx_access.log combined;
    error_log /data/logs/ngx_error.log notice;

    lua_code_cache off;

    server
    {
        listen 80 default backlog=8192;

        location /w {
            content_by_lua_file "conf/w.lua";
        }
    }
}

========================

w.lua 只有两行:

os.execute("/bin/mkdir -p /tmp/xx")
ngx.exit(ngx.HTTP_OK)

每次请求 /usr/bin/curl "http://localhost/w/x"，在 /data/logs/error.log 里会多一条错误日志
2012/09/05 15:25:10 [alert] 13215#0: waitpid() failed (10: No child processes)

这时目标目录已经创建成功了
drwxrwxrwx 2 nobody nobody 4096 Sep 5 15:20 xx

有一个奇怪之处是这个日志写在了全局的 error.log 里，而不是http段的 ngx_error.log里，应该是个bug？

Lance

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

--

Jinglong
Software Engineer
Server Platforms Team at Taobao

agentzh

Hello!

2012/9/5 pengqi <fen...@gmail.com>:
> os.execute调用shell的代价很大，而且会阻塞worker，所以建议使用luaposix这一段库来创建目录
>

嗯，是的。

当然，另一种选择是使用 LuaJIT 的 FFI 来从 Lua 直接调用 POSIX 接口，例如我们可以创建下面这个 utils 模块：

    -- utils.lua
    module("utils", package.seeall)

    local ffi = require "ffi"
    local C = ffi.C
    local errno = ffi.errno
    local string = ffi.string

    ffi.cdef[[
        int mkdir(const char *path, int mode);
        char *strerror(int errnum);
    ]]

    function mkdir(path, mode)
        if not mode then
            mode = 0x1FF
        end
        local rc = C.mkdir(path, mode)
        if rc ~= 0 then
            return false, string(C.strerror(errno()))
        end

        return true
    end

然后使用下面这个 nginx location 来测试一下：

    location ~ '^/t/(\w+)$' {
        content_by_lua '
            local utils = require "utils"
            local dir = ngx.var[1]
            local ok, err = utils.mkdir("/tmp/" .. dir)
            if not ok then
                ngx.say("failed to mkdir ", dir, ": ", err)
                return
            end

            ngx.say("directory ", dir, " created!")
        ';
    }

请求之：

    $ rm -rf /tmp/foo

    $ curl localhost:1984/t/foo
    directory foo created!

    $ curl localhost:1984/t/foo
    failed to mkdir foo: File exists

使用 FFI 来调用 C API 在效率上应当会高于传统的 C 模块，因为 JIT 编译器会直接内联 C 调用。

Best regards,
-agentzh

lancelijade

io.*也会阻塞worker吗？ffi呢？

发自我的 iPad

在 Sep 6, 2012，2:41 AM，agentzh <age...@gmail.com> 写道：

> Hello!
> 
> 2012/9/5 pengqi <fen...@gmail.com>:
>> os.execute调用shell的代价很大，而且会阻塞worker，所以建议使用luaposix这一段库来创建目录
>> 
> 
> 嗯，是的。
> 
> 当然，另一种选择是使用 LuaJIT 的 FFI 来从 Lua 直接调用 POSIX 接口，例如我们可以创建下面这个 utils 模块：
> 
>    -- utils.lua
>    module("utils", package.seeall)
> 
>    local ffi = require "ffi"
>    local C = ffi.C
>    local errno = ffi.errno
>    local string = ffi.string
> 
>    ffi.cdef[[
>        int mkdir(const char *path, int mode);
>        char *strerror(int errnum);
>    ]]
> 
>    function mkdir(path, mode)
>        if not mode then
>            mode = 0x1FF
>        end
>        local rc = C.mkdir(path, mode)
>        if rc ~= 0 then
>            return false, string(C.strerror(errno()))
>        end
> 
>        return true
>    end
> 
> 然后使用下面这个 nginx location 来测试一下：
> 
>    location ~ '^/t/(\w+)$' {
>        content_by_lua '
>            local utils = require "utils"
>            local dir = ngx.var[1]
>            local ok, err = utils.mkdir("/tmp/" .. dir)
>            if not ok then
>                ngx.say("failed to mkdir ", dir, ": ", err)
>                return
>            end
> 
>            ngx.say("directory ", dir, " created!")
>        ';
>    }
> 
> 请求之：
> 
>    $ rm -rf /tmp/foo
> 
>    $ curl localhost:1984/t/foo
>    directory foo created!
> 
>    $ curl localhost:1984/t/foo
>    failed to mkdir foo: File exists
> 
> 使用 FFI 来调用 C API 在效率上应当会高于传统的 C 模块，因为 JIT 编译器会直接内联 C 调用。
> 
> Best regards,
> -agentzh
> 
>

agentzh

Hello!

2012/9/5 Lance Li <lance...@gmail.com>:
> io.*也会阻塞worker吗？ffi呢？
>

文件系统相关操作的系统调用都会阻塞，除非启用了 AIO :) 相对于一般更不可控的网络 I/O，少量的磁盘 I/O 的阻塞效应倒不一定会成为瓶颈 :)

Best regards,
-agentzh