feature-active-standby-management/src/main/java/org/onap/policy/drools/activestandby/PmStandbyStateChangeNotifier.java

   1 /*
   2  * ============LICENSE_START=======================================================
   3  * feature-active-standby-management
   4  * ================================================================================
   5  * Copyright (C) 2017-2019 AT&T Intellectual Property. All rights reserved.
   6  * ================================================================================
   7  * Licensed under the Apache License, Version 2.0 (the "License");
   8  * you may not use this file except in compliance with the License.
   9  * You may obtain a copy of the License at
  10  *
  11  *      http://www.apache.org/licenses/LICENSE-2.0
  12  *
  13  * Unless required by applicable law or agreed to in writing, software
  14  * distributed under the License is distributed on an "AS IS" BASIS,
  15  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  16  * See the License for the specific language governing permissions and
  17  * limitations under the License.
  18  * ============LICENSE_END=========================================================
  19  */
  20
  21 package org.onap.policy.drools.activestandby;
  22
  23 /*
  24  * Per MultiSite_v1-10.ppt:
  25  *
  26  * Extends the StateChangeNotifier class and overwrites the abstract handleStateChange() method to get state changes
  27  * and do the following:
  28  *
  29  * When the Standby Status changes (from providingservice) to hotstandby or coldstandby,
  30  * the Active/Standby selection algorithm must stand down if the PDP-D is currently the lead/active node
  31  * and allow another PDP-D to take over.  It must also call lock on all engines in the engine management.
  32  *
  33  * When the Standby Status changes from (hotstandby) to coldstandby, the Active/Standby algorithm must NOT assume
  34  * the active/lead role.
  35  *
  36  * When the Standby Status changes (from coldstandby or providingservice) to hotstandby,
  37  * the Active/Standby algorithm may assume the active/lead role if the active/lead fails.
  38  *
  39  * When the Standby Status changes to providingservice (from hotstandby or coldstandby) call unlock on all
  40  * engines in the engine management layer.
  41  */
  42 import java.util.Date;
  43 import java.util.Timer;
  44 import java.util.TimerTask;
  45
  46 import org.onap.policy.common.im.StateChangeNotifier;
  47 import org.onap.policy.common.im.StateManagement;
  48 import org.onap.policy.drools.system.PolicyEngine;
  49 import org.slf4j.Logger;
  50 import org.slf4j.LoggerFactory;
  51
  52 /*
  53  * Some background:
  54  *
  55  * Originally, there was a "StandbyStateChangeNotifier" that belonged to policy-core, and this class's
  56  * handleStateChange() method used to take care of invoking conn.standDownPdp().
  57  *
  58  * But testing revealed that when a state change to hot standby
  59  * occurred from a demote() operation, first the PMStandbyStateChangeNotifier.handleStateChange() method
  60  * would be invoked and then the StandbyStateChangeNotifier.handleStateChange() method would be invoked,
  61  * and this ordering was creating the following problem:
  62  *
  63  * When PMStandbyStateChangeNotifier.handleStateChange() was invoked it would take a long time to finish,
  64  * because it would result in SingleThreadedUebTopicSource.stop() being invoked, which can potentially do a
  65  * 5 second sleep for each controller being stopped.
  66  *
  67  * Meanwhile, as these controller stoppages and their associated sleeps were occurring, the election handler
  68  * would discover the demoted PDP in hotstandby (but still designated!) and promote it, resulting in the
  69  * standbyStatus going from hotstandby to providingservice.  So then, by the time that
  70  * PMStandbyStateChangeNotifier.handleStateChange() finished its work and
  71  * StandbyStateChangeNotifier.handleStateChange() started executing, the standbyStatus was no longer hotstandby
  72  * (as effected by the demote), but providingservice (as reset by the election handling logic) and
  73  * conn.standDownPdp() would not get called!
  74  *
  75  * To fix this bug, we consolidated StandbyStateChangeNotifier and PMStandbyStateChangeNotifier,
  76  * with the standDownPdp() always
  77  * being invoked prior to the TopicEndpoint.manager.lock().  In this way, when the election handling logic is invoked
  78  * during the controller stoppages, the PDP is in hotstandby and the standdown occurs.
  79  *
  80  */
  81 public class PmStandbyStateChangeNotifier extends StateChangeNotifier {
  82     // get an instance of logger
  83     private static final Logger logger = LoggerFactory.getLogger(PmStandbyStateChangeNotifier.class);
  84     private Timer delayActivateTimer;
  85     private int pdpUpdateInterval;
  86     private boolean isWaitingForActivation;
  87     private long startTimeWaitingForActivationMs;
  88     private long waitInterval;
  89     private boolean isNowActivating;
  90     private String previousStandbyStatus;
  91     public static final String NONE = "none";
  92     public static final String UNSUPPORTED = "unsupported";
  93     public static final String HOTSTANDBY_OR_COLDSTANDBY = "hotstandby_or_coldstandby";
  94
  95     /**
  96      * Constructor.
  97      *
  98      */
  99     public PmStandbyStateChangeNotifier() {
 100         pdpUpdateInterval =
 101                 Integer.parseInt(ActiveStandbyProperties.getProperty(ActiveStandbyProperties.PDP_UPDATE_INTERVAL));
 102         isWaitingForActivation = false;
 103         startTimeWaitingForActivationMs = new Date().getTime();
 104         // delay the activate so the DesignatedWaiter can run twice - give it an extra 2 seconds
 105         waitInterval = 2 * pdpUpdateInterval + 2000L;
 106         isNowActivating = false;
 107         previousStandbyStatus = PmStandbyStateChangeNotifier.NONE;
 108     }
 109
 110     @Override
 111     public void handleStateChange() {
 112         /*
 113          * A note on synchronization: This method is not synchronized because the caller,
 114          * stateManagememt, has synchronize all of its methods. Only one stateManagement operation
 115          * can occur at a time. Thus, only one handleStateChange() call will ever be made at a time.
 116          */
 117         if (logger.isDebugEnabled()) {
 118             logger.debug("handleStateChange: Entering, message={}, standbyStatus={}", super.getMessage(),
 119                     super.getStateManagement().getStandbyStatus());
 120         }
 121         String standbyStatus = super.getStateManagement().getStandbyStatus();
 122         String pdpId = ActiveStandbyProperties.getProperty(ActiveStandbyProperties.NODE_NAME);
 123
 124         if (logger.isDebugEnabled()) {
 125             logger.debug("handleStateChange: previousStandbyStatus = {}; standbyStatus = {}",
 126                     previousStandbyStatus, standbyStatus);
 127         }
 128
 129         if (standbyStatus == null || standbyStatus.equals(StateManagement.NULL_VALUE)) {
 130             if (logger.isDebugEnabled()) {
 131                 logger.debug("handleStateChange: standbyStatus is null; standing down PDP={}", pdpId);
 132             }
 133             if (previousStandbyStatus.equals(StateManagement.NULL_VALUE)) {
 134                 // We were just here and did this successfully
 135                 if (logger.isDebugEnabled()) {
 136                     logger.debug(
 137                         "handleStateChange: "
 138                         + "Is returning because standbyStatus is null and was previously 'null'; PDP={}",
 139                         pdpId);
 140                 }
 141                 return;
 142             }
 143             isWaitingForActivation = false;
 144             try {
 145                 try {
 146                     if (logger.isDebugEnabled()) {
 147                         logger.debug("handleStateChange: null:  cancelling delayActivationTimer.");
 148                     }
 149                     delayActivateTimer.cancel();
 150                 } catch (Exception e) {
 151                     if (logger.isInfoEnabled()) {
 152                         logger.info("handleStateChange: null no delayActivationTimer existed.", e);
 153                     }
 154                     // If you end of here, there was no active timer
 155                 }
 156                 // Only want to lock the endpoints, not the controllers.
 157                 PolicyEngine.manager.deactivate();
 158                 // The operation was fully successful, but you cannot assign it a real null value
 159                 // because later we might try to execute previousStandbyStatus.equals() and get
 160                 // a null pointer exception.
 161                 previousStandbyStatus = StateManagement.NULL_VALUE;
 162             } catch (Exception e) {
 163                 logger.warn("handleStateChange: standbyStatus == null caught exception: ", e);
 164             }
 165         } else if (standbyStatus.equals(StateManagement.HOT_STANDBY)
 166                 || standbyStatus.equals(StateManagement.COLD_STANDBY)) {
 167             if (logger.isDebugEnabled()) {
 168                 logger.debug("handleStateChange: standbyStatus={}; standing down PDP={}", standbyStatus, pdpId);
 169             }
 170             if (previousStandbyStatus.equals(PmStandbyStateChangeNotifier.HOTSTANDBY_OR_COLDSTANDBY)) {
 171                 // We were just here and did this successfully
 172                 if (logger.isDebugEnabled()) {
 173                     logger.debug("handleStateChange: Is returning because standbyStatus is {}"
 174                             + " and was previously {}; PDP= {}", standbyStatus, previousStandbyStatus, pdpId);
 175                 }
 176                 return;
 177             }
 178             isWaitingForActivation = false;
 179             try {
 180                 try {
 181                     if (logger.isDebugEnabled()) {
 182                         logger.debug(
 183                                 "handleStateChange: HOT_STNDBY || COLD_STANDBY:  cancelling delayActivationTimer.");
 184                     }
 185                     delayActivateTimer.cancel();
 186                 } catch (Exception e) {
 187                     if (logger.isDebugEnabled()) {
 188                         logger.debug("handleStateChange: HOT_STANDBY || COLD_STANDBY no delayActivationTimer existed.",
 189                                 e);
 190                     }
 191                     // If you end of here, there was no active timer
 192                 }
 193                 // Only want to lock the endpoints, not the controllers.
 194                 PolicyEngine.manager.deactivate();
 195                 // The operation was fully successful
 196                 previousStandbyStatus = PmStandbyStateChangeNotifier.HOTSTANDBY_OR_COLDSTANDBY;
 197             } catch (Exception e) {
 198                 logger.warn("handleStateChange: standbyStatus = {} caught exception: {}", standbyStatus, e.getMessage(),
 199                         e);
 200             }
 201
 202         } else if (standbyStatus.equals(StateManagement.PROVIDING_SERVICE)) {
 203             if (logger.isDebugEnabled()) {
 204                 logger.debug("handleStateChange: standbyStatus= {} scheduling activation of PDP={}", standbyStatus,
 205                         pdpId);
 206             }
 207             if (previousStandbyStatus.equals(StateManagement.PROVIDING_SERVICE)) {
 208                 // We were just here and did this successfully
 209                 if (logger.isDebugEnabled()) {
 210                     logger.debug("handleStateChange: Is returning because standbyStatus is {}"
 211                             + "and was previously {}; PDP={}", standbyStatus, previousStandbyStatus, pdpId);
 212                 }
 213                 return;
 214             }
 215             try {
 216                 // UnLock all the endpoints
 217                 if (logger.isDebugEnabled()) {
 218                     logger.debug("handleStateChange: standbyStatus={}; controllers must be unlocked.", standbyStatus);
 219                 }
 220                 /*
 221                  * Only endpoints should be unlocked. Controllers have not been locked. Because,
 222                  * sometimes, it is possible for more than one PDP-D to become active (race
 223                  * conditions) we need to delay the activation of the topic endpoint interfaces to
 224                  * give the election algorithm time to resolve the conflict.
 225                  */
 226                 if (logger.isDebugEnabled()) {
 227                     logger.debug("handleStateChange: PROVIDING_SERVICE isWaitingForActivation= {}",
 228                             isWaitingForActivation);
 229                 }
 230
 231                 // Delay activation for 2*pdpUpdateInterval+2000 ms in case of an election handler
 232                 // conflict.
 233                 // You could have multiple election handlers thinking they can take over.
 234
 235                 // First let's check that the timer has not died
 236                 if (isWaitingForActivation) {
 237                     if (logger.isDebugEnabled()) {
 238                         logger.debug("handleStateChange: PROVIDING_SERVICE isWaitingForActivation = {}",
 239                                 isWaitingForActivation);
 240                     }
 241                     long now = new Date().getTime();
 242                     long waitTimeMs = now - startTimeWaitingForActivationMs;
 243                     if (waitTimeMs > 3 * waitInterval) {
 244                         if (logger.isDebugEnabled()) {
 245                             logger.debug(
 246                                 "handleStateChange: PROVIDING_SERVICE looks like the activation wait timer may be hung,"
 247                                 + " waitTimeMs = {} and allowable waitInterval = {}"
 248                                 + " Checking whether it is currently in activation. isNowActivating = {}",
 249                                 waitTimeMs, waitInterval, isNowActivating);
 250                         }
 251                         // Now check that it is not currently executing an activation
 252                         if (!isNowActivating) {
 253                             if (logger.isDebugEnabled()) {
 254                                 logger.debug(
 255                                     "handleStateChange: PROVIDING_SERVICE looks like the activation wait timer died");
 256                             }
 257                             // This will assure the timer is cancelled and rescheduled.
 258                             isWaitingForActivation = false;
 259                         }
 260                     }
 261
 262                 }
 263
 264                 if (!isWaitingForActivation) {
 265                     try {
 266                         // Just in case there is an old timer hanging around
 267                         if (logger.isDebugEnabled()) {
 268                             logger.debug("handleStateChange: PROVIDING_SERVICE cancelling delayActivationTimer.");
 269                         }
 270                         delayActivateTimer.cancel();
 271                     } catch (Exception e) {
 272                         if (logger.isDebugEnabled()) {
 273                             logger.debug("handleStateChange: PROVIDING_SERVICE no delayActivationTimer existed.", e);
 274                         }
 275                         // If you end of here, there was no active timer
 276                     }
 277                     delayActivateTimer = new Timer();
 278                     // delay the activate so the DesignatedWaiter can run twice
 279                     delayActivateTimer.schedule(new DelayActivateClass(), waitInterval);
 280                     isWaitingForActivation = true;
 281                     startTimeWaitingForActivationMs = new Date().getTime();
 282                     if (logger.isDebugEnabled()) {
 283                         logger.debug("handleStateChange: PROVIDING_SERVICE scheduling delayActivationTimer in {} ms",
 284                                 waitInterval);
 285                     }
 286                 } else {
 287                     if (logger.isDebugEnabled()) {
 288                         logger.debug(
 289                                 "handleStateChange: PROVIDING_SERVICE delayActivationTimer is waiting for activation.");
 290                     }
 291                 }
 292
 293             } catch (Exception e) {
 294                 logger.warn("handleStateChange: PROVIDING_SERVICE standbyStatus == providingservice caught exception: ",
 295                         e);
 296             }
 297
 298         } else {
 299             logger.error("handleStateChange: Unsupported standbyStatus={}; standing down PDP={}", standbyStatus, pdpId);
 300             if (previousStandbyStatus.equals(PmStandbyStateChangeNotifier.UNSUPPORTED)) {
 301                 // We were just here and did this successfully
 302                 if (logger.isDebugEnabled()) {
 303                     logger.debug("handleStateChange: Is returning because standbyStatus is "
 304                             + "UNSUPPORTED and was previously {}; PDP={}", previousStandbyStatus, pdpId);
 305                 }
 306                 return;
 307             }
 308             // Only want to lock the endpoints, not the controllers.
 309             isWaitingForActivation = false;
 310             try {
 311                 try {
 312                     if (logger.isDebugEnabled()) {
 313                         logger.debug("handleStateChange: unsupported standbystatus:  cancelling delayActivationTimer.");
 314                     }
 315                     delayActivateTimer.cancel();
 316                 } catch (Exception e) {
 317                     if (logger.isDebugEnabled()) {
 318                         logger.debug("handleStateChange: unsupported standbystatus: no delayActivationTimer existed.",
 319                                 e);
 320                     }
 321                     // If you end of here, there was no active timer
 322                 }
 323                 PolicyEngine.manager.deactivate();
 324                 // We know the standbystatus is unsupported
 325                 previousStandbyStatus = PmStandbyStateChangeNotifier.UNSUPPORTED;
 326             } catch (Exception e) {
 327                 logger.warn("handleStateChange: Unsupported standbyStatus = {} " + "caught exception: {} ",
 328                         standbyStatus, e.getMessage(), e);
 329             }
 330         }
 331         if (logger.isDebugEnabled()) {
 332             logger.debug("handleStateChange: Exiting");
 333         }
 334     }
 335
 336     private class DelayActivateClass extends TimerTask {
 337
 338         private Object delayActivateLock = new Object();
 339
 340
 341         @Override
 342         public void run() {
 343             isNowActivating = true;
 344             try {
 345                 if (logger.isDebugEnabled()) {
 346                     logger.debug("DelayActivateClass.run: entry");
 347                 }
 348                 synchronized (delayActivateLock) {
 349                     PolicyEngine.manager.activate();
 350                     // The state change fully succeeded
 351                     previousStandbyStatus = StateManagement.PROVIDING_SERVICE;
 352                     // We want to set this to false here because the activate call can take a while
 353                     isWaitingForActivation = false;
 354                     isNowActivating = false;
 355                 }
 356                 if (logger.isDebugEnabled()) {
 357                     logger.debug("DelayActivateClass.run.exit");
 358                 }
 359             } catch (Exception e) {
 360                 isWaitingForActivation = false;
 361                 isNowActivating = false;
 362                 logger.warn("DelayActivateClass.run: caught an unexpected exception "
 363                         + "calling PolicyEngine.manager.activate: ", e);
 364             }
 365         }
 366     }
 367
 368     public String getPreviousStandbyStatus() {
 369         return previousStandbyStatus;
 370     }
 371 }