aa9b42a5a739908d05824275c9f2b672085894b2
[appc.git] / appc-dispatcher / appc-request-handler / appc-request-handler-core / src / main / java / org / onap / appc / requesthandler / impl / AbstractRequestHandlerImpl.java
1 /*-
2  * ============LICENSE_START=======================================================
3  * ONAP : APPC
4  * ================================================================================
5  * Copyright (C) 2017-2019 AT&T Intellectual Property. All rights reserved.
6  * ================================================================================
7  * Copyright (C) 2017 Amdocs
8  * =============================================================================
9  * Licensed under the Apache License, Version 2.0 (the "License");
10  * you may not use this file except in compliance with the License.
11  * You may obtain a copy of the License at
12  *
13  *      http://www.apache.org/licenses/LICENSE-2.0
14  *
15  * Unless required by applicable law or agreed to in writing, software
16  * distributed under the License is distributed on an "AS IS" BASIS,
17  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
18  * See the License for the specific language governing permissions and
19  * limitations under the License.
20  *
21  * ============LICENSE_END=========================================================
22  */
23
24 package org.onap.appc.requesthandler.impl;
25
26 import com.att.eelf.configuration.EELFLogger;
27 import com.att.eelf.configuration.EELFManager;
28 import org.apache.commons.lang.ObjectUtils;
29 import org.apache.commons.lang.StringUtils;
30 import org.onap.appc.configuration.Configuration;
31 import org.onap.appc.configuration.ConfigurationFactory;
32 import org.onap.appc.domainmodel.lcm.Flags;
33 import org.onap.appc.domainmodel.lcm.RequestContext;
34 import org.onap.appc.domainmodel.lcm.RequestStatus;
35 import org.onap.appc.domainmodel.lcm.ResponseContext;
36 import org.onap.appc.domainmodel.lcm.RuntimeContext;
37 import org.onap.appc.domainmodel.lcm.Status;
38 import org.onap.appc.domainmodel.lcm.TransactionRecord;
39 import org.onap.appc.domainmodel.lcm.VNFOperation;
40 import org.onap.appc.exceptions.APPCException;
41 import org.onap.appc.exceptions.InvalidInputException;
42 import org.onap.appc.executor.objects.LCMCommandStatus;
43 import org.onap.appc.executor.objects.Params;
44 import org.onap.appc.lockmanager.api.LockException;
45 import org.onap.appc.logging.LoggingConstants;
46 import org.onap.appc.logging.LoggingUtils;
47 import org.onap.appc.messageadapter.MessageAdapter;
48 import org.onap.appc.messageadapter.impl.MessageAdapterImpl;
49 import org.onap.appc.metricservice.MetricRegistry;
50 import org.onap.appc.metricservice.MetricService;
51 import org.onap.appc.metricservice.metric.DispatchingFuntionMetric;
52 import org.onap.appc.metricservice.metric.Metric;
53 import org.onap.appc.metricservice.metric.MetricType;
54 import org.onap.appc.metricservice.policy.PublishingPolicy;
55 import org.onap.appc.metricservice.publisher.LogPublisher;
56 import org.onap.appc.requesthandler.RequestHandler;
57 import org.onap.appc.requesthandler.exceptions.RequestValidationException;
58 import org.onap.appc.requesthandler.helper.RequestValidator;
59 import org.onap.appc.requesthandler.objects.RequestHandlerInput;
60 import org.onap.appc.requesthandler.objects.RequestHandlerOutput;
61 import org.onap.appc.transactionrecorder.TransactionRecorder;
62 import org.onap.appc.transactionrecorder.objects.TransactionConstants;
63 import org.osgi.framework.BundleContext;
64 import org.osgi.framework.FrameworkUtil;
65 import org.osgi.framework.ServiceReference;
66 import org.slf4j.MDC;
67
68 import java.net.InetAddress;
69 import java.net.UnknownHostException;
70 import java.text.SimpleDateFormat;
71 import java.time.Instant;
72 import java.util.Date;
73 import java.util.HashMap;
74 import java.util.Map;
75 import java.util.Properties;
76 import java.util.UUID;
77 import java.util.TimeZone;
78 import static com.att.eelf.configuration.Configuration.MDC_INSTANCE_UUID;
79 import static com.att.eelf.configuration.Configuration.MDC_KEY_REQUEST_ID;
80 import static com.att.eelf.configuration.Configuration.MDC_SERVER_FQDN;
81 import static com.att.eelf.configuration.Configuration.MDC_SERVER_IP_ADDRESS;
82 import static com.att.eelf.configuration.Configuration.MDC_SERVICE_INSTANCE_ID;
83 import static com.att.eelf.configuration.Configuration.MDC_SERVICE_NAME;
84
85 /**
86  * This class provides application logic for the Request/Response Handler Component.
87  */
88 public abstract class AbstractRequestHandlerImpl implements RequestHandler {
89
90     private RequestValidator requestValidator;
91
92     protected TransactionRecorder transactionRecorder;
93
94     private MessageAdapter messageAdapter;
95
96     static MetricRegistry metricRegistry;
97
98     private boolean isMetricEnabled = false;
99
100     protected final Configuration configuration = ConfigurationFactory.getConfiguration();
101
102     private final EELFLogger logger = EELFManager.getInstance().getLogger(AbstractRequestHandlerImpl.class);
103
104     AbstractRequestHandlerImpl() {
105         messageAdapter = new MessageAdapterImpl();
106         messageAdapter.init();
107         Properties properties = configuration.getProperties();
108         if (properties != null && properties.getProperty("metric.enabled") != null) {
109             isMetricEnabled = Boolean.valueOf(properties.getProperty("metric.enabled"));
110         }
111         if (isMetricEnabled) {
112             initMetric();
113         }
114     }
115
116     public void setTransactionRecorder(TransactionRecorder transactionRecorder) {
117         this.transactionRecorder = transactionRecorder;
118     }
119
120     public void setRequestValidator(RequestValidator requestValidator) {
121         this.requestValidator = requestValidator;
122     }
123
124     public void setMessageAdapter(MessageAdapter messageAdapter) {
125         this.messageAdapter = messageAdapter;
126     }
127
128     /**
129      * It receives requests from the north-bound REST API (Communication) Layer and
130      * performs following validations.
131      * 1. VNF exists in A&AI for the given targetID (VnfID)
132      * 2. For the current VNF  Orchestration Status, the command can be executed
133      * 3. For the given VNF type and Operation, there exists work-flow definition in the APPC database
134      * If any of the validation fails, it returns appropriate response     *
135      *
136      * @param input RequestHandlerInput object which contains request header and  other request parameters like
137      *              command , target Id , payload etc.
138      * @return response for request as enum with Return code and message.
139      */
140     @Override
141     public RequestHandlerOutput handleRequest(RequestHandlerInput input) {
142         if (logger.isTraceEnabled())
143             logger.trace("Entering to handleRequest with RequestHandlerInput = " + ObjectUtils.toString(input) + ")");
144         String errorMessage = null;
145         RequestStatus requestStatus;
146         TransactionRecord transactionRecord = createTransactionRecord(input);
147         RuntimeContext runtimeContext = createRuntimeContext(input, transactionRecord);
148         ResponseContext responseContext = createResponseContext(input);
149         runtimeContext.setResponseContext(responseContext);
150         RequestHandlerOutput output = new RequestHandlerOutput();
151         try {
152             transactionRecorder.store(transactionRecord);
153             requestValidator.validateRequest(runtimeContext);
154
155             setInitialLogProperties(input.getRequestContext());
156
157             handleRequest(runtimeContext);
158             output.setResponseContext(runtimeContext.getResponseContext());
159         } catch (RequestValidationException e) {
160             errorMessage = e.getMessage();
161             logger.error(errorMessage, e);
162             if (!StringUtils.isEmpty(e.getLogMessage()))
163                 storeErrorMessageToLog(runtimeContext, e.getTargetEntity(), e.getTargetService(), e.getLogMessage());
164             output = buildRequestHandlerOutput(e.getLcmCommandStatus(), e.getParams());
165         } catch (InvalidInputException e) {
166             logger.error("InvalidInputException : " + e.getMessage(), e);
167             errorMessage = e.getMessage() != null ? e.getMessage() : e.toString();
168             output = buildRequestHandlerOutput(LCMCommandStatus.INVALID_INPUT_PARAMETER, new Params().addParam
169                 ("errorMsg", errorMessage));
170         } catch (LockException e) {
171             logger.error("LockException : " + e.getMessage(), e);
172             Params params = new Params().addParam("errorMsg", e.getMessage());
173             fillStatus(runtimeContext, LCMCommandStatus.LOCKED_VNF_ID, params);
174             output = buildRequestHandlerOutput(LCMCommandStatus.LOCKED_VNF_ID, params);
175         } catch (Exception e) {
176             logger.error("Exception : " + e.getMessage(), e);
177             storeErrorMessageToLog(runtimeContext, "", "", "Exception = " + e.getMessage());
178             errorMessage = e.getMessage() != null ? e.getMessage() : e.toString();
179             Params params = new Params().addParam("errorMsg", errorMessage);
180             output = buildRequestHandlerOutput(LCMCommandStatus.UNEXPECTED_ERROR, params);
181         } finally {
182             final int statusCode = output.getResponseContext().getStatus().getCode();
183             if (statusCode == LCMCommandStatus.ACCEPTED.getResponseCode()) {
184                 requestStatus = RequestStatus.ACCEPTED;
185             } else if (statusCode == LCMCommandStatus.SUCCESS.getResponseCode()) {
186                 requestStatus = RequestStatus.SUCCESSFUL;
187                 if (isMetricEnabled)
188                     ((DispatchingFuntionMetric) metricRegistry.metric("DISPATCH_FUNCTION")).incrementAcceptedRequest();
189             } else {
190                 requestStatus = (statusCode == LCMCommandStatus.EXPIRED_REQUEST.getResponseCode()) ? RequestStatus
191                     .TIMEOUT : RequestStatus.REJECTED;
192                 if (isMetricEnabled)
193                     ((DispatchingFuntionMetric) metricRegistry.metric("DISPATCH_FUNCTION")).incrementRejectedRequest();
194             }
195             try {
196                 if (errorMessage != null && logger.isDebugEnabled())
197                     logger.debug("error occurred in handleRequest " + errorMessage);
198                 logger.debug("output.getResponseContext().getStatus().getCode():  " + statusCode);
199                 runtimeContext.setResponseContext(output.getResponseContext());
200             } finally {
201                 runtimeContext.getTransactionRecord().setRequestState(requestStatus);
202                 runtimeContext.getTransactionRecord().setResultCode(output.getResponseContext().getStatus().getCode());
203                 updateTransactionStatus(runtimeContext.getTransactionRecord());
204                 recordAndClearLogProperties(runtimeContext);
205             }
206         }
207         if (logger.isTraceEnabled()) {
208             logger.trace("Exiting from handleRequest with (RequestHandlerOutput = " +
209                 ObjectUtils.toString(output.getResponseContext()) + ")");
210         }
211         return output;
212     }
213
214     private ResponseContext createResponseContext(RequestHandlerInput input) {
215         final ResponseContext responseContext = new ResponseContext();
216         responseContext.setStatus(new Status());
217         responseContext.setAdditionalContext(new HashMap<>(4));
218         responseContext.setCommonHeader(input.getRequestContext().getCommonHeader());
219         return responseContext;
220     }
221
222     private void updateTransactionStatus(TransactionRecord record) {
223         Map<TransactionConstants.TRANSACTION_ATTRIBUTES, String> updateColumns = new HashMap<>();
224         if (!StringUtils.isBlank(record.getTargetType())) {
225             updateColumns.put(TransactionConstants.TRANSACTION_ATTRIBUTES.TARGET_TYPE, record.getTargetType());
226         }
227         updateColumns.put(TransactionConstants.TRANSACTION_ATTRIBUTES.STATE, record.getRequestState());
228         updateColumns.put(TransactionConstants.TRANSACTION_ATTRIBUTES.RESULT_CODE,
229                 String.valueOf(record.getResultCode()));
230         if (RequestStatus.valueOf(record.getRequestState()).isTerminal()) {
231             Date endTime = new Date();
232             updateColumns.put(TransactionConstants.TRANSACTION_ATTRIBUTES.END_TIME,
233                     dateToStringConverterMillis(endTime));
234         }
235         try {
236             transactionRecorder.update(record.getTransactionId(), record.getRequestId(), updateColumns);
237         } catch (APPCException e) {
238             logger.error("Error accessing database", e);
239         }
240     }
241
242     private RuntimeContext createRuntimeContext(RequestHandlerInput input, TransactionRecord transactionRecord) {
243         RuntimeContext runtimeContext;
244         runtimeContext = new RuntimeContext();
245         runtimeContext.setRequestContext(input.getRequestContext());
246         runtimeContext.setTimeStart(transactionRecord.getStartTime());
247         runtimeContext.setRpcName(input.getRpcName());
248         runtimeContext.setTransactionRecord(transactionRecord);
249         return runtimeContext;
250     }
251
252     private TransactionRecord createTransactionRecord(RequestHandlerInput input) {
253         Instant startTime = Instant.now();
254         TransactionRecord record = new TransactionRecord();
255         record.setTransactionId(UUID.randomUUID().toString());
256         record.setRequestState(RequestStatus.RECEIVED);
257         record.setRequestId(input.getRequestContext().getCommonHeader().getRequestId());
258         record.setSubRequestId(input.getRequestContext().getCommonHeader().getSubRequestId());
259         record.setOriginatorId(input.getRequestContext().getCommonHeader().getOriginatorId());
260         record.setOriginTimestamp(input.getRequestContext().getCommonHeader().getTimeStamp().toInstant());
261         record.setStartTime(startTime);
262         record.setOperation(VNFOperation.valueOf(input.getRequestContext().getAction().name()));
263         record.setTargetId(input.getRequestContext().getActionIdentifiers().getVnfId());
264         record.setVnfcName(input.getRequestContext().getActionIdentifiers().getVnfcName());
265         record.setVserverId(input.getRequestContext().getActionIdentifiers().getVserverId());
266         record.setVfModuleId(input.getRequestContext().getActionIdentifiers().getVfModuleId());
267         record.setServiceInstanceId(input.getRequestContext().getActionIdentifiers().getServiceInstanceId());
268         Flags.Mode mode;
269         if (input.getRequestContext().getCommonHeader().getFlags() != null &&
270             input.getRequestContext().getCommonHeader().getFlags().getMode() != null) {
271             mode = input.getRequestContext().getCommonHeader().getFlags().getMode();
272         } else {
273             mode = Flags.Mode.NORMAL;
274         }
275         record.setMode(mode);
276         return record;
277     }
278
279     private void recordAndClearLogProperties(RuntimeContext runtimeContext) {
280         storeAuditLogRecord(runtimeContext);
281         storeMetricLogRecord(runtimeContext);
282         clearRequestLogProperties();
283     }
284
285     void storeErrorMessageToLog(RuntimeContext runtimeContext, String targetEntity, String targetServiceName,
286                                 String additionalMessage) {
287         LoggingUtils.logErrorMessage(runtimeContext.getResponseContext().getStatus() != null ?
288                 String.valueOf(runtimeContext.getResponseContext().getStatus().getCode()) : "",
289             runtimeContext.getResponseContext().getStatus() != null ?
290                 String.valueOf(runtimeContext.getResponseContext().getStatus().getMessage()) : "",
291             targetEntity,
292             targetServiceName,
293             additionalMessage,
294             this.getClass().getCanonicalName());
295     }
296
297     protected abstract void handleRequest(RuntimeContext runtimeContext);
298
299     void fillStatus(RuntimeContext runtimeContext, LCMCommandStatus lcmCommandStatus, Params params) {
300         runtimeContext.getResponseContext().getStatus().setCode(lcmCommandStatus.getResponseCode());
301         runtimeContext.getResponseContext().getStatus().setMessage(lcmCommandStatus.getFormattedMessage(params));
302     }
303
304     private void clearRequestLogProperties() {
305         try {
306             MDC.remove(MDC_KEY_REQUEST_ID);
307             MDC.remove(MDC_SERVICE_INSTANCE_ID);
308             MDC.remove(MDC_SERVICE_NAME);
309             MDC.remove(LoggingConstants.MDCKeys.PARTNER_NAME);
310             MDC.remove(LoggingConstants.MDCKeys.TARGET_VIRTUAL_ENTITY);
311         } catch (Exception e) {
312             logger.error("Error clearing MDC log properties. " + e.getMessage(), e);
313         }
314     }
315
316     private void setInitialLogProperties(RequestContext requestContext) {
317
318         try {
319             MDC.put(MDC_KEY_REQUEST_ID, requestContext.getCommonHeader().getRequestId());
320             if (requestContext.getActionIdentifiers().getServiceInstanceId() != null) {
321                 MDC.put(MDC_SERVICE_INSTANCE_ID, requestContext.getActionIdentifiers().getServiceInstanceId());
322             }
323             MDC.put(LoggingConstants.MDCKeys.PARTNER_NAME, requestContext.getCommonHeader().getOriginatorId());
324             MDC.put(MDC_INSTANCE_UUID, ""); // value should be created in the future
325             //Don't change it to a.getHostName() again please. It's wrong!
326             MDC.put(MDC_SERVER_FQDN, InetAddress.getLocalHost().getCanonicalHostName());
327             MDC.put(MDC_SERVER_IP_ADDRESS, InetAddress.getLocalHost().getHostAddress());
328             MDC.put(LoggingConstants.MDCKeys.SERVER_NAME, InetAddress.getLocalHost().getHostName());
329             MDC.put(MDC_SERVICE_NAME, requestContext.getAction().name());
330             MDC.put(LoggingConstants.MDCKeys.TARGET_VIRTUAL_ENTITY, requestContext.getActionIdentifiers().getVnfId());
331         } catch (UnknownHostException e) {
332             logger.error("Error occured while setting initial log properties", e);
333         }
334     }
335
336     private static RequestHandlerOutput buildRequestHandlerOutput(LCMCommandStatus response, Params params) {
337         RequestHandlerOutput output = new RequestHandlerOutput();
338         ResponseContext responseContext = new ResponseContext();
339         org.onap.appc.domainmodel.lcm.Status status = new org.onap.appc.domainmodel.lcm.Status();
340         status.setCode(response.getResponseCode());
341         status.setMessage(response.getFormattedMessage(params));
342         responseContext.setStatus(status);
343         output.setResponseContext(responseContext);
344         return output;
345     }
346
347     /**
348      * This method perform following operations required after execution of workflow.
349      * It posts asynchronous response to message bus (DMaaP).
350      * Unlock VNF Id
351      * Removes request from request registry.
352      * Generate audit logs.
353      * Adds transaction record to database id if transaction logging is enabled.
354      */
355     @Override
356     public void onRequestExecutionEnd(RuntimeContext runtimeContext) {
357         if (logger.isTraceEnabled()) {
358             logger.trace("Entering to onRequestExecutionEnd with runtimeContext = " +
359                 ObjectUtils.toString(runtimeContext));
360         }
361         postMessageToDMaaP(runtimeContext.getRequestContext().getAction(), runtimeContext.getRpcName(),
362             runtimeContext.getResponseContext());
363         final int statusCode = runtimeContext.getResponseContext().getStatus().getCode();
364         RequestStatus requestStatus =
365             (statusCode == LCMCommandStatus.SUCCESS.getResponseCode()) ?
366                 RequestStatus.SUCCESSFUL : RequestStatus.FAILED;
367         runtimeContext.getTransactionRecord().setRequestState(requestStatus);
368         runtimeContext.getTransactionRecord().setResultCode(runtimeContext.getResponseContext().getStatus().getCode());
369         updateTransactionStatus(runtimeContext.getTransactionRecord());
370         storeAuditLogRecord(runtimeContext);
371     }
372
373     private void storeAuditLogRecord(RuntimeContext runtimeContext) {
374         LoggingUtils.logAuditMessage(runtimeContext.getTimeStart(),
375             Instant.now(),
376             String.valueOf(runtimeContext.getResponseContext().getStatus().getCode()),
377             runtimeContext.getResponseContext().getStatus().getMessage(),
378             this.getClass().getCanonicalName());
379     }
380
381     private void storeMetricLogRecord(RuntimeContext runtimeContext) {
382         LoggingUtils.logMetricsMessage(runtimeContext.getTimeStart(),
383             Instant.now(),
384             LoggingConstants.TargetNames.APPC,
385             runtimeContext.getRequestContext().getAction().name(),
386             runtimeContext.getResponseContext().getStatus().getCode() == LCMCommandStatus.ACCEPTED.getResponseCode()
387                 ? LoggingConstants.StatusCodes.COMPLETE : LoggingConstants.StatusCodes.ERROR,
388             String.valueOf(runtimeContext.getResponseContext().getStatus().getCode()),
389             runtimeContext.getResponseContext().getStatus().getMessage(),
390             this.getClass().getCanonicalName());
391     }
392
393     private void postMessageToDMaaP(VNFOperation operation, String rpcName, ResponseContext responseContext) {
394         if (logger.isTraceEnabled()) {
395             logger.trace("Entering to postMessageToDMaaP with AsyncResponse = " +
396                 ObjectUtils.toString(responseContext));
397         }
398         logger.debug("In postMessageToDMaap before invoking post()");
399         boolean callbackResponse = messageAdapter.post(operation, rpcName, responseContext);
400         logger.debug("In postMessageToDMaap after invoking post()");
401         if (!callbackResponse) {
402             logger.error("DMaaP posting status: false", "dmaapMessage: " + responseContext);
403         }
404         if (logger.isTraceEnabled())
405             logger.trace("Exiting from postMessageToDMaaP with (callbackResponse = " +
406                 ObjectUtils.toString(callbackResponse) + ")");
407     }
408
409     private void initMetric() {
410         if (logger.isDebugEnabled())
411             logger.debug("Metric getting initialized");
412         MetricService metricService = getMetricservice();
413         // Check for the metric service created before trying to create registry using
414         // the metricService object
415         if (metricService == null) {
416             // Cannot find service reference for org.onap.appc.metricservice.MetricService
417             throw new NullPointerException("org.onap.appc.metricservice.MetricService is null. " +
418                     "Failed to init Metric");
419         }
420         metricRegistry = metricService.createRegistry("APPC");
421         DispatchingFuntionMetric dispatchingFuntionMetric = metricRegistry.metricBuilderFactory().
422             dispatchingFunctionCounterBuilder().
423             withName("DISPATCH_FUNCTION").withType(MetricType.COUNTER).
424             withAcceptRequestValue(0)
425             .withRejectRequestValue(0)
426             .build();
427         if (metricRegistry.register(dispatchingFuntionMetric)) {
428             Metric[] metrics = new Metric[]{dispatchingFuntionMetric};
429             LogPublisher logPublisher = new LogPublisher(metricRegistry, metrics);
430             LogPublisher[] logPublishers = new LogPublisher[1];
431             logPublishers[0] = logPublisher;
432             PublishingPolicy manuallyScheduledPublishingPolicy = metricRegistry.policyBuilderFactory()
433                 .scheduledPolicyBuilder()
434                 .withPublishers(logPublishers)
435                 .withMetrics(metrics)
436                 .build();
437
438             if (logger.isDebugEnabled())
439                 logger.debug("Policy getting initialized");
440             manuallyScheduledPublishingPolicy.init();
441             if (logger.isDebugEnabled())
442                 logger.debug("Metric initialized");
443         }
444     }
445
446     private MetricService getMetricservice() {
447         BundleContext bctx = FrameworkUtil.getBundle(MetricService.class).getBundleContext();
448         ServiceReference sref = bctx.getServiceReference(MetricService.class.getName());
449         if (sref != null) {
450             logger.info("Metric Service from bundlecontext");
451             return (MetricService) bctx.getService(sref);
452         } else {
453             logger.info("Metric Service error from bundlecontext");
454             logger.warn("Cannot find service reference for org.onap.appc.metricservice.MetricService");
455             return null;
456         }
457     }
458
459     /**
460      * This method returns the count of in progress requests
461      * * @return in progress requests count
462      */
463     @Override
464     public int getInprogressRequestCount() throws APPCException {
465         if (logger.isTraceEnabled()) {
466             logger.trace("Entering to getInprogressRequestCount");
467         }
468         return transactionRecorder.getInProgressRequestsCount();
469     }
470
471     public static String dateToStringConverterMillis(Date date) {
472         SimpleDateFormat customDate = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
473         customDate.setTimeZone(TimeZone.getTimeZone("UTC"));
474         if (date != null) {
475             return customDate.format(date);
476         }
477         return null;
478     }
479 }