BUG #8612: Truncate did not release disk space - Mailing list pgsql-bugs

The following bug has been logged on the website:

Bug reference:      8612
Logged by:          Eduardo Armendariz
Email address:      eduardoa@mirthcorp.com
PostgreSQL version: 9.0.13
Operating system:   CentOS
Description:

Ran out of disk space and postgres shut down. Recovered enough disk space
for database to be operational. Truncated the largest table in the database,
the message table. This table had over 600gb of data. The result of the
truncate was that only about 200gb of the data was actually released to the
OS.


Made sure the data was actually in in the postgres directory:
[05:41 PM|V1000-04-3DE62003-0001|mirth primary device|/opt]# du -sh *
3.4M openvpn
380K pdmenu
437G pgsql


Size of tables after truncate of message table:
mirthdb=# SELECT relname AS "tablename",
pg_size_pretty(pg_total_relation_size(relid)) AS "total_usage",
pg_size_pretty(pg_total_relation_size(relid) - pg_relation_size(relid)) AS
"external_table_usage" FROM pg_catalog.pg_statio_user_tables ORDER BY
pg_total_relation_size(relid) DESC;


tablename | total_usage | external_table_usage
--------------------+-------------+----------------------
event | 101 MB | 85 MB
channel_statistics | 37 MB | 35 MB
channel | 1944 kB | 1808 kB
script | 1552 kB | 624 kB
message | 1032 kB | 768 kB
template | 168 kB | 160 kB
alert | 64 kB | 56 kB
person | 64 kB | 56 kB
configuration | 48 kB | 40 kB
person_password | 40 kB | 32 kB
channel_alert | 40 kB | 32 kB
alert_email | 40 kB | 32 kB
attachment | 24 kB | 24 kB
code_template | 16 kB | 16 kB
schema_info | 8192 bytes | 0 bytes


Here is the size of the actual mirthdb database though:
mirthdb=# SELECT pg_database.datname,
pg_size_pretty(pg_database_size(pg_database.datname)) AS size FROM
pg_database;
datname | size
----------+--------
template1 | 5329 kB
template0 | 5329 kB
postgres | 5457 kB
mirthdb | 465 GB
(4 rows)


I have never seen truncate behave this way and I am not able to explain this
behavior. Here is the logs around the time of the truncate:


2013-11-16 16:29:16 MST - LOG:  could not write temporary statistics file
"pg_stat_tmp/pgstat.tmp": No space left on device
2013-11-16 16:29:16 MST - LOG:  could not write temporary statistics file
"pg_stat_tmp/pgstat.tmp": No space left on2013-11-16 17:24:19 MST - LOG:
database system shutdown was interrupted; last known up at 2013-11-16
16:42:57 MST
2013-11-16 17:24:19 MST - LOG:  database system was not properly shut down;
automatic recovery in progress
2013-11-16 17:24:19 MST - LOG:  redo starts at CDE/EFFFEFF8
2013-11-16 17:24:19 MST - FATAL:  the database system is starting up
2013-11-16 17:24:20 MST - LOG:  record with zero length at CDE/F34E3B98
2013-11-16 17:24:20 MST - LOG:  redo done at CDE/F34E3B58
2013-11-16 17:24:20 MST - LOG:  last completed transaction was at log time
2013-11-16 16:42:53.361929-07
2013-11-16 17:24:20 MST - FATAL:  the database system is starting up
2013-11-16 17:24:21 MST - LOG:  autovacuum launcher started
2013-11-16 17:24:21 MST - LOG:  database system is ready to accept
connections
2013-11-16 17:32:51 MST - LOG:  automatic analyze of table
"mirthdb.public.channel_statistics" system usage: CPU 0.00s/0.00u sec
elapsed 0.04 sec
2013-11-16 17:32:52 MST - LOG:  automatic vacuum of table
"mirthdb.public.script": index scans: 1
    pages: 0 removed, 116 remain
    tuples: 294 removed, 346 remain
    system usage: CPU 0.00s/0.00u sec elapsed 0.08 sec
2013-11-16 17:32:52 MST - LOG:  automatic analyze of table
"mirthdb.public.script" system usage: CPU 0.00s/0.00u sec elapsed 0.03 sec
2013-11-16 17:33:52 MST - LOG:  automatic analyze of table
"mirthdb.public.message" system usage: CPU 0.00s/0.02u sec elapsed 0.15 sec
2013-11-16 17:33:57 MST - LOG:  automatic vacuum of table
"mirthdb.public.channel_statistics": index scans: 1
    pages: 0 removed, 228 remain
    tuples: 168 removed, 147 remain
    system usage: CPU 0.00s/0.00u sec elapsed 5.02 sec
2013-11-16 17:33:57 MST - LOG:  automatic analyze of table
"mirthdb.public.channel_statistics" system usage: CPU 0.00s/0.00u sec
elapsed 0.04 sec
2013-11-16 17:34:52 MST - LOG:  automatic vacuum of table
"mirthdb.pg_toast.pg_toast_2619": index scans: 1
    pages: 0 removed, 69 remain
    tuples: 207 removed, 37 remain
    system usage: CPU 0.00s/0.00u sec elapsed 0.13 sec


Thanks,
Eduardo Armendariz