Обсуждение: Problem with invalid byte sequence and log_min_error_statement
Hi, i run the greatest database ever, postgresql-8.3, on debian etch I am investigating some error messages in my log file: Apr 15 08:04:34 postgres[20686]: [4-1] 2009-04-15 08:04:34 CEST ERROR: invalid byte sequence for encoding "UTF8": 0x81 Apr 15 08:04:34 postgres[20686]: [4-2] 2009-04-15 08:04:34 CEST HINT: This error can also happen if the byte sequence does not match the encoding expected by the Apr 15 08:04:34 postgres[20686]: [4-3] server, which is controlled by "client_encoding". I want to know which statement produces this error. I have show log_min_error_statement ; error show log_error_verbosity; default so i think the error statement should be logged. Why is the error statement not logged? Or do i need to set log_error_verbosity to verbose to see the statement producing the error? I always see 0x81 and 0xe46973 as invalid byte sequence. Can someone give me a hint what characters in which encoding those bytes might be? kind regards Janning
Janning Vygen <vygen@kicktipp.de> writes:
> I am investigating some error messages in my log file:
> Apr 15 08:04:34 postgres[20686]: [4-1] 2009-04-15 08:04:34 CEST ERROR:
> invalid byte sequence for encoding "UTF8": 0x81
> Apr 15 08:04:34 postgres[20686]: [4-2] 2009-04-15 08:04:34 CEST HINT: This
> error can also happen if the byte sequence does not match the encoding
> expected by the
> Apr 15 08:04:34 postgres[20686]: [4-3] server, which is controlled by
> "client_encoding".
> I want to know which statement produces this error. I have
> show log_min_error_statement ;
> error
> show log_error_verbosity;
> default
> so i think the error statement should be logged. Why is the error statement
> not logged?
Because the error is happening while trying to convert the statement
into the database's encoding. We cannot log the string we have without
creating an encoding mismatch in the postmaster log.
> I always see 0x81 and 0xe46973 as invalid byte sequence. Can someone give me a
> hint what characters in which encoding those bytes might be?
LATIN1, or some other one of the single-byte LATINn encodings, likely.
regards, tom lane
Hi, Thank you for this great and ultra-fast support! One more question: On Wednesday 15 April 2009 17:38:51 you wrote: > Janning Vygen <vygen@kicktipp.de> writes: > > I am investigating some error messages in my log file: > > > > Apr 15 08:04:34 postgres[20686]: [4-1] 2009-04-15 08:04:34 CEST ERROR: > > invalid byte sequence for encoding "UTF8": 0x81 > > Apr 15 08:04:34 postgres[20686]: [4-2] 2009-04-15 08:04:34 CEST HINT: > > This error can also happen if the byte sequence does not match the > > encoding expected by the > > Apr 15 08:04:34 postgres[20686]: [4-3] server, which is controlled by > > "client_encoding". > > > > I want to know which statement produces this error. I have > > > > show log_min_error_statement ; > > error > > > > show log_error_verbosity; > > default > > > > so i think the error statement should be logged. Why is the error > > statement not logged? > > Because the error is happening while trying to convert the statement > into the database's encoding. We cannot log the string we have without > creating an encoding mismatch in the postmaster log. Ok, so i need to track it another way. Now i see that the errors occur _exactly_ every 4000 seconds (1 hour, 6 minutes and 40 seconds). I have no clue as i only have one cronjob at night concerning postgresql. I have no autovacuum running (only manual at night). my application cronjobs are only running at night. i have a few threads but no thread has a sleep time of 4000 millis, besides the fact that they all work fine. Maybe i have to check my c3p0 pool. however, i know i have to search for my own, as you can't look into my app. But maybe someone has a hint, that something inside or outside postgresql is usually running every 4000 seconds? > > I always see 0x81 and 0xe46973 as invalid byte sequence. Can someone give > > me a hint what characters in which encoding those bytes might be? "0xe46973" looks like "äis" which i found in another thread about encodings http://archives.postgresql.org/pgsql-de-allgemein/2006-10/msg00007.php "äis" is part of "Westeuropäische Normalzeit" (i hope you can see the german umlaut ä) But why would any process run every 4000 seconds doing something like saying "Westeuropäische Normalzeit"? And as far as i can see, the code sequence 0x81 is not defined in latin-n. kind regards Janning > LATIN1, or some other one of the single-byte LATINn encodings, likely. > > regards, tom lane
Janning Vygen <vygen@kicktipp.de> writes:
> Now i see that the errors occur _exactly_ every 4000 seconds (1 hour, 6
> minutes and 40 seconds). I have no clue as i only have one cronjob at night
> concerning postgresql. I have no autovacuum running (only manual at night). my
> application cronjobs are only running at night. i have a few threads but no
> thread has a sleep time of 4000 millis, besides the fact that they all work
> fine. Maybe i have to check my c3p0 pool. however, i know i have to search for
> my own, as you can't look into my app. But maybe someone has a hint, that
> something inside or outside postgresql is usually running every 4000
> seconds?
There's nothing inside of postgres that would operate on such a
schedule. Furthermore, unless I'm all wet about where the error is
coming from, this *must* be happening during receipt of a command from
an external client.
Perhaps turning on log_connections would give you a clue about what it
is. Also set log_line_prefix to make sure you can match up the error
report with the previous connection log entry (adding the PID is usually
enough).
regards, tom lane
On Wednesday 15 April 2009 19:21:03 you wrote: > Janning Vygen <vygen@kicktipp.de> writes: > > Now i see that the errors occur _exactly_ every 4000 seconds (1 hour, 6 > > minutes and 40 seconds). I have no clue as i only have one cronjob at > > night concerning postgresql. I have no autovacuum running (only manual at > > night). my application cronjobs are only running at night. i have a few > > threads but no thread has a sleep time of 4000 millis, besides the fact > > that they all work fine. Maybe i have to check my c3p0 pool. however, i > > know i have to search for my own, as you can't look into my app. But > > maybe someone has a hint, that something inside or outside postgresql is > > usually running every 4000 seconds? > > There's nothing inside of postgres that would operate on such a > schedule. Furthermore, unless I'm all wet about where the error is > coming from, this *must* be happening during receipt of a command from > an external client. You were right. > Perhaps turning on log_connections would give you a clue about what it > is. thanks. Turning log_connections on helped me a lot! I found a buggy query from my postfix mailserver which retried the query every 4000 seconds. thanks again for this excellent database and excellent support. kind regards Janning > Also set log_line_prefix to make sure you can match up the error > report with the previous connection log entry (adding the PID is usually > enough). > > regards, tom lane