DocForum 051209 - Troubleshooting slow logons in XenApp

+28

No comments posted yet

Comments

Slide 5

P

Slide 7

Winlogon A component of the Windows operating system that provides interactive logon support. Winlogon is designed around an interactive logon model that consists of three components: the Winlogon executable, a Graphical Identification and Authentication dynamic-link library (DLL) referred to as the GINA, and any number of network providers. Windows Me/98/95:  Winlogon is not supported. GINA A Graphical Identification and Authentication dynamic-link library (DLL). The GINA is a replaceable DLL component that is loaded by the Winlogon executable. The GINA implements the authentication policy of the interactive logon model and is expected to perform all identification and authentication user interactions. Winlogon Notification Packages Winlogon notification packages are DLLs that receive and handle events generated by Winlogon. You can implement such a notification package to monitor and respond to Winlogon events. This is useful for applications that need to perform additional processing during logon or logoff, or maintain state information that must be updated when Winlogon events occur.

Slide 8

Lock Unlock, Logoff, Logon, Startup, Shutdown, Startscreensaver, Stopscreensaver, startshell.”

Slide 10

Lock Unlock, Logoff, Logon, Startup, Shutdown, Startscreensaver, Stopscreensaver, startshell.”

Slide 35

Link Control Protocol (LCP) est un protocole intégré au PPP, Il est détaillé dans la même RFC 1661 que celui-ci. Dans une communication PPP, l'émetteur et le récepteur envoient des paquets LCP pour déterminer des informations spécifiques à la transmission de données. Le LCP vérifie l'identité de l'élément connecté et l'accepte ou le refuse, il détermine la taille des paquets acceptables pour la transmission, recherche les erreurs dans la configuration et peut interrompre la communication en cas d'erreur. Les données ne peuvent pas être transmises sur un réseau tant que la connexion n'est pas acceptée par LCP.

Slide 1

Diagnostiquer les lenteurs de connexion dans XenApp Etudes de cas 5 Décembre 2009 Frédéric SERRIERE (ThinIsFat) Citrix Systems Inc.

Slide 2

Agenda Etude de cas 1 : Logon gelé pendant 60 secondes Etude de cas 2 : Les connexions restent figées

Slide 3

Agenda

Slide 4

Connaissez-vous ce diagramme ? Source : www.brianmadden.com

Slide 5

Kernel User Session 0 Session 1..n SMSS.exe (Session Manager) Winlogon.exe CtxNotif.dll IMA Service (IMAserv.exe) Terminal Services Stack (Termdd.sys) (1...N) WDICA.sys (ICA Winstation Driver) TdTcp.sys Session Manager Win32k.sys(GDI) VDTW30.dll (Citrix Thinwire driver) Video Via win32!EngDeviceIOControl WINotif.dll RdpDD.sys (MS Remote Display Driver) RDPWD.sys (RDP Winstation Driver) Video Clavier et Souris Session space System space Terminal Services Service (termserv.exe) PD’s (PDCRYPT, PDRFRAME, …) PDs WSXICA.dll RDPWSX.dll Winstation API WFShell.exe app.exe, Cdmprov.dll, Mfaphook.dll,etc Modules Citrix en rouge CSRSS.exe Win32KSrv.dll 3 4 Le listener ICA envoie la reqête vers la session d’attente (idle) 2 Création de la session (Winstation) 5 Winlogon envoie la requête de connexion de session à Terminal Services 6 Termsrv envoie le handle de connexion de la video, clavier, souris, nom du pilote vidéo à CSRSS.exe 7 9 Lance la session, charge les hooks Citrix, le Shell et l’application publiée Envoi et réception du ICA_Detect_string Assigne l’ID de session et initalise les structures internes pour la session Récupération de la licence TSCAL Paquets INIT_Request, INIT_Response Winlogon (CTXNotify) envoie la notification de reconnexion / logon 8 CtxGina.dll Etapes de connexion (côté serveur) Winlogon (GINA) authentifie l’utilisateur

