Gene Kupfer who is one of the best resources around when it comes to Symantec Workspace Streaming published an excellent article on the inner workings of the streaming process. I often refer to this article when I am trying to determine a cause when I'm having issues.
This article is meant to be used in conjunction with Gene's article to help you find the cause of issues you may be experiencing. For each of the steps mentioned in the article, the SWS system created log entries. This document is an attempt to show where the log entries can be located. In this article, I attempt to show the log entries for a successful streaming process. If you are having issues, this might help you determine which step is breaking down.
Topics
Key Bits of Information
One of the key pieces of information you will need is the Unique Package ID. The log files produce a lot of information, so we are going to need some key piece of information to help us search the logs. For this example I am going to trace the streaming of the Opera Browser from my Streaming Server (SWSSWCSVR) to my client (SWCClient1).
To find the Unique Package ID, you will start the Streaming Console, 1) navigate to the packages tab, 2) click on the + key next to the package, 3) then select the package version that is provisioned to the user.
Once you have selected the package you will have access to the Unique Package ID
Make note of this value. Note: I usually just use the first 8 characters of the GUID. In some of the logs we remove the dashes before writing entries to the log, but in others we write the GUID with the dashes. For this example the GUID in question is 7d0b50b5-9332-45fe-835b-d2601fe2dd42, and for most of my log searches I will be looking for 7d0b50b5. Note: Because I will be taking each of these steps individually, the times will not be in sync between the various log files.
Making the process as easy as possible
Because the Workspace Streaming system utilizes rollover logs, there can be a number of log files on both the client and the server. Since I only need to use the logs if something isn't working the way I want, I try to do all of my debugging work from a single client. I also remove all logs before starting the process.
Client Cleanup
To remove all client side logs, stop the AWE x.x Streaming Service. Delete all of the logs which are stored in the C:\_AC\Logs folder by default. If this path is not correct you can find the correct path by looking at the HKLM\Software\AppStream\AppMgr\DestinationFolder registry key. You will need to append Logs to this value for the correct path.
Server Cleanup
In this example all server services are on a single box. If you have implemented a tiered architecture you would stop the various service on the specific machine the service is running.
On the server stop the AWE Launch Server, AWE Streaming Server, and AWE Streamlet Engine. Delete all of the files in the following folders.
%ProgramFiles%\Symantec\Endpoint Virtualization\Workspace Streaming\Server\launchserv\log
%ProgramFiles%\Symantec\Endpoint Virtualization\Workspace Streaming\Server\server\Logs
%ProgramFiles%\Symantec\Endpoint Virtualization\Workspace Streaming\Server\streamletEngine\dci\log
You will need to restart all of the services before starting the debugging process. Once the services have been restarted and you have confirmed the Streaming Server components are up and running, just double-click the pre-cached icon to start the process.
Client Log Entries
If you stopped the service and deleted the log files, you can search the MgrLog1.txt file for the relevant entries. You should see something like the following values:
2010-08-12 14:28:50 INFO [2164] Management,Manager::launchStreamedApplication#2339| Package "{7D0B50B5933245FE835BD2601FE2DD42}" not found in launch info store, user will be directed to launch server to install application.
2010-08-12 14:28:50 ERROR [1772] Management,LaunchSessionInfo::readLaunchInfoFromRegistry#190| Could not open Registry Key Apps\launch_7D0B50B5933245FE835BD2601FE2DD42, error: 2
2010-08-12 14:28:50 INFO [3652] AppMgrGui,CEventHandler::launchSessionFromUrl#3846| Launching session for package Opera
2010-08-12 14:28:50 INFO [3724] AppMgrGui,CAppMgrApp::launchSession#679| Attempting to authenticate session, URL: http://swsswcsvr:8080/loginServlet?ExeName=Program Files\Opera\opera.exe&CmdLineParams=&WorkingDir=PROGRAM FILES\OPERA\&ServerParams=1/1&aid=8ad9e67e-f772-49d0-909f-d3dd6fda24de&pid=7d0b50b5-9332-45fe-835b-d2601fe2dd42
2010-08-12 14:28:50 INFO [3724] Authentication,WinHttpInterface::enableAutoLogin#2089| Enabling auto-login. Enable: 1
2010-08-12 14:28:50 INFO [3724] Authentication,Authenticator::authenticate#920| Session created.
The first error you see is just stating that the package has not been streamed to the client so it is going to be need to streamed to the client.
Launch Server Log Entries
The Launch Server logs are stored in %ProgramFiles%\Symantec\Endpoint Virtualization\Workspace Streaming\Server\launchserv\log folder on the server. The log file to search is the launchserver.log. You will seen messages like the following for the package request.
2010-08-12 14:28:50,752 INFO [http-SWSSWCSvr%2F192.168.11.152-8080-2] | shortcut launch {pid=7d0b50b5-9332-45fe-835b-d2601fe2dd42, ServerParams=1/1, ExeName=Program Files\Opera\opera.exe, WorkingDir=PROGRAM FILES\OPERA\, aid=8ad9e67e-f772-49d0-909f-d3dd6fda24de, OS=Windows NT 5.1}
2010-08-12 14:28:50,752 INFO [http-SWSSWCSvr%2F192.168.11.152-8080-2] | datasource is set as LDAP
2010-08-12 14:28:50,752 INFO [http-SWSSWCSvr%2F192.168.11.152-8080-2] | Integrated login enabled; using NTLM
2010-08-12 14:28:50,752 WARN [http-SWSSWCSvr%2F192.168.11.152-8080-2] | Authentication failure challenge
2010-08-12 14:28:50,752 INFO [http-SWSSWCSvr%2F192.168.11.152-8080-2] | shortcut launch {pid=7d0b50b5-9332-45fe-835b-d2601fe2dd42, ServerParams=1/1, ExeName=Program Files\Opera\opera.exe, WorkingDir=PROGRAM FILES\OPERA\, aid=8ad9e67e-f772-49d0-909f-d3dd6fda24de, OS=Windows NT 5.1}
2010-08-12 14:28:50,768 INFO [http-SWSSWCSvr%2F192.168.11.152-8080-2] | datasource is set as LDAP
2010-08-12 14:28:50,768 INFO [http-SWSSWCSvr%2F192.168.11.152-8080-2] | Integrated login enabled; using NTLM
2010-08-12 14:28:50,768 INFO [http-SWSSWCSvr%2F192.168.11.152-8080-2] | user identified as SEVDOMAIN\Scot
The log entries we are looking at here are a combination of Steps 1 - 4 of Gene's flow chart. You can see that the Launch Server is passing information to the STE and in the first set of entries authentication failed. The second set of entries show success.
Streamlet Engine Log Entries
The Streamlet Log Entries will be located in %ProgramFiles%\Symantec\Endpoint Virtualization\Workspace Streaming\Server\streamletEngine\dci\log\dci_all.log folder. If things are working correctly, you will see log entries like the following:
2010-08-12 16:13:46,255 DEBUG [http-0.0.0.0-9832-3] getAppGroupLaunchParameters| Checking cache for username=Scot; returning: Username :Scot
First Name :Scot
Last Name :Curry
# of groups :4
group0 = Domain Admins
group1 = LOCAL\DefaultAllGroup
group2 = Administrators
group3 = Domain Users
2010-08-12 16:13:46,255 INFO [http-0.0.0.0-9832-3] getAppGroupLaunchParameters| USER getUser() : Scot
2010-08-12 16:13:46,255 DEBUG [http-0.0.0.0-9832-3] getAppGroupLaunchParameters| Double-click launch request for [Scot] on
App 8ad9e67e-f772-49d0-909f-d3dd6fda24de, Package 7d0b50b5-9332-45fe-835b-d2601fe2dd42:1; labelId 1; Launcher ID=3; OS: Windows NT 5.1
2010-08-12 16:13:46,271 DEBUG [http-0.0.0.0-9832-3] getAppGroupLaunchParameters| Number of provision records: 14
2010-08-12 16:13:46,271 DEBUG [http-0.0.0.0-9832-3] getAppGroupLaunchParameters| Launch app: {'34','11','8ad9e67ef77249d0909fd3dd6fda24de','Opera','PROGRAM FILES\OPERA\OPERA.EXE','PROGRAM FILES\OPERA\','','','null','null','Opera','$userappdatadir$\Microsoft\Internet Explorer\Quick Launch|$desktopdir$|$programmenudir$','11','7d0b50b5933245fe835bd2601fe2dd42','1','Opera','11','Windows NT 5.0,Windows NT 5.1,Windows NT 5.2','','null','null','null','null','1080','2010-02-06 17:13:05.917','2008-12-03 16:05:00.0','2008-12-03 16:05:00.0','null','Opera','null','4','4','1','1','0','1','4258694','1','Opera.ZIP','Version 5.2.2.604','x86','1','none','1020','63','0','Scot','0','0','63','34','1','1','2','Default Server Group','null','null','null','null','1','1','1','0','0','0','0','1','null','2010-01-16 15:48:56.533'}
2010-08-12 16:13:46,333 DEBUG [http-0.0.0.0-9832-3] getAppGroupLaunchParameters| app launch paramters got AsApplication:
AppPk = 34
PackagePk = 11
GuidAsString = 8ad9e67ef77249d0909fd3dd6fda24de
ApplicationName = Opera
ExecutablePath = PROGRAM FILES\OPERA\OPERA.EXE
WorkingDirectory = PROGRAM FILES\OPERA\
CommandLineParameters =
VendorVersion =
Description = null
Tooltip = null
DisplayTitle = Opera
ShortcutPath = $userappdatadir$\Microsoft\Internet Explorer\Quick Launch|$desktopdir$|$programmenudir$
Server name :server-backup=;ls-backup=;
IP :SWSSWCSvr
Port :8080
Session ID :1480
2010-08-12 16:13:46,364 INFO [http-0.0.0.0-9832-3] getAppGroupLaunchParameters| RQ dispatch time: 109 ms
2010-08-12 16:13:46,427 INFO [http-0.0.0.0-9832-2] ReqAuthenticateSession| InsideClientLicenseInfo
2010-08-12 16:13:46,427 INFO [http-0.0.0.0-9832-2] ReqAuthenticateSession| LICENSE TYPE : 3
2010-08-12 16:13:46,427 DEBUG [http-0.0.0.0-9832-2] ReqAuthenticateSession| MAX_SEATS = 0
2010-08-12 16:13:46,443 DEBUG [http-0.0.0.0-9832-2] ReqAuthenticateSession| PGuid :7d0b50b5933245fe835bd2601fe2dd42
2010-08-12 16:13:46,443 INFO [http-0.0.0.0-9832-2] ReqAuthenticateSession| Package Name --> Opera
2010-08-12 16:13:46,458 DEBUG [http-0.0.0.0-9832-2] ReqAuthenticateSession| Authentication :OK: sessionId=1480, packageId=7d0b50b5-9332-45fe-835b-d2601fe2dd42:1, time_gap=0
2010-08-12 16:13:46,458 DEBUG [http-0.0.0.0-9832-2] ReqAuthenticateSession| AUTH: OK
Launch Server Log Entries
The launch server log entries are in the %ProgramFiles%\Symantec\Endpoint Virtualization\Workspace Streaming\Server\server\Logs folder. If you stopped the services and deleted the logs, you will see entries like the following if everything is working as expected.
Thu Aug 12 16:13:46 2010 Event: New Session, Status: Success, USER_ID: 1480 NEW_USER: True USER_NAME: Scot CLIENT_VERSION: 6.2.0.924 USER_MACHINE: 192.168.11.152 SESSION_ID: 1480 APPLICATION_GUID: 7D0B50B5933245FE835BD2601FE2DD42 VERSION_ID: 1 APPLICATION_NAME: Opera
Thu Aug 12 16:13:53 2010 Event: Produce Predictive Data, Status: Success, APPLICATION_GUID: 7D0B50B5933245FE835BD2601FE2DD42 VERSION_ID: 1 APPLICATION_NAME: Opera PREDICTION_FILE_NAME: Pred2.prd
The information above is related to the streaming of actual packages to the client. I occasionally have to deal with pre-populated icons that don't show up on the desktop. In those instances there are fewer entries that need to be checked.
Client Logs
The client log entries will look something like the following:
2010-08-12 16:57:08 INFO [3540] Management,AdReporter::sendRequestWithCallback#1183| Sending package advertisement request on behalf of windows user SEVDOMAIN\Scot
2010-08-12 16:57:10 INFO [3540] Management,AdReporter::sendRequestWithCallback#1243| send to Server:http://swsswcsvr:8080, UN=Scot, CL=6.2.0.924, OS=5
2010-08-12 16:57:10 INFO [3540] Management,Streamer::Streamer#89| New Server - name: swsswcsvr, port: 8080, protocol: 0, id: 1
Streamlet Engine Entries
When just requesting icon pre-population, the launch server and the streaming server are not required and the request is forwarded directly to the Streamlet Engine. The Streamlet Engine should look like:
2010-08-12 16:57:10,726 DEBUG [http-0.0.0.0-9832-3] ProvisionInfoRequest| Checking cache for username=Scot; returning: Username :Scot
First Name :Scot
Last Name :Curry
# of groups :4
group0 = LOCAL\DefaultAllGroup
group1 = Domain Users
group2 = Administrators
group3 = Domain Admins
2010-08-12 16:57:10,726 INFO [http-0.0.0.0-9832-3] ProvisionInfoRequest| USER getUser() : Scot
2010-08-12 16:57:11,054 INFO [http-0.0.0.0-9832-3] ProvisionInfoRequest| RQ dispatch time: 343 ms
2010-08-12 16:57:12,086 DEBUG [http-0.0.0.0-9832-3] ReqPrepopulateIconData| In getPrepopulateIconData
2010-08-12 16:57:12,133 DEBUG [http-0.0.0.0-9832-3] ReqPrepopulateIconData| In getPrepopulateIconData list size = 1
2010-08-12 16:57:12,133 DEBUG [http-0.0.0.0-9832-3] ReqPrepopulateIconData| icon = icon1101-ec45cbcb4477.ico
2010-08-12 16:57:12,133 DEBUG [http-0.0.0.0-9832-3] ReqPrepopulateIconData| Pid = ReplyPrepopulateIconData$PrepopulateIconData
Magic= 0x61707073
Protocol= -1
MsgId= 0xff
packageGuid= eabcd41d2f2a46318501a0337d91ff02
appGuid= 1e718ec3fe904994a5b12d8ec00262c7
serverParams= 1/1
iconSize= 362102
2010-08-12 16:57:12,133 DEBUG [http-0.0.0.0-9832-3] ReqPrepopulateIconData| getPrepopulateIconInfo: retVal= List,size=1
2010-08-12 16:57:12,148 INFO [http-0.0.0.0-9832-3] ReqPrepopulateIconData| RQ dispatch time: 62 ms
Conclusion
Hopefully you never need this article. If you do understanding where how the process works and where to go to get the appropriate information can go a long way towards getting the system up and running.