Merge pull request #105 from gregarndt/bug_1174559_parse_error_message

Bug 1174559 - Make taskcluster log errors be parseable

lib/features/local_live_log.js

@@ -32,7 +32,7 @@ export default class TaskclusterLogs {
     this.token = slugid.v4();
   }
 
-  async created(task) {
+  async link(task) {
     debug('create live log container...')
     // ensure we have a bulk log backing stuff...
     this.bulkLog = new BulkLog(BACKING_ARTIFACT_NAME);
@@ -154,6 +154,11 @@ export default class TaskclusterLogs {
         url: this.publicUrl
       }
     );
+
+    return {
+      links: [],
+      env: {}
+    };
   }
 
   async killed(task) {

lib/pull_image_to_stream.js

@@ -12,9 +12,9 @@ const IMAGE_SCOPE_PREFIX = 'docker-worker:image:';
 
 // This string was super long but I wanted to say all these thing so I broke it
 // out into a constant even though most errors are closer to their code...
-export const IMAGE_ERROR = 'Pulling docker image "%s" has failed this may indicate an ' +
+export const IMAGE_ERROR = 'Error: Pulling docker image "%s" has failed this may indicate an ' +
                   'Error with the registry used or an authentication error ' +
-                  'in the worker try pulling the image locally. \n Error %s';
+                  'in the worker try pulling the image locally. %s';
 
 // Settings for exponential backoff for retrying image pulls.
 // Last attempt will be in a range between 6 and 10 minutes which is acceptable

lib/task.js

@@ -24,7 +24,7 @@ const PAYLOAD_SCHEMA =
   'http://schemas.taskcluster.net/docker-worker/v1/payload.json#';
 
 // TODO probably a terrible error message, look at making it better later
-const CANCEL_ERROR = 'Task was canceled by another entity. This can happen using ' +
+const CANCEL_ERROR = 'Error: Task was canceled by another entity. This can happen using ' +
                    'a taskcluster client or by cancelling a task within Treeherder.';
 
 /*
@@ -308,7 +308,7 @@ export default class Task {
 
   logSchemaErrors(prefix, errors) {
     return this.fmtLog(
-      "%s format is invalid json schema errors:\n %s",
+      'Error: %s format is invalid json schema errors:\n %s',
       prefix, JSON.stringify(errors, null, 2)
     );
   }
@@ -448,7 +448,7 @@ export default class Task {
       // exit code.
       this.dockerProcess.kill();
       this.stream.write(this.fmtLog(
-        'Task timeout after %d seconds. Force killing container.',
+        'Error: Task timeout after %d seconds. Force killing container.',
         this.task.payload.maxRunTime
       ));
     }.bind(this), maxRuntimeMS);
@@ -525,7 +525,7 @@ export default class Task {
     if (this.dockerProcess) this.dockerProcess.kill();
 
     this.stream.write(
-      this.fmtLog(`Task has been aborted prematurely. Reason: ${reason}`)
+      this.fmtLog(`Error: Task has been aborted prematurely. Reason: ${reason}`)
     );
   }
 
@@ -584,8 +584,8 @@ export default class Task {
       return await this.abortRun(
         'states_failed',
         this.fmtLog(
-          'Task was aborted because states could not be created ' +
-          `successfully. Error: ${e}`
+          'Error: Task was aborted because states could not be created ' +
+          `successfully. ${e}`
         )
       );
     }
@@ -643,9 +643,9 @@ export default class Task {
     try {
       dockerConfig = await this.dockerConfig(linkInfo);
     } catch (e) {
-      let error = this.fmtLog('Docker configuration could not be ' +
+      let error = this.fmtLog('Error: Docker configuration could not be ' +
         'created.  This may indicate an authentication error when validating ' +
-        'scopes necessary for running the task. \n Error %s', e);
+        'scopes necessary for running the task. \n %s', e);
       return await this.abortRun('docker_configuration', error);
     }
 
@@ -702,7 +702,7 @@ export default class Task {
         stack: e.stack
       });
       this.stream.write(this.fmtLog(
-        `Unknown taskcluster error encountered.  Ask administrator to lookup ` +
+        `Error: Unknown taskcluster error encountered.  Ask administrator to lookup ` +
         `incidentId in log-file. Incident ID: ${lookupId}`
       ));
       success = false;

test/integration/balrog_vpn_proxy_test.js

@@ -1,3 +1,4 @@
+import assert from 'assert';
 import * as settings from '../settings';
 import DockerWorker from '../dockerworker';
 import TestWorker from '../testworker';
@@ -21,13 +22,8 @@ suite('balrog vpn proxy', () => {
   });
 
   test('feature can be used within task', async () => {
-    let error;
-    worker.on('task aborted', (message) => {
-      error = message.err
-    });
-
     let result = await worker.postToQueue({
-      scopes: ["docker-worker:feature:balrogVPNProxy"],
+      scopes: ['docker-worker:feature:balrogVPNProxy'],
       payload: {
         features: {
           balrogVPNProxy: true
@@ -48,15 +44,10 @@ suite('balrog vpn proxy', () => {
       'completed',
       'Task not resolved as complete'
     );
-    assert.ok(result.log.indexOf("1 received", "Proxy could not be reached"));
+    assert.ok(result.log.indexOf('1 received', 'Proxy could not be reached'));
   });
 
   test('missing feature scope', async () => {
-    let error;
-    worker.on('task aborted', (message) => {
-      error = message.err
-    });
-
     let result = await worker.postToQueue({
       payload: {
         features: {
@@ -72,12 +63,13 @@ suite('balrog vpn proxy', () => {
       }
     });
 
-    // Need to rely on looking at the logging from the worker because the logserve
-    // container might not have created a logging artifact in time because of where
-    // this check takes place.
     assert.ok(
-      error.indexOf('Insufficient scopes to use') !== -1,
-      'Error does not contain correct message'
+      result.log.includes('[taskcluster] Error: Task was aborted because states'),
+      'Error does not container message about states being aborted'
+    );
+    assert.ok(
+      result.log.includes('Insufficient scopes to use \'balrogVPNProxy\''),
+      'Error does not contain message about insufficient scopes'
     );
 
     assert.equal(result.status.state, 'failed', 'Task not marked as failed');

test/integration/maxruntime_test.js

@@ -19,7 +19,7 @@ suite('worker timeouts', function() {
     assert.ok(result.log.indexOf('Hello') !== -1);
     assert.ok(result.log.indexOf('done') === -1);
     assert.ok(
-      result.log.indexOf('[taskcluster] Task timeout') !== -1,
+      result.log.indexOf('[taskcluster] Error: Task timeout') !== -1,
       'Task should contain logs about timeout'
     );
   }));