Bidmgr logs are missing soap requests

Bidmgr scripts like admax.sh, sebidupdater.sh are missing soap requests in their logs.

Eg.,

[TSAApp@aml-qa5-core1 bidmgr]$ ./admax.sh -d3 -a 988 -z America/New_York -T 2016-05-13
------- Loaded DatabaseAccounts properties from file:/usr/local/tsa/bidmgr-distribution-2.9.1-dev-t20160510-0933/libs/deployment-bidmgr-shaded-jar-2.9.1.jar!/core-jdb-datasource.properties -------

{datasource-user=spike, datasource-password=tar63t}

2016-05-13 14:14:12.672 (3) [main]: Debug Level set to 3
2016-05-13 14:14:12.674 (3) [main]: Licensing environment detected, loading configuration.
2016-05-13 14:14:12.675 (3) [main]: Loaded property: distribution-service-url=http://aml-qa5-front1:8080/distribution
2016-05-13 14:14:12.675 (3) [main]: Loaded property: distribution-service-username=readwrite
2016-05-13 14:14:12.675 (3) [main]: Loaded property: distribution-service-password=readwrite
2016-05-13 14:14:12.675 (3) [main]: Loaded property: sapi-auth-url=http://aml-qa5-front1:8080/sapi/rest/security/tokens
2016-05-13 14:14:12.675 (3) [main]: Loaded property: sapi-merchant-service-url=http://aml-qa5-front1:8080/sapi/rest/merchants
2016-05-13 14:14:12.675 (3) [main]: Loaded property: sapi-reseller-service-url=http://aml-qa5-front1:8080/sapi/rest/resellers
2016-05-13 14:14:12.675 (3) [main]: Loaded property: sapi-username=admin+tsa@thesearchagency.com
2016-05-13 14:14:12.675 (3) [main]: Loaded property: sapi-password=admin
2016-05-13 14:14:12.675 (3) [main]: Loaded property: sapi-realm=thesearchagency
2016-05-13 14:14:12.676 (3) [main]: Loaded property: tsa.google.mcc.developerToken=ojCnjZaM6RD1h0yt_DOJZg
2016-05-13 14:14:12.676 (3) [main]: Loaded property: tsa.google.mcc.isReseller=true
2016-05-13 14:14:12.676 (3) [main]: Loaded property: tsa.google.mcc.userAgent=AdMaxLocal AdWords Software TSA QA
2016-05-13 14:14:12.676 (3) [main]: Loaded property: tsa.timezone=UTC
2016-05-13 14:14:12.680 (3) [main]: Debug Level set to 3
2016-05-13 14:14:12.680 (3) [main]: AdMax Summarizer parameters: -d3 -a 988 -z America/New_York -T 2016-05-13
2016-05-13 14:14:13.013 (3) [main]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:13.025 (3) [main]: DatabasePool with a limit of 18 created
2016-05-13 14:14:13.048 (3) [main]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:13.070 (3) [main]: Could not save process history start
2016-05-13 14:14:13.071 (3) [main]: =============== Starting AdMax Summarizer ================
2016-05-13 14:14:13.071 (3) [main]: ----------------AdMax Summarizer starting
2016-05-13 14:14:13.094 (3) [main]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:13.126 (3) [P1T1]: Starting Account ID #988: f06251cf-a9a8-46b5-95b2-b2c7e649658d
2016-05-13 14:14:13.151 (3) [P1T1]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:13.158 (3) [P1T1]: DatabasePool with a limit of 18 created
2016-05-13 14:14:13.176 (3) [P1T1]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:13.177 (3) [P1T1]: DatabasePool with a limit of 18 created
2016-05-13 14:14:13.194 (3) [P1T1]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:13.217 (3) [P1T1]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:13.220 (3) [P1T1]: DatabasePool with a limit of 18 created
2016-05-13 14:14:13.244 (3) [P1T1]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:13.263 (3) [P1T1]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:13.265 (3) [P1T1]: DatabasePool with a limit of 18 created
2016-05-13 14:14:13.288 (3) [P1T1]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:13.290 (3) [P1T1]: Got migrator lock for Account ID #988
2016-05-13 14:14:13.838 (3) [P1T1]: Applying algorithm [SABB] for Account ID #988 in distributions [3, 178, 147]
2016-05-13 14:14:13.843 (3) [P1T1]: Processing data for 2016-05-13 00:00:00 EDT
2016-05-13 14:14:13.945 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1406
2016-05-13 14:14:13.947 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1407
2016-05-13 14:14:13.949 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1408
2016-05-13 14:14:13.951 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1409
2016-05-13 14:14:13.954 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1410
2016-05-13 14:14:13.956 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1411
2016-05-13 14:14:13.958 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1406
2016-05-13 14:14:13.960 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1407
2016-05-13 14:14:13.962 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1408
2016-05-13 14:14:13.964 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1409
2016-05-13 14:14:13.966 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1410
2016-05-13 14:14:13.968 (3) [P1T1]: Retrieved campaign status Active for AdMax campaign 1411
2016-05-13 14:14:13.990 (2) [P1T1]: AdMax campaign ID: 1411 spent 0.2
2016-05-13 14:14:13.991 (2) [P1T1]: AdMax campaign ID: 1409 spent 0.3
2016-05-13 14:14:13.991 (2) [P1T1]: AdMax campaign ID: 1407 spent 0.3
2016-05-13 14:14:13.991 (2) [P1T1]: AdMax campaign ID: 1406 spent 0.2
2016-05-13 14:14:13.991 (2) [P1T1]: AdMax campaign ID: 1408 spent 0.3
2016-05-13 14:14:13.992 (2) [P1T1]: AdMax campaign ID: 1410 spent 0.3
2016-05-13 14:14:13.998 (2) [P1T1]: AdMax campaign ID: 1411 spent 200000.2
2016-05-13 14:14:14.002 (2) [P1T1]: AdMax campaign ID: 1409 spent 300000.3
2016-05-13 14:14:14.002 (2) [P1T1]: AdMax campaign ID: 1407 spent 300000.3
2016-05-13 14:14:14.005 (3) [P1T1]: Could not find boosted carryover for AdMaxCampaignID: 1406
2016-05-13 14:14:14.006 (3) [P1T1]: Could not find boosted carryover for AdMaxCampaignID: 1407
2016-05-13 14:14:14.007 (3) [P1T1]: Could not find boosted carryover for AdMaxCampaignID: 1408
2016-05-13 14:14:14.008 (3) [P1T1]: Could not find boosted carryover for AdMaxCampaignID: 1409
2016-05-13 14:14:14.009 (3) [P1T1]: Could not find boosted carryover for AdMaxCampaignID: 1410
2016-05-13 14:14:14.010 (3) [P1T1]: Could not find boosted carryover for AdMaxCampaignID: 1411
2016-05-13 14:14:14.018 (3) [P1T1]: Could not find boosted actual daily budget for AdMaxCampaignID: 1406
2016-05-13 14:14:14.019 (3) [P1T1]: Could not find boosted actual daily budget for AdMaxCampaignID: 1407
2016-05-13 14:14:14.020 (3) [P1T1]: Could not find boosted actual daily budget for AdMaxCampaignID: 1408
2016-05-13 14:14:14.021 (3) [P1T1]: Could not find boosted actual daily budget for AdMaxCampaignID: 1409
2016-05-13 14:14:14.021 (3) [P1T1]: Could not find boosted actual daily budget for AdMaxCampaignID: 1410
2016-05-13 14:14:14.027 (3) [P1T1]: Could not find boosted actual daily budget for AdMaxCampaignID: 1411
2016-05-13 14:14:14.104 (3) [P1T1]: Could not find nominal daily budget for AdMaxCampaignID: 1406 and date Fri May 13 00:00:00 UTC 2016
2016-05-13 14:14:14.104 (3) [P1T1]: Could not find nominal daily budget for AdMaxCampaignID: 1407 and date Fri May 13 00:00:00 UTC 2016
2016-05-13 14:14:14.105 (3) [P1T1]: Could not find nominal daily budget for AdMaxCampaignID: 1408 and date Fri May 13 00:00:00 UTC 2016
2016-05-13 14:14:14.106 (3) [P1T1]: Could not find nominal daily budget for AdMaxCampaignID: 1409 and date Fri May 13 00:00:00 UTC 2016
2016-05-13 14:14:14.107 (3) [P1T1]: Could not find nominal daily budget for AdMaxCampaignID: 1410 and date Fri May 13 00:00:00 UTC 2016
2016-05-13 14:14:14.108 (3) [P1T1]: Could not find nominal daily budget for AdMaxCampaignID: 1411 and date Fri May 13 00:00:00 UTC 2016
2016-05-13 14:14:14.116 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2648
2016-05-13 14:14:14.116 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2649
2016-05-13 14:14:14.117 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2646
2016-05-13 14:14:14.118 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2647
2016-05-13 14:14:14.119 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2650
2016-05-13 14:14:14.119 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2651
2016-05-13 14:14:14.120 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2643
2016-05-13 14:14:14.121 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2645
2016-05-13 14:14:14.122 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2652
2016-05-13 14:14:14.123 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2653
2016-05-13 14:14:14.123 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2642
2016-05-13 14:14:14.124 (3) [P1T1]: Could not find balance factor for searchEngineAccountID: 2644
2016-05-13 14:14:14.138 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2648
2016-05-13 14:14:14.139 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2649
2016-05-13 14:14:14.140 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2646
2016-05-13 14:14:14.141 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2647
2016-05-13 14:14:14.141 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2650
2016-05-13 14:14:14.142 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2651
2016-05-13 14:14:14.143 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2643
2016-05-13 14:14:14.144 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2645
2016-05-13 14:14:14.145 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2652
2016-05-13 14:14:14.145 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2653
2016-05-13 14:14:14.146 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2642
2016-05-13 14:14:14.147 (3) [P1T1]: Could not find actual daily budget for searchEngineAccountID: 2644
2016-05-13 14:14:14.224 (3) [P1T1]: Distribution Properties Cache: Loading new properties for f06251cf-a9a8-46b5-95b2-b2c7e649658d_ALGORITHM
2016-05-13 14:14:14 INFO [P1T1] org.apache.commons.httpclient.auth.AuthChallengeProcessor:101 - digest authentication scheme selected
2016-05-13 14:14:14.762 (3) [P1T1]: Pausing campaign 2646 because budget (-152264.53 ==> -152264.5) is less than the minimum allowed budget (0.05)
2016-05-13 14:14:14.762 (3) [P1T1]: Pausing campaign 2647 because budget (-114398.4 ==> -114398.4) is less than the minimum allowed budget (0.05)
2016-05-13 14:14:14.762 (3) [P1T1]: Pausing campaign 2643 because budget (-228397.38 ==> -228397.36) is less than the minimum allowed budget (0.05)
2016-05-13 14:14:14.762 (3) [P1T1]: Pausing campaign 2645 because budget (-171598.03 ==> -171598.0) is less than the minimum allowed budget (0.05)
2016-05-13 14:14:14.763 (3) [P1T1]: Pausing campaign 2642 because budget (-76131.695 ==> -76131.7) is less than the minimum allowed budget (0.05)
2016-05-13 14:14:14.763 (3) [P1T1]: Pausing campaign 2644 because budget (-57198.77 ==> -57198.75) is less than the minimum allowed budget (0.05)
2016-05-13 14:14:14.847 (3) [P1T1]: DistributionServiceRemoteClient created for f06251cf-a9a8-46b5-95b2-b2c7e649658d_2_qa5amltest_Randomize1
2016-05-13 14:14:15.665 (3) [P1T1]: [oauth] Creating new OAuthService component
2016-05-13 14:14:15 INFO [P1T1] com.thesearchagency.services.oauth.core.OAuthServiceComponent:75 - [oauth] Creating new OAuthServiceComponent
2016-05-13 14:14:15.804 (3) [P1T1]: Creating API for reseller DistributionSettings 33146f19-22f8-4b98-96f7-6cb4f0da283b
2016-05-13 14:14:15.828 (3) [P1T1]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:15.851 (3) [P1T1]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:15.870 (3) [P1T1]: JDBC Driver Version: 5.1 (com.mysql.jdbc.Driver)
2016-05-13 14:14:15.870 (3) [P1T1]: Created shared sesystem connection rw
2016-05-13 14:14:15.888 (3) [P1T1]: Retrieving credentials for search engine user id : 1052 || client id : 708478822263-srenocq0gcguusttt4aunqjdi2jnllcg.apps.googleusercontent.com , client secret :eGE8JpEDaEgVb26gQg_ePnaG , refresh token : 1/PPPmQLADSV-h2NEsY4vmLgBmiDtScaB01K55xhGOaHE
2016-05-13 14:14:16.881 (3) [P1T1]: [oauth] Returning access token from OAuth service: ya29.CirhAuLntNkHwS421J9_cMsjzGYIx1Dr-gt2T-bN05Kmt204K7vVSiFalgo
2016-05-13 14:14:16.882 (3) [P1T1]: Retrieving credentials for search engine user id : 1052 || client id : 708478822263-srenocq0gcguusttt4aunqjdi2jnllcg.apps.googleusercontent.com , client secret :eGE8JpEDaEgVb26gQg_ePnaG , refresh token : 1/PPPmQLADSV-h2NEsY4vmLgBmiDtScaB01K55xhGOaHE
2016-05-13 14:14:16.883 (3) [P1T1]: [oauth] Returning access token from OAuth service: ya29.CirhAuLntNkHwS421J9_cMsjzGYIx1Dr-gt2T-bN05Kmt204K7vVSiFalgo
2016-05-13 14:14:24.413 (3) [P1T1]: New bid for SE campaign 2649: 0.6 ==> 1.1
2016-05-13 14:14:24.415 (3) [P1T1]: New bid for SE campaign 2646: 0.6 ==> 0.55
2016-05-13 14:14:24.418 (3) [P1T1]: New bid for SE campaign 2651: 0.6 ==> 1.1
2016-05-13 14:14:24.420 (3) [P1T1]: New bid for SE campaign 2643: 0.6 ==> 0.55
2016-05-13 14:14:24.422 (3) [P1T1]: New bid for SE campaign 2653: 0.6 ==> 1.1
2016-05-13 14:14:24.423 (3) [P1T1]: New bid for SE campaign 2642: 0.6 ==> 0.55
2016-05-13 14:14:24.455 (3) [P1T1]: Finished applying algorithm [SABB] for account [988] in distributions [3, 178, 147]
2016-05-13 14:14:24.456 (3) [P1T1]: Released migrator lock for Account ID #988
2016-05-13 14:14:24.456 (3) [P1T1]: Completed Account ID #988: f06251cf-a9a8-46b5-95b2-b2c7e649658d
2016-05-13 14:14:24.457 (3) [main]: ------------AdMax Summarizer done
2016-05-13 14:14:24.457 (3) [main]: =============== Completed AdMax Summarizer ================
2016-05-13 14:14:24.458 (3) [main]: Could not save process history stop
2016-05-13 14:14:24.458 (3) [main]: =============== Stats ================
2016-05-13 14:14:24.458 (3) [main]: — Process —
2016-05-13 14:14:24.458 (3) [main]:
2016-05-13 14:14:24.459 (3) [main]: ABU Process(start): Fri May 13 14:14:12 UTC 2016
2016-05-13 14:14:24.459 (3) [main]: ABU Process(stop): Fri May 13 14:14:24 UTC 2016
2016-05-13 14:14:24.459 (3) [main]:
2016-05-13 14:14:24.459 (3) [main]: — Accounts —
2016-05-13 14:14:24.459 (3) [main]:
2016-05-13 14:14:24.459 (3) [main]: Accounts Processed: 1
2016-05-13 14:14:24.459 (3) [main]: Accounts Skipped: 0
2016-05-13 14:14:24.459 (3) [main]: Accounts Processed Successfully: 1
2016-05-13 14:14:24.459 (3) [main]:
2016-05-13 14:14:24.459 (3) [main]: — Campaigns —
2016-05-13 14:14:24.459 (3) [main]:
2016-05-13 14:14:24.459 (3) [main]: Campaigns Processed: 6
2016-05-13 14:14:24.459 (3) [main]: Campaigns Processed Successfully: 6
2016-05-13 14:14:24.459 (3) [main]: Campaign Budgets Capped: 0
2016-05-13 14:14:24.459 (3) [main]:
2016-05-13 14:14:24.459 (3) [main]: — SE Campaigns —
2016-05-13 14:14:24.459 (3) [main]:
2016-05-13 14:14:24.459 (3) [main]: SE Campaigns Processed: 12
2016-05-13 14:14:24.460 (3) [main]: SE Campaigns Processed Successfully: 12
2016-05-13 14:14:24.460 (3) [main]:
2016-05-13 14:14:24.460 (3) [main]: — Budget/Spend —
2016-05-13 14:14:24.460 (3) [main]:
2016-05-13 14:14:24.460 (3) [main]: SE Campaign Budgets Updated: 12
2016-05-13 14:14:24.460 (3) [main]: SE Campaign Budgets Sent To Google: 6
2016-05-13 14:14:24.460 (3) [main]: SE Campaign Budgets Sent To Yahoo Japan:0
2016-05-13 14:14:24.460 (3) [main]: SE Campaign Budgets Sent To Bing: 6
2016-05-13 14:14:24.460 (3) [main]:
2016-05-13 14:14:24.460 (3) [main]: Spend Total: 800001.6
2016-05-13 14:14:24.460 (3) [main]: Common Carryover Total: -799989.6
2016-05-13 14:14:24.460 (3) [main]:
2016-05-13 14:14:24.460 (3) [main]: — Bids —
2016-05-13 14:14:24.461 (3) [main]:
2016-05-13 14:14:24.461 (3) [main]: New Campaign Bids: 6
2016-05-13 14:14:24.461 (3) [main]:
2016-05-13 14:14:24.462 (3) [main]: AdMaxSummarizer: 11.692s
2016-05-13 14:14:24.462 (3) [main]: by key:
2016-05-13 14:14:24.462 (3) [main]: db: 0.103s
2016-05-13 14:14:24.462 (3) [main]: by thread:
2016-05-13 14:14:24.462 (3) [main]: P1T1: 0.100s
2016-05-13 14:14:24.462 (3) [main]: main: 0.003s
2016-05-13 14:14:24.463 (3) [main]: google: 1.893s
2016-05-13 14:14:24.463 (3) [main]: other: 9.696s
[TSAApp@aml-qa5-core1 bidmgr]$