[Swan-dev] problems building test system

Fri Jan 20 16:57:44 UTC 2017

wThe last time I ran my tests system was January 2.
Yesterday I did a "git pull" (master) and a "make kvm-install".

The make failed.  Here's a chunk of the output:
================
make[2]: Entering directory '/source/programs/pluto'
set -e ; \
for f in ike_alg_nss_cbc.h ike_alg_nss_cbc.c cbc_test_vectors.h cbc_test_vectors.c ctr_test_vectors.h ctr_test_vectors.c gcm_test_vectors.h gcm_test_vectors.c test_buffer.h test_buffer.c connections.c initiate.c terminate.c connections.h pending.c pendin!
	case $f in \
		*.c ) echo "-include $(basename $f .c).d # $f" ;; \
		*.o ) echo "-include $(basename $f .o).d # $f" ;; \
		* ) echo "# $f ignored by Makefile.dep" ;; \
	esac ; \
done > ../../OBJ.kvm/programs/pluto/Makefile.depend.mk.tmp
mv ../../OBJ.kvm/programs/pluto/Makefile.depend.mk.tmp ../../OBJ.kvm/programs/pluto/Makefile.depend.mk
make[2]: Warning: File '../../OBJ.kvm/programs/pluto/Makefile.depend.mk' has modification time 0.91 s in the future
make -C ../../OBJ.kvm/programs/pluto buildall
make[3]: Entering directory '/source/OBJ.kvm/programs/pluto'
make[3]: Warning: File 'Makefile.depend.mk' has modification time 0.61 s in the future
make[3]: *** No rule to make target '/source/programs/pluto/dnskey.h', needed by 'connections.o'.  Stop.
make[3]: Leaving directory '/source/OBJ.kvm/programs/pluto'
Makefile:456: recipe for target 'local-base' failed
================

This make often fails and I put it down to the makefiles not capturing
all dependencies (perhaps on makefiles themselves).  Looking more
closely now, it actually looks more curious than that.  As if there is
clock skew somewhere in the process.  Are we using VMs with different
clocks.  (Note that the test machine was rebooted yesterday, after
Fedora updates, so there virtual machines were fairly fresh).

In any case, I took my normal action when confronted with make errors
like this:

	make clean
	rm OBJ.* -r
	make kvm-install

This worked, up to a point.  18 hours later, it hasn't finished.  ps
says its waiting for "virsh console --force a.east" to finish:

0  1105  5296  3223  20   0 146292  4248 wait   S+   pts/1      0:00  |                   \_ make kvm-install
0  1105  5452  5296  20   0 200848 15592 poll_s S+   pts/1      0:00  |                       \_ python3 /home/build/libreswan/testing/utils/kvmsh.py --chdir . a.east export OBJDIR=OBJ.kvm ; make -j2 OBJDIR=OBJ.kvm module
4     0  5453  5452  20   0 227508  5808 -      Ss+  pts/3      0:00  |                           \_ /usr/bin/sudo virsh console --force a.east
4     0  5454  5453  20   0 383560 13728 -      Sl+  pts/3      0:02  |                               \_ virsh console --force a.east

I just killed it.  The make took 20 hours of real time but only 3.5
seconds of user time.  Clearly it was waiting for something most of
the time.

Repeating the "make clean" etc. proceedure fails quite quickly:

================
[build at redtiny libreswan]$ time make kvm-install
: kvm-build-domain domain=a.east
test -w /var/lib/libvirt/qemu || make broken-kvm-qemu-directory
/home/build/libreswan/testing/utils/kvmsh.py  --chdir . a.east 'export OBJDIR=OBJ.kvm ; make -j2 OBJDIR=OBJ.kvm base'
virsh 0.00: waiting 10 seconds for login prompt; 5 seconds for password prompt; 5 seconds for shell prompt
Traceback (most recent call last):
  File "/usr/lib/python3.5/site-packages/pexpect/expect.py", line 99, in expect_loop
    incoming = spawn.read_nonblocking(spawn.maxread, timeout)
  File "/usr/lib/python3.5/site-packages/pexpect/pty_spawn.py", line 465, in read_nonblocking
    raise TIMEOUT('Timeout exceeded.')
pexpect.exceptions.TIMEOUT: Timeout exceeded.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/build/libreswan/testing/utils/kvmsh.py", line 152, in <module>
    main()
  File "/home/build/libreswan/testing/utils/kvmsh.py", line 106, in main
    remote.login(domain, console)
  File "/home/build/libreswan/testing/utils/fab/remote.py", line 167, in login
    shell_timeout=shell_timeout)
  File "/home/build/libreswan/testing/utils/fab/remote.py", line 133, in _login
    also_expect=[console.prompt]) == 1:
  File "/home/build/libreswan/testing/utils/fab/remote.py", line 107, in _wait_for_login_prompt
    match = console.expect(matches, timeout=timeout)
  File "/home/build/libreswan/testing/utils/fab/shell.py", line 201, in expect
    searchwindowsize=searchwindowsize)
  File "/usr/lib/python3.5/site-packages/pexpect/spawnbase.py", line 321, in expect
    timeout, searchwindowsize, async)
  File "/usr/lib/python3.5/site-packages/pexpect/spawnbase.py", line 345, in expect_list
    return exp.expect_loop(timeout)
  File "/usr/lib/python3.5/site-packages/pexpect/expect.py", line 107, in expect_loop
    return self.timeout(e)
  File "/usr/lib/python3.5/site-packages/pexpect/expect.py", line 70, in timeout
    raise TIMEOUT(msg)
pexpect.exceptions.TIMEOUT: Timeout exceeded.
<pexpect.pty_spawn.spawn object at 0x7f22025faa58>
command: /usr/bin/sudo
args: [b'/usr/bin/sudo', b'virsh', b'console', b'--force', b'a.east']
buffer (last 100 chars): ''
before (last 100 chars): ''
after: <class 'pexpect.exceptions.TIMEOUT'>
match: None
match_index: None
exitstatus: None
flag_eof: False
pid: 9322
child_fd: 5
closed: False
timeout: 0
delimiter: <class 'pexpect.exceptions.EOF'>
logfile: None
logfile_read: <fab.shell.Debug object at 0x7f2202610358>
logfile_send: <fab.shell.Debug object at 0x7f22026100f0>
maxread: 2000
ignorecase: False
searchwindowsize: None
delaybeforesend: 0.05
delayafterclose: 0.1
delayafterterminate: 0.1
searcher: searcher_re:
    0: re.compile("login: ")
    1: re.compile("\[(?P<username>[-\.a-z0-9]+)@(?P<hostname>[-a-z0-9]+) (?P<basename>[-\.a-z0-9A-Z_~]+)(?P<status>| [0-9]+)\](?P<dollar>[#\$]) ")
/home/build/libreswan/mk/kvm-targets.mk:672: recipe for target 'kvm-build-a.east' failed
make: *** [kvm-build-a.east] Error 1
================

I just rebooted the host machine and reran the procedure and it
succeeded.