-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Hi all,
this morning I perform an upgrade 7.4.2 -> 7.4.5 and
after 6 months without errors this night a backend
crashed:


ERROR:  invalid string enlargement request size 1476395004
DEBUG:  AbortCurrentTransaction
WARNING:  AbortTransaction and not in in-progress state
ERROR:  could not send data to client: Broken pipe
PANIC:  error during error recovery, giving up
DEBUG:  child process (PID 32247) was terminated by signal 6
LOG:  server process (PID 32247) was terminated by signal 6
LOG:  terminating any other active server processes


do you have any idea on what could be the reason ?

Regards
Gaetano Mendola







-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.4 (MingW32)
Comment: Using GnuPG with Thunderbird - http://enigmail.mozdev.org

iD8DBQFBNlh77UpzwH2SGd4RAqfoAJ4zEPgG/0Yr8YTKN+PpbYQvbU7TigCggQ+3
ie8oxH9jFgFDDMlZfNnKj4w=
=5epB
-----END PGP SIGNATURE-----


Thu, 02 Sep 2004 01:17:16 +0200
Gaetano Mendola <mendola@bigfoot.com>
iinvalid string enlargement   PG 7.4.5
Gaetano Mendola <mendola@bigfoot.com> writes:
> ERROR:  invalid string enlargement request size 1476395004
> DEBUG:  AbortCurrentTransaction
> WARNING:  AbortTransaction and not in in-progress state
> ERROR:  could not send data to client: Broken pipe
> PANIC:  error during error recovery, giving up

> do you have any idea on what could be the reason ?

I'm betting on a communications failure.  What I see there is a few
bytes of corrupted data received from the client (ie, a ridiculous
message-length word) followed by abrupt disconnect *by the client*.

You have any logs indicating what might have happened at the client
end?

			regards, tom lane

Wed, 01 Sep 2004 19:23:15 -0400
Tom Lane <tgl@sss.pgh.pa.us>
Re: iinvalid string enlargement PG 7.4.5 
Tom Lane wrote:

> Gaetano Mendola <mendola@bigfoot.com> writes:
> 
>>ERROR:  invalid string enlargement request size 1476395004
>>DEBUG:  AbortCurrentTransaction
>>WARNING:  AbortTransaction and not in in-progress state
>>ERROR:  could not send data to client: Broken pipe
>>PANIC:  error during error recovery, giving up
> 
> 
>>do you have any idea on what could be the reason ?
> 
> 
> I'm betting on a communications failure.  What I see there is a few
> bytes of corrupted data received from the client (ie, a ridiculous
> message-length word) followed by abrupt disconnect *by the client*.
> 
> You have any logs indicating what might have happened at the client
> end?


I had this failure several time:

Sep  1 20:49:51 dbsdr1 postgres[23173]: [124865-1] LOG:  statement: SELECT sp_foo (
Sep  1 20:49:51 dbsdr1 postgres[23173]: [124865-2]  'EmailAlert','xxxxxxx','waelkhemiri00d0d7031e93','application/x-www-form-urlencoded','date=Wed+Sep+01+08%3A06%3A16+CEST+2004&su
Sep  1 20:49:51 dbsdr1 postgres[23173]: [124865-3] bject=HBM+Pics+for+September+1%2C+2004&from=hardcorebm%40hardcorebymail.com&to=khemiriwael%40webmails.com' )
Sep  1 20:49:51 dbsdr1 postgres[23173]: [124881-1] ERROR:  invalid string enlargement request size 1476395004
Sep  1 20:49:51 dbsdr1 postgres[23173]: [124882-1] DEBUG:  AbortCurrentTransaction
Sep  1 20:49:51 dbsdr1 postgres[23173]: [124883-1] WARNING:  AbortTransaction and not in in-progress state
Sep  1 20:49:51 dbsdr1 postgres[23173]: [124884-1] LOG:  could not send data to client: Broken pipe
Sep  1 20:49:51 dbsdr1 postgres[23173]: [124885-1] FATAL:  invalid frontend message type 4
[...]
Sep  1 23:45:58 dbsdr1 postgres[24080]: [152267-1] LOG:  statement: SELECT sp_foo (
Sep  1 23:45:58 dbsdr1 postgres[24080]: [152267-2]  'EmailAlert','xxxxxxx','bridge500306a80229c','application/x-www-form-urlencoded','date=Wed+Dec+17+21%3A43%3A10+CET+2003&subject
Sep  1 23:45:58 dbsdr1 postgres[24080]: [152267-3] =XPiedziivojumi+-+jauns+zhurnaals%21&from=promotions%40inbox.lv&to=ahsan%40inbox.lv' )
Sep  1 23:45:58 dbsdr1 postgres[24080]: [152283-1] ERROR:  invalid string enlargement request size 1476395004
Sep  1 23:45:58 dbsdr1 postgres[24080]: [152284-1] DEBUG:  AbortCurrentTransaction
Sep  1 23:45:58 dbsdr1 postgres[24080]: [152285-1] WARNING:  AbortTransaction and not in in-progress state
Sep  1 23:45:58 dbsdr1 postgres[24080]: [152286-1] LOG:  could not send data to client: Broken pipe
Sep  1 23:45:58 dbsdr1 postgres[24080]: [152287-1] FATAL:  invalid frontend message type 4
[...]
Sep  1 23:52:24 dbsdr1 postgres[32247]: [153117-1] LOG:  statement: SELECT sp_foo (
Sep  1 23:52:24 dbsdr1 postgres[32247]: [153117-2]  'EmailAlert','xxxxxxx','waelkhemiri00d0d7031e93','application/x-www-form-urlencoded','date=Wed+Sep+01+08%3A06%3A16+CEST+2004&su
Sep  1 23:52:24 dbsdr1 postgres[32247]: [153117-3] bject=HBM+Pics+for+September+1%2C+2004&from=hardcorebm%40hardcorebymail.com&to=khemiriwael%40webmails.com' )
Sep  1 23:52:24 dbsdr1 postgres[32247]: [153133-1] ERROR:  invalid string enlargement request size 1476395004
Sep  1 23:52:24 dbsdr1 postgres[32247]: [153134-1] DEBUG:  AbortCurrentTransaction
Sep  1 23:52:24 dbsdr1 postgres[32247]: [153135-1] WARNING:  AbortTransaction and not in in-progress state
Sep  1 23:52:24 dbsdr1 postgres[32247]: [153136-1] ERROR:  could not send data to client: Broken pipe
Sep  1 23:52:24 dbsdr1 postgres[32247]: [153137-1] PANIC:  error during error recovery, giving up
[...]
Sep  2 00:00:58 dbsdr1 postgres[11857]: [156602-1] LOG:  duration: 209.141 ms
Sep  2 00:00:58 dbsdr1 postgres[11857]: [156603-1] LOG:  duration: 209.141 ms  statement: SELECT sp_foo (
Sep  2 00:00:58 dbsdr1 postgres[11857]: [156603-2]  'EmailAlert','xxxxxxx','bridge500306a80229c','application/x-www-form-urlencoded','date=Thu+Jan+29+18%3A54%3A03+CET+2004&subject
Sep  2 00:00:58 dbsdr1 postgres[11857]: [156603-3] =Laimee+celojumu+uz+Egipti%21&from=promotions%40inbox.lv&to=ahsan%40inbox.lv' )
Sep  2 00:00:58 dbsdr1 postgres[11857]: [156604-1] ERROR:  invalid string enlargement request size 1476395004
Sep  2 00:00:58 dbsdr1 postgres[11857]: [156605-1] DEBUG:  AbortCurrentTransaction
Sep  2 00:00:58 dbsdr1 postgres[11857]: [156606-1] WARNING:  AbortTransaction and not in in-progress state
Sep  2 00:00:58 dbsdr1 postgres[11857]: [156607-1] LOG:  could not send data to client: Broken pipe
Sep  2 00:00:58 dbsdr1 postgres[11857]: [156608-1] FATAL:  invalid frontend message type 4
[...]

basically is a store procedure call that genereate that error, only once there was that PANIC

On the client side I have always:

Internal Server Error: org.postgresql.util.PSQLException: An I/O error has occured while flushing the output - Exception: java.net.SocketException: Socket closed
Stack Trace:

java.net.SocketException: Socket closed
         at java.net.SocketOutputStream.socketWrite(Native Method)
         at java.net.SocketOutputStream.write(SocketOutputStream.java:83)
         at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:72)
         at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:130)
         at org.postgresql.core.PGStream.flush(PGStream.java:412)
         at org.postgresql.core.QueryExecutor.sendQueryV3(QueryExecutor.java:339)
         at org.postgresql.core.QueryExecutor.executeV3(QueryExecutor.java:122)
         at org.postgresql.core.QueryExecutor.execute(QueryExecutor.java:101)
         at org.postgresql.core.QueryExecutor.execute(QueryExecutor.java:43)
         at org.postgresql.jdbc1.AbstractJdbc1Statement.execute(AbstractJdbc1Statement.java:515)
         at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:50)
         at org.postgresql.jdbc1.AbstractJdbc1Statement.executeQuery(AbstractJdbc1Statement.java:231)



I searched the error "invalid string enlargment request" in the logs of last week and I never encountered it.
Only since today after the 7.4.5 installation. Note that the request size is always the same!



Regards
Gaetano Mendola

Thu, 02 Sep 2004 02:51:06 +0200
Gaetano Mendola <mendola@bigfoot.com>
Re: iinvalid string enlargement PG 7.4.5