logging: add 'unique-message-ids' (or 'umids') to each WEIRD-or-higher log.msg call...

diff --git a/src/allmydata/client.py b/src/allmydata/client.py
index e8f5e57b15082fcc19759ba2fa8d134554cd5c6c..87f498334438f1503ffba5f7e14002029b83a45a 100644 (file)
--- a/src/allmydata/client.py
+++ b/src/allmydata/client.py
@@ -111,7 +111,8 @@ class Client(node.Node, testutil.PollMixin):
             # nodes that want to upload and download will need storage servers
             ic.subscribe_to("storage")
         d.addCallback(_start_introducer_client)
-        d.addErrback(log.err, facility="tahoe.init", level=log.BAD)
+        d.addErrback(log.err, facility="tahoe.init",
+                     level=log.BAD, umid="URyI5w")
 
     def init_stats_provider(self):
         gatherer_furl = self.get_config('stats_gatherer.furl')
@@ -165,7 +166,8 @@ class Client(node.Node, testutil.PollMixin):
             ri_name = RIStorageServer.__remote_name__
             self.introducer_client.publish(furl, "storage", ri_name)
         d.addCallback(_publish)
-        d.addErrback(log.err, facility="tahoe.init", level=log.BAD)
+        d.addErrback(log.err, facility="tahoe.init",
+                     level=log.BAD, umid="aLGBKw")
 
     def init_client(self):
         helper_furl = self.get_config("helper.furl")
@@ -185,7 +187,8 @@ class Client(node.Node, testutil.PollMixin):
             self.introducer_client.publish(furl, "stub_client", ri_name)
         d = self.when_tub_ready()
         d.addCallback(_publish)
-        d.addErrback(log.err, facility="tahoe.init", level=log.BAD)
+        d.addErrback(log.err, facility="tahoe.init",
+                     level=log.BAD, umid="OEHq3g")
 
     def init_control(self):
         d = self.when_tub_ready()
@@ -195,7 +198,8 @@ class Client(node.Node, testutil.PollMixin):
             control_url = self.tub.registerReference(c)
             self.write_private_config("control.furl", control_url + "\n")
         d.addCallback(_publish)
-        d.addErrback(log.err, facility="tahoe.init", level=log.BAD)
+        d.addErrback(log.err, facility="tahoe.init",
+                     level=log.BAD, umid="d3tNXA")
 
     def init_helper(self):
         d = self.when_tub_ready()
@@ -211,14 +215,16 @@ class Client(node.Node, testutil.PollMixin):
                                            "private", "helper.furl")
             self.tub.registerReference(h, furlFile=helper_furlfile)
         d.addCallback(_publish)
-        d.addErrback(log.err, facility="tahoe.init", level=log.BAD)
+        d.addErrback(log.err, facility="tahoe.init",
+                     level=log.BAD, umid="K0mW5w")
 
     def init_key_gen(self, key_gen_furl):
         d = self.when_tub_ready()
         def _subscribe(self):
             self.tub.connectTo(key_gen_furl, self._got_key_generator)
         d.addCallback(_subscribe)
-        d.addErrback(log.err, facility="tahoe.init", level=log.BAD)
+        d.addErrback(log.err, facility="tahoe.init",
+                     level=log.BAD, umid="z9DMzw")
 
     def _got_key_generator(self, key_generator):
         self._key_generator = key_generator

diff --git a/src/allmydata/immutable/download.py b/src/allmydata/immutable/download.py
index c719739b71f8d354059320c1ba309406d5a3cfe5..52decdfc3d5671a31d245077877c8d0e16090261 100644 (file)
--- a/src/allmydata/immutable/download.py
+++ b/src/allmydata/immutable/download.py
@@ -121,7 +121,8 @@ class Output:
             # download, not so scary
             self.log("download stopped", level=log.UNUSUAL)
         else:
-            self.log("download failed!", failure=why, level=log.SCARY)
+            self.log("download failed!", failure=why,
+                     level=log.SCARY, umid="lp1vaQ")
         self.downloadable.fail(why)
 
     def close(self):
