Skip to content
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@
import org.apache.kafka.streams.errors.LockException;
import org.apache.kafka.streams.errors.ProcessorStateException;
import org.apache.kafka.streams.errors.StreamsException;
import org.apache.kafka.streams.errors.TaskMigratedException;
import org.apache.kafka.streams.processor.ProcessorContext;
import org.apache.kafka.streams.processor.StateStore;
import org.apache.kafka.streams.processor.TaskId;
Expand Down Expand Up @@ -172,7 +173,13 @@ public String toString(final String indent) {
* Flush all state stores owned by this task
*/
void flushState() {
stateMgr.flush();
try {
stateMgr.flush();
} catch (final ProcessorStateException e) {

@mjsax mjsax Nov 27, 2019

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do we catch it at this level? Seems we should move it into ProcessorStateManger#flush() ?

Also note, that ProcessorStateManger#flush() only throws the first exception what might not be what we want to detect this case correctly.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, I wasn't sure... This way is a bit roundabout. On the other hand, right now, TaskMigratedException is only thrown by the tasks themselves or the threads that run them. It didn't seem within the responsibility of the ProcessorStateManager to reason about what specific exceptions imply about the state of the task.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fair enough. It's not ideal that we get a ProcessorStateException and have to call getCause(), but well, it is what it is.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reading the code here: we throw TaskMigratedException in both StreamTask as well as StreamThread. For the first case, the exception is thrown all the way to the caller of TaskManager and rethrown (hence in the level of StreamThread); the latter case is only a few exceptional situations where the tasks are closed due to underlying exceptions.

I feel throwing the exception in the level of StreamTask is fine, but we did too many capture / rethrow in different layers on top of it, which could be cleaned up in a separate tech-debt PR.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I very much agree. It's quite difficult to trace which exceptions would exist in different parts of the stack, and it would be nice to clean it up in the future.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@vvcephei while working on the cleanup PR I realized that when we call store.flush internally we should not blindly wrap all thrown exceptions from stores, but only those not StreamsException -- i.e. if the error is not from the store itself (like an IOException) but from the streams library, then just throw it out directly.

Will do this small refactoring in my PR.

if (e.getCause() instanceof RecoverableClientException) {
throw new TaskMigratedException(this, e);
}
}
}

/**
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -148,7 +148,7 @@ private RuntimeException suspendRunningTasks(final Set<TaskId> runningTasksToSus
// swallow and move on since we are rebalancing
log.info("Failed to suspend stream task {} since it got migrated to another thread already. " +
"Closing it as zombie and moving on.", id);
firstException.compareAndSet(null, closeZombieTask(task));
tryCloseZombieTask(task);

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why this change?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sorry, I should have documented why I made another round of changes. When I tested the code prior to this change, we still had threads dying with a different exception...

[2019-11-27 11:28:59,965] ERROR [stream-soak-test-92665673-8057-4ee8-8619-bffd3670817d-StreamThread-2] stream-thread [stream-soak-test-92665673-8057-4ee8-8619-bffd3670817d-StreamThread-2] Encountered the following unexpected Kafka exception during processing, this usually indicate Streams internal errors: (org.apache.kafka.streams.processor.internals.StreamThread)
org.apache.kafka.streams.errors.StreamsException: stream-thread [stream-soak-test-92665673-8057-4ee8-8619-bffd3670817d-StreamThread-2] Failed to rebalance.
	at org.apache.kafka.streams.processor.internals.StreamThread.pollRequests(StreamThread.java:852)
	at org.apache.kafka.streams.processor.internals.StreamThread.runOnce(StreamThread.java:739)
	at org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:698)
	at org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:671)
 Caused by: org.apache.kafka.streams.errors.StreamsException: stream-thread [stream-soak-test-92665673-8057-4ee8-8619-bffd3670817d-StreamThread-2] failed to suspend stream tasks
	at org.apache.kafka.streams.processor.internals.TaskManager.suspendActiveTasksAndState(TaskManager.java:253)
	at org.apache.kafka.streams.processor.internals.StreamsRebalanceListener.onPartitionsRevoked(StreamsRebalanceListener.java:116)
	at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.invokePartitionsRevoked(ConsumerCoordinator.java:291)
	at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.onLeavePrepare(ConsumerCoordinator.java:707)
	at org.apache.kafka.clients.consumer.KafkaConsumer.unsubscribe(KafkaConsumer.java:1073)
	at org.apache.kafka.streams.processor.internals.StreamThread.enforceRebalance(StreamThread.java:716)
	at org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:710)
	... 1 more
 Caused by: org.apache.kafka.streams.errors.TaskMigratedException: Client request for task 1_0 has been fenced due to a rebalance
	at org.apache.kafka.streams.processor.internals.AbstractTask.flushState(AbstractTask.java:182)
	at org.apache.kafka.streams.processor.internals.StreamTask.suspend(StreamTask.java:679)
	at org.apache.kafka.streams.processor.internals.StreamTask.close(StreamTask.java:787)
	at org.apache.kafka.streams.processor.internals.AssignedTasks.closeZombieTask(AssignedTasks.java:102)
	at org.apache.kafka.streams.processor.internals.AssignedStreamsTasks.suspendRunningTasks(AssignedStreamsTasks.java:151)
	at org.apache.kafka.streams.processor.internals.AssignedStreamsTasks.suspendOrCloseTasks(AssignedStreamsTasks.java:128)
	at org.apache.kafka.streams.processor.internals.TaskManager.suspendActiveTasksAndState(TaskManager.java:246)
	... 7 more
 Caused by: org.apache.kafka.streams.errors.ProcessorStateException: task [1_0] Failed to flush state store logData10MinuteFinalCount-store
	at org.apache.kafka.streams.processor.internals.ProcessorStateManager.flush(ProcessorStateManager.java:279)
	at org.apache.kafka.streams.processor.internals.AbstractTask.flushState(AbstractTask.java:178)
	... 13 more
 Caused by: org.apache.kafka.common.errors.ProducerFencedException: task [1_0] Abort sending since producer got fenced with a previous record (timestamp 1574853975939) to topic windowed-node-counts due to org.apache.kafka.common.errors.ProducerFencedException: Producer attempted an operation with an old epoch. Either there is a newer producer with the same transactionalId, or the producer's transaction has been expired by the broker.
 [2019-11-27 11:28:59,966] INFO [stream-soak-test-92665673-8057-4ee8-8619-bffd3670817d-StreamThread-2] stream-thread [stream-soak-test-92665673-8057-4ee8-8619-bffd3670817d-StreamThread-2] State transition from PARTITIONS_REVOKED to PENDING_SHUTDOWN (org.apache.kafka.streams.processor.internals.StreamThread)
 [2019-11-27 11:28:59,969] INFO [stream-soak-test-92665673-8057-4ee8-8619-bffd3670817d-StreamThread-2] stream-thread [stream-soak-test-92665673-8057-4ee8-8619-bffd3670817d-StreamThread-2] State transition from PENDING_SHUTDOWN to DEAD (org.apache.kafka.streams.processor.internals.StreamThread)

It turns out that firstException actually winds up being a fatal exception. The usages of this method express an intent to ignore any exceptions, so that's what this change does. I also made sure that any relevant state tracking still happens correctly. I.e., even if we can't cleanly close this zombie task, it's still removed from the "previous running" collection, etc.

prevActiveTasks.remove(id);
} catch (final RuntimeException e) {
log.error("Suspending stream task {} failed due to the following error:", id, e);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -97,14 +97,12 @@ Collection<T> running() {
return running.values();
}

RuntimeException closeZombieTask(final T task) {
void tryCloseZombieTask(final T task) {
try {
task.close(false, true);
} catch (final RuntimeException e) {
log.warn("Failed to close zombie {} {} due to {}; ignore and proceed.", taskTypeName, task.id(), e.toString());
return e;
}
return null;
}

boolean hasRunningTasks() {
Expand Down Expand Up @@ -259,7 +257,7 @@ void shutdown(final boolean clean) {
} catch (final TaskMigratedException e) {
log.info("Failed to close {} {} since it got migrated to another thread already. " +
"Closing it as zombie and move on.", taskTypeName, task.id());
firstException.compareAndSet(null, closeZombieTask(task));
tryCloseZombieTask(task);
} catch (final RuntimeException t) {
log.error("Failed while closing {} {} due to the following error:",
task.getClass().getSimpleName(),
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -101,6 +101,9 @@ public void update(final ConsumerRecord<byte[], byte[]> record) {
}

public void flushState() {
// this could theoretically throw a ProcessorStateException caused by a ProducerFencedException,
// but in practice this shouldn't happen for global state update tasks, since the stores are not
// logged and there are no downstream operators after global stores.
stateMgr.flush();
stateMgr.checkpoint(offsets);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@
import org.apache.kafka.common.errors.SecurityDisabledException;
import org.apache.kafka.common.errors.SerializationException;
import org.apache.kafka.common.errors.TimeoutException;
import org.apache.kafka.common.errors.UnknownProducerIdException;
import org.apache.kafka.common.errors.UnknownServerException;
import org.apache.kafka.common.metrics.Sensor;
import org.apache.kafka.common.header.Headers;
Expand Down Expand Up @@ -179,21 +180,22 @@ public void onCompletion(final RecordMetadata metadata,
offsets.put(tp, metadata.offset());
} else {
if (sendException == null) {
if (exception instanceof ProducerFencedException) {
if (exception instanceof ProducerFencedException || exception instanceof UnknownProducerIdException) {
log.warn(LOG_MESSAGE, topic, exception.getMessage(), exception);

// KAFKA-7510 put message key and value in TRACE level log so we don't leak data by default
log.trace("Failed message: (key {} value {} timestamp {}) topic=[{}] partition=[{}]", key, value, timestamp, topic, partition);

sendException = new ProducerFencedException(
sendException = new RecoverableClientException(
String.format(
EXCEPTION_MESSAGE,
logPrefix,
"producer got fenced",
timestamp,
topic,
exception.toString()
)
),
exception

@guozhangwang guozhangwang Dec 3, 2019

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Minor for log4j succinctness: from looking at the production log files, I think keeping the whole stack trace of the original exception is not necessary since we know exactly it would be thrown from

	at org.apache.kafka.streams.processor.internals.RecordCollectorImpl$1.onCompletion(RecordCollectorImpl.java:202)
	at org.apache.kafka.clients.producer.KafkaProducer$InterceptorCallback.onCompletion(KafkaProducer.java:1318)
	at org.apache.kafka.clients.producer.internals.ProducerBatch.completeFutureAndFireCallbacks(ProducerBatch.java:230)
	at org.apache.kafka.clients.producer.internals.ProducerBatch.done(ProducerBatch.java:196)
	at org.apache.kafka.clients.producer.internals.Sender.failBatch(Sender.java:730)
	at org.apache.kafka.clients.producer.internals.Sender.failBatch(Sender.java:716)
	at org.apache.kafka.clients.producer.internals.Sender.completeBatch(Sender.java:674)
	at org.apache.kafka.clients.producer.internals.Sender.handleProduceResponse(Sender.java:596)
	at org.apache.kafka.clients.producer.internals.Sender.access$100(Sender.java:74)
	at org.apache.kafka.clients.producer.internals.Sender$1.onComplete(Sender.java:798)
	at org.apache.kafka.clients.ClientResponse.onComplete(ClientResponse.java:109)
	at org.apache.kafka.clients.NetworkClient.completeResponses(NetworkClient.java:561)
	at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:553)
	at org.apache.kafka.clients.producer.internals.Sender.runOnce(Sender.java:335)
	at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:244)

So may be we can just log the original exception name; similarly in recordSendError we can just keep the original exception's name but not the stack trace since we know exactly it is from the same Sender.failBatch trace.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In practice, the exceptions we're recording here are ApiExceptions, so they don't contain stack traces anyway.

I actually added the exception to the "cause" on purpose, because it was a pain trying to understand the stack traces we were previously logging while I was digging in to this issue. Even if the log messages are more verbose, they're easy to follow. I.e., it's a nice chain of "E1 caused by E2 caused by E3", instead of "E1-with-E3-in-the-message caused by E2".

I actually wanted to take it farther by removing the exception.toString from the message, but I didn't want to be too bold in this patch, and cause even more controversy.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

SG!

);
} else {
if (productionExceptionIsFatal(exception)) {
Expand Down Expand Up @@ -233,13 +235,13 @@ public void onCompletion(final RecordMetadata metadata,
String.format("%sFailed to send record to topic %s due to timeout.", logPrefix, topic),
e
);
} catch (final Exception uncaughtException) {
} catch (final RuntimeException uncaughtException) {
if (uncaughtException instanceof KafkaException &&
uncaughtException.getCause() instanceof ProducerFencedException) {
final KafkaException kafkaException = (KafkaException) uncaughtException;
// producer.send() call may throw a KafkaException which wraps a FencedException,
// in this case we should throw its wrapped inner cause so that it can be captured and re-wrapped as TaskMigrationException
throw (ProducerFencedException) kafkaException.getCause();
throw new RecoverableClientException("Caught a wrapped ProducerFencedException", kafkaException);
} else {
throw new StreamsException(
String.format(
Expand All @@ -264,15 +266,23 @@ private void checkForException() {
@Override
public void flush() {
log.debug("Flushing producer");
producer.flush();
try {
producer.flush();
} catch (final ProducerFencedException | UnknownProducerIdException e) {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For UnknownProducerIdException we actually can still reuse the client and just need to send the next produce request (unlike ProducerFencedException we cannot reuse the client and hence have to create a new client). However when we translate them into TaskMigrationException on higher level it would be treated equally as re-triggering a rebalance.

It's just that in current EOS implementation (before KIP-447) have one producer per task, hence when the task is closed the corresponding producer is closed and discarded as well. In KIP-447 however we may still need to treat them differently: for UnknownProducerIdException we can just log and proceed, for ProducerFencedException we need to close the producer and re-create a new one.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks. One thing I'm not sure about, but felt at the time of putting this together was that, if we get an UnknownProducerIdException on one call, we'd probably just keep getting it on all subsequent calls. It seemed to me that the exception was originating from a condition where the broker "forgot" about our id, and if it has "forgotten" about us, I'm not sure why it would "remember" us later on.

If that's not true, then this approach certainly may result in more close+reopen operations than is necessary.

throw new RecoverableClientException("Caught a recoverable exception while flushing", e);
}
checkForException();
}

@Override
public void close() {
log.debug("Closing producer");
if (producer != null) {
producer.close();
try {
producer.close();
} catch (final ProducerFencedException | UnknownProducerIdException e) {
throw new RecoverableClientException("Caught a recoverable exception while closing", e);
}
producer = null;
}
checkForException();
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,33 @@
/*
* Licensed to the Apache Software Foundation (ASF) under one or more
* contributor license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright ownership.
* The ASF licenses this file to You under the Apache License, Version 2.0
* (the "License"); you may not use this file except in compliance with
* the License. You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package org.apache.kafka.streams.processor.internals;

import org.apache.kafka.common.KafkaException;

/**
* Denotes an exception that is recoverable by re-creating the client (ie, the client is no longer in a valid state),
* as opposed to retriable (the failure was transient, so the same client can be used again later),
* or fatal (the request was actually invalid, so retrying or recovering would not help)
*
* This class also serves the dual purpose of capturing the stack trace as early as possible,
* at the site of the Producer call, since the exeptions that cause this don't record stack traces.
*/
public class RecoverableClientException extends KafkaException {
public RecoverableClientException(final String message, final Throwable cause) {
super(message, cause);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -122,6 +122,9 @@ public void commit() {
}

private void flushAndCheckpointState() {
// this could theoretically throw a ProcessorStateException caused by a ProducerFencedException,
// but in practice this shouldn't happen for standby tasks, since they don't produce to changelog topics
// or downstream topics.
stateMgr.flush();
stateMgr.checkpoint(Collections.emptyMap());
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@
import org.apache.kafka.common.errors.AuthorizationException;
import org.apache.kafka.common.errors.ProducerFencedException;
import org.apache.kafka.common.errors.TimeoutException;
import org.apache.kafka.common.errors.UnknownProducerIdException;
import org.apache.kafka.common.errors.WakeupException;
import org.apache.kafka.common.metrics.Sensor;
import org.apache.kafka.common.metrics.stats.Avg;
Expand Down Expand Up @@ -337,8 +338,8 @@ public void initializeTopology() {
if (eosEnabled) {
try {
this.producer.beginTransaction();
} catch (final ProducerFencedException fatal) {
throw new TaskMigratedException(this, fatal);
} catch (final ProducerFencedException | UnknownProducerIdException e) {
throw new TaskMigratedException(this, e);

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think that an UnknownProducerIdException implies that a task was migrated.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agreed, but TaskMigratedException is the mechanism to initiate a rebalance, which is currently the only way that we can re-initialize the producers.

I think we can stand to re-evaluate how we're handling all these different producer and consumer exceptions (with and without eos). Right now, there are a lot of catch blocks for specific exceptions sprinkled throughout the codebase, and we universally either crash the thread or initiate a rebalance to attempt recovery. It would certainly benefit from developing a holistic approach, but right now, I'm just trying to get Streams threads to quit dying within a few hours of running in EOS mode, and I'm trying to restrain myself from broad refactoring so we can hope to merge this in for 2.4.0.

(About that last statement, I've been on holiday this week, so I haven't had time to document the comprehensive analysis in the ticket, but I do plan to make a case that it is a regression. When I ran 2.3 under similar conditions, we still had threads dying, but they were only dying from KIP-360-related-causes. In 2.4, Streams threads are dying from multiple new causes, related to the changes that we made in 2.4... Anyway, more details coming early next week, then we can discuss it)

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Give the fix for the root cause of UnknownProducerIdException (via KIP-360), I am wondering if we should actually treat it as fatal? I also don't see why it would be regression if KS dies if this exception is thrown though? (I understand that we did introduce some regression bugs, but those seem unrelated to UnknownProducerIdException?)

To be fair, 2.4.0 does not contain a full implementation of KIP-360 and thus, this fix might be a workaround... But frankly, I am not very happy about it, even if I understand the desire to just stabilize it somehow without a refactoring that won't make it into 2.4.0 anyway.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, then it seems worth hashing it out. Can you elaborate what is there to be unhappy about? I figured it would be reasonable to treat it as "recoverable by creating a new Producer" instead of "fatal and you should immediately terminate the thread".

What I was thinking was that is seems like the broker is telling us it doesn't know who we are (anymore). Because of the context, we know that it used to know who we were, so it must have forgotten somehow, and it doesn't really matter how because we can always shrug it off and re-create our producer to try again.

IIUC, KIP-360 would reduce the occurrence of the exception by keeping your producer id cached even after its ttl has expired, but it by no means guarantees that it'll remember you regardless of how long you're silent.

From that perspective it seems reasonable to catch this exception and conclude, "Oops, it looks like we were silent too long and our Producer has effectively expired. We should make a new one and try again." This isn't the same thing as getting fenced, but the resolution is the same (make a new Producer and try again).

Then again, this perspective may be based on a faulty understanding of the system. Is this approach unsafe, and we should actually terminate the application instead?

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For this type or error, before KIP-360, the producer should self-recover and never throw an exception. (Cf "motivation" section of the KIP). If this error occurs, something really bad happened for the transaction and we are in an unknown state -- not sure if rebalancing and retrying is the right approach for this case \cc @guozhangwang @hachikuji @bob-barrett -- also, maybe it's just sufficient to close the task locally and recreate it -- I don't see a need to trigger a rebalance (in case it is ok to recorve from within KS).

This isn't the same thing as getting fenced, but the resolution is the same (make a new Producer and try again).

I disagree. If we got fenced, a new producer with the same transactional.id was created and we know that we don't own the task any longer. For a UnknownProducerIdException we still own the task.

Is this approach unsafe, and we should actually terminate the application instead?

I don't thinks it's unsafe, but it's not the "right" fix IMHO, and this bug is also not a regression.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the clarification, @mjsax .

I agree that it would be better to just close the task and re-open it, but I don't feel comfortable introducing a whole new task lifecycle at this point for the 2.4.0 release. My rationale was that triggering a rebalance would put Kafka Streams through a well-known and well-tested code path that will result in the task getting closed and then opened again.

I do think it makes sense to go ahead and handle this case along with the two regressions. In my testing, this exception was just as fatal for Streams as the other two. Specifically, unless I include all three fixes, my soak test saw StreamThreads start dying within a few hours.

It seems like maybe a good approach right now would be to take the simple and sub-optimal path of just rebalancing when we encounter this exception for the 2.4.0 release, and file a Jira to optimize it in the way you suggest.

It would be good, by the way, to find out the answer to your question of whether it's safe to continue or not. Note that the current behavior, both in 2.4 and 2.3, without this patch is that a thread will get this exception and then shut itself down. This leads to a rebalance (since a member has left the group), after which the task is assigned to another thread, which continues processing it. Thus, we are already responding to this condition by rebalancing. It's just that we permanently lose a thread in the process. With this patch, we still rebalance, but we get to keep the thread running. If it's really unsafe to continue processing, though, we should stop the entire Streams application and force the operator to diagnose the problem with the brokers and start the app back up in a safe state.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I shared some thoughts on the comment above: before KIP-447, when we re-trigger the rebalance if the task is indeed migrated out the corresponding producer would be closed, otherwise that producer will be retained. But I think after KIP-447 we need to revisit this again.

At the moment I feel okay to treat UnknownProducerId equally as ProducerFenced.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks. That will be a good opportunity to clean up what is honestly a pretty ham-handed approach here to gracefully deal with this condition without changing too much code.

}
transactionInFlight = true;
}
Expand Down Expand Up @@ -438,8 +439,8 @@ public boolean process() {
if (recordInfo.queue().size() == maxBufferedSize) {
consumer.resume(singleton(partition));
}
} catch (final ProducerFencedException fatal) {
throw new TaskMigratedException(this, fatal);
} catch (final RecoverableClientException e) {
throw new TaskMigratedException(this, e);
} catch (final KafkaException e) {
final String stackTrace = getStacktraceString(e);
throw new StreamsException(format("Exception caught in process. taskId=%s, " +
Expand Down Expand Up @@ -488,8 +489,8 @@ public void punctuate(final ProcessorNode node, final long timestamp, final Punc

try {
node.punctuate(timestamp, punctuator);
} catch (final ProducerFencedException fatal) {
throw new TaskMigratedException(this, fatal);
} catch (final RecoverableClientException e) {
throw new TaskMigratedException(this, e);
} catch (final KafkaException e) {
throw new StreamsException(String.format("%sException caught while punctuating processor '%s'", logPrefix, node.name()), e);
} finally {
Expand Down Expand Up @@ -558,7 +559,7 @@ void commit(final boolean startNewTransaction, final Map<TopicPartition, Long> p
} else {
consumer.commitSync(consumedOffsetsAndMetadata);
}
} catch (final CommitFailedException | ProducerFencedException error) {
} catch (final CommitFailedException | ProducerFencedException | UnknownProducerIdException error) {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For here and producer.beginTransaction above: I think beginTxn / sendOffsetsToTxn / commitTxn would not throw UnknownProducerIdException but it does not harm to be more careful for 2.4 release -- so if you want to keep it as is I'm fine with it too.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, I wasn't sure, so I just put it everywhere that we already check for ProducerFencedException, on the rationale that, if we can get fenced, then we must have a transactional id, and if we have an id, then it could be "unknown". Clearly, this is more intuitive than analytical, so I find your feedback plausible.

throw new TaskMigratedException(this, error);
}

Expand All @@ -581,8 +582,8 @@ protected void flushState() {
super.flushState();
try {
recordCollector.flush();
} catch (final ProducerFencedException fatal) {
throw new TaskMigratedException(this, fatal);
} catch (final RecoverableClientException e) {
throw new TaskMigratedException(this, e);
}
}

Expand Down Expand Up @@ -664,7 +665,7 @@ void suspend(final boolean clean,

try {
recordCollector.close();
} catch (final ProducerFencedException e) {
} catch (final RecoverableClientException e) {
taskMigratedException = new TaskMigratedException(this, e);
} finally {
producer = null;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -188,10 +188,11 @@ void openDB(final ProcessorContext context) {
throw new ProcessorStateException(fatal);
}

maybeSetUpMetricsRecorder(context, configs);

openRocksDB(dbOptions, columnFamilyOptions);
open = true;

// Do this last because the prior operations could throw exceptions.
maybeSetUpMetricsRecorder(context, configs);
}

private void maybeSetUpMetricsRecorder(final ProcessorContext context, final Map<String, Object> configs) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -37,15 +37,16 @@
import org.easymock.EasyMock;
import org.junit.Before;
import org.junit.Test;
import org.junit.function.ThrowingRunnable;

import java.util.ArrayList;
import java.util.Collection;
import java.util.Collections;
import java.util.HashSet;
import java.util.List;
import java.util.Set;
import org.junit.function.ThrowingRunnable;

import static org.hamcrest.CoreMatchers.is;
import static org.hamcrest.CoreMatchers.not;
import static org.hamcrest.CoreMatchers.nullValue;
import static org.hamcrest.MatcherAssert.assertThat;
Expand Down Expand Up @@ -235,14 +236,45 @@ public void shouldCloseTaskOnSuspendIfTaskMigratedException() {
t1.suspend();
EasyMock.expectLastCall().andThrow(new TaskMigratedException());
t1.close(false, true);
EasyMock.expectLastCall();
EasyMock.expectLastCall().andThrow(new RuntimeException("any exception"));
EasyMock.replay(t1);

assertThat(suspendTask(), nullValue());
assertTrue(assignedTasks.runningTaskIds().isEmpty());
EasyMock.verify(t1);
}

@Test
public void shouldCloseUncleanAndThenRethrowOnShutdownIfRuntimeException() {
mockTaskInitialization();

t1.close(true, false);
EasyMock.expectLastCall().andThrow(new RuntimeException("any first exception"));
t1.close(false, false);
EasyMock.expectLastCall().andThrow(new RuntimeException("any second exception"));
EasyMock.replay(t1);
addAndInitTask();
try {
assignedTasks.shutdown(true);
fail("expected a runtime exception");
} catch (final RuntimeException e) {
assertThat(e.getMessage(), is("any first exception"));
}
}

@Test
public void shouldCloseWithoutExceptionOnShutdownIfTaskMigratedException() {
mockTaskInitialization();

t1.close(true, false);
EasyMock.expectLastCall().andThrow(new TaskMigratedException());
t1.close(false, true);
EasyMock.expectLastCall().andThrow(new RuntimeException("any second exception"));
EasyMock.replay(t1);
addAndInitTask();
assignedTasks.shutdown(true);
}

@Test
public void shouldResumeMatchingSuspendedTasks() {
mockRunningTaskSuspension();
Expand Down Expand Up @@ -603,7 +635,7 @@ public void action(final StreamTask task) {
public Set<TaskId> taskIds() {
return assignedTasks.suspendedTaskIds();
}

}.createTaskAndClear();
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@
import org.apache.kafka.common.Node;
import org.apache.kafka.common.PartitionInfo;
import org.apache.kafka.common.TopicPartition;
import org.apache.kafka.common.errors.ProducerFencedException;
import org.apache.kafka.common.header.Header;
import org.apache.kafka.common.header.Headers;
import org.apache.kafka.common.header.internals.RecordHeader;
Expand Down Expand Up @@ -191,6 +192,26 @@ public synchronized Future<RecordMetadata> send(final ProducerRecord record, fin
collector.send("topic1", "3", "0", null, null, stringSerializer, stringSerializer, streamPartitioner);
}

@SuppressWarnings("unchecked")
@Test(expected = RecoverableClientException.class)
public void shouldThrowRecoverableExceptionWhenProducerFencedInCallback() {
final RecordCollector collector = new RecordCollectorImpl(
"test",
logContext,
new DefaultProductionExceptionHandler(),
new Metrics().sensor("skipped-records"));
collector.init(new MockProducer(cluster, true, new DefaultPartitioner(), byteArraySerializer, byteArraySerializer) {
@Override
public synchronized Future<RecordMetadata> send(final ProducerRecord record, final Callback callback) {
callback.onCompletion(null, new ProducerFencedException("asdf"));
return null;
}
});

collector.send("topic1", "3", "0", null, null, stringSerializer, stringSerializer, streamPartitioner);
collector.send("topic1", "3", "0", null, null, stringSerializer, stringSerializer, streamPartitioner);
}

@SuppressWarnings("unchecked")
@Test
public void shouldThrowStreamsExceptionOnSubsequentCallIfASendFailsWithDefaultExceptionHandler() {
Expand Down
Loading