![Close [x]](http://dw1.s81c.com/i/c.gif){kind=small}
IBM Tivoli Access Manager for e-business (TAMeb) provides configurable tracing capabilities. When enabled, these tracing capabilities can produce trace data that can aid IBM Tivoli Software Support in problem determination. Experienced product administrators can use trace data to diagnose and correct problems in a TAMeb environment. WebSEAL and Plug-in for Web Servers provide around 220 different trace components. The trace that is produced by many of these trace components is complex and may require intimate knowledge of the source code. However, there are a number of trace points that produce trace data that can be interpreted by a learned TAMeb administrator. This article describes, at a high level, the tracing system employed by IBM Tivoli Access Manager, and describes some of these less complex WebSEAL and Plug-in for Web Servers trace points. By the end of this article, the reader should have some knowledge of the tracing subsystem in TAMeb and be able to apply that knowledge in a problem determination situation.
There are two elements within the trace system used to control the activation of trace statements. These are the trace component and the trace level.
Trace component
The trace within Tivoli Access Manager is organized into trace components. When trace is activated to help diagnose a problem, it is important to select the appropriate trace component for the problem area. This article describes some of the most commonly used, and less complex, trace components within WebSEAL and Plug-in for Web Servers.
The trace components themselves are organized in a hierarchical fashion. If trace is activated for a parent trace component, it will automatically be activated for all children trace components. As an example, if you activate trace for the component: pdweb.snoop, tracing for the sub-component, pdweb.snoop.jct will also be activated.
Trace level
The amount of detail that is produced for a particular trace component is governed by the trace level that is selected. The trace level is a single integer within the range of 1-9, with 9 reporting the most amount of detail and 1 reporting the least amount of detail.
The following listing shows an example of a trace entry produced by the tracing system.
Listing 1. Sample trace output
2007-02-15-14:42:19.800+10:00I----- thread(5) trace.pdwebpi.azn:5
/mnt/raid/sandboxes/amwebpi/amwebpi610/src/pdwebpi/proxy/rh/WPIVirtualHost.cpp:1729:
Testing [PDWebPI]r permission on /PDWebPI/webpi.vwasp.gc.au.ibm.com for user sec_master
|
The trace entry consists of:
-
2007-02-15-14:42:19.800+10:00I - A time stamp for the trace entry, in the format of
YYY-MM-DD-hh:mm:ss.fff[+|-]hh.mmI. The first part of the time stamp contains the date and time, while the last part of the time stamp contains the time inaccuracy factor. -
thread(5) - The ID of the thread that initiated the trace request.
-
trace.pdwebpi.azn:5 - The name of the trace component that produced the line, prefixed by trace, as well as the associated trace level.
-
/mnt/raid/sandboxes/amwebpi/amwebpi610/src/pdwebpi/proxy/rh/WPIVirtualHost.cpp:1729 - The name of the product source file that generated the entry, and the line within the file on which the trace point resides.
-
Testing [PDWebPI]r permission on /PDWebPI/webpi.vwasp.gc.au.ibm.com for user sec_master - The trace text associated with the trace entry.
Tracing can be activated either through a routing file, or through a Tivoli Access Manager server task administrative command. This section will outline details of the second method. For details on how to activate tracing through a routing file, refer to the Tivoli Access Manager Problem Determination Guide.
The server task trace command can be used to dynamically control trace operations. As with other Tivoli Access Manager administrative functions, the trace command can be issued through either the pdadmin utility, or programmatically through the Tivoli Access Manager Administrative API. Figure 1 illustrates the process flow for a command.
Figure 1. TAM trace command process flow
Different pdadmin commands are available to:
- List all of the available trace points
- Change the level, and destination, for specific trace points
- Retrieve the trace point level for specific trace points
Listing trace components
To list all of the trace components offered by a server, issue the trace list command:
server task <server-name> trace list
Listing 2. trace list command
pdadmin> server task PDWebPI-webpi.gc.au.ibm.com trace list
pdwebpi.request
pdwebpi.response
...
|
Adjusting the trace level of a component
To change the level and destination for a specific trace point, use the following command:
server task <server-name> trace set <component> <level> [file path=file|other-log-agent-config]
Where component is the name of trace component as shown by the list command. The level will control the amount of detail to be gathered, in the range of 1 to 9. The optional file path parameter specifies the location for trace output. If this parameter is not supplied the trace output will be sent to the stdout stream of the server.
The following example will set the trace level to 9 for the pdwebpi.request component. Any output generated will be sent to the /tmp/log.txt file on the WebPI server.
Listing 3. Trace set command
pdadmin> server task PDWebPI-wpi.com trace set pdwebpi.request 9 file path=/tmp/log.txt
|
Retrieving the current trace level of a component
To show the names and levels for all enabled trace components use the following command:
server task <server-name> trace show [component]
If the component parameter is omitted the output will list the name and level of all of the enabled trace components.
Listing 4. Trace show command
pdadmin> server task PDWebPI-wpi.ibm.com trace show
pdwebpi.request 9
|
This section outlines some of the trace components common to WebSEAL and Plug-in for Web Servers.
The pd.ivc.ira component is used to trace the Tivoli Access Manager interaction with the LDAP server. As such, it is a trace component that can be used with WebSEAL or PDWebPI. The trace is useful in determining problems that occur during authentication. It can show the LDAP search path used when searching for a user, whether authentication succeeded for the user, whether any policy (for example, password, time-of-day) took effect, amongst other things. This information alone is powerful in performing problem determination of many of the common TAMeb problems encountered that originate from the LDAP server. It can also show the general interaction with the local user registry cache.
If the trace level is set to 7, approximately 30 lines of trace are produced for every transaction. This trace level will mostly show the authentication process. It can be used to determine whether a DN for the user was successfully located, and whether authentication for the user succeeded.
If the trace level is set to 8, approximately 170 lines of trace are produced for every transaction. In addition to the authentication process this trace level will log the steps involved in validating the user policy. It will also show some interaction with the local user registry cache.
The following sample output is an extract of the trace produced during a standard authentication for a trace level of 8. The output shows that the user, scotte, was successfully authenticated and that the DN of the user is 'cn=Scott Exton,o=ibm,c=au'.
Listing 5. Example pd.ivc.ira output (extract)
...
2007-03-09-14:31:00.329+10:00I----- thread(2) trace.pd.ivc.ira:8 /project/am610/build/am61
0/src/ivrgy/ira_auth.c:1221: CII ENTRY: ira_get_dn_utf8() parm: scotte
...
2007-03-09-14:31:00.329+10:00I----- thread(2) trace.pd.ivc.ira:7 /project/am610/build/am61
0/src/ivrgy/ira_entry.c:2879: ira_ldap_search_ext_s() base: SECAUTHORITY=DEFAULT scope: 2
filter: (secDomainId=Default%scotte)
2007-03-09-14:31:00.329+10:00I----- thread(2) trace.pd.ivc.ira:7 /project/am610/build/am61
0/src/ivrgy/ira_ldap.c:3009: ira_ldap_search_ext_s(): No timeout - calling ldap_search_ext
_s
2007-03-09-14:31:00.331+10:00I----- thread(2) trace.pd.ivc.ira:7 /project/am610/build/am61
0/src/ivrgy/ira_ldap.c:3029: ira_ldap_search_ext_s: Returning LDAP rc x0
...
2007-03-09-14:31:00.332+10:00I----- thread(2) trace.pd.ivc.ira:8 /project/am610/build/am61
0/src/ivrgy/ira_auth.c:1738: CII ENTRY: ira_authenticate_user3() parm: cn=Scott Exton,o=ib
m,c=au
...
2007-03-09-14:31:00.334+10:00I----- thread(2) trace.pd.ivc.ira:8 /project/am610/build/am61
0/src/ivrgy/ira_auth.c:1596: CII EXIT ira_auth_passwd_compare() with status: 0x00000000
...
2007-03-09-14:31:00.334+10:00I----- thread(2) trace.pd.ivc.ira:8 /project/am610/build/am61
0/src/ivrgy/ira_cache.c:1588: CII EXIT ira_cache_user_get_account_state() with status: 0x
00000000
...
2007-03-09-14:31:00.340+10:00I----- thread(2) trace.pd.ivc.ira:8 /project/am610/build/am61
0/src/ivrgy/ira_auth.c:2160: CII EXIT ira_authenticate_user3() with status: 0x00000000
...
|
This section outlines some of the trace components supported by WebSEAL.
The pdweb.debug component is used to trace the HTTP headers sent between the client and WebSEAL. This includes the headers contained within the request, as well as the response. The following sample output shows the headers that are passed between WebSEAL and a Mozilla client for a single request. To trace the message body as well as the headers, refer to the section titled “pdweb.snoop trace” below.
Listing 6. Example pdweb.debug output
2007-03-09-15:59:43.381+10:00I----- thread(3) trace.pdweb.debug:2 /project/amweb600/build/
amweb600/src/pdweb/webseald/ras/trace/debug_log.cpp:134: ----------------- Browser ===> PD
-----------------
Thread_ID:35384240
GET / HTTP/1.1
accept: text/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8;q=0.5
accept-encoding: gzip,deflate
accept-language: en-us,en;q=0.5
authorization:*******************************
connection: keep-alive
host: webpi.vwasp.gc.au.ibm.com:8443
keep-alive: 300
user-agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1.2) Gecko/20070220 Firefox
accept-charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
cache-control: no-cache
pragma: no-cache
Cookie: w3ibmProfile=200508042136420894-553226052|gASP|616|616|en; s_nr=1158564023064; IBM
ISP=e70885cd950911d9a3a7ed228d15f2c0-e70885cd950911d9a3a7ed228d15f2c0-f887f6433223bf1363af
6c84803c14a5; WLS_ibmintra_USERID=scotte@au1.ibm.com; PDWPI-SESSION-COOKIE=gMcBnf-N2xGZ3QA
MKenDWA==7i4b7vopVjuQrK7o2H47cY7EbIo0gk-0cREsQF2Fo0o=; PD-S-SESSION-ID=2_mbgnxIxfGMI0VYdyO
PBYXZXA+wbils2WGPn7-7oE-1t6wd3H
---------------------------------------------------
2007-03-09-15:59:43.440+10:00I----- thread(3) trace.pdweb.debug:2 /project/amweb600/build
/amweb600/src/pdweb/webseald/ras/trace/debug_log.cpp:178: ----------------- Browser +=== P
D -----------------
Thread_ID:35384240
HTTP/1.1 200 OK
content-length: 381
content-type: text/html
date: Fri, 09 Mar 2007 05:59:43 GMT
last-modified: Fri, 09 Mar 2007 05:58:27 GMT
p3p: CP="NON CUR OTPi OUR NOR UNI"
server: WebSEAL/6.0.0.3 (Build 060807)
Set-Cookie: PD-S-SESSION-ID=2_pWKdWf7wKm5De0xC9OvHXfXEo0ucDlt4fohCij-P+jzCscFk; Path=/; Se
cure
---------------------------------------------------
|
The pdweb.snoop.client component is used trace the HTTP packets which are transmitted between WebSEAL and the client. The following sample output shows a single request from a client, and the associated response from WebSEAL. Both the ASCII and Hexadecimal representations of the packets are logged.
Listing 7. Example pdweb.snoop.client output
2007-03-09-16:08:50.180+10:00I----- thread(3) trace.pdweb.snoop.client:1 /project/amwebrte
610/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:112:
----------------------------------------
Thread 42494896; fd 6; local ::ffff:10.251.140.29:8443; remote ::ffff:10.251.140.1:60110
Socket opened.
----------------------------------------
2007-03-09-16:08:50.208+10:00I----- thread(4) trace.pdweb.snoop.client:1 /project/amwebrte
610/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:145:
----------------------------------------
Thread 28593072; fd 6; local ::ffff:10.251.140.29:8443; remote ::ffff:10.251.140.1:60110
Receiving 239 bytes
0x0000 4745 5420 2f20 4854 5450 2f31 2e31 0d0a GET./.HTTP/1.1..
0x0010 4175 7468 6f72 697a 6174 696f 6e3a 2042 Authorization:.B
0x0020 6173 6963 2063 324e 7664 4852 6c4f 6e42 asic.c2NvdHRlOnB
0x0030 6863 334e 3362 334a 6b4d 513d 3d0d 0a55 hc3N3b3JkMQ==..U
0x0040 7365 722d 4167 656e 743a 2063 7572 6c2f ser-Agent:.curl/
0x0050 372e 3132 2e31 2028 6933 3836 2d72 6564 7.12.1.(i386-red
0x0060 6861 742d 6c69 6e75 782d 676e 7529 206c hat-linux-gnu).l
0x0070 6962 6375 726c 2f37 2e31 322e 3120 4f70 ibcurl/7.12.1.Op
0x0080 656e 5353 4c2f 302e 392e 3761 207a 6c69 enSSL/0.9.7a.zli
0x0090 622f 312e 322e 312e 3220 6c69 6269 646e b/1.2.1.2.libidn
0x00a0 2f30 2e35 2e36 0d0a 486f 7374 3a20 7765 /0.5.6..Host:.we
0x00b0 6270 692e 7677 6173 702e 6763 2e61 752e bpi.vwasp.gc.au.
0x00c0 6962 6d2e 636f 6d3a 3834 3433 0d0a 5072 ibm.com:8443..Pr
0x00d0 6167 6d61 3a20 6e6f 2d63 6163 6865 0d0a agma:.no-cache..
0x00e0 4163 6365 7074 3a20 2a2f 2a0d 0a0d 0a Accept:.*/*....
----------------------------------------
2007-03-09-16:08:50.251+10:00I----- thread(4) trace.pdweb.snoop.client:1 /project/amwebrte
610/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:171:
----------------------------------------
Thread 28593072; fd 6; local ::ffff:10.251.140.29:8443; remote ::ffff:10.251.140.1:60110
Sending 470 bytes
0x0000 4854 5450 2f31 2e31 2032 3030 204f 4b0d HTTP/1.1.200.OK.
0x0010 0a63 6f6e 7465 6e74 2d6c 656e 6774 683a .content-length:
0x0020 2031 3530 0d0a 636f 6e74 656e 742d 7479 .150..content-ty
0x0030 7065 3a20 7465 7874 2f68 746d 6c0d 0a64 pe:.text/html..d
0x0040 6174 653a 2046 7269 2c20 3039 204d 6172 ate:.Fri,.09.Mar
0x0050 2032 3030 3720 3036 3a30 383a 3530 2047 .2007.06:08:50.G
0x0060 4d54 0d0a 6c61 7374 2d6d 6f64 6966 6965 MT..last-modifie
0x0070 643a 2046 7269 2c20 3039 204d 6172 2032 d:.Fri,.09.Mar.2
0x0080 3030 3720 3036 3a30 383a 3332 2047 4d54 007.06:08:32.GMT
0x0090 0d0a 7033 703a 2043 503d 224e 4f4e 2043 ..p3p:.CP="NON.C
0x00a0 5552 204f 5450 6920 4f55 5220 4e4f 5220 UR.OTPi.OUR.NOR.
0x00b0 554e 4922 0d0a 7365 7276 6572 3a20 5765 UNI"..server:.We
0x00c0 6253 4541 4c2f 362e 302e 302e 3320 2842 bSEAL/6.0.0.3.(B
0x00d0 7569 6c64 2030 3630 3830 3729 0d0a 5365 uild.060807)..Se
0x00e0 742d 436f 6f6b 6965 3a20 5044 2d53 2d53 t-Cookie:.PD-S-S
0x00f0 4553 5349 4f4e 2d49 443d 325f 6347 6a2d ESSION-ID=2_cGj-
0x0100 4234 5655 7247 7245 7930 4c4a 4143 722d B4VUrGrEy0LJACr-
0x0110 472b 5a6d 334a 3941 6267 5843 302b 7758 G+Zm3J9AbgXC0+wX
0x0120 6351 476b 4c31 6e35 4b42 5857 3b20 5061 cQGkL1n5KBXW;.Pa
0x0130 7468 3d2f 3b20 5365 6375 7265 0d0a 0d0a th=/;.Secure....
0x0140 3c68 746d 6c3e 0a3c 6865 6164 3e0a 3c6d .html>..head>..m
0x0150 6574 6120 6874 7470 2d65 7175 6976 3d22 eta.http-equiv="
0x0160 436f 6e74 656e 742d 5479 7065 2220 636f Content-Type".co
0x0170 6e74 656e 743d 2274 6578 742f 6874 6d6c ntent="text/html
0x0180 3b20 6368 6172 7365 743d 5554 462d 3822 ;.charset=UTF-8"
0x0190 3e0a 3c2f 6865 6164 3e0a 3c62 6f64 793e >../head>..body>
0x01a0 0a54 6869 7320 6973 2061 2073 696d 706c .This.is.a.simpl
0x01b0 6520 5765 6253 4541 4c20 7465 7374 2070 e.WebSEAL.test.p
0x01c0 6167 652e 0a3c 2f62 6f64 793e 0a3c 2f68 age.../body>../h
0x01d0 746d 6c3e 0a0a tml>..
----------------------------------------
2007-03-09-16:08:50.252+10:00I----- thread(4) trace.pdweb.snoop.client:1 /project/amwebrte
610/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:112:
----------------------------------------
Thread 28593072; fd 6; local ::ffff:10.251.140.29:8443; remote ::ffff:10.251.140.1:60110
Wrote 470 bytes
----------------------------------------
|
The pdweb.snoop.jct component is used trace the HTTP packets that are transmitted between WebSEAL and the junctioned back-end Web server. The following sample output shows a single request from WebSEAL, and the associated response from the back-end Web server. Both the ASCII and Hexadecimal representations of the packets are logged.
Listing 8. Example pdweb.snoop.jct output
2007-03-09-16:28:48.644+10:00I----- thread(7) trace.pdweb.snoop.jct:1 /project/amwebrte610
/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:112:
----------------------------------------
Thread 53009328; fd 15; local 10.251.140.29:35441; remote 192.168.115.51:80
Socket opened.
----------------------------------------
2007-03-09-16:28:48.644+10:00I----- thread(7) trace.pdweb.snoop.jct:1 /project/amwebrte610
/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:171:
----------------------------------------
Thread 53009328; fd 15; local 10.251.140.29:35441; remote 192.168.115.51:80
Sending 317 bytes
0x0000 4745 5420 2f77 6562 7365 616c 2e68 746d GET./webseal.htm
0x0010 6c20 4854 5450 2f31 2e31 0d0a 6163 6365 l.HTTP/1.1..acce
0x0020 7074 3a20 2a2f 2a0d 0a63 6f6e 6e65 6374 pt:.*/*..connect
0x0030 696f 6e3a 2063 6c6f 7365 0d0a 686f 7374 ion:.close..host
0x0040 3a20 7761 7370 2e67 632e 6175 2e69 626d :.wasp.gc.au.ibm
0x0050 2e63 6f6d 0d0a 7573 6572 2d61 6765 6e74 .com..user-agent
0x0060 3a20 6375 726c 2f37 2e31 322e 3120 2869 :.curl/7.12.1.(i
0x0070 3338 362d 7265 6468 6174 2d6c 696e 7578 386-redhat-linux
0x0080 2d67 6e75 2920 6c69 6263 7572 6c2f 372e -gnu).libcurl/7.
0x0090 3132 2e31 204f 7065 6e53 534c 2f30 2e39 12.1.OpenSSL/0.9
0x00a0 2e37 6120 7a6c 6962 2f31 2e32 2e31 2e32 .7a.zlib/1.2.1.2
0x00b0 206c 6962 6964 6e2f 302e 352e 360d 0a76 .libidn/0.5.6..v
0x00c0 6961 3a20 4854 5450 2f31 2e31 2077 6562 ia:.HTTP/1.1.web
0x00d0 7069 2e76 7761 7370 2e67 632e 6175 2e69 pi.vwasp.gc.au.i
0x00e0 626d 2e63 6f6d 3a38 3434 330d 0a69 765f bm.com:8443..iv_
0x00f0 7365 7276 6572 5f6e 616d 653a 2064 6566 server_name:.def
0x0100 6175 6c74 2d77 6562 7365 616c 642d 7765 ault-webseald-we
0x0110 6270 692e 7677 6173 702e 6763 2e61 752e bpi.vwasp.gc.au.
0x0120 6962 6d2e 636f 6d0d 0a70 7261 676d 613a ibm.com..pragma:
0x0130 206e 6f2d 6361 6368 650d 0a0d 0a .no-cache....
----------------------------------------
2007-03-09-16:28:48.646+10:00I----- thread(7) trace.pdweb.snoop.jct:1 /project/amwebrte610
/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:112:
----------------------------------------
Thread 53009328; fd 15; local 10.251.140.29:35441; remote 192.168.115.51:80
Wrote 317 bytes
----------------------------------------
2007-03-09-16:28:48.648+10:00I----- thread(7) trace.pdweb.snoop.jct:1 /project/amwebrte610
/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:145:
----------------------------------------
Thread 53009328; fd 15; local 10.251.140.29:35441; remote 192.168.115.51:80
Receiving 412 bytes
0x0000 4854 5450 2f31 2e31 2032 3030 204f 4b0d HTTP/1.1.200.OK.
0x0010 0a44 6174 653a 2046 7269 2c20 3039 204d .Date:.Fri,.09.M
0x0020 6172 2032 3030 3720 3036 3a31 383a 3336 ar.2007.06:18:36
0x0030 2047 4d54 0d0a 5365 7276 6572 3a20 4170 .GMT..Server:.Ap
0x0040 6163 6865 2f32 2e30 2e35 3220 2852 6564 ache/2.0.52.(Red
0x0050 2048 6174 290d 0a4c 6173 742d 4d6f 6469 .Hat)..Last-Modi
0x0060 6669 6564 3a20 4672 692c 2030 3920 4d61 fied:.Fri,.09.Ma
0x0070 7220 3230 3037 2030 363a 3138 3a30 3520 r.2007.06:18:05.
0x0080 474d 540d 0a45 5461 673a 2022 3139 6330 GMT..ETag:."19c0
0x0090 3934 2d39 332d 3632 6631 3831 3430 220d 94-93-62f18140".
0x00a0 0a41 6363 6570 742d 5261 6e67 6573 3a20 .Accept-Ranges:.
0x00b0 6279 7465 730d 0a43 6f6e 7465 6e74 2d4c bytes..Content-L
0x00c0 656e 6774 683a 2031 3437 0d0a 436f 6e6e ength:.147..Conn
0x00d0 6563 7469 6f6e 3a20 636c 6f73 650d 0a43 ection:.close..C
0x00e0 6f6e 7465 6e74 2d54 7970 653a 2074 6578 ontent-Type:.tex
0x00f0 742f 6874 6d6c 3b20 6368 6172 7365 743d t/html;.charset=
0x0100 5554 462d 380d 0a0d 0a3c 6874 6d6c 3e0a UTF-8.....html>.
0x0110 3c68 6561 643e 0a3c 6d65 7461 2068 7474 .head>..meta.htt
0x0120 702d 6571 7569 763d 2243 6f6e 7465 6e74 p-equiv="Content
0x0130 2d54 7970 6522 2063 6f6e 7465 6e74 3d22 -Type".content="
0x0140 7465 7874 2f68 746d 6c3b 2063 6861 7273 text/html;.chars
0x0150 6574 3d55 5446 2d38 223e 0a3c 2f68 6561 et=UTF-8">../hea
0x0160 643e 0a3c 626f 6479 3e0a 5468 6973 2069 d>..body>.This.i
0x0170 7320 6120 7369 6d70 6c65 2048 544d 4c20 s.a.simple.HTML.
0x0180 7465 7374 2070 6167 652e 0a3c 2f62 6f64 test.page.../bod
0x0190 793e 0a3c 2f68 746d 6c3e 0a0a y>../html>..
----------------------------------------
2007-03-09-16:28:48.650+10:00I----- thread(7) trace.pdweb.snoop.jct:1 /project/amwebrte610
/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:112:
----------------------------------------
Thread 53009328; fd 15; local 10.251.140.29:35441; remote 192.168.115.51:80
Shutting down read.
----------------------------------------
2007-03-09-16:28:48.650+10:00I----- thread(7) trace.pdweb.snoop.jct:1 /project/amwebrte610
/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:112:
----------------------------------------
Thread 53009328; fd 15; local 10.251.140.29:35441; remote 192.168.115.51:80
Shutting down write.
----------------------------------------
2007-03-09-16:28:48.650+10:00I----- thread(7) trace.pdweb.snoop.jct:1 /project/amwebrte610
/build/amwebrte610/src/pdwebrte/webcore/amw_snoop.cpp:112:
----------------------------------------
Thread 53009328; fd 15; local 10.251.140.29:35441; remote .error getting peer name for 15:
Transport endpoint is not connected>
Closing socket.
----------------------------------------
|
The pdweb.wan.azn component is used to trace the authorization decision for all transactions. This includes details related to the credential upon which the authorization decision is made, the resource that is being accessed, as well as the result of the authorization decision. The following sample output is an extract of the trace which is produced from a single authorization decision.
Listing 9. Example pdweb.wan.azn output (extract)
...
2007-03-09-16:12:35.195+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:95: [10.251.140.1] Dumping attrlist: creds
2007-03-09-16:12:35.195+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AUTHENTICATI
ON_LEVEL , Value: 1
2007-03-09-16:12:35.195+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_AUT
HNMECH_INFO , Value: LDAP Registry
2007-03-09-16:12:35.195+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_AUT
HZN_ID , Value: cn=Scott Exton,o=ibm,c=au
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_AUT
H_METHOD , Value: password
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_BRO
WSER_INFO , Value: curl/7.12.1 (i386-redhat-linux-gnu) libcurl/7.12.1 OpenSSL/0.9.7a zlib/
1.2.1.2 libidn/0.5.6
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_IP_
FAMILY , Value: AF_INET
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_MEC
H_ID , Value: IV_LDAP_V3.0
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_NET
WORK_ADDRESS_BIN , Value: 0x0afb8c01
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_NET
WORK_ADDRESS_STR , Value: 10.251.140.1
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_PRI
NCIPAL_DOMAIN , Value: Default
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_PRI
NCIPAL_NAME , Value: scotte
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_PRI
NCIPAL_UUID , Value: ad987b08-cdf4-11db-a51a-000c29e9c358
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_QOP
_INFO , Value: SSK: TLSV1: 35
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_REG
ISTRY_ID , Value: cn=Scott Exton,o=ibm,c=au
2007-03-09-16:12:35.196+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_USE
R_INFO , Value:
2007-03-09-16:12:35.197+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:AZN_CRED_VER
SION , Value: 0x00000600
2007-03-09-16:12:35.197+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:tagvalue_log
in_user_name , Value: scotte
2007-03-09-16:12:35.197+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:117: [10.251.140.1] Attr Name:tagvalue_ses
sion_index , Value: 2c5bfdba-ce05-11db-bba0-000c29e9c358
...
2007-03-09-16:12:35.197+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:233: [10.251.140.1] INPUTS - protected_res
ource=/WebSEAL/webpi.vwasp.gc.au.ibm.com-default/index.html, operation=r
...
2007-03-09-16:12:35.198+10:00I----- thread(5) trace.pdweb.wan.azn:9 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:254: [10.251.140.1] OUTPUT - permission=0
...
2007-03-09-16:12:35.198+10:00I----- thread(5) trace.pdweb.wan.azn:8 /project/amwebrte610/b
uild/amwebrte610/src/pdwebrte/webcore/amw_azn.c:261: [10.251.140.1] CII EXIT amw_azn_decis
ion_access_allowed_ext with status=0x00000000
|
The pdweb.wns.authn component is used to trace details concerning the authentication process applied by WebSEAL. This includes information such as the authentication mechanism, the details used during the authentication process, and the result of the authentication. The following sample output is an extract of the trace which is produced from a single authentication operation.
Listing 10. Example pdweb.wns.authn output (extract)
...
2007-03-09-16:18:38.594+10:00I----- thread(3) trace.pdweb.wns.authn:8 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/authn/framework/authn-doauth.cpp:1241: [10.251.140.1] CII
ENTER doBAAuth
2007-03-09-16:18:38.594+10:00I----- thread(3) trace.pdweb.wns.authn:8 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/authn/framework/authn-getcreds.cpp:209: [10.251.140.1] CII
ENTER get_user_pwd_cred
2007-03-09-16:18:38.594+10:00I----- thread(3) trace.pdweb.wns.authn:9 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/authn/framework/authn-getcreds.cpp:215: [10.251.140.1] Par
ameters - username: scotte, auth_type: 32, existing_creds: 0
...
2007-03-09-16:18:38.622+10:00I----- thread(3) trace.pdweb.wns.authn:6 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/authn/framework/authn-doauth.cpp:1737: [10.251.140.1] CEI
EXIT doAuthentication with status: 0x00000000
...
2007-03-09-16:18:38.622+10:00I----- thread(3) trace.pdweb.wns.authn:8 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/authn/framework/authn-cred.cpp:568: [10.251.140.1] CII EXI
T get_user_name with name: scotte
...
2007-03-09-16:18:38.623+10:00I----- thread(3) trace.pdweb.wns.authn:9 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/authn/framework/authn-main.cpp:422: [10.251.140.1] Paramet
ers - valid_sess_types=2, auth_type_used=32, azn_username=scotte
...
2007-03-09-16:18:38.623+10:00I----- thread(3) trace.pdweb.wns.authn:9 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/authn/framework/authn-main.cpp:144: [10.251.140.1] Creatin
g new cookie session
...
2007-03-09-16:18:38.652+10:00I----- thread(3) trace.pdweb.wns.authn:6 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/credscache/WSCredsCacheEntry.cpp:512: [10.251.140.1] ENTER
WSCredsCacheEntry::getNewEntry
...
2007-03-09-16:18:38.652+10:00I----- thread(3) trace.pdweb.wns.authn:9 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/credscache/WSCredsCacheEntry.cpp:2126: [10.251.140.1] WSCr
edsCacheEntry::getCreateTime = 1173421118
2007-03-09-16:18:38.652+10:00I----- thread(3) trace.pdweb.wns.authn:9 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/credscache/WSCredsCacheEntry.cpp:2090: [10.251.140.1] WSCr
edsCacheEntry::setLifetimeTimeout = 1173424718
2007-03-09-16:18:38.653+10:00I----- thread(3) trace.pdweb.wns.authn:9 /project/amweb600/bu
ild/amweb600/src/pdweb/webseald/credscache/WSCredsCacheEntry.cpp:977: [10.251.140.1] WSCre
dsCacheEntry::setLastUserName scotte
...
|
Plug-in for Web Servers trace components
This section outlines some of the trace components supported by Plug-in for Web Servers.
The pdwebpi.azn component is used to trace the authorization decision for all transactions. This includes details related to the credential upon which the authorization decision is made, the resource that is being accessed, as well as the result of the authorization decision. The following sample output shows the information which is traced for a single authorization decision.
Listing 11. Example pdwebpi.azn output
2007-03-09-14:57:09.587+10:00I----- thread(2) trace.pdwebpi.azn:5 /mnt/amraid/TAMDev/sandb
oxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/rh/WPIVirtualHost.cpp:1729: [webp
i.vwasp.gc.au.ibm.com] [10.251.140.1] Testing [PDWebPI]r permission on /PDWebPI/webpi.vwas
p.gc.au.ibm.com for user scotte
2007-03-09-14:57:09.588+10:00I----- thread(2) trace.pdwebpi.azn:2 /mnt/amraid/TAMDev/sandb
oxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/rh/WPIVirtualHost.cpp:1515: [webp
i.vwasp.gc.au.ibm.com] [10.251.140.1] Authorization decision:
Request: GET http://webpi.vwasp.gc.au.ibm.com/
Session: 5PnKH-rN2xGrqgAMKenDWA==
Username: scotte
Credential attributes:
AUTHENTICATION_LEVEL = 1
AZN_CRED_AUTHNMECH_INFO = LDAP Registry
AZN_CRED_AUTHZN_ID = cn=Scott Exton,o=ibm,c=au
AZN_CRED_AUTH_METHOD = password
AZN_CRED_BROWSER_INFO = Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1.2)
AZN_CRED_IP_FAMILY = AF_INET
AZN_CRED_MECH_ID = IV_LDAP_V3.0
AZN_CRED_NETWORK_ADDRESS_BIN = 0x0afb8c01
AZN_CRED_NETWORK_ADDRESS_STR = 10.251.140.1
AZN_CRED_PRINCIPAL_DOMAIN = Default
AZN_CRED_PRINCIPAL_NAME = scotte
AZN_CRED_PRINCIPAL_UUID = ad987b08-cdf4-11db-a51a-000c29e9c358
AZN_CRED_QOP_INFO = None
AZN_CRED_REGISTRY_ID = cn=Scott Exton,o=ibm,c=au
AZN_CRED_USER_INFO =
AZN_CRED_VERSION = 0x00000600
Object: /PDWebPI/webpi.vwasp.gc.au.ibm.com
Action: [PDWebPI]r
Input attributes:
-null-
Result: GRANTED
Output attributes:
-null-
2007-03-09-14:57:09.588+10:00I----- thread(2) trace.pdwebpi.azn:5 /mnt/amraid/TAMDev/sandb
oxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/rh/WPIVirtualHost.cpp:1740: [webp
i.vwasp.gc.au.ibm.com] [10.251.140.1] [PDWebPI]r permission to /PDWebPI/webpi.vwasp.gc.au.
ibm.com for user scotte GRANTED
|
The Plug-in for Web Servers architecture is comprised of two main components, the plug-in component and the proxy component. The plug-in component resides within the hosting Web server itself and is used to communicate with the Web server. The proxy component runs as a separate process on the system and controls all of the authorization and authentication processing for a request. The proxy component exerts control over the HTTP request and response through the use of 'commands'. These commands are passed to the plug-in component, which in turn communicates these commands to the hosting Web server. The following diagrams illustrate this architecture.
Figure 2. PDWebPI architecture
The pdwebpi.proxy-cmd trace component can be used to examine these commands, and from this an administrator can derive what the proxy component is instructing the Web server to do with each request. The following trace illustrates the commands, which might be sent to the hosting Web server for a standard request. The commands listed include instructions on removing certain headers from the request, as well as setting a new session cookie. The final command is used to instruct the Web server whether to allow the request to proceed, or whether to deny the request.
Listing 12. Example pdwebpi.proxy-cmd output
2007-03-09-15:17:21.462+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:5 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:63: [] =============== New Request ==========================
2007-03-09-15:17:21.486+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:5 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:136: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] cmd(wpi_req_set_web_log_user): [0
] scotte [1] - [2] %25t
2007-03-09-15:17:21.487+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:5 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:136: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] cmd(wpi_req_remove_header): Autho
rization
2007-03-09-15:17:21.487+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:5 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:136: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] cmd(wpi_req_remove_header): If-Mo
dified-Since
2007-03-09-15:17:21.487+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:5 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:136: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] cmd(wpi_req_remove_header): If-Ma
tch
2007-03-09-15:17:21.487+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:5 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:136: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] cmd(wpi_req_remove_header): If-No
ne-Match
2007-03-09-15:17:21.487+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:5 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:136: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] cmd(wpi_req_remove_header): If-Ra
nge
2007-03-09-15:17:21.487+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:5 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:136: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] cmd(wpi_req_remove_header): If-Un
modified-Since
2007-03-09-15:17:21.487+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:5 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:136: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] cmd(wpi_req_set_header): Name: Co
okie - Value: w3ibmProfile=200508042136420894-553226052|gASP|616|616|en;%20s_nr=1158564023
064;%20IBMISP=e70885cd950911d9a3a7ed228d15f2c0-e70885cd950911d9a3a7ed228d15f2c0-f887f64332
23bf1363af6c84803c14a5;%20WLS_ibmintra_USERID=scotte@au1.ibm.com;%20PDWPI-SESSION-COOKIE=J
Es7df3N2xGFrAAMKenDWA==ccIA46Br5bT05GRy30wBTKtAihAJi6zKRTeYSLb1MBA=
2007-03-09-15:17:21.487+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:5 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:136: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] cmd(wpi_rsp_add_header): Name: Se
t-Cookie - Value: PDWPI-SESSION-COOKIE=JEs7df3N2xGFrAAMKenDWA==ccIA46Br5bT05GRy30wBTKtAihA
Ji6zKRTeYSLb1MBA=;%20Path=/
2007-03-09-15:17:21.487+10:00I----- thread(2) trace.pdwebpi.proxy-cmd:4 /mnt/amraid/TAMDev
/sandboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/msg/proxy/WPIWebTransAnswerMarsha
ller.cpp:267: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] response code: wpi_continue
|
The pdwebpi.request component is used to trace the HTTP requests that are received by the system. If a trace level of 2 is specified, only the requested URL and HTTP method will be traced. If a trace level of 9 is specified, the entire HTTP request will be traced. The following sample output shows the information that is traced for a single HTTP request.
Listing 13. Example pdwebpi.request output
2007-03-09-15:26:40.751+10:00I----- thread(2) trace.pdwebpi.request:2 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/rh/WPIProxyRequestHandler.cpp
:442: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] Handling request: GET http://webpi.vwasp.
gc.au.ibm.com/
2007-03-09-15:26:40.751+10:00I----- thread(2) trace.pdwebpi.request:9 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/rh/WPIProxyRequestHandler.cpp
:496: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] HTTP request buffer [812 bytes]:
GET / HTTP/1.1
Host: webpi.vwasp.gc.au.ibm.com
User-Agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1.2) Gecko/20070220 Firefox
Accept: text/xml,application/xhtml+xml,text/html;q=0.9,text/plain;*/*;q=0.5
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive
Cookie: w3ibmProfile=200508042136420894-553226052|gASP|616|616|en; s_nr=1158564023064; IBM
ISP=e70885cd950911d9a3a7ed228d15f2c0-e70885cd950911d9a3a7ed228d15f2c0-f887f6433223bf1363af
6c84803c14a5; WLS_ibmintra_USERID=scotte@au1.ibm.com; PDWPI-SESSION-COOKIE=JEs7df3N2xGFrAA
MKenDWA==ccIA46Br5bT05GRy30wBTKtAihAJi6zKRTeYSLb1MBA=
Authorization: Basic c2NvdHRlOnBhc3N3b3JkMQ==
Pragma: no-cache
Cache-Control: no-cache
|
The pdwebpi.session component is used to trace details pertaining to a user's session. In particular, it will trace the contents of the user's session along with session expiration details and any changes that might be made to a user's session. The contents of the session itself will be traced whenever it is retrieved from the session cache (that is, on each HTTP request). The following sample output shows the information that is traced whenever a new session is created.
Listing 14. Example pdwebpi.session output
2007-03-09-15:32:47.205+10:00I----- thread(2) trace.pdwebpi.session:8 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:650: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::setAuthType - 4241
2007-03-09-15:32:47.209+10:00I----- thread(2) trace.pdwebpi.session:3 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:1779: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::addAuthenticationData - No
authentication level set by CDAS
2007-03-09-15:32:47.209+10:00I----- thread(2) trace.pdwebpi.session:3 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:1833: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::addAuthenticationData Settin
g authentication level to 1
2007-03-09-15:32:47.209+10:00I----- thread(2) trace.pdwebpi.session:3 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:1981: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::addAuthenticationData - addi
ng user session info UERXZWJQSS13ZWJwaS52d2FzcC5nYy5hdS5pYm0uY29t_gMcBnf-N2xGZ3QAMKenDWA==
2007-03-09-15:32:47.209+10:00I----- thread(2) trace.pdwebpi.session:8 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:626: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::setAuthModuleName - BA
2007-03-09-15:32:47.209+10:00I----- thread(2) trace.pdwebpi.session:8 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:599: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::setAuthModuleID - 1
2007-03-09-15:32:47.210+10:00I----- thread(2) trace.pdwebpi.session:8 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:352: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::getIdleTimeout - 0
2007-03-09-15:32:47.210+10:00I----- thread(2) trace.pdwebpi.session:8 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:368: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::setIdleTimeout - 600
2007-03-09-15:32:47.210+10:00I----- thread(2) trace.pdwebpi.session:8 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:378: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::getLifetimeTimeout - 0
2007-03-09-15:32:47.210+10:00I----- thread(2) trace.pdwebpi.session:8 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:394: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::setLifetimeTimeout - 11734219
67
2007-03-09-15:32:47.210+10:00I----- thread(2) trace.pdwebpi.session:7 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:309: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1] WPISession::lock - new expiration time -
1173418967
2007-03-09-15:32:47.211+10:00I----- thread(2) trace.pdwebpi.session:7 /mnt/amraid/TAMDev/s
andboxes/amwebpi/nightly/amwebpi610.061205/src/pdwebpi/proxy/module/session/WPISession.cpp
:2049: [webpi.vwasp.gc.au.ibm.com] [10.251.140.1]
========================================
Session (0x9E6CAEC): scotte
Session Data: eb - sms (has changed)
com.tivoli.am.webpi.session.auth-type = 0x4241
com.tivoli.am.eb.auth-type = basicAuthRFC2617
com.tivoli.am.eb.credential = BAKs3DCCA/EMADCCA+swggPnAgIGADAsMCgwHgIErZh7CAIDAM30AgIR2
wICAKUCARoEBgAMKenDWAwGc2NvdHRlMAACAQEwggOuMIIDqjAiDBRBVVRIRU5USUNBVElPTl9MRVZFTDAKMAgC
AQQMATEEADAxDBdBWk5fQ1JFRF9BVVRITk1FQ0hfSU5GTzAWMBQCAQQMDUxEQVAgUmVnaXN0cnkEADA4DBJBWk5
fQ1JFRF9BVVRIWk5fSUQwIjAgAgEEDBljbj1TY290dCBFeHRvbixvPWlibSxjPWF1BAAwKQwUQVpOX0NSRURfQV
VUSF9NRVRIT0QwETAPAgEEDAhwYXNzd29yZAQAMHQMFUFaTl9DUkVEX0JST1dTRVJfSU5GTzBbMFkCAQQMUk1ve
mlsbGEvNS4wIChYMTE7IFU7IExpbnV4IGk2ODY7IGVuLVVTOyBydjoxLjguMS4yKSBHZWNrby8yMDA3MDIyMCBG
aXJlZm94LzIuMC4wLjIEADAmDBJBWk5fQ1JFRF9JUF9GQU1JTFkwEDAOAgEEDAdBRl9JTkVUBAAwKQwQQVpOX0N
SRURfTUVDSF9JRDAVMBMCAQQMDElWX0xEQVBfVjMuMAQAMDMMHEFaTl9DUkVEX05FVFdPUktfQUREUkVTU19CSU
4wEzARAgEEDAoweDBhZmI4YzAxBAAwNQwcQVpOX0NSRURfTkVUV09SS19BRERSRVNTX1NUUjAVMBMCAQQMDDEwL
jI1MS4xNDAuMQQAMC0MGUFaTl9DUkVEX1BSSU5DSVBBTF9ET01BSU4wEDAOAgEEDAdEZWZhdWx0BAAwKgwXQVpO
X0NSRURfUFJJTkNJUEFMX05BTUUwDzANAgEEDAZzY290dGUEADBIDBdBWk5fQ1JFRF9QUklOQ0lQQUxfVVVJRDA
tMCsCAQQMJGFkOTg3YjA4LWNkZjQtMTFkYi1hNTFhLTAwMGMyOWU5YzM1OAQAMCIMEUFaTl9DUkVEX1FPUF9JTk
ZPMA0wCwIBBAwETm9uZQQAMDoMFEFaTl9DUkVEX1JFR0lTVFJZX0lEMCIwIAIBBAwZY249U2NvdHQgRXh0b24sb
z1pYm0sYz1hdQQAMB8MEkFaTl9DUkVEX1VTRVJfSU5GTzAJMAcCAQQMAAQAMCcMEEFaTl9DUkVEX1ZFUlNJT04w
EzARAgEEDAoweDAwMDAwNjAwBAAwaAwWdGFndmFsdWVfc2Vzc2lvbl9pbmRleDBOMEwCAQQMRVVFUlhaV0pRU1M
xM1pXSndhUzUyZDJGemNDNW5ZeTVoZFM1cFltMHVZMjl0X2dNY0JuZi1OMnhHWjNRQU1LZW5EV0E9PQQA
com.tivoli.am.eb.expiry = 0x45f0ff8f
Session Data: session - session (has changed)
com.tivoli.am.webpi.session.auth-module = com.tivoli.am.webpi.session.auth-module-id
com.tivoli.am.webpi.session.auth-module-id = 0x1
com.tivoli.am.webpi.session.term-audit-action = 0x67
com.tivoli.am.webpi.session.is-secondary = false
com.tivoli.am.sms.creation-time = 0x45f0f17f
com.tivoli.am.sms.session-index = gMcBnf-N2xGZ3QAMKenDWA==
com.tivoli.am.webpi.session.is-proxy = unknown
com.tivoli.am.webpi.session.no-logout = true
com.tivoli.am.webpi.session.prior-authn-level = 0x0
com.tivoli.am.webpi.session.primary-auth-module-id = 0x0
com.tivoli.am.webpi.session.logout-pwd-change = false
Session Data: trans - session (has changed)
com.tivoli.am.webpi.trans.reauth = false
com.tivoli.am.webpi.trans.reauth-grace-applied = false
com.tivoli.am.webpi.trans.restore-on-auth = true
com.tivoli.am.webpi.trans.reauth-reset-lifetime = false
com.tivoli.am.webpi.trans.is-initial-authn = true
com.tivoli.am.webpi.trans.authn-uri = /
com.tivoli.am.webpi.trans.mfa = 0x0
com.tivoli.am.webpi.trans.password-expired = false
com.tivoli.am.webpi.trans.post-auth-url =
com.tivoli.am.webpi.trans.can-be-terminated = true
Session Data: ba-authenticated - BA (has changed)
com.tivoli.am.webpi.ba-authenticated.header = Basic c2NvdHRlOnBhc3N3b3JkMQ==
Session Data: web-log - web-log
========================================
|
Learn
-
"
IBM Tivoli Access Manager Problem Determination Guide
" provides more information on the Tivoli Access Manager tracing, and how to enable the tracing.
-
An IBM Redbooks® publication on IBM Tivoli Access Manager is available.
-
Browse the technology bookstore for books on these and other technical topics.
Get products and technologies
-
Find out more about IBM Tivoli Access Manager.
Scott Exton is a development lead for the IBM Tivoli Access Manager product. He is currently responsible for the development of the Plug-in for Web Servers, and Session Management Server components. He joined IBM in Gold Coast Australia as a software engineer in 1997 and has been working on the IBM Tivoli Access Manager product since then. His undergraduate degree is in Business Computing from the Queensland University of Technology.
