WO networking issue

Christian Pekeler Sat, 17 Jun 2006 10:25:58 -0700

Hi,

we're having a strange, randomly occurring networking problem in one of our production environments. The deployment is running on Xserves with the latest OS X Server and the first release of WO 5.3.1. The following was written by our administrator. Any help would be greatly appreciated.


Thanks,
Christian

Problem: Users get page from WebObjects application that says they've been logged out of their instance. At this point they can either log back in and get placed into a new instance, or they can click the browser back button once to return to the initial instance they were in before they received the log out message, and they can continue to work just as though nothing happened. At the point of the click that presents the logout page /tmp/ logWebObjects spits out:

Debug: WOSocket: connect timeout in NB connect

Error: couldn't connect to 192.168.11.108 (1085): Operation now in progress

Error: Error connecting to server 192.168.11.108

And

Problem was first noticed when performance issues forced upgrading to a gigabit switch with VLANs (one for internet, one for SSL enabled web servers in DMZ, and one for private app and db network), however the router also decided to fail when this upgrade occurred. The old switch is back in place and the router has been replaced and restored with backup files.

Run 2 other production systems configured same as this one. They do not have this issue.


Have looked at the following to isolate:

1 - verified host IPs in /WebObjects/Adaptors/Apache/apache.conf

(ie. WebObjectsConfig http://app1.domain.com:1085,http:// app2.domain.com:1085 10)

2 - turned on WOAdapterInfoPage in /WebObjects/Adaptors/Apache/ apache.conf. Appears that all instances of all applications are running. Some of our heavier used applications may have up to 11 instances, our least used may have 1 instance. Multiple reloads of the page will show some instances disappear sometimes, although there is always at least 1 instance of each application running. Additional reload causes the instances to reappear. This does not seem to occur in our other production environments.

3 - turned on logging of web adapter (touch /tmp/logWebObjects) and see following info occur when user receives the logout message. (This log is from production and has been cleaned up to make it easier to view the instance of interest -- oEQ02UQTRMxBLHhlunDCfg)

Debug: ac_readConfiguration(): skipped reading config

Info: <WebObjects Apache Module> new request: /cgi-bin/WebObjects/ TheClient.woa/8/wa/mainLogin

Debug: App Name: TheClient.woa/8/wa/mainLogin (8)
Debug: we have ssl
Info: V4 URL: /cgi-bin/WebObjects/TheClient.woa/8/wa/mainLogin
Info: Selecting specific app instance 8.

Debug: Composed URL to '/cgi-bin/WebObjects/TheClient.woa/8/wa/ mainLogin?wosid=oEQ02UQTRMxBLHhlunDCfg' Info: New request is POST /cgi-bin/WebObjects/TheClient.woa/8/wa/ mainLogin?wosid=oEQ02UQTRMxBLHhlunDCfg HTTP/1.1


Info: Sending request to instance number 8, port 2006
Info: Trying to contact TheClient:8 on (2006)
Info: attempting to connect to server-app8 on port 2006
Info: TheClient:8 on (2006) connected [pooled: No]

Info: Request POST /cgi-bin/WebObjects/TheClient.woa/8/wa/mainLogin? wosid=oEQ02UQTRMxBLHhlunDCfg HTTP/1.1


sent, awaiting response

Info: Reading configuration from http://192.168.11.101:1085/ WebObjects/wotaskd.woa/wa/woconfig

Info: attempting to connect to 192.168.11.101 on port 1085

Info: Reading configuration from http://192.168.11.102:1085/ WebObjects/wotaskd.woa/wa/woconfig

Info: attempting to connect to 192.168.11.102 on port 1085

Info: Reading configuration from http://192.168.11.103:1085/ WebObjects/wotaskd.woa/wa/woconfig

Info: attempting to connect to 192.168.11.103 on port 1085

Info: Reading configuration from http://192.168.11.7:1085/WebObjects/ wotaskd.woa/wa/woconfig

Info: attempting to connect to 192.168.11.7 on port 1085

Info: Reading configuration from http://192.168.11.8:1085/WebObjects/ wotaskd.woa/wa/woconfig

Info: attempting to connect to 192.168.11.8 on port 1085

Info: Reading configuration from http://192.168.11.107:1085/ WebObjects/wotaskd.woa/wa/woconfig

Info: attempting to connect to 192.168.11.107 on port 1085

Info: Reading configuration from http://192.168.11.108:1085/ WebObjects/wotaskd.woa/wa/woconfig

Info: attempting to connect to 192.168.11.108 on port 1085
Debug: WOSocket: connect timeout in NB connect

Error: couldn't connect to 192.168.11.108 (1085): Operation now in progress

Error: Error connecting to server 192.168.11.108

Info: Reading configuration from http://192.168.11.109:1085/ WebObjects/wotaskd.woa/wa/woconfig

Info: attempting to connect to 192.168.11.109 on port 1085
Info: Preparing to read config for host: 192.168.11.101
Info: New response: HTTP/1.0 200 Apple WebObjects
Info: Preparing to read config for host: 192.168.11.102
Info: New response: HTTP/1.0 200 Apple WebObjects
Info: Preparing to read config for host: 192.168.11.103
Info: New response: HTTP/1.0 200 Apple WebObjects
Info: Preparing to read config for host: 192.168.11.7
Info: New response: HTTP/1.0 200 Apple WebObjects
Info: Preparing to read config for host: 192.168.11.8
Info: New response: HTTP/1.0 200 Apple WebObjects
Info: Preparing to read config for host: 192.168.11.107

Info: <WebObjects Apache Module> new request: /cgi-bin/WebObjects/ TheVendor.woa/3/wo/8wgs9ciuYpOxg7YaSx5SJ0/13.0.17.10 Debug: App Name: TheVendor.woa/3/wo/8wgs9ciuYpOxg7YaSx5SJ0/13.0.17.10 (8)

Debug: we have ssl

Info: V4 URL: /cgi-bin/WebObjects/TheVendor.woa/3/wo/ 8wgs9ciuYpOxg7YaSx5SJ0/13.0.17.10

Info: Selecting specific app instance 3.

Debug: Composed URL to '/cgi-bin/WebObjects/TheVendor.woa/3/wo/ 8wgs9ciuYpOxg7YaSx5SJ0/13.0.17.10' Info: New request is POST /cgi-bin/WebObjects/TheVendor.woa/3/wo/ 8wgs9ciuYpOxg7YaSx5SJ0/13.0.17.10 HTTP/1.1


sent, awaiting response
Info: New response: HTTP/1.0 200 Apple WebObjects
Info: Config server 192.168.11.108:1085 didn't respond.
Info: Preparing to read config for host: 192.168.11.109
Info: New response: HTTP/1.0 200 Apple WebObjects
Info: ac_finishedModifyingConfig(): removing TheClient:7 (2005)
Info: ac_finishedModifyingConfig(): removing TheClient:8 (2006)
Info: ac_finishedModifyingConfig(): removing TheClient:9 (2007)
Info: ac_finishedModifyingConfig(): removing TheVendor:1 (2003)
Info: ac_finishedModifyingConfig(): removing TheRegionAdmin:1 (2015)

Info: ac_finishedModifyingConfig(): TheRegionAdmin has no instances. Removing from config.

Info: ac_finishedModifyingConfig(): removing TheDaemon:1 (2016)

Info: ac_finishedModifyingConfig(): TheDaemon has no instances. Removing from config.

Info: ac_finishedModifyingConfig(): removing TheMessage:1 (2001)
Debug: ac_readConfiguration(): skipped reading config
Info: New response: HTTP/1.1 200 Apple WebObjects
Info: New response: HTTP/1.1 200 Apple WebObjects
Info: received ->200 Apple
Info: TheVendor 2 load avg = 16
Info: received ->200 Apple

sent, awaiting response
Debug: ac_readConfiguration(): skipped reading config
Info: New response: HTTP/1.1 200 Apple WebObjects
Info: received ->200 Apple

Info: <WebObjects Apache Module> new request: /cgi-bin/WebObjects/ TheVendor.woa/2/wo/2fjTuXNbDrZW6N12BvybVg/66.0.17.10.12.5 Debug: App Name: TheVendor.woa/2/wo/2fjTuXNbDrZW6N12BvybVg/ 66.0.17.10.12.5 (8)

Debug: we have ssl

Info: V4 URL: /cgi-bin/WebObjects/TheVendor.woa/2/wo/ 2fjTuXNbDrZW6N12BvybVg/66.0.17.10.12.5

Info: Selecting specific app instance 2.

Debug: Composed URL to '/cgi-bin/WebObjects/TheVendor.woa/2/wo/ 2fjTuXNbDrZW6N12BvybVg/66.0.17.10.12.5' Info: New request is GET /cgi-bin/WebObjects/TheVendor.woa/2/wo/ 2fjTuXNbDrZW6N12BvybVg/66.0.17.10.12.5 HTTP/1.1


Info: Sending request to instance number 2, port 2024
Info: Trying to contact TheVendor:2 on (2024)
Info: attempting to connect to server-app8 on port 2024
Info: TheVendor:2 on (2024) connected [pooled: No]

Info: Request GET /cgi-bin/WebObjects/TheVendor.woa/2/wo/ 2fjTuXNbDrZW6N12BvybVg/66.0.17.10.12.5 HTTP/1.1


sent, awaiting response
Debug: ac_readConfiguration(): skipped reading config
Info: New response: HTTP/1.1 200 Apple WebObjects
Info: TheVendor 2 load avg = 16
Info: received ->200 Apple

Info: <WebObjects Apache Module> new request: /cgi-bin/WebObjects/ TheClient.woa/8/wo/oEQ02UQTRMxBLHhlunDCfg/2.0.15.0.3.0.3 Debug: App Name: TheClient.woa/8/wo/oEQ02UQTRMxBLHhlunDCfg/ 2.0.15.0.3.0.3 (8)

Debug: we have ssl

Info: V4 URL: /cgi-bin/WebObjects/TheClient.woa/8/wo/ oEQ02UQTRMxBLHhlunDCfg/2.0.15.0.3.0.3

Info: Selecting specific app instance 8.
Warn: Unable to find instance 8. Attempting to select another.
Info: loadaverage: selected instance at index 38

Debug: Composed URL to '/cgi-bin/WebObjects/TheClient.woa/2/wo/ oEQ02UQTRMxBLHhlunDCfg/2.0.15.0.3.0.3? targetPage=ServiceRequestSearchPage&linkName=SearchServiceRequests' Info: New request is GET /cgi-bin/WebObjects/TheClient.woa/2/wo/ oEQ02UQTRMxBLHhlunDCfg/2.0.15.0.3.0.3? targetPage=ServiceRequestSearchPage&linkName=SearchServiceRequests H TTP/1.1



sent, awaiting response
Debug: ac_readConfiguration(): skipped reading config
Info: TheVendor 2 load avg = 16
Info: received ->200 Apple

Info: <WebObjects Apache Module> new request: /cgi-bin/WebObjects/ TheClient.woa/8/wa/mainLogin

Debug: App Name: TheClient.woa/8/wa/mainLogin (8)
Debug: we have ssl
Info: V4 URL: /cgi-bin/WebObjects/TheClient.woa/8/wa/mainLogin
Info: Selecting specific app instance 8.


Info: Sending request to instance number 8, port 2006
Info: Trying to contact TheClient:8 on (2006)
Info: attempting to connect to server-app8 on port 2006
Info: TheClient:8 on (2006) connected [pooled: No]

Info: Request POST /cgi-bin/WebObjects/TheClient.woa/8/wa/mainLogin? wosid=oEQ02UQTRMxBLHhlunDCfg HTTP/1.1


sent, awaiting response
Debug: ac_readConfiguration(): skipped reading config
Info: New response: HTTP/1.1 200 Apple WebObjects

Info: <WebObjects Apache Module> new request: /cgi-bin/WebObjects/ TheClient.woa/8/wo/oEQ02UQTRMxBLHhlunDCfg/4.0.15.0.7.0.3 Debug: App Name: TheClient.woa/8/wo/oEQ02UQTRMxBLHhlunDCfg/ 4.0.15.0.7.0.3 (8)

Debug: we have ssl

Info: V4 URL: /cgi-bin/WebObjects/TheClient.woa/8/wo/ oEQ02UQTRMxBLHhlunDCfg/4.0.15.0.7.0.3

Info: Selecting specific app instance 8.

Debug: Composed URL to '/cgi-bin/WebObjects/TheClient.woa/8/wo/ oEQ02UQTRMxBLHhlunDCfg/4.0.15.0.7.0.3? targetPage=ContractStatusPage&linkName=ContractStatus' Info: New request is GET /cgi-bin/WebObjects/TheClient.woa/8/wo/ oEQ02UQTRMxBLHhlunDCfg/4.0.15.0.7.0.3? targetPage=ContractStatusPage&linkName=ContractStatus HTTP/1.1


Info: Sending request to instance number 8, port 2006
Info: Trying to contact TheClient:8 on (2006)
Info: attempting to connect to server-app8 on port 2006
Info: TheClient:8 on (2006) connected [pooled: No]

Info: Request GET /cgi-bin/WebObjects/TheClient.woa/8/wo/ oEQ02UQTRMxBLHhlunDCfg/4.0.15.0.7.0.3? targetPage=ContractStatusPage&linkName=ContractStatus HTTP/1.1

4 - Don't see any issues with the network router or switch (packet loss, delays, etc.) DNS services are up and running, although we've moved config to IPs to troubleshoot this issue.

5 - WebObjects logs don't show any errors. The request associated with the logout message never seems to get to the instance logs (or the instance since it can be back-clicked in the browser and resumed.)

It seems that when WebObjects refreshes, then randomly it decides to timeout when attempting to communicate with an appserver, then on the next click by the user, the logout message appears. What is going on here? Is it just a broken web adaptor? Is there a way to fix this?


Any other suggestions or things we've missed looking at?

smime.p7s
Description: S/MIME cryptographic signature

 _______________________________________________
Do not post admin requests to the list. They will be ignored.
Webobjects-deploy mailing list      ([email protected])
Help/Unsubscribe/Update your Subscription:
http://lists.apple.com/mailman/options/webobjects-deploy/archive%40mail-archive.com

This email sent to [email protected]

WO networking issue

Reply via email to