ApexRefreshProject and ApexRetrieve fail about vim-force.com HOT 12 CLOSED

Hello @anandghegde

Thank you for reporting this.

Did you check your local files to see if the operation actually failed, i.e. expected files have not been refreshed/retrieved?

Also do you see

ERROR: Operation failed

if you call ApexRefreshProject second or third time (without closing/re-opening vim) ?

At first glance it looks like initial tooling-foce.com.jar server start is not handled nicely and reports failure prematurely while actual operation proceeds once OS had a chance to load and execute .jar.

from vim-force.com.

@neowit I was able to ApexRetrieve just the classes, triggers and pages separately (3 different ApexRetrieves), but when do ApexRetrieve on all three of them together, it doesnt fetch the files (I waited for 3 min).

Also, I tried ApexRefreshProject without closing vim thrice and it still doesnt fetch the files.

On a different sandbox, I tried ApexRetrive for just apex classes and it didnt complete succesfully.

from vim-force.com.

hello @anandghegde

Please enable "debug" log level via adding following line to your .vimrc

let g:apex_tooling_force_dot_com_java_params = "-Dorg.apache.commons.logging.simplelog.defaultlog=debug"

make sure you do not have another let g:apex_tooling_force_dot_com_java_params = ... statement later in your .vimrc.
Then open new vim instance with an apex class, run :ApexRefreshProject and copy here the output of :ApexMessages

Thank you.

from vim-force.com.

In addition to the above, can you please try tooling-force.com-0.3.6.4-68.jar

When you open vim check that the version is correct using ApexToolingVersion it should report version: 0.3.6.4-#68. If that's the case then run : ApexRefreshProject.

from vim-force.com.

@neowit Here is the ouput for ApexRefreshProject with the debugs -

`

--action=refresh --tempFolderPath='/Users/ahegde/.vim_runtime/sources_non_forked/force_config_folder/temp_folder' --config='/Users/ahegde/.vim_runtime/sources_non_forked/force_config_folder/properties_folder/sfdcjune.properties' --projectPath='/Users/ahegde/releases/sfdcjune' --responseFilePath='/Users/ahegde/releases/sfdcjune/.vim-force.com/response_refresh' --pollWaitMillis=1000 --maxPollRequests=1000
Trying to start server using command: java -Dorg.apache.commons.logging.simplelog.defaultlog=debug -Dfile.encoding=UTF-8 -jar /Users/ahegde/.vim_runtime/sources_non_forked/force_config_folder/tooling-force.jar --action=serverStart --port=8888 --timeoutSec=60

--action=refresh --tempFolderPath='/Users/ahegde/.vim_runtime/sources_non_forked/force_config_folder/temp_folder' --config='/Users/ahegde/.vim_runtime/sources_non_forked/force_config_folder/properties_folder/sfdcjune.properties' --projectPath='/Users/ahegde/releases/sfdcjune' --responseFilePath='/Users/ahegde/releases/sfdcjune/.vim-force.com/response_refresh' --pollWaitMillis=1000 --maxPollRequests=1000
[DEBUG] ResponseWriter - RESULT=FAILURE
[DEBUG] ResponseWriter - MESSAGE: {"id":1,"text":"Use --skipModifiedFilesCheck=true command line option to force Refresh","type":"DEBUG"}
[DEBUG] ResponseWriter - MESSAGE: {"id":2,"text":"Modified file(s) detected.","type":"WARN","code":"HAS_MODIFIED_FILES"}
[DEBUG] ResponseWriter - MESSAGE DETAIL: {"messageId":2,"filePath":"/Users/ahegde/releases/sfdcjune/src/triggers/OpportunityLineItem_au_ad.trigger","text":"src/triggers/OpportunityLineItem_au_ad.trigger"}
[DEBUG] ResponseWriter - MESSAGE DETAIL: {"messageId":2,"filePath":"/Users/ahegde/releases/sfdcjune/src/classes/CustomButtonController.cls","text":"src/classes/CustomButtonController.cls"}
[DEBUG] ResponseWriter - MESSAGE DETAIL: {"messageId":2,"filePath":"/Users/ahegde/releases/sfdcjune/src/triggers/OpportunityLineItemTrigger.trigger","text":"src/triggers/OpportunityLineItemTrigger.trigger"}
[DEBUG] ResponseWriter - MESSAGE DETAIL: {"messageId":2,"filePath":"/Users/ahegde/releases/sfdcjune/src/classes/OpportunityCreateNew.cls","text":"src/classes/OpportunityCreateNew.cls"}
[DEBUG] ResponseWriter - MESSAGE DETAIL: {"messageId":2,"filePath":"/Users/ahegde/releases/sfdcjune/src/package.xml","text":"src/package.xml"}
[DEBUG] ResponseWriter - MESSAGE DETAIL: {"messageId":2,"filePath":"/Users/ahegde/releases/sfdcjune/src/classes/OpportunityGetBaseline.cls","text":"src/classes/OpportunityGetBaseline.cls"}
[DEBUG] ResponseWriter - MESSAGE DETAIL: {"messageId":2,"filePath":"/Users/ahegde/releases/sfdcjune/src/classes/OpportunityTriggerClass.cls","text":"src/classes/OpportunityTriggerClass.cls"}
[DEBUG] ResponseWriter - MESSAGE DETAIL: {"messageId":2,"filePath":"/Users/ahegde/releases/sfdcjune/src/classes/RenewalOpportunityCreationClass.cls","text":"src/classes/RenewalOpportunityCreationClass.cls"}
[DEBUG] ResponseWriter - HAS_MODIFIED_FILES=true
[DEBUG] ResponseWriter - #SECTION START: MODIFIED FILE LIST
[DEBUG] ResponseWriter - MODIFIED_FILE=src/triggers/OpportunityLineItem_au_ad.trigger
[DEBUG] ResponseWriter - MODIFIED_FILE=src/classes/CustomButtonController.cls
[DEBUG] ResponseWriter - MODIFIED_FILE=src/triggers/OpportunityLineItemTrigger.trigger
[DEBUG] ResponseWriter - MODIFIED_FILE=src/classes/OpportunityCreateNew.cls
[DEBUG] ResponseWriter - MODIFIED_FILE=src/package.xml
[DEBUG] ResponseWriter - MODIFIED_FILE=src/classes/OpportunityGetBaseline.cls
[DEBUG] ResponseWriter - MODIFIED_FILE=src/classes/OpportunityTriggerClass.cls
[DEBUG] ResponseWriter - MODIFIED_FILE=src/classes/RenewalOpportunityCreationClass.cls
[DEBUG] ResponseWriter - #SECTION END: MODIFIED FILE LIST
[INFO] Executor - # Time taken: 2.124s
ERROR: Operation failed

--action=refresh --tempFolderPath='/Users/ahegde/.vim_runtime/sources_non_forked/force_config_folder/temp_folder' --config='/Users/ahegde/.vim_runtime/sources_non_forked/force_config_folder/properties_folder/sfdcjune.properties' --projectPath='/Users/ahegde/releases/sfdcjune' --skipModifiedFilesCheck=true --responseFilePath='/Users/ahegde/releases/sfdcjune/.vim-force.com/response_refresh' --pollWaitMillis=1000 --maxPollRequests=1000
[DEBUG] RefreshMetadata - Manifest file: /Users/ahegde/releases/sfdcjune/src/package.xml
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #2
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #4
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #6
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #8
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #10
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #12
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #14
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #16
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #18
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #20
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #22
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #24
[DEBUG] Session - Status is: InProgress
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #26
[DEBUG] Session - Status is: InProgress

press 'q' to close this buffer

`

from vim-force.com.

hello @anandghegde

Thank you for the log.

Does it actually stop after

[INFO] Session - waiting result, poll #26
[DEBUG] Session - Status is: InProgress
press 'q' to close this buffer

?

FYI - "press 'q' to close this buffer" message is displayed when ":ApexMessages" window is opened first time in current vim session. It does not necessarily mean that nothing else is coming
after that message and for the purposes of debug log it can be ignored.

So in your example I would expect the log to continue... something like:

[INFO] Session - waiting result, poll #29
[DEBUG] Session - Status is: InProgress
[INFO] Session - waiting result, poll #32
[DEBUG] Session - Status is: InProgress

and eventually

 [INFO] Executor - # Time taken: nn.nnn
INFO: No errors found

or

ERROR: Operation failed

but it definitely is not expected to stop at

[DEBUG] Session - Status is: InProgress

Questions:
Q1. please can you confirm that the log you included is indeed a complete log?

• If there is nothing else in your log then something must be killing the channel between vim and tooling-force.com.jar server. In which case you may need to explore an alternative vim build.

Q2. How do you get into :ApexMessages window ? Do you open it manually or it gets opened automatically?

Q3. Which OS and vim flavour you use?

FYI - first "Operation failed" shown in

[DEBUG] ResponseWriter - #SECTION END: MODIFIED FILE LIST
[INFO] Executor - # Time taken: 2.124s
ERROR: Operation failed

may be confusing, but it only signals vim plugin that it needs to ask if user is happy to overwrite existing files and does not signal a real failure. I need to look into this at some point to make it less confusing.

from vim-force.com.

It does stop at

Session - waiting result, poll ..

I tried with tooling-force.com-0.3.6.4-68.jar and got the same behaviour.

Q1 - Yes, that was the complete log, I waited for around 3 min. No logs after that.

Q2 - It opens automatically.

Q3 - Mac OS El Capitan 10.11.6 and VIM - Vi IMproved 8.0 (2016 Sep 12, compiled Sep 30 2016 05:49:50)

from vim-force.com.

Hello @anandghegde

Thank you for the update.

Q3.1. - where did you get this particular vim build?
Did you build it yourselves, from homebrew or somewhere else?

Q4.1. Which java version do you use?

Q4.2. can you confirm if you have only 1 java version installed?

from vim-force.com.

A3.1 - I used homebrew to install vim.

A4.1 -
java version "1.8.0_101"
Java(TM) SE Runtime Environment (build 1.8.0_101-b13)
Java HotSpot(TM) 64-Bit Server VM (build 25.101-b13, mixed mode)

A4.2 - I'm not sure about this. Is there a way to list all the versions on my system?

from vim-force.com.

Hello @anandghegde

I think the issue is your --timeoutSec=60 parameter.
You set it too short and server shuts itself down after 60 seconds elapsed since last command received, which in your case happens in the middle of retrieve/refresh.

from doc.txt

Once loaded tooling-force.com.jar will keep itself loaded until 'g:apex_server_timeoutSec' timeout since last touch is reached.
For example if g:apex_server_timeoutSec is set to 1800 seconds then tooling-force.com.jar
will unload itself from memory when 30 minutes elapse since last time vim-force.com called it.

When working with vim plugin you really do not want timeoutSec to be this short because that would mean the plugin has to start the server part pretty much every time when you run :Apex[something] command, which is a waste of time.

One scenario when you may not want tooling-force.com.jar server to stick around is when it is used standalone (without vim plugin), e.g. in Continuous Integration or any other automated deployment. But in that case server mode (as in case of vim plugin) should not be used at all.

from vim-force.com.

Increasing the timeout parameter seems to have fixed this issue.

from vim-force.com.

closing, unless you have further comments on this.

from vim-force.com.