Collect console log and allow time-travel to log invocation

.gitignore

@@ -1 +1,2 @@
 README.html
+.DS_Store

README.md

@@ -42,6 +42,12 @@ have white background.
 
 ![Live coding](docs/images/edit.gif)
 
+- Console logs are collected and displayed in a separate view. When you click
+  the log you get into debugger to the call of `console.log` or
+  `console.error`.  You can go back and forth like in a time machine.
+
+![Logs](docs/images/logs.gif)
+
 - Leporello is (mostly) self-hosted, i.e. built in itself
 
 ![Self-hosted](docs/images/self-hosted.png)

index.html

@@ -62,7 +62,7 @@
         box-shadow: 1px 1px 6px 3px var(--shadow_color);
       }
 
-      .calltree:focus-within, .problems:focus-within {
+      .tab_content:focus-within, .problems:focus-within {
         outline: none;
       }
 
@@ -114,7 +114,23 @@
         color: red;
       }
 
-      /* calltree */
+      /* Tabs */
+
+      .tabs {
+        display: flex;
+        padding-bottom: 0.5em;
+      }
+
+      .tabs > .tab {
+        margin-right: 1em;
+        padding: 0.3em 1em;
+      }
+
+      .tabs > .tab.active {
+        background-color: rgb(225, 244, 253);
+      }
+
+      /* debugger */
 
       .bottom {
         grid-area: bottom;
@@ -122,15 +138,32 @@
         overflow: auto;
       }
 
