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

times() function overflows after 49.7 days (2**32 millisec) #13086

Open
p5pRT opened this issue Jul 6, 2013 · 5 comments
Open

times() function overflows after 49.7 days (2**32 millisec) #13086

p5pRT opened this issue Jul 6, 2013 · 5 comments

Comments

@p5pRT
Copy link

p5pRT commented Jul 6, 2013

Migrated from rt.perl.org#118777 (status was 'open')

Searchable as RT118777$

@p5pRT
Copy link
Author

p5pRT commented Jul 6, 2013

From kjohnstn@sbcglobal.net

This is a bug report for perl from kjohnstn@​sbcglobal.net,
generated with the help of perlbug 1.39 running under perl 5.12.4.

Here is an extract from a log of a program that runs basically forever.
The only point of interest is the very last number of each line, it is
the elapsed execution time, in seconds, as reported by times()​:

#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 1 0 1 1 1 3 3 3 2 2 1 1 1 3 2 1 0 0 1 1 1
3 2 1 0 0 1 1 3 2 2 1 0 0 1 3 2 2 3#9231483673 4615186958 4288947.48#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 1 0 1 1 3 2 3 2 1 0 1 3 2 2 2 2 1 0 1 3 2
2 2 2 2 3 1 1 0 0 0 0 0 3 1 3 2 3#9232532249 4615676592 4289412.32#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 1 0 3 1 1 1 0 0 1 0 1 1 1 1 0 0 3 2 1 1 1
1 0 0 3 2 1 1 1 3 3 2 2 2 1 1 1 1 3 3 3#9233580825 4616156037 4289872.63#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 2 2 1 1 1 3 2 3 2 2 1 3 1 1 0 1 0 0 1 3 2
2 3 1 0 0 3 2 2 2 1 1 0 0 1 0 0 0 1 3 3#9234629401 4616637559 4290336.45#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 2 2 1 3 1 1 0 0 0 0 1 1 3 2 2 3 2 2 1 3 1
0 0 1 0 0 1 1 3 2 2 2 2 3 3 2 2 3#9235677977 4617217777 4290894.02#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 2 3 1 1 1 3 3 3 2 1 1 1 1 1 3 1 0 1 3 1 1
1 1 1 0 1 1 1 1 3 2 2 2 2 3 2 2 2 2 2 2 2#9236726553 4617814514 4291474.81#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 3 1 0 1 1 1 1 0 1 3 3 1 1 1 1 0 1 1 3 1 1 3
2 3 1 1 1 1 1 3 2 2 2 1 1 1 1 3 2 2 2 2 2#9237775129 4618432258 4292068.55#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 3 1 0 1 1 1 3 2 2 2 3 1 1 3 1 0 0 0 1 1 1 1
3 2 2 2 2 1 1 3 2 3 2 2 2 3 2 2 2 2 2 2 2#9238823705 4618944283 4292529.4#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 3 1 0 1 3 1 1 0 1 1 0 1 1 1 3 3 1 1 0 1 1 3
2 2 1 1 0 3 1 1 0 0 1 1 0 1 3 2 3#9239872281 4619393866 4292937.93#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 3 2 2 1 1 1 3 2 2 2 2 1 1 3 1 0 0 0 0 3 2 2
2 2 2 2 2 3 2 2 2 2 2 2 2 3 2 2 2 3 2 3#9240920857 4619845850 4293365.19#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 3 2 3 1 1 1 3 2 2 2 1 1 1 1 1 0 0 0 3 1 3 1
1 0 0 0 1 3 2 1 1 0 0 0 1 3 2 2 2 3 2 2 2#9241969433 4620397169
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 2 1 0 1 1 1 1 3 2 1 0 1 1 1 1 1 0 3 2 1 1 1
1 3 3 2 3 1 1 1 1 3 1 0 1 1 3 2 2 2 2 2 1#9243018009 4621074197
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 2 1 0 1 1 1 3 1 0 1 0 1 3 1 1 1 0 1 0 3 2 1
1 1 0 1 0 1 0 3 1 1 0 3#9244066585 4621556747 17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 2 1 0 1 3 1 1 1 0 1 0 1 1 3 2 2 3 1 0 1 1 3
2 2 2 1 0 3 2 2 2 2 2 2 3 3 2 2 2 2 2 2 2#9245115161 4622016428
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 2 2 2 1 1 1 3 1 0 0 0 1 1 1 1 3 3 2 3 1 1 3
2 1 1 0 1 1 3 2 2 2 1 0 1 1 3 2 2 2 1 0 1#9246163737 4622514926
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 2 2 3 1 1 1 3 1 0 0 1 1 1 1 1 1 0 0 3 1 3 2
2 2 2 2 1 1 3 2 2 2 3 2 1 3 2 2 2 2 2 2 1#9247212313 4623098426
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 3 1 0 1 1 1 1 1 3 1 0 1 1 1 3 1 1 1 0 1 1 1
1 1 1 3 2 3 1 1 1 1 1 1 0 1 1 3 2 1 1 3#9248260889 4623750788
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 3 1 0 1 1 3 1 1 1 1 0 1 1 1 1 1 1 3 3 3 2 1
1 1 1 1 1 3 2 2 2 1 1 1 1 3 2 2 2 2 2 2 1#9249309465 4624231769
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 3 2 2 1 1 1 1 1 3 2 2 1 1 1 1 3 1 0 0 1 3 2
2 1 1 0 0 3 2 2 2 2 1 0 0 1 0 0 0 0 3 2 3#9250358041 4624671742
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 3 2 3 1 1 1 1 3 1 0 1 1 1 3 1 1 1 0 1 1 1 1
1 1 3 2 1 1 1 3 1 1 1 0 1 3 2 2 2 2 2 2 2#9251406617 4625268015
17637359757.92#
#7 3 3 2 2 2 2 3 2 3 1 0 0 0 0 1 0 1 1 0 0 0 0 3 2 1 3 3 2 2 3 2 2 1 1 3
3 2 2 2 3 1 1 3 2 2 2 2 1 1 3 2 3#9252455193 4625947331 17637359757.92#

(If the lines get wrapped in mailing, every original line begins and
ends with the hash '#' character.)

Notice the last few "times" are all the same​: 17637359757.92. That's an
elapsed time of 559 years, obviously nonsense.

Everything is fine up to time 4293365.19, then all following timestamps
are the nonsense value.

Something is overflowing a 32 bit value​: (2**32)millisec is
4294967.296s, about 50 days.

I don't know for sure whether the overflow is in perl or in the OS, but
I don't know how to tell the difference.


Flags​:
  category=utilities
  severity=low


This perlbug was built using Perl 5.12.4 in the Fedora build system.
It is being executed now by Perl 5.12.4 - Mon May 14 12​:46​:27 UTC 2012.

Site configuration information for perl 5.12.4​:

Configured by Red Hat, Inc. at Mon May 14 12​:46​:27 UTC 2012.

Summary of my perl5 (revision 5 version 12 subversion 4) configuration​:

  Platform​:
  osname=linux, osvers=2.6.32-220.4.1.el6.x86_64,
archname=x86_64-linux-thread-multi
  uname='linux x86-14.phx2.fedoraproject.org
2.6.32-220.4.1.el6.x86_64 #1 smp thu jan 19 14​:50​:54 est 2012 x86_64
x86_64 x86_64 gnulinux '
  config_args='-des -Doptimize=-O2 -g -pipe -Wall
-Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector
--param=ssp-buffer-size=4 -m64 -mtune=generic
-Dccdlflags=-Wl,--enable-new-dtags -DDEBUGGING=-g -Dversion=5.12.4
-Dmyhostname=localhost -Dperladmin=root@​localhost -Dcc=gcc -Dcf_by=Red
Hat, Inc. -Dprefix=/usr -Dvendorprefix=/usr -Dsiteprefix=/usr/local
-Dsitelib=/usr/local/share/perl5 -Dsitearch=/usr/local/lib64/perl5
-Dprivlib=/usr/share/perl5 -Dvendorlib=/usr/share/perl5/vendor_perl
-Darchlib=/usr/lib64/perl5 -Dvendorarch=/usr/lib64/perl5/vendor_perl
-Darchname=x86_64-linux-thread-multi -Dlibpth=/usr/local/lib64 /lib64
/usr/lib64 -Duseshrplib -Dusethreads -Duseithreads
-Dusedtrace=/usr/bin/dtrace -Duselargefiles -Dd_semctl_semun -Di_db
-Ui_ndbm -Di_gdbm -Di_shadow -Di_syslog -Dman3ext=3pm -Duseperlio
-Dinstallusrbinperl=n -Ubincompat5005 -Uversiononly
-Dpager=/usr/bin/less -isr -Dd_gethostent_r_proto -Ud_endhostent_r_proto
-Ud_sethostent_r_proto -Ud_endprotoent_r_proto -Ud_setprotoent_r_proto
-Ud_endservent_r_proto -Ud_setservent_r_proto -Dscriptdir=/usr/bin'
  hint=recommended, useposix=true, d_sigaction=define
  useithreads=define, usemultiplicity=define
  useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=undef
  use64bitint=define, use64bitall=define, uselongdouble=undef
  usemymalloc=n, bincompat5005=undef
  Compiler​:
  cc='gcc', ccflags ='-D_REENTRANT -D_GNU_SOURCE -fno-strict-aliasing
-pipe -fstack-protector -I/usr/local/include -D_LARGEFILE_SOURCE
-D_FILE_OFFSET_BITS=64',
  optimize='-O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions
-fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic',
  cppflags='-D_REENTRANT -D_GNU_SOURCE -fno-strict-aliasing -pipe
-fstack-protector -I/usr/local/include'
  ccversion='', gccversion='4.6.3 20120306 (Red Hat 4.6.3-2)',
gccosandvers=''
  intsize=4, longsize=8, ptrsize=8, doublesize=8, byteorder=12345678
  d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=16
  ivtype='long', ivsize=8, nvtype='double', nvsize=8, Off_t='off_t',
lseeksize=8
  alignbytes=8, prototype=define
  Linker and Libraries​:
  ld='gcc', ldflags =' -fstack-protector'
  libpth=/usr/local/lib64 /lib64 /usr/lib64
  libs=-lresolv -lnsl -lgdbm -ldb -ldl -lm -lcrypt -lutil -lpthread
-lc -lgdbm_compat
  perllibs=-lresolv -lnsl -ldl -lm -lcrypt -lutil -lpthread -lc
  libc=, so=so, useshrplib=true, libperl=libperl.so
  gnulibc_version='2.14.1'
  Dynamic Linking​:
  dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef,
ccdlflags='-Wl,--enable-new-dtags -Wl,-rpath,/usr/lib64/perl5/CORE'
  cccdlflags='-fPIC', lddlflags='-shared -O2 -g -pipe -Wall
-Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector
--param=ssp-buffer-size=4 -m64 -mtune=generic'

Locally applied patches​:


@​INC for perl 5.12.4​:
  /usr/local/lib64/perl5
  /usr/local/share/perl5
  /usr/lib64/perl5/vendor_perl
  /usr/share/perl5/vendor_perl
  /usr/lib64/perl5
  /usr/share/perl5
  .


Environment for perl 5.12.4​:
  HOME=/home/tk
  LANG=en_US.UTF-8
  LANGUAGE (unset)
  LD_LIBRARY_PATH (unset)
  LOGDIR (unset)

PATH=/usr/local/bin​:/usr/bin​:/bin​:/usr/local/sbin​:/usr/sbin​:/sbin​:/opt/real/RealPlayer​:/home/tk/bin​:/opt/real/RealPlayer
  PERL_BADLANG (unset)
  SHELL=/bin/bash

@p5pRT
Copy link
Author

p5pRT commented Jul 6, 2013

From @cpansprout

On Fri Jul 05 19​:21​:55 2013, kjohnstn wrote​:

Something is overflowing a 32 bit value​: (2**32)millisec is
4294967.296s, about 50 days.

