Message-ID: <4C35E61B.3010904@magwerks.com>
Date: Thu, 08 Jul 2010 09:52:11 -0500
From: Justin Graf <justin@magwerks.com>
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US;
	rv:1.9.1.10) Gecko/20100512 Thunderbird/3.0.5
MIME-Version: 1.0
To: pgsql-sql@postgresql.org, John <johnf@jfcomputer.com>
Subject: Re: strangest thing happened
References: <201007071259.03294.johnf@jfcomputer.com>
	<20100707204244.GB28181@rice.edu> <4C34FC50.6070203@magwerks.com>
	<201007071541.27248.johnf@jfcomputer.com>
In-Reply-To: <201007071541.27248.johnf@jfcomputer.com>
Content-Type: multipart/mixed; boundary="------------000407090200080909080904"

This is a multi-part message in MIME format.
--------------000407090200080909080904
Content-Type: text/plain; charset="utf-8"
Content-Transfer-Encoding: 7bit

On 7/7/2010 5:41 PM, John wrote:
> On Wednesday 07 July 2010 03:14:40 pm Justin Graf wrote:
>    
>> I would be looking at the log files for the Inserts into that table as a
>> means to track down what is the cause.  If there are no log files or
>> don't have enough detail, crank up the logging level and wait for it to
>> happen again???
>>      
>
> That is scary - let it happen again????  I'm not keeping enough info in the
> log.  I actually turned off most of the info the log files are gathering
> because the system has been running for 6-7 months without an issue.  I just
> got a call around noon telling me something was going wrong.  That's when I
> discovered the sequences were the wrong values.  I'm sure there has to be
> some sort of real explanation - but I don't know what it is.
>
> Johnf
>
>    

Sometimes we just don't have a choice but to let things become broke 
again to figure out what is the cause.

I had an odd case where Parent records could become deleted every once 
in a while.  For what appeared to be no rhyme or reason
The app had around 1000 functions in pg/psql not counting triggers,  so 
figuring out the cause by just staring at the code was not practical.
The log was already was set to record
     log_statement (all)
     log_line_prefix ('User %u, DB%d, Client%r, PID %p, Time %m, SID %c, 
LineCount %l , TID %x);
     log_destination ('csvlog')

The logs rotated out every 30 days.  So I had good sample of the 
commands sent to PG to figure out what went wrong

As the statements are logged all i had to do was search for
     Delete from cohead where cohead_id = XXXX

this gave me the transaction ID and the Session ID to start backtracking 
to see if a Trigger or Function issued the delete.  Once I had figured 
out that it was pg/psql procedure, i needed to figure out where in the 
application called this seriously miss thought out  DELETE Sales Order 
function.  I threw in a RAISE EXCEPTION in the psql and waited for the 
Data entry people to come screaming.

Around 3 weeks later a data entry girl came and found me asking to 
explain why her computer ordered her to come find me ASAP and why 
nothing else matter but stop and find me.

With that error, I now the call stack from the app to figure out the 
serious of events that allowed a Sales Order to be deleted.

After all was said and done there was a total of 50 records deleted out 
of 60,000 (not even 0.1%)  not a big deal unless you are customer who's 
order was deleted.

My experience has taught me never turn off logging because we never when 
we may need it.


All legitimate Magwerks Corporation quotations are sent in a .PDF file attachment with a unique ID number generated by our proprietary quotation system. Quotations received via any other form of communication will not be honored.

CONFIDENTIALITY NOTICE: This e-mail, including attachments, may contain legally privileged, confidential or other information proprietary to Magwerks Corporation and is intended solely for the use of the individual to whom it addresses. If the reader of this e-mail is not the intended recipient or authorized agent, the reader is hereby notified that any unauthorized viewing, dissemination, distribution or copying of this e-mail is strictly prohibited. If you have received this e-mail in error, please notify the sender by replying to this message and destroy all occurrences of this e-mail immediately.
Thank you.

--------------000407090200080909080904
Content-Type: text/x-vcard; charset="utf-8"
Content-Transfer-Encoding: base64
Content-Disposition: attachment;
 filename="justin.vcf"

YmVnaW46dmNhcmQNCmZuOkp1c3RpbiBHcmFmDQpuOkdyYWY7SnVzdGluDQpvcmc6TWFnd2Vy
a3MgQ29ycA0KYWRyOjs7NTAxIENvbW1lcmNlIERyaXZlO0RhbnZpbGxlIDtJTjs0NjEyMjtV
U0ENCmVtYWlsO2ludGVybmV0Omp1c3RpbkBtYWd3ZXJrcy5jb20NCnRlbDt3b3JrOjMxNy0y
NDEtODAxMSBleHQgNzAzDQp0ZWw7ZmF4OjMxNy0yNDEtODAxNQ0KeC1tb3ppbGxhLWh0bWw6
RkFMU0UNCnVybDp3d3cubWFnd2Vya3MuY29tDQp2ZXJzaW9uOjIuMQ0KZW5kOnZjYXJkDQoN
Cg==
--------------000407090200080909080904--