Code evaluations are duplicated

[munshkr]

No description provided.

[tmhglnd]

I have noticed this some time as well, where code was posted twice in the flok-repl when I just evaluated once. Don't have any specific steps for reproducing currently, also not sure if it still happened lately. I'll keep an eye out!

[munshkr]

Yes, this still happens.. I think I know what's the problem, it's your own message that gets back at you from the server, and evaluates it (thinking it was from some other user). I need to filter your own messages correctly.

[totalgee]

It's definitely happening here all the time, with SC REPL (both users are getting double evaluations of everything).

[Bubobubobubobubo]

Can confirm that I'm getting this error too! It really makes things weird with my setup. SC is getting confused about it.

[tmhglnd]

I tried to look into this issue but I'm having a hard time and no idea where to look to try and fix this. I've been searching through the code for a while to find from where the actually evaluating is "emitted" to the repl. Sadly there is too little documentation in the code for me to figure out how this actually works. Can you give some pointers/explanation where this can be fixed? Then I'm happy to help, because I like this issue to be resolved.

I've been able to trace that the BaseREPL receives a message with { docID, body, user, mode, from, to } via the pubSubSubscribe.

I have not been able to find how this works in the PubSub class though and also not how this message is send from the web session to the server.

I'm also wondering if you could explain how you develop for Flok packages? Because only the web package has an option to run npm run dev (if I see correctly), how can I work on the Repl and other packages without having to run npm run build every time? Maybe I'm missing something basic here about how Typescript works (for example I see there is a debugModule(), but I also have no idea how to work with that and wasn't able to find documentation about it so far), I usually install some package like watchify to be able to develop without building every time, but I don't see that (or something similar) listed in the dependencies.

[tmhglnd]

@munshkr, a little bump here too, if you find some time :)

[felixroos]

that might be the same issue as this: #299 ?

[Bubobubobubobubo]

This bug also happens with Sardine and other languages I have tried. Only appears when multiple people join the session though. Hard to reproduce when playing/experimenting alone.

[TodePond]

Could this potentially be because of a sync issue where the contents of an editor get duplicated. I've seen times where you get the same code listed out many times. It's sometimes hard to notice it because the duplicated code is way below your currently visible code.

Might be a more general YJS issue.

[felixroos]

while skimming the code, i've noticed the fromMe flag which stops your own window from being evaluated twice:

flok/packages/session/lib/session.ts

Line 373 in 39a05e5

if ((mode === "web" || mode === "webLocal") && fromMe) return;

maybe that flag is sometimes false when it shouldn't be ? just speculation but probably a good point to test

[sqaxomonophonen]

I tried removing the line:

flok/packages/session/lib/session.ts

Line 373 in 39a05e5

if ((mode === "web" || mode === "webLocal") && fromMe) return;

To test what happens if fromMe===false. But the volume stays the same.

I also duplicated this line 4 times to simulate message duplication. No double-volume:

flok/packages/web/src/components/web-target-iframe.tsx

Line 33 in 9630cae

ref.current?.contentWindow?.postMessage(payload, "*");

And also this one 4 times, still no double-volume (although Bubo suggests it's a problem with all langs, not just Strudel):

flok/packages/web/src/routes/frames/strudel.tsx

Line 48 in 9630cae

instance.tryEval(msg);

I was starting to look into how Flok passes new code to Strudel, and I'm still puzzled how Strudel knows which doc to update, but then I read Bubo's comment...

flok/packages/web/src/lib/strudel-wrapper.ts

Line 153 in 39a05e5

const pattern = await this._repl.evaluate(`${code}//${docId}`);

TodePond's suggestion is what I'd look at next, because:

• It matches how it sounds (like duplicating a $:-section).
• It seems like the type of bug that wouldn't care about the language/backend.
• I think I've already seen docs get "corrupted" a couple of times..

Not sure why the problem "corrects itself" later though, but I haven't dived into the server code yet.

[sqaxomonophonen]

The server appears to be a simple "pubsub" so I don't expect we'll find the bug there..

TodePond's theory is still my best bet: that code gets duplicated somehow; $:s("bd")\n becomes $:s("bd")\n$:s("bd")\n

If everybody hears the same "volume-doubling incident" at the same time then I'd also expect to see code duplication in the messages that the server passes around. This should be visible in the network tab ("pubsub" WebSocket traffic). Unfortunately, browsers don't record traffic until you ask them to so you'd have to start recording up-front and "wait" until the problem happens...

If the volume-doubling is only heard by one person then I'd expect the network messages to look normal, while duplication would be seen in the Strudel/etc evals (if we logged them).

Whether it's heard-by-one or heard-by-everybody could be found out if we have multiple independent recordings of a session where it occurs? (or, someone could write // MY VOLUME DOUBLED, DID ANYBODY HEAR IT TOO? and wait for a response? :)

We could also add temporary debug code like console.log()s or store info in window globals. I think I would want to log user- and server-initiated evals separately to collect evidence on the heard-by-one vs heard-by-everybody question. (I can cook up a small PR if this is something we'd like to pursue)

[sqaxomonophonen]

Got a screenshot of "code-doubling" yesterday:

From this session:
https://post.lurk.org/@froos/113738614447214053
Volume-doubling also happened a couple of times independently of this.

[TodePond]

I think one thing we may as well do is bump yjs to the latest version. It gets regular fixes. Not confidence it would help but no harm I dont think

[TodePond]

Here's me bumping yjs
#311

[felixroos]

Got a screenshot of "code-doubling" yesterday: From this session: https://post.lurk.org/@froos/113738614447214053 Volume-doubling also happened a couple of times independently of this.

where does this happen? so its visible in the editor?

[tmhglnd]

Interesting, I've never seen code actually doubling in the editor. Just the OSC-message for the repl being send twice (or more than 2x if more people are active in the session).

[sqaxomonophonen]

Got a screenshot of "code-doubling" yesterday: From this session: https://post.lurk.org/@froos/113738614447214053 Volume-doubling also happened a couple of times independently of this.

where does this happen? so its visible in the editor?

Yes. Here it's visible in the video:
https://youtu.be/SHjM6-dhpwM?t=4281
(bottom-left window)

[felixroos]

Got a screenshot of "code-doubling" yesterday: From this session: https://post.lurk.org/@froos/113738614447214053 Volume-doubling also happened a couple of times independently of this.

where does this happen? so its visible in the editor?

Yes. Here it's visible in the video: https://youtu.be/SHjM6-dhpwM?t=4281 (bottom-left window)

interesting, i haven't had that before.. here's a moment where the volume doubles, but the code stays intact: https://www.youtube.com/watch?v=jdFSmr3koXg&t=3470s (doubling is gone after re-eval). as reported in #299

[felixroos]

Whether it's heard-by-one or heard-by-everybody could be found out if we have multiple independent recordings of a session where it occurs?

recording the next session from 2 machines is a good idea, as we could see if the doubling is synced or not

[TodePond]

Seems like two separate issues. I've definitely seen the "doubled code" issue a lot. Never noticed the "double eval" issue

[Bubobubobubobubo]

I agree, I think that we are chasing two separate issues. I've experienced the double eval but never the doubled code (the opposite compared to @TodePond). The former might be a bug in the backend while the latter appears to be some CodeMirror related issue. I've experienced line/code duplication in the past while dealing with some editor plugins.

[felixroos]

We could also add temporary debug code like console.log()s or store info in window globals. I think I would want to log user- and server-initiated evals separately to collect evidence on the heard-by-one vs heard-by-everybody question. (I can cook up a small PR if this is something we'd like to pursue)

extensive logging seems like the only way to identify the issue. we need to log all server messages then play and see if we hit the bug. probably best to add logging (to a file) on a seperate branch and run locally?

edit: combined with a recording, we can pinpoint when it happens

[sqaxomonophonen]

I wrote a tiny "pubsub logger" script for flok. Requires npm install websocket. Put it in flog.mjs and run it like node flog.mjs todepond to subscribe to the messages for flok.cc/s/todepond. Messages are then logged to the terminal and a file named flok.todepond.log. The idea is you can "attach" it while performing, and then inspect the log if something fishy happens. There's also 2 other websockets that might be worth spying on (like the YJS one), but this one should tell if duplicated code is being "broadcasted".

(edit: it prints both the json message, but also the code blob itself for readability if present)

import fs from 'fs';
if (process.argv.length !== 3) {
   console.error(`Usage: ${process.argv[1]} <session name>`);
   process.exit(1);
}
const session_name = process.argv[2];
import websocket from 'websocket'; // npm install websocket
const client = new websocket.client();
client.on("connect", (conn) => {
   conn.sendUTF(JSON.stringify({
      type:"state",
      payload:{topics:[`session:${session_name}:target:strudel:eval`]}
   }));
   conn.on("message", (msg) => {
      msg = JSON.parse(msg.utf8Data);
      let code = msg.payload && msg.payload.message && msg.payload.message.body || "";
      const SEP="==========================\n";
      const logmsg = SEP+Date()+":\n"+JSON.stringify(msg)+"\n"+code+"\n"+SEP+"\n";
      console.info(logmsg);
      fs.appendFileSync(`flok.${session_name}.log`, logmsg)
   });
});
client.connect("wss://flok.cc/pubsub");