Mercurial > prosody-modules

annotate mod_log_slow_events/mod_log_slow_events.lua @ 2494:d300ae5dba87

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
mod_smacks: Fix some bugs with smacks-ack-delayed event triggering. The old code had several flaws which are addressed here. First of all this fixes the if statement guarding the event generation There where some timing glitches addressed by this commit as well.
author tmolitor <thilo@eightysoft.de>
date Sun, 12 Feb 2017 21:23:22 +0100
parents 8c0bf3151e37
children 5e74028557dc
Ignore whitespace changes - Everywhere: Within whitespace: At end of lines:
rev   line source
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
1 local time = require "socket".gettime;
1696
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
2 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
3
a9df1f7e273d mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff changeset
4 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
5
2296
8c0bf3151e37 mod_log_slow_events: Add metric to monitor number of slow events
Matthew Wild <mwild1@gmail.com>
parents: 1696
diff changeset
6 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
7
1696
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
8 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
9 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
10 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
11 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
12 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
13 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
14 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
15 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
16 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
17 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
18 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
19 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
20 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
21 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
22 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
23 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
24 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
25 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
26 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
27 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
28 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
29 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
30 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
31 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
32 log_data("stanza", tostring(stanza));
1696
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
33 else
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
34 local request = event_data.request;
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
35 if request then
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
36 log_data("http_method", request.method);
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
37 log_data("http_path", request.path);
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
38 local auth = request.headers.authorization;
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
39 if auth then
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
40 local creds = auth:match("^Basic +(.+)$");
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
41 if creds then
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
42 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
43 log_data("http_user", user);
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
44 end
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
45 end
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
46 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
47 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
48 end
2296
8c0bf3151e37 mod_log_slow_events: Add metric to monitor number of slow events
Matthew Wild <mwild1@gmail.com>
parents: 1696
diff changeset
49 measure_slow_event();
1695
78b3b3add19c mod_log_slow_events: Minor improvement to log message
Matthew Wild <mwild1@gmail.com>
parents: 1680
diff changeset
50 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
51 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
52 return ret;
1696
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
53 end
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
54
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
55 module:wrap_event(false, event_wrapper);
efc1d674eac0 mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents: 1695
diff changeset
56 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
57 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
58