FWD » Core Development » Runtime Infrastructure

The problem is not Tomcat, but Spring. I'm not sure how to reproduce it to be able to offer a smarter solution instead of losing some logs.

How is their Spring logging configured, does it produce separate files?

Galya B wrote:

How is their Spring logging configured, does it produce separate files?

I do not know these details.

But, as this is not a FWD JVM (server or client), I don't think CentralLogger should default (via slf4j) or interfere with the web app logging configuration.

Usually when you decide to use a framework, logging is provided by the framework. Here we have Spring framework in FWD framework and FWD framework needs to pretend it's invisible. There is something fishy here, but I can't put my finger on it right away. So this spring web app is deployed as .war in deploy/lib and defined in standard/warfile in directory? I'll try to reproduce it.

For the time being easiest would be to remove slf4j logs by separating StaticLoggerBinder, as suggested, but it means 3rd party libs logs will be lost.

No, the spring web app is running in its own JVM via tomcat - it is not running in the FWD server JVM.

The customer reports that after removing org.slf4j.impl.StaticLoggerBinder from the p2j.jar used in tomcat the issue is gone.

• the FWD server will add fwd-slf4j.jar to the classpath (via deploy/lib/) and all will work the same
• when deploying to tomcat, this @fwd-slf4j.jar@ will not be included.

Galya B wrote:

The problem is not Tomcat, but something with Spring picking up slf4j impl from the classpath.

They have no control over the classpath, to i.e. move p2j.jar to be the last in the classpath; even so, we should not introduce configuration requirements when p2j.jar is used outside of FWD server or client.

Can you please share the full stacktrace for the above exception, while I'm working on separating the class?

This is all I have from the customer.

When using framework as library inside a container there is a very high chance to get classpath problems. The real solution of this task is not separating slf4j and losing logs. Configurations are a way around bad classpath, when developers don't understand what it is or don't care what they put in it.

Both logs are pretty obscure without the cause of the issue (initial call in the stacktrace). This does not look acceptable to me for accepting an Urgent task.

Galya B wrote:

The real solution of this task is not separating slf4j and losing logs.

What do you mean by 'losing logs'? Logs from FWD? From somewhere else?

Both logs are pretty obscure without the cause of the issue (initial call in the stacktrace). This does not look acceptable to me for accepting an Urgent task.

The customer is down without a fix, and can't work with the webapp. Please go ahead with the separate jar at this time.

Constantin Asofiei wrote:

Galya B wrote:

The real solution of this task is not separating slf4j and losing logs.

What do you mean by 'losing logs'? Logs from FWD? From somewhere else?

From FWD's 3rd party libraries.

Both logs are pretty obscure without the cause of the issue (initial call in the stacktrace). This does not look acceptable to me for accepting an Urgent task.

The customer is down without a fix, and can't work with the webapp. Please go ahead with the separate jar at this time.

I am working on it, as I've said, but the task can't be closed with this "fix".

Ask the customer to send the full exceptions, when their stress level is lower and they can manage the mouse to copy paste more context.

Galya B wrote:

From FWD's 3rd party libraries.

FWD can't be in charge of 3rd party libraries when is deployed in a separate JVM; FWD is in charge of logging only when running as FWD server or FWD client.

Constantin Asofiei wrote:

Galya B wrote:

From FWD's 3rd party libraries.

FWD can't be in charge of 3rd party libraries when is deployed in a separate JVM; FWD is in charge of logging only when running as FWD server or FWD client.

FWD consists of 3rd party libraries and quite a few I should say.
Do you mean when FWD is used as library, there will be no FWD logs at all?

Galya B wrote:

Do you mean when FWD is used as library, there will be no FWD logs at all?

For FWD, the default is CentralLoggerFallback, which fallsback to STDERR - so log message are still emitted. What I mean is that there will be no log files managed by FWD.

I'm not sure if the default slf4j impl that logs to stderr slf4j-simple-2.0.7.jar will work with their setup. Anyways, I'll have to work on reproducing it for a long-term solution.

7589a r14664 ready for review.

Roger, please take a look at 7589a.

Galya, I think the jar needs to be added to this, too:

 <zip destfile="${archive.convert_destfile}" >

I checked it, it's fine. This covers it:

<zipfileset dir="${basedir}/build/lib" 
                    prefix="build/lib" 
                    includes="**" />

I've also tested the deployment with the separate jar and slf4j impl is picked up by 3rd party libs.

I've done a ./gradlew all and it fails with this:

FAILURE: Build failed with an exception.

* What went wrong:
Execution failed for task ':ant-jar'.
> Manifest file: ~/branches/7589a/build/manifest/fwdslf4j.mf does not exist.

* Try:
Run with --stacktrace option to get the stack trace. Run with --info or --debug option to get more log output. Run with --scan to get full insights.

* Get more help at https://help.gradle.org

Deprecated Gradle features were used in this build, making it incompatible with Gradle 6.0.
Use '--warning-mode all' to show the individual deprecation warnings.
See https://docs.gradle.org/5.6.4/userguide/command_line_interface.html#sec:command_line_warnings

BUILD FAILED in 1m 3s
36 actionable tasks: 36 executed

Ops, I forgot bzr add again, up in r14665.

Constantin Asofiei wrote:

Roger, please take a look at 7589a.

What should I take a look at? You mean with my customer's app?

Roger Borrello wrote:

Constantin Asofiei wrote:

Roger, please take a look at 7589a.

What should I take a look at? You mean with my customer's app?

I know you've made edits to build.xml and build.gradle lately, if the change makes sense in this regard.

When used in this "separate Tomcat JVM" scenario, we should to implement a fwd-appserver-client.jar which only includes enough of FWD to replace the 4GL "Open Java Client". Customers should not have to load the full p2j.jar for this use case. This work will be done in a different task.

Constantin Asofiei wrote:

I know you've made edits to build.xml and build.gradle lately, if the change makes sense in this regard.

Looks fine.

The new jar will be included in the archive, which is unzipped in its entirety by the deploy_fwd.sh script. That script is used in my docker build scripts. All good!

The customer's log has this:

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/home/app/projects/webapp/app-war/target/app/WEB-INF/lib/fwd-p2j-jar-4.0.0.14663.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/home/app/projects/webapp/app-war/target/app/WEB-INF/lib/logback-classic-1.2.10.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [com.goldencode.p2j.util.logging.CentralSlf4jLoggerFactory]

According to the logs customer's app uses the first implementation it finds, i.e. FWD's, that's why we see Spring trying to use CentralSlf4jLogger in the stacktrace, while logback-classic comes from Spring. Supposedly now that our StaticLoggerBinder is removed, FWD's 3rd party libs will log using logback-classic.

Don't we need to do something with 7589a?

Right. It has to be merged. It separates slf4j implementation in its own jar, but builds in the same way. Can be removed on deploy.

Hynek/Constantin: Any objection to the merge?

Galya: What documentation do we need to explain this?

There is no change for customers who don't experience problems with their own Java logging. If they have their own Java logging (like Spring does) and complain about it, they will have to just remove the jar from the lib folder. It's very customer specific. Not sure how it can be documented.

There is no change for customers who don't experience problems with their own Java logging. If they have their own Java logging (like Spring does) and complain about it, they will have to just remove the jar from the lib folder. It's very customer specific. Not sure how it can be documented.

I think in our logging-related pages we need to highlight an example of the problem that can occur and explain the resolution.

Since we add our own slf4j override implementation, it can affect many customers. This would be unexpected. Adding this to the documentation will at least allow customers to help themselves instead of calling Galya. ;)

Yep, yep, I forgot we have relevant documentation... Working on it.

Check the new Logging section Interference with customer's Java app logging.

Check the new Logging section Interference with customer's Java app logging.

It is a good result. I've made some small edits. Please confirm they are OK.

Thanks! I was struggling badly with that possessive 's :) It's good.

Greg Shah wrote:

Hynek/Constantin: Any objection to the merge?

No objection here.

Hynek Cihlar wrote:

Greg Shah wrote:

Hynek/Constantin: Any objection to the merge?

No objection here.

I'm good too.

You can merge now.

Code Review fix-spawner-classpath.diff

I'm fine with the changes.

How have they been tested?

7589b r14868: adds FWD's slf4j implementation to the classpath of both the temp JVM created by the spawner and the spawned client.

execvp previously was showing a warning that slf4j implementation is not found. Now this is fixed.

fwd-slf4j.jar is added to the client's classpath in ClientBuilderOptions, being the default for directory's config classpath-extra-jars and thus can be replaced easily with another slf4j implementation.

If the slf4j library file is missing from the path, the client still spawns without issues. When it's available, the logs will have the record INFO | org.eclipse.jetty.util.log | PID:136019, ThreadName:main | Logging initialized @800ms to org.eclipse.jetty.util.log.Slf4jLog.

This is the type of warnings displayed when no slf4j imp present for the client:

23/12/14 09:28:47.867+0200 | WARNING | Spawner-2 | ThreadName:Spawner-2-Logger | SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
23/12/14 09:28:47.867+0200 | WARNING | Spawner-2 | ThreadName:Spawner-2-Logger | SLF4J: Defaulting to no-operation (NOP) logger implementation
23/12/14 09:28:47.867+0200 | WARNING | Spawner-2 | ThreadName:Spawner-2-Logger | SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.

Greg Shah wrote:

Code Review Task Branch 7589b Revision 14868

The changes look good. If suitable testing has been completed, we can get this merged.

I've tested both clients (temp and regular) with and without the .jar in the classpath and I think it can be merged.

You can merge now.

Happy New Year!

I just wanted to post a "public service announcement" as this update to postbuild.sh creates a minor issue with Docker projects. These are projects that use postbuild.sh to position the spawner in the Docker images, as well as the FWD Docker images, which include as much of the FWD aspects of the /opt/spawner as possible. We don't want to assume a build environment is available, so that is the background for why the postbuild.sh was updated in the first place.

To illustrate, the FWD Docker file has:

# Step 9/11
RUN chown -R fwd:fwd /opt/fwd-deploy && \
    mkdir -p /opt/spawner && \
    cp /opt/fwd-deploy/spawner/spawn /opt/fwd-deploy/spawner/p2j.jar /opt/spawner/ && \
    chmod -R gou+rx /opt/spawner/ && \
    chmod u+s /opt/spawner/spawn && \
    chmod 0550 /opt/spawner/p2j.jar

