Showing posts with label java. Show all posts
Showing posts with label java. Show all posts

Friday, November 30, 2018

In JDK 9 (and well 8) and above everything can be a stream.

In JDK 8 we finally got to use streams and everything was good apart from the times when the API you used couldn't produce a stream. Then you ended up writing a wrapper class method that allowed you to convert an iterator into a Stream, because you missed streams.

public static <T> Stream<T> asStream(Iterator<T> it) {
    return StreamSupport.stream(Spliterators.spliteratorUnknownSize(it,
        Spliterator.IMMUTABLE | Spliterator.ORDERED),false);
}

Now there are methods to programmatically generate stream in the case of iterate and generate but both of these generate an infinite stream whereas in most cases you really wanted to adapt an existing interface into a finite Stream.

This was resolved nicely in JDK 9 with the introduction of a new form of iterate method that allows you to provide a predicate to signal the end of the stream.

In the examples below I am going to use a predicate that continues until you get a null entry to the stream, I will leave it up to the reader to come up with more imaginative uses for predicate. In this simple example I am using the getCause method of Throwable to move us along a linked list of errors. Note how little code this would take when compared with a pre stream version.

// Simple linked list
//
Exception e = new Exception("one");
Exception e2 = new Exception("two",e);
Exception e3 = new Exception("three", e2);

Stream.iterate(e3, Objects::nonNull, Throwable::getCause)

    // Output the messages in turn
    .map(Throwable::getMessage)
    .forEach(System.out::println);

The second example converts a ReferenceQueue into a Stream so that we can easily drain its contents for processing as required. This code is a little bit different because the container is different from the object be worked on, so we provide the seed and the next value using the same method, This returns null when the queue becomes empty.

ReferenceQueue<Thing> queue = new ReferenceQueue<>();

// Make some things and then collect them
WeakReference one = new WeakReference<Thing>(new Thing(), queue);
WeakReference two = new WeakReference<Thing>(new Thing(), queue);
System.gc(); System.gc(); System.gc(); System.gc(); System.gc();

Stream.<Reference<? extends Thing>>iterate(
    queue.poll(), Objects::nonNull, v -> queue.poll())


    .forEach(System.out::println);

The third example shows a walk over a Node tree, note the nested stream iterator to work back up the list when we have worked to the end of a leaf.

Node root = doc.getDocumentElement();

Stream.iterate(
    root,
    Objects::nonNull,
    v -> {
        if (v.getFirstChild()!=null) {
            return v.getFirstChild();
        }

        if (v.getNextSibling()!=null) {
            return v.getNextSibling();
        }

        return Stream.iterate(v, Objects::nonNull, Node::getParentNode)
            .filter(node -> node.getNextSibling()!=null)
            .map(Node::getNextSibling).findFirst().orElse(null);
    })

    .map(Node::getNodeName)
    .forEach(System.out::println);


So with a little bit of mental gymnastics it is possible to transform most legacy APIs into a nice clean Stream, so you can ignore those nasty old fashioned for loops. And if you are stuck in JDK 8 then it is quite easy to put together a similar function using the asStream from before:

public static<T> Stream<T> iterateFinite(T seed, Predicate<? super T> hasNext, UnaryOperator<T> next) {

    return asStream(new Iterator<>() {

        T current = seed;

        @Override
        public boolean hasNext() {
            return hasNext.test(current);
        }

        @Override
        public T next() {
            if (current == null) {
                throw new NoSuchElementException();
            }
            try {
                return current;
            } finally {
                current = next.apply(current);
            }
        }
    });
}


Thursday, June 15, 2017

Interpreting wpad.dat using jrunscript from JDK 8 to work out the right proxy.

In many environments you find that the correct proxy can only be fetched by parsing http://wpad/wpad.dat, which is a pain because it is actually a JavaScript file. Working out the right proxy to call for say a unix environment is a bit of a fiddle particularly if you company is huge and requires different proxies for different countries. JDK 8 to the rescue, as you can run a simple script in the Nashorn environment to get the suggested proxy for one host and use that for everything:

jrunscript -e "`curl -o - -s http://wpad/wpad.dat` function isPlainHostName(hostname) { return hostname.indexOf('.')==-1;}; var proxyList = FindProxyForURL('http://github.com','github.com'); var firstProxy = proxyList.split(';')[0].trim(); print('DIRECT'.equals(firstProxy) ?  '' : 'http://' + firstProxy.split(' ')[1]);"

Depending on your local environment you might have to implement one or more functions from the list that your wpad.dat expects, in our case I needed to implement isPlainHost.

The last part of the script just picks the first proxy name, as the function returns a list of PROXY is suggested order. The raw output looks like this:

PROXY london.example.com:80; PROXY sf.example.com:80; DIRECT;

So we just pick the first one with http as the prefix, as some tools such as docker are fussy about this, or returns an empty string if DIRECT is recommended.

http://london.example.com:80

Thursday, April 7, 2016

Converting string configuration properties to other types, with a bit of Optional.

Somedays you come across some code and think that's pretty, why didn't I think of that? So my long time colleague Mark Warner has a nice twist on the standard name/value store pattern using method references to deal with converting from a String.

int size = store.getProperty("cache.limit", 500, Integer::parseInt);
    boolean enabled = store.getProperty("cache.enabled", true, Boolean::getBoolean);

I took his example and refactored it slightly to return Optional, and I ended up with the following:

public Optional<String> getProperty(
        String propertyName) {
    return Optional.ofNullable(map.get(propertyName));
}
   
public <T> Optional<T> getProperty(
        String propertyName, 
        ThrowingFunction<String,? extends T,? extends Exception> func ) {

    return getProperty(propertyName).map(val -> {
        try {
            return func.apply( val );
        } catch ( Exception e ) {
            LOGGER.severe( () -> "Invalid property transform, will default " + e.getMessage() );
            return null;
        }
    });
}

This means that the default value ends up being provided by the Optional which is a nice application of OAOO.

int size = store.getProperty("cache.limit", Integer::parseInt).orElse(500);
    boolean enabled = store.getProperty("cache.enabled", Boolean::getBoolean).orElse(true);

I think this is even tidier; but it does depend on who you feel about using Optionals.

Thursday, March 10, 2016

Lambda of Lambda, if/else from an Optional

So I got frustrated with two limitations of the Optional interface in JDK 8. The first problem is that there is no obvious way to perform an else operation in a block as there is only a isPresent method unless you are using an old school if statement. The second problem is of course the old chestnut that even if you could do that the methods would not be able to throw a checked exception. (Yes you can wrap with a RuntimeException but it is not the prettiest.)

The workaround I found was to use the map function as the success case and the orElseGet to return the failure case. In both branches the code returns an instance of ThrowingRunnable by having a lambda return a lambda. The run() is then called at the end and it can throw any exception it wants to.

@FunctionalInterface
public interface ThrowingRunnable<E extends Throwable>  {
    
    public void run() throws E;
}



Optional<Credential> credential = ....

credential.<ThrowingRunnable<IOException>>map(auth -> () -> {
                PasswordWrapper pw = auth.getToken();
                ... // something that might throw an IOException
            }).orElseGet(() -> () -> {
                        response.setStatus(401);
                        LOGGER.log(Level.INFO, "credential is not found");
                    }
            ).run();


This is possibly excessive for this particular use case; but I can see this technique being useful elsewhere and it is worth knowing what it looks like so it is not a surprise in others code.

Update 14th March 2016: Thanks to Michael Rasmussen on the DZone version of this article he noted I could use orElse rather than orElseGet to remove the second double lambda.

credential.<ThrowingRunnable<IOException>>map(auth -> () -> {
                PasswordWrapper pw = auth.getToken();
                ... // something that might throw an IOException
            }).orElse(() -> {
                        response.setStatus(401);
                        LOGGER.log(Level.INFO, "credential is not found");
                    }
            ).run();



Wednesday, March 2, 2016

Getting hold of an un-used port when writing a test

A really quick post today, I was writing a unit test that needed to put up a temporary JAX-RS resource in order to test something very specific with out the need of a large testing framework. Unfortunately the code I was using didn't know about replacing zero with a random allocated port so I had to do something different. The nice tidy code that does this looks like the following:

try(ServerSocket ss = new ServerSocket(0)) {
   freePort = ss.getLocalPort();
}

server = createServerWithPort(freePort);

But of course there is a race condition here as there could be another process on the machine running the exact same code that gets lucky with its time on the CPU - note the API I was using couldn't use the ServerSocket directly so there is a gap where the port is not tied up. So to rule out the one in a million failure chance, which always comes on a Friday at 5pm, we need to wrap this code in a loop.

while(server==null) {
    try(ServerSocket ss = new ServerSocket(0)) {
       freePort = ss.getLocalPort();
    }

    server = createServerWithPort(freePort);
}

This may seem extreme; but if you are running some kind of CI system like Hudson or Jenkins it is not unusual to be running multiple executors on the same machine. You might have two developers running preflights at the same time causing an annoying intermittent failure as described above.

Finally a version using a JDK 8 stream with a helper method to convert the IOException from ServerSocket into a RuntimeException. Some would argue this is less readable; but I find it more explicit.

server = Stream.generate(convertException(() -> {
    try(ServerSocket ss = new ServerSocket(0)) {
        return ss.getLocalPort();
    }
})).map(TestClass::createServerWithPort)
.filter(Objects::nonNull)
.findFirst().get();

Tuesday, January 12, 2016

Beware of slightly different behaviour between ConcurrentMap and ConcurrentHashMap for computeIfAbsent

So I was refactoring some code to use non-locking collection classes and I noticed the this significant different between ConcurrentMap.computeIfAbsent and ConcurrentHashMap.computeIfAbsent. They key different is that for the former default implementing the mapping function can be called many times for a particular key where as for the concrete implementation it will be called only once. This will likely affect whether the code in the function needs to be thread safe or not.

Right okay so armed with that you know that any collection that implements just ConcurrentMap will inherit this behaviour, further to that I found in particular guava would return a different implementation depending on the passed on parameters:

ConcurrentMap map1 = new MapMaker().makeMap();
System.out.println(map1.getClass());

ConcurrentMap map2 = new MapMaker().weakKeys().makeMap();
System.out.println(map2.getClass());

....

class java.util.concurrent.ConcurrentHashMap
class com.google.common.collect.MapMakerInternalMap

MapMakerInternalMap doesn't override computerIfAbsent therefore the behaviour of this function will be significantly different depending on the parameters to pass into the maker, something that might be apparent from the get go.

Wednesday, November 25, 2015

A very simple implementation of Suite to make it easy to run across a bunch of test machines at the same time.

So I was presented with a large suite that I need to distribute amongst an arbitrary number of Hudson slaves. Now my first guess would be to hand balance this into N sub suites; but that would require on-going work and would need to change depending on the number of nodes. (We have a target of 30 minutes to run all tests in parallel which is going to take some machines)

@RunWith(Suite.class)
@Suite.SuiteClasses({
    TableCRUD.class,
    TableCRUDChild.class,
    TableFilterSort.class,
    TableDefaultQuery.class,
    TableActions.class,
    ....
})
public class DevSuite {

}

So the quickest way I found to do this was to write different version of Suite that allocated the tests to different bins. This implementation doesn't ensure properly balanced bins as it is biased towards keeping the order stable and consistent which is useful for comparing tests results split into multiple jobs.

import java.util.Collection;
import java.util.List;
import java.util.Map;
import java.util.TreeMap;
import java.util.function.Function;
import java.util.function.ToIntFunction;
import java.util.stream.Collector;
import java.util.stream.Collectors;
import org.junit.runner.Runner;
import org.junit.runners.Suite;
import org.junit.runners.model.InitializationError;
import org.junit.runners.model.RunnerBuilder;

/**
 * Try to proportion a suites tests into "SPLIT" number of equals sections and
 * then just run "SECTION" rather than all of the tests. Defined by
 * "SplitSuite.split" and "SplitSuite.section" respectively
 */
public class SplitSuite
        extends Suite {

    private static int SECTIONS
            = Integer.getInteger("SplitSuite.split", -1);
    private static int SECTION
            = Integer.getInteger("SplitSuite.section", -1);

    public SplitSuite(RunnerBuilder builder, Class<?>[] classes) throws InitializationError {
        super(builder, classes);
    }

    public SplitSuite(Class<?> klass, RunnerBuilder builder) throws InitializationError {
        super(klass, builder);
    }

    public List<Runner> getChildren() {
        if (SECTIONS < 0) {
            return super.getChildren();
        } else if (SECTIONS == 0) {
            throw new IllegalArgumentException("SplitSuite.split needs to be a positive integer, it cannot be zero. A negative valid will disable this feature.");
        } else if (SECTION >= SECTIONS) {
            throw new IllegalArgumentException("SplitSuite.section parameter " + SECTION + " needs to be less than SplitSuite.split " + SECTIONS);
        }

        final Map<Integer, List<Runner>> collect = originalList.stream().collect(
                assignToGroups(SECTIONS, Runner::testCount, originalList));

        return collect.get(SECTION);
    }

    
    /**
     * Assigns object to buckets, moving to the next when filled, whilst preserving
     * the original order.
     * @param <Type> The type that has some kind of size property
     * @param sections The number of sections to split the code across
     * @param sizer A function to return the size of the given object
     * @param originalList The original list to provide a base line size
     * @return A map that contains an order list of sections
     */
    public static <Type> Collector<Type, ?, Map<Integer, List<Type>>> assignToGroups(
            int sections, 
            final ToIntFunction<Type> sizer,
            Collection<Type> originalList) {

        // Get length
        int count = originalList.stream().collect(Collectors.summingInt(sizer));
        // Workout section length
        int sectionLength = count / sections;
        
        Function<Type, Integer> grouping = new Function<Type, Integer>() {
            
            int counter = 0;
            
            @Override
            public Integer apply(Type t) {
                int section = Math.min(counter / sectionLength, sections - 1);
                counter += sizer.applyAsInt(t);                
                return section; 
            }
        };
        
        
        return Collectors.groupingBy(grouping, TreeMap::new, Collectors.toList());
    }
    
    
}



So a quick change to the suite class....

@RunWith(SplitSuite.class)
@Suite.SuiteClasses({
    TableCRUD.class,
    TableCRUDChild.class,
    TableFilterSort.class,
    TableDefaultQuery.class,
    TableActions.class,
    ....
})
public class DevSuite {

}

Now the actual test step looks like this, note that this is running under hudson but you should be able to achieve something similar on the CI server of your choice. In order to make my life easier I derive the section number from the job name for so 3 sections I have ..._0 ..._1 and ..._2. In hudson the later jobs all cascade from the the first sharing all properties which makes maintenance a lot easier.

java ... -DSplitSuite.sections=${SECTIONS} -DSplitSuite.section=`echo ${JOB_NAME} | sed -e s/.*_//` ...

And it appears to work, obviously the algorithm to split the suites could be better to produce more balanced results; but that is an effort for another day.....

Monday, March 9, 2015

Quick and dirty test for thread leakage in java

I was looking at a bit of code was leaking class loaders when deployed to tomcat - so I wanted to quick rule out that a background Thread was holding onto the loader. Pain by eye, it is quite easy with a few unix commands to process the stack trace, filter for the lines that contain the thread name, filter for just the thread names and sort:
sudo -u tomcat jstack 1853 | grep " prio=" | sed -e 's/"\(.*\)".*/\1/' | sort
Once this is done it is a simple matter to pipe the output to a file, say /tmp/before.threads, then run the deploy task a small prime number of times in order to create a clear signal, and then compare with the original thread list
[gdavison ~]$ diff /tmp/before.threads /tmp/after.threads
26a27
> RMI TCP Connection(11)-127.0.0.1
[gdavison ~]$
As with any server there will be a lot going on, in this case I saw a spurious RMI thread we can probably ignore, but if there was any application specific thread leakage the problem should repeat a number of times that is cleanly divisible with the prime number you picked before, for example where the prime is three with an example issue:
[gdavison@slc01htu ~]$ diff /tmp/before.threads /tmp/after.threads
8a9,11
> Problem Thread
> Problem Thread
> Problem Thread
26a30
> RMI TCP Connection(11)-127.0.0.1
[gdavison ~]$

As I say quick and dirty; but might be worth writing down for later use.

Monday, November 17, 2014

But that's impossible, or finding out that the JIT has broken your code.

Every now and then you look at some code and think that it cannot be possibly be wrong. Once you have ruled out a simple programmer screw up / enemy action in code (Make sure you read Java Puzzlers or similar) or a concurrency issue (Read Java Concurrency or go on Dr Heniz excellent course) you should sit back and take a few days and then starting thinking about whether the JDK is indeed out to get you. I haven't seen one in the wild in my 18 odd years as a Java programmer so it kinda took me by surprise.

If you are running against JDK 8 in a large scale Swing application you might eventually see the following exception, lots of lots of times. (Unless you forgot the lesson learned in my previous blog in your logging code, in which case you might see lots of ArrayOfOutBoundsException)

Caused by: java.lang.NullPointerException 
    at javax.swing.text.GlyphView.getBreakSpot(GlyphView.java:799) 
    at javax.swing.text.GlyphView.getBreakWeight(GlyphView.java:724) 
    at javax.swing.text.FlowView$LogicalView.getPreferredSpan(FlowView.java:733) 
    at javax.swing.text.FlowView.calculateMinorAxisRequirements(FlowView.java:233) 
    at javax.swing.text.ParagraphView.calculateMinorAxisRequirements(ParagraphView.java:717) 
    at javax.swing.text.BoxView.checkRequests(BoxView.java:935) 
    at javax.swing.text.BoxView.getMinimumSpan(BoxView.java:568) 
    at javax.swing.text.BoxView.calculateMinorAxisRequirements(BoxView.java:903) 
    at javax.swing.text.BoxView.checkRequests(BoxView.java:935) 
    at javax.swing.text.BoxView.setSpanOnAxis(BoxView.java:343) 
    at javax.swing.text.BoxView.layout(BoxView.java:708) 
    at javax.swing.text.BoxView.setSize(BoxView.java:397) 
    ...

This error is particularly insidious because it takes around ten minutes to show itself and sometimes not at all. If you look at the code for this class the line in question, starts with "startsFrom = break", only accesses two local variables both of which have been previously referenced in the method.

            Segment s = getText(pstart, pend); 
            s.first(); 
            BreakIterator breaker = getBreaker(); 
            breaker.setText(s); 

            // Backward search should start from end+1 unless there's NO end+1 
            int startFrom = end + (pend > end ? 1 : 0); 
            for (;;) { 
                startFrom = breaker.preceding(s.offset + (startFrom - pstart))   
                          + (pstart - s.offset); 
                if (startFrom > start) { 
                    // The break spot is within the view 
                    bs[ix++] = startFrom; 
                } else { 
                    break; 
                } 
            } 

The most direct way to rule out a JIT error is to disable compilation for just this single method, here is an example; but you can fine more in the documentation for the command line java tool.

javaThing -XX:CompileCommand=exclude,javax/swing/text/GlyphView,getBreakSpot

When this parameter is added, the problem goes away. - since we have ruled out enemy action by code or a concurrency issue we can be more sure this is a JIT issue. Now as part of the bug logging for this I output diagnostics for this single method, and found out that the problem, didn't occur until the method was JITted for a fifth time.

javaThing -XX:CompileCommand=print,javax/swing/text/GlyphView,getBreakSpot

Here is some diagnostic output seen with the above command:

Compiled method (c2)  914078 33142       4       javax.swing.text.GlyphView::getBreakSpot (247 bytes)
 total in heap  [0x00002aaab0749e10,0x00002aaab0750fe0] = 29136
 relocation     [0x00002aaab0749f38,0x00002aaab074a1e8] = 688
 constants      [0x00002aaab074a200,0x00002aaab074a2a0] = 160
 main code      [0x00002aaab074a2a0,0x00002aaab074cde0] = 11072
 stub code      [0x00002aaab074cde0,0x00002aaab074ce40] = 96
 oops           [0x00002aaab074ce40,0x00002aaab074ce58] = 24
 metadata       [0x00002aaab074ce58,0x00002aaab074d058] = 512
 scopes data    [0x00002aaab074d058,0x00002aaab074ea20] = 6600
 scopes pcs     [0x00002aaab074ea20,0x00002aaab0750c50] = 8752
 dependencies   [0x00002aaab0750c50,0x00002aaab0750c80] = 48
 handler table  [0x00002aaab0750c80,0x00002aaab0750e90] = 528
 nul chk table  [0x00002aaab0750e90,0x00002aaab0750fe0] = 336
OopMapSet contains 113 OopMaps
#0 
OopMap{[8]=Oop [32]=Oop [40]=Oop off=892}
#1 
OopMap{[32]=Oop [40]=Oop off=960}
#2 
OopMap{[32]=Oop [40]=Oop off=980}
#3 
OopMap{[32]=Oop [40]=Oop [48]=Oop off=1048}
#4 
OopMap{[32]=Oop [40]=Oop [48]=Oop off=1084}
#5 
OopMap{[0]=Oop [24]=Oop [48]=Oop [56]=Oop [80]=Oop off=2500}
#6 
OopMap{rbx=Oop rdi=Oop [32]=Oop [40]=Oop [112]=Oop off=2533}
#7 
OopMap{rbx=Oop rdi=Oop r14=Oop [32]=Oop [112]=Oop off=3081}
#8 
OopMap{rbx=Oop rdi=Oop r14=Oop [32]=Oop [40]=Oop [112]=Oop off=3190}
#9 
OopMap{[8]=Oop [32]=Oop [40]=Oop off=4408}
#10 
OopMap{[32]=Oop [40]=Oop [48]=Oop off=4640}
#11 
OopMap{rbp=Oop [16]=Oop [24]=Oop [40]=Oop [64]=Oop off=5232}
#12 
OopMap{rbp=Oop [0]=NarrowOop [32]=Oop off=5364}
#13 
OopMap{[32]=Oop [40]=Oop [48]=Oop off=5408}
#14 
OopMap{rbp=Oop [32]=Oop [40]=Oop [48]=Oop off=5436}
#15 
OopMap{rbp=Oop [32]=Oop [40]=Oop [48]=Oop off=5468}
#16 
OopMap{rbp=Oop [32]=Oop [40]=Oop [48]=Oop off=5524}
#17 
OopMap{rbp=Oop [32]=Oop [40]=Oop [48]=Oop [88]=Oop off=5552}
#18 
OopMap{[32]=Oop [40]=Oop [48]=Oop [64]=Oop [72]=Derived_oop_[64] [112]=Oop off=5608}
#19 
OopMap{[8]=Oop [32]=Oop off=5680}
#20 
OopMap{rbp=Oop off=5720}
#21 
OopMap{rbp=Oop off=5752}
#22 
OopMap{rbp=Oop [24]=NarrowOop [28]=NarrowOop [32]=Oop [40]=Oop [48]=Oop [56]=Oop [64]=Oop [88]=Oop off=5812}
#23 
OopMap{rbp=Oop [16]=Oop [24]=Oop [40]=Oop [64]=Oop [88]=Oop off=5960}
#24 
OopMap{[0]=Oop [24]=Oop [48]=Oop [56]=Oop [72]=Oop [88]=NarrowOop off=6056}
#25 
OopMap{[40]=Oop off=6088}
#26 
OopMap{[0]=Oop off=6120}
#27 
OopMap{[8]=Oop [24]=Oop [56]=Oop [72]=Oop [112]=Oop off=6216}
#28 
OopMap{[0]=Oop [32]=NarrowOop [40]=Oop off=6284}
#29 
OopMap{rbp=Oop [16]=Oop [40]=Oop [64]=Oop [112]=Oop off=6384}
#30 
OopMap{[0]=Oop off=6412}
#31 
OopMap{[0]=Oop [16]=Oop [32]=NarrowOop [40]=Oop [48]=Oop off=6488}
#32 
OopMap{rbp=Oop [16]=Oop [40]=Oop [48]=Oop off=6560}
#33 
OopMap{[32]=Oop [40]=Oop [48]=Oop [64]=Oop [112]=Oop off=6608}
#34 
OopMap{[8]=Oop [28]=NarrowOop [32]=Oop [40]=Oop [48]=Oop off=6768}
#35 
OopMap{rbp=NarrowOop [0]=Oop [16]=Oop [32]=Oop [40]=NarrowOop off=6860}
#36 
OopMap{[0]=Oop [16]=Oop [32]=NarrowOop [40]=Oop [48]=Oop off=6988}
#37 
OopMap{rbp=Oop [32]=Oop off=7024}
#38 
OopMap{rbp=NarrowOop [0]=Oop [24]=Oop [32]=Oop off=7260}
#39 
OopMap{rbp=NarrowOop [0]=Oop [24]=Oop [32]=Oop off=7344}
#40 
OopMap{rbp=Oop [16]=Oop [24]=Oop [40]=Oop [60]=NarrowOop [64]=Oop off=7452}
#41 
OopMap{rbp=NarrowOop [32]=Oop off=7476}
#42 
OopMap{rbp=NarrowOop [0]=Oop off=7524}
#43 
OopMap{[32]=Oop [40]=Oop [48]=Oop off=7588}
#44 
OopMap{[32]=Oop [40]=Oop [48]=Oop off=7616}
#45 
OopMap{[32]=Oop [40]=Oop [48]=Oop off=7632}
#46 
OopMap{rbp=NarrowOop [32]=Oop off=7676}
#47 
OopMap{rbp=NarrowOop [0]=Oop off=7724}
#48 
OopMap{[0]=Oop [16]=Oop [28]=NarrowOop [40]=Oop [48]=Oop [56]=NarrowOop [64]=Oop off=7868}
#49 
OopMap{[8]=Oop [28]=NarrowOop [32]=Oop [40]=Oop [48]=Oop [56]=Oop off=7916}
#50 
OopMap{rbp=Oop [16]=Oop [24]=NarrowOop off=8016}
#51 
OopMap{rbp=Oop [16]=Oop [28]=NarrowOop off=8080}
#52 
OopMap{rbp=NarrowOop [0]=Oop [24]=Oop [32]=Oop off=8152}
#53 
OopMap{rbp=Oop [8]=NarrowOop off=8212}
#54 
OopMap{rbp=NarrowOop [32]=Oop off=8236}
#55 
OopMap{rbp=Oop [16]=NarrowOop off=8272}
#56 
OopMap{rbp=NarrowOop [0]=Oop off=8320}
#57 
OopMap{rbp=Oop [12]=NarrowOop off=8360}
#58 
OopMap{rbp=NarrowOop [32]=Oop off=8400}
#59 
OopMap{rbp=Oop [12]=NarrowOop off=8460}
#60 
OopMap{rbp=NarrowOop [0]=Oop off=8508}
#61 
OopMap{rbp=Oop [24]=NarrowOop [40]=Oop off=8572}
#62 
OopMap{rbp=Oop off=8600}
#63 
OopMap{rbp=Oop [8]=Oop [28]=NarrowOop off=8640}
#64 
OopMap{rbp=Oop [8]=Oop [20]=NarrowOop [112]=Oop off=8704}
#65 
OopMap{rbp=Oop [16]=Oop [24]=Oop [48]=Oop off=8788}
#66 
OopMap{rbp=Oop [16]=Oop [24]=Oop [40]=Oop [64]=Oop off=8912}
#67 
OopMap{rbp=Oop [16]=Oop [24]=Oop [40]=Oop [64]=Oop off=9036}
#68 
OopMap{rbp=Oop [16]=Oop [24]=Oop [40]=Oop [64]=Oop off=9160}
#69 
OopMap{rbp=Oop [16]=Oop [24]=Oop [40]=Oop [64]=Oop off=9284}
#70 
OopMap{rbp=Oop [16]=Oop [24]=Oop [40]=Oop [64]=Oop off=9408}
#71 
OopMap{rbp=Oop [16]=Oop [24]=Oop [40]=Oop [64]=Oop off=9532}
#72 
OopMap{off=9556}
#73 
OopMap{off=9580}
#74 
OopMap{off=9604}
#75 
OopMap{[112]=Oop off=9628}
#76 
OopMap{rbp=Oop [8]=Oop [24]=Oop [32]=NarrowOop off=9696}
#77 
OopMap{rbp=Oop [8]=Oop [24]=NarrowOop off=9760}
#78 
OopMap{off=9784}
#79 
OopMap{off=9812}
#80 
OopMap{off=9836}
#81 
OopMap{off=9860}
#82 
OopMap{off=9884}
#83 
OopMap{off=9908}
#84 
OopMap{off=9932}
#85 
OopMap{off=9956}
#86 
OopMap{off=9980}
#87 
OopMap{off=10004}
#88 
OopMap{off=10028}
#89 
OopMap{rbp=Oop [16]=Oop [28]=NarrowOop off=10092}
#90 
OopMap{rbp=Oop [16]=Oop [24]=Oop [48]=Oop off=10176}
#91 
OopMap{off=10200}
#92 
OopMap{off=10224}
#93 
OopMap{off=10248}
#94 
OopMap{off=10272}
#95 
OopMap{off=10296}
#96 
OopMap{off=10320}
#97 
OopMap{off=10344}
#98 
OopMap{off=10368}
#99 
OopMap{off=10392}
#100 
OopMap{off=10416}
#101 
OopMap{off=10440}
#102 
OopMap{off=10464}
#103 
OopMap{off=10488}
#104 
OopMap{off=10512}
#105 
OopMap{off=10536}
#106 
OopMap{off=10560}
#107 
OopMap{off=10584}
#108 
OopMap{off=10608}
#109 
OopMap{off=10632}
#110 
OopMap{off=10656}
#111 
OopMap{off=10680}
#112 
OopMap{off=11028}
java.lang.NullPointerException
 at javax.swing.text.GlyphView.getBreakSpot(GlyphView.java:799)
 at javax.swing.text.GlyphView.getBreakWeight(GlyphView.java:724)
 at javax.swing.text.html.InlineView.getBreakWeight(InlineView.java:150)
 at javax.swing.text.FlowView$LogicalView.getPreferredSpan(FlowView.java:733)
 at javax.swing.text.FlowView.calculateMinorAxisRequirements(FlowView.java:233)
 at javax.swing.text.ParagraphView.calculateMinorAxisRequirements(ParagraphView.java:717)
 at javax.swing.text.html.ParagraphView.calculateMinorAxisRequirements(ParagraphView.java:157)
 at javax.swing.text.BoxView.checkRequests(BoxView.java:935)
 at javax.swing.text.BoxView.getMinimumSpan(BoxView.java:568)
 at javax.swing.text.html.ParagraphView.getMinimumSpan(ParagraphView.java:270)
 at javax.swing.text.BoxView.calculateMinorAxisRequirements(BoxView.java:903)

Now I am still working with the JDK team for a fix for this one; but I do feel I have discovered a useful set of tools for providing some evidence that the JIT compiler is causing my bad day. And more importantly I have a workaround so I can run my tests until this is resolved.

Thursday, November 6, 2014

Missing stack traces for repeated exceptions (reminder)

A long while ago a optimisation was added to the JVM so that if the same exception is thrown again and again and again a single instance of the Exception is created without the stack trace filled in in order to increase performance. This is an excellent idea unless you are trying to diagnose a problem and you have missed the original error.

If you forgot about this optimisation you send the afternoon looking at the following log output and weeping slightly. (In my defence I have a little one in the house hence the fuzzy brain and lack of blogging action this year)

java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
java.lang.ArrayIndexOutOfBoundsException
...
java.lang.Exception: Uncaught exceptions during test
 at oracle.jdevstudio-testware-tests.level0.testADFcMATS(/.../work/mw9111/jdeveloper/jdev/extensions/oracle.jdevstudio-testware-tests/abbot/common-adf/CreateNewCustomAppAndProjectWithName.xml:25)
 at oracle.jdevstudio-testware-tests.level0.testADFcMATS(/.../work/mw9111/jdeveloper/jdev/extensions/oracle.jdevstudio-testware-tests/abbot/level0/testADFcMATS.xml:94)
 at oracle.abbot.JDevScriptFixture.runTest(JDevScriptFixture.java:555)
 at junit.framework.TestCase.runBare(TestCase.java:134)
 at junit.framework.TestResult$1.protect(TestResult.java:110)
 at junit.framework.TestResult.runProtected(TestResult.java:128)
 at junit.framework.TestResult.run(TestResult.java:113)
 at junit.framework.TestCase.run(TestCase.java:124)
 at junit.framework.TestSuite.runTest(TestSuite.java:243)
 at junit.framework.TestSuite.run(TestSuite.java:238)
 at junit.textui.TestRunner.doRun(TestRunner.java:116)
 at junit.textui.TestRunner.doRun(TestRunner.java:109)
 at oracle.abbot.AbbotRunner.run(AbbotRunner.java:614)
 at oracle.abbot.AbbotAddin$IdeAbbotRunner.run(AbbotAddin.java:634)
 at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.ArrayIndexOutOfBoundsException

[Crickets]

It turns out that you can turn off this optimisation with a simple flag:

java -XX:-OmitStackTraceInFastThrow ....

In my particular case the actual exception causing this trouble was a NPE from the GlyphView code in JDK8. (One that is being caused by a glitch in hotspot it seems) But that in turn was causing the AIOOBE in some logging code clouding the issue even more.

This in particular is a good flag to add by default when running your automated tests, particularly in combination with the stack trace length override I have talked about before.

Tuesday, January 7, 2014

Post-hoc tracing using a debugger

Once nice little features of most debuggers that I have been exercising recently is the ability to log information on a breakpoint. This can be a really useful was to understand code without having to modify it is involve byte code modification.


Let's consider this very trivial and inefficient implementation of a function to return the n'th number in the Fibonacci sequence.


public class Fib {



    public long fib(long number) {
        return number < 1 ? 0 :    // Breakpoint here
            number < 2 ? 1 : fib(number - 2) + fib(number - 1);
    }




    public static void main(String[] args) {

        Fib fib = new Fib();
        System.out.println(fib.fib(10L));

    }

}

Now we add a simple breakpoint, I am going to modify it slightly so that it doesn't halt; but it will log a simple expression which gives us the current value of number

This gives you the following output for our rather inefficient code:

ebugger connected to local process.
Source breakpoint: Fib.java:11, evaluate(number)=10 (long)
Source breakpoint: Fib.java:11, evaluate(number)=8 (long)
Source breakpoint: Fib.java:11, evaluate(number)=6 (long)
Source breakpoint: Fib.java:11, evaluate(number)=4 (long)
Source breakpoint: Fib.java:11, evaluate(number)=2 (long)
Source breakpoint: Fib.java:11, evaluate(number)=0 (long)
Source breakpoint: Fib.java:11, evaluate(number)=1 (long)
Source breakpoint: Fib.java:11, evaluate(number)=3 (long)
Source breakpoint: Fib.java:11, evaluate(number)=1 (long)
Source breakpoint: Fib.java:11, evaluate(number)=2 (long)
... sometime later
Source breakpoint: Fib.java:11, evaluate(number)=1 (long)
Source breakpoint: Fib.java:11, evaluate(number)=2 (long)
Source breakpoint: Fib.java:11, evaluate(number)=0 (long)
Source breakpoint: Fib.java:11, evaluate(number)=1 (long)
55

So what we have done here is to add trace post-hoc, you might not even have access to the source and still be able to get useful information out of what the code is doing.

Now the obvious take away from the above example is that we are computing the same value over and over again. So here is another version of the code which instead uses a Map to store previously computed values in the sequence. Note also it is more of a pain to add trace to this code than in the previous case without making the Lambda less pretty.

import java.util.HashMap;
import java.util.Map;

public class Fib {


    Map<Long, Long> data = new HashMap<>();
    {
        data.put(1L, 1L);
    }


    public long fib(long number) {
        return data.computeIfAbsent(number,
                      n -> n < 1 ? 0 : fib(n - 2) + fib(n - 1)); // Breakpoint here
    }




    public static void main(String[] args) {

        Fib fib = new Fib();
        System.out.println(fib.fib(10L));

    }

}

It is worth noting two things here, first of all your breakpoint log expression should be evaluating the value of the Lambda parameter n and that the second is that you should always put your expression on a new line so that future developer can easily breakpoint it. (Not matter now much smaller/ prettier/ clever it would look if you put the code on one).

So the trace output is now as follows, much better as each value is only computed the once.

Debugger connected to local process.
Source breakpoint: Fib.java:17, evaluate(n)=10
Source breakpoint: Fib.java:17, evaluate(n)=8
Source breakpoint: Fib.java:17, evaluate(n)=6
Source breakpoint: Fib.java:17, evaluate(n)=4
Source breakpoint: Fib.java:17, evaluate(n)=2
Source breakpoint: Fib.java:17, evaluate(n)=0
Source breakpoint: Fib.java:17, evaluate(n)=3
Source breakpoint: Fib.java:17, evaluate(n)=5
Source breakpoint: Fib.java:17, evaluate(n)=7
Source breakpoint: Fib.java:17, evaluate(n)=9
55

The screen grabs in this blog are from Jdeveloper; but similar features are available in Intelij, Netbeans and if you are a bit crafty you can get something similar in Eclipse.

Thursday, December 19, 2013

Lambda'ery WebSocket code (from UKTECH13 presentation)

At UKTECH13 I was asked to post the source code to the WebSocket used in my presentation, primarily because it was using JDK 8 constructs that were unfamiliar to many. One of the very nice things about the changes to the languages and the supporting library changes is the lack of if statements in the code.

I would note that in a real world chat application that it unlikely different rooms would have different resource URIs but for the purposes of the presentation this made sense.

package websocket;

import static java.util.Collections.emptySet;
import java.util.Set;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentMap;
import java.util.concurrent.CopyOnWriteArraySet;

import javax.websocket.OnClose;
import javax.websocket.OnError;
import javax.websocket.OnMessage;
import javax.websocket.OnOpen;
import javax.websocket.Session;
import javax.websocket.server.PathParam;
import javax.websocket.server.ServerEndpoint;

@ServerEndpoint(value = "/chat/{room}")
public class ChatService {

  private static final Set<Session> EMPTY_ROOM = emptySet();

  static final ConcurrentMap<String, Set<Session>> rooms =
    new ConcurrentHashMap<>(); 


  @OnOpen
  public void onOpen(Session peer, @PathParam("room") String room) {
    rooms.computeIfAbsent(room,
                          s -> new CopyOnWriteArraySet<Session>()).add(peer);
  }

  @OnClose
  public void onClose(Session peer, @PathParam("room") String room) {

    rooms.getOrDefault(room, EMPTY_ROOM).remove(peer);
    
  }

  @OnError
  public void onError(Session peer, Throwable th,
                      @PathParam("room") String room) {
    System.out.println("Peer error " + room + " " + th);
  }


  @OnMessage
  public void message(String message, Session peer,
                      @PathParam("room") String room) {

    // Send a message to all peers in a room who are not the current
    // peer and are still open. Send the message asynchronously to ensure
    // that the first client is not hung up. 

    rooms.getOrDefault(room, EMPTY_ROOM).parallelStream()
         .filter(s -> s != peer && s.isOpen())
         .forEach(s -> s.getAsyncRemote().sendObject(message));
  };

}

One of the problem with the above design is that there is no error logging when an invalid room is used. This could be useful to diagnose errors. Not wanting to use any conditional statements you could use an Optional object:

import java.util.Optional;


  @OnClose
  public void onClose(Session peer, @PathParam("room") String room) {

    Optional.ofNullable(rooms.get(room))
      .orElseThrow(() -> new IllegalStateException("Cannot find room " + room))
      .remove(peer);
    
  }


Of course you might want this on your method objects, so you can use default methods to create a mixin for this on all your Map objects with a trivial subclass.

import java.util.Optional;


  public interface OptionalMap<K,V> extends ConcurrentMap<K,V> {
     public default Optional<V> find(K key) {
        return Optional.ofNullable(get(key));
     }
  }

  public static class OptionalHashMap<K,V> extends ConcurrentHashMap<K,V>
   implements OptionalMap<K,V> {
       
  }
    

  static final OptionalMap<String, Set<Session>> rooms =
    new OptionalHashMap<>(); 


  @OnClose
  public void onClose(Session peer, @PathParam("room") String room) {

    rooms.find(room)
      .orElseThrow(() -> new IllegalStateException("Cannot find room " + room))
      .remove(peer);
    
  }





Whilst working on my presentation it became apparent that it was also possible to use the "openSessions" and "getUserProperties" method to store discrimination data against the Session. I don't have enough experience yet to say which is the better design for a particular case.

package websocket;


import javax.websocket.OnClose;
import javax.websocket.OnError;
import javax.websocket.OnMessage;
import javax.websocket.OnOpen;
import javax.websocket.Session;
import javax.websocket.server.PathParam;
import javax.websocket.server.ServerEndpoint;

@ServerEndpoint(value = "/chat/{room}")
public class ChatService {

  private static final String ROOM_PROPERTY = "ROOM";


  @OnOpen
  public void onOpen(Session peer, @PathParam("room") String room) {
    peer.getUserProperties().put(ROOM_PROPERTY, room);
  }

  @OnClose
  public void onClose(Session peer, @PathParam("room") String room) {
    
    // No need to tidy up and data is store against peer
  }

  @OnError
  public void onError(Session peer, Throwable th,
                      @PathParam("room") String room) {
    System.out.println("Peer error " + room + " " + th);
  }


  @OnMessage
  public void message(String message, Session peer,
                      @PathParam("room") String room) {

    peer.getOpenSessions().parallelStream()
         .filter(s -> room.equals(s.getUserProperties().get(ROOM_PROPERTY)))
         .filter(s -> s != peer && s.isOpen())
         .forEach(s -> s.getAsyncRemote().sendObject(message));
  };

}

Wednesday, October 2, 2013

Write an auto-debugger to catch Exceptions during test execution

Previously I have stated that there are some exceptions you would always want to keep an debugger breakpoint on for. This help prevents code rotting away without you noticing - sometimes masking a different problem.

If you take this seriously then it is a good idea to extend this idea to you automated testing; but coming up with a comprehensive solution is not entirely trivial. You could just start with a try/catch but that won't capture exceptions on other threads. You could also do something using AOP; but depending on the framework you are not guaranteed to catch everything also it does mean you are testing with slightly different code which will worry some.

A few days ago I came across this blog entry on how to write your own debugger, and I wondered if it was possible for java process to debug itself. Turn out you can and here is the code I came up with as part of this little thought experiment.

The first part of the class just contains something fairly hacky code to guess what the port that would be required to connect back to the same VM based on the start up parameters. It might be possible to use the Attach mechanism to start the debugger; but I didn't seen an obvious way to get it to work. Then there are just a couple of factory methods that take a list of exceptions to look out for.

package com.kingsfleet.debug;

import com.sun.jdi.Bootstrap;
import com.sun.jdi.ReferenceType;
import com.sun.jdi.VirtualMachine;
import com.sun.jdi.connect.AttachingConnector;
import com.sun.jdi.connect.Connector;
import com.sun.jdi.connect.IllegalConnectorArgumentsException;
import com.sun.jdi.event.ClassPrepareEvent;
import com.sun.jdi.event.Event;
import com.sun.jdi.event.EventQueue;
import com.sun.jdi.event.EventSet;
import com.sun.jdi.event.ExceptionEvent;
import com.sun.jdi.event.VMDeathEvent;
import com.sun.jdi.event.VMDisconnectEvent;
import com.sun.jdi.request.ClassPrepareRequest;
import com.sun.jdi.request.EventRequest;
import com.sun.jdi.request.ExceptionRequest;

import java.io.IOException;

import java.lang.management.ManagementFactory;
import java.lang.management.RuntimeMXBean;

import java.util.Collections;
import java.util.HashSet;
import java.util.List;
import java.util.Map;
import java.util.Set;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;


public class ExceptionDebugger implements AutoCloseable {




   public static int getDebuggerPort() {
       // Try to work out what port we need to connect to

       RuntimeMXBean runtime = ManagementFactory.getRuntimeMXBean();
       List<String> inputArguments = runtime.getInputArguments();
       int port = -1;
       boolean isjdwp = false;

       for (String next : inputArguments) {
           if (next.startsWith("-agentlib:jdwp=")) {
               isjdwp = true;
               String parameterString = next.substring("-agentlib:jdwp=".length());
               String[] parameters = parameterString.split(",");
               for (String parameter : parameters) {
                   if (parameter.startsWith("address")) {
                       int portDelimeter = parameter.lastIndexOf(":");
                       if (portDelimeter != -1) {
                           port = Integer.parseInt(parameter.substring(portDelimeter + 1));
                       } else {
                           port = Integer.parseInt(parameter.split("=")[1]);
                       }
                   }
               }
           }
       }
       return port;
   }


   public static ExceptionDebugger connect(final String... exceptions) throws InterruptedException {
       return connect(getDebuggerPort(),exceptions);
   }

   public static ExceptionDebugger connect(final int port, final String... exceptions) throws InterruptedException {

       ExceptionDebugger ed = new ExceptionDebugger(port, exceptions);

       return ed;
   }


The constructor create a simple daemon thread that starts the connection back to the VM. It is very important to do this is a separate thread otherwise obviously the VM will grind to a halt when we hit a breakpoint. It is a good idea to make sure that code in that thread doesn't throw one of the exceptions - for the moment I am just hoping for the best.

Finally the code just maintains a list of the banned exceptions, if you had a bit more time it should be possible to store the stack trace where the exception occurred.

// 
   // Instance variables

   private final CountDownLatch startupLatch = new CountDownLatch(1);
   private final CountDownLatch shutdownLatch = new CountDownLatch(1);

   private final Set<String> set = Collections.synchronizedSet(new HashSet<String>());
   private final int port;
   private final String exceptions[];
   private Thread debugger;
   private volatile boolean shutdown = false;


   //
   // Object construction and methods
   //




   private ExceptionDebugger(final int port, final String... exceptions) throws InterruptedException {

       this.port = port;
       this.exceptions = exceptions;

       debugger = new Thread(new Runnable() {

           @Override
           public void run() {
               try {
                   connect();
               } catch (Exception ex) {
                   ex.printStackTrace();
               }
           }
       }, "Self debugging");
       debugger.setDaemon(true); // Don't hold the VM open
       debugger.start();

       // Make sure the debugger has connected
       if (!startupLatch.await(1, TimeUnit.MINUTES)) {
           throw new IllegalStateException("Didn't connect before timeout");
       }
   }


   @Override
   public void close() throws InterruptedException {
       shutdown = true;
       // Somewhere in JDI the interrupt was being eaten, hence the volatile flag 
       debugger.interrupt();
       shutdownLatch.await();
   }


   /**
    * @return A list of exceptions that were thrown
    */
   public Set<String> getExceptionsViolated() {
       return new HashSet<String>(set);
   }

   /**
    * Clear the list of exceptions violated
    */
   public void clearExceptionsViolated() {
       set.clear();
   }


The main connect method is a fair simple block of code that ensures the connection and configures any initial breakpoints.

//
   // Implementation details
   //


   private void connect() throws java.io.IOException {


       try {
           // Create a virtual machine connection
           VirtualMachine attach = connectToVM();


           try
           {

               // Add prepare and any already loaded exception breakpoints
               createInitialBreakpoints(attach);

               // We can now allow the rest of the work to go on as we have created the breakpoints
               // we required

               startupLatch.countDown();

               // Process the events
               processEvents(attach);
           }
           finally {

               // Disconnect the debugger
               attach.dispose();

               // Give the debugger time to really disconnect
               // before we might reconnect, couldn't find another
               // way to do this

               try {
                   TimeUnit.SECONDS.sleep(1);
               } catch (InterruptedException e) {
                   Thread.currentThread().interrupt();
               }
           }
       } finally {
           // Notify watchers that we have shutdown
           shutdownLatch.countDown();
       }
   }



Connecting back to self is just a process of finding the right attaching connector, in this case Socket although I guess you could use the shared memory transport on some platforms if you modified the code slightly.

private VirtualMachine connectToVM() throws java.io.IOException {

       List<AttachingConnector> attachingConnectors = Bootstrap.virtualMachineManager().attachingConnectors();
       AttachingConnector ac = null;

       found:
       for (AttachingConnector next : attachingConnectors) {
           if (next.name().contains("SocketAttach")) {
               ac = next;
               break;

           }
       }

       Map<String, Connector.Argument> arguments = ac.defaultArguments();
       arguments.get("hostname").setValue("localhost");
       arguments.get("port").setValue(Integer.toString(port));
       arguments.get("timeout").setValue("4000");

       try {
           return ac.attach(arguments);
       } catch (IllegalConnectorArgumentsException e) {
           throw new IOException("Problem connecting to debugger",e);
       }
   }


When you connect the debugger you have no idea as to whether the exceptions you are interested in have been loaded, so you need to register breakpoints for both the point where the classes are prepared and for those that have already been loaded.

Note that the breakpoint is set with a policy only to break the one thread - otherwise for obvious reasons the current VM will grind to a halt if the debugger thread is also put to sleep.

private void createInitialBreakpoints(VirtualMachine attach) {
       // Our first exception is for class loading

       for (String exception : exceptions) {
           ClassPrepareRequest cpr = attach.eventRequestManager().createClassPrepareRequest();
           cpr.addClassFilter(exception);
           cpr.setSuspendPolicy(EventRequest.SUSPEND_EVENT_THREAD);
           cpr.setEnabled(true);
       }

       // Then we can check each in turn to see if it have already been loaded as we might
       // be late to the game, remember classes can be loaded more than once
       //

       for (String exception : exceptions) {
           List<ReferenceType> types = attach.classesByName(exception);
           for (ReferenceType type : types) {
               createExceptionRequest(attach, type);
           }
       }
   }


