7 Replies Latest reply on Oct 30, 2013 4:07 PM by pathduck

    RHQ 4.9 - Server logs do not rotate based on size

    pathduck

      Hi,

      since RHQ went with EAP 6 the logs, specifically server.log does not rotate like the old rhq-server-log4j.log did.

       

      This could potentially lead to serious problems if the server has an issue that leads to excessive logging. I've seen 200 MB/day for an error with initializing a servlet. AFAIK, the logging is now controlled by /opt/rhq/rhq-server/jbossas/standalone/configuration/standalone-full.xml, and this is where the problem is, in that the default log-definition in Jboss does not rotate the server.log.

       

      This could be easily remedied by changing to a size rotating file handler:

       

                  <size-rotating-file-handler name="FILE">
                      <formatter>
                          <pattern-formatter pattern="%d %-5p [%c] (%t) %s%E%n"/>
                      </formatter>
                      <file relative-to="jboss.server.log.dir" path="server.log"/>
                      <rotate-size value="10m"/>
                      <max-backup-index value="10"/>
                      <append value="true"/>
                  </size-rotating-file-handler>
      
      
      
      
      
      

       

      Also there seems to be references to the file in logging.properties but not sure how related that is.

       

      IMO the default log handler in Jboss should be changed to size-rotating as standard, non-rotating files are very nasty 

       

      Other things related to logging;

      - The rhq-storage.log has a backupindex of 50x20MB which might be taking it too far?

      log4j.appender.R.maxBackupIndex=50

        • 1. Re: RHQ 4.9 - Server logs do not rotate
          mazz

          Can you report each of these in separate bugzilla reports? https://bugzilla.redhat.com/enter_bug.cgi?product=RHQ%20Project

          • 2. Re: RHQ 4.9 - Server logs do not rotate
            pathduck

            mazz skrev:

             

            Can you report each of these in separate bugzilla reports? https://bugzilla.redhat.com/enter_bug.cgi?product=RHQ%20Project

             

            Sure,

            https://bugzilla.redhat.com/show_bug.cgi?id=1023466

             

            I will make a BZ on the storage log as well over the weekend

             

            have a good one,

            Stian

            • 3. Re: Re: RHQ 4.9 - Server logs do not rotate
              pathduck

              I opened a bug for the RHQ-Storage log4j konfig as well:

              https://bugzilla.redhat.com/show_bug.cgi?id=1023888

               

              As to the matter of rotating server.log; it is true they do rotate, only daily, so the title was misleading and thanks for changing it.

               

              Elias wrote in the bz:

               

              I kind of like the way logs rotate daily. Yes, mine are around 200MB per day, but it's not a big deal.

               

              I would prefer if logs were automatically removed after, say, a week, but that's fine.

               

              From working in operations, I know from experience that daily logs inevitably cause problems. I believe in 'no-touch' servers, and having to occasionally clean up is not something I like to do. Sure, it could be solved with a simple cronjob, but anything that needs to be configured in addition to installing is best avoided. Especially if people have different directories for every new install of RHQ, and for people who run many clustered installs of RHQ.

               

              Creating cronjobs/logrotate is also not a trivial matter for users of RHQ running on Windows for instance - it could require knowledge of advanced scripting and possibly need third-party tools installed. Thankfully we run on RHEL so I can easily create a crontab job to clear logs, it's been a long time since I worked with on Windows

               

              For some reason developers on the other hand seem to prefer daily logs, maybe because they want control of everything that logs during a day... maybe this is why the default logging in Jboss EAP is set to have daily logs.

               

              At the moment we have a bug with 4.9 leading to excessive logging (lazy remoting init?) and RHQ server logs are 250-300 megs daily. I guess this will improve when it's fixed. But an RHQ server could easily live several months and we run small Vmware images with small root disks, 4-5 gigs.

               

              By the way:

              Another suggestion; if logs are changed to no longer be daily rotating, the pattern needs to be changed to have full date timestamps; simply change the complex timestamp to just %d:

               

              <pattern-formatter pattern="%d %-5p [%c] (%t) %s%E%n"/>
              
              • 4. Re: RHQ 4.9 - Server logs do not rotate based on size
                genman

                Stian, I agree that applications removing the logs automatically is a good thing, and excessive logging is bad.

                 

                My problem is somehow the server sees this over and over again:

                 

                22:17:08,384 ERROR [org.rhq.enterprise.server.discovery.DiscoveryBossBean] (http-/0.0.0.0:7080-137) Reported resource [Resource[id=0, uuid=d264c138-d3b6-4af8-8313-2c9f2858737b, type={JBossAS7}Authentication (Classic), key=subsystem=security,security-domain=RHQUserSecurityDomain,authentication=classic, name=Authentication (Classic), parent=RHQUserSecurityDomain]] has an unknown type [ResourceType[id=0, name=Authentication (Classic), plugin=JBossAS7, category=Service]]. Agent 'null' most likely has a plugin named 'JBossAS7' installed that is not installed on the Server. Resource will be ignored...

                 

                and I have no way to fix it.

                • 5. Re: Re: RHQ 4.9 - Server logs do not rotate based on size
                  pathduck

                  Yeah, I see the same in our logs. At the moment I can't get up the RHQ Console at all, since Remoting has not been initalized properly (I assume), so it "spams" the logs with:

                   

                  11:40:36,412 ERROR [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/jboss-remoting-servlet-invoker].[ServerInvokerServlet]] (http-/0.0.0.0:7080-4) JBWEB000235: Allocate exception for servlet ServerInvokerServlet: javax.servlet.ServletException: Could not find the remoting servlet invoker: jboss.remoting:service=invoker,rhq.communications.connector.rhqtype=server,* - need to wait for remoting to be initialized later

                      at org.rhq.enterprise.communications.servlet.ServerInvokerServlet.getInvokerFromInvokerName(ServerInvokerServlet.java:78) [classes:]

                      at org.jboss.remoting.transport.servlet.web.ServerInvokerServlet.init(ServerInvokerServlet.java:78) [jboss-remoting-2.5.4.SP4.jar:]

                      at sun.reflect.GeneratedMethodAccessor88.invoke(Unknown Source) [:1.7.0_17]

                      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_17]

                      at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_17]

                      at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:263) [jbossweb-7.2.0.Final.jar:7.2.0.Final]

                      at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:261) [jbossweb-7.2.0.Final.jar:7.2.0.Final]

                      at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.7.0_17]

                      at javax.security.auth.Subject.doAsPrivileged(Subject.java:536) [rt.jar:1.7.0_17]

                  These amount to 2-300 megs a day, I guess if this was not there it wouldn't be so bad...

                  • 6. Re: Re: RHQ 4.9 - Server logs do not rotate based on size
                    mazz

                    If your logs are getting filled every day with the error message:


                    Could not find the remoting servlet invoker: jboss.remoting:service=invoker,rhq.communications.connector.rhqtype=server,* - need to wait for remoting to be initialized later


                    then something is really wrong. That error should only ever happen at startup of the server - once the server is up and running, you should never get that message again. What this error message means is you are getting agent messages but the server isn't fully initialized yet (under normal circumstances, you could see this if agents are trying to send messages to a server you just restarted - the server just isn't ready yet to process those agent messages, but should be soon - within minutes at least). Once the server starts up and initializes successfully, the JBoss/Remoting JMX service should be registered and accepting messages - if you are getting this message over and over, that means your agents aren't getting messages through to the server. I've seen this happen when the server fails to start up properly. You need to look at your server logs and find out what other errors are occurring that is causing it to fail to start up. Until those other error conditions are cleared up and you restart the server, you will get this error message for every single agent message that that server receives (it may even happen on every CLI request too).

                    • 7. Re: RHQ 4.9 - Server logs do not rotate based on size
                      pathduck

                      I know it ain't supposed to be like that Mazz

                      I can't even get the login page to show  - so I guess it's the same thing. I was thinking I would hold off until 4.10 is out but maybe I should make a new thread about this problem?