Thread

1. WAL_DEBUG logs spurious data

   Markus Wanner <markus@bluegap.ch> — 2012-10-11T21:08:46Z

   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
   

2. Re: WAL_DEBUG logs spurious data

   Tom Lane <tgl@sss.pgh.pa.us> — 2012-10-11T22:11:45Z

   Markus Wanner <markus@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
   
   
   

3. Re: WAL_DEBUG logs spurious data

   Markus Wanner <markus@bluegap.ch> — 2012-10-11T22:21:31Z

   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
   
   
   

4. Re: WAL_DEBUG logs spurious data

   Tom Lane <tgl@sss.pgh.pa.us> — 2012-10-11T23:06:15Z

   Markus Wanner <markus@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
   
   
   

5. Re: WAL_DEBUG logs spurious data

   Markus Wanner <markus@bluegap.ch> — 2012-10-11T23:16:20Z

   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
   
   
   

6. Re: WAL_DEBUG logs spurious data

   Bruce Momjian <bruce@momjian.us> — 2013-01-25T21:27:18Z

   On Thu, Oct 11, 2012 at 07:06:15PM -0400, Tom Lane wrote:
   > Markus Wanner <markus@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  <bruce@momjian.us>        http://momjian.us
     EnterpriseDB                             http://enterprisedb.com
   
     + It's impossible for everything to be true. +