   private static void createExceptionRequest(VirtualMachine attach, 
                                              ReferenceType refType) {
       ExceptionRequest er = attach.eventRequestManager().createExceptionRequest(
           refType, true, true);
       er.setSuspendPolicy(EventRequest.SUSPEND_EVENT_THREAD);
       er.setEnabled(true);
   }



The event processing loop polls for EventSet instances which contain one or more Event instances. Not all of these events are down to a breakpoint request though so you have to take care to not always call resume on the event set. This is because you might have two event sets in a row, with the code calling resume before you even get to read the second one. This results in missed breakpoints as the code caught up.

For some reason JDI appeared to be eating the interrupted flag, hence the boolean property to stop the loop with the close method from before.

private void processEvents(VirtualMachine attach) {
       // Listen for events

       EventQueue eq = attach.eventQueue();
       eventLoop: while (!Thread.interrupted() && !shutdown) {

           // Poll for event sets, with a short timeout so that we can
           // be interrupted if required
           EventSet eventSet = null;
           try 
           {
               eventSet = eq.remove(500);
           }
           catch (InterruptedException ex) {
               Thread.currentThread().interrupt();
               continue eventLoop;  
           }

           // Just loop again if we have no events
           if (eventSet == null) {
               continue eventLoop;
           }

           //

           boolean resume = false;
           for (Event event : eventSet) {

               EventRequest request = event.request();
               if (request != null) {
                   int eventPolicy = request.suspendPolicy();
                   resume |= eventPolicy != EventRequest.SUSPEND_NONE;
               }

               if (event instanceof VMDeathEvent || event instanceof VMDisconnectEvent) {
                   // This should never happen as the VM will exit before this is called

               } else if (event instanceof ClassPrepareEvent) {

                   // When an instance of the exception class is loaded attach an exception breakpoint
                   ClassPrepareEvent cpe = (ClassPrepareEvent) event;
                   ReferenceType refType = cpe.referenceType();
                   createExceptionRequest(attach, refType);

               } else if (event instanceof ExceptionEvent) {

                   String name = ((ExceptionRequest)event.request()).exception().name();
                   set.add(name);
               }
           }

           // Dangerous to call resume always because not all event suspend the VM
           // and events happen asynchornously.
           if (resume)
               eventSet.resume();
       }
   }

}

So all that remains is a simple test example, since this is JDK 7 and the ExceptionDebugger is AutoCloseable we can do this using the try-with-resources construct as follows. Obviously if doing automated test use the testing framework fixtures of your choice.

public class Target {

   public static void main(String[] args) throws InterruptedException {


       try (ExceptionDebugger ex = ExceptionDebugger.connect(
               NoClassDefFoundError.class.getName())) {

           doSomeWorkThatQuietlyThrowsAnException();

           System.out.println(ex.getExceptionsViolated());
       }


       System.exit(0);
   }


   private static void doSomeWorkThatQuietlyThrowsAnException() {
       // Check to see that break point gets fired

       try {
           Thread t = new Thread(new Runnable() {
                           public void run() {
                               try
                               {
                                   throw new NoClassDefFoundError();
                               }
                               catch (Throwable ex) {

                               }
                           }
                      });
           t.start();
           t.join();
       } catch (Throwable th) {
           // Eat this and don't tell anybody
       }
   }
}


So if you run this class with the following VM parameter, note the suspend=n otherwise the code won't start running, you will find that it can connect back to itself and start running.

-agentlib:jdwp=transport=dt_socket,address=localhost:5656,server=y,suspend=n

This gives you the following output, note the extra debug line from the VM:

Listening for transport dt_socket at address: 5656
[java.lang.NoClassDefFoundError]
Listening for transport dt_socket at address: 5656

As every I would be interested to read if this was something that is useful for people and to help remove any obvious mistakes.

Friday, August 9, 2013

Almost named method arguments in JDK 8

Sometimes it would be really nice to have named method parameter in Java, this doesn't look likely for a long while but there is always another little work around, for example using a builder pattern to get similar behaviour, that will bridge the gap for a little bit. It occurred to me that using the Lambda support in JDK 8 you could get something very close without the boiler plate required by some of the other methods.

So consider this simple Facade class, that presents a method with a variable list of parameters. Note the variant of the method that takes in a Consumer object - this is what we are going to invoke with a Lambda later on.

package client;

import java.util.function.Consumer;

public class Facade {
    
    public static void invoke(Consumer<Parameter> op) {
        
        Parameter p = new Parameter();
        op.accept(new Parameter());
        invoke(p);        
    }
    
    public static void invoke(Parameter p) {

        // Defensive copy and validate
        p = p.clone();
        p.validate();
        
        // ...
    }

    
    public static class Parameter implements Cloneable {
        public String value1, value2, value3;
        
        public Parameter validate() {
            // ...
            
            return this;
        }

        public Parameter clone() {
            // We can use vanilla clone here, for more complicated mutable objects
            // you might need to perform a deeper copy
            try {
                return (Parameter) super.clone();
            } catch (CloneNotSupportedException e) {
                throw new RuntimeException(e);
            }
        }
    }
    
}

So once you have this in place, you can use Lambda notation to call the invoke method with how every many parameters as you might think suitable:

...
{

    public static void main(String[] args) {
        
        // Single parameter version
        Facade.invoke(p ->  p.value1="x" );
        // Multiple parameter version
        Facade.invoke(p -> { p.value1="x"; p.value2="y";});
    }
}

Of course the eagle eyed of your will recognise that the same pattern, minus the Consumer method of course, with an earlier JDK. Given the number of java developers out there some-one probably will have probably already invented this pattern; but you never know and if you don't write it down the thought it didn't happen.

...
{

    public static void main(String[] args) {
        
        // Using an anonymous inner class pre JDK 8
        Facade.invoke(new Parameter() {{
            value1 = "x";
            value2 = "y";
        }});
    }
}

Thursday, June 6, 2013

Problems running lots of X11 sessions concurrently when testing under Hudson/Jenkins

So we are running a quite a bit of automated UI testing and we have found over a large number of concurrent test nodes that even when the Xvnc plugin has correctly started that the environment is not always ready or reliable. This blog post looks at two changes we made that have improved our test stability in recent times.

The first and most important thing to settle when using the Xvnc plugin is to make sure that the user that is running the tests has a normal window manager. By default the default VNC server will start using "twm" as defined in the .vnc/xstartup file. This has significant behavioural differences from the more standard Gnome / KDE and indeed the window managers on Windows and a Mac. Rather than deal with this we have standardised on running with Gnome.

The problem is though is that in our experience if you have multiple gnome sessions starting at the same time that sometimes they will fail with odd error messages. My esteemed colleague Mark Warner came up with the following xstartup script which just puts a simple lock around the startup code.

#!/bin/bash
# It uses a lockfile in the user's .vnc directory to ensure that
# only one instance of gnome will start up for the given user
# at once. This should work around problems associated with
# multiple gnome instances starting and failing to lock certain
# files. It will start gnome after 5 mins of failing to lock as
# a fail safe so a gnome startup will always be attempted.
#

LOCK_FILE=${HOME}/.vnc/xstartup.lock
SESSION_VNC_NAME=VNC-`hostname -f`
LOCKED=0

function clean_up {
  # don't delete the lock file if we didn't create it
  if [ $LOCKED -eq 1 ]; then
    echo "$(date) All finished, deleting lock file."
    rm -f $LOCK_FILE
  fi
}

# make sure that we delete the lock file if we get killed
trap clean_up SIGHUP SIGINT SIGTERM

# retry for 5 mins then assume something died and delete
# the existing lockfile taking control of it for ourselves.
echo "$(date) Attempting to obtain startup lock."
if lockfile -l 300 $LOCK_FILE; then
  echo "$(date) Startup lock aquired."
  LOCKED=1
else
  echo "$(date) Lock failed... starting anyway."
fi

# give X a little breather before we start gnome
sleep 10 

# Start Gnome
gnome-session &

# just let gnome settle before we relinquish the lock
sleep 20
clean_up

Now this resolved spurious test failures that were due to a missing window manager, but as recently the number of nodes increased we found that we were still seeing troubling intermittent failures that took the form of failures to connect to the window server for no obvious reason.

This would happen even if previously in the job we had displayed a window successfully.

[exec] java.lang.InternalError: Can't connect to X11 window server using ':58' as the value of the DISPLAY variable.
     [exec]  at sun.awt.X11GraphicsEnvironment.initDisplay(Native Method)
     [exec]  at sun.awt.X11GraphicsEnvironment.access$200(X11GraphicsEnvironment.java:65)
     [exec]  at sun.awt.X11GraphicsEnvironment$1.run(X11GraphicsEnvironment.java:110)
     [exec]  at java.security.AccessController.doPrivileged(Native Method)
     [exec]  at sun.awt.X11GraphicsEnvironment.(X11GraphicsEnvironment.java:74)
     [exec]  at java.lang.Class.forName0(Native Method)
     [exec]  at java.lang.Class.forName(Class.java:186)
     [exec]  at java.awt.GraphicsEnvironment.createGE(GraphicsEnvironment.java:102)
     [exec]  at java.awt.GraphicsEnvironment.getLocalGraphicsEnvironment(GraphicsEnvironment.java:81)
     [exec]  at org.netbeans.core.startup.Main.start(Main.java:253)
     [exec]  at org.netbeans.core.startup.TopThreadGroup.run(TopThreadGroup.java:123)
     [exec]  at java.lang.Thread.run(Thread.java:722)
     [exec] Result: 2

