12

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....'));)

  • 1
    That's odd. I've done a lot of Apex debugging in my time and I haven't seen that. Can you post either your actual code, or get to a very base repro case that you can post? Another thing you could try - upping the LogLevel of the missing debug call and see if it then shows up. Your #2 and #3 hypotheses seem like very unlikely causes if you're not seeing any LimitExceptions. – jkraybill Mar 18 '13 at 6:59
  • What is makeCalculations actually doing? Including the code could help, I don't think either of the three options you've highlighted are viable. Is there definitely no way the message could not be called? – Matt Lacey Mar 18 '13 at 6:59
  • Thanks for the two comments. It is a large amount of code, but I will put it in a gist (extra explanation in question). – lindon fox Mar 18 '13 at 7:31
  • 3
    How big is your log file? If it gets too large Salesforce will truncate it. I have also seen cases where the middle of the log is cut out, so you get both the start and the end but not certain records in the middle. If this is the case, try adjusting the Logging level on your debug statements and also adjusting the level that gets captured. – Daniel Ballinger Mar 18 '13 at 8:22
  • 2
    Logging level is determined by your client (if you run a code snippet from Eclipse's "Execute Anonymous" it'll be there; if you attach debug logs to user in Monitoring -> Debug logs it'll be there in "filters"). You can also define logging level per code unit (class or trigger) in the web interface! that way you could "skip" a class that you're sure doesn't have problems but occupies lots of space in your log. – eyescream Mar 18 '13 at 9:12
2

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.

  • 1
    This suggestion is actually really useful. Sometimes you just want to get the log now - and throwing an exception will do just that. Thanks for the tip. – lindon fox Mar 27 '13 at 7:19
  • 1
    You can turn off ALL filters (set all log levels to Error), and use System.Debug(System.LoggingLevel, Object) to generate logs at the Error level (System.LoggingLevel.Error). This will reduce your log into mere lines and give you all of your statements, even if there are hundreds or thousands of them. – sfdcfox Jul 12 '13 at 13:30
  • I'm with @sfdcfox on this one, see salesforce.stackexchange.com/questions/11239/…. Personally all of my System.debug statements use the form: System.debug(DebugCtrl.getLoglevel(),'my debug msg') where a static variable in DebugCtrl is set to LoggingLevel.INFO and I run all my debug sessions at Apex Code = INFO'. DebugCtrl has methods to set and get the current log level and thus my testmethods can turn off debug for data record setup and then turn on for the sections needing to debug – cropredy Jul 13 '13 at 0:41
6

I have had this issue recently where the Apex class I am attempting to debug performed a lot of calculations/script statements. The platform will truncate the debug logs and you would see something along the lines of ******** Max debug log size reached********.

What worked for me was to a combination of the methods mentioned above (I notice you have tried changing the logging levels)

  1. Upping the logging level in your debug statement i.e System.debug(Logginglevel.ERROR , ::::::: My Debug :::::::::::::)
  2. Setting up my debug logs with filtering with the filters below through the salesforce UI

    • Database : NONE
    • Workflow : NONE
    • Validation : NONE
    • Callouts : NONE
    • Apex Code : ERROR
    • Apex Profiling : NONE
    • Visualforce : NONE

For more detailed info check out this awesome blog post http://forceguru.blogspot.co.uk/2011/04/system-debug.html

  • Thanks for the suggestion. I will try it out when I get time and get back to you (will be a while sorry). – lindon fox Mar 27 '13 at 7:20
0

I think what you are trying to do is a classic developer problem. We tried to find the line of code which causes the problem and think if salesforce logs would atleast say something to us to know where the problem is. So to solve this, you need to follow the method of guess and elimination.

  1. comment out all methods where you think the problem is not there.

  2. Make the system filter to none so that you dont want loops to be printed.

  3. if this is a vfpage, use apex messages to print on the screen.

  4. Use developer console to view the log and see if if shows the values.

Once you know, the value of the variables, then you can easily fix the line of code. Doing this 3 times would help you to come to the problematic code area. Sorry for being too theory oriented but this might help..

Your Answer

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

Not the answer you're looking for? Browse other questions tagged or ask your own question.