Performance issues with USS Download

[phaumer]

I am experiencing an odd performance problem with the download of USS files. I get expected response times for List, but Download seems to be hanging until timeout or something like that. Getting a 2k file takes over 2 minutes. When I download the same file via sftp command line it takes a few ms. Uploading the same file again takes 2.5 secs.

$ time zowe zftp ls uss /u/zoweph/projects/SAM/COPYBOOK/
CUSTCOPY.cpy 2511 ZOWEPH OMVS -rw-r--r--
TRANREC.cpy  1948 ZOWEPH OMVS -rw-r--r--
zowe zftp ls uss /u/zoweph/projects/SAM/COPYBOOK/  0.80s user 0.18s system 41% cpu 2.390 total

$ time zowe zftp download uss /u/zoweph/projects/SAM/COPYBOOK/CUSTCOPY.cpy
Successfully downloaded USS file '/u/zoweph/projects/SAM/COPYBOOK/CUSTCOPY.cpy' to local file 'CUSTCOPY.cpy'
zowe zftp download uss /u/zoweph/projects/SAM/COPYBOOK/CUSTCOPY.cpy  1.35s user 0.29s system 1% cpu **2:02.90 total**

$ time zowe zftp upload file-to-uss-file CUSTCOPY.cpy /u/zoweph/CUSTCOPY.cpy 
Uploaded from local file 'CUSTCOPY.cpy' to /u/zoweph/CUSTCOPY.cpy 
zowe zftp upload file-to-uss-file CUSTCOPY.cpy /u/zoweph/CUSTCOPY.cpy  0.79s user 0.18s system 39% cpu 2.486 total 

[phaumer]

@std4lqi any idea what could cause this problem? Thanks.

[std4lqi]

I cannot reproduce it at my end. I talked with Tina, who reproduced it. It seems the stream end event is received with some delay, or maybe not received at all, resulting in 2-min timeout. We'll look into it this week. Thanks!

[phaumer]

Are you on Node 8 @std4lqi ? I see this issue: mscdex/node-ftp#228

It looks like that this ftp library is old and not maintained anymore.

[phaumer]

I installed Node 8 and it confirms that it is related to the node version.

$ node -v                                       
v8.16.2
$ time zowe zftp download uss /u/haumer/SAM1.cbl
Successfully downloaded USS file '/u/haumer/SAM1.cbl' to local file 'SAM1.cbl'
zowe zftp download uss /u/haumer/SAM1.cbl  0.67s user 0.15s system 27% cpu 2.999 total

$ node -v 
v10.17.0
$ time zowe zftp download uss /u/haumer/SAM1.cbl  
Successfully downloaded USS file '/u/haumer/SAM1.cbl' to local file 'SAM1.cbl'
zowe zftp download uss /u/haumer/SAM1.cbl  1.29s user 0.27s system 1% cpu 2:02.99 total

[std4lqi]

Hi @phaumer Many thanks for your findings!

Yes, I'm on Node 8. Tina confirmed her Node 8 works well, while Node 10 and Node 12 have this problem.

The events, prefinish, finish, and close, are not received at the end of download from Node 10. Maybe it's also true for Node 12.

Will take some time to have better understanding.

[phaumer]

Would it make sense to switch to a new library such as https://github.com/patrickjuchli/basic-ftp ?

[std4lqi]

We consider to switch to an active repo forked from mscdex/node-ftp, to avoid big impact.

I post my findings at mscdex/node-ftp#228, and will run our system test to see any impact.

[phaumer]

Sounds great. Thanks a lot.

[phaumer]

@std4lqi I tried reapplying the changes you proposed as well, but it did not fix the problem for me (I was using the CLI api from within VS Code). For now I can only continue using basic-ftp with the zftp profile, which worked for me. Do you have an ETA for your fixes?

[std4lqi]

Hi @phaumer, I updated zos-node-accessor to 1.0.4, which uses std4lqi/node-ftp forked from mscdex/node-ftp. The mscdex/node-ftp#259 is created, and I hope it could be merged back if that repo is not completely abandoned.

The PR #25 is created for review.

[std4lqi]

Here is the result.

$ nvm use v8
Now using node v8.16.2 (npm v6.4.1)
$ time zowe zftp download ds "HLQ.ABC.TXT"
Data set downloaded successfully.
Destination: liangqi/abc/txt
zowe zftp download ds "HLQ.ABC.TXT"  0.92s user 0.25s system 14% cpu 8.002 total
$ nvm use v10
Now using node v10.17.0 (npm v6.11.3)
$ time zowe zftp download ds "HLQ.ABC.TXT"
Data set downloaded successfully.
Destination: liangqi/abc/txt
zowe zftp download ds "HLQ.ABC.TXT"  0.99s user 0.25s system 15% cpu 7.861 total
$ nvm use v12
Now using node v12.13.1 (npm v6.12.1)
$ time zowe zftp download ds "HLQ.ABC.TXT"
Data set downloaded successfully.
Destination: liangqi/abc/txt
zowe zftp download ds "HLQ.ABC.TXT"  0.83s user 0.26s system 14% cpu 7.792 total

[phaumer]

Awesome. I tried the command line ops and it worked for me as well.
Turns out though that stream breaks as a combination of one more bug I found with Issue #26.