VARCHAR 컬럼 사이즈 축소후 UPDATE 실행으로 인한 인포믹스 다운

안녕하세요. 인포믹스 12.10.FC12, 12.10.FC12W1, 14.10.FC1 버전에서 발생하는 문제를 소개드립니다.

문제가 발생한 이후부터는 인포믹스 프로세스가 시작되지 않으므로 매우 치명적인 결함입니다.

문제가 발생할 수 있는 조건은 아래와 같습니다.

1. 해당 테이블에 VARCHAR 컬럼을 추가한다.

2. 추가한 VARCHAR 컬럼의 사이즈를 축소한다.

위와 같은 상황에서 UPDATE 문장을 실행하면 오류가 발생하면서 인포믹스 프로세스가 다운됩니다.

그러나 항상 다운되는 것은 아니고 대상 테이블에 저장된 데이터 길이에 따라 다운될 수도, 다운되지 않을 수도 있습니다.

아래는 인포믹스 12.10.FC12와 14.10.FC1 버전의 환경에서 다운되는 현상을 재현했을 때의 로그 메시지입니다.

## 12.10.FC12W1

11:20:01  Assert Failed: Buffer modified in inconsistent chunk.

11:20:01  IBM Informix Dynamic Server Version 12.10.FC12W1WE

11:20:01   Who: Session(87, informix@pilma01, 39452766, 700000020593858)

                Thread(222, sqlexec, 700000020553068, 10)

                File: rsdebug.c Line: 1047

11:20:01   Results: Chunk 13 is being taken OFFLINE.

11:20:01   Action: Restore space containing this chunk from the archive.

11:20:01  stack trace for pid 36175890 written to /work2/ifx1210fc12w1we/tmp/af.4c6a350

11:20:02   See Also: /work2/ifx1210fc12w1we/tmp/af.4c6a350, shmem.4c6a350.0

11:20:10  Buffer modified in inconsistent chunk.

11:20:11  Assert Failed: INFORMIX-OnLine Must ABORT

        Critical media failure.

11:20:11  IBM Informix Dynamic Server Version 12.10.FC12W1WE

11:20:11   Who: Session(87, informix@pilma01, 39452766, 700000020593858)

                Thread(222, sqlexec, 700000020553068, 10)

                File: rsmirror.c Line: 2080

11:20:11  stack trace for pid 36175890 written to /work2/ifx1210fc12w1we/tmp/af.4c6a350

11:20:12   See Also: /work2/ifx1210fc12w1we/tmp/af.4c6a350

11:20:19  Thread ID 222 will NOT be suspended because

          it is in a critical section.

11:20:19   See Also: /work2/ifx1210fc12w1we/tmp/af.4c6a350

11:20:19  rsmirror.c, line 2080, thread 222, proc id 36175890, INFORMIX-OnLine Must ABORT

        Critical media failure..

11:20:19  Fatal error in ADM VP at mt_fn.c:14593

11:20:19  Unexpected virtual processor termination: pid = 36175890, exit status = 0x1.

11:20:19  PANIC: Attempting to bring system down

## 14.10.FC1DE

12:46:54  Assert Failed: Buffer modified in inconsistent chunk.

12:46:54  IBM Informix Dynamic Server Version 14.10.FC1DE

12:46:54   Who: Session(46, informix@ifxdb1, 62804, 0x4526fbc8)

                Thread(55, sqlexec, 4522d8c8, 1)

                File: rsdebug.c Line: 908

12:46:54   Results: Chunk 1 is being taken OFFLINE.

12:46:54   Action: Restore space containing this chunk from the archive.

12:46:54  stack trace for pid 62571 written to /opt/IBM/Informix_Software_Bundle/tmp/af.41fb7ad

12:46:54   See Also: /opt/IBM/Informix_Software_Bundle/tmp/af.41fb7ad, shmem.41fb7ad.0

12:46:57  Buffer modified in inconsistent chunk.

12:46:58  Assert Failed: INFORMIX-OnLine Must ABORT

        Critical media failure.

12:46:58  IBM Informix Dynamic Server Version 14.10.FC1DE

12:46:58   Who: Session(46, informix@ifxdb1, 62804, 0x4526fbc8)

                Thread(55, sqlexec, 4522d8c8, 1)

                File: rsmirror.c Line: 2062

