Code-server: heartbeat file modify date keeps getting updated

[OliverwengFiltered]

• Web Browser: Chrome latest, mac os latest.
• Local OS: mac os latest
• Remote OS: Google VM Compute Engine
• Remote Architecture: Ubuntu 20
• code-server --version: 3.5.0

the heartbeat file modify date seems acting a bit weird.

if you open the code server and then close the code server in a relatively short time window, and then ssh into the vm machine to check out the heartbeat file modify date, you will start noticing that the heartbeat file modify date keeps getting updated every minute, but there is no active browser connection to code server.

wondering if anyone where had this issue ?

[code-asher]

If you run code-server with --log trace it will report how many connections it thinks are still connected. Could you do that and verify that it reports > 0 when no browser windows are open?

I'll try to replicate as well as soon as I can.

[OliverwengFiltered]

my service starts with systemctl start code-server@$USER,

I modified the code-server.service file to include --log trace located at /usr/lib/systemd/system/user/

and restarted the systemctl , it seems still don't see any relevant log shows up when I do journalctl -u code-server

I do see some extension logs located at .../.local/share/code-server/logs/...

[OliverwengFiltered]

Hi @code-asher

I'm wondering if you can reproduce the same issue ?

[code-asher]

Odd, there should definitely be stdout. We also log stdout to ~/.local/share/code-server/coder-logs so you could check that.

I ran 3.5.0 but wasn't able to replicate the issue (Firefox & Chrome running locally on Linux):

# < connected here
[2020-09-28T22:18:24.774Z] trace 2 active connections
[2020-09-28T22:18:24.775Z] trace heartbeat
[server] received ping {"proxies":3}
[server] received ping {"proxies":3}
[2020-09-28T22:19:24.780Z] trace 2 active connections
[2020-09-28T22:19:24.780Z] trace heartbeat
[server] received ping {"proxies":3}
# < disconnected here
[server] disconnected from client {"proxies":3}
[2020-09-28T22:20:24.785Z] trace 0 active connections
# < notice no "trace heartbeat" line

I also double-checked the heartbeat file and the timestamp was at 22:19 which matches with the last heartbeat log.

[OliverwengFiltered]

Hi @code-asher
it's kinda sporadic.
but the issue still exists for sure.
when all browsers closed, it seems still one active connection, and then I open one session it says 2 active connections.
and then I close the browser again, it turn back to 0.
PFA

Thanks,
any ideas in terms of what's going on ?

[OliverwengFiltered]

reproduced again.

PFA for the image to get some more insights.

Thanks

[code-asher]

Ah, there will be two connections per page since VS Code makes two
websocket connections. So with that in mind it looks like things are
working as expected, at least as far as these logs go.

[OliverwengFiltered]

Hi @code-asher
so I see what you meant, and after a few times retry, I reproduced again. and this logs seems a bit different from previous ones.
what happened was, when I created a new instance and opened vscode it asks me to reload window because it tries to reconnect. and then I did click reload window and then everything back to normal, after a few minutes, I turned off browser tab, and never opened the vscode link again.

PFA for the log.

Thanks
-Oliver

[code-asher]

Ah yeah it definitely looks like some connection isn't closing.

I tried to replicate on 3.5.0 but I'm not having much luck. Here's what
I did based on your comment, do these look like the right steps?

1. Start code-server
2. Open code-server in the browser
3. Restart code-server
4. Click "reconnect now" or wait for VS Code to reconnect, it will fail
5. Click "reload window"
6. Once VS Code has connected, close the VS Code tab

Once I do these steps I get this for the next heartbeat:

[2020-10-16T15:48:13.213Z] trace 0 active connections

I tried it a few times but no luck yet.

It's also interesting that you get four connections at one point! Very
strange.

Do you know if this happens if you close your browser entirely?

[OliverwengFiltered]

Hi @code-asher

so I just closed the whole browser chrome entirely, and after that, when I check the log, it's still updating every minute.

I guess to reproduce, you have to have a new VM instance and then put the link in a iframe to open it when VM instance code server is ready.

I noticed that for any code server vscode that had this issue and then If I open the vscode again, it will most likely update the connections to its correct amount and then if you close the browser tab, the connection will back to 0.

[code-asher]

Hmm that's very interesting. I'll try an iframe and maybe I can spin up
some VMs to test as well. I think what I'll do in the meantime is add
some more detailed logging which will hopefully help figure out what
connection isn't getting closed.

[OliverwengFiltered]

@code-asher
sounds good, also, I can give you access to the VM machine which has the 1 active connection issue if you give me your public key if that helps. my email is [email protected].

Thanks

[nhooyr]

Hi @OliverwengFiltered, can you try to reproduce this on v3.7.1?

We've made major changes to the HTTP layer so it may be fixed.

[OliverwengFiltered]

Hi @nhooyr ,
will try and update you.

[OliverwengFiltered]

Hi @nhooyr

Curious, do you happen to know about when this one will be resolved ?

https://github.com/cdr/code-server/issues/2274

I can't upgrade to v3.7.1 for my users because of the above issue.

[code-asher]

I'm going to tackle #2274 after the update to VS Code 1.51.1 which I'm
hoping to finish this week.

[OliverwengFiltered]

just switched to 3.7.3, so far so good, not seeing this issue anymore on v 3.7.3
I think it can be closed. will re-open if this issue shows up again.
@code-asher @nhooyr
great work, folks.

[nhooyr]

That's awesome to hear!! 🎊

[OliverwengFiltered]

Hi @nhooyr @code-asher

unfortunately, it happens on v3.7.3 too, I didn't have the enough data to draw a conclusion back then.

but all our system has upgraded to v3.7.3 a week ago, and we still see this happens occasionally. Exactly same logging "trace 1 active connection" .

Thanks
-Oliver

[nhooyr]

Nooo :(

Are you absolutely positive there isn't an active connection? You can check with sudo ss -tpn