From 254b13827b0eff9bd416e139c64f6d43ef7c2b3a Mon Sep 17 00:00:00 2001 From: Mikhail Trofimov Date: Fri, 19 Sep 2025 14:27:47 +0300 Subject: [PATCH] added trace logs --- .../CreditTrackerApplication.java | 15 +++++------ .../credit_tracker/facade/SignalFacade.java | 5 ++++ .../credit_tracker/service/SignalService.java | 25 ++++++++++++++++- .../service/indic/FlagsService.java | 27 ++++++++++++++++--- .../service/indic/PersonService.java | 15 ++++++++++- .../service/indic/PhoneService.java | 9 ++++++- .../service/signal/SignalRestService.java | 4 +++ src/main/resources/logback.xml | 6 ++--- 8 files changed, 87 insertions(+), 19 deletions(-) diff --git a/src/main/java/ru/nbch/credit_tracker/CreditTrackerApplication.java b/src/main/java/ru/nbch/credit_tracker/CreditTrackerApplication.java index d3a78f1..891ec93 100644 --- a/src/main/java/ru/nbch/credit_tracker/CreditTrackerApplication.java +++ b/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); - MonitoringService monitoringService = ctx.getBean(MonitoringService.class); - UpdatingFlagsService updatingFlagsService = ctx.getBean(UpdatingFlagsService.class); - updateProcessingPackagesService.run(); - monitoringService.run(); - updatingFlagsService.run(); +// UpdateProcessingPackagesService updateProcessingPackagesService = ctx.getBean(UpdateProcessingPackagesService.class); +// MonitoringService monitoringService = ctx.getBean(MonitoringService.class); +// UpdatingFlagsService updatingFlagsService = ctx.getBean(UpdatingFlagsService.class); +// updateProcessingPackagesService.run(); +// monitoringService.run(); +// updatingFlagsService.run(); } } diff --git a/src/main/java/ru/nbch/credit_tracker/facade/SignalFacade.java b/src/main/java/ru/nbch/credit_tracker/facade/SignalFacade.java index 218a1c8..9a34e84 100644 --- a/src/main/java/ru/nbch/credit_tracker/facade/SignalFacade.java +++ b/src/main/java/ru/nbch/credit_tracker/facade/SignalFacade.java @@ -84,6 +84,7 @@ public class SignalFacade { } public ResponseEntity 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); diff --git a/src/main/java/ru/nbch/credit_tracker/service/SignalService.java b/src/main/java/ru/nbch/credit_tracker/service/SignalService.java index 138a075..3c06fa2 100644 --- a/src/main/java/ru/nbch/credit_tracker/service/SignalService.java +++ b/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 filter) { + log.info("Start updating subjects. PackageId: {}", packageId); boolean updated = false; boolean noFidsFound = true; int offset = 0; List batch; do { + long start = System.currentTimeMillis(); batch = phoneFidMapService.findFullPhoneFidMap(packageId, offset, batchSize); + log.trace("Select subject's batch took {} ms", System.currentTimeMillis() - start); List 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 subjects, Integer packageId) { log.info("Start calculating fids and flags for subjects batch. PackageId: {}", packageId); + long start = System.currentTimeMillis(); Map 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 flagsDataMap = flagsService.findFlags(fidsMap.values().stream().filter(Objects::nonNull).toList()); + log.trace("findFlags took {} ms", System.currentTimeMillis() - start); List 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> writer) { + long start = System.currentTimeMillis(); int offset = 0; List 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 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 persons = new ArrayList<>(); + long start = System.currentTimeMillis(); Map 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; } diff --git a/src/main/java/ru/nbch/credit_tracker/service/indic/FlagsService.java b/src/main/java/ru/nbch/credit_tracker/service/indic/FlagsService.java index f2bafa2..147519e 100644 --- a/src/main/java/ru/nbch/credit_tracker/service/indic/FlagsService.java +++ b/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 result = new HashMap<>(); + long start = System.currentTimeMillis(); + log.trace("Fids count: {}", fids.size()); Map flags5000 = calcFlag5000(fids); + log.trace("calcFlag5000 time: {}", System.currentTimeMillis() - start); + start = System.currentTimeMillis(); Map flags90DaysByPastDueArrear = calcFlag90DaysByPastDueArrear(fids); + log.trace("flags90DaysByPastDueArrear time: {}", System.currentTimeMillis() - start); + start = System.currentTimeMillis(); Map 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 calcFlag5000(List fids) { - return mapper.findFlagsDebt5000(fids).stream() + long start = System.currentTimeMillis(); + List 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 calcFlag90DaysByPastDueArrear(List fids) { + long start = System.currentTimeMillis(); LocalDate yearAgo = LocalDate.now().minusYears(1); - return mapper.findFlag90ByPastDueArrear(fids, yearAgo).stream() + List 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 calcFlag90DaysByRuPaymt(List fids) { + long start = System.currentTimeMillis(); LocalDate yearAgo = LocalDate.now().minusYears(1); - return mapper.findFlag90ByRuPaymt(fids, yearAgo).stream() + List 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) { diff --git a/src/main/java/ru/nbch/credit_tracker/service/indic/PersonService.java b/src/main/java/ru/nbch/credit_tracker/service/indic/PersonService.java index ece472c..a64a943 100644 --- a/src/main/java/ru/nbch/credit_tracker/service/indic/PersonService.java +++ b/src/main/java/ru/nbch/credit_tracker/service/indic/PersonService.java @@ -30,8 +30,12 @@ public class PersonService { return new HashMap<>(); } Map personDataMap = new HashMap<>(); + long start = System.currentTimeMillis(); Map nameDataMap = findNameData(fids); + log.trace("findNameData time {} ms", System.currentTimeMillis() - start); + start = System.currentTimeMillis(); Map passortDataMap = findPassportData(fids); + log.trace("findPassportData time {} ms", System.currentTimeMillis() - start); fids.forEach(fid -> { @@ -49,8 +53,11 @@ public class PersonService { private Map findNameData(List fids) { + long start = System.currentTimeMillis(); List persons = mapper.findNameData(fids); - return persons.stream() + log.trace("findNameData(db) time {} ms", System.currentTimeMillis() - start); + start = System.currentTimeMillis(); + Map res = persons.stream() .collect(Collectors.toMap(NameData::getFid, nameData -> nameData, (existing, replacement) -> { LocalDate existingDate = existing.getFileSinceDate(); @@ -67,13 +74,18 @@ public class PersonService { return replacement; } })); + log.trace("findNameData(collecting) time {} ms", System.currentTimeMillis() - start); + return res; } private Map findPassportData(List fids) { Map resultMap = new HashMap<>(); + long start = System.currentTimeMillis(); List passports = mapper.findPassportData(fids); + log.trace("findPassportData(db) time {} ms", System.currentTimeMillis() - start); + start = System.currentTimeMillis(); Map> passportsMap = passports.stream() .collect(Collectors.groupingBy(PassportData::getFid)); @@ -83,6 +95,7 @@ public class PersonService { resultMap.put(fid, passport); } }); + log.trace("findPassportData(collecting) time {} ms", System.currentTimeMillis() - start); return resultMap; } diff --git a/src/main/java/ru/nbch/credit_tracker/service/indic/PhoneService.java b/src/main/java/ru/nbch/credit_tracker/service/indic/PhoneService.java index d063be1..9d7ee4f 100644 --- a/src/main/java/ru/nbch/credit_tracker/service/indic/PhoneService.java +++ b/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,13 @@ public class PhoneService { * @return Map: key - номер телефона; value - fid */ public Map findFidsPhoneData(List subjects) { + long start = System.currentTimeMillis(); List 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(); + Map res = convertFidsDataToMap(mapper.findFids(phones)); + log.trace("convertFidsDataToMap {} ms", System.currentTimeMillis() - start); + return res; } private Map convertFidsDataToMap(List fidsData) { diff --git a/src/main/java/ru/nbch/credit_tracker/service/signal/SignalRestService.java b/src/main/java/ru/nbch/credit_tracker/service/signal/SignalRestService.java index 9bf608d..febec20 100644 --- a/src/main/java/ru/nbch/credit_tracker/service/signal/SignalRestService.java +++ b/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 body = new LinkedMultiValueMap<>(); body.add("file", request); diff --git a/src/main/resources/logback.xml b/src/main/resources/logback.xml index 0825d76..add48c1 100644 --- a/src/main/resources/logback.xml +++ b/src/main/resources/logback.xml @@ -63,18 +63,18 @@ - + - + - +