Java apache commons FTPClient fails allocating space for destination mainframe file

Question

Here's a work problem I've been attacking diligently for about a week now without success.

I have legacy Java code that uses the apache commons net FTPClient library to send a file to a mainframe. The code works perfectly for files under 86Mb. However, when it encounters a file over 86Mb, it fails with a CopyStreamException (with no other useful information). I've added timeouts and a CopyStreamListener to no avail. The listener outputs some messages indicating that the ftp is successfully uploading buffers of data to the mainframe until it gets to 86Mb (sample log output is included below).

I originally thought the problem was network/firewall related (which is why you see so many timeout manipulations in the code), but now I understand it has to do with the space allocation commands I am sending to the mainframe. I have gotten assistance from a mainframe expert here and he has made NUMEROUS suggestions as to different combinations of BLKSIZE, SPACE, LRECL, etc. But none of them have worked. I did get the transfer to work to completion one time, however the mainframe guy then informed me that the blocksize and format parameters of the file created on the mainframe were incorrect, so I had to scrap that (I'll explain what it was that worked in this case down below).

First, here's the Java code:

public static boolean copyFileThruFTP(
    String srcFileName, String remoteFileName, Properties exportProps) {
    boolean success = true;
    String serverUserName = exportProps.getProperty(WebUtil.FTP_SERVER_USER);
    String serverPwd = exportProps.getProperty(WebUtil.FTP_SERVER_PWD);
    String serverIp = exportProps.getProperty(WebUtil.FTP_SERVER_IP);
    File f = new File(srcFileName);
    FTPClient ftpClient = null;
    try {
        String errorMessage = null;
        FileInputStream input = new FileInputStream(f);
        ftpClient = new FTPClient();

        ftpClient.setDataTimeout(6000000); // 100 minutes
        ftpClient.setConnectTimeout(6000000); // 100 minutes
        ftpClient.connect(serverIp);
        int reply = ftpClient.getReplyCode();

        if (!FTPReply.isPositiveCompletion(reply)) {
            errorMessage = "FTP server refused connection: " + ftpClient.getReplyString();
        } else {
            if (!ftpClient.login(serverUserName,serverPwd)) {
                errorMessage = "Failed to copy file thru FTP: login failed.";
            } else {
                ftpClient.setBufferSize(1024000);
                ftpClient.setControlKeepAliveTimeout(30); // sends a keepalive every thirty seconds

                if (ftpClient.deleteFile(remoteFileName)) {
                    log.warn("Deleted existing file from remote server: " + remoteFileName);
                }
                ftpClient.setFileTransferMode(FTP.ASCII_FILE_TYPE);
                ftpClient.setFileType(FTP.ASCII_FILE_TYPE);
                ftpClient.sendSiteCommand("RECFM=FB");
                ftpClient.sendSiteCommand("LRECL=2000");
                ftpClient.sendSiteCommand("BLKSIZE=27000");
                //ftpClient.sendSiteCommand("DCB=(RECFM=FB,LRECL=2000,BLKSIZE=26000)");
                ftpClient.sendSiteCommand("SPACE=(TRK,(500,500),RLSE)");

                OutputStream ftpOut = ftpClient.storeFileStream(remoteFileName);
                if (ftpOut == null) {
                    errorMessage = "FTP server could not open file for write: " + ftpClient.getReplyString();
                } else {
                    OutputStream output = new BufferedOutputStream(ftpOut);

                    log.warn("copyFileThruFTP calling copyStream() for file: " + f.getAbsolutePath());
                    Util.copyStream(input, output, ftpClient.getBufferSize(), f.length(),
                        new CopyStreamAdapter() {
                            public void bytesTransferred(
                                long totalBytesTransferred, int bytesTransferred, long streamSize) {
                                    log.warn(bytesTransferred + " bytes written; total: " + totalBytesTransferred + " of " + streamSize);
                            }
                        });
                    input.close();
                    output.close();
                    if (!ftpClient.completePendingCommand()) {
                        errorMessage = "Failed to copy file thru FTP: completePendingCommand failed.";
                    }
                }
            }
            ftpClient.logout();
            ftpClient.disconnect();
            ftpClient = null;
        }
        if (!StringUtils.isEmpty(errorMessage)) {
            log.error(errorMessage);
            System.out.print(errorMessage);
            success = false;
        }
    } catch (CopyStreamException cse){
        cse.printStackTrace();
        log.error("Failed to copy file thru FTP (CopyStreamException).", cse);
        success = false;
    } catch (IOException e){
        e.printStackTrace();
        log.error("Failed to copy file thru FTP (IOException).", e);
        success = false;
    } finally {
        try {
            if (ftpClient != null) {
                ftpClient.logout();
                ftpClient.disconnect();
            }
        } catch (IOException ignore) {}
    }

    return success;    
}

Now, as I've said, this code works exceptionally well for all files under 86Mb, so while it may be useful from a knowledge point of view, I don't really need tips on Java coding style, etc. Also note that in posting this method, I removed comments and extraneous code, so there may be a syntax error or two, although I didn't see any when I copied this back into eclipse. What I'm trying to resolve is why this code works for small files, but not for big files!

Here is a sample of the log output for the large file (modified slightly for aesthetics):

2012-02-29 11:13 WARN - copyFileThruFTP calling copyStream() for file: C:\data\mergedcdi\T0090200.txt
2012-02-29 11:13 WARN - 1024000 bytes; total: 1024000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 2048000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 3072000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 4096000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 5120000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 6144000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 7168000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 8192000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 9216000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 10240000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 11264000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 12288000 of 96580484
2012-02-29 11:13 WARN - 1024000 bytes; total: 13312000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 14336000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 15360000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 16384000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 17408000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 18432000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 19456000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 20480000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 21504000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 22528000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 23552000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 24576000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 25600000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 26624000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 27648000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 28672000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 29696000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 30720000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 31744000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 32768000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 33792000 of 96580484
2012-02-29 11:14 WARN - 1024000 bytes; total: 34816000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 35840000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 36864000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 37888000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 38912000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 39936000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 40960000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 41984000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 43008000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 44032000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 45056000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 46080000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 47104000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 48128000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 49152000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 50176000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 51200000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 52224000 of 96580484
2012-02-29 11:15 WARN - 1024000 bytes; total: 53248000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 54272000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 55296000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 56320000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 57344000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 58368000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 59392000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 60416000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 61440000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 62464000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 63488000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 64512000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 65536000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 66560000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 67584000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 68608000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 69632000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 70656000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 71680000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 72704000 of 96580484
2012-02-29 11:16 WARN - 1024000 bytes; total: 73728000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 74752000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 75776000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 76800000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 77824000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 78848000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 79872000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 80896000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 81920000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 82944000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 83968000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 84992000 of 96580484
2012-02-29 11:17 WARN - 1024000 bytes; total: 86016000 of 96580484
2012-02-29 11:17 ERROR- Failed to copy file thru FTP (CopyStreamException).
org.apache.commons.net.io.CopyStreamException: IOException caught while copying.
    at org.apache.commons.net.io.Util.copyStream(Util.java:130)
    at org.apache.commons.net.io.Util.copyStream(Util.java:174)
    at com.pa.rollupedit.util.WebUtil.copyFileThruFTP(WebUtil.java:1120)
    at com.pa.rollupedit.util.CdiBuilder.process(CdiBuilder.java:361)
    at com.pa.rollupedit.controller.ExportCDI.doGet(ExportCDI.java:55)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
    at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:227)
    at weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:125)
    at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:292)
    at weblogic.servlet.internal.TailFilter.doFilter(TailFilter.java:26)
    at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
    at com.pa.rollupedit.controller.LoginFilter.doFilter(LoginFilter.java:90)
    at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
    at com.pa.rollupedit.util.RequestTimeFilter.doFilter(RequestTimeFilter.java:18)
    at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:42)
    at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3496)
    at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
    at weblogic.security.service.SecurityManager.runAs(Unknown Source)
    at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2180)
    at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:2086)
    at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1406)
    at weblogic.work.ExecuteThread.execute(ExecuteThread.java:201)
    at weblogic.work.ExecuteThread.run(ExecuteThread.java:173)

