Trying to understand why a file got deleted.

Discussion of Co:Z sftp, a port of OpenSSH sftp for z/OS
Post Reply
giltjr
Posts: 26
Joined: Wed Jul 07, 2010 9:06 pm

Trying to understand why a file got deleted.

Post by giltjr »

We have conddisp=delete, so I know when a transfer is considered a failure the file should be deleted. However, I'm trying to figure out why a this transfer, which appears to work, is being considered a failure. Below is the last part of the log. Now we have a exit that will change the file name the user enters by appending ".Dmmddyy.Thhmm" to the end of the file name at the start of the transfer. It appears that the client is trying to do a "stat" on the file after the transfer is done and that Co:Z SFTP knows that the file name has changed and so it is trying to "stat" the new name. It does get a CC=4 from a READDSCB, not sure if that is considered "failure" error or not. I do see a "forced close", but I don't know what this is or what would cause it. This seems to be what is causing CoZ: SFTP to act as if there is an error and thus deletes the file.

[39.325] debug1: request 45: write "/-/XME.PROD.XMTMERCZ.BSP" (handle 0) off 444416 len 31744
ZosDataset[T]: -> write(off=444416 len=31744)
ZosDataset[T]: <- write(31744, recordCount=17, totalBytesWritten=476160)
[39.325] debug3: request 45: sent status 0
[39.325] sent status Success
[39.624] debug1: request 46: write "/-/XME.PROD.XMTMERCZ.BSP" (handle 0) off 476160 len 31744
ZosDataset[T]: -> write(off=476160 len=31744)
ZosDataset[T]: <- write(31744, recordCount=18, totalBytesWritten=507904)
[39.624] debug3: request 46: sent status 0
[39.624] sent status Success
[39.924] debug1: request 47: write "/-/XME.PROD.XMTMERCZ.BSP" (handle 0) off 507904 len 30153
ZosDataset[T]: -> write(off=507904 len=30153)
ZosDataset[T]: <- write(30153, recordCount=19, totalBytesWritten=538057)
[39.924] debug3: request 47: sent status 0
[39.924] sent status Success
[40.406] debug3: request 48: stat
[40.406] stat name "/-/XME.PROD.XMTMERCZ.BSP"
CatalogSearch[D]: filterKey="XME.PROD.XMTMERCZ.BSP"
CatalogSearch[D]: filterKey="XME.PROD.XMTMERCZ.BSP.**"
CatalogSearch[D]: READDSCB rc=4 for dsn=XME.PROD.XMTMERCZ.BSP.D022616.T0352146 and volser="*"
CatalogSearch[D]: READDSCB rc=4 for dsn=XME.PROD.XMTMERCZ.BSP.D022616.T0352146 and volser="*"
ZosExitInterface[T]: -> checkChangeDir(/-/XME.PROD.XMTMERCZ.BSP)
ZosExitInterface[D]: -> checkSetFiletype(SEQ)
ZosExitInterface[D]: <- checkSetFiletype(true (no change))
ZosExitInterface[T]: <- checkChangeDir(true)
[40.436] debug1: request 48: sent attrib have 0x4
[40.904] debug1: request 49: setstat name "/-/XME.PROD.XMTMERCZ.BSP"
[40.904] debug3: request 49: sent status 0
[40.904] sent status Success
[41.364] debug1: read eof
[41.364] forced close "/-/XME.PROD.XMTMERCZ.BSP" bytes read 0 written 538057
ZosDataset[T]: -> close(forced )
ZosDataset: Closing dataset //XME.PROD.XMTMERCZ.BSP.D022616.T0352146 before completion and deleting - 538057 bytes received, 19 records written
DatasetHandler[T]: -> close()
DatasetHandler[T]: -> freeDD(SYS00004 disp=delete)
DatasetHandler[T]: <- freeDD(rc=0)
DatasetHandler[T]: <- close()
ZosDataset[T]: <- close(rc=0)
DatasetHandler[T]: -> close()
DatasetHandler[T]: <- close()
ZosSmf119Record[D]: Unable to send SMF 119 record to monitor socket "/var/log/cozsftp.smf.sock" - EDC5129I NO SUCH FILE OR DIRECTORY. (errno2=0x0594003D)
ZosExitInterface[T]: -> postProcessExit()
ZosExitInterface[T]: <- postProcessExit()
[41.401] session closed for local user XME0FT1 from [195.5.173.104]
dovetail
Site Admin
Posts: 2022
Joined: Thu Jul 29, 2004 12:12 pm

Re: Trying to understand why a file got deleted.

Post by dovetail »

This trace shows that the client terminated the connection without sending a close packet for the file (data set).

It looks like the client does a "stat" (ls) for the dataset name before closing also. We returned information that indicated that the data set name was a (pseudo) directory. This is because there were data sets found at levels below the data set (the listing shows these with time stamp suffixes).

So, I am hypothesizing that this particular sftp client is writing to the data set and then doing a "stat" to get information on it before closing. When the name is a directory, then this is unexpected and it fails.
Post Reply