Issue #342: Threaded Test - Failed to commit transaction: Unexpected internal exception

Hi

I'm trying to create a simple producer-consumer queue scenario but am getting the followin exception:

Caused by: java.lang.NullPointerException
at com.objectdb.o.VAR.L(VAR.java:254)
at com.objectdb.o.VAR.K(VAR.java:216)
at com.objectdb.o.SYR.v(SYR.java:477)
at com.objectdb.o.QRC.u(QRC.java:170)
at com.objectdb.o.QRM.UR(QRM.java:242)
at com.objectdb.o.MST.UR(MST.java:887)
at com.objectdb.o.WRA.UR(WRA.java:286)
at com.objectdb.o.WSM.UR(WSM.java:113)
at com.objectdb.o.QRR.g(QRR.java:220)
at com.objectdb.o.QRR.b(QRR.java:143)
at com.objectdb.jpa.JpaQuery.getSingleResult(JpaQuery.java:645)

This was using v2.2.7

The same test used to work in v2.2.0

I've attached the stripped down example that I'm running along with a file containing the full stack trace that I'm getting.

Let me know if you need any further information or if I'm doing anything wrong.

Thanks,

Richard

Also if I run the example code with fewer consumer (I just tried 2) it seems to just hang on the "take" commit.

I've attached the objectdb log from these runs if that helps.

The following test case is based on your example (some changes were required to pass compilation). It reproduces the deadlock, which is now fixed in build 2.2.7_01, but the other exception is not thrown.

Please check build 2.2.7_01 and if the exception is still thrown try to change the following test to reproduce it.

package com.objectdb.test.bug.issue;

import java.util.ArrayList;

import javax.persistence.*;

import junit.framework.Assert;
import net.sourceforge.groboutils.junit.v1.*;

import org.junit.Test;


public class T342 {
    @Test
    public void testMultiThreadedEntryPipe() {
        EntityManagerFactory emf = Persistence.createEntityManagerFactory(
            "$objectdb/db/testMultiThreadedEntryPipe.odb");
        try {
            int msgs = 1000;
            ArrayList<TestRunnable> runnables = new ArrayList<TestRunnable>();
            for(int i = 1; i < 6; i++)
                runnables.add(new ObjectDbProducer("p" + i, emf, msgs));
            for(int i = 1; i < 6; i++)
                runnables.add(new ObjectDbConsumer("c" + i, emf, msgs));
            TestRunnable[] trs = runnables.toArray(
                new TestRunnable[runnables.size()]);
            MultiThreadedTestRunner mttr = new MultiThreadedTestRunner(trs);
            mttr.runTestRunnables();
        }
        catch (Throwable e) {
            e.printStackTrace();
            Assert.fail();
        } finally {
            emf.close();
        }
    }

    private class ObjectDbProducer extends TestRunnable {
        private String _name;
        private EntityManagerFactory _emf;
        private int _num;
        public ObjectDbProducer(String name, EntityManagerFactory emf, int num) {
            _name = name;
            _emf = emf;
            _num = num;
        }
        @Override
        public void runTest() throws Throwable {
            for(int i=0; i<_num; i++) {
                Point p = new Point(i, i + 1);
                put(p);
                System.out.println("put " + p);
            }
        }
       
        public void put(Point p) {
            EntityManager em = _emf.createEntityManager();
            em.getTransaction().begin();
            try {
                em.persist(p);
                em.getTransaction().commit();
            }
            catch(Exception e) {
                if(em.getTransaction().isActive())
                    em.getTransaction().rollback();
                throw new RuntimeException("Error putting message on objectdb queue", e);
            }
            finally {
                em.close();
            }
        }
    }

    private class ObjectDbConsumer extends TestRunnable {
        private String _name;
        private EntityManagerFactory _emf;
        private int _num;
        public ObjectDbConsumer(String name, EntityManagerFactory emf, int num) {
            _name = name;
            _emf = emf;
            _num = num;
        }
        @Override
        public void runTest() throws Throwable {
            for(int i=0; i<_num; i++) {
                Point p = take();
                assert p != null;
            }
        }
       
        public synchronized Point take() {
            EntityManager em = _emf.createEntityManager();
            em.getTransaction().begin();
            try {
                Query q = em.createQuery("SELECT p FROM Point p");
                Point p = (Point)q.setMaxResults(1).setLockMode(
                    LockModeType.PESSIMISTIC_WRITE).getSingleResult();
                em.remove(p);
                em.getTransaction().commit();
                System.out.println("take " + p);
                return p;
            }
            catch(NoResultException nre) {
                //the queue is currently empty
                return null;
            }
            catch(LockTimeoutException lte) {
                //another consumer is competing for the same object
                return null;
            }
            catch(Exception e) {
                throw new RuntimeException(
                    "Error taking message from ObjectDB queue", e);
            }
            finally {
                if(em.getTransaction().isActive())
                    em.getTransaction().rollback();
                em.close();
            }
        }
    }
   
    @Entity
    public static class Point
    {
        private int x, y;
       
        public Point(int x, int y) {
            this.x = x;
            this.y = y;
        }
    }
}

Initial tests look good - thanks for the quick response.

I'm also unable to recreate the exception using the new build so it looks like that is no longer a problem.

Thanks again!

Thank you for this report and for the update.

A follow up questions to this - I'm not sure if its linked so let me know if I should move it to the forums.

I've changed my test to closer represent a real scenario. Now each object that gets saved carries a 2mb string payload. The rest of the test in the same - 5 producer threads saving 1000 objects each and 5 consumer threads. Code is attached. I'm running with v2.2.7_01 and the default objectDb config.

I've limited the test to a jvm size of 1gb (-Xms1g -Xmx1g) partly for environment reasons, partly because it seems that this should be ok given the test parameters (let me know if you think i've got this wrong though...)

The consumers run a lot slower than the producers as I'm synchronising access to force the queue behaviour so at some point the producers are all finished and the consumers are still running. Shortly after this (approx 700 further consumer requests) I get an out of memory exception.

The test doesnt hold on to any objects beyond the scope of each put or take so I wouldve thought the max data I'm holding should be around 20mb (5 consumers * 5 producers * 2mb) and when the consumers alone are running this should drop to a max of around 10mb (5 consumers * 2mb). I tried adding an "evictAll" call after each take in case the objects were being cached but this had no effect.

I guess my question is: are my assumptions wrong and this test is doomed to failure or is there a problem somewhere, either with my code, my use of objectdb config settings, or objectdb itself?

Thanks for your help!

It seems that there was a bug in evaluating the size of cached query results for queries that were run by getSingleResult. The result size was evaluated to fixed size of 100 bytes, keeping much more results in cache than allowed by the defined cache size. Please try build 2.2.7_02 that should fix it.

About the consumer / producer rate - try adding synchronized to the put method - it seems that when both put and take are synchronized the consumer is fast as the producer (even though query operations are more expansive than persist).

That seems to have done the trick - thanks.

However, on to the next problem. I've now updated my test so that the persistable object has an Id and I get another Unexpected internal exception. The Id is a string and for the test I'm generating a random UUID - I understand this will be slower than using a generated id or a long, etc, but I'm constrained by an existing system. If I remove the @Id attribute it works ok again.

My final object will also have a CreateTime (long) and Priority (int) as I want to query for the oldest object with the highest priority. I'm hoping to add these fields as indexes.

I've attached the updated test code, the full stack trace from my log and the objectdb log.

This was another bug. Please try build 2.2.7_03.

Great - that seems to have fixed it - thanks.

One final (hopefully!) question:

I've now got to the full functionality that I need. This changes the test in the following ways:

1. Producer thread inserts object into the "queue" database
2. Consumer thread reads and removes an object from the "queue" database
3. Consumer thread inserts object into a "work in progress" database
4. Consumer thread removes object from "work in progress" database

In the simple case this works ok. Obviously the runtime is longer due to the second insert/remove but it runs at a relatively consistent pace and completes ok.

However, in the real case I'd like the consumer to read from the "queue" database based on a priority and creation time. The query looks like:

SELECT p FROM IdPoint p ORDER by p.priority DESC, p.createTime

When I run the test using this query is eventually grinds to a halt. No errors are thrown and process does continue but incredibly slowly. I've tried with the priority and createTime fields as both index and non-index but this doesn't make any difference.

If I dont enable the "work in progress" database then this query works ok so it seems to be a problem only when running the ordered query and writing to the second database.

Again, I'm not sure if this is a problem with the approach I'm taking or something in objectdb itself.

I've attached the test case I'm running in the form that causes the problem. The ObjectDbQueue object takes a flag which can be used to switch of the "work in progress" functionality for comparrison

Apologies for taking up so much of your time!

It seems that this version of the test has a memory leakage due to a missing EntityManager's close (in removeFromWip). I didn't see the halt - but maybe I stopped the test too early. I cannot explain the effect of the sort either.

Please try running the test after adding the missing close + enhancing the entity classes.

Good spot on the missing close but unfortunately it hasnt solved the problem. I also tried enhancing the classes using the javaagent method but to no avail.

I've put some timing around the logging to show the slowdown better.

At the start the processing is reasonably responsive with a put/take every 50-100ms:

2011-06-17 15:17:50,659 Producer p3 putting point 2
2011-06-17 15:17:50,675 Producer p1 putting point 3
2011-06-17 15:17:51,519 Producer p2 putting point 3
2011-06-17 15:17:51,566 Producer p4 putting point 3
2011-06-17 15:17:51,613 Producer p5 putting point 3
2011-06-17 15:17:51,644 Producer p3 putting point 3
2011-06-17 15:17:51,659 Producer p1 putting point 4
2011-06-17 15:17:52,050 Consumer c3 taking point 0 - 4e238206-4a4c-4f9a-8c65-fcf7b178be9a - (0, 1)
2011-06-17 15:17:52,128 Consumer c1 taking point 0 - 005d74f1-95ee-49a3-b272-64218f914b0a - (0, 1)
2011-06-17 15:17:52,175 Consumer c2 taking point 0 - cd76ee37-8f61-41b2-ac3a-b4e2534560d8 - (0, 1)
2011-06-17 15:17:52,238 Consumer c4 taking point 0 - d101e8d7-b52d-4d76-84f7-ace0a1420e73 - (0, 1)
2011-06-17 15:17:52,316 Producer p2 putting point 4
2011-06-17 15:17:52,316 Consumer c5 taking point 0 - ee5030a8-8b59-4592-899f-5220d4d8baec - (0, 1)
2011-06-17 15:17:52,331 Producer p4 putting point 4
2011-06-17 15:17:52,347 Producer p5 putting point 4
2011-06-17 15:17:52,394 Producer p3 putting point 4
2011-06-17 15:17:52,409 Producer p1 putting point 5
2011-06-17 15:17:52,488 Consumer c3 taking point 1 - 89ee0003-7861-40db-8f04-93dd037aa4f8 - (1, 2)
2011-06-17 15:17:52,534 Consumer c1 taking point 1 - 153be145-158b-4ccd-8afb-9c9bdafea59a - (1, 2)
2011-06-17 15:17:52,581 Consumer c2 taking point 1 - 9916ee37-36b4-48aa-a9df-62e3b0d24118 - (1, 2)
2011-06-17 15:17:52,628 Consumer c4 taking point 1 - 84280aa6-ac46-48d3-9248-e9672a13e143 - (1, 2)

After letting it run for a couple of minutes this drops down to a put/take every 10s or so:

2011-06-17 15:20:41,282 Producer p3 putting point 51
2011-06-17 15:20:52,610 Consumer c3 taking point 37 - a9ff831a-b2f9-40d8-ba44-2240afe6ef0e - (37, 38)
2011-06-17 15:21:03,360 Consumer c1 taking point 37 - 1cc644b1-6282-46fc-a634-7e0cc7234bdd - (37, 38)
2011-06-17 15:21:03,391 Producer p1 putting point 52
2011-06-17 15:21:03,548 Producer p2 putting point 52
2011-06-17 15:21:14,704 Consumer c2 taking point 37 - 21dc22d3-856e-4574-9d9f-82e25a14bc20 - (37, 38)
2011-06-17 15:21:25,922 Consumer c4 taking point 37 - 4ff6c763-0aac-4605-a8ac-0edae2a3b843 - (37, 38)
2011-06-17 15:21:25,954 Producer p4 putting point 52
2011-06-17 15:21:38,016 Consumer c5 taking point 37 - 681cda26-30ce-4711-b776-51f583ad23b1 - (37, 38)
2011-06-17 15:21:38,125 Producer p5 putting point 52
2011-06-17 15:21:38,203 Producer p3 putting point 52
2011-06-17 15:21:50,125 Consumer c3 taking point 38 - 4ab07fa0-4ccd-4bc1-8c4d-ac913d442363 - (38, 39)
2011-06-17 15:22:00,641 Consumer c1 taking point 38 - a416e4b2-4173-408e-8655-ced8a18addfd - (38, 39)
2011-06-17 15:22:00,734 Producer p1 putting point 53
2011-06-17 15:22:00,781 Producer p2 putting point 53
2011-06-17 15:22:11,047 Consumer c2 taking point 38 - fff9cdc5-8a2d-4c8e-8ad2-fe17900abd27 - (38, 39)
2011-06-17 15:22:21,828 Producer p4 putting point 53
2011-06-17 15:22:21,937 Consumer c4 taking point 38 - 7be6f6c1-5e1d-4b2f-8227-ea2d4c9dce3f - (38, 39)

