[AML-2341] Migration - Quote stuck in processing when deployed post-migration - Admax Local

Details

Type: Bug
Status: Closed
Priority: Major
Resolution: Fixed
Affects Version/s: Wickford
Fix Version/s: Wickford
Component/s: None
Labels:
None
Environment:
- Reseller UI - Build 91 RC 5
- Merchant UI - Build 91 RC 5
- SAPI - Build 301 RC 4
- Core - Johnston 2.2.1 RELEASE P1
- BidMgr - Johnston 2.2.1 RELEASE P6

Sprint:
Wickford - Sprint 7

Description

We are having an issue getting an order to deploy in QA3 post migration. Here is the history of this order so far:

Quote was created in Apponaug
System and data was migrated to Wickford
Quote was deployed via Groovy script (change order state) set to SCHEDULED to deploy today.
Order is stuck in processing state with the following error. Campaigns are created and active in AdWords but no ads or keywords are there.

013-10-11 12:37:30,421-41893464 [OrderScheduler_Worker-5] INFO com.thesearchagency.sapi.services.order.OrderStatusUpdateJob [] - Beginning update for 1 orders.
2013-10-11 12:37:30,423-41893466 [OrderScheduler_Worker-5] INFO com.thesearchagency.sapi.services.order.OrderService [] - Attempting to update order status for order 8add4cbb-9058-4532-9e2f-b391727293e2
2013-10-11 12:37:33,672-41896715 [OrderScheduler_Worker-5] ERROR com.thesearchagency.saas.core.services.user.UserServiceComponent [] - Error fetching user
com.thesearchagency.database.storage.StorageManagerException: package com.thesearchagency.database.storage.INVALID_KEY_EXCEPTION
at com.thesearchagency.database.storage.jdbc.BaseJDBCStorageManager.validateKey(BaseJDBCStorageManager.java:1104) ~[tsa-dao-2.2.0.jar:2.2.0]
at com.thesearchagency.database.storage.jdbc.SpringJDBCStorageManager.get(SpringJDBCStorageManager.java:125) ~[tsa-dao-2.2.0.jar:2.2.0]
at com.thesearchagency.database.storage.jdbc.SpringJDBCStorageManager.get(SpringJDBCStorageManager.java:63) ~[tsa-dao-2.2.0.jar:2.2.0]
at com.thesearchagency.database.storage.jdbc.BaseJDBCStorageManager.get(BaseJDBCStorageManager.java:129) ~[tsa-dao-2.2.0.jar:2.2.0]
at com.thesearchagency.saas.core.services.user.managers.dao.UserDAO.get(UserDAO.java:22) ~[aml-user-service-2.2.0.jar:2.2.0]
at sun.reflect.GeneratedMethodAccessor61.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.6.0_24]
at java.lang.reflect.Method.invoke(Method.java:616) ~[na:1.6.0_24]
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319) [aml-data-tool-2.2.0-BETA3.jar:2.2.0-BETA3]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:196) [aml-data-tool-2.2.0-BETA3.jar:2.2.0-BETA3]
at sun.proxy.$Proxy57.get(Unknown Source) ~[na:na]
at com.thesearchagency.saas.core.services.user.managers.UserManager.getUser(UserManager.java:111) ~[aml-user-service-2.2.0.jar:2.2.0]
at com.thesearchagency.saas.core.services.user.UserServiceComponent.getUser(UserServiceComponent.java:149) ~[aml-user-service-2.2.0.jar:2.2.0]
at sun.reflect.GeneratedMethodAccessor60.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.6.0_24]
at java.lang.reflect.Method.invoke(Method.java:616) ~[na:1.6.0_24]
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319) [aml-data-tool-2.2.0-BETA3.jar:2.2.0-BETA3]
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) [aml-data-tool-2.2.0-BETA3.jar:2.2.0-BETA3]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) [aml-data-tool-2.2.0-BETA3.jar:2.2.0-BETA3]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110) [aml-data-tool-2.2.0-BETA3.jar:2.2.0-BETA3]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [aml-data-tool-2.2.0-BETA3.jar:2.2.0-BETA3]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) [aml-data-tool-2.2.0-BETA3.jar:2.2.0-BETA3]
at sun.proxy.$Proxy58.getUser(Unknown Source) [na:na]
at com.thesearchagency.sapi.services.order.OrderService.updateOrder(OrderService.java:375) [OrderService.class:na]
at com.thesearchagency.sapi.services.order.DeploymentServiceHelper$8.call(DeploymentServiceHelper.java:1010) [DeploymentServiceHelper$8.class:na]
at com.thesearchagency.sapi.services.order.DeploymentServiceHelper$8.call(DeploymentServiceHelper.java:997) [DeploymentServiceHelper$8.class:na]
at com.thesearchagency.sapi.services.order.DeploymentServiceHelper.checkDeploymentState(DeploymentServiceHelper.java:183) [DeploymentServiceHelper.class:na]
at com.thesearchagency.sapi.services.order.OrderService.updateStatus(OrderService.java:452) [OrderService.class:na]
at com.thesearchagency.sapi.services.order.OrderStatusUpdateJob.updateDeployedOrders(OrderStatusUpdateJob.java:138) [OrderStatusUpdateJob.class:na]
at com.thesearchagency.sapi.services.order.OrderStatusUpdateJob.doRunUpdates(OrderStatusUpdateJob.java:98) [OrderStatusUpdateJob.class:na]
at com.thesearchagency.sapi.services.order.OrderStatusUpdateJob.execute(OrderStatusUpdateJob.java:66) [OrderStatusUpdateJob.class:na]
at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz-2.1.7.jar:na]
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz-2.1.7.jar:na]
2013-10-11 12:37:33,675-41896718 [OrderScheduler_Worker-5] ERROR com.thesearchagency.sapi.services.order.OrderService [] - Could not check the deployment status for Order[8add4cbb-9058-4532-9e2f-b391727293e2] due to exception: Error in the database!

