greenplum集群发生了某个节点报“could not open relation 1663/16384/32749972: 无此文件或目录”后再无法启动后的一个解决方法-唐成

本周三下午数据仓库的greenplum集群发生了某个数据节点报“could not open relation 1663/16384/32749972: 无此文件或目录”，然后这个节点就再也无法启动了，然后导致了整个集群无法启动。后面，数据仓库的同事通过从备节点拷贝整个数据库恢复了这个节点的数据库，由于数据库的数据大小有500G-600G，数据量比较大，所以恢复时间比较长，对业务有很大的影响。这个故障在几周前也出现过一次，本周四早上又出现过一次，所以是一个急需要解决的问题。我们想，能否有一种方法能让数据库正常启动，这样就不需要从备节点拷贝数据了。

我对此问题进行了详细分析：发现当数据库在启动过程中，在通过应用WAL日志（类似oracle的redo日志）做实例恢复时，需要文件“32749972”，而我们检查其它好的节点，却没有发现这个文件，所以基本认为，这个文件只是恢复过程中需要的一个文件，最终实际上并不需要这个文件，可能的场景是：一个表先insert了一些数据，然后又被truncate掉了，这时开始这个文件存在，且被insert了一些数据，最后由于truncate，这个文件被删除掉了，所以最终实际上是不需要这个文件的。我们想，如果先touch一个空的文件，然后再启动数据库，看数据库能否正常启动，这样做后，发现恢复过程中会自动把我们建的这个文件删除掉，然后再报同样的错误。从这个现象看，可能是数据库在记WAL日志时出现了某种错误、或软件bug。于是我想，如果恢复过程中让数据库先删除不掉这个文件，后面它再需要这个文件时，就不会发生找不到此文件的错误了。

那如何让系统无法删除这个文件呢？
可以这样做，写一个动态库，动态库中写一个删除函数unlink，然后设置环境变量LD_PRELOAD_64指向我写的这个动态库，然后再启动数据库，这样数据库调用删除函数unlink删除文件时，就会调用到我写的这个动态库中的unlink函数。然后我写的这个unlink函数中判断如果要删除的文件是32749972时，就不删除这个文件，直接返加0，这样让数据库认为成功删除了这个文件，实际上这个文件没有被删除 。
我写的这个函数为：
int unlink(const char *path)
{
static int (*real_unlink)(const char * path) = NULL;
char * hookenv=getenv("FILEHOOK");
    char * filename;
    int len;
    len = strlen(path);

    filename = (char *)malloc(len+2);
    strcpy(filename,path);
    strcat(filename,",");
   
    if(strstr(hookenv,filename)!=NULL)
    {
        free(filename);
        return 0;
    }
    free(filename);

    if (!real_unlink)
    {
real_unlink = dlsym(RTLD_NEXT, "unlink");
if (!real_unlink)
        {
exit(20);
}
}

    return real_unlink(path);
}

注意，我这个函数读环境变量FILEHOOK，我们把环境变量FILEHOOK设置为：
export FILEHOOK=base/16384/32749972,base/16384/32749972.1,
这样，当恢复过程中删除文件32749972和32749972.1时，这两个文件实际并不会删除 。

下面开始我们的恢复过程：
export LD_PRELOAD_64='/export/home/gpadmin/filehook/filehook.so'
export FILEHOOK=base/16384/32749972,

启动数据库：
postgres -D /storagepool/gpdatap4_bak/aligp71/ -i -p 50004

发现数据库还是启动不起来，日志中报如下错误：
2011-03-04 10:57:12.568698 CST,,,p12300,th1,,,,0,,,seg-1,,,,,"WARNING","01000","page 33141 of relation 1663/16384/32749972 did not exist",,,,,,,0,,"xlogu
tils.c",186,
2011-03-04 10:57:12.569183 CST,,,p12300,th1,,,,0,,,seg-1,,,,,"PANIC","XX000","WAL contains references to invalid pages (xlogutils.c:193)",,,,,,,0,,"xlogu
tils.c",193,"Traceback 0: a11dc6: /opt/greenplum/greenplum-db-3.3.6.1/bin/postgres errstart+0x3e6

日志的意思是数据块“33141”不存在，由于greenplum中数据文件最大是1G，33141块的位置大约是1035M，超过了1G的大小，这样数据库就会把数据放到32749972.1的文件中。
而我们没有创建32749972.1的文件，看样子，我们还需要再建一个32749972.1的空文件。
建了再试：
touch /storagepool/gpdatap4_bak/aligp71/base/16384/32749972
touch /storagepool/gpdatap4_bak/aligp71/base/16384/32749972.1
export LD_PRELOAD_64='/export/home/gpadmin/filehook/filehook.so'
export FILEHOOK=base/16384/32749972,base/16384/32749972.1

