bee
bee copied to clipboard
Published
20 hours ago •
ethersphere
ethersphere
pullsync/pullstorage/Cursors ignores context
Summary
I have a bee node with 150+GB of pinned content making the localstore bins quite full. I have noticed several times that my CPU consumption has pegged at 100% for hours at a time. I finally tracked this down to pullsync/pullstorage/Cursors being invoked from pullsync/cursorHandler. In my previous observations, LastPullSubscriptionBinID(bin) takes a LONG time to complete given the data content of my localstore.
Right now there are 125 goroutines currently spinning around in LastPullSubscriptionBinID(bin) (1.5 hours after the CPU consumption went to 100%), and I suspect that many of them are for peers that have long since been disconnected and blocklisted for various reasons. But the pullstorage/Cursors() routine doesn't reference the context, so it will continue to do all bins for each peer that starts the query.
Steps to reproduce
First you have to pin LOTS of content in a node. Then you have to have a swarm event that causes most of your peers to be disconnected, possibly crashing your and other's kademlia depths, then wait for the new connections and Cursors() requests to come flooding in as peers reconnect to your node.
This is aggravated in my case by having increased kademlia connection limits and an overlay ID that lends itself for lots of incoming connections (lots of leading zero bits).
Expected behavior
I would expect disconnected peers to quit trying to count the Cursors and honor the cancelled context.
Actual behavior
Here's the stack of the goroutines that are beating up my localstore counting the Cursors(). Note that this is a "dirty" build of 1.3 and the line numbers may not match exactly, but you'll get the idea from the bottom 4 entries. There aren't that many invocations of LastPullSubscriptionBinID in the source code.
125 @ 0x441de5 0x453a25 0x453a0e 0x4753a7 0x491ea5 0x9b2b2e 0x9b26c2 0x9b126c 0x9b95e5 0x9b956d 0x9ba69b 0x9ba8d8 0x9b84a5 0x9a79c2 0x9a825d 0x9a8325 0x9a9859 0x9d215a 0x9d202e 0xc14d11 0xdf8ea5 0x109532d 0x109bd0f 0xf95b2f 0xf4fb62 0x479321
# 0x4753a6 sync.runtime_SemacquireMutex+0x46 runtime/sema.go:71
# 0x491ea4 sync.(*Mutex).lockSlow+0x104 sync/mutex.go:138
# 0x9b2b2d sync.(*Mutex).Lock+0x48d sync/mutex.go:81
# 0x9b26c1 github.com/syndtr/goleveldb/leveldb/cache.(*lru).Promote+0x21 github.com/syndtr/[email protected]/leveldb/cache/lru.go:85
# 0x9b126b github.com/syndtr/goleveldb/leveldb/cache.(*Cache).Get+0x1eb github.com/syndtr/[email protected]/leveldb/cache/cache.go:399
# 0x9b95e4 github.com/syndtr/goleveldb/leveldb/cache.(*NamespaceGetter).Get+0xc4 github.com/syndtr/[email protected]/leveldb/cache/cache.go:58
# 0x9b956c github.com/syndtr/goleveldb/leveldb/table.(*Reader).readBlockCached+0x4c github.com/syndtr/[email protected]/leveldb/table/reader.go:625
# 0x9ba69a github.com/syndtr/goleveldb/leveldb/table.(*Reader).getDataIter+0x5a github.com/syndtr/[email protected]/leveldb/table/reader.go:765
# 0x9ba8d7 github.com/syndtr/goleveldb/leveldb/table.(*Reader).getDataIterErr+0x137 github.com/syndtr/[email protected]/leveldb/table/reader.go:780
# 0x9b84a4 github.com/syndtr/goleveldb/leveldb/table.(*indexIter).Get+0x284 github.com/syndtr/[email protected]/leveldb/table/reader.go:507
# 0x9a79c1 github.com/syndtr/goleveldb/leveldb/iterator.(*indexedIterator).setData+0x41 github.com/syndtr/[email protected]/leveldb/iterator/indexed_iter.go:39
# 0x9a825c github.com/syndtr/goleveldb/leveldb/iterator.(*indexedIterator).Next+0xbc github.com/syndtr/[email protected]/leveldb/iterator/indexed_iter.go:160
# 0x9a8324 github.com/syndtr/goleveldb/leveldb/iterator.(*indexedIterator).Next+0x184 github.com/syndtr/[email protected]/leveldb/iterator/indexed_iter.go:149
# 0x9a9858 github.com/syndtr/goleveldb/leveldb/iterator.(*mergedIterator).Next+0x1f8 github.com/syndtr/[email protected]/leveldb/iterator/merged_iter.go:169
# 0x9d2159 github.com/syndtr/goleveldb/leveldb.(*dbIter).next+0xb9 github.com/syndtr/[email protected]/leveldb/db_iter.go:232
# 0x9d202d github.com/syndtr/goleveldb/leveldb.(*dbIter).Seek+0x10d github.com/syndtr/[email protected]/leveldb/db_iter.go:202
# 0xc14d10 github.com/ethersphere/bee/pkg/shed.Index.Last+0x1f0 github.com/ethersphere/bee/pkg/shed/index.go:495
# 0xdf8ea4 github.com/ethersphere/bee/pkg/localstore.(*DB).LastPullSubscriptionBinID+0x124 github.com/ethersphere/bee/pkg/localstore/subscription_pull.go:191
# 0x109532c github.com/ethersphere/bee/pkg/pullsync/pullstorage.(*PullStorer).Cursors+0x8c github.com/ethersphere/bee/pkg/pullsync/pullstorage/pullstorage.go:153
# 0x109bd0e github.com/ethersphere/bee/pkg/pullsync.(*Syncer).cursorHandler+0x2ee github.com/ethersphere/bee/pkg/pullsync/pullsync.go:474
# 0xf95b2e github.com/ethersphere/bee/pkg/p2p/libp2p.(*Service).AddProtocol.func1+0xa2e github.com/ethersphere/bee/pkg/p2p/libp2p/libp2p.go:485
Note: I am adding some pullstorage metrics to my node to count the starts and finishes of Cursors() and a logger.debug in handleCursors() to show me their timings. So the next time my CPU spikes (after I get this new build running in my pusher), I'll have more concrete evidence that this is truly the cause.
Here's a Grafana view of the CPU/Connectivity correlation graphs over the past 2 days. https://gateway.ethswarm.org/access/5073c6779df5d2889356730efa4aee92f0b892fa9a148677f924ecdba32d9128
The first timing log on the Cursors() call:
time="2021-11-05T10:08:01-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 3m7.689375318s for 61353f0ba6f661ff8d0b06e64ac8d6e28f7d491752d78bb0f15a36cf66765acb"
time="2021-11-05T10:13:48-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 3m12.577957385s for 562735c0e18c83a47bb6612f63b970673421d91434c6430c4dc7e98c1b651d95"
time="2021-11-05T10:14:08-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 3m16.600494236s for 46790f28e8682d3fc580ba9397a6b206f41f4801f814cb1fb5f16f6301282bcb"
time="2021-11-05T10:14:49-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2m58.372309317s for 6bc0bd532d4a65496cef25eedf2f3a006ff70049ae5c7a19e3c126fee3f0e888"
from the source code in pullsync.go's cursorHandler (just so you know how the timing is measured):
start := time.Now()
var ack pb.Ack
s.metrics.DbOps.Inc()
ints, err := s.storage.Cursors(ctx)
if err != nil {
return err
}
s.logger.Debugf("pullsync:cursorHandler:Cursors() took %s for %s", time.Since(start), p.Address.String())
And for the final correlation between Cursors() activity and CPU consumption for large localstores (regardless of the ignored context, these peers were still actively connected): https://gateway.ethswarm.org/access/90663dde0b22abc2bd2bcf3c0cc964a6da5766f86924bac2cfb93a449c6116e5
This is the pullstorage code with my new metrics and the graph is the difference between Started and Complete thereby showing the currently active count.
// Cursors gets the last BinID for every bin in the local storage
func (s *PullStorer) Cursors(ctx context.Context) (curs []uint64, err error) {
s.metrics.PullCursorsStarted.Inc()
curs = make([]uint64, swarm.MaxBins)
for i := uint8(0); i < swarm.MaxBins; i++ {
binID, err := s.Storer.LastPullSubscriptionBinID(i)
if err != nil {
s.metrics.PullCursorsFailures.Inc()
return nil, err
}
curs[i] = binID
}
s.metrics.PullCursorsComplete.Inc()
return curs, nil
}
Here's another extreme view of the slow cursors... Yes, that says there were and still are 175+ active goroutines all trying to build Cursors responses. https://gateway.ethswarm.org/access/19f358a6729e89cbe08f98c4a680d97e0c20a525e9d956699a9e6314d8078fbd
And finally, here's the response time (if you call hours a response) of the concurrent Cursors requests. Working on putting a singleFlight around this with a Forget so that it only suppresses simultaneous concurrent requests.
time="2021-11-05T19:12:39-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 3m0.847984256s for 7ebe228ffd53cf1c3575644e7e651a8c42179d283776666b6c0799287ca83f2e"
time="2021-11-05T19:38:30-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2m58.421629743s for 611cd41342fdfa5d5191375c504455ec23a2858e66515c6fd99ac935d24d9539"
time="2021-11-05T19:43:32-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2m59.07920128s for 6130f9f78a961f20ab9cd4c7a798d182ec79d68690e85b38acde8c25ad212cf5"
time="2021-11-05T22:39:46-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h39m41.651836888s for 4c53572cd4ea24f548f84673368d9ebe5a578e8c72d3a179960a89c7cac65757"
time="2021-11-05T22:40:06-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h40m2.074486509s for 471a62e58d4e32dff23ad46032160d8a8dc34139f9fd5a2de1540774d890bdc0"
time="2021-11-05T22:40:12-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h40m7.454022661s for 775b89e14af7ddf48c31111d7d3ab3539c42f085c072f0a859e1b79df513a754"
time="2021-11-05T22:41:04-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h40m58.652331878s for 56c6c9610ec4ee74b2dd3cac605beaf485fb1c60136774f60cfcba2025672700"
time="2021-11-05T22:41:22-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h41m16.586418273s for 7fd433dbfc1dfa5970bd79612f2a91fa825350829c95570068a55d4457b351b3"
time="2021-11-05T22:42:16-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h42m12.716471455s for 4a7aa4fe85ea75863a99502177f41ef963e5d85855ad40be1d8fda0c5e832d09"
time="2021-11-05T22:43:21-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h42m56.065427893s for bb8bcefde644b466749a3453d6601578cd32d09605f7b42aae46b0623451c8dd"
time="2021-11-05T22:43:42-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h43m28.320252478s for 79cd9fd39c90761b622809583f5cb3f172f59781b499230bd6bd799f0257e480"
time="2021-11-05T22:44:30-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h44m13.441437076s for 5acfbaa00e2826cd114c5025e62e689b6b822f6de22bda77c1940214e4f657d3"
time="2021-11-05T22:44:38-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h44m15.361927755s for 77af2041aac7654b7d44cfd09ed71f3fb52a0eaefea679edba34dc58c18f6007"
time="2021-11-05T22:44:48-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h44m36.341321426s for 5b48eba35835c06867bb07742cbe8b28e70a094d5576b3bd796e50bac2dc2838"
time="2021-11-05T22:45:07-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m2.149066377s for 4ce3b5c1753c474af61f838e64e9b396e02be861358ddf9a5603f6c789223ab8"
time="2021-11-05T22:45:10-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h44m4.734782297s for 745ff704208601c15ead5a239fac13c762898a381c9af1233378aaff7f5df14f"
time="2021-11-05T22:45:21-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h44m57.626688516s for 775c9ccf4a32e8209f33cf09aecd8af8510cb54ea6d59f13ffcefee0ab94d417"
time="2021-11-05T22:45:24-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h44m54.461900241s for 551d6ae7a33749a45536dc8f2a3b5f55de860b17337c26ea9e91ea52a5141254"
time="2021-11-05T22:45:28-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m14.869055149s for 4e817951a35a2ce27ddde1085aafe0c4aaedb7b0d9306c3835eec820f4072fe1"
time="2021-11-05T22:45:37-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m15.241374315s for 561835099462942817dc2524740e56a972bce23c012aee6940443d4a1ed69f2c"
time="2021-11-05T22:45:49-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m23.674026251s for 6ede4f8e8ccd90d96bcf420f6b5b3fbdf19fa26dffb701fc66fd359b8c5f69d8"
time="2021-11-05T22:46:21-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h46m7.817825181s for 9c3ce10bffe3963f6266e004a5874b2f9f80ae9ba588d83d33b63274d419a1ef"
time="2021-11-05T22:46:43-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h46m15.29079976s for 3cd5bc0f75857f80c7713f4e1ea987c3ebda789b4d8652ee6e77277e177b4432"
time="2021-11-05T22:46:52-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m36.314240112s for 2e69e8eace0ccec9514505ca4cd5833f426545feeecdae2bdfa8a6a7fa0f85d6"
time="2021-11-05T22:46:55-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h46m30.257495911s for 4e9806da031d5e89e056a21d2cc15a0f9e580dd6d42cea1684906e5ea8ed6ef7"
time="2021-11-05T22:47:10-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h46m53.953129263s for 62f10bd2c00d0c36406768f90d39fbca59c134bb36eab44c57319dce058c0bc6"
time="2021-11-05T22:47:13-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h46m40.91084107s for 2eaec555604e554f498d302f97d3990ec24b62e1f49ce9cd1e65266f795bcd61"
time="2021-11-05T22:47:17-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h46m30.728748805s for 7e88cac987f7d26c8e50ba72c3e56151eaa2f6d878a445d3bfcaec0e64637da6"
time="2021-11-05T22:47:22-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m55.844052162s for 7d28c2ab1ead8865c07c1dfcfcea43aa313672f9da6d856f101df56fc75f7ee3"
time="2021-11-05T22:47:35-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m7.940950626s for 7d15c6d521a490aecffa9ade540e34efa08fbc7282b4314e6a76760e68515a4d"
time="2021-11-05T22:47:38-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m14.949278535s for 7c178898bffb599cb51451f304431ee2f67c9698641083858e557d5164ccfa1a"
time="2021-11-05T22:47:40-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m21.998449722s for 58a9acf2063e790d91995110d4d83622b66382cd08f0f19af3c39552fbe2b8c1"
time="2021-11-05T22:47:44-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m22.494333182s for 52feaeacba2af2069f92da5d5bdfeee183b41bfae059ab214b4b58fa5378c93e"
time="2021-11-05T22:47:48-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m28.12237446s for 4bcb22405755635580d4ea6e18e7b84a3370e412ee6140f4bdc576ce6994adab"
time="2021-11-05T22:47:56-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m37.934018801s for 4f2e346c0351067a05a506af60d3b007038b93077da6404622fdb2ef9785db83"
time="2021-11-05T22:47:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m11.523490749s for 41f6fc5616e3ecc57bc17cc2de4a18fac047a79338e08f857904a86e9db21bd7"
time="2021-11-05T22:48:04-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m47.96947515s for 61665d5a9be5299a05778257af154c9e1722089bfb8fe1969707d92f0f10a265"
time="2021-11-05T22:48:21-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m4.717038984s for 616785688697412e5d0428bad402b228632c018b613fbe165a0f755ea450249c"
time="2021-11-05T22:48:24-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m7.503240099s for 55c951d10838709cce235d829849c1d525128d990777cf406c0a56e86d06044e"
time="2021-11-05T22:48:28-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m26.995917217s for 5dbcb5fd3b09a2dbd8ea91758ae790dbdc8dbf3424feee976b21aa3110d29749"
time="2021-11-05T22:48:31-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m5.166995914s for 469bf6e2d2977899c1f45b9a3109b24a60b824f0697a039a6d8775848153e202"
time="2021-11-05T22:48:35-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m29.034414237s for 5a07cefaf06d3197383eab5eac6e157f010ee708b014307686af270917ace0a1"
time="2021-11-05T22:48:41-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m24.060924109s for 59974164c42400e577cbfc8860b9be4bdfbd3046d9761ed131ee0ca081d2215c"
time="2021-11-05T22:48:46-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m30.540959658s for 4fcd601fa1a013399f9a179cbea6fe518b0ae89b0460941ff2489cab7a59f586"
time="2021-11-05T22:48:52-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m8.597921889s for 51004aa995792433c1d10aa60e405e05fbf701a5e320c66b67e69e8b4055d734"
time="2021-11-05T22:48:54-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m24.960764456s for 55c6a4a377ef236f5dbbd5e69ff3564bca9866b1e6870dc9080716690babb942"
time="2021-11-05T22:48:58-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m41.700281309s for 5d657c847caee37e5eacf70c2cbe4db673db61b1e4223a898407f7ce652d3774"
time="2021-11-05T22:48:58-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m42.494336608s for 6c52b7fa3ae60ee85c35eb040946a53e4c4648fcf6794e870ce671733ba945e7"
time="2021-11-05T22:49:13-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m26.761438159s for df71974ec454183ebcfbd789955c39a5964a05458d45712a7ceef31a215a89da"
time="2021-11-05T22:49:19-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m35.684110293s for 0d835f740e2990851edb814f36b18daeb95933eb29993ca269fcec2fd3eda945"
time="2021-11-05T22:49:33-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m16.220676489s for 99cd8e90bc955c41480d19af8a6a6b25bcf7662b0133e8d3f4fa63ec85280025"
time="2021-11-05T22:49:34-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m15.97921273s for 4934b62edca85f0d26c8272e9b86bff061a69770f6423cb7c9f31de9bf9343f3"
time="2021-11-05T22:49:36-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m5.75644429s for 9da1090801ef1ad5f600cc51f9dd0ac41dc7ea036e5d74ea4dfbd6961a24762b"
time="2021-11-05T22:49:39-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m0.006327346s for 7d5d5b4247410eaf5bf54dea1125521f21231c1acbdbdfddd53d0c4d9069567c"
time="2021-11-05T22:49:47-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m24.297264173s for 1e6a1942db5c0a3b1590cfcf9894e5ad45b5cb5d0bbf0dbb59d3cda27c8e18c2"
time="2021-11-05T22:49:48-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m5.742301793s for 432c77df29480dfb77ab9dd4321495c32afb6e5dd6b968ddc7fc3230e07a1426"
time="2021-11-05T22:50:00-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m13.751652196s for 468ddd03312f23a2af1e2c40443dc6b00e9e3683c3c44c96e8d63eea84a989ca"
time="2021-11-05T22:50:12-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m40.635153841s for 6d30fe083851d6f3ee8d5a92dd02d2107bd66978134433cdfbc21b2accf1b549"
time="2021-11-05T22:50:15-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m42.354439112s for 6e6a0aa8ad12533e41f00d573cc408e6cebed8d17311fc5c41bc6421388f94f3"
time="2021-11-05T22:50:22-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m54.567060241s for d6eb5aeb9cc7d7fdf0bad89a582c126f20a4ab4532d0542dcb4f9e8c70982522"
time="2021-11-05T22:50:29-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m31.99663807s for 6ae839b6d99ce505eca2c9e830835bf8e32606f7bde89aa1a2fae9dcbdaabc41"
time="2021-11-05T22:50:34-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m40.654075216s for 35d745cb417f51a037d39ceaab482ed013a78b23e2de7649e4810d8d210affe1"
time="2021-11-05T22:50:37-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m44.956134857s for 77d57489910114cb625855465c4b38bdba19c84deb810df2d8c8a8c62d71b55b"
time="2021-11-05T22:50:38-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m23.73528057s for 7a7eb4a87b525e1929f80a74723fc53e7b87a3c9951514eb969df167a24fa6db"
time="2021-11-05T22:50:38-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m59.714626817s for f5f307d1713441c19e27e0099dbe66d22437f0e4d1e5b2d98b4a1276aeb3a650"
time="2021-11-05T22:50:40-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m10.659989611s for 69076b26cb12d0690336bb26007da7277d0d0ef76cb54a3150cf8de29309df07"
time="2021-11-05T22:50:41-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m39.305616295s for 7ed805d74eb264635714894da92ecc03133b583f2e378a9759e4df304c296e4a"
time="2021-11-05T22:50:49-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m31.798572873s for 5b98ef59bd977fe1a1749e62fd84b15c01a51564e81a7c669af81256abf79a0b"
time="2021-11-05T22:50:50-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m8.487278359s for 4583f88c6f4ccc624d4dbb3f57e06ec73451a6ec49459bf251f561cf8a62dc41"
time="2021-11-05T22:51:01-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m51.262165123s for 7249f6fb597eaa9e56dd4379b465b8e9e5d6afa83383ba7baa9aceb1f369b767"
time="2021-11-05T22:51:01-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m48.448133222s for 4c675672bc07ed5bba84736ada199d59cd6948e5764b5ef17c4f5c83ff0780bd"
time="2021-11-05T22:51:02-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m0.385987127s for 750527d256a49c232affab8f2a76f2b3adb9797e6ee8aa391a7a28fd1b9f89de"
time="2021-11-05T22:51:08-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m36.967468045s for b35174cd03adab831434b5530d64bf2e314406d5a58783a4d9a09242eda6df1b"
time="2021-11-05T22:51:12-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m59.157324334s for 7747ffa301397681e923c6ad127146c93d50eab38d329e8622b04fa1362dafb3"
time="2021-11-05T22:51:17-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m23.982943106s for 73df4f31310ed7304027c690eb1e377f144e52fd390cf6136e7b269d66301d1b"
time="2021-11-05T22:51:19-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m26.327430788s for 69aaa8162d61e8701487f1f80544fba963b2d068ac98f86bd1ce5e275ea626e9"
time="2021-11-05T22:51:20-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m51.246276085s for 6bb02165e6f6033bf56399991528c8eea59f6e103d1f4dddac9cb754a8450da6"
time="2021-11-05T22:51:20-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h46m23.862422763s for 6f74f6db4cb6fba5e7888f7e2c5c10722400b814f26ea245494c03d5cc7b1f87"
time="2021-11-05T22:51:27-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m47.402282278s for 555bbcf8cdbdb36fa6fbd3212e7d4eca58baafa11721964075a5f5d88e87e0ea"
time="2021-11-05T22:51:28-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m12.826985951s for 4e2b9d2e6b91a3aa9243b4675d311ae5083eecfdb9f6ab508b72955bf0e60e79"
time="2021-11-05T22:51:28-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m49.913741491s for 4d2b030d7f81c03d1aa8df0072ae81124df97a197fd21b027b22e72511b02377"
time="2021-11-05T22:51:28-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m59.591109345s for 34a307093e6583980aee1f671e3bf3046030c52469bc1a45e1a6e6916a636e19"
time="2021-11-05T22:51:41-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m3.363080585s for 6bfc23b51646f19539f710dcbf442b071c53a68fa6d5876a7b7ca708d36213b8"
time="2021-11-05T22:51:46-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m46.253992857s for 6f1ac596552e16606a85bd3bac271f0b8f2e1af35100cb1cc066695826888c49"
time="2021-11-05T22:51:46-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m59.896267278s for 1c89ad02a6b57693f2d76f04bee90f600f67112f6e58671f9d4297b46ebb7375"
time="2021-11-05T22:51:49-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m41.055190401s for 569e7c05fbe90f77034dc3e9c63f665b918d483bd274a449c7b221094653c3f3"
time="2021-11-05T22:51:52-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m24.243633859s for a6bf0a3d19dcddee48613fa9e3f938b8efdc1c857d28dcfb72bd56e89f1da1dd"
time="2021-11-05T22:51:55-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m30.018586701s for 753e9f10d0c8263a4977499141661002f1255ea60336c342e14604ae4c31dbda"
time="2021-11-05T22:51:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m42.230891785s for 4c1973de358cba0ff325724129d0be1ceb9a0c88a0147e5950cdb4e59587fb4b"
time="2021-11-05T22:51:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m24.438212558s for 65f70074c992dd15437cfb718494450b5bb93049de0cfa66364de74648da5d1e"
time="2021-11-05T22:51:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m23.552492319s for 6d536e55e8594f77ea0a60671b6f48092789291233a601272a4d32ab4d150707"
time="2021-11-05T22:51:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m54.099651505s for 4fa0670c049514d92fd01b157a604dc1b88e3f604c05523fbdaa9e169362721f"
time="2021-11-05T22:51:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m18.066253584s for 75c21619cb64371367e8b0b36920054b30c8a1ee16267cbac086a9d707e8250b"
time="2021-11-05T22:51:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m20.877582443s for 5296a582def7a74399725c30c1cd228477e4361b06ad7ab3bbbe2802574b5931"
time="2021-11-05T22:52:03-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m24.2599688s for 532e8aad089798186b33e11b801361ddbe35cc13958c043ee473c5b1fb7ee676"
time="2021-11-05T22:52:05-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m42.364413897s for 58fa13b6afac6a4795fdc1fc5a6cf441dfdd418a9a1771a5784010523cce755d"
time="2021-11-05T22:52:08-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m9.317131756s for 48758bd00d35b48cc59701834b18c429c01efd2e65d95269f22959381788e072"
time="2021-11-05T22:52:11-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m55.183022126s for 71cdbb640102f0a537235c62bcc094cc6a7766dbc823da6b589bac781cdcbab0"
time="2021-11-05T22:52:14-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m29.23582292s for 7e937e386b93abc9c10cc8156853a6c1937b7d92a7c7975ef937b18b56c708f3"
time="2021-11-05T22:52:15-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m5.132476692s for 4e72fec8689f98bf8c5199f1196f7010d68ab207bfbd03e577abc4105e99beda"
time="2021-11-05T22:52:17-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m51.895597003s for 355a4b331935c37be3e7ae19715a66adeab98c4c16e74f795398f637ceff760a"
time="2021-11-05T22:52:19-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m42.345592579s for 4d03589f3eb25fe9165a14a7e74bfadd53fd39152df0db31f198b37637ea61ab"
time="2021-11-05T22:52:20-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m0.792722678s for 6d681f4d7b5a5c78c7372de35f9ea4a58faf8dfa6803ac3b047585892aaf93bb"
time="2021-11-05T22:52:22-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m8.441813362s for 7ec60e4c87c542a916999c21e3d3b424d9dc2c91c86827c700910f4e09518cc9"
time="2021-11-05T22:52:25-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m12.15804078s for 99e952caeea0dc7f72bdd3ed9e40dad5a93170ead861db7748e946630eedc71d"
time="2021-11-05T22:52:32-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m15.138959803s for 79c02d7afa4ad3fbfe6359b863cce8e75667af059ae7edb980c9e3139363941b"
time="2021-11-05T22:52:39-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m51.990892011s for 5680e5bb1298ad0364b637ed5ae039c5046a18d7b788c25f759b136355f3e9f1"
time="2021-11-05T22:52:40-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m28.516934254s for 4679e8be5e223c7977994d65eeef5e197832e35b185f381b251fe4ee49b40db6"
time="2021-11-05T22:52:43-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m3.576704668s for 6d005b110a60fa6e645da3f5cea048a62d70f2f9d15787f8737b30f6f5c23b0f"
time="2021-11-05T22:52:44-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m36.611083245s for 7e1b5b76625d307861b32f0bc3e6345fad350ad158635db41e8b5b7d657c02b7"
time="2021-11-05T22:52:45-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m52.36494353s for 4d96a9df4885108468c051e68d2288bcb69e4f937afd9e02c8749458efa9738e"
time="2021-11-05T22:52:46-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m19.459351936s for 41fe081f6530a825dc186ce6add23624c42c2621c40fccb85fb39bdc701177cb"
time="2021-11-05T22:52:46-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m35.752742457s for 3566ebef0cae1664adc1b6b5f520478801be8d478122733f84653927d16acd9a"
time="2021-11-05T22:52:49-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m39.660055742s for 59116eea184a9d492806c97b5a75dcc221389566f4960269dc6a8c26917c5035"
time="2021-11-05T22:52:50-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m28.192224978s for 46723e581e046e82275df46f28341d0a1610934911df4a82e3cb9d3ecd2e6e43"
time="2021-11-05T22:52:52-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m13.6135764s for 6aa94cfabb8f83befbed245e8cd615ab6445350d041c1fd78e549678405de383"
time="2021-11-05T22:52:53-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m40.807018269s for 69c20e23437de271693c9731b8d660cf26b0b108566531c68746ab27a55532eb"
time="2021-11-05T22:52:55-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m57.892203227s for 6b732374dce1a7dc9c3cbb16f2cabad0811d379ffb0f0aafa33ad76c3c359833"
time="2021-11-05T22:52:56-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m47.446790659s for ef67d4f7c80ac54fa083273c1d15044523eabbd73409b2207813c953b6103963"
time="2021-11-05T22:52:56-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m12.519700887s for 5b681416896c84a1386f68d041cd0331e1f7aefee9847f51dc83e96103da7b83"
time="2021-11-05T22:52:58-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m47.809241921s for 747f46360d9ec86f8e239b68c8ada6f9b8b00347b86744a92830bcf828ca1419"
time="2021-11-05T22:52:58-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m50.695861403s for 6070d74a55f2330b502a9f1c7ee10856dc71c718ab52ce024533e0445f299aa3"
time="2021-11-05T22:53:01-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m9.279988285s for 2d3bf4151a065b3e5f7c8e63dd5bddfd588e2f29e0d620e675cdb6f1c5d0d703"
time="2021-11-05T22:53:05-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m33.846516842s for 7543cd12d179397b81ad7ec723a5246bc901b4e4c183dcad7bcc0672b9d7f6a0"
time="2021-11-05T22:53:10-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m34.618756532s for 4a62766c31b50581fb7dd9924dbd628f4e44e4926bd35e217746ea7392907304"
time="2021-11-05T22:53:11-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m39.069753246s for 56af60c45ee2bbaf78665fb7688fce4ddd01417379fc26be76c3e183c4971a03"
time="2021-11-05T22:53:15-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m43.001974076s for 1dc11dcc9adc235efabeb0c33772cec6d76e52415891b003ff35a77774c2ab83"
time="2021-11-05T22:53:18-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m5.407419799s for 7c60f365d414b894d1b3da0c3de0100c351faf0ea45b787d25c7342dac637723"
time="2021-11-05T22:53:21-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m5.366504025s for 49c09bfd98a1ce46fa61eb78363753e9acd6dd471f2bcb1dfc610dba25882214"
time="2021-11-05T22:53:31-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m9.962877508s for 7b126fb3064cc055879fdcaccb81fa3a60ab2b5d66b8c00186b59e027cd7ca27"
time="2021-11-05T22:53:41-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m18.010350462s for 5ae34cd8456298004381018afcd2d588a503839fbbc93321ca8c64c6d3a62e16"
time="2021-11-05T22:53:44-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m9.198325668s for 5f31fb57ce1cd0a13a0f8393e23951880ef81baf5c6fc3e5c50d38b19cd17ed5"
time="2021-11-05T22:53:45-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m22.97136322s for 450d31467c22e6f24c49986946718bbbf093c6963e48c571ae099f72a37ccf7d"
time="2021-11-05T22:53:47-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h53m26.71963057s for 7bef121b1cd548220c7910e100c1c2ff9641103e6512ff46ba057f70abd41f98"
time="2021-11-05T22:53:48-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h53m17.527903678s for 45453cf1fa8bd5a90e77be2125e51102d4138a7f85ea8bccb5faea25c18c0fce"
time="2021-11-05T22:53:57-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m41.060148093s for 3619284ad5696a0c38040c0bb691839e93f0a6826f7ea52dfe86bd007d9d7c23"
time="2021-11-05T22:53:58-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m47.383565085s for 5a32943929dc7a5ad80afcd72a23f022213787517e8f4289cf87c23866d276e3"
time="2021-11-05T22:54:03-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m2.34587834s for 45ed7dd46bfddae42231e3bcff3d7916c2cd0b82e7b3f2a404938d3752254846"
time="2021-11-05T22:54:05-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m56.288088342s for 52f012fe1f53da448ae1d7a834aba3f526901263cbcc80c76cbd43f70b7e37a2"
time="2021-11-05T22:54:08-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m49.115275298s for 78816f8c1b078b185a56aac6e7c6c95d198d2a5d4d52a24f76ff7853c4fd978a"
time="2021-11-05T22:54:10-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m29.575310694s for 739ff78396aa324a58d03d5cbdd99611ad118e59a0781e7565007fc669c6b960"
time="2021-11-05T22:54:20-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m53.809558064s for bec69dc69e86b3291238a065a954b04e7f89e8d09e78d71d163c8421a2d65e2c"
time="2021-11-05T22:54:24-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h53m4.466113859s for 4d20ad285155a90b73100e0b18b6207f0983533a9818f0e9b79e41dc1993b078"
time="2021-11-05T22:54:24-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h52m40.689235853s for 4a237cd9af4caf8c390eb0abcf492f4d0117cf2cc73806a498bf7f2cc65b9984"
time="2021-11-05T22:54:33-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m35.135995448s for 42c7a4280a7b2539f86ecd8b93ef4778529ccb0ab321d5d961e5ad2b3594a25a"
time="2021-11-05T22:54:43-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m18.541189464s for 561c65551c5795cf1b2d29eac196ae8493f5beed047898b0a9c9083af3c7ec83"
time="2021-11-05T22:54:47-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h53m43.497682905s for 720e3112cb553b9712d4d69c9fb3b67e3a19e7349c8717f655d03228771d7d31"
time="2021-11-05T22:54:54-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m10.515854378s for 5569ed5903e41c08069f95508fcde41d86f6f7366407c0229906fdc758909ba7"
time="2021-11-05T22:55:07-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m25.781636553s for 40cfc0dc9cf8e844e9209b5960aa789046235ecf970e56f4bd6490c3c82372c4"
time="2021-11-05T22:55:55-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m8.261518426s for 6583d4e323f93519eaf6205143af92730cbe8510649f282ee11521a935f61e96"
time="2021-11-05T22:56:00-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h51m27.630003377s for b6e61dc689bf49865ed89062d56d1005964acbfbc8d17f36b06b3fb235fe2b57"
time="2021-11-05T22:56:26-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m52.625261366s for 6cfef0533775f92fdf9b492d8fd4d9c8ff6bb266ab4c6fdf354388456bf286a8"
time="2021-11-05T22:57:09-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m54.001806836s for 69c4c4058a52dd3e2fcdaa21a1c6ba97a335b3b71fb632c6aa49c6bf25e6b62d"
time="2021-11-05T22:58:16-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h46m53.164076868s for 6cfef0533775f92fdf9b492d8fd4d9c8ff6bb266ab4c6fdf354388456bf286a8"
time="2021-11-05T22:58:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m26.053182408s for 7379e0eb925c69e10f7702366b6a2d15955b6899ca957ceada84487c7ac50fbe"
time="2021-11-05T22:59:02-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m25.510809629s for 77d4f122f62ffe116ed7842da98e77d7f9cc3287c73d9380854fe05effb7ac0b"
time="2021-11-05T22:59:08-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h37m51.779929406s for 6c63fbd3677a858b031d95258fbb484f65cc8545990b79ffc08b9cad9cad9b26"
time="2021-11-05T22:59:11-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m54.475123181s for 2ef52890a14f4087a4ff9e62015d49cb8ead21e2d2add086b271d7c6955d5488"
time="2021-11-05T22:59:34-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m47.529201214s for 5c37e0eb18692267c9894ecb76b3fafc5a0b6f44cdc013d31c117b0c5aa9e4fc"
time="2021-11-05T23:00:38-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h48m26.330230135s for 53ab293c5e8fabcb4b89cb6cda530a7e05e72e97988c8941f43bf3f0168c53c4"
time="2021-11-05T23:02:15-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h49m6.13128967s for 6bc0bd532d4a65496cef25eedf2f3a006ff70049ae5c7a19e3c126fee3f0e888"
time="2021-11-05T23:02:26-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m41.404904927s for 479d6d0886414bac0bd4984a7e979998e0fbb11316d246c804415cf1b6fbdc5d"
time="2021-11-05T23:02:42-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h46m51.919319424s for 720033d169b6d98dc7f480fe9cb67bdaff545d6117728e3c45d222278a60e376"
time="2021-11-05T23:09:07-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h44m49.664654866s for 616a5e6458b11d18afaa3d538809d18f3b501fa6b3e8bf850f2ab9ccee331fe3"
time="2021-11-05T23:09:16-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m57.289995217s for 7b608c19f865ca7286b91b0c80eb76a2796f926c6a7dc6f6cb05a1c0afa8684c"
time="2021-11-05T23:09:37-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m45.366742628s for 655f413dde209ad6a1329fbe67a24d835bd7502ab28b566f2c281e42bf6505aa"
time="2021-11-05T23:10:38-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m17.20162509s for 558cb1757df3ffec2583d9a67ac0ba09e8672e51afb788fdacf3a23feaec55c8"
time="2021-11-05T23:11:33-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h50m56.160453685s for 61353f0ba6f661ff8d0b06e64ac8d6e28f7d491752d78bb0f15a36cf66765acb"
time="2021-11-05T23:12:12-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m38.072057942s for 7dc330195bc1229465fb58283049072586daef87151ab1fa602010433d97a65f"
time="2021-11-05T23:13:01-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m13.627449863s for 6ecbb539f72d5db30ebb9c49f9c1f2f7b4f55bcaa81952e79087202f8b244f3c"
time="2021-11-05T23:13:07-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m33.112351287s for 4b5a8fdf336248dee2fb79828318bab3c90517d22cf484e2e3dae08b5cf62190"
time="2021-11-05T23:13:19-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h45m30.188257852s for 743d5e6b8ddd72d449449c7fb483d0b8ec456bb44d5c08f072a3816c448a8be1"
time="2021-11-05T23:18:35-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h47m10.596973305s for 7df49a75a3ef914841047aa6b4c40d5b396255bae68d204edd27666795e8cde1"
time="2021-11-05T23:18:56-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h43m12.945947372s for 63e69f63424f2924d9537273ef9cc7475ef690f1c054c73a3371f7260525315c"
time="2021-11-05T23:19:17-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h44m46.10630061s for 6dbbf866ab77bb9f964d37637f54af45a5d5c408089653b6af79c64c07228434"
time="2021-11-05T23:19:26-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h42m48.291092585s for 2d59c6457d1600badcad1dc34f617965c8c70afdfb7316fc40b695b3f3186c1e"
time="2021-11-05T23:21:42-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h44m33.592509345s for 44f16aed2b27814250863e343b55671f6e3fd64725c9e812d48a98e54a6dac7f"
time="2021-11-05T23:24:51-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h40m42.213089579s for 7b343bb55fe32aca01c4df79d12d90760a89dee9ddb509ddce08d96c496ea423"
time="2021-11-05T23:29:31-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h38m49.477201664s for 6704805ab48829ee6f510756b4302724bae5f2a3c3a5f41249a084762a6c3add"
time="2021-11-05T23:30:43-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h34m31.930749225s for 6a3f1b2616e339de27538ecd7576523215c79066b67ae4f0e06643716ad1b24d"
time="2021-11-05T23:34:21-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h34m13.138773017s for 46fd7f0e11034cba7fc6ee55da71e3c988d57dddf80d2378be7448fe640c29be"
time="2021-11-05T23:42:08-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h33m38.526811382s for 79d36e718c544e20809d55e7777507bda4f356ebc0f4f522dd841c9768bf8bb2"
time="2021-11-05T23:49:28-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h25m9.419230203s for 6d0a9e3cc607ef9df10636d50f2482489e7b724b32b70b80e686c935f845b1d3"
time="2021-11-06T00:00:01-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h15m54.190142546s for 5b11240e86d2eeb901c43018a5d7d3315165a282927828cb7a02359f65d512c9"
time="2021-11-06T00:00:30-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 2h16m25.169898821s for 4949d3357ef2e374554fac26f76f90b55771a789c34ea490f0d88a503b83c418"
time="2021-11-06T00:26:53-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h43m54.089977446s for 561c65551c5795cf1b2d29eac196ae8493f5beed047898b0a9c9083af3c7ec83"
time="2021-11-06T00:30:55-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h51m55.88978711s for 7d28c2ab1ead8865c07c1dfcfcea43aa313672f9da6d856f101df56fc75f7ee3"
time="2021-11-06T00:31:38-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h52m8.861093411s for 6dabda2e0fcb2fb7eab64eb15be9887d32cb76443df1e72609000d49cebe485a"
time="2021-11-06T00:32:32-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m9.285475028s for 3fae0e1f89b94e696a10ccf2bb2fc14019539a0ec15089531c7ed2f8794856f1"
time="2021-11-06T00:32:47-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m30.840012208s for 76e79a7cc92280e3b5b15a8cc3dea50fde8ea99ac1a563f9656d9303fb4d7291"
time="2021-11-06T00:32:50-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m3.107839321s for 7399e86d1d3d618d9dc6eb34b9e4a6c57aa81ba3b19766e88d3148cfdfa891f2"
time="2021-11-06T00:32:50-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m51.535679394s for 7b9789c99ec4c2163a9d86873e8082f638b76639cf7674da1fb5bb470ae7cc8d"
time="2021-11-06T00:32:51-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m44.847363354s for 53ab293c5e8fabcb4b89cb6cda530a7e05e72e97988c8941f43bf3f0168c53c4"
time="2021-11-06T00:32:55-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m32.357785964s for 7b0979edfc1dc954dee7c73ea375b73d1711a90c4b82f09d4595ad3f2347f6fb"
time="2021-11-06T00:32:55-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m54.25916335s for 774e3dec7aacca982f34128c9a026ff52f0471da59a28b5b58ffb3389e531b5d"
time="2021-11-06T00:33:11-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m40.454452798s for 5479d19bc0254cfbfe4286d69ab79bc840bbc61d4fc4ca2aca4a51eaab701605"
time="2021-11-06T00:33:13-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m3.706176574s for 41fe081f6530a825dc186ce6add23624c42c2621c40fccb85fb39bdc701177cb"
time="2021-11-06T00:33:15-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m4.645801607s for 45168d1c7be9aa4eb3b08b97641b2bbe2bb57bbb7c46c4f67ae2c7e305e71ee7"
time="2021-11-06T00:33:22-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m51.054853597s for 53affb649e1c00f5c6db6c852bf1ec6dfbef62a655532db664691ba6fbfd83f3"
time="2021-11-06T00:33:25-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m1.079040034s for d8417aa357281af6422f8c97fbee56adde073d770b2a0aec08a1746a8e659438"
time="2021-11-06T00:33:29-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m27.624790472s for 7e88eb956c243afb9b2c784065f6ec8057d89c8716571b5b0784873301c32a50"
time="2021-11-06T00:33:29-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h50m30.185956163s for 5d62091cb67c59692d73701b14340ccb4f73d78e4bc59027b72801e2368af89b"
time="2021-11-06T00:33:32-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m38.666990059s for 7bac52a1f8d09d77ff76433418f81e195a2756edd5a04d76e64517f47b835252"
time="2021-11-06T00:33:36-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m17.362773239s for 7ec60e4c87c542a916999c21e3d3b424d9dc2c91c86827c700910f4e09518cc9"
time="2021-11-06T00:33:38-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m13.521545416s for 5a07cefaf06d3197383eab5eac6e157f010ee708b014307686af270917ace0a1"
time="2021-11-06T00:33:41-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m13.235894561s for 720e3112cb553b9712d4d69c9fb3b67e3a19e7349c8717f655d03228771d7d31"
time="2021-11-06T00:33:43-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h51m41.136396378s for bd61c6a06e664c88acf92d32b14fcb101d3f7242c6547a054aa77245d62de929"
time="2021-11-06T00:33:45-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h50m47.982299486s for f5236d06b644c9bccac21ac850b4939e1d52c9d2b73c4ed414a92873f785a194"
time="2021-11-06T00:33:45-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m20.148038962s for 2ee5f0edacc7b2990ed304034d119179b843040ebf98dd98f68a138911bb043f"
time="2021-11-06T00:33:45-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h47m21.374604931s for 0c0bf88faf73029b7711daecf0d09d4b01a2f165a2d2afd371572b92ece2e9b4"
time="2021-11-06T00:33:46-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m23.995969553s for 0f58fbadc208e36bfcb3e6cb090424fad6a6959a883f5f385942bde6aaae543b"
time="2021-11-06T00:33:48-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m42.492138526s for 54ba42dacc57896d2adbd9f64aff84306120a702788169197eab5af707ebc4b0"
time="2021-11-06T00:33:48-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h50m38.017966318s for 77196eab5e2674e603e48273a072ae8dab012e9775f2fd8d741aa5edef37c231"
time="2021-11-06T00:33:50-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m50.150351766s for 7379e0eb925c69e10f7702366b6a2d15955b6899ca957ceada84487c7ac50fbe"
time="2021-11-06T00:33:52-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m26.145404288s for 54e42e974ff9c3127f9f8ca39eb2afd42009182311e3cdba845b25c250ca2ba8"
time="2021-11-06T00:33:54-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m24.344874392s for 7d014ffe6a30951e5bc843d35667019c983fcb573b168567a6df52f04659bafb"
time="2021-11-06T00:33:55-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h52m33.989495892s for 74f9cff21d2a6c2d15c37389c6395db6ab6917294439dc6e1a99fdf8c2f0ae66"
time="2021-11-06T00:33:57-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m1.303726633s for 8c50078f8e9bbc5ce37f53026ce9375cb66244c8123bee26c4b72ca50c3ad3ee"
time="2021-11-06T00:33:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m50.085161736s for 7d1fe997df12598ea559193eb2963a58341dfe496846c76770a3af2e9407e3b3"
time="2021-11-06T00:33:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m35.544433946s for 7c87cf3d1f3905f433f57d700107a82254a303307c1043d5931e3af667606bf6"
time="2021-11-06T00:33:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m47.008142905s for 4ca134d0bb4f977c3ff86039071718a30fa372a03adae4ad8fb39a933fa572ac"
time="2021-11-06T00:34:00-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m0.342943585s for 4acbd8d600763ddcc3c902e28a5f8abccab201c1e97bae96a3577f6d18167ffd"
time="2021-11-06T00:34:02-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m33.790702188s for 71bf8f0ffcfa7d712eb4c4cb1aaec31c55fbcc4843d058eceadb6e72ea74b9b2"
time="2021-11-06T00:34:03-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m33.298150178s for 1d362f3723333166fd0d4944471651e6af9e099c29662364901d501907f75f00"
time="2021-11-06T00:34:04-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m36.837906231s for 14d60acdafeb26dc847eabf14dcba517707b3baae2aa952720c5642fe81c52d9"
time="2021-11-06T00:34:04-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h52m2.087784118s for f925efa0beb51d688b42003d88871ec24d5ba4cb94d7ca8504d94ae4f64e75a0"
time="2021-11-06T00:34:04-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m41.58021735s for 788da31821b4f84670400c0561b69e3c79b538545c04436bf840fa463ef6ee86"
time="2021-11-06T00:34:06-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m37.856914231s for 7b6b3d83281b20e714faa8885cdecb056c75531150421cc0ccfdfc2f88fb3996"
time="2021-11-06T00:34:06-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m10.796188978s for 74f23c1edb60f98b4ebf120a33fe381ce3b2e73341ffaf7b1332855a67cc5159"
time="2021-11-06T00:34:07-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h51m7.668234413s for 555bbcf8cdbdb36fa6fbd3212e7d4eca58baafa11721964075a5f5d88e87e0ea"
time="2021-11-06T00:34:07-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h51m2.942824882s for 6b20b013346c65ee5c6d38f07c8c8174774afbc7eab051394e4c0a247386026b"
time="2021-11-06T00:34:10-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m42.05122558s for 1ec7b990ceda90ac9cecc2b12d930d7cec3de2dc80245915c2ec8409b037d736"
time="2021-11-06T00:34:10-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m48.523991933s for 5bd32f9c2b5b5adc06b64f4da04543d55679455ddceb61ddd73084406d54d8e4"
time="2021-11-06T00:34:11-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m4.134608432s for 42806d10914f742b38b98173e178b2ad8b7937f3d4d5b6ae0279b1251984d09c"
time="2021-11-06T00:34:12-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m12.8486331s for 58a9acf2063e790d91995110d4d83622b66382cd08f0f19af3c39552fbe2b8c1"
time="2021-11-06T00:34:13-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h51m22.750377255s for 468c6d38cc315c31c03d88e580faf1700249ccffc0d8da3ffebd2fb67c4d7254"
time="2021-11-06T00:34:15-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m44.879583184s for 7d657b2bcb1dee6c1492362a0344f49a3b3904ec6a1999e35d777f75ac1283da"
time="2021-11-06T00:34:18-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h49m48.459438421s for 74c9daf103b8a0db96203b15b0217274557665e1046256f8334fd10c4c632683"
time="2021-11-06T00:34:19-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m15.965230179s for 7543cd12d179397b81ad7ec723a5246bc901b4e4c183dcad7bcc0672b9d7f6a0"
time="2021-11-06T00:34:19-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m59.558457018s for 7328f6a5eb9fabafdce157f52bf59d1fcc4410daaa7c18b4d4f3c893341c4905"
time="2021-11-06T00:34:19-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m10.579011713s for 5d913cb99299426fdbc1f5f6cd6444f296c6677757a6be6f279e5d4bc69e3750"
time="2021-11-06T00:34:21-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m59.898039942s for 5633c9aa66797a6254943669dcf74f1e137076b344fc260d471c1006a6785ce9"
time="2021-11-06T00:34:21-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m3.909545985s for 41b4b1971270451e29e7223e89c58c5be97bf653cc9f53b73f17a01a903dfe4a"
time="2021-11-06T00:34:25-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m27.634107121s for 4971ba22a35ec49e91a8f66304819be3a658d74ec3f70845ea206fc814b2447b"
time="2021-11-06T00:34:26-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h52m0.760171987s for 5dbe4656d783af3b6445395c9f5549408bf42c96388dec27606e90a6ebe973a9"
time="2021-11-06T00:34:29-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h51m17.023704793s for 59577a1ca0186db0bc1941a84f4f005bfc622e8d97ffd0ba0085553599b4cc73"
time="2021-11-06T00:34:30-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m29.157846609s for 2b27e7e5c0719c77188cc1992d7fa6717bfa0d884d5cd1ab6f2c4aa34987ca5a"
time="2021-11-06T00:34:31-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m30.133665397s for 7747ffa301397681e923c6ad127146c93d50eab38d329e8622b04fa1362dafb3"
time="2021-11-06T00:34:31-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m27.939211987s for 542747931d6ccc676db772ad0285b9ae67bcd685735096661692542b3180f48b"
time="2021-11-06T00:34:32-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m51.243192263s for 43ecfaa318fab64bf10c6eed3834532ef7d81dd31742d18bf54e75cc20575678"
time="2021-11-06T00:34:33-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m41.330978908s for 743b6950f3adc08717d9725e3139027295eb95c6f79e625471e337c02a35931e"
time="2021-11-06T00:34:33-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m5.976458134s for 79cd9fd39c90761b622809583f5cb3f172f59781b499230bd6bd799f0257e480"
time="2021-11-06T00:34:34-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h50m38.92428343s for 2550efdbe78e8c9802cc625f181734ab439c6a114db1adbcaf482a594139b92d"
time="2021-11-06T00:34:35-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m7.332930725s for 3fdbe7b135153601673c527f94d36a735a6f978e892c367e1022efd0a3094110"
time="2021-11-06T00:34:35-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h47m28.785073076s for 4ab12df11cee6023a9e7717e184c63475b407e4a9e96acea4616b02796798667"
time="2021-11-06T00:34:36-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m12.73800875s for 478aaea03548c7cc67b9f9c7d84c57b85dbf983e03e721c4221f69c331060fdd"
time="2021-11-06T00:34:36-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m3.083115354s for 07874f48928b7b0d7e5b5fe13dc4831d3044c97e4f2510dcf1a0d9cc2813d10e"
time="2021-11-06T00:34:37-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m57.032308554s for 16cf8c3840c38a1ad86f43fc6f9675518bafc051f2baee07b0e2d3b98a268ed2"
time="2021-11-06T00:34:37-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h49m41.135318994s for e9cc3ebaea22a320679adef79b65412535e623c07eb12149e8a5bd5b0e59fd4b"
time="2021-11-06T00:34:37-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m15.12158336s for 0a27c9c46c53c4170c01c5fe92e92d8f74923a06c0e754af00b13f0011491b5e"
time="2021-11-06T00:34:37-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h50m14.99352905s for 2aa1631f8ed007ad8adc4186b34cac1d7d69d1eb984eb14da179b47d6953c796"
time="2021-11-06T00:34:39-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h51m50.065917588s for 1e8362db18352bee26456ab1cb243a9e087c4554f209438e0708443e4635df5f"
time="2021-11-06T00:34:39-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m37.775338177s for 4598b5586127c73566086f630f6f13038781e1d29083a0e369164032b2d46e37"
time="2021-11-06T00:34:40-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h51m42.73823103s for 27a6dac2162439c07bfcd9d6a4e2e4ea977e026e7e4d066e68f64db3ddd6d8eb"
time="2021-11-06T00:34:40-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h54m24.490542022s for dbc562a815a88862d65a056c5992f2bde25ec639e8f8fd039c779b3a638278dd"
time="2021-11-06T00:34:40-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m35.684628213s for 5a872f2c1d4fc9739e345bbcd873a96d7c93500bb7544449a25724380da9e3d3"
time="2021-11-06T00:34:41-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h55m32.667911821s for 5520692a13cb12be281db4ff52aa279ca1d44619a1ff25415e70c334920b3fd2"
time="2021-11-06T00:34:41-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h53m34.332503845s for 7b09ecba124d72ade36cfdd3f12a62f8d163117cc5a3289fe5e520a2b6a026fb"
time="2021-11-06T00:34:45-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h44m26.927638374s for 7702c2d84bf8b4173368d76cc8961e4e8b46fa08a144ede1f247b723ca0abbdb"
time="2021-11-06T00:34:47-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h51m58.211248764s for 69d84180b0bf9ad4542b3eaa8f77b6bd2d7d26cb853070c90a02b2ca2e8e352f"
time="2021-11-06T00:34:50-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h46m46.845053546s for 1b8f170563edb73db72f0799b3c1e5908ae7fe9d913e9cd459e1b37a8ddaff3c"
time="2021-11-06T00:35:27-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h39m49.688438259s for 498cf95c0e97457e87f0bfa999dcba9fc1e344edb2080e79f73467c65e6e7568"
time="2021-11-06T00:35:27-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h42m46.742495958s for 6be447d93a69c172228bdc286fc6c820cb25c4a2db26af078bbe73464d383055"
time="2021-11-06T00:35:45-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h36m3.072781143s for 61353f0ba6f661ff8d0b06e64ac8d6e28f7d491752d78bb0f15a36cf66765acb"
time="2021-11-06T00:35:48-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h38m10.399591931s for c85542eb9266cb6d4fc08e7fbea4efa4c0da8a3e3c1874854e370e38c1462c33"
time="2021-11-06T00:36:19-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h36m16.16162902s for 5e8790495d5edd652eff9cbed4296e4ee38bc4ab45d3b72806ba2145e84e1bca"
time="2021-11-06T00:37:03-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h26m50.770374714s for 6cbf039f98eb447ba27b64bf0ed4a36c48c2920809366f78f4a22eaecb49fc8e"
time="2021-11-06T00:37:13-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h23m53.661236034s for 456b108b335d5d5caa97e09c11bbf748bbf452c0cf705279da0422a168ba95bc"
time="2021-11-06T00:37:19-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h24m0.017939432s for 45453cf1fa8bd5a90e77be2125e51102d4138a7f85ea8bccb5faea25c18c0fce"
time="2021-11-06T00:37:47-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 1h14m24.506834137s for 6da8f76e0a85fd3745f6670d2e75dfde75ee41cdea17bca0934b0129e3fbc16e"
time="2021-11-06T00:39:48-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 36m37.370984357s for 616246b56b890146d0977b176a6fcd84c42aef16f2c1399a02f14631b2c611b3"
time="2021-11-06T00:40:49-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 13m35.616193866s for 608ace4fc7cb6f885fa058fec65ed8f01fe14dc6dd809159bccc376edafbee1d"
time="2021-11-06T00:40:59-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 8m19.368464483s for 2b961a717154b9d3006438341eb731cfdebcc5ab9c0117940564cc8084a5eb23"
time="2021-11-06T00:41:00-04:00" level=debug msg="pullsync:cursorHandler:Cursors() took 8m37.43035445s for 7faa451845337567300f4af4a3c92a9825f7f2ae8f111e4910d75ed0fa29d6e0"
The problem here is less about context handling than the fact that the bee storage abstraction cannot cater to 150gb of data at this point. While we work on improving this, you are advised to run nodes that are trying to push such amounts of data in light node mode, which would prevent other nodes from querying the cursors from you.
Well, I'm glad somebody did the trailblazing to identify that large storage nodes have some issues before the whole world starts loading up lots of data.
In the meantime, I've implemented a singleflight around my cursors handler that helps some. Rest easy, I'm also deleting the singleflight key as soon as it is completed so that it only coalesces concurrent requests and will re-execute the actual queries later when someone new asks for cursors.
I'll keep the light node mode in mind, but for now I'll continue living with the (slightly mitigated) pain. Thanks.
But in the end, regardless of the storage abstraction, context cancellation should be honored and because more and more cursors will be requested, and they seem to bunch up around connection issues, a singleflight approach may yet be beneficial overall.
This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 5 days.
![github-actions[bot] avatar](https://avatars.githubusercontent.com/in/15368?v=4 "Published by a pub.dev verified publisher"){kind=small}
This issue was closed because it has been stalled for 5 days with no activity.
This issue was closed because it has been stalled for 5 days with no activity.
This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 5 days.
This issue was closed because it has been stalled for 5 days with no activity.
This issue was closed because it has been stalled for 5 days with no activity.