author | Kim Alvefur <zash@zash.se> |
Sun, 13 Sep 2015 15:45:40 +0200 | |
changeset 1848 | 04e168063fc7 |
parent 1700 | efc1d674eac0 |
child 2300 | 8c0bf3151e37 |
permissions | -rw-r--r-- |
1684
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; |
1700
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
2 |
local base64_decode = require "util.encodings".base64.decode; |
1684
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 |
|
1700
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
6 |
function event_wrapper(handlers, event_name, event_data) |
1684
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 |
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
|
8 |
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
|
9 |
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
|
10 |
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
|
11 |
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
|
12 |
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
|
13 |
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
|
14 |
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
|
15 |
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
|
16 |
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
|
17 |
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
|
18 |
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
|
19 |
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
|
20 |
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
|
21 |
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
|
22 |
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
|
23 |
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
|
24 |
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
|
25 |
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
|
26 |
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
|
27 |
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
|
28 |
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
|
29 |
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
|
30 |
log_data("stanza", tostring(stanza)); |
1700
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
31 |
else |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
32 |
local request = event_data.request; |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
33 |
if request then |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
34 |
log_data("http_method", request.method); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
35 |
log_data("http_path", request.path); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
36 |
local auth = request.headers.authorization; |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
37 |
if auth then |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
38 |
local creds = auth:match("^Basic +(.+)$"); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
39 |
if creds then |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
40 |
local user = string.match(base64_decode(creds) or "", "^([^:]+):"); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
41 |
log_data("http_user", user); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
42 |
end |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
43 |
end |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
44 |
end |
1684
a9df1f7e273d
mod_log_slow_events: Log events that take a long time to process (including stanzas)
Matthew Wild <mwild1@gmail.com>
parents:
diff
changeset
|
45 |
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
|
46 |
end |
1699
78b3b3add19c
mod_log_slow_events: Minor improvement to log message
Matthew Wild <mwild1@gmail.com>
parents:
1684
diff
changeset
|
47 |
module:log("warn", "Slow event '%s' took %0.2fs: %s", event_name, duration, next(data) and table.concat(data, ", ") or "no recognised data"); |
1684
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 |
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 |
return ret; |
1700
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
50 |
end |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
51 |
|
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
52 |
module:wrap_event(false, event_wrapper); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
53 |
local http_events = require "net.http.server"._events; |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
54 |
module:wrap_object_event(http_events, false, event_wrapper); |
efc1d674eac0
mod_log_slow_events: Log slow HTTP requests
Matthew Wild <mwild1@gmail.com>
parents:
1699
diff
changeset
|
55 |