← Back to branch summary

~ubuntu-branches/ubuntu/trusty/proftpd-dfsg/trusty

« back to all changes in this revision

Viewing changes to tests/t/lib/ProFTPD/Tests/Logging/ExtendedLog.pm

  • Committer: Bazaar Package Importer
  • Author(s): Francesco Paolo Lovergine
  • Date: 2011-10-06 12:57:29 UTC
  • mfrom: (1.2.4 upstream)
  • Revision ID: james.westby@ubuntu.com-20111006125729-wiq6d3yzf2ensafj
Tags: 1.3.4~rc3-1
* New upstream pre-release.
* Refreshed all patches.
* Changed patch xferstats.holger-preiss to fix a few warnings and use
  Getopt::Std instead of the old getopts.pl which will be removed soon or
  later in perl5. Thanks lintian.
* Policy bumped to 3.9.2.

Show diffs side-by-side

added added

removed removed

Lines of Context:
tests/t/lib/ProFTPD/Tests/Logging/ExtendedLog.pm
199
199
    test_class => [qw(forking)],
200
200
  },
201
201
 
 
202
  extlog_xfer_timeout_bug3696 => {
 
203
    order => ++$order,
 
204
    test_class => [qw(bug forking)],
 
205
  },
 
206
 
 
207
  extlog_sftp_xfer_timeout_bug3696 => {
 
208
    order => ++$order,
 
209
    test_class => [qw(bug forking mod_sftp ssh2)],
 
210
  },
 
211
 
202
212
  # XXX Need unit tests for all LogFormat variables
203
213
};
204
214
 
311
321
 
312
322
      my $buf;
313
323
      $conn->read($buf, 8192, 30);
314
 
      $conn->close();
 
324
      eval { $conn->close() };
315
325
    };
316
326
 
317
327
    if ($@) {
446
456
 
447
457
      my $buf = "Foo!\n";
448
458
      $conn->write($buf, length($buf));
449
 
      $conn->close();
 
459
      eval { $conn->close() };
450
460
    };
451
461
 
452
462
    if ($@) {
1349
1359
 
1350
1360
      my $buf;
1351
1361
      $conn->read($buf, 8192, 30);
1352
 
      $conn->close();
 
1362
      eval { $conn->close() };
1353
1363
 
1354
1364
      $client->quit();
1355
1365
    };
1510
1520
          $client->response_msg());
1511
1521
      }
1512
1522
 
1513
 
      $conn->close();
 
1523
      eval { $conn->close() };
1514
1524
      $client->quit();
1515
1525
    };
1516
1526
 
2174
2184
 
2175
2185
      my $buf;
2176
2186
      $conn->read($buf, 8192, 30);
2177
 
      $conn->close();
 
2187
      eval { $conn->close() };
2178
2188
    };
2179
2189
 
2180
2190
    if ($@) {
2306
2316
 
2307
2317
      my $buf;
2308
2318
      $conn->read($buf, 8192, 30);
2309
 
      $conn->close();
 
2319
      eval { $conn->close() };
2310
2320
    };
2311
2321
 
2312
2322
    if ($@) {
2728
2738
 
2729
2739
      my $buf = "ABCD\n" x 8;
2730
2740
      $conn->write($buf, length($buf), 30);
2731
 
      $conn->close();
 
2741
      eval { $conn->close() };
2732
2742
 
2733
2743
      my $resp_code = $client->response_code();
2734
2744
      my $resp_msg = $client->response_msg();
2911
2921
 
2912
2922
      my $buf;
2913
2923
      $conn->read($buf, 16382, 30);
2914
 
      $conn->close();
 
2924
      eval { $conn->close() };
2915
2925
 
2916
2926
      my $resp_code = $client->response_code();
2917
2927
      my $resp_msg = $client->response_msg();
3090
3100
      my $buf = "ABCD\n" x 8;
3091
3101
      my $deflated = compress($buf);
3092
3102
      $conn->write($deflated, length($deflated), 30);
3093
 
      $conn->close();
 
3103
      eval { $conn->close() };
3094
3104
 
3095
3105
      my $resp_code = $client->response_code();
3096
3106
      my $resp_msg = $client->response_msg();
3350
3360
        next unless $cmd eq 'QUIT';
3351
3361
 
3352
3362
        # The expected bytes in/out will vary on the ciphers used, etc.
3353
 
        my $expected_min = 42340;
3354
 
        my $expected_max = 42358;
 
3363
        my $expected_min = 42240;
 
3364
        my $expected_max = 42378;
3355
3365
        $self->assert($expected_min <= $bytes_in &&
3356
3366
                      $expected_max >= $bytes_in,
3357
3367
          test_msg("Expected $expected_min - $expected_max, got $bytes_in"));
3550
3560
                      $expected_max >= $bytes_in,
3551
3561
          test_msg("Expected $expected_min - $expected_max, got $bytes_in"));
