Launchpad itself

Merge lp:~jml/launchpad/extract-ssh-server-logging into lp:launchpad

  1. extract-ssh-server-logging
  2. Merge into devel
Proposed by Jonathan Lange
Status: Merged
Approved by: Jonathan Lange
Approved revision: no longer in the source branch.
Merged at revision: not available
Proposed branch: lp:~jml/launchpad/extract-ssh-server-logging
Merge into: lp:launchpad
Prerequisite: lp:~jml/launchpad/extract-ssh-server
Diff against target: 1186 lines (+524/-349) (has conflicts)
9 files modified
daemons/sftp.tac (+31/-7)
lib/lp/codehosting/sftp.py (+3/-3)
lib/lp/codehosting/sshserver/accesslog.py (+46/-176)
lib/lp/codehosting/sshserver/auth.py (+3/-3)
lib/lp/codehosting/sshserver/events.py (+155/-0)
lib/lp/codehosting/sshserver/service.py (+125/-29)
lib/lp/codehosting/sshserver/session.py (+3/-3)
lib/lp/codehosting/sshserver/tests/test_events.py (+91/-0)
lib/lp/codehosting/sshserver/tests/test_logging.py (+67/-128)
Text conflict in daemons/sftp.tac
Text conflict in lib/lp/codehosting/sshserver/accesslog.py
Text conflict in lib/lp/codehosting/sshserver/service.py
To merge this branch: bzr merge lp:~jml/launchpad/extract-ssh-server-logging
Reviewer Review Type Date Requested Status
Michael Nelson (community) Approve
Michael Hudson-Doyle Pending
Review via email: mp+23425@code.launchpad.net

Commit message

Parametrize the codehosting SSH server logging so that it does not assume codehosting.

Description of the change

This change builds on my previous SSH server refactoring branch. It takes the customized logging stuff that we've built for codehosting and tears out all of the codehosting specific bits.

Specifically, it:
 * splits the event classes into another module
 * parametrizes the main log, the access log and the access log file path in the logging manager
 * moves the _log_event helper into the LoggingManager
 * deletes the silly get_codehosting_logger and get_access_logger functions
 * cleans up the tests a bit

It's a pretty boring branch, all told.

I look forward to your review.
jml

To post a comment you must log in.
Revision history for this message
Michael Nelson (michael.nelson) wrote :
Download full text (11.5 KiB)

Hi Jonathan,

I love the test simplifications (LoggingManagerMixin). The only things I noticed were:

