t/60-fsck.t

   1 # -*-perl-*-
   2 # some of the comments match the comments in MogileFS/Worker/Fsck.pm
   3 # _exactly_ for reference purposes
   4 use strict;
   5 use warnings;
   6 use Test::More;
   7 use FindBin qw($Bin);
   8 use Time::HiRes qw(sleep);
   9 use MogileFS::Server;
  10 use MogileFS::Test;
  11 use HTTP::Request;
  12 find_mogclient_or_skip();
  13 use MogileFS::Admin;
  14
  15 my $sto = eval { temp_store(); };
  16 if (!$sto) {
  17     plan skip_all => "Can't create temporary test database: $@";
  18     exit 0;
  19 }
  20
  21 use File::Temp;
  22 my %mogroot;
  23 $mogroot{1} = File::Temp::tempdir( CLEANUP => 1 );
  24 $mogroot{2} = File::Temp::tempdir( CLEANUP => 1 );
  25 my $dev2host = { 1 => 1, 2 => 2, };
  26 foreach (sort { $a <=> $b } keys %$dev2host) {
  27     my $root = $mogroot{$dev2host->{$_}};
  28     mkdir("$root/dev$_") or die "Failed to create dev$_ dir: $!";
  29 }
  30
  31 my $ms1 = create_mogstored("127.0.1.1", $mogroot{1});
  32 ok($ms1, "got mogstored1");
  33 my $ms2 = create_mogstored("127.0.1.2", $mogroot{2});
  34 ok($ms1, "got mogstored2");
  35
  36 while (! -e "$mogroot{1}/dev1/usage" &&
  37        ! -e "$mogroot{2}/dev2/usage") {
  38     print "Waiting on usage...\n";
  39     sleep(.25);
  40 }
  41
  42 my $tmptrack = create_temp_tracker($sto);
  43 ok($tmptrack);
  44
  45 my $admin = IO::Socket::INET->new(PeerAddr => '127.0.0.1:7001');
  46 $admin or die "failed to create admin socket: $!";
  47 my $moga = MogileFS::Admin->new(hosts => [ "127.0.0.1:7001" ]);
  48 my $mogc = MogileFS::Client->new(
  49                                  domain => "testdom",
  50                                  hosts  => [ "127.0.0.1:7001" ],
  51                                  );
  52 my $be = $mogc->{backend}; # gross, reaching inside of MogileFS::Client
  53
  54 # test some basic commands to backend
  55 ok($tmptrack->mogadm("domain", "add", "testdom"), "created test domain");
  56 ok($tmptrack->mogadm("class", "add", "testdom", "2copies", "--mindevcount=2"), "created 2copies class in testdom");
  57 ok($tmptrack->mogadm("class", "add", "testdom", "1copy", "--mindevcount=1"), "created 1copy class in testdom");
  58
  59 ok($tmptrack->mogadm("host", "add", "hostA", "--ip=127.0.1.1", "--status=alive"), "created hostA");
  60 ok($tmptrack->mogadm("host", "add", "hostB", "--ip=127.0.1.2", "--status=alive"), "created hostB");
  61
  62 ok($tmptrack->mogadm("device", "add", "hostA", 1), "created dev1 on hostA");
  63 ok($tmptrack->mogadm("device", "add", "hostB", 2), "created dev2 on hostB");
  64
  65 sub wait_for_monitor {
  66     my $be = shift;
  67     my $was = $be->{timeout};  # can't use local on phash :(
  68     $be->{timeout} = 10;
  69     ok($be->do_request("clear_cache", {}), "waited for monitor")
  70         or die "Failed to wait for monitor";
  71     ok($be->do_request("clear_cache", {}), "waited for monitor")
  72         or die "Failed to wait for monitor";
  73     $be->{timeout} = $was;
  74 }
  75
  76 sub wait_for_empty_queue {
  77     my ($table, $dbh) = @_;
  78     my $limit = 600;
  79     my $delay = 0.1;
  80     my $i = $limit;
  81     my $count;
  82     while ($i > 0) {
  83         $count = $dbh->selectrow_array("SELECT COUNT(*) from $table");
  84         return if ($count == 0);
  85         sleep $delay;
  86     }
  87     my $time = $delay * $limit;
  88     die "$table is not empty after ${time}s!";
  89 }
  90
  91 sub full_fsck {
  92     my ($tmptrack, $dbh) = @_;
  93
  94     # this should help prevent race conditions:
  95     wait_for_empty_queue("file_to_queue", $dbh);
  96
  97     ok($tmptrack->mogadm("fsck", "stop"), "stop fsck");
  98     ok($tmptrack->mogadm("fsck", "clearlog"), "clear fsck log");
  99     ok($tmptrack->mogadm("fsck", "reset"), "reset fsck");
 100     ok($tmptrack->mogadm("fsck", "start"), "started fsck");
 101 }
 102
 103 wait_for_monitor($be);
 104
 105 my ($req, $rv, %opts, @paths, @fsck_log, $info);
 106 my $ua = LWP::UserAgent->new;
 107 my $key = "testkey";
 108 my $dbh = $sto->dbh;
 109
 110 use Data::Dumper;
 111
 112 # upload a file and wait for replica to appear
 113 {
 114     my $fh = $mogc->new_file($key, "1copy");
 115     print $fh "hello\n";
 116     ok(close($fh), "closed file");
 117 }
 118
 119 # first obvious fucked-up case:  no devids even presumed to exist.
 120 {
 121     $info = $mogc->file_info($key);
 122     is($info->{devcount}, 1, "ensure devcount is correct at start");
 123
 124     # ensure repl queue is empty before destroying file_on
 125     wait_for_empty_queue("file_to_replicate", $dbh);
 126
 127     my @devids = $sto->fid_devids($info->{fid});
 128     is(scalar(@devids), 1, "devids retrieved");
 129     is($sto->remove_fidid_from_devid($info->{fid}, $devids[0]), 1,
 130        "delete $key from file_on table");
 131
 132     full_fsck($tmptrack, $dbh);
 133     do {
 134         @fsck_log = $sto->fsck_log_rows;
 135     } while (scalar(@fsck_log) < 3 && sleep(0.1));
 136
 137     wait_for_empty_queue("file_to_queue", $dbh);
 138     @fsck_log = $sto->fsck_log_rows;
 139
 140     my $nopa = $fsck_log[0];
 141     is($nopa->{evcode}, "NOPA", "evcode for no paths logged");
 142
 143     # entering "desperate" mode
 144     my $srch = $fsck_log[1];
 145     is($srch->{evcode}, "SRCH", "evcode for start search logged");
 146
 147     # wow, we actually found it!
 148     my $fond = $fsck_log[2];
 149     is($fond->{evcode}, "FOND", "evcode for start search logged");
 150
 151     $info = $mogc->file_info($key);
 152     is($info->{devcount}, 1, "ensure devcount is correct at fsck end");
 153     @paths = $mogc->get_paths($key);
 154     is(scalar(@paths), 1, "get_paths returns correctly at fsck end");
 155 }
 156
 157 # update class to require 2copies and have fsck fix it
 158 {
 159     @paths = $mogc->get_paths($key);
 160     is(scalar(@paths), 1, "only one path exists before fsck");
 161
 162     # _NOT_ using "updateclass" command since that enqueues for replication
 163     my $fid = MogileFS::FID->new($info->{fid});
 164     my $classid_2copies = $sto->get_classid_by_name($fid->dmid, "2copies");
 165     is($fid->update_class(classid => $classid_2copies), 1, "classid updated");
 166
 167     full_fsck($tmptrack, $dbh);
 168
 169     do {
 170         @paths = $mogc->get_paths($key);
 171     } while (scalar(@paths) == 1 and sleep(0.1));
 172     is(scalar(@paths), 2, "replicated from fsck");
 173
 174     $info = $mogc->file_info($key);
 175     is($info->{devcount}, 2, "ensure devcount is updated by replicate");
 176
 177     do {
 178         @fsck_log = $sto->fsck_log_rows;
 179     } while (scalar(@fsck_log) == 0 and sleep(0.1));
 180
 181     my $povi = $fsck_log[0];
 182     is($povi->{evcode}, "POVI", "policy violation logged by fsck");
 183
 184     my $repl = $fsck_log[1];
 185     is($repl->{evcode}, "REPL", "replication request logged by fsck");
 186 }
 187
 188 # wrong devcount in file column, but otherwise everything is OK
 189 {
 190     foreach my $wrong_devcount (13, 0, 1) {
 191         is($dbh->do("UPDATE file SET devcount = ? WHERE fid = ?", undef, $wrong_devcount, $info->{fid}), 1, "set improper devcount");
 192
 193         $info = $mogc->file_info($key);
 194         is($info->{devcount}, $wrong_devcount, "devcount is set to $wrong_devcount");
 195
 196         full_fsck($tmptrack, $dbh);
 197
 198         do {
 199             $info = $mogc->file_info($key);
 200         } while ($info->{devcount} == $wrong_devcount && sleep(0.1));
 201         is($info->{devcount}, 2, "devcount is corrected by fsck");
 202
 203         # XXX POVI gets logged here, but BCNT might be more correct...
 204         wait_for_empty_queue("file_to_queue", $dbh);
 205         @fsck_log = $sto->fsck_log_rows;
 206         is($fsck_log[0]->{evcode}, "POVI", "policy violation logged");
 207     }
 208 }
 209
 210 # nuke a file from disk but keep the file_on row
 211 {
 212     @paths = $mogc->get_paths($key);
 213     is(scalar(@paths), 2, "two paths returned from get_paths");
 214     $req = HTTP::Request->new(DELETE => $paths[0]);
 215     $rv = $ua->request($req);
 216     ok($rv->is_success, "DELETE successful");
 217
 218     full_fsck($tmptrack, $dbh);
 219     do {
 220         @fsck_log = $sto->fsck_log_rows;
 221     } while (scalar(@fsck_log) < 2 && sleep(0.1));
 222
 223     my $miss = $fsck_log[0];
 224     is($miss->{evcode}, "MISS", "missing file logged by fsck");
 225
 226     my $repl = $fsck_log[1];
 227     is($repl->{evcode}, "REPL", "replication request logged by fsck");
 228
 229     wait_for_empty_queue("file_to_replicate", $dbh);
 230
 231     @paths = $mogc->get_paths($key);
 232     is(scalar(@paths), 2, "two paths returned from get_paths");
 233     foreach my $path (@paths) {
 234         $rv = $ua->get($path);
 235         is($rv->content, "hello\n", "GET successful on restored path");
 236     }
 237 }
 238
 239 # change the length of a file from disk and have fsck correct it
 240 {
 241     @paths = $mogc->get_paths($key);
 242     is(scalar(@paths), 2, "two paths returned from get_paths");
 243     $req = HTTP::Request->new(PUT => $paths[0]);
 244     $req->content("hello\r\n");
 245     $rv = $ua->request($req);
 246     ok($rv->is_success, "PUT successful");
 247
 248     full_fsck($tmptrack, $dbh);
 249     do {
 250         @fsck_log = $sto->fsck_log_rows;
 251     } while (scalar(@fsck_log) < 2 && sleep(0.1));
 252
 253     my $blen = $fsck_log[0];
 254     is($blen->{evcode}, "BLEN", "missing file logged by fsck");
 255
 256     my $repl = $fsck_log[1];
 257     is($repl->{evcode}, "REPL", "replication request logged by fsck");
 258
 259     wait_for_empty_queue("file_to_replicate", $dbh);
 260
 261     @paths = $mogc->get_paths($key);
 262     is(scalar(@paths), 2, "two paths returned from get_paths");
 263     foreach my $path (@paths) {
 264         $rv = $ua->get($path);
 265         is($rv->content, "hello\n", "GET successful on restored path");
 266     }
 267 }
 268
 269 # nuke a file completely and irreparably
 270 {
 271     @paths = $mogc->get_paths($key);
 272     is(scalar(@paths), 2, "two paths returned from get_paths");
 273     foreach my $path (@paths) {
 274         $req = HTTP::Request->new(DELETE => $path);
 275         $rv = $ua->request($req);
 276         ok($rv->is_success, "DELETE successful");
 277     }
 278
 279     full_fsck($tmptrack, $dbh);
 280     do {
 281         @fsck_log = $sto->fsck_log_rows;
 282     } while (scalar(@fsck_log) < 4 && sleep(0.1));
 283
 284     is($fsck_log[0]->{evcode}, "MISS", "missing file logged for first path");
 285     is($fsck_log[1]->{evcode}, "MISS", "missing file logged for second path");
 286     is($fsck_log[2]->{evcode}, "SRCH", "desperate search attempt logged");
 287     is($fsck_log[3]->{evcode}, "GONE", "inability to fix FID logged");
 288
 289     wait_for_empty_queue("file_to_queue", $dbh);
 290     $info = $mogc->file_info($key);
 291
 292     # XXX devcount probably needs to be updated on GONE
 293     # is($info->{devcount}, 2, "devcount updated to zero");
 294     @paths = $mogc->get_paths($key);
 295     is(scalar(@paths), 0, "get_paths returns nothing");
 296 }
 297
 298 done_testing();