How do I use debug logs to troubleshoot a GUP?

How does the GUP get defined?

• A setting will be added to the LiveUpdate (LU) policy specifying one member of the client group as a content proxy. This machine will be the Group Update Provider (GUP)
• Every SEP client contains mini-HTTP server code that allows it to potentially become the GUP.
• The LU Policy will specify a hostname/IP and port of the GUP HTTP server machine that will default to port 2967, but can be reconfigured to an alternate port. The administrator can specify either the host name of the machine or the IP. (The reason for using port 2967 is that Symantec customers already have routing and firewalls set up for this. In most instances, it is known that there are no conflicts with port 2967, or those conflicts were already sorted out by the administrators. Port 80 is a collision prone port.)
• The file transfer will be over HTTP and contained within the HTTP Response payload. This is exactly the same as the existing transport. The protocol will be the SyLink protocol.
• Content delivered by Symantec Endpoint Protection Manager (SEPM) will be cached.
• The GUP will NOT initially support the patch and update channel. There are no plans to address this yet.

When a client becomes the GUP

• The mini-HTTP server code will be a DLL extension to the SMC Agent. The design has the GUP running independently of the internal content handling. GUP is loaded by the SMC Agent when configured. When it starts up it begins listening on the configured port. It continues listening until it is shut down.
• All the clients in the group receive the same proxy policy configuration. The one that matches the proxy address/hostname is the proxy and loads the micro web server..
• The machine that is designated as the GUP will create a directory, if it doesn’t already exist, at the following location:

  (Client install location)\SharedUpdates

Default location in Windows 32bit: C:\Program Files\Symantec\Symantec Endpoint Protection\<Current version/build number>\Bin\SharedUpdates

Default location in Windows 64bit: C:\Program Files(x86)\Symantec\Symantec Endpoint Protection\<Current version/build number>\Bin\SharedUpdates

• This SharedUpdates folder will cache all proxied files. For the first round of implementation this will only be managed LU content. No other communication or content will be proxied. Getting index files and profiles, posting state and logs, etc. will be done directly with server.

• The SharedUpdates directory will not immediately be populated, but rather, when the GUP receives a request it checks to see if the requested file(s) are present in the local cache. If it is, it responds to the request with the file. If it isn’t, then GUP holds the pending request, and reissues the same GetLUFile SyLink request to the server. When that file arrives it is added to the GUP cache.
• The GUP code can only get content updates from SEPM. As far as the GUP is concerned, it does not know about the client it resides on, so even if the client were to get updated via alternative means - Intelligent Updater or Symantec/Internal LiveUpdate - the GUP would not be able to use those updates to proxy for other clients.
• For more information regarding GUP see the latest Installation and Administration Guide under the "Current release:" section at Related Documents

Below is an example of a system registry after the GUP is activated:

• [HKEY_LOCAL_MACHINE\SOFTWARE\Symantec\Symantec Endpoint Protection\LiveUpdate]
  "Description"="Created automatically during product installation."
  "Enabled3rdPartyManagement"=dword:00000000
  "MasterClientHost"="##,###,###,###"
  "MasterClientPort"="2967"
  "UseLiveUpdateServer"=dword:00000000
  "UseManagementServer"=dword:00000001
  "UseMasterClient"=dword:00000001
  "HttpEncrypt"=dword:00000001
  "HttpProxyMode"=dword:00000000
  "HttpProxyRequireAuthentication"=dword:00000000
  "FtpEncrypt"=dword:00000001
  "FtpProxyMode"=dword:00000000
  "FtpProxyRequireAuthentication"=dword:00000000
  "AllowLocalScheduleChange"=dword:00000000
  "AllowManualLiveUpdate"=dword:00000000
  "EnableProductUpdates"=dword:00000000
  "LastLuProductInventoryHash"=hex:##,##,##,##,##,##,##,##,##,##,##,##,##,##,##,\##
  "LastGoodSession"=hex:##,##,##,##,##,##,##,##
• There is a debug.log file saved to the "C:\ProgramData\Symantec\Symantec Endpoint Protection\CurrentVersion\Data\Logs" folder by default. If the default logging is disabled you can enable it with the following registry setting:
• To enable debugging for the GUP, you can either enable it through the SEP user interface - SEP UI -> Help and Support button -> Troubleshooting -> Debug Logs -> Client Management section -> Edit Debug Log Settings button -> check the Debug On box -> Debug level: 0 -> Log level: 0 - Debug -> Log file size (KB): 10000 -> OK -> Close, or modify the following registry keys:

Windows 64bit: [HKEY_LOCAL_MACHINE\SOFTWARE\WOW6432node\Symantec\Symantec Endpoint Protection\SMC]
Windows 32bit: [HKEY_LOCAL_MACHINE\SOFTWARE\Symantec\Symantec Endpoint Protection\SMC]

"smc_debuglog_on = dword:00000001"

Windows 64bit: [HKEY_LOCAL_MACHINE\SOFTWARE\WOW6432node\Symantec\Symantec Endpoint Protection\SMC]
Windows 32bit: [HKEY_LOCAL_MACHINE\SOFTWARE\WOW6432node\Symantec\Symantec Endpoint Protection\SMC\Log]

"debug_log_filesize = dword:0x00002710 (10000)"

• The SMC process (the executable for the "Symantec Management Client" service) must be stopped and restarted for changes in debug logging to take effect:

From a Run line type in the following:
smc -stop
Once the SEP shield icon disappears from the System Tray, then type:
smc -start

• You also should be able to telnet to Port 2967 on the GUP and see the connection in the GUP logs.
  
  
  Below is an example of a GUP receiving a connection from another machine and the connection working but the data in the connection
  is bad and the GUP rejecting the connection:
  
  03/21 23:00:59 [2628:1908] GUProxy: thread [1908] accepted on socket 2228
  03/21 23:01:03 [2628:1908] GUPROXY - GUProxy HTTP in - H
  03/21 23:01:03 [2628:1908] GUPROXY - malformed or misdirected request
  03/21 23:01:03 [2628:1908] GUProxy - closing accepted socket

• Successful Connection and update from a client:
  
  03/23 11:06:01 [2640:2088] GUProxy: thread [2088] accepted on socket 2012
  03/23 11:06:01 [2640:2088] GUPROXY - GUProxy HTTP in - GET /content/{C60DC234-65F9-4674-94AE-62158EFCA433}/80322021/delta8032
  03/23 11:06:01 [2640:2088] GUPROXY - GUProxy File - /content/{C60DC234-65F9-4674-94AE-62158EFCA433}/80322021/delta80322003.dax
  03/23 11:06:01 [2640:2088] GUProxy content cached - sending to client
  03/23 11:06:01 [2640:2088] GUProxy - closing accepted socket
  03/23 11:06:01 [2640:2088] GUProxy thread [2088] accepting

• Below is what you will see in the debug.log when a GUP is first configured:
  
  03/21 20:03:05 [2628:3124] GUProxy: PolicyUpdateCallback called
  03/21 20:03:06 [2628:3124] GUProxy system event - type 0 - desc <Start using Group Update Provider (proxy server) @ 192.168.2.4:2967.> -extra <(null)>
  03/21 20:03:06 [2628:3124] GUProxy: Start using Group Update Provider (proxy server) @ 192.168.2.4:2967.
  03/21 20:03:06 [2628:3124] GUProxy system event - type 0 - desc <Start serving as the Group Update Provider (proxy server).> - extra <(null)>
  03/21 20:03:06 [2628:3124] GUProxy: Policy Change - Client will start serving as a local proxy server @ 192.168.2.4:2967
  03/21 20:03:06 [2628:3124] GUProxy: SetUpGUPListenSocket
  03/21 20:03:06 [2628:3124] GUProxy: Create new GUP socket
  03/21 20:03:06 [2628:3124] GUProxy: creating GUP listen socket with port 2967
  03/21 20:03:07 [2628:1908] GUProxy: listenthread [1908] starting
  03/21 20:03:07 [2628:1908] GUProxy thread [1908] accepting

• Example of a File request "not in cache", but being retrieved by the GUP from the server:
  
  03/24 13:26:08 [1436:1796] GUProxy: thread [1796] accepted on socket 2404
  03/24 13:26:08 [1436:1796] GUPROXY - GUProxy HTTP in - GET /content/{C60DC234-65F9-4674-94AE-62158EFCA433}/80324005/delta8032
  03/24 13:26:08 [1436:1796] GUPROXY - GUProxy File - /content/{C60DC234-65F9-4674-94AE-62158EFCA433}/80324005/delta80323019.dax
  03/24 13:26:08 [1436:1796] GUProxy new cache entry
  03/24 13:26:08 [1436:1796] GUPROXY - GUProxy mangled file -
  #content#{C60DC234-65F9-4674-94AE-62158EFCA433}#80324005#delta80323019!dax
  03/24 13:26:09 [1436:1796] Lock held for 47ms
  03/24 13:26:09 [1436:1796] GUPROXY - GUProxy - Requested file not in cache; contacting the SEPM server at - <SERVER>
  03/24 13:26:09 [1436:1796] GUPROXY - GUProxy Response - HTTP/1.1 200 OK Server: Microsoft-IIS/5.1 X-Powered-By: ASP.NET Dat
  03/24 13:26:09 [1436:1796] GUProxy - sending response to client
  03/24 13:26:09 [1436:1796] GUProxy - closing accepted socket
  03/24 13:26:09 [1436:1796] GUProxy thread [1796] accepting

Example of a Sylink log from a client to a GUP requesting an update:

  <LUThreadProc>Starting LU download.
03/24 14:29:04 [2232] <LUThreadProc>Got a valid context from GetCurrentServerEx
03/24 14:29:04 [2232] <LUThreadProc>Setting the session timeout on LUSession to 2 min.
03/24 14:29:04 [2232] <mfn_MakeGetLUFileIISUrl:>Requested Content Path is:
/content/{C60DC234-65F9-4674-94AE-62158EFCA433}/80324005/delta80323019.dax
03/24 14:29:04 [2232] <GetLUFileRequest:>IIS URL: /content/{C60DC234-65F9-4674-94AE-62158EFCA433}/80324005/delta80323019.dax
03/24 14:29:04 [2232]
<GetLUFileRequest:>http://192.168.2.5:2967/content/{C60DC234-65F9-4674-94AE-62158EFCA433}/80324005/delta80323019.dax
03/24 14:29:04 [2232] <GetLUFileRequest:>NEW download: C:\Program Files\Symantec\Symantec Endpoint Protection\LiveUpdate\LUF5.tmp
03/24 14:29:04 [2232] <UpdateLUFileList:>Updating existing Download File List with : {C60DC234-65F9-4674-94AE-62158EFCA433}80324005
03/24 14:29:04 [2232] <UpdateLUFileList:>Updating existing Download File List Temp file name from:  to C:\Program Files\Symantec\Symantec Endpoint Protection\LiveUpdate\LUF5.tmp
03/24 14:29:04 [2232] 14:29:4=>Sending HTTP REQUEST to download LU file
03/24 14:29:05 [2232] 14:29:5=>HTTP REQUEST sent
03/24 14:29:05 [2232] <GetLUFileRequest:>IIS return=200
03/24 14:29:05 [2232] <mfn_DoGetLUFile200>Downloading LU file from server. Moniker: {C60DC234-65F9-4674-94AE-62158EFCA433}Server File Path:/content/{C60DC234-65F9-4674-94AE-62158EFCA433}/80324005/delta80323019.daxLocal Path:C:\Program
Files\Symantec\Symantec Endpoint Protection\LiveUpdate\LUF5.tmp
03/24 14:29:05 [2232] <mfn_DoGetLUFile200>Content Length => 35403
03/24 14:29:05 [2232] <UpdateLUFileList:>Updating existing Download File List with : {C60DC234-65F9-4674-94AE-62158EFCA433}80324005
03/24 14:29:05 [2232] <UpdateLUFileList:>Updating existing Download File List Temp file name from: C:\Program Files\Symantec\Symantec Endpoint Protection\LiveUpdate\LUF5.tmp to C:\Program Files\Symantec\Symantec Endpoint Protection\LiveUpdate\LUF5.tmp
03/24 14:29:05 [2232] <mfn_DoGetLUFile200>LU Content Downloaded.  Moniker: {C60DC234-65F9-4674-94AE-62158EFCA433} Target     Seq:80324005 Full version:0 Delta Base Seq:80323019
03/24 14:29:05 [2232] <PostEvent>going to post event=EVENT_LU_DOWNLOAD_COMPLETED
03/24 14:29:25 [2224] <CSyLink::mfn_DownloadNow()>
03/24 14:29:25 [2224] </CSyLink::mfn_DownloadNow()>
03/24 14:29:30 [2232] <PostEvent>done post event=EVENT_LU_DOWNLOAD_COMPLETED, return=0



Below is what you will see in the Sylink if the GUP is off line:

