SmartClient logging using SLF4j API does not have ISCInit logs and writes null character in the beginning.

[muralik]

We are using SmartClient_v121p_2021-01-09_Enterprise version for smartclient

We are using Slf4j API logging for smartclient as our application is moving to log4j2 loggers.
Smartclient default logging was log4j 1.x. We have disabled it with flag -DiscUseLog4jConfig=false.
So our application is now using slf4j api logging and log4j2 implementation.
We have set -DiscUseSlf4j=true -DiscUseLog4jConfig=false and -Dlog4j2.configurationFile=<log4j2 config file for smartclient>

We can now see the logs. However, in the beginning of the log file there are null characters. I have attach the log file to show the null characters in the beginning. I have trimmed the log file. It generates 985k length of null characters. It is also missing following ISCInit log statements

================================================

=== 2022-07-08 06:49:07,767 [d-11] INFO ISCInit - Isomorphic SmartClient/SmartGWT Framework - Initializing
=== 2022-07-08 06:49:07,767 [d-11] INFO ISCInit - Isomorphic SmartClient/SmartGWT Framework - Initializing
=== 2022-07-08 06:49:07,771 [d-11] INFO ConfigLoader - Attempting to load framework.properties from CLASSPATH
=== 2022-07-08 06:49:07,771 [d-11] INFO ConfigLoader - Attempting to load framework.properties from CLASSPATH
=== 2022-07-08 06:49:07,796 [d-11] INFO ConfigLoader - Successfully loaded framework.properties from CLASSPATH at location: jar:file:*****/webapp/WEB-INF/lib/isomorphic_core_rpc.jar!/framework.properties
=== 2022-07-08 06:49:07,796 [d-11] INFO ConfigLoader - Successfully loaded framework.properties from CLASSPATH at location: jar:file:***/webapp/WEB-INF/lib/isomorphic_core_rpc.jar!/framework.properties
=== 2022-07-08 06:49:07,798 [d-11] INFO ConfigLoader - Attempting to load project.properties from CLASSPATH
=== 2022-07-08 06:49:07,798 [d-11] INFO ConfigLoader - Attempting to load project.properties from CLASSPATH
=== 2022-07-08 06:49:07,799 [d-11] INFO ConfigLoader - Unable to locate project.properties in CLASSPATH
=== 2022-07-08 06:49:07,799 [d-11] INFO ConfigLoader - Unable to locate project.properties in CLASSPATH
=== 2022-07-08 06:49:07,803 [d-11] INFO ConfigLoader - Successfully loaded isc_interfaces.properties from CLASSPATH at location: jar:file:/*****/webapp/WEB-INF/lib/isomorphic_core_rpc.jar!/isc_interfaces.properties
=== 2022-07-08 06:49:07,803 [d-11] INFO ConfigLoader - Successfully loaded isc_interfaces.properties from CLASSPATH at location: jar:file:*****/webapp/WEB-INF/lib/isomorphic_core_rpc.jar!/isc_interfaces.properties
=== 2022-07-08 06:49:07,804 [d-11] INFO ConfigLoader - Attempting to load server.properties from CLASSPATH
=== 2022-07-08 06:49:07,804 [d-11] INFO ConfigLoader - Attempting to load server.properties from CLASSPATH
=== 2022-07-08 06:49:07,806 [d-11] INFO ConfigLoader - Successfully loaded server.properties from CLASSPATH at location: file:****/webapp/WEB-INF/classes/server.properties
=== 2022-07-08 06:49:07,806 [d-11] INFO ConfigLoader - Successfully loaded server.properties from CLASSPATH at location: file:***/webapp/WEB-INF/classes/server.properties
=== 2022-07-08 06:49:07,810 [d-11] INFO Config - Applying system property webdriver.http.factory: apache
=== 2022-07-08 06:49:07,810 [d-11] DEBUG Config - ThreadLocal Config enabled === 2022-07-08 06:49:07,812 [d-11] INFO Logger - Logging system started.

========================================================================================================================

[muralik]

Any update on this team? Is it expected behaviour? Is it known issue and do we have workaround ?

[Isomorphic]

This is not expected. What do you use to redirect Slf4j logging to Log4j2?

Also, please clarify - everything works fine in console, i.e. complete logs including ISCInit messages are logged as expected. Is this correct?

Then in the log file ISCInit messages are missing and there is a bunch of null characters in the beginning. Is your log file completely empty with just nulls or do you have log messages in the log file after them? Also, is this related to just Smartclient logging or do you have the same problem with your application logging as well?

[muralik]

We are using log4j-slf4j-impl-2.17.2.jar.

We are using the flags -DiscUseLog4jConfig=false -DiscUseSlf4j=true and we have provided our own configuration file for log4j2

What do you mean by "Also, please clarify - everything works fine in console, i.e. complete logs including ISCInit messages are logged as expected."

The documentation says "Note that the features of the "Server Logs" tab will not be available if using slf4j, even if Log4j is also used". So the Admin console do not show any messages in server logs tab. The tomcat console also do not show ISCInit messages.

In our log file there are about 600 empty lines and after that log messages appear. Subsequent rolled files are proper with log messages and no empty lines.
We see this problem with only smartClient logging. Our application logging is working fine.

[Isomorphic]

We did not mean the Smartclient Admin console, but rather server console/terminal. So, these log files with empty lines are the only output for the Smartclient logging?

Did you try to configure more appenders in your Log4j2 config for the Smartclient related logging and see if all appenders would have the same issue with empty messages in the beginning? You could also try to test this with Slf4j simple logger (slf4j-simple-*.jar) which outputs logging to the server console just to make sure that Smartclient logging works. Also, is this consistently happening after each server restart for example?

Let us know please if this helped to reveal something. This seems to be configuration / implementation specific, cause from Smartclient point of view with this configuration we just use Slf4j API for logging and that's all.

[muralik]

Yes I am able to identify and resolve the issue. SmartClient has some log messages in ISCInit, Config and ConfigLoader class before it initializes it logger configuration. These log messages are written to the log file. But after initialization of loggers, based on the appender definition given (which as append="false"), it tries to delete these log entries and hence the file is generated with null characters. Ideally it should have truncated the file but it is present with null characters.
However, we set the append="true" to the appender definition, all the initialization entries are retained and further logging happens. So this solves our problem.
Thanks, looking at the console appender logging it helped me identify the issue.
One thing is the logging entries should be generated after Loggers are initialized in your code ISCInit class isn't it?

[Isomorphic]

Smartclient logging system initializes once it is first touched, so there's no such thing as generated logging entries before logging system started. Also, in your case when you are using Slf4j, there's not too much to initialize as we just forward log messages to the Slf4j API.

We would like to better understand your issue, despite you've already solved it. Do you mind to let us know how to reproduce that? Like, what is your setup and what config did you use to get the log file with null entries.