0s autopkgtest [21:15:23]: starting date and time: 2024-11-13 21:15:23+0000
  0s autopkgtest [21:15:23]: git checkout: 0acbae0a WIP show VirtSubproc stderr in real-time
  0s autopkgtest [21:15:23]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.iqhh_tnj/out --timeout-copy=6000 -a i386 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:python3-defaults,src:python3-stdlib-extensions --apt-upgrade wtf-peewee --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=python3-defaults/3.12.7-1 python3-stdlib-extensions/3.12.7-1' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor builder-cpu2-ram4-disk20 --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-16.secgroup --name adt-plucky-i386-wtf-peewee-20241113-200518-juju-7f2275-prod-proposed-migration-environment-2-6839bf3c-f994-452b-9018-bf4c7cc50f90 --image adt/ubuntu-plucky-amd64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration-amd64 -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/
1801s virt: nova [W] Skipping flock for amd64
1801s virt: Creating nova instance adt-plucky-i386-wtf-peewee-20241113-200518-juju-7f2275-prod-proposed-migration-environment-2-6839bf3c-f994-452b-9018-bf4c7cc50f90 from image adt/ubuntu-plucky-amd64-server-20241113.img (UUID 62c21ac4-2290-4c8d-8313-dddd18eacff4)...
1801s virt: nova [W] nova quota exceeded (attempt #0)
1801s virt: nova [W] nova quota exceeded (attempt #1)
1801s virt: nova [W] nova quota exceeded (attempt #2)
1801s virt: nova [W] nova quota exceeded (attempt #3)
1801s virt: nova [W] nova quota exceeded (attempt #4)
1801s Unexpected error:
1801s Traceback (most recent call last):
1801s   File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 159, in execute_timeout
1801s     (out, err) = sp.communicate(instr, timeout=1)
1801s   File "/usr/lib/python3.8/subprocess.py", line 1028, in communicate
1801s     stdout, stderr = self._communicate(input, endtime, timeout)
1801s   File "/usr/lib/python3.8/subprocess.py", line 1869, in _communicate
1801s     self._check_timeout(endtime, orig_timeout, stdout, stderr)
1801s   File "/usr/lib/python3.8/subprocess.py", line 1072, in _check_timeout
1801s     raise TimeoutExpired(
1801s subprocess.TimeoutExpired: Command '['/home/ubuntu/autopkgtest/ssh-setup/nova', 'open', '--flavor', 'builder-cpu2-ram4-disk20', '--security-groups', 'autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-16.secgroup', '--name', 'adt-plucky-i386-wtf-peewee-20241113-200518-juju-7f2275-prod-proposed-migration-environment-2-6839bf3c-f994-452b-9018-bf4c7cc50f90', '--image', 'adt/ubuntu-plucky-amd64-server', '--keyname', 'testbed-juju-7f2275-prod-proposed-migration-environment-2', '--net-id=net_prod-proposed-migration-amd64', '-e', 'TERM=linux', '-e', "'http_proxy=http://squid.internal:3128'", '-e', "'https_proxy=http://squid.internal:3128'", '-e', "'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'", '--mirror=http://ftpmaster.internal/ubuntu/']' timed out after 1 seconds
1801s 
1801s During handling of the above exception, another exception occurred:
1801s 
1801s Traceback (most recent call last):
1801s   File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 843, in mainloop
1801s     command()
1801s   File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 772, in command
1801s     r = f(c, ce)
1801s   File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 361, in cmd_open
1801s     caller.hook_open()
1801s   File "/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 423, in hook_open
1801s     host_setup('open')
1801s   File "/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 250, in host_setup
1801s     execute_setup_script(command)
1801s   File "/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 202, in execute_setup_script
1801s     (status, out, err) = VirtSubproc.execute_timeout(
1801s   File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 169, in execute_timeout
1801s     for line in sp.stderr:
1801s   File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 75, in alarm_handler
1801s     raise Timeout(to)
1801s VirtSubproc.Timeout: 1800
1801s autopkgtest [21:45:24]: ERROR: testbed failure: unexpected eof from the testbed