outbackcdx icon indicating copy to clipboard operation
outbackcdx copied to clipboard

Replication secondary applies the last batch over and over

Open ato opened this issue 5 years ago • 3 comments

When running in secondary mode OutbackCDX seems to apply the latest write batch over and over even if it has already been applied. I'm not sure this necessarily causes any functional problems but it does mean the index keeps getting updated on disk unnecessarily. The RocksDB log file grows but I assume it will eventually be compacted. It still seems less than ideal though.

How to reproduce:

Run a primary instance:

$ mkdir /tmp/primary
$ java -jar outbackcdx-0.7.0.jar -d /tmp/primary --replication-window 0

Create a collection named 'example' with some record:

$ echo '- 20190101000000 http://example.org/ text/html 200 - - - 1043 333 example.warc.gz' > example.cdx
$ curl --data-binary @example.cdx http://localhost:8080/example

Run a secondary instance:

$ java -jar outbackcdx-0.7.0.jar -d /tmp/secondary -p 8081 --primary http://localhost:8080/example
OutbackCDX http://localhost:8081
Tue Jan 14 17:32:29 KST 2020 ChangePollingThread(http://localhost:8080/example): replicated 1 write batches (1..1) with total length 132 in 0.504s from http://localhost:8080/example/changes?size=10485760&since=0 and our latest sequence number is now 2
Tue Jan 14 17:32:38 KST 2020 ChangePollingThread(http://localhost:8080/example): replicated 1 write batches (1..1) with total length 132 in 0.004s from http://localhost:8080/example/changes?size=10485760&since=1 and our latest sequence number is now 4
Tue Jan 14 17:32:48 KST 2020 ChangePollingThread(http://localhost:8080/example): replicated 1 write batches (1..1) with total length 132 in 0.006s from http://localhost:8080/example/changes?size=10485760&since=1 and our latest sequence number is now 6
Tue Jan 14 17:32:58 KST 2020 ChangePollingThread(http://localhost:8080/example): replicated 1 write batches (1..1) with total length 132 in 0.006s from http://localhost:8080/example/changes?size=10485760&since=1 and our latest sequence number is now 8

CC: @jkafader @nlevitt

ato avatar Jan 14 '20 08:01 ato

We left it that way because rocksdb sequence numbers are not unique. For example:

18:43:33:nlevitt@ait-cdx-qa-sec-01:~$ curl -gsS 'http://ait-cdx-qa-master:8080/archiveit-limbo/changes?size=10485760&since=51370259' |& less
[
{"sequenceNumber": "51370259", "writeBatch": "E9kPAwAAAACkAAAAAYgBZnV6enk6Y29tLHZpbWVvY2RuLHNr
{"sequenceNumber": "51370423", "writeBatch": "t9kPAwAAAAAAAAAA"},
{"sequenceNumber": "51370423", "writeBatch": "t9kPAwAAAADOAAAAARxjb20sdmltZW8pLzI0NTA2MzA3NgAA
]

One round of replication could conceivably leave off after the first 51370423 there, so you have to be careful not to skip the second one. Maybe possible but we didn't take the time to figure out how to do it reliably.

nlevitt avatar Jan 14 '20 18:01 nlevitt

Oh! Weird. Hm I suppose a way to do that would be to record not just the last applied sequence number but also a count of the number of writebatches with that same sequence number that have been applied.

ato avatar Jan 15 '20 01:01 ato

Yeah I think that would work.

nlevitt avatar Jan 15 '20 01:01 nlevitt