search

modular-mind / updatemanager

Simple service that performs p2 auto-update and auto-install logic for Eclipse RCP applications
Eclipse Public License 2.0
7 stars 3 forks source link

Updates work only the first time #5

Closed nagelfargithub closed 2 years ago

nagelfargithub commented 2 years ago

I'm using the UpdateManager for my e4 based Eclipse RCP Client.

The situation: my build generates a zip file containing the full client and a repository directory containing the full p2 repository.

I unpack the zip to my local drive and copy the repository to some webserver. I start the client, the update process starts, checks for updates, there are none and the client starts. This is as expected. Then I do a fresh build and copy the p2 repository to the webserver again. I start the client, the update process starts, updates are found, installed and I automatically restart the client. The new version is properly installed. This is also expected. From then on, whenever I add a new version to the repository and start the client the update process doesn't start properly anymore and the performAutoUpdate method always returns false although I can see the modal dialog that is downloading the new repository content. I can show this in my logs, this is a proper update

21.10.2021 13:56:14.059 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - version: 1.0.0.202110120936
21.10.2021 13:56:14.059 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Starting P2 auto-update process
21.10.2021 13:56:14.062 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Provisioning agent created
21.10.2021 13:56:14.464 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Provisioning session created
21.10.2021 13:56:15.488 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Metadata repository loaded: http://server/klv/p2/
21.10.2021 13:56:15.877 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Artifact repository loaded: http://server/klv/p2/
21.10.2021 13:56:16.758 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Update operation resolved successfully
21.10.2021 13:56:16.759 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Possible updates:
21.10.2021 13:56:16.759 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   -  - Update klv-feature.feature.group 1.0.0.202110120936 ==> klv-feature.feature.group 1.0.0.202110211116
21.10.2021 13:56:16.759 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   -  - Update com.modumind.updatemanager.feature.feature.group 1.0.0.202106231823 ==> com.modumind.updatemanager.feature.feature.group 1.0.0.202110122005
21.10.2021 13:56:16.768 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - IUs to install (possibly 249):
21.10.2021 13:56:16.768 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   -  - nothing to install
21.10.2021 13:56:20.781 [dalContext] [ERROR]  c.e.klv.service.KLVUpdateManagerLogger   - Status severity=0, message=OK, code=0
21.10.2021 13:56:20.785 [dalContext] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Updates installed, restart required
21.10.2021 13:56:21.024 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - update was performed
21.10.2021 13:56:22.970 [      main] [DEBUG]  com.evolit.klv.ui.LifeCycleManager       - let the eventhandler restart the application

This is the second start, no update is necessary

21.10.2021 13:56:30.670 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - version: 1.0.0.202110211116
21.10.2021 13:56:30.670 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - check for updates...
21.10.2021 13:56:30.713 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - no update necessary
21.10.2021 13:56:30.713 [      main] [INFO ]  com.evolit.klv.ui.login.LoginController  - doLogin() -  starting the login dialog

But you can already see that all log message of type KLVUpdateManagerLogger are missing.

From then on, no further updates get processed.

If I "install" the client from scratch again aka start with a fresh workspace and everything the update starts working again image

Any idea why that might be?

nagelfargithub commented 2 years ago

I prepared a testcase. I have my client, version is version: 1.0.0.202110120936. I have two p2 repos, repo1 and repo2. I copy repo1 to my webserver and start the client. Update happens. Client restarts. Version is now 1.0.0.202110211213. I copy repo2, restart the client. I SEE the modal popup downloading the new p2 feature but I don't see any logs, no updates happens and client is still on 1.0.0.202110211213.

Full log

