Skip Menu |

This queue is for tickets about the DBI CPAN distribution.

Report information
The Basics
Id: 27666
Status: resolved
Priority: 0/
Queue: DBI
People
Owner: Nobody in particular
Requestors: jdhedden [...] cpan.org
Cc:
AdminCc:
Bug Information
Severity: Normal
Broken in: 1.57
Fixed in: (no value)

History Show all quoted text
  Wed Jun 20 15:18:15 2007 jdhedden [...] cpan.org - Ticket created
Subject: Test failure in t/40profile.t
Using blead under Cygwin, I get the following test failure from t/40profile.t: testing '!Time' and variants in Path not ok 44 - !Time and !Time~100000 should work # Failed test '!Time and !Time~100000 should work' # at t/40profile.t line 295. # Structures begin differing at: # $got->{1182365712} = Does not exist # $expected->{1182365712} = HASH(0x1031aef8) Let me know if you need more info. Show quoted text
> perl -V
Summary of my perl5 (revision 5 version 9 subversion 5 patch 31430) configuration: Platform: osname=cygwin, osvers=1.5.24(0.15642), archname=cygwin-thread-multi-64int uname='cygwin_nt-5.0 pn100-02-2-054p 1.5.24(0.15642) 2007-01-31 10:57 i686 cygwin ' config_args='-de -Dusedevel -Dversiononly=no -Dinstallusrbinperl -Duse64bitint -Dusethreads -Uusemymalloc -Dnoextensions=attrs IPC/SysV Sys/Syslog DB_File NDBM_File ODBM_File SDBM_File Devel/DProf Devel/Peek re XS/APItest XS/Typemap Encode PerlIO/encoding Unicode/Normalize I18N/Langinfo Text/Soundex Math/BigInt/FastCalc Time/Piece -A define:optimize=-O3 -pipe -funit-at-a-time -mtune=pentium4m -march=pentium4 -mfpmath=sse -mieee-fp -mmmx -msse -msse2 -A define:ld=/usr/bin/ld2 -A append:ccflags= -DNO_MATHOMS' hint=recommended, useposix=true, d_sigaction=define useithreads=define, usemultiplicity=define useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=undef use64bitint=define, use64bitall=undef, uselongdouble=undef usemymalloc=n, bincompat5005=undef Compiler: cc='gcc', ccflags ='-DPERL_USE_SAFE_PUTENV -U__STRICT_ANSI__ -DNO_MATHOMS -fno-strict-aliasing -pipe', optimize='-O3 -pipe -funit-at-a-time -mtune=pentium4m -march=pentium4 -mfpmath=sse -mieee-fp -mmmx -msse -msse2', cppflags='-DPERL_USE_SAFE_PUTENV -U__STRICT_ANSI__ -DNO_MATHOMS -fno-strict-aliasing -pipe' ccversion='', gccversion='3.4.4 (cygming special, gdc 0.12, using dmd 0.125)', gccosandvers='' intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=12345678 d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=12 ivtype='long long', ivsize=8, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8 alignbytes=8, prototype=define Linker and Libraries: ld='/usr/bin/ld2', ldflags =' -Wl,--enable-auto-import -s' libpth=/usr/lib /lib libs=-lgdbm -ldl -lcrypt -lgdbm_compat perllibs=-ldl -lcrypt -lgdbm_compat libc=/usr/lib/libc.a, so=dll, useshrplib=true, libperl=libperl.a gnulibc_version='' Dynamic Linking: dlsrc=dl_dlopen.xs, dlext=dll, d_dlsymun=undef, ccdlflags=' -s' cccdlflags=' ', lddlflags=' -s' Characteristics of this binary (from libperl): Compile-time options: MULTIPLICITY NO_MATHOMS PERL_DONT_CREATE_GVSV PERL_IMPLICIT_CONTEXT PERL_MALLOC_WRAP PERL_USE_SAFE_PUTENV USE_64_BIT_INT USE_ITHREADS USE_LARGE_FILES USE_PERLIO USE_REENTRANT_API Locally applied patches: DEVEL 31430 Built under cygwin Compiled at Jun 20 2007 13:20:40 %ENV: PERLIO="perlio" CYGWIN="ntsec" @INC: /usr/lib/perl5/5.9/cygwin /usr/lib/perl5/5.9 .
  Wed Jun 20 15:37:48 2007 jdhedden [...] cpan.org - Correspondence added
