Hands-on Android: lessons learned from our first game project

About one year ago we wanted to gain some experience in android app development and the whole associated workflow, consisting of:

  • developing an Android app
  • publishing and maintaining the app in the Play Store
  • performing marketing and earning some money

So we decided to create a trial-balloon-project to get started. Despite the fact that our company normally creates serious business software, we gladly received the ok to do some more “funny stuff” like a game for this special case. We are working for a really cool company, do we?
In this short series of blog posts I want to share with you some of the key-insights we’ve gained (and problems we’ve encountered) since the first version of the app was released one year ago. Today I want to start from a technical perspective which must be a little “game specific”. But the later blog posts will focus on the Google Play Store as well as marketing and selling activities we’ve tried, which should make the whole story more interesting for a wider audience as just game developers. So keep on reading! Continue reading

Creating MS Word reports with Java

If your application stores a lots of user content, it seems to be an obvious idea to offer some template mechanism, which can be used by your customers to create reports. So, the user can get a printable, styled and easy to process version of the interesting information out of your system, designed by himself and filled with data with just one click. Of course, creating and styling those templates should be easy enough for your customer to do it by himself… so, whats about using the well-known MS Word application for it? The user creates a document with his beloved office suite from Redmond, containing formatted text, images and charts and finally adds also some placeholders. Afterwards he passes this document to your application and, whenever the user wants to create a report, you magically fill the placeholders with the actual data from your system. Reporting can be so easy … if you can find some way to manipulate the word document the correct way with the tools your platform offers!

Continue reading

The weak performance of the Groovy minus operator

During a recent hunt for performance problems within our grails application we’ve discovered that using the minus operator to subtract one list from another one seems to perform badly for list items which doesn’t implement the Comparable interface. This post will show the supposed reason for this bottleneck.

Have a look at the following simple microbenchmark which shows the problem:

We have a very simple pogo class which holds some data about books:

class Book {
    final String name
    final String author

    public Book(String  name, String author) {
        this.name = name
        this.author = author
    }

    public String toString() {
        return "Title: ${name} Author: ${author}"
    }
}

This Book class is used in an abstract unit-test to create one list of books, consisting of a configurable number of tech books and novels. The test cases will subtract the novels from the list: one time via an old school Java “removeAll” call, the second time via the Groovy minus-operator.

abstract class ListPerformanceTest extends TestCase {
    protected List<Book> novels
    protected List<Book> techBooks

    protected void setUp() {
        novels = createNovelsForFixture()
        techBooks = createTechBooksForFixture()
    }

    public void testGroovyMinus() {
        List<Book> allBooks = novels + techBooks
        measureTimeInMS("Subtracting ${novels.size()} novels from the list of ${allBooks.size()} books") {
            allBooks = allBooks - novels
        }
        assertEquals(techBooks.size(), allBooks.size())
    }

    public void testJavaRemoveAll() {
        List<Book> allBooks = novels + techBooks
        measureTimeInMS("Removing ${novels.size()} novels from the list of ${allBooks.size()} books") {
            allBooks.removeAll(novels)
        }
        assertEquals(techBooks.size(), allBooks.size())
    }

    public long measureTimeInMS(String description, Closure toMeasure) {
        long nanoTimeStart = System.nanoTime()
        toMeasure.call()
        long nanoTimeEnd = System.nanoTime()
        long result = (nanoTimeEnd - nanoTimeStart) * 1E-6
        println description + " took ${result} ms"
        return result
    }

    protected abstract List<Book> createNovelsForFixture()
    protected abstract List<Book> createTechBooksForFixture()
}

We created three subclasses: a SmallTestCase class (subtracting 1000 novels from a 2000 books’ list), a MediumTestCase (subtracting 2000 novels from a 4000 books’ list) and finally a LargeTestCase (subtracting 4000 novels from the list containing 8000 books).

Following you can find the results of the test runs:
Statistic Groovy minus

We performed the tests within the following environment:
Win-7 64 bit, JDK 1.6.0.33 (32 bit), Intel i5-2500 (4 cores, 3.3GHz per core), 8GB RAM

You could argue that it is not fair to compare both methods: the Groovy way will return a new list, the removeAll-method of Java uses an in-place-removement, so the original list will be lost. But just the fact that Groovy is creating a new list can not explain why the minus operator is so expensive: for the small list with 2000 books Groovy is about 1700 times slower than Javas’ removeAll, for the medium list even over 3000 times. And remember: all of this will only happen when your item class doesn’t implement Comparable.

That’s why we decided to do some more research to get an explanation. After some runs with JProfiler and the medium-sized test-case we found out that one of the biggest hotspots was the toString()-method of the Book class. According to the profiler it was called nearly 12 million times while performing the minus operation and burnt about 15% of the overall time. Because the profiler did not tell us anything about other hotspots we started with this trace and decided to take a look at the implementation of the minus operator within the Groovy source code under “Source release” of version 1.8.8.

We found the following implementation:

public class DefaultGroovyMethods extends DefaultGroovyMethodsSupport {
...
   public static <T> List<T> minus(List<T> self, Collection<?> removeMe) {
	...
        Comparator<T> numberComparator = new NumberAwareComparator<T>();
        if (nlgnSort && (self.get(0) instanceof Comparable)) {
		// Not interesting in our case, because Book doesn't implement Comparable
		...
        } else {
            //n*n version
            List<T> tmpAnswer = new LinkedList<T>(self);
            for (Iterator<T> iter = tmpAnswer.iterator(); iter.hasNext();) {
                T element = iter.next();
                boolean elementRemoved = false;
                for (Iterator<?> iterator = removeMe.iterator(); iterator.hasNext() && !elementRemoved;) {
                    Object elt = iterator.next();
                    if (numberComparator.compare(element, (T)elt) == 0) {
                        iter.remove();
                        elementRemoved = true;
                    }
                }
            }
            ...
        }
    }
...
}

At the first glance we did not find anything special about the code: it has a worst case scenario of O(n*m) and uses the so called “NumberAwareComparator” to decide, if two elements of the list are equal or not. So, let’s proceed with this Comparator:

public class NumberAwareComparator<T> implements Comparator<T> {
    public int compare(T o1, T o2) {
        try {
            return DefaultTypeTransformation.compareTo(o1, o2);
        } catch (ClassCastException cce) {
            /* ignore */
        } catch (GroovyRuntimeException gre) {
            /* ignore */
        }
        // since the object does not have a valid compareTo method
        // we compare using the hashcodes. null cases are handled by
        // DefaultTypeTransformation.compareTo
        int x1 = o1.hashCode();
        int x2 = o2.hashCode();
        if (x1 == x2) return 0;
        if (x1 < x2) return -1;
        return 1;
    }
}

You can find here a typical code smell in form of a misuse of the exception concept (see this refactoring catalogue for details): the comparator doesn’t check if the two instances can be compared at all by the DefaultTypeTransformation class before calling its compareTo method. Instead, the code relies upon the fact that DefaultTypeTransformation#compareTo will throw an exception whenever the list items can not be compared. In our case this will happen for nearly all Book items (except those pointing to one and the same reference). This leads to the following approximation of thrown exceptions:
Number of exceptions thrown by minus

So, in our example we will have about 6 million exceptions which will be thrown and afterwards just be ignored. Because the profiler ignores the overhead produced by the exceptions we did not have a chance to see this: the only trace for this problem were the 12 million calls of toString.

But everything we said up to now doesn’t explain them. To understand why we call toString so often, you just have to take a short look how the exception thrown by DefaultTypeTransformation#compareTo is constructed:

public class DefaultTypeTransformation {
...
    private static int compareToWithEqualityCheck(Object left, Object right, boolean equalityCheckOnly) {
        if (left == right) {
            return 0;
        }
	...
        throw new GroovyRuntimeException("Cannot compare " + left.getClass().getName() + " with value '" +
                left + "' and " + right.getClass().getName() + " with value '" + right + "'");
    }
}

As you can see here Groovys’ minus doesn’t only throw 6 million exceptions in our case but also use a string concatenation of the left and right element to construct the exception message, i.e. for each exception we will call toString() of the Book class twice.

Conclusion

You shouldn’t use the minus operator if you have lists with more than some hundred elements which don’t implement Comparable. We’ve tested this only with Groovy 1.8.8, because this is the version shipped with the current Grails version 2.1.1. But after a short look at the current Groovy 2.0.5 code it seems that the performance leak should still exist. And according to this jira issue we are not the only one having problems with the collection performance of Groovy. To avoid the minus operator just for performance reasons is a real pitty, because the minus syntax is not only much more readable than the method call but feels also “cleaner” in terms of having no side effects on the list it is called at.

How to use gorm after a http session timeout

In the previous part we’ve already discussed how to get informed about “regular” logout- and timeout-events in order to maintain a list of currently logged in users. But in our use-case we not only want to maintain a simple list, but also want to do some database cleanup queries whenever a user logs out (in our case: we have to remove some “locking” entries, identifiying resources exclusively locked by the current user).

We’ve already identified the two different places where we have to handle the logout event:

  1. The “onLogout” method of the RewooAuthenticationListener (informed by shiro when a regular logout occurres)
  2. The “sessionDestroyed” method of the RewooHttpSessionListener (informed by the servlet container when a timeout occurres)

The first scenario can be handled quite easily: because we are informed about the event by the shiro plugin we will have a fully initialized hibernate session which can be used to clean up your tables in the usual way:

public class RewooAuthenticationListener implements AuthenticationListener {
...
    public void onLogout(PrincipalCollection principalCollection) {
        // Maintain your user list as described in the previous post
        // ...
        // Do the clean up now
        SystemUser user = SystemUser.findByName(userName)
        ExclusiveLocks.findAllByUser(user) {
            it.delete()
        }
    }
...
}

The second one is the tricky part: because the method is called by the servlet container we will not have any valid hibernate session bound to the SessionHolder of the thread-context. So, the Gorm calls will break with a “No hibernate session bound to thread” exception The first solution which came into our minds was, to retrieve a new session by wrapping the routine in a simple withNewSession-closure call, like this:

public class RewooHttpSessionListener implements HttpSessionListener {
...
    public void sessionDestroyed(HttpSessionEvent event) {
        // Maintain your user list as described in the previous post
        // ...
        // Do the clean up now
        ExclusiveLocks.withNewSession {
            SystemUser user = SystemUser.findByName(userName)
            ExclusiveLocks.findAllByUser(user) {
                it.delete()
            }
        }
    }
    ...
}

In fact this solution will work for the FIRST timeout event. But afterwards you will get the following exception each time a new timeout occurres:

org.springframework.dao.DataAccessResourceFailureException: Could not open Hibernate Session; nested exception is org.hibernate.SessionException: Session is closed!

After some research and digging into the grails / hibernate code we discovered that after leaving the withNewSession closure (which resides within a grails class called “HibernatePluginSupport”) the session is closed but not removed from the SessionHolder. When the next timeout occurres the old session will be found by hibernate and the exception will be thrown. Interestingly enough the clean up code used by grails 1.3.5 is significantly different to the new cleanup algorithm used by HibernateGormEnhancer (which replaces HibernatePluginSupport in newer grails versions). Because of some compatibility issues we can not upgrade to a newer version of grails at the moment so we can not say if the problems described here will vanish with a newer grails release.

We’ve searched around for a while to find a possibility to remove the outdated session from the session holder, but we did not found any proper way to accomplish this:

  • you can not access the underlying sessionMap directly, because it is a private variable and for encapsulation purposes there is no getter
  • you can not use the removeSession method, because you have to pass in the key of the session to remove: unfortunately this key is not the session itself but a private object created by SessionHolder during instantiation of the holder and there is no way to retrieve it
  • even calling the clean method of the SessionHolder will not clean the internal map

Finally we found a solution: by calling the SessionHolder#getValidatedSession you will only get the current session, if the session is not already closed. In case it is closed, it will be removed from the internal map as a side effect. So, that is exactly what we want to have in our case but be aware that this is a very ugly workaround. It depends upon an implementation detail of a class which is not under your control.

Our solution leads us to the following method which can be used to clean up the hibernate session:

