tests/scripts/features/output-sync

   1 #                                                                    -*-perl-*-
   2
   3 $description = "Test --output-sync (-O) option.";
   4
   5 $details = "Test the synchronization of output from parallel jobs.";
   6
   7 # If we don't have output sync support, never mind.
   8 exists $FEATURES{'output-sync'} or return -1;
   9
  10 # Output sync can't be tested without parallelization
  11 $parallel_jobs or return -1;
  12
  13
  14 # The following subdirectories with Makefiles are used in several
  15 # of the following tests.  The model is:
  16 #   foo/Makefile - has a "foo" target that waits for the bar target
  17 #   bar/Makefile - has a "bar" target that runs immediately
  18 #                - has a "baz" target that waits for the foo target
  19 #
  20 # So, you start the two sub-makes in parallel and first the "bar" target is
  21 # built, followed by "foo", followed by "baz".  The trick is that first each
  22 # target prints a "start" statement, then waits (if appropriate), then prints
  23 # an end statement.  Thus we can tell if the -O flag is working, since
  24 # otherwise these statements would be mixed together.
  25
  26 @syncfiles = ();
  27
  28 sub output_sync_clean {
  29     rmfiles('foo/Makefile', 'bar/Makefile', @syncfiles);
  30     rmdir('foo');
  31     rmdir('bar');
  32 }
  33
  34 # We synchronize the different jobs by having them wait for a sentinel file to
  35 # be created, instead of relying on a certain amount of time passing.
  36 # Unfortunately in this test we have to sleep after we see the sync file,
  37 # since we also want to make the obtaining of the write synchronization lock
  38 # reliable.  If things are too fast, then sometimes a different job will steal
  39 # the output sync lock and the output is mis-ordered from what we expect.
  40 sub output_sync_wait {
  41     return subst_make_string("#HELPER# -q wait ../mksync.$_[0] sleep 1");
  42 }
  43 sub output_sync_set {
  44     return subst_make_string("#HELPER# -q file ../mksync.$_[0]");
  45 }
  46
  47 @syncfiles = qw(mksync.foo mksync.foo_start mksync.bar mksync.bar_start);
  48
  49 $tmout = 30;
  50
  51 output_sync_clean();
  52 mkdir('foo', 0777);
  53 mkdir('bar', 0777);
  54
  55 $set_foo = output_sync_set('foo');
  56 $set_bar = output_sync_set('bar');
  57 $set_foo_start = output_sync_set('foo_start');
  58 $set_bar_start = output_sync_set('bar_start');
  59
  60 $wait_foo = output_sync_wait('foo');
  61 $wait_bar = output_sync_wait('bar');
  62 $wait_foo_start = output_sync_set('foo_start');
  63 $wait_bar_start = output_sync_set('bar_start');
  64
  65 open(MAKEFILE,"> foo/Makefile");
  66 print MAKEFILE <<EOF;
  67 all: foo
  68
  69 foo: foo-base ; \@$set_foo
  70
  71 foo-base:
  72 \t\@echo foo: start
  73 \t\@$wait_bar
  74 \t\@echo foo: end
  75
  76 foo-job: foo-job-base ; \@$set_foo
  77
  78 foo-job-base:
  79 \t\@$wait_bar_start
  80 \t\@echo foo: start
  81 \t\@$set_foo_start
  82 \t\@$wait_bar
  83 \t\@echo foo: end
  84
  85 foo-fail:
  86 \t\@echo foo-fail: start
  87 \t\@$wait_bar
  88 \t\@echo foo-fail: end
  89 \t\@exit 1
  90 EOF
  91 close(MAKEFILE);
  92
  93 open(MAKEFILE,"> bar/Makefile");
  94 print MAKEFILE <<EOF;
  95 all: bar baz
  96
  97 bar: bar-base ; \@$set_bar
  98 bar-base:
  99 \t\@echo bar: start
 100 \t\@echo bar: end
 101
 102 bar-job: bar-job-base ; \@$set_bar
 103
 104 bar-job-base:
 105 \t\@echo bar: start
 106 \t\@$set_bar_start
 107 \t\@$wait_foo_start
 108 \t\@echo bar: end
 109
 110 baz: baz-base
 111 baz-base:
 112 \t\@echo baz: start
 113 \t\@$wait_foo
 114 \t\@echo baz: end
 115 EOF
 116 close(MAKEFILE);
 117
 118 # Test per-make synchronization.
 119 # Note we have to sleep again here after starting the foo makefile before
 120 # starting the bar makefile, otherwise the "entering/leaving" messages for the
 121 # submakes might be ordered differently than we expect.
 122
 123 unlink(@syncfiles);
 124 run_make_test(qq!
 125 all: make-foo make-bar
 126
 127 make-foo: ; \$(MAKE) -C foo
 128
 129 make-bar: ; #HELPER# -q sleep 1 ; \$(MAKE) -C bar!,
 130               '-j -Orecurse',
 131 "#MAKEPATH# -C foo
 132 #MAKE#[1]: Entering directory '#PWD#/foo'
 133 foo: start
 134 foo: end
 135 #MAKE#[1]: Leaving directory '#PWD#/foo'
 136 #HELPER# -q sleep 1 ; #MAKEPATH# -C bar
 137 #MAKE#[1]: Entering directory '#PWD#/bar'
 138 bar: start
 139 bar: end
 140 baz: start
 141 baz: end
 142 #MAKE#[1]: Leaving directory '#PWD#/bar'\n", 0, $tmout);
 143
 144 # Test per-target synchronization.
 145 # Note we have to sleep again here after starting the foo makefile before
 146 # starting the bar makefile, otherwise the "entering/leaving" messages for the
 147 # submakes might be ordered differently than we expect.
 148
 149 unlink(@syncfiles);
 150 run_make_test(qq!
 151 x=1
 152 \$xMAKEFLAGS += --no-print-directory
 153
 154 all: make-foo make-bar
 155
 156 make-foo: ; \$(MAKE) -C foo
 157
 158 make-bar: ; #HELPER# -q sleep 1 ; \$(MAKE) -C bar!,
 159               '-j --output-sync=target',
 160 "#MAKEPATH# -C foo
 161 #HELPER# -q sleep 1 ; #MAKEPATH# -C bar
 162 #MAKE#[1]: Entering directory '#PWD#/bar'
 163 bar: start
 164 bar: end
 165 #MAKE#[1]: Leaving directory '#PWD#/bar'
 166 #MAKE#[1]: Entering directory '#PWD#/foo'
 167 foo: start
 168 foo: end
 169 #MAKE#[1]: Leaving directory '#PWD#/foo'
 170 #MAKE#[1]: Entering directory '#PWD#/bar'
 171 baz: start
 172 baz: end
 173 #MAKE#[1]: Leaving directory '#PWD#/bar'\n", 0, $tmout);
 174
 175 # Rerun but this time suppress the directory tracking
 176 unlink(@syncfiles);
 177 run_make_test(undef, '-j --output-sync=target x=',
 178               "#MAKEPATH# -C foo
 179 #HELPER# -q sleep 1 ; #MAKEPATH# -C bar
 180 bar: start
 181 bar: end
 182 foo: start
 183 foo: end
 184 baz: start
 185 baz: end\n", 0, $tmout);
 186
 187 # Test that messages from make itself are enclosed with
 188 # "Entering/Leaving directory" messages.
 189 unlink(@syncfiles);
 190 run_make_test(qq!
 191 all: make-foo-fail make-bar-bar
 192
 193 make-foo-fail: ; \$(MAKE) -C foo foo-fail
 194
 195 make-bar-bar: ; #HELPER# -q sleep 1 ; \$(MAKE) -C bar bar!,
 196               '-j -O',
 197 "#MAKEPATH# -C foo foo-fail
 198 #HELPER# -q sleep 1 ; #MAKEPATH# -C bar bar
 199 #MAKE#[1]: Entering directory '#PWD#/bar'
 200 bar: start
 201 bar: end
 202 #MAKE#[1]: Leaving directory '#PWD#/bar'
 203 #MAKE#[1]: Entering directory '#PWD#/foo'
 204 foo-fail: start
 205 foo-fail: end
 206 #MAKE#[1]: *** [Makefile:23: foo-fail] Error 1
 207 #MAKE#[1]: Leaving directory '#PWD#/foo'
 208 #MAKE#: *** [#MAKEFILE#:4: make-foo-fail] Error 2\n",
 209 512);
 210
 211 # Test the per-job synchronization.
 212 # For this we'll have bar-job:
 213 #   print start, invoke bar-start, wait for foo-start, print end, print-bar-end
 214 # And foo-job:
 215 #   wait for bar-start, print foo-start, wait for bar-end, print end
 216
 217 unlink(@syncfiles);
 218 run_make_test(qq!
 219 all: make-foo make-bar
 220
 221 make-foo: ; \$(MAKE) -C foo foo-job
 222
 223 make-bar: ; #HELPER# -q sleep 1 ; \$(MAKE) -C bar bar-job!,
 224               '-j --output-sync=line',
 225 "#MAKEPATH# -C foo foo-job
 226 #HELPER# -q sleep 1 ; #MAKEPATH# -C bar bar-job
 227 #MAKE#[1]: Entering directory '#PWD#/foo'
 228 foo: start
 229 #MAKE#[1]: Leaving directory '#PWD#/foo'
 230 #MAKE#[1]: Entering directory '#PWD#/bar'
 231 bar: start
 232 #MAKE#[1]: Leaving directory '#PWD#/bar'
 233 #MAKE#[1]: Entering directory '#PWD#/bar'
 234 bar: end
 235 #MAKE#[1]: Leaving directory '#PWD#/bar'
 236 #MAKE#[1]: Entering directory '#PWD#/foo'
 237 foo: end
 238 #MAKE#[1]: Leaving directory '#PWD#/foo'\n", 0, $tmout);
 239
 240 # Remove temporary directories and contents.
 241 output_sync_clean();
 242
 243 # Ensure recursion doesn't mis-order or double-print output
 244 run_make_test(qq!
 245 all:
 246 \t\@echo foo
 247 \t\@+echo bar
 248 !,
 249               '-j -Oline', "foo\nbar\n");
 250
 251 run_make_test(undef, '-j -Otarget', "foo\nbar\n");
 252
 253 # Ensure when make writes out command it's not misordered
 254 run_make_test(qq!
 255 all:
 256 \t\@echo foobar
 257 \ttrue
 258 !,
 259               '-j -Oline', "foobar\ntrue\n");
 260
 261 run_make_test(undef, '-j -Otarget', "foobar\ntrue\n");
 262
 263 # Ensure that shell functions inside recipes write stderr to the sync file
 264 run_make_test(q!
 265 all: ; @: $(shell echo foo 1>&2)
 266 !,
 267               '-w -Oline', "#MAKE#: Entering directory '#PWD#'\nfoo\n#MAKE#: Leaving directory '#PWD#'\n");
 268
 269 # Ensure that output generated while parsing makefiles is synced
 270 # when appropriate.
 271 run_make_test(q!
 272 $(shell echo foo 1>&2)
 273 all: ; echo bar
 274 !,
 275               '-s -w -Otarget', "#MAKE#: Entering directory '#PWD#'\nfoo\n#MAKE#: Leaving directory '#PWD#'\n#MAKE#: Entering directory '#PWD#'\nbar\n#MAKE#: Leaving directory '#PWD#'\n");
 276
 277 # Test recursion
 278 $m1 = get_tmpfile();
 279 $m2 = get_tmpfile();
 280
 281 open(M1, "> $m1");
 282 print M1 <<'EOF';
 283 $(shell echo d1 stderr 1>&2)
 284 $(info d1 stdout)
 285 all:; @:
 286 EOF
 287 close(M1);
 288
 289 open(M2, "> $m2");
 290 print M2 <<'EOF';
 291 $(shell echo d2 stderr 1>&2)
 292 $(info d2 stdout)
 293 all:; @:
 294 # Force an ordering on the output
 295 $(shell sleep 1)
 296 EOF
 297 close(M2);
 298
 299 run_make_test(qq!
 300 all: t1 t2
 301 t1: ; \@\$(MAKE) -f $m1
 302 t2: ; \@\$(MAKE) -f $m2
 303 !,
 304               "-j -Oline", "#MAKE#[1]: Entering directory '#PWD#'\nd1 stderr\nd1 stdout\n#MAKE#[1]: Leaving directory '#PWD#'\n#MAKE#[1]: Entering directory '#PWD#'\nd2 stderr\nd2 stdout\n#MAKE#[1]: Leaving directory '#PWD#'\n");
 305
 306 rmfiles($m1, $m2);
 307
 308 # Ensure that output generated while parsing makefiles is synced
 309 # when appropriate.
 310 $m1 = get_tmpfile();
 311
 312 open(M1, "> $m1");
 313 print M1 <<'EOF';
 314 $(shell echo d1 stderr 1>&2)
 315 $(info d1 stdout)
 316 $(error d1 failed)
 317 all:; @:
 318 EOF
 319 close(M1);
 320
 321 run_make_test(qq!
 322 all: t1
 323 t1: ; -\@\$(MAKE) -f $m1
 324 !,
 325               "-j -Oline", "#MAKE#[1]: Entering directory '#PWD#'\nd1 stderr\nd1 stdout\n$m1:3: *** d1 failed.  Stop.\n#MAKE#[1]: Leaving directory '#PWD#'\n#MAKE#: [#MAKEFILE#:3: t1] Error 2 (ignored)\n");
 326
 327 rmfiles($m1);
 328
 329 # Test $(error ...) functions in recipes
 330
 331 run_make_test(q!
 332 foo: $(OBJS) ; echo $(or $(filter %.o,$^),$(error fail))
 333 !,
 334               '-O', "#MAKEFILE#:2: *** fail.  Stop.\n", 512);
 335
 336 # SV 47365: Make sure exec failure error messages are shown
 337 # Needs to be ported to Windows
 338 if ($port_type ne 'W32') {
 339     run_make_test(q!
 340 all:: ; @./foo bar baz
 341 !,
 342               '-O', "#MAKE#: ./foo: $ERR_no_such_file\n#MAKE#: *** [#MAKEFILE#:2: all] Error 127\n", 512);
 343 }
 344
 345 if ($port_type eq 'UNIX') {
 346 # POSIX doesn't require sh to set PPID so test this
 347 my $cmd = create_command();
 348 add_options($cmd, '-f', '/dev/null', '-E', q!all:;@echo $$PPID!);
 349 my $fout = 'ppidtest.out';
 350 run_command_with_output($fout, @$cmd);
 351 $_ = read_file_into_string($fout);
 352 chomp($_);
 353 if (/^[0-9]+$/) {
 354 use POSIX ();
 355 # SV 63157.
 356 # Test that make removes temporary files, even when a signal is received.
 357 # The general test_driver postprocessing will ensure the temporary file used
 358 # to synchronize output and the jobserver fifo are both removed.
 359 # sleep is needed to let make write its "... Terminated" message to the log
 360 # file.
 361 run_make_test(q!
 362 pid:=$(shell echo $$PPID)
 363 all:; @kill -TERM $(pid) && sleep 16
 364 !, '-O -j2', '/#MAKE#: \*\*\* \[#MAKEFILE#:3: all] Terminated/', POSIX::SIGTERM);
 365 }
 366
 367 unlink($fout);
 368 }
 369
 370 # This tells the test driver that the perl test script executed properly.
 371 1;