Sarcasm / irony-mode

A C/C++ minor mode for Emacs powered by libclang
GNU General Public License v3.0
906 stars 99 forks source link

Any way to speed up Boost headers completion? #131

Open fspeech opened 9 years ago

fspeech commented 9 years ago

Once I included boost completion seems to slow down to a crawl. I am actually amazed that results eventually show up if you wait long enough. But this is not going to be very useful at the current speed. Is there anyway to speed up the completion, say with some pre-compiled headers? I saw this talked about but how is it actually done?

Sarcasm commented 9 years ago

Sadly on Windows I don't know where these precompiled headers end up, on Linux you can check out your /tmp/ directory for file with the following prefix preamble.pch-.

Also, precompiled headers may not work with older version of libclang, do you know which version you have?

How long do you wait? 3 seconds, 30 seconds?

For me the first time takes a few seconds maybe but once the preamble has been generated it is quite responsive less than 1 second I would say.

#include <cstdlib>
#include <iostream>

#include <boost/asio.hpp>
#include <boost/bind.hpp>
#include <boost/array.hpp>
#include <boost/signal.hpp>
#include <boost/function.hpp>
#include <boost/shared_ptr.hpp>
#include <boost/noncopyable.hpp>
#include <boost/aligned_storage.hpp>
#include <boost/enable_shared_from_this.hpp>

int main()
{
  boost::|
}
fspeech commented 9 years ago

It is definitely closer to 30 seconds than 3 seconds. I have the latest clang:

$ pacman -Qs clang
local/mingw-w64-i686-clang 3.5.0-5
    C language family frontend for LLVM
local/mingw-w64-i686-clang-analyzer 3.5.0-5
    A source code analysis framework
local/mingw-w64-i686-clang-tools-extra 3.5.0-5
    Extra tools built using Clang's tooling APIs

I noticed if company mode is not sending new requests it can be fast after the initial wait. But each new request seems to take forever and some does not seem to come back at all -- it is hard to tell since the wait is so long. In my tmp directory I can see a bunch of .pch files. preamble-935dd8.pch was created today.

fspeech commented 9 years ago

I also played with irony-server.exe -i. I first sent the complete FILE ROW COL command, then I sent the compiler options. Some times I can back a bunch of completions, but often I get nothing back, just:

(
)

;;EOT

This takes more like 3 seconds. But somehow in emacs I seem to get more completion candidates eventually. Maybe I don't understand the -i mode operations.

Sarcasm commented 9 years ago

So to do some manual debugging.

First let's assume that you have a file that needs some flags to be set, in this case the file uses C++11 (which may be enabled by default on Windows so maybe you don't need it for real...)

cat <<EOF > /tmp/c++11.cpp
#include <memory>

int foo(std::unique_ptr<int> &pint) {
  pint.
}
EOF

Assuming you are in the build directory of irony, you can first check that the completion results are good with the following command:

./bin/irony-server -d complete /tmp/c++11.cpp 4 8 <<< '-std=c++11'
execute: Command{action=Command::Complete, file='/tmp/c++11.cpp', line=4, column=8, flags=['-std=c++11'], unsavedFiles.count=0, opt=off}
(
debug: complete: 0 diagnostic(s)
("get" 35 "pointer" "" "get() const" 3 ("()"))
("get_deleter" 34 "deleter_type &" "" "get_deleter()" 11 ("()"))
("get_deleter" 35 "const deleter_type &" "" "get_deleter() const" 11 ("()"))
("operator _Bool" 35 "" "" "operator _Bool() const" 14 ("()"))
("operator*" 35 "typename std::add_lvalue_reference<element_type>::type" "" "operator*() const" 9 ("()"))
("operator->" 35 "pointer" "" "operator->() const" 10 ("()"))
("operator=" 34 "std::unique_ptr<int, std::default_delete<int> > &" "" "operator=(std::unique_ptr<int, std::default_delete<int> > &&__u)" 9 ("(std::unique_ptr<int, std::default_delete<int> > &&__u)" 1 54))
("operator=" 35 "std::unique_ptr<int, std::default_delete<int> > &" "" "operator=(unique_ptr<_Up, _Ep> &&__u)" 9 ("(unique_ptr<_Up, _Ep> &&__u)" 1 27))
("operator=" 34 "std::unique_ptr<int, std::default_delete<int> > &" "" "operator=(nullptr_t)" 9 ("(nullptr_t)" 1 10))
("operator=" 34 "std::unique_ptr<int, std::default_delete<int> > &" "" "operator=(const std::unique_ptr<int, std::default_delete<int> > &)" 9 ("(const std::unique_ptr<int, std::default_delete<int> > &)" 1 56))
("release" 34 "pointer" "" "release()" 7 ("()"))
("reset" 34 "void" "" "reset()" 5 ("()"))
("swap" 34 "void" "" "swap(std::unique_ptr<int, std::default_delete<int> > &__u)" 4 ("(std::unique_ptr<int, std::default_delete<int> > &__u)" 1 53))
("unique_ptr" 35 "void" "" "unique_ptr(unique_ptr<_Up, _Ep> &&__u)" 10 ("(unique_ptr<_Up, _Ep> &&__u)" 1 27))
("unique_ptr" 35 "void" "" "unique_ptr(auto_ptr<_Up> &&__u)" 10 ("(auto_ptr<_Up> &&__u)" 1 20))
("unique_ptr" 75 "" "" "unique_ptr::" 10 ("::"))
("~unique_ptr" 34 "void" "" "~unique_ptr()" 11 ("()"))
)

;;EOT

And if you want to trigger a multiple commands, you can do the following:

./bin/irony-server -i
complete /tmp/c++11.cpp 4 8
-std=c++11
<...>
;;EOT
complete /tmp/c++11.cpp 4 8
-std=c++11
<...>
;;EOT
<command>
<flags>
<irony-server answer>
Sarcasm commented 9 years ago

You can try to add a #warning Compile preamble disabled in the following code https://github.com/Sarcasm/irony-mode/blob/cd6f4540e5f6b4b1cb8f159c3c1a9a4f1273fab0/server/src/TUManager.cpp#L188-L197 to see if you have the compile preamble disabled somehow but I doubt it since it seems that you have the preamble files.

fspeech commented 9 years ago

We are onto something here. Running in command line I get the following:

$ ~/w/.emacs.d/irony/bin/irony-server.exe -d complete /tmp/c++11.cpp 4 8 <<< '-x c++ -std=c++11'
execute: Command{action=Command::Complete, file='C:/alt/msys32/tmp/c++11.cpp', line=4, column=8, flags=['-x', 'c++', '-std=c++11'], unsavedFiles.count=0, opt=off}
debug: complete: 4 diagnostic(s)
C:/alt/msys32/tmp/c++11.cpp:3:9: error: use of undeclared identifier 'std'
C:/alt/msys32/tmp/c++11.cpp:3:28: error: expected '(' for function-style cast or type construction
C:/alt/msys32/tmp/c++11.cpp:3:31: error: use of undeclared identifier 'pint'
C:/alt/msys32/tmp/c++11.cpp:3:36: error: expected ';' after top level declarator

plus a bunch of completion options that are not relevant to what is asked.

If I do clang++ -E I can get all the std headers. No sure what is going on here.

Sarcasm commented 9 years ago

Do you know if irony was able to find the clang built-in headers? When running CMake you should see the following message:

$ cmake ../server
<...>
-- Detecting libclang builtin headers directory
-- Detecting libclang builtin headers directory -- success

Or by inspecting the cache with:

fspeech commented 9 years ago

Yes the build did find the headers:

CHECK_LIBCLANG_BUILTIN_HEADERS_STDDEF_DIR:PATH=C:/alt/msys32/mingw32/lib/clang/3.5.0/include
fspeech commented 9 years ago
grep LIBCLANG_BUILTIN CMakeCache.txt
CHECK_LIBCLANG_BUILTIN_HEADERS_STDDEF_DIR:PATH=C:/alt/msys32/mingw32/lib/clang/3.5.0/include
CHECK_LIBCLANG_BUILTIN_HEADERS_COMPILE_RESULT:INTERNAL=TRUE
CHECK_LIBCLANG_BUILTIN_HEADERS_DIR_NUM_DIAGNOSTICS:INTERNAL=0
LIBCLANG_BUILTIN_HEADERS_DIR:INTERNAL=C:/alt/msys32/mingw32/lib/clang/3.5.0/include
fspeech commented 9 years ago

If I run clang++ -std=c++11 -c on the file the output was sensible:

$ clang++ -std=c++11 -c /tmp/c++11.cpp
C:/alt/msys32/tmp/c++11.cpp:5:1: error: expected unqualified-id
}
^
1 error generated.

So the system clang++ can handle it okay.

Sarcasm commented 9 years ago

Hum, Did the completion ever worked with std, for example without C++11?

I don't have a lot of ideas for now, I think one of the main difference between clang and libclang is that libclang can't find the built-in headers but in this case that doesn't seem to be the case.

It's weird to have a warning complaining about 'std::', without an error first with the #include <memory>.

fspeech commented 9 years ago

Well it probably did not find <memory> in the first place. Otherwise it would have got the namespace std {...} declaration. So I assume that is the same error. Not finding include files does not seem to stop libclang, which makes sense.

Sarcasm commented 9 years ago

Hum:

$ ~/w/.emacs.d/irony/bin/irony-server.exe -d complete /tmp/c++11.cpp 4 8 <<< '-x c++ -std=c++11'
execute: Command{action=Command::Complete, file='C:/alt/msys32/tmp/c++11.cpp', line=4, column=8, flags=['-x', 'c++', '-std=c++11'], unsavedFiles.count=0, opt=off}

Is there some kind of weird path conversion happening? /tmp/c++11.cpp => C:/alt/msys32/tmp/c++11.cpp

I guess it the way mingw works.

If I do clang++ -E I can get all the std headers. No sure what is going on here.

Have you tried to add the paths manually to the irony-server command line?

fspeech commented 9 years ago

Yes my mingw shell understands unix paths. I fed all the canonical MS paths (starting with C:) to irony-server. I will try including the std headers path by hand next.

fspeech commented 9 years ago

Yes manually including paths worked:

$ ~/w/.emacs.d/irony/bin/irony-server.exe -d complete /tmp/c++11.cpp 4 8 <<< '-x c++ -std=c++11 -IC:/alt/msys32/mingw32/include/c++/4.9.1/i686-w64-mingw32/ -IC:/alt/msys32/mingw32/include/c++/4.9.1/ -IC:/alt/msys32/mingw32/lib/clang/3.5.0/include/'
(
("get" 35 "pointer" "" "get() const" 3 ("()"))
("get_deleter" 34 "deleter_type &" "" "get_deleter()" 11 ("()"))
("get_deleter" 35 "const deleter_type &" "" "get_deleter() const" 11 ("()"))
("operator bool" 35 "" "" "operator bool() const" 13 ("()"))
("operator*" 35 "typename add_lvalue_reference<element_type>::type" "" "operator*() const" 9 ("()"))
("operator->" 35 "pointer" "" "operator->() const" 10 ("()"))
("operator=" 34 "std::unique_ptr<int, std::default_delete<int> > &" "" "operator=(std::unique_ptr<int, std::default_delete<int> > &&__u)" 9 ("(std::unique_ptr<int, std::default_delete<int> > &&__u)" 1 54))
("operator=" 35 "typename enable_if<__and_<is_convertible<typename unique_ptr<_Up, _Ep>::pointer, pointer>, __not_<is_array<_Up> > >::value, unique_ptr<int, default_delete<int> > &>::type" "" "operator=(unique_ptr<_Up, _Ep> &&__u)" 9 ("(unique_ptr<_Up, _Ep> &&__u)" 1 27))
("operator=" 34 "std::unique_ptr<int, std::default_delete<int> > &" "" "operator=(nullptr_t)" 9 ("(nullptr_t)" 1 10))
("operator=" 34 "std::unique_ptr<int, std::default_delete<int> > &" "" "operator=(const std::unique_ptr<int, std::default_delete<int> > &)" 9 ("(const std::unique_ptr<int, std::default_delete<int> > &)" 1 56))
("release" 34 "pointer" "" "release()" 7 ("()"))
("reset" 34 "void" "" "reset()" 5 ("()"))
("swap" 34 "void" "" "swap(std::unique_ptr<int, std::default_delete<int> > &__u)" 4 ("(std::unique_ptr<int, std::default_delete<int> > &__u)" 1 53))
("unique_ptr" 75 "" "" "unique_ptr::" 10 ("::"))
("unique_ptr" 35 "void" "" "unique_ptr(unique_ptr<_Up, _Ep> &&__u)" 10 ("(unique_ptr<_Up, _Ep> &&__u)" 1 27))
("unique_ptr" 35 "void" "" "unique_ptr(auto_ptr<_Up> &&__u)" 10 ("(auto_ptr<_Up> &&__u)" 1 20))
("~unique_ptr" 34 "void" "" "~unique_ptr()" 11 ("()"))
)

;;EOT
execute: Command{action=Command::Complete, file='C:/alt/msys32/tmp/c++11.cpp', line=4, column=8, flags=['-x', 'c++', '-std=c++11', '-IC:/alt/msys32/mingw32/include/c++/4.9.1/i686-w64-mingw32/', '-IC:/alt/msys32/mingw32/include/c++/4.9.1/', '-IC:/alt/msys32/mingw32/lib/clang/3.5.0/include/'], unsavedFiles.count=0, opt=off}
debug: complete: 0 diagnostic(s)

Do you think this is a irony-sever issue or a libclang issue on my system? If the latter I can open a ticket with the package maintainer.

fspeech commented 9 years ago

Unfortunately while I can complete std now it is still as slow as before in completing with boost included.

Sarcasm commented 9 years ago

hum, I'm not sure. Just out of curiosity, if you use the unix path style for the "-I/mingw32/include/c++/4.9.1/", does it work the same?

Unfortunately while I can complete std now it is still as slow as before in completing with boost included.

Slow every times? Or only the first time?

Sarcasm commented 9 years ago

Can you check that you don't have any error with a "complete" boost file, e.g:

$ cat <<EOF > /tmp/boost.cpp
#include <cstdlib>
#include <iostream>

#include <boost/asio.hpp>
#include <boost/bind.hpp>
#include <boost/array.hpp>
#include <boost/signal.hpp>
#include <boost/function.hpp>
#include <boost/shared_ptr.hpp>
#include <boost/noncopyable.hpp>
#include <boost/aligned_storage.hpp>
#include <boost/enable_shared_from_this.hpp>

int main()
{
  boost::shared_ptr<int> i;

  return *i; // boom :)
}
EOF
$ ./bin/irony-server -d check-compile /tmp/boost.cpp <<< '-std=c++11'
execute: Command{action=Command::CheckCompile, file='/tmp/boost.cpp', line=0, column=0, flags=['-std=c++11'], unsavedFiles.count=0, opt=off}
()

;;EOT

If irony-server prints something like ( :errors 1) or something like that maybe something is not right and Clang is not able to generate the preamble.

Sadly only errors/warning/... will be printed but no diagnostics with this command.

I'm going to sleep.

fspeech commented 9 years ago

No those unix paths don't mean anything to a native program. Only in a mingw shell where the directories are "mounted" virtually would the paths make sense.

Good night! Thanks for all the help! I am suspecting maybe this is an emacs issue. When I run irony-server -i, as you said, the second time things get a lot faster. But a lot of stuff is also returned. I will try to trap the irony elisp calls to see where the bottleneck is.

fspeech commented 9 years ago

Here is a poor man's trace on some completions. Because of all the async calls I don't know if you can make any sense of it:

company-irony completing cli Thu Oct  9 16:47:47 2014
Async callback Thu Oct  9 16:47:47 2014
Sending file request Thu Oct  9 16:47:47 2014
Irony doing callback Thu Oct  9 16:48:10 2014
company-irony completing cli Thu Oct  9 16:48:10 2014
company-irony completing ( . t) Thu Oct  9 16:48:24 2014
Async callback Thu Oct  9 16:48:24 2014
Sending file request Thu Oct  9 16:48:24 2014
Irony doing callback Thu Oct  9 16:48:27 2014
company-irony completing ( . t) Thu Oct  9 16:48:27 2014
company-irony continued completing r Thu Oct  9 16:48:28 2014
company-irony continued completing re Thu Oct  9 16:48:28 2014
company-irony completing req Thu Oct  9 16:48:40 2014
Async callback Thu Oct  9 16:48:40 2014
Sending file request Thu Oct  9 16:48:40 2014
company-irony completing reques Thu Oct  9 16:48:41 2014
Async callback Thu Oct  9 16:48:41 2014
Still completing Thu Oct  9 16:48:41 2014
company-irony completing request Thu Oct  9 16:48:41 2014
Async callback Thu Oct  9 16:48:41 2014
Still completing Thu Oct  9 16:48:41 2014
Irony doing callback Thu Oct  9 16:48:43 2014
company-irony completing request_ Thu Oct  9 16:48:44 2014
company-irony completing cli Thu Oct  9 16:48:52 2014
Async callback Thu Oct  9 16:48:52 2014
Sending file request Thu Oct  9 16:48:52 2014
Irony doing callback Thu Oct  9 16:49:15 2014
company-irony completing cli Thu Oct  9 16:49:15 2014
company-irony completing client Thu Oct  9 16:49:23 2014
Async callback Thu Oct  9 16:49:23 2014
Sending file request Thu Oct  9 16:49:23 2014
company-irony completing client_ Thu Oct  9 16:49:24 2014
Async callback Thu Oct  9 16:49:24 2014
Still completing Thu Oct  9 16:49:24 2014
Irony doing callback Thu Oct  9 16:49:26 2014

company-irony ... is from the company front end calling backend (begin-new and continue) Sending file ... is irony send file request Irony doing callback ... is irony popping callback stack Async callback ... is irony called by the front end Still completing ... is irony returns still-completing (so not all Async callback results in sending file request, even if candidates are not available. candidates available is also logged but never shows up.)

fspeech commented 9 years ago

It certainly appears elisp is okay. The bottleneck is getting a response from the server. I will check the server CheckCompile next.

fspeech commented 9 years ago

check-compile found errors. I then checked again with clang++ and found some boost header in conflict with system header. I've filed a bug report with the package maintainer. Hopefully you are right that this is preventing the headers from getting precompiled.

fspeech commented 9 years ago

Resolved clang++ compiling issue by using -DBOOST_USE_WINDOWS_H flag, however libclang check-compile still fails. Will next try to get clang++ to dump all include paths to see if something is still missing.

fspeech commented 9 years ago

An update: I was able to get libclang to accept your test code. However for my own code, which uses cpp-netlib, even clang++ won't compile due to a boost header problem. g++ works fine with the same compiler options. I have filed a bug report with the maintainer but clang is known to be not reliable on mingw platform. Thanks for all your help in getting to the bottom of this. I think the speed issue will have to wait till the header issues are resolved to see what is exactly going on. Right now any number is suspect.

Sarcasm commented 9 years ago

Great work!

One thing you can try for debugging is to modify the following code: https://github.com/Sarcasm/irony-mode/blob/cd6f4540e5f6b4b1cb8f159c3c1a9a4f1273fab0/irony.el#L546-L552

Change:

Add the debug flag -d to the format line:

- (format "%s -i 2>> %s/irony.$$.log"
+ (format "%s -d -i 2>> %s/irony.$$.log"

Then, if you open the log file you will see what arguments went to Clang, and you can see the warnings that happened during completion too.

Did you try irony-mode with the simple boost example from the comment above: https://github.com/Sarcasm/irony-mode/issues/131#issuecomment-58570497

Maybe with the additional flags (-DBOOST_USE_WINDOWS_H) and paths to boost if needs be.

That may give a good idea whether you can get acceptable performances with Boost or not.

Silex commented 9 years ago

Sorry if that was already answered but I have to ask. When I was still on vim I helped with the maintainance of clang_complete at some point. I specifically remember when we moved from the clang binary to libclang, and in particular how it solved the "precompiled headers" problem.

Basically, libclang already uses a form of "precompiled" headers internally and thus you don't need to manage them yourself. You just need to enable caching or something.

My questions are:

  1. Does irony use libclang or the clang binary?
  2. Does irony use these automatic libclang precompiled headers?
Sarcasm commented 9 years ago

Sorry if that was already answered but I have to ask.

That's perfectly fine.

  1. irony uses libclang
  2. irony uses libclang precompiled headers (except on some old versions of libclang where it was buggy)

    #if !defined(CINDEX_VERSION_MAJOR) || !defined(CINDEX_VERSION_MINOR) ||        \
      (CINDEX_VERSION_MAJOR == 0 && CINDEX_VERSION_MINOR < 6)
    // XXX: A bug in old version of Clang (at least '3.1-8') caused the completion
    //      to fail on the standard library types when
    //      CXTranslationUnit_PrecompiledPreamble is used. We disable this option
    //      for old versions of libclang. As a result the completion will work but
    //      significantly slower.
    // -- https://github.com/Sarcasm/irony-mode/issues/4
    settings.parseTUOptions &= ~CXTranslationUnit_PrecompiledPreamble;
    #endif

    -- https://github.com/Sarcasm/irony-mode/blob/cd6f4540e5f6b4b1cb8f159c3c1a9a4f1273fab0/server/src/TUManager.cpp#L188-L197

Clang, the binary is not used.

Silex commented 9 years ago

:+1: Thanks for the info. So the issue here is that libclang maybe doesn't support CXTranslationUnit_PrecompiledPreamble on windows?

Sarcasm commented 9 years ago

Thanks for the info. So the issue here is that libclang maybe doesn't support CXTranslationUnit_PrecompiledPreamble on windows?

I don't think so, fspeech reported that some preamble files where created. But if libclang has trouble parsing the files/finding the headers it will not be able to create a preamble. Once the parsing succeed we will see if there is a performance issue.

fspeech commented 9 years ago

I switched from cpp-netlib to libcurl, which got rid of the dependence on Boost, yet the completion is still very slow. Debug output looks pretty benign. Here is a typical sequence:

Sending file request Fri Oct 10 18:05:53 2014
Sending file request Fri Oct 10 18:06:08 2014
Still completing Fri Oct 10 18:06:11 2014
Still completing Fri Oct 10 18:06:13 2014 [2 times]
Sending file request Fri Oct 10 18:06:16 2014
Irony doing callback Fri Oct 10 18:06:22 2014
Sending file request Fri Oct 10 18:06:29 2014
Sending file request Fri Oct 10 18:06:33 2014
Sending file request Fri Oct 10 18:06:43 2014
Sending file request Fri Oct 10 18:06:46 2014
Still completing Fri Oct 10 18:06:48 2014
Still completing Fri Oct 10 18:06:49 2014
Irony doing callback Fri Oct 10 18:06:51 2014 [2 times]
Sending file request Fri Oct 10 18:06:57 2014
Still completing Fri Oct 10 18:07:06 2014 [2 times]
Still completing Fri Oct 10 18:07:08 2014
Still completing Fri Oct 10 18:07:09 2014
Still completing Fri Oct 10 18:07:10 2014
Irony doing callback Fri Oct 10 18:07:20 2014 [2 times]
Sending file request Fri Oct 10 18:07:33 2014
Still completing Fri Oct 10 18:07:33 2014
Sending file request Fri Oct 10 18:07:45 2014
Irony doing callback Fri Oct 10 18:07:50 2014 [3 times]

"Still completing" apparently does not lock out all the new requests. Is the server interface able to handle multiple requests?

fspeech commented 9 years ago

BTW, eventually something hosed up company mode and I had to manually kill the irony-server to salvage the emacs session. When the screen unfroze, the header include lines were commented out auto-magically (with the correct // syntax), which is pretty hilarious considering how much trouble it is having with the headers :-)

Sending file request Fri Oct 10 18:33:55 2014
Still completing Fri Oct 10 18:33:56 2014
Sending file request Fri Oct 10 18:33:58 2014
Company: An error occurred in auto-begin
writing to process: invalid argument, Irony
Quit
irony process stopped!
fspeech commented 9 years ago

Irony buffer is normally empty right? After I killed the server manually, I could see that the buffer was filled to the gilt. And it stopped at around letter J. So maybe the server is returning way too much stuff and the tty interface between emacs and the server is slow. Just a thought. Is it normal for the server to return so many results?

fspeech commented 9 years ago

I have downloaded the official windows binary from the LLVM.org site and put that DLL in the irony server directory and hid my MinGW DLL (and also fresh started everything) just to make sure this issue isn't limited to the MinGW build. And the official libclang binary behaves the same way. Some more observations:

  1. I've measured through clang++ -E the various sizes of the processed source with a single #include at the top. The Boost network library came in at 279K lines and more than 10M bytes (that is with defining DYN_LINK to try to include as little as possible). I can't believe people would put up with that kind of crap and actually use it. The preamble files left behind by libclang are over 100MB!
  2. With libcurl and stdio it came in at "only" 20K lines and less than 1M. The preamble is about 6M. I suspect that the slowness may be due to a particularly slow tty interface on Windows between emacs and inferior processes ?? The reason is I don't get any faster with libcurl than with boost. If anything it appeared slower.
  3. I know the setup is okay. With -d logging I mostly get 0 or 1 reasonable diagnostic. And if I wait long enough the completions eventually show up and they are good completion suggestions.
  4. Crash has happened more than once. Irony is crammed full with results and is only mid-way through when that happens. Killing the server (have to use system tools to do so) unfreezes emacs.

How is the experience with irony-mode on Linux? I read a lot of praises and I assume they are not using Windows?

Sarcasm commented 9 years ago

Arf, it's possible that the tty interface is shitty on Windows. Maybe something else should be used there but on Linux it runs fine.

To be sure, you can maybe add some timing code to irony-server around those lines: https://github.com/Sarcasm/irony-mode/blob/cd6f4540e5f6b4b1cb8f159c3c1a9a4f1273fab0/server/src/Irony.cpp#L145-L198

If the timing is not significant then it should be an IO issue, I guess I should try it out on Windows but I will probably try using the native compiler instead of mingw, hopefully the issue will remain the same.

fspeech commented 9 years ago

I'd much rather instrument emacs code than c++ code :-) And after some work it confirmed that it is the pty that is slow! The pty buffer is about 4k, the total server output is about 1.8M. Below you can see right after a request, the server sent back the response in no time. I only logged the first 4k (otherwise, as it happened first, the Received message is going to fill up the message buffer). It takes 30 seconds to accumulate all the pty outputs. Now I don't know if pty is literally slow, or it is rate limited by the emacs loop (since it is async it is only going to run when the main loop gets to it), or if inserting 4k into an emacs buffer is slow. Doubt the last reason. Likely a combination of first two? Though there is no reason for pty to be slow, but since we have to receive over 400 batches and if emacs does not get around to it very often? Weird. Not sure if there is anyway to up the buffer size without recompiling emacs.

Sending file request Sat Oct 11 10:54:34 2014
Received 4040 Sat Oct 11 10:54:35 2014
Sending file request Sat Oct 11 10:54:45 2014
EOT received 1864373 Sat Oct 11 10:55:04 2014
Handler finished Sat Oct 11 10:55:04 2014
Received 4040 Sat Oct 11 10:55:04 2014
EOT received 1864410 Sat Oct 11 10:55:33 2014
Handler finished Sat Oct 11 10:55:33 2014
fspeech commented 9 years ago

I am going to switch to pipe instead of using pty and see if that improves things.

fspeech commented 9 years ago

Switching to pipe didn't do anything :-( EDIT: someone more knowledgeable than me suggested that on Windows Emacs defaults to pipe instead of pty. No wonder I didn't see any difference.

irony process stopped!
Sending file request Sat Oct 11 11:15:26 2014
Received first 4040 Sat Oct 11 11:15:28 2014
Sending file request Sat Oct 11 11:15:48 2014
EOT received 1864373 Sat Oct 11 11:15:57 2014
Handler finished Sat Oct 11 11:15:58 2014
Received first 4040 Sat Oct 11 11:15:58 2014
EOT received 1864412 Sat Oct 11 11:16:27 2014
Handler finished Sat Oct 11 11:16:27 2014
fspeech commented 9 years ago

I guess the solution is either to xfer using temp files or do the narrowing of choices on the server side. The second would make the most sense in the long run, as I think even on Linux transferring multi-MB on each keystroke will eat into responsiveness. Even just a simple one or two letter prefix filtering would significantly cut the number of choices to send back.

fspeech commented 9 years ago

Found a solution to the problem. Someone on Reddit pointed out this bug http://lists.gnu.org/archive/html/bug-gnu-emacs/2014-10/msg00159.html which explains the vast majority of the delay I encountered. After I (setq w32-pipe-read-delay 0) the new timing is a lot more tolerable:

Sending file request Sat Oct 11 18:32:42 2014
Received first 4040 Sat Oct 11 18:32:42 2014
EOT received 1864451 Sat Oct 11 18:32:44 2014
Handler actually called Sat Oct 11 18:32:44 2014
Handler finished Sat Oct 11 18:32:44 2014
Sending file request Sat Oct 11 18:33:58 2014
Received first 4040 Sat Oct 11 18:33:58 2014
EOT received 1864473 Sat Oct 11 18:34:00 2014
Handler actually called Sat Oct 11 18:34:00 2014
Handler finished Sat Oct 11 18:34:00 2014

Still if we can cut down on the transfer size we can speed up by another 2-3 seconds which is significant. Interesting clang++ itself is fast.

fspeech commented 9 years ago

Updated the wiki page summarizing the new findings and solutions in this long thread:

  1. libclang default paths different from clang exe
  2. emacs bug(s) adding delay to reading from a pipe
Sarcasm commented 9 years ago

Sorry for the delay busy week-end and I didn't make much progress on Windows.

I am going to switch to pipe instead of using pty and see if that improves things.

FYI, that's pipes are already forced by irony since irony-server doesn't need the additional support for job control and things like that. It's enabled here https://github.com/Sarcasm/irony-mode/blob/cd6f4540e5f6b4b1cb8f159c3c1a9a4f1273fab0/irony.el#L559

I guess the solution is either to xfer using temp files or do the narrowing of choices on the server side. The second would make the most sense in the long run, as I think even on Linux transferring multi-MB on each keystroke will eat into responsiveness. Even just a simple one or two letter prefix filtering would significantly cut the number of choices to send back.

Right now I'm using Boost as the "extreme" case and it seems to work fine on Linux, so I would prefer keeps things the way they are if possible. Before doing the narrowing server-side, I would also be more keen to test an alternative communication scheme, for example using some kind of local socket (not sure if there is an equivalent of Unix Domain Socket on Windows).

Found a solution to the problem. Someone on Reddit pointed out this bug http://lists.gnu.org/archive/html/bug-gnu-emacs/2014-10/msg00159.html which explains the vast majority of the delay I encountered. After I (setq w32-pipe-read-delay 0) the new timing is a lot more tolerable:

Nice finding!

Still if we can cut down on the transfer size we can speed up by another 2-3 seconds which is significant. Interesting clang++ itself is fast.

Yeah that would be great.

I managed to set up a native irony-server, not using Msys2 but the native toolchain and the libclang packaged from the LLVM Download page: http://llvm.org/releases/download.html

Sadly I have some issues getting anything out of a buffer that includes a system header. I don't know the reason yet but I'm really slow getting along with Windows (that's even more reason for me to thank you for your work! Thank you!). When I find the fix I will have to try with Boost.

Do you already have visible delays with a simple std?

Maybe some other things to look at to reduce delays, such as:

Also I would like to make a checklist and on fixing Windows issues and fixes otherwise they will get lost. The best would be to start fresh with #61, since irony-mode has changed since then.

fspeech commented 9 years ago

Do you already have visible delays with a simple std?

Yes as I found out the delay is not on clang side. Even with std you get a lot of headers and therefore a lot of possible completion suggestions at places. The transfer to Emacs is what is slow.

checking that there is no unnecessary character encoding/decoding going on

Yes that may very well be a major source of the remaining delay.

a possibility to read the whole response at once? Irony may be able to send a slightly different request, such as "\n"

I don't think you need to bother. The pipe read buffer is hard coded in C at 4K, which is what is causing the problem. You can't transfer more than 4K without blocking as I understand it.

Sorry for the delay busy week-end

No problem as I am sure this is a project of love. Hope you had a good weekend.

fspeech commented 9 years ago

Yes that may very well be a major source of the remaining delay.

Strike that. First thing I tried was to set Irony buffer to uni-byte instead of multi-byte. But since Emacs internal string representation is multi-byte anyway I don't think that would save anything and it turned out to make no difference. Second thing to try is to change the decoding system. Here again I don't think decoding an ascii stream into utf costs any time since it should be mostly a no-op. It is important that the line endings match and here the default works well enough. (Changing to 'binary would break the exchange because of dos line endings). I don't think there is anything to be gained here.

fspeech commented 9 years ago

What kind of delay do you see on Linux? I think now the two (Windows and Linux) should match. You can eval the following (minor logging changes from your originals) in any scratch elisp buffer and it will track timings in Messages:

(setq sigstart t)

(defun irony--server-process-filter (process output)
  "Handle output that come from an irony-server process."
  (let ((pbuf (process-buffer process))
        responses)
    ;; append output to process buffer
    (when (buffer-live-p pbuf)
      (with-current-buffer pbuf
        (save-excursion
          (goto-char (process-mark process))
      (when sigstart
        (message (format "Received first %s %s" (length output) (current-time-string)))
        (setq sigstart nil))
          (insert output)
          (set-marker (process-mark process) (point))
          ;; check if the message is complete based on `irony--eot'
          (goto-char (point-min))
          (while (search-forward irony--eot nil t)
            (let ((response (buffer-substring-no-properties (point-min)
                                                            (point))))
          (message (format "EOT received %s %s" (- (point) (point-min)) (current-time-string)))
          (setq sigstart t)
              (delete-region (point-min) (point))
              (setq responses (cons response responses))
              (goto-char (process-mark process)))))))
    ;; Handle all responses.
    (mapc #'(lambda (r)
              (irony--process-server-response process r))
          (nreverse responses))))

and maybe this one as well to track when the file request started so you can see how fast the server was able to respond:

(defun irony--send-file-request (request callback &rest args)
  "Send a request that acts on the current buffer to irony-server.

This concerns mainly irony-server commands that do some work on a
translation unit for libclang, the unsaved buffer data are taken
care of."
  (let ((process (irony--get-server-process))
        (argv (append (list request
                            "--num-unsaved=1"
                            (irony--get-buffer-path-for-server))
                      args))
        (compile-options (irony--libclang-compile-options)))
    (when process
      (message (concat "Sending file request " (current-time-string)))
      (irony--server-process-push-callback process callback)
      ;; skip narrowing to compute buffer size and content
      (irony-without-narrowing
        (process-send-string process
                             (format "%s\n%s\n%s\n%d\n"
                                     (combine-and-quote-strings argv)
                                     (combine-and-quote-strings compile-options)
                                     buffer-file-name
                                     (irony-buffer-size-in-bytes)))
        (process-send-region process (point-min) (point-max))
        ;; always make sure to finis with a newline (required by irony-server to
        ;; always make sure to finish with a newline (required by irony-server
        ;; to play nice with line buffering even when the file doesn't end with
        ;; a newline)
        (process-send-string process "\n")))))
Sarcasm commented 9 years ago

You are reading my mind, I was going to ask you for your debugging message since I managed to get the STL working on Windows and wanted to compare the times, since the delays looks okay on a simple example. I will tell you when I test but it's getting late here.

Sarcasm commented 9 years ago

Just for the record, the completion is slower now that I have enabled the debugging.

Edit: at first it looked like this but in the end I doubt it, the following tests looked okay. By the way, I'm still doing my tests on Windows right now. I will try to make some measurements at work tomorrow.

Sarcasm commented 9 years ago

So, I'm on Windows with Boost

I have (setq w32-pipe-read-delay -1).

Using the code from above (https://github.com/Sarcasm/irony-mode/issues/131#issuecomment-58570497) I have the following timings:

Sending file request Mon Oct 13 01:59:49 2014
Received first 11 Mon Oct 13 01:59:53 2014
EOT received 11 Mon Oct 13 01:59:53 2014
Received first 4060 Mon Oct 13 01:59:53 2014
EOT received 110675 Mon Oct 13 01:59:53 2014
Sending file request Mon Oct 13 01:59:55 2014
Received first 4083 Mon Oct 13 01:59:55 2014
EOT received 60577 Mon Oct 13 01:59:55 2014
Sending file request Mon Oct 13 02:00:00 2014
Received first 4060 Mon Oct 13 02:00:01 2014
EOT received 110675 Mon Oct 13 02:00:01 2014
Sending file request Mon Oct 13 02:00:12 2014
Received first 4034 Mon Oct 13 02:00:13 2014
Sending file request Mon Oct 13 02:00:22 2014
EOT received 2915674 Mon Oct 13 02:00:22 2014
Received first 4061 Mon Oct 13 02:00:23 2014
EOT received 8588 Mon Oct 13 02:00:23 2014

Then testing on this example of the Boost documentation: http://www.boost.org/doc/libs/1_56_0/doc/html/boost_asio/example/cpp11/echo/async_udp_echo_server.cpp

Well, I go to do some completion without issues but then a freeze, It happened twice in a row, I have no idea what is the origin of this freeze yet (irony, Emacs, ...?).

image

fspeech commented 9 years ago

You can see that the sending and receiving are out of sync from the above sequence:

Sending file request Mon Oct 13 02:00:12 2014
Received first 4034 Mon Oct 13 02:00:13 2014
Sending file request Mon Oct 13 02:00:22 2014
EOT received 2915674 Mon Oct 13 02:00:22 2014
Received first 4061 Mon Oct 13 02:00:23 2014
EOT received 8588 Mon Oct 13 02:00:23 2014

You can see the first request going out at 2:00:12 (BTW at 2am you are staying up way too late for this! Unless it is your regular schedule!) but the transfer of the whole 2.9M did not finish until 2:00:22, after a second request was already out at 2:00:13 (which if I understood correctly would render the first xfer useless as the context tick would not match). Try setting the read delay to 0 instead of -1 as I recall reading the bug report thread that -1 has some special meaning. It would also be nice for the server to terminate early by sending the EOT if it gets a new request, for example the server could check the stdin for every 100K bytes transferred to see if it has new requests pending.

Also make sure that you did what the Wiki item 7 suggested. If clang didn't find all the include files it may do something weird. I remember the std case where it sent a lot more stuff when it couldn't find the right headers. The gist of that Wiki item is to use clang to dump out all the paths it knows already. Oh here is a question: if you installed the native clang without mingw what c++ headers are you using? Do you have MSVC installed already? Clang binary distribution doesn't have those and system headers as I recall.

Sarcasm commented 9 years ago

You can see that the sending and receiving are out of sync from the above sequence:

This is the intended behavior. irony-completion will skip expired requests and always give priority to the last one.

BTW at 2am you are staying up way too late for this! Unless it is your regular schedule!

I enjoyed working on this, that's fine. I don't do this everyday.

Try setting the read delay to 0 instead of -1 as I recall reading the bug report thread that -1 has some special meaning.

Yeah, I can try with 0. I set it to -1 because someone suggested making it the default value on Windows (http://lists.gnu.org/archive/html/bug-gnu-emacs/2014-10/msg00345.html).

It would also be nice for the server to terminate early by sending the EOT if it gets a new request, for example the server could check the stdin for every 100K bytes transferred to see if it has new requests pending.

Would be nice but I don't want to do this for now.

The direction I had in mind to overcome overlapping request was to handle multiple processes. This would be also nice to support a server optimized for syntax checking, another for completion. I'm not sure yet, but this is something I had in mind since multi-threading is not really cooked in libclang and that the design of irony-mode can easily balance work-load between processes. All of this was under the assumption that completion time was longer than transfer time though.

Also make sure that you did what the Wiki item 7 suggested.

That was taken care of.

if you installed the native clang without mingw what c++ headers are you using?

I'm using the Visual Studio ones.

Do you have MSVC installed already?

Yes, MSVC 2012 for professional I think.

Clang binary distribution doesn't have those and system headers as I recall.

That's true but Clang make a lot of progress on supporting Windows. It's kinda cool, it seems to be possible to make irony-mode compatible with projects compiled with cl. This is something I would like to explore as I'm usually not a big fan of emulation layers. Configuring the .clang_complete with Windows seemed to work after a lot of tweaking to find the proper set of compiler options. See clang-cl, see http://llvm.org/devmtg/2014-04/PDFs/Talks/clang-cl.pdf

I think everything should even with the Visual Studio Express edition, making it accessible to everyone in theory.

On another note, I found out that, irony-server may send some data before Clang even started to process the request (see https://github.com/Sarcasm/irony-mode/blob/cd6f4540e5f6b4b1cb8f159c3c1a9a4f1273fab0/server/src/Irony.cpp#L158). Maybe some of the timing are a bit misleading as the first bytes are received before Clang did its job. I can fix this in the evening.

fspeech commented 9 years ago

Maybe some of the timing are a bit misleading

I think you are mostly okay as you can see that emacs only calls the process filter if there are enough bytes or the pipe is flushed.