Replication with SSH transport crash with compression enabled (any of LZ4/pigz/pizip)

[2020/02/02 22:19:57] INFO [MainThread] [zettarepl.scheduler.clock] Interrupted
[2020/02/02 22:19:57] INFO [MainThread] [zettarepl.zettarepl] Scheduled tasks: [<Replication Task 'task_19'>]
[2020/02/02 22:19:57] DEBUG [replication_task__task_19] [zettarepl.transport.local.shell.1.async_exec.547] Running ['zfs', 'get', '-H', '-p', 'type', 'pool0/ATUIN.NineX.info/NineX']
[2020/02/02 22:19:57] DEBUG [replication_task__task_19] [zettarepl.transport.local.shell.1.async_exec.547] Success: 'pool0/ATUIN.NineX.info/NineX\ttype\tfilesystem\t-\n'
[2020/02/02 22:19:57] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133] Connecting...
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] starting thread (client mode): 0x1159a650
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Local version/idstring: SSH-2.0-paramiko_2.7.1
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Remote version/idstring: SSH-2.0-OpenSSH_8.0-hpn14v15
[2020/02/02 22:19:57] INFO [Thread-245] [zettarepl.paramiko.replication_task__task_19] Connected (version 2.0, client OpenSSH_8.0-hpn14v15)
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] kex algos:['curve25519-sha256', 'curve25519-sha256@libssh.org', 'ecdh-sha2-nistp256', 'ecdh-sha2-nistp384', 'ecdh-sha2-nistp521', 'diffie-hellman-group-exchange-sha256', 'diffie-hellman-group16-sha512', 'diffie-hellman-group18-sha512', 'diffie-hellman-group14-sha256', 'diffie-hellman-group14-sha1'] server key:['rsa-sha2-512', 'rsa-sha2-256', 'ssh-rsa', 'ecdsa-sha2-nistp256', 'ssh-ed25519'] client encrypt:['chacha20-poly1305@openssh.com', 'aes128-ctr', 'aes192-ctr', 'aes256-ctr', 'aes128-gcm@openssh.com', 'aes256-gcm@openssh.com', 'aes128-cbc', 'none'] server encrypt:['chacha20-poly1305@openssh.com', 'aes128-ctr', 'aes192-ctr', 'aes256-ctr', 'aes128-gcm@openssh.com', 'aes256-gcm@openssh.com', 'aes128-cbc', 'none'] client mac:['umac-64-etm@openssh.com', 'umac-128-etm@openssh.com', 'hmac-sha2-256-etm@openssh.com', 'hmac-sha2-512-etm@openssh.com', 'hmac-sha1-etm@openssh.com', 'umac-64@openssh.com', 'umac-128@openssh.com', 'hmac-sha2-256', 'hmac-sha2-512', 'hmac-sha1'] server mac:['umac-64-etm@openssh.com', 'umac-128-etm@openssh.com', 'hmac-sha2-256-etm@openssh.com', 'hmac-sha2-512-etm@openssh.com', 'hmac-sha1-etm@openssh.com', 'umac-64@openssh.com', 'umac-128@openssh.com', 'hmac-sha2-256', 'hmac-sha2-512', 'hmac-sha1'] client compress:['none', 'zlib@openssh.com'] server compress:['none', 'zlib@openssh.com'] client lang:[''] server lang:[''] kex follows?False
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Kex agreed: ecdh-sha2-nistp256
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] HostKey agreed: ssh-ed25519
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Cipher agreed: aes128-ctr
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] MAC agreed: hmac-sha2-256
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Compression agreed: none
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] kex engine KexNistp256 specified hash_algo <built-in function openssl_sha256>
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Switch to new keys ...
[2020/02/02 22:19:57] DEBUG [replication_task__task_19] [zettarepl.paramiko.replication_task__task_19] Trying SSH key b'c4c2dfcf46bd4ba2492d777e85203a46'
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] userauth is OK
[2020/02/02 22:19:57] INFO [Thread-245] [zettarepl.paramiko.replication_task__task_19] Authentication (publickey) successful!
[2020/02/02 22:19:57] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.548] Running ['zfs', 'get', '-H', '-p', 'type', 'pool0/ATUIN.NineX.info/NineX']
[2020/02/02 22:19:57] DEBUG [replication_task__task_19] [zettarepl.paramiko.replication_task__task_19] [chan 0] Max packet in: 32768 bytes
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Received global request "hostkeys-00@openssh.com"
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Rejecting "hostkeys-00@openssh.com" global request from server.
[2020/02/02 22:19:57] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Debug msg: b'/mnt/pool0/ATUIN.NineX.info/.ssh/authorized_keys:2: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding'
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 0] Max packet out: 32768 bytes
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Secsh channel 0 opened.
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 0] Sesch channel 0 request ok
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.548] Waiting for exit status
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 0] EOF received (0)
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 0] EOF sent (0)
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.548] Success: 'pool0/ATUIN.NineX.info/NineX\ttype\tfilesystem\t-\n'
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.local.shell.1.async_exec.549] Running ['zfs', 'list', '-t', 'filesystem,volume', '-H', '-o', 'name', '-s', 'name', '-d', '1', 'pool0/ATUIN.NineX.info/NineX']
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.local.shell.1.async_exec.549] Success: 'pool0/ATUIN.NineX.info/NineX\n'
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.local.shell.1.async_exec.550] Running ['zfs', 'list', '-t', 'snapshot', '-H', '-o', 'name', '-s', 'name', '-d', '1', 'pool0/ATUIN.NineX.info/NineX']
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.local.shell.1.async_exec.550] Success: 'pool0/ATUIN.NineX.info/NineX@a....o/NineX@auto-2020-02-02_22-03\n'
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.551] Running ['zfs', 'list', '-t', 'filesystem,volume', '-H', '-o', 'name', '-s', 'name', '-d', '1', 'pool0/ATUIN.NineX.info/NineX']
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.paramiko.replication_task__task_19] [chan 1] Max packet in: 32768 bytes
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 1] Max packet out: 32768 bytes
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Secsh channel 1 opened.
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 1] Sesch channel 1 request ok
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.551] Waiting for exit status
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 1] EOF received (1)
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.551] Success: 'pool0/ATUIN.NineX.info/NineX\n'
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.paramiko.replication_task__task_19] [chan 1] EOF sent (1)
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.552] Running ['zfs', 'list', '-t', 'snapshot', '-H', '-o', 'name', '-s', 'name', '-d', '1', 'pool0/ATUIN.NineX.info/NineX']
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.paramiko.replication_task__task_19] [chan 2] Max packet in: 32768 bytes
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 2] Max packet out: 32768 bytes
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Secsh channel 2 opened.
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 2] Sesch channel 2 request ok
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.552] Waiting for exit status
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 2] EOF received (2)
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.552] Success: ''
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.paramiko.replication_task__task_19] [chan 2] EOF sent (2)
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.553] Running ['zfs', 'get', '-H', '-p', 'receive_resume_token', 'pool0/ATUIN.NineX.info/NineX']
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.paramiko.replication_task__task_19] [chan 3] Max packet in: 32768 bytes
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 3] Max packet out: 32768 bytes
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] Secsh channel 3 opened.
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 3] Sesch channel 3 request ok
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.553] Waiting for exit status
[2020/02/02 22:19:58] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] [chan 3] EOF received (3)
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.base_ssh.replicator@192.168.1.2.shell.133.async_exec.553] Success: 'pool0/ATUIN.NineX.info/NineX\treceive_resume_token\t-\t-\n'
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.paramiko.replication_task__task_19] [chan 3] EOF sent (3)
[2020/02/02 22:19:58] INFO [replication_task__task_19] [zettarepl.replication.run] For replication task 'task_19': doing push from 'pool0/ATUIN.NineX.info/NineX' to 'pool0/ATUIN.NineX.info/NineX' of snapshot='auto-2020-02-02_22-00' incremental_base=None receive_resume_token=None
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.local.shell.1.async_exec.554] Running ['zfs', 'send', '-V']
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.local.shell.1.async_exec.554] Error 2: 'missing snapshot argument\nusag.... list, run: zfs allow|unallow\n'
[2020/02/02 22:19:58] DEBUG [replication_task__task_19] [zettarepl.transport.local.shell.1.async_exec.556] Running ['sh', '-c', 'exec 3>&1\neval $(\nexec 4>&1 >&.... ] && exit $pipestatus1\nexit 0']
[2020/02/02 22:19:59] DEBUG [replication_task__task_19.async_exec_tee.wait] [zettarepl.transport.local.shell.1.async_exec.556] Error 141: None
[2020/02/02 22:19:59] DEBUG [replication_task__task_19.process] [zettarepl.transport.local.shell.1.async_exec.555] Error 141: "full send of pool0/ATUIN.NineX....ined variable.\nUnmatched '''.\n"
[2020/02/02 22:19:59] ERROR [replication_task__task_19] [zettarepl.replication.run] For task 'task_19' unhandled replication error ExecException(141, "full send of pool0/ATUIN.NineX.info/NineX@auto-2020-02-02_22-00 estimated size is 346G\nfull send of pool0/ATUIN.NineX.info/NineX@auto-2020-02-02_22-00 estimated size is 346G\nUnmatched '''.\nIllegal variable name.\nAmbiguous output redirect.\n{: Command not found.\n}: Command not found.\n{: Command not found.\n}: Command not found.\nToo many )'s.\npipestatus0: Undefined variable.\npipestatus1: Undefined variable.\nUnmatched '''.\n")
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/zettarepl/replication/run.py", line 119, 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 180, in run_replication_task_part
run_replication_steps(step_templates, observer)
File "/usr/local/lib/python3.7/site-packages/zettarepl/replication/run.py", line 352, in run_replication_steps
replicate_snapshots(step_template, incremental_base, snapshots, observer)
File "/usr/local/lib/python3.7/site-packages/zettarepl/replication/run.py", line 404, in replicate_snapshots
run_replication_step(step_template.instantiate(incremental_base=incremental_base, snapshot=snapshot), observer)
File "/usr/local/lib/python3.7/site-packages/zettarepl/replication/run.py", line 449, in run_replication_step
ReplicationProcessRunner(process, monitor).run()
File "/usr/local/lib/python3.7/site-packages/zettarepl/replication/process_runner.py", line 33, in run
raise self.process_exception
File "/usr/local/lib/python3.7/site-packages/zettarepl/replication/process_runner.py", line 37, in _wait_process
self.replication_process.wait()
File "/usr/local/lib/python3.7/site-packages/zettarepl/transport/ssh.py", line 146, in wait
self.async_exec.wait()
File "/usr/local/lib/python3.7/site-packages/zettarepl/transport/async_exec_tee.py", line 100, in wait
raise ExecException(exit_event.returncode, self.output)
zettarepl.transport.interface.ExecException: full send of pool0/ATUIN.NineX.info/NineX@auto-2020-02-02_22-00 estimated size is 346G
full send of pool0/ATUIN.NineX.info/NineX@auto-2020-02-02_22-00 estimated size is 346G
Unmatched '''.
Illegal variable name.
Ambiguous output redirect.
{: Command not found.
}: Command not found.
{: Command not found.
}: Command not found.
Too many )'s.
pipestatus0: Undefined variable.
pipestatus1: Undefined variable.
Unmatched '''.
[2020/02/02 22:19:59] DEBUG [replication_task__task_19.monitor] [zettarepl.transport.local.shell.1.async_exec.556] Stopping
[2020/02/02 22:19:59] DEBUG [Thread-245] [zettarepl.paramiko.replication_task__task_19] EOF in transport thread
[2020/02/02 22:19:59] INFO [Thread-247] [zettarepl.paramiko.retention] Connected (version 2.0, client OpenSSH_8.0-hpn14v15)
[2020/02/02 22:19:59] INFO [Thread-247] [zettarepl.paramiko.retention] Authentication (publickey) successful!
[2020/02/02 22:19:59] INFO [Thread-249] [zettarepl.paramiko.retention] Connected (version 2.0, client OpenSSH_8.0-hpn14v15)
[2020/02/02 22:19:59] INFO [Thread-249] [zettarepl.paramiko.retention] Authentication (publickey) successful!
[2020/02/02 22:20:00] INFO [Thread-251] [zettarepl.paramiko.retention] Connected (version 2.0, client OpenSSH_8.0-hpn14v15)
[2020/02/02 22:20:00] INFO [Thread-251] [zettarepl.paramiko.retention] Authentication (publickey) successful!
[2020/02/02 22:20:00] INFO [retention] [zettarepl.zettarepl] Retention destroying local snapshots: []
[2020/02/02 22:20:00] INFO [retention] [zettarepl.zettarepl] Retention on <SSH Transport(replicator@192.168.1.2)> destroying snapshots: []
[2020/02/02 22:20:00] INFO [Thread-253] [zettarepl.paramiko.retention] Connected (version 2.0, client OpenSSH_8.0-hpn14v15)
[2020/02/02 22:20:00] INFO [Thread-253] [zettarepl.paramiko.retention] Authentication (publickey) successful!
[2020/02/02 22:20:00] INFO [retention] [zettarepl.zettarepl] Retention on <SSH Transport(replicator@192.168.1.2)> destroying snapshots: []
[2020/02/02 22:20:00] ERROR [retention] [zettarepl.zettarepl] Unhandled exception while running retention
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/zettarepl/zettarepl.py", line 239, in _run_retention
self._run_remote_retention(self.retention_datetime)
File "/usr/local/lib/python3.7/site-packages/zettarepl/zettarepl.py", line 323, in _run_remote_retention
shell = self._get_retention_shell(transport)
File "/usr/local/lib/python3.7/site-packages/zettarepl/zettarepl.py", line 263, in _get_retention_shell
return self.retention_shells[transport]
KeyError: <SSH Transport(replicator@192.168.1.2)>