DevOps Zone is brought to you in partnership with:

Gerard Davison is a Senior Principal Software Engineer working at Oracle in the UK on SOAP and REST tooling. Currently he is contributing in the area of WADL generation and client generation in the Jersey project and is maintaining the Abbot swing automation project. He also maintain a small holding of Hudson nodes run all those tests. He graduated from the University of Reading with a degree in Human Cybernetic and can't help looking for feedback loops. Gerard is a DZone MVB and is not an employee of DZone and has posted 32 posts at DZone. You can read more from them at their website. View Full User Profile

A Little Temporal Feedback When Running Tests

02.23.2013
| 1970 views |
  • submit to reddit

I have been working a lot recently with a bunch of test jobs that are intermittently getting stuck. Now it is possible to work out the point where the problem is occurring by looking at the date labels on the LOG output; but it is hard visually to pick these discontinuities out.

In order improve the output in a way that my brain can really quickly parse and identify I thought I would try my hand a bit of simple ASCII animation. I wrote a simple fixture that writes out a line every 1 minute while the test is running, here is a very simple implementation - I am sure there are better ways to do the animation!

view plaincopy to clipboardprint?
  1. import java.util.Timer; 
  2. import java.util.TimerTask; 
  3. import java.util.concurrent.TimeUnit; 
  4. public class TickTockFixture 
  5.  private Timer timer; 
  6.  @Before 
  7.  public void setUp() 
  8.  { 
  9.  // Clean out any old timers 
  10.  tearDown(); 
  11.  // Start a new timer 
  12.  timer = new Timer(); 
  13.  timer.scheduleAtFixedRate(new TimerTask() 
  14.  { 
  15.  int counter = 0; 
  16.  @Override 
  17.  public void run() 
  18.  { 
  19.  StringBuilder sb = new StringBuilder(". TickTock : "); 
  20.  int animation = counter++ % 10; 
  21.  boolean direction = animation < 5; 
  22.  int count = direction ? animation : 9 - animation; 
  23.  sb.append(" ", 0, count); 
  24.  sb.append(direction ? "/" : "\\"); 
  25.  sb.append(" ",0, 5-count); 
  26.  sb.append(counter); 
  27.  sb.append(" min(s)"); 
  28.  System.err.println(sb); 
  29.  } 
  30.  }, 0, TimeUnit.MINUTES.toMillis(1)); 
  31.  } 
  32.  @After 
  33.  public void tearDown() 
  34.  { 
  35.  if (timer!=null) 
  36.  { 
  37.  timer.cancel(); 
  38.  timer = null; 
  39.  } 
  40.  } 
So does this help, well take a look at the - made up example - output below and try to spot the section of the log output where everything slows down. It is a lot easier with the ticking output which I think sticks out better because of the animation.

22-Feb-2013 11:54:30 Items in drs, going to tidy up
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/WEB-INF/weblogic.xml
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/WEB-INF/web.xml
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/WEB-INF/classes/project1/Hello.class
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/WEB-INF/classes/project1/
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/WEB-INF/classes/
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/WEB-INF/
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/.module_marker
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/META-INF/weblogic-application.xml
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/META-INF/application.xml
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/META-INF/
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/.adrs-module.properties
22-Feb-2013 11:54:40 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/
22-Feb-2013 11:54:53 oracle.jdevimpl.webservices.tcpmonitor.config.AnalyzerInstance stop
WARNING: AnalyzerInstance aborting a stop as already appears to be stopped
22-Feb-2013 11:54:53 weblogic.logging.ServerLoggingHandler publish
WARNING: Container weblogic.wsee.jaxws.WLSContainer$BasicContainer@1232e17 doesn't support class com.sun.xml.ws.api.server.Module
22-Feb-2013 11:54:53 weblogic.logging.ServerLoggingHandler publish
WARNING: Container weblogic.wsee.jaxws.WLSContainer$BasicContainer@1232e17 doesn't support class com.sun.xml.ws.api.server.Module
trigger seeding of SecureRandom
. TickTock :  \    9 min(s)
. TickTock : \     10 min(s)
. TickTock : /     11 min(s)
. TickTock :  /    12 min(s)
. TickTock :   /   13 min(s)
22-Feb-2013 11:59:50 done seeding SecureRandom
22-Feb-2013 11:59:53 weblogic.logging.ServerLoggingHandler publish
WARNING: Container weblogic.wsee.jaxws.WLSContainer$BasicContainer@1232e17 doesn't support class com.sun.xml.ws.api.server.Module
22-Feb-2013 12:00:01 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/WEB-INF/classes/project1/Hello.class
22-Feb-2013 12:00:01 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/WEB-INF/classes/project1/
22-Feb-2013 12:00:01 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/WEB-INF/classes/
22-Feb-2013 12:00:01 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/WEB-INF/
22-Feb-2013 12:00:01 Removing file:/scratch/gdavison/view_storage/gdavison_lt/oracle/jdeveloper/system12.1.2.0.40.65.92/o.j2ee/drs/Application1/Project1WebApp.war/

Published at DZone with permission of Gerard Davison, author and DZone MVB. (source)

(Note: Opinions expressed in this article and its replies are the opinions of their respective authors and not those of DZone, Inc.)