Materialize: Occasional timestamp error

[JLDLaughlin]

What version of Materialize are you using?

"0.5.0-dev"

How did you install Materialize?

• [ ] Docker image
• [ ] Linux release tarball
• [ ] APT package
• [ ] macOS release tarball
• [ ] Homebrew tap
• [X] Built from source

What was the issue?

Repeatedly running the following diagnostic query, I occasionally encounter the following error:

materialize=> select * from mz_perf_arrangement_records;
ERROR:  Timestamp (96803999) is not valid for all inputs: [(System(1001), Some(Antichain { elements: [96804000] }))]

Is the issue reproducible? If so, please provide reproduction instructions.

Start materialized, run the above query a handful of times.

[frankmcsherry]

I currently see it 100% of the time on

select mdo.id, mdo.name, sum(mas.records) as records, sum(mas.batches) as batches
from mz_arrangement_sizes as mas,
     mz_dataflow_operators as mdo
where
    mas.operator = mdo.id and
    mas.worker = mdo.worker
group by mdo.id, mdo.name
order by sum(mas.records) desc;

[cuongdo]

@umanwizard This is impeding diagnostic efforts. Can you either take a look or reassign?

[frankmcsherry]

For whoever ends up investigating: one candidate culprit is that the catalog and logging sources used to be very much in sync, as the catalog was mirrored up through the logging. This is no longer the case, as the catalog sources are now driven explicitly by the coordinator, and they may not be nearly as in sync any more.

[umanwizard]

I've noticed this too, but trying to run it a few times got it to work.

[umanwizard]

(That seems to align with what Jessica reported -- I'm just confirming)

[frankmcsherry]

one candidate culprit ...

On further reflection, the query that wasn't working for me doesn't involve the catalog, I don't believe.

[benesch]

This seems to be working now. At least, I can't reproduce the issue. Not sure what changed, but going to close this out. We can always reopen if we observe the anomaly again.

[benesch]

Ok, we have a confirmed report from @mjibson that this is happening again. Here's the issue as it presented for him:

materialize=> select * from mz_catalog.mz_records_per_dataflow_global;
ERROR:  Timestamp (1601679072999) is not valid for all inputs: [(System(1001), Some(Antichain { elements: [1601679074000] })), (System(1003), Some(Antichain { elements: [1601679074000] }))]

A common theme is a timestamp selected that's before the antichains in the views. Notably the views are always just logging views, so it's not clear this is a result of skew between the catalog tables and the logging views.

[benesch]

Also, apparently running chbench is a reliable way to trigger this error.

[benesch]

Notably the views are always just logging views, so it's not clear this is a result of skew between the catalog tables and the logging views.

@justinj points out that the error message only includes the views for which the timestamp is invalid, so it is still quite possibly the result of skew between the catalog tables and the logging views.

[ruchirK]

I can reproduce this by hooking up Materialize to a large source and querying mz_records_per_dataflow_global during ingest. Also -- this is a bit of a shot in the dark but could this be tied to / exacerbated by the fact that system logs are hardcoded to a much smaller compaction frontier than everything else?
from src/coord/coord.rd:

242                         // TODO(benesch): why is this hardcoded to 1000?
 243                         // Should it not be the same logical compaction window
 244                         // that everything else uses?
 245                         self.indexes
 246                             .insert(*id, Frontiers::new(self.num_timely_workers, Some(1_000)));

[benesch]

There is some additional context in #4147. I've closed that issue in favor of this one.

[cuongdo]

@frankmcsherry Could you look at this when you get back?

[frankmcsherry]

In the meantime, materializing the query as a view and selecting from it should clear up the problem. The issue is that the coordinator's timestamp selection policies clash with its arrangement compaction policies. The only "bug" I think is that the policies are configured to avoid unintended performance problems, at the expense of ergonomic problems.

At least one floated proposal was to use the AS OF notation to specify a preferred timestamp, with something like logical_time() though perhaps not exactly this, as it means to reference the determined time. An absent AS OF clause could then default the query to whichever default we like more (there have been arguments in both directions, about the usability surprise and the performance surprise).

[benesch]

Fixed in #4467.