From Listner/Core:

==> /home/TSAApp/apps/jboss-5.1.0.GA/tsa_messaging_node_server.log <==
12:38:46,334 INFO [LoggingInInterceptor] Inbound Message
----------------------------
ID: 7397
Address: /SMB-ADS/AdMaxDeploymentService
Encoding: UTF-8
Content-Type: text/xml; charset=UTF-8
Headers:

{cache-control=[no-cache], content-type=[text/xml; charset=UTF-8], connection=[keep-alive], host=[aml-svc-deploy:8080], Content-Length=[282], SOAPAction=[""], user-agent=[Apache CXF 2.7.5], Content-Type=[text/xml; charset=UTF-8], Accept=[*/*], pragma=[no-cache]}

Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><core:getCampaignsByCustomerID xmlns:core="http://thesearchagency.com/smb/core"><customerID>a51bdff6-23ec-4325-a919-5495ec9bedda</customerID></core:getCampaignsByCustomerID></soap:Body></soap:Envelope>
--------------------------------------
12:38:46,336 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,336 DEBUG [JdbcTemplate] Executing prepared SQL statement [select id, bpID, domain from mms_common.accounts where bpID = ?]
12:38:46,339 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'id' to property 'ID' of type int
12:38:46,340 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'bpID' to property 'BPID' of type class java.lang.String
12:38:46,340 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'domain' to property 'domain' of type class java.lang.String
12:38:46,341 INFO [AdMaxDeploymentServiceImpl] getCampaignsByCustomerID properties =

{smb-admax-deployment-service.port=8443, smb-admax-deployment-service.protocol=https, smb-admax-deployment-service.context.root=SMB-ADS, smb-admax-deployment-service.service.endpoint=AdMaxDeploymentService, smb-admax-deployment-service.feature.siteLinks=false, smb-admax-deployment-service.hostname=localhost}
12:38:46,341 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,341 DEBUG [JdbcTemplate] Executing prepared SQL statement [select campaigns.id, accountID, advertID, businessFunctionID, locationID, customerDisplayURL, customerDestinationURL, localeName from accounts join campaigns on accounts.id=campaigns.accountID where bpID=?]
12:38:46,342 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'id' to property 'ID' of type int
12:38:46,342 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'accountID' to property 'accountID' of type int
12:38:46,342 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'advertID' to property 'advertID' of type class java.lang.String
12:38:46,342 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'businessFunctionID' to property 'businessFunctionID' of type int
12:38:46,342 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'locationID' to property 'locationID' of type int
12:38:46,343 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'customerDisplayURL' to property 'customerDisplayURL' of type class java.lang.String
12:38:46,343 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'customerDestinationURL' to property 'customerDestinationURL' of type class java.lang.String
12:38:46,343 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'localeName' to property 'localeName' of type class java.lang.String
12:38:46,350 INFO [AdMaxDeploymentServiceImpl] getCampaignStatus 78: Active -> Active
12:38:46,350 INFO [AdMaxDeploymentWS] getCampaignsByCustomerID: 78 -> ACTIVE
12:38:46,351 INFO [ContentRepositoryServiceImpl] Inside ContentRepositoryServiceImpl Constructor : EntityId [0] BusinessTypeID [0] BusinessLocationID [0]
12:38:46,351 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,351 DEBUG [JdbcTemplate] Executing prepared SQL statement [select id from contentEntityMap where customerBpId=?]
12:38:46,355 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,355 DEBUG [JdbcTemplate] Executing prepared SQL statement [select id, customerBpId, dateAssigned, requestData from contentEntityMap where id=?]
12:38:46,358 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,358 DEBUG [JdbcTemplate] Executing prepared SQL statement [select * from accounts where description = ? ]
12:38:46,360 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,360 DEBUG [JdbcTemplate] Executing prepared SQL statement [SELECT count(1) FROM clients.externalCampaign LEFT JOIN clients.externalCampaignParent ON externalCampaignParentID = clients.externalCampaignParent.id WHERE clients.externalCampaign.accountID = ? AND enabled = 1 AND status <> 'Deleted' AND typeID = ? ]
12:38:46,362 INFO [LoggingInInterceptor] Outbound Message
---------------------------
ID: 7397
Encoding: UTF-8
Content-Type: text/xml
Headers: {}
Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><ns2:getCampaignsByCustomerIDResponse xmlns:ns2="http://thesearchagency.com/smb/core"><CampaignListResponse><customerID>a51bdff6-23ec-4325-a919-5495ec9bedda</customerID><domain>www.groovy.vom</domain><deploymentStatus>success</deploymentStatus><campaignList><campaignID>78</campaignID><businessAreaID>11210</businessAreaID><businessLocationID>36</businessLocationID><customLandingPage><destinationURL>http://www.groovy.vom</destinationURL><displayURL>www.groovy.vom</displayURL></customLandingPage><deploymentStatus>Success</deploymentStatus><campaignStatus>active</campaignStatus><localeName>en_us</localeName></campaignList></CampaignListResponse></ns2:getCampaignsByCustomerIDResponse></soap:Body></soap:Envelope>
--------------------------------------
12:38:46,374 INFO [LoggingInInterceptor] Inbound Message
----------------------------
ID: 7398
Address: /SMB-ADS/AdMaxDeploymentService
Encoding: UTF-8
Content-Type: text/xml; charset=UTF-8
Headers: {cache-control=[no-cache], content-type=[text/xml; charset=UTF-8], connection=[keep-alive], host=[aml-svc-deploy:8080], Content-Length=[291], SOAPAction=[""], user-agent=[Apache CXF 2.7.5], Content-Type=[text/xml; charset=UTF-8], Accept=[*/*], pragma=[no-cache]}
Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><core:getOperationErrors xmlns:core="http://thesearchagency.com/smb/core">
<operationErrorsRequest>
<campaigns>78</campaigns>
</operationErrorsRequest>
</core:getOperationErrors></soap:Body></soap:Envelope>
--------------------------------------
12:38:46,381 INFO [STDOUT] GCE_CAMPAIGNS:95, 94, 96
12:38:46,381 INFO [STDOUT] getOperationErrorsResponse query: SELECT `reason`, `field`, `trigger` FROM gce_campaignAdExtensionMapPendingChange INNER JOIN gce_campaignAdExtensionMapError ON gce_campaignAdExtensionMapPendingChange.campaignID = gce_campaignAdExtensionMapError.campaignID INNER JOIN gce_campaignAdExtensionMap ON gce_campaignAdExtensionMap.campaignID = gce_campaignAdExtensionMapPendingChange.campaignID WHERE gce_campaignAdExtensionMap.campaignID IN (95, 94, 96) AND gce_campaignAdExtensionMapPendingChange.isFailed='true'
12:38:46,383 INFO [STDOUT] getOperationErrorsResponse query: SELECT gce_feed.name as 'category', `reason`, `trigger`, `field` FROM gce_campaignFeedPendingChange INNER JOIN gce_campaignFeedError ON gce_campaignFeedPendingChange.`campaignFeedID` = gce_campaignFeedError.`campaignFeedID` INNER JOIN gce_campaignFeed ON gce_campaignFeed.id=gce_campaignFeedPendingChange.campaignFeedID INNER JOIN gce_feed ON gce_feed.id = gce_campaignFeed.feedID WHERE gce_campaignFeed.campaignID IN (95, 94, 96) AND gce_campaignFeedPendingChange.isFailed='true'
12:38:46,385 INFO [STDOUT] getOperationErrorsResponse query: SELECT gce_feed.name as 'category', `reason`, `trigger`, `field` FROM gce_feedPendingChange INNER JOIN gce_feedError ON gce_feedPendingChange.`feedID` = gce_feedError.`feedID` INNER JOIN gce_feed ON gce_feed.id=gce_feedError.`feedID` INNER JOIN gce_campaignFeed ON gce_campaignFeed.feedID=gce_feed.id WHERE gce_campaignFeed.campaignID IN (95, 94, 96) AND gce_feedPendingChange.isFailed='true'
12:38:46,386 INFO [STDOUT] getOperationErrorsResponse query: SELECT gce_feed.name as 'category', `reason`, `trigger`, `field` FROM gce_feedItemPendingChange INNER JOIN gce_feedItemError ON gce_feedItemPendingChange.`feedItemID` = gce_feedItemError.`feedItemID` INNER JOIN gce_feedItem ON gce_feedItem.id=gce_feedItemError.`feedItemID` INNER JOIN gce_campaignFeed ON gce_campaignFeed.feedID=gce_feedItem.feedID INNER JOIN gce_feed ON gce_feed.id = gce_feedItem.feedID WHERE gce_campaignFeed.campaignID IN (95, 94, 96) AND gce_feedItemPendingChange.isFailed='true'
12:38:46,388 INFO [STDOUT] getOperationErrorsResponse query: SELECT gce_feed.name as 'category', `reason`, `trigger`, `field` FROM gce_feedMappingPendingChange INNER JOIN gce_feedMappingError ON gce_feedMappingPendingChange.`feedMappingID` = gce_feedMappingError.`feedMappingID` INNER JOIN gce_feedMapping ON gce_feedMapping.id=gce_feedMappingError.`feedMappingID` INNER JOIN gce_campaignFeed ON gce_campaignFeed.feedID=gce_feedMapping.feedID INNER JOIN gce_feed ON gce_feed.id = gce_feedMapping.feedID WHERE gce_campaignFeed.campaignID IN (95, 94, 96) AND gce_feedMappingPendingChange.isFailed='true'
12:38:46,389 INFO [LoggingInInterceptor] Outbound Message
---------------------------
ID: 7398
Encoding: UTF-8
Content-Type: text/xml
Headers: {}
Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><ns2:getOperationErrorsResponse xmlns:ns2="http://thesearchagency.com/smb/core"><getOperationErrorsResponse/></ns2:getOperationErrorsResponse></soap:Body></soap:Envelope>
--------------------------------------
12:38:46,395 INFO [LoggingInInterceptor] Inbound Message
----------------------------
ID: 7399
Address: /SMB-ADS/AdMaxDeploymentService
Encoding: UTF-8
Content-Type: text/xml; charset=UTF-8
Headers: {cache-control=[no-cache], content-type=[text/xml; charset=UTF-8], connection=[keep-alive], host=[aml-svc-deploy:8080], Content-Length=[282], SOAPAction=[""], user-agent=[Apache CXF 2.7.5], Content-Type=[text/xml; charset=UTF-8], Accept=[*/*], pragma=[no-cache]}
Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><core:getCampaignsByCustomerID xmlns:core="http://thesearchagency.com/smb/core"><customerID>a51bdff6-23ec-4325-a919-5495ec9bedda</customerID></core:getCampaignsByCustomerID></soap:Body></soap:Envelope>
--------------------------------------
12:38:46,397 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,397 DEBUG [JdbcTemplate] Executing prepared SQL statement [select id, bpID, domain from mms_common.accounts where bpID = ?]
12:38:46,398 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'id' to property 'ID' of type int
12:38:46,398 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'bpID' to property 'BPID' of type class java.lang.String
12:38:46,398 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'domain' to property 'domain' of type class java.lang.String
12:38:46,399 INFO [AdMaxDeploymentServiceImpl] getCampaignsByCustomerID properties = {smb-admax-deployment-service.port=8443, smb-admax-deployment-service.protocol=https, smb-admax-deployment-service.context.root=SMB-ADS, smb-admax-deployment-service.service.endpoint=AdMaxDeploymentService, smb-admax-deployment-service.feature.siteLinks=false, smb-admax-deployment-service.hostname=localhost}

12:38:46,399 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,400 DEBUG [JdbcTemplate] Executing prepared SQL statement [select campaigns.id, accountID, advertID, businessFunctionID, locationID, customerDisplayURL, customerDestinationURL, localeName from accounts join campaigns on accounts.id=campaigns.accountID where bpID=?]
12:38:46,401 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'id' to property 'ID' of type int
12:38:46,401 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'accountID' to property 'accountID' of type int
12:38:46,401 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'advertID' to property 'advertID' of type class java.lang.String
12:38:46,401 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'businessFunctionID' to property 'businessFunctionID' of type int
12:38:46,402 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'locationID' to property 'locationID' of type int
12:38:46,402 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'customerDisplayURL' to property 'customerDisplayURL' of type class java.lang.String
12:38:46,402 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'customerDestinationURL' to property 'customerDestinationURL' of type class java.lang.String
12:38:46,402 DEBUG [ParameterizedBeanPropertyRowMapper] Mapping column 'localeName' to property 'localeName' of type class java.lang.String
12:38:46,404 INFO [AdMaxDeploymentServiceImpl] getCampaignStatus 78: Active -> Active
12:38:46,405 INFO [AdMaxDeploymentWS] getCampaignsByCustomerID: 78 -> ACTIVE
12:38:46,405 INFO [ContentRepositoryServiceImpl] Inside ContentRepositoryServiceImpl Constructor : EntityId [0] BusinessTypeID [0] BusinessLocationID [0]
12:38:46,406 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,406 DEBUG [JdbcTemplate] Executing prepared SQL statement [select id from contentEntityMap where customerBpId=?]
12:38:46,409 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,409 DEBUG [JdbcTemplate] Executing prepared SQL statement [select id, customerBpId, dateAssigned, requestData from contentEntityMap where id=?]
12:38:46,410 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,411 DEBUG [JdbcTemplate] Executing prepared SQL statement [select * from accounts where description = ? ]
12:38:46,413 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,413 DEBUG [JdbcTemplate] Executing prepared SQL statement [SELECT count(1) FROM clients.externalCampaign LEFT JOIN clients.externalCampaignParent ON externalCampaignParentID = clients.externalCampaignParent.id WHERE clients.externalCampaign.accountID = ? AND enabled = 1 AND status <> 'Deleted' AND typeID = ? ]
12:38:46,415 INFO [LoggingInInterceptor] Outbound Message
---------------------------
ID: 7399
Encoding: UTF-8
Content-Type: text/xml
Headers: {}
Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><ns2:getCampaignsByCustomerIDResponse xmlns:ns2="http://thesearchagency.com/smb/core"><CampaignListResponse><customerID>a51bdff6-23ec-4325-a919-5495ec9bedda</customerID><domain>www.groovy.vom</domain><deploymentStatus>success</deploymentStatus><campaignList><campaignID>78</campaignID><businessAreaID>11210</businessAreaID><businessLocationID>36</businessLocationID><customLandingPage><destinationURL>http://www.groovy.vom</destinationURL><displayURL>www.groovy.vom</displayURL></customLandingPage><deploymentStatus>Success</deploymentStatus><campaignStatus>active</campaignStatus><localeName>en_us</localeName></campaignList></CampaignListResponse></ns2:getCampaignsByCustomerIDResponse></soap:Body></soap:Envelope>
--------------------------------------
12:38:46,427 INFO [LoggingInInterceptor] Inbound Message
----------------------------
ID: 7400
Address: /SMB-ADS/AdMaxDeploymentService
Encoding: UTF-8
Content-Type: text/xml; charset=UTF-8
Headers:

{cache-control=[no-cache], content-type=[text/xml; charset=UTF-8], connection=[keep-alive], host=[aml-svc-deploy:8080], Content-Length=[571], SOAPAction=[""], user-agent=[Apache CXF 2.7.5], Content-Type=[text/xml; charset=UTF-8], Accept=[*/*], pragma=[no-cache]}

Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><core:updateCampaignStatus xmlns:core="http://thesearchagency.com/smb/core">
<updateCampaignStatusRequest>
<header>
<requestID>8add4cbb-9058-4532-9e2f-b391727293e2</requestID>
</header>
<customerID>a51bdff6-23ec-4325-a919-5495ec9bedda</customerID>
<campaignStatusList>
<campaignID>78</campaignID>
<campaignStatus>active</campaignStatus>
</campaignStatusList>
</updateCampaignStatusRequest>
</core:updateCampaignStatus></soap:Body></soap:Envelope>
--------------------------------------
12:38:46,429 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,430 DEBUG [JdbcTemplate] Executing prepared SQL statement [select * from accounts where description = ? ]
12:38:46,434 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,434 DEBUG [JdbcTemplate] Executing prepared SQL statement [select * from sites where accountID = ? ]
12:38:46,436 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,436 DEBUG [JdbcTemplate] Executing prepared SQL statement [select * from waypoints where siteID = ? ]
12:38:46,455 WARN [QueueUtils] Setting message priority to 4
12:38:46,475 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,475 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,475 DEBUG [JdbcTemplate] Executing prepared SQL statement [select id from mms_common.blacklist where customerBpId = ?]
12:38:46,475 DEBUG [JdbcTemplate] Executing prepared SQL statement [select responseMsg from mms_common.campUpdateResp where deploymentID = ?]
12:38:46,477 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,477 DEBUG [JdbcTemplate] Executing prepared SQL statement [select id from mms_common.requests r where r.requestType = ? and r.deploymentID = ?]
12:38:46,481 INFO [AdMaxDeploymentFauxSyncMessenger] Starting campaign status update blocking loop
12:38:46,481 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,481 DEBUG [JdbcTemplate] Executing prepared SQL statement [select responseMsg from mms_common.campUpdateResp where deploymentID = ?]
12:38:46,487 WARN [AdMaxDeploymentRequestMDB] UPDATE request with deployID 8add4cbb-9058-4532-9e2f-b391727293e2, account a51bdff6-23ec-4325-a919-5495ec9bedda has already been sent to the listener.
12:38:46,494 WARN [QueueUtils] Setting message priority to 9
12:38:46,498 INFO [AdMaxDeploymentRequestMDB] Sent UPDATE request to listener. BPID: a51bdff6-23ec-4325-a919-5495ec9bedda DeployID: 8add4cbb-9058-4532-9e2f-b391727293e2

==> /var/local/tsa/log/tsa-admax-jmslistener/tsa-admax-jmslistener.log <==
2013-10-11 12:38:46.498 (3) [Thread-9]: Request added to map for customerID a51bdff6-23ec-4325-a919-5495ec9bedda
2013-10-11 12:38:46.498 (3) [Thread-9]: HighPriorityMessageHandler handling message ID ID:JBM-66bbb654-da61-464b-aa8a-cde545a19f17
2013-10-11 12:38:46.498 (3) [Thread-9]: Request worker created for a51bdff6-23ec-4325-a919-5495ec9bedda
2013-10-11 12:38:46.499 (3) [Thread-9]: Submitted executor job for a51bdff6-23ec-4325-a919-5495ec9bedda
2013-10-11 12:38:46.501 (3) [Thread-9]: HighPriorityMessageHandler took message ID ID:JBM-66bbb654-da61-464b-aa8a-cde545a19f17 out of queue

==> /home/TSAApp/apps/jboss-5.1.0.GA/tsa_messaging_node_server.log <==
12:38:46,531 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:46,532 DEBUG [JdbcTemplate] Executing prepared SQL statement [select * from admaxAccountAnniversary where accountId = ? and endDate is NULL]

==> /var/local/tsa/log/tsa-admax-jmslistener/tsa-admax-jmslistener.log <==
2013-10-11 12:38:46.553 (3) [pool-3-thread-12]: Updating deployment status to 'InProgress' for campaignID: 78
2013-10-11 12:38:46.557 (3) [pool-3-thread-12]: Start processing UPDATE request (8add4cbb-9058-4532-9e2f-b391727293e2) for account a51bdff6-23ec-4325-a919-5495ec9bedda. 3 campaign(s).
2013-10-11 12:38:46.557 (3) [pool-3-thread-12]: Performing update for account: a51bdff6-23ec-4325-a919-5495ec9bedda ID#32
2013-10-11 12:38:46.562 (3) [pool-3-thread-12]: 3 campaign(s) to update.
2013-10-11 12:38:46.562 (3) [pool-3-thread-12]: 0 campaign(s) to retry and update.
2013-10-11 12:38:46.566 (3) [pool-3-thread-12]: CampaignWorker initialized for account: 32
2013-10-11 12:38:46.566 (3) [pool-3-thread-12]: Updating a51bdff6-23ec-4325-a919-5495ec9bedda_11210_36_78_GM Status: Active
2013-10-11 12:38:46.566 (3) [pool-3-thread-12]: Updating a51bdff6-23ec-4325-a919-5495ec9bedda_11210_36_78_GT Status: Active
2013-10-11 12:38:46.566 (3) [pool-3-thread-12]: Updating a51bdff6-23ec-4325-a919-5495ec9bedda_11210_36_78_MO Status: Active
2013-10-11 12:38:46.566 (3) [pool-3-thread-12]: CampaignUpdateWorker started...
2013-10-11 12:38:46.580 (3) [pool-3-thread-12]: a51bdff6-23ec-4325-a919-5495ec9bedda_11210_36_78_GT is already set to Active in the database.
2013-10-11 12:38:46.580 (3) [pool-3-thread-12]: No budget update required
2013-10-11 12:38:46.580 (3) [pool-3-thread-12]: a51bdff6-23ec-4325-a919-5495ec9bedda_11210_36_78_GM is already set to Active in the database.
2013-10-11 12:38:46.580 (3) [pool-3-thread-12]: No budget update required
2013-10-11 12:38:46.580 (3) [pool-3-thread-12]: a51bdff6-23ec-4325-a919-5495ec9bedda_11210_36_78_MO is already set to Active in the database.
2013-10-11 12:38:46.581 (3) [pool-3-thread-12]: No budget update required
2013-10-11 12:38:46.581 (3) [pool-3-thread-12]: ----------------Google Content Editor starting
2013-10-11 12:38:46.632 (3) [P774T1]: ... SEUser 31 finished
2013-10-11 12:38:46.633 (3) [pool-3-thread-12]: ------------Google Content Editor done
2013-10-11 12:38:46.634 (3) [pool-3-thread-12]: Campaign structure sync not enabled for this request.
2013-10-11 12:38:46.638 (3) [pool-3-thread-12]: Structure sync disabled, ignoring 0 structure operation errors.
2013-10-11 12:38:46.638 (3) [pool-3-thread-12]: 78_MO has no applicable GCE errors.
2013-10-11 12:38:46.641 (3) [pool-3-thread-12]: Structure sync disabled, ignoring 0 structure operation errors.
2013-10-11 12:38:46.641 (3) [pool-3-thread-12]: 78_GM has no applicable GCE errors.
2013-10-11 12:38:46.645 (3) [pool-3-thread-12]: Structure sync disabled, ignoring 0 structure operation errors.
2013-10-11 12:38:46.645 (3) [pool-3-thread-12]: 78_GT has no applicable GCE errors.
2013-10-11 12:38:46.646 (3) [pool-3-thread-12]: Finished UPDATE request for campaign a51bdff6-23ec-4325-a919-5495ec9bedda_11210_36_78_GM: SUCCEEDED
2013-10-11 12:38:46.647 (3) [pool-3-thread-12]: Finished UPDATE request for campaign a51bdff6-23ec-4325-a919-5495ec9bedda_11210_36_78_GT: SUCCEEDED
2013-10-11 12:38:46.647 (3) [pool-3-thread-12]: Finished UPDATE request for campaign a51bdff6-23ec-4325-a919-5495ec9bedda_11210_36_78_MO: SUCCEEDED
2013-10-11 12:38:46.647 (3) [pool-3-thread-12]: a51bdff6-23ec-4325-a919-5495ec9bedda has 0 campaigns for a SE Update accounts sync.
2013-10-11 12:38:46.647 (3) [pool-3-thread-12]: a51bdff6-23ec-4325-a919-5495ec9bedda has 0 campaigns for a SE Update groups-listings sync.
2013-10-11 12:38:46.647 (3) [pool-3-thread-12]: Finished sub-campaign processing for UPDATE deploymentID (8add4cbb-9058-4532-9e2f-b391727293e2). account a51bdff6-23ec-4325-a919-5495ec9bedda. 3 submitted, 3 ok.
2013-10-11 12:38:46.648 (3) [pool-3-thread-12]: Updating deployment status to 'Success' for campaignID: 78
2013-10-11 12:38:46.648 (3) [pool-3-thread-12]: Finished UPDATE request for 78: SUCCEEDED
2013-10-11 12:38:46.648 (3) [pool-3-thread-12]: Finished UPDATE request, deploymentID (8add4cbb-9058-4532-9e2f-b391727293e2), account a51bdff6-23ec-4325-a919-5495ec9bedda
2013-10-11 12:38:46.649 (3) [pool-3-thread-12]: Request removed from map for customerID a51bdff6-23ec-4325-a919-5495ec9bedda

