Re: [HACKERS] WAL_DEBUG logs spurious data
On Thu, Oct 11, 2012 at 07:06:15PM -0400, Tom Lane wrote: Markus Wanner mar...@bluegap.ch writes: On 10/11/2012 03:11 PM, Tom Lane wrote: The original design intention was that rm_desc should not attempt to print any such data, but obviously some folks didn't get the word. FWIW: in case the source code contains comments explaining that intention, I certainly missed them so far. Yeah, if we decide to stick with the limitation, some documentation would be called for. I remember having run into this and having removed functionality from an rm_desc function rather than question the premise. But maybe the extra functionality is worth the cycles. I assume there is no TODO item or patch here. -- Bruce Momjian br...@momjian.ushttp://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. + -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
[HACKERS] WAL_DEBUG logs spurious data
Hi,
I stumbled across a minor issue in xlog.c:1030: the WAL_DEBUG code block
there passes rdata-data to the rm_desc() methode. However, that's only
the first XLogRecData struct, not the entire XLog record. So the
rm_desc() method effectively reports spurious data for any subsequent part.
Take a commit record with subxacts as an example: during XLogInsert,
Postgres reports the following:
LOG: INSERT @ 0/16F3270: prev 0/16F3234; xid 688; len 16: Transaction -
commit: 2012-10-11 09:31:17.790368-07; subxacts: 3214563816
Note that the xid in subxacts is way off. During recovery from WAL, the
record is logged correctly:
LOG: REDO @ 0/16F3270; LSN 0/16F329C: prev 0/16F3234; xid 688; len 16:
Transaction - commit: 2012-10-11 09:31:17.790368-07; subxacts: 689
Attached is a possible fix.
Regards
Markus Wanner
*** a/src/backend/access/transam/xlog.c
--- b/src/backend/access/transam/xlog.c
***
*** 1033,1039 begin:;
#ifdef WAL_DEBUG
if (XLOG_DEBUG)
{
! StringInfoData buf;
initStringInfo(buf);
appendStringInfo(buf, INSERT @ %X/%X: ,
--- 1033,1056
#ifdef WAL_DEBUG
if (XLOG_DEBUG)
{
! StringInfoData buf;
! char *full_rec = palloc(write_len), *ins_ptr;
!
! /*
! * We need assemble the entire record once, to be able to dump it out
! * properly.
! */
! rdt = rdata;
! ins_ptr = full_rec;
! while (rdt)
! {
! if (rdt-data != NULL)
! {
! memcpy(ins_ptr, rdt-data, rdt-len);
! ins_ptr += rdt-len;
! }
! rdt = rdt-next;
! }
initStringInfo(buf);
appendStringInfo(buf, INSERT @ %X/%X: ,
***
*** 1042,1051 begin:;
if (rdata-data != NULL)
{
appendStringInfo(buf, - );
! RmgrTable[rechdr-xl_rmid].rm_desc(buf, rechdr-xl_info, rdata-data);
}
elog(LOG, %s, buf.data);
pfree(buf.data);
}
#endif
--- 1059,1069
if (rdata-data != NULL)
{
appendStringInfo(buf, - );
! RmgrTable[rechdr-xl_rmid].rm_desc(buf, rechdr-xl_info, full_rec);
}
elog(LOG, %s, buf.data);
pfree(buf.data);
+ pfree(full_rec);
}
#endif
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] WAL_DEBUG logs spurious data
Markus Wanner mar...@bluegap.ch writes: I stumbled across a minor issue in xlog.c:1030: the WAL_DEBUG code block there passes rdata-data to the rm_desc() methode. However, that's only the first XLogRecData struct, not the entire XLog record. So the rm_desc() method effectively reports spurious data for any subsequent part. The original design intention was that rm_desc should not attempt to print any such data, but obviously some folks didn't get the word. The question is whether we're willing to add a lot of cycles to XLOG_DEBUG mode in order to make the full record available for printing purposes. Not sure if it's a good tradeoff or not. regards, tom lane -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] WAL_DEBUG logs spurious data
Tom, On 10/11/2012 03:11 PM, Tom Lane wrote: The original design intention was that rm_desc should not attempt to print any such data, but obviously some folks didn't get the word. FWIW: in case the source code contains comments explaining that intention, I certainly missed them so far. Regards Markus -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] WAL_DEBUG logs spurious data
Markus Wanner mar...@bluegap.ch writes: On 10/11/2012 03:11 PM, Tom Lane wrote: The original design intention was that rm_desc should not attempt to print any such data, but obviously some folks didn't get the word. FWIW: in case the source code contains comments explaining that intention, I certainly missed them so far. Yeah, if we decide to stick with the limitation, some documentation would be called for. I remember having run into this and having removed functionality from an rm_desc function rather than question the premise. But maybe the extra functionality is worth the cycles. regards, tom lane -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
Re: [HACKERS] WAL_DEBUG logs spurious data
On 10/11/2012 04:06 PM, Tom Lane wrote: Yeah, if we decide to stick with the limitation, some documentation would be called for. I remember having run into this and having removed functionality from an rm_desc function rather than question the premise. But maybe the extra functionality is worth the cycles. Well, I've been interested in getting it correct, and didn't care about performance. But I can certainly imagine someone enabling it on a production system to get more debug info. In which case performance would matter more. However, WAL_DEBUG being a #define, I bet only very few admins do that. So I tend towards sacrificing performance for better debug info in the WAL_DEBUG case. (Especially given that you can still disable it via GUC). Regards Markus -- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers
