← Back to branch summary

~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/lockdir.py

  • Committer: Ian Clatworthy
  • Author(s): Robert Collins
  • Date: 2009-04-03 05:08:45 UTC
  • mfrom: (4241.4.1 bzr.bris-vf)
  • mto: This revision was merged to the branch mainline in revision 4245.
  • Revision ID: ian.clatworthy@canonical.com-20090403050845-w656xtmr19jtuovs
add sha generation support to versioned files (Robert Collins)

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/lockdir.py
1
 
# Copyright (C) 2006 Canonical Ltd
 
1
# Copyright (C) 2006, 2007, 2008 Canonical Ltd
2
2
#
3
3
# This program is free software; you can redistribute it and/or modify
4
4
# it under the terms of the GNU General Public License as published by
12
12
#
13
13
# You should have received a copy of the GNU General Public License
14
14
# along with this program; if not, write to the Free Software
15
 
# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
 
15
# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
16
16
 
17
17
"""On-disk mutex protecting a resource
18
18
 
21
21
internal locks (such as flock etc) because they can be seen across all
22
22
transports, including http.
23
23
 
24
 
Objects can be read if there is only physical read access; therefore 
 
24
Objects can be read if there is only physical read access; therefore
25
25
readers can never be required to create a lock, though they will
26
26
check whether a writer is using the lock.  Writers can't detect
27
27
whether anyone else is reading from the resource as they write.
56
56
 
57
57
The desired characteristics are:
58
58
 
59
 
* Locks are not reentrant.  (That is, a client that tries to take a 
 
59
* Locks are not reentrant.  (That is, a client that tries to take a
60
60
  lock it already holds may deadlock or fail.)
61
61
* Stale locks can be guessed at by a heuristic
62
62
* Lost locks can be broken by any client
78
78
and deadlocks will likely occur if the locks are aliased.
79
79
 
80
80
In the future we may add a "freshen" method which can be called
81
 
by a lock holder to check that their lock has not been broken, and to 
 
81
by a lock holder to check that their lock has not been broken, and to
82
82
update the timestamp within it.
83
83
 
84
84
Example usage:
88
88
>>> t = MemoryTransport()
89
89
>>> l = LockDir(t, 'sample-lock')
90
90
>>> l.create()
91
 
>>> l.wait_lock()
 
91
>>> token = l.wait_lock()
92
92
>>> # do something here
93
93
>>> l.unlock()
94
94
 
95
95
"""
96
96
 
 
97
 
 
98
# TODO: We sometimes have the problem that our attempt to rename '1234' to
 
99
# 'held' fails because the transport server moves into an existing directory,
 
100
# rather than failing the rename.  If we made the info file name the same as
 
101
# the locked directory name we would avoid this problem because moving into
 
102
# the held directory would implicitly clash.  However this would not mesh with
 
103
# the existing locking code and needs a new format of the containing object.
 
104
# -- robertc, mbp 20070628
 
105
 
97
106
import os
98
107
import time
99
 
from cStringIO import StringIO
100
108
 
101
109
from bzrlib import (
 
110
    debug,
102
111
    errors,
 
112
    lock,
103
113
    )
104
114
import bzrlib.config
105
115
from bzrlib.errors import (
108
118
        LockBreakMismatch,
109
119
        LockBroken,
110
120
        LockContention,
 
121
        LockFailed,
111
122
        LockNotHeld,
112
123
        NoSuchFile,
113
124
        PathError,
114
125
        ResourceBusy,
115
 
        UnlockableTransport,
 
126
        TransportError,
116
127
        )
117
128
from bzrlib.trace import mutter, note
118
 
from bzrlib.transport import Transport
119
 
from bzrlib.osutils import rand_chars, format_delta
120
 
from bzrlib.rio import read_stanza, Stanza
 
129
from bzrlib.osutils import format_delta, rand_chars, get_host_name
121
130
import bzrlib.ui
122
131
 
 
132
from bzrlib.lazy_import import lazy_import
 
133
lazy_import(globals(), """
 
134
from bzrlib import rio
 
135
""")
123
136
 
124
137
# XXX: At the moment there is no consideration of thread safety on LockDir
125
138
# objects.  This should perhaps be updated - e.g. if two threads try to take a
140
153
_DEFAULT_POLL_SECONDS = 1.0
141
154
 
142
155
 
143
 
class LockDir(object):
144
 
    """Write-lock guarding access to data."""
 
156
class LockDir(lock.Lock):
 
157
    """Write-lock guarding access to data.
 
158
    """
145
159
 
146
160
    __INFO_NAME = '/info'
147
161
 
152
166
 
153
167
        :param transport: Transport which will contain the lock
154
168
 
155
 
        :param path: Path to the lock within the base directory of the 
 
169
        :param path: Path to the lock within the base directory of the
156
170
            transport.
157
171
        """
158
 
        assert isinstance(transport, Transport), \
159
 
            ("not a transport: %r" % transport)
160
172
        self.transport = transport
161
173
        self.path = path
162
174
        self._lock_held = False
 
175
        self._locked_via_token = False
163
176
        self._fake_read_lock = False
164
177
        self._held_dir = path + '/held'
165
178
        self._held_info_path = self._held_dir + self.__INFO_NAME
166
179
        self._file_modebits = file_modebits
167
180
        self._dir_modebits = dir_modebits
168
 
        self.nonce = rand_chars(20)
169
181
 
170
182
        self._report_function = note
171
183
 
179
191
    def create(self, mode=None):
180
192
        """Create the on-disk lock.
181
193
 
182
 
        This is typically only called when the object/directory containing the 
 
194
        This is typically only called when the object/directory containing the
183
195
        directory is first created.  The lock is not held when it's created.
184
196
        """
185
 
        if self.transport.is_readonly():
186
 
            raise UnlockableTransport(self.transport)
187
 
        self.transport.mkdir(self.path, mode=mode)
188
 
 
189
 
    def attempt_lock(self):
190
 
        """Take the lock; fail if it's already held.
191
 
        
192
 
        If you wish to block until the lock can be obtained, call wait_lock()
193
 
        instead.
 
197
        self._trace("create lock directory")
 
198
        try:
 
199
            self.transport.mkdir(self.path, mode=mode)
 
200
        except (TransportError, PathError), e:
 
201
            raise LockFailed(self, e)
 
202
 
 
203
 
 
204
    def _attempt_lock(self):
 
205
        """Make the pending directory and attempt to rename into place.
 
206
 
 
207
        If the rename succeeds, we read back the info file to check that we
 
208
        really got the lock.
 
209
 
 
210
        If we fail to acquire the lock, this method is responsible for
 
211
        cleaning up the pending directory if possible.  (But it doesn't do
 
212
        that yet.)
 
213
 
 
214
        :returns: The nonce of the lock, if it was successfully acquired.
 
215
 
 
216
        :raises LockContention: If the lock is held by someone else.  The exception
 
217
            contains the info of the current holder of the lock.
194
218
        """
195
 
        if self._fake_read_lock:
196
 
            raise LockContention(self)
197
 
        if self.transport.is_readonly():
198
 
            raise UnlockableTransport(self.transport)
199
 
        try:
200
 
            tmpname = '%s/pending.%s.tmp' % (self.path, rand_chars(20))
201
 
            try:
202
 
                self.transport.mkdir(tmpname)
203
 
            except NoSuchFile:
204
 
                # This may raise a FileExists exception
205
 
                # which is okay, it will be caught later and determined
206
 
                # to be a LockContention.
207
 
                self.create(mode=self._dir_modebits)
208
 
                
209
 
                # After creating the lock directory, try again
210
 
                self.transport.mkdir(tmpname)
211
 
 
212
 
            info_bytes = self._prepare_info()
213
 
            # We use put_file_non_atomic because we just created a new unique
214
 
            # directory so we don't have to worry about files existing there.
215
 
            # We'll rename the whole directory into place to get atomic
216
 
            # properties
217
 
            self.transport.put_bytes_non_atomic(tmpname + self.__INFO_NAME,
218
 
                                                info_bytes)
219
 
 
 
219
        self._trace("lock_write...")
 
220
        start_time = time.time()
 
221
        try:
 
222
            tmpname = self._create_pending_dir()
 
223
        except (errors.TransportError, PathError), e:
 
224
            self._trace("... failed to create pending dir, %s", e)
 
225
            raise LockFailed(self, e)
 
226
        try:
220
227
            self.transport.rename(tmpname, self._held_dir)
221
 
            self._lock_held = True
222
 
            self.confirm()
223
 
        except (PathError, DirectoryNotEmpty, FileExists, ResourceBusy), e:
224
 
            mutter("contention on %r: %s", self, e)
225
 
            raise LockContention(self)
 
228
        except (errors.TransportError, PathError, DirectoryNotEmpty,
 
229
                FileExists, ResourceBusy), e:
 
230
            self._trace("... contention, %s", e)
 
231
            self._remove_pending_dir(tmpname)
 
232
            raise LockContention(self)
 
233
        except Exception, e:
 
234
            self._trace("... lock failed, %s", e)
 
235
            self._remove_pending_dir(tmpname)
 
236
            raise
 
237
        # We must check we really got the lock, because Launchpad's sftp
 
238
        # server at one time had a bug were the rename would successfully
 
239
        # move the new directory into the existing directory, which was
 
240
        # incorrect.  It's possible some other servers or filesystems will
 
241
        # have a similar bug allowing someone to think they got the lock
 
242
        # when it's already held.
 
243
        info = self.peek()
 
244
        self._trace("after locking, info=%r", info)
 
245
        if info['nonce'] != self.nonce:
 
246
            self._trace("rename succeeded, "
 
247
                "but lock is still held by someone else")
 
248
            raise LockContention(self)
 
249
        self._lock_held = True
 
250
        self._trace("... lock succeeded after %dms",
 
251
                (time.time() - start_time) * 1000)
 
252
        return self.nonce
 
253
 
 
254
    def _remove_pending_dir(self, tmpname):
 
255
        """Remove the pending directory
 
256
 
 
257
        This is called if we failed to rename into place, so that the pending
 
258
        dirs don't clutter up the lockdir.
 
259
        """
 
260
        self._trace("remove %s", tmpname)
 
261
        try:
 
262
            self.transport.delete(tmpname + self.__INFO_NAME)
 
263
            self.transport.rmdir(tmpname)
 
264
        except PathError, e:
 
265
            note("error removing pending lock: %s", e)
 
266
 
 
267
    def _create_pending_dir(self):
 
268
        tmpname = '%s/%s.tmp' % (self.path, rand_chars(10))
 
269
        try:
 
270
            self.transport.mkdir(tmpname)
 
271
        except NoSuchFile:
 
272
            # This may raise a FileExists exception
 
273
            # which is okay, it will be caught later and determined
 
274
            # to be a LockContention.
 
275
            self._trace("lock directory does not exist, creating it")
 
276
            self.create(mode=self._dir_modebits)
 
277
            # After creating the lock directory, try again
 
278
            self.transport.mkdir(tmpname)
 
279
        self.nonce = rand_chars(20)
 
280
        info_bytes = self._prepare_info()
 
281
        # We use put_file_non_atomic because we just created a new unique
 
282
        # directory so we don't have to worry about files existing there.
 
283
        # We'll rename the whole directory into place to get atomic
 
284
        # properties
 
285
        self.transport.put_bytes_non_atomic(tmpname + self.__INFO_NAME,
 
286
                                            info_bytes)
 
287
        return tmpname
226
288
 
227
289
    def unlock(self):
