ImportError: No module named catkin.environment_cache

[mikepurvis]

System Info

• Operating System: Ubuntu Trusty
• Version of catkin_tools: 0.4.2-1
• ROS Distro: Indigo-ish, catkin 0.6.18

Build / Run Issue

I have a large build which runs via Jenkins inside a cowbuilder environment. I periodically have this build fail with an error which looks like the following:

00:10:36.448 _______________________________________________________________________________
00:10:36.448 Errors << controller_manager_msgs:cmake /tmp/buildd/workspace/debian/tmp/build/logs-sdk/controller_manager_msgs/build.cmake.000.log
00:10:36.448 Traceback (most recent call last):
00:10:36.448   File "/tmp/buildd/workspace/debian/tmp/build/build-sdk/controller_manager_msgs/catkin_generated/generate_cached_setup.py", line 20, in <module>
00:10:36.448     from catkin.environment_cache import generate_environment_script
00:10:36.448 ImportError: No module named catkin.environment_cache
00:10:36.448 CMake Error at /tmp/buildd/workspace/debian/tmp/opt/clearpath/2.0pre/sdk/share/catkin/cmake/safe_execute_process.cmake:11 (message):
00:10:36.448   execute_process(/usr/bin/python
00:10:36.448   "/tmp/buildd/workspace/debian/tmp/build/build-sdk/controller_manager_msgs/catkin_generated/generate_cached_setup.py")
00:10:36.448   returned error code 1
00:10:36.448 Call Stack (most recent call first):
00:10:36.448   /tmp/buildd/workspace/debian/tmp/opt/clearpath/2.0pre/sdk/share/catkin/cmake/all.cmake:186 (safe_execute_process)
00:10:36.448   /tmp/buildd/workspace/debian/tmp/opt/clearpath/2.0pre/sdk/share/catkin/cmake/catkinConfig.cmake:20 (include)
00:10:36.448   CMakeLists.txt:5 (find_package)
00:10:36.448 
00:10:36.448 

The package which triggers the issue is arbitrary— it seems to simply happen whenever, on various different packages. It looks like some kind of a race condition, but it's unclear to me whether the root cause is in catkin_tools or catkin itself.

I don't believe I ever saw this with 0.3.x, but we also switched to 0.4.x pretty early on.

I'm not using eatmydata, so all writes to disk should be fully synced, but it's certainly possible this is coming from an interaction between catkin and the cowbuilder's copy-on-write fs overlay.

I don't have concrete steps to reproduce, but please let me know if there are ways I could instrument my build to supply more meaningful diagnostic information.

[jbohren]

So what's strange is that all of those errors are from the cmake stage, and the traceback is coming out of the core catkin stuff (i.e. not catkin_tools).

[mikepurvis]

Hence why I'm inclined to suspect an issue with the cowbuilder environment, which makes it that much less likely that anyone else has seen anything like this (or indeed, that there's much of anything catkin_tools can do about it).

Still, had to ask. :)

[mikepurvis]

@jbohren @wjwwood This is probably a bit antithetical to the point of a deterministic build system, but I wonder if we'd consider a --build-retries N (default 0) option which lets catkin_tools take more than 1 kick at the can, in the case of these kinds of intermittent failures.

[jbohren]

@mikepurvis why not an environment variable:

export CATKIN_TOOLS_DEFINITION_OF_INSANITY=n # retry failed build stages n times

[mikepurvis]

(In the meantime, I'm experimenting with switching my build environment to use pbuilder rather than cowbuilder— it's a longer startup time, but obviously worth it if it eliminates this kind of flakiness.)

[jbohren]

@wjwwood Would you be open to the addition of a stage retry hack as described above?

[wjwwood]

Well, perhaps somewhat obviously, I'd prefer to fix the underlying issue. However, if it were the case that the problem is actually a user's flaky build then it might be useful to have some options to restart catkin build from where it failed. However, I'm wary of having the looping logic internal to catkin build to prevent that code from getting too complicated. So, I was thinking of like catkin build --restart, and @mikepurvis could put catkin build in a --restart loop to retry failed builds. Also, the catkin build --restart option would be useful outside of this use case, whereas the internal rebuilding is really only useful for automated situations.

[wjwwood]

I guess catkin build --unbuilt (which already exists) might work for this, but maybe --restart would be slightly different in that it would rebuild packages that are already built, choosing to restart wherever the build failed.

[mikepurvis]

catkin build --unbuilt does seem like it would do what I want. I shall investigate.

[mikepurvis]

Alas, I cannot make --unbuilt do what I require, or indeed, anything at all. Filed #384.

[mikepurvis]

Based on my findings and @davetcoleman's report on the other ticket (ros/catkin#806 (comment)), it doesn't seem like re-building would actually fix the problem anyway, without cleaning the build folder of the failed package.

Anyone have any other ideas what could be going on here to intermittently cause this issue?

---

Digging a bit further on the catkin side, the CATKIN_WORKSPACES var, which populates the generate_cached_setup template originates with an iteration of CMAKE_PREFIX_PATH that happens on initial build here:

set(CATKIN_WORKSPACES "")
foreach(path ${CMAKE_PREFIX_PATH})
  if(EXISTS "${path}/.catkin")
    list(FIND CATKIN_WORKSPACES ${path} _index)
    if(_index EQUAL -1)
      list(APPEND CATKIN_WORKSPACES ${path})
    endif()
  endif()
endforeach()

The next step here is probably dumping CMAKE_PREFIX_PATH from that error handler. If it's wrong, then there's something wrong in this logic; if it's right, then there's a FS issue preventing CMake from seeing the ${path}/.catkin marker file.

[mikepurvis]

Okay, so I had switched our infrastructure to use pbuilder rather than cowbuilder, on the hunch that it was an issue with the copy-on-write FS, but the issue struck again today— so I'm back to square one as far as looking for a root cause in catkin/catkin_tools. (FYI @jjekircp)

[mikepurvis]

To start the process of grinding toward a MWE of this issue, I set a VM last night to repeatedly build a ros_base workspace. Setup like so:

rosinstall_generator ros_base --tar --deps --flat > ros_base.rosinstall
rosinstall src ros_base.rosinstall -j8
catkin config --install

And then running the following script:

#!/bin/bash

set -e
count=0
while true; do
  count=$((count+1))
  echo "Starting run $count"
  catkin clean -y
  catkin build --no-status
  echo "Ending run $count"
  sleep 2s
done

The error which I eventually caught (on iteration 228!) was this:

Finished  <<< geometry_msgs                        [ 5.3 seconds ]
Starting  >>> nav_msgs
Starting  >>> sensor_msgs
Starting  >>> shape_msgs
Starting  >>> trajectory_msgs
Starting  >>> visualization_msgs
/home/mpurvis/catkin_tools_fail/install/env.sh: 59: /home/mpurvis/catkin_tools_fail/install/setup.sh: /home/mpurvis/catkin_tools_fail/install/_setup_util.py: not found
Finished  <<< rosconsole                           [ 9.3 seconds ]
Starting  >>> pluginlib
Starting  >>> rosconsole_bridge
Starting  >>> roscpp
Finished  <<< roslisp                              [ 1.8 seconds ]
___________________________________________________________________________________________
Errors     << sensor_msgs:cmake /home/mpurvis/catkin_tools_fail/logs/sensor_msgs/build.cmake.000.log
CMake Warning at /opt/clearpath/2.1devel/sdk/share/catkin/cmake/catkinConfig.cmake:76 (find_package):
  Could not find a package configuration file provided by "geometry_msgs"
  with any of the following names:

    geometry_msgsConfig.cmake
    geometry_msgs-config.cmake

  Add the installation prefix of "geometry_msgs" to CMAKE_PREFIX_PATH or set
  "geometry_msgs_DIR" to a directory containing one of the above files.  If
  "geometry_msgs" provides a separate development package or SDK, be sure it
  has been installed.

This isn't the exact catkin.environment_cache import problem, but I wonder if it might actually be a better pointer to the root cause—looks like there's some provision for mutexing writes to the shared installspace, but I think the real issue is that locking only writes is insufficient— if a package is sourcing setup files at the moment where they're being recreated (as above), you'll get an inconsistent state at configure time. Perhaps the easiest fix is to somehow blacklist packages from writing those common files to the installspace?

[mikepurvis]

Another possible fix is putting a mutex on reads of the setup files. It's a rabbit hole here, but it looks like the magic happens with job.getenv(os.environ), which finally actually calls the load_env function returned here (which in turns calls through to get_resultspace_environment which uses repeated subprocess.Popen calls to execute the required setup files and env hooks).

The catkin build Job gets built up here. However, the job.getenv call (presently) happens before any of the stages. So I think the options on this front would be to either put a special mutex on the getenv call, or move that call into a "Stage" so that the existing locked_resource='installspace' framework could be used.

IMO, it should be moved into a stage, and each stage passed a common dict() for the env argument, so that when the getenv stage completes, it can mutate that dict and all successive stages will be automatically updated. If we don't like the common dict, then a new GetEnvironmentStage could be created, with another block in async_job to handle running it and extracting the updated environment afterward.

@wjwwood @jbohren Thoughts on this approach?

[mikepurvis]

Closed via #391.

[130s]

For the future visitors, I hit the similar (presumably the same) error (on a private Docker container) with catkin_tools 0.4.4. Solution for me was to source /opt/ros/kinetic/setup.bash (apparently I forgot to do so). HTH.

# catkin b
:
Errors     << catkin_tools_prebuild:cmake /root/catkin_ws/logs/catkin_tools_prebuild/build.cmake.001.log                                                                                                                                                             
Traceback (most recent call last):
  File "/root/catkin_ws/build/catkin_tools_prebuild/catkin_generated/generate_cached_setup.py", line 20, in <module>
    from catkin.environment_cache import generate_environment_script
ImportError: No module named catkin.environment_cache
CMake Error at /opt/ros/kinetic/share/catkin/cmake/safe_execute_process.cmake:11 (message):
  execute_process(/usr/bin/python
  "/root/catkin_ws/build/catkin_tools_prebuild/catkin_generated/generate_cached_setup.py")
  returned error code 1
Call Stack (most recent call first):
  /opt/ros/kinetic/share/catkin/cmake/all.cmake:186 (safe_execute_process)
  /opt/ros/kinetic/share/catkin/cmake/catkinConfig.cmake:20 (include)
  CMakeLists.txt:4 (find_package)


cd /root/catkin_ws/build/catkin_tools_prebuild; catkin build --get-env catkin_tools_prebuild | catkin env -si  /usr/bin/cmake /root/catkin_ws/build/catkin_tools_prebuild --no-warn-unused-cli -DCATKIN_DEVEL_PREFIX=/root/catkin_ws/devel/.private/catkin_tools_prebu
ild -DCMAKE_INSTALL_PREFIX=/root/catkin_ws/install -DCMAKE_BUILD_TYPE=Release -DCMAKE_INSTALL_PREFIX=/opt/ros/kinetic; cd -

[build]   Ignored:   None.
[build]   Warnings:  None.
[build]   Abandoned: 5 packages were abandoned.
[build]   Failed:    1 packages failed.        
[build] Runtime: 0.4 seconds total.            
root@df28ea59b8fe:~/catkin_ws# apt-cache policy python-catkin-tools
python-catkin-tools:
  Installed: 0.4.4-1
  Candidate: 0.4.4-1
  Version table:
 *** 0.4.4-1 500
        500 http://packages.ros.org/ros/ubuntu xenial/main amd64 Packages
        100 /var/lib/dpkg/status

[lzyplayer]

@130s I have the same issues when using Clion and just solve it. But I don't think our problem is the same with the one they mentioned.

/home/*******/APPlication/clion-2019.1.4/bin/cmake/linux/bin/cmake -DCMAKE_BUILD_TYPE=Debug -DCATKIN_DEVEL_PREFIX:PATH=/home/vickylzy/WorkSPacesROS/catkin_ws/devel -G "CodeBlocks - Unix Makefiles" /home/vickylzy/WorkSPacesROS/catkin_ws/src
-- Using CATKIN_DEVEL_PREFIX: /home/vickylzy/WorkSPacesROS/catkin_ws/devel
-- Using CMAKE_PREFIX_PATH: 
-- Using PYTHON_EXECUTABLE: /usr/bin/python
-- Using Debian Python package layout
-- Using empy: /usr/bin/empy
-- Using CATKIN_ENABLE_TESTING: ON
-- Call enable_testing()
-- Using CATKIN_TEST_RESULTS_DIR: /home/vickylzy/WorkSPacesROS/catkin_ws/build/test_results
-- Found gmock sources under '/usr/src/gmock': gmock will be built
-- Found gtest sources under '/usr/src/gmock': gtests will be built
-- Using Python nosetests: /usr/bin/nosetests-2.7
-- catkin 0.7.18
-- BUILD_SHARED_LIBS is on
Traceback (most recent call last):
  File "/home/*******/WorkSPacesROS/catkin_ws/build/catkin_generated/generate_cached_setup.py", line 20, in <module>
    from catkin.environment_cache import generate_environment_script
ImportError: No module named catkin.environment_cache
CMake Error at /opt/ros/kinetic/share/catkin/cmake/safe_execute_process.cmake:11 (message):
  execute_process(/usr/bin/python
  "/home/*******/WorkSPacesROS/catkin_ws/build/catkin_generated/generate_cached_setup.py")
  returned error code 1
Call Stack (most recent call first):
  /opt/ros/kinetic/share/catkin/cmake/all.cmake:207 (safe_execute_process)
  /opt/ros/kinetic/share/catkin/cmake/catkinConfig.cmake:20 (include)
  CMakeLists.txt:56 (find_package)


-- Configuring incomplete, errors occurred!
See also "/home/*******/WorkSPacesROS/catkin_ws/build/CMakeFiles/CMakeOutput.log".
See also "/home/*******/WorkSPacesROS/catkin_ws/build/CMakeFiles/CMakeError.log".

[Failed to reload]

• Problem:
  • I have source /opt/ros/kinetic/setup.bash line added in my ~/.bashrc. Thus it won't be the problem. However I have also added /home/USERNAME/catkin_ws/devel/setup.bash(I know it's not recommended) after former line. And when i start clion byPATH_TO_CLION/clion.sh cmake went wrong and show just the same error ImportError: No module named catkin.environment_cachein clion--cmake bar
• solution:
  • comment out line /home/USERNAME/catkin_ws/devel/setup.bash in ~/.bashrc and start over , problem gone

Thanks for any advice on why this problem occur!

[Lycanthropeus]

Hello everyone, I am getting this same error, but I am using Windows. After reading the discussion above, I couldn't figure out how to get rid of this error. I am a newbie at this, so could someone please help me with this issue?

--Using CATKIN_DEVEL_PREFIX: E:/trac_ik_git/trac_ik/trac_ik_csharp/build/devel
-- Using CMAKE_PREFIX_PATH: D:/Downloads/vcpkg-master/installed/x86-windows/debug;D:/Downloads/vcpkg-master/installed/x86-windows
-- Found PythonInterp: C:/Python27/python.exe (found version "2.7.18")
-- Using PYTHON_EXECUTABLE: C:/Python27/python.exe
-- Found PY_em: C:\Python27\lib\site-packages\em.pyc
-- Using empy: C:/Python27/lib/site-packages/em.pyc``
-- Using CATKIN_ENABLE_TESTING: ON
-- Call enable_testing()
-- Using CATKIN_TEST_RESULTS_DIR: E:/trac_ik_git/trac_ik/trac_ik_csharp/build/test_results
-- gtest not found, C++ tests can not be built. Please install the gtest headers globally in your system to enable gtests
-- nosetests not found, Python tests can not be run (try installing package 'python-nose')
-- catkin 0.7.24
-- BUILD_SHARED_LIBS is on
Traceback (most recent call last):
File "E:/trac_ik_git/trac_ik/trac_ik_csharp/build/catkin_generated/generate_cached_setup.py", line 20, in
from catkin.environment_cache import generate_environment_script
ImportError: No module named catkin.environment_cache
CMake Error at C:/opt/ros/melodic/x64/share/catkin/cmake/safe_execute_process.cmake:11 (message):
execute_process(C:/Python27/python.exe
returned error code 1
Call Stack (most recent call first):
C:/opt/ros/melodic/x64/share/catkin/cmake/all.cmake:208 (safe_execute_process)
C:/opt/ros/melodic/x64/share/catkin/cmake/catkinConfig.cmake:20 (include)
D:/Downloads/vcpkg-master/scripts/buildsystems/vcpkg.cmake:331 (_find_package)
CMakeLists.txt:17 (find_package)
CMakeLists.txt:17 (find_package)

-- Configuring incomplete, errors occurred!
See also "E:/trac_ik_git/trac_ik/trac_ik_csharp/build/CMakeFiles/CMakeOutput.log".**