3

I'm working through a problem here where we have a website that making calls into Apex code that's taking 8 seconds to add an item to a quote, and I wonder if I could get some help understanding if we're following best-practices here, or what could cause these methods to take so long the main calls that are low are calls to SBQQ.ServiceRouter.read, SBQQ.ServiceRouter.load, and SBQQ.ServiceRouter.save, each taking approximately two seconds, and we call the load twice so that's a total of 8

// load the quote and product models, add the product to the quote, and save it. 
String quoteModel = SBQQ.ServiceRouter.read('SBQQ.QuoteAPI.QuoteReader', quoteId);
String productModel = SBQQ.ServiceRouter.load('SBQQ.ProductAPI.ProductLoader', productId, '{"pricebookId" : "' + pricebookId + '", "currencyCode" : "' + currencyCode + '"}');
String updatedQuoteModel = SBQQ.ServiceRouter.load('SBQQ.QuoteAPI.QuoteProductAdder', null, '{"quote" : ' + quoteModel + ', "products" : [' + productModel + '], "ignoreCalculate" : true}');
String savedQuoteModel = SBQQ.ServiceRouter.save('SBQQ.QuoteAPI.QuoteSaver', updatedQuoteModel);

it was suggested that perhaps there are triggers running which is slowing this down, but the first line just reads the quote, right? how could that trigger anything? In the debug log, I get this:

12:57:27.607 (4994302117)|METHOD_ENTRY|[203]|01pf2000006LzXR|SBQQ.ServiceRouter.read(String, String)

then a whole bunch of these:

12:57:27.607 (5596017973)|ENTERING_MANAGED_PKG|SBQQ

and in the middle of those is this:

12:57:27.607 (5102296770)|SOQL_EXECUTE_BEGIN|[107]|Aggregations:0|SELECT ObjectName__c, FieldName__c, LookupName__c, ParentObjectName__c FROM CalculatorReferencedField__c
12:57:27.607 (5106566512)|SOQL_EXECUTE_END|[107]|Rows:33

then more of those, and then suddenly they switch timestamps:

12:57:28.609 (5655147902)|ENTERING_MANAGED_PKG|SBQQ

there's a whole bunch of those and in the middle is this:

12:57:28.609 (6023486190)|SOQL_EXECUTE_BEGIN|[109]|Aggregations:0|SELECT Id,Name,SBQQ__Type__c,SBQQ__CustomerDiscount__c,SBQQ__MarkupRate__c,SBQQ__Account__c,SBQQ__PartnerDiscount__c,SBQQ__SubscriptionTerm__c,SBQQ__ExpirationDate__c,SBQQ__StartDate__c,SBQQ__EndDate__c,SBQQ__MasterContract__c,SBQQ__MasterEvergreenContract__c,SBQQ__QuoteProcessId__c,SBQQ__DistributorDiscount__c,SBQQ__NetAmount__c,SBQQ__CustomerAmount__c,SBQQ__PricebookId__c,SBQQ__FirstSegmentTermEndDate__c,SBQQ__GenerateContractedPrice__c,SBQQ__ContractingMethod__c,SBQQ__BillingFrequency__c,SBQQ__Unopened__c,SBQQ__RenewalTerm__c,SBQQ__RenewalUpliftRate__c,SBQQ__LineItemCount__c,SBQQ__PaymentTerms__c,SBQQ__OrderGroupID__c,SBQQ__TargetCustomerAmount__c,SBQQ__WatermarkShown__c,SBQQ__OrderBy__c,Promo_Code__c,Terms_Conditions__c,Total_per_month__c,SBQQ__Account__r.Name,SBQQ__MasterContract__r.ContractNumber,SBQQ__MasterEvergreenContract__r.ContractNumber,SBQQ__Status__c,SBQQ__Primary__c,SBQQ__LineItemsGrouped__c,SBQQ__Opportunity2__r.Id,SBQQ__Opportunity2__r.SBQQ__PrimaryQuote__c,SBQQ__Opportunity2__r.Pricebook2Id,SBQQ__Opportunity2__r.AccountId,SBQQ__Account__r.SBQQ__RenewalModel__c,SBQQ__Account__r.SBQQ__RenewalPricingMethod__c FROM SBQQ__Quote__c WHERE Id IN ('a0q4D000000ElEPQA0')
12:57:28.609 (6044003732)|SOQL_EXECUTE_END|[109]|Rows:1

and a whole bunch more later is this:

12:57:28.609 (6113669261)|SOQL_EXECUTE_BEGIN|[31]|Aggregations:0|SELECT Id,Name,SBQQ__Description__c,SBQQ__Number__c,SBQQ__ListTotal__c,SBQQ__NetTotal__c,SBQQ__CustomerTotal__c,SBQQ__SubscriptionTerm__c,SBQQ__Quote__c,SBQQ__AdditionalDiscountRate__c,SBQQ__MarkupRate__c,SBQQ__StartDate__c,SBQQ__EndDate__c,SBQQ__Optional__c,SBQQ__SeparateContract__c,SBQQ__QuoteProcess__c,SBQQ__Favorite__c,SBQQ__TargetCustomerAmount__c,SBQQ__Quote__r.Name,SBQQ__QuoteProcess__r.Name,SBQQ__Favorite__r.Name FROM SBQQ__QuoteLineGroup__c WHERE SBQQ__Quote__c IN ('a0q4D000000ElEPQA0') ORDER BY SBQQ__Number__c ASC,CreatedDate ASC
12:57:28.609 (6122899696)|SOQL_EXECUTE_END|[31]|Rows:0

and then a whole bunch more and then the timestamp changes again:

12:57:28.609 (6608755667)|ENTERING_MANAGED_PKG|SBQQ
12:57:29.609 (6609231989)|ENTERING_MANAGED_PKG|SBQQ

and then a whole bunch more at the new timestamp, and then in the middle is a query again with over 2000 characters ending in: FROM SBQQ__QuoteLine__c WHERE SBQQ__Quote__c IN ('a0q4D000000ElEPQA0') ORDER BY SBQQ__Number__c ASC,SBQQ__SegmentIndex__c ASC,CreatedDate ASC and then it goes to the next function:

12:57:29.609 (6806789249)|METHOD_EXIT|[203]|01pf2000006LzXR|SBQQ.ServiceRouter.read(String, String)
12:57:29.609 (6806799561)|VARIABLE_SCOPE_BEGIN|[203]|quoteModel|String|false|false
12:57:29.609 (6806822873)|VARIABLE_ASSIGNMENT|[203]|quoteModel|"{\"ui_original_record (2298 more) ..."
12:57:29.609 (6806828793)|STATEMENT_EXECUTE|[204]
12:57:29.609 (6806833946)|HEAP_ALLOCATE|[204]|Bytes:29
12:57:29.609 (6806841072)|HEAP_ALLOCATE|[204]|Bytes:18
12:57:29.609 (6806845091)|HEAP_ALLOCATE|[204]|Bytes:21
12:57:29.609 (6806848813)|HEAP_ALLOCATE|[204]|Bytes:2
12:57:29.609 (6806862774)|HEAP_ALLOCATE|[204]|Bytes:62
12:57:29.609 (6806886614)|METHOD_ENTRY|[204]|01pf2000006LzXR|SBQQ.ServiceRouter.load(String, String, String)

any thoughts about all that? Sorry it's a hell of a dump, but since I have those details... how can I figure out what's going on here?

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.