Help me understand these "PagePool size has exceeded max size" warnings

dev support
1

We recently changed our log level on the Application.log file to be “INFO” instead of “ERROR”. I believe this makes sense because when we do things like <cflog text="The process is done"/>, that is an INFO message and we want to see those.

But there has been some additional noise in the application.log lately, and I think it’s related to the loglevel change. I’d like to understand if what I am seeing in the log is a problem and what I should do about it. And why I can’t correlate that number (1551 or even 1000) when running PagePoolList().

The new-to-me log lines are, for example:

"INFO","Thread-1239792","02/17/2023","12:16:45","lucee.runtime.PageSourcePool","PagePool size [1551] has exceeded max size [1000]. Clearing unused..."
"INFO","Thread-1239792","02/17/2023","12:16:45","lucee.runtime.PageSourcePool","New pagePool size [1551]."
"INFO","Thread-1239900","02/17/2023","12:17:45","lucee.runtime.PageSourcePool","PagePool size [1551] has exceeded max size [1000]. Clearing unused..."
"INFO","Thread-1239900","02/17/2023","12:17:45","lucee.runtime.PageSourcePool","New pagePool size [1551]."
"INFO","Thread-1240065","02/17/2023","12:18:46","lucee.runtime.PageSourcePool","PagePool size [1551] has exceeded max size [1000]. Clearing unused..."
"INFO","Thread-1240065","02/17/2023","12:18:46","lucee.runtime.PageSourcePool","New pagePool size [1551]."
"INFO","Thread-1240180","02/17/2023","12:19:45","lucee.runtime.PageSourcePool","PagePool size [1556] has exceeded max size [1000]. Clearing unused..."
"INFO","Thread-1240180","02/17/2023","12:19:45","lucee.runtime.PageSourcePool","New pagePool size [1556]."
"INFO","Thread-1240335","02/17/2023","12:20:45","lucee.runtime.PageSourcePool","PagePool size [1556] has exceeded max size [1000]. Clearing unused..."
"INFO","Thread-1240335","02/17/2023","12:20:45","lucee.runtime.PageSourcePool","New pagePool size [1556]."

First of all the application name (lucee.runtime.PageSourcePool) must be something internal, we don’t have anything named like that obviously.

I wanted to get a sense for what was in this overflowing page pool, so I ran <cfdump var="#PagePoolList()#"/>, but the count on that array is always around 800-900. Not the 1556 number shown in the logs.

But then I realized that my dump code above was using my app’s application name, so maybe it’s showing me a different list than than what the log entry is referring to. So I created a new directory with a new application.cfc file and gave it an application name of “lucee.runtime.PageSourcePool” and ran the same getPagePool dump code. That dumps out around 450 files in the page pool. The names of those files are files from my codebase, although obviously some are missing because my other dump of getPagePool using my own application name results in a dump of 800-900 files.

Can someone help me understand what is going on? Which page pool is overflowing past 1000 entries?

And if it is of no consequence - then should a change be made to turn off this logging? Maybe it should only show up with a more verbose log level?

Thanks.

OS: Windows 2019
Java Version: 11.0.18
Tomcat Version: 9.0.71
Lucee Version: 5.3.10.120

2

The page pool is a memory pool used by Lucee Server to store compiled cfm pages. Throw more memory at it :slight_smile:

3

No, memory will not fix this. Lucee has a hard coded limit of 1000 items in the pagepool cache for … reasons. It cannot be changed. All you can do is adjust your logging levels to hide the warnings.

As to why the output of the pagePoolList() BIF returns a smaller number, that’s a great question, but Im tempted to say there may be more than one pool. You’d have to dig into the source code to compare that pool that BIF is looking at compared to the controller thread, which logs that warning…

Ideally, you’d be allowed to configure the limit like Adobe has had forever. Here’s some related links

https://luceeserver.atlassian.net/browse/LDEV-2418
https://lucee.daemonite.io/t/pagepool-1191-1000/5562

1 Like
4

@stillnet I know this is an old thread, but I ran into this recently and wanted to share a few things.

