ERROR: left link changed unexpectedly

Anyone interested ?

Regards
Gaetano Mendola

Gaetano Mendola wrote:

Hi all,
in my development server running a 7.4.5 I can replicate
continuously this error:

ERROR: left link changed unexpectedly

I obtain this with a vacuum full:

test=# vacuum full verbose ua_user_data_exp;
INFO: vacuuming "public.ua_user_data_exp"
INFO: "ua_user_data_exp": found 361471 removable, 20867 nonremovable
row versions in 28373 pages
DETAIL: 0 dead row versions cannot be removed yet.
Nonremovable row versions range from 432 to 1060 bytes long.
There were 0 unused item pointers.
Total free space (including removable row versions) is 218782956 bytes.
26761 pages are or will become empty, including 0 at the end of the table.
27543 pages containing 218591140 free bytes are potential move
destinations.
CPU 1.73s/0.40u sec elapsed 17.66 sec.
INFO: index "exp_id_provider" now contains 20867 row versions in 1077
pages
DETAIL: 0 index row versions were removed.
1003 index pages have been deleted, 1003 are currently reusable.
CPU 0.05s/0.06u sec elapsed 4.87 sec.
INFO: index "exp_ci_login" now contains 20867 row versions in 1832 pages
DETAIL: 0 index row versions were removed.
866 index pages have been deleted, 866 are currently reusable.
CPU 0.18s/0.02u sec elapsed 12.96 sec.
^[INFO: index "exp_country" now contains 20867 row versions in 1341 pages
DETAIL: 0 index row versions were removed.
1187 index pages have been deleted, 1187 are currently reusable.
CPU 0.11s/0.05u sec elapsed 5.89 sec.
INFO: index "exp_os_type" now contains 20867 row versions in 1333 pages
DETAIL: 0 index row versions were removed.
1237 index pages have been deleted, 1237 are currently reusable.
CPU 0.05s/0.03u sec elapsed 5.84 sec.
INFO: index "exp_card" now contains 20867 row versions in 1417 pages
DETAIL: 0 index row versions were removed.
1288 index pages have been deleted, 1288 are currently reusable.
CPU 0.09s/0.02u sec elapsed 6.14 sec.
ERROR: left link changed unexpectedly

last lines in the logs ( with verbose on ):

Oct 1 21:35:31 porto postgres[31356]: [1268-5] LOCATION: vacuum_index,
vacuum.c:2728
Oct 1 21:35:38 porto postgres[31356]: [1269-1] ERROR: XX000: left link
changed unexpectedly
Oct 1 21:35:38 porto postgres[31356]: [1269-2] LOCATION: _bt_pagedel,
nbtpage.c:888

I don't care to fix the problem immediatelly, so if you want dig on it
let me
know.

Regards
Gaetano Mendola

---------------------------(end of broadcast)---------------------------
TIP 6: Have you searched our list archives?

http://archives.postgresql.org

On Tue, Oct 05, 2004 at 12:08:26AM +0200, Gaetano Mendola wrote:

Anyone interested ?

I saw the code involved, and I think the only way this can happen is if
the index file itself was corrupted by previous operation. How could
that happen elludes me; maybe a previous VACUUM changed a sibling's side
pointer but not the page itself's. This is hard to believe however.
Maybe a partial write of some kind; but WAL should save whole-page
snapshots of the four pages involved, so I don't think the corruption
would survive WAL replay (that part of the code I didn't read however).

Not sure what to do about it. I assume that if you reindex, the problem
disappears and you can't reproduce it again? In any case, please save a
copy of the corrupted index file(s). Would you send it to me?

Gaetano Mendola wrote:

Hi all,
in my development server running a 7.4.5 I can replicate
continuously this error:

ERROR: left link changed unexpectedly

I obtain this with a vacuum full:

test=# vacuum full verbose ua_user_data_exp;
INFO: vacuuming "public.ua_user_data_exp"
INFO: "ua_user_data_exp": found 361471 removable, 20867 nonremovable
row versions in 28373 pages
DETAIL: 0 dead row versions cannot be removed yet.
Nonremovable row versions range from 432 to 1060 bytes long.
There were 0 unused item pointers.
Total free space (including removable row versions) is 218782956 bytes.
26761 pages are or will become empty, including 0 at the end of the table.
27543 pages containing 218591140 free bytes are potential move
destinations.
CPU 1.73s/0.40u sec elapsed 17.66 sec.
INFO: index "exp_id_provider" now contains 20867 row versions in 1077
pages
DETAIL: 0 index row versions were removed.
1003 index pages have been deleted, 1003 are currently reusable.
CPU 0.05s/0.06u sec elapsed 4.87 sec.
INFO: index "exp_ci_login" now contains 20867 row versions in 1832 pages
DETAIL: 0 index row versions were removed.
866 index pages have been deleted, 866 are currently reusable.
CPU 0.18s/0.02u sec elapsed 12.96 sec.
^[INFO: index "exp_country" now contains 20867 row versions in 1341 pages
DETAIL: 0 index row versions were removed.
1187 index pages have been deleted, 1187 are currently reusable.
CPU 0.11s/0.05u sec elapsed 5.89 sec.
INFO: index "exp_os_type" now contains 20867 row versions in 1333 pages
DETAIL: 0 index row versions were removed.
1237 index pages have been deleted, 1237 are currently reusable.
CPU 0.05s/0.03u sec elapsed 5.84 sec.
INFO: index "exp_card" now contains 20867 row versions in 1417 pages
DETAIL: 0 index row versions were removed.
1288 index pages have been deleted, 1288 are currently reusable.
CPU 0.09s/0.02u sec elapsed 6.14 sec.
ERROR: left link changed unexpectedly

last lines in the logs ( with verbose on ):

Oct 1 21:35:31 porto postgres[31356]: [1268-5] LOCATION: vacuum_index,
vacuum.c:2728
Oct 1 21:35:38 porto postgres[31356]: [1269-1] ERROR: XX000: left link
changed unexpectedly
Oct 1 21:35:38 porto postgres[31356]: [1269-2] LOCATION: _bt_pagedel,
nbtpage.c:888

I don't care to fix the problem immediatelly, so if you want dig on it
let me
know.

--
Alvaro Herrera (<alvherre[a]dcc.uchile.cl>)
"Crear es tan dif�cil como ser libre" (Elsa Triolet)

Alvaro Herrera wrote:

On Tue, Oct 05, 2004 at 12:08:26AM +0200, Gaetano Mendola wrote:

Anyone interested ?

I saw the code involved, and I think the only way this can happen is if
the index file itself was corrupted by previous operation. How could
that happen elludes me; maybe a previous VACUUM changed a sibling's side
pointer but not the page itself's. This is hard to believe however.
Maybe a partial write of some kind; but WAL should save whole-page
snapshots of the four pages involved, so I don't think the corruption
would survive WAL replay (that part of the code I didn't read however).

Not sure what to do about it. I assume that if you reindex, the problem
disappears and you can't reproduce it again? In any case, please save a
copy of the corrupted index file(s). Would you send it to me?

If you need the file for the index exp_card then I'm going to send you
the file.

Regards
Gaetano Mendola