Enable proxy debug

Turn on proxy debug by setting Debug="ALL" in the proxy configuration file.

Enable proxy bridge

Set DebugConfigInfo="ON" in the proxy configuration file.
Refer to General Parameters for Web Server Plug-Ins for details about these configuration parameters.
Both the above settings require restart of the web server.

Example configuration for the Sun Java System Web Server Plug-In (previously called the Netscape Enterprise Server plug-in or iPlanet/SunOne plug-in) (obj.conf):
<Object name="weblogic" ppath="*/mywebapp/*">
Service fn=wl-proxy\
WebLogicCluster="sol1:8001,sol2:8001,sol3:8003"\
Debug="ALL"\
DebugConfigInfo="ON"\
WLLogFile="/tmp/wlproxy.log"
</Object>
For configuration details, refer to Installing and Configuring the Sun Java System Web Server Plug-In.
Example configuration for Apache plug-in (httpd.conf):
<Location /mywebapp>
SetHandlerweblogic-handler
WebLogicCluster sol1:8001,sol2:8001,sol3:8003
Debug ALL
DebugConfigInfo ON
WLLogFile /tmp/wlproxy.log
</Location>
For configuration details, refer to Installing and Configuring the Apache HTTP Server Plug-In.
Example configuration for IIS plug-in (iisproxy.ini):
WebLogicCluster sol1:8001,sol2:8001,sol3:8003
Debug ALL
DebugConfigInfo ON
WLLogFile C:\temp\wlproxy.log
For configuration details, refer to Installing and Configuring the Microsoft IIS Plug-In


Analyzing the Proxy Log File

Below is an example of a request (with session cookie) processed by plug-in and the log messages that it generates. There are four distinct phases between receiving a new request and returning the response:
  • Receiving a new request dispatched by WebServer, parsing request headers and session cookie (if present)
  • Connecting to a WebLogic server node and forwarding the request
  • Reading the response from WebLogic server node
  • Writing the response back to the client
