Taras Bobrovytsky created KUDU-1753:
---------------------------------------
Summary: Impala query fails: Unable to advance iterator: Illegal
state: Tablet is not running
Key: KUDU-1753
URL: https://issues.apache.org/jira/browse/KUDU-1753
Project: Kudu
Issue Type: Bug
Reporter: Taras Bobrovytsky
We were running queries (with mem limits set in Impala) like the following one
after another (only one query was executing at the same time at any point).
{code}
upsert into table lineitem select * from lineitem_original where l_orderkey %
11 = 0
{code}
and
{code}
delete from lineitem where l_orderkey % 11 = 0
{code}
One of the queries failed with the following error:
{code}
Unable to advance iterator: Illegal state: Tablet is not running
{code}
from kudu-tserver.INFO:
{code}
I1122 17:54:10.659071 7021 tablet.cc:1160] T 5e7e168f1919488ba902f87b32be6065
Flush: entering phase 2 (starting to duplicate updates in new rowsets)
I1122 17:54:10.740268 16858 log.cc:513] Max segment size reached. Starting new
segment allocation.
I1122 17:54:10.772285 7086 raft_consensus.cc:1192] Rejecting consensus
request: Soft memory limit exceeded (at 82.22% of capacity) [suppressed 5
similar messages]
I1122 17:54:11.809483 7094 raft_consensus.cc:1192] Rejecting consensus
request: Soft memory limit exceeded (at 84.45% of capacity) [suppressed 5
similar messages]
I1122 17:54:12.095155 16858 log.cc:398] Rolled over to a new segment:
/data1/kudu/tserver/ wals/5e7e168f1919488ba902f87b32be6065/wal-000000082
I1122 17:54:13.143566 7088 raft_consensus.cc:1192] Rejecting consensus
request: Soft memory limit exceeded (at 82.84% of capacity) [suppressed 6
similar messages]
I1122 17:54:13.633990 7021 tablet.cc:1215] T 5e7e168f1919488ba902f87b32be6065
Flush Phase 2: carrying over any updates which arrived during Phase 1
I1122 17:54:13.634016 7021 tablet.cc:1217] T 5e7e168f1919488ba902f87b32be6065
Phase 2 snapshot: MvccSnapshot[committed={T|T < 1298537 or (T in
{1298538,1298537})}]
I1122 17:54:14.154855 7094 raft_consensus.cc:1192] Rejecting consensus
request: Soft memory limit exceeded (at 83.44% of capacity) [suppressed 5
similar messages]
I1122 17:54:15.068207 7095 tablet_copy_client.cc:273] T
44cf60f4c34841899e3a32852365b112 P 8e6f4cf16c544ef3b7913f6cda1bfe54: Tablet
Copy client: Tablet Copy complete. Replacing tablet superblock.
I1122 17:54:15.071156 9784 ts_tablet_manager.cc:633] T
44cf60f4c34841899e3a32852365b112 P 8e6f4cf16c544ef3b7913f6cda1bfe54:
Bootstrapping tablet
I1122 17:54:15.071321 9784 tablet_bootstrap.cc:380] T
44cf60f4c34841899e3a32852365b112 P 8e6f4cf16c544ef3b7913f6cda1bfe54: Bootstrap
starting.
I1122 17:54:15.081435 9784 tablet_bootstrap.cc:542] T
44cf60f4c34841899e3a32852365b112 P 8e6f4cf16c544ef3b7913f6cda1bfe54: Time
spent opening tablet: real 0.010s user 0.006s sys 0.004s
.....
.....
I1122 17:54:15.086483 9784 tablet_bootstrap.cc:606] T
44cf60f4c34841899e3a32852365b112 P 8e6f4cf16c544ef3b7913f6cda1bfe54: Moving
log directory /data1/kudu/tserver/wals/
44cf60f4c34841899e3a32852365b112 to recovery directory
/data1/kudu/tserver/wals/ 44cf60f4c34841899e3a32852365b112.recovery
in preparation for log replay
I1122 17:54:15.087378 9784 log_util.cc:312] Log segment
/data1/kudu/tserver/wals/
44cf60f4c34841899e3a32852365b112.recovery/wal-000000087 has no footer. This
segment was likely being written when the server previously shut down.
I1122 17:54:15.087385 9784 log_reader.cc:151] Log segment
/data1/kudu/tserver/wals/
44cf60f4c34841899e3a32852365b112.recovery/wal-000000087 was likely left
in-progress after a previous crash. Will try to rebuild footer by scanning
data.
W1122 17:54:15.119765 7095 rpcz_store.cc:234] Call
kudu.consensus.ConsensusService. StartTabletCopy from 172.28.195.11:33598
(request call id 247782) took 56098ms (client timeout 1000).
W1122 17:54:15.119963 7095 rpcz_store.cc:238] Trace:
1122 17:53:19.020889 (+ 0us) service_pool.cc:143] Inserting onto call queue
1122 17:53:19.020911 (+ 22us) service_pool.cc:202] Handling call
1122 17:53:19.022175 (+ 1264us) ts_tablet_manager.cc:418] T
44cf60f4c34841899e3a32852365b112 P 8e6f4cf16c544ef3b7913f6cda1bfe54:
Initiating tablet copy from Peer bb2ce221ba374ff4bff7ff5c56946f45
(kudu-stress-8.vpc.cloudera.com:7050)
1122 17:53:19.064954 (+ 42779us) tablet_metadata.cc:461] Metadata flushed
1122 17:53:19.065703 (+ 749us) tablet_metadata.cc:461] Metadata flushed
1122 17:54:15.071167 (+56005464us) ts_tablet_manager.cc:634] Bootstrapping
tablet
1122 17:54:15.119736 (+ 48569us) inbound_call.cc:130] Queueing success response
Metrics:
{"fdatasync":967,"fdatasync_us":32775470,"spinlock_wait_cycles":4352,"tablet-
bootstrap.queue_time_us":248,"tcmalloc_contention_cycles":527821056,"thread_start_us":229,
"threads_started":1}
W1122 17:54:15.251955 7021 tablet_peer.cc:656] Time spent Committing
in-flights took a long time.: real 1.530s user 0.000s sys 0.000s
{code}
from impalad.INFO:
{code}
8e6f4cf16c544ef3b7913f6cda1bfe54 (kudu-stress-6.vpc.cloudera.com:7050) of
tablet impala:: tpch_10_kudu.lineitem: failed: Illegal state: Tablet is not
running
I1122 17:53:23.382364 9488 status.cc:114] Unable to advance iterator: Illegal
state: Tablet is not running
@ 0x11c14e3 impala::Status::Status()
@ 0x17eace2 impala::KuduScanner::GetNextScannerBatch()
@ 0x17e93fa impala::KuduScanner::GetNext()
@ 0x1785893 impala::KuduScanNode::ProcessScanToken()
@ 0x1785bb2 impala::KuduScanNode::RunScannerThread()
@ 0x1787ad2 boost::_mfi::mf2<>::operator()()
@ 0x1787998 boost::_bi::list3<>::operator()<>()
@ 0x1787519 boost::_bi::bind_t<>::operator()()
@ 0x178734f
boost::detail::function::void_function_obj_invoker0<>::invoke()
@ 0x133ce98 boost::function0<>::operator()()
@ 0x15e8921 impala::Thread::SuperviseThread()
@ 0x15ef8fa boost::_bi::list4<>::operator()<>()
@ 0x15ef83d boost::_bi::bind_t<>::operator()()
@ 0x15ef798 boost::detail::thread_data<>::run()
@ 0x1a3c34a thread_proxy
@ 0x38382079d1 (unknown)
@ 0x3837ee88fd (unknown)
I1122 17:53:23.392840 9459 runtime-state.cc:208] Error from query
6e47c2d5c47683e8: 5c1a097d00000000: Unable to advance iterator: Illegal
state: Tablet is not running
I1122 17:53:23.451575 9459 fragment-mgr.cc:99] PlanFragment completed.
instance_id=6e47c2d5c47683e8:5c1a097d00000000
{code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