-      .calltree, .problems {
+      .debugger {
+        display: flex;
+        flex-direction: column;
+      }
+
+      .debugger, .problems {
         padding: 5px;
         overflow: auto;
       }
 
+      .logs {
+        padding-left: 1em;
+      }
+
+      .logs .log.active {
+        background-color: rgb(225, 244, 253);
+      }
+
+      .tab_content {
+        overflow: auto;
+      }
+
       .entrypoint_select {
-        position: absolute;
+        display: flex;
-        right: 20px;
+        align-items: center;
-        top: 7px;
+        margin-left: auto;
       }
 
       .entrypoint_title {

src/calltree.js

@@ -4,15 +4,17 @@ import {find_node, find_leaf, ancestry_inc} from './ast_utils.js'
 import {color} from './color.js'
 import {eval_frame} from './eval.js'
 
-export const pp_calltree = calltree => map_object(
+export const pp_calltree = calltree => stringify(map_object(
   calltree,
-  (module, {exports, calls}) => stringify(do_pp_calltree(calls))
+  (module, {exports, calls}) => do_pp_calltree(calls)
-)
+))
 
-const do_pp_calltree = tree => ({
+export const do_pp_calltree = tree => ({
   id: tree.id,
+  ok: tree.ok,
+  is_log: tree.is_log,
   has_more_children: tree.has_more_children,
-  string: tree.code.string,
+  string: tree.code?.string,
   children: tree.children && tree.children.map(do_pp_calltree)
 })
 
@@ -657,10 +659,7 @@ export const find_call = (state, index) => {
 
   return add_frame(
     expand_path(
-      {...state, 
+      {...state, calltree: merged},
-        calltree: merged,
-        calltree_changed_token: {},
-      },
       active_calltree_node
     ),
     active_calltree_node,
@@ -708,8 +707,8 @@ const select_return_value = state => {
   } else {
     result_node = find_node(frame, n => 
       n.type == 'function_call'
-      &&
+      && n.result != null
-      n.result.call.id == state.current_calltree_node.id
+      && n.result.call.id == state.current_calltree_node.id
     )
     node = find_node(code, n => is_eq(result_node, n))
   }
@@ -718,7 +717,6 @@ const select_return_value = state => {
     state: {...state, 
       current_module: loc.module,
       selection_state: {
-        index: node.index,
         node,
         initial_is_expand: true,
         result: result_node.result,
@@ -729,7 +727,7 @@ const select_return_value = state => {
 
 }
 
-const select_arguments = state => {
+const select_arguments = (state, with_focus = true) => {
   if(state.current_calltree_node.toplevel) {
     return {state}
   }
@@ -749,8 +747,8 @@ const select_arguments = state => {
   } else {
     const call = find_node(frame, n => 
       n.type == 'function_call'
-      &&
+      && n.result != null
-      n.result.call.id == state.current_calltree_node.id
+      && n.result.call.id == state.current_calltree_node.id
     )
     const call_node = find_node(state.active_calltree_node.code, n => is_eq(n, call))
     node = call_node.children[1] // call_args
@@ -761,13 +759,41 @@ const select_arguments = state => {
     state: {...state, 
       current_module: loc.module,
       selection_state: {
-        index: node.index,
         node,
         initial_is_expand: true,
         result,
       }
     }, 
-    effects: {type: 'set_caret_position', args: [node.index, true]}
+    effects: {type: 'set_caret_position', args: [node.index, with_focus]}
+  }
+}
+
+const navigate_logs_increment = (state, increment) => {
+  const index = 
+    Math.max(
+      Math.min(
+        state.logs.log_position == null
+          ? 0
+          : state.logs.log_position + increment,
+        state.logs.logs.length - 1
+      ),
+      0
+    )
+  return navigate_logs_position(state, index)
+}
+
+const navigate_logs_position = (state, log_position) => {
+  const node = find_node(
+    root_calltree_node(state), 
+    n => n.id == state.logs.logs[log_position].id
+  )
+  const {state: next, effects} = select_arguments(
+    expand_path(jump_calltree_node(state, node).state, node),
+    false,
+  )
+  return {
+    state: {...next, logs: {...state.logs, log_position}},
+    effects,
   }
 }
 
@@ -779,4 +805,6 @@ export const calltree_commands = {
   click,
   select_return_value,
   select_arguments,
+  navigate_logs_position,
+  navigate_logs_increment,
 }

src/cmd.js

@@ -1,4 +1,4 @@
-import {map_object, pick_keys} from './utils.js'
+import {map_object, pick_keys, collect_nodes_with_parents} from './utils.js'
 import {
   is_eq, is_child, ancestry, ancestry_inc, map_tree,
   find_leaf, find_fn_by_location, find_node, find_error_origin_node
@@ -13,6 +13,38 @@ import {
   find_call, find_call_node, set_active_calltree_node
 } from './calltree.js'
 
+const apply_eval_result = (state, eval_result) => {
+  // TODO what if console.log called from native fn (like Array::map)?
+  // Currently it is not recorded. Maybe we should patch monkey patch console?
+  const logs = (
+    eval_result.calltree[state.entrypoint] == null
+      ? []
+      : collect_nodes_with_parents(
+          eval_result.calltree[state.entrypoint].calls, 
+          n => n.is_log,
+        )
+    )
+    .map(({parent, node}) => (
+      {
+        id: node.id,
+        toplevel: parent.toplevel,
+        module: parent.toplevel 
+          ? parent.module
+          : parent.fn.__location.module,
+        parent_name: parent.fn?.name,
+        args: node.args,
+        log_fn_name: node.fn.name,
+      }
+    ))
+    
+  return {
+    ...state, 
+    calltree: eval_result.calltree,
+    calltree_actions: eval_result.calltree_actions,
+    logs: {logs, log_position: null},
+  }
+}
+
 const apply_active_calltree_node = (state, index) => {
   if(!state.parse_result.ok) {
     return state
@@ -27,11 +59,8 @@ const apply_active_calltree_node = (state, index) => {
     node.type == 'do' /* toplevel AST node */
   ) {
     const result = eval_modules(state.parse_result.modules, state.parse_result.sorted)
-    const next = {
+    const next = apply_eval_result(state, result)
-      ...state,
+
-      calltree: result.calltree,
-      calltree_actions: result.calltree_actions,
-    }
     if(node == state.parse_result.modules[root_calltree_module(next)]) {
       const toplevel = root_calltree_node(next)
       return add_frame(
@@ -47,26 +76,24 @@ const apply_active_calltree_node = (state, index) => {
     }
   }
 
-  const {calltree, call, calltree_actions} = eval_modules(
+  const result = eval_modules(
     state.parse_result.modules, 
     state.parse_result.sorted,
     {index: node.index, module: state.current_module},
   )
 
-  if(call == null) {
+  if(result.call == null) {
     // Unreachable call
-    const {node, state: next} = initial_calltree_node({
+    const {node, state: next} = initial_calltree_node(
-      ...state,
+      apply_eval_result(state, result)
-      calltree,
+    )
-      calltree_actions,
-    })
     return set_active_calltree_node(next, null, node)
   }
 
-  const next = {...state, calltree, calltree_actions }
+  const next = apply_eval_result(state, result)
   // We cannot use `call` because `code` was not assigned to it
   const active_calltree_node = find_node(root_calltree_node(next),
-    n => n.id == call.id
+    n => n.id == result.call.id
   )
 
   return add_frame(
@@ -127,6 +154,7 @@ const apply_code = (state, dirty_files) => {
     calltree_changed_token: {},
 
     calltree_actions: null,
+    logs: null,
     current_calltree_node: null,
     active_calltree_node: null,
     calltree_node_is_expanded: null,

src/editor/calltree.js

@@ -24,11 +24,15 @@ export class CallTree {
       e.preventDefault()
 
       if(e.key == 'F1') {
-        this.ui.editor.focus()
+        this.ui.editor.focus_value_explorer(this.container)
       }
 
       if(e.key == 'F2') {
-        this.ui.editor.focus_value_explorer(this.container)
+        this.ui.editor.focus()
+      }
+
+      if(e.key == 'F3') {
+        this.ui.set_active_tab('logs')
       }
 
       if(e.key == 'a') {
@@ -80,12 +84,12 @@ export class CallTree {
     this.state = null
   }
 
-  render_node(n, current_node){
+  render_node(n){
     const is_expanded = this.state.calltree_node_is_expanded[n.id]
 
     const result = el('div', 'callnode',
       el('div', {
-        'class': (n == current_node ? 'call_el active' : 'call_el'),
+        'class': 'call_el',
         click: () => this.on_click_node(n.id),
       },
         !is_expandable(n)
@@ -104,9 +108,7 @@ export class CallTree {
                 + (n.fn.__location == null ? ' native' : '')
             ,
             // TODO show `this` argument
-            n.fn.__location == null
+            n.fn.name
-              ? fn_link(n.fn)
-              : n.fn.name
             ,
             '(' ,
              ...join(
@@ -123,7 +125,7 @@ export class CallTree {
       ),
       (n.children == null || !is_expanded)
         ? null
-        : n.children.map(c => this.render_node(c, current_node))
+        : n.children.map(c => this.render_node(c))
     )
 
     this.node_to_el.set(n.id, result)
@@ -142,8 +144,10 @@ export class CallTree {
     }
   }
 
-  render_select_node(state) {
+  render_select_node(prev, state) {
-    this.render_active(this.state.current_calltree_node, false)
+    if(prev != null) {
+      this.render_active(prev.current_calltree_node, false)
+    }
     this.state = state
     this.render_active(this.state.current_calltree_node, true)
     scrollIntoViewIfNeeded(
@@ -152,12 +156,38 @@ export class CallTree {
     )
   }
 
-  render_expand_node(state) {
+  render_expand_node(prev_state, state) {
     this.state = state
-    const current_node = this.state.current_calltree_node
+    this.do_render_expand_node(
-    const prev_dom_node = this.node_to_el.get(current_node.id)
+      prev_state.calltree_node_is_expanded,
-    const next = this.render_node(current_node, current_node)
+      state.calltree_node_is_expanded,
-    prev_dom_node.parentNode.replaceChild(next, prev_dom_node)
+      root_calltree_node(prev_state),
+      root_calltree_node(state),
+    )
+    this.render_select_node(prev_state, state)
+  }
+
+  do_render_expand_node(prev_exp, next_exp, prev_node, next_node) {
+    if(prev_node.id != next_node.id) {
+      throw new Error()
+    }
+    if(!!prev_exp[prev_node.id] != !!next_exp[next_node.id]) {
+      const prev_dom_node = this.node_to_el.get(prev_node.id)
+      const next = this.render_node(next_node)
+      prev_dom_node.parentNode.replaceChild(next, prev_dom_node)
+    } else {
+      if(prev_node.children == null) {
+        return
+      }
+      for(let i = 0; i < prev_node.children.length; i++) {
+        this.do_render_expand_node(
+          prev_exp, 
+          next_exp, 
+          prev_node.children[i],
+          next_node.children[i],
+        )
+      }
+    }
   }
 
   // TODO on hover highlight line where function defined/
@@ -166,8 +196,7 @@ export class CallTree {
     this.clear_calltree()
     this.state = state
     const root = root_calltree_node(this.state)
-    const current_node = state.current_calltree_node
+    this.container.appendChild(this.render_node(root))
-    this.container.appendChild(this.render_node(root, current_node))
+    this.render_select_node(null, state)
-    this.render_select_node(state, root, current_node)
   }
 }

src/editor/editor.js

@@ -292,7 +292,7 @@ export class Editor {
     const VimApi = require("ace/keyboard/vim").CodeMirror.Vim
 
 
-    this.ace_editor.commands.bindKey("F1", "switch_window");
+    this.ace_editor.commands.bindKey("F2", "switch_window");
     VimApi._mapCommand({
       keys: '<C-w>',
       type: 'action',
@@ -302,12 +302,20 @@ export class Editor {
     this.ace_editor.commands.addCommand({
       name: 'switch_window',
       exec: (editor) => {
-        this.ui.calltree_container.focus()
+        this.ui.set_active_tab('calltree')
+      }
+    })
+
+    this.ace_editor.commands.bindKey("F3", "focus_logs");
+    this.ace_editor.commands.addCommand({
+      name: 'focus_logs',
+      exec: (editor) => {
+        this.ui.set_active_tab('logs')
       }
     })
 
 
-    this.ace_editor.commands.bindKey("F3", "goto_definition");
+    this.ace_editor.commands.bindKey("F4", "goto_definition");
     VimApi._mapCommand({
       keys: 'gd',
       type: 'action',
@@ -322,7 +330,7 @@ export class Editor {
     })
 
 
-    this.ace_editor.commands.bindKey("F2", "focus_value_explorer");
+    this.ace_editor.commands.bindKey("F1", "focus_value_explorer");
     this.ace_editor.commands.addCommand({
       name: 'focus_value_explorer',
       exec: (editor) => {

src/editor/logs.js

@@ -0,0 +1,87 @@
+import {el, scrollIntoViewIfNeeded} from './domutils.js'
+import {exec} from '../index.js'
+import {header} from './value_explorer.js'
+
+export class Logs {
+  constructor(ui, el) {
+    this.el = el
+    this.ui = ui
+    this.el.addEventListener('keydown', (e) => {
+
+      if(e.key == 'Enter') {
+        // TODO reselect call node that was selected previously by calling
+        // 'calltree.navigate_logs_position'
+        this.ui.editor.focus()
+      }
+
+      if(e.key == 'F1') {
+        this.ui.editor.focus_value_explorer(this.el)
+      }
+
+      if(e.key == 'F2') {
+        this.ui.set_active_tab('calltree')
+      }
+
+      if(e.key == 'F3') {
+        this.ui.editor.focus()
+      }
+
+      if(e.key == 'ArrowDown' || e.key == 'j'){
+        exec('calltree.navigate_logs_increment', 1)
+      }
+
+      if(e.key == 'ArrowUp' || e.key == 'k'){
+        exec('calltree.navigate_logs_increment', -1)
+      }
+    })
+  }
+
+  render_logs(prev_logs, logs) {
+
+    if(prev_logs?.logs != logs.logs) {
+
+      this.el.innerHTML = ''
+      for(let i = 0; i < logs.logs.length; i++) {
+        const log = logs.logs[i]
+        this.el.appendChild(
+          el('div', 
+            'log call_header ' 
+              + (log.log_fn_name == 'error' ? 'error' : '') 
+              // Currently console.log calls from native fns (like Array::map)
+              // are not recorded, so next line is dead code
+              + (log.module == null ? ' native' : '')
+            ,
+            el('a', {
+              href: 'javascript: void(0)', 
+              click: () => exec('calltree.navigate_logs_position', i),
+            },
+              (log.module == '' ? '*scratch*' : log.module)
+              + ': '
+              + (
+                log.toplevel
+                ? 'toplevel'
+                : 'fn ' + (log.parent_name == '' ? 'anonymous' : log.parent_name)
+              )
+              + ':'
+            ),
+            ' ',
+            log.args.map(a => header(a)).join(', ')
+          )
+        )
+      }
+
+    }
+
+    if(prev_logs?.log_position != logs.log_position) {
+      if(prev_logs?.log_position != null) {
+        this.el.children[prev_logs.log_position].classList.remove('active')
+      }
+      if(logs.log_position != null) {
+        const active_child = this.el.children[logs.log_position]
+        active_child.classList.add('active')
+        scrollIntoViewIfNeeded(this.el, active_child)
+      }
+    }
+  }
+
+}

src/editor/ui.js

@@ -2,6 +2,7 @@ import {exec, get_state} from '../index.js'
 import {Editor} from './editor.js'
 import {Files} from './files.js'
 import {CallTree} from './calltree.js'
+import {Logs} from './logs.js'
 import {Eval} from './eval.js'
 import {el} from './domutils.js'
 import {FLAGS} from '../feature_flags.js'
@@ -12,6 +13,9 @@ export class UI {
 
     this.files = new Files(this)
 
+    this.tabs = {}
+    this.debugger = {}
+
     container.appendChild(
       (this.root = el('div', 
           'root ' + (FLAGS.embed_value_explorer ? 'embed_value_explorer' : ''),
@@ -20,9 +24,32 @@ export class UI {
           ? null
           : (this.eval_container = el('div', {class: 'eval'})),
         el('div', 'bottom', 
-          this.calltree_container = el('div', {"class": 'calltree', tabindex: 0}),
+          this.debugger_container = el('div', 'debugger',
+            el('div', 'tabs', 
+              this.tabs.calltree = el('div', 'tab', 
+                el('a', {
+                  click: () => this.set_active_tab('calltree'),
+                  href: 'javascript: void(0)',
+                }, 'Call tree (F2)')
+              ),
+              this.tabs.logs = el('div', 'tab', 
+                el('a', {
+                  click: () => this.set_active_tab('logs'),
+                  href: 'javascript: void(0)',
+                }, 'Logs (F3)')
+              ),
+              this.entrypoint_select = el('div', 'entrypoint_select')
+            ),
+            this.debugger.calltree = el('div', {
+              'class': 'tab_content', 
+              tabindex: 0,
+            }),
+            this.debugger.logs = el('div', {
+              'class': 'tab_content logs', 
+              tabindex: 0,
+            }),
+          ),
           this.problems_container = el('div', {"class": 'problems', tabindex: 0}),
-          this.entrypoint_select = el('div', 'entrypoint_select')
         ),
 
         this.files.el,
@@ -88,17 +115,21 @@ export class UI {
     this.root.addEventListener('click', () => this.clear_status(), true)
 
     this.editor_container.addEventListener('keydown', e => {
+      // Bind F2 and F3 for embed_value_explorer
       if(
         e.key.toLowerCase() == 'w' && e.ctrlKey == true
         ||
-        // We bind F1 later, this one to work from embed_value_explorer
+        e.key == 'F2'
-        e.key == 'F1'
       ){
-        this.calltree_container.focus()
+        this.set_active_tab('calltree')
+      }
+
+      if(e.key == 'F3'){
+        this.set_active_tab('logs')
       }
     })
 
-    this.calltree_container.addEventListener('keydown', e => {
+    const escape = e => {
       if(
         (e.key.toLowerCase() == 'w' && e.ctrlKey == true)
         ||
@@ -106,7 +137,10 @@ export class UI {
       ){
         this.editor.focus()
       }
-    })
+    }
+
+    this.debugger.calltree.addEventListener('keydown', escape)
+    this.debugger.logs.addEventListener('keydown', escape)
 
 
     if(!FLAGS.embed_value_explorer) {
@@ -122,7 +156,8 @@ export class UI {
 
     this.editor = new Editor(this, this.editor_container)
 
-    this.calltree = new CallTree(this, this.calltree_container)
+    this.calltree = new CallTree(this, this.debugger.calltree)
+    this.logs = new Logs(this, this.debugger.logs)
 
     // TODO jump to another module
     // TODO use exec
@@ -137,10 +172,22 @@ export class UI {
 
     // TODO when click in calltree, do not jump to location, navigateCallTree
     // instead
-    this.calltree_container.addEventListener('click', jump_to_fn_location)
+    this.debugger.calltree.addEventListener('click', jump_to_fn_location)
 
     this.render_entrypoint_select(state)
     this.render_current_module(state.current_module)
+
+    this.set_active_tab('calltree', true)
+  }
+
+  set_active_tab(tab_id, skip_focus = false) {
+    Object.values(this.tabs).forEach(el => el.classList.remove('active'))
+    this.tabs[tab_id].classList.add('active')
+    Object.values(this.debugger).forEach(el => el.style.display = 'none')
+    this.debugger[tab_id].style.display = 'block'
+    if(!skip_focus) {
+      this.debugger[tab_id].focus()
+    }
   }
 
   render_entrypoint_select(state) {
@@ -172,14 +219,15 @@ export class UI {
     this.editor.focus()
   }
 
-  render_calltree(state) {
+  render_debugger(state) {
-    this.calltree_container.style = ''
+    this.debugger_container.style = ''
     this.problems_container.style = 'display: none'
     this.calltree.render_calltree(state)
+    this.logs.render_logs(null, state.logs)
   }
 
   render_problems(problems) {
-    this.calltree_container.style = 'display: none'
+    this.debugger_container.style = 'display: none'
     this.problems_container.style = ''
     this.problems_container.innerHTML = ''
     problems.forEach(p => {
@@ -220,15 +268,17 @@ export class UI {
 
   render_help() {
     const options =  [
-      ['Switch between editor and call tree', 'F1 or Ctrl-w'],
+      ['Focus value explorer', 'F1'],
-      ['Go from call tree to editor', 'F1 or Esc'],
-      ['Focus value explorer', 'F2'],
       ['Navigate value explorer', '← → ↑ ↓ or hjkl'],
       ['Leave value explorer', 'Esc'],
-      ['Jump to definition', 'F3', 'gd'],
+      ['Switch between editor and call tree view', 'F2 or Ctrl-w'],
+      ['Navigate call tree view', '← → ↑ ↓ or hjkl'],
+      ['Leave call tree view', 'F2 or Esc'],
+      ['Focus console logs', 'F3'],
+      ['Navigate console logs', '↑ ↓ or jk'],
+      ['Jump to definition', 'F4', 'gd'],
       ['Expand selection to eval expression', 'Ctrl-↓ or Ctrl-j'],
       ['Collapse selection', 'Ctrl-↑ or Ctrl-k'],
-      ['Navigate call tree view', '← → ↑ ↓ or hjkl'],
       ['Step into call', 'Ctrl-i', '\\i'],
       ['Step out of call', 'Ctrl-o', '\\o'],
       ['When in call tree view, jump to return statement', 'Enter'],

src/editor/value_explorer.js

@@ -1,6 +1,8 @@
 // TODO large arrays/objects
 // TODO maps, sets
 // TODO show Errors in red
+// TODO fns as clickable links (jump to definition), both for header and for
+// content
 
 import {el, stringify, scrollIntoViewIfNeeded} from './domutils.js'
 
@@ -53,7 +55,7 @@ export const stringify_for_header = v => {
   }
 }
 
-const header = object => {
+export const header = object => {
   if(typeof(object) == 'undefined') {
     return 'undefined'
   } else if(object == null) {

src/effects.js

@@ -81,7 +81,7 @@ export const render_initial_state = (ui, state) => {
   ui.editor.switch_session(state.current_module)
   render_parse_result(ui, state)
   if(state.current_calltree_node != null) {
-    ui.render_calltree(state)
+    ui.render_debugger(state)
     render_coloring(ui, state)
   }
 }
@@ -115,7 +115,7 @@ export const render_common_side_effects = (prev, next, command, ui) => {
     render_parse_result(ui, next)
   }
 
-  if(next.current_calltree_node == null) {
+  if(!next.parse_result.ok) {
 
     ui.calltree.clear_calltree()
     ui.editor.for_each_session((file, session) => clear_coloring(ui, file))
@@ -129,24 +129,24 @@ export const render_common_side_effects = (prev, next, command, ui) => {
       prev.calltree_changed_token != next.calltree_changed_token
     ) {
       // Rerender entire calltree
-      ui.render_calltree(next)
+      ui.render_debugger(next)
       ui.eval.clear_value_or_error()
       ui.editor.for_each_session(f => clear_coloring(ui, f))
       render_coloring(ui, next)
       ui.editor.unembed_value_explorer()
     } else {
-      const node_changed = next.current_calltree_node != prev.current_calltree_node
+      if(
-      const id = next.current_calltree_node.id
+        prev.calltree != next.calltree 
-      const exp_changed = !!prev.calltree_node_is_expanded[id] 
+        || 
-                          != 
+        prev.calltree_node_is_expanded != next.calltree_node_is_expanded
-                          !!next.calltree_node_is_expanded[id] 
+      ) {
-
+        ui.calltree.render_expand_node(prev, next)
-      if(node_changed) {
-        ui.calltree.render_select_node(next)
       }
 
-      if(exp_changed) {
+      const node_changed = next.current_calltree_node != prev.current_calltree_node
-        ui.calltree.render_expand_node(next)
+
+      if(node_changed) {
+        ui.calltree.render_select_node(prev, next)
       } 
 
       if(node_changed) {
@@ -161,21 +161,25 @@ export const render_common_side_effects = (prev, next, command, ui) => {
         render_coloring(ui, next)
       }
     }
+
+    if(prev.logs != next.logs) {
+      ui.logs.render_logs(prev.logs, next.logs)
+    }
   }
 
   // Render 
 
   /* Eval selection */
 
-  const selnode = next.selection_state?.node
+  if(prev.selection_state != next.selection_state) {
-  if(prev.selection_state?.node != selnode) {
     ui.editor.remove_markers_of_type(next.current_module, 'selection')
-    if(selnode != null) {
+    const node = next.selection_state?.node
+    if(node != null) {
       ui.editor.add_marker(
         next.current_module, 
         'selection', 
-        selnode.index, 
+        node.index, 
-        selnode.index + selnode.length
+        node.index + node.length
       )
     } 
   }

src/eval.js

@@ -1,4 +1,9 @@
-import {zip, stringify, map_object, filter_object} from './utils.js'
+import {
+  zip, 
+  stringify, 
+  map_object, 
+  filter_object, 
+} from './utils.js'
 
 import {
   find_fn_by_location, 
@@ -235,28 +240,24 @@ export const eval_modules = (modules, sorted, location) => {
 
   const codestring = 
     `
-    const MAX_DEPTH = 1
+    let children, prev_children
-    let depth
+    // TODO use native array for stack?
-    let current_call
+    const stack = new Array() 
+
     let call_counter = 0
 
-    let enable_find_call
+    let is_entrypoint
     let searched_location
     let found_call
 
-    function add_call(call) {
+    const set_record_call = () => {
-      depth++
+      for(let i = 0; i < stack.length; i++) {
-      call.id = call_counter++
+        stack[i] = true
-      if(current_call.children == null) {
-        current_call.children = [] 
       }
-      current_call.children.push(call)
-      current_call = call
     }
 
     const expand_calltree_node = (node) => {
-      depth = 0
+      children = null
-      current_call = {}
       try {
         node.fn.apply(node.context, node.args)
       } catch(e) {
@@ -264,14 +265,16 @@ export const eval_modules = (modules, sorted, location) => {
       }
       if(node.fn.__location != null) {
         // fn is hosted, it created call, this time with children
-        const result = current_call.children[0]
+        const result = children[0]
         result.id = node.id
+        result.children = prev_children
+        result.has_more_children = false
         return result
       } else {
         // fn is native, it did not created call, only its child did
         return {...node, 
-          children: current_call.children,
+          children,
-          has_more_children: null,
+          has_more_children: false,
         }
       }
     }
@@ -291,55 +294,71 @@ export const eval_modules = (modules, sorted, location) => {
           result.__closure = get_closure()
         }
 
-        const prev = current_call
+        const children_copy = children
-        add_call({
+        children = null
-          fn: result,
+        stack.push(false)
-          args: argscount == null 
-            ? args
-            // Do not capture unused args
-            : args.slice(0, argscount)
-        })
 
-        if(
+        const is_found_call =
-            enable_find_call
+          is_entrypoint
+          &&
+          (searched_location != null && found_call == null)
+          &&
+          (
+            __location.index == searched_location.index
             &&
-            (searched_location != null && found_call == null)
+            __location.module == searched_location.module
-            &&
+          )
-            (
-              __location.index == searched_location.index
-              &&
-              __location.module == searched_location.module
-            )
-        ) {
-          found_call = current_call
 
-          // Set depth to record children of found call
+        if(is_found_call) {
-          depth = 1
+          // Assign temporary value to prevent nested calls from populating
+          // found_call
+          found_call = {}
         }
 
+        let ok, value, error
+
         try {
-          const value = fn(...args)
+          value = fn(...args)
-          current_call.ok = true
+          ok = true
-          current_call.value = value
-          if(depth > MAX_DEPTH) {
-            if(current_call.children != null && current_call.children.length > 0) {
-              current_call.has_more_children = true
-              current_call.children = null
-            }
-          }
           return value
-        } catch(error) {
+        } catch(_error) {
-          current_call.ok = false
+          ok = false
-          current_call.error = error
+          error = _error
+          set_record_call()
           throw error
         } finally {
-          depth--
+
-          if(found_call != null && depth < 1) {
+          prev_children = children
-            // Set depth to 1 to record sibling calls for calls that precede
+
-            // found call
+          const call = {
-            depth = 1
+            id: call_counter++,
+            ok,
+            value,
+            error,
+            fn: result,
+            args: argscount == null 
+              ? args
+              // Do not capture unused args
+              : args.slice(0, argscount),
           }
-          current_call = prev
+
+          if(is_found_call) {
+            found_call = call
+            set_record_call()
+          }
+
+          const should_record_call = stack.pop()
+
+          if(should_record_call) {
+            call.children = children
+          } else {
+            call.has_more_children = children != null && children.length != 0
+          }
+          children = children_copy
+          if(children == null) {
+            children = []
+          }
+          children.push(call)
         }
       }
 
@@ -352,47 +371,81 @@ export const eval_modules = (modules, sorted, location) => {
       if(fn != null && fn.__location != null) {
         return fn(...args)
       }
+
       if(typeof(fn) != 'function') {
         return fn.apply(context, args)
       }
-      const prev = current_call
+
-      add_call({fn, args, context})
+      const children_copy = children
+      children = null
+      stack.push(false)
+
+      const is_log = is_entrypoint 
+        ? fn == console.log || fn == console.error // TODO: other console fns
+        : undefined
+
+      if(is_log) {
+        set_record_call()
+      }
+
+      let ok, value, error
+
       try {
-        const value = fn.apply(context, args)
+        if(!is_log) {
-        current_call.ok = true
+          value = fn.apply(context, args)
-        current_call.value = value
+        } else {
-        if(depth > MAX_DEPTH) {
+          value = undefined
-          if(current_call.children != null && current_call.children.length > 0) {
-            current_call.has_more_children = true
-            current_call.children = null
-          }
         }
+        ok = true
         return value
-      } catch(error) {
+      } catch(_error) {
-        current_call.ok = false
+        ok = false
-        current_call.error = error
+        error = _error
+        set_record_call()
         throw error
       } finally {
-          depth--
+
-          if(found_call != null && depth < 1) {
+        prev_children = children
-            // Set depth to 1 to record sibling calls for calls that precede
+
-            // found call
+        const call = {
-            depth = 1
+          id: call_counter++,
-          }
+          ok,
-          current_call = prev
+          value,
+          error,
+          fn,
+          args,
+          context,
+          is_log,
+        }
+
+        const should_record_call = stack.pop()
+
+        if(should_record_call) {
+          call.children = children
+        } else {
+          call.has_more_children = children != null && children.length != 0
+        }
+
+        children = children_copy
+        if(children == null) {
+          children = []
+        }
+        children.push(call)
       }
     }
 
-    const run = find_call_entrypoint => {
+    const run = entrypoint => {
-      depth = 1
       const __modules = {}
+      let current_call
+
     `
     +
     sorted
       .map((m, i) => 
         `
-         enable_find_call = find_call_entrypoint == '${m}'
+         is_entrypoint = entrypoint == '${m}'
          __modules['${m}'] = {}
+         children = null
          current_call = {
            toplevel: true, 
            module: '${m}', 
@@ -411,9 +464,10 @@ export const eval_modules = (modules, sorted, location) => {
                 current_call.error = error
               }
            })()
-          if(!__modules['${m}'].calls.ok) {
+         current_call.children = children
-            return __modules
+         if(!__modules['${m}'].calls.ok) {
-          }
+           return __modules
+         }
         `
       )
       .join('')
@@ -447,16 +501,14 @@ export const eval_modules = (modules, sorted, location) => {
     }
   }
 
+  const entrypoint = sorted[sorted.length - 1]
+
   let calltree, call
 
   if(location == null) {
-    // Intentionally do not pass arg to run()
+    calltree = actions.run(entrypoint)
-    calltree = actions.run()
   } else {
-    const result = calltree_actions.find_call(
+    const result = calltree_actions.find_call(entrypoint, location)
-      sorted[sorted.length - 1], 
-      location
-    )
     calltree = result.calltree
     call = result.call
   }
@@ -468,6 +520,7 @@ export const eval_modules = (modules, sorted, location) => {
   }
 }
 
+// TODO: assign_code: benchmark and use imperative version for perf?
 const assign_code_calltree = (modules, calltree) =>
   map_object(
     calltree,
@@ -486,6 +539,7 @@ const assign_code = (modules, call, module) => {
     return {...call, 
       code: call.fn == null || call.fn.__location == null 
         ? null
+          // TODO cache find_fn_by_location calls?
         : find_fn_by_location(modules[call.fn.__location.module], call.fn.__location),
       children: call.children && call.children.map(call => assign_code(modules, call)),
     }

src/utils.js

@@ -59,6 +59,25 @@ export const zip = (x,y) => {
 
 export const uniq = arr => [...new Set(arr)]
 
+export const collect_nodes_with_parents = new Function('node', 'pred', `
+  const result = []
+
+  const do_collect = (node, parent) => {
+    if(node.children != null) {
+      for(let c of node.children) {
+        do_collect(c, node)
+      }
+    }
+    if(pred(node)) {
+      result.push({node, parent})
+    }
+  }
+
+  do_collect(node, null)
+
+  return result
+`)
+
 // TODO remove
 /*
 function object_diff(a,b){

test/test.js

@@ -2,7 +2,7 @@ import {find_leaf, ancestry, find_node} from '../src/ast_utils.js'
 import {parse, print_debug_node} from '../src/parse_js.js'
 import {eval_tree, eval_frame, eval_modules} from '../src/eval.js'
 import {COMMANDS, get_initial_state} from '../src/cmd.js'
-import {root_calltree_node, active_frame, pp_calltree} from '../src/calltree.js'
+import {root_calltree_node, active_frame, pp_calltree, do_pp_calltree} from '../src/calltree.js'
 import {color_file} from '../src/color.js'
 import {
   test, 
@@ -435,9 +435,13 @@ export const tests = [
       `
     const s1 = test_initial_state(code)
     // TODO fix error messages
+    const message = root_calltree_node(s1).error.message
     assert_equal(
-      root_calltree_node(s1).error.message, 
+      message == "Cannot read property 'apply' of null"
-      "Cannot read property 'apply' of null"
+      ||
+      message == "Cannot read properties of null (reading 'apply')"
+      ,
+      true
     )
   }),
 
@@ -1566,6 +1570,16 @@ const y = x()`
     assert_equal(s2.current_calltree_node.code.index, code.indexOf('x =>'))
   }),
 
+  test('find_call should find first call', () => {
+    const code = `
+      const rec = i => i == 0 ? 0 : rec(i - 1)
+      rec(10)
+    `
+    const s1 = test_initial_state(code)
+    const {state, effects} = COMMANDS.move_cursor(s1, code.indexOf('i == 0'))
+    assert_equal(state.current_calltree_node.args, [10])
+  }),
+  
   test('select_return_value not expanded', () => {
     const code = `
       const x = (a) => 1
@@ -1995,4 +2009,36 @@ const y = x()`
 
   }),
 
+  test('logs simple', () => {
+    const code = `console.log(10)`
+    const i = test_initial_state(code)
+    assert_equal(i.logs.logs.length, 1)
+    assert_equal(i.logs.logs[0].args, [10])
+  }),
+
+  test('logs', () => {
+    const code = `
+      const deep = x => {
+        if(x == 10) {
+          console.log(x)
+        } else {
+          deep(x + 1)
+        }
+      }
+
+      deep(0)
+    `
+
+    const i = test_initial_state(code)
+    assert_equal(i.logs.logs.length, 1)
+    assert_equal(i.logs.logs[0].args, [10])
+    const {state, effects} = COMMANDS.calltree.navigate_logs_position(i, 0)
+    assert_equal(state.logs.log_position, 0)
+    assert_equal(state.selection_state.result.value, [10])
+    assert_equal(
+      effects, 
+      {type: 'set_caret_position', args: [code.indexOf('(x)'), false]}
+    )
+  }),
+
 ]