[
https://issues.apache.org/jira/browse/CASSANDRA-21794?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18135884#comment-18135884
]
Deepak Kumar Jothimanickam commented on CASSANDRA-21794:
--------------------------------------------------------
[~mck] Good day, Can you assign the ticket to me, I want to work on this
> Commit log replay after an interrupted DROP TABLE discards whole mutations
> that also touched the dropped table (5.0: acknowledged rows of other tables
> in the same logged batch are lost; trunk: the node does not start)
> -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: CASSANDRA-21794
> URL: https://issues.apache.org/jira/browse/CASSANDRA-21794
> Project: Apache Cassandra
> Issue Type: Bug
> Components: Local/Commit Log, Local/Startup and Shutdown
> Reporter: Ke Han
> Priority: Normal
>
>
> Affects Version/s: 5.0.9, 5.0.x, 7.0 (trunk); by code inspection also 6.0
> (same CoordinatorBehindException path as trunk) and 4.1.x (same per-mutation
> skip as 5.0)
>
> Environment: Single node, Linux 5.15 x86_64, ext4, OpenJDK 11,
> commitlog_sync: batch, disk_failure_policy: stop (default). Built from
> source: trunk 95b178a1 (2026-10-17) and cassandra-5.0 dd48703a (2026-10-17);
> first seen on the 5.0.9 docker image.
>
> Description:
>
> *What happens*
>
> A logged batch that writes the same partition key to two tables of one
> keyspace is stored as one Mutation per partition key, carrying a
> PartitionUpdate for each table. DROP TABLE a calls
> ColumnFamilyStore.onTableDropped -> CommitLog.forceRecycleAllSegments, which
> flushes every table with data in the current segments, so normally the replay
> never needs those mutations again. If that forced flush does not complete (an
> I/O error with disk_failure_policy: stop, a crash, a power loss) while the
> drop itself has already been persisted, the rows of the other table b exist
> only in the commit log, and the replay handles the mixed mutations as a whole:
>
> - cassandra-5.0: PartitionUpdate deserialization throws UnknownTableException
> for a's update, CommitLogReader.readMutation catches it and skips the entire
> mutation ("Skipped N mutations from unknown (probably removed) CF"), so the
> acknowledged b rows in it are lost silently.
> - trunk: the deserialization throws CoordinatorBehindException instead
> (PartitionUpdate.serializer, lines 801-814: the local epoch is after the
> mutation's epoch), which readMutation does not treat as an unknown table;
> start-up stops with "Exiting due to error while processing commit log during
> initialization". This happens for any leftover mutation of the dropped table,
> not only mixed ones. With -Dcassandra.commitlog.ignorereplayerrors=true the
> node starts and the mixed mutations are dropped, losing the b rows as on 5.0.
>
> *Reproduce* (cqlsh and nodetool against a single node with commitlog_sync:
> batch; strace >= 4.16, run as root or with ptrace permission)
>
> {code:bash}
> bin/cqlsh -e "
> CREATE KEYSPACE ks WITH replication = \{'class': 'SimpleStrategy',
> 'replication_factor': 1};
> CREATE TABLE ks.a (id int PRIMARY KEY, v text);
> CREATE TABLE ks.b (id int PRIMARY KEY, v text);
> BEGIN BATCH
> INSERT INTO ks.a (id, v) VALUES (1, 'a1'); INSERT INTO ks.a (id, v) VALUES
> (2, 'a2'); INSERT INTO ks.a (id, v) VALUES (3, 'a3');
> INSERT INTO ks.a (id, v) VALUES (4, 'a4'); INSERT INTO ks.a (id, v) VALUES
> (5, 'a5');
> INSERT INTO ks.b (id, v) VALUES (1, 'b1'); INSERT INTO ks.b (id, v) VALUES
> (2, 'b2'); INSERT INTO ks.b (id, v) VALUES (3, 'b3');
> INSERT INTO ks.b (id, v) VALUES (4, 'b4'); INSERT INTO ks.b (id, v) VALUES
> (5, 'b5'); INSERT INTO ks.b (id, v) VALUES (6, 'b6');
> INSERT INTO ks.b (id, v) VALUES (7, 'b7'); INSERT INTO ks.b (id, v) VALUES
> (8, 'b8'); INSERT INTO ks.b (id, v) VALUES (9, 'b9');
> INSERT INTO ks.b (id, v) VALUES (10, 'b10');
> APPLY BATCH;
> SELECT count(*) FROM ks.b;" # 10
>
> # one EIO on the first fsync of b's table directory (the forced flush of b
> creates its flush txn log there);
> # use signal=KILL instead of error=EIO for a crash at the same point
> BDIR=$(ls -d /var/lib/cassandra/data/ks/b-*)
> strace -f -o /tmp/strace.log -e trace=fsync -e inject=fsync:error=EIO:when=1
> -P $BDIR -p $(pgrep -f CassandraDaemon) &
> sleep 5
> bin/cqlsh -e "DROP TABLE ks.a;" # FSWriteError, "Stopping transports as
> disk_failure_policy is stop"
> kill %1; kill -9 $(pgrep -f CassandraDaemon)
> bin/cassandra # restart
> bin/cqlsh -e "SELECT id, v FROM ks.b;"
> {code}
>
> *Actual*
>
> cassandra-5.0 dd48703a (same with signal=KILL instead of EIO):
>
> {noformat}
> WARN [main] CommitLogReplayer.java:247 - Skipped 5 mutations from unknown
> (probably removed) CF with id c76c6560-cb2e-11f1-af99-b54fecb308d4
> INFO [main] CommitLog.java:210 - Log replay complete, 13 replayed mutations
> in 526 ms
>
> id | v
> ----+-----
> 10 | b10
> 8 | b8
> 7 | b7
> 6 | b6
> 9 | b9
> (5 rows)
> {noformat}
>
> Rows 1..5 of b, acknowledged by the batch long before the DROP, are gone.
> Control: the same script with a's inserts using ids 101..105 (no shared
> partition keys) also skips 5 mutations (a's own) and returns all 10 rows of b.
>
> trunk 95b178a1 (EIO or SIGKILL at the same point; also with the ids 101..105
> control):
>
> {noformat}
> ERROR [main] DefaultDiskErrorsHandler.java:177 - Exiting due to error while
> processing commit log during initialization.
> org.apache.cassandra.db.commitlog.CommitLogReadHandler$CommitLogReadException:
> Unexpected error deserializing mutation; saved to
> /tmp/mutation4107001581964003181dat. This may be caused by replaying a
> mutation against a table with the same name but incompatible schema.
> Exception follows:
> org.apache.cassandra.exceptions.CoordinatorBehindException: Couldn't find
> table with id tid:4. If a table was just created, this is likely due to the
> schema not being fully propagated. Please wait for schema agreement on table
> creation.
> at
> org.apache.cassandra.db.commitlog.CommitLogReader.readMutation(CommitLogReader.java:472)
> at
> org.apache.cassandra.db.commitlog.CommitLogReader.readSection(CommitLogReader.java:405)
> at
> org.apache.cassandra.db.commitlog.CommitLogReader.readCommitLogSegment(CommitLogReader.java:251)
> ...
> at
> org.apache.cassandra.service.CassandraDaemon.setup(CassandraDaemon.java:362)
> {noformat}
>
> The node does not start. Restarted with
> -Dcassandra.commitlog.ignorereplayerrors=true it starts ("Ignoring commit log
> replay error" for each mixed mutation) and SELECT returns only ids 6..10.
>
> *Expected*
>
> All 10 rows of b after the restart, and a node that starts. Mutations for a
> table that was dropped after they were written are expected garbage; the
> replay should skip only the PartitionUpdate of the dropped table and apply
> the rest of the mutation (on trunk, a mutation older than the drop should be
> treated like an unknown table during local replay, not as a coordinator that
> is behind).
>
> *Code (trunk 95b178a1)*
>
> - src/java/org/apache/cassandra/db/commitlog/CommitLogReader.java:446-458
> catches UnknownTableException around Mutation.serializer.deserialize and
> returns, dropping the whole mutation; any other exception goes to the
> "Unexpected error deserializing mutation" path (460-480), which is fatal
> unless ignorereplayerrors is set.
> - src/java/org/apache/cassandra/db/Mutation.java:598-612 deserializes the
> PartitionUpdates one by one; the first unknown table aborts the whole
> mutation.
> - src/java/org/apache/cassandra/db/partitions/PartitionUpdate.java:801-814
> turns UnknownTableException into CoordinatorBehindException when the local
> epoch is after the mutation's epoch, which is what happens when replaying a
> mutation written before the DROP (observed in every run).
> - src/java/org/apache/cassandra/db/ColumnFamilyStore.java:3414
> (onTableDropped) is where the forced flush happens; nothing on start-up
> accounts for it not having completed.
> - cassandra-5.0 dd48703a: CommitLogReader.java:438 (catch
> UnknownTableException), CommitLogReplayer.java:247 (the "Skipped ... probably
> removed" warning).
>
> *Related*
>
> - CASSANDRA-1353 (fixed 2010): "commit log recovery is broken when the CL
> contains mutations to CFs that have been dropped". The skipping that exists
> today works per mutation, not per table.
> - CASSANDRA-9179 (fixed): replay skips mutations of a dropped-and-recreated
> table; by design for that table, it does not cover other tables in the same
> mutation.
> - CASSANDRA-16878 (Review In Progress): a race in commit log replay can cause
> rejected mutations; different cause.
>
--
This message was sent by Atlassian Jira
(v10.3.26#10030026)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