228
290
        """Release a held lock
232
294
            return
233
295
        if not self._lock_held:
234
296
            raise LockNotHeld(self)
235
 
        # rename before deleting, because we can't atomically remove the whole
236
 
        # tree
237
 
        tmpname = '%s/releasing.%s.tmp' % (self.path, rand_chars(20))
238
 
        # gotta own it to unlock
239
 
        self.confirm()
240
 
        self.transport.rename(self._held_dir, tmpname)
241
 
        self._lock_held = False
242
 
        self.transport.delete(tmpname + self.__INFO_NAME)
243
 
        self.transport.rmdir(tmpname)
 
297
        if self._locked_via_token:
 
298
            self._locked_via_token = False
 
299
            self._lock_held = False
 
300
        else:
 
301
            old_nonce = self.nonce
 
302
            # rename before deleting, because we can't atomically remove the
 
303
            # whole tree
 
304
            start_time = time.time()
 
305
            self._trace("unlocking")
 
306
            tmpname = '%s/releasing.%s.tmp' % (self.path, rand_chars(20))
 
307
            # gotta own it to unlock
 
308
            self.confirm()
 
309
            self.transport.rename(self._held_dir, tmpname)
 
310
            self._lock_held = False
 
311
            self.transport.delete(tmpname + self.__INFO_NAME)
 
312
            try:
 
313
                self.transport.rmdir(tmpname)
 
314
            except DirectoryNotEmpty, e:
 
315
                # There might have been junk left over by a rename that moved
 
316
                # another locker within the 'held' directory.  do a slower
 
317
                # deletion where we list the directory and remove everything
 
318
                # within it.
 
319
                #
 
320
                # Maybe this should be broader to allow for ftp servers with
 
321
                # non-specific error messages?
 
322
                self._trace("doing recursive deletion of non-empty directory "
 
323
                        "%s", tmpname)
 
324
                self.transport.delete_tree(tmpname)
 
325
            self._trace("... unlock succeeded after %dms",
 
326
                    (time.time() - start_time) * 1000)
 
327
            result = lock.LockResult(self.transport.abspath(self.path),
 
328
                old_nonce)
 
329
            for hook in self.hooks['lock_released']:
 
330
                hook(result)
244
331
 
245
332
    def break_lock(self):
246
333
        """Break a lock not held by this instance of LockDir.
255
342
            lock_info = '\n'.join(self._format_lock_info(holder_info))
256
343
            if bzrlib.ui.ui_factory.get_boolean("Break %s" % lock_info):
257
344
                self.force_break(holder_info)
258
 
        
 
345
 
259
346
    def force_break(self, dead_holder_info):
260
347
        """Release a lock held by another process.
261
348
 
269
356
        LockBreakMismatch is raised.
270
357
 
271
358
        After the lock is broken it will not be held by any process.
272
 
        It is possible that another process may sneak in and take the 
 
359
        It is possible that another process may sneak in and take the
273
360
        lock before the breaking process acquires it.
274
361
        """
275
362
        if not isinstance(dead_holder_info, dict):
284
371
        tmpname = '%s/broken.%s.tmp' % (self.path, rand_chars(20))
285
372
        self.transport.rename(self._held_dir, tmpname)
286
373
        # check that we actually broke the right lock, not someone else;
287
 
        # there's a small race window between checking it and doing the 
 
374
        # there's a small race window between checking it and doing the
288
375
        # rename.
289
376
        broken_info_path = tmpname + self.__INFO_NAME
290
377
        broken_info = self._read_info_file(broken_info_path)
305
392
        or if the lock has been affected by a bug.
306
393
 
307
394
        If the lock is not thought to be held, raises LockNotHeld.  If
308
 
        the lock is thought to be held but has been broken, raises 
 
395
        the lock is thought to be held but has been broken, raises
309
396
        LockBroken.
310
397
        """
311
398
        if not self._lock_held:
317
404
        if info.get('nonce') != self.nonce:
318
405
            # there is a lock, but not ours
319
406
            raise LockBroken(self)
320
 
        
 
407
 
321
408
    def _read_info_file(self, path):
322
409
        """Read one given info file.
323
410
 
327
414
 
328
415
    def peek(self):
329
416
        """Check if the lock is held by anyone.
330
 
        
 
417
 
331
418
        If it is held, this returns the lock info structure as a rio Stanza,
332
419
        which contains some information about the current lock holder.
333
420
        Otherwise returns None.
334
421
        """
335
422
        try:
336
423
            info = self._read_info_file(self._held_info_path)
337
 
            assert isinstance(info, dict), \
338
 
                    "bad parse result %r" % info
 
424
            self._trace("peek -> held")
339
425
            return info
340
426
        except NoSuchFile, e:
341
 
            return None
 
427
            self._trace("peek -> not held")
342
428
 
343
429
    def _prepare_info(self):
344
430
        """Write information about a pending lock to a temporary file.
345
431
        """
346
 
        import socket
347
432
        # XXX: is creating this here inefficient?
348
433
        config = bzrlib.config.GlobalConfig()
349
434
        try:
350
435
            user = config.user_email()
351
436
        except errors.NoEmailInUsername:
352
437
            user = config.username()
353
 
        s = Stanza(hostname=socket.gethostname(),
 
438
        s = rio.Stanza(hostname=get_host_name(),
354
439
                   pid=str(os.getpid()),
355
440
                   start_time=str(int(time.time())),
356
441
                   nonce=self.nonce,
359
444
        return s.to_string()
360
445
 
361
446
    def _parse_info(self, info_file):
362
 
        return read_stanza(info_file.readlines()).as_dict()
363
 
 
364
 
    def wait_lock(self, timeout=None, poll=None):
 
447
        return rio.read_stanza(info_file.readlines()).as_dict()
 
448
 
 
449
    def attempt_lock(self):
 
450
        """Take the lock; fail if it's already held.
 
451
 
 
452
        If you wish to block until the lock can be obtained, call wait_lock()
 
453
        instead.
 
454
 
 
455
        :return: The lock token.
 
456
        :raises LockContention: if the lock is held by someone else.
 
457
        """
 
458
        if self._fake_read_lock:
 
459
            raise LockContention(self)
 
460
        result = self._attempt_lock()
 
461
        hook_result = lock.LockResult(self.transport.abspath(self.path),
 
462
                self.nonce)
 
463
        for hook in self.hooks['lock_acquired']:
 
464
            hook(hook_result)
 
465
        return result
 
466
 
 
467
    def wait_lock(self, timeout=None, poll=None, max_attempts=None):
365
468
        """Wait a certain period for a lock.
366
469
 
367
470
        If the lock can be acquired within the bounded time, it
369
472
        is raised.  Either way, this function should return within
370
473
        approximately `timeout` seconds.  (It may be a bit more if
371
474
        a transport operation takes a long time to complete.)
 
475
 
 
476
        :param timeout: Approximate maximum amount of time to wait for the
 
477
        lock, in seconds.
 
478
 
 
479
        :param poll: Delay in seconds between retrying the lock.
 
480
 
 
481
        :param max_attempts: Maximum number of times to try to lock.
 
482
 
 
483
        :return: The lock token.
372
484
        """
373
485
        if timeout is None:
374
486
            timeout = _DEFAULT_TIMEOUT_SECONDS
375
487
        if poll is None:
376
488
            poll = _DEFAULT_POLL_SECONDS
377
 
 
378
 
        # XXX: the transport interface doesn't let us guard 
379
 
        # against operations there taking a long time.
 
489
        # XXX: the transport interface doesn't let us guard against operations
 
490
        # there taking a long time, so the total elapsed time or poll interval
 
491
        # may be more than was requested.
380
492
        deadline = time.time() + timeout
381
493
        deadline_str = None
382
494
        last_info = None
 
495
        attempt_count = 0
383
496
        while True:
 
497
            attempt_count += 1
384
498
            try:
385
 
                self.attempt_lock()
386
 
                return
 
499
                return self.attempt_lock()
387
500
            except LockContention:
 
501
                # possibly report the blockage, then try again
388
502
                pass
 
503
            # TODO: In a few cases, we find out that there's contention by
 
504
            # reading the held info and observing that it's not ours.  In
 
505
            # those cases it's a bit redundant to read it again.  However,
 
506
            # the normal case (??) is that the rename fails and so we
 
507
            # don't know who holds the lock.  For simplicity we peek
 
508
            # always.
389
509
            new_info = self.peek()
390
 
            mutter('last_info: %s, new info: %s', last_info, new_info)
391
510
            if new_info is not None and new_info != last_info:
392
511
                if last_info is None:
393
512
                    start = 'Unable to obtain'
398
517
                if deadline_str is None:
399
518
                    deadline_str = time.strftime('%H:%M:%S',
400
519
                                                 time.localtime(deadline))
 
520
                lock_url = self.transport.abspath(self.path)
401
521
                self._report_function('%s %s\n'
402
522
                                      '%s\n' # held by
403
523
                                      '%s\n' # locked ... ago
404
 
                                      'Will continue to try until %s\n',
 
524
                                      'Will continue to try until %s, unless '
 
525
                                      'you press Ctrl-C\n'
 
526
                                      'If you\'re sure that it\'s not being '
 
527
                                      'modified, use bzr break-lock %s',
405
528
                                      start,
406
529
                                      formatted_info[0],
407
530
                                      formatted_info[1],
408
531
                                      formatted_info[2],
409
 
                                      deadline_str)
 
532
                                      deadline_str,
 
533
                                      lock_url)
410
534
 
 
535
            if (max_attempts is not None) and (attempt_count >= max_attempts):
 
536
                self._trace("exceeded %d attempts")
 
537
                raise LockContention(self)
411
538
            if time.time() + poll < deadline:
 
539
                self._trace("waiting %ss", poll)
412
540
                time.sleep(poll)
413
541
            else:
 
542
                self._trace("timeout after waiting %ss", timeout)
414
543
                raise LockContention(self)
415
544
 
416
 
    def lock_write(self):
417
 
        """Wait for and acquire the lock."""
418
 
        self.wait_lock()
 
545
    def leave_in_place(self):
 
546
        self._locked_via_token = True
 
547
 
 
548
    def dont_leave_in_place(self):
 
549
        self._locked_via_token = False
 
550
 
 
551
    def lock_write(self, token=None):
 
552
        """Wait for and acquire the lock.
 
553
 
 
554
        :param token: if this is already locked, then lock_write will fail
 
555
            unless the token matches the existing lock.
 
556
        :returns: a token if this instance supports tokens, otherwise None.
 
557
        :raises TokenLockingNotSupported: when a token is given but this
 
558
            instance doesn't support using token locks.
 
559
        :raises MismatchedToken: if the specified token doesn't match the token
 
560
            of the existing lock.
 
561
 
 
562
        A token should be passed in if you know that you have locked the object
 
563
        some other way, and need to synchronise this object's state with that
 
564
        fact.
 
565
 
 
566
        XXX: docstring duplicated from LockableFiles.lock_write.
 
567
        """
 
568
        if token is not None:
 
569
            self.validate_token(token)
 
570
            self.nonce = token
 
571
            self._lock_held = True
 
572
            self._locked_via_token = True
 
573
            return token
 
574
        else:
 
575
            return self.wait_lock()
419
576
 
420
577
    def lock_read(self):
421
578
        """Compatibility-mode shared lock.
422
579
 
423
 
        LockDir doesn't support shared read-only locks, so this 
 
580
        LockDir doesn't support shared read-only locks, so this
424
581
        just pretends that the lock is taken but really does nothing.
425
582
        """
426
 
        # At the moment Branches are commonly locked for read, but 
 
583
        # At the moment Branches are commonly locked for read, but
427
584
        # we can't rely on that remotely.  Once this is cleaned up,
428
 
        # reenable this warning to prevent it coming back in 
 
585
        # reenable this warning to prevent it coming back in
429
586
        # -- mbp 20060303
430
587
        ## warn("LockDir.lock_read falls back to write lock")
431
588
        if self._lock_held or self._fake_read_lock:
432
589
            raise LockContention(self)
433
590
        self._fake_read_lock = True
434
591
 
435
 
    def wait(self, timeout=20, poll=0.5):
436
 
        """Wait a certain period for a lock to be released."""
437
 
        # XXX: the transport interface doesn't let us guard 
438
 
        # against operations there taking a long time.
439
 
        deadline = time.time() + timeout
440
 
        while True:
441
 
            if self.peek():
442
 
                return
443
 
            if time.time() + poll < deadline:
444
 
                time.sleep(poll)
445
 
            else:
446
 
                raise LockContention(self)
447
 
 
448
592
    def _format_lock_info(self, info):
449
593
        """Turn the contents of peek() into something for the user"""
450
594
        lock_url = self.transport.abspath(self.path)
455
599
            'locked %s' % (format_delta(delta),),
456
600
            ]
457
601
 
 
602
    def validate_token(self, token):
 
603
        if token is not None:
 
604
            info = self.peek()
 
605
            if info is None:
 
606
                # Lock isn't held
 
607
                lock_token = None
 
608
            else:
 
609
                lock_token = info.get('nonce')
 
610
            if token != lock_token:
 
611
                raise errors.TokenMismatch(token, lock_token)
 
612
            else:
 
613
                self._trace("revalidated by token %r", token)
 
614
 
 
615
    def _trace(self, format, *args):
 
616
        if 'lock' not in debug.debug_flags:
 
617
            return
 
618
        mutter(str(self) + ": " + (format % args))