Firstly, Lucee has more than one page pool. It actually has one for every mapping, which explains why the logs doesn’t necessarily path the pagePoolList() function. The function combines the sources stored across a handful of mapping types, but not all of them. The log messages don’t tell you WHICH page pool they are referring to which makes it hard to decipher. If you want to see every possible page pool and every possible mapping, this code will show you. This is also the full list of page pools cleared when you run pagePoolClear().

                config = getPageContext().getConfig();
                mappingTypes = [
                    config.getMappings(),
                    config.getCustomTagMappings(),
                    config.getComponentMappings(),
                    config.getFunctionMappings().toArray(),
                    config.getServerFunctionMappings().toArray(),
                    config.getTagMappings().toArray(),
                    config.getServerTagMappings().toArray()
                ]

                ac = getPageContext().getApplicationContext();
                if( !isNull( ac ) ) {
                    mappingTypes.append( ac.getMappings() ?: [] )
                    mappingTypes.append( ac.getComponentMappings() ?: [] )
                    mappingTypes.append( ac.getCustomTagMappings() ?: [] )
                }
                qryData = queryNew( "virtual,path,size,max", "string,string,number,number" );
                for( mappings in mappingTypes ) {
                    for( mapping in mappings ) {
                        pool = mapping.getPageSourcePool();
                        qryData.addRow( [ mapping.getVirtualLowerCaseWithSlash(), ( mapping.getArchive() ?: mapping.getPhysical() ?: 'N/A' ) & '', pool.size(), pool.getMaxSize() ] );

                    }
                }
                qryData.sort( 'size', 'desc' );
                echo( '<table>' );
                echo( '<tr><td><b>Mapping</b></td><td><b>Physical/Archive</b></td><td><b>Pool size</b></td></tr>' );
                for( row in qryData ) {
                    echo( '<tr><td>#encodeForHTML( row.virtual )#</td><td>#encodeForHTML( row.path )#</td><td>#row.size# / #row.max#</td></tr>' );
                }
                echo( '</table>' );

Furthermore, Lucee currently still has the clearUnused() method in place even though it’s been neutered and doesn’t actually remove anything. No clue why, it doesn’t make a lot of sense and when pointed this out on a ticket a couple years ago, no one replied :person_shrugging: The messages are still annoying however, and the clear unused function runs every 60 seconds or so and is a waste of CPU that ALSO synchronized the entire page pool every time it runs. :confused:

The following code will effectively hack the size of every page pool to 10,000 so the clear unused method exits without doing anything. You only need to run this code once after your application has been defined. Use at your own risk :slight_smile:

			config = getPageContext().getCOnfig();
			mappingTypes = [
				config.getMappings(),
				config.getCustomTagMappings(),
				config.getComponentMappings(),
				config.getFunctionMappings().toArray(),
				config.getServerFunctionMappings().toArray(),
				config.getTagMappings().toArray(),
				config.getServerTagMappings().toArray()
			]

			ac = getPageContext().getApplicationContext();
			if( !isNull( ac ) ) {
				mappingTypes.append( ac.getMappings() ?: [] )
				mappingTypes.append( ac.getComponentMappings() ?: [] ) 
				mappingTypes.append( ac.getCustomTagMappings() ?: [] )
			}

			for( mappings in mappingTypes ) {
				for( mapping in mappings ) {
					pool = mapping.getPageSourcePool();
					if( pool.getMaxSize() == 1000 ) {
						f = pool.getClass().getDeclaredField( 'maxSize' );
						ms = f.getClass().getDeclaredMethods()
						f2 = arrayFilter( ms, (m)=>m.getName() == 'setAccessible' )[1]
						f2.invoke( f, [true] )
						f.setInt( pool, 10000 )
					}
				}
			}
1 Like
5

Or just add the following java option and restart lucee. -Dlucee.pagePool.maxSize=4000

It will set all the pools to 4000.

1 Like
6

Ohh, nice-- that was added very recently in 5.4. I was using the 5.3 branch of Lucee when researching this so I didn’t notice that.

1 Like
7

I knew it was going to be part of 6 and also missed it being added to 5.4. Excellent!