TCA=mod_sm22.cpp:8327ms

[SamatBoA]

We have a customer complaining about latency when running load tests.  He is sending us log snippets from his webserver showing what he considers the issue.  What is the time that is returned?  Is it the start to end time for the siteminder module to complete its work?  I can't find any docs on exactly what that time means.  And obviously if it is taking 8.327 seconds to go through SiteMinder, that's a problem...

 

some-ip some-ip - - [30/Aug/2016:04:26:48 -0400] "GET /servletsso/servlet/ssoservlet HTTP/1.1" 302 - 8330714 "-" "Mozilla/5.0 (Windows NT 6.1; Trident/7.0; rv:11.0) like Gecko" "-" "-" "-" TCA=mod_sm22.cpp:8327ms TRH=mod_was_ap22_http.c:2ms 

 

 

[Hongxu Liu]

Hi Sam,

 

TCA=Check_user_access, this is not SSO agent log setting.

It is Apache's diagnostic report.

There could be many reasons or factors for performance slowness during a load test.

What listed only demonstrates that particular apache server may be under stress at the time.

What needs to be looked at is overall performance from front end to back end, and measure performance for every component, then you will know what is normal, what is not. 

 

Even a well tuned apache server may not take 1 mil/sec hit traffic load.

 

I would suggest to run diagnosis tool following the below community link, and identify the bottle neck and adjust them accordingly. The tool will provide better measurement on user auth and az time, which is much more meaningful. Performance tuning is best done by CA services if additional help is required.

 

https://communities.ca.com/thread/97562407

 

Thanks

Hongxu

[SamatBoA]

Thank Hongxu.  But in this case, I'm really just looking for someone to explain what that value is that is returned in the log.  It has to mean something.  Is it being calculated from within the mod_sm22 code itself or is it coming from Apache as the amount of time spent in that module?  And is there any documentation on what that module is actually doing?

 

Sam

[Sandra Green]

Hi Sam,

 

Unfortunately we have no documentation on what that value means.  As Hongxu mentioned, it would be best to gather a log set (policy server trace and web trace) and run them through the Policy Server Trace Analayis Tool.

 

Optionally you can open a case and we can dig into deeper.

 

Sandy

[SamatBoA]

Thanks.  Yes I already opened a case and received my answer.  I will close this one out.

[Stephen McQuiggan]

Sam,

 

Reporting the request spent 8 seconds in the apache SSO module mod_sm22.spp:8327ms

Next step is to open issue provide WebAgent trace logs, may also want to turn on apache logging

Apache LogFormat (http://httpd.apache.org/docs/current/mod/mod_log_config.html)

%P – process

%p – port

%h - Remote host

%t - Time the request was received

%T – Time to serve request in seconds

%D – Time to serve request in Microseconds

%I - Remote logname

%u – Remote User

%r First line of request

%s status

%b size of request

Also logging SiteMinder transactionID

 

LogFormat "%P %p %h %t %T %D %l %u \"%r\" %>s %b \"%{Referer}i\" \"%{SM_TRANSACTIONID}i\"" combined

CustomLog logs/acces_log combined

[SamatBoA]

Thanks Steve.  We're good now anyway.  After claiming that "nothing changed", we were advised this morning that the testing team running the load test had changed the max load to something totally unrealistic, especially for a non-prod environment.  And they didn't bother to let our customer know that little gem... 

 

So after reverting to a common sense max load, there was no problem.

 

But thanks for the response.  I thought that was the answer but was just verifying.

 

Sam