From a03be0e6f9624d1445570217774e21971e3bf41e Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 12:43:03 -0500 Subject: [PATCH 01/25] verb added --- pkg/arvo/sys/vane/eyre.hoon | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 24354a128..063dee96b 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -2,6 +2,7 @@ :: lighter than eyre :: |= our=ship +=/ verb=@ 1 =, eyre :: internal data structures :: @@ -2168,6 +2169,11 @@ |= [channel-id=@t request-id=@ud =ship app=term] ^- wire (weld (channel-wire channel-id request-id) /(scot %p ship)/[app]) +:: +++ trace + |= [pri=@ print=(trap tape)] + ?: (lth verb pri) same + (slog leaf+"eyre: {(print)}" ~) -- :: end the =~ :: From 54d655aedaac61a5a80bc560b58107138444a58e Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 13:44:09 -0500 Subject: [PATCH 02/25] all ~& replaced with trace calls --- pkg/arvo/sys/vane/eyre.hoon | 28 ++++++++++++++-------------- 1 file changed, 14 insertions(+), 14 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 063dee96b..5bba29d22 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -1124,7 +1124,7 @@ :: POST methods are used solely for deleting channels (on-put-request channel-id request) :: - ~& %session-not-a-put + %- (trace 1 |.("session-not-a-put")) [~ state] :: +on-cancel-request: cancels an ongoing subscription :: @@ -1466,7 +1466,8 @@ :: the client sent us a weird request referring to a subscription :: which isn't active. :: - ~& [%missing-subscription-in-unsubscribe channel-id subscription-id] + =* msg=tape "{} {}" + %- (trace 1 |.("missing-subscription-in-unsubscribe {msg}")) $(requests t.requests) :: =. gall-moves @@ -1604,14 +1605,14 @@ =/ num=@ud (~(gut by unacked.u.channel) request-id 0) :_ (~(put by unacked.u.channel) request-id +(num)) - ?& (gte num clog-threshold) - (lth (add last-ack.u.channel clog-timeout) now) - == - ~? clogged [%e %clogged channel-id request-id] + ?: ?& (gte num clog-threshold) + (lth (add last-ack.u.channel clog-timeout) now) + == + ((trace 1 |.("eyre: clogged {} {}")) &) | :: if we're clogged, or we ran into an event we can't serialize, :: kill this gall subscription. :: - =* kicking |(clogged ?=(~ json)) + =/ kicking=? |(clogged ?=(~ json)) =? moves kicking :_ moves ::NOTE this shouldn't crash because we @@ -1876,7 +1877,7 @@ :: verify that this is a valid response on the duct :: ?~ connection-state=(~(get by connections.state) duct) - ~& [%invalid-outstanding-connection duct] + %- (trace 1 |.("invalid-outstanding-connection {}")) [~ state] :: |^ ^- [(list move) server-state] @@ -1885,7 +1886,7 @@ :: %start ?^ response-header.u.connection-state - ~& [%http-multiple-start duct] + %- (trace 1 |.("http-multiple-start {}")) error-connection :: if request was authenticated, extend the session & cookie's life :: @@ -1900,7 +1901,7 @@ ?~ session-id=(session-id-from-request request.inbound) :: cookies are the only auth method, so this is unexpected :: - ~& [%e %authenticated-without-cookie] + %- (trace 1 |.("authenticated-without-cookie")) no-op ?. (~(has by sessions) u.session-id) :: if the session has expired since the request was opened, @@ -1946,7 +1947,7 @@ :: %continue ?~ response-header.u.connection-state - ~& [%http-continue-without-start duct] + %- (trace 1 |.("http-continue-without-start {}")) error-connection :: =. connections.state @@ -2533,7 +2534,7 @@ =* extra-wire t.t.t.t.wire =/ on-gall-response on-gall-response:by-channel:(per-server-event event-args) - :: ~& [%gall-response sign] + %- (trace 1 |.("gall-response for {}")) :: TODO other info might be more useful here =^ moves server-state.ax %- on-gall-response [channel-id (slav %ud request-id) extra-wire p.sign] @@ -2625,8 +2626,7 @@ ?. =(our who) ?. =([%da now] p.lot) [~ ~] - ~& [%r %scry-foreign-host who] - ~ + ((trace 1 |.("%r %scry-foreign-host {}")) ~) ?: &(?=(%x ren) ?=(~ syd)) =, server-state.ax ?+ tyl [~ ~] From c377008f62e022b3a4ca8b335b74fc67f0b1c833 Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 13:47:43 -0500 Subject: [PATCH 03/25] fixed kick messages --- pkg/arvo/sys/vane/eyre.hoon | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 5bba29d22..3963f6245 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -1605,14 +1605,17 @@ =/ num=@ud (~(gut by unacked.u.channel) request-id 0) :_ (~(put by unacked.u.channel) request-id +(num)) - ?: ?& (gte num clog-threshold) - (lth (add last-ack.u.channel clog-timeout) now) - == - ((trace 1 |.("eyre: clogged {} {}")) &) | + ?& (gte num clog-threshold) + (lth (add last-ack.u.channel clog-timeout) now) + == :: if we're clogged, or we ran into an event we can't serialize, :: kill this gall subscription. :: - =/ kicking=? |(clogged ?=(~ json)) + =/ kicking=? + ?: clogged + ((trace 1 |.("clogged {} {}")) &) + ?: ?=(~ json) + ((trace 1 |.("can't serialize event, kicking")) &) | =? moves kicking :_ moves ::NOTE this shouldn't crash because we From 69f7fc40c367f35c22b49e7390c0238601a41be0 Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 14:15:55 -0500 Subject: [PATCH 04/25] slog calls replaced with trace --- pkg/arvo/sys/vane/eyre.hoon | 33 +++++++++++++++------------------ 1 file changed, 15 insertions(+), 18 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 3963f6245..ad382debb 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -1136,10 +1136,9 @@ :: lookup the session id by duct :: ?~ maybe-channel-id=(~(get by duct-to-key.channel-state.state) duct) - ~> %slog.[0 leaf+"eyre: no channel to cancel {}"] - [~ state] + ((trace 0 |.("no channel to cancel {}")) `state) :: - ~> %slog.[0 leaf+"eyre: canceling {}"] + %- (trace 0 |.("canceling {}")) :: =/ maybe-session (~(get by session.channel-state.state) u.maybe-channel-id) @@ -1517,10 +1516,9 @@ (emit-event channel-id request-id sign) =/ =ship (slav %p i.extra) =* app=term i.t.extra - =/ =tape - %+ weld "eyre: removing watch for " - "non-existent channel {(trip channel-id)} on {(trip app)}" - %- (slog leaf+tape ~) + =* msg=tape + "removing watch for non-existent channel {} {}" + %- (trace 0 |.(msg)) :_ state :_ ~ ^- move @@ -1672,11 +1670,11 @@ ^- (unit desk) =/ sub (~(get by subscriptions.channel) request-id) ?~ sub - ((slog leaf+"eyre: no subscription for request-id {}" ~) ~) + ((trace 0 |.("no subscription for request-id {}")) ~) =/ des=(unit (unit cage)) (rof ~ %gd [our app.u.sub da+now] ~) ?. ?=([~ ~ *] des) - ((slog leaf+"eyre: no desk for app {(trip app.u.sub)}" ~) ~) + ((trace 0 |.("no desk for app {(trip app.u.sub)}")) ~) `!<(=desk q.u.u.des) :: +channel-event-to-sign: attempt to recover a sign from a channel-event :: @@ -1693,11 +1691,11 @@ =/ val=(unit (unit cage)) (rof ~ %cb [our u.des da+now] /[have]) ?. ?=([~ ~ *] val) - ((slog leaf+"eyre: no mark {(trip have)}" ~) ~) + ((trace 0 |.("no mark {(trip have)}")) ~) =+ !<(=dais:clay q.u.u.val) =/ res (mule |.((vale:dais noun.event))) ?: ?=(%| -.res) - ((slog leaf+"eyre: stale fact of mark {(trip have)}" ~) ~) + ((trace 0 |.("stale fact of mark {(trip have)}")) ~) `[%fact have p.res] :: +sign-to-json: render sign from request-id as json channel event :: @@ -1723,7 +1721,7 @@ ?. ?=([~ ~ *] cag) ~ `q.u.u.cag ?~ convert - ((slog leaf+"eyre: no convert {desc}" ~) [~ ~]) + ((trace 0 |.("no convert {desc}")) [~ ~]) ~| "conversion failed {desc}" [`[u.des have] `[%fact %json (slym u.convert q.q.cage.sign)]] ?~ jsyn ~ @@ -2152,8 +2150,8 @@ :: replace already bound paths :: ?: =([site path]:bid [site path]:binding.new) - ~> %slog.[0 leaf+"eyre: replacing existing binding at {<`path`path.bid>}"] - [new t.bindings] + %. [new t.bindings] + (trace 0 |.("replacing existing binding at {<`path`path.bid>}")) :: if new comes before bid, prepend it. :: otherwise, continue our search. :: @@ -2238,8 +2236,7 @@ ?: =(~ inactive) [~ http-server-gate] :: - =/ len=tape (scow %ud (lent inactive)) - ~> %slog.[0 leaf+"eyre: trim: closing {len} inactive channels"] + %- (trace 0 |.("trim: closing {<(lent inactive)>} inactive channels")) :: =| moves=(list (list move)) |- ^- [(list move) _http-server-gate] @@ -2292,7 +2289,7 @@ == :: ?: ?=(%code-changed -.task) - ~> %slog.[0 leaf+"eyre: code-changed: throwing away cookies and sessions"] + %- (trace 0 |.("code-changed: throwing away cookies and sessions")) =. authentication-state.server-state.ax *authentication-state :: =/ event-args [[eny duct now rof] server-state.ax] @@ -2580,7 +2577,7 @@ [~ http-server-gate] :: received a negative acknowledgment: XX do something :: - [((slog u.p.p.sign) ~) http-server-gate] + ((trace 0 |.("{}")) `http-server-gate) :: TODO this should be better -- :: ++ http-server-gate ..$ From e00e959100916cefb6ba8c0fc10aa81e667743a0 Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 14:43:13 -0500 Subject: [PATCH 05/25] trace moved into +per-server-event --- pkg/arvo/sys/vane/eyre.hoon | 14 ++++++++------ 1 file changed, 8 insertions(+), 6 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index ad382debb..fdfc9fd6a 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -2,7 +2,6 @@ :: lighter than eyre :: |= our=ship -=/ verb=@ 1 =, eyre :: internal data structures :: @@ -113,6 +112,9 @@ :: outgoing-duct: to unix :: outgoing-duct=duct + :: veb: verbosity + :: + veb=_1 :: TODO @ == :: channel-request: an action requested on a channel :: @@ -2098,6 +2100,11 @@ (cury cat 3) ?~ ext.request-line '' (cat 3 '.' u.ext.request-line) + :: + ++ trace + |= [pri=@ print=(trap tape)] + ?: (lth veb.state pri) same + (slog leaf+"eyre: {(print)}" ~) -- :: ++ forwarded-params @@ -2171,11 +2178,6 @@ |= [channel-id=@t request-id=@ud =ship app=term] ^- wire (weld (channel-wire channel-id request-id) /(scot %p ship)/[app]) -:: -++ trace - |= [pri=@ print=(trap tape)] - ?: (lth verb pri) same - (slog leaf+"eyre: {(print)}" ~) -- :: end the =~ :: From 318e001c28342bf2e225c693cbbd6b8d9ee71a43 Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 14:46:05 -0500 Subject: [PATCH 06/25] trace removed from main core --- pkg/arvo/sys/vane/eyre.hoon | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index fdfc9fd6a..b4617efa6 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -2238,7 +2238,8 @@ ?: =(~ inactive) [~ http-server-gate] :: - %- (trace 0 |.("trim: closing {<(lent inactive)>} inactive channels")) + =/ len=tape (scow %ud (lent inactive)) + ~> %slog.[0 leaf+"eyre: trim: closing {len} inactive channels"] :: =| moves=(list (list move)) |- ^- [(list move) _http-server-gate] @@ -2291,7 +2292,7 @@ == :: ?: ?=(%code-changed -.task) - %- (trace 0 |.("code-changed: throwing away cookies and sessions")) + ~> %slog.[0 leaf+"eyre: code-changed: throwing away cookies and sessions"] =. authentication-state.server-state.ax *authentication-state :: =/ event-args [[eny duct now rof] server-state.ax] @@ -2536,7 +2537,7 @@ =* extra-wire t.t.t.t.wire =/ on-gall-response on-gall-response:by-channel:(per-server-event event-args) - %- (trace 1 |.("gall-response for {}")) :: TODO other info might be more useful here + :: ~& [%gall-response sign] =^ moves server-state.ax %- on-gall-response [channel-id (slav %ud request-id) extra-wire p.sign] @@ -2579,7 +2580,7 @@ [~ http-server-gate] :: received a negative acknowledgment: XX do something :: - ((trace 0 |.("{}")) `http-server-gate) :: TODO this should be better + [((slog u.p.p.sign) ~) http-server-gate] -- :: ++ http-server-gate ..$ @@ -2628,7 +2629,8 @@ ?. =(our who) ?. =([%da now] p.lot) [~ ~] - ((trace 1 |.("%r %scry-foreign-host {}")) ~) + ~& [%r %scry-foreign-host who] + ~ ?: &(?=(%x ren) ?=(~ syd)) =, server-state.ax ?+ tyl [~ ~] From 46a9556f4b5abb1b6b42ed3996103b9ec3146f3b Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 14:47:54 -0500 Subject: [PATCH 07/25] +insert-binding reverted --- pkg/arvo/sys/vane/eyre.hoon | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index b4617efa6..fa37e4232 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -2157,8 +2157,8 @@ :: replace already bound paths :: ?: =([site path]:bid [site path]:binding.new) - %. [new t.bindings] - (trace 0 |.("replacing existing binding at {<`path`path.bid>}")) + ~> %slog.[0 leaf+"eyre: replacing existing binding at {<`path`path.bid>}"] + [new t.bindings] :: if new comes before bid, prepend it. :: otherwise, continue our search. :: From aedb261b7e7fa47396d1a7fb4d003ab72080c465 Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 15:10:16 -0500 Subject: [PATCH 08/25] +load properly migrates state --- pkg/arvo/sys/vane/eyre.hoon | 59 +++++++++++++++++++++++++++++-------- 1 file changed, 46 insertions(+), 13 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index fa37e4232..0e0ec56e8 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -67,12 +67,8 @@ :: more structures :: |% -++ axle - $: :: date: date at which http-server's state was updated to this data structure - :: - date=%~2020.10.18 - :: server-state: state of inbound requests - :: ++$ axle + $: %1 =server-state == :: +server-state: state relating to open inbound HTTP connections @@ -2587,15 +2583,52 @@ :: +load: migrate old state to new state (called on vane reload) :: ++ load - |= old=axle + => |% + +$ axle-any + $% [%~2020.10.18 =server-state-0] + [%1 =server-state] + == + +$ server-state-0 + $: bindings=(list [=binding =duct =action]) + =cors-registry + connections=(map duct outstanding-connection) + =authentication-state + =channel-state + domains=(set turf) + =http-config + ports=[insecure=@ud secure=(unit @ud)] + outgoing-duct=duct + == + -- + |= old=axle-any ^+ ..^$ - :: enable https redirects if certificate configured + ?- -.old + %~2020.10.18 + =, server-state-0.old + =/ new=axle + :* %1 + bindings + cors-registry + connections + authentication-state + channel-state + domains + http-config + ports + outgoing-duct + 0 + == + ..^$(ax new) :: - =. redirect.http-config.server-state.old - ?& ?=(^ secure.ports.server-state.old) - ?=(^ secure.http-config.server-state.old) - == - ..^$(ax old) + %1 + :: enable https redirects if certificate configured + :: + =. redirect.http-config.server-state.old + ?& ?=(^ secure.ports.server-state.old) + ?=(^ secure.http-config.server-state.old) + == + ..^$(ax old) + == :: +stay: produce current state :: ++ stay `axle`ax From c271ade94146cd9488833b4d578dc1eb9a2642ce Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 15:19:14 -0500 Subject: [PATCH 09/25] veb to verb --- pkg/arvo/sys/vane/eyre.hoon | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 0e0ec56e8..444d8cdb1 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -108,9 +108,9 @@ :: outgoing-duct: to unix :: outgoing-duct=duct - :: veb: verbosity + :: verb: verbosity :: - veb=_1 :: TODO @ + verb=@ == :: channel-request: an action requested on a channel :: @@ -2099,7 +2099,7 @@ :: ++ trace |= [pri=@ print=(trap tape)] - ?: (lth veb.state pri) same + ?: (lth verb.state pri) same (slog leaf+"eyre: {(print)}" ~) -- :: From 09017729bc105c59cdf17509d00371dfe4661c61 Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 15:20:07 -0500 Subject: [PATCH 10/25] eyre %spew added to toggle verbosity --- pkg/arvo/sys/lull.hoon | 3 +++ pkg/arvo/sys/vane/eyre.hoon | 4 ++++ 2 files changed, 7 insertions(+) diff --git a/pkg/arvo/sys/lull.hoon b/pkg/arvo/sys/lull.hoon index 9bca8c59b..8d3a7f0e6 100644 --- a/pkg/arvo/sys/lull.hoon +++ b/pkg/arvo/sys/lull.hoon @@ -1326,6 +1326,9 @@ :: start responding negatively to cors requests from origin :: [%reject-origin =origin] + :: %spew: set verbosity toggle + :: + [%spew veb=@] == :: +origin: request origin as specified in an Origin header :: diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 444d8cdb1..5c2859341 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -2399,6 +2399,10 @@ (~(del in approved) origin.task) (~(put in rejected) origin.task) [~ http-server-gate] + :: + %spew + =. verb.server-state.ax veb.task + `http-server-gate == :: ++ take From c59813e367a5cfc6971410d8982b1bc64b5f7262 Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 16:19:13 -0500 Subject: [PATCH 11/25] gall watch/leave traces added --- pkg/arvo/sys/vane/eyre.hoon | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 5c2859341..7907e4d52 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -813,6 +813,7 @@ :: ++ subscribe-to-app |= [app=term =inbound-request:eyre] + %- (trace 2 |.("subscribing to {} on {}")) ^- (list move) :~ :* duct %pass /watch-response/[eyre-id] %g %deal [our our] app @@ -842,6 +843,7 @@ %app :_ state :_ ~ + %- (trace 2 |.("leaving subscription to {}")) :* duct %pass /watch-response/[eyre-id] %g %deal [our our] app.action.u.connection %leave ~ @@ -1437,6 +1439,7 @@ ^- move :^ duct %pass (subscription-wire channel-id request-id ship app) + %- (trace 2 |.("subscribing to {} on {}")) :* %g %deal [our ship] app `task:agent:gall`[%watch path] == @@ -1473,6 +1476,7 @@ =, u.maybe-subscription :^ duc %pass (subscription-wire channel-id subscription-id.i.requests ship app) + %- (trace 2 |.("leaving subscription to {}")) :* %g %deal [our ship] app `task:agent:gall`[%leave ~] == @@ -1520,6 +1524,7 @@ :_ state :_ ~ ^- move + %- (trace 2 |.("leaving subscription to {}")) :^ duct %pass (subscription-wire channel-id request-id ship app) [%g %deal [our ship] app `task:agent:gall`[%leave ~]] @@ -1619,6 +1624,7 @@ :: - only clog on %facts, which have a subscription associated, :: - and already checked whether we still have that subscription. =+ (~(got by subscriptions.u.channel) request-id) + %- (trace 2 |.("leaving subscription to {}")) :^ duct %pass (subscription-wire channel-id request-id ship app) [%g %deal [our ship] app %leave ~] @@ -1834,6 +1840,7 @@ %+ turn ~(tap by subscriptions.session) |= [request-id=@ud ship=@p app=term =path duc=^duct] ^- move + %- (trace 2 |.("leaving subscription to {}")) :^ duc %pass (subscription-wire channel-id request-id ship app) [%g %deal [our ship] app %leave ~] @@ -1849,6 +1856,7 @@ ?. ?=(%app -.action.connection) ~ :_ ~ + %- (trace 2 |.("leaving subscription to {}")) :* duct %pass /watch-response/[eyre-id] %g %deal [our our] app.action.connection %leave ~ @@ -1994,6 +2002,8 @@ ?. ?=(%app -.action.u.connection-state) ~ :_ ~ + %- %+ trace 2 + |.("leaving subscription to {}") :* duct %pass /watch-response/[eyre-id] %g %deal [our our] app.action.u.connection-state %leave ~ From abdff98864c8d4c0a855b48972aec221c3edad17 Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 16:54:36 -0500 Subject: [PATCH 12/25] traces added for connections --- pkg/arvo/sys/vane/eyre.hoon | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 7907e4d52..f9745d7c4 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -583,6 +583,7 @@ [act [& secure address request] ~ 0] :: =. connections.state + %- (trace 2 |.("creating local connection {}}")) (~(put by connections.state) duct connection) :: :_ state @@ -612,6 +613,7 @@ =/ connection=outstanding-connection [action [authenticated secure address request] ~ 0] =. connections.state + %- (trace 2 |.("creating connection {}")) (~(put by connections.state) duct connection) :: redirect to https if insecure, redirects enabled :: and secure port live @@ -836,7 +838,9 @@ :: [~ state] :: - =. connections.state (~(del by connections.state) duct) + =. connections.state + %- (trace 2 |.("connection cancelled {}")) + (~(del by connections.state) duct) :: ?- -.action.u.connection %gen [~ state] @@ -1941,6 +1945,7 @@ :: =. response-header.http-event response-header =. connections.state + %- (trace 2 |.("creating connection {}")) %+ ~(put by connections.state) duct %_ connection response-header `response-header @@ -1958,6 +1963,7 @@ error-connection :: =. connections.state + %- (trace 2 |.("continuing connection {}}")) %+ ~(jab by connections.state) duct |= connection=outstanding-connection =+ size=?~(data.http-event 0 p.u.data.http-event) @@ -1984,6 +1990,7 @@ :: remove all outstanding state for this connection :: =. connections.state + %- (trace 2 |.("connection completed {}")) (~(del by connections.state) duct) state :: @@ -1993,6 +2000,7 @@ :: remove all outstanding state for this connection :: =. connections.state + %- (trace 2 |.("connection cancelled due to an error {}")) (~(del by connections.state) duct) :: respond to outside with %error :: From 738b1a562c03b3b634f23a924894c43c230d6c2c Mon Sep 17 00:00:00 2001 From: dachus Date: Wed, 8 Feb 2023 17:03:02 -0500 Subject: [PATCH 13/25] style fixes --- pkg/arvo/sys/vane/eyre.hoon | 41 ++++++++++++++++--------------------- 1 file changed, 18 insertions(+), 23 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index f9745d7c4..7e9c64c5f 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -583,8 +583,8 @@ [act [& secure address request] ~ 0] :: =. connections.state - %- (trace 2 |.("creating local connection {}}")) - (~(put by connections.state) duct connection) + %. (~(put by connections.state) duct connection) + (trace 2 |.("creating local connection {}}")) :: :_ state (subscribe-to-app app.act inbound-request.connection) @@ -613,8 +613,8 @@ =/ connection=outstanding-connection [action [authenticated secure address request] ~ 0] =. connections.state - %- (trace 2 |.("creating connection {}")) - (~(put by connections.state) duct connection) + %. (~(put by connections.state) duct connection) + (trace 2 |.("creating connection {}")) :: redirect to https if insecure, redirects enabled :: and secure port live :: @@ -839,8 +839,8 @@ [~ state] :: =. connections.state - %- (trace 2 |.("connection cancelled {}")) - (~(del by connections.state) duct) + %. (~(del by connections.state) duct) + (trace 2 |.("connection cancelled {}")) :: ?- -.action.u.connection %gen [~ state] @@ -1128,8 +1128,7 @@ :: POST methods are used solely for deleting channels (on-put-request channel-id request) :: - %- (trace 1 |.("session-not-a-put")) - [~ state] + ((trace 1 |.("session-not-a-put")) `state) :: +on-cancel-request: cancels an ongoing subscription :: :: One of our long lived sessions just got closed. We put the associated @@ -1471,8 +1470,8 @@ :: which isn't active. :: =* msg=tape "{} {}" - %- (trace 1 |.("missing-subscription-in-unsubscribe {msg}")) - $(requests t.requests) + %. $(requests t.requests) + (trace 1 |.("missing-subscription-in-unsubscribe {msg}")) :: =. gall-moves :_ gall-moves @@ -1528,7 +1527,6 @@ :_ state :_ ~ ^- move - %- (trace 2 |.("leaving subscription to {}")) :^ duct %pass (subscription-wire channel-id request-id ship app) [%g %deal [our ship] app `task:agent:gall`[%leave ~]] @@ -1888,8 +1886,7 @@ :: verify that this is a valid response on the duct :: ?~ connection-state=(~(get by connections.state) duct) - %- (trace 1 |.("invalid-outstanding-connection {}")) - [~ state] + ((trace 1 |.("invalid-outstanding-connection {}")) `state) :: |^ ^- [(list move) server-state] :: @@ -1897,8 +1894,7 @@ :: %start ?^ response-header.u.connection-state - %- (trace 1 |.("http-multiple-start {}")) - error-connection + ((trace 1 |.("http-multiple-start {}")) error-connection) :: if request was authenticated, extend the session & cookie's life :: =^ response-header sessions.authentication-state.state @@ -1912,8 +1908,7 @@ ?~ session-id=(session-id-from-request request.inbound) :: cookies are the only auth method, so this is unexpected :: - %- (trace 1 |.("authenticated-without-cookie")) - no-op + ((trace 1 |.("authenticated-without-cookie")) no-op) ?. (~(has by sessions) u.session-id) :: if the session has expired since the request was opened, :: tough luck, we don't create/revive sessions here @@ -1959,8 +1954,8 @@ :: %continue ?~ response-header.u.connection-state - %- (trace 1 |.("http-continue-without-start {}")) - error-connection + %. error-connection + (trace 1 |.("http-continue-without-start {}")) :: =. connections.state %- (trace 2 |.("continuing connection {}}")) @@ -1990,8 +1985,8 @@ :: remove all outstanding state for this connection :: =. connections.state - %- (trace 2 |.("connection completed {}")) - (~(del by connections.state) duct) + %. (~(del by connections.state) duct) + (trace 2 |.("connection completed {}")) state :: ++ error-connection @@ -2000,8 +1995,8 @@ :: remove all outstanding state for this connection :: =. connections.state - %- (trace 2 |.("connection cancelled due to an error {}")) - (~(del by connections.state) duct) + %. (~(del by connections.state) duct) + (trace 2 |.("connection cancelled due to an error {}")) :: respond to outside with %error :: ^- [(list move) server-state] From 50c0fc39ae7c8ca207a42ec064acf4b390ff6785 Mon Sep 17 00:00:00 2001 From: dachus Date: Thu, 9 Feb 2023 12:55:08 -0500 Subject: [PATCH 14/25] changed messages --- pkg/arvo/sys/vane/eyre.hoon | 39 ++++++++++++++++++------------------- 1 file changed, 19 insertions(+), 20 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 7e9c64c5f..0906de209 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -584,7 +584,7 @@ :: =. connections.state %. (~(put by connections.state) duct connection) - (trace 2 |.("creating local connection {}}")) + (trace 2 |.("{} creating local")) :: :_ state (subscribe-to-app app.act inbound-request.connection) @@ -612,9 +612,9 @@ :: =/ connection=outstanding-connection [action [authenticated secure address request] ~ 0] + :: XX pretty sure this is superfluous - done in +handle-response =. connections.state - %. (~(put by connections.state) duct connection) - (trace 2 |.("creating connection {}")) + (~(put by connections.state) duct connection) :: redirect to https if insecure, redirects enabled :: and secure port live :: @@ -815,7 +815,7 @@ :: ++ subscribe-to-app |= [app=term =inbound-request:eyre] - %- (trace 2 |.("subscribing to {} on {}")) + %- (trace 2 |.("awaiting http response from {} id {}")) ^- (list move) :~ :* duct %pass /watch-response/[eyre-id] %g %deal [our our] app @@ -840,7 +840,7 @@ :: =. connections.state %. (~(del by connections.state) duct) - (trace 2 |.("connection cancelled {}")) + (trace 2 |.("{} connection cancelled")) :: ?- -.action.u.connection %gen [~ state] @@ -1139,9 +1139,9 @@ :: lookup the session id by duct :: ?~ maybe-channel-id=(~(get by duct-to-key.channel-state.state) duct) - ((trace 0 |.("no channel to cancel {}")) `state) + ((trace 0 |.("{} no channel to cancel")) `state) :: - %- (trace 0 |.("canceling {}")) + %- (trace 0 |.("{} cancelling")) :: =/ maybe-session (~(get by session.channel-state.state) u.maybe-channel-id) @@ -1442,7 +1442,7 @@ ^- move :^ duct %pass (subscription-wire channel-id request-id ship app) - %- (trace 2 |.("subscribing to {} on {}")) + %- (trace 1 |.("subscribing to {} on {}")) :* %g %deal [our ship] app `task:agent:gall`[%watch path] == @@ -1469,8 +1469,8 @@ :: the client sent us a weird request referring to a subscription :: which isn't active. :: - =* msg=tape "{} {}" %. $(requests t.requests) + =* msg=tape "{} {}" (trace 1 |.("missing-subscription-in-unsubscribe {msg}")) :: =. gall-moves @@ -1521,9 +1521,8 @@ (emit-event channel-id request-id sign) =/ =ship (slav %p i.extra) =* app=term i.t.extra - =* msg=tape - "removing watch for non-existent channel {} {}" - %- (trace 0 |.(msg)) + =* msg=tape "{} {}" + %- (trace 0 |.("removing watch for non-existent channel {msg}")) :_ state :_ ~ ^- move @@ -1720,12 +1719,12 @@ ?~ des [~ ~] :: =* have=mark p.cage.sign - =* desc=tape "from {(trip have)} to json" =/ convert=(unit vase) =/ cag=(unit (unit cage)) (rof ~ %cf [our u.des da+now] /[have]/json) ?. ?=([~ ~ *] cag) ~ `q.u.u.cag + =* desc=tape "from {(trip have)} to json" ?~ convert ((trace 0 |.("no convert {desc}")) [~ ~]) ~| "conversion failed {desc}" @@ -1886,7 +1885,7 @@ :: verify that this is a valid response on the duct :: ?~ connection-state=(~(get by connections.state) duct) - ((trace 1 |.("invalid-outstanding-connection {}")) `state) + ((trace 1 |.("{} invalid-outstanding-connection")) `state) :: |^ ^- [(list move) server-state] :: @@ -1894,7 +1893,7 @@ :: %start ?^ response-header.u.connection-state - ((trace 1 |.("http-multiple-start {}")) error-connection) + ((trace 1 |.("{} http-multiple-start")) error-connection) :: if request was authenticated, extend the session & cookie's life :: =^ response-header sessions.authentication-state.state @@ -1940,7 +1939,7 @@ :: =. response-header.http-event response-header =. connections.state - %- (trace 2 |.("creating connection {}")) + %- (trace 2 |.("{} start")) %+ ~(put by connections.state) duct %_ connection response-header `response-header @@ -1955,10 +1954,10 @@ %continue ?~ response-header.u.connection-state %. error-connection - (trace 1 |.("http-continue-without-start {}")) + (trace 1 |.("{} http-continue-without-start")) :: =. connections.state - %- (trace 2 |.("continuing connection {}}")) + %- (trace 2 |.("{} continuing ")) %+ ~(jab by connections.state) duct |= connection=outstanding-connection =+ size=?~(data.http-event 0 p.u.data.http-event) @@ -1986,7 +1985,7 @@ :: =. connections.state %. (~(del by connections.state) duct) - (trace 2 |.("connection completed {}")) + (trace 2 |.("{} completed")) state :: ++ error-connection @@ -1996,7 +1995,7 @@ :: =. connections.state %. (~(del by connections.state) duct) - (trace 2 |.("connection cancelled due to an error {}")) + (trace 2 |.("{} connection cancelled due to an error")) :: respond to outside with %error :: ^- [(list move) server-state] From b6c1ed2240f2cffddb780c0b0a2524a594a797fc Mon Sep 17 00:00:00 2001 From: dachus Date: Thu, 9 Feb 2023 12:55:47 -0500 Subject: [PATCH 15/25] load changed --- pkg/arvo/sys/vane/eyre.hoon | 28 ++++++++++++++-------------- 1 file changed, 14 insertions(+), 14 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 0906de209..336bf8990 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -2621,20 +2621,20 @@ ?- -.old %~2020.10.18 =, server-state-0.old - =/ new=axle - :* %1 - bindings - cors-registry - connections - authentication-state - channel-state - domains - http-config - ports - outgoing-duct - 0 - == - ..^$(ax new) + %= ..^$ + ax ^- axle + :* %1 + bindings + cors-registry + connections + authentication-state + channel-state + domains + http-config + ports + outgoing-duct + 0 + == == :: %1 :: enable https redirects if certificate configured From 7e4a55b304724ffbd7e262c7e382ad9345657298 Mon Sep 17 00:00:00 2001 From: dachus Date: Thu, 9 Feb 2023 13:06:02 -0500 Subject: [PATCH 16/25] error connections tuned --- pkg/arvo/sys/vane/eyre.hoon | 11 +++++------ 1 file changed, 5 insertions(+), 6 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 336bf8990..bfdc083a7 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -1141,7 +1141,7 @@ ?~ maybe-channel-id=(~(get by duct-to-key.channel-state.state) duct) ((trace 0 |.("{} no channel to cancel")) `state) :: - %- (trace 0 |.("{} cancelling")) + %- (trace 1 |.("{} cancelling")) :: =/ maybe-session (~(get by session.channel-state.state) u.maybe-channel-id) @@ -1893,7 +1893,7 @@ :: %start ?^ response-header.u.connection-state - ((trace 1 |.("{} http-multiple-start")) error-connection) + ((trace 1 |.("{} error multiple start")) error-connection) :: if request was authenticated, extend the session & cookie's life :: =^ response-header sessions.authentication-state.state @@ -1954,7 +1954,7 @@ %continue ?~ response-header.u.connection-state %. error-connection - (trace 1 |.("{} http-continue-without-start")) + (trace 1 |.("{} error continue without start")) :: =. connections.state %- (trace 2 |.("{} continuing ")) @@ -1971,7 +1971,7 @@ %cancel :: todo: log this differently from an ise. :: - error-connection + ((trace 1 |.("cancel http event")) error-connection) == :: ++ pass-response @@ -1994,8 +1994,7 @@ :: remove all outstanding state for this connection :: =. connections.state - %. (~(del by connections.state) duct) - (trace 2 |.("{} connection cancelled due to an error")) + (~(del by connections.state) duct) :: respond to outside with %error :: ^- [(list move) server-state] From d52df27ca0e1365d4659583cd41e0c74c698f6a8 Mon Sep 17 00:00:00 2001 From: dachus Date: Thu, 9 Feb 2023 13:58:24 -0500 Subject: [PATCH 17/25] channel discarding messages added --- pkg/arvo/sys/vane/eyre.hoon | 26 +++++++++++++------------- 1 file changed, 13 insertions(+), 13 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index bfdc083a7..cd01a7f0b 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -839,8 +839,7 @@ [~ state] :: =. connections.state - %. (~(del by connections.state) duct) - (trace 2 |.("{} connection cancelled")) + (~(del by connections.state) duct) :: ?- -.action.u.connection %gen [~ state] @@ -1017,6 +1016,7 @@ =^ moz state (handle-response response) [(weld moves moz) state] + %- (trace 1 |.("{} discarding channel due to logout")) =^ moz state (discard-channel:by-channel i.channels |) $(moves (weld moves moz), channels t.channels) @@ -1138,14 +1138,15 @@ ^- [(list move) server-state] :: lookup the session id by duct :: - ?~ maybe-channel-id=(~(get by duct-to-key.channel-state.state) duct) - ((trace 0 |.("{} no channel to cancel")) `state) + %- (trace 1 |.("{} cancelling subscription to channel")) :: - %- (trace 1 |.("{} cancelling")) + ?~ maybe-channel-id=(~(get by duct-to-key.channel-state.state) duct) + ((trace 1 |.("{} no channel to cancel")) `state) :: =/ maybe-session (~(get by session.channel-state.state) u.maybe-channel-id) - ?~ maybe-session [~ state] + ?~ maybe-session + ((trace 1 |.("{} session doesn't exist")) `state) :: =/ heartbeat-cancel=(list move) ?~ heartbeat.u.maybe-session ~ @@ -1495,6 +1496,7 @@ $(requests t.requests) :: %delete + %- (trace 1 |.("{} discarding due to %delete PUT")) =^ moves state (discard-channel channel-id |) =. gall-moves @@ -1814,6 +1816,7 @@ [~ state] =/ session=channel u.usession :: + %- (trace 1 |.("{} discarding channel")) :_ %_ state session.channel-state (~(del by session.channel-state.state) channel-id) @@ -1841,7 +1844,7 @@ %+ turn ~(tap by subscriptions.session) |= [request-id=@ud ship=@p app=term =path duc=^duct] ^- move - %- (trace 2 |.("leaving subscription to {}")) + %- (trace 2 |.("{} leaving subscription to {}")) :^ duc %pass (subscription-wire channel-id request-id ship app) [%g %deal [our ship] app %leave ~] @@ -2245,9 +2248,6 @@ ?: =(~ inactive) [~ http-server-gate] :: - =/ len=tape (scow %ud (lent inactive)) - ~> %slog.[0 leaf+"eyre: trim: closing {len} inactive channels"] - :: =| moves=(list (list move)) |- ^- [(list move) _http-server-gate] =* channel-id i.inactive @@ -2525,10 +2525,10 @@ ?> ?=([%behn %wake *] sign) ?^ error.sign [[duct %slip %d %flog %crud %wake u.error.sign]~ http-server-gate] - =/ discard-channel - discard-channel:by-channel:(per-server-event event-args) + ~> %slog.[0 leaf+"eyre: {} cancelling channel due to timeout"] =^ moves server-state.ax - (discard-channel i.t.t.wire &) + %. [i.t.t.wire &] + discard-channel:by-channel:(per-server-event event-args) [moves http-server-gate] :: %heartbeat From 9aadada6fc7a9d1148e14c2b5b969e85027af008 Mon Sep 17 00:00:00 2001 From: dachus Date: Thu, 9 Feb 2023 14:11:35 -0500 Subject: [PATCH 18/25] discard-channel traces fixed --- pkg/arvo/sys/vane/eyre.hoon | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index cd01a7f0b..422d7284c 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -1016,7 +1016,7 @@ =^ moz state (handle-response response) [(weld moves moz) state] - %- (trace 1 |.("{} discarding channel due to logout")) + %- (trace 1 |.("{(trip i.channels)} discarding channel due to logout")) =^ moz state (discard-channel:by-channel i.channels |) $(moves (weld moves moz), channels t.channels) @@ -1816,7 +1816,6 @@ [~ state] =/ session=channel u.usession :: - %- (trace 1 |.("{} discarding channel")) :_ %_ state session.channel-state (~(del by session.channel-state.state) channel-id) @@ -2248,6 +2247,9 @@ ?: =(~ inactive) [~ http-server-gate] :: + =/ len=tape (scow %ud (lent inactive)) + ~> %slog.[0 leaf+"eyre: trim: closing {len} inactive channels"] + :: =| moves=(list (list move)) |- ^- [(list move) _http-server-gate] =* channel-id i.inactive @@ -2525,10 +2527,10 @@ ?> ?=([%behn %wake *] sign) ?^ error.sign [[duct %slip %d %flog %crud %wake u.error.sign]~ http-server-gate] - ~> %slog.[0 leaf+"eyre: {} cancelling channel due to timeout"] + =* id i.t.t.wire + ~> %slog.[0 leaf+"eyre: {(trip id)} cancelling channel due to timeout"] =^ moves server-state.ax - %. [i.t.t.wire &] - discard-channel:by-channel:(per-server-event event-args) + (discard-channel:by-channel:(per-server-event event-args) id &) [moves http-server-gate] :: %heartbeat From d8ca915c22b259acb680482d85aa001214715026 Mon Sep 17 00:00:00 2001 From: dachus Date: Thu, 9 Feb 2023 14:22:50 -0500 Subject: [PATCH 19/25] cleaning up message rankings --- pkg/arvo/sys/vane/eyre.hoon | 21 ++++++++++----------- 1 file changed, 10 insertions(+), 11 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 422d7284c..6c8f1ab4e 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -815,7 +815,6 @@ :: ++ subscribe-to-app |= [app=term =inbound-request:eyre] - %- (trace 2 |.("awaiting http response from {} id {}")) ^- (list move) :~ :* duct %pass /watch-response/[eyre-id] %g %deal [our our] app @@ -846,7 +845,7 @@ %app :_ state :_ ~ - %- (trace 2 |.("leaving subscription to {}")) + %- (trace 1 |.("leaving subscription to {}")) :* duct %pass /watch-response/[eyre-id] %g %deal [our our] app.action.u.connection %leave ~ @@ -1480,7 +1479,7 @@ =, u.maybe-subscription :^ duc %pass (subscription-wire channel-id subscription-id.i.requests ship app) - %- (trace 2 |.("leaving subscription to {}")) + %- (trace 1 |.("leaving subscription to {}")) :* %g %deal [our ship] app `task:agent:gall`[%leave ~] == @@ -1523,7 +1522,7 @@ (emit-event channel-id request-id sign) =/ =ship (slav %p i.extra) =* app=term i.t.extra - =* msg=tape "{} {}" + =* msg=tape "{(trip channel-id)} {(trip app)}" %- (trace 0 |.("removing watch for non-existent channel {msg}")) :_ state :_ ~ @@ -1617,9 +1616,9 @@ :: =/ kicking=? ?: clogged - ((trace 1 |.("clogged {} {}")) &) + ((trace 0 |.("clogged {} {}")) &) ?: ?=(~ json) - ((trace 1 |.("can't serialize event, kicking")) &) | + ((trace 0 |.("can't serialize event, kicking")) &) | =? moves kicking :_ moves ::NOTE this shouldn't crash because we @@ -1627,7 +1626,7 @@ :: - only clog on %facts, which have a subscription associated, :: - and already checked whether we still have that subscription. =+ (~(got by subscriptions.u.channel) request-id) - %- (trace 2 |.("leaving subscription to {}")) + %- (trace 1 |.("leaving subscription to {}")) :^ duct %pass (subscription-wire channel-id request-id ship app) [%g %deal [our ship] app %leave ~] @@ -1677,7 +1676,7 @@ ^- (unit desk) =/ sub (~(get by subscriptions.channel) request-id) ?~ sub - ((trace 0 |.("no subscription for request-id {}")) ~) + ((trace 0 |.("no subscription for request-id {(trip request-id)}")) ~) =/ des=(unit (unit cage)) (rof ~ %gd [our app.u.sub da+now] ~) ?. ?=([~ ~ *] des) @@ -1843,7 +1842,7 @@ %+ turn ~(tap by subscriptions.session) |= [request-id=@ud ship=@p app=term =path duc=^duct] ^- move - %- (trace 2 |.("{} leaving subscription to {}")) + %- (trace 1 |.("{} leaving subscription to {}")) :^ duc %pass (subscription-wire channel-id request-id ship app) [%g %deal [our ship] app %leave ~] @@ -1859,7 +1858,7 @@ ?. ?=(%app -.action.connection) ~ :_ ~ - %- (trace 2 |.("leaving subscription to {}")) + %- (trace 1 |.("leaving subscription to {}")) :* duct %pass /watch-response/[eyre-id] %g %deal [our our] app.action.connection %leave ~ @@ -2005,7 +2004,7 @@ ?. ?=(%app -.action.u.connection-state) ~ :_ ~ - %- %+ trace 2 + %- %+ trace 1 |.("leaving subscription to {}") :* duct %pass /watch-response/[eyre-id] %g %deal [our our] app.action.u.connection-state From 785fa057bd6bbc5becf56dca4426f8864c20acca Mon Sep 17 00:00:00 2001 From: dachus Date: Thu, 9 Feb 2023 14:51:34 -0500 Subject: [PATCH 20/25] cleaning code --- pkg/arvo/sys/vane/eyre.hoon | 13 ++++++------- 1 file changed, 6 insertions(+), 7 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 6c8f1ab4e..67dd9a9ea 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -612,8 +612,8 @@ :: =/ connection=outstanding-connection [action [authenticated secure address request] ~ 0] - :: XX pretty sure this is superfluous - done in +handle-response =. connections.state + :: XX pretty sure this is superfluous - done in +handle-response (~(put by connections.state) duct connection) :: redirect to https if insecure, redirects enabled :: and secure port live @@ -837,8 +837,7 @@ :: [~ state] :: - =. connections.state - (~(del by connections.state) duct) + =. connections.state (~(del by connections.state) duct) :: ?- -.action.u.connection %gen [~ state] @@ -1127,7 +1126,7 @@ :: POST methods are used solely for deleting channels (on-put-request channel-id request) :: - ((trace 1 |.("session-not-a-put")) `state) + ((trace 0 |.("session not a put")) `state) :: +on-cancel-request: cancels an ongoing subscription :: :: One of our long lived sessions just got closed. We put the associated @@ -1470,7 +1469,7 @@ :: which isn't active. :: %. $(requests t.requests) - =* msg=tape "{} {}" + =* msg=tape "{(trip channel-id)} {}" (trace 1 |.("missing-subscription-in-unsubscribe {msg}")) :: =. gall-moves @@ -1680,7 +1679,7 @@ =/ des=(unit (unit cage)) (rof ~ %gd [our app.u.sub da+now] ~) ?. ?=([~ ~ *] des) - ((trace 0 |.("no desk for app {(trip app.u.sub)}")) ~) + ((trace 0 |.("no desk for app {}")) ~) `!<(=desk q.u.u.des) :: +channel-event-to-sign: attempt to recover a sign from a channel-event :: @@ -1908,7 +1907,7 @@ ?~ session-id=(session-id-from-request request.inbound) :: cookies are the only auth method, so this is unexpected :: - ((trace 1 |.("authenticated-without-cookie")) no-op) + ((trace 1 |.("error authenticated without cookie")) no-op) ?. (~(has by sessions) u.session-id) :: if the session has expired since the request was opened, :: tough luck, we don't create/revive sessions here From b5b11b0bf1a138c153cc278b1c0acf5ddaabeac0 Mon Sep 17 00:00:00 2001 From: dachus Date: Thu, 9 Feb 2023 14:56:50 -0500 Subject: [PATCH 21/25] cleaning --- pkg/arvo/sys/vane/eyre.hoon | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 67dd9a9ea..1b16078e7 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -1724,10 +1724,9 @@ (rof ~ %cf [our u.des da+now] /[have]/json) ?. ?=([~ ~ *] cag) ~ `q.u.u.cag - =* desc=tape "from {(trip have)} to json" ?~ convert - ((trace 0 |.("no convert {desc}")) [~ ~]) - ~| "conversion failed {desc}" + ((trace 0 |.("no convert from {(trip have)} to json")) [~ ~]) + ~| "conversion failed from {(trip have)} to json" [`[u.des have] `[%fact %json (slym u.convert q.q.cage.sign)]] ?~ jsyn ~ %- some @@ -1885,7 +1884,7 @@ :: verify that this is a valid response on the duct :: ?~ connection-state=(~(get by connections.state) duct) - ((trace 1 |.("{} invalid-outstanding-connection")) `state) + ((trace 0 |.("{} invalid outstanding connection")) `state) :: |^ ^- [(list move) server-state] :: From 50d35ad89a35e4cfa7d142123ead01d1dda5d020 Mon Sep 17 00:00:00 2001 From: dachus Date: Thu, 9 Feb 2023 15:06:06 -0500 Subject: [PATCH 22/25] cleaning --- pkg/arvo/sys/vane/eyre.hoon | 15 ++++++++------- 1 file changed, 8 insertions(+), 7 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 1b16078e7..83b5bef37 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -1139,7 +1139,7 @@ %- (trace 1 |.("{} cancelling subscription to channel")) :: ?~ maybe-channel-id=(~(get by duct-to-key.channel-state.state) duct) - ((trace 1 |.("{} no channel to cancel")) `state) + ((trace 0 |.("{} no channel to cancel")) `state) :: =/ maybe-session (~(get by session.channel-state.state) u.maybe-channel-id) @@ -1470,7 +1470,7 @@ :: %. $(requests t.requests) =* msg=tape "{(trip channel-id)} {}" - (trace 1 |.("missing-subscription-in-unsubscribe {msg}")) + (trace 0 |.("missing subscription in unsubscribe {msg}")) :: =. gall-moves :_ gall-moves @@ -1613,11 +1613,12 @@ :: if we're clogged, or we ran into an event we can't serialize, :: kill this gall subscription. :: + =* msg=tape "on {(trip channel-id)} for {(trip request-id)}" =/ kicking=? ?: clogged - ((trace 0 |.("clogged {} {}")) &) + ((trace 0 |.("clogged {msg}")) &) ?: ?=(~ json) - ((trace 0 |.("can't serialize event, kicking")) &) | + ((trace 0 |.("can't serialize event, kicking {msg}")) &) | =? moves kicking :_ moves ::NOTE this shouldn't crash because we @@ -1892,7 +1893,7 @@ :: %start ?^ response-header.u.connection-state - ((trace 1 |.("{} error multiple start")) error-connection) + ((trace 0 |.("{} error multiple start")) error-connection) :: if request was authenticated, extend the session & cookie's life :: =^ response-header sessions.authentication-state.state @@ -1906,7 +1907,7 @@ ?~ session-id=(session-id-from-request request.inbound) :: cookies are the only auth method, so this is unexpected :: - ((trace 1 |.("error authenticated without cookie")) no-op) + ((trace 0 |.("error authenticated without cookie")) no-op) ?. (~(has by sessions) u.session-id) :: if the session has expired since the request was opened, :: tough luck, we don't create/revive sessions here @@ -1953,7 +1954,7 @@ %continue ?~ response-header.u.connection-state %. error-connection - (trace 1 |.("{} error continue without start")) + (trace 0 |.("{} error continue without start")) :: =. connections.state %- (trace 2 |.("{} continuing ")) From c62549e0b338ad12d7075afe90ab06c8bdcba09f Mon Sep 17 00:00:00 2001 From: dachus Date: Tue, 14 Feb 2023 10:46:07 -0600 Subject: [PATCH 23/25] message changed --- pkg/arvo/sys/vane/eyre.hoon | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 83b5bef37..feb350274 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -1136,10 +1136,10 @@ ^- [(list move) server-state] :: lookup the session id by duct :: - %- (trace 1 |.("{} cancelling subscription to channel")) + %- (trace 1 |.("{} moving channel to waiting state")) :: ?~ maybe-channel-id=(~(get by duct-to-key.channel-state.state) duct) - ((trace 0 |.("{} no channel to cancel")) `state) + ((trace 0 |.("{} no channel to move")) `state) :: =/ maybe-session (~(get by session.channel-state.state) u.maybe-channel-id) From 5433d186aa688d5bd934cef24d565c9e25cee372 Mon Sep 17 00:00:00 2001 From: dachus Date: Thu, 16 Feb 2023 09:02:34 -0600 Subject: [PATCH 24/25] requested changes fixed --- pkg/arvo/sys/vane/eyre.hoon | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index e0ef6939a..0f04f0ccc 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -1638,8 +1638,8 @@ =/ kicking=? ?: clogged ((trace 0 |.("clogged {msg}")) &) - ?: ?=(~ json) - ((trace 0 |.("can't serialize event, kicking {msg}")) &) | + ?. ?=(~ json) | + ((trace 0 |.("can't serialize event, kicking {msg}")) &) =? moves kicking :_ moves ::NOTE this shouldn't crash because we @@ -2547,8 +2547,9 @@ ?> ?=([%behn %wake *] sign) ?^ error.sign [[duct %slip %d %flog %crud %wake u.error.sign]~ http-server-gate] - =* id i.t.t.wire - ~> %slog.[0 leaf+"eyre: {(trip id)} cancelling channel due to timeout"] + =* id i.t.t.wire + %- %+ trace:(per-server-event event-args) 1 + |.("{(trip id)} cancelling channel due to timeout") =^ moves server-state.ax (discard-channel:by-channel:(per-server-event event-args) id &) [moves http-server-gate] From 7c046d8812a7c0c9e20fb1cf69a1cf0fbc7ee9c4 Mon Sep 17 00:00:00 2001 From: dachus Date: Fri, 17 Feb 2023 10:15:27 -0600 Subject: [PATCH 25/25] +load fixed --- pkg/arvo/sys/vane/eyre.hoon | 26 ++++++++++++++++++++++---- 1 file changed, 22 insertions(+), 4 deletions(-) diff --git a/pkg/arvo/sys/vane/eyre.hoon b/pkg/arvo/sys/vane/eyre.hoon index 003d01946..0972d75c9 100644 --- a/pkg/arvo/sys/vane/eyre.hoon +++ b/pkg/arvo/sys/vane/eyre.hoon @@ -68,7 +68,7 @@ :: |% +$ axle - $: %1 + $: %~2023.2.17 =server-state == :: +server-state: state relating to open inbound HTTP connections @@ -2637,7 +2637,8 @@ => |% +$ axle-any $% [%~2020.10.18 =server-state-0] - [%1 =server-state] + [%~2022.7.26 =server-state-0] + [%~2023.2.17 =server-state] == +$ server-state-0 $: bindings=(list [=binding =duct =action]) @@ -2658,7 +2659,24 @@ =, server-state-0.old %= ..^$ ax ^- axle - :* %1 + :* %~2023.2.17 + (insert-binding [[~ /~/name] outgoing-duct [%name ~]] bindings) + cors-registry + connections + authentication-state + channel-state + domains + http-config + ports + outgoing-duct + 0 + == == + :: + %~2022.7.26 + =, server-state-0.old + %= ..^$ + ax ^- axle + :* %~2023.2.17 bindings cors-registry connections @@ -2671,7 +2689,7 @@ 0 == == :: - %1 + %~2023.2.17 :: enable https redirects if certificate configured :: =. redirect.http-config.server-state.old