...

• an example execution of the endpoint endpoints on the UI,
• how long it took for methods in the requisition service to execute,
• where the endpoint takes endpoints take too much time,
• proposal solutions.

...

Endpoint execution

After clicking "AuthorizeSubmit" we can see the following requests being executed:

Image RemovedImage Added

The ones worth noting are:

• GET PUT /api/requisitions/<id>, which takes 24.96s
  Is this really needed? The requisition was already fetched when entering the product gridtook 22.86s
• POST /api/requisitions/<id>/authorizesubmit,  2320.06s54s
  This is These are the endpoint endpoints we are interested in. The response contains 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.
  Image RemovedImage Added
  Image Added
  
  
• GET /api/requisitions/periodsForInitiate, 1.59s94s
  
• GET /api/requisitions/search, 1.3m9m
  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 image presents images present a list of methods that have been used while authorizing saving and submitting the requisition. The request was 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.Image Removed

Save

Image Added

Submit

Image Added

The above example shows that endpoint was executed in 21.40s, most of which (17.70s) was examples show that most of the time was consumed by RequisitionDtoBuilder to construct the response.Getting all orderables from reference data service took another 2,78s. 

Code

RequisitionController

public RequisitionDto authorizeRequisition(updateRequisition(@RequestBody RequisitionDto requisitionDto,
                                        @PathVariable("id") UUID requisitionId) {
  permissionService.canAuthorizeRequisitioncanUpdateRequisition(requisitionId);

  if (isNotTrue(isNull(requisitionDto.getId()))
   (configurationSettingService.getBoolValue("skipAuthorization"   && isNotTrue(requisitionId.equals(requisitionDto.getId()))) {
    throw new ValidationMessageException(new Message(ERROR_AUTHORIZATION_TO_BE_SKIPPEDID_MISMATCH));
  }

  Requisition requisitionrequisitionToUpdate = requisitionRepository.findOne(requisitionId);

  if (requisition == nullisNull(requisitionToUpdate)) {
    throw new ContentNotFoundMessageException(new Message(
       new Message(MessageKeys.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);
    validatordraftValidator.validate(requisition, bindingResult);

    if (bindingResult.hasErrors()) {
      LOGGER.warn("Validation for requisition failed: {}", getErrors(bindingResult));
      throw new BindingResultException(getErrors(bindingResult));
    }

 facilitySupportsProgramHelper.checkIfFacilitySupportsProgram(requisition.getFacilityId(),   requisitionToUpdate.updateFrom(requisition,
        stockAdjustmentReasonReferenceDataService.getStockAdjustmentReasonsByProgram(
            requisitionrequisitionToUpdate.getProgramId()), orderableReferenceDataService.findAll());

   UserDto userrequisitionToUpdate = authenticationHelperrequisitionRepository.getCurrentUsersave(requisitionToUpdate);

    LOGGER.debug("Saved requisition.authorize(orderableReferenceDataService.findAll(), user.getId( with id: " + requisitionToUpdate.getId());
    return requisitionDtoBuilder.build(requisitionToUpdate);
  } else {
    throw new ValidationMessageException(new Message(ERROR_CANNOT_UPDATE_WITH_STATUS,
        requisitionToUpdate.getStatus()));
  }
}

Time consuming calls:

• Line 313: Build the response dto.

public RequisitionDto submitRequisition(@PathVariable("id") UUID supervisoryNode requisitionId) {
  permissionService.canSubmitRequisition(requisitionId);
  Requisition requisition = supervisoryNodeReferenceDataService.findSupervisoryNode(
      requisition.getProgramId(), requisition.getFacilityId()).getId();
  requisition.setSupervisoryNodeId(supervisoryNode);
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 " + requisitionIdrequisition.getId() + " authorized.submitted");

  return requisitionDtoBuilder.build(requisition);
}

Time consuming calls:

• Line 537237: Fetch  Fetch all the orderables from reference data service.
• Line 549244: Build  Build the response dto.

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;
}

...

• Lines 87-95: Fetch each of requisition's non full supply products from reference data service one by one.

Solutions

Both save and submit:

• Return only relevant information about a requisition to the client: Do we really need to return non full supply products in the response of authorize endpointthose endpoints? Perhaps we could keep this as a set of UUIDs instead of calling orderableReferenceDataService.findOne for each one of them, Another solution would be to or, if really needed, create a batch endpoint that returns all of them at once

Submit:

• We could reuse products that were previously retrieved in RequisitionController. 
• Try not to fetch all the orderables, search them by facility/program instead.