Skip to content
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

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

Open
vbmithr opened this issue Nov 2, 2024 · 7 comments
Open

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

vbmithr opened this issue Nov 2, 2024 · 7 comments
Labels
bug Something isn't working

Comments

@vbmithr
Copy link

vbmithr commented Nov 2, 2024

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.

@vbmithr vbmithr changed the title tasklite polls stdin for 0.5 seconds before printing task lists tasklite polls stdin for 0.5 seconds before printing tasks list Nov 2, 2024
@ad-si
Copy link
Owner

ad-si commented Nov 4, 2024

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
Copy link
Author

vbmithr commented Nov 4, 2024

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 ad-si added the bug Something isn't working label Nov 4, 2024
@ad-si
Copy link
Owner

ad-si commented Nov 20, 2024

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
Copy link
Author

vbmithr commented Nov 20, 2024

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

@vbmithr
Copy link
Author

vbmithr commented Nov 20, 2024

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
Copy link
Author

vbmithr commented Nov 20, 2024

tl.log

@ad-si
Copy link
Owner

ad-si commented Nov 20, 2024

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants