Appendix A Debugging ENS

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.

Environment Variables

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 variable can be set for service bus tracing: SERVICEBUS_DEBUG.

GAP_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 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

GAP_LOG_MODULES

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 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

GAP_LOGFILE

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.

XENP_TRACE

Use this variable to generate encoded data traces. Any non-zero value activates the trace.

ENS_DEBUG

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 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

ENS_LOG_MODULES

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 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

ENS_LOGFILE

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.

ENS_STATS

SERVICEBUS_DEBUG

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.

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.



Note	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.

Sample Debugging Sessions

The following are sample debugging sessions on the Messaging Server and Calendar Server.

Example 1: For Messaging Server

Set Environment Variables

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

Sample Trace Output

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

Short Commentary


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.

Example 2: For Messaging Server

Set Environment Variables

1 | (293 root) setenv ENS_DEBUG 99
2 | (294 root) setenv ENS_LOG_MODULES 63
3 | (295 root) msg_svr_base/bin/enpd

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&timestamp=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&timestamp=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

Short Commentary


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