Weird Lucene behaviour: The same "document" w/ multiple ids

mbauer77 · **Joined:** Sun Jul 12, 2009 9:53 am **Posts:** 21

Hi,

yes, i know - but I didn't have the time to really dig into Seam yet, and it seemed to need JBoss which is not an option for this project.

Thanks for the package logging hint, I will try that. I hoped that with the update to the newest lucene package the problem would be gone, but it isn't.
Could it be that there is a problem if i use xml-files for the hibernate mapping, search annotations for lucene in combination with composite keys?

sanne.grinovero · **Posted:** Wed Nov 25, 2009 7:58 am

Hi,

Quote:

I didn't have the time to really dig into Seam yet, and it seemed to need JBoss

no any servlet container will do, even Tomcat.

Quote:

Could it be that there is a problem if i use xml-files for the hibernate mapping, search annotations for lucene in combination with composite keys?

well I doubt the combination of xml-files and search annotations could do any harm. composite keys could be a lead to follow.
Lucene doesn't support updating, so it doesn't mess with this: we manage this with Hibernate event listeners.

mbauer77 · **Joined:** Sun Jul 12, 2009 9:53 am **Posts:** 21

s.grinovero wrote:

Quote:

Could it be that there is a problem if i use xml-files for the hibernate mapping, search annotations for lucene in combination with composite keys?

well I doubt the combination of xml-files and search annotations could do any harm. composite keys could be a lead to follow.
Lucene doesn't support updating, so it doesn't mess with this: we manage this with Hibernate event listeners.

You mean, you have an own event listener to solve the hibernate search / lucene issue with composite keys to make it "delete" the "old" document before creating the new one ?

Could you provide some abstract (or concrete) code for this, please ?

sanne.grinovero · **Posted:** Sun Dec 06, 2009 10:51 am

mbauer77 wrote:

You mean, you have an own event listener to solve the hibernate search / lucene issue with composite keys to make it "delete" the "old" document before creating the new one ?

Could you provide some abstract (or concrete) code for this, please ?

No sorry I mean hibernate search does do it this way: I'm referring to the eventlistener included in hibernate search.
Every update operation is implemented using a pair of operations on the index: delete and then add.
The "delete" operation is implemented as "delete all documents having that ID", so it would delete all documents in case of duplicates.

The only remaining explanation for your case is then that you're having multiple add or update statements in the same transaction?
Or that you're cheating the session someway to make him think these are add operations while they should be updates. (ADD doesn't perform the delete first)

sanne.grinovero · **Posted:** Sun Dec 06, 2009 10:58 am

Could you enable logging for

Code:

org.hibernate.search.backend.impl.lucene.works

and please post the output, and the Search version?

mbauer77 · **Joined:** Sun Jul 12, 2009 9:53 am **Posts:** 21

Hi,

i just edited one the Objects and let the app store it, the log is below and the number of "concurrent" documents raised from 3 to 4. :-/

Code:

193344 TRACE [pool-3-thread-1] org.hibernate.search.backend.impl.lucene.works.DeleteExtWorkDelegate     - Removing class de.bauerlive.ngshop.data.Product#de.bauerlive.ngshop.data.identifiers.Product_Id@68b67f56 by id using an IndexWriter.
193347 TRACE [pool-3-thread-1] org.hibernate.search.backend.impl.lucene.works.AddWorkDelegate     - add to Lucene index: class de.bauerlive.ngshop.data.Product#de.bauerlive.ngshop.data.identifiers.Product_Id@68b67f56:Document<stored/uncompressed,indexed<_hibernate_class:de.bauerlive.ngshop.data.Product> stored/uncompressed,indexed<id.mandt:0001> stored/uncompressed,indexed<id.prodid:CAN-B-13000> indexed,tokenized<manufacturerName:CANON> stored/uncompressed,indexed,tokenized<catalogs: _1_  _1_  _1_ > stored/uncompressed,indexed,tokenized<eans:4960999150406> stored/uncompressed,indexed,tokenized<id.mandt:0001> stored/uncompressed,indexed,tokenized<id.prodid:CAN-B-13000> indexed,tokenized<matkl:Zubehör Foto> indexed,tokenized<manufacturer:33470> indexed,tokenized<manufacturer_aid:2262A008>>
193509 DEBUG [http-9090-17]                     org.hibernate.SQL     - update product_text set STEXT=?, ltext=? where MANDT=? and LANG=? and PRODID=?
193523 TRACE [pool-4-thread-1] org.hibernate.search.backend.impl.lucene.works.DeleteExtWorkDelegate     - Removing class de.bauerlive.ngshop.data.ProductText#-2136254013 by id using an IndexWriter.
193524 TRACE [pool-4-thread-1] org.hibernate.search.backend.impl.lucene.works.AddWorkDelegate     - add to Lucene index: class de.bauerlive.ngshop.data.ProductText#-2136254013:Document<stored/uncompressed,indexed<_hibernate_class:de.bauerlive.ngshop.data.ProductText> stored/uncompressed,indexed<id.mandt:0001> stored/uncompressed,indexed<id.lang:DE> stored/uncompressed,indexed<id.prodid:CAN-B-13000> stored/uncompressed,indexed<mandt:0001> stored/uncompressed,indexed,tokenized<lang:DE> stored/uncompressed,indexed,tokenized<prodid:CAN-B-13000> stored/uncompressed,indexed,tokenized<stext:Canon Speedlite 220 EX - Blitz> indexed,tokenized<ltext:<p>Canon Speedlite 220 EX - Blitz<br />Leitzahl 22, A-TTL u. E-TTL Blitzsysteme<br />E-TTL mit Blitzme&szlig;wertspeicher<br />Hochgeschwindigkeitssynchronisation<br />automatische Blitzabschaltung<br />Leuchtwinkel 28mm f. EOS-Kleinbild<br />Leuchtw. 24 mm f. Advance Phot System<br />f. PowerShot Pro70, Pro 90IS,<br />G1/G2/G3/G5, EOS D30 und D60<br />MV1/10/30/30/ XM1/XM2<br />&Uuml;ber Blitzkabel FA-200 f&uuml;r XL1/XL1s/XL2</p>> indexed,tokenized<product.manufacturerName:CANON> stored/uncompressed,indexed,tokenized<product.catalogs: _1_  _1_  _1_ > stored/uncompressed,indexed,tokenized<product.eans:4960999150406> stored/uncompressed,indexed<product.id.mandt:0001> stored/uncompressed,indexed<product.id.prodid:CAN-B-13000> stored/uncompressed,indexed,tokenized<product.id.mandt:0001> stored/uncompressed,indexed,tokenized<product.id.prodid:CAN-B-13000> indexed,tokenized<product.matkl:Zubehör Foto> indexed,tokenized<product.manufacturer:33470> indexed,tokenized<product.manufacturer_aid:2262A008>>
193643 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
193645 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
193646 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
193652 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
193658 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
193660 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
193751 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
193753 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
193753 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
193856 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
193857 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
193858 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
193952 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
193957 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
193959 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
194053 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
194054 DEBUG [http-9090-17]                     org.hibernate.SQL     - update productcskind set VALUE=?, BPME=? where MANDT=? and CSKIND=? and PRODID=?
194056 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
194162 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
194171 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
194173 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
194255 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
194256 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
194259 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
194354 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
194355 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
194359 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
194454 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
194455 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
194458 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing
194554 DEBUG [http-9090-17]                     org.hibernate.SQL     - select productcsk_.MANDT, productcsk_.CSKIND, productcsk_.PRODID, productcsk_.VALUE as VALUE35_, productcsk_.BPME as BPME35_ from productcskind productcsk_ where productcsk_.MANDT=? and productcsk_.CSKIND=? and productcsk_.PRODID=?
194556 INFO  [http-9090-17] org.hibernate.event.def.DefaultDeleteEventListener     - handling transient entity in delete processing

Hibernate Versions:

Code:

351  INFO  [main] org.hibernate.cfg.annotations.Version     - Hibernate Annotations 3.4.0.GA
428  INFO  [main]         org.hibernate.cfg.Environment     - Hibernate 3.3.2.GA
433  INFO  [main]         org.hibernate.cfg.Environment     - hibernate.properties not found
439  INFO  [main]         org.hibernate.cfg.Environment     - Bytecode provider name : javassist
457  INFO  [main]         org.hibernate.cfg.Environment     - using JDK 1.4 java.sql.Timestamp handling
726  INFO  [main] org.hibernate.annotations.common.Version     - Hibernate Commons Annotations 3.1.0.GA
...
7447 INFO  [main]          org.hibernate.search.Version     - Hibernate Search 3.1.1.GA

So, Hibernate Search obviously thinks that it deleted the old document, but in reality it didn't. Weird...

hardy.ferentschik · **Posted:** Mon Dec 07, 2009 8:36 am

Are you able to extract a testcase? Preferably a Junit test we could run within HSearch itself? Or maybe you could create some sort of minimal example project showing the problem?
Maybe it would help following the trace if you add toString implementations to your objects.

--Hardy

mbauer77 · **Joined:** Sun Jul 12, 2009 9:53 am **Posts:** 21

Hi,

extracting a test case is really a big task because the project has grown extremely. I'll try to write a sample project demonstrating the problem.

In the meantime I added a toString() method, so the interesting lines now look like this:

Code:

197002 TRACE [pool-1-thread-1] org.hibernate.search.backend.impl.lucene.works.DeleteExtWorkDelegate     - Removing class de.bauerlive.ngshop.data.ProductText#0001 DE test by id using an IndexWriter.
197004 TRACE [pool-1-thread-1] org.hibernate.search.backend.impl.lucene.works.AddWorkDelegate     - add to Lucene index: class de.bauerlive.ngshop.data.ProductText#0001 DE test:Document<stored/uncompressed,indexed<_hibernate_class:de.bauerlive.ngshop.data.ProductText> stored/uncompressed,indexed<id.mandt:0001> stored/uncompressed,indexed<id.lang:DE> stored/uncompressed,indexed<id.prodid:test> stored/uncompressed,indexed<mandt:0001> stored/uncompressed,indexed,tokenized<lang:DE> stored/uncompressed,indexed,tokenized<prodid:test> stored/uncompressed,indexed,tokenized<stext:test 6> indexed,tokenized<ltext:<p>test mit &auml;nderung</p>> indexed,tokenized<product.manufacturerName:ACER> stored/uncompressed,indexed<product.id.mandt:0001> stored/uncompressed,indexed<product.id.prodid:test> stored/uncompressed,indexed,tokenized<product.id.mandt:0001> stored/uncompressed,indexed,tokenized<product.id.prodid:test> indexed,tokenized<product.matkl:1> stored/uncompressed,indexed<product.kzfront:X> stored/uncompressed,indexed<product.kzneu:X> indexed,tokenized<product.manufacturer:33414> indexed,tokenized<product.manufacturer_aid:test>>

As you can see, HSearch is claiming that it deleted the "old" document by id - but it didn't.
Do I have to do anything else besides the following to get the index updated correctly ?

Code:

SessionFactory sessionFactory = HibernateUtil.getSessionFactory();
        Session session = sessionFactory.openSession(); 
        session.beginTransaction();
        try {
            session.saveOrUpdate(producttext);
            session.getTransaction().commit();
        } catch (Exception e) {
            e.printStackTrace();
            session.getTransaction().rollback();
        }
       
        session.close();

mbauer77 · **Joined:** Sun Jul 12, 2009 9:53 am **Posts:** 21

I just went through the startup log and found a

Code:

@DocumentId specified on an entity which is not indexed by itself. Annotation gets ignored. Use @Field instead

Could it be, that Hibernate Search does not accept my ID component and that's the cause why it generates always new IDs and new documents and does not delete the old ones ?

My ID component looks like this:

Code:

@Embeddable
public class ProductText_Id implements Serializable {

