You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@kudu.apache.org by "Andrew Wong (JIRA)" <ji...@apache.org> on 2018/03/06 02:05:00 UTC

[jira] [Commented] (KUDU-1678) Race during abort of pending operations during raft shutdown

    [ https://issues.apache.org/jira/browse/KUDU-1678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16387148#comment-16387148 ] 

Andrew Wong commented on KUDU-1678:
-----------------------------------

Still exists as of Kudu 1.6. Similar logs:

{{I0306 00:17:15.490319 307 raft_consensus.cc:2012] T e1d15822abc748239abee3de00d23450 P 01076373237e457d9d20570e9915cc7b [term 1 FOLLOWER]: Raft consensus shutting down. I0306 00:17:15.490316 306 tablet_service.cc:755] Processing CreateTablet for tablet c926cb59d3d24e8596a8554365f4e3ea (table=test-table [id=59728a33a7134d979cc23bea31f8e515]), partition=RANGE (c531) PARTITION 2080374753 <= VALUES < 2147483616 I0306 00:17:15.490334 307 pending_rounds.cc:63] T e1d15822abc748239abee3de00d23450 P 01076373237e457d9d20570e9915cc7b: Trying to abort 2 pending transactions. I0306 00:17:15.490439 307 pending_rounds.cc:68] T e1d15822abc748239abee3de00d23450 P 01076373237e457d9d20570e9915cc7b: Aborting transaction as it isn't in flight: id \{ term: 1 index: 16 } timestamp: 6227130103078129664 op_type: ALTER_SCHEMA_OP alter_schema_request \{ tablet_id: "e1d15822abc748239abee3de00d23450" schema { columns { id: 0 name: "c531" type: INT32 is_key: true is_nullable: false encoding: AUTO_ENCODING compression: DEFAULT_COMPRESSION cfile_block_size: 0 } columns \{ id: 4 name: "c109" type: INT32 is_key: false is_nullable: false read_default_value: "\217\177Z\n" write_default_value: "wO\253^" encoding: AUTO_ENCODING compression: DEFAULT_COMPRESSION cfile_block_size: 0 } columns \{ id: 5 name: "c609" type: INT32 is_key: false is_nullable: true write_default_value: "\203\323\304d" encoding: RLE compression: DEFAULT_COMPRESSION cfile_block_size: 0 } columns \{ id: 7 name: "c75" type: INT32 is_key: false is_nullable: false read_default_value: "o^\n%" write_default_value: "o^\n%" encoding: AUTO_ENCODING compression: DEFAULT_COMPRESSION cfile_block_size: 0 } columns \{ id: 9 name: "c636" type: INT32 is_key: false is_nullable: true encoding: AUTO_ENCODING compression: DEFAULT_COMPRESSION cfile_block_size: 0 } } schema_version: 19 new_table_name: "test-table" dest_uuid: "37d511d1e6d2420bb38eff3196611830" } I0306 00:17:15.490530 307 pending_rounds.cc:68] T e1d15822abc748239abee3de00d23450 P 01076373237e457d9d20570e9915cc7b: Aborting transaction as it isn't in flight: id \{ term: 1 index: 17 } timestamp: 6227130103109320704 op_type: WRITE_OP write_request \{ tablet_id: "e1d15822abc748239abee3de00d23450" schema { columns { name: "c531" type: INT32 is_key: true is_nullable: false } columns \{ name: "c109" type: INT32 is_key: false is_nullable: false read_default_value: "\217\177Z\n" write_default_value: "wO\253^" } columns \{ name: "c609" type: INT32 is_key: false is_nullable: true write_default_value: "\203\323\304d" } columns \{ name: "c75" type: INT32 is_key: false is_nullable: false read_default_value: "o^\n%" write_default_value: "o^\n%" } columns \{ name: "c636" type: INT32 is_key: false is_nullable: true } } row_operations \{ rows: "\001\037\000\216\306\235a\266\200Z\031\266\200Z\031\266\200Z\031\266\200Z\031" } external_consistency_mode: CLIENT_PROPAGATED propagated_timestamp: 6227130103069212672 } request_id \{ client_id: "726a6c0cf6844fa8a88312ca5d0569ce" seq_no: 681 first_incomplete_seq_no: 681 attempt_no: 0 } I0306 00:17:15.490552 307 raft_consensus.cc:2039] T e1d15822abc748239abee3de00d23450 P 01076373237e457d9d20570e9915cc7b [term 1 FOLLOWER]: Raft consensus is shut down! F0306 00:17:15.490658 377 transaction_driver.cc:383] T e1d15822abc748239abee3de00d23450 P 01076373237e457d9d20570e9915cc7b S RF-NP Ts 6227130103109320704: Cannot cancel transactions that have already replicated: Aborted: Transaction aborted transaction:RF-NP WriteTransaction [type=REPLICA, start_time=2018-03-06 00:17:15, state=WriteTransactionState 0x1b96700 [op_id=(term: 1 index: 17), ts=6227130103109320704, rows=[]]]}}

> Race during abort of pending operations during raft shutdown
> ------------------------------------------------------------
>
>                 Key: KUDU-1678
>                 URL: https://issues.apache.org/jira/browse/KUDU-1678
>             Project: Kudu
>          Issue Type: Bug
>          Components: consensus
>    Affects Versions: 1.0.0, 1.6.0
>            Reporter: Todd Lipcon
>            Priority: Major
>
> I'm seeing the following race occasionally in alter_table-randomized-test:
> - a follower tablet is shutting down while some operations are pending. The first operation is an ALTER_TABLE, and the second is a WRITE which depends on the ALTER (i.e includes the new column)
> - we cancel the ALTER successfully, and then the thread gets de-scheduled
> - the PrepareTask for the WRITE runs before we're able to cancel it. It then fails to prepare because the alter it depends on has not completed
> It seems like we should probably cancel the pending operations in reverse order.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)