Re: Strange problem with create table as select * from table;

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) group by 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 then 1 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 some time 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) order by 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 way not 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_tsz in ('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_tsz in ( 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 (irrelevant row 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 (irrelevant row with the same creation_tsz as relevant row)
35147344 | 31794624 | 5665781 | 11816238 | 2011-07-03 15:20:21+00 | 42017de7cb7227b25c4092ba0619b18e (irrelevant row 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 (irrelevant row 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/