New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: Make warnings available as soon as they are received. #857

Merged
merged 6 commits into from Oct 20, 2017

Conversation

Projects
None yet
7 participants
@magJ
Contributor

magJ commented Jun 30, 2017

Until REL9.4.1210 warnings were available via Statement#getWarnings()
and ResultSet#getWarnings() as soon as they were received from the
server. This commit returns to that behavior.
This is useful for long running queries, where it can be beneficial
to know about a warning before the query completes.

This addresses GH issue #856

@vlsi

This comment has been minimized.

Member

vlsi commented Jun 30, 2017

  1. getWarnings / clearWarnings was never thread safe. In other words, you might easily get NPE when inspecting the warning
  2. PgResultSet#addWarning is O(N), so it would take extreme time in case of lots of warnings
@magJ

This comment has been minimized.

Contributor

magJ commented Jun 30, 2017

This change makes use of the existing optimizations to operate in O(1) time for adding a new warning, it doesn't call PgResultSet#addWarning
Regarding thread safety I'm not really clear on what you mean, I'm not providing any guarantees that the latest warning will be visible to other threads, I guess that the means that the unit test can be flakey, as demonstrated by travis.
People trying to read warnings early should be catering for the possibility of null.
Clearly the test need to be made reliable(il experiment with this).

@vlsi

This comment has been minimized.

Member

vlsi commented Jun 30, 2017

Regarding thread safety I'm not really clear on what you mean, I'm not providing any guarantees that the latest warning will be visible to other threads

Here's what I mean: https://shipilev.net/blog/2014/safe-public-construction/#_safe_publication, https://shipilev.net/blog/2016/close-encounters-of-jmm-kind/#_conclusion_and_parting_thoughts, etc

fix: Make warnings available as soon as they are received.
Until REL9.4.1210 warnings were available via Statement#getWarnings()
and ResultSet#getWarnings() as soon as they were received from the
server. This commit returns to that behavior.
This is useful for long running queries, where it can be beneficial
to know about a warning before the query completes.

This addresses GH issue #856
@codecov-io

This comment has been minimized.

codecov-io commented Jun 30, 2017

Codecov Report

Merging #857 into master will increase coverage by 0.17%.
The diff coverage is 100%.

@@             Coverage Diff             @@
##             master    #857      +/-   ##
===========================================
+ Coverage     65.62%   65.8%   +0.17%     
+ Complexity     3551    3547       -4     
===========================================
  Files           166     167       +1     
  Lines         15248   15233      -15     
  Branches       2473    2471       -2     
===========================================
+ Hits          10007   10024      +17     
+ Misses         4062    4030      -32     
  Partials       1179    1179
@magJ

This comment has been minimized.

Contributor

magJ commented Jun 30, 2017

Well I made some changes fixed the tests and rebased, this change is really just aimed at reclaiming the functionality available prior. I did however mark the PgStatement warnings volatile, which should help with potential cross thread visibility issues.

@vlsi

This comment has been minimized.

Member

vlsi commented Jun 30, 2017

this change is really just aimed at reclaiming the functionality available prior

I won't say "functionality was available prior". It is rather "it seemed like the functionality was available even though that availability was not intentional".

@vlsi

This comment has been minimized.

Member

vlsi commented Jun 30, 2017

@magJ , What thread semantics should be blessed to PgStatement#clearWarnings in case PgStatement#getWarnings is made thread safe?
Should clearWarnings be allowed from within a concurrent thread?
What should be the outcome?

@magJ

This comment has been minimized.

Contributor

magJ commented Jul 1, 2017

@vlsi I don't see a simple way of blessing the use of clearWarnings from outside of the statement executing thread.
If your query generates a lot of warnings it might be desirable to clear them as to free some memory while the query runs I guess.
There are a couple of issues with calling clearWarnings from an outside thread.

  1. Concurrent calls to addWarning and clearWarnings could result in one of the variables warnings or lastWarning having a value, while the other does not, which could result in either a nullpointer calling the next addWarning or the warnings variable never being set again.
  2. The other issue is that a thread attempting to read and clear read warnings could potentially miss a warning that was received in-between the read and the clear.

I would simply recommend not calling clearWarnings but if we want to support that use case, then it will require a more complex synchronization approach.

The first issue can be fixed by synchronizing addWarning and clearWarnings around some lock object, or perhaps some other lock free approach.

If you address the first issue then the second issue can be addressed by having the user hold a reference to the last warning they read and check if its next has a value ie:

