Hack 80. Monitor Attachment Usage

Determine how heavily your users are accessing the Attachment Service.

Attachment reading with the BlackBerry is a very useful feature of the BlackBerry Enterprise Server. Having the ability to read the contents of attachments comes in very handy when you don't have access to a desktop computer with office productivity software installed.

This power comes at a price the BlackBerry Attachment Service is a resource-intensive beast that requires a sizeable amount of system resources to work effectively. As a BlackBerry administrator, it is a good idea to keep track of Attachment Service usage over time. As more and more of your users discover the functionality, your hardware requirements might change and you may want to upgrade the server or move the service to its own dedicated hardware [Hack #79].

7.10.1. Turn On Attachment Service Logging

Attachment logging is disabled by default in both BlackBerry Enterprise Server 3.6 and 4.0. You can enable it by logging onto your BlackBerry Enterprise Server and going to Start Programs BlackBerry Enterprise Server Attachment Service Configuration Tool. Click on the Connector Configuration node on the left size of the dialog box. As shown in Figure 7-14, enable the Extended Logging feature and click Apply. After setting to Enabled, youll be prompted with a dialog box that indicates you will need to stop and start the BlackBerry Service for the setting to take effect.

In Version 4.0, use the BlackBerry Server Configuration Tool to set the Debug Log Level to 5 for the BlackBerry Attachment Service and BlackBerry Attachment Conversion. Due to a bug in the current version of 4.0, you'll also need to modify the registry to enable the level of logging required to see the attachment names in the debug logs. Set HKLM\Software\Research In Motion\ BBAttachServer\BBAttachBESExtension\BBAttachEnableExtensionLog to 1, set HKLM\Software\Research In Motion\BBAttachServer\BBAttachBESExtension\ BBAttachServerLogLevel to 5, and then set HKLM\System\CurrentControlSet\Services\BBAttachServer\Parameters\EnableLog to 5.

Figure 7-14. Enabling Extended Logging in 3.6

7.10.2. Debug Log Entries

Attachment Service usage gets logged to the standard debug log on the BlackBerry Enterprise Server that the reader's device is homed on. A typical set of log entries for BES 3.6 that occur when someone reads an attachment is as follows:

 [40000] (04/13 10:56:10):{0x3DC} TransID=1241871075, AttachmentTempFileName=C:\ DOCUME~1\bessvc2\LOCALS~1\Temp\bes38, Attachment data successfully retrieved, Success=0x0000000C [40000] (04/13 10:56:10):{0x3DC} TransID=1241871075, Entering the _ ConvertAttachment method attachment=sales presentation.ppt, Success=0x00000002 [40000] (04/13 10:56:10):{0x3DC} TransID=1241871075, ([e-mail]) Operation completed successfully - Attachment=sales presentation.ppt, Success=0x00000000 [40000] (04/13 10:56:10):{0x3DC} TransID=1241871075, Leaving the _ ConvertAttachment method attachment=sales presentation.ppt, Success=0x00000004 [40000] (04/13 10:56:10):{0x3DC} TransID=1241871075, Atomic attachment conversion request completed successfully attachment=sales presentation.ppt, Success=0x00000005 [40000] (04/13 10:56:10):{0x3DC} TransID=1241871075, Leaving the ExtendedMoreRequest2 method, Success=0x00000001 [30328] (04/13 10:56:10):{0x3DC} {[e-mail]} The extension returned MORE_COMPLETE, for the Extended More Request, for transid 1241871075. [40439] (04/13 10:56:10):{0x3DC} {[e-mail]} Actual MORE data available, size=2783, Tag=2113806225, TransactionId=1241871075 [40298] (04/13 10:56:10):{0x3DC} {[e-mail]} Sending MORE to device, RefId=-712861129, PartId=0, Offset=0, Length=3000 [40140] (04/13 10:56:10):{0x3DC} Encrypting using key ID 0B2746A34+G+i [40583] (04/13 10:56:10):{0x3DC} {[e-mail]} Sending message to device, Size=1503, Tag=366484, TransactionId=-1065991950 [40279] (04/1310:56:10):{0x3DC} {[e-mail]} SubmitToRelaySendQ, Tag=366484 [40279] (04/1310:56:10):{0x3DC} {[e-mail]} SubmitToRelaySendQ, Tag=2113806225 [40000] (04/13 10:56:10):{0xAC0} [SRP] Send data, Tag=366484 [40000] (04/13 10:56:10):{0xAC0} [SRP] Send status DATA_ACCEPTED, Tag=2113806225 

BlackBerry Enterprise Server Version 4.0 and greater has a different format for the attachment viewing in its debug log. You'll find the entries in the *_MAGT_* logfiles. Despite the difference in formatting, the code in this hack will work for a 4.0 log or a 3.6 log.

The previous excerpt shows that a user ([e-mail]) performed an attachment read on a Microsoft PowerPoint file named sales presentation.ppt. You can use a Perl script to go through the file looking for lines similar to this:

 [40000] (04/1310:56:10):{0x3DC} TransID=1241871075, ([e-mail]) Operation completed successfully - Attachment=sales presentation.ppt, Success=0x00000000 

When you read an attachment from a BlackBerry, you don't retrieve the entire contents of it all at once. Similar to reading a long email message, your device retrieves the first section (actually the first few bytes) of the attachment and places it in a buffer. When you approach the end of the buffer, your device then retrieves the next section of the attachment and puts it into the buffer. This process happens fairly quickly, so it's possible you may not even realize the whole attachment isn't retrieved at once at the beginning.

This also means that every time a device retrieves "more" of the attachment, another line gets logged to the file similar to the previous line. You'll need to account for this in the code so that you don't count these "more retrievals" as additional attachment reads.

7.10.3. The Code

 use strict; my $file = "path to debug log"; my $attachments = {}; my %refids = (); open FILE, $file; while (<FILE>) { chomp; my ($idtext,undef) = split / /; my $id = substr $idtext, 1, 5; if ($id == 40182) { my ($refid) = (/{(0x[^}]{3,4})}/); my ($email) = (/} {([^@]+@[^}]+)}/); $refids{$refid} = $email; } if ($id == 40000 and / Operation completed successfully - Attachment=/) { # 3.6 log my ($email) = (/[{\(]([^\({\@]+\@[^}\)]+)[}\)]/); my ($filename) = (/\)\sOperation\scompleted \ssuccessfully\s-\sAttachment=(.+),\sSuccess=/x); my $timestamp = substr $_, 9, 14; if ($attachments->{$email}->{$filename}) { $attachments->{$email}->{$filename}->{endtime} = $timestamp; } else { $attachments->{$email}->{$filename}->{starttime} = $timestamp; } } if ($id == 30000 and /, Attachment=([^,]+), Attachment conversion/) { # 4.0 log my $filename = $1; my ($refid) = (/{(0x[^}]{3,4})}/); my $email = $refids{$refid}; my $timestamp = substr $_, 9, 14; if ($attachments->{$email}->{$filename}) { $attachments->{$email}->{$filename}->{endtime} = $timestamp; } else { $attachments->{$email}->{$filename}->{starttime} = $timestamp; } } } foreach my $email (keys %{ $attachments }) {    foreach my $attachment (keys %{ $attachments->{$email} }) {   my $start_time = $$attachments{$email}{$attachment}{starttime};   my $end_time = $$attachments{$email}{$attachment}{endtime};   print "$email\t$attachment\t$start_time\t$end_time\n";    } } 

7.10.4. Run the Code

Save the previous code in a text file called bbattach.pl and run the following command from a command prompt.

 C:>perl bbattach.pl 

Running the code will produce output similar to the following:

 [e-mail] sales presentation.ppt 04/13 10:56:10 04/13 10:59:10 

It parses your debug log and tracks the first and last read times of attachments read by your users. In the previous example, user [e-mail] started reading an attachment called sales presentation.ppt at 10:56 A.M., and the last retrieval of data occurred at 10:59 A.M.