search

pytroll / trollmoves

Server/Client -based file transfer in Python
GNU Lesser General Public License v3.0
7 stars 11 forks source link

Heartbeat not received when a transfer is in progress #131

Open TAlonglong opened 2 years ago

TAlonglong commented 2 years ago

Describe the bug When transfer large files or the connection is slow, heartbeats is not received during transfer.

To Reproduce

# Your code here

Expected behavior I expect the heartbeat to be received during transfer and not the connection to be restarted due missed heartbeats when transfer in progress.

Actual results Move-it-client logs:

[2022-10-03 05:47:57,500 DEBUG    trollmoves.client] Receiving (SUB) pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA file meos@<move-it-server> 2022-10-03T05:47:57.497649 v1.01 application/json {"
antenna": "XL-BAND", "sensor": ["mersi", "hiras", "vass"], "platform_name": "Fengyun-3D", "start_time": "2022-10-03T05:38:56", "end_time": "2022-10-03T05:47:57", "process_time": "20
22-10-03T05:38:56", "uid": "rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "type": "1", "orbit_number": "25305", "uri": "/data/rawd
ata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "request_address": "<move-it-server>:9109"}
[2022-10-03 05:47:57,500 DEBUG    trollmoves.heartbeat_monitor] Resetting heartbeat alarm timer to 60.0 sec
[2022-10-03 05:47:57,501 INFO     trollmoves.client] Requesting: pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA push ubuntu@fengyun-a 2022-10-03T05:47:57.501200 v1.01 application/json {"
antenna": "XL-BAND", "sensor": ["mersi", "hiras", "vass"], "platform_name": "Fengyun-3D", "start_time": "2022-10-03T05:38:56", "end_time": "2022-10-03T05:47:57", "process_time": "20
22-10-03T05:38:56", "uid": "rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "type": "1", "orbit_number": "25305", "uri": "/data/rawd
ata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "request_address": "<move-it-server>:9109", "destination": "scp://fengyun-a/data/p
ytroll/fengyun3/rawdata"}
[2022-10-03 05:47:57,502 DEBUG    trollmoves.client] Send and recv timeout is 240.00 seconds
[2022-10-03 05:48:57,603 DEBUG    trollmoves.heartbeat_monitor] Missing heartbeat alarm!
[2022-10-03 05:49:29,711 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
[2022-10-03 05:49:29,712 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
[2022-10-03 05:49:29,712 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
[2022-10-03 05:49:29,809 DEBUG    trollmoves.client] Receiving (SUB) pytroll://heartbeat/move_it_server beat eumetcast@sater6 2022-10-03T05:49:29.808737 v1.01 application/json {"min_interval": 30}
[2022-10-03 05:49:29,810 DEBUG    trollmoves.heartbeat_monitor] Resetting heartbeat alarm timer to 900.0 sec
[2022-10-03 05:49:57,078 DEBUG    trollmoves.client] Receiving (SUB) pytroll://heartbeat/move_it_server beat ubuntu@fengyun-a 2022-10-03T05:49:57.076502 v1.01 application/json {"min_interval": 30}
[2022-10-03 05:49:57,078 DEBUG    trollmoves.heartbeat_monitor] Resetting heartbeat alarm timer to 900.0 sec
[2022-10-03 05:49:57,654 DEBUG    trollmoves.heartbeat_monitor] Missing heartbeat alarm!
[2022-10-03 05:49:57,820 DEBUG    trollmoves.client] Receiving (SUB) pytroll://heartbeat/move_it_server beat eumetcast@sater5 2022-10-03T05:49:57.818825 v1.01 application/json {"min_interval": 30}
[2022-10-03 05:49:57,821 DEBUG    trollmoves.heartbeat_monitor] Resetting heartbeat alarm timer to 900.0 sec
[2022-10-03 05:49:59,743 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
[2022-10-03 05:49:59,744 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
[2022-10-03 05:49:59,745 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
[2022-10-03 05:49:59,839 DEBUG    trollmoves.client] Receiving (SUB) pytroll://heartbeat/move_it_server beat eumetcast@sater6 2022-10-03T05:49:59.839160 v1.01 application/json {"min_interval": 30}
[2022-10-03 05:49:59,840 DEBUG    trollmoves.heartbeat_monitor] Resetting heartbeat alarm timer to 900.0 sec
[2022-10-03 05:50:18,015 DEBUG    trollmoves.client] Receiving (REQ) pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA file meos@<move-it-server> 2022-10-03T05:50:17.936793 v1.01 application/json {"antenna": "XL-BAND", "sensor": ["mersi", "hiras", "vass"], "platform_name": "Fengyun-3D", "start_time": "2022-10-03T05:38:56", "end_time": "2022-10-03T05:47:57", "process_time": "2022-10-03T05:38:56", "uid": "rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "type": "1", "orbit_number": "25305", "uri": "/data/rawdata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "request_address": "<move-it-server>:9109", "destination": "scp://fengyun-a/data/pytroll/fengyun3/rawdata"}
[2022-10-03 05:50:18,015 DEBUG    trollmoves.client] Server done sending file
[2022-10-03 05:50:18,015 DEBUG    trollmoves.client] Add rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data to file cache
[2022-10-03 05:50:18,016 DEBUG    trollmoves.client] Sending a public 'ack' of completed transfer: pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA ack ubuntu@fengyun-a 2022-10-03T05:50:18.016318 v1.01 application/json {"antenna": "XL-BAND", "sensor": ["mersi", "hiras", "vass"], "platform_name": "Fengyun-3D", "start_time": "2022-10-03T05:38:56", "end_time": "2022-10-03T05:47:57", "process_time": "2022-10-03T05:38:56", "uid": "rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "type": "1", "orbit_number": "25305", "uri": "/data/rawdata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "request_address": "<move-it-server>:9109"}
[2022-10-03 05:50:18,023 DEBUG    trollmoves.client] publishing pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA file ubuntu@fengyun-a 2022-10-03T05:50:18.017102 v1.01 application/json {"antenna": "XL-BAND", "sensor": ["mersi", "hiras", "vass"], "platform_name": "fengyun 3d", "start_time": "2022-10-03T05:38:56", "end_time": "2022-10-03T05:47:57", "process_time": "2022-10-03T05:38:56", "uid": "rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "type": "1", "orbit_number": "25305", "uri": "ssh://fengyun-a/data/pytroll/fengyun3/rawdata/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "origin": "<move-it-server>:9109"}
[2022-10-03 05:50:18,023 DEBUG    trollmoves.client] Remove uid 20f5d7994f0033bd9db078f826867045: []
[2022-10-03 05:50:18,024 WARNING  trollmoves.client] Missing a heartbeat, restarting the subscriber to dict_values(['tcp://<move-it-server>:9019']).
[2022-10-03 05:50:19,026 DEBUG    trollmoves.client] Exiting listener tcp://<move-it-server>:9019
[2022-10-03 05:50:19,026 DEBUG    trollmoves.client] Starting listener tcp://<move-it-server>:9019
[2022-10-03 05:50:19,026 INFO     trollmoves.client] Subscribing to tcp://<move-it-server>:9019 with topics ['/XLBANDANTENNA/FENGYUN3D/RAWDATA', '/heartbeat/move_it_server', '/heartbeat/move_it_RAWDATA-FENGYUN3D']
[2022-10-03 05:50:19,027 INFO     posttroll.subscriber] Subscriber adding address tcp://<move-it-server>:9019 with topics ['pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA', 'pytroll://heartbeat/move_it_server', 'pytroll://heartbeat/move_it_RAWDATA-FENGYUN3D']

Environment Info:

Additional context Add any other context about the problem here.

TAlonglong commented 2 years ago

move-it-server logs

Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,496 DEBUG    trollmoves.server] We have a match: /data/rawdata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_202210
03T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,498 DEBUG    trollmoves.server] Message sent: pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA file meos@satrec2 20
22-10-03T05:47:57.497649 v1.01 application/json {"antenna": "XL-BAND", "sensor": ["mersi", "hiras", "vass"], "platform_name": "Fengyun-3D", "start_time": "2022-10-03T05:38:56", "end
_time": "2022-10-03T05:47:57", "process_time": "2022-10-03T05:38:56", "uid": "rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "type"
: "1", "orbit_number": "25305", "uri": "/data/rawdata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "request_address": "157.249.1
7.67:9109"}
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,511 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,519 DEBUG    trollmoves.server] Received a request
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,521 DEBUG    trollmoves.server] processing request: pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA push ubuntu@fe
ngyun-b 2022-10-03T05:47:57.499965 v1.01 application/json {"antenna": "XL-BAND", "sensor": ["mersi", "hiras", "vass"], "platform_name": "Fengyun-3D", "start_time": "2022-10-03T05:38
:56", "end_time": "2022-10-03T05:47:57", "process_time": "2022-10-03T05:38:56", "uid": "rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.dat
a", "type": "1", "orbit_number": "25305", "uri": "/data/rawdata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "request_address": 
"157.249.17.67:9109", "destination": "scp://fengyun-b/data/pytroll/fengyun3/rawdata"}
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,522 DEBUG    trollmoves.movers] new_dest = ParseResult(scheme='scp', netloc='ubuntu@fengyun-b', path='/data/
pytroll/fengyun3/rawdata', params='', query='', fragment='')
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,522 DEBUG    trollmoves.movers] Copying to: scp://fengyun-b/data/pytroll/fengyun3/rawdata
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,522 DEBUG    trollmoves.movers] Scheme = scp
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,522 DEBUG    trollmoves.movers] Destination: ParseResult(scheme='scp', netloc='ubuntu@fengyun-b', path='/dat
a/pytroll/fengyun3/rawdata', params='', query='', fragment='')
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,522 DEBUG    trollmoves.movers] Destination username and passwd: ubuntu None
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,522 DEBUG    trollmoves.movers] Getting connection to ubuntu@fengyun-b:22
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,522 DEBUG    trollmoves.server] Received a request
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,524 DEBUG    trollmoves.server] processing request: pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA push ubuntu@fe
ngyun-a 2022-10-03T05:47:57.501547 v1.01 application/json {"antenna": "XL-BAND", "sensor": ["mersi", "hiras", "vass"], "platform_name": "Fengyun-3D", "start_time": "2022-10-03T05:38
:56", "end_time": "2022-10-03T05:47:57", "process_time": "2022-10-03T05:38:56", "uid": "rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.dat
a", "type": "1", "orbit_number": "25305", "uri": "/data/rawdata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "request_address": 
"157.249.17.67:9109", "destination": "scp://fengyun-a/data/pytroll/fengyun3/rawdata"}
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,525 DEBUG    trollmoves.movers] new_dest = ParseResult(scheme='scp', netloc='ubuntu@fengyun-a', path='/data/
pytroll/fengyun3/rawdata', params='', query='', fragment='')
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,526 DEBUG    trollmoves.movers] Copying to: scp://fengyun-a/data/pytroll/fengyun3/rawdata
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,526 DEBUG    trollmoves.movers] Scheme = scp
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,526 DEBUG    trollmoves.movers] Destination: ParseResult(scheme='scp', netloc='ubuntu@fengyun-a', path='/data/pytroll/fengyun3/rawdata', params='', query='', fragment='')
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,535 DEBUG    paramiko.transport] starting thread (client mode): 0x507eb910
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,535 DEBUG    paramiko.transport] Local version/idstring: SSH-2.0-paramiko_2.11.0
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,572 DEBUG    paramiko.transport] Remote version/idstring: SSH-2.0-OpenSSH_7.6p1 Ubuntu-4ubuntu0.5
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,573 INFO     paramiko.transport] Connected (version 2.0, client OpenSSH_7.6p1)
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,577 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,577 DEBUG    paramiko.transport] 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
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,577 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,577 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,577 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,577 DEBUG    paramiko.transport] 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
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,577 DEBUG    paramiko.transport] 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
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,577 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,578 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,578 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,578 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,578 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,578 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,578 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,578 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,578 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,579 DEBUG    paramiko.transport] Compression: none
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,579 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,597 DEBUG    paramiko.transport] kex engine KexCurve25519 specified hash_algo <built-in function openssl_sha256>
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,597 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,598 DEBUG    paramiko.transport] Adding ssh-ed25519 host key for fengyun-b: b'43fda2e5b513f5c89ba406a32d42eb97'
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,599 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,632 DEBUG    paramiko.transport] Trying discovered key b'2066c2b40e17399ae6a836ac02bcc30c' in /home/meos/.ssh/id_rsa
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,639 DEBUG    paramiko.transport] userauth is OK
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,640 DEBUG    paramiko.transport] Finalizing pubkey algorithm for key of type 'ssh-rsa'
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,640 DEBUG    paramiko.transport] Our pubkey algorithm list: ['rsa-sha2-512', 'rsa-sha2-256', 'ssh-rsa']
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,640 DEBUG    paramiko.transport] Server-side algorithm list: ['ssh-ed25519', 'ssh-rsa', 'rsa-sha2-256', 'rsa-sha2-512', 'ssh-dss', 'ecdsa-sha2-nistp256', 'ecdsa-sha2-nistp384', 'ecdsa-sha2-nistp521']
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,640 DEBUG    paramiko.transport] Agreed upon 'rsa-sha2-512' pubkey algorithm
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,676 INFO     paramiko.transport] Authentication (publickey) successful!
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,676 DEBUG    trollmoves.movers] Successfully connected to fengyun-b:22 as ubuntu
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,677 DEBUG    paramiko.transport] [chan 0] Max packet in: 32768 bytes
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,677 DEBUG    trollmoves.movers] Destination username and passwd: ubuntu None
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,678 DEBUG    trollmoves.movers] Getting connection to ubuntu@fengyun-a:22
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,689 DEBUG    paramiko.transport] starting thread (client mode): 0x50623490
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,689 DEBUG    paramiko.transport] Local version/idstring: SSH-2.0-paramiko_2.11.0
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,738 DEBUG    paramiko.transport] Remote version/idstring: SSH-2.0-OpenSSH_7.6p1 Ubuntu-4ubuntu0.5
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,739 INFO     paramiko.transport] Connected (version 2.0, client OpenSSH_7.6p1)
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,742 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,742 DEBUG    paramiko.transport] 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
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,742 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,743 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,743 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,743 DEBUG    paramiko.transport] 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
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,743 DEBUG    paramiko.transport] 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
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,743 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,743 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,743 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,743 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,743 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,743 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,744 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,744 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,744 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,744 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,744 DEBUG    paramiko.transport] Compression: none
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,744 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,767 DEBUG    paramiko.transport] kex engine KexCurve25519 specified hash_algo <built-in function openssl_sha256>
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,768 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,769 DEBUG    paramiko.transport] Adding ssh-ed25519 host key for fengyun-a: b'4a4d0005b2da1f7dfee941c278f0f700'
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,769 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,801 DEBUG    paramiko.transport] Trying discovered key b'2066c2b40e17399ae6a836ac02bcc30c' in /home/meos/.ssh/id_rsa
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,811 DEBUG    paramiko.transport] userauth is OK
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,811 DEBUG    paramiko.transport] Finalizing pubkey algorithm for key of type 'ssh-rsa'
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,811 DEBUG    paramiko.transport] Our pubkey algorithm list: ['rsa-sha2-512', 'rsa-sha2-256', 'ssh-rsa']
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,812 DEBUG    paramiko.transport] Server-side algorithm list: ['ssh-ed25519', 'ssh-rsa', 'rsa-sha2-256', 'rsa-sha2-512', 'ssh-dss', 'ecdsa-sha2-nistp256', 'ecdsa-sha2-nistp384', 'ecdsa-sha2-nistp521']
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,812 DEBUG    paramiko.transport] Agreed upon 'rsa-sha2-512' pubkey algorithm
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,848 INFO     paramiko.transport] Authentication (publickey) successful!
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,848 DEBUG    trollmoves.movers] Successfully connected to fengyun-a:22 as ubuntu
Oct 03 05:47:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:57,849 DEBUG    paramiko.transport] [chan 0] Max packet in: 32768 bytes
Oct 03 05:47:58 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:58,922 DEBUG    paramiko.transport] Received global request "hostkeys-00@openssh.com"
Oct 03 05:47:58 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:58,922 DEBUG    paramiko.transport] Rejecting "hostkeys-00@openssh.com" global request from server.
Oct 03 05:47:58 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:58,966 DEBUG    paramiko.transport] [chan 0] Max packet out: 32768 bytes
Oct 03 05:47:58 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:58,967 DEBUG    paramiko.transport] Secsh channel 0 opened.
Oct 03 05:47:58 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:58,970 DEBUG    paramiko.transport] [chan 0] Sesch channel 0 request ok
Oct 03 05:47:59 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:59,195 DEBUG    paramiko.transport] Received global request "hostkeys-00@openssh.com"
Oct 03 05:47:59 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:59,195 DEBUG    paramiko.transport] Rejecting "hostkeys-00@openssh.com" global request from server.
Oct 03 05:47:59 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:59,237 DEBUG    paramiko.transport] [chan 0] Max packet out: 32768 bytes
Oct 03 05:47:59 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:59,237 DEBUG    paramiko.transport] Secsh channel 0 opened.
Oct 03 05:47:59 satrec2 move_it_server.py[3491769]: [2022-10-03 05:47:59,241 DEBUG    paramiko.transport] [chan 0] Sesch channel 0 request ok
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,445 DEBUG    paramiko.transport] Rekeying (hit 32646 packets, 536880768 bytes sent)
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,492 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,492 DEBUG    paramiko.transport] 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
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,493 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,493 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,493 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,493 DEBUG    paramiko.transport] 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
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,494 DEBUG    paramiko.transport] 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
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,494 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,494 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,494 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,494 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,495 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,495 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,495 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,495 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,496 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,496 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,496 DEBUG    paramiko.transport] Compression: none
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,496 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,518 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:48:20 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:20,521 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,299 DEBUG    paramiko.transport] Rekeying (hit 32646 packets, 536880768 bytes sent)
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,303 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,303 DEBUG    paramiko.transport] 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
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,304 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,304 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,304 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,305 DEBUG    paramiko.transport] 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
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,305 DEBUG    paramiko.transport] 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
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,305 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,305 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,305 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,306 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,306 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,306 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,306 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,306 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,306 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,307 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,307 DEBUG    paramiko.transport] Compression: none
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,307 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,320 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:48:21 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:21,322 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:48:27 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:27,552 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,772 DEBUG    paramiko.transport] Rekeying (hit 32641 packets, 536879168 bytes sent)
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,778 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,778 DEBUG    paramiko.transport] 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
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,778 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,779 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,779 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,779 DEBUG    paramiko.transport] 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
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,779 DEBUG    paramiko.transport] 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
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,779 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,779 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,779 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,779 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,780 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,780 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,780 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,780 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,780 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,780 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,780 DEBUG    paramiko.transport] Compression: none
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,780 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,793 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:48:43 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:43,794 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,031 DEBUG    paramiko.transport] Rekeying (hit 32641 packets, 536879168 bytes sent)
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,037 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,037 DEBUG    paramiko.transport] 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
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,037 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,037 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,037 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,038 DEBUG    paramiko.transport] 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
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,038 DEBUG    paramiko.transport] 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
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,038 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,038 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,038 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,038 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,038 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,038 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,038 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,039 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,039 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,039 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,039 DEBUG    paramiko.transport] Compression: none
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,039 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,055 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:48:45 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:45,058 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:48:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:48:57,592 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,114 DEBUG    paramiko.transport] Rekeying (hit 32641 packets, 536879168 bytes sent)
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,119 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,120 DEBUG    paramiko.transport] 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
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,120 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,120 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,120 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,120 DEBUG    paramiko.transport] 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
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,121 DEBUG    paramiko.transport] 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
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,121 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,121 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,121 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,122 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,122 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,122 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,122 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,123 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,123 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,123 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,123 DEBUG    paramiko.transport] Compression: none
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,124 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,138 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,140 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,613 DEBUG    paramiko.transport] Rekeying (hit 32641 packets, 536879168 bytes sent)
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,616 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,616 DEBUG    paramiko.transport] 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
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,616 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,617 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,617 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,617 DEBUG    paramiko.transport] 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
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,618 DEBUG    paramiko.transport] 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
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,618 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,618 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,619 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,619 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,620 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,620 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,620 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,620 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,621 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,621 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,621 DEBUG    paramiko.transport] Compression: none
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,622 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,634 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:49:08 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:08,636 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:49:27 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:27,632 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,059 DEBUG    paramiko.transport] Rekeying (hit 32641 packets, 536879168 bytes sent)
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,066 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,066 DEBUG    paramiko.transport] 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
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,067 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,067 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,067 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,067 DEBUG    paramiko.transport] 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
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,067 DEBUG    paramiko.transport] 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
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,068 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,068 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,068 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,068 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,069 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,069 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,069 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,070 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,070 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,070 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,071 DEBUG    paramiko.transport] Compression: none
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,071 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,088 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,091 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,104 DEBUG    paramiko.transport] Rekeying (hit 32641 packets, 536879168 bytes sent)
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,155 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,156 DEBUG    paramiko.transport] 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
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,156 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,156 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,157 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,157 DEBUG    paramiko.transport] 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
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,157 DEBUG    paramiko.transport] 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
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,157 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,158 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,158 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,158 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,158 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,158 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,159 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,159 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,159 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,160 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,160 DEBUG    paramiko.transport] Compression: none
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,160 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,173 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:49:32 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:32,175 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,171 DEBUG    paramiko.transport] Rekeying (hit 32641 packets, 536879168 bytes sent)
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,224 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,224 DEBUG    paramiko.transport] 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
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,224 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,224 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,224 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,225 DEBUG    paramiko.transport] 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
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,225 DEBUG    paramiko.transport] 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
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,225 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,226 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,226 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,226 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,226 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,226 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,226 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,227 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,227 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,227 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,227 DEBUG    paramiko.transport] Compression: none
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,227 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,243 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,245 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,784 DEBUG    paramiko.transport] Rekeying (hit 32641 packets, 536879168 bytes sent)
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,836 DEBUG    paramiko.transport] === Key exchange possibilities ===
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,836 DEBUG    paramiko.transport] 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
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,837 DEBUG    paramiko.transport] server key: ssh-rsa, rsa-sha2-512, rsa-sha2-256, ecdsa-sha2-nistp256, ssh-ed25519
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,837 DEBUG    paramiko.transport] client encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,837 DEBUG    paramiko.transport] server encrypt: chacha20-poly1305@openssh.com, aes128-ctr, aes192-ctr, aes256-ctr, aes128-gcm@openssh.com, aes256-gcm@openssh.com
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,837 DEBUG    paramiko.transport] 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
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,837 DEBUG    paramiko.transport] 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
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,838 DEBUG    paramiko.transport] client compress: none, zlib@openssh.com
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,838 DEBUG    paramiko.transport] server compress: none, zlib@openssh.com
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,838 DEBUG    paramiko.transport] client lang: <none>
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,838 DEBUG    paramiko.transport] server lang: <none>
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,838 DEBUG    paramiko.transport] kex follows: False
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,838 DEBUG    paramiko.transport] === Key exchange agreements ===
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,839 DEBUG    paramiko.transport] Kex: curve25519-sha256@libssh.org
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,839 DEBUG    paramiko.transport] HostKey: ssh-ed25519
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,839 DEBUG    paramiko.transport] Cipher: aes128-ctr
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,840 DEBUG    paramiko.transport] MAC: hmac-sha2-256
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,840 DEBUG    paramiko.transport] Compression: none
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,840 DEBUG    paramiko.transport] === End of kex handshake ===
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,857 DEBUG    paramiko.transport] Switch to new keys ...
Oct 03 05:49:55 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:55,859 DEBUG    paramiko.transport] Got EXT_INFO: {'server-sig-algs': b'ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521'}
Oct 03 05:49:57 satrec2 move_it_server.py[3491769]: [2022-10-03 05:49:57,668 DEBUG    posttroll.publisher] Publish heartbeat (min_interval is 30.0 sec)
Oct 03 05:50:17 satrec2 move_it_server.py[3491769]: [2022-10-03 05:50:17,936 DEBUG    paramiko.transport] [chan 0] EOF sent (0)
Oct 03 05:50:17 satrec2 move_it_server.py[3491769]: [2022-10-03 05:50:17,936 INFO     trollmoves.movers] Successfully copied /data/rawdata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data to scp://fengyun-a/data/pytroll/fengyun3/rawdata
Oct 03 05:50:17 satrec2 move_it_server.py[3491769]: [2022-10-03 05:50:17,937 DEBUG    trollmoves.server] Response: pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA file meos@satrec2 2022-10-03T05:50:17.936793 v1.01 application/json {"antenna": "XL-BAND", "sensor": ["mersi", "hiras", "vass"], "platform_name": "Fengyun-3D", "start_time": "2022-10-03T05:38:56", "end_time": "2022-10-03T05:47:57", "process_time": "2022-10-03T05:38:56", "uid": "rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "type": "1", "orbit_number": "25305", "uri": "/data/rawdata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "request_address": "157.249.17.67:9109", "destination": "scp://fengyun-a/data/pytroll/fengyun3/rawdata"}
Oct 03 05:50:17 satrec2 move_it_server.py[3491769]: [2022-10-03 05:50:17,937 DEBUG    paramiko.transport] [chan 0] EOF received (0)
Oct 03 05:50:18 satrec2 move_it_server.py[3491769]: [2022-10-03 05:50:18,417 DEBUG    paramiko.transport] [chan 0] EOF sent (0)
Oct 03 05:50:18 satrec2 move_it_server.py[3491769]: [2022-10-03 05:50:18,418 INFO     trollmoves.movers] Successfully copied /data/rawdata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data to scp://fengyun-b/data/pytroll/fengyun3/rawdata
Oct 03 05:50:18 satrec2 move_it_server.py[3491769]: [2022-10-03 05:50:18,418 DEBUG    trollmoves.server] Response: pytroll://XLBANDANTENNA/FENGYUN3D/RAWDATA file meos@satrec2 2022-10-03T05:50:18.418225 v1.01 application/json {"antenna": "XL-BAND", "sensor": ["mersi", "hiras", "vass"], "platform_name": "Fengyun-3D", "start_time": "2022-10-03T05:38:56", "end_time": "2022-10-03T05:47:57", "process_time": "2022-10-03T05:38:56", "uid": "rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "type": "1", "orbit_number": "25305", "uri": "/data/rawdata1/rawdata_FY3D_MPT_ch1_20221003T053856Z_20221003T054757Z_20221003T053856Z_IwmdPIGV3_1_25305.data", "request_address": "157.249.17.67:9109", "destination": "scp://fengyun-b/data/pytroll/fengyun3/rawdata"}
Oct 03 05:50:18 satrec2 move_it_server.py[3491769]: [2022-10-03 05:50:18,420 DEBUG    paramiko.transport] [chan 0] EOF received (0)