uyuni-project / uyuni

Source code for Uyuni
https://www.uyuni-project.org/
GNU General Public License v2.0
429 stars 180 forks source link

Many Openfiles and Running DB schema Upgrade on every spacewalk start #5467

Closed vega82 closed 2 years ago

vega82 commented 2 years ago

Problem description

Since update from 2022.03 to 2022.04 and still present since updating to 2022.05 i have a problem with many openfiles of uyuni. Openfiles on System ist increasing up to 15.000 files per 24h. Java process ist spawning this processes but i can not find out why. I can attach a list of "lsof output" if needed for debugging the problem.

I think the problem i releated to schema upgrade which occurs also since upgrade 2022.03>2022.04.

While starting spacewalk i allways got: "Starting spacewalk services... Running DB schema upgrade. This may take a while. Call the following command to see progress: journalctl -f -u uyuni-check-database.service Done. "

But journal shows:

" journalctl -f -u uyuni-check-database.service -- Logs begin at Tue 2022-05-17 14:19:28 CEST. -- May 19 07:14:49 vsrvuyuni01.labor.local systemd[1]: Finished Uyuni check database. May 19 07:22:41 vsrvuyuni01.labor.local systemd[1]: uyuni-check-database.service: Succeeded. May 19 07:22:41 vsrvuyuni01.labor.local systemd[1]: Stopped Uyuni check database. May 19 07:22:41 vsrvuyuni01.labor.local systemd[1]: Starting Uyuni check database... May 19 07:22:42 vsrvuyuni01.labor.local spacewalk-startup-helper[51852]: report_db_host = vsrvuyuni01.labor.local May 19 07:22:42 vsrvuyuni01.labor.local spacewalk-startup-helper[51863]: Your database schema already matches the schema package version [susemanager-schema-4.3.11-1.1.uyuni1]. May 19 07:22:42 vsrvuyuni01.labor.local spacewalk-startup-helper[51863]: Schema upgrade: [susemanager-schema-4.3.11-1.1.uyuni1] -> [susemanager-schema-4.3.11-1.1.uyuni1] May 19 07:22:42 vsrvuyuni01.labor.local spacewalk-startup-helper[51884]: Your database schema already matches the schema package version [uyuni-reportdb-schema-4.3.4-1.1.uyuni1]. May 19 07:22:42 vsrvuyuni01.labor.local spacewalk-startup-helper[51884]: Schema upgrade: [uyuni-reportdb-schema-4.3.4-1.1.uyuni1] -> [uyuni-reportdb-schema-4.3.4-1.1.uyuni1] May 19 07:22:42 vsrvuyuni01.labor.local systemd[1]: Finished Uyuni check database. "

Version of Uyuni Server and Proxy (if used)

Information for package Uyuni-Server-release:

Repository : Uyuni Stabe release (openSUSE_Leap_15.3) Name : Uyuni-Server-release Version : 2022.05-180.1.uyuni1 Arch : x86_64 Vendor : obs://build.opensuse.org/systemsmanagement:Uyuni Support Level : Level 3 Installed Size : 1.4 KiB Installed : Yes Status : up-to-date Source package : Uyuni-Server-release-2022.05-180.1.uyuni1.src Summary : Uyuni Server

Details about the issue

rhn_web_ui.log:

[ajp-nio-0:0:0:0:0:0:0:1-8009-exec-498] ERROR com.redhat.rhn.frontend.servlets.SessionFilter - Error during transaction. Rolling back java.lang.IllegalStateException: Session/EntityManager is closed at org.hibernate.internal.AbstractSharedSessionContract.checkOpen(AbstractSharedSessionContract.java:360) at org.hibernate.engine.spi.SharedSessionContractImplementor.checkOpen(SharedSessionContractImplementor.java:139) at org.hibernate.internal.AbstractSharedSessionContract.getFlushMode(AbstractSharedSessionContract.java:586) at com.redhat.rhn.common.db.datasource.CachedStatement.doWithStolenConnection(CachedStatement.java:905) at com.redhat.rhn.common.db.datasource.CachedStatement.executeChecking(CachedStatement.java:453) at com.redhat.rhn.common.db.datasource.CachedStatement.executeElaboratorBatch(CachedStatement.java:392) at com.redhat.rhn.common.db.datasource.CachedStatement.executeElaboratorBatch(CachedStatement.java:419) at com.redhat.rhn.common.db.datasource.CachedStatement.executeElaborator(CachedStatement.java:368) at com.redhat.rhn.common.db.datasource.SelectMode.elaborate(SelectMode.java:136) at com.redhat.rhn.common.db.datasource.ModeElaborator.elaborate(ModeElaborator.java:47) at com.redhat.rhn.frontend.taglibs.list.decorators.ElaborationDecorator.elaborateContents(ElaborationDecorator.java:56) at com.redhat.rhn.frontend.taglibs.list.decorators.ElaborationDecorator.setCurrentList(ElaborationDecorator.java:36) at com.redhat.rhn.frontend.taglibs.list.ListTag.doAfterBodyRenderListBegin(ListTag.java:758) at com.redhat.rhn.frontend.taglibs.list.ListTag.doAfterBody(ListTag.java:779) at org.apache.jsp.WEB_002dINF.pages.systems.systemlist_jsp._jspx_meth_rl_005flist_005f0(Unknown Source) at org.apache.jsp.WEB_002dINF.pages.systems.systemlist_jsp._jspx_meth_rl_005flistset_005f0(Unknown Source) at org.apache.jsp.WEB_002dINF.pages.systems.systemlist_jsp._jspService(Unknown Source) at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:71) at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:712) at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:459) at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:384) at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:312) at org.apache.struts.action.RequestProcessor.doForward(RequestProcessor.java:1085) at org.apache.struts.action.RequestProcessor.processForwardConfig(RequestProcessor.java:398) at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:241) at com.redhat.rhn.frontend.struts.RhnRequestProcessor.process(RhnRequestProcessor.java:104) at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1196) at org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:432) at javax.servlet.http.HttpServlet.service(HttpServlet.java:660) at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.redhat.rhn.frontend.servlets.AuthFilter.doFilter(AuthFilter.java:98) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.opensymphony.module.sitemesh.filter.PageFilter.parsePage(PageFilter.java:142) at com.opensymphony.module.sitemesh.filter.PageFilter.doFilter(PageFilter.java:58) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.redhat.rhn.frontend.servlets.LocalizedEnvironmentFilter.doFilter(LocalizedEnvironmentFilter.java:69) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.redhat.rhn.frontend.servlets.EnvironmentFilter.doFilter(EnvironmentFilter.java:99) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.redhat.rhn.frontend.servlets.SessionFilter.doFilter(SessionFilter.java:55) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.redhat.rhn.frontend.servlets.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:97) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:690) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:432) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1591) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.base/java.lang.Thread.run(Thread.java:829) 2022-04-29 10:43:18,373 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-520] ERROR com.redhat.rhn.frontend.servlets.SessionFilter - Error during transaction. Rolling back java.lang.IllegalStateException: Session/EntityManager is closed

Errors in rhn_taskomatic_daemon.log:

[DefaultQuartzScheduler_Worker-5] ERROR com.redhat.rhn.taskomatic.task.ForwardRegistrationTask - Executing a task threw an exception: java.util.NoSuchElementException [DefaultQuartzScheduler_Worker-5] ERROR com.redhat.rhn.taskomatic.task.ForwardRegistrationTask - Message: No value present [DefaultQuartzScheduler_Worker-5] ERROR com.redhat.rhn.taskomatic.task.ForwardRegistrationTask - Cause: {} [DefaultQuartzScheduler_Worker-5] ERROR com.redhat.rhn.taskomatic.task.ForwardRegistrationTask - Stack trace:java.util.NoSuchElementException: No value present at java.base/java.util.Optional.orElseThrow(Optional.java:382) at com.suse.scc.SCCSystemRegistrationManager.updateLastSeen(SCCSystemRegistrationManager.java:76) at com.redhat.rhn.taskomatic.task.ForwardRegistrationTask.execute(ForwardRegistrationTask.java:88) at com.redhat.rhn.taskomatic.task.RhnJavaJob.execute(RhnJavaJob.java:91) at com.redhat.rhn.taskomatic.TaskoJob.execute(TaskoJob.java:155) at org.quartz.core.JobRunShell.run(JobRunShell.java:202) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)

And many hibernating failures: WARN org.hibernate.orm.deprecation - HHH90000017: Found use of deprecated entity-type selector syntax in HQL/JPQL query ['s.class']; use TYPE operator instead : type(s WARN org.hibernate.orm.deprecation - HHH90000022: Hibernate's legacy org.hibernate.Criteria API is deprecated; use the JPA javax.persistence.criteria.CriteriaQuery instead

mcalmer commented 2 years ago

Are these "open files" from rpm or debian packages? For this we reacently fixed a problem, but it is not yet released for Uyuni. It will be part of the next Uyuni release.

The schema migration is not really started, but it has to check if there is a migration. This is a must have otherwise code and schema may differ.

The last issue is already on our agenda. It happens when no SCC credential is defined. This will be fixed with a future update.

mcalmer commented 2 years ago

For the last one we have already https://github.com/uyuni-project/uyuni/issues/5459

vega82 commented 2 years ago

Openfiles Problem is from RPM Packages.

mcalmer commented 2 years ago

Ok, than I think both problems will be fixed with 2022.06. Thanks for the report

vega82 commented 1 year ago

I still have issues with Openfiles. Spacewalk is running in Trouble every week and open files are filling up the system. Meanwhile i'm on 2022.10.