Bug#408879: /bin/ps: TIME drifted
this time with the right email alias. On Sun, Jan 3, 2016 at 1:01 PM Craig Smallwrote: > Hello Paul, > I'm chasing up old procps bugs and noticed this one is still opened. > It's been a long way since a 2.6 kernel and 3.2.x procps, wondering > if you still get your odd start times? > > - Craig > -- > Craig Small (@smallsees) http://enc.com.au/ csmall at : enc.com.au > Debian GNU/Linux http://www.debian.org/ csmall at : debian.org > GPG fingerprint:5D2F B320 B825 D939 04D2 0519 3938 F96B DF50 FEA5 >
Bug#408879: /bin/ps: TIME drifted
Hello Paul, I'm chasing up old procps bugs and noticed this one is still opened. It's been a long way since a 2.6 kernel and 3.2.x procps, wondering if you still get your odd start times? - Craig -- Craig Small (@smallsees) http://enc.com.au/ csmall at : enc.com.au Debian GNU/Linux http://www.debian.org/ csmall at : debian.org GPG fingerprint:5D2F B320 B825 D939 04D2 0519 3938 F96B DF50 FEA5
Bug#408879: /bin/ps: TIME drifted
On Mon, Jan 30, 2012 at 12:06:27PM +1100, paul.sz...@sydney.edu.au wrote: Testing this old thing again at squeeze 6.0.4 with 2.6.32 kernel, can still reproduce, the long command in previous message shows: Hi Paul, Thanks for letting me know this is still a problem. The only thing is, I couldn't see which version of procps you were using. We've had a lot of changes in the 3.3.x versions. Is it always just a second earlier? That is what I'm noticing. The relevant code is: t = getbtime() + pp-start_time / Hertz; getbtime is basically 'grep btime /proc/stat' start_time comes from column 23 of /proc/PID/stat divided by jiffies. It is looking like a kernel problem, or more specifically a procfs output problem. - Craig -- Craig Small VK2XLZ http://enc.com.au/ csmall at : enc.com.au Debian GNU/Linux http://www.debian.org/ csmall at : debian.org GPG fingerprint: 5D2F B320 B825 D939 04D2 0519 3938 F96B DF50 FEA5 -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#408879: /bin/ps: TIME drifted
Dear Craig, I couldn't see which version of procps you were using. dpkg -l shows ii procps 1:3.2.8-9 ... (squeeze up-to-date). Is it always just a second earlier? ... Yes, it seems so. Have not seen any other discrepancies for a long time now. It is looking like a kernel problem, or more specifically a procfs output problem. I also think so. Please let me know if I should run some other tests. (Noting bug #657916 also.) Thanks, Paul Paul Szabo p...@maths.usyd.edu.au http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#408879: /bin/ps: TIME drifted
Testing this old thing again at squeeze 6.0.4 with 2.6.32 kernel, can still reproduce, the long command in previous message shows: $ while :; do \ date; /bin/ps -o lstart,command | grep /ps; date; echo; \ done | \ perl -ne ' BEGIN { $/ = \n\n } @x=grep(s/^(... ... .. ..:..:..).*$/$1/, split(/\n/)); $p=; $z=0; $z ||= $p gt $_, $p=$_ foreach @x; print if $z' Mon Jan 30 12:00:45 EST 2012 Mon Jan 30 12:00:44 2012 /bin/ps -o lstart,command Mon Jan 30 12:00:44 2012 grep /ps Mon Jan 30 12:00:45 EST 2012 Mon Jan 30 12:00:52 EST 2012 Mon Jan 30 12:00:51 2012 /bin/ps -o lstart,command Mon Jan 30 12:00:51 2012 grep /ps Mon Jan 30 12:00:52 EST 2012 ... Cheers, Paul Paul Szabo p...@maths.usyd.edu.au http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#408879: /bin/ps: TIME drifted
I can still (2.6.24 kernel, lenny up-to-date) reproduce with command (wrapped for readability, OK for cut-and-paste into xterm, ctrl-C when had enough): while :; do \ date; /bin/ps -o lstart,command | grep /ps; date; echo; \ done | \ perl -ne ' BEGIN { $/ = \n\n } @x=grep(s/^(... ... .. ..:..:..).*$/$1/, split(/\n/)); $p=; $z=0; $z ||= $p gt $_, $p=$_ foreach @x; print if $z' that shows things like: Wed Aug 25 12:36:44 EST 2010 Wed Aug 25 12:36:43 2010 /bin/ps -o lstart,command Wed Aug 25 12:36:44 EST 2010 Should the tag unreproducible be removed? Thanks, Paul Paul Szabo p...@maths.usyd.edu.au http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#408879: /bin/ps: TIME drifted
One day after the lenny upgrade and last boot of the machine, there does not seem to be a great time drift. I was running something like while :; do date; /bin/ps -o lstart,command | grep /ps; date done and that showed: ... Thu May 14 13:18:42 EST 2009 Thu May 14 13:18:42 2009 /bin/ps -o lstart,command Thu May 14 13:18:42 EST 2009 Thu May 14 13:18:43 EST 2009 Thu May 14 13:18:43 2009 /bin/ps -o lstart,command Thu May 14 13:18:43 EST 2009 (above block repeated 22 times) Thu May 14 13:18:43 EST 2009 Thu May 14 13:18:42 2009 /bin/ps -o lstart,commandnote bad time Thu May 14 13:18:43 EST 2009 Thu May 14 13:18:43 EST 2009 Thu May 14 13:18:43 2009 /bin/ps -o lstart,command Thu May 14 13:18:43 EST 2009 (above block repeated 8 times) Thu May 14 13:18:44 EST 2009 Thu May 14 13:18:44 2009 /bin/ps -o lstart,command Thu May 14 13:18:44 EST 2009 ... which would suggest something other than a few milliseconds drift. Rather curious; the bad time always positioned about the 3/4 of the elapsed second... Cheers, Paul Szabo p...@maths.usyd.edu.au http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#408879: /bin/ps: TIME drifted
I have now updated my problem machine to lenny and 2.6.26 kernel: r...@pisa:~# cat /etc/debian_version 5.0.1 r...@pisa:~# uname -r 2.6.26-pk03.10-svr and the problem already is visible two hours after boot: r...@pisa:~# date; /bin/ps -o lstart,command | grep /ps; date Wed May 13 11:40:18 EST 2009 Wed May 13 11:40:17 2009 /bin/ps -o lstart,command Wed May 13 11:40:17 2009 grep /ps Wed May 13 11:40:18 EST 2009 (I expect the time drift to grow steadily). Cheers, Paul Szabo p...@maths.usyd.edu.au http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#408879: /bin/ps: TIME drifted
On Mon, Aug 11, 2008 at 12:58:54PM +1000, Paul Szabo wrote: Running the commands suggested, I get: That's interesting, but its looking like its not a procps bug. Or perhaps there is something procps assumes that is incorrect. There is no overflow problems here, the manual calculation is agreeing with procps PID START CMD 24954 12:48 bash and [EMAIL PROTECTED]:~$ echo '1218423322 - 2339691.29 + ( 233925387 /100 )' | bc | perl -e 'use Time::localtime; my $mytime=; ; print ctime($mytime).\n;' Mon Aug 11 12:48:03 2008 Looking at the values: The now() time is correct. The uptime is about 29 days, the computer was booted 11am 15th July Now you would expect that the uptime and the process start time would be pretty close to each other, because they are being done at the same time, or a second or so between them. But they are not: In fact, your process start time is *less* than the uptime, by about 438 seconds, or 7 minutes. Mon Aug 11 12:55:15 EST 2008 Mon Aug 11 12:48:03 2008 That's 7 minutes. So, the kernel is giving the wrong start time. -- Craig Small GnuPG:1C1B D893 1418 2AF4 45EE 95CB C76C E5AC 12CA DFA5 http://www.enc.com.au/ csmall at : enc.com.au http://www.debian.org/ Debian GNU/Linux, software should be Free -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
Dear Craig, ... its looking like its not a procps bug. Or perhaps there is something procps assumes that is incorrect. I suspect the latter (this is idle speculation, without having delved into the sources). ... your process start time is *less* than the uptime ... So, the kernel is giving the wrong start time. Does the start time given by the kernel need a correction? Is the bug in the kernel for lieing, or in ps for not applying that correction? Cheers, Paul Szabo [EMAIL PROTECTED] http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
On Sun, Aug 10, 2008 at 03:13:50PM +1000, Paul Szabo wrote: I often observe this, mostly on that one machine pisa. I do not think pisa is special in any way: has same hardware as some others, runs the same kernel, more-or-less the same daemons. Pisa is still running sarge: Curious, just a standard type computer. There are some arches where the jiffies don't quite work and I thought it was that. Probably best to work out what numbers we use. Start time is found in the 22nd field of /proc/pid/stat and is in number of jiffies since the computer had booted. To get this to a wall clock start time we add the boot time of the computer to the converted start time. BUT, to get the boot time we need to subtract the uptime of the computer from now. Or: w_stime = (now - uptime) + ( j_stime / Hertz) w_stime is wall clock start time now is seconds since epoch for the time now uptime is first column of /proc/uptime j_stime is 22nd column of /proc/pid/uptime Hertz is usually 100 Can you run the following commands, you will need to change the PID to whatever process id you have. PID=21789 ; ( date +%s - ; cut -f 1 -d ' ' /proc/uptime ; echo + ( ; cut -f 22 -d ' ' /proc/$PID/stat ; echo ' / 100 )' ) | (tr '\n' ' ' ; echo ) ; ps -p $PID -o pid,start_time,cmd then take the first line of the output (not the ps bit) and then: echo THE OUTPUT | bc | perl -e 'use Time::localtime; my $mytime=; ; print ctime($mytime).\n;' So for me I get: gonzo$ PID=21789 ; ( date +%s - ; cut -f 1 -d ' ' /proc/uptime ; echo + ( ; cut -f 22 -d ' ' /proc/$PID/stat ; echo ' / 100 )' ) | (tr '\n' ' ' ; echo ) ; ps -p $PID -o pid,start_time,cmd 1218419241 - 251503.45 + ( 24646725 / 100 ) PID START CMD 21789 10:23 sshd: [EMAIL PROTECTED]/0 gonzo$ echo 1218419241 - 251503.45 + ( 24646725 / 100 ) | bc | perl -e 'use Time::localtime; my $mytime=; ; print ctime($mytime).\n;' Mon Aug 11 10:23:24 2008 As you can see, I'm getting the same results (10:23) here. We may have an under/overflow problem too. - Craig -- Craig Small GnuPG:1C1B D893 1418 2AF4 45EE 95CB C76C E5AC 12CA DFA5 http://www.enc.com.au/ csmall at : enc.com.au http://www.debian.org/ Debian GNU/Linux, software should be Free -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
Running the commands suggested, I get: [EMAIL PROTECTED]:~$ date Mon Aug 11 12:55:15 EST 2008 [EMAIL PROTECTED]:~$ bash [EMAIL PROTECTED]:~$ PID=$$; ( date +%s - ; cut -f 1 -d ' ' /proc/uptime ; echo + ( ; cut -f 22 -d ' ' /proc/$PID/stat ; echo ' /100 )' ) | (tr '\n' ' '; echo ) ; ps -p $PID -o pid,start_time,cmd 1218423322 - 2339691.29 + ( 233925387 /100 ) PID START CMD 24954 12:48 bash [EMAIL PROTECTED]:~$ echo '1218423322 - 2339691.29 + ( 233925387 /100 )' | bc | perl -e 'use Time::localtime; my $mytime=; ; print ctime($mytime).\n;' Mon Aug 11 12:48:03 2008 [EMAIL PROTECTED]:~$ date Mon Aug 11 12:55:46 EST 2008 [EMAIL PROTECTED]:~$ exit [EMAIL PROTECTED]:~$ date Mon Aug 11 12:55:49 EST 2008 Cheers, Paul Szabo [EMAIL PROTECTED] http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
tags 408879 unreproducible thankyou On Mon, Feb 26, 2007 at 06:41:24AM -0500, Justin Pryzby wrote: Might have expected hz to be accurate to better than .02; on another machine: Ah, it might be related to the Hertz calculation, but the bug submitters are not using strange architectures so its not that. The problem here is I don't see it. My start times always seem to line up, when I check them. I've also used ntp for years. I'm not sure anyone is seeing this problem anymore, which if noone is then I'll close the bug. - Craig -- Craig Small GnuPG:1C1B D893 1418 2AF4 45EE 95CB C76C E5AC 12CA DFA5 http://www.enc.com.au/ csmall at : enc.com.au http://www.debian.org/ Debian GNU/Linux, software should be Free -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
I still see the problem: [EMAIL PROTECTED]:~$ date; /bin/ps ux | grep /ps; date Sun Aug 10 14:45:24 EST 2008 psz 15724 0.0 0.0 2496 844 pts/3R+ 14:38 0:00 /bin/ps ux psz 15725 0.0 0.0 1548 472 pts/3S+ 14:38 0:00 grep /ps Sun Aug 10 14:45:24 EST 2008 I often observe this, mostly on that one machine pisa. I do not think pisa is special in any way: has same hardware as some others, runs the same kernel, more-or-less the same daemons. Pisa is still running sarge: [EMAIL PROTECTED]:~$ cat /etc/debian_version 3.1 [EMAIL PROTECTED]:~$ uname -a Linux pisa.maths.usyd.edu.au 2.6.8-spm1.11 #1 SMP Mon Jul 23 18:53:40 EST 2007 i686 GNU/Linux This behaviour is not unique, some other (also sarge but hardware-wise completely different) machines also show the problem: [EMAIL PROTECTED]:~# date; /bin/ps ux | grep /ps; date Sun Aug 10 14:58:24 EST 2008 root 15027 0.0 0.1 2504 852 pts/1R+ 14:57 0:00 /bin/ps ux root 15028 0.0 0.0 1556 484 pts/1S+ 14:57 0:00 grep /ps Sun Aug 10 14:58:24 EST 2008 I do not see the problem on all my machines; some though exactly the same hardware as pisa, never exhibited the problem (not while they were running sarge, not now under etch). I do not now see the problem on any etch machines. Thanks, Paul Paul Szabo [EMAIL PROTECTED] http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
On Mon, Feb 19, 2007 at 09:50:36AM +1100, Craig Small wrote: On Sun, Feb 18, 2007 at 03:38:00PM -0500, Justin Pryzby wrote: I'm of the understanding that ntp uses adjtimex() to do it's stuff. I suppose the next thing to work out is, is it a kernel problem or a ps problem. I guess (strace) it uses some combination of /proc/uptime and /proc/PID/stat starttime %lu The time in jiffies the process started after system boot. uptime (jiffies): sh -c 'cut -d -f22 /proc/$$/stat' uptime (seconds): cut -d' ' -f1 /proc/uptime $ date; ps aux |tail -1 Thu Feb 22 08:57:35 EST 2007 jpryzby 20446 0.0 0.0 2696 472 pts/1521 R+ 09:37 0:00 tail -1 $ echo `sh -c 'cut -d -f22 /proc/$$/stat'` / `cut -d' ' -f1 /proc/uptime` |bc -l 100.0230992939513293 but, 09:06:13 up 118 days, 13:39, 9 users, load average: 0.00, 0.02, 0.00 Might have expected hz to be accurate to better than .02; on another machine: up 15 days 99.9777870238057132 (1000 more accurate) I don't know if that can explain it. -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
Justin, does this happen to you on a laptop machine, or otherwise? I do not have Debian laptops. So it is otherwise: on my main departmental login server Cheers, Paul Szabo [EMAIL PROTECTED] http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
On Sun, Feb 18, 2007 at 09:29:05PM +1100, Paul Szabo wrote: Justin, does this happen to you on a laptop machine, or otherwise? I do not have Debian laptops. So it is otherwise: on my main departmental login server Same for us. You mentioned bug #161633, in which the submitter is clearly convinced that it is APM suspend time that isn't taken into account. Do you suspect some particular cause here, too? (Or, you aren't suspending your shell server, are you?) Justin -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
Justin, ... Do you suspect some particular cause here, too? Yes, I blame ntpd. I only guess that it uses suspend to slow things down. (No, I wouldn't manually suspend my server.) Cheers, Paul Szabo [EMAIL PROTECTED] http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
On Mon, Feb 19, 2007 at 06:41:24AM +1100, Paul Szabo wrote: Justin, ... Do you suspect some particular cause here, too? Yes, I blame ntpd. I only guess that it uses suspend to slow things down. (No, I wouldn't manually suspend my server.) I'm of the understanding that ntp uses adjtimex() to do it's stuff. -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
On Sun, Feb 18, 2007 at 03:38:00PM -0500, Justin Pryzby wrote: I'm of the understanding that ntp uses adjtimex() to do it's stuff. I suppose the next thing to work out is, is it a kernel problem or a ps problem. - Craig -- Craig Small GnuPG:1C1B D893 1418 2AF4 45EE 95CB C76C E5AC 12CA DFA5 http://www.enc.com.au/ MIEE Debian developer csmall at : enc.com.au ieee.org debian.org -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
On Mon, Jan 29, 2007 at 09:49:49AM +1100, Paul Szabo wrote: Again looking at BTS, this bug seems similar to #161633. me too; Paul, does this happen to you on a laptop machine, or otherwise? -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
Package: procps Version: 1:3.2.1-2 Severity: normal File: /bin/ps We use ntpd to keep time synced. Then somehow the machine uses two times, a good one set by ntpd, and an internal drifted one that should never be shown. Confusingly, ps shows the wrong START time: [EMAIL PROTECTED]:~$ date Mon Jan 29 08:47:40 EST 2007 [EMAIL PROTECTED]:~$ last -1 psz pts/6y622.yt.maths.us Mon Jan 29 08:46 still logged in wtmp begins Mon Jan 1 08:54:56 2007 [EMAIL PROTECTED]:~$ ps aux | grep -E 'psz|USER' USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND psz 14608 0.0 0.0 8568 2896 ?S08:33 0:00 xterm -font 9x15 -bg #ffdab9 -fg black -T [EMAIL PROTECTED] -n [EMAIL PROTECTED] -sb -sl 1 -ls psz 14611 0.0 0.0 2568 1436 pts/6Ss 08:33 0:00 -bash psz 14626 0.0 0.0 1548 472 pts/6S+ 08:34 0:00 grep -E psz|USER psz 14627 0.0 0.0 2496 848 pts/6R+ 08:34 0:00 ps aux [EMAIL PROTECTED]:~$ Cheers, Paul Szabo [EMAIL PROTECTED] http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- System Information: Debian Release: 3.1 Architecture: i386 (i686) Kernel: Linux 2.6.8-spm1.7 Locale: LANG=C, LC_CTYPE=C (charmap=ANSI_X3.4-1968) Versions of packages procps depends on: ii libc6 2.3.2.ds1-22sarge4 GNU C Library: Shared libraries an ii libncurses5 5.4-4 Shared libraries for terminal hand -- no debconf information -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]
Bug#408879: /bin/ps: TIME drifted
Again looking at BTS, this bug seems similar to #161633. Cheers, Paul Szabo [EMAIL PROTECTED] http://www.maths.usyd.edu.au/u/psz/ School of Mathematics and Statistics University of SydneyAustralia -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of unsubscribe. Trouble? Contact [EMAIL PROTECTED]