"sleep 1" sleeps for 15+ seconds

Asked by Geoff Pendery on 2007-08-24

I originally came across the problem in perl, but have managed to determine it's happening when I run the standard sleep util from bash as well.

When I enter "sleep 1" or "sleep 2" or "sleep 5", the box stalls for 15-30 seconds, not 1 or 2 or 5 seconds.
"w" shows a load average of 0.00 0.00 0.00
It's a Pentium 4, 2.8 GHz box doing practically nothing else.
I'm accessing it by SSH, and it's running Ubuntu server, not desktop. No X installed.

I'm not sure how to troubleshoot further. I've resorted to downloading source packages, in the hopes that I can study the implementation of "sleep" closer, but in the meantime I'm hoping someone has seen this before and will say "oh, you need to change a setting in /etc/foo in order to detect your CPU clock correctly" or something.

Anybody?

Question information

Language:
English Edit question
Status:
Solved
For:
Ubuntu Edit question
Assignee:
No assignee Edit question
Solved by:
Geoff Pendery
Solved:
2007-08-27
Last query:
2007-08-27
Last reply:
2007-08-27
Geoff Pendery (geoff-pendery) said : #1

When I run "top", nothing happens.
It just hangs there, printing nothing, until I kill it.

I would not be surprised to find these two problems are related.

What is the routput of the following command:-

time sleep 1

For example:-

alan@wopr:~$ time sleep 1

real 0m1.009s
user 0m0.004s
sys 0m0.000s

Is there anything odd when you run "dmesg"?

Geoff Pendery (geoff-pendery) said : #3

Thanks for the response.
Yeah, when I first discovered the issue, I ran five trials each of "time sleep 1", "time sleep 2", "time sleep 5", "time sleep 10"

I just re-ran them with the following results:
$ time sleep 1

real 0m12.936s
user 0m0.010s
sys 0m0.000s

Results listed as "real" time values on each trial:
sleep 1: 12.936, 28.829, 29.835, 29.711, 29.765
sleep 2: 27.871, 28.682, 4.167, 26.326, 30.535
sleep 5: 24.950, 10.005, 27.987, 18.930, 27.093
sleep 10: 20.341, 30.039, 22.939, 39.304, 23.067

Note that sleep 1 gets as low as 12.9s, sleep 2 gets as low as 4.2s, and that all seem to average around 27s.

I'm not familiar with the output of dmesg, so I'm not sure what to look for in terms of "odd"
The counter on the left (seconds?) is at 0.0 for a while, printing low-level startup messages. It jumps suddenly to 30.797114, saying it built 1 zonelist. Many startup messages continue, ticking up from 30 to 51.818240 (eth0: no IPv6 routers present) then it jumps way ahead to 234381.362106, with:
[234381.362106] ISO 9660 Extensions: Microsoft Joliet Level 3
[234381.445086] ISO 9660 Extensions: RRIP_1991A
[240043.643618] ISO 9660 Extensions: Microsoft Joliet Level 3
[240043.720492] ISO 9660 Extensions: RRIP_1991A
[517178.347413] ISO 9660 Extensions: Microsoft Joliet Level 3
[517178.422068] ISO 9660 Extensions: RRIP_1991A

I appreciate your interest, and if you have anything else you want me to check or try, just let me know.

Thanks.

Thomas Butter (tbutter) said : #4

Hi,

are you using ubuntu inside a virtual machine like vmware?

Geoff Pendery (geoff-pendery) said : #5

Nope.

It's installed on an IBM ThinkCentre workstation, Pentium 4 2.8 GHz, 1 Gig of DDR RAM, FSB 200 MHz.

Geoff Pendery (geoff-pendery) said : #6

Two more tests, to rule stuff out:
memtest came back clean, and chkrootkit came back clean (although admittedly, I ran it from the machine, so there's a remote possibility that the rootkit was defending itself from chkrootkit)

Geoff Pendery (geoff-pendery) said : #7

So, in the process of running the memtest and confirming that Hyperthreading was disabled (it was) I had to reboot the machine.
This has caused the problem to vanish.

sleep 2 now takes 2 seconds, top works fine.

This is a frustrating resolution to the problem, and I hope it doesn't return.
Thanks to those who tried to help, I'll post more updates if the problem recurs.