Unwired Server Performance Counter Reference

This topic covers counters used in current logging and tracing done by Unwired Server.

The counters are by default logged in the log file <SUP_HOME>/logs/counters.log. This can be changed by modifying <SUP_HOME>/config/log4j.properties. The general format of counters is:

<timestamp>|<thread-id>|<counter-name>:<counter-specific-info>

Unwired Server generates a trace log message at specific points during processing, called counters. Some of the counters list time spent at various stages of activity. The counters logs can be post-processed to generate aggregate numbers also. The counters can be enabled or disabled in sup.properties. The property names are counter.<counter-name>, for example, counter.sync.time.

You enable counters in the sup.properties file. The following counters are most likely to be useful in troubleshooting:

sync.time: Complete synchronization. Note that this is the time spent inside the Unwired Server. The ML Server may add some overhead. This counter prints two lines. At the beginning of sync the following line is printed:
- sync.time:+:queue-size:remote-id
```
2009-04-13 20:09:40,234|Thread-52|sync.time:+:1:df28289b-2275-490b-9e0a-fd524d0ff47f
```
  At the beginning of a sync:
  - queue-size is the total number of sync requests in progress, including the current one.
- sync.time:-:queue-size:time-spent:record-count:char-count
```
2009-04-13 20:09:42,625|Thread-52|sync.time:-:0:2391:40:520
```
  At the end of the sync:
  - queue-size is the total number of sync requests in progress, excluding the current one.
  - time-spent is the time in milliseconds spent in processing the request.
  - record-count and char-count are approximate number of records and characters downloaded to the device respectively. Note that these numbers are inaccurate and are only good for comparison with other lines printed by the same counter.
sync.download: Writing data to download cursors. One line is printed:
- sync.download:time-spent:record-count:char-count
```
sync.download:31:40:520
```
handle.download.data: Download phase of MobiLink sync. Unwired Server in this phase does EIS interaction for MBOs (but not operations), CDB Update, and writes to download cursors. The counter prints several lines, but only three are relevant:
- handle_download_data:+
```
2009-04-13 20:09:40,328|Thread-52|handle_download_data:+
```
  Beginning of download phase.
- handle_download_data:m:free-memory
```
2009-04-13 20:09:40,328|Thread-52|handle_download_data:m:250642128
```
  Also at the beginning of download phase; free memory is in bytes.
- handle_download_data:-:time-spent
```
2009-04-13 20:09:42,578|Thread-52|handle_download_data:-:2250
```
uascripts.getPlaybackTree: Processing for each top level MBO request, includes EIS Interaction and CDB Update. Two lines are printed, one at the beginning and one at the end.
- uascripts.getPlaybackTree:+
```
2009-04-13 20:09:40,421|Thread-52|uascripts.getPlaybackTree:+
```
  Beginning of download phase.
- uascripts.getPlaybackTree:-:time-spent
```
2009-04-13 20:09:42,406|Thread-52|uascripts.getPlaybackTree:-:1985
```
push.init: Initializing data structures for push processing. Several lines are printed, but only the beginning and end lines are important.
push.process: Initializing data structures for push processing. Several lines are printed, but only the beginning and end lines are important

lock.wait: While a single property in the sup.properties file is provided, the counter names used are cdb_lock.read for reading cdb, playback_lock.write for doing a playback, and cdb_lock.write for updating cdb. Prints one line each when lock is requested and acquired.

2009-04-13 20:09:41,062|Thread-52|cdb_lock.read.wait:+
2009-04-13 20:09:41,062|Thread-52|cdb_lock.read.wait:-:0
2009-04-13 20:09:41,078|Thread-52|playback_lock.write.wait:+
2009-04-13 20:09:41,078|Thread-52|playback_lock.write.wait:-:0
2009-04-13 20:09:41,640|Thread-52|cdb_lock.write.wait:+
2009-04-13 20:09:41,640|Thread-52|cdb_lock.write.wait:-:0

lock.held: A single property listing the time for which the lock was held. A single line is printed when releasing the lock. The end of lock.wait is the beginning of lock.held.
```
2009-04-13 20:09:42,390|Thread-52|cdb_lock.held:-:750
2009-04-13 20:09:42,390|Thread-52|playback_lock.held:-:1312
```
eis.time: Two lines are printed, one at the beginning and one at the end of every EIS Interaction, both for MBO read and operation replay.