added trace logs

src/main/java/ru/nbch/credit_tracker/CreditTrackerApplication.java

@@ -3,21 +3,18 @@ package ru.nbch.credit_tracker;
 import org.springframework.boot.SpringApplication;
 import org.springframework.boot.autoconfigure.SpringBootApplication;
 import org.springframework.context.ConfigurableApplicationContext;
-import ru.nbch.credit_tracker.service.MonitoringService;
-import ru.nbch.credit_tracker.service.UpdateProcessingPackagesService;
-import ru.nbch.credit_tracker.service.UpdatingFlagsService;
 
 @SpringBootApplication
 public class CreditTrackerApplication {
 
 	public static void main(String[] args) {
 		ConfigurableApplicationContext ctx = SpringApplication.run(CreditTrackerApplication.class, args);
-		UpdateProcessingPackagesService updateProcessingPackagesService = ctx.getBean(UpdateProcessingPackagesService.class);
+//		UpdateProcessingPackagesService updateProcessingPackagesService = ctx.getBean(UpdateProcessingPackagesService.class);
-		MonitoringService monitoringService = ctx.getBean(MonitoringService.class);
+//		MonitoringService monitoringService = ctx.getBean(MonitoringService.class);
-		UpdatingFlagsService updatingFlagsService = ctx.getBean(UpdatingFlagsService.class);
+//		UpdatingFlagsService updatingFlagsService = ctx.getBean(UpdatingFlagsService.class);
-		updateProcessingPackagesService.run();
+//		updateProcessingPackagesService.run();
-		monitoringService.run();
+//		monitoringService.run();
-		updatingFlagsService.run();
+//		updatingFlagsService.run();
 	}
 
 }

src/main/java/ru/nbch/credit_tracker/facade/SignalFacade.java

