Re: BUG #15240: JDBC driver sometimes hangs on copy out; suspect Json

From: Flo Rance <trourance(at)gmail(dot)com>
To: bwbecker(at)uwaterloo(dot)ca, pgsql-bugs(at)lists(dot)postgresql(dot)org
Subject: Re: BUG #15240: JDBC driver sometimes hangs on copy out; suspect Json
Date: 2018-06-14 10:05:44
Message-ID: CAHogYcX+bVYZoc_Ah3=wthisH+tGeJp7HaOp6LWTkJPJ0LrmhA@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

There's a dedicated project for JDBC driver: https://github.com/pgjdbc/
pgjdbc

You may try to report the issue there.

Flo

On Tue, Jun 12, 2018 at 6:02 PM, PG Bug reporting form <
noreply(at)postgresql(dot)org> wrote:

> The following bug has been logged on the website:
>
> Bug reference: 15240
> Logged by: Byron Weber Becker
> Email address: bwbecker(at)uwaterloo(dot)ca
> PostgreSQL version: 10.3
> Operating system: Mac OS 10.13.5
> Description:
>
> I use the following Scala code to copy the results of a query to a stream
> for further processing.
>
> Class.forName(config.get[String]("db.default.driver"))
>
> val con = DriverManager.getConnection(
> config.get[String]("db.default.url"),
> config.get[String]("db.default.user"),
> config.get[String]("db.default.password")
> ).asInstanceOf[PGConnection]
>
> val cm: CopyManager = con.getCopyAPI
> logger.debug("executeCSV.30")
>
> val qryText = s"""COPY ($queryString) TO STDOUT (FORMAT CSV,
> HEADER)"""
> cm.copyOut(qryText, stream)
> logger.debug("executeCSV.40")
>
> This code has worked well hundreds of times but recently began failing for
> one particular query. The query is new and the only difference between it
> and others that I can see is that it uses JSON -->> notation. From both
> the
> debugging output and tracing in a debugger the program enters
> cm.copyOut(qryText, stream) but does not exit.
>
> Tracing with the debugger into copyOut:
>
> public long copyOut(final String sql, OutputStream to) throws
> SQLException, IOException {
> byte[] buf;
> CopyOut cp = copyOut(sql);
> try {
> while ((buf = cp.readFromCopy()) != null) {
> to.write(buf);
> }
> return cp.getHandledRowCount();
> } catch (IOException ioEX) {
> ....
>
> the program executes the while loop a number of times but will not stop at
> a
> breakpoint set on the return statement. I've not been able to get it to
> fail on a small enough sample that makes stepping through to see the ending
> behaviour practical. The call to copyOut is enclosed in a try-catch block
> but nothing is caught.
>
> I'm using version 42.2.2 of the database driver.
>
> The query in question is
>
> SELECT
> submitter_userid AS userid
> , uw_id
> , office_use_data ->> 'decision' AS decision
> , data ->> 'first_choice' AS first_choice
> , data ->> 'second_choice' AS second_choice
> , course_grade
> , class_id
> FROM _oat.form_data
> JOIN _quest.std_student AS ss ON (userid = submitter_userid)
> JOIN _quest.std_term_course USING (uw_id)
>
> WHERE form_id = 'mathInternalXfer'
>
> ****
> This is the only query I have that makes use of the json ->> notation.
> ****
>
> The table definitions are:
>
> CREATE TABLE IF NOT EXISTS form_data
> (
> form_id TEXT NOT NULL,
> version INTEGER NOT NULL,
> submitter_userid TEXT NOT NULL,
> seq INTEGER NOT NULL,
> state TEXT NOT NULL,
> data JSONB NOT NULL,
> office_use_data JSONB,
> date_added TIMESTAMP,
> ranking DOUBLE PRECISION,
> CONSTRAINT form_data_pkey
> PRIMARY KEY (form_id, version, submitter_userid, seq)
> );
>
> COMMENT ON TABLE form_data IS 'Data for a specified form, as provided by
> the
> submitter.';
>
> CREATE TABLE IF NOT EXISTS std_student
> (
> uw_id _quest.QUEST_UW_ID NOT NULL
> CONSTRAINT std_student_pkey
> PRIMARY KEY,
> gender_code TEXT NOT NULL
> CONSTRAINT std_student_gender_code_fkey
> REFERENCES uw_gender,
> birthdate DATE,
> deathdate DATE,
> userid _quest.QUEST_USERID,
> email TEXT,
> wlu_id TEXT,
> privacy_flag BOOLEAN NOT NULL,
> aboriginal_flag BOOLEAN,
> visible_minority_code TEXT
> CONSTRAINT std_student_visible_minority_code_fkey
> REFERENCES uw_visible_minority
> );
>
> CREATE TABLE IF NOT EXISTS std_term_course
> (
> uw_id _quest.QUEST_UW_ID NOT NULL,
> term_id _quest.QUEST_TERM_ID NOT NULL,
> class_id INTEGER NOT NULL,
> course_grade TEXT,
> earn_credit BOOLEAN NOT NULL,
> include_in_gpa BOOLEAN NOT NULL,
> requirement_designation TEXT,
> requirement_designation_grade TEXT,
> units_attempted_code _quest.QUEST_COMPLETION_CODE NOT NULL,
> grade_points NUMERIC(9, 3) NOT NULL,
> student_take_units NUMERIC(5, 2) NOT NULL,
> student_ap_units NUMERIC(5, 2) NOT NULL,
> grading_basis TEXT NOT NULL,
> valid_attempt BOOLEAN,
> grade_category TEXT,
> grade_submission_date DATE,
> transcript_note TEXT,
> CONSTRAINT std_term_course_pkey
> PRIMARY KEY (uw_id, term_id, class_id),
> CONSTRAINT std_term_course_uw_id_fkey
> FOREIGN KEY (uw_id, term_id) REFERENCES std_term,
> CONSTRAINT std_term_course_term_id_fkey
> FOREIGN KEY (term_id, class_id) REFERENCES off_course
> );
>
> CREATE INDEX IF NOT EXISTS std_term_course_term_id_class_id_idx
> ON std_term_course (term_id, class_id);
>
> The activity while the application is hung:
> t08_dev=# SELECT *
> FROM pg_stat_activity where pid = 8713;
> datid | datname | pid | usesysid | usename | application_name |
> client_addr | client_hostname | client_port | backend_start
> | xact_start | query_start | state_change
> | wait_event_type | wait_event | state | backend_xid | backend_xmin |
>
> query |
> backend_type
>
> -------+---------+------+----------+----------+-------------
> -----------+-------------+-----------------+-------------+--
> -----------------------------+------------+-----------------
> --------------+------------------------------+--------------
> ---+------------+-------+-------------+--------------+------
> ------------------------------------------------------------
> --+----------------
> 16404 | t08_dev | 8713 | 10 | bwbecker | PostgreSQL JDBC Driver |
> 127.0.0.1 | | 58184 | 2018-06-12 11:34:21.641199-04
> | | 2018-06-12 11:34:21.646087-04 | 2018-06-12 11:34:21.64978-04
> | Client | ClientRead | idle | | | COPY
> (SELECT\r +| client
> backend
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | |
> submitter_userid AS userid\r +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | ,
> uw_id\r +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | ,
> office_use_data ->> 'decision' AS decision\r +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | , data
> ->> 'first_choice' AS first_choice\r +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | , data
> ->> 'second_choice' AS second_choice\r +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | ,
> course_grade\r +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | ,
> class_id\r +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | FROM
> _oat.form_data\r +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | JOIN
> _quest.std_student AS ss ON (userid = submitter_userid)\r+|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | JOIN
> _quest.std_term_course USING (uw_id)\r +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | \r
>
> +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | WHERE
> form_id = 'mathInternalXfer'\r +|
> | | | | | |
>
> | | | |
>
> | | |
>
> | | | | | ) TO STDOUT
> (FORMAT CSV, HEADER) |
> (1 row)
>
>
> The query output is
> \i 1203_mathXfer.sql
> userid,uw_id,decision,first_choice,second_choice,course_grade,class_id
> meconway,104,,pmath,pmath,57,4590
> meconway,104,,pmath,pmath,66,4598
> meconway,104,,pmath,pmath,45,5053
> meconway,104,,pmath,pmath,70,5335
> meconway,104,,pmath,pmath,67,5506
> meconway,104,,pmath,pmath,81,6548
> meconway,104,,pmath,pmath,50,4612
> meconway,104,,pmath,pmath,66,4619
> meconway,104,,pmath,pmath,57,5283
> meconway,104,,pmath,pmath,41,5393
> meconway,104,,pmath,pmath,68,5401
> meconway,104,,pmath,pmath,,6447
> meconway,104,,pmath,pmath,CR,4119
> meconway,104,,pmath,pmath,CR,4357
> meconway,104,,pmath,pmath,51,4761
> meconway,104,,pmath,pmath,50,4768
> meconway,104,,pmath,pmath,52,5486
> meconway,104,,pmath,pmath,60,5580
> meconway,104,,pmath,pmath,60,5588
> meconway,104,,pmath,pmath,,6663
> meconway,104,,pmath,pmath,CR,4092
> meconway,104,,pmath,pmath,CR,4180
> meconway,104,,pmath,pmath,68,3417
> meconway,104,,pmath,pmath,50,5385
> meconway,104,,pmath,pmath,69,5627
> meconway,104,,pmath,pmath,44,5746
> meconway,104,,pmath,pmath,50,5998
> meconway,104,,pmath,pmath,CR,6941
> meconway,104,,pmath,pmath,CR,7152
> meconway,104,,pmath,pmath,62,2124
> meconway,104,,pmath,pmath,62,3528
> meconway,104,,pmath,pmath,56,3731
> meconway,104,,pmath,pmath,77,4459
> meconway,104,,pmath,pmath,50,4525
> meconway,104,,pmath,pmath,WD,5708
> meconway,104,,pmath,pmath,66,6205
> meconway,104,,pmath,pmath,53,6242
> meconway,104,,pmath,pmath,85,7335
> meconway,104,,pmath,pmath,66,7703
> meconway,104,,pmath,pmath,35,5792
> meconway,104,,pmath,pmath,30,5830
> meconway,104,,pmath,pmath,WD,6189
> tmjvasig,20000001,,amath,pmath,72,2343
> tmjvasig,20000001,,amath,pmath,87,2425
> tmjvasig,20000001,,amath,pmath,77,2553
> tmjvasig,20000001,,amath,pmath,,2559
> tmjvasig,20000001,,amath,pmath,80,3137
> tmjvasig,20000001,,amath,pmath,71,3161
> tmjvasig,20000001,,amath,pmath,63,4010
> tmjvasig,20000001,,amath,pmath,NCR,2811
> tmjvasig,20000001,,amath,pmath,CR,4397
> tmjvasig,20000001,,amath,pmath,88,1442
> tmjvasig,20000001,,amath,pmath,94,2197
> tmjvasig,20000001,,amath,pmath,84,2226
> tmjvasig,20000001,,amath,pmath,80,2234
> tmjvasig,20000001,,amath,pmath,62,2694
> tmjvasig,20000001,,amath,pmath,CR,4484
> tmjvasig,20000001,,amath,pmath,92,1454
> tmjvasig,20000001,,amath,pmath,83,1757
> tmjvasig,20000001,,amath,pmath,82,3336
> tmjvasig,20000001,,amath,pmath,92,3366
> tmjvasig,20000001,,amath,pmath,92,3375
> tmjvasig,20000001,,amath,pmath,84,5123
> tmjvasig,20000001,,amath,pmath,CR,2735
> tmjvasig,20000001,,amath,pmath,67,2920
> tmjvasig,20000001,,amath,pmath,83,1451
> tmjvasig,20000001,,amath,pmath,90,3431
> tmjvasig,20000001,,amath,pmath,92,3435
> tmjvasig,20000001,,amath,pmath,67,3545
> tmjvasig,20000001,,amath,pmath,90,3665
> tmjvasig,20000001,,amath,pmath,83,5204
> tmjvasig,20000001,,amath,pmath,74,1801
> tmjvasig,20000001,,amath,pmath,80,2566
> tmjvasig,20000001,,amath,pmath,69,2589
> tmjvasig,20000001,,amath,pmath,74,2594
> tmjvasig,20000001,,amath,pmath,82,2744
> tmjvasig,20000001,,amath,pmath,CR,5062
> tmjvasig,20000001,,amath,pmath,74,6858
> tmjvasig,20000001,,amath,pmath,88,2138
> tmjvasig,20000001,,amath,pmath,80,2444
> tmjvasig,20000001,,amath,pmath,86,2854
> tmjvasig,20000001,,amath,pmath,80,4301
> tmjvasig,20000001,,amath,pmath,79,7480
> tmjvasig,20000001,,amath,pmath,96,7874
> tmjvasig,20000001,,amath,pmath,CR,3794
> tmjvasig,20000001,,amath,pmath,76,2514
> tmjvasig,20000001,,amath,pmath,79,2515
> tmjvasig,20000001,,amath,pmath,86,3216
> tmjvasig,20000001,,amath,pmath,85,3496
> tmjvasig,20000001,,amath,pmath,92,4898
> tmjvasig,20000001,,amath,pmath,87,7385
> t08_dev=#
>
> I've tried reducing the number of rows of data output by adding "WHERE
> class_id between 1 and 4500". That continues to hang. But "between 1
> and
> 2501" and "between 2500 and 4500" both return the expected results without
> hanging.
>
> I'd very much appreciate pointers next steps.
>
> Thanks,
> Byron
>
>

In response to

Browse pgsql-bugs by date

  From Date Subject
Next Message Matkar, Prasad L (BHGE) 2018-06-14 14:16:48 BUG #15235: Getting failure message "Restore archive operation failed" while restoring database
Previous Message hemin 2018-06-14 09:30:20 When pg_rewind success, the database can't startup