[ https://issues.apache.org/jira/browse/IMPALA-5142?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Pranay Singh resolved IMPALA-5142. ---------------------------------- Resolution: Resolved This issue has been resolved by the below checkin IMPALA-5142 EventSequence displays negative elapsed time. EventSequence::EventList which stores the Event in increasing time order may have at times Events that are not stored in increasing time order. This may happen when concurrently EventSequence::MarkEvent() is called for different Events in the same EventSequence. The incorrect time order of Event in EventList results in a negative value being displayed, which is the issue reported in this JIRA. The issue can be fixed either be re-ordering the lock in EventSequence::MarkEvent() or by sorting the EventList before printing. Reordering of lock in EventSequence::MarkEvent() will involve holding the lock across clock_gettime() so that approach is not taken. This patch fixes the issue by sorting the EventList in GetEvents() as this function is expected to return sorted list of events based on time. Testing: Ran all the front-end/backend and end-end tests. Change-Id: I8c944396d96473b17b453da3e913ffc56680a896 Reviewed-on: http://gerrit.cloudera.org:8080/8215 Reviewed-by: Dan Hecht <dhe...@cloudera.com> Tested-by: Impala Public Jenkins > EventSequence::MarkEvent() may record concurrent events out of serialized > order > ------------------------------------------------------------------------------- > > Key: IMPALA-5142 > URL: https://issues.apache.org/jira/browse/IMPALA-5142 > Project: IMPALA > Issue Type: Bug > Components: Distributed Exec > Affects Versions: Impala 2.7.0 > Reporter: Mostafa Mokhtar > Assignee: Pranay Singh > Priority: Trivial > Labels: ramp-up, trivial > > When the event for first dynamic filter is received ahead of all fragments > started the query timeline prints a negative time value for "fragment > instances started" > {code} > - Planning finished: 790.555ms (32.872ms) > Query Timeline: 2m40s > - Query submitted: 7.295ms (7.295ms) > - Planning finished: 1s397ms (1s390ms) > - Submit for admission: 3s059ms (1s661ms) > - Completed admission: 3s087ms (27.810ms) > - Ready to start 90 fragment instances: 3s527ms (440.540ms) > - First dynamic filter received: 7s851ms (4s323ms) > - All 90 fragment instances started: 7s851ms (-88037.000ns) > - Rows available: 2m28s (2m20s) > - First row fetched: 2m28s (51.725ms) > - Unregister query: 2m30s (1s459ms) > - ComputeScanRangeAssignmentTimer: 770.794ms > {code} > Query timeline when filter arrive after all fragments starting. > {code} > Query Timeline: 17s011ms > - Query submitted: 174.449us (174.449us) > - Planning finished: 209.847ms (209.672ms) > - Submit for admission: 255.819ms (45.971ms) > - Completed admission: 256.212ms (393.074us) > - Ready to start 90 fragment instances: 283.582ms (27.370ms) > - All 90 fragment instances started: 627.013ms (343.430ms) > - First dynamic filter received: 954.223ms (327.209ms) > - Rows available: 16s393ms (15s439ms) > - First row fetched: 16s705ms (311.586ms) > - Unregister query: 16s871ms (165.908ms) > - ComputeScanRangeAssignmentTimer: 13.125ms > {code} -- This message was sent by Atlassian JIRA (v6.4.14#64029)