Message-ID: <4B7A72DC.4020201@boozter.com>
Date: Tue, 16 Feb 2010 11:26:36 +0100
From: lionel duboeuf <lionel.duboeuf@boozter.com>
User-Agent: Thunderbird 2.0.0.23 (X11/20090817)
MIME-Version: 1.0
To: pgsql-performance@postgresql.org
Subject: Re: Almost infinite query -> Different Query Plan when
	changing where clause value
References: <4B790387020000250002F2CF@gw.wicourts.gov>
In-Reply-To: <4B790387020000250002F2CF@gw.wicourts.gov>
Content-Type: multipart/mixed; boundary="------------090607010609020106080302"

This is a multi-part message in MIME format.
--------------090607010609020106080302
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 8bit

Here is my log analysis:
Due to a database recovery task it appears that:

    I stopped postgresql
    I started postgresql (and as default autovacuum daemon)
    I restored the databases (need to restore 4 databases)
    It seems that after database 1 have been restored, autovacumm 
started on it and has been stopped while restoring database 2.
   
    @see log as attached


Here is backup/restore commands i use:

/usr/bin/pg_dump -i -h localhost -U postgres -F c -b -f  ... x 4 times

sudo -u postgres pg_restore -d 'database1' x 4 times


Does this kind of error can lead to the query problem  ?
If so, what would you suggest me to do to avoid the problem again ?.


Thanks
Lionel

   
Kevin Grittner a �crit :
> lionel duboeuf  wrote:
>   
>> Kevin Grittner a �crit :
>>     
>  
>   
>>> I just reread your original email, and I'm not sure I understand
>>> what you meant regarding VACUUM ANALYZE. If you run that right
>>> beforehand, do you still get the slow plan for user 10?
>>>       
>  
>   
>> I confirm by executing manual "VACUUM ANALYZE" that the problem is
>> solved.  But what i don't understand is that i would expect
>> autovacuum to do the job.
>>     
>  
> I think this is the crux of the issue.  Boosting the
> default_statistics_target or the statistics target for specific
> columns might help, reducing autovacuum_analyze_scale_factor might
> help, but I can't help wondering whether you inserted a large number
> of rows for user 10 and then ran the query to select user 10 before
> autovacuum had time to complete.  Does that seem possible?
>
> -Kevin
>
>   


--------------090607010609020106080302
Content-Type: text/plain;
 name="log_postgres"
Content-Transfer-Encoding: 8bit
Content-Disposition: inline;
 filename="log_postgres"

2010-02-10 12:24:25 CET LOG:  paquet de démarrage incomplet
2010-02-10 12:24:25 CET LOG:  a reçu une demande d'arrêt rapide
2010-02-10 12:24:25 CET LOG:  annulation des transactions actives
2010-02-10 12:24:25 CET LOG:  arrêt du processus autovacuum
2010-02-10 12:24:25 CET LOG:  arrêt en cours
2010-02-10 12:24:25 CET LOG:  le système de base de données est arrêté
2010-02-10 12:24:26 CET LOG:  n'a pas pu charger le fichier du certificat racine « root.crt » : aucun code d'erreur SSL rapporté
2010-02-10 12:24:26 CET DÉTAIL:  Ne vérifiera pas les certificats du client.
2010-02-10 12:24:26 CET LOG:  le système de bases de données a été arrêté à 2010-02-10 12:24:25 CET
2010-02-10 12:24:26 CET LOG:  le système de bases de données est prêt pour accepter les connexions
2010-02-10 12:24:26 CET LOG:  lancement du processus autovacuum
2010-02-10 12:24:26 CET LOG:  paquet de démarrage incomplet
[checkpoints Warning]
2010-02-10 12:24:34 CET LOG:  les points de vérification (checkpoints) arrivent trop fréquemment
        (toutes les 3 secondes)
2010-02-10 12:24:34 CET ASTUCE :  Considèrez l'augmentation du paramètre « checkpoint_segments ».
2010-02-10 12:24:39 CET LOG:  les points de vérification (checkpoints) arrivent trop fréquemment
        (toutes les 5 secondes)
2010-02-10 12:24:39 CET ASTUCE :  Considèrez l'augmentation du paramètre « checkpoint_segments ».
2010-02-10 12:24:43 CET LOG:  les points de vérification (checkpoints) arrivent trop fréquemment
        (toutes les 4 secondes)
2010-02-10 12:24:43 CET ASTUCE :  Considèrez l'augmentation du paramètre « checkpoint_segments ».
2010-02-10 12:24:47 CET LOG:  les points de vérification (checkpoints) arrivent trop fréquemment
        (toutes les 4 secondes)
2010-02-10 12:24:47 CET ASTUCE :  Considèrez l'augmentation du paramètre « checkpoint_segments ».
2010-02-10 12:24:52 CET LOG:  les points de vérification (checkpoints) arrivent trop fréquemment
        (toutes les 5 secondes)
2010-02-10 12:24:52 CET ASTUCE :  Considèrez l'augmentation du paramètre « checkpoint_segments ».
2010-02-10 12:24:56 CET LOG:  les points de vérification (checkpoints) arrivent trop fréquemment
        (toutes les 4 secondes)
2010-02-10 12:24:56 CET ASTUCE :  Considèrez l'augmentation du paramètre « checkpoint_segments ».
2010-02-10 12:25:01 CET LOG:  les points de vérification (checkpoints) arrivent trop fréquemment
        (toutes les 5 secondes)
[database 1 restore]
2010-02-10 12:25:03 CET INFO:  ALTER TABLE / ADD PRIMARY KEY créera un index implicite « pk_block » pour la table « block »
...
...
2010-02-10 12:25:13 CET INFO:  ALTER TABLE / ADD PRIMARY KEY créera un index implicite « pk_user_panel » pour la table « user_panel »
[here is autovacuum error]
2010-02-10 12:25:44 CET ERREUR:  annulation de la tâche d'autovacuum 
2010-02-10 12:25:44 CET CONTEXTE :  ANALYZE automatique de la table « boozterbase.public.translation »
2010-02-10 12:25:45 CET ERREUR:  annulation de la tâche d'autovacuum
2010-02-10 12:25:45 CET CONTEXTE :  ANALYZE automatique de la table « boozterbase.public.label »
2010-02-10 12:25:48 CET ERREUR:  annulation de la tâche d'autovacuum
2010-02-10 12:25:48 CET CONTEXTE :  ANALYZE automatique de la table « boozterbase.public.link »
[end autovacuum error]
[database 2 restore]
2010-02-10 12:25:53 CET INFO:  ALTER TABLE / ADD PRIMARY KEY créera un index implicite « Coordinate_pkey » pour la table « coordinate »
2010-02-10 12:25:53 CET INFO:  ALTER TABLE / ADD PRIMARY KEY créera un index implicite « compte_mail_pkey » pour la table « mail_account »
2010-02-10 12:25:53 CET INFO:  ALTER TABLE / ADD UNIQUE créera un index implicite « person_uid_uc » pour la table « person »
...
[nothing to see here]


--------------090607010609020106080302--