Acceleration refresh policies, always shows expired

dealercrm · March 15, 2018, 4:40pm

A data sources table is set to refresh every 2 hours and always shows expired in the reflection window, even though the refreshes are successful.

Help me understand please.

At the MySQL data source level

46%20PM

Then at the data source table level, if you hover over the orange triangle with the error, it states “Expired”
17%20PM

Then we click on jobs to review when the last time the table was queried for incremental updates. This shows that Accelerators are being created every 2 hours, as planned.

We click on the settings of the data sources table and then click on refresh policy. We then see that the refresh policy is set at 2 hours and to expire after 4 hours. We are looking at the error of “Expired” within the hour of when the Accelerator was created.
31%20PM

What am I missing?

I jumped into the server.log, then I find a “Unable to cache materialzation” error. However, when I search for the job, it shows completed.

Here is the server log

2018-03-15 16:30:16,860 [pool-11-thread-1] WARN  c.d.s.a.CachedMaterializationProvider - Unable to cache materialization a4fd6347-f865-47c1-ac37-a909b06632b8
java.lang.AssertionError: null
	at org.apache.calcite.util.Pair.zip(Pair.java:202) ~[calcite-core-1.12.0-201802162217200854-87dbbf1.jar:1.12.0-201802162217200854-87dbbf1]
	at org.apache.calcite.rex.RexUtil.generateCastExpressions(RexUtil.java:177) ~[calcite-core-1.12.0-201802162217200854-87dbbf1.jar:1.12.0-201802162217200854-87dbbf1]
	at org.apache.calcite.rex.RexUtil.generateCastExpressions(RexUtil.java:159) ~[calcite-core-1.12.0-201802162217200854-87dbbf1.jar:1.12.0-201802162217200854-87dbbf1]
	at com.dremio.exec.planner.common.MoreRelOptUtil.createCastRel(MoreRelOptUtil.java:239) ~[dremio-sabot-kernel-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.exec.planner.common.MoreRelOptUtil.createCastRel(MoreRelOptUtil.java:214) ~[dremio-sabot-kernel-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.exec.planner.sql.MaterializationExpander.expand(MaterializationExpander.java:90) ~[dremio-sabot-kernel-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.exec.planner.sql.MaterializationDescriptor.getMaterializationFor(MaterializationDescriptor.java:148) ~[dremio-sabot-kernel-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider.expand(CachedMaterializationProvider.java:288) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider.updateCache(CachedMaterializationProvider.java:239) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider.compareAndSetCache(CachedMaterializationProvider.java:182) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider.refresh(CachedMaterializationProvider.java:164) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider.access$000(CachedMaterializationProvider.java:68) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider$1.run(CachedMaterializationProvider.java:155) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_151]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0_151]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_151]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_151]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_151]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_151]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
2018-03-15 16:30:16,875 [pool-11-thread-1] WARN  c.d.s.a.CachedMaterializationProvider - Unable to cache materialization 6732821f-973b-47fe-8887-785e1a149469
java.lang.AssertionError: null
	at org.apache.calcite.util.Pair.zip(Pair.java:202) ~[calcite-core-1.12.0-201802162217200854-87dbbf1.jar:1.12.0-201802162217200854-87dbbf1]
	at org.apache.calcite.rex.RexUtil.generateCastExpressions(RexUtil.java:177) ~[calcite-core-1.12.0-201802162217200854-87dbbf1.jar:1.12.0-201802162217200854-87dbbf1]
	at org.apache.calcite.rex.RexUtil.generateCastExpressions(RexUtil.java:159) ~[calcite-core-1.12.0-201802162217200854-87dbbf1.jar:1.12.0-201802162217200854-87dbbf1]
	at com.dremio.exec.planner.common.MoreRelOptUtil.createCastRel(MoreRelOptUtil.java:239) ~[dremio-sabot-kernel-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.exec.planner.common.MoreRelOptUtil.createCastRel(MoreRelOptUtil.java:214) ~[dremio-sabot-kernel-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.exec.planner.sql.MaterializationExpander.expand(MaterializationExpander.java:90) ~[dremio-sabot-kernel-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.exec.planner.sql.MaterializationDescriptor.getMaterializationFor(MaterializationDescriptor.java:148) ~[dremio-sabot-kernel-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider.expand(CachedMaterializationProvider.java:288) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider.updateCache(CachedMaterializationProvider.java:239) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider.compareAndSetCache(CachedMaterializationProvider.java:182) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider.refresh(CachedMaterializationProvider.java:164) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider.access$000(CachedMaterializationProvider.java:68) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.service.accelerator.CachedMaterializationProvider$1.run(CachedMaterializationProvider.java:155) [dremio-services-accelerator-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_151]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0_151]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_151]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_151]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_151]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_151]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
2018-03-15 16:30:16,893 [pool-11-thread-1] WARN  c.d.s.a.CachedMaterializationProvider - Unable to cache materialization 9504017d-533b-4d7a-86ab-0ddeb3d98903
java.lang.AssertionError: null
	at org.apache.calcite.util.Pair.zip(Pair.java:202) ~[calcite-core-1.12.0-201802162217200854-87dbbf1.jar:1.12.0-201802162217200854-87dbbf1]
	at org.apache.calcite.rex.RexUtil.generateCastExpressions(RexUtil.java:177) ~[calcite-core-1.12.0-201802162217200854-87dbbf1.jar:1.12.0-201802162217200854-87dbbf1]
	at org.apache.calcite.rex.RexUtil.generateCastExpressions(RexUtil.java:159) ~[calcite-core-1.12.0-201802162217200854-87dbbf1.jar:1.12.0-201802162217200854-87dbbf1]
	at com.dremio.exec.planner.common.MoreRelOptUtil.createCastRel(MoreRelOptUtil.java:239) ~[dremio-sabot-kernel-1.4.9-201802191836310213-7195059.jar:1.4.9-201802191836310213-7195059]
	at com.dremio.exec.planner.common.MoreRelOptUtil.c

dealercrm · March 15, 2018, 6:20pm

Definately has something to do with the incremental update. As I switched back the datasource table to NOT have a reflection. Then switched it to FULL UPDATE.

Then I wrote a query with all the fields in the table 70% of the data in the table, created a reflection on the query and now the reflection is created.

So I still need to figure out why it is failing during the incremental update of the reflection at the datasource table level.

dealercrm · March 21, 2018, 2:36pm

Bump.

Still not able to get any table or query to auto update, always have to choose full update. Which is not going to work long term. Need auto update to provide incremental updates to large data sources that are append only.

Anyone have any examples I could walk through?

doron · March 21, 2018, 5:41pm

Hi,

Sorry for the late response. If you remove the partitioning from the reflection does that make it work correctly with the incremental refreshes? Also can you give us the version of Dremio you are using?

thanks,
Doron

dealercrm · May 3, 2018, 12:28pm

No removing partitioning does not resolve the issue.

I have tried many different data sources that have the BIGINT data type as an incremental field. None of them work.

Version is 1.4.9-201802191836310213-7195059

hakim · May 3, 2018, 2:09pm

did you try on 2.0.3 ? we fixed a lot of issues around reflection management and we also improved how we report the state. In your case, either the problem will be resolved or the UI and log will give you more information about the problem (we improved the log message for such failures to report additional information instead of just AssertionError:null).

Some clarifications about the issue: when we are done refreshing the reflection we do some additional internal work (materialization cache being one of them), so it’s always possible to fail even if the job itself was successful. We are aware that the job history can be confusing in such situations and we are working on improving how to better report those issues.

dealercrm · May 3, 2018, 3:12pm

Not yet.
I read all of the release notes.
Looking at migrating, as there are many items that have been resolved, that we have been experiencing pain around. Looks great!

My initial post was trying to elicit some response from the community on an example of a working incremental update.

Create a table with this structure in the db.
Add data.
Create reflection with incremental update.
Show initial reflection creation success.
Add more data.
See update of reflection as successful.

I did something similar with a MySQL table with a incremental id field and a text field, with no success.

dfleckinger · May 4, 2018, 7:31am

Hi @hakim, you mention 2.0.3, that fixes issues about reflection management.
Is it released, where can it be found ?

hakim · May 4, 2018, 2:15pm

sorry, that was a typo. The fixes I was referring to are all in 2.0.1 already

dfleckinger · May 4, 2018, 2:19pm

ok. This issue seem similar to this one : dremio-2-0-1rc-some-reflections-fail-at-creation

hakim · May 4, 2018, 2:32pm

it’s similar in a sense that the refresh job succeeded but the the “internal” work failed after that, but looking at the stacktrace, it’s 2 different issues

dealercrm · May 17, 2018, 6:10pm

Upgrading to 2.x solved this issue.

Thanks.