From 3899c7ac4b50242ccfc78edc6d5e3d6c3b954008 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Thu, 25 Oct 2018 15:12:59 +0200 Subject: net.server: Add an API for holding writes of outgoing data --- net/server_epoll.lua | 20 ++++++++++++++++++-- 1 file changed, 18 insertions(+), 2 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 4b40c7d5..cdf3e8fe 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -409,8 +409,10 @@ function interface:write(data) else self.writebuffer = { data }; end - self:setwritetimeout(); - self:set(nil, true); + if not self._write_lock then + self:setwritetimeout(); + self:set(nil, true); + end return #data; end interface.send = interface.write; @@ -590,6 +592,20 @@ function interface:pausefor(t) end); end +function interface:pause_writes() + self._write_lock = true; + self:setwritetimeout(false); + self:set(nil, false); +end + +function interface:resume_writes() + self._write_lock = nil; + if self.writebuffer[1] then + self:setwritetimeout(); + self:set(nil, true); + end +end + -- Connected! function interface:onconnect() if self.conn and not self.peername and self.conn.getpeername then -- cgit v1.2.3 From 1f9b825c34e068f951cf4154ceb71580aea23eb0 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 28 Oct 2018 18:22:17 +0100 Subject: net.server_epoll: Reschedule delayed timers relative to current time This should normally never happen, but can be reproduced by suspending the process a while. --- net/server_epoll.lua | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index cdf3e8fe..ce8996a8 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -106,9 +106,13 @@ local function runtimers(next_delay, min_wait) end local new_timeout = f(now); if new_timeout then - -- Schedule for 'delay' from the time actually scheduled, - -- not from now, in order to prevent timer drift. - timer[1] = t + new_timeout; + -- Schedule for 'delay' from the time actually scheduled, not from now, + -- in order to prevent timer drift, unless it already drifted way out of sync. + if (t + new_timeout) > ( now - new_timeout ) then + timer[1] = t + new_timeout; + else + timer[1] = now + new_timeout; + end resort_timers = true; else t_remove(timers, i); -- cgit v1.2.3 From fb768f193f73d360a61758b5a46e14d81c967151 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Mon, 29 Oct 2018 02:13:09 +0100 Subject: net.server_epoll: Use method to update peername on connect --- net/server_epoll.lua | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index ce8996a8..f7e5ae49 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -612,9 +612,7 @@ end -- Connected! function interface:onconnect() - if self.conn and not self.peername and self.conn.getpeername then - self.peername, self.peerport = self.conn:getpeername(); - end + self:updatenames(); self.onconnect = noop; self:on("connect"); end -- cgit v1.2.3 From 726a7996dd944551c5a4007872ae06dd7f3facae Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 8 Dec 2018 21:17:39 +0100 Subject: net.server_epoll: Call onconnect right after accept()ing a new client --- net/server_epoll.lua | 2 ++ 1 file changed, 2 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 13c8315a..3088b55b 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -577,6 +577,8 @@ function interface:onacceptable() client:init(); if self.tls_direct then client:starttls(self.tls_ctx); + else + client:onconnect(); end end -- cgit v1.2.3 From e6e285898bd7dab34cf8c4c0ac5a748334f65ff0 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 8 Dec 2018 21:28:48 +0100 Subject: net.server_epoll: Bail on callback error An error calling a callback would be considered a truthy return value, which is not right. --- net/server_epoll.lua | 1 + 1 file changed, 1 insertion(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 3088b55b..b2165b1d 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -180,6 +180,7 @@ function interface:on(what, ...) local ok, err = pcall(listener, self, ...); if not ok then log("error", "Error calling on%s: %s", what, err); + return; end return err; end -- cgit v1.2.3 From a40e044c0327b838e4a4e161e92798ed3ceadcf5 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 9 Feb 2019 20:34:00 +0100 Subject: net.server_epoll: Separate timeout for initial connection attempts server_event has this separation already --- net/server_epoll.lua | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 807e0b4c..a80b33a9 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -41,6 +41,9 @@ local default_config = { __index = { -- How long to wait for a socket to become writable after queuing data to send send_timeout = 60; + -- How long to wait for a socket to become writable after creation + connect_timeout = 20; + -- Some number possibly influencing how many pending connections can be accepted tcp_backlog = 128; @@ -585,7 +588,7 @@ end -- Initialization function interface:init() - self:setwritetimeout(); + self:setwritetimeout(cfg.connect_timeout); return self:add(true, true); end -- cgit v1.2.3 From ce03153c84ca4f2ef38daa09ab078d6e1a092469 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 9 Feb 2019 20:54:35 +0100 Subject: net.server_epoll: Increase send_timeout to 3 minutes (to match server_event) The separate connect_timeout means we can afford a longer send_timeout --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index a80b33a9..fdf006f6 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -39,7 +39,7 @@ local default_config = { __index = { read_timeout = 14 * 60; -- How long to wait for a socket to become writable after queuing data to send - send_timeout = 60; + send_timeout = 180; -- How long to wait for a socket to become writable after creation connect_timeout = 20; -- cgit v1.2.3 From 3cb132326dd6489e14a26071f87d68bf277a5a70 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Thu, 13 Sep 2018 21:16:37 +0200 Subject: net.server: New API for creating server listeners server.listen(interface, port, listeners, options); --- net/server_epoll.lua | 18 ++++++++++++++---- 1 file changed, 14 insertions(+), 4 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index fdf006f6..5609f058 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -637,7 +637,7 @@ function interface:onconnect() self:on("connect"); end -local function addserver(addr, port, listeners, read_size, tls_ctx) +local function listen(addr, port, listeners, config) local conn, err = socket.bind(addr, port, cfg.tcp_backlog); if not conn then return conn, err; end conn:settimeout(0); @@ -645,10 +645,10 @@ local function addserver(addr, port, listeners, read_size, tls_ctx) conn = conn; created = gettime(); listeners = listeners; - read_size = read_size; + read_size = config and config.read_size; onreadable = interface.onacceptable; - tls_ctx = tls_ctx; - tls_direct = tls_ctx and true or false; + tls_ctx = config and config.tls_ctx; + tls_direct = config and config.tls_direct; sockname = addr; sockport = port; }, interface_mt); @@ -656,6 +656,15 @@ local function addserver(addr, port, listeners, read_size, tls_ctx) return server; end +-- COMPAT +local function addserver(addr, port, listeners, read_size, tls_ctx) + return listen(addr, port, listeners, { + read_size = read_size; + tls_ctx = tls_ctx; + tls_direct = tls_ctx and true or false; + }); +end + -- COMPAT local function wrapclient(conn, addr, port, listeners, read_size, tls_ctx) local client = wrapsocket(conn, nil, read_size, listeners, tls_ctx); @@ -792,6 +801,7 @@ return { addserver = addserver; addclient = addclient; add_task = addtimer; + listen = listen; at = at; loop = loop; closeall = closeall; -- cgit v1.2.3 From a1ef28548caaf3dc474b4c638aee917e2ca1563d Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 10 Mar 2019 19:35:34 +0100 Subject: net.server_epoll: Add support for SNI (#409) --- net/server_epoll.lua | 8 ++++++++ 1 file changed, 8 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 5609f058..3c8b2613 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -509,6 +509,13 @@ function interface:tlshandskake() end conn:settimeout(0); self.conn = conn; + if conn.sni then + if self.servername then + conn:sni(self.servername); + elseif self._server and self._server.hosts then + conn:sni(self._server.hosts, true); + end + end self:on("starttls"); self.ondrain = nil; self.onwritable = interface.tlshandskake; @@ -649,6 +656,7 @@ local function listen(addr, port, listeners, config) onreadable = interface.onacceptable; tls_ctx = config and config.tls_ctx; tls_direct = config and config.tls_direct; + hosts = config and config.sni_hosts; sockname = addr; sockport = port; }, interface_mt); -- cgit v1.2.3 From 5d2608e150b7a739c0b1658fd2e9031af9ad2991 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Mon, 11 Mar 2019 13:00:51 +0100 Subject: net.server: Only add alternate SNI contexts if at least one is provided Fixes use of when a client sends SNI, which would send no certificate otherwise. --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 3c8b2613..4bdc2e21 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -512,7 +512,7 @@ function interface:tlshandskake() if conn.sni then if self.servername then conn:sni(self.servername); - elseif self._server and self._server.hosts then + elseif self._server and type(self._server.hosts) == "table" and next(self._server.hosts) ~= nil then conn:sni(self._server.hosts, true); end end -- cgit v1.2.3 From 50f89a9f96e4a37cb367c732fefd9ae40a6d82f9 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Tue, 12 Mar 2019 23:13:51 +0100 Subject: net.server_epoll: Optimize timer handling --- net/server_epoll.lua | 83 +++++++++++++++++++--------------------------------- 1 file changed, 30 insertions(+), 53 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 4bdc2e21..4037f7ab 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -6,9 +6,7 @@ -- -local t_sort = table.sort; local t_insert = table.insert; -local t_remove = table.remove; local t_concat = table.concat; local setmetatable = setmetatable; local tostring = tostring; @@ -20,6 +18,7 @@ local log = require "util.logger".init("server_epoll"); local socket = require "socket"; local luasec = require "ssl"; local gettime = require "util.time".now; +local indexedbheap = require "util.indexedbheap"; local createtable = require "util.table".create; local inet = require "util.net"; local inet_pton = inet.pton; @@ -69,22 +68,24 @@ local fds = createtable(10, 0); -- FD -> conn -- Timer and scheduling -- -local timers = {}; +local timers = indexedbheap.create(); local function noop() end local function closetimer(t) t[1] = 0; t[2] = noop; + timers:remove(t.id); end --- Set to true when timers have changed -local resort_timers = false; +local function reschedule(t, time) + t[1] = time; + timers:reprioritize(t.id, time); +end -- Add absolute timer local function at(time, f) - local timer = { time, f, close = closetimer }; - t_insert(timers, timer); - resort_timers = true; + local timer = { time, f, close = closetimer, reschedule = reschedule, id = nil }; + timer.id = timers:insert(timer, time); return timer; end @@ -97,54 +98,32 @@ end -- Return time until next timeout local function runtimers(next_delay, min_wait) -- Any timers at all? - if not timers[1] then - return next_delay; - end + local now = gettime(); + local peek = timers:peek(); + while peek do - if resort_timers then - -- Sort earliest timers to the end - t_sort(timers, function (a, b) return a[1] > b[1]; end); - resort_timers = false; - end - - -- Iterate from the end and remove completed timers - for i = #timers, 1, -1 do - local timer = timers[i]; - local t, f = timer[1], timer[2]; - -- Get time for every iteration to increase accuracy - local now = gettime(); - if t > now then - -- This timer should not fire yet - local diff = t - now; - if diff < next_delay then - next_delay = diff; - end + if peek > now then + next_delay = peek - now; break; end - local new_timeout = f(now); - if new_timeout then - -- Schedule for 'delay' from the time actually scheduled, not from now, - -- in order to prevent timer drift, unless it already drifted way out of sync. - if (t + new_timeout) > ( now - new_timeout ) then - timer[1] = t + new_timeout; - else - timer[1] = now + new_timeout; - end - resort_timers = true; - else - t_remove(timers, i); + + local _, timer, id = timers:pop(); + local ok, ret = pcall(timer[2], now); + if ok and type(ret) == "number" then + local next_time = now+ret; + timer[1] = next_time; + timers:insert(timer, next_time); end - end - if resort_timers or next_delay < min_wait then - -- Timers may be added from within a timer callback. - -- Those would not be considered for next_delay, - -- and we might sleep for too long, so instead - -- we return a shorter timeout so we can - -- properly sort all new timers. - next_delay = min_wait; + peek = timers:peek(); + end + if peek == nil then + return next_delay; end + if next_delay < min_wait then + return min_wait; + end return next_delay; end @@ -251,8 +230,7 @@ function interface:setreadtimeout(t) end t = t or cfg.read_timeout; if self._readtimeout then - self._readtimeout[1] = gettime() + t; - resort_timers = true; + self._readtimeout:reschedule(gettime() + t); else self._readtimeout = addtimer(t, function () if self:on("readtimeout") then @@ -276,8 +254,7 @@ function interface:setwritetimeout(t) end t = t or cfg.send_timeout; if self._writetimeout then - self._writetimeout[1] = gettime() + t; - resort_timers = true; + self._writetimeout:reschedule(gettime() + t); else self._writetimeout = addtimer(t, function () self:on("disconnect", "write timeout"); -- cgit v1.2.3 From d06300c456ad2209a500e64a6efac1094d58bdea Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 25 May 2019 16:09:26 +0200 Subject: net.server_epoll: Return listener error message --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 5f62d931..4061d755 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -162,7 +162,7 @@ function interface:on(what, ...) local ok, err = pcall(listener, self, ...); if not ok then log("error", "Error calling on%s: %s", what, err); - return; + return nil, err; end return err; end -- cgit v1.2.3 From 2b596d7bd69f1c67a53c8166cc7b59cda3efce17 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 25 May 2019 16:14:31 +0200 Subject: net.server_epoll: Add experimental option to close connections in case of listener error Sometimes such errors leave sessions in an inconsistent state, so it might be better to close them early. --- net/server_epoll.lua | 8 ++++++++ 1 file changed, 8 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 4061d755..251f91f7 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -61,6 +61,10 @@ local default_config = { __index = { -- Maximum and minimum amount of time to sleep waiting for events (adjusted for pending timers) max_wait = 86400; min_wait = 1e-06; + + -- EXPERIMENTAL + -- Whether to kill connections in case of callback errors. + fatal_errors = false; }}; local cfg = default_config.__index; @@ -162,6 +166,10 @@ function interface:on(what, ...) local ok, err = pcall(listener, self, ...); if not ok then log("error", "Error calling on%s: %s", what, err); + if cfg.fatal_errors then + log("debug", "Closing %s due to error in listener", self); + self:destroy(); + end return nil, err; end return err; -- cgit v1.2.3 From d9649edc2c6a2c22d2cdc5c8fe577deb510580bf Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Tue, 23 Jul 2019 18:06:34 +0200 Subject: net.server_epoll: Return errors from creating sockets Prevents error from attempting to index nil conn on such failure. Silences luacheck warning about the 'err' variable being unused --- net/server_epoll.lua | 1 + 1 file changed, 1 insertion(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 251f91f7..f296dd37 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -694,6 +694,7 @@ local function addclient(addr, port, listeners, read_size, tls_ctx, typ) return nil, "invalid socket type"; end local conn, err = create(); + if not conn then return conn, err; end local ok, err = conn:settimeout(0); if not ok then return ok, err; end local ok, err = conn:setpeername(addr, port); -- cgit v1.2.3 From e6a6668fb5ec2eb87ec51bc23613d5c5046549ed Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Wed, 24 Jul 2019 16:50:06 +0200 Subject: net.server_epoll: Deprecate libevent emulation layer --- net/server_epoll.lua | 1 + 1 file changed, 1 insertion(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index f296dd37..b6f377fd 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -813,6 +813,7 @@ return { -- libevent emulation event = { EV_READ = "r", EV_WRITE = "w", EV_READWRITE = "rw", EV_LEAVE = -1 }; addevent = function (fd, mode, callback) + log("warn", "Using deprecated libevent emulation, please update code to use watchfd API instead"); local function onevent(self) local ret = self:callback(); if ret == -1 then -- cgit v1.2.3 From 0cd5fc425d98ae6bf94b4e06a3a2d8196a9ddaf4 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Fri, 26 Jul 2019 21:21:48 +0200 Subject: net.server_epoll: Overhaul logging with one log sink per connection --- net/server_epoll.lua | 64 +++++++++++++++++++++++++++++++++------------------- 1 file changed, 41 insertions(+), 23 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index b6f377fd..1ae92d87 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -14,7 +14,8 @@ local pcall = pcall; local type = type; local next = next; local pairs = pairs; -local log = require "util.logger".init("server_epoll"); +local logger = require "util.logger"; +local log = logger.init("server_epoll"); local socket = require "socket"; local luasec = require "ssl"; local gettime = require "util.time".now; @@ -23,6 +24,7 @@ local createtable = require "util.table".create; local inet = require "util.net"; local inet_pton = inet.pton; local _SOCKETINVALID = socket._SOCKETINVALID or -1; +local new_id = require "util.id".medium; local poller = require "util.poll" local EEXIST = poller.EEXIST; @@ -145,6 +147,15 @@ function interface_mt:__tostring() return ("FD %d"):format(self:getfd()); end +interface.log = log; +function interface:debug(msg, ...) --luacheck: ignore 212/self + self.log("debug", msg, ...); +end + +function interface:error(msg, ...) --luacheck: ignore 212/self + self.log("error", msg, ...); +end + -- Replace the listener and tell the old one function interface:setlistener(listeners, data) self:on("detach"); @@ -155,20 +166,21 @@ end -- Call a listener callback function interface:on(what, ...) if not self.listeners then - log("error", "%s has no listeners", self); + self:debug("Interface is missing listener callbacks"); return; end local listener = self.listeners["on"..what]; if not listener then - -- log("debug", "Missing listener 'on%s'", what); -- uncomment for development and debugging + -- self:debug("Missing listener 'on%s'", what); -- uncomment for development and debugging return; end local ok, err = pcall(listener, self, ...); if not ok then - log("error", "Error calling on%s: %s", what, err); if cfg.fatal_errors then - log("debug", "Closing %s due to error in listener", self); + self:debug("Closing due to error calling on%s: %s", what, err); self:destroy(); + else + self:debug("Error calling on%s: %s", what, err); end return nil, err; end @@ -281,15 +293,15 @@ function interface:add(r, w) local ok, err, errno = poll:add(fd, r, w); if not ok then if errno == EEXIST then - log("debug", "%s already registered!", self); + self:debug("FD already registered in poller! (EEXIST)"); return self:set(r, w); -- So try to change its flags end - log("error", "Could not register %s: %s(%d)", self, err, errno); + self:debug("Could not register in poller: %s(%d)", err, errno); return ok, err; end self._wantread, self._wantwrite = r, w; fds[fd] = self; - log("debug", "Watching %s", self); + self:debug("Registered in poller"); return true; end @@ -302,7 +314,7 @@ function interface:set(r, w) if w == nil then w = self._wantwrite; end local ok, err, errno = poll:set(fd, r, w); if not ok then - log("error", "Could not update poller state %s: %s(%d)", self, err, errno); + self:debug("Could not update poller state: %s(%d)", err, errno); return ok, err; end self._wantread, self._wantwrite = r, w; @@ -319,12 +331,12 @@ function interface:del() end local ok, err, errno = poll:del(fd); if not ok and errno ~= ENOENT then - log("error", "Could not unregister %s: %s(%d)", self, err, errno); + self:debug("Could not unregister: %s(%d)", err, errno); return ok, err; end self._wantread, self._wantwrite = nil, nil; fds[fd] = nil; - log("debug", "Unwatched %s", self); + self:debug("Unregistered from poller"); return true; end @@ -432,10 +444,10 @@ function interface:close() if self.writebuffer and self.writebuffer[1] then self:set(false, true); -- Flush final buffer contents self.write, self.send = noop, noop; -- No more writing - log("debug", "Close %s after writing", self); + self:debug("Close after writing"); self.ondrain = interface.close; else - log("debug", "Close %s now", self); + self:debug("Closing now"); self.write, self.send = noop, noop; self.close = noop; self:on("disconnect"); @@ -464,7 +476,7 @@ function interface:starttls(tls_ctx) if tls_ctx then self.tls_ctx = tls_ctx; end self.starttls = false; if self.writebuffer and self.writebuffer[1] then - log("debug", "Start TLS on %s after write", self); + self:debug("Start TLS after write"); self.ondrain = interface.starttls; self:set(nil, true); -- make sure wantwrite is set else @@ -474,7 +486,7 @@ function interface:starttls(tls_ctx) self.onwritable = interface.tlshandskake; self.onreadable = interface.tlshandskake; self:set(true, true); - log("debug", "Prepare to start TLS on %s", self); + self:debug("Prepared to start TLS"); end end @@ -483,12 +495,12 @@ function interface:tlshandskake() self:setreadtimeout(false); if not self._tls then self._tls = true; - log("debug", "Start TLS on %s now", self); + self:debug("Starting TLS now"); self:del(); local ok, conn, err = pcall(luasec.wrap, self.conn, self.tls_ctx); if not ok then conn, err = ok, conn; - log("error", "Failed to initialize TLS: %s", err); + self:debug("Failed to initialize TLS: %s", err); end if not conn then self:on("disconnect", err); @@ -512,22 +524,22 @@ function interface:tlshandskake() end local ok, err = self.conn:dohandshake(); if ok then - log("debug", "TLS handshake on %s complete", self); + self:debug("TLS handshake complete"); self.onwritable = nil; self.onreadable = nil; self:on("status", "ssl-handshake-complete"); self:setwritetimeout(); self:set(true, true); elseif err == "wantread" then - log("debug", "TLS handshake on %s to wait until readable", self); + self:debug("TLS handshake to wait until readable"); self:set(true, false); self:setreadtimeout(cfg.ssl_handshake_timeout); elseif err == "wantwrite" then - log("debug", "TLS handshake on %s to wait until writable", self); + self:debug("TLS handshake to wait until writable"); self:set(false, true); self:setwritetimeout(cfg.ssl_handshake_timeout); else - log("debug", "TLS handshake error on %s: %s", self, err); + self:debug("TLS handshake error: %s", err); self:on("disconnect", err); self:destroy(); end @@ -544,6 +556,7 @@ local function wrapsocket(client, server, read_size, listeners, tls_ctx) -- luas writebuffer = {}; tls_ctx = tls_ctx or (server and server.tls_ctx); tls_direct = server and server.tls_direct; + log = logger.init(("conn%s"):format(new_id())); }, interface_mt); conn:updatenames(); @@ -567,12 +580,12 @@ end function interface:onacceptable() local conn, err = self.conn:accept(); if not conn then - log("debug", "Error accepting new client: %s, server will be paused for %ds", err, cfg.accept_retry_interval); + self:debug("Error accepting new client: %s, server will be paused for %ds", err, cfg.accept_retry_interval); self:pausefor(cfg.accept_retry_interval); return; end local client = wrapsocket(conn, self, nil, self.listeners); - log("debug", "New connection %s", tostring(client)); + client:debug("New connection %s on server %s", client, self); client:init(); if self.tls_direct then client:starttls(self.tls_ctx); @@ -647,7 +660,9 @@ local function listen(addr, port, listeners, config) hosts = config and config.sni_hosts; sockname = addr; sockport = port; + log = logger.init(("serv%s"):format(new_id())); }, interface_mt); + server:debug("Server %s created", server); server:add(true, false); return server; end @@ -705,6 +720,7 @@ local function addclient(addr, port, listeners, read_size, tls_ctx, typ) if tls_ctx then client:starttls(tls_ctx); end + client:debug("Client %s created", client); return client, conn; end @@ -723,6 +739,7 @@ local function watchfd(fd, onreadable, onwritable) end; -- Otherwise it'll need to be something LuaSocket-compatible end + conn.log = logger.init(("fdwatch%s"):format(new_id())); conn:add(onreadable, onwritable); return conn; end; @@ -833,6 +850,7 @@ return { fds[fd] = nil; end; }, interface_mt); + conn.log = logger.init(("fdwatch%d"):format(conn:getfd())); local ok, err = conn:add(mode == "r" or mode == "rw", mode == "w" or mode == "rw"); if not ok then return ok, err; end return conn; -- cgit v1.2.3 From ad9b431b8c24e909e2f2bc693b60bf11dd130372 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Fri, 26 Jul 2019 21:23:53 +0200 Subject: net.server_epoll: Remove unused local [luacheck] --- net/server_epoll.lua | 1 - 1 file changed, 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 1ae92d87..ccf46928 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -9,7 +9,6 @@ local t_insert = table.insert; local t_concat = table.concat; local setmetatable = setmetatable; -local tostring = tostring; local pcall = pcall; local type = type; local next = next; -- cgit v1.2.3 From 5c48dbda51bac9bf58dff9be6bc19524734ac42a Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 18 Dec 2016 17:39:16 +0000 Subject: server_epoll: Add native support for per socket bandwith limits --- net/server_epoll.lua | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index ccf46928..49ad48ea 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -377,6 +377,14 @@ function interface:onreadable() end end if not self.conn then return; end + if self._limit and (data or partial) then + local cost = self._limit * #(data or partial); + if cost > cfg.min_wait then + self:setreadtimeout(false); + self:pausefor(cost); + return; + end + end if self._wantread and self.conn:dirty() then self:setreadtimeout(false); self:pausefor(cfg.read_retry_delay); @@ -609,6 +617,7 @@ end -- Pause connection for some time function interface:pausefor(t) + self:debug("Pause for %fs", t); if self._pausefor then self._pausefor:close(); end @@ -623,6 +632,14 @@ function interface:pausefor(t) end); end +function interface:setlimit(Bps) + if Bps > 0 then + self._limit = 1/Bps; + else + self._limit = nil; + end +end + function interface:pause_writes() self._write_lock = true; self:setwritetimeout(false); -- cgit v1.2.3 From 4cc299fc0214368012a2775b94c746d2290327a0 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Wed, 28 Aug 2019 01:41:00 +0200 Subject: net.server_epoll: Add support for opportunistic writes This tries to flush data to the underlying sockets when receiving writes. This should lead to fewer timer objects being around. On the other hand, this leads to more and smaller writes which may translate to more TCP/IP packets being sent, depending on how the kernel handles this. This trades throughput for lower latency. --- net/server_epoll.lua | 8 ++++++++ 1 file changed, 8 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 49ad48ea..ef021851 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -66,6 +66,9 @@ local default_config = { __index = { -- EXPERIMENTAL -- Whether to kill connections in case of callback errors. fatal_errors = false; + + -- Attempt writes instantly + opportunistic_writes = false; }}; local cfg = default_config.__index; @@ -413,6 +416,7 @@ function interface:onwritable() for i = #buffer, 2, -1 do buffer[i] = nil; end + self:set(nil, true); self:setwritetimeout(); end if err == "wantwrite" or err == "timeout" then @@ -439,6 +443,10 @@ function interface:write(data) self.writebuffer = { data }; end if not self._write_lock then + if cfg.opportunistic_writes then + self:onwritable(); + return #data; + end self:setwritetimeout(); self:set(nil, true); end -- cgit v1.2.3 From 9afa1ac496bac9d9eaaf687edbdde3f0c7fb66e1 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 1 Sep 2019 01:55:55 +0200 Subject: net.server: Accept and save an 'extra' field for client connections This lets code attach some extra data to be attached to client connections. --- net/server_epoll.lua | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index ef021851..96e7b201 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -560,7 +560,7 @@ function interface:tlshandskake() end end -local function wrapsocket(client, server, read_size, listeners, tls_ctx) -- luasocket object -> interface object +local function wrapsocket(client, server, read_size, listeners, tls_ctx, extra) -- luasocket object -> interface object client:settimeout(0); local conn = setmetatable({ conn = client; @@ -572,6 +572,7 @@ local function wrapsocket(client, server, read_size, listeners, tls_ctx) -- luas tls_ctx = tls_ctx or (server and server.tls_ctx); tls_direct = server and server.tls_direct; log = logger.init(("conn%s"):format(new_id())); + extra = extra; }, interface_mt); conn:updatenames(); @@ -701,8 +702,8 @@ local function addserver(addr, port, listeners, read_size, tls_ctx) end -- COMPAT -local function wrapclient(conn, addr, port, listeners, read_size, tls_ctx) - local client = wrapsocket(conn, nil, read_size, listeners, tls_ctx); +local function wrapclient(conn, addr, port, listeners, read_size, tls_ctx, extra) + local client = wrapsocket(conn, nil, read_size, listeners, tls_ctx, extra); if not client.peername then client.peername, client.peerport = addr, port; end @@ -715,7 +716,7 @@ local function wrapclient(conn, addr, port, listeners, read_size, tls_ctx) end -- New outgoing TCP connection -local function addclient(addr, port, listeners, read_size, tls_ctx, typ) +local function addclient(addr, port, listeners, read_size, tls_ctx, typ, extra) local create; if not typ then local n = inet_pton(addr); @@ -738,7 +739,7 @@ local function addclient(addr, port, listeners, read_size, tls_ctx, typ) if not ok then return ok, err; end local ok, err = conn:setpeername(addr, port); if not ok and err ~= "timeout" then return ok, err; end - local client = wrapsocket(conn, nil, read_size, listeners, tls_ctx) + local client = wrapsocket(conn, nil, read_size, listeners, tls_ctx, extra) local ok, err = client:init(); if not ok then return ok, err; end if tls_ctx then -- cgit v1.2.3 From fb692a2cedc46229966f4a84585f292abe850ba4 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 1 Sep 2019 01:58:38 +0200 Subject: net.server: Handle server name (SNI) as extra argument Code added in 75d2874502c3, 9a905888b96c and adc0672b700e uses this field. See #409 and #1408 --- net/server_epoll.lua | 6 ++++++ 1 file changed, 6 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 96e7b201..f48086e3 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -575,6 +575,12 @@ local function wrapsocket(client, server, read_size, listeners, tls_ctx, extra) extra = extra; }, interface_mt); + if extra then + if extra.servername then + conn.servername = extra.servername; + end + end + conn:updatenames(); return conn; end -- cgit v1.2.3 From 2aedce23760830b08c7cdd76b1164f9e6f2fbea9 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 29 Sep 2019 14:50:04 +0200 Subject: net.server_epoll: Make it easy to override handler for incoming data --- net/server_epoll.lua | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index f48086e3..fd9e0416 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -189,6 +189,11 @@ function interface:on(what, ...) return err; end +-- Allow this one to be overridden +function interface:onincoming(...) + return self:on("incoming", ...); +end + -- Return the file descriptor number function interface:getfd() if self.conn then @@ -360,7 +365,7 @@ function interface:onreadable() local data, err, partial = self.conn:receive(self.read_size or cfg.read_size); if data then self:onconnect(); - self:on("incoming", data); + self:onincoming(data); else if err == "wantread" then self:set(true, nil); @@ -371,7 +376,7 @@ function interface:onreadable() end if partial and partial ~= "" then self:onconnect(); - self:on("incoming", partial, err); + self:onincoming(partial, err); end if err ~= "timeout" then self:on("disconnect", err); -- cgit v1.2.3 From 315959a49a675d2f95610828ddcc66d2f1fb535c Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 29 Sep 2019 15:00:28 +0200 Subject: net.server_epoll: Make log tag accessible as a field To allow referencing connections by id instead of tostring form --- net/server_epoll.lua | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index fd9e0416..633b038c 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -567,6 +567,7 @@ end local function wrapsocket(client, server, read_size, listeners, tls_ctx, extra) -- luasocket object -> interface object client:settimeout(0); + local conn_id = ("conn%s"):format(new_id()); local conn = setmetatable({ conn = client; _server = server; @@ -576,7 +577,8 @@ local function wrapsocket(client, server, read_size, listeners, tls_ctx, extra) writebuffer = {}; tls_ctx = tls_ctx or (server and server.tls_ctx); tls_direct = server and server.tls_direct; - log = logger.init(("conn%s"):format(new_id())); + id = conn_id; + log = logger.init(conn_id); extra = extra; }, interface_mt); -- cgit v1.2.3 From 6e360554ffaa391f23a9e0bb93adde3f1bd32020 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 29 Sep 2019 15:02:05 +0200 Subject: net.server_epoll: Add debug logging for various connection events --- net/server_epoll.lua | 6 ++++++ 1 file changed, 6 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 633b038c..c3354006 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -630,10 +630,12 @@ function interface:init() end function interface:pause() + self:debug("Pause reading"); return self:set(false); end function interface:resume() + self:debug("Resume reading"); return self:set(true); end @@ -663,12 +665,14 @@ function interface:setlimit(Bps) end function interface:pause_writes() + self:debug("Pause writes"); self._write_lock = true; self:setwritetimeout(false); self:set(nil, false); end function interface:resume_writes() + self:debug("Resume writes"); self._write_lock = nil; if self.writebuffer[1] then self:setwritetimeout(); @@ -678,6 +682,7 @@ end -- Connected! function interface:onconnect() + self:debug("Connected"); self:updatenames(); self.onconnect = noop; self:on("connect"); @@ -784,6 +789,7 @@ end; -- Dump all data from one connection into another local function link(from, to) + from:debug("Linking to %s", to.id); from.listeners = setmetatable({ onincoming = function (_, data) from:pause(); -- cgit v1.2.3 From 4f848e3ea0c92e545b9d162d55959e4f281aca70 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 29 Sep 2019 15:18:40 +0200 Subject: net.server_epoll: Add some timeout related logging --- net/server_epoll.lua | 3 +++ 1 file changed, 3 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index c3354006..250ce4d0 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -261,8 +261,10 @@ function interface:setreadtimeout(t) else self._readtimeout = addtimer(t, function () if self:on("readtimeout") then + self:debug("Read timeout, handled"); return cfg.read_timeout; else + self:debug("Read timeout, fatal"); self:on("disconnect", "read timeout"); self:destroy(); end @@ -284,6 +286,7 @@ function interface:setwritetimeout(t) self._writetimeout:reschedule(gettime() + t); else self._writetimeout = addtimer(t, function () + self:debug("Write timeout"); self:on("disconnect", "write timeout"); self:destroy(); end); -- cgit v1.2.3 From 5eea3358fd7f8ca8b0edb36769b393bb0f1423ca Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 29 Sep 2019 15:36:23 +0200 Subject: net.server_epoll: Handle read size argument to link --- net/server_epoll.lua | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 250ce4d0..c2eb7b1c 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -791,7 +791,7 @@ local function watchfd(fd, onreadable, onwritable) end; -- Dump all data from one connection into another -local function link(from, to) +local function link(from, to, read_size) from:debug("Linking to %s", to.id); from.listeners = setmetatable({ onincoming = function (_, data) @@ -804,6 +804,7 @@ local function link(from, to) from:resume(); end, }, {__index=to.listeners}); + from:set_mode(read_size); from:set(true, nil); to:set(nil, true); end -- cgit v1.2.3 From 79b375cb53b2e160d18309c6f88b9fa70a88d2e5 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 29 Sep 2019 15:41:01 +0200 Subject: net.server_epoll: Fix link function to not replace listeners mod_proxy65 calls link twice, once for each direction. This would overwrite the listeners with one that has the previous listeners as metatable.__index, but none of the others. This takes advantage of 94c584d67533 to improve this. --- net/server_epoll.lua | 14 +++++--------- 1 file changed, 5 insertions(+), 9 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index c2eb7b1c..d2964888 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -793,17 +793,13 @@ end; -- Dump all data from one connection into another local function link(from, to, read_size) from:debug("Linking to %s", to.id); - from.listeners = setmetatable({ - onincoming = function (_, data) - from:pause(); + function from:onincoming(data) + self:pause(); to:write(data); - end, - }, {__index=from.listeners}); - to.listeners = setmetatable({ - ondrain = function () + end + function to:ondrain() from:resume(); - end, - }, {__index=to.listeners}); + end from:set_mode(read_size); from:set(true, nil); to:set(nil, true); -- cgit v1.2.3 From 2feedcb7d6875ff3ae40c615f3087de8a61c999e Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 29 Sep 2019 15:51:21 +0200 Subject: net.server_epoll: Ignore unused self argument [luacheck] --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index d2964888..3aa37ee6 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -797,7 +797,7 @@ local function link(from, to, read_size) self:pause(); to:write(data); end - function to:ondrain() + function to:ondrain() -- luacheck: ignore 212/self from:resume(); end from:set_mode(read_size); -- cgit v1.2.3 From 90d58b619e2533d796e20235cfcd750a55152bf5 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 29 Sep 2019 17:30:54 +0200 Subject: net.server_epoll: Correct indentation --- net/server_epoll.lua | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 3aa37ee6..ab513e93 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -795,10 +795,10 @@ local function link(from, to, read_size) from:debug("Linking to %s", to.id); function from:onincoming(data) self:pause(); - to:write(data); + to:write(data); end function to:ondrain() -- luacheck: ignore 212/self - from:resume(); + from:resume(); end from:set_mode(read_size); from:set(true, nil); -- cgit v1.2.3 From 5cadccc68af00a5d2dcd2ea09c03e713e4fa4739 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 5 Oct 2019 15:22:59 +0200 Subject: net.server_epoll: Return early when attepting to set write lock state to current state Reduces needless duplication of work and log messages.. --- net/server_epoll.lua | 6 ++++++ 1 file changed, 6 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index ab513e93..62db6c86 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -668,6 +668,9 @@ function interface:setlimit(Bps) end function interface:pause_writes() + if self._write_lock then + return + end self:debug("Pause writes"); self._write_lock = true; self:setwritetimeout(false); @@ -675,6 +678,9 @@ function interface:pause_writes() end function interface:resume_writes() + if not self._write_lock then + return + end self:debug("Resume writes"); self._write_lock = nil; if self.writebuffer[1] then -- cgit v1.2.3 From 153ebfe5d719d50312629bb9475bde5500f1da6e Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 5 Oct 2019 18:10:12 +0200 Subject: net.server_epoll: Log size of partial writes (debug) --- net/server_epoll.lua | 1 + 1 file changed, 1 insertion(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 62db6c86..991383ec 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -420,6 +420,7 @@ function interface:onwritable() self:ondrain(); -- Be aware of writes in ondrain return; elseif partial then + self:debug("Sent %d out of %d buffered bytes", partial, #data); buffer[1] = data:sub(partial+1); for i = #buffer, 2, -1 do buffer[i] = nil; -- cgit v1.2.3 From 56e9e471e7501bffa576aa5eef51d9bf3c0561b5 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 6 Oct 2019 16:23:43 +0200 Subject: net.server_epoll: Log TLS version and cipher for all completed handshakes The similar logging in mod_c2s and mod_s2s does not cover all connections, like HTTPS or other Direct TLS ports. --- net/server_epoll.lua | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 991383ec..6c65bcdd 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -548,7 +548,12 @@ function interface:tlshandskake() end local ok, err = self.conn:dohandshake(); if ok then - self:debug("TLS handshake complete"); + if self.conn.info then + local info = self.conn:info(); + self:debug("TLS handshake complete (%s with %s)", info.protocol, info.cipher); + else + self:debug("TLS handshake complete"); + end self.onwritable = nil; self.onreadable = nil; self:on("status", "ssl-handshake-complete"); -- cgit v1.2.3 From 193bc49cac95c2876afcd223379a93eff9855770 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 6 Oct 2019 19:34:03 +0200 Subject: net.server_epoll: Guard against nil return from TLS info method --- net/server_epoll.lua | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 6c65bcdd..cccc8b5d 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -548,8 +548,8 @@ function interface:tlshandskake() end local ok, err = self.conn:dohandshake(); if ok then - if self.conn.info then - local info = self.conn:info(); + local info = self.conn.info and self.conn:info(); + if type(info) == "table" then self:debug("TLS handshake complete (%s with %s)", info.protocol, info.cipher); else self:debug("TLS handshake complete"); -- cgit v1.2.3 From 73d6c64bd7b061a8790919daac19e09cd00fa5e1 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 12 Oct 2019 19:51:29 +0200 Subject: net.server_epoll: Move a log message to improve ordering It was weird that it said "Prepared to start TLS" before "Client .. created" --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index cccc8b5d..3b134312 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -775,10 +775,10 @@ local function addclient(addr, port, listeners, read_size, tls_ctx, typ, extra) local client = wrapsocket(conn, nil, read_size, listeners, tls_ctx, extra) local ok, err = client:init(); if not ok then return ok, err; end + client:debug("Client %s created", client); if tls_ctx then client:starttls(tls_ctx); end - client:debug("Client %s created", client); return client, conn; end -- cgit v1.2.3 From 3585385ab60126105f7e0c7900399ec05c56a781 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 12 Oct 2019 20:07:50 +0200 Subject: net.server_epoll: Fix to get remote IP on direct TLS connections A Direct TLS connection (eg HTTPS) gets turned into a LuaSec handle before the :updatenames call done in the :connect method. LuaSec does not expose the :getpeername and :getsockname methods, so the addresses remain obscured, making debugging trickier since the actual IP addrerss connected to does not show up. --- net/server_epoll.lua | 1 + 1 file changed, 1 insertion(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 3b134312..7a414901 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -521,6 +521,7 @@ function interface:tlshandskake() self._tls = true; self:debug("Starting TLS now"); self:del(); + self:updatenames(); -- Can't getpeer/sockname after wrap() local ok, conn, err = pcall(luasec.wrap, self.conn, self.tls_ctx); if not ok then conn, err = ok, conn; -- cgit v1.2.3 From 3e8be00bbec2bfc691a2fd7fdb4dde33d39a55d4 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 12 Oct 2019 20:12:04 +0200 Subject: net.server_epoll: Handle getpeer/sockname returning a normal error These will sometimes return nil, "Transport not connected" but not throw a hard error. This shouldn't be treated as success. --- net/server_epoll.lua | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 7a414901..3745b426 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -605,11 +605,11 @@ end function interface:updatenames() local conn = self.conn; local ok, peername, peerport = pcall(conn.getpeername, conn); - if ok then + if ok and peername then self.peername, self.peerport = peername, peerport; end local ok, sockname, sockport = pcall(conn.getsockname, conn); - if ok then + if ok and sockname then self.sockname, self.sockport = sockname, sockport; end end -- cgit v1.2.3 From 066ee6e7810f638be65445ef7161ee41b6e33f14 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 12 Oct 2019 20:15:31 +0200 Subject: server_epoll: Log full string represestation when connected Since they may have been unknown when the connection was created. --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 3745b426..9feba360 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -698,8 +698,8 @@ end -- Connected! function interface:onconnect() - self:debug("Connected"); self:updatenames(); + self:debug("Connected (%s)", self); self.onconnect = noop; self:on("connect"); end -- cgit v1.2.3 From c5a70f10627bcdbc1b9f67e055574bbedc801fac Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 12 Oct 2019 20:22:07 +0200 Subject: net.server_epoll: Save IP and port from connection creation call Might come out of :getpeername different later but at least it's something. --- net/server_epoll.lua | 4 ++++ 1 file changed, 4 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 9feba360..a2052875 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -775,6 +775,10 @@ local function addclient(addr, port, listeners, read_size, tls_ctx, typ, extra) if not ok and err ~= "timeout" then return ok, err; end local client = wrapsocket(conn, nil, read_size, listeners, tls_ctx, extra) local ok, err = client:init(); + if not client.peername then + -- otherwise not set until connected + client.peername, client.peerport = addr, port; + end if not ok then return ok, err; end client:debug("Client %s created", client); if tls_ctx then -- cgit v1.2.3 From b87fbcd1e0fb88b63a77d8d0db06e56db6149d0e Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 19 Oct 2019 20:10:14 +0200 Subject: net.server_epoll: Clarify a debug message Writing what? The data that's been buffered for writing --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index a2052875..8f3d28db 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -468,7 +468,7 @@ function interface:close() if self.writebuffer and self.writebuffer[1] then self:set(false, true); -- Flush final buffer contents self.write, self.send = noop, noop; -- No more writing - self:debug("Close after writing"); + self:debug("Close after writing remaining buffered data"); self.ondrain = interface.close; else self:debug("Closing now"); -- cgit v1.2.3 From c9b83c46682de98ed66585e50c2119f6453620db Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 19 Oct 2019 20:11:21 +0200 Subject: net.server_epoll: Improve read timeout debug messages --- net/server_epoll.lua | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 8f3d28db..3a2dcbad 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -261,10 +261,10 @@ function interface:setreadtimeout(t) else self._readtimeout = addtimer(t, function () if self:on("readtimeout") then - self:debug("Read timeout, handled"); + self:debug("Read timeout handled"); return cfg.read_timeout; else - self:debug("Read timeout, fatal"); + self:debug("Read timeout not handled, disconnecting"); self:on("disconnect", "read timeout"); self:destroy(); end -- cgit v1.2.3 From 7b8100dc081e37bd45c1baaf100e2580fe302d06 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 17 Nov 2019 23:27:48 +0100 Subject: net.server_epoll: Save log tag in a field on FD watchers too As with 0e1701197722 --- net/server_epoll.lua | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 3a2dcbad..d6174a4e 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -383,7 +383,7 @@ function interface:onreadable() end if err ~= "timeout" then self:on("disconnect", err); - self:destroy() + self:close() return; end end @@ -802,7 +802,8 @@ local function watchfd(fd, onreadable, onwritable) end; -- Otherwise it'll need to be something LuaSocket-compatible end - conn.log = logger.init(("fdwatch%s"):format(new_id())); + conn.id = new_id(); + conn.log = logger.init(("fdwatch%s"):format(conn.id)); conn:add(onreadable, onwritable); return conn; end; @@ -911,7 +912,8 @@ return { fds[fd] = nil; end; }, interface_mt); - conn.log = logger.init(("fdwatch%d"):format(conn:getfd())); + conn.id = conn:getfd(); + conn.log = logger.init(("fdwatch%d"):format(conn.id)); local ok, err = conn:add(mode == "r" or mode == "rw", mode == "w" or mode == "rw"); if not ok then return ok, err; end return conn; -- cgit v1.2.3 From 7dc9926e110024b70c497481538615a5f89e31c4 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 17 Nov 2019 23:45:44 +0100 Subject: Back out c8aa66595072: Extra changes accidentally included --- net/server_epoll.lua | 8 +++----- 1 file changed, 3 insertions(+), 5 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index d6174a4e..3a2dcbad 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -383,7 +383,7 @@ function interface:onreadable() end if err ~= "timeout" then self:on("disconnect", err); - self:close() + self:destroy() return; end end @@ -802,8 +802,7 @@ local function watchfd(fd, onreadable, onwritable) end; -- Otherwise it'll need to be something LuaSocket-compatible end - conn.id = new_id(); - conn.log = logger.init(("fdwatch%s"):format(conn.id)); + conn.log = logger.init(("fdwatch%s"):format(new_id())); conn:add(onreadable, onwritable); return conn; end; @@ -912,8 +911,7 @@ return { fds[fd] = nil; end; }, interface_mt); - conn.id = conn:getfd(); - conn.log = logger.init(("fdwatch%d"):format(conn.id)); + conn.log = logger.init(("fdwatch%d"):format(conn:getfd())); local ok, err = conn:add(mode == "r" or mode == "rw", mode == "w" or mode == "rw"); if not ok then return ok, err; end return conn; -- cgit v1.2.3 From 970ac1aa6c95fd9d8d1f2de01388dcc5113ef296 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 17 Nov 2019 23:47:31 +0100 Subject: net.server_epoll: Save log tag in a field on FD watchers too As with 0e1701197722 --- net/server_epoll.lua | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 3a2dcbad..d44149f3 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -802,7 +802,8 @@ local function watchfd(fd, onreadable, onwritable) end; -- Otherwise it'll need to be something LuaSocket-compatible end - conn.log = logger.init(("fdwatch%s"):format(new_id())); + conn.id = new_id(); + conn.log = logger.init(("fdwatch%s"):format(conn.id)); conn:add(onreadable, onwritable); return conn; end; @@ -911,7 +912,8 @@ return { fds[fd] = nil; end; }, interface_mt); - conn.log = logger.init(("fdwatch%d"):format(conn:getfd())); + conn.id = conn:getfd(); + conn.log = logger.init(("fdwatch%d"):format(conn.id)); local ok, err = conn:add(mode == "r" or mode == "rw", mode == "w" or mode == "rw"); if not ok then return ok, err; end return conn; -- cgit v1.2.3 From d84a2484dce365fa5047eaf746930f9b6a7dccc2 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 7 Dec 2019 19:05:10 +0100 Subject: net.server_epoll: Add debug logging for delayed reading In :onreadable, if there is still buffered incoming data after reading from the socket (as indicated by the :dirty method, usually because LuaSocket has an 8k buffer that's full but it read a smaller amount), another attempt to read is scheduled via this :pausefor method. This is also called from some other places where it would be pointless to read because there shouldn't be any data. In the delayed read case, this should report that the socket is "dirty". If it reports that the socket is "clean" then the question is where the buffer contents went? If this doesn't get logged after the scheduled time (0.000001s by default) then this would suggests a problem with timer or scheduling. --- net/server_epoll.lua | 1 + 1 file changed, 1 insertion(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index d44149f3..17faa848 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -660,6 +660,7 @@ function interface:pausefor(t) self._pausefor = addtimer(t, function () self._pausefor = nil; self:set(true); + self:debug("Resuming after pause, connection is %s", not self.conn and "missing" or self.conn:dirty() and "dirty" or "clean"); if self.conn and self.conn:dirty() then self:onreadable(); end -- cgit v1.2.3 From 158be3a8f16ff6f713d216e450e23a23e1f577b2 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 8 Dec 2019 13:40:42 +0100 Subject: net.server_epoll: Remove unused function for adding timer at absolute time This won't make sense if we switch to monotonic time --- net/server_epoll.lua | 11 +++-------- 1 file changed, 3 insertions(+), 8 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 17faa848..8af6f484 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -90,18 +90,14 @@ local function reschedule(t, time) timers:reprioritize(t.id, time); end --- Add absolute timer -local function at(time, f) +-- Add relative timer +local function addtimer(timeout, f) + local time = gettime() + timeout; local timer = { time, f, close = closetimer, reschedule = reschedule, id = nil }; timer.id = timers:insert(timer, time); return timer; end --- Add relative timer -local function addtimer(timeout, f) - return at(gettime() + timeout, f); -end - -- Run callbacks of expired timers -- Return time until next timeout local function runtimers(next_delay, min_wait) @@ -879,7 +875,6 @@ return { addclient = addclient; add_task = addtimer; listen = listen; - at = at; loop = loop; closeall = closeall; setquitting = setquitting; -- cgit v1.2.3 From 654d9817ad2211686f3d25d79a72cfe9266f8b58 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 8 Dec 2019 14:20:56 +0100 Subject: net.server_epoll: Change timer rescheduling method to match util.timer Relative to current time instead of absolute time, in preparation for switching to monotonic time. --- net/server_epoll.lua | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 8af6f484..77619b69 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -86,6 +86,7 @@ local function closetimer(t) end local function reschedule(t, time) + time = gettime() + time; t[1] = time; timers:reprioritize(t.id, time); end @@ -253,7 +254,7 @@ function interface:setreadtimeout(t) end t = t or cfg.read_timeout; if self._readtimeout then - self._readtimeout:reschedule(gettime() + t); + self._readtimeout:reschedule(t); else self._readtimeout = addtimer(t, function () if self:on("readtimeout") then @@ -279,7 +280,7 @@ function interface:setwritetimeout(t) end t = t or cfg.send_timeout; if self._writetimeout then - self._writetimeout:reschedule(gettime() + t); + self._writetimeout:reschedule(t); else self._writetimeout = addtimer(t, function () self:debug("Write timeout"); -- cgit v1.2.3 From 9a041bb926ec6596572911b864dd3002d7798dad Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 8 Dec 2019 14:26:32 +0100 Subject: net.server_epoll: Use monotonic time for scheduling Timer API of passing wallclock time remains --- net/server_epoll.lua | 20 +++++++++++--------- 1 file changed, 11 insertions(+), 9 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 77619b69..46fcbf02 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -17,7 +17,8 @@ local logger = require "util.logger"; local log = logger.init("server_epoll"); local socket = require "socket"; local luasec = require "ssl"; -local gettime = require "util.time".now; +local realtime = require "util.time".now; +local monotonic = require "util.time".monotonic; local indexedbheap = require "util.indexedbheap"; local createtable = require "util.table".create; local inet = require "util.net"; @@ -86,14 +87,14 @@ local function closetimer(t) end local function reschedule(t, time) - time = gettime() + time; + time = monotonic() + time; t[1] = time; timers:reprioritize(t.id, time); end -- Add relative timer local function addtimer(timeout, f) - local time = gettime() + timeout; + local time = monotonic() + timeout; local timer = { time, f, close = closetimer, reschedule = reschedule, id = nil }; timer.id = timers:insert(timer, time); return timer; @@ -103,19 +104,20 @@ end -- Return time until next timeout local function runtimers(next_delay, min_wait) -- Any timers at all? - local now = gettime(); + local elapsed = monotonic(); + local now = realtime(); local peek = timers:peek(); while peek do - if peek > now then - next_delay = peek - now; + if peek > elapsed then + next_delay = peek - elapsed; break; end local _, timer, id = timers:pop(); local ok, ret = pcall(timer[2], now); if ok and type(ret) == "number" then - local next_time = now+ret; + local next_time = elapsed+ret; timer[1] = next_time; timers:insert(timer, next_time); end @@ -578,7 +580,7 @@ local function wrapsocket(client, server, read_size, listeners, tls_ctx, extra) local conn = setmetatable({ conn = client; _server = server; - created = gettime(); + created = realtime(); listeners = listeners; read_size = read_size or (server and server.read_size); writebuffer = {}; @@ -708,7 +710,7 @@ local function listen(addr, port, listeners, config) conn:settimeout(0); local server = setmetatable({ conn = conn; - created = gettime(); + created = realtime(); listeners = listeners; read_size = config and config.read_size; onreadable = interface.onacceptable; -- cgit v1.2.3 From c3d1266e34e25c71692c109ee597160d9d7231f3 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Mon, 23 Dec 2019 21:51:52 +0100 Subject: net.server_epoll: Remove an unused variable [luacheck] --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 46fcbf02..e2c5f977 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -114,7 +114,7 @@ local function runtimers(next_delay, min_wait) break; end - local _, timer, id = timers:pop(); + local _, timer = timers:pop(); local ok, ret = pcall(timer[2], now); if ok and type(ret) == "number" then local next_time = elapsed+ret; -- cgit v1.2.3 From d20b12c208ec42372f5cd24ac1334e347762085a Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 28 Dec 2019 06:18:58 +0100 Subject: net.server_epoll: Avoid concatenating buffer with single item Saves creating a string that'll be identical to buffer[1] anyways, as well as a C function call. Depending on Lua version and length of the string, this could be reusing an interned string, but a longer one would probably be duplicated for no reason. Having exactly one item in the buffer seems like it would be fairly common, but I have not done an extensive study. If opportunistic writes are enabled then it will be even more likely. This special case could be optimized like this in table.concat but it does not look like it is. --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index e2c5f977..4ad142ce 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -408,7 +408,7 @@ function interface:onwritable() self:onconnect(); if not self.conn then return; end -- could have been closed in onconnect local buffer = self.writebuffer; - local data = t_concat(buffer); + local data = #buffer == 1 and buffer[1] or t_concat(buffer); local ok, err, partial = self.conn:send(data); if ok then self:set(nil, false); -- cgit v1.2.3 From 25ce791b75a3f6facb3c7c3d48df4a86805f997f Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 5 Jan 2020 02:29:31 +0100 Subject: net.server_epoll: Collect full traceback from errors in listeners --- net/server_epoll.lua | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 4ad142ce..ff69bfbf 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -13,6 +13,7 @@ local pcall = pcall; local type = type; local next = next; local pairs = pairs; +local traceback = debug.traceback; local logger = require "util.logger"; local log = logger.init("server_epoll"); local socket = require "socket"; @@ -25,6 +26,7 @@ local inet = require "util.net"; local inet_pton = inet.pton; local _SOCKETINVALID = socket._SOCKETINVALID or -1; local new_id = require "util.id".medium; +local xpcall = require "util.xpcall".xpcall; local poller = require "util.poll" local EEXIST = poller.EEXIST; @@ -175,7 +177,7 @@ function interface:on(what, ...) -- self:debug("Missing listener 'on%s'", what); -- uncomment for development and debugging return; end - local ok, err = pcall(listener, self, ...); + local ok, err = xpcall(listener, traceback, self, ...); if not ok then if cfg.fatal_errors then self:debug("Closing due to error calling on%s: %s", what, err); -- cgit v1.2.3 From deedb80ea43834999a49e509bed8d55b0810d95b Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 12 Jan 2020 20:35:04 +0100 Subject: net.server_epoll: Add option for reducing debug logging Sometimes all these things just drown out the logs you are interested in with low-level socket noise. Enabled since it's still new and experimental. --- net/server_epoll.lua | 39 +++++++++++++++++++++++++-------------- 1 file changed, 25 insertions(+), 14 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index ff69bfbf..b5c69a6d 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -66,6 +66,10 @@ local default_config = { __index = { max_wait = 86400; min_wait = 1e-06; + -- Enable extra noisy debug logging + -- TODO disable once considered stable + verbose = true; + -- EXPERIMENTAL -- Whether to kill connections in case of callback errors. fatal_errors = false; @@ -155,6 +159,13 @@ function interface:debug(msg, ...) --luacheck: ignore 212/self self.log("debug", msg, ...); end +interface.noise = interface.debug; +function interface:noise(msg, ...) --luacheck: ignore 212/self + if cfg.verbose then + return self:debug(msg, ...); + end +end + function interface:error(msg, ...) --luacheck: ignore 212/self self.log("error", msg, ...); end @@ -174,7 +185,7 @@ function interface:on(what, ...) end local listener = self.listeners["on"..what]; if not listener then - -- self:debug("Missing listener 'on%s'", what); -- uncomment for development and debugging + self:noise("Missing listener 'on%s'", what); -- uncomment for development and debugging return; end local ok, err = xpcall(listener, traceback, self, ...); @@ -262,7 +273,7 @@ function interface:setreadtimeout(t) else self._readtimeout = addtimer(t, function () if self:on("readtimeout") then - self:debug("Read timeout handled"); + self:noise("Read timeout handled"); return cfg.read_timeout; else self:debug("Read timeout not handled, disconnecting"); @@ -287,7 +298,7 @@ function interface:setwritetimeout(t) self._writetimeout:reschedule(t); else self._writetimeout = addtimer(t, function () - self:debug("Write timeout"); + self:noise("Write timeout"); self:on("disconnect", "write timeout"); self:destroy(); end); @@ -312,7 +323,7 @@ function interface:add(r, w) end self._wantread, self._wantwrite = r, w; fds[fd] = self; - self:debug("Registered in poller"); + self:noise("Registered in poller"); return true; end @@ -347,7 +358,7 @@ function interface:del() end self._wantread, self._wantwrite = nil, nil; fds[fd] = nil; - self:debug("Unregistered from poller"); + self:noise("Unregistered from poller"); return true; end @@ -562,15 +573,15 @@ function interface:tlshandskake() self:setwritetimeout(); self:set(true, true); elseif err == "wantread" then - self:debug("TLS handshake to wait until readable"); + self:noise("TLS handshake to wait until readable"); self:set(true, false); self:setreadtimeout(cfg.ssl_handshake_timeout); elseif err == "wantwrite" then - self:debug("TLS handshake to wait until writable"); + self:noise("TLS handshake to wait until writable"); self:set(false, true); self:setwritetimeout(cfg.ssl_handshake_timeout); else - self:debug("TLS handshake error: %s", err); + self:error("TLS handshake error: %s", err); self:on("disconnect", err); self:destroy(); end @@ -641,18 +652,18 @@ function interface:init() end function interface:pause() - self:debug("Pause reading"); + self:noise("Pause reading"); return self:set(false); end function interface:resume() - self:debug("Resume reading"); + self:noise("Resume reading"); return self:set(true); end -- Pause connection for some time function interface:pausefor(t) - self:debug("Pause for %fs", t); + self:noise("Pause for %fs", t); if self._pausefor then self._pausefor:close(); end @@ -661,7 +672,7 @@ function interface:pausefor(t) self._pausefor = addtimer(t, function () self._pausefor = nil; self:set(true); - self:debug("Resuming after pause, connection is %s", not self.conn and "missing" or self.conn:dirty() and "dirty" or "clean"); + self:noise("Resuming after pause, connection is %s", not self.conn and "missing" or self.conn:dirty() and "dirty" or "clean"); if self.conn and self.conn:dirty() then self:onreadable(); end @@ -680,7 +691,7 @@ function interface:pause_writes() if self._write_lock then return end - self:debug("Pause writes"); + self:noise("Pause writes"); self._write_lock = true; self:setwritetimeout(false); self:set(nil, false); @@ -690,7 +701,7 @@ function interface:resume_writes() if not self._write_lock then return end - self:debug("Resume writes"); + self:noise("Resume writes"); self._write_lock = nil; if self.writebuffer[1] then self:setwritetimeout(); -- cgit v1.2.3 From 4a424901c6baefd64fb99acdb019517f6b77d856 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 12 Jan 2020 20:36:04 +0100 Subject: net.server_epoll: Log errors caught in listeners on 'error' level --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index b5c69a6d..74cec7a2 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -191,7 +191,7 @@ function interface:on(what, ...) local ok, err = xpcall(listener, traceback, self, ...); if not ok then if cfg.fatal_errors then - self:debug("Closing due to error calling on%s: %s", what, err); + self:error("Closing due to error calling on%s: %s", what, err); self:destroy(); else self:debug("Error calling on%s: %s", what, err); -- cgit v1.2.3 From 20ad50db57c447158df7162a1f48c3f6ec244553 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sun, 12 Jan 2020 20:36:21 +0100 Subject: net.server_epoll: Log error about missing *all* callbacks at 'error' level --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 74cec7a2..897bd111 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -180,7 +180,7 @@ end -- Call a listener callback function interface:on(what, ...) if not self.listeners then - self:debug("Interface is missing listener callbacks"); + self:error("Interface is missing listener callbacks"); return; end local listener = self.listeners["on"..what]; -- cgit v1.2.3 From 0f96c438e5b03eea8d1a1126333b99a3018c0bfb Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 1 Feb 2020 00:33:08 +0100 Subject: net.server_epoll: Different error to distinguish connection timeout This mirrors what server_event does. --- net/server_epoll.lua | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 897bd111..fa247191 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -299,7 +299,7 @@ function interface:setwritetimeout(t) else self._writetimeout = addtimer(t, function () self:noise("Write timeout"); - self:on("disconnect", "write timeout"); + self:on("disconnect", self._connected and "write timeout" or "connection timeout"); self:destroy(); end); end @@ -711,6 +711,7 @@ end -- Connected! function interface:onconnect() + self._connected = true; self:updatenames(); self:debug("Connected (%s)", self); self.onconnect = noop; -- cgit v1.2.3 From 61b6b340b1fb3c3bfc01e3cb22058cc8a2c52064 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 15 Feb 2020 16:43:18 +0100 Subject: net.server_epoll: Reduce log level of TLS handshake errors to debug These are triggered all the time by random HTTPS connections, so they are mostly just useless noise. When you actually do need them, you probably have debug logging enabled too, since these messages are fairly useless without more context. --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index fa247191..b281d463 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -581,7 +581,7 @@ function interface:tlshandskake() self:set(false, true); self:setwritetimeout(cfg.ssl_handshake_timeout); else - self:error("TLS handshake error: %s", err); + self:debug("TLS handshake error: %s", err); self:on("disconnect", err); self:destroy(); end -- cgit v1.2.3 From a166ab719cbdcb89e7bdfca6f0c89239c7942f57 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Fri, 22 May 2020 15:20:19 +0200 Subject: net.server_epoll: Log some noise before TLS handshake step This would help pinpoint if a crash happens during the handshake, which has occurred a few times, e.g. like https://github.com/brunoos/luasec/issues/75 --- net/server_epoll.lua | 1 + 1 file changed, 1 insertion(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index b281d463..632958ba 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -559,6 +559,7 @@ function interface:tlshandskake() self.onreadable = interface.tlshandskake; return self:init(); end + self:noise("Continuing TLS handshake"); local ok, err = self.conn:dohandshake(); if ok then local info = self.conn.info and self.conn:info(); -- cgit v1.2.3 From 9783208ba5af9749a111cd70761afeed383d751a Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Fri, 22 May 2020 15:36:03 +0200 Subject: net.server_epoll: Fix typo in internal method name --- net/server_epoll.lua | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 632958ba..82f7ab59 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -519,14 +519,14 @@ function interface:starttls(tls_ctx) if self.ondrain == interface.starttls then self.ondrain = nil; end - self.onwritable = interface.tlshandskake; - self.onreadable = interface.tlshandskake; + self.onwritable = interface.tlshandshake; + self.onreadable = interface.tlshandshake; self:set(true, true); self:debug("Prepared to start TLS"); end end -function interface:tlshandskake() +function interface:tlshandshake() self:setwritetimeout(false); self:setreadtimeout(false); if not self._tls then @@ -555,8 +555,8 @@ function interface:tlshandskake() end self:on("starttls"); self.ondrain = nil; - self.onwritable = interface.tlshandskake; - self.onreadable = interface.tlshandskake; + self.onwritable = interface.tlshandshake; + self.onreadable = interface.tlshandshake; return self:init(); end self:noise("Continuing TLS handshake"); -- cgit v1.2.3 From 6ccd66e347747b0fd7b2a193a777b46d913c38ee Mon Sep 17 00:00:00 2001 From: Matthew Wild Date: Mon, 1 Jun 2020 14:26:11 +0100 Subject: net.server_epoll: Handle missing ports from getsock/peername (as in the case of unix sockets) --- net/server_epoll.lua | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 82f7ab59..ded42c4d 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -619,11 +619,11 @@ function interface:updatenames() local conn = self.conn; local ok, peername, peerport = pcall(conn.getpeername, conn); if ok and peername then - self.peername, self.peerport = peername, peerport; + self.peername, self.peerport = peername, peerport or 0; end local ok, sockname, sockport = pcall(conn.getsockname, conn); if ok and sockname then - self.sockname, self.sockport = sockname, sockport; + self.sockname, self.sockport = sockname, sockport or 0; end end -- cgit v1.2.3 From 9708aab9b3b62c87e038f8d33cf64c8d11d53d32 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Mon, 1 Jun 2020 17:19:08 +0200 Subject: net.server_epoll: Add way to start accepting clients on an arbitrary server socket This adds an escape hatch where things like UNIX sockets can be added. --- net/server_epoll.lua | 13 +++++++++---- 1 file changed, 9 insertions(+), 4 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index ded42c4d..f4c14e13 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -719,10 +719,7 @@ function interface:onconnect() self:on("connect"); end -local function listen(addr, port, listeners, config) - local conn, err = socket.bind(addr, port, cfg.tcp_backlog); - if not conn then return conn, err; end - conn:settimeout(0); +local function wrapserver(conn, addr, port, listeners, config) local server = setmetatable({ conn = conn; created = realtime(); @@ -741,6 +738,13 @@ local function listen(addr, port, listeners, config) return server; end +local function listen(addr, port, listeners, config) + local conn, err = socket.bind(addr, port, cfg.tcp_backlog); + if not conn then return conn, err; end + conn:settimeout(0); + return wrapserver(conn, addr, port, listeners, config); +end + -- COMPAT local function addserver(addr, port, listeners, read_size, tls_ctx) return listen(addr, port, listeners, { @@ -897,6 +901,7 @@ return { closeall = closeall; setquitting = setquitting; wrapclient = wrapclient; + wrapserver = wrapserver; watchfd = watchfd; link = link; set_config = function (newconfig) -- cgit v1.2.3 From 927ef9f2f233b616d66e736dc19cd7e4d62dfcc7 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Mon, 29 Jun 2020 16:42:16 +0200 Subject: net.server_epoll: Make API-compatible with util.timer --- net/server_epoll.lua | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index f4c14e13..fbe11401 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -99,9 +99,9 @@ local function reschedule(t, time) end -- Add relative timer -local function addtimer(timeout, f) +local function addtimer(timeout, f, param) local time = monotonic() + timeout; - local timer = { time, f, close = closetimer, reschedule = reschedule, id = nil }; + local timer = { time, f, param, close = closetimer, reschedule = reschedule, id = nil }; timer.id = timers:insert(timer, time); return timer; end @@ -121,7 +121,7 @@ local function runtimers(next_delay, min_wait) end local _, timer = timers:pop(); - local ok, ret = pcall(timer[2], now); + local ok, ret = pcall(timer[2], now, timer, timer[3]); if ok and type(ret) == "number" then local next_time = elapsed+ret; timer[1] = next_time; -- cgit v1.2.3 From ee10afcfabfce801deb7b07882674264f3892390 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Mon, 29 Jun 2020 17:13:05 +0200 Subject: net.server_epoll: Signal API-compatibilty with util.timer Reduces the overhead of having both util.timer and the timer handling here, since they are very similar and now API-compatible. --- net/server_epoll.lua | 6 ++++++ 1 file changed, 6 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index fbe11401..b7a11e8b 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -896,6 +896,12 @@ return { addserver = addserver; addclient = addclient; add_task = addtimer; + timer = { + -- API-compatible with util.timer + add_task = addtimer; + stop = closetimer; + reschedule = reschedule; + }; listen = listen; loop = loop; closeall = closeall; -- cgit v1.2.3 From 2b81c3b50f78236db6cf91d80eaee161de384dc9 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Mon, 29 Jun 2020 20:13:12 +0200 Subject: net.server_epoll: Remove unused time field from timer objects Unused since the move to util.indexedbheap in c8c3f2eba898 --- net/server_epoll.lua | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index b7a11e8b..f65be224 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -87,21 +87,19 @@ local timers = indexedbheap.create(); local function noop() end local function closetimer(t) - t[1] = 0; - t[2] = noop; + t[1] = noop; timers:remove(t.id); end local function reschedule(t, time) time = monotonic() + time; - t[1] = time; timers:reprioritize(t.id, time); end -- Add relative timer local function addtimer(timeout, f, param) local time = monotonic() + timeout; - local timer = { time, f, param, close = closetimer, reschedule = reschedule, id = nil }; + local timer = { f, param, close = closetimer, reschedule = reschedule, id = nil }; timer.id = timers:insert(timer, time); return timer; end @@ -121,10 +119,9 @@ local function runtimers(next_delay, min_wait) end local _, timer = timers:pop(); - local ok, ret = pcall(timer[2], now, timer, timer[3]); + local ok, ret = pcall(timer[1], now, timer, timer[2]); if ok and type(ret) == "number" then local next_time = elapsed+ret; - timer[1] = next_time; timers:insert(timer, next_time); end -- cgit v1.2.3 From a1ae266ff7913c4dbc50856ab191c15e92bd6e8a Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Mon, 29 Jun 2020 20:23:59 +0200 Subject: net.server_epoll: Optimize away table allocation for timer objects --- net/server_epoll.lua | 36 +++++++++++++++++++++--------------- 1 file changed, 21 insertions(+), 15 deletions(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index f65be224..e4bf7708 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -86,22 +86,27 @@ local fds = createtable(10, 0); -- FD -> conn local timers = indexedbheap.create(); local function noop() end -local function closetimer(t) - t[1] = noop; - timers:remove(t.id); +local function closetimer(id) + timers:remove(id); end -local function reschedule(t, time) +local function reschedule(id, time) time = monotonic() + time; - timers:reprioritize(t.id, time); + timers:reprioritize(id, time); end -- Add relative timer local function addtimer(timeout, f, param) local time = monotonic() + timeout; - local timer = { f, param, close = closetimer, reschedule = reschedule, id = nil }; - timer.id = timers:insert(timer, time); - return timer; + if param ~= nil then + local timer_callback = f + function f(current_time, timer_id) + local t = timer_callback(current_time, timer_id, param) + return t; + end + end + local id = timers:insert(f, time); + return id; end -- Run callbacks of expired timers @@ -118,8 +123,8 @@ local function runtimers(next_delay, min_wait) break; end - local _, timer = timers:pop(); - local ok, ret = pcall(timer[1], now, timer, timer[2]); + local _, timer, id = timers:pop(); + local ok, ret = pcall(timer, now, id); if ok and type(ret) == "number" then local next_time = elapsed+ret; timers:insert(timer, next_time); @@ -259,14 +264,14 @@ end function interface:setreadtimeout(t) if t == false then if self._readtimeout then - self._readtimeout:close(); + closetimer(self._readtimeout); self._readtimeout = nil; end return end t = t or cfg.read_timeout; if self._readtimeout then - self._readtimeout:reschedule(t); + reschedule(self._readtimeout, t); else self._readtimeout = addtimer(t, function () if self:on("readtimeout") then @@ -285,14 +290,14 @@ end function interface:setwritetimeout(t) if t == false then if self._writetimeout then - self._writetimeout:close(); + closetimer(self._writetimeout); self._writetimeout = nil; end return end t = t or cfg.send_timeout; if self._writetimeout then - self._writetimeout:reschedule(t); + reschedule(self._writetimeout, t); else self._writetimeout = addtimer(t, function () self:noise("Write timeout"); @@ -663,7 +668,8 @@ end function interface:pausefor(t) self:noise("Pause for %fs", t); if self._pausefor then - self._pausefor:close(); + closetimer(self._pausefor); + self._pausefor = nil; end if t == false then return; end self:set(false); -- cgit v1.2.3 From 8ac1c4193c3a63b85e45c08b14cd63a29c5c2fc9 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Tue, 30 Jun 2020 02:31:29 +0200 Subject: net.server_epoll: Expose way to turn monotonic time into wall clock time --- net/server_epoll.lua | 3 +++ 1 file changed, 3 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index e4bf7708..c5d5ec6c 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -904,6 +904,9 @@ return { add_task = addtimer; stop = closetimer; reschedule = reschedule; + to_absolute_time = function (t) + return t-monotonic()+realtime(); + end; }; listen = listen; loop = loop; -- cgit v1.2.3 From 6baa04b056c6090a1b236eef246eed914c91da83 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Tue, 30 Jun 2020 17:33:48 +0200 Subject: net.server_epoll: Report errors in timers --- net/server_epoll.lua | 2 ++ 1 file changed, 2 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index c5d5ec6c..64f79921 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -128,6 +128,8 @@ local function runtimers(next_delay, min_wait) if ok and type(ret) == "number" then local next_time = elapsed+ret; timers:insert(timer, next_time); + elseif not ok then + log("error", "Error in timer: %s", ret); end peek = timers:peek(); -- cgit v1.2.3 From 0a071df2d476cabe6153b250189ca6fa0e8a1762 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Tue, 30 Jun 2020 17:34:39 +0200 Subject: net.server_epoll: ... and include a traceback --- net/server_epoll.lua | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 64f79921..f102f806 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -124,7 +124,7 @@ local function runtimers(next_delay, min_wait) end local _, timer, id = timers:pop(); - local ok, ret = pcall(timer, now, id); + local ok, ret = xpcall(timer, traceback, now, id); if ok and type(ret) == "number" then local next_time = elapsed+ret; timers:insert(timer, next_time); -- cgit v1.2.3 From 7acd39cdbef144ecf3f32d4237de945c188fd5be Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Tue, 30 Jun 2020 17:35:07 +0200 Subject: net.server_epoll: Allow setting a custom error handler for listener This lets plugins handle errors in some custom way, should they wish to. --- net/server_epoll.lua | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index f102f806..5ad20371 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -192,7 +192,8 @@ function interface:on(what, ...) self:noise("Missing listener 'on%s'", what); -- uncomment for development and debugging return; end - local ok, err = xpcall(listener, traceback, self, ...); + local onerror = self.listeners.onerror or traceback; + local ok, err = xpcall(listener, onerror, self, ...); if not ok then if cfg.fatal_errors then self:error("Closing due to error calling on%s: %s", what, err); -- cgit v1.2.3 From 8b9da402600ec5cea44968b05bfe0ccf92cf0999 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Tue, 30 Jun 2020 18:31:48 +0200 Subject: net.server_epoll: Add setting for turning off callback protections Might improve (CPU) performance at the risk of triggering top level errors. --- net/server_epoll.lua | 6 ++++++ 1 file changed, 6 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index 5ad20371..f767db78 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -74,6 +74,9 @@ local default_config = { __index = { -- Whether to kill connections in case of callback errors. fatal_errors = false; + -- Or disable protection (like server_select) for potential performance gains + protect_listeners = true; + -- Attempt writes instantly opportunistic_writes = false; }}; @@ -192,6 +195,9 @@ function interface:on(what, ...) self:noise("Missing listener 'on%s'", what); -- uncomment for development and debugging return; end + if not cfg.protect_listeners then + return listener(self, ...); + end local onerror = self.listeners.onerror or traceback; local ok, err = xpcall(listener, onerror, self, ...); if not ok then -- cgit v1.2.3 From 7c00bae93a5034e1fdcae5ed2052439fe995a709 Mon Sep 17 00:00:00 2001 From: Kim Alvefur Date: Sat, 25 Jul 2020 17:26:11 +0200 Subject: net.server_epoll: Log debug message when a connection errors on read It's confusingly quiet otherwise, even with maximum verboseness. Thanks perflyst --- net/server_epoll.lua | 5 +++++ 1 file changed, 5 insertions(+) (limited to 'net/server_epoll.lua') diff --git a/net/server_epoll.lua b/net/server_epoll.lua index f767db78..32b2f032 100644 --- a/net/server_epoll.lua +++ b/net/server_epoll.lua @@ -405,6 +405,11 @@ function interface:onreadable() self:onincoming(partial, err); end if err ~= "timeout" then + if err == "closed" then + self:debug("Connection closed by remote"); + else + self:debug("Read error, closing (%s)", err); + end self:on("disconnect", err); self:destroy() return; -- cgit v1.2.3