[
https://issues.apache.org/jira/browse/CASSANDRA-15159?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16866546#comment-16866546
]
Per Otterström edited comment on CASSANDRA-15159 at 6/18/19 12:03 PM:
----------------------------------------------------------------------
I had a look at this ticket [~laxmikant99].
I'm able to reproduce with your instructions on {{trunk}} as well. It's nothing
related to TTL, so a simple delete will give the same result.
>From what I can tell, this behavior comes from
>{{ReadCommand.withoutPurgeableTombstones()}}. Given the title of this ticket,
>I'm guessing you arrived at the same conclusion. :-)
That method has the following comment:
{code:java}
// Skip purgeable tombstones. We do this because it's safe to do (post-merge of
the memtable and sstable at least), it
// can save us some bandwith, and avoid making us throw a
TombstoneOverwhelmingException for purgeable tombstones (which
// are to some extend an artefact of compaction lagging behind and hence
counting them is somewhat unintuitive).
{code}
So, this seem very intentional. Reasons I can think of for this behavior are:
* The query result is consistent whether compaction happened or not - after
all, gc grace has expired
* And as mentioned in the comment; overwhelming amount of tombstones and
bandwidth
At the same time, it is annoying to get back resurrected data, when you *know*
the tombstone is still there.
But what worries me the most is that a read-repair will be triggered on every
read and spread the resurrected data.
{noformat}
cqlsh> select * from test.table1 where key = 'key2';
key | col | val
------+-----+-----
key2 | abc | xyz
(1 rows)
Tracing session: 4f1a9b90-91b6-11e9-a0ff-9d318f160025
activity
| timestamp |
source | source_elapsed | client
-------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------+-----------
Execute CQL3 query | 2019-06-18 12:46:20.873000 |
127.0.0.1 | 0 | 127.0.0.1
Parsing select * from test.table1
where key = 'key2'; [Native-Transport-Requests-1] | 2019-06-18 12:46:20.874000
| 127.0.0.1 | 358 | 127.0.0.1
Preparing statement [Native-Transport-Requests-1] | 2019-06-18 12:46:20.875000
| 127.0.0.1 | 1331 | 127.0.0.1
reading digest
from 127.0.0.3:7000 [Native-Transport-Requests-1] | 2019-06-18 12:46:20.875000
| 127.0.0.1 | 1922 | 127.0.0.1
Executing
single-partition query on table1 [ReadStage-2] | 2019-06-18 12:46:20.876000 |
127.0.0.1 | 2048 | 127.0.0.1
Acquiring sstable references [ReadStage-2] | 2019-06-18 12:46:20.876000 |
127.0.0.1 | 2166 | 127.0.0.1
Sending READ_REQ
message to 127.0.0.3:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.876000 | 127.0.0.1 | 2212 | 127.0.0.1
Key cache hit for sstable 2 [ReadStage-2] | 2019-06-18 12:46:20.876000 |
127.0.0.1 | 2376 | 127.0.0.1
Skipped 0/2 non-slice-intersecting
sstables, included 0 due to tombstones [ReadStage-2] | 2019-06-18
12:46:20.876000 | 127.0.0.1 | 2542 | 127.0.0.1
Merged
data from memtables and 1 sstables [ReadStage-2] | 2019-06-18 12:46:20.876000 |
127.0.0.1 | 2772 | 127.0.0.1
Read
0 live rows and 0 tombstone cells [ReadStage-2] | 2019-06-18 12:46:20.876001 |
127.0.0.1 | 2899 | 127.0.0.1
READ_REQ message
received from 127.0.0.1:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.877000 | 127.0.0.3 | 73 | 127.0.0.1
Executing
single-partition query on table1 [ReadStage-1] | 2019-06-18 12:46:20.878000 |
127.0.0.3 | 1148 | 127.0.0.1
Acquiring sstable references [ReadStage-1] | 2019-06-18 12:46:20.878000 |
127.0.0.3 | 1401 | 127.0.0.1
Skipped 0/1 non-slice-intersecting
sstables, included 0 due to tombstones [ReadStage-1] | 2019-06-18
12:46:20.878000 | 127.0.0.3 | 1637 | 127.0.0.1
Key cache hit for sstable 1 [ReadStage-1] | 2019-06-18 12:46:20.878000 |
127.0.0.3 | 1917 | 127.0.0.1
Merged
data from memtables and 1 sstables [ReadStage-1] | 2019-06-18 12:46:20.879000 |
127.0.0.3 | 2442 | 127.0.0.1
Read
1 live rows and 0 tombstone cells [ReadStage-1] | 2019-06-18 12:46:20.879000 |
127.0.0.3 | 2654 | 127.0.0.1
Enqueuing response to 127.0.0.1:7000 [ReadStage-1] | 2019-06-18 12:46:20.879000
| 127.0.0.3 | 2851 | 127.0.0.1
Sending READ_RSP
message to 127.0.0.1:7000 [Messaging-EventLoop-3-3] | 2019-06-18
12:46:20.880000 | 127.0.0.3 | 3276 | 127.0.0.1
READ_RSP message
received from 127.0.0.3:7000 [Messaging-EventLoop-3-2] | 2019-06-18
12:46:20.881000 | 127.0.0.1 | 7419 | 127.0.0.1
Processing
response from 127.0.0.3:7000 [RequestResponseStage-5] | 2019-06-18
12:46:20.882000 | 127.0.0.1 | 8800 | 127.0.0.1
Digest mismatch: Mismatch for key
DecoratedKey(8482869187405483569, 6b657932) [Native-Transport-Requests-1] |
2019-06-18 12:46:20.883000 | 127.0.0.1 | 9551 | 127.0.0.1
Enqueuing full data read to
Full(127.0.0.3:7000,(3074457345618258602,-9223372036854775808])
[Native-Transport-Requests-1] | 2019-06-18 12:46:20.883000 | 127.0.0.1 |
9771 | 127.0.0.1
Executing
single-partition query on table1 [ReadStage-6] | 2019-06-18 12:46:20.883000 |
127.0.0.1 | 9800 | 127.0.0.1
Acquiring sstable references [ReadStage-6] | 2019-06-18 12:46:20.883000 |
127.0.0.1 | 9880 | 127.0.0.1
Key cache hit for sstable 2 [ReadStage-6] | 2019-06-18 12:46:20.884000 |
127.0.0.1 | 10095 | 127.0.0.1
Sending READ_REQ
message to 127.0.0.3:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.884000 | 127.0.0.1 | 10121 | 127.0.0.1
Skipped 0/2 non-slice-intersecting
sstables, included 0 due to tombstones [ReadStage-6] | 2019-06-18
12:46:20.884000 | 127.0.0.1 | 10235 | 127.0.0.1
Merged
data from memtables and 1 sstables [ReadStage-6] | 2019-06-18 12:46:20.884000 |
127.0.0.1 | 10463 | 127.0.0.1
Read
0 live rows and 0 tombstone cells [ReadStage-6] | 2019-06-18 12:46:20.884000 |
127.0.0.1 | 10598 | 127.0.0.1
READ_REQ message
received from 127.0.0.1:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.885000 | 127.0.0.3 | 105 | 127.0.0.1
Executing
single-partition query on table1 [ReadStage-2] | 2019-06-18 12:46:20.885000 |
127.0.0.3 | 665 | 127.0.0.1
Acquiring sstable references [ReadStage-2] | 2019-06-18 12:46:20.886000 |
127.0.0.3 | 867 | 127.0.0.1
Skipped 0/1 non-slice-intersecting
sstables, included 0 due to tombstones [ReadStage-2] | 2019-06-18
12:46:20.886000 | 127.0.0.3 | 1067 | 127.0.0.1
Key cache hit for sstable 1 [ReadStage-2] | 2019-06-18 12:46:20.886000 |
127.0.0.3 | 1349 | 127.0.0.1
Merged
data from memtables and 1 sstables [ReadStage-2] | 2019-06-18 12:46:20.886000 |
127.0.0.3 | 1731 | 127.0.0.1
Read
1 live rows and 0 tombstone cells [ReadStage-2] | 2019-06-18 12:46:20.887000 |
127.0.0.3 | 1930 | 127.0.0.1
Enqueuing response to 127.0.0.1:7000 [ReadStage-2] | 2019-06-18 12:46:20.887000
| 127.0.0.3 | 2634 | 127.0.0.1
Sending READ_RSP
message to 127.0.0.1:7000 [Messaging-EventLoop-3-3] | 2019-06-18
12:46:20.889000 | 127.0.0.3 | 3510 | 127.0.0.1
READ_RSP message
received from 127.0.0.3:7000 [Messaging-EventLoop-3-2] | 2019-06-18
12:46:20.889000 | 127.0.0.1 | 15665 | 127.0.0.1
Processing
response from 127.0.0.3:7000 [RequestResponseStage-6] | 2019-06-18
12:46:20.890000 | 127.0.0.1 | 16028 | 127.0.0.1
Sending read-repair-mutation to
Full(127.0.0.1:7000,(3074457345618258602,-9223372036854775808])
[Native-Transport-Requests-1] | 2019-06-18 12:46:20.890000 | 127.0.0.1 |
16762 | 127.0.0.1
Sending READ_REPAIR_REQ
message to 127.0.0.1:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.891000 | 127.0.0.1 | 17413 | 127.0.0.1
READ_REPAIR_REQ message
received from 127.0.0.1:7000 [Messaging-EventLoop-3-1] | 2019-06-18
12:46:20.891000 | 127.0.0.1 | 17839 | 127.0.0.1
Appending to commitlog [MutationStage-6] | 2019-06-18 12:46:20.892000 |
127.0.0.1 | 18064 | 127.0.0.1
Adding to table1 memtable [MutationStage-6] | 2019-06-18 12:46:20.892000 |
127.0.0.1 | 18219 | 127.0.0.1
Sending READ_REPAIR_RSP
message to 127.0.0.1:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.892000 | 127.0.0.1 | 18494 | 127.0.0.1
READ_REPAIR_RSP message
received from 127.0.0.1:7000 [Messaging-EventLoop-3-1] | 2019-06-18
12:46:20.892000 | 127.0.0.1 | 18767 | 127.0.0.1
Processing
response from 127.0.0.1:7000 [RequestResponseStage-5] | 2019-06-18
12:46:20.892000 | 127.0.0.1 | 18937 | 127.0.0.1
Request complete | 2019-06-18 12:46:20.892148 |
127.0.0.1 | 19148 | 127.0.0.1
{noformat}
This in turn will probably delay the collection of data/tombstone as data will
keep spreading into new sstables which in turn result in more read-repairs...
Perhaps it would make more sense if the purgable tombstone was transferred on
read-repair, in which case it probably should have been included in the initial
response.
There may be more side effects that I'm overlooking. Would be great if someone
with more experience could share their view on this.
was (Author: eperott):
I had a look at this ticket [~laxmikant99].
I'm able to reproduce with your instructions on {{trunk}} as well. It's nothing
related to TTL, so a simple delete will give the same result.
>From what I can tell, this behavior comes from
>{{ReadCommand.withoutPurgeableTombstones()}}. Given the title of this ticket,
>I'm guessing you arrived at the same conclusion. :-)
That method has the following comment:
{code:java}
// Skip purgeable tombstones. We do this because it's safe to do (post-merge of
the memtable and sstable at least), it
// can save us some bandwith, and avoid making us throw a
TombstoneOverwhelmingException for purgeable tombstones (which
// are to some extend an artefact of compaction lagging behind and hence
counting them is somewhat unintuitive).
{code}
So, this seem very intentional. Reasons I can think of for this behavior are:
* The query result is consistent whether compaction happened or not - after
all, gc grace has expired
* And as mentioned in the comment; overwhelming amount of tombstones and
bandwidth
At the same time, it is annoying to get back resurrected data, when you *know*
the tombstone is still there.
But what worries me the most is that a read-repair will be triggered on every
read and spread the resurrected data.
{noformat}
cqlsh> select * from test.table1 where key = 'key2';
key | col | val
------+-----+-----
key2 | abc | xyz
(1 rows)
Tracing session: 4f1a9b90-91b6-11e9-a0ff-9d318f160025
activity
| timestamp |
source | source_elapsed | client
-------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------+-----------
Execute CQL3 query | 2019-06-18 12:46:20.873000 |
127.0.0.1 | 0 | 127.0.0.1
Parsing select * from test.table1
where key = 'key2'; [Native-Transport-Requests-1] | 2019-06-18 12:46:20.874000
| 127.0.0.1 | 358 | 127.0.0.1
Preparing statement [Native-Transport-Requests-1] | 2019-06-18 12:46:20.875000
| 127.0.0.1 | 1331 | 127.0.0.1
reading digest
from 127.0.0.3:7000 [Native-Transport-Requests-1] | 2019-06-18 12:46:20.875000
| 127.0.0.1 | 1922 | 127.0.0.1
Executing
single-partition query on table1 [ReadStage-2] | 2019-06-18 12:46:20.876000 |
127.0.0.1 | 2048 | 127.0.0.1
Acquiring sstable references [ReadStage-2] | 2019-06-18 12:46:20.876000 |
127.0.0.1 | 2166 | 127.0.0.1
Sending READ_REQ
message to 127.0.0.3:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.876000 | 127.0.0.1 | 2212 | 127.0.0.1
Key cache hit for sstable 2 [ReadStage-2] | 2019-06-18 12:46:20.876000 |
127.0.0.1 | 2376 | 127.0.0.1
Skipped 0/2 non-slice-intersecting
sstables, included 0 due to tombstones [ReadStage-2] | 2019-06-18
12:46:20.876000 | 127.0.0.1 | 2542 | 127.0.0.1
Merged
data from memtables and 1 sstables [ReadStage-2] | 2019-06-18 12:46:20.876000 |
127.0.0.1 | 2772 | 127.0.0.1
Read
0 live rows and 0 tombstone cells [ReadStage-2] | 2019-06-18 12:46:20.876001 |
127.0.0.1 | 2899 | 127.0.0.1
READ_REQ message
received from 127.0.0.1:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.877000 | 127.0.0.3 | 73 | 127.0.0.1
Executing
single-partition query on table1 [ReadStage-1] | 2019-06-18 12:46:20.878000 |
127.0.0.3 | 1148 | 127.0.0.1
Acquiring sstable references [ReadStage-1] | 2019-06-18 12:46:20.878000 |
127.0.0.3 | 1401 | 127.0.0.1
Skipped 0/1 non-slice-intersecting
sstables, included 0 due to tombstones [ReadStage-1] | 2019-06-18
12:46:20.878000 | 127.0.0.3 | 1637 | 127.0.0.1
Key cache hit for sstable 1 [ReadStage-1] | 2019-06-18 12:46:20.878000 |
127.0.0.3 | 1917 | 127.0.0.1
Merged
data from memtables and 1 sstables [ReadStage-1] | 2019-06-18 12:46:20.879000 |
127.0.0.3 | 2442 | 127.0.0.1
Read
1 live rows and 0 tombstone cells [ReadStage-1] | 2019-06-18 12:46:20.879000 |
127.0.0.3 | 2654 | 127.0.0.1
Enqueuing response to 127.0.0.1:7000 [ReadStage-1] | 2019-06-18 12:46:20.879000
| 127.0.0.3 | 2851 | 127.0.0.1
Sending READ_RSP
message to 127.0.0.1:7000 [Messaging-EventLoop-3-3] | 2019-06-18
12:46:20.880000 | 127.0.0.3 | 3276 | 127.0.0.1
READ_RSP message
received from 127.0.0.3:7000 [Messaging-EventLoop-3-2] | 2019-06-18
12:46:20.881000 | 127.0.0.1 | 7419 | 127.0.0.1
Processing
response from 127.0.0.3:7000 [RequestResponseStage-5] | 2019-06-18
12:46:20.882000 | 127.0.0.1 | 8800 | 127.0.0.1
Digest mismatch: Mismatch for key
DecoratedKey(8482869187405483569, 6b657932) [Native-Transport-Requests-1] |
2019-06-18 12:46:20.883000 | 127.0.0.1 | 9551 | 127.0.0.1
Enqueuing full data read to
Full(127.0.0.3:7000,(3074457345618258602,-9223372036854775808])
[Native-Transport-Requests-1] | 2019-06-18 12:46:20.883000 | 127.0.0.1 |
9771 | 127.0.0.1
Executing
single-partition query on table1 [ReadStage-6] | 2019-06-18 12:46:20.883000 |
127.0.0.1 | 9800 | 127.0.0.1
Acquiring sstable references [ReadStage-6] | 2019-06-18 12:46:20.883000 |
127.0.0.1 | 9880 | 127.0.0.1
Key cache hit for sstable 2 [ReadStage-6] | 2019-06-18 12:46:20.884000 |
127.0.0.1 | 10095 | 127.0.0.1
Sending READ_REQ
message to 127.0.0.3:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.884000 | 127.0.0.1 | 10121 | 127.0.0.1
Skipped 0/2 non-slice-intersecting
sstables, included 0 due to tombstones [ReadStage-6] | 2019-06-18
12:46:20.884000 | 127.0.0.1 | 10235 | 127.0.0.1
Merged
data from memtables and 1 sstables [ReadStage-6] | 2019-06-18 12:46:20.884000 |
127.0.0.1 | 10463 | 127.0.0.1
Read
0 live rows and 0 tombstone cells [ReadStage-6] | 2019-06-18 12:46:20.884000 |
127.0.0.1 | 10598 | 127.0.0.1
READ_REQ message
received from 127.0.0.1:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.885000 | 127.0.0.3 | 105 | 127.0.0.1
Executing
single-partition query on table1 [ReadStage-2] | 2019-06-18 12:46:20.885000 |
127.0.0.3 | 665 | 127.0.0.1
Acquiring sstable references [ReadStage-2] | 2019-06-18 12:46:20.886000 |
127.0.0.3 | 867 | 127.0.0.1
Skipped 0/1 non-slice-intersecting
sstables, included 0 due to tombstones [ReadStage-2] | 2019-06-18
12:46:20.886000 | 127.0.0.3 | 1067 | 127.0.0.1
Key cache hit for sstable 1 [ReadStage-2] | 2019-06-18 12:46:20.886000 |
127.0.0.3 | 1349 | 127.0.0.1
Merged
data from memtables and 1 sstables [ReadStage-2] | 2019-06-18 12:46:20.886000 |
127.0.0.3 | 1731 | 127.0.0.1
Read
1 live rows and 0 tombstone cells [ReadStage-2] | 2019-06-18 12:46:20.887000 |
127.0.0.3 | 1930 | 127.0.0.1
Enqueuing response to 127.0.0.1:7000 [ReadStage-2] | 2019-06-18 12:46:20.887000
| 127.0.0.3 | 2634 | 127.0.0.1
Sending READ_RSP
message to 127.0.0.1:7000 [Messaging-EventLoop-3-3] | 2019-06-18
12:46:20.889000 | 127.0.0.3 | 3510 | 127.0.0.1
READ_RSP message
received from 127.0.0.3:7000 [Messaging-EventLoop-3-2] | 2019-06-18
12:46:20.889000 | 127.0.0.1 | 15665 | 127.0.0.1
Processing
response from 127.0.0.3:7000 [RequestResponseStage-6] | 2019-06-18
12:46:20.890000 | 127.0.0.1 | 16028 | 127.0.0.1
Sending read-repair-mutation to
Full(127.0.0.1:7000,(3074457345618258602,-9223372036854775808])
[Native-Transport-Requests-1] | 2019-06-18 12:46:20.890000 | 127.0.0.1 |
16762 | 127.0.0.1
Sending READ_REPAIR_REQ
message to 127.0.0.1:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.891000 | 127.0.0.1 | 17413 | 127.0.0.1
READ_REPAIR_REQ message
received from 127.0.0.1:7000 [Messaging-EventLoop-3-1] | 2019-06-18
12:46:20.891000 | 127.0.0.1 | 17839 | 127.0.0.1
Appending to commitlog [MutationStage-6] | 2019-06-18 12:46:20.892000 |
127.0.0.1 | 18064 | 127.0.0.1
Adding to table1 memtable [MutationStage-6] | 2019-06-18 12:46:20.892000 |
127.0.0.1 | 18219 | 127.0.0.1
Sending READ_REPAIR_RSP
message to 127.0.0.1:7000 [Messaging-EventLoop-3-4] | 2019-06-18
12:46:20.892000 | 127.0.0.1 | 18494 | 127.0.0.1
READ_REPAIR_RSP message
received from 127.0.0.1:7000 [Messaging-EventLoop-3-1] | 2019-06-18
12:46:20.892000 | 127.0.0.1 | 18767 | 127.0.0.1
Processing
response from 127.0.0.1:7000 [RequestResponseStage-5] | 2019-06-18
12:46:20.892000 | 127.0.0.1 | 18937 | 127.0.0.1
Request complete | 2019-06-18 12:46:20.892148 |
127.0.0.1 | 19148 | 127.0.0.1
{noformat}
This in turn will probably delay the collection of data/tombstone as data will
keep spreading into new sstables which in turn result in more read-repairs...
Perhaps it would make more sense if the purgable tombstone was transferred on
repair, in which case it probably should have been included in the initial
response.
There may be more side effects that I'm overlooking. Would be great if someone
with more experience could share their view on this.
> Purgable tombstones are ignored by read query
> ---------------------------------------------
>
> Key: CASSANDRA-15159
> URL: https://issues.apache.org/jira/browse/CASSANDRA-15159
> Project: Cassandra
> Issue Type: Bug
> Components: Legacy/Local Write-Read Paths
> Reporter: Laxmikant Upadhyay
> Priority: Normal
> Attachments: steps2reproduce.txt, trace.txt
>
>
> In 3 node Cassandra cluster, one node has old mutation and two nodes have
> evict-able (crossed gc grace period) tombstone produced by TTL. A read query
> with local quorum return the old mutation as result when one request goes to
> the node having old mutation. However expected result should be empty.
> Attached the steps to reproduce and trace of read query.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
