+ Start a Discussion
AWL-CRMAWL-CRM 

Some System.Debug statements not displayed in Debug Log

Dear All,

 

I have a particularly annoying issue with Debug statements.

 

Considering this piece of code:

 

...
System.Debug('## Start request Preparation - Timestamp:' + DateTime.now().format('HH:mm:ss:SSS'));
RequestPreparationResult res = prepareRequest(lstUpIds, operation);
System.Debug('## End request Preparation - Timestamp:' + DateTime.now().format('HH:mm:ss:SSS'));
...

In the debug log window, I can easily find the 'USER_DEBUG|[450]|DEBUG|## End request Preparation - Timestamp:12:36:58:525'
statement but I am unable to find the first one ('## Start request preparation').
In fact, all System.Debug statement after the 'End request' one are displayed but all those before the 'Start request' one (included) are not displayed.

Is anyone aware of limitations regarding System.Debug statements or anything that can prevent my statements to be displayed????

I really need help on this one. Thanks in advance. Best Regards

Ispita_NavatarIspita_Navatar

Hi AWL-CRM,

 I do not think that there is limit in system.debug  in salesforce, and its unusual if you are unable to see the first debug statement in the system log. You should run the debug log again and cross check the debug statements , may be this is happening due to exception in the source code.

 

Did this answer your question? If not, let me know what didn't work, or if so, please mark it solved.

AWL-CRMAWL-CRM

Thanks for your answer Ispita_Navatar,

 

Unfortunately your answer does not help me much or maybe it does I don't know. Let me be clearer.

 

He re is a sample of my code:

 

public static void SendReProvisioning(List<Id> userProfileIds)
{
  System.Debug('## Reprovisioning List: ' + userProfileIds);
  if (userProfileIds.size() > 0)
  {
    ...
    ProvisioningResult out = Provision(idUp, 'Reprovision');
    ...
  }
  ...
}

public static ProvisioningResult Provision(List<Id> lstUpIds, String operation)
{
   ProvisioningResult out = new ProvisioningResult();
   
   System.Debug('## Start request Preparation - Timestamp:' + DateTime.now().format('HH:mm:ss:SSS'));
   RequestPreparationResult res = prepareRequest(lstUpIds, operation);
   System.Debug('## End request Preparation - Timestamp:' + DateTime.now().format('HH:mm:ss:SSS'));
        
   if (res.status)
   {
      System.Debug('## Start create WS - Timestamp:' + DateTime.now().format('HH:mm:ss:SSS'));
      LibSFDCToESBV2.SFToESBv2Export2_SFToESBv2HttpPort ws = createWS();
      System.Debug('## End create WS - Timestamp:' + DateTime.now().format('HH:mm:ss:SSS'));
      System.Debug('## Start callout - Timestamp:' + DateTime.now().format('HH:mm:ss:SSS'));
      LibWKTSComCrmProvisioningV2.CRMProvisionningResponseTypev2 ret = callWS(ws, res.req);
      System.Debug('## End callout - Timestamp:' + DateTime.now().format('HH:mm:ss:SSS'));
      System.Debug('## Start response management - Timestamp:' + DateTime.now().format('HH:mm:ss:SSS'));
      handleResponse(ret, lstUpIds, out, res.req, operation);
      System.Debug('## End response management - Timestamp:' + DateTime.now().format('HH:mm:ss:SSS'));
   }
   else
   {
      out.status = res.status;
      out.error  = res.error;
   }
        
   return out;
}

public static RequestPreparationResult prepareRequest(List<Id> lstUpIds, String operation)
{
  System.Debug('############ operation = ' + operation);
  RequestPreparationResult output = new RequestPreparationResult();
  
  ...
  for (Account acc : accounts.values())
  {
    ...
    for (Integer i = 0; i < lstUserProfile.size(); i++)
    {
      ...
      System.Debug('## Contact:' + output.req.members[index].contact[i].fullName + 'Mailing Cntry:' + up.Contact__r.MailingCountry + '-Account.Country:' + up.Contact__r.Account.BillingCountry + '-Envoye:' + output.req.members[index].contact[i].country);
      ...
    }
    ...
  }
  ...
}

 And here is what I get in System Log for two different executions (as you can see execution is basically based on a loop on some Contacts).

 

-- First, an execution with only one Contact:

 

...
09:53:19.305 (305012000)|USER_DEBUG|[172]|DEBUG|## Reprovisioning List: (a0JT0000003QbfxMAC)
...
09:53:19.324 (324472000)|USER_DEBUG|[448]|DEBUG|## Start request Preparation - Timestamp:09:53:19:427
...
09:53:19.324 (324678000)|USER_DEBUG|[533]|DEBUG|############ operation = Reprovision
...
09:53:19.536 (536921000)|USER_DEBUG|[1080]|DEBUG|## Contact:NiD Test-2011-11-03-03Mailing Cntry:France-Account.Country:France-Envoye:FRANCE
...
09:53:19.547 (547676000)|USER_DEBUG|[450]|DEBUG|## End request Preparation - Timestamp:09:53:19:650
...
09:53:19.547 (547793000)|USER_DEBUG|[454]|DEBUG|## Start create WS - Timestamp:09:53:19:650
...
09:53:19.582 (582493000)|USER_DEBUG|[456]|DEBUG|## End create WS - Timestamp:09:53:19:685
...
09:53:19.582 (582605000)|USER_DEBUG|[457]|DEBUG|## Start callout - Timestamp:09:53:19:685
...
09:53:19.583 (583298000)|USER_DEBUG|[21]|DEBUG|## Start Provisioning, endpoint:...
...
09:53:21.554 (2554919000)|USER_DEBUG|[43]|DEBUG|## End Provisioning, output:...
...
09:53:21.555 (2555402000)|USER_DEBUG|[459]|DEBUG|## End callout - Timestamp:09:53:21:658
...
09:53:21.555 (2555539000)|USER_DEBUG|[460]|DEBUG|## Start response management - Timestamp:09:53:21:658
...
09:53:21.557 (2557764000)|USER_DEBUG|[462]|DEBUG|## End response management - Timestamp:09:53:21:660
...

 As we can see everything is fine.

 

--Second, an execution with 48 Contacts:

...
10:20:58.485 (3485801000)|USER_DEBUG|[1080]|DEBUG|## Contact:ESTEBAN ROMERAMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.500 (3500709000)|USER_DEBUG|[1080]|DEBUG|## Contact:SONIA BUENOMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.515 (3515489000)|USER_DEBUG|[1080]|DEBUG|## Contact:VICTOR BENITOMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.528 (3528357000)|USER_DEBUG|[1080]|DEBUG|## Contact:ESTEBAN ROMERAMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.543 (3543153000)|USER_DEBUG|[1080]|DEBUG|## Contact:LAURENT LAVOLEMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.557 (3557882000)|USER_DEBUG|[1080]|DEBUG|## Contact:JUAN MORCILLOMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.572 (3572782000)|USER_DEBUG|[1080]|DEBUG|## Contact:SALVADOR GARCIAMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
0:20:58.601 (3601554000)|USER_DEBUG|[1080]|DEBUG|## Contact:JOSE RAMON DIEGOMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.616 (3616471000)|USER_DEBUG|[1080]|DEBUG|## Contact:Luis OliverMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.631 (3631277000)|USER_DEBUG|[1080]|DEBUG|## Contact:LUIS OLIVER MARTINEZ SANCHEZMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.646 (3646123000)|USER_DEBUG|[1080]|DEBUG|## Contact:JUAN MORCILLO PARELLADAMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.660 (3660472000)|USER_DEBUG|[1080]|DEBUG|## Contact:ERNESTO SASTREMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.671 (3671435000)|USER_DEBUG|[1080]|DEBUG|## Contact:Sonia -Mailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.682 (3682113000)|USER_DEBUG|[1080]|DEBUG|## Contact:CARLOS ALONSOMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.692 (3692808000)|USER_DEBUG|[1080]|DEBUG|## Contact:Marta PlouMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.702 (3702039000)|USER_DEBUG|[1080]|DEBUG|## Contact:Moises AvilaMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.712 (3712683000)|USER_DEBUG|[1080]|DEBUG|## Contact:Remo De FabritiisMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.723 (3723602000)|USER_DEBUG|[1080]|DEBUG|## Contact:Angel PascualMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.734 (3734230000)|USER_DEBUG|[1080]|DEBUG|## Contact:Suzanne SullivanMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.744 (3744870000)|USER_DEBUG|[1080]|DEBUG|## Contact:Beatriz LA PAZMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.755 (3755501000)|USER_DEBUG|[1080]|DEBUG|## Contact:MARIA JOSE LOPEZMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.766 (3766117000)|USER_DEBUG|[1080]|DEBUG|## Contact:ISABEL VIGUERAMailing Cntry:null-Account.Country:Spain-Envoye:SPAIN
...
10:20:58.772 (3772090000)|USER_DEBUG|[450]|DEBUG|## End request Preparation - Timestamp:10:20:59:027
...
10:20:58.772 (3772190000)|USER_DEBUG|[454]|DEBUG|## Start create WS - Timestamp:10:20:59:027
...
10:20:58.861 (3861627000)|USER_DEBUG|[456]|DEBUG|## End create WS - Timestamp:10:20:59:116
...
10:20:58.861 (3861725000)|USER_DEBUG|[457]|DEBUG|## Start callout - Timestamp:10:20:59:116
...
10:20:58.861 (3861865000)|USER_DEBUG|[21]|DEBUG|## Start Provisioning, endpoint:...
...
10:21:01.340 (6340606000)|USER_DEBUG|[55]|DEBUG|## End Provisioning, error:Error: Provisioning system unavailable! Web service callout failed: Unexpected element....
...
10:21:01.340 (6340933000)|USER_DEBUG|[459]|DEBUG|## End callout - Timestamp:10:21:01:595
...
10:21:01.341 (6341034000)|USER_DEBUG|[460]|DEBUG|## Start response management - Timestamp:10:21:01:596
...
10:21:01.341 (6341244000)|USER_DEBUG|[462]|DEBUG|## End response management - Timestamp:10:21:01:596
...

 3 Different remarqs regarding this log:

-- I can only find 22 contacts from my 48

-- It seems I am missing all the first statements (Reprovisioning List, Start request preparation, operation and some Contacts)

-- As we can see with the line ## End Provisioning, error, I do have an exception catched (in fact it is due to the size of the message I try to send wia callout, but whatever).

 

As the exception is catched after statements at the beginning , should not they be displayed? Is it linked anyway?

 

Hope it can help you find out why it is not working fine !!

 

Thanks in advance.

Best Regards