I don't know for sure whether the overflow is in perl or in the OS,
but
I don't know how to tell the difference.

The value returned by the OS is of type clock_t. pp_tms in pp_sys.c
casts it to NV.

I don’t know enough about C to know whether that has anything to do with it.

--

Father Chrysostomos

@p5pRT
Copy link
Author

p5pRT commented Jul 6, 2013

The RT System itself - Status changed from 'new' to 'open'

@p5pRT
Copy link
Author

p5pRT commented Jul 6, 2013

From @Leont

On Fri Jul 05 19​:21​:55 2013, kjohnstn wrote​:

This is a bug report for perl from kjohnstn@​sbcglobal.net,
generated with the help of perlbug 1.39 running under perl 5.12.4.

Here is an extract from a log of a program that runs basically
forever.
The only point of interest is the very last number of each line, it is
the elapsed execution time, in seconds, as reported by times()​:

#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 1 0 1 1 1 3 3 3 2 2 1 1 1 3 2 1 0 0 1 1
1
3 2 1 0 0 1 1 3 2 2 1 0 0 1 3 2 2 3#9231483673 4615186958 4288947.48#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 1 0 1 1 3 2 3 2 1 0 1 3 2 2 2 2 1 0 1 3
2
2 2 2 2 3 1 1 0 0 0 0 0 3 1 3 2 3#9232532249 4615676592 4289412.32#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 1 0 3 1 1 1 0 0 1 0 1 1 1 1 0 0 3 2 1 1
1
1 0 0 3 2 1 1 1 3 3 2 2 2 1 1 1 1 3 3 3#9233580825 4616156037
4289872.63#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 2 2 1 1 1 3 2 3 2 2 1 3 1 1 0 1 0 0 1 3
2
2 3 1 0 0 3 2 2 2 1 1 0 0 1 0 0 0 1 3 3#9234629401 4616637559
4290336.45#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 2 2 1 3 1 1 0 0 0 0 1 1 3 2 2 3 2 2 1 3
1
0 0 1 0 0 1 1 3 2 2 2 2 3 3 2 2 3#9235677977 4617217777 4290894.02#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 2 2 3 1 1 1 3 3 3 2 1 1 1 1 1 3 1 0 1 3 1
1
1 1 1 0 1 1 1 1 3 2 2 2 2 3 2 2 2 2 2 2 2#9236726553 4617814514
4291474.81#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 3 1 0 1 1 1 1 0 1 3 3 1 1 1 1 0 1 1 3 1 1
3
2 3 1 1 1 1 1 3 2 2 2 1 1 1 1 3 2 2 2 2 2#9237775129 4618432258
4292068.55#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 3 1 0 1 1 1 3 2 2 2 3 1 1 3 1 0 0 0 1 1 1
1
3 2 2 2 2 1 1 3 2 3 2 2 2 3 2 2 2 2 2 2 2#9238823705 4618944283
4292529.4#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 3 1 0 1 3 1 1 0 1 1 0 1 1 1 3 3 1 1 0 1 1
3
2 2 1 1 0 3 1 1 0 0 1 1 0 1 3 2 3#9239872281 4619393866 4292937.93#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 3 2 2 1 1 1 3 2 2 2 2 1 1 3 1 0 0 0 0 3 2
2
2 2 2 2 2 3 2 2 2 2 2 2 2 3 2 2 2 3 2 3#9240920857 4619845850
4293365.19#
#7 3 3 2 2 2 2 3 2 1 3 3 3 2 3 2 3 1 1 1 3 2 2 2 1 1 1 1 1 0 0 0 3 1 3
1
1 0 0 0 1 3 2 1 1 0 0 0 1 3 2 2 2 3 2 2 2#9241969433 4620397169
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 2 1 0 1 1 1 1 3 2 1 0 1 1 1 1 1 0 3 2 1 1
1
1 3 3 2 3 1 1 1 1 3 1 0 1 1 3 2 2 2 2 2 1#9243018009 4621074197
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 2 1 0 1 1 1 3 1 0 1 0 1 3 1 1 1 0 1 0 3 2
1
1 1 0 1 0 1 0 3 1 1 0 3#9244066585 4621556747 17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 2 1 0 1 3 1 1 1 0 1 0 1 1 3 2 2 3 1 0 1 1
3
2 2 2 1 0 3 2 2 2 2 2 2 3 3 2 2 2 2 2 2 2#9245115161 4622016428
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 2 2 2 1 1 1 3 1 0 0 0 1 1 1 1 3 3 2 3 1 1
3
2 1 1 0 1 1 3 2 2 2 1 0 1 1 3 2 2 2 1 0 1#9246163737 4622514926
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 2 2 3 1 1 1 3 1 0 0 1 1 1 1 1 1 0 0 3 1 3
2
2 2 2 2 1 1 3 2 2 2 3 2 1 3 2 2 2 2 2 2 1#9247212313 4623098426
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 3 1 0 1 1 1 1 1 3 1 0 1 1 1 3 1 1 1 0 1 1
1
1 1 1 3 2 3 1 1 1 1 1 1 0 1 1 3 2 1 1 3#9248260889 4623750788
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 3 1 0 1 1 3 1 1 1 1 0 1 1 1 1 1 1 3 3 3 2
1
1 1 1 1 1 3 2 2 2 1 1 1 1 3 2 2 2 2 2 2 1#9249309465 4624231769
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 3 2 2 1 1 1 1 1 3 2 2 1 1 1 1 3 1 0 0 1 3
2
2 1 1 0 0 3 2 2 2 2 1 0 0 1 0 0 0 0 3 2 3#9250358041 4624671742
17637359757.92#
#7 3 3 2 2 2 2 3 2 1 3 3 3 3 3 2 3 1 1 1 1 3 1 0 1 1 1 3 1 1 1 0 1 1 1
1
1 1 3 2 1 1 1 3 1 1 1 0 1 3 2 2 2 2 2 2 2#9251406617 4625268015
17637359757.92#
#7 3 3 2 2 2 2 3 2 3 1 0 0 0 0 1 0 1 1 0 0 0 0 3 2 1 3 3 2 2 3 2 2 1 1
3
3 2 2 2 3 1 1 3 2 2 2 2 1 1 3 2 3#9252455193 4625947331
17637359757.92#

