Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-4377

Failure in UdfExecutorTest.HiveStringsTest

    Details

      Description

      I suspect this is a flaky test problem, as I havent seen it before and it manifested after 13455b5a24a9d4d009d1dd0d72944c6cacd54829 but before or in c24e9da914e1d5e5dabd1bded5a78452bccff9b5

      13:52:35.660 Running org.apache.impala.hive.executor.UdfExecutorTest
      13:52:35.660 Tests run: 3, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 0.086 sec <<< FAILURE! - in org.apache.impala.hive.executor.UdfExecutorTest
      13:52:35.660 HiveStringsTest(org.apache.impala.hive.executor.UdfExecutorTest)  Time elapsed: 0.037 sec  <<< FAILURE!
      13:52:35.660 	at org.apache.impala.hive.executor.UdfExecutorTest.TestUdfImpl(UdfExecutorTest.java:327)
      13:52:35.660 	at org.apache.impala.hive.executor.UdfExecutorTest.TestHiveUdf(UdfExecutorTest.java:349)
      13:52:35.660 	at org.apache.impala.hive.executor.UdfExecutorTest.HiveStringsTest(UdfExecutorTest.java:406)
      13:52:35.660   UdfExecutorTest.HiveStringsTest:406->TestHiveUdf:349->TestUdfImpl:327 arrays first differed at element [0]; expected:<-96> but was:<2>
      13:52:35.660 Tests run: 533, Failures: 1, Errors: 0, Skipped: 20
      

        Issue Links

          Activity

          Hide
          jbapple Jim Apple added a comment -

          I've started builds with all of the commits in question to see which one (if any) can reliably reproduce the error.

          Show
          jbapple Jim Apple added a comment - I've started builds with all of the commits in question to see which one (if any) can reliably reproduce the error.
          Hide
          bharathv bharath v added a comment -

          I'm not able to repro it locally. Are your builds reliably reproducing it?

          Show
          bharathv bharath v added a comment - I'm not able to repro it locally. Are your builds reliably reproducing it?
          Hide
          jbapple Jim Apple added a comment -

          Nope. Looks like a flaky test.

          Show
          jbapple Jim Apple added a comment - Nope. Looks like a flaky test.
          Hide
          alex.behm Alexander Behm added a comment -

          I've been looking at this issue and I it's very hard to tell what's going on.

          • There have been no recent code changes in the affected paths as far as I can tell.
          • The diagnostics from the failed tests are not very useful.
          • The issue does not reproduce for me locally or in Jenkins runs.

          I'm going to improve the logging when there is such a test failure, so that when we hit this next time we have more useful info.

          I suggest downgrading until we hit this again and have better logging.

          Show
          alex.behm Alexander Behm added a comment - I've been looking at this issue and I it's very hard to tell what's going on. There have been no recent code changes in the affected paths as far as I can tell. The diagnostics from the failed tests are not very useful. The issue does not reproduce for me locally or in Jenkins runs. I'm going to improve the logging when there is such a test failure, so that when we hit this next time we have more useful info. I suggest downgrading until we hit this again and have better logging.
          Hide
          alex.behm Alexander Behm added a comment -

          Patch for better diagnostics: http://gerrit.cloudera.org:8080/4881

          Downgrading issue until we hit it again.

          Show
          alex.behm Alexander Behm added a comment - Patch for better diagnostics: http://gerrit.cloudera.org:8080/4881 Downgrading issue until we hit it again.
          Hide
          alex.behm Alexander Behm added a comment -

          The bug is actually easy to repro when increasing the number of test iterations. Looks like a use-after-free problem with memory allocated with Unsafe. Pretty sure it's a test framework problem and a product bug, but we will definitely hit this problem again in test runs.

          Show
          alex.behm Alexander Behm added a comment - The bug is actually easy to repro when increasing the number of test iterations. Looks like a use-after-free problem with memory allocated with Unsafe. Pretty sure it's a test framework problem and a product bug, but we will definitely hit this problem again in test runs.
          Hide
          alex.behm Alexander Behm added a comment -

          commit 6d1a130d85562aad694ef78522e471b7cf025c30
          Author: Alex Behm <alex.behm@cloudera.com>
          Date: Fri Oct 28 16:33:40 2016 -0700

          IMPALA-4377: Fix Java UDF-arg buffer use-after-free in UdfExecutorTest.

          The bug is simplest to explain with the old buggy test code below.
          I added comments in the code to explain the bug.

          // We used this for creating Text UDF arguments before invoking a UDF.
          Writable createText(String v)

          { // Note that 'w' does not own the native buffer backing the string, // explained below. ImpalaTextWritable w = new ImpalaTextWritable(createStringValue(v)); return w; }

          long createStringValue(String v)

          { byte[] array = v.getBytes(); long ptr = allocate(16); UnsafeUtil.UNSAFE.putInt(ptr + 8, 0); ImpalaStringWritable sw = new ImpalaStringWritable(ptr); // This allocates a new native buffer and sets it as a member // of 'sw'. The native buffer is freed in sw.finalize(). // However, after this function there are no more references // to 'sw', so the GC is allowed to free it. When that happens // the UDF argument's native memory is gone and we get garbage // UDF evaluations. sw.set(array, 0, array.length); return ptr; }

          This change also includes logging improvements to make similar
          issues easier to diagnose in the future.

          Testing: The bug was easy to reproduce by increasing the number
          of runs in TestUdfImpl() to a large number. After this patch
          I could not reproduce the issue anymore.

          Change-Id: Id94130715e4f342e4dd2f6cd137ac1eb7b1ecf2d
          Reviewed-on: http://gerrit.cloudera.org:8080/4881
          Reviewed-by: Matthew Jacobs <mj@cloudera.com>
          Tested-by: Internal Jenkins

          Show
          alex.behm Alexander Behm added a comment - commit 6d1a130d85562aad694ef78522e471b7cf025c30 Author: Alex Behm <alex.behm@cloudera.com> Date: Fri Oct 28 16:33:40 2016 -0700 IMPALA-4377 : Fix Java UDF-arg buffer use-after-free in UdfExecutorTest. The bug is simplest to explain with the old buggy test code below. I added comments in the code to explain the bug. // We used this for creating Text UDF arguments before invoking a UDF. Writable createText(String v) { // Note that 'w' does not own the native buffer backing the string, // explained below. ImpalaTextWritable w = new ImpalaTextWritable(createStringValue(v)); return w; } long createStringValue(String v) { byte[] array = v.getBytes(); long ptr = allocate(16); UnsafeUtil.UNSAFE.putInt(ptr + 8, 0); ImpalaStringWritable sw = new ImpalaStringWritable(ptr); // This allocates a new native buffer and sets it as a member // of 'sw'. The native buffer is freed in sw.finalize(). // However, after this function there are no more references // to 'sw', so the GC is allowed to free it. When that happens // the UDF argument's native memory is gone and we get garbage // UDF evaluations. sw.set(array, 0, array.length); return ptr; } This change also includes logging improvements to make similar issues easier to diagnose in the future. Testing: The bug was easy to reproduce by increasing the number of runs in TestUdfImpl() to a large number. After this patch I could not reproduce the issue anymore. Change-Id: Id94130715e4f342e4dd2f6cd137ac1eb7b1ecf2d Reviewed-on: http://gerrit.cloudera.org:8080/4881 Reviewed-by: Matthew Jacobs <mj@cloudera.com> Tested-by: Internal Jenkins

            People

            • Assignee:
              alex.behm Alexander Behm
              Reporter:
              jbapple Jim Apple
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development