How to improve performance of SimpleDateFormat wrapped in ThreadLocal?

Question

This is on Java 7 (51) on RHEL with 24 cores We are noticing a rise in average response times of a java SimpleDateFormat wrapped in thread local as we increase the thread pool size. Is this expected? or, I am just doing something stupid ?

Test program

    public class DateFormatterLoadTest {         private static final Logger LOG = Logger.getLogger(DateFormatterLoadTest .class);         private final static int CONCURRENCY = 10;          public static void main(String[] args) throws Exception {             final AtomicLong total = new AtomicLong(0);             ExecutorService es = Executors.newFixedThreadPool(CONCURRENCY);             final CountDownLatch cdl = new CountDownLatch(CONCURRENCY);             for (int i = 0; i < CONCURRENCY; i++) {                 es.execute(new Runnable() {                     @Override                     public void run() {                         try {                             int size = 65000;                             Date d = new Date();                              long time = System.currentTimeMillis();                             for (int i = 0; i < size; i++) {                                 String sd = ISODateFormatter.convertDateToString(d);                                 assert (sd != null);                             }                             total.addAndGet((System.currentTimeMillis() - time));                          } catch (Throwable t) {                             t.printStackTrace();                         } finally {                             cdl.countDown();                         }                     }                 });             }             cdl.await();             es.shutdown();             LOG.info("TOTAL TIME:" + total.get());             LOG.info("AVERAGE TIME:" + (total.get() / CONCURRENCY));         }     } 

DateFormatter class:

public class ISODateFormatter {     private static final Logger LOG = Logger.getLogger(ISODateFormatter.class);      private static ThreadLocal<DateFormat> dfWithTZ = new ThreadLocal<DateFormat>() {         @Override         public DateFormat get() {             return super.get();         }          @Override         protected DateFormat initialValue() {             return new SimpleDateFormat("yyyy-MM-dd'T'HH:mm:ssZ",                     Locale.ENGLISH);         }          @Override         public void remove() {             super.remove();         }          @Override         public void set(DateFormat value) {             super.set(value);         }      };      public static String convertDateToString(Date date) {         if (date == null) {             return null;         }         try {             return dfWithTZ.get().format(date);         } catch (Exception e) {             LOG.error("!!! Error parsing dateString: " + date, e);             return null;         }     } } 

Someone suggested to take out the AtomicLong so just wanted to share that it is not playing any role in increasing the average time:

##NOT USING ATOMIC LONG## 2014-02-28 11:03:52,790 [pool-1-thread-1] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:328 2014-02-28 11:03:52,868 [pool-1-thread-6] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:406 2014-02-28 11:03:52,821 [pool-1-thread-2] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:359 2014-02-28 11:03:52,821 [pool-1-thread-8] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:359 2014-02-28 11:03:52,868 [pool-1-thread-4] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:406 2014-02-28 11:03:52,915 [pool-1-thread-5] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:453 2014-02-28 11:03:52,930 [pool-1-thread-7] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:468 2014-02-28 11:03:52,930 [pool-1-thread-3] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:468 2014-02-28 11:03:52,930 [main] INFO  net.ahm.graph.DateFormatterLoadTest  - CONCURRENCY:8  ##USING ATOMIC LONG## 2014-02-28 11:02:53,852 [main] INFO  net.ahm.graph.DateFormatterLoadTest  - TOTAL TIME:2726 2014-02-28 11:02:53,852 [main] INFO  net.ahm.graph.DateFormatterLoadTest  - CONCURRENCY:8 2014-02-28 11:02:53,852 [main] INFO  net.ahm.graph.DateFormatterLoadTest  - AVERAGE TIME:340  ##NOT USING ATOMIC LONG## 2014-02-28 11:06:57,980 [pool-1-thread-3] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:312 2014-02-28 11:06:58,339 [pool-1-thread-8] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:671 2014-02-28 11:06:58,339 [pool-1-thread-4] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:671 2014-02-28 11:06:58,307 [pool-1-thread-7] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:639 2014-02-28 11:06:58,261 [pool-1-thread-6] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:593 2014-02-28 11:06:58,105 [pool-1-thread-15] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:437 2014-02-28 11:06:58,089 [pool-1-thread-13] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:421 2014-02-28 11:06:58,073 [pool-1-thread-1] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:405 2014-02-28 11:06:58,073 [pool-1-thread-12] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:405 2014-02-28 11:06:58,042 [pool-1-thread-14] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:374 2014-02-28 11:06:57,995 [pool-1-thread-2] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:327 2014-02-28 11:06:57,995 [pool-1-thread-16] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:327 2014-02-28 11:06:58,385 [pool-1-thread-10] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:717 2014-02-28 11:06:58,385 [pool-1-thread-11] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:717 2014-02-28 11:06:58,417 [pool-1-thread-9] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:749 2014-02-28 11:06:58,418 [pool-1-thread-5] INFO  net.ahm.graph.DateFormatterLoadTest  - THREAD TIME:750 2014-02-28 11:06:58,418 [main] INFO  net.ahm.graph.DateFormatterLoadTest  - CONCURRENCY:16  ##USING ATOMIC LONG## 2014-02-28 11:07:57,510 [main] INFO  net.ahm.graph.DateFormatterLoadTest  - TOTAL TIME:9365 2014-02-28 11:07:57,510 [main] INFO  net.ahm.graph.DateFormatterLoadTest  - CONCURRENCY:16 2014-02-28 11:07:57,510 [main] INFO  net.ahm.graph.DateFormatterLoadTest  - AVERAGE TIME:585 

Answer 1

Creating an instance of SimpleDateFormat is very expensive (this article shows some profiling/benchmarking). If this is true, compared with the parsing of the dates into strings, then it follows that as you increase the number of threads (and therefore the number of SimpleDateFormat instances as they are threadlocals) your average time is going to increase.