Merge pull request #304 from tloncorp/mp/lure-logs

logs: improve Lure tracing

desk/app/bait.hoon

@@ -116,22 +116,47 @@
     ::
         %'POST'
       ?~  body.request
-        :-  (tell:log ~ %crit 'body not found' ~)
-        (give-not-found 'body not found')
+        :_  (give-not-found 'body not found')
+        %^  tell:log  %crit
+          ~['POST body not found']
+        ~['event'^s+'Lure POST Fail' 'flow'^s+'lure']
       ?.  =('ship=%7E' (end [3 8] q.u.body.request))
-        :-  (tell:log ~ %crit 'ship not found in body' ~)
-        (give-not-found 'ship not found in body')
-      =/  joiner  (slav %p (cat 3 '~' (rsh [3 8] q.u.body.request)))
-      =;  [=bite:reel inviter=(unit ship)]
+        :_  (give-not-found 'ship not found in body')
+        %^  tell:log  %crit
+          ~['ship not found in POST body']
+        ~['event'^s+'Lure POST Fail' 'flow'^s+'lure']
+      =/  joiner=@p  (slav %p (cat 3 '~' (rsh [3 8] q.u.body.request)))
+      ::
+      =/  token
+        ?~  ext.full-line  i.line
+        (crip "{(trip i.line)}.{(trip u.ext.full-line)}")
+      =>
+        |%
+        ++  lure-log
+          |=  [=volume:logs event=@t =echo:logs]
+          %^  tell:log  volume
+            echo
+          :~  'event'^s+event
+              'flow'^s+'lure'
+              'lure-id'^s+token
+              'lure-joiner'^s+(scot %p joiner)
+          ==
+        --
+      =;  [bite=(unit bite:reel) inviter=(unit ship)]
+        ?~  bite
+          :_  (give-not-found 'invite token not found')
+          %^  lure-log  %crit  'Invite Token Missing'
+          ~[leaf+"invite token {<token>} not found"]
         ?~  inviter
