Обсуждение: An I/O error occured while sending to the backend

Поиск
Список
Период
Сортировка

An I/O error occured while sending to the backend

От
Radek Jíra
Дата:
Hello,

I have a problem that I am not able to solve. I have this exception:

org.postgresql.util.PSQLException: An I/O error occured while sending to
the backend.
    at
org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:216)
    at
org.postgresql.jdbc2.AbstractJdbc2Connection.executeTransactionCommand(AbstractJdbc2Connection.java:649)
    at
org.postgresql.jdbc2.AbstractJdbc2Connection.rollback(AbstractJdbc2Connection.java:686)
    at com.evermind._id.rollback(.:196)
    at com.evermind._ja.rollback(.:104)
    at com.evermind._bs._gbc(.:118)
    at com.evermind.server.ApplicationServerTransaction._gcc(.:334)
    at com.evermind.server.ApplicationServerTransaction._gbc(.:296)
    at com.evermind.server.ApplicationServerTransaction.rollback(.:279)
    at
com.evermind.server.ApplicationServerTransactionManager.rollback(.:285)
    at
cz.iiprg.util.importer.ejb.ImporterEJB.rollbackTransaction(ImporterEJB.java:173)
    at
Importer_StatefulSessionBeanWrapper34.rollbackTransaction(Importer_StatefulSessionBeanWrapper34.java:416)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:324)
    at com.evermind._bt._uab(.:79)
    at com.evermind._bf.run(.:62)
Caused by: java.io.IOException: Stream closed
    at sun.nio.cs.StreamEncoder.ensureOpen(StreamEncoder.java:38)
    at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:151)
    at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:213)
    at org.postgresql.core.PGStream.flush(PGStream.java:501)
    at
org.postgresql.core.v3.QueryExecutorImpl.sendSync(QueryExecutorImpl.java:674)
    at
org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:189)
    ... 17 more

It is strange that it occurs randomly and only when the server is loaded.

Radek

Re: An I/O error occured while sending to the backend

От
Craig Ringer
Дата:
On 06/10/2012 05:05 PM, wbrana@gmail.com wrote:
> The following bug has been logged on the website:
>
> Bug reference:      6684
> Logged by:          wbrana
> Email address:      wbrana@gmail.com
> PostgreSQL version: 9.1.4
> Operating system:   Linux
> Description:
>
> I tried to post this to pgsql-jdbc, but it was blocked.

Check the PostgreSQL *server* logs, see if the connection got closed
server-side and if so why.

--
Craig Ringer

Re: An I/O error occured while sending to the backend

От
wbrana
Дата:
On Mon, Jun 11, 2012 at 4:28 AM, Craig Ringer <ringerc@ringerc.id.au> wrote:
>
>
> Check the PostgreSQL *server* logs, see if the connection got closed
> server-side and if so why.
>
> --
> Craig Ringer
2012-06-11 11:36:55.511
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,54,"PARSE",2012-06-11
11:36:55 CEST,10/3,6291,DEBUG,00000,"parse <unnamed>: analyze
posts",,,,,,"analyze posts",,"exec_parse_message, postgres.c:1146",""
2012-06-11 11:36:55.511
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,55,"PARSE",2012-06-11
11:36:55 CEST,10/3,6291,DEBUG,00000,"StartTransactionCommand",,,,,,"analyze
posts",,"start_xact_command, postgres.c:2426",""
2012-06-11 11:36:55.511
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,56,"PARSE",2012-06-11
11:36:55 CEST,10/3,6291,DEBUG,00000,"bind <unnamed> to
<unnamed>",,,,,,,,"exec_bind_message, postgres.c:1429",""
2012-06-11 11:36:55.511
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,57,"ANALYZE",2012-06-11
11:36:55 CEST,10/3,6291,LOG,00000,"execute <unnamed>: analyze
posts",,,,,,,,"exec_execute_message, postgres.c:1940",""
2012-06-11 11:36:55.511
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,58,"ANALYZE",2012-06-11
11:36:55 CEST,10/3,6291,DEBUG,00000,"ProcessUtility",,,,,,"analyze
posts",,"PortalRunUtility, pquery.c:1153",""
2012-06-11 11:36:55.511
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,59,"ANALYZE",2012-06-11
11:36:55 CEST,10/3,6291,DEBUG,00000,"analyzing
""forum.posts""",,,,,,"analyze posts",,"do_analyze_rel,
analyze.c:292",""
2012-06-11 11:36:55.532
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,91,"PARSE",2012-06-11
11:36:49 CEST,2/0,0,DEBUG,00000,"parse <unnamed>: SELECT forum_id,
cat_id, cat_name, forum_description, forum_name, login, post_count,
post_created, thread_count, thread_name FROM v_forums",,,,,,"SELECT
forum_id, cat_id, cat_name, forum_description, forum_name, login,
post_count, post_created, thread_count, thread_name FROM
v_forums",,"exec_parse_message, postgres.c:1146",""
2012-06-11 11:36:55.532
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,92,"PARSE",2012-06-11
11:36:49 CEST,2/0,0,DEBUG,00000,"StartTransactionCommand",,,,,,"SELECT
forum_id, cat_id, cat_name, forum_description, forum_name, login,
post_count, post_created, thread_count, thread_name FROM
v_forums",,"start_xact_command, postgres.c:2426",""
2012-06-11 11:36:55.532
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,93,"PARSE",2012-06-11
11:36:49 CEST,2/14,0,DEBUG,00000,"StartTransaction",,,,,,"SELECT
forum_id, cat_id, cat_name, forum_description, forum_name, login,
post_count, post_created, thread_count, thread_name FROM
v_forums",,"ShowTransactionState, xact.c:4316",""
2012-06-11 11:36:55.532
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,94,"PARSE",2012-06-11
11:36:49 CEST,2/14,0,DEBUG,00000,"name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
",,,,,,"SELECT forum_id, cat_id, cat_name, forum_description,
forum_name, login, post_count, post_created, thread_count, thread_name
FROM v_forums",,"ShowTransactionStateRec, xact.c:4354",""
2012-06-11 11:36:55.535
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,95,"PARSE",2012-06-11
11:36:49 CEST,2/14,0,DEBUG,00000,"bind <unnamed> to
<unnamed>",,,,,,,,"exec_bind_message, postgres.c:1429",""
2012-06-11 11:36:55.535
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,96,"SELECT",2012-06-11
11:36:49 CEST,2/14,0,LOG,00000,"execute <unnamed>: SELECT forum_id,
cat_id, cat_name, forum_description, forum_name, login, post_count,
post_created, thread_count, thread_name FROM
v_forums",,,,,,,,"exec_execute_message, postgres.c:1940",""
2012-06-11 11:36:55.535
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,97,"SELECT",2012-06-11
11:36:49 CEST,2/14,0,DEBUG,00000,"CommitTransactionCommand",,,,,,,,"finish_xact_command,
postgres.c:2450",""
2012-06-11 11:36:55.535
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,98,"SELECT",2012-06-11
11:36:49 CEST,2/14,0,DEBUG,00000,"CommitTransaction",,,,,,,,"ShowTransactionState,
xact.c:4316",""
2012-06-11 11:36:55.535
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,99,"SELECT",2012-06-11
11:36:49 CEST,2/14,0,DEBUG,00000,"name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
",,,,,,,,"ShowTransactionStateRec, xact.c:4354",""
2012-06-11 11:36:55.539
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,100,"PARSE",2012-06-11
11:36:49 CEST,2/0,0,DEBUG,00000,"parse <unnamed>: SET application_name
= ''",,,,,,"SET application_name = ''",,"exec_parse_message,
postgres.c:1146",""
2012-06-11 11:36:55.539
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,101,"PARSE",2012-06-11
11:36:49 CEST,2/0,0,DEBUG,00000,"StartTransactionCommand",,,,,,"SET
application_name = ''",,"start_xact_command, postgres.c:2426",""
2012-06-11 11:36:55.540
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,102,"PARSE",2012-06-11
11:36:49 CEST,2/15,0,DEBUG,00000,"StartTransaction",,,,,,"SET
application_name = ''",,"ShowTransactionState, xact.c:4316",""
2012-06-11 11:36:55.540
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,103,"PARSE",2012-06-11
11:36:49 CEST,2/15,0,DEBUG,00000,"name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
",,,,,,"SET application_name = ''",,"ShowTransactionStateRec,
xact.c:4354",""
2012-06-11 11:36:55.540
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,104,"PARSE",2012-06-11
11:36:49 CEST,2/15,0,DEBUG,00000,"bind <unnamed> to
<unnamed>",,,,,,,,"exec_bind_message, postgres.c:1429",""
2012-06-11 11:36:55.540
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,105,"SET",2012-06-11
11:36:49 CEST,2/15,0,LOG,00000,"execute <unnamed>: SET
application_name = ''",,,,,,,,"exec_execute_message,
postgres.c:1940",""
2012-06-11 11:36:55.540
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,106,"SET",2012-06-11
11:36:49 CEST,2/15,0,DEBUG,00000,"ProcessUtility",,,,,,"SET
application_name = ''",,"PortalRunUtility, pquery.c:1153",""
2012-06-11 11:36:55.540
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,107,"SET",2012-06-11
11:36:49 CEST,2/15,0,DEBUG,00000,"CommitTransactionCommand",,,,,,,,"finish_xact_command,
postgres.c:2450",""
2012-06-11 11:36:55.540
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,108,"SET",2012-06-11
11:36:49 CEST,2/15,0,DEBUG,00000,"CommitTransaction",,,,,,,,"ShowTransactionState,
xact.c:4316",""
2012-06-11 11:36:55.540
CEST,"forum","forum",5275,"127.0.0.1:40359",4fd5bc31.149b,109,"SET",2012-06-11
11:36:49 CEST,2/15,0,DEBUG,00000,"name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
",,,,,,,,"ShowTransactionStateRec, xact.c:4354",""
2012-06-11 11:36:55.614
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,60,"ANALYZE",2012-06-11
11:36:55 CEST,10/3,6291,DEBUG,00000,"""posts"": scanned 12763 of 12763
pages, containing 1200000 live rows and 27 dead rows; 30000 rows in
sample, 1200000 estimated total rows",,,,,,"analyze
posts",,"acquire_sample_rows, analyze.c:1244",""
2012-06-11 11:36:55.868
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,61,"ANALYZE",2012-06-11
11:36:55 CEST,10/3,6291,DEBUG,00000,"tsvector_stats: target # mces =
1000, bucket width = 144285, # lexemes = 45311, hashtable size =
29291, usable entries = 1483",,,,,,"analyze
posts",,"compute_tsvector_stats, ts_typanalyze.c:330",""
2012-06-11 11:36:55.868
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,62,"ANALYZE",2012-06-11
11:36:55 CEST,10/3,6291,LOG,08006,"could not send data to client:
Broken pipe",,,,,,"analyze posts",,"internal_flush, pqcomm.c:1245",""
2012-06-11 11:36:55.873
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,63,"ANALYZE",2012-06-11
11:36:55 CEST,10/3,6291,DEBUG,00000,"CommitTransactionCommand",,,,,,,,"finish_xact_command,
postgres.c:2450",""
2012-06-11 11:36:55.873
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,64,"idle in
transaction",2012-06-11 11:36:55
CEST,10/3,6291,DEBUG,00000,"shmem_exit(0): 7 callbacks to
make",,,,,,,,"shmem_exit, ipc.c:211",""
2012-06-11 11:36:55.873
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,65,"idle in
transaction",2012-06-11 11:36:55 CEST,,0,DEBUG,00000,"proc_exit(0): 4
callbacks to make",,,,,,,,"proc_exit_prepare, ipc.c:183",""
2012-06-11 11:36:55.873
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,66,"idle in
transaction",2012-06-11 11:36:55 CEST,,0,LOG,00000,"disconnection:
session time: 0:00:00.376 user=forum database=forum host=127.0.0.1
port=40370",,,,,,,,"log_disconnections, postgres.c:4375",""
2012-06-11 11:36:55.873
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,67,"idle in
transaction",2012-06-11 11:36:55
CEST,,0,DEBUG,00000,"exit(0)",,,,,,,,"proc_exit, ipc.c:135",""
2012-06-11 11:36:55.873
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,68,"idle in
transaction",2012-06-11 11:36:55 CEST,,0,DEBUG,00000,"shmem_exit(-1):
0 callbacks to make",,,,,,,,"shmem_exit, ipc.c:211",""
2012-06-11 11:36:55.873
CEST,"forum","forum",5345,"127.0.0.1:40370",4fd5bc37.14e1,69,"idle in
transaction",2012-06-11 11:36:55 CEST,,0,DEBUG,00000,"proc_exit(-1): 0
callbacks to make",,,,,,,,"proc_exit_prepare, ipc.c:183",""