Wed Oct 27 15:03:16 2010 <4468128817199630>
================New Request: [GET /browsestore/ HTTP/1.1] =================
Wed Oct 27 15:03:16 2010 <4468128817199630> INFO: SSL is not configured
Wed Oct 27 15:03:16 2010 <4468128817199630> Using Uri /browsestore/
Wed Oct 27 15:03:16 2010 <4468128817199630> After trimming path: '/browsestore/'
Wed Oct 27 15:03:16 2010 <4468128817199630> The final request string is '/browsestore/'
Wed Oct 27 15:03:16 2010 <4468128817199630> SEARCHING id=[10.177.57.202:7003,10.177.57.203:7001] from current ID=[10.177.57.202:7003,10.177.57.203:7001]
Wed Oct 27 15:03:16 2010 <4468128817199630> The two ids matched
Wed Oct 27 15:03:16 2010 <4468128817199630> @@@FOUND...id=[10.177.57.202:7003,10.177.57.203:7001], server_name=[localhost], server_port=[80]
Wed Oct 27 15:03:16 2010 <4468128817199630> getPreferred: availcookie=[JSESSIONID=bTwRMHSZG9Lhf1H2cJqr93W0bgqKRbRwGxYk4pGh0jcCzfB70vfh!-858027425!-2126611057]
Wed Oct 27 15:03:16 2010 <4468128817199630> Found cookie from cookie header: JSESSIONID=bTwRMHSZG9Lhf1H2cJqr93W0bgqKRbRwGxYk4pGh0jcCzfB70vfh!-858027425!-2126611057
Wed Oct 27 15:03:16 2010 <4468128817199630> Parsing cookie JSESSIONID=bTwRMHSZG9Lhf1H2cJqr93W0bgqKRbRwGxYk4pGh0jcCzfB70vfh!-858027425!-2126611057
Wed Oct 27 15:03:16 2010 <4468128817199630> getpreferredServersFromCookie: [-858027425!-2126611057]
Wed Oct 27 15:03:16 2010 <4468128817199630> primaryJVMID: [-858027425]
secondaryJVMID: [-2126611057]
Wed Oct 27 15:03:16 2010 <4468128817199630> No of JVMIDs found in cookie: 2
Wed Oct 27 15:03:16 2010 <4468128817199630> getPreferredFromCookie: Start Position is 1, listLen is 2
Wed Oct 27 15:03:16 2010 <4468128817199630> getPreferredFromCookie: Either JVMIDs not set or they are stale. Will try to get JVMIDs from WLS
Wed Oct 27 15:03:16 2010 <4468128817199630> initJVMID: Iterating SrvrList from position 1
Wed Oct 27 15:03:16 2010 <4468128817199630> ======internal request /bea_wls_internal/WLDummyInitJVMIDs======
initJVMID: Trying Host[10.177.57.203] Port[7001] SecurePort[7001] useSSL [0] ioTimeout [30] socketTimeout [2]
Wed Oct 27 15:03:16 2010 <4468128817199630> INFO: New NON-SSL URL
Wed Oct 27 15:03:16 2010 <4468128817199630> Connect returns -1, and error no set to 10035, msg 'Unknown error'
Wed Oct 27 15:03:16 2010 <4468128817199630> EINPROGRESS in connect() - selecting
Wed Oct 27 15:03:16 2010 <4468128817199630> Local Port of the socket is 1724
Wed Oct 27 15:03:16 2010 <4468128817199630> Remote Host 10.177.57.203 Remote Port 7001
Wed Oct 27 15:03:16 2010 <4468128817199630> URL::sendHeaders(): meth='HEAD' file='/bea_wls_internal/WLDummyInitJVMIDs' protocol='HTTP/1.0'
Wed Oct 27 15:03:16 2010 <4468128817199630> Hdrs to WLS:[Connection]=[Close]
Wed Oct 27 15:03:16 2010 <4468128817199630> Hdrs to WLS:[X-WebLogic-Request-ClusterInfo]=[true]
Wed Oct 27 15:03:16 2010 <4468128817199630> Hdrs to WLS:[X-WebLogic-Force-JVMID]=[unset]
Wed Oct 27 15:03:16 2010 <4468128817199630> Hdrs to WLS:[X-WebLogic-KeepAliveSecs]=[30]
Wed Oct 27 15:03:17 2010 <4468128817199630> URL::parseHeaders: CompleteStatusLine set to [HTTP/1.1 404 Not Found]
Wed Oct 27 15:03:17 2010 <4468128817199630> URL::parseHeaders: StatusLine set to [404 Not Found]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from WLS:[Connection]=[close]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from WLS:[Date]=[Wed, 27 Oct 2010 09:38:48 GMT]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from WLS:[Content-Length]=[1214]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from WLS:[Content-Type]=[text/html]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from WLS:[X-WebLogic-Cluster-Hash]=[nxnvXEeT3GGcn45ixdTTMb0Ap14]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from WLS:[X-Powered-By]=[Servlet/2.5 JSP/2.1]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from WLS:[X-WebLogic-Cluster-List]=[1008485548!179386826!7003!-1|-1255457301!179386827!7001!-1]
Wed Oct 27 15:03:17 2010 <4468128817199630> parsed all headers OK
Wed Oct 27 15:03:17 2010 <4468128817199630> Parsing cluster list: 1008485548!179386826!7003!-1|-1255457301!179386827!7001!-1
Wed Oct 27 15:03:17 2010 <4468128817199630> parseJVMID: Parsing JVMID '1008485548!179386826!7003!-1|-1255457301!179386827!7001!-1'
Wed Oct 27 15:03:17 2010 <4468128817199630> parseJVMID: Actually parsing '1008485548!179386826!7003!-1'
Wed Oct 27 15:03:17 2010 <4468128817199630> ServerInfo struct for JVMID '1008485548' populated
Server Details are:
OrigHostInfo [10.177.57.202]
isOrigHostInfoDNS [0]
Host [10.177.57.202]
Port [7003]
SecurePort [0]
Wed Oct 27 15:03:17 2010 <4468128817199630> parseJVMID: Parsing JVMID '-1255457301!179386827!7001!-1'
Wed Oct 27 15:03:17 2010 <4468128817199630> parseJVMID: Actually parsing '-1255457301!179386827!7001!-1'
Wed Oct 27 15:03:17 2010 <4468128817199630> ServerInfo struct for JVMID '-1255457301' populated
Server Details are:
OrigHostInfo [10.177.57.203]
isOrigHostInfoDNS [0]
Host [10.177.57.203]
Port [7001]
SecurePort [0]
Wed Oct 27 15:03:17 2010 <4468128817199630> Initializing lastIndex=0 for a list of length=2
Wed Oct 27 15:03:17 2010 <4468128817199630> initJVMID: Trying to locate Primary or Secondary using SrvrInfo with JVMID [1008485548]
Wed Oct 27 15:03:17 2010 <4468128817199630> initJVMID: Trying to locate Primary or Secondary using SrvrInfo with JVMID [-1255457301]
Wed Oct 27 15:03:17 2010 <4468128817199630> .....internal request /bea_wls_internal/WLDummyInitJVMIDs.....processed
Wed Oct 27 15:03:17 2010 <4468128817199630> getPreferredFromCookie: Found 0 servers
Wed Oct 27 15:03:17 2010 <4468128817199630> attempt #0 out of a max of 5
Wed Oct 27 15:03:17 2010 <4468128817199630> Trying a pooled connection for '10.177.57.202/7003/0'
Wed Oct 27 15:03:17 2010 <4468128817199630> getPooledConn: No more connections in the pool for Host[10.177.57.202] Port[7003] SecurePort[0]
Wed Oct 27 15:03:17 2010 <4468128817199630> general list: trying connect to '10.177.57.202'/7003/0 at line 2635 for '/browsestore/'
Wed Oct 27 15:03:17 2010 <4468128817199630> INFO: New NON-SSL URL
Wed Oct 27 15:03:17 2010 <4468128817199630> Connect returns -1, and error no set to 10035, msg 'Unknown error'
Wed Oct 27 15:03:17 2010 <4468128817199630> EINPROGRESS in connect() - selecting
Wed Oct 27 15:03:17 2010 <4468128817199630> Local Port of the socket is 1725
Wed Oct 27 15:03:17 2010 <4468128817199630> Remote Host 10.177.57.202 Remote Port 7003
Wed Oct 27 15:03:17 2010 <4468128817199630> general list: created a new connection to '10.177.57.202'/7003 for '/browsestore/', Local port:1725
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from clnt:[Host]=[localhost]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from clnt:[User-Agent]=[Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1.13) Gecko/20100914 Firefox/3.5.13 (.NET CLR 3.5.30729)]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from clnt:[Accept]=[text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from clnt:[Accept-Language]=[en-us,en;q=0.5]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from clnt:[Accept-Encoding]=[gzip,deflate]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from clnt:[Accept-Charset]=[ISO-8859-1,utf-8;q=0.7,*;q=0.7]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from clnt:[Keep-Alive]=[300]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from clnt:[Connection]=[keep-alive]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from clnt:[Cookie]=[JSESSIONID=bTwRMHSZG9Lhf1H2cJqr93W0bgqKRbRwGxYk4pGh0jcCzfB70vfh!-858027425!-2126611057]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs from clnt:[Cache-Control]=[max-age=0]
Wed Oct 27 15:03:17 2010 <4468128817199630> URL::sendHeaders(): meth='GET' file='/browsestore/' protocol='HTTP/1.1'
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[Host]=[localhost]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[User-Agent]=[Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1.13) Gecko/20100914 Firefox/3.5.13 (.NET CLR 3.5.30729)]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[Accept]=[text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[Accept-Language]=[en-us,en;q=0.5]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[Accept-Encoding]=[gzip,deflate]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[Accept-Charset]=[ISO-8859-1,utf-8;q=0.7,*;q=0.7]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[Keep-Alive]=[300]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[Cookie]=[JSESSIONID=bTwRMHSZG9Lhf1H2cJqr93W0bgqKRbRwGxYk4pGh0jcCzfB70vfh!-858027425!-2126611057]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[Cache-Control]=[max-age=0]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[Connection]=[Keep-Alive]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[WL-Proxy-SSL]=[false]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[WL-Proxy-Client-IP]=[127.0.0.1]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[Proxy-Client-IP]=[127.0.0.1]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[X-Forwarded-For]=[127.0.0.1]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[X-WebLogic-KeepAliveSecs]=[30]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[X-WebLogic-Request-ClusterInfo]=[true]
Wed Oct 27 15:03:17 2010 <4468128817199630> Hdrs to WLS:[x-weblogic-cluster-hash]=[nxnvXEeT3GGcn45ixdTTMb0Ap14]
Wed Oct 27 15:03:38 2010 <4468128817199630> URL::parseHeaders: CompleteStatusLine set to [HTTP/1.1 200 OK]
Wed Oct 27 15:03:38 2010 <4468128817199630> URL::parseHeaders: StatusLine set to [200 OK]
Wed Oct 27 15:03:38 2010 <4468128817199630> Hdrs from WLS:[Cache-Control]=[no-cache="set-cookie"]
Wed Oct 27 15:03:38 2010 <4468128817199630> Hdrs from WLS:[Date]=[Wed, 27 Oct 2010 09:36:53 GMT]
Wed Oct 27 15:03:38 2010 <4468128817199630> Hdrs from WLS:[Content-Length]=[751]
Wed Oct 27 15:03:38 2010 <4468128817199630> Hdrs from WLS:[Content-Type]=[text/html; charset=ISO-8859-1]
Wed Oct 27 15:03:38 2010 <4468128817199630> Hdrs from WLS:[Set-Cookie]=[JSESSIONID=Fy1wMHyVftp3LPWmGbT93QP75ttTdpJhJXrtQF2Wv5yhLr711vJ4!1008485548!-1255457301; path=/]
Wed Oct 27 15:03:38 2010 <4468128817199630> Hdrs from WLS:[X-Powered-By]=[Servlet/2.5 JSP/2.1]
Wed Oct 27 15:03:38 2010 <4468128817199630> parsed all headers OK
Wed Oct 27 15:03:38 2010 <4468128817199630> sendResponse() : r->status = '200'
Wed Oct 27 15:03:38 2010 <4468128817199630> Hdrs to client (add):[Cache-Control]=[no-cache="set-cookie"]
Wed Oct 27 15:03:38 2010 <4468128817199630> Hdrs to client (add):[Date]=[Wed, 27 Oct 2010 09:36:53 GMT]
Wed Oct 27 15:03:38 2010 <4468128817199630> Hdrs to client (add):[Set-Cookie]=[JSESSIONID=Fy1wMHyVftp3LPWmGbT93QP75ttTdpJhJXrtQF2Wv5yhLr711vJ4!1008485548!-1255457301; path=/]
Wed Oct 27 15:03:38 2010 <4468128817199630> Hdrs to client (add):[X-Powered-By]=[Servlet/2.5 JSP/2.1]
Wed Oct 27 15:03:38 2010 <4468128817199630> canRecycle: conn=1 status=200 isKA=1 clen=751 isCTE=0
Wed Oct 27 15:03:38 2010 <4468128817199630> closeConn: pooling for '10.177.57.202/7003'
Wed Oct 27 15:03:38 2010 <4468128817199630> request [/browsestore/] processed successfully..................

Viewing the Proxy Bridge Page

The proxy bridge page can be viewed with an URL like,
http://webserver_host:port/path/xyz.jsp?__WebLogicBridgeConfig
where path should be something that invokes the plug-in.
For example,http://myhost:8080/mywebapp/session.jsp?__WebLogicBridgeConfig
An example of proxy bridge page is given below.
Query String: '__WebLogicBridgeConfig'
This entry is cluster aware.

ClusterID (from obj.conf): "sol1:8001,sol2:8001,sol3:8001"
This is the same list of servers that is configured in proxy configuration file

WebLogic Cluster List:
Host: '172.18.137.54' Port: 8001 *Primary*
Host: '172.18.137.50' Port: 8001 *Secondary*
General Server List:
Also called dynamic server list and contains the server nodes that are known to be healthy at this point
Host: '172.18.137.50' Port: 8001 Status: OK
Host: '172.18.137.54' Port: 8001 Status: OK
ConnectRetrySecs: '2'
ConnectTimeoutSecs: '10'
CookieName: JSESSIONID
Debug: 'ALL'
DebugConfigInfo: 'ON'
DefaultFileName:
DynamicServerList: ON
ErrorPage: ''
FileCaching: ON
Idempotent: ON
KeepAliveEnabled: true
KeepAliveSecs: '20'
MaxPostSize: '-1'
MaxSkipTime: '10'
PathPrepend: ''
PathTrim: ''
SecureProxy: 'OFF'
StatPath: false
WLIOTimeoutSecs(old name is HungServerRecoverSecs): '300'
WLSocketTimeoutSecs: '2'
WLLogFile: '/tmp/wlproxy.log'
WLProxySSL: 'OFF'

Runtime statistics:
requests: 4
successful requests: 4
Exception objects created: 0
Exception Objects deleted: 0
URL Objects created: 1
URL Objects deleted: 1
connections recycled: 3
UNKNOWN_ERROR_CODE exceptions: 0
CONNECTION_REFUSED exceptions: 0
CONNECTION_TIMEOUT exceptions: 0
READ_ERROR_FROM_CLIENT exceptions: 0
READ_ERROR_FROM_SERVER exceptions: 0
READ_ERROR_FROM_FILE exceptions: 0
WRITE_ERROR_TO_CLIENT exceptions: 0
WRITE_ERROR_TO_SERVER exceptions: 0
WRITE_ERROR_TO_FILE exceptions: 0
READ_TIMEOUT exceptions: 0
WRITE_TIMEOUT exceptions: 0
UNKNOWN_HOST exceptions: 0
NO_RESOURCES exceptions: 0
PROTOCOL_ERROR exceptions: 0
CONFIG_ERROR exceptions: 0
FAILOVER_REQUIRED exceptions: 0
POST_TIMEOUT exceptions: 0
REQUEST_ENTITY_TOO_LARGE exceptions: 0
Build date/time: Oct 4 200318:00:57

Change Number: 291942

0 Comments