Skip to content

Improve kernel boot checking on the desktop #8929

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
3 tasks done
qingtian805 opened this issue Aug 8, 2023 · 7 comments
Closed
3 tasks done

Improve kernel boot checking on the desktop #8929

qingtian805 opened this issue Aug 8, 2023 · 7 comments
Assignees
Milestone

Comments

@qingtian805
Copy link

qingtian805 commented Aug 8, 2023

Linux 系统上检查内核时间过短

Is there an existing issue for this?

  • I have searched the existing issues

Can the issue be reproduced with the default theme (daylight/midnight)?

  • I was able to reproduce the issue with the default theme

Could the issue be due to extensions?

  • I've ruled out the possibility that the extension is causing the problem.

Describe the problem

在Linux系统上遇到了获取内核端口失败的情况,日志显示前端等待了Kernel 3秒时间,但核心3秒后才刚开始启动。
Issue #7473 是一个类似的问题,但我的日志中15次尝试似乎被挤压在不到3秒的时间内,而非 #7473 中的15秒
我的系统运行在一个较为缓慢的硬盘上,不排除因此导致内核启动缓慢。
2.9.9也出现了此问题,内核启动提前了一些,但依然正好在前端等待结束时才启动完毕。日志更改为2.9.9的日志。

Siyuan app failed to get kernel port on linux. My log shows that Siyuan app only waits 3 seconds for the kernel to boot up. But kernel just started to boot at the same time Siyuan app stop waitting.
Issue #7473 is a similar problem but my log shows 15 tries are done within only 3 seconds, but not 15 seconds.
BTW, my system is running on a slow hard drive, could that be a reason?
I just updated to 2.9.9, new log shows kernel started to boot earlier but still not booted after Siyuan app stoped to wait. Log updated to 2.9.9.

Expected result

等待内核的时间应该是15s而不是3s。

Siyuan app should waits kernel to boot for 15 seconds but not 3 seconds on linux.

Screenshot or screen recording presentation

No response

Version environment

- Version: 2.9.8 Appimage(AUR Package)
- Operating System: Arch Linux

Log file

I 2023/08/08 14:39:13 working.go:116:
___ ___ ___ ___
/ /\ ___ ___ //\ / /\ //
/ /:/_ / /\ //| \ :\ / /::\ \ :
/ /:/ /\ / /:/ | |:| \ :\ / /:/:\ \ :
/ /:/ /::\ /
/::\ | |:| ___ \ :\ / /://::\ __:
//:/ /:/:\ _/:_ ||:| /
/\ __:\ /
/:/ /:/:\ /_/::::::::
\ :/:/
/:/ \ :/\ //::::\ \ :\ / /:/ \ :/:// \ :~~/
\ ::/ /:/ _::/ ~:\ \ :\ /:/ \ ::/ \ :\ ~~~
_
/ /:/ //:/ \ :\ \ :/:/ \ :\ \ :
/
/:/ _/ _/ \ ::/ \ :\ \ :
_/ _/ _/ _/
I 2023/08/08 14:39:13 runtime.go:74: kernel is booting:
* ver [2.9.9]
* arch [amd64]
* os [arch]
* pid [13971]
* runtime mode [prod]
* working directory [/tmp/.mount_siyuanxzGE0w/resources]
* read only [false]
* container [std]
* database [ver=20220501]
* workspace directory [/run/media/kevin/Personal/qingt/App Data/SiYuan]
I 2023/08/08 14:39:13 conf.go:232: upgraded from version [2.9.8] to [2.9.9]
I 2023/08/08 14:39:13 conf.go:383: user has enabled [Automatically upload error messages and diagnostic data]
I 2023/08/08 14:39:13 runtime.go:128: use network proxy [system]
I 2023/08/08 14:39:13 serve.go:119: kernel [pid=13971] http server [0.0.0.0:42503] is booting
I 2023/08/08 14:39:13 pandoc.go:132: built-in pandoc [ver=2.19.2, bin=/run/media/kevin/Personal/qingt/App Data/SiYuan/temp/pandoc/bin/pandoc]
I 2023/08/08 14:39:13 conf.go:927: pandoc initialized, set pandoc bin to [/run/media/kevin/Personal/qingt/App Data/SiYuan/temp/pandoc/bin/pandoc]
I 2023/08/08 14:39:14 blocktree.go:446: read block tree [1.2 MB] to [/run/media/kevin/Personal/qingt/App Data/SiYuan/temp/blocktree], elapsed [0.01s]
I 2023/08/08 14:39:14 conf.go:710: database size [20 MB], tree/block count [139/3910]
I 2023/08/08 14:39:14 working.go:154: kernel booted
I 2023/08/08 14:39:14 box.go:79: auto stat [trees=139, blocks=3910, dataSize=219 MB, assetsSize=15 MB]
I 2023/08/08 14:39:14 disk.go:33: disk usage [total=500 GB, used=163 GB, free=338 GB]
I 2023/08/08 14:39:14 serve.go:132: reverse proxy server [0.0.0.0:6806] is booting
E 2023/08/08 14:39:26 working.go:420: lock workspace [/run/media/kevin/Personal/qingt/App Data/SiYuan] failed
I 2023/08/08 14:39:49 process.go:36: received os signal [terminated], exit kernel process now
I 2023/08/08 14:39:49 conf.go:476: exiting kernel [force=false, execInstallPkg=1]
I 2023/08/08 14:39:49 database.go:1195: closed database
I 2023/08/08 14:39:49 conf.go:867: cleared workspace temp
I 2023/08/08 14:39:50 conf.go:522: exited kernel
I 2023/08/08 14:39:50 sync.go:660: sync websocket closed

More information

// 对应的app.log日志,时间慢8小时

2023-08-08 06:39:12 got kernel port [42503]
2023-08-08 06:39:12 ui version [2.9.9], booting kernel [/tmp/.mount_siyuanxzGE0w/resources/kernel/SiYuan-Kernel --port 42503 --wd /tmp/.mount_siyuanxzGE0w/resources]
2023-08-08 06:39:12 booted kernel process [pid=13971, port=42503]
2023-08-08 06:39:12 checking kernel version
2023-08-08 06:39:12 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:12 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:12 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:12 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:12 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:13 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:13 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:13 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:13 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:13 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:13 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:13 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:13 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:13 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 06:39:14 get kernel ver failed
2023-08-08 06:39:14 got kernel version [2.9.9]

@qingtian805
Copy link
Author

qingtian805 commented Aug 8, 2023

// 相同的工作区,Windows版本至少会等待内核7秒
// With the same workspace, Windows version will waits for at least 7 seconds
2023-08-08 07:02:25 checking kernel version
2023-08-08 07:02:27 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 07:02:28 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 07:02:30 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 07:02:30 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 07:02:32 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 07:02:32 get kernel version failed: net::ERR_CONNECTION_REFUSED
2023-08-08 07:02:32 got kernel version [2.9.9]

@nekrondev
Copy link
Contributor

Please check if in your configuration directory (/run/media/kevin/Personal/qingt/App Data/SiYuan) is some kind of .lockfile located and remove that file before starting SiYuan.

@qingtian805
Copy link
Author

@nekrondev Thanks for your help. But my problem is that Siyuan app runs on linux will only waits kernel for only 3 seconds (maybe shorter) to boot up. That`s much shorter than Windows on which Siyuan app will waits more than 10 seconds (mentioned in #7473 ). Thanks again and sorry for my poor English.

@qingtian805 qingtian805 changed the title 获取内核端口失败 Linux 系统上检查内核时间过短 Aug 8, 2023
@nekrondev
Copy link
Contributor

nekrondev commented Aug 8, 2023

@qingtian805 No problem, your English is fine (I'm also no native speaker so we are in the same boat) ... sorry I think I misunderstood your issue then. Yes the timeout for finally aborting the kernel version check is too short but then it resolves after the final 2023-08-08 06:39:14 get kernel ver failed line returning the kernel version.

So if I look at

siyuan/app/electron/main.js

Lines 510 to 531 in 95c0955

writeLog("checking kernel version");
while (!gotVersion && count < 15) {
try {
const apiResult = await net.fetch(getServer() + "/api/system/version");
apiData = await apiResult.json();
gotVersion = true;
bootWindow.setResizable(false);
bootWindow.loadURL(getServer() + "/appearance/boot/index.html");
bootWindow.show();
} catch (e) {
writeLog("get kernel version failed: " + e.message);
await sleep(100);
} finally {
count++;
if (14 < count) {
writeLog("get kernel ver failed");
showErrorWindow("⚠️ 获取内核服务端口失败 Failed to get kernel serve port", "<div>获取内核服务端口失败,请确保程序拥有网络权限并不受防火墙和杀毒软件阻止。</div><div>Failed to get kernel serve port, please make sure the program has network permissions and is not blocked by firewalls and antivirus software.</div>");
bootWindow.destroy();
resolve(false);
}
}
}

SiYuan electron UI tries to fetch the kernel version 14 times at max waiting for 100ms inbetween failed attempts. That means after 1.5s (if there would be no network latency) the frontend displays some error message. However if you have a look at your Windows log you see 6 attempts to fetch the version that took 7 seconds to complete. That means Windows kernel service has some local networking delay of 7000ms - 6*100ms = 6400ms.

In contrast the Linux-based installation had 14 failed version fetch attempts within 2s, i.e. networking delay is much shorter on Linux than on Windows (2000ms - 14*100ms = 600ms).

The networking stack is based on your operating system and only used by Electrons network bindings. That means its operating system dependent and could work differently based on the stacks implementation. Maybe the Electron fetch-request on Windows uses some Window-internal network timeout for completing the request with an error that is not applied when accessed on Linux.

I think the only valid option to get this behavior in sync between Linux and Windows systems would be to use the web socket connection to push some "system is ready" message that would afterwards start fetching the API and doing initial booting the application. The current solutions behavior is basically a race condition between frontend and backend that needs to be synced.

@88250
Copy link
Member

88250 commented Aug 8, 2023

In the next version, we will change sleep(100) to sleep(200) to see if this problem can be solved.

The premise of the websocket notification mentioned by @nekrondev is to establish a connection with the kernel. If the connection can be established, it means that the kernel is started. In fact, this is the purpose of this part of the retry connection code.

@88250 88250 self-assigned this Aug 8, 2023
@88250 88250 added this to the 2.10.0 milestone Aug 8, 2023
@88250 88250 changed the title Linux 系统上检查内核时间过短 Improve kernel boot checking on the desktop Aug 8, 2023
88250 added a commit that referenced this issue Aug 8, 2023

Verified

This commit was signed with the committer’s verified signature.
@88250 88250 closed this as completed Aug 8, 2023
@qingtian805
Copy link
Author

qingtian805 commented Aug 18, 2023

Just a feed back:
Wating time is extended to around 5s (about three tries per second), seems to be fine for now.
Also, I made some capture by wireshark on SiYuan 2.10.0. I found that windows will retransmite SYN package when establishing TCP connection 3 or 4 times with a 200ms delay between each retransmition, causing 600ms or 800ms delay.

Capture file:
captures_cut.zip

@nekrondev
Copy link
Contributor

@qingtian805 Thanks for your analysis! This makes it clear why there is different behavior between Linux and Windows OS systems.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants