TritonDataCenter / java-http-signature

Library for performing RSA signed HTTP requests in Java
Mozilla Public License 2.0
17 stars 13 forks source link

Signer uses SimpleDateFormat in a manner that is not thread safe #34

Closed cburroughs closed 7 years ago

cburroughs commented 7 years ago

Example from a concurrency heavy test:

java.lang.ArrayIndexOutOfBoundsException: 962
        at sun.util.calendar.BaseCalendar.getCalendarDateFromFixedDate(BaseCalendar.java:453) ~[na:1.8.0_131]
        at java.util.GregorianCalendar.computeFields(GregorianCalendar.java:2397) ~[na:1.8.0_131]
        at java.util.GregorianCalendar.computeFields(GregorianCalendar.java:2312) ~[na:1.8.0_131]
        at java.util.Calendar.setTimeInMillis(Calendar.java:1804) ~[na:1.8.0_131]
        at java.util.Calendar.setTime(Calendar.java:1770) ~[na:1.8.0_131]
        at java.text.SimpleDateFormat.format(SimpleDateFormat.java:943) ~[na:1.8.0_131]
        at java.text.SimpleDateFormat.format(SimpleDateFormat.java:936) ~[na:1.8.0_131]
        at java.text.DateFormat.format(DateFormat.java:345) ~[na:1.8.0_131]
        at com.joyent.manta.http.signature.Signer.defaultSignDateAsString(Signer.java:420)

See https://bugs.openjdk.java.net/browse/JDK-6231579 --> from the docs "Date formats are not synchronized"

cburroughs commented 7 years ago

I am deeply regretting not saving the full stack trace, because this is much more confusing than I thought:

I've been unable to reproduce this exact case synthetically. A snippet will help explain:

    public static void main(String args[]) throws Exception {
        TestApp app = new TestApp();
        app.setup();
        app.run();

   }

    public void run() throws Exception {
        for (int i =0; i< 48 ; i++){
            Thread thread = new Thread(new Runner());
            thread.start();
        }
    }

    public class Runner implements Runnable {
        public void run() {
            String str;
            String str2;            
            for (long i=1; ; i++) {
                str = signer.defaultSignDateAsString();
                //str2 = signer.DATE_FORMAT.format(new java.util.Date(i));
            }
        }
    } 

No amount of fiddling with signer.defaultSignDateAsString() and the number of threads has reproduced this, but formatting two different dates quickly errors (the str2 statement). Since we are always formatting "now", I think the reason we don't see this all the time in practice is that threads usually agree on what time it is and only on the "border" of time units could we hit this.

That makes me feel slightly less crazy as with many instances running 24/7 I think I've only seen this once. Still need to fix as it is a bug and we are grabbing a lock we do not need. It would just be nice to have a cleaner repro case.

cburroughs commented 7 years ago

Benchmark with current code to reference (ubuntu-16.04 g4-highcpu-64G):

Benchmark                                   Mode  Cnt        Score       Error  Units
DefaultSignDateAsStringBenchmark.thread1   thrpt  100   795233.851 ± 92250.500  ops/s
DefaultSignDateAsStringBenchmark.thread4   thrpt  100  1896470.814 ± 79153.738  ops/s
DefaultSignDateAsStringBenchmark.thread64  thrpt  100  1163259.568 ± 43861.006  ops/s
cburroughs commented 7 years ago

With incoming change:

Benchmark                                   Mode  Cnt         Score         Error  Units
DefaultSignDateAsStringBenchmark.thread1   thrpt  100    985689.667 ±   99171.261  ops/s
DefaultSignDateAsStringBenchmark.thread4   thrpt  100   4260681.530 ±  276958.920  ops/s
DefaultSignDateAsStringBenchmark.thread64  thrpt  100  40677035.264 ± 1116732.322  ops/s