ApacheJServ/1.1.2: Failed to bind to port(s) specified in jserv.properties

Recently we had an issue on the newly created extranet tiers. Apache was running fine but jserv would not come up. We got errors like this one in jvm logs:

ApacheJServ/1.1.2: Failed to bind to port(s) specified in $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.properties. Please check $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.properties and jserv.conf file, and make sure number of JServ process specified in jserv.conf is less than number of ports specified in $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.properties. and the ports are not used by other processes.

It was a mystery why jserv refused to come up.

A grep on servlet port range used on context file returned this:

$ grep s_oacore_servlet_portrange $CONTEXT_FILE
16000-16009
$

To rule out any hardening on the server which may cause ports to be disaabled, we tried starting the apps listener on ports 16000 to 16009 and it came up without issues. Seeing the error messages I was sure that it was trying to open these ports on some other server, may be the load balancer hostname.

After enabling debug logging on Apache and jserv as specified in metalink note 230688.1, we got the following error in jserv.log.

[16/05/2008 22:03:42:946 EDT] ApacheJServ/1.1.2 is starting...
[16/05/2008 22:03:42:946 EDT] using confFile $IAS_ORACLE_HOME/Apache
/Jserv/etc/jserv.properties
[16/05/2008 22:03:43:086 EDT] Connection authentication enabled
[16/05/2008 22:03:43:106 EDT] Connection allowed from /127.0.0.1
[16/05/2008 22:03:43:113 EDT] Connection allowed from extranet1.jstanexample.com/192.168.1.101
[16/05/2008 22:03:43:113 EDT] port 16000 is specified in properties file
[16/05/2008 22:03:43:113 EDT] port 16001 is specified in properties file
[16/05/2008 22:03:43:113 EDT] port 16002 is specified in properties file
[16/05/2008 22:03:43:113 EDT] port 16003 is specified in properties file
[16/05/2008 22:03:43:113 EDT] port 16004 is specified in properties file
[16/05/2008 22:03:43:113 EDT] port 16005 is specified in properties file
[16/05/2008 22:03:43:113 EDT] port 16006 is specified in properties file
[16/05/2008 22:03:43:113 EDT] port 16007 is specified in properties file
[16/05/2008 22:03:43:113 EDT] port 16008 is specified in properties file
[16/05/2008 22:03:43:113 EDT] port 16009 is specified in properties file
16/05/2008 22:03:43:117 EDT] cannot create socket on 16000
[16/05/2008 22:03:43:117 EDT] try to start on port 16001
[16/05/2008 22:03:43:117 EDT] cannot create socket on 16001
[16/05/2008 22:03:43:117 EDT] try to start on port 16002
[16/05/2008 22:03:43:117 EDT] cannot create socket on 16002
[16/05/2008 22:03:43:117 EDT] try to start on port 16003
[16/05/2008 22:03:43:118 EDT] cannot create socket on 16003
[16/05/2008 22:03:43:118 EDT] try to start on port 16004
[16/05/2008 22:03:43:118 EDT] cannot create socket on 16004
[16/05/2008 22:03:43:118 EDT] try to start on port 16005
[16/05/2008 22:03:43:118 EDT] cannot create socket on 16005
[16/05/2008 22:03:43:118 EDT] try to start on port 16006
[16/05/2008 22:03:43:118 EDT] cannot create socket on 16006
[16/05/2008 22:03:43:118 EDT] try to start on port 16007
[16/05/2008 22:03:43:118 EDT] cannot create socket on 16007
[16/05/2008 22:03:43:118 EDT] try to start on port 16008
[16/05/2008 22:03:43:118 EDT] cannot create socket on 16008
[16/05/2008 22:03:43:118 EDT] try to start on port 16009
[16/05/2008 22:03:43:119 EDT] cannot create socket on 16009
[16/05/2008 22:03:43:119 EDT] ApacheJServ/1.1.2: Failed to bind to port(s) specified in $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.properties. Please check $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.properties and jserv.conf file, and make sure number of JServ process specified in jserv.conf is less than number of ports specified in $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.properties. and the ports are not used by other processes. ApacheJServ/1.1.2: Failed to bind to port(s) specified in $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.properties. Please check $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.properties and jserv.conf file, and make sure number of JServ process specified in jserv.conf is less than number of ports specified in $IAS_ORACLE_HOME/Apache/Jserv/etc/jserv.properties. and the ports are not used by other processes.

mod_jserv.log showed:
[16/05/2008 23:51:19:877] (EMERGENCY) ajp12: can not connect to host 192.168.1.100:16000
[16/05/2008 23:51:19:878] (EMERGENCY) ajp12: function connection fail


That was the first clue we got that it was trying to connect to 192.168.1.100 on port 16000. 192.168.1.100 was not the IP address of the Apache server. It was the IP used to connect to the server from the intranet.

An nslookup on extranet1.justanexample.com showed that the DNS was returning the address 192.168.1.100 when this name was queried. Even though pinging the name returned the 10.x address assigned to the extranet apache server, when Oracle apps queried for the name it was resolving to the IP returned by DNS.

This means that the order of name resolution was dns first and /etc/hosts next. I corrected this in /etc/nsswitch.conf by switching this line:

hosts: dns files

with this line

hosts: files dns

After we did this, when we bounced Apache, jserv finally came up, as it was now biding on the correct IP address and port. The mystery was solved, and we correctly identified that it was previously trying to bind to ports on 192.168.1.100 instead of the base IP address 10.1.1.1 of the extranet server.