pgwire panics when opening a connection from jdbc.postgresql #3819

knz · 2016-01-13T23:32:16Z

So I am trying to get clojure (for jepsen, see #4036 ) to talk to cockroach via jdbc and --insecure.
For this I use the standard Java org.postgresql JDBC driver (provided by postgres) version 9.4-1204-jdbc42 and clojure/java.jdbc 0.4.1 (JDK 8)

My JDBC object is instantiated with the following config:

(fn conn-spec [_]
                            {:classname   "org.postgresql.Driver"
                             :subprotocol "postgresql"
                             :subname     (str "//n1:15432/system")
                             :user        "psql"
                             :password    "dummy"})

Upon starting the client, the (Java) client fails with:

WARN  jepsen.cockroach - Lost connection {:classname org.postgresql.Driver, :subprotocol postgresql, :subname //n1:15432/system, :user psql, :password dummy, :connection #object[org.postgresql
.jdbc42.Jdbc42Connection 0x28ba4cca org.postgresql.jdbc42.Jdbc42Connection@28ba4cca]} , reconnecting

(then the client gives up)
After this happens, I observe the cockroach server has died with the following trace:

I0113 23:16:18.354134 17749 server/node.go:389  connecting to gossip network to verify cluster ID...
I0113 23:16:18.354150 17749 server/node.go:406  node connected via gossip and verified as part of cluster "ddd32b9f-4d8e-42c9-b087-2ce276a97cc7"
I0113 23:16:18.354224 17749 server/node.go:258  Started node with [[ssd]=data] engine(s) and attributes []
I0113 23:16:18.354417 17749 server/server.go:262  starting http server at ip-172-31-63-242:26257
I0113 23:16:18.354528 17749 sql/pgwire/server.go:76  starting postgres server at [::]:15432
W0113 23:16:20.355864 17749 storage/store.go:639  error gossiping system config: range 0: replica <nil> not leader; leader is <nil>
I0113 23:16:28.355472 17749 server/status/runtime.go:137  runtime stats: 60 goroutines, 3.94MiB active, 0.00cgo/sec, 0.00/0.00 %(u/s)time, 0.00 %gc (0x)
W0113 23:16:31.376006 17749 sql/pgwire/v3.go:147  unrecognized configuration parameter "client_encoding"
W0113 23:16:31.376175 17749 sql/pgwire/v3.go:147  unrecognized configuration parameter "DateStyle"
W0113 23:16:31.376311 17749 sql/pgwire/v3.go:147  unrecognized configuration parameter "TimeZone"
W0113 23:16:31.376328 17749 sql/pgwire/v3.go:147  unrecognized configuration parameter "extra_float_digits"
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x9c pc=0xb69cfc]

goroutine 127 [running]:
github.com/cockroachdb/cockroach/sql.(*planner).Show(0xc820480500, 0xc8204cd340, 0x0, 0x0, 0x2)
        /go/src/github.com/cockroachdb/cockroach/sql/show.go:47 +0xb9c
github.com/cockroachdb/cockroach/sql.(*planner).makePlan(0xc820480500, 0x7f93d550d978, 0xc8204cd340, 0x0, 0x0, 0x0, 0x0)
        /go/src/github.com/cockroachdb/cockroach/sql/plan.go:130 +0x63e
github.com/cockroachdb/cockroach/sql.(*Executor).StatementResult(0xc8201d0210, 0xc82034f009, 0x4, 0x7f93d550d978, 0xc8204cd340, 0xc8204e65a0, 0x0, 0x0, 0x0, 0x0)
        /go/src/github.com/cockroachdb/cockroach/sql/executor.go:152 +0x275
github.com/cockroachdb/cockroach/sql/pgwire.(*v3Conn).handleParse(0xc82005c000, 0xc82005c038, 0x0, 0x0)
        /go/src/github.com/cockroachdb/cockroach/sql/pgwire/v3.go:321 +0xc31
github.com/cockroachdb/cockroach/sql/pgwire.(*v3Conn).serve(0xc82005c000, 0x0, 0x0, 0x0)
        /go/src/github.com/cockroachdb/cockroach/sql/pgwire/v3.go:223 +0xb62
github.com/cockroachdb/cockroach/sql/pgwire.(*Server).serveConn(0xc8201c3110, 0x7f93d550b228, 0xc8200f41b8, 0x0, 0x0)
        /go/src/github.com/cockroachdb/cockroach/sql/pgwire/server.go:199 +0x9b5
github.com/cockroachdb/cockroach/sql/pgwire.(*Server).serve.func1(0xc8201c3110, 0x7f93d550b228, 0xc8200f41b8)
        /go/src/github.com/cockroachdb/cockroach/sql/pgwire/server.go:108 +0x90
created by github.com/cockroachdb/cockroach/sql/pgwire.(*Server).serve
        /go/src/github.com/cockroachdb/cockroach/sql/pgwire/server.go:113 +0x20a

Not sure where to go from here. Is there a way to ask the server to emit the sql queries into its log / stderr?

The text was updated successfully, but these errors were encountered:

andreimatei · 2016-01-13T23:37:10Z

I don't know what kind of sql logging we might have already, but a lot of our objects implement fmt.Stringer, so you could, for example, print the parser.Show node to see what statement it's trying to execute.

bdarnell · 2016-01-13T23:37:12Z

A full dump of the network traffic is helpful for things like this: sudo tshark -i eth0 -f "tcp port 15432" -O pgsql (tshark is the command-line version of wireshark. replace eth0 with the appropriate network interface)

bdarnell · 2016-01-13T23:44:57Z

Also from that line number, my guess is that it's trying to query the default transaction isolation level outside a transaction.

knz · 2016-01-14T00:07:18Z

So see the attachment net.txt
for the decoded network trace.

Indeed there is a "show transaction isolation level" as first statement and that causes the server to terminate the TCP connection.

On the other hand I confirm I can also enter this statement (and get a valid answer) from cockroach sql outside of a transaction. What makes the jdbc-created connection different?

petermattis · 2016-01-14T02:21:03Z

The cockroach sql shell is still using the non-pgwire protocol which might be the difference. See #3511. Or it could be something else.

The panic is very strange. Every SQL statement is executed within a transaction. If not an user specified transaction, then an automatically created/committed one.

@mjibson: Can you take a look at this?

mberhault · 2016-01-14T03:34:28Z

This may be related to the server-side crashes I'm encountering when using libpq in cockroach sql (#3757)
I thought it might have been due to the fact that I'm using sql.Query for everything (it's definitely causing client issues, but it may be something else.

knz · 2016-01-14T09:46:59Z

How to reproduce (perhaps an idea to integrate in the test suite):

install jdk 8
install recent leiningen (clojure build system + dependency manager; no need to install clojure itself before this point because leiningen will take care of this automatically):
```
curl -O https://raw.githubusercontent.com/technomancy/leiningen/stable/bin/lein
chmod +x lein
```
create a simple leiningen project: lein new jdbc-test

add the following extra dependencies to jdbc-test/project.clj:

             [org.clojure/java.jdbc "0.4.1"]
             [org.postgresql/postgresql "9.4-1204-jdbc42"]

populate(replace) jdbc-test/test/jdbc_test/core_test.clj with the following, replacing //n1:15432 by your server address in the connection string (subname):

(ns jdbc-test.core-test
(:require [clojure.test :refer :all]
          [jdbc-test.core :refer :all]
          [clojure.java.jdbc :as j]
))


(deftest a-test
(testing "FIXME, I fail."
         (let [spec {:classname   "org.postgresql.Driver"
                           :subprotocol "postgresql"
                           :subname     (str "//n1:15432/system")
                           :user        "psql"
                           :password    "dummy"}]
         (let [conn (j/add-connection spec (j/get-connection spec))]
              (j/with-db-transaction [c conn :isolation :serializable]
                  (j/execute! c ["create table if not exists test (x int)"])
              )
         ))
))

start the cockroach server insecure, or modify the user/password combination in the clojure test according to your auth data
cd jdbc-test; lein test

This should fail with org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend.

Then you should observe the cockroach server has died (running lein test again at this point reports the connection is refused).

mberhault · 2016-01-14T17:06:06Z

my failure is in the same place. I'm issuing a INSERT, but it fails within handleParse on a nil txn.

Last few log lines and trace:

W0114 12:01:48.771447 31624 sql/pgwire/v3.go:147  unrecognized configuration parameter "extra_float_digits"
W0114 12:01:48.771475 31624 sql/pgwire/v3.go:147  unrecognized configuration parameter "client_encoding"
W0114 12:01:48.771485 31624 sql/pgwire/v3.go:147  unrecognized configuration parameter "datestyle"
I0114 12:01:48.771556 31624 sql/pgwire/v3.go:182  pgwire: serverMsgReady: 'I'
I0114 12:01:48.771658 31624 sql/pgwire/v3.go:207  pgwire: processing clientMsgParse
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x0 pc=0xa17cbe]

