Does jdbc keep a long connection with postgres ?

[farewall]

My web application uses jdbc to connect to the database. When I first query the database with a read-only transaction, will subsequent updates be affected by previous read-only transactions?

[davecramer]

As long as the query does not take a lock you should be fine.

[farewall]

Thank you for your answer, Dave. Sometimes, my app fails when it is running: cannot execute UPDATE in a read-only transaction. But I don't use transactions in the relevant code block, which makes me feel very confused. So I tried to get a detailed log of the transaction from postgres:

<2023-08-29 18:34:34.955 CST> <20912> <0> <4/0> <00000>DEBUG:  StartTransactionCommand
<2023-08-29 18:34:34.955 CST> <20912> <0> <4/152554> <00000>DEBUG:  StartTransaction
<2023-08-29 18:34:34.955 CST> <20912> <0> <4/152554> <00000>DEBUG:  name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 
<2023-08-29 18:34:34.955 CST> <20912> <0> <4/152554> <00000>LOG:  execute S_11: BEGIN READ ONLY
<2023-08-29 18:34:34.955 CST> <20912> <0> <4/152554> <00000>DEBUG:  ProcessUtility
<2023-08-29 18:34:34.955 CST> <20912> <0> <4/152554> <00000>DEBUG:  CommitTransactionCommand
<2023-08-29 18:34:34.955 CST> <20912> <0> <4/152554> <00000>DEBUG:  parse <unnamed>: select current_schema()
<2023-08-29 18:34:34.955 CST> <20912> <0> <4/152554> <00000>DEBUG:  StartTransactionCommand
<2023-08-29 18:34:34.955 CST> <20912> <0> <4/152554> <00000>DEBUG:  bind <unnamed> to <unnamed>
<2023-08-29 18:34:34.955 CST> <20912> <0> <4/152554> <00000>LOG:  execute <unnamed>: select current_schema()
<2023-08-29 18:34:34.955 CST> <20912> <0> <4/152554> <00000>DEBUG:  CommitTransactionCommand
<2023-08-29 18:34:34.956 CST> <20912> <0> <4/152554> <00000>DEBUG:  bind <unnamed> to S_2
<2023-08-29 18:34:34.956 CST> <20912> <0> <4/152554> <00000>DEBUG:  StartTransactionCommand
<2023-08-29 18:34:34.956 CST> <20912> <0> <4/152554> <00000>LOG:  execute S_2: SELECT 1
<2023-08-29 18:34:34.956 CST> <20912> <0> <4/152554> <00000>DEBUG:  CommitTransactionCommand
<2023-08-29 18:34:34.956 CST> <20912> <0> <4/152554> <00000>DEBUG:  parse S_13: select accountdia0_.id as id1_18_0_, accountdia0_.acc_names as acc_name2_18_0_, accountdia0_.dev_id as dev_id3_18_0_, accountdia0_.dial_request_id as dial_req9_18_0_, accountdia0_.end_time as end_time4_18_0_, accountdia0_.extra as extra5_18_0_, accountdia0_.reason as reason6_18_0_, accountdia0_.start_time as start_ti7_18_0_, accountdia0_.status as status8_18_0_ from tbl_account_dial_request_detail accountdia0_ where accountdia0_.id=$1
<2023-08-29 18:34:34.956 CST> <20912> <0> <4/152554> <00000>DEBUG:  StartTransactionCommand
<2023-08-29 18:34:34.956 CST> <20912> <0> <4/152554> <00000>DEBUG:  bind <unnamed> to S_13
<2023-08-29 18:34:34.956 CST> <20912> <0> <4/152554> <00000>LOG:  execute S_13: select accountdia0_.id as id1_18_0_, accountdia0_.acc_names as acc_name2_18_0_, accountdia0_.dev_id as dev_id3_18_0_, accountdia0_.dial_request_id as dial_req9_18_0_, accountdia0_.end_time as end_time4_18_0_, accountdia0_.extra as extra5_18_0_, accountdia0_.reason as reason6_18_0_, accountdia0_.start_time as start_ti7_18_0_, accountdia0_.status as status8_18_0_ from tbl_account_dial_request_detail accountdia0_ where accountdia0_.id=$1
<2023-08-29 18:34:34.956 CST> <20912> <0> <4/152554> <00000>DETAIL:  parameters: $1 = '2356498'
<2023-08-29 18:34:34.956 CST> <20912> <0> <4/152554> <00000>DEBUG:  CommitTransactionCommand
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>DEBUG:  parse S_14: select accountdia0_.id as id1_17_0_, accountdia0_.end_time as end_time2_17_0_, accountdia0_.executor as executor3_17_0_, accountdia0_.extra as extra4_17_0_, accountdia0_.log_id as log_id5_17_0_, accountdia0_.plan_id as plan_id6_17_0_, accountdia0_.region_id as region_i7_17_0_, accountdia0_.source as source8_17_0_, accountdia0_.start_time as start_ti9_17_0_, accountdia0_.status as status10_17_0_, accountdia0_.uuid as uuid11_17_0_ from tbl_account_dial_request accountdia0_ where accountdia0_.id=$1
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>DEBUG:  StartTransactionCommand
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>DEBUG:  bind <unnamed> to S_14
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>LOG:  execute S_14: select accountdia0_.id as id1_17_0_, accountdia0_.end_time as end_time2_17_0_, accountdia0_.executor as executor3_17_0_, accountdia0_.extra as extra4_17_0_, accountdia0_.log_id as log_id5_17_0_, accountdia0_.plan_id as plan_id6_17_0_, accountdia0_.region_id as region_i7_17_0_, accountdia0_.source as source8_17_0_, accountdia0_.start_time as start_ti9_17_0_, accountdia0_.status as status10_17_0_, accountdia0_.uuid as uuid11_17_0_ from tbl_account_dial_request accountdia0_ where accountdia0_.id=$1
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>DETAIL:  parameters: $1 = '18'
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>DEBUG:  CommitTransactionCommand
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>DEBUG:  parse S_15: update tbl_account_dial_request_detail set acc_names=$1, dev_id=$2, dial_request_id=$3, end_time=$4, extra=$5, reason=$6, start_time=$7, status=$8 where id=$9
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>DEBUG:  StartTransactionCommand
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>DEBUG:  bind <unnamed> to S_15
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>LOG:  execute S_15: update tbl_account_dial_request_detail set acc_names=$1, dev_id=$2, dial_request_id=$3, end_time=$4, extra=$5, reason=$6, start_time=$7, status=$8 where id=$9
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>DETAIL:  parameters: $1 = '["root"]', $2 = '326831', $3 = '18', $4 = '2023-08-29 18:34:34.956', $5 = '{}', $6 = NULL, $7 = '2023-08-29 18:34:34.503', $8 = '0', $9 = '2356498'
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <00000>DEBUG:  ProcessQuery
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <25006>ERROR:  cannot execute UPDATE in a read-only transaction
<2023-08-29 18:34:34.957 CST> <20912> <0> <4/152554> <25006>STATEMENT:  update tbl_account_dial_request_detail set acc_names=$1, dev_id=$2, dial_request_id=$3, end_time=$4, extra=$5, reason=$6, start_time=$7, status=$8 where id=$9```

  I suspect it has something to do with the fact that my application runs in a multi-threaded environment. Any help?
  Regards.

[davecramer]

sorry for the late reply, what is 20912, is that the pid ?

[farewall]

Yes, that is postgres pid. And 4/152554 means postgres virtual transaction ID.

[davecramer]

Looks to me like you are sharing the connection. This is not supported without doing what @sehrope mentions below.

[sehrope]

I suspect it has something to do with the fact that my application runs in a multi-threaded environment. Any help?

It definitely seems like something specific to your application. If you're sharing database connections directly between threads, you need to be careful to reset the state of the connection. PostgreSQL even has a special command that does just that called DISCARD: https://www.postgresql.org/docs/current/sql-discard.html

If you are manually sharing connections and each is modifying the state with things like transaction management, you probably want to issue a ROLLBACK / DISCARD to reset the connection before a different thread uses a connection. Some connection pools handle this type of thing for you.

You do need to be careful not to concurrently use a JDBC connection with multiple threads. To debug, try adding some logging before you SQL execution in the Java program to log the current thread, connection ID, and call stack. That should give you more information on where the problem is happening.