Overview of Client Trace for Enterprise Vault Client

Posted by: RKirc on Dec 21, 2009

Tagged in: Untagged

This article is aimed at assisting and understanding what is in a client trace, which is a log capture from an Enterprise Vault Client PC/Laptop that has had this client deployed to. The client installation used is Enterprise Vault 8 base in this article, though most of what this document explains is relevant for most client versions all the way back to Enterprise Vault 7 and older.

The technote referenced in the link below, contains information on how to perform a client trace. This is used to perform troubleshooting of a great many client issues, from restoring data to client driven migrations.

http://support.veritas.com/docs/276094

All client traces are kept in the users temporary file location. The simplest way to access this is go to startrun and type %temp% and select OK. It is useful to know old client traces are also stored here.

So let’s look at some of the more important entries in a client trace. When you open a client trace one of the first lines is the logging level.

03/08/2009 13:16:39.810[1764]: Log file created (level 3)

For troubleshooting, this should be set to maximum, which is 3 (Shown as four when opening the Enterprise Vault Diagnostics window, holding shift and CTRL, and selecting an Enterprise Vault button). Altering this value actually alters the registry in HKLMSoftwareKVSEnterpriseVaultClient and is a DWORD value named LoggingLevel. This can also be changed from 0 to 3 manually (Hence the four levels) here to change the logging level in registry as per below.

3 = Maximum Tracing

2=Minimum Tracing

1=Information

0=Errors Only

Who the client trace is being logged for the associated mailbox is also shown as below.

03/08/2009 13:16:39.874[1764]: Name: Mailbox - Robert Hanson

If PST’s are enabled to be marked.

03/08/2009 13:16:40.206[1764]:     Desktop Setting: MARKPSTS
03/08/2009 13:16:40.207[1764]:     Value: 1

The following information is also shown under environment. Note the section in brackets showing that the client being used is HTTP. In older versions this would say full or lite for DCOM or HTTP respectively. More on this later in the article.

03/08/2009 13:16:40.241[1764]: Environment:
03/08/2009 13:16:40.241[1764]:     Enterprise Vault Client 8.0.0.1404.0 (HTTP)
03/08/2009 13:16:40.242[1764]:     Microsoft Windows XP Professional Service Pack 2 (Build 2600)
03/08/2009 13:16:40.243[1764]: Intel(R) Xeon(TM) CPU 3.00GHz x86 Family 15 Model 4 Stepping 10;
03/08/2009 13:16:40.243[1764]:     Microsoft Outlook 2007
03/08/2009 13:16:40.243[1764]: CDesktop::GetOLConnectionState: 0x0
03/08/2009 13:16:40.244[1764]:     Outlook Exchange Connection Mode: 1
03/08/2009 13:16:40.244[1764]: ~CDesktop::GetOLConnectionState: 0x0
03/08/2009 13:16:40.244[1764]:         [Exchange connection mode: Online (1)]
03/08/2009 13:16:40.245[1764]: DesktopCommon::UseRPCOverHTTP: 0x0
03/08/2009 13:16:40.245[1764]: ~DesktopCommon::UseRPCOverHTTP: 0x0
03/08/2009 13:16:40.246[1764]:         [RPC over HTTP not enabled]
03/08/2009 13:16:40.246[1764]:     Microsoft Internet Explorer 6.0.2900.2180

Most of the above is self explanatory. The most useful aspect is the Connection State which in turn can affect how Enterprise Vault behaves. An example of the most common connection states are below.

olOnline = 1,
olOffline = 2,
olNoExchange = 3,
olCachedOffline = 5,
olDisconnected = 4,
olCachedDisconnected = 6,
olCachedConnectedHeaders = 7,
olCachedConnectedFull = 8,
olCachedConnectedDrizzle = 9

Next you have your trusted Zones. These are added in via policy and if set incorrectly will affect HTTP requests behavior. Best policy is to have both the NetBios and FQDN of all Enterprise Vault Servers added.

Intranet Zone Trusted Sites:

Test-ev.ev8.local

VaultSrv1.ev7.local

http://Test-ev

Test-ev

http://vault

