# HG changeset patch # User agpetit # Date 1653923091 0 # Node ID a7128cd8f0e15f460f73ed8b126d6baa04554f6b # Parent e504457035e5308ce7cd6dd6d391e536054120bf "planemo upload for repository https://github.com/mesocentre-clermont-auvergne/aubi_piaf commit b6488400d4478d46697019485e912c38ea2202a5-dirty" diff -r e504457035e5 -r a7128cd8f0e1 run_installed_tests.html --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/run_installed_tests.html Mon May 30 15:04:51 2022 +0000 @@ -0,0 +1,920 @@ + + + + + Test Report + + + +

run_installed_tests.html

+

Report generated on 30-May-2022 at 16:40:20 by pytest-html v3.1.1

+

Environment

+ + + + + + + + + + + + +
Packages{"pluggy": "1.0.0", "py": "1.11.0", "pytest": "6.2.5"}
PlatformLinux-5.13.0-44-generic-x86_64-with-glibc2.29
Plugins{"anyio": "3.5.0", "asyncio": "0.17.2", "celery": "0.0.0", "cov": "3.0.0", "html": "3.1.1", "json-report": "1.4.1", "metadata": "1.11.0", "mock": "3.7.0", "postgresql": "4.1.0", "pythonpath": "0.7.3", "shard": "0.1.2"}
Python3.8.10
+

Summary

+

6 tests ran in 207.85 seconds.

+ 4 passed, 0 skipped, 2 failed, 0 errors, 0 expected failures, 0 unexpected passes +

Results

+ + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + +
ResultTestDurationLinks
Failedtest/functional/test_toolbox_pytest.py::test_tool[testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0_test_1]41.70
+
testcases = ('testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0_test_1', <functional.test_toolbox.TestForTool_testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0 testMethod=runTest>, 0)
driver = <functional.test_toolbox_pytest.DefaultGalaxyTestDriver object at 0x7fbd7dccadc0>

@pytest.mark.parametrize("testcases", cases(), ids=idfn)
def test_tool(testcases, driver):
test = testcases[1]
> test.do_it(test_index=testcases[2])

test/functional/test_toolbox_pytest.py:84:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
test/functional/test_toolbox.py:35: in do_it
verify_tool(tool_id, self.galaxy_interactor, resource_parameters=resource_parameters, test_index=test_index, tool_version=tool_version, register_job_data=register_job_data)
lib/galaxy/tool_util/verify/interactor.py:1127: in verify_tool
raise e
lib/galaxy/tool_util/verify/interactor.py:1123: in verify_tool
job_stdio = _verify_outputs(testdef, test_history, jobs, data_list, data_collection_list, galaxy_interactor, quiet=quiet)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

testdef = <galaxy.tool_util.verify.interactor.ToolTestDescription object at 0x7fbd717e2400>, history = '54f2a3a23292eb07'
jobs = [{'create_time': '2022-05-30T14:38:35.742760', 'exit_code': None, 'galaxy_version': '22.01', 'history_id': '54f2a3a23292eb07', ...}]
data_list = {'cut_log': {'create_time': '2022-05-30T14:38:35.746121', 'data_type': 'galaxy.datatypes.data.Text', 'deleted': False,...b446aa50-6cfd-42d4-a1ed-d388b4035422', 'validated_state': 'unknown', 'validated_state_message': None, 'visible': True}}
data_collection_list = {'output_traj': {'collection_type': 'list', 'contents_url': '/api/dataset_collections/5729865256bc2525/contents/5729865256bc2525', 'create_time': '2022-05-30T14:38:35.744675', 'deleted': False, ...}}
galaxy_interactor = <galaxy.tool_util.verify.interactor.GalaxyInteractorApi object at 0x7fbd2509c1f0>, quiet = False

def _verify_outputs(testdef, history, jobs, data_list, data_collection_list, galaxy_interactor, quiet=False):
assert len(jobs) == 1, "Test framework logic error, somehow tool test resulted in more than one job."
job = jobs[0]

found_exceptions = []

def register_exception(e):
if not found_exceptions and not quiet:
# Only print this stuff out once.
for stream in ['stdout', 'stderr']:
if stream in job_stdio:
print(_format_stream(job_stdio[stream], stream=stream, format=True), file=sys.stderr)
found_exceptions.append(e)

if testdef.expect_failure:
if testdef.outputs:
raise Exception("Cannot specify outputs in a test expecting failure.")

maxseconds = testdef.maxseconds
# Wait for the job to complete and register expections if the final
# status was not what test was expecting.
job_failed = False
try:
galaxy_interactor.wait_for_job(job['id'], history, maxseconds)
except Exception as e:
job_failed = True
if not testdef.expect_failure:
found_exceptions.append(e)

job_stdio = galaxy_interactor.get_job_stdio(job['id'])

if testdef.num_outputs is not None:
expected = testdef.num_outputs
actual = len(data_list) + len(data_collection_list)
if expected != actual:
message = f"Incorrect number of outputs - expected {expected}, found {actual}: datasets {data_list.keys()} collections {data_collection_list.keys()}"
error = AssertionError(message)
register_exception(error)

if not job_failed and testdef.expect_failure:
error = AssertionError("Expected job to fail but Galaxy indicated the job successfully completed.")
register_exception(error)

expect_exit_code = testdef.expect_exit_code
if expect_exit_code is not None:
exit_code = job_stdio["exit_code"]
if str(expect_exit_code) != str(exit_code):
error = AssertionError(f"Expected job to complete with exit code {expect_exit_code}, found {exit_code}")
register_exception(error)

for output_index, output_dict in enumerate(testdef.outputs):
# Get the correct hid
name = output_dict["name"]
outfile = output_dict["value"]
attributes = output_dict["attributes"]
output_testdef = Bunch(name=name, outfile=outfile, attributes=attributes)
try:
output_data = data_list[name]
except (TypeError, KeyError):
# Legacy - fall back on ordered data list access if data_list is
# just a list (case with twill variant or if output changes its
# name).
if hasattr(data_list, "values"):
output_data = list(data_list.values())[output_index]
else:
output_data = data_list[len(data_list) - len(testdef.outputs) + output_index]
assert output_data is not None
try:
galaxy_interactor.verify_output(history, jobs, output_data, output_testdef=output_testdef, tool_id=job['tool_id'], maxseconds=maxseconds, tool_version=testdef.tool_version)
except Exception as e:
register_exception(e)

other_checks = {
"command_line": "Command produced by the job",
"command_version": "Tool version indicated during job execution",
"stdout": "Standard output of the job",
"stderr": "Standard error of the job",
}
# TODO: Only hack the stdio like this for older profile, for newer tool profiles
# add some syntax for asserting job messages maybe - or just drop this because exit
# code and regex on stdio can be tested directly - so this is really testing Galaxy
# core handling more than the tool.
job_messages = job_stdio.get("job_messages") or []
stdout_prefix = ""
stderr_prefix = ""
for job_message in job_messages:
message_type = job_message.get("type")
if message_type == "regex" and job_message.get("stream") == "stderr":
stderr_prefix += f"{job_message.get('desc') or ''}\n"
elif message_type == "regex" and job_message.get("stream") == "stdout":
stdout_prefix += f"{job_message.get('desc') or ''}\n"
elif message_type == "exit_code":
stderr_prefix += f"{job_message.get('desc') or ''}\n"
else:
raise Exception(f"Unknown job message type [{message_type}] in [{job_message}]")

for what, description in other_checks.items():
if getattr(testdef, what, None) is not None:
try:
raw_data = job_stdio[what]
assertions = getattr(testdef, what)
if what == "stdout":
data = stdout_prefix + raw_data
elif what == "stderr":
data = stderr_prefix + raw_data
else:
data = raw_data
verify_assertions(data, assertions)
except AssertionError as err:
errmsg = f'{description} different than expected\n'
errmsg += util.unicodify(err)
register_exception(AssertionError(errmsg))

for output_collection_def in testdef.output_collections:
try:
name = output_collection_def.name
# TODO: data_collection_list is clearly a bad name for dictionary.
if name not in data_collection_list:
message = f"Failed to find output [{name}], tool outputs include [{','.join(data_collection_list.keys())}]"
raise AssertionError(message)

# Data collection returned from submission, elements may have been populated after
# the job completed so re-hit the API for more information.
data_collection_id = data_collection_list[name]["id"]
galaxy_interactor.verify_output_collection(output_collection_def, data_collection_id, history, job['tool_id'])
except Exception as e:
register_exception(e)

if found_exceptions and not testdef.expect_test_failure:
> raise JobOutputsError(found_exceptions, job_stdio)
E galaxy.tool_util.verify.interactor.JobOutputsError: Output cut_log: different than expected, difference (using diff):
E ( /tmp/tmppchetkzbcut_trajectories_file.log v. /tmp/tmpt35t2o_2cut_trajectories_file.log )
E --- local_file
E +++ history_data
E @@ -25,9 +25,9 @@
E
E :-) GROMACS - gmx trjconv, 2022.1-conda_forge (-:
E
E -Executable: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1/bin.AVX2_256/gmx
E -Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1
E -Working dir: /tmp/tmp87fei_xs/job_working_directory/000/5/working
E +Executable: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296/bin.AVX2_256/gmx
E +Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296
E +Working dir: /tmp/tmpudbcnm66/job_working_directory/000/11/working
E Command line:
E gmx trjconv -f PIP2.1_test.xtc -s PIP2.1_test.gro -b 0 -e 20 -o out/PIP2.1_test_traj_1.xtc
E
E @@ -63,16 +63,16 @@
E Last written: frame 2 time 20.000
E
E
E -GROMACS reminds you: "The Microsecond is Within Reach" (P.J. Van Maaren)
E +GROMACS reminds you: "Unlike teachers or doctors, our efforts improve the lives of people we'll never meet." (Katie Busch-Sorensen)
E
E Note that major changes are planned in future for trjconv, to improve usability and utility.
E Select group for output
E Selected 0: 'System'
E ********
E *SNIP *
E ********
E +GROMACS reminds you: "What about my nose?" (Aneesur Rahman, responding to an Argonne manager arguing the long hair of Charles Bennett in his group was disreputing the lab; Retold by Michael Klein)
E
E Note that major changes are planned in future for trjconv, to improve usability and utility.
E Select group for output
E Selected 0: 'System'
E :-) GROMACS - gmx trjconv, 2022.1-conda_forge (-:
E
E -Executable: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1/bin.AVX2_256/gmx
E -Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1
E -Working dir: /tmp/tmp87fei_xs/job_working_directory/000/5/working
E +Executable: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296/bin.AVX2_256/gmx
E +Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296
E +Working dir: /tmp/tmpudbcnm66/job_working_directory/000/11/working
E Command line:
E gmx trjconv -f PIP2.1_test.xtc -s PIP2.1_test.gro -b 60 -e 80 -o out/PIP2.1_test_traj_3.xtc
E
E @@ -155,7 +155,7 @@
E Last written: frame 2 time 80.000
E
E
E -GROMACS reminds you: "Furious activity is no substitute for understanding." (H.H. Williams)
E +GROMACS reminds you: "There's so many shades of black" (The Raconteurs)
E
E Note that major changes are planned in future for trjconv, to improve usability and utility.
E Select group for output

lib/galaxy/tool_util/verify/interactor.py:1299: JobOutputsError
------------------------------Captured stderr call------------------------------
2022-05-30 16:38:07,832 DEBUG [multipart.multipart] Calling on_field_start with no data +2022-05-30 16:38:07,832 DEBUG [multipart.multipart] Calling on_field_name with data[0:4] +2022-05-30 16:38:07,833 DEBUG [multipart.multipart] Calling on_field_data with data[5:123] +2022-05-30 16:38:07,833 DEBUG [multipart.multipart] Calling on_field_end with no data +2022-05-30 16:38:07,833 DEBUG [multipart.multipart] Calling on_end with no data +2022-05-30 16:38:08,953 INFO [galaxy.tools] Validated and populated state for tool request (29.050 ms) +2022-05-30 16:38:08,960 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.145 ms) +2022-05-30 16:38:09,092 DEBUG [galaxy.tools.actions.upload] Checked uploads (132.576 ms) +2022-05-30 16:38:09,098 DEBUG [galaxy.tools.actions.upload] Created upload job (6.056 ms) +2022-05-30 16:38:09,122 INFO [galaxy.web_stack.handlers] (Job[id=8,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:38:09,852 INFO [galaxy.jobs.handler] (8) Job dispatched +2022-05-30 16:38:10,126 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/8/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/8/registry.xml' '/tmp/upload_params_i5a_w25s' '9:/tmp/tmpudbcnm66/job_working_directory/000/8/working/dataset_23d2a6f5-94b1-4d86-9f3f-a265f3acfe63_files:/tmp/tmpudbcnm66/files/2/3/d/dataset_23d2a6f5-94b1-4d86-9f3f-a265f3acfe63.dat'] +2022-05-30 16:38:18,031 INFO [galaxy.tools] Validated and populated state for tool request (29.267 ms) +2022-05-30 16:38:18,038 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.146 ms) +2022-05-30 16:38:18,189 DEBUG [galaxy.tools.actions.upload] Checked uploads (150.477 ms) +2022-05-30 16:38:18,195 DEBUG [galaxy.tools.actions.upload] Created upload job (6.006 ms) +2022-05-30 16:38:18,222 INFO [galaxy.web_stack.handlers] (Job[id=9,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:38:19,453 INFO [galaxy.jobs.handler] (9) Job dispatched +2022-05-30 16:38:19,600 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/9/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/9/registry.xml' '/tmp/upload_params_f8bxg9_p' '10:/tmp/tmpudbcnm66/job_working_directory/000/9/working/dataset_db8cec7e-182c-4956-ab6d-92d9562a59a0_files:/tmp/tmpudbcnm66/files/d/b/8/dataset_db8cec7e-182c-4956-ab6d-92d9562a59a0.dat'] +2022-05-30 16:38:26,862 INFO [galaxy.tools] Validated and populated state for tool request (22.705 ms) +2022-05-30 16:38:26,868 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.148 ms) +2022-05-30 16:38:26,990 DEBUG [galaxy.tools.actions.upload] Checked uploads (121.841 ms) +2022-05-30 16:38:26,997 DEBUG [galaxy.tools.actions.upload] Created upload job (6.363 ms) +2022-05-30 16:38:27,045 INFO [galaxy.web_stack.handlers] (Job[id=10,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:38:28,374 INFO [galaxy.jobs.handler] (10) Job dispatched +2022-05-30 16:38:28,534 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/10/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/10/registry.xml' '/tmp/upload_params_ta376p5u' '11:/tmp/tmpudbcnm66/job_working_directory/000/10/working/dataset_3d11862f-97ea-4b1f-9042-90ff10bf136a_files:/tmp/tmpudbcnm66/files/3/d/1/dataset_3d11862f-97ea-4b1f-9042-90ff10bf136a.dat'] +2022-05-30 16:38:35,702 INFO [galaxy.tools] Validated and populated state for tool request (25.700 ms) +2022-05-30 16:38:35,716 INFO [galaxy.tools.actions] Handled collection output named output_traj for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0 (2.649 ms) +2022-05-30 16:38:35,718 INFO [galaxy.tools.actions] Handled output named cut_log for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0 (2.191 ms) +2022-05-30 16:38:35,729 INFO [galaxy.tools.actions] Added output datasets to history (10.524 ms) +2022-05-30 16:38:35,731 INFO [galaxy.tools.actions] Setup for job Job[unflushed,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0] complete, ready to be enqueued (1.911 ms) +2022-05-30 16:38:35,771 INFO [galaxy.web_stack.handlers] (Job[id=11,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:38:36,103 INFO [galaxy.jobs.handler] (11) Job dispatched +2022-05-30 16:38:36,326 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/11/tool_script.sh] for tool command [[ "$(basename "$CONDA_DEFAULT_ENV")" = "$(basename '/home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296')" ] || { +MAX_TRIES=3 +COUNT=0 +while [ $COUNT -lt $MAX_TRIES ]; do + . '/home/aepetit/miniconda3/bin/activate' '/home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296' > conda_activate.log 2>&1 + if [ $? -eq 0 ];then + break + else + let COUNT=COUNT+1 + if [ $COUNT -eq $MAX_TRIES ];then + echo "Failed to activate conda environment! Error was:" + cat conda_activate.log + exit 1 + fi + sleep 10s + fi +done +} ; [ "$(basename "$CONDA_DEFAULT_ENV")" = "$(basename '/home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296')" ] || { +MAX_TRIES=3 +COUNT=0 +while [ $COUNT -lt $MAX_TRIES ]; do + . '/home/aepetit/miniconda3/bin/activate' '/home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296' > conda_activate.log 2>&1 + if [ $? -eq 0 ];then + break + else + let COUNT=COUNT+1 + if [ $COUNT -eq $MAX_TRIES ];then + echo "Failed to activate conda environment! Error was:" + cat conda_activate.log + exit 1 + fi + sleep 10s + fi +done +} ; ln -s '/tmp/tmpudbcnm66/files/2/3/d/dataset_23d2a6f5-94b1-4d86-9f3f-a265f3acfe63.dat' 'PIP2.1_test.gro' && ln -s '/tmp/tmpudbcnm66/files/d/b/8/dataset_db8cec7e-182c-4956-ab6d-92d9562a59a0.dat' 'PIP2.1_test.xtc' && ln -s '/tmp/tmpudbcnm66/files/3/d/1/dataset_3d11862f-97ea-4b1f-9042-90ff10bf136a.dat' 'estimated_number_of_sub_trajectories.tsv' && python '/tmp/tmpudbcnm66/shed_tools/testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/b9fb306ccb2a/cut_trajectory/cut_trajectory.py' --verbose --gro_file 'PIP2.1_test.gro' --xtc_file 'PIP2.1_test.xtc' --log_output 'out_log/cut_trajectories.log' --output_directory 'out/' --nbr_sub_traj 'estimated_number_of_sub_trajectories.tsv' --group_output 0 --number_cpus "${GALAXY_SLOTS:-1}"] +2022-05-30 16:38:47,856 INFO [galaxy.tool_util.verify] ## files diff on '/tmp/tmppchetkzbcut_trajectories_file.log' and '/tmp/tmpt35t2o_2cut_trajectories_file.log': lines_diff = 12, found diff = 24 +---------------------- >> begin tool stdout << ----------------------- + +----------------------- >> end tool stdout << ------------------------ + +---------------------- >> begin tool stderr << ----------------------- + +----------------------- >> end tool stderr << ------------------------ + +
-------------------------------Captured log call--------------------------------
DEBUG multipart.multipart:multipart.py:604 Calling on_field_start with no data +DEBUG multipart.multipart:multipart.py:601 Calling on_field_name with data[0:4] +DEBUG multipart.multipart:multipart.py:601 Calling on_field_data with data[5:123] +DEBUG multipart.multipart:multipart.py:604 Calling on_field_end with no data +DEBUG multipart.multipart:multipart.py:604 Calling on_end with no data
Failedtest/functional/test_toolbox_pytest.py::test_tool[testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0_test_2]45.94
+
testcases = ('testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0_test_2', <functional.test_toolbox.TestForTool_testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0 testMethod=runTest>, 1)
driver = <functional.test_toolbox_pytest.DefaultGalaxyTestDriver object at 0x7fbd7dccadc0>

@pytest.mark.parametrize("testcases", cases(), ids=idfn)
def test_tool(testcases, driver):
test = testcases[1]
> test.do_it(test_index=testcases[2])

test/functional/test_toolbox_pytest.py:84:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
test/functional/test_toolbox.py:35: in do_it
verify_tool(tool_id, self.galaxy_interactor, resource_parameters=resource_parameters, test_index=test_index, tool_version=tool_version, register_job_data=register_job_data)
lib/galaxy/tool_util/verify/interactor.py:1127: in verify_tool
raise e
lib/galaxy/tool_util/verify/interactor.py:1123: in verify_tool
job_stdio = _verify_outputs(testdef, test_history, jobs, data_list, data_collection_list, galaxy_interactor, quiet=quiet)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

testdef = <galaxy.tool_util.verify.interactor.ToolTestDescription object at 0x7fbd7aaba0d0>, history = '8155e4b4bf1581ff'
jobs = [{'create_time': '2022-05-30T14:39:20.051320', 'exit_code': None, 'galaxy_version': '22.01', 'history_id': '8155e4b4bf1581ff', ...}]
data_list = {'cut_log': {'create_time': '2022-05-30T14:39:20.055030', 'data_type': 'galaxy.datatypes.data.Text', 'deleted': False,...9bcf1c61-a26b-4578-9eb2-b93eb3b0d2d9', 'validated_state': 'unknown', 'validated_state_message': None, 'visible': True}}
data_collection_list = {'output_traj': {'collection_type': 'list', 'contents_url': '/api/dataset_collections/54f2a3a23292eb07/contents/54f2a3a23292eb07', 'create_time': '2022-05-30T14:39:20.052784', 'deleted': False, ...}}
galaxy_interactor = <galaxy.tool_util.verify.interactor.GalaxyInteractorApi object at 0x7fbd2509c1f0>, quiet = False

def _verify_outputs(testdef, history, jobs, data_list, data_collection_list, galaxy_interactor, quiet=False):
assert len(jobs) == 1, "Test framework logic error, somehow tool test resulted in more than one job."
job = jobs[0]

found_exceptions = []

def register_exception(e):
if not found_exceptions and not quiet:
# Only print this stuff out once.
for stream in ['stdout', 'stderr']:
if stream in job_stdio:
print(_format_stream(job_stdio[stream], stream=stream, format=True), file=sys.stderr)
found_exceptions.append(e)

if testdef.expect_failure:
if testdef.outputs:
raise Exception("Cannot specify outputs in a test expecting failure.")

maxseconds = testdef.maxseconds
# Wait for the job to complete and register expections if the final
# status was not what test was expecting.
job_failed = False
try:
galaxy_interactor.wait_for_job(job['id'], history, maxseconds)
except Exception as e:
job_failed = True
if not testdef.expect_failure:
found_exceptions.append(e)

job_stdio = galaxy_interactor.get_job_stdio(job['id'])

if testdef.num_outputs is not None:
expected = testdef.num_outputs
actual = len(data_list) + len(data_collection_list)
if expected != actual:
message = f"Incorrect number of outputs - expected {expected}, found {actual}: datasets {data_list.keys()} collections {data_collection_list.keys()}"
error = AssertionError(message)
register_exception(error)

if not job_failed and testdef.expect_failure:
error = AssertionError("Expected job to fail but Galaxy indicated the job successfully completed.")
register_exception(error)

expect_exit_code = testdef.expect_exit_code
if expect_exit_code is not None:
exit_code = job_stdio["exit_code"]
if str(expect_exit_code) != str(exit_code):
error = AssertionError(f"Expected job to complete with exit code {expect_exit_code}, found {exit_code}")
register_exception(error)

for output_index, output_dict in enumerate(testdef.outputs):
# Get the correct hid
name = output_dict["name"]
outfile = output_dict["value"]
attributes = output_dict["attributes"]
output_testdef = Bunch(name=name, outfile=outfile, attributes=attributes)
try:
output_data = data_list[name]
except (TypeError, KeyError):
# Legacy - fall back on ordered data list access if data_list is
# just a list (case with twill variant or if output changes its
# name).
if hasattr(data_list, "values"):
output_data = list(data_list.values())[output_index]
else:
output_data = data_list[len(data_list) - len(testdef.outputs) + output_index]
assert output_data is not None
try:
galaxy_interactor.verify_output(history, jobs, output_data, output_testdef=output_testdef, tool_id=job['tool_id'], maxseconds=maxseconds, tool_version=testdef.tool_version)
except Exception as e:
register_exception(e)

other_checks = {
"command_line": "Command produced by the job",
"command_version": "Tool version indicated during job execution",
"stdout": "Standard output of the job",
"stderr": "Standard error of the job",
}
# TODO: Only hack the stdio like this for older profile, for newer tool profiles
# add some syntax for asserting job messages maybe - or just drop this because exit
# code and regex on stdio can be tested directly - so this is really testing Galaxy
# core handling more than the tool.
job_messages = job_stdio.get("job_messages") or []
stdout_prefix = ""
stderr_prefix = ""
for job_message in job_messages:
message_type = job_message.get("type")
if message_type == "regex" and job_message.get("stream") == "stderr":
stderr_prefix += f"{job_message.get('desc') or ''}\n"
elif message_type == "regex" and job_message.get("stream") == "stdout":
stdout_prefix += f"{job_message.get('desc') or ''}\n"
elif message_type == "exit_code":
stderr_prefix += f"{job_message.get('desc') or ''}\n"
else:
raise Exception(f"Unknown job message type [{message_type}] in [{job_message}]")

for what, description in other_checks.items():
if getattr(testdef, what, None) is not None:
try:
raw_data = job_stdio[what]
assertions = getattr(testdef, what)
if what == "stdout":
data = stdout_prefix + raw_data
elif what == "stderr":
data = stderr_prefix + raw_data
else:
data = raw_data
verify_assertions(data, assertions)
except AssertionError as err:
errmsg = f'{description} different than expected\n'
errmsg += util.unicodify(err)
register_exception(AssertionError(errmsg))

for output_collection_def in testdef.output_collections:
try:
name = output_collection_def.name
# TODO: data_collection_list is clearly a bad name for dictionary.
if name not in data_collection_list:
message = f"Failed to find output [{name}], tool outputs include [{','.join(data_collection_list.keys())}]"
raise AssertionError(message)

# Data collection returned from submission, elements may have been populated after
# the job completed so re-hit the API for more information.
data_collection_id = data_collection_list[name]["id"]
galaxy_interactor.verify_output_collection(output_collection_def, data_collection_id, history, job['tool_id'])
except Exception as e:
register_exception(e)

if found_exceptions and not testdef.expect_test_failure:
> raise JobOutputsError(found_exceptions, job_stdio)
E galaxy.tool_util.verify.interactor.JobOutputsError: Output cut_log: different than expected, difference (using diff):
E ( /tmp/tmp64i094o0cut_trajectories_no_file.log v. /tmp/tmpmbp6yd0kcut_trajectories_no_file.log )
E --- local_file
E +++ history_data
E @@ -23,9 +23,9 @@
E
E :-) GROMACS - gmx trjconv, 2022.1-conda_forge (-:
E
E -Executable: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1/bin.AVX2_256/gmx
E -Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1
E -Working dir: /tmp/tmp87fei_xs/job_working_directory/000/7/working
E +Executable: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296/bin.AVX2_256/gmx
E +Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296
E +Working dir: /tmp/tmpudbcnm66/job_working_directory/000/15/working
E Command line:
E gmx trjconv -f PIP2.1_test.xtc -s PIP2.1_test.gro -b 0 -e 20 -o out/PIP2.1_test_traj_1.xtc
E
E @@ -61,16 +61,16 @@
E Last written: frame 2 time 20.000
E
E
E -GROMACS reminds you: "It is now quite lawful for a Catholic woman to avoid pregnancy by a resort to mathematics, though she is still forbidden to resort to physics and chemistry." (Henry Louis Mencken)
E +GROMACS reminds you: "Pretend That You're Hercule Poirot" (TeX)
E
E Note that major changes are planned in future for trjconv, to improve usability and utility.
E Select group for output
E Selected 0: 'System'
E ********
E *SNIP *
E ********
E +GROMACS reminds you: "If it's a good idea, go ahead and do it. It's much easier to apologize than it is to get permission." (Grace Hopper, developer of COBOL)
E
E Note that major changes are planned in future for trjconv, to improve usability and utility.
E Select group for output
E Selected 0: 'System'
E :-) GROMACS - gmx trjconv, 2022.1-conda_forge (-:
E
E -Executable: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1/bin.AVX2_256/gmx
E -Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1
E -Working dir: /tmp/tmp87fei_xs/job_working_directory/000/7/working
E +Executable: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296/bin.AVX2_256/gmx
E +Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296
E +Working dir: /tmp/tmpudbcnm66/job_working_directory/000/15/working
E Command line:
E gmx trjconv -f PIP2.1_test.xtc -s PIP2.1_test.gro -b 60 -e 80 -o out/PIP2.1_test_traj_3.xtc
E
E @@ -153,7 +153,7 @@
E Last written: frame 2 time 80.000
E
E
E -GROMACS reminds you: "Whatever Happened to Pong ?" (F. Black)
E +GROMACS reminds you: "Oh My God ! It's the Funky Shit" (Beastie Boys)
E
E Note that major changes are planned in future for trjconv, to improve usability and utility.
E Select group for output

lib/galaxy/tool_util/verify/interactor.py:1299: JobOutputsError
------------------------------Captured stderr call------------------------------
2022-05-30 16:38:49,689 DEBUG [multipart.multipart] Calling on_field_start with no data +2022-05-30 16:38:49,689 DEBUG [multipart.multipart] Calling on_field_name with data[0:4] +2022-05-30 16:38:49,689 DEBUG [multipart.multipart] Calling on_field_data with data[5:123] +2022-05-30 16:38:49,689 DEBUG [multipart.multipart] Calling on_field_end with no data +2022-05-30 16:38:49,690 DEBUG [multipart.multipart] Calling on_end with no data +2022-05-30 16:38:50,819 INFO [galaxy.tools] Validated and populated state for tool request (23.182 ms) +2022-05-30 16:38:50,825 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.158 ms) +2022-05-30 16:38:50,943 DEBUG [galaxy.tools.actions.upload] Checked uploads (118.175 ms) +2022-05-30 16:38:50,952 DEBUG [galaxy.tools.actions.upload] Created upload job (8.520 ms) +2022-05-30 16:38:50,974 INFO [galaxy.web_stack.handlers] (Job[id=12,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:38:51,873 INFO [galaxy.jobs.handler] (12) Job dispatched +2022-05-30 16:38:52,023 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/12/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/12/registry.xml' '/tmp/upload_params_fm4vkooe' '16:/tmp/tmpudbcnm66/job_working_directory/000/12/working/dataset_835311dd-d3e5-4db2-bd98-274b2aa04186_files:/tmp/tmpudbcnm66/files/8/3/5/dataset_835311dd-d3e5-4db2-bd98-274b2aa04186.dat'] +2022-05-30 16:39:00,135 INFO [galaxy.tools] Validated and populated state for tool request (22.401 ms) +2022-05-30 16:39:00,141 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.169 ms) +2022-05-30 16:39:00,253 DEBUG [galaxy.tools.actions.upload] Checked uploads (111.316 ms) +2022-05-30 16:39:00,260 DEBUG [galaxy.tools.actions.upload] Created upload job (7.542 ms) +2022-05-30 16:39:00,290 INFO [galaxy.web_stack.handlers] (Job[id=13,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:39:00,589 INFO [galaxy.jobs.handler] (13) Job dispatched +2022-05-30 16:39:00,789 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/13/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/13/registry.xml' '/tmp/upload_params_porkb1x0' '17:/tmp/tmpudbcnm66/job_working_directory/000/13/working/dataset_93d9a3db-08e5-4c64-b4b8-6ea194b2ec67_files:/tmp/tmpudbcnm66/files/9/3/d/dataset_93d9a3db-08e5-4c64-b4b8-6ea194b2ec67.dat'] +2022-05-30 16:39:07,852 INFO [galaxy.tools] Validated and populated state for tool request (23.241 ms) +2022-05-30 16:39:07,858 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.145 ms) +2022-05-30 16:39:07,983 DEBUG [galaxy.tools.actions.upload] Checked uploads (124.879 ms) +2022-05-30 16:39:07,994 DEBUG [galaxy.tools.actions.upload] Created upload job (10.361 ms) +2022-05-30 16:39:08,024 INFO [galaxy.web_stack.handlers] (Job[id=14,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:39:09,254 INFO [galaxy.jobs.handler] (14) Job dispatched +2022-05-30 16:39:09,407 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/14/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/14/registry.xml' '/tmp/upload_params_zlwcb6g0' '18:/tmp/tmpudbcnm66/job_working_directory/000/14/working/dataset_89419396-ffd3-496c-9421-9534fdcdfb7b_files:/tmp/tmpudbcnm66/files/8/9/4/dataset_89419396-ffd3-496c-9421-9534fdcdfb7b.dat'] +2022-05-30 16:39:20,011 INFO [galaxy.tools] Validated and populated state for tool request (25.260 ms) +2022-05-30 16:39:20,024 INFO [galaxy.tools.actions] Handled collection output named output_traj for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0 (0.951 ms) +2022-05-30 16:39:20,025 INFO [galaxy.tools.actions] Handled output named cut_log for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0 (0.960 ms) +2022-05-30 16:39:20,036 INFO [galaxy.tools.actions] Added output datasets to history (11.339 ms) +2022-05-30 16:39:20,039 INFO [galaxy.tools.actions] Setup for job Job[unflushed,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0] complete, ready to be enqueued (1.890 ms) +2022-05-30 16:39:20,079 INFO [galaxy.web_stack.handlers] (Job[id=15,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/cut_trajectory/0.1.0]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:39:21,134 INFO [galaxy.jobs.handler] (15) Job dispatched +2022-05-30 16:39:21,441 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/15/tool_script.sh] for tool command [[ "$(basename "$CONDA_DEFAULT_ENV")" = "$(basename '/home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296')" ] || { +MAX_TRIES=3 +COUNT=0 +while [ $COUNT -lt $MAX_TRIES ]; do + . '/home/aepetit/miniconda3/bin/activate' '/home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296' > conda_activate.log 2>&1 + if [ $? -eq 0 ];then + break + else + let COUNT=COUNT+1 + if [ $COUNT -eq $MAX_TRIES ];then + echo "Failed to activate conda environment! Error was:" + cat conda_activate.log + exit 1 + fi + sleep 10s + fi +done +} ; [ "$(basename "$CONDA_DEFAULT_ENV")" = "$(basename '/home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296')" ] || { +MAX_TRIES=3 +COUNT=0 +while [ $COUNT -lt $MAX_TRIES ]; do + . '/home/aepetit/miniconda3/bin/activate' '/home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296' > conda_activate.log 2>&1 + if [ $? -eq 0 ];then + break + else + let COUNT=COUNT+1 + if [ $COUNT -eq $MAX_TRIES ];then + echo "Failed to activate conda environment! Error was:" + cat conda_activate.log + exit 1 + fi + sleep 10s + fi +done +} ; ln -s '/tmp/tmpudbcnm66/files/8/3/5/dataset_835311dd-d3e5-4db2-bd98-274b2aa04186.dat' 'PIP2.1_test.gro' && ln -s '/tmp/tmpudbcnm66/files/9/3/d/dataset_93d9a3db-08e5-4c64-b4b8-6ea194b2ec67.dat' 'PIP2.1_test.xtc' && ln -s '/tmp/tmpudbcnm66/files/8/9/4/dataset_89419396-ffd3-496c-9421-9534fdcdfb7b.dat' 'PIP2.1_test_check.txt' && python '/tmp/tmpudbcnm66/shed_tools/testtoolshed.g2.bx.psu.edu/repos/agpetit/cut_trajectory/b9fb306ccb2a/cut_trajectory/cut_trajectory.py' --verbose --gro_file 'PIP2.1_test.gro' --xtc_file 'PIP2.1_test.xtc' --log_output 'out_log/cut_trajectories.log' --output_directory 'out/' --nbr_sub_traj '3' --input_check 'PIP2.1_test_check.txt' --start_traj '0' --end_traj '10' --group_output 0 --number_cpus "${GALAXY_SLOTS:-1}"] +2022-05-30 16:39:33,777 INFO [galaxy.tool_util.verify] ## files diff on '/tmp/tmp64i094o0cut_trajectories_no_file.log' and '/tmp/tmpmbp6yd0kcut_trajectories_no_file.log': lines_diff = 12, found diff = 24 +---------------------- >> begin tool stdout << ----------------------- + +----------------------- >> end tool stdout << ------------------------ + +---------------------- >> begin tool stderr << ----------------------- + +----------------------- >> end tool stderr << ------------------------ + +
-------------------------------Captured log call--------------------------------
DEBUG multipart.multipart:multipart.py:604 Calling on_field_start with no data +DEBUG multipart.multipart:multipart.py:601 Calling on_field_name with data[0:4] +DEBUG multipart.multipart:multipart.py:601 Calling on_field_data with data[5:123] +DEBUG multipart.multipart:multipart.py:604 Calling on_field_end with no data +DEBUG multipart.multipart:multipart.py:604 Calling on_end with no data
Passedtest/functional/test_toolbox_pytest.py::test_tool[testtoolshed.g2.bx.psu.edu/repos/agpetit/calculate_diameter/calculate_diameter/1.0.0_test_1]30.87
+
------------------------------Captured stderr call------------------------------
2022-05-30 16:37:05,655 DEBUG [multipart.multipart] Calling on_field_start with no data +2022-05-30 16:37:05,655 DEBUG [multipart.multipart] Calling on_field_name with data[0:4] +2022-05-30 16:37:05,655 DEBUG [multipart.multipart] Calling on_field_data with data[5:131] +2022-05-30 16:37:05,655 DEBUG [multipart.multipart] Calling on_field_end with no data +2022-05-30 16:37:05,655 DEBUG [multipart.multipart] Calling on_end with no data +2022-05-30 16:37:05,796 INFO [galaxy.managers.configuration] Galaxy extra version JSON file /tmp/tmpudbcnm66/galaxy-dev/version.json not loaded. +2022-05-30 16:37:06,804 INFO [galaxy.tools] Validated and populated state for tool request (24.171 ms) +2022-05-30 16:37:06,821 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.159 ms) +2022-05-30 16:37:06,969 DEBUG [galaxy.tools.actions.upload] Checked uploads (147.872 ms) +2022-05-30 16:37:06,975 DEBUG [galaxy.tools.actions.upload] Created upload job (5.802 ms) +2022-05-30 16:37:07,006 INFO [galaxy.web_stack.handlers] (Job[id=1,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:37:07,656 INFO [galaxy.jobs.handler] (1) Job dispatched +2022-05-30 16:37:07,917 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/1/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/1/registry.xml' '/tmp/upload_params_b__72u_9' '1:/tmp/tmpudbcnm66/job_working_directory/000/1/working/dataset_fa99edec-859c-4f92-a5c3-df96305c5bb8_files:/tmp/tmpudbcnm66/files/f/a/9/dataset_fa99edec-859c-4f92-a5c3-df96305c5bb8.dat'] +2022-05-30 16:37:15,524 INFO [galaxy.tools] Validated and populated state for tool request (24.286 ms) +2022-05-30 16:37:15,531 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.453 ms) +2022-05-30 16:37:15,643 DEBUG [galaxy.tools.actions.upload] Checked uploads (112.079 ms) +2022-05-30 16:37:15,650 DEBUG [galaxy.tools.actions.upload] Created upload job (6.610 ms) +2022-05-30 16:37:15,678 INFO [galaxy.web_stack.handlers] (Job[id=2,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:37:16,066 INFO [galaxy.jobs.handler] (2) Job dispatched +2022-05-30 16:37:16,315 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/2/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/2/registry.xml' '/tmp/upload_params_tk7_ntpu' '2:/tmp/tmpudbcnm66/job_working_directory/000/2/working/dataset_428a901e-46dd-433f-aa38-040834923c53_files:/tmp/tmpudbcnm66/files/4/2/8/dataset_428a901e-46dd-433f-aa38-040834923c53.dat'] +2022-05-30 16:37:23,491 INFO [galaxy.tools] Validated and populated state for tool request (28.958 ms) +2022-05-30 16:37:23,505 INFO [galaxy.tools.actions] Handled output named table for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/calculate_diameter/calculate_diameter/1.0.0 (2.815 ms) +2022-05-30 16:37:23,507 INFO [galaxy.tools.actions] Handled output named tool_log for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/calculate_diameter/calculate_diameter/1.0.0 (2.062 ms) +2022-05-30 16:37:23,523 INFO [galaxy.tools.actions] Added output datasets to history (15.846 ms) +2022-05-30 16:37:23,527 INFO [galaxy.tools.actions] Setup for job Job[unflushed,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/calculate_diameter/calculate_diameter/1.0.0] complete, ready to be enqueued (3.520 ms) +2022-05-30 16:37:23,568 INFO [galaxy.web_stack.handlers] (Job[id=3,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/calculate_diameter/calculate_diameter/1.0.0]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:37:24,549 INFO [galaxy.jobs.handler] (3) Job dispatched +2022-05-30 16:37:24,812 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/3/tool_script.sh] for tool command [[ "$(basename "$CONDA_DEFAULT_ENV")" = "$(basename '/home/aepetit/miniconda3/envs/__mdanalysis@2.1.0')" ] || { +MAX_TRIES=3 +COUNT=0 +while [ $COUNT -lt $MAX_TRIES ]; do + . '/home/aepetit/miniconda3/bin/activate' '/home/aepetit/miniconda3/envs/__mdanalysis@2.1.0' > conda_activate.log 2>&1 + if [ $? -eq 0 ];then + break + else + let COUNT=COUNT+1 + if [ $COUNT -eq $MAX_TRIES ];then + echo "Failed to activate conda environment! Error was:" + cat conda_activate.log + exit 1 + fi + sleep 10s + fi +done +} ; python '/tmp/tmpudbcnm66/shed_tools/testtoolshed.g2.bx.psu.edu/repos/agpetit/calculate_diameter/e504457035e5/calculate_diameter/calculate_pore_diameter_aqp.py' --arr_one 'HSD LEU ALA THR' --arr_second 'ARG SER PHE GLY' --gro_file '/tmp/tmpudbcnm66/files/f/a/9/dataset_fa99edec-859c-4f92-a5c3-df96305c5bb8.dat' --xtc_file '/tmp/tmpudbcnm66/files/4/2/8/dataset_428a901e-46dd-433f-aa38-040834923c53.dat' --gro_file_ext 'gro' --xtc_file_ext 'xtc' --output '/tmp/tmpudbcnm66/files/9/7/7/dataset_977de3e3-d359-4a40-8a4b-7c51d4262504.dat' --verbose --log_output '/tmp/tmpudbcnm66/files/4/5/1/dataset_451a5cfb-9113-4c26-83ee-01449cf245c7.dat' --output_directory 'out' 2>&1] +
-------------------------------Captured log call--------------------------------
DEBUG multipart.multipart:multipart.py:604 Calling on_field_start with no data +DEBUG multipart.multipart:multipart.py:601 Calling on_field_name with data[0:4] +DEBUG multipart.multipart:multipart.py:601 Calling on_field_data with data[5:131] +DEBUG multipart.multipart:multipart.py:604 Calling on_field_end with no data +DEBUG multipart.multipart:multipart.py:604 Calling on_end with no data
Passedtest/functional/test_toolbox_pytest.py::test_tool[testtoolshed.g2.bx.psu.edu/repos/agpetit/concatenate_table/concatenate_table/1.0.0_test_1]31.28
+
------------------------------Captured stderr call------------------------------
2022-05-30 16:37:36,534 DEBUG [multipart.multipart] Calling on_field_start with no data +2022-05-30 16:37:36,535 DEBUG [multipart.multipart] Calling on_field_name with data[0:4] +2022-05-30 16:37:36,535 DEBUG [multipart.multipart] Calling on_field_data with data[5:129] +2022-05-30 16:37:36,535 DEBUG [multipart.multipart] Calling on_field_end with no data +2022-05-30 16:37:36,535 DEBUG [multipart.multipart] Calling on_end with no data +2022-05-30 16:37:36,751 INFO [galaxy.tools] Validated and populated state for tool request (22.588 ms) +2022-05-30 16:37:36,757 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.152 ms) +2022-05-30 16:37:36,869 DEBUG [galaxy.tools.actions.upload] Checked uploads (111.983 ms) +2022-05-30 16:37:36,876 DEBUG [galaxy.tools.actions.upload] Created upload job (6.364 ms) +2022-05-30 16:37:36,905 INFO [galaxy.web_stack.handlers] (Job[id=4,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:37:37,198 INFO [galaxy.jobs.handler] (4) Job dispatched +2022-05-30 16:37:37,368 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/4/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/4/registry.xml' '/tmp/upload_params_86aigh4i' '5:/tmp/tmpudbcnm66/job_working_directory/000/4/working/dataset_31f0355f-84ac-411f-97a3-0ac90eb23f59_files:/tmp/tmpudbcnm66/files/3/1/f/dataset_31f0355f-84ac-411f-97a3-0ac90eb23f59.dat'] +2022-05-30 16:37:44,495 INFO [galaxy.tools] Validated and populated state for tool request (22.079 ms) +2022-05-30 16:37:44,502 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.148 ms) +2022-05-30 16:37:44,627 DEBUG [galaxy.tools.actions.upload] Checked uploads (125.252 ms) +2022-05-30 16:37:44,636 DEBUG [galaxy.tools.actions.upload] Created upload job (8.474 ms) +2022-05-30 16:37:44,669 INFO [galaxy.web_stack.handlers] (Job[id=5,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:37:45,610 INFO [galaxy.jobs.handler] (5) Job dispatched +2022-05-30 16:37:45,851 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/5/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/5/registry.xml' '/tmp/upload_params_wrbilm9o' '6:/tmp/tmpudbcnm66/job_working_directory/000/5/working/dataset_3698b34a-13cb-49f7-a025-b7c5874abd65_files:/tmp/tmpudbcnm66/files/3/6/9/dataset_3698b34a-13cb-49f7-a025-b7c5874abd65.dat'] +2022-05-30 16:37:53,123 INFO [galaxy.tools] Validated and populated state for tool request (26.199 ms) +2022-05-30 16:37:53,129 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.147 ms) +2022-05-30 16:37:53,247 DEBUG [galaxy.tools.actions.upload] Checked uploads (117.795 ms) +2022-05-30 16:37:53,253 DEBUG [galaxy.tools.actions.upload] Created upload job (5.870 ms) +2022-05-30 16:37:53,281 INFO [galaxy.web_stack.handlers] (Job[id=6,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:37:54,076 INFO [galaxy.jobs.handler] (6) Job dispatched +2022-05-30 16:37:54,263 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/6/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/6/registry.xml' '/tmp/upload_params_a2trnhop' '7:/tmp/tmpudbcnm66/job_working_directory/000/6/working/dataset_8eed8997-0952-492c-82cf-ec9c086fbdc2_files:/tmp/tmpudbcnm66/files/8/e/e/dataset_8eed8997-0952-492c-82cf-ec9c086fbdc2.dat'] +2022-05-30 16:38:01,685 INFO [galaxy.tools] Validated and populated state for tool request (28.588 ms) +2022-05-30 16:38:01,747 INFO [galaxy.tools.actions] Handled output named sort_file for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/concatenate_table/concatenate_table/1.0.0 (3.914 ms) +2022-05-30 16:38:01,762 INFO [galaxy.tools.actions] Added output datasets to history (14.449 ms) +2022-05-30 16:38:01,763 INFO [galaxy.tools.actions] Setup for job Job[unflushed,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/concatenate_table/concatenate_table/1.0.0] complete, ready to be enqueued (1.467 ms) +2022-05-30 16:38:01,798 INFO [galaxy.web_stack.handlers] (Job[id=7,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/concatenate_table/concatenate_table/1.0.0]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:38:02,505 INFO [galaxy.jobs.handler] (7) Job dispatched +2022-05-30 16:38:02,788 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/7/tool_script.sh] for tool command [cat /tmp/tmpudbcnm66/files/3/1/f/dataset_31f0355f-84ac-411f-97a3-0ac90eb23f59.dat | awk -F'\t' 'BEGIN{mean="Time (ps)"; std=""} /^Time/ {for (i=2; i<(NF+1); i++) gsub(" ", ",mean ",$i) ; for (i=2; i<(NF+1); i++) mean=mean "\t" $i ; for (i=2; i<(NF+1); i++) gsub(",mean", ",std ",$i); for (i=2; i<(NF+1); i++) std=std "\t" $i } END{print (mean std)}' &>> '/tmp/tmpudbcnm66/files/2/d/6/dataset_2d6d52d2-777e-48e6-b725-28a364f4e52c.dat' ; cat /tmp/tmpudbcnm66/files/3/1/f/dataset_31f0355f-84ac-411f-97a3-0ac90eb23f59.dat | awk -F'\t' -v min=200.0 'BEGIN{min_val=min ; max_val=0 ; means=""; std=""} /^[0-9]/ {if ($1 <= min_val) {min_val=$1} ; if ($1 >= max_val) {max_val=$1}} ; /Mean/ {for (i=2; i<NF; i++) means=means"\t"$i ;means=means"\t"$NF } ; /Std/ {for (i=2; i<NF; i++) std=std"\t"$i; ;std=std"\t"$NF} END {print (min_val "-" max_val means std)}' &>> 'test.tabular' ; cat /tmp/tmpudbcnm66/files/3/6/9/dataset_3698b34a-13cb-49f7-a025-b7c5874abd65.dat | awk -F'\t' -v min=500.0 'BEGIN{min_val=min ; max_val=0 ; means=""; std=""} /^[0-9]/ {if ($1 <= min_val) {min_val=$1} ; if ($1 >= max_val) {max_val=$1}} ; /Mean/ {for (i=2; i<NF; i++) means=means"\t"$i ;means=means"\t"$NF } ; /Std/ {for (i=2; i<NF; i++) std=std"\t"$i; ;std=std"\t"$NF} END {print (min_val "-" max_val means std)}' &>> 'test.tabular' ; cat /tmp/tmpudbcnm66/files/8/e/e/dataset_8eed8997-0952-492c-82cf-ec9c086fbdc2.dat | awk -F'\t' -v min=1000.0 'BEGIN{min_val=min ; max_val=0 ; means=""; std=""} /^[0-9]/ {if ($1 <= min_val) {min_val=$1} ; if ($1 >= max_val) {max_val=$1}} ; /Mean/ {for (i=2; i<NF; i++) means=means"\t"$i ;means=means"\t"$NF } ; /Std/ {for (i=2; i<NF; i++) std=std"\t"$i; ;std=std"\t"$NF} END {print (min_val "-" max_val means std)}' &>> 'test.tabular' ; cat 'test.tabular' | sort -k1 -n &>> '/tmp/tmpudbcnm66/files/2/d/6/dataset_2d6d52d2-777e-48e6-b725-28a364f4e52c.dat'] +
-------------------------------Captured log call--------------------------------
DEBUG multipart.multipart:multipart.py:604 Calling on_field_start with no data +DEBUG multipart.multipart:multipart.py:601 Calling on_field_name with data[0:4] +DEBUG multipart.multipart:multipart.py:601 Calling on_field_data with data[5:129] +DEBUG multipart.multipart:multipart.py:604 Calling on_field_end with no data +DEBUG multipart.multipart:multipart.py:604 Calling on_end with no data
Passedtest/functional/test_toolbox_pytest.py::test_tool[testtoolshed.g2.bx.psu.edu/repos/agpetit/estimate_nb_sub_trajectories/estimate_nb_sub_trajectories/0.1.0_test_1]18.87
+
------------------------------Captured stderr call------------------------------
2022-05-30 16:39:35,689 DEBUG [multipart.multipart] Calling on_field_start with no data +2022-05-30 16:39:35,689 DEBUG [multipart.multipart] Calling on_field_name with data[0:4] +2022-05-30 16:39:35,689 DEBUG [multipart.multipart] Calling on_field_data with data[5:151] +2022-05-30 16:39:35,689 DEBUG [multipart.multipart] Calling on_field_end with no data +2022-05-30 16:39:35,689 DEBUG [multipart.multipart] Calling on_end with no data +2022-05-30 16:39:35,939 INFO [galaxy.tools] Validated and populated state for tool request (22.631 ms) +2022-05-30 16:39:35,946 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.145 ms) +2022-05-30 16:39:36,081 DEBUG [galaxy.tools.actions.upload] Checked uploads (135.506 ms) +2022-05-30 16:39:36,091 DEBUG [galaxy.tools.actions.upload] Created upload job (9.617 ms) +2022-05-30 16:39:36,127 INFO [galaxy.web_stack.handlers] (Job[id=16,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:39:37,095 INFO [galaxy.jobs.handler] (16) Job dispatched +2022-05-30 16:39:37,276 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/16/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/16/registry.xml' '/tmp/upload_params_yw33j4zk' '23:/tmp/tmpudbcnm66/job_working_directory/000/16/working/dataset_5b800b43-9848-4d53-9323-c6aceb22f262_files:/tmp/tmpudbcnm66/files/5/b/8/dataset_5b800b43-9848-4d53-9323-c6aceb22f262.dat'] +2022-05-30 16:39:47,071 INFO [galaxy.tools] Validated and populated state for tool request (13.357 ms) +2022-05-30 16:39:47,085 INFO [galaxy.tools.actions] Handled output named sub_trajectories_out_file for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/estimate_nb_sub_trajectories/estimate_nb_sub_trajectories/0.1.0 (2.867 ms) +2022-05-30 16:39:47,087 INFO [galaxy.tools.actions] Handled output named estimate_log for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/estimate_nb_sub_trajectories/estimate_nb_sub_trajectories/0.1.0 (1.940 ms) +2022-05-30 16:39:47,102 INFO [galaxy.tools.actions] Added output datasets to history (14.826 ms) +2022-05-30 16:39:47,105 INFO [galaxy.tools.actions] Setup for job Job[unflushed,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/estimate_nb_sub_trajectories/estimate_nb_sub_trajectories/0.1.0] complete, ready to be enqueued (1.997 ms) +2022-05-30 16:39:47,141 INFO [galaxy.web_stack.handlers] (Job[id=17,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/estimate_nb_sub_trajectories/estimate_nb_sub_trajectories/0.1.0]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:39:47,780 INFO [galaxy.jobs.handler] (17) Job dispatched +2022-05-30 16:39:48,028 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/17/tool_script.sh] for tool command [ln -s '/tmp/tmpudbcnm66/files/5/b/8/dataset_5b800b43-9848-4d53-9323-c6aceb22f262.dat' 'PIP2.1_test_check.txt' && ln -s '/tmp/tmpudbcnm66/files/c/5/6/dataset_c56e8bb6-ce7d-4267-8564-4773459f1129.dat' 'estimated_number_of_sub_trajectories.tsv' && python '/tmp/tmpudbcnm66/shed_tools/testtoolshed.g2.bx.psu.edu/repos/agpetit/estimate_nb_sub_trajectories/5fcbf7af809c/estimate_nb_sub_trajectories/estimate_nb_sub_trajectories.py' --input_check 'PIP2.1_test_check.txt' --verbose --output_file 'estimated_number_of_sub_trajectories.tsv' --log_output 'out_log/estimated_number_of_sub_trajectories.log' --nb_frames '3' --start_traj '' --end_traj ''] +
-------------------------------Captured log call--------------------------------
DEBUG multipart.multipart:multipart.py:604 Calling on_field_start with no data +DEBUG multipart.multipart:multipart.py:601 Calling on_field_name with data[0:4] +DEBUG multipart.multipart:multipart.py:601 Calling on_field_data with data[5:151] +DEBUG multipart.multipart:multipart.py:604 Calling on_field_end with no data +DEBUG multipart.multipart:multipart.py:604 Calling on_end with no data
Passedtest/functional/test_toolbox_pytest.py::test_tool[testtoolshed.g2.bx.psu.edu/repos/agpetit/visualize_pore_diameter_aqp/visualize_pore_diameter_aqp/0.1.0_test_1]26.28
+
------------------------------Captured stderr call------------------------------
2022-05-30 16:39:54,571 DEBUG [multipart.multipart] Calling on_field_start with no data +2022-05-30 16:39:54,571 DEBUG [multipart.multipart] Calling on_field_name with data[0:4] +2022-05-30 16:39:54,571 DEBUG [multipart.multipart] Calling on_field_data with data[5:149] +2022-05-30 16:39:54,571 DEBUG [multipart.multipart] Calling on_field_end with no data +2022-05-30 16:39:54,571 DEBUG [multipart.multipart] Calling on_end with no data +2022-05-30 16:39:54,792 INFO [galaxy.tools] Validated and populated state for tool request (26.681 ms) +2022-05-30 16:39:54,798 DEBUG [galaxy.tools.actions.upload] Persisted uploads (0.150 ms) +2022-05-30 16:39:54,915 DEBUG [galaxy.tools.actions.upload] Checked uploads (116.261 ms) +2022-05-30 16:39:54,921 DEBUG [galaxy.tools.actions.upload] Created upload job (6.361 ms) +2022-05-30 16:39:54,943 INFO [galaxy.web_stack.handlers] (Job[id=18,tool_id=upload1]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:39:55,282 INFO [galaxy.jobs.handler] (18) Job dispatched +2022-05-30 16:39:55,521 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/18/tool_script.sh] for tool command [python '/tmp/tmpudbcnm66/galaxy-dev/tools/data_source/upload.py' '/tmp/tmpudbcnm66/galaxy-dev' '/tmp/tmpudbcnm66/job_working_directory/000/18/registry.xml' '/tmp/upload_params_tj6wy_cu' '26:/tmp/tmpudbcnm66/job_working_directory/000/18/working/dataset_12912b09-e396-43d6-afbb-14e2260e8be3_files:/tmp/tmpudbcnm66/files/1/2/9/dataset_12912b09-e396-43d6-afbb-14e2260e8be3.dat'] +2022-05-30 16:40:03,597 INFO [galaxy.tools] Validated and populated state for tool request (16.995 ms) +2022-05-30 16:40:03,623 INFO [galaxy.tools.actions] Handled output named out_file for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/visualize_pore_diameter_aqp/visualize_pore_diameter_aqp/0.1.0 (4.741 ms) +2022-05-30 16:40:03,628 INFO [galaxy.tools.actions] Handled output named out_file2 for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/visualize_pore_diameter_aqp/visualize_pore_diameter_aqp/0.1.0 (4.097 ms) +2022-05-30 16:40:03,630 INFO [galaxy.tools.actions] Handled output named out_file3 for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/visualize_pore_diameter_aqp/visualize_pore_diameter_aqp/0.1.0 (2.331 ms) +2022-05-30 16:40:03,634 INFO [galaxy.tools.actions] Handled output named out_file4 for tool testtoolshed.g2.bx.psu.edu/repos/agpetit/visualize_pore_diameter_aqp/visualize_pore_diameter_aqp/0.1.0 (3.048 ms) +2022-05-30 16:40:03,656 INFO [galaxy.tools.actions] Added output datasets to history (22.238 ms) +2022-05-30 16:40:03,659 INFO [galaxy.tools.actions] Setup for job Job[unflushed,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/visualize_pore_diameter_aqp/visualize_pore_diameter_aqp/0.1.0] complete, ready to be enqueued (2.452 ms) +2022-05-30 16:40:03,721 INFO [galaxy.web_stack.handlers] (Job[id=19,tool_id=testtoolshed.g2.bx.psu.edu/repos/agpetit/visualize_pore_diameter_aqp/visualize_pore_diameter_aqp/0.1.0]) Handler '_default_' assigned using 'HANDLER_ASSIGNMENT_METHODS.DB_SKIP_LOCKED' assignment method +2022-05-30 16:40:04,091 INFO [galaxy.jobs.handler] (19) Job dispatched +2022-05-30 16:40:04,375 INFO [galaxy.jobs.command_factory] Built script [/tmp/tmpudbcnm66/job_working_directory/000/19/tool_script.sh] for tool command [[ "$(basename "$CONDA_DEFAULT_ENV")" = "$(basename '/home/aepetit/miniconda3/envs/mulled-v1-5a4fbc211f26cb04dc98136056f4848655807f4df79e1bb9f5b172569688ee2f')" ] || { +MAX_TRIES=3 +COUNT=0 +while [ $COUNT -lt $MAX_TRIES ]; do + . '/home/aepetit/miniconda3/bin/activate' '/home/aepetit/miniconda3/envs/mulled-v1-5a4fbc211f26cb04dc98136056f4848655807f4df79e1bb9f5b172569688ee2f' > conda_activate.log 2>&1 + if [ $? -eq 0 ];then + break + else + let COUNT=COUNT+1 + if [ $COUNT -eq $MAX_TRIES ];then + echo "Failed to activate conda environment! Error was:" + cat conda_activate.log + exit 1 + fi + sleep 10s + fi +done +} ; [ "$(basename "$CONDA_DEFAULT_ENV")" = "$(basename '/home/aepetit/miniconda3/envs/mulled-v1-5a4fbc211f26cb04dc98136056f4848655807f4df79e1bb9f5b172569688ee2f')" ] || { +MAX_TRIES=3 +COUNT=0 +while [ $COUNT -lt $MAX_TRIES ]; do + . '/home/aepetit/miniconda3/bin/activate' '/home/aepetit/miniconda3/envs/mulled-v1-5a4fbc211f26cb04dc98136056f4848655807f4df79e1bb9f5b172569688ee2f' > conda_activate.log 2>&1 + if [ $? -eq 0 ];then + break + else + let COUNT=COUNT+1 + if [ $COUNT -eq $MAX_TRIES ];then + echo "Failed to activate conda environment! Error was:" + cat conda_activate.log + exit 1 + fi + sleep 10s + fi +done +} ; [ "$(basename "$CONDA_DEFAULT_ENV")" = "$(basename '/home/aepetit/miniconda3/envs/mulled-v1-5a4fbc211f26cb04dc98136056f4848655807f4df79e1bb9f5b172569688ee2f')" ] || { +MAX_TRIES=3 +COUNT=0 +while [ $COUNT -lt $MAX_TRIES ]; do + . '/home/aepetit/miniconda3/bin/activate' '/home/aepetit/miniconda3/envs/mulled-v1-5a4fbc211f26cb04dc98136056f4848655807f4df79e1bb9f5b172569688ee2f' > conda_activate.log 2>&1 + if [ $? -eq 0 ];then + break + else + let COUNT=COUNT+1 + if [ $COUNT -eq $MAX_TRIES ];then + echo "Failed to activate conda environment! Error was:" + cat conda_activate.log + exit 1 + fi + sleep 10s + fi +done +} ; [ "$(basename "$CONDA_DEFAULT_ENV")" = "$(basename '/home/aepetit/miniconda3/envs/mulled-v1-5a4fbc211f26cb04dc98136056f4848655807f4df79e1bb9f5b172569688ee2f')" ] || { +MAX_TRIES=3 +COUNT=0 +while [ $COUNT -lt $MAX_TRIES ]; do + . '/home/aepetit/miniconda3/bin/activate' '/home/aepetit/miniconda3/envs/mulled-v1-5a4fbc211f26cb04dc98136056f4848655807f4df79e1bb9f5b172569688ee2f' > conda_activate.log 2>&1 + if [ $? -eq 0 ];then + break + else + let COUNT=COUNT+1 + if [ $COUNT -eq $MAX_TRIES ];then + echo "Failed to activate conda environment! Error was:" + cat conda_activate.log + exit 1 + fi + sleep 10s + fi +done +} ; ln -s '/tmp/tmpudbcnm66/files/1/2/9/dataset_12912b09-e396-43d6-afbb-14e2260e8be3.dat' 'table_sort_pore_diameter_aqp.tabular' && Rscript '/tmp/tmpudbcnm66/shed_tools/testtoolshed.g2.bx.psu.edu/repos/agpetit/visualize_pore_diameter_aqp/7f1b1530d0fb/visualize_pore_diameter_aqp/visualize_pore_diameter_aqp.R' -i 'table_sort_pore_diameter_aqp.tabular' -a TRUE -p TRUE -d TRUE -f TRUE] +2022-05-30 16:40:19,428 INFO [galaxy.tool_util.verify] ## files diff on '/tmp/tmpaz27gu1ball_graphics_distribution.pdf' and '/tmp/tmphrnvqxzjall_graphics_distribution.pdf': lines_diff = 0, found diff = 4, found pdf invalid diff = 0 +
-------------------------------Captured log call--------------------------------
DEBUG multipart.multipart:multipart.py:604 Calling on_field_start with no data +DEBUG multipart.multipart:multipart.py:601 Calling on_field_name with data[0:4] +DEBUG multipart.multipart:multipart.py:601 Calling on_field_data with data[5:149] +DEBUG multipart.multipart:multipart.py:604 Calling on_field_end with no data +DEBUG multipart.multipart:multipart.py:604 Calling on_end with no data
----------------------------Captured stderr teardown----------------------------
2022-05-30 16:40:19,530 INFO [test_driver] 21 threads were active before stopping embedded server +2022-05-30 16:40:19,530 INFO [test_driver] Shutting down embedded galaxy uvicorn server +2022-05-30 16:40:19,530 INFO [test_driver] Embedded web server galaxy stopped +2022-05-30 16:40:19,531 INFO [test_driver] Stopping embedded server thread +INFO: Shutting down +2022-05-30 16:40:19,532 INFO [uvicorn.error] Shutting down +INFO: Waiting for application shutdown. +2022-05-30 16:40:19,632 INFO [uvicorn.error] Waiting for application shutdown. +INFO: Application shutdown complete. +2022-05-30 16:40:19,633 INFO [uvicorn.error] Application shutdown complete. +INFO: Finished server process [39518] +2022-05-30 16:40:19,633 INFO [uvicorn.error] Finished server process [39518] +2022-05-30 16:40:19,633 INFO [test_driver] Event loop for uvicorn closed +2022-05-30 16:40:19,633 INFO [test_driver] Embedded server thread stopped +2022-05-30 16:40:19,634 INFO [test_driver] Stopping application galaxy +2022-05-30 16:40:20,509 INFO [galaxy.queue_worker] Sending reconfigure_watcher control task. +2022-05-30 16:40:20,524 INFO [galaxy.jobs.handler] sending stop signal to worker thread +2022-05-30 16:40:20,525 INFO [galaxy.jobs.handler] job handler queue stopped +2022-05-30 16:40:20,525 INFO [galaxy.jobs.runners] LocalRunner: Sending stop signal to 4 job worker threads +2022-05-30 16:40:20,525 INFO [galaxy.jobs.runners] Waiting up to 5 seconds for job worker threads to shutdown... +2022-05-30 16:40:20,526 INFO [galaxy.jobs.runners] All job worker threads shutdown cleanly +2022-05-30 16:40:20,526 INFO [galaxy.jobs.runners] TaskRunner: Sending stop signal to 2 job worker threads +2022-05-30 16:40:20,526 INFO [galaxy.jobs.runners] Waiting up to 5 seconds for job worker threads to shutdown... +2022-05-30 16:40:20,800 INFO [galaxy.jobs.runners] All job worker threads shutdown cleanly +2022-05-30 16:40:20,801 INFO [galaxy.jobs.handler] sending stop signal to worker thread +2022-05-30 16:40:20,801 INFO [galaxy.jobs.handler] job handler stop queue stopped +2022-05-30 16:40:20,802 INFO [test_driver] Application galaxy stopped. +2022-05-30 16:40:20,803 INFO [test_driver] 2 active after stopping embedded server +
-----------------------------Captured log teardown------------------------------
INFO test_driver:driver_util.py:747 21 threads were active before stopping embedded server +INFO test_driver:driver_util.py:755 Shutting down embedded galaxy uvicorn server +INFO test_driver:driver_util.py:757 Embedded web server galaxy stopped +INFO test_driver:driver_util.py:760 Stopping embedded server thread +INFO uvicorn.error:server.py:252 Shutting down +INFO uvicorn.error:on.py:64 Waiting for application shutdown. +INFO uvicorn.error:on.py:75 Application shutdown complete. +INFO uvicorn.error:server.py:85 Finished server process [39518] +INFO test_driver:driver_util.py:587 Event loop for uvicorn closed +INFO test_driver:driver_util.py:762 Embedded server thread stopped +INFO test_driver:driver_util.py:765 Stopping application galaxy +INFO test_driver:driver_util.py:767 Application galaxy stopped. +INFO test_driver:driver_util.py:769 2 active after stopping embedded server
\ No newline at end of file diff -r e504457035e5 -r a7128cd8f0e1 test-data/cut_trajectories_file.log --- a/test-data/cut_trajectories_file.log Mon May 30 14:21:51 2022 +0000 +++ b/test-data/cut_trajectories_file.log Mon May 30 15:04:51 2022 +0000 @@ -25,8 +25,8 @@ :-) GROMACS - gmx trjconv, 2022.1-conda_forge (-: -Executable: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1/bin.AVX2_256/gmx -Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1 +Executable: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296/bin.AVX2_256/gmx +Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296 Working dir: /tmp/tmp87fei_xs/job_working_directory/000/5/working Command line: gmx trjconv -f PIP2.1_test.xtc -s PIP2.1_test.gro -b 0 -e 20 -o out/PIP2.1_test_traj_1.xtc @@ -70,8 +70,8 @@ Selected 0: 'System' :-) GROMACS - gmx trjconv, 2022.1-conda_forge (-: -Executable: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1/bin.AVX2_256/gmx -Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1 +Executable: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296/bin.AVX2_256/gmx +Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296 Working dir: /tmp/tmp87fei_xs/job_working_directory/000/5/working Command line: gmx trjconv -f PIP2.1_test.xtc -s PIP2.1_test.gro -b 30 -e 50 -o out/PIP2.1_test_traj_2.xtc @@ -116,8 +116,8 @@ Selected 0: 'System' :-) GROMACS - gmx trjconv, 2022.1-conda_forge (-: -Executable: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1/bin.AVX2_256/gmx -Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1 +Executable: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296/bin.AVX2_256/gmx +Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296 Working dir: /tmp/tmp87fei_xs/job_working_directory/000/5/working Command line: gmx trjconv -f PIP2.1_test.xtc -s PIP2.1_test.gro -b 60 -e 80 -o out/PIP2.1_test_traj_3.xtc diff -r e504457035e5 -r a7128cd8f0e1 test-data/cut_trajectories_no_file.log --- a/test-data/cut_trajectories_no_file.log Mon May 30 14:21:51 2022 +0000 +++ b/test-data/cut_trajectories_no_file.log Mon May 30 15:04:51 2022 +0000 @@ -23,8 +23,8 @@ :-) GROMACS - gmx trjconv, 2022.1-conda_forge (-: -Executable: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1/bin.AVX2_256/gmx -Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1 +Executable: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296/bin.AVX2_256/gmx +Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296 Working dir: /tmp/tmp87fei_xs/job_working_directory/000/7/working Command line: gmx trjconv -f PIP2.1_test.xtc -s PIP2.1_test.gro -b 0 -e 20 -o out/PIP2.1_test_traj_1.xtc @@ -68,8 +68,8 @@ Selected 0: 'System' :-) GROMACS - gmx trjconv, 2022.1-conda_forge (-: -Executable: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1/bin.AVX2_256/gmx -Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1 +Executable: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296/bin.AVX2_256/gmx +Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296 Working dir: /tmp/tmp87fei_xs/job_working_directory/000/7/working Command line: gmx trjconv -f PIP2.1_test.xtc -s PIP2.1_test.gro -b 30 -e 50 -o out/PIP2.1_test_traj_2.xtc @@ -114,8 +114,8 @@ Selected 0: 'System' :-) GROMACS - gmx trjconv, 2022.1-conda_forge (-: -Executable: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1/bin.AVX2_256/gmx -Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-0569c04ab612909a373223b7f7da6469041d31d933b93b55db5a38a76d747ad1 +Executable: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296/bin.AVX2_256/gmx +Data prefix: /home/aepetit/miniconda3/envs/mulled-v1-2880a0cc8fea113b095b7fdfec6d72552feed785405b8640b3b3dfce7df9d296 Working dir: /tmp/tmp87fei_xs/job_working_directory/000/7/working Command line: gmx trjconv -f PIP2.1_test.xtc -s PIP2.1_test.gro -b 60 -e 80 -o out/PIP2.1_test_traj_3.xtc