Repository: gocd/gocd
Issue: Temporary console log issues

1) ~~Even though console logs are available in 'Artifacts' tab, yet i see following message there which should not be happen~~

~~"Artifacts for this job instance are unavailable as they may have been purged by Go or deleted externally. Re-run the stage or job to generate them again."~~

This is not an issue [@arikagoyal]

2) a) When a job is cancelled, its o/p looks like this -

[go] Job Completed Console-testing/8/defaultStage/1/job213:30:25.194 [go] Start to execute cancel task: Kills child processes
13:30:25.383 [go] Task is cancelled

Expected : "[go] Job Completed Console-testing/8/defaultStage/1/job2" should show up in the end of console log

b) Also on specifying job timeout, the console o/p looks like this -

[go] Job Completed Simple-console-testing/3/defaultStage/1/defaultJobGo cancelled this job as it has not generated any console output for more than 2 minute(s)10:15:54.829 [go] Start to execute cancel task: Kills child processes
10:15:54.891 [go] Task is cancelled

Expected o/p :

Go cancelled this job as it has not generated any console output for more than 1 minute(s)
[go] Start to execute cancel task: Kills child processes

[go] Task is cancelled

[go] Job completed test/4/defaultStage/1/defaultJob on f9c423f70d26 [/var/lib/cruise-agent] at Wed Apr 15 20:43:26 UTC 2015

Also at times when a job is cancelled, sometimes logs do not get moved to the final artifact location.

3) ~~If temporary console logs fails to make to the final artifact location due to disk space issue or permissions issue, they continue to lie in the temporary location forever. There should be a way to get these temp logs moved over to the actual location once the issue is resolved with the actual artifact location. Some automatic retry mechanism or on demand retry mechanism should be in place ?? Maybe in later releases ?~~ Moved this to #1057


Changed files:
server/src/com/thoughtworks/go/domain/activity/ConsoleLogArtifactHandler.java
common/src/com/thoughtworks/go/work/DefaultGoPublisher.java
server/test/unit/com/thoughtworks/go/domain/activity/ConsoleLogArtifactHandlerTest.java
common/src/com/thoughtworks/go/remote/work/BuildWork.java
server/src/com/thoughtworks/go/server/service/ConsoleService.java

diff --git a/common/src/com/thoughtworks/go/remote/work/BuildWork.java b/common/src/com/thoughtworks/go/remote/work/BuildWork.java
index 2732b8543e..b6bc734e87 100644
--- a/common/src/com/thoughtworks/go/remote/work/BuildWork.java
+++ b/common/src/com/thoughtworks/go/remote/work/BuildWork.java
@@ -94,6 +94,8 @@ public class BuildWork implements Work {
             LOGGER.error("Agent UUID changed in the middle of the build.", e);
         } catch (Exception e) {
             reportFailure(e);
+        } finally {
+            goPublisher.stop();
         }
     }
 
@@ -110,9 +112,9 @@ public class BuildWork implements Work {
     private void reportCompletion(JobResult result) {
         try {
             builders.waitForCancelTasks();
-            goPublisher.stop();
             if (result == null) {
                 goPublisher.reportCurrentStatus(JobState.Completed);
+                goPublisher.reportCompletedAction();
             } else {
                 goPublisher.reportCompleted(result);
             }
diff --git a/common/src/com/thoughtworks/go/work/DefaultGoPublisher.java b/common/src/com/thoughtworks/go/work/DefaultGoPublisher.java
index 36aece3d2d..b7d3e8b71e 100644
--- a/common/src/com/thoughtworks/go/work/DefaultGoPublisher.java
+++ b/common/src/com/thoughtworks/go/work/DefaultGoPublisher.java
@@ -16,11 +16,13 @@
 
 package com.thoughtworks.go.work;
 
+import java.io.File;
+
+import com.thoughtworks.go.domain.builder.FetchArtifactBuilder;
 import com.thoughtworks.go.domain.JobIdentifier;
 import com.thoughtworks.go.domain.JobResult;
 import com.thoughtworks.go.domain.JobState;
 import com.thoughtworks.go.domain.Property;
-import com.thoughtworks.go.domain.builder.FetchArtifactBuilder;
 import com.thoughtworks.go.publishers.GoArtifactsManipulator;
 import com.thoughtworks.go.remote.AgentIdentifier;
 import com.thoughtworks.go.remote.BuildRepositoryRemote;
@@ -32,8 +34,6 @@ import com.thoughtworks.go.util.TimeProvider;
 import org.apache.commons.logging.Log;
 import org.apache.commons.logging.LogFactory;
 
-import java.io.File;
-
 import static java.lang.String.format;
 
 public class DefaultGoPublisher implements GoPublisher {
@@ -107,6 +107,11 @@ public class DefaultGoPublisher implements GoPublisher {
         LOG.info(String.format("%s is reporting build result [%s] to Go Server for %s", agentIdentifier, result,
                 jobIdentifier.toFullString()));
         remoteBuildRepository.reportCompleted(agentRuntimeInfo, jobIdentifier, result);
+        reportCompletedAction();
+    }
+
+    public void reportCompletedAction() {
+        reportAction("Job completed");
     }
 
     public boolean isIgnored() {
diff --git a/server/src/com/thoughtworks/go/domain/activity/ConsoleLogArtifactHandler.java b/server/src/com/thoughtworks/go/domain/activity/ConsoleLogArtifactHandler.java
index 9a39151595..38643b1547 100644
--- a/server/src/com/thoughtworks/go/domain/activity/ConsoleLogArtifactHandler.java
+++ b/server/src/com/thoughtworks/go/domain/activity/ConsoleLogArtifactHandler.java
@@ -22,12 +22,9 @@ import com.thoughtworks.go.domain.JobIdentifier;
 import com.thoughtworks.go.domain.JobInstance;
 import com.thoughtworks.go.server.domain.JobStatusListener;
 import com.thoughtworks.go.server.service.ConsoleService;
-import com.thoughtworks.go.util.GoConstants;
 import org.springframework.beans.factory.annotation.Autowired;
 import org.springframework.stereotype.Component;
 
-import static java.lang.String.format;
-
 @Component
 public class ConsoleLogArtifactHandler implements JobStatusListener {
     private ConsoleService consoleService;
@@ -43,9 +40,6 @@ public class ConsoleLogArtifactHandler implements JobStatusListener {
             try {
                 JobIdentifier identifier = job.getIdentifier();
                 consoleService.moveConsoleArtifacts(identifier);
-                // TODO: Put correct timestamp of job completion the agent and the server maybe on different timezones.
-                consoleService.appendToConsoleLog(identifier, format("[%s] %s %s", GoConstants.PRODUCT_NAME, "Job Completed"
-                        , identifier.buildLocatorForDisplay()));
             } catch (Exception e) {
                 throw new RuntimeException(e);
             }
diff --git a/server/src/com/thoughtworks/go/server/service/ConsoleService.java b/server/src/com/thoughtworks/go/server/service/ConsoleService.java
index 74609d7b3a..c55be1ec99 100644
--- a/server/src/com/thoughtworks/go/server/service/ConsoleService.java
+++ b/server/src/com/thoughtworks/go/server/service/ConsoleService.java
@@ -173,6 +173,7 @@ public class ConsoleService {
     public void moveConsoleArtifacts(LocatableEntity locatableEntity) {
         try {
             File from = chooser.temporaryConsoleFile(locatableEntity);
+            from.createNewFile(); // Job cancellation skips temporary file creation. Force create one if it does not exist.
             File to = chooser.findArtifact(locatableEntity, getConsoleOutputFolderAndFileName());
             FileUtils.moveFile(from, to);
         } catch (IOException e) {
diff --git a/server/test/unit/com/thoughtworks/go/domain/activity/ConsoleLogArtifactHandlerTest.java b/server/test/unit/com/thoughtworks/go/domain/activity/ConsoleLogArtifactHandlerTest.java
index a7e297e068..86ab26af52 100644
--- a/server/test/unit/com/thoughtworks/go/domain/activity/ConsoleLogArtifactHandlerTest.java
+++ b/server/test/unit/com/thoughtworks/go/domain/activity/ConsoleLogArtifactHandlerTest.java
@@ -35,12 +35,6 @@ public class ConsoleLogArtifactHandlerTest {
         verify(consoleService, never()).moveConsoleArtifacts(buildingJobInstance.getIdentifier());
     }
 
-    @Test
-    public void shouldReportJobAsCompletedOnConsole() throws Exception {
-        handler.jobStatusChanged(completedJobInstance);
-        verify(consoleService).appendToConsoleLog(completedJobInstance.getIdentifier(), "[go] Job Completed pipeline/label-1/stage/1/job");
-    }
-
     @Test
     public void shouldReportJobAsCompletedOnConsoleOnlyWhenStatusIsCompleted() throws Exception {
         handler.jobStatusChanged(buildingJobInstance);