IBM Support

CDS Tracing Information

Troubleshooting


Problem

CDS Tracing Information

Resolving The Problem

This note describes techniques for tracing CDS client and server processes,
and presents a few tips that can be used to help interpret the results. It is intended primarily for use by DCE administrators who want to understand more about the workload that's being imposed on their CDS, or who are attempting to troubleshoot some operational problem with CDS.

We make no attempt here to explain all CDS trace messages; instead, we concentrate on the more generally informative messages. You should know that in general, our Support group cannot provide detailed analyses of this type of tracing output -- this web page is presented "for your information" only. You should also realize that enabling tracing can have a performance impact: overall CDS performance could be reduced by 50% or even more in some cases.
Just so you know...

OK, now that we have the disclaimers out of the way, let's dive in.

CDS tracing is done via DCE's serviceability facility. You will need to understand CDS processes in order to make sense of the results; see the DCE tech note describing CDS processes.

In the examples, we'll send our trace output to files in /usr/trace.You can send them anywhere you want to, but you'll have to make sure your intended directory actually exists before you set up the tracing on your own systems. Some of the trace output files can be several megabytes in size, so make sure you choose a location where there is adequate disk free space.

Your trace output will consist of lines like this:

2000-01-12-08:49:32.871-05:00I0.154 cdsd(5058) DEBUG2 cds server ? 0 0x00000013 \\
>dnscp_server(318e00,130,4030,3f75c0,325970)

2000-01-12-08:49:32.871-05:00I0.154 cdsd(5058) DEBUG3 cds server ? 0 0x00000013 \\
>srv_show_server(0x1e1130,0x3f75c0,attr_id=0,0x325970)

2000-01-12-08:49:32.871-05:00I0.154 cdsd(5058) DEBUG2 cds server ? 0 0x00000013 \\
>TestServerUserAccess (318e00,1)

2000-01-12-08:49:32.873-05:00I0.154 cdsd(5058) DEBUG2 cds server ? 0 0x00000013 \\
<TestServerUserAccess (318e00,1) return(1)

2000-01-12-08:49:32.873-05:00I0.154 cdsd(5058) DEBUG3 cds server ? 0 0x00000013 \\
<srv_show_server(0x1e1130,0x3f75c0,attr_id=0,0x325970) return (282107905)

2000-01-12-08:49:32.873-05:00I0.154 cdsd(5058) DEBUG2 cds server ? 0 0x00000013 \\
<dnscp_server(318e00,130,4030,0x3f75c0,0x325970) cmd_status=282107905 return(rpc_s_ok)

Here I have split the very long lines at the point indicated as "\\". Each line consists of a timestamp, a process name and PID, the debug level and component and subcomponent that produced the line, a "? 0" that can be ignored, a thread ID, and finally the trace message itself. Note especially that the 0x00000013 in the lines above is a thread number, not an error code. Also note the use of ">" and "<" to indicate where the process entered and exited
various functions. Finally, note that the status code of 282107905 means "all is well":
% dcecp -c errtext 282107905
Successful completion.

The examples below assume we're working on a machine named "foo". Depending on your DCE implementation, you may have to use a fully-qualified machine name like "foo.company.com" instead of just "foo". List the contents of your /.:/hosts CDS directory in order to see which type of name you need to use.


CDS Server Tracing

We'll use "cds:*.6" tracing on the server. There are several ways to enable this tracing; three common ones are as follows:

  • 1. Stop the running CDS server via the "cdscp disable server" command. You'll have to be root to do this, and you'll want to use "ps" to verify that cdsd has actually stopped. (It can take a minute or two to halt the server process, since it has to write its clearinghouse to disk as it terminates.) Then set the SVC_CDS_DBG environment variable and restart the server. The whole sequence of commands might look like this:

    # cdscp disable server
    # ps -ef | egrep 'PID|cdsd'
    # setenv SVC_CDS_DBG 'cds:*.6:FILE:/usr/trace/cdsd.log'
    # /etc/init.d/dce start (for Solaris DCE users)
    or
    # start.dce (for AIX DCE users)
    # unsetenv SVC_CDS_DBG
  • 2. Stop the running CDS server via "cdscp disable server", as root, and use "ps" to verify that cdsd has actually stopped; same as in the first technique. (Alternatively, you could also just stop all of DCE, via your normal DCE stop script, instead of just clobbering the CDS server process.) Now add the following line to the /opt/dcelocal/var/svc/routing file:

    cds:*.6:FILE:/usr/trace/cdsd.log

    ...and then restart the CDS server via your normal DCE start script.
  • 3. Use the dcecp log modify command to start tracing. If the CDS server is on a machine named "foo", then you could just do this:

    % dcecp -c log modify /.:/hosts/foo/cds-server -change \
    '{cds:*.6:FILE:/usr/trace/cdsd.log}'

    ...and you'd have to be authenticated as cell_admin or a similar powerful DCE administrator. With this technique, you don't have to be UNIX root and you don't even have to type the command on the CDS server machine. However, the trace output file will appear on the CDS server machine, no matter where you are when you issue the dcecp command.


Each of the above techniques will cause the CDS server to write trace data to /usr/trace/cdsd.log. When you want to stop the tracing, you can turn it off in one of three ways:

 

  • 1. Stop and restart the CDS server, with SVC_CDS_DBG unset:

    # unsetenv SVC_CDS_DBG
    # cdscp disable server
    # ps -ef | egrep 'PID|cdsd'
    # /etc/init.d/dce start (for Solaris DCE users)
    or
    # start.dce (for AIX DCE users)

 

 

  • 2. Remove the line from /opt/dcelocal/var/svc/routing, then stop and restart the CDS server.

 

  • 3. Via dcecp log modify:
    % dcecp -c log modify /.:/hosts/foo/cds-server -change '{cds:*.9:DISCARD:}'


Now you have server trace output in /usr/trace/cdsd.log on the CDS server machine.

Some interesting things to look for:

 

    • cdscp operations are indicated by ">dnscp_server" and "<dnscp_server" lines. Examples might include cdscp disable server (to stop the server) and cdscp show server (to view counters). You won't easily be able to tell which cdscp operation is being performed, however, unless you get lucky and some lower-level function entry tips you off (like ">srv_show_server" in the trace output at the top of this page, for example).
    • When the CDS server handles an incoming RPC to perform some routine operation like directory or object creation, deletion, or reading, there will be a line like ">cds_Xyyy", where "Xyyy" describes the operation. For example, directory creation is done via "cds_CreateDirectory".
    • You can see the DCE identity of the caller in terms of UUIDs (which you may want to translate by examining the security registry) in lines right after the ">cds_Xyyy" line. For example:

  • 2000-01-12-08:49:35.128-05:00I0.156 cdsd(5058) DEBUG2 cds server ? 0 0x00000013 \\
    >cds_CreateDirectory(,{{},/.../supportsnare.dce.company.com/pdh/d11,0:/})

    2000-01-12-08:49:35.130-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    Principal: <00000064-78ab-21d2-b800-9e620bdbaa77>

    2000-01-12-08:49:35.130-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    Group : <0000000c-78ab-21d2-b801-9e620bdbaa77>

    2000-01-12-08:49:35.131-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    Local groupset :

    2000-01-12-08:49:35.131-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    <0000000c-78ab-21d2-b801-9e620bdbaa77>

    2000-01-12-08:49:35.131-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    <00000065-78ab-21d2-9901-9e620bdbaa77>

    2000-01-12-08:49:35.132-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    <00000066-78ab-21d2-9901-9e620bdbaa77>

    2000-01-12-08:49:35.132-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    <00000067-78ab-21d2-9901-9e620bdbaa77>

    2000-01-12-08:49:35.133-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    <00000068-78ab-21d2-9901-9e620bdbaa77>

    2000-01-12-08:49:35.133-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    <00000069-78ab-21d2-9901-9e620bdbaa77>

    2000-01-12-08:49:35.133-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    <0000006c-78ab-21d2-9901-9e620bdbaa77>

    2000-01-12-08:49:35.134-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    <0000006e-7d80-21d2-9301-9e620bdbaa77>

    2000-01-12-08:49:35.134-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    <00000078-808c-21d2-8801-9e620bdbaa77>

    2000-01-12-08:49:35.134-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    <0000006d-ae60-21d3-b101-00062921fb74>

    2000-01-12-08:49:35.135-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    Foreign groupset :

    2000-01-12-08:49:35.135-05:00I0.156 cdsd(5058) DEBUG5 cds server ? 0 0x00000013 \\
    * * * * * * * * * * * * * *
    • Access-control checking is done under ">security_check" lines:

    2000-01-12-08:49:35.144-05:00I0.156 cdsd(5058) DEBUG6 cds server ? 0 0x00000013 \\
    >security_check

    2000-01-12-08:49:35.144-05:00I0.156 cdsd(5058) DEBUG6 cds server ? 0 0x00000013 \\
    >security_dacl(looking for rights = 0x2)

    2000-01-12-08:49:35.144-05:00I0.156 cdsd(5058) DEBUG2 cds library ? 0 0x00000013 \\
    >dpe_acl_flat_to_wire

    2000-01-12-08:49:35.145-05:00I0.156 cdsd(5058) DEBUG2 cds library ? 0 0x00000013 \\
    <dpe_acl_flat_to_wire: @ end - return(dpe_acl_success)

    2000-01-12-08:49:35.145-05:00I0.156 cdsd(5058) DEBUG6 cds general ? 0 0x00000013 \\
    >dpe_acl_mgr_get_access()

    2000-01-12-08:49:35.145-05:00I0.156 cdsd(5058) DEBUG6 cds general ? 0 0x00000013 \\
    Authenticated.

    2000-01-12-08:49:35.146-05:00I0.156 cdsd(5058) DEBUG2 cds general ? 0 0x00000013 \\
    <dpe_acl_mgr_get_access: return 1, 0

    2000-01-12-08:49:35.146-05:00I0.156 cdsd(5058) DEBUG6 cds server ? 0 0x00000013 \\
    security_dacl (haverights = 0x6B)

    2000-01-12-08:49:35.146-05:00I0.156 cdsd(5058) DEBUG6 cds server ? 0 0x00000013 \\
    <security_dacl: return(status=282107905)

    2000-01-12-08:49:35.147-05:00I0.156 cdsd(5058) DEBUG6 cds server ? 0 0x00000013 \\
    <security_check: @end - return(sts=282107905)


(Recall that 282107905 is the "success" status code.)

 

 

    • Writes to the server's transaction-log file are indicated by ">db_tlog_create" and ">db_tlog_update" lines.

 

    • Directory skulks are indicated by ">skulk_dir" lines:

  • 2000-01-12-08:49:35.526-05:00I0.156 cdsd(5058) DEBUG6 cds server ? 0 0x00000013 \\
    >skulk_dir(/.../supportsnare.dce.company.com/pdh/d11) state(1) type(1)
    • Update propagation (when a change is made to a replicated directory) is indicated by a ">back_propagate" line.
    • By searching for the string "checkpoint", you can see lines that show where the CDS server determines whether or not it needs to checkpoint its data to disk, and you can see the progress of the checkpoint operation when it does one.


If you simply want to see what operations your CDS server is performing, then you could just use "cds:server.2" tracing and look for the ">cds_X" lines. In general, once you become familiar with CDS server trace output, you might choose to use less than the "cds:*.6" that we used, depending on what you're really interested in.

One quirk to be aware of: if for example you decide that you want different trace levels on different subcomponents, like say "cds:server.4,database.3" tracing, then you must actually specify "cds:*.1,server.4,database.3", or else you'll get "cds:*.9", which is just a ton of junk. (This is probably the result of a bug in the parsing of the serviceability specification.)


CDS Client Tracing

For the client, we start with "cds:*.3,adver.8,clerk.7,cache.5" tracing. As with the server tracing, you can enable it in many different ways. Unfortunately, setting up client tracing is uglier than server tracing because you have to worry about more processes. Anyway, here are three common techniques:


  • 1. Stop the running CDS client processes and restart with SVC_CDS_DBG set. You must use ps to verify that cdsadv is down, since it writes its cache to disk as it halts and that can take a minute or so.

    If the machine is also a CDS server, then this can get nasty because you must stop the server before stopping the client, and you must restart the server after restarting the client. But, you don't really want the new server to run with SVC_CDS_DBG set, so you pretty much have to start the client process cdsadv manually. Here are the commands:
  • # cdscp disable server
    # ps -ef | egrep 'PID|cdsd'
    # cdscp disable clerk
    # ps -ef | egrep 'PID|cdsadv'
    # setenv SVC_CDS_DBG 'cds:*.3,adver.8,clerk.7,cache.5:FILE:/usr/trace/client.log'
    # cdsadv -s (for Solaris DCE users)
    or
    # cdsadv (for AIX DCE users)
    # unsetenv SVC_CDS_DBG
    # /etc/init.d/dce start (for Solaris DCE users)
    or
    # start.dce (for AIX DCE users)

    If however the machine is not a CDS server, then the following should suffice:

    # cdscp disable clerk
    # ps -ef | egrep 'PID|cdsadv'
    # setenv SVC_CDS_DBG 'cds:*.3,adver.8,clerk.7,cache.5:FILE:/usr/trace/client.log'
    # /etc/init.d/dce start (for Solaris DCE users)
    or
    # start.dce (for AIX DCE users)
    # unsetenv SVC_CDS_DBG
  • 2. Stop the running CDS client processes, modify the /opt/dcelocal/var/svc/routing file, and restart the processes. You'll need to disable the CDS server first (if a server is running on your machine), then the CDS client; or you could just stop all of DCE. Then add a line like the following to the routing file:

    cds:*.3,adver.8,clerk.7,cache.5:FILE:/usr/trace/client.log

    ...and then re-start DCE via your standard DCE start script. (Note that if a CDS server is configured on your machine, then you'll get CDS server tracing mixed in with the client tracing in the trace output file.)
  • 3. Use the dcecp log modify command. This command will set the trace spec in the running cdsadv process; you must then kill any running cdsclerk processes so that new ones are created with the desired trace setting. For example:

    # dcecp -c log modify /.:/hosts/foo/cds-clerk -change \
    '{cds:*.3,adver.8,clerk.7,cache.5:FILE:/usr/trace/client.log}'
    # ps -ef | egrep 'PID|cdsclerk'
    # kill clerk-PID-1 clerk-PID-2 ...


You need to be root to do most of this, and you need to be cell_admin (or similar) to do the dcecp log modify.

Each of the above techniques will cause the CDS client processes to write trace data to /usr/trace/client.log. When you want to stop the tracing, you can turn it off in one of three ways:

 

  • 1. Stop and restart, with SVC_CDS_DBG unset:

    # unsetenv SVC_CDS_DBG
    # cdscp disable server
    # ps -ef | egrep 'PID|cdsd'
    # cdscp disable clerk
    # ps -ef | egrep 'PID|cdsadv'
    # /etc/init.d/dce start (for Solaris DCE users)
    or
    # start.dce (for AIX DCE users)

 

  • 2. Remove the line from <code>/opt/dcelocal/var/svc/routing</code>, then stop and restart the CDS processes.
  • 3. Via dcecp log modify:

    # dcecp -c log modify /.:/hosts/foo/cds-clerk -change '{cds:*.9:DISCARD:}'
    # ps -ef | egrep 'PID|cdsclerk'
    # kill clerk-PID-1 clerk-PID-2 ...


Note that the names of the "cdscp disable clerk" command and of the "/.:/hosts/foo/cds-clerk" CDS entry are misleading, since both really refer to cdsadv in addition to cdsclerk. Sorry...

Some things to look for in the /usr/trace/client.log output:

 

 

  • Almost any lines from cdsadv are interesting; these will mainly show the advertiser accepting a user request and dispatching it to a clerk (possibly creating a new clerk). For example, creating a new clerk:


2000-01-12-14:10:26.767-05:00I0.133 cdsadv(401) DEBUG6 cds adver ? 0 0x0000000a \\
adver_clerk_listener(76358) client socket(14)

2000-01-12-14:10:26.768-05:00I0.133 cdsadv(401) DEBUG3 cds adver ? 0 0x0000015d \\
&gt;adver_clerk_client(79738)

2000-01-12-14:10:26.770-05:00I0.133 cdsadv(401) DEBUG4 cds adver ? 0 0x0000015d \\
&gt;BindChildDssd(76358,,)

2000-01-12-14:10:26.774-05:00I0.133 cdsadv(401) DEBUG8 cds adver ? 0 0x0000015d \\
&gt;adver_open_socket(/opt/dcelocal/var/adm/directory/cds/dssS23,5)

2000-01-12-14:10:26.910-05:00I0.133 cdsadv(401) DEBUG6 cds adver ? 0 0x0000015d \\
BindChildDssd() exec(/opt/dcelocal/bin/cdsclerk) for(0,0) name(/opt/dcelocal/ \\
var/adm/directory/cds/cdsclerk_9278_root)

2000-01-12-14:10:26.914-05:00I0.133 cdsclerk(9278) DEBUG3 cds clerk ? 0 0x00000001 \\
main: using cache(1)

2000-01-12-14:10:26.916-05:00I0.133 cdsclerk(9278) DEBUG2 cds clerk ? 0 0x00000001 \\
&gt;start_listener(0xeffffb4c-&gt;)

... and using an existing clerk:

2000-01-12-14:10:27.426-05:00I0.134 cdsadv(401) DEBUG6 cds adver ? 0 0x0000000a \\
adver_clerk_listener(76358) client socket(14)

2000-01-12-14:10:27.427-05:00I0.134 cdsadv(401) DEBUG3 cds adver ? 0 0x00000160 \\
&gt;adver_clerk_client(e7eb8)

2000-01-12-14:10:27.428-05:00I0.134 cdsadv(401) DEBUG4 cds adver ? 0 0x00000160 \\
&gt;BindChildDssd(76358,,)

2000-01-12-14:10:27.429-05:00I0.134 cdsadv(401) DEBUG4 cds adver ? 0 0x00000160 \\
BindChildDssd found child 9278 (/opt/dcelocal/var/adm/directory/cds/ \\
cdsclerk_9278_root) for uid 0, gid 0

2000-01-12-14:10:27.429-05:00I0.134 cdsadv(401) DEBUG4 cds adver ? 0 0x00000160 \\
&lt;BindChildDssd(76358,,) return(DNS_SUCCESS)

2000-01-12-14:10:27.430-05:00I0.134 cdsadv(401) DEBUG8 cds adver ? 0 0x00000160 \\
&gt;client_cleanup(e7eb8)

2000-01-12-14:10:27.430-05:00I0.134 cdsadv(401) DEBUG8 cds adver ? 0 0x00000160 \\
&lt;client_cleanup(e7eb8)

2000-01-12-14:10:27.430-05:00I0.134 cdsadv(401) DEBUG3 cds adver ? 0 0x00000160 \\
&lt;adver_clerk_client(e7eb8) return(0)

2000-01-12-14:10:27.432-05:00I0.134 cdsclerk(9278) DEBUG2 cds clerk ? 0 0x00000005 \\
&gt;clerk_socket_accept(5)

 

 

 

 

  • Individual requests will start with a few "clerk_request" lines, then there will be a line like "&gt;clerkFooBar". Requests to read a CDS attribute are common; here the clerk line will be like "&gt;clerkReadAttribute". This will be followed by "&gt;clerkReadAttributeCache" to see if the read can be satisfied from the CDS cache. If it can, then there will be a call to "&gt;CAReadAttrbute"; otherwise an RPC to a CDS server will be required. RPCs to CDS servers are indicated by lines like "&gt;FooBarRPC". The action is over when you see a "write_response" line, which shows the clerk is sending the results back to the calling process.




    •  
  •  

Here is an example of a read that was done via the cache:

2000-12-19-13:58:03.646-05:00I----- cdsclerk(13631) DEBUG3 cds clerk ? 0 0x00000013 \\
&gt;clerk_request(0x1116d8-&gt;6)

2000-12-19-13:58:03.655-05:00I----- cdsclerk(13631) DEBUG3 cds clerk ? 0 0x00000013 \\
clerk_request: clerkWait is 300

2000-12-19-13:58:03.660-05:00I----- cdsclerk(13631) DEBUG3 cds clerk ? 0 0x00000013 \\
clerk_request: expire is 19-dec-2000 14:03:03.6578110

2000-12-19-13:58:03.665-05:00I----- cdsclerk(13631) DEBUG4 cds clerk ? 0 0x00000013 \\
&gt;clerkReadAttribute(/.../rootbeer/sec,dirOrObj,RPC_ClassVersion,false,0/ \\
00-00-00-00-00-00,00000000-0000-0000-0000-000000000000,119125,11912d)

2000-12-19-13:58:03.669-05:00I----- cdsclerk(13631) DEBUG5 cds clerk ? 0 0x00000013 \\
&gt;clerkReadAttributeCache

2000-12-19-13:58:03.674-05:00I----- cdsclerk(13631) DEBUG4 cds cache ? 0 0x00000013 \\
&gt;CAReadAttribute(*ANONYMOUS*,35530,/.../rootbeer/sec,dirOrObj,RPC_ClassVersion, \\
0/00-00-00-00-00-00,14244,0xFB9ADC64,ee6b718f,ee6bbbdc,128ad3)

2000-12-19-13:58:03.735-05:00I----- cdsclerk(13631) DEBUG5 cds cache ? 0 0x00000013 \\
&gt;CA_LookupUser(*ANONYMOUS*)

2000-12-19-13:58:03.761-05:00I----- cdsclerk(13631) DEBUG5 cds cache ? 0 0x00000013 \\
&lt;CA_LookupUser(NO_USER) return(ee8029c8)

2000-12-19-13:58:03.792-05:00I----- cdsclerk(13631) DEBUG5 cds cache ? 0 0x00000013 \\
&gt;ReadAttr(ee8018d4,RPC_ClassVersion,0/00-00-00-00-00-00,14244,0xFB9ADC64, \\
ee6b718f,35530,ee6bbbdc)

2000-12-19-13:58:03.829-05:00I----- cdsclerk(13631) DEBUG5 cds cache ? 0 0x00000013 \\
&lt;ReadAttr(ee8018d4,RPC_ClassVersion,0/00-00-00-00-00-00,14244,0xFB9ADC64, \\
ee6b718f,35530,ee6bbbdc) return(DNS_SUCCESS)

2000-12-19-13:58:03.839-05:00I----- cdsclerk(13631) DEBUG4 cds cache ? 0 0x00000013 \\
&lt;CAReadAttribute(*ANONYMOUS*,35530,/.../rootbeer/sec,dirOrObj,RPC_
ClassVersion,0/00-00-00-00-00-00,14244,0xFB9ADC64,ee6b718f-&gt;1,ee6bbbdc-&gt;0, \\
128ad3-&gt;0) return(DNS_SUCCESS)

2000-12-19-13:58:03.843-05:00I----- cdsclerk(13631) DEBUG5 cds clerk ? 0 0x00000013 \\
&lt;clerkReadAttributeCache: return(TRUE)

2000-12-19-13:58:03.847-05:00I----- cdsclerk(13631) DEBUG4 cds clerk ? 0 0x00000013 \\
&lt;clerkReadAttribute(/.../rootbeer/sec,dirOrObj,RPC_ClassVersion,false, \\
0/00-00-00-00-00-00,00000000-0000-0000-0000-000000000000,119125,11912d) \\
status(DNS_SUCCESS)

2000-12-19-13:58:03.850-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000013 \\
&gt;write_response


Here is a read that went to a server (note that the processCH and get_rpc_handle lines show you which server was used):

 

 




     
  •  

2000-12-19-13:56:59.570-05:00I----- cdsclerk(13631) DEBUG3 cds clerk ? 0 0x00000010 \\
&gt;clerk_request(0x11aa30-&gt;6)

2000-12-19-13:56:59.574-05:00I----- cdsclerk(13631) DEBUG3 cds clerk ? 0 0x00000010 \\
clerk_request: clerkWait is 300

2000-12-19-13:56:59.579-05:00I----- cdsclerk(13631) DEBUG3 cds clerk ? 0 0x00000010 \\
clerk_request: expire is 19-dec-2000 14:01:59.5770849

2000-12-19-13:56:59.584-05:00I----- cdsclerk(13631) DEBUG4 cds clerk ? 0 0x00000010 \\
&gt;clerkReadAttribute(/.../rootbeer/sec,dirOrObj,RPC_ClassVersion,false, \\
0/00-00-00-00-00-00,00000000-0000-0000-0000-000000000000,11173d,111745)

2000-12-19-13:56:59.589-05:00I----- cdsclerk(13631) DEBUG5 cds clerk ? 0 0x00000010 \\
&gt;clerkReadAttributeCache

2000-12-19-13:56:59.597-05:00I----- cdsclerk(13631) DEBUG5 cds clerk ? 0 0x00000010 \\
&lt;clerkReadAttributeCache: (1) return(FALSE)

2000-12-19-13:56:59.600-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&gt;sendToWalkTree(0x0004A265,/.../rootbeer/sec)

2000-12-19-13:56:59.605-05:00I----- cdsclerk(13631) DEBUG4 cds clerk ? 0 0x00000010 \\
&gt;clerk_WalkTree(0x0004A265,/.../rootbeer/sec)

2000-12-19-13:56:59.609-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&gt;clerkgetch

2000-12-19-13:56:59.612-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&lt;clerkgetch: return(NULL)

2000-12-19-13:56:59.614-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&gt;ChooseInitCh(,/.../rootbeer/sec)

2000-12-19-13:56:59.649-05:00I----- cdsclerk(13631) DEBUG4 cds cache ? 0 0x00000010 \\
&gt;CAFindCle(/.../rootbeer/cspool15_ch,10)

2000-12-19-13:56:59.652-05:00I----- cdsclerk(13631) DEBUG4 cds cache ? 0 0x00000010 \\
&lt;CAFindCle(/.../rootbeer/cspool15_ch,10) return(ee800cb0)

2000-12-19-13:56:59.655-05:00I----- cdsclerk(13631) DEBUG4 cds cache ? 0 0x00000010 \\
&gt;CAFindCle(/.../rootbeer/cspool36.test.ibm.com_ch,7)

2000-12-19-13:56:59.659-05:00I----- cdsclerk(13631) DEBUG4 cds cache ? 0 0x00000010 \\
&lt;CAFindCle(/.../rootbeer/cspool36.test.ibm.com_ch,7) return(0)

2000-12-19-13:56:59.669-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
ChooseInitCh(,/.../rootbeer) return(a4938)

2000-12-19-13:56:59.682-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&lt;ChooseInitCh

2000-12-19-13:56:59.685-05:00I----- cdsclerk(13631) DEBUG4 cds clerk ? 0 0x00000010 \\
clerk_WalkTree(0x0004A265,/.../rootbeer/sec) looking for (/.../rootbeer)

2000-12-19-13:56:59.688-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&gt;ChooseCh()

2000-12-19-13:56:59.692-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&lt;ChooseCh() return(best_p : a4938-&gt;/.../rootbeer/cspool15_ch)

2000-12-19-13:56:59.695-05:00I----- cdsclerk(13631) DEBUG5 cds clerk ? 0 0x00000010 \\
&gt;processCH(0x0004A265,/.../rootbeer/cspool15_ch)

2000-12-19-13:56:59.698-05:00I----- cdsclerk(13631) DEBUG5 cds clerk ? 0 0x00000010 \\
processCH(0x0004A265,/.../rootbeer/cspool15_ch): try addr from cache or hint

2000-12-19-13:56:59.701-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
&gt;processAddr(0x0004A265,{/.../rootbeer/cspool15_ch,872257b8-a9e9-11d4- \\
a7a4-0926cd0faa77},0x00029264)

2000-12-19-13:56:59.704-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
processAddr: taRPC=0x3ceb4

2000-12-19-13:56:59.707-05:00I----- cdsclerk(13631) DEBUG4 cds clerk ? 0 0x00000010 \\
&gt;ReadAttributeRPC

2000-12-19-13:56:59.711-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&gt;get_cached_handle(872257b8-a9e9-11d4-a7a4-0926cd0faa77)

2000-12-19-13:56:59.714-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&lt;get_cached_handle(872257b8-a9e9-11d4-a7a4-0926cd0faa77, 0)

2000-12-19-13:56:59.721-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
&gt;get_rpc_handle(ee6b84f8,a4999,a4950,128994)

2000-12-19-13:56:59.726-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
get_rpc_handle: string binding: ncacn_ip_tcp:9.38.205.15[], uuid: \\
872257b8-a9e9-11d4-a7a4-0926cd0faa77

2000-12-19-13:56:59.728-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
&gt;get_secure_handle(128994,ee6b84f8)

2000-12-19-13:56:59.732-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
&lt;get_secure_handle: return(TRUE)

2000-12-19-13:56:59.735-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
&lt;get_rpc_handle(status=1, getout=0)

2000-12-19-13:56:59.834-05:00I----- cdsclerk(13631) DEBUG4 cds clerk ? 0 0x00000010 \\
&lt;ReadAttributeRPC: return(DNS_SUCCESS)

2000-12-19-13:56:59.838-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
processAddr(0x0004A265,{/.../rootbeer/cspool15_ch,872257b8-a9e9-11d4-a7a4- \\
0926cd0faa77},0x00029264) response received

2000-12-19-13:56:59.845-05:00I----- cdsclerk(13631) DEBUG5 cds clerk ? 0 0x00000010 \\
&gt;proc_prog()

2000-12-19-13:56:59.848-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
&gt;proc_done()

2000-12-19-13:56:59.851-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
&gt;proc_chlist()

2000-12-19-13:56:59.896-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
&lt;proc_done()

2000-12-19-13:56:59.899-05:00I----- cdsclerk(13631) DEBUG5 cds clerk ? 0 0x00000010 \\
&lt;proc_prog(): (1) return(DNS_SUCCESS)

2000-12-19-13:56:59.903-05:00I----- cdsclerk(13631) DEBUG6 cds clerk ? 0 0x00000010 \\
&lt;processAddr(0x0004A265,{/.../rootbeer/cspool15_ch,872257b8-a9e9-11d4-a7a4- \\
0926cd0faa77},0x00029264), status1(DNS_SUCCESS), status2(DNS_SUCCESS)

2000-12-19-13:56:59.906-05:00I----- cdsclerk(13631) DEBUG5 cds clerk ? 0 0x00000010 \\
&lt;processCH(0x0004A265,) return(DNS_SUCCESS)

2000-12-19-13:56:59.909-05:00I----- cdsclerk(13631) DEBUG4 cds clerk ? 0 0x00000010 \\
&lt;clerk_WalkTree(0x0004A265,/.../rootbeer/sec)

2000-12-19-13:56:59.914-05:00I----- cdsclerk(13631) DEBUG4 cds cache ? 0 0x00000010 \\
&gt;CAInsertAttribute(*ANONYMOUS*,/.../rootbeer/sec,object,RPC_ClassVersion, \\
0/00-00-00-00-00-00,10c5c2,1)

2000-12-19-13:56:59.927-05:00I----- cdsclerk(13631) DEBUG5 cds cache ? 0 0x00000010 \\
&gt;CA_InsertName(/.../rootbeer/sec,object,ee6ba62c)

2000-12-19-13:56:59.955-05:00I----- cdsclerk(13631) DEBUG5 cds cache ? 0 0x00000010 \\
&lt;CA_InsertName(/.../rootbeer/sec,object,ee6ba62c-&gt;DNS_SUCCESS) return(ee8018d4)

2000-12-19-13:57:00.086-05:00I----- cdsclerk(13631) DEBUG5 cds cache ? 0 0x00000010 \\
&gt;CA_InsertUser(*ANONYMOUS*,ee6ba450)

2000-12-19-13:57:00.117-05:00I----- cdsclerk(13631) DEBUG5 cds cache ? 0 0x00000010 \\
&lt;CA_InsertUser(NO_USER,ee6ba450-&gt;DNS_CLERKBUG) return(ee8029c8)

2000-12-19-13:57:00.170-05:00I----- cdsclerk(13631) DEBUG4 cds cache ? 0 0x00000010 \\
&lt;CAInsertAttribute(*ANONYMOUS*,/.../rootbeer/sec,object,RPC_ClassVersion, \\
0/00-00-00-00-00-00,10c5c2,1) return(DNS_SUCCESS)

2000-12-19-13:57:00.173-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&lt;sendToWalkTree(0x0004A265,/.../rootbeer/sec)

2000-12-19-13:57:00.178-05:00I----- cdsclerk(13631) DEBUG4 cds clerk ? 0 0x00000010 \\
&lt;clerkReadAttribute(/.../rootbeer/sec,dirOrObj,RPC_ClassVersion,false, \\
0/00-00-00-00-00-00,00000000-0000-0000-0000-000000000000,11173d,111745) \\
status(DNS_SUCCESS)

2000-12-19-13:57:00.181-05:00I----- cdsclerk(13631) DEBUG7 cds clerk ? 0 0x00000010 \\
&gt;write_response


As with the server tracing, you can cut down the trace spec if you know what you're looking for. In particular, you could use "cds:*.1,adver.4,clerk.4" if you just wanted to see the clerk dispatching and the RPCs.


gdad Tracing

gdad offers the CDS server interface, and is used to help enable cross-cell RPCs. gdad tracing is described in the troubleshooting section of the DCE cross-cell tech note.
 

[{"Business Unit":{"code":"BU054","label":"Systems w\/TPS"},"Product":{"code":"SSGMCP","label":"Distributed Computing Environment"},"Component":"--","Platform":[{"code":"PF002","label":"AIX"},{"code":"PF027","label":"Solaris"}],"Version":"3.1;3.2","Edition":"","Line of Business":{"code":"","label":""}}]

Document Information

Modified date:
23 August 2018

UID

swg21112355

Page Feedback