Mockeagain++ differs in behavior of mockeagain when running ngx_postgres's tests

[agentzh]

I've noted that mockeagain can successfully detect potential issues in libpq while running the ngx_postgres module's test suite in "writing mode" while mockeagain++ fails. mockeagain++ finds nothing in either the poll mode or the default epoll mode.

We're expecting a lot of test failures in mockeagain's writing mode, as demonstrated below:

https://qa.openresty.org/linux_x86_64_nginx_1_11_2__no_pool__ngx_postgres_w.html

Will you dig it up? It looks strange :) There shouldn't be any differences between mockeagain and mockeagain++ here.

The environments I'm setting during my test:

export TEST_NGINX_EVENT_TYPE=poll
export MOCKEAGAIN=w
export TEST_NGINX_POSTPONE_OUTPUT=1
#export LD_PRELOAD="$HOME/git/mockeagain/mockeagain.so $LD_PRELOAD"
export LD_PRELOAD="$HOME/git/mockeagainxx/mockeagainxx.so $LD_PRELOAD"

Thanks!

[agentzh]

Seems like for some reasons, mockeagain++ thinks that the send() call initiated by libpq is not active according to the error logs:

mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.
mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.
2017/01/12 13:49:06 [debug] 88906#88906: *1 postgres: sending query: "SELECT * FROM cats ORDER BY id ASC"
mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.
2017/01/12 13:49:06 [debug] 88906#88906: *1 postgres: sending query: "SELECT * FROM cats ORDER BY id DESC"
mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.
2017/01/12 13:49:06 [debug] 88906#88906: *3 postgres: sending query: "SELECT * FROM cats ORDER BY id ASC"
mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.
2017/01/12 13:49:06 [debug] 88906#88906: *3 postgres: sending query: "SELECT * FROM cats ORDER BY id DESC"
mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.
mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.

While mockeagain gives the following nginx error logs:

mockeagain: mocking "send" on fd 7 to emit 1 byte data only
2017/01/12 13:47:08 [error] 88875#88875: *1 postgres: connection failed: could not send startup packet: Resource temporarily unavailable
mockeagain: mocking "send" on fd 7 to emit 1 byte data only
2017/01/12 13:47:08 [error] 88875#88875: *1 postgres: connection failed: could not send startup packet: Resource temporarily unavailable
mockeagain: mocking "send" on fd 7 to emit 1 byte data only
2017/01/12 13:47:08 [error] 88875#88875: *4 postgres: connection failed: could not send startup packet: Resource temporarily unavailable
mockeagain: mocking "send" on fd 7 to emit 1 byte data only
2017/01/12 13:47:08 [error] 88875#88875: *4 postgres: connection failed: could not send startup packet: Resource temporarily unavailable

[agentzh]

Okay, I've noted that the send() calls initiated by libdrizzle in the drizzle-nginx-module project are also always inactive under mockeagain++:

mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.
2017/01/12 13:53:23 [debug] 88976#0: *1 drizzle sending query "select * from cats"
mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.
2017/01/12 13:53:23 [debug] 88976#0: *1 drizzle libdrizzle returned IO_WAIT while sending query
2017/01/12 13:53:23 [debug] 88976#0: *1 drizzle sending query "select * from cats"
2017/01/12 13:53:23 [debug] 88976#0: *1 drizzle libdrizzle returned IO_WAIT while sending query
2017/01/12 13:53:23 [debug] 88976#0: *1 drizzle sending query "select * from cats"
mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.
2017/01/12 13:53:23 [debug] 88976#0: *3 drizzle sending query "select * from cats"
mockeagainxx: [LOG] send mocking is not active at mockeagainxx.c line 631.
2017/01/12 13:53:23 [debug] 88976#0: *3 drizzle libdrizzle returned IO_WAIT while sending query
2017/01/12 13:53:23 [debug] 88976#0: *3 drizzle sending query "select * from cats"
2017/01/12 13:53:23 [debug] 88976#0: *3 drizzle libdrizzle returned IO_WAIT while sending query
2017/01/12 13:53:23 [debug] 88976#0: *3 drizzle sending query "select * from cats"

In contrast, the logs for mockeagain and the same ngx_drizzle test case do show the expected behavior:

mockeagain: mocking "send" on fd 7 to emit 1 byte data only
mockeagain: mocking "send" on fd 7 to signal EAGAIN
mockeagain: mocking "send" on fd 7 to signal EAGAIN
mockeagain: mocking "send" on fd 7 to emit 1 byte data only
mockeagain: mocking "send" on fd 7 to signal EAGAIN
mockeagain: mocking "send" on fd 7 to emit 1 byte data only
mockeagain: mocking "send" on fd 7 to signal EAGAIN
mockeagain: mocking "send" on fd 7 to emit 1 byte data only
mockeagain: mocking "send" on fd 7 to signal EAGAIN
mockeagain: mocking "send" on fd 7 to emit 1 byte data only
mockeagain: mocking "send" on fd 7 to signal EAGAIN
mockeagain: mocking "send" on fd 7 to emit 1 byte data only
mockeagain: mocking "send" on fd 7 to signal EAGAIN
mockeagain: mocking "send" on fd 7 to emit 1 byte data only
mockeagain: mocking "send" on fd 7 to signal EAGAIN
mockeagain: mocking "send" on fd 7 to emit 1 byte data only
...

So it looks like a bug in mockeagain++? Will you confirm?

[dndx]

Yes the mocking is not enabled with libpq due to the fact that mockeagain++ doesn't hook fcntl() which is used by libpq to make a file descriptor non-blocking. When mockeagain++ can't be sure that the file is in non-blocking mode, mocking is disabled.

I actually did tried to hook fcntl(), but since it's third argument is optional (depends on the operation), it is a bit tricky and will require a bit more work.

[agentzh]

@dndx I think you can just always just add the 3rd argument to your C function? You can first check the 2nd argument to determine if the 3rd argument should also be inspected. I guess this should be harmless.

[dndx]

@agentzh The size of the third argument is actually a concern as on a 64-bit platform, it could be 64 or 32 bits depending on cmd. If we use something like uintptr_t as the third argument, we might read more bytes than we should if user application only passed in an int.

I tried to use correctly sized types by inspecting cmd and using variadic arguments macros. Please give hook_fcntl a try and let me know how it works.

[agentzh]

@dndx I don't think that would be an issue at least on x86_64 since the 3rd argument of the function call is always passed in a CPU register anyway, according to the x86_64 calling convention :) So we cannot read across memory page boundaries.

[agentzh]

@dndx I've just tried your hook_fcntl branch and it seems that perl (Test::Nginx) enters an infinite hot loop at 100% CPU usage.

[dndx]

@agentzh Looks like test-nginx uses non-blocking socket while connecting to nginx. It also uses select() for event polling, which mockeagain++ doesn't hook yet! Therefore, mockeagain++ will think that Perl haven't polled the fd (despite it did with select()), causing it to keep returning EAGAIN indefinitely.

Luckily, hooking select() is not the hardest thing in the world. I will be working on it shortly.

Since mockeagain does not start mocking until after a fd is poll()ed, it won't run into this issue.

[agentzh]

@dndx Yes, Test::Nginx::Socket uses nonblocking sockets and select(). Thanks for your hard work on this! :)