V7.0.2 SMF 119 subtype 70 truncated remote user-id.

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

V7.0.2 SMF 119 subtype 70 truncated remote user-id.

Post by giltjr »

Just upgraded from V1.7.2, yes I know that was VERY OLD, to V7.0.2

Not that important to us, but I just noticed that in the SMF 119 records subtype 70, ftp server complete, the remote user-id is being truncated at 7 characters.

Since we did a big jump from V1.7.2 to V7.0.2 I don't know if this was something introduced in this release or if it has been there for awhile.
SteveGoetze
Posts: 385
Joined: Fri Jul 30, 2004 5:29 pm

Re: V7.0.2 SMF 119 subtype 70 truncated remote user-id.

Post by SteveGoetze »

It would be helpful for us to have a trace of this issue. Can you re-run the scenario with the following trace active?

export COZ_LOG=T,ZosSmf119Record=F,ZosExitInterface=F

Then collect the results and send to info@dovetail.com for us to look at. Thanks
giltjr
Posts: 22
Joined: Wed Jul 07, 2010 9:06 pm

Re: V7.0.2 SMF 119 subtype 70 truncated remote user-id.

Post by giltjr »

Done. Userid is ftptest01. I can't figure out how to attach a file so.
Co:Z SFTP version: 7.0.2 (8.4p1) 2022-01-11
Copyright (C) Dovetailed Technologies, LLC. 2008-2022. All rights reserved.
ZosUtil[T]: -> zos_log_region_size()
ZosUtil[D]: region size requested = 65536K, Actual below/above limit = 11240K / 65536K
ZosUtil[T]: <- zos_log_region_size()
ZosUtil[T]: using override: _CEE_REALLOC_CONTROL=32K,25
Connecting to nssifltest01...
FOTS2274 Warning: Permanently added 'nssifltest01,192.168.14.98' (ECDSA) to the list of known hosts.
****************************************************************************
* Authorized access only! *
* Disconnect IMMEDIATELY if you are not an authorized user!!! *
* All actions Will be monitored and recorded *
* *
* You are entering the proprietary environment of the Airline Tariff *
* Publishing Company's computing systems. Unauthorized access to or *
* use of any ZZZCO data, program, system or information is explicitly *
* prohibited by ZZZCO and may constitute a violation of federal and/or *
* state law, including without limitation 18 U.S.C. Section 1030 and *
* VA Code Ann. Sections 18.2.152.1-18.2.152.15. Violators could be *
* subject to civil liability as well as criminal penalties, including *
* fines and imprisonment for up to ten years. *
****************************************************************************
/usr/local/coz/bin/read_passwd_dsn.sh prompt: "ftptest01@nssifltest01's password: "
fromdsn: version: 7.0.2 2022-01-11
fromdsn: Copyright (C) Dovetailed Technologies, LLC. 2006-2022. All rights reserved.
fromdsn[T]: -> fromdsn()
fromdsn[T]: <- fromdsn()
fromdsn[T]: -> fromdsn.run()
fromdsn[T]: -> fromdsn.parseArgs()
fromdsn[T]: DatasetHandler: -> setDSN(AAAAAAAA.ZZZXXXX.TEMPF01)
fromdsn[T]: DatasetHandler: <- setDSN(effectiveDSN=AAAAAAAA.ZZZXXXX.TEMPF01)
fromdsn[T]: -> readConfig(/etc/dsn_profile dsn=AAAAAAAA.ZZZXXXX.TEMPF01)
fromdsn[T]: <- readConfig()
fromdsn[T]: <- fromdsn.parseArgs()
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: DatasetHandler: -> open()
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: DatasetHandler: -> doOpen("//DD:SYS00003", "rb,type=record,noseek,recfm=*", jobAlias=)
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: DatasetHandler: doOpen: opened "dd:SYS00003",dsorg=ps,recfm=fb,maxreclen=80,blksize=27920,_
_device=0
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: DatasetHandler: <- doOpen()
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: DatasetHandler: <- open()
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01): opts=rb,type=record,noseek,recfm=* maxreclen=80 trim=false
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: -> fromdsn.copyData()
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: <- fromdsn.copyData()
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[N]: 1 records/80 bytes read; 81 bytes written in 0 milliseconds.
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[D]: numWrites=1
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: CoZServerUtil: writeErrorStatusPacket: packet ignored: fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01): msg=
"", rc=0, emsg="", errno=0, errno2=0X00000000
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: <- fromdsn.run(0)
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: -> ~fromdsn()
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: <- ~fromdsn()
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: DatasetHandler: -> close()
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: DatasetHandler: -> freeDD(SYS00003)
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: DatasetHandler: <- freeDD(rc=0)
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[T]: DatasetHandler: <- close(true)
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[D]: fromdsn current thread cpu time: 0.002633 secs
fromdsn(AAAAAAAA.ZZZXXXX.TEMPF01)[D]: Exiting main(), rc=0
Connected to nssifltest01.
Connection established, local_addr=172.16.206.100 local_port=47147 remote_addr=192.168.14.98 remote_port=22
CatalogSearch[T]: -> DatasetInfo::getDatasetInfo(DD:EMPTY->NULLFILE w/jfcb)
CatalogSearch[T]: <- DatasetInfo::getDatasetInfo()
ZosSmf119Record[F]: -> ZosSmf119Record()
ZosSmf119Record[F]: <- ZosSmf119Record()
ZosSmf119Record[F]: -> ZosSmfFtpClientRecord(filename=)
ZosSmf119Record[F]: <- ZosSmfFtpClientRecord()
ZosDataset[T]: -> open("//DD:EMPTY", 0x0002, 0x0000, , , 0x80000000, )
CatalogSearch[T]: -> DatasetInfo::getDatasetInfo(DD:EMPTY->NULLFILE w/jfcb)
CatalogSearch[T]: <- DatasetInfo::getDatasetInfo()
ZosSettings: Transfer options: gdgnt,mode=binary
ZosSmf119Record[F]: -> addLogMessage(ZosSettings: Transfer options: gdgnt,mode=binary)
ZosSmf119Record[F]: <- addLogMessage()
DatasetHandler[T]: -> setDSN(DD:EMPTY)
DatasetHandler[T]: <- setDSN(effectiveDSN=DD:EMPTY)
ZosDataset: Opening dataset DD:EMPTY for read
ZosSmf119Record[F]: -> addLogMessage(ZosDataset: Opening dataset DD:EMPTY for read)
ZosSmf119Record[F]: <- addLogMessage()
DatasetHandler[T]: -> open()
DatasetHandler[T]: -> doOpen("//DD:EMPTY", "rb,type=record,noseek,recfm=*", jobAlias=)
DatasetHandler[T]: doOpen: opened "dd:EMPTY",dsorg=ps,recfm=u,maxreclen=6144,blksize=6144,__device=6
DatasetHandler[T]: <- doOpen()
DatasetHandler[T]: <- open()
ZosSmf119Record[F]: -> initialize("DD:EMPTY")
ZosSmf119Record[F]: -> initHeader(reclen=373 subtype=3)
ZosSmf119Record[F]: <- initHeader()
ZosSmf119Record[F]: -> initIdentSection()
ZosSmf119Record[F]: <- initIdentSection()
ZosSmf119Record[F]: -> initServerSecuritySection()
ZosSmf119Record[F]: <- initServerSecuritySection()
ZosSmf119Record[F]: -> initFtpClientSection()
ZosSmf119Record[F]: <- initFtpClientSection()
ZosSmf119Record[F]: <- initialize()
ZosDataset[T]: <- open()
ZosDataset[D]: EOF reached
ZosDataset[T]: -> close(forced=0 writeError=0)
ZosDataset: Closing dataset //DD:EMPTY - 0 records read, 0 bytes sent
ZosSmf119Record[F]: -> addLogMessage(ZosDataset: Closing dataset //DD:EMPTY - 0 records read, 0 bytes sent)
ZosSmf119Record[F]: <- addLogMessage()
DatasetHandler[T]: -> close()
DatasetHandler[T]: <- close(true)
ZosDataset[T]: <- close(rc=0)
ZosSmf119Record[F]: -> writeRecord()
ZosSmf119Record[F]: -> initCompletionRecord()
ZosSmf119Record[F]: <- initCompletionRecord()
ZosSmf119Record[F]: hexdump of smf119header (373 bytes):
ZosSmf119Record[F]: >01750000 5E77003B B2850122 140FD4E5< ....;....e....MV 00000000 1A883968
ZosSmf119Record[F]: >E2C10000 00000003 00060000 00000054< SA.............. 00000010 1A883978
ZosSmf119Record[F]: >00400001 00000094 00AC0001 00000140< . .....m....... 00000020 1A883988
ZosSmf119Record[F]: >00080001 00000000 00000000 00000148< ................ 00000030 1A883998
ZosSmf119Record[F]: >00260001 0000016E 00070001 00000000< .......>........ 00000040 1A8839A8
ZosSmf119Record[F]: >00000000 D4E5E2C1 40404040 C1E3D7D7< ....MVSA ZZZP 00000050 1A8839B8
ZosSmf119Record[F]: >D3C5E7F1 E3C3D7C9 D7404040 F0F1F1F1< LEX1TCPIP 0111 00000060 1A8839C8
ZosSmf119Record[F]: >F0F04040 E2C6E3D7 C3404040 C6E95BD1< 00 SFTPC FZ$J 00000070 1A8839D8
ZosSmf119Record[F]: >C7F1D1C7 C1E3D7F1 D1E2C740 000000B9< G1JGZZZXXXX .... 00000080 1A8839E8
ZosSmf119Record[F]: >08000000 E2E3D6D9 E2C5D840 00000000< ....STORSEQ .... 00000090 1A8839F8
ZosSmf119Record[F]: >00000000 0000FFFF C0A80E62 00000000< ........{y...... 000000A0 1A883A08
ZosSmf119Record[F]: >00000000 0000FFFF AC10CE64 0016B82B< ................ 000000B0 1A883A18
ZosSmf119Record[F]: >00000000 00000000 0000FFFF C0A80E62< ............{y.. 000000C0 1A883A28
ZosSmf119Record[F]: >00000000 00000000 0000FFFF AC10CE64< ................ 000000D0 1A883A38
ZosSmf119Record[F]: >0016B82B 86A397A3 85A2A340 C1E3D7F1< ....ftptest ZZZ1 000000E0 1A883A48
ZosSmf119Record[F]: >D1E2C740 C9E2C6E2 0051AB85 0122140F< XXX ISFS...e.... 000000F0 1A883A58
ZosSmf119Record[F]: >0051AB85 0122140F 00000000 00000000< ...e............ 00000100 1A883A68
ZosSmf119Record[F]: >00000000 F2F5F040 40404040 40404040< ....250 00000110 1A883A78
ZosSmf119Record[F]: >81F6F091 85A2F240 40404040 40404040< a60jes2 00000120 1A883A88
ZosSmf119Record[F]: >00000000 00000000 0D9584BB 0D9584BB< .........nd..nd. 00000130 1A883A98
ZosSmf119Record[F]: >C4C47AC5 D4D7E3E8 E3D7D7D7 40404040< DD:EMPTYTPPP 00000140 1A883AA8
ZosSmf119Record[F]: >40404040 40404040 40404040 40404040< 00000150 1A883AB8
ZosSmf119Record[F]: >40404040 40404040 00000000 0000C1E3< ......AT 00000160 1A883AC8
ZosSmf119Record[F]: >D7F1D1E2 C7< PXXXX 00000170 1A883AD8
ZosSmf119Record[F]: -> doWriteDgRecord()
ZosSmf119Record[D]: Unable to send SMF 119 record to monitor socket "/var/log/cozsftp.smf.sock" - EDC5129I NO SUCH FILE OR DIRECTORY
. (errno2=0x0594003D)
ZosSmf119Record[F]: <- doWriteDgRecord(false)
ZosSmf119Record[F]: -> smf_write(SMF_IEFU84)
ZosSmf119Record[F]: <- smf_write(true)
ZosExitInterface[F]: -> ZosExitInterface()
ZosExitInterface[F]: ZosExitInterface: client_addr: 172.16.206.100 port: 47147
ZosExitInterface[F]: ZosExitInterface: server_addr: 192.168.14.98 port: 22
ZosExitInterface[F]: <- ZosExitInterface()
ZosExitInterface[T]: -> postProcessExit()
ZosExitInterface[T]: <- postProcessExit()
ZosSmf119Record[F]: hexdump of smf119header (401 bytes):
ZosSmf119Record[F]: >01910000 5E77003B B2850122 140FD4E5< .j..;....e....MV 00000000 1A883968
ZosSmf119Record[F]: >E2C10000 000000C1 00030000 00000054< SA.....A........ 00000010 1A883978
ZosSmf119Record[F]: >00400001 00000094 00340001 000000C8< . .....m.......H 00000020 1A883988
ZosSmf119Record[F]: >00C90001 00000000 00000000 00000000< .I.............. 00000030 1A883998
ZosSmf119Record[F]: >00000000 00000000 00000000 00000000< ................ 00000040 1A8839A8
ZosSmf119Record[F]: >00000000 D4E5E2C1 40404040 C1E3D7D7< ....MVSA ZZZP 00000050 1A8839B8
ZosSmf119Record[F]: >D3C5E7F1 E3C3D7C9 D7404040 F0F1F1F1< LEX1TCPIP 0111 00000060 1A8839C8
ZosSmf119Record[F]: >F0F04040 E2C6E3D7 C3404040 C6E95BD1< 00 SFTPC FZ$J 00000070 1A8839D8
ZosSmf119Record[F]: >C7F1D1C7 C1E3D7F1 D1E2C740 000000B9< G1JGZZZXXXX .... 00000080 1A8839E8
ZosSmf119Record[F]: >08000000 00000000 00000000 0000FFFF< ................ 00000090 1A8839F8
ZosSmf119Record[F]: >C0A80E62 00000000 00000000 0000FFFF< {y.............. 000000A0 1A883A08
ZosSmf119Record[F]: >AC10CE64 0016B82B 40404040 40404040< ........ 000000B0 1A883A18
ZosSmf119Record[F]: >40404040 40404000 0051AB85 0122140F< ....e.... 000000C0 1A883A28
ZosSmf119Record[F]: >0033E996 A2E285A3 A3899587 A2ADC9BD< ..ZosSettings 000000D0 1A883A38
ZosSmf119Record[F]: >7A40E399 8195A286 85994096 97A38996< : Transfer optio 000000E0 1A883A48
ZosSmf119Record[F]: >95A27A40 87848795 A36B9496 84857E82< ns: gdgnt,mode=b 000000F0 1A883A58
ZosSmf119Record[F]: >89958199 A80051AB 85012214 0F0030E9< inary...e......Z 00000100 1A883A68
ZosSmf119Record[F]: >96A2C481 A381A285 A3ADC9BD 7A40D697< osDataset[I]: Op 00000110 1A883A78
ZosSmf119Record[F]: >85958995 87408481 A381A285 A340C4C4< ening dataset DD 00000120 1A883A88
ZosSmf119Record[F]: >7AC5D4D7 E3E84086 96994099 85818400< :EMPTY for read. 00000130 1A883A98
ZosSmf119Record[F]: >51AB8501 22140F00 48E996A2 C481A381< ..e......ZosData 00000140 1A883AA8
ZosSmf119Record[F]: >A285A3AD C9BD7A40 C39396A2 89958740< set[I]: Closing 00000150 1A883AB8
ZosSmf119Record[F]: >8481A381 A285A340 6161C4C4 7AC5D4D7< dataset //DD:EMP 00000160 1A883AC8
ZosSmf119Record[F]: >E3E84060 40F04099 85839699 84A24099< TY - 0 records r 00000170 1A883AD8
ZosSmf119Record[F]: >8581846B 40F04082 A8A385A2 40A28595< ead, 0 bytes sen 00000180 1A883AE8
ZosSmf119Record[F]: >A3< t 00000190 1A883AF8
ZosSmf119Record[F]: -> smf_write(SMF_IEFU84)
ZosSmf119Record[F]: <- smf_write(true)
ZosSmf119Record[F]: <- writeRecord(true)
ZosSmf119Record[F]: -> ~ZosSmfFtpClientRecord()
ZosSmf119Record[F]: <- ~ZosSmfFtpClientRecord()
ZosSmf119Record[F]: -> ~ZosSmf119Record()
ZosSmf119Record[F]: <- ~ZosSmf119Record()
DatasetHandler[T]: -> close()
DatasetHandler[T]: <- close(true)
ZosUtil[D]: SSH process times: elapsed=2 secs, user cpu=0.040000 secs, sys cpu=0.010000 secs
ZosExitInterface[F]: -> ~ZosExitInterface()
ZosExitInterface[F]: <- ~ZosExitInterface()
Post Reply