SQLWarning lastProcessed = null;
while(statementIsExecuting) {
  SQLWarning warn = statement.getWarnings();
  //if next linked warning has value use that, otherwise keep using latest head
  if (lastProcessed != null && lastProcessed.getNextWarning() != null) {
    warn = lastProcessed.getNextWarning();
  }
  if(warn != null) {
    processWarning(warn);
    lastProcessed = warn;
    if(warn == statement.getWarnings()) {
      statement.clearWarnings();
    }
  }
}
fix: Add support for concurrent read/clear of statement warnings
Prior to this change, clearing warnings while a statement is executing
could of resulted in a NullPointerException when the next warning
was added, or warnings being added to an unreachable warning chain.
@magJ

This comment has been minimized.

Contributor

magJ commented Jul 4, 2017

@vlsi I have added support for thread safe Statement#clearWarnings()

}
super.handleCompletion();
public void handleCommandStatus(String status, int updateCount, long insertOID) {
append(new ResultWrapper(updateCount, insertOID));

This comment has been minimized.

@vlsi

vlsi Jul 22, 2017

Member

Please refrain from method reordering. AFAIK handleCommandStatus was not changed, however it is listed in the diff.

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

I think it's just the way the diff algorithm interpreted the change, handleCompletion() was removed and handleWarning() was added, il have a play around with it so that it doesn’t appear so misleading.
Using the patience algorithm might help, otherwise il just place handleWarning() below handleCommandStatus().

@Override
public void run() {
try {
warning.set(preparedStatement.getWarnings());

This comment has been minimized.

@vlsi

vlsi Jul 22, 2017

Member

Could this be just return preparedStatement.getWarnings() (and could AtomicReference be removed)?

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

Good point, il just use a Callable instead of a Runnable.

try {
warning.set(preparedStatement.getWarnings());
} catch (SQLException e) {
fail("Exception thrown: " + e.getMessage());

This comment has been minimized.

@vlsi

vlsi Jul 22, 2017

Member

Could exception be just propagated? Does fail add some goods here?

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

Yeah, no real reason not to if I use a Callable, but otherwise I cant throw a checked exception from a Runnable

executorService.shutdown();
assertNotNull(warning.get());
assertEquals(warning.get().getMessage(), "Test 1");

This comment has been minimized.

@vlsi

vlsi Jul 22, 2017

Member

Is expected/actual order right here? Could you please use more meaningful messages and/or add an explanation message to assert?

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

Sure.

});
for (int i = 0; i < iterations; i++) {
statement.addWarning(new SQLWarning("Warning " + i));

This comment has been minimized.

@vlsi

vlsi Jul 22, 2017

Member

Is there a reason you use addWarning rather than running a SQL that produces warnings?

I think end-to-end test would make sense here

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

Mostly just because it was easier and faster for me to test locally, I agree it makes more sense to test it end-to-end.

lastProcessed = warn;
if (warn == statement.getWarnings()) {
//System.out.println("Clearing warnings");
statement.clearWarnings();

This comment has been minimized.

@vlsi

vlsi Jul 22, 2017

Member

As far as I can understand, a warning can be lost in the following scenario:
Precondition: satement has chain of 5 warnings.

  1. Thread 1 acquires st.getWarnings()
  2. Thread 2 acquires st.getWarnings() and starts addWarning. Unfortunately it gets suspended.
  3. Thread 1 performs clear warnings
  4. Thread 1 walks getNextWarning chain up to the very end, and "processes" all the warnings
  5. Thread 2 acquires CPU and adds yet another warning to the chain (the chain head was obtained at step 2)
    Thread 1 will never see the warning from step 5 since it did walk through the chain.

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

When you say "suspended" are you referring to Thread#suspend(), or something else?
Because I don't think there is really much that can be done about the former, it's a deprecated API for good reason.

This comment has been minimized.

This comment has been minimized.

@magJ

magJ Jul 26, 2017

Contributor

I was able to simulate your scenario by manually adding delay into the PgStatement#addWarning method after it acquires the reference to the warning wrapper and also adding some delay between the checking of lastProcesed.getNextWarning() and the statement.getWarnings() call.
It was indeed possible for a very unlikely race to cause a warning to be missed.
I have fixed that issue by doing the warn = statement.getWarnings() assignment up front, so there is no way for a racing thread to add any warnings between the check and the assignment.

This comment has been minimized.

@vlsi

vlsi Jul 26, 2017

Member

I have fixed that issue by doing the warn = statement.getWarnings() assignment up front, so there is no way for a racing thread to add any warnings between the check and the assignment.

I am afraid I do not see how the additional warn = statement.getWarnings() solves the issue.
The issue is addWarning thread might wait infinitely long before actually adding a warning. The only check "receiver" does it checks lastProcessed.getNextWarning(), however that gives absolutely no clue on whether new warnings might be added or not.

This comment has been minimized.

@magJ

magJ Jul 26, 2017

Contributor

Well there are only two places a new warning can be added, onto the previous chain or added as the new head of the chain, lastProcessed will be the previous chain.
This algorithm only needs to handle a single-producer scenario, if addWarning takes an indeterminate amount of time, then the consumer will just spin until the producer finally wakes up.
#getNextWarning() and statement.getWarnings() are both volatile reads, so even if two new warnings are added, one to the previous chain and one to the new head, we wont start using the new head until everything is read from the last chain.

This comment has been minimized.

@vlsi

vlsi Jul 26, 2017

Member

Thanks, I see now.
I wonder how many users would be able to replicate this warning consumer loop.

This comment has been minimized.

@magJ

magJ Jul 27, 2017

Contributor

I think it would be unlikely someone would replicate it without looking at this unit test.
Concurrently reading warnings from a statement is probably a fairly niche feature, I think for the majority of use-cases it is unlikely that someone is going to generate enough notices that they would consider using Statement#clearWarnings(), but if they do I think the important thing is that the driver doesn’t crash, and we at least provide some way of the user reading the warnings safely, despite how abstruse the implementation might be.

I considered other approaches like employing locks/synchronization or maybe even exposing a queue data structure, but I felt that those options would introduce negative performance implications for users who don’t need the feature, or in the case of exposing a queue, wouldn’t work with the standard JDBC API.

@magJ

I will work on incorporating your feedback when I get a bit of time, hopefully within the next couple of days.

}
super.handleCompletion();
public void handleCommandStatus(String status, int updateCount, long insertOID) {
append(new ResultWrapper(updateCount, insertOID));

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

I think it's just the way the diff algorithm interpreted the change, handleCompletion() was removed and handleWarning() was added, il have a play around with it so that it doesn’t appear so misleading.
Using the patience algorithm might help, otherwise il just place handleWarning() below handleCommandStatus().

});
for (int i = 0; i < iterations; i++) {
statement.addWarning(new SQLWarning("Warning " + i));

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

Mostly just because it was easier and faster for me to test locally, I agree it makes more sense to test it end-to-end.

@Override
public void run() {
try {
warning.set(preparedStatement.getWarnings());

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

Good point, il just use a Callable instead of a Runnable.

try {
warning.set(preparedStatement.getWarnings());
} catch (SQLException e) {
fail("Exception thrown: " + e.getMessage());

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

Yeah, no real reason not to if I use a Callable, but otherwise I cant throw a checked exception from a Runnable

executorService.shutdown();
assertNotNull(warning.get());
assertEquals(warning.get().getMessage(), "Test 1");

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

Sure.

lastProcessed = warn;
if (warn == statement.getWarnings()) {
//System.out.println("Clearing warnings");
statement.clearWarnings();

This comment has been minimized.

@magJ

magJ Jul 25, 2017

Contributor

When you say "suspended" are you referring to Thread#suspend(), or something else?
Because I don't think there is really much that can be done about the former, it's a deprecated API for good reason.

fix: Incorporate PR feedback, fix test race condition
If the producer thread added multiple warnings after the check
of lastProcessed.getNextWarning, then it was possible for warnings to be
missed by the consumer thread.
@magJ

This comment has been minimized.

Contributor

magJ commented Jul 26, 2017

@vlsi I have incorporated your feedback, please review.

assertNotNull(warning);
assertEquals("First warning received not first notice raised",
warning.getMessage(), "Test 1");

This comment has been minimized.

@vlsi

vlsi Jul 26, 2017

Member

Please use the proper expected, actual argument order: http://junit.sourceforge.net/javadoc/org/junit/Assert.html#assertEquals(java.lang.String, java.lang.Object, java.lang.Object)

lastProcessed = warn;
if (warn == statement.getWarnings()) {
//System.out.println("Clearing warnings");
statement.clearWarnings();

This comment has been minimized.

@vlsi

vlsi Jul 26, 2017

Member

I have fixed that issue by doing the warn = statement.getWarnings() assignment up front, so there is no way for a racing thread to add any warnings between the check and the assignment.

I am afraid I do not see how the additional warn = statement.getWarnings() solves the issue.
The issue is addWarning thread might wait infinitely long before actually adding a warning. The only check "receiver" does it checks lastProcessed.getNextWarning(), however that gives absolutely no clue on whether new warnings might be added or not.

}
if (warn != null) {
warnings++;
//System.out.println("Processing " + warn.getMessage());

This comment has been minimized.

@vlsi

vlsi Jul 26, 2017

Member

Please add assert for each received warning

@Override
public void handleWarning(SQLWarning warning) {
super.handleWarning(warning);
PgResultSet.this.warnings = this.getWarning();

This comment has been minimized.

@vlsi

vlsi Jul 26, 2017

Member

As far as I understand, this might cause double-processing via the following scenario:

  1. Consumer consumes all the warnings, and clears the chain
  2. Producer handles yet another warning, and PgResultSet.this.warnings = this.getWarning(); write results in the same head being used.

This comment has been minimized.

@vlsi

vlsi Jul 26, 2017

Member

Please add a test for ResultSet.getWarnings() as well.

This comment has been minimized.

@magJ

magJ Jul 31, 2017

Contributor

@vlsi I decided to revert the change to ResultSet because I couldn't actually come up with test a scenario where it made sense.
I'm not sure it is even possible for postgres to raise warnings while a result set is reading from a cursor.

* of calling #setNextWarning on the head. By encapsulating this into a single object it allows
* users(ie PgStatement) to atomically set and clear the warning chain.
*/
public class PGSQLWarningWrapper {

This comment has been minimized.

@vlsi

vlsi Jul 26, 2017

Member

Should this be PSQLWarningWrapper? We already have PSQLWarning, PSQLState, PSQLSavepoint, ...

On the other hand, I'm sure this (PGSQLWarningWrapper) class should not be a part of public API, so it might make sense to put it to some .internal. package (or specify in the javadoc that this class should not be used by end clients)

This comment has been minimized.

@magJ

magJ Jul 27, 2017

Contributor

How about moving it to org.postgresql.jdbc.PSQLWarningWrapper and making the class package-private?

This comment has been minimized.

@vlsi

vlsi Jul 27, 2017

Member

If package-private is possible, please do that.

+ "BEGIN "
+ "RAISE NOTICE 'Test 1'; "
+ "RAISE NOTICE 'Test 2'; "
+ "EXECUTE pg_sleep(2); "

This comment has been minimized.

@vlsi

vlsi Jul 26, 2017

Member

Alternative approach would be to use two connections, and make sure the outer transaction holds a row lock preventing notify_then_sleep from making progress.
That would ensure Java gets warnings before statement finish.

What do you think?

This comment has been minimized.

@magJ

magJ Jul 31, 2017

Contributor

Great idea, I have now implemented this, it should speed up the test a bit and make it a little more robust.

lastProcessed = warn;
if (warn == statement.getWarnings()) {
//System.out.println("Clearing warnings");
statement.clearWarnings();

This comment has been minimized.

@vlsi

vlsi Jul 26, 2017

Member

Thanks, I see now.
I wonder how many users would be able to replicate this warning consumer loop.

fix: Add support for concurrent read/clear of statement warnings
Revert change to ResultSet, as could nto conceive of scenario where it
would be needed.
Make PSQLWarningWrapper package-private and moved namespace.
Refactored test to use a lock rather than rely on timing,
should make the test faster and more robust.
con.createStatement().execute("SET SESSION statement_timeout = 1000");
final PreparedStatement preparedStatement = con.prepareStatement("SELECT notify_then_sleep()");
ExecutorService executorService = Executors.newSingleThreadExecutor();
Future<Void> future = executorService.submit(new Callable<Void>() {

This comment has been minimized.

@AlexElin

AlexElin Aug 1, 2017

Contributor

submit Runnable instead of Callable<Void>

This comment has been minimized.

@magJ

magJ Aug 1, 2017

Contributor

@AlexElin Callable is used because the method throws a checked exception, using a Runnable would require catching the exception and manually fail()ing the test, it was changed to Callable based on earlier feedback from vlsi.

This comment has been minimized.

@AlexElin

AlexElin Aug 1, 2017

Contributor

ok

//If test takes longer than 2 seconds its a failure.
future.get(2, TimeUnit.SECONDS);
executorService.shutdown();

This comment has been minimized.

@panchenko

panchenko Aug 1, 2017

can we have executorService as a field and shutdown in @After, to make sure it's always executed?

This comment has been minimized.

@magJ

magJ Aug 1, 2017

Contributor

I didn't want to introduce a new field that is only used in a couple of tests.
This test class currently only has one field which is used in seemingly every test.
The executor will only not be shutdown if the test fails, so it shouldn't really be an issue.
Additionally the the executor will be automatically shut down when its finalizer runs.

This comment has been minimized.

@magJ

magJ Aug 8, 2017

Contributor

I have added a try-finally condition to ensure the executor is shut down.

SQLWarning next = warning.getNextWarning();
if (next != null) {
assertEquals("Second warning received not second notice raised",
"Test 2", warning.getNextWarning().getMessage());

This comment has been minimized.

@panchenko

panchenko Aug 1, 2017

s/warning.getNextWarning()/next/

lastProcessed = warn;
if (warn == statement.getWarnings()) {
//System.out.println("Clearing warnings");
statement.clearWarnings();

This comment has been minimized.

@panchenko

panchenko Aug 1, 2017

It's not obvious to me what happens in the loop here and when warnings are cleared, etc. Would it be possible to improve readability somehow?

This comment has been minimized.

@magJ

magJ Aug 1, 2017

Contributor

Warnings are cleared if the warning just processed is the head of the warning chain, does that explanation help?
I can add a comment to that affect.

This comment has been minimized.

@panchenko

panchenko Aug 1, 2017

Yes, I can see this condition, but trying to understand how often it happens. will try more making notes on paper :)

This comment has been minimized.

@magJ

magJ Aug 1, 2017

Contributor

How often it happens depends on a few factors, I tried to explain it a bit in the javadoc comment.
Some factors that affect it are:

  • How long the users "process" function takes.
  • If they opt to add some delay between each warn == null iteration.
  • OS thread sheduling.
  • Burstiness of the received warnings.

Overall it's fairly random, im not sure how to describe it in a useful way.

public Void call() throws SQLException {
while (true) {
SQLWarning warning = preparedStatement.getWarnings();
if (warning != null) {

This comment has been minimized.

@vlsi

vlsi Aug 7, 2017

Member

In case of failure, this will spin forever.
Please add polling delay and make the thread finish in case of "no warnings received for some reason"

This comment has been minimized.

@magJ

magJ Aug 8, 2017

Contributor

The thread should now be interrupted upon shutting down of the executor.

final int iterations = 1000;
final ExecutorService executor = Executors.newSingleThreadExecutor();
con.createStatement()
.execute("CREATE OR REPLACE FUNCTION notify_loop() RETURNS VOID AS "

This comment has been minimized.

@vlsi

vlsi Aug 7, 2017

Member

Should the procedure be removed from the database after the test?

This comment has been minimized.

@magJ

magJ Aug 8, 2017

Contributor

I have added function removal to the @After test section.

fix: Add support for concurrent read/clear of statement warnings
Ensure that warning reader threads are shut down in case of test failure
Remove tables and functions created during the tests.
@magJ

This comment has been minimized.

Contributor

magJ commented Aug 23, 2017

@vlsi Thanks for all your detailed feedback, I appreciate that there may be more important issues that command your attention, but I would rather not have this PR open for an extended period of time.
Could you please let me know what if anything I can do to have this change merged?

@davecramer

This comment has been minimized.

Member

davecramer commented Aug 23, 2017

@gregsh

This comment has been minimized.

gregsh commented Oct 17, 2017

Any news?

@vlsi vlsi added this to the 42.1.5 milestone Oct 20, 2017

@vlsi vlsi merged commit 83dd5fe into pgjdbc:master Oct 20, 2017

2 checks passed

codecov/project 65.8% (+0.17%) compared to 551d71b
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details

@vlsi vlsi modified the milestones: 42.1.5, 42.2.0 Jan 8, 2018

rhavermans added a commit to bolcom/pgjdbc that referenced this pull request Jul 13, 2018

fix: make warnings available as soon as they are received (pgjdbc#857)
Until REL9.4.1210 warnings were available via Statement#getWarnings()
and ResultSet#getWarnings() as soon as they were received from the
server. This commit returns to that behavior.
This is useful for long running queries, where it can be beneficial
to know about a warning before the query completes.

fixes pgjdbc#856

rhavermans added a commit to bolcom/pgjdbc that referenced this pull request Jul 13, 2018

fix: make warnings available as soon as they are received (pgjdbc#857)
Until REL9.4.1210 warnings were available via Statement#getWarnings()
and ResultSet#getWarnings() as soon as they were received from the
server. This commit returns to that behavior.
This is useful for long running queries, where it can be beneficial
to know about a warning before the query completes.

fixes pgjdbc#856
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment