17.4 Poor Performance and long Server Log

Dear all,

 

I am using v17.4 HotfixC for my Linux Environment. It keeps generating extremely long server logs each time I click a button and loads really long and thus resulting in poor performance.

 

The following logs were keep generating 

 

05:21:56,597 ERROR [stderr] (MSC service thread 1-3) log4j:WARN No appenders could be found for logger (org.apache.commons.configuration.PropertiesConfiguration).
05:21:56,598 ERROR [stderr] (MSC service thread 1-3) log4j:WARN Please initialize the log4j system properly.
05:21:56,598 ERROR [stderr] (MSC service thread 1-3) log4j:WARN See logging.apache.org/.../faq.html for more info.
05:21:56,657 ERROR [stderr] (MSC service thread 1-3) SLF4J: Class path contains multiple SLF4J bindings.
05:21:56,658 ERROR [stderr] (MSC service thread 1-3) SLF4J: Found binding in [vfs:/app1/appian/ear/suite.ear/lib/slf4j-simple-1.7.21.jar/org/slf4j/impl/StaticLoggerBinder.class]
05:21:56,658 ERROR [stderr] (MSC service thread 1-3) SLF4J: Found binding in [vfs:/app1/appian/ear/suite.ear/lib/slf4j-log4j12-1.7.0.jar/org/slf4j/impl/StaticLoggerBinder.class]
05:21:56,658 ERROR [stderr] (MSC service thread 1-3) SLF4J: See www.slf4j.org/codes.html for an explanation.
05:21:56,666 ERROR [stderr] (MSC service thread 1-3) SLF4J: Actual binding is of type [org.slf4j.impl.SimpleLoggerFactory]

[...]

05:22:02,659 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.core.config.InitializationService - Initializing OpenSAML using the Java Services API
05:22:03,298 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.xmlsec.algorithm.AlgorithmRegistry - Cipher algorithm 'www.w3.org/.../xmlenc is not supported, its key length 192 exceeds Cipher max key length 128
05:22:03,300 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.xmlsec.algorithm.AlgorithmRegistry - Algorithm failed runtime support check, will not be usable: www.w3.org/.../xmlenc
05:22:03,301 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.xmlsec.algorithm.AlgorithmRegistry - Cipher algorithm 'www.w3.org/.../xmlenc11 is not supported, its key length 192 exceeds Cipher max key length 128
05:22:03,302 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.xmlsec.algorithm.AlgorithmRegistry - Algorithm failed runtime support check, will not be usable: www.w3.org/.../xmlenc11
05:22:03,302 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.xmlsec.algorithm.AlgorithmRegistry - Cipher algorithm 'www.w3.org/.../xmlenc is not supported, its key length 256 exceeds Cipher max key length 128
05:22:03,303 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.xmlsec.algorithm.AlgorithmRegistry - Algorithm failed runtime support check, will not be usable: www.w3.org/.../xmlenc
05:22:03,303 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.xmlsec.algorithm.AlgorithmRegistry - Cipher algorithm 'www.w3.org/.../xmlenc11 is not supported, its key length 256 exceeds Cipher max key length 128
05:22:03,304 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.xmlsec.algorithm.AlgorithmRegistry - Algorithm failed runtime support check, will not be usable: www.w3.org/.../xmlenc11
05:22:03,314 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.xmlsec.algorithm.AlgorithmRegistry - Algorithm failed runtime support check, will not be usable: www.w3.org/.../xmlenc
05:22:03,319 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.opensaml.xmlsec.algorithm.AlgorithmRegistry - Algorithm failed runtime support check, will not be usable: http://www.w3.org/2001/04/xmldsig-more#hmac-ripemd160

 

[...]

 

5:22:06,793 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.annotations.common.Version - Hibernate Commons Annotations 3.2.0.Final
05:22:06,797 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.Environment - Hibernate 3.6.3.Final
05:22:06,800 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.Environment - hibernate.properties not found
05:22:06,803 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.Environment - Bytecode provider name : javassist
05:22:06,805 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.Environment - using JDK 1.4 java.sql.Timestamp handling
05:22:06,840 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.ejb.Version - Hibernate EntityManager 3.6.3.Final
05:22:06,867 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.dialect.Dialect - Using dialect: com.appiancorp.rdbms.hb.dialect.AppianMySQLDialect
05:22:06,873 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.dialect.Dialect - Using dialect: com.appiancorp.rdbms.hb.dialect.AppianOracleDialect
05:22:06,875 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.dialect.Dialect - Using dialect: com.appiancorp.rdbms.hb.dialect.AppianSqlServerDialect
05:22:06,878 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.dialect.Dialect - Using dialect: com.appiancorp.rdbms.hb.dialect.AppianDb2Dialect
05:22:06,917 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: com.appiancorp.object.test.runtime.PersistedTestResult
05:22:06,939 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.annotations.EntityBinder - Bind entity com.appiancorp.object.test.runtime.PersistedTestResult on table test_result
05:22:06,973 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: com.appiancorp.common.config.persistence.Config
05:22:06,973 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.annotations.EntityBinder - Bind entity com.appiancorp.common.config.persistence.Config on table cfg
05:22:06,979 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: com.appiancorp.tempo.rdbms.FeedSubscription
05:22:06,979 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.annotations.EntityBinder - Bind entity com.appiancorp.tempo.rdbms.FeedSubscription on table tp_feed_usr_subs
05:22:06,990 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: com.appiancorp.type.model.DatatypeModel
05:22:06,990 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.annotations.EntityBinder - Bind entity com.appiancorp.type.model.DatatypeModel on table DT_MODEL
05:22:06,993 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: com.appiancorp.security.external.SystemSecuredValue
05:22:06,994 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.annotations.EntityBinder - Bind entity com.appiancorp.security.external.SystemSecuredValue on table external_sys_attr_sys_val
05:22:06,998 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: com.appiancorp.security.acl.Role
05:22:06,999 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.annotations.EntityBinder - Bind entity com.appiancorp.security.acl.Role on table rm_role
05:22:07,001 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: com.appiancorp.security.auth.rememberme.RememberMeToken
05:22:07,002 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.annotations.EntityBinder - Bind entity com.appiancorp.security.auth.rememberme.RememberMeToken on table usr_remember_me_token
05:22:07,005 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.AnnotationBinder - Binding entity from annotated class: com.appiancorp.security.external.SecuredAttribute
05:22:07,005 ERROR [stderr] (ServerService Thread Pool -- 86) [ServerService Thread Pool -- 86] INFO org.hibernate.cfg.annotations.EntityBinder - Bind entity com.appiancorp.security.external.SecuredAttribute on table external_sys_attr

 

[...]

 

06:20:21,350 ERROR [stderr] (Appian AppianServerThreadPoolProvider 1672) [Appian AppianServerThreadPoolProvider 1672] INFO feature_context - begin com.appiancorp.core.expr.Parse eval [Thread 1963]
06:20:21,368 ERROR [stderr] (Appian AppianServerThreadPoolProvider 1672) [Appian AppianServerThreadPoolProvider 1672] INFO feature_context - end com.appiancorp.core.expr.Parse eval:17ms [Thread 1963]
06:20:21,387 ERROR [stderr] (Appian AppianServerThreadPoolProvider 1672) [Appian AppianServerThreadPoolProvider 1672] INFO feature_context - begin com.appiancorp.core.expr.Parse eval [Thread 1963]
06:20:21,401 ERROR [stderr] (Appian AppianServerThreadPoolProvider 1672) [Appian AppianServerThreadPoolProvider 1672] INFO feature_context - end com.appiancorp.core.expr.Parse eval:14ms [Thread 1963]
06:20:21,429 ERROR [stderr] (Appian AppianServerThreadPoolProvider 1622) [Appian AppianServerThreadPoolProvider 1622] INFO feature_context - begin com.appiancorp.core.expr.Parse eval [Thread 1913]
06:20:21,452 ERROR [stderr] (Appian AppianServerThreadPoolProvider 1622) [Appian AppianServerThreadPoolProvider 1622] INFO feature_context - end com.appiancorp.core.expr.Parse eval:22ms [Thread 1913]
06:20:21,474 ERROR [stderr] (Appian AppianServerThreadPoolProvider 1622) [Appian AppianServerThreadPoolProvider 1622] INFO feature_context - begin com.appiancorp.core.expr.Parse eval [Thread 1913]
06:20:21,489 ERROR [stderr] (Appian AppianServerThreadPoolProvider 1622) [Appian AppianServerThreadPoolProvider 1622] INFO feature_context - end com.appiancorp.core.expr.Parse eval:14ms [Thread 1913]

 

Do  you have any clues what is going on on my server?

  Discussion posts and replies are publicly visible

Parents
  • Hello,

    It looks like you are having multiple errors,
    One of those is that you have duplicated one key in the log4j or something like that, try removing those.
    change the global logging level to error (it seems like you are getting lot of issues) if this reduces the amount of logging then it will be easier to approach the real problem.
    Reference:
    docs.appian.com/.../Logging.html

    Some questions? You just installed the server? upgraded? did you configured something special?

    Jose
  • Dear ,

    We applied Hotfix C in our testing and prod environment with the same repo config.
    However, just one of them experience this issue.

    Responding to the suggestion about "global logging level ", so far as I know the logging levels are set independently in the " "appian_log4j.properties" file , have I miss out anything? Do you know where could I set the "global" logging Level?

    Thanks for your help
  • Hello Joanneh,

    You are right, I didn't remembered the proper name but i was referring to the "DEFAULT or rootLogger" as the "Global setting"
    --------------------
    ###### Default
    log4j.rootLogger=ERROR, CONSOLE, METRICS
    #log4j.debug=true
    --------------------------

    From your previous response i see that you left the default values.

    When i have one working and the other not, i always compare the configuration and/or override. I really hope your problem is in test which you can override without a problem.

    Regards
    Jose
  • Looking again at the logs you shared I just noticed this
    -------------------------------------
    05:21:56,658 ERROR [stderr] (MSC service thread 1-3) SLF4J: Found binding in [vfs:/app1/appian/ear/suite.ear/lib/slf4j-simple-1.7.21.jar/org/slf4j/impl/StaticLoggerBinder.class]
    05:21:56,658 ERROR [stderr] (MSC service thread 1-3) SLF4J: Found binding in [vfs:/app1/appian/ear/suite.ear/lib/slf4j-log4j12-1.7.0.jar/org/slf4j/impl/StaticLoggerBinder.class]
    -------------------------------------

    Seems like you have two versions of the same class in different jars
    app1/appian/ear/suite.ear/lib/slf4j-simple-1.7.21.jar/org/slf4j/impl/StaticLoggerBinder.class
    app1/appian/ear/suite.ear/lib/slf4j-log4j12-1.7.0.jar/org/slf4j/impl/StaticLoggerBinder.class

    Maybe thats the reason why
    Class path contains multiple SLF4J bindings..

    Can you check in the other environment if you have both jars in the path
    /app1/appian/ear/suite.ear/lib/

    if one of them is missing in the other environment, I can guess that maybe this step was missing
    --------------------------------------------
    * Run the deleteFiles script (deleteFiles.bat on Windows, deleteFiles.sh on Linux) that is now located in your <APPIAN_HOME> directory.
    -------------------------------------------

    Best Regards
    Jose Perez
  • Some interesting notes:
    * from the hotfix we can see that the new file is this "17_4_0_0_Hotfix_Package_C\updates.zip\ear\suite.ear\lib\slf4j-simple-1.7.21.jar"
    * but in the delete script i don't see "the other file been deleted" i found a similar file "services\zookeeper-3.4.10\lib\slf4j-log4j12-1.6.1.jar"

    I was thinking to tell you to just to take out that "other" jar file and test(this is your decision), but maybe there are other jar files which doesn't belong to that folder or should be there. So please compare the \ear\suite.ear\lib\ folders maybe those two environment do not have the same hotfixes applied or upgrades . At this point I strongly recomend to open a ticket with Appian.

    Best Regards
    Jose Perez
Reply
  • Some interesting notes:
    * from the hotfix we can see that the new file is this "17_4_0_0_Hotfix_Package_C\updates.zip\ear\suite.ear\lib\slf4j-simple-1.7.21.jar"
    * but in the delete script i don't see "the other file been deleted" i found a similar file "services\zookeeper-3.4.10\lib\slf4j-log4j12-1.6.1.jar"

    I was thinking to tell you to just to take out that "other" jar file and test(this is your decision), but maybe there are other jar files which doesn't belong to that folder or should be there. So please compare the \ear\suite.ear\lib\ folders maybe those two environment do not have the same hotfixes applied or upgrades . At this point I strongly recomend to open a ticket with Appian.

    Best Regards
    Jose Perez
Children