This would also happen right at the start when gnome was being set up, as shown here by looking at the content of the logs under .vnc .

_XSERVTransmkdir: Owner of /tmp/.X11-unix should be set to root

Xvnc Free Edition 4.1.2
Copyright (C) 2002-2005 RealVNC Ltd.
See http://www.realvnc.com for information on VNC.
Underlying X server release 70101000, The X.Org Foundation


Thu May 30 03:51:34 2013
 vncext:      VNC extension running!
 vncext:      Listening for VNC connections on port 5974
 vncext:      Listening for HTTP connections on port 5874
 vncext:      created VNC server for screen 0
Thu May 30 03:51:37 BST 2013 Attempting to obtain startup lock.
Thu May 30 03:53:45 BST 2013 Startup lock aquired.
Start gnome for OL4 or OL5
AUDIT: Thu May 30 03:53:56 2013: 10280 Xvnc: client 1 rejected from local host
Xlib: connection to ":74.0" refused by server
Xlib: No protocol specified


(gnome-session:10543): Gtk-WARNING **: cannot open display:  
Thu May 30 03:54:15 BST 2013 All finished, deleting lock file.
AUDIT: Thu May 30 04:14:03 2013: 10280 Xvnc: client 1 rejected from local host
AUDIT: Thu May 30 04:14:22 2013: 10280 Xvnc: client 1 rejected from local host
FreeFontPath: FPE "unix/:7100" refcount is 2, should be 1; fixing.

After a little bit of playing around suspicion fell to the .Xauthority file we we knew could cause error messages like this and could become corrupted. Removing /zeroing the file didn't help so like the Gnome problems some kind of concurrency / contention issues was suspected.

After a bit of playing about we decided that for our test user it was going to be best to just have a copy of this file per host. This works for us as we only have the single executor per machine in order to get consistent testing results. In our case we just added the following line in our .bashrc for the NIS user we run our tests as and restarted all our of slave nodes.

# make sure we don't share the Xauthority file between hosts

export XAUTHORITY=~/.Xauthority.`hostname -f`

Since we have made this change we have seen no failures of the above type after nearly week, that of course doesn't rule out that we have just reduced the occurrence of the issue to a reasonably small level; but we are happy that we can run tests again. Of course the moment I post this blog I am going to loose that lovely run of blue balls. :-)



Thursday, May 23, 2013

Persistent breakpoints every java developer should have

When a developer is working in Java there are a few failure cases you always want to know about even if you were trying to debug something else. Here is a list of the persistent breakpoints that should be enabled in every IDE. (IMHO of course)

Yes in theory you should be able to just get this from a good logging implementation; but often these problems are deep down in somebody else's library caused by changes that are beyond your control..... or just hidden in a large number of currently executing threads.

Java these days doesn't have that much of an overhead to be running in debug mode, generally I never run anything I am working on without a debugger attached as HotSwap is such a productivity boost.

I would be interested to heard of other people's must have breakpoints. They should be failures that should never come up in the normal running of your application that you would want to know about right away.

Deadlock detection


The VM is getting better and better at recognising deadlocks from low level java contracts, you debugger should have an option to break on deadlock. You should make sure it is turned on by default.

On java.lang.ExceptionInInitializer


This one can be a right pain to track down because further down the line it can become a ClassNotFoundException and often if it is more than a few levels down there is no obvious reason why the indirectly referencing class has failed to load.

Often caused by people initialising public/final/static variables with methods/constructors that throw RuntimeExceptions. If you are not sure use a static{} block with proper error handling, never do something in there that depends on something external to the current jar file.

On java.lang.NoClassDefFoundError


Always a popular when working in OSGi, normally you have forgotten a dependant jar file and you see this type of failure. Interestingly you sometimes only get a cause for the first time this exception is thrown for a particular class. So if you have a breakpoint then you can more quickly track this down.

I have found that sometimes that the breakpoint is not hit when behind some reflective code. In that case I often have breakpoints in the constructor of this class just to make sure.

On java.lang.NoSuchMethodError


You will of course generally see this if you haven't built locally properly or you are using miss-matched versions of libraries. You always want to know about this as soon as it happens.

On java.lang.LinkageError


This normally only turns up when things really go bad, for example when you have two versions of the same class hanging about even though they are from the same jar file. (Gotta love multiple class loaders) Be thankful these don't turn up very often, normally timed for a day when I have a really bad headache already.

On java.lang.OutOfMemoryError / java.lang.StackOverflowException


If you are very lucky the VM will breakpoint for these; but unfortunately as a lot of time this will happen in native code you will just have to deal with the fallout.

Getting the full stack for the latter is a bit of a pain; but not impossible. See this older post on getting the full stack trace.

On java.lang.AssertionError


