Annotate

util/logger.lua @ 13652:a08065207ef0

net.server_epoll: Call :shutdown() on TLS sockets when supported Comment from Matthew: This fixes a potential issue where the Prosody process gets blocked on sockets waiting for them to close. Unlike non-TLS sockets, closing a TLS socket sends layer 7 data, and this can cause problems for sockets which are in the process of being cleaned up. This depends on LuaSec changes which are not yet upstream. From Martijn's original email: So first my analysis of luasec. in ssl.c the socket is put into blocking mode right before calling SSL_shutdown() inside meth_destroy(). My best guess to why this is is because meth_destroy is linked to the __close and __gc methods, which can't exactly be called multiple times and luasec does want to make sure that a tls session is shutdown as clean as possible. I can't say I disagree with this reasoning and don't want to change this behaviour. My solution to this without changing the current behaviour is to introduce a shutdown() method. I am aware that this overlaps in a conflicting way with tcp's shutdown method, but it stays close to the OpenSSL name. This method calls SSL_shutdown() in the current (non)blocking mode of the underlying socket and returns a boolean whether or not the shutdown is completed (matching SSL_shutdown()'s 0 or 1 return values), and returns the familiar ssl_ioerror() strings on error with a false for completion. This error can then be used to determine if we have wantread/wantwrite to finalize things. Once meth_shutdown() has been called once a shutdown flag will be set, which indicates to meth_destroy() that the SSL_shutdown() has been handled by the application and it shouldn't be needed to set the socket to blocking mode. I've left the SSL_shutdown() call in the LSEC_STATE_CONNECTED to prevent TOCTOU if the application reaches a timeout for the shutdown code, which might allow SSL_shutdown() to clean up anyway at the last possible moment. Another thing I've changed to luasec is the call to socket_setblocking() right before calling close(2) in socket_destroy() in usocket.c. According to the latest POSIX[0]: Note that the requirement for close() on a socket to block for up to the current linger interval is not conditional on the O_NONBLOCK setting. Which I read to mean that removing O_NONBLOCK on the socket before close doesn't impact the behaviour and only causes noise in system call tracers. I didn't touch the windows bits of this, since I don't do windows. For the prosody side of things I've made the TLS shutdown bits resemble interface:onwritable(), and put it under a combined guard of self._tls and self.conn.shutdown. The self._tls bit is there to prevent getting stuck on this condition, and self.conn.shutdown is there to prevent the code being called by instances where the patched luasec isn't deployed. The destroy() method can be called from various places and is read by me as the "we give up" error path. To accommodate for these unexpected entrypoints I've added a single call to self.conn:shutdown() to prevent the socket being put into blocking mode. I have no expectations that there is any other use here. Same as previous, the self.conn.shutdown check is there to make sure it's not called on unpatched luasec deployments and self._tls is there to make sure we don't call shutdown() on tcp sockets. I wouldn't recommend logging of the conn:shutdown() error inside close(), since a lot of clients simply close the connection before SSL_shutdown() is done.
author Martijn van Duren <martijn@openbsd.org>
date Thu, 06 Feb 2025 15:04:38 +0000
parent 12975:d10957394a3c
Ignore whitespace changes - Everywhere: Within whitespace: At end of lines:
rev   line source
1523
841d61be198f Remove version number from copyright headers
Matthew Wild <mwild1@gmail.com>
parents: 1020
diff changeset
1 -- Prosody IM
2923
b7049746bd29 Update copyright headers for 2010
Matthew Wild <mwild1@gmail.com>
parents: 1523
diff changeset
2 -- Copyright (C) 2008-2010 Matthew Wild
b7049746bd29 Update copyright headers for 2010
Matthew Wild <mwild1@gmail.com>
parents: 1523
diff changeset
3 -- Copyright (C) 2008-2010 Waqas Hussain
5776
bd0ff8ae98a8 Remove all trailing whitespace
Florian Zeitz <florob@babelmonkeys.de>
parents: 4937
diff changeset
4 --
758
b1885732e979 GPL->MIT!
Matthew Wild <mwild1@gmail.com>
parents: 716
diff changeset
5 -- This project is MIT/X11 licensed. Please see the
b1885732e979 GPL->MIT!
Matthew Wild <mwild1@gmail.com>
parents: 716
diff changeset
6 -- COPYING file in the source package for more information.
519
cccd610a0ef9 Insert copyright/license headers
Matthew Wild <mwild1@gmail.com>
parents: 437
diff changeset
7 --
7131
ea3eea291321 util.logger: Silence luacheck warning
Kim Alvefur <zash@zash.se>
parents: 7130
diff changeset
8 -- luacheck: ignore 213/level
519
cccd610a0ef9 Insert copyright/license headers
Matthew Wild <mwild1@gmail.com>
parents: 437
diff changeset
9
7130
2b48ce0bfe7d util.logger: Remove unused locals
Kim Alvefur <zash@zash.se>
parents: 6777
diff changeset
10 local pairs = pairs;
8556
5800f0c7afd6 util.logger: Import globals (fixes on Lua 5.2)
Kim Alvefur <zash@zash.se>
parents: 8555
diff changeset
11 local ipairs = ipairs;
5800f0c7afd6 util.logger: Import globals (fixes on Lua 5.2)
Kim Alvefur <zash@zash.se>
parents: 8555
diff changeset
12 local require = require;
12394
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
13 local t_remove = table.remove;
262
8c73fb2ff4a2 A treat for Linux users ;)
Matthew Wild <mwild1@gmail.com>
parents: 259
diff changeset
14
6777
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
15 local _ENV = nil;
8555
4f0f5b49bb03 vairious: Add annotation when an empty environment is set [luacheck]
Kim Alvefur <zash@zash.se>
parents: 8553
diff changeset
16 -- luacheck: std none
30
bcf539295f2d Huge commit to:
Matthew Wild <mwild1@gmail.com>
parents:
diff changeset
17
4627
b046cafc81a8 loggingmanager, util.logger: Remove name sinks and the ability to filter logs by source name (lots of code, hardly used if at all, and possibly broken)
Matthew Wild <mwild1@gmail.com>
parents: 3556
diff changeset
18 local level_sinks = {};
262
8c73fb2ff4a2 A treat for Linux users ;)
Matthew Wild <mwild1@gmail.com>
parents: 259
diff changeset
19
1015
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
20 local make_logger;
582
8eb45a8099c4 Make it possible to set custom output handler for logger
Matthew Wild <mwild1@gmail.com>
parents: 519
diff changeset
21
6777
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
22 local function init(name)
1015
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
23 local log_debug = make_logger(name, "debug");
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
24 local log_info = make_logger(name, "info");
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
25 local log_warn = make_logger(name, "warn");
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
26 local log_error = make_logger(name, "error");
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
27
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
28 return function (level, message, ...)
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
29 if level == "debug" then
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
30 return log_debug(message, ...);
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
31 elseif level == "info" then
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
32 return log_info(message, ...);
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
33 elseif level == "warn" then
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
34 return log_warn(message, ...);
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
35 elseif level == "error" then
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
36 return log_error(message, ...);
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
37 end
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
38 end
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
39 end
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
40
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
41 function make_logger(source_name, level)
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
42 local level_handlers = level_sinks[level];
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
43 if not level_handlers then
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
44 level_handlers = {};
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
45 level_sinks[level] = level_handlers;
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
46 end
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
47
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
48 local logger = function (message, ...)
3554
1770f8aaf04a util.logger: Remove my precious premature optimisation :(
Matthew Wild <mwild1@gmail.com>
parents: 3540
diff changeset
49 for i = 1,#level_handlers do
1015
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
50 level_handlers[i](source_name, level, message, ...);
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
51 end
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
52 end
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
53
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
54 return logger;
30
bcf539295f2d Huge commit to:
Matthew Wild <mwild1@gmail.com>
parents:
diff changeset
55 end
bcf539295f2d Huge commit to:
Matthew Wild <mwild1@gmail.com>
parents:
diff changeset
56
6777
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
57 local function reset()
3357
1dd83dd2b832 util.logger: Add reset() method to clear all sinks
Matthew Wild <mwild1@gmail.com>
parents: 2923
diff changeset
58 for level, handler_list in pairs(level_sinks) do
1dd83dd2b832 util.logger: Add reset() method to clear all sinks
Matthew Wild <mwild1@gmail.com>
parents: 2923
diff changeset
59 -- Clear all handlers for this level
1dd83dd2b832 util.logger: Add reset() method to clear all sinks
Matthew Wild <mwild1@gmail.com>
parents: 2923
diff changeset
60 for i = 1, #handler_list do
1dd83dd2b832 util.logger: Add reset() method to clear all sinks
Matthew Wild <mwild1@gmail.com>
parents: 2923
diff changeset
61 handler_list[i] = nil;
1dd83dd2b832 util.logger: Add reset() method to clear all sinks
Matthew Wild <mwild1@gmail.com>
parents: 2923
diff changeset
62 end
1dd83dd2b832 util.logger: Add reset() method to clear all sinks
Matthew Wild <mwild1@gmail.com>
parents: 2923
diff changeset
63 end
1dd83dd2b832 util.logger: Add reset() method to clear all sinks
Matthew Wild <mwild1@gmail.com>
parents: 2923
diff changeset
64 end
1dd83dd2b832 util.logger: Add reset() method to clear all sinks
Matthew Wild <mwild1@gmail.com>
parents: 2923
diff changeset
65
6777
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
66 local function add_level_sink(level, sink_function)
1015
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
67 if not level_sinks[level] then
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
68 level_sinks[level] = { sink_function };
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
69 else
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
70 level_sinks[level][#level_sinks[level] + 1 ] = sink_function;
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
71 end
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
72 end
9e31e9397cff util.logger: Revamped logger library, but backwards-compatible for users of logger.init()
Matthew Wild <mwild1@gmail.com>
parents: 977
diff changeset
73
8553
32438665dc5e util.logger: New method 'add_simple_sink', logger.add_simple_sink(print) works
Matthew Wild <mwild1@gmail.com>
parents: 7131
diff changeset
74 local function add_simple_sink(simple_sink_function, levels)
12975
d10957394a3c util: Prefix module imports with prosody namespace
Kim Alvefur <zash@zash.se>
parents: 12395
diff changeset
75 local format = require "prosody.util.format".format;
8553
32438665dc5e util.logger: New method 'add_simple_sink', logger.add_simple_sink(print) works
Matthew Wild <mwild1@gmail.com>
parents: 7131
diff changeset
76 local function sink_function(name, level, msg, ...)
32438665dc5e util.logger: New method 'add_simple_sink', logger.add_simple_sink(print) works
Matthew Wild <mwild1@gmail.com>
parents: 7131
diff changeset
77 return simple_sink_function(name, level, format(msg, ...));
32438665dc5e util.logger: New method 'add_simple_sink', logger.add_simple_sink(print) works
Matthew Wild <mwild1@gmail.com>
parents: 7131
diff changeset
78 end
32438665dc5e util.logger: New method 'add_simple_sink', logger.add_simple_sink(print) works
Matthew Wild <mwild1@gmail.com>
parents: 7131
diff changeset
79 for _, level in ipairs(levels or {"debug", "info", "warn", "error"}) do
32438665dc5e util.logger: New method 'add_simple_sink', logger.add_simple_sink(print) works
Matthew Wild <mwild1@gmail.com>
parents: 7131
diff changeset
80 add_level_sink(level, sink_function);
32438665dc5e util.logger: New method 'add_simple_sink', logger.add_simple_sink(print) works
Matthew Wild <mwild1@gmail.com>
parents: 7131
diff changeset
81 end
12395
1e34b910b73a util.logger: Return sink_function from add_simple_sink()
Matthew Wild <mwild1@gmail.com>
parents: 12394
diff changeset
82 return sink_function;
8553
32438665dc5e util.logger: New method 'add_simple_sink', logger.add_simple_sink(print) works
Matthew Wild <mwild1@gmail.com>
parents: 7131
diff changeset
83 end
32438665dc5e util.logger: New method 'add_simple_sink', logger.add_simple_sink(print) works
Matthew Wild <mwild1@gmail.com>
parents: 7131
diff changeset
84
12394
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
85 local function remove_sink(sink_function)
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
86 local removed;
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
87 for level, sinks in pairs(level_sinks) do
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
88 for i = #sinks, 1, -1 do
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
89 if sinks[i] == sink_function then
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
90 t_remove(sinks, i);
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
91 removed = true;
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
92 end
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
93 end
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
94 end
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
95 return removed;
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
96 end
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
97
6777
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
98 return {
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
99 init = init;
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
100 make_logger = make_logger;
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
101 reset = reset;
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
102 add_level_sink = add_level_sink;
8553
32438665dc5e util.logger: New method 'add_simple_sink', logger.add_simple_sink(print) works
Matthew Wild <mwild1@gmail.com>
parents: 7131
diff changeset
103 add_simple_sink = add_simple_sink;
6777
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
104 new = make_logger;
12394
86d6b069b892 util.logger: Support for removing individual log sinks without a full reset
Matthew Wild <mwild1@gmail.com>
parents: 8556
diff changeset
105 remove_sink = remove_sink;
6777
5de6b93d0190 util.*: Remove use of module() function, make all module functions local and return them in a table at the end
Kim Alvefur <zash@zash.se>
parents: 5776
diff changeset
106 };