Felix
  1. Felix
  2. FELIX-2383

Bundles are restarted during start level change

    Details

      Description

      When shutting down felix, some bundles get started again during shutdown: Can be reproduced like this:

      install felix in a fresh directory.
      Put configadmin-1.2.4, shell-1.4.0 and fileinstall-3.0.0 in bundle directory.
      Put pax-logging-api-1.5 and pax-logging-service-1.5 in load directory.
      Put a .cfg file to configure logging in load directory.

      Start felix.
      Stop felix.

      The log output shows that bundles are stopped, and the started again. Felix outputs IllegalStateExceptions: Zipfile is closed during shutdown.

      [DEBUG, 06/03-13:17:49, FelixDispatchQueue , framework ] BundleEvent STOPPED
      [INFO , 06/03-13:17:49, FelixStartLevel , Activator ] Disabling SLF4J API support.
      [INFO , 06/03-13:17:49, FelixStartLevel , Activator ] Disabling Jakarta Commons Logging API support.
      [INFO , 06/03-13:17:49, FelixStartLevel , Activator ] Disabling Log4J API support.
      [INFO , 06/03-13:17:49, FelixStartLevel , Activator ] Disabling Avalon Logger API support.
      [INFO , 06/03-13:17:49, FelixStartLevel , Activator ] Disabling JULI Logger API support.
      [DEBUG, 06/03-13:17:49, FelixDispatchQueue , pax-logging-service ] BundleEvent STARTED <--- HERE **********
      [DEBUG, 06/03-13:17:49, FelixStartLevel , configadmin ] Scheduling task Thread[Configuration Updater,5,main]
      [INFO , 06/03-13:17:49, fileinstall-load , Activator ] Enabling SLF4J API support.
      [INFO , 06/03-13:17:49, fileinstall-load , Activator ] Enabling Jakarta Commons Logging API support.
      [INFO , 06/03-13:17:49, fileinstall-load , Activator ] Enabling Log4J API support.
      [INFO , 06/03-13:17:49, fileinstall-load , Activator ] Enabling Avalon Logger API support.
      [INFO , 06/03-13:17:49, fileinstall-load , Activator ] Enabling JULI Logger API support.
      [DEBUG, 06/03-13:17:49, FelixDispatchQueue , pax-logging-api ] BundleEvent STARTED
      [DEBUG, 06/03-13:17:49, FelixStartLevel , configadmin ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixDispatchQueue , configadmin ] BundleEvent STOPPED
      [DEBUG, 06/03-13:17:49, FelixDispatchQueue , compendium ] BundleEvent STOPPED
      [DEBUG, 06/03-13:17:49, FelixDispatchQueue , remote ] BundleEvent STOPPED
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , shell ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixDispatchQueue , shell ] BundleEvent STOPPED
      [DEBUG, 06/03-13:17:49, FelixStartLevel , fileinstall ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixStartLevel , fileinstall ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixDispatchQueue , fileinstall ] BundleEvent STOPPED
      [DEBUG, 06/03-13:17:49, FelixShutdown , framework ] ServiceEvent UNREGISTERING
      [DEBUG, 06/03-13:17:49, FelixShutdown , framework ] ServiceEvent UNREGISTERING

      java.lang.IllegalStateException: zip file closed
      at java.util.zip.ZipFile.ensureOpen(ZipFile.java:403)
      at java.util.zip.ZipFile.getEntry(ZipFile.java:148)
      at java.util.jar.JarFile.getEntry(JarFile.java:206)
      at org.apache.felix.framework.util.JarFileX.getEntry(JarFileX.java:61)
      at org.apache.felix.framework.cache.JarContent.getEntryAsBytes(JarContent.java:120)
      at org.apache.felix.framework.ModuleImpl$ModuleClassLoader.findClass(ModuleImpl.java:1781)
      at org.apache.felix.framework.ModuleImpl.findClassOrResourceByDelegation(ModuleImpl.java:758)
      at org.apache.felix.framework.ModuleImpl.access$100(ModuleImpl.java:61)
      at org.apache.felix.framework.ModuleImpl$ModuleClassLoader.loadClass(ModuleImpl.java:1733)
      at java.lang.ClassLoader.loadClass(ClassLoader.java:252)
      at org.apache.felix.framework.ModuleImpl.getClassByDelegation(ModuleImpl.java:674)
      at org.apache.felix.framework.ServiceRegistrationImpl$ServiceReferenceImpl.isAssignableTo(ServiceRegistrationImpl.java:470)
      at org.apache.felix.framework.util.Util.isServiceAssignable(Util.java:224)
      at org.apache.felix.framework.util.EventDispatcher.invokeServiceListenerCallback(EventDispatcher.java:848)
      at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:732)
      at org.apache.felix.framework.util.EventDispatcher.fireServiceEvent(EventDispatcher.java:662)
      at org.apache.felix.framework.Felix.fireServiceEvent(Felix.java:3623)
      at org.apache.felix.framework.Felix.access$000(Felix.java:39)
      at org.apache.felix.framework.Felix$2.serviceChanged(Felix.java:667)
      at org.apache.felix.framework.ServiceRegistry.unregisterService(ServiceRegistry.java:124)
      at org.apache.felix.framework.ServiceRegistrationImpl.unregister(ServiceRegistrationImpl.java:129)
      at org.apache.felix.framework.PackageAdminActivator.stop(PackageAdminActivator.java:44)
      at org.apache.felix.framework.util.SecureAction.stopActivator(SecureAction.java:683)
      at org.apache.felix.framework.Felix$SystemBundleActivator.run(Felix.java:4168)
      at java.lang.Thread.run(Thread.java:619)

      If i put the pax-logging bundles in the bundle directory, felix shuts down clean

        Activity

        Hide
        Richard S. Hall added a comment -

        It is not clear to me why you think the framework is restarting a bundle. From the stack trace it is just delivering a service event which causes a class load that fails because the associated bundle JAR file has already been closed. I am not sure why this is happening like this, since the framework should stop every bundle first, so it doesn't seem like there should be any listeners at this point. So, that could still be a bug.

        Show
        Richard S. Hall added a comment - It is not clear to me why you think the framework is restarting a bundle. From the stack trace it is just delivering a service event which causes a class load that fails because the associated bundle JAR file has already been closed. I am not sure why this is happening like this, since the framework should stop every bundle first, so it doesn't seem like there should be any listeners at this point. So, that could still be a bug.
        Hide
        Richard S. Hall added a comment -

        Can you should me what I should put in my .cfg file?

        Show
        Richard S. Hall added a comment - Can you should me what I should put in my .cfg file?
        Hide
        Atle Prange added a comment -

        The reason i suspect this is because the output from the logfiles states "BundleEvent STARTED" (I marked it: <-- HERE at the right side of the log output") during the sutdown.

        Show
        Atle Prange added a comment - The reason i suspect this is because the output from the logfiles states "BundleEvent STARTED" (I marked it: <-- HERE at the right side of the log output") during the sutdown.
        Hide
        Atle Prange added a comment -

        .cfg file for pax logging

        Show
        Atle Prange added a comment - .cfg file for pax logging
        Hide
        Richard S. Hall added a comment -

        Ok, sorry, I didn't see that. In that case, I'd assume that File Install is restarting the bundle during framework shutdown. I will have to look into a way of preventing this. Not that long ago we changed the start level to not actually reflect the changed start level until after the start level was completely changed (as per the spec), this likely opened a window to allow File Install to restart bundles during shutdown.

        I don't use PAX Logging, so a specific example of what the .cfg file should look like would be helpful.

        Show
        Richard S. Hall added a comment - Ok, sorry, I didn't see that. In that case, I'd assume that File Install is restarting the bundle during framework shutdown. I will have to look into a way of preventing this. Not that long ago we changed the start level to not actually reflect the changed start level until after the start level was completely changed (as per the spec), this likely opened a window to allow File Install to restart bundles during shutdown. I don't use PAX Logging, so a specific example of what the .cfg file should look like would be helpful.
        Hide
        Atle Prange added a comment -

        I attached a .cfg file you can use

        Show
        Atle Prange added a comment - I attached a .cfg file you can use
        Hide
        Richard S. Hall added a comment - - edited

        Sorry, apparently I'm a little out of it this morning.

        Is this something you can reproduce on the trunk build? I can't seem to reproduce it, although I do believe there is an issue here. I have a patch for trunk (for framework 3.0), but it would be nice to know if it was reproducible on trunk so I can see if the patch actually addresses the issue.

        We have snapshot of the new framework binary distro in the snapshot repository, which should make it easy for you to test:

        https://repository.apache.org/content/groups/snapshots-group/org/apache/felix/org.apache.felix.main.distribution/2.1.0-SNAPSHOT/

        Show
        Richard S. Hall added a comment - - edited Sorry, apparently I'm a little out of it this morning. Is this something you can reproduce on the trunk build? I can't seem to reproduce it, although I do believe there is an issue here. I have a patch for trunk (for framework 3.0), but it would be nice to know if it was reproducible on trunk so I can see if the patch actually addresses the issue. We have snapshot of the new framework binary distro in the snapshot repository, which should make it easy for you to test: https://repository.apache.org/content/groups/snapshots-group/org/apache/felix/org.apache.felix.main.distribution/2.1.0-SNAPSHOT/
        Hide
        Atle Prange added a comment -

        I tried with the build from 05 / 30, but i observed the same behaviour.

        Show
        Atle Prange added a comment - I tried with the build from 05 / 30, but i observed the same behaviour.
        Hide
        Atle Prange added a comment -

        Disregard. It seems like it is fixed in the latest 2.1.0-SNAPSHOT.

        Show
        Atle Prange added a comment - Disregard. It seems like it is fixed in the latest 2.1.0-SNAPSHOT.
        Hide
        Richard S. Hall added a comment -

        Well, technically, I don't think it is fixed, but since it is related to threading, maybe the timing has changed or some other locking behavior has changed and that impacted the behavior. Can you reproduce the error in framework 2.0.5? If so, I will create a patched version of it for you to test instead, just to make sure my patch does the correct thing. Thanks.

        Show
        Richard S. Hall added a comment - Well, technically, I don't think it is fixed, but since it is related to threading, maybe the timing has changed or some other locking behavior has changed and that impacted the behavior. Can you reproduce the error in framework 2.0.5? If so, I will create a patched version of it for you to test instead, just to make sure my patch does the correct thing. Thanks.
        Hide
        Atle Prange added a comment -

        I can reproduce the error in 2.0.5.

        Show
        Atle Prange added a comment - I can reproduce the error in 2.0.5.
        Hide
        Atle Prange added a comment -

        The patch you sent me works. At least i am not seeing the reported behavior.

        Show
        Atle Prange added a comment - The patch you sent me works. At least i am not seeing the reported behavior.
        Hide
        Richard S. Hall added a comment -

        Ok, great. I will apply a similar patch to trunk, so it gets included in the 3.0.0 release. Thanks.

        Show
        Richard S. Hall added a comment - Ok, great. I will apply a similar patch to trunk, so it gets included in the 3.0.0 release. Thanks.
        Hide
        Richard S. Hall added a comment -

        Closing this since the reported confirmed the fix.

        Show
        Richard S. Hall added a comment - Closing this since the reported confirmed the fix.

          People

          • Assignee:
            Richard S. Hall
            Reporter:
            Atle Prange
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development