XCOM takes long time to authenticate Windows user's domain
search cancel

XCOM takes long time to authenticate Windows user's domain

book

Article ID: 273085

calendar_today

Updated On:

Products

XCOM Data Transport - Windows XCOM Data Transport

Issue/Introduction

We have noticed that XCOM is taking 10 seconds to authenticate a user against a Windows domain controller.
We can reproduce the issue in multiple environments and we have XCOM traces and wireshark packet captures showing the issue.
We can see XCOM first trying to authenticate against the Windows Server 2019 domain controller and failing. It then waits and retries using a different authentication mechanism and succeeds. This takes consistently 10 seconds. This is causing performance delays.
XCOM trace file collected using parameter XTRACE=10 provided. It shows mutex waits (9 seconds worth).

Environment

Release : 11.6

Cause

Per the below trace file extract (with added comments in red), it shows the delay occurs after the actual file transfer has been completed and during the post-processing phase where the defined XPPCMD file "D:\FileTransfer\ReceivedNewXComFile.bat" is executed i.e. the file transfer processing is complete between 16:57:27 and 16:57:28 and the post-processing execution runs from 16:57:28 to 16:57:36.

===
LOGGED >>> 2023/09/05 16:57:27 TID=282099 [...];    XCOMN0026I Remotely initiated first try.;

...
 fsmachin 9205: Opening output file '...'
...
Xfclose: Closing file ...
Xrename: rename file <...> to <...>
"End of file transfer"
...
"Start of post-processing"
fsmachin 1600: Command line = "cmd.exe" "/c" "D:\FileTransfer\ReceivedNewXComFile.bat" ...

 Try 3 to WaitForSingleObject for Mutex 0000000000000158
 ReleaseMutex on 0000000000000158
 fsmachin 1816: RevertToSelf OK.
 ntsuid    339: NT_ProcessCmd: Entering NT_ProcessCmd
 ntsuid    341: Checking request number (282099) validity before invoking post/end processing scripts ntsuid    365: NT_ProcessCmd: About to add ACE to windowstation,desktop
 ...
 ntsuid    524: NT_ProcessCmd: CA-XCOM-Batch WindowStation found.
 ntsuid   1141: CheckTheAceDesktop: descriptor allocated, 232 bytes
 ntsuid   1163: CheckTheAceDesktop: GetUserObjectSecurity OK
 ntsuid   1169: CheckTheAceDesktop: GetSecurityDescriptorDacl OK
 ntsuid   1186: CheckTheAceDesktop: GetAclInformation OK
 ntsuid   1203: CheckTheAceDesktop: GetAce OK
...
 ntsuid   1208: CheckTheAceDesktop: SID found
 ntsuid   1203: CheckTheAceDesktop: GetAce OK
 ntsuid   1224: CheckTheAceDesktop: descriptor free OK
 ntsuid    536: NT_ProcessCmd: CA-XCOM-Batch Desktop found.
 ntsuid    948: RemoveSid: SID buffer free OK
 ntsuid    547: calling CreateProcessAsUser; token: 572
 ntsuid    589: NT_ProcessCmd: Checking process completion code.
 ntsuid    613: NT_ProcessCmd: Waiting up to 60 minutes for completion of process.
Tue Sep 05 16:57:28 2023
 Try 3 to WaitForSingleObject for Mutex 0000000000000158
 ReleaseMutex on 0000000000000158
Tue Sep 05 16:57:29 2023
 Try 3 to WaitForSingleObject for Mutex 0000000000000158
 ReleaseMutex on 0000000000000158
Tue Sep 05 16:57:30 2023
 Try 3 to WaitForSingleObject for Mutex 0000000000000158
 ReleaseMutex on 0000000000000158
Tue Sep 05 16:57:31 2023
 Try 3 to WaitForSingleObject for Mutex 0000000000000158
 ReleaseMutex on 0000000000000158
Tue Sep 05 16:57:32 2023
 Try 3 to WaitForSingleObject for Mutex 0000000000000158
 ReleaseMutex on 0000000000000158
Tue Sep 05 16:57:33 2023
 Try 3 to WaitForSingleObject for Mutex 0000000000000158
 ReleaseMutex on 0000000000000158
Tue Sep 05 16:57:34 2023
 Try 3 to WaitForSingleObject for Mutex 0000000000000158
 ReleaseMutex on 0000000000000158
Tue Sep 05 16:57:35 2023
 Try 3 to WaitForSingleObject for Mutex 0000000000000158
 ReleaseMutex on 0000000000000158
Tue Sep 05 16:57:36 2023
 ntsuid    628: NT_ProcessCmd: Process completion signaled.
"End of post-processing"
...
LOGGED >>> 2023/09/05 16:57:36 TID=282099;    XCOMN0011I Transfer ended; 16 records (832 bytes) transmitted in 10 seconds (83 bytes/second); 
...
 parmblk   631: FreeParmblock: XPPCMD(165):=D:\FileTransfer\ReceivedNewXComFile.bat(000002A198D71930)
===

Resolution

The post-processing script ReceivedNewXComFile.bat was removed from the XCOM file transfer operation and the transfer then only took 1 second. Why the script is adding 9 seconds to the transfer time will be investigated further.