moqui-framework icon indicating copy to clipboard operation
moqui-framework copied to clipboard

auto dataFeed service not always executed when entity created

Open fokunn opened this issue 5 years ago • 9 comments

Bump into a scenario on the auto dataFeed service for elastic search.

this scenario is that auto dataFeed service may not have started after an new entity is created through create#${ENTITYNAME} service call as I can not get any out put by search "*" through elastic search service. It may happen on many entity creations.

Then after login into the tools page -> entity edit page -> update any of the new created entity . then got all the new created entity searchable through elastic search.

Some one has clue know why?

Tried to find clue in code.. . but no gain at the moment..

edit----- the version is 2.1.1, the code is runing on windows server 2019, 64 bit data-center

fokunn avatar Jul 12 '19 07:07 fokunn

Are you talking about initial data load, and by 'entity created' do you mean creating a record for an entity?

If it is an initial data load the DataFeed and other data won't have been there when Moqui starts and so won't be used. You can include an XML element to explicitly call a DataFeed index just as is done in various demo data files, like:

<org.moqui.search.SearchServices.indexDataFeedDocuments dataFeedId="MantleSearch"/>

This is from the PopCommerceDemoData.xml file (near the bottom):

https://github.com/moqui/PopCommerce/blob/master/data/PopCommerceDemoData.xml

jonesde avatar Jul 17 '19 23:07 jonesde

Sorry for the bad description of the situation and wrong word , should be realtime datafeed instead of auto datafeed.
Initial data loading is working very well as expected.
by word entity of entity created I mean a instance of entity of a type of primary entity defined in the data documents. by created I mean after a successful service-call"create#${mantle udm defination}"

the services seems working fine most of the time. I would expect each time a instance of primary entity defined in data has been created (or a successful transaction submitted? ), there should be one data push execution. But sometime Moqui does not behave like this. it needs a manual update of either instance of the entity to trigger the mealtime datafeed.

Hope you can get what I mean

have a nice day then

fokunn avatar Jul 18 '19 01:07 fokunn

I just did some more tests on it. Found out that the org.moqui.search.SearchServices.indexDataDocuments wont be called sometimes. For the moment, I just manually call org.moqui.search.SearchServices.indexDataDocumentsec.getTool("ElasticSearch", EsClient.class).client.prepareIndex(indexname, documenttype, documentId).setSource(document).execute().actionGet() to get around the issue

---------edit---------------

After some research I found this function dataFeedCheckAndRegister. It might be that the database logic made this function think it is not necessary to register datafeed.

I got some logger output by enable logger in method dataFeedCheckAndRegister and DataFeedSynchronization :

--- 2019-07-21 00:32:22.323 [tp1586600255-61] WARN                org.moqui.impl.entity.EntityDataFeed []
 ============== DataFeed checking entity isModified=true [fokunn.wisdom.Question] value: [noOfAnswers:null, questionName:C1, lastUpdatedStamp:2019-07-21 00:32:21.619, description:W
, createdDate:2019-07-21 00:32:22.323, authorPartyId:100051, questionId:100204, questionClassEnumId:null, htmlDescription:<p>W</p>, anonymous:N, noOfFollowers:null]
--- 2019-07-21 00:32:22.323 [tp1586600255-61] WARN                org.moqui.impl.entity.EntityDataFeed []
 ======= dataFeedCheckAndRegister update? false mod? true
ev: [noOfAnswers:null, questionName:C1, lastUpdatedStamp:2019-07-21 00:32:21.619, description:W
, createdDate:2019-07-21 00:32:22.323, authorPartyId:100051, questionId:100204, questionClassEnumId:null, htmlDescription:<p>W</p>, anonymous:N, noOfFollowers:null]
oldValues=null
--- 2019-07-21 00:32:22.323 [tp1586600255-61] WARN                org.moqui.impl.entity.EntityDataFeed []
 ===============  at last return emptylist for   [fokunn.wisdom.Question]
--- 2019-07-21 00:32:22.323 [tp1586600255-61] WARN                org.moqui.impl.entity.EntityDataFeed []
 ======= dataFeedCheckAndRegister entityInfoList size 0

the method DataFeedSynchronization look like:

protected DataFeedSynchronization getDataFeedSynchronization() {
      DataFeedSynchronization dfxr = (DataFeedSynchronization) efi.ecfi.transactionFacade.getActiveSynchronization("DataFeedSynchronization")
      if (dfxr == null) {
          dfxr = new DataFeedSynchronization(this)
          dfxr.enlist()
      }
      return dfxr
  }

  final Set<String> dataFeedSkipEntities = new HashSet<String>(['moqui.entity.SequenceValueItem'])
  protected final static ArrayList<DocumentEntityInfo> emptyList = new ArrayList<DocumentEntityInfo>()

  // NOTE: this is called frequently (every create/update/delete)
  ArrayList<DocumentEntityInfo> getDataFeedEntityInfoList(String fullEntityName) {
      // see if this is a known entity in a feed
      // NOTE: this avoids issues with false negatives from the cache or excessive rebuilds (for every entity the
      //     first time) but means if an entity is added to a DataDocument at runtime it won't pick it up!!!!
      // NOTE2: this could be cleared explicitly when a DataDocument is added or changed, but that is done through
      //     direct DB stuff now (data load, etc), there is no UI or services for it
      if (entitiesWithDataFeed == null) rebuildDataFeedEntityInfo()
      if (!entitiesWithDataFeed.contains(fullEntityName))  logger.warn("=============== data feed not contains  [${fullEntityName}]")
      if (!entitiesWithDataFeed.contains(fullEntityName)) return emptyList

      ArrayList<DocumentEntityInfo> cachedList = (ArrayList<DocumentEntityInfo>) dataFeedEntityInfo.get(fullEntityName)
      if (cachedList != null) return cachedList

      // if this is an entity to skip, return now (do after primary lookup to avoid additional performance overhead in common case)
      if (dataFeedSkipEntities.contains(fullEntityName)) {
          logger.warn("=============== skip entity  [${fullEntityName}]")
          dataFeedEntityInfo.put(fullEntityName, emptyList)
          return emptyList
      }

      // logger.warn("=============== getting DocumentEntityInfo for [${fullEntityName}], from cache: ${entityInfoList}")
      // MAYBE (often causes issues): only rebuild if the cache is empty, most entities won't have any entry in it and don't want a rebuild for each one
      rebuildDataFeedEntityInfo()
      // now we should have all document entityInfos for all entities
      cachedList = (ArrayList<DocumentEntityInfo>) dataFeedEntityInfo.get(fullEntityName)
      if (cachedList != null) return cachedList

      // remember that we don't have any info
      dataFeedEntityInfo.put(fullEntityName, emptyList)
      logger.warn("===============  at last return emptylist for   [${fullEntityName}]")

      return emptyList
  }

fokunn avatar Jul 20 '19 14:07 fokunn

When you say "wont be called sometimes" what are the conditions you found where the indexing is not done?

It is odd that calling the ElasticSearch indexing directly is necessary... does the database (entity) record you are looking at get indexed when you explicitly can an index on the DataFeed (through the screen in the System app or by calling the index#DataFeed service)?

jonesde avatar Jul 20 '19 17:07 jonesde

It is not regularly. Got one not indexing after several times successful indexing. I also felt very odd and had no clue at all.

About what condition, I would say that I have noticed a small interesting stuff: I have a field named createdDate in the entity, and in system, there is a lastupdatedTimestamp?, I found the createdDate is later then lastUpdatedTimestamp though the difference is very small, only serveal mill seconds. Dont know if this might be reason.

--- 2019-07-21 00:32:22.323 [tp1586600255-61] WARN                org.moqui.impl.entity.EntityDataFeed []
 ======= dataFeedCheckAndRegister update? false mod? true
ev: [noOfAnswers:null, questionName:C1, lastUpdatedStamp:2019-07-21 00:32:21.619, description:W
, createdDate:2019-07-21 00:32:22.323, authorPartyId:100051, questionId:100204, questionClassEnumId:null, htmlDescription:<p>W</p>, anonymous:N, noOfFollowers:null]
oldValues=null

Form user point of view, there is no obvious difference between the condition of success indexing and of non-success one. I got an app creates Question with questionName and description. And I operates on the GUI, after one Question is created, I continue to create the second one with different questionName and description. of course, the questionId also is different, as it is generated by the system. The datadocument definition is as following:

<moqui.entity.document.DataDocument dataDocumentId="Question" indexName="Question" documentName="Fokunn answer and question" primaryEntityName="fokunn.wisdom.Question" />
	
	<!--  -->
	
	
	<!-- -->
	<moqui.entity.document.DataDocumentField dataDocumentId="Question" fieldPath="questionName"   fieldNameAlias="questionName" />
	<moqui.entity.document.DataDocumentField dataDocumentId="Question" fieldPath="description"   fieldNameAlias="description" />
    <moqui.entity.document.DataDocumentField dataDocumentId="Question" fieldPath="questionId"  />
	<moqui.entity.document.DataDocumentField dataDocumentId="Question" fieldPath="author:partyId"   fieldNameAlias="authorPartyId"  />
	
    
    <!-- ================ -->
    <!-- Search Data Feed -->
    <moqui.entity.feed.DataFeed dataFeedId="FERPSearchQuestion" dataFeedTypeEnumId="DTFDTP_RT_PUSH"
            feedName="FERP geo assoc search" feedReceiveServiceName="org.moqui.search.SearchServices.index#DataDocuments">
        <documents dataDocumentId="Question"/>
    </moqui.entity.feed.DataFeed>
	
	<!-- explicitly index the Data Feed documents since the trigger won't be in place until restart -->
    <org.moqui.search.SearchServices.indexDataFeedDocuments dataFeedId="FERPSearchQuestion"/>


And I have a search for another entity, and so far , there is not any problem with that indexing. In the data documents, I added some fields of the related entity as the document fields. Could be that it needs fields from related entity to act as expected?

Yes, through system app System ->Data Document ->Index, left timestamp area empty, and it I upate entity through entity tools , it also get indexed.

I am totally lost in the jungle...

fokunn avatar Jul 21 '19 02:07 fokunn

Any updates on this?

The most common issue report related to this is the expectation that data feeds happen synchronously but they don't, they are asynchronous. That means if you display based on ElasticSearch data in a screen render after an update the data won't always be there yet but will be within seconds or milliseconds (depending on the ElasticSearch setup, the load on the server, other async operations queued, etc).

jonesde avatar Aug 30 '19 15:08 jonesde

I think you are right about the asynchronous nature of the real-time data feed.  I dont have any updates on this as I fed data manully by calling the datafeed right after I created the entity. I ll comment out the manual data feed and see what will happen. But based on the previous observations I can say that if it did not happen it will never happen unless I update the entity through tool screen.  The time it took before I do the updating job Is much longer then some seconds. My server seems not busy at all.  

发自我的iPhone

------------------ Original ------------------ From: David E. Jones <[email protected]> Date: 周五,8月 30,2019 23:51 To: moqui/moqui-framework <[email protected]> Cc: fokunn <[email protected]>, Author <[email protected]> Subject: Re: [moqui/moqui-framework] auto dataFeed service not always executed when entity created (#370)

Any updates on this?

The most common issue report related to this is the expectation that data feeds happen synchronously but they don't, they are asynchronous. That means if you display based on ElasticSearch data in a screen render after an update the data won't always be there yet but will be within seconds or milliseconds (depending on the ElasticSearch setup, the load on the server, other async operations queued, etc).

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or mute the thread.

fokunn avatar Aug 30 '19 17:08 fokunn

Well,I think I know the root cause for your question, I had encounter the same issue before. this only happend in dev config https://github.com/moqui/moqui-runtime/issues/139

you need to changed this settings from to

lightning-pro avatar Dec 17 '19 02:12 lightning-pro

The timing of your comment was helpful, had noticed this once in dev mode while working on some recent DataFeed improvements (for bulk DataFeed runs to do batches, default 1000 DataDocuments at a time), and this explained what was going on. There are some changes in moqui-framework commit ba199ea that should address this.

If there are further issues I'm tempted to eliminate the use of a cache altogether. Using a cache for this is not natural in any way because there is no way to detect that a cache entry is missing without doing the full reload of all feed data for all data documents in the feed (to get the set of all entities registered for a feed).

jonesde avatar Dec 17 '19 05:12 jonesde