Addressing PR comments.

This commit is contained in:
jushkem 2020-02-13 12:50:26 -08:00
parent 2f6e5d32c1
commit dd15ea2a57
8 changed files with 91 additions and 66 deletions

View file

@ -2,12 +2,54 @@ package software.amazon.kinesis.common;
import lombok.AllArgsConstructor; import lombok.AllArgsConstructor;
import lombok.Getter; import lombok.Getter;
import lombok.NoArgsConstructor;
import lombok.experimental.Accessors; import lombok.experimental.Accessors;
@Accessors(fluent = true) import java.util.Optional;
@Accessors(fluent=true)
@Getter @Getter
@AllArgsConstructor
public class RequestDetails { public class RequestDetails {
private final String requestId;
private final String timestamp; /**
* Placeholder for logging when no successful request has been made.
*/
private static final String NONE = "NONE";
private final Optional<String> requestId;
private final Optional<String> timestamp;
public RequestDetails() {
this(Optional.empty(), Optional.empty());
}
public RequestDetails(Optional<String> requestId, Optional<String> timestamp) {
this.requestId = requestId;
this.timestamp = timestamp;
}
/**
* Gets last successful response's request id.
*
* @return requestId associated with last succesful response.
*/
public String getLastSuccessfulResponseRequestId() {
return requestId.orElse(NONE);
}
/**
* Gets last successful response's timestamp.
*
* @return timestamp associated with last successful response.
*/
public String getLastSuccessfulResponseTimestamp() {
return timestamp.orElse(NONE);
}
@Override
public String toString() {
return String.format("request id - %s, timestamp - %s", getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp());
}
} }

View file

@ -129,8 +129,8 @@ class ShardConsumerSubscriber implements Subscriber<RecordsRetrieved> {
Duration timeSinceLastResponse = Duration.between(lastRequestTime, now); Duration timeSinceLastResponse = Duration.between(lastRequestTime, now);
if (timeSinceLastResponse.toMillis() > maxTimeBetweenRequests) { if (timeSinceLastResponse.toMillis() > maxTimeBetweenRequests) {
log.error( log.error(
"{}: Last request was dispatched at {}, but no response as of {} ({}). Cancelling subscription, and restarting. Last successful response: RequestId - {}, Timestamp - {}", "{}: Last request was dispatched at {}, but no response as of {} ({}). Cancelling subscription, and restarting. Last successful response details: {}",
shardConsumer.shardInfo().shardId(), lastRequestTime, now, timeSinceLastResponse, recordsPublisher.getLastSuccessfulResponseRequestId(), recordsPublisher.getLastSuccessfulResponseTimestamp()); shardConsumer.shardInfo().shardId(), lastRequestTime, now, timeSinceLastResponse, recordsPublisher.getLastSuccessfulResponseDetails());
cancel(); cancel();
// Start the subscription again which will update the lastRequestTime as well. // Start the subscription again which will update the lastRequestTime as well.

View file

@ -28,10 +28,7 @@ import java.util.Optional;
*/ */
public interface RecordsPublisher extends Publisher<RecordsRetrieved> { public interface RecordsPublisher extends Publisher<RecordsRetrieved> {
/**
* Placeholder for logging when no successful request has been made.
*/
String NONE = "NONE";
/** /**
* Initializes the publisher with where to start processing. If there is a stored sequence number the publisher will * Initializes the publisher with where to start processing. If there is a stored sequence number the publisher will
@ -61,25 +58,7 @@ public interface RecordsPublisher extends Publisher<RecordsRetrieved> {
* *
* @return details associated with last successful response. * @return details associated with last successful response.
*/ */
Optional<RequestDetails> getLastSuccessfulResponseDetails(); RequestDetails getLastSuccessfulResponseDetails();
/**
* Gets last successful response's request id.
*
* @return requestId associated with last succesful response.
*/
default String getLastSuccessfulResponseRequestId() {
return getLastSuccessfulResponseDetails().map(RequestDetails::requestId).orElse(NONE);
}
/**
* Gets last successful response's timestamp.
*
* @return timestamp associated with last successful response.
*/
default String getLastSuccessfulResponseTimestamp() {
return getLastSuccessfulResponseDetails().map(RequestDetails::timestamp).orElse(NONE);
}
/** /**
* Notify the publisher on receipt of a data event. * Notify the publisher on receipt of a data event.

View file

@ -89,7 +89,7 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
private BlockingQueue<RecordsRetrievedContext> recordsDeliveryQueue = new LinkedBlockingQueue<>( private BlockingQueue<RecordsRetrievedContext> recordsDeliveryQueue = new LinkedBlockingQueue<>(
MAX_EVENT_BURST_FROM_SERVICE); MAX_EVENT_BURST_FROM_SERVICE);
private Optional<RequestDetails> lastSuccessfulRequestDetails = Optional.empty(); private RequestDetails lastSuccessfulRequestDetails = new RequestDetails();
@Override @Override
public void start(ExtendedSequenceNumber extendedSequenceNumber, public void start(ExtendedSequenceNumber extendedSequenceNumber,
@ -148,12 +148,12 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
} }
@Override @Override
public Optional<RequestDetails> getLastSuccessfulResponseDetails() { public RequestDetails getLastSuccessfulResponseDetails() {
return lastSuccessfulRequestDetails; return lastSuccessfulRequestDetails;
} }
public void setLastSuccessfulResponseDetails(RequestDetails requestDetails) { private void setLastSuccessfulResponseDetails(RequestDetails requestDetails) {
lastSuccessfulRequestDetails = Optional.of(requestDetails); lastSuccessfulRequestDetails = requestDetails;
} }
// This method is not thread-safe. You need to acquire a lock in the caller in order to execute this. // This method is not thread-safe. You need to acquire a lock in the caller in order to execute this.
@ -218,8 +218,8 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
} }
} catch (IllegalStateException e) { } catch (IllegalStateException e) {
log.warn("{}: Unable to enqueue the payload due to capacity restrictions in delivery queue with remaining capacity {}. Last successful response: RequestId - {}, Timestamp - {}", log.warn("{}: Unable to enqueue the payload due to capacity restrictions in delivery queue with remaining capacity {}. Last successful response details: {}",
shardId, recordsDeliveryQueue.remainingCapacity(), getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp()); shardId, recordsDeliveryQueue.remainingCapacity(), lastSuccessfulRequestDetails);
throw e; throw e;
} catch (Throwable t) { } catch (Throwable t) {
log.error("{}: Unable to deliver event to the shard consumer.", shardId, t); log.error("{}: Unable to deliver event to the shard consumer.", shardId, t);
@ -303,13 +303,12 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
if(hasValidFlow()) { if(hasValidFlow()) {
log.warn( log.warn(
"{}: [SubscriptionLifetime] - (FanOutRecordsPublisher#errorOccurred) @ {} id: {} -- Subscriber is null." + "{}: [SubscriptionLifetime] - (FanOutRecordsPublisher#errorOccurred) @ {} id: {} -- Subscriber is null." +
" Last successful response: RequestId - {}, Timestamp - {}", " Last successful response details: {}", shardId, flow.connectionStartedAt,
shardId, flow.connectionStartedAt, flow.subscribeToShardId, getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp()); flow.subscribeToShardId, lastSuccessfulRequestDetails);
} else { } else {
log.warn( log.warn(
"{}: [SubscriptionLifetime] - (FanOutRecordsPublisher#errorOccurred) -- Subscriber and flow are null." + "{}: [SubscriptionLifetime] - (FanOutRecordsPublisher#errorOccurred) -- Subscriber and flow are null." +
" Last successful response: RequestId - {}, Timestamp - {}", " Last successful response details: {}", shardId, lastSuccessfulRequestDetails);
shardId, getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp());
} }
return; return;
} }
@ -321,8 +320,8 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
if (flow != null) { if (flow != null) {
String logMessage = String.format( String logMessage = String.format(
"%s: [SubscriptionLifetime] - (FanOutRecordsPublisher#errorOccurred) @ %s id: %s -- %s." + "%s: [SubscriptionLifetime] - (FanOutRecordsPublisher#errorOccurred) @ %s id: %s -- %s." +
" Last successful response: RequestId - {}, Timestamp - {}", " Last successful response details: {}",
shardId, flow.connectionStartedAt, flow.subscribeToShardId, category.throwableTypeString, getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp()); shardId, flow.connectionStartedAt, flow.subscribeToShardId, category.throwableTypeString, lastSuccessfulRequestDetails);
switch (category.throwableType) { switch (category.throwableType) {
case READ_TIMEOUT: case READ_TIMEOUT:
log.debug(logMessage, propagationThrowable); log.debug(logMessage, propagationThrowable);
@ -347,7 +346,7 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
handleFlowError(propagationThrowable, triggeringFlow); handleFlowError(propagationThrowable, triggeringFlow);
} catch (Throwable innerThrowable) { } catch (Throwable innerThrowable) {
log.warn("{}: Exception while calling subscriber.onError. Last successful response:" + log.warn("{}: Exception while calling subscriber.onError. Last successful response:" +
" RequestId - {}, Timestamp - {}", shardId, innerThrowable, getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp()); "Last successful response details: {}", shardId, innerThrowable, lastSuccessfulRequestDetails);
} }
subscriber = null; subscriber = null;
flow = null; flow = null;
@ -369,7 +368,7 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
// Clear any lingering records in the queue. // Clear any lingering records in the queue.
if (!recordsDeliveryQueue.isEmpty()) { if (!recordsDeliveryQueue.isEmpty()) {
log.warn("{}: Found non-empty queue while starting subscription. This indicates unsuccessful clean up of" log.warn("{}: Found non-empty queue while starting subscription. This indicates unsuccessful clean up of"
+ "previous subscription - {}. Last successful response: RequestId - {}, Timestamp - {}", shardId, subscribeToShardId, getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp()); + "previous subscription - {}. Last successful response details: {}", shardId, subscribeToShardId, lastSuccessfulRequestDetails);
recordsDeliveryQueue.clear(); recordsDeliveryQueue.clear();
} }
} }
@ -480,7 +479,7 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
bufferCurrentEventAndScheduleIfRequired(recordsRetrieved, triggeringFlow); bufferCurrentEventAndScheduleIfRequired(recordsRetrieved, triggeringFlow);
} catch (Throwable t) { } catch (Throwable t) {
log.warn("{}: Unable to buffer or schedule onNext for subscriber. Failing publisher." + log.warn("{}: Unable to buffer or schedule onNext for subscriber. Failing publisher." +
" Last successful response: RequestId - {}, Timestamp - {}", shardId, getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp()); " Last successful response details: {}", shardId, lastSuccessfulRequestDetails);
errorOccurred(triggeringFlow, t); errorOccurred(triggeringFlow, t);
} }
} }
@ -576,8 +575,8 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
synchronized (lockObject) { synchronized (lockObject) {
if (subscriber != s) { if (subscriber != s) {
log.warn( log.warn(
"{}: (FanOutRecordsPublisher/Subscription#request) - Rejected an attempt to request({}), because subscribers don't match. Last successful response: RequestId - {}, Timestamp - {}", "{}: (FanOutRecordsPublisher/Subscription#request) - Rejected an attempt to request({}), because subscribers don't match. Last successful response details: {}",
shardId, n, getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp()); shardId, n, lastSuccessfulRequestDetails);
return; return;
} }
if (flow == null) { if (flow == null) {
@ -603,14 +602,14 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
synchronized (lockObject) { synchronized (lockObject) {
if (subscriber != s) { if (subscriber != s) {
log.warn( log.warn(
"{}: (FanOutRecordsPublisher/Subscription#cancel) - Rejected attempt to cancel subscription, because subscribers don't match. Last successful response: RequestId - {}, Timestamp - {}", "{}: (FanOutRecordsPublisher/Subscription#cancel) - Rejected attempt to cancel subscription, because subscribers don't match. Last successful response details: {}",
shardId, getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp()); shardId, lastSuccessfulRequestDetails);
return; return;
} }
if (!hasValidSubscriber()) { if (!hasValidSubscriber()) {
log.warn( log.warn(
"{}: (FanOutRecordsPublisher/Subscription#cancel) - Cancelled called even with an invalid subscriber. Last successful response: RequestId - {}, Timestamp - {}", "{}: (FanOutRecordsPublisher/Subscription#cancel) - Cancelled called even with an invalid subscriber. Last successful response details: {}",
shardId, getLastSuccessfulResponseRequestId(), getLastSuccessfulResponseTimestamp()); shardId, lastSuccessfulRequestDetails);
} }
subscriber = null; subscriber = null;
if (flow != null) { if (flow != null) {
@ -738,10 +737,10 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
@Override @Override
public void responseReceived(SubscribeToShardResponse response) { public void responseReceived(SubscribeToShardResponse response) {
log.debug("{}: [SubscriptionLifetime]: (RecordFlow#responseReceived) @ {} id: {} -- Response received. Last successful response: RequestId - {}, Timestamp - {}, ExtendedLast successful response: RequestId - {}, Timestamp - {}", log.debug("{}: [SubscriptionLifetime]: (RecordFlow#responseReceived) @ {} id: {} -- Response received. Last successful response details: {}, ExtendedLast successful response: RequestId - {}, Timestamp - {}",
parent.shardId, connectionStartedAt, subscribeToShardId, response.responseMetadata().requestId(), response.responseMetadata().extendedRequestId(), connectionStartedAt); parent.shardId, connectionStartedAt, subscribeToShardId, response.responseMetadata().requestId(), response.responseMetadata().extendedRequestId(), connectionStartedAt);
lastSuccessfulResponseDetails = new RequestDetails(response.responseMetadata().requestId(), connectionStartedAt.toString()); lastSuccessfulResponseDetails = new RequestDetails(Optional.of(response.responseMetadata().requestId()), Optional.of(connectionStartedAt.toString()));
parent.setLastSuccessfulResponseDetails(lastSuccessfulResponseDetails); parent.setLastSuccessfulResponseDetails(lastSuccessfulResponseDetails);
} }
@ -804,9 +803,9 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
.add(new RecordsRetrievedContext(Either.right(subscriptionShutdownEvent), this, Instant.now())); .add(new RecordsRetrievedContext(Either.right(subscriptionShutdownEvent), this, Instant.now()));
} catch (Exception e) { } catch (Exception e) {
log.warn( log.warn(
"{}: Unable to enqueue the {} shutdown event due to capacity restrictions in delivery queue with remaining capacity {}. Ignoring. Last successful response: RequestId - {}, Timestamp - {}", "{}: Unable to enqueue the {} shutdown event due to capacity restrictions in delivery queue with remaining capacity {}. Ignoring. Last successful response details: {}",
parent.shardId, subscriptionShutdownEvent.getEventIdentifier(), parent.recordsDeliveryQueue.remainingCapacity(), parent.shardId, subscriptionShutdownEvent.getEventIdentifier(), parent.recordsDeliveryQueue.remainingCapacity(),
subscriptionShutdownEvent.getShutdownEventThrowableOptional(), parent.getLastSuccessfulResponseRequestId(), parent.getLastSuccessfulResponseTimestamp()); subscriptionShutdownEvent.getShutdownEventThrowableOptional(), parent.lastSuccessfulRequestDetails);
} }
} }
@ -822,14 +821,14 @@ public class FanOutRecordsPublisher implements RecordsPublisher {
// the // the
// subscription, which was cancelled for a reason (usually queue overflow). // subscription, which was cancelled for a reason (usually queue overflow).
// //
log.warn("{}: complete called on a cancelled subscription. Ignoring completion. Last successful response: RequestId - {}, Timestamp - {}", log.warn("{}: complete called on a cancelled subscription. Ignoring completion. Last successful response details: {}",
parent.shardId, parent.getLastSuccessfulResponseRequestId(), parent.getLastSuccessfulResponseTimestamp()); parent.shardId, parent.lastSuccessfulRequestDetails);
return; return;
} }
if (this.isDisposed) { if (this.isDisposed) {
log.warn( log.warn(
"{}: [SubscriptionLifetime]: (RecordFlow#complete) @ {} id: {} -- This flow has been disposed not dispatching completion. Last successful response: RequestId - {}, Timestamp - {}", "{}: [SubscriptionLifetime]: (RecordFlow#complete) @ {} id: {} -- This flow has been disposed not dispatching completion. Last successful response details: {}",
parent.shardId, connectionStartedAt, subscribeToShardId, parent.getLastSuccessfulResponseRequestId(), parent.getLastSuccessfulResponseTimestamp()); parent.shardId, connectionStartedAt, subscribeToShardId, parent.lastSuccessfulRequestDetails);
return; return;
} }

View file

@ -42,6 +42,7 @@ public class BlockingRecordsPublisher implements RecordsPublisher {
private final GetRecordsRetrievalStrategy getRecordsRetrievalStrategy; private final GetRecordsRetrievalStrategy getRecordsRetrievalStrategy;
private Subscriber<? super RecordsRetrieved> subscriber; private Subscriber<? super RecordsRetrieved> subscriber;
private final RequestDetails lastSuccessfulResponseDetails = new RequestDetails();
public BlockingRecordsPublisher(final int maxRecordsPerCall, public BlockingRecordsPublisher(final int maxRecordsPerCall,
final GetRecordsRetrievalStrategy getRecordsRetrievalStrategy) { final GetRecordsRetrievalStrategy getRecordsRetrievalStrategy) {
@ -73,8 +74,8 @@ public class BlockingRecordsPublisher implements RecordsPublisher {
} }
@Override @Override
public Optional<RequestDetails> getLastSuccessfulResponseDetails() { public RequestDetails getLastSuccessfulResponseDetails() {
return Optional.empty(); return lastSuccessfulResponseDetails;
} }
@Override @Override

View file

@ -100,6 +100,7 @@ public class PrefetchRecordsPublisher implements RecordsPublisher {
private boolean wasReset = false; private boolean wasReset = false;
private Instant lastEventDeliveryTime = Instant.EPOCH; private Instant lastEventDeliveryTime = Instant.EPOCH;
private final RequestDetails lastSuccessfulRequestDetails = new RequestDetails();
@Data @Data
@Accessors(fluent = true) @Accessors(fluent = true)
@ -263,8 +264,8 @@ public class PrefetchRecordsPublisher implements RecordsPublisher {
} }
@Override @Override
public Optional<RequestDetails> getLastSuccessfulResponseDetails() { public RequestDetails getLastSuccessfulResponseDetails() {
return Optional.empty(); return lastSuccessfulRequestDetails;
} }
@Override @Override

View file

@ -79,6 +79,8 @@ public class ShardConsumerSubscriberTest {
private static final String TERMINAL_MARKER = "Terminal"; private static final String TERMINAL_MARKER = "Terminal";
private final RequestDetails lastSuccessfulRequestDetails = new RequestDetails();
@Mock @Mock
private ShardConsumer shardConsumer; private ShardConsumer shardConsumer;
@Mock @Mock
@ -559,8 +561,8 @@ public class ShardConsumerSubscriberTest {
} }
@Override @Override
public Optional<RequestDetails> getLastSuccessfulResponseDetails() { public RequestDetails getLastSuccessfulResponseDetails() {
return Optional.empty(); return lastSuccessfulRequestDetails;
} }
@Override @Override

View file

@ -89,6 +89,7 @@ public class ShardConsumerTest {
private final String shardId = "shardId-0-0"; private final String shardId = "shardId-0-0";
private final String concurrencyToken = "TestToken"; private final String concurrencyToken = "TestToken";
private final RequestDetails lastSuccessfulRequestDetails = new RequestDetails();
private ShardInfo shardInfo; private ShardInfo shardInfo;
private TaskExecutionListenerInput initialTaskInput; private TaskExecutionListenerInput initialTaskInput;
private TaskExecutionListenerInput processTaskInput; private TaskExecutionListenerInput processTaskInput;
@ -211,8 +212,8 @@ public class ShardConsumerTest {
} }
@Override @Override
public Optional<RequestDetails> getLastSuccessfulResponseDetails() { public RequestDetails getLastSuccessfulResponseDetails() {
return Optional.empty(); return lastSuccessfulRequestDetails;
} }
@Override @Override