Store build logs automatically

This updates the builder to store individual build logs in dedicated
files, one per build, named for the image and build id.  Old logs are
automatically pruned.  By default, they are stored in
/var/log/nodepool/builds, but this can be changed.

This removes the need to specially configure logging handler for the
image build logs.

Change-Id: Ia7415d2fbbb320f8eddc4e46c3a055414df5f997
This commit is contained in:
James E. Blair 2018-02-08 11:52:58 -08:00
parent 9f2230ab14
commit baa831192f
57 changed files with 144 additions and 9 deletions

View File

@ -27,6 +27,8 @@
s-proxy: false
devstack_plugins:
nodepool: https://git.openstack.org/openstack-infra/nodepool
zuul_copy_output:
'/var/log/nodepool/builds': 'logs'
- job:
name: nodepool-functional-py35

View File

@ -168,6 +168,9 @@ EOF
EOF
sudo mv /tmp/secure.conf $NODEPOOL_SECURE
sudo mkdir /var/log/nodepool
sudo chown -R stack:stack /var/log/nodepool
if use_library_from_git "glean"; then
git --git-dir=$DEST/glean/.git checkout -b devstack
DIB_GLEAN_INSTALLTYPE="DIB_INSTALLTYPE_simple_init: 'repo'"

View File

@ -65,6 +65,34 @@ Example::
images-dir: /path/to/images/dir
.. _build-log-dir:
build-log-dir
-------------
The builder will store build logs in this directory. It will create
one file for each build, named `<image>-<build-id>.log`; for example,
`fedora-0000000004.log`. It defaults to ``/var/log/nodepool/builds``.
Example::
build-log-dir: /path/to/log/dir
.. _build-log-retention:
build-log-retention
-------------------
At the start of each build, the builder will remove old build logs if
they exceed a certain number. This option specifies how many will be
kept (usually you will see one more, as deletion happens before
starting a new build). By default, the last 7 old build logs are
kept.
Example::
build-log-retention: 14
zookeeper-servers
-----------------
Lists the ZooKeeper servers uses for coordinating information between

View File

@ -547,6 +547,29 @@ class BuildWorker(BaseWorker):
self.name = 'BuildWorker.%s' % name
self.dib_cmd = dib_cmd
def _getBuildLogRoot(self, name):
log_dir = self._config.build_log_dir
if not log_dir:
log_dir = '/var/log/nodepool/builds'
if not os.path.exists(log_dir):
os.makedirs(log_dir)
return log_dir
def _pruneBuildLogs(self, name):
log_dir = self._getBuildLogRoot(name)
keep = max(self._config.build_log_retention, 1)
existing = sorted(os.listdir(log_dir))
existing = [f for f in existing if f.startswith(name)]
delete = existing[:0 - keep]
for f in delete:
fp = os.path.join(log_dir, f)
self.log.info("Deleting old build log %s" % (fp,))
os.unlink(fp)
def _getBuildLog(self, name, build_id):
log_dir = self._getBuildLogRoot(name)
return os.path.join(log_dir, '%s-%s.log' % (name, build_id))
def _checkForScheduledImageUpdates(self):
'''
Check every DIB image to see if it has aged out and needs rebuilt.
@ -714,10 +737,11 @@ class BuildWorker(BaseWorker):
(self.dib_cmd, img_types, qemu_img_options, filename,
img_elements))
log = logging.getLogger("nodepool.image.build.%s" %
(diskimage.name,))
self._pruneBuildLogs(diskimage.name)
log_fn = self._getBuildLog(diskimage.name, build_id)
self.log.info('Running %s' % cmd)
self.log.info('Running %s' % (cmd,))
self.log.info('Logging to %s' % (log_fn,))
try:
p = subprocess.Popen(
@ -730,13 +754,17 @@ class BuildWorker(BaseWorker):
"Failed to exec '%s'. Error: '%s'" % (cmd, e.strerror)
)
while True:
ln = p.stdout.readline()
log.info(ln.strip())
if not ln:
break
with open(log_fn, 'wb') as log:
while True:
ln = p.stdout.readline()
log.write(ln)
log.flush()
if not ln:
break
p.wait()
rc = p.wait()
m = "Exit code: %s\n" % rc
log.write(m.encode('utf8'))
# It's possible the connection to the ZK cluster could have been
# interrupted during the build. If so, wait for it to return.

View File

@ -58,6 +58,8 @@ class ConfigValidator:
'webapp': webapp,
'elements-dir': str,
'images-dir': str,
'build-log-dir': str,
'build-log-retention': int,
'zookeeper-servers': [{
'host': str,
'port': int,

View File

@ -110,6 +110,8 @@ def loadConfig(config_path):
newconfig.labels = {}
newconfig.elementsdir = config.get('elements-dir')
newconfig.imagesdir = config.get('images-dir')
newconfig.build_log_dir = config.get('build-log-dir')
newconfig.build_log_retention = config.get('build-log-retention', 7)
newconfig.provider_managers = {}
newconfig.zookeeper_servers = {}
newconfig.diskimages = {}

View File

@ -286,18 +286,22 @@ class DBTestCase(BaseTestCase):
if images_dir is None:
images_dir = fixtures.TempDir()
self.useFixture(images_dir)
build_log_dir = fixtures.TempDir()
self.useFixture(build_log_dir)
configfile = os.path.join(os.path.dirname(__file__),
'fixtures', filename)
(fd, path) = tempfile.mkstemp()
with open(configfile, 'rb') as conf_fd:
config = conf_fd.read().decode('utf8')
data = config.format(images_dir=images_dir.path,
build_log_dir=build_log_dir.path,
zookeeper_host=self.zookeeper_host,
zookeeper_port=self.zookeeper_port,
zookeeper_chroot=self.zookeeper_chroot)
os.write(fd, data.encode('utf8'))
os.close(fd)
self._config_images_dir = images_dir
self._config_build_log_dir = build_log_dir
validator = ConfigValidator(path)
validator.validate()
return path

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,4 +1,5 @@
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: localhost

View File

@ -1,4 +1,5 @@
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: localhost

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,7 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
build-log-retention: 1
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,4 +1,5 @@
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: invalid_host

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -1,5 +1,6 @@
elements-dir: .
images-dir: '{images_dir}'
build-log-dir: '{build_log_dir}'
zookeeper-servers:
- host: {zookeeper_host}

View File

@ -184,12 +184,18 @@ class TestNodePoolBuilder(tests.DBTestCase):
configfile = self.setup_config('node.yaml')
self.useBuilder(configfile)
build = self.waitForBuild('fake-image', '0000000001')
log_path1 = os.path.join(self._config_build_log_dir.path,
'fake-image-0000000001.log')
self.assertTrue(os.path.exists(log_path1))
image = self.waitForImage('fake-provider', 'fake-image')
# Expire rebuild-age (default: 1day) to force a new build.
build.state_time -= expire
with self.zk.imageBuildLock('fake-image', blocking=True, timeout=1):
self.zk.storeBuild('fake-image', build, '0000000001')
self.waitForBuild('fake-image', '0000000002')
log_path2 = os.path.join(self._config_build_log_dir.path,
'fake-image-0000000002.log')
self.assertTrue(os.path.exists(log_path2))
self.waitForImage('fake-provider', 'fake-image', [image])
builds = self.zk.getBuilds('fake-image', zk.READY)
self.assertEqual(len(builds), 2)
@ -205,6 +211,16 @@ class TestNodePoolBuilder(tests.DBTestCase):
self.zk.storeBuild('fake-image', build, '0000000002')
self.waitForBuildDeletion('fake-image', '0000000001')
self.waitForBuild('fake-image', '0000000003')
log_path1 = os.path.join(self._config_build_log_dir.path,
'fake-image-0000000001.log')
log_path2 = os.path.join(self._config_build_log_dir.path,
'fake-image-0000000002.log')
log_path3 = os.path.join(self._config_build_log_dir.path,
'fake-image-0000000003.log')
# Our log retention is set to 1, so the first log should be deleted.
self.assertFalse(os.path.exists(log_path1))
self.assertTrue(os.path.exists(log_path2))
self.assertTrue(os.path.exists(log_path3))
builds = self.zk.getBuilds('fake-image', zk.READY)
self.assertEqual(len(builds), 2)