Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

OpenTelemetry metrics & Miner Index fix for document max-size limit & new deal-watcher #811

Merged
merged 22 commits into from
Mar 29, 2021

Conversation

jsign
Copy link
Contributor

@jsign jsign commented Mar 25, 2021

This PR includes multiple improvements:

  • The Miner Index was refactored, and new flags/envs can be tuned to: refresh the index on Powergate start, tune the level of parallelization to speed up rebuilding the index, and the frequency of index refresh.
  • Any go-datastore implementation is wrapped to a cusotmized go-ds-measure to publish Prometheus metrics of Get, Put, Query, Commit, and other usual operations of go-datastore. We forked the original repo to add Txn based metrics.
  • Opencensus was removed, and was replaced with Opentelemetry.
  • The miner index saving switched from being saved as a complete snapshot, to being saved per miner. This was to fix a limitation of MongoDB backed go-datastore not allowing to save documents bigger than 16MB.
  • A new DealWatcher component was created to provide an instant-based solution to detect deal state changes. The existing poll-style is kept because we aren't totally sure how reliable this new way is. In fact, this was done originally and we switched to poll-based since long-running websocket connections of go-jsonrpc for the Lotus client were unreliable. Keeping both allows to get the benefits of instant updating, but if for some reason that breaks, we still do polling once in a while. (Apart from trying to recover that broken watcher).

A new set of application metrics are exposed:

  • General metrics about the build:
    • Build date
    • Git summary
    • Git branch
    • Git commit
      Datastore:
    • All mentioned operations of go-datastore latencies.
  • Deal watcher metrics:
    • How many deal updates we get from the chain
    • How many times the watcher got in bad health and had to be re-created. This helps to understand how reliable this new mechanism is.
  • Deal module:
    • A counter of how many deals are being actively tracked (in-progress)
    • Same as above but for retrievals
    • A counter of the number of finalized deals, tagged with success or error.
    • A counter of the number of bytes of finalized deals, tagged with success or error.
  • Cold-storage:
    • A gauge to understand the data pre-processing queue (deal size + CommP calculation), tagged with "waiting" and "in-progress". (Remember that we rate-limit by default to 2 "in-progress" since it's a heavy process to avoid killing the Lotus node)
  • Scheduler:
    • A counter to show the Jobs in final status, each tagged with "success", "failed", "canceled".
    • A gauge to show Jobs in "queued" and "executing" status.
  • Indices:
    • Ask and Miner index progress gauge. (0%/100%
  • Wallet module:
    • A counter of the number of created wallet addresses
    • A histogram of wallet transfer amounts.

I believe there's a lot of room to continue thinking if these are the right metrics or other ones that are useful to be gathered. The main point here was doing some kickoff and we can keep making some incremental improvements not that we have things wired.

Here's a quick screenshot of the Grafana dashboard. It has some rough edges, but we'll eventually also publish in Grafana dashboards:
image

While doing this work, some secondary repos were forked+edited and created:

jsign added 19 commits March 25, 2021 09:13
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
.
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
index/miner/lotusidx/store/store.go Outdated Show resolved Hide resolved
index/miner/lotusidx/store/store.go Outdated Show resolved Hide resolved
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
Signed-off-by: Ignacio Hagopian <jsign.uy@gmail.com>
@jsign jsign changed the title Opentelemetry application metrics & MongoDB fix for documents hard-limit & new deal-watcher Opentelemetry application metrics & Miner Index fix for document max-size limit & new deal-watcher Mar 25, 2021
@jsign jsign changed the title Opentelemetry application metrics & Miner Index fix for document max-size limit & new deal-watcher OpenTelemetry metrics & Miner Index fix for document max-size limit & new deal-watcher Mar 25, 2021
Comment on lines +64 to +66
IndexMinersRefreshOnStart: false,
IndexMinersOnChainMaxParallel: 1,
IndexMinersOnChainFrequency: time.Minute,
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

New knobs via env/flags.

minerIndex "github.com/textileio/powergate/v2/index/miner/module"
minerIndex "github.com/textileio/powergate/v2/index/miner/lotusidx"
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Switching names since module still feels too abstract. I mention lotus in the new name since this implementation of index/miner uses a Lotus as a Filecoin client.

@@ -74,6 +76,7 @@ var (
2: migration.V2StorageInfoDealIDs,
3: migration.V3StorageJobsIndexMigration,
4: migration.V4RecordsMigration,
5: migration.V5DeleteOldMinerIndex,
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Simple migration to delete old Miner Index store, since the new one uses another key namespace.

Comment on lines -228 to +241
mi, err := minerModule.New(txndstr.Wrap(ds, "index/miner"), clientBuilder, fchost, mm, conf.IndexMinersRefreshOnStart, conf.DisableIndices)

log.Info("Starting miner index...")
minerIdxConf := minerIndex.Config{
RefreshOnStart: conf.IndexMinersRefreshOnStart,
Disable: conf.DisableIndices,
OnChainMaxParallel: conf.IndexMinersOnChainMaxParallel,
OnChainFrequency: conf.IndexMinersOnChainFrequency,
}
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

To avoid constructor parameter explosion: introducing some config struct.

return nil, fmt.Errorf("opening badger datastore: %s", err)
}
return ds, nil
return measure.New("powergate.datastore", ds), nil
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Here we now return a wrapped datastore (being Badger or MongoDB backed) that will intercept go-datastore calls and produce counters and histograms for operations. These will be collected by OpenTelemetry and exposed as Prometehus endpoint.

}

// SaveOnChain creates/updates on-chain information of miners.
func (s *Store) SaveOnChain(ctx context.Context, index miner.ChainIndex) error {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The miner index has a lot of miners. I used a datastore.Batching interface to allow to persist things in batches since single updates were too slow.

Comment on lines +60 to +68
if i%1000 == 0 {
if err := b.Commit(); err != nil {
return fmt.Errorf("committing batch: %s", err)
}
b, err = s.ds.Batch()
if err != nil {
return fmt.Errorf("creating batch: %s", err)
}
}
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Every 1000 miner index entries, we commit the batch and start a new one.

@@ -7,19 +7,11 @@ import (
"time"
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Migrating some old metrics about Lotus health from OpenCensus to OpenTelemetry, plus adding other to know about sync lag. (See screenshot from Grafana dashboard in Lotus section).

Comment on lines +14 to +32
Run: func(ds datastoreReaderWriter) error {
q := query.Query{Prefix: "/index/miner/chainstore"}
res, err := ds.Query(q)
if err != nil {
return fmt.Errorf("querying records: %s", err)
}
defer func() { _ = res.Close() }()

var count int
for v := range res.Next() {
if err := ds.Delete(datastore.NewKey(v.Key)); err != nil {
return fmt.Errorf("deleting miner chainstore key: %s", err)
}
count++
}
log.Infof("deleted %d chainstore keys", count)

return nil
},
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The new miner-index store saves the data in a new namespace. The only thing this migration is doing is removing the old persisted miner-index data. If wasn't removed it would stay there forever. Isn't really that big, but doing it as to keep things clean.

@@ -18,6 +18,7 @@ import (
logger "github.com/ipfs/go-log/v2"
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added some metrics in the Wallet Module to have some counter of how many new addresses and transfers are happening. This would show interesting info for Powergate used by Hub, since we create a new wallet-address per new Account/User. It will be cool to see.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yea very interesting.

@jsign jsign marked this pull request as ready for review March 25, 2021 14:38
@jsign jsign requested a review from asutula March 25, 2021 14:38
@eightysteele
Copy link
Contributor

Any go-datastore implementation is wrapped to a cusotmized go-ds-measure to publish Prometheus metrics of Get, Put, Query, Commit, and other usual operations of go-datastore. We forked the original repo to add Txn based metrics.

So good!

Curious if any of the refactoring here makes it easier to eventually add in some rolling averages stuff (textileio/textile#519).

@jsign
Copy link
Contributor Author

jsign commented Mar 25, 2021

Any go-datastore implementation is wrapped to a cusotmized go-ds-measure to publish Prometheus metrics of Get, Put, Query, Commit, and other usual operations of go-datastore. We forked the original repo to add Txn based metrics.

So good!

Curious if any of the refactoring here makes it easier to eventually add in some rolling averages stuff (textileio/textile#519).

The Hub Miner Index is built with mindexd daemon. This was done to allow the Hub to decide its own path on what the Hub Miner Index should look like. (Also, to gather deal-making information from all our hosted powergates, so it has more information than any powergate too. But this fact is unrelated to that feature).

That daemon is already querying Powergate on regular intervals about prices offered by miners, so it can already do further aggregations (being rolling averages, or other things) on its own. It would need to keep some short history of the last ask prices, and do more calculation on tops or similar.

@eightysteele
Copy link
Contributor

Gotcha, that makes sense 👍🏻 (thanks!)

Copy link
Member

@asutula asutula left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks great. No issues at all, just some general questions for my own curiosity.

@@ -105,6 +106,16 @@ func (m *Module) Watch(ctx context.Context, proposal cid.Cid) (<-chan deals.Stor
go func() {
defer close(updates)

watcherUpdates := make(chan struct{}, 20)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Very cool. Glad we're going to try the push based mechanism, and will either have success or file some new lotus issues. Good outcome either way.

@@ -103,6 +103,9 @@ func (m *Module) retrieve(ctx context.Context, lapi *apistruct.FullNodeStruct, l
go func() {
defer lapiCls()
defer close(out)
m.metricRetrievalTracking.Add(ctx, 1)
defer m.metricRetrievalTracking.Add(ctx, -1)

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like how easy this api is to use. In the new services I've been creating, I've exposed this sort of metrics data through the api thinking that some external monitoring would poll the api. Is that even possible? Either way, this seems like a nicer solution.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, that could be possible. I'd vote to let the daemon itself publish the metric instead of being an external component, just at to make metrics a baked-in feature of the daemon.

mi.metricLock.Lock()
defer mi.metricLock.Unlock()
result.Observe(mi.onchainProgress, onchainSubindex)
result.Observe(mi.metaProgress, metaSubindex)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Awesome you can observe like this. Seems like magic, I guess it's probably simple since it's Go.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

But I am really curious, when it comes to actually being notified the observed valued changed... how does that work? You update the observed value directly, not via some func wrapper, right?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This metric is defined as:

_ = metric.Must(meter).NewFloat64ValueObserver("powergate.index.ask.progress", ai.progressValueObserver, metric.WithDescription("Ask index refresh progress"), metric.WithUnit(unit.Dimensionless))

So what happens in the NewXXXXObserver style of metrics, is that the OpenTelemetry library will call the callback (progressValueObserver) on defined intervals.
This has some benefits of not needing to record quickly changing metrics, and also registering a ton of observations within the same timestamp.

In this case, since the update progress is a gauge, I let this metric be updated on every collection interval.

There are quite a few things to learn, and keep improving. I think this is the best reference as to understand how different measurements work. I still need to give a full read, but that's the best source of documentation for the metrics API.

@@ -18,6 +18,7 @@ import (
logger "github.com/ipfs/go-log/v2"
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yea very interesting.

@jsign jsign merged commit 813687f into master Mar 29, 2021
@jsign jsign deleted the jsign/chgmi branch March 29, 2021 16:36
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants