Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

OWLS-89106 - Potential fix for pod startup issue in GBU CNE environment after node drain/repave operation #2398

Merged
merged 23 commits into from
Jun 16, 2021
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
23 commits
Select commit Hold shift + click to select a range
b33a4a3
Potential fix for pod startup issue in GBU CNE env after node drain/r…
ankedia Jun 8, 2021
9c83cb0
Increase the pod ready wait timeout to 5 min (instead of 2 min) to av…
ankedia Jun 9, 2021
4d6749c
Undo refactoring related changes.
ankedia Jun 9, 2021
291d6d2
Fix to not increment count for introspector job.
ankedia Jun 10, 2021
6d106c7
Potential fix for the race condition in the introspector job completi…
ankedia Jun 10, 2021
3fb128f
Reduce timeout interval to 2 min.
ankedia Jun 10, 2021
70eab49
Add previously removed event validation.
ankedia Jun 11, 2021
4dbbe1c
Changes to check if the cached pod is not found on read then execute …
ankedia Jun 12, 2021
240130d
Fix checkstyle error.
ankedia Jun 12, 2021
b035257
Minor refactoring and increase the timeout value.
ankedia Jun 12, 2021
e988050
Fix comments and minor change.
ankedia Jun 12, 2021
b009898
Minor changes.
ankedia Jun 14, 2021
9a913de
Fix checkstyle error.
ankedia Jun 14, 2021
2093c8f
PR review comments - create new MakeRightDomainOperation instead of u…
ankedia Jun 14, 2021
b3f2362
Revert previous change to create a new make-right operation and imple…
ankedia Jun 14, 2021
b471058
Refactoring changes.
ankedia Jun 14, 2021
7b2bc9f
Check for null call result.
ankedia Jun 15, 2021
5a040cc
More refactoring changes.
ankedia Jun 15, 2021
b974ff8
Added debug message.
ankedia Jun 15, 2021
0616eb6
Minor changes.
ankedia Jun 15, 2021
1c3b6a0
added unit test to test that wait for ready timeout executes make rig…
ankedia Jun 16, 2021
a61ddea
Minor change.
ankedia Jun 16, 2021
23b60ae
Remove unused variable and potential fix for integration test failure.
ankedia Jun 16, 2021
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -137,7 +137,6 @@
import static oracle.weblogic.kubernetes.utils.DeployUtil.deployUsingWlst;
import static oracle.weblogic.kubernetes.utils.FileUtils.doesFileExistInPod;
import static oracle.weblogic.kubernetes.utils.K8sEvents.DOMAIN_CHANGED;
import static oracle.weblogic.kubernetes.utils.K8sEvents.DOMAIN_PROCESSING_COMPLETED;
import static oracle.weblogic.kubernetes.utils.K8sEvents.DOMAIN_PROCESSING_STARTING;
import static oracle.weblogic.kubernetes.utils.K8sEvents.POD_STARTED;
import static oracle.weblogic.kubernetes.utils.K8sEvents.POD_TERMINATED;
Expand Down Expand Up @@ -740,16 +739,6 @@ public void testMultiClustersRollingRestart() {
.until(checkDomainEvent(opNamespace, miiDomainNamespace, miiDomainUid,
DOMAIN_PROCESSING_STARTING, "Normal", timestamp));

withStandardRetryPolicy
.conditionEvaluationListener(
condition -> logger.info("Waiting for domain event {0} to be logged "
+ "(elapsed time {1}ms, remaining time {2}ms)",
DOMAIN_PROCESSING_COMPLETED,
condition.getElapsedTimeInMS(),
condition.getRemainingTimeInMS()))
.until(checkDomainEvent(opNamespace, miiDomainNamespace, miiDomainUid,
DOMAIN_PROCESSING_COMPLETED, "Normal", timestamp));

// Verify that pod termination and started events are logged only once for each managed server in each cluster
for (int i = 1; i <= NUMBER_OF_CLUSTERS_MIIDOMAIN; i++) {
for (int j = 1; j <= replicaCount; j++) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -746,7 +746,7 @@ private void addServerToMaps(Map<String, ServerHealth> serverHealthMap,
*/
class MakeRightDomainOperationImpl implements MakeRightDomainOperation {

private final DomainPresenceInfo liveInfo;
private DomainPresenceInfo liveInfo;
private boolean explicitRecheck;
private boolean deleting;
private boolean willInterrupt;
Expand Down Expand Up @@ -851,6 +851,12 @@ public void setInspectionRun() {
inspectionRun = true;
}

@Override
public void setLiveInfo(DomainPresenceInfo info) {
this.liveInfo = info;
}


@Override
public boolean wasInspectionRun() {
return inspectionRun;
Expand Down
19 changes: 19 additions & 0 deletions operator/src/main/java/oracle/kubernetes/operator/JobWatcher.java
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@
import java.util.Optional;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.function.Consumer;
import javax.annotation.Nonnull;
Expand All @@ -25,13 +26,16 @@
import io.kubernetes.client.util.Watchable;
import oracle.kubernetes.operator.TuningParameters.WatchTuning;
import oracle.kubernetes.operator.builders.WatchBuilder;
import oracle.kubernetes.operator.calls.CallResponse;
import oracle.kubernetes.operator.helpers.CallBuilder;
import oracle.kubernetes.operator.helpers.KubernetesUtils;
import oracle.kubernetes.operator.helpers.ResponseStep;
import oracle.kubernetes.operator.logging.LoggingFacade;
import oracle.kubernetes.operator.logging.LoggingFactory;
import oracle.kubernetes.operator.logging.MessageKeys;
import oracle.kubernetes.operator.steps.DefaultResponseStep;
import oracle.kubernetes.operator.watcher.WatchListener;
import oracle.kubernetes.operator.work.NextAction;
import oracle.kubernetes.operator.work.Packet;
import oracle.kubernetes.operator.work.Step;
import oracle.kubernetes.utils.SystemClock;
Expand Down Expand Up @@ -302,6 +306,21 @@ Throwable createTerminationException(V1Job job) {
void logWaiting(String name) {
LOGGER.fine(MessageKeys.WAITING_FOR_JOB_READY, name);
}

@Override
protected DefaultResponseStep<V1Job> resumeIfReady(Callback callback) {
return new DefaultResponseStep<>(null) {
@Override
public NextAction onSuccess(Packet packet, CallResponse<V1Job> callResponse) {
if (isReady(callResponse.getResult())) {
callback.proceedFromWait(callResponse.getResult());
return doNext(packet);
}
return doDelay(createReadAndIfReadyCheckStep(callback), packet,
getWatchBackstopRecheckDelaySeconds(), TimeUnit.SECONDS);
}
};
}
}

static class DeadlineExceededException extends Exception {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,8 @@ public interface MakeRightDomainOperation {

void setInspectionRun();

void setLiveInfo(DomainPresenceInfo info);

boolean wasInspectionRun();

private static boolean wasInspectionRun(Packet packet) {
Expand Down
75 changes: 75 additions & 0 deletions operator/src/main/java/oracle/kubernetes/operator/PodWatcher.java
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@
import java.util.Map;
import java.util.Optional;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.function.Consumer;
import javax.annotation.Nonnull;
Expand All @@ -28,16 +29,24 @@
import io.kubernetes.client.util.Watchable;
import oracle.kubernetes.operator.TuningParameters.WatchTuning;
import oracle.kubernetes.operator.builders.WatchBuilder;
import oracle.kubernetes.operator.calls.CallResponse;
import oracle.kubernetes.operator.helpers.CallBuilder;
import oracle.kubernetes.operator.helpers.DomainPresenceInfo;
import oracle.kubernetes.operator.helpers.KubernetesUtils;
import oracle.kubernetes.operator.helpers.LegalNames;
import oracle.kubernetes.operator.helpers.PodHelper;
import oracle.kubernetes.operator.helpers.ResponseStep;
import oracle.kubernetes.operator.logging.LoggingFacade;
import oracle.kubernetes.operator.logging.LoggingFactory;
import oracle.kubernetes.operator.logging.MessageKeys;
import oracle.kubernetes.operator.steps.DefaultResponseStep;
import oracle.kubernetes.operator.watcher.WatchListener;
import oracle.kubernetes.operator.work.NextAction;
import oracle.kubernetes.operator.work.Packet;
import oracle.kubernetes.operator.work.Step;
import oracle.kubernetes.weblogic.domain.model.Domain;

import static oracle.kubernetes.operator.ProcessingConstants.MAKE_RIGHT_DOMAIN_OPERATION;

/**
* Watches for changes to pods.
Expand Down Expand Up @@ -322,6 +331,55 @@ V1ObjectMeta getMetadata(V1Pod pod) {
Step createReadAsyncStep(String name, String namespace, String domainUid, ResponseStep<V1Pod> responseStep) {
return new CallBuilder().readPodAsync(name, namespace, domainUid, responseStep);
}

@Override
protected DefaultResponseStep<V1Pod> resumeIfReady(Callback callback) {
return new DefaultResponseStep<>(null) {
@Override
public NextAction onSuccess(Packet packet, CallResponse<V1Pod> callResponse) {
DomainPresenceInfo info = packet.getSpi(DomainPresenceInfo.class);
Optional.ofNullable(callResponse.getResult()).ifPresent(pod -> setServerPodFromEvent(info, pod));
if (isReady(callResponse.getResult())) {
resetWatchBackstopRecheckCount(info);
return proceedFromWait(packet, callResponse);
}
if (shouldWait(info)) {
// Watch backstop recheck count is less than or equal to the configured recheck count, delay.
return doDelay(createReadAndIfReadyCheckStep(callback), packet,
getWatchBackstopRecheckDelaySeconds(), TimeUnit.SECONDS);
} else {
// Watch backstop recheck count is more than configured recheck count, proceed to make-right step.
return doNext(new CallBuilder().readDomainAsync(info.getDomainUid(),
Copy link
Member

Choose a reason for hiding this comment

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

Here you reread the domain, but don't we also need to reread the pod and/or other services?

Copy link
Member Author

Choose a reason for hiding this comment

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

I was following the approach in handleModifiedDomain where we call the make-right domain with just the domain object received in the watch event.

  private void handleModifiedDomain(Domain domain) {
    LOGGER.fine(MessageKeys.WATCH_DOMAIN, domain.getDomainUid());
    createMakeRightOperation(new DomainPresenceInfo(domain))
        .interrupt()
        .withEventData(EventItem.DOMAIN_CHANGED, null)
        .execute();
  }

info.getNamespace(), new MakeRightDomainStep(null)), packet);
}
}

private void resetWatchBackstopRecheckCount(DomainPresenceInfo info) {
Optional.ofNullable(info).ifPresent(DomainPresenceInfo::resetWatchBackstopRecheckCount);
}

private void setServerPodFromEvent(DomainPresenceInfo info, V1Pod pod) {
Optional.ofNullable(info).ifPresent(i -> i.setServerPodFromEvent(getPodLabel(pod), pod));
}

private NextAction proceedFromWait(Packet packet, CallResponse<V1Pod> callResponse) {
callback.proceedFromWait(callResponse.getResult());
return doNext(packet);
}

private boolean shouldWait(DomainPresenceInfo info) {
return info == null || info.incrementAndGetWatchBackstopRecheckCount() <= getWatchBackstopRecheckCount();
}

private String getPodLabel(V1Pod pod) {
return Optional.ofNullable(pod)
.map(V1Pod::getMetadata)
.map(V1ObjectMeta::getLabels)
.map(m -> m.get(LabelConstants.SERVERNAME_LABEL))
.orElse(null);
}
};
}
}

private class WaitForPodReadyStep extends WaitForPodStatusStep {
Expand Down Expand Up @@ -360,6 +418,7 @@ protected void removeCallback(String podName, Consumer<V1Pod> callback) {
protected void logWaiting(String name) {
LOGGER.fine(MessageKeys.WAITING_FOR_POD_READY, name);
}

}

private class WaitForPodDeleteStep extends WaitForPodStatusStep {
Expand All @@ -383,4 +442,20 @@ protected void removeCallback(String podName, Consumer<V1Pod> callback) {
removeOnDeleteCallback(podName, callback);
}
}

private static class MakeRightDomainStep extends DefaultResponseStep {
MakeRightDomainStep(Step next) {
super(next);
}

@Override
public NextAction onSuccess(Packet packet, CallResponse callResponse) {
MakeRightDomainOperation makeRightDomainOperation =
Copy link
Member

Choose a reason for hiding this comment

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

I am not sure if it is always correct for all cases to use the existing MakeRightDomainOperation object. For example, if the original object has an EventData, we may not know if the event has been generated already or not in the previous attempt.

Copy link
Member Author

Choose a reason for hiding this comment

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

Thanks, Dongbo. That's a good point. In the latest integration test run, I'm seeing some new failures in ItKubernetesEvent and ItPodsRestart related to event generation. It looks like these failures are intermittent and timing-dependent. I'm not sure if I can create a new MakeRightDomainOperation object in this step. I'll continue looking into this tomorrow.

Copy link
Member

Choose a reason for hiding this comment

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

@doxiao, I'm not sure but I wouldn't be surprised if there are some bug in our flow. The intended design is that the operator could die at any code point and have a new operator start and have to recover. Therefore, it's a bug if any of our code paths depend on in-memory state. Since updating the Domain status and generated Events is not transactional then there may be some gaps that are impossible to close, but we should for instance be able to start a rolling, have the operator die, be restarted, and then have the new operator complete the roll and properly generate the rolling completed event. I see these timeouts as being analogous. If a wait timesout and the make-right loop goes back to the "top" then it ought to complete similarly.

Copy link
Member

Choose a reason for hiding this comment

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

Ryan, I agree with you that the operator's processing flow should not depend on in-memory states. We could review the flow to make sure that is the case. But the issue here is a little different, I think - we are reusing a DomainMakeRightOperation object to do a new execution. I don't think the operator does this prior to this PR. EventData is just one piece of the data in the MakeRightDomainOperation object. We are probably better off creating a new MakeRightDomainOperation; the new code here already overrides some of the data in the existing object prior to calling execute().

Copy link
Member

Choose a reason for hiding this comment

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

I'm not quite sure what you are proposing. What Anil and I originally discussed was to, on timeout, cancel the current fiber and start a new fiber for a new make-right operation. He found that he could instead take the current Fiber back to the top step using this pattern. That sounds reasonable. Is there just some other state in the current make right operation and/or Fiber that he needs to clear.

Copy link
Member

@doxiao doxiao Jun 9, 2021

Choose a reason for hiding this comment

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

My suggestion is to create a new MakeRightDomainOperation passing in the new DomainPresenceInfo, instead of reusing the current make right domain operation. This suggestion does not change the logic/spirit of the current changes. I discussed with Anil offline, and found out that apparently he had problem in creating a new make right domain operation instance within PodWatcher's static context. We could add a static method somewhere for this. For example, we could refactor the Main class a little and add a static factory method there for PodWatcher to use to create a new make right domain operation instance. What I like about using a new instance is that the code here would have full control of what it needs to do. Alternatively, we could have a clear() method on MakeRightDomainOperation to start clean if we know for sure there is no other fiber running using this make right domain operation instance. Then we have to keep the clear() method up-to-date when we add new variables into it in the future. I personally prefers the first option.

Copy link
Member Author

Choose a reason for hiding this comment

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

I have implemented the clear() method on MakeRightDomainOperation to reset its state before executing the new make-right operation in MakeRightDomainStep. Thanks.

(MakeRightDomainOperation)packet.get(MAKE_RIGHT_DOMAIN_OPERATION);
makeRightDomainOperation.setLiveInfo(new DomainPresenceInfo((Domain)callResponse.getResult()));
makeRightDomainOperation.withExplicitRecheck().interrupt().execute();
return super.onSuccess(packet, callResponse);
}
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -194,17 +194,20 @@ class WatchTuning {
public final int watchLifetime;
public final int watchMinimumDelay;
public final int watchBackstopRecheckDelay;
public final int watchBackstopRecheckCount;

/**
* Create watch tuning.
* @param watchLifetime Watch lifetime
* @param watchMinimumDelay Minimum delay before accepting new events to prevent hot loops
* @param watchBackstopRecheckDelay Recheck delay for get while waiting for a status to backstop missed watch events
*/
public WatchTuning(int watchLifetime, int watchMinimumDelay, int watchBackstopRecheckDelay) {
public WatchTuning(int watchLifetime, int watchMinimumDelay, int watchBackstopRecheckDelay,
int watchBackstopRecheckCount) {
this.watchLifetime = watchLifetime;
this.watchMinimumDelay = watchMinimumDelay;
this.watchBackstopRecheckDelay = watchBackstopRecheckDelay;
this.watchBackstopRecheckCount = watchBackstopRecheckCount;
}

@Override
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -75,7 +75,8 @@ private void update() {
new WatchTuning(
(int) readTuningParameter("watchLifetime", 300),
(int) readTuningParameter("watchMinimumDelay", 5),
(int) readTuningParameter("watchBackstopRecheckDelaySeconds", 5));
(int) readTuningParameter("watchBackstopRecheckDelaySeconds", 5),
(int) readTuningParameter("watchBackstopRecheckCount", 24));

PodTuning pod =
new PodTuning(
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,16 +4,12 @@
package oracle.kubernetes.operator;

import java.util.Optional;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.function.Consumer;

import io.kubernetes.client.openapi.models.V1ObjectMeta;
import io.kubernetes.client.openapi.models.V1Pod;
import oracle.kubernetes.operator.calls.CallResponse;
import oracle.kubernetes.operator.helpers.DomainPresenceInfo;
import oracle.kubernetes.operator.helpers.ResponseStep;
import oracle.kubernetes.operator.steps.DefaultResponseStep;
import oracle.kubernetes.operator.work.AsyncFiber;
import oracle.kubernetes.operator.work.NextAction;
import oracle.kubernetes.operator.work.Packet;
Expand All @@ -27,7 +23,9 @@
* @param <T> the type of resource handled by this step
*/
abstract class WaitForReadyStep<T> extends Step {

private static final int DEFAULT_RECHECK_SECONDS = 5;
private static final int DEFAULT_RECHECK_COUNT = 24;

static int getWatchBackstopRecheckDelaySeconds() {
return Optional.ofNullable(TuningParameters.getInstance())
Expand All @@ -36,6 +34,13 @@ static int getWatchBackstopRecheckDelaySeconds() {
.orElse(DEFAULT_RECHECK_SECONDS);
}

static int getWatchBackstopRecheckCount() {
return Optional.ofNullable(TuningParameters.getInstance())
.map(TuningParameters::getWatchTuning)
.map(t -> t.watchBackstopRecheckCount)
.orElse(DEFAULT_RECHECK_COUNT);
}

private final T initialResource;
private final String resourceName;

Expand Down Expand Up @@ -173,14 +178,16 @@ private void checkUpdatedResource(Packet packet, AsyncFiber fiber, Callback call
null);
}

private Step createReadAndIfReadyCheckStep(Callback callback) {
Step createReadAndIfReadyCheckStep(Callback callback) {
if (initialResource != null) {
return createReadAsyncStep(getName(), getNamespace(), getDomainUid(), resumeIfReady(callback));
} else {
return new ReadAndIfReadyCheckStep(getName(), callback, getNext());
return new ReadAndIfReadyCheckStep(getName(), callback, resumeIfReady(callback), getNext());
}
}

protected abstract ResponseStep resumeIfReady(Callback callback);

private String getNamespace() {
return getMetadata(initialResource).getNamespace();
}
Expand All @@ -193,53 +200,28 @@ public String getName() {
return initialResource != null ? getMetadata(initialResource).getName() : resourceName;
}

private DefaultResponseStep<T> resumeIfReady(Callback callback) {
return new DefaultResponseStep<>(null) {
@Override
public NextAction onSuccess(Packet packet, CallResponse<T> callResponse) {
if ((callResponse != null) && (callResponse.getResult() instanceof V1Pod)) {
V1Pod pod = (V1Pod) callResponse.getResult();
Optional.ofNullable(packet.getSpi(DomainPresenceInfo.class))
.ifPresent(i -> i.setServerPodFromEvent(getPodLabel(pod, LabelConstants.SERVERNAME_LABEL), pod));
}
if (isReady(callResponse.getResult())) {
callback.proceedFromWait(callResponse.getResult());
return doNext(packet);
}
return doDelay(createReadAndIfReadyCheckStep(callback), packet,
getWatchBackstopRecheckDelaySeconds(), TimeUnit.SECONDS);
}

private String getPodLabel(V1Pod pod, String labelName) {
return Optional.ofNullable(pod)
.map(V1Pod::getMetadata)
.map(V1ObjectMeta::getLabels)
.map(m -> m.get(labelName))
.orElse(null);
}
};
}

private class ReadAndIfReadyCheckStep extends Step {
private final Callback callback;
private final String resourceName;
private final ResponseStep responseStep;

ReadAndIfReadyCheckStep(String resourceName, Callback callback, Step next) {
ReadAndIfReadyCheckStep(String resourceName, Callback callback, ResponseStep responseStep, Step next) {
super(next);
this.callback = callback;
this.resourceName = resourceName;
this.responseStep = responseStep;
}

@Override
public NextAction apply(Packet packet) {
DomainPresenceInfo info = packet.getSpi(DomainPresenceInfo.class);
return doNext(createReadAsyncStep(resourceName, info.getNamespace(),
info.getDomainUid(), resumeIfReady(callback)), packet);
info.getDomainUid(), responseStep), packet);
}

}

private class Callback implements Consumer<T> {
class Callback implements Consumer<T> {
private final AsyncFiber fiber;
private final Packet packet;
private final AtomicBoolean didResume = new AtomicBoolean(false);
Expand All @@ -258,7 +240,7 @@ public void accept(T resource) {
}

// The resource has now either completed or failed, so we can continue processing.
private void proceedFromWait(T resource) {
void proceedFromWait(T resource) {
removeCallback(getName(), this);
if (mayResumeFiber()) {
handleResourceReady(fiber, packet, resource);
Expand Down
Loading