Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix uv.shutdown cb being called when canceled #414

Closed
wants to merge 1 commit into from

Conversation

squeek502
Copy link
Member

@squeek502 squeek502 commented Oct 14, 2019

This could happen during lua_close, and after absolutely all handles have been closed, so there's no point in running the callback.

I'm not sure, but there might be other legitimate situations where UV_ECANCELED should be passed along to the callback. If so, then there would need to be a more involved fix here to handle when the stream is closed via lua_close/__gc


This is something I found when looking at our CI's PROCESS_CLEANUP_TEST jobs (see #193 and #194 for when/why they exist) and noticing that they were throwing a Lua error (and somehow not failing the CI?). I think this has been broken for a long time (likely ever since uv_handle_t got a __gc that closed itself).

This is what happens when running ./tests/test-sigchld-after-lua_close.sh

{ pid = 5757, handle = uv_process_t: 0xbdfed0 }
Uncaught Error: examples/talking-to-children.lua:28: bad argument #1 to 'close' (Expected uv_handle userdata)
stack traceback:
	[C]: in function 'luv.close'
	examples/talking-to-children.lua:28: in function <examples/talking-to-children.lua:27>
	[C]: in ?

This is not caused by not passing in a uv_handle userdata, but rather because the uv_handle has been closed, and onshutdown is being called during lua_close. Adding a print statement to the onshutdown callback gives you this:

Uncaught Error: ./lib/utils.lua:155: bad argument #1 to 'tostring' (Expected uv_handle userdata)
stack traceback:
        [C]: in function 'tostring'
        ./lib/utils.lua:155: in function 'print'
        examples/talking-to-children.lua:28: in function <examples/talking-to-children.lua:27>

i.e. the __tostring metamethod of the userdata is failing because the userdata is a closed (via __gc) uv_stream_t.

This could happen after lua_close, and after absolutely all handles have been closed/freed, so there's no point in running the callback.

There might be other legitimate situations where UV_ECANCELED should be passed along to the callback. If so, then there would need to be a more involved fix here to handle when the stream is closed via lua_close/__gc
@squeek502
Copy link
Member Author

squeek502 commented Oct 15, 2019

Some debug printing to better explain what's happening:

luv_shutdown called with handle: 000000000035FF50 -> req: 00000000001E8DE0
handle gc | 00000000003601D0 -> not closed, closing
handle gc | 000000000035FF50 -> not closed, closing
loop gc
-> uv_walk
-> uv_run
-> uv_process_endgames
-> uv_pipe_endgame
-> req->cb(req, UV_ECANCELED);
luv_shutdown_cb called for req: 00000000001E8DE0

cb called    ECANCELED
Uncaught Error: bad argument #1 to '?' (Expected uv_handle userdata)
stack traceback:
        [C]: at 0x07fee3d32da0
        [C]: in function 'print'
        test.lua:24: in function <test.lua:22>
        [C]: at 0x07fee3d49950

Minimal reproduction:

local uv = require('luv')

local stdin = uv.new_pipe(false)

local process, pid = uv.spawn(jit.os == "Windows" and "cmd.exe" or "cat", {
  stdio = {stdin, nil, nil}
})

assert(uv.shutdown(stdin, function(...)
  print("cb called", ...)
  print(process)
end))

@squeek502
Copy link
Member Author

squeek502 commented Oct 15, 2019

Worth noting that doing this from the Lua side also fixes this particular case:

uv.shutdown(stdin, function(err)
  if err == "ECANCELED" then
    return
  end
  print(process)
end)

So instead of doing this on the C side we could call the callback with ECANCELED (even during lua_close) and it would be up to the user to handle that case in their callback.

@zhaozg
Copy link
Member

zhaozg commented Oct 15, 2019

So instead of doing this on the C side we could call the callback with ECANCELED (even during lua_close) and it would be up to the user to handle that case in their callback.

What is prefer solution, lua side or c side?
In c silde will never fire callback when err is "ECANCELED"

@squeek502
Copy link
Member Author

squeek502 commented Oct 15, 2019

I think it would be better on the C side if we can be sure that UV_ECANCELED is only possible during lua_close/loop_gc. I'm not sure if that's true yet, though. I'll do some more testing.

@zhaozg
Copy link
Member

zhaozg commented Oct 15, 2019

https://github.com/libuv/libuv/search?q=UV_ECANCELED&unscoped_q=UV_ECANCELED shows some api will cause UV_ECANCELED, e.g. uv_cancel()

@zhaozg
Copy link
Member

zhaozg commented Nov 1, 2019

this should be merge now?

test-sigchld-after-lua_close.sh is still 'passing' even though the Lua script is throwing an error. Once that's fixed, though, it will depend on #414 in order to fix the Lua execution error (I still need to investigate #414 (comment) more before I merge that).

@squeek502
Copy link
Member Author

Don't want to merge it yet, still not sure if handling this on the C side is correct and want to do some more testing.

Take a look at #433, it's the more important thing to get fixed first.

@squeek502
Copy link
Member Author

Going to focus on this today.

@squeek502
Copy link
Member Author

squeek502 commented Nov 3, 2019

This is not the right fix. The shutdown callback can be called with UV_ECANCELED with the following code:

local uv = require('luv')
local isWindows = package.config:find("\\") and true or false

local stdin = uv.new_pipe(false)

handle, pid = uv.spawn(isWindows and "cmd.exe" or "cat", {
  stdio = {stdin, nil, nil}
}, function(...)
  print("onexit", ...)
end)

assert(uv.shutdown(stdin, function(...)
  print("onshutdown", ...)
end))
uv.close(stdin, function(...)
  print("onclose", ...)
end)

uv.run()

(the call to uv.close cancels the shutdown req)

@squeek502 squeek502 closed this Nov 3, 2019
squeek502 added a commit to squeek502/luv that referenced this pull request Nov 3, 2019
The problem is that the shutdown callback is being called during loop_gc, so the Lua/Libuv state is being closed/free'd and the `handle` local var has already been closed/free'd so it's no longer a valid uv_stream_t (see luvit#414).

This will fix PROCESS_CLEANUP_TEST but there is more to do to solve the general case of 'things happening during loop gc'
squeek502 added a commit that referenced this pull request Nov 3, 2019
The problem is that the shutdown callback is being called during loop_gc, so the Lua/Libuv state is being closed/free'd and the `handle` local var has already been closed/free'd so it's no longer a valid uv_stream_t (see #414).

This will fix PROCESS_CLEANUP_TEST but there is more to do to solve the general case of 'things happening during loop gc'
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants