AnsweredAssumed Answered

Sharepoint 4.2.d/nightly broken?

Question asked by brandall on Apr 4, 2013
Not to duplicate my addition to the 4.2.c thread here:

http://forums.alfresco.com/forum/installation-upgrades-configuration-integration/installation-upgrades/sharepoint-bug-edit

But I've run into issues, as per below, with a FRESH install of the latest 4.2.d nightly (Mar. 29/4.2.0 (r48711-b4727) schema 6,023) onto a fresh LT Ubuntu 12.04 system.

After a default install, I see that the vti.module is installed, I get the edit button, but Alfresco does not seem to be turning on the Sharepoint system - http://localhost:7070 does nothing, and netstat shows no listening on 7070 whatsoever. Is this a new bug introduced into the nightly that renders the previous "edit online" advice (get the nightly!) obsolete?

Catalina.out is included below; I only see one innocuous-seeming WARN event, not related.


Apr 04, 2013 11:00:33 AM org.apache.catalina.core.AprLifecycleListener init
INFO: Loaded APR based Apache Tomcat Native library 1.1.24 using APR version 1.4.6.
Apr 04, 2013 11:00:33 AM org.apache.catalina.core.AprLifecycleListener init
INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
Apr 04, 2013 11:00:33 AM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFO: OpenSSL successfully initialized (OpenSSL 0.9.8o 01 Jun 2010)
Apr 04, 2013 11:00:33 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-apr-8080"]
Apr 04, 2013 11:00:33 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-apr-8009"]
Apr 04, 2013 11:00:33 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8443"]
Apr 04, 2013 11:00:34 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 1315 ms
Apr 04, 2013 11:00:34 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Apr 04, 2013 11:00:34 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.30
Apr 04, 2013 11:00:34 AM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor /opt/alfresco/tomcat/conf/Catalina/localhost/solr.xml
Apr 04, 2013 11:00:34 AM org.apache.catalina.startup.SetContextPropertiesRule begin
WARNING: [SetContextPropertiesRule]{Context} Setting property 'debug' to '0' did not find a matching property.
2013-04-04 11:00:39,719  WARN  [handler.component.SpellCheckComponent] [localhost-startStop-1] No queryConverter defined, using default converter
2013-04-04 11:00:40,754  WARN  [handler.component.SpellCheckComponent] [localhost-startStop-1] No queryConverter defined, using default converter
Apr 04, 2013 11:00:40 AM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /opt/alfresco/tomcat/webapps/share.war
2013-04-04 11:00:49,214  INFO  [extensions.webscripts.TemplateProcessorRegistry] [localhost-startStop-1] Registered template processor freemarker for extension ftl
2013-04-04 11:00:49,279  INFO  [extensions.webscripts.ScriptProcessorRegistry] [localhost-startStop-1] Registered script processor javascript for extension js
2013-04-04 11:00:49,280  INFO  [extensions.webscripts.TemplateProcessorRegistry] [localhost-startStop-1] Registered template processor freemarker for extension ftl
2013-04-04 11:00:49,284  INFO  [extensions.webscripts.ScriptProcessorRegistry] [localhost-startStop-1] Registered script processor javascript for extension js
2013-04-04 11:00:51,080  INFO  [extensions.webscripts.DeclarativeRegistry] [localhost-startStop-1] Registered 347 Web Scripts (+0 failed), 361 URLs
2013-04-04 11:00:51,081  INFO  [extensions.webscripts.DeclarativeRegistry] [localhost-startStop-1] Registered 8 Package Description Documents (+0 failed)
2013-04-04 11:00:51,081  INFO  [extensions.webscripts.DeclarativeRegistry] [localhost-startStop-1] Registered 0 Schema Description Documents (+0 failed)
2013-04-04 11:00:51,323  INFO  [extensions.webscripts.AbstractRuntimeContainer] [localhost-startStop-1] Initialised Spring Surf Container Web Script Container (in 2033.3934ms)
2013-04-04 11:00:51,336  INFO  [extensions.webscripts.TemplateProcessorRegistry] [localhost-startStop-1] Registered template processor freemarker for extension ftl
2013-04-04 11:00:51,344  INFO  [extensions.webscripts.ScriptProcessorRegistry] [localhost-startStop-1] Registered script processor javascript for extension js
Apr 04, 2013 11:00:51 AM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /opt/alfresco/tomcat/webapps/alfresco.war
Apr 04, 2013 11:00:57 AM org.apache.catalina.startup.TaglibUriRule body
INFO: TLD skipped. URI: http://java.sun.com/jsp/jstl/core is already defined
Apr 04, 2013 11:00:57 AM org.apache.catalina.core.StandardContext addApplicationListener
INFO: The listener "org.apache.myfaces.webapp.StartupServletContextListener" is already configured for this context. The duplicate definition has been ignored.
Apr 04, 2013 11:00:58 AM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
2013-04-04 11:01:07,882  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'sysAdmin' subsystem, ID: [sysAdmin, default]
2013-04-04 11:01:07,901  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'sysAdmin' subsystem, ID: [sysAdmin, default] complete
2013-04-04 11:01:11,240  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'Transformers' subsystem, ID: [Transformers, default]
2013-04-04 11:01:11,449  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'Transformers' subsystem, ID: [Transformers, default] complete
Apr 04, 2013 11:01:13 AM org.activiti.engine.impl.ProcessEngineImpl <init>
INFO: ProcessEngine default created
2013-04-04 11:01:17,435  INFO  [extensions.webscripts.TemplateProcessorRegistry] [localhost-startStop-1] Registered template processor Repository Template Processor for extension ftl
2013-04-04 11:01:17,439  INFO  [extensions.webscripts.ScriptProcessorRegistry] [localhost-startStop-1] Registered script processor Repository Script Processor for extension js
2013-04-04 11:01:24,479  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Connecting to database: jdbc:postgresql://localhost:5432/alfresco, UserName=alfresco, PostgreSQL Native Driver
2013-04-04 11:01:24,479  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] Schema managed by database dialect org.hibernate.dialect.PostgreSQLDialect.
2013-04-04 11:01:27,267  INFO  [domain.schema.SchemaBootstrap] [localhost-startStop-1] No changes were made to the schema.
2013-04-04 11:01:27,718  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'Search' subsystem, ID: [Search, managed, solr]
2013-04-04 11:01:27,960  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'Search' subsystem, ID: [Search, managed, solr] complete
2013-04-04 11:01:28,320  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'thirdparty' subsystem, ID: [thirdparty, default]
2013-04-04 11:01:28,447  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'thirdparty' subsystem, ID: [thirdparty, default] complete
2013-04-04 11:01:28,447  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'OOoDirect' subsystem, ID: [OOoDirect, default]
2013-04-04 11:01:28,942  WARN  [alfresco.util.OpenOfficeConnectionTester] [localhost-startStop-1] An initial OpenOffice connection could not be established.
2013-04-04 11:01:28,953  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'OOoDirect' subsystem, ID: [OOoDirect, default] complete
2013-04-04 11:01:28,956  INFO  [repo.admin.ConfigurationChecker] [localhost-startStop-1] The Alfresco root data directory ('dir.root') is: /opt/alfresco/alf_data
2013-04-04 11:01:28,990  INFO  [admin.patch.PatchExecuter] [localhost-startStop-1] Checking for patches to apply …
2013-04-04 11:01:29,722  INFO  [admin.patch.PatchExecuter] [localhost-startStop-1] No patches were required.
2013-04-04 11:01:29,765  INFO  [repo.module.ModuleServiceImpl] [localhost-startStop-1] Found 2 module(s).
2013-04-04 11:01:29,841  INFO  [repo.module.ModuleServiceImpl] [localhost-startStop-1] Starting module 'org.alfresco.module.vti' version 1.2.
2013-04-04 11:01:29,865  INFO  [repo.module.ModuleServiceImpl] [localhost-startStop-1] Starting module 'org.alfresco.integrations.google.docs' version 2.0.1.
2013-04-04 11:01:29,877  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'fileServers' subsystem, ID: [fileServers, default]
2013-04-04 11:01:30,266  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1]
2013-04-04 11:01:30,560  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'Authentication' subsystem, ID: [Authentication, managed, alfrescoNtlm1] complete
2013-04-04 11:01:35,594  WARN  [org.alfresco.fileserver] [localhost-startStop-1] CIFS, Unable to get local domain/workgroup name, using default of WORKGROUP. This may be due to firewall settings or incorrect <broadcast> setting)
2013-04-04 11:01:35,659  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'fileServers' subsystem, ID: [fileServers, default] complete
2013-04-04 11:01:35,659  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'imap' subsystem, ID: [imap, default]
2013-04-04 11:01:35,937  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'imap' subsystem, ID: [imap, default] complete
2013-04-04 11:01:35,938  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'email' subsystem, ID: [email, outbound]
2013-04-04 11:01:36,057  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'email' subsystem, ID: [email, outbound] complete
2013-04-04 11:01:36,057  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'email' subsystem, ID: [email, inbound]
2013-04-04 11:01:36,208  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'email' subsystem, ID: [email, inbound] complete
2013-04-04 11:01:36,208  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'googledocs' subsystem, ID: [googledocs, default]
2013-04-04 11:01:36,293  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'googledocs' subsystem, ID: [googledocs, default] complete
2013-04-04 11:01:36,294  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'Subscriptions' subsystem, ID: [Subscriptions, default]
2013-04-04 11:01:36,311  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'Subscriptions' subsystem, ID: [Subscriptions, default] complete
2013-04-04 11:01:36,312  INFO  [repo.usage.UserUsageTrackingComponent] [localhost-startStop-1] Disabled - clear non-missing user usages …
2013-04-04 11:01:36,327  INFO  [repo.usage.UserUsageTrackingComponent] [localhost-startStop-1] Found 0 users to clear
2013-04-04 11:01:36,327  INFO  [repo.usage.UserUsageTrackingComponent] [localhost-startStop-1] … cleared non-missing usages for 0 users
2013-04-04 11:01:36,327  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'Synchronization' subsystem, ID: [Synchronization, default]
2013-04-04 11:01:36,402  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'Synchronization' subsystem, ID: [Synchronization, default] complete
2013-04-04 11:01:36,476  INFO  [service.descriptor.DescriptorService] [localhost-startStop-1] Alfresco JVM - v1.7.0_07-b10; maximum heap size 910.250MB
2013-04-04 11:01:36,477  INFO  [service.descriptor.DescriptorService] [localhost-startStop-1] Alfresco started (Community). Current version: 4.2.0 (r48711-b4727) schema 6,023. Originally installed version: 4.2.0 (r48711-b4727) schema 6,023.
Apr 04, 2013 11:01:36 AM org.activiti.engine.impl.jobexecutor.JobExecutor start
INFO: Starting up the JobExecutor[org.activiti.engine.impl.jobexecutor.DefaultJobExecutor].
2013-04-04 11:01:36,490  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'ActivitiesFeed' subsystem, ID: [ActivitiesFeed, default]
Apr 04, 2013 11:01:36 AM org.activiti.engine.impl.jobexecutor.AcquireJobsRunnable run
INFO: JobExecutor[org.activiti.engine.impl.jobexecutor.DefaultJobExecutor] starting to acquire jobs
2013-04-04 11:01:36,670  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'ActivitiesFeed' subsystem, ID: [ActivitiesFeed, default] complete
2013-04-04 11:01:36,670  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'Replication' subsystem, ID: [Replication, default]
2013-04-04 11:01:36,692  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'Replication' subsystem, ID: [Replication, default] complete
2013-04-04 11:01:38,932  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Starting 'googledocs' subsystem, ID: [googledocs, v2]
2013-04-04 11:01:38,985  INFO  [management.subsystems.ChildApplicationContextFactory] [localhost-startStop-1] Startup of 'googledocs' subsystem, ID: [googledocs, v2] complete
2013-04-04 11:01:44,619  INFO  [extensions.webscripts.DeclarativeRegistry] [localhost-startStop-1] Registered 491 Web Scripts (+0 failed), 772 URLs
2013-04-04 11:01:44,619  INFO  [extensions.webscripts.DeclarativeRegistry] [localhost-startStop-1] Registered 2 Package Description Documents (+0 failed)
2013-04-04 11:01:44,619  INFO  [extensions.webscripts.DeclarativeRegistry] [localhost-startStop-1] Registered 1 Schema Description Documents (+0 failed)
2013-04-04 11:01:44,620  INFO  [extensions.webscripts.AbstractRuntimeContainer] [localhost-startStop-1] Initialised Repository Web Script Container (in 5616.578ms)
2013-04-04 11:01:44,634  INFO  [extensions.webscripts.TemplateProcessorRegistry] [localhost-startStop-1] Registered template processor freemarker for extension ftl
2013-04-04 11:01:44,635  INFO  [extensions.webscripts.ScriptProcessorRegistry] [localhost-startStop-1] Registered script processor javascript for extension js
Apr 04, 2013 11:01:44 AM com.sun.xml.ws.transport.http.servlet.WSServletContextListener contextInitialized
INFO: WSSERVLET12: JAX-WS context listener initializing
Apr 04, 2013 11:01:46 AM com.sun.xml.ws.transport.http.servlet.WSServletDelegate <init>
INFO: WSSERVLET14: JAX-WS servlet initializing
Apr 04, 2013 11:01:47 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /opt/alfresco/tomcat/webapps/host-manager
Apr 04, 2013 11:01:47 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /opt/alfresco/tomcat/webapps/manager
Apr 04, 2013 11:01:47 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /opt/alfresco/tomcat/webapps/ROOT
Apr 04, 2013 11:01:47 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-apr-8080"]
Apr 04, 2013 11:01:47 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-apr-8009"]
Apr 04, 2013 11:01:47 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8443"]
Apr 04, 2013 11:01:47 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 73106 ms
2013-04-04 11:01:47,602  ERROR [solr.tracker.CoreTracker] [SolrTrackerScheduler_Worker-2] Tracking failed
java.net.SocketTimeoutException: Read timed out
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.read(SocketInputStream.java:150)
   at java.net.SocketInputStream.read(SocketInputStream.java:121)
   at sun.security.ssl.InputRecord.readFully(InputRecord.java:312)
   at sun.security.ssl.InputRecord.read(InputRecord.java:350)
   at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:927)
   at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1328)
   at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:702)
   at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:122)
   at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
   at java.io.BufferedOutputStream.write(BufferedOutputStream.java:121)
   at java.io.FilterOutputStream.write(FilterOutputStream.java:97)
   at org.apache.commons.httpclient.methods.ByteArrayRequestEntity.writeRequest(ByteArrayRequestEntity.java:90)
   at org.apache.commons.httpclient.methods.EntityEnclosingMethod.writeRequestBody(EntityEnclosingMethod.java:499)
   at org.apache.commons.httpclient.HttpMethodBase.writeRequest(HttpMethodBase.java:2114)
   at org.apache.commons.httpclient.HttpMethodBase.execute(HttpMethodBase.java:1096)
   at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:398)
   at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171)
   at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
   at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323)
   at org.alfresco.httpclient.AbstractHttpClient.executeMethod(AbstractHttpClient.java:132)
   at org.alfresco.httpclient.AbstractHttpClient.sendRemoteRequest(AbstractHttpClient.java:108)
   at org.alfresco.httpclient.HttpClientFactory$HttpsClient.sendRequest(HttpClientFactory.java:370)
   at org.alfresco.solr.client.SOLRAPIClient.getModelsDiff(SOLRAPIClient.java:1035)
   at org.alfresco.solr.tracker.CoreTracker.trackModels(CoreTracker.java:1893)
   at org.alfresco.solr.tracker.CoreTracker.trackRepository(CoreTracker.java:1187)
   at org.alfresco.solr.tracker.CoreTracker.updateIndex(CoreTracker.java:489)
   at org.alfresco.solr.tracker.CoreTrackerJob.execute(CoreTrackerJob.java:45)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:216)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:563)
Apr 04, 2013 11:01:47 AM org.apache.coyote.http11.Http11Processor actionInternal
WARNING: Exception getting SSL attributes
java.net.SocketException: Socket Closed
   at java.net.AbstractPlainSocketImpl.getOption(AbstractPlainSocketImpl.java:273)
   at java.net.Socket.getSoTimeout(Socket.java:1108)
   at sun.security.ssl.BaseSSLSocketImpl.getSoTimeout(BaseSSLSocketImpl.java:416)
   at org.apache.tomcat.util.net.jsse.JSSESupport.handShake(JSSESupport.java:176)
   at org.apache.tomcat.util.net.jsse.JSSESupport.getPeerCertificateChain(JSSESupport.java:153)
   at org.apache.coyote.http11.Http11Processor.actionInternal(Http11Processor.java:344)
   at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:847)
   at org.apache.coyote.Request.action(Request.java:344)
   at org.apache.catalina.authenticator.SSLAuthenticator.authenticate(SSLAuthenticator.java:137)
   at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:544)
   at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
   at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
   at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
   at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
   at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
   at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1002)
   at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:585)
   at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:310)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
   at java.lang.Thread.run(Thread.java:722)

2013-04-04 11:02:00,164  WARN  [alfresco.util.OpenOfficeConnectionTester] [DefaultScheduler_Worker-3] Error trying to query Open Office version information. OpenOffice.org's ConfigurationRegistry not implemented in this version of OOo. This should not affect the operation of OOo.
2013-04-04 11:02:00,170  INFO  [alfresco.util.OpenOfficeConnectionTester] [DefaultScheduler_Worker-3] The OpenOffice connection was re-established.
2013-04-04 11:08:20,220  INFO  [web.site.EditionInterceptor] [http-bio-8443-exec-8] Successfully retrieved license information from Alfresco.
2013-04-04 11:08:27,349  INFO  [web.scripts.ImapServerStatus] [http-bio-8443-exec-8] Successfully retrieved IMAP server status from Alfresco: disabled

Outcomes