Uplink CLI 1.37.3 and ctrl-c

Developer Discussions troubleshooting
1

Saw some weirdness with uplink today when interrupting it. I tried ^C and it printed a new progress line. So tried a few ^C, ^Z, ^\ and it just got stuck. So I killed it from another shell:

mbp:~ jim$ time uplink cp big70 sj://hbtest/big70a
58.12 MiB / 70.00 MiB [-------------------------------------------------------------------------------->________________] 83.04% 8.01 MiB p/s58.12 MiB / 70.00 MiB [-------------------------------------------------------------------------------->________________] 83.04% 7.01 MiB p/s^C^C^C^C
^C^Z
^C^\
^\


real	1m16.939s
user	0m1.528s
sys	0m1.417s
mbp:~ jim$

Tried again, this time got a weird error:

mbp:~ jim$ uplink cp big70 sj://hbtest/big70a
0 B / 70.00 MiB [_______________________________________________________________________________________________________________] 0.00% ? p/serror closing project: uplink: lookup collectora.storj.io: no such host
	storj.io/uplink.(*Project).Close:151
	storj.io/storj/cmd/uplink/cmd.closeProject:116
	storj.io/storj/cmd/uplink/cmd.upload:122
	storj.io/storj/cmd/uplink/cmd.copyMain:470
	storj.io/private/process.cleanup.func1.4:363
	storj.io/private/process.cleanup.func1:381
	github.com/spf13/cobra.(*Command).execute:852
	github.com/spf13/cobra.(*Command).ExecuteC:960
	github.com/spf13/cobra.(*Command).Execute:897
	storj.io/private/process.ExecWithCustomConfig:88
	main.main:17
	runtime.main:204
Error: uplink: metaclient: rpc: dial tcp: lookup us1.storj.io: no such host

mbp:~ jim$ uplink version
Release build
Version: v1.37.3
Build timestamp: 14 Sep 21 09:57 EDT
Git commit: 0ded229c30d59f28bcd253788b03d3245c5e4571

Tried a 3rd time. Every ^C was ignored, but this time ^Z eventually worked to suspend it:

mbp:~ jim$ uplink cp big70 sj://hbtest/big70a
58.12 MiB / 70.00 MiB [-------------------------------------------------------------------------------->________________] 83.04% 2.38 MiB p/s58.12 MiB / 70.00 MiB 
... (more of these every time ^C pressed)
[------------------------------------------------------------------------------>________________] 83.04% 562.62 KiB p/s^Z
[4]+  Stopped                 uplink cp big70 sj://hbtest/big70a
mbp:~ jim$ jobs
[1]   Stopped                 emacs z.py
[2]   Stopped                 emacs z.py
[3]-  Stopped                 emacs z.py
[4]+  Stopped                 uplink cp big70 sj://hbtest/big70a

Tried to kill it but it’s like the Energizer bunny (keeps going and going). But it’s only transferring 6 bytes/s at the end. It did eventually stop on its own.

mbp:~ jim$ kill %4
58.12 MiB / 70.00 MiB [------------------------------------------------------------------------------>________________] 83.04% 526.32 KiB p/s
[4]+  Stopped                 uplink cp big70 sj://hbtest/big70a
58.12 MiB / 70.00 MiB [------------------------------------------------------------------------------>________________] 83.04% 181.06 KiB p/s
58.12 MiB / 70.00 MiB [------------------------------------------------------------------------------------>_________________] 83.04% 6 B p/s
Error: uplink: stream: context canceled; ecclient: upload cancelled by user

[4]+  Exit 1                  uplink cp big70 sj://hbtest/big70a
mbp:~ jim$
2 Likes
2

Well that’s not right.

Does this always happen to you, every time? Or was it a weird sequence of three different failure scenarios, and then it went back to working again? Just trying to get an idea of how hard this ought to be to reproduce (I’ve tried a dozen times on my own mbp here but ^C seems to do the right thing each time for me).

It should print out something like “ecclient: upload cancelled by user” and terminate.

I’m really confused by the ^Z behavior here, though. I’m nearly 100% certain that none of our code or dependencies tries to catch/block/ignore SIGTSTP, so I have no idea what could go wrong to make it seem like the process was hung instead. Is it at all possible that your system was heavily loaded or that your terminal emulator was doing something unusual?

3

I ran some more tests. I think a key thing is that I only have 1.25Mbit upload bandwidth, but the behavior is not completely explained by that.

I ran uplink again, hit ctrl-c 2 times, and waited:

