Skip to content
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.

Sign up for GitHub

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

Jump to bottom

sql: JDBC not happy about results for DROP and CREATE #4538

Closed
knz opened this issue Feb 20, 2016 · 8 comments
Closed

sql: JDBC not happy about results for DROP and CREATE #4538

knz opened this issue Feb 20, 2016 · 8 comments
Assignees
@knz
Labels
C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior.

Comments

@knz
Copy link
Contributor

knz commented Feb 20, 2016

After applyting #4537, I run into the next error:

  actual: org.postgresql.util.PSQLException: A result was returned when none was expected.
 at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate (AbstractJdbc2Statement.java:417)
    clojure.java.jdbc$db_do_execute_prepared_statement$fn__7266.invoke (jdbc.clj:731)
    clojure.java.jdbc$db_transaction_STAR_.doInvoke (jdbc.clj:587)
    clojure.lang.RestFn.invoke (RestFn.java:425)
    clojure.java.jdbc$db_do_execute_prepared_statement.invoke (jdbc.clj:730)
    clojure.java.jdbc$db_do_prepared.doInvoke (jdbc.clj:764)
    clojure.lang.RestFn.invoke (RestFn.java:442)
    clojure.java.jdbc$execute_BANG_$execute_helper__7299.invoke (jdbc.clj:867)
    clojure.java.jdbc$execute_BANG_.doInvoke (jdbc.clj:869)
    clojure.lang.RestFn.invoke (RestFn.java:425)
    jepsen.cockroach$atomic_client$reify__7900.setup_BANG_ (cockroach.clj:281)
    jepsen.core$run_case_BANG_$fn__6884$fn__6885.invoke (core.clj:288)
    clojure.lang.AFn.applyToHelper (AFn.java:154)
    clojure.lang.AFn.applyTo (AFn.java:144)
    clojure.core$apply.invoke (core.clj:630)
    jepsen.core$fcatch$wrapper__6776.doInvoke (core.clj:55)
    clojure.lang.RestFn.invoke (RestFn.java:408)
    clojure.core$pmap$fn__6744$fn__6745.invoke (core.clj:6729)
    clojure.core$binding_conveyor_fn$fn__4444.invoke (core.clj:1916)
    clojure.lang.AFn.call (AFn.java:18)
    java.util.concurrent.FutureTask.run (FutureTask.java:266)
    java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1142)
    java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:617)
    java.lang.Thread.run (Thread.java:745)

This issue is occuring when JDBC sends "DROP TABLE IF NOT EXISTS TEST" to the db.

The network trace for the CockroachDB connection ( test.cdb.txt ) and a reference using PostgreSQL ( test.pg.txt ) are attached.
@knz knz closed this as completed Feb 20, 2016
@knz knz changed the title sql: JDBC not happy about results for DROP or ROLLBACK sql: JDBC not happy about results for DROP Feb 20, 2016
@knz knz reopened this Feb 20, 2016
@knz
Copy link
Contributor Author

knz commented Feb 20, 2016

After investigating the network traces, two observations:

  • CockroachDB splits an answer across many packets, whereas pg combines multiple into one
  • it is not so clear what the difference is on the DROP between CockroachDB and pg.

@knz
Copy link
Contributor Author

knz commented Feb 20, 2016

One more investigation. I changed the test to use CREATE instead of DROP, so as to avoid red herrings around pg's "Notice" message. Here is a compared network trace (left: pg; right: cdb). The difference starts here:

    Type: Parse                                                     Type: Parse
    Length: 13                                                      Length: 13
    Statement:                                                      Statement:
    Query: BEGIN                                                    Query: BEGIN
    Parameters: 0                                                   Parameters: 0
    Type: Bind                                                      Type: Bind
    Length: 12                                                      Length: 12
    Portal:                                                         Portal:
    Statement:                                                      Statement:
    Parameter formats: 0                                            Parameter formats: 0
    Parameter values: 0                                             Parameter values: 0
    Result formats: 0                                               Result formats: 0
    Type: Execute                                                   Type: Execute
    Length: 9                                                       Length: 9
    Portal:                                                         Portal:
    Returns: all rows                                               Returns: all rows
    Type: Parse                                                     Type: Parse
    Length: 49                                                      Length: 49
    Statement:                                                      Statement:
    Query: create table test (name varchar, val int)                Query: create table test (name varchar, val int)
    Parameters: 0                                                   Parameters: 0
    Type: Bind                                                      Type: Bind
    Length: 12                                                      Length: 12
    Portal:                                                         Portal:
    Statement:                                                      Statement:
    Parameter formats: 0                                            Parameter formats: 0
    Parameter values: 0                                             Parameter values: 0
    Result formats: 0                                               Result formats: 0
    Type: Describe                                                  Type: Describe
    Length: 6                                                       Length: 6
    Portal:                                                         Portal:
    Type: Execute                                                   Type: Execute
    Length: 9                                                       Length: 9
    Portal:                                                         Portal:
    Returns: all rows                                               Returns: all rows
    Type: Parse                                                     Type: Parse
    Length: 49                                                      Length: 49
    Statement:                                                      Statement:
    Query: create table test (name varchar, val int)                Query: create table test (name varchar, val int)
    Parameters: 0                                                   Parameters: 0
    Type: Bind                                                      Type: Bind
    Length: 12                                                      Length: 12
    Portal:                                                         Portal:
    Statement:                                                      Statement:
    Parameter formats: 0                                            Parameter formats: 0
    Parameter values: 0                                             Parameter values: 0
    Result formats: 0                                               Result formats: 0
    Type: Describe                                                  Type: Describe
    Length: 6                                                       Length: 6
    Portal:                                                         Portal:
    Type: Execute                                                   Type: Execute
    Length: 9                                                       Length: 9
    Portal:                                                         Portal:
    Returns: 1 rows                                                 Returns: 1 rows
    Type: Sync                                                      Type: Sync
    Length: 4                                                       Length: 4

     40 1.497256       127.0.0.1             127.0.0.1        |      64 1.488846       172.31.53.252         172.31.50.219

     40 1.497256       127.0.0.1             127.0.0.1        |      64 1.488846       172.31.53.252         172.31.50.219

    Type: Parse completion                                          Type: Parse completion
    Length: 4                                                       Length: 4
                                                              >
                                                              >      65 1.488906       172.31.53.252         172.31.50.219
                                                              >
    Type: Bind completion                                           Type: Bind completion
    Length: 4                                                       Length: 4
                                                              >
                                                              >      66 1.488910       172.31.53.252         172.31.50.219
                                                              >
    Type: Command completion                                        Type: Command completion
    Length: 10                                                      Length: 10
    Tag: BEGIN                                                      Tag: BEGIN
                                                              >
                                                              >      67 1.488925       172.31.50.219         172.31.53.252
                                                              >
                                                              >
                                                              >      68 1.488957       172.31.53.252         172.31.50.219
                                                              >

    Type: Parse completion                                          Type: Parse completion
    Length: 4                                                       Length: 4
    Type: Bind completion                                           Type: Bind completion
    Length: 4                                                       Length: 4
    Type: No data                             <HERE>          |     Type: Row description
    Length: 4                                                 |     Length: 6
                                                              >     Field count: 0
                                                              >
                                                              >      69 1.493148       172.31.53.252         172.31.50.219
                                                              >
    Type: Command completion                                        Type: Command completion
    Length: 17                                                      Length: 17
    Tag: CREATE TABLE                                               Tag: CREATE TABLE
                                                              >
                                                              >      70 1.493161       172.31.50.219         172.31.53.252
                                                              >
                                                              >
                                                              >      71 1.493216       172.31.53.252         172.31.50.219
                                                              >
    Type: Ready for query                                           Type: Ready for query
    Length: 5                                                       Length: 5
    Status: In a transaction (84)                                   Status: In a transaction (84)

     41 1.497417       127.0.0.1             127.0.0.1        |      72 1.495541       172.31.50.219         172.31.53.252

    Type: Parse                                                     Type: Parse
    Length: 17                                                |     Length: 19
    Statement: S_1                                                  Statement: S_1
    Query: COMMIT                                             |     Query: ROLLBACK
    Parameters: 0                                                   Parameters: 0
    Type: Bind                                                      Type: Bind
    Length: 15                                                      Length: 15
    Portal:                                                         Portal:
    Statement: S_1                                                  Statement: S_1
    Parameter formats: 0                                            Parameter formats: 0
    Parameter values: 0                                             Parameter values: 0
    Result formats: 0                                               Result formats: 0
    Type: Execute                                                   Type: Execute
    Length: 9                                                       Length: 9
    Portal:                                                         Portal:
    Returns: 1 rows                                                 Returns: 1 rows
    Type: Sync                                                      Type: Sync
    Length: 4                                                       Length: 4

As can be seen here, the transaction is aborted when CREATE completes. Note how cockroach's CREATE returns rows, whereas pg's doesn't.

@knz knz changed the title sql: JDBC not happy about results for DROP sql: JDBC not happy about results for DROP and CREATE Feb 20, 2016
@andreimatei
Copy link
Contributor

This sounds to me like a beta bug (but then again many things sounds like beta bugs to me:)) particularly if this is triggered by some framework?
Feel free to assign to me if you're not looking into it, but please give some repro instructions and the wireshark or whatever commands you use to capture these traces.

@andreimatei
Copy link
Contributor

Looks like BEGIN also seems to return some rows in cockroach. Don't know
what's up with that.
How do you get that "the transaction is aborted when CREATE completes"? I
see "Status: In a transaction (84)" after the CREATE results.

On Sat, Feb 20, 2016 at 12:18 PM, kena notifications@github.com wrote:

One more investigation. I changed the test to use CREATE instead of DROP,
so as to avoid red herrings around pg's "Notice" message. Here is a
compared network trace (left: pg; right: cdb). The difference starts here:

Type: Parse                                                     Type: Parse
Length: 13                                                      Length: 13
Statement:                                                      Statement:
Query: BEGIN                                                    Query: BEGIN
Parameters: 0                                                   Parameters: 0
Type: Bind                                                      Type: Bind
Length: 12                                                      Length: 12
Portal:                                                         Portal:
Statement:                                                      Statement:
Parameter formats: 0                                            Parameter formats: 0
Parameter values: 0                                             Parameter values: 0
Result formats: 0                                               Result formats: 0
Type: Execute                                                   Type: Execute
Length: 9                                                       Length: 9
Portal:                                                         Portal:
Returns: all rows                                               Returns: all rows
Type: Parse                                                     Type: Parse
Length: 49                                                      Length: 49
Statement:                                                      Statement:
Query: create table test (name varchar, val int)                Query: create table test (name varchar, val int)
Parameters: 0                                                   Parameters: 0
Type: Bind                                                      Type: Bind
Length: 12                                                      Length: 12
Portal:                                                         Portal:
Statement:                                                      Statement:
Parameter formats: 0                                            Parameter formats: 0
Parameter values: 0                                             Parameter values: 0
Result formats: 0                                               Result formats: 0
Type: Describe                                                  Type: Describe
Length: 6                                                       Length: 6
Portal:                                                         Portal:
Type: Execute                                                   Type: Execute
Length: 9                                                       Length: 9
Portal:                                                         Portal:
Returns: all rows                                               Returns: all rows
Type: Parse                                                     Type: Parse
Length: 49                                                      Length: 49
Statement:                                                      Statement:
Query: create table test (name varchar, val int)                Query: create table test (name varchar, val int)
Parameters: 0                                                   Parameters: 0
Type: Bind                                                      Type: Bind
Length: 12                                                      Length: 12
Portal:                                                         Portal:
Statement:                                                      Statement:
Parameter formats: 0                                            Parameter formats: 0
Parameter values: 0                                             Parameter values: 0
Result formats: 0                                               Result formats: 0
Type: Describe                                                  Type: Describe
Length: 6                                                       Length: 6
Portal:                                                         Portal:
Type: Execute                                                   Type: Execute
Length: 9                                                       Length: 9
Portal:                                                         Portal:
Returns: 1 rows                                                 Returns: 1 rows
Type: Sync                                                      Type: Sync
Length: 4                                                       Length: 4

 40 1.497256       127.0.0.1             127.0.0.1        |      64 1.488846       172.31.53.252         172.31.50.219

 40 1.497256       127.0.0.1             127.0.0.1        |      64 1.488846       172.31.53.252         172.31.50.219

Type: Parse completion                                          Type: Parse completion
Length: 4                                                       Length: 4
                                                          >
                                                          >      65 1.488906       172.31.53.252         172.31.50.219
                                                          >
Type: Bind completion                                           Type: Bind completion
Length: 4                                                       Length: 4
                                                          >
                                                          >      66 1.488910       172.31.53.252         172.31.50.219
                                                          >
Type: Command completion                                        Type: Command completion
Length: 10                                                      Length: 10
Tag: BEGIN                                                      Tag: BEGIN
                                                          >
                                                          >      67 1.488925       172.31.50.219         172.31.53.252
                                                          >
                                                          >
                                                          >      68 1.488957       172.31.53.252         172.31.50.219
                                                          >

Type: Parse completion                                          Type: Parse completion
Length: 4                                                       Length: 4
Type: Bind completion                                           Type: Bind completion
Length: 4                                                       Length: 4
Type: No data                             <HERE>          |     Type: Row description
Length: 4                                                 |     Length: 6
                                                          >     Field count: 0
                                                          >
                                                          >      69 1.493148       172.31.53.252         172.31.50.219
                                                          >
