[jboss-jira] [JBoss JIRA] (WFLY-11037) Intermittent Agroal warnings during startup
Rich DiCroce (JIRA)
issues at jboss.org
Mon Sep 24 12:22:01 EDT 2018
[ https://issues.jboss.org/browse/WFLY-11037?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Rich DiCroce updated WFLY-11037:
--------------------------------
Description:
Sometimes during startup, Agroal spams the log with this:
{code}
2018-09-18 10:35:46,226 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state CHECKED_IN
2018-09-18 10:35:46,226 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,226 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,233 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
{code}
I'm not sure why, and it doesn't always happen.
My pool configuration is:
{code}
<connection-pool max-size="${database.maxPool:20}" background-validation="30000" idle-removal="30"/>
{code}
But this also occurs when background-validation and idle-removal are omitted.
was:
Sometimes during startup, Agroal spams the log with this:
{code}
2018-09-18 10:35:46,226 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state CHECKED_IN
2018-09-18 10:35:46,226 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,226 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
2018-09-18 10:35:46,233 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
{code}
I'm not sure why, and it doesn't always happen. It appears to have something to do with idle-removal being on, as I was not able to reproduce the issue without it.
My pool configuration with the problem (sometimes) happening is:
{code}
<connection-pool max-size="${database.maxPool:20}" background-validation="30000" idle-removal="30"/>
{code}
> Intermittent Agroal warnings during startup
> -------------------------------------------
>
> Key: WFLY-11037
> URL: https://issues.jboss.org/browse/WFLY-11037
> Project: WildFly
> Issue Type: Bug
> Components: Agroal
> Affects Versions: 14.0.0.Final
> Reporter: Rich DiCroce
>
> Sometimes during startup, Agroal spams the log with this:
> {code}
> 2018-09-18 10:35:46,226 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state CHECKED_IN
> 2018-09-18 10:35:46,226 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,226 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,227 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,228 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,229 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,230 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,231 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,232 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> 2018-09-18 10:35:46,233 WARN [io.agroal.pool] (Agroal_6738675721) WFLYAG0601: SciQ_DS: Closing connection in incorrect state DESTROYED
> {code}
> I'm not sure why, and it doesn't always happen.
> My pool configuration is:
> {code}
> <connection-pool max-size="${database.maxPool:20}" background-validation="30000" idle-removal="30"/>
> {code}
> But this also occurs when background-validation and idle-removal are omitted.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
More information about the jboss-jira
mailing list