From e9f632559246c582c90f58507aedfbb3629fa1eb Mon Sep 17 00:00:00 2001
From: Daniel Nichter <daniel@percona.com>
Date: Tue, 14 Feb 2012 09:31:47 -0700
Subject: [PATCH] Add hires timestamp to PTDEVDEBUG.  Debug daemonize.pl.  Make
 wait_until() defaults shorter.

---
 lib/PerconaTest.pm          | 13 ++++++++-----
 t/lib/Daemon.t              | 12 ++++++++----
 t/lib/samples/daemonizes.pl | 19 ++++++++++++++-----
 3 files changed, 30 insertions(+), 14 deletions(-)

diff --git a/lib/PerconaTest.pm b/lib/PerconaTest.pm
index 5b6e5aaa..4943d7ba 100644
--- a/lib/PerconaTest.pm
+++ b/lib/PerconaTest.pm
@@ -31,10 +31,10 @@ package PerconaTest;
 use strict;
 use warnings FATAL => 'all';
 use English qw(-no_match_vars);
-use constant PTDEBUG => $ENV{PTDEBUG} || 0;
+use constant PTDEVDEBUG => $ENV{PTDEVDEBUG} || 0;
 
 use Test::More;
-use Time::HiRes qw(sleep);
+use Time::HiRes qw(sleep time);
 use POSIX qw(signal_h);
 use Data::Dumper;
 $Data::Dumper::Indent    = 1;
@@ -220,14 +220,16 @@ sub parse_file {
 # Wait until code returns true.
 sub wait_until {
    my ( $code, $t, $max_t ) = @_;
-   $t     ||= .5;
-   $max_t ||= 10;
+   $t     ||= .25;
+   $max_t ||= 5;
 
    my $slept = 0;
    while ( $slept <= $max_t ) {
       return 1 if $code->();
+      PTDEVDEBUG && _d('wait_until sleeping', $t);
       sleep $t;
       $slept += $t;
+      PTDEVDEBUG && _d('wait_until slept', $slept, 'of', $max_t);
    }
    return 0;
 }
@@ -622,7 +624,8 @@ sub _d {
    @_ = map { (my $temp = $_) =~ s/\n/\n# /g; $temp; }
         map { defined $_ ? $_ : 'undef' }
         @_;
-   print STDERR "# $package:$line $PID ", join(' ', @_), "\n";
+   my $t = sprintf '%.3f', time;
+   print STDERR "# $package:$line $PID $t ", join(' ', @_), "\n";
 }
 
 1;
diff --git a/t/lib/Daemon.t b/t/lib/Daemon.t
index f20437c9..21faee35 100644
--- a/t/lib/Daemon.t
+++ b/t/lib/Daemon.t
@@ -54,17 +54,19 @@ ok(! -f $pid_file, 'Removes PID file upon exit');
 # ############################################################################
 rm_tmp_files();
 
-system("$cmd 2 --daemonize --log $log_file");
+system("$cmd 0 --daemonize --log $log_file");
 PerconaTest::wait_for_files($log_file);
 ok(-f $log_file, 'Log file exists');
 
-sleep 2;
 $output = `cat $log_file`;
 like($output, qr/STDOUT\nSTDERR\n/, 'STDOUT and STDERR went to log file');
 
+my $log_size = -s $log_file;
+PTDEVDEBUG && PerconaTest::_d('log size', $log_size);
+
 # Check that the log file is appended to.
 system("$cmd 0 --daemonize --log $log_file");
-PerconaTest::wait_for_files($log_file);
+PerconaTest::wait_until(sub { -s $log_file > $log_size });
 $output = `cat $log_file`;
 like(
    $output,
@@ -82,7 +84,7 @@ ok(
    'PID file already exists'
 );
 
-$output = `PTDEBUG=1 $cmd 0 --daemonize --pid $pid_file 2>&1`;
+$output = `$cmd 2 --daemonize --pid $pid_file 2>&1`;
 like(
    $output,
    qr{The PID file $pid_file already exists},
@@ -126,6 +128,8 @@ SKIP: {
    $proc_fd_0 = -l "/proc/$pid/0"    ? "/proc/$pid/0"
               : -l "/proc/$pid/fd/0" ? "/proc/$pid/fd/0"
               : die "Cannot find fd 0 symlink in /proc/$pid";
+   PTDEVDEBUG && PerconaTest::_d('pid_file', $pid_file,
+      'pid', $pid, 'proc_fd_0', $proc_fd_0, `ls -l $proc_fd_0`);
    $stdin = readlink $proc_fd_0;
    like(
       $stdin,
diff --git a/t/lib/samples/daemonizes.pl b/t/lib/samples/daemonizes.pl
index 33053294..b9319487 100755
--- a/t/lib/samples/daemonizes.pl
+++ b/t/lib/samples/daemonizes.pl
@@ -11,9 +11,10 @@ BEGIN {
 
 use strict;
 use warnings FATAL => 'all';
-
 use English qw(-no_match_vars);
-use constant PTDEBUG => $ENV{PTDEBUG};
+use constant PTDEVDEBUG => $ENV{PTDEVDEBUG};
+
+use Time::HiRes qw(sleep);
 
 use Daemon;
 use OptionParser;
@@ -23,7 +24,8 @@ my $o = new OptionParser(file => "$trunk/t/lib/samples/daemonizes.pl");
 $o->get_specs();
 $o->get_opts();
 
-if ( scalar @ARGV < 1 ) {
+my ($sleep_time) = shift @ARGV;
+if ( !defined $sleep_time ) {
    $o->save_error('No SLEEP_TIME specified');
 }
 
@@ -31,15 +33,22 @@ $o->usage_or_errors();
 
 my $daemon;
 if ( $o->get('daemonize') ) {
+   PTDEVDEBUG && PerconaTest::_d('daemonizing');
+
+   $OUTPUT_AUTOFLUSH = 1;
+
    $daemon = new Daemon(o=>$o);
    $daemon->daemonize();
+   PTDEVDEBUG && PerconaTest::_d('daemonized');
 
    print "STDOUT\n";
    print STDERR "STDERR\n";
 
-   sleep $ARGV[0];
+   PTDEVDEBUG && PerconaTest::_d('daemon sleep', $sleep_time);
+   sleep $sleep_time;
 }
 
+PTDEVDEBUG && PerconaTest::_d('daemon done');
 exit;
 
 # ############################################################################
@@ -50,7 +59,7 @@ exit;
 
 =head1 SYNOPSIS
 
-Usage: daemonizes.pl SLEEP_TIME [ARGS]
+Usage: daemonizes.pl SLEEP_TIME
 
 daemonizes.pl daemonizes, prints to STDOUT and STDERR, sleeps and exits.