Re: iinvalid string enlargement PG 7.4.5 - Mailing list pgsql-hackers

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