This document has been created to show performance of requisition initiate endpoint. The document contains:
The test was executed on the following machine:
Both OpenLMIS instance and PostgreSQL database are on the same machine. In the database there is about 99,096 requisitions in the RELEASE status. A user has only rights to create and authorize requisitions. In this test the user will try to create a new requisition for the given program and supervised facility. The following java options has been set for the requisition service to connect with the service by JMX:
-Dlogging.config=/config/log/logback.xml -Dflyway.locations=classpath:db/migration -Dcom.sun.management.jmxremote.port=9010 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.rmi.port=9010 -Djava.rmi.server.hostname=IP_ADDRESS
The endpoint is executed each time when a user clicks on Proceed button on Create/Authorize view and the status of a requisition is equal to "Not yet started". To display the button the user has to select Create/Authorize option in the navigation bar (in the Requisition section). On this view he or she has ability to select if want to create a requisition for home facility or supervised facility. For both cases the user has ability to select a program. After that the user has to click the Search button. The table will be shown and user will have ability to initiate a requisition for the last free period. A period is free when there is no a requisition for the given facility, program and period.
The above image presents execution time of the initiate endpoint. It took 34.85 seconds to initiate a new requisition. The request response is not used on UI. After response the UI move to other view (product grid view) which retrieve the initiated requisition one more time.
The following image presents a list of methods that has been used while the user initiate requisition. 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.
In the above example the initiate endpoint was executed in 34.85s. It takes about 21 seconds (another 21 seconds has been used by other endpoint) to retrieve single objects from the reference-data service. It's quite interesting that the service needed about 9 seconds to retrieve the last regular requisition. We create a single SQL query and execute it. The issue may be in fact that we join two tables and the join operation can be time consuming.
The following image presents only methods that has been executed with the initiate endpoint:
We can see that the check permission method was quite fast but still retrieving last regular requisition takes about 8 seconds.
The code that is used to create a new requisition is long and split into few methods and classes:
public RequisitionDto initiate(@RequestParam(value = "program") UUID program,
@RequestParam(value = "facility") UUID facility,
@RequestParam(value = "suggestedPeriod", required = false) UUID suggestedPeriod,
@RequestParam(value = "emergency") boolean emergency) {
if (null == facility || null == program) {
throw new ValidationMessageException(
new Message(MessageKeys.ERROR_INITIALIZE_MISSING_PARAMETERS));
}
permissionService.canInitRequisition(program, facility);
facilitySupportsProgramHelper.checkIfFacilitySupportsProgram(facility, program);
Requisition newRequisition = requisitionService
.initiate(program, facility, suggestedPeriod, emergency);
return requisitionDtoBuilder.build(newRequisition);
} |
Most important things:
public Requisition initiate(UUID programId, UUID facilityId, UUID suggestedPeriodId,
boolean emergency) {
Requisition requisition = RequisitionBuilder.newRequisition(
facilityId, programId, emergency);
requisition.setStatus(RequisitionStatus.INITIATED);
ProcessingPeriodDto period = periodService
.findPeriod(programId, facilityId, suggestedPeriodId, emergency);
requisition.setProcessingPeriodId(period.getId());
requisition.setNumberOfMonthsInPeriod(period.getDurationInMonths());
FacilityDto facility = facilityReferenceDataService.findOne(facilityId);
ProgramDto program = programReferenceDataService.findOne(programId);
Collection<ApprovedProductDto> approvedProducts =
approvedProductReferenceDataService.getApprovedProducts(
facility.getId(), program.getId(), true);
RequisitionTemplate requisitionTemplate = findRequisitionTemplate(programId);
int numberOfPreviousPeriodsToAverage;
List<Requisition> previousRequisitions;
// numberOfPeriodsToAverage is always >= 2 or null
if (requisitionTemplate.getNumberOfPeriodsToAverage() == null) {
numberOfPreviousPeriodsToAverage = 0;
previousRequisitions = getRecentRequisitions(requisition, 1);
} else {
numberOfPreviousPeriodsToAverage = requisitionTemplate.getNumberOfPeriodsToAverage() - 1;
previousRequisitions =
getRecentRequisitions(requisition, numberOfPreviousPeriodsToAverage);
}
if (numberOfPreviousPeriodsToAverage > previousRequisitions.size()) {
numberOfPreviousPeriodsToAverage = previousRequisitions.size();
}
ProofOfDeliveryDto pod = getProofOfDeliveryDto(emergency, requisition);
requisition.initiate(requisitionTemplate, approvedProducts, previousRequisitions,
numberOfPreviousPeriodsToAverage, pod, authenticationHelper.getCurrentUser().getId());
requisition.setAvailableNonFullSupplyProducts(approvedProductReferenceDataService
.getApprovedProducts(facility.getId(), program.getId(), false)
.stream()
.map(ap -> ap.getOrderable().getId())
.collect(Collectors.toSet()));
requisitionRepository.save(requisition);
return requisition;
} |
Most important things:
private List<Requisition> getRecentRequisitions(Requisition requisition, int amount) {
List<ProcessingPeriodDto> previousPeriods =
periodService.findPreviousPeriods(requisition.getProcessingPeriodId(), amount);
List<Requisition> recentRequisitions = new ArrayList<>();
for (ProcessingPeriodDto period : previousPeriods) {
List<Requisition> requisitionsByPeriod = getRequisitionsByPeriod(requisition, period);
if (!requisitionsByPeriod.isEmpty()) {
Requisition requisitionByPeriod = requisitionsByPeriod.get(0);
recentRequisitions.add(requisitionByPeriod);
}
}
return recentRequisitions;
} |
Most important things:
public ProcessingPeriodDto findPeriod(UUID programId, UUID facilityId, UUID suggestedPeriodId,
Boolean emergency) {
ProcessingPeriodDto period;
if (emergency) {
List<ProcessingPeriodDto> periods = getCurrentPeriods(programId, facilityId);
if (periods.isEmpty()) {
throw new ValidationMessageException(new Message(ERROR_INCORRECT_SUGGESTED_PERIOD));
}
period = periods.get(0);
} else {
period = findTheOldestPeriod(programId, facilityId);
}
if (period == null
|| (null != suggestedPeriodId && !suggestedPeriodId.equals(period.getId()))) {
throw new ValidationMessageException(new Message(
ERROR_PERIOD_SHOULD_BE_OLDEST_AND_NOT_ASSOCIATED));
}
Collection<ProcessingScheduleDto> schedules =
scheduleReferenceDataService.searchByProgramAndFacility(programId, facilityId);
if (schedules == null || schedules.isEmpty()) {
throw new ContentNotFoundMessageException(new Message(
ERROR_REQUISITION_GROUP_PROGRAM_SCHEDULE_WITH_PROGRAM_AND_FACILITY_NOT_FOUND));
}
ProcessingScheduleDto scheduleDto = schedules.iterator().next();
if (!scheduleDto.getId().equals(period.getProcessingSchedule().getId())) {
throw new ValidationMessageException(new Message(
ERROR_PERIOD_MUST_BELONG_TO_THE_SAME_SCHEDULE));
}
return period;
} |
Most important things:
public List<ProcessingPeriodDto> findPreviousPeriods(UUID periodId, int amount) {
// retrieve data from reference-data
ProcessingPeriodDto period = getPeriod(periodId);
if (null == period) {
return Collections.emptyList();
}
Collection<ProcessingPeriodDto> collection = search(
period.getProcessingSchedule().getId(), period.getStartDate()
);
if (null == collection || collection.isEmpty()) {
return Collections.emptyList();
}
// create a list...
List<ProcessingPeriodDto> list = new ArrayList<>(collection);
// ...remove the latest period from the list...
list.removeIf(p -> p.getId().equals(periodId));
// .. and sort elements by startDate property DESC.
list.sort((one, two) -> ObjectUtils.compare(two.getStartDate(), one.getStartDate()));
if (amount > list.size()) {
return list;
}
return list.subList(0, amount);
} |
Most important things:
Additional I checked the system usage when the requisition initiate endpoint is executed. This time I used our training server where there are more than 90,000 requisitions in RELEASED status. After 15 minutes a user gets 504 error message from backend. It seems like there is no big problem with CPU, disk, memory or network usage. There are two spikes in the CPU usage but they are quickly end. The disk and memory usage is on the same level during the initiation process. The network bandwidth shows that a lot of data have been received by the system while the OpenLMIS tried to create a new requisition for the given facility and program.
