Profiling an AppServer

Posted by Rob Fitzpatrick on 05-Dec-2017 08:32

Windows Server 2012
OE 11.6.3 32-bit

I have an appserver that publishes a web service. I'm connected to the WSA with SoapUI to fire through a message. I'm trying to profile the code running in the appserver but I'm not getting any output. I feel like I'm missing something obvious; I'd appreciate a hand.

The AS runs on a Windows box. I'm doing configuration/start/stop via OEE. To enable profiling I've edited <asname> | Agent | General | Server startup parameters and added "-profile c:\temp\profiling\profile.cfg" to the list of parameters. Profile.cfg contains:


-FILENAME     c:\temp\profiling\profile_test.prof
-DESCRIPTION  "This is the description of my profiling test."
-LISTINGS     c:\temp\profiling\
-COVERAGE
-TRACE-FILTER "*"
-STATISTICS
-RAWDATA

I've looked at a bunch of different sources of info on profiling, of various vintages, and they don't all agree on the list of keyword names. In particular, it seems the file name param might be "-FILENAME" or "-OUTFILE"; I assume both work? (And of course some of the keywords are different from the corresponding PROFILER attributes...) I used basically the same config file on a CHUI client on Linux and it did give me profiling data.

I start the agent, run the program, and stop the agent. I don't get a .prof file or any debug listings. I don't see any errors in the server.log that would indicate a misspelled parameter or keyword name.

Is there some special incantation I need for appserver? Should I use the profiler system handle instead, and start it in the Activate procedure and stop/flush data in the Shutdown procedure?

All Replies

Posted by Peter Judge on 05-Dec-2017 11:47

-FILENAME  (or the PROFILER’s FILE-NAME attribute) is the profiler’s output file . It can be fulloy or relatively pathed; if the latter, it’s to the session’s working directory (start-in). -OUTFILE looks to be the same thing.

Do you see data written when you shut the agent down?

I’d recommend using the PROFILER handle and turning profiling on and off in the activate – this way you get more control or what is written and when (add the WRITE-DATA() calls to the deactivate procedure).

When using the PROFILER handle,  make sure you set the ENABLED property to TRUE first, then all of the options (file-name etc), and only then set PROFILING to true (starts measuring).

Posted by Peter Judge on 05-Dec-2017 12:29

-FILENAME  (or the PROFILER’s FILE-NAME attribute) is the profiler’s output file . It can be fulloy or relatively pathed; if the latter, it’s to the session’s working directory (start-in). -OUTFILE looks to be the same thing.
 
Do you see data written when you shut the agent down?
 
I’d recommend using the PROFILER handle and turning profiling on and off in the activate – this way you get more control or what is written and when (add the WRITE-DATA() calls to the deactivate procedure).
 
When using the PROFILER handle,  make sure you set the ENABLED property to TRUE first, then all of the options (file-name etc), and only then set PROFILING to true (starts measuring).
 
 

Posted by Rob Fitzpatrick on 05-Dec-2017 12:32

Thanks Peter.  With the config file above I don't get any output when I shut down the agent.  I don't understand why.  Looking at your slide deck from EMEA PUG I also see a "-PROFILING" keyword.  What does that do?  I've never used it.

This appserver doesn't have a deactivate procedure, although it does have a shutdown procedure.  Can I add the code there to disable profiling and flush data?

Posted by Peter Judge on 05-Dec-2017 12:42

I *think* that will turn the feature on.

The reason why I suggest activate/deactivate is that otherwise you will be profiling all requests in that session (or all sessions) which will produce a lot of data.

Posted by Rob Fitzpatrick on 05-Dec-2017 12:53

In this case it's a dev environment and it's one agent handling one request at a time, so I guess I can handle profiling everything.  The only caveat is that the first request after the agent starts is always slow (I assume because it hasn't cached schema, r-code, etc.) and then the subsequent queries are faster.  

The challenge because of this is that I'd like to profile the *second* request/response, so maybe doing it programmatically is the way to go.  I've thought about maybe creating a flag file that the agent can read and using that as a toggle to enable profiling.  In other words, start the agent, send a message (which I don't want to profile), consume the response, create the flag file, send another message (which is profiled), stop the agent and flush the data.

This programmatic approach is better I think than using -profile in this case, but I'd still like to understand why it isn't working.  

Also, re "-profiling" in the config file, it seems redundant.  I think the fact that I'm specifying "-profile <cfg file>" on the command line should turn the feature on.

Posted by Rob Fitzpatrick on 06-Dec-2017 14:30

I'm looking at profiling data in PDSOE and in some cases there isn't agreement on the total time spent in a module, between the Module Details tab and the Call Tree tab.  I can't tell whether it's a PDSOE bug or not.

Is there a document that describes the layout of the profiling output file?  

Posted by Peter Judge on 06-Dec-2017 14:40

There are bugs in the call tree view IIRC (I’ve seen issues with the parent modules in particular).
 
I’ve read (somewhat recently) a doc on the format of the output file, but I can’t remember if that was a published doc or not. I’ll  take a look for it.
 

Posted by Rob Fitzpatrick on 06-Dec-2017 14:44

Thanks, it's good to know at least which one I should believe when they don't agree.

Posted by Peter Judge on 06-Dec-2017 14:48

The underlying data is the same (the .proffile), so trust that.

Posted by Rob Fitzpatrick on 06-Dec-2017 14:57

> The underlying data is the same (the .proffile), so trust that.

That's why I was looking for a doc to ensure I'm interpreting the data correctly.  ;)

I did try to match up some of my caller-callee pairs in the UI and compare it back to the data.  Given my 4 GB+ .prof file it's a bit of a chore.

This thread is closed