[Debian-med-packaging] Bug#1076925: snakemake: FTBFS: failing tests
Santiago Vila
sanvila at debian.org
Wed Jul 24 11:49:52 BST 2024
Package: src:snakemake
Version: 7.32.4-3
Severity: serious
Tags: ftbfs
Dear maintainer:
During a rebuild of all packages in unstable, your package failed to build:
--------------------------------------------------------------------------------
[...]
debian/rules binary
dh binary --with python3,sphinxdoc --buildsystem=pybuild
dh_update_autotools_config -O--buildsystem=pybuild
dh_autoreconf -O--buildsystem=pybuild
dh_auto_configure -O--buildsystem=pybuild
dh_auto_build -O--buildsystem=pybuild
I: pybuild plugin_pyproject:129: Building wheel for python3.12 with "build" module
I: pybuild base:311: python3.12 -m build --skip-dependency-check --no-isolation --wheel --outdir /<<PKGBUILDDIR>>/.pybuild/cpython3_3.12_snakemake
* Building wheel...
running bdist_wheel
running build
running build_py
creating build
creating build/lib
[... snipped ...]
for f in os.listdir(path):
copy(os.path.join(path, f), tmpdir)
# Snakefile is now in temporary directory
snakefile = join(tmpdir, snakefile)
# run snakemake
if shellcmd:
if not shellcmd.startswith("snakemake"):
raise ValueError("shellcmd does not start with snakemake")
shellcmd = "{} -m {}".format(sys.executable, shellcmd)
try:
if sigint_after is None:
subprocess.run(
shellcmd,
cwd=path if no_tmpdir else tmpdir,
check=True,
shell=True,
stderr=subprocess.STDOUT,
stdout=subprocess.PIPE,
)
success = True
else:
with subprocess.Popen(
shlex.split(shellcmd),
cwd=path if no_tmpdir else tmpdir,
stderr=subprocess.STDOUT,
stdout=subprocess.PIPE,
) as process:
time.sleep(sigint_after)
process.send_signal(signal.SIGINT)
time.sleep(2)
success = process.returncode == 0
except subprocess.CalledProcessError as e:
success = False
print(e.stdout.decode(), file=sys.stderr)
else:
assert sigint_after is None, "Cannot sent SIGINT when calling directly"
success = snakemake(
snakefile=original_snakefile if no_tmpdir else snakefile,
cores=cores,
nodes=nodes,
workdir=path if no_tmpdir else tmpdir,
stats="stats.txt",
config=config,
verbose=True,
targets=targets,
conda_frontend=conda_frontend,
container_image=container_image,
overwrite_resource_scopes=(
ResourceScopes(overwrite_resource_scopes)
if overwrite_resource_scopes is not None
else overwrite_resource_scopes
),
**params,
)
if shouldfail:
assert not success, "expected error on execution"
else:
if not success:
print("Workdir:")
print_tree(tmpdir, exclude=".snakemake/conda")
> assert success, "expected successful execution"
E AssertionError: expected successful execution
.pybuild/cpython3_3.12_snakemake/build/tests/common.py:259: AssertionError
----------------------------- Captured stdout call -----------------------------
Workdir:
snakemake-pmpd9u7i/
Snakefile
.snakemake/
log/
2024-07-23T024036.012256.snakemake.log
locks/
singularity/
incomplete/
metadata/
auxiliary/
shadow/
expected-results/
.gitignore
----------------------------- Captured stderr call -----------------------------
Building DAG of jobs...
Using shell: /usr/bin/bash
Provided cores: 3
Rules claiming more threads will be scaled down.
Job stats:
job count
----- -------
2 3
3 1
all 1
total 5
Resources before job selection: {'_cores': 3, '_nodes': 9223372036854775807}
Ready jobs (1)
Select jobs to execute...
Using greedy selector because only single job has to be scheduled.
Selected jobs (1)
Resources after job selection: {'_cores': 2, '_nodes': 9223372036854775806}
[Tue Jul 23 02:40:36 2024]
rule 3:
output: test.in
jobid: 2
reason: Missing output files: test.in
resources: tmpdir=/tmp
/tmp/snakemake-pmpd9u7i/Snakefile:4: UserWarning: pytools.persistent_dict 'mystorage': enabling safe_sync as default. This provides strong protection against data loss, but can be unnecessarily expensive for use cases such as caches.Pass 'safe_sync=False' if occasional data loss is tolerable. Pass 'safe_sync=True' to suppress this warning.
storage = PersistentDict("mystorage")
Building DAG of jobs...
Using shell: /usr/bin/bash
Provided cores: 3
Rules claiming more threads will be scaled down.
Select jobs to execute...
[Tue Jul 23 02:40:36 2024]
Error in rule 3:
jobid: 0
output: test.in
RuleException:
ProgrammingError in file /tmp/snakemake-pmpd9u7i/Snakefile, line 26:
SQLite objects created in a thread can only be used in that same thread. The object was created in thread id 140638792650880 and this is thread id 140638741497536.
File "/tmp/snakemake-pmpd9u7i/Snakefile", line 26, in __rule_3
File "/usr/lib/python3/dist-packages/pytools/persistent_dict.py", line 783, in store
File "/usr/lib/python3/dist-packages/pytools/persistent_dict.py", line 533, in _exec_sql
File "/usr/lib/python3/dist-packages/pytools/persistent_dict.py", line 545, in _exec_sql_fn
File "/usr/lib/python3/dist-packages/pytools/persistent_dict.py", line 531, in execute
File "/usr/lib/python3.12/concurrent/futures/thread.py", line 58, in run
Shutting down, this might take some time.
Exiting because a job execution failed. Look above for error message
Shutting down, this might take some time.
Exiting because a job execution failed. Look above for error message
Complete log: .snakemake/log/2024-07-23T024036.012256.snakemake.log
unlocking
removing lock
removing lock
removed all locks
------------------------------ Captured log call -------------------------------
WARNING snakemake.logging:logging.py:580 Building DAG of jobs...
WARNING snakemake.logging:logging.py:580 Using shell: /usr/bin/bash
WARNING snakemake.logging:logging.py:588 Provided cores: 3
WARNING snakemake.logging:logging.py:588 Rules claiming more threads will be scaled down.
WARNING snakemake.logging:logging.py:590 Job stats:
job count
----- -------
2 3
3 1
all 1
total 5
DEBUG snakemake.logging:logging.py:586 Resources before job selection: {'_cores': 3, '_nodes': 9223372036854775807}
DEBUG snakemake.logging:logging.py:586 Ready jobs (1)
WARNING snakemake.logging:logging.py:580 Select jobs to execute...
DEBUG snakemake.logging:logging.py:586 Using greedy selector because only single job has to be scheduled.
DEBUG snakemake.logging:logging.py:586 Selected jobs (1)
DEBUG snakemake.logging:logging.py:586 Resources after job selection: {'_cores': 2, '_nodes': 9223372036854775806}
INFO snakemake.logging:logging.py:498
INFO snakemake.logging:logging.py:492 [Tue Jul 23 02:40:36 2024]
INFO snakemake.logging:logging.py:505 rule 3:
output: test.in
jobid: 2
reason: Missing output files: test.in
resources: tmpdir=/tmp
INFO snakemake.logging:logging.py:512
WARNING snakemake.logging:logging.py:580 Shutting down, this might take some time.
ERROR snakemake.logging:logging.py:584 Exiting because a job execution failed. Look above for error message
WARNING snakemake.logging:logging.py:580 Complete log: .snakemake/log/2024-07-23T024036.012256.snakemake.log
DEBUG snakemake.logging:logging.py:586 unlocking
DEBUG snakemake.logging:logging.py:586 removing lock
DEBUG snakemake.logging:logging.py:586 removing lock
DEBUG snakemake.logging:logging.py:586 removed all locks
________________________________ test_issue328 _________________________________
def test_issue328():
try:
import pytools
> run(dpath("test_issue328"), forcerun=["split"])
.pybuild/cpython3_3.12_snakemake/build/tests/tests.py:489:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
path = '/<<PKGBUILDDIR>>/.pybuild/cpython3_3.12_snakemake/build/tests/test_issue328'
shouldfail = False, snakefile = '/tmp/snakemake-xyjl7tjt/Snakefile'
subpath = None, no_tmpdir = False, check_md5 = True, check_results = True
cores = 3, nodes = None, set_pythonpath = True, cleanup = True
conda_frontend = 'mamba', config = {}, targets = None
container_image = 'snakemake/snakemake:latest', shellcmd = None
sigint_after = None, overwrite_resource_scopes = None
params = {'forcerun': ['split']}
results_dir = '/<<PKGBUILDDIR>>/.pybuild/cpython3_3.12_snakemake/build/tests/test_issue328/expected-results'
original_snakefile = '/<<PKGBUILDDIR>>/.pybuild/cpython3_3.12_snakemake/build/tests/test_issue328/Snakefile'
tmpdir = '/tmp/snakemake-xyjl7tjt', f = 'in.txt', success = False
def run(
path,
shouldfail=False,
snakefile="Snakefile",
subpath=None,
no_tmpdir=False,
check_md5=True,
check_results=None,
cores=3,
nodes=None,
set_pythonpath=True,
cleanup=True,
conda_frontend="mamba",
config=dict(),
targets=None,
container_image=os.environ.get("CONTAINER_IMAGE", "snakemake/snakemake:latest"),
shellcmd=None,
sigint_after=None,
overwrite_resource_scopes=None,
**params,
):
"""
Test the Snakefile in the path.
There must be a Snakefile in the path and a subdirectory named
expected-results. If cleanup is False, we return the temporary
directory to the calling test for inspection, and the test should
clean it up.
"""
if check_results is None:
if not shouldfail:
check_results = True
else:
check_results = False
if set_pythonpath:
# Enforce current workdir (the snakemake source dir) to also be in PYTHONPATH
# when subprocesses are invoked in the tempdir defined below.
os.environ["PYTHONPATH"] = os.getcwd()
elif "PYTHONPATH" in os.environ:
del os.environ["PYTHONPATH"]
results_dir = join(path, "expected-results")
original_snakefile = join(path, snakefile)
assert os.path.exists(original_snakefile)
assert os.path.exists(results_dir) and os.path.isdir(
results_dir
), "{} does not exist".format(results_dir)
# If we need to further check results, we won't cleanup tmpdir
tmpdir = next(tempfile._get_candidate_names())
tmpdir = os.path.join(tempfile.gettempdir(), "snakemake-%s" % tmpdir)
os.mkdir(tmpdir)
config = dict(config)
# handle subworkflow
if subpath is not None:
# set up a working directory for the subworkflow and pass it in `config`
# for now, only one subworkflow is supported
assert os.path.exists(subpath) and os.path.isdir(
subpath
), "{} does not exist".format(subpath)
subworkdir = os.path.join(tmpdir, "subworkdir")
os.mkdir(subworkdir)
# copy files
for f in os.listdir(subpath):
copy(os.path.join(subpath, f), subworkdir)
config["subworkdir"] = subworkdir
# copy files
for f in os.listdir(path):
copy(os.path.join(path, f), tmpdir)
# Snakefile is now in temporary directory
snakefile = join(tmpdir, snakefile)
# run snakemake
if shellcmd:
if not shellcmd.startswith("snakemake"):
raise ValueError("shellcmd does not start with snakemake")
shellcmd = "{} -m {}".format(sys.executable, shellcmd)
try:
if sigint_after is None:
subprocess.run(
shellcmd,
cwd=path if no_tmpdir else tmpdir,
check=True,
shell=True,
stderr=subprocess.STDOUT,
stdout=subprocess.PIPE,
)
success = True
else:
with subprocess.Popen(
shlex.split(shellcmd),
cwd=path if no_tmpdir else tmpdir,
stderr=subprocess.STDOUT,
stdout=subprocess.PIPE,
) as process:
time.sleep(sigint_after)
process.send_signal(signal.SIGINT)
time.sleep(2)
success = process.returncode == 0
except subprocess.CalledProcessError as e:
success = False
print(e.stdout.decode(), file=sys.stderr)
else:
assert sigint_after is None, "Cannot sent SIGINT when calling directly"
success = snakemake(
snakefile=original_snakefile if no_tmpdir else snakefile,
cores=cores,
nodes=nodes,
workdir=path if no_tmpdir else tmpdir,
stats="stats.txt",
config=config,
verbose=True,
targets=targets,
conda_frontend=conda_frontend,
container_image=container_image,
overwrite_resource_scopes=(
ResourceScopes(overwrite_resource_scopes)
if overwrite_resource_scopes is not None
else overwrite_resource_scopes
),
**params,
)
if shouldfail:
assert not success, "expected error on execution"
else:
if not success:
print("Workdir:")
print_tree(tmpdir, exclude=".snakemake/conda")
> assert success, "expected successful execution"
E AssertionError: expected successful execution
.pybuild/cpython3_3.12_snakemake/build/tests/common.py:259: AssertionError
----------------------------- Captured stdout call -----------------------------
Workdir:
snakemake-xyjl7tjt/
Snakefile
in.txt
.snakemake/
log/
2024-07-23T024223.243912.snakemake.log
locks/
singularity/
incomplete/
aW5fX19zbmFrZW1ha2VfZHluYW1pY19fLnR4dA==
metadata/
auxiliary/
shadow/
expected-results/
out.txt
----------------------------- Captured stderr call -----------------------------
Building DAG of jobs...
Using shell: /usr/bin/bash
Provided cores: 3
Rules claiming more threads will be scaled down.
Job stats:
job count
----- -------
merge 1
split 1
total 2
Resources before job selection: {'_cores': 3, '_nodes': 9223372036854775807}
Ready jobs (1)
Select jobs to execute...
Using greedy selector because only single job has to be scheduled.
Selected jobs (1)
Resources after job selection: {'_cores': 2, '_nodes': 9223372036854775806}
[Tue Jul 23 02:42:23 2024]
rule split:
input: in.txt
output: in_{*}.txt (dynamic)
jobid: 1
reason: Forced execution
resources: tmpdir=/tmp
Subsequent jobs will be added dynamically depending on the output of this job
/tmp/snakemake-xyjl7tjt/Snakefile:4: UserWarning: pytools.persistent_dict 'storage': enabling safe_sync as default. This provides strong protection against data loss, but can be unnecessarily expensive for use cases such as caches.Pass 'safe_sync=False' if occasional data loss is tolerable. Pass 'safe_sync=True' to suppress this warning.
storage = PersistentDict("storage")
Building DAG of jobs...
Using shell: /usr/bin/bash
Provided cores: 3
Rules claiming more threads will be scaled down.
Select jobs to execute...
Subsequent jobs will be added dynamically depending on the output of this job
[Tue Jul 23 02:42:23 2024]
Error in rule split:
jobid: 0
input: in.txt
output: in_{*}.txt (dynamic)
RuleException:
ProgrammingError in file /tmp/snakemake-xyjl7tjt/Snakefile, line 21:
SQLite objects created in a thread can only be used in that same thread. The object was created in thread id 140306412494976 and this is thread id 140306361636544.
File "/tmp/snakemake-xyjl7tjt/Snakefile", line 21, in __rule_split
File "/usr/lib/python3/dist-packages/pytools/persistent_dict.py", line 576, in __getitem__
File "/usr/lib/python3/dist-packages/pytools/persistent_dict.py", line 789, in fetch
File "/usr/lib/python3/dist-packages/pytools/persistent_dict.py", line 533, in _exec_sql
File "/usr/lib/python3/dist-packages/pytools/persistent_dict.py", line 545, in _exec_sql_fn
File "/usr/lib/python3/dist-packages/pytools/persistent_dict.py", line 531, in execute
File "/usr/lib/python3.12/concurrent/futures/thread.py", line 58, in run
Shutting down, this might take some time.
Exiting because a job execution failed. Look above for error message
Shutting down, this might take some time.
Exiting because a job execution failed. Look above for error message
Complete log: .snakemake/log/2024-07-23T024223.243912.snakemake.log
unlocking
removing lock
removing lock
removed all locks
------------------------------ Captured log call -------------------------------
WARNING snakemake.logging:logging.py:580 Building DAG of jobs...
WARNING snakemake.logging:logging.py:580 Using shell: /usr/bin/bash
WARNING snakemake.logging:logging.py:588 Provided cores: 3
WARNING snakemake.logging:logging.py:588 Rules claiming more threads will be scaled down.
WARNING snakemake.logging:logging.py:590 Job stats:
job count
----- -------
merge 1
split 1
total 2
DEBUG snakemake.logging:logging.py:586 Resources before job selection: {'_cores': 3, '_nodes': 9223372036854775807}
DEBUG snakemake.logging:logging.py:586 Ready jobs (1)
WARNING snakemake.logging:logging.py:580 Select jobs to execute...
DEBUG snakemake.logging:logging.py:586 Using greedy selector because only single job has to be scheduled.
DEBUG snakemake.logging:logging.py:586 Selected jobs (1)
DEBUG snakemake.logging:logging.py:586 Resources after job selection: {'_cores': 2, '_nodes': 9223372036854775806}
INFO snakemake.logging:logging.py:498
INFO snakemake.logging:logging.py:492 [Tue Jul 23 02:42:23 2024]
INFO snakemake.logging:logging.py:505 rule split:
input: in.txt
output: in_{*}.txt (dynamic)
jobid: 1
reason: Forced execution
resources: tmpdir=/tmp
INFO snakemake.logging:logging.py:512
WARNING snakemake.logging:logging.py:580 Subsequent jobs will be added dynamically depending on the output of this job
WARNING snakemake.logging:logging.py:580 Shutting down, this might take some time.
ERROR snakemake.logging:logging.py:584 Exiting because a job execution failed. Look above for error message
WARNING snakemake.logging:logging.py:580 Complete log: .snakemake/log/2024-07-23T024223.243912.snakemake.log
DEBUG snakemake.logging:logging.py:586 unlocking
DEBUG snakemake.logging:logging.py:586 removing lock
DEBUG snakemake.logging:logging.py:586 removing lock
DEBUG snakemake.logging:logging.py:586 removed all locks
=============================== warnings summary ===============================
tests/test_schema.py: 12 warnings
tests/tests.py: 6 warnings
/<<PKGBUILDDIR>>/.pybuild/cpython3_3.12_snakemake/build/snakemake/utils.py:50: DeprecationWarning: jsonschema.RefResolver is deprecated as of v4.18.0, in favor of the https://github.com/python-jsonschema/referencing library, which provides more compliant referencing behavior as well as more flexible APIs for customization. A future release will remove RefResolver. Please file a feature request (on referencing) if you are missing an API for the kind of customization you need.
from jsonschema import validators, RefResolver
tests/testapi.py::test_keep_logger
/usr/lib/python3/dist-packages/stopit/__init__.py:10: DeprecationWarning: pkg_resources is deprecated as an API. See https://setuptools.pypa.io/en/latest/pkg_resources.html
import pkg_resources
tests/testapi.py::test_lockexception
/usr/lib/python3/dist-packages/_pytest/python.py:166: PytestReturnNotNoneWarning: Expected None, but tests/testapi.py::test_lockexception returned True, which will be an error in a future version of pytest. Did you mean to use `assert` instead of `return`?
warnings.warn(
tests/tests.py::test_persistent_dict
/tmp/snakemake-pmpd9u7i/Snakefile:4: UserWarning: pytools.persistent_dict 'mystorage': enabling safe_sync as default. This provides strong protection against data loss, but can be unnecessarily expensive for use cases such as caches.Pass 'safe_sync=False' if occasional data loss is tolerable. Pass 'safe_sync=True' to suppress this warning.
storage = PersistentDict("mystorage")
tests/tests.py::test_issue328
/tmp/snakemake-xyjl7tjt/Snakefile:4: UserWarning: pytools.persistent_dict 'storage': enabling safe_sync as default. This provides strong protection against data loss, but can be unnecessarily expensive for use cases such as caches.Pass 'safe_sync=False' if occasional data loss is tolerable. Pass 'safe_sync=True' to suppress this warning.
storage = PersistentDict("storage")
-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
=========================== short test summary info ============================
FAILED .pybuild/cpython3_3.12_snakemake/build/tests/tests.py::test_persistent_dict
FAILED .pybuild/cpython3_3.12_snakemake/build/tests/tests.py::test_issue328
= 2 failed, 256 passed, 46 skipped, 90 deselected, 1 xfailed, 22 warnings in 1124.50s (0:18:44) =
E: pybuild pybuild:389: test: plugin custom failed with: exit code=1: python3.12 -m pytest -o faulthandler_timeout=60 -v /<<PKGBUILDDIR>>/.pybuild/cpython3_3.12_snakemake/build/tests/test*.py -k 'not test_cwl and not test_cwl_singularity and not test_url_include and not test_wrapper and not test_issue1083 and not test_github_issue78 and not test_container and not test_singularity and not test_singularity_conda and not test_convert_to_cwl and not test_report and not test_report_zip and not test_archive and not test_jupyter_notebook and not test_conda and not test_upstream_conda and not test_conda_custom_prefix and not test_script and not test_issue635 and not test_issue1093 and not test_default_resources and not test_default_remote and not test_remote and not test_output_file_cache_remote and not test_tibanna and not test_module_complex and not test_module_complex2 and not test_module_with_script and not test_module_report and not test_modules_meta_wrapper and not test_tes and not test_deploy_script and not test_deploy_hashing and not test_peppy and not test_modules_peppy and not test_report_display_code and not test_wrapper_local_git_prefix and not test_github_issue1396 and not test_az_batch_executor and not test_modules_prefix and not test_ancient and not test_github_issue1062 and not test_symlink_time_handling and not test_env_modules and not test_github_issue1460 and not test_rule_inheritance_globals and not test_prebuilt_conda_script'
dh_auto_test: error: pybuild --test --test-pytest -i python{version} -p 3.12 returned exit code 13
make[1]: *** [debian/rules:59: override_dh_auto_test] Error 25
make[1]: Leaving directory '/<<PKGBUILDDIR>>'
make: *** [debian/rules:46: binary] Error 2
dpkg-buildpackage: error: debian/rules binary subprocess returned exit status 2
--------------------------------------------------------------------------------
The above is just how the build ends and not necessarily the most relevant part.
If required, the full build log is available here:
https://people.debian.org/~sanvila/build-logs/202407/
About the archive rebuild: The build was made on virtual machines
of type m6a.large and r6a.large from AWS, using sbuild and a
reduced chroot with only build-essential packages.
If you could not reproduce the bug please contact me privately, as I
am willing to provide ssh access to a virtual machine where the bug is
fully reproducible.
If this is really a bug in one of the build-depends, please use
reassign and affects, so that this is still visible in the BTS web
page for this package.
Thanks.
More information about the Debian-med-packaging
mailing list