Logger.log does not work in workflow

[itrub]

Dear colleagues
I have faced with heavy and unexplainable problem. logger.log does not work at all! I saw similar topics, but any recommendation has not helped me. There is my log4j.properties:
———————————
# Set root logger level to error
log4j.rootLogger=error, File, Console

###### Console appender definition #######

# All outputs currently set to be a ConsoleAppender.
log4j.appender.Console=org.apache.log4j.ConsoleAppender
log4j.appender.Console.layout=org.apache.log4j.PatternLayout

# use log4j NDC to replace %x with tenant domain / username
log4j.appender.Console.layout.ConversionPattern=%d{ABSOLUTE} %x %-5p [%c{3}] %m%n
#log4j.appender.Console.layout.ConversionPattern=%d{ABSOLUTE} %-5p [%c] %m%n

###### File appender definition #######
log4j.appender.File=org.apache.log4j.DailyRollingFileAppender
log4j.appender.File.File=alfresco.log
log4j.appender.File.Append=true
log4j.appender.File.DatePattern='.'yyyy-MM-dd
log4j.appender.File.layout=org.apache.log4j.PatternLayout
log4j.appender.File.layout.ConversionPattern=%d{ABSOLUTE} %-5p [%c] %m%n

###### Hibernate specific appender definition #######
#log4j.appender.file=org.apache.log4j.FileAppender
#log4j.appender.file.File=hibernate.log
#log4j.appender.file.layout=org.apache.log4j.PatternLayout
#log4j.appender.file.layout.ConversionPattern=%d{ABSOLUTE} %5p %c{1}:%L - %m%n

###### Log level overrides #######

# Commented-in loggers will be exposed as JMX MBeans (refer to org.alfresco.repo.admin.Log4JHierarchyInit)
# Hence, generally useful loggers should be listed with at least ERROR level to allow simple runtime
# control of the level via a suitable JMX Console. Also, any other loggers can be added transiently via
# Log4j addLoggerMBean as long as the logger exists and has been loaded.

# Hibernate
log4j.logger.org.hibernate=WARN
log4j.logger.org.hibernate.util.JDBCExceptionReporter=fatal
log4j.logger.org.hibernate.event.def.AbstractFlushingEventListener=fatal
log4j.logger.org.hibernate.type=warn
log4j.logger.org.hibernate.cfg.SettingsFactory=warn

# Spring
log4j.logger.org.springframework=warn
# Turn off Spring remoting warnings that should really be info or debug.
log4j.logger.org.springframework.remoting.support=error
log4j.logger.org.springframework.util=error

# Axis/WSS4J
log4j.logger.org.apache.axis=info
log4j.logger.org.apache.ws=info

# CXF
log4j.logger.org.apache.cxf=error

# MyFaces
log4j.logger.org.apache.myfaces.util.DebugUtils=info
log4j.logger.org.apache.myfaces.el.VariableResolverImpl=error
log4j.logger.org.apache.myfaces.application.jsp.JspViewHandlerImpl=error
log4j.logger.org.apache.myfaces.taglib=error

# OpenOfficeConnection
log4j.logger.net.sf.jooreports.openoffice.connection=fatal

# log prepared statement cache activity ###
log4j.logger.org.hibernate.ps.PreparedStatementCache=info

# Alfresco
log4j.logger.org.alfresco=INFO
log4j.logger.org.alfresco.repo.admin=info
log4j.logger.org.alfresco.repo.cache.TransactionalCache=warn
log4j.logger.org.alfresco.repo.model.filefolder=info
log4j.logger.org.alfresco.repo.tenant=info
log4j.logger.org.alfresco.repo.avm=info
log4j.logger.org.alfresco.config=info
log4j.logger.org.alfresco.config.JndiObjectFactoryBean=warn
log4j.logger.org.alfresco.config.JBossEnabledWebApplicationContext=warn
log4j.logger.org.alfresco.repo.management.subsystems=info
log4j.logger.org.alfresco.repo.management.subsystems.ChildApplicationContextFactory$ChildApplicationContext=warn
log4j.logger.org.alfresco.repo.security.sync=info
log4j.logger.org.alfresco.repo.security.person=info

log4j.logger.org.alfresco.sample=info
log4j.logger.org.alfresco.web=info
#log4j.logger.org.alfresco.web.app.AlfrescoNavigationHandler=DEBUG
#log4j.logger.org.alfresco.web.ui.repo.component.UIActions=DEBUG
#log4j.logger.org.alfresco.web.ui.repo.tag.PageTag=DEBUG
#log4j.logger.org.alfresco.web.bean.clipboard=DEBUG
log4j.logger.org.alfresco.repo.webservice=info
log4j.logger.org.alfresco.service.descriptor.DescriptorService=info
#log4j.logger.org.alfresco.web.page=DEBUG

