Execution monitor refresh causes the whole table blinks

[tomas-knap]

When execution monitor is refreshed, it is blinking, which was not happening before. See ODCS-test

[tomas-knap]

Also when loading pipeline list, first record is loaded first and then the rest (also such problem does not happen before)

[tomas-knap]

Happens in all tables

[bogo777]

It looks like some delay in db access:

For pipeline list:

20:54:48.379 [http-bio-8084-exec-35] DEBUG o.e.p.logging.sql - 2014-02-10 20:54:48.379--ServerSession(1614751376)--Connection(1552388229)--SELECT COUNT(ID) FROM ppl_model
20:54:48.383 [http-bio-8084-exec-35] DEBUG o.e.p.logging.sql - 2014-02-10 20:54:48.383--ServerSession(1614751376)--Connection(58539980)--SELECT TOP 0,1 ID AS a1, DESCRIPTION AS a2, last_change AS a3, NAME AS a4, visibility AS a5, user_id AS a6 FROM ppl_model
20:54:48.390 [http-bio-8084-exec-35] DEBUG o.e.p.logging.sql - 2014-02-10 20:54:48.39--ServerSession(1614751376)--Connection(1916207590)--SELECT TOP 1,9 ID AS a1, DESCRIPTION AS a2, last_change AS a3, NAME AS a4, visibility AS a5, user_id AS a6 FROM ppl_model
20:54:48.395 [http-bio-8084-exec-35] DEBUG o.e.p.logging.sql - 2014-02-10 20:54:48.394--ServerSession(1614751376)--Connection(451933599)--SELECT TOP 0,1 ID AS a1, t_end AS a2, debug_mode AS a3, t_last_change AS a4, silent_mode AS a5, t_start AS a6, STATUS AS a7, stop AS a8, debugnode_id AS a9, owner_id AS a10, pipeline_id AS a11, schedule_id AS a12, context_id AS a13 FROM exec_pipeline WHERE (((pipeline_id = ?) AND (STATUS IN (?,?,?))) AND (t_end IS NOT NULL)) ORDER BY t_end DESC
    bind => [1, 4, 5, 6]
20:54:48.720 [http-bio-8084-exec-35] DEBUG o.e.p.logging.sql - 2014-02-10 20:54:48.72--ServerSession(1614751376)--Connection(1315680341)--SELECT TOP 0,1 ID AS a1, t_end AS a2, debug_mode AS a3, t_last_change AS a4, silent_mode AS a5, t_start AS a6, STATUS AS a7, stop AS a8, debugnode_id AS a9, owner_id AS a10, pipeline_id AS a11, schedule_id AS a12, context_id AS a13 FROM exec_pipeline WHERE (((pipeline_id = ?) AND (STATUS IN (?,?,?))) AND (t_end IS NOT NULL)) ORDER BY t_end DESC
    bind => [154, 4, 5, 6]
20:54:48.774 [http-bio-8084-exec-35] DEBUG o.e.p.logging.sql - 2014-02-10 20:54:48.774--ServerSession(1614751376)--Connection(184826872)--SELECT TOP 0,1 ID AS a1, t_end AS a2, debug_mode AS a3, t_last_change AS a4, silent_mode AS a5, t_start AS a6, STATUS AS a7, stop AS a8, debugnode_id AS a9, owner_id AS a10, pipeline_id AS a11, schedule_id AS a12, context_id AS a13 FROM exec_pipeline WHERE (((pipeline_id = ?) AND (STATUS IN (?,?,?))) AND (t_end IS NOT NULL)) ORDER BY t_end DESC
    bind => [155, 4, 5, 6]
20:54:48.780 [http-bio-8084-exec-35] DEBUG o.e.p.logging.sql - 2014-02-10 20:54:48.779--ServerSession(1614751376)--Connection(833121297)--SELECT TOP 0,1 ID AS a1, t_end AS a2, debug_mode AS a3, t_last_change AS a4, silent_mode AS a5, t_start AS a6, STATUS AS a7, stop AS a8, debugnode_id AS a9, owner_id AS a10, pipeline_id AS a11, schedule_id AS a12, context_id AS a13 FROM exec_pipeline WHERE (((pipeline_id = ?) AND (STATUS IN (?,?,?))) AND (t_end IS NOT NULL)) ORDER BY t_end DESC
    bind => [156, 4, 5, 6]
20:54:48.784 [http-bio-8084-exec-35] DEBUG o.e.p.logging.sql - 2014-02-10 20:54:48.784--ServerSession(1614751376)--Connection(1422376949)--SELECT TOP 0,1 ID AS a1, t_end AS a2, debug_mode AS a3, t_last_change AS a4, silent_mode AS a5, t_start AS a6, STATUS AS a7, stop AS a8, debugnode_id AS a9, owner_id AS a10, pipeline_id AS a11, schedule_id AS a12, context_id AS a13 FROM exec_pipeline WHERE (((pipeline_id = ?) AND (STATUS IN (?,?,?,?,?,?,?))) AND (t_end IS NOT NULL)) ORDER BY t_end DESC
    bind => [156, 0, 1, 2, 3, 4, 5, 6]

execution list:

20:55:54.309 [http-bio-8084-exec-36] DEBUG o.e.p.logging.sql - 2014-02-10 20:55:54.308--ServerSession(1614751376)--Connection(1437863558)--SELECT COUNT(ID) FROM exec_pipeline
20:55:54.312 [http-bio-8084-exec-36] DEBUG o.e.p.logging.sql - 2014-02-10 20:55:54.312--ServerSession(1614751376)--Connection(1525771978)--SELECT TOP 0,1 ID AS a1, t_end AS a2, debug_mode AS a3, t_last_change AS a4, silent_mode AS a5, t_start AS a6, STATUS AS a7, stop AS a8, debugnode_id AS a9, owner_id AS a10, pipeline_id AS a11, schedule_id AS a12, context_id AS a13 FROM exec_pipeline ORDER BY ID DESC
20:55:54.318 [http-bio-8084-exec-36] DEBUG o.e.p.logging.sql - 2014-02-10 20:55:54.318--ServerSession(1614751376)--Connection(892723955)--SELECT COUNT(t0.ID) FROM exec_pipeline t0, usr_user t1 WHERE (t1.USERNAME LIKE ? AND (t1.ID = t0.owner_id))
    bind => [**admin]
20:55:54.324 [http-bio-8084-exec-36] DEBUG o.e.p.logging.sql - 2014-02-10 20:55:54.323--ServerSession(1614751376)--Connection(789122523)--SELECT TOP 0,1 t0.ID AS a1, t0.t_end AS a2, t0.debug_mode AS a3, t0.t_last_change AS a4, t0.silent_mode AS a5, t0.t_start AS a6, t0.STATUS AS a7, t0.stop AS a8, t0.debugnode_id AS a9, t0.owner_id AS a10, t0.pipeline_id AS a11, t0.schedule_id AS a12, t0.context_id AS a13 FROM exec_pipeline t0, usr_user t1 WHERE (t1.USERNAME LIKE ? AND (t1.ID = t0.owner_id)) ORDER BY t0.ID DESC
    bind => [**admin]
20:55:54.328 [http-bio-8084-exec-36] DEBUG o.e.p.logging.sql - 2014-02-10 20:55:54.328--ServerSession(1614751376)--Connection(243980471)--SELECT TOP 1,9 t0.ID AS a1, t0.t_end AS a2, t0.debug_mode AS a3, t0.t_last_change AS a4, t0.silent_mode AS a5, t0.t_start AS a6, t0.STATUS AS a7, t0.stop AS a8, t0.debugnode_id AS a9, t0.owner_id AS a10, t0.pipeline_id AS a11, t0.schedule_id AS a12, t0.context_id AS a13 FROM exec_pipeline t0, usr_user t1 WHERE (t1.USERNAME LIKE ? AND (t1.ID = t0.owner_id)) ORDER BY t0.ID DESC
    bind => [**admin]
20:55:54.395 [http-bio-8084-exec-36] DEBUG o.e.p.logging.sql - 2014-02-10 20:55:54.395--ServerSession(1614751376)--Connection(128743283)--SELECT ID, DESCRIPTION, last_change, NAME, visibility, user_id FROM ppl_model WHERE (ID = ?)
    bind => [155]
20:55:54.398 [http-bio-8084-exec-36] DEBUG o.e.p.logging.sql - 2014-02-10 20:55:54.398--ServerSession(1614751376)--Connection(778447490)--SELECT ID, full_name, u_password, table_rows, USERNAME, email_id FROM usr_user WHERE (ID = ?)
    bind => [1]
