SuggestionPickerField performance

Support
#1

I have a SuggestionPickerField loading from an Oracle Database. It is defined like this:

<suggestionPickerField id="lstField" property="lst" caption="List" width="100%" tabIndex="1" suggestionsLimit="20" required="true">
    <query entityClass="com.paslists.rentals.entity.Lists"
                 escapeValueForLike="false" view="lists-view" searchStringFormat="%$searchString%">
          select e from rentals_Lists e where lower(e.title) like lower(:searchString) and e.noRentals is null
    </query>
    <actions>
        <action id="lookup" type="picker_lookup"/>
        <action id="open" type="picker_open"/>
        <action id="clear" type="picker_clear"/>
     </actions>
</suggestionPickerField>

Most of the time it works just fine. However, we have found one string where it takes much longer than it should. When I examine the query plan for what I think the Oracle SQL should be, it is very fast. However, when I enable eclipselink.sql to DEBUG so I can watch the SQL go by, I don’t see the SQL for the backgroundWorker. I just see:

2019-10-03 12:01:38.959 DEBUG [BackgroundTask-1-admin/rentals/admin] com.haulmont.cuba.web.gui.executors.impl.WebBackgroundWorker - Done task. User: admin
2019-10-03 12:01:38.959 DEBUG [BackgroundTask-1-admin/rentals/admin] com.haulmont.cuba.web.gui.components.WebSuggestionPickerField - Search results for 'ls dir'

Is there a way to see the SQL it is executing - or somehow trace why it is taking so long for this particular string?

#2

Hi,

Let’s clarify: when you enable “eclipselink.sql” debug logging - are you starting to see at least some SQL messages in the log?
Because if you don’t - you have not enabled it.

There is only one way to see the SQL - and it is configuring eclipselink.sql debug logging (like described here Useful Loggers - CUBA Platform. Developer’s Manual) and investigating log messages.

#3

Maybe you are right. I thought I enabled it, but I will try again just to be sure.

#4

Sorry this took so long to get back. I finally had a chance to work on this again. When I search for “ls dir”, I see this in the logs:

2019-10-08 17:23:12.222 DEBUG [BackgroundTask-1-admin/rentals/admin] com.haulmont.cuba.web.gui.components.WebSuggestionPickerField - Search 'ls dir'
2019-10-08 17:23:12.609 WARN  [BackgroundTask-0-admin/rentals/admin] com.haulmont.cuba.core.sys.remoting.LocalServiceDirectory - Interrupted awaiting for context to start
2019-10-08 17:23:12.611 DEBUG [BackgroundTask-0-admin/rentals-core/admin] com.haulmont.cuba.core.app.RdbmsStore - loadList: metaClass=rentals_Lists, view=com.paslists.rentals.entit
y.Lists/lists-view, query=select e from rentals_Lists e where lower(e.title) like lower(:searchString) escape '\' and e.noRentals is null order by e.title
2019-10-08 17:23:12.611 DEBUG [BackgroundTask-1-admin/rentals-core/admin] com.haulmont.cuba.core.app.RdbmsStore - loadList: metaClass=rentals_Lists, view=com.paslists.rentals.entit
y.Lists/lists-view, query=select e from rentals_Lists e where lower(e.title) like lower(:searchString) escape '\' and e.noRentals is null order by e.title
2019-10-08 17:23:12.634 DEBUG [BackgroundTask-1-admin/rentals-core/admin] eclipselink.sql - <t 1971325842, conn 1421071147> SELECT t1.ID, t1.ARCLIM, t1.ARCTAB, t1.CNTMONTHS, t1.COU
NTRYCD, t1.COUNTSEMAIL, t1.COUNTSEMAILTEMPLATE, t1.DISKCHG, t1.DISKMIN, t1.DISKUNIT, t1.EMAILCHG, t1.HOTLINEFMT, t1.KEYCHG, t1.KEYLEN, t1.KEYPOS, t1.LASTUPD, t1.LST_TABLE, t1.MAXCH
G, t1.MAXHLDATE, t1.MINCHG, t1.MINSELFLAG, t1.NO_RENTALS, t1.NOCOUNTS, t1.PSCHG, t1.PSMIN, t1.QTYAPPEMAIL, t1.RUNCHG, t1.RUNUNIT, t1.SEEDSPERORDER, t1.SELCHG, t1.SELSTMT, t1.SELUNI
T, t1.SENDMONTHLYCNTS, t1.SHIPEMAIL, t1.SPECINST, t1.SPECINSTC, t1.TAPECHG, t1.TITLE, t1.UPDCHG, t1.UPDLIM, t1.UPDLISTID, t1.UPDMIN, t1.UPDNOTIFYDATE, t1.UPDPROC, t1.UPDUNIT, t1.ZI
PDCHG, t1.ZIPDMIN, t1.ZIPDUNIT, t1.CUS_ID, t0.ID, t0.COMPANY FROM LISTS t1 LEFT OUTER JOIN CUSTOMERS t0 ON (t0.ID = t1.CUS_ID) WHERE (LOWER(t1.TITLE) LIKE LOWER(?) ESCAPE ? AND (t1
.NO_RENTALS IS NULL)) ORDER BY t1.TITLE
        bind => [%ls dir%, \]

That’s what I would expect. But then I see this?

2019-10-08 17:23:12.662 DEBUG [BackgroundTask-0-admin/rentals-core/admin] eclipselink.sql - <t 1389557852, conn 132457288> SELECT t1.ID, t1.ARCLIM, t1.ARCTAB, t1.CNTMONTHS, t1.COUN
TRYCD, t1.COUNTSEMAIL, t1.COUNTSEMAILTEMPLATE, t1.DISKCHG, t1.DISKMIN, t1.DISKUNIT, t1.EMAILCHG, t1.HOTLINEFMT, t1.KEYCHG, t1.KEYLEN, t1.KEYPOS, t1.LASTUPD, t1.LST_TABLE, t1.MAXCHG
, t1.MAXHLDATE, t1.MINCHG, t1.MINSELFLAG, t1.NO_RENTALS, t1.NOCOUNTS, t1.PSCHG, t1.PSMIN, t1.QTYAPPEMAIL, t1.RUNCHG, t1.RUNUNIT, t1.SEEDSPERORDER, t1.SELCHG, t1.SELSTMT, t1.SELUNIT
, t1.SENDMONTHLYCNTS, t1.SHIPEMAIL, t1.SPECINST, t1.SPECINSTC, t1.TAPECHG, t1.TITLE, t1.UPDCHG, t1.UPDLIM, t1.UPDLISTID, t1.UPDMIN, t1.UPDNOTIFYDATE, t1.UPDPROC, t1.UPDUNIT, t1.ZIP
DCHG, t1.ZIPDMIN, t1.ZIPDUNIT, t1.CUS_ID, t0.ID, t0.COMPANY FROM LISTS t1 LEFT OUTER JOIN CUSTOMERS t0 ON (t0.ID = t1.CUS_ID) WHERE (LOWER(t1.TITLE) LIKE LOWER(?) ESCAPE ? AND (t1.
NO_RENTALS IS NULL)) ORDER BY t1.TITLE
        bind => [%ls%, \]
2019-10-08 17:23:12.676 DEBUG [BackgroundTask-0-admin/rentals-core/admin] eclipselink.sql - <t 1389557852, conn 132457288> [13 ms] spent

Unfortunately, this returns MANY more rows and the extra fetches for associations make it slow.

Why did it remove the " dir" and re-run the query?

#5

Hi,

I think when you were typing “ls dir” text - the field first launched search by “ls” and then by “ls dir”. Then these queries became a bit messed in time because they are executed in parallel.

You can set SuggestionPickerField attribute minSearchStringLength=“5” attribute to avoid searching by short text.

Then, from the log you posted I see that it took just 13 milliseconds to load rows by “ls”. Is it too long?
Maybe this is your problem:

Unfortunately, this returns MANY more rows and the extra fetches for associations make it slow.

Looks like you are using a too large view “lists-view” for suggestions.

One of main performance optimization principles for CUBA UI is to load as few attributes for lists, tables, collections as you can. For lookupField, suggestionField’s options the ideal case is to use “_minimal” view which only contains attributes enough to display the caption.

Later when user has selected desired suggestion - you can reload the selected entity with required bulky view.

#6

OK, so can you give me some example code to do this if I change the view to “_minimal”?

It would be great if the SuggestionPickerField did that for you (and probably other lookup components as well). There would be two view properties: lookup-view and load-view. lookup-view would run the searches and load-view would be executed on the final chosen object. (Just me being lazy. :wink: )

The List object is an association to my Order object (so this is loading a property). What’s the best way to take the object pointed to by the property and reload it with the full “lists-view”?

Here’s what I have tried:

    @Subscribe("lstField")
    private void onLstFieldValueChange(HasValue.ValueChangeEvent<Lists> event) {

        if (event.isUserOriginated() && getEditedEntity().getLst() != null) {
            getEditedEntity().setLst(dataManager.load(Lists.class).id(getEditedEntity().getLst().getId()).view("lists-view").one());
            if (getEditedEntity().getCus() == null) {
                getEditedEntity().setCus(getEditedEntity().getLst().getCus());
            }
            if (getEditedEntity().getSpecinst() == null) {
                getEditedEntity().setSpecinst(getEditedEntity().getLst().getSpecinst());
            }
        }
    }

I have multiple associations going on here. Before this ValueChange even gets fired, the SuggestionPickerField saves my List entity in my Order. List, in turn, is associated with the Seeds entity. Since that is not in the “_minimal” view, it is not loaded so I am getting a detached entity error.

How do I make this work without loading the full “lists-view” in my SuggestionPickerField?

#7

Hi,
Your code sample should work fine.

I don’t understand this: “Since that is not in the “_minimal” view, it is not loaded so I am getting a detached entity error.”
In your code you do the reload and you control that “getEditedEntity().getLst()” is loaded with necessary view, before accessing getCus() and getSpecinst() attributes.

#8

There is another association between Lists and Seeds that is loaded automatically by Cuba. Unfortunately, the automatic loader is trying to load Seeds before this event fires. I have not yet changed the view from “_minimal” to “list-view”, so the Seeds entities are not yet loaded. Therefore I get a detached error.

How should I have coded this to avoid the problem?

#9

What is an automatic loader? When the association is loaded automatically?
I don’t understand what you are meaning here, sorry.

#10

Exactly, when you declare an association and then indicate that the corresponding entities should be loaded in a view, they are loaded automatically, right?

I have numerous entities attached to an order and many tabs/tables displaying them all. When I load an order, all of those associated Entities get loaded due to my orders-view. Here is the entire view:

    <view entity="rentals_Orders" name="order-view" extends="_local">
        <property name="cus" view="_minimal">
            <property name="creditstatus"/>
        </property>
        <property name="lst" view="_minimal">
            <property name="arclim"/>
            <property name="arctab"/>
            <property name="cntmonths"/>
            <property name="countrycd"/>
            <property name="countsemail"/>
            <property name="countsemailtemplate"/>
            <property name="diskchg"/>
            <property name="diskmin"/>
            <property name="diskunit"/>
            <property name="emailchg"/>
            <property name="hotlinefmt"/>
            <property name="keychg"/>
            <property name="keylen"/>
            <property name="keypos"/>
            <property name="lastupd"/>
            <property name="lstTable"/>
            <property name="maxchg"/>
            <property name="maxhldate"/>
            <property name="mgr" view="_minimal"/>
            <property name="minchg"/>
            <property name="minselflag"/>
            <property name="noRentals"/>
            <property name="nocounts"/>
            <property name="own" view="_minimal"/>
            <property name="pschg"/>
            <property name="psmin"/>
            <property name="qtyappemail"/>
            <property name="runchg"/>
            <property name="rununit"/>
            <property name="seedsperorder"/>
            <property name="selchg"/>
            <property name="selstmt"/>
            <property name="selunit"/>
            <property name="sendmonthlycnts"/>
            <property name="shipemail"/>
            <property name="specinst"/>
            <property name="specinstc"/>
            <property name="tapechg"/>
            <property name="updchg"/>
            <property name="updlim"/>
            <property name="updlistid"/>
            <property name="updmin"/>
            <property name="updnotifydate"/>
            <property name="updproc"/>
            <property name="updunit"/>
            <property name="zipdchg"/>
            <property name="zipdmin"/>
            <property name="zipdunit"/>
            <property name="seeds" view="_minimal">
                <property name="address1"/>
                <property name="address2"/>
                <property name="address3"/>
                <property name="city"/>
                <property name="countrycode"/>
                <property name="lstTable" view="_minimal"/>
                <property name="postalcode"/>
                <property name="province"/>
                <property name="recType"/>
                <property name="required"/>
                <property name="status"/>
            </property>
        </property>
        <property name="mlr" view="_minimal"/>
        <property name="ordShipQty"/>
        <property name="ordlines" view="_minimal">
            <property name="contact"/>
            <property name="keycode"/>
            <property name="keyrec"/>
            <property name="material"/>
            <property name="nthflag"/>
            <property name="ordqty"/>
            <property name="orlDesc"/>
            <property name="price"/>
            <property name="shipchg"/>
            <property name="shipqty"/>
            <property name="shipvia"/>
            <property name="shp" view="_minimal">
                <property name="address1"/>
                <property name="address2"/>
                <property name="city"/>
                <property name="country"/>
                <property name="division"/>
                <property name="state"/>
                <property name="zip"/>
                <property name="zip4"/>
            </property>
            <property name="tracknum"/>
            <property name="unit"/>
            <property name="selects" view="_minimal">
                <property name="selnum"/>
                <property name="connector"/>
                <property name="description"/>
                <property name="price"/>
                <property name="selclause"/>
                <property name="unit"/>
            </property>
            <property name="rentalemail" view="_minimal"/>
        </property>
        <property name="prioromit" view="_minimal">
            <property name="omitOrder" view="_local">
                <property name="bkrnum"/>
                <property name="cancelled"/>
                <property name="curstep"/>
                <property name="cus" view="_minimal"/>
                <property name="cutoffdate"/>
                <property name="femalethres"/>
                <property name="holduntil"/>
                <property name="lst" view="_minimal"/>
                <property name="luoEstqty"/>
                <property name="luoEsttapes"/>
                <property name="maildate"/>
                <property name="malethres"/>
                <property name="mgrnum"/>
                <property name="mlr" view="_minimal"/>
                <property name="mpoEstqty"/>
                <property name="mpoEsttapes"/>
                <property name="ordType"/>
                <property name="orddate"/>
                <property name="outfmt"/>
                <property name="qtyappdate"/>
                <property name="qtycheckid"/>
                <property name="respmlg"/>
                <property name="rundate"/>
                <property name="seedcount"/>
                <property name="seeddate"/>
                <property name="seedrecd"/>
                <property name="shipdate"/>
                <property name="specinst"/>
                <property name="status"/>
                <property name="tapestatbkr"/>
                <property name="tapestatmlr"/>
                <property name="wantdate"/>
                <property name="ordShipQty"/>
                <property name="ordlines" view="_local"/>
                <property name="prioromit" view="_local"/>
                <property name="orderImages" view="_local"/>
            </property>
        </property>
        <property name="orderImages" view="_local"/>
    </view>

And here is lists-view:

    <view entity="rentals_Lists" name="lists-view" extends="_local">
        <property name="cus" view="_minimal"/>
        <property name="seeds" view="_minimal">
            <property name="address1"/>
            <property name="address2"/>
            <property name="address3"/>
            <property name="city"/>
            <property name="countrycode"/>
            <property name="postalcode"/>
            <property name="province"/>
            <property name="recType"/>
            <property name="required"/>
            <property name="status"/>
        </property>
    </view>

As you can see, there are a lot of related entities. The problem is with the chain rentals_orders->lst->seeds. Everything works perfectly when I uses lists-view, because the related seeds are loaded and the data is available for the screen.

If I use _minimal instead, then the seeds are not available and I get a detached error BEFORE my onLstFieldValueChange event fires. If that fired before the seeds tried to redisplay, then I could change the view and load the seeds associated with the list.

If I use list-view during the lookup, then the seeds are already loaded and all is well.

How do I fix this so that I can use _minimal during the search and not get a detached error?

#11

I suspect that there is some place in your code which triggers seeds loading too early.
If you present a demo project that reproduces your case - we will be able to show you a workaround.

For example, you could extract “seeds” to be stored in a separate collection container, and refresh the data in that container every time when “lists” value changes. Then “seeds” displaying becomes independent of lists’s view.

#12

OK – I understand. Not sure I can re-create the issue on a small scale, but I get the idea. I will try that out and see if it helps.

In the meantime, the stopgap of requiring minimum of 4 characters before the search starts is working.

Thanks for your help!