stanza_router: Don't log full stanzas destined for s2s
[prosody.git] / core / s2smanager.lua
1 -- Prosody IM
2 -- Copyright (C) 2008-2009 Matthew Wild
3 -- Copyright (C) 2008-2009 Waqas Hussain
4 -- 
5 -- This project is MIT/X11 licensed. Please see the
6 -- COPYING file in the source package for more information.
7 --
8
9
10
11 local hosts = hosts;
12 local sessions = sessions;
13 local core_process_stanza = function(a, b) core_process_stanza(a, b); end
14 local add_task = require "util.timer".add_task;
15 local socket = require "socket";
16 local format = string.format;
17 local t_insert, t_sort = table.insert, table.sort;
18 local get_traceback = debug.traceback;
19 local tostring, pairs, ipairs, getmetatable, newproxy, error, tonumber
20     = tostring, pairs, ipairs, getmetatable, newproxy, error, tonumber;
21
22 local idna_to_ascii = require "util.encodings".idna.to_ascii;
23 local connlisteners_get = require "net.connlisteners".get;
24 local wrapclient = require "net.server".wrapclient;
25 local modulemanager = require "core.modulemanager";
26 local st = require "stanza";
27 local stanza = st.stanza;
28 local nameprep = require "util.encodings".stringprep.nameprep;
29
30 local fire_event = require "core.eventmanager".fire_event;
31 local uuid_gen = require "util.uuid".generate;
32
33 local logger_init = require "util.logger".init;
34
35 local log = logger_init("s2smanager");
36
37 local sha256_hash = require "util.hashes".sha256;
38
39 local dialback_secret = uuid_gen();
40
41 local adns, dns = require "net.adns", require "net.dns";
42 local config = require "core.configmanager";
43 local connect_timeout = config.get("*", "core", "s2s_timeout") or 60;
44 local dns_timeout = config.get("*", "core", "dns_timeout") or 60;
45 local max_dns_depth = config.get("*", "core", "dns_max_depth") or 3;
46
47 incoming_s2s = {};
48 _G.prosody.incoming_s2s = incoming_s2s;
49 local incoming_s2s = incoming_s2s;
50
51 module "s2smanager"
52
53 local function compare_srv_priorities(a,b) return a.priority < b.priority or a.weight < b.weight; end
54
55 local function bounce_sendq(session)
56         local sendq = session.sendq;
57         if sendq then
58                 session.log("info", "sending error replies for "..#sendq.." queued stanzas because of failed outgoing connection to "..tostring(session.to_host));
59                 local dummy = {
60                         type = "s2sin";
61                         send = function(s)
62                                 (session.log or log)("error", "Replying to to an s2s error reply, please report this! Traceback: %s", get_traceback());
63                         end;
64                         dummy = true;
65                 };
66                 for i, data in ipairs(sendq) do
67                         local reply = data[2];
68                         local xmlns = reply.attr.xmlns;
69                         if not xmlns or xmlns == "jabber:client" or xmlns == "jabber:server" then
70                                 reply.attr.type = "error";
71                                 reply:tag("error", {type = "cancel"})
72                                         :tag("remote-server-not-found", {xmlns = "urn:ietf:params:xml:ns:xmpp-stanzas"}):up();
73                                 core_process_stanza(dummy, reply);
74                         end
75                         sendq[i] = nil;
76                 end
77                 session.sendq = nil;
78         end
79 end
80
81 function send_to_host(from_host, to_host, data)
82         local host = hosts[from_host].s2sout[to_host];
83         if host then
84                 -- We have a connection to this host already
85                 if host.type == "s2sout_unauthed" and (data.name ~= "db:verify" or not host.dialback_key) and ((not data.xmlns) or data.xmlns == "jabber:client" or data.xmlns == "jabber:server") then
86                         (host.log or log)("debug", "trying to send over unauthed s2sout to "..to_host);
87                         
88                         -- Queue stanza until we are able to send it
89                         if host.sendq then t_insert(host.sendq, {tostring(data), st.reply(data)});
90                         else host.sendq = { {tostring(data), st.reply(data)} }; end
91                         host.log("debug", "stanza [%s] queued ", data.name);
92                 elseif host.type == "local" or host.type == "component" then
93                         log("error", "Trying to send a stanza to ourselves??")
94                         log("error", "Traceback: %s", get_traceback());
95                         log("error", "Stanza: %s", tostring(data));
96                 else
97                         (host.log or log)("debug", "going to send stanza to "..to_host.." from "..from_host);
98                         -- FIXME
99                         if host.from_host ~= from_host then
100                                 log("error", "WARNING! This might, possibly, be a bug, but it might not...");
101                                 log("error", "We are going to send from %s instead of %s", tostring(host.from_host), tostring(from_host));
102                         end
103                         host.sends2s(data);
104                         host.log("debug", "stanza sent over "..host.type);
105                 end
106         else
107                 log("debug", "opening a new outgoing connection for this stanza");
108                 local host_session = new_outgoing(from_host, to_host);
109
110                 -- Store in buffer
111                 host_session.sendq = { {tostring(data), st.reply(data)} };
112                 log("debug", "stanza [%s] queued until connection complete", tostring(data.name));
113                 if (not host_session.connecting) and (not host_session.conn) then
114                         log("warn", "Connection to %s failed already, destroying session...", to_host);
115                         destroy_session(host_session);
116                 end
117         end
118 end
119
120 local open_sessions = 0;
121
122 function new_incoming(conn)
123         local session = { conn = conn, type = "s2sin_unauthed", direction = "incoming", hosts = {} };
124         if true then
125                 session.trace = newproxy(true);
126                 getmetatable(session.trace).__gc = function () open_sessions = open_sessions - 1; end;
127         end
128         open_sessions = open_sessions + 1;
129         local w, log = conn.write, logger_init("s2sin"..tostring(conn):match("[a-f0-9]+$"));
130         session.log = log;
131         session.sends2s = function (t) log("debug", "sending: %s", (t.top_tag and t:top_tag()) or t:match("^([^>]*>?)")); w(tostring(t)); end
132         incoming_s2s[session] = true;
133         add_task(connect_timeout, function ()
134                 if session.conn ~= conn or
135                    session.type == "s2sin" then
136                         return; -- Ok, we're connect[ed|ing]
137                 end
138                 -- Not connected, need to close session and clean up
139                 (session.log or log)("warn", "Destroying incomplete session %s->%s due to inactivity", 
140                     session.from_host or "(unknown)", session.to_host or "(unknown)");
141                 session:close("connection-timeout");
142         end);
143         return session;
144 end
145
146 function new_outgoing(from_host, to_host)
147                 local host_session = { to_host = to_host, from_host = from_host, host = from_host, 
148                                        notopen = true, type = "s2sout_unauthed", direction = "outgoing" };
149                 
150                 hosts[from_host].s2sout[to_host] = host_session;
151                 
152                 local log;
153                 do
154                         local conn_name = "s2sout"..tostring(host_session):match("[a-f0-9]*$");
155                         log = logger_init(conn_name);
156                         host_session.log = log;
157                 end
158                 
159                 -- Kick the connection attempting machine
160                 attempt_connection(host_session);
161                 
162                 if not host_session.sends2s then                
163                         -- A sends2s which buffers data (until the stream is opened)
164                         -- note that data in this buffer will be sent before the stream is authed
165                         -- and will not be ack'd in any way, successful or otherwise
166                         local buffer;
167                         function host_session.sends2s(data)
168                                 if not buffer then
169                                         buffer = {};
170                                         host_session.send_buffer = buffer;
171                                 end
172                                 log("debug", "Buffering data on unconnected s2sout to %s", to_host);
173                                 buffer[#buffer+1] = data;
174                                 log("debug", "Buffered item %d: %s", #buffer, tostring(data));
175                         end
176                         
177                 end
178
179                 return host_session;
180 end
181
182
183 function attempt_connection(host_session, err)
184         local from_host, to_host = host_session.from_host, host_session.to_host;
185         local connect_host, connect_port = idna_to_ascii(to_host), 5269;
186         
187         if not connect_host then
188                 return false;
189         end
190         
191         if not err then -- This is our first attempt
192                 log("debug", "First attempt to connect to %s, starting with SRV lookup...", to_host);
193                 host_session.connecting = true;
194                 local handle;
195                 handle = adns.lookup(function (answer)
196                         handle = nil;
197                         host_session.connecting = nil;
198                         if answer then
199                                 log("debug", to_host.." has SRV records, handling...");
200                                 local srv_hosts = {};
201                                 host_session.srv_hosts = srv_hosts;
202                                 for _, record in ipairs(answer) do
203                                         t_insert(srv_hosts, record.srv);
204                                 end
205                                 t_sort(srv_hosts, compare_srv_priorities);
206                                 
207                                 local srv_choice = srv_hosts[1];
208                                 host_session.srv_choice = 1;
209                                 if srv_choice then
210                                         connect_host, connect_port = srv_choice.target or to_host, srv_choice.port or connect_port;
211                                         log("debug", "Best record found, will connect to %s:%d", connect_host, connect_port);
212                                 end
213                         else
214                                 log("debug", to_host.." has no SRV records, falling back to A");
215                         end
216                         -- Try with SRV, or just the plain hostname if no SRV
217                         local ok, err = try_connect(host_session, connect_host, connect_port);
218                         if not ok then
219                                 if not attempt_connection(host_session, err) then
220                                         -- No more attempts will be made
221                                         destroy_session(host_session);
222                                 end
223                         end
224                 end, "_xmpp-server._tcp."..connect_host..".", "SRV");
225                 
226                 -- Set handler for DNS timeout
227                 add_task(dns_timeout, function ()
228                         if handle then
229                                 adns.cancel(handle, true);
230                         end
231                 end);
232                 
233                 log("debug", "DNS lookup for %s sent, waiting for response before we can connect", to_host);
234                 return true; -- Attempt in progress
235         elseif host_session.srv_hosts and #host_session.srv_hosts > host_session.srv_choice then -- Not our first attempt, and we also have SRV
236                 host_session.srv_choice = host_session.srv_choice + 1;
237                 local srv_choice = host_session.srv_hosts[host_session.srv_choice];
238                 connect_host, connect_port = srv_choice.target or to_host, srv_choice.port or connect_port;
239                 host_session.log("info", "Connection failed (%s). Attempt #%d: This time to %s:%d", tostring(err), host_session.srv_choice, connect_host, connect_port);
240         else
241                 host_session.log("info", "Out of connection options, can't connect to %s", tostring(host_session.to_host));
242                 -- We're out of options
243                 return false;
244         end
245         
246         if not (connect_host and connect_port) then
247                 -- Likely we couldn't resolve DNS
248                 log("warn", "Hmm, we're without a host (%s) and port (%s) to connect to for %s, giving up :(", tostring(connect_host), tostring(connect_port), tostring(to_host));
249                 return false;
250         end
251         
252         return try_connect(host_session, connect_host, connect_port);
253 end
254
255 function try_connect(host_session, connect_host, connect_port)
256         host_session.connecting = true;
257         local handle;
258         handle = adns.lookup(function (reply)
259                 handle = nil;
260                 host_session.connecting = nil;
261                 
262                 -- COMPAT: This is a compromise for all you CNAME-(ab)users :)
263                 if not (reply and reply[#reply] and reply[#reply].a) then
264                         local count = max_dns_depth;
265                         reply = dns.peek(connect_host, "CNAME", "IN");
266                         while count > 0 and reply and reply[#reply] and not reply[#reply].a and reply[#reply].cname do
267                                 log("debug", "Looking up %s (DNS depth is %d)", tostring(reply[#reply].cname), count);
268                                 reply = dns.peek(reply[#reply].cname, "A", "IN") or dns.peek(reply[#reply].cname, "CNAME", "IN");
269                                 count = count - 1;
270                         end
271                 end
272                 -- end of CNAME resolving
273                 
274                 if reply and reply[#reply] and reply[#reply].a then
275                         log("debug", "DNS reply for %s gives us %s", connect_host, reply[#reply].a);
276                         return make_connect(host_session, reply[#reply].a, connect_port);
277                 else
278                         log("debug", "DNS lookup failed to get a response for %s", connect_host);
279                         if not attempt_connection(host_session, "name resolution failed") then -- Retry if we can
280                                 log("debug", "No other records to try for %s - destroying", host_session.to_host);
281                                 destroy_session(host_session); -- End of the line, we can't
282                         end
283                 end
284         end, connect_host, "A", "IN");
285
286         -- Set handler for DNS timeout
287         add_task(dns_timeout, function ()
288                 if handle then
289                         adns.cancel(handle, true);
290                 end
291         end);
292                 
293         return true;
294 end
295
296 function make_connect(host_session, connect_host, connect_port)
297         host_session.log("info", "Beginning new connection attempt to %s (%s:%d)", host_session.to_host, connect_host, connect_port);
298         -- Ok, we're going to try to connect
299         
300         local from_host, to_host = host_session.from_host, host_session.to_host;
301         
302         local conn, handler = socket.tcp()
303
304         conn:settimeout(0);
305         local success, err = conn:connect(connect_host, connect_port);
306         if not success and err ~= "timeout" then
307                 log("warn", "s2s connect() to %s (%s:%d) failed: %s", host_session.to_host, connect_host, connect_port, err);
308                 return false, err;
309         end
310         
311         local cl = connlisteners_get("xmppserver");
312         conn = wrapclient(conn, connect_host, connect_port, cl, cl.default_mode or 1, hosts[from_host].ssl_ctx, false );
313         host_session.conn = conn;
314         
315         -- Register this outgoing connection so that xmppserver_listener knows about it
316         -- otherwise it will assume it is a new incoming connection
317         cl.register_outgoing(conn, host_session);
318         
319         local w, log = conn.write, host_session.log;
320         host_session.sends2s = function (t) log("debug", "sending: %s", (t.top_tag and t:top_tag()) or t:match("^[^>]*>?")); w(tostring(t)); end
321         
322         conn.write(format([[<stream:stream xmlns='jabber:server' xmlns:db='jabber:server:dialback' xmlns:stream='http://etherx.jabber.org/streams' from='%s' to='%s' version='1.0' xml:lang='en'>]], from_host, to_host));
323         log("debug", "Connection attempt in progress...");
324         add_task(connect_timeout, function ()
325                 if host_session.conn ~= conn or
326                    host_session.type == "s2sout" or
327                    host_session.connecting then
328                         return; -- Ok, we're connect[ed|ing]
329                 end
330                 -- Not connected, need to close session and clean up
331                 (host_session.log or log)("warn", "Destroying incomplete session %s->%s due to inactivity", 
332                     host_session.from_host or "(unknown)", host_session.to_host or "(unknown)");
333                 host_session:close("connection-timeout");
334         end);
335         return true;
336 end
337
338 function streamopened(session, attr)
339         local send = session.sends2s;
340         
341         -- TODO: #29: SASL/TLS on s2s streams
342         session.version = tonumber(attr.version) or 0;
343         
344         if session.secure == false then
345                 session.secure = true;
346         end
347         
348         if session.version >= 1.0 and not (attr.to and attr.from) then
349                 
350                 (session.log or log)("warn", "Remote of stream "..(session.from_host or "(unknown)").."->"..(session.to_host or "(unknown)")
351                         .." failed to specify to (%s) and/or from (%s) hostname as per RFC", tostring(attr.to), tostring(attr.from));
352         end
353         
354         if session.direction == "incoming" then
355                 -- Send a reply stream header
356                 session.to_host = attr.to and nameprep(attr.to);
357                 session.from_host = attr.from and nameprep(attr.from);
358         
359                 session.streamid = uuid_gen();
360                 (session.log or log)("debug", "incoming s2s received <stream:stream>");
361                 send("<?xml version='1.0'?>");
362                 send(stanza("stream:stream", { xmlns='jabber:server', ["xmlns:db"]='jabber:server:dialback', 
363                                 ["xmlns:stream"]='http://etherx.jabber.org/streams', id=session.streamid, from=session.to_host, version=(session.version > 0 and "1.0" or nil) }):top_tag());
364                 if session.to_host and not hosts[session.to_host] then
365                         -- Attempting to connect to a host we don't serve
366                         session:close({ condition = "host-unknown"; text = "This host does not serve "..session.to_host });
367                         return;
368                 end
369                 if session.version >= 1.0 then
370                         local features = st.stanza("stream:features");
371                                                         
372                         if session.to_host then
373                                 hosts[session.to_host].events.fire_event("s2s-stream-features", { session = session, features = features });
374                         else
375                                 (session.log or log)("warn", "No 'to' on stream header from %s means we can't offer any features", session.from_host or "unknown host");
376                         end
377                         
378                         log("debug", "Sending stream features: %s", tostring(features));
379                         send(features);
380                 end
381         elseif session.direction == "outgoing" then
382                 -- If we are just using the connection for verifying dialback keys, we won't try and auth it
383                 if not attr.id then error("stream response did not give us a streamid!!!"); end
384                 session.streamid = attr.id;
385         
386                 -- Send unauthed buffer
387                 -- (stanzas which are fine to send before dialback)
388                 -- Note that this is *not* the stanza queue (which 
389                 -- we can only send if auth succeeds) :)
390                 local send_buffer = session.send_buffer;
391                 if send_buffer and #send_buffer > 0 then
392                         log("debug", "Sending s2s send_buffer now...");
393                         for i, data in ipairs(send_buffer) do
394                                 session.sends2s(data);
395                                 send_buffer[i] = nil;
396                         end
397                 end
398                 session.send_buffer = nil;
399         
400                 -- If server is pre-1.0, don't wait for features, just do dialback
401                 if session.version < 1.0 then
402                         if not session.dialback_verifying then
403                                 log("debug", "Initiating dialback...");
404                                 initiate_dialback(session);
405                         else
406                                 mark_connected(session);
407                         end
408                 end
409         end
410
411         session.notopen = nil;
412 end
413
414 function streamclosed(session)
415         (session.log or log)("debug", "</stream:stream>");
416         if session.sends2s then
417                 session.sends2s("</stream:stream>");
418         end
419         session.notopen = true;
420 end
421
422 function initiate_dialback(session)
423         -- generate dialback key
424         session.dialback_key = generate_dialback(session.streamid, session.to_host, session.from_host);
425         session.sends2s(format("<db:result from='%s' to='%s'>%s</db:result>", session.from_host, session.to_host, session.dialback_key));
426         session.log("info", "sent dialback key on outgoing s2s stream");
427 end
428
429 function generate_dialback(id, to, from)
430         return sha256_hash(id..to..from..dialback_secret, true);
431 end
432
433 function verify_dialback(id, to, from, key)
434         return key == generate_dialback(id, to, from);
435 end
436
437 function make_authenticated(session, host)
438         if session.type == "s2sout_unauthed" then
439                 session.type = "s2sout";
440         elseif session.type == "s2sin_unauthed" then
441                 session.type = "s2sin";
442                 if host then
443                         session.hosts[host].authed = true;
444                 end
445         elseif session.type == "s2sin" and host then
446                 session.hosts[host].authed = true;
447         else
448                 return false;
449         end
450         session.log("debug", "connection %s->%s is now authenticated", session.from_host or "(unknown)", session.to_host or "(unknown)");
451         
452         mark_connected(session);
453         
454         return true;
455 end
456
457 -- Stream is authorised, and ready for normal stanzas
458 function mark_connected(session)
459         local sendq, send = session.sendq, session.sends2s;
460         
461         local from, to = session.from_host, session.to_host;
462         
463         session.log("info", session.direction.." s2s connection "..from.."->"..to.." complete");
464         
465         local send_to_host = send_to_host;
466         function session.send(data) send_to_host(to, from, data); end
467         
468         
469         if session.direction == "outgoing" then
470                 if sendq then
471                         session.log("debug", "sending "..#sendq.." queued stanzas across new outgoing connection to "..session.to_host);
472                         for i, data in ipairs(sendq) do
473                                 send(data[1]);
474                                 sendq[i] = nil;
475                         end
476                         session.sendq = nil;
477                 end
478                 
479                 session.srv_hosts = nil;
480         end
481 end
482
483 function destroy_session(session)
484         (session.log or log)("info", "Destroying "..tostring(session.direction).." session "..tostring(session.from_host).."->"..tostring(session.to_host));
485         
486         if session.direction == "outgoing" then
487                 hosts[session.from_host].s2sout[session.to_host] = nil;
488                 bounce_sendq(session);
489         elseif session.direction == "incoming" then
490                 incoming_s2s[session] = nil;
491         end
492         
493         for k in pairs(session) do
494                 if k ~= "trace" then
495                         session[k] = nil;
496                 end
497         end
498 end
499
500 return _M;