private void cleanUpHibernateSession() {
    SessionHolder sessionHolder = (SessionHolder) TransactionSynchronizationManager.getResource(SessionGrabber.getSessionFactory())
    if (sessionHolder != null &amp;&amp; !sessionHolder.isEmpty()) {
        // Calling this method will "remove" already closed sessions as a side-effect (so we don't care about the return-value)
        sessionHolder.getValidatedSession()
        if (sessionHolder.isEmpty()) {
            sessionHolder.clear()
        }
    }
}

The method will be called after the withNewSession closure call like this:

public class RewooHttpSessionListener implements HttpSessionListener {
...
    public void sessionDestroyed(HttpSessionEvent event) {
        // Maintain your user list as described in the previous post
        // ...
        // Do the clean up now
        ExclusiveLocks.withNewSession {
            SystemUser user = SystemUser.findByName(userName)
            ExclusiveLocks.findAllByUser(user) {
                it.delete()
            }
        }
        cleanUpHibernateSession()
    }
    ...
}

This will make sure that the next call of withNewSession will not be disturbed by an already closed session.

Conclusion

The solution we’ve presented here give you the possibility to clean up parts of your database each time a user logs out. We don’t feel very comfortable with our workaround for the SessionHolder problem: if you know a better solution we would be glad to hear about it!

Maintain a user list with grails

Preface

This is the first part of a blog entry about the problems we had with grails 1.3.5 in conjunction with shiro to retrieve and maintain a simple list with the currently logged in users. The first part will explain how to keep the list up to date. The second part will describe a solution we use to interact with the grails-environment in case of an automatic logout to remove some rows from the database.

How to take care of automatic timeouts for a active user list

As already mentioned we have the following (as we thought very simple) use-case for our web-application: We want to have an overview-page containing a list of all currently logged in users. To accomplish this, it should be sufficient to catch the following events:

  • Whenever a user logs in, add him to a internal list of logged in users
  • Whenever a user logs out, remove him from the list and release all resources locked by him (in our case: remove a row from a table. This will be the topic of part two)

Of course, we want the same behaviour for an automatic logout (which should take place after some minutes of inactivity).

To secure our app we use the shiro-plugin based on the apache shiro project. In fact, shiro already offers an easy-to-implement interface to inform our app about login and logout events called “AuthenticationListener”. So, we started with the following straight-forward implementation (based on this discussion), which has to be registiered in the resources.groovy file:

public class RewooAuthenticationListener implements AuthenticationListener {
    private static Collection activeUsers = Collections.synchronizedList(new ArrayList());

    @Override
    public void onSuccess(AuthenticationToken authenticationToken, AuthenticationInfo authenticationInfo) {
        PrincipalCollection collection = authenticationInfo.getPrincipals();
        activeUsers.add((String) collection.getPrimaryPrincipal());
    }

    @Override
    public void onFailure(AuthenticationToken authenticationToken, AuthenticationException e) { }

    @Override
    public void onLogout(PrincipalCollection principalCollection) {
        PrincipalCollection collection = authenticationInfo.getPrincipals();
        activeUsers.remove((String) collection.getPrimaryPrincipal());
    }

    public static Collection getActiveUsers() {
        return Collections.unmodifiableList(activeUsers);
    }
}

In case of a “normal” logout this solution works pretty well. But whenever a user just forgets to logout properly (like it is usual for hard working days) and the timeout mechanism has to take place our methods aren’t called at all. After carefully reading the javadoc we recognized the following statement: “This method will only be triggered when a Subject explicitly logs-out of the session. It will not be triggered if their Session times out.”

Therefore, the automatic timeout is neither triggered by your grails app nor by grails at all. Instead, it is your servlet-container which recognizes the connection timeout and cleans up the session. So we’ve searched for another possibility to get informed about the timeout (in this case through the servlet-container itself). The standard way to achieve this is via an own implementation of an HttpSessionListener which has to be registered within web.xml like the following:

...
    <listener>
        <listener-class>com.rewoo.listeners.RewooHttpSessionListener</listener-class>
    </listener>
...

The registered RewooHttpSessionListener looks like this:

public class RewooHttpSessionListener implements HttpSessionListener {
    private static List activeUsers = Collections.synchronizedList(new ArrayList());

    @Override
    public void sessionCreated(HttpSessionEvent event) { }

    @Override
    public void sessionDestroyed(HttpSessionEvent event) {
        String userName = getCurrentUserName(event)
        if (userName == null) {
            return
        }
        RewooHttpSessionListener.userLoggedOut(userName)
    }

    public static void userLoggedIn(String userName) {
        activeUsers.add(userName)
    }

    public static void userLoggedOut(String userName) {
        activeUsers.remove(userName)
    }

    public static List getCurrentUserNames() {
        return Collections.unmodifiableList(activeUsers);
    }

    private String getCurrentUserName(HttpSessionEvent event) {
        PrincipalCollection currentUser = (PrincipalCollection) event.getSession().getAttribute(DefaultSubjectContext.PRINCIPALS_SESSION_KEY);
        if (currentUser == null) {
            return null
        }
        return (String) collection.getPrimaryPrincipal();
    }
}

As you can see, we’ve moved the activeUsers list to the SessionListener and added public methods which can be used by the RewooAuthenticationListener to inform us about regular login / logout events recognized by shiro. We better don’t use the sessionCreated method here to update our user list, because it will be called each time some client connects to the server (and establishes a http session), no matter if the user has been logged in correctly or not. Thus, we better handle this within our RewooAuthenticationListener.

In case of a sessionDestroyed event, we have to differ between two situations:

  • a normal logout occurred: in this case shiro has already cleaned up the current session, so the HttpSessionEvent will not contain the name of the previously logged in user
  • a timeout occurred: in this case shiro hasn’t performed any clean up operation upon the session, so we can read out the name of the previously logged in user

This leads us to the following, new implementation of the RewooAuthenticationListener:

public class RewooAuthenticationListener implements AuthenticationListener {
    @Override
    public void onSuccess(AuthenticationToken authenticationToken, AuthenticationInfo authenticationInfo) {
        RewooHttpSessionListener.userLoggedIn((String) authenticationInfo.getPrincipals().getPrimaryPrincipal());
    }

    @Override
    public void onFailure(AuthenticationToken authenticationToken, AuthenticationException e) { }

    @Override
    public void onLogout(PrincipalCollection principalCollection) {
        RewooHttpSessionListener.userLoggedOut((String) principalCollection.getPrimaryPrincipal());
    }
}

Conclusion

To detect manual and automatic logouts, you have to combine the AuthenticationListener of shiro with the HttpSessionListener of your servlet api. Manual logouts will be handled by shiro, automatic logouts (due a timeout) by the session listener.

Count prepared statements within your grails application

Sometimes it is not so easy to find hotspots within your grails application. Even commercial profilers like JProfiler seem to have their problems generating useful “output” of the artifacts generated by the grails/groovy stack. For lack of alternatives we use a “primitve” closure to measure the time-consumption of a code-block, just to get some hint if we increased the performance of a block of code (e.g. a grails-service) or not.

But sometimes you need more than just a time-measurement closure. A good point to start performance-optimizations in our application seems to be to watch out for blocks doing a lot of sql-statements. With all that ORM and GORM magic you can run very fast in a situation that hundreds of selects and updates are fired within one service but you don’t know which individual methods within the service are causing them.

To “count” the number of prepared statements used within a code-block, we use the following closure within a “Measurement” class:

public class Measurement {
    // ...
    public static def countSQLStatements = { String blockIdentifier, Closure toExecute ->
        SessionFactory sessionFactory = ApplicationHolder.application.mainContext.sessionFactory
        boolean oldStatisticsState = enableStatistics(sessionFactory)

        long start = System.nanoTime()
        long queriesBeforeCall = sessionFactory.getStatistics().prepareStatementCount
        toExecute.call()
        long queriesOfCall =  sessionFactory.getStatistics().prepareStatementCount - queriesBeforeCall
        println "${blockIdentifier} caused the execution of ${queriesOfCall} prepared statements and took ${getTimeDeltaInMilliSeconds(start, System.nanoTime())} ms."

        resetStatisticsState(oldStatisticsState, sessionFactory)
        return queriesOfCall
    }
    //...
}

The method “getTimeDeltaInMilliSeconds” is implemented like this:

private static long getTimeDeltaInMilliSeconds(long nanoTimeStart, long nanoTimeEnd) {
    return  (nanoTimeEnd - nanoTimeStart) / 1E6
}

So, whenever you want to know how expensive a method call or other block within your code is, you can just write:

Measurement.countSQLStatements("Some block description",
  { methodCallToMeasure1()
     methodCallToMeasure2()
     // ...
})

Do you have any more tricks how to profile a grails-app? We would love to hear about them.

How to fix Hibernate Query Cache for Grails 1.3.5

To speed up our Grails-application we’ve decided to use hibernates’ second-level- and query-cache. To do so, we performed the following steps:

  • Added appropriate caching-xml-elements to our ehcache.xml (resides within grails-app/conf)
  • Enabled query-cache (“cache.use_query_cache=true” within DataSource.groovy)
  • Enabled the 2nd level cache for the relevant entities
  • Enabled the Query-Cache for a specific query via (SomeClass.findAllByX(someX, [cache: true]))

To test the cache, we implemented an integration-test. Whenever we created an entity and asked for it multiple times the cache worked as expected. The first retrieval-attempt lead to a cache-miss, the following calls to cache-hits. In a next step we adapted the test a little: we changed the entity AFTER it was added to the query-cache and tried afterwards to retrieve it again and again. But the cache just produced cache-misses. After some debugging and reading we discovered that this behaviour was the result of a bug of the hibernate-version used by Grails 1.3.5. You can find details about  this here. In addition to the linked blog-post we will describe here in more detail what you have to do to fix the bug so that you can really use the hibernate-cache with this grails-version.

  1. Download hibernate-distribution-3.3.1.GA-dist.zip from http://sourceforge.net/projects/hibernate/files/
  2. You are just interested in the “project”-folder, so unzip it to a separate project-director
  3. Open the pom with your favourite java-ide (we are using IntelliJ for this)
  4. Download the latest 1.5 jdk and install it. Adapt the project to use this jdk
  5. Open org.hibernate.cache.StandardQueryCache and go to the “put” method. There you will find the following line (around line 90):

    ...
    Long ts = Long.valueOf( session.getTimestamp() );
    ...

    Replace it with the following code:

    ...
    Long ts = Long.valueOf(cacheRegion.nextTimestamp());
    ...
  6. Use the “package” target of “Hibernate Core” to create your customized jar. When Maven have problems to download some of the necessary dependencies (e.g. JAAS jar), you have to download them manually and add them to the appropriate folder within /youruserhome/.m2/repository/
  7. Finally you have your own version of hibernate-core.jar -> add it to your grails installation by copying it to GRAILS_HOME/lib. You will have to overwrite the existing hibernate-core-3.3.1.GA.jar with your customized jar
  8. There is just one step left: don’t forget to also replace the hibernate-core-3.3.1.GA.jar from your local ivy cache. You can find it under/youruserhome/.ivy2/cache. If you don’t replace this jar, Grails will replace your custom  hibernate version with the old one and you will see no effect.

Conclusion

To create a “custom build” of hibernate is no big deal, after you found the sources and all the dependencies you need. But from my point of view you shouldn’t need to do this for an “ordinary feature” like query-caching. I’m not quite sure why Grails ships such an outdated version of hibernate: the current version is 3.6.0 and the version which comes with Grails is 3.3.1.

Grails 1.3.5 upgrade problems

Recently we decided to upgrade our Grails version from 1.3.2 to 1.3.5. Because of our project history we use jetty instead of apache tomcat as our servlet-container, but we thought this shouldn’t be a big deal: for previous upgrades we just had to remove the tomcat-plugin via grails uninstall-plugin within our ide before re-compiling and starting the app.

But this time (at least on my windows-7-machine) we had no possibility to get rid of the tomcat-plugin. Each time we started grails, it tried to use tomcat instead of jetty. The only solution which worked for me was to uninstall the plugin AND to manually delete the physical tomcat folder. The funny thing is, that this was just necessary on my windows-machine: a colleague had no problems on his Mac.

Maybe I should mention that we “upgraded” our grails version within IntelliJ 9.0.3 and not directly via the grails-console-commands. We didn’t do any more research on this topic, so we don’t know if this is an IntelliJ or a Grails issue. But maybe this blog-entry can help others having the same problems.