Database issues when migrating from 10.11/10.10 to 11.0 [SOLVED]

Help / Discuss
#1

Hi,

after 11.0 ist marked as stable I installed it via debian repository, but this kills my pre-live Xwiki installation.
Is it to earyl to migrate ?

Most seen exception was:

2019-01-29 13:18:50,871 [http://xwiki-upgrade:8080/xwiki/wiki/produkte/view/Main/] ERROR c.x.x.i.s.WikiSkinUtils        - Faied to get document [produkte:Main.flamingo] 
com.xpn.xwiki.XWikiException: Error number 3202 in 3: Exception while reading document [produkte:Main.flamingo]
	at com.xpn.xwiki.store.XWikiHibernateStore.loadXWikiDoc(XWikiHibernateStore.java:1022)
	at com.xpn.xwiki.store.XWikiCacheStore.loadXWikiDoc(XWikiCacheStore.java:353)
	at com.xpn.xwiki.XWiki.getDocument(XWiki.java:1916)
	at com.xpn.xwiki.XWiki.getDocument(XWiki.java:1978)
	at com.xpn.xwiki.internal.skin.WikiSkinUtils.getSkinDocument(WikiSkinUtils.java:89)
	at com.xpn.xwiki.internal.skin.WikiSkinUtils.isWikiSkin(WikiSkinUtils.java:113)
	at com.xpn.xwiki.internal.skin.InternalSkinManager.createSkin(InternalSkinManager.java:142)
	at com.xpn.xwiki.internal.skin.InternalSkinManager.getSkin(InternalSkinManager.java:132)
	at com.xpn.xwiki.internal.skin.InternalSkinManager.getCurrentSkin(InternalSkinManager.java:154)
	at com.xpn.xwiki.internal.template.InternalTemplateManager.getTemplate(InternalTemplateManager.java:925)
	at com.xpn.xwiki.internal.template.InternalTemplateManager.renderFromSkin(InternalTemplateManager.java:693)
	at com.xpn.xwiki.internal.template.InternalTemplateManager.renderFromSkin(InternalTemplateManager.java:676)
	at com.xpn.xwiki.internal.template.InternalTemplateManager.render(InternalTemplateManager.java:662)
	at com.xpn.xwiki.internal.template.DefaultTemplateManager.render(DefaultTemplateManager.java:78)
	at com.xpn.xwiki.XWiki.evaluateTemplate(XWiki.java:2290)
	at com.xpn.xwiki.XWiki.parseTemplate(XWiki.java:2268)
	at com.xpn.xwiki.api.XWiki.parseTemplate(XWiki.java:992)
	at sun.reflect.GeneratedMethodAccessor275.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.doInvoke(UberspectImpl.java:395)
	at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.invoke(UberspectImpl.java:384)
	at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:173)
	at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:280)
	at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:369)
	at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
	at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:216)
	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:311)
	at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:230)
	at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)
	at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)
	at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluateInternal(DefaultVelocityEngine.java:259)
	at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate(DefaultVelocityEngine.java:222)
	at com.xpn.xwiki.render.DefaultVelocityManager.evaluate(DefaultVelocityManager.java:358)
	at com.xpn.xwiki.internal.template.InternalTemplateManager.evaluateContent(InternalTemplateManager.java:847)
	at com.xpn.xwiki.internal.template.InternalTemplateManager.render(InternalTemplateManager.java:723)
	at com.xpn.xwiki.internal.template.InternalTemplateManager.lambda$renderFromSkin$0(InternalTemplateManager.java:698)
	at com.xpn.xwiki.internal.security.authorization.DefaultAuthorExecutor.call(DefaultAuthorExecutor.java:98)
	at com.xpn.xwiki.internal.template.InternalTemplateManager.renderFromSkin(InternalTemplateManager.java:697)
	at com.xpn.xwiki.internal.template.InternalTemplateManager.renderFromSkin(InternalTemplateManager.java:676)
	at com.xpn.xwiki.internal.template.InternalTemplateManager.render(InternalTemplateManager.java:662)
	at com.xpn.xwiki.internal.template.DefaultTemplateManager.render(DefaultTemplateManager.java:78)
	at com.xpn.xwiki.XWiki.evaluateTemplate(XWiki.java:2290)
	at com.xpn.xwiki.web.Utils.parseTemplate(Utils.java:179)
	at com.xpn.xwiki.web.Utils.parseTemplate(Utils.java:88)
	at com.xpn.xwiki.web.XWikiAction.execute(XWikiAction.java:544)
	at com.xpn.xwiki.web.XWikiAction.execute(XWikiAction.java:210)
	at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:425)
	at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:228)
	at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1913)
	at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:449)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:635)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at com.xpn.xwiki.web.ActionFilter.doFilter(ActionFilter.java:112)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.xwiki.wysiwyg.filter.ConversionFilter.doFilter(ConversionFilter.java:109)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.xwiki.container.servlet.filters.internal.SetHTTPHeaderFilter.doFilter(SetHTTPHeaderFilter.java:63)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.xwiki.container.servlet.filters.internal.SavedRequestRestorerFilter.doFilter(SavedRequestRestorerFilter.java:208)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.xwiki.container.servlet.filters.internal.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:111)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.xwiki.resource.servlet.RoutingFilter.doFilter(RoutingFilter.java:132)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:470)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1458)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)
Caused by: com.xpn.xwiki.XWikiException: Error number 3301 in 3: Exception while switching to database produkte
	at com.xpn.xwiki.internal.store.hibernate.HibernateStore.setWiki(HibernateStore.java:345)
	at com.xpn.xwiki.internal.store.hibernate.HibernateStore.setWiki(HibernateStore.java:302)
	at com.xpn.xwiki.internal.store.hibernate.HibernateStore.beginTransaction(HibernateStore.java:472)
	at com.xpn.xwiki.store.XWikiHibernateBaseStore.beginTransaction(XWikiHibernateBaseStore.java:682)
	at com.xpn.xwiki.store.XWikiHibernateStore.loadXWikiDoc(XWikiHibernateStore.java:894)
	... 92 common frames omitted
Caused by: com.xpn.xwiki.store.migration.DataMigrationException: Migration of database [produkte] has failed, it could not be safely used! Database is currently in version [1008010] while the required version is [1100000].
	at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.preventAccessToOutdatedDb(AbstractDataMigrationManager.java:594)
	at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.checkDatabase(AbstractDataMigrationManager.java:541)
	at com.xpn.xwiki.internal.store.hibernate.HibernateStore.setWiki(HibernateStore.java:339)
	... 96 common frames omitted
#2

This error is more a consequence of a failed migration. You should have a more detailed error before this one at the beginning of the tomcat startup log.

#3

First exception that came up on start was:

2019-01-29 08:39:48,319 [localhost-startStop-1] WARN  .o.i.DefaultObservationManager - An Event Listener named [Blog Document Saving Listener] already exists, ignoring the [org.xwiki.platform.blog.internal.BlogD
ocumentSavingListener] component 
2019-01-29 08:39:48,353 [localhost-startStop-1] ERROR .i.DefaultExtensionInitializer - Failed to initialize local extension [org.xwiki.contrib.blog:application-blog-notification/9.3.3] 
java.lang.NoClassDefFoundError: org/xwiki/notifications/NotificationDisplayer
        at java.lang.ClassLoader.defineClass1(Native Method)
        at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
        at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
        at org.xwiki.classloader.URIClassLoader.defineClass(URIClassLoader.java:238)
        at org.xwiki.classloader.URIClassLoader$1.run(URIClassLoader.java:188)
        at org.xwiki.classloader.URIClassLoader$1.run(URIClassLoader.java:180)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.xwiki.classloader.URIClassLoader.findClass(URIClassLoader.java:179)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        at org.xwiki.component.annotation.ComponentAnnotationLoader.register(ComponentAnnotationLoader.java:159)
        at org.xwiki.component.annotation.ComponentAnnotationLoader.initialize(ComponentAnnotationLoader.java:136)
        at org.xwiki.extension.jar.internal.handler.JarExtensionHandler.loadComponents(JarExtensionHandler.java:227)
        at org.xwiki.extension.jar.internal.handler.JarExtensionHandler.install(JarExtensionHandler.java:165)
        at org.xwiki.extension.jar.internal.handler.JarExtensionHandler.initialize(JarExtensionHandler.java:143)
        at org.xwiki.extension.handler.internal.DefaultExtensionHandlerManager.initialize(DefaultExtensionHandlerManager.java:154)
        at org.xwiki.extension.handler.internal.DefaultExtensionInitializer.initializeExtensionInNamespace(DefaultExtensionInitializer.java:202)
        at org.xwiki.extension.handler.internal.DefaultExtensionInitializer.initializeExtensionInNamespace(DefaultExtensionInitializer.java:161)
        at org.xwiki.extension.handler.internal.DefaultExtensionInitializer.initializeExtension(DefaultExtensionInitializer.java:133)
        at org.xwiki.extension.handler.internal.DefaultExtensionInitializer.initialize(DefaultExtensionInitializer.java:105)
        at org.xwiki.extension.handler.internal.DefaultExtensionInitializer.initialize(DefaultExtensionInitializer.java:81)
        at org.xwiki.component.embed.InitializableLifecycleHandler.handle(InitializableLifecycleHandler.java:39)
        at org.xwiki.component.embed.EmbeddableComponentManager.createInstance(EmbeddableComponentManager.java:365)
        at org.xwiki.component.embed.EmbeddableComponentManager.getComponentInstance(EmbeddableComponentManager.java:451)
        at org.xwiki.component.embed.EmbeddableComponentManager.getInstance(EmbeddableComponentManager.java:201)
        at org.xwiki.component.embed.EmbeddableComponentManager.getInstance(EmbeddableComponentManager.java:189)
        at org.xwiki.container.servlet.XWikiServletContextListener.contextInitialized(XWikiServletContextListener.java:120)
        at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4841)
        at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5265)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
        at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:724)
        at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:700)
        at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:714)
        at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:581)
        at org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1685)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.ClassNotFoundException: org.xwiki.notifications.NotificationDisplayer
        at org.xwiki.classloader.URIClassLoader$1.run(URIClassLoader.java:193)
        at org.xwiki.classloader.URIClassLoader$1.run(URIClassLoader.java:180)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.xwiki.classloader.URIClassLoader.findClass(URIClassLoader.java:179)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        ... 40 common frames omitted

After this several warnings appear like:

2019-01-29 08:39:48,762 [localhost-startStop-1] WARN  .o.i.DefaultObservationManager - The [org.xwiki.ratings.internal.UpdateReputationListener] listener is overwriting a previously registered listener [org.xwiki.ratings.internal.UpdateReputationListener] since they both are registered under the same id [updatereputation]. In the future consider removing a Listener first if you really want to register it again. 
2019-01-29 08:39:48,765 [localhost-startStop-1] WARN  .o.i.DefaultObservationManager - The [org.xwiki.ratings.internal.AverageRatingProtectionListener] listener is overwriting a previously registered listener [org.xwiki.ratings.internal.AverageRatingProtectionListener] since they both are registered under the same id [AverageRatingProtectionListener]. In the future consider removing a Listener first if you really want to register it again.

and than hundreds of these came up:

2019-01-29 08:40:07,531 [localhost-startStop-1] ERROR .i.DefaultExtensionInitializer - Failed to initialize local extension [org.xwiki.platform:xwiki-platform-rendering-wikimacro-ui/9.4] 
org.xwiki.extension.InstallException: Failed to initialize extension [org.xwiki.platform:xwiki-platform-rendering-wikimacro-ui/9.4]
    at org.xwiki.extension.handler.internal.DefaultExtensionHandlerManager.initialize(DefaultExtensionHandlerManager.java:156)
    at org.xwiki.extension.handler.internal.DefaultExtensionInitializer.initializeExtensionInNamespace(DefaultExtensionInitializer.java:202)
    at org.xwiki.extension.handler.internal.DefaultExtensionInitializer.initializeExtensionInNamespace(DefaultExtensionInitializer.java:161)
    at org.xwiki.extension.handler.internal.DefaultExtensionInitializer.initializeExtension(DefaultExtensionInitializer.java:127)
    at org.xwiki.extension.handler.internal.DefaultExtensionInitializer.initialize(DefaultExtensionInitializer.java:105)
    at org.xwiki.extension.handler.internal.DefaultExtensionInitializer.initialize(DefaultExtensionInitializer.java:81)
    at org.xwiki.component.embed.InitializableLifecycleHandler.handle(InitializableLifecycleHandler.java:39)
    at org.xwiki.component.embed.EmbeddableComponentManager.createInstance(EmbeddableComponentManager.java:365)
    at org.xwiki.component.embed.EmbeddableComponentManager.getComponentInstance(EmbeddableComponentManager.java:451)
    at org.xwiki.component.embed.EmbeddableComponentManager.getInstance(EmbeddableComponentManager.java:201)
    at org.xwiki.component.embed.EmbeddableComponentManager.getInstance(EmbeddableComponentManager.java:189)
    at org.xwiki.container.servlet.XWikiServletContextListener.contextInitialized(XWikiServletContextListener.java:120)
    at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4841)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5265)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:724)
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:700)
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:714)
    at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:581)
    at org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1685)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: org.xwiki.component.manager.ComponentLookupException: Failed to lookup component [org.xwiki.extension.xar.internal.handler.XarExtensionHandler] identified by type [interface org.xwiki.extension.handler.ExtensionHandler] and hint [xar]
    at org.xwiki.component.embed.EmbeddableComponentManager.getInstance(EmbeddableComponentManager.java:204)
    at org.xwiki.extension.handler.internal.DefaultExtensionHandlerManager.getExtensionHandler(DefaultExtensionHandlerManager.java:71)
    at org.xwiki.extension.handler.internal.DefaultExtensionHandlerManager.initialize(DefaultExtensionHandlerManager.java:152)
    ... 24 common frames omitted

Is it that what you are looking for ?
Anything I can do to make a diagnose ?

#4

My previous message was not very accurate. It’s not actually Tomcat startup but XWiki initialization: stuff printed the first time you access XWiki when Tomcat startup is fully finished. In short I would like to see the first message which talk about migration.

You did not disabled migration in xwiki.cfg (property xwiki.store.migration), right ?

#5

This is pretty old actually. It’s pre 9.5 blog (the blog was removed from XWiki Standard in 9.5) so you have this error in the log since you upgraded to XWiki 9.5+. You should either installed the new blog version (which will replace this one) or uninstall it if you don’t need it.

Sounds like xwiki-platform-ratings-api installed on several wikis which does not work very well for some use cases. It should be installed “On Farm” instead.

You should have more caused by in this stack trace explaining why it failed to lookup this component.

#6

xwiki.store.migration is set to 1 that means that it is switched on … right ?

The first Exception I see after accessing the xwiki the first time is this:

