Mercurial > prosody-modules

annotate mod_log_slow_events/mod_log_slow_events.lua @ 2296:8c0bf3151e37

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
mod_log_slow_events: Add metric to monitor number of slow events
author Matthew Wild <mwild1@gmail.com>
date Wed, 31 Aug 2016 11:29:26 +0100
parents efc1d674eac0
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