goroutine 228 [running]:
github.com/cockroachdb/cockroach/client.(*Txn).Get(0x0, 0x1498540, 0xc82068d960, 0x0, 0x0, 0x0, 0x0, 0xc800000000)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/client/txn.go:161 +0x1ce
github.com/cockroachdb/cockroach/sql.(*planner).getDescriptor(0xc820214a00, 0x7fad25bf2778, 0xc820667120, 0x7fad25bee5c0, 0xc82068d940, 0x7fad25bf2778)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/descriptor.go:129 +0xb5
github.com/cockroachdb/cockroach/sql.(*planner).getDatabaseDesc(0xc820214a00, 0xc82071700d, 0x6, 0x0, 0x0)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/database.go:48 +0x102
github.com/cockroachdb/cockroach/sql.(*planner).getTableDesc(0xc820214a00, 0xc8205fa510, 0x152e0c0, 0x6)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/table.go:184 +0xe5
github.com/cockroachdb/cockroach/sql.(*planner).getTableLease(0xc820214a00, 0xc8205fa510, 0x5f65646f6e227b5b, 0x73222c313a226469)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/table.go:223 +0x127
github.com/cockroachdb/cockroach/sql.(*planner).Insert(0xc820214a00, 0xc8205fa540, 0xe984f100, 0x0, 0x0, 0x3)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/insert.go:37 +0x9b
github.com/cockroachdb/cockroach/sql.(*planner).makePlan(0xc820214a00, 0x7fad25bf23e8, 0xc8205fa540, 0x0, 0x0, 0x0, 0x77575535582f6632)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/plan.go:106 +0x1151
github.com/cockroachdb/cockroach/sql.(*Executor).StatementResult(0xc8202d0f20, 0xc8205a202e, 0x4, 0x7fad25bf23e8, 0xc8205fa540, 0xc8205fa5a0, 0x0, 0x0, 0x0, 0x0)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/executor.go:152 +0x275
github.com/cockroachdb/cockroach/sql/pgwire.(*v3Conn).handleParse(0xc8205c64e0, 0xc8205c6518, 0x0, 0x0)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/pgwire/v3.go:321 +0xc31
github.com/cockroachdb/cockroach/sql/pgwire.(*v3Conn).serve(0xc8205c64e0, 0x0, 0x0, 0x0)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/pgwire/v3.go:223 +0xb62
github.com/cockroachdb/cockroach/sql/pgwire.(*Server).serveConn(0xc8202be750, 0x7fad25bf21a0, 0xc8204e8138, 0x0, 0x0)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/pgwire/server.go:199 +0x9b5
github.com/cockroachdb/cockroach/sql/pgwire.(*Server).serve.func1(0xc8202be750, 0x7fad25bf21a0, 0xc8204e8138)
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/pgwire/server.go:108 +0x90
created by github.com/cockroachdb/cockroach/sql/pgwire.(*Server).serve
    /home/marc/cockroach/src/github.com/cockroachdb/cockroach/sql/pgwire/server.go:113 +0x20a

Specifically, it's going into handleParse which calls executor.StatementResult. However, StatementResult does not create a transaction, executor.ExecuteStatements does.

mberhault · 2016-01-14T18:28:47Z

to clarify: my INSERT used placeholders:

db.Exec(`INSERT INTO system.users VALUES ($1, $2)`, args[0], hashed)

On the wire, this turned into (wireshark postgres decoder):

PostgreSQL:
  Type: Parse
  Length: 48
  Statement:
  Query: INSERT INTO system.users VALUES ($1, $2)
  Parameters: 0
PostgreSQL:
  Type: Describe
  Length: 6
  Statement: 
PostgreSQL:
  Type: Sync
  Length: 4

I'm guessing the next packet was going to be the execute with actual args, but the server crashed first.

knz added the SQL label Jan 13, 2016

andreimatei added this to the Beta milestone Jan 13, 2016

maddyblue self-assigned this Jan 14, 2016

bdarnell mentioned this issue Jan 14, 2016

sql: support placeholders in logictest #3854

Closed

tamird mentioned this issue Jan 14, 2016

sql/pgwire: tidy up tests for Exec with placeholders #3856

Merged

nvanbenschoten mentioned this issue Jan 16, 2016

sql: remove remaining uses of cockroach/sql/driver #3511

Closed

maddyblue mentioned this issue Jan 25, 2016

sql: support prepare INSERT statements #3958

Closed

This was referenced Jan 26, 2016

Support sql prepare for show statements #3972

Closed

sql/pgwire: missing support for row count limits in pgwire #4035

Closed

maddyblue mentioned this issue Jan 29, 2016

sql: prepare support for INSERT, UPDATE, DELETE #4037

Merged

maddyblue closed this as completed in #4037 Jan 30, 2016

knz mentioned this issue Feb 19, 2016

sql: JDBC wants "set session parameters as ..." #4524

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

pgwire panics when opening a connection from jdbc.postgresql #3819

pgwire panics when opening a connection from jdbc.postgresql #3819

knz commented Jan 13, 2016

andreimatei commented Jan 13, 2016

bdarnell commented Jan 13, 2016

bdarnell commented Jan 13, 2016

knz commented Jan 14, 2016

petermattis commented Jan 14, 2016

mberhault commented Jan 14, 2016

knz commented Jan 14, 2016

mberhault commented Jan 14, 2016

mberhault commented Jan 14, 2016

pgwire panics when opening a connection from jdbc.postgresql #3819

pgwire panics when opening a connection from jdbc.postgresql #3819

Comments

knz commented Jan 13, 2016

andreimatei commented Jan 13, 2016

bdarnell commented Jan 13, 2016

bdarnell commented Jan 13, 2016

knz commented Jan 14, 2016

petermattis commented Jan 14, 2016

mberhault commented Jan 14, 2016

knz commented Jan 14, 2016

mberhault commented Jan 14, 2016

mberhault commented Jan 14, 2016