2019-01-29 16:53:22,299 [XWiki initialization] ERROR .HibernateDataMigrationManager - Failed to migrate database [nanomfppublic]... 
com.xpn.xwiki.store.migration.DataMigrationException: Data migration R1100000XWIKI15620 failed
        at com.xpn.xwiki.store.migration.hibernate.AbstractHibernateDataMigration.migrate(AbstractHibernateDataMigration.java:120)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.startMigrations(AbstractDataMigrationManager.java:848)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.migrateDatabase(AbstractDataMigrationManager.java:743)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.startMigrations(AbstractDataMigrationManager.java:674)
        at com.xpn.xwiki.store.migration.hibernate.HibernateDataMigrationManager.startMigrations(HibernateDataMigrationManager.java:346)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.startMigrationsOnlyOnce(AbstractDataMigrationManager.java:644)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.tryToProcceedToMigration(AbstractDataMigrationManager.java:621)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.checkDatabase(AbstractDataMigrationManager.java:538)
        at com.xpn.xwiki.internal.store.hibernate.HibernateStore.setWiki(HibernateStore.java:339)
        at com.xpn.xwiki.internal.store.hibernate.HibernateStore.setWiki(HibernateStore.java:302)
        at com.xpn.xwiki.internal.store.hibernate.HibernateStore.beginTransaction(HibernateStore.java:472)
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.beginTransaction(XWikiHibernateBaseStore.java:682)
        at com.xpn.xwiki.store.XWikiHibernateStore.loadXWikiDoc(XWikiHibernateStore.java:894)
        at com.xpn.xwiki.store.XWikiCacheStore.loadXWikiDoc(XWikiCacheStore.java:353)
        at com.xpn.xwiki.XWiki.getDocument(XWiki.java:1916)
        at com.xpn.xwiki.XWiki.getDocument(XWiki.java:1978)
        at com.xpn.xwiki.XWiki.initializeMandatoryDocument(XWiki.java:1333)
        at com.xpn.xwiki.XWiki.initializeMandatoryDocuments(XWiki.java:1307)
        at com.xpn.xwiki.XWiki.initXWiki(XWiki.java:1225)
        at com.xpn.xwiki.XWiki.initXWiki(XWiki.java:1167)
        at com.xpn.xwiki.XWiki.<init>(XWiki.java:1140)
        at com.xpn.xwiki.internal.XWikiInitializerJob.runInternal(XWikiInitializerJob.java:117)
        at org.xwiki.job.AbstractJob.runInContext(AbstractJob.java:236)
        at org.xwiki.job.AbstractJob.run(AbstractJob.java:213)
        at java.lang.Thread.run(Thread.java:748)
Caused by: com.xpn.xwiki.XWikiException: Error number 0 in 3: Exception while hibernate execute
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.execute(XWikiHibernateBaseStore.java:927)
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.executeWrite(XWikiHibernateBaseStore.java:1036)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.hibernateMigrate(R1100000XWIKI15620DataMigration.java:121)
        at com.xpn.xwiki.store.migration.hibernate.AbstractHibernateDataMigration.migrate(AbstractHibernateDataMigration.java:118)
        ... 24 common frames omitted
Caused by: org.hibernate.HibernateException: Failed to refactor filesystem store paths
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.lambda$hibernateMigrate$0(R1100000XWIKI15620DataMigration.java:125)
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.execute(XWikiHibernateBaseStore.java:921)
        ... 27 common frames omitted
Caused by: java.lang.NullPointerException: null
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11EntityReference(AbstractFileStoreDataMigration.java:105)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11EntityReference(AbstractFileStoreDataMigration.java:108)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11EntityReference(AbstractFileStoreDataMigration.java:108)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11EntityReference(AbstractFileStoreDataMigration.java:108)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11EntityReference(AbstractFileStoreDataMigration.java:108)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11EntityReference(AbstractFileStoreDataMigration.java:108)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11EntityReference(AbstractFileStoreDataMigration.java:108)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11EntityReference(AbstractFileStoreDataMigration.java:108)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11EntityReference(AbstractFileStoreDataMigration.java:108)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11DocumentReference(AbstractFileStoreDataMigration.java:116)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrateDocumentContent(R1100000XWIKI15620DataMigration.java:167)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrate(R1100000XWIKI15620DataMigration.java:152)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrate(R1100000XWIKI15620DataMigration.java:154)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrate(R1100000XWIKI15620DataMigration.java:154)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.lambda$hibernateMigrate$0(R1100000XWIKI15620DataMigration.java:123)
#7

Thanks. That’s exactly what I was looking for.

Caused by: java.lang.NullPointerException: null
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11EntityReference(AbstractFileStoreDataMigration.java:105)

This is weird. Not much idea of what could cause this.

I will deploy a patched version of the migration to get more details.

#8

OK let me know if I can help.

#9

I deployed a new version with more details. Would be great if you could replace /usr/lib/xwiki/WEB-INF/lib/xwiki-platform-store-filesystem-oldcore-11.0.jar with the last jar in http://nexus.xwiki.org/nexus/content/repositories/snapshots/org/xwiki/platform/xwiki-platform-store-filesystem-oldcore/11.0.1-SNAPSHOT/ and try again so that we get more information about what could cause this nullpointer.

See also https://jira.xwiki.org/browse/XWIKI-16075.

#10

Nice, should I reset my pre-live system first or can I proceed with the failed installation ?

#11

Always safer to reset if you can but it should keep failing in the same location until it’s fixed I think so it should not be required.

#12

After exchanging the jar I got this as th first exception:

2019-01-30 09:53:32,718 [XWiki initialization] INFO  .HibernateDataMigrationManager - Checking Hibernate mapping and updating schema if needed for wiki [nanomfppublic] 
2019-01-30 09:53:34,384 [XWiki initialization] INFO  .HibernateDataMigrationManager - Starting data migration [R1100000XWIKI15620] with version [1100000] on database [nanomfppublic] 
2019-01-30 09:53:34,398 [XWiki initialization] ERROR .HibernateDataMigrationManager - Failed to migrate database [nanomfppublic]... 
com.xpn.xwiki.store.migration.DataMigrationException: Data migration R1100000XWIKI15620 failed
        at com.xpn.xwiki.store.migration.hibernate.AbstractHibernateDataMigration.migrate(AbstractHibernateDataMigration.java:120)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.startMigrations(AbstractDataMigrationManager.java:848)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.migrateDatabase(AbstractDataMigrationManager.java:743)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.startMigrations(AbstractDataMigrationManager.java:674)
        at com.xpn.xwiki.store.migration.hibernate.HibernateDataMigrationManager.startMigrations(HibernateDataMigrationManager.java:346)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.startMigrationsOnlyOnce(AbstractDataMigrationManager.java:644)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.tryToProcceedToMigration(AbstractDataMigrationManager.java:621)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.checkDatabase(AbstractDataMigrationManager.java:538)
        at com.xpn.xwiki.internal.store.hibernate.HibernateStore.setWiki(HibernateStore.java:339)
        at com.xpn.xwiki.internal.store.hibernate.HibernateStore.setWiki(HibernateStore.java:302)
        at com.xpn.xwiki.internal.store.hibernate.HibernateStore.beginTransaction(HibernateStore.java:472)
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.beginTransaction(XWikiHibernateBaseStore.java:682)
        at com.xpn.xwiki.store.XWikiHibernateStore.loadXWikiDoc(XWikiHibernateStore.java:894)
        at com.xpn.xwiki.store.XWikiCacheStore.loadXWikiDoc(XWikiCacheStore.java:353)
        at com.xpn.xwiki.XWiki.getDocument(XWiki.java:1916)
        at com.xpn.xwiki.XWiki.getDocument(XWiki.java:1978)
        at com.xpn.xwiki.XWiki.initializeMandatoryDocument(XWiki.java:1333)
        at com.xpn.xwiki.XWiki.initializeMandatoryDocuments(XWiki.java:1307)
        at com.xpn.xwiki.XWiki.initXWiki(XWiki.java:1225)
        at com.xpn.xwiki.XWiki.initXWiki(XWiki.java:1167)
        at com.xpn.xwiki.XWiki.<init>(XWiki.java:1140)
        at com.xpn.xwiki.internal.XWikiInitializerJob.runInternal(XWikiInitializerJob.java:117)
        at org.xwiki.job.AbstractJob.runInContext(AbstractJob.java:236)
        at org.xwiki.job.AbstractJob.run(AbstractJob.java:213)
        at java.lang.Thread.run(Thread.java:748)