3552
3562
 
3553
 
        $expected_min = 2156;
 
3563
        $expected_min = 2116;
3554
3564
        $expected_max = 2196;
3555
3565
        $self->assert($expected_min <= $bytes_out &&
3556
3566
                      $expected_max >= $bytes_out,
3852
3862
 
3853
3863
      my $buf = "ABCD\n" x 8;
3854
3864
      $conn->write($buf, length($buf), 30);
3855
 
      $conn->close();
 
3865
      eval { $conn->close() };
3856
3866
 
3857
3867
      my $resp_code = $client->response_code();
3858
3868
      my $resp_msg = $client->response_msg();
3916
3926
        # number is ephemeral, chosen by the kernel.
3917
3927
 
3918
3928
        my $expected_min = 232;
3919
 
        my $expected_max = 236;
 
3929
        my $expected_max = 286;
3920
3930
        $self->assert($expected_min <= $bytes_out &&
3921
3931
                      $expected_max >= $bytes_out,
3922
3932
          test_msg("Expected $expected_min - $expected_max, got $bytes_out"));
5769
5779
  unlink($log_file);
5770
5780
}
5771
5781
 
 
5782
sub extlog_xfer_timeout_bug3696 {
 
5783
  my $self = shift;
 
5784
  my $tmpdir = $self->{tmpdir};
 
5785
 
 
5786
  my $config_file = "$tmpdir/extlog.conf";
 
5787
  my $pid_file = File::Spec->rel2abs("$tmpdir/extlog.pid");
 
5788
  my $scoreboard_file = File::Spec->rel2abs("$tmpdir/extlog.scoreboard");
 
5789
 
 
5790
  my $log_file = File::Spec->rel2abs('tests.log');
 
5791
 
 
5792
  my $auth_user_file = File::Spec->rel2abs("$tmpdir/extlog.passwd");
 
5793
  my $auth_group_file = File::Spec->rel2abs("$tmpdir/extlog.group");
 
5794
 
 
5795
  my $test_file = File::Spec->rel2abs("$tmpdir/foo.txt");
 
5796
 
 
5797
  my $user = 'proftpd';
 
5798
  my $passwd = 'test';
 
5799
  my $group = 'ftpd';
 
5800
  my $home_dir = File::Spec->rel2abs($tmpdir);
 
5801
  my $uid = 500;
 
5802
  my $gid = 500;
 
5803
 
 
5804
  # Make sure that, if we're running as root, that the home directory has
 
5805
  # permissions/privs set for the account we create
 
5806
  if ($< == 0) {
 
5807
    unless (chmod(0755, $home_dir)) {
 
5808
      die("Can't set perms on $home_dir to 0755: $!");
 
5809
    }
 
5810
 
 
5811
    unless (chown($uid, $gid, $home_dir)) {
 
5812
      die("Can't set owner of $home_dir to $uid/$gid: $!");
 
5813
    }
 
5814
  }
 
5815
 
 
5816
  auth_user_write($auth_user_file, $user, $passwd, $uid, $gid, $home_dir,
 
5817
    '/bin/bash');
 
5818
  auth_group_write($auth_group_file, $group, $gid, $user);
 
5819
 
 
5820
  my $ext_log = File::Spec->rel2abs("$tmpdir/custom.log");
 
5821
 
 
5822
  my $timeout_stalled = 2;
 
5823
 
 
5824
  my $config = {
 
5825
    PidFile => $pid_file,
 
5826
    ScoreboardFile => $scoreboard_file,
 
5827
    SystemLog => $log_file,
 
5828
 
 
5829
    AuthUserFile => $auth_user_file,
 
5830
    AuthGroupFile => $auth_group_file,
 
5831
 
 
5832
    LogFormat => 'custom "%f"',
 
5833
    ExtendedLog => "$ext_log WRITE custom",
 
5834
 
 
5835
    TimeoutStalled => $timeout_stalled,
 
5836
 
 
5837
    IfModules => {
 
5838
      'mod_delay.c' => {
 
5839
        DelayEngine => 'off',
 
5840
      },
 
5841
    },
 
5842
  };
 
5843
 
 
5844
  my ($port, $config_user, $config_group) = config_write($config_file, $config);
 
5845
 
 
5846
  # Open pipes, for use between the parent and child processes.  Specifically,
 
5847
  # the child will indicate when it's done with its test by writing a message
 
5848
  # to the parent.
 
5849
  my ($rfh, $wfh);
 
5850
  unless (pipe($rfh, $wfh)) {
 
5851
    die("Can't open pipe: $!");
 
5852
  }
 
5853
 
 
5854
  my $ex;
 
5855
 
 
5856
  # Fork child
 
5857
  $self->handle_sigchld();
 
5858
  defined(my $pid = fork()) or die("Can't fork: $!");
 
5859
  if ($pid) {
 
5860
    eval {
 
5861
      my $client = ProFTPD::TestSuite::FTP->new('127.0.0.1', $port);
 
5862
      $client->login($user, $passwd);
 
5863
 
 
5864
      my $conn = $client->stor_raw('foo.txt');
 
5865
      unless ($conn) {
 
5866
        die("Failed to STOR foo.txt: " . $client->response_code() . " " .
 
5867
          $client->response_msg());
 
5868
      }
 
5869
 
 
5870
      # Wait for longer than the TimeoutStalled limit
 
5871
      sleep($timeout_stalled + 2);
 
5872
 
 
5873
      eval {
 
5874
        my $buf = "Foo!\n";
 
5875
        $conn->write($buf, length($buf));
 
5876
        eval { $conn->close() };
 
5877
 
 
5878
        $client->quit();
 
5879
      };
 
5880
    };
 
5881
 
 
5882
    if ($@) {
 
5883
      $ex = $@;
 
5884
    }
 
5885
 
 
5886
    $wfh->print("done\n");
 
5887
    $wfh->flush();
 
5888
 
 
5889
  } else {
 
5890
    eval { server_wait($config_file, $rfh) };
 
5891
    if ($@) {
 
5892
      warn($@);
 
5893
      exit 1;
 
5894
    }
 
5895
 
 
5896
    exit 0;
 
5897
  }
 
5898
 
 
5899
  # Stop server
 
5900
  server_stop($pid_file);
 
5901
 
 
5902
  $self->assert_child_ok($pid);
 
5903
 
 
5904
  # Now, read in the ExtendedLog, and see whether the %f variable was
 
5905
  # properly written out.  Bug#3696 occurred because mod_log would not
 
5906
  # properly notice that a data transfer was in progress when the
 
5907
  # session was disconnected due to hitting TimeoutStalled.
 
5908
  # information.
 
5909
  if (open(my $fh, "< $ext_log")) {
 
5910
    my $line = <$fh>;
 
5911
    chomp($line);
 
5912
    close($fh);
 
5913
 
 
5914
    $self->assert($test_file eq $line,
 
5915
      test_msg("Expected '$test_file', got '$line'"));
 
5916
 
 
5917
  } else {
 
5918
    die("Can't read $ext_log: $!");
 
5919
  }
 
5920
 
 
5921
  if ($ex) {
 
5922
    die($ex);
 
5923
  }
 
5924
 
 
5925
  unlink($log_file);
 
5926
}
 
5927
 
 
5928
sub extlog_sftp_xfer_timeout_bug3696 {
 
5929
  my $self = shift;
 
5930
  my $tmpdir = $self->{tmpdir};
 
5931
 
 
5932
  my $config_file = "$tmpdir/extlog.conf";
 
5933
  my $pid_file = File::Spec->rel2abs("$tmpdir/extlog.pid");
 
5934
  my $scoreboard_file = File::Spec->rel2abs("$tmpdir/extlog.scoreboard");
 
5935
 
 
5936
  my $log_file = File::Spec->rel2abs('tests.log');
 
5937
 
 
5938
  my $auth_user_file = File::Spec->rel2abs("$tmpdir/extlog.passwd");
 
5939
  my $auth_group_file = File::Spec->rel2abs("$tmpdir/extlog.group");
 
5940
 
 
5941
  my $user = 'proftpd';
 
5942
  my $passwd = 'test';
 
5943
  my $group = 'ftpd';
 
5944
  my $home_dir = File::Spec->rel2abs($tmpdir);
 
5945
  my $uid = 500;
 
5946
  my $gid = 500;
 
5947
 
 
5948
  # Make sure that, if we're running as root, that the home directory has
 
5949
  # permissions/privs set for the account we create
 
5950
  if ($< == 0) {
 
5951
    unless (chmod(0755, $home_dir)) {
 
5952
      die("Can't set perms on $home_dir to 0755: $!");
 
5953
    }
 
5954
 
 
5955
    unless (chown($uid, $gid, $home_dir)) {
 
5956
      die("Can't set owner of $home_dir to $uid/$gid: $!");
 
5957
    }
 
5958
  }
 
5959
 
 
5960
  auth_user_write($auth_user_file, $user, $passwd, $uid, $gid, $home_dir,
 
5961
    '/bin/bash');
 
5962
  auth_group_write($auth_group_file, $group, $gid, $user);
 
5963
 
 
5964
  my $rsa_host_key = File::Spec->rel2abs('t/etc/modules/mod_sftp/ssh_host_rsa_key');
 
5965
  my $dsa_host_key = File::Spec->rel2abs('t/etc/modules/mod_sftp/ssh_host_dsa_key');
 
5966
 
 
5967
  my $ext_log = File::Spec->rel2abs("$tmpdir/custom.log");
 
5968
 
 
5969
  my $test_file = File::Spec->rel2abs("$tmpdir/test.txt");
 
5970
  my $timeout_stalled = 2;
 
5971
 
 
5972
  my $config = {
 
5973
    PidFile => $pid_file,
 
5974
    ScoreboardFile => $scoreboard_file,
 
5975
    SystemLog => $log_file,
 
5976
    TraceLog => $log_file,
 
5977
    Trace => 'DEFAULT:10 ssh2:20 sftp:20 scp:20',
 
5978
 
 
5979
    AuthUserFile => $auth_user_file,
 
5980
    AuthGroupFile => $auth_group_file,
 
5981
 
 
5982
    LogFormat => 'custom "%f"',
 
5983
    ExtendedLog => "$ext_log WRITE custom",
 
5984
 
 
5985
    TimeoutStalled => $timeout_stalled,
 
5986
 
 
5987
    IfModules => {
 
5988
      'mod_delay.c' => {
 
5989
        DelayEngine => 'off',
 
5990
      },
 
5991
 
 
5992
      'mod_sftp.c' => [
 
5993
        "SFTPEngine on",
 
5994
        "SFTPLog $log_file",
 
5995
        "SFTPHostKey $rsa_host_key",
 
5996
        "SFTPHostKey $dsa_host_key",
 
5997
      ],
 
5998
    },
 
5999
  };
 
6000
 
 
6001
  my ($port, $config_user, $config_group) = config_write($config_file, $config);
 
6002
 
 
6003
  # Open pipes, for use between the parent and child processes.  Specifically,
 
6004
  # the child will indicate when it's done with its test by writing a message
 
6005
  # to the parent.
 
6006
  my ($rfh, $wfh);
 
6007
  unless (pipe($rfh, $wfh)) {
 
6008
    die("Can't open pipe: $!");
 
6009
  }
 
6010
 
 
6011
  require Net::SSH2;
 
6012
 
 
6013
  my $ex;
 
6014
 
 
6015
  # Ignore SIGPIPE
 
6016
  local $SIG{PIPE} = sub { };
 
6017
 
 
6018
  # Fork child
 
6019
  $self->handle_sigchld();
 
6020
  defined(my $pid = fork()) or die("Can't fork: $!");
 
6021
  if ($pid) {
 
6022
    eval {
 
6023
      my $ssh2 = Net::SSH2->new();
 
6024
 
 
6025
      sleep(1);
 
6026
 
 
6027
      unless ($ssh2->connect('127.0.0.1', $port)) {
 
6028
        my ($err_code, $err_name, $err_str) = $ssh2->error();
 
6029
        die("Can't connect to SSH2 server: [$err_name] ($err_code) $err_str");
 
6030
      }
 
6031
 
 
6032
      unless ($ssh2->auth_password($user, $passwd)) {
 
6033
        my ($err_code, $err_name, $err_str) = $ssh2->error();
 
6034
        die("Can't login to SSH2 server: [$err_name] ($err_code) $err_str");
 
6035
      }
 
6036
 
 
6037
      my $sftp = $ssh2->sftp();
 
6038
      unless ($sftp) {
 
6039
        my ($err_code, $err_name, $err_str) = $ssh2->error();
 
6040
        die("Can't use SFTP on SSH2 server: [$err_name] ($err_code) $err_str");
 
6041
      }
 
6042
 
 
6043
      my $fh = $sftp->open('test.txt', O_WRONLY|O_CREAT|O_TRUNC, 0644);
 
6044
      unless ($fh) {
 
6045
        my ($err_code, $err_name) = $sftp->error();
 
6046
        die("Can't open test.txt: [$err_name] ($err_code)");
 
6047
      }
 
6048
 
 
6049
      print $fh "ABCD\n" x 8;
 
6050
 
 
6051
      # Wait for longer than the TimeoutStalled limit
 
6052
      sleep($timeout_stalled + 2);
 
6053
 
 
6054
      # To issue the FXP_CLOSE, we have to explicitly destroy the filehandle
 
6055
      $fh = undef;
 
6056
 
 
6057
      # To issue the CHANNEL_CLOSE, we have to explicitly destroy the sftp
 
6058
      # object.  Sigh.
 
6059
      $sftp = undef;
 
6060
 
 
6061
      $ssh2->disconnect();
 
6062
    };
 
6063
 
 
6064
    if ($@) {
 
6065
      $ex = $@;
 
6066
    }
 
6067
 
 
6068
    $wfh->print("done\n");
 
6069
    $wfh->flush();
 
6070
 
 
6071
  } else {
 
6072
    eval { server_wait($config_file, $rfh) };
 
6073
    if ($@) {
 
6074
      warn($@);
 
6075
      exit 1;
 
6076
    }
 
6077
 
 
6078
    exit 0;
 
6079
  }
 
6080
 
 
6081
  # Stop server
 
6082
  server_stop($pid_file);
 
6083
 
 
6084
  $self->assert_child_ok($pid);
 
6085
 
 
6086
  if ($ex) {
 
6087
    die($ex);
 
6088
  }
 
6089
 
 
6090
  # Now, read in the ExtendedLog, and see whether the %f variable was
 
6091
  # properly written out.  Bug#3696 occurred because mod_log would not
 
6092
  # properly notice that a data transfer was in progress when the
 
6093
  # session was disconnected due to hitting TimeoutStalled.
 
6094
  # information.
 
6095
  if (open(my $fh, "< $ext_log")) {
 
6096
    my $line = <$fh>;
 
6097
    chomp($line);
 
6098
    close($fh);
 
6099
 
 
6100
    $self->assert($test_file eq $line,
 
6101
      test_msg("Expected '$test_file', got '$line'"));
 
6102
 
 
6103
  } else {
 
6104
    die("Can't read $ext_log: $!");
 
6105
  }
 
6106
 
 
6107
  unlink($log_file);
 
6108
}
 
6109
 
5772
6110
1;