colcon build "hangs" after completion [WSL2]

[newcanopies]

Hi, thanks for this great package. I am having a not before seen issue, where colcon build logs the Finish and Summary of a ROS2 package, but "hangs" between 2 and 5 minutes afterwards, holding up that terminal. Note: same hang-up occurs for failed builds...

If I CTRL-C in order to continue using that terminal, am I interrupting full completion of the process?

What could be the root cause?

ROS2 env:

   PLATFORM INFORMATION
system           : Linux
platform info    : Linux-5.4.72-microsoft-standard-WSL2-x86_64-with-glibc2.29
release          : 5.4.72-microsoft-standard-WSL2
processor        : x86_64

   RMW MIDDLEWARE
middleware name    : rmw_fastrtps_cpp

   ROS 2 INFORMATION
distribution name      : foxy
distribution type      : ros2
distribution status    : active
release platforms      : {'ubuntu': ['focal']}

[christophebedard]

Side node: this probably belongs in https://github.com/colcon/colcon-core

I've also noticed a delay with colcon build after the last line is printed on Windows.

From what I can tell, after building, colcon creates the necessary setup scripts (so it does some processing and creates some files). It does that even if the build failed.

https://github.com/colcon/colcon-core/blob/aa3b73518f1cf259732cdea21f4ee36384fec921/colcon_core/verb/build.py#L146-L150

I've only had delays of around a few seconds, but you seem to be using WSL, and from a quick Google search WSL(2)'s filesystem seems to be kind of slow, so maybe that's why it takes considerably longer.

• https://github.com/microsoft/WSL/issues/4197
• https://dev.to/kleeut/why-is-wsl2-so-slow-4n3i
• https://www.reddit.com/r/bashonubuntuonwindows/comments/a23nul/very_slow_performance_is_this_normal_for_wsl/

So, yes, I think you'd be interrupting colcon build's job if you were to kill it before it's done.

If you could share the content of the log file (log/latest_build/logger_all.log), it might confirm that colcon build is creating files during that time. The log file is quite long, so you can simply share the lines starting from DEBUG:colcon.colcon_core.event_reactor:joined thread.

[newcanopies]

Since I've used WSL1 prior extensively (without this colcon hangup), I do read here that the actual TL;DR; is:

• that WSL2 is in fact fastest on the Linux file system,
• while https://github.com/microsoft/WSL/issues/4197 benchmarks are specifically for "performance of accessing Windows drives from WSL2" that WSL2 mounts as user@machine:/mnt/c/Users/ which is not related to ROS colcon build inside WSL2 Linux. Nominally all ROS work is done inside WSL2 Linux, I only ever mount Windows on /mnt/c/Users/ to copy over CAD meshes from SW/Rhino/Blender..

Thanks very much for these christophebedard, very curious if writing to local_setup and setup.zsh is the whole duration of the hangup:

here's the end of the log/latest_build/logger_all.log for a moveit2 build that completed in: Summary: 54 packages finished [2min 22s] but then hungup the terminal for an additional 5mins

[275.658s] DEBUG:colcon.colcon_core.event_reactor:joined thread
[275.660s] INFO:colcon.colcon_core.shell:Creating prefix script '/home/user/ws_ROS2/moveit2/install/local_setup.ps1'
[275.663s] INFO:colcon.colcon_core.shell:Creating prefix util module '/home/user/ws_ROS2/moveit2/install/_local_setup_util_ps1.py'
[275.666s] INFO:colcon.colcon_core.shell:Creating prefix chain script '/home/user/ws_ROS2/moveit2/install/setup.ps1'
[275.671s] INFO:colcon.colcon_core.shell:Creating prefix script '/home/user/ws_ROS2/moveit2/install/local_setup.sh'
[275.672s] INFO:colcon.colcon_core.shell:Creating prefix util module '/home/user/ws_ROS2/moveit2/install/_local_setup_util_sh.py'
[275.673s] INFO:colcon.colcon_core.shell:Creating prefix chain script '/home/user/ws_ROS2/moveit2/install/setup.sh'
[275.678s] INFO:colcon.colcon_core.shell:Creating prefix script '/home/user/ws_ROS2/moveit2/install/local_setup.bash'
[275.679s] INFO:colcon.colcon_core.shell:Creating prefix chain script '/home/user/ws_ROS2/moveit2/install/setup.bash'
[275.683s] INFO:colcon.colcon_core.shell:Creating prefix script '/home/user/ws_ROS2/moveit2/install/local_setup.zsh'
[275.684s] INFO:colcon.colcon_core.shell:Creating prefix chain script '/home/user/ws_ROS2/moveit2/install/setup.zsh'

[christophebedard]

Interesting!

That looks good though. Then, unless the rest of the log file can shed light on this (e.g. looking at the timestamps), I'm not sure what's going on. Could you share the (full) log file using https://pastebin.com/?

[newcanopies]

the hangup lasts longer than the build, (with any package) here is the full 2min 22s log: https://gist.github.com/newcanopies/8358a454e5ac8edf0e172ba0ed9c834f

[newcanopies]

possible cause:

• X11 was not running before starting the X11 XLaunch instance (which provides GUI on WSL2 Linux) the colcon build hang-up seems to be solved.

[christophebedard]

Yes, WSL/X11 seems to have been the problem

I was going to post this:

there is a significant jump in time here:

[142.360s] INFO:colcon.colcon_notification.desktop_notification:Sending desktop notification using 'notify2'
[275.657s] DEBUG:colcon.colcon_notification.desktop_notification.notify2:Failed to initialize notify2: org.freedesktop.DBus.Error.Spawn.ExecFailed: /usr/bin/dbus-launch terminated abnormally with the following error: Autolaunch error: X11 initialization failed.

Looking at that, there seems to be an issue with the notification system (which usually triggers a "build successful" or "build failed" notification). I'm guessing it's related to WSL.

[newcanopies]

very good to know this, thanks a ton @christophebedard !

[christophebedard]

My pleasure!

by the way, if you wanted to avoid having to start X11, you could uninstall colcon-notification and colcon just wouldn't try to send a notification, e.g.

$ sudo apt-get purge python3-colcon-notification
$ pip3 uninstall colcon-notification

depending on how you installed colcon. I'm guessing you installed colcon-common-extensions, so the commands above might slightly mess with apt/pip (you could just install the colcon-* packages manually afterwards).

[newcanopies]

Great to understand other functions of X11. Generally, you want X11 running (baseline @ 20Mb memory), for gedit and nautilus , so I'll leave be colcon-notification for debugging. Funny thing is, I realized X11 wasn't running in order to gedit _log/latest_build/loggerall.log ^^'

Thanks again very much for sharing your knowledge on this notifications mechanism, have a great day!

[MatteoAlbi]

Just run in the same problem and I was browsing online looking for a solution. For future readers, it is also possible to turn off colcon notifications setting an env variable. Run: export COLCON_EXTENSION_BLOCKLIST=colcon_core.event_handler.desktop_notification or add it to your .bashrc for auto exporting when opening new terminals