[sip-comm-dev] Some notes about usage of logging


#1

Dear all,

in my ongoing efforts to reduce the resource usage of SC I did some more
measurements and did some enhancements based on the results.

I used a SC configuration with one active account (iptel), no contacts,
some call history. Then I monitored memory usage and object creation activities,
this time concentrating on SIP et al.

During SIP activities (request/response) I saw quite a lot of logging actions
and monitored these. It turned out that about 25% of all memory usage and
object allocations of SIP request/response processing are due to logging
(REGISTER request/responses only) activities.

Even changing the log level did not change this (setting to .SEVERE instead
of .FINE in logging.properties). This was due to the fact that many, and
in SipLogger.java none at all, logger message functions are not "protected".
Thus the message string is created and handed to logger. Then the logger
discards the string because the log level is higher than for example
INFO or TRACE.

The set-up of a logger message can be quite complex, depending which class
is converted with ".toString()" as part of a loggin message (for SIP
requests/responses objects this is a lot of work).

One SIP REGISTER request/response pair required about 250KB memory and about
2100 object allocation if used with logging. The numbers for the same
request pair without logging: ~150KB and ~1500 allocations. According to
the SC configuration (and Wireshark monitoring) we have 4 such pair per
minute, thus this saves about 400KB and 2400 object allocations per minute
and reduces CPU usage.

I'll check-in some SIP protocol files where I added the "protection" to
logger INFO, DEBUG, and TRACE message functions. ERROR and WARNING are
not protected. I would ask all developers to enhance their code in the same
way. This could save quite some resources if the logging.properties file
sets the log level so WARING or higher.

Regards,
Werner

···

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net


#2

Hey Werner,

На 28.05.10 14:19, Werner Dittmann написа:

Dear all,

in my ongoing efforts to reduce the resource usage of SC I did some more
measurements and did some enhancements based on the results.

I used a SC configuration with one active account (iptel), no contacts,
some call history. Then I monitored memory usage and object creation activities,
this time concentrating on SIP et al.

During SIP activities (request/response) I saw quite a lot of logging actions
and monitored these. It turned out that about 25% of all memory usage and
object allocations of SIP request/response processing are due to logging
(REGISTER request/responses only) activities.

Even changing the log level did not change this (setting to .SEVERE instead
of .FINE in logging.properties). This was due to the fact that many, and
in SipLogger.java none at all, logger message functions are not "protected".
Thus the message string is created and handed to logger. Then the logger
discards the string because the log level is higher than for example
INFO or TRACE.

The set-up of a logger message can be quite complex, depending which class
is converted with ".toString()" as part of a loggin message (for SIP
requests/responses objects this is a lot of work).

One SIP REGISTER request/response pair required about 250KB memory and about
2100 object allocation if used with logging. The numbers for the same
request pair without logging: ~150KB and ~1500 allocations. According to
the SC configuration (and Wireshark monitoring) we have 4 such pair per
minute, thus this saves about 400KB and 2400 object allocations per minute
and reduces CPU usage.

I'll check-in some SIP protocol files where I added the "protection" to
logger INFO, DEBUG, and TRACE message functions. ERROR and WARNING are
not protected. I would ask all developers to enhance their code in the same
way. This could save quite some resources if the logging.properties file
sets the log level so WARING or higher.

Way to go! Thanks for taking care of this!

Emil

···

Regards,
Werner

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net