Unexpected performance issue with SQL query followed by error

classic Classic list List threaded Threaded
38 messages Options
12
jan.swaelens jan.swaelens
Reply | Threaded
Open this post in threaded view
|

Unexpected performance issue with SQL query followed by error

Hello All,

Following up on my previous adventures I am not at the point where I can test my real life case - replacing a module which is performing slow by heavy database access.

This is the scenario:

1) I load up 4 of our tables into memory, to give you an example on size and speed these are some stats dumped to log:

Loaded Activity - Count #1227517 in 113382ms
Loaded ActivityHistory - Count #1227517 in 115530ms
Loaded ActivityHistoryUserAccount - Count #1227517 in 115009ms
Loaded ActivityUseraccountRole - Count #1227517 in 124547ms

At this point the metrics in my ignite log are as follows:

Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=80cb91a1, name=null, uptime=00:21:04:226]
    ^-- H/N/C [hosts=1, nodes=1, CPUs=8]
    ^-- CPU [cur=100%, avg=9.58%, GC=21.17%]
    ^-- Heap [used=3056MB, free=17.68%, comm=3713MB]
    ^-- Non heap [used=240MB, free=57.04%, comm=267MB]
    ^-- Public thread pool [active=1, idle=15, qSize=0]
    ^-- System thread pool [active=0, idle=16, qSize=0]
    ^-- Outbound messages queue [size=0]

After things are loaded I execute a non representative query for testing (which you might have see before, it lead to the alias support on fields and db cols):

SELECT DISTINCT activity0.activity_id, activity0.sequencenr, activity0.name_mlid, activity0.name, activity0.description_mlid, activity0.description, activity0.durationunit_enumid, activity0.duration, activity0.required, activity0.predecessortype_enumid, activity0.successortype_enumid, activity0.removefromworklist, activity0.lastactivity_id, activity0.lifecyclereporting, activity0.duedate, activity0.priority_enumid, activity0.notify, activity0.timestamp, activity0.ActivityType_id, activity0.container_id, activity0.realization_id, activity0.kernel_id, activity0.sysrepoperation_id
FROM activity activity0


This results in these timings:
- executeQuery (executing the prepared statement using jdbc connection on localhost): 595ms
- rs.next (looping the resultset, which contains a lot of results due to the basic qry without conditions): 20404ms

I'm not sure that these figures are representative but as I indicated, this is a qry for testing only. Moving to the real target of my tests we observe the following sql:

SELECT DISTINCT activity0.activity_id, activity0.sequencenr, activity0.name_mlid, activity0.name, activity0.description_mlid, activity0.description, activity0.durationunit_enumid, activity0.duration, activity0.required, activity0.predecessortype_enumid, activity0.successortype_enumid, activity0.removefromworklist, activity0.lastactivity_id, activity0.lifecyclereporting, activity0.duedate, activity0.priority_enumid, activity0.notify, activity0.timestamp, activity0.ActivityType_id, activity0.container_id, activity0.realization_id, activity0.kernel_id, activity0.sysrepoperation_id
FROM activity activity0 LEFT OUTER JOIN activityhistory activityhistory0 ON activityhistory0.activityhistory_id = activity0.lastactivity_id
LEFT OUTER JOIN activityuseraccountrole activityuseraccountrole0 ON activityuseraccountrole0.activity_id = activity0.activity_id
LEFT OUTER JOIN activityhistoryuseraccount activityhistoryuseraccount0 ON activityhistoryuseraccount0.ActivityHistory_id = activityhistory0.activityhistory_id  
WHERE activity0.kernel_id IS NULL
AND activity0.realization_id IS NULL
AND NOT activityhistory0.activitystate_enumid IN (37, 30, 463, 33, 464)  
AND ((activityuseraccountrole0.useraccountrole_id IN (1, 3)  
AND (activity0.removefromworklist = 0  
OR activityhistoryuseraccount0.UserAccount_id IS NULL))
OR activityhistoryuseraccount0.UserAccount_id = 600301)


Executing this query leads to a long time of processing without ever finishing resulting in a crash, attached in ignite-perf.txt.

Basically I was expecting this sql to fly in memory, so maybe I am doing something wrong?

Attached you can also find the relevant classes I am using:
samplecode.zip

The cache is configured as follows:

            CacheConfiguration<ActivityKey, Activity> activityCacheCfg = CacheConfig.cache("Activity", new SofIgniteDSStoreFactory<ActivityKey, Activity>());
            CacheConfiguration<ActivityhistoryKey, Activityhistory> activityHistoryCacheCfg = CacheConfig.cache("ActivityHistory", new SofIgniteDSStoreFactory<ActivityhistoryKey, Activityhistory>());
            CacheConfiguration<ActivityhistoryuseraccountKey, Activityhistoryuseraccount> activityHistoryUserAccountCacheCfg = CacheConfig.cache("ActivityHistoryUseraccount", new SofIgniteDSStoreFactory<ActivityhistoryuseraccountKey, Activityhistoryuseraccount>());
            CacheConfiguration<ActivityuseraccountroleKey, Activityuseraccountrole> activityUseraccountRoleCacheCfg = CacheConfig.cache("ActivityUseraccountRole", new SofIgniteDSStoreFactory<ActivityuseraccountroleKey, Activityuseraccountrole>());
           
            cfg.setCacheConfiguration(activityCacheCfg, activityHistoryCacheCfg, activityHistoryUserAccountCacheCfg, activityUseraccountRoleCacheCfg);


And all data is loaded like this:

                // Load Activities
                IgniteCache<ActivityKey, Activity> activityCache = ignite.getOrCreateCache("Activity");
                long start = System.currentTimeMillis();
                activityCache.loadCache(null);
                long end = System.currentTimeMillis();
                System.out.println("Loaded Activity - Count #" + activityCache.size(CachePeekMode.ALL) + " in " + (end-start) + "ms");
               
                // Load Activity Histories
                IgniteCache<ActivityhistoryKey, Activityhistory> activityHistoryCache = ignite.getOrCreateCache("ActivityHistory");
                start = System.currentTimeMillis();
                activityHistoryCache.loadCache(null);
                end = System.currentTimeMillis();
                System.out.println("Loaded ActivityHistory - Count #" + activityHistoryCache.size(CachePeekMode.ALL) + " in " + (end-start) + "ms");
                               
                // Load Activity Histories Useraccount
                IgniteCache<ActivityhistoryuseraccountKey, Activityhistoryuseraccount> activityHistoryUseraccountCache = ignite.getOrCreateCache("ActivityHistoryUseraccount");
                start = System.currentTimeMillis();
                activityHistoryUseraccountCache.loadCache(null);
                end = System.currentTimeMillis();
                System.out.println("Loaded ActivityHistoryUserAccount - Count #" + activityHistoryUseraccountCache.size(CachePeekMode.ALL) + " in " + (end-start) + "ms");
               
                // Load Activity Useraccount Role
                IgniteCache<ActivityuseraccountroleKey, Activityuseraccountrole> activityUseraccountRoleCache = ignite.getOrCreateCache("ActivityUseraccountRole");
                start = System.currentTimeMillis();
                activityUseraccountRoleCache.loadCache(null);
                end = System.currentTimeMillis();
                System.out.println("Loaded ActivityUseraccountRole - Count #" + activityUseraccountRoleCache.size(CachePeekMode.ALL) + " in " + (end-start) + "ms");


Any guidance would be greatly appreciated.

best regards
jan
vkulichenko vkulichenko
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hi Jan,

Looks like you're running out of memory and having high GC load. Indexes and query execution requires some additional memory, you should take this into account when planning capacity. Can you try to allocate more heap memory and check if it helps? I would also recommend to use JVM settings provided in [1], there are proven to be effective in majority of use cases.

[1] https://apacheignite.readme.io/docs/jvm-and-system-tuning#section-basic-jvm-configuration

-Val
jan.swaelens jan.swaelens
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hello,

I adapted the JVM settings as follows:
 -server -XX:PermSize=256m -Xms1g -Xmx8g -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+UseTLAB -XX:NewSize=128m -XX:MaxNewSize=128m -XX:MaxTenuringThreshold=0 -XX:SurvivorRatio=1024 -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=60 -XX:+DisableExplicitGC

The first SQL now runs as follows:
executeQuery: 1017ms
rs.next: 15118ms
> Which is 5 seconds faster on the query result iteration.

The big sql still runs very long (but without errors).
Based on the log I don't think it is in need of memory now and GC also looks under control:

Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=f4f5b285, name=null, uptime=00:28:00:175]
    ^-- H/N/C [hosts=1, nodes=1, CPUs=8]
    ^-- CPU [cur=13.73%, avg=17.07%, GC=0.17%]
    ^-- Heap [used=2890MB, free=64.72%, comm=4805MB]
    ^-- Non heap [used=263MB, free=13.34%, comm=273MB]
    ^-- Public thread pool [active=1, idle=15, qSize=0]
    ^-- System thread pool [active=0, idle=16, qSize=0]
    ^-- Outbound messages queue [size=0]
 INFO  [20160504 08:51:56] -
Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=f4f5b285, name=null, uptime=00:29:00:192]
    ^-- H/N/C [hosts=1, nodes=1, CPUs=8]
    ^-- CPU [cur=13.7%, avg=16.97%, GC=0.2%]
    ^-- Heap [used=2800MB, free=65.81%, comm=4805MB]
    ^-- Non heap [used=263MB, free=13.34%, comm=273MB]
    ^-- Public thread pool [active=1, idle=15, qSize=0]
    ^-- System thread pool [active=0, idle=16, qSize=0]
    ^-- Outbound messages queue [size=0]


Minutes further:

Metrics for local node (to disable set 'metricsLogFrequency' to 0)
    ^-- Node [id=c8a9b84a, name=null, uptime=00:28:00:136]
    ^-- H/N/C [hosts=1, nodes=1, CPUs=8]
    ^-- CPU [cur=13.53%, avg=15.33%, GC=0.2%]
    ^-- Heap [used=2671MB, free=67.39%, comm=4691MB]
    ^-- Non heap [used=156MB, free=48.68%, comm=266MB]
    ^-- Public thread pool [active=1, idle=15, qSize=0]
    ^-- System thread pool [active=0, idle=16, qSize=0]
    ^-- Outbound messages queue [size=0]

At this point I just kill the server ;-).

br
jan
Denis Magda Denis Magda
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hi Jan,

I would suggest double-checking that the most selective indexes are chosen by Ignite SQL engine and there are no full scans during a SQL query execution.

To fulfill this you can use "EXPLAIN" statement to see an execution plan of every query [1]. If a index is not optimally selected for a query then you can create a group index if needed [2].

[1] https://apacheignite.readme.io/docs/sql-queries#using-explain
[2] https://apacheignite.readme.io/docs/sql-queries#section-group-indexes
Alexey Kuznetsov Alexey Kuznetsov
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hi Jan,

You could also see EXPLAIN in Web Console SQL screen.
See Addons page on Ignite site: https://ignite.apache.org/addons.html

On Wed, May 4, 2016 at 6:49 PM, Denis Magda <[hidden email]> wrote:
Hi Jan,

I would suggest double-checking that the most selective indexes are chosen
by Ignite SQL engine and there are no full scans during a SQL query
execution.

To fulfill this you can use "EXPLAIN" statement to see an execution plan of
every query [1]. If a index is not optimally selected for a query then you
can create a group index if needed [2].

[1] https://apacheignite.readme.io/docs/sql-queries#using-explain
[2] https://apacheignite.readme.io/docs/sql-queries#section-group-indexes



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Unexpected-performance-issue-with-SQL-query-followed-by-error-tp4726p4760.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.



--
Alexey Kuznetsov
GridGain Systems
www.gridgain.com
jan.swaelens jan.swaelens
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Thanks,

It indeed looks like its not using indexes. I'll have a go with it and let you know where I ended up.

SELECT DISTINCT
    ACTIVITY0.ACTIVITY_ID AS __C0,
    ACTIVITY0.SEQUENCENR AS __C1,
    ACTIVITY0.NAME_MLID AS __C2,
    ACTIVITY0.NAME AS __C3,
    ACTIVITY0.DESCRIPTION_MLID AS __C4,
    ACTIVITY0.DESCRIPTION AS __C5,
    ACTIVITY0.DURATIONUNIT_ENUMID AS __C6,
    ACTIVITY0.DURATION AS __C7,
    ACTIVITY0.REQUIRED AS __C8,
    ACTIVITY0.PREDECESSORTYPE_ENUMID AS __C9,
    ACTIVITY0.SUCCESSORTYPE_ENUMID AS __C10,
    ACTIVITY0.REMOVEFROMWORKLIST AS __C11,
    ACTIVITY0.LASTACTIVITY_ID AS __C12,
    ACTIVITY0.LIFECYCLEREPORTING AS __C13,
    ACTIVITY0.DUEDATE AS __C14,
    ACTIVITY0.PRIORITY_ENUMID AS __C15,
    ACTIVITY0.NOTIFY AS __C16,
    ACTIVITY0.TIMESTAMP AS __C17,
    ACTIVITY0.ACTIVITYTYPE_ID AS __C18,
    ACTIVITY0.CONTAINER_ID AS __C19,
    ACTIVITY0.REALIZATION_ID AS __C20,
    ACTIVITY0.KERNEL_ID AS __C21,
    ACTIVITY0.SYSREPOPERATION_ID AS __C22
FROM "Activity".ACTIVITY ACTIVITY0
    /* "Activity".FI_ACTIVITY2: KERNEL_ID IS NULL */
    /* WHERE (ACTIVITY0.KERNEL_ID IS NULL)
        AND (ACTIVITY0.REALIZATION_ID IS NULL)
    */
LEFT OUTER JOIN "Activity".ACTIVITYHISTORY ACTIVITYHISTORY0
    /* "Activity".PK_ACTIVITYHISTORY: ACTIVITYHISTORY_ID = ACTIVITY0.LASTACTIVITY_ID */
    ON ACTIVITYHISTORY0.ACTIVITYHISTORY_ID = ACTIVITY0.LASTACTIVITY_ID
LEFT OUTER JOIN "Activity".ACTIVITYUSERACCOUNTROLE ACTIVITYUSERACCOUNTROLE0
    /* "Activity".ACTIVITYUSERACCOUNTROLE.__SCAN_ */
    ON ACTIVITYUSERACCOUNTROLE0.ACTIVITY_ID = ACTIVITY0.ACTIVITY_ID
LEFT OUTER JOIN "Activity".ACTIVITYHISTORYUSERACCOUNT ACTIVITYHISTORYUSERACCOUNT0
    /* "Activity".ACTIVITYHISTORYUSERACCOUNT.__SCAN_ */
    ON ACTIVITYHISTORYUSERACCOUNT0.ACTIVITYHISTORY_ID = ACTIVITYHISTORY0.ACTIVITYHISTORY_ID
WHERE ((NOT (ACTIVITYHISTORY0.ACTIVITYSTATE_ENUMID IN(37, 30, 463, 33, 464)))
    AND ((ACTIVITY0.KERNEL_ID IS NULL)
    AND (ACTIVITY0.REALIZATION_ID IS NULL)))
    AND ((ACTIVITYHISTORYUSERACCOUNT0.USERACCOUNT_ID = 600301)
    OR ((ACTIVITYUSERACCOUNTROLE0.USERACCOUNTROLE_ID IN(1, 3))
    AND ((ACTIVITY0.REMOVEFROMWORKLIST = 0)
    OR (ACTIVITYHISTORYUSERACCOUNT0.USERACCOUNT_ID IS NULL))))
SELECT DISTINCT
    __C0 AS ACTIVITY_ID,
    __C1 AS SEQUENCENR,
    __C2 AS NAME_MLID,
    __C3 AS NAME,
    __C4 AS DESCRIPTION_MLID,
    __C5 AS DESCRIPTION,
    __C6 AS DURATIONUNIT_ENUMID,
    __C7 AS DURATION,
    __C8 AS REQUIRED,
    __C9 AS PREDECESSORTYPE_ENUMID,
    __C10 AS SUCCESSORTYPE_ENUMID,
    __C11 AS REMOVEFROMWORKLIST,
    __C12 AS LASTACTIVITY_ID,
    __C13 AS LIFECYCLEREPORTING,
    __C14 AS DUEDATE,
    __C15 AS PRIORITY_ENUMID,
    __C16 AS NOTIFY,
    __C17 AS TIMESTAMP,
    __C18 AS ACTIVITYTYPE_ID,
    __C19 AS CONTAINER_ID,
    __C20 AS REALIZATION_ID,
    __C21 AS KERNEL_ID,
    __C22 AS SYSREPOPERATION_ID
FROM PUBLIC.__T0
    /* "Activity"."merge_scan" */

br
jan
jan.swaelens jan.swaelens
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

I tried to defined the grouped indexes but I see no result on the explain plan nor on the actual run. This must mean that either I am doing something wrong or that something is going wrong.

First attempt I annotated the fields on the objects, for example an extract of the Activity pojo:

    /** Value for activityId. */
    @QuerySqlField(orderedGroups={@QuerySqlField.Group(name = "Activity_idx", order = 0, descending = true)})
    private long activityId;

    /** Value for realizationId. */
    @QuerySqlField(orderedGroups={@QuerySqlField.Group(name = "Activity_idx", order = 1, descending = true)})
    private Long realizationId;

    /** Value for kernelId. */
    @QuerySqlField(orderedGroups={@QuerySqlField.Group(name = "Activity_idx", order = 2, descending = true)})
    private Long kernelId;

    /** Value for removefromworklist. */
    @QuerySqlField(orderedGroups={@QuerySqlField.Group(name = "Activity_idx", order = 3, descending = true)})
    private boolean removefromworklist;

    /** Value for lastactivityId. */
    @QuerySqlField(orderedGroups={@QuerySqlField.Group(name = "Activity_idx", order = 4, descending = true)})
    private Long lastactivityId;


Since that did not work I also had an attempt to define it on the cache configuration (query entity):

        QueryIndex gIdx = new QueryIndex();
        idxs.add(gIdx);
        gIdx.setName("Activity_idx");
       
        Collection<String> gFields = new ArrayList<>();
        gFields.add("activityId");
        gFields.add("realizationId");
        gFields.add("kernelId");
        gFields.add("removefromworklist");
        gFields.add("lastactivityId");
        gIdx.setFieldNames(gFields, true);



Could it be that the field aliases I use are causing this? Or something else I am missing?

tx
Alexei Scherbakov Alexei Scherbakov
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hi,

I think your query should be rewritten for correct index usage.
Ignite has some known pitfalls concerning index usage [1].
Also, join order is sensitive to index configuration.
FIrst specify joins using indexes.

Could you provide your business model pojos and current indexes configuration?


2016-05-09 14:23 GMT+03:00 jan.swaelens <[hidden email]>:
I tried to defined the grouped indexes but I see no result on the explain
plan nor on the actual run. This must mean that either I am doing something
wrong or that something is going wrong.

First attempt I annotated the fields on the objects, for example an extract
of the Activity pojo:

/    /** Value for activityId. */
    @QuerySqlField(orderedGroups={@QuerySqlField.Group(name =
"Activity_idx", order = 0, descending = true)})
    private long activityId;

    /** Value for realizationId. */
    @QuerySqlField(orderedGroups={@QuerySqlField.Group(name =
"Activity_idx", order = 1, descending = true)})
    private Long realizationId;

    /** Value for kernelId. */
    @QuerySqlField(orderedGroups={@QuerySqlField.Group(name =
"Activity_idx", order = 2, descending = true)})
    private Long kernelId;

    /** Value for removefromworklist. */
    @QuerySqlField(orderedGroups={@QuerySqlField.Group(name =
"Activity_idx", order = 3, descending = true)})
    private boolean removefromworklist;

    /** Value for lastactivityId. */
    @QuerySqlField(orderedGroups={@QuerySqlField.Group(name =
"Activity_idx", order = 4, descending = true)})
    private Long lastactivityId;/

Since that did not work I also had an attempt to define it on the cache
configuration (query entity):

/        QueryIndex gIdx = new QueryIndex();
        idxs.add(gIdx);
        gIdx.setName("Activity_idx");

        Collection<String> gFields = new ArrayList<>();
        gFields.add("activityId");
        gFields.add("realizationId");
        gFields.add("kernelId");
        gFields.add("removefromworklist");
        gFields.add("lastactivityId");
        gIdx.setFieldNames(gFields, true);/


Could it be that the field aliases I use are causing this? Or something else
I am missing?

tx



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Unexpected-performance-issue-with-SQL-query-followed-by-error-tp4726p4846.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.



--

Best regards,
Alexei Scherbakov
jan.swaelens jan.swaelens
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hello,

Please find the attached pojo instances with group index annotations.
JoinPerfPojos.zip

Yes I understand that there are probably better ways to retrieve the data, but the point of my exercise is to see how we can slide in an in memory solution without actually impacting the implementation of the business logic as coded today.

Thanks for your insights!
Alexei Scherbakov Alexei Scherbakov
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hi,

In current state of SQL engine where is a very high probability for necessity of query modification for efficient use with Ignite.
I'll look into your data soon. Was very busy last week.

2016-05-17 17:37 GMT+03:00 jan.swaelens <[hidden email]>:
Hello,

Please find the attached pojo instances with group index annotations.
JoinPerfPojos.zip
<http://apache-ignite-users.70518.x6.nabble.com/file/n4993/JoinPerfPojos.zip>

Yes I understand that there are probably better ways to retrieve the data,
but the point of my exercise is to see how we can slide in an in memory
solution without actually impacting the implementation of the business logic
as coded today.

Thanks for your insights!



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Unexpected-performance-issue-with-SQL-query-followed-by-error-tp4726p4993.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.



--

Best regards,
Alexei Scherbakov
Alexei Scherbakov Alexei Scherbakov
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hi,

I've looked closer to the query.
First, it should be splitted by 3 sub-queries.
Each sub-query must be optimized separately and joined by UNION ALL.
Let's start from the first query.
I've provided updated indexes for your model in the attachment.
Please start server with enabled H2 console[1] and run there the following query after the data is loaded:

EXPLAIN ANALYZE SELECT DISTINCT * FROM activity activity0
LEFT OUTER JOIN "activityuseraccountrole".activityuseraccountrole activityuseraccountrole0
ON activityuseraccountrole0.activityId = activity0.activityId
AND activityuseraccountrole0.useraccountroleId IN (1, 3)

LEFT OUTER JOIN "activityhistory".activityhistory activityhistory0
ON activityhistory0.activityhistoryId = activity0.lastactivityId
AND activityhistory0.activitystateEnumid NOT IN (37, 30, 463, 33, 464)

LEFT OUTER JOIN "activityhistoryuseraccount".activityhistoryuseraccount activityhistoryuseraccount0
ON activityhistoryuseraccount0.activityHistoryId = activityhistory0.activityhistoryId

WHERE activity0.kernelId IS NULL
AND activity0.realizationId IS NULL
AND activity0.removefromworklist = 0
Grab the output and send it to me.


2016-05-23 16:36 GMT+03:00 Alexei Scherbakov <[hidden email]>:
Hi,

In current state of SQL engine where is a very high probability for necessity of query modification for efficient use with Ignite.
I'll look into your data soon. Was very busy last week.

2016-05-17 17:37 GMT+03:00 jan.swaelens <[hidden email]>:
Hello,

Please find the attached pojo instances with group index annotations.
JoinPerfPojos.zip
<http://apache-ignite-users.70518.x6.nabble.com/file/n4993/JoinPerfPojos.zip>

Yes I understand that there are probably better ways to retrieve the data,
but the point of my exercise is to see how we can slide in an in memory
solution without actually impacting the implementation of the business logic
as coded today.

Thanks for your insights!



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Unexpected-performance-issue-with-SQL-query-followed-by-error-tp4726p4993.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.



--

Best regards,
Alexei Scherbakov



--

Best regards,
Alexei Scherbakov
jan.swaelens jan.swaelens
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hello Alexei,

Thanks for this! Could you provide the attachment you speak of I think you forgot to attach it.

br
jan
Alexei Scherbakov Alexei Scherbakov
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hi, Jan

Added the attachment.


2016-05-25 9:56 GMT+03:00 jan.swaelens <[hidden email]>:
Hello Alexei,

Thanks for this! Could you provide the attachment you speak of I think you
forgot to attach it.

br
jan



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Unexpected-performance-issue-with-SQL-query-followed-by-error-tp4726p5162.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.



--

Best regards,
Alexei Scherbakov

java.zip (18K) Download Attachment
jan.swaelens jan.swaelens
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Thanks,

Added the code and executed the following:

EXPLAIN ANALYZE SELECT DISTINCT * FROM "Activity".activity activity0
LEFT OUTER JOIN "Activity".activityuseraccountrole activityuseraccountrole0
ON activityuseraccountrole0.activity_Id = activity0.activity_Id
AND activityuseraccountrole0.useraccountrole_Id IN (1, 3)

This also keeps running until eternity, well at least for 30 minutes after which I give up. Should I wait it out or does it make sense to add a clause to limit the data?

best regards
jan
Alexei Scherbakov Alexei Scherbakov
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

How much data do you have in both tables?

30 minutes is too long even for full scan in memory.

Please run

EXPLAIN ANALYZE SELECT DISTINCT * FROM "Activity".activity activity0

EXPLAIN ANALYZE SELECT DISTINCT * FROM "Activity".activityuseraccountrole activityuseraccountrole0
WHERE activityuseraccountrole0.useraccountrole_Id IN (1, 3)

Don't you forget to configure GC property, as discussed earlier in this topic ?
Do you have any activity on cache while running the query ?


2016-05-25 16:48 GMT+03:00 jan.swaelens <[hidden email]>:
Thanks,

Added the code and executed the following:

EXPLAIN ANALYZE SELECT DISTINCT * FROM "Activity".activity activity0
LEFT OUTER JOIN "Activity".activityuseraccountrole activityuseraccountrole0
ON activityuseraccountrole0.activity_Id = activity0.activity_Id
AND activityuseraccountrole0.useraccountrole_Id IN (1, 3)

This also keeps running until eternity, well at least for 30 minutes after
which I give up. Should I wait it out or does it make sense to add a clause
to limit the data?

best regards
jan



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Unexpected-performance-issue-with-SQL-query-followed-by-error-tp4726p5194.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.



--

Best regards,
Alexei Scherbakov
jan.swaelens jan.swaelens
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hello,

The activity table is 121823 records and the activityuseraccountrole 1027839 records.

First one runs under a second and produces:

SELECT DISTINCT
    ACTIVITY0._KEY,
    ACTIVITY0._VAL,
    ACTIVITY0.ACTIVITY_ID,
    ACTIVITY0.TIMESTAMP,
    ACTIVITY0.CONTAINER_ID,
    ACTIVITY0.ACTIVITYTYPE_ID,
    ACTIVITY0.REALIZATION_ID,
    ACTIVITY0.KERNEL_ID,
    ACTIVITY0.PREDECESSORTYPE_ENUMID,
    ACTIVITY0.SUCCESSORTYPE_ENUMID,
    ACTIVITY0.DURATIONUNIT_ENUMID,
    ACTIVITY0.NAME,
    ACTIVITY0.NAME_MLID,
    ACTIVITY0.DESCRIPTION,
    ACTIVITY0.DESCRIPTION_MLID,
    ACTIVITY0.DURATION,
    ACTIVITY0.REQUIRED,
    ACTIVITY0.ESTIMSTARTDATE,
    ACTIVITY0.ESTIMSTARTHOUR,
    ACTIVITY0.ESTIMENDHOUR,
    ACTIVITY0.ESTIMENDDATE,
    ACTIVITY0.REMOVEFROMWORKLIST,
    ACTIVITY0.SEQUENCENR,
    ACTIVITY0.SESSION_ID,
    ACTIVITY0.LASTACTIVITY_ID,
    ACTIVITY0.SYSREPOPERATION_ID,
    ACTIVITY0.LIFECYCLEREPORTING,
    ACTIVITY0.DUEDATE,
    ACTIVITY0.PRIORITY_ENUMID,
    ACTIVITY0.NOTIFY
FROM "Activity".ACTIVITY ACTIVITY0
    /* "Activity".ACTIVITY.__SCAN_ */
    /* scanCount: 121824 */


The seconds one also very fast and produces:

SELECT DISTINCT
    ACTIVITYUSERACCOUNTROLE0._KEY,
    ACTIVITYUSERACCOUNTROLE0._VAL,
    ACTIVITYUSERACCOUNTROLE0.ACTIVITY_ID,
    ACTIVITYUSERACCOUNTROLE0.USERACCOUNTROLE_ID
FROM "Activity".ACTIVITYUSERACCOUNTROLE ACTIVITYUSERACCOUNTROLE0
    /* "Activity".ACTIVITYUSERACCOUNTROLE.__SCAN_ */
    /* scanCount: 1027840 */
WHERE ACTIVITYUSERACCOUNTROLE0.USERACCOUNTROLE_ID IN(1, 3)


So basically, the join seems to kill it?

br
jan
jan.swaelens jan.swaelens
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

And indeed, I am running with these options:

MEM_ARGS="-XX:PermSize=256m -Xms1g -Xmx8g -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+UseTLAB -XX:NewSize=128m -XX:MaxNewSize=128m -XX:MaxTenuringThreshold=0 -XX:SurvivorRatio=1024 -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=60 -XX:+DisableExplicitGC -DIGNITE_H2_DEBUG_CONSOLE=true"

thanks
Alexei Scherbakov Alexei Scherbakov
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

I'll try to reproduce your case tomorrow using these cardinalities.
Meanwhile  try to execute the following query.

EXPLAIN ANALYZE SELECT DISTINCT * FROM "Activity".activity activity0
LEFT OUTER JOIN "Activity".activityuseraccountrole activityuseraccountrole0
ON activity0.activity_Id=activityuseraccountrole0.activity_Id

I suspect the IN condition is the culprit.

2016-05-26 17:26 GMT+03:00 jan.swaelens <[hidden email]>:
And indeed, I am running with these options:

/MEM_ARGS="-XX:PermSize=256m -Xms1g -Xmx8g -XX:+UseParNewGC
-XX:+UseConcMarkSweepGC -XX:+UseTLAB -XX:NewSize=128m -XX:MaxNewSize=128m
-XX:MaxTenuringThreshold=0 -XX:SurvivorRatio=1024
-XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=60
-XX:+DisableExplicitGC -DIGNITE_H2_DEBUG_CONSOLE=true"/

thanks



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Unexpected-performance-issue-with-SQL-query-followed-by-error-tp4726p5240.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.



--

Best regards,
Alexei Scherbakov
jan.swaelens jan.swaelens
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hello,

This one has been running for 10 minutes now without producing results - so rather the join.

EXPLAIN ANALYZE SELECT DISTINCT * FROM "Activity".activity activity0
LEFT OUTER JOIN "Activity".activityuseraccountrole activityuseraccountrole0
ON activity0.activity_Id=activityuseraccountrole0.activity_Id


This one works fine though:

EXPLAIN ANALYZE SELECT DISTINCT * FROM "Activity".activity activity0, "Activity".activityuseraccountrole activityuseraccountrole0
WHERE activity0.activity_Id=activityuseraccountrole0.activity_Id


SELECT DISTINCT
    ACTIVITY0._KEY,
    ACTIVITY0._VAL,
    ACTIVITY0.ACTIVITY_ID,
    ACTIVITY0.TIMESTAMP,
    ACTIVITY0.CONTAINER_ID,
    ACTIVITY0.ACTIVITYTYPE_ID,
    ACTIVITY0.REALIZATION_ID,
    ACTIVITY0.KERNEL_ID,
    ACTIVITY0.PREDECESSORTYPE_ENUMID,
    ACTIVITY0.SUCCESSORTYPE_ENUMID,
    ACTIVITY0.DURATIONUNIT_ENUMID,
    ACTIVITY0.NAME,
    ACTIVITY0.NAME_MLID,
    ACTIVITY0.DESCRIPTION,
    ACTIVITY0.DESCRIPTION_MLID,
    ACTIVITY0.DURATION,
    ACTIVITY0.REQUIRED,
    ACTIVITY0.ESTIMSTARTDATE,
    ACTIVITY0.ESTIMSTARTHOUR,
    ACTIVITY0.ESTIMENDHOUR,
    ACTIVITY0.ESTIMENDDATE,
    ACTIVITY0.REMOVEFROMWORKLIST,
    ACTIVITY0.SEQUENCENR,
    ACTIVITY0.SESSION_ID,
    ACTIVITY0.LASTACTIVITY_ID,
    ACTIVITY0.SYSREPOPERATION_ID,
    ACTIVITY0.LIFECYCLEREPORTING,
    ACTIVITY0.DUEDATE,
    ACTIVITY0.PRIORITY_ENUMID,
    ACTIVITY0.NOTIFY,
    ACTIVITYUSERACCOUNTROLE0._KEY,
    ACTIVITYUSERACCOUNTROLE0._VAL,
    ACTIVITYUSERACCOUNTROLE0.ACTIVITY_ID,
    ACTIVITYUSERACCOUNTROLE0.USERACCOUNTROLE_ID
FROM "Activity".ACTIVITYUSERACCOUNTROLE ACTIVITYUSERACCOUNTROLE0
    /* "Activity".ACTIVITYUSERACCOUNTROLE.__SCAN_ */
    /* scanCount: 1027840 */
INNER JOIN "Activity".ACTIVITY ACTIVITY0
    /* "Activity".PK_ACTIVITY: ACTIVITY_ID = ACTIVITYUSERACCOUNTROLE0.ACTIVITY_ID */
    ON 1=1
    /* scanCount: 2055678 */
WHERE ACTIVITY0.ACTIVITY_ID = ACTIVITYUSERACCOUNTROLE0.ACTIVITY_ID


So looks like the LEFT OUTER is the culprit, or at least one of them.

br
jan
Alexei Scherbakov Alexei Scherbakov
Reply | Threaded
Open this post in threaded view
|

Re: Unexpected performance issue with SQL query followed by error

Hi,

The query doesn't use index.
Did you correctly apply my changes to indexes in the model ?
Here my output using similar cardinalities (100k activities, 1M roles):

Query:
EXPLAIN  ANALYZE SELECT activity0._VAL ,  activityuseraccountrole0 ._VAL FROM "activity".ACTIVITY activity0 LEFT OUTER JOIN "activityuseraccountrole".ACTIVITYUSERACCOUNTROLE activityuseraccountrole0 
ON activity0.activityId=activityuseraccountrole0.activityId;

Output:
SELECT
    ACTIVITY0._VAL,
    ACTIVITYUSERACCOUNTROLE0._VAL
FROM "activity".ACTIVITY ACTIVITY0
    /* "activity".ACTIVITY.__SCAN_ */
    /* scanCount: 100001 */
LEFT OUTER JOIN "activityuseraccountrole".ACTIVITYUSERACCOUNTROLE ACTIVITYUSERACCOUNTROLE0
    /* "activityuseraccountrole"."Activityuseraccountrole_idx": ACTIVITYID = ACTIVITY0.ACTIVITYID */
    ON ACTIVITY0.ACTIVITYID = ACTIVITYUSERACCOUNTROLE0.ACTIVITYID
    /* scanCount: 1100000 */

(1 row, 1190 ms)


2016-05-27 9:23 GMT+03:00 jan.swaelens <[hidden email]>:
Hello,

This one has been running for 10 minutes now without producing results - so
rather the join.

/EXPLAIN ANALYZE SELECT DISTINCT * FROM "Activity".activity activity0
LEFT OUTER JOIN "Activity".activityuseraccountrole activityuseraccountrole0
ON activity0.activity_Id=activityuseraccountrole0.activity_Id/

This one works fine though:

/EXPLAIN ANALYZE SELECT DISTINCT * FROM "Activity".activity activity0,
"Activity".activityuseraccountrole activityuseraccountrole0
WHERE activity0.activity_Id=activityuseraccountrole0.activity_Id/

/SELECT DISTINCT
    ACTIVITY0._KEY,
    ACTIVITY0._VAL,
    ACTIVITY0.ACTIVITY_ID,
    ACTIVITY0.TIMESTAMP,
    ACTIVITY0.CONTAINER_ID,
    ACTIVITY0.ACTIVITYTYPE_ID,
    ACTIVITY0.REALIZATION_ID,
    ACTIVITY0.KERNEL_ID,
    ACTIVITY0.PREDECESSORTYPE_ENUMID,
    ACTIVITY0.SUCCESSORTYPE_ENUMID,
    ACTIVITY0.DURATIONUNIT_ENUMID,
    ACTIVITY0.NAME,
    ACTIVITY0.NAME_MLID,
    ACTIVITY0.DESCRIPTION,
    ACTIVITY0.DESCRIPTION_MLID,
    ACTIVITY0.DURATION,
    ACTIVITY0.REQUIRED,
    ACTIVITY0.ESTIMSTARTDATE,
    ACTIVITY0.ESTIMSTARTHOUR,
    ACTIVITY0.ESTIMENDHOUR,
    ACTIVITY0.ESTIMENDDATE,
    ACTIVITY0.REMOVEFROMWORKLIST,
    ACTIVITY0.SEQUENCENR,
    ACTIVITY0.SESSION_ID,
    ACTIVITY0.LASTACTIVITY_ID,
    ACTIVITY0.SYSREPOPERATION_ID,
    ACTIVITY0.LIFECYCLEREPORTING,
    ACTIVITY0.DUEDATE,
    ACTIVITY0.PRIORITY_ENUMID,
    ACTIVITY0.NOTIFY,
    ACTIVITYUSERACCOUNTROLE0._KEY,
    ACTIVITYUSERACCOUNTROLE0._VAL,
    ACTIVITYUSERACCOUNTROLE0.ACTIVITY_ID,
    ACTIVITYUSERACCOUNTROLE0.USERACCOUNTROLE_ID
FROM "Activity".ACTIVITYUSERACCOUNTROLE ACTIVITYUSERACCOUNTROLE0
    /* "Activity".ACTIVITYUSERACCOUNTROLE.__SCAN_ */
    /* scanCount: 1027840 */
INNER JOIN "Activity".ACTIVITY ACTIVITY0
    /* "Activity".PK_ACTIVITY: ACTIVITY_ID =
ACTIVITYUSERACCOUNTROLE0.ACTIVITY_ID */
    ON 1=1
    /* scanCount: 2055678 */
WHERE ACTIVITY0.ACTIVITY_ID = ACTIVITYUSERACCOUNTROLE0.ACTIVITY_ID/

So looks like the LEFT OUTER is the culprit, or at least one of them.

br
jan



--
View this message in context: http://apache-ignite-users.70518.x6.nabble.com/Unexpected-performance-issue-with-SQL-query-followed-by-error-tp4726p5267.html
Sent from the Apache Ignite Users mailing list archive at Nabble.com.



--

Best regards,
Alexei Scherbakov
12