Ask Questions and Find Answers
Important:
Ask is now read-only. You can review any existing questions and answers, but not add anything new.
But - don't panic! While ask is no more, we've replaced it with discuss - the new Liferay Discussion Forum! Read more here here or just visit the site here:
discuss.liferay.com
RE: How to debug an OSGi module start/stop loop?
Hi all,
We've got a strange problem here. We've got a bunch of custom modules deployed in our 7.3.3ga4 instance (mostly fragments and language resources), and we keep getting module start-stop loops after some hot-deploys. That is: three Liferay modules stopping and starting themselves repeatedly and indefinitely:
2021-03-16 10:13:00.064 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.contacts.web_4.0.18 [1109]
2021-03-16 10:13:00.075 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.social.activities.taglib_3.0.4 [879]
2021-03-16 10:13:00.091 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.social.activities.web_5.0.6 [782]
2021-03-16 10:13:00.222 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.social.activities.web_5.0.6 [782]
2021-03-16 10:13:00.267 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.social.activities.taglib_3.0.4 [879]
2021-03-16 10:13:00.302 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.contacts.web_4.0.18 [1109]
2021-03-16 10:13:00.441 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.contacts.web_4.0.18 [1109]
2021-03-16 10:13:00.451 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.social.activities.taglib_3.0.4 [879]
2021-03-16 10:13:00.468 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.social.activities.web_5.0.6 [782]
2021-03-16 10:13:00.602 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.social.activities.web_5.0.6 [782]
2021-03-16 10:13:00.647 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.social.activities.taglib_3.0.4 [879]
2021-03-16 10:13:00.678 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.contacts.web_4.0.18 [1109]
2021-03-16 10:13:00.764 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.social.activities.web_5.0.6 [782]
2021-03-16 10:13:00.891 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.social.activities.web_5.0.6 [782]
2021-03-16 10:13:01.000 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.asset.publisher.web_4.0.26 [329]
2021-03-16 10:13:01.134 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.asset.publisher.web_4.0.26 [329]
2021-03-16 10:13:01.371 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.social.activities.web_5.0.6 [782]
2021-03-16 10:13:01.531 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.social.activities.web_5.0.6 [782]
2021-03-16 10:13:01.608 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.contacts.web_4.0.18 [1109]
2021-03-16 10:13:01.617 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.social.activities.taglib_3.0.4 [879]
2021-03-16 10:13:01.633 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:49] STOPPED com.liferay.social.activities.web_5.0.6 [782]
2021-03-16 10:13:01.768 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.social.activities.web_5.0.6 [782]
2021-03-16 10:13:01.818 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.social.activities.taglib_3.0.4 [879]
2021-03-16 10:13:01.853 INFO [Refresh Thread: Equinox Container: f91611d8-c156-48ba-910b-3006228e0b85][BundleStartStopLogger:46] STARTED com.liferay.contacts.web_4.0.18 [1109]
We did override some language strings of com.liferay.social.activities.web using a custom resource bundle module. But even if we remove that, then restart Liferay, then hot-deploy a completely different resource bundle, we end up with this deploy loop (after the portal stopped and started a bunch of other modules).
The start-stop loop can be interrupted by restarting Tomcat, but after that, the language strings from our resource bundles are not being used. Hot-deploying the resource bundle then helped in the past, but now we keep getting those start-stop loops after deploy, which can only be interrupted by restarting Tomcat, after which our language strings are not being used anymore (despite the gogo shell telling us that the module is deployed and active).
So, since we did not succeed in creating a minimal error reproduction example, our question would be: How can we debug this mess? How can we find out _why_ three Liferay modules decide to stop and start themselves over and over again? (Increasing the log level of BundleStartStopLogger does not produce any new information in the logs).
We've got the same problem. If you ever find a solution it would be nice to post it here...
Just a very wild guess here:
Does this loop happen if
you restart (without rebuilding) on the next day? (maybe only the next
hour or two)
What I'm after here is a detection of a changed bundle that isn't changed but timestamped in the future, through different timezone assumptions by the build system and the deploying system.
Edit after Dominik's reply:
If the problem goes away after a while, this is a good pointer: If the server is running on UTC timezone, but your deployed bundles are built on a system with a different timezone (let's say Central European Time, 1h ahead of UTC), they will have been built "1h in the future" from the perspective of the UTC server (file timestamps don't contain timezones).
When the server checks the bundles that have been changed past the time it looked last time, it will find the same new bundles for 1h, and only then stop the redeploy loop.
Make sure the timestamps of the built deployment jars are good for the server that you're deploying on. Validate those timestamps on the target infrastructure, or run your buildserver on UTC as well.
Thank you Olaf,
yes when restarting the server after a few hours or the next day the loop does not occur.
What does that mean now? How can we "fix" the problem?
The server runs in UTC timezone.
We've got the same problem. any solution?
the only way out for us now, is delete all in osgi/state and paste from origin osgi/state
run up again.
Powered by Liferay™