Re: Strange problem with create table as select * from table; - Mailing list pgsql-general

From hubert depesz lubaczewski
Subject Re: Strange problem with create table as select * from table;
Date
Msg-id 20111104201702.GA20219@depesz.com
Whole thread Raw
In response to Re: Strange problem with create table as select * from table;  (hubert depesz lubaczewski <depesz@depesz.com>)
Responses Re: Strange problem with create table as select * from table;  (Adrian Klaver <adrian.klaver@gmail.com>)
Re: Strange problem with create table as select * from table;  (Tom Lane <tgl@sss.pgh.pa.us>)
List pgsql-general
On Thu, Nov 03, 2011 at 11:03:45PM +0100, hubert depesz lubaczewski wrote:
> looking for some other info. will post as soon as i'll gather it, but
> that will be in utc morning :(


I looked closer at the rows that got -1 xobject_id.
$ select magic_id, count(*) from qqq where xobject_id = -1 group by 1 order by 1;

                                                                              
 magic_id | count
----------+-------
 30343295 |     2
 30408831 |     3
 30539903 |     1
 30605439 |     2
 30670975 |     3
 30802047 |     1
 30867583 |     1
 30933119 |     1
 31195263 |     2
 31260799 |     1
 31326335 |     1
 31588479 |     3
 31654015 |     1
 31719551 |     1
 31785087 |     3
 31850623 |     4
 31981695 |     2
 32047231 |     2
 32112767 |     1
 32309375 |     1
 32374911 |     1
 32440447 |     1
 32505983 |     2
(23 rows)

So, I checked original counts for these magic_id:

$ select magic_id, count(*) from sssssss.xobjects where magic_id in
(30343295,30408831,30539903,30605439,30670975,30802047,30867583,30933119,31195263,31260799,31326335,31588479,31654015,31719551,31785087,31850623,31981695,32047231,32112767,32309375,32374911,32440447,32505983)
groupby 1 order by 1; 
 magic_id | count
----------+-------
 30343295 |     1
 30408831 |     1
 30539903 |     1
 30605439 |     1
 30670975 |     1
 30802047 |     1
 30867583 |     1
 30933119 |     1
 31195263 |     1
 31260799 |     1
 31326335 |     1
 31588479 |     1
 31654015 |     1
 31719551 |     1
 31785087 |     1
 31850623 |     1
 31981695 |     1
 32047231 |     1
 32112767 |     1
 32309375 |     1
 32374911 |     1
 32440447 |     1
 32505983 |     1
(23 rows)

$ select min(magic_id), max(magic_id), count(distinct magic_id), sum( case when magic_id between 30343295 and 32505983
then1 else 0 end ) as count_in_range from sssssss.xobjects; 
 min  |   max    |  count   | count_in_range

                                                                              
------+----------+----------+----------------
 1000 | 37830834 | 32030523 |        2079327
(1 row)

So, the ids are not clustered.

at least the magic_id. but since these are more or less chronological, it means that these rows were added to db quite
sometime apart: 

 magic_id |     creation_tsz
----------+------------------------
 30343295 | 2011-05-28 00:57:36+00
 30408831 | 2011-05-30 01:51:09+00
 30539903 | 2011-06-02 04:06:20+00
 30605439 | 2011-06-03 18:23:06+00
 30670975 | 2011-06-05 16:49:49+00
 30802047 | 2011-06-08 16:46:22+00
 30867583 | 2011-06-10 01:39:41+00
 30933119 | 2011-06-11 19:48:07+00
 31195263 | 2011-06-18 00:33:24+00
 31260799 | 2011-06-20 01:49:46+00
 31326335 | 2011-06-21 17:53:41+00
 31588479 | 2011-06-28 07:07:19+00
 31654015 | 2011-06-29 20:30:52+00
 31719551 | 2011-07-01 09:50:54+00
 31785087 | 2011-07-03 03:42:02+00
 31850623 | 2011-07-05 05:02:27+00
 31981695 | 2011-07-08 04:49:21+00
 32047231 | 2011-07-09 21:59:25+00
 32112767 | 2011-07-11 16:53:10+00
 32309375 | 2011-07-15 21:52:31+00
 32374911 | 2011-07-17 19:20:34+00
 32440447 | 2011-07-19 03:13:21+00
 32505983 | 2011-07-20 16:15:38+00

So, Let's see how the bad rows (-1) look, in comparison to good ones, in copy of the table:

$ select xobject_id, magic_id, creation_tsz from qqq where magic_id in
(30343295,30408831,30539903,30605439,30670975,30802047,30867583,30933119,31195263,31260799,31326335,31588479,31654015,31719551,31785087,31850623,31981695,32047231,32112767,32309375,32374911,32440447,32505983)
orderby 2, 1; 
 xobject_id | magic_id |      creation_tsz

                                                                              
------------+----------+------------------------
         -1 | 30343295 | 2011-05-28 17:24:58+00
         -1 | 30343295 | 2011-05-28 04:57:23+00
   33695980 | 30343295 | 2011-05-28 00:57:36+00
         -1 | 30408831 | 2011-05-31 04:25:44+00
         -1 | 30408831 | 2011-05-31 01:03:03+00
         -1 | 30408831 | 2011-05-30 14:52:29+00
   33761515 | 30408831 | 2011-05-30 01:51:09+00
         -1 | 30539903 | 2011-06-02 05:05:08+00
   33892588 | 30539903 | 2011-06-02 04:06:20+00
         -1 | 30605439 | 2011-06-05 05:13:01+00
         -1 | 30605439 | 2011-06-04 03:22:08+00
   33958124 | 30605439 | 2011-06-03 18:23:06+00
         -1 | 30670975 | 2011-06-05 17:54:06+00
         -1 | 30670975 | 2011-06-06 13:59:01+00
         -1 | 30670975 | 2011-06-06 14:44:22+00
   34023662 | 30670975 | 2011-06-05 16:49:49+00
         -1 | 30802047 | 2011-06-08 19:06:23+00
   34154737 | 30802047 | 2011-06-08 16:46:22+00
         -1 | 30867583 | 2011-06-11 03:35:12+00
   34220289 | 30867583 | 2011-06-10 01:39:41+00
         -1 | 30933119 | 2011-06-13 12:31:46+00
   34285828 | 30933119 | 2011-06-11 19:48:07+00
         -1 | 31195263 | 2011-06-20 01:08:40+00
         -1 | 31195263 | 2011-06-19 06:27:08+00
   34547974 | 31195263 | 2011-06-18 00:33:24+00
         -1 | 31260799 | 2011-06-21 09:10:19+00
   34613511 | 31260799 | 2011-06-20 01:49:46+00
         -1 | 31326335 | 2011-06-22 15:34:12+00
   34679047 | 31326335 | 2011-06-21 17:53:41+00
         -1 | 31588479 | 2011-06-29 00:10:51+00
         -1 | 31588479 | 2011-06-28 11:32:31+00
         -1 | 31588479 | 2011-06-29 10:37:13+00
   34941191 | 31588479 | 2011-06-28 07:07:19+00
         -1 | 31654015 | 2011-06-30 22:32:22+00
   35006735 | 31654015 | 2011-06-29 20:30:52+00
         -1 | 31719551 | 2011-07-03 02:04:12+00
   35072271 | 31719551 | 2011-07-01 09:50:54+00
         -1 | 31785087 | 2011-07-03 14:44:51+00
         -1 | 31785087 | 2011-07-03 17:05:13+00
         -1 | 31785087 | 2011-07-03 15:20:21+00
   35137807 | 31785087 | 2011-07-03 03:42:02+00
         -1 | 31850623 | 2011-07-06 17:51:30+00
         -1 | 31850623 | 2011-07-05 11:45:57+00
         -1 | 31850623 | 2011-07-06 09:58:26+00
         -1 | 31850623 | 2011-07-06 08:53:44+00
   35203343 | 31850623 | 2011-07-05 05:02:27+00
         -1 | 31981695 | 2011-07-08 09:19:59+00
         -1 | 31981695 | 2011-07-08 08:14:24+00
   35334415 | 31981695 | 2011-07-08 04:49:21+00
         -1 | 32047231 | 2011-07-11 16:45:51+00
         -1 | 32047231 | 2011-07-11 14:49:26+00
   35399951 | 32047231 | 2011-07-09 21:59:25+00
         -1 | 32112767 | 2011-07-11 17:51:43+00
   35465487 | 32112767 | 2011-07-11 16:53:10+00
         -1 | 32309375 | 2011-07-16 21:38:56+00
   35662095 | 32309375 | 2011-07-15 21:52:31+00
         -1 | 32374911 | 2011-07-18 07:04:27+00
   35727631 | 32374911 | 2011-07-17 19:20:34+00
         -1 | 32440447 | 2011-07-19 13:18:55+00
   35793169 | 32440447 | 2011-07-19 03:13:21+00
         -1 | 32505983 | 2011-07-21 12:04:21+00
         -1 | 32505983 | 2011-07-21 05:04:36+00
   35858705 | 32505983 | 2011-07-20 16:15:38+00
(63 rows)

What is important, that even if creation_tsz matches for given magic_id - data in other rows are very different - in a
waynot justifiable by simple update of rows. It looks like the content of the row would be made from some other rows? 

Checked the last magic_id that we have problems with: 32505983.

Original data:

$ select xobject_id, magic_id, some_column_01, some_column_2, creation_tsz, md5(xxxx) from qqq where magic_id =
32505983;
 xobject_id | magic_id | some_column_01 | some_column_2 |      creation_tsz      |               md5
------------+----------+----------------+---------------+------------------------+----------------------------------
   35858705 | 32505983 |        5209830 |       8536762 | 2011-07-20 16:15:38+00 | 59ecde2fa2758fa68db3199f5388771f
         -1 | 32505983 |        7492565 |      15395178 | 2011-07-21 05:04:36+00 | 6cadaeab659101ddec2b8b80ab10bea6
         -1 | 32505983 |        5325985 |      10853000 | 2011-07-21 12:04:21+00 | 887f30da9d60237e150e8b788aa3b68c
(3 rows)

$ select xobject_id, magic_id, some_column_01, some_column_2, creation_tsz, md5(xxxx) from sssssss.xobjects where
magic_id= 32505983; 
 xobject_id | magic_id | some_column_01 | some_column_2 |      creation_tsz      |               md5
------------+----------+----------------+---------------+------------------------+----------------------------------
   35858705 | 32505983 |        5209830 |       8536762 | 2011-07-20 16:15:38+00 | 59ecde2fa2758fa68db3199f5388771f
(1 row)

(the selected columns ate the first 6 columns of the table).

As you can see the row with correct xobject_id seems to be perfectly ok.

But what about the rows with xobject_id = -1 ? I used creation_tsz to find them:

$ select xobject_id, magic_id, some_column_01, some_column_2, creation_tsz, md5(xxxx) from sssssss.xobjects where
creation_tszin ('2011-07-21 05:04:36+00', '2011-07-21 12:04:21+00'); 
 xobject_id | magic_id | some_column_01 | some_column_2 |      creation_tsz      |               md5
------------+----------+----------------+---------------+------------------------+----------------------------------
   35891226 | 32538466 |        7492565 |      15395178 | 2011-07-21 05:04:36+00 | 6cadaeab659101ddec2b8b80ab10bea6
   35896800 | 32544040 |        5325985 |      10853000 | 2011-07-21 12:04:21+00 | 887f30da9d60237e150e8b788aa3b68c
(2 rows)

Please note that the rows match *perfectly* aside from the 2 first columns ?!

Let's look into some more, to get more rows to work on:

$ select xobject_id, magic_id, some_column_01, some_column_2, creation_tsz, md5(xxxx) from qqq where magic_id in
(31785087,31850623, 31981695, 31588479, 32505983) order by creation_tsz;
                                                                                     
 xobject_id | magic_id | some_column_01 | some_column_2 |      creation_tsz      |               md5

                                                                              
------------+----------+----------------+---------------+------------------------+----------------------------------
   34941191 | 31588479 |       14187503 |       5243045 | 2011-06-28 07:07:19+00 | fdf95dd37e1f37b8d38eee63bea8fd5c
         -1 | 31588479 |        6665439 |      10951593 | 2011-06-28 11:32:31+00 | 75da687e0823bca3594a52510c658d92
         -1 | 31588479 |        6665439 |      12887953 | 2011-06-29 00:10:51+00 | 6007e35f346df7da585bbfc137df6a20
         -1 | 31588479 |        5325985 |      15444995 | 2011-06-29 10:37:13+00 | 5eac30a00c8d81ca8979ab7f44d7f660
   35137807 | 31785087 |       11559453 |       5052671 | 2011-07-03 03:42:02+00 | 1beb042a8106465f52d8378937791631
         -1 | 31785087 |        5895587 |      10594827 | 2011-07-03 14:44:51+00 | 907fd04a01095ff719092cce391f12e3
         -1 | 31785087 |          41796 |       5785895 | 2011-07-03 15:20:21+00 | dd8c168feeaa78219de7f096824d11a1
         -1 | 31785087 |          64040 |        102195 | 2011-07-03 17:05:13+00 | d03f944d09e6554608d7756b19281526
   35203343 | 31850623 |       12948972 |       7508016 | 2011-07-05 05:02:27+00 | b1e0551397ee61658328a5ece7204a13
         -1 | 31850623 |       10222885 |      15216048 | 2011-07-05 11:45:57+00 | 329b26b67e0333b8c6e524a31150431e
         -1 | 31850623 |        7405758 |       7084671 | 2011-07-06 08:53:44+00 | 27fada1f5777d5b3005230fdc696d69c
         -1 | 31850623 |          21314 |       9122048 | 2011-07-06 09:58:26+00 | 0ad6292210386a3767111df35c2bec26
         -1 | 31850623 |       14364837 |      10260130 | 2011-07-06 17:51:30+00 | d16c07121570e370609493a68c4c4606
   35334415 | 31981695 |       14382062 |      15553123 | 2011-07-08 04:49:21+00 | ca66936edcd8f0e195bdaa3f0887332d
         -1 | 31981695 |          64040 |      10955898 | 2011-07-08 08:14:24+00 | 3d11154de2df1b0758f345df603f14b9
         -1 | 31981695 |          64040 |       7849141 | 2011-07-08 09:19:59+00 | 0593a4250cabf4e0fc90721a0586d5c9
   35858705 | 32505983 |        5209830 |       8536762 | 2011-07-20 16:15:38+00 | 59ecde2fa2758fa68db3199f5388771f
         -1 | 32505983 |        7492565 |      15395178 | 2011-07-21 05:04:36+00 | 6cadaeab659101ddec2b8b80ab10bea6
         -1 | 32505983 |        5325985 |      10853000 | 2011-07-21 12:04:21+00 | 887f30da9d60237e150e8b788aa3b68c
(19 rows)

$ select xobject_id, magic_id, some_column_01, some_column_2, creation_tsz, md5(xxxx) from sssssss.xobjects where
creation_tszin ( select creation_tsz from qqq where magic_id in (31785087, 31850623, 31981695, 31588479, 32505983) and
xobject_id= -1 ) order by creation_tsz;                                              
 xobject_id | magic_id | some_column_01 | some_column_2 |      creation_tsz      |               md5

                                                                              
------------+----------+----------------+---------------+------------------------+----------------------------------
   34943757 | 31591045 |        5801572 |      14146975 | 2011-06-28 11:32:31+00 | 1fb5d088e9be92609f5d2d237033ff71
(irrelevantrow with the same creation_tsz as relevant row) 
   34943758 | 31591046 |        6665439 |      10951593 | 2011-06-28 11:32:31+00 | 75da687e0823bca3594a52510c658d92
   34971890 | 31619170 |        6665439 |      12887953 | 2011-06-29 00:10:51+00 | 6007e35f346df7da585bbfc137df6a20
   34986625 | 31633905 |        5325985 |      15444995 | 2011-06-29 10:37:13+00 | 5eac30a00c8d81ca8979ab7f44d7f660
   35146513 | 31793793 |        5895587 |      10594827 | 2011-07-03 14:44:51+00 | 907fd04a01095ff719092cce391f12e3
   35146514 | 31793794 |        6451300 |      11916744 | 2011-07-03 14:44:51+00 | ca3ae62f59cf76e75ee39dad6762cf16
(irrelevantrow with the same creation_tsz as relevant row) 
   35147344 | 31794624 |        5665781 |      11816238 | 2011-07-03 15:20:21+00 | 42017de7cb7227b25c4092ba0619b18e
(irrelevantrow with the same creation_tsz as relevant row) 
   35147343 | 31794623 |          41796 |       5785895 | 2011-07-03 15:20:21+00 | dd8c168feeaa78219de7f096824d11a1
   35150207 | 31797487 |          64040 |        102195 | 2011-07-03 17:05:13+00 | d03f944d09e6554608d7756b19281526
   35207670 | 31854950 |       10222885 |      15216048 | 2011-07-05 11:45:57+00 | 329b26b67e0333b8c6e524a31150431e
   35248094 | 31895374 |        7405758 |       7084671 | 2011-07-06 08:53:44+00 | 27fada1f5777d5b3005230fdc696d69c
   35248630 | 31895910 |          21314 |       9122048 | 2011-07-06 09:58:26+00 | 0ad6292210386a3767111df35c2bec26
   35262548 | 31909828 |       14364837 |      10260130 | 2011-07-06 17:51:30+00 | d16c07121570e370609493a68c4c4606
   35262549 | 31909829 |       15304799 |       9494587 | 2011-07-06 17:51:30+00 | d70ab6ca0bd99726d3dd66f7287974c5
(irrelevantrow with the same creation_tsz as relevant row) 
   35337757 | 31985037 |          64040 |      10955898 | 2011-07-08 08:14:24+00 | 3d11154de2df1b0758f345df603f14b9
   35338337 | 31985617 |          64040 |       7849141 | 2011-07-08 09:19:59+00 | 0593a4250cabf4e0fc90721a0586d5c9
   35891226 | 32538466 |        7492565 |      15395178 | 2011-07-21 05:04:36+00 | 6cadaeab659101ddec2b8b80ab10bea6
   35896800 | 32544040 |        5325985 |      10853000 | 2011-07-21 12:04:21+00 | 887f30da9d60237e150e8b788aa3b68c
(18 rows)

So we have 14 missing xobject_ids:

$ select xobject_id from qqq where xobject_id in
(34943758,34971890,34986625,35146513,35147343,35150207,35207670,35248094,35248630,35262548,35337757,35338337,35891226,35896800);
 xobject_id

                                                                              
------------
(0 rows)

OK. So based on it all, it looks like for some rows, first two columns got mangled.

But why? System columns for the 14 rows in source table:

$ select xobject_id, ctid, xmin, xmax, cmin, cmax from sssssss.xobjects where xobject_id in
(34943758,34971890,34986625,35146513,35147343,35150207,35207670,35248094,35248630,35262548,35337757,35338337,35891226,35896800);
 xobject_id |     ctid     |   xmin    | xmax | cmin | cmax

                                                                              
------------+--------------+-----------+------+------+------
   35891226 | (1000302,18) | 103473550 |    0 |    8 |    8
   35896800 | (1037570,16) | 103541296 |    0 |    8 |    8
   34986625 | (3113025,5)  |  98897359 |    0 |    8 |    8
   35150207 | (3148101,3)  |  99819079 |    0 |    8 |    8
   35147343 | (3164551,5)  | 100274767 |    0 |    8 |    8
   35207670 | (3179416,9)  | 100564691 |    0 |    8 |    8
   35262548 | (3185219,2)  | 100685664 |    0 |    8 |    8
   35248630 | (3188532,7)  | 100742039 |    0 |    8 |    8
   35337757 | (3189663,9)  | 100782477 |    0 |    8 |    8
   35338337 | (3189785,8)  | 100792384 |    0 |    8 |    8
   35146513 | (3214806,6)  | 101489289 |    0 |    8 |    8
   35248094 | (3219436,2)  | 101542297 |    0 |    8 |    8
   34943758 | (3247211,6)  | 102143923 |    0 |    8 |    8
   34971890 | (3247212,8)  | 102143923 |    0 |    8 |    8
(14 rows)

Does it tell you anything?

Best regards,

depesz

--
The best thing about modern society is how easy it is to avoid contact with it.
                                                             http://depesz.com/

pgsql-general by date:

Previous
From: Rob Sargent
Date:
Subject: Re: psql is too slow to connect
Next
From: Adrian Klaver
Date:
Subject: Re: Strange problem with create table as select * from table;