$inspect.trace() is missing information or Svelte is running effects unnecessarily

[webJose]

Describe the bug

It seems that there might be room for improvement for $inspect.trace(). There are cases where the trace doesn't highlight anything as changed. If nothing really changed, then why did the effect fire, right?

My current possibilities are:

1. The trace is correct, and no recorded signals really changed. Implication: There's a bug in Svelte that fires effects unnecessarily.
2. The trace is incorrect, as a signal really did change. Implication: $inspect.trace() doesn't always show the signals that change, or its highlighting algorithm is sometimes failing to indicate which signals changed.

One possibility that occurs to me: The trace is shown after the effect runs, and it contains all the signals read during that execution. This list is then shown using data from before the effect run to show which signals made the effect fire to begin with by highlighting them in cornflower blue. The potential fail might come here: What if the run doesn't read the signal that made the effect fire? Then there's nothing to highlight.

Reproduction

REPL

Instructions

1. Open REPL.
2. Clear the console.
3. Click the "Synchronize Columns" button.
4. Examine the third trace: Nothing is highlighted blue.

Logs

No response

System Info

REPL

Severity

annoyance

[paoloricciuti]

This is a way minimal reproduction

https://svelte.dev/playground/1119fe0a689544d58c0c89f71fdbe016?version=5.15.0

However I feel like this is how it should work. I think you should be more interested about which dependencies your effect actively has rather than "was this dependency dirty when the effect ran".

I fear that if we include something that is not a dependency just to say "this was dirty" might get confusing.

I'll try to see if there's a decent way to add this

[paoloricciuti]

Actually better reproduction even tho is the same problem

https://svelte.dev/playground/32f6a2d5ae114955bf126a27f2457ec5?version=5.15.0

[webJose]

I don't understand your first minimal, but the second one I think I do: The effect changes count, which triggers the effect one more time. This time the effect is read but not changed, so shows up in gray. So what does the coloring actually mean? Is it the signals that changed during the effect's run? Or is it the signals that made the effect run?

My original issue is: I suspected my last effect run. I run the column algorithm in my head and I don't see a reason for the last run. This is why I added the trace. My expectation was that the coloring would tell me which signal or signals triggers this last run, but to my surprise (dismay), there are no blue signals. So the trace is being unhelpful for me. It is not fulfilling its purpose.

[paoloricciuti]

The first minimal is showing an effect rerun where in the end no dependencies where tracked so nothing is shown (but something had to trigger the rerun).

[webJose]

The first minimal is showing an effect rerun where in the end no dependencies where tracked so nothing is shown (but something had to trigger the rerun).

Ok, got it. This confirms my suspicion that the docs are incorrect: What's printed is the list of signals that are read during the run, not the list of signals that made the effect run.

Still, I think that tracing is not fulfilling its purpose: I need to know which signal triggered my last effect, and the list is all gray. I understand that if the signal that triggered the effect is not re-read, then there would be nothing to highlight, and this would be missing information that I wish we could still get. Otherwise my question still goes unanswered. Basically I'm still as I was when I wrote this issue: Either the trace is missing information, or Svelte is running effects when it shouldn't. In my case, I am suspecting the latter, but I agree: That's unlikely. So which signal triggered the last effect of ID parent in my repro?

[paoloricciuti]

So which signal triggered the last effect of ID parent in my repro?

I don't know, I tried to follow a bit but it's jumping into too many hoops for me to follow from the phone.

I'm trying to figure out what the right behavior should be because it really depends on what you are looking for...in your case you want to know which source triggered your effect but in other cases the thing you might look for is "which are the dependencies of my effect?".

[webJose]

I'll explain the logic of the column synchronization algorithm here in case people find it useful.

Column synchronization starts by creating properites with special get/set functions in the POJO's that define the columns. The getter will look for the sync property in the object, and if found, it reads the width from sync.value.witdth. sync.value is $state. If not found, then the width is read from a scoped $state signal created in the createProperty() method. The setter always sets both width's in both $state's.

To actually synchronize the columns visually, the width of the 2 columns must be equal, and its left coordinate must be equal as well. The getter above fulfills very easily the first requirement: The syncColumns() method ensures the same object in both column objects' sync property, so both widths come from the same object, therefore the same width. EZ stuff.

The left coordinate, however, is a different story. Each sync object carries another signal called expectedLeft. Whenever the width of a column changes (be it synchronized or not), its setter will reset expectedLeft to zero. This triggers the effect in the table component for all components that have a synchronized column. The effect's logic will, for synchronized columns ask this: Is the expected left greater than the column's current left? If yes, a filler column that eliminates the difference is synthetized. If not, then the sync object's expectedLeft is set to the column's actual left because this notifies all other tables to recalculate as one of the tables cannot fulfill what was set.

This re-setting of expectedLeft is what should be producing some re-runs in the components that ran before the change. This algorithm always converges so long there is no crossing between column synchronizations.

The following column synchronization pairs would result in an infinte loop:

[webJose]

To further explain why I think Svelte might be running the last effect unnecessarily, the algorithm converges for a synchronization pair when expectedLeft doesn't change after running the effects on all table components involved. In my original post, I see that the effect runs one last time for the parent component, but expectedLeft is not changed in the effect of the child because it immediately converges by adding a filler column.

[paoloricciuti]

To further explain why I think Svelte might be running the last effect unnecessarily, the algorithm converges for a synchronization pair when expectedLeft doesn't change after running the effects on all table components involved. In my original post, I see that the effect runs one last time for the parent component, but expectedLeft is not changed in the effect of the child because it immediately converges by adding a filler column.

$inspect.trace will not help you here because if you look at my minimal example the value of the signal is the "last value" of the signal. So even if at the start of the effect count is 1 since it's increased inside the effect $inspect.trace will show count as 2 in the log.

Exploring this the problem really is that the effect version is set to current_version (which is a global counter increased every time a source or a derived changes). But this means that if you change state within an effect the final version of that effect will be the same of the just-changed signal marking that signal incorrectly as not dirty (for $inspect.trace.

[webJose]

Ok, I think I know where the extra effect run comes from.

Synchronization produces a reset of expectedLeft to zero. Then comes the first run of the parent table's effect. This effect finds that 0 is less than the synchronized column's left coordinate, so it sets expectedLeft to the left coordinate. Without taking into account anything else: The effect started by reading expectedLeft and then changed its value. It is bound to re-run even to just find out that nothing changed.

I suppose this solves that mystery. What's still fuzzy for me is the rules as to when the signal is shown blue vs gray in the trace. It is safe to say that the docs are wrong, so what would be a better documentation for tracing, and what would be an accurate explanation for the highlighting feature?

Paolo can probably explain why the last trace shows all gray signals, so I'll leave him to decide if this behavior is correct or not. We just need to come up with accurate documentation about the highlighting behavior.

[paoloricciuti]

Paolo can probably explain why the last trace shows all gray signals, so I'll leave him to decide if this behavior is correct or not. We just need to come up with accurate documentation about the highlighting behavior.

I kinda already explained it in my last comment but yeah I think there's a slight bug here and maybe some behavioral change to made.

So first thing first is that you will get a log for each signal read in the current run. So if the signal that triggered the effect is not read during this run it will not show up at all.

Secondly: each source/derived has a version based on a global counter, whenever the source/derived changes the counter is increased and the version of that source/derived is set to the increased version. When an effect finishes the version of the effect is set to the current version (without increasing).

Normally when you set a value to a source you increase the version, then the effect run so the version of the source is greater than the version of the effect. When the effect finish they will be equal.

But if you set a variable within the effect that re-triggers the same effect, the version of the effect is set to your version before rerunning so your version is effectively equal (which generally means that that signal did not trigger the effect).

This is the normal flow (when effect is not re triggered)

effect version: 0;
source version 0;
change source;
source version 1;
run effect;
trace check versions and 1 > 0;
effect version 1;

And here's the one when effect is re-triggered

effect version: 0;
source version 0;
change source;
source version 1;
run effect;
trace check versions 1 > 0;
change source;
source version 2;
effect version 2;
run effect;
trace check version 2 > 2;
effect version 2;

[webJose]

Thanks for the explanations. Much appreciated.

For others: source === signal, just in case.

This makes me wonder: Can a utility function like untrack() be created to say "I (an effect or derived once derived's can mutate state) am making this change. Don't run me again for this version of the source."?? That way I can avoid the extra effect re-run on components that already converged its algorithm.

[trueadm]

The documentation needs to be tweaked a bit here.

What $inspect.trace does is trace the reactive graph a given reactive function after it has run. It's not designed to tell you why an effect has changed – it can't do that, as by the time the trace has begun, that information has already been lost.

The colouring of the different properties has a bug in it though – and I believe I have a fix.