ssh transport : adapt for subclassing #4363

adegomme · 2020-09-09T13:36:57Z

follow up of #4199 ( and #4235)

To be able to release aiida-sshonly as a plugin without duplicating code, I had to make some tiny changes to ssh.py, easing its subclassing to better isolate the file transfer parts and keep sftp references wrapped.

this adds some simple wrappers around some sftp calls, that can be overriden in another class. Most methods don't need changing, as it has to be overriden fully, mainly utilities are changed (stat, lstat, symlink)
new method to initialize file transport separately. Also adds error checking for SFTP initialization, with an explicit message if it fails to launch, and a possible solution.
also limit the output of a log message to 1000 characters, as whole files can be printed in it when using a transport sending large ssh commands.

Merging this would would allow (even better if #3787 is also merged) the plugin to use ssh.py from aiida instead of a copy, which leads to incompatibilities and duplications.

- try to minimize intrusivity and changes in ssh.py (no new class/subclass) - initialization of the file transport is moved to another method - some calls are untouched, as they have to be overriden entirely - some calls had to be split (by adding a wrapper around the self.sftp call), so that only this wrapper is overriden.

When sending files with ssonly plugin, they get pasted entirely in the log otherwise.

codecov · 2020-09-09T13:53:21Z

Codecov Report

Merging #4363 into develop will decrease coverage by 0.03%.
The diff coverage is 80.77%.

@@             Coverage Diff             @@
##           develop    #4363      +/-   ##
===========================================
- Coverage    79.23%   79.20%   -0.02%     
===========================================
  Files          476      473       -3     
  Lines        34827    34800      -27     
===========================================
- Hits         27591    27560      -31     
- Misses        7236     7240       +4

Flag	Coverage Δ
#django	`73.09% <80.77%> (+0.05%)`	⬆️
#sqlalchemy	`72.29% <80.77%> (-<0.01%)`	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

Impacted Files	Coverage Δ
aiida/transports/plugins/ssh.py	`77.78% <80.77%> (+0.03%)`	⬆️
aiida/engine/daemon/runner.py	`79.32% <0.00%> (-3.44%)`	⬇️
aiida/engine/daemon/client.py	`72.42% <0.00%> (-1.14%)`	⬇️
aiida/orm/entities.py	`97.62% <0.00%> (-0.59%)`	⬇️
aiida/transports/plugins/local.py	`81.29% <0.00%> (-0.25%)`	⬇️
aiida/backends/sqlalchemy/models/group.py	`92.86% <0.00%> (-0.24%)`	⬇️
aiida/backends/djsite/db/models.py	`81.18% <0.00%> (-0.11%)`	⬇️
aiida/orm/nodes/data/remote.py	`58.52% <0.00%> (ø)`
aiida/backends/djsite/db/migrations/__init__.py	`68.84% <0.00%> (ø)`
...migrations/versions/0edcdd5a30f0_dbgroup_extras.py
... and 2 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 26f14ae...41cd80b. Read the comment docs.

ltalirz · 2020-09-15T21:42:47Z

thanks a lot, @adegomme !
@giovannipizzi would you be available for reviewing this?

ramirezfranciscof

Hi @adegomme , and thanks for this re-structuring! This all looks really good, I just had one modification request for the error message and maybe some discussion regarding the 1000 char cap on the logging.

aiida/transports/plugins/ssh.py

ramirezfranciscof · 2020-09-16T16:52:43Z

aiida/transports/plugins/ssh.py

@@ -1228,7 +1256,7 @@ def _exec_command_internal(self, command, combine_stderr=False, bufsize=-1):  #
        else:
            command_to_execute = command

-        self.logger.debug('Command to be executed: {}'.format(command_to_execute))
+        self.logger.debug('Command to be executed: {}'.format(command_to_execute[:1000]))


So the rest of the re-organization and wrapping of methods seems ok to me, but this is the only modification that I am unsure about. Can't you be loosing important log info like this? I would also maybe ask for the input of @giovannipizzi and/or @sphuber in this, since they probably know better what to expect inside that command and why is being logged.

Also interested to know why @adegomme thinks this should be cropped.

To send a file with the sshonly plugin, the resulting command is equivalent to ssh remote "echo '$(cat localfile)' | cat > remotefile" , with the '$(cat localfile)' being a python read instead, as I never managed to have the cat version behave correctly.
This logger call means that the whole content of the file is printed in the log :
example when making a 'verdi computer test'
09/17/2020 10:17:12 AM <1120861> aiida.transport.SshOnlyTransport: [DEBUG] Command to be executed: cd '/path/aiida' && echo 'Test from '"'"'verdi computer test'"'"' on 2020-09-17T10:17:05.830707' | cat > /path/aiida/tmpbtteknws

So this adds the whole file content to the log output when debug is activated, which is not great. Every input file, structure file, pseudopotential file gets printed in the stdout or the log when debug is on, and when several MB get dumped on you, this can be troublesome.
Cropping is meant to avoid ruining the log and the terminal. 1000 char is a bit arbitrary (but seemed to be large enough to not affect other messages in my tests), and maybe we could add a comment when it's cropped ( simply "...", or "cropped to 1000 chars to maintain readability") to avoid confusion.
Another idea would be to have an optional parameter on _exec_command_internal to disable this log message, but you would not see any file upload log in this case.

I see. Thanks for the explanation. In any case, even if we keep this, we should definitely comment this, because it is not obvious at all, especially given that the actual use case comes from a subclass that lives in another plugin package. @giovannipizzi do you see a way around this? If we make the cropping size an optional argument to the function, at least SshOnly can override the copy file method to call _exec_command_internal to pass max_log_size=1000 or something to that effect.

After discussing with @sphuber I think a good solution is to have a class attribute, e.g. _MAX_EXEC_COMMAND_LOG_SIZE=None in this base class.
Here the logic would not crop if self._MAX_EXEC_COMMAND_LOG_SIZE is None, otherwise it would crop to this length (command_to_execute[:self._MAX_EXEC_COMMAND_LOG_SIZE]).

In this way the current behaviour is unchanged, and in your subclass @adegomme you can just set _MAX_EXEC_COMMAND_LOG_SIZE to the value you want.

@adegomme what do you think? Are you OK to do this small change? After, it's ready to merge for me

sphuber

Thanks a lot @adegomme in addition to @ramirezfranciscof comments, I have some other small comments, but other than that this looks good and almost ready to go.

aiida/transports/plugins/ssh.py

Co-authored-by: ramirezfranciscof <[email protected]>

Add full plugin entry point please linter

…lugin name)

sphuber · 2020-09-17T14:11:11Z

Thanks for all the changes @adegomme . I am happy with the current state, except I would like to think a bit more about the cropping of the logging in the _exec_internal_command. Once we have the input of @giovannipizzi I think this should be ready to go.

giovannipizzi · 2020-09-23T09:51:50Z

aiida/transports/plugins/ssh.py

@@ -1228,7 +1256,7 @@ def _exec_command_internal(self, command, combine_stderr=False, bufsize=-1):  #
        else:
            command_to_execute = command

-        self.logger.debug('Command to be executed: {}'.format(command_to_execute))
+        self.logger.debug('Command to be executed: {}'.format(command_to_execute[:1000]))


After discussing with @sphuber I think a good solution is to have a class attribute, e.g. _MAX_EXEC_COMMAND_LOG_SIZE=None in this base class.
Here the logic would not crop if self._MAX_EXEC_COMMAND_LOG_SIZE is None, otherwise it would crop to this length (command_to_execute[:self._MAX_EXEC_COMMAND_LOG_SIZE]).

In this way the current behaviour is unchanged, and in your subclass @adegomme you can just set _MAX_EXEC_COMMAND_LOG_SIZE to the value you want.

@adegomme what do you think? Are you OK to do this small change? After, it's ready to merge for me

adegomme · 2020-09-23T09:56:31Z

The _MAX_EXEC_COMMAND_LOG_SIZE seems to be a great solution, I will do this immediately.

…g default behavior

Changes addressed

sphuber · 2020-09-23T11:30:39Z

Thanks a lot @adegomme !

adegomme added 4 commits September 9, 2020 14:34

limit output of this logger call to 1000 chars.

0689d2b

When sending files with ssonly plugin, they get pasted entirely in the log otherwise.

please linter

745ca9c

add docstrings

4543bf7

ramirezfranciscof previously requested changes Sep 16, 2020

View reviewed changes

sphuber requested changes Sep 16, 2020

View reviewed changes

aiida/transports/plugins/ssh.py Outdated Show resolved Hide resolved

aiida/transports/plugins/ssh.py Outdated Show resolved Hide resolved

aiida/transports/plugins/ssh.py Outdated Show resolved Hide resolved

aiida/transports/plugins/ssh.py Outdated Show resolved Hide resolved

adegomme and others added 7 commits September 17, 2020 09:45

clarify error message

5f22ff6

Co-authored-by: ramirezfranciscof <[email protected]>

Don't catch everything, just sshexception.

13fa71a

Add full plugin entry point please linter

add comments for stat/lstat functionality and output (from paramiko)

88b88c9

rename symlink_internal to _symlink

81319e4

try to avoid warning by circleci

a141f47

try again

5f84473

transport name was renamed (and be more explicit by giving the full p…

9f52676

…lugin name)

giovannipizzi previously requested changes Sep 23, 2020

View reviewed changes

adegomme and others added 2 commits September 23, 2020 12:26

allow subclasses to configure cropping of log message without changin…

bcab0a9

…g default behavior

Merge branch 'develop' into sshbase

41cd80b

sphuber approved these changes Sep 23, 2020

View reviewed changes

sphuber merged commit f2f6e2f into aiidateam:develop Sep 23, 2020

adegomme deleted the sshbase branch September 23, 2020 12:17

adegomme mentioned this pull request Feb 24, 2021

Avoid deadlocks when retrieving stdout/stderr via SSH #3787

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

ssh transport : adapt for subclassing #4363

ssh transport : adapt for subclassing #4363

adegomme commented Sep 9, 2020

codecov bot commented Sep 9, 2020 •

edited

Loading

ltalirz commented Sep 15, 2020

ramirezfranciscof left a comment

ramirezfranciscof Sep 16, 2020

sphuber Sep 16, 2020

adegomme Sep 17, 2020 •

edited

Loading

sphuber Sep 17, 2020

giovannipizzi Sep 23, 2020

sphuber left a comment

sphuber commented Sep 17, 2020

giovannipizzi Sep 23, 2020

adegomme commented Sep 23, 2020

sphuber commented Sep 23, 2020

ssh transport : adapt for subclassing #4363

ssh transport : adapt for subclassing #4363

Conversation

adegomme commented Sep 9, 2020

codecov bot commented Sep 9, 2020 • edited Loading

Codecov Report

ltalirz commented Sep 15, 2020

ramirezfranciscof left a comment

Choose a reason for hiding this comment

ramirezfranciscof Sep 16, 2020

Choose a reason for hiding this comment

sphuber Sep 16, 2020

Choose a reason for hiding this comment

adegomme Sep 17, 2020 • edited Loading

Choose a reason for hiding this comment

sphuber Sep 17, 2020

Choose a reason for hiding this comment

giovannipizzi Sep 23, 2020

Choose a reason for hiding this comment

sphuber left a comment

Choose a reason for hiding this comment

sphuber commented Sep 17, 2020

giovannipizzi Sep 23, 2020

Choose a reason for hiding this comment

adegomme commented Sep 23, 2020

sphuber commented Sep 23, 2020

codecov bot commented Sep 9, 2020 •

edited

Loading

adegomme Sep 17, 2020 •

edited

Loading