18:16:02  <rphillips>hmm
18:16:18  <rphillips>maybe not gc related... i disabled the gc and it still is asserting
18:21:29  <creationix>rphillips: any idea what kind of handle it was before it became undefined? You could log the pointers of handles when created and compare with the pointer when it's bad
18:21:52  <rphillips>great idea... i'll print those out
18:24:41  <creationix>I'm guessing it's either a uv_pipe_t or uv_process_t since you reproduce it when using uv_spawn
18:24:47  <rphillips>it's the uv_process_t
18:27:04  <creationix>do you know if it's https://github.com/libuv/libuv/blob/60e515d9e6f3d86c0eedad583805201f32ea3aed/src/win/process.c#L865 or https://github.com/libuv/libuv/blob/60e515d9e6f3d86c0eedad583805201f32ea3aed/src/win/process.c#L909
18:29:06  <rphillips>i'll figure that out
18:33:12  <rphillips>it's the 909 one
18:33:19  <rphillips>uv_process_close
18:44:03  <creationix>rphillips: I wonder if we're calling close twice
18:44:40  <creationix>hmm, probably not there is a guard in luv https://github.com/luvit/luv/blob/master/src/handle.c#L72-L74
18:45:22  <rphillips>https://github.com/luvit/luv/blob/master/src/process.c#L218
18:45:30  <rphillips>there is this close on the error path as well
18:45:48  <creationix>right, but in that case the userdata for the handle is never handed to lua
18:50:49  <creationix>but that is interesting. https://github.com/luvit/luv/blob/3c3e790d5b93e533d0f48c9802ae08d36d5ecfb5/src/lhandle.c#L104-L109
18:51:15  <creationix>in your sample, is the subprocess running or is it hitting this error case?
18:52:28  <rphillips>so the executable does not exist
18:52:32  <rphillips>so no, it is not running
18:56:13  <creationix>smells like gc
18:56:28  <creationix>in the error case, we remove all references to the userdata and then call uv_close()
18:56:54  <creationix>if libuv defers running the endgame till a later event tick, it might be GCed
18:59:40  <creationix>https://github.com/joyent/libuv/issues/796
19:00:58  <kostco>not sure if relevent but
19:01:00  <kostco>https://github.com/joyent/node/issues/1669
19:01:09  <kostco>https://github.com/joyent/node/issues/3737
19:01:54  <kostco>im gonna circle back to the coroutine thing, gonna see if i cant port any more checks that dont need to run multiple spawns
19:17:58  <rphillips>the issue is that you need to wait for the end event
19:18:00  <rphillips>on the stdout
19:23:29  <rphillips>creationix: https://github.com/luvit/luv/compare/fix/exec_run_loop_after_close
19:23:32  <rphillips>this fixes it
19:23:39  <rphillips>not sure if we want to do it this way though
19:24:37  * travis-cijoined
19:24:38  <travis-ci>luvit/luv#35 (fix/exec_run_loop_after_close - 7106483 : Ryan Phillips): The build passed.
19:24:38  <travis-ci>Change view : https://github.com/luvit/luv/commit/71064833dc77
19:24:38  <travis-ci>Build details : https://travis-ci.org/luvit/luv/builds/73069106
19:24:38  * travis-cipart
19:28:14  <rphillips>hmm weird
19:28:24  <rphillips>i thought i had luv_get_loop
19:29:30  <rphillips>copy and pasted wrong
19:30:50  * travis-cijoined
19:30:51  <travis-ci>luvit/luv#36 (fix/exec_run_loop_after_close - 80b68d0 : Ryan Phillips): The build passed.
19:30:51  <travis-ci>Change view : https://github.com/luvit/luv/compare/71064833dc77...80b68d0fbe7e
19:30:51  <travis-ci>Build details : https://travis-ci.org/luvit/luv/builds/73069930
19:30:51  * travis-cipart
19:35:48  <creationix>rphillips: I don't want to do that, but it's interesting that it fixes this case
19:35:59  <rphillips>yeah
19:36:06  <creationix>blocking during a non-blocking call will invalidate many assumptions
19:36:53  <creationix>so is your end handler calling close or something?
19:37:01  <creationix>or does libuv just break if you close before end?
19:37:26  <kostco>rphillips: but i do do that here dont i?
19:37:26  <kostco>https://github.com/kaustavha/rackspace-monitoring-agent/blob/67b108e1bff5340a6153318ec1abef473668b555/hostinfo/misc.lua
19:37:26  <kostco>the cb doesnt fire till stdout emits an end
19:38:13  <rphillips>https://github.com/luvit/luvit/blob/master/deps/childprocess.lua#L58
19:38:21  <rphillips>it doesn't call :close() in the error case
19:39:13  <rphillips>right... so what are you seeing again?
19:39:22  <creationix>right, if the blocking uv_run fixes it, it has nothing to do with other lua code
19:39:47  <creationix>kostco: you can't assume an ordering between the stdio end events and the process exit event
19:39:54  <creationix>exit may come first or last
19:39:56  <rphillips>yeah, i think it's a libuv-ism
19:40:13  <rphillips>async.parallel takes that into account
19:40:48  <creationix>sounds like the callback version of coro-split
19:41:09  <kostco>hmm ill give the async parallel method a shot, but i think execfiletobuffers cant run with a bunch of asyncly spawned spawns due to the fireonce(callback) line
19:41:37  <creationix>rphillips: this was my worry in kostco's code https://github.com/kaustavha/rackspace-monitoring-agent/blob/67b108e1bff5340a6153318ec1abef473668b555/hostinfo/misc.lua#L161
19:42:00  <creationix>calling the cb here assumes that stdout#end is the last event
19:42:40  <rphillips>yeah, we have helpers we can use... let me find one
19:43:16  <rphillips>https://github.com/kaustavha/rackspace-monitoring-agent/blob/67b108e1bff5340a6153318ec1abef473668b555/hostinfo/misc.lua#L24
19:43:18  <rphillips>same file
19:43:30  <creationix>yep, that one looks safe
19:44:46  <creationix>kostco: the fireOnce isn't a problem because every call to the helper gets it's own once callback
19:45:26  <creationix>though in this particular function, the fireOnce check is redundant assuming async.parallel always fires once
19:45:38  <kostco>interesting
19:46:50  <rphillips>yep... let's remove it
19:54:30  <kostco>awesomesauce it works
19:57:46  <rphillips>creationix: i think we will need to fix the spawn issue for all these new hostinfo calls
19:58:03  <creationix>yep
19:58:14  <rphillips>at least we know where it is now
19:58:20  <creationix>I'm still trying to figure out if this is a libuv bug or a luv bug
19:58:23  <rphillips>it seems to be the same issue on linux
19:58:44  <creationix>do you have a minimal use case to reproduce it?
19:59:10  <rphillips>i will work on that next.. not yet
20:00:51  <creationix>rphillips: this isn't enough to reproduce it https://gist.github.com/creationix/840b2f85d90353fb3842
20:00:59  <creationix>not on my linux box at least
20:21:10  <kostco>k i took care of the fireonce, should be good to go
20:21:27  <kostco>the prs, that is, took care of them too, fixes and such
20:22:53  <kostco>nvm travis isnt showing me much love
21:28:27  <rphillips>creationix: taking out the 2 collectgarbage() calls around the uv.run() in tap.lua fixes it as well
21:28:47  <creationix>yep, sounds gc related
21:30:30  <kostco>hmm i cant figure out why travis is failing here:
21:30:30  <kostco>https://github.com/virgo-agent-toolkit/rackspace-monitoring-agent/pull/811
21:30:30  <kostco>Can one of you take a look if you get a chance
21:34:12  <creationix>kostco: did you commit your misc.asyncSpawn. I don't see it in that tree
21:34:26  <kostco>nope here ill merge it in
21:34:57  <creationix>on the long unit test runs, search for "not ok" to find failed tests quickly on travis
21:35:18  <kostco>ah thanks
21:35:31  <kostco>never worked with travis before yea that was very helpful lol
21:35:59  <kostco>hmm is there some way to make travis rerun a check without pushing
21:36:28  <kostco>what confused me was that is passed before with no asyncspawn in the tree, yesterday
21:38:20  <kostco>kk i figured it out
21:38:24  <kostco>thanks creationix
21:39:35  <rphillips>creationix: https://github.com/luvit/luv/pull/169
21:39:44  <rphillips>we may need to do that everywhere
21:40:16  <creationix>rphillips: great idea
21:40:44  <creationix>that's the only place that calls uv_close directly
21:40:46  * travis-cijoined
21:40:47  <travis-ci>luvit/luv#40 (fix/close_process_async - 970d5a1 : Ryan Phillips): The build passed.
21:40:47  <travis-ci>Change view : https://github.com/luvit/luv/commit/970d5a185376
21:40:47  <travis-ci>Build details : https://travis-ci.org/luvit/luv/builds/73091700
21:40:47  * travis-cipart
21:40:50  <rphillips>sweet
21:40:53  <kostco>hmmm so now i get a test fail and nothing turns up for not ok
21:40:54  <creationix>all other handles are handled by lua
21:44:00  <creationix>this came up fairly clean https://github.com/creationix/virgo-proto/blob/91e7ffccc273d644a0a0131fcfa4004710c825b5/checks/tcp.lua#L50-L128
21:44:36  <creationix>kostco: congrats, you've reproduced a segfault
21:45:41  <creationix>though that particular segfault looks like what rphillips is fixing
21:46:00  <kostco>so uhm what do i do? suggestions?
21:46:02  <kostco>yay!
21:46:06  <creationix>crash when trying to spawn a non-existent file
21:46:29  <creationix>I'm guessing that's what "test custom plugin file does not exist" does
21:46:44  <kostco>hmm thats rather weird cos if a user is in /etc/passwd, spawning passwd -S name should definitely return
21:47:15  <creationix>I'm talking about these lines: https://travis-ci.org/virgo-agent-toolkit/rackspace-monitoring-agent/builds/73088318#L1164-L1165
21:48:04  <kostco>hmm
21:49:27  <kostco>so wait is it something in my code causing the seg fault
21:49:42  <kostco>whats strange is the most likely culprit would be the asyncspawn func imo but the test there passes
21:49:46  <kostco>sigh
21:50:14  * travis-cijoined
21:50:15  <travis-ci>luvit/luv#42 (master - 4b3a10c : Tim Caswell): The build passed.
21:50:15  <travis-ci>Change view : https://github.com/luvit/luv/compare/55d81e9ea39d...4b3a10c79462
21:50:15  <travis-ci>Build details : https://travis-ci.org/luvit/luv/builds/73093328
21:50:15  * travis-cipart
21:50:42  <rphillips>yes. This patch should fix that crash
21:50:51  <rphillips>Works on windows
21:51:13  <creationix>I've got to leave soon to take kids swimming. I can maybe get the luv release builds started before then
21:51:18  <creationix>rphillips: ready to merge it?
21:52:10  <creationix>now that I see your fix, it all makes sense and was a GC issue all along
21:54:44  <creationix>kostco: you can maybe just re-run the test. I don't think it crashes every time
21:55:27  <kostco>ill try that in a sec, figured out a small bug in my code as well, which shouldnt ever happen since the agent runs in sudo but might as well
21:59:41  * creationixtakes kids to the pool. Can do a luvi release later
22:01:26  <kostco>itd be cool if luvit/lua had a built in function to check if something is empty, like doing the good old ~= nil and ~= '' is kinda ugly imo, but then most languages dont so meh
22:02:06  * boxofroxquit (Ping timeout: 252 seconds)
22:29:22  * boxofroxjoined
22:45:33  <rphillips>ok. merged that patch
22:46:06  <rphillips>creationix: sorry, i had to drive home from my son's appointment... we can do a release tomorrow
22:46:13  <rphillips>or whenever
22:46:26  * travis-cijoined
22:46:27  <travis-ci>luvit/luv#43 (fix/close_process_async - 91a4a05 : Ryan Phillips): The build passed.
22:46:27  <travis-ci>Change view : https://github.com/luvit/luv/compare/970d5a185376...91a4a053a05c
22:46:27  <travis-ci>Build details : https://travis-ci.org/luvit/luv/builds/73100701
22:46:27  * travis-cipart
23:56:11  * hdmsquit (Quit: hdms)