20:55:55.008 [http-bio-8084-exec-36] DEBUG o.e.p.logging.sql - 2014-02-10 20:55:55.008--ServerSession(1614751376)--Connection(217336813)--SELECT ID, DESCRIPTION, last_change, NAME, visibility, user_id FROM ppl_model WHERE (ID = ?)
    bind => [155]
20:55:55.011 [http-bio-8084-exec-36] DEBUG o.e.p.logging.sql - 2014-02-10 20:55:55.011--ServerSession(1614751376)--Connection(47905596)--SELECT ID, full_name, u_password, table_rows, USERNAME, email_id FROM usr_user WHERE (ID = ?)
    bind => [1]
20:55:55.015 [http-bio-8084-exec-36] DEBUG o.e.p.logging.sql - 2014-02-10 20:55:55.015--ServerSession(1614751376)--Connection(391402055)--SELECT ID, DESCRIPTION, last_change, NAME, visibility, user_id FROM ppl_model WHERE (ID = ?)
    bind => [1]

@skodape @janvojt Any ideas?

[skodapetr]

Jde o to, že se nejprve načte první řádek a až pak ostatní? (btw. mě to přišlo na jednu stranu docela cool 0: ) Není to prostě to jak se přenáší data v tabulce? Nebo myslíš Bohuslave, že je to opravu tím, že ten load z DB trvá 0.7 vteřiny? - myslíš, že je možné .. že se vyrenderuje stránka a až pak se renderují a poslají položky?

[janvojt]

I agree with Petr, the log does not tell anything about the speed of SQL query. The .7 seconds between the 2 queries may be just some slow java code in between. Did you try to execute query from console?

[janvojt]

I do not think the query SELECT ID, full_name, u_password, table_rows, USERNAME, email_id FROM usr_user WHERE (ID = ?) is going to be problematic, I am guessing there are only few users in DB. Even if there were many, we are searching with primary key, that must be fast.

[bogo777]

I didn't mean that the SQL is responsible for the slowness, but from what I remember from debugging containers and tables, all these queries are result of single command at the frontend/table level. So if this isn't slowness of db(which it almost certainly isn't) this is most propably issue of container or PagedFilter addon. I think I saw some "DbCachedSource" in commits from @skodape which I thought might be related. Also addon version was recently upped, but reverting to older version and rebuilding frontend is lenghty task(at least for me), so I wanted to ask if there aren't any other potential sources this...

[skodapetr]

I can replicate on local host for 4 pipelines, which is positive as I can debug. I may try to add logs into DataSource and container to see what happens on background. But I do not see any reason for such behaviour on first glance.

@bogo777 I may try older version of the container first .. to try this I just need to update pom.xml for frontend?

[bogo777]

Yes, that should be enough. The previous working version was:

filteringtable 0.9.0.v7

[skodapetr]

Well, with the older version all the data are shown at once. So it's probably problem-feature of the container (version 0.9.4.v7).

[tomas-knap]

Is there any problem with the older version, or we switched to the newer one just because such version was available?

[bogo777]

Motivation for upping the version was possible solution to #1025, but if it actually helped wasn't confirmed. For me, the tooltips didn' t show even after the update.

[tomas-knap]

For me, tooltips are working. But I do not know if that was because of that update

[tomas-knap]

Petr has downgraded the version, I will try it out

[tomas-knap]

Please try to debug DBpedia pipeline on http://odcs.xrg.cz:8080/odcleanstore-test/ When exec monitor is refreshed, the table also always disappears (except of the first line) and reappears

[tomas-knap]

@skodape Where was the problem?

[skodapetr]

Byl v tride DbCachedSource source. Když jsem tam přidával ochranu proti chybě "Array can't cast to String" nebo jak to je (je to ta chyba v zobrazeni logu, kdyz jsou moc dlouhe a spatné). Tak jsem tam zanesl tento bug - mimo debug není zase až tak viditelný a proto jsem si ho nevšiml. Nicméně ono ta ochrana stejně byla k ničemu, neb to sice tabulka přežila ale spatla aplikace na nejbližším dotazu. Tedy jsem tonto nadbytečný kód odstranil a snad to bude ok.