21.10.2021 14:53:41.710 [cf4debd028] [DEBUG]  c.e.k.s.extension.KlvApiObjectMapper     - Initialize new ObjectMapper.
21.10.2021 14:53:43.692 [      main] [INFO ]  c.evolit.klv.ui.state.ApplicationState   - ClientId set to 54E1AD6D54EC
21.10.2021 14:53:43.827 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - ------------------------------
21.10.2021 14:53:43.827 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       -        Starting KLV 4.0       
21.10.2021 14:53:43.828 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - ------------------------------
21.10.2021 14:53:43.828 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.version: 11.0.2
21.10.2021 14:53:43.828 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.class.version: 55.0
21.10.2021 14:53:43.830 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.home: C:\Users\mfrank\Desktop\klv40_client\plugins\org.eclipse.justj.openjdk.hotspot.jre.full.win32.x86_64_11.0.2.v20200815-0835\jre
21.10.2021 14:53:43.830 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.class.path: C:\Users\mfrank\Desktop\klv40_client\\plugins/org.eclipse.equinox.launcher_1.5.700.v20200207-2156.jar
21.10.2021 14:53:43.830 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - user.dir: C:\Users\mfrank\Desktop\klv40_client
21.10.2021 14:53:43.830 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - user.home: C:\Users\mfrank
21.10.2021 14:53:43.830 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - isTest: true
21.10.2021 14:53:43.831 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - repository URL: http://server.evolit.co.at/klv/p2/
21.10.2021 14:53:43.831 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - version: 1.0.0.202110120936
21.10.2021 14:53:43.831 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Starting P2 auto-update process
21.10.2021 14:53:43.834 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Provisioning agent created
21.10.2021 14:53:44.488 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Provisioning session created
21.10.2021 14:53:46.009 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Metadata repository loaded: http://server.evolit.co.at/klv/p2/
21.10.2021 14:53:46.438 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Artifact repository loaded: http://server.evolit.co.at/klv/p2/
21.10.2021 14:53:47.463 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Update operation resolved successfully
21.10.2021 14:53:47.463 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Possible updates:
21.10.2021 14:53:47.463 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   -  - Update klv-feature.feature.group 1.0.0.202110120936 ==> klv-feature.feature.group 1.0.0.202110211213
21.10.2021 14:53:47.463 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   -  - Update com.modumind.updatemanager.feature.feature.group 1.0.0.202106231823 ==> com.modumind.updatemanager.feature.feature.group 1.0.0.202110122005
21.10.2021 14:53:47.472 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - IUs to install (possibly 249):
21.10.2021 14:53:47.473 [      main] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   -  - nothing to install
21.10.2021 14:53:51.514 [dalContext] [ERROR]  c.e.klv.service.KLVUpdateManagerLogger   - Status severity=0, message=OK, code=0
21.10.2021 14:53:51.518 [dalContext] [INFO ]  c.e.klv.service.KLVUpdateManagerLogger   - Updates installed, restart required
21.10.2021 14:53:51.567 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - update was performed
21.10.2021 14:53:55.352 [      main] [DEBUG]  com.evolit.klv.ui.LifeCycleManager       - let the eventhandler restart the application
21.10.2021 14:53:55.672 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - processAdditions()
21.10.2021 14:53:55.673 [      main] [INFO ]  c.e.klv.ui.part.utils.ResourceUtils      - loadFont(fontPath=resources/fonts/MaterialIcons-Regular.ttf)
21.10.2021 14:53:55.700 [      main] [INFO ]  c.e.klv.ui.part.utils.ResourceUtils      - Load font for file: C:\Users\mfrank\Desktop\klv40_client\configuration\org.eclipse.osgi\29\0\.cp\resources\fonts\MaterialIcons-Regular.ttf
21.10.2021 14:53:55.702 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - Icon Font resources/fonts/MaterialIcons-Regular.ttf successfully loaded
21.10.2021 14:53:56.142 [      main] [INFO ]  com.evolit.klv.ui.part.DashboardPart     - createControls()
21.10.2021 14:53:56.168 [      main] [INFO ]  c.e.k.u.s.AbrechnungViewSizeService      - init()
21.10.2021 14:53:56.224 [      main] [INFO ]  com.evolit.klv.ui.part.KLVBreadcrumb     - createBreadcrumb()
21.10.2021 14:53:56.227 [      main] [INFO ]  c.e.klv.ui.part.utils.ResourceUtils      - getImage(name=right.png) using the ResourceManager
21.10.2021 14:53:56.347 [      main] [INFO ]  c.e.k.u.u.ApplicationUpdateListener      - event received, restarting workbench
21.10.2021 14:54:02.567 [      main] [INFO ]  c.evolit.klv.ui.state.ApplicationState   - ApplicationState init
21.10.2021 14:54:02.975 [      main] [INFO ]  c.evolit.klv.ui.state.ApplicationState   - ClientId set to 54E1AD6D54EC
21.10.2021 14:54:03.086 [      main] [INFO ]  com.evolit.klv.ui.login.LoginController  - LoginController init
21.10.2021 14:54:03.088 [      main] [INFO ]  c.e.k.u.p.u.AnwenderEinstellungCache     - AnwenderEinstellungCache init
21.10.2021 14:54:03.102 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - LifeCycleManager init
21.10.2021 14:54:03.107 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - ------------------------------
21.10.2021 14:54:03.107 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       -        Starting KLV 4.0       
21.10.2021 14:54:03.107 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - ------------------------------
21.10.2021 14:54:03.107 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.version: 11.0.2
21.10.2021 14:54:03.108 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.class.version: 55.0
21.10.2021 14:54:03.108 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.home: C:\Users\mfrank\Desktop\klv40_client\plugins\org.eclipse.justj.openjdk.hotspot.jre.full.win32.x86_64_11.0.2.v20200815-0835\jre
21.10.2021 14:54:03.108 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.class.path: C:\Users\mfrank\Desktop\klv40_client\\plugins/org.eclipse.equinox.launcher_1.5.700.v20200207-2156.jar
21.10.2021 14:54:03.108 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - user.dir: C:\Users\mfrank\Desktop\klv40_client
21.10.2021 14:54:03.108 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - user.home: C:\Users\mfrank
21.10.2021 14:54:03.108 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - isTest: true
21.10.2021 14:54:03.109 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - repository URL: http://server.evolit.co.at/klv/p2/
21.10.2021 14:54:03.109 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - version: 1.0.0.202110211213
21.10.2021 14:54:03.109 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - check for updates...now really
21.10.2021 14:54:03.141 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - no update necessary
21.10.2021 14:54:03.142 [      main] [INFO ]  com.evolit.klv.ui.login.LoginController  - doLogin() -  starting the login dialog
21.10.2021 14:54:03.199 [      main] [INFO ]  com.evolit.klv.ui.login.LoginController  - doLogin with dialog
21.10.2021 14:54:03.289 [      main] [INFO ]  c.e.klv.ui.part.utils.ResourceUtils      - getImage(name=container.gif) using the ResourceManager
21.10.2021 14:54:06.053 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - User canceled the login exit the application
21.10.2021 14:54:34.668 [      main] [INFO ]  c.evolit.klv.ui.state.ApplicationState   - ApplicationState init
21.10.2021 14:54:35.177 [      main] [INFO ]  c.evolit.klv.ui.state.ApplicationState   - ClientId set to 54E1AD6D54EC
21.10.2021 14:54:35.309 [      main] [INFO ]  com.evolit.klv.ui.login.LoginController  - LoginController init
21.10.2021 14:54:35.311 [      main] [INFO ]  c.e.k.u.p.u.AnwenderEinstellungCache     - AnwenderEinstellungCache init
21.10.2021 14:54:35.325 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - LifeCycleManager init
21.10.2021 14:54:35.328 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - ------------------------------
21.10.2021 14:54:35.329 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       -        Starting KLV 4.0       
21.10.2021 14:54:35.329 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - ------------------------------
21.10.2021 14:54:35.329 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.version: 11.0.2
21.10.2021 14:54:35.329 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.class.version: 55.0
21.10.2021 14:54:35.329 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.home: C:\Users\mfrank\Desktop\klv40_client\plugins\org.eclipse.justj.openjdk.hotspot.jre.full.win32.x86_64_11.0.2.v20200815-0835\jre
21.10.2021 14:54:35.329 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - java.class.path: C:\Users\mfrank\Desktop\klv40_client\\plugins/org.eclipse.equinox.launcher_1.5.700.v20200207-2156.jar
21.10.2021 14:54:35.329 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - user.dir: C:\Users\mfrank\Desktop\klv40_client
21.10.2021 14:54:35.330 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - user.home: C:\Users\mfrank
21.10.2021 14:54:35.330 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - isTest: true
21.10.2021 14:54:35.330 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - repository URL: http://server.evolit.co.at/klv/p2/
21.10.2021 14:54:35.330 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - version: 1.0.0.202110211213
21.10.2021 14:54:35.330 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - check for updates...now really
21.10.2021 14:54:42.033 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - no update necessary
21.10.2021 14:54:42.034 [      main] [INFO ]  com.evolit.klv.ui.login.LoginController  - doLogin() -  starting the login dialog
21.10.2021 14:54:42.044 [      main] [INFO ]  com.evolit.klv.ui.login.LoginController  - doLogin with dialog
21.10.2021 14:54:42.135 [      main] [INFO ]  c.e.klv.ui.part.utils.ResourceUtils      - getImage(name=container.gif) using the ResourceManager
21.10.2021 14:54:45.042 [      main] [INFO ]  com.evolit.klv.ui.LifeCycleManager       - User canceled the login exit the application
nagelfargithub commented 2 years ago

So, I'm one step further without understanding what is going on. After the first update has worked the Logger can't be injected anymore. I don't know why it isn't injected but it leads to a NullpointerException because of this code part:

private void log(String message, Throwable e) {
        if (this.logger == null) {
            System.out.println(message);
            e.printStackTrace();
            return;
        }

        this.logger.log(message, e);
    }

This Nullpointers on e.printStackTrace() if e is null. So it is not that the update doesn't work the second time because of the update mechanism itself but because the Logger can't be injected which in turn leads to a Nullpointer which in turn kills the update. My working theory so far: I have version 0, version 1 and version 2. From version 0 to version 1 I (somehow) broke the injection of the logger. So the update from 0 to 1 works as well as the update from 0 to 2. But the update from 1 to 2 doesn't work as the logger can't be injected anymore which nullpointers which prevents updates. I'll try to confirm this in my local setup.

modular-mind commented 2 years ago

Focusing on the NPE first, this is definitely a bug. When logging out Status objects the exception is passed to the logger even if it's null. This is now fixed and the new version is in the p2 repository.

If after that there is still an issue with updates not occurring, let me know and I'll look into it.

nagelfargithub commented 2 years ago

I'll update to the new version. Besides the nullpointer I still think there is an issue that the Logger can't be injected on updated clients but I'll try to confirm this after the update.

nagelfargithub commented 2 years ago

Updated, still NullPointering on e.printStackTrace as the logger is null.

if (e == null) {
  log(message);
}

if (this.logger == null) {
  System.out.println(message);
  e.printStackTrace();
  return;
}

We either need a return after the newly introduced log(message) or perhaps better rewrite the stacktrace part?

        if (this.logger == null) {
            System.out.println(message);
                        if(e != null) {
              e.printStackTrace();
                        }
            return;
        }
modular-mind commented 2 years ago

Ugh, need to drink some more coffee this morning ;-) Added a return after the call to log(message).

nagelfargithub commented 2 years ago

Another observation, this is the start of the logfile on a "clean" start (without any prior update)

17:11:15.553 [Start Level: Equinox Container: 56b500db-eb98-4011-81bf-301ccbd78d12] DEBUG c.e.k.s.extension.KlvApiObjectMapper - Initialize new ObjectMapper.
17:11:15.906 [Start Level: Equinox Container: 56b500db-eb98-4011-81bf-301ccbd78d12] INFO  c.e.k.service.KLVUpdateManagerLogger - Initialize new KLVUpdateManagerLogger
17:11:17.106;IMPORT_REGISTRATION;importedSR={com.evolit.klv.service.AbrechnungServiceInterface, com.evolit.klv.service.AnwenderEinstellungServiceInterface, com.evolit.klv.service.AuthenticationServiceInterface, com.evolit.klv.service.BetreiberServiceInterface, com.evolit.klv.service.LookupServiceInterface, com.evolit.klv.service.RechnungServiceInterface, com.evolit.klv.service.TerminalServiceInterface, com.evolit.klv.service.NebengebuehrServiceInterface, com.evolit.klv.service.ITEVorgangServiceInterface, com.evolit.klv.service.ReportingServiceInterface, com.evolit.klv.service.LogEndToEndServiceInterface, com.evolit.klv.service.AbrechnungKorrekturServiceInterface, com.evolit.klv.service.KundenServiceInterface}={service.intents=osgi.async,

We can see the KLVUpdateManagerLogger being initialized. After that the update happens and I restart the application automatically, this is what the log looks like now

17:12:03.480 [Start Level: Equinox Container: 52c0a665-54db-4431-98f0-50a6eb78a531] DEBUG c.e.k.s.extension.KlvApiObjectMapper - Initialize new ObjectMapper.
17:12:05.110;IMPORT_REGISTRATION;importedSR={com.evolit.klv.service.AbrechnungServiceInterface, com.evolit.klv.service.AnwenderEinstellungServiceInterface, com.evolit.klv.service.AuthenticationServiceInterface, com.evolit.klv.service.BetreiberServiceInterface, com.evolit.klv.service.LookupServiceInterface, com.evolit.klv.service.RechnungServiceInterface, com.evolit.klv.service.TerminalServiceInterface, com.evolit.klv.service.NebengebuehrServiceInterface, com.evolit.klv.service.ITEVorgangServiceInterface, com.evolit.klv.service.ReportingServiceInterface, com.evolit.klv.service.LogEndToEndServiceInterface, com.evolit.klv.service.AbrechnungKorrekturServiceInterface, com.evolit.klv.service.KundenServiceInterface}={service.intents=osgi.async,

Initialize new KLVUpdateManagerLogger is now missing and also missing on any subsequent start of the application. The log happens in the constructor

    public KLVUpdateManagerLogger() {
        log.info("Initialize new KLVUpdateManagerLogger");
    }

So for whatever reason the constructor is not called after an update has happened.

Could you please also update the repository, I'm still seeing only the old version.

nagelfargithub commented 2 years ago

Updated to the new version and also changed my XML config to have immediate=true (which was missing before). It now looks like this

<?xml version="1.0" encoding="UTF-8"?>
<scr:component xmlns:scr="http://www.osgi.org/xmlns/scr/v1.1.0" immediate="true" name="com.evolit.klv.service.extension.KlvApiObjectMapper">
   <implementation class="com.evolit.klv.service.extension.KlvApiObjectMapper"/>
   <property name="jaxrs-service-exported-config-target" value="ecf.jaxrs.jersey.client"/>
   <service>
      <provide interface="javax.ws.rs.ext.ContextResolver"/>
   </service>
</scr:component>

Now I always see the logger being initialized

18:02:24.439 [Start Level: Equinox Container: 4fc22113-9d78-4fbf-aba6-e88660bd94a4] DEBUG c.e.k.s.extension.KlvApiObjectMapper - Initialize new ObjectMapper.
18:02:24.617 [Start Level: Equinox Container: 4fc22113-9d78-4fbf-aba6-e88660bd94a4] INFO  c.e.k.service.KLVUpdateManagerLogger - Initialize new KLVUpdateManagerLogger
18:02:25.577;IMPORT_REGISTRATION;importedSR={com.evolit.klv.service.AbrechnungServiceInterface, com.evolit.klv.service.A

but it still doesn't get injected into the UpdateManager so logmessages still go to System.out.

modular-mind commented 2 years ago

Could you show me the XML config for the logger? The XML above is for the object mapper.

nagelfargithub commented 2 years ago

My bad

<?xml version="1.0" encoding="UTF-8"?>
<scr:component xmlns:scr="http://www.osgi.org/xmlns/scr/v1.1.0" immediate="true" name="com.evolit.klv.service.KLVUpdateManagerLogger">
   <service>
      <provide interface="com.modumind.updatemanager.service.UpdateManagerLogger"/>
   </service>
   <implementation class="com.evolit.klv.service.KLVUpdateManagerLogger"/>
</scr:component>

Perhaps we are a running into a similar problem like https://stackoverflow.com/questions/55168855/osgi-declarative-services-does-not-bind-services-when-manually-installing-bundle and need to set policyOption=ReferencePolicyOption.GREEDY) or volatile/dynamic as stated at https://enroute.osgi.org/FAQ/300-declarative-services.html

EDIT: perhaps also taking into account this part

The following bad code shows a common (but horrible) pattern that people use to use foo:

    if ( foo != null ) // BAD!
        foo.bar();
This innocuous looking code is actually a Null Pointer Exception in the waiting. A better way is to do:

    Foo foo = this.foo;
    if ( foo != null )
        foo.bar();
By using a local variable we guarantee that the check (is foo null?) is using the same object as the one we will call bar() on. This is a very cheap form of synchronization.
modular-mind commented 2 years ago

I updated the DS settings to include the policy option, and also updated the null checks. Can you also check in the OSGi console to make sure the bundle that contributes the logger has started up properly?

nagelfargithub commented 2 years ago

Thanks, will let you know monday, latest tuesday.

nagelfargithub commented 2 years ago

I'm happy to report that this change has fixed things for me. I didn't check the OSGi console but the logger gets now injected every single time, on restarts, after update as well as on subsequent starts and even after updating twice, thanks a lot!