galaxyproject / galaxy

Data intensive science for everyone.
https://galaxyproject.org
Other
1.41k stars 1.01k forks source link

19.09 toolshed installation errors #8952

Closed bgruening closed 5 years ago

bgruening commented 5 years ago

1: All repositories with a minor update, like Alevin (908a8d400fa2)

grafik

will be turned into the new state during the update with ephemeris

2: Going from new state to install

Nov 09 13:23:50 sn04.bi.uni-freiburg.de uwsgi[4107748]: tool_shed.util.hg_util ERROR 2019-11-09 13:23:50,455 [p:4124529,w:4,m:0] [uWSGIWorker4Core0] Error cloning repository: Command '['hg', 'clone', '-r', '6', u'https://toolshed.g2.bx.psu.edu/repos/iuc/bcftools_call', u'/opt/galaxy/shed_tools/toolshed.g2.bx.psu.edu/repos/iuc/bcftools_call/3296c3680d96/bcftools_call']' returned non-zero exit status 255
Nov 09 13:23:50 sn04.bi.uni-freiburg.de uwsgi[4107748]: Output was:
Nov 09 13:23:50 sn04.bi.uni-freiburg.de uwsgi[4107748]: abort: destination '/opt/galaxy/shed_tools/toolshed.g2.bx.psu.edu/repos/iuc/bcftools_call/3296c3680d96/bcftools_call' is not empty

Here it would help now to also install the repo if it is either in new state or in error state I think.

Nov 09 13:22:10 sn04.bi.uni-freiburg.de uwsgi[4107748]: [pid: 4124485|app: 0|req: 9911/42155] 88.66.136.83 () {84 vars in 1575 bytes} [Sat Nov  9 13:22:10 2019] POST /admin_toolshed/repository_installation_status_updates => generated 2 bytes in 23 msecs (HTTP/1.1 200) 3 headers in 96 bytes (1 switches on core 0)
Nov 09 13:22:11 sn04.bi.uni-freiburg.de uwsgi[3191341]: galaxy.datatypes.registry DEBUG 2019-11-09 13:22:11,317 [p:119216,w:4,m:0] [Thread-1] Loaded external metadata tool: __SET_METADATA__
Nov 09 13:22:11 sn04.bi.uni-freiburg.de uwsgi[3191341]: galaxy.tools.special_tools DEBUG 2019-11-09 13:22:11,323 [p:119216,w:4,m:0] [Thread-1] Loaded history import tool: __IMPORT_HISTORY__
Nov 09 13:22:11 sn04.bi.uni-freiburg.de uwsgi[3191341]: galaxy.tools.special_tools DEBUG 2019-11-09 13:22:11,327 [p:119216,w:4,m:0] [Thread-1] Loaded data fetch tool: __DATA_FETCH__
Nov 09 13:22:11 sn04.bi.uni-freiburg.de uwsgi[3191341]: galaxy.tools.special_tools DEBUG 2019-11-09 13:22:11,330 [p:119216,w:4,m:0] [Thread-1] Loaded history export tool: __EXPORT_HISTORY__
Nov 09 13:22:11 sn04.bi.uni-freiburg.de uwsgi[3191341]: galaxy.queue_worker INFO 2019-11-09 13:22:11,332 [p:119216,w:4,m:0] [Thread-1] Queuing async task rebuild_toolbox_search_index for main.web.4.
Nov 09 13:22:11 sn04.bi.uni-freiburg.de uwsgi[3191341]: galaxy.queue_worker DEBUG 2019-11-09 13:22:11,336 [p:119216,w:4,m:0] [Thread-1] Toolbox reload (29743.348 ms)
Nov 09 13:22:11 sn04.bi.uni-freiburg.de uwsgi[3191341]: galaxy.queue_worker INFO 2019-11-09 13:22:11,338 [p:119216,w:4,m:0] [Thread-1] Instance 'main.web.4' received 'reload_toolbox' task, executing now.
Nov 09 13:22:11 sn04.bi.uni-freiburg.de uwsgi[3191341]: galaxy.queue_worker DEBUG 2019-11-09 13:22:11,338 [p:119216,w:4,m:0] [Thread-1] Executing toolbox reload on 'main.web.4'
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3843198]: 115.146.92.55 - - [09/Nov/2019:13:22:11 +0200] "GET /api/jobs/4d16a9b9d521c9b3?key=59001665ead9d0bfd82dad0c0253dda0 HTTP/1.1" 200 - "-" "python-requests/2.22.0"
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3843198]: [pid: 3882852|app: 0|req: 11155/55634] 115.146.92.55 () {70 vars in 992 bytes} [Sat Nov  9 13:22:11 2019] GET /api/jobs/4d16a9b9d521c9b3?key=59001665ead9d0bfd82dad0c0253dda0 => generated 1118 bytes in 88 msecs (HTTP/1.1 200) 2 headers in 110 bytes (1 switches on core 0)
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3843198]: galaxy.tools.search DEBUG 2019-11-09 13:22:12,036 [p:228435,w:4,m:0] [Thread-1] Toolbox index finished (29660.792 ms)
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: galaxy.util ERROR 2019-11-09 13:22:12,537 [p:119216,w:4,m:0] [Thread-1] Error parsing file /opt/galaxy/mutable-config/integrated_tool_panel.xml
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: Traceback (most recent call last):
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "lib/galaxy/util/__init__.py", line 236, in parse_xml
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: root = tree.parse(fname, parser=ElementTree.XMLParser(target=DoctypeSafeCallbackTarget()))
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 657, in parse
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: self._root = parser.close()
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1654, in close
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: self._raiseerror(v)
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1506, in _raiseerror
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: raise err
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: ParseError: unclosed token: line 10952, column 8
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: galaxy.queue_worker ERROR 2019-11-09 13:22:12,538 [p:119216,w:4,m:0] [Thread-1] Error running control task type: reload_toolbox
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: Traceback (most recent call last):
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "lib/galaxy/queue_worker.py", line 372, in process_task
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: result = f(self.app, **body['kwargs'])
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "lib/galaxy/queue_worker.py", line 171, in reload_toolbox
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: _get_new_toolbox(app)
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "lib/galaxy/queue_worker.py", line 188, in _get_new_toolbox
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: new_toolbox = tools.ToolBox(tool_configs, app.config.tool_path, app)
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "lib/galaxy/tools/__init__.py", line 253, in __init__
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: app=app,
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "lib/galaxy/tools/toolbox/base.py", line 1163, in __init__
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: super(BaseGalaxyToolBox, self).__init__(config_filenames, tool_root_dir, app)
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "lib/galaxy/tools/toolbox/base.py", line 100, in __init__
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: self._init_integrated_tool_panel(app.config)
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "lib/galaxy/tools/toolbox/integrated_panel.py", line 39, in _init_integrated_tool_panel
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: self._load_integrated_tool_panel_keys()
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "lib/galaxy/tools/toolbox/base.py", line 445, in _load_integrated_tool_panel_keys
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: tree = parse_xml(self._integrated_tool_panel_config)
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "lib/galaxy/util/__init__.py", line 236, in parse_xml
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: root = tree.parse(fname, parser=ElementTree.XMLParser(target=DoctypeSafeCallbackTarget()))
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 657, in parse
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: self._root = parser.close()
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1654, in close
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: self._raiseerror(v)
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1506, in _raiseerror
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: raise err
Nov 09 13:22:12 sn04.bi.uni-freiburg.de uwsgi[3191341]: ParseError: unclosed token: line 10952, column 8

The above seems just to be temporary ... as the file looks ok all the time I lint it.

Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: 88.66.136.83 - - [09/Nov/2019:13:08:06 +0200] "POST /admin_toolshed/install_repositories HTTP/1.1" 500 - "https://usegalaxy.eu/admin_toolshed/reinstall_repository?id=cf561391762ef90f" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:70.0) Gecko/20100101 Firefox/70.0"
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: Error - <type 'exceptions.ValueError'>: invalid literal for int() with base 10: 'dbkey'
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: URL: https://usegalaxy.eu/admin_toolshed/install_repositories
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/web/framework/middleware/error.py', line 154 in __call__
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: app_iter = self.application(environ, sr_checker)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File '/opt/galaxy/venv/lib/python2.7/site-packages/paste/recursive.py', line 85 in __call__
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: return self.application(environ, start_response)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/web/framework/middleware/statsd.py', line 40 in __call__
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: req = self.application(environ, start_response)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File '/opt/galaxy/venv/lib/python2.7/site-packages/paste/httpexceptions.py', line 640 in __call__
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: return self.application(environ, start_response)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/web/framework/base.py', line 143 in __call__
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: return self.handle_request(environ, start_response)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/web/framework/base.py', line 222 in handle_request
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: body = method(trans, **kwargs)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/web/framework/decorators.py', line 101 in decorator
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: return func(self, trans, *args, **kwargs)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/webapps/galaxy/controllers/admin_toolshed.py', line 560 in install_repositories
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: reinstalling=reinstalling,
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/tool_shed/galaxy_install/install_manager.py', line 846 in install_repositories
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: tool_panel_section_mapping=tool_panel_section_mapping)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/tool_shed/galaxy_install/install_manager.py', line 903 in install_tool_shed_repository
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: tool_panel_section_mapping=tool_panel_section_mapping)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/tool_shed/galaxy_install/install_manager.py', line 544 in __handle_repository_contents
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: repository_tools_tups = irmm.get_repository_tools_tups()
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/tool_shed/galaxy_install/metadata/installed_repository_metadata_manager.py', line 75 in get_repository_tools_tups
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: tool = self.app.toolbox.load_tool(os.path.abspath(load_relative_path), guid=guid, use_cached=False)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/tools/toolbox/base.py', line 825 in load_tool
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: tool = self.create_tool(config_file=config_file, tool_shed_repository=tool_shed_repository, guid=guid, **kwds)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/tools/__init__.py', line 280 in create_tool
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: return self._create_tool_from_source(tool_source, config_file=config_file, **kwds)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/tools/__init__.py', line 283 in _create_tool_from_source
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: return create_tool_from_source(self.app, tool_source, **kwds)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/tools/__init__.py', line 233 in create_tool_from_source
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: tool = ToolClass(config_file, tool_source, app, **kwds)
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: File 'lib/galaxy/tools/__init__.py', line 483 in __init__
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: raise e
Nov 09 13:11:15 sn04.bi.uni-freiburg.de uwsgi[3843198]: ValueError: invalid literal for int() with base 10: 'dbkey'
bgruening commented 5 years ago

Mh, it seems even worse. I have now fixed all our tools. This means all tools are updated and upgraded. The automatic installation, however, reset repositories. This is because we do have non-installable revisions in our YAML file. Revisions have been added in the past, they do not need to be strictly the latest installable one. That is not optimal, but I think those revisions should map indirectly to the next installable-revision. What happens currently, I think, is that this repositories crash with the below stacktrace and are then in "new" state. I can then indeed install that old revision - the repo is then shown as "there is an update available" ... and I can do the update (I do not mean the upgrade here).

@natefoo how do you handle that? Have you seen similar things?

Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: galaxy.web.framework.decorators ERROR 2019-11-10 23:53:09,788 [p:46171,w:1,m:0] [uWSGIWorker1Core0] Uncaught exception in exposed API method:
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: Traceback (most recent call last):
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: File "lib/galaxy/web/framework/decorators.py", line 282, in decorator
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: rval = func(self, trans, *args, **kwargs)
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: File "lib/galaxy/webapps/galaxy/api/tool_shed_repositories.py", line 531, in install_repository_revision
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: payload)
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: File "lib/tool_shed/galaxy_install/install_manager.py", line 700, in install
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: install_options
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: File "lib/tool_shed/galaxy_install/install_manager.py", line 799, in __initiate_and_install_repositories
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: return self.install_repositories(tsr_ids, decoded_kwd, reinstalling=False, install_options=install_options)
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: File "lib/tool_shed/galaxy_install/install_manager.py", line 846, in install_repositories
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: tool_panel_section_mapping=tool_panel_section_mapping)
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: File "lib/tool_shed/galaxy_install/install_manager.py", line 874, in install_tool_shed_repository
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: install_options=install_options)
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: File "lib/tool_shed/galaxy_install/install_manager.py", line 976, in update_tool_shed_repository
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: persist=True)
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: File "lib/tool_shed/galaxy_install/metadata/installed_repository_metadata_manager.py", line 29, in __init__
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: metadata_dict=metadata_dict, user=None)
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: File "lib/tool_shed/metadata/metadata_generator.py", line 64, in __init__
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: self.metadata_dict = {'shed_config_filename': self.shed_config_dict.get('config_filename', None)}
Nov 10 23:53:09 sn04.bi.uni-freiburg.de uwsgi[3615164]: AttributeError: 'NoneType' object has no attribute 'get'
mvdbeek commented 5 years ago

Looking into it now, I see a couple of things we can do to make this more robust.

mvdbeek commented 5 years ago

OK, I think I have fixed all of the issues in https://github.com/galaxyproject/galaxy/pull/8959, except the syntax error issue when parsing the integrated_tool_panel.xml file, but that shouldn't block installation. I've tested this manually and I think it works. I'll see if I can also come up with some integration tests for non-installable revision updates.

mvdbeek commented 5 years ago

Should be fixed by https://github.com/galaxyproject/galaxy/pull/8959. Hope the next round of updates will go smoothly @bgruening!

bgruening commented 5 years ago

I updated today the branch and currently it looks too good to be true: https://build.galaxyproject.eu/job/usegalaxy-eu/job/install-tools/161/console

:heart:

bgruening commented 5 years ago

I'm trying to understand whats happening, but it seems that newly installed tools are not added to the shed_tool_conf.yml ...

I swear I have seen it in the integrated_tool_conf ... but it's not in the shed_tool_conf ... :(

I will find time to investigate, but @natefoo maybe hold of running anything against main.

martenson commented 5 years ago

Just installing snippy, guess we will see soon. https://jenkins.galaxyproject.org/job/usegalaxy-tools/111/console