Error reading SSH protocol banner during replication

[Samuel Mutel]

Hello,

I am using FreeNAS 11.3. I have several replication task between the master FreeNas and a slave FreeNas.
Quite all replications are done at the same time so I receive a lot of error with message "Error reading SSH protocol banner during replication".
Some are working correctly some not. What is the issue here ? A ssh timeout or limit that I need to increase ?

Thanks.

 

[jvanas]

Same here. "Replication Tasks" display flips between nearly all "Finished" or all "Error" and the ones with error have the "Error reading SSH protocol banner" message in the drill down detail. The ones not running go back to "Finished" status on the next update. The ones in process just say "Waiting" and there is no way to get details of replication status. Although, it would appear the replication is working based on network statistics - but drilling down on "Waiting" button yields no information. Should state that this behavior seems unique to SSH+NETCAT transport.

 

[jvanas]

Found this in a Job log:
/tmp/middlewared/jobs # cat 2431.log

[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] Exception: Error reading SSH protocol banner
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] Traceback (most recent call last):
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] File "/usr/local/lib/python3.7/site-packages/paramiko/transport.py", line 2211, in _check_banner
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] buf = self.packetizer.readline(timeout)
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] File "/usr/local/lib/python3.7/site-packages/paramiko/packet.py", line 380, in readline
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] buf += self._read_timeout(timeout)
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] File "/usr/local/lib/python3.7/site-packages/paramiko/packet.py", line 609, in _read_timeout
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] raise EOFError()
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] EOFError
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17]
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] During handling of the above exception, another exception occurred:
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17]
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] Traceback (most recent call last):
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] File "/usr/local/lib/python3.7/site-packages/paramiko/transport.py", line 2039, in run
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] self._check_banner()
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] File "/usr/local/lib/python3.7/site-packages/paramiko/transport.py", line 2216, in _check_banner
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] "Error reading SSH protocol banner" + str(e)
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17] paramiko.ssh_exception.SSHException: Error reading SSH protocol banner
[2020/03/17 19:55:00] ERROR [Thread-3781] [zettarepl.paramiko.replication_task__task_17]
[2020/03/17 19:55:00] ERROR [replication_task__task_17] [zettarepl.replication.run] For task 'task_17' unhandled replication error SSHException('Error reading SSH protocol banner')
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/paramiko/transport.py", line 2211, in _check_banner
buf = self.packetizer.readline(timeout)
File "/usr/local/lib/python3.7/site-packages/paramiko/packet.py", line 380, in readline
buf += self._read_timeout(timeout)
File "/usr/local/lib/python3.7/site-packages/paramiko/packet.py", line 609, in _read_timeout
raise EOFError()
EOFError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/zettarepl/replication/run.py", line 139, in run_replication_tasks
run_replication_task_part(replication_task, source_dataset, src_context, dst_context, observer)
File "/usr/local/lib/python3.7/site-packages/zettarepl/replication/run.py", line 190, in run_replication_task_part
check_target_type(replication_task, source_dataset, src_context, dst_context)
File "/usr/local/lib/python3.7/site-packages/zettarepl/replication/run.py", line 209, in check_target_type
target_dataset_type = get_property(dst_context.shell, target_dataset, "type")
File "/usr/local/lib/python3.7/site-packages/zettarepl/transport/zfscli/__init__.py", line 76, in get_property
return get_properties(shell, dataset, {property: type})[property]
File "/usr/local/lib/python3.7/site-packages/zettarepl/transport/zfscli/__init__.py", line 69, in get_properties
for line in shell.exec(["zfs", "get", "-H", "-p", ",".join(properties.keys()), dataset]).strip().split("\n"):
File "/usr/local/lib/python3.7/site-packages/zettarepl/transport/interface.py", line 83, in exec
return self.exec_async(args, encoding, stdout).wait()
File "/usr/local/lib/python3.7/site-packages/zettarepl/transport/interface.py", line 87, in exec_async
async_exec.run()
File "/usr/local/lib/python3.7/site-packages/zettarepl/transport/base_ssh.py", line 24, in run
client = self.shell.get_client()
File "/usr/local/lib/python3.7/site-packages/zettarepl/transport/base_ssh.py", line 86, in get_client
auth_timeout=self.transport.connect_timeout,
File "/usr/local/lib/python3.7/site-packages/paramiko/client.py", line 406, in connect
t.start_client(timeout=timeout)
File "/usr/local/lib/python3.7/site-packages/paramiko/transport.py", line 660, in start_client
raise e
File "/usr/local/lib/python3.7/site-packages/paramiko/transport.py", line 2039, in run
self._check_banner()
File "/usr/local/lib/python3.7/site-packages/paramiko/transport.py", line 2216, in _check_banner
"Error reading SSH protocol banner" + str(e)
paramiko.ssh_exception.SSHException: Error reading SSH protocol banner

 

[Samuel Mutel]

It seems that it's related to https://github.com/paramiko/paramiko/issues/965. So the parameter banner_timeout needs to be updated in the FreeNAS code.
Do you have the directory service enabled ? I disabled the LDAP directory service and now I don't see the SSH protocol banner anymore.

 

[jvanas]

No, I don't have directory services (LDAP or other) enabled.

 

[jvanas]

So, there is nothing I can adjust on FreeNAS to resolve this? Should I file a bug report?