[#2858] Improve asynchronous span event ordering

profiler-test/src/main/java/com/navercorp/pinpoint/test/OrderedSpanRecorder.java

@@ -33,76 +33,97 @@ import com.navercorp.pinpoint.profiler.context.SpanEvent;
 public class OrderedSpanRecorder implements ListenableDataSender.Listener, Iterable<TBase<?, ?>> {
     private static final int ROOT_SEQUENCE = -1;
     private static final int ASYNC_ID_NOT_SET = -1;
+    private static final int ASYNC_SEQUENCE_NOT_SET = -1;
 
     private final List<Item> list = new ArrayList<Item>();
 
     private static final class Item implements Comparable<Item> {
 
-
         private final TBase<?, ?> value;
         private final long time;
         private final long spanId;
         private final int sequence;
         private final int asyncId;
+        private final int asyncSequence;
 
         public Item(TBase<?, ?> value, long time, long spanId, int sequence) {
-            this(value, time, spanId, sequence, ASYNC_ID_NOT_SET);
+            this(value, time, spanId, sequence, ASYNC_ID_NOT_SET, ASYNC_SEQUENCE_NOT_SET);
         }
 
-        public Item(TBase<?, ?> value, long time, long spanId, int sequence, int asyncId) {
+        public Item(TBase<?, ?> value, long time, long spanId, int sequence, int asyncId, int asyncSequence) {
             this.value = value;
             this.time = time;
             this.spanId = spanId;
             this.sequence = sequence;
             this.asyncId = asyncId;
+            this.asyncSequence = asyncSequence;
         }
 
         @Override
         public int compareTo(Item o) {
-            if (this.asyncId == ASYNC_ID_NOT_SET) {
-                if (o.asyncId == ASYNC_ID_NOT_SET) {
-                    // fall through
-                } else {
-                    return -1;
-                }
+            if (this.asyncId == ASYNC_ID_NOT_SET && o.asyncId == ASYNC_ID_NOT_SET) {
+                return compareItems(this, o);
+            } else if (this.asyncId != ASYNC_ID_NOT_SET && o.asyncId != ASYNC_ID_NOT_SET) {
+                return compareAsyncItems(this, o);
             } else {
-                if (o.asyncId == ASYNC_ID_NOT_SET) {
-                    return 1;
+                if (this.asyncId == ASYNC_ID_NOT_SET) {
+                    return -1;
                 } else {
-                    if (this.asyncId < o.asyncId) {
-                        return -1;
-                    } else if (this.asyncId > o.asyncId) {
-                        return 1;
-                    }
-
-                    // if both async events have the same asyncId, do normal event comparison
+                    return 1;
                 }
             }
+        }
 
-
-            if (this.time < o.time) {
+        private static int compareItems(Item lhs, Item rhs) {
+            if (lhs.time < rhs.time) {
                 return -1;
-            } else if (this.time > o.time) {
+            } else if (lhs.time > rhs.time) {
                 return 1;
             } else {
-                if (this.spanId < o.spanId) {
+                if (lhs.spanId < rhs.spanId) {
                     return -1;
-                } else if (this.spanId > o.spanId) {
+                } else if (lhs.spanId > rhs.spanId) {
                     return 1;
                 } else {
-                    if (this.sequence < o.sequence) {
+                    if (lhs.sequence < rhs.sequence) {
                         return -1;
-                    } else if (this.sequence > o.sequence) {
+                    } else if (lhs.sequence > rhs.sequence) {
                         return 1;
                     } else {
-                        int h1 = System.identityHashCode(this.value);
-                        int h2 = System.identityHashCode(o.value);
-
-                        return h1 < h2 ? -1 : (h1 > h2 ? 1 : 0);
+                        return compareHashes(lhs, rhs);
                     }
                 }
             }
         }
+
+        private static int compareAsyncItems(Item lhs, Item rhs) {
+            if (lhs.asyncId < rhs.asyncId) {
+                return -1;
+            } else if (lhs.asyncId > rhs.asyncId) {
+                return 1;
+            } else {
+                if (lhs.asyncSequence < rhs.asyncSequence) {
+                    return -1;
+                } else if (lhs.asyncSequence > rhs.asyncSequence) {
+                    return 1;
+                } else {
+                    if (lhs.sequence < rhs.sequence) {
+                        return -1;
+                    } else if (lhs.sequence > rhs.sequence) {
+                        return 1;
+                    } else {
+                        return compareHashes(lhs, rhs);
+                    }
+                }
+            }
+        }
+
+        private static int compareHashes(Item lhs, Item rhs) {
+            int h1 = System.identityHashCode(lhs.value);
+            int h2 = System.identityHashCode(rhs.value);
+
+            return h1 < h2 ? -1 : (h1 > h2 ? 1 : 0);
+        }
     }
 
     @Override
@@ -139,7 +160,8 @@ public class OrderedSpanRecorder implements ListenableDataSender.Listener, Itera
     private void handleSpanEvent(SpanEvent event) {
         Span span = event.getSpan();
         int asyncId = event.isSetAsyncId() ? event.getAsyncId() : ASYNC_ID_NOT_SET;
-        insertItem(new Item(event, span.getStartTime() + event.getStartElapsed(), span.getSpanId(), event.getSequence(), asyncId));
+        int asyncSequence = event.isSetAsyncSequence() ? event.getAsyncSequence() : ASYNC_SEQUENCE_NOT_SET;
+        insertItem(new Item(event, span.getStartTime() + event.getStartElapsed(), span.getSpanId(), event.getSequence(), asyncId, asyncSequence));
     }
 
     public synchronized TBase<?, ?> pop() {

profiler-test/src/test/java/com/navercorp/pinpoint/test/OrderedSpanRecorderTest.java

@@ -37,11 +37,12 @@ import com.navercorp.pinpoint.profiler.context.SpanEvent;
  * @author HyunGil Jeong
  */
 public class OrderedSpanRecorderTest {
-    
-    private static final int UNSET_ASYNC_ID = 0;
+
+    private static final int UNSET_ASYNC_ID = -1;
+    private static final short UNSET_ASYNC_SEQUENCE = -1;
 
     private final Logger logger = LoggerFactory.getLogger(this.getClass());
-    
+
     private final OrderedSpanRecorder recorder = new OrderedSpanRecorder();
 
     @After
@@ -55,42 +56,86 @@ public class OrderedSpanRecorderTest {
         final long startTime = System.currentTimeMillis();
         final long spanId = 1L;
         Span span = createSpan(startTime, spanId);
-        SpanEvent event = createSpanEvent(span, 0, (short)0);
-        SpanEvent event1 = createSpanEvent(span, 0, (short)1);
-        SpanEvent event2 = createSpanEvent(span, 0, (short)2);
-        SpanEvent asyncEvent1 = createAsyncSpanEvent(span, 0, (short)0, 1);
-        SpanEvent asyncEvent1_1 = createAsyncSpanEvent(span, 0, (short)1, 1);
-        SpanEvent asyncEvent2 = createAsyncSpanEvent(span, 0, (short)0, 2);
+        SpanEvent event = createSpanEvent(span, 0, (short) 0);
+        SpanEvent event1 = createSpanEvent(span, 0, (short) 1);
+        SpanEvent event2 = createSpanEvent(span, 0, (short) 2);
+        SpanEvent asyncEvent1_1 = createAsyncSpanEvent(span, 0, (short) 0, 1, (short) 1);
+        SpanEvent asyncEvent1_2 = createAsyncSpanEvent(span, 0, (short) 1, 1, (short) 1);
+        SpanEvent asyncEvent2 = createAsyncSpanEvent(span, 0, (short) 0, 2, (short) 1);
         @SuppressWarnings("unchecked")
-        final List<? extends TBase<?,?>> expectedOrder = Arrays.asList(
+        final List<? extends TBase<?, ?>> expectedOrder = Arrays.asList(
                 span,
                 event,
                 event1,
                 event2,
-                asyncEvent1,
                 asyncEvent1_1,
+                asyncEvent1_2,
                 asyncEvent2
         );
         // when
         @SuppressWarnings("unchecked")
-        final List<? extends TBase<?,?>> listToBeHandled = Arrays.asList(
-                span, event, event1, event2, asyncEvent1, asyncEvent1_1, asyncEvent2
+        final List<? extends TBase<?, ?>> listToBeHandled = Arrays.asList(
+                span, event, event1, event2, asyncEvent1_1, asyncEvent1_2, asyncEvent2
         );
         Collections.shuffle(listToBeHandled);
-        for (TBase<?,?> base : listToBeHandled) {
+        for (TBase<?, ?> base : listToBeHandled) {
             this.recorder.handleSend(base);
         }
         // then
         ByteArrayOutputStream baos = new ByteArrayOutputStream();
         this.recorder.print(new PrintStream(baos));
         this.logger.debug(baos.toString());
-        for (TBase<?,?> expectedBase : expectedOrder) {
-            TBase<?,?> actualBase = this.recorder.pop();
+        for (TBase<?, ?> expectedBase : expectedOrder) {
+            TBase<?, ?> actualBase = this.recorder.pop();
             assertSame(expectedBase, actualBase);
         }
         assertNull(this.recorder.pop());
     }
-    
+
+    @Test
+    public void testMultipleAsyncSpanEvents() {
+        // given
+        final long startTime = System.currentTimeMillis();
+        final long spanId = 1L;
+        Span span = createSpan(startTime, spanId);
+        SpanEvent event1 = createSpanEvent(span, 0, (short) 0);
+        SpanEvent asyncEvent1_1_1 = createAsyncSpanEvent(span, 0, (short) 0, 1, (short) 1);
+        SpanEvent asyncEvent1_1_2 = createAsyncSpanEvent(span, 0, (short) 1, 1, (short) 1);
+        SpanEvent asyncEvent1_2_1 = createAsyncSpanEvent(span, 0, (short) 0, 1, (short) 2);
+        SpanEvent event2 = createSpanEvent(span, 0, (short) 1);
+        SpanEvent asyncEvent2_1 = createAsyncSpanEvent(span, 0, (short) 0, 2, (short) 1);
+        SpanEvent asyncEvent2_2 = createAsyncSpanEvent(span, 0, (short) 0, 2, (short) 2);
+        @SuppressWarnings("unchecked")
+        final List<? extends TBase<?, ?>> expectedOrder = Arrays.asList(
+                span,
+                event1,
+                event2,
+                asyncEvent1_1_1,
+                asyncEvent1_1_2,
+                asyncEvent1_2_1,
+                asyncEvent2_1,
+                asyncEvent2_2
+        );
+        // when
+        @SuppressWarnings("unchecked")
+        final List<? extends TBase<?, ?>> listToBeHandled = Arrays.asList(
+                span, event1, asyncEvent1_1_1, asyncEvent1_1_2, asyncEvent1_2_1, event2, asyncEvent2_1, asyncEvent2_2
+        );
+        Collections.shuffle(listToBeHandled);
+        for (TBase<?, ?> base : listToBeHandled) {
+            this.recorder.handleSend(base);
+        }
+        // then
+        ByteArrayOutputStream baos = new ByteArrayOutputStream();
+        this.recorder.print(new PrintStream(baos));
+        this.logger.debug(baos.toString());
+        for (TBase<?, ?> expectedBase : expectedOrder) {
+            TBase<?, ?> actualBase = this.recorder.pop();
+            assertSame(expectedBase, actualBase);
+        }
+        assertNull(this.recorder.pop());
+    }
+
     @Test
     public void testMultipleSpanOrdering() {
         // given
@@ -99,16 +144,16 @@ public class OrderedSpanRecorderTest {
         final long startTime2 = startTime1 + 10L;
         final long spanId2 = 2L;
         Span span1 = createSpan(startTime1, spanId1);
-        SpanEvent event1_0 = createSpanEvent(span1, 1, (short)0);
-        SpanEvent event1_1 = createSpanEvent(span1, 2, (short)1);
-        SpanEvent asyncEvent1_0 = createAsyncSpanEvent(span1, 1, (short)0, 1);
-        SpanEvent asyncEvent1_1 = createAsyncSpanEvent(span1, 2, (short)1, 1);
+        SpanEvent event1_0 = createSpanEvent(span1, 1, (short) 0);
+        SpanEvent event1_1 = createSpanEvent(span1, 2, (short) 1);
+        SpanEvent asyncEvent1_0 = createAsyncSpanEvent(span1, 1, (short) 0, 1, (short) 1);
+        SpanEvent asyncEvent1_1 = createAsyncSpanEvent(span1, 2, (short) 1, 1, (short) 1);
         Span span2 = createSpan(startTime2, spanId2);
-        SpanEvent event2_0 = createSpanEvent(span2, 0, (short)0);
-        SpanEvent event2_1 = createSpanEvent(span2, 1, (short)1);
-        SpanEvent asyncEvent2_0 = createAsyncSpanEvent(span2, 0, (short)0, 1);
+        SpanEvent event2_0 = createSpanEvent(span2, 0, (short) 0);
+        SpanEvent event2_1 = createSpanEvent(span2, 1, (short) 1);
+        SpanEvent asyncEvent2_0 = createAsyncSpanEvent(span2, 0, (short) 0, 2, (short) 1);
         @SuppressWarnings("unchecked")
-        final List<? extends TBase<?,?>> expectedOrder = Arrays.asList(
+        final List<? extends TBase<?, ?>> expectedOrder = Arrays.asList(
                 span1,
                 event1_0,
                 event1_1,
@@ -121,47 +166,41 @@ public class OrderedSpanRecorderTest {
         );
         // when
         @SuppressWarnings("unchecked")
-        final List<? extends TBase<?,?>> listToBeHandled = Arrays.asList(
+        final List<? extends TBase<?, ?>> listToBeHandled = Arrays.asList(
                 span1, event1_0, event1_1, span2, event2_0, event2_1, asyncEvent1_0, asyncEvent1_1, asyncEvent2_0
         );
         Collections.shuffle(listToBeHandled);
-        for (TBase<?,?> base : listToBeHandled) {
+        for (TBase<?, ?> base : listToBeHandled) {
             this.recorder.handleSend(base);
         }
         // then
         ByteArrayOutputStream baos = new ByteArrayOutputStream();
         this.recorder.print(new PrintStream(baos));
         this.logger.debug(baos.toString());
-        for (TBase<?,?> expectedBase : expectedOrder) {
-            TBase<?,?> actualBase = this.recorder.pop();
+        for (TBase<?, ?> expectedBase : expectedOrder) {
+            TBase<?, ?> actualBase = this.recorder.pop();
             assertSame(expectedBase, actualBase);
         }
         assertNull(this.recorder.pop());
     }
-    
+
     private SpanEvent createSpanEvent(Span associatedSpan, int startElapsed, short sequence) {
-        return createAsyncSpanEvent(associatedSpan, startElapsed, sequence, UNSET_ASYNC_ID);
+        return createAsyncSpanEvent(associatedSpan, startElapsed, sequence, UNSET_ASYNC_ID, UNSET_ASYNC_SEQUENCE);
     }
-    
-    private SpanEvent createAsyncSpanEvent(Span associatedSpan, int startElapsed, short sequence, int asyncId) {
-        if (startElapsed < 0) {
-            throw new IllegalArgumentException("startElapsed cannot be less than 0");
-        }
-        if (sequence < 0) {
-            throw new IllegalArgumentException("sequence cannot be less than 0");
-        }
-        if (asyncId < 0) {
-            throw new IllegalArgumentException("asyncId cannot be less than 0");
-        }
+
+    private SpanEvent createAsyncSpanEvent(Span associatedSpan, int startElapsed, short sequence, int asyncId, short asyncSequence) {
         SpanEvent event = new SpanEvent(associatedSpan);
         event.setStartElapsed(startElapsed);
         event.setSequence(sequence);
         if (asyncId != UNSET_ASYNC_ID) {
             event.setAsyncId(asyncId);
         }
+        if (asyncSequence != UNSET_ASYNC_SEQUENCE) {
+            event.setAsyncSequence(asyncSequence);
+        }
         return event;
     }
-    
+
     private Span createSpan(long startTime, long spanId) {
         Span span = new Span();
         span.setStartTime(startTime);