When I activated the 'warn Dumper($tmp);' statement above the failing test, I got: { '1182367251' => { '1182300000' => { 'prepare' => [ 1, 0, 0, 0, 0, 0, 0 ] } } } not ok 44 - !Time and !Time~100000 should work # Failed test '!Time and !Time~100000 should work' # at t/40profile.t line 295. # Structures begin differing at: # $got->{1182367252} = Does not exist # $expected->{1182367252} = HASH(0x1031eb70) When I tried the test a few more time, it does pass sometime. However, it fails more than 50% of the time. The failures are always with the key one less than expected. With the attached patch, the test always seems to pass.
--- DBI-1.57/t/40profile.t.orig 2007-06-20 15:36:04.000000000 -0400 +++ DBI-1.57/t/40profile.t 2007-06-20 15:36:12.000000000 -0400 @@ -284,9 +284,9 @@ undef $sth; my $factor = 100_000; # ~27 hours $dbh->{Profile}->{Path} = [ '!Time', "!Time~$factor", '!MethodName' ]; +$t1 = time(); $dbh->{Profile}->{Data} = undef; -$t1 = time()+1; 1 while time() < $t1; # spin till new second starts $sth = $dbh->prepare("select name from ."); $t2 = int($t1/$factor)*$factor;
  Thu Jun 21 10:29:54 2007 Tim.Bunce [...] pobox.com - Correspondence added
