syslog fix
Since logging with syslog is a documented feature, we need to fix it
anyway, IMHO. Here is a proposed fix for "too long message" problem of
syslog.
Included patches do followings:
o modifies write_syslog in utils/misc/trace.c
o if the message is too long (currently longer than 128 bytes), then
divides into smaller message segments. "128" would be probably too
small for some platforms, but I don't how long is the actual safe
limit of syslog messages on particular platform (seems 512 is safe on
Linux, for example).
o division of the message is carefully done so that it does not break
the word boundary.
o each message is prefixed with [logid-seq] where logid is incremented
at each write_syslog call, and seq is incremented at each syslog call
within a write_syslog call. This will prevent syslog to suppress
"same" messages.
o tested on Linux (RH4.2) and FreeBSD 4.0.
Comments are welcome....
--
Tatsuo Ishii
BTW, here are some examples from actual syslog messages:
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-1] NOTICE: QUERY DUMP: { SEQSCAN :startup_cost 0.00 :total_cost 3.22 :rows 122 :width 81 :state <> :qptargetlist ({ TARGETENTRY
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-2] :resdom { RESDOM :resno 1 :restype 19 :restypmod -1 :resname typname :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false }
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-3] :expr { VAR :varno 1 :varattno 1 :vartype 19 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 1}} { TARGETENTRY :resdom {
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-4] RESDOM :resno 2 :restype 23 :restypmod -1 :resname typowner :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr {
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-5] VAR :varno 1 :varattno 2 :vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 2}} { TARGETENTRY :resdom { RESDOM
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-6] :resno 3 :restype 21 :restypmod -1 :resname typlen :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-7] 1 :varattno 3 :vartype 21 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 3}} { TARGETENTRY :resdom { RESDOM :resno 4
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-8] :restype 21 :restypmod -1 :resname typprtlen :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-9] :varattno 4 :vartype 21 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 4}} { TARGETENTRY :resdom { RESDOM :resno 5
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-10] :restype 16 :restypmod -1 :resname typbyval :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-11] :varattno 5 :vartype 16 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 5}} { TARGETENTRY :resdom { RESDOM :resno 6
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-12] :restype 18 :restypmod -1 :resname typtype :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-13] :varattno 6 :vartype 18 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 6}} { TARGETENTRY :resdom { RESDOM :resno 7
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-14] :restype 16 :restypmod -1 :resname typisdefined :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-15] :varattno 7 :vartype 16 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 7}} { TARGETENTRY :resdom { RESDOM :resno 8
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-16] :restype 18 :restypmod -1 :resname typdelim :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-17] :varattno 8 :vartype 18 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 8}} { TARGETENTRY :resdom { RESDOM :resno 9
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-18] :restype 26 :restypmod -1 :resname typrelid :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-19] :varattno 9 :vartype 26 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 9}} { TARGETENTRY :resdom { RESDOM :resno 10
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-20] :restype 26 :restypmod -1 :resname typelem :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-21] :varattno 10 :vartype 26 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 10}} { TARGETENTRY :resdom { RESDOM :resno 11
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-22] :restype 24 :restypmod -1 :resname typinput :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-23] :varattno 11 :vartype 24 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 11}} { TARGETENTRY :resdom { RESDOM :resno 12
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-24] :restype 24 :restypmod -1 :resname typoutput :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-25] :varattno 12 :vartype 24 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 12}} { TARGETENTRY :resdom { RESDOM :resno 13
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-26] :restype 24 :restypmod -1 :resname typreceive :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-27] :varattno 13 :vartype 24 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 13}} { TARGETENTRY :resdom { RESDOM :resno 14
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-28] :restype 24 :restypmod -1 :resname typsend :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-29] :varattno 14 :vartype 24 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 14}} { TARGETENTRY :resdom { RESDOM :resno 15
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-30] :restype 18 :restypmod -1 :resname typalign :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-31] :varattno 15 :vartype 18 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 15}} { TARGETENTRY :resdom { RESDOM :resno 16
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-32] :restype 25 :restypmod -1 :resname typdefault :reskey 0 :reskeyop 0 :ressortgroupref 0 :resjunk false } :expr { VAR :varno 1
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-33] :varattno 16 :vartype 25 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 16}}) :qpqual <> :lefttree <> :righttree <>
May 23 10:58:51 srapc968-yotsuya postgres[9902]: [1-34] :extprm () :locprm () :initplan <> :nprm 0 :scanrelid 1 }
May 23 10:58:51 srapc968-yotsuya postgres[9902]: NOTICE: QUERY PLAN: Seq Scan on pg_type (cost=0.00..3.22 rows=122 width=81)
Attachments:
syslog.patchtext/plain; charset=us-asciiDownload
*** postgresql-7.0/src/backend/utils/misc/trace.c.orig Mon May 22 09:01:13 2000
--- postgresql-7.0/src/backend/utils/misc/trace.c Tue May 23 10:40:58 2000
***************
*** 24,29 ****
--- 24,35 ----
#include "miscadmin.h"
#include "utils/trace.h"
+ #include <ctype.h>
+
+ #ifdef MULTIBYTE
+ #include "mb/pg_wchar.h"
+ #endif
+
/*
* We could support trace messages of indefinite length, as elog() does,
* but it's probably not worth the trouble. Instead limit trace message
***************
*** 204,219 ****
void
write_syslog(int level, char *line)
{
static int openlog_done = 0;
if (UseSyslog >= 1)
{
if (!openlog_done)
{
openlog_done = 1;
openlog(PG_LOG_IDENT, LOG_PID | LOG_NDELAY, PG_LOG_FACILITY);
}
! syslog(level, "%s", line);
}
}
--- 210,299 ----
void
write_syslog(int level, char *line)
{
+ #ifndef PG_SYSLOG_LIMIT
+ #define PG_SYSLOG_LIMIT 128
+ #endif /* PG_SYSLOG_LIMIT */
+
static int openlog_done = 0;
+ static char buf[PG_SYSLOG_LIMIT+1];
+ static int logid = 0;
if (UseSyslog >= 1)
{
+ int len = strlen(line);
+ int buflen;
+ int seq = 0;
+ int l;
+ int i;
+
if (!openlog_done)
{
openlog_done = 1;
openlog(PG_LOG_IDENT, LOG_PID | LOG_NDELAY, PG_LOG_FACILITY);
}
!
! /* divide into multiple syslog() calls if message is
! * too long
! */
! if (len > PG_SYSLOG_LIMIT)
! {
! logid++;
!
! while (len > 0)
! {
! strncpy(buf, line, PG_SYSLOG_LIMIT);
! buf[PG_SYSLOG_LIMIT] = '\0';
!
! l = strlen(buf);
! #ifdef MULTIBYTE
! /* trim to multibyte letter boundary */
! buflen = pg_mbcliplen(buf, l, l);
! buf[buflen] = '\0';
! l = strlen(buf);
! #endif
! /* already word boundary? */
! if (isspace(line[l]) || line[l] == '\0')
! {
! buflen = l;
! }
! else
! {
! /* try to divide in word boundary */
! i = l - 1;
! while(i > 0 && !isspace(buf[i]))
! {
! i--;
! }
! if (i <= 0) /* couldn't divide word boundary */
! {
! buflen = l;
! }
! else
! {
! buflen = i;
! buf[i] = '\0';
! }
! }
!
! seq++;
! /*
! * Here we actually call syslog().
! * For segmented messages, we add logid
! * (incremented at each write_syslog call),
! * and seq (incremented at each syslog call
! * within a write_syslog call).
! * This will prevent syslog to surpress
! * "same" messages...
! */
! syslog(level, "[%d-%d] %s", logid, seq, buf);
! line += buflen;
! len -= buflen;
! }
! }
! else
! {
! syslog(level, "%s", line);
! }
}
}
Since logging with syslog is a documented feature, we need to fix it
anyway, IMHO. Here is a proposed fix for "too long message" problem of
syslog.Do you plan to get this into 7.0.1? If not, let me take your patch and
integrate it into my new configuration system, because all that code has
moved around quite a bit in there.
I would like the fix appear in 7.0.1.
--
Tatsuo Ishii
Import Notes
Reply to msg id not found: Pine.GSO.4.02A.10005231418470.20047-100000@Sparv.DoCS.UU.SE
Since logging with syslog is a documented feature, we need to fix it
anyway, IMHO. Here is a proposed fix for "too long message" problem of
syslog.Do you plan to get this into 7.0.1? If not, let me take your patch and
integrate it into my new configuration system, because all that code has
moved around quite a bit in there.I would like the fix appear in 7.0.1.
Fix comitted.
--
Tatsuo Ishii