-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

View unanswered posts | View active topics


Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]


Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 8 posts ] 
  Previous topic | Next topic 
Author Message
hal18000
 Post subject: slowness in hibernate while iterating over 1000+objects
PostPosted: Thu Mar 30, 2006 7:32 pm 
Newbie

Joined: Tue Aug 02, 2005 5:04 pm
Posts: 15
I do a massive select w/ hibernate, do left join fetchs, DB logs verify that I hit the DB once then operate from hibernate objects from there, iterating through Product objects in a loop. Takes 100% CPU while iterating and 10+ seconds for 1-2k of objects, I ultimately want 50k objects so this will not scale.

This is a major roadblock for us and I've had similar problems like this, I want to get to the bottom of this or I will stop using hibernate, I'm sure I'm doing something wrong but as it is this isnt acceptable. Hibernate is amazing and I'm sure there's something I am missing. Thanks for any help.

Details:

Hibernate version:
3.0.5
Mapping documents:

Code between sessionFactory.openSession() and session.close():
Code:
    public List<Product> findByFilter(Integer start, Integer maxResults, String advertiser, String sku, String color, String size, String category, String description, String manufacturer) throws Exception {
        log.debug("finding Product instance by findByFilter, sku = "+sku);
        try {
           String hql = "from Product p left join fetch p.campaignMedias cm left join cm.campaign c left join fetch c.adType left join p.advertiser a left join a.account ";
           List<String> andQuery = new ArrayList<String>();
           if(sku != null)
           {
              sku = "%"+sku+"%";
              andQuery.add("p.sku like :sku");
           }
           if(color != null)
           {
              color = "%"+color+"%";
              andQuery.add("p.color like :color");
           }
           if(size != null)
           {
              size = "%"+size+"%";
              andQuery.add("p.size like :size");
           }
           if(category != null)
           {
              category = "%"+category+"%";
              andQuery.add("p.category like :category");
           }

           if(description != null)
           {
              description = "%"+description+"%";
              andQuery.add("p.description like :description");
           }

           if(manufacturer != null)
           {
              manufacturer = "%"+manufacturer+"%";
              andQuery.add("p.manufacturer like :manufacturer");
           }

           if(advertiser != null)
           {
              andQuery.add("p.advertiser.account.companyName = :advertiser");
           }
           if(andQuery.size() > 0)
           {
               String andQueryStr = StringUtils.join(andQuery.toArray()," and ");
              hql += " where "+andQueryStr;              
           }
           Query query = getCurrentSession().createQuery(hql);
           if(start != null && maxResults != null)
           {
              query.setFirstResult(start);
              query.setMaxResults(maxResults);
           }
           if(sku != null)
           {
              query.setString("sku", sku);
           }
           if(color != null)
           {
              query.setString("color", color);
           }
           if(size != null)
           {
              query.setString("size", size);
           }
           if(category != null)
           {
              query.setString("category", category);
           }
           if(description != null)
           {
              query.setString("description", description);
           }
           if(manufacturer != null)
           {
              query.setString("manufacturer", manufacturer);
           }
           if(advertiser != null)
           {
              query.setString("advertiser", advertiser);
           }
           List results = null;
           CacheMode cm =getCurrentSession().getCacheMode();
         try {
              getCurrentSession().setCacheMode(CacheMode.IGNORE);
            results = query.list();
         } catch (RuntimeException e) {
            // TODO Auto-generated catch block
            e.printStackTrace();
         } finally
         {
              getCurrentSession().setCacheMode(cm);
         }
         // go through list
         List<Product> prods = new ArrayList<Product>();
         for(Object[] obj : (List<Object[]>)results)
         {
            prods.add((Product)obj[0]);
         }
            log.debug("findByFilter successful, result size: " + results.size());
            return prods;
        }
        catch (Exception re) {
            log.error("find by example failed", re);
            throw re;
        }
   }