Slide 6

“Un Winlogon Notification Package est une DLL qui exporte des fonctions qui interprètent des évênements de Winlogon.exe.” Winlogon.exe exécutera ces fonctions suivant les informations stockées dans : HKLM\Software\Microsoft\Windows NT\CurrentVersion \Winlogon\Notify Winlogon Notification Package : notions

Slide 7

Composants de WinLogon Winlogon.exe GINA Address Space CTXNotif.dll NotifyMe.dll Winlogon Notification Packages Network Providers WgaLogon.dll WLNotif.dll G2WinLogon.dll

Slide 8

Winlogon Notification Package Events Notification Package Surveillent et répondent aux évênements WinLogon Logon Logoff Lock Unlock PostShell (TermServ event) Startup Shutdown StartScreenSaver StopScreenSaver Exports Reconnect(TermServ event) StartShell NotifyMe.dll

Slide 9

C’est un composant du Seamless Effectue l’initialisation et le nettoyage des sessions utilisateurs Ctxnotif.dll est un Winlogon Notification Package. Qu’est ce que CTXNOTIF.DLL ?

Slide 10

Que fait CTXNOTIF.DLL pour nous ? Notification Package Exports CTXNotif.dll MFLogon MFLogoff MFPostShell MFStartup MFShutdown Notifie l’évênement de connexion (logoff) Informe le service IMA (MFServer Subsystem) Supprime les imprimantes de session Nettoyage des informations de sécurité Arrête l’indicateur de shadowing (si activé) Nettoyage des éléments de session Lance le moteur Seamless du serveur Affichage de l’image ICA (console session (WinSta0) Désactive l’ombre du curseur de souris Ouvre une session vers le Citrix Health Care Agent service. Vérifie si la session a été créée suite à une demande de changement de mot de passe et reset la session Notifie l’évênement de connexion (logon) Informe le service IMA (MFSrvss.dll) Notifie leCitrix Health Care Agent de la connexion Enregistre le nom de client pour la session (ICA/RDP). Met en place des éléments requis pour la fermeture de session Met à jour les informations de sécurité nécessaire pour CTX_SMAUser/CTX_CPSVCUser Enumération de l’ensemble des ports de communication (LPT, COM) Démarre l’indicateur de shadowing (si activé)

Slide 11

Agenda

Slide 12

Avant la récupération du fichier ICA Durant l’intialisation de la connexion Après avoir validé le mot de passe Pendant le chargement de profil Pendant le chargement de l’application Identifier les étapes

Slide 13

Tester depuis une autre machine et différentes méthodes PNAgent Web Interface Connexion directe (PN lourd, Citrix Quick Launch) Connexion RDP Capturer une trace réseau : timeout, retransmissions etc Tester une autre version de client ICA Etc.. Avant la récupération du fichier ICA

Slide 14

Etapes identiques à l'étape précédente plus : Désactiver le masquage des informations (CTX108298) Vérifier que le serveur cible est disponible Désactiver la fiabilité de session (CTX108439) Etc.. Durant l'initalisation de la connexion

Slide 15

Etapes identiques à l'étape précédente plus : Tester avec un compte local au serveur Renommer une à une les clefs dans : HKLM\SW\Microsoft\WindowsNT\CurrentVersion\WinLogon\Notify\MetaFrame : Logon PostShell Startup Capturer une trace CDF MF_DLL_Ctxgina, MF_DLL_ctxnotif, MF_DLL_cutil, IMA_Subsystems_ MFServer, MF_Session_WFShell, MF_DLL_Ctxauth (sur 4.5) Capturer un dump mémoire complet pendant le délai Après avoir validé le mot de passe

Slide 16

Etapes identiques à l'étape précédente plus : Activer le logging de chargement de profil (325376, 221833) Tester avec un compte AD nouvellement créé (sans profil) Vérifier la connexion avec le serveur de profils Si Citrix Profile Manager est utilisé, activer le logging Pendant le chargement du profil

Slide 17

Tester en bureau publié Capturer une trace réseau depuis le serveur XenApp Prendre un dump mémoire du processus applicatif Désactiver l’autocréation des imprimantes Désactiver le mappage des lecteurs clients Pendant le lancement de l'application

Slide 18

CTX101705 : Troubleshooting Slow Logons CTX105618 : Troubleshooting Profile Issues in XenApp CTX106727 : Brief Troubleshooting Guide Troubleshooting Group Policy and profile issues in a domain environment by using Userenv logging Troubleshooting Slow Citrix and Terminal Server logons Understanding the new logon throttling load evaluator options in Citrix Presentation Server 4.5 Articles conseillés

Slide 19

Agenda Etude de cas 1 : Logon gelé pendant 60 secondes

Slide 20

Connexion figée pendant 60 seconds sur ctxnotif.dll Apparu après l’installation du HRP03 de XenApp 4.5 Survient 9 fois sur 10 Se produit avec toute version de client ICA ET RDP Se produit avec un compte local au serveur s'il est dans l'AD Ne se produit pas si le serveur est hors AD Ne se produit pas si la clef Logon est altérée Contexte de l’incident

Slide 21

Capture de traces CDF avec et sans la clef altérée Apres l’event STARTUP : <..> CDF_INFO 19/12/2008 12:38:05.730 CTXGINA. EUEM: endSCSD 1218562, COSD 3438ms, CASD 0ms Apres l’event LOGON : <…> CDF_INFO 19/12/2008 12:39:06.756 CTXGINA. EUEM: PLSD 61016ms, startLSESD 1283031 Analyse de traces CDF (1) Valeurs utilisées par l’agent EdgeSight. Ces valeurs sont intégrées au code de XenApp

Slide 22

La trace CDF indique un délai sans préciser son origine L’ajout d’information dans le code a permis de tracer des étapes supplémentaires <...>12/01/2009 18:30:28.374 CDF_ENTRY IMA_MFServer::InitNameTranslationObject: Entry <…>12/01/2009 18:30:28.375 CDF_INFO IMA_MFServer::InitNameTranslationObject: IClassFactory::LockServer(TRUE) for CLSID_NameTranslate succeeded <…>12/01/2009 18:31:18.904 CDF_ERROR IMA_MFServer::InitNameTranslationObject: translate init failed, result = 0x800706BE  0x800706BE est un code erreur générique concernant une communication RPC   Analyse de traces CDF (2)

Slide 23

Trace réseau depuis le serveur XenApp pour comprendre d’où vient l’erreur RPC 0x800706BE Utilisation de l’outil NLTEST.EXE de Microsoft pour faciliter l’analyse de la trace réseau C:\>nltest /PARENTDOMAIN  C:\>nltest /SC_QUERY:<machinesParentDomain>  C:\>nltest /DSGETDC: <machinesParentDomain> /GC C:\>nltest /DSGETDC: <userDomain> /GC C:\>nltest /DSGETSITE  C:\>nltest /DSGETDC:<parentDomainName> /SITE:<site returned by /DSGETSITE>  Les adresses IP récupérées par ces commandes facilitent l'analyse. Ces API sont filtrées dans WireShark avec la commande DCERPC Investigations supplémentaires

Slide 24

Analyse de la trace réseau

Slide 25

DCERPC montre des retransmissions TCP NLTEST et la trace CDF montrent que l’IP ciblée est un DC WireShark indique que ces paquets transitent par un périphérique Juniper. Ces logs montrent des paquets bloqués.  Cause : Les objets COM sont initialisés une seule fois avec IMA. Juniper bloque les appels suivants car étant considérés comme venant d'une session "TCP stale" (adj. rassie). Analyse de la trace réseau

Slide 26

Résolution Mise à jour du Firewall Juniper avec un nouveau firmware : Modèle Juniper Netscreen ISG2000 Mis à jour vers ScreenOS6.2.0r1 Installer KB948496 (Turn off default SNP features) OU ajouter HKLM\SYSTEM\CCS\Services\Tcpip\Parameters EnableTCPChimney 0x0 EnableRSS 0x0 EnableTCPA 0x0

Slide 27

Désactiver sur la carte réseau du serveur XenApp : IPv4 Checksum Offload IPv4 Large Send Offload Receive Side Scaling KB904946 HKLM\SYSTEM\CCS\Services\Tcpip\Parameters DisableTaskOffload 0x1  Résolution

Slide 28

Commandes utiles nltest /PARENTDOMAIN Renvoie du domaine parent du serveur. nltest /SC_QUERY:<machinesParentDomain> Rapport sur l'état du canal sécurisé utilisé par le service NetLogon lors de sa dernière utilisation et retourne le nom du DC contacté. nltest /DSGETDC: <machinesParentDomain> /GC Interroge le serveur DNS pour la liste des DC et leurs adresses IP. Le paramètre /GC retourne uniquement les serveurs Global Catalog. Le paramètre /SITE: classe les enregistrements renvoyés pour que ceux du site choisi s'affichent en premier. nltest /DSGETSITE Renvoie le nom du site du DC.

Slide 29

Références NLTEXT.EXE http://technet.microsoft.com/en-us/library/cc784211.aspx Syntaxe de NLTEST http://technet.microsoft.com/en-us/library/cc786478.aspx Wireshark www.wireshark.org Modules CDF pour les lenteurs de connexion CTX117590

Slide 30

Agenda Etude de cas 2 : Les connexions restent figées

Slide 31

Les connexions sont figées, n’affichant qu’un fond d’écran Probléme aléatoire sur XenApp 4.5 HRP04 Se produit avec toute version de client ICA ET RDP Se produit après l'authentification Qwinsta et Qfarm sont figées depuis la console Action: récupération d’un dump complet du système quand la commande Qwinsta se fige Contexte de l’incident

Slide 32

Installer les “Debugging Tools for Windows” Ouvrir le fichier de dump avec WinDBG Configurer WinDBG pour utiliser les serveurs de symboles Microsoft et Citrix : SRV*c:\localsymbolcache*http://msdl.microsoft.com/download/symbols*http://ctxsym.citrix.com/symbols Utilisation de WinDbg

Slide 33

!process 0 0 <snip> PROCESS 870fad88 SessionId: 4 Cid: 1828 Peb: 7ffd6000 ParentCid: 01d8 DirBase: a04b4000 ObjectTable: e615a270 HandleCount: 58. Image: csrss.exe PROCESS 8845c958 SessionId: 4 Cid: 1b0c Peb: 7ffd6000 ParentCid: 01d8 DirBase: 9f6f8000 ObjectTable: e6023640 HandleCount: 84. Image: winlogon.exe PROCESS 88556778 SessionId: 0 Cid: 1f88 Peb: 7ffdc000 ParentCid: 0f74 DirBase: 96460000 ObjectTable: e65a5348 HandleCount: 80. Image: qwinsta.exe Etape 1 : Rechercher le process figé

Slide 34

Etape 2 : Regarder les threads du process 7: kd> !process 88556778 PROCESS 88556778 SessionId: 0 Cid: 1f88 Peb: 7ffdc000 ParentCid: 0f74 DirBase: 96460000 ObjectTable: e65a5348 HandleCount: 80. Image: qwinsta.exe VadRoot 870d2208 Vads 54 Clone 0 Private 234. Modified 0. Locked 0. DeviceMap e22ba7c0 Token e5e47cf0 ElapsedTime 00:04:44.017 La commande !process permet d’afficher les détails du process désiré : Temps d’exécution Nom du process Messages associés ….

Slide 35

Etape 2 : Regarder les threads du process THREAD 8861aab8 Cid 1f88.1bd4 Teb: 7ffdf000 Win32Thread: bc161ea8 WAIT: (Unknown) UserMode Non-Alertable 8861aca4 Semaphore Limit 0x1 Waiting for reply to LPC MessageId 00037bb2: Current LPC port e625bbd0 Not impersonating DeviceMap e22ba7c0 Owning Process 88556778 Image: qwinsta.exe Ce thread attend un retour d’un message LPC, allons le consulter Infos sur LPC : http://fr.wikipedia.org/wiki/Link_Control_Protocol http://www.tcpipguide.com/free/t_PPPLinkControlProtocolLCP.htm

Slide 36

Etape 3 : Sauts de puce… 7: kd> !lpc message 00037bb2 Searching message 37bb2 in threads ... Server thread 89815db0 is working on message 37bb2 Client thread 8861aab8 waiting a reply from 37bb2 Searching thread 8861aab8 in port rundown queues .. Allons voir le thread 89815db0 qui a envoyé ce message LPC 7: kd> !thread 89815db0 THREAD 89815db0 Cid 1218.0c00 Teb: 7ff8f000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable 88603e40 Mutant - owning thread 884d7db0 Not impersonating DeviceMap e10018b8 Owning Process 887d32d0 Image: svchost.exe Ce thread appartient à un autre thread de svchost.exe…

Slide 37

Etape 3 : Sauts de puce… 7: kd> !thread 884d7db0 THREAD 884d7db0 Cid 1218.12ec Teb: 7ffdd000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable 884d7f9c Semaphore Limit 0x1 Waiting for reply to LPC MessageId 0000fa9e: Current LPC port e121fdb8 Not impersonating DeviceMap e10018b8 Owning Process 887d32d0 Image: svchost.exe Ce thread attend aussi un retour d’un message LPC, allons le consulter

Slide 38

Etape 3 : Sauts de puce… 7: kd> !lpc message 0000fa9e Searching message fa9e in threads ... Server thread 898c6db0 is working on message fa9e Client thread 884d7db0 waiting a reply from fa9e Searching thread 884d7db0 in port rundown queues ... On continue… allons voir le thread 898c6db0 7: kd> !thread 898c6db0 THREAD 898c6db0 Cid 0b38.188c Teb: 7ff4d000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable 884362c8 SynchronizationEvent Not impersonating DeviceMap e11399e8 Owning Process 88340758 Image: ImaSrv.exe <..> LPC Server thread working on message Id fa9e Ce thread appartient à ImaSrv.exe et ne semble pas attendre d’autre objets !!

Slide 39

Etape 4 : Analyse d’un dump ImaSrv.exe 0:029>!analyze –v –hang <…> DERIVED_WAIT_CHAIN: Dl Eid Cid WaitType -- --- ------- -------------------------- 29 ad0.bdc Critical Section --> 71 ad0.1030 Sleep WAIT_CHAIN_COMMAND: ~29s;k;;~71s;k;; L’analyse automatique indique que le thread 71 bloque le thread 29. Allons plus loin que l’analyse automatique en regardant l’état des blocages (locks).

Slide 40

Etape 4 : Analyse d’un dump ImaSrv.exe 0:029> !locks   CritSec +7156fe8 at 07156fe8 WaiterWoken No LockCount 6 RecursionCount 1 OwningThread 1030 EntryCount 0 ContentionCount 6d *** Locked Thread 1030 (thread n°71) bloque 6 autres threads Cherchons les….

Slide 41

Etape 4 : Analyse d’un dump ImaSrv.exe 0:029> ~*kv <snip> 70 Id: ad0.102c Suspend: 1 Teb: 7ffde000 Unfrozen ChildEBP RetAddr Args to Child 282bf9d4 7c827d0b 7c83d236 00000590 00000000 ntdll!KiFastSystemCallRet (FPO: [0,0,0]) 282bf9d8 7c83d236 00000590 00000000 00000000 ntdll!NtWaitForSingleObject+0xc (FPO: [3,0,0]) 282bfa14 7c83d281 00000590 00000004 031de9c8 ntdll!RtlpWaitOnCriticalSection+0x1a3 (FPO: [Non-Fpo]) 282bfa34 003d1add 07156fe8 282bfa54 07111411 ntdll!RtlEnterCriticalSection+0xa8 (FPO: [Non-Fpo]) 282bfa40 07111411 07156fe8 031de9e0 046a5b80 ImaCommon!Sync_EnterCriticalSection+0xd 282bfa54 071150dd 031de9e0 282bfa8c 00000001 ImaAccess!OdbcConnectionMgr::GetConnectionFromPool+0x11 282bfbc8 04701fe4 031de9c8 282bfd8c 00000001 ImaAccess!IMA_DIR_DADODBC::Search+0x8d 282bfc08 046e5691 282bfd8c 00000001 282bfd40 ImaLhc!LHCSearch+0x34 Un CTRL+F pour chercher toutes les sections critiques “07156fe8” : Threads ~70,~75,~81,~91,~93,~97 sont bloquées sur cette critical section

Slide 42

Etape 4 : Analyse d’un dump ImaSrv.exe 0:071> ~71s <..> 0:071> kv ChildEBP RetAddr Args to Child <..> 283bf660 1b0425ca 283bf670 419305f4 00000001 msjet40!Cursor::Delete+0x125 (FPO: [Uses EBP] [1,0,3]) 283bf9e8 1b039b82 0789a310 00000001 00000000 msjet40!ErrExecuteQuery+0x65a 283bfa34 1b05548b 0779ddcc 00000000 00000732 msjet40!ErrExecuteTempQuery+0x13d 283bfa64 4c23b01e 1b01dbc8 000000fd 00000732 msjet40!JetExecuteTempQuery+0xc9 <..> 283bfd20 488b3fc1 0d9554c4 283bfdc8 26e3ebcc odbcjt32!SQLExecute+0x9 (FPO: [1,0,0]) 283bfd3c 26e099f5 00000001 00000000 2701cf90 odbc32!SQLExecute+0xd3 (FPO: [Non-Fpo]) 283bfd5c 26e0a05c 27310cf8 26df8081 26e3ebc0 RMMonitorSS!CrmsDb::ExecutePrepared+0x15 283bfd64 26df8081 26e3ebc0 26e3ecc4 283bfdc8 RMMonitorSS!CRMS_Database_Bind::Execute+0xc 283bfd74 26df0472 283bfdc8 290026b0 26e3ebc0 RMMonitorSS!Purge_Metric_Table::Purge+0x61 283bfd98 26df2694 26e3ecc4 290026b0 283bfef8 RMMonitorSS!LocalDatabase::PurgeMetric+0xa2 283bfe84 26d8c72f 290026b0 01c95eb0 003e1530 RMMonitorSS!LocalDatabase::Purge+0x1b4 ImaSrv.exe est donc en train de faire une purge de la base de données locale RM

Slide 43

MSJet a un problème de synchronisation et le code a été modifié il y a longtemps pour autoriser un seul thread d’ImaSrv à accéder à MSJet (RM, LHC, PS) Si une base est trop importante (RM typiquement), sa purge peut prendre énormément de temps et donc bloquer d’autres opérations concomittentes Dans ce dossier, recréer la base RM locale a résolu le problème de logon figés. Résolution

Slide 44

Références Userdump http://support.microsoft.com/kb/241215 Systemdump http://support.citrix.com/article/CTX111072 Debugging Tools for Windows http://www.microsoft.com/whdc/devtools/debugging/debugstart.mspx How to use the Citrix Symbols Server CTX118622 Critical Tool Matrix for XenApp Environments CTX122827

Slide 45

Questions

Slide 46

by

Summary: Troubleshooting slow logons

Tags: docforum

URL:
More by this User
Most Viewed