数据库仍然报：
2011-03-04 13:35:09.988426 CST,,,p12748,th1,,,,0,,,seg-1,,,,,"WARNING","01000","page 33141 of relation 1663/16384/32749972 was uninitialized",,,,,,,0,,"x
logutils.c",182,
2011-03-04 13:35:09.988915 CST,,,p12748,th1,,,,0,,,seg-1,,,,,"PANIC","XX000","WAL contains references to invalid pages (xlogutils.c:193)",,,,,,,0,,"xlogu
tils.c",193,"Traceback 0: a11dc6: /opt/greenplum/greenplum-db-3.3.6.1/bin/postgres errstart+0x3e6

报33141块是一个未初使用化的数据块，把这个数据块读出来。
我以前写的一个blockcopy的工具，使用这个工具读这个数据块。
33141块超过了1G大小，33141块应该在32749972.1的文件中，前1G大小的块是32768块(32768*32K=1G)，那么这个块就是32749972.1中的第373个块，也就是在文件32749972.1的11936k的偏移量处，读这个块：
blockcopy /storagepool/gpdatap4_bak/aligp71/base/16384/32749972 11936k 32k tang1.dat 0
然后看内容：
od -t x1 tang1.dat |more
发现原来全是0，怪不得报“was uninitialize”，于是我想拷贝一个正确的块，把这个块覆盖掉，能否就可以了呢：

先把下一个块拷贝出来：
blockcopy /storagepool/gpdatap4_bak/aligp71/base/16384/32749972 11968k 32k tang2.dat 0
然后看内容:
od -t x1 tang2.dat |more
发现不是全零，可以使用。
把这个块覆盖回去：
blockcopy tang2.dat 0 32k /storagepool/gpdatap4_bak/aligp71/base/16384/32749972 11936k

然后再启动数据库，日志中出现“database system is ready”，数据库终于启动起来了。

011-03-04 15:29:24.254245 CST,,,p13035,th1,,,,0,,,seg-1,,,,,"LOG","00000","next MultiXactId: 1; next MultiXactOffset: 0",,,,,,,0,,"xlog.c",5746,
2011-03-04 15:29:24.254403 CST,,,p13035,th1,,,,0,,,seg-1,,,,,"LOG","00000","database system was not properly shut down; automatic recovery in progress",,
,,,,,0,,"xlog.c",5829,
2011-03-04 15:29:24.264931 CST,,,p13035,th1,,,,0,,,seg-1,,,,,"LOG","00000","redo starts at 3C4/F85DB258",,,,,,,0,,"xlog.c",5893,
2011-03-04 15:29:25.417542 CST,,,p13035,th1,,,,0,,,seg-1,,,,,"LOG","00000","recovery restart point at 3C4/F85DB258",,,,,"xlog redo checkpoint: redo 3C4/F
85DB258; undo 0/0; tli 1; xid 0/16208151; oid 32752070; multi 1; offset 0; online",,0,,"xlog.c",7283,
2011-03-04 15:31:33.492538 CST,,,p13035,th1,,,,0,,,seg-1,,,,,"LOG","00000","record with zero length at 3C5/31EB7BF8",,,,,,,0,,"xlog.c",3725,
2011-03-04 15:31:33.492623 CST,,,p13035,th1,,,,0,,,seg-1,,,,,"LOG","00000","redo done at 3C5/31EB7BC0",,,,,,,0,,"xlog.c",5979,
2011-03-04 15:31:33.492814 CST,,,p13035,th1,,,,0,,,seg-1,,,,,"LOG","00000","end of transaction log location is 3C5/31EB7BF8",,,,,,,0,,"xlog.c",5998,
2011-03-04 15:31:35.816999 CST,,,p13035,th1,,,,0,,,seg-1,,,,,"LOG","00000","database system is ready",,,,,,,0,,"xlog.c",6189,
2011-03-04 15:31:35.817076 CST,,,p13035,th1,,,,0,,,seg-1,,,,,"LOG","00000","PostgreSQL 8.2.13 (Greenplum Database 3.3.6.1 build 1) on x86_64-pc-solaris2.
10, compiled by GCC gcc.exe (GCC) 4.1.1 compiled on Apr  2 2010 16:29:41",,,,,,,0,,"xlog.c",6199,

当然这个方法只是一个临时的解决方法，后面我们会联系greenplum公司的人，分析这个问题产生的根本原因，最终解决这个问题。

 

Greenplum扩展阅读：http://baike.baidu.com/view/2101242.htm