Application.log full of unwanted OSGI logs

My application.log seems to have my own statements, as well as ones from OSGI :

"INFO","http-nio-8888-exec-7","06/19/2020","11:16:36","OSGI","add bundle:/wwwroot/clients/p/patientpass/dev/java-libs/aws/joda-time-2.8.1.jar"
"INFO","http-nio-8888-exec-7","06/19/2020","11:16:36","","application started"

Is there any way to filter this log before it is output ? I can’t change every single one of our writelog()'s to a different level, that’s tons of work…

OS: Amzon Linux
Java Version: 11
Lucee Version: Docker - lucee/lucee:5.3-nginx

@thefalken, Change the log level for application.log info to error in the admin-logging.

That removes the OSGI lines, but also my own log ( e.g. CFLOG or writelog() )

For clarity I want to not have the first line in the example above, but keep the 2nd. All in a single file.
I don’t understand what is going wrong, or if Lucee has new defaults, or what.

This is possible to duplicate with the default Docker image @justincarter

Run the image with docker run -p 80:80 -v/tmp/:/var/www lucee/lucee:5.3-nginx

Unpack this .zip into tmp - it contains a very basic Application.cfc and index page that creates a Java object from the included .jar files.
You can unpack anywhere - just adjust the -v above to match

Run the index.cfm via your browser.

To see the log file I ran docker ps then put the name into docker exec -it dazzling_cerf /bin/bash and ran tail -f /opt/lucee/web/logs/application.log (3.5 MB)
The log file lists multiple unwanted “OSGI add bundle” lines for each request.

"INFO","http-nio-8888-exec-1","06/19/2020","12:54:21","","hi from cf logs"
"INFO","http-nio-8888-exec-1","06/19/2020","12:54:21","OSGI","add bundle:/var/www/java-libs/aws/joda-time-2.8.1.jar"
"INFO","http-nio-8888-exec-1","06/19/2020","12:54:21","OSGI","add bundle:/var/www/java-libs/aws/jackson-databind-"
"INFO","http-nio-8888-exec-1","06/19/2020","12:54:21","OSGI","add bundle:/var/www/java-libs/aws/jackson-core-2.6.7.jar"
"INFO","http-nio-8888-exec-1","06/19/2020","12:54:21","OSGI","add bundle:/var/www/java-libs/aws/jackson-annotations-2.6.0.jar"

What is the exact Lucee version?

the latest 5.3.7 RC apparently doesn’t have this problem anymore

I’m using FROM lucee/lucee:5.3-nginx which is Lucee

Can confirm that applying 5.3.7 RC resolves the issue.

Docker image lucee/lucee: still has the issue from the same test files

<cflog text="hi from cf logs #serializeJson(server.lucee.version)#">
<cfset f=createObject('java',"com.amazonaws.HttpMethod") />


"INFO","http-nio-8888-exec-2","06/19/2020","14:46:30","","hi from cf logs """""
"INFO","http-nio-8888-exec-2","06/19/2020","14:46:30","OSGI","add bundle:/var/www/java-libs/aws/jackson-annotations-2.6.0.jar"
"INFO","http-nio-8888-exec-2","06/19/2020","14:46:30","OSGI","add bundle:/var/www/java-libs/aws/jackson-core-2.6.7.jar"
"INFO","http-nio-8888-exec-2","06/19/2020","14:46:30","OSGI","add bundle:/var/www/java-libs/aws/jackson-databind-"

AFAIK, it’s normal you will see that on restart after the upgrade…after 7 days since applying the upgrade, I still have only 1 entry. Keep monitoring. I was getting them every 5 minutes.

3 	 add bundle:C:\lucee\tomcat\lucee-server\bundles\mssqljdbc4-4. 0.2206.100.jar	7 days ago	1   	
4 	 Start bundle: [mssqljdbc4:4.0.2206.100]	7 days ago	1   	
5 	 add bundle:C:\lucee\tomcat\lucee-server\bundles\sun.jai. codec-	7 days ago	1   	
6 	 Start bundle: [metadata.extractor:]	7 days ago	1   	
7 	 add bundle:C:\lucee\tomcat\lucee-server\bundles\lucee.image. extension-	7 days ago	1  

BTW…if you don’t know there’s a good plugin you can add from the server admin called Log Analyzer

I get an OSGI line for each and every writelog() call, see below.

You are using the RC Docker image ?

"INFO","http-nio-8888-exec-3","06/22/2020","09:06:31","","hi from cf logs"
"INFO","http-nio-8888-exec-3","06/22/2020","09:06:31","OSGI","add bundle:/var/www/java-libs/aws/jackson-annotations-2.6.0.jar"
"INFO","http-nio-8888-exec-3","06/22/2020","09:06:31","OSGI","add bundle:/var/www/java-libs/aws/jackson-core-2.6.7.jar"
"INFO","http-nio-8888-exec-3","06/22/2020","09:06:32","OSGI","add bundle:/var/www/java-libs/aws/jackson-databind-"
"INFO","http-nio-8888-exec-3","06/22/2020","09:06:32","OSGI","add bundle:/var/www/java-libs/aws/joda-time-2.8.1.jar"
"INFO","http-nio-8888-exec-4","06/22/2020","09:06:32","","hi from cf logs"
"INFO","http-nio-8888-exec-4","06/22/2020","09:06:32","OSGI","add bundle:/var/www/java-libs/aws/jackson-annotations-2.6.0.jar"
"INFO","http-nio-8888-exec-4","06/22/2020","09:06:32","OSGI","add bundle:/var/www/java-libs/aws/jackson-core-2.6.7.jar"
"INFO","http-nio-8888-exec-4","06/22/2020","09:06:32","OSGI","add bundle:/var/www/java-libs/aws/jackson-databind-"
"INFO","http-nio-8888-exec-4","06/22/2020","09:06:32","OSGI","add bundle:/var/www/java-libs/aws/joda-time-2.8.1.jar"

Nope. Just the standard server admin update

@justincarter is the lucee/lucee: updating OK ?

It looks like Lucee is doing that logging for the OSGI bundles that it’s loading. It shouldn’t be specific to using the Docker images, I would guess it’s reproducible in a standard install or in Lucee Express as well?

Docker builds for a specific version number only happen once, so was built 22 days ago, and once that image is tagged it will not change (any new builds will have a new version number)

From the comments in the ticket I suspect it’s not fixed in Lucee yet;

Pothys - MitrahSoft [June 15, 2020, 9:30 AM]: I’ve checked this with and latest snapshot also. That latest RC version is not a fix for this issue. Still, it throws an same issue.

I think there’s been a subsequent RC ? Further up the thread ?

______________________________________________________________________ This email has been scanned by the Symantec Email service. For more information please visit ______________________________________________________________________