Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
Tom, Your patch works for my test cases. Thanks to both you and Oliver for getting this fixed. --Barry -Original Message- From: Tom Lane [mailto:[EMAIL PROTECTED] Sent: Sunday, November 28, 2004 2:23 PM To: Oliver Jowett Cc: Barry Lind; [EMAIL PROTECTED] Subject: Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver Oliver Jowett [EMAIL PROTECTED] writes: Perhaps PerformCursorOpen should copy the query tree before planning, or plan in a different memory context? Patch attached. It moves query planning inside the new portal's memory context. With this applied I can run Barry's testcase without errors, and valgrind seems OK with it too. I think the better solution is the first way (copy the querytree first). The problem with the way you did it is that all the temporary structures built by the planner will be left behind in the cursor's memory context, and can't be reclaimed until the cursor is destroyed. In the case of a complex query that could represent a pretty serious memory leak. It seems better to eat the cost of copying the querytree an extra time, especially since this way forms a patch that's easy to reverse whenever we fix the planner to be less cavalier about scribbling on its input. I've applied the attached patch instead (and analogously in 7.4 branch). Would you confirm it fixes the problem you see? regards, tom lane *** src/backend/commands/portalcmds.c.orig Thu Sep 16 12:58:28 2004 --- src/backend/commands/portalcmds.c Sun Nov 28 17:02:22 2004 *** *** 62,73 RequireTransactionChain((void *) stmt, DECLARE CURSOR); /* * The query has been through parse analysis, but not rewriting or * planning as yet. Note that the grammar ensured we have a SELECT * query, so we are not expecting rule rewriting to do anything * strange. */ ! rewritten = QueryRewrite((Query *) stmt-query); if (list_length(rewritten) != 1 || !IsA(linitial(rewritten), Query)) elog(ERROR, unexpected rewrite result); query = (Query *) linitial(rewritten); --- 62,82 RequireTransactionChain((void *) stmt, DECLARE CURSOR); /* +* Because the planner is not cool about not scribbling on its input, +* we make a preliminary copy of the source querytree. This prevents +* problems in the case that the DECLARE CURSOR is in a portal and is +* executed repeatedly. XXX the planner really shouldn't modify its +* input ... FIXME someday. +*/ + query = copyObject(stmt-query); + + /* * The query has been through parse analysis, but not rewriting or * planning as yet. Note that the grammar ensured we have a SELECT * query, so we are not expecting rule rewriting to do anything * strange. */ ! rewritten = QueryRewrite(query); if (list_length(rewritten) != 1 || !IsA(linitial(rewritten), Query)) elog(ERROR, unexpected rewrite result); query = (Query *) linitial(rewritten); ---(end of broadcast)--- TIP 8: explain analyze is your friend
Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
Oliver Jowett [EMAIL PROTECTED] writes: Perhaps PerformCursorOpen should copy the query tree before planning, or plan in a different memory context? Patch attached. It moves query planning inside the new portal's memory context. With this applied I can run Barry's testcase without errors, and valgrind seems OK with it too. I think the better solution is the first way (copy the querytree first). The problem with the way you did it is that all the temporary structures built by the planner will be left behind in the cursor's memory context, and can't be reclaimed until the cursor is destroyed. In the case of a complex query that could represent a pretty serious memory leak. It seems better to eat the cost of copying the querytree an extra time, especially since this way forms a patch that's easy to reverse whenever we fix the planner to be less cavalier about scribbling on its input. I've applied the attached patch instead (and analogously in 7.4 branch). Would you confirm it fixes the problem you see? regards, tom lane *** src/backend/commands/portalcmds.c.orig Thu Sep 16 12:58:28 2004 --- src/backend/commands/portalcmds.c Sun Nov 28 17:02:22 2004 *** *** 62,73 RequireTransactionChain((void *) stmt, DECLARE CURSOR); /* * The query has been through parse analysis, but not rewriting or * planning as yet. Note that the grammar ensured we have a SELECT * query, so we are not expecting rule rewriting to do anything * strange. */ ! rewritten = QueryRewrite((Query *) stmt-query); if (list_length(rewritten) != 1 || !IsA(linitial(rewritten), Query)) elog(ERROR, unexpected rewrite result); query = (Query *) linitial(rewritten); --- 62,82 RequireTransactionChain((void *) stmt, DECLARE CURSOR); /* +* Because the planner is not cool about not scribbling on its input, +* we make a preliminary copy of the source querytree. This prevents +* problems in the case that the DECLARE CURSOR is in a portal and is +* executed repeatedly. XXX the planner really shouldn't modify its +* input ... FIXME someday. +*/ + query = copyObject(stmt-query); + + /* * The query has been through parse analysis, but not rewriting or * planning as yet. Note that the grammar ensured we have a SELECT * query, so we are not expecting rule rewriting to do anything * strange. */ ! rewritten = QueryRewrite(query); if (list_length(rewritten) != 1 || !IsA(linitial(rewritten), Query)) elog(ERROR, unexpected rewrite result); query = (Query *) linitial(rewritten); ---(end of broadcast)--- TIP 4: Don't 'kill -9' the postmaster
Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
Barry Lind wrote: I also have the test case (in java) down to the bare minimum that generated the following output (that test case is attached). (Note that if the FETCH in the test case is not executed then the backend crashes; with the FETCH you get an error: ERROR: unrecognized node type: 0) I narrowed this down to: while (true) { l_stmtDeclare.execute(); } producing: FE= Parse(stmt=S_1,query=BEGIN,oids={}) FE= Bind(stmt=S_1,portal=null) FE= Execute(portal=null,limit=0) FE= Parse(stmt=S_2,query=DECLARE CUR CURSOR FOR SELECT 1,oids={}) FE= Bind(stmt=S_2,portal=null) FE= Describe(portal=null) FE= Execute(portal=null,limit=0) FE= Sync =BE ParseComplete [S_1] =BE BindComplete [null] =BE CommandStatus(BEGIN) =BE ParseComplete [S_2] =BE BindComplete [null] =BE NoData =BE CommandStatus(DECLARE CURSOR) =BE ReadyForQuery(T) simple execute, [EMAIL PROTECTED], maxRows=0, fetchSize=0, flags=0 FE= Bind(stmt=S_2,portal=null) FE= Describe(portal=null) FE= Execute(portal=null,limit=0) FE= Sync =BE BindComplete [null] =BE NoData =BE ErrorMessage(ERROR: unrecognized node type: 2139062143 Location: File: clauses.c, Routine: expression_tree_mutator, Line: 3237 Server SQLState: XX000) Valgrind says this is the culprit: ==26451== Invalid read of size 4 ==26451==at 0x8185C86: eval_const_expressions_mutator (clauses.c:1185) ==26451==by 0x8185C32: eval_const_expressions (clauses.c:1152) ==26451==by 0x817D1A6: preprocess_expression (planner.c:415) ==26451==by 0x817CEBF: subquery_planner (planner.c:240) ==26451==by 0x817CD59: planner (planner.c:129) ==26451==by 0x810DF03: PerformCursorOpen (portalcmds.c:87) ==26451==by 0x81C1402: PortalRunUtility (pquery.c:934) ==26451==by 0x81C1762: PortalRunMulti (pquery.c:1001) ==26451==by 0x81C0D8E: PortalRun (pquery.c:617) ==26451==by 0x81BDDA7: exec_execute_message (postgres.c:1673) ==26451==by 0x81BF6E1: PostgresMain (postgres.c:3035) ==26451==by 0x818FC39: BackendRun (postmaster.c:2817) ==26451==by 0x818F642: BackendStartup (postmaster.c:2453) ==26451==by 0x818D989: ServerLoop (postmaster.c:1198) ==26451==by 0x818CDBA: PostmasterMain (postmaster.c:917) ==26451==by 0x81570F4: main (main.c:268) ==26451== Address 0x1BBBF704 is 260 bytes inside a block of size 1024 free'd ==26451==at 0x1B905460: free (vg_replace_malloc.c:153) ==26451==by 0x8245706: AllocSetDelete (aset.c:466) ==26451==by 0x82468B8: MemoryContextDelete (mcxt.c:193) ==26451==by 0x8247BCF: PortalDrop (portalmem.c:384) ==26451==by 0x82475B5: CreatePortal (portalmem.c:179) ==26451==by 0x81BD735: exec_bind_message (postgres.c:1369) ==26451==by 0x81BF4EF: PostgresMain (postgres.c:3023) ==26451==by 0x818FC39: BackendRun (postmaster.c:2817) ==26451==by 0x818F642: BackendStartup (postmaster.c:2453) ==26451==by 0x818D989: ServerLoop (postmaster.c:1198) ==26451==by 0x818CDBA: PostmasterMain (postmaster.c:917) ==26451==by 0x81570F4: main (main.c:268) With a bit of gdb work, I think what is happening is this: The first Execute of S_2, running in portal context, calls the planner on the query contained in S_2's DeclareCursorStmt. The planner modifies the query tree in the course of planning it (specifically, it modifies parse-targetList). Memory allocated for the modified query comes from the portal context. The portal context is freed implicitly by the second Bind of S_2 (second stack trace above). The second Execute of S_2 then tries to use parse-targetList when planning (first stack trace above), but that's now pointing to freed memory. Boom. Perhaps PerformCursorOpen should copy the query tree before planning, or plan in a different memory context? -O ---(end of broadcast)--- TIP 7: don't forget to increase your free space map settings
Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
Oliver Jowett wrote: Perhaps PerformCursorOpen should copy the query tree before planning, or plan in a different memory context? Patch attached. It moves query planning inside the new portal's memory context. With this applied I can run Barry's testcase without errors, and valgrind seems OK with it too. -O Index: src/backend/commands/portalcmds.c === RCS file: /projects/cvsroot/pgsql/src/backend/commands/portalcmds.c,v retrieving revision 1.36 diff -c -r1.36 portalcmds.c *** src/backend/commands/portalcmds.c 16 Sep 2004 16:58:28 - 1.36 --- src/backend/commands/portalcmds.c 24 Nov 2004 09:28:34 - *** *** 67,73 * query, so we are not expecting rule rewriting to do anything * strange. */ ! rewritten = QueryRewrite((Query *) stmt-query); if (list_length(rewritten) != 1 || !IsA(linitial(rewritten), Query)) elog(ERROR, unexpected rewrite result); query = (Query *) linitial(rewritten); --- 67,86 * query, so we are not expecting rule rewriting to do anything * strange. */ ! ! /* Create a new portal, and do all query planning on a copy of !* the query allocated in the new portal's memory context. The !* planner may modify the query, and it is not safe to have !* those modifications persist as we are ourselves running in a !* transient portal context. !*/ ! portal = CreatePortal(stmt-portalname, false, false); ! ! oldContext = MemoryContextSwitchTo(PortalGetHeapMemory(portal)); ! ! query = copyObject(stmt-query); ! ! rewritten = QueryRewrite(query); if (list_length(rewritten) != 1 || !IsA(linitial(rewritten), Query)) elog(ERROR, unexpected rewrite result); query = (Query *) linitial(rewritten); *** *** 86,102 plan = planner(query, true, stmt-options, NULL); - /* -* Create a portal and copy the query and plan into its memory -* context. -*/ - portal = CreatePortal(stmt-portalname, false, false); - - oldContext = MemoryContextSwitchTo(PortalGetHeapMemory(portal)); - - query = copyObject(query); - plan = copyObject(plan); - PortalDefineQuery(portal, NULL, /* unfortunately don't have sourceText */ SELECT, /* cursor's query is always a SELECT */ --- 99,104 ---(end of broadcast)--- TIP 9: the planner will ignore your desire to choose an index scan if your joining column's datatypes do not match
Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
Oliver, The patch works for me. Thanks. Things look good now against an 8.0 server. (I still have a lot more testing to do though). However I still have problems against a 7.4 server with the 8.0 jdbc driver. (ERROR: no value found for parameter 1). You mentioned that you had found this bug and fixed it in 8.0 of the server. Any chance of getting a backport? Or is my only option to run with protocolVersion=2 on the jdbc connection. Thanks, --Barry -Original Message- From: Oliver Jowett [mailto:[EMAIL PROTECTED] Sent: Wednesday, November 24, 2004 1:38 AM To: Barry Lind Cc: Tom Lane; [EMAIL PROTECTED] Subject: Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver Oliver Jowett wrote: Perhaps PerformCursorOpen should copy the query tree before planning, or plan in a different memory context? Patch attached. It moves query planning inside the new portal's memory context. With this applied I can run Barry's testcase without errors, and valgrind seems OK with it too. -O ---(end of broadcast)--- TIP 5: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faqs/FAQ.html
Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
Barry Lind [EMAIL PROTECTED] writes: OK, getting closer. The error happens if in jdbc I reuse PreparedStatement objects to reexecute the same set of queries multiple times. The TRAP you showed looked like it might have something to do with trying to execute code outside any transaction. But I dunno how it got there. If you still need a test case, let me know, and I will continue to package up what I have been working on. What I'd actually rather have is a list of the exact sequence of messages sent to the server. regards, tom lane ---(end of broadcast)--- TIP 9: the planner will ignore your desire to choose an index scan if your joining column's datatypes do not match
Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
Tom, Here is what you requested. (Thanks to Oliver for the good logging in the jdbc driver). I also have the test case (in java) down to the bare minimum that generated the following output (that test case is attached). (Note that if the FETCH in the test case is not executed then the backend crashes; with the FETCH you get an error: ERROR: unrecognized node type: 0) Thanks, --Barry PostgreSQL 8.0devel JDBC3 with SSL (build 308) Trying to establish a protocol version 3 connection to localhost:5432 FE= StartupPacket(user=blind, database=fileswfs43, client_encoding=UNICODE, DateStyle=ISO) =BE AuthenticationOk =BE ParameterStatus(client_encoding = UNICODE) =BE ParameterStatus(DateStyle = ISO, MDY) =BE ParameterStatus(integer_datetimes = off) =BE ParameterStatus(is_superuser = on) =BE ParameterStatus(server_encoding = UNICODE) =BE ParameterStatus(server_version = 8.0.0beta4) =BE ParameterStatus(session_authorization = blind) =BE BackendKeyData(pid=3348,ckey=914259969) =BE ReadyForQuery(I) compatible = 8.0 loglevel = 2 prepare threshold = 1 getConnection returning driver[className=org.postgresql.Driver,[EMAIL PROTECTED] simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandl [EMAIL PROTECTED], maxRows=0, fetchSize=0, flags=0 FE= Parse(stmt=S_1,query=BEGIN,oids={}) FE= Bind(stmt=S_1,portal=null) FE= Execute(portal=null,limit=0) FE= Parse(stmt=S_2,query=DECLARE CUR CURSOR FOR SELECT 1,oids={}) FE= Bind(stmt=S_2,portal=null) FE= Describe(portal=null) FE= Execute(portal=null,limit=0) FE= Sync =BE ParseComplete [S_1] =BE BindComplete [null] =BE CommandStatus(BEGIN) =BE ParseComplete [S_2] =BE BindComplete [null] =BE NoData =BE CommandStatus(DECLARE CURSOR) =BE ReadyForQuery(T) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandl [EMAIL PROTECTED], maxRows=0, fetchSize=0, flags=0 FE= Parse(stmt=S_3,query=FETCH FORWARD 10 FROM CUR,oids={}) FE= Bind(stmt=S_3,portal=null) FE= Describe(portal=null) FE= Execute(portal=null,limit=0) FE= Sync =BE ParseComplete [S_3] =BE BindComplete [null] =BE RowDescription(1) =BE DataRow =BE CommandStatus(FETCH) =BE ReadyForQuery(T) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandl [EMAIL PROTECTED], maxRows=0, fetchSize=0, flags=0 FE= Parse(stmt=S_4,query=CLOSE CUR,oids={}) FE= Bind(stmt=S_4,portal=null) FE= Describe(portal=null) FE= Execute(portal=null,limit=0) FE= Sync =BE ParseComplete [S_4] =BE BindComplete [null] =BE NoData =BE CommandStatus(CLOSE CURSOR) =BE ReadyForQuery(T) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandl [EMAIL PROTECTED], maxRows=0, fetchSize=0, flags=0 FE= Bind(stmt=S_2,portal=null) FE= Describe(portal=null) FE= Execute(portal=null,limit=0) FE= Sync =BE BindComplete [null] =BE NoData =BE ErrorMessage(ERROR: unrecognized node type: 0 Location: File: clauses.c, Routine: expression_tree_mutator, Line: 3220 Server SQLState: XX000) java.sql.SQLException: ERROR: unrecognized node type: 0 Location: File: clauses.c, Routine: expression_tree_mutator, Line: 3220 Server SQLState: XX000 at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecu torImpl.java:1356) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImp l.java:1151) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java: 166) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Stateme nt.java:363) at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdb c2Statement.java:308) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Stateme nt.java:299) at test80.main(test80.java:31) SQLException: SQLState(XX000) =BE ReadyForQuery(E) java.sql.SQLException: ERROR: unrecognized node type: 0 Location: File: clauses.c, Routine: expression_tree_mutator, Line: 3220 Server SQLState: XX000 -Original Message- From: Tom Lane [mailto:[EMAIL PROTECTED] Sent: Tuesday, November 23, 2004 7:10 AM To: Barry Lind Cc: [EMAIL PROTECTED]; [EMAIL PROTECTED] Subject: Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver Barry Lind [EMAIL PROTECTED] writes: OK, getting closer. The error happens if in jdbc I reuse PreparedStatement objects to reexecute the same set of queries multiple times. The TRAP you showed looked like it might have something to do with trying to execute code outside any transaction. But I dunno how it got there. If you still need a test case, let me know, and I will continue to package up what I have been working on. What I'd actually rather have is a list of the exact sequence of messages sent to the server. regards, tom lane test80.java Description: test80.java ---(end of broadcast)--- TIP 3: if posting
FW: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
I have been unable to come up with a simple test case for this problem (yet). But here is some additional information. Today I setup a 7.4.6 and an 8.0.0beta5 on linux (RH9) and could also reproduce the problem. However there were some new twists. I now sometimes get the following error on 8.0: ERROR: cache lookup failed for function 18005 I did as Tom suggested and rebuilt with --enable-cassert and strangely that made the problem more difficult to reproduce. Once I finally was able to get the server to start having errors, I got the following interesting message in the log file: TRAP: FailedAssertion(!(serializable ? !((MyProc-xmin) != ((TransactionId) 0)) : ((MyProc-xmin) != ((TransactionId) 0))), File: sinval.c, Line: 767) I am going to try to continue to see if I can come up with a test case, but I wanted to pass this information on in case it might mean anything to anyone. Thanks, --Barry -Original Message- From: Barry Lind Sent: Friday, November 19, 2004 5:40 PM To: Kris Jurka Cc: [EMAIL PROTECTED]; [EMAIL PROTECTED] Subject: Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver Kris, Environment #1: WinXP 8.0beta4 server, 8.0jdbc client I get random failures with the following errors: $ grep ERROR postgresql-2004-11-19_091524.log 2004-11-19 12:19:06 ERROR: unrecognized node type: 25344832 2004-11-19 12:20:06 ERROR: unrecognized node type: 25344832 2004-11-19 12:21:06 ERROR: unrecognized node type: 0 2004-11-19 12:22:06 ERROR: unrecognized node type: 0 2004-11-19 12:23:06 ERROR: unrecognized node type: 0 2004-11-19 12:24:06 ERROR: unrecognized node type: 0 2004-11-19 12:25:06 ERROR: unrecognized node type: 0 2004-11-19 12:26:06 ERROR: unrecognized node type: 0 2004-11-19 12:27:06 ERROR: unrecognized node type: 0 2004-11-19 12:28:06 ERROR: unrecognized node type: 653 2004-11-19 12:29:06 ERROR: unrecognized node type: 0 2004-11-19 12:30:06 ERROR: unrecognized node type: 0 2004-11-19 12:30:30 ERROR: unrecognized node type: 26 2004-11-19 12:31:06 ERROR: unrecognized node type: 0 2004-11-19 12:32:06 ERROR: unrecognized node type: 0 2004-11-19 12:33:06 ERROR: unrecognized node type: 0 2004-11-19 12:34:06 ERROR: unrecognized node type: 0 2004-11-19 12:35:06 ERROR: unrecognized node type: 0 2004-11-19 12:36:06 ERROR: unrecognized node type: 0 2004-11-19 12:37:06 ERROR: unrecognized node type: 0 Environment #2: Sun Solaris 7.4.3 server, 8.0jdbc client I get random failures with the following errors: ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 I am seeing errors in the two different environments where I am testing the 8.0 driver (which fully uses the V3 protocol), I don't have errors with the 7.4 driver (which only used basic V3 protocol features). I will work to try to come up with a smaller reproducable test case and repro in a linux environment where I can do more. Thanks, --Barry -Original Message- From: Kris Jurka [mailto:[EMAIL PROTECTED] Sent: Friday, November 19, 2004 3:57 PM To: Barry Lind Cc: [EMAIL PROTECTED] Subject: Re: [JDBC] Strange server error with current 8.0beta driver On Fri, 19 Nov 2004, Barry Lind wrote: During my testing with the 8.0 driver, I am occasionally getting failures. The strange thing is that a test will only fail 1 out of 10 times. The error I am getting from the server is: ERROR: unrecognized node type: 25344832 This type of error points to a bug in the server. It means a query plan is created that it can't process. A higher level node finds a lower level node that it doesn't expect. The variability of the test failure could be due to different plans being generated (note that V2 vs V3 can generate different plans because of string substitution vs a prepared query). The fact that the node number varies is a little suspicious, also because it's a very large value. Does it vary between a couple values or is it different every time. If it varies wildly then that could point to a memory overwrite instead of a bad plan being created, but in any case this problem is on the server side. Kris Jurka ---(end of broadcast)--- TIP 4: Don't 'kill -9' the postmaster ---(end of broadcast)--- TIP 8: explain analyze is your friend
Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
OK, getting closer. The error happens if in jdbc I reuse PreparedStatement objects to reexecute the same set of queries multiple times. Specifically if I do the following set of queries: Declare cursor Close cursor Declare cursor Close cursor Declare cursor Close cursor Declare cursor Close cursor Declare cursor Close cursor After the 5th close the server will gpf on windows (if I add fetches between the declare and close then I don't get a gfp, but instead get ERROR: unrecognized node type: 0 I believe the current jdbc driver begins to use a named portal for reuse after five executions of the same jdbc PreparedStatement (until then it uses an unnamed portal), which would seem to jive with the fact that it errors after the fifth execution. (Oliver please correct me if I am wrong here). If you still need a test case, let me know, and I will continue to package up what I have been working on. Thanks, --Barry -Original Message- From: Barry Lind Sent: Monday, November 22, 2004 7:48 PM To: [EMAIL PROTECTED]; [EMAIL PROTECTED] Subject: FW: [HACKERS] [JDBC] Strange server error with current 8.0beta driver I have been unable to come up with a simple test case for this problem (yet). But here is some additional information. Today I setup a 7.4.6 and an 8.0.0beta5 on linux (RH9) and could also reproduce the problem. However there were some new twists. I now sometimes get the following error on 8.0: ERROR: cache lookup failed for function 18005 I did as Tom suggested and rebuilt with --enable-cassert and strangely that made the problem more difficult to reproduce. Once I finally was able to get the server to start having errors, I got the following interesting message in the log file: TRAP: FailedAssertion(!(serializable ? !((MyProc-xmin) != ((TransactionId) 0)) : ((MyProc-xmin) != ((TransactionId) 0))), File: sinval.c, Line: 767) I am going to try to continue to see if I can come up with a test case, but I wanted to pass this information on in case it might mean anything to anyone. Thanks, --Barry -Original Message- From: Barry Lind Sent: Friday, November 19, 2004 5:40 PM To: Kris Jurka Cc: [EMAIL PROTECTED]; [EMAIL PROTECTED] Subject: Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver Kris, Environment #1: WinXP 8.0beta4 server, 8.0jdbc client I get random failures with the following errors: $ grep ERROR postgresql-2004-11-19_091524.log 2004-11-19 12:19:06 ERROR: unrecognized node type: 25344832 2004-11-19 12:20:06 ERROR: unrecognized node type: 25344832 2004-11-19 12:21:06 ERROR: unrecognized node type: 0 2004-11-19 12:22:06 ERROR: unrecognized node type: 0 2004-11-19 12:23:06 ERROR: unrecognized node type: 0 2004-11-19 12:24:06 ERROR: unrecognized node type: 0 2004-11-19 12:25:06 ERROR: unrecognized node type: 0 2004-11-19 12:26:06 ERROR: unrecognized node type: 0 2004-11-19 12:27:06 ERROR: unrecognized node type: 0 2004-11-19 12:28:06 ERROR: unrecognized node type: 653 2004-11-19 12:29:06 ERROR: unrecognized node type: 0 2004-11-19 12:30:06 ERROR: unrecognized node type: 0 2004-11-19 12:30:30 ERROR: unrecognized node type: 26 2004-11-19 12:31:06 ERROR: unrecognized node type: 0 2004-11-19 12:32:06 ERROR: unrecognized node type: 0 2004-11-19 12:33:06 ERROR: unrecognized node type: 0 2004-11-19 12:34:06 ERROR: unrecognized node type: 0 2004-11-19 12:35:06 ERROR: unrecognized node type: 0 2004-11-19 12:36:06 ERROR: unrecognized node type: 0 2004-11-19 12:37:06 ERROR: unrecognized node type: 0 Environment #2: Sun Solaris 7.4.3 server, 8.0jdbc client I get random failures with the following errors: ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 I am seeing errors in the two different environments where I am testing the 8.0 driver (which fully uses the V3 protocol), I don't have errors with the 7.4 driver (which only used basic V3 protocol features). I will work to try to come up with a smaller reproducable test case and repro in a linux environment where I can do more. Thanks, --Barry -Original Message- From: Kris Jurka [mailto:[EMAIL PROTECTED] Sent: Friday, November 19, 2004 3:57 PM To: Barry Lind Cc: [EMAIL PROTECTED] Subject: Re: [JDBC] Strange server error with current 8.0beta driver On Fri, 19 Nov 2004, Barry Lind wrote: During my testing with the 8.0 driver, I am occasionally getting failures. The strange thing is that a test will only fail 1 out of 10 times. The error I am getting from the server is: ERROR: unrecognized node type: 25344832 This type of error points to a bug in the server. It means a query plan is created that it can't process. A higher level node finds a lower level node that it doesn't expect. The variability of the test failure could be due to different
Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
Barry Lind wrote: Environment #1: WinXP 8.0beta4 server, 8.0jdbc client 2004-11-19 12:19:06 ERROR: unrecognized node type: 25344832 Environment #2: Sun Solaris 7.4.3 server, 8.0jdbc client ERROR: no value found for parameter 1 From memory the 7.4.3 behaviour you see can happen if you DECLARE CURSOR with a parameterized query (executes OK) then try to FETCH from it (fails with the above error, as the original parameter values from DECLARE execution are not stored with the portal). The parameterization can happen either via V3 protocol Parse/Bind or via function execution, IIRC. I put together a patch to fix this that made it into 8.0 (with some changes IIRC), perhaps the bug lies in there somewhere. -O ---(end of broadcast)--- TIP 6: Have you searched our list archives? http://archives.postgresql.org
Re: [HACKERS] [JDBC] Strange server error with current 8.0beta driver
Kris, Environment #1: WinXP 8.0beta4 server, 8.0jdbc client I get random failures with the following errors: $ grep ERROR postgresql-2004-11-19_091524.log 2004-11-19 12:19:06 ERROR: unrecognized node type: 25344832 2004-11-19 12:20:06 ERROR: unrecognized node type: 25344832 2004-11-19 12:21:06 ERROR: unrecognized node type: 0 2004-11-19 12:22:06 ERROR: unrecognized node type: 0 2004-11-19 12:23:06 ERROR: unrecognized node type: 0 2004-11-19 12:24:06 ERROR: unrecognized node type: 0 2004-11-19 12:25:06 ERROR: unrecognized node type: 0 2004-11-19 12:26:06 ERROR: unrecognized node type: 0 2004-11-19 12:27:06 ERROR: unrecognized node type: 0 2004-11-19 12:28:06 ERROR: unrecognized node type: 653 2004-11-19 12:29:06 ERROR: unrecognized node type: 0 2004-11-19 12:30:06 ERROR: unrecognized node type: 0 2004-11-19 12:30:30 ERROR: unrecognized node type: 26 2004-11-19 12:31:06 ERROR: unrecognized node type: 0 2004-11-19 12:32:06 ERROR: unrecognized node type: 0 2004-11-19 12:33:06 ERROR: unrecognized node type: 0 2004-11-19 12:34:06 ERROR: unrecognized node type: 0 2004-11-19 12:35:06 ERROR: unrecognized node type: 0 2004-11-19 12:36:06 ERROR: unrecognized node type: 0 2004-11-19 12:37:06 ERROR: unrecognized node type: 0 Environment #2: Sun Solaris 7.4.3 server, 8.0jdbc client I get random failures with the following errors: ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 ERROR: no value found for parameter 1 I am seeing errors in the two different environments where I am testing the 8.0 driver (which fully uses the V3 protocol), I don't have errors with the 7.4 driver (which only used basic V3 protocol features). I will work to try to come up with a smaller reproducable test case and repro in a linux environment where I can do more. Thanks, --Barry -Original Message- From: Kris Jurka [mailto:[EMAIL PROTECTED] Sent: Friday, November 19, 2004 3:57 PM To: Barry Lind Cc: [EMAIL PROTECTED] Subject: Re: [JDBC] Strange server error with current 8.0beta driver On Fri, 19 Nov 2004, Barry Lind wrote: During my testing with the 8.0 driver, I am occasionally getting failures. The strange thing is that a test will only fail 1 out of 10 times. The error I am getting from the server is: ERROR: unrecognized node type: 25344832 This type of error points to a bug in the server. It means a query plan is created that it can't process. A higher level node finds a lower level node that it doesn't expect. The variability of the test failure could be due to different plans being generated (note that V2 vs V3 can generate different plans because of string substitution vs a prepared query). The fact that the node number varies is a little suspicious, also because it's a very large value. Does it vary between a couple values or is it different every time. If it varies wildly then that could point to a memory overwrite instead of a bad plan being created, but in any case this problem is on the server side. Kris Jurka ---(end of broadcast)--- TIP 4: Don't 'kill -9' the postmaster