12:46:58  stack trace for pid 62571 written to /opt/IBM/Informix_Software_Bundle/tmp/af.41fb7ad

12:46:58   See Also: /opt/IBM/Informix_Software_Bundle/tmp/af.41fb7ad

12:47:02  Thread ID 55 will NOT be suspended because

          it is in a critical section.

12:47:02   See Also: /opt/IBM/Informix_Software_Bundle/tmp/af.41fb7ad

12:47:02  Starting crash time check of:

12:47:02  1. memory block headers

12:47:02  2. stacks

12:47:02  Crash time checking found no problems

12:47:02  rsmirror.c, line 2062, thread 55, proc id 62571, INFORMIX-OnLine Must ABORT

        Critical media failure..

12:47:02  The Master Daemon Died

12:47:02  PANIC: Attempting to bring system down

관련 내용으로 IBM에 기술지원을 요청했었습니다.

해당 문제는 해외에서 발생한 사례가 이미 있었다고 하고 재현 시나리오도 구체적이진 않지만 존재했습니다.

관련 문제를 서술한 문서의 링크는 아래입니다.

http://www-01.ibm.com/support/docview.wss?crawler=1&uid=swg1IT27997

장애 재현시의 메시지 로그에서 보이는 assert failure file 내용을 살펴보니 해당 사용자 스레드의 stack trace를 확인할 수 있었습니다.

0x00000001000af9cc (oninit)afstack

0x00000001000aeb5c (oninit)afhandler

0x00000001000af038 (oninit)affail_interface

0x00000001001b8844 (oninit)buffcheck

0x00000001002371a0 (oninit)buffput

0x0000000100b88640 (oninit)ckpgversion

0x0000000100b87af4 (oninit)rewrecord

0x0000000100b870ec (oninit)rsrewrec

0x000000010071ab00 (oninit)fmrewrec

0x00000001008382a0 (oninit)aud_sqisrewrec

0x0000000100d40a90 (oninit)doupdate

0x0000000100d3ff2c (oninit)chkrowcons

0x000000010114ea04 (oninit)dodmlrow

0x0000000101150eac (oninit)dodelupd

0x000000010083ee30 (oninit)aud_dodelupd

0x0000000100d1ec24 (oninit)excommand

0x00000001008c8590 (oninit)sq_execute

0x00000001008103ac (oninit)sqmain

0x00000001014d6898 (oninit)listen_verify

0x00000001014d530c (oninit)spawn_thread

0x0000000101482ae0 (oninit)th_init_initgls

0x00000001018f86e0 (oninit)startup

defect IT27997에 대해 서술한 내용과 상당히 유사한 stack trace 임을 알 수 있었습니다.

stack trace 중에서 ckpgversion function 부분이 문제인 듯 합니다.

그리고 12.10.FC12 버전부터 In-place alter 기능이 개선되었다고 알려져있는데, 이 개선으로 인해 defect가 발생한 것이 아닌가 생각도 듭니다. 물론 제 추측이기 때문에 정확한 원인으로 보기는 어렵습니다.

IIUG2018의 발표자료중 Jeff McMahon and Nick Geib가 발표한 What’s New in Informix 장표를 살표보면 VARCHAR 에서 VARCHAR 간 (smaller or larger) 사이즈를 변경하는 유형도 In-place alter 방식으로 이루어진다고 나와 있습니다.

아래는 위의 IT27997의 내용을 토대로 작성한 장애재현 스크립트 내용입니다.

테스트용 데이터는 60자 고정길이 필드 한개로 만드시면 재현이 쉽습니다.

drop table test;

create table test (a varchar(60));

load from test.unl insert into test;

alter table test add b int;

alter table test add c varchar(5);

alter table test add d varchar(5);

alter table test add e varchar(5);

alter table test modify c varchar(1);

alter table test modify d varchar(1);

alter table test modify e varchar(1);

update test set a=' qui officia deserunt mollit anim id est laborum.Lorem ip';

해당 문제는 12.10.FC12 및 12.10.FC12W1 에서 발생하는 문제이므로 해당버전을 사용중이라면 IBM에 패치버전을 요청하시거나 12.10.FC11 이하 버전으로 다운그레이드하면 문제가 발생하지 않습니다.

참고가 되시길 바랍니다.