Re: pg 8.3beta 2 restore db with autovacuum report

with autovacuum enabled with default settings, cramd.sql is 154M:

andy(at)slacker:/pub/back$ time pg_restore -Fc -C -d postgres cramd.sql

real 3m43.687s
user 0m11.689s
sys 0m0.868s
andy(at)slacker:/pub/back$

during restore we see scary things like:

root(at)slacker:~# ps awx|grep postgres
2497 ? Ss 0:00 postgres: logger process
2499 ? Ss 0:00 postgres: writer process
2500 ? Ss 0:00 postgres: wal writer process
2501 ? Ss 0:00 postgres: autovacuum launcher process
2502 ? Ss 0:00 postgres: stats collector process
2519 pts/0 S+ 0:12 pg_restore -Fc -C -d postgres cramd.sql
2521 ? Ss 1:04 postgres: andy cramd [local] CREATE INDEX
waiting
2526 ? Ss 0:03 postgres: autovacuum worker process cramd
2571 ? Ss 0:01 postgres: autovacuum worker process cramd
2582 pts/1 R+ 0:00 grep postgres

Now I dropdb and disable autovacuum, restart pg:

andy(at)slacker:/pub/back$ time ( pg_restore -Fc -C -d postgres cramd.sql;
vacuumdb -z cramd )

real 3m47.229s
user 0m9.933s
sys 0m0.744s

Sweet, about the same amount of time.
Performed on my laptop, an asus m5n, running slackware 12

-Andy

andy wrote:
>
> with autovacuum enabled with default settings, cramd.sql is 154M:
>
> andy(at)slacker:/pub/back$ time pg_restore -Fc -C -d postgres cramd.sql
>
> real 3m43.687s

[...]

> Now I dropdb and disable autovacuum, restart pg:
>
> andy(at)slacker:/pub/back$ time ( pg_restore -Fc -C -d postgres cramd.sql;
> vacuumdb -z cramd )
>
> real 3m47.229s
> user 0m9.933s
> sys 0m0.744s
>
> Sweet, about the same amount of time.

Thanks. I find it strange that it takes 3 minutes to restore a 150 MB
database ... do you have many indexes?

Even though the restore times are very similar, I find it a bit
disturbing that the "CREATE INDEX" is shown to be waiting. Was it just
bad luck that the ps output shows it that way, or does it really wait
for long?

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

Alvaro,

On 11/2/07, Alvaro Herrera <alvherre(at)commandprompt(dot)com> wrote:
> Even though the restore times are very similar, I find it a bit
> disturbing that the "CREATE INDEX" is shown to be waiting. Was it just
> bad luck that the ps output shows it that way, or does it really wait
> for long?

I did the test again with the reference database I used a month ago.

My previous figures with 8.3devel of October 1st were:
- autovacuum off: 14m39
- autovacuum on, delay 20: 51m37

With 8.3devel of today, I have:
- autovacuum on, delay 20: 15m26

I can see (CREATE INDEX|ALTER TABLE) waiting from time to time in my
watch -n 1 but it disappears within 1 or 2 seconds so what Simon and
you did seems to work as expected AFAICS.

--
Guillaume

Alvaro Herrera wrote:
> andy wrote:
>> with autovacuum enabled with default settings, cramd.sql is 154M:
>>
>> andy(at)slacker:/pub/back$ time pg_restore -Fc -C -d postgres cramd.sql
>>
>> real 3m43.687s
>
> [...]
>
>> Now I dropdb and disable autovacuum, restart pg:
>>
>> andy(at)slacker:/pub/back$ time ( pg_restore -Fc -C -d postgres cramd.sql;
>> vacuumdb -z cramd )
>>
>> real 3m47.229s
>> user 0m9.933s
>> sys 0m0.744s
>>
>> Sweet, about the same amount of time.
>
> Thanks. I find it strange that it takes 3 minutes to restore a 150 MB
> database ... do you have many indexes?
>
> Even though the restore times are very similar, I find it a bit
> disturbing that the "CREATE INDEX" is shown to be waiting. Was it just
> bad luck that the ps output shows it that way, or does it really wait
> for long?
>

There are about 800 tables, each has one index. Most tables (75%) are
very small, the rest have, maybe 50K rows.

I had to run the ps several times to catch it waiting. It didnt seem to
wait too long.

It was run on my laptop, which may not have the best io times in the
world (and it only has 512 Meg ram).

-Andy

Guillaume Smet wrote:

> I did the test again with the reference database I used a month ago.
>
> My previous figures with 8.3devel of October 1st were:
> - autovacuum off: 14m39
> - autovacuum on, delay 20: 51m37
>
> With 8.3devel of today, I have:
> - autovacuum on, delay 20: 15m26

Yay! Thanks!

(It does take a bit longer, but I'm not really concerned about it.)

--
Alvaro Herrera http://www.amazon.com/gp/registry/5ZYLFMCVHXC
"En las profundidades de nuestro inconsciente hay una obsesiva necesidad
de un universo lógico y coherente. Pero el universo real se halla siempre
un paso más allá de la lógica" (Irulan)