log4j.logger.org.alfresco.repo.importer.ImporterBootstrap=error
#log4j.logger.org.alfresco.repo.importer.ImporterBootstrap=info

log4j.logger.org.alfresco.web.ui.common.Utils=error
#log4j.logger.org.alfresco.web.ui.common.Utils=info

log4j.logger.org.alfresco.repo.admin.patch.PatchExecuter=info

# Specific patches
log4j.logger.org.alfresco.repo.admin.patch.impl.DeploymentMigrationPatch=info
log4j.logger.org.alfresco.repo.version.VersionMigrator=info
log4j.logger.org.alfresco.repo.admin.patch.impl.ResetWCMToGroupBasedPermissionsPatch=info

log4j.logger.org.alfresco.repo.module.ModuleServiceImpl=info
log4j.logger.org.alfresco.repo.domain.schema.SchemaBootstrap=info
log4j.logger.org.alfresco.repo.admin.ConfigurationChecker=info
log4j.logger.org.alfresco.repo.node.index.IndexTransactionTracker=warn
log4j.logger.org.alfresco.repo.node.index.FullIndexRecoveryComponent=info
log4j.logger.org.alfresco.repo.node.index.AVMFullIndexRecoveryComponent=info
log4j.logger.org.alfresco.util.OpenOfficeConnectionTester=info
log4j.logger.org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl=warn
log4j.logger.org.alfresco.repo.domain.hibernate.DirtySessionMethodInterceptor=warn
log4j.logger.org.alfresco.repo.transaction.RetryingTransactionHelper=warn
log4j.logger.org.alfresco.util.transaction.SpringAwareUserTransaction.trace=warn
log4j.logger.org.alfresco.repo.jgroups.AlfrescoJGroupsChannelFactory=info
log4j.logger.org.alfresco.enterprise.repo.cache.jgroups.JGroupsKeepAliveHeartbeatReceiver=info

#log4j.logger.org.alfresco.web.app.DebugPhaseListener=DEBUG
#log4j.logger.org.alfresco.repo.cache.EhCacheTracerJob=DEBUG

log4j.logger.org.alfresco.repo.workflow=error
#log4j.logger.org.alfresco.repo.workflow=info

# CIFS server debugging
log4j.logger.org.alfresco.smb.protocol=error
#log4j.logger.org.alfresco.smb.protocol.auth=debug
#log4j.logger.org.alfresco.acegi=debug

# FTP server debugging
log4j.logger.org.alfresco.ftp.protocol=error
#log4j.logger.org.alfresco.ftp.server=debug

# WebDAV debugging
#log4j.logger.org.alfresco.webdav.protocol=debug
log4j.logger.org.alfresco.webdav.protocol=error

# NTLM servlet filters
#log4j.logger.org.alfresco.web.app.servlet.NTLMAuthenticationFilter=debug
#log4j.logger.org.alfresco.repo.webdav.auth.NTLMAuthenticationFilter=debug

# Kerberos servlet filters
#log4j.logger.org.alfresco.web.app.servlet.KerberosAuthenticationFilter=debug
#log4j.logger.org.alfresco.repo.webdav.auth.KerberosAuthenticationFilter=debug

# File servers
log4j.logger.org.alfresco.fileserver=warn

# Repo filesystem debug logging
#log4j.logger.org.alfresco.filesys.repo.ContentDiskDriver=DEBUG

# AVM filesystem DEBUG logging
#log4j.logger.org.alfresco.filesys.avm.AVMDiskDriver=DEBUG

# Integrity message threshold - if 'failOnViolation' is off, then WARNINGS are generated
log4j.logger.org.alfresco.repo.node.integrity=ERROR

# Indexer DEBUGging
log4j.logger.org.alfresco.repo.search.Indexer=error
#log4j.logger.org.alfresco.repo.search.Indexer=DEBUG

log4j.logger.org.alfresco.repo.search.impl.lucene.index=error
#log4j.logger.org.alfresco.repo.search.impl.lucene.index=DEBUG

# Audit DEBUGging
# log4j.logger.org.alfresco.repo.audit=DEBUG
# log4j.logger.org.alfresco.repo.audit.model=DEBUG

# Forms DEBUGging
# log4j.logger.org.alfresco.web.forms=DEBUG
# log4j.logger.org.chiba.xml.xforms=DEBUG
log4j.logger.org.alfresco.web.forms.xforms.XFormsBean=error
log4j.logger.org.alfresco.web.forms.XSLTRenderingEngine=error

# Property sheet and modelling DEBUGging
# change to error to hide the warnings about missing properties and associations
log4j.logger.alfresco.missingProperties=warn
log4j.logger.org.alfresco.web.ui.repo.component.property.UIChildAssociation=warn
log4j.logger.org.alfresco.web.ui.repo.component.property.UIAssociation=warn
#log4j.logger.org.alfresco.web.ui.repo.component.property=DEBUG

# Dictionary/Model DEBUGging
log4j.logger.org.alfresco.repo.dictionary=warn
log4j.logger.org.alfresco.repo.dictionary.types.period=warn

# Virtualization Server Registry
log4j.logger.org.alfresco.mbeans.VirtServerRegistry=error

# Spring context runtime property setter
log4j.logger.org.alfresco.util.RuntimeSystemPropertiesSetter=info

# Link Validation DEBUGging
log4j.logger.org.alfresco.linkvalidation.LinkValidationServiceImpl=error
log4j.logger.org.alfresco.linkvalidation.LinkValidationStoreCallbackHandler=error

# Debugging options for clustering
log4j.logger.org.alfresco.repo.content.ReplicatingContentStore=error
log4j.logger.org.alfresco.repo.content.replication=error

#log4j.logger.org.alfresco.repo.deploy.DeploymentServiceImpl=DEBUG

# Activity service
log4j.logger.org.alfresco.repo.activities=info

# User usage tracking
log4j.logger.org.alfresco.repo.usage=info

# Sharepoint
log4j.logger.org.alfresco.module.vti=info

# Forms Engine
log4j.logger.org.alfresco.repo.forms=info
log4j.logger.org.alfresco.web.config.forms=info

# CMIS
log4j.logger.org.alfresco.cmis=error
log4j.logger.org.alfresco.cmis.dictionary=warn

# IMAP
log4j.logger.org.alfresco.repo.imap=info

# JBPM
# Note: non-fatal errors (eg. logged during job execution) should be handled by Alfresco's retrying transaction handler
log4j.logger.org.jbpm.graph.def.GraphElement=fatal
log4j.logger.org.jbpm=INFO
#log4j.logger.org.alfresco.repo.googledocs=DEBUG

###### Scripting #######

# Web Framework
log4j.logger.org.springframework.extensions.webscripts=error
log4j.logger.org.springframework.extensions.webscripts.ScriptLogger=info
log4j.logger.org.springframework.extensions.webscripts.ScriptDebugger=off

# Repository
log4j.logger.org.alfresco.repo.web.scripts=DEBUG
log4j.logger.org.alfresco.repo.web.scripts.ScriptLogger=DEBUG
log4j.logger.org.alfresco.repo.web.scripts.BaseWebScriptTest=info
log4j.logger.org.alfresco.repo.web.scripts.AlfrescoRhinoScriptDebugger=off
log4j.logger.org.alfresco.repo.jscript=DEBUG
log4j.logger.org.alfresco.repo.jscript.ScriptLogger=DEBUG
log4j.logger.org.alfresco.repo.cmis.rest.CMISTest=info

log4j.logger.org.alfresco.repo.avm.actions=info

# Freemarker
# Note the freemarker.runtime logger is used to log non-fatal errors that are handled by Alfresco's retrying transaction handler
log4j.logger.freemarker.runtime=

log4j.logger.com.sample=DEBUG
————————————-
And there is how I try to apply logger.log in workflow:
    <start-state name="start">
        <task name="wf:submitParallelReview1Task" swimlane="initiator" />
        <transition name="" to="startreview">
        <action class="org.alfresco.repo.workflow.jbpm.AlfrescoJavaScript">
            <script>
      logger.log("AAABBBCCCDDD");
            </script>
        </action>

        </transition>
    </start-state>
Workflow works correctly, but "AAABBBCCCDDD" did not appear neither in alfresco.log, nor anywhere at all.
Could anybody give me useful advance< what is wrong?
Sincerely, Iliya

[smicyk]

Hi,

what application do you use for executing workflows Explorer or Share?

[tekuento]

Hi,

Try to set log4j.logger.org.alfresco.repo.workflow to DEBUG level.

Greetings,

Antonio José Molina Gutiérrez

[itrub]

Dear colleagues
Thanks for your replies and take apologies for extra noise. The reason was very simple. I forgot to change <redeploy>-tag in processdefinition.xml to true, so my added codestrings "logger.log(…)" did not take effect on workflow execution. The problem is closed.

[mjboere]

You can also try setting this one. This solved my issue.
Also thanks to this thread : https://forums.alfresco.com/en/viewtopic.php?f=10&t=21838

log4j.logger.org.alfresco.repo.jscript.ScriptLogger=debug