Re: [NSE] assertion failure in stdnse.sleep()

[David Fifield <david () bamsoftware com>]

On Sat, Oct 06, 2012 at 11:00:50PM +0200, Henri Doreau wrote:
> Hi,
>
> stdnse.sleep() sometimes leads to the following assertion failure:
>
> nmap: nse_nsock.cc:709: void sleep_callback(nsock_pool, nsock_event,
> void*): Assertion `lua_status(L) == 1' failed.
>
> I can reproduce it with the little script attached, but some scripts
> (dunno which ones) from trunk trigger it too. I'm not sure how to fix
> it best. I suppose that when a script gets one of its timers cancelled
> its entire execution should be stopped...

So, I don't think that the problem is really with the timer being
cancelled. There is more than one thing going on here. One is that
calling sleep or another yielding function doesn't seem to work from an
exception handler:

local stdnse = require('stdnse')
prerule = function() return true end
action = function()
  local catch = function() stdnse.sleep(20) end
  local try = nmap.new_try(catch)
  try(false)
end

attempt to yield across metamethod/C-call boundary
stack traceback:
        [C]: in function 'sleep'
        a.nse:4: in function <a.nse:4>
        [C]: in function 'try'
        a.nse:6: in function <a.nse:3>
        (...tail calls...)

I'm confused by this error because I thought that "yield across
metamethod/C-call boundary" wasn't a thing anymore with Lua 5.2. The
same thing happens if you do a sock:connect within the exception
handler, though doing that doesn't cause the additional problem
described below.

The above error inside the exception handler causes the thread to be
deleted, even though an Nsock timer is pending with the thread's address
as userdata. When the nsock_pool is later deleted, sleep_callback
deferences freed memory, and lua_status(L) returns garbage. (It changes
per execution.)

NSOCK (2.3260s) Callback: TIMER KILL for EID 12
==22880== Invalid read of size 1
==22880==    at 0x4C85E0: lua_status (lapi.c:1010)
==22880==    by 0x49E6BB: sleep_callback(void*, void*, void*) (nse_nsock.cc:709)
==22880==    by 0x4B06BD: nsp_delete (nsock_pool.c:241)
==22880==    by 0x49EB0A: gc_pool(lua_State*) (nse_nsock.cc:74)
==22880==    by 0x4CA369: luaD_precall (ldo.c:317)
==22880==    by 0x4CA5CC: luaD_call (ldo.c:392)
==22880==    by 0x4C9C4A: luaD_rawrunprotected (ldo.c:131)
==22880==    by 0x4CA804: luaD_pcall (ldo.c:590)
==22880==    by 0x4CB766: GCTM (lgc.c:826)
==22880==    by 0x4CB7FE: callallpendingfinalizers (lgc.c:965)
==22880==    by 0x4CCB33: luaC_freeallobjects (lgc.c:975)
==22880==    by 0x4D103D: close_state (lstate.c:224)
==22880==  Address 0xd52e90a is 10 bytes inside a block of size 208 free'd
==22880==    at 0x4C27D4E: free (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==22880==    by 0x4D59C8: l_alloc (lauxlib.c:921)
==22880==    by 0x4CD050: luaM_realloc_ (lmem.c:84)
==22880==    by 0x4CB5D6: sweeplist (lgc.c:678)
==22880==    by 0x4CC51E: singlestep (lgc.c:1078)
==22880==    by 0x4CCBC7: luaC_runtilstate (lgc.c:1102)
==22880==    by 0x4CCCDF: luaC_fullgc (lgc.c:1192)
==22880==    by 0x4C867E: lua_gc (lapi.c:1034)
==22880==    by 0x4DAF6D: luaB_collectgarbage (lbaselib.c:169)
==22880==    by 0x4CA369: luaD_precall (ldo.c:317)
==22880==    by 0x4D44B3: luaV_execute (lvm.c:710)
==22880==    by 0x4CA5D8: luaD_call (ldo.c:393)
==22880==
nmap: nse_nsock.cc:709: void sleep_callback(nsock_pool, nsock_event, void*): Assertion `lua_status(L) == 1' failed.

I thought about using nse_destructor to have l_sleep register a
destructor that cancels the timer event; hopefully this happens before
the thread is freed. sleep_callback would simply remove the registered
destructor.

David Fifield
_______________________________________________
Sent through the nmap-dev mailing list
http://cgi.insecure.org/mailman/listinfo/nmap-dev
Archived at http://seclists.org/nmap-dev/