-          :-  (tell:log `token.bite %crit 'inviter not found' ~)
-          (give-not-found 'inviter not found')
+          :_  (give-not-found 'inviter not found')
+          %^  lure-log  %crit  'Inviter Not Found'
+          ~['inviter not found']
         ^-  (list card)
-        :*  %^  tell:log  `token.bite  %info
+        :*  %^  lure-log  %info  'Invite Redeemed'
             ~[leaf+"{<joiner>} redeemed lure invite from {<u.inviter>}"]
             ::
             :*  %pass  /bite  %agent  [u.inviter %reel]
-                %poke  %reel-bite  !>(bite)
+                %poke  %reel-bite  !>(u.bite)
             ==
           (give (manx-response:gen:server (sent-page joiner)))
         ==
@@ -140,16 +165,14 @@
         =/  inviter  (slav %p i.line)
         =/  old-token  i.t.line
         :_  `inviter
-        [%bite-1 old-token joiner inviter]
-      =/  token
-        ?~  ext.full-line  i.line
-        (crip "{(trip i.line)}.{(trip u.ext.full-line)}")
+        `[%bite-1 old-token joiner inviter]
       =/  =metadata:reel  (~(gut by token-metadata) token *metadata:reel)
       ?~  type=(~(get by fields.metadata) 'bite-type')
-        ~|("no bite type for token: {<token>}" !!)
+        [~ ~]
       ?>  =('2' u.type)
-      :-  [%bite-2 token joiner metadata]
-      ?~  inviter-field=(~(get by fields.metadata) 'inviter')  ~
+      :-  `[%bite-2 token joiner metadata]
+      ?~  inviter-field=(~(get by fields.metadata) 'inviter')
+        ~
       `(slav %p u.inviter-field)
     ==
     ++  get-request
@@ -227,5 +250,5 @@
   |=  [=term =tang]
   ^-  (quip card _this)
   :_  this
-  [(fail:log term tang)]~
+  [(fail:log term tang ~)]~
 --

desk/app/reel.hoon

@@ -158,14 +158,20 @@
     =+  !<(confirmation:reel vase)
     =.  open-describes  (~(del in open-describes) nonce)
     ?~  md=(~(get by our-metadata) nonce)
-      ~|("no metadata for nonce: {<nonce>}" !!)
+      :_  this  :_  ~
+      %^  tell:log  %crit
+        ~[leaf+"failed to receive metadata for nonce {<nonce>}"]
+      ~['event'^s+'Invite Creation Failed' 'flow'^s+'lure']
     =/  ids=(list [id=cord =token:reel])
       %+  skim
         ~(tap by stable-id)
       |=  [key=cord =token:reel]
       =(nonce token)
     ?~  ids
-      ~|("no stable id for nonce: {<nonce>}" !!)
+      :_  this  :_  ~
+      %^  tell:log  %crit
+        ~[leaf+"no stable id found for nonce {<nonce>}"]
+      ~['event'^s+'Invite Creation Failed' 'flow'^s+'lure']
     =*  id  -<.ids
     ::  update the token the id points to
     =.  stable-id  (~(put by stable-id) id token)
@@ -175,14 +181,19 @@
     :_  this
     =/  url  (cat 3 vic token)
     =/  path  (stab (cat 3 '/v1/id-link/' id))
-    :-  (tell:log `token %info 'lure link generated' ~)
+    :-  %^  tell:log  %info
+          ~[leaf+"invite link for {(trip id)} created"]
+        ~['event'^s+'Invite Link Created' 'flow'^s+'lure' 'lure-id'^s+token]
     ~[[%give %fact ~[path] %json !>(s+url)]]
   ::
       %reel-undescribe
     ?>  =(our.bowl src.bowl)
     =+  !<(=token:reel vase)
     ::  the token here should be the actual token given to us by the provider
     :_  this(our-metadata (~(del by our-metadata) token))
+    :-  %^  tell:log  %info
+          ~[leaf+"invite link removed"]
+        ~['event'^s+'Invite Link Removed' 'flow'^s+'lure' 'lure-id'^s+token]
     ~[[%pass /undescribe %agent [civ %bait] %poke %bait-undescribe !>(token)]]
   ::  old pokes for getting links, we no longer use these because all links
   ::  are unique to that ship/user and can be scried out
@@ -301,7 +312,7 @@
     ?>  ?=([%khan %arow *] sign-arvo)
     ?:  ?=(%.n -.p.sign-arvo)
       :_  this
-      ~[(tell:log ~ %warn 'fetch bait ship failed' ~)]
+      ~[(tell:log %warn ~['fetch bait ship failed'] ~)]
     `this
   ::
       [%expire @ @ ~]
@@ -320,5 +331,5 @@
   |=  [=term =tang]
   ^-  (quip card _this)
   :_  this
-  [(fail:log term tang)]~
+  [(fail:log term tang ~)]~
 --

desk/lib/logs.hoon

@@ -3,23 +3,23 @@
   |_  [our=ship =wire]
   ::
   ++  fail
-    |=  [desc=term trace=tang]
+    |=  [desc=term trace=tang =log-data]
     ^-  card:agent:gall
     =/  event=$>(%fail log-event)
       [%fail desc trace]
-    (pass event)
+    (pass event log-data)
   ::
   ++  tell
-    |=  [id=(unit @ta) vol=volume =echo]
+    |=  [vol=volume =echo =log-data]
     ^-  card:agent:gall
     =/  event=$>(%tell log-event)
-      [%tell id vol echo]
-    (pass event)
+      [%tell vol echo]
+    (pass event log-data)
   ::
   ++  pass
-    |=  event=log-event
+    |=  [event=log-event data=log-data]
     ^-  card:agent:gall
-    [%pass wire %agent [our %logs] %poke log-action+!>([%log event])]
+    [%pass wire %agent [our %logs] %poke log-action+!>([%log event data])]
   --
 |%
 ::
@@ -29,9 +29,9 @@
   [%fail term tang]
 ::
 ++  tell-event
-  |=  [id=(unit @ta) vol=volume =echo]
+  |=  [vol=volume =echo]
   ^-  $>(%tell log-event)
-  [%tell id vol echo]
+  [%tell vol echo]
 ::
 ++  enjs
   =,  format
@@ -62,10 +62,6 @@
         %tell
       =-  ?>(?=(%o -.-) -)
       %-  pairs:enjs
-      ::
-      ::  insert tell id if present
-      =-  ?~  id.e  -
-          [id/s+u.id.e -]
       :~  type/s+event-type
           message/(tang echo.e)
           volume/s+vol.e

desk/sur/logs.hoon

@@ -12,13 +12,14 @@
 ::
 +$  log-event
   $%  [%fail desc=term trace=tang]
-      [%tell id=(unit @ta) vol=volume =echo]
+      [%tell vol=volume =echo]
   ==
-::
 ::  $log-item: event with timestamp
 +$  log-item  [=time event=log-event]
+::  $log-data: supplemental data
++$  log-data  (list (pair @t json))
 ::
 +$  a-log
-  $%  [%log log-event]
+  $%  [%log log-event data=log-data]
   ==
 --