Next you can see Desktop Settings, now I will not list out each and every setting, but basically you will see entries like.

Contents of Desktop Settings:

03/08/2009 13:16:40.253[1764]: ARCHIVEEXPLORERBTNVISIBLE = 1

This means the policy is set to show Archive Explorer button.

03/08/2009 13:16:40.256[1764]:     DELETEBTNVISIBLE = 0

This means that the delete button is not visible.

Some of the options are more than just on or off, display or not. These options may then have a number 2 for example.

An important entry to make a note of is the defaultwebappurl. If this is incorrect then a whole host of features will not work from the client. Basically all HTTP requests internally will go via this URL so it is important.

03/08/2009 13:16:40.256[1764]:     DEFAULTWEBAPPURL = http://VaultSrv1.ev7.local/EnterpriseVault

The other is using Outlook Web Access, especially with Exchange 2007. This is the URL that Outlook Web Access will use to access Archive Explorer and Search. There is a great PDF document on configuring this in full.

03/08/2009 13:16:40.260[1764]:     EXTERNALWEBAPPURL = https://Test-Symantec.local/EnterpriseVault

All registry settings and paths are listed under the setting below. Useful to see all registry locations for the Enterprise Vault Client.

Registry Settings:

The next setting is for offline vault which contains settings and includes the path used for Offline VaultVault Cache.

One important line you will see is below is commonly seen in a client trace.