A surprising number of people use assertions and then get upset when you complain about there exceptions when debugging or running tests. (You are doing this with -ea aren't you?)

The downside is that you want to turn this off when debugging certain testing frameworks, I am looking at you JUnit, as it is not entirely helpful to hit a breakpoint when you just want to run all of your tests.

Finally every now and again I will run across the following code, which causes an exception just to test if assertions are enabled.

boolean assertionsEnabled = false;
    try
    { assert false; }
    catch (AssertionException ae)
    { assertionsEnabled = true }

Update: It has been pointed out by a helpful colleague at that I should have provided some alternative suggestions as to what this code should be replaced with. The first option would be to call Class.desiredAssertionStatus but if you want to be totally sure you can use the following code that uses assignment to capture the assertion status without throwing an exception.

boolean assertionsEnabled = false;

    assert isAssertionsEnabled = true;

Thursday, April 25, 2013

Building a simple java client for forecast.io

I like to be outdoors when life allows so weather is always an interest for me. So i was very pleases to see forecast.io becoming available with global coverage after being jealous of the US only "DarkSkys" app. It was also nice to see that there is a nice REST api for the service which I could play with.

Unfortunately there was only a textual description of service, nothing I could consume with the Java client tools I have been working with. But I though it would be an interesting experiment to try to document an existing service from scratch.

The first thing I did was to get an example of the data that the service would respond with and run it through a JSON->JSON Schema tool. I used JSONSchema.net which gave me a rough v3 JSON Schema; but it wasn't able to take into account elements that are reused. A little bit of hand editing later I ended up with three JSON Schema files, one for the forecast itself and one for a list of weather details and and one for each particular data point.

From there is was pretty simple to read the developer documentation and write up a simple WADL to describe the two resources provided by the service. Luckily Jason LaPort from the DarkSkys was on hand to fix a few mistake and generally verify my description.

Once I had this all in place I of course found a couple of bugs in my own code, so it was time to update and fix wadl.java.net and release a 1.1.5 version with a revised depdency on the jsonschema2pojo project. This is why a little bit of adhoc expert testing pay dividends.

So taking the WADL from github it is possible to generate a nice clean Java API using the wadl.java.net generator. I won't reproduce the steps to generate the client here, but this is the end result and the kind of code you can get out of it.

// Create a Jersey client and setup for POJO JSON mapping

    ClientConfig cc = new DefaultClientConfig();
    cc.getFeatures().put(JSONConfiguration.FEATURE_POJO_MAPPING, true);
    Client c = Client.create(cc);


    // Get current weather for location and check for any alerts 
    
    Forecast f = ApiForecastIo_Forecast
        .apikey(c, "xxxxxxx")                  // Get own key from developer.forecast.io
        .latitudeLongitude(51.32d, -1.244d)    // Some location near where I live
           .getAsForecast(
              null,                            // Not JSONP
              Units.SI,                        // Return values in SI units
              "hourly,minutely,daily,flags");  // Just return current weather and any alerts
    
    // Output a summary

    System.out.println(
        f.getCurrently().getSummary() + " " +
        f.getCurrently().getTemperature() + " C");

    // Output any alerts
  
    List<Alert> alerts = f.getAlerts();
    for (Alert altert : alerts) {
        System.out.println(
            altert.getTitle() + " " + altert.getUri());
    }

The nice thing here was just how pleasantly easy describing a service that already exists was, yes I could have written it by hand in Java; but then when I wanted to move to Jersey 2.x I would have to re-write by hand rather that just regenerating from the metadata to a new technology target. (Also did the same for a BBC REST Schedule API, that is in the same git project)

Friday, February 22, 2013

Using UriTemplate to change path parameters in a URI

I have been recently working on a client generator in the wadl.java.net project and I was solving a bug where I wanted to change path parameter on a URI. This turned out to be quite easy with existing classes that are part of the Jersey project.

First of all you need a instance of UriTemplate, depending on the very of Jersey this is in a slightly different package - you IDE's automatic import will do the work for you.

  String template = "http://example.com/name/{name}/age/{age}";
  UriTemplate uriTemplate = new UriTemplate(template);


Then you use match(...) to extract them:

  String uri = "http://example.com/name/Bob/age/47";
  Map<String, String> parameters = new HashMap<>();

  // Not this method returns false if the URI doesn't match, ignored
  // for the purposes of the this blog.
  uriTemplate.match(uri, parameters);

Then you can replace the parameters at will and rebuild the URI:

  parameters.put("name","Arnold");

  UriBuilder builder = UriBuilder.fromPath(template);
  URI output = builder.build(parameters);

Thursday, October 11, 2012

Using Hudson/Jenkins to diagnose that intermittent failure


I have been working on one of those intermittent bugs that just won't reproduce on my machine; but will reproduce intermittently on other machines while they are running automated testing. I filled the code with trace statements, now I suspect the problem is in code that I don't control and doesn't appear to have much in the way of diagnostics in the place I am working on.

So I did the obvious thing which is to run the tests on a loop on my machine overnight, 12 hours later and 8 test iterations later, no test failures and I am no further forward.

Since the tests are failing in the Hudson farm, it make sense to try to connect the debugger up to those jobs; but I don't want to hang around to attach the remove debugger to each. Thankfully there is a workaround that will allow me to set suitable breakpoints and manage the debugger connection for me.

First of all you need to configure you IDE to accept incoming debugger connections, here are some notes on configuring JDeveloper for a listening debugger, in Netbeans you need to use the Debug->Attach menu item and select "SocketListen" as the connector and configure as per JDeveloper. In Eclipse you need to configure the debug type as "Socket Listen".

The second step is modifying your build system so that there is a target you can call that will start the test cases in debug mode. This is an example of the parameters for one of our CI jobs that passes in the right information. Note of course the blacked out text the the name of then machine you are trying to connect back to. (The java tests are started with the parameter -agentlib:jdwp=transport=dt_socket,address=xxxx.oracle.com:5000,server=n) Make sure that you don't have any firewalls running on that machine that will block the in-coming connections.




You probably will want to run to run multiple jobs at the same time if you have the nodes available, so consider checking this concurrent build box. Always a good idea to bring cakes / cookies into the office if you are going to tie up all the preflight nodes for the day.




And then all that remains is to run a bunch of jobs and wait for your breakpoint to be hit, might take a little while; but it is going be quicker than running these jobs in series on your own machine. And if your farm is Heterogeneous so much the better for reproducing intermittent failures.



You can sit back and then wait for your code to fail..... may I suggest some sessions from JavaOne while you wait?

Wednesday, September 5, 2012

Changing delay, and hence the order, in a DelayQueue

So I was looking at building a simple object cache that expires the objects after a given time. The obvious mechanism for this is the use the DelayedQueue class from the concurrency package in Java; but I wanted to know if it way possible to update the delay after an object has been added to the queue. Looking at the Delayed interface there didn't seem to be a good reason not to in the docs so I thought it was time to experiment.

So first of all you need to to create an instance of Delayed, this is a very simple implementation that with the switch of a flag you can basically invert the timeout order in the list. (And add a suitable offset so things happen in the right order)

static int COUNT=100;


   class DelayedSwap implements Delayed, Comparable<Delayed> {

       int index = 0;
       volatile boolean swap = false;
       long starttime;

       public DelayedSwap(int index, long starttime) {
           super();
           this.index = index;
           this.starttime = starttime;
       }

       private long getDelay() {
           return (swap ? starttime + (2*COUNT - index) * 100 :
               starttime + index * 100) - System.currentTimeMillis();
       }


       public String toString()
       {
           return index + " swapped " + swap + " delay " + getDelay();
       }

       @Override
       public long getDelay(TimeUnit unit) {
           return unit.convert(getDelay(), TimeUnit.MILLISECONDS);
       }

       @Override
       public int compareTo(Delayed delayed) {
           if (delayed == this)
               return 0;

           return (int)(getDelay(TimeUnit.MILLISECONDS) - delayed.getDelay(TimeUnit.MILLISECONDS));
       }
   }


So to test this I created a method that would create a bunch of the DelayedSwap objects and half way through processing the list switch the flag so altering the order of expiration.

public static void main(String[] args) throws InterruptedException {

       long start = System.currentTimeMillis();
       final List delayed = new ArrayList();
       for (int i = 1; i < COUNT; i++) {
           delayed.add(new DelayedSwap(i, start));
       }

       final DelayQueue dq = new DelayQueue();
       dq.addAll(delayed);

       new Thread(new Runnable() {

           @Override
           public void run() {
               try {
                   TimeUnit.SECONDS.sleep(5);
               } catch (InterruptedException e) {
               }
               for (DelayedSwap d : delayed) {
                   d.swap = true;
               }
           }
       }).start();

       while (!dq.isEmpty()) {
           System.out.println(dq.take());
       }

   }

So what I was expecting was the elements 1-50 ish written out in the correct order but instead after the swap over the elements are coming out in an arbitrary order quite far away from the request delay time.

1 swapped false delay -19
2 swapped false delay -4
3 swapped false delay -4
4 swapped false delay -4
5 swapped false delay -4
6 swapped false delay -4
7 swapped false delay -4
8 swapped false delay -4
9 swapped false delay -4
10 swapped false delay -4
11 swapped false delay -4
12 swapped false delay -4
13 swapped false delay -4
14 swapped false delay -4
15 swapped false delay -4
16 swapped false delay -4
17 swapped false delay -4
18 swapped false delay -4
19 swapped false delay -4
20 swapped false delay -4
21 swapped false delay -4
22 swapped false delay -4
23 swapped false delay -4
24 swapped false delay -4
25 swapped false delay -4
26 swapped false delay -4
27 swapped false delay -4
28 swapped false delay -4
29 swapped false delay -4
30 swapped false delay -4
31 swapped false delay -4
32 swapped false delay -4
33 swapped false delay -4
34 swapped false delay -4
35 swapped false delay -4
36 swapped false delay -4
37 swapped false delay -4
38 swapped false delay -4
39 swapped false delay -5
40 swapped false delay -4
41 swapped false delay -4
42 swapped false delay -5
43 swapped false delay -4
44 swapped false delay -5
45 swapped false delay -5
46 swapped false delay -5
47 swapped false delay -5
48 swapped false delay -5
49 swapped false delay -5
50 swapped false delay -5
51 swapped true delay -6
94 swapped true delay -4306
96 swapped true delay -4506
87 swapped true delay -3606
91 swapped true delay -4006
97 swapped true delay -4606
95 swapped true delay -4406
98 swapped true delay -4706
92 swapped true delay -4106
82 swapped true delay -3106
80 swapped true delay -2906
90 swapped true delay -3906
93 swapped true delay -4206
74 swapped true delay -2306
99 swapped true delay -4806
70 swapped true delay -1906
69 swapped true delay -1806
66 swapped true delay -1506
83 swapped true delay -3206
62 swapped true delay -1107
61 swapped true delay -1007
58 swapped true delay -707
71 swapped true delay -2007
89 swapped true delay -3807
85 swapped true delay -3407
78 swapped true delay -2707
86 swapped true delay -3507
81 swapped true delay -3007
88 swapped true delay -3707
84 swapped true delay -3307
79 swapped true delay -2807
76 swapped true delay -2507
72 swapped true delay -2107
68 swapped true delay -1707
65 swapped true delay -1407
60 swapped true delay -907
57 swapped true delay -608
55 swapped true delay -408
75 swapped true delay -2408
77 swapped true delay -2608
73 swapped true delay -2208
63 swapped true delay -1208
67 swapped true delay -1608
64 swapped true delay -1308
59 swapped true delay -808
56 swapped true delay -508
54 swapped true delay -308
53 swapped true delay -208
52 swapped true delay -108
Process exited with exit code 0.

So the trick is when you know you are going to modify the delay is to remove and then re-add the element to the queue.

// Replacement swap loop
    for (DelayedSwap d : delayed) {
        if (dq.remove(d))
        {
            d.swap = true;
            dq.add(d);
        }
    }

This run produces a more sensible set of results:

1 swapped false delay -4
2 swapped false delay -8
3 swapped false delay -14
4 swapped false delay -8
5 swapped false delay -4
6 swapped false delay -4
7 swapped false delay -4
8 swapped false delay -4
9 swapped false delay -4
10 swapped false delay -4
11 swapped false delay -4
12 swapped false delay -4
13 swapped false delay -4
14 swapped false delay -4
15 swapped false delay -4
16 swapped false delay -4
17 swapped false delay -4
18 swapped false delay -8
19 swapped false delay -4
20 swapped false delay -4
21 swapped false delay -4
22 swapped false delay -4
23 swapped false delay -4
24 swapped false delay -4
25 swapped false delay -4
26 swapped false delay -4
27 swapped false delay -4
28 swapped false delay -4
29 swapped false delay -4
30 swapped false delay -4
31 swapped false delay -4
32 swapped false delay -4
33 swapped false delay -4
34 swapped false delay -4
35 swapped false delay -4
36 swapped false delay -4
37 swapped false delay -4
38 swapped false delay -4
39 swapped false delay -5
40 swapped false delay -5
41 swapped false delay -5
42 swapped false delay -4
43 swapped false delay -4
44 swapped false delay -5
45 swapped false delay -5
46 swapped false delay -5
47 swapped false delay -5
48 swapped false delay -5
49 swapped false delay -5
50 swapped false delay -5
99 swapped true delay -5
98 swapped true delay -5
97 swapped true delay -11
96 swapped true delay -1
95 swapped true delay -5
94 swapped true delay -9
93 swapped true delay -5
92 swapped true delay -5
91 swapped true delay -5
90 swapped true delay -5
89 swapped true delay -5
88 swapped true delay -5
87 swapped true delay -5
86 swapped true delay -5
85 swapped true delay -5
84 swapped true delay -5
83 swapped true delay -5
82 swapped true delay -5
81 swapped true delay -5
80 swapped true delay -5
79 swapped true delay -5
78 swapped true delay -5
77 swapped true delay -5
76 swapped true delay -5
75 swapped true delay -5
74 swapped true delay -5
73 swapped true delay -5
72 swapped true delay -6
71 swapped true delay -5
70 swapped true delay -5
69 swapped true delay -5
68 swapped true delay -5
67 swapped true delay -5
66 swapped true delay -5
65 swapped true delay -5
64 swapped true delay -5
63 swapped true delay -6
62 swapped true delay -5
61 swapped true delay -6
60 swapped true delay -6
59 swapped true delay -6
58 swapped true delay -6
57 swapped true delay -6
56 swapped true delay -6
55 swapped true delay -6
54 swapped true delay -6
53 swapped true delay -6
52 swapped true delay -6
51 swapped true delay -6
Process exited with exit code 0.

I don't think this is a bug in the object itself, as you wouldn't expect a HashTable to orders it's self when the key changes, but I was a little bit surprise by the behaviour.