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