@@ -293,7 +294,7 @@ class BlockDownloader:
         if f.check(DeadReferenceError):
             level = log.UNUSUAL
         self.log("BlockDownloader[%d] got error" % self.blocknum,
-                 failure=f, level=level, parent=lognum)
+                 failure=f, level=level, parent=lognum, umid="5Z4uHQ")
         if self.results:
             peerid = self.vbucket.bucket.get_peerid()
             self.results.server_problems[peerid] = str(f)
@@ -595,7 +596,8 @@ class FileDownloader:
         level = log.WEIRD
         if f.check(DeadReferenceError):
             level = log.UNUSUAL
-        self._client.log("Error during get_buckets", failure=f, level=level)
+        self._client.log("Error during get_buckets", failure=f, level=level,
+                         umid="3uuBUQ")
 
     def bucket_failed(self, vbucket):
         shnum = vbucket.sharenum
@@ -643,7 +645,7 @@ class FileDownloader:
                        (bucket,
                         base32.b2a(self._uri_extension_hash),
                         base32.b2a(h)))
-                self.log(msg, level=log.SCARY)
+                self.log(msg, level=log.SCARY, umid="jnkTtQ")
                 raise BadURIExtensionHashValue(msg)
             return self._unpack_uri_extension_data(proposal)
         return self._obtain_validated_thing(None,
@@ -668,7 +670,7 @@ class FileDownloader:
                 level = log.UNUSUAL
             self.log(format="operation %(op)s from vbucket %(vbucket)s failed",
                      op=name, vbucket=str(bucket),
-                     failure=f, level=level)
+                     failure=f, level=level, umid="JGXxBA")
             if not sources:
                 raise NotEnoughSharesError("ran out of peers, last error was %s"
                                           % (f,))

diff --git a/src/allmydata/immutable/encode.py b/src/allmydata/immutable/encode.py
index 766292fee4baef022ea9f654580f0d6279b28298..1982567c3a0557c4e0d8f98e5d3715691c8b956c 100644 (file)
--- a/src/allmydata/immutable/encode.py
+++ b/src/allmydata/immutable/encode.py
@@ -404,7 +404,8 @@ class Encoder(object):
                 # non-tail segments should be the full segment size
                 if length != input_chunk_size:
                     log.msg("non-tail segment should be full segment size: %d!=%d"
-                            % (length, input_chunk_size), level=log.BAD)
+                            % (length, input_chunk_size),
+                            level=log.BAD, umid="jNk5Yw")
                 precondition(length == input_chunk_size,
                              "length=%d != input_chunk_size=%d" %
                              (length, input_chunk_size))
@@ -486,7 +487,7 @@ class Encoder(object):
         else:
             # even more UNUSUAL
             self.log("they weren't in our list of landlords", parent=ln,
-                     level=log.WEIRD)
+                     level=log.WEIRD, umid="TQGFRw")
         if len(self.landlords) < self.shares_of_happiness:
             msg = "lost too many shareholders during upload: %s" % why
             raise NotEnoughSharesError(msg)

diff --git a/src/allmydata/introducer/client.py b/src/allmydata/introducer/client.py
index 59a7434129b368478851abaad945522455cf2678..bc7d5fd3fe3ef19b976d0923b7042d3080ef15fb 100644 (file)
--- a/src/allmydata/introducer/client.py
+++ b/src/allmydata/introducer/client.py
@@ -123,7 +123,7 @@ class IntroducerClient(service.Service, Referenceable):
         self._introducer_reconnector = rc
         def connect_failed(failure):
             self.log("Initial Introducer connection failed: perhaps it's down",
-                     level=log.WEIRD, failure=failure)
+                     level=log.WEIRD, failure=failure, umid="c5MqUQ")
         d = self._tub.getReference(self.introducer_furl)
         d.addErrback(connect_failed)
 
@@ -175,7 +175,7 @@ class IntroducerClient(service.Service, Referenceable):
                 self._subscriptions.add(service_name)
                 d = self._publisher.callRemote("subscribe", self, service_name)
                 d.addErrback(log.err, facility="tahoe.introducer",
-                             level=log.WEIRD)
+                             level=log.WEIRD, umid="2uMScQ")
 
     def _maybe_publish(self):
         if not self._publisher:
@@ -185,7 +185,7 @@ class IntroducerClient(service.Service, Referenceable):
         for ann in self._published_announcements:
             d = self._publisher.callRemote("publish", ann)
             d.addErrback(log.err, facility="tahoe.introducer",
-                         level=log.WEIRD)
+                         level=log.WEIRD, umid="xs9pVQ")
 
 
 
@@ -195,7 +195,7 @@ class IntroducerClient(service.Service, Referenceable):
             (furl, service_name, ri_name, nickname, ver, oldest) = ann
             if service_name not in self._subscribed_service_names:
                 self.log("announcement for a service we don't care about [%s]"
-                         % (service_name,), level=log.WEIRD)
+                         % (service_name,), level=log.UNUSUAL, umid="dIpGNA")
                 continue
             if ann in self._received_announcements:
                 self.log("ignoring old announcement: %s" % (ann,),

diff --git a/src/allmydata/introducer/server.py b/src/allmydata/introducer/server.py
index a6d028b84e884a25a88f34838ec2ab98365477f6..b0b9b652ffebbcf6b257e05a2d7cbcab570eec81 100644 (file)
--- a/src/allmydata/introducer/server.py
+++ b/src/allmydata/introducer/server.py
@@ -31,7 +31,8 @@ class IntroducerNode(node.Node):
             self.log(" introducer is at %s" % self.introducer_url)
             self.write_config("introducer.furl", self.introducer_url + "\n")
         d.addCallback(_publish)
-        d.addErrback(log.err, facility="tahoe.init", level=log.BAD)
+        d.addErrback(log.err, facility="tahoe.init",
+                     level=log.BAD, umid="UaNs9A")
 
     def init_web(self, webport):
         self.log("init_web(webport=%s)", args=(webport,))

diff --git a/src/allmydata/mutable/checker.py b/src/allmydata/mutable/checker.py
index 375a1fbc583f604c6347253b167b0a14a7769a51..ef4575230371c9c1b53b8a22cf9f230884243264 100644 (file)
--- a/src/allmydata/mutable/checker.py
+++ b/src/allmydata/mutable/checker.py
@@ -203,7 +203,7 @@ class MutableChecker:
                         si=base32.b2a(self._storage_index),
                         shnum=shnum,
                         where=ft,
-                        level=log.WEIRD)
+                        level=log.WEIRD, umid="EkK8QA")
 
         self.results.status_report = "\n".join(report) + "\n"
 

diff --git a/src/allmydata/mutable/publish.py b/src/allmydata/mutable/publish.py
index 22a496ad4a081a9f3c1b1712a864a6a4cc2edea0..04621559cbcca985de00c182f629e406a7fbfb26 100644 (file)
--- a/src/allmydata/mutable/publish.py
+++ b/src/allmydata/mutable/publish.py
@@ -665,7 +665,7 @@ class Publish:
         if surprise_shares:
             self.log("they had shares %s that we didn't know about" %
                      (list(surprise_shares),),
-                     parent=lp, level=log.WEIRD)
+                     parent=lp, level=log.WEIRD, umid="un9CSQ")
             self.surprised = True
 
         if not wrote:
@@ -685,7 +685,7 @@ class Publish:
             # bother adding to self.bad_peers .
 
             self.log("our testv failed, so the write did not happen",
-                     parent=lp, level=log.WEIRD)
+                     parent=lp, level=log.WEIRD, umid="8sc26g")
             self.surprised = True
             self.bad_peers.add(peerid) # don't ask them again
             # use the checkstring to add information to the log message
@@ -741,7 +741,8 @@ class Publish:
         self._status.timings["total"] = now - self._started
         self._status.set_active(False)
         if isinstance(res, failure.Failure):
-            self.log("Publish done, with failure", failure=res, level=log.WEIRD)
+            self.log("Publish done, with failure", failure=res,
+                     level=log.WEIRD, umid="nRsR9Q")
             self._status.set_status("Failed")
         elif self.surprised:
             self.log("Publish done, UncoordinatedWriteError", level=log.UNUSUAL)

diff --git a/src/allmydata/mutable/retrieve.py b/src/allmydata/mutable/retrieve.py
index 9000f42135913bffa0ffb64855b5c4e6728aab4f..ed4b907340ebdea3ebc569a61dc9f9efb5b8de4e 100644 (file)
--- a/src/allmydata/mutable/retrieve.py
+++ b/src/allmydata/mutable/retrieve.py
@@ -206,7 +206,7 @@ class Retrieve:
                      shnum=shnum,
                      peerid=idlib.shortnodeid_b2a(peerid),
                      failure=f,
-                     level=log.WEIRD)
+                     level=log.WEIRD, umid="W0xnQA")
         d.addErrback(_oops)
         d.addBoth(self._check_for_done)
         # any error during _check_for_done means the download fails. If the
@@ -251,7 +251,8 @@ class Retrieve:
                 # log it and give the other shares a chance to be processed
                 f = failure.Failure()
                 self.log(format="bad share: %(f_value)s",
-                         f_value=str(f.value), failure=f, level=log.WEIRD)
+                         f_value=str(f.value), failure=f,
+                         level=log.WEIRD, umid="7fzWZw")
                 self.remove_peer(peerid)
                 self.servermap.mark_bad_share(peerid, shnum, prefix)
                 self._bad_shares.add( (peerid, shnum) )
@@ -309,7 +310,7 @@ class Retrieve:
         if f.check(DeadReferenceError):
             level = log.UNUSUAL
         self.log(format="error during query: %(f_value)s",
-                 f_value=str(f.value), failure=f, level=level)
+                 f_value=str(f.value), failure=f, level=level, umid="gOJB5g")
 
     def _check_for_done(self, res):
         # exit paths:
@@ -411,14 +412,14 @@ class Retrieve:
                     "bad": len(self._bad_shares),
                     }
             self.log(format=format,
-                     level=log.WEIRD, **args)
+                     level=log.WEIRD, umid="ezTfjw", **args)
             err = NotEnoughSharesError("%s, last failure: %s" %
                                       (format % args, self._last_failure))
             if self._bad_shares:
                 self.log("We found some bad shares this pass. You should "
                          "update the servermap and try again to check "
                          "more peers",
-                         level=log.WEIRD)
+                         level=log.WEIRD, umid="EFkOlA")
                 err.servermap = self.servermap
             raise err
 

diff --git a/src/allmydata/mutable/servermap.py b/src/allmydata/mutable/servermap.py
index 69b75b3e10f85df16118da0caa763bd46b5901b3..4ec40cc699a3aff05b3e2ad1b766ccdad4e6dc6f 100644 (file)
--- a/src/allmydata/mutable/servermap.py
+++ b/src/allmydata/mutable/servermap.py
@@ -540,7 +540,7 @@ class ServermapUpdater:
                 # log it and give the other shares a chance to be processed
                 f = failure.Failure()
                 self.log(format="bad share: %(f_value)s", f_value=str(f.value),
-                         failure=f, parent=lp, level=log.WEIRD)
+                         failure=f, parent=lp, level=log.WEIRD, umid="h5llHg")
                 self._bad_peers.add(peerid)
                 self._last_failure = f
                 checkstring = data[:SIGNED_PREFIX_LENGTH]
@@ -676,7 +676,7 @@ class ServermapUpdater:
         if alleged_writekey != self._node.get_writekey():
             self.log("invalid privkey from %s shnum %d" %
                      (idlib.nodeid_b2a(peerid)[:8], shnum),
-                     parent=lp, level=log.WEIRD)
+                     parent=lp, level=log.WEIRD, umid="aJVccw")
             return
 
         # it's good
@@ -692,7 +692,8 @@ class ServermapUpdater:
 
     def _query_failed(self, f, peerid):
         self.log(format="error during query: %(f_value)s",
-                 f_value=str(f.value), failure=f, level=log.WEIRD)
+                 f_value=str(f.value), failure=f,
+                 level=log.WEIRD, umid="IHXuQg")
         if not self._running:
             return
         self._must_query.discard(peerid)
@@ -711,7 +712,8 @@ class ServermapUpdater:
         if not self._need_privkey:
             return
         if shnum not in datavs:
-            self.log("privkey wasn't there when we asked it", level=log.WEIRD)
+            self.log("privkey wasn't there when we asked it",
+                     level=log.WEIRD, umid="VA9uDQ")
             return
         datav = datavs[shnum]
         enc_privkey = datav[0]
@@ -721,7 +723,7 @@ class ServermapUpdater:
         self._queries_outstanding.discard(peerid)
         self.log(format="error during privkey query: %(f_value)s",
                  f_value=str(f.value), failure=f,
-                 parent=lp, level=log.WEIRD)
+                 parent=lp, level=log.WEIRD, umid="McoJ5w")
         if not self._running:
             return
         self._queries_outstanding.discard(peerid)
@@ -942,7 +944,7 @@ class ServermapUpdater:
         eventually(self._done_deferred.callback, self._servermap)
 
     def _fatal_error(self, f):
-        self.log("fatal error", failure=f, level=log.WEIRD)
+        self.log("fatal error", failure=f, level=log.WEIRD, umid="1cNvlw")
         self._done_deferred.errback(f)
 
 

diff --git a/src/allmydata/offloaded.py b/src/allmydata/offloaded.py
index 06a5345b2d44df01c13eaa4810ebe5711bff7118..8ed82e2684f2762a33c0b51f578f16d683633b0d 100644 (file)
--- a/src/allmydata/offloaded.py
+++ b/src/allmydata/offloaded.py
@@ -101,7 +101,7 @@ class CHKCheckerAndUEBFetcher:
     def _ueb_error(self, f):
         # an error means the file is unavailable, but the overall check
         # shouldn't fail.
-        self.log("UEB fetch failed", failure=f, level=log.WEIRD)
+        self.log("UEB fetch failed", failure=f, level=log.WEIRD, umid="sJLKVg")
         return None
 
     def _done(self, res):
@@ -598,7 +598,7 @@ class Helper(Referenceable, service.MultiService):
         d.addCallback(_checked)
         def _err(f):
             self.log("error while checking for chk-already-in-grid",
-                     failure=f, level=log.WEIRD, parent=lp)
+                     failure=f, level=log.WEIRD, parent=lp, umid="jDtxZg")
             return f
         d.addErrback(_err)
         return d

diff --git a/src/allmydata/storage.py b/src/allmydata/storage.py
index 72cbdaddb9882bf9353032a545dbb8512bbda9be..b2e9685b55be30e65465044ac27d063ebcda5e72 100644 (file)
--- a/src/allmydata/storage.py
+++ b/src/allmydata/storage.py
@@ -694,7 +694,7 @@ class MutableShareFile:
             self.log(format="bad write enabler on SI %(si)s,"
                      " recorded by nodeid %(nodeid)s",
                      facility="tahoe.storage",
-                     level=log.WEIRD,
+                     level=log.WEIRD, umid="cE1eBQ",
                      si=si_s, nodeid=idlib.nodeid_b2a(write_enabler_nodeid))
             msg = "The write enabler was recorded by nodeid '%s'." % \
                   (idlib.nodeid_b2a(write_enabler_nodeid),)

diff --git a/src/allmydata/web/root.py b/src/allmydata/web/root.py
index 7326a17f9f57bd7421cfc90dc2445d2aed160596..c5057f48e40fa98f6d7cb7d18c5807693181f97e 100644 (file)
--- a/src/allmydata/web/root.py
+++ b/src/allmydata/web/root.py
@@ -109,7 +109,7 @@ class IncidentReporter(RenderMixin, rend.Page):
         req = IRequest(ctx)
         log.msg(format="User reports incident through web page: %(details)s",
                 details=get_arg(req, "details", ""),
-                level=log.WEIRD)
+                level=log.WEIRD, umid="LkD9Pw")
         req.setHeader("content-type", "text/plain")
         return "Thank you for your report!"