Type: Command completion                                        Type: Command completion
Length: 17                                                      Length: 17
Tag: CREATE TABLE                                               Tag: CREATE TABLE
                                                          >
                                                          >      70 1.493161       172.31.50.219         172.31.53.252
                                                          >
                                                          >
                                                          >      71 1.493216       172.31.53.252         172.31.50.219
                                                          >
Type: Ready for query                                           Type: Ready for query
Length: 5                                                       Length: 5
Status: In a transaction (84)                                   Status: In a transaction (84)

 41 1.497417       127.0.0.1             127.0.0.1        |      72 1.495541       172.31.50.219         172.31.53.252

Type: Parse                                                     Type: Parse
Length: 17                                                |     Length: 19
Statement: S_1                                                  Statement: S_1
Query: COMMIT                                             |     Query: ROLLBACK
Parameters: 0                                                   Parameters: 0
Type: Bind                                                      Type: Bind
Length: 15                                                      Length: 15
Portal:                                                         Portal:
Statement: S_1                                                  Statement: S_1
Parameter formats: 0                                            Parameter formats: 0
Parameter values: 0                                             Parameter values: 0
Result formats: 0                                               Result formats: 0
Type: Execute                                                   Type: Execute
Length: 9                                                       Length: 9
Portal:                                                         Portal:
Returns: 1 rows                                                 Returns: 1 rows
Type: Sync                                                      Type: Sync
Length: 4                                                       Length: 4

As can be seen here, the transaction is aborted when CREATE completes.
Note how cockroach's CREATE returns rows, whereas pg's doesn't.

—
Reply to this email directly or view it on GitHub
#4538 (comment)
.

@knz
Copy link
Contributor Author

knz commented Feb 20, 2016

I meant the client aborts the transaction (with a rollback) because it's not happy with the results of create. See the exception message in the initial issue description.

Sent from my Android device with K-9 Mail. Please excuse my brevity.

@knz
Copy link
Contributor Author

knz commented Feb 21, 2016

To reproduce:

  1. install Oracle JDK 8 and leiningen ( http://leiningen.org/ )
  2. run a cockroach instance insecure
  3. create a database called jepsen in there
  4. clone https://github.com/knz/jepsen
  5. take a cursory look at the configuration variables at the beginning of jepsen/cockroachdb/src/jepsen/cockroach.clj. Notice how jdbc-mode can switch between pg and cockroach. Ensure is set to :cdb-local.
  6. run: lein test :only jepsen.cockroach-test/atomic-test from the jepsen/cockroachdb subdir.

This should output:

lein test jepsen.cockroach-test
INFO  jepsen.os.ubuntu - :n1l setting up ubuntu
INFO  jepsen.cockroach - :n1l Testing JDBC connection...
INFO  jepsen.cockroach - :n1l Setup complete

INFO  jepsen.core - Tearing down nemesis
INFO  jepsen.core - Nemesis torn down

lein test :only jepsen.cockroach-test/atomic-test

ERROR in (atomic-test) (AbstractJdbc2Statement.java:417)
expected: (:valid? (:results (jepsen/run! (cl/atomic-test nodes))))
  actual: org.postgresql.util.PSQLException: A result was returned when none was expected.
 at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate (AbstractJdbc2Statement.java:417)
    clojure.java.jdbc$db_do_execute_prepared_statement$fn__7266.invoke (jdbc.clj:731)
[... rest of backtrace ...]

@knz
Copy link
Contributor Author

knz commented Feb 21, 2016

From there if you are using the local instance you can run tcpdump -w trace.pcap -i lo0 port 15432 during the test to capture the packet log. Then tshark -r trace.pcap -d tcp.port=15432,pgsql -O pgsql to parse the trace and extract the protocol details.

@knz knz added C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior. help wanted Help is requested / needed by the one who filed the issue to fix it. labels Feb 21, 2016
@knz knz self-assigned this Feb 22, 2016
@knz knz removed the help wanted Help is requested / needed by the one who filed the issue to fix it. label Feb 22, 2016
This was referenced Feb 22, 2016
Merged
Closed
Closed
Closed
@knz knz closed this as completed in #4548 Feb 23, 2016
@knz
Copy link
Contributor Author

knz commented Feb 25, 2016

While looking at #4036

@knz knz mentioned this issue Feb 23, 2017
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@knz knz

Labels
C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@andreimatei @knz