Ok, so now to what happens on the mainframe. Here is the information the mainframe guy provided me with regards to the file generated by the incomplete transmission:

    Data Set Name . . . . : BSFP.ICEDCDI.SPC10.T0090200

General Data                           Current Allocation
 Management class . . : MCDFLT          Allocated tracks  . : 1,650
 Storage class  . . . : SCSTD           Allocated extents . : 32
  Volume serial . . . : SMS217 +
  Device type . . . . : 3390
 Data class . . . . . : DCDFLT
  Organization  . . . : PS             Current Utilization
  Record format . . . : FB              Used tracks . . . . : 1,650
  Record length . . . : 2000            Used extents  . . . : 32
  Block size  . . . . : 26000
  1st extent tracks . : 100
  Secondary tracks  . : 50             Dates
  Data set name type  :                 Creation date . . . : 2012/02/29
  SMS Compressible. . : NO              Referenced date . . : 2012/02/29
                                        Expiration date . . : None

Note that the Record Length, Record Format, and Block Size seem to be as you'd expect them to be based on the site commands I sent. However, the 1st extent and Secondary tracks look to me to be incorrect. The mainframe guy has given me about 10 different SPACE commands to try (along with some modification to the Block size). The record size is definitely 2000 characters so that's stayed consistent. But so far, none of his suggestions have worked.

On my own, I discovered a different way of setting the parameters and tried that at one point. You can see this in the code as the commented out line:

 //ftpClient.sendSiteCommand("DCB=(RECFM=FB,LRECL=2000,BLKSIZE=26000)");

What's interesting about this is that when I used this command (and commented out the RECFM/LRECL/BLKSIZE commands), the ftp transmission was successful!! BUT the mainframe guy then shared the following remote file information, indicating that the various parameters were not set correctly. It would appear that the DCB command didn't work at all.

    Data Set Name . . . . : BSFP.ICEDCDI.SPC10.T0090200

General Data                           Current Allocation
 Management class . . : MCDFLT          Allocated tracks  . : 230
 Storage class  . . . : SCSTD           Allocated extents . : 4
  Volume serial . . . : SMS195
  Device type . . . . : 3390
 Data class . . . . . : DCDFLT
  Organization  . . . : PS             Current Utilization
  Record format . . . : VB              Used tracks . . . . : 230
  Record length . . . : 256             Used extents  . . . : 4
  Block size  . . . . : 27000
  1st extent tracks . : 100
  Secondary tracks  . : 50             Dates
  Data set name type  :                 Creation date . . . : 2012/02/28
  SMS Compressible. . : NO              Referenced date . . : 2012/02/29
                                        Expiration date . . : None

Needless to say, that really put a damper on things.

An update from this morning: the mainframe guy reached out to other mainframe experts, one of whom told him that "TRK" was incorrect in the SPACE command, and instead to use the following:

    ftpClient.sendSiteCommand("SPACE=(TRA,(PRI=500,SEC=500))");

I tried this (along with other variations, such as without the PRI= and SEC=) but the results are exactly the same (i.e. fails at 86Mb).

As you can see, this is not a frivolous question. I'm not even delving into the many gyrations I went through in verifying that this was not a network issue. At this point, I am about 98.6% sure that this problem is being caused by the mainframe site commands.

If you can provide any assistance I would most greatly appreciate it!!

Answer 1

Since you're failing at a certain size, it's your mainframe space command.

A mainframe file can only have 16 extents, 1 primary allocation and 15 secondary allocations. If the disk pack is full or nearly full, you might not get your primary allocation.

In your current allocation, you're asking for 500 primary tracks and 15 * 500 secondary tracks, for a total of 8,000 tracks. A track will hold either 2 or 3 blocks of 26,000 bytes, depending on the disk drive track size. If you specify a block size of 0, the IBM operating system will calculate the most efficient block size.

A bit of math indicates you've allocated for 208,000 records (worst case).

You probably should specify your space in cylinders, and have a small primary and larger secondary. Something like:

ftpClient.sendSiteCommand("SPACE=(CYL,(30,300),RLSE)"); 

If your mainframe shop insists on you specifying tracks, try this:

ftpClient.sendSiteCommand("SPACE=(TRK,(450,4500),RLSE)");

I made both numbers divisible by 15, because if I recall correctly, a cylinder contains 15 tracks.

Edited to add:

I just found the IBM FTP commands page on the IBM web site. It appears you have to send each part of the space command separately, just like the DCB command.

ftpClient.sendSiteCommand("TR");
ftpClient.sendSiteCommand("PRI=450");
ftpClient.sendSiteCommand("SEC=4500");

Answer 2

I would like to add a few comments to the excellent answer given by Gilbert Le Blanc

The reason for specifying a small primary and large secondary space is a little counter intuitive. Primary space allocations always request contiguous space (i.e. in one big chunk). The job will fail with a B37 return code when a volume (disk) cannot be found with that amount of contiguous space on it. In situations where the primary space allocation represents a significant percentage of a volume (3390 DASD devices are actually fairly small - on the order of 10Gb or so), the probability of not finding a volume with the required space can be significant. Hence the job blows up on a B37.

Sencondary allocations do not have to be allocated contiguous blocks and may span multiple volumes. By requesting a fairly small primary quantity you avoid the B37 abend by allowing the dataset to allocate secondary space to fulfill the total space requirement. The catch with this approach is that you may only get 15 secondary extents per volume (this is an artificial but historical limit that can be lifted by the DASD management in your shop). To avoid blowing the extent limit, causing an E37 abend, you request a large extent size.

Finally, you can specify an FTP VCOUNT parameter that can set the number of volumes a dataset may span (each volume can have up to 15 extents). This can make for absolutely huge datasets.

All this to point out that understanding traditional dataset allocation on an IBM mainframe involves a bit of witch-craft.

Life can be made a lot simpler by relying on Storage Management System (SMS) to do the figuring for you. Most shops will have SMS in place. Instead of having to do all the math to calculate primary/secondary extent sizes, you can probably just ask for the appropriate SMS DATACLAS. Most installations will have something appropriate for large data sets such as yours. Each installation defines its own DATACLS names so your mainframe guys will have to dig them up for you. The SMS DATACLAS is specified using the FTP LOCSITE option: DATAC=xxx where xxx is the appropriate DATACLAS name.