This degrades further for as long as I let it run. I've also deployed this test on better hardware (8 core, 64GB) and allowed a jvm size up to 3GB but have hit the same results and always at a similar stage in the test.

If you cant recreate the behaviour with the test (I've attached a version with the close bug fixed btw) then I guess it must be a problem somewhere in my environment.

Thanks anyway for your help, especially with the previous issues

Here are the results of my run (new test, no enhancement):

2011-06-17 17:46:28,093 Producer p1 putting point 0
2011-06-17 17:46:28,125 Producer p5 putting point 0
2011-06-17 17:46:28,125 Producer p4 putting point 0
2011-06-17 17:46:28,125 Producer p3 putting point 0
2011-06-17 17:46:28,093 Producer p2 putting point 0
2011-06-17 17:46:30,343 No point
2011-06-17 17:46:30,687 Producer p4 putting point 1
2011-06-17 17:46:30,765 Producer p1 putting point 1
2011-06-17 17:46:30,875 Producer p5 putting point 1
2011-06-17 17:46:30,953 Producer p2 putting point 1
2011-06-17 17:46:31,046 Producer p3 putting point 1
2011-06-17 17:46:31,609 Consumer c1 taking point 0 - 04f73cd4-e069-444e-af80-a1a0382270fb - (0, 1)
2011-06-17 17:46:31,812 Consumer c5 taking point 0 - 06df102a-28f3-48ce-b664-51a5de9394f1 - (0, 1)
2011-06-17 17:46:31,875 Consumer c2 taking point 0 - 286142a7-1f17-467f-a196-14f2a98614cc - (0, 1)
2011-06-17 17:46:31,906 No point
2011-06-17 17:46:31,968 Consumer c4 taking point 0 - a57173da-7d5e-485a-b299-f7156f76e3f6 - (0, 1)
2011-06-17 17:46:31,984 Producer p3 putting point 2
2011-06-17 17:46:32,125 Producer p3 putting point 3
2011-06-17 17:46:32,187 Producer p2 putting point 2
2011-06-17 17:46:32,218 Consumer c1 taking point 1 - b919ae43-c9a8-4f3b-ae9b-3ba5b12e390d - (0, 1)
2011-06-17 17:46:32,296 Producer p5 putting point 2
2011-06-17 17:46:32,359 Producer p5 putting point 3
2011-06-17 17:46:32,500 Producer p1 putting point 2
2011-06-17 17:46:32,843 Producer p4 putting point 2
2011-06-17 17:46:32,906 Producer p1 putting point 3
2011-06-17 17:46:32,968 Producer p5 putting point 4
2011-06-17 17:46:33,187 Consumer c1 taking point 2 - 310b364b-7619-4ede-a367-facf94fb18ef - (1, 2)
2011-06-17 17:46:33,234 Producer p2 putting point 3
2011-06-17 17:46:33,281 Consumer c2 taking point 1 - 473832e7-f6d5-4391-aba6-5dd04e9af6c6 - (1, 2)
2011-06-17 17:46:33,359 Producer p3 putting point 4
2011-06-17 17:46:33,531 Consumer c4 taking point 1 - 9575bb87-a767-43b2-b82e-75cf61b17d7c - (1, 2)
2011-06-17 17:46:33,656 Consumer c5 taking point 1 - 38ef12ff-5d49-4de5-b423-8e4e7e8f0b4b - (1, 2)
2011-06-17 17:46:33,703 Producer p3 putting point 5
2011-06-17 17:46:33,703 Consumer c4 taking point 2 - e0d1807f-f3ac-4318-889d-5310df7699c0 - (1, 2)
2011-06-17 17:46:33,906 Consumer c1 taking point 3 - ddc39f04-1d23-42f4-93ae-169b146b46e1 - (2, 3)
2011-06-17 17:46:33,921 Producer p2 putting point 4
2011-06-17 17:46:33,953 Consumer c2 taking point 2 - 91dbfb17-8d2b-4f8b-8013-6d8aa42e363b - (3, 4)
2011-06-17 17:46:33,984 Producer p5 putting point 5
2011-06-17 17:46:34,031 Producer p1 putting point 4
2011-06-17 17:46:34,140 Consumer c3 taking point 0 - 79e2a270-24ec-40d7-8da2-dc02dbc363e5 - (2, 3)
2011-06-17 17:46:34,140 Producer p4 putting point 3
2011-06-17 17:46:34,187 Producer p1 putting point 5
2011-06-17 17:46:34,281 Consumer c2 taking point 3 - 3e60e5ff-8e09-4fc2-903c-bab54d322a1f - (2, 3)
2011-06-17 17:46:34,343 Producer p5 putting point 6
2011-06-17 17:46:34,359 Consumer c1 taking point 4 - b47b46c5-f364-4128-b536-2d1e794cd0a2 - (3, 4)
2011-06-17 17:46:34,437 Producer p2 putting point 5
2011-06-17 17:46:34,578 Consumer c4 taking point 3 - 4f4139c1-5861-4185-96e4-35b7ea3d2a5f - (2, 3)
2011-06-17 17:46:34,625 Producer p3 putting point 6
2011-06-17 17:46:34,656 Consumer c5 taking point 2 - 2bd521ac-9a34-41ee-8463-d10626c92446 - (2, 3)
2011-06-17 17:46:34,703 Producer p2 putting point 6
2011-06-17 17:46:34,812 Producer p5 putting point 7
2011-06-17 17:46:34,828 Consumer c1 taking point 5 - 323ac262-3227-453e-821e-d10762c471fd - (3, 4)
2011-06-17 17:46:34,953 Producer p1 putting point 6
2011-06-17 17:46:34,953 Consumer c2 taking point 4 - 348921d7-5182-498d-81a1-741afdfc4182 - (4, 5)

...

2011-06-17 17:52:24,046 Consumer c1 taking point 467 - b440ad13-068c-4af6-8236-f2cee760f4d4 - (515, 516)
2011-06-17 17:52:24,046 Producer p1 putting point 521
2011-06-17 17:52:24,156 Producer p5 putting point 519
2011-06-17 17:52:24,156 Consumer c4 taking point 384 - 87accd6f-53c6-41b3-8088-eb8c4bf6c047 - (515, 516)
2011-06-17 17:52:24,281 Producer p2 putting point 519
2011-06-17 17:52:24,281 Consumer c3 taking point 379 - 11344235-66b9-4c80-b6ca-e6b947cb1bd8 - (262, 263)
2011-06-17 17:52:24,437 Producer p3 putting point 264
2011-06-17 17:52:24,453 Consumer c5 taking point 447 - 22b4261b-b6b5-4f8f-9fcb-b055726fa1f0 - (516, 517)
2011-06-17 17:52:24,593 Producer p2 putting point 520
2011-06-17 17:52:24,593 Consumer c3 taking point 380 - ae7bd389-89bf-407d-a38e-f90bff2aa452 - (516, 517)
2011-06-17 17:52:24,703 Consumer c4 taking point 385 - 6cb865a7-0ecc-484e-99c0-35f20ec4775e - (518, 519)
2011-06-17 17:52:24,703 Producer p5 putting point 520
2011-06-17 17:52:24,812 Consumer c1 taking point 468 - 058cdf67-5937-429a-932a-00f11891bf27 - (258, 259)
2011-06-17 17:52:24,812 Producer p1 putting point 522
2011-06-17 17:52:24,968 Consumer c2 taking point 391 - e640694d-f5c8-4880-8866-fb9151ef3521 - (519, 520)
2011-06-17 17:52:24,968 Producer p4 putting point 260
2011-06-17 17:52:25,078 Producer p1 putting point 523
2011-06-17 17:52:25,078 Consumer c1 taking point 469 - aedb092f-cb2a-48b6-86d3-1e8f6629579c - (517, 518)
2011-06-17 17:52:25,203 Producer p5 putting point 521
2011-06-17 17:52:25,203 Consumer c4 taking point 386 - 2dfb8bfc-e869-4df6-8404-c56ee8a5eba3 - (517, 518)
2011-06-17 17:52:25,312 Producer p2 putting point 521
2011-06-17 17:52:25,312 Consumer c3 taking point 381 - 2fc565bd-70fa-4d79-b9e2-35570300265b - (263, 264)
2011-06-17 17:52:25,468 Producer p3 putting point 265
2011-06-17 17:52:25,468 Consumer c5 taking point 448 - 566c7aee-5baa-497c-8faa-1e43d59d1c7e - (518, 519)
2011-06-17 17:52:25,609 Producer p2 putting point 522
2011-06-17 17:52:25,609 Consumer c3 taking point 382 - c23b0ae1-f4a2-4a35-bed2-0e5005d25c31 - (518, 519)
2011-06-17 17:52:25,734 Producer p5 putting point 522
2011-06-17 17:52:25,734 Consumer c4 taking point 387 - 3a87c849-680a-4388-b740-e06f0ee968ad - (520, 521)
2011-06-17 17:52:25,859 Producer p1 putting point 524
2011-06-17 17:52:25,859 Consumer c1 taking point 470 - 7cac4531-ef4c-428d-9374-0901c2352dc2 - (259, 260)
2011-06-17 17:52:25,968 Consumer c2 taking point 392 - d2086471-0aa9-45bb-8dee-6cad2821ca6e - (521, 522)
2011-06-17 17:52:25,968 Producer p4 putting point 261
2011-06-17 17:52:26,187 Producer p1 putting point 525
2011-06-17 17:52:26,187 Consumer c1 taking point 471 - eafd9e1e-f83d-429d-98d7-145827060040 - (519, 520)
2011-06-17 17:52:26,312 Producer p5 putting point 523
2011-06-17 17:52:26,312 Consumer c4 taking point 388 - 60760479-3dc7-4bb6-a1c0-84a46f8c797e - (519, 520)
2011-06-17 17:52:26,453 Consumer c3 taking point 383 - 31c54b61-13df-4e70-88f3-c3250ee6db3e - (264, 265)
2011-06-17 17:52:26,468 Producer p2 putting point 523
2011-06-17 17:52:26,609 Consumer c5 taking point 449 - 1cc868ca-877f-486d-abed-4a7a49c6484f - (520, 521)
2011-06-17 17:52:26,609 Producer p3 putting point 266
2011-06-17 17:52:26,718 Producer p2 putting point 524
2011-06-17 17:52:26,718 Consumer c3 taking point 384 - 1e03de90-b2e2-4377-9664-66eb4235c954 - (520, 521)
2011-06-17 17:52:26,843 Producer p5 putting point 524
2011-06-17 17:52:26,843 Consumer c4 taking point 389 - 3bb2298b-de20-4e01-b576-1150986bda5e - (522, 523)
2011-06-17 17:52:26,953 Consumer c1 taking point 472 - 7653c3bd-63d9-447e-9d04-39a5aee5487a - (260, 261)
2011-06-17 17:52:26,953 Producer p1 putting point 526

If you have more details please post them. This session helped fixing some important issues in ObjectDB, and apparently you are facing now another issue that may needs a fix on the ObjectDB side. Thanks you for all these reports.

This may be something to do with the Java version...

I was originally running the test using v1.5 but I just tried it in v1.6 and it seems much smoother. This is good & bad news though as it may be difficult to update the main application to use v1.6!

I tried the test with JDK 1.5 and had the performance problem as you described.

The problem is indeed in running a query with sort:

SELECT p FROM IdPoint p ORDER by p.priority DESC, p.createTime

Because the objects in this test are large, when the queue becomes full and the total size of these objects is larger than the memory processing threshold - temporary files are used, which is very slow.

I found out that using the following hint helps:

  Query q = em.createQuery(
    "SELECT p FROM IdPoint p ORDER by p.priority DESC, p.createTime");
  q.setHint("objectdb.result-fetch", "LAZY");

because it affects the query plan selection, and a more appropriate query plan is used for this case.

Probably the query planner should be improved to handle this without hints.

Anyway, dividing the entity object into two entity objects - small metadata and large data - is probably the right solution in this case.

I don't know why we haven't seen the problem in JDK 1.6 - maybe the consumer keeps up with the producer rate (because of some unknown differences between the JDKs) and the queue remains almost empty.

Agreed - I've split the entity and performance is much improved and consistent. Thanks for your help with it!

By the way,  the sort could be more efficient with a composite index that contains both priority and creationTime (in the same index). If the sort direction of priority and createTime is the same (no DESC, or DESC for both) - it could be even more efficient, because it may eliminate the need to sort at all (you can reverse the meaning of the priority field).

But this may affect mainly if there are many objects to sort, and of course maintaining the index has its own overhead.