# Step 9/11
RUN chown -R fwd:fwd /opt/fwd-deploy && \
    mkdir -p /opt/spawner && \
    cp /opt/fwd-deploy/spawner/spawn /opt/fwd-deploy/spawner/*.jar /opt/spawner/ && \
    chmod -R gou+rx /opt/spawner/ && \
    chmod u+s /opt/spawner/spawn && \
    chmod 0550 /opt/spawner/*.jar

Then, project Docker files like fwd_4.0_ubuntu_22.04_hotel_gui_server_Dockerfile.template in the hotel_gui project will have:

/opt/fwd-deploy/spawner/postbuild.sh /opt/spawner /opt/fwd-deploy/spawner/spawn /tmp/${PROJECT}/deploy/server/srv-certs.store /opt/fwd/build/lib/p2j.jar

/opt/fwd-deploy/spawner/postbuild.sh /opt/spawner /opt/fwd-deploy/spawner/spawn /tmp/${PROJECT}/deploy/server/srv-certs.store /opt/fwd/build/lib/p2j.jar /opt/fwd/build/lib/slf4j-impl.jar

The default for SLF4J_JAR (../lib/fwd-slf4j.jar) won't be found unless the current directory is ./p2j/src/native, which is the whole reason to have updated postbuild.sh in the first place, so that relative pathing that assumes a build environment can be overridden. I'll be updating hotel_gui and the customer projects I am maintaining.

The often used install_spawner.sh scripts will mostly be OK, since typically it is used with a build environment in place. The updated install_spawner.sh is a little more complicated in that it is aware of, and uses the FWD_LIB environment variable to find the FWD jars if it is set. I'll be updating it as well, to pass in the SLF4J_JAR explicitly to postbuild.sh. I am also correcting some of the default behavior of install_spawner.sh so it still works as it had in the past. But we really do want to avoid forcing a build environment to be available when creating the spawner directory. But it should behave properly if there is a build environment, which I will be correcting in hotel_gui.

There were also a couple of oversights with this branch that was merged to trunk. The first is that there isn't a failure check if SLF4J_IMPL doesn't exist:

=== modified file 'src/native/postbuild.sh'
--- old/src/native/postbuild.sh    2023-12-13 10:14:46 +0000
+++ new/src/native/postbuild.sh    2024-01-02 17:51:38 +0000
@@ -133,6 +133,11 @@
    exit 1
 fi

+if [ ! -f $SLF4J_IMPL ]; then
+   echo "$SLF4J_IMPL does not exist!" 
+   exit 1
+fi
+
 if [ $# -gt 2 ]; then
    if [ ! -f "$cert_file" ];    then
       echo "$cert_file does not exist!" 

The other is really something that was missing before, but should be addressed, and that is the inclusion of the necessary jar files in the native archive:

=== modified file 'build.xml'
--- old/build.xml    2024-01-02 13:01:11 +0000
+++ new/build.xml    2024-01-02 17:49:45 +0000
@@ -1134,9 +1134,13 @@
     <property name="archive.native_destfile" 
               value="${dist.home}/fwd_deploy-native_${major}.${minor}.${release}_${repo}_${branch}_${rev}_${today_date}.zip" />
     <zip destfile="${archive.native_destfile}" >
+        <zipfileset dir="${basedir}/build/lib" 
+                    prefix="lib" 
+                    includes="p2j.jar
+                              fwd-slf4j.jar 
+                              ${libname}" />
         <zipfileset dir="${basedir}/build/native" 
                     includes="spawn*
-                              ${libname}
                               ${launcher}" />
     </zip>
     <chmod file="${archive.native_destfile}" perm="755"/>

The inclusion of all the FWD jars in the native archive does make the use of install_spawner.sh mostly moot, as at that point only the srv-certs.store file is missing from the spawner directory. I'm not sure how/where to address that, but right now the only place this affects is in the creation of Docker images. Some projects (mostly ones I have touched) do take advantage of the deployment of FWD for devops, and I honestly don't know if all the projects are implemented in the same manner.

Roger Borrello wrote:

Happy New Year!

Happy New Year!

There were also a couple of oversights with this branch that was merged to trunk. The first is that there isn't a failure check if SLF4J_IMPL doesn't exist:

SLF4J_IMPL is not critical, but recommended for the execution of the clients. Adding a failure is not necessary. The customer's case presented in this task is an example, where the slf4j impl won't be provided in a jar.

The other is really something that was missing before, but should be addressed, and that is the inclusion of the necessary jar files in the native archive:
[...]

The inclusion of all the FWD jars in the native archive does make the use of install_spawner.sh mostly moot, as at that point only the srv-certs.store file is missing from the spawner directory. I'm not sure how/where to address that, but right now the only place this affects is in the creation of Docker images.

If you want to introduce a related change, please take into consideration that with 7589b postbuild.sh renames fwd-slf4j.jar to slf4j-impl.jar, when the lib is placed in the spawner dir and this is the name spawn.c and winspawn.c are looking for. The reason is that a different (non-FWD) slf4j implementation can be passed in to the script.

Galya B wrote:

If you want to introduce a related change, please take into consideration that with 7589b postbuild.sh renames fwd-slf4j.jar to slf4j-impl.jar, when the lib is placed in the spawner dir and this is the name spawn.c and winspawn.c are looking for. The reason is that a different (non-FWD) slf4j implementation can be passed in to the script.

Ah, thank you for the explanation. So if there is not a slf4j-impl.jar in place, things will still work fine, but the logging will be sub-optimal?

The reason I am pressing this is that use of relative pathing for the default (../lib/) is problematic in most of my use cases.

Roger Borrello wrote:

Galya B wrote:

If you want to introduce a related change, please take into consideration that with 7589b postbuild.sh renames fwd-slf4j.jar to slf4j-impl.jar, when the lib is placed in the spawner dir and this is the name spawn.c and winspawn.c are looking for. The reason is that a different (non-FWD) slf4j implementation can be passed in to the script.

Ah, thank you for the explanation. So if there is not a slf4j-impl.jar in place, things will still work fine, but the logging will be sub-optimal?

If there is no slf4j implementation lib in the classpath (which can also be set by the web framework in the case of #7589), some 3rd party libraries (most notably Jetty) won't output logs. It's not a major issue, but it's preferable to have it configured. Because of #7589 we had move the slf4j impl as optional / separate jar.

The reason I am pressing this is that use of relative pathing for the default (../lib/) is problematic in most of my use cases.

I see. I'm also not aware of all deployment configs and I'm not sure what else needs to be done.

Thanks for the explanation. In order to achieve a level of flexibility in the Docker versions of projects, the Dockerfiles will need to have an ENV SLF4J_IMPL /opt/spawner/fwd-slf4j.jar in it as the default. This requires a pre-requisite of /opt/spawner/fwd-slf4j.jar being in place, which I can achieve with an update to build.xml as noted in #7589-51. I would also propose this update to postbuild.sh just to prevent any unnecessary error messages:

@@ -146,7 +146,7 @@

 cp -f $spawn_prog ${spawn_dir}/spawn
 cp -f $P2J_JAR ${spawn_dir}/p2j.jar
-cp -f $SLF4J_IMPL ${spawn_dir}/slf4j-impl.jar
+[ -f "$SLF4J_IMPL" ] && cp -f $SLF4J_IMPL ${spawn_dir}/slf4j-impl.jar

 chown root:root ${spawn_dir}/spawn ${spawn_dir}/p2j.jar 
 chown root:root ${spawn_dir}/spawn ${spawn_dir}/slf4j-impl.jar

In the Docker file:

ENV SLF4J_IMPL /opt/spawner/fwd-slf4j.jar
...
# Step 10/17
RUN unzip /tmp/deploy.zip -d /tmp/${PROJECT} && \
    /opt/fwd-deploy/spawner/postbuild.sh /opt/spawner /opt/fwd-deploy/spawner/spawn /tmp/${PROJECT}/deploy/server/srv-certs.store /opt/fwd/build/lib/p2j.jar ${SLF4J_IMPL}

Unfortunately the only example we have is hotel_gui, which I don't believe uses anything other than fwd-slf4j.jar. If there's an example of something other than fwd-slf4j.jar, we'd have the Dockerfile doing something like copying the implementation from the context directory to the image, and that location would be the SLF4J_IMPL value. I can place this as a comment in the hotel_gui dockerfile for now.

I want to make sure we have the fwd-slf4j.jar available in all cases, and that's why I want to update the build.xml to make sure it is in the native archive.

Should I create a 7589b branch to work on this?

Roger Borrello wrote:

In order to achieve a level of flexibility in the Docker versions of projects, the Dockerfiles will need to have an ENV SLF4J_IMPL /opt/spawner/fwd-slf4j.jar in it as the default. This requires a pre-requisite of /opt/spawner/fwd-slf4j.jar being in place, which I can achieve with an update to build.xml as noted in #7589-51.

The Dockerfile accesses /opt/fwd/build/lib/p2j.jar, so SLF4J_IMPL can default to /opt/fwd/build/lib/fwd-slf4j.jar in the Dockerfile. This way it won't have to be copied to the native archive and the spawn dir won't end up with two .jar files for slf4j.

I would also propose this update to postbuild.sh just to prevent any unnecessary error messages

This is a good addition. You can create a new branch for it or add it to another working branch that will be merged soon. Up to you.

Galya B wrote:

Roger Borrello wrote:

In order to achieve a level of flexibility in the Docker versions of projects, the Dockerfiles will need to have an ENV SLF4J_IMPL /opt/spawner/fwd-slf4j.jar in it as the default. This requires a pre-requisite of /opt/spawner/fwd-slf4j.jar being in place, which I can achieve with an update to build.xml as noted in #7589-51.

The Dockerfile accesses /opt/fwd/build/lib/p2j.jar, so SLF4J_IMPL can default to /opt/fwd/build/lib/fwd-slf4j.jar in the Dockerfile. This way it won't have to be copied to the native archive and the spawn dir won't end up with two .jar files for slf4j.

The purpose of having the separate spawner deployment archive was so that it would contain all files necessary to build a working /opt/spawner (or whatever path is desired) directory, so I'm inclined to keep the FWD implementation in it. I have been placing the deployments under /opt/fwd-deploy/... and then using that location to link up the /opt/fwd to /opt/fwd-deploy/convert and use the /opt/fwd-deploy/spawner as the place from which the postbuild.sh is run. If a customer has an implementation, they can specify it when they build the Docker image, and it won't move the fwd-slf4j.jar in the /opt/spawner directory.

I would also propose this update to postbuild.sh just to prevent any unnecessary error messages

This is a good addition. You can create a new branch for it or add it to another working branch that will be merged soon. Up to you.

I have created 7589b and updated the build.xml and postbuild.sh in revision 14912.

I tested postbuild.sh with a bogus file, such that I would be able to test my dockerfile's ability to handle a build-arg and create images containing a specified SLF4J jar file.

The dockerfile has:

ARG SLF4J_IMPL=/opt/fwd-deploy/spawner/fwd-slf4j.jar
ENV SLF4J_IMPL ${SLF4J_IMPL}

So the default works, utilizing the fwd-slf4j.jar that this branch now includes in the spawner archive, but when I specified something bogus, I did get errors in postbuild.sh due to the "bogus" file not being available. While this wouldn't be normal, because the only time you'd really specify something is if it existed, I wanted to clean up the error message.

The revision 14913 I just checked in shows a more controlled warning message:

#11 0.629 Installing the spawn tool /opt/fwd-deploy/spawner/spawn into /opt/spawner/spawn using /tmp/intermodal/deploy/server/srv-certs.store as srv-certs.store 
#11 0.629    file with p2j=/opt/fwd/build/lib/p2j.jar and slf4j=bogus...
#11 0.789 WARNING! The /opt/spawner/slf4j-impl.jar file was not found.
#11 DONE 0.9s

Please review, it would be great to merge this to trunk soon.

Branch 7589b was rebased to trunk_14912 and is at revision 14914.

Roger, did you create 7589b? 7589b is merged. It should have been 7589c.

Galya B wrote:

Roger, did you create 7589b? 7589b is merged. It should have been 7589c.

Oops... I've correct it. Branch 7589c is at revision 14914.

Branch 7589c was rebased to trunk_14915 and is at revision 14916.

Two conditions are introduced, that can be merged together: [ -f "$SLF4J_IMPL" ] && cp -f $SLF4J_IMPL ${spawn_dir}/slf4j-impl.jar and if [ -f "${spawn_dir}/slf4j-impl.jar" ]; then can be simply -f "$SLF4J_IMPL" and then the copy can be moved next to the other file operations.

Otherwise it's good.

Galya B wrote:

Two conditions are introduced, that can be merged together: [ -f "$SLF4J_IMPL" ] && cp -f $SLF4J_IMPL ${spawn_dir}/slf4j-impl.jar and if [ -f "${spawn_dir}/slf4j-impl.jar" ]; then can be simply -f "$SLF4J_IMPL" and then the copy can be moved next to the other file operations.

Otherwise it's good.

Great feedback... committed revision 14917.

Roger Borrello wrote:

Great feedback... committed revision 14917.

Greg, it's good for merge.

You can merge after 7667b.

Greg Shah wrote:

You can merge after 7667b.

I'll rebase and merge as soon as I see it hits.

Branch 7589c was rebased to trunk_14916 and is at revision 14918.

Branch 7589c was merged to trunk as revision 14917 and archived.

This can be closed. We've delivered a way to disable the FWD's slf4j impl what was the issue.