DRAFT
Overview
This document has been created to show poor performance of requisition submit/save endpoints. It contains:
- an example execution of the endpoints on the UI,
- how long it took for methods in the requisition service to execute,
- where the endpoints take too much time,
- proposal solutions.
Test environment
The tests were executed on EC2 m4.large instance (except for visualvm samples which were captured locally). The selected requisition contains over 230 products, most of which were skipped.
Endpoint execution
After clicking "Submit" we can see the following requests being executed:
The ones worth noting are:
- PUT /api/requisitions/<id>, which took 22.86s
- POST /api/requisitions/<id>/submit, 20.54s
These are the endpoints we are interested in. Their responses contain over 1000 non full supply products and over 230 requisition line items. We will look into what took so long in the next paragraph.
- GET /api/requisitions/periodsForInitiate, 1.94s
- GET /api/requisitions/search, 1.9m
These endpoints are executed when the UI goes back to the previous state (Create/authorize list).
Scalyr also shows a spike in CPU, Network and Disk bandwidth usage:
Methods
The following images present a list of methods that have been used while saving and submitting the requisition. The requests were sent through Swagger UI and no other endpoints were called during that time. The visualvm tool has been used to capture those methods. The tool was configured to capture only methods from org.openlmis package and sub-packages in the requisition service.
Save
Submit
The above examples show that most of the time was consumed by RequisitionDtoBuilder to construct the response.
Code
RequisitionController
public RequisitionDto updateRequisition(@RequestBody RequisitionDto requisitionDto,
@PathVariable("id") UUID requisitionId) {
permissionService.canUpdateRequisition(requisitionId);
if (isNotTrue(isNull(requisitionDto.getId()))
&& isNotTrue(requisitionId.equals(requisitionDto.getId()))) {
throw new ValidationMessageException(new Message(ERROR_ID_MISMATCH));
}
Requisition requisitionToUpdate = requisitionRepository.findOne(requisitionId);
if (isNull(requisitionToUpdate)) {
throw new ContentNotFoundMessageException(new Message(
ERROR_REQUISITION_NOT_FOUND, requisitionId));
}
Requisition requisition = RequisitionBuilder.newRequisition(requisitionDto,
requisitionToUpdate.getTemplate(), requisitionToUpdate.getProgramId(),
requisitionToUpdate.getStatus());
requisition.setId(requisitionId);
requisitionVersionValidator.validateRequisitionTimestamps(
requisition, requisitionToUpdate
);
RequisitionStatus status = requisitionToUpdate.getStatus();
if (status != RequisitionStatus.APPROVED
&& status != RequisitionStatus.SKIPPED
&& status != RequisitionStatus.RELEASED) {
LOGGER.debug("Updating requisition with id: {}", requisitionId);
BindingResult bindingResult = new BeanPropertyBindingResult(requisition, REQUISITION);
draftValidator.validate(requisition, bindingResult);
if (bindingResult.hasErrors()) {
LOGGER.warn("Validation for requisition failed: {}", getErrors(bindingResult));
throw new BindingResultException(getErrors(bindingResult));
}
requisitionToUpdate.updateFrom(requisition,
stockAdjustmentReasonReferenceDataService.getStockAdjustmentReasonsByProgram(
requisitionToUpdate.getProgramId()), orderableReferenceDataService.findAll());
requisitionToUpdate = requisitionRepository.save(requisitionToUpdate);
LOGGER.debug("Saved requisition with id: " + requisitionToUpdate.getId());
return requisitionDtoBuilder.build(requisitionToUpdate);
} else {
throw new ValidationMessageException(new Message(ERROR_CANNOT_UPDATE_WITH_STATUS,
requisitionToUpdate.getStatus()));
}
}
Time consuming calls:
public RequisitionDto submitRequisition(@PathVariable("id") UUID requisitionId) {
permissionService.canSubmitRequisition(requisitionId);
Requisition requisition = requisitionRepository.findOne(requisitionId);
if (requisition == null) {
throw new ContentNotFoundMessageException(
new Message(MessageKeys.ERROR_REQUISITION_NOT_FOUND, requisitionId));
}
BindingResult bindingResult = new BeanPropertyBindingResult(requisition, REQUISITION);
validator.validate(requisition, bindingResult);
if (bindingResult.hasErrors()) {
LOGGER.warn("Validation for requisition failed: {}", getErrors(bindingResult));
throw new BindingResultException(getErrors(bindingResult));
}
facilitySupportsProgramHelper.checkIfFacilitySupportsProgram(requisition.getFacilityId(),
requisition.getProgramId());
LOGGER.debug("Submitting a requisition with id " + requisition.getId());
UserDto user = authenticationHelper.getCurrentUser();
requisition.submit(orderableReferenceDataService.findAll(), user.getId());
saveStatusMessage(requisition);
requisitionRepository.save(requisition);
requisitionStatusProcessor.statusChange(requisition);
LOGGER.debug("Requisition with id " + requisition.getId() + " submitted");
return requisitionDtoBuilder.build(requisition);
}
Time consuming calls:
RequisitionDtoBuilder
public RequisitionDto build(Requisition requisition) {
if (null == requisition) {
return null;
}
RequisitionDto requisitionDto = new RequisitionDto();
requisition.export(requisitionDto);
List<RequisitionLineItemDto> requisitionLineItemDtoList =
requisitionExportHelper.exportToDtos(requisition.getRequisitionLineItems());
requisitionDto.setTemplate(requisition.getTemplate());
requisitionDto.setFacility(facilityReferenceDataService.findOne(requisition.getFacilityId()));
requisitionDto.setProgram(programReferenceDataService.findOne(requisition.getProgramId()));
requisitionDto.setProcessingPeriod(periodService.getPeriod(
requisition.getProcessingPeriodId()));
requisitionDto.setRequisitionLineItems(requisitionLineItemDtoList);
if (null != requisition.getAvailableNonFullSupplyProducts()) {
requisitionDto.setAvailableNonFullSupplyProducts(
requisition.getAvailableNonFullSupplyProducts()
.stream()
.filter(Objects::nonNull)
.map(orderableReferenceDataService::findOne)
.collect(Collectors.toSet())
);
}
return requisitionDto;
}
Time consuming calls:
- Lines 87-95: Fetch each of requisition's non full supply products from reference data service one by one.
Solutions
- Return only relevant information about a requisition to the client: Do we really need to return non full supply products in the response of those endpoint? Perhaps we could keep this as a set of UUIDs instead of calling orderableReferenceDataService.findOne for each one of them,