10.6.5 JSS breakdown

[#1]

So, my first post to the mailing list and of course it's a problem, the big kind.

I'll start by introducing myself though...
My name is Patrik Sonestad and work as a tech/teacher/admin (not the tech kind) at Lund University, Sweden (quite close to Denmark and Copenhagen). Being a long time mac admin with a speciality in NetBoot/OSXS sysadmin, I became the head of the Casper project at Lund University when we decided to go Casper. The admin situation had gone out of hand with far too many workstations and student computers and just me and a few parttimers to admin it all.
We got into Casper about a year ago and had our jumpstart this april. Since then, we've (read: me, more or less) been working on getting our "product" ready for big time deployment across the entire uni. So far, the Casper part has been going smoothly, while PHDs on Windows servers have not. We have about 100 computers connected so far as a first test bed, planning to go uni-wide during 2011 and ramping it all up to about 2000 clients, including teacher-, student- and lab computers on 3 campuses in the area.

I've been following the casper list for some time now, but haven't had the need to post, just follow the interesting issues brought up on the list.

I'm gonna skip all the foul words and headaches about xserve being discontinued, that goes without saying when our servers are required to be in the uni data centre and they charge (internally) per U and not allowing access to the server unless accompanied by a computer centre employee, during business hours. :-(

So, down to the problem:

Last night, 10.6.5 arrived and I happily installed the update on our 2 xserves, one being the JSS/OD-master and the other OD-replica/web/afp(student homes).
The web/afp server installed fine, no hickups, but the JSS/OD did not. Somehow the update only updated half the MySQL installation (no fancy stuff, just the standard install and hosting the JSS database) so MySQL would not start. Installing the 10.6.5 combo on top made MySQL come back to life and the JSS Database is all fine, but Tomcat is not.
Tomcat refuses to start and the log files do not make any sense to me, being not so into Tomcat.
Trying to start catalina manually (probably not the best of ideas, but the errors are the same that show up in the logs:

admin$ sudo ./catalina.sh run
Using CATALINA_BASE: /Library/Tomcat
Using CATALINA_HOME: /Library/Tomcat
Using CATALINA_TMPDIR: /Library/Tomcat/temp
Using JRE_HOME: /System/Library/Frameworks/JavaVM.framework/Versions/CurrentJDK/Home
Using CLASSPATH: /Library/Tomcat/bin/bootstrap.jar
Nov 11, 2010 1:47:27 PM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: .:/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java
Nov 11, 2010 1:47:27 PM org.apache.coyote.http11.Http11Protocol init
SEVERE: Error initializing endpoint
java.net.BindException: Address already in use <null>:8080 at org.apache.tomcat.util.net.JIoEndpoint.init(JIoEndpoint.java:549) at org.apache.coyote.http11.Http11Protocol.init(Http11Protocol.java:176) at org.apache.catalina.connector.Connector.initialize(Connector.java:1007) at org.apache.catalina.core.StandardService.initialize(StandardService.java:677) at org.apache.catalina.core.StandardServer.initialize(StandardServer.java:795) at org.apache.catalina.startup.Catalina.load(Catalina.java:540) at org.apache.catalina.startup.Catalina.load(Catalina.java:560) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:261) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:413)
Caused by: java.net.BindException: Address already in use at java.net.PlainSocketImpl.socketBind(Native Method) at java.net.PlainSocketImpl.bind(PlainSocketImpl.java:365) at java.net.ServerSocket.bind(ServerSocket.java:319) at java.net.ServerSocket.<init>(ServerSocket.java:185) at java.net.ServerSocket.<init>(ServerSocket.java:141) at org.apache.tomcat.util.net.DefaultServerSocketFactory.createSocket(DefaultServerSocketFactory.java:50) at org.apache.tomcat.util.net.JIoEndpoint.init(JIoEndpoint.java:538) ... 12 more
Nov 11, 2010 1:47:27 PM org.apache.catalina.startup.Catalina load
SEVERE: Catalina.start
LifecycleException: Protocol handler initialization failed: java.net.BindException: Address already in use <null>:8080 at org.apache.catalina.connector.Connector.initialize(Connector.java:1009) at org.apache.catalina.core.StandardService.initialize(StandardService.java:677) at org.apache.catalina.core.StandardServer.initialize(StandardServer.java:795) at org.apache.catalina.startup.Catalina.load(Catalina.java:540) at org.apache.catalina.startup.Catalina.load(Catalina.java:560) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:261) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:413)
Nov 11, 2010 1:47:27 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 414 ms
Nov 11, 2010 1:47:27 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Nov 11, 2010 1:47:27 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.24
Nov 11, 2010 1:47:27 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor host-manager.xml
Nov 11, 2010 1:47:27 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor manager.xml
Nov 11, 2010 1:47:27 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor ROOT.xml
log4j:WARN No appenders could be found for logger (com.mchange.v2.log.MLog).
log4j:WARN Please initialize the log4j system properly.
Nov 11, 2010 1:47:32 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory docs
Nov 11, 2010 1:47:32 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory examples
Nov 11, 2010 1:47:33 PM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory TOMCAT
Nov 11, 2010 1:47:33 PM org.apache.coyote.http11.Http11Protocol start
SEVERE: Error starting endpoint
java.net.BindException: Address already in use <null>:8080 at org.apache.tomcat.util.net.JIoEndpoint.init(JIoEndpoint.java:549) at org.apache.tomcat.util.net.JIoEndpoint.start(JIoEndpoint.java:565) at org.apache.coyote.http11.Http11Protocol.start(Http11Protocol.java:203) at org.apache.catalina.connector.Connector.start(Connector.java:1080) at org.apache.catalina.core.StandardService.start(StandardService.java:531) at org.apache.catalina.core.StandardServer.start(StandardServer.java:710) at org.apache.catalina.startup.Catalina.start(Catalina.java:593) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
Caused by: java.net.BindException: Address already in use at java.net.PlainSocketImpl.socketBind(Native Method) at java.net.PlainSocketImpl.bind(PlainSocketImpl.java:365) at java.net.ServerSocket.bind(ServerSocket.java:319) at java.net.ServerSocket.<init>(ServerSocket.java:185) at java.net.ServerSocket.<init>(ServerSocket.java:141) at org.apache.tomcat.util.net.DefaultServerSocketFactory.createSocket(DefaultServerSocketFactory.java:50) at org.apache.tomcat.util.net.JIoEndpoint.init(JIoEndpoint.java:538) ... 12 more
Nov 11, 2010 1:47:33 PM org.apache.catalina.startup.Catalina start
SEVERE: Catalina.start: LifecycleException: service.getName(): "Catalina"; Protocol handler start failed: java.net.BindException: Address already in use <null>:8080 at org.apache.catalina.connector.Connector.start(Connector.java:1087) at org.apache.catalina.core.StandardService.start(StandardService.java:531) at org.apache.catalina.core.StandardServer.start(StandardServer.java:710) at org.apache.catalina.startup.Catalina.start(Catalina.java:593) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
Nov 11, 2010 1:47:33 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 5869 ms
Nov 11, 2010 1:47:33 PM org.apache.catalina.core.StandardServer await
SEVERE: StandardServer.await: create[8005]: java.net.BindException: Address already in use at java.net.PlainSocketImpl.socketBind(Native Method) at java.net.PlainSocketImpl.bind(PlainSocketImpl.java:365) at java.net.ServerSocket.bind(ServerSocket.java:319) at java.net.ServerSocket.<init>(ServerSocket.java:185) at org.apache.catalina.core.StandardServer.await(StandardServer.java:373) at org.apache.catalina.startup.Catalina.await(Catalina.java:657) at org.apache.catalina.startup.Catalina.start(Catalina.java:617) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)
Nov 11, 2010 1:47:33 PM org.apache.coyote.http11.Http11Protocol pause
INFO: Pausing Coyote HTTP/1.1 on http-8080
log4j:ERROR LogMananger.repositorySelector was null likely due to error in class reloading, using NOPLoggerRepository.
-------

There seems to be some problem binding to the server adress?
I tried repearing the permissions and there was indeed a lot of errors there, but it didn't help repairing them.
I tried the troubleshooting tools in JSS Setup Utility, with no effect.

I think the problem is in the part: java.net.BindException: Address already in use <null>:8080
But where to fix it? And why did this break?

Help appreciated ;-)

Regards

Patrik

---------------------------------------------------------------
Patrik Sonestad
Avdelningsansvarig
Avdelningen för ABM och Bokhistoria
Institutionen för kulturvetenskaper
Lunds universitet
Telefon: 046-2223141, 070-3219074
E-post: Patrik.Sonestad at kultur.lu.se

[#2]

Worked wonderfully!

My bad for not trying the Jamf knowledgebase, not very clever of me. Sorry!

But big thanks for an impressively fast response!

//Patrik

11 nov 2010 kl. 14.17 skrev Dusty Dorey:

[ernstcs]

Welcome, Patrik! Glad we couldn't help you!

Dusty Dorey @ JAMF? Really? Nice work, man!

Craig E