==> /home/TSAApp/apps/jboss-5.1.0.GA/tsa_messaging_node_server.log <==
12:38:47,483 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:47,483 DEBUG [JdbcTemplate] Executing prepared SQL statement [select responseMsg from mms_common.campUpdateResp where deploymentID = ?]

==> /var/local/tsa/log/tsa-admax-jmslistener/tsa-admax-jmslistener.log <==
2013-10-11 12:38:47.596 (3) [AdMaxListener]: Sent message to response queue.

==> /home/TSAApp/apps/jboss-5.1.0.GA/tsa_messaging_node_server.log <==
12:38:47,599 INFO [AdMaxDeploymentResponseMDB] Response MDB triggered.
12:38:47,652 DEBUG [JdbcTemplate] Executing prepared SQL update
12:38:47,653 DEBUG [JdbcTemplate] Executing prepared SQL statement [insert into mms_common.campUpdateResp(deploymentID, responseMsg) values (?, ?) on duplicate key update responseMsg = ?]
12:38:47,655 DEBUG [JdbcTemplate] SQL update affected 1 rows
12:38:47,656 WARN [AdMaxDeploymentFauxSyncMessenger] Put update ok for deploy 8add4cbb-9058-4532-9e2f-b391727293e2
12:38:47,656 INFO [AdMaxDeploymentResponseMDB] Handling update campaign status.
12:38:48,485 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:48,485 DEBUG [JdbcTemplate] Executing prepared SQL statement [select responseMsg from mms_common.campUpdateResp where deploymentID = ?]
12:38:48,993 DEBUG [CallbackEventEJBTimer] CallbackEventTimer : START TIMEOUT
12:38:48,993 DEBUG [CallbackEventEJBTimer] CallbackEventTimer : ENABLED
12:38:48,994 DEBUG [JdbcTemplate] Executing SQL query [select * from callbackEvent]
12:38:49,008 DEBUG [CallbackEventEJBTimer] CallbackEventTimer : END TIMEOUT
12:38:49,493 INFO [AdMaxDeploymentFauxSyncMessenger] Exited blocking loop
12:38:49,497 DEBUG [JdbcTemplate] Executing prepared SQL update
12:38:49,497 DEBUG [JdbcTemplate] Executing prepared SQL statement [delete from mms_common.campUpdateResp where deploymentID = ?]
12:38:49,499 DEBUG [JdbcTemplate] SQL update affected 1 rows
12:38:49,502 INFO [LoggingInInterceptor] Outbound Message
---------------------------
ID: 7400
Encoding: UTF-8
Content-Type: text/xml
Headers: {}
Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><ns2:updateCampaignStatusResponse xmlns:ns2="http://thesearchagency.com/smb/core"><updateCampaignStatusResponse><header><requestID>8add4cbb-9058-4532-9e2f-b391727293e2</requestID></header><customerID>a51bdff6-23ec-4325-a919-5495ec9bedda</customerID><campaignResult><campaignID>78</campaignID><result><resultCode>success</resultCode><resultString>Information: [78_GM:SUCCEEDED] [78_GT:SUCCEEDED] [78_MO:SUCCEEDED] </resultString></result></campaignResult></updateCampaignStatusResponse></ns2:updateCampaignStatusResponse></soap:Body></soap:Envelope>
--------------------------------------
12:38:49,512 INFO [LoggingInInterceptor] Inbound Message
----------------------------
ID: 7401
Address: /SMB-ADS/AdMaxDeploymentService
Encoding: UTF-8
Content-Type: text/xml; charset=UTF-8
Headers:

{cache-control=[no-cache], content-type=[text/xml; charset=UTF-8], connection=[keep-alive], host=[aml-svc-deploy:8080], Content-Length=[675], SOAPAction=[""], user-agent=[Apache CXF 2.7.5], Content-Type=[text/xml; charset=UTF-8], Accept=[*/*], pragma=[no-cache]}

Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><core:updateCampaignBudgetAccrualStatus xmlns:core="http://thesearchagency.com/smb/core">
<updateCampaignBudgetAccrualStatusRequest>
<header>
<requestID>8add4cbb-9058-4532-9e2f-b391727293e2</requestID>
</header>
<customerID>a51bdff6-23ec-4325-a919-5495ec9bedda</customerID>
<campaignBudgetAccrualStatusList>
<campaignID>78</campaignID>
<campaignBudgetAccrualStatus>active</campaignBudgetAccrualStatus>
</campaignBudgetAccrualStatusList>
</updateCampaignBudgetAccrualStatusRequest>
</core:updateCampaignBudgetAccrualStatus></soap:Body></soap:Envelope>
--------------------------------------
12:38:49,519 INFO [AdMaxAccountDeploymentBD] validated: []
12:38:49,519 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:49,519 DEBUG [JdbcTemplate] Executing prepared SQL statement [select * from accounts where description = ? ]
12:38:49,521 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:49,521 DEBUG [JdbcTemplate] Executing prepared SQL statement [select * from sites where accountID = ? ]
12:38:49,524 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:49,524 DEBUG [JdbcTemplate] Executing prepared SQL statement [select * from waypoints where siteID = ? ]
12:38:49,534 INFO [AdMaxAccountDeploymentBD] Account: Account [theAccountID=32, theDescription=a51bdff6-23ec-4325-a919-5495ec9bedda, theTier=1, thePriority=50, theReportClickOuts=0, theReportConversions=0, theConversionTypes=[], isBidManaged=1, isActive=true, thePerformanceMetric=cpa, theProvidesConversionData=true, theAddConversionDate=false, theFractionalConversionCounts=false, theHideNullSources=0, theNowTime=Fri Oct 11 12:38:49 UTC 2013, theWarehouseDB=warehouse_1, theDatabaseInstance=1, theWarehouseInstance=1, isOnline=true, currencyCode=, theSites=[Site [theSiteId=31, theAccountId=32, isDefault=true, theDescription=a51bdff6-23ec-4325-a919-5495ec9bedda_Main, theInternalURLPattern=, hasIgnorePixels=false, theWaypoints=[Waypoint [theWaypointId=61, theSiteId=31, theGroupId=0, theType=2, theConverstionType=null, theDefaultCost=0.0, theDefaultValue=0.0, theTestingURL=, theDestinationURL=, theDescription=Page View, thePassParams=, theDebounceWindow=30, theLimitPerWindow=1, theLastTestedDate=null, theTestStatus=null], Waypoint [theWaypointId=62, theSiteId=31, theGroupId=0, theType=4, theConverstionType=null, theDefaultCost=0.0, theDefaultValue=0.0, theTestingURL=, theDestinationURL=, theDescription=Conversion, thePassParams=, theDebounceWindow=0, theLimitPerWindow=0, theLastTestedDate=null, theTestStatus=null]]]]]
12:38:49,534 INFO [AdMaxAccountDeploymentBD] Updating CampaignID [78] budget accrual status to [active]
12:38:49,535 INFO [CampaignBudgetAccrualStatusServiceBD] Entering CampaignBudgetAccrualStatusServiceImpl.updateCampaignBudgetAccrualStatus method.
12:38:49,537 INFO [CampaignBudgetAccrualStatusServiceBD] Searching for last CampaignBudgetAccrualStatus record for CampiagnId [33]
12:38:49,537 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:49,537 DEBUG [JdbcTemplate] Executing prepared SQL statement [select * from admaxCampaignBudgetAccrualStatus where admaxCampaignID = ? and endDate is NULL]
12:38:49,547 INFO [CampaignBudgetAccrualStatusServiceBD] CampaignId [33] last CampaignBudgetAccrualStatus current status
CampaignBugetAccrualStatus [theId=67, theCampaignId=33, theStartDate=2013-10-10, theEndDate=null, theStatus=active]
12:38:49,547 DEBUG [JdbcTemplate] Executing prepared SQL query
12:38:49,547 DEBUG [JdbcTemplate] Executing prepared SQL statement [select accountID, currencyCode, timeZoneId from gce_googleAccount where accountID = ? ]
12:38:49,549 INFO [CampaignBudgetAccrualStatusServiceBD] CampaignId [33] last CampaignBudgetAccrualStatus not found
CampaignBugetAccrualStatus [theId=67, theCampaignId=33, theStartDate=2013-10-10, theEndDate=null, theStatus=active]
12:38:49,549 INFO [CampaignBudgetAccrualStatusServiceBD] Exiting CampaignBudgetAccrualStatusServiceImpl.updateCampaignBudgetAccrualStatus method.
12:38:49,554 INFO [LoggingInInterceptor] Outbound Message
---------------------------
ID: 7401
Encoding: UTF-8
Content-Type: text/xml
Headers: {}
Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><ns2:updateCampaignBudgetAccrualStatusResponse xmlns:ns2="http://thesearchagency.com/smb/core"><updateCampaignBudgetAccrualStatusResponse><header><requestID>8add4cbb-9058-4532-9e2f-b391727293e2</requestID></header><customerID>a51bdff6-23ec-4325-a919-5495ec9bedda</customerID><campaignResult><campaignID>78</campaignID><result><resultCode>success</resultCode></result></campaignResult></updateCampaignBudgetAccrualStatusResponse></ns2:updateCampaignBudgetAccrualStatusResponse></soap:Body></soap:Envelope>
--------------------------------------

Attachments

Options
- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

Attachments

original-order-post-to-sapi-log.txt
11/Oct/13 2:40 PM
26 kB
Patrick Wynne

Activity

People

Assignee:

Unassigned

Reporter:

Jeff Brown (Inactive)

Votes:

0 Vote for this issue

Watchers:

0 Start watching this issue

Dates

Created:

11/Oct/13 9:18 AM

Updated:

14/Oct/13 3:57 PM

Resolved:

14/Oct/13 3:57 PM