03/25 00:38:01 [2232] <LUThreadProc>Setting the session timeout on LUSession to 2 min.
03/25 00:38:01 [2232] <mfn_MakeGetLUFileIISUrl:>Requested Content Path is:
/content/{812CD25E-1049-4086-9DDD-A4FAE649FBDF}/80324040/delta80321051.dax
03/25 00:38:01 [2232] <GetLUFileRequest:>IIS URL: /content/{812CD25E-1049-4086-9DDD-A4FAE649FBDF}/80324040/delta80321051.dax
03/25 00:38:01 [2232]   
<GetLUFileRequest:>http://192.168.2.5:2967/content/{812CD25E-1049-4086-9DDD-A4FAE649FBDF}/80324040/delta80321051.dax
03/25 00:38:01 [2232] <GetLUFileRequest:>NEW download: C:\Program Files\Symantec\Symantec Endpoint
Protection\LiveUpdate\LUF140D.tmp
03/25 00:38:01 [2232] <UpdateLUFileList:>Updating existing Download File List with : {812CD25E-1049-4086-9DDD-A4FAE649FBDF}80324040
03/25 00:38:01 [2232] <UpdateLUFileList:>Updating existing Download File List Temp file name from:  to C:\Program Files\Symantec\Symantec Endpoint Protection\LiveUpdate\LUF140D.tmp
03/25 00:38:01 [2232] 0:38:1=>Sending HTTP REQUEST to download LU file
03/25 00:38:24 [2224] <CSyLink::mfn_DownloadNow()>
03/25 00:38:24 [2224] </CSyLink::mfn_DownloadNow()>
03/25 00:38:24 [2232] 0:38:24=>HTTP REQUEST sent
03/25 00:38:24 [2232] <GetLUFileRequest:>Send Request failed.. Error Code = 12029
03/25 00:38:24 [2232] <ParseErrorCode:>12029=>The attempt to connect to the server failed.
03/25 00:38:24 [2232] <GetLUFileRequest:>IIS return=0
03/25 00:38:24 [2232] <ParseErrorCode:>12029=>The attempt to connect to the server failed.
03/25 00:38:24 [2232] <GetLUFileRequest:>COMPLETED
03/25 00:38:24 [2232] <LUThreadProc> - GETLUFILE_CONNECTION_ERROR getting content moniker:   
{812CD25E-1049-4086-9DDD-A4FAE649FBDF}; revision: 80324040 from server: 192.168.2.5
03/25 00:38:24 [2232] LU file download failed due to HTTP error:0
03/25 00:38:24 [2232] <CExpBackoff::Increment()>
03/25 00:38:24 [2232] Backoff index incremented
03/25 00:38:24 [2232] Backoff wait index: 1
03/25 00:38:24 [2232] </CExpBackoff::Increment()>
03/25 00:38:24 [2232] <CExpBackoff::Wait()>
03/25 00:38:24 [2232] CExpBackoff wait time in seconds: 32
03/25 00:38:56 [2232] </CExpBackoff::Wait()>
03/25 00:38:56 [2232] <LUThreadProc>Setting the session timeout on LUSession to 2 min.
03/25 00:38:56 [2232] <mfn_MakeGetLUFileIISUrl:>Requested Content Path is:   
/content/{E5A3EBEE-D580-421e-86DF-54C0B3739522}/80324040/delta80321051.dax
03/25 00:38:56 [2232] <GetLUFileRequest:>IIS URL: /content/{E5A3EBEE-D580-421e-86DF-54C0B3739522}/80324040/delta80321051.dax
03/25 00:38:56 [2232]   
<GetLUFileRequest:>http://192.168.2.5:2967/content/{E5A3EBEE-D580-421e-86DF-54C0B3739522}/80324040/delta80321051.dax
03/25 00:38:56 [2232] <GetLUFileRequest:>NEW download: C:\Program Files\Symantec\Symantec Endpoint
Protection\LiveUpdate\LUF140E.tmp
03/25 00:38:56 [2232] <UpdateLUFileList:>Updating existing Download File List with : {E5A3EBEE-D580-421e-86DF-54C0B3739522}80324040
03/25 00:38:56 [2232] <UpdateLUFileList:>Updating existing Download File List Temp file name from:  to C:\Program Files\Symantec\Symantec Endpoint Protection\LiveUpdate\LUF140E.tmp
03/25 00:38:56 [2232] 0:38:56=>Sending HTTP REQUEST to download LU file
03/25 00:39:18 [2232] 0:39:18=>HTTP REQUEST sent
03/25 00:39:18 [2232] <GetLUFileRequest:>Send Request failed.. Error Code = 12029
03/25 00:39:18 [2232] <ParseErrorCode:>12029=>The attempt to connect to the server failed.
03/25 00:39:18 [2232] <GetLUFileRequest:>IIS return=0
03/25 00:39:18 [2232] <ParseErrorCode:>12029=>The attempt to connect to the server failed.
03/25 00:39:18 [2232] <GetLUFileRequest:>COMPLETED
03/25 00:39:18 [2232] <LUThreadProc> - GETLUFILE_CONNECTION_ERROR getting content moniker:   
{E5A3EBEE-D580-421e-86DF-54C0B3739522}; revision: 80324040 from server: 192.168.2.5
03/25 00:39:18 [2232] LU file download failed due to HTTP error:0
03/25 00:39:18 [2232] <CExpBackoff::Increment()>
03/25 00:39:18 [2232] Backoff index incremented
03/25 00:39:18 [2232] Backoff wait index: 2
03/25 00:39:18 [2232] </CExpBackoff::Increment()>
03/25 00:39:18 [2232] <CExpBackoff::Wait()>
03/25 00:39:18 [2232] CExpBackoff wait time in seconds: 64
03/25 00:39:26 [2224] <CSyLink::mfn_DownloadNow()>
03/25 00:39:26 [2224] </CSyLink::mfn_DownloadNow()>
03/25 00:40:22 [2232] </CExpBackoff::Wait()>