When debug mode on a unit test is terminated, can you show the reason why?

[June Bischoff]

I LOVE debug mode! But sometimes I have a unit test that shows Terminated, with the event log "Failed to start: 0 passed, 1 not started"

It SEEMS like this happens if a class used by the unit test is out of sync, maybe? The unit test will run fine when I'm not trying to debug.

Can you shed some light into why it fails to start? And if it's possible to show a user-friendly reason for the failure in the UI, that would be a great enhancement.

Attached is a snippet from the idea.log.

[Scott Wells]

Thanks for the log, June. I'll take a look. And glad you're finding the debugger useful!

[Anthony Sanchez]

I'm also running into this bug. I tailed the log and it looks like this is the cause?

2016-06-23 10:17:51,178 [3262316]   WARN - inatedcloud.client.ApexLogUtil - Found old TraceFlags that cannot be updated. Deleting them and creating a new one. 
2016-06-23 10:17:56,800 [3267938]   WARN - cloud.client.ForceComApiClient - Status code 400 returned trying to retrieve 'https://cs24.salesforce.com/services/data/v37.0/tooling/sobjects/ApexLog/07L1900000FMlVoEAL/Body/': Bad Request 
2016-06-23 10:17:56,801 [3267939]   WARN - inatedcloud.client.ApexLogUtil - Empty log body returned for Apex log ID 07L1900000FMlVoEAL 
2016-06-23 10:17:56,802 [3267940]  ERROR - pplication.impl.LaterInvocator - Argument for @NotNull parameter 'name' of com/intellij/execution/testframework/sm/ServiceMessageBuilder.testFailed must not be null 
java.lang.IllegalArgumentException: Argument for @NotNull parameter 'name' of com/intellij/execution/testframework/sm/ServiceMessageBuilder.testFailed must not be null
    at com.intellij.execution.testframework.sm.ServiceMessageBuilder.testFailed(ServiceMessageBuilder.java)
    at com.illuminatedcloud.intellij.unittest.ApexUnitTestRunProcessHandler$23.run(SourceFile:1513)
    at com.intellij.openapi.application.impl.LaterInvocator$FlushQueue.a(LaterInvocator.java:345)
    at com.intellij.openapi.application.impl.LaterInvocator$FlushQueue.run(LaterInvocator.java:329)
    at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:311)
    at java.awt.EventQueue.dispatchEventImpl(EventQueue.java:756)
    at java.awt.EventQueue.access$500(EventQueue.java:97)
    at java.awt.EventQueue$3.run(EventQueue.java:709)
    at java.awt.EventQueue$3.run(EventQueue.java:703)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:76)
    at java.awt.EventQueue.dispatchEvent(EventQueue.java:726)
    at com.intellij.ide.IdeEventQueue.g(IdeEventQueue.java:857)
    at com.intellij.ide.IdeEventQueue._dispatchEvent(IdeEventQueue.java:658)
    at com.intellij.ide.IdeEventQueue.dispatchEvent(IdeEventQueue.java:386)
    at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:201)
    at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:116)
    at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:105)
    at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101)
    at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:93)
    at java.awt.EventDispatchThread.run(EventDispatchThread.java:82)

[June Bischoff]

I'm seeing the same error threads as Anthony now, and no luck syncing my code in getting the debugger to run. If I click directly on the bad request link I get

<Errors>
<Error>
<errorCode>INVALID_SESSION_ID</errorCode>
<message>Session expired or invalid</message>
</Error>
</Errors>

I'm up against a place where it would be supremely helpful to be able to debug.

My unit test has a @testSetup method, if that makes any difference at all.

[Scott Wells]

June, I'm not sure I follow your last comment. When you say "syncing my code", do you mean from the server to the local filesystem or aligning the resulting log to allow it to be debugged. Can you elaborate on what exactly you're doing and what's happening?

I'll see if I can take a look tonight. I've had company in town for the past week which has monopolized my evenings and weekends, but I should have some time this week to dig in more.

[June Bischoff]

I meant retrieving all changes from the server to the local filesystem. My test method suddenly decided it would run in debug mode about an hour ago, but it behaves extremely strangely if I have a TestSetup class. (Attempts to step through jump further down the code than I would expect, including through to completion of the unit test.)

[Scott Wells]

Okay. I'll see if I can reproduce that behavior. I've also added more null checking in the stack trace identified above by you and Anthony. However, I can't say for sure why that value (the test method name) is null as I'm pulling it directly from the Salesforce Tooling API response (RunTestFailure.getMethodName()). I may have to follow up with the folks at Salesforce to see if they know why it might return null sometimes.

Let me try debugging a test method in a class with a @TestSetup-annotated method and see if I can reproduce the behavior you've described.

[Scott Wells]

June, I've added a @TestSetup annotation to one of my test classes and debugged it. What I see is that the debugger stops inside of the test setup method, and when I step out of that method (assuming I don't have other breakpoints), it runs to completion. This is because I don't have enough information to step out into the test harness and then back into a test method. However, if I set a breakpoint on the first line of the test method I want to debug and tell the debugger to resume, it stops properly on the breakpoint and I can begin debugging in earnest.

If you find that you're unable to control the debugger in your own classes this way, it would help tremendously if you could put together a small, standalone test class that reproduces the issue and attach it here so I can debug...er...the debugger.

[June Bischoff]

After a brief spurt of deciding it didn't want to run, I was able to confirm that my breakpoint at the start of the test class proper is resoundingly ignored.

Part of the problem may lie in the fact that this is NOT a small standalone test class; I'm calling out to other classes including in test setup, and we have a complex suspend/resume saves method within that. I'll see what I can do to put together the minimal classes that reproduce the issue.

[Scott Wells]

Thanks. A reproducible example will definitely help. As you can imagine, creating a debugger based on log files with a reasonable amount of inconsistency in their content has been quite difficult, so I imagine whatever is happening here is one of many "not happy path" scenarios that don't work well with it right now. I'll definitely see what I can do once I have a standalone test case, though.

[Scott Wells]

Partially fixed (the IllegalArgumentException) in 1.7.2.6.

[June Bischoff]

Hmm. Realizing with the number of managed-package objects and customized fields we have, creating a small sample is not a small feat. :(

[June Bischoff]

My sample ran fine. And now, for no apparent reason, my stepping through is running reasonably well in the real-world beast. It still sporadically decides not to debug, and then it's good again. If you want to keep fixing debugger issues as you see them and close or downgrade the priority of this ticket, I'm good with that. I'll come crying when it misbehaves again.

[Scott Wells]

I'll probably go ahead and resolve this, but I'll share a few tidbits of info that might help in the future when using the offline debugger. First, if the resulting log file is more than the 2MB max, you'll get a truncated log. Where the log gets truncated is seemingly random, so sometimes these look like good logs that ultimately go into a dead end; sometimes they're truncated at the top and I can't get a foothold to start the debugger. Take a look at the resulting log and if it's truncated, you'll need to debug using lower logging levels and checkpoints/breakpoints. Second, I've noticed that after a while, the logs for your user fill up (across all logs rather than a single log) and you'll start getting odd results. Go into IC's Log Viewer and highlight some logs to make space, then click the "X" button to delete them. Retry the operation and often it will suddenly produce a usable log.

This is the fun of building an interactive diagnostic tool on top of an inconsistent diagnostic reporting mechanism!

Regards, Scott