Skip to content

Commit ae8c16d

Browse files
karrgovkarrgov
committed
Adding logging for testing purposes - flowable problem
LMCROSSITXSADEPLOY-2301
1 parent 5fa31a4 commit ae8c16d

File tree

9 files changed

+114
-1
lines changed

9 files changed

+114
-1
lines changed

‎multiapps-controller-process/src/main/java/org/cloudfoundry/multiapps/controller/process/security/SecretTokenSerializer.java‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,9 +23,13 @@
2323
import org.cloudfoundry.multiapps.controller.process.security.util.SecretTokenUtil;
2424
import org.cloudfoundry.multiapps.controller.process.variables.Serializer;
2525
import org.flowable.common.engine.api.variable.VariableContainer;
26+
import org.slf4j.Logger;
27+
import org.slf4j.LoggerFactory;
2628

2729
public class SecretTokenSerializer<T> implements Serializer<T> {
2830

31+
private static final Logger LOGGER = LoggerFactory.getLogger(SecretTokenSerializer.class);
32+
2933
private static final ObjectMapper OBJECT_MAPPER = new ObjectMapper().enable(DeserializationFeature.FAIL_ON_TRAILING_TOKENS);
3034

3135
private final Serializer<T> serializer;
@@ -176,6 +180,9 @@ private String transformJson(String candidate, boolean censor) {
176180
}
177181
return null;
178182
} catch (Exception e) {
183+
LOGGER.info("transformJson failed for var {} (more info = {}): {}: {}", variableName, candidate, e.getClass()
184+
.getSimpleName(),
185+
e.getMessage());
179186
throw new SLException(MessageFormat.format(Messages.JSON_TRANSFORMATION_FAILED_FOR_VARIABLE_0, variableName), e);
180187
}
181188
}

‎multiapps-controller-process/src/main/java/org/cloudfoundry/multiapps/controller/process/security/resolver/SecretTokenKeyResolverImpl.java‎

Lines changed: 79 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,10 @@
11
package org.cloudfoundry.multiapps.controller.process.security.resolver;
22

3+
import java.nio.charset.StandardCharsets;
4+
import java.security.MessageDigest;
35
import java.text.MessageFormat;
46
import java.time.Duration;
7+
import java.util.HexFormat;
58
import java.util.Map;
69
import java.util.UUID;
710

@@ -40,26 +43,75 @@ public SecretTokenKeyResolverImpl(CloudControllerClientProvider cloudControllerC
4043
@Override
4144
public String resolve(DelegateExecution execution) {
4245
String correlationId = VariableHandling.get(execution, Variables.CORRELATION_ID);
46+
47+
final Boolean disposable = VariableHandling.get(execution, Variables.IS_DISPOSABLE_USER_PROVIDED_SERVICE_ENABLED);
48+
final String disposableName = VariableHandling.get(execution, Variables.DISPOSABLE_USER_PROVIDED_SERVICE_NAME);
49+
final String mtaId = VariableHandling.get(execution, Variables.MTA_ID);
50+
final String namespace = VariableHandling.get(execution, Variables.MTA_NAMESPACE);
51+
52+
LOGGER.error(
53+
"SecretTokenKeyResolver START RESOLVE instance={} correlationId={} disposable={} disposableName={} mtaId={} namespace={}",
54+
instance(),
55+
correlationId, disposable, disposableName, mtaId, namespace);
56+
4357
String encryptionKey = cachedMap.get(correlationId);
4458
if (encryptionKey != null) {
59+
LOGGER.error("SecretTokenKeyResolver CACHE_HIT instance={} correlationId={} key={}",
60+
instance(), correlationId, fingerprint(encryptionKey));
4561
return encryptionKey;
4662
}
63+
LOGGER.error("SecretTokenKeyResolver CACHE_MISSED instance={} correlationId={}", instance(), correlationId);
4764

4865
CloudControllerClient cloudControllerClient = createCloudControllerClient(execution, correlationId);
66+
LOGGER.error("SecretTokenKeyResolver CLIENT_CREATED instance={} correlationId={} userGuid={} spaceGuid={}",
67+
instance(), correlationId, StepsUtil.determineCurrentUserGuid(execution),
68+
VariableHandling.get(execution, Variables.SPACE_GUID));
69+
4970
String userProvidedServiceName = getUserProvidedServiceName(execution);
71+
LOGGER.error("SecretTokenKeyResolver UPS_NAME_CHOSEN instance={} correlationId={} upsName='{}'",
72+
instance(), correlationId, userProvidedServiceName);
73+
5074
CloudServiceInstance cloudServiceInstance = cloudControllerClient.getServiceInstance(userProvidedServiceName);
5175
if (cloudServiceInstance == null) {
76+
LOGGER.error("SecretTokenKeyResolver UPS_NOT_FOUND instance={} correlationId={} upsName='{}'",
77+
instance(), correlationId, userProvidedServiceName);
5278
throw new SLException(Messages.COULD_NOT_RETRIEVE_USER_PROVIDED_SERVICE_INSTANCE_ENCRYPTION_RELATED);
5379
}
5480

81+
UUID upsGuid = cloudServiceInstance.getGuid();
82+
LOGGER.error("SecretTokenKeyResolver UPS_RESOLVED instance={} correlationId={} upsName='{}' guid={}",
83+
instance(), correlationId, userProvidedServiceName, upsGuid);
84+
5585
Map<String, Object> serviceInstanceCredentials = getUserProvidedServiceInstanceParameters(cloudServiceInstance,
5686
cloudControllerClient);
5787
if (serviceInstanceCredentials == null || serviceInstanceCredentials.isEmpty()) {
88+
LOGGER.error("SecretTokenKeyResolver CREDENTIALS_EMPTY instance={} correlationId={} guid={}", instance(), correlationId,
89+
upsGuid);
5890
throw new SLException(Messages.COULD_NOT_RETRIEVE_CREDENTIALS_FROM_USER_PROVIDED_SERVICE_INSTANCE_ENCRYPTION_RELATED);
5991
}
6092

93+
boolean hasKey = serviceInstanceCredentials.containsKey(Constants.ENCRYPTION_KEY);
94+
Object rawKey = serviceInstanceCredentials.get(Constants.ENCRYPTION_KEY);
95+
int keyLength = String.valueOf(rawKey)
96+
.length();
97+
LOGGER.error("SecretTokenKeyResolver CREDENTIALS_PRESENT instance={} correlationId={} guid={} hasEncryptionKey={} keyLength={}",
98+
instance(), correlationId, upsGuid, hasKey, keyLength);
99+
61100
String resultEncryptionKey = getEncryptionKeyFromCredentials(serviceInstanceCredentials);
101+
102+
LOGGER.error("SecretTokenKeyResolver KEY_RETRIEVED instance={} correlationId={} guid={} key={}",
103+
instance(), correlationId, upsGuid, fingerprint(resultEncryptionKey));
104+
105+
String beforePut = cachedMap.get(correlationId);
106+
if (beforePut != null && !beforePut.equals(resultEncryptionKey)) {
107+
LOGGER.error("SecretTokenKeyResolver CACHE_OVERWRITE instance={} correlationId={} oldKey={} newKey={}",
108+
instance(), correlationId, fingerprint(beforePut), fingerprint(resultEncryptionKey));
109+
}
110+
62111
cachedMap.put(correlationId, resultEncryptionKey);
112+
LOGGER.error("SecretTokenKeyResolver CACHE_PUT instance={} correlationId={} guid={} key={}",
113+
instance(), correlationId, upsGuid, fingerprint(resultEncryptionKey));
114+
63115
return resultEncryptionKey;
64116
}
65117

@@ -79,10 +131,13 @@ private String getUserProvidedServiceName(DelegateExecution execution) {
79131
if (isDisposableUserProvidedServiceEnabled) {
80132
String disposableUserProvidedServiceName = VariableHandling.get(execution, Variables.DISPOSABLE_USER_PROVIDED_SERVICE_NAME);
81133
LOGGER.debug(MessageFormat.format(Messages.USING_DISPOSABLE_USER_PROVIDED_SERVICE_0_, disposableUserProvidedServiceName));
134+
LOGGER.error(Messages.USING_DISPOSABLE_USER_PROVIDED_SERVICE_0_, disposableUserProvidedServiceName);
82135
return disposableUserProvidedServiceName;
83136
}
84137

85138
if (mtaId == null) {
139+
LOGGER.error("SecretTokenKeyResolver MISSING_MTA_ID instance={} correlationId={}", instance(),
140+
VariableHandling.get(execution, Variables.CORRELATION_ID));
86141
throw new SLException(Messages.MISSING_MTA_ID_IN_ENCRYPTION_KEY_RESOLVER);
87142
}
88143

@@ -91,12 +146,14 @@ private String getUserProvidedServiceName(DelegateExecution execution) {
91146
Constants.USER_PROVIDED_SERVICE_PREFIX_NAME_ENCRYPTION_DECRYPTION, mtaId,
92147
namespace);
93148
LOGGER.debug(MessageFormat.format(Messages.USING_DEFAULT_USER_PROVIDED_SERVICE_0_, userProvidedServiceName));
149+
LOGGER.error(Messages.USING_DEFAULT_USER_PROVIDED_SERVICE_0_, userProvidedServiceName);
94150
return userProvidedServiceName;
95151
} else {
96152
String userProvidedServiceName = String.format(Constants.DOUBLE_APPENDED_STRING,
97153
Constants.USER_PROVIDED_SERVICE_PREFIX_NAME_ENCRYPTION_DECRYPTION,
98154
mtaId);
99155
LOGGER.debug(MessageFormat.format(Messages.USING_DEFAULT_USER_PROVIDED_SERVICE_0_, userProvidedServiceName));
156+
LOGGER.error(Messages.USING_DEFAULT_USER_PROVIDED_SERVICE_0_, userProvidedServiceName);
100157
return userProvidedServiceName;
101158
}
102159
}
@@ -109,6 +166,8 @@ private String getEncryptionKeyFromCredentials(Map<String, Object> serviceInstan
109166
}
110167

111168
if (encryptionKey.length() != Constants.ENCRYPTION_KEY_LENGTH) {
169+
LOGGER.error("SecretTokenKeyResolver INVALID_KEY_LENGTH keyLength={} expected={}", encryptionKey.length(),
170+
Constants.ENCRYPTION_KEY_LENGTH);
112171
throw new SLException(Messages.INVALID_ENCRYPTION_KEY_LENGTH);
113172
}
114173

@@ -118,7 +177,26 @@ private String getEncryptionKeyFromCredentials(Map<String, Object> serviceInstan
118177
private Map<String, Object> getUserProvidedServiceInstanceParameters(CloudServiceInstance cloudServiceInstance,
119178
CloudControllerClient cloudControllerClient) {
120179
UUID serviceInstanceGuid = cloudServiceInstance.getGuid();
180+
LOGGER.error("SecretTokenKeyResolver RETRIEVED_CREDENTIALS instance={} guid={}", instance(), serviceInstanceGuid);
121181
return cloudControllerClient.getUserProvidedServiceInstanceParameters(serviceInstanceGuid);
122182
}
123183

124-
}
184+
private static String instance() {
185+
String index = System.getenv("CF_INSTANCE_INDEX");
186+
String guid = System.getenv("CF_INSTANCE_GUID");
187+
return (index + "/" + guid);
188+
}
189+
190+
private static String fingerprint(String key) {
191+
try {
192+
byte[] hash = MessageDigest.getInstance("SHA-256")
193+
.digest(key.getBytes(StandardCharsets.UTF_8));
194+
return HexFormat.of()
195+
.formatHex(hash)
196+
.substring(0, 12);
197+
} catch (Exception e) {
198+
return "Error - encryption key";
199+
}
200+
}
201+
202+
}

‎multiapps-controller-process/src/main/resources/org/cloudfoundry/multiapps/controller/process/backup-existing-app.bpmn‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,9 @@
2020
<flowable:in source="__SPACE_ID" target="__SPACE_ID"></flowable:in>
2121
<flowable:in source="hookForExecution" target="hookForExecution"></flowable:in>
2222
<flowable:in source="isSecurityEnabled" target="isSecurityEnabled"></flowable:in>
23+
<flowable:in source="secureExtensionDescriptorParameterNames" target="secureExtensionDescriptorParameterNames"></flowable:in>
24+
<flowable:in source="isDisposableUserProvidedServiceEnabled" target="isDisposableUserProvidedServiceEnabled"></flowable:in>
25+
<flowable:in source="disposableUserProvidedServiceName" target="disposableUserProvidedServiceName"></flowable:in>
2326
<flowable:in source="mtaId" target="mtaId"></flowable:in>
2427
</extensionElements>
2528
<multiInstanceLoopCharacteristics isSequential="false" flowable:collection="hooksForExecution" flowable:elementVariable="hookForExecution">

‎multiapps-controller-process/src/main/resources/org/cloudfoundry/multiapps/controller/process/delete-services.bpmn‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,8 @@
3434
<flowable:in source="serviceBindingToDelete" target="serviceBindingToDelete"></flowable:in>
3535
<flowable:in source="secureExtensionDescriptorParameterNames" target="secureExtensionDescriptorParameterNames"></flowable:in>
3636
<flowable:in source="isSecurityEnabled" target="isSecurityEnabled"></flowable:in>
37+
<flowable:in source="isDisposableUserProvidedServiceEnabled" target="isDisposableUserProvidedServiceEnabled"></flowable:in>
38+
<flowable:in source="disposableUserProvidedServiceName" target="disposableUserProvidedServiceName"></flowable:in>
3739
<flowable:in source="mtaId" target="mtaId"></flowable:in>
3840
</extensionElements>
3941
<multiInstanceLoopCharacteristics isSequential="false" flowable:collection="cloudServiceBindingsToDelete" flowable:elementVariable="serviceBindingToDelete">
@@ -63,6 +65,9 @@
6365
<flowable:in source="correlationId" target="correlationId"/>
6466
<flowable:in source="__SPACE_ID" target="__SPACE_ID"/>
6567
<flowable:in source="isSecurityEnabled" target="isSecurityEnabled"></flowable:in>
68+
<flowable:in source="secureExtensionDescriptorParameterNames" target="secureExtensionDescriptorParameterNames"></flowable:in>
69+
<flowable:in source="isDisposableUserProvidedServiceEnabled" target="isDisposableUserProvidedServiceEnabled"></flowable:in>
70+
<flowable:in source="disposableUserProvidedServiceName" target="disposableUserProvidedServiceName"></flowable:in>
6671
<flowable:in source="mtaId" target="mtaId"></flowable:in>
6772
</extensionElements>
6873
<multiInstanceLoopCharacteristics isSequential="false" flowable:collection="cloudServiceKeysToDelete" flowable:elementVariable="serviceKeyToProcess">

‎multiapps-controller-process/src/main/resources/org/cloudfoundry/multiapps/controller/process/recreate-service-keys.bpmn‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,9 @@
1717
<flowable:in source="correlationId" target="correlationId"/>
1818
<flowable:in source="__SPACE_ID" target="__SPACE_ID"/>
1919
<flowable:in source="isSecurityEnabled" target="isSecurityEnabled"></flowable:in>
20+
<flowable:in source="secureExtensionDescriptorParameterNames" target="secureExtensionDescriptorParameterNames"></flowable:in>
21+
<flowable:in source="isDisposableUserProvidedServiceEnabled" target="isDisposableUserProvidedServiceEnabled"></flowable:in>
22+
<flowable:in source="disposableUserProvidedServiceName" target="disposableUserProvidedServiceName"></flowable:in>
2023
<flowable:in source="mtaId" target="mtaId"></flowable:in>
2124
</extensionElements>
2225
<multiInstanceLoopCharacteristics isSequential="false" flowable:collection="cloudServiceKeysToDelete" flowable:elementVariable="serviceKeyToProcess"></multiInstanceLoopCharacteristics>

‎multiapps-controller-process/src/main/resources/org/cloudfoundry/multiapps/controller/process/undeploy-app.bpmn‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,9 @@
2121
<flowable:in source="__SPACE_ID" target="__SPACE_ID"></flowable:in>
2222
<flowable:in source="hookForExecution" target="hookForExecution"></flowable:in>
2323
<flowable:in source="isSecurityEnabled" target="isSecurityEnabled"></flowable:in>
24+
<flowable:in source="secureExtensionDescriptorParameterNames" target="secureExtensionDescriptorParameterNames"></flowable:in>
25+
<flowable:in source="isDisposableUserProvidedServiceEnabled" target="isDisposableUserProvidedServiceEnabled"></flowable:in>
26+
<flowable:in source="disposableUserProvidedServiceName" target="disposableUserProvidedServiceName"></flowable:in>
2427
<flowable:in source="mtaId" target="mtaId"></flowable:in>
2528
</extensionElements>
2629
<multiInstanceLoopCharacteristics isSequential="false" flowable:collection="hooksForExecution" flowable:elementVariable="hookForExecution">
@@ -48,6 +51,9 @@
4851
<flowable:in source="__SPACE_ID" target="__SPACE_ID"></flowable:in>
4952
<flowable:in source="hookForExecution" target="hookForExecution"></flowable:in>
5053
<flowable:in source="isSecurityEnabled" target="isSecurityEnabled"></flowable:in>
54+
<flowable:in source="secureExtensionDescriptorParameterNames" target="secureExtensionDescriptorParameterNames"></flowable:in>
55+
<flowable:in source="isDisposableUserProvidedServiceEnabled" target="isDisposableUserProvidedServiceEnabled"></flowable:in>
56+
<flowable:in source="disposableUserProvidedServiceName" target="disposableUserProvidedServiceName"></flowable:in>
5157
<flowable:in source="mtaId" target="mtaId"></flowable:in>
5258
</extensionElements>
5359
<multiInstanceLoopCharacteristics isSequential="false" flowable:collection="hooksForExecution" flowable:elementVariable="hookForExecution">
@@ -96,6 +102,8 @@
96102
<flowable:in source="serviceBindingToDelete" target="serviceBindingToDelete"></flowable:in>
97103
<flowable:in source="secureExtensionDescriptorParameterNames" target="secureExtensionDescriptorParameterNames"></flowable:in>
98104
<flowable:in source="isSecurityEnabled" target="isSecurityEnabled"></flowable:in>
105+
<flowable:in source="isDisposableUserProvidedServiceEnabled" target="isDisposableUserProvidedServiceEnabled"></flowable:in>
106+
<flowable:in source="disposableUserProvidedServiceName" target="disposableUserProvidedServiceName"></flowable:in>
99107
<flowable:in source="mtaId" target="mtaId"></flowable:in>
100108
</extensionElements>
101109
<multiInstanceLoopCharacteristics isSequential="false" flowable:collection="cloudServiceBindingsToDelete" flowable:elementVariable="serviceBindingToDelete">

‎multiapps-controller-process/src/main/resources/org/cloudfoundry/multiapps/controller/process/xs2-bg-deploy.bpmn‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -180,6 +180,9 @@
180180
<flowable:in source="correlationId" target="correlationId"/>
181181
<flowable:in source="__SPACE_ID" target="__SPACE_ID"/>
182182
<flowable:in source="isSecurityEnabled" target="isSecurityEnabled"></flowable:in>
183+
<flowable:in source="secureExtensionDescriptorParameterNames" target="secureExtensionDescriptorParameterNames"></flowable:in>
184+
<flowable:in source="isDisposableUserProvidedServiceEnabled" target="isDisposableUserProvidedServiceEnabled"></flowable:in>
185+
<flowable:in source="disposableUserProvidedServiceName" target="disposableUserProvidedServiceName"></flowable:in>
183186
<flowable:in source="mtaId" target="mtaId"></flowable:in>
184187
</extensionElements>
185188
<multiInstanceLoopCharacteristics isSequential="false" flowable:collection="serviceKeysToDelete" flowable:elementVariable="serviceKeyToProcess"></multiInstanceLoopCharacteristics>

‎multiapps-controller-process/src/main/resources/org/cloudfoundry/multiapps/controller/process/xs2-deploy.bpmn‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -162,6 +162,9 @@
162162
<flowable:in source="correlationId" target="correlationId"/>
163163
<flowable:in source="__SPACE_ID" target="__SPACE_ID"/>
164164
<flowable:in source="isSecurityEnabled" target="isSecurityEnabled"></flowable:in>
165+
<flowable:in source="secureExtensionDescriptorParameterNames" target="secureExtensionDescriptorParameterNames"></flowable:in>
166+
<flowable:in source="isDisposableUserProvidedServiceEnabled" target="isDisposableUserProvidedServiceEnabled"></flowable:in>
167+
<flowable:in source="disposableUserProvidedServiceName" target="disposableUserProvidedServiceName"></flowable:in>
165168
<flowable:in source="mtaId" target="mtaId"></flowable:in>
166169
</extensionElements>
167170
<multiInstanceLoopCharacteristics isSequential="false" flowable:collection="serviceKeysToDelete" flowable:elementVariable="serviceKeyToProcess"></multiInstanceLoopCharacteristics>

‎multiapps-controller-process/src/main/resources/org/cloudfoundry/multiapps/controller/process/xs2-undeploy.bpmn‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -122,6 +122,9 @@
122122
<flowable:in source="correlationId" target="correlationId"/>
123123
<flowable:in source="__SPACE_ID" target="__SPACE_ID"/>
124124
<flowable:in source="isSecurityEnabled" target="isSecurityEnabled"></flowable:in>
125+
<flowable:in source="secureExtensionDescriptorParameterNames" target="secureExtensionDescriptorParameterNames"></flowable:in>
126+
<flowable:in source="isDisposableUserProvidedServiceEnabled" target="isDisposableUserProvidedServiceEnabled"></flowable:in>
127+
<flowable:in source="disposableUserProvidedServiceName" target="disposableUserProvidedServiceName"></flowable:in>
125128
<flowable:in source="mtaId" target="mtaId"></flowable:in>
126129
</extensionElements>
127130
<multiInstanceLoopCharacteristics isSequential="false" flowable:collection="serviceKeysToDelete" flowable:elementVariable="serviceKeyToProcess"></multiInstanceLoopCharacteristics>

0 commit comments

Comments
 (0)