Error in Security Loader

[Steven Githens]

Hi Kernel,

Just did a complete fresh script run of the 3akai-sling build steps. Is
anyone else seeing the following?

Cheers,
Steve

23:54:59 slingtests: java -jar
osgikernel/app/target/org.sakaiproject.kernel.app-0.1-SNAPSHOT.jar
04.06.2009 23:55:16.510 *INFO* [main] Setting sling.home=sling (default)
04.06.2009 23:55:16.510 *INFO* [main] Starting Sling in sling
04.06.2009 23:55:16.511 *INFO* [main] Checking launcher JAR in sling
04.06.2009 23:55:16.562 *INFO* [main] Installed or Updated launcher JAR
file from
jar:file:/home/sgithens/code/3akai-work/open-experiments/slingtests/osgikernel/app/target/org.sakaiproject.kernel.app-0.1-SNAPSHOT.jar!/resources/org.apache.sling.launchpad.base.jar
04.06.2009 23:55:16.562 *INFO* [main] Loading launcher class
org.apache.sling.launchpad.base.app.MainDelegate
04.06.2009 23:55:16.593 *INFO* [main] Starting launcher ...
04.06.2009 23:55:16.595 *INFO* [main] HTTP server port: 8080
Persistence bundle starting...
Persistence bundle started.
ProviderTracker: New service detected...
ProviderTracker: Added service
org.eclipse.persistence.jpa.osgi.PersistenceProviderOSGi
ERROR: Error starting
slinginstall:org.sakaiproject.kernel.securityloader-0.1-SNAPSHOT.jar
(org.osgi.framework.BundleException: Unresolved constraint in bundle 75:
package; (package=org.apache.sling.jackrabbit.usermanager.api.event))
org.osgi.framework.BundleException: Unresolved constraint in bundle 75:
package; (package=org.apache.sling.jackrabbit.usermanager.api.event)
at org.apache.felix.framework.Felix.resolveBundle(Felix.java:3097)
at org.apache.felix.framework.Felix.startBundle(Felix.java:1439)
at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:984)
at
org.apache.felix.framework.StartLevelImpl.run(StartLevelImpl.java:263)
at java.lang.Thread.run(Thread.java:595)
[EL Info]: 2009-06-04
23:55:26.307--ServerSession(12058647)--Thread(Thread[FelixStartLevel,5,main])--EclipseLink,
version: Eclipse Persistence Services - 1.1.0.r3634
[EL Info]: 2009-06-04
23:55:29.365--ServerSession(12058647)--Thread(Thread[FelixStartLevel,5,main])--file:/tmp/sakai/1244174125886/-default
login successful
Entity Manager List 1
org.eclipse.persistence.internal.jpa.EntityManagerImpl@18f48a1 on
Thread[FelixStartLevel,5,main]

04.06.2009 23:55:30.425 *INFO* [main] Startup completed

[paulbr]

Steve,

When you go to /system/console do you have a number of bundles in
resolved state rather than active? If so I may have experienced this.

Did you delete the old sling directory? I think this might fix it.

(My current issue with building is that /dev errors with
'ResourceResolverFactory service missing, cannot service requests' -
it works fine from the binary snapshot of 27 May)

Paul

[paulbr]

> (My current issue with building is that /dev errors with
> 'ResourceResolverFactory service missing, cannot service requests' -
> it works fine from the binary snapshot of 27 May)

Now working, just takes a while to load:

sling\logs\error.log(576): 05.06.2009 14:50:51.036 *ERROR* [127.0.0.1
[1244177451021] GET /dev HTTP/1.1]
org.apache.sling.engine.impl.SlingMainServlet ResourceResolverFactory
service missing, cannot service requests , sending status 503
sling\logs\error.log(597): 05.06.2009 14:50:59.722 *INFO* [SCR
Component Actor] org.apache.sling.jcr.resource Service
[org.apache.sling.jcr.resource.internal.JcrResourceResolverFactoryImpl,
135] ServiceEvent REGISTERED

Paul

[Steven Githens]

Ah, yup, you're right, it does help to just wait a while. (luckily I
didn't kill it and am just checkign back several hours later now :p )
I won't consider the '[main] Startup completed' to be the definitive
signal of readyness again. :)

Cheers,
Steve
> Paul
> >
>

[Ian Boston]

The loading of the UX files into the JCR takes a while on first start
( there are 1000 of them).
Second starts should be much faster, and yes, there is a certain
amount of lazyness, with some components not being declarative with
loose binding it quite possible for the container to look like its up
with services still coming in.
Ian

[Simon Gaeremynck]

I just downloaded a fresh copy for the bundles and the open
expirements as well. After compiling and trying to run the kernel I
get the following error message:

morion:osgikernel sg555$ java -jar app/target/
org.sakaiproject.kernel.app-0.1-SNAPSHOT.jar -f -
05.06.2009 10:56:16.361 *INFO* [main] Setting sling.home=sling
(default)
05.06.2009 10:56:16.362 *INFO* [main] Starting Sling in sling
05.06.2009 10:56:16.362 *INFO* [main] Checking launcher JAR in sling
05.06.2009 10:56:16.374 *INFO* [main] Existing launcher JAR file
already up to date
05.06.2009 10:56:16.374 *INFO* [main] Loading launcher class
org.apache.sling.launchpad.base.app.MainDelegate
05.06.2009 10:56:16.393 *INFO* [main] Starting launcher ...
05.06.2009 10:56:16.395 *INFO* [main] HTTP server port: 8080
05.06.2009 10:56:17.124 *INFO* [FelixStartLevel] org.mortbay.jetty
Logging to org.ops4j.pax.web.service.internal.util.JCLLogger@eb717e
via org.ops4j.pax.web.service.internal.util.JCLLogger
05.06.2009 10:56:17.124 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.Activator Starting pax http service
05.06.2009 10:56:17.140 *WARN* [FelixStartLevel]
org.ops4j.pax.web.service.internal.ConfigurationImpl Reading
configuration property org.ops4j.pax.web.session.timeout has failed
05.06.2009 10:56:17.140 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.ServerControllerImpl configuring
server: ServerControllerImpl{state=UNCONFIGURED} -> ConfigurationImpl
{http enabled=true,http port=8080,http secure enabled=false,http
secure port=8443,ssl keystore=/Users/sg555/.keystore,ssl
keystoreType=null,session timeout=null,listening addresses=
[Ljava.lang.String;@b2ede8}
05.06.2009 10:56:17.141 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.ServerControllerImpl starting
server: ServerControllerImpl{state=STOPPED}
05.06.2009 10:56:17.169 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.JettyServerImpl adding
connectorNIOSocke...@0.0.0.0:8080
05.06.2009 10:56:17.171 *WARN* [FelixStartLevel]
org.ops4j.pax.web.service.internal.ConfigurationImpl Reading
configuration property org.ops4j.pax.web.session.timeout has failed
05.06.2009 10:56:17.171 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.JettyServerImpl starting
JettyServerImpl{}
05.06.2009 10:56:17.171 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.JettyServerImpl configure using
bundle://77.0:1/jetty.xml
05.06.2009 10:56:17.247 *INFO* [FelixStartLevel] org.mortbay.jetty
jetty-0.1-SNAPSHOT
05.06.2009 10:56:17.288 *INFO* [FelixStartLevel] org.mortbay.jetty
Started NIOSocketCon...@0.0.0.0:8080
05.06.2009 10:56:17.291 *INFO* [FelixStartLevel] org.mortbay.jetty
Started Ajp13Socke...@0.0.0.0:8009
05.06.2009 10:56:17.292 *INFO* [FelixStartLevel] org.mortbay.jetty
AJP13 is not a secure protocol. Please protect port 8009
05.06.2009 10:56:17.293 *WARN* [FelixStartLevel]
org.ops4j.pax.web.service.internal.ConfigurationImpl Reading
configuration property org.ops4j.pax.web.session.timeout has failed
05.06.2009 10:56:17.294 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.HttpServiceFactoryImpl binding
bundle: [org.apache.felix.webconsole [75]] to http service
05.06.2009 10:56:17.299 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.HttpServiceStarted Creating http
service for: org.apache.felix.webconsole [75]
05.06.2009 10:56:17.340 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.HttpServiceProxy Creating adefault
context
05.06.2009 10:56:17.341 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.HttpServiceProxy Registering
servlet: [/system/console] ->
org.apache.felix.webconsole.internal.servlet.OsgiManager@d557c2
05.06.2009 10:56:17.378 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.JettyServerWrapper added servlet
context: HttpServiceContext
{httpContext=org.apache.felix.webconsole.internal.servlet.OsgiManagerHttpContext@74b024}
*INFO * Failed to instantiate plugin
org.apache.felix.webconsole.internal.misc.ShellServlet. Reason:
java.lang.NoClassDefFoundError: org.apache.felix.shell.ShellService
05.06.2009 10:56:17.468 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.HttpServiceProxy Registering
resource: [/system/console/res] -> /res
05.06.2009 10:56:17.469 *INFO* [FelixStartLevel]
org.ops4j.pax.web.service.internal.Activator Started pax http service
INFO : org.sakaiproject.kernel.meservice (66): Ignoring unsupported
element {}components (bundle
slinginstall:org.sakaiproject.kernel.meservice-0.1-SNAPSHOT.jar)
INFO : org.sakaiproject.kernel.meservice (66):
[org.sakaiproject.kernel.meservice.MeServiceResourceProvider]
Dependency not satisfied: UserFactoryService
INFO : org.sakaiproject.kernel.site (67): Ignoring unsupported element
{}components (bundle slinginstall:org.sakaiproject.kernel.site-0.1-
SNAPSHOT.jar)
INFO : org.sakaiproject.kernel.site (67):
[org.sakaiproject.kernel.site.SiteServiceImpl] Dependency not
satisfied: eventAdmin
INFO : org.apache.sling.fsresource (68): Ignoring unsupported element
{}components (bundle slinginstall:org.apache.sling.fsresource-0.9.3-
incubator-SNAPSHOT.jar)
INFO : org.sakaiproject.kernel.site (67):
[org.sakaiproject.kernel.site.servlet.SiteGetServlet] Dependency not
satisfied: SiteService
INFO : org.sakaiproject.kernel.site (67):
[org.sakaiproject.kernel.site.servlet.SiteJoinServlet] Dependency not
satisfied: SiteService
INFO : org.sakaiproject.kernel.site (67):
[org.sakaiproject.kernel.site.servlet.SiteMembersServlet] Dependency
not satisfied: SiteService
INFO : org.sakaiproject.kernel.site (67):
[org.sakaiproject.kernel.site.servlet.SiteMembershipServlet]
Dependency not satisfied: SiteService
INFO : org.sakaiproject.kernel.site (67):
[org.sakaiproject.kernel.site.servlet.SiteUnJoinServlet] Dependency
not satisfied: SiteService
05.06.2009 10:56:17.623 *INFO* [FelixStartLevel]
org.sakaiproject.kernel.guice.OsgiServiceProvider Service
org.sakaiproject.kernel.api.configuration.ConfigurationServicenot yet
available, will register when it is
ERROR: Error starting
slinginstall:org.sakaiproject.kernel.lifecycle-0.1-SNAPSHOT.jar
(org.osgi.framework.BundleException: Activator start error in bundle
org.sakaiproject.kernel.lifecycle [71].)
java.lang.IllegalStateException: Service
org.sakaiproject.kernel.api.configuration.ConfigurationService is not
yet available, last Event was :null
at org.sakaiproject.kernel.guice.OsgiServiceProvider.invoke
(OsgiServiceProvider.java:127)
at $Proxy4.getProperties(Unknown Source)
at org.sakaiproject.kernel.guice.AbstractOsgiModule.configure
(AbstractOsgiModule.java:55)
at org.sakaiproject.kernel.lifecycle.ActivatorModule.configure
(ActivatorModule.java:43)
at com.google.inject.AbstractModule.configure(AbstractModule.java:66)
at com.google.inject.BinderImpl.install(BinderImpl.java:199)
at com.google.inject.Guice.createInjector(Guice.java:77)
at com.google.inject.Guice.createInjector(Guice.java:53)
at com.google.inject.Guice.createInjector(Guice.java:43)
at org.sakaiproject.kernel.guice.GuiceActivator.start
(GuiceActivator.java:53)
at org.sakaiproject.kernel.lifecycle.Activator.start(Activator.java:
53)
at org.apache.felix.framework.util.SecureAction.startActivator
(SecureAction.java:589)
at org.apache.felix.framework.Felix.startBundle(Felix.java:1458)

at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:
984)
at org.apache.felix.framework.StartLevelImpl.run(StartLevelImpl.java:
263)

at java.lang.Thread.run(Thread.java:613)
INFO : org.sakaiproject.kernel.personal (72): Ignoring unsupported
element {}components (bundle
slinginstall:org.sakaiproject.kernel.personal-0.1-SNAPSHOT.jar)
05.06.2009 10:56:17.634 *INFO* [main] Startup completed



If I go into system/console/bundles I see a lot of bundles with a
Resolved status. My webdav is also completely empty.
I have deleted my previous checkout.
I also tried recompiling a few times, but that doesn't seem to help
much.
Any ideas?

Simon

[Ian Boston]

Did you refresh and rebuild our branch of sling ?
There have been a number of changes recently.

Also, which OS ?
Ian

[Simon Gaeremynck]

I'm currently on Mac OSX 10.5.7
I cloned a fresh copy for k2-sling and open-expirements.
Simon

> > connectorNIOSocketConnectorWrap...@0.0.0.0:8080

> > 05.06.2009 10:56:17.171 *WARN* [FelixStartLevel]
> > org.ops4j.pax.web.service.internal.ConfigurationImpl Reading
> > configuration property org.ops4j.pax.web.session.timeout has failed
> > 05.06.2009 10:56:17.171 *INFO* [FelixStartLevel]
> > org.ops4j.pax.web.service.internal.JettyServerImpl starting
> > JettyServerImpl{}
> > 05.06.2009 10:56:17.171 *INFO* [FelixStartLevel]
> > org.ops4j.pax.web.service.internal.JettyServerImpl configure using
> > bundle://77.0:1/jetty.xml
> > 05.06.2009 10:56:17.247 *INFO* [FelixStartLevel] org.mortbay.jetty
> > jetty-0.1-SNAPSHOT
> > 05.06.2009 10:56:17.288 *INFO* [FelixStartLevel] org.mortbay.jetty

> > Started NIOSocketConnectorWrap...@0.0.0.0:8080

> > 05.06.2009 10:56:17.291 *INFO* [FelixStartLevel] org.mortbay.jetty

> > Started Ajp13SocketConnec...@0.0.0.0:8009

> ...
>
> read more »

[Ian Boston]

In your executable jar,
where is the bundle
org.sakaiproject.kernel.configuration-0.1-SNAPSHOT.jar
located and where is
org.sakaiproject.kernel.lifecycle-0.1-SNAPSHOT.jar

located.

Lifecycle appears to be starting before configuration is available.

Ian

[Simon Gaeremynck]

I have just rebooted and downloaded the k2-sling and open experiments
files and compiled them.
Now I am able to start the server without any problem.

No idea what the cause could be however.
Simon

> ...
>
> read more »

[Ian Boston]

You might have had another copy of the server running, which would
have prevented some of the services that bind to ports coming up.
Ian