1. Some missing imports (as per our chat),
2. Some tests not asserting the intermediate state (but you said that other tests in the module already do this, but will check (I didn't)), and
3. A duplicate test.

Great stuff!

IRC chat:
{{{
11:11 < noodles> jml: any reason that you're not importing adapter and using @adapter, rather than @zope.component.adapter? Is there a preference?
11:12 < jml> noodles: just me being lazy. I have to import zope.component.event anyway
11:13 < noodles> jml: ok, while you're there, provideHandler too I guess.
11:13 < jml> (as a side-effect, z.c.event import starts up the event system)
11:35 < noodles> jml: there are some tests that setup the logging manager, and then immediately tear it down and make an assertion about the end state, without asserting the intermediate state (ie. showing that it is *not* the same as the endstate). Is that not worthwhile? (if not, I'll stop doing it :) ).
11:36 < noodles> oops, wrong channel, but anyway...
11:36 < jml> noodles: I'm on a call atm.
11:36 < noodles> np.
11:36 < jml> noodles: I think you'll find that the intermediate state is tested in other tests.
11:37 < noodles> Ah, right.
11:37 * jml isn't sure though
}}}

Notes:
> === modified file 'lib/lp/codehosting/sshserver/accesslog.py'
> --- lib/lp/codehosting/sshserver/accesslog.py 2010-04-14 19:38:29 +0000
> +++ lib/lp/codehosting/sshserver/accesslog.py 2010-04-14 19:38:33 +0000

> @@ -25,70 +14,72 @@
>
> # This non-standard import is necessary to hook up the event system.
> import zope.component.event
> -from zope.interface import Attribute, implements, Interface
>
> -from canonical.config import config
> from canonical.launchpad.scripts import WatchedFileHandler
> +from lp.codehosting.sshserver.events import ILoggingEvent
> from lp.services.utils import synchronize
> -from lp.services.twistedsupport.loggingsupport import set_up_oops_reporting
>
>
> class LoggingManager:
> """Class for managing codehosting logging."""
>
> - def setUp(self, configure_oops_reporting=False):
> + def __init__(self, main_log, access_log, access_log_path):
> + """Construct the logging manager.
> +
> + :param main_log: The main log. Twisted will log to this.
> + :param access_log: The access log object.
> + :param access_log_path: The path to the file where access log
> + messages go.
> + """
> + self._main_log = main_log
> + self._access_log = access_log
> + self._access_log_path = access_log_path
> + self._is_set_up = False
> +
> + def setUp(self):
> """Set up logging for the smart server.
>
> This sets up a debugging handler on the 'codehosting' logger, makes
> sure that things logged there won't go to stderr (necessary because of
> bzrlib.trace shenanigans) and then returns the 'codehosting' logger.
> -
> - :param configure_oops_reporting: If True, install a Twisted log
> - observer that ensures unhandled exceptions get reported as OOPSes.
> """
> - log = get_codehosting_logger()
>...

review: Approve
Revision history for this message
Jonathan Lange (jml) wrote :

On Thu, Apr 15, 2010 at 10:47 AM, Michael Nelson
<email address hidden> wrote:
> Review: Approve
> Hi Jonathan,
>
> I love the test simplifications (LoggingManagerMixin). The only things I noticed were:
>

Thanks!

> 1. Some missing imports (as per our chat),

These have been fixed.

> 2. Some tests not asserting the intermediate state (but you said that other tests in the module already do this, but will check (I didn't)), and

I've checked, and they are all good.

> 3. A duplicate test.
>

It's not a duplicate test, but rather a very similar test for some
very similar code. I've put the two tests next to each other, changed
the names a bit and added comments so that the difference is clear.

Thanks,
jml

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'daemons/sftp.tac'
2--- daemons/sftp.tac 2010-04-15 13:40:21 +0000
3+++ daemons/sftp.tac 2010-04-16 18:57:30 +0000
4@@ -9,20 +9,44 @@
5
6 from canonical.config import config
7 from canonical.launchpad.daemons import tachandler
8+<<<<<<< TREE
9
10 from lp.codehosting.sshserver.service import (
11 get_key_path, make_portal, PRIVATE_KEY_FILE, PUBLIC_KEY_FILE, SSHService)
12
13
14 # Construct an Application that has the codehosting SSH server.
15+=======
16+
17+from lp.codehosting.sshserver.service import (
18+ ACCESS_LOG_NAME, get_key_path, LOG_NAME, make_portal, OOPS_CONFIG_SECTION,
19+ PRIVATE_KEY_FILE, PUBLIC_KEY_FILE, SSHService)
20+
21+
22+# Construct an Application that has the codehosting SSH server.
23+>>>>>>> MERGE-SOURCE
24 application = service.Application('sftponly')
25-svc = SSHService(
26- portal=make_portal(),
27- private_key_path=get_key_path(PRIVATE_KEY_FILE),
28- public_key_path=get_key_path(PUBLIC_KEY_FILE),
29- strport=config.codehosting.port,
30- idle_timeout=config.codehosting.idle_timeout,
31- banner=config.codehosting.banner)
32+<<<<<<< TREE
33+svc = SSHService(
34+ portal=make_portal(),
35+ private_key_path=get_key_path(PRIVATE_KEY_FILE),
36+ public_key_path=get_key_path(PUBLIC_KEY_FILE),
37+ strport=config.codehosting.port,
38+ idle_timeout=config.codehosting.idle_timeout,
39+ banner=config.codehosting.banner)
40+=======
41+svc = SSHService(
42+ portal=make_portal(),
43+ private_key_path=get_key_path(PRIVATE_KEY_FILE),
44+ public_key_path=get_key_path(PUBLIC_KEY_FILE),
45+ oops_configuration=OOPS_CONFIG_SECTION,
46+ main_log=LOG_NAME,
47+ access_log=ACCESS_LOG_NAME,
48+ access_log_path=config.codehosting.access_log,
49+ strport=config.codehosting.port,
50+ idle_timeout=config.codehosting.idle_timeout,
51+ banner=config.codehosting.banner)
52+>>>>>>> MERGE-SOURCE
53 svc.setServiceParent(application)
54
55 # Service that announces when the daemon is ready
56
57=== modified file 'lib/lp/codehosting/sftp.py'
58--- lib/lp/codehosting/sftp.py 2010-03-19 10:43:51 +0000
59+++ lib/lp/codehosting/sftp.py 2010-04-16 18:57:30 +0000
60@@ -38,7 +38,7 @@
61 from zope.interface import implements
62
63 from lp.codehosting.vfs import AsyncLaunchpadTransport, LaunchpadServer
64-from lp.codehosting.sshserver import accesslog
65+from lp.codehosting.sshserver import events
66 from canonical.config import config
67 from lp.services.twistedsupport import gatherResults
68
69@@ -253,7 +253,7 @@
70 avatar.branchfs_proxy, user_id, hosted_transport, mirror_transport)
71 server.start_server()
72 transport = AsyncLaunchpadTransport(server, server.get_url())
73- notify(accesslog.SFTPStarted(avatar))
74+ notify(events.SFTPStarted(avatar))
75 return TransportSFTPServer(transport)
76
77
78@@ -272,7 +272,7 @@
79 if self.avatar is not None:
80 avatar = self.avatar
81 self.avatar = None
82- notify(accesslog.SFTPClosed(avatar))
83+ notify(events.SFTPClosed(avatar))
84
85
86 class TransportSFTPServer:
87
88=== modified file 'lib/lp/codehosting/sshserver/accesslog.py'
89--- lib/lp/codehosting/sshserver/accesslog.py 2010-04-13 19:07:23 +0000
90+++ lib/lp/codehosting/sshserver/accesslog.py 2010-04-16 18:57:30 +0000
91@@ -5,235 +5,105 @@
92
93 __metaclass__ = type
94 __all__ = [
95- 'AuthenticationFailed',
96- 'BazaarSSHClosed',
97- 'BazaarSSHStarted',
98- 'LoggingEvent',
99- 'ServerStarting',
100- 'ServerStopped',
101- 'SFTPClosed',
102- 'SFTPStarted',
103- 'UserConnected',
104- 'UserDisconnected',
105- 'UserLoggedIn',
106- 'UserLoggedOut',
107+ 'LoggingManager',
108 ]
109
110 import logging
111
112 from twisted.python import log as tplog
113
114+from zope.component import adapter, getGlobalSiteManager, provideHandler
115 # This non-standard import is necessary to hook up the event system.
116 import zope.component.event
117-from zope.interface import Attribute, implements, Interface
118
119-from canonical.config import config
120 from canonical.launchpad.scripts import WatchedFileHandler
121+from lp.codehosting.sshserver.events import ILoggingEvent
122 from lp.services.utils import synchronize
123-from lp.services.twistedsupport.loggingsupport import set_up_oops_reporting
124
125
126 class LoggingManager:
127+<<<<<<< TREE
128 """Class for managing codehosting logging."""
129
130 def setUp(self, configure_oops_reporting=False):
131+=======
132+ """Class for managing SSH server logging."""
133+
134+ def __init__(self, main_log, access_log, access_log_path):
135+ """Construct the logging manager.
136+
137+ :param main_log: The main log. Twisted will log to this.
138+ :param access_log: The access log object.
139+ :param access_log_path: The path to the file where access log
140+ messages go.
141+ """
142+ self._main_log = main_log
143+ self._access_log = access_log
144+ self._access_log_path = access_log_path
145+ self._is_set_up = False
146+
147+ def setUp(self):
148+>>>>>>> MERGE-SOURCE
149 """Set up logging for the smart server.
150
151+<<<<<<< TREE
152 This sets up a debugging handler on the 'codehosting' logger, makes
153 sure that things logged there won't go to stderr (necessary because of
154 bzrlib.trace shenanigans) and then returns the 'codehosting' logger.
155
156 :param configure_oops_reporting: If True, install a Twisted log
157 observer that ensures unhandled exceptions get reported as OOPSes.
158+=======
159+ This sets up a debugging handler on the main logger and makes sure
160+ that things logged there won't go to stderr. It also sets up an access
161+ logger.
162+>>>>>>> MERGE-SOURCE
163 """
164- log = get_codehosting_logger()
165+ log = self._main_log
166 self._orig_level = log.level
167 self._orig_handlers = list(log.handlers)
168 self._orig_observers = list(tplog.theLogPublisher.observers)
169 log.setLevel(logging.INFO)
170 log.addHandler(_NullHandler())
171- access_log = get_access_logger()
172- handler = WatchedFileHandler(config.codehosting.access_log)
173+ handler = WatchedFileHandler(self._access_log_path)
174 handler.setFormatter(
175 logging.Formatter("%(asctime)s %(levelname)s %(message)s"))
176- access_log.addHandler(handler)
177- if configure_oops_reporting:
178- set_up_oops_reporting('codehosting')
179+ self._access_log.addHandler(handler)
180 # Make sure that our logging event handler is there, ready to receive
181 # logging events.
182- zope.component.provideHandler(_log_event)
183+ provideHandler(self._log_event)
184+ self._is_set_up = True
185+
186+ @adapter(ILoggingEvent)
187+ def _log_event(self, event):
188+ """Log 'event' to the access log."""
189+ self._access_log.log(event.level, event.message)
190
191 def tearDown(self):
192- log = get_codehosting_logger()
193+ if not self._is_set_up:
194+ return
195+ log = self._main_log
196 log.level = self._orig_level
197 synchronize(
198 log.handlers, self._orig_handlers, log.addHandler,
199 log.removeHandler)
200- access_log = get_access_logger()
201 synchronize(
202- access_log.handlers, self._orig_handlers, access_log.addHandler,
203- access_log.removeHandler)
204+ self._access_log.handlers, self._orig_handlers,
205+ self._access_log.addHandler, self._access_log.removeHandler)
206 synchronize(
207 tplog.theLogPublisher.observers, self._orig_observers,
208 tplog.addObserver, tplog.removeObserver)
209- zope.component.getGlobalSiteManager().unregisterHandler(_log_event)
210-
211-
212-def get_codehosting_logger():
213- """Return the codehosting logger."""
214- # This is its own function to avoid spreading the string 'codehosting'
215- # everywhere and to avoid duplicating information about how log objects
216- # are acquired.
217- return logging.getLogger('codehosting')
218-
219-
220-def get_access_logger():
221- return logging.getLogger('codehosting.access')
222+ getGlobalSiteManager().unregisterHandler(self._log_event)
223+ self._is_set_up = False
224
225
226 class _NullHandler(logging.Handler):
227 """Logging handler that does nothing with messages.
228
229 At the moment, we don't want to do anything with the Twisted log messages
230- that go to the 'codehosting' logger, and we also don't want warnings about
231+ that go to the SSH server logger, and we also don't want warnings about
232 there being no handlers. Hence, we use this do-nothing handler.
233 """
234
235 def emit(self, record):
236 pass
237-
238-
239-class ILoggingEvent(Interface):
240- """An event is a logging event if it has a message and a severity level.
241-
242- Events that provide this interface will be logged in codehosting access
243- log.
244- """
245-
246- level = Attribute("The level to log the event at.")
247- message = Attribute("The message to log.")
248-
249-
250-class LoggingEvent:
251- """An event that can be logged to a Python logger.
252-
253- :ivar level: The level to log itself as. This should be defined as a
254- class variable in subclasses.
255- :ivar template: The format string of the message to log. This should be
256- defined as a class variable in subclasses.
257- """
258-
259- implements(ILoggingEvent)
260-
261- def __init__(self, level=None, template=None, **data):
262- """Construct a logging event.
263-
264- :param level: The level to log the event as. If specified, overrides
265- the 'level' class variable.
266- :param template: The format string of the message to log. If
267- specified, overrides the 'template' class variable.
268- :param **data: Information to be logged. Entries will be substituted
269- into the template and stored as attributes.
270- """
271- if level is not None:
272- self._level = level
273- if template is not None:
274- self.template = template
275- self._data = data
276-
277- @property
278- def level(self):
279- """See `ILoggingEvent`."""
280- return self._level
281-
282- @property
283- def message(self):
284- """See `ILoggingEvent`."""
285- return self.template % self._data
286-
287-
288-class ServerStarting(LoggingEvent):
289-
290- level = logging.INFO
291- template = '---- Server started ----'
292-
293-
294-class ServerStopped(LoggingEvent):
295-
296- level = logging.INFO
297- template = '---- Server stopped ----'
298-
299-
300-class UserConnected(LoggingEvent):
301-
302- level = logging.INFO
303- template = '[%(session_id)s] %(address)s connected.'
304-
305- def __init__(self, transport, address):
306- LoggingEvent.__init__(
307- self, session_id=id(transport), address=address)
308-
309-
310-class AuthenticationFailed(LoggingEvent):
311-
312- level = logging.INFO
313- template = '[%(session_id)s] failed to authenticate.'
314-
315- def __init__(self, transport):
316- LoggingEvent.__init__(self, session_id=id(transport))
317-
318-
319-class UserDisconnected(LoggingEvent):
320-
321- level = logging.INFO
322- template = '[%(session_id)s] disconnected.'
323-
324- def __init__(self, transport):
325- LoggingEvent.__init__(self, session_id=id(transport))
326-
327-
328-class AvatarEvent(LoggingEvent):
329- """Base avatar event."""
330-
331- level = logging.INFO
332-
333- def __init__(self, avatar):
334- self.avatar = avatar
335- LoggingEvent.__init__(
336- self, session_id=id(avatar.transport), username=avatar.username)
337-
338-
339-class UserLoggedIn(AvatarEvent):
340-
341- template = '[%(session_id)s] %(username)s logged in.'
342-
343-
344-class UserLoggedOut(AvatarEvent):
345-
346- template = '[%(session_id)s] %(username)s disconnected.'
347-
348-
349-class SFTPStarted(AvatarEvent):
350-
351- template = '[%(session_id)s] %(username)s started SFTP session.'
352-
353-
354-class SFTPClosed(AvatarEvent):
355-
356- template = '[%(session_id)s] %(username)s closed SFTP session.'
357-
358-
359-class BazaarSSHStarted(AvatarEvent):
360-
361- template = '[%(session_id)s] %(username)s started bzr+ssh session.'
362-
363-
364-class BazaarSSHClosed(AvatarEvent):
365-
366- template = '[%(session_id)s] %(username)s closed bzr+ssh session.'
367-
368-
369-@zope.component.adapter(ILoggingEvent)
370-def _log_event(event):
371- """Log 'event' to the codehosting logger."""
372- get_access_logger().log(event.level, event.message)
373
374=== modified file 'lib/lp/codehosting/sshserver/auth.py'
375--- lib/lp/codehosting/sshserver/auth.py 2010-04-13 18:32:15 +0000
376+++ lib/lp/codehosting/sshserver/auth.py 2010-04-16 18:57:30 +0000
377@@ -39,7 +39,7 @@
378 from zope.interface import implements
379
380 from lp.codehosting import sftp
381-from lp.codehosting.sshserver import accesslog
382+from lp.codehosting.sshserver import events
383 from lp.codehosting.sshserver.session import (
384 launch_smart_server, PatchedSSHSession)
385 from lp.services.twistedsupport.xmlrpc import trap_fault
386@@ -71,7 +71,7 @@
387 self.subsystemLookup = {'sftp': sftp.FileTransferServer}
388
389 def logout(self):
390- notify(accesslog.UserLoggedOut(self))
391+ notify(events.UserLoggedOut(self))
392
393
394 components.registerAdapter(launch_smart_server, LaunchpadAvatar, ISession)
395@@ -215,7 +215,7 @@
396 # connection in the logs.
397 avatar = self.transport.avatar
398 avatar.transport = self.transport
399- notify(accesslog.UserLoggedIn(avatar))
400+ notify(events.UserLoggedIn(avatar))
401 return ret
402
403 def _ebLogToBanner(self, reason):
404
405=== added file 'lib/lp/codehosting/sshserver/events.py'
406--- lib/lp/codehosting/sshserver/events.py 1970-01-01 00:00:00 +0000
407+++ lib/lp/codehosting/sshserver/events.py 2010-04-16 18:57:30 +0000
408@@ -0,0 +1,155 @@
409+# Copyright 2010 Canonical Ltd. This software is licensed under the
410+# GNU Affero General Public License version 3 (see the file LICENSE).
411+
412+"""Events generated by the SSH server."""
413+
414+__metaclass__ = type
415+__all__ = [
416+ 'AuthenticationFailed',
417+ 'BazaarSSHClosed',
418+ 'BazaarSSHStarted',
419+ 'ILoggingEvent',
420+ 'LoggingEvent',
421+ 'ServerStarting',
422+ 'ServerStopped',
423+ 'SFTPClosed',
424+ 'SFTPStarted',
425+ 'UserConnected',
426+ 'UserDisconnected',
427+ 'UserLoggedIn',
428+ 'UserLoggedOut',
429+ ]
430+
431+import logging
432+
433+from zope.interface import Attribute, implements, Interface
434+
435+
436+class ILoggingEvent(Interface):
437+ """An event is a logging event if it has a message and a severity level.
438+
439+ Events that provide this interface will be logged in codehosting access
440+ log.
441+ """
442+
443+ level = Attribute("The level to log the event at.")
444+ message = Attribute("The message to log.")
445+
446+
447+class LoggingEvent:
448+ """An event that can be logged to a Python logger.
449+
450+ :ivar level: The level to log itself as. This should be defined as a
451+ class variable in subclasses.
452+ :ivar template: The format string of the message to log. This should be
453+ defined as a class variable in subclasses.
454+ """
455+
456+ implements(ILoggingEvent)
457+
458+ def __init__(self, level=None, template=None, **data):
459+ """Construct a logging event.
460+
461+ :param level: The level to log the event as. If specified, overrides
462+ the 'level' class variable.
463+ :param template: The format string of the message to log. If
464+ specified, overrides the 'template' class variable.
465+ :param **data: Information to be logged. Entries will be substituted
466+ into the template and stored as attributes.
467+ """
468+ if level is not None:
469+ self._level = level
470+ if template is not None:
471+ self.template = template
472+ self._data = data
473+
474+ @property
475+ def level(self):
476+ """See `ILoggingEvent`."""
477+ return self._level
478+
479+ @property
480+ def message(self):
481+ """See `ILoggingEvent`."""
482+ return self.template % self._data
483+
484+
485+class ServerStarting(LoggingEvent):
486+
487+ level = logging.INFO
488+ template = '---- Server started ----'
489+
490+
491+class ServerStopped(LoggingEvent):
492+
493+ level = logging.INFO
494+ template = '---- Server stopped ----'
495+
496+
497+class UserConnected(LoggingEvent):
498+
499+ level = logging.INFO
500+ template = '[%(session_id)s] %(address)s connected.'
501+
502+ def __init__(self, transport, address):
503+ LoggingEvent.__init__(
504+ self, session_id=id(transport), address=address)
505+
506+
507+class AuthenticationFailed(LoggingEvent):
508+
509+ level = logging.INFO
510+ template = '[%(session_id)s] failed to authenticate.'
511+
512+ def __init__(self, transport):
513+ LoggingEvent.__init__(self, session_id=id(transport))
514+
515+
516+class UserDisconnected(LoggingEvent):
517+
518+ level = logging.INFO
519+ template = '[%(session_id)s] disconnected.'
520+
521+ def __init__(self, transport):
522+ LoggingEvent.__init__(self, session_id=id(transport))
523+
524+
525+class AvatarEvent(LoggingEvent):
526+ """Base avatar event."""
527+
528+ level = logging.INFO
529+
530+ def __init__(self, avatar):
531+ self.avatar = avatar
532+ LoggingEvent.__init__(
533+ self, session_id=id(avatar.transport), username=avatar.username)
534+
535+
536+class UserLoggedIn(AvatarEvent):
537+
538+ template = '[%(session_id)s] %(username)s logged in.'
539+
540+
541+class UserLoggedOut(AvatarEvent):
542+
543+ template = '[%(session_id)s] %(username)s disconnected.'
544+
545+
546+class SFTPStarted(AvatarEvent):
547+
548+ template = '[%(session_id)s] %(username)s started SFTP session.'
549+
550+
551+class SFTPClosed(AvatarEvent):
552+
553+ template = '[%(session_id)s] %(username)s closed SFTP session.'
554+
555+
556+class BazaarSSHStarted(AvatarEvent):
557+
558+ template = '[%(session_id)s] %(username)s started bzr+ssh session.'
559+
560+
561+class BazaarSSHClosed(AvatarEvent):
562+
563+ template = '[%(session_id)s] %(username)s closed bzr+ssh session.'
564
565=== modified file 'lib/lp/codehosting/sshserver/service.py'
566--- lib/lp/codehosting/sshserver/service.py 2010-04-15 09:14:06 +0000
567+++ lib/lp/codehosting/sshserver/service.py 2010-04-16 18:57:30 +0000
568@@ -8,10 +8,17 @@
569
570 __metaclass__ = type
571 __all__ = [
572+ 'ACCESS_LOG_NAME',
573+ 'get_key_path',
574+ 'LOG_NAME',
575+ 'make_portal',
576+ 'PRIVATE_KEY_FILE',
577+ 'PUBLIC_KEY_FILE',
578 'SSHService',
579 ]
580
581
582+import logging
583 import os
584
585 from twisted.application import service, strports
586@@ -25,9 +32,20 @@
587 from zope.event import notify
588
589 from canonical.config import config
590-from lp.codehosting.sshserver import accesslog
591+from lp.codehosting.sshserver import accesslog, events
592 from lp.codehosting.sshserver.auth import get_portal, SSHUserAuthServer
593 from lp.services.twistedsupport import gatherResults
594+from lp.services.twistedsupport.loggingsupport import set_up_oops_reporting
595+
596+
597+# The names of the key files of the server itself. The directory itself is
598+# given in config.codehosting.host_key_pair_path.
599+PRIVATE_KEY_FILE = 'ssh_host_key_rsa'
600+PUBLIC_KEY_FILE = 'ssh_host_key_rsa.pub'
601+
602+OOPS_CONFIG_SECTION = 'codehosting'
603+LOG_NAME = 'codehosting'
604+ACCESS_LOG_NAME = 'codehosting.access'
605
606
607 # The names of the key files of the server itself. The directory itself is
608@@ -43,26 +61,46 @@
609 self.transport.setTcpKeepAlive(True)
610
611
612-def get_key_path(key_filename):
613- key_directory = config.codehosting.host_key_pair_path
614- return os.path.join(config.root, key_directory, key_filename)
615-
616-
617-def make_portal():
618- """Create and return a `Portal` for the SSH service.
619-
620- This portal accepts SSH credentials and returns our customized SSH
621- avatars (see `lp.codehosting.sshserver.auth.LaunchpadAvatar`).
622- """
623- authentication_proxy = Proxy(
624- config.codehosting.authentication_endpoint)
625- branchfs_proxy = Proxy(config.codehosting.branchfs_endpoint)
626- return get_portal(authentication_proxy, branchfs_proxy)
627-
628-
629-
630+<<<<<<< TREE
631+def get_key_path(key_filename):
632+ key_directory = config.codehosting.host_key_pair_path
633+ return os.path.join(config.root, key_directory, key_filename)
634+
635+
636+def make_portal():
637+ """Create and return a `Portal` for the SSH service.
638+
639+ This portal accepts SSH credentials and returns our customized SSH
640+ avatars (see `lp.codehosting.sshserver.auth.LaunchpadAvatar`).
641+ """
642+ authentication_proxy = Proxy(
643+ config.codehosting.authentication_endpoint)
644+ branchfs_proxy = Proxy(config.codehosting.branchfs_endpoint)
645+ return get_portal(authentication_proxy, branchfs_proxy)
646+
647+
648+
649+=======
650+def get_key_path(key_filename):
651+ key_directory = config.codehosting.host_key_pair_path
652+ return os.path.join(config.root, key_directory, key_filename)
653+
654+
655+def make_portal():
656+ """Create and return a `Portal` for the SSH service.
657+
658+ This portal accepts SSH credentials and returns our customized SSH
659+ avatars (see `lp.codehosting.sshserver.auth.LaunchpadAvatar`).
660+ """
661+ authentication_proxy = Proxy(
662+ config.codehosting.authentication_endpoint)
663+ branchfs_proxy = Proxy(config.codehosting.branchfs_endpoint)
664+ return get_portal(authentication_proxy, branchfs_proxy)
665+
666+
667+>>>>>>> MERGE-SOURCE
668 class Factory(SSHFactory):
669- """SSH factory that uses the codehosting custom authentication.
670+ """SSH factory that uses Launchpad's custom authentication.
671
672 This class tells the SSH service to use our custom authentication service
673 and configures the host keys for the SSH server. It also logs connection
674@@ -105,7 +143,7 @@
675 transport._realConnectionLost = transport.connectionLost
676 transport.connectionLost = (
677 lambda reason: self.connectionLost(transport, reason))
678- notify(accesslog.UserConnected(transport, address))
679+ notify(events.UserConnected(transport, address))
680 return transport
681
682 def connectionLost(self, transport, reason):
683@@ -124,9 +162,15 @@
684 # b) the server doesn't normally generate a "go away" event.
685 # Rather, the client simply stops trying.
686 if getattr(transport, 'avatar', None) is None:
687+<<<<<<< TREE
688 notify(accesslog.AuthenticationFailed(transport))
689 notify(accesslog.UserDisconnected(transport))
690
691+=======
692+ notify(events.AuthenticationFailed(transport))
693+ notify(events.UserDisconnected(transport))
694+
695+>>>>>>> MERGE-SOURCE
696 def getPublicKeys(self):
697 """Return the server's configured public key.
698
699@@ -143,6 +187,7 @@
700
701
702 class SSHService(service.Service):
703+<<<<<<< TREE
704 """A Twisted service for the codehosting SSH server."""
705
706 def __init__(self, portal, private_key_path, public_key_path,
707@@ -159,20 +204,71 @@
708 connection that isn't doing anything. Defaults to 3600.
709 :param banner: An announcement printed to users when they connect.
710 By default, announce nothing.
711+=======
712+ """A Twisted service for the SSH server."""
713+
714+ def __init__(self, portal, private_key_path, public_key_path,
715+ oops_configuration, main_log, access_log,
716+ access_log_path, strport='tcp:22', idle_timeout=3600,
717+ banner=None):
718+ """Construct an SSH service.
719+
720+ :param portal: The `Portal` that turns authentication requests into
721+ views on the system.
722+ :param private_key_path: The path to the SSH server's private key.
723+ :param public_key_path: The path to the SSH server's public key.
724+ :param oops_configuration: The section of the configuration file with
725+ the OOPS config details for this server.
726+ :param main_log: A `logging.Logger` object to log most of the server
727+ stuff to.
728+ :param access_log: A `logging.Logger` object to log the server access
729+ details to.
730+ :param access_log_path: The path to the access log file.
731+ :param strport: The port to run the server on, expressed in Twisted's
732+ "strports" mini-language. Defaults to 'tcp:22'.
733+ :param idle_timeout: The number of seconds to wait before killing a
734+ connection that isn't doing anything. Defaults to 3600.
735+ :param banner: An announcement printed to users when they connect.
736+ By default, announce nothing.
737+>>>>>>> MERGE-SOURCE
738 """
739 ssh_factory = TimeoutFactory(
740- Factory(
741- portal,
742- private_key=Key.fromFile(private_key_path),
743- public_key=Key.fromFile(public_key_path),
744- banner=banner),
745- timeoutPeriod=idle_timeout)
746- self.service = strports.service(strport, ssh_factory)
747+<<<<<<< TREE
748+ Factory(
749+ portal,
750+ private_key=Key.fromFile(private_key_path),
751+ public_key=Key.fromFile(public_key_path),
752+ banner=banner),
753+ timeoutPeriod=idle_timeout)
754+ self.service = strports.service(strport, ssh_factory)
755+=======
756+ Factory(
757+ portal,
758+ private_key=Key.fromFile(private_key_path),
759+ public_key=Key.fromFile(public_key_path),
760+ banner=banner),
761+ timeoutPeriod=idle_timeout)
762+ self.service = strports.service(strport, ssh_factory)
763+ self._oops_configuration = oops_configuration
764+ self._main_log = main_log
765+ self._access_log = access_log
766+ self._access_log_path = access_log_path
767+>>>>>>> MERGE-SOURCE
768
769 def startService(self):
770 """Start the SSH service."""
771+<<<<<<< TREE
772 accesslog.LoggingManager().setUp(configure_oops_reporting=True)
773 notify(accesslog.ServerStarting())
774+=======
775+ manager = accesslog.LoggingManager(
776+ logging.getLogger(self._main_log),
777+ logging.getLogger(self._access_log_path),
778+ self._access_log_path)
779+ manager.setUp()
780+ set_up_oops_reporting(self._oops_configuration)
781+ notify(events.ServerStarting())
782+>>>>>>> MERGE-SOURCE
783 # By default, only the owner of files should be able to write to them.
784 # Perhaps in the future this line will be deleted and the umask
785 # managed by the startup script.
786@@ -186,6 +282,6 @@
787 defer.maybeDeferred(service.Service.stopService, self),
788 defer.maybeDeferred(self.service.stopService)])
789 def log_stopped(ignored):
790- notify(accesslog.ServerStopped())
791+ notify(events.ServerStopped())
792 return ignored
793 return deferred.addBoth(log_stopped)
794
795=== modified file 'lib/lp/codehosting/sshserver/session.py'
796--- lib/lp/codehosting/sshserver/session.py 2010-03-15 05:38:03 +0000
797+++ lib/lp/codehosting/sshserver/session.py 2010-04-16 18:57:30 +0000
798@@ -22,7 +22,7 @@
799
800 from canonical.config import config
801 from lp.codehosting import get_bzr_path
802-from lp.codehosting.sshserver import accesslog
803+from lp.codehosting.sshserver import events
804
805
806 class PatchedSSHSession(session.SSHSession, object):
807@@ -116,7 +116,7 @@
808 def closed(self):
809 """See ISession."""
810 if self._transport is not None:
811- notify(accesslog.BazaarSSHClosed(self.avatar))
812+ notify(events.BazaarSSHClosed(self.avatar))
813 try:
814 self._transport.signalProcess('HUP')
815 except (OSError, ProcessExitedAlready):
816@@ -156,7 +156,7 @@
817 # XXX: JonathanLange 2008-12-23: This is something of an abstraction
818 # violation. Apart from this line, this class knows nothing about
819 # Bazaar.
820- notify(accesslog.BazaarSSHStarted(self.avatar))
821+ notify(events.BazaarSSHStarted(self.avatar))
822 self._transport = self.reactor.spawnProcess(
823 protocol, executable, arguments, env=self.environment)
824
825
826=== added file 'lib/lp/codehosting/sshserver/tests/test_events.py'
827--- lib/lp/codehosting/sshserver/tests/test_events.py 1970-01-01 00:00:00 +0000
828+++ lib/lp/codehosting/sshserver/tests/test_events.py 2010-04-16 18:57:30 +0000
829@@ -0,0 +1,91 @@
830+# Copyright 2010 Canonical Ltd. This software is licensed under the
831+# GNU Affero General Public License version 3 (see the file LICENSE).
832+
833+"""Tests for the logging events."""
834+
835+__metaclass__ = type
836+
837+import logging
838+import unittest
839+
840+from zope.component import adapter, getGlobalSiteManager, provideHandler
841+# This non-standard import is necessary to hook up the event system.
842+import zope.component.event
843+from zope.event import notify
844+
845+from lp.codehosting.sshserver.events import ILoggingEvent, LoggingEvent
846+
847+from lp.testing import TestCase
848+
849+
850+class ListHandler(logging.Handler):
851+ """Logging handler that just appends records to a list.
852+
853+ This handler isn't intended to be used by production code -- memory leak
854+ city! -- instead it's useful for unit tests that want to make sure the
855+ right events are being logged.
856+ """
857+
858+ def __init__(self, logging_list):
859+ """Construct a `ListHandler`.
860+
861+ :param logging_list: A list that will be appended to. The handler
862+ mutates this list.
863+ """
864+ logging.Handler.__init__(self)
865+ self._list = logging_list
866+
867+ def emit(self, record):
868+ """Append 'record' to the list."""
869+ self._list.append(record)
870+
871+
872+class TestLoggingEvent(TestCase):
873+
874+ def assertLogs(self, records, function, *args, **kwargs):
875+ """Assert 'function' logs 'records' when run with the given args."""
876+ logged_events = []
877+ handler = ListHandler(logged_events)
878+ self.logger.addHandler(handler)
879+ result = function(*args, **kwargs)
880+ self.logger.removeHandler(handler)
881+ self.assertEqual(
882+ [(record.levelno, record.getMessage())
883+ for record in logged_events], records)
884+ return result
885+
886+ def assertEventLogs(self, record, logging_event):
887+ self.assertLogs([record], notify, logging_event)
888+
889+ def setUp(self):
890+ TestCase.setUp(self)
891+ logger = logging.getLogger(self.factory.getUniqueString())
892+ logger.setLevel(logging.DEBUG)
893+ self.logger = logger
894+
895+ @adapter(ILoggingEvent)
896+ def _log_event(event):
897+ logger.log(event.level, event.message)
898+
899+ provideHandler(_log_event)
900+ self.addCleanup(getGlobalSiteManager().unregisterHandler, _log_event)
901+
902+ def test_level(self):
903+ event = LoggingEvent(logging.CRITICAL, "foo")
904+ self.assertEventLogs((logging.CRITICAL, 'foo'), event)
905+
906+ def test_formatting(self):
907+ event = LoggingEvent(logging.DEBUG, "foo: %(name)s", name="bar")
908+ self.assertEventLogs((logging.DEBUG, 'foo: bar'), event)
909+
910+ def test_subclass(self):
911+ class SomeEvent(LoggingEvent):
912+ template = "%(something)s happened."
913+ level = logging.INFO
914+ self.assertEventLogs(
915+ (logging.INFO, 'foo happened.'), SomeEvent(something='foo'))
916+
917+
918+def test_suite():
919+ return unittest.TestLoader().loadTestsFromName(__name__)
920+
921
922=== modified file 'lib/lp/codehosting/sshserver/tests/test_logging.py'
923--- lib/lp/codehosting/sshserver/tests/test_logging.py 2010-01-22 03:27:59 +0000
924+++ lib/lp/codehosting/sshserver/tests/test_logging.py 2010-04-16 18:57:30 +0000
925@@ -7,26 +7,48 @@
926
927 import codecs
928 import logging
929+import os
930 from StringIO import StringIO
931+import tempfile
932 import unittest
933 import sys
934
935 from bzrlib.tests import TestCase as BzrTestCase
936
937-from twisted.python import log as tplog
938-
939 import zope.component.event
940-from zope.event import notify
941
942-from lp.codehosting.sshserver.accesslog import (
943- _log_event, get_access_logger, get_codehosting_logger, LoggingEvent,
944- LoggingManager)
945-from canonical.config import config
946 from canonical.launchpad.scripts import WatchedFileHandler
947+from lp.codehosting.sshserver.accesslog import LoggingManager
948 from lp.testing import TestCase
949
950
951-class TestLoggingBazaarInteraction(BzrTestCase):
952+class LoggingManagerMixin:
953+
954+ _log_count = 0
955+
956+ def makeLogger(self, name=None):
957+ if name is None:
958+ self._log_count += 1
959+ name = '%s-%s' % (self.id().split('.')[-1], self._log_count)
960+ return logging.getLogger(name)
961+
962+ def installLoggingManager(self, main_log=None, access_log=None,
963+ access_log_path=None):
964+ if main_log is None:
965+ main_log = self.makeLogger()
966+ if access_log is None:
967+ access_log = self.makeLogger()
968+ if access_log_path is None:
969+ fd, access_log_path = tempfile.mkstemp()
970+ os.close(fd)
971+ self.addCleanup(os.unlink, access_log_path)
972+ manager = LoggingManager(main_log, access_log, access_log_path)
973+ manager.setUp()
974+ self.addCleanup(manager.tearDown)
975+ return manager
976+
977+
978+class TestLoggingBazaarInteraction(BzrTestCase, LoggingManagerMixin):
979
980 def setUp(self):
981 BzrTestCase.setUp(self)
982@@ -44,9 +66,7 @@
983 root_handlers = logging.getLogger('').handlers
984 bzr_handlers = logging.getLogger('bzr').handlers
985
986- manager = LoggingManager()
987- manager.setUp()
988- self.addCleanup(manager.tearDown)
989+ self.installLoggingManager()
990
991 self.assertEqual(root_handlers, logging.getLogger('').handlers)
992 self.assertEqual(bzr_handlers, logging.getLogger('bzr').handlers)
993@@ -55,30 +75,24 @@
994 # Once logging setup is called, any messages logged to the
995 # codehosting logger should *not* be logged to stderr. If they are,
996 # they will appear on the user's terminal.
997- manager = LoggingManager()
998- manager.setUp()
999- self.addCleanup(manager.tearDown)
1000+ log = self.makeLogger()
1001+ self.installLoggingManager(log)
1002
1003 # Make sure that a logged message does not go to stderr.
1004- get_codehosting_logger().info('Hello hello')
1005+ log.info('Hello hello')
1006 self.assertEqual(sys.stderr.getvalue(), '')
1007
1008
1009-class TestLoggingManager(TestCase):
1010-
1011- def test_returns_codehosting_logger(self):
1012- # get_codehosting_logger returns the 'codehosting' logger.
1013- self.assertIs(
1014- logging.getLogger('codehosting'), get_codehosting_logger())
1015-
1016- def test_codehosting_handlers(self):
1017- # There needs to be at least one handler for the codehosting root
1018- # logger.
1019- manager = LoggingManager()
1020- manager.setUp()
1021- self.addCleanup(manager.tearDown)
1022- handlers = get_codehosting_logger().handlers
1023- self.assertNotEqual([], handlers)
1024+class TestLoggingManager(TestCase, LoggingManagerMixin):
1025+
1026+ def test_main_log_handlers(self):
1027+ # There needs to be at least one handler for the root logger. If there
1028+ # isn't, we'll get constant errors complaining about the lack of
1029+ # logging handlers.
1030+ log = self.makeLogger()
1031+ self.assertEqual([], log.handlers)
1032+ self.installLoggingManager(log)
1033+ self.assertNotEqual([], log.handlers)
1034
1035 def _get_handlers(self):
1036 registrations = (
1037@@ -87,126 +101,51 @@
1038 registration.factory
1039 for registration in registrations]
1040
1041- def test_log_event_handler_not_registered(self):
1042- self.assertNotIn(_log_event, self._get_handlers())
1043-
1044 def test_set_up_registers_event_handler(self):
1045- manager = LoggingManager()
1046- manager.setUp()
1047- self.addCleanup(manager.tearDown)
1048- self.assertIn(_log_event, self._get_handlers())
1049+ manager = self.installLoggingManager()
1050+ self.assertIn(manager._log_event, self._get_handlers())
1051
1052 def test_teardown_restores_event_handlers(self):
1053 handlers = self._get_handlers()
1054- manager = LoggingManager()
1055- manager.setUp()
1056+ manager = self.installLoggingManager()
1057 manager.tearDown()
1058 self.assertEqual(handlers, self._get_handlers())
1059
1060 def test_teardown_restores_level(self):
1061- log = get_codehosting_logger()
1062+ log = self.makeLogger()
1063 old_level = log.level
1064- manager = LoggingManager()
1065- manager.setUp()
1066+ manager = self.installLoggingManager(log)
1067 manager.tearDown()
1068 self.assertEqual(old_level, log.level)
1069
1070- def test_teardown_restores_handlers(self):
1071- log = get_codehosting_logger()
1072+ def test_teardown_restores_main_log_handlers(self):
1073+ # tearDown restores log handlers for the main logger.
1074+ log = self.makeLogger()
1075 handlers = list(log.handlers)
1076- manager = LoggingManager()
1077- manager.setUp()
1078+ manager = self.installLoggingManager(log)
1079 manager.tearDown()
1080 self.assertEqual(handlers, log.handlers)
1081
1082- def test_teardown_restores_twisted_observers(self):
1083- observers = list(tplog.theLogPublisher.observers)
1084- manager = LoggingManager()
1085- manager.setUp(True)
1086+ def test_teardown_restores_access_log_handlers(self):
1087+ # tearDown restores log handlers for the access logger.
1088+ log = self.makeLogger()
1089+ handlers = list(log.handlers)
1090+ manager = self.installLoggingManager(access_log=log)
1091 manager.tearDown()
1092- self.assertEqual(observers, list(tplog.theLogPublisher.observers))
1093+ self.assertEqual(handlers, log.handlers)
1094
1095 def test_access_handlers(self):
1096 # The logging setup installs a rotatable log handler that logs output
1097 # to config.codehosting.access_log.
1098- manager = LoggingManager()
1099- manager.setUp()
1100- self.addCleanup(manager.tearDown)
1101- [handler] = get_access_logger().handlers
1102+ directory = self.makeTemporaryDirectory()
1103+ access_log = self.makeLogger()
1104+ access_log_path = os.path.join(directory, 'access.log')
1105+ self.installLoggingManager(
1106+ access_log=access_log,
1107+ access_log_path=access_log_path)
1108+ [handler] = access_log.handlers
1109 self.assertIsInstance(handler, WatchedFileHandler)
1110- self.assertEqual(config.codehosting.access_log, handler.baseFilename)
1111-
1112- def test_teardown_restores_access_handlers(self):
1113- log = get_access_logger()
1114- handlers = list(log.handlers)
1115- manager = LoggingManager()
1116- manager.setUp()
1117- manager.tearDown()
1118- self.assertEqual(handlers, log.handlers)
1119-
1120-
1121-class ListHandler(logging.Handler):
1122- """Logging handler that just appends records to a list.
1123-
1124- This handler isn't intended to be used by production code -- memory leak
1125- city! -- instead it's useful for unit tests that want to make sure the
1126- right events are being logged.
1127- """
1128-
1129- def __init__(self, logging_list):
1130- """Construct a `ListHandler`.
1131-
1132- :param logging_list: A list that will be appended to. The handler
1133- mutates this list.
1134- """
1135- logging.Handler.__init__(self)
1136- self._list = logging_list
1137-
1138- def emit(self, record):
1139- """Append 'record' to the list."""
1140- self._list.append(record)
1141-
1142-
1143-class TestLoggingEvent(TestCase):
1144-
1145- def assertLogs(self, records, function, *args, **kwargs):
1146- """Assert 'function' logs 'records' when run with the given args."""
1147- logged_events = []
1148- handler = ListHandler(logged_events)
1149- self.logger.addHandler(handler)
1150- result = function(*args, **kwargs)
1151- self.logger.removeHandler(handler)
1152- self.assertEqual(
1153- [(record.levelno, record.getMessage())
1154- for record in logged_events], records)
1155- return result
1156-
1157- def assertEventLogs(self, record, logging_event):
1158- self.assertLogs([record], notify, logging_event)
1159-
1160- def setUp(self):
1161- TestCase.setUp(self)
1162- zope.component.provideHandler(_log_event)
1163- self.addCleanup(
1164- zope.component.getGlobalSiteManager().unregisterHandler,
1165- _log_event)
1166- self.logger = get_codehosting_logger()
1167- self.logger.setLevel(logging.DEBUG)
1168-
1169- def test_level(self):
1170- event = LoggingEvent(logging.CRITICAL, "foo")
1171- self.assertEventLogs((logging.CRITICAL, 'foo'), event)
1172-
1173- def test_formatting(self):
1174- event = LoggingEvent(logging.DEBUG, "foo: %(name)s", name="bar")
1175- self.assertEventLogs((logging.DEBUG, 'foo: bar'), event)
1176-
1177- def test_subclass(self):
1178- class SomeEvent(LoggingEvent):
1179- template = "%(something)s happened."
1180- level = logging.INFO
1181- self.assertEventLogs(
1182- (logging.INFO, 'foo happened.'), SomeEvent(something='foo'))
1183+ self.assertEqual(access_log_path, handler.baseFilename)
1184
1185
1186 def test_suite():