update idx handling #574

woodsaj · 2017-03-21T16:32:29Z

support LastSave property, so we only periodically save to cassandra.
make adding to the writeQueue a non-blocking operation, unless the
def has not been updated for 1.5x the updateInterval.

replaces PR #569 and PR #571

woodsaj · 2017-03-21T16:48:54Z

Insert benchmarks

new code

$ go test -v -run NONE -bench . -benchtime 1s
BenchmarkIndexing-4       30000	     51445 ns/op	    3518 B/op	      62 allocs/op
BenchmarkLoad-4            200000	      9355 ns/op	    1745 B/op	      14 allocs/op

current master

(current benchmarks in master dont work, as they dont write to cassandra. So these results are from local modifications to set updateCassIdx=true)

$ go test -v -run NONE -bench . -benchtime 1s
BenchmarkIndexing-4   	   30000	     49439 ns/op	    3518 B/op	      61 allocs/op
BenchmarkLoad-4       	  200000	      9384 ns/op	    1744 B/op	      14 allocs/op

Results are pretty much identical because all writes are blocking writes to cassandra.

updates

new code

$ go test -v -run NONE -bench BenchmarkIndexingWithUpdates
BenchmarkIndexingWithUpdates-4   	  500000	      2376 ns/op	     760 B/op	      14 allocs/op

current master

(master does not currently have the BenchmarkIndexingWithUpdates benchmark, so these results are from local edits to add it.)

$ go test -v -run NONE -bench BenchmarkIndexingWithUpdates
BenchmarkIndexingWithUpdates-4   	   30000	     48469 ns/op	    2693 B/op	      51 allocs/op

When performing updates that dont require a save to cassandra, the new code is way faster.

- support LastSave property, so we only periodically save to cassandra. - make adding to the writeQueue a non-blocking operation, unless the def has not been updated for 1.5x the updateInterval.

replay · 2017-03-21T17:31:10Z

idx/cassandra/cassandra.go

+		log.Debug("cassandra-idx updating def in index.")
+		c.writeQueue <- writeReq{recvTime: time.Now(), def: &archive.MetricDefinition}
+		archive.LastSave = now
+		c.MemoryIdx.Update(archive)


Should we maybe collect some statistics that track how many % of the updates happen due to the if condition being met and how many happen via the non-blocking writes? That might be a good indicator to look at if we seem to hit a writes-per-time limitation.

That is a good idea.

i added a counter idx.cassandra.save.skipped to keep track of how many saves are being skipped due to the writeQ being full. Spikes in this counter would be normal, but continued growth over an extended time would indicate a performance problem.

Dieterbe · 2017-03-21T17:33:38Z

metrictank-sample.ini

@@ -251,10 +251,8 @@ max-stale = 0
 prune-interval = 3h
 # synchronize index changes to cassandra. not all your nodes need to do this.
 update-cassandra-index = true
-#frequency at which we should update the metricDef lastUpdate field, use 0s for instant updates
+#frequency at which we should update flush changes to cassandra. only relevent if update-cassandra-index is true.


relevant. (sorry)

Dieterbe · 2017-03-21T19:20:53Z

idx/memory/memory.go

@@ -132,6 +142,9 @@ func (m *MemoryIdx) Load(defs []schema.MetricDefinition) int {
 			continue
 		}
 		m.add(def)
+		// as we are loading the metricDefs from a persistant store, set the lastSave
+		// to the lastUpdate timestamp.


this comment says exactly what the code does but it should say why it does it, and should explain why this is OK

Dieterbe · 2017-03-21T19:35:41Z

idx/memory/memory.go

+		m.Unlock()
+		return
+	}
+	*(m.DefById[entry.Id]) = entry


couldn't we just write m.DefById[entry.Id] = &entry here? why not?

This is safer. Another goroutine could already have a copy of the reference. If we just changed the address of what m.DefById[entry.Id] pointed to rather then content, then any modifications made by those other goroutines would be lost.

Dieterbe · 2017-03-21T19:42:37Z

idx/cassandra/cassandra.go

+		archive.MetricDefinition.Partition = partition
+	}
+
+	// if the entry has not been saved for 1.5x updateInterval


why do we use 1.5x the interval? wouldn't it make more sense (and be easier to reason about) to start doing blocking writes at exactly the 1 updateInterval mark?

BTW the compiler should optimize uint divisions by factors of two, i don't think we need to do it manually?

No. Writes aren't tried until exactly the updateInterval or greater has passed. If you forced a bocking write at exactly the 1 updateInterval then you would only ever try the non-blocking once, forcing all saves to be completed within 2x your metric interval. That is way to aggressive.

as for why 1.5X, because that is what we have been using in hosted-metrics. ie updateFuzziness of 0.5 leading to updates to happen between updateInterval and updateInterval x 1.5

Dieterbe · 2017-03-21T20:00:54Z

idx/cassandra/cassandra.go

+	// This is just a safety precaution to prevent corrupt index entries.
+	// This ensures that the index entry always contains the correct metricDefinition data.
+	if inMemory {
+		archive.MetricDefinition = *schema.MetricDefinitionFromMetricData(data)


note that the id is generated from (almost) all the properties. properties not included in the name are Partition, Lastupdate (and Name but Name should always be same as Metric so it's not relevant here, that's still something we have to clean up at some point btw). MemoryIdx.AddOrUpdate already made sure to update Partition and LastUpdate, so i see no need for this.

this is to fix https://github.com/raintank/ops/issues/394

aha ok. so after this has run for a while, at some point we'll be able to take out these lines again?

yes. Unless we introduce metadata fields in future that do not contribute to the generated id.

Dieterbe · 2017-03-21T20:02:34Z

idx/cassandra/cassandra.go

+	// This ensures that the index entry always contains the correct metricDefinition data.
+	if inMemory {
+		archive.MetricDefinition = *schema.MetricDefinitionFromMetricData(data)
+		archive.MetricDefinition.Partition = partition


MemoryIdx.AddOrUpdate already made sure to update/set Partition field correctly?

Dieterbe · 2017-03-21T20:08:24Z

replaces PR #569 and PR #571

571 also had a change to make the index Pruning use LastSave instead of LastUpdate. I think we should still apply that, as it seems to make more sense

woodsaj · 2017-03-21T20:11:47Z

LastSave cant be used for pruning, as not all nodes save metricDefs. So if updateCassIdx=false, then LastSave always be what was set when the def was loaded at startup.

Dieterbe · 2017-03-21T20:25:57Z

for nodes that don't write to cassandra, we could just make it so that LastSave means "last save to the memory index" instead of "last save to the cassandra index". in other words, just have it be the timestamp of when it was last seen. that way we could do this. But anyway I don't feel strongly about it, I don't have a good example to make a strong case for this (other than people for some reason loading in old data, which doesn't seem very common), so we can keep as is.

woodsaj · 2017-03-21T20:29:10Z

for hosted-metrics the default MAX_STALE is 48hours. So users would have be streaming data with a delay of 48hours (as LastUpdate is now set for every point received instead of the previous periodic saving of lastUpdate). It is extremely unlikely anyone will send data with that much lag, and if they do we can just change MAX_STALE or turn pruning off completely.

replay · 2017-03-21T20:34:00Z

idx/cassandra/cassandra.go

+		// lastSave timestamp become more then 1.5 x UpdateInterval, in which case we will
+		// do a blocking write to the queue.
+		select {
+		case c.writeQueue <- writeReq{recvTime: time.Now(), def: &archive.MetricDefinition}:


shouldn't time.Unix(now, 0) be faster than time.Now()?

faster? yes. But as we use this for measuring how long items are spending in the queue time.Unix(now, 0) does not provide the required precision

Dieterbe · 2017-03-21T20:40:37Z

idx/cassandra/cassandra_test.go

+			OrgId:    1,
+			Time:     10,
+		}
+		data.SetId()


now that an iteration is in the order of nanoseconds, the overhead of the Itoa call , instantiating data, and calling SetId is probably starting to get significant. maybe use StopTimer and StartTimer to take this stuff out of the equation.

Dieterbe · 2017-03-21T20:49:06Z

idx/cassandra/cassandra_test.go

@@ -285,3 +387,46 @@ func BenchmarkLoad(b *testing.B) {
 	ix.Init()
 	ix.Stop()
 }
+
+func BenchmarkIndexingWithUpdates(b *testing.B) {


It seems like the goal of this test - due to it calling insertDefs(ix, b.N) first - is to measure how long AddOrUpdate takes if and only if no update needs to happen. the name of this benchmark should reflect that. why is it called WithUpdates?

benchmarking when the metrics inserted are updates, not adds.

right but it's not updating anything in cassandra. and since this test is called WithUpdates and it's in idx/cassandra/cassandra_test.go this leads to believe it benchmarks updates in cassandra. so maybe just call it BenchmarkIndexingUpdatesMemoryNotCassandra or something

your suggestion makes less sense.
the benchmark calls CasIdx.AddOrUpdate() with items that only update. So "BENCHMARK INDEXING WITH metricData payloads that result in UPDATES" == BenchmarkIndexingWithUpdates

- create the metricData to be added outside of the main loop.

Dieterbe · 2017-03-21T21:02:46Z

idx/cassandra/cassandra_test.go

-
-	b.ReportAllocs()
-	b.ResetTimer()
+	updates := make([]*schema.MetricData, b.N)


by pre-allocating you could exhaust ram. i've ran into this a few times hence the suggestion to use StopTimer and StartTimer. but anyway i guess we'll see if it happens

Dieterbe · 2017-03-21T21:08:51Z

btw to compare benchmarks, these tools are nice:
https://godoc.org/golang.org/x/tools/cmd/benchcmp
https://godoc.org/golang.org/x/perf/cmd/benchstat

woodsaj force-pushed the idxLastSave branch from 5af8cea to 6d0d778 Compare March 21, 2017 16:48

update idx handling

b853661

- support LastSave property, so we only periodically save to cassandra. - make adding to the writeQueue a non-blocking operation, unless the def has not been updated for 1.5x the updateInterval.

woodsaj force-pushed the idxLastSave branch from 6d0d778 to b853661 Compare March 21, 2017 16:55

replay reviewed Mar 21, 2017

View reviewed changes