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 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.slf4j.Logger;
  49 import org.slf4j.LoggerFactory;
  50 import org.onap.policy.drools.system.PolicyEngine;
  51
  52 /*
  53  * Some background:
  54  *
  55  * Originally, there was a "StandbyStateChangeNotifier" that belonged to policy-core, and this class's handleStateChange() method
  56  * used to take care of invoking conn.standDownPdp().   But testing revealed that when a state change to hot standby occurred
  57  * from a demote() operation, first the PMStandbyStateChangeNotifier.handleStateChange() method would be invoked and then the
  58  * StandbyStateChangeNotifier.handleStateChange() method would be invoked, and this ordering was creating the following problem:
  59  *
  60  * When PMStandbyStateChangeNotifier.handleStateChange() was invoked it would take a long time to finish, because it would result
  61  * in SingleThreadedUebTopicSource.stop() being invoked, which can potentially do a 5 second sleep for each controller being stopped.
  62  * Meanwhile, as these controller stoppages and their associated sleeps were occurring, the election handler would discover the
  63  * demoted PDP in hotstandby (but still designated!) and promote it, resulting in the standbyStatus going from hotstandby
  64  * to providingservice.  So then, by the time that PMStandbyStateChangeNotifier.handleStateChange() finished its work and
  65  * StandbyStateChangeNotifier.handleStateChange() started executing, the standbyStatus was no longer hotstandby (as effected by
  66  * the demote), but providingservice (as reset by the election handling logic) and conn.standDownPdp() would not get called!
  67  *
  68  * To fix this bug, we consolidated StandbyStateChangeNotifier and PMStandbyStateChangeNotifier, with the standDownPdp() always
  69  * being invoked prior to the TopicEndpoint.manager.lock().  In this way, when the election handling logic is invoked
  70  * during the controller stoppages, the PDP is in hotstandby and the standdown occurs.
  71  *
  72  */
  73 public class PMStandbyStateChangeNotifier extends StateChangeNotifier {
  74         // get an instance of logger
  75         private static final Logger  logger = LoggerFactory.getLogger(PMStandbyStateChangeNotifier.class);
  76         private Timer delayActivateTimer;
  77         private int pdpUpdateInterval;
  78         private boolean isWaitingForActivation;
  79         private long startTimeWaitingForActivationMs;
  80         private long waitInterval;
  81         private boolean isNowActivating;
  82         private String previousStandbyStatus;
  83         public static String NONE = "none";
  84         public static String UNSUPPORTED = "unsupported";
  85         public static String HOTSTANDBY_OR_COLDSTANDBY = "hotstandby_or_coldstandby";
  86
  87         public PMStandbyStateChangeNotifier(){
  88                 pdpUpdateInterval = Integer.parseInt(ActiveStandbyProperties.getProperty(ActiveStandbyProperties.PDP_UPDATE_INTERVAL));
  89                 isWaitingForActivation = false;
  90                 startTimeWaitingForActivationMs = new Date().getTime();
  91                 //delay the activate so the DesignatedWaiter can run twice - give it an extra 2 seconds
  92                 waitInterval = 2*pdpUpdateInterval + 2000;
  93                 isNowActivating=false;
  94                 previousStandbyStatus = PMStandbyStateChangeNotifier.NONE;
  95         }
  96
  97         @Override
  98         public void handleStateChange() {
  99                 /*
 100                  * A note on synchronization: This method is not synchronized because the caller, stateManagememt,
 101                  * has synchronize all of its methods. Only one stateManagement operation can occur at a time. Thus,
 102                  * only one handleStateChange() call will ever be made at a time.
 103                  */
 104                 if(logger.isInfoEnabled()){
 105                         if(logger.isDebugEnabled()){
 106                                 logger.debug("handleStateChange: Entering, message={}, standbyStatus={}",
 107                                                  super.getMessage(), super.getStateManagement().getStandbyStatus());
 108                         }
 109                 }
 110                 String standbyStatus = super.getStateManagement().getStandbyStatus();
 111                 String pdpId = ActiveStandbyProperties
 112                                 .getProperty(ActiveStandbyProperties.NODE_NAME);
 113
 114                 if(logger.isDebugEnabled()){
 115                         logger.debug("handleStateChange: previousStandbyStatus = {}"
 116                                 + "; standbyStatus = {}", previousStandbyStatus, standbyStatus);
 117                 }
 118
 119                 if (standbyStatus == null  || standbyStatus.equals(StateManagement.NULL_VALUE)) {
 120                         if(logger.isDebugEnabled()){
 121                                 logger.debug("handleStateChange: standbyStatus is null; standing down PDP={}", pdpId);
 122                         }
 123                         if(previousStandbyStatus.equals(StateManagement.NULL_VALUE)){
 124                                 //We were just here and did this successfully
 125                                 if(logger.isDebugEnabled()){
 126                                         logger.debug("handleStateChange: Is returning because standbyStatus is null and was previously 'null'; PDP={}", pdpId);
 127                                 }
 128                                 return;
 129                         }
 130                         isWaitingForActivation = false;
 131                         try{
 132                                 try{
 133                                         if(logger.isDebugEnabled()){
 134                                                 logger.debug("handleStateChange: null:  cancelling delayActivationTimer.");
 135                                         }
 136                                         delayActivateTimer.cancel();
 137                                 }catch(Exception e){
 138                                         if(logger.isInfoEnabled()){
 139                                                 logger.info("handleStateChange: null no delayActivationTimer existed.", e);
 140                                         }
 141                                         //If you end of here, there was no active timer
 142                                 }
 143                                 //Only want to lock the endpoints, not the controllers.
 144                                 PolicyEngine.manager.deactivate();
 145                                 //The operation was fully successful, but you cannot assign it a real null value
 146                                 //because later we might try to execute previousStandbyStatus.equals() and get
 147                                 //a null pointer exception.
 148                                 previousStandbyStatus = StateManagement.NULL_VALUE;
 149                         }catch(Exception e){
 150                                 logger.warn("handleStateChange: standbyStatus == null caught exception: ", e);
 151                         }
 152                 } else if (standbyStatus.equals(StateManagement.HOT_STANDBY) || standbyStatus.equals(StateManagement.COLD_STANDBY)) {
 153                         if(logger.isDebugEnabled()){
 154                                 logger.debug("handleStateChange: standbyStatus={}; standing down PDP={}", standbyStatus, pdpId);
 155                         }
 156                         if(previousStandbyStatus.equals(PMStandbyStateChangeNotifier.HOTSTANDBY_OR_COLDSTANDBY)){
 157                                 //We were just here and did this successfully
 158                                 if(logger.isDebugEnabled()){
 159                                         logger.debug("handleStateChange: Is returning because standbyStatus is {}"
 160                                                         + " and was previously {}; PDP= {}", standbyStatus, previousStandbyStatus, pdpId);
 161                                 }
 162                                 return;
 163                         }
 164                         isWaitingForActivation = false;
 165                         try{
 166                                 try{
 167                                         if(logger.isDebugEnabled()){
 168                                                 logger.debug("handleStateChange: HOT_STNDBY || COLD_STANDBY:  cancelling delayActivationTimer.");
 169                                         }
 170                                         delayActivateTimer.cancel();
 171                                 }catch(Exception e){
 172                                         if(logger.isDebugEnabled()){
 173                                                 logger.debug("handleStateChange: HOT_STANDBY || COLD_STANDBY no delayActivationTimer existed.", e);
 174                                         }
 175                                         //If you end of here, there was no active timer
 176                                 }
 177                                 //Only want to lock the endpoints, not the controllers.
 178                                 PolicyEngine.manager.deactivate();
 179                                 //The operation was fully successful
 180                                 previousStandbyStatus = PMStandbyStateChangeNotifier.HOTSTANDBY_OR_COLDSTANDBY;
 181                         }catch(Exception e){
 182                                 logger.warn("handleStateChange: standbyStatus = {} caught exception: {}", standbyStatus, e.getMessage(), e);
 183                         }
 184
 185                 } else if (standbyStatus.equals(StateManagement.PROVIDING_SERVICE)) {
 186                         if(logger.isDebugEnabled()){
 187                                 logger.debug("handleStateChange: standbyStatus= {} "
 188                                                 + "scheduling activation of PDP={}",standbyStatus, pdpId);
 189                         }
 190                         if(previousStandbyStatus.equals(StateManagement.PROVIDING_SERVICE)){
 191                                 //We were just here and did this successfully
 192                                 if(logger.isDebugEnabled()){
 193                                         logger.debug("handleStateChange: Is returning because standbyStatus is {}"
 194                                                         + "and was previously {}; PDP={}", standbyStatus, previousStandbyStatus, pdpId);
 195                                 }
 196                                 return;
 197                         }
 198                         try{
 199                                 //UnLock all the endpoints
 200                                 if(logger.isDebugEnabled()){
 201                                         logger.debug("handleStateChange: standbyStatus={}; controllers must be unlocked.",standbyStatus );
 202                                 }
 203                                 /*
 204                                  * Only endpoints should be unlocked. Controllers have not been locked.
 205                                  * Because, sometimes, it is possible for more than one PDP-D to become active (race conditions)
 206                                  * we need to delay the activation of the topic endpoint interfaces to give the election algorithm
 207                                  * time to resolve the conflict.
 208                                  */
 209                                 if(logger.isDebugEnabled()){
 210                                         logger.debug("handleStateChange: PROVIDING_SERVICE isWaitingForActivation= {}", isWaitingForActivation);
 211                                 }
 212
 213                                 //Delay activation for 2*pdpUpdateInterval+2000 ms in case of an election handler conflict.
 214                                 //You could have multiple election handlers thinking they can take over.
 215
 216                                  // First let's check that the timer has not died
 217                                 if(isWaitingForActivation){
 218                                         if(logger.isDebugEnabled()){
 219                                                 logger.debug("handleStateChange: PROVIDING_SERVICE isWaitingForActivation = {}", isWaitingForActivation);
 220                                         }
 221                                         long now = new Date().getTime();
 222                                         long waitTimeMs = now - startTimeWaitingForActivationMs;
 223                                         if(waitTimeMs > 3*waitInterval){
 224                                                 if(logger.isDebugEnabled()){
 225                                                         logger.debug("handleStateChange: PROVIDING_SERVICE looks like the activation wait timer may be hung,"
 226                                                                 + " waitTimeMs = {} and allowable waitInterval = {}"
 227                                                                 + " Checking whether it is currently in activation. isNowActivating = {}",
 228                                                                 waitTimeMs, waitInterval, isNowActivating);
 229                                                 }
 230                                                 //Now check that it is not currently executing an activation
 231                                                 if(!isNowActivating){
 232                                                         if(logger.isDebugEnabled()){
 233                                                                 logger.debug("handleStateChange: PROVIDING_SERVICE looks like the activation wait timer died");
 234                                                         }
 235                                                         // This will assure the timer is cancelled and rescheduled.
 236                                                         isWaitingForActivation = false;
 237                                                 }
 238                                         }
 239
 240                                 }
 241
 242                                 if(!isWaitingForActivation){
 243                                         try{
 244                                                 //Just in case there is an old timer hanging around
 245                                                 if(logger.isDebugEnabled()){
 246                                                         logger.debug("handleStateChange: PROVIDING_SERVICE cancelling delayActivationTimer.");
 247                                                 }
 248                                                 delayActivateTimer.cancel();
 249                                         }catch(Exception e){
 250                                                 if(logger.isDebugEnabled()){
 251                                                         logger.debug("handleStateChange: PROVIDING_SERVICE no delayActivationTimer existed.");
 252                                                 }
 253                                                 //If you end of here, there was no active timer
 254                                         }
 255                                         delayActivateTimer = new Timer();
 256                                         //delay the activate so the DesignatedWaiter can run twice
 257                                         delayActivateTimer.schedule(new DelayActivateClass(), waitInterval);
 258                                         isWaitingForActivation = true;
 259                                         startTimeWaitingForActivationMs = new Date().getTime();
 260                                         if(logger.isDebugEnabled()){
 261                                                 logger.debug("handleStateChange: PROVIDING_SERVICE scheduling delayActivationTimer in {} ms", waitInterval);
 262                                         }
 263                                 }else{
 264                                         if(logger.isDebugEnabled()){
 265                                                 logger.debug("handleStateChange: PROVIDING_SERVICE delayActivationTimer is waiting for activation.");
 266                                         }
 267                                 }
 268
 269                         }catch(Exception e){
 270                                 logger.warn("handleStateChange: PROVIDING_SERVICE standbyStatus == providingservice caught exception: ", e);
 271                         }
 272
 273                 } else {
 274                         logger.error("handleStateChange: Unsupported standbyStatus={}; standing down PDP={}", standbyStatus, pdpId);
 275                         if(previousStandbyStatus.equals(PMStandbyStateChangeNotifier.UNSUPPORTED)){
 276                                 //We were just here and did this successfully
 277                                 if(logger.isDebugEnabled()){
 278                                         logger.debug("handleStateChange: Is returning because standbyStatus is "
 279                                                 + "UNSUPPORTED and was previously {}; PDP={}", previousStandbyStatus, pdpId);
 280                                 }
 281                                 return;
 282                         }
 283                         //Only want to lock the endpoints, not the controllers.
 284                         isWaitingForActivation = false;
 285                         try{
 286                                 try{
 287                                         if(logger.isDebugEnabled()){
 288                                                 logger.debug("handleStateChange: unsupported standbystatus:  cancelling delayActivationTimer.");
 289                                         }
 290                                         delayActivateTimer.cancel();
 291                                 }catch(Exception e){
 292                                         if(logger.isDebugEnabled()){
 293                                                 logger.debug("handleStateChange: unsupported standbystatus: no delayActivationTimer existed.", e);
 294                                         }
 295                                         //If you end of here, there was no active timer
 296                                 }
 297                                 PolicyEngine.manager.deactivate();
 298                                 //We know the standbystatus is unsupported
 299                                 previousStandbyStatus = PMStandbyStateChangeNotifier.UNSUPPORTED;
 300                         }catch(Exception e){
 301                                 logger.warn("handleStateChange: Unsupported standbyStatus = {} "
 302                                                 + "caught exception: {} ",standbyStatus, e.getMessage(), e);
 303                         }
 304                 }
 305                 if(logger.isDebugEnabled()){
 306                         logger.debug("handleStateChange: Exiting");
 307                 }
 308         }
 309
 310         private class DelayActivateClass extends TimerTask{
 311
 312                 private Object delayActivateLock = new Object();
 313
 314
 315                 @Override
 316                 public void run() {
 317                         isNowActivating = true;
 318                         try{
 319                                 if(logger.isDebugEnabled()){
 320                                         logger.debug("DelayActivateClass.run: entry");
 321                                 }
 322                                 synchronized(delayActivateLock){
 323                                         PolicyEngine.manager.activate();
 324                                         // The state change fully succeeded
 325                                         previousStandbyStatus = StateManagement.PROVIDING_SERVICE;
 326                                         // We want to set this to false here because the activate call can take a while
 327                                         isWaitingForActivation = false;
 328                                         isNowActivating = false;
 329                                 }
 330                                 if(logger.isDebugEnabled()){
 331                                         logger.debug("DelayActivateClass.run.exit");
 332                                 }
 333                         }catch(Exception e){
 334                                 isWaitingForActivation = false;
 335                                 isNowActivating = false;
 336                                 logger.warn("DelayActivateClass.run: caught an unexpected exception "
 337                                                 + "calling PolicyEngine.manager.activate: ", e);
 338                         }
 339                 }
 340         }
 341
 342         public String getPreviousStandbyStatus(){
 343                 return previousStandbyStatus;
 344         }
 345 }