@@ -0,0 +1,381 @@
1++++
2+title = "Move trace"
3+weight = 12
4+template = "doc.html"
5++++
6+
7+
8+## Move trace tutorial
9+
10+In this tutorial we will run a simple "move trace" and use the output to get a
11+picture of what the Arvo kernel proper does during the routine task of setting a
12+timer. Some level of familiarity with the kernel is required for this section,
13+which can be obtained in our [Arvo kernel tutorial](@/docs/tutorials/arvo/arvo.md#the-kernel).
14+
15+### Running a move trace
16+
17+Ultimately, everything that happens in Arvo is reduced to Unix events, and the
18+Arvo kernel acts as a sort of traffic cop for vanes and apps to talk to one
19+another. Here we look at how a simple command, `-time ~s1`, goes from pressing
20+Enter on your keyboard in Dojo towards returning a notification that one second
21+has elapsed.
22+
23+To follow along yourself, boot up a fake `~zod` and enter `|verb` into the dojo
24+and press Enter to enable verbose mode (this is tracked by the laconic bit
25+introduced in the section on [the
26+state](@/docs/tutorials/arvo/arvo.md#the-state)) in the kernel documentation, followed by `-time ~s1`
27+followed by Enter. Your terminal should pretty print a series of `move`s that looks something like this:
28+
29+```
30+["" %unix p=%belt //term/1 ~2020.1.14..19.01.25..7556]
31+["|" %pass [%d %g] [[%deal [~zod ~zod] %hood %poke] /] [i=//term/1 t=~]]
32+["||" %pass [%g %g] [[%deal [~zod ~zod] %dojo %poke] /use/hood/~zod/out/~zod/dojo/drum/phat/~zod/dojo] [i=/d t=~[//term/1]]]
33+["|||" %give %g [%unto %fact] [i=/g/use/hood/~zod/out/~zod/dojo/drum/phat/~zod/dojo t=~[/d //term/1]]]
34+["||||" %give %g [%unto %fact] [i=/d t=~[//term/1]]]
35+["|||||" %give %d %blit [i=//term/1 t=~]]
36+["|||" %pass [%g %f] [%build /use/dojo/~zod/drum/hand] [i=/d t=~[//term/1]]]
37+["||||" %give %f %made [i=/g/use/dojo/~zod/drum/hand t=~[/d //term/1]]]
38+["|||||" %pass [%g %g] [[%deal [~zod ~zod] %spider %watch] /use/dojo/~zod/out/~zod/spider/drum/wool] [i=/d t=~[//term/1]]]
39+["||||||" %give %g [%unto %watch-ack] [i=/g/use/dojo/~zod/out/~zod/spider/drum/wool t=~[/d //term/1]]]
40+["|||||" %pass [%g %g] [[%deal [~zod ~zod] %spider %poke] /use/dojo/~zod/out/~zod/spider/drum/wool] [i=/d t=~[//term/1]]]
41+//term/1]]]
42+["||||||" %pass [%g %f] [%build /use/spider/~zod/find/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u] [i=/d t=~[//term/1]]]
43+["|||||||" %give %f %made [i=/g/use/spider/~zod/find/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u t=~[/d //term/1]]]
44+["||||||||" %pass [%g %f] [%build /use/spider/~zod/build/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u] [i=/d t=~[//term/1]]]
45+["|||||||||" %give %f %made [i=/g/use/spider/~zod/build/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u t=~[/d //term/1]]]
46+["||||||||||" %pass [%g %b] [%wait /use/spider/~zod/thread/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u/wait/~2020.1.14..19.01.26..7556] [i=/d t=~[//term/1]]]
47+["|||||||||||" %give %b %doze [i=//behn/0v1p.sn2s7 t=~]]
48+> -time ~s1
49+```
50+followed by a pause of one second, then
51+```
52+["" %unix p=%wake //behn ~2020.1.14..19.01.26..755d]
53+["|" %give %b %doze [i=//behn/0v1p.sn2s7 t=~]]
54+["|" %give %b %wake [i=/g/use/spider/~zod/thread/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u/wait/~2020.1.14..19.01.26..7556 t=~[/d //term/1]]]
55+["||" %give %g [%unto %fact] [i=/g/use/dojo/~zod/out/~zod/spider/drum/wool t=~[/d //term/1]]]
56+["|||" %give %g [%unto %fact] [i=/g/use/hood/~zod/out/~zod/dojo/drum/phat/~zod/dojo t=~[/d //term/1]]]
57+["||||" %give %g [%unto %fact] [i=/d t=~[//term/1]]]
58+["|||||" %give %d %blit [i=//term/1 t=~]]
59+["||" %give %g [%unto %kick] [i=/g/use/dojo/~zod/out/~zod/spider/drum/wool t=~[/d //term/1]]]
60+~s1..0007
61+```
62+This gives us a move trace that is a list of `move`s and some
63+associated metadata. Some of the `move`s are a bit of a distraction from what's
64+going on overall such as acknowledgements that a `poke` was received
65+(`%poke-ack`s), so we've omitted them for clarity. Furthermore, two `move`s (the
66+`%blit` `card`s) is not printed even in verbose mode because it occurs so
67+frequently, but there are only two of them here and so we have added it in.
68+
69+The main process that is occurring here is a sequence of `%pass` `move`s initiated
70+by pressing Enter in the terminal that goes on to be handled by Dill, then Gall,
71+and finally Behn. After the timer has elapsed, a sequence of `%give` `move`s is
72+begun by Behn, which then passes through Gall and ultimately ends up back at the
73+terminal. Any `move`s besides `%pass` in the first segment of the move trace is a
74+secondary process utilized for book-keeping, spawning processes, interpreting
75+commands, etc. All of this will be explained in detail below.
76+
77+
78+It is important to note that this move trace should be thought of
79+as being from the "point of view" of the kernel - each line represents the
80+kernel taking in a message from one source and passing it along to its
81+destination. It is then processed at that destination (which could be a vane or
82+an app), and the return of that process is sent back to Arvo in the form of
83+another `move` to perform and the loop begins again. Thus this move trace does
84+not display information about what is going on inside of the vane or app such as
85+private function calls, only what the kernel itself sees.
86+
87+### Interpreting the move trace
88+
89+In this section we will go over the move trace line-by-line, explaining how the
90+move trace is printed, what each line means (including some things not found in
91+the move trace), and a particular focus on what code is being activated in the
92+first few lines that should equip you well enough to unravel the rest of the
93+move trace in as much detail as you desire.
94+
95+
96+#### The call
97+
98+Let's put the first part of the move trace into a diagram to make following
99+along a little easier.
100+
101+<div style="text-align:center">
102+<img src="https://media.urbit.org/docs/arvo/move-trace-with-key.png">
103+</div>
104+
105+Here, each arrow represents the passing of some information, with most of it
106+being from vane to vane. Here, when Vane A has an arrow to a card and then an
107+arrow to Vane B, this represents either a `%pass` `note/task` sequence or a
108+`%give` `gift/sign` sequence that actually has the Arvo kernel in the middle.
109+That is to say, Vane A `%pass`es a `note` to the Arvo kernel addressed to Vane
110+B, and the Arvo kernel then `%pass`es a `task` to Vane B. For more information,
111+see the [Arvo kernel tutorial](@/docs/tutorials/arvo/arvo.md#the-kernel).
112+
113+This simple action ends up involving four vanes - Dill, Gall, Behn, and Ford -
114+as well as four applications - hood, spider, dojo, and time.
115+
116+Now let's go through each line one by one.
117+```
118+["" %unix p=%belt //term/1 ~2020.1.14..19.01.25..7556]
119+```
120+This tells us that Unix has sent a `%belt` `card`, which corresponds to
121+terminal input (the Enter keystroke) at time `~2020.1.14..19.01.25..7556`
122+
123+Here is the line of code in `arvo.hoon`, found in the [section
124+3bE core](@/docs/tutorials/arvo/arvo.md#section-3be-core), that generated the output:
125+
126+```hoon
127+ ~? !lac ["" %unix -.q.ovo p.ovo now]
128+```
129+First we note that this line is executed only if the laconic bit is set to true,
130+as we did when we input `|verb`. Here, `ovo` is the input `ovum`. Knowing that an `ovum` is a `[p=wire q=curd]`,
131+we can then say that this is a `%unix` `move` tagged with `%belt` whose cause is a `wire` given by `//term/1`,
132+where the empty span `//` represents Unix and `term/1` represents the terminal
133+in Unix. Here we have a `wire` instead of a `duct` (i.e. a list of `wire`s)
134+since Unix I/O events are always the beginning and end of the Arvo event loop,
135+thus only a single `wire` is ever required at this initial stage.
136+
137+The `""` here is a metadatum that keeps track of how many steps deep in the
138+causal chain the event is. An event
139+with `n` `|`'s was caused by the most recent previous event with `n-1` `|`'s. In
140+this case, Unix events are an "original cause" and thus represented by an empty
141+string.
142+
143+At this point in time, Dill has received the `move` and then processes it. The
144+`%belt` `task` in `dill.hoon` is `+call`ed, which is processed using the `+send`
145+arm:
146+
147+```hoon
148+ ++ send :: send action
149+ |= bet/dill-belt
150+ ^+ +>
151+ ?^ tem
152+ +>(tem `[bet u.tem])
153+ (deal / [%poke [%dill-belt -:!>(bet) bet]])
154+```
155+
156+Dill has taken in the command and in response it `%pass`es a `task` `card` with
157+instructions to `%poke` hood, which is a Gall app
158+primarily used for interfacing with Dill. Here, `+deal` is an arm for
159+`%pass`ing a `card` to Gall to ask it to create a `%deal` `task`:
160+
161+
162+```hoon
163+ ++ deal :: pass to %gall
164+ |= [=wire =deal:gall]
165+ (pass wire [%g %deal [our our] ram deal])
166+```
167+
168+Next in our move trace we have this:
169+```
170+["|" %pass [%d %g] [[%deal [~zod ~zod] %hood %poke] /] [i=//term/1 t=~]]
171+```
172+Here, Dill `%pass`es a `task` `card` saying to `%poke` Gall's hood app (with the
173+Enter keystroke).
174+
175+Let's glance at part of the `+jack` arm in `arvo.hoon`, located in the [section 3bE
176+core](@/docs/tutorials/arvo/arvo.md#section-3be-core). This arm is what the Arvo kernel uses to send `card`s,
177+and here we look at the segment that includes `%pass` `move`s.
178+
179+```hoon
180+ ++ jack :: dispatch card
181+ |= [lac=? gum=muse]
182+ ^- [[p=(list ovum) q=(list muse)] _vanes]
183+ ~| %failed-jack
184+ :: =. lac |(lac ?=(?(%g %f) p.gum))
185+ :: =. lac &(lac !?=($b p.gum))
186+ %^ fire
187+ p.gum
188+ s.gum
189+ ?- -.r.gum
190+ $pass
191+ ~? &(!lac !=(%$ p.gum))
192+ :- (runt [s.gum '|'] "")
193+ :^ %pass [p.gum p.q.r.gum]
194+ ?: ?=(?(%deal %deal-gall) +>-.q.q.r.gum)
195+ :- :- +>-.q.q.r.gum
196+ (,[[ship ship] term term] [+>+< +>+>- +>+>+<]:q.q.r.gum)
197+ p.r.gum
198+ [(symp +>-.q.q.r.gum) p.r.gum]
199+ q.gum
200+ [p.q.r.gum ~ [[p.gum p.r.gum] q.gum] q.q.r.gum]
201+```
202+
203+Code for writing traces can be a bit tricky, but let's try not to get too
204+distracted by the lark expressions and such. By paying attention to the lines
205+concerning the laconic bit (following `!lac`) we can mostly determine what is being told to us.
206+
207+From the initial input event, Arvo has generated a `card` that it is now
208+`%pass`ing from Dill (represented by `%d`) to Gall (represented by `%g`). The
209+`card` is a `%deal` `task`, asking Gall to `%poke` hood using data that has
210+originated from the terminal `//term/1`, namely that the Enter key was pressed. The line `:- (runt [s.gum '|'] "")`
211+displays the causal chain length metadatum mentioned above. Lastly, `[~zod ~zod]` tells us that
212+`~zod` is both the sending and receiving ship.
213+
214+From here on our explanations will be more brief. We include some information
215+that cannot be directly read from the move trace in [brackets]. Onto the next line:
216+
217+```
218+["||" %pass [%g %g] [[%deal [~zod ~zod] %dojo %poke] /use/hood/~zod/out/~zod/dojo/drum/phat/~zod/dojo] [i=/d t=~[//term/1]]]
219+```
220+
221+Here is another `%pass` `move`, this time from Gall to iself as denoted by `[%g
222+%g]`. Gall's hood has received the `%deal` `card` from Dill, and in response it is
223+`%poke`ing dojo with the information [that Enter was pressed].
224+
225+```
226+["|||" %give %g [%unto %fact] [i=/g/use/hood/~zod/out/~zod/dojo/drum/phat/~zod/dojo t=~[/d //term/1]]]
227+```
228+
229+Gall's dojo `%give`s a `gift` with a `%fact` (subscription update) to Gall's hood, [saying to clear
230+the terminal prompt].
231+
232+```
233+["||||" %give %g [%unto %fact] [i=/d t=~[//term/1]]]
234+```
235+Gall's hood `%give`s a `gift` with a `%fact` to Dill [saying to replace the current terminal line with `~zod:dojo>`]
236+
237+Next is the `move` that is not actually printed in the move trace mentioned
238+above:
239+
240+```
241+["|||||" %give %d %blit [i=//term/1 t=~]]
242+```
243+
244+Dill `%give`s a `%blit` (terminal output) event to Unix [saying to replace the current terminal line with `~zod:dojo>`].
245+
246+```
247+["|||" %pass [%g %f] [%build /use/dojo/~zod/drum/hand] [i=/d t=~[//term/1]]]
248+```
249+
250+Gall's dojo also `%pass`es a `%build` request to Ford [asking to run "~s1" against the subject we use in the dojo].
251+
252+```
253+["||||" %give %f %made [i=/g/use/dojo/~zod/drum/hand t=~[/d //term/1]]]
254+```
255+
256+Ford `%give`s a result back to dojo [with the value `~s1`]
257+
258+```
259+["|||||" %pass [%g %g] [[%deal [~zod ~zod] %spider %watch] /use/dojo/~zod/out/~zod/spider/drum/wool] [i=/d t=~[//term/1]]]
260+```
261+
262+Gall's dojo `%pass`es a `%watch` to Gall's spider app [to start listening for the result of the thread it's about to start].
263+
264+```
265+["||||||" %give %g [%unto %watch-ack] [i=/g/use/dojo/~zod/out/~zod/spider/drum/wool t=~[/d //term/1]]]
266+```
267+
268+Gall's spider acknowledges the subscription from dojo.
269+
270+```
271+["|||||" %pass [%g %g] [[%deal [~zod ~zod] %spider %poke] /use/dojo/~zod/out/~zod/spider/drum/wool] [i=/d t=~[//term/1]]]
272+```
273+
274+Gall's dojo also `%pass`es a `%poke` to Gall's spider [asking it start the thread "-time" with argument `~s1`].
275+
276+```
277+["||||||" %pass [%g %f] [%build /use/spider/~zod/find/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u] [i=/d t=~[//term/1]]]
278+```
279+
280+Gall's spider `%pass`es a `%build` request to Ford [asking it to find the path in `/ted` where the "time" thread is].
281+
282+```
283+["|||||||" %give %f %made [i=/g/use/spider/~zod/find/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u t=~[/d //term/1]]]
284+```
285+
286+Ford `%give`s a result back to Gall's spider [saying it's in `/ted/time.hoon`].
287+
288+```
289+["||||||||" %pass [%g %f] [%build /use/spider/~zod/build/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u] [i=/d t=~[//term/1]]]
290+```
291+
292+Gall's spider `%pass`es a `%build` request to Ford [asking it to compile the file `/ted/time.hoon`].
293+
294+```
295+["|||||||||" %give %f %made [i=/g/use/spider/~zod/build/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u t=~[/d //term/1]]]
296+```
297+
298+Ford `%give`s a result back to Gall's spider [with the compiled thread].
299+
300+```
301+["||||||||||" %pass [%g %b] [%wait /use/spider/~zod/thread/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u/wait/~2020.1.14..19.01.26..7556] [i=/d t=~[//term/1]]]
302+```
303+
304+Gall's spider's thread with id `~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u` asks Behn to set a timer [for one second].
305+
306+```
307+["|||||||||||" %give %b %doze [i=//behn/0v1p.sn2s7 t=~]]
308+```
309+
310+Behn `%give`s a `%doze` `card` to Unix, asking it to set a timer [for one second from
311+now]. At this point Arvo may rest.
312+
313+#### The return
314+
315+Now Unix sets a timer for one second, waits one second, and then informs Behn that a second has
316+passed, leading to a chain of `%give` `move`s that ultimately prints
317+`~s1..0007`.
318+
319+Let's throw the move trace into a table:
320+
321+| length | move | vane(s) | card | duct |
322+|--------|---------|---------|-----------------|------------------------------------------------------------------------------------------------------------------|
323+| 0 | `%unix` | | `%wake` | `//behn` |
324+| 1 | `%give` | `%b` | `%doze` | `//behn/0v1p.sn2s7` |
325+| 1 | `%give` | `%b` | `%wake` | `/g/use/spider/~zod/thread/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u/wait/~2020.1.14..19.01.26..7556 /d //term/1` |
326+| 2 | `%give` | `%g` | `[%unto %fact]` | `/g/use/dojo/~zod/out/~zod/spider/drum/wool /d //term/1` |
327+| 3 | `%give` | `%g` | `[%unto %fact]` | `/g/use/hood/~zod/out/~zod/dojo/drum/phat/~zod/dojo /d //term/1` |
328+| 4 | `%give` | `%g` | `[%unto %fact]` | `/d //term/1` |
329+| 5 | `%give` | `%d` | `%blit` | `//term/1` |
330+| 2 | `%give` | `%g` | `[%unto %kick]` | `/g/use/dojo/~zod/out/~zod/spider/drum/wool /d //term/1` |
331+
332+Now we follow it line-by-line:
333+
334+```
335+["" %unix p=%wake //behn ~2020.1.14..19.01.26..755d]
336+```
337+
338+Unix sends a `%wake` (timer fire) `card` at time `~2020.1.14..19.01.26..755d`.
339+
340+```
341+["|" %give %b %doze [i=//behn/0v1p.sn2s7 t=~]]
342+```
343+
344+Behn `%give`s a `%doze` `card` to Unix, asking it to set a timer [for whatever next timer it has in its queue].
345+
346+```
347+["|" %give %b %wake [i=/g/use/spider/~zod/thread/~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u/wait/~2020.1.14..19.01.26..7556 t=~[/d //term/1]]]
348+```
349+
350+Behn `%give`s a `%wake` to Gall's spider's thread with id `~.dojo_0v6.210tt.1sme1.ev3qm.qgv2e.a754u`.
351+
352+```
353+["||" %give %g [%unto %fact] [i=/g/use/dojo/~zod/out/~zod/spider/drum/wool t=~[/d //term/1]]]
354+```
355+
356+Gall's spider `%give`s a `%fact` (subscription update) to dojo [saying that the thread completed successfully and produced value `~s1.0007`].
357+
358+```
359+["|||" %give %g [%unto %fact] [i=/g/use/hood/~zod/out/~zod/dojo/drum/phat/~zod/dojo t=~[/d //term/1]]]
360+```
361+
362+Gall's dojo `%give`s a `%fact` to hood [saying to output `~s1..0007`].
363+
364+```
365+["||||" %give %g [%unto %fact] [i=/d t=~[//term/1]]]
366+```
367+
368+Gall's hood `%give`s a `%fact` to Dill [saying to output `~s1..0007`].
369+
370+```
371+["|||||" %give %d %blit [i=//term/1 t=~]]
372+```
373+
374+Dill `%give`s a `%blit` (terminal output) event to Unix [saying to print a new line with output `~s1..0007`].
375+
376+```
377+["||" %give %g [%unto %kick] [i=/g/use/dojo/~zod/out/~zod/spider/drum/wool t=~[/d //term/1]]]
378+```
379+
380+Gall's spider also closes the subscription from dojo [since the thread has completed].
381+