This appendix contains instructions for obtaining trace information that can be valuable for debugging problems with any program that uses the ENS API. This includes all servers that send notifications through enpd, csadmind, csnotifyd, the iBiff plug-in, stored, imapd. Trace information can be obtained by setting several environment variables.
This appendix is divided into the following topics:
Tracing can be done at both the GAP (generic request and reply protocol layer) and ENP (publish and subscribe protocol layer) levels. Also, service bus traces can be set. The default is for no logging or tracing.
The following environment variables can be set for GAP tracing:
GAP_LOGFILE (Calendar Server only)
The following environment variables can be set for ENP tracing:
ENS_LOGFILE (Calendar Server only)
The following environment variable can be set for service bus tracing: SERVICEBUS_DEBUG.
The value is a positive integer which indicates the trace level. Each higher trace level includes the output from the levels below it. For example, if you set the trace level to 7, level 1-6 traces are also included. The default value for this variable is 4, but since GAP_LOG_MODULES defaults to zero (0), no logging is done.
While it is possible to set the variable to any integer value greater than 7 and less than 100, the effect will be the same as setting it to 7.
Table A–1 lists the trace levels for the variable GAP_DEBUG:
Table A–1 Trace Level Values
Trace Level |
Trace Level Name |
Description |
---|---|---|
0 |
N/A |
No output except emergency messages |
1 |
NSLOG_ALERT |
Alert messages |
2 |
NSLOG_CRIT |
Critical messages |
3 |
NSLOG_ERR |
Software error conditions |
4 |
NSLOG_WARNING |
Default; warning messages (user error conditions) |
5 |
NSLOG_NOTICE |
Normal but significant conditions |
6 |
NSLOG_INFO |
Informational messages |
7 |
NSLOG_DEBUG |
Debug messages |
100 |
NSLOG_TRACE |
Full trace |
Use this variable to obtain trace information specific to one or more functional modules in the GAP code. This variable is a bit map. That is, each bit set in the variable turns on tracing for a particular module.
More than one module can be specified at once. To specify multiple modules, add the individual values of the modules you want. For example, if you want to trace both the connection layer and the transaction modules, you set the value of this variable to 10; to get all modules, set the value to 15.
Table A–2 lists the values for the variable GAP_LOG_MODULES:
Table A–2 GAP_LOG_MODULES Values
Value |
Value Name |
Description |
---|---|---|
0 |
N/A |
Default; no modules logged. |
1 |
GAPLOG_CONNECTION |
Connection layer– socket input output calls |
2 |
GAPLOG_SESSION |
Session layer– session setup and closing |
4 |
GAPLOG_TRANSACTION |
Transaction creation– continuation and termination |
8 |
GAPLOG_DISPATCHER |
Thread dispatcher code– GDisp tracing |
This variable is used for Calendar Server only. This variable tells the system where to output GAP tracing. To send the output to a log file, set the variable to a text file name. The default (variable set to zero) sends GAP tracing to standard out.
Use this variable to generate encoded data traces. Any non-zero value activates the trace.
Use this variable to trace functional (unencoded) client or server request responses.
The value is a positive integer which indicates the trace level. Each higher trace level includes the output from the levels below it. For example, if you set the trace level to 4, level 1-3 traces are also included.
While it is also possible to set the variable to any integer between 7 and 100, the effect will be the same as setting it to 7. That is, anything less than 100 but greater than 6 is treated the same.
Table A–3 lists the trace level values for the ENS_DEBUG variable:
Table A–3 ENS_DEBUG Trace Level Values
Trace Level |
Trace Level Name |
Desciption |
---|---|---|
0 |
N/A |
No output except emergency messages |
1 |
NSLOG_ALERT |
Alert messages |
2 |
NSLOG_CRIT |
Critical messages |
3 |
NSLOG_ERR |
Software error conditions |
4 |
NSLOG_WARNING |
Warning messages (user error conditions) |
5 |
NSLOG_NOTICE |
Normal but significant conditions |
6 |
NSLOG_INFO |
Informational messages |
7 |
NSLOG_DEBUG |
Debug messages |
100 |
NSLOG_TRACE |
Full trace |
Use this variable to obtain trace information specific to one or more functional modules in the ENS code. This variable is a bit map. That is, each bit set in the variable turns on tracing for a particular module.
More than one module can be specified at once. To specify multiple modules, add the individual values of the modules you want. For example, if you want to trace both the server and the RENL modules, you set the value of this variable to 10; to get all modules, set the value to 31.
Table A–4 lists the values for the variable ENS_LOG_MODULES:
Table A–4 ENS_LOG_MODULES Values
Values |
Value Names |
Description |
---|---|---|
0 |
N/A |
Default; no modules logged. |
1 |
ENSLOG_CLIENT_API |
Client API generated transactions |
2 |
ENSLOG_SERVER |
Server generated transactions |
4 |
ENSLOG_UPUB |
Publisher transactions |
8 |
ENSLOG_RENL |
Reliable event notifications |
16 |
ENSLOG_STORE |
ENS message store transactions |
This variable is used for Calendar Server only. This variable tells the system where to output ENS tracing. To send the output to a log file, set the variable to a text file name. The default (variable set to zero) sends ENS tracing to standard out.
To have statistics printed periodically, set this variable to a non-zero value.
Service Bus is a process monitoring system based on ENS, and is used in ENS. Any non-zero value causes service bus traces to be sent to standard out. There is no logfile variable for service bus. To send the traces to a log file, temporarily redefine standard out to a text file name. During this time, all standard out messages will appear in the text file you create.
The following procedure describes how to enable debug tracing.
If ENS is running, stop enpd.
To start and stop enpd, you must be in the bin directory.
For example:
For Calendar Server on Unix, /opt/SUNWics/cal/bin.
For Calendar Server on Windows, C:\Program Files\Sun ONE Calendar Server\..\.cal\bin.
You can enable debugging for specific services by stopping only that service, for example stop csnotifyd, instead of the entire ENS server.
Set all variables to the desired value.
For Unix:
Bourne shell
variable_name=value; export variable_name
For example:
GAP_DEBUG=2; export GAP_DEBUG
C shell
setenv variable_name value
For example:
setenv GAP_DEBUG 2
For Windows:
set variable_name=value
For example,
set GAP_DEBUG=2
If you want the traces to print to a log file, set the appropriate logfile variables (for END_LOGFILE, or GAP_LOGFILE) or temporarily redefine standard out to a text file.
Restart ENS– start enpd
If you only disabled one service rather than the whole ENS server, you start that service only, for example start csnotifyd.
The following are sample debugging sessions on the Messaging Server and Calendar Server.
Each example has three parts:
Set Environment Variables
Sample Trace Output
Short Commentary
setenv LD_LIBRARY_PATH msg-svr-base/lib/ stop-ens setenv SERVICEBUS_DEBUG 1 setenv ENS_DEBUG 1 setenv ENS_LOG_MODULES 1 setenv GAP_DEBUG 1 setenv GAP_LOG_MODULES 1 setenv XENP_TRACE 1 setenv ENS_STATS 1 msg-svr-base/bin/enpd
1 | servbus 3451633705 [26321]: Starting Service Bus 2 | servbus 3451636227 [26321]: Service Bus subscriber created successfully 3 | servbus 3451636286 [26321]: Service Bus Ready 4 | XENP -> len=36 servbus:///monitor/ens|subs|00010000 5 | XENP -> len=60 servbus:///service/ens&pid=26321 &state=running|ntfy|00000000 6 | XENP <- len=36 servbus:///monitor/ens|subs|00010000 7 | XENP <- len=4 PACK 8 | XENP <- len=60 servbus:///service/ens&pid=26321 &state=running|ntfy|00000000 9 |secs: pub: pub/s: pub/s(i): ntfy: ntfy/s :ntfy/s(i): 10 | 5 : 1: 0 : 0 : 0 : 0 : 0 : 11 |10 : 1: 0 : 0 : 0 : 0 : 0 : 12 | XENP <- len=232enp://127.0.0.1/store?evtType=NewMs&mailboxName=ServiceAdmin& timestamp=1027623669000&process=2637&hostname=ketu&numMsgs=14&size=621 &uidValidity=1025118712&imapUid=14&hdrLen=547&qUsed=16&qMax=-1& qMsgUsed=15&qMsgMax=-1|ntfy|00000000 13 | 15 : 2: 0 : 0 : 0 : 0 : 0 : 14 | 20 : 2: 0 : 0 : 0 : 0 : 0 : 15 | 25 : 2: 0 : 0 : 0 : 0 : 0 : 16 | 30 : 2: 0 : 0 : 0 : 0 : 0 : 17 | 35 : 2: 0 : 0 : 0 : 0 : 0 : 18 | 40 : 2: 0 : 0 : 0 : 0 : 0 : 19 | 45 : 2: 0 : 0 : 0 : 0 : 0 : 20 | 51 : 2: 0 : 0 : 0 : 0 : 0 : 21 | 56 : 2: 0 : 0 : 0 : 0 : 0 : 22 | 61 : 2: 0 : 0 : 0 : 0 : 0 : 23 | 66 : 2: 0 : 0 : 0 : 0 : 0 : 24 | 71 : 2: 0 : 0 : 0 : 0 : 0 : 25 | 76 : 2: 0 : 0 : 0 : 0 : 0 : 26 |secs: pub: pub/s: pub/s(i): ntfy: ntfy/s :ntfy/s(i): 27 | 81 : 2: 0 : 0 : 0 : 0 : 0 : 28 | 86 : 2: 0 : 0 : 0 : 0 : 0 : 29 | 91 : 2: 0 : 0 : 0 : 0 : 0 : 30 | 96 : 2: 0 : 0 : 0 : 0 : 0 : 31 |101: 2: 0 : 0 : 0 : 0 : 0 : 32 |106: 2: 0 : 0 : 0 : 0 : 0 : 33 |111: 2: 0 : 0 : 0 : 0 : 0 : 34 |116: 2: 0 : 0 : 0 : 0 : 0 : 35 |121: 2: 0 : 0 : 0 : 0 : 0 : 36 |126: 2: 0 : 0 : 0 : 0 : 0 : 37 |131: 2: 0 : 0 : 0 : 0 : 0 : 38 |136: 2: 0 : 0 : 0 : 0 : 0 : 39 |141: 2: 0 : 0 : 0 : 0 : 0 : 40 |146: 2: 0 : 0 : 0 : 0 : 0 : 41 |151: 2: 0 : 0 : 0 : 0 : 0 : 42 |^C 43 | XENP -> len=60 servbus:///service/ens&pid=26321 &state=stopped|ntfy|00000000 44 |servbus 3466881202 [26321]: Service Bus going away 45 |servbus 3466881542 [26321]: Failed to create subscriber- error-1
The following comments apply to the lines of the preceding trace output:
Line Number |
Comment |
1 - 8 |
Printed upon startup |
9 - 11 and 13 - 41 |
Periodic statistics print out |
12 |
A message is sent |
42 |
Control-c stopped operation. This was done to end the sample only. Not recommended for stopping processes normally. |
1 | (293 root) setenv ENS_DEBUG 99 2 | (294 root) setenv ENS_LOG_MODULES 63 3 | (295 root) msg-svr-base/bin/enpd Sample Trace Output 4 | ENS 3588422667 [26400]: LOGIN 2 5 | ENS 3588423361 [26400]: _enp_session_open_cb : new session id=2 created 6 | ENS 3588423380 [26400]: recorded new subscription : 0001; servbus:///monitor/ens 7 | ENS 3588423395 [26400]: subscribe (event=servbus:///monitor/ens, sid=2) = 0 8 | ENS 3588423403 [26400]:publish (event=servbus:///service/ens&pid=26400&state=running, sid=2) 9 | ENS 3588423414 [26400]:publish (event=servbus:///service/ens&pid=26400&state=running, sid=2) = 0 10 | ENS 3588423825 [26400]: _ens_recv_request_cb: sid=2 op=1 id=00010000 11 | ENS 3588423842 [26400]: simple|store_req (servbus:///monitor/ens#2) =2,servbus:///monitor/ens 12 | ENS 3588423848 [26400]: simple|store_evt (servbus:///monitor/ens#2) = 2,servbus:///monitor/ens 13 | ENS 3588423853 [26400]: SUBS 2 servbus:///monitor/ens 00010000 14 | ENS 3588424389 [26400]: _ens_recv_request_cb: sid=2 op=2 id=00000000 15 | ENS 3588424395 [26400]: NTFY 2 servbus:///service/ens &pid=26400&state=running 16 | ENS 3588424409 [26400]:ens_notify (event=servbus:///service/ens&pid=26400&state=running, id=00000000,sid=2):no match 17 | ENS 3588503451 [26400]: LOGIN 3 18 | ENS 3588504099 [26400]: LOGIN 4 19 | ENS 3588504938 [26400]: LOGIN 5 20 | ENS 3588505284 [26400]: LOGIN 6 21 22 | ENS 3591631839 [26400]: LOGIN 7 23 | ENS 3591637445 [26400]: _ens_recv_request_cb: sid=7 op=2 id=00000000 24 | ENS 3591637452 [26400]: NTFY 7 enp://127.0.0.1/store?evtType=NewMsg &mailboxName=ServiceAdmin×tamp=1027625056000&process=2646 &hostname=ketu&numMsgs=19&size=621&uidValidity=1025118712 &imapUid=19&hdrLen=547&qUsed=19&qMax=-1&qMsgUsed=20&qMsgMax=-1 25 | ENS 3591637467 [26400]:ens_notify (event=enp://127.0.0.1/store?evtType=NewMsg &mailboxName=ServiceAdmin×tamp=1027625056000&process=2646 &hostname=ketu&numMsgs=19&size=621&uidValidity=1025118712 &imapUid=19&hdrLen=547&qUsed=19&qMax=-1&qMsgUsed=20 &qMsgMax=-1, id=00000000, sid=7): no match 26 | 27 | ENS 3595049771 [26400]: session closing 7 28 | ^CENS 3596193757 [26400]:publish (event=servbus:///service/ens&pid=26400&state=stopped, sid=2) 29 | ENS 3596193782 [26400]:publish (event=servbus:///service/ens&pid=26400&state=stopped, sid=2) = 0 30 | ENS 3596193987 [26400]: pas_dispatcher_delete : clean up starting 31 | ENS 3596194018 [26400]: _enp_session_closing_cb : closing session id=2 32 | ENS 3596194024 [26400]: destroying subscription :0001; servbus:///monitor/ens 33 | ENS 3596194041 [26400]: pas_dispatcher_delete : 0 client(s) have been bumped 34 | ENS 3596194065 [26400]: session closing 2 35 | ENS 3596194075 [26400]: simple|remov_evt (2, servbus:///monitor/ens) 36 | ENS 3596194107 [26400]: session closing 3 37 | ENS 3596194216 [26400]: session closing 4 38 | ENS 3596194281 [26400]: session closing 5 39 | ENS 3596195039 [26400]: session closing 6
The following comments apply to the lines of the preceding trace output:
Line Number |
Comment |
1 - 20 |
Initialization |
22-26 |
Sent email message |
27 |
Printed asynchronously |
28 |
Control-c stopped operation. This was done to end the sample only. Not recommended for stopping processes normally. |
29-39 |
enpd exiting |