New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improved Collection and Workflow State with Applications #5013

Merged
merged 22 commits into from Nov 30, 2017

Conversation

@jmchilton
Member

jmchilton commented Nov 15, 2017

Overview

This is a fairly expansive reworking on the concept of state for both workflows and dataset collections and many new features and fixes these state changes allow. These features include displaying more information with less noise to users of collections and making both collections and workflows simultaneously more correct and more efficient.

(Sorry for the unwieldy PR in terms of both scope and code lines - I've broken many smaller PRs off this branch but the core changes each involve modifying the same database migration repeatedly and so are inter-dependent despite seemingly being seemingly disjoint.)

Features

The main features are as follows and described in detail below.

  • Display collection state in the GUI.
  • Optimize dataset collection APIs and UX interactions.
  • Hide outputs of collection mapping immediately.
  • Allow empty collections and empty collection mapping.
  • Explicitly track workflow invocation outputs - provide via API.
  • Explicitly track workflow invocation step outputs - provide via API.
  • Add concept of workflow invocation step state - allow re-scheduling same step multiple times.
  • Many tests covering workflow and collection applications.

Display collection state in the GUI.

To do this I implement a model abstraction called ImplicitCollectionJobs. These aggregate all the jobs contributing to an implicitly created HistoryDatasetCollectionAssociation. This PR includes model enhancements that allow this and API endpoints for fetching a single job summary or set of job summaries for a history.

With the addition of ImplicitCollectionJobs , there are now three types of collections - those generated from a single tool (job_source_type = "Job"), those generated from many jobs via mapping (job_source_type = "ImplicitCollectionJobs"), and those just created via the GUI. The following screenshots demonstrate state representations for each for each of these combinations:

We don't have the connections to properly produce this data efficiently for existing collections - so legacy collections (collections created prior to 18.01) will have the improved display of collection counts and such but will not have proper gray, yellow, green, red states. New collections however will.

Fixes #4820.
Fixes #4735.
Fixes #4245.
Fixes #1244.
Progress toward #1810.

Optimize dataset collection APIs and UX interactions.

I've eliminate populated from the default dataset collection information in the API. For large and/or nested collections this could cause hundreds of thousands of database queries and joins to compute. I should have never been included - my bad. This is a breaking change but I think it is important. If anyone complains I'd be happy to add a Galaxy config option or something to restore it - but it would be better to fetch it from the detailed variants of those APIs.

Element collection counts used to be relatively expensive to compute and not included in the summary collection API view so the history panel would wait for the history contents to render and then would pause a little and issue a separate AJAX request for the collection counts and populate them in the GUI. I've reworked the collection models so this information is persisted (this was easy since it is only set once and in one thread ever) and then I included this information in the summary API. This allows the eliminate of that separate request from the GUI and allows rendering more information about collections in the GUI more quickly.

Progress toward #3939.

Hide outputs of collection mapping immediately.

When executing tools (ad-hoc and in workflows) create "mapped over" collections ahead of time instead of at the end only if they are valid and use this to track state of collection mapping progress so we can hide output datasets immediately.

I believe this should improve performance and prevent locks because we no longer have conflicting threads trying to write dataset state. The intermittent failures described in #1790 likely are causing undue contention at the database level as well.

Pre-creating these collections and the ImplicitCollectionJobs allows us to re-schedule workflows steps as discussed below.

Fixes #1790.
Progress toward #1810.

Allow empty collections and empty collection mapping.

If one maps a tool over an empty collection, one should get an empty output collection for each of the tool's outputs.

This should have always been a valid operation, the code just wasn't quite structured right when the collection work was merged - there were too many places I was assuming the existence of at least one actual output or input that was mapped over to continue going. The improved state handling finally allowed me to do away with this and this reworks all the collection plumbing above the state level to handle empty collections appropriately.

This was used by real world CWL workflows in the GA4GH challenge - so I think that is good evidence this is the right thing to do and continued progress on the challenge and CWL will require this work.

Fixes #4025.

Explicitly track workflow invocation outputs

This is modeled somewhat on job outputs, output datasets and output dataset collections are now tracked for each workflow invocation and exposed via the workflow invocation API. This required adding new tables (linked to WorkflowInvocation s and WorkflowOutput s) that track these output associations.

Previously one could imagine backtracking this information for simple tool steps via the WorkflowInvocationStep -> Job table, but for steps that have many jobs (i.e. mapping over a collection) or for non-tool steps such information was more difficult to recover (and simply couldn't be recovered from the API at all or even internally without significant knowledge of the underlying workflow).

This makes it much clearer what a workflow is producing via the API at least and required for workflow testing and CWL from Planemo.

Fixes common-workflow-language#73.

Explicitly track workflow invocation step outputs

Tracking the outputs of WorkflowInvocationStep s was not previously done at all, one would have to follow the Job table as well. A significant downside to this is that one cannot map over empty collections in a workflow - since no such job would exist. The outputs of WorklfowInvocationStep are now explicitly tracked via WorkflowInvocationStepOutputDatasetAssociation and WorkflowInvocationStepOutputDatasetCollectionAssociation models.

Tracking these job outputs for WorkflowInvocationSteps was not a simple matter of just attaching outputs to an existing table because we had no concept of a workflow step tracked - since there could be many WorklfowInvocationSteps corresponding to the same combination of WorkflowInvocation and WorkflowStep. That should feel wrong and that is because it is - when collections were added the possibility of having many jobs for the same combination of WorkflowInvocation and WorkflowStep was added.

Rather then a WorkflowStep being associated with number of WorklfowInvocationStep each with their own job - now each WorkflowStep is associated with a single Job, a single ImplicitCollectionJobs, or neither.

This transition involved fairly substantial changes to the workflow module interface. Any place a list of WorkflowInvocationStep s was assumed, I reworked it to just expect a single WorkflowInvocationStep. I vastly simplified recover_mapping to just use the persisted outputs (this was needed in order to also implement empty collection mapping in workflows).

This also fixes a bug (or implements a missing feature) where Subworkflow modules had no recover_mapping method - so for instance if a tool that produces dynamic collections appeared anywhere in a workflow after a subworkflow step - that workflow would not complete scheduling properly.

Add concept of workflow invocation step state - allow re-scheduling same step multiple times.

The WorkflowInvocationStep model now has the concept of state that lines up with the state of the WorkflowInvocation model. This along with the improved tracking or workflow steps in general and pre-creating output collections during mapping - means we can now do large collection mappings over several workflow scheduling iterations. Mapping a tool over a collection with tens of thousands of elements requires a significant amount of memory and time unfortunately - allowing this to happen over several iterations should hopefully allow the amount of time and memory to constrained and prevent such steps from interfering so dramatically with the process itself and other workflow invocations.

This can be exercised by setting maximum_workflow_jobs_per_scheduling_iteration now.

If this doesn't fix all the memory issues - the rest of this state tracking will positions us to do things a lot more cleverly now - so we should be able to follow up with even more fixes.

Fixes #3883.
Progress toward #3939.

Many tests covering workflow and collection applications.

In addition to various testing framework enhancements - this PR includes tests:

  • API tests for collection state summaries (both for simple output collections and mapped output collections).
  • API tests for tool output filters.
  • API tests for mapping over empty collections.
  • API tests confirming mapping over subworkflows works and mapping over workflows themselves works on the backend.
  • Rescheduling of workflow steps for large collection mapping.
  • UX (selenium) tests for collection state for simple output collections and mapped output collections.
  • UX (selenium) tests for collection state of copied collections.
  • UX (selenium) tests for simple rendering in history multi-view.
@bgruening

This comment has been minimized.

Member

bgruening commented Nov 20, 2017

Awesome stuff John!

If everyone wants to test this, we have prepared a Docker container with these enhancements.
Use with docker run -i -t -p 8080:80 quay.io/bgruening/galaxy:workflow_and_collection_state and test workflows/subworkflows and collections!

@jmchilton

This comment has been minimized.

Member

jmchilton commented Nov 20, 2017

Thanks @bgruening !

stateDescription: function() {
var collection = this.model;
var elementCount = collection.get("element_count");
console.log(elementCount);

This comment has been minimized.

@martenson

martenson Nov 27, 2017

Member

this log and the above one should probably go or be tied to Galaxy debugging state

This comment has been minimized.

@jmchilton

jmchilton Nov 27, 2017

Member

I'll just drop it all together - thanks.

} else if (elementCount) {
itemsDescription = ` with ${elementCount} items`;
}
var collectionCount = 42; // TODO - and handle unpopulated...

This comment has been minimized.

@martenson

martenson Nov 27, 2017

Member

the default value seems confusing here

This comment has been minimized.

@jmchilton

jmchilton Nov 27, 2017

Member

Yes - I need to fix this - debugging left overs.

collection_type = tool_output.structure.collection_type
tree = UnitializedTree(collection_type)
# else:

This comment has been minimized.

@martenson

martenson Nov 27, 2017

Member

is this helpful here?

Column("populated_state", TrimmedString(64), default='new', nullable=False),
)
# model.ImplicitCollectionJobsHistoryDatasetCollectionAssociation.table = Table(

This comment has been minimized.

@martenson

martenson Nov 27, 2017

Member

are we dropping this whole table?

This comment has been minimized.

@martenson

martenson Nov 27, 2017

Member

If not (and the migration seems to not to) we might want to track this (and others) dead/unused tables.

This comment has been minimized.

@jmchilton

jmchilton Nov 27, 2017

Member

More left overs from a messy development process - that was never added and I'll just drop the commented code. Thanks for the catch.

@martenson

This comment has been minimized.

Member

martenson commented Nov 27, 2017

Showing the 'loading' state collection the same way as we show 'scheduling' datasets is a bit confusing to me.
screenshot 2017-11-27 15 48 43

@jmchilton

This comment has been minimized.

Member

jmchilton commented Nov 27, 2017

@martenson Sure - what would you prefer - any easy visual clues we could use to distinguish these?

Update: We discussed in person and gray is fine but I will switch this to use the circular spinning icon instead of the stop watch (like when waiting for tool search for instance).

jmchilton added some commits Jul 25, 2017

Formalize workflow invocation and invocation step outputs.
Workflow Invocations
--------------------

The workflow invocation outputs half of this is relatively straight forward. It is modelled somewhat on job outputs, output datasets and output dataset collections are now tracked for each workflow invocation and exposed via the workflow invocation API. This required adding new tables (linked to WorkflowInvocations and WorkflowOutputs) that track these output associations.

Previously one could imagine backtracking this information for simple tool steps via the WorkflowInvocationStep -> Job table, but for steps that have many jobs (i.e. mapping over a collection) or for non-tool steps such information was more difficult to recover (and simply couldn't be recovered from the API at all or even internally without significant knowledge of the underlying workflow).

Workflow Invocation Steps
-------------------------

Tracking the outputs of WorkflowInvocationSteps was not previously done at all, one would have to follow the Job table as well. A signficant downside to this is that one cannot map over empty collections in a workflow - since no such job would exist. Tracking job outputs for WorkflowInvocationSteps is not a simple matter of just attaching outputs to an existing table because we had no concept of a workflow step tracked - since there could be many WorklfowInvocationSteps corresponding to the same combination of WorkflowInvocation and WorkflowStep. That should feel wrong and that is because it is - when collections were added the possiblity of having many jobs for the same combination of WorkflowInvocation and WorkflowStep was added. I should have split WorkflowInvocationSteps into WorkflowInvocationSteps and WorkflowInvocationStepJobAssociations at that time but didn't. This commit now does it - effectively normalizing the ``workflow_invocation_step`` table by introducing the new ``workflow_invocation_step_job_association`` table.

Splitting up the WorkflowInvocationStep table this way allows recovering the mapped over output (e.g. the implicitly created collection from all the jobs) as well the outputs from the individual jobs (by walking WorkflowInvocationStep -> WorkflowInvocationStepJobAssociation -> Job -> JobToOutput*Association).

This split up involves failrly substantial changes to the workflow module interface. Any place a list of WorkflowInvocationSteps was assumed, I reworked it to just expect a single WorkflowInvocationStep. I vastly simplified recover_mapping to just use the persisted outputs (this was needed in order to also implment empty collection mapping in workflows). This also fixes a bug (or implements a missing feature) where Subworkflow moudles had no recover_mapping methods - so for instance if a tool that produces dynamic collections appeared anywhere in a workflow after a subworkflow step - that workflow would not complete scheduling properly.

Now that we have a way to reference the set of jobs corresponding to a workflow step within an invocation, we can start to track partial scheduling of such steps. This is outlined in #3883 and refactoring toward this goal is included here - including adding a state to WorkflowInvocationStep so Galaxy can determine if it has started scheduling this step and an index when scheduling jobs so it can tell how far into a scheduling things have gone as well as augmenting the tool executor to take a maximum number of jobs to execute and allow recovery of existing jobs for collection building purposes.

*Applications*

These changes will enable:

- A simple, consistent API for finding workflow outputs that can be consumed by Planemo for testing workflows.
- Mapping over empty collections in workflows.
- Re-scheduling workflow invocations that include subworkflow steps.
- Partial scheduling within steps requiring a large number of jobs when scheduling workflow invocations.
Test cases for mapping for outputs with filter statements.
Checked through tools-iuc and I couldn't find any tools that use the actual input data parameters in filter statements so I think it is a fairly good approximation to assume that all mapped jobs will either filter or not at least with current execution model.
Refactor workflow testing toward reuse via "populators".
Should allow more functionality to be shared between vanilla API tests and integration tests for various workflow scheduling options.

@martenson martenson merged commit 9ef4e3b into galaxyproject:dev Nov 30, 2017

1 of 7 checks passed

api test Test started.
Details
framework test Test started.
Details
integration test Test started.
Details
lgtm analysis: JavaScript Running analyses for revisions
Details
selenium test Test started.
Details
toolshed test Test started.
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details
@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 1, 2017

Thanks @jmchilton for the updates. I wish this PR would solve the problem I encountered sub-workflow scheduling :-)

Today I did some tests using the docker-galaxy built on the dev branch quay.io/bgruening/galaxy:dev

Some observations:

  • The base RNA clustering workflow, that we are developing (https://github.com/BackofenLab/docker-galaxy-graphclust/tree/master/workflows), is getting stopped after a certain step. I am trying to trace the error then will post it here.

  • Visualization: The data-collection progress bar is indeed very cool!

    • While all jobs are finished: Refreshing history changes the color for a range of already finished (green) items into rotating-gray. I takes a few seconds until they turn back to green.
    • While a list-generating job is running (yellow), some of the previously finished list-generating jobs are also changing to yellow.
@martenson

This comment has been minimized.

Member

martenson commented Dec 1, 2017

@mmiladi

While all jobs are finished: Refreshing history changes the color for a range of already finished (green) items into rotating-gray. I takes a few seconds until they turn back to green.

This is a feature, the client is lazy-loading the collection contents.

While a list-generating job is running (yellow), some of the previously finished list-generating jobs are also changing to yellow.

This sounds like a bug but I am unable to replicate.

@jmchilton

This comment has been minimized.

Member

jmchilton commented Dec 1, 2017

@mmiladi Thanks a bunch for the testing!

I wish this PR would solve the problem I encountered sub-workflow scheduling :-)

I was going to ping you and ask you to check after the next release :( - I swear this solves some serious problems with subworkflows but clearly there are still issues. If you get that stack trace I'll definitely take a look. These subworkflow issues are tricky because it is hard to determine if it is a problem with how the GUI is constructing the workflow or how the backend is running it.

While all jobs are finished: Refreshing history changes the color for a range of already finished (green) items into rotating-gray. I takes a few seconds until they turn back to green.

Yes - the UI renders all the datasets and collections first and then fetches the collection states after a bit of delay when it has more information. Hopefully the job status bar indicates that it is fetching this information. This keeps the initial rendering quick (in theory much quicker than before for very large collections since we don't need to grab the full collection contents to put the initial box on the screen - this probably isn't noticeable for small collections though). I could probably fetch the more detailed job information with less of a delay if it is disorienting - I think it is like two seconds or something currently but that isn't needed I suppose - it is kind of a remanent of how collection element counts used to be fetched .

Another idea is to sort of cache the job state on the client so we can recover the last available state during history refreshes. I don't have a lot of experience with JavaScript caching though so I don't know how I would approach that right away. Does anyone know if we do anything like that anywhere else in the app?

While a list-generating job is running (yellow), some of the previously finished list-generating jobs are also changing to yellow.

Well that is just a flat out bug I think - nothing that was green should go back to yellow I don't think - really odd. I'll try to recreate it.

@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 1, 2017

@martenson @jmchilton : Thanks much for your quick reply! The 2-seconds delay is not annoying, just was not sure if it's a feature or a bug :) Also I am running a cloud instance that might be slower than usual hardware resources being used for galaxy servers.

With the 2nd visualization error: This happens after rerunning the terminated workflow in the same history. So it might be dependent on the termination issue.

@jmchilton Thanks again! Actually Bjoern recommended to test this branch and see if sub-workflow issue is resolved :) . With this branch I receive streams of HTTP log messages in the console, from the webserver I guess. So it's a bit difficult to catch error messages. Could you please mention the log files that I should first check?

@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 6, 2017

Ok finally I managed to get full log, this seems to be the error:

galaxy.tools.actions INFO 2017-12-06 13:22:10,342 Flushed transaction for job Job[id=13,tool_id=toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0] (22.541 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:10,342 Tool [toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0] created job [13] (97.394 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:10,369 Executed 2 job(s) for tool toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0 request: (245.948 ms)
galaxy.workflow.run ERROR 2017-12-06 13:22:10,398 Failed to schedule Workflow[id=34,name=GraphClust_1r_vrnafold_fast (imported from uploaded file)], problem occurred on WorkflowStep[index=9,type=tool].
Traceback (most recent call last):
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 185, in invoke
    incomplete_or_none = self._invoke_step(workflow_invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 258, in _invoke_step
    incomplete_or_none = invocation_step.workflow_step.module.execute(self.trans, self.progress, invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/modules.py", line 904, in execute
    progress.set_step_outputs(invocation_step, step_outputs, already_persisted=not invocation_step.is_new)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 403, in set_step_outputs
    raise KeyError("Failed to find [%s] in step outputs [%s]" % (output_name, outputs))
KeyError: u"Failed to find [xfile] in step outputs [{'cmfile_outfile': <galaxy.model.HistoryDatasetCollectionAssociation object at 0x7faa080a6110>}]"
galaxy.workflow.run ERROR 2017-12-06 13:22:10,399 Failed to execute scheduled workflow.
Traceback (most recent call last):
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 80, in __invoke
    outputs = invoker.invoke()
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 185, in invoke
    incomplete_or_none = self._invoke_step(workflow_invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 258, in _invoke_step
    incomplete_or_none = invocation_step.workflow_step.module.execute(self.trans, self.progress, invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/modules.py", line 904, in execute
    progress.set_step_outputs(invocation_step, step_outputs, already_persisted=not invocation_step.is_new)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 403, in set_step_outputs
    raise KeyError("Failed to find [%s] in step outputs [%s]" % (output_name, outputs))
KeyError: u"Failed to find [xfile] in step outputs [{'cmfile_outfile': <galaxy.model.HistoryDatasetCollectionAssociation object at 0x7faa080a6110>}]"

@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 6, 2017

@jmchilton The tool that fails here (cmsearch) has dynamic number of input fields. By default there is a single input, but here 'covariance models from history' is selected instead of the "locally installed cm files". This would dynamically add a second input pin to the tool.

@bgruening

This comment has been minimized.

Member

bgruening commented Dec 6, 2017

@jmchilton if it helps the tool is part of the infernal tool in the TS.

@jmchilton

This comment has been minimized.

Member

jmchilton commented Dec 6, 2017

So this xfile output:

        <data name="xfile" format="txt" label="xfile, an cmcalibrate additional output file, on ${on_string}">
            <filter>
                ((
                Calibrate['selector'] is True and
                Calibrate['output_options_cond']['selector'] == "extra" and
                'xfile' in Calibrate['output_options_cond']['output_options']
                ))
            </filter>
        </data>
  • The input to cmbuild is being mapped over right (it has a ribbon connected to it instead of a line)?
  • Is this step in the subworkflow or the outer workflow?
  • Was something connected to this output?
  • Was this output marked as an output?
  • Was an actual file produced for this output or was it really filtered out like the message above suggests?
@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 6, 2017

  • Please have a look at this screenshot:
    screenshot from 2017-12-06 18-41-19

  • This is a simple classic workflow. No subwork-flow is involved.

  • The 'cmbuild' output is really generated successfully. Here is an extended log message with some lines before the error:

==> /var/log/supervisor/handler0-stderr---supervisor-7Ri1Qz.log <==
galaxy.managers.collections DEBUG 2017-12-06 13:22:09,259 Created collection with 2 elements
galaxy.tools.actions INFO 2017-12-06 13:22:09,422 Handled output named model_tree_stk for tool toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3 (17.275 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,430 Added output datasets to history (8.007 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,469 Verified access to datasets for Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3] (19.287 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,470 Setup for job Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3] complete, ready to flush (40.258 ms
)
galaxy.tools.actions INFO 2017-12-06 13:22:09,502 Flushed transaction for job Job[id=8,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3] (31.896 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:09,503 Tool [toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3] created job [8] (163.466 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,627 Handled output named model_tree_stk for tool toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3 (15.021 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,634 Added output datasets to history (7.092 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,660 Verified access to datasets for Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3] (13.031 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,661 Setup for job Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3] complete, ready to flush (26.265 ms
)
galaxy.tools.actions INFO 2017-12-06 13:22:09,685 Flushed transaction for job Job[id=9,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3] (24.236 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:09,685 Tool [toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3] created job [9] (137.945 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:09,718 Executed 2 job(s) for tool toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_mlocarna/locarna_best_subtree/0.3 request: (482.893 ms)
galaxy.workflow.run DEBUG 2017-12-06 13:22:09,725 Workflow step 173 of invocation 1 invoked (593.476 ms)
galaxy.managers.collections DEBUG 2017-12-06 13:22:09,772 Created collection with 2 elements
galaxy.tools.actions INFO 2017-12-06 13:22:09,872 Handled output named model_cmfinder_stk for tool toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3 (17.178 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,879 Added output datasets to history (7.159 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,893 Verified access to datasets for Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3] (6.871 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,893 Setup for job Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3] complete, ready to flush (14.237 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,912 Flushed transaction for job Job[id=10,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3] (18.576 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:09,912 Tool [toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3] created job [10] (105.327 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,993 Handled output named model_cmfinder_stk for tool toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3 (16.918 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:09,999 Added output datasets to history (6.609 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,020 Verified access to datasets for Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3] (12.249 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,021 Setup for job Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3] complete, ready to flush (21.506 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,042 Flushed transaction for job Job[id=11,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3] (20.836 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:10,042 Tool [toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3] created job [11] (101.635 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:10,089 Executed 2 job(s) for tool toolshed.g2.bx.psu.edu/repos/rnateam/graphclust_cmfinder/cmFinder/0.3 request: (319.279 ms)
galaxy.workflow.run DEBUG 2017-12-06 13:22:10,098 Workflow step 174 of invocation 1 invoked (372.100 ms)
galaxy.managers.collections DEBUG 2017-12-06 13:22:10,126 Created collection with 2 elements
galaxy.tools.actions INFO 2017-12-06 13:22:10,191 Handled output named cmfile_outfile for tool toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0 (15.414 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,198 Added output datasets to history (6.204 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,206 Verified access to datasets for Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0] (3.355 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,207 Setup for job Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0] complete, ready to flush (9.125 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,228 Flushed transaction for job Job[id=12,tool_id=toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0] (20.888 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:10,228 Tool [toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0] created job [12] (73.915 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,302 Handled output named cmfile_outfile for tool toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0 (23.863 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,309 Added output datasets to history (7.143 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,318 Verified access to datasets for Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0] (3.587 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,319 Setup for job Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0] complete, ready to flush (9.485 ms)
galaxy.tools.actions INFO 2017-12-06 13:22:10,342 Flushed transaction for job Job[id=13,tool_id=toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0] (22.541 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:10,342 Tool [toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0] created job [13] (97.394 ms)
galaxy.tools.execute DEBUG 2017-12-06 13:22:10,369 Executed 2 job(s) for tool toolshed.g2.bx.psu.edu/repos/bgruening/infernal/infernal_cmbuild/1.1.2.0 request: (245.948 ms)
galaxy.workflow.run ERROR 2017-12-06 13:22:10,398 Failed to schedule Workflow[id=34,name=GraphClust_1r_vrnafold_fast (imported from uploaded file)], problem occurred on WorkflowStep[index=9,type=tool].
Traceback (most recent call last):
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 185, in invoke
    incomplete_or_none = self._invoke_step(workflow_invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 258, in _invoke_step
    incomplete_or_none = invocation_step.workflow_step.module.execute(self.trans, self.progress, invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/modules.py", line 904, in execute
    progress.set_step_outputs(invocation_step, step_outputs, already_persisted=not invocation_step.is_new)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 403, in set_step_outputs
    raise KeyError("Failed to find [%s] in step outputs [%s]" % (output_name, outputs))
KeyError: u"Failed to find [xfile] in step outputs [{'cmfile_outfile': <galaxy.model.HistoryDatasetCollectionAssociation object at 0x7faa080a6110>}]"
galaxy.workflow.run ERROR 2017-12-06 13:22:10,399 Failed to execute scheduled workflow.
Traceback (most recent call last):
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 80, in __invoke
    outputs = invoker.invoke()
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 185, in invoke
    incomplete_or_none = self._invoke_step(workflow_invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 258, in _invoke_step
    incomplete_or_none = invocation_step.workflow_step.module.execute(self.trans, self.progress, invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/modules.py", line 904, in execute
    progress.set_step_outputs(invocation_step, step_outputs, already_persisted=not invocation_step.is_new)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 403, in set_step_outputs
    raise KeyError("Failed to find [%s] in step outputs [%s]" % (output_name, outputs))
KeyError: u"Failed to find [xfile] in step outputs [{'cmfile_outfile': <galaxy.model.HistoryDatasetCollectionAssociation object at 0x7faa080a6110>}]"

@jmchilton

This comment has been minimized.

Member

jmchilton commented Dec 6, 2017

Ahhhh - I think I get it now. I bet optional output xfile parameter isn't in the outputs are actually generated at runtime right? But it is marked as an output of the workflow. I can see how the changes in ... probably d5f98f4 ... would cause that. It'd be nice if you were warned about this - because it seems like it should be some kind of error in general if an expected workflow output isn't generated. In this case Galaxy should know all the way at the beginning that this is a problem and warn about it before the workflow even runs - but it isn't that smart yet. I need to restore the old behavior at least until we have a way of restricting that behavior to newer workflows and have a way of indicating through the GUI that an expected workflow output wasn't generated. I'll keep looking at this.

@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 6, 2017

@jmchilton ah this was a hit! Unmarked all the 6 dangling cmbuild outputs and workflow successfully finished .

@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 6, 2017

@jmchilton Thanks much for the help!
There is another problem with creating&editing workflows. While creating a workflow of ~10 tools, after a certain point, connecting output of a specific tool to another (both sides data-collection) prevents creating any other link. The connecting arrow, which suppose to popup by moving the mouse over it, does not show up anymore. Instead the mouse drags & moves the tool rectangle. It feels to be a client side issue, though not sure. Is there any mechanism to prevent a user from creating a new link?

@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 6, 2017

So now I am able to test the sub-workflow scenario.
The sub-workflow issue appears to be still in place on this branch. This is a
minimal workflow, that can successfully be run on as a workflow:
screenshot from 2017-12-06 20-00-59

However this super-workflow does not run beyond the GSPAN step:
screenshot from 2017-12-06 20-07-15

The error log should be this one:

galaxy.managers.collections DEBUG 2017-12-06 19:09:43,369 Created collection with 0 elements
galaxy.tools.actions INFO 2017-12-06 19:09:43,449 Handled collection output named gspan_compressed for tool toolshed.g2.bx.psu.edu/repos/rnateam/structure_to_gspan/structure_to_gspan/0.3 (80.916 ms)
galaxy.tools.actions INFO 2017-12-06 19:09:43,450 Added output datasets to history (0.032 ms)
galaxy.tools.actions INFO 2017-12-06 19:09:43,487 Verified access to datasets for Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/structure_to_gspan/structure_to_gspan/0.3] (9.130 ms)
galaxy.tools.actions INFO 2017-12-06 19:09:43,496 Setup for job Job[unflushed,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/structure_to_gspan/structure_to_gspan/0.3] complete, ready to flush (40.527 ms)
galaxy.tools.actions INFO 2017-12-06 19:09:43,566 Flushed transaction for job Job[id=71,tool_id=toolshed.g2.bx.psu.edu/repos/rnateam/structure_to_gspan/structure_to_gspan/0.3] (70.028 ms)
galaxy.tools.execute DEBUG 2017-12-06 19:09:43,567 Tool [toolshed.g2.bx.psu.edu/repos/rnateam/structure_to_gspan/structure_to_gspan/0.3] created job [71] (307.408 ms)
galaxy.tools.execute DEBUG 2017-12-06 19:09:43,625 Executed 1 job(s) for tool toolshed.g2.bx.psu.edu/repos/rnateam/structure_to_gspan/structure_to_gspan/0.3 request: (364.661 ms)
galaxy.workflow.run DEBUG 2017-12-06 19:09:43,686 Workflow step 274 of invocation 13 invoked (443.177 ms)
galaxy.workflow.run DEBUG 2017-12-06 19:09:43,721 Marking step 275 outputs of invocation 13 delayed (dependent collection [58] not yet populated with datasets)
galaxy.workflow.run DEBUG 2017-12-06 19:09:43,766 Marking step 276 outputs of invocation 13 delayed (dependent step [275] delayed, so this step must be delayed)
galaxy.workflow.run ERROR 2017-12-06 19:09:43,827 Failed to schedule Workflow[id=49,name=super-workflow], problem occurred on WorkflowStep[index=1,type=subworkflow].
Traceback (most recent call last):
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 185, in invoke
    incomplete_or_none = self._invoke_step(workflow_invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 258, in _invoke_step
    incomplete_or_none = invocation_step.workflow_step.module.execute(self.trans, self.progress, invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/modules.py", line 349, in execute
    replacement = subworkflow_progress.get_replacement_workflow_output(workflow_output)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 369, in get_replacement_workflow_output
    return self.outputs[step.id][output_name]
TypeError: 'object' object has no attribute '__getitem__'
galaxy.workflow.run ERROR 2017-12-06 19:09:43,829 Failed to execute scheduled workflow.
Traceback (most recent call last):
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 80, in __invoke
    outputs = invoker.invoke()
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 185, in invoke
    incomplete_or_none = self._invoke_step(workflow_invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 258, in _invoke_step
    incomplete_or_none = invocation_step.workflow_step.module.execute(self.trans, self.progress, invocation_step)
  File "/galaxy-central/lib/galaxy/workflow/modules.py", line 349, in execute
    replacement = subworkflow_progress.get_replacement_workflow_output(workflow_output)
  File "/galaxy-central/lib/galaxy/workflow/run.py", line 369, in get_replacement_workflow_output
    return self.outputs[step.id][output_name]
TypeError: 'object' object has no attribute '__getitem__'
galaxy.jobs.runners DEBUG 2017-12-06 19:09:44,056 (69) command is: rm -rf working; mkdir -p working; cd working; /export/galaxy-central/database/job_working_directory/000/69/tool_script.sh; return_code=$?
; if [ -f /export/galaxy-central/database/job_working_directory/000/69/working/alignment_data_split.stk ] ; then cp /export/galaxy-central/database/job_working_directory/000/69/working/alignment_data_spli
t.stk /export/galaxy-central/database/files/000/dataset_552.dat ; fi; if [ -f /export/galaxy-central/database/job_working_directory/000/69/working/shape_data_split.react ] ; then cp /export/galaxy-central
/database/job_working_directory/000/69/working/shape_data_split.react /export/galaxy-central/database/files/000/dataset_551.dat ; fi; if [ -f /export/galaxy-central/database/job_working_directory/000/69/working/FASTA.zip ] ; then cp /export/galaxy-central/database/job_working_directory/000/69/working/FASTA.zip /export/galaxy-central/database/files/000/dataset_550.dat ; fi; if [ -f /export/galaxy-central/d
atabase/job_working_directory/000/69/working/FASTA/data.fasta.scan ] ; then cp /export/galaxy-central/database/job_working_directory/000/69/working/FASTA/data.fasta.scan /export/galaxy-central/database/files/000/dataset_549.dat ; fi; if [ -f /export/galaxy-central/database/job_working_directory/000/69/working/FASTA/data.names ] ; then cp /export/galaxy-central/database/job_working_directory/000/69/working
/FASTA/data.names /export/galaxy-central/database/files/000/dataset_548.dat ; fi; if [ -f /export/galaxy-central/database/job_working_directory/000/69/working/FASTA/data.map ] ; then cp /export/galaxy-cen
tral/database/job_working_directory/000/69/working/FASTA/data.map /export/galaxy-central/database/files/000/dataset_547.dat ; fi; if [ -f /export/galaxy-central/database/job_working_directory/000/69/worki
ng/FASTA/data.fasta ] ; then cp /export/galaxy-central/database/job_working_directory/000/69/working/FASTA/data.fasta /export/galaxy-central/database/files/000/dataset_546.dat ; fi; cd '/export/galaxy-central/database/job_working_directory/000/69'; 

jmchilton added a commit to jmchilton/galaxy that referenced this pull request Dec 6, 2017

Re-allow workflow outputs that aren't produced during workflow schedu…
…ling.

These are sort of an error in the workflow definition but we don't have a means to competently display this information to the user via the UI so I think we need to just allow this to happen.

I've attached a test case that exhibits this behavior and passes under 17.09 but fails under the current dev branch without these fixes. This was broken in galaxyproject@d5f98f4 when we started to actually persist pointers to workflow invocation outputs (as part of galaxyproject#5013).
@jmchilton

This comment has been minimized.

Member

jmchilton commented Dec 6, 2017

Before I look at the subworkflow issue - I wanted to record here that I've opened a PR against Galaxy to re-allow workflow outputs that aren't actually generated (#5143) - this should hopefully be merged in by the next release.

@jmchilton

This comment has been minimized.

Member

jmchilton commented Dec 6, 2017

@mmiladi Thanks so much for the stack traces - this is really helpful!

Are you in a position to update the running Galaxy code and let me know if it fixes this problem? I have a vague sense that this f2b584f might fix the problem but I need to think about it more before actually opening a PR to fix it. I'd like to be able to re-create this in my testing also so I need to do some more work.

@jmchilton

This comment has been minimized.

Member

jmchilton commented Dec 6, 2017

Okay - I was actually able to create that same stack trace on my first attempt - I've opened another PR with the fixed linked to in my last comment @ #5145.

@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 7, 2017

@jmchilton Thanks much for the developments. I would be happy to test. Please let me know which branch to use for creating the docker-galaxy image.

@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 7, 2017

@jmchilton @bgruening Patched run.py within the docker instance with changes made in b1d6c01 and f2b584f

Both optional workflow output and sub-workflow issues are resolved. Wonderful wonderful! 🎉
Sending and 🤗 from Freiburg!

@mmiladi

This comment has been minimized.

Contributor

mmiladi commented Dec 8, 2017

#5163 created for the workflow editor problem. Probably it's not caused by this PR.

natefoo added a commit to natefoo/galaxy that referenced this pull request Oct 9, 2018

Remove some model objects added in galaxyproject#5013 but unused befo…
…re the PR was

merged. Also, fix the typo:

  WorkflowRequestInputStepParmeter -> WorkflowRequestInputStepParameter

Both found by @nsoranzo in galaxyproject#6757.

jmchilton added a commit that referenced this pull request Oct 10, 2018

Merge pull request #6843 from natefoo/remove-unused-model-objects
Remove some model objects added in #5013 but unused before the PR was merged, and fix a model object typo
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment