OGo has quite a lot of profiling capabilities

WOStats

In case someone is interested ... profiling information for OGo is exported using the "WOStats" direct action, eg:
http://developer.opengroupware.org/OpenGroupware/x/WOStats
it returnes an XML document (styled to a table on Internet Explorer 5+) which contains extremely useful information after an OGo instance is run "warm". Eg which components are called in which frequency, how many of them were compressed using gzip, which component did what traffic etc.

Echo

On a similiar note, you can use the URL
http://developer.opengroupware.org/OpenGroupware/x/echo
... to find out about your current browser. Especially interesting is the WEClientCapabilties key in the user info which shows how OGo detects your browser (eg in my case it prints "cpu=ppc fast-tbl css1 css2 js vb" which tells us that my browser is pretty fast at rendering deeply nested tables [which NS4 wasn't], supports CSS, JavaScript and Visual Basic [which is probably a bug, since IE Mac AFAIK doesn't allow VB ...]).

Access Logs

Well, and finally the stdout OGo logfiles also carry information on OGo resource usage. For example:

---
groove.in.skyrix.com - - [12/Oct/2003:00:14:04 GMT] \
"GET /OGo HTTP/1.1" 200 3671 0.917 - - 2M
---

Note: output is wrapped using "\" for this document. Interesting are the last numbers:

Again, quite useful to find out, where your OGo produces high memory or processing overhead. To gain information on the decision made whether a response is zipped, use the "-WODebugZipResponse YES" default.

Commands

All the functionality of OGo is implemented in terms of so called "command objects" which are Objective-C objects that run some part of the OGo business logic.
So if you have a request which is a bit slow and you want to know which part of Logic causes that slowness, you can use the LSProfileCommands default.
Sample Output:

0.006s appointment::query
0.003s account::teams
0.008s appointment::query
0.008s job::get-executant-jobs

The output is properly nested. Eg in the above case we see two appointment queries taking 6ms and 8ms and a task query which takes up 8ms. The account::teams command is executed by the appointment::query command.

WOHttpAdaptor

The HTTP processing of SOPE can be profiled using WOProfileHttpAdaptor.

-WOProfileHttpAdaptor YES

This will give you logs like:

Jan 14 18:04:49 OpenGroupware [3294]: [httpperf]: decoding of request took 0.003s.
Jan 14 18:04:50 OpenGroupware [3294]: [httpperf]: dispatch of request took 1.425s.
Jan 14 18:04:50 OpenGroupware [3294]: [httpperf]: delivery of request took 0.005s.
Jan 14 18:04:50 OpenGroupware [3294]: WOHttpAdaptor: handling of request took 1.435s.

So it is a bit more detailed than the timing logged by the HTTP access log.

IMAP4 Implementation

You can also trace and profile the performance of the IMAP4 client implementation which is helpful in case your mailer configuration is too slow.

-ProfileImapEnabled YES
-ImapLogEnabled YES

This will give you logs like those:

[-[NGImap4Client _openConnection]] <openConnection> : \
time needed: 0.0153s
{}[-[NGImap4Client processCommand:withTag:withNotification:logText:]] \
<Send Command [list "" "INBOX.%"]> : time needed: 0.0407s
{}[-[NGImap4Client processCommand:withTag:withNotification:logText:]] \
<Send Command [status "INBOX" (messages recent unseen)]> : \
time needed: 0.0410s

Note: output is wrapped using "\" for this document.
The logged timings are the times required to fetch the data from the IMAP4 server and to wrap them into low-level objects (NGHashMap's). This data is still going to be parsed with the NGMime MIME parser, which also has quite some overhead.

One thing to look for is whether IMAP4 server side sorting is actually enabled, as this will give a major boost on larger folders:

{}[-[NGImap4Client ...:]] <Send Command [status "INBOX.GNUstep" \
(messages recent unseen)]> : time needed: 0.0412s
{}[-[NGImap4Client ...:]] <Send Command [UID SORT (REVERSE date) UTF-8 ALL]> : \
time needed: 0.0756s
{}[-[NGImap4Client ...:]] <Send Command [search]> : time needed: 0.0008s
{}[-[NGImap4Client ...:]] <Send Command [uid fetch 1003,7,970,...,998,999 \
(uid rfc822.header rfc822.size flags)]> : time needed: 0.1411s

Note: output is wrapped using "\" for this document.
As you can see the client issues a uid sort on the date and then fetches just the messages required.

NGObjWeb Templates

To find out which components or elements are responsible for page generation time, you can enable some NGObjWeb profiling defaults.
In short: "components" are stateful high-level page objects, like an address viewer or a project list while "elements" are stateless low-level page objects like a dynamic link or tab. Elements will ask their components if they need data (eg a list of mails to be displayed), which in turn may show up in their response generation time.

-WOProfileComponents YES

Will give you logs like that:

content: [SkyTableView appendToResponse:inContext:]: 0.000s
[SkyTableView appendToResponse:inContext:]: 0.117s
[SkyJobList appendToResponse:inContext:]: 0.163s
content: [LSWSkyrixFrame appendToResponse:inContext:]: 0.388s
[LSWSkyrixFrame appendToResponse:inContext:]: 1.180s
prof[SkyNews appendToResponse:inContext:]: 1.199s

The "content" section is actually a WOComponentContent element, that is, the content of a "container" component (eg the LSWSkyrixFrame is put around the whole page content and renders the navigation etc itself but has the actual page as its "content").
Also note: the timing is always logged after everything was rendered, so the the stuff listed above an entry are actually subitems (eg in the example SkyTableView is called by SkyJobList)

-WOProfileElements YES

This is the most detailed page log. Since dynamic elements very very seldom have a higher overhead than 1ms or something, timings are quite inaccurate. What you should mostly look for are any timings which are way higher - eg 100ms. This usually signals a place which triggers some action (like fetching data) in the associated component. Actually this happens a lot in OGo, since most fetches are implemented as lazy fetches (fetch when needed, then cache).

Logs look like this:

Child of 0x0877114C: i[3] 0024005891508740704.3 <_WOResourceImage>: 0.001s
Child of 0x0877114C: i[5] 0024005891508740704.5 <_WOResourceImage>: 0.001s
Child of 0x0877114C: i[7] 0024005891508740704.7 <_WOResourceImage>: 0.001s
Child of 0x0877114C: i[9] 0024005891508740704.9 <_WOResourceImage>: 0.001s
Child of 0x0877114C: i[11] 0024005891508740704.11 <WOConditional>: 0.009s
CompoundElem0x0876C064(#2) 0024005891508740704.13.1.1.5 (component=Main): 0.000s
CompoundElem0x0876CFDC(#2) 0024005891508740704.13.1.1.9 (component=Main): 0.000s
CompoundElem0x087701D4(#19) 0024005891508740704.13.1.1 (component=Main): 0.001s
Child of 0x0877052C: i[1] 0024005891508740704.13.1.1 <WOForm>: 0.001s
CompoundElem0x0877052C(#3) 0024005891508740704.13.1 (component=Main): 0.002s
Child of 0x0877114C: i[13] 0024005891508740704.13 <WOConditional>: 0.002s
Child of 0x0877114C: i[15] 0024005891508740704.15 <_WOResourceImage>: 0.001s
CompoundElem0x0877114C(#27) 0024005891508740704 (component=Main): 0.017s
Template 0024005891508740704 (comp Main): 0.018s

This is actually the log of the main page (which is an extremely simple one - logs for a regular OGo page will be way more). As mentioned, a log which shows 0.001s is likely to be incorrect and mostly due to logging overhead (eg I guess the actually template generation time is more like 9ms for this example).
Anyway, the compound elements are generic containers generated automatically by the template parser. WOResourceImage is for the various images on the Main page.
As you can see, most time is spend in "WOConditional" - 9ms. I didn't check, but I guess this is where the Main page checks whether the PostgreSQL connection works (the conditional will ask the Main component whether it should generate its subcomponents, which in turn will check whether the DB connection is up - vola, 9ms spend ;-)