(If the lines get wrapped in mailing, every original line begins and
ends with the hash '#' character.)

Notice the last few "times" are all the same​: 17637359757.92. That's
an
elapsed time of 559 years, obviously nonsense.

Everything is fine up to time 4293365.19, then all following
timestamps
are the nonsense value.

Something is overflowing a 32 bit value​: (2**32)millisec is
4294967.296s, about 50 days.

I don't know for sure whether the overflow is in perl or in the OS,
but
I don't know how to tell the difference.

POSIX has a caveat that starts with «If the type clock_t is defined to
be a signed 32-bit integer, it overflows in …», so getting an overflow
is not a perl bug per se.

That said, the 17637359757.92 value is strange. It's 2**44 milliseconds,
but I'm not sure either where that comes from.

Leon

@p5pRT
Copy link
Author

p5pRT commented Jul 6, 2013

From @bulk88

On Fri Jul 05 20​:39​:56 2013, sprout wrote​:

On Fri Jul 05 19​:21​:55 2013, kjohnstn wrote​:

Something is overflowing a 32 bit value​: (2**32)millisec is
4294967.296s, about 50 days.

I don't know for sure whether the overflow is in perl or in the OS,
but
I don't know how to tell the difference.

The value returned by the OS is of type clock_t. pp_tms in pp_sys.c
casts it to NV.

I don’t know enough about C to know whether that has anything to do
with it.

Here is a infamous 50 day overflow time function (GetTickCount) in
Windows,
http​://msdn.microsoft.com/en-us/library/windows/desktop/ms724408%28v=vs.85%29.aspx
. Googling it will probably lead to many discussions on how to handle
the 49/50 day overflow.

--
bulk88 ~ bulk88 at hotmail.com

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants