Versions Compared

Old Version 2

changes.mady.by.user David Blevins

Saved on

compared with

New Version Current

changes.mady.by.user David Blevins

Saved on

Key

  • This line was added.
  • This line was removed.
  • Formatting was changed.
Comment: Migrated to Confluence 5.3

Watching the logs

The log file for a given GBuild Agent is located at gbuild-agent-1.0-SNAPSHOT/logs/wrapper.log

Aside from grep and less, a great way to watch the log file is to 'tail' it continuously like such:

$ tail -f gbuild-agent-1.0-SNAPSHOT/logs/wrapper.log

Interpreting the lines (Stan's log)

Watching the log files is fairly intuative but the volume of output can make the simplicity hard to see. This gives you a nice break of a run in a way that's more cleaned up.

Work added

When someone puts a new properties file containing build tasks in the "gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/tasks/" directory, you will see lines similar to the following in the log file.
When that file is added to the gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/tasks directory, you'll see something like the following in the log file.

No Format
2005-12-19 23:57:39,845 [Thread-1] DEBUG BuildAgent:build-producer      - File Discovered: /home/dblevins/gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/tasks/tck-tomcat-large.properties
2005-12-19 23:57:49,849 [Thread-1] INFO  BuildAgent:build-producer      - New File: /home/dblevins/gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/tasks/tck-tomcat-large.properties
2005-12-19 23:57:49,854 [Thread-1] INFO  BuildAgent:build-producer      - Processing /home/dblevins/gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/tasks/tck-tomcat-large.properties
2005-12-19 23:57:49,854 [Thread-1] INFO  BuildAgent:build-producer      - Project - 52 - geronimo-tck-tomcat 1.0
2005-12-19 23:57:49,855 [Thread-1] INFO  BuildAgent:build-producer      - Build - 0 - build.four clean tck:tomcat four tck:work-status
2005-12-19 23:57:49,856 [Thread-1] INFO  BuildAgent:build-producer      - Build - 1 - build.three clean tck:tomcat three tck:work-status
2005-12-19 23:57:49,861 [Thread-1] INFO  BuildAgent:build-producer      - Build - 2 - build.five clean tck:tomcat five tck:work-status

This means you've just added three build definitions to the BUILD.TASKS queue.

Work started

Assuming there are agents ready and waiting for work, you'll see the following in the log file shortly after.

No Format
2005-12-19 23:57:49,876 [Thread-4] INFO  BuildAgent:build-activity      - [kenny.gbuild.org:127.0.0.1] geronimo-tck-tomcat-1.0 - five 2 - Started
2005-12-19 23:57:50,047 [Thread-4] INFO  BuildAgent:build-activity      - [jimmy:67.103.164.101] geronimo-tck-tomcat-1.0 - four 0 - Started
2005-12-19 23:57:50,081 [Thread-4] INFO  BuildAgent:build-activity      - [timmy:67.103.164.98] geronimo-tck-tomcat-1.0 - three 1 - Started

In this example, the hosts kenny, timmy and jimmy picked up those builds and started working on them. Whenever they finish, they will report the results back to the BUILD.RESULTS topic.

Work completed

Here is the example log messages from kenny in on the work that he did.

No Format
1. 2005-12-20 05:29:12,056 [Thread-4] INFO  BuildAgent:build-activity      - [kenny.gbuild.org:127.0.0.1] geronimo-tck-tomcat-1.0 - five 2 - Completed: 331 minutes: Successful
2. 2005-12-20 05:29:40,548 [Thread-2] INFO  BuildAgent:build-results       - Message Received ID:kenny.gbuild.org-60448-1135064141036-8:2 on ID:stan.gbuild.org-39135-1135064138912-1:0:BUILD.RESULTS
3. 2005-12-20 05:29:41,597 [Thread-2] DEBUG BuildResultsExtension:log-failed-build-file - five 2 - exit code (0)
4. 2005-12-20 05:29:41,598 [Thread-2] INFO  BuildResultsExtension:write-include-file - Writing 663332 characters to /home/dblevins/gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/results/geronimo-tck-tomcat/1.0/five-2.properties
5. 2005-12-20 05:29:41,611 [Thread-2] INFO  BuildAgent:build-results       - Finished processing ID:kenny.gbuild.org-60448-1135064141036-8:2
  1. In the first line you see the text "BuildAgent:build-activity", which is a message sent by kenny onto the BUILD.ACTIVITY topic.
  2. This line is printed by the build-results Agent telling us that it has received a results message from kenny on the BUILD.RESULTS topic.
  3. The first extension to be processed is the one that checks the build result and writes the build output if the build failed. We can see by the exit code (0) that everything went OK. Not build output will be written.
  4. The second extension to do any processing is the write-include-file extension. This means the build task messages had an "include." header which pointed to a file it wanted slurped into the results message. Our WriteIncludeFileExtenion is doing like it should and writing that content to a file.
  5. The last line is also printed by the build-results Agent and it lets us know that all the Extensions have run and kenny's results message has been fully processed.

What you don't see

You don't see output above is the build task being received, the BuildAgentExtensions being run, and the result message being created. Why you ask? Because all that happened on Kenny. In this example, Stan is just creating build definitions and collecting results, not building anything himself. We would need to log into kenny.gbuild.org and check his log file to see what he did.

Interpreting the lines (Kenny's log)

Task received

No Format
2005-12-19 23:57:50,726 [Thread-2] INFO  BuildAgent:build-executor      - Message Received ID:stan.gbuild.org-39135-1135064138912-9:2 on ID:kenny.gbuild.org-60448-1135064141036-1:0:BUILD.TASKS

Extensions do pre-precessing

The first thing Kenny does invoke the preProcess method of the BuildAgentExtensions

No Format
2005-12-19 23:57:50,729 [Thread-2] INFO  BuildAgentExtentionManager     - Executing extention clean-dead-processes pre process
2005-12-19 23:57:50,729 [Thread-2] INFO  BuildAgentExtentionManager     - Executing extention general-headers pre process
2005-12-19 23:57:50,730 [Thread-2] INFO  BuildAgentExtentionManager     - Executing extention report-activity pre process
2005-12-19 23:57:50,732 [Thread-2] INFO  BuildAgentExtentionManager     - Executing extention build-output pre process
2005-12-19 23:57:50,732 [Thread-2] INFO  BuildAgentExtentionManager     - Executing extention file-include pre process

Each extension does it's thing. The "report-activity" extension, for example, is responsible for the "geronimo-tck-tomcat-1.0 - five 2 - Started" message received and logged by Stan in our examples above.

SCM Update

With pre-processing done, Kenny hands the build task over to Continuum.

No Format
2005-12-19 23:57:50,734 [Thread-2] INFO  ContinuumScm                   - Updating project: id: '52', name 'geronimo-tck-tomcat'.
2005-12-19 23:57:50,734 [Thread-2] INFO  ScmManager                     - Executing: svn --non-interactive update
2005-12-19 23:57:50,735 [Thread-2] INFO  ScmManager                     - Working directory: /home/dblevins/gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/agent/work/52
2005-12-19 23:57:52,101 [Thread-17] DEBUG ScmManager                     - At revision 1123.
2005-12-19 23:57:52,103 [Thread-2] INFO  Action:update-project-from-working-directory - Updating project 'geronimo-tck-tomcat' from checkout.

Continuum successfully determines the project uses SVN and updates the source.

Executing the build

No Format
2005-12-19 23:57:52,103 [Thread-2] WARN  ContinuumBuildExecutor:shell   - Executable '/home/dblevins/gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/agent/work/52/maven.sh'.
2005-12-19 23:57:52,103 [Thread-2] INFO  ContinuumBuildExecutor:shell   - Arguments: clean tck:tomcat five tck:work-status
2005-12-19 23:57:52,104 [Thread-2] INFO  ContinuumBuildExecutor:shell   - Working directory: /home/dblevins/gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/agent/work/52
2005-12-20 05:29:12,856 [Thread-2] INFO  ContinuumBuildExecutor:shell   - Exit code: 0

Continuum finds the script that will run our build and executes it with the arguments "clean tck:tomcat five tck:work-status". In this case the maven.sh is just a script that calls maven and passes the arguments right to it. After quite some time, we see the build complete and it's exit code is logged showing things went perfectly.

Extensions do post-precessing

A results HashMap is created and all of the BuildAgentExtensions are called again for post processing.

No Format
2005-12-20 05:29:12,857 [Thread-2] INFO  BuildAgentExtentionManager     - Executing extention clean-dead-processes post process
2005-12-20 05:29:12,875 [Thread-2] DEBUG BuildAgentExtension:clean-dead-processes - No processes found matching ".*geronimo-tck.*".
2005-12-20 05:29:12,875 [Thread-2] INFO  BuildAgentExtentionManager     - Executing extention general-headers post process
2005-12-20 05:29:12,876 [Thread-2] WARN  BuildAgentExtension:general-headers - replaced projectId = 52
2005-12-20 05:29:12,876 [Thread-2] WARN  BuildAgentExtension:general-headers - replaced buildDefinitionId = 2
2005-12-20 05:29:12,876 [Thread-2] INFO  BuildAgentExtentionManager     - Executing extention report-activity post process
2005-12-20 05:29:12,900 [Thread-2] INFO  BuildAgentExtentionManager     - Executing extention build-output post process
2005-12-20 05:29:12,900 [Thread-2] DEBUG BuildAgentExtension:build-output - Reading /home/dblevins/gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/agent/output/52/0.log.txt
2005-12-20 05:29:32,745 [Thread-2] INFO  BuildAgentExtension:build-output - Including 19004671 - /home/dblevins/gbuild-agent-1.0-SNAPSHOT/apps/gbuild-agent/agent/output/52/0.log.txt
2005-12-20 05:29:32,745 [Thread-2] INFO  BuildAgentExtentionManager     - Executing extention file-include post process

Task completed and results sent

And finally Kenny tells us that he is done processing the build task message received from Stan and has placed the results onto the BUILD.RESULTS topic.

No Format
2005-12-20 05:29:33,057 [Thread-2] INFO  BuildAgent:build-executor      - Finished processing ID:stan.gbuild.org-39135-1135064138912-9:2
2005-12-20 05:29:39,485 [Thread-2] INFO  BuildAgent:build-executor      - Results sent to BUILD.RESULTS