When save fails, errors are not highlighted

[Evgenii Azimzhanov]

Saving a class, two errors appear but the lines with the errors are not highlighted. Earlier Intellij highlighted the lines with the issues.

[Scott Wells]

Hmmmm....I'm not aware of anything that would have changed to cause this not to work now. I just tried to reproduce this locally and here's what I see:

I've included all views where the errors details are displayed:

1. The Event Log (bottom-right) which doesn't include much in the way of details.
2. The Messages view (top-left) which includes full details in a textual manner hyperlinked to source.
3. The Illuminated Cloud Problems view (bottom-left) which includes details in a tree view hyperlinked to source.
4. The editor itself (top-right) which includes line-level highlighting of the reported errors.

As you can see, I'm seeing the error in the editor as well as in the other views, so that should obviously be our goal for you as well. I'd be curious to see the Messages and/or Illuminated Cloud Problems view when this happens to you, in particular to see the reported file path and line/column number information. I'd also like to see the idea.log from when this happens to see if there are any errors reported there that might be preventing the editor from being highlighted properly. Can you provide this information so that I can debug further? Thanks!

[Doug Ayers]

I've noticed that working with scratch org (sfdx projects), then I do not see my editors mark up with the errors. I have to read the messages toolbar.

For non-sfdx projects (traditional package.xml), then I do see my editors mark up with errors fine.

[Scott Wells]

Doug, I'm also unable to reproduce that behavior. Here's error reporting in an SFDX project for me:

Can you verify that you're on the latest builds of both IC and the SFDX CLI? If you are and the problem persists, can you reproduce the issue with debug logging enabled for Salesforce DX as documented here:

http://www.illuminatedcloud.com/support/debuglogging

and provide the resulting idea.log? I'd be curious to see what's going on behind the scenes.

[Doug Ayers]

Hi Scott, I wonder if it's isolated to WebStorm? I think you use IntelliJ Ultimate?

In WebStorm, I do not have the "Illuminated Cloud" panel on the bottom toolbar like in your screen shot. I also cannot find it in the "View > Tool Windows" menu either.

What I see in the bottom toolbar:

WebStorm version:

Illuminated Cloud version:

Salesforce CLI version:

sfdx-cli/6.26.0-7de08aa3af (darwin-x64) node-v8.9.4

Log Files

Collected after modifying apex class named BindingParam.cls and pressing CMD+S (save all) in WebStorm, which fired a force:source:push.

Using these debug qualifiers:

#com.illuminatedcloud.util.CommandLineUtil
#com.illuminatedcloud.intellij.sfdx.SfdxUtil
#com.illuminatedcloud.intellij.builder.ForceComSfdxDeployer
#com.illuminatedcloud.intellij.builder.ForceComSfdxRetriever
#com.illuminatedcloud.util.VariableLengthPollingInterval

sfdx.log

{  
   "name":"sfdx",
   "hostname":"dougayers-ltm.internal.salesforce.com",
   "pid":12206,
   "level":50,
   "msg":"{\"message\":\"Push failed.\",\"status\":1,\"stack\":\"DeployFailed: Push failed.\\n    at ALMError (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/salesforce-alm/dist/lib/almError.js:43:19)\\n    at MetadataRegistry.initializeMetadataTypeInfos.then.catch.e (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/salesforce-alm/dist/lib/mdapiPushCommand.js:49:31)\\n    at tryCatcher (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/util.js:16:23)\\n    at Promise._settlePromiseFromHandler (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/promise.js:510:31)\\n    at Promise._settlePromise (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/promise.js:567:18)\\n    at Promise._settlePromise0 (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/promise.js:612:10)\\n    at Promise._settlePromises (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/promise.js:687:18)\\n    at Async._drainQueue (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/async.js:138:16)\\n    at Async._drainQueues (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/async.js:148:10)\\n    at Immediate.Async.drainQueues (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/async.js:17:14)\\n    at runCallback (timers.js:789:20)\\n    at tryOnImmediate (timers.js:751:5)\\n    at processImmediate [as _immediateCallback] (timers.js:722:5)\",\"name\":\"DeployFailed\",\"result\":[{\"columnNumber\":\"41\",\"lineNumber\":\"229\",\"error\":\"Variable does not exist: value2 (229:41)\",\"fullName\":\"BindingParam\",\"type\":\"ApexClass\",\"filePath\":\"force-di/main/default/classes/BindingParam.cls\"}],\"warnings\":[]}",
   "time":"2018-07-28T20:56:24.920Z",
   "v":0
}

idea.log

2018-07-28 16:14:41,783 [      0]   INFO -        #com.intellij.idea.Main - ------------------------------------------------------ IDE STARTED ------------------------------------------------------ 
2018-07-28 16:14:41,816 [     33]   INFO -        #com.intellij.idea.Main - IDE: WebStorm (build #WS-182.3684.70, 20 Jul 2018 03:41) 
2018-07-28 16:14:41,816 [     33]   INFO -        #com.intellij.idea.Main - OS: Mac OS X (10.13.6, x86_64) 
2018-07-28 16:14:41,816 [     33]   INFO -        #com.intellij.idea.Main - JRE: 1.8.0_152-release-1248-b8 (JetBrains s.r.o) 
2018-07-28 16:14:41,816 [     33]   INFO -        #com.intellij.idea.Main - JVM: 25.152-b8 (OpenJDK 64-Bit Server VM) 
2018-07-28 16:14:41,824 [     41]   INFO -        #com.intellij.idea.Main - JVM Args: -Xms128m -Xmx750m -XX:ReservedCodeCacheSize=240m -XX:+UseCompressedOops -Dfile.encoding=UTF-8 -XX:+UseConcMarkSweepGC -XX:SoftRefLRUPolicyMSPerMB=50 -ea -Dsun.io.useCanonCaches=false -Djava.net.preferIPv4Stack=true -XX:+HeapDumpOnOutOfMemoryError -XX:-OmitStackTraceInFastThrow -Xverify:none -XX:ErrorFile=/Users/doug.ayers/java_error_in_webstorm_%p.log -XX:HeapDumpPath=/Users/doug.ayers/java_error_in_webstorm.hprof -Dide.no.platform.update=true -Djdk.http.auth.tunneling.disabledSchemes="" -Djb.vmOptionsFile=/Users/doug.ayers/Library/Application Support/JetBrains/Toolbox/apps/WebStorm/ch-0/182.3684.70/WebStorm.app.vmoptions -Didea.java.redist=jdk-bundled -Didea.home.path=/Users/doug.ayers/Library/Application Support/JetBrains/Toolbox/apps/WebStorm/ch-0/182.3684.70/WebStorm.app/Contents -Didea.executable=webstorm -Didea.platform.prefix=WebStorm -Didea.paths.selector=WebStorm2018.2 
2018-07-28 16:14:41,824 [     41]   INFO -        #com.intellij.idea.Main - ext: /Users/doug.ayers/Library/Application Support/JetBrains/Toolbox/apps/WebStorm/ch-0/182.3684.70/WebStorm.app/Contents/jdk/Contents/Home/jre/lib/ext: [sunec.jar, nashorn.jar, cldrdata.jar, jfxrt.jar, dnsns.jar, localedata.jar, sunjce_provider.jar, meta-index, sunpkcs11.jar, jaccess.jar, zipfs.jar] 
2018-07-28 16:14:41,824 [     41]   INFO -        #com.intellij.idea.Main - ext: /System/Library/Java/Extensions: [MRJToolkit.jar] 
2018-07-28 16:14:41,825 [     42]   INFO -        #com.intellij.idea.Main - charsets: JNU=UTF-8 file=UTF-8 
2018-07-28 16:14:41,838 [     55]   INFO -        #com.intellij.idea.Main - JNA library (64-bit) loaded in 13 ms 
2018-07-28 16:14:41,869 [     86]   INFO -        #com.intellij.idea.Main - initializing environment 
2018-07-28 16:14:41,870 [     87]   INFO - .intellij.util.EnvironmentUtil - loading shell env: /bin/zsh -l -i -c '/Users/doug.ayers/Library/Application Support/JetBrains/Toolbox/apps/WebStorm/ch-0/182.3684.70/WebStorm.app/Contents/bin/printenv.py' '/private/var/folders/sp/zk3hs3ys4yn4kvg_n9vdz1yd6vy8f3/T/intellij-shell-env.tmp' 
2018-07-28 16:14:42,089 [    306]   INFO -     #com.intellij.util.ui.JBUI - User scale factor: 1.0 
2018-07-28 16:14:42,101 [    318]   INFO -     #com.intellij.util.ui.JBUI - System scale factor: 1.0 (JRE-managed HiDPI) 
2018-07-28 16:14:44,648 [   2865]   INFO - .intellij.util.EnvironmentUtil - shell environment loaded (36 vars) 
2018-07-28 16:14:44,828 [   3045]   INFO - llij.ide.plugins.PluginManager - Cannot find optional descriptor java-specific.xml 
2018-07-28 16:14:44,833 [   3050]   INFO - llij.ide.plugins.PluginManager - Cannot find optional descriptor javaee-specific.xml 
2018-07-28 16:14:44,885 [   3102]   INFO - llij.ide.plugins.PluginManager - Cannot find optional descriptor uml-properties-support.xml 
2018-07-28 16:14:44,885 [   3102]   INFO - llij.ide.plugins.PluginManager - Cannot find optional descriptor uml-java-support.xml 
2018-07-28 16:14:45,087 [   3304]   INFO - llij.ide.plugins.PluginManager - Cannot find optional descriptor js-nashorn-support.xml 
2018-07-28 16:14:46,140 [   4357]   INFO - .intellij.idea.IdeaApplication - CPU cores: 4; ForkJoinPool.commonPool: java.util.concurrent.ForkJoinPool@47851395[Running, parallelism = 3, size = 0, active = 0, running = 0, steals = 0, tasks = 0, submissions = 0]; factory: com.intellij.concurrency.IdeaForkJoinWorkerThreadFactory@9a6f36e 
2018-07-28 16:14:46,490 [   4707]   INFO - llij.ide.plugins.PluginManager - Cannot find optional descriptor java-specific.xml 
2018-07-28 16:14:46,494 [   4711]   INFO - llij.ide.plugins.PluginManager - Cannot find optional descriptor javaee-specific.xml 
2018-07-28 16:14:46,513 [   4730]   INFO - llij.ide.plugins.PluginManager - Cannot find optional descriptor uml-properties-support.xml 
2018-07-28 16:14:46,514 [   4731]   INFO - llij.ide.plugins.PluginManager - Cannot find optional descriptor uml-java-support.xml 
2018-07-28 16:14:46,636 [   4853]   INFO - llij.ide.plugins.PluginManager - Cannot find optional descriptor js-nashorn-support.xml 
2018-07-28 16:14:46,955 [   5172]   INFO - llij.ide.plugins.PluginManager - 61 plugins initialized in 538 ms 
2018-07-28 16:14:46,955 [   5172]   INFO - llij.ide.plugins.PluginManager - Loaded bundled plugins: ASP (0.1), AngularJS (182.3684.70), CSS Support (182.3684.70), CoffeeScript (182.3684.70), Copyright (8.1), Cucumber.js (0.1), Dart (182.3684.70), Docker integration (182.3684.70), EJS (182.3684.70), EditorConfig (182.3684.70), File Watchers (182.3684.70), Gherkin (999.999), Git Integration (8.1), GitHub (182.3684.70), HTML Tools (2.0), HTTP Client (182.3684.70), Haml (182.3684.70), Handlebars/Mustache (182.3684.70), IDE Settings Sync (182.3684.70), IDEA CORE (182.3684.70), IntelliLang (8.0), Java Server Pages (JSP) Integration (1.0), JavaScript Debugger (1.0), JavaScript Intention Power Pack (0.9.4), JavaScript Support (1.0), Karma (182.3684.70), Less support (182.3684.70), LiveEdit (182.3684.70), Mercurial Integration (10.0), Meteor (182.3684.70), Node.js Remote Interpreter (182.3684.70), NodeJS (182.3684.70), Performance Testing (182.3684.70), PhoneGap/Cordova Plugin (182.3684.70), Polymer & Web Components (999.999), Prettier (182.3684.70), Pug (ex-Jade) (182.3684.70), Refactor-X (2.01), Remote Hosts Access (0.1), SSH Remote Run (0.1), Sass support (182.3684.70), Settings Repository (182.3684.70), Spy-js (182.3684.70), Stylus support (999.999), Subversion Integration (1.1), Task Management (1.0), Terminal (0.1), TextMate bundles support (182.3684.70), Time Tracking (1.0), UML Support (1.0), Vagrant (182.3684.70), Vue.js (182.3684.70), W3C Validators (2.0), XPathView + XSLT Support (4), YAML (182.3684.70), Yeoman (182.3684.70), tslint (182.3684.70) 
2018-07-28 16:14:46,955 [   5172]   INFO - llij.ide.plugins.PluginManager - Loaded custom plugins: BashSupport (1.6.13.182), CodeGlance (1.5.4), Illuminated Cloud 2 (2.0.2.9), Markdown support (182.2371) 
2018-07-28 16:14:47,421 [   5638]   INFO - cloudConfig.CloudConfigManager - === Exit: JBA_NOT_FOUND === 
2018-07-28 16:14:47,502 [   5719]   INFO - ellij.util.io.PagedFileStorage - lower=100; upper=500; buffer=10; max=705 
2018-07-28 16:14:47,546 [   5763]   INFO - pl.local.NativeFileWatcherImpl - Starting file watcher: /Users/doug.ayers/Library/Application Support/JetBrains/Toolbox/apps/WebStorm/ch-0/182.3684.70/WebStorm.app/Contents/bin/fsnotifier 
2018-07-28 16:14:47,562 [   5779]   INFO - pl.local.NativeFileWatcherImpl - Native file watcher is operational. 
2018-07-28 16:14:47,765 [   5982]   INFO - pi.util.registry.RegistryState - Registry values changed by user: 
2018-07-28 16:14:47,765 [   5982]   INFO - pi.util.registry.RegistryState -   debugger.mayBringFrameToFrontOnBreakpoint = false 
2018-07-28 16:14:47,765 [   5982]   INFO - pi.util.registry.RegistryState -   ide.editor.tabs.open.at.the.end = true 
2018-07-28 16:14:47,765 [   5982]   INFO - pi.util.registry.RegistryState -   ide.tooltip.show.with.actions = true 
2018-07-28 16:14:47,765 [   5982]   INFO - pi.util.registry.RegistryState -   search.everywhere.settings = true 
2018-07-28 16:14:47,778 [   5995]   INFO - pi.util.registry.RegistryState - Experimental features enabled for user: inline.browse.button 
2018-07-28 16:14:47,815 [   6032]   INFO - tellij.openapi.util.IconLoader - replace '/nodes/newFolder.png' with 'AllIcons.Nodes.Folder' 
2018-07-28 16:14:48,100 [   6317]   INFO - lluminatedCloudFileTypeFactory - Registering external resource http://soap.sforce.com/2006/04/metadata as /Users/doug.ayers/Library/Application Support/WebStorm2018.2/IlluminatedCloud2/lib/IlluminatedCloud.jar!/xsd/metadata.xsd. 
2018-07-28 16:14:48,282 [   6499]   INFO - com.intellij.ide.ui.UISettings - Loaded: fontSize=12, fontScale=0.0; restored: fontSize=12, fontScale=1.0 
2018-07-28 16:14:48,863 [   7080]   INFO - til.net.ssl.CertificateManager - Default SSL context initialized 
2018-07-28 16:14:48,884 [   7101]   INFO - lij.diagnostic.DebugLogManager - Set DEBUG for the following categories: #com.illuminatedcloud.util.CommandLineUtil, #com.illuminatedcloud.intellij.sfdx.SfdxUtil, #com.illuminatedcloud.intellij.builder.ForceComSfdxDeployer, #com.illuminatedcloud.intellij.builder.ForceComSfdxRetriever, #com.illuminatedcloud.util.VariableLengthPollingInterval 
2018-07-28 16:14:48,909 [   7126]   INFO - rains.ide.BuiltInServerManager - built-in server started, port 63342 
2018-07-28 16:14:49,227 [   7444]   INFO - j.ide.ui.OptionsTopHitProvider - 475 ms spent to cache options in application 
2018-07-28 16:14:49,227 [   7444]   INFO - .openapi.application.Preloader - Finished preloading com.intellij.ide.ui.OptionsTopHitProvider$Activity@153d413d 
2018-07-28 16:14:49,331 [   7548]   INFO - m.intellij.ui.mac.touchbar.NST - touchbar-server isn't running, skip nst loading 
2018-07-28 16:14:49,393 [   7610]   INFO - gs.impl.UpdateCheckerComponent - channel: release 
2018-07-28 16:14:49,635 [   7852]   INFO - il.indexing.FileBasedIndexImpl - Index exts enumerated:63, number of extensions:46 
2018-07-28 16:14:49,644 [   7861]   INFO - il.indexing.FileBasedIndexImpl - Index scheduled:8 
2018-07-28 16:14:49,712 [   7929]   INFO - tellij.psi.stubs.StubIndexImpl - All stub exts enumerated:56, number of extensions:70 
2018-07-28 16:14:49,713 [   7930]   INFO - tellij.psi.stubs.StubIndexImpl - stub exts update scheduled:0 
2018-07-28 16:14:49,857 [   8074]   INFO - ellij.license.LicenseValidator - Initializing Illuminated Cloud 2.0.2.9 (20180723123912). 
2018-07-28 16:14:49,857 [   8074]   INFO - ellij.license.LicenseValidator - Validating certificate. 
2018-07-28 16:14:49,863 [   8080]   INFO - ellij.license.LicenseValidator - Successfully validated certificate. 
2018-07-28 16:14:49,863 [   8080]   INFO - llij.license.SignedJarVerifier - Verifying application contents. 
2018-07-28 16:14:50,008 [   8225]   INFO - plication.impl.ApplicationImpl - 82 application components initialized in 3596ms 
2018-07-28 16:14:50,101 [   8318]   INFO - .intellij.idea.IdeaApplication - App initialization took 9098 ms 
2018-07-28 16:14:51,804 [  10021]   INFO - com.intellij.ide.ui.UISettings - Loaded: fontSize=12, fontScale=1.0; restored: fontSize=12, fontScale=1.0 
2018-07-28 16:14:51,805 [  10022]   INFO - com.intellij.ide.ui.UISettings - Loaded: fontSize=14, fontScale=1.0; restored: fontSize=14, fontScale=1.0 
2018-07-28 16:14:51,986 [  10203]   INFO - com.intellij.ide.ui.UISettings - Loaded: fontSize=14, fontScale=1.0; restored: fontSize=14, fontScale=1.0 
2018-07-28 16:14:52,207 [  10424]   INFO - .openapi.application.Preloader - Finished preloading com.intellij.openapi.actionSystem.impl.ActionPreloader@5e550e13 
2018-07-28 16:14:52,502 [  10719]   INFO - j.ide.ui.OptionsTopHitProvider - 970 ms spent on EDT to cache options in application 
2018-07-28 16:14:52,537 [  10754]   INFO - llij.license.SignedJarVerifier - Successfully verified application contents. 
2018-07-28 16:14:52,537 [  10754]   INFO - ellij.license.LicenseValidator - Initializing the licensing system. 
2018-07-28 16:14:52,641 [  10858]   INFO - ellij.license.LicenseValidator - Validating libraries. 
2018-07-28 16:14:52,801 [  11018]   INFO - ellij.license.LicenseValidator - Successfully validated libraries. 
2018-07-28 16:14:53,322 [  11539]   INFO - .openapi.application.Preloader - Finished preloading com.intellij.ide.ui.search.SearchableOptionPreloader@711c18b2 
2018-07-28 16:14:53,561 [  11778]   INFO - pl$FileIndexDataInitialization - Initialization done:3916 
2018-07-28 16:14:53,745 [  11962]   INFO - .openapi.application.Preloader - Finished preloading com.intellij.codeInsight.completion.CompletionPreloader@9e31afb 
2018-07-28 16:14:53,750 [  11967]   INFO - exImpl$StubIndexInitialization - Initialization done:189 
2018-07-28 16:14:53,752 [  11969]   INFO - .openapi.application.Preloader - Finished preloading com.intellij.ide.actions.GotoClassPresentationUpdater@109b4448 
2018-07-28 16:14:59,333 [  17550]   INFO - pl.projectlevelman.NewMappings - VCS Root: [] - [<Project>] 
2018-07-28 16:14:59,336 [  17553]   INFO - pl.projectlevelman.NewMappings - VCS Root: [Git] - [/Users/doug.ayers/Documents/workspace/sfdx-force-di] 
2018-07-28 16:14:59,842 [  18059]   INFO - ellij.project.impl.ProjectImpl - 105 project components initialized in 768 ms 
2018-07-28 16:15:00,082 [  18299]   INFO - le.impl.ModuleManagerComponent - 1 module(s) loaded in 239 ms 
2018-07-28 16:15:00,284 [  18501]   INFO - j.ide.script.IdeStartupScripts - 0 startup script(s) found 
2018-07-28 16:15:00,690 [  18907]   INFO - om.intellij.util.ProfilingUtil - Profiling agent is not enabled. Add -agentlib:yjpagent to idea.vmoptions if necessary to profile IDEA. 
2018-07-28 16:15:00,855 [  19072]   INFO - ellij.project.impl.ProjectImpl - 15 project components initialized in 21 ms 
2018-07-28 16:15:01,058 [  19275]   INFO -              PerformancePlugin - Performance Plugin is in silent mode 
2018-07-28 16:15:01,738 [  19955]   INFO - rojectCodeStyleSettingsManager - Initialized from default code style settings. 
2018-07-28 16:15:02,031 [  20248]   INFO - .diagnostic.PerformanceWatcher - Pushing properties took 538ms; general responsiveness: ok; EDT responsiveness: ok 
2018-07-28 16:15:02,285 [  20502]  DEBUG - edcloud.intellij.sfdx.SfdxUtil - Using SFDX project file /Users/doug.ayers/Documents/workspace/sfdx-force-di/sfdx-project.json for module sfdx-force-di. 
2018-07-28 16:15:02,787 [  21004]   INFO - tartup.impl.StartupManagerImpl - OpenFilesActivity run in 1392ms under project opening modal progress 
2018-07-28 16:15:02,874 [  21091]   INFO - .diagnostic.PerformanceWatcher - Post-startup activities under progress took 1591ms; general responsiveness: ok; EDT responsiveness: 0/2 sluggish, 1/2 very slow 
2018-07-28 16:15:03,149 [  21366]   WARN - openapi.wm.impl.ToolWindowImpl - ToolWindow icons should be 13x13. Please fix ToolWindow (ID:  Anonymous Apex) or icon jar:file:/Users/doug.ayers/Library/Application%20Support/JetBrains/Toolbox/apps/WebStorm/ch-0/182.3684.70/WebStorm.app/Contents/lib/icons.jar!/nodes/ejbFinderMethod.png 
2018-07-28 16:15:03,162 [  21379]   WARN - openapi.wm.impl.ToolWindowImpl - ToolWindow icons should be 13x13. Please fix ToolWindow (ID:  SOQL Query) or icon jar:file:/Users/doug.ayers/Library/Application%20Support/JetBrains/Toolbox/apps/WebStorm/ch-0/182.3684.70/WebStorm.app/Contents/lib/icons.jar!/nodes/dataSchema.png 
2018-07-28 16:15:03,570 [  21787]   INFO - Json.PackageJsonUpdateNotifier - processPackageJsonFiles [] 
2018-07-28 16:15:03,926 [  22143]   INFO - tartup.impl.StartupManagerImpl - /Users/doug.ayers/Documents/workspace/sfdx-force-di/.idea case-sensitivity: expected=false actual=false 
2018-07-28 16:15:03,953 [  22170]   INFO -  #git4idea.commands.GitHandler - [.] git version 
2018-07-28 16:15:03,974 [  22191]   INFO -  #git4idea.commands.GitHandler - git version 2.17.0 
2018-07-28 16:15:03,979 [  22196]   INFO - ea.config.GitExecutableManager - Git version for /usr/local/bin/git : 2.17.0 
2018-07-28 16:15:04,131 [  22348]   INFO - pl.projectlevelman.NewMappings - VCS Root: [Git] - [/Users/doug.ayers/Documents/workspace/sfdx-force-di] 
2018-07-28 16:15:04,505 [  22722]   INFO - tor.impl.FileEditorManagerImpl - Project opening took 5462 ms 
2018-07-28 16:15:05,706 [  23923]   INFO - .diagnostic.PerformanceWatcher - Indexable file iteration took 3673ms; general responsiveness: ok; EDT responsiveness: 1/4 sluggish, 1/4 very slow 
2018-07-28 16:15:05,735 [  23952]   WARN - ess.util.ProgressIndicatorBase - This progress indicator is indeterminate, this may lead to visual inconsistency. Please call setIndeterminate(false) before you start progress. 
2018-07-28 16:15:05,844 [  24061]   INFO - j.ide.ui.OptionsTopHitProvider - 97 ms spent to cache options in project 
2018-07-28 16:15:05,860 [  24077]   INFO - tartup.impl.StartupManagerImpl - Some post-startup activities freeze UI for noticeable time. Please consider making them DumbAware to do them in background under modal progress, or just making them faster to speed up project opening. 
2018-07-28 16:15:05,861 [  24078]   INFO - tartup.impl.StartupManagerImpl - Activity run in 113ms on UI thread 
2018-07-28 16:15:05,876 [  24093]   INFO - cloudConfig.CloudConfigManager - === StatusBar ignored === 
2018-07-28 16:15:05,953 [  24170]   INFO - ellij.license.LicenseValidator - Server license validation result was Genuine. 
2018-07-28 16:15:05,956 [  24173]   INFO - ellij.license.LicenseValidator - Illuminated Cloud features are enabled. 
2018-07-28 16:15:05,965 [  24182]   INFO - ontentsSynchronizationListener - Initializing module contents synchronization listener. 
2018-07-28 16:15:05,966 [  24183]   INFO - d.intellij.sfdx.InitializeSfdx - Listing Salesforce DX connections. 
2018-07-28 16:15:05,967 [  24184]   INFO - luminatedCloudConnectionConfig - Retrieving org list from sfdx CLI. 
2018-07-28 16:15:05,968 [  24185]   INFO - luminatedCloudConnectionConfig - Retrieving org list information from sfdx CLI. 
2018-07-28 16:15:05,969 [  24186]  DEBUG - atedcloud.util.CommandLineUtil - Running command line: /usr/local/bin/sfdx force:org:list --json 
2018-07-28 16:15:05,971 [  24188]   INFO - ng.IlluminatedCloudFileHandler - Initializing Illuminated Cloud file handler. 
2018-07-28 16:15:05,980 [  24197]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:org:list --json: Using polling interval 1000 ms for polling iteration 1. 
2018-07-28 16:15:06,509 [  24726]   INFO - j.ide.plugins.RepositoryHelper - using cached plugin list (updated at 7/28/18, 3:47 PM) 
2018-07-28 16:15:06,868 [  25085]   INFO - j.ide.ui.OptionsTopHitProvider - 196 ms spent on EDT to cache options in project 
2018-07-28 16:15:06,992 [  25209]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:org:list --json: Using polling interval 1000 ms for polling iteration 2. 
2018-07-28 16:15:07,993 [  26210]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:org:list --json: Using polling interval 1000 ms for polling iteration 3. 
2018-07-28 16:15:08,994 [  27211]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:org:list --json: Using polling interval 1000 ms for polling iteration 4. 
2018-07-28 16:15:09,999 [  28216]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:org:list --json: Using polling interval 1000 ms for polling iteration 5. 
2018-07-28 16:15:11,001 [  29218]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:org:list --json: Using polling interval 1000 ms for polling iteration 6. 
2018-07-28 16:15:12,004 [  30221]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:org:list --json: Using polling interval 1000 ms for polling iteration 7. 
2018-07-28 16:15:13,005 [  31222]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:org:list --json: Using polling interval 1000 ms for polling iteration 8. 
2018-07-28 16:15:14,006 [  32223]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:org:list --json: Using polling interval 1000 ms for polling iteration 9. 
2018-07-28 16:15:15,007 [  33224]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:org:list --json: Using polling interval 1000 ms for polling iteration 10. 
2018-07-28 16:15:16,009 [  34226]  DEBUG - atedcloud.util.CommandLineUtil - Returning command-line response: CommandLineResponse{exitCode=0, output='REDACTED', error=''} 
2018-07-28 16:15:16,031 [  34248]   INFO - d.intellij.sfdx.InitializeSfdx - Listed 7 Salesforce DX connections in 10 s 64 ms. 
2018-07-28 16:15:16,050 [  34267]  DEBUG - edcloud.intellij.sfdx.SfdxUtil - Loaded SFDX project from file /Users/doug.ayers/Documents/workspace/sfdx-force-di/sfdx-project.json. 
2018-07-28 16:15:16,046 [  34263]  DEBUG - edcloud.intellij.sfdx.SfdxUtil - Loaded SFDX project from file /Users/doug.ayers/Documents/workspace/sfdx-force-di/sfdx-project.json. 
2018-07-28 16:15:16,051 [  34268]  DEBUG - edcloud.intellij.sfdx.SfdxUtil - Loaded SFDX project from file /Users/doug.ayers/Documents/workspace/sfdx-force-di/sfdx-project.json. 
2018-07-28 16:15:16,065 [  34282]  DEBUG - edcloud.intellij.sfdx.SfdxUtil - Loaded SFDX project from file /Users/doug.ayers/Documents/workspace/sfdx-force-di/sfdx-project.json. 
2018-07-28 16:15:23,039 [  41256]  DEBUG - j.builder.ForceComSfdxDeployer - Pushing 'sfdx-force-di' to 'force-di' 
2018-07-28 16:15:23,052 [  41269]   WARN - ess.util.ProgressIndicatorBase - This progress indicator is indeterminate, this may lead to visual inconsistency. Please call setIndeterminate(false) before you start progress. 
2018-07-28 16:15:23,053 [  41270]  DEBUG - j.builder.ForceComSfdxDeployer - Bringing static resource bundles up-to-date. 
2018-07-28 16:15:23,054 [  41271]   INFO - j.builder.ForceComSfdxDeployer - Using the sfdx CLI to push changes for project 'sfdx-force-di' to scratch org 'force-di' with force=false, background=true. 
2018-07-28 16:15:23,055 [  41272]  DEBUG - atedcloud.util.CommandLineUtil - Running command line: /usr/local/bin/sfdx force:source:push -u [e-mail] --json 
2018-07-28 16:15:23,064 [  41281]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:source:push -u [e-mail] --json: Using polling interval 1000 ms for polling iteration 1. 
2018-07-28 16:15:24,068 [  42285]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:source:push -u [e-mail] --json: Using polling interval 1000 ms for polling iteration 2. 
2018-07-28 16:15:25,071 [  43288]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:source:push -u [e-mail] --json: Using polling interval 1000 ms for polling iteration 3. 
2018-07-28 16:15:26,074 [  44291]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:source:push -u [e-mail] --json: Using polling interval 1000 ms for polling iteration 4. 
2018-07-28 16:15:27,079 [  45296]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:source:push -u [e-mail] --json: Using polling interval 1000 ms for polling iteration 5. 
2018-07-28 16:15:28,085 [  46302]  DEBUG - .VariableLengthPollingInterval - /usr/local/bin/sfdx force:source:push -u [e-mail] --json: Using polling interval 1000 ms for polling iteration 6. 
2018-07-28 16:15:29,087 [  47304]  DEBUG - atedcloud.util.CommandLineUtil - Returning command-line response: CommandLineResponse{exitCode=1, output='', error='{"message":"Push failed.","status":1,"stack":"DeployFailed: Push failed.\n    at ALMError (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/salesforce-alm/dist/lib/almError.js:43:19)\n    at MetadataRegistry.initializeMetadataTypeInfos.then.catch.e (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/salesforce-alm/dist/lib/mdapiPushCommand.js:49:31)\n    at tryCatcher (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/util.js:16:23)\n    at Promise._settlePromiseFromHandler (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/promise.js:510:31)\n    at Promise._settlePromise (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/promise.js:567:18)\n    at Promise._settlePromise0 (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/promise.js:612:10)\n    at Promise._settlePromises (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/promise.js:687:18)\n    at Async._drainQueue (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/async.js:138:16)\n    at Async._drainQueues (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/async.js:148:10)\n    at Immediate.Async.drainQueues (/Users/doug.ayers/.local/share/sfdx/plugins/node_modules/bluebird/js/release/async.js:17:14)\n    at runCallback (timers.js:789:20)\n    at tryOnImmediate (timers.js:751:5)\n    at processImmediate [as _immediateCallback] (timers.js:722:5)","name":"DeployFailed","result":[{"columnNumber":"41","lineNumber":"229","error":"Variable does not exist: value2 (229:41)","fullName":"BindingParam","type":"ApexClass","filePath":"force-di/main/default/classes/BindingParam.cls"}],"warnings":[]}'} 
2018-07-28 16:15:29,093 [  47310]   INFO - j.builder.ForceComSfdxDeployer - Push completed in 6 s 39 ms. 
2018-07-28 16:15:29,101 [  47318]  DEBUG - j.builder.ForceComSfdxDeployer - Received push response:
{
  "status": 1,
  "failureResponse": {
    "status": 1,
    "message": "Push failed.",
    "name": "DeployFailed",
    "result": [
      {
        "columnNumber": "41",
        "error": "Variable does not exist: value2 (229:41)",
        "lineNumber": "229",
        "filePath": "force-di/main/default/classes/BindingParam.cls",
        "fullName": "BindingParam",
        "type": "ApexClass"
      }
    ]
  }
} 
2018-07-28 16:15:29,101 [  47318]  DEBUG - j.builder.ForceComSfdxDeployer - Checking for conflicts. 
2018-07-28 16:15:29,102 [  47319]  DEBUG - j.builder.ForceComSfdxDeployer - Push appears to have failed. Adding details. 
2018-07-28 16:15:29,102 [  47319]  DEBUG - j.builder.ForceComSfdxDeployer - Processing result:
{
  "columnNumber": "41",
  "error": "Variable does not exist: value2 (229:41)",
  "lineNumber": "229",
  "filePath": "force-di/main/default/classes/BindingParam.cls",
  "fullName": "BindingParam",
  "type": "ApexClass"
} 
2018-07-28 16:15:29,102 [  47319]  DEBUG - j.builder.ForceComSfdxDeployer - Trying to find a file for path: force-di/main/default/classes/BindingParam.cls 
2018-07-28 16:15:29,103 [  47320]  DEBUG - j.builder.ForceComSfdxDeployer -   Looking for files named: BindingParam.cls 
2018-07-28 16:15:29,103 [  47320]  DEBUG - j.builder.ForceComSfdxDeployer -   Found 1 matching files. 
2018-07-28 16:15:29,104 [  47321]  DEBUG - j.builder.ForceComSfdxDeployer -   Evaluating as match: /Users/doug.ayers/Documents/workspace/sfdx-force-di/force-di/main/default/classes/BindingParam.cls 
2018-07-28 16:15:29,104 [  47321]  DEBUG - j.builder.ForceComSfdxDeployer -   Looking for file under deployable source roots: 
2018-07-28 16:15:29,104 [  47321]  DEBUG - j.builder.ForceComSfdxDeployer -   No matching source file found. 
2018-07-28 16:15:29,104 [  47321]   WARN - j.builder.ForceComSfdxDeployer - No source file found for 'force-di/main/default/classes/BindingParam.cls'. 
2018-07-28 16:15:29,104 [  47321]  DEBUG - j.builder.ForceComSfdxDeployer -   Adding push failure as 'ApexClass/BindingParam: ERROR at line 229, column 41 - Variable does not exist: value2 (229:41)'. 
2018-07-28 16:15:29,105 [  47322]   INFO - .IlluminatedCloudExceptionUtil - Pushed 0/1 components to force-di in 6 s 39 ms with status 1. 
2018-07-28 16:15:29,107 [  47324]   INFO - .IlluminatedCloudExceptionUtil - Push details:
{
  "successes": [],
  "failures": [
    "ApexClass/BindingParam: ERROR at line 229, column 41 - Variable does not exist: value2 (229:41)"
  ],
  "numSuccesses": 0,
  "numFailures": 1
} 

[Scott Wells]

Let me check WebStorm real quick, but note that the Illuminated Cloud Problems view won't pop up until it's needed. It's not available in that list when there's nothing to show.

However, I can generally see what's going on in the log you provided:

2018-07-28 16:15:29,102 [  47319]  DEBUG - j.builder.ForceComSfdxDeployer - Trying to find a file for path: force-di/main/default/classes/BindingParam.cls 
2018-07-28 16:15:29,103 [  47320]  DEBUG - j.builder.ForceComSfdxDeployer -   Looking for files named: BindingParam.cls 
2018-07-28 16:15:29,103 [  47320]  DEBUG - j.builder.ForceComSfdxDeployer -   Found 1 matching files. 
2018-07-28 16:15:29,104 [  47321]  DEBUG - j.builder.ForceComSfdxDeployer -   Evaluating as match: /Users/doug.ayers/Documents/workspace/sfdx-force-di/force-di/main/default/classes/BindingParam.cls 
2018-07-28 16:15:29,104 [  47321]  DEBUG - j.builder.ForceComSfdxDeployer -   Looking for file under deployable source roots: 
2018-07-28 16:15:29,104 [  47321]  DEBUG - j.builder.ForceComSfdxDeployer -   No matching source file found. 
2018-07-28 16:15:29,104 [  47321]   WARN - j.builder.ForceComSfdxDeployer - No source file found for 'force-di/main/default/classes/BindingParam.cls'. 

It looks like the class BindingParam isn't under a source root for the project. Can you open Illuminated Cloud>Configure Module, switch to the Project Structure tab, and attach a screenshot? I want to see how your content roots and source roots are configured. I bet it's just a configuration issue.

[Scott Wells]

FYI, I just verified that WebStorm produces the exact same correct behavior as IntelliJ IDEA, so my guess is definitely that it's a project source root config issue and then you'll be good to go.

[Doug Ayers]

Thanks for the quick response!

Here's my project config, thanks

[Doug Ayers]

You're absolutely right, Scott. My module's project structure wasn't specifying the correct source folders.

I updated it to mark the "force-di/main/default" folder as a source folder and then on save fail the "Illuminated Cloud" toolbar appeared and the red squiggles in my code editor.

Thanks!

[Scott Wells]

Thanks, Doug. And where is your sfdx-project.json file? Is it a peer to all of the source root directories? I ask because the way that IC evaluates the project structure is by finding that file, pulling the configured package directories from it, and assuming those are relative to the directory in which the sfdx-project.json file is found. I'm wondering if there's some mismatch there ("mismatch" meaning relative to what IC expect even if it's valid for SFDX).

[Doug Ayers]

sfdx-project.json is in the root folder, sibling to the other package directories.

{
  "packageDirectories": [
    {
      "path": "force-di",
      "default": true
    },
    {
      "path": "force-di-trigger-demo",
      "default": false
    },
    {
      "path": "force-app-1",
      "default": false
    },
    {
      "path": "force-app-2",
      "default": false
    },
    {
      "path": "force-app-3",
      "default": false
    }
  ],
  "namespace": "",
  "sfdcLoginUrl": "https://login.salesforce.com",
  "sourceApiVersion": "43.0"
}

[Scott Wells]

Okay. I'll probably need to add some additional diagnostic logging to get to the bottom of this because everything you've shown me looks correct. I'll add that for the next build (likely Monday morning) and will tell you any changes required to debug logging configuration to get the additional info.

[Doug Ayers]

Sounds good, thanks!

[Evgenii Azimzhanov]

Seems helped for me as well. Thank you!