[SOLVED] 5.0.23 upgrade hangs

[aner]

I am upgrading a NE 5.0.15 release to 5.0.23. Everything was going fine until it reached "Upgrading Document templates...". That was 31 minutes ago and I'm starting to doubt it will come back.

The system seems mostly idle and the last few lines in the zmsetup.log say:

Thu Apr 8 22:19:36 2010 checking isEnabled zimbra-store
Thu Apr 8 22:19:36 2010 zimbra-store is enabled
Thu Apr 8 22:19:36 2010 Upgrading Document templates...
Thu Apr 8 22:19:36 2010 *** Running as zimbra user: /opt/zimbra/bin/zmprov ut -h zimbra-svc.ncstech.com /opt/zimbra/wiki/Template

Any suggestions? I'm thinking of killing the zmprov command so the install can move on but I'm worried there's a bigger issue here.

BTW, we have few if any "Document" users on this system.

[aner]

As feared, there is a bigger issue here. I can access fine using IMAP but the web UI is not responding! I can't get to the admin UI either...

Generated a stack trace of the zmprov java client by using kill -SIGQUIT pid:

Full thread dump Java HotSpot(TM) 64-Bit Server VM (1.5.0_20-b02 mixed mode):

"Low Memory Detector" daemon prio=1 tid=0x0000000050ab2fb0 nid=0x3352 runnable [0x0000000000000000..0x0000000000000000]

"CompilerThread1" daemon prio=1 tid=0x0000000050ab1410 nid=0x3351 waiting on condition [0x0000000000000000..0x000000004191c4f0]

"CompilerThread0" daemon prio=1 tid=0x0000000050aafef0 nid=0x3350 waiting on condition [0x0000000000000000..0x000000004181b520]

"AdapterThread" daemon prio=1 tid=0x0000000050aae820 nid=0x334f waiting on condition [0x0000000000000000..0x0000000000000000]

"Signal Dispatcher" daemon prio=1 tid=0x0000000050aad590 nid=0x334e runnable [0x0000000000000000..0x0000000000000000]

"Finalizer" daemon prio=1 tid=0x0000000050a9a100 nid=0x334d in Object.wait() [0x0000000041f16000..0x0000000041f16e10]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00002b4d9cdf4b40> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:120)
	- locked <0x00002b4d9cdf4b40> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:136)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=1 tid=0x0000000050a99920 nid=0x334c in Object.wait() [0x0000000041e15000..0x0000000041e15a90]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00002b4d9cc83ea8> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:474)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
	- locked <0x00002b4d9cc83ea8> (a java.lang.ref.Reference$Lock)

"main" prio=1 tid=0x00000000509fad20 nid=0x331c runnable [0x00007fffa0ddf000..0x00007fffa0de0270]
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at com.sun.net.ssl.internal.ssl.InputRecord.readFully(InputRecord.java:293)
	at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:331)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:782)
	- locked <0x00002b4da7b6f4f8> (a java.lang.Object)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1089)
	- locked <0x00002b4da7b6f4a0> (a java.lang.Object)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:618)
	at com.sun.net.ssl.internal.ssl.AppOutputStream.write(AppOutputStream.java:59)
	- locked <0x00002b4da7b73be0> (a com.sun.net.ssl.internal.ssl.AppOutputStream)
	at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
	at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
	- locked <0x00002b4da7b88f98> (a java.io.BufferedOutputStream)
	at org.apache.commons.httpclient.methods.StringRequestEntity.writeRequest(StringRequestEntity.java:150)
	at org.apache.commons.httpclient.methods.EntityEnclosingMethod.writeRequestBody(EntityEnclosingMethod.java:495)
	at org.apache.commons.httpclient.HttpMethodBase.writeRequest(HttpMethodBase.java:1973)
	at org.apache.commons.httpclient.HttpMethodBase.execute(HttpMethodBase.java:993)
	at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:397)
	at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:170)
	at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:396)
	at com.zimbra.common.soap.SoapHttpTransport.invoke(SoapHttpTransport.java:272)
	at com.zimbra.common.soap.SoapHttpTransport.invoke(SoapHttpTransport.java:226)
	at com.zimbra.common.soap.SoapTransport.invoke(SoapTransport.java:316)
	at com.zimbra.common.soap.SoapTransport.invoke(SoapTransport.java:280)
	at com.zimbra.cs.account.soap.SoapProvisioning.invoke(SoapProvisioning.java:188)
	- locked <0x00002b4d9cd0d918> (a com.zimbra.cs.account.soap.SoapProvisioning)
	at com.zimbra.cs.account.soap.SoapProvisioning.soapAdminAuthenticate(SoapProvisioning.java:141)
	at com.zimbra.cs.account.soap.SoapProvisioning.soapZimbraAdminAuthenticate(SoapProvisioning.java:168)
	at com.zimbra.cs.account.ProvUtil.initProvisioning(ProvUtil.java:409)
	at com.zimbra.cs.account.ProvUtil.main(ProvUtil.java:2181)

"VM Thread" prio=1 tid=0x0000000050a95490 nid=0x334b runnable 

"GC task thread#0 (ParallelGC)" prio=1 tid=0x0000000050a187c0 nid=0x3349 runnable 

"GC task thread#1 (ParallelGC)" prio=1 tid=0x0000000050a19640 nid=0x334a runnable 

"VM Periodic Task Thread" prio=1 tid=0x0000000050a0f720 nid=0x3353 waiting on condition

After killing the zmprov process, the install completed except for an "Upgrading Document templates...failed." message.

[aner]

Seeing errors in /var/log/zimbra.log

Apr  9 00:39:47 zimbra-svc slapd[12072]: conn=280 op=0 STARTTLS
Apr  9 00:39:47 zimbra-svc slapd[12072]: conn=280 op=0 RESULT oid= err=0 text=
Apr  9 00:39:47 zimbra-svc slapd[12072]: conn=280 fd=19 closed (TLS negotiation failure)

Running

/opt/zimbra/bin/zmcertmgr deploycrt self

and restarting seems to have fixed the problem. Ran

zmprov ut -h zimbra-svc.ncstech.com /opt/zimbra/wiki/Template

manually to complete missing install step.

[vavai]

Originally Posted by aner

Seeing errors in /var/log/zimbra.log

Apr  9 00:39:47 zimbra-svc slapd[12072]: conn=280 op=0 STARTTLS
Apr  9 00:39:47 zimbra-svc slapd[12072]: conn=280 op=0 RESULT oid= err=0 text=
Apr  9 00:39:47 zimbra-svc slapd[12072]: conn=280 fd=19 closed (TLS negotiation failure)

Running

and restarting seems to have fixed the problem. Ran

manually to complete missing install step.

Thank you for writing the problem solving. I'm planning to upgrade some 5.0.x into 5.0.23 and curious if found similar problem.