Discussion:
AddSelectedToCart web page times out
(too old to reply)
VijayaR
2006-11-03 00:31:21 UTC
Permalink
We have done some customization for OrderItemAdd command to calculate discount prices etc. Our custom logic invokes "orderPrepareCommand" with the URL set to OrderItemDisplay.

Everything works fine when the cart has less number of items.

When the customer adds 30 items or so to an existing cart with a significantly high number of items(say above 60), our command finishes successfully and takes about 18.5 seconds. What we observed is, when our command takes more than 10 seconds to finish, the store web page times out.

What would be the best way to deal with this type of situation? I am investigating whether this time out can be something configurable? But I definitely appreciate any suggestions folks might have.

-thanks
Robert Brown
2006-11-03 03:10:33 UTC
Permalink
Your command should not take 18 seconds to complete. Either your
command logic or any SQL queries it invokes should be corrected. What
is the size of the CATENTRY table? Is the poor performance for this
command due to an extremely catalog?

There are configurable timeouts at the database level, the WebSphere
Application server level, and at the webserver level. Which level have
you concluded is timing out?

R
Post by VijayaR
We have done some customization for OrderItemAdd command to calculate discount prices etc. Our custom logic invokes "orderPrepareCommand" with the URL set to OrderItemDisplay.
Everything works fine when the cart has less number of items.
When the customer adds 30 items or so to an existing cart with a significantly high number of items(say above 60), our command finishes successfully and takes about 18.5 seconds. What we observed is, when our command takes more than 10 seconds to finish, the store web page times out.
What would be the best way to deal with this type of situation? I am investigating whether this time out can be something configurable? But I definitely appreciate any suggestions folks might have.
-thanks
Robert Brown
2006-11-03 03:11:41 UTC
Permalink
extremely large catalog ... geez, need a grammatical checker

R
Post by Robert Brown
Your command should not take 18 seconds to complete. Either your
command logic or any SQL queries it invokes should be corrected. What
is the size of the CATENTRY table? Is the poor performance for this
command due to an extremely catalog?
There are configurable timeouts at the database level, the WebSphere
Application server level, and at the webserver level. Which level have
you concluded is timing out?
R
Post by VijayaR
We have done some customization for OrderItemAdd command to calculate
discount prices etc. Our custom logic invokes "orderPrepareCommand"
with the URL set to OrderItemDisplay.
Everything works fine when the cart has less number of items.
When the customer adds 30 items or so to an existing cart with a
significantly high number of items(say above 60), our command finishes
successfully and takes about 18.5 seconds. What we observed is, when
our command takes more than 10 seconds to finish, the store web page
times out.
What would be the best way to deal with this type of situation? I am
investigating whether this time out can be something configurable?
But I definitely appreciate any suggestions folks might have.
-thanks
VijayaR
2006-11-03 23:47:51 UTC
Permalink
Well, we do not have any custom SQL queries to impact this issue.

"OrderPrepare" command is taking nearly 6 seconds for processing a cart with one order item. So as the cart size goes higher, as expected the command is taking longer time to finish. Here is the trace for a single execution of "OrderPrepare" for one order item.

---------------------------------------------------------------------
[11/3/06 15:11:00:336 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl setRequestProperties Entry
[11/3/06 15:11:00:336 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl setRequestProperties Entry
[11/3/06 15:11:00:336 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.commands.OrderPrepareCmdImpl setRequestProperties status is P
[11/3/06 15:11:00:336 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl setRequestProperties Exit
[11/3/06 15:11:00:336 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl setRequestProperties Exit
[11/3/06 15:11:00:336 PST] 478ce0f0 SystemOut O Invoke OrderPrepare Command
[11/3/06 15:11:00:352 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl isReadyToCallExecute Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl checkPendingOrderParameters Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.utils.MiscCmd verifyParamValSyntax Order ref num : '36051'
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl checkPendingOrderParameters Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl findOrders Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.utils.ResolveOrdersCmdImpl validateParameters Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.utils.ResolveOrdersCmdImpl validateParameters Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.utils.ResolveOrdersCmdImpl performExecute Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.utils.ResolveOrdersCmdImpl getFromCache(Long) Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.utils.ResolveOrdersCmdImpl getFromCache(Long) Long cache hit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.utils.ResolveOrdersCmdImpl getFromCache(Long) Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.utils.ResolveOrdersCmdImpl performExecute Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER d MiscCmd getPendingOrders Pending orders to be processed:
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER d MiscCmd printOrderList 36051
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl findOrders Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl isReadyToCallExecute Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl performExecute Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.PrepareOrderCmdImpl performExecute Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.commands.OrderProcessingHelper initialize Order Item : 520001
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.PrepareOrderCmdImpl doProcess Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper removeGeneratedOrderItems Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper removeGeneratedOrderItems Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper ensureAllOrderItemsAreBuyable Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper ensureAllOrderItemsAreBuyable Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemAddresses Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.updateShippingAddressCmdImpl validateParameters Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.updateShippingAddressCmdImpl validateParameters Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.updateShippingAddressCmdImpl performExecute() Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.updateShippingAddressCmdImpl findAddressIdForOrderItem Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.updateShippingAddressCmdImpl findAddressIdForOrderItem Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.updateShippingAddressCmdImpl updateAddress Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.commands.updateShippingAddressCmdImpl updateAddress Setting shipping address of order item 520001 to address id 67552
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.updateShippingAddressCmdImpl updateAddress Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.updateShippingAddressCmdImpl performExecute() Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemAddresses Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemConfigurations Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemConfigurations Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper checkOrderInventory Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl isReadyToCallExecute Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl isReadyToCallExecute Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl checkParameters Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl checkParameters Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl performExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.FulfillmentRegistry isShippingArrangementRestricted Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.FulfillmentRegistry isShippingArrangementRestricted Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.FulfillmentRegistry getEffectiveFulfillmentCenterIds Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.FulfillmentRegistry getMatchingEffectiveFulfillmentCenterIds Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.ShippingArrangementWrapper isValid Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.fulfillment.commands.ShippingArrangementWrapper isValid Shipping arrangement 10001 is assumed valid since the shipping address is not known.
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.ShippingArrangementWrapper isValid Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.FulfillmentRegistry getMatchingEffectiveFulfillmentCenterIds Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.FulfillmentRegistry getEffectiveFulfillmentCenterIds Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl performExecute Try to use the fulfillmentCenterId: 10051 to check inventory.
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl isReadyToCallExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl isReadyToCallExecute Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl checkParameters Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl checkParameters Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl performExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl performExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl findByCatalogEntryAndFulfillmentCenterAndStore Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl findByCatalogEntryAndFulfillmentCenterAndStore Try to check inventory for catalogEntryId=10142, fulfillmentCenterId=10051, storeId=10051
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl findByCatalogEntryAndFulfillmentCenterAndStore Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl performExecute Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl performExecute Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl getOutOfInventoryOrderItems Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl getOutOfInventoryOrderItems Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl performExecute Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper checkOrderInventory Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemPrices Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper getCurrencyForOveriddenOrderItems Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper getCurrencyForOveriddenOrderItems Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveOffers Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveOffers Retrieved offers : |10071|
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveOffers Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveTradings Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper getEligibleTradingAgreements Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper getEligibleTradingAgreements eligible trading agreement from Command Context: 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper getEligibleTradingAgreements Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper isTradingAgreementValid -- input trading agreement is valid = 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveTradings Retrieved tradings |10504|
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveTradings Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemPrices trading agreement from orderitem to be used: 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl validateParameters Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl validateParameters Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl performExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputParameters Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputParameters currency used for prices: USD
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputParameters input error mode: true
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputParameters resolve input for catentryprices.
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveTradingAgreements Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveTradingAgreements trading agreement from input to be used: 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveTradingAgreements Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputFromCatEntryPrices Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputFromCatEntryPrices Use same trading agreements for all catentries
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputFromCatEntryPrices Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputParameters Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePriceListInfo Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePriceListInfo retrieving price list for trading agreement: 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePriceListInfo retrieving price list for T&C: 10001(PriceTCMasterCatalogWithFiltering)
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl createCmdMasterCatalogPriceList Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl createCmdMasterCatalogPriceList policy id and pricelist id: 10051,10051
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl createCmdMasterCatalogPriceList pricelist id
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl createCmdMasterCatalogPriceList Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePriceListInfo Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePrices Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrieveOffersForPriceList Resetting retrievePriceCmd
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl reset Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl reset Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrieveOffersForPriceList price list input to retrieve offers: 10051
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl validateParameters Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl validateParameters Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl performExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffersForCatentries Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers retrieving offers for catentries: (10142) in store: 10051
retrieving offers from price list: (10051)
retrieving offers from offers: Empty array
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers storeId=10051, productItemIds=(10142), iOfferIds=Empty array, iPriceListIds=(10051), iPSExclusionList=null, iPSInclusionList=null
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Retrieved offers: offer ID=10071, CatalogEntryReferenceNumber=10142offer ID=42176, CatalogEntryReferenceNumber=10142
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl getValidOffers Entry

[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl getValidOffers Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffersForCatentries Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl performExecute Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePrices Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl calculatePrices Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl calculatePrices trading agreement input to retrieve offers: 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl calculatePrices master catalog price list input to retrieve offers: 10051
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl validateParameters Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl validateParameters Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl performExecute Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl retrievePriceListInfo Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl retrievePriceListInfo store PriceTCMasterCatalog info that refers to T&C: 10001 and priceList: 10051
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl retrievePriceListInfo Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl retrieveProductSetAdjustments productSetAdjustments={10001=null}
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getTradingOffers Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getTradingOffers Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyPriceAdjustmentForAll Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyPriceAdjustmentForAll applying price adjustments for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment selecting Price Adjustment for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment processing Price T&C = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment catalogEntryId=10142,tcId=10001,productSetAdjustments=null,entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment productSetAdjustments=null,adjustment=entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment best PriceTC is null w/ FoundInProductSet
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment price T&C with best adjustment = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment -- number of prices per offer = 1
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price before adjustment: 19.98000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price termcond id: 10001
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price trading id: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment applying price adjustment: 0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price after adjustment: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment selecting Price Adjustment for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment processing Price T&C = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment catalogEntryId=10142,tcId=10001,productSetAdjustments=null,entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment productSetAdjustments=null,adjustment=entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment best PriceTC is null w/ FoundInProductSet
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment price T&C with best adjustment = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment -- number of prices per offer = 1
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price before adjustment: 19.98000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price termcond id: 10001
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price trading id: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment applying price adjustment: 0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price after adjustment: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyPriceAdjustmentForAll Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyTradingPriceAdjustments Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyTradingPriceAdjustments applying price adjustments for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyTradingPriceAdjustments applying price adjustments for trading agreement: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment selecting Price Adjustment for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment processing Price T&C = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment catalogEntryId=10142,tcId=10001,productSetAdjustments=null,entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment productSetAdjustments=null,adjustment=entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment best PriceTC is null w/ FoundInProductSet
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment price T&C with best adjustment = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment -- number of prices per offer = 1
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price before adjustment: 19.98000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price termcond id: 10001
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price trading id: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment applying price adjustment: 0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price after adjustment: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment selecting Price Adjustment for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment processing Price T&C = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment catalogEntryId=10142,tcId=10001,productSetAdjustments=null,entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment productSetAdjustments=null,adjustment=entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment best PriceTC is null w/ FoundInProductSet
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment price T&C with best adjustment = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment -- number of prices per offer = 1
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price before adjustment: 19.98000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price termcond id: 10001
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price trading id: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment applying price adjustment: 0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price after adjustment: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyTradingPriceAdjustments Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl performExecute Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl calculatePrices Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl selectPrices Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.SelectContractPricesCmdImpl validateParameters Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.SelectContractPricesCmdImpl validateParameters Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.SelectContractPricesCmdImpl performExecute Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers selecting offer for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers selecting offer for trading agreement: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.SelectContractPricesCmdImpl findBestOffer Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl findBestOffer processing offer id: 10071 with pricelist id: 10051 and offer precedence: 1.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl findBestOffer processing offer id: 42176 with pricelist id: 10051 and offer precedence: 1.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.PriceCalculationHelper isBestPrice current new price value: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.PriceCalculationHelper isBestPrice current lowest price value: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.SelectContractPricesCmdImpl findBestOffer Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers best unit price: 19.98000000000000000000
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers best T&C id: 10001
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers best offer id: 10071
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer Entry
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer selecting offer for item: 10142
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer best unit price: USD 19.98000000000000000000
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer best unit monetary amount: USD 19.98000000000000000000
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer best trading id: 10504
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer best T&C id: 10001
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer best offer id: 10071
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.SelectContractPricesCmdImpl performExecute Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl selectPrices selected trading id: 10504 tc id: 10001 offer id: 10071 unit price: USD 19.98
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl selectPrices Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl performExecute Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper updateTradingId Entry
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper updateTradingId Use trading id returned from pricing: 10504
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper updateTradingId Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper verifyTradingPaymentMethods Entry
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper verifyTradingPaymentMethods Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemPrices Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemTotals Entry
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemTotals Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper calculateShippingAndTaxCharges Entry
[11/3/06 15:11:00:602 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages Entry
[11/3/06 15:11:00:867 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages initializeCalculationUsageMethodId(storeId=10051,usageId=-5)=-5231
[11/3/06 15:11:00:899 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages initializeCalculationUsageMethodId(storeId=10051,usageId=-1)=-201
[11/3/06 15:11:00:899 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.InitializeAdjustmentCmdImpl performExecute Entry
[11/3/06 15:11:00:914 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.InitializeAdjustmentCmdImpl performExecute Exit
[11/3/06 15:11:00:914 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages initializeCalculationUsageMethodId(storeId=10051,usageId=-2)=-211
[11/3/06 15:11:00:930 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.InitializeShippingCmdImpl performExecute Entry
[11/3/06 15:11:00:930 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.InitializeShippingCmdImpl performExecute Exit
[11/3/06 15:11:00:930 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages initializeCalculationUsageMethodId(storeId=10051,usageId=-3)=-221
[11/3/06 15:11:00:946 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.InitializeSalesTaxCmdImpl performExecute Entry
[11/3/06 15:11:00:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.InitializeSalesTaxCmdImpl performExecute Exit
[11/3/06 15:11:00:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages initializeCalculationUsageMethodId(storeId=10051,usageId=-4)=-231
[11/3/06 15:11:00:961 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.InitializeShippingTaxCmdImpl performExecute Entry
[11/3/06 15:11:00:961 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.InitializeShippingTaxCmdImpl performExecute Exit
[11/3/06 15:11:00:961 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages Exit
[11/3/06 15:11:00:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-5)=-5232
[11/3/06 15:11:01:024 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-5)=null
[11/3/06 15:11:01:024 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages checkAppliedItems(storeId=10051,usageId=-5)=false
[11/3/06 15:11:01:024 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-1)=-202
[11/3/06 15:11:05:055 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-1)=null
[11/3/06 15:11:05:055 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages checkAppliedItems(storeId=10051,usageId=-1)=false
[11/3/06 15:11:05:055 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Entry
[11/3/06 15:11:05:102 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl performExecute Entry
[11/3/06 15:11:05:102 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl performExecute promotionEngineEnabled=true
[11/3/06 15:11:05:102 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl performExecute Entry
[11/3/06 15:11:05:102 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl performExecute Exit
[11/3/06 15:11:05:102 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl invokePromotionEngine Invoking Promotions Engine with following parameters: OrderId : 36051 DiscardPrevious : true Save Results : true Template : All Promotions
[11/3/06 15:11:05:164 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetStandardOfferCmdImpl validateParameters Entry
[11/3/06 15:11:05:164 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetStandardOfferCmdImpl validateParameters Exit
[11/3/06 15:11:05:164 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetStandardOfferCmdImpl performExecute Entry
[11/3/06 15:11:05:164 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetStandardOfferCmdImpl validateParameters Entry
[11/3/06 15:11:05:164 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetStandardOfferCmdImpl validateParameters Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl validateParameters Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl validateParameters Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl performExecute Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffersForCatentries Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers retrieving offers for catentries: (10142) in store: 10051
retrieving offers from price list: (10051)
retrieving offers from offers: Empty array
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers storeId=10051, productItemIds=(10142), iOfferIds=Empty array, iPriceListIds=(10051), iPSExclusionList=null, iPSInclusionList=null
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Retrieved offers: offer ID=10071, CatalogEntryReferenceNumber=10142offer ID=42176, CatalogEntryReferenceNumber=10142
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl getValidOffers Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer OfferAB -- offer ID: 10071 QuantityUnit: C62
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer valid conversion: true UOM: C62
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer input quantity: 1.0 min quantity: 1.0 max quantity: Infinity
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer valid offer = true
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer OfferAB -- offer ID: 42176 QuantityUnit: C62
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer valid conversion: true UOM: C62
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer input quantity: 1.0 min quantity: 1.0 max quantity: Infinity
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer valid offer = true
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl getValidOffers Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffersForCatentries Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl performExecute Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetStandardOfferCmdImpl retrievePricesWithRequestedCurrency Prices for offer IDs = [] and currency = USD: {10071=USD 19.98000, 42176=USD 19.98000}
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetStandardOfferCmdImpl selectBestOffers The number of the best offers = 1
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetStandardOfferCmdImpl performExecute Exit
[11/3/06 15:11:05:852 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl performExecute Exit
[11/3/06 15:11:05:852 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Exit
[11/3/06 15:11:05:852 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-2)=-212
[11/3/06 15:11:05:883 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-2)=null
[11/3/06 15:11:05:883 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages checkAppliedItems(storeId=10051,usageId=-2)=false
[11/3/06 15:11:05:883 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl performExecute Entry
[11/3/06 15:11:05:914 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl getPolicyId tcIds(tradingId=10504,tcSubType=ShippingTCShippingCharge,memberId=10002)={10003}
[11/3/06 15:11:05:930 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl getPolicyId policyIds(tcId=10003)={-7001}
[11/3/06 15:11:05:930 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyStandardShippingChargeBySellerCmdImpl performExecute Entry
[11/3/06 15:11:05:930 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyStandardShippingChargeBySellerCmdImpl performExecute Entry
[11/3/06 15:11:05:930 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.CalculationCodeCombineCmdImpl performExecute Entry
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper getProductAndItemIds getProductAndItemIds(catalogEntryId=10142)={10141,10142}
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationCodeCombineCmdImpl getIndirectlyAttachedCodes indirectlyAttachedCodeIds(catalogEntryId=10142,contractId=10504,storeId10051,usageId=-2,timestamp=2006-11-03 15:11:00.102)={}
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationCodeCombineCmdImpl getDefaultCode defaultCodeId(storeId=10051,usageId=-2,timestamp=2006-11-03 15:11:00.102)=null
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.CalculationCodeCombineCmdImpl performExecute Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyStandardShippingChargeBySellerCmdImpl performExecute Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyStandardShippingChargeBySellerCmdImpl performExecute Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl applyServiceDiscounts Entry
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl applyServiceDiscounts vecServiceDiscounts=null
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl applyServiceDiscounts Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl performExecute Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-3)=-222
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl reset Entry
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl reset Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-3)=null
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages checkAppliedItems(storeId=10051,usageId=-3)=false
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Entry
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl performExecute Entry
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper getProductAndItemIds getProductAndItemIds(catalogEntryId=10142)={10141,10142}
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getIndirectlyAttachedCodes indirectlyAttachedCodeIds(catalogEntryId=10142,contractId=10504,storeId10051,usageId=-3,timestamp=2006-11-03 15:11:00.102)={}
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getDefaultCode defaultCodeId(storeId=10051,usageId=-3,timestamp=2006-11-03 15:11:00.102)=null
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getCodes codeIds(itemId=520001,storeId=10051,usageId-3,timestamp=2006-11-03 15:11:00.102)=null
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl performExecute Exit
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Exit
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-4)=-232
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl reset Entry
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl reset Exit
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-4)=null
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages checkAppliedItems(storeId=10051,usageId=-4)=false
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Entry
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl reset Entry
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl reset Exit
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl performExecute Entry
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper getProductAndItemIds getProductAndItemIds(catalogEntryId=10142)={10141,10142}
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getIndirectlyAttachedCodes indirectlyAttachedCodeIds(catalogEntryId=10142,contractId=10504,storeId10051,usageId=-4,timestamp=2006-11-03 15:11:00.102)={}
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getDefaultCode defaultCodeId(storeId=10051,usageId=-4,timestamp=2006-11-03 15:11:00.102)=null
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getCodes codeIds(itemId=520001,storeId=10051,usageId-4,timestamp=2006-11-03 15:11:00.102)=null
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl performExecute Exit
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Exit
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper calculateShippingAndTaxCharges Exit
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper computeOrderTotals Entry
[11/3/06 15:11:06:008 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper updateSubOrders productTotal(orderId=36051,addressId=67552)=19.98
[11/3/06 15:11:06:008 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper summarizeCalculationUsages summarizeCalculationUsageMethodId(storeId=10051,usageId=-5)=-5233
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.couponredemption.commands.SummarizeCouponUsageCmdImpl performExecute Entry
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.couponredemption.commands.SummarizeCouponUsageCmdImpl performExecute subOrderAdjustmentAmounts(usageId=-5)={}
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.couponredemption.commands.SummarizeCouponUsageCmdImpl performExecute subOrderAdjustmentTotals(usageId=-5)={}
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.couponredemption.commands.SummarizeCouponUsageCmdImpl performExecute orderAdjustmentTotal(orderId=36051)=0
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.couponredemption.commands.SummarizeCouponUsageCmdImpl performExecute Exit
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper summarizeCalculationUsages summarizeCalculationUsageMethodId(storeId=10051,usageId=-1)=-203
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.SummarizeAdjustmentCmdImpl performExecute Entry
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.SummarizeAdjustmentCmdImpl performExecute subOrderAdjustmentAmounts(usageId=-1)={}
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.SummarizeAdjustmentCmdImpl performExecute subOrderAdjustmentTotals(usageId=-1)={}
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.SummarizeAdjustmentCmdImpl performExecute orderAdjustmentTotal(orderId=36051)=0
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.SummarizeAdjustmentCmdImpl performExecute Exit
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper summarizeCalculationUsages summarizeCalculationUsageMethodId(storeId=10051,usageId=-2)=-213
[11/3/06 15:11:06:055 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.SummarizeShippingCmdImpl performExecute Entry
[11/3/06 15:11:06:055 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.SummarizeShippingCmdImpl performExecute Exit
[11/3/06 15:11:06:055 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper summarizeCalculationUsages summarizeCalculationUsageMethodId(storeId=10051,usageId=-3)=-223
[11/3/06 15:11:06:071 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.SummarizeSalesTaxCmdImpl performExecute Entry
[11/3/06 15:11:06:071 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.CalculationHelper getTaxCategoryIds Entry
[11/3/06 15:11:06:071 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.CalculationHelper getTaxCategoryIds Exit
[11/3/06 15:11:06:071 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.SummarizeSalesTaxCmdImpl performExecute Exit
[11/3/06 15:11:06:071 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper summarizeCalculationUsages summarizeCalculationUsageMethodId(storeId=10051,usageId=-4)=-233
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.SummarizeShippingTaxCmdImpl performExecute Entry
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.CalculationHelper getTaxCategoryIds Entry
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.CalculationHelper getTaxCategoryIds Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.SummarizeShippingTaxCmdImpl performExecute Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper computeOrderTotals Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper saveOrder Entry
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper saveOrder Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.PrepareOrderCmdImpl doProcess Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.PrepareOrderCmdImpl performExecute Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl performExecute Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 SystemOut O orderPrepareCommand command finished in 5.8s

---------------------------------------------------------------------

We have no custom logic which would impact the processing time for "OrderPrepare" command. Out CATENTRY for development database has around 48000 rows.

Any suggestions as to whether we could get away with out "OrderPrepare".
Robert Brown
2006-11-04 02:37:49 UTC
Permalink
Post by VijayaR
Well, we do not have any custom SQL queries to impact this issue.
"OrderPrepare" command is taking nearly 6 seconds for processing a cart with one order item. So as the cart size goes higher, as expected the command is taking longer time to finish. Here is the trace for a single execution of "OrderPrepare" for one order item.
Well, the command is not really taking 6 seconds - a single task call to
applyCalculationUsages() is taking 4 seconds, while the rest of the
command takes less than 2 seconds.
Post by VijayaR
[11/3/06 15:11:01:024 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-1)=-202
[11/3/06 15:11:05:055 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-1)=null
...
Post by VijayaR
[11/3/06 15:11:06:086 PST] 478ce0f0 SystemOut O orderPrepareCommand command finished in 5.8s
Something is unusual. You say 50,000 rows in the CATENTRY table? Not
an extremely alarming number. Have you perhaps taken the time to reorg
and runstat your development database since loading this data? Is DB2
debugging turned on - that'll slow up everything considerably.
Post by VijayaR
---------------------------------------------------------------------
We have no custom logic which would impact the processing time for "OrderPrepare" command. Out CATENTRY for development database has around 48000 rows.
I've seen abnormal performance results with a variety of client
customizations where we loaded large amounts of data and witnessed the
default classes and starter store JSPs bring a site to its knees. I'm
not so sure that is the case here but something is amiss and if you
haven't customized the Java end then that leaves the database.
Post by VijayaR
Any suggestions as to whether we could get away with out "OrderPrepare".
I wouldn't recommend it since usually the customer should be informed of
appropriate discounts and the like before landing on the order submit
page. Consider the OrderPrepare command a crucial step in preparing the
order for checkout. You can bypass and call the OrderDisplay view
command which will in turn invoke OrderPrepare to prepare (calculate)
and lock an order that is not locked and ready for payment processing
(OrderProcess command). In the end, you take the 6+ second hit anyway,
just depends on where.

R
VijayaR
2006-11-03 23:50:59 UTC
Permalink
Well, we do not have any custom SQL queries to impact this issue.

"OrderPrepare" command is taking nearly 6 seconds for processing a cart with one order item. So as the cart size goes higher, as expected the command is taking longer time to finish. Here is the trace for a single execution of "OrderPrepare" for one order item.

---------------------------------------------------------------------
[11/3/06 15:11:00:336 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl setRequestProperties Entry
[11/3/06 15:11:00:336 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl setRequestProperties Entry
[11/3/06 15:11:00:336 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.commands.OrderPrepareCmdImpl setRequestProperties status is P
[11/3/06 15:11:00:336 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl setRequestProperties Exit
[11/3/06 15:11:00:336 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl setRequestProperties Exit
[11/3/06 15:11:00:336 PST] 478ce0f0 SystemOut O Invoke OrderPrepare Command
[11/3/06 15:11:00:352 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl isReadyToCallExecute Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl checkPendingOrderParameters Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.utils.MiscCmd verifyParamValSyntax Order ref num : '36051'
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl checkPendingOrderParameters Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl findOrders Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.utils.ResolveOrdersCmdImpl validateParameters Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.utils.ResolveOrdersCmdImpl validateParameters Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.utils.ResolveOrdersCmdImpl performExecute Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.utils.ResolveOrdersCmdImpl getFromCache(Long) Entry
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.utils.ResolveOrdersCmdImpl getFromCache(Long) Long cache hit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.utils.ResolveOrdersCmdImpl getFromCache(Long) Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.utils.ResolveOrdersCmdImpl performExecute Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER d MiscCmd getPendingOrders Pending orders to be processed:
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER d MiscCmd printOrderList 36051
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl findOrders Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl isReadyToCallExecute Exit
[11/3/06 15:11:00:367 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderPrepareCmdImpl performExecute Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.PrepareOrderCmdImpl performExecute Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.commands.OrderProcessingHelper initialize Order Item : 520001
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.PrepareOrderCmdImpl doProcess Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper removeGeneratedOrderItems Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper removeGeneratedOrderItems Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper ensureAllOrderItemsAreBuyable Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper ensureAllOrderItemsAreBuyable Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemAddresses Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.updateShippingAddressCmdImpl validateParameters Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.updateShippingAddressCmdImpl validateParameters Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.updateShippingAddressCmdImpl performExecute() Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.updateShippingAddressCmdImpl findAddressIdForOrderItem Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.updateShippingAddressCmdImpl findAddressIdForOrderItem Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.updateShippingAddressCmdImpl updateAddress Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.commands.updateShippingAddressCmdImpl updateAddress Setting shipping address of order item 520001 to address id 67552
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.updateShippingAddressCmdImpl updateAddress Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.updateShippingAddressCmdImpl performExecute() Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemAddresses Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemConfigurations Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemConfigurations Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper checkOrderInventory Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl isReadyToCallExecute Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl isReadyToCallExecute Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl checkParameters Entry
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl checkParameters Exit
[11/3/06 15:11:00:524 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl performExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.FulfillmentRegistry isShippingArrangementRestricted Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.FulfillmentRegistry isShippingArrangementRestricted Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.FulfillmentRegistry getEffectiveFulfillmentCenterIds Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.FulfillmentRegistry getMatchingEffectiveFulfillmentCenterIds Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.ShippingArrangementWrapper isValid Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.fulfillment.commands.ShippingArrangementWrapper isValid Shipping arrangement 10001 is assumed valid since the shipping address is not known.
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.ShippingArrangementWrapper isValid Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.FulfillmentRegistry getMatchingEffectiveFulfillmentCenterIds Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.FulfillmentRegistry getEffectiveFulfillmentCenterIds Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl performExecute Try to use the fulfillmentCenterId: 10051 to check inventory.
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl isReadyToCallExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl isReadyToCallExecute Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl checkParameters Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl checkParameters Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl performExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl performExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl findByCatalogEntryAndFulfillmentCenterAndStore Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl findByCatalogEntryAndFulfillmentCenterAndStore Try to check inventory for catalogEntryId=10142, fulfillmentCenterId=10051, storeId=10051
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl findByCatalogEntryAndFulfillmentCenterAndStore Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl performExecute Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl performExecute Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl getOutOfInventoryOrderItems Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.CheckInventoryCmdImpl getOutOfInventoryOrderItems Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.fulfillment.commands.ResolveFulfillmentCenterCmdImpl performExecute Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper checkOrderInventory Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemPrices Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper getCurrencyForOveriddenOrderItems Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper getCurrencyForOveriddenOrderItems Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveOffers Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveOffers Retrieved offers : |10071|
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveOffers Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveTradings Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper getEligibleTradingAgreements Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper getEligibleTradingAgreements eligible trading agreement from Command Context: 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper getEligibleTradingAgreements Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper isTradingAgreementValid -- input trading agreement is valid = 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveTradings Retrieved tradings |10504|
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper retrieveTradings Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemPrices trading agreement from orderitem to be used: 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl validateParameters Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl validateParameters Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl performExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputParameters Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputParameters currency used for prices: USD
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputParameters input error mode: true
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputParameters resolve input for catentryprices.
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveTradingAgreements Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveTradingAgreements trading agreement from input to be used: 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveTradingAgreements Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputFromCatEntryPrices Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputFromCatEntryPrices Use same trading agreements for all catentries
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputFromCatEntryPrices Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl resolveInputParameters Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePriceListInfo Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePriceListInfo retrieving price list for trading agreement: 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePriceListInfo retrieving price list for T&C: 10001(PriceTCMasterCatalogWithFiltering)
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl createCmdMasterCatalogPriceList Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl createCmdMasterCatalogPriceList policy id and pricelist id: 10051,10051
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl createCmdMasterCatalogPriceList pricelist id
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl createCmdMasterCatalogPriceList Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePriceListInfo Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePrices Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrieveOffersForPriceList Resetting retrievePriceCmd
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl reset Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl reset Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrieveOffersForPriceList price list input to retrieve offers: 10051
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl validateParameters Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl validateParameters Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl performExecute Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffersForCatentries Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers retrieving offers for catentries: (10142) in store: 10051
retrieving offers from price list: (10051)
retrieving offers from offers: Empty array
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers storeId=10051, productItemIds=(10142), iOfferIds=Empty array, iPriceListIds=(10051), iPSExclusionList=null, iPSInclusionList=null
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Retrieved offers: offer ID=10071, CatalogEntryReferenceNumber=10142offer ID=42176, CatalogEntryReferenceNumber=10142
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl getValidOffers Entry

[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl getValidOffers Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffersForCatentries Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl performExecute Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl retrievePrices Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl calculatePrices Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl calculatePrices trading agreement input to retrieve offers: 10504
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl calculatePrices master catalog price list input to retrieve offers: 10051
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl validateParameters Entry
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl validateParameters Exit
[11/3/06 15:11:00:539 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl performExecute Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl retrievePriceListInfo Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl retrievePriceListInfo store PriceTCMasterCatalog info that refers to T&C: 10001 and priceList: 10051
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl retrievePriceListInfo Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl retrieveProductSetAdjustments productSetAdjustments={10001=null}
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getTradingOffers Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getTradingOffers Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyPriceAdjustmentForAll Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyPriceAdjustmentForAll applying price adjustments for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment selecting Price Adjustment for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment processing Price T&C = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment catalogEntryId=10142,tcId=10001,productSetAdjustments=null,entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment productSetAdjustments=null,adjustment=entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment best PriceTC is null w/ FoundInProductSet
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment price T&C with best adjustment = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment -- number of prices per offer = 1
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price before adjustment: 19.98000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price termcond id: 10001
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price trading id: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment applying price adjustment: 0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price after adjustment: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment selecting Price Adjustment for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment processing Price T&C = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment catalogEntryId=10142,tcId=10001,productSetAdjustments=null,entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment productSetAdjustments=null,adjustment=entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment best PriceTC is null w/ FoundInProductSet
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment price T&C with best adjustment = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment -- number of prices per offer = 1
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price before adjustment: 19.98000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price termcond id: 10001
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price trading id: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment applying price adjustment: 0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price after adjustment: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyPriceAdjustmentForAll Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyTradingPriceAdjustments Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyTradingPriceAdjustments applying price adjustments for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyTradingPriceAdjustments applying price adjustments for trading agreement: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment selecting Price Adjustment for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment processing Price T&C = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment catalogEntryId=10142,tcId=10001,productSetAdjustments=null,entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment productSetAdjustments=null,adjustment=entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment best PriceTC is null w/ FoundInProductSet
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment price T&C with best adjustment = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment -- number of prices per offer = 1
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price before adjustment: 19.98000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price termcond id: 10001
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price trading id: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment applying price adjustment: 0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price after adjustment: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment selecting Price Adjustment for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment processing Price T&C = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl isTradingEntitledForCatalogEntry filterEnabled(tradingId=10504)=false
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment catalogEntryId=10142,tcId=10001,productSetAdjustments=null,entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl getAdjustment productSetAdjustments=null,adjustment=entireCatalogAdjustment=0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment best PriceTC is null w/ FoundInProductSet
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl selectPriceAdjustment price T&C with best adjustment = 10001 with Adj 0.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment -- number of prices per offer = 1
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price before adjustment: 19.98000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price termcond id: 10001
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price trading id: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment applying price adjustment: 0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment price after adjustment: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl calculatePriceAdjustment Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl applyTradingPriceAdjustments Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.CalculateContractPricesCmdImpl performExecute Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl calculatePrices Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl selectPrices Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.SelectContractPricesCmdImpl validateParameters Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.SelectContractPricesCmdImpl validateParameters Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.SelectContractPricesCmdImpl performExecute Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers selecting offer for item: 10142
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers selecting offer for trading agreement: 10504
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.SelectContractPricesCmdImpl findBestOffer Entry
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl findBestOffer processing offer id: 10071 with pricelist id: 10051 and offer precedence: 1.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl findBestOffer processing offer id: 42176 with pricelist id: 10051 and offer precedence: 1.0
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.PriceCalculationHelper isBestPrice current new price value: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.PriceCalculationHelper isBestPrice current lowest price value: 19.98000000000000000000
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.SelectContractPricesCmdImpl findBestOffer Exit
[11/3/06 15:11:00:555 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers best unit price: 19.98000000000000000000
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers best T&C id: 10001
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers best offer id: 10071
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectTradingOffers Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer Entry
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer selecting offer for item: 10142
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer best unit price: USD 19.98000000000000000000
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer best unit monetary amount: USD 19.98000000000000000000
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer best trading id: 10504
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer best T&C id: 10001
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer best offer id: 10071
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.SelectContractPricesCmdImpl selectOffer Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.SelectContractPricesCmdImpl performExecute Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl selectPrices selected trading id: 10504 tc id: 10001 offer id: 10071 unit price: USD 19.98
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl selectPrices Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetContractUnitPriceCmdImpl performExecute Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper updateTradingId Entry
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper updateTradingId Use trading id returned from pricing: 10504
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper updateTradingId Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper verifyTradingPaymentMethods Entry
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.orderitems.commands.OrderItemsCmdHelper verifyTradingPaymentMethods Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemPrices Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemTotals Entry
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper updateOrderItemTotals Exit
[11/3/06 15:11:00:571 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper calculateShippingAndTaxCharges Entry
[11/3/06 15:11:00:602 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages Entry
[11/3/06 15:11:00:867 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages initializeCalculationUsageMethodId(storeId=10051,usageId=-5)=-5231
[11/3/06 15:11:00:899 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages initializeCalculationUsageMethodId(storeId=10051,usageId=-1)=-201
[11/3/06 15:11:00:899 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.InitializeAdjustmentCmdImpl performExecute Entry
[11/3/06 15:11:00:914 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.InitializeAdjustmentCmdImpl performExecute Exit
[11/3/06 15:11:00:914 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages initializeCalculationUsageMethodId(storeId=10051,usageId=-2)=-211
[11/3/06 15:11:00:930 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.InitializeShippingCmdImpl performExecute Entry
[11/3/06 15:11:00:930 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.InitializeShippingCmdImpl performExecute Exit
[11/3/06 15:11:00:930 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages initializeCalculationUsageMethodId(storeId=10051,usageId=-3)=-221
[11/3/06 15:11:00:946 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.InitializeSalesTaxCmdImpl performExecute Entry
[11/3/06 15:11:00:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.InitializeSalesTaxCmdImpl performExecute Exit
[11/3/06 15:11:00:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages initializeCalculationUsageMethodId(storeId=10051,usageId=-4)=-231
[11/3/06 15:11:00:961 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.InitializeShippingTaxCmdImpl performExecute Entry
[11/3/06 15:11:00:961 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.InitializeShippingTaxCmdImpl performExecute Exit
[11/3/06 15:11:00:961 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.CalculationHelper initializeCalculationUsages Exit
[11/3/06 15:11:00:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-5)=-5232
[11/3/06 15:11:01:024 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-5)=null

[11/3/06 15:11:01:024 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages checkAppliedItems(storeId=10051,usageId=-5)=false
[11/3/06 15:11:01:024 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-1)=-202
[11/3/06 15:11:05:055 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-1)=null
[11/3/06 15:11:05:055 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages checkAppliedItems(storeId=10051,usageId=-1)=false
[11/3/06 15:11:05:055 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Entry
[11/3/06 15:11:05:102 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl performExecute Entry
[11/3/06 15:11:05:102 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl performExecute promotionEngineEnabled=true
[11/3/06 15:11:05:102 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl performExecute Entry
[11/3/06 15:11:05:102 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl performExecute Exit
[11/3/06 15:11:05:102 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl invokePromotionEngine Invoking Promotions Engine with following parameters: OrderId : 36051 DiscardPrevious : true Save Results : true Template : All Promotions
[11/3/06 15:11:05:164 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetStandardOfferCmdImpl validateParameters Entry
[11/3/06 15:11:05:164 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetStandardOfferCmdImpl validateParameters Exit
[11/3/06 15:11:05:164 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetStandardOfferCmdImpl performExecute Entry
[11/3/06 15:11:05:164 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.GetStandardOfferCmdImpl validateParameters Entry
[11/3/06 15:11:05:164 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetStandardOfferCmdImpl validateParameters Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl validateParameters Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl validateParameters Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl performExecute Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffersForCatentries Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers retrieving offers for catentries: (10142) in store: 10051
retrieving offers from price list: (10051)
retrieving offers from offers: Empty array
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers storeId=10051, productItemIds=(10142), iOfferIds=Empty array, iPriceListIds=(10051), iPSExclusionList=null, iPSInclusionList=null
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Retrieved offers: offer ID=10071, CatalogEntryReferenceNumber=10142offer ID=42176, CatalogEntryReferenceNumber=10142
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl getOffers Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl getValidOffers Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer OfferAB -- offer ID: 10071 QuantityUnit: C62
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer valid conversion: true UOM: C62
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer input quantity: 1.0 min quantity: 1.0 max quantity: Infinity
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer valid offer = true
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer Entry
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer OfferAB -- offer ID: 42176 QuantityUnit: C62
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer valid conversion: true UOM: C62
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer input quantity: 1.0 min quantity: 1.0 max quantity: Infinity
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer valid offer = true
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl isValidOffer Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl getValidOffers Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffers Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl retrieveOffersForCatentries Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.RetrievePricesCmdImpl performExecute Exit
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetStandardOfferCmdImpl retrievePricesWithRequestedCurrency Prices for offer IDs = [] and currency = USD: {10071=USD 19.98000, 42176=USD 19.98000}
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.price.commands.GetStandardOfferCmdImpl selectBestOffers The number of the best offers = 1
[11/3/06 15:11:05:196 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.price.commands.GetStandardOfferCmdImpl performExecute Exit
[11/3/06 15:11:05:852 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.PromotionEngineDiscountCalculationCodeCombineCmdImpl performExecute Exit
[11/3/06 15:11:05:852 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Exit
[11/3/06 15:11:05:852 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-2)=-212
[11/3/06 15:11:05:883 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-2)=null
[11/3/06 15:11:05:883 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages checkAppliedItems(storeId=10051,usageId=-2)=false
[11/3/06 15:11:05:883 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl performExecute Entry
[11/3/06 15:11:05:914 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl getPolicyId tcIds(tradingId=10504,tcSubType=ShippingTCShippingCharge,memberId=10002)={10003}
[11/3/06 15:11:05:930 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl getPolicyId policyIds(tcId=10003)={-7001}
[11/3/06 15:11:05:930 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyStandardShippingChargeBySellerCmdImpl performExecute Entry
[11/3/06 15:11:05:930 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyStandardShippingChargeBySellerCmdImpl performExecute Entry
[11/3/06 15:11:05:930 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.CalculationCodeCombineCmdImpl performExecute Entry
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper getProductAndItemIds getProductAndItemIds(catalogEntryId=10142)={10141,10142}
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationCodeCombineCmdImpl getIndirectlyAttachedCodes indirectlyAttachedCodeIds(catalogEntryId=10142,contractId=10504,storeId10051,usageId=-2,timestamp=2006-11-03 15:11:00.102)={}
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationCodeCombineCmdImpl getDefaultCode defaultCodeId(storeId=10051,usageId=-2,timestamp=2006-11-03 15:11:00.102)=null
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.CalculationCodeCombineCmdImpl performExecute Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyStandardShippingChargeBySellerCmdImpl performExecute Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyStandardShippingChargeBySellerCmdImpl performExecute Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl applyServiceDiscounts Entry
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl applyServiceDiscounts vecServiceDiscounts=null
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl applyServiceDiscounts Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.PromotionEngineApplyShippingCmdImpl performExecute Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-3)=-222
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl reset Entry
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl reset Exit
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-3)=null
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages checkAppliedItems(storeId=10051,usageId=-3)=false
[11/3/06 15:11:05:946 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Entry
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl performExecute Entry
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper getProductAndItemIds getProductAndItemIds(catalogEntryId=10142)={10141,10142}
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getIndirectlyAttachedCodes indirectlyAttachedCodeIds(catalogEntryId=10142,contractId=10504,storeId10051,usageId=-3,timestamp=2006-11-03 15:11:00.102)={}
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getDefaultCode defaultCodeId(storeId=10051,usageId=-3,timestamp=2006-11-03 15:11:00.102)=null
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getCodes codeIds(itemId=520001,storeId=10051,usageId-3,timestamp=2006-11-03 15:11:00.102)=null
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl performExecute Exit
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Exit
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages applyCalculationUsageMethodId(storeId=10051,usageId=-4)=-232
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl reset Entry
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl reset Exit
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages taxCategoryIds(storeId=10051,usageId=-4)=null
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper applyCalculationUsages checkAppliedItems(storeId=10051,usageId=-4)=false
[11/3/06 15:11:05:961 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Entry
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl reset Entry
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl reset Exit
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl performExecute Entry
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper getProductAndItemIds getProductAndItemIds(catalogEntryId=10142)={10141,10142}
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getIndirectlyAttachedCodes indirectlyAttachedCodeIds(catalogEntryId=10142,contractId=10504,storeId10051,usageId=-4,timestamp=2006-11-03 15:11:00.102)={}
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getDefaultCode defaultCodeId(storeId=10051,usageId=-4,timestamp=2006-11-03 15:11:00.102)=null
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl getCodes codeIds(itemId=520001,storeId=10051,usageId-4,timestamp=2006-11-03 15:11:00.102)=null
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.TaxCalculationCodeCombineCmdImpl performExecute Exit
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.ApplyCalculationUsageCmdImpl performExecute Exit
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper calculateShippingAndTaxCharges Exit
[11/3/06 15:11:05:977 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper computeOrderTotals Entry
[11/3/06 15:11:06:008 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper updateSubOrders productTotal(orderId=36051,addressId=67552)=19.98
[11/3/06 15:11:06:008 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper summarizeCalculationUsages summarizeCalculationUsageMethodId(storeId=10051,usageId=-5)=-5233
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.couponredemption.commands.SummarizeCouponUsageCmdImpl performExecute Entry
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.couponredemption.commands.SummarizeCouponUsageCmdImpl performExecute subOrderAdjustmentAmounts(usageId=-5)={}
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.couponredemption.commands.SummarizeCouponUsageCmdImpl performExecute subOrderAdjustmentTotals(usageId=-5)={}
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.couponredemption.commands.SummarizeCouponUsageCmdImpl performExecute orderAdjustmentTotal(orderId=36051)=0
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.couponredemption.commands.SummarizeCouponUsageCmdImpl performExecute Exit
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper summarizeCalculationUsages summarizeCalculationUsageMethodId(storeId=10051,usageId=-1)=-203
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.SummarizeAdjustmentCmdImpl performExecute Entry
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.SummarizeAdjustmentCmdImpl performExecute subOrderAdjustmentAmounts(usageId=-1)={}
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.SummarizeAdjustmentCmdImpl performExecute subOrderAdjustmentTotals(usageId=-1)={}
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.SummarizeAdjustmentCmdImpl performExecute orderAdjustmentTotal(orderId=36051)=0
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.SummarizeAdjustmentCmdImpl performExecute Exit
[11/3/06 15:11:06:039 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper summarizeCalculationUsages summarizeCalculationUsageMethodId(storeId=10051,usageId=-2)=-213
[11/3/06 15:11:06:055 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.SummarizeShippingCmdImpl performExecute Entry
[11/3/06 15:11:06:055 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.SummarizeShippingCmdImpl performExecute Exit
[11/3/06 15:11:06:055 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper summarizeCalculationUsages summarizeCalculationUsageMethodId(storeId=10051,usageId=-3)=-223
[11/3/06 15:11:06:071 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.SummarizeSalesTaxCmdImpl performExecute Entry
[11/3/06 15:11:06:071 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.CalculationHelper getTaxCategoryIds Entry
[11/3/06 15:11:06:071 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.CalculationHelper getTaxCategoryIds Exit
[11/3/06 15:11:06:071 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.SummarizeSalesTaxCmdImpl performExecute Exit
[11/3/06 15:11:06:071 PST] 478ce0f0 WC_ORDER d com.ibm.commerce.order.calculation.CalculationHelper summarizeCalculationUsages summarizeCalculationUsageMethodId(storeId=10051,usageId=-4)=-233
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.SummarizeShippingTaxCmdImpl performExecute Entry
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.calculation.CalculationHelper getTaxCategoryIds Entry
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.CalculationHelper getTaxCategoryIds Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.calculation.SummarizeShippingTaxCmdImpl performExecute Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper computeOrderTotals Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER > com.ibm.commerce.order.commands.OrderProcessingHelper saveOrder Entry
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderProcessingHelper saveOrder Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.PrepareOrderCmdImpl doProcess Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.PrepareOrderCmdImpl performExecute Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 WC_ORDER < com.ibm.commerce.order.commands.OrderPrepareCmdImpl performExecute Exit
[11/3/06 15:11:06:086 PST] 478ce0f0 SystemOut O orderPrepareCommand command finished in 5.8s

---------------------------------------------------------------------

We have no custom logic which would impact the processing time for "OrderPrepare" command. Out CATENTRY for development database has around 48000 rows.

Any suggestions as to whether we could get away with out "OrderPrepare".
VijayaR
2006-11-03 23:55:32 UTC
Permalink
Well, we do not have any custom SQL queries to impact this issue.

"OrderPrepare" command is taking nearly 6 seconds for processing a cart with one order item. So as the cart size goes higher, as expected the command is taking longer time to finish. The trace turned on for WC_ORDER(just for single execution of "OrderPrepare" command) is too big to post it here.

We have no custom logic which would impact the processing time for "OrderPrepare" command. Out CATENTRY for development database has around 48000 rows.

Any suggestions as to whether we could get away with out "OrderPrepare".
VijayaR
2006-11-04 00:19:33 UTC
Permalink
Also the URL we send to "OrderPrepare" cmd is below:

"OrderCalculate?updatePrices=1&calculationUsageId=-1&URL=OrderItemDisplay?selected*=&partNumber*=&orderItemId*=&quantity*="
geo
2006-11-06 22:07:33 UTC
Permalink
No you cannot do away with OrderPrepare, that drives the calculations for
tax, shipping, promotions, etc, unless you do not plan on allowing people
to checkout. If that is the case then you can skip OrderPrepare
Post by VijayaR
"OrderCalculate?updatePrices=1&calculationUsageId=-1&URL=OrderItemDisplay?selected*=&partNumber*=&orderItemId*=&quantity*="
m***@ca.ibm.com
2006-11-07 15:03:49 UTC
Permalink
Not sure if this is you as well but see this thread, same type of problem..

http://www-128.ibm.com/developerworks/forums/dw_thread.jsp?forum=284&thread=141168&cat=9
Loading...