mbp:hbrel jim$ uplink version
Release build
Version: v1.37.3
Build timestamp: 14 Sep 21 09:57 EDT
Git commit: 0ded229c30d59f28bcd253788b03d3245c5e4571
mbp:hbrel jim$ cd ..
mbp:~ jim$ ls -l big70
-rw-r--r--  1 jim  staff  73400320 Oct  4 13:08 big70
mbp:~ jim$ jobs
mbp:~ jim$ uplink cp big70 sj://hbtest/big70x
58.12 MiB / 70.00 MiB [-------------------------------------------------------------------------------->________________] 83.04% 8.06 MiB p/s58.12 MiB / 70.00 MiB [-------------------------------------------------------------------------------->________________] 83.04% 6.60 MiB p/s^C^C

This time it did stop, but it took a while, like a minute. What is strange is that it said it was 83% complete. This file should take around 7 minutes to upload.

For the next test, I did the same thing, but it started much slower. I’m thinking Spectrum (my ISP) might be doing some weird traffic shaping to get my upload bandwidth down to 1.25Mbit/s. The first upload triggered that, then on the 2nd one it was already slow. I dunno, just a guess. For this test I was going to let it run to completion to see how long it took, but it never finished. The progress bar kept reporting slower rates, down to 5 bytes/s, then 0 bytes/sec, then it just stayed there. I hit Enter a couple of times and it redisplayed the progress bar:

mbp:~ jim$ time uplink cp big70 sj://hbtest/big70x
64.03 MiB / 70.00 MiB [--------------------------------------------------------------------------------------------->________] 91.47% 0 B p/s
64.03 MiB / 70.00 MiB [--------------------------------------------------------------------------------------------->________] 91.47% 0 B p/s
64.03 MiB / 70.00 MiB [--------------------------------------------------------------------------------------------->________] 91.47% 0 B p/s

So now I hit ctrl-c. First time it displays another progress bar. 2nd time it displays ^c and quits:

64.03 MiB / 70.00 MiB [--------------------------------------------------------------------------------------------->________] 91.47% 0 B p/s^C

real	23m59.334s
user	0m8.129s
sys	0m8.848s

So I try again to do an upload, no interruptions:

mbp:~ jim$ time uplink cp big70 sj://hbtest/big70x
58.12 MiB / 70.00 MiB [------------------------------------------------------------------------------------>_________________] 83.04% 2 B p/sError: uplink: stream: ecclient: successful puts (0) less than or equal to repair threshold (35)

real	2m24.495s
user	0m3.092s
sys	0m3.276s

I guess my puny upload bandwidth, in combination with Spectrum’s traffic shaping, is causing uplink some heartburn.

4

Had another unusual uplink today trying to upload a 1g file with different --parallelism settings. 4 and 8 worked (this VM is an 8-cpu, 64GB system), but 16 failed almost immediately. So I tried 9, which worked, and then 10, which went into the weeds. It ran for a while, said it transferred 100%, then the bytes/s counter just kept going down until it got down to 5 bytes/s so I killed it.

[root@hbsj ~]# uplink cp test1g sj://hbtest --parallelism 4
1.00 GiB / 1.00 GiB [-------------------------------------------------------------------------------------------------] 100.00% 79.33 MiB p/s
Created sj://hbtest/test1g
[root@hbsj ~]# uplink cp test1g sj://hbtest --parallelism 8
1.00 GiB / 1.00 GiB [-------------------------------------------------------------------------------------------------] 100.00% 93.86 MiB p/s
Created sj://hbtest/test1g
[root@hbsj ~]# uplink cp test1g sj://hbtest --parallelism 16
832.09 MiB / 1.00 GiB [----------------------------------------------------------------------------->_________________] 81.26% 340.51 MiB p/sError: uplink: stream: ecclient: successful puts (0) less than or equal to repair threshold (35); uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user
[root@hbsj ~]# uplink cp test1g sj://hbtest --parallelism 16
83.12 MiB / 1.00 GiB [-------->_________________________________________________________________________________________________] 8.12% ? p/sError: uplink: stream: ecclient: successful puts (0) less than or equal to repair threshold (35); context canceled; context canceled; context canceled; context canceled; context canceled; context canceled; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: metaclient: context canceled; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user
[root@hbsj ~]# uplink cp test1g sj://hbtest --parallelism 9
1.00 GiB / 1.00 GiB [------------------------------------------------------------------------------------------------] 100.00% 102.95 MiB p/s
Created sj://hbtest/test1g
[root@hbsj ~]# uplink cp test1g sj://hbtest --parallelism 10
1.00 GiB / 1.00 GiB [------------------------------------------------------------------------------------------------------>] 100.00% 4 B p/s1.00 GiB / 1.00 GiB [------------------------------------------------------------------------------------------------------>] 100.00% 4 B p/sError: uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: metaclient: context canceled
[root@hbsj ~]# uplink version
Development build
Build timestamp: 25 Oct 21 15:15 UTC
Git commit: 85b49bb27c36fdd625dbe1c8086dddefa29f8b73

I tried again and 10 worked but 12 failed. But this time it exited on its own:

[root@hbsj ~]# /usr/bin/time -v uplink cp test1g sj://hbtest --parallelism 10
1.00 GiB / 1.00 GiB [-------------------------------------------------------------------------------------------------] 100.00% 94.35 MiB p/s
Created sj://hbtest/test1g
	Command being timed: "uplink cp test1g sj://hbtest --parallelism 10"
	User time (seconds): 51.21
	System time (seconds): 45.65
	Percent of CPU this job got: 873%
	Elapsed (wall clock) time (h:mm:ss or m:ss): 0:11.09
	Average shared text size (kbytes): 0
	Average unshared data size (kbytes): 0
	Average stack size (kbytes): 0
	Average total size (kbytes): 0
	Maximum resident set size (kbytes): 1037936
	Average resident set size (kbytes): 0
	Major (requiring I/O) page faults: 0
	Minor (reclaiming a frame) page faults: 14763
	Voluntary context switches: 31845
	Involuntary context switches: 1650
	Swaps: 0
	File system inputs: 0
	File system outputs: 2102016
	Socket messages sent: 0
	Socket messages received: 0
	Signals delivered: 0
	Page size (bytes): 4096
	Exit status: 0
[root@hbsj ~]# /usr/bin/time -v uplink cp test1g sj://hbtest --parallelism 12
1.00 GiB / 1.00 GiB [------------------------------------------------------------------------------------------------>] 100.00% 17.42 MiB p/sError: uplink: stream: ecclient: successful puts (15) less than or equal to repair threshold (35); uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user
Command exited with non-zero status 1
	Command being timed: "uplink cp test1g sj://hbtest --parallelism 12"
	User time (seconds): 45.18
	System time (seconds): 39.77
	Percent of CPU this job got: 396%
	Elapsed (wall clock) time (h:mm:ss or m:ss): 0:21.45
	Average shared text size (kbytes): 0
	Average unshared data size (kbytes): 0
	Average stack size (kbytes): 0
	Average total size (kbytes): 0
	Maximum resident set size (kbytes): 1006012
	Average resident set size (kbytes): 0
	Major (requiring I/O) page faults: 0
	Minor (reclaiming a frame) page faults: 14387
	Voluntary context switches: 58934
	Involuntary context switches: 1659
	Swaps: 0
	File system inputs: 0
	File system outputs: 2102016
	Page size (bytes): 4096
	Exit status: 1

I tried 12 again, but instead of failing fairly quickly like it did previously, it took almost a minute to fail.

[root@hbsj ~]# /usr/bin/time -v uplink cp test1g sj://hbtest --parallelism 12
1.00 GiB / 1.00 GiB [----------------------------------------------------------------------------------------------->] 100.00% 882.62 KiB p/sError: uplink: stream: ecclient: successful puts (6) less than or equal to repair threshold (35); uplink: stream: context canceled; ecclient: upload cancelled by user; uplink: stream: context canceled; ecclient: upload cancelled by user
Command exited with non-zero status 1
	Command being timed: "uplink cp test1g sj://hbtest --parallelism 12"
	User time (seconds): 46.54
	System time (seconds): 41.69
	Percent of CPU this job got: 147%
	Elapsed (wall clock) time (h:mm:ss or m:ss): 0:59.87
	Average shared text size (kbytes): 0
	Average unshared data size (kbytes): 0
	Average stack size (kbytes): 0
	Average total size (kbytes): 0
	Maximum resident set size (kbytes): 944728
	Average resident set size (kbytes): 0
	Major (requiring I/O) page faults: 0
	Minor (reclaiming a frame) page faults: 13149
	Voluntary context switches: 127872
	Involuntary context switches: 2016
	Swaps: 0
	File system inputs: 0
	File system outputs: 2102016
	Socket messages sent: 0
	Socket messages received: 0
	Signals delivered: 0
	Page size (bytes): 4096
	Exit status: 1

I’m doing tests with uplink to compare it to the S3MTGW for HashBackup.

Doesn’t seem to be a memory problem because it only used a bit over 1GB.

Another thing to mention is that uplink appears to always say “canceled by user”, even when it just fails.