    private static final long serialVersionUID = 8194101847993970529L;
    @Column(name = "MANDT", length = 4)
    protected String mandt;
    @Column(name = "LANG", length = 3)
    protected String lang;
    @Column(name = "PRODID", length = 40)
    protected String prodid;

    [... getters, setters, toString, equals and hashcode....]
}

And it the Search-Indexed class uses it like this:

Code:

@Indexed
@Analyzer(impl = de.bauerlive.ngshop.logic.BLNGAnalyzer.class)
public class ProductText implements Serializable {

    private static final long serialVersionUID = -8429603356751414390L;
    
    protected ProductText_Id id;
    
    /**
     * Get the value of id
     *
     * @return the value of id
     */
    @DocumentId
    @FieldBridge(impl = ProductTextBridge.class)
    public ProductText_Id getId() {
        return id;
    }
  
    [...]
}

sanne.grinovero · **Posted:** Sun Dec 13, 2009 5:52 pm

This is complex and a lot of code is involved, sorry if you can't provide a test I'll have to ask you to debug:
can you step on org.hibernate.search.backend.impl.lucene.works.DeleteExtWorkDelegate at line 67?
You should check that the term used for deletion from the index matches the term in the index: use the Luke tool to look into the index.
For some reason it's not deleting the document, I bet the terms don't match.
While you step you can look into the index and verify if it's getting deleted or not.

jwickers · **Joined:** Mon Dec 14, 2009 8:45 am **Posts:** 1

Hi,

I had the exact same problem, and after a few hours of head banging the keyboard it just hit me (the solution, not the keyboard):

In your ProductBridge, you (and I) forgot to set the "fieldName" field in the document,

Code:

public void set(String fieldName, Object obj, Document doc, Store store, Index index, Float boost) {
        Product_Id questionPK = (Product_Id) obj;
        Field field = new Field(fieldName + ".mandt", questionPK.getMandt(), store, index);

        if (boost != null) {
            field.setBoost(boost);
        }

        doc.add(field);

        field = new Field(fieldName + ".prodid", questionPK.getProdid(), store, index);

        if (boost != null) {
            field.setBoost(boost);
        }

        doc.add(field);
    }

Just add :

Code:

field = new Field(fieldName, objectToString(questionPK), store, index);
doc.add(field);

(To be sure i personally also used "_" as a separator instead of " " in objectToString.)

And that's it, no more duplicate :)

Now thinking about it, it actually makes sense (sort of), but the Hibernate Search documentation should definitely make this clearer.

hardy.ferentschik · **Posted:** Mon Dec 14, 2009 9:31 am

Quote:

I just went through the startup log and found a

Code:

@DocumentId specified on an entity which is not indexed by itself. Annotation gets ignored. Use @Field instead

I don't think this is related. You probably have an entity which is index using @IndexedEmbedded and is by itself not indexed (does not contain @Indexed and cannot be returned as as a result from a fulltext query). In such a case it does not make sense to have @DocumentId on the embedded entity.
Looking at your original post you did not seem to have this case in the classes you are having problems with (unless you are posting 'modified' code).

Regarding your problem - does your code work outside a container? Do you have some unit tests which tests index/search functionality in unit tests? I still have the feeling you might be having problems with session management. But that's just a guess. At this stage we really would need some sort of testcase.

--Hardy

mbauer77 · **Joined:** Sun Jul 12, 2009 9:53 am **Posts:** 21

jwickers wrote:

Hi,

I had the exact same problem, and after a few hours of head banging the keyboard it just hit me (the solution, not the keyboard):

In your ProductBridge, you (and I) forgot to set the "fieldName" field in the document,

Just add :

Code:

field = new Field(fieldName, objectToString(questionPK), store, index);
doc.add(field);

(To be sure i personally also used "_" as a separator instead of " " in objectToString.)

And that's it, no more duplicate :)

Now thinking about it, it actually makes sense (sort of), but the Hibernate Search documentation should definitely make this clearer.

Wow - looks like you solved the problem ! I just tested it a few times and there really are no more duplicates !

Great ! Thanks a lot !!!