...

         String[] header = {"id","advertiser","manufacturer","productName","category","price",
               "saleprice","imageUrl","destinationUrl","description"};
         String[] headerDisplay = {"id","advertiser","designer","productName","category","price",
               "saleprice","imageUrl","destinationUrl","description"};

         for(Product prod : products)
         {
            String[] newArr = new String[header.length];
            int i;
            for(i=0;i<newArr.length;i++)
            {
               String field = header[i];
               String value = null;
               if(field.equals("destinationUrl"))
               {
                  TestTimer test = new TestTimer();
                  //value = CampaignMediaHelper.getClickUrl(prod,ch);
                  //System.out.println("Seconds for 1:"+test.getMilliseconds());
               }else if(field.equals("advertiser"))
               {
                  value = prod.getAdvertiser().getAccount().getCompanyName();
               }
               else
               {
                  value = BeanUtils.getProperty(prod,field);
               }
               if(value == null)
               {
                  value = "";
               }
               newArr[i] = value;
            }
            output += getTabbedLine(newArr);
            output += crlf;


Full stack trace of any exception that occurs:

Name and version of the database you are using:
postgres 8.1
The generated SQL (show_sql=true):

Debug level Hibernate log excerpt:
15:13:08,988 DEBUG Loader:978 - Initializing object from ResultSet: [com.forward
network.managerserver.db.maindb.datatransfer.CampaignMedia#280]
15:13:08,988 DEBUG BasicEntityPersister:1651 - Hydrating entity: [com.forwardnet
work.managerserver.db.maindb.datatransfer.CampaignMedia#280]
15:13:08,988 DEBUG IntegerType:86 - returning '236' as column: product2_17_1_
15:13:08,988 DEBUG IntegerType:86 - returning '21' as column: campaign3_17_1_
15:13:08,988 DEBUG IntegerType:80 - returning null as column: restrict4_17_1_
15:13:08,988 DEBUG IntegerType:86 - returning '1' as column: weight17_1_
15:13:08,988 DEBUG StringType:80 - returning null as column: richmedia17_1_
15:13:08,988 DEBUG BigDecimalType:80 - returning null as column: ecpm17_1_
15:13:08,988 DEBUG StringType:80 - returning null as column: destinat8_17_1_
15:13:08,988 DEBUG StringType:80 - returning null as column: image9_17_1_
15:13:08,988 DEBUG StringType:86 - returning 'test prod' as column: name17_1_
15:13:08,988 DEBUG BooleanType:86 - returning 'false' as column: deleted17_1_
15:13:08,988 DEBUG StringType:86 - returning 'manufacturer test prod' as column:
anchor12_17_1_
15:13:08,988 DEBUG BooleanType:86 - returning 'true' as column: allow13_17_1_
15:13:09,003 DEBUG BooleanType:86 - returning 'true' as column: allow14_17_1_
15:13:09,003 DEBUG BooleanType:86 - returning 'true' as column: advertiser15_17_
1_
15:13:09,019 DEBUG IntegerType:86 - returning '236' as column: product2_0__
15:13:09,034 DEBUG Loader:654 - found row of collection: [com.forwardnetwork.man
agerserver.db.maindb.datatransfer.Product.campaignMedias#236]
15:13:09,034 DEBUG CollectionLoadContext:101 - new collection: instantiating
15:13:09,034 DEBUG IntegerType:86 - returning '280' as column: id0__
15:13:09,034 DEBUG DefaultLoadEventListener:143 - loading entity: [com.forwardne
twork.managerserver.db.maindb.datatransfer.CampaignMedia#280]
15:13:09,034 DEBUG DefaultLoadEventListener:290 - attempting to resolve: [com.fo
rwardnetwork.managerserver.db.maindb.datatransfer.CampaignMedia#280]
15:13:09,034 DEBUG DefaultLoadEventListener:299 - resolved object in session cac
he: [com.forwardnetwork.managerserver.db.maindb.datatransfer.CampaignMedia#280]
15:13:09,034 DEBUG Loader:410 - result set row: 233
15:13:09,034 DEBUG IntegerType:86 - returning '237' as column: id0_
15:13:09,034 DEBUG IntegerType:86 - returning '281' as column: id1_
15:13:09,034 DEBUG IntegerType:86 - returning '21' as column: id2_
15:13:09,034 DEBUG IntegerType:86 - returning '2' as column: id3_
15:13:09,034 DEBUG IntegerType:86 - returning '1' as column: id4_
15:13:09,034 DEBUG IntegerType:86 - returning '22' as column: id5_
15:13:09,034 DEBUG Loader:828 - result row: EntityKey[com.forwardnetwork.manager
server.db.maindb.datatransfer.Product#237], EntityKey[com.forwardnetwork.manager
server.db.maindb.datatransfer.CampaignMedia#281], EntityKey[com.forwardnetwork.m
anagerserver.db.maindb.datatransfer.Campaign#21], EntityKey[com.forwardnetwork.m
anagerserver.db.maindb.datatransfer.AdType#2], EntityKey[com.forwardnetwork.mana
gerserver.db.maindb.datatransfer.Advertiser#1], EntityKey[com.forwardnetwork.man
agerserver.db.maindb.datatransfer.Account#22]
15:13:09,034 DEBUG Loader:978 - Initializing object from ResultSet: [com.forward
network.managerserver.db.maindb.datatransfer.Product#237]
15:13:09,050 DEBUG BasicEntityPersister:1651 - Hydrating entity: [com.forwardnet
work.managerserver.db.maindb.datatransfer.Product#237]
15:13:09,050 DEBUG IntegerType:86 - returning '1' as column: advertiser2_7_0_
15:13:09,050 DEBUG StringType:86 - returning 'manufacturer' as column: manufact3
_7_0_
15:13:09,050 DEBUG StringType:86 - returning 'test prod' as column: product4_7_0
_
15:13:09,050 DEBUG StringType:86 - returning 'category' as column: category7_0_
15:13:09,050 DEBUG StringType:86 - returning '394.40' as column: price7_0_
15:13:09,050 DEBUG StringType:80 - returning null as column: saleprice7_0_
15:13:09,050 DEBUG StringType:80 - returning null as column: shipping7_0_
15:13:09,050 DEBUG StringType:80 - returning null as column: image9_7_0_
15:13:09,050 DEBUG StringType:86 - returning 'http://couturecandy.com' as column
: destina10_7_0_
15:13:09,050 DEBUG StringType:80 - returning null as column: in11_7_0_
15:13:09,050 DEBUG StringType:80 - returning null as column: descrip12_7_0_
15:13:09,050 DEBUG IntegerType:80 - returning null as column: product13_7_0_
Top
 Profile  
 
tenwit
 Post subject:
PostPosted: Fri Mar 31, 2006 12:17 am 
Expert
Expert

Joined: Thu Dec 23, 2004 9:08 pm
Posts: 2008
You should be able to shave off about 90% of the time by turning off tracing, especially the org.hibernate.type tracing. If you can get the loop to not print anything, you'll have a more representative test.

Incidentally, have you considered Criteria instead of that findByFilter method? It won't help performance, but... ewww...
Top
 Profile  
 
hal18000
 Post subject:
PostPosted: Fri Mar 31, 2006 3:37 am 
Newbie

Joined: Tue Aug 02, 2005 5:04 pm
Posts: 15
tenwit wrote:
You should be able to shave off about 90% of the time by turning off tracing, especially the org.hibernate.type tracing. If you can get the loop to not print anything, you'll have a more representative test.

Incidentally, have you considered Criteria instead of that findByFilter method? It won't help performance, but... ewww...


When I do it without tracing it takes 10 seconds while it takes up 100% CPU. Your suggestion is noted.
Top
 Profile  
 
hal18000
 Post subject:
PostPosted: Sat Apr 01, 2006 8:44 pm 
Newbie

Joined: Tue Aug 02, 2005 5:04 pm
Posts: 15
Any other ideas, this is a showstopper for me and I'm sure anyone else doing lots of work with Hibernate. It looks like fetching associations, even if they are in memory, results in a sequential search in memory for the association object possibly? That's my best theory right now.
Top
 Profile  
 
the-gtm
 Post subject:
PostPosted: Sun Apr 02, 2006 4:01 am 
Regular
Regular

Joined: Wed Feb 08, 2006 3:59 pm
Posts: 75
Are you sure the slowness comes from Hibernate ? Maybe you should first try to create objects yourself and run your test case. If it takes significantly less time then it comes from Hibernate, if not it comes from your test case.

I see that you do a lot a string concatenations (output += ...) this can be quite memory intensive and could explain your problem. It's a good practice to use StringBuffer or StringBuilder instead.
Top
 Profile  
 
hal18000
 Post subject:
PostPosted: Sun Apr 02, 2006 8:24 pm 
Newbie

Joined: Tue Aug 02, 2005 5:04 pm
Posts: 15
Thank you, I took out the output += and put in StringBuffers and runtime went from 14sec for 2000 rows to 3 seconds. I'm now told that the maximum amount of rows will be 900 so this is more than satisfactory so I'll stop optimizing at this point.

Thank you once again.
Top
 Profile  
 
tenwit
 Post subject:
PostPosted: Sun Apr 02, 2006 8:52 pm 
Expert
Expert

Joined: Thu Dec 23, 2004 9:08 pm
Posts: 2008
If the code in question is threadsafe then switching StringBuffer to StringBuilder will give you another minor performance boost for no extra work. StringBuilder is exactly the same as StringBuffer, but isn't threadsafe, and it gains its performance boost by not bothering with the synchronizes that are in all of StringBuffer's methods.
Top
 Profile  
 
hal18000
 Post subject:
PostPosted: Sun Apr 02, 2006 9:52 pm 
Newbie

Joined: Tue Aug 02, 2005 5:04 pm
Posts: 15
Thanks, I'll use StringBuilder.
Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 8 posts ] 

Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]

You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.