Add tracing to virtual_dom

[jereanon]

Address #1161; Add tracing to virtual dom:

• Added a dependency on tracing-fluent-assertions for test cases
• Added a test case showing tracing

example log

2024-02-28T21:52:25.266474Z TRACE dioxus_core::scope_context: providing context alloc::rc::Rc<dioxus_core::error_boundary::ErrorBoundary> (TypeId { t: 86211292795840746005296084033382154959 }) in app
    at packages/core/src/scope_context.rs:189
    in dioxus_core::virtual_dom::VirtualDom::new

  2024-02-28T21:52:25.266651Z TRACE dioxus_core::scope_context: looking for context generational_box::Owner<generational_box::sync::SyncStorage> (TypeId { t: 16187079142358387300491255137481079601 }) in app
    at packages/core/src/scope_context.rs:106
    in dioxus_core::scope_arena::render with scope: app
    in dioxus_core::virtual_dom::VirtualDom::rebuild

  2024-02-28T21:52:25.266662Z TRACE dioxus_core::scope_context: context generational_box::Owner<generational_box::sync::SyncStorage> (TypeId { t: 16187079142358387300491255137481079601 }) not found
    at packages/core/src/scope_context.rs:140
    in dioxus_core::scope_arena::render with scope: app
    in dioxus_core::virtual_dom::VirtualDom::rebuild

  2024-02-28T21:52:25.266671Z TRACE dioxus_core::scope_context: providing context generational_box::Owner<generational_box::sync::SyncStorage> (TypeId { t: 16187079142358387300491255137481079601 }) in app
    at packages/core/src/scope_context.rs:189
    in dioxus_core::scope_arena::render with scope: app
    in dioxus_core::virtual_dom::VirtualDom::rebuild

  2024-02-28T21:52:25.266713Z TRACE dioxus_core::scope_context: providing context dioxus_signals::reactive_context::ReactiveContext (TypeId { t: 86476382904980360086558195405008306005 }) in app
    at packages/core/src/scope_context.rs:189
    in dioxus_core::scope_arena::render with scope: app
    in dioxus_core::virtual_dom::VirtualDom::rebuild

  2024-02-28T21:52:25.266723Z TRACE dioxus_core::scope_context: looking for context generational_box::Owner (TypeId { t: 87785542931436862771411509553978749471 }) in app
    at packages/core/src/scope_context.rs:106
    in dioxus_core::scope_arena::render with scope: app
    in dioxus_core::virtual_dom::VirtualDom::rebuild

  2024-02-28T21:52:25.266730Z TRACE dioxus_core::scope_context: context generational_box::Owner (TypeId { t: 87785542931436862771411509553978749471 }) not found
    at packages/core/src/scope_context.rs:140
    in dioxus_core::scope_arena::render with scope: app
    in dioxus_core::virtual_dom::VirtualDom::rebuild

  2024-02-28T21:52:25.266769Z TRACE dioxus_core::scope_context: providing context generational_box::Owner (TypeId { t: 87785542931436862771411509553978749471 }) in app
    at packages/core/src/scope_context.rs:189
    in dioxus_core::scope_arena::render with scope: app
    in dioxus_core::virtual_dom::VirtualDom::rebuild

  2024-02-28T21:52:25.266828Z  INFO dioxus_core::diff::node: creating template, self: VNode { vnode: VNodeInner { key: None, template: Cell { value: Template { name: "packages/core/tests/tracing.rs:60:5:1728", roots: [Element { tag: "div", namespace: None, attrs: [], children: [Element { tag: "button", namespace: None, attrs: [Dynamic { id: 0 }], children: [Text { text: "+" }] }, Element { tag: "button", namespace: None, attrs: [Dynamic { id: 1 }], children: [Text { text: "-" }] }, Element { tag: "ul", namespace: None, attrs: [], children: [Dynamic { id: 0 }] }] }], node_paths: [[0, 2, 0]], attr_paths: [[0, 0], [0, 1]] } }, dynamic_nodes: [Placeholder(VPlaceholder)], dynamic_attrs: [[Attribute { name: "onclick", value: Listener, namespace: None, volatile: false }], [Attribute { name: "onclick", value: Listener, namespace: None, volatile: false }]] }, mount: Cell { value: MountId(0) } }, mount: MountId(0)
    at packages/core/src/diff/node.rs:547
    in dioxus_core::virtual_dom::VirtualDom::rebuild

  2024-02-28T21:52:25.266896Z TRACE dioxus_core::virtual_dom: Calling 1 listeners
    at packages/core/src/virtual_dom.rs:695
    in dioxus_core::virtual_dom::VirtualDom::handle_bubbling_event with parent: Some(ElementRef { path: ElementPath { path: [0, 0] }, mount: MountId(0) }), name: "click"
    in dioxus_core::virtual_dom::VirtualDom::handle_event with name: "click", data: Any { .. }, element: ElementId(2), bubbles: true

  2024-02-28T21:52:25.266934Z TRACE dioxus_core::virtual_dom: Marking scope ScopeId(0) (app) as dirty
    at packages/core/src/virtual_dom.rs:379
    in dioxus_core::virtual_dom::VirtualDom::process_events

  2024-02-28T21:52:25.266997Z  INFO dioxus_core::diff::node: creating template, self: VNode { vnode: VNodeInner { key: None, template: Cell { value: Template { name: "packages/core/tests/tracing.rs:71:37:2059", roots: [Dynamic { id: 0 }], node_paths: [[0]], attr_paths: [] } }, dynamic_nodes: [Component(VComponent { name: "ChildExample" })], dynamic_attrs: [] }, mount: Cell { value: MountId(1) } }, mount: MountId(1)
    at packages/core/src/diff/node.rs:547
    in dioxus_core::virtual_dom::VirtualDom::render_immediate

  2024-02-28T21:52:25.267026Z  INFO dioxus_core::diff::node: creating template, self: VNode { vnode: VNodeInner { key: None, template: Cell { value: Template { name: "packages/core/tests/tracing.rs:81:5:2238", roots: [Element { tag: "li", namespace: None, attrs: [Dynamic { id: 0 }], children: [DynamicText { id: 0 }] }], node_paths: [[0, 0]], attr_paths: [[0]] } }, dynamic_nodes: [Text(VText { value: "0" })], dynamic_attrs: [[Attribute { name: "onmouseover", value: Listener, namespace: None, volatile: false }]] }, mount: Cell { value: MountId(2) } }, mount: MountId(2)
    at packages/core/src/diff/node.rs:547
    in dioxus_core::virtual_dom::VirtualDom::render_immediate

  2024-02-28T21:52:25.267061Z TRACE dioxus_core::virtual_dom: Calling 1 listeners
    at packages/core/src/virtual_dom.rs:695
    in dioxus_core::virtual_dom::VirtualDom::handle_bubbling_event with parent: Some(ElementRef { path: ElementPath { path: [0, 0] }, mount: MountId(0) }), name: "click"
    in dioxus_core::virtual_dom::VirtualDom::handle_event with name: "click", data: Any { .. }, element: ElementId(2), bubbles: true

  2024-02-28T21:52:25.267084Z TRACE dioxus_core::virtual_dom: Marking scope ScopeId(0) (app) as dirty
    at packages/core/src/virtual_dom.rs:379
    in dioxus_core::virtual_dom::VirtualDom::process_events

  2024-02-28T21:52:25.267131Z  INFO dioxus_core::diff::node: creating template, self: VNode { vnode: VNodeInner { key: None, template: Cell { value: Template { name: "packages/core/tests/tracing.rs:71:37:2059", roots: [Dynamic { id: 0 }], node_paths: [[0]], attr_paths: [] } }, dynamic_nodes: [Component(VComponent { name: "ChildExample" })], dynamic_attrs: [] }, mount: Cell { value: MountId(3) } }, mount: MountId(3)
    at packages/core/src/diff/node.rs:547
    in dioxus_core::virtual_dom::VirtualDom::render_immediate

  2024-02-28T21:52:25.267157Z  INFO dioxus_core::diff::node: creating template, self: VNode { vnode: VNodeInner { key: None, template: Cell { value: Template { name: "packages/core/tests/tracing.rs:81:5:2238", roots: [Element { tag: "li", namespace: None, attrs: [Dynamic { id: 0 }], children: [DynamicText { id: 0 }] }], node_paths: [[0, 0]], attr_paths: [[0]] } }, dynamic_nodes: [Text(VText { value: "1" })], dynamic_attrs: [[Attribute { name: "onmouseover", value: Listener, namespace: None, volatile: false }]] }, mount: Cell { value: MountId(4) } }, mount: MountId(4)
    at packages/core/src/diff/node.rs:547
    in dioxus_core::virtual_dom::VirtualDom::render_immediate

  2024-02-28T21:52:25.267206Z TRACE dioxus_core::virtual_dom: Calling 1 listeners
    at packages/core/src/virtual_dom.rs:695
    in dioxus_core::virtual_dom::VirtualDom::handle_bubbling_event with parent: Some(ElementRef { path: ElementPath { path: [0, 0] }, mount: MountId(0) }), name: "click"
    in dioxus_core::virtual_dom::VirtualDom::handle_event with name: "click", data: Any { .. }, element: ElementId(2), bubbles: true

  2024-02-28T21:52:25.267229Z TRACE dioxus_core::virtual_dom: Marking scope ScopeId(0) (app) as dirty
    at packages/core/src/virtual_dom.rs:379
    in dioxus_core::virtual_dom::VirtualDom::process_events

  2024-02-28T21:52:25.267274Z  INFO dioxus_core::diff::node: creating template, self: VNode { vnode: VNodeInner { key: None, template: Cell { value: Template { name: "packages/core/tests/tracing.rs:71:37:2059", roots: [Dynamic { id: 0 }], node_paths: [[0]], attr_paths: [] } }, dynamic_nodes: [Component(VComponent { name: "ChildExample" })], dynamic_attrs: [] }, mount: Cell { value: MountId(5) } }, mount: MountId(5)
    at packages/core/src/diff/node.rs:547
    in dioxus_core::virtual_dom::VirtualDom::render_immediate

  2024-02-28T21:52:25.267297Z  INFO dioxus_core::diff::node: creating template, self: VNode { vnode: VNodeInner { key: None, template: Cell { value: Template { name: "packages/core/tests/tracing.rs:81:5:2238", roots: [Element { tag: "li", namespace: None, attrs: [Dynamic { id: 0 }], children: [DynamicText { id: 0 }] }], node_paths: [[0, 0]], attr_paths: [[0]] } }, dynamic_nodes: [Text(VText { value: "2" })], dynamic_attrs: [[Attribute { name: "onmouseover", value: Listener, namespace: None, volatile: false }]] }, mount: Cell { value: MountId(6) } }, mount: MountId(6)
    at packages/core/src/diff/node.rs:547
    in dioxus_core::virtual_dom::VirtualDom::render_immediate

[ealmloff]

I'm torn on testing the traces we output. The tests added in this PR are for APIs that are already public (new and rebuild) but for internal functions it feels like these tests would be very fragile. For example, it isn't defined exactly how many times poll_tasks should be called every rebuild, so we probably shouldn't test how many times that trace is seen

On the other hand, if tracing is the API we plan to use for dev tools in the future, it might make sense to test that tracing is working correctly

The specific tests added in this PR don't seem flakey and are easy enough to remove if they do end up being problematic, so I'm going to go ahead and merge this PR

[jereanon]

I wouldn't recommend testing the traces outputted, but for the purposes of this PR/issue, i felt it was necessary to prove completion of the work.

[ealmloff]

Thanks for adding tracing to core! This will make it much easier to see what is going on inside of the virtual dom