Hi I notice huge difference in tail of busybox comparing with util-linux busybox. tail -f, for example, from util-linux on increasing large log (around 5GB) with busybox, it takes around one minute just to show up last lines. Probably it is possible to change something in algorithm? Here is strace comparison for interesting parts util-linux open("/var/log/messages", O_RDONLY) = 3 fstat(3, {st_mode=S_IFREG|0644, st_size=13752879, ...}) = 0 lseek(3, 0, SEEK_CUR) = 0 lseek(3, 0, SEEK_END) = 13752879 lseek(3, 13746176, SEEK_SET) = 13746176 read(3, "ast -9, max_rtt 582\nAug 8 17:09:56 sunfire-1 distnetmond: <insatgx> 12 max jitter, last -9, max_rtt 582\nAug 8 17:09:56 sunfire-1 distnetmond: <greeks> 12 max jitter fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 10), ...}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcb91347000 write(1, "Aug 8 17:10:10 sunfire-1 distnetmond: <greeks> 20 max jitter, last 1, max_rtt 444\n"..., 83) = 83 write(1, "Aug 8 17:10:10 sunfire-1 distnetmond: <greeks> 20 max jitter, last 6, max_rtt 444\n"..., 83) = 83 write(1, "Aug 8 17:10:11 sunfire-1 distnetmond: <insatgx> 2 max jitter, last -2, max_rtt 427\n"..., 84) = 84 write(1, "Aug 8 17:10:11 sunfire-1 distnetmond: <greeks> 20 max jitter, last -12, max_rtt 461\n"..., 85) = 85 write(1, "Aug 8 17:10:11 sunfire-1 distnetmond: <insatgx> 2 max jitter, last -2, max_rtt 427\n"..., 84) = 84 write(1, "Aug 8 17:10:11 sunfire-1 distnetmond: <greeks> 21 max jitter, last -13, max_rtt 461\n"..., 85) = 85 write(1, "Aug 8 17:10:12 sunfire-1 distnetmond: <insatgx> 2 max jitter, last -2, max_rtt 444\n"..., 84) = 84 write(1, "Aug 8 17:10:12 sunfire-1 distnetmond: <greeks> 21 max jitter, last -4, max_rtt 461\n"..., 84) = 84 write(1, "Aug 8 17:10:12 sunfire-1 distnetmond: <insatgx> 2 max jitter, last -2, max_rtt 444\n"..., 84) = 84 write(1, "Aug 8 17:10:12 sunfire-1 distnetmond: <greeks> 21 max jitter, last -13, max_rtt 461\n"..., 85) = 85 read(3, ""..., 0) = 0 fstat(3, {st_mode=S_IFREG|0644, st_size=13752879, ...}) = 0 fcntl(3, F_GETFL) = 0x8000 (flags O_RDONLY|O_LARGEFILE) fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 0 fstat(3, {st_mode=S_IFREG|0644, st_size=13752879, ...}) = 0 clock_gettime(CLOCK_MONOTONIC, {255234, 516342978}) = 0 nanosleep({1, 0}, NULL) = 0 clock_gettime(CLOCK_MONOTONIC, {255235, 516520072}) = 0 fstat(3, {st_mode=S_IFREG|0644, st_size=13753046, ...}) = 0 read(3, "Aug 8 17:10:13 sunfire-1 distnetmond: <insatgx> 2 max jitter, last 0, max_rtt 444\nAug 8 17:10:13 sunfire-1 distnetmond: <greeks> 21 max jitter, last -9, max_rtt 461\ write(1, "Aug 8 17:10:13 sunfire-1 distnetmond: <insatgx> 2 max jitter, last 0, max_rtt 444\nAug 8 17:10:13 sunfire-1 distnetmond: <greeks> 21 max jitter, last -9, max_rtt 461 read(3, ""..., 8192) = 0 fstat(3, {st_mode=S_IFREG|0644, st_size=13753046, ...}) = 0 clock_gettime(CLOCK_MONOTONIC, {255235, 516822345}) = 0 nanosleep({1, 0}, <unfinished ...> busybox open("/var/log/messages", O_RDONLY) = 3 lseek(3, 0, SEEK_CUR) = 0 fstat(3, {st_mode=S_IFREG|0644, st_size=13749328, ...}) = 0 read(3, "Aug 8 06:14:57 sunfire-1 syslog-ng[4507]: Configuration reload request received, reloading configuration;\nAug 8 06:14:57 sunfire-1 distnetmond: <insatgx> 19 max jitt lseek(3, 0, SEEK_CUR) = 8192 fstat(3, {st_mode=S_IFREG|0644, st_size=13749328, ...}) = 0 read(3, " 8 06:15:19 sunfire-1 distnetmond: <insatgx> 29 max jitter, last -15, max_rtt 377\nAug 8 06:15:19 sunfire-1 distnetmond: <greeks> 8 max jitter, last -5, max_rtt 400\nA lseek(3, 0, SEEK_CUR) = 16384 fstat(3, {st_mode=S_IFREG|0644, st_size=13749328, ...}) = 0 read(3, "nd: <insatgx> 10 max jitter, last -9, max_rtt 380\nAug 8 06:15:42 sunfire-1 distnetmond: <greeks> 2 max jitter, last -2, max_rtt 403\nAug 8 06:15:43 sunfire-1 distnet lseek(3, 0, SEEK_CUR) = 24576 fstat(3, {st_mode=S_IFREG|0644, st_size=13749328, ...}) = 0 read(3, "06:16:05 sunfire-1 distnetmond: <greeks> 13 max jitter, last -12, max_rtt 401\nAug 8 06:16:06 sunfire-1 distnetmond: <insatgx> 8 max jitter, last -7, max_rtt 380\nAug lseek(3, 0, SEEK_CUR) = 32781 fstat(3, {st_mode=S_IFREG|0644, st_size=13749328, ...}) = 0 read(3, " jitter, last -10, max_rtt 401\nAug 8 06:16:29 sunfire-1 distnetmond: <insatgx> 5 max jitter, last -5, max_rtt 379\nAug 8 06:16:29 sunfire-1 distnetmond: <greeks> 12 lseek(3, 0, SEEK_CUR) = 40973 I can attach full strace log
Created attachment 589 [details] FIx Please try this patch.
Patch fixing problem completely. It didn't apply to git nor stable version, so i had to adapt it, but seems works fine after that. Here is some numbers Proxy-Karam-Main ~ # time tail -n 1 /var/log/squid/access.log ^CCommand terminated by signal 2 real 3m 18.09s user 0m 36.04s sys 0m 25.23s New version Proxy-Karam-Main ~ # time ./busybox tail -n 1 /var/log/squid/access.log 1249886795.283 941 10.0.1.35 TCP_MISS/200 375 POST http://207.46.110.50/gateway/gateway.dll?Action=poll&SessionID=1742306031.1067981419 - DIRECT/207.46.110.50 application/x-msn-messenger real 0m 0.00s user 0m 0.00s sys 0m 0.00s