Mercurial > prosody-modules
annotate mod_log_slow_events/mod_log_slow_events.lua @ 4651:8231774f5bfd
mod_cloud_notify_encrypted: Ensure body substring remains valid UTF-8
The `body:sub()` call risks splitting the string in the middle of a
multi-byte UTF-8 sequence. This should have been caught by util.stanza
validation, but that would have caused some havoc, at the very least causing
the notification to not be sent.
There have been no reports of this happening. Likely because this module
isn't widely deployed among users with languages that use many longer UTF-8
sequences.
The util.encodings.utf8.valid() function is O(n) where only the last
sequence really needs to be checked, but it's in C and expected to be fast.
author | Kim Alvefur <zash@zash.se> |
---|---|
date | Sun, 22 Aug 2021 13:22:59 +0200 |
parents | 3ba8fd1a297e |
children |
rev | line source |
---|---|
2849
5e74028557dc
mod_log_slow_events: Turn into a shared module (fixes http events being logged multiple times)
Kim Alvefur <zash@zash.se>
parents:
2296
diff
changeset
|
1 module:set_global(); |
5e74028557dc
mod_log_slow_events: Turn into a shared module (fixes http events being logged multiple times)
Kim Alvefur <zash@zash.se>
parents:
2296
diff
changeset
|
2 |
1680
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
3 local time = require "socket".gettime; |
1696
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
4 local base64_decode = require "util.encodings".base64.decode; |
1680
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
5 |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
6 local max_seconds = module:get_option_number("log_slow_events_threshold", 0.5); |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
7 |
2296
8c0bf3151e37
mod_log_slow_events: Add metric to monitor number of slow events
Matthew Wild <mwild1@gmail.com>
parents:
1696
diff
changeset
|
8 local measure_slow_event = module:measure("slow_events", "rate"); |
8c0bf3151e37
mod_log_slow_events: Add metric to monitor number of slow events
Matthew Wild <mwild1@gmail.com>
parents:
1696
diff
changeset
|
9 |
1696
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
10 function event_wrapper(handlers, event_name, event_data) |
1680
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
11 local start = time(); |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
12 local ret = handlers(event_name, event_data); |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
13 local duration = time()-start; |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
14 if duration > max_seconds then |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
15 local data = {}; |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
16 if event_data then |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
17 local function log_data(name, value) |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
18 if value then |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
19 table.insert(data, ("%s=%q"):format(name, value)); |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
20 return true; |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
21 end |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
22 end |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
23 local sess = event_data.origin or event_data.session; |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
24 if sess then |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
25 log_data("ip", sess.ip); |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
26 if not log_data("full_jid", sess.full_jid) then |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
27 log_data("username", sess.username); |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
28 end |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
29 log_data("type", sess.type); |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
30 log_data("host", sess.host); |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
31 end |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
32 local stanza = event_data.stanza; |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
33 if stanza then |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
34 log_data("stanza", tostring(stanza)); |
1696
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
35 else |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
36 local request = event_data.request; |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
37 if request then |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
38 log_data("http_method", request.method); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
39 log_data("http_path", request.path); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
40 local auth = request.headers.authorization; |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
41 if auth then |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
42 local creds = auth:match("^Basic +(.+)$"); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
43 if creds then |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
44 local user = string.match(base64_decode(creds) or "", "^([^:]+):"); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
45 log_data("http_user", user); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
46 end |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
47 end |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
48 end |
1680
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
49 end |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
50 end |
2296
8c0bf3151e37
mod_log_slow_events: Add metric to monitor number of slow events
Matthew Wild <mwild1@gmail.com>
parents:
1696
diff
changeset
|
51 measure_slow_event(); |
1695
78b3b3add19c
mod_log_slow_events: Minor improvement to log message
Matthew Wild <mwild1@gmail.com>
parents:
1680
diff
changeset
|
52 module:log("warn", "Slow event '%s' took %0.2fs: %s", event_name, duration, next(data) and table.concat(data, ", ") or "no recognised data"); |
1680
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
53 end |
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
54 return ret; |
1696
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
55 end |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
56 |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
57 local http_events = require "net.http.server"._events; |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
58 module:wrap_object_event(http_events, false, event_wrapper); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1695
diff
changeset
|
59 |
2850
3ba8fd1a297e
mod_log_slow_events: Also catch global events
Kim Alvefur <zash@zash.se>
parents:
2849
diff
changeset
|
60 module:wrap_event(false, event_wrapper); |
2849
5e74028557dc
mod_log_slow_events: Turn into a shared module (fixes http events being logged multiple times)
Kim Alvefur <zash@zash.se>
parents:
2296
diff
changeset
|
61 function module.add_host(module) |
5e74028557dc
mod_log_slow_events: Turn into a shared module (fixes http events being logged multiple times)
Kim Alvefur <zash@zash.se>
parents:
2296
diff
changeset
|
62 module:wrap_event(false, event_wrapper); |
5e74028557dc
mod_log_slow_events: Turn into a shared module (fixes http events being logged multiple times)
Kim Alvefur <zash@zash.se>
parents:
2296
diff
changeset
|
63 end |