Upgrading to Oak 1.10.0 for Sling10

classic Classic list List threaded Threaded
9 messages Options
Reply | Threaded
Open this post in threaded view
|

Upgrading to Oak 1.10.0 for Sling10

marc.davenport
Hello,

We are in the process of migrating from Sling6 to Sling10 (Sling11 came
out after we started the initiative). One of the upgrades is moving from
Jackrabbit 2 to Jackrabbit Oak.  We've modeled ourselves after the
Sling10 starter war. The starter war uses Oak 1.6.8 so we started with
that. Unfortunately a bug fixed in Oak 1.10.0
<https://issues.apache.org/jira/browse/OAK-7778> means we have to
migrate from Oak 1.6.8 to 1.10.0.  Mostly this was just dealing with the
broken apart modules of Oak and including the proper artifacts. For this
I tried to cross reference with the starter of sling11 which had already
migrated to Oak 1.8.x.   I've been moderately successful. However, about
1/2 the time, our application will fail to deploy. I can not parse if
this is a Oak failure or a sling10 failure, or a configuration between
the two issue. I'm looking for any insight as to what this might be.

Here is what I believe to be the relevant  error messages:

14.02.2019 12:28:29.190 *WARN*[CM Event Dispatcher (Fire
ConfigurationEvent:
pid=org.apache.jackrabbit.oak.segment.SegmentNodeStoreService)]
org.apache.sling.commons.scheduler.impl.QuartzScheduler Scheduler job
requested thread pool with name oak but this thread pool is not in the
list of allowed pools.
14.02.2019 12:28:29.453 *WARN*[Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.name.NameValidator Invalid namespace
prefix([, sv, nt, xml, jcr, oak, rep, mix]): slingevent
14.02.2019 12:28:29.454 *WARN*[Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.name.NameValidator Invalid namespace
prefix([, sv, nt, xml, jcr, oak, rep, mix]): sling
14.02.2019 12:28:29.455 *WARN*[Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.name.NameValidator Invalid namespace
prefix([, sv, nt, xml, jcr, oak, rep, mix]): sling
14.02.2019 12:28:29.455 *WARN*[Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.name.NameValidator Invalid namespace
prefix([, sv, nt, xml, jcr, oak, rep, mix]): sling
14.02.2019 12:28:29.456 *WARN*[Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.name.NameValidator Invalid namespace
prefix([, sv, nt, xml, jcr, oak, rep, mix]): sling
14.02.2019 12:28:29.904 *ERROR*[Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager
start: Uncaught Throwable trying to access Repository, calling
stopRepository()
java.lang.RuntimeException:
org.apache.jackrabbit.oak.api.CommitFailedException: OakConstraint0001:
/oak:index/jcrLanguage/:index[[]]: The primary type null does not exist
         at
org.apache.jackrabbit.oak.OakInitializer.initialize(OakInitializer.java:50)
         at org.apache.jackrabbit.oak.Oak.initialContent(Oak.java:682)
         at
org.apache.jackrabbit.oak.Oak.createNewContentRepository(Oak.java:725)
         at
org.apache.jackrabbit.oak.Oak.createContentRepository(Oak.java:670)
         at
org.apache.jackrabbit.oak.jcr.Jcr.createContentRepository(Jcr.java:376)
         at
org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager.acquireRepository(OakSlingRepositoryManager.java:152)
         at
org.apache.sling.jcr.base.AbstractSlingRepositoryManager.initializeAndRegisterRepositoryService(AbstractSlingRepositoryManager.java:471)
         at
org.apache.sling.jcr.base.AbstractSlingRepositoryManager.access$300(AbstractSlingRepositoryManager.java:85)
         at
org.apache.sling.jcr.base.AbstractSlingRepositoryManager$4.run(AbstractSlingRepositoryManager.java:455)
Caused by: org.apache.jackrabbit.oak.api.CommitFailedException:
OakConstraint0001: /oak:index/jcrLanguage/:index[[]]: The primary type
null does not exist

Any help or pointing in the right direction would be much appreciated.

Marc

Reply | Threaded
Open this post in threaded view
|

Re: Upgrading to Oak 1.10.0 for Sling10

Robert Munteanu-2
Hi Marc,

On Thu, 2019-02-14 at 16:02 -0500, [hidden email] wrote:
> I've been moderately successful. However, about
> 1/2 the time, our application will fail to deploy. I can not parse
> if
> this is a Oak failure or a sling10 failure, or a configuration
> between
> the two issue. I'm looking for any insight as to what this might be.

A sample project reproducing the issue would be very helpful.

Thanks,

Robert

Reply | Threaded
Open this post in threaded view
|

Re: Upgrading to Oak 1.10.0 for Sling10

marc.davenport
Hello Robert et all,

Thank you for your reply.  I have not been able to pair down to a sample
project that isolates this issue. I'm currently deploying my application
over and over until I hit the failure mode. I haven't identified the
code that would have created the missing primary types.  I could use
some ideas on where to look next, even if it is just a best guess.

In the failed state I can see that the component
org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager is
active according the Felix Webconsole. But there is no corresponding
service of the type org.apache.sling.jcr.api.SlingRepository.   This may
another version of the information the logs are telling me. But it is
something I noticed trying to compare working and not working instances.

Any ideas would be helpful at this point. I was kind of hoping that the
log messages might trigger an "oh yeah, I've seen this before in X" kind
of moment, since I currently have no purchase on the problem.

Thank you,

Marc



14.02.2019 12:28:29.190 *WARN*[CM Event Dispatcher (Fire
ConfigurationEvent:
pid=org.apache.jackrabbit.oak.segment.SegmentNodeStoreService)]
org.apache.sling.commons.scheduler.impl.QuartzScheduler Scheduler job
requested thread pool with name oak but this thread pool is not in the
list of allowed pools.
14.02.2019 12:28:29.453 *WARN*[Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.name.NameValidator Invalid namespace
prefix([, sv, nt, xml, jcr, oak, rep, mix]): slingevent
14.02.2019 12:28:29.454 *WARN*[Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.name.NameValidator Invalid namespace
prefix([, sv, nt, xml, jcr, oak, rep, mix]): sling
14.02.2019 12:28:29.455 *WARN*[Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.name.NameValidator Invalid namespace
prefix([, sv, nt, xml, jcr, oak, rep, mix]): sling
14.02.2019 12:28:29.455 *WARN*[Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.name.NameValidator Invalid namespace
prefix([, sv, nt, xml, jcr, oak, rep, mix]): sling
14.02.2019 12:28:29.456 *WARN*[Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.name.NameValidator Invalid namespace
prefix([, sv, nt, xml, jcr, oak, rep, mix]): sling
14.02.2019 12:28:29.904 *ERROR*[Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager
start: Uncaught Throwable trying to access Repository, calling
stopRepository()
java.lang.RuntimeException:
org.apache.jackrabbit.oak.api.CommitFailedException: OakConstraint0001:
/oak:index/jcrLanguage/:index[[]]: The primary type null does not exist
         at
org.apache.jackrabbit.oak.OakInitializer.initialize(OakInitializer.java:50)
         at org.apache.jackrabbit.oak.Oak.initialContent(Oak.java:682)
         at
org.apache.jackrabbit.oak.Oak.createNewContentRepository(Oak.java:725)
         at
org.apache.jackrabbit.oak.Oak.createContentRepository(Oak.java:670)
         at
org.apache.jackrabbit.oak.jcr.Jcr.createContentRepository(Jcr.java:376)
         at
org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager.acquireRepository(OakSlingRepositoryManager.java:152)
         at
org.apache.sling.jcr.base.AbstractSlingRepositoryManager.initializeAndRegisterRepositoryService(AbstractSlingRepositoryManager.java:471)
         at
org.apache.sling.jcr.base.AbstractSlingRepositoryManager.access$300(AbstractSlingRepositoryManager.java:85)
         at
org.apache.sling.jcr.base.AbstractSlingRepositoryManager$4.run(AbstractSlingRepositoryManager.java:455)
Caused by: org.apache.jackrabbit.oak.api.CommitFailedException:
OakConstraint0001: /oak:index/jcrLanguage/:index[[]]: The primary type
null does not exist

On 2/15/19 10:51 AM, Robert Munteanu wrote:

> Hi Marc,
>
> On Thu, 2019-02-14 at 16:02 -0500, [hidden email] wrote:
>> I've been moderately successful. However, about
>> 1/2 the time, our application will fail to deploy. I can not parse
>> if
>> this is a Oak failure or a sling10 failure, or a configuration
>> between
>> the two issue. I'm looking for any insight as to what this might be.
> A sample project reproducing the issue would be very helpful.
>
> Thanks,
>
> Robert
>
Reply | Threaded
Open this post in threaded view
|

Re: Upgrading to Oak 1.10.0 for Sling10

Robert Munteanu-2
Hi Marc,

On Thu, 2019-02-21 at 18:18 -0500, [hidden email] wrote:

> Hello Robert et all,
>
> Thank you for your reply.  I have not been able to pair down to a
> sample
> project that isolates this issue. I'm currently deploying my
> application
> over and over until I hit the failure mode. I haven't identified the
> code that would have created the missing primary types.  I could use
> some ideas on where to look next, even if it is just a best guess.
>
> In the failed state I can see that the component
> org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager
> is
> active according the Felix Webconsole. But there is no corresponding
> service of the type org.apache.sling.jcr.api.SlingRepository.   This
> may
> another version of the information the logs are telling me. But it
> is
> something I noticed trying to compare working and not working
> instances.
>
> Any ideas would be helpful at this point. I was kind of hoping that
> the
> log messages might trigger an "oh yeah, I've seen this before in X"
> kind
> of moment, since I currently have no purchase on the problem.

Unfortunately I haven't seen this problem so far. Could you maybe try
the same setup with the old Oak version that was working? If you
encounter the same problem it's probably not Oak, so at least we can
rule that out.

Also, do you have any custom code that plugs into the repository
initialisation?

The index you referenced is created by ExtraSlingContent [1] and is
added _after_ Oak's InitialContent [2][3]. So the question is - has the
InitialContent been installed successfully? Are you able to inspect the
repository after in the scenario where this fails?

Thanks,

Robert

[1]: https://github.com/apache/sling-org-apache-sling-jcr-oak-server/blob/6aa041d47fe5a8df834b83170bc0f5df460ed94d/src/main/java/org/apache/sling/jcr/oak/server/internal/OakSlingRepositoryManager.java#L212
[2]: https://github.com/apache/sling-org-apache-sling-jcr-oak-server/blob/6aa041d47fe5a8df834b83170bc0f5df460ed94d/src/main/java/org/apache/sling/jcr/oak/server/internal/OakSlingRepositoryManager.java#L127-L128
[3]: https://github.com/apache/jackrabbit-oak/blob/jackrabbit-oak-1.10.0/oak-core/src/main/java/org/apache/jackrabbit/oak/InitialContent.java

Reply | Threaded
Open this post in threaded view
|

Re: Upgrading to Oak 1.10.0 for Sling10

Robert Munteanu-2
In reply to this post by marc.davenport
On Thu, 2019-02-14 at 16:02 -0500, [hidden email] wrote:
> 14.02.2019 12:28:29.190 *WARN*[CM Event Dispatcher (Fire
> ConfigurationEvent:
> pid=org.apache.jackrabbit.oak.segment.SegmentNodeStoreService)]
> org.apache.sling.commons.scheduler.impl.QuartzScheduler Scheduler
> job
> requested thread pool with name oak but this thread pool is not in
> the
> list of allowed pools.

There's also this warning, I overlooked it. I don't see it the latest
Sling starter. Can you adjust the configuration of the QuartzScheduler
to include 'oak' in the allowed pool names?

Robert

Reply | Threaded
Open this post in threaded view
|

Re: Upgrading to Oak 1.10.0 for Sling10

marc.davenport
In reply to this post by Robert Munteanu-2
Robert,

Thanks for thinking about this issue with me.

You asked: do you have any custom code that plugs into the repository initialisation?
I can not find any custom classes that are implementing RepositoryInitilizer.

We have a custom class which provides the SlingRepository service and a service ranking of 1000. It wraps the OakSlingRepositoryManager

     @Reference(target="(component.name=org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager)")
     private SlingRepository repository;

We do this so that we can cast the Sessions as our own special Session objects. This is what I've been able to figure out from walking up to this project. This may be a defunct pattern since we have moved from Sling6 to 10 recently.

The order of the bundles
CustomWorkspace (14) <- contains the custom impl of
Oak bundles(15)
Sling JCR Oak Server (16)

I've tried moving the order of the bundles around to see if I had something in common with SLING-4556, but again this grasping with hope.

You asked: "Are you able to inspect the repository after in the scenario where this fails?"
As far as a can tell the repository is completely unavailable. But I'm open to debugging suggestions.

You asked: "Can you adjust the configuration of the QuartzScheduler to include 'oak' in the allowed pool names?"
I'm not sure how to do this. Also, I see this error in both working and non working instances.

I've been looking at the logs from the working and failed state trying to find an error or warning that is in one but not the other.  It looks like the OakConstraint error on the missing null primary type actually happens in both situations. So I think tracking down my first error message suspect is a dead end.

I lopped off the timestamps so I could diff the logs from a good and a bad state. Below I've added the log messages I should have focused on.  Is there a proper way to share whole logs on this mailing list? Attaching a 9mb file didn't seem appropriate.

Thank you for all you time so far,
Marc

22.02.2019 12:52:40.867 *ERROR* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager
start: Uncaught Throwable trying to access Repository, calling
stopRepository()
java.lang.NullPointerException: null
     at
org.apache.sling.jcr.base.AbstractSlingRepositoryManager.initializeAndRegisterRepositoryService(AbstractSlingRepositoryManager.java:478)
     at
org.apache.sling.jcr.base.AbstractSlingRepositoryManager.access$300(AbstractSlingRepositoryManager.java:85)
     at
org.apache.sling.jcr.base.AbstractSlingRepositoryManager$4.run(AbstractSlingRepositoryManager.java:455)
22.02.2019 12:52:40.867 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager stop:
Repository still running, forcing shutdown
22.02.2019 12:52:40.868 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [482,
[org.apache.jackrabbit.api.jmx.QueryStatManagerMBean]] ServiceEvent
UNREGISTERING
22.02.2019 12:52:40.869 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [483,
[org.apache.jackrabbit.oak.api.jmx.RepositoryStatsMBean]] ServiceEvent
UNREGISTERING
22.02.2019 12:52:40.870 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [484, [java.lang.Runnable]]
ServiceEvent UNREGISTERING
22.02.2019 12:52:40.871 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [485,
[org.apache.jackrabbit.oak.spi.gc.GCMonitor]] ServiceEvent UNREGISTERING
22.02.2019 12:52:40.874 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [403,
[java.util.concurrent.Executor]] ServiceEvent UNREGISTERING
22.02.2019 12:52:40.875 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [474, [java.lang.Runnable]]
ServiceEvent UNREGISTERING
22.02.2019 12:52:40.896 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [475,
[org.apache.jackrabbit.oak.api.jmx.IndexStatsMBean]] ServiceEvent
UNREGISTERING
22.02.2019 12:52:40.900 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [476,
[org.apache.jackrabbit.oak.plugins.index.property.jmx.PropertyIndexAsyncReindexMBean]]
ServiceEvent UNREGISTERING
22.02.2019 12:52:40.901 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [477,
[org.apache.jackrabbit.oak.plugins.index.counter.jmx.NodeCounterMBean]]
ServiceEvent UNREGISTERING
22.02.2019 12:52:40.902 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [478,
[org.apache.jackrabbit.oak.api.jmx.QueryEngineSettingsMBean]]
ServiceEvent UNREGISTERING
22.02.2019 12:52:40.904 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [479,
[org.apache.jackrabbit.oak.query.stats.QueryStatsMBean]] ServiceEvent
UNREGISTERING
22.02.2019 12:52:40.905 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [480,
[org.apache.jackrabbit.oak.api.jmx.RepositoryManagementMBean]]
ServiceEvent UNREGISTERING
22.02.2019 12:52:40.906 *INFO* [Apache Sling Repository Startup Thread]
org.apache.sling.jcr.oak.server Service [481,
[org.apache.jackrabbit.oak.spi.commit.CommitHook]] ServiceEvent
UNREGISTERING
22.02.2019 12:52:40.906 *INFO* [Apache Sling Repository Startup Thread]
org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate [async] Closed
22.02.2019 12:52:49.349 *INFO* [http-nio-8006-exec-1]
org.apache.felix.http.whiteboard Detected extended HttpService. Filters
enabled.
22.02.2019 12:52:49.358 *INFO* [http-nio-8006-exec-1]
org.apache.felix.http.bridge Service [486,
[org.osgi.service.http.HttpService,
org.apache.felix.http.api.ExtHttpService]] ServiceEvent REGISTERED
22.02.2019 12:52:49.358 *INFO* [http-nio-8006-exec-1]
org.apache.felix.http.bridge Service [487,
[org.osgi.service.http.runtime.HttpServiceRuntime]] ServiceEvent REGISTERED
22.02.2019 12:52:49.360 *INFO* [http-nio-8006-exec-1]
org.apache.felix.http.bridge Service [488,
[org.osgi.service.http.context.ServletContextHelper]] ServiceEvent
REGISTERED
22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
org.apache.sling.engine.parameters Default Character Encoding: ISO-8859-1
22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
org.apache.sling.engine.parameters Parameter Number Limit: 10000
22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
org.apache.sling.engine.parameters Maximum Request Size: -1
22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
org.apache.sling.engine.parameters Temporary File Location: null
22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
org.apache.sling.engine.parameters Maximum File Size: -1
22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
org.apache.sling.engine.parameters Tempory File Creation Threshold: 256000
22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
org.apache.sling.engine.parameters Check for additional container
parameters: false
22.02.2019 12:52:49.378 *INFO* [http-nio-8006-exec-1]
org.apache.felix.inventory Service [491, [javax.servlet.Servlet]]
ServiceEvent REGISTERED
22.02.2019 12:52:49.378 *INFO* [http-nio-8006-exec-1]
org.apache.felix.inventory Service [490,
[org.apache.felix.inventory.InventoryPrinter]] ServiceEvent REGISTERED
22.02.2019 12:52:49.379 *INFO* [http-nio-8006-exec-1]
org.apache.felix.http.bridge Service [HTTP Service Web Console
Plugin,489, [javax.servlet.Servlet]] ServiceEvent REGISTERED
22.02.2019 12:52:49.383 *ERROR* [http-nio-8006-exec-1]
org.apache.sling.engine.impl.SlingHttpContext handleSecurity:
AuthenticationSupport service missing. Cannot authenticate request.
22.02.2019 12:52:49.383 *ERROR* [http-nio-8006-exec-1]
org.apache.sling.engine.impl.SlingHttpContext handleSecurity: Possible
reason is missing Repository service. Check AuthenticationSupport
dependencies.


Reply | Threaded
Open this post in threaded view
|

Re: Upgrading to Oak 1.10.0 for Sling10

Julian Sedding-3
Hi Marc

From your log, I suspect that the "sling" and "slingevent" Namespaces
are (not yet?) registered when the repository is being initialized.
During repository initialization all installed OSGi bundles are
inspected in order to see whether they contribute namespaces or
node-type definitions (via special manifest headers and embedded *.cnd
files).

The "sling" namespace is defined by the bundle
"org.apache.sling.jcr.resource", the "slingevent" namespace by
"org-apache-sling-event". Try making sure that they are installed
before repository initialization happens.

It may help to enable debug logging for "org.apache.sling.jcr.base" to
better understand when during initialization this happens.

Note: this advice is based on speculation, so YMMV.

Regards
Julian

On Sat, Feb 23, 2019 at 1:45 AM <[hidden email]> wrote:

>
> Robert,
>
> Thanks for thinking about this issue with me.
>
> You asked: do you have any custom code that plugs into the repository initialisation?
> I can not find any custom classes that are implementing RepositoryInitilizer.
>
> We have a custom class which provides the SlingRepository service and a service ranking of 1000. It wraps the OakSlingRepositoryManager
>
>      @Reference(target="(component.name=org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager)")
>      private SlingRepository repository;
>
> We do this so that we can cast the Sessions as our own special Session objects. This is what I've been able to figure out from walking up to this project. This may be a defunct pattern since we have moved from Sling6 to 10 recently.
>
> The order of the bundles
> CustomWorkspace (14) <- contains the custom impl of
> Oak bundles(15)
> Sling JCR Oak Server (16)
>
> I've tried moving the order of the bundles around to see if I had something in common with SLING-4556, but again this grasping with hope.
>
> You asked: "Are you able to inspect the repository after in the scenario where this fails?"
> As far as a can tell the repository is completely unavailable. But I'm open to debugging suggestions.
>
> You asked: "Can you adjust the configuration of the QuartzScheduler to include 'oak' in the allowed pool names?"
> I'm not sure how to do this. Also, I see this error in both working and non working instances.
>
> I've been looking at the logs from the working and failed state trying to find an error or warning that is in one but not the other.  It looks like the OakConstraint error on the missing null primary type actually happens in both situations. So I think tracking down my first error message suspect is a dead end.
>
> I lopped off the timestamps so I could diff the logs from a good and a bad state. Below I've added the log messages I should have focused on.  Is there a proper way to share whole logs on this mailing list? Attaching a 9mb file didn't seem appropriate.
>
> Thank you for all you time so far,
> Marc
>
> 22.02.2019 12:52:40.867 *ERROR* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager
> start: Uncaught Throwable trying to access Repository, calling
> stopRepository()
> java.lang.NullPointerException: null
>      at
> org.apache.sling.jcr.base.AbstractSlingRepositoryManager.initializeAndRegisterRepositoryService(AbstractSlingRepositoryManager.java:478)
>      at
> org.apache.sling.jcr.base.AbstractSlingRepositoryManager.access$300(AbstractSlingRepositoryManager.java:85)
>      at
> org.apache.sling.jcr.base.AbstractSlingRepositoryManager$4.run(AbstractSlingRepositoryManager.java:455)
> 22.02.2019 12:52:40.867 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager stop:
> Repository still running, forcing shutdown
> 22.02.2019 12:52:40.868 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [482,
> [org.apache.jackrabbit.api.jmx.QueryStatManagerMBean]] ServiceEvent
> UNREGISTERING
> 22.02.2019 12:52:40.869 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [483,
> [org.apache.jackrabbit.oak.api.jmx.RepositoryStatsMBean]] ServiceEvent
> UNREGISTERING
> 22.02.2019 12:52:40.870 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [484, [java.lang.Runnable]]
> ServiceEvent UNREGISTERING
> 22.02.2019 12:52:40.871 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [485,
> [org.apache.jackrabbit.oak.spi.gc.GCMonitor]] ServiceEvent UNREGISTERING
> 22.02.2019 12:52:40.874 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [403,
> [java.util.concurrent.Executor]] ServiceEvent UNREGISTERING
> 22.02.2019 12:52:40.875 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [474, [java.lang.Runnable]]
> ServiceEvent UNREGISTERING
> 22.02.2019 12:52:40.896 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [475,
> [org.apache.jackrabbit.oak.api.jmx.IndexStatsMBean]] ServiceEvent
> UNREGISTERING
> 22.02.2019 12:52:40.900 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [476,
> [org.apache.jackrabbit.oak.plugins.index.property.jmx.PropertyIndexAsyncReindexMBean]]
> ServiceEvent UNREGISTERING
> 22.02.2019 12:52:40.901 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [477,
> [org.apache.jackrabbit.oak.plugins.index.counter.jmx.NodeCounterMBean]]
> ServiceEvent UNREGISTERING
> 22.02.2019 12:52:40.902 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [478,
> [org.apache.jackrabbit.oak.api.jmx.QueryEngineSettingsMBean]]
> ServiceEvent UNREGISTERING
> 22.02.2019 12:52:40.904 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [479,
> [org.apache.jackrabbit.oak.query.stats.QueryStatsMBean]] ServiceEvent
> UNREGISTERING
> 22.02.2019 12:52:40.905 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [480,
> [org.apache.jackrabbit.oak.api.jmx.RepositoryManagementMBean]]
> ServiceEvent UNREGISTERING
> 22.02.2019 12:52:40.906 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.sling.jcr.oak.server Service [481,
> [org.apache.jackrabbit.oak.spi.commit.CommitHook]] ServiceEvent
> UNREGISTERING
> 22.02.2019 12:52:40.906 *INFO* [Apache Sling Repository Startup Thread]
> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate [async] Closed
> 22.02.2019 12:52:49.349 *INFO* [http-nio-8006-exec-1]
> org.apache.felix.http.whiteboard Detected extended HttpService. Filters
> enabled.
> 22.02.2019 12:52:49.358 *INFO* [http-nio-8006-exec-1]
> org.apache.felix.http.bridge Service [486,
> [org.osgi.service.http.HttpService,
> org.apache.felix.http.api.ExtHttpService]] ServiceEvent REGISTERED
> 22.02.2019 12:52:49.358 *INFO* [http-nio-8006-exec-1]
> org.apache.felix.http.bridge Service [487,
> [org.osgi.service.http.runtime.HttpServiceRuntime]] ServiceEvent REGISTERED
> 22.02.2019 12:52:49.360 *INFO* [http-nio-8006-exec-1]
> org.apache.felix.http.bridge Service [488,
> [org.osgi.service.http.context.ServletContextHelper]] ServiceEvent
> REGISTERED
> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
> org.apache.sling.engine.parameters Default Character Encoding: ISO-8859-1
> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
> org.apache.sling.engine.parameters Parameter Number Limit: 10000
> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
> org.apache.sling.engine.parameters Maximum Request Size: -1
> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
> org.apache.sling.engine.parameters Temporary File Location: null
> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
> org.apache.sling.engine.parameters Maximum File Size: -1
> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
> org.apache.sling.engine.parameters Tempory File Creation Threshold: 256000
> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
> org.apache.sling.engine.parameters Check for additional container
> parameters: false
> 22.02.2019 12:52:49.378 *INFO* [http-nio-8006-exec-1]
> org.apache.felix.inventory Service [491, [javax.servlet.Servlet]]
> ServiceEvent REGISTERED
> 22.02.2019 12:52:49.378 *INFO* [http-nio-8006-exec-1]
> org.apache.felix.inventory Service [490,
> [org.apache.felix.inventory.InventoryPrinter]] ServiceEvent REGISTERED
> 22.02.2019 12:52:49.379 *INFO* [http-nio-8006-exec-1]
> org.apache.felix.http.bridge Service [HTTP Service Web Console
> Plugin,489, [javax.servlet.Servlet]] ServiceEvent REGISTERED
> 22.02.2019 12:52:49.383 *ERROR* [http-nio-8006-exec-1]
> org.apache.sling.engine.impl.SlingHttpContext handleSecurity:
> AuthenticationSupport service missing. Cannot authenticate request.
> 22.02.2019 12:52:49.383 *ERROR* [http-nio-8006-exec-1]
> org.apache.sling.engine.impl.SlingHttpContext handleSecurity: Possible
> reason is missing Repository service. Check AuthenticationSupport
> dependencies.
>
>
Reply | Threaded
Open this post in threaded view
|

Re: Upgrading to Oak 1.10.0 for Sling10

marc.davenport
Julian,

Thanks for even the wildest of speculation. I can use all the help I can
get right now.  It looks like the slingevent namespace we don't even
need. I inherited this project as a kind of mess. It looks like whoever
was migrating this from Sling 6 to Sling 10 had just included the
provisioning/model.txt and config/*.config files from the sling10
starter war. The war that we use is still made from a maven assembly
definition.  This assembly includes those configuration files (instead
of generating them from the models) and then repo init reads the
model.txt.   So this is probably one big source of configuration
failures.  We are not including the org.apache.sling.event &
org.apache.sling.event.dea artifacts.  We don't seem to need them. They
simply remain installed but not active bundles when we include them.

I've been trying to rationalize the hit or miss nature of this problem.
In my mind,  I'm looking for a race condition. I'm going to bet that
this is a configuration issue on our end, but I'm not sure how this
would happen or where to look. Perhaps we are have some bundles out of
order.  While I had mentioned in a previous email that we had our own
supplier of SlingRepository, I temporarily removed it trying to debug
this issue.  I can see that two different instances of
OakSlingRepositoryManager (which implement SlingRepository) are created
on the first server startup. I saw this by setting a break point in
start(BundleContext, Config) of AbstractSlingRepositoryManager.

The first is called in a event dispatcher thread for [CM Event
Dispatcher (Fire ConfigurationEvent :
pid=org.apache.jackrabbit.oak.segment.SegmentNodeStoreService)]
I can see this is when the SegmentNodeStoreService is registering itself.

The second instance of the OakSlingRepositoryManager is called from :
[CM Event Dispatcher (Fire ConfigurationEvent:
pid=org.apache.jackrabbit.oak.spi.security.user.action.DefaultAuthorizableActionProvider)]
This is during the call to maybeRegister() in
SecurityProviderRegistration. I can clearly see that this is a different
object.

If I stop and start the server again. start() is only called once (from
a Felix start level thread) and I never have the reported issue of
"AuthenticationSupport service missing"

This very well may be standard operating procedure. Tomorrow I'm going
to deploy the sling10war and look for the exact same behavior to see if
I'm barking up the wrong tree. But if this seems very peculiar (or very
normal) to someone, please let me know what you think.

Marc

On 2/25/19 9:07 AM, Julian Sedding wrote:

> Hi Marc
>
>  From your log, I suspect that the "sling" and "slingevent" Namespaces
> are (not yet?) registered when the repository is being initialized.
> During repository initialization all installed OSGi bundles are
> inspected in order to see whether they contribute namespaces or
> node-type definitions (via special manifest headers and embedded *.cnd
> files).
>
> The "sling" namespace is defined by the bundle
> "org.apache.sling.jcr.resource", the "slingevent" namespace by
> "org-apache-sling-event". Try making sure that they are installed
> before repository initialization happens.
>
> It may help to enable debug logging for "org.apache.sling.jcr.base" to
> better understand when during initialization this happens.
>
> Note: this advice is based on speculation, so YMMV.
>
> Regards
> Julian
>
> On Sat, Feb 23, 2019 at 1:45 AM <[hidden email]> wrote:
>> Robert,
>>
>> Thanks for thinking about this issue with me.
>>
>> You asked: do you have any custom code that plugs into the repository initialisation?
>> I can not find any custom classes that are implementing RepositoryInitilizer.
>>
>> We have a custom class which provides the SlingRepository service and a service ranking of 1000. It wraps the OakSlingRepositoryManager
>>
>>       @Reference(target="(component.name=org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager)")
>>       private SlingRepository repository;
>>
>> We do this so that we can cast the Sessions as our own special Session objects. This is what I've been able to figure out from walking up to this project. This may be a defunct pattern since we have moved from Sling6 to 10 recently.
>>
>> The order of the bundles
>> CustomWorkspace (14) <- contains the custom impl of
>> Oak bundles(15)
>> Sling JCR Oak Server (16)
>>
>> I've tried moving the order of the bundles around to see if I had something in common with SLING-4556, but again this grasping with hope.
>>
>> You asked: "Are you able to inspect the repository after in the scenario where this fails?"
>> As far as a can tell the repository is completely unavailable. But I'm open to debugging suggestions.
>>
>> You asked: "Can you adjust the configuration of the QuartzScheduler to include 'oak' in the allowed pool names?"
>> I'm not sure how to do this. Also, I see this error in both working and non working instances.
>>
>> I've been looking at the logs from the working and failed state trying to find an error or warning that is in one but not the other.  It looks like the OakConstraint error on the missing null primary type actually happens in both situations. So I think tracking down my first error message suspect is a dead end.
>>
>> I lopped off the timestamps so I could diff the logs from a good and a bad state. Below I've added the log messages I should have focused on.  Is there a proper way to share whole logs on this mailing list? Attaching a 9mb file didn't seem appropriate.
>>
>> Thank you for all you time so far,
>> Marc
>>
>> 22.02.2019 12:52:40.867 *ERROR* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager
>> start: Uncaught Throwable trying to access Repository, calling
>> stopRepository()
>> java.lang.NullPointerException: null
>>       at
>> org.apache.sling.jcr.base.AbstractSlingRepositoryManager.initializeAndRegisterRepositoryService(AbstractSlingRepositoryManager.java:478)
>>       at
>> org.apache.sling.jcr.base.AbstractSlingRepositoryManager.access$300(AbstractSlingRepositoryManager.java:85)
>>       at
>> org.apache.sling.jcr.base.AbstractSlingRepositoryManager$4.run(AbstractSlingRepositoryManager.java:455)
>> 22.02.2019 12:52:40.867 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server.internal.OakSlingRepositoryManager stop:
>> Repository still running, forcing shutdown
>> 22.02.2019 12:52:40.868 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [482,
>> [org.apache.jackrabbit.api.jmx.QueryStatManagerMBean]] ServiceEvent
>> UNREGISTERING
>> 22.02.2019 12:52:40.869 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [483,
>> [org.apache.jackrabbit.oak.api.jmx.RepositoryStatsMBean]] ServiceEvent
>> UNREGISTERING
>> 22.02.2019 12:52:40.870 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [484, [java.lang.Runnable]]
>> ServiceEvent UNREGISTERING
>> 22.02.2019 12:52:40.871 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [485,
>> [org.apache.jackrabbit.oak.spi.gc.GCMonitor]] ServiceEvent UNREGISTERING
>> 22.02.2019 12:52:40.874 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [403,
>> [java.util.concurrent.Executor]] ServiceEvent UNREGISTERING
>> 22.02.2019 12:52:40.875 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [474, [java.lang.Runnable]]
>> ServiceEvent UNREGISTERING
>> 22.02.2019 12:52:40.896 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [475,
>> [org.apache.jackrabbit.oak.api.jmx.IndexStatsMBean]] ServiceEvent
>> UNREGISTERING
>> 22.02.2019 12:52:40.900 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [476,
>> [org.apache.jackrabbit.oak.plugins.index.property.jmx.PropertyIndexAsyncReindexMBean]]
>> ServiceEvent UNREGISTERING
>> 22.02.2019 12:52:40.901 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [477,
>> [org.apache.jackrabbit.oak.plugins.index.counter.jmx.NodeCounterMBean]]
>> ServiceEvent UNREGISTERING
>> 22.02.2019 12:52:40.902 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [478,
>> [org.apache.jackrabbit.oak.api.jmx.QueryEngineSettingsMBean]]
>> ServiceEvent UNREGISTERING
>> 22.02.2019 12:52:40.904 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [479,
>> [org.apache.jackrabbit.oak.query.stats.QueryStatsMBean]] ServiceEvent
>> UNREGISTERING
>> 22.02.2019 12:52:40.905 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [480,
>> [org.apache.jackrabbit.oak.api.jmx.RepositoryManagementMBean]]
>> ServiceEvent UNREGISTERING
>> 22.02.2019 12:52:40.906 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.sling.jcr.oak.server Service [481,
>> [org.apache.jackrabbit.oak.spi.commit.CommitHook]] ServiceEvent
>> UNREGISTERING
>> 22.02.2019 12:52:40.906 *INFO* [Apache Sling Repository Startup Thread]
>> org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate [async] Closed
>> 22.02.2019 12:52:49.349 *INFO* [http-nio-8006-exec-1]
>> org.apache.felix.http.whiteboard Detected extended HttpService. Filters
>> enabled.
>> 22.02.2019 12:52:49.358 *INFO* [http-nio-8006-exec-1]
>> org.apache.felix.http.bridge Service [486,
>> [org.osgi.service.http.HttpService,
>> org.apache.felix.http.api.ExtHttpService]] ServiceEvent REGISTERED
>> 22.02.2019 12:52:49.358 *INFO* [http-nio-8006-exec-1]
>> org.apache.felix.http.bridge Service [487,
>> [org.osgi.service.http.runtime.HttpServiceRuntime]] ServiceEvent REGISTERED
>> 22.02.2019 12:52:49.360 *INFO* [http-nio-8006-exec-1]
>> org.apache.felix.http.bridge Service [488,
>> [org.osgi.service.http.context.ServletContextHelper]] ServiceEvent
>> REGISTERED
>> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
>> org.apache.sling.engine.parameters Default Character Encoding: ISO-8859-1
>> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
>> org.apache.sling.engine.parameters Parameter Number Limit: 10000
>> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
>> org.apache.sling.engine.parameters Maximum Request Size: -1
>> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
>> org.apache.sling.engine.parameters Temporary File Location: null
>> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
>> org.apache.sling.engine.parameters Maximum File Size: -1
>> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
>> org.apache.sling.engine.parameters Tempory File Creation Threshold: 256000
>> 22.02.2019 12:52:49.370 *INFO* [http-nio-8006-exec-1]
>> org.apache.sling.engine.parameters Check for additional container
>> parameters: false
>> 22.02.2019 12:52:49.378 *INFO* [http-nio-8006-exec-1]
>> org.apache.felix.inventory Service [491, [javax.servlet.Servlet]]
>> ServiceEvent REGISTERED
>> 22.02.2019 12:52:49.378 *INFO* [http-nio-8006-exec-1]
>> org.apache.felix.inventory Service [490,
>> [org.apache.felix.inventory.InventoryPrinter]] ServiceEvent REGISTERED
>> 22.02.2019 12:52:49.379 *INFO* [http-nio-8006-exec-1]
>> org.apache.felix.http.bridge Service [HTTP Service Web Console
>> Plugin,489, [javax.servlet.Servlet]] ServiceEvent REGISTERED
>> 22.02.2019 12:52:49.383 *ERROR* [http-nio-8006-exec-1]
>> org.apache.sling.engine.impl.SlingHttpContext handleSecurity:
>> AuthenticationSupport service missing. Cannot authenticate request.
>> 22.02.2019 12:52:49.383 *ERROR* [http-nio-8006-exec-1]
>> org.apache.sling.engine.impl.SlingHttpContext handleSecurity: Possible
>> reason is missing Repository service. Check AuthenticationSupport
>> dependencies.
>>
>>
Reply | Threaded
Open this post in threaded view
|

Re: Upgrading to Oak 1.10.0 for Sling10

Robert Munteanu-2
On Mon, 2019-02-25 at 18:53 -0500, [hidden email] wrote:

> I've been trying to rationalize the hit or miss nature of this
> problem.
> In my mind,  I'm looking for a race condition. I'm going to bet that
> this is a configuration issue on our end, but I'm not sure how this
> would happen or where to look. Perhaps we are have some bundles out
> of
> order.  While I had mentioned in a previous email that we had our
> own
> supplier of SlingRepository, I temporarily removed it trying to
> debug
> this issue.  I can see that two different instances of
> OakSlingRepositoryManager (which implement SlingRepository) are
> created
> on the first server startup. I saw this by setting a break point in
> start(BundleContext, Config) of AbstractSlingRepositoryManager.

This reminds me of SLING-7811 [1]. While we did not get to a definitive
solution, it might be worth upgrading the o.a.s.jcr.base bundle to
3.0.6 ( Sling 10 has 3.0.4 ) and see if the situation is improved.

Thanks,

Robert

[1]: https://issues.apache.org/jira/browse/SLING-7811