lune-org/lune

HTTP server dies after 13 requests to it

Closed this issue · 2 comments

Repro Script
local net = require("@lune/net")

local start = os.clock()
local counter = 0

net.serve(8080, {
	handleRequest = function(request)
		counter += 1
		print("meow", request.path, os.clock() - start, counter)
		return {
			body = "meow!!"
		}
	end
})

print("meow time")

Opening localhost:8080 and refreshing at any rate will work for 13 requests and then stop. Adding RUST_LOG=trace gives the following output during the last two requests:

Logs
meow / 9.042200000025332 12
   9.052470750s DEBUG lune::lune::scheduler::impl_runner: resumed lua futures count=2
   9.052489625s DEBUG lune::lune::scheduler::impl_runner: resumed lua count=1
   9.052512875s TRACE encode_headers: hyper::proto::h1::role: Server::encode status=200, body=Some(Known(6)), req_method=Some(GET)
   9.052523834s TRACE hyper::proto::h1::io: buffer.queue self.len=75 buf.len=6
   9.052539084s DEBUG hyper::proto::h1::io: flushed 81 bytes
   9.052542334s TRACE hyper::proto::h1::conn: flushed({role=server}): State { reading: Init, writing: Init, keep_alive: Idle }
   9.618968709s TRACE hyper::proto::h1::conn: Conn::read_head
   9.618990000s TRACE hyper::proto::h1::io: received 574 bytes
   9.619000709s TRACE parse_headers: hyper::proto::h1::role: Request.parse bytes=574
   9.619028459s TRACE parse_headers: hyper::proto::h1::role: Request.parse Complete(574)
   9.619165542s DEBUG hyper::proto::h1::io: parsed 10 headers
   9.619170167s DEBUG hyper::proto::h1::conn: incoming body is empty
   9.619203084s TRACE hyper::proto::h1::conn: flushed({role=server}): State { reading: KeepAlive, writing: Init, keep_alive: Busy }
   9.619260125s DEBUG lune::lune::scheduler::impl_runner: resumed lua count=1
meow / 9.609050333383493 13
   9.619338834s DEBUG lune::lune::scheduler::impl_runner: resumed lua futures count=2
   9.619348500s DEBUG lune::lune::scheduler::impl_runner: resumed lua count=1
   9.619388417s TRACE encode_headers: hyper::proto::h1::role: Server::encode status=200, body=Some(Known(6)), req_method=Some(GET)
   9.619397834s TRACE hyper::proto::h1::io: buffer.queue self.len=75 buf.len=6
   9.619412084s DEBUG hyper::proto::h1::io: flushed 81 bytes
   9.619415250s TRACE hyper::proto::h1::conn: flushed({role=server}): State { reading: Init, writing: Init, keep_alive: Idle }
   9.619252834s DEBUG hyper::server::shutdown: signal received, starting graceful shutdown
   9.619719667s TRACE hyper::proto::h1::conn: disable_keep_alive; closing idle connection
   9.619723375s TRACE hyper::proto::h1::conn: State::close()
   9.619725000s TRACE hyper::proto::h1::conn: State::close_read()
   9.619726625s TRACE hyper::proto::h1::conn: State::close_write()
   9.619728709s TRACE hyper::proto::h1::conn: flushed({role=server}): State { reading: Closed, writing: Closed, keep_alive: Disabled }
   9.619740500s TRACE hyper::proto::h1::conn: shut down IO complete
   9.619801625s DEBUG lune::lune::scheduler::impl_runner: resumed lua futures count=2
   9.619808084s DEBUG lune::lune::scheduler::impl_runner: scheduler ran to completion, with success

It seems that assigning the net.ServeHandle to serveHandle and adding this after net.serve will prevent this from happening.

while true do
	task.wait(60)
	print(serveHandle)
end

I think this means it might be a garbage collection issue? My guess is that after around 13 requests, the heap is big enough that garbage collection runs, and without the reference to the ServeHandle garbage collection will incorrectly collect it.

Fixed in fbee7c8