CC: undisclosed-recipients: ;
Subject: Re: [rt.cpan.org #27666] Test failure in t/40profile.t
Date: Thu, 21 Jun 2007 15:29:33 +0100
To: "Jerry D. Hedden via RT" <bug-DBI [...] rt.cpan.org>
From: Tim Bunce <Tim.Bunce [...] pobox.com>
On Wed, Jun 20, 2007 at 03:37:51PM -0400, Jerry D. Hedden via RT wrote: Show quoted text
> > When I activated the 'warn Dumper($tmp);' statement above > the failing test, I got: > > { > '1182367251' => { > '1182300000' => {
Show quoted text
> # $got->{1182367252} = Does not exist > # $expected->{1182367252} = HASH(0x1031eb70) > > > When I tried the test a few more time, it does pass > sometime. However, it fails more than 50% of the time. > The failures are always with the key one less than > expected. > With the attached patch, the test always seems to pass.
--- DBI-1.57/t/40profile.t.orig 2007-06-20 15:36:04.000000000 -0400 +++ DBI-1.57/t/40profile.t 2007-06-20 15:36:12.000000000 -0400 @@ -284,9 +284,9 @@ undef $sth; my $factor = 100_000; # ~27 hours $dbh->{Profile}->{Path} = [ '!Time', "!Time~$factor", '!MethodName' ]; +$t1 = time(); $dbh->{Profile}->{Data} = undef; -$t1 = time()+1; 1 while time() < $t1; # spin till new second starts $sth = $dbh->prepare("select name from ."); $t2 = int($t1/$factor)*$factor; Odd. That spin loop is there to make sure that a fresh second has only just started so there's no risk of the time incrementing during the test. Are you on a dual cpu machine? Do you sometimes get a warning from the t/40profile.t test about the clock going backwards? Does it work more reliably if you revert the patch, back the the original, and then just move the whole "$t1 = ..." line up to just after the "my $factor"? Tim.
  Thu Jun 21 10:29:58 2007 The RT System itself - Status changed from 'new' to 'open'
  Thu Jun 21 11:15:42 2007 jdhedden [...] cpan.org - Correspondence added
Subject: Re: [rt.cpan.org #27666] Test failure in t/40profile.t
Date: Thu, 21 Jun 2007 11:15:24 -0400
To: bug-DBI [...] rt.cpan.org
From: "Jerry D. Hedden" <jdhedden [...] cpan.org>
Show quoted text
> Are you on a dual cpu machine?
No. Windows box with Pentium 4. Show quoted text
> Do you sometimes get a warning from the t/40profile.t test > about the clock going backwards?
No. Show quoted text
> Does it work more reliably if you revert the patch, back > the the original, and then just move the whole "$t1 = ..." > line up to just after the "my $factor"?
No. Fails nearly all the time with the same problem - $t1 is 1 too large.
  Fri Jun 22 04:14:41 2007 Tim.Bunce [...] pobox.com - Correspondence added
CC: TIMB [...] cpan.org
Subject: Re: [rt.cpan.org #27666] Test failure in t/40profile.t
Date: Fri, 22 Jun 2007 09:14:13 +0100
To: "Jerry D. Hedden via RT" <bug-DBI [...] rt.cpan.org>
From: Tim Bunce <Tim.Bunce [...] pobox.com>
On Thu, Jun 21, 2007 at 11:15:44AM -0400, Jerry D. Hedden via RT wrote: Show quoted text
> > <URL: http://rt.cpan.org/Ticket/Display.html?id=27666 > >
> > Are you on a dual cpu machine?
> > No. Windows box with Pentium 4. >
> > Do you sometimes get a warning from the t/40profile.t test > > about the clock going backwards?
> > No. >
> > Does it work more reliably if you revert the patch, back > > the the original, and then just move the whole "$t1 = ..." > > line up to just after the "my $factor"?
> > No. Fails nearly all the time with the same problem - $t1 > is 1 too large.
Umm. Okay, let's try this patch over the original (or use the attached file). Thanks! Tim. Index: t/40profile.t =================================================================== --- t/40profile.t (revision 9660) +++ t/40profile.t (working copy) @@ -9,7 +9,7 @@ use Config; use DBI::Profile; -use DBI; +use DBI qw(dbi_time); use Data::Dumper; use File::Spec; use Storable qw(dclone); @@ -149,7 +149,7 @@ ok($time1 >= $^T); ok($time2 >= $^T); ok($time1 <= $time2); -my $next = time + 1; +my $next = int(dbi_time()) + 1; ok($next > $time1) or warn "next $next > first $time1: failed\n"; ok($next > $time2) or warn "next $next > last $time2: failed\n"; if ($shortest < 0) { @@ -286,15 +286,16 @@ $dbh->{Profile}->{Path} = [ '!Time', "!Time~$factor", '!MethodName' ]; $dbh->{Profile}->{Data} = undef; -$t1 = time()+1; 1 while time() < $t1; # spin till new second starts -$sth = $dbh->prepare("select name from ."); +$t1 = int(dbi_time())+1; 1 while int(dbi_time()) < $t1; # spin till new second starts $t2 = int($t1/$factor)*$factor; +$sth = $dbh->prepare("select name from ."); + $tmp = sanitize_profile_data_nodes($dbh->{Profile}{Data}); -#warn Dumper($tmp); is_deeply $tmp, { $t1 => { $t2 => { prepare => [ 1, 0, 0, 0, 0, 0, 0 ] }} -}, "!Time and !Time~$factor should work"; +}, "!Time and !Time~$factor should work" + or print Dumper($tmp); print "testing &norm_std_n3 in Path\n";

Message body is not shown because sender requested not to inline it.

  Fri Jun 22 08:28:08 2007 jdhedden [...] cpan.org - Correspondence added
CC: TIMB [...] cpan.org
Subject: Re: [rt.cpan.org #27666] Test failure in t/40profile.t
Date: Fri, 22 Jun 2007 08:27:52 -0400
To: bug-DBI [...] rt.cpan.org
From: "Jerry D. Hedden" <jdhedden [...] cpan.org>
Show quoted text
> Okay, let's try this patch over the original (or use the attached > file). Thanks!
Bravo. That works.
  Sat Jun 23 07:39:15 2007 TIMB [...] cpan.org - Correspondence added
Fixed by changing time() to int(dbi_time())
  Sat Jun 23 07:39:20 2007 TIMB [...] cpan.org - Status changed from 'open' to 'resolved'