Skip to content

Commit

Permalink
feat(imp):[#214] debug logging (to be removed/adapted after debugging)
Browse files Browse the repository at this point in the history 
switch log.debug to info because debug does not seem to get logged and add special marker "#214@" to filter the logs for debugging the story
  • Loading branch information
@dsmf
dsmf committed Jan 24, 2024
1 parent 7a7324b commit 824d1d9
Show file tree
Hide file tree
Showing 3 changed files with 59 additions and 56 deletions.
25 changes: 13 additions & 12 deletions irs-common/src/main/java/org/eclipse/tractusx/irs/common/util/concurrent/ResultFinder.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -54,11 +54,11 @@ public class ResultFinder {
public <T> CompletableFuture<T> getFastestResult(final List<CompletableFuture<T>> futures) {

if (futures == null || futures.isEmpty()) {
log.warn("getFastestResult#0 Called getFastestResult with empty list of futures");
log.warn("#214@getFastestResult#0 Called getFastestResult with empty list of futures");
return CompletableFuture.completedFuture(null);
}

log.debug("getFastestResult#1 Trying to get fastest result from list of futures");
log.info("#214@getFastestResult#1 Trying to get fastest result from list of futures");

final CompletableFuture<T> fastestResultPromise = new CompletableFuture<>();

Expand All @@ -69,19 +69,19 @@ public <T> CompletableFuture<T> getFastestResult(final List<CompletableFuture<T>
.handle(completingOnFirstSuccessful(fastestResultPromise)))
.toList();

log.debug("getFastestResult#2");
log.info("#214@getFastestResult#2");

allOf(toArray(futuresList)).whenComplete((value, ex) -> {

log.debug("getFastestResult#3 List of futures completed");
log.info("#214@getFastestResult#3 List of futures completed");

if (ex != null) {
log.error("getFastestResult#4 Exception occurred: " + ex.getMessage(), ex);
log.error("g#214@etFastestResult#4 Exception occurred: " + ex.getMessage(), ex);
fastestResultPromise.completeExceptionally(new CompletionExceptions(exceptions));
} else if (fastestResultPromise.isDone()) {
log.debug("getFastestResult#5 Fastest result already found, ignoring the others");
log.info("#214@getFastestResult#5 Fastest result already found, ignoring the others");
} else {
log.debug("getFastestResult#6 Completing");
log.info("#214@getFastestResult#6 Completing");
fastestResultPromise.complete(null);
}
});
Expand All @@ -98,26 +98,27 @@ private static <T> BiFunction<T, Throwable, Boolean> completingOnFirstSuccessful

return (value, throwable) -> {

log.debug("completingOnFirstSuccessful#1 value: {}, throwable: {}", value, throwable);
log.info("#214@completingOnFirstSuccessful#1 value: {}, throwable: {}", value, throwable);

final boolean notFinishedByOtherFuture = !resultPromise.isDone();
log.debug("completingOnFirstSuccessful#2 notFinishedByOtherFuture {} ", notFinishedByOtherFuture);
log.info("#214@completingOnFirstSuccessful#2 notFinishedByOtherFuture {} ", notFinishedByOtherFuture);

final boolean currentFutureSuccessful = throwable == null && value != null;

if (notFinishedByOtherFuture && currentFutureSuccessful) {

// first future that completes successfully completes the overall future
log.debug("completingOnFirstSuccessful#3 First future that completed successfully");
log.info("#214@completingOnFirstSuccessful#3 First future that completed successfully");
resultPromise.complete(value);
return true;

} else {
if (throwable != null) {
log.warn("completingOnFirstSuccessful#4 Exception occurred: " + throwable.getMessage(), throwable);
log.warn("#214@completingOnFirstSuccessful#4 Exception occurred: " + throwable.getMessage(),
throwable);
throw new CompletionException(throwable.getMessage(), throwable);
} else {
log.debug("completingOnFirstSuccessful#5 log just for debugging");
log.info("#214@completingOnFirstSuccessful#5 log just for debugging");
}
return false;
}
Expand Down
75 changes: 38 additions & 37 deletions ...rg/eclipse/tractusx/irs/registryclient/decentral/DecentralDigitalTwinRegistryService.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -83,35 +83,36 @@ public Collection<AssetAdministrationShellDescriptor> fetchShells(final Collecti

try {

log.info("fetchShells#1 Fetching shell(s) for {} key(s)", keys.size());
log.info("#214@fetchShells#1 Fetching shell(s) for {} key(s)", keys.size());

final var calledEndpoints = new HashSet<String>();
final var collectedShells = groupKeysByBpn(keys).flatMap(
entry -> fetchShellDescriptors(calledEndpoints, entry.getKey(), entry.getValue()).stream())
.toList();

if (collectedShells.isEmpty()) {
log.debug("fetchShells#2 no shells found");
log.info("#214@fetchShells#2 no shells found");
throw new ShellNotFoundException("Unable to find any of the requested shells", calledEndpoints);
} else {
log.info("fetchShells#3 Found {} shell(s) for {} key(s)", collectedShells.size(), keys.size());
log.info("#214@fetchShells#3 Found {} shell(s) for {} key(s)", collectedShells.size(), keys.size());
return collectedShells;
}

} finally {
log.debug("fetchShells#4 finally");
log.info("#214@fetchShells#4 finally");
}
}

@NotNull
private List<AssetAdministrationShellDescriptor> fetchShellDescriptors(final Set<String> calledEndpoints,
final String bpn, final List<DigitalTwinRegistryKey> keys) {

log.info("fetchShellDescriptors#1 Fetching {} shells for bpn {}", keys.size(), bpn);
log.info("#214@fetchShellDescriptors#1 Fetching {} shells for bpn {}", keys.size(), bpn);

final var connectorEndpoints = connectorEndpointsService.fetchConnectorEndpoints(bpn);

log.debug("fetchShellDescriptors#2 Found {} connector endpoints for bpn {}", connectorEndpoints.size(), bpn);
log.info("#214@fetchShellDescriptors#2 Found {} connector endpoints for bpn {}", connectorEndpoints.size(),
bpn);

calledEndpoints.addAll(connectorEndpoints);

Expand All @@ -121,7 +122,7 @@ private List<AssetAdministrationShellDescriptor> fetchShellDescriptors(final Set
private List<AssetAdministrationShellDescriptor> fetchShellDescriptorsForConnectorEndpoints(final String bpn,
final List<DigitalTwinRegistryKey> keys, final List<String> connectorEndpoints) {

log.debug("fetchShellDescriptorsForConnectorEndpoints#1");
log.info("#214@fetchShellDescriptorsForConnectorEndpoints#1");

final EndpointDataForConnectorsService service = endpointDataForConnectorsService;
try {
Expand All @@ -131,33 +132,33 @@ private List<AssetAdministrationShellDescriptor> fetchShellDescriptorsForConnect
edr -> supplyAsync(() -> fetchShellDescriptorsForKey(keys, edr))))
.toList();

log.debug("fetchShellDescriptorsForConnectorEndpoints#2");
log.info("#214@fetchShellDescriptorsForConnectorEndpoints#2");

return resultFinder.getFastestResult(futures).get();

} catch (InterruptedException e) {
log.debug(
"fetchShellDescriptorsForConnectorEndpoints#3 InterruptedException occurred while fetching shells for bpn '%s'".formatted(
log.warn(
"#214@fetchShellDescriptorsForConnectorEndpoints#3 InterruptedException occurred while fetching shells for bpn '%s'".formatted(
bpn), e);
Thread.currentThread().interrupt();
return emptyList();
} catch (ResultFinder.CompletionExceptions e) {

log.debug("fetchShellDescriptorsForConnectorEndpoints#4 " + e.getMessage(), e);
e.getCauses().forEach(ex -> log.debug("fetchShellDescriptorsForConnectorEndpoints#5 " //
log.warn("#214@fetchShellDescriptorsForConnectorEndpoints#4 " + e.getMessage(), e);
e.getCauses().forEach(ex -> log.warn("#214@fetchShellDescriptorsForConnectorEndpoints#5 " //
+ ex.getMessage(), ex));

throw new RegistryServiceRuntimeException(
"Exception occurred while fetching shells for bpn '%s'".formatted(bpn), e);
"#214@ Exception occurred while fetching shells for bpn '%s'".formatted(bpn), e);

} catch (ExecutionException e) {

log.error("fetchShellDescriptorsForConnectorEndpoints#6 " + e.getMessage(), e);
log.error("#214@fetchShellDescriptorsForConnectorEndpoints#6 " + e.getMessage(), e);
throw new RegistryServiceRuntimeException(
"Exception occurred while fetching shells for bpn '%s'".formatted(bpn), e);
"#214@ Exception occurred while fetching shells for bpn '%s'".formatted(bpn), e);

} finally {
log.debug("fetchShellDescriptorsForConnectorEndpoints#7 finally");
log.info("#214@fetchShellDescriptorsForConnectorEndpoints#7 finally");
}
}

Expand All @@ -170,13 +171,13 @@ private List<AssetAdministrationShellDescriptor> fetchShellDescriptorsForKey(
private AssetAdministrationShellDescriptor fetchShellDescriptor(final EndpointDataReference endpointDataReference,
final DigitalTwinRegistryKey key) {
try {
log.info("fetchShellDescriptor#1 Retrieving AAS Identification for DigitalTwinRegistryKey: {}", key);
log.info("#214@fetchShellDescriptor#1 Retrieving AAS Identification for DigitalTwinRegistryKey: {}", key);
final String aaShellIdentification = mapToShellId(endpointDataReference, key.shellId());
log.debug("fetchShellDescriptor#2 aaShellIdentification: {}", aaShellIdentification);
log.info("#214@fetchShellDescriptor#2 aaShellIdentification: {}", aaShellIdentification);
return decentralDigitalTwinRegistryClient.getAssetAdministrationShellDescriptor(endpointDataReference,
aaShellIdentification);
} finally {
log.debug("fetchShellDescriptor#3 finally");
log.info("#214@fetchShellDescriptor#3 finally");
}
}

Expand All @@ -192,7 +193,7 @@ private AssetAdministrationShellDescriptor fetchShellDescriptor(final EndpointDa
@NotNull
private String mapToShellId(final EndpointDataReference endpointDataReference, final String key) {

log.debug("mapToShellId#1");
log.info("#214@mapToShellId#1");

try {

Expand All @@ -207,30 +208,30 @@ private String mapToShellId(final EndpointDataReference endpointDataReference, f
.findFirst()
.orElse(key);

log.debug("mapToShellId#2");
log.info("#214@mapToShellId#2");

if (key.equals(aaShellIdentification)) {
log.info("mapToShellId#3 Found shell with shellId {} in registry", aaShellIdentification);
log.info("#214@mapToShellId#3 Found shell with shellId {} in registry", aaShellIdentification);
} else {
log.info("mapToShellId#4 Retrieved shellId {} for globalAssetId {}", aaShellIdentification, key);
log.info("#214@mapToShellId#4 Retrieved shellId {} for globalAssetId {}", aaShellIdentification, key);
}
return aaShellIdentification;
} finally {
log.debug("mapToShellId#5 finally");
log.info("#214@mapToShellId#5 finally");
}
}

private Collection<String> lookupShellIds(final String bpn) {

log.info("lookupShellIds#1 Looking up shell ids for bpn {}", bpn);
log.info("#214@lookupShellIds#1 Looking up shell ids for bpn {}", bpn);

final var connectorEndpoints = connectorEndpointsService.fetchConnectorEndpoints(bpn);
log.debug("lookupShellIds#2 Looking up shell ids for bpn {} with connector endpoints {}", bpn,
log.info("#214@lookupShellIds#2 Looking up shell ids for bpn {} with connector endpoints {}", bpn,
connectorEndpoints);

final var endpointDataReferenceFutures = endpointDataForConnectorsService.createFindEndpointDataForConnectorsFutures(
connectorEndpoints);
log.debug("lookupShellIds#3 created futures");
log.info("#214@lookupShellIds#3 created futures");

try {
final var futures = endpointDataReferenceFutures.stream()
Expand All @@ -239,39 +240,39 @@ private Collection<String> lookupShellIds(final String bpn) {
.toList();
final var shellIds = resultFinder.getFastestResult(futures).get();

log.info("lookupShellIds#4 Found {} shell id(s) in total", shellIds.size());
log.info("#214@lookupShellIds#4 Found {} shell id(s) in total", shellIds.size());
return shellIds;

} catch (InterruptedException e) {
log.debug(
"lookupShellIds#5 InterruptedException occurred while looking up shells ids for bpn '%s'".formatted(
log.info(
"#214@lookupShellIds#5 InterruptedException occurred while looking up shells ids for bpn '%s'".formatted(
bpn), e);
Thread.currentThread().interrupt();
return emptyList();
} catch (ResultFinder.CompletionExceptions e) {

log.debug("lookupShellIds#6" + e.getMessage(), e);
e.getCauses().forEach(ex -> log.debug("lookupShellIds#7 " + ex.getMessage(), ex));
log.warn("#214@lookupShellIds#6" + e.getMessage(), e);
e.getCauses().forEach(ex -> log.warn("lookupShellIds#7 " + ex.getMessage(), ex));

throw new RegistryServiceRuntimeException(
"Exception occurred while looking up shell ids for bpn '%s'".formatted(bpn), e);
"#214@ Exception occurred while looking up shell ids for bpn '%s'".formatted(bpn), e);

} catch (ExecutionException e) {
log.error("lookupShellIds#8 " + e.getMessage(), e);
log.error("#214@lookupShellIds#8 " + e.getMessage(), e);
throw new RegistryServiceRuntimeException(
"Exception occurred while looking up shell ids for bpn '%s'".formatted(bpn), e);
"#214@ Exception occurred while looking up shell ids for bpn '%s'".formatted(bpn), e);
}
}

private List<String> lookupShellIds(final String bpn, final EndpointDataReference endpointDataReference) {
log.debug("lookupShellIds#1 look up shell IDs for bpn {} with endpointDataReference {}", bpn,
log.info("#214@lookupShellIds#1 look up shell IDs for bpn {} with endpointDataReference {}", bpn,
endpointDataReference);
try {
return decentralDigitalTwinRegistryClient.getAllAssetAdministrationShellIdsByAssetLink(
endpointDataReference,
List.of(IdentifierKeyValuePair.builder().name("manufacturerId").value(bpn).build())).getResult();
} finally {
log.debug("lookupShellIds#2 finally");
log.info("#214@lookupShellIds#2 finally");
}
}

Expand Down
15 changes: 8 additions & 7 deletions ...a/org/eclipse/tractusx/irs/registryclient/decentral/EndpointDataForConnectorsService.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -52,35 +52,36 @@ public List<CompletableFuture<EndpointDataReference>> createFindEndpointDataForC

List<CompletableFuture<EndpointDataReference>> futures = Collections.emptyList();
try {
log.debug(
"createFindEndpointDataForConnectorsFutures#1 creating futures to get EndpointDataReferences for endpoints: {}",
log.info(
"#214#createFindEndpointDataForConnectorsFutures#1 creating futures to get EndpointDataReferences for endpoints: {}",
connectorEndpoints);
futures = connectorEndpoints.stream()
.map(connectorEndpoint -> supplyAsync(
() -> getEndpointReferenceForAsset(connectorEndpoint)))
.toList();
return futures;
} finally {
log.debug("createFindEndpointDataForConnectorsFutures#2 created {} futures", futures.size());
log.info("#214@createFindEndpointDataForConnectorsFutures#2 created {} futures", futures.size());
}
}

private EndpointDataReference getEndpointReferenceForAsset(final String connector) {
log.info("getEndpointReferenceForAsset#1 Trying to retrieve EndpointDataReference for connector {}", connector);
log.info("#214@getEndpointReferenceForAsset#1 Trying to retrieve EndpointDataReference for connector {}",
connector);
try {
final var endpointDataReference = edcSubmodelFacade.getEndpointReferenceForAsset(connector,
DT_REGISTRY_ASSET_TYPE, DT_REGISTRY_ASSET_VALUE);

log.debug("getEndpointReferenceForAsset#2 Got EndpointDataReference for connector {}", connector);
log.info("#214@getEndpointReferenceForAsset#2 Got EndpointDataReference for connector {}", connector);

return endpointDataReference;
} catch (EdcRetrieverException e) {
log.warn(
"getEndpointReferenceForAsset#3 Exception occurred when retrieving EndpointDataReference from connector {}",
"#214@getEndpointReferenceForAsset#3 Exception occurred when retrieving EndpointDataReference from connector {}",
connector, e);
throw new CompletionException(e.getMessage(), e);
} finally {
log.debug("getEndpointReferenceForAsset#4 finally");
log.info("#214@getEndpointReferenceForAsset#4 finally");
}

}
Expand Down

0 comments on commit 824d1d9

Please sign in to comment.