Comparison

net/server_epoll.lua @ 10587:863aa36a9dd8

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.
author Kim Alvefur <zash@zash.se>
date Sun, 12 Jan 2020 20:35:04 +0100
parent 10586:f86ed818a7f8
child 10588:ceadf3d3fecf
comparison
equal deleted inserted replaced
10586:f86ed818a7f8 10587:863aa36a9dd8
64 64
65 -- Maximum and minimum amount of time to sleep waiting for events (adjusted for pending timers) 65 -- Maximum and minimum amount of time to sleep waiting for events (adjusted for pending timers)
66 max_wait = 86400; 66 max_wait = 86400;
67 min_wait = 1e-06; 67 min_wait = 1e-06;
68 68
69 -- Enable extra noisy debug logging
70 -- TODO disable once considered stable
71 verbose = true;
72
69 -- EXPERIMENTAL 73 -- EXPERIMENTAL
70 -- Whether to kill connections in case of callback errors. 74 -- Whether to kill connections in case of callback errors.
71 fatal_errors = false; 75 fatal_errors = false;
72 76
73 -- Attempt writes instantly 77 -- Attempt writes instantly
153 interface.log = log; 157 interface.log = log;
154 function interface:debug(msg, ...) --luacheck: ignore 212/self 158 function interface:debug(msg, ...) --luacheck: ignore 212/self
155 self.log("debug", msg, ...); 159 self.log("debug", msg, ...);
156 end 160 end
157 161
162 interface.noise = interface.debug;
163 function interface:noise(msg, ...) --luacheck: ignore 212/self
164 if cfg.verbose then
165 return self:debug(msg, ...);
166 end
167 end
168
158 function interface:error(msg, ...) --luacheck: ignore 212/self 169 function interface:error(msg, ...) --luacheck: ignore 212/self
159 self.log("error", msg, ...); 170 self.log("error", msg, ...);
160 end 171 end
161 172
162 -- Replace the listener and tell the old one 173 -- Replace the listener and tell the old one
172 self:debug("Interface is missing listener callbacks"); 183 self:debug("Interface is missing listener callbacks");
173 return; 184 return;
174 end 185 end
175 local listener = self.listeners["on"..what]; 186 local listener = self.listeners["on"..what];
176 if not listener then 187 if not listener then
177 -- self:debug("Missing listener 'on%s'", what); -- uncomment for development and debugging 188 self:noise("Missing listener 'on%s'", what); -- uncomment for development and debugging
178 return; 189 return;
179 end 190 end
180 local ok, err = xpcall(listener, traceback, self, ...); 191 local ok, err = xpcall(listener, traceback, self, ...);
181 if not ok then 192 if not ok then
182 if cfg.fatal_errors then 193 if cfg.fatal_errors then
260 if self._readtimeout then 271 if self._readtimeout then
261 self._readtimeout:reschedule(t); 272 self._readtimeout:reschedule(t);
262 else 273 else
263 self._readtimeout = addtimer(t, function () 274 self._readtimeout = addtimer(t, function ()
264 if self:on("readtimeout") then 275 if self:on("readtimeout") then
265 self:debug("Read timeout handled"); 276 self:noise("Read timeout handled");
266 return cfg.read_timeout; 277 return cfg.read_timeout;
267 else 278 else
268 self:debug("Read timeout not handled, disconnecting"); 279 self:debug("Read timeout not handled, disconnecting");
269 self:on("disconnect", "read timeout"); 280 self:on("disconnect", "read timeout");
270 self:destroy(); 281 self:destroy();
285 t = t or cfg.send_timeout; 296 t = t or cfg.send_timeout;
286 if self._writetimeout then 297 if self._writetimeout then
287 self._writetimeout:reschedule(t); 298 self._writetimeout:reschedule(t);
288 else 299 else
289 self._writetimeout = addtimer(t, function () 300 self._writetimeout = addtimer(t, function ()
290 self:debug("Write timeout"); 301 self:noise("Write timeout");
291 self:on("disconnect", "write timeout"); 302 self:on("disconnect", "write timeout");
292 self:destroy(); 303 self:destroy();
293 end); 304 end);
294 end 305 end
295 end 306 end
310 self:debug("Could not register in poller: %s(%d)", err, errno); 321 self:debug("Could not register in poller: %s(%d)", err, errno);
311 return ok, err; 322 return ok, err;
312 end 323 end
313 self._wantread, self._wantwrite = r, w; 324 self._wantread, self._wantwrite = r, w;
314 fds[fd] = self; 325 fds[fd] = self;
315 self:debug("Registered in poller"); 326 self:noise("Registered in poller");
316 return true; 327 return true;
317 end 328 end
318 329
319 function interface:set(r, w) 330 function interface:set(r, w)
320 local fd = self:getfd(); 331 local fd = self:getfd();
345 self:debug("Could not unregister: %s(%d)", err, errno); 356 self:debug("Could not unregister: %s(%d)", err, errno);
346 return ok, err; 357 return ok, err;
347 end 358 end
348 self._wantread, self._wantwrite = nil, nil; 359 self._wantread, self._wantwrite = nil, nil;
349 fds[fd] = nil; 360 fds[fd] = nil;
350 self:debug("Unregistered from poller"); 361 self:noise("Unregistered from poller");
351 return true; 362 return true;
352 end 363 end
353 364
354 function interface:setflags(r, w) 365 function interface:setflags(r, w)
355 if not(self._wantread or self._wantwrite) then 366 if not(self._wantread or self._wantwrite) then
560 self.onreadable = nil; 571 self.onreadable = nil;
561 self:on("status", "ssl-handshake-complete"); 572 self:on("status", "ssl-handshake-complete");
562 self:setwritetimeout(); 573 self:setwritetimeout();
563 self:set(true, true); 574 self:set(true, true);
564 elseif err == "wantread" then 575 elseif err == "wantread" then
565 self:debug("TLS handshake to wait until readable"); 576 self:noise("TLS handshake to wait until readable");
566 self:set(true, false); 577 self:set(true, false);
567 self:setreadtimeout(cfg.ssl_handshake_timeout); 578 self:setreadtimeout(cfg.ssl_handshake_timeout);
568 elseif err == "wantwrite" then 579 elseif err == "wantwrite" then
569 self:debug("TLS handshake to wait until writable"); 580 self:noise("TLS handshake to wait until writable");
570 self:set(false, true); 581 self:set(false, true);
571 self:setwritetimeout(cfg.ssl_handshake_timeout); 582 self:setwritetimeout(cfg.ssl_handshake_timeout);
572 else 583 else
573 self:debug("TLS handshake error: %s", err); 584 self:error("TLS handshake error: %s", err);
574 self:on("disconnect", err); 585 self:on("disconnect", err);
575 self:destroy(); 586 self:destroy();
576 end 587 end
577 end 588 end
578 589
639 self:setwritetimeout(cfg.connect_timeout); 650 self:setwritetimeout(cfg.connect_timeout);
640 return self:add(true, true); 651 return self:add(true, true);
641 end 652 end
642 653
643 function interface:pause() 654 function interface:pause()
644 self:debug("Pause reading"); 655 self:noise("Pause reading");
645 return self:set(false); 656 return self:set(false);
646 end 657 end
647 658
648 function interface:resume() 659 function interface:resume()
649 self:debug("Resume reading"); 660 self:noise("Resume reading");
650 return self:set(true); 661 return self:set(true);
651 end 662 end
652 663
653 -- Pause connection for some time 664 -- Pause connection for some time
654 function interface:pausefor(t) 665 function interface:pausefor(t)
655 self:debug("Pause for %fs", t); 666 self:noise("Pause for %fs", t);
656 if self._pausefor then 667 if self._pausefor then
657 self._pausefor:close(); 668 self._pausefor:close();
658 end 669 end
659 if t == false then return; end 670 if t == false then return; end
660 self:set(false); 671 self:set(false);
661 self._pausefor = addtimer(t, function () 672 self._pausefor = addtimer(t, function ()
662 self._pausefor = nil; 673 self._pausefor = nil;
663 self:set(true); 674 self:set(true);
664 self:debug("Resuming after pause, connection is %s", not self.conn and "missing" or self.conn:dirty() and "dirty" or "clean"); 675 self:noise("Resuming after pause, connection is %s", not self.conn and "missing" or self.conn:dirty() and "dirty" or "clean");
665 if self.conn and self.conn:dirty() then 676 if self.conn and self.conn:dirty() then
666 self:onreadable(); 677 self:onreadable();
667 end 678 end
668 end); 679 end);
669 end 680 end
678 689
679 function interface:pause_writes() 690 function interface:pause_writes()
680 if self._write_lock then 691 if self._write_lock then
681 return 692 return
682 end 693 end
683 self:debug("Pause writes"); 694 self:noise("Pause writes");
684 self._write_lock = true; 695 self._write_lock = true;
685 self:setwritetimeout(false); 696 self:setwritetimeout(false);
686 self:set(nil, false); 697 self:set(nil, false);
687 end 698 end
688 699
689 function interface:resume_writes() 700 function interface:resume_writes()
690 if not self._write_lock then 701 if not self._write_lock then
691 return 702 return
692 end 703 end
693 self:debug("Resume writes"); 704 self:noise("Resume writes");
694 self._write_lock = nil; 705 self._write_lock = nil;
695 if self.writebuffer[1] then 706 if self.writebuffer[1] then
696 self:setwritetimeout(); 707 self:setwritetimeout();
697 self:set(nil, true); 708 self:set(nil, true);
698 end 709 end