Caused by: com.xpn.xwiki.XWikiException: Error number 0 in 3: Exception while hibernate execute
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.execute(XWikiHibernateBaseStore.java:927)
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.executeWrite(XWikiHibernateBaseStore.java:1036)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.hibernateMigrate(R1100000XWIKI15620DataMigration.java:121)
        at com.xpn.xwiki.store.migration.hibernate.AbstractHibernateDataMigration.migrate(AbstractHibernateDataMigration.java:118)
        ... 24 common frames omitted
Caused by: org.hibernate.HibernateException: Failed to refactor filesystem store paths
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.lambda$hibernateMigrate$0(R1100000XWIKI15620DataMigration.java:125)
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.execute(XWikiHibernateBaseStore.java:921)
        ... 27 common frames omitted
Caused by: com.xpn.xwiki.store.migration.DataMigrationException: Failed to get document reference for filesystem path [/var/lib/xwiki/data/store/file/nanomfppublic/%4Dacro/%54abs%4Dacro] (root=/var/lib/xwiki/data/storage)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11DocumentReference(AbstractFileStoreDataMigration.java:120)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrateDocumentContent(R1100000XWIKI15620DataMigration.java:167)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrate(R1100000XWIKI15620DataMigration.java:152)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrate(R1100000XWIKI15620DataMigration.java:154)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrate(R1100000XWIKI15620DataMigration.java:154)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.lambda$hibernateMigrate$0(R1100000XWIKI15620DataMigration.java:123)
        ... 28 common frames omitted

I checked the path: /var/lib/xwiki/data/store/file/nanomfppublic/%4Dacro/%54abs%4Dacro and it exists.

#13

Yes but the root path does not match it, that’s where the nullpointer is coming from. Need to figure out how it can end up in this situation now.

#14

Actually I may have an idea: you did not reseted the data before the migration and the previous error was with a retry too ?

It’s indeed possible retry don’t work very well. Need to improve that.

#15

I have a VM snapshot here. If you like I could reset to the state before the upgrade. Let me know how and when to inject the new .jar file.

#16

It’s possible you hit https://jira.xwiki.org/browse/XWIKI-16076 in the first migration and then any retry cause a nullpointer (because the migration is not designed to be retried, will improve that).

Ideally you should reset the data to 10.11/10.11 state and upgrade with the new jar.

#17

OK, it took a while to switch back, I started with 10.11.

This is what I did:

  1. upgraded the package (not navigating to this xwiki).
  2. stopped tomcat
  3. injected the .jar file
  4. started tomcat

I got:

2019-01-30 14:29:04,639 [XWiki initialization] INFO  .HibernateDataMigrationManager - Checking Hibernate mapping and updating schema if needed for wiki [nanomfppublic] 
2019-01-30 14:29:06,448 [XWiki initialization] INFO  .HibernateDataMigrationManager - Starting data migration [R1100000XWIKI15620] with version [1100000] on database [nanomfppublic] 
2019-01-30 14:29:06,466 [XWiki initialization] ERROR .HibernateDataMigrationManager - Failed to migrate database [nanomfppublic]... 
com.xpn.xwiki.store.migration.DataMigrationException: Data migration R1100000XWIKI15620 failed
        at com.xpn.xwiki.store.migration.hibernate.AbstractHibernateDataMigration.migrate(AbstractHibernateDataMigration.java:120)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.startMigrations(AbstractDataMigrationManager.java:848)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.migrateDatabase(AbstractDataMigrationManager.java:743)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.startMigrations(AbstractDataMigrationManager.java:674)
        at com.xpn.xwiki.store.migration.hibernate.HibernateDataMigrationManager.startMigrations(HibernateDataMigrationManager.java:346)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.startMigrationsOnlyOnce(AbstractDataMigrationManager.java:644)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.tryToProcceedToMigration(AbstractDataMigrationManager.java:621)
        at com.xpn.xwiki.store.migration.AbstractDataMigrationManager.checkDatabase(AbstractDataMigrationManager.java:538)
        at com.xpn.xwiki.internal.store.hibernate.HibernateStore.setWiki(HibernateStore.java:339)
        at com.xpn.xwiki.internal.store.hibernate.HibernateStore.setWiki(HibernateStore.java:302)
        at com.xpn.xwiki.internal.store.hibernate.HibernateStore.beginTransaction(HibernateStore.java:472)
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.beginTransaction(XWikiHibernateBaseStore.java:682)
        at com.xpn.xwiki.store.XWikiHibernateStore.loadXWikiDoc(XWikiHibernateStore.java:894)
        at com.xpn.xwiki.store.XWikiCacheStore.loadXWikiDoc(XWikiCacheStore.java:353)
        at com.xpn.xwiki.XWiki.getDocument(XWiki.java:1916)
        at com.xpn.xwiki.XWiki.getDocument(XWiki.java:1978)
        at com.xpn.xwiki.XWiki.initializeMandatoryDocument(XWiki.java:1333)
        at com.xpn.xwiki.XWiki.initializeMandatoryDocuments(XWiki.java:1307)
        at com.xpn.xwiki.XWiki.initXWiki(XWiki.java:1225)
        at com.xpn.xwiki.XWiki.initXWiki(XWiki.java:1167)
        at com.xpn.xwiki.XWiki.<init>(XWiki.java:1140)
        at com.xpn.xwiki.internal.XWikiInitializerJob.runInternal(XWikiInitializerJob.java:117)
        at org.xwiki.job.AbstractJob.runInContext(AbstractJob.java:236)
        at org.xwiki.job.AbstractJob.run(AbstractJob.java:213)
        at java.lang.Thread.run(Thread.java:748)
Caused by: com.xpn.xwiki.XWikiException: Error number 0 in 3: Exception while hibernate execute
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.execute(XWikiHibernateBaseStore.java:927)
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.executeWrite(XWikiHibernateBaseStore.java:1036)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.hibernateMigrate(R1100000XWIKI15620DataMigration.java:121)
        at com.xpn.xwiki.store.migration.hibernate.AbstractHibernateDataMigration.migrate(AbstractHibernateDataMigration.java:118)
        ... 24 common frames omitted
Caused by: org.hibernate.HibernateException: Failed to refactor filesystem store paths
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.lambda$hibernateMigrate$0(R1100000XWIKI15620DataMigration.java:125)
        at com.xpn.xwiki.store.XWikiHibernateBaseStore.execute(XWikiHibernateBaseStore.java:921)
        ... 27 common frames omitted
Caused by: com.xpn.xwiki.store.migration.DataMigrationException: Failed to get document reference for filesystem path [/var/lib/xwiki/data/store/file/nanomfppublic/%4Dacro/%54abs%4Dacro] (root=/var/lib/xwiki/data/storage)
        at org.xwiki.store.filesystem.internal.migration.AbstractFileStoreDataMigration.getPre11DocumentReference(AbstractFileStoreDataMigration.java:120)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrateDocumentContent(R1100000XWIKI15620DataMigration.java:167)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrate(R1100000XWIKI15620DataMigration.java:152)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrate(R1100000XWIKI15620DataMigration.java:154)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.migrate(R1100000XWIKI15620DataMigration.java:154)
        at org.xwiki.store.filesystem.internal.migration.R1100000XWIKI15620DataMigration.lambda$hibernateMigrate$0(R1100000XWIKI15620DataMigration.java:123)
        ... 28 common frames omitted

looks the same for me :frowning:

#18

From what I remember the JAR you downloaded does not fix anything, it was just here to give more information.

You should try with 11.0.1.

#19

Sorry, may be not clear what I did: Step 1. means upgrading with the debian package from 10.11. to 11.0.

#20

Have you deleted the SNAPSHOT jar ? apt/dpkg won’t touch it (since it’s a custom thing) and if it’s there it might be the one used instead of 11.0.1 one.