[SalesForce] Inconsistent logging output!

I am trying to log some values for general testing and I am getting some really strange behaviour. Some of the logs are just not printing. This is what is happening:

  1. I am pressing a button that runs a query, make some calculations and displays the results in a table
  2. When the button action method runs, I am writing messages to the console using System.debug
  3. Confusingly, some of the messages are just not showing when run. For example, I get the last print of the method, but not the first one (on the first line of the method). How can the last line print, but not the first??? There is no login before the first line that would mean that it would not be run. If the last line runs, then so must the first line…

I have been able to find the method (makeCalculations) that causes the "problem". If i remove this method, then the logs seem to print out as expected. But the trouble is, I was kinda wanting to make those calculations. If I go into more detail, I can get about half of the method (makeCalculations) commented out and the console logs are still fine. But if I add just one additional System.debug line to that method, then the logs become screwey again.

I think I can assert that it is not that the System.debug is not being called, because setting variables which are shown on the page above and below the line and they output as expected.

I have also tried downloading the raw log file in case there was some limit on the browser (which I think i have reached before, but when I did, I was alerted to this fact). The only real thing I can think of is:

  1. There is a limit to the number of logs you are allowed to output and to be really mean they decided to just randomly delete some log messages, but not all.
  2. I have too mush sql – I don't think so – only three
  3. The code is running for too long – maybe, but the calculations are only iterating over a small collection and the calculations are not anything special (there are a lot of them though)

Any ideas? This is driving me crazy.


update

Added the code to a gist as requested. The names have been changed to protect the innocent. Apologies for the length. The code comes in through doSearch. The method 'makeCalculations' gets called on an inner class, which in tern instantiates a different inner class. The second class is where the calculations are done.

Update 2

I have tried changing the logging levels (as discussed in the comments below), with no apparent change. Any further ideas appreciated.

Update 3

After a bit more pain with this. I have found that the most reliable way to get logging is by throwing exceptions as suggested below. A little less destructive, but not always as reliable is to add an ApexPages memssage (ApexPages.addMessage(new ApexPages.Message(ApexPages.severity.ERROR, 'Search did not validate....'));)

Best Answer

This seems to happen whenever the log is very long. Salesforce seems to skip your Logging statements to put more of their own into the file.

The only (ugly) workaround I found for those case to throw a custom exception that shows my debug output. That always reveals a result.

Related Topic