Failed to transfer a file to a virtual directory

htran-21 · ‎Apr 18, 2020

Hi,

Thingworx WSEMS process is running as LocalSystem user, the target folder is accessible, but it is failed to move a file in Thingworx staging folder into the designated folder due to Error 17.

Does anyone know what the error means? Any help would be greatly appreciated!

My Bests,

Hung Tran

mnarang · ‎Apr 20, 2020

Can you please attach complete EMS logs by putting the logger level in DEBUG/TRACE in config.json ?It's difficult to crack this from this screenshot .

you can also put verbose= true in ws_connection segment of config.json along with the above setting .

Thanks ,

Mukul Narang

htran-21 · ‎Jun 05, 2020

Hi Mukul Narang,

I have just had a chance to duplicate it. However, the TRACE log is not actually explaining what happened.

[DEBUG] 2020-06-05 01:37:22,779 serviceHandler: Handling service MoveFile for thing IPU_100346 locally
[DEBUG] 2020-06-05 01:37:22,782 SDK: getRealPath: Real path for IPU_100346:__staging__\IPU_100346.Folder1.zk.bat.part\ = r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part
[DEBUG] 2020-06-05 01:37:22,785 SDK: getRealPath: Real path for IPU_100346:\Folder1\zk.bat\ = c:\Folder1\zk.bat
[DEBUG] 2020-06-05 01:37:22,787 SDK: getRealPath: Real path for IPU_100346:__staging__\IPU_100346.Folder1.zk.bat.part\ = r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part
[TRACE] 2020-06-05 01:37:22,787 SDK: twFileManager_GetOpenFile: Looking for tid: NA, realpath: r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part.
[TRACE] 2020-06-05 01:37:22,788 SDK: twFileManager_GetOpenFile: Compare to tid: d4851164-6d93-4ca5-ab6e-284ca2d15207, realpath: r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part.
[TRACE] 2020-06-05 01:37:22,789 SDK: twFileManager_GetOpenFile: Found Open file r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part\
[TRACE] 2020-06-05 01:37:22,790 SDK: twFileManager_GetOpenFile: Returning r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part
[DEBUG] 2020-06-05 01:37:22,792 SDK: twMoveFile: Moving file __staging__\IPU_100346.Folder1.zk.bat.part to \Folder1\zk.bat
[ERROR] 2020-06-05 01:37:22,793 SDK: twMoveFile: Error moving file __staging__\IPU_100346.Folder1.zk.bat.part to \Folder1\zk.bat. Error: 17
[TRACE] 2020-06-05 01:37:22,794 SDK: twOfflineMsgStore_Flush: Creating buffer for reading offline message store. size = 8220
[DEBUG] 2020-06-05 01:37:22,795 SDK: twMessage_Delete:  Deleting RESPONSE Message: 0
[DEBUG] 2020-06-05 01:37:22,795 SDK: twWs_SendMessage: Sent 17 bytes using 1 frames.
[TRACE] 2020-06-05 01:37:22,796 SDK: twMessage_Send: Message with RequestId 177937 sent successfully
[DEBUG] 2020-06-05 01:37:22,797 SDK: twMessage_Delete:  Deleting RESPONSE Message: 177937
[DEBUG] 2020-06-05 01:37:22,797 SDK: twMessage_Delete:  Deleting REQUEST Message: 177937
[TRACE] 2020-06-05 01:37:22,798 SDK: twTlsClient_Read: Read: 2, Asked for: 2
[TRACE] 2020-06-05 01:37:22,801 SDK: twWs_Receive: Read 2 bytes into header buffer
[TRACE] 2020-06-05 01:37:22,803 SDK: twWs_Receive: Got Header: Body length = 1
[TRACE] 2020-06-05 01:37:22,806 SDK: twTlsClient_Read: Read: 1, Asked for: 1
[TRACE] 2020-06-05 01:37:22,809 SDK: twWs_Receive: Read 1 bytes into Frame buffer
[TRACE] 2020-06-05 01:37:22,812 SDK: twWs_Receive: Received Ping
[TRACE] 2020-06-05 01:37:22,814 SDK: msgHandlerOnPing: Received Ping.  Data:
[TRACE] 2020-06-05 01:37:23, 19 SDK: twTlsClient_Read: Read: 2, Asked for: 2
[TRACE] 2020-06-05 01:37:23, 20 SDK: twWs_Receive: Read 2 bytes into header buffer
[TRACE] 2020-06-05 01:37:23, 45 SDK: twTlsClient_Read: Read: 2, Asked for: 2
[TRACE] 2020-06-05 01:37:23, 46 SDK: twWs_Receive: Read 2 bytes into header buffer
[TRACE] 2020-06-05 01:37:23, 46 SDK: twWs_Receive: Got 2 byte length. 0x8 0x17
[TRACE] 2020-06-05 01:37:23, 47 SDK: twWs_Receive: Got Header: Body length = 2071
[TRACE] 2020-06-05 01:37:23, 47 SDK: twTlsClient_Read: Read: 2071, Asked for: 2071
[TRACE] 2020-06-05 01:37:23, 52 SDK: twWs_Receive: Read 2071 bytes into Frame buffer
[TRACE] 2020-06-05 01:37:23, 54 SDK: twWs_Receive: Received Binary Message in Single Frame
[TRACE] 2020-06-05 01:37:23, 57 SDK: twInfoTableRow_CreateFromStream: Marker is empty. No more rows in stream
[TRACE] 2020-06-05 01:37:23, 60 SDK: twInfoTableRow_CreateFromStream: Marker is empty. No more rows in stream
[TRACE] 2020-06-05 01:37:23, 63 SDK: msgHandlerOnBinaryMessage: Inserted message onto queue. ID: 177938, Type: 1, Queue Total: 1
[TRACE] 2020-06-05 01:37:23, 65 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1
[TRACE] 2020-06-05 01:37:23, 67 SDK: twMessageHandler_msgHandlerTask: Removing Message ID: 177938 from Incoming Messages Queue
[TRACE] 2020-06-05 01:37:23, 67 SDK: twMessageHandler_msgHandlerTask: Received Binary Message ID: 177938, Queue Total: 0
[TRACE] 2020-06-05 01:37:23, 67 SDK: handleMessage: Received Request Message ID: 177938
[DEBUG] 2020-06-05 01:37:23, 68 serviceHandler: Handling service CancelFileTransfer for thing IPU_100346 locally
[DEBUG] 2020-06-05 01:37:23, 68 SDK: twFinishFileTransfer: Finishing file transfer d4851164-6d93-4ca5-ab6e-284ca2d15207
[TRACE] 2020-06-05 01:37:23, 68 SDK: twFileManager_GetOpenFile: Looking for tid: d4851164-6d93-4ca5-ab6e-284ca2d15207, realpath: NA.
[TRACE] 2020-06-05 01:37:23, 69 SDK: twFileManager_GetOpenFile: Compare to tid: d4851164-6d93-4ca5-ab6e-284ca2d15207, realpath: r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part.
[TRACE] 2020-06-05 01:37:23, 69 SDK: twFileManager_GetOpenFile: Found Open file r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part\
[TRACE] 2020-06-05 01:37:23, 70 SDK: twFileManager_GetOpenFile: Returning r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part
[TRACE] 2020-06-05 01:37:23, 70 SDK: adjustPath:
Original Path: \Folder1\zk.bat.
AdjustedPath: __staging__\IPU_100346.Folder1.zk.bat.part
[DEBUG] 2020-06-05 01:37:23, 71 SDK: getRealPath: Real path for IPU_100346:__staging__\IPU_100346.Folder1.zk.bat.part\ = r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part
[TRACE] 2020-06-05 01:37:23, 71 SDK: twFileManager_GetOpenFile: Looking for tid: NA, realpath: r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part.
[TRACE] 2020-06-05 01:37:23, 71 SDK: twFileManager_GetOpenFile: Compare to tid: d4851164-6d93-4ca5-ab6e-284ca2d15207, realpath: r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part.
[TRACE] 2020-06-05 01:37:23, 72 SDK: twFileManager_GetOpenFile: Found Open file r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part\
[TRACE] 2020-06-05 01:37:23, 74 SDK: twFileManager_GetOpenFile: Returning r:\Build\Thingworx.MicroServer\sendfolder\IPU_100346.Folder1.zk.bat.part
[FORCE] 2020-06-05 01:37:23, 78 SDK: twFinishFileTransfer: ERROR.  File: \Folder1\zk.bat
[AUDIT] 2020-06-05 01:37:23, 81 :

*****************
FILE TRANSFER NOTIFICATION:
Source: FileRepo_IPU_100346:\zk.bat/zk.bat
Destination: IPU_100346:\Folder1\zk.bat/zk.bat
Size:        59
StartTime: 2020-06-05 01:37:21,505
EndTime: 2020-06-05 01:37:22,260
Duration: 755 msec
User: tranh
State: ERROR
Message: Error occurred during transfer.
Transfer ID: d4851164-6d93-4ca5-ab6e-284ca2d15207
*****************

[TRACE] 2020-06-05 01:37:23, 83 SDK: twFileManager_CloseFile: Closing file: IPU_100346.Folder1.zk.bat.part

My Bests,

Hung Tran