03/08/2009 13:16:40.572[1644]: Attempting connection to (http://VaultSrv1.ev7.local/EnterpriseVault/clienttest.gif)...

What this is a test to see if you are internal or external and a connection can be established.

If the connection is successful you will the below, returned from IIS on the Enterprise Vault Server.

03/08/2009 13:16:40.658[1644]: Connected - Returned status code(200)
03/08/2009 13:16:40.659[1644]: Internet connection state = 1 (flags = 18)
03/08/2009 13:16:40.659[1644]: ~DesktopCommonUtil::HasInternetConnection: 0x0
03/08/2009 13:16:40.660[1644]: Successfully contacted the EV web server using: http://VaultSrv1.ev7.local/EnterpriseVault

If this is not successful and you are using RPC/HTTPS and have set this as a policy, you will the external URL being used and hopefully successfully connecting to the EV Server, on that attempt. If this is not configured or is unsuccessful then the ability to recall, archive items is probably going to be unsuccessful as there is a connection issue.

On the line below and others for the different FDM files, you will the forms being loaded, to display icons from Enterprise Vault in Outlook.

03/08/2009 13:16:40.798[ 596]: Successfully loaded form file: C:Program FilesEnterprise VaultEVClientLanguagesFormsenEVPendingArchive.fdm

Next you will see the client driven migration entries. However there is already a great article on this written by Paul Grimshaw and I would recommend referring to this.

Now we will move onto a few basic operations.

The following was taken from Outlook 2007 in cached mode with the Enterprise Vault 8 Client installed (HTTP) and is an archive request for a new item. There are additional entries, too many but these I consider a few of the most important. We can see the item being marked and the request being made to the Enterprise Vault Server.

08/08/2009 21:06:40.238[5936]: CItemMarker::MarkArchiveMe: 0x0
08/08/2009 21:06:40.240[5936]:     Marking for archive: 08/08/2009 21:06:40.238[5936]: CItemMarker::MarkArchiveMe: 0x0
08/08/2009 21:06:40.240[5936]:     Marking for archive: This is a test
08/08/2009 21:06:41.369[5936]: Sending HTTP request: http://vltsrv06.enterprise.veritas.com/EnterpriseV...
08/08/2009 21:06:41.374[5936]: ~DesktopCommon::GetClientActionURL: 0x0

Here we see a restore of an archived item, by selecting the restore now button. Much like the archive request we see the item being marked and a request being made to the Enterprise Vault Server.

08/08/2009 21:25:23.391[5936]: CItemMarker::MarkRestoreMe: 0x0
08/08/2009 21:25:23.392[5936]:     Marking for restore: This is a Test
08/08/2009 21:25:23.461[5936]: Sending HTTP request: http://vltsrv06.enterprise.veritas.com/EnterpriseVault/clientaction.asp?act=4&fdrenc=SQBuAGIAbwB4AA==&dn=/O=Enterprise/OU=MDH/cn=Recipients/cn=user25385593&svr=DUB1XCHEVSPIN01&sid=12E27B397FB7CBA4CB24F2E45473CBBE11d10000EVGlobal1&tsp=2009-08-08T21:25:24&pdl=AAAAAAAAIIFNEBECGNDBPIEILHPNKHIEIBEGMEAKABAANNLHOGPMAPHKPPEPKKEKDDIPCCNDNFFNAAAAAACIHDOOAAAA

Here we see an archived message being opened by double clicking the message. Note the ASP used for this operation is download.asp, not clientaction.asp.

09/08/2009 16:44:23.435[5564]: ~CDesktop::LoadSettingsFromHiddenMessage: 0x0
09/08/2009 16:44:23.436[5564]:     Desktop Setting: DefaultDoubleClickView
09/08/2009 16:44:23.436[5564]:     Value: 0
09/08/2009 16:44:23.437[5564]: ~CDesktop::GetSetting: 0x0
09/08/2009 16:44:23.438[5564]: ~CDesktop::get_Setting: 0x0
09/08/2009 16:44:23.438[5564]: Downloading from: http://vltsrv06.enterprise.veritas.com/EnterpriseVault/download.asp?VaultID=171492D9AF9669143A3A45518D6A5FFB81110000EVGlobal1&SaveSetID=200906190000000~200904161235120000~Z~50EDC76A9AA3C2EE08D47EF321B40621&FormatType=Unicode&Client=EV7.0.1.2002-Outlook12

Here we see a request made by double clicking on an archived item. Note the ASP used is different as this is using download.asp.

09/08/2009 16:44:23.435[5564]: ~CDesktop::LoadSettingsFromHiddenMessage: 0x0
09/08/2009 16:44:23.436[5564]:     Desktop Setting: DefaultDoubleClickView
09/08/2009 16:44:23.436[5564]:     Value: 0
09/08/2009 16:44:23.437[5564]: ~CDesktop::GetSetting: 0x0
09/08/2009 16:44:23.438[5564]: ~CDesktop::get_Setting: 0x0
09/08/2009 16:44:23.438[5564]: Downloading from: http://vltsrv06.enterprise.veritas.com/EnterpriseVault/download.asp?VaultID=171492D9AF9669143A3A45518D6A5FFB81110000EVGlobal1&SaveSetID=200906190000000~200904161235120000~Z~50EDC76A9AA3C2EE08D47EF321B40621&FormatType=Unicode&Client=EV7.0.1.2002-Outlook12

Of course there are many other calls that can be made such as opening Archive Explorer or search, deletes and so on, but the three shown are probably the most commonly used.

The best way to capture these is to set logging to full, note the last entry time and then perform the operation. Open the client trace again and review the new entries. Simple really. A good troubleshooting step is to capture from a working and then non-working machine and have a look for the differences. Can you spot any errors or failures. This will give you a great head start if you then have to log a call as you can supply this information.

Another is to look at the call made to the Enterprise Vault Server, and see if you can spot that entry in the IIS logs. You may see the entry with a 401 IIS code at the end and then a 200. This is normal, however if you see both with other codes such as 500, 403 etc then you will have an issue in IIS that requires troubleshooting. Remember a 200 entry is a success!!!

Also remember that the Enterprise Vault client is multi-threaded. In the examples above you can see a number in the brackets. Such as [5564]. This is the process thread and you need to follow this through, ignoring other entries for other processes etc whenever tracking an operation. As they will be jumbled up together.

It is worth mentioning that since Enterprise Vault version 8, the default protocol for the Enterprise Vault Client is HTTP not DCOM as in previous versions. This difference is that HTTP will use clientaction.asp to pass requests on and DCOM will use Valkyrie.dll on the client to access AgentClientBroker a DCOM server on the EV Server.

This concludes my article on a client trace.

Set as favorite

Bookmark

Email this

Comments (0) Add Comment

Subscribe to this comment's feed

Write comment

[ Back ]