ad-si / TaskLite

The CLI task manager for power users
https://tasklite.org
GNU Affero General Public License v3.0
229 stars 13 forks source link

tasklite polls stdin for 0.5 seconds before printing tasks list #88

Open vbmithr opened 3 weeks ago

vbmithr commented 3 weeks ago
15:48:28.083214 poll([{fd=0, events=POLLIN}], 1, 0) = 0 (Timeout)
15:48:28.083246 pselect6(1, [0], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
15:48:28.083283 pselect6(1, [0], [], NULL, {tv_sec=0, tv_nsec=499999000}, NULL) = 0 (Timeout)
15:48:28.584388 futex(0x2d95228, FUTEX_WAKE_PRIVATE, 1) = 1

Haven't checked the code for why there is this waiting time, but it's kinda annoying.

ad-si commented 3 weeks ago

Mh, maybe because of the hooks: https://tasklite.org/cli/hooks/main

But I don't think I have any polling going on my system (macOS). Might be a Linux problem? How can I reproduce this output?

vbmithr commented 3 weeks ago

trace.log

Just run tasklite without arguments. You can see in logs

10:46:34.103099 poll([{fd=0, events=POLLIN}], 1, 0) = 0 (Timeout)
10:46:34.103185 pselect6(1, [0], [], NULL, {tv_sec=0, tv_nsec=0}, NULL) = 0 (Timeout)
10:46:34.103289 pselect6(1, [0], [], NULL, {tv_sec=0, tv_nsec=499999000}, NULL) = 0 (Timeout)
10:46:34.604083 futex(0x2e21d68, FUTEX_WAKE_PRIVATE, 1) = 1
10:46:34.604233 futex(0x2e21d00, FUTEX_WAKE_PRIVATE, 1) = 1
10:46:34.604368 ioctl(0, TCGETS, {c_iflag=ICRNL|IXON, c_oflag=NL0|CR0|TAB0|BS0|VT0|FF0|OPOST|ONLCR, c_cflag=B38400|CS8|
CREAD, c_lflag=ISIG|ECHOE|ECHOK|IEXTEN|ECHOCTL|ECHOKE, ...}) = 0

It happens only on listing commands.

ad-si commented 1 week ago

What did you use to generate the trace.log file? strace?

I just checked the profiling output of GHC (https://downloads.haskell.org/ghc/9.6-latest/docs/users_guide/profiling.html), but couldn't see anything suspicious.

If you have an idea how this could be debugged, any help would be highly appreciated!

vbmithr commented 1 week ago

strace yes. I tried to understand too but the code is a bit cryptic for me.

vbmithr commented 1 week ago

Given the trace, the lag happens between a stat to main.db-wal and main.db. As if the library tried to poll stdin in between…?

vbmithr commented 1 week ago

tl.log

ad-si commented 1 week ago

If SQLite makes a request in WAL mode it first checks main.db-wal (basically a cache) and then main.db for the data. So it might be a bug in the SQLite library? => https://github.com/IreneKnapp/direct-sqlite But I can't imagine why it would poll stdin in between.