#1071217 Since Debian Bookworm less +F needs 100% of one CPU Core if there are no more Data in Buffer

Package:
less
Source:
less
Description:
pager program similar to more
Submitter:
Juergen Kuri
Date:
2024-05-16 10:33:03 UTC
Severity:
normal
#1071217#5
Date:
2024-05-16 10:28:21 UTC
From:
To:

Since Bookworm I observed this several times, a less +F process constantly in run mode
needing a lot of CPU processing time when there are no more newer data in log file buffer:

USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root       92642  0.0  0.0  37748  6364 ?        S    May15   0:00 sudo
su root       92643  0.0  0.0  37748  1044 ?        Ss   May15   0:00
  \_ sudo su root       92644  0.0  0.0  20528  4328 ?        S    May15
   0:00      \_ su root       92645  0.0  0.0   7320  4248 ?        S  
  May15   0:00          \_ bash root       92649 85.3  0.0   5972  2360
?        R    May15 830:48              \_ less +F bkclientd_debug.log
In that case of zero reads less normally polls every 2 ms if I recall
correctly but here we see no waits (clock_nanosleep()) on zero reads, it
polls every 40 µs: 09:45:34.782289 read(3, "", 1) = 0 <0.000004>
09:45:34.782304 read(3, "", 1) = 0 <0.000013> 09:45:34.782344 read(3,
"", 1) = 0 <0.000014> 09:45:34.782374 read(3, "", 1) = 0 <0.000013>
09:45:34.782404 read(3, "", 1) = 0 <0.000013> 09:45:34.782442 read(3,
"", 1) = 0 <0.000015> 09:45:34.782482 read(3, "", 1) = 0 <0.000004>
09:45:34.782523 read(3, "", 1) = 0 <0.000014> 09:45:34.782562 read(3,
"", 1) = 0 <0.000014> 09:45:34.782589 read(3, "", 1) = 0 <0.000003>
09:45:34.782627 read(3, "", 1) = 0 <0.000014> 09:45:34.782667 read(3,
"", 1) = 0 <0.000004> 09:45:34.782707 read(3, "", 1) = 0 <0.000015>
09:45:34.782747 read(3, "", 1) = 0 <0.000003> 09:45:34.782819 read(3,
"", 1) = 0 <0.000011> 09:45:34.782853 read(3, "", 1) = 0 <0.000003>
09:45:34.782882 read(3, "", 1) = 0 <0.000004> 09:45:34.782924 read(3,
"", 1) = 0 <0.000004> 09:45:34.782964 read(3, "", 1) = 0 <0.000005>
09:45:34.782991 read(3, "", 1) = 0 <0.000014> 09:45:34.783032 read(3,
"", 1) = 0 <0.000014> 09:45:34.783071 read(3, "", 1) = 0 <0.000004>
09:45:34.783100 read(3, "", 1) = 0 <0.000014> 09:45:34.783139 read(3,
"", 1) = 0 <0.000014> 09:45:34.783178 read(3, "", 1) = 0 <0.000019>
09:45:34.783224 read(3, "", 1) = 0 <0.000014> 09:45:34.783264 read(3,
"", 1) = 0 <0.000014> 09:45:34.783303 read(3, "", 1) = 0 <0.000014>
09:45:34.783342 read(3, "", 1) = 0 <0.000015> 09:45:34.783385 read(3,
"", 1) = 0 <0.000015> 09:45:34.783425 read(3, "", 1) = 0 <0.000014> An
intact less +F has these nano_sleep() - poll() sequences between the
read() which we don't have anymore for less delivered with Bookworm:
12:20:19.583389 read(4, "", 4672) = 0 <0.000005> 12:20:19.583406
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=2000000}, NULL) =
0 <0.002061> 12:20:19.585484 poll([{fd=3, events=POLLIN}], 1, 0) = 0
(Timeout) <0.000006> 12:20:19.585507 poll([{fd=4,
events=POLLERR|POLLHUP}], 1, 0) = 0 (Timeout) <0.000005> 12:20:19.585527
read(4, "", 4672) = 0 <0.000005> 12:20:19.585545
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=2000000}, NULL) =
0 <0.002093> 12:20:19.587658 poll([{fd=3, events=POLLIN}], 1, 0) = 0
(Timeout) <0.000008> 12:20:19.587684 poll([{fd=4,
events=POLLERR|POLLHUP}], 1, 0) = 0 (Timeout) <0.000006> 12:20:19.587707
read(4, "", 4672) = 0 <0.000007> 12:20:19.587729
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=2000000}, NULL) =
0 <0.002073> 12:20:19.589843 poll([{fd=3, events=POLLIN}], 1, 0) = 0
(Timeout) <0.000010> 12:20:19.589898 poll([{fd=4,
events=POLLERR|POLLHUP}], 1, 0) = 0 (Timeout) <0.000010> 12:20:19.589929
read(4, "", 4672) = 0 <0.000007> 12:20:19.589963
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=2000000}, NULL) =
0 <0.002102> 12:20:19.592101 poll([{fd=3, events=POLLIN}], 1, 0) = 0
(Timeout) <0.000005> 12:20:19.592127 poll([{fd=4,
events=POLLERR|POLLHUP}], 1, 0) = 0 (Timeout) <0.000005> 12:20:19.592146
read(4, "", 4672) = 0 <0.000005> 12:20:19.592162
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=2000000}, NULL) =
0 <0.002099> 12:20:19.594299 poll([{fd=3, events=POLLIN}], 1, 0) = 0
(Timeout) <0.000009>