Hibernate ORM: drop-and-create logs too verbose
#16204
Comments
|
I guess we could filter them, but I'm not sure about it being a good idea. It seems the ones you got are harmless, but what if you had a more serious SQL exception? Ideally ORM could be improved to have an advanced dictionary to grade the severity of each such case, but unless it gets contributed I'm afraid we have more pressing things to fix. |
|
Agreed. We really don't have a good way to know that the warning is completely harmless. |
|
Don't they follow an obvious pattern? If we know what tables we create, I mean. |
|
Which database is it? Is it one for which we use |
agreed this is the better direction to approach the issue. |
|
Pretty sure it's postgres. Not sure if you use |
|
So, my app startup is now: As you can see, it's mostly bullshit. I wish I could filter it out but it doesn't seem obvious how. I've set a breakpoint in where it's printed and there: I guess if we could set a threadlocal indicating we're in We really have to fix this stuff, it's a very poor startup experience. |
|
Note it's even worse with some databases, e.g. Oracle: it seems we display a full stack trace... See #26228 Maybe we should have a look at how to fix this in Hibernate ORM 6.x, with a list of error codes we can safely ignore in exceptions/JDBC warnings, but that should be only in the context of schema dropping, and that will probably require some disruptive internal changes... |
|
Is it possible to suppress these logs? |
|
FYI @yrodiere , Renarde took this bold build step: @BuildStep
void removeHibernateLogging(LaunchModeBuildItem launchMode,
BuildProducer<LogCleanupFilterBuildItem> logFilters) {
if (launchMode.getLaunchMode().isDevOrTest()) {
// FIXME: this is too broad, but waits for https://github.com/quarkusio/quarkus/issues/16204 to be fixed
logFilters
.produce(new LogCleanupFilterBuildItem("org.hibernate.engine.jdbc.spi.SqlExceptionHelper",
"SQL Warning Code: 0, SQLState: 00000",
"relation \"",
"table \"",
"sequence \""));
}
}And I've never felt this problem again :) |
|
@gavinking any change you can make magic happen? |
|
Another input for this issue: I have a quarkus microservice using a h2 db (in test) and I have configured a default scheme
and in test I have configured quarkus/hibernate to create schema and tables
When I run tests I see logs of warning level regarding an unknown schema (when dropping tables). Can I do anything so hibernate orm does not try to delete tables in a non-existing schema? Thanks for any input. Best regards Trym Stracktrace: |
We do (of course) use
This has annoyed me no end, but I don't see an obvious reasonable way to fix it. I don't think we can just ignore errors that occur during schema export, not even while dropping.
I'm skeptical that such error codes exist. If you look at what we log for Postgres, it's: So there's no useful information there. We also get the message: so in principle we could filter based on that English text, but that's quite fragile.
Well, yes, of course you can: configure it to only-export, instead of first dropping. Hell, with So this is quite easily-solved on your end. |
|
If someone really wants this fixed, they could write code to check with the JDBC metadata (or |
Actually, this is not terribly hard, since |
|
This is quite annoying when you start developing in Quarkus. |
I just looked at what this SQLState is... and it turns out it's clearly defined. From the javadoc of
In Postgres at least, this code is not just set to And from what I can read here, Question is, can we actually rely on these codes being set correctly by JDBC drivers. But if they are, and for postgres it seems they are, we can probably do something. WDYT @gavinking? Am I misinterpreting something? I just learned about this "standard"... |
|
I mean:
So I don't see how a warning can be 00, unless it's just .... wrong, and therefore untrustworthy. I already outlined a way to solve this by simply not sending the On the other hand, if nobody can be bothered to implement the straightforward fix, then obviously this is a very low-priority problem and we should quit wasting time arguing over it. |
It's straightforward to implement, but this has obvious downsides. We have several pending bug reports about very bad performance when retrieving metadata from the database on large models -- we're talking about dozens of minutes. So sure it's one way, but no it's not a silver bullet. Hence this discussion.
My point is not -- or rather, wasn't -- to argue, but to propose a workable solution that wouldn't cost much to implement. I suppose we can indeed call that a waste of time if it doesn't lead to any actual patch.
In the specific case of the PostgresQL JDBC driver, these codes seem trustworthy -- as in, they match what the DB returned. It's simply that the driver shoves all non-error messages into warnings. To be fair, it's not like JDBC has a very precise mapping with these SQL states: there's success, warning, error, "no data" (whatever that means), but on the JDBC side we have only warning and exception. We can certainly report the problem to the postgresql JDBC driver, and ask them to filter out non-warnings properly. But I'm not very confident this will lead somewhere, and I suspect it will take time (though I may be wrong). Personally I think implementing a few conditions in ORM's SQLHelper, at least for databases known to have reliable SQLStates, to log on a different level depending on the SQLState, would make sense. It wouldn't be the first time we work around a questionable behavior in a JDBC driver for convenience. |
Here, somebody could be bothered: hibernate/hibernate-orm#8595 , https://hibernate.atlassian.net/browse/HHH-18296 |
|
This sounds great, @yrodiere :) |
|
FWIW I also reported the issue to pg-jdbc: pgjdbc/pgjdbc#3300 This might be useful if my PR doesn't get merged (and right now, that seems to be the most likely outcome). |
|
The warning comes from the server. I don't think it's the job of the driver to filter out warnings. |
My point is it's not a warning, since the SQL state starts with And if you think it's not the job of the driver to filter out any message, well, @gavinking thinks it's not the job of Hibernate ORM either, so I guess it will be the application programmer's responsibility. |
|
So after looking at this some more, I have to agree. Not sure why this is a new problem ? |
|
Thanks you so much, that's a nice ending to a bad day 🙂 I don't think the problem is very new, since this was reported in 2021... It just took this long to get prioritized and forwarded after the root cause was identified. Also, Hibernate ORM has been pushing users to newer db/dialect versions more aggressively lately, so maybe most Hibernate ORM users were using an old dialect before? That does result in far worse logs with large stacktraces, but completely unrelated to pgjdbc. Which would explain why the problem in pgjdbc wasn't noticed by Hibernate ORM users, at least. |
|
So, recap of the day:
So https://hibernate.atlassian.net/browse/HHH-18296 will be fixed in ORM 6.6 and this issue will be fixed as soon as Quarkus upgrades to that version (see #41359) Thanks everyone! |
yrodiere
added
the
triage/upstream
|
Sounds great, thanks everyone :) |
In DEV mode, I just got those logs:
Due to this config:
Given that they're not real issues, and we know about them, is there any way we can filter them out?
CC @Sanne @yrodiere ?
The text was updated successfully, but these errors were encountered: