Okay,
I'll admit it openly to the SCN community. I'm a geek. On Christmas Morning,
instead of making a real fire in my real wood-burning fireplace, I will instead
search around and find one of many channels on the television that show hours
of footage of the Yule Log and accompanying beautiful Christmas music. It's so
much easier to apply technology to solve the problem than to build an actual
fire. And my fireplace doesn't play music. But I digress.
The
other type of logs that I want to give some holiday cheer to are
BusinessObjects Enterprise trace logs. They may make many shudder and cringe,
but I learned a few things about these logs recently and think the community
could definitely benefit.
Why
use Trace Logs?
I
will apologize up front if you use other reporting tools, but I presently work
for a Webi only shop, so focus of this will be on WebIntelligence. The
information holds for other tools/services, but individual results may vary.
As
a BusinessObjects Administrator, I often get asked why reports are "so
slow". It takes some effort to describe the internal processes of BOE to
developers, managers, and other lay people. How the report request moves from
the web browser, to the BOE server, how it is processed, and how long each step
takes. I won't cover this in detail here, but know that this information is a
part of what used to be called the BusinessObjects Certified Professional
certification, and is now called SAP Certified Application Associate for
BOE. At a high level, here is what
happens:
- User logs in to InfoView and clicks on a report
- If there are prompts, the
prompt window is returned with it's List of Values
- User will select prompts, and
click Run Query
- The query will be generated,
and passed to the source Database
- Data will be returned to the
Webi report
- The report will be rendered
- The report will be 'painted'
on the user's screen
While
you can use a web based tool such as HTTPWatch to see what is going on in your
browser window, you will miss much of the behind-the-scenes processing
information. That detail is available in the Trace Logs.
Enabling
trace turns on verbose logging on your server of choice. This means that every action taken by the
server (service) is written to a log file. As you can imagine, there is a
definite cost to performance for turning trace on. You also need to watch your
disk space, since these files can grow rapidly, and quickly eat up any free
space you might have. Cautions aside,
you can learn much from a carefully executed trace.
Before
you start, you create a test plan. It doesn't need to be intricate, but before
you start you should know what reports you want to investigate and what order
you are going to run them in. You should also, if possible, run this test with
no other users on the system. This will help keep extra clutter out of your
trace logs and make them easier to analyze. One final recommendation I would
make is that if you run multiple Webi servers (like I do) shut all of them down
except one. This way you know for sure which one is handling your request, and
also cuts down on the clutter in the logs.
How
to Enable Trace
In
BusinessObjects XI r2, trace is merely a factor of On or Off. In Windows, you open the CCM tool and edit
the startup string for the server adding the '-trace' switch, and restart the
server. In Non-Windows (Linux or UNIX), you edit the ccm.config file, add the
'-trace' switch and restart the server using ccm.sh.
The
log files will go to the default logging folder.
In XI 3.x you have more options. You can set the level of verbosity you want
trace to use, and you can specify a target folder for the logs to be placed in
overriding the default.
To
set up trace in XI 3.x, first you must create an .ini file. Open up your favorite text editor, and create
a new file with the following values:
active
= true;
importance
= xs;
alert
= true;
severity
= 'E';
keep
= true;
size
= 100 * 1000;
//
Specify your target folder in this line, default_ /BusinessObjects
Enterprise 12.0/logging on WIN32 and /bobje/logging
on UNIX//log_dir="C:/Temp";
example for WINDOWS
//log_dir="/var/logs";
example for UNIX
You
can choose your level of verbosity in the file by changing the value of the
"importance=" tag.
You
have the following verbosity options to choose from:
xs
or '<<' Lowest level (most
verbose option). All details.
s
or '<=' Low level: at/or above the
low level.
m
or '==' Normal level: at/or above the
normal level.
l
or '>=' High level: at/or above
the high level.
xl
or '>>' Highest level (least
verbose option). Highest level.
Save
the file with the following name and extension based on your OS:
WIReportServer_Trace.ini
(On Windows)
WIReportServer.bin_trace.ini
(On UNIX)
And
then place your file where the monitored process resides.
On
Windows:
…\BusinessObjects
Enteprise 12.0\win32_86
On
UNIX:
[BusinessObjects install folder]\bobje
And
one final configuration change. Edit the file in
\BusinessObjects Enterprise
12.0platform]\dataAccess\connectionServer\cs.cfgEach traced activity
will have an tag where the operation starts, and an tag where it
completed along with a duration. The duration timestamp goes down to the
nanosecond.Here is my test
report again, and the entry for how long it took this report to be retrieved
from the FRS:
[Fri Dec 10 19:39:06 2010] 6895 92 trace message: TraceLog: dg_srm_storeWIQT:RetrieveFromRepo: 0.734Note this is the
entry, and RetrieveFromRepo is the keyword, and the task took 0.734
seconds.Keep walking through
your log and you will see the logical progression of the report generation as
described earlier. The SQL statement will get generated, and you will even see
the SQL Statement before and after the refresh in the log files. You will find the tag for the refresh,
so you know how long it took BOE to get the data from your database:
[Fri Dec 10 19:42:47 2010] 6895 92 trace message: TraceLog: C3_RefreshInfo:refresh_info::stream::Refresh: 3:38.882Mine took 3 minutes,
38.882 seconds
Another important
piece is how long it took to render the page. Applying fonts, determining how
many pages, page breaks, formatting, etc. all takes some time:
[Fri Dec 10 19:43:43 2010] 6895 108 trace message: TraceLog: repeng:RERender::Render: 40.597My report took
40.597 seconds to render.
Summary
There is much, much
more detail in the trace logs for you to discover. Take your time and go
through them and you can see all of the different pieces involved between that
user request for the report, and the finished product being displayed on the
screen. Keep in mind that many operations happen simultaneously, so keep your eye on the timestamp so you don't get lost in the flood of information. Use your contemporaneous log from the test run to keep track of where you are in the test process, and you'll be amazed at what you start learning about your BOE system and where it spends its time.
Hope you find this
useful, and that your Holidays will be filled with many happy Logs!