@@ -84,6 +84,7 @@ public class SignalFacade {
     }
 
     public ResponseEntity<MonitoringSetupResponse> setupMonitoring(MultipartFile file) {
+        log.trace("Start processing file");
         // первичные валидации
         if (file.isEmpty() || !isZipFile(file)) {
             throw clientExcp(SignalError.ERROR_001, XmlErrorFormat.MonitoringError);
@@ -131,7 +132,9 @@ public class SignalFacade {
 
         // валидация xml
         try {
+            log.trace("Start validation");
             monitoringRequest = readAndValidateMonitoringRequest(filePath);
+            log.trace("End validation");
         } catch (Exception e) {
             CTUtil.removeFile(filePath);
             if (e.getCause() instanceof XMLStreamException) {
@@ -225,7 +228,9 @@ public class SignalFacade {
             try {
                 signalService.registerSubjects(filePath, packageId);
                 CTUtil.removeFile(filePath);
+                long start = System.currentTimeMillis();
                 SignalService.UpdateResult updateResult = signalService.updateSubjects(packageId, null);
+                log.trace("updateSubjects time: {}", System.currentTimeMillis() - start);
                 if (updateResult.isNoFidsFound()) {
                     log.info("No fids found for PackageId: {} PackageName: {}. Package status ON_MONITORING. No registration in signal service.", packageId, packageName);
                     signalService.updatePackageStatus(packageId, Status.ON_MONITORING);

src/main/java/ru/nbch/credit_tracker/service/SignalService.java

@@ -106,12 +106,15 @@ public class SignalService {
      * Обрабатывает все PhoneFidMap по packageId, выгружая их пачками и фильтруя по переданному фильтру
      */
     public UpdateResult updateSubjects(Integer packageId, Predicate<PhoneFidMap> filter) {
+        log.info("Start updating subjects. PackageId: {}", packageId);
         boolean updated = false;
         boolean noFidsFound = true;
         int offset = 0;
         List<PhoneFidMap> batch;
         do {
+            long start = System.currentTimeMillis();
             batch = phoneFidMapService.findFullPhoneFidMap(packageId, offset, batchSize);
+            log.trace("Select subject's batch took {} ms", System.currentTimeMillis() - start);
 
             List<PhoneFidMap> filteredItems;
             if (filter != null) {
@@ -133,6 +136,7 @@ public class SignalService {
 
             offset += batchSize;
         } while (!batch.isEmpty());
+        log.info("End updating subjects. PackageId: {}", packageId);
 
         return new UpdateResult(updated, noFidsFound);
     }
@@ -143,12 +147,17 @@ public class SignalService {
      */
     public boolean updateFlags(List<PhoneFidMap> subjects, Integer packageId) {
         log.info("Start calculating fids and flags for subjects batch. PackageId: {}", packageId);
+        long start = System.currentTimeMillis();
         Map<String, Integer> fidsMap = phoneService.findFidsPhoneData(subjects);
+        log.trace("findFidsPhoneData took {} ms", System.currentTimeMillis() - start);
         LocalDateTime calculatedAt = LocalDateTime.now();
         boolean fidsFound = fidsMap.values().stream().anyMatch(Objects::nonNull);
+        start = System.currentTimeMillis();
         Map<Integer, FlagsService.FlagsData> flagsDataMap = flagsService.findFlags(fidsMap.values().stream().filter(Objects::nonNull).toList());
+        log.trace("findFlags took {} ms", System.currentTimeMillis() - start);
         List<PhoneFidMap> subjectToUpdate = new ArrayList<>();
 
+        start = System.currentTimeMillis();
         subjects.forEach(subject -> {
             Integer fid = fidsMap.get("9" + subject.getPhone());
             if (fid != null) {
@@ -174,14 +183,16 @@ public class SignalService {
             }
             subjectToUpdate.add(subject);
         });
+        log.trace("Iteration by batch took {} ms", System.currentTimeMillis() - start);
 
         int updateBatchSize = batchSize / 9; // 9 параметров на одну запись для обновления. Максимальное количество параметров ~65000
+        start = System.currentTimeMillis();
         for (int j = 0; j < subjectToUpdate.size(); j += updateBatchSize) {
             int endIndex = Math.min(j + updateBatchSize, subjectToUpdate.size());
             phoneFidMapService.updatePhoneFidMaps(subjectToUpdate.subList(j, endIndex));
             log.trace("Updated fids and flags for subject's batch from: {} to: {}. Total count: {}. PackageId: {}", j, endIndex, subjectToUpdate.size(), packageId);
         }
-
+        log.trace("Updating subjects batch took {} ms", System.currentTimeMillis() - start);
         log.info("Finish calculating fids and flags for subjects. PackageId: {}. Batch size: {}", packageId, subjects.size());
 
         return fidsFound;
@@ -239,17 +250,25 @@ public class SignalService {
      * writer записывает пачку сразу в файл
      */
     private void buildPersons(Integer packageId, Consumer<List<Person>> writer) {
+        long start = System.currentTimeMillis();
         int offset = 0;
         List<PhoneFidMap> batch;
         do {
+            long startBatch = System.currentTimeMillis();
             batch = phoneFidMapService.findFullPhoneFidMap(packageId, offset, batchSize);
+            log.trace("findFullPhoneFidMap(buildPersons) time {} ms", System.currentTimeMillis() - startBatch);
+            startBatch = System.currentTimeMillis();
             List<Person> persons = findPersons(batch);
+            log.trace("findPersons(buildPersons) time {} ms", System.currentTimeMillis() - startBatch);
             if (!persons.isEmpty()) {
+                startBatch = System.currentTimeMillis();
                 writer.accept(persons); // записывает пачку Persons в файл
+                log.trace("Write batch (buildPersons) time {} ms", System.currentTimeMillis() - startBatch);
             }
             offset += batchSize;
         } while (!batch.isEmpty());
 
+        log.trace("buildPersons time {} ms", System.currentTimeMillis() - start);
     }
 
     /**
@@ -260,9 +279,12 @@ public class SignalService {
             return Collections.emptyList();
         }
         List<Person> persons = new ArrayList<>();
+        long start = System.currentTimeMillis();
         Map<Integer, PersonService.PersonData> personFidMap = personService.findPersonData(subjects.stream()
                 .map(PhoneFidMap::getFid)
                 .filter(Objects::nonNull).toList());
+        log.trace("findPersonData time {} ms", System.currentTimeMillis() - start);
+        start = System.currentTimeMillis();
         subjects.forEach(data -> {
             if (data.getFid() != null) {
                 PersonService.PersonData personData = personFidMap.get(data.getFid());
@@ -275,6 +297,7 @@ public class SignalService {
                 }
             }
         });
+        log.trace("Collecting persons time {} ms", System.currentTimeMillis() - start);
         return persons;
     }
 

src/main/java/ru/nbch/credit_tracker/service/indic/FlagsService.java

@@ -3,6 +3,7 @@ package ru.nbch.credit_tracker.service.indic;
 import lombok.AllArgsConstructor;
 import lombok.Getter;
 import lombok.Setter;
+import lombok.extern.slf4j.Slf4j;
 import org.springframework.stereotype.Service;
 import ru.nbch.credit_tracker.mapper.indic.FlagsMapper;
 
@@ -12,6 +13,7 @@ import java.util.List;
 import java.util.Map;
 import java.util.stream.Collectors;
 
+@Slf4j
 @Service
 public class FlagsService {
 
@@ -26,10 +28,18 @@ public class FlagsService {
             return new HashMap<>();
         }
         Map<Integer, FlagsData> result = new HashMap<>();
+        long start = System.currentTimeMillis();
+        log.trace("Fids count: {}", fids.size());
         Map<Integer, Integer> flags5000 = calcFlag5000(fids);
+        log.trace("calcFlag5000 time: {}", System.currentTimeMillis() - start);
+        start = System.currentTimeMillis();
         Map<Integer, Integer> flags90DaysByPastDueArrear = calcFlag90DaysByPastDueArrear(fids);
+        log.trace("flags90DaysByPastDueArrear time: {}", System.currentTimeMillis() - start);
+        start = System.currentTimeMillis();
         Map<Integer, Integer> flags90DaysByRuPaymt = calcFlag90DaysByRuPaymt(fids);
+        log.trace("calcFlag90DaysByRuPaymt time: {}", System.currentTimeMillis() - start);
 
+        start = System.currentTimeMillis();
         fids.forEach(fid -> {
             Integer flagDebt5000 = flags5000.get(fid);
             if (flagDebt5000 == null) {
@@ -45,7 +55,7 @@ public class FlagsService {
             }
             result.put(fid, new FlagsData(flagDebt5000, flag90days));
         });
-
+        log.trace("Iteration by fids batch and collecting map time: {}", System.currentTimeMillis() - start);
         return result;
     }
 
@@ -55,7 +65,10 @@ public class FlagsService {
      * Если ни по одному счёту условие не выполняется или счетов вообще не найдено, флаг = 0.
      */
     private Map<Integer, Integer> calcFlag5000(List<Integer> fids) {
-        return mapper.findFlagsDebt5000(fids).stream()
+        long start = System.currentTimeMillis();
+        List<FlagFidData> res = mapper.findFlagsDebt5000(fids);
+        log.trace("findFlagsDebt5000 time: {}", System.currentTimeMillis() - start);
+        return res.stream()
                 .collect(Collectors.toMap(FlagFidData::getFid, FlagFidData::getFlag,
                         (existing, replacement) -> {
                             if (existing == 1) {
@@ -72,8 +85,11 @@ public class FlagsService {
      * Если ни по одной записи условия не выполняются или записей вообще не найдено, флаг = 0.
      */
     private Map<Integer, Integer> calcFlag90DaysByPastDueArrear(List<Integer> fids) {
+        long start = System.currentTimeMillis();
         LocalDate yearAgo = LocalDate.now().minusYears(1);
-        return mapper.findFlag90ByPastDueArrear(fids, yearAgo).stream()
+        List<FlagFidData> res = mapper.findFlag90ByPastDueArrear(fids, yearAgo);
+        log.trace("findFlag90ByPastDueArrear time: {}", System.currentTimeMillis() - start);
+        return res.stream()
                 .collect(Collectors.toMap(FlagFidData::getFid, FlagFidData::getFlag,
                         (existing, replacement) -> {
                             if (existing == 1) {
@@ -85,8 +101,11 @@ public class FlagsService {
     }
 
     private Map<Integer, Integer> calcFlag90DaysByRuPaymt(List<Integer> fids) {
+        long start = System.currentTimeMillis();
         LocalDate yearAgo = LocalDate.now().minusYears(1);
-        return mapper.findFlag90ByRuPaymt(fids, yearAgo).stream()
+        List<FlagFidData> res = mapper.findFlag90ByRuPaymt(fids, yearAgo);
+        log.trace("findFlag90ByRuPaymt time: {}", System.currentTimeMillis() - start);
+        return res.stream()
                 .collect(Collectors.toMap(FlagFidData::getFid, FlagFidData::getFlag,
                         (existing, replacement) -> {
                             if (existing == 1) {

src/main/java/ru/nbch/credit_tracker/service/indic/PersonService.java

@@ -29,9 +29,14 @@ public class PersonService {
         if (fids.isEmpty()) {
             return new HashMap<>();
         }
+        log.trace("findPersonData: fids count: {}", fids.size());
         Map<Integer, PersonData> personDataMap = new HashMap<>();
+        long start = System.currentTimeMillis();
         Map<Integer, NameData> nameDataMap = findNameData(fids);
+        log.trace("findNameData time {} ms", System.currentTimeMillis() - start);
+        start = System.currentTimeMillis();
         Map<Integer, PassportData> passortDataMap = findPassportData(fids);
+        log.trace("findPassportData time {} ms", System.currentTimeMillis() - start);
 
 
         fids.forEach(fid -> {
@@ -49,8 +54,11 @@ public class PersonService {
 
 
     private Map<Integer, NameData> findNameData(List<Integer> fids) {
+        long start = System.currentTimeMillis();
         List<NameData> persons = mapper.findNameData(fids);
-        return persons.stream()
+        log.trace("findNameData(db) time {} ms", System.currentTimeMillis() - start);
+        start = System.currentTimeMillis();
+        Map<Integer, NameData> res =  persons.stream()
                 .collect(Collectors.toMap(NameData::getFid, nameData -> nameData,
                         (existing, replacement) -> {
                             LocalDate existingDate = existing.getFileSinceDate();
@@ -67,13 +75,18 @@ public class PersonService {
                                 return replacement;
                             }
                         }));
+        log.trace("findNameData(collecting) time {} ms", System.currentTimeMillis() - start);
+        return res;
     }
 
     private Map<Integer, PassportData> findPassportData(List<Integer> fids) {
         Map<Integer, PassportData> resultMap = new HashMap<>();
 
+        long start = System.currentTimeMillis();
         List<PassportData> passports = mapper.findPassportData(fids);
+        log.trace("findPassportData(db) time {} ms", System.currentTimeMillis() - start);
 
+        start = System.currentTimeMillis();
         Map<Integer, List<PassportData>> passportsMap = passports.stream()
                 .collect(Collectors.groupingBy(PassportData::getFid));
 
@@ -83,6 +96,7 @@ public class PersonService {
                 resultMap.put(fid, passport);
             }
         });
+        log.trace("findPassportData(collecting) time {} ms", System.currentTimeMillis() - start);
 
         return resultMap;
     }

src/main/java/ru/nbch/credit_tracker/service/indic/PhoneService.java

@@ -2,6 +2,7 @@ package ru.nbch.credit_tracker.service.indic;
 
 import lombok.Getter;
 import lombok.Setter;
+import lombok.extern.slf4j.Slf4j;
 import org.springframework.stereotype.Service;
 import ru.nbch.credit_tracker.entities.dto.PhoneFidMap;
 import ru.nbch.credit_tracker.mapper.indic.PhoneMapper;
@@ -13,6 +14,7 @@ import java.util.List;
 import java.util.Map;
 import java.util.stream.Collectors;
 
+@Slf4j
 @Service
 public class PhoneService {
 
@@ -27,8 +29,16 @@ public class PhoneService {
      * @return Map: key - номер телефона; value - fid
      */
     public Map<String, Integer> findFidsPhoneData(List<PhoneFidMap> subjects) {
+        long start = System.currentTimeMillis();
         List<String> phones = subjects.stream().map(subject -> "9" + subject.getPhone()).toList();
-        return convertFidsDataToMap(mapper.findFids(phones));
+        log.trace("Find fids phone data in {} ms", System.currentTimeMillis() - start);
+        start = System.currentTimeMillis();
+        List<FidsData> fidsData = mapper.findFids(phones);
+        log.trace("findFids {} ms", System.currentTimeMillis() - start);
+        start = System.currentTimeMillis();
+        Map<String, Integer> res = convertFidsDataToMap(fidsData);
+        log.trace("convertFidsDataToMap {} ms", System.currentTimeMillis() - start);
+        return res;
     }
 
     private Map<String, Integer> convertFidsDataToMap(List<FidsData> fidsData) {

src/main/java/ru/nbch/credit_tracker/service/signal/SignalRestService.java

@@ -69,8 +69,12 @@ public class SignalRestService {
      * @return true - если пакет успешно поставился на мониторинг. false - в противном случае
      */
     public boolean setupMonitoring(Integer packageId) throws Exception {
+        long start = System.currentTimeMillis();
         String path = signalService.writeSignals(packageId);
+        log.trace("writeSignals time {} ms", System.currentTimeMillis() - start);
+        start = System.currentTimeMillis();
         Resource request = compressFile(path);
+        log.trace("compressFile time {} ms", System.currentTimeMillis() - start);
 
         MultiValueMap<String, Resource> body = new LinkedMultiValueMap<>();
         body.add("file", request);

src/main/resources/logback.xml

@@ -63,18 +63,18 @@
     </appender>
 
     <!--SQL запросы и результаты их выполнения-->
-    <logger name="ru.nbch.credit_tracker.mapper" level="INFO" additivity="false">
+    <logger name="ru.nbch.credit_tracker.mapper" level="DEBUG" additivity="false">
         <appender-ref ref="FILE"/>
         <appender-ref ref="FILE-JSON"/>
     </logger>
 
-    <logger name="ru.nbch.credit_tracker.service" level="INFO" additivity="false">
+    <logger name="ru.nbch.credit_tracker.service" level="TRACE" additivity="false">
         <appender-ref ref="FILE"/>
         <appender-ref ref="FILE-JSON"/>
         <appender-ref ref="CONSOLE"/>
     </logger>
 
-    <logger name="ru.nbch.credit_tracker.facade" level="INFO" additivity="false">
+    <logger name="ru.nbch.credit_tracker.facade" level="TRACE" additivity="false">
         <appender-ref ref="FILE"/>
         <appender-ref ref="FILE-JSON"/>
         <appender-ref ref="CONSOLE"/>