10-25-2016 07:07 AM
Hello!
In a for i am trying to do an update of the same customer. In run mode the first update is doing ok, but the next is throwing the next exception:
09:46:30.776 [Thread-13] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[AND], piiElementHashes.IA_Company=[35c08c984e664772f702bc3e7729bbb8af4d497b7d7f3fcf21231d772604a26e], piiElementHashes.IA_Num_Client=[e664fee0cb398cae461f88103e1ce57e0ce0920180929658396af9383a4bd493], type=[customer]}
09:46:30.812 [Thread-28] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[AND], piiElementHashes.IA_Company=[35c08c984e664772f702bc3e7729bbb8af4d497b7d7f3fcf21231d772604a26e], piiElementHashes.IA_Num_Client=[d121f70602566fc7a0559d4773367dd93809763033e81d67fa5dc0036ce6d33f], type=[customer]}
09:46:30.897 [Thread-36] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[OR], customerId=[570cb380-85af-11e6-abf0-eb3e5baf184d], type=[pod]}
09:46:31.099 [Thread-39] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[AND], piiElementHashes.IA_Company=[35c08c984e664772f702bc3e7729bbb8af4d497b7d7f3fcf21231d772604a26e], piiElementHashes.IA_Num_Client=[d210976dcb3ee354c8aa4e77d5b59c53f732eda05d204c723fb15a986103c937], type=[customer]}
09:46:31.135 [Thread-23] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[AND], piiElementHashes.IA_Company=[35c08c984e664772f702bc3e7729bbb8af4d497b7d7f3fcf21231d772604a26e], piiElementHashes.IA_Num_Client=[d121f70602566fc7a0559d4773367dd93809763033e81d67fa5dc0036ce6d33f], type=[customer]}
09:46:31.201 [Thread-32] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList metrics size= 18
09:46:31.202 [Thread-32] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList size= 18
09:46:31.202 [Thread-32] DEBUG c.c.t.metrics.ClientMetricsManager - logReportingEventBeanList size= 0
09:46:31.211 [Thread-22] INFO com.cisco.thunderhead.RESTClient - ERROR HTTP STATUS = 400
09:46:31.312 [Thread-22] INFO com.cisco.thunderhead.RESTClient - Error on UPDATE: https://context-service.produs1.ciscoccservice.com/context/context/v1/id/c3960ff0-921c-11e6-8a19-41afa69a6ea9
com.cisco.thunderhead.errors.InvalidInputRestApiException: java.lang.Exception: {"errorType":"syncError","errorData":"lastUpdated","errorMessage":"Last updated date (2016-10-14T15:40:31.772Z) does not match db., trackingId: b600b900-d470-423e-83b4-1d459d0de529"}: RestApiError with errorType: syncError, errorData: lastUpdated, errorMessage: Last updated date (2016-10-14T15:40:31.772Z) does not match db., trackingId: b600b900-d470-423e-83b4-1d459d0de529
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_101]
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_101]
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_101]
at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[na:1.8.0_101]
at com.cisco.thunderhead.errors.ApiExceptionFactory.getApiException(ApiExceptionFactory.java:78) ~[context-service-sdk-extension-2.0.2-10370.jar:na]
at com.cisco.thunderhead.errors.ApiExceptionFactory.generateApiException(ApiExceptionFactory.java:113) ~[context-service-sdk-extension-2.0.2-10370.jar:na]
at com.cisco.thunderhead.RESTClient.createExceptionFromErrorString(RESTClient.java:841) [context-service-sdk-extension-2.0.2-10370.jar:na]
at com.cisco.thunderhead.RESTClient.throwApiException(RESTClient.java:858) [context-service-sdk-extension-2.0.2-10370.jar:na]
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:671) [context-service-sdk-extension-2.0.2-10370.jar:na]
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:648) [context-service-sdk-extension-2.0.2-10370.jar:na]
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:705) [context-service-sdk-extension-2.0.2-10370.jar:na]
at com.cisco.thunderhead.client.BaseEncryptionService.encryptAndUpdate(BaseEncryptionService.java:160) [context-service-sdk-extension-2.0.2-10370.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl$2.execute(ContextServiceClientImpl.java:420) [context-service-sdk-extension-2.0.2-10370.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl$2.execute(ContextServiceClientImpl.java:416) [context-service-sdk-extension-2.0.2-10370.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl$ContextCallable.call(ContextServiceClientImpl.java:1099) [context-service-sdk-extension-2.0.2-10370.jar:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_101]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_101]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_101]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_101]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_101]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_101]
Caused by: java.lang.Exception: {"errorType":"syncError","errorData":"lastUpdated","errorMessage":"Last updated date (2016-10-14T15:40:31.772Z) does not match db., trackingId: b600b900-d470-423e-83b4-1d459d0de529"}
... 15 common frames omitted
09:46:31.325 [Thread-22] ERROR c.c.t.c.ContextServiceClientImpl - RestApiError with errorType: syncError, errorData: lastUpdated, errorMessage: Last updated date (2016-10-14T15:40:31.772Z) does not match db., trackingId: b600b900-d470-423e-83b4-1d459d0de529
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.cisco.thunderhead.errors.ApiExceptionFactory.getApiException(ApiExceptionFactory.java:78)
at com.cisco.thunderhead.errors.ApiExceptionFactory.generateApiException(ApiExceptionFactory.java:113)
at com.cisco.thunderhead.RESTClient.createExceptionFromErrorString(RESTClient.java:841)
at com.cisco.thunderhead.RESTClient.throwApiException(RESTClient.java:858)
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:671)
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:648)
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:705)
at com.cisco.thunderhead.client.BaseEncryptionService.encryptAndUpdate(BaseEncryptionService.java:160)
at com.cisco.thunderhead.client.ContextServiceClientImpl$2.execute(ContextServiceClientImpl.java:420)
at com.cisco.thunderhead.client.ContextServiceClientImpl$2.execute(ContextServiceClientImpl.java:416)
at com.cisco.thunderhead.client.ContextServiceClientImpl$ContextCallable.call(ContextServiceClientImpl.java:1099)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.Exception: {"errorType":"syncError","errorData":"lastUpdated","errorMessage":"Last updated date (2016-10-14T15:40:31.772Z) does not match db., trackingId: b600b900-d470-423e-83b4-1d459d0de529"}
... 15 more
How can I fix this? Thanks
10-26-2016 03:30 PM
Hi Rodica,
Based on the error stacktrace you have provided, it seems like that after the first update you are not performing GET. You might be updating a local record and trying to push another update. Because of this, last updated timestamp on client does not match with server and that is why you are seeing the error.
Here is what you should do:
1) Perform first update
2) Get the customer
3) Perform second update
Thank you
Ankit Parikh
10-26-2016 04:47 PM
Hi Rodica,
While you try what we recommended, can you please also share your sample code? (Please remove connection data from the sample program before you share it).
Thank you
Ankit Parikh
10-28-2016 09:05 AM
Hello!
The algorith is very simple:
public static void main(String args[]) {
ArgumentImport arguments = new ArgumentImport(args);
// initialize the Context Service SDK using the connection data
contextServiceClient = IAConnectorFactory.initContextServiceClient(arguments.CONNECTIONDATA);
parseDeltaFile();
if (contextServiceClient != null)
contextServiceClient.destroy();
System.out.println("\n\n*** Finished ***\n\n");
}
private static void parseDeltaFile() {
for (int i = 0; i < 1000; i++) {
List<Customer> customerList = searchForCustomerByIANumClientAndIACompany("FOUK740613034", "0");
if (!customerList.isEmpty()) {
Customer customer = customerList.get(0);
contextServiceClient.update(customer);
}
}
}
/**
* Search for customer matching iANumClient and iACompany fields.
*
* @param iANumClient-the
* number of the customer
* @param iACompany
* -the company of the client
*
* iANumClient & iACompany are the unique key for the customer
*
* @return List of customers matching the criteria
*/
public static List<Customer> searchForCustomerByIANumClientAndIACompany(String iANumClient, String iACompany) {
SearchParameters params = new SearchParameters();
params.add(IA_NUM_CLIENT, iANumClient);
params.add(IA_COMPANY, iACompany);
List<Customer> result = contextServiceClient.search(Customer.class, params, Operation.AND);
return result;
}
The log file:
12:02:29.239 [main] INFO c.c.t.plugin.ConnectorFactory - Current path :E:\CCS\workspace\sdk_example\.
12:02:29.244 [main] INFO c.c.t.plugin.ConnectorFactory - loadConfigurations path :E:\CCS\workspace\sdk_example\connector.property
12:02:30.494 [main] INFO c.c.t.plugin.ConnectorFactory - >>> Inside resetPluginManager: getConnectorDestroyInProcess()
12:02:30.495 [main] INFO c.c.t.plugin.ConnectorFactory - Loading extensions from jarPath :E:\CCS\workspace\sdk_example\plugin\context-service-sdk-downloads\context-service-sdk-extension-2.0.2-10379.jar
12:02:30.676 [main] INFO c.c.t.loader.JarClassLoader - JarClassLoader: fatJarPath=file:/E:/CCS/workspace/sdk_example/plugin/context-service-sdk-downloads/context-service-sdk-extension-2.0.2-10379.jar
12:02:30.676 [main] INFO c.c.t.loader.JarClassLoader - JarClassLoader: after setupClassInFatJar, classToJarFileMap size=7868
12:02:30.873 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - loading new implClass in ConnectorProxyInvocationHandler = com.cisco.thunderhead.connector.impl.ManagementConnectorImpl@3386c206
12:02:30.873 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Getting cached init params and connector state
12:02:30.874 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Ignoring initializing new connector because cached parameters are empty
12:02:30.874 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Setting update Listeners and PersistentInfo/connectorState for newImplClass: com.cisco.thunderhead.connector.impl.ManagementConnectorImpl@3386c206
12:02:30.875 [main] INFO c.c.t.c.u.impl.SoftwareUpdateImpl - Setting connector state from previous version
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Versions are swapped
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Swapping versions from null to com.cisco.thunderhead.connector.impl.ManagementConnectorImpl@3386c206
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - loading new implClass in ConnectorProxyInvocationHandler = com.cisco.thunderhead.client.ContextServiceClientImpl@d504137
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Getting cached init params and connector state
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Ignoring initializing new connector because cached parameters are empty
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Setting update Listeners and PersistentInfo/connectorState for newImplClass: com.cisco.thunderhead.client.ContextServiceClientImpl@d504137
12:02:30.876 [main] INFO c.c.t.c.u.impl.SoftwareUpdateImpl - Setting connector state from previous version
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Versions are swapped
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Swapping versions from null to com.cisco.thunderhead.client.ContextServiceClientImpl@d504137
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - loading new implClass in ConnectorProxyInvocationHandler = com.cisco.thunderhead.connector.impl.RegisteringApplicationImpl@8432469
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Getting cached init params and connector state
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Ignoring initializing new connector because cached parameters are empty
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Versions are swapped
12:02:30.876 [main] INFO c.c.t.p.ConnectorProxyInvocationHandler - Swapping versions from null to com.cisco.thunderhead.connector.impl.RegisteringApplicationImpl@8432469
12:02:30.877 [main] INFO c.c.t.plugin.ConnectorFactory - ConnectorFactory.resetPluginManager - completed oldPluginManager shutdown
12:02:30.877 [main] INFO c.c.t.plugin.ConnectorFactory - Cleaning sequester directory...
12:02:30.877 [main] INFO c.c.t.plugin.ConnectorFactory - Not deleting: context-service-sdk-extension-2.0.2-10379.jar
12:02:30.878 [main] INFO c.c.t.plugin.ConnectorFactory - Cleaned sequester directory.
12:02:30.878 [main] INFO c.c.t.plugin.ConnectorFactory - ConnectorFactory.resetPluginManager - done
ContextServiceClient version : 2.0.2-10379
12:02:31.301 [main] INFO c.c.t.connector.impl.ConnectorImpl - [com.cisco.thunderhead.client.ContextServiceClientImpl@d504137] start init, ConnectorState=UNREGISTERED
12:02:31.669 [main] INFO c.c.t.connector.impl.ConnectorImpl - Creating executor with thread pool size: 50
12:02:31.671 [main] INFO c.c.t.connector.impl.ConnectorImpl - [com.cisco.thunderhead.client.ContextServiceClientImpl@d504137] needManagementConnector(configuration) true, construct this.fusionConnector
12:02:34.216 [Thread-2] INFO c.c.t.c.i.c.OAuthTokenFetcherUtils - Retrieving SAML Bearer Assertion
12:02:35.625 [Thread-2] INFO c.c.t.c.i.c.OAuthTokenFetcherUtils - Exchanging SAML Bearer Assertion for access token.
12:02:36.210 [Thread-2] INFO c.c.t.c.i.c.RequestNewTokenTask - Obtained new token
12:02:36.210 [main] INFO c.c.t.c.impl.fusion.FuseRestClient - Fuse REST client obtained oAuthClient <com.cisco.thunderhead.connector.impl.clientoauth.NonBlockingOAuthClient@53d808ea> with scopes: squared-fusion-mgmt:management
12:02:36.234 [main] INFO c.c.t.c.i.f.daemon.HeartBeatDaemon - HeartBeatTask Sending: {"id":"cs_context@0944b723-ef25-4cc5-aaf5-7e330347829a","serial":"0944b723-ef25-4cc5-aaf5-7e330347829a","host_name":"sva0740/10.1.0.86","connector_type":"cs_context","cluster_id":"92770022-5291-4dd9-95fe-f0da9658d6ee","cluster_name":"custom-context-1571FB0D892","version":"2.0.2-10379","status":{"state":"running","startTimestamp":0}}
12:02:36.715 [main] INFO c.c.t.c.i.f.daemon.HeartBeatDaemon - [com.cisco.thunderhead.connector.impl.fusion.daemon.HeartBeatDaemon@2a504ea7] HeartBeatTask Received: {"id":"cs_context@0944b723-ef25-4cc5-aaf5-7e330347829a","cluster_id":"92770022-5291-4dd9-95fe-f0da9658d6ee","display_name":"Context Connector","host_name":"sva0740/10.1.0.86","cluster_name":"custom-context-1571FB0D892","connector_type":"cs_context","version":"2.0.2-10379","serial":"0944b723-ef25-4cc5-aaf5-7e330347829a","status":{"state":"running","maintenance_mode":false,"alarms":[],"startTimestamp":"0"},"registered_by":"d2e8c3f1-1015-4a61-b5a8-ecfcf89d3082","provisioning":{"connectors":[{"connector_type":"cs_context","display_name":"Context Connector","version":"1.0.8-10372","packages":[{"tlp_url":"https://context-service-downloads.produs1.ciscoccservice.com/files/latest/context-service-sdk-extension-1.0.8.jar"}],"package":{"url":"https://context-service-downloads.produs1.ciscoccservice.com/files/latest/context-service-sdk-extension-1.0.8.jar","versions":[{"static":"2.0.1","extension":"2.0.2-10379","url":"https://context-service-downloads.produs1.ciscoccservice.com/files/latest/context-service-sdk-extension-2.0.2.jar"},{"static":"1.0.7","extension":"1.0.8-10372","url":"https://context-service-downloads.produs1.ciscoccservice.com/files/latest/context-service-sdk-extension-1.0.8.jar"}]}}],"dependencies":[],"heartbeatInterval":30},"properties":{"_.targetType":"cs_mgmt","fms.releaseChannel":"stable"}}
12:02:36.717 [main] INFO c.c.t.c.i.f.daemon.HeartBeatDaemon - [com.cisco.thunderhead.connector.impl.fusion.daemon.HeartBeatDaemon@2a504ea7] no need to upgrade: Version is not a minor update. Installed: 2.0.2-10379 Provisioned Version: 2.0.2-10379
12:02:36.717 [main] INFO c.c.t.connector.impl.ConnectorImpl - [com.cisco.thunderhead.client.ContextServiceClientImpl@d504137] call startConnector(connectionData, configuration)
12:02:36.718 [main] INFO c.c.t.c.ContextServiceClientImpl - Initializing system with params. Timeouts: 10000 Retries: 2 Lab Mode: false
12:02:36.718 [main] INFO c.c.t.metrics.ClientMetricsManager - Setting SDK version: 2.0.2-10379
12:02:36.718 [main] INFO c.c.t.metrics.ClientMetricsManager - Setting metris prefix: 1c113969-7fdd-488f-8068-3b43244a1b44.Cdae9e2ac5b6fb800a56b970e836c0c5ca84ca96d1a3fa681f8b4c7ae35e5afb8.d2e8c3f1-1015-4a61-b5a8-ecfcf89d3082
12:02:37.407 [Thread-2] INFO c.c.t.c.i.c.OAuthTokenFetcherUtils - Retrieving SAML Bearer Assertion
12:02:37.713 [Thread-2] INFO c.c.t.c.i.c.OAuthTokenFetcherUtils - Exchanging SAML Bearer Assertion for access token.
12:02:38.084 [Thread-2] INFO c.c.t.c.i.c.RequestNewTokenTask - Obtained new token
12:02:38.310 [main] INFO c.c.t.c.ContextServiceClientImpl - Found Endpoints:
12:02:38.311 [main] INFO c.c.t.c.ContextServiceClientImpl - context: 1:https://context-service.produs1.ciscoccservice.com
12:02:38.311 [main] INFO c.c.t.c.ContextServiceClientImpl - dictionary: 1:https://dictionary.produs1.ciscoccservice.com
12:02:38.311 [main] INFO c.c.t.c.ContextServiceClientImpl - eventing: 1:https://eventing.produs1.ciscoccservice.com
12:02:38.311 [main] INFO c.c.t.c.ContextServiceClientImpl - kms: 1:https://encryption-a.wbx2.com
12:02:38.311 [main] INFO c.c.t.c.ContextServiceClientImpl - management: 1:https://management.produs1.ciscoccservice.com
12:02:38.317 [main] INFO c.c.t.c.ContextServiceClientImpl - ContextServiceEncryptionClient: management host found management.produs1.ciscoccservice.com
12:02:38.742 [main] INFO com.cisco.thunderhead.util.Utils - Found feature: KMS_ENCRYPTION_KEY
12:02:38.742 [main] INFO c.c.t.c.ContextServiceClientImpl - ContextServiceEncryptionClient: dictionary host found dictionary.produs1.ciscoccservice.com
12:02:39.153 [main] INFO c.c.t.c.ContextServiceClientImpl - ContextServiceEncryptionClient: eventing host found eventing.produs1.ciscoccservice.com
12:02:39.413 [main] INFO c.c.t.c.ContextServiceClientImpl - ContextServiceEncryptionClient: kms host found encryption-a.wbx2.com
12:02:39.697 [main] INFO c.c.thunderhead.kms.KmsSecureChannel - Attempting to establish KMS secure channel with device ID 57360257-a8ce-4253-8c18-5cb893af301e
12:02:39.698 [Thread-5] INFO c.c.t.c.i.c.OAuthTokenFetcherUtils - Retrieving SAML Bearer Assertion
12:02:39.911 [Thread-5] INFO c.c.t.c.i.c.OAuthTokenFetcherUtils - Exchanging SAML Bearer Assertion for access token.
12:02:40.097 [Thread-5] INFO c.c.t.c.i.c.RequestNewTokenTask - Obtained new token
12:02:40.487 [Thread-2] INFO c.c.thunderhead.kms.KmsSecureChannel - Successfully retrieved public key from KMS, using KMS cluster https://encryption-a.wbx2.com/encryption/api/v1
12:02:40.490 [Thread-6] INFO c.c.thunderhead.kms.KmsSecureChannel - Submitting request to establish KMS ephemeral key for device 57360257-a8ce-4253-8c18-5cb893af301e
12:02:40.490 [Thread-6] INFO c.c.thunderhead.kms.KmsSecureChannel - User Id: d2e8c3f1-1015-4a61-b5a8-ecfcf89d3082, KMS Request Owner Id: d2e8c3f1-1015-4a61-b5a8-ecfcf89d3082
12:02:41.276 [Thread-6] DEBUG c.c.thunderhead.kms.KmsSecureChannel - Submitting KMS request, requestId=c0f6c090-95a8-4a03-b14d-1ccc1fe8662a - create /ecdhe for type: EPHEMERAL_KEY_COLLECTION
12:02:41.687 [Thread-2] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList metrics size= 18
12:02:41.689 [Thread-2] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList size= 18
12:02:41.689 [Thread-2] DEBUG c.c.t.metrics.ClientMetricsManager - logReportingEventBeanList size= 0
12:02:41.962 [Thread-11] INFO c.c.t.c.i.c.OAuthTokenFetcherUtils - Retrieving SAML Bearer Assertion
12:02:42.162 [Thread-11] INFO c.c.t.c.i.c.OAuthTokenFetcherUtils - Exchanging SAML Bearer Assertion for access token.
12:02:42.453 [Thread-11] INFO c.c.t.c.i.c.RequestNewTokenTask - Obtained new token
12:02:42.641 [Thread-6] DEBUG c.c.thunderhead.kms.KmsSecureChannel - Successfully submitted KMS request c0f6c090-95a8-4a03-b14d-1ccc1fe8662a
12:02:42.697 [Thread-6] DEBUG c.c.thunderhead.kms.KmsSecureChannel - KMS request c0f6c090-95a8-4a03-b14d-1ccc1fe8662a succeeded.
12:02:42.703 [Thread-6] INFO c.c.thunderhead.kms.KmsSecureChannel - Established KMS ephemeral key (/ecdhe/df01e575-49fb-4646-b172-26d1b112cc4e) for device 57360257-a8ce-4253-8c18-5cb893af301e
12:02:42.706 [Thread-6] DEBUG c.c.thunderhead.kms.KmsSecureChannel - newEphemeralKey's createDate=Fri Oct 28 12:02:42 EDT 2016 and its expirationDate=Sat Oct 29 12:02:42 EDT 2016
12:02:42.706 [Thread-6] DEBUG c.c.thunderhead.kms.KmsSecureChannel - priorEphemeralKeyUri=null, currentEphemeralKeyUri=/ecdhe/df01e575-49fb-4646-b172-26d1b112cc4e
12:02:42.706 [Thread-6] DEBUG c.c.thunderhead.kms.KmsSecureChannel - Schedule next task of rotating ephemeral key in 82080 seconds.
12:02:43.098 [Thread-9] INFO com.cisco.thunderhead.util.Utils - Found feature: KMS_ENCRYPTION_KEY
12:02:43.203 [Thread-9] INFO c.c.t.k.OrgSpecificKmsResourceManager - Feature KMS_ENCRYPTION_KEY is enabled.
12:02:43.204 [Thread-8] INFO c.c.thunderhead.kms.KmsSecureChannel - User Id: d2e8c3f1-1015-4a61-b5a8-ecfcf89d3082, KMS Request Owner Id: d2e8c3f1-1015-4a61-b5a8-ecfcf89d3082
12:02:43.204 [Thread-8] DEBUG c.c.thunderhead.kms.KmsSecureChannel - Submitting KMS request, requestId=abd819af-5afe-4d8e-9116-5b5dc1636e35 - retrieve https://encryption-a.wbx2.com/encryption/api/v1/keys/bc58040b-302e-46be-a8bb-2f0cd36b13b7 for type: KEY
12:02:43.350 [Thread-8] DEBUG c.c.thunderhead.kms.KmsSecureChannel - Successfully submitted KMS request abd819af-5afe-4d8e-9116-5b5dc1636e35
12:02:43.360 [Thread-8] DEBUG c.c.thunderhead.kms.KmsSecureChannel - KMS request abd819af-5afe-4d8e-9116-5b5dc1636e35 succeeded.
12:02:43.360 [Thread-8] INFO c.c.t.k.OrgSpecificKmsResourceManager - Successfully loaded the hashing salt from key https://encryption-a.wbx2.com/encryption/api/v1/keys/bc58040b-302e-46be-a8bb-2f0cd36b13b7
12:02:43.395 [Thread-8] INFO c.c.t.k.OrgSpecificKmsResourceManager - Found valid key URL https://encryption-a.wbx2.com/encryption/api/v1/keys/606bbdc6-2d58-443d-a09d-2ff2f20497a8
12:02:43.396 [Thread-8] INFO c.c.thunderhead.kms.KmsSecureChannel - User Id: d2e8c3f1-1015-4a61-b5a8-ecfcf89d3082, KMS Request Owner Id: d2e8c3f1-1015-4a61-b5a8-ecfcf89d3082
12:02:43.402 [Thread-8] DEBUG c.c.thunderhead.kms.KmsSecureChannel - Submitting KMS request, requestId=0c998217-934c-445b-ba9e-b3c9044b7a10 - retrieve https://encryption-a.wbx2.com/encryption/api/v1/keys/606bbdc6-2d58-443d-a09d-2ff2f20497a8 for type: KEY
12:02:43.580 [Thread-8] DEBUG c.c.thunderhead.kms.KmsSecureChannel - Successfully submitted KMS request 0c998217-934c-445b-ba9e-b3c9044b7a10
12:02:43.583 [Thread-8] DEBUG c.c.thunderhead.kms.KmsSecureChannel - KMS request 0c998217-934c-445b-ba9e-b3c9044b7a10 succeeded.
12:02:43.587 [main] INFO com.cisco.thunderhead.kms.KmsManager - no Multitenancy - hashing Salt for default org: 1c113969-7fdd-488f-8068-3b43244a1b44
12:02:44.098 [main] INFO c.c.t.c.ContextServiceClientImpl - **** Context Service Client Initialization Complete. ****
12:02:44.497 [main] INFO c.c.t.c.i.c.NonBlockingOAuthClient - Creating executor with thread pool size: 8
12:02:44.753 [Thread-17] INFO c.c.t.c.i.c.OAuthTokenFetcherUtils - Retrieving SAML Bearer Assertion
12:02:45.131 [Thread-17] INFO c.c.t.c.i.c.OAuthTokenFetcherUtils - Exchanging SAML Bearer Assertion for access token.
12:02:45.433 [Thread-17] INFO c.c.t.c.i.c.RequestNewTokenTask - Obtained new token
12:02:45.434 [main] INFO c.c.t.c.impl.fusion.FuseRestClient - Fuse REST client obtained oAuthClient <com.cisco.thunderhead.connector.impl.clientoauth.NonBlockingOAuthClient@6baee63b> with scopes: squared-fusion-mgmt:management
12:02:45.441 [main] INFO c.c.t.connector.impl.ConnectorImpl - [com.cisco.thunderhead.client.ContextServiceClientImpl@d504137] [cs_context]: state change request, from UNREGISTERED to REGISTERED
12:02:45.441 [main] INFO c.c.t.connector.impl.ConnectorImpl - [com.cisco.thunderhead.client.ContextServiceClientImpl@d504137] init is completed.
*** Client Connector Connected ***
12:02:45.713 [Thread-5] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[AND], piiElementHashes.IA_Company=[0fa5db6cced9c18fb11ae06abe66714e84c66e5b1b8e7c78bb41f5ab301b616d], piiElementHashes.IA_Num_Client=[7ae0f0194632f7d9c97666ff5930589325350987c75ddf70ba4943c2199f9cdc], type=[customer]}
12:02:46.898 [Thread-9] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList metrics size= 24
12:02:46.898 [Thread-9] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList size= 24
12:02:46.898 [Thread-9] DEBUG c.c.t.metrics.ClientMetricsManager - logReportingEventBeanList size= 0
12:02:51.978 [Thread-9] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList metrics size= 0
12:02:51.978 [Thread-9] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList size= 0
12:02:51.978 [Thread-9] DEBUG c.c.t.metrics.ClientMetricsManager - logReportingEventBeanList size= 0
12:02:56.980 [Thread-9] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList metrics size= 0
12:02:56.980 [Thread-9] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList size= 0
12:02:56.980 [Thread-9] DEBUG c.c.t.metrics.ClientMetricsManager - logReportingEventBeanList size= 0
12:02:59.052 [Thread-8] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[AND], piiElementHashes.IA_Company=[0fa5db6cced9c18fb11ae06abe66714e84c66e5b1b8e7c78bb41f5ab301b616d], piiElementHashes.IA_Num_Client=[7ae0f0194632f7d9c97666ff5930589325350987c75ddf70ba4943c2199f9cdc], type=[customer]}
12:02:59.738 [Thread-20] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[AND], piiElementHashes.IA_Company=[0fa5db6cced9c18fb11ae06abe66714e84c66e5b1b8e7c78bb41f5ab301b616d], piiElementHashes.IA_Num_Client=[7ae0f0194632f7d9c97666ff5930589325350987c75ddf70ba4943c2199f9cdc], type=[customer]}
12:03:00.349 [Thread-7] INFO com.cisco.thunderhead.RESTClient - ERROR HTTP STATUS = 400
12:03:00.374 [Thread-7] INFO com.cisco.thunderhead.RESTClient - Error on UPDATE: https://context-service.produs1.ciscoccservice.com/context/context/v1/id/d31d4e10-9d26-11e6-9653-717401eb2581
com.cisco.thunderhead.errors.InvalidInputRestApiException: java.lang.Exception: {"errorType":"syncError","errorData":"lastUpdated","errorMessage":"Last updated date (2016-10-28T16:02:58.040Z) does not match db., trackingId: 16979795-22b5-421f-9b8e-2027852f186f"}: RestApiError with errorType: syncError, errorData: lastUpdated, errorMessage: Last updated date (2016-10-28T16:02:58.040Z) does not match db., trackingId: 16979795-22b5-421f-9b8e-2027852f186f
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_101]
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_101]
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_101]
at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[na:1.8.0_101]
at com.cisco.thunderhead.errors.ApiExceptionFactory.getApiException(ApiExceptionFactory.java:78) ~[context-service-sdk-extension-2.0.2-10379.jar:na]
at com.cisco.thunderhead.errors.ApiExceptionFactory.generateApiException(ApiExceptionFactory.java:113) ~[context-service-sdk-extension-2.0.2-10379.jar:na]
at com.cisco.thunderhead.RESTClient.createExceptionFromErrorString(RESTClient.java:841) [context-service-sdk-extension-2.0.2-10379.jar:na]
at com.cisco.thunderhead.RESTClient.throwApiException(RESTClient.java:858) [context-service-sdk-extension-2.0.2-10379.jar:na]
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:671) [context-service-sdk-extension-2.0.2-10379.jar:na]
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:648) [context-service-sdk-extension-2.0.2-10379.jar:na]
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:705) [context-service-sdk-extension-2.0.2-10379.jar:na]
at com.cisco.thunderhead.client.BaseEncryptionService.encryptAndUpdate(BaseEncryptionService.java:160) [context-service-sdk-extension-2.0.2-10379.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl$2.execute(ContextServiceClientImpl.java:420) [context-service-sdk-extension-2.0.2-10379.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl$2.execute(ContextServiceClientImpl.java:416) [context-service-sdk-extension-2.0.2-10379.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl$ContextCallable.call(ContextServiceClientImpl.java:1099) [context-service-sdk-extension-2.0.2-10379.jar:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_101]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_101]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_101]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_101]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_101]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_101]
Caused by: java.lang.Exception: {"errorType":"syncError","errorData":"lastUpdated","errorMessage":"Last updated date (2016-10-28T16:02:58.040Z) does not match db., trackingId: 16979795-22b5-421f-9b8e-2027852f186f"}
... 15 common frames omitted
12:03:00.384 [Thread-7] ERROR c.c.t.c.ContextServiceClientImpl - RestApiError with errorType: syncError, errorData: lastUpdated, errorMessage: Last updated date (2016-10-28T16:02:58.040Z) does not match db., trackingId: 16979795-22b5-421f-9b8e-2027852f186f
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.cisco.thunderhead.errors.ApiExceptionFactory.getApiException(ApiExceptionFactory.java:78)
at com.cisco.thunderhead.errors.ApiExceptionFactory.generateApiException(ApiExceptionFactory.java:113)
at com.cisco.thunderhead.RESTClient.createExceptionFromErrorString(RESTClient.java:841)
at com.cisco.thunderhead.RESTClient.throwApiException(RESTClient.java:858)
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:671)
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:648)
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:705)
at com.cisco.thunderhead.client.BaseEncryptionService.encryptAndUpdate(BaseEncryptionService.java:160)
at com.cisco.thunderhead.client.ContextServiceClientImpl$2.execute(ContextServiceClientImpl.java:420)
at com.cisco.thunderhead.client.ContextServiceClientImpl$2.execute(ContextServiceClientImpl.java:416)
at com.cisco.thunderhead.client.ContextServiceClientImpl$ContextCallable.call(ContextServiceClientImpl.java:1099)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.Exception: {"errorType":"syncError","errorData":"lastUpdated","errorMessage":"Last updated date (2016-10-28T16:02:58.040Z) does not match db., trackingId: 16979795-22b5-421f-9b8e-2027852f186f"}
... 15 more
10-28-2016 09:14 AM
2) Get the customer
Here I got the problem: there's a way to know what is the last updated customer in the db? I didn't find this in the context-service-sdk-guide. The getLastUpdated() method is giving me the lastUpdated time in the daemon thread launched by cisco context service library, but not the last updated time in the db; how can i get this last updated customer in the db?
Thnaks.
11-01-2016 08:31 AM
Hi Rodica,
hopefully the information below will clarify this issue.
Please let us know if still some questions.
Thanks you!
Release notes of the SDK doc says - "Newly created PODs are not visible to the search method for up to 1 second and can cause Read POD Step/node to return stale results. If you need to retrieve PODs at creation time, use get POD."
https://developer.cisco.com/site/context-service/documents/context-service-sdk-guide/index.gsp#version-2-0-1-current-version
The same applies to updates. Once the object , pod or customer , or request, is updated, the search results will not give you the newly updated version of the object immediately, but with some delay. That is why, in the customer app, the updated object has a new lastUpdated date assigned after the update, but it is not yet reflected in the search results that follow the update immediately.
The proper way to perform another update on just updated object is to do Get on it , obtain the lastUpdated => set it on the bean to be used in update and fire the actual UPDATE request. The code example for the same is below and we will update the do to be more clear on this.
//// Create some POD for testing
ContextBean bean = createDefaultBean();
List<String> fieldsets = new LinkedList<String>();
fieldsets.add(userConfig.getTestSubsetName()+".default");
bean.setDataElements(getCustomerTestDataElements());
bean.setFieldsets(fieldsets);
ClientResponse bean1Resp = contextServiceClient.create(bean);
String beanID1 = SDKUtils.getIdFromResponse(bean1Resp);
Thread.sleep(5000);
//Keep doing search and update on this POD in a loop
for(int i=0; i< 20 ; i++) {
// search for the created field
SearchParameters params = new SearchParameters() {{
add(userConfig.getTestSubsetName() + "_ssn", "AHMN81121324124009");
}};
List<Pod> searchPods = contextServiceClient.search(getClassType(), params, Operation.AND);
Pod newPod = searchPods.get(0);
newPod.setMediaType("voice");
//set any new data here
//////// IMPORTANT : to do before update ///////////////////
ContextBean ct1Bean = contextServiceClient.get(bean.getClass(), getRefURl(bean, beanID1));
newPod.setLastUpdated(ct1Bean.getLastUpdated());
//////// //////////////////////////////// ///////////////////
contextServiceClient.update(newPod);
}
11-01-2016 08:47 AM
Hello Tetyana,
Thank you for the information. That's what I was trying to found, can we update Customers immediately at creation time. I already implemented a similar solution, so I’m on the good way.
Thanks for your help.
Regards,
Rodica
11-10-2016 12:58 PM
Hello,
I have a new problem in my program, so I'm back. I have the program that read from a file line by line some information and for each line is doing a search for customer (by 2 fields IA_Company and IA_Num_Client taken from the file), some modification of the customer and an update in CCS data base.
After 11441 cycles the programme crashed with the exception (in the Rest_Exception file I put the whole exception trace):
What can be the cause of this error?
Total number of read lines:11441***
11:33:23.446 [Thread-36] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[AND], piiElementHashes.IA_Company=[35c08c984e664772f702bc3e7729bbb8af4d497b7d7f3fcf21231d772604a26e], piiElementHashes.IA_Num_Client=[43f0f0e517413252ea069e0a92aef68cba0a435324dce806a50853435a350214], type=[customer]}
11:33:33.462 [Thread-36] INFO com.cisco.thunderhead.RESTClient - Error on GET: https://context-service.produs1.ciscoccservice.com/context/context/v1/search?wg=production&op=AND&piiElementHashes.IA_Company=35c08c984e664772f702bc3e7729bbb8af4d497b7d7f3fcf21231d772604a26e&piiElementHashes.IA_Num_Client=43f0f0e517413252ea069e0a92ae...
11:33:33.478 [main] ERROR c.c.t.c.ContextServiceClientImpl - Timeout occurred. Timeout: 10000 Method: Search on Class: Customer true
I am just trying to confirm on various reasons this can happen and from what I understood the Cisco Server is trying to read data from the request, but its taking longer than the timeout value for the data to arrive from the client.
The question is: where can I change the timeout value for contextServiceClient.search() method ?
It’s the same that I gaved on configuration of the contextServiceClient?
ConnectorConfiguration config = new ConnectorConfiguration();
I started the application one more time and no Exception is coming. I don’t understand why was throwing such an Exception. There’s a problem with the connection? Why for 11400 rows it’s doing fine and suddenly a TimeoutException is thrown. How can I prevent this? The application should work automatically with no support, so it’s very important to know the reason of all the runtime exception and connection lost.
Thanks a lot for your help!
11-10-2016 01:00 PM
The whole exception (no ideea how to attach a file ).
Total number of read lines:11441***
11:33:23.446 [Thread-36] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[AND], piiElementHashes.IA_Company=[35c08c984e664772f702bc3e7729bbb8af4d497b7d7f3fcf21231d772604a26e], piiElementHashes.IA_Num_Client=[43f0f0e517413252ea069e0a92aef68cba0a435324dce806a50853435a350214], type=[customer]}
11:33:24.524 [Thread-29] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList metrics size= 12
11:33:24.524 [Thread-29] DEBUG c.c.t.metrics.ClientMetricsManager - processingExecutionBeanList size= 12
11:33:24.524 [Thread-29] DEBUG c.c.t.metrics.ClientMetricsManager - logReportingEventBeanList size= 0
11:33:33.462 [Thread-36] INFO com.cisco.thunderhead.RESTClient - Error on GET: https://context-service.produs1.ciscoccservice.com/context/context/v1/search?wg=production&op=AND&piiElementHashes.IA_Company=35c08c984e664772f702bc3e7729bbb8af4d497b7d7f3fcf21231d772604a26e&piiElementHashes.IA_Num_Client=43f0f0e517413252ea069e0a92ae...
11:33:33.478 [main] ERROR c.c.t.c.ContextServiceClientImpl - Timeout occurred. Timeout: 10000 Method: Search on Class: Customer true
at java.util.concurrent.FutureTask.get(FutureTask.java:205) ~[na:1.8.0_101]
at com.cisco.thunderhead.client.ContextServiceClientImpl.executeWithTimeout(ContextServiceClientImpl.java:1027) [context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl.search(ContextServiceClientImpl.java:572) [context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl.search(ContextServiceClientImpl.java:523) [context-service-sdk-extension-2.0.2-10384.jar:na]
at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_101]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_101]
at com.cisco.thunderhead.plugin.ConnectorProxyInvocationHandler.invoke(ConnectorProxyInvocationHandler.java:139) [context-service-sdk-2.0.1.jar:na]
at com.sun.proxy.$Proxy0.search(Unknown Source) [na:na]
at ia_importIntoCCS.ImportDataInCCS.searchForCustomerByIANumClientAndIACompany(ImportDataInCCS.java:395) [SupplyCCS.jar:na]
at ia_importIntoCCS.ImportDataInCCS.modifyLine(ImportDataInCCS.java:667) [SupplyCCS.jar:na]
at ia_importIntoCCS.ImportDataInCCS.parseDeltaFile(ImportDataInCCS.java:530) [SupplyCCS.jar:na]
at ia_importIntoCCS.ImportDataInCCS.main(ImportDataInCCS.java:134) [SupplyCCS.jar:na]
11:33:33.540 [Thread-36] ERROR com.cisco.thunderhead.RESTClient - Attempt to connect failed: type:timeoutRequest, data: path: /context/context/v1/search, message: Request timed out: com.sun.jersey.api.client.ClientHandlerException: java.net.SocketTimeoutException: Read timed out
at com.sun.jersey.client.apache4.ApacheHttpClient4Handler.handle(ApacheHttpClient4Handler.java:187)
at com.sun.jersey.api.client.Client.handle(Client.java:652)
at com.sun.jersey.api.client.WebResource.handle(WebResource.java:682)
at com.sun.jersey.api.client.WebResource.access$200(WebResource.java:74)
at com.sun.jersey.api.client.WebResource$Builder.get(WebResource.java:509)
at com.cisco.thunderhead.RESTClient.get(RESTClient.java:318)
at com.cisco.thunderhead.RESTClient.getList(RESTClient.java:373)
at com.cisco.thunderhead.client.ContextEncryptionService.searchAndDecrypt(ContextEncryptionService.java:145)
at com.cisco.thunderhead.client.ContextServiceClientImpl$4.execute(ContextServiceClientImpl.java:562)
at com.cisco.thunderhead.client.ContextServiceClientImpl$4.execute(ContextServiceClientImpl.java:558)
at com.cisco.thunderhead.client.ContextServiceClientImpl$ContextCallable.call(ContextServiceClientImpl.java:1077)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
at sun.security.ssl.InputRecord.read(InputRecord.java:503)
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)
at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)
at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:139)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:155)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:284)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:165)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:167)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:271)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:117)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
at com.sun.jersey.client.apache4.ApacheHttpClient4Handler.handle(ApacheHttpClient4Handler.java:173)
... 16 more
11:33:33.572 [Thread-36] ERROR c.c.t.c.ContextServiceClientImpl - RestApiError with errorType: timeoutRequest, errorData: path: /context/context/v1/search, errorMessage: Request timed out: com.sun.jersey.api.client.ClientHandlerException: java.net.SocketTimeoutException: Read timed out
at com.sun.jersey.client.apache4.ApacheHttpClient4Handler.handle(ApacheHttpClient4Handler.java:187)
at com.sun.jersey.api.client.Client.handle(Client.java:652)
at com.sun.jersey.api.client.WebResource.handle(WebResource.java:682)
at com.sun.jersey.api.client.WebResource.access$200(WebResource.java:74)
at com.sun.jersey.api.client.WebResource$Builder.get(WebResource.java:509)
at com.cisco.thunderhead.RESTClient.get(RESTClient.java:318)
at com.cisco.thunderhead.RESTClient.getList(RESTClient.java:373)
at com.cisco.thunderhead.client.ContextEncryptionService.searchAndDecrypt(ContextEncryptionService.java:145)
at com.cisco.thunderhead.client.ContextServiceClientImpl$4.execute(ContextServiceClientImpl.java:562)
at com.cisco.thunderhead.client.ContextServiceClientImpl$4.execute(ContextServiceClientImpl.java:558)
at com.cisco.thunderhead.client.ContextServiceClientImpl$ContextCallable.call(ContextServiceClientImpl.java:1077)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
at sun.security.ssl.InputRecord.read(InputRecord.java:503)
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)
at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)
at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:139)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:155)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:284)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:165)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:167)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:271)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:117)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
at com.sun.jersey.client.apache4.ApacheHttpClient4Handler.handle(ApacheHttpClient4Handler.java:173)
... 16 more
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.cisco.thunderhead.errors.ApiExceptionFactory.getApiException(ApiExceptionFactory.java:78)
at com.cisco.thunderhead.errors.ApiExceptionFactory.generateApiException(ApiExceptionFactory.java:113)
at com.cisco.thunderhead.RESTClient.mapClientExceptionToApiException(RESTClient.java:875)
at com.cisco.thunderhead.RESTClient.get(RESTClient.java:324)
at com.cisco.thunderhead.RESTClient.getList(RESTClient.java:373)
at com.cisco.thunderhead.client.ContextEncryptionService.searchAndDecrypt(ContextEncryptionService.java:145)
at com.cisco.thunderhead.client.ContextServiceClientImpl$4.execute(ContextServiceClientImpl.java:562)
at com.cisco.thunderhead.client.ContextServiceClientImpl$4.execute(ContextServiceClientImpl.java:558)
at com.cisco.thunderhead.client.ContextServiceClientImpl$ContextCallable.call(ContextServiceClientImpl.java:1077)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
at sun.security.ssl.InputRecord.read(InputRecord.java:503)
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)
at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)
at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:139)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:155)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:284)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:165)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:167)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:271)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:117)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
at com.sun.jersey.client.apache4.ApacheHttpClient4Handler.handle(ApacheHttpClient4Handler.java:173)
at com.sun.jersey.api.client.Client.handle(Client.java:652)
at com.sun.jersey.api.client.WebResource.handle(WebResource.java:682)
at com.sun.jersey.api.client.WebResource.access$200(WebResource.java:74)
at com.sun.jersey.api.client.WebResource$Builder.get(WebResource.java:509)
at com.cisco.thunderhead.RESTClient.get(RESTClient.java:318)
... 11 more
11:33:33.572 [main] INFO c.c.t.connector.impl.ConnectorImpl - STARTING DESTROY BASE CONNECTOR After Lock. Connector state is REGISTERED
11-11-2016 07:45 AM
Hi Rodica,
We looked at IA's org. We too see two timeout errors at the same time as you reported. Internally within the SDK, multiple REST calls are made for customer read/write operation. Two of them, one to get the customer and one to get its field definitions took too long. As a result, your customer SDK call failed. Now, we didn't see any latency in processing those at the server side, either for your org or for any other other. We then observed that calls from your client are generally taking a lot longer than usual in the 3-5 seconds range (round trip, from your client). This is abnormally high. Even across the globe from India to US, we've seen these calls take around 300-500 millisecond range. Currently, your timeout is set pretty high, at 10 seconds, hence you saw just one call fail. If you lowered it, I would imagine you would see more timeout. So the question is where is the network latency between your client and our services? Are you using a proxy? We've seen some slow proxies create delays. Can you try run this in a separate environment, run a controlled test, tell us exact time of run so we can check the latency again?
Thanks
Vikram
11-15-2016 11:46 AM
Hello Vikram,
Yesterday and last week I didn't have problems with RuntimeException. And I thought that finally everything is fine, but I lanced today my application 3 times for the same Delta file. In 2 of them the DB crashed.
We still have the problem with TimeOutException.
Here the answer I got from the analystes:
Perhaps Vikram could point to you a peace of code that we could use to test for latency ?
Or can you create a peace of code to test the latency that we could run on another server in a different environment?
Do you have a test for latency?
And I received today a new Exception: UnavailableException, errorMessage: Not enough replica available for query at consistency LOCAL_QUORUM (2 required but only 1 alive).
Usually when this exception happens it indicates that is an insufficient replication factor in the db. In our case where is the problem?
So the first run I got:
12:08:39.597 [Thread-13] DEBUG c.c.t.c.ContextEncryptionService - Search by field values is called for </context/context/v1/search> with parameters: {wg=[production], op=[AND], piiElementHashes.IA_Company=[35c08c984e664772f702bc3e7729bbb8af4d497b7d7f3fcf21231d772604a26e], piiElementHashes.IA_Num_Client=[46301399d645648c85702e179b1c6f9d29246affc60c28fd4867a6d3e369d94b], type=[customer]}
12:08:39.667 [Thread-41] INFO com.cisco.thunderhead.RESTClient - ERROR HTTP STATUS = 400
12:08:39.687 [Thread-41] INFO com.cisco.thunderhead.RESTClient - Error on CREATE: https://context-service.produs1.ciscoccservice.com/context/context/v1
com.cisco.thunderhead.errors.CassandraDatabaseRestApiException: java.lang.Exception: {"errorType":"databaseDriver.exception.queryExecution","errorData":"UnavailableException","errorMessage":"Not enough replica available for query at consistency LOCAL_QUORUM (2 required but only 1 alive), trackingId: a3495374-78e5-418c-82c1-abcf5e55c9b5"}: RestApiError with errorType: databaseDriver.exception.queryExecution, errorData: UnavailableException, errorMessage: Not enough replica available for query at consistency LOCAL_QUORUM (2 required but only 1 alive), trackingId: a3495374-78e5-418c-82c1-abcf5e55c9b5
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_101]
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_101]
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_101]
at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[na:1.8.0_101]
at com.cisco.thunderhead.errors.ApiExceptionFactory.getApiException(ApiExceptionFactory.java:78) ~[context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.errors.ApiExceptionFactory.generateApiException(ApiExceptionFactory.java:113) ~[context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.RESTClient.createExceptionFromErrorString(RESTClient.java:841) [context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.RESTClient.throwApiException(RESTClient.java:858) [context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.RESTClient.create(RESTClient.java:479) [context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.RESTClient.create(RESTClient.java:435) [context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.RESTClient.create(RESTClient.java:534) [context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.client.BaseEncryptionService.encryptAndCreate(BaseEncryptionService.java:134) [context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl$1.execute(ContextServiceClientImpl.java:366) [context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl$1.execute(ContextServiceClientImpl.java:362) [context-service-sdk-extension-2.0.2-10384.jar:na]
at com.cisco.thunderhead.client.ContextServiceClientImpl$ContextCallable.call(ContextServiceClientImpl.java:1077) [context-service-sdk-extension-2.0.2-10384.jar:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_101]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_101]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_101]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_101]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_101]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_101]
Caused by: java.lang.Exception: {"errorType":"databaseDriver.exception.queryExecution","errorData":"UnavailableException","errorMessage":"Not enough replica available for query at consistency LOCAL_QUORUM (2 required but only 1 alive), trackingId: a3495374-78e5-418c-82c1-abcf5e55c9b5"}
... 15 common frames omitted
And for the second:
12:33:37.484 [Thread-39] INFO com.cisco.thunderhead.RESTClient - Error on UPDATE: https://context-service.produs1.ciscoccservice.com/context/context/v1/id/a93b57c0-85cc-11e6-bc9e-7d84b7a5ad80
12:33:37.487 [Thread-39] ERROR com.cisco.thunderhead.RESTClient - Attempt to connect failed: type:timeoutRequest, data: path: /context/context/v1/id/a93b57c0-85cc-11e6-bc9e-7d84b7a5ad80, message: Request timed out: com.sun.jersey.api.client.ClientHandlerException: java.net.SocketTimeoutException: Read timed out
at com.sun.jersey.client.apache4.ApacheHttpClient4Handler.handle(ApacheHttpClient4Handler.java:187)
at com.sun.jersey.api.client.Client.handle(Client.java:652)
at com.sun.jersey.api.client.WebResource.handle(WebResource.java:682)
at com.sun.jersey.api.client.WebResource.access$200(WebResource.java:74)
at com.sun.jersey.api.client.WebResource$Builder.put(WebResource.java:539)
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:666)
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:648)
at com.cisco.thunderhead.RESTClient.update(RESTClient.java:705)
at com.cisco.thunderhead.client.BaseEncryptionService.encryptAndUpdate(BaseEncryptionService.java:160)
at com.cisco.thunderhead.client.ContextServiceClientImpl$2.execute(ContextServiceClientImpl.java:422)
at com.cisco.thunderhead.client.ContextServiceClientImpl$2.execute(ContextServiceClientImpl.java:418)
at com.cisco.thunderhead.client.ContextServiceClientImpl$ContextCallable.call(ContextServiceClientImpl.java:1077)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
I'm trying to understand how the Cisco DB is working to avoid such Exceptions, but I don't have success. Please, help me to understand where the bug is.
Thanks,
Rodica
11-16-2016 06:01 AM
Hi Rodika,
This issue does not seem related to your previously reported issue.
Can you please open a new thread so that we can keep two issues and their resolution separate?
Also, when you create a new thread, please collect all available log files and SDK version information. We will need to do some more investigation to determine the root cause of this issue. We will get back to you when we have more information.
Thank you
Ankit Parikh
11-16-2016 09:35 AM
Hello Ankit,
I opened a new thread on cisco context forum. It would be perfect to have an answer as fast as possible.
Thank you,
Rodica
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide