--job fails with 3.7.1 & gc3pie 2.5.0

[jpecar]

We had our CI pipeline running fine all the way & including EasyBuild 3.6.2 & GC3Pie 2.4.2. Now I've upgraded to 3.7.1 and GC3Pie 2.5.0 and jobs are created by GC3Pie but fail immediately with "eb: command not found", causing gc3pie to fail with " gc3libs.exceptions.LRMSError: Could not retrieve status information for task Application@3aa5250".

It appears that something changed in the way how environment is propagated down from eb that generates a job to a job itself. There are no changes that would mention anything like this in either easybuild or gc3pie changelogs.

For now I've hardcoded our CI to use previous versions of EasyBuild and GC3Pie but would eventually like to see this resolved.

[boegel]

Instinct tells me this is most likely a problem with GC3Pie, but I'll let @riccardomurri be the judge on this... Is GC3Pie somehow resetting the environment?

@jpecar Can you provide some more information on how EasyBuild was installed? Are you loading a module file for EasyBuild, or was it installed via easy_install or pip, etc.?

[jpecar]

It's a module file.

[riccardomurri]

GC3Pie does not reset the environment; all processes are run in the environment inherited from the parent process. What has changed in rel 2.5.0 compared to rel 2.4.2 is that sub-processes are now executed directly without calling a shell (i.e., we use Python's subprocess.Popen(..., shell=False) instead of subprocess.Popen(..., shell=True). This might have consequences if your shell's startup files were used to set the environment/PATH where to find the eb executable.

Environmental variables can be overridden, but that has to be specified when you create the GC3Pie Task object; in EB's code, this is the argument env_vars to EB's make_job() method. As far as I can see, the only place where make_job() is called is in EB's parallelbuild.py where the env_vars parameter is passed a dictionary comprising all EASYBUILD_* variables plus PYTHONPATH and MODULEPATH. Maybe what happens is that the previous version of EB included more stuff in the environment? Or did not reset the environment before calling into GC3Pie?

I guess it would help in your case if gc3pie/gc3pie#609 was solved?

[boegel]

@riccardomurri: It seems like we should also be explicitly passing PATH via env_vars? That would probably fix the issue @jpecar is seeing?

[riccardomurri]

It seems like we should also be explicitly passing PATH via env_vars? That would probably fix the issue @jpecar <https://github.com/jpecar> is seeing?

Yes, I think that would do it.

[boegel]

@jpecar Can you try applying this patch in your EasyBuild installation as see if that fixes the problem you're seeing?

diff --git a/easybuild/tools/parallelbuild.py b/easybuild/tools/parallelbuild.py
index 1a5018a3e..7511fce57 100644
--- a/easybuild/tools/parallelbuild.py
+++ b/easybuild/tools/parallelbuild.py
@@ -161,7 +161,7 @@ def create_job(job_backend, build_command, easyconfig, output_dir='easybuild-bui
         if name.startswith("EASYBUILD"):
             easybuild_vars[name] = os.environ[name]
 
-    for env_var in ["PYTHONPATH", "MODULEPATH"]:
+    for env_var in ["PATH", "PYTHONPATH", "MODULEPATH"]:
         if env_var in os.environ:
             easybuild_vars[env_var] = os.environ[env_var]
 

[jpecar]

With this patch eb command is now found but fails with "ERROR: Lmod modules tool can not be used, 'lmod' command is not available". So I guess more variables from env need to be passed down, some of the LMOD_* ones? Don't know in detail how easybuild detects lmod availability.

[boegel]

@jpecar OK, then try also passing down $LMOD_CMD.

This may point to a bigger problem there, if the shell in the job being submitted isn't properly set up, you may run into more problems...

How is Lmod installed & initialized in shell sessions?

[vanzod]

@jpecar I hit the same issue and the easiest workaround for now is to pass a bunch of Lmod related env vars to GC3Pie. Here is a patch that does the job for me:

--- parallelbuild.py.orig       2018-10-24 10:52:55.959314000 -0500
+++ parallelbuild.py    2018-10-24 10:33:27.066026750 -0500
@@ -155,17 +155,16 @@
 
     returns the job
     """
-    # capture PYTHONPATH, MODULEPATH and all variables starting with EASYBUILD
-    easybuild_vars = {}
-    for name in os.environ:
-        if name.startswith("EASYBUILD"):
-            easybuild_vars[name] = os.environ[name]
-
-    for env_var in ["PYTHONPATH", "MODULEPATH"]:
-        if env_var in os.environ:
-            easybuild_vars[env_var] = os.environ[env_var]
+    # capture PYTHONPATH, MODULEPATH and all variables starting with EASYBUILD or LMOD
+    env_vars_to_pass = {}
 
-    _log.info("Dictionary of environment variables passed to job: %s" % easybuild_vars)
+    regex = re.compile("^(PATH|PYTHONPATH|MODULEPATH|USER)$|^(LMOD|EASYBUILD).*")
+
+    for env_var in os.environ:
+        if re.match(regex, env_var) is not None:
+            env_vars_to_pass[env_var] = os.environ[env_var]
+
+    _log.info("Dictionary of environment variables passed to job: %s" % env_vars_to_pass)
 
     # obtain unique name based on name/easyconfig version tuple
     ec_tuple = (easyconfig['ec']['name'], det_full_ec_version(easyconfig['ec']))
@@ -194,7 +193,7 @@
     if build_option('job_cores'):
         extra['cores'] = build_option('job_cores')
 
-    job = job_backend.make_job(command, name, easybuild_vars, **extra)
+    job = job_backend.make_job(command, name, env_vars_to_pass, **extra)
     job.module = easyconfig['ec'].full_mod_name
 
     return job

[vanzod]

@riccardomurri The workaround above is clearly not enough to ensure that the environment is correctly set in the job. Think for example of a customized environment where Lmod or EasyBuild pull information from a site-specific environment variable. Obviously we cannot predict this a priori.

Is there any way to request GC3Pie to start the subprocess with shell=True as it used to do before?

[boegel]

@riccardomurri +1 on @vanzod's question.

Also, can you clarify why that change to using shell=False was made? Just wondering, this isn't criticism, to be clear. ;-)

[jpecar]

@vanzod: Thanks, now I see --job jobs running and producing expected output. In the log files I actually see builds succeeding.

However in CI I still see that there's some communication error, apparently in gc3pie-slurm:

== GC3Pie job overview: 1 running (total: 1)
Traceback (most recent call last):
  File "/usr/lib64/python2.7/runpy.py", line 162, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/usr/lib64/python2.7/runpy.py", line 72, in _run_code
    exec code in run_globals
  File "/g/easybuild/x86_64/CentOS/7/skylake/software/EasyBuild/3.7.1/lib/python2.7/site-packages/easybuild_framework-3.7.1-py2.7.egg/easybuild/main.py", line 529, in <module>
    main()
  File "/g/easybuild/x86_64/CentOS/7/skylake/software/EasyBuild/3.7.1/lib/python2.7/site-packages/easybuild_framework-3.7.1-py2.7.egg/easybuild/main.py", line 487, in main
    submit_jobs(ordered_ecs, eb_go.generate_cmd_line(), testing=testing)
  File "/g/easybuild/x86_64/CentOS/7/skylake/software/EasyBuild/3.7.1/lib/python2.7/site-packages/easybuild_framework-3.7.1-py2.7.egg/easybuild/tools/parallelbuild.py", line 144, in submit_jobs
    return build_easyconfigs_in_parallel(command, ordered_ecs, prepare_first=prepare_first)
  File "/g/easybuild/x86_64/CentOS/7/skylake/software/EasyBuild/3.7.1/lib/python2.7/site-packages/easybuild_framework-3.7.1-py2.7.egg/easybuild/tools/parallelbuild.py", line 114, in build_easyconfigs_in_parallel
    active_job_backend.complete()
  File "/g/easybuild/x86_64/CentOS/7/skylake/software/EasyBuild/3.7.1/lib/python2.7/site-packages/easybuild_framework-3.7.1-py2.7.egg/easybuild/tools/job/gc3pie.py", line 240, in complete
    self._engine.progress()
  File "/g/easybuild/x86_64/CentOS/7/skylake/software/GC3Pie/2.5.0/lib/python2.7/site-packages/gc3pie-2.5.0-py2.7.egg/gc3libs/core.py", line 1735, in progress
  File "/g/easybuild/x86_64/CentOS/7/skylake/software/GC3Pie/2.5.0/lib/python2.7/site-packages/gc3pie-2.5.0-py2.7.egg/gc3libs/core.py", line 1712, in progress
  File "/g/easybuild/x86_64/CentOS/7/skylake/software/GC3Pie/2.5.0/lib/python2.7/site-packages/gc3pie-2.5.0-py2.7.egg/gc3libs/core.py", line 423, in update_job_state
  File "/g/easybuild/x86_64/CentOS/7/skylake/software/GC3Pie/2.5.0/lib/python2.7/site-packages/gc3pie-2.5.0-py2.7.egg/gc3libs/core.py", line 461, in __update_application
gc3libs.exceptions.LRMSError: Could not retrieve status information for task Application@38462d0

Seems like something else changed in gc3pie as well. Any pointers?

[boegel]

@jpecar What does "in CI" mean exactly?

Again, maybe @riccardomurri can help here...

[riccardomurri]

Hello all,

before we jump straight to conclusions and suggested patches, I would
like to dig into the issue a bit more...

First of all: a different backend is used in GC3Pie, depending on
whether the jobs are to be executed on the local machine (shellcmd
backend) or on a cluster (backends depend on the actual queueing
system, but they share a large amount of code).

What is the backend that @jpecar and @vanzod are using here? (I was
assuming it's shellcmd but maybe you have your CI system hooked to a
batch-queueing cluster so you're using slurm?)

Anyway, whatever the backend, the environmental variable passed to
GC3Pie act as overrides: they overwrite values that may be already
present in the environment, but the UNIX process environment comes
from -well- the execution environment: if you run through SLURM, it
will be set by slurmd, if you use GC3Pie's shellcmd backend, it
will be inherited from the parent process (i.e., the eb command
itself). Let me repeat this: GC3Pie does not clear the environment;
if Lmod or EB env variables are missing, they have been removed
elsewhere.

So, before we go on: what backend are you guys using for these tests?

[jpecar]

This is a chunk of my gc3pie.conf:

[auth/none]
type = none

[resource/nehalem]
enabled = yes
auth = none
type = slurm
frontend = localhost
transport = local
architecture = x86_64
max_cores_per_job = 8
max_cores = 32
max_memory_per_core = 4 GiB
max_walltime = 1 day
sbatch = sbatch -t 8:00 -N 1 -C nehalem -p htc --reservation=ebbuild

And the same for other archs.

CI is run through gitlab, where each commit spawns a docker container that can talk and submit jobs to our slurm cluster. Within that docker easybuild is run with --job option, using gc3pie to manage slurm jobs.

[boegel]

@riccardomurri Thanks for clarifying.

The claim is that this worked with GC3Pie 2.4.x, so I'm assuming the same setup is being used here by @jpecar & @vanzod w.r.t. Gc3Pie configuration & backends.

If it doesn't work in Gc3Pie 2.5.0 anymore, then something was changed that changes the (default) behavior w.r.t. passing down of environment variables. It's clear that GC3Pie isn't actively resetting the environment, but it may be a secondary effect, e.g. by no longer starting a login shell?

[riccardomurri]

@jpecar Would you be able to apply the following patch to your GC3Pie code and retry?

diff --git a/gc3libs/__init__.py b/gc3libs/__init__.py
index b7ed95e0..3979ab46 100755
--- a/gc3libs/__init__.py
+++ b/gc3libs/__init__.py
@@ -1572,7 +1572,9 @@ class Application(Task):
                       + ['{0}={1}'.format(name, value)
                          for name, value in self.environment.iteritems()]
                       + sbatch
-                      + ['--export', ','.join(self.environment.keys())])
+                      + ['--export', ','.join(self.environment.keys() + ['ALL'])])
+        else:
+            sbatch += ['--export', 'ALL']
 
         return (sbatch, cmdline)

If you cannot patch GC3Pie, it should suffice to change your config to read::

    sbatch = sbatch --export=PWD,ALL # rest of the line as it was

[riccardomurri]

@boegel

If it doesn't work in Gc3Pie 2.5.0 anymore, then something was changed that changes the (default) behavior w.r.t. passing down of environment variables.[...] may be a secondary effect, e.g. by no longer starting a login shell?

Yes, I'm not trying to say that it doesn't depend on GC3Pie at all. But I'm not convinced that Popen(..., shell=True) as suggested in @vanzod 's comment #2632 (comment) is the fix. (For one, GC3Pie had never invoked login shells...)

[jpecar]

With patch by @vanzod reverted and sbatch --export=PWD,ALL in gc3pie.cfg, I'm back to "/bin/sh: eb: command not found".

@boegel: is there anything blocking me from trying eb 3.7.1 with gc3pie 2.4.2? I'm thinking of isolating the problem to one of the involved components and then bisecting it to identify the issue ... seems like a good opportunity to learn how to do that :)

[riccardomurri]

@jpecar It's possible that SLURM's --export options are not cumulative so the --export=...,ALL gets overwritten by the later one generated by GC3Pie (man page is not clear). Any chance you could try patching the sources?

Also, if you create a file with just these contents:

#! /bin/sh
printenv

Do you see any difference in the output if you submit it with:

   sbatch --export=PWD,ALL # rest of args as in config

or with::

    sbatch --export=PWD # rest of args as in config

[vanzod]

@riccardomurri In my setup the backend is Slurm. As @boegel pointed out, nothing changed in our setup or configuration after moving to 2.5.0 from 2.4.2.

My reference to the issue being shell=True was just an hypothesis based on your first comment and the fact that I have noticed similar issues when using subprocess.Popen in other contexts.

[boegel]

@jpecar The required version was bumped to 2.5.0 in #2554, I don't think EasyBuild v3.7.x is compatible with GC3Pie 2.4.x...

[riccardomurri]

I think I have a clue now about what happens.

On our prod clusters, all running SLURM 15.08 on Ubuntu 16.04, I see that (1) all environment variables are propagated, (2) unless sbatch is passed the --export option with a list of specific variables which does not include ALL. Furthermore, (3) multiple --export options do not cumulate, instead the last one wins:

$ sbatch --version
slurm 15.08.7

$ export FOO=bar
$ cat foo.sh
#! /bin/sh
echo ${FOO:-no FOO!}

$ sbatch foo.sh  # (1)
Submitted batch job 1276138
$ cat slurm-1276138.out
bar

$ sbatch --export=PWD,ALL foo.sh # (2)
Submitted batch job 1276139
$ cat slurm-1276139.out
bar

$ sbatch --export=PWD foo.sh # (2)
Submitted batch job 1276140
$ cat slurm-1276140.out
no FOO!

$ sbatch --export=FOO,ALL --export=PWD foo.sh # (3)
Submitted batch job 1276141
$ cat slurm-1276141.out
no FOO!

So, one thing that changed in the transition from GC3Pie 2.4.2 to 2.5.0 is exactly the addition of --export to honor the environment setting with SLURM. However, in its current form, this seems to be broken in that --export=FOO,BAR,BAZ will only export those 3 vars and reset the rest of the environment so we need --export=FOO,BAR,BAZ,ALL instead.

Can someone please try applying the patch from #2632 (comment) and tell if it fixes the issue? (It should if this explanation is correct.)

[boegel]

@riccardomurri But then, what's the point of passing any environment that should be passed at all, since you'll always pass the current environment anyway via ALL?

[jpecar]

@riccardomurri I tried the patched gc3pie and it seems to work: I see jobs submitted and software being built.

However I still see that "Could not retrieve status information" like I mentioned in #2632 (comment) . I guess this is another issue, unrelated to this one?

[boegel]

It seems like we should change the current behavior in EasyBuild, to make it not specify any environment variables to pass down into submitted jobs (which assumes that EasyBuild will be available by default in submitted jobs).
This would effectively restore the behavior we had before with EasyBuild & GC3Pie, where the environment is passed down into jobs...

Does that make sense @riccardomurri, @vanzod?

cc @akesandgren

[akesandgren]

My problem might be unrelated (PySlurm) but I'll investigate a bit more.

[boegel]

I think the proper way to fix this in the EasyBuild framework is to simply stop passing down specific environment variables in submitted jobs.
I've made that proposed change in #2643...

[riccardomurri]

hi all, sorry for being silent on this for a while -- it's a very busy time until Dec. for me...

Anyway, I think GC3Pie's submit method needs to be corrected to include --export=ALL; I'll try to get out GC3Pie 2.5.1rc1 next week to test.

[boegel]

@riccardomurri Any updates?

[boegel]

@vanzod Can you check whether this is still a problem?

[riccardomurri]

I have just released GC3Pie 2.5.1 with the SLURM environment fix. Let me know if it fixes this issue.

[boegel]

@jpecar Can you test GC3Pie 2.5.1 with EasyBuild 3.7.1, and see whether this problem is resolved with that combination?

In any case, this issue should also be solved with the upcoming EasyBuild 3.8.0 (thanks to #2643), which (I think) work with both GC3Pie 2.5.0 and 2.5.1

[jpecar]

@boegel Initial problem is resolved with 2.5.1 (job is submitted, package starts building and gets successfully built), but it appears there's another problem lurking. See above my post from Oct 25.

[riccardomurri]

@jpecar Following up on your comment from Oct. 25: can you set the GC3Pie logging level to DEBUG? That should show the actual interactions with SLURM.

[jpecar]

@riccardomurri Maybe a stupid question, but ... how? I didn't find anything relevant in gc3pie docs, grepping the source gave me two ideas (adding "debug=1" to gc3pie.conf and creating $HOME/.gc3/gc3libs.log.conf with content "level=debug"), none of which made any change to output I get. I agree that looking at commands fired at slurm and reading their output is the right way to understand what I'm seeing, just let me know how I can achieve that.

[riccardomurri]

@jpecar GC3Pie uses the logger passed by EB, so just raising EB's log level should be enough.

[nortex]

Is there an option to build the gc3pie with the easybuild python instead of system? i have old 2.6 system python with old setuptools that cannot be upgraded to newer.

[riccardomurri]

Is there an option to build the gc3pie with the easybuild python instead of system?

I am not sure I understand the question: GC3Pie is a pure Python library, there is nothing being compiled, and it will run in EB's Python interpreter when used by EasyBuild...

[nortex]

Is there an option to build the gc3pie with the easybuild python instead of system?

I am not sure I understand the question: GC3Pie is a pure Python library, there is nothing being compiled, and it will run in EB's Python interpreter when used by EasyBuild...

I get this error when trying to compile with EasyBuild:

== 2019-10-27 14:02:01,748 run.py:192 INFO running cmd: unzip -qq /data/sources/g/GC3Pie/extensions/setuptools-41.0.1.zip
== 2019-10-27 14:02:02,396 run.py:192 INFO running cmd: /usr/bin/python -V
== 2019-10-27 14:02:02,430 run.py:192 INFO running cmd: /usr/bin/python -c 'import sys; print(sys.executable)'
== 2019-10-27 14:02:02,484 environment.py:97 INFO Environment variable PYTHONNOUSERSITE set to 1 (previously undefined)
== 2019-10-27 14:02:02,485 run.py:192 INFO running cmd: /usr/bin/python -c 'import sys; print(sys.path)'
== 2019-10-27 14:02:02,539 run.py:192 INFO running cmd:  /usr/bin/python setup.py build
== 2019-10-27 14:02:03,189 build_log.py:163 ERROR EasyBuild crashed with an error (at ?:124 in __init__): cmd " /usr/bin/python setup.py build " exited with exit code 1 and output:
Traceback (most recent call last):
  File "setup.py", line 11, in <module>
    import setuptools
  File "/data/sources/build/GC3Pie/2.5.2/dummy-dummy/setuptools/setuptools-41.0.1/setuptools/__init__.py", line 18, in <module>
    import setuptools.version
  File "/data/sources/build/GC3Pie/2.5.2/dummy-dummy/setuptools/setuptools-41.0.1/setuptools/version.py", line 1, in <module>
    import pkg_resources
  File "/data/sources/build/GC3Pie/2.5.2/dummy-dummy/setuptools/setuptools-41.0.1/pkg_resources/__init__.py", line 959, in <module>
    class Environment:
  File "/data/sources/build/GC3Pie/2.5.2/dummy-dummy/setuptools/setuptools-41.0.1/pkg_resources/__init__.py", line 963, in Environment
    self, search_path=None, platform=get_supported_platform(),
  File "/data/sources/build/GC3Pie/2.5.2/dummy-dummy/setuptools/setuptools-41.0.1/pkg_resources/__init__.py", line 190, in get_supported_platform
    plat = get_build_platform()
  File "/data/sources/build/GC3Pie/2.5.2/dummy-dummy/setuptools/setuptools-41.0.1/pkg_resources/__init__.py", line 393, in get_build_platform
    from sysconfig import get_platform
ImportError: No module named sysconfig
 (at easybuild/tools/run.py:501 in parse_cmd_output)
== 2019-10-27 14:02:03,189 easyblock.py:3053 WARNING build failed (first 300 chars): cmd " /usr/bin/python setup.py build " exited with exit code 1 and output:
Traceback (most recent call last):
  File "setup.py", line 11, in <module>
    import setuptools
  File "/data/sources/build/GC3Pie/2.5.2/dummy-dummy/setuptools/setuptools-41.0.1/setuptools/__init__.py", line 18, in <module>

[riccardomurri]

I get this error when trying to compile with EasyBuild

Looks like a more general error to me: the traceback points to a problem importing setuptools, so I guess EB is setting some wrong paths here? Anyway I don't think it's related to the issue with --job that was being discussed here, maybe open a new issue?

[nortex]

I get this error when trying to compile with EasyBuild

Looks like a more general error to me: the traceback points to a problem importing setuptools, so I guess EB is setting some wrong paths here? Anyway I don't think it's related to the issue with --job that was being discussed here, maybe open a new issue?

You are right, will open a new issue.