星期六, 九月 29, 2007

福无双至,祸不单行

Prima 的那一套东西实在不敢恭维。本来软件的一个目的就是要和硬件分离,结果他们搞的许可证和硬件绑在一起,令人深受其害。而且其可管理性也不好,只能按单个主机的方式排列,如果想要实现真正的集群,那似乎是没有希望了。

昨天下午 wdwd 重启了一次(搬机器的时候掉电了),本来已经忙了一天了——早上肚子里还在翻江倒海,数据库的硬盘就坏了,想找个替手的人都没有(就我一个 SA),急急忙忙处理了备份恢复,检测确诊,写笔记,中间还时不时抛过来一些杂七杂八的事情,然后又要和机房联系,急急忙忙跑过去把损坏的硬盘拿出来,在机房磨了两个小时,做 ts,——晚上回去还没进门,同事打电话跟我说发现所有的新的订单都变成“待处理”,听说上线的消息已经在各大网站发布(反正没给我说过,也没有接到过消息,反正是他们这些老板出钱,又有关系,他们想怎么干就怎么干好了,何必问我们)。 Prima 没有其他报警机制,只好回去查后台和日志,发现"License not match"。但这个 license 是昨天刚刚申请的正式授权证书,之前是运行“正常”的!

我尝试重新上载那个授权证书,结果报告“序列号不符”。解开证书的压缩包,查看 license.info 中的 serial,确实与 /usr/prima/bin/print_serial 的结果不一样。再次重启这台主机,发现序列号又变了!

从昨天晚上折腾到今天下午(晚上别指望能找到人),最后查出来原因是主机每次启动的时候,板载的那块网卡会自动改变 MAC 地址!!!而 Prima 的许可证要根据所谓 CPU 个数、频率和网卡 MAC 地址来生成序列号,然后授权证书要用到这个序列号,一套很复杂的设置,晕 @_@~~~

最后,只好在系统 /etc/rc.d/rc.local 里面每次启动时自动改一下 MAC 地址:
/sbin/ifconfig eth0 hw ether 00:00:6C:92:4E:19
我后来问 Prima 是不是我更换网卡后把新网卡的 MAC 地址设置和以前一样就可以,回复说没有测过。没有测过!!!其实他们没有测过的东西也不少了,耗了我不少时间精力。我个人感觉 Prima 就是一个坑,一台主机什么都干的单主机排列的方式不利于实现集群和扩展,而且这种许可证方法使得高可用的代价更高了,和硬件绑定也不是什么好事 ... 商业软件,反而让人更不放心。

其实不仅他们没有严格测过,我们现在在生产线上的那些东西,其实大多也都没有严格测过,很多都是急急忙忙逼着上线,最多手工运行看看。大家都在急功近利,想着怎么尽快捞钱,成本就转嫁给下面的人去扛着就是了,用户在分担一点,他们自己就安心了。真正能静下心来做点事情的没几个。

星期五, 九月 28, 2007

trouble shooting for ext3fs with disk error

今天放数据库的主机不能正常运行了,因为以前出过文件系统错误,当时我把数据磁盘 umount,再做 fsck.ext3 /dev/sdb1 后就直接从 journal 恢复了。但今天却不行,当运行 fsck.ext3 /dev/sdb1 的时候,出现
(Attempt to read block from filesystem resulted in short read).  Ignore error?
这样的错误。

于是检查一下系统日志 /var/log/message
Sep 23 04:07:38 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 23 04:09:31 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 23 04:28:51 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 23 04:31:38 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 23 04:34:01 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 23 04:37:40 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
......
Sep 23 12:07:13 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 23 12:07:36 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 23 12:40:05 db kernel: __journal_remove_journal_head: freeing b_frozen_data
Sep 23 12:40:05 db kernel: __journal_remove_journal_head: freeing b_committed_data
Sep 23 12:40:05 db kernel: __journal_remove_journal_head: freeing b_frozen_data
Sep 23 12:40:59 db kernel: kjournald starting. Commit interval 5 seconds
Sep 23 12:40:59 db kernel: EXT3 FS on sdb1, internal journal
Sep 23 12:40:59 db kernel: EXT3-fs: mounted filesystem with ordered data mode.
Sep 27 02:34:00 db kernel: (scsi1:A:1:0): Unexpected busfree in Data-in phase
Sep 27 02:34:00 db kernel: SEQADDR == 0x82
Sep 27 02:34:00 db kernel: SCSI error : <1 0 1 0> return code = 0x10000
Sep 27 02:34:00 db kernel: end_request: I/O error, dev sdb, sector 272737767
Sep 27 02:34:01 db kernel: SCSI error : <1 0 1 0> return code = 0x10000
Sep 27 02:34:01 db kernel: end_request: I/O error, dev sdb, sector 272737775
Sep 27 02:34:01 db kernel: SCSI error : <1 0 1 0> return code = 0x10000
Sep 27 02:34:01 db kernel: end_request: I/O error, dev sdb, sector 272737783
Sep 27 02:34:01 db kernel: SCSI error : <1 0 1 0> return code = 0x10000
Sep 27 02:34:01 db kernel: end_request: I/O error, dev sdb, sector 272737791
Sep 27 02:34:01 db kernel: SCSI error : <1 0 1 0> return code = 0x10000
Sep 27 02:34:01 db kernel: end_request: I/O error, dev sdb, sector 272737799
Sep 27 02:34:02 db kernel: SCSI error : <1 0 1 0> return code = 0x10000
......
Sep 27 02:34:14 db kernel: SCSI error : <1 0 1 0> return code = 0x8000002
Sep 27 02:34:14 db kernel: Info fld=0x0, Current sdb: sense key Aborted Command
Sep 27 02:34:14 db kernel: end_request: I/O error, dev sdb, sector 272737767
Sep 27 02:34:14 db kernel: (scsi1:A:1): 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Sep 27 02:34:15 db kernel: (scsi1:A:1:0): Unexpected busfree in Data-in phase
Sep 27 02:34:15 db kernel: SEQADDR == 0x56
Sep 27 02:34:15 db kernel: SCSI error : <1 0 1 0> return code = 0x10000
Sep 27 02:34:15 db kernel: end_request: I/O error, dev sdb, sector 272872423
Sep 27 02:34:16 db kernel: SCSI error : <1 0 1 0> return code = 0x10000
Sep 27 02:34:16 db kernel: end_request: I/O error, dev sdb, sector 272872431
......
Sep 27 02:34:30 db kernel: SCSI error : <1 0 1 0> return code = 0x8000002
Sep 27 02:34:30 db kernel: Info fld=0x0, Current sdb: sense key Aborted Command
Sep 27 02:34:30 db kernel: end_request: I/O error, dev sdb, sector 272872639
Sep 27 02:34:30 db kernel: (scsi1:A:1): 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Sep 28 02:35:10 db kernel: (scsi1:A:1:0): Unexpected busfree in Data-in phase
Sep 28 02:35:10 db kernel: SEQADDR == 0x53
Sep 28 02:35:10 db kernel: scsi1:A:15: parity error detected while idle. SEQADDR(0x1) SCSIRATE(0xc2)
Sep 28 02:35:10 db kernel: No terminal CRC packet recevied
Sep 28 02:35:10 db kernel: SCSI error : <1 0 1 0> return code = 0x10000
Sep 28 02:35:10 db kernel: end_request: I/O error, dev sdb, sector 270637663
......
Sep 28 02:35:27 db kernel: SCSI error : <1 0 1 0> return code = 0x8000002
Sep 28 02:35:27 db kernel: Info fld=0x0, Current sdb: sense key Aborted Command
Sep 28 02:35:27 db kernel: end_request: I/O error, dev sdb, sector 120062031
Sep 28 02:35:27 db kernel: EXT3-fs error (device sdb1): ext3_get_inode_loc: unable to read inode block - inode=7503878, block=15007746
Sep 28 02:35:27 db kernel: Aborting journal on device sdb1.
Sep 28 02:35:27 db kernel: SCSI error : <1 0 1 0> return code = 0x8000002
Sep 28 02:35:27 db kernel: Info fld=0x0, Current sdb: sense key Aborted Command
Sep 28 02:35:27 db kernel: end_request: I/O error, dev sdb, sector 273146143
......
Sep 28 02:35:29 db kernel: SCSI error : <1 0 1 0> return code = 0x8000002
Sep 28 02:35:29 db kernel: Info fld=0x0, Current sdb: sense key Aborted Command
Sep 28 02:35:29 db kernel: end_request: I/O error, dev sdb, sector 63
Sep 28 02:35:29 db kernel: EXT3-fs error (device sdb1) in ext3_reserve_inode_write: IO failure
Sep 28 02:35:29 db kernel: SCSI error : <1 0 1 0> return code = 0x8000002
Sep 28 02:35:29 db kernel: Info fld=0x0, Current sdb: sense key Aborted Command
Sep 28 02:35:29 db kernel: end_request: I/O error, dev sdb, sector 272573927
Sep 28 02:35:29 db kernel: SCSI error : <1 0 1 0> return code = 0x8000002
Sep 28 02:35:29 db kernel: Info fld=0x0, Current sdb: sense key Aborted Command
Sep 28 02:35:29 db kernel: end_request: I/O error, dev sdb, sector 272574783
Sep 28 02:35:29 db kernel: ext3_abort called.
Sep 28 02:35:29 db kernel: EXT3-fs error (device sdb1): ext3_journal_start_sb: Detected aborted journal
Sep 28 02:35:29 db kernel: Remounting filesystem read-only
Sep 28 02:35:29 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 28 02:35:29 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 28 02:35:29 db kernel: (scsi1:A:1): 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Sep 28 02:35:29 db kernel: EXT3-fs error (device sdb1) in ext3_dirty_inode: IO failure
Sep 28 02:35:29 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 28 02:35:29 db kernel: __journal_remove_journal_head: freeing b_frozen_data
Sep 28 02:35:29 db kernel: __journal_remove_journal_head: freeing b_frozen_data
Sep 28 02:35:55 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 28 02:41:25 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 28 03:10:40 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 28 03:42:08 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 28 03:51:37 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
Sep 28 03:54:38 db kernel: EXT3-fs error (device sdb1) in start_transaction: Journal has aborted
......
基本上,可以肯定是磁盘损坏了,出现了坏道!

因为这里是没有使用 RAID 设施的,所以只能使用 rescue 主机替代,这属于高可用(HA: High Availability)的问题了,这里不讨论。回过头来,需要检查和确认这块磁盘的问题。

首先使用另外一个 IP 启动这台主机(因为 HA 已经使用了原来的 IP 地址)。在这里我遇到的情况是在重启时第二块磁盘(/dev/sdb)还是被“正常”挂载了(/dev/sdb1),这意味着你仍然可以从里面把数据拷贝出来,当然最好是只读使用!——运气不错,不是吗?但这并不意味着这块磁盘就没有问题了,需要先进行检查:
sh# fsck.ext3 /dev/sdb1
e2fsck 1.35 (28-Feb-2004)
/dev/sdb1: clean, 39195/17924096 files, 22706784/35843015 blocks
好像没有问题?但真的是这样吗?

应该使用其他的超级块检查一下,因为很可能这个超级块本身就有问题。从 Ext3 文件系统使用磁盘的基本原理上看,一个磁盘被分成若干 groups,每个 groups 包含很多物理 blocks(通常为 4KB,和内存的一个 page 的大小一致。注意,这里和使用 fdisk 是显示的 Blocks 是不一样的,后者是以 1KB 为单元的),通常一个 group 可能包含 8192/16384/32768 个 blocks,取决于磁盘的大小或创建分区文件系统时的设置,而每一个 group 上面都有一个超级块(super block),只有第一个 group 的超级块被实际使用,其他 group 的超级块都作为备用。因此,尝试使用另外一个超级块:
sh# fsck.ext3 -b 8192 /dev/sdb1
e2fsck 1.35 (28-Feb-2004)
fsck.ext3: Bad magic number in super-block while trying to open /dev/sdb1

The superblock could not be read or does not describe a correct ext2
filesystem. If the device is valid and it really contains an ext2
filesystem (and not swap or ufs or something else), then the superblock
is corrupt, and you might try running e2fsck with an alternate superblock:
e2fsck -b 8193

sh# fsck.ext3 -b 8193 /dev/sdb1
e2fsck 1.35 (28-Feb-2004)
fsck.ext3: Bad magic number in super-block while trying to open /dev/sdb1

The superblock could not be read or does not describe a correct ext2
filesystem. If the device is valid and it really contains an ext2
filesystem (and not swap or ufs or something else), then the superblock
is corrupt, and you might try running e2fsck with an alternate superblock:
e2fsck -b 8193
两者都不行!这说明一个 group 的大小不是 8192,第二个 super block 不在第 8193 个 block 上,那么可以通过 tune2fs 来获得文件系统的信息,进而找到下一个超级块。
sh# tune2fs -l /dev/sdb1
tune2fs 1.35 (28-Feb-2004)
Filesystem volume name:
Last mounted on:
Filesystem UUID: 204a2d09-12d5-4623-bb0d-75b2e340401d
Filesystem magic number: 0xEF53
Filesystem revision #: 1 (dynamic)
Filesystem features: has_journal resize_inode filetype sparse_super large_file
Default mount options: (none)
Filesystem state: clean
Errors behavior: Continue
Filesystem OS type: Linux
Inode count: 17924096
Block count: 35843015
Reserved block count: 1792150
Free blocks: 13136231
Free inodes: 17884901
First block: 0
Block size: 4096
Fragment size: 4096
Reserved GDT blocks: 1024
Blocks per group: 32768
Fragments per group: 32768
Inodes per group: 16384
Inode blocks per group: 512
Filesystem created: Sun Jan 7 15:50:06 2007
Last mount time: Fri Sep 28 10:05:06 2007
Last write time: Fri Sep 28 11:01:56 2007
Mount count: 1
Maximum mount count: 35
Last checked: Fri Sep 28 10:05:05 2007
Check interval: 15552000 (6 months)
Next check after: Wed Mar 26 10:05:05 2008
Reserved blocks uid: 0 (user root)
Reserved blocks gid: 0 (group root)
First inode: 11
Inode size: 128
Journal inode: 8
Default directory hash: tea
Directory Hash Seed: dd1084ed-a28f-489e-8e47-c4a3a49f5e6d
Journal backup: inode blocks
可以看出每个块组拥有 32768 个 blocks,所以应该指定 -b 32768 来进行检查:
sh# fsck.ext3 -b 32768 /dev/sdb1
e2fsck 1.35 (28-Feb-2004)
/dev/sdb1 contains a file system with errors, check forced.
Pass 1: Checking inodes, blocks, and sizes
Duplicate blocks found... invoking duplicate block passes.
Pass 1B: Rescan for duplicate/bad blocks
Duplicate/bad block(s) in inode 311389: 712136
Duplicate/bad block(s) in inode 311425: 680600 680633 680634 680635 680636 680637 680638 680639 680641 680642 680643 680644 680645 680646 680647 680665 680666 680667 680668 680669 680670 680671 680673 681752 682704 684104 684352 685688 686064
Duplicate/bad block(s) in inode 311560: 657856 658872 662192 665192 669600 686504 689824 694104 696144 696904 698816 703032
Duplicate/bad block(s) in inode 344144: 705776 706088 706784
Duplicate/bad block(s) in inode 344151: 708952
Duplicate/bad block(s) in inode 344170: 709200
Duplicate/bad block(s) in inode 377354: 810496
Error reading block 22872266 (Attempt to read block from filesystem resulted in short read). Ignore error?
已经报告出现了 bad blocks。

short read 通常意味着文件系统中的一个 i 节点指向一个不能再读取的块,或者关于文件系统的某个元数据位于一个或者几个不能读取的块。对于日志文件系统,如果文件系统的日志的任何一部分存储在一个坏块上,也会出现这个错误,因为不能读取事务。

如果运气不够好,磁盘分区完全不能挂载和读取,可以先尝试把日志删除,再尝试挂接和访问数据。先用 debugfs 来看看文件系统的特性:
sh# debugfs /dev/sdb1
debugfs 1.35 (28-Feb-2004)
debugfs: features
Filesystem features: has_journal resize_inode filetype sparse_super large_file
debugfs: open /dev/sdb1
open: Filesystem /dev/sdb1 is still open. Close it first.
debugfs: open /dev/sdb1
open: Filesystem /dev/sdb1 is still open. Close it first.
debugfs: close /dev/sdb1
close: Usage: close_filesys
debugfs:
debugfs: open /dev/sdb1
open: Filesystem /dev/sdb1 is still open. Close it first.
debugfs: quit
可以看到 has_journal 特性。使用 tune2fs 可以设置和清除文件系统特性。下面的命令删除日志:
sh# tune2fs -f -O ^has_journal /dev/sdb1
tune2fs 1.35 (28-Feb-2004)
sh# debugfs /dev/sdb1
debugfs 1.35 (28-Feb-2004)
debugfs: features
Filesystem features: resize_inode filetype sparse_super large_file
debugfs: open /dev/sdb1
open: Filesystem /dev/sdb1 is still open. Close it first.
debugfs: quit
has_journal 特性已经被清除。这时候,再次运行 fsck.ext3,不使用 -b 指定 super block,也可以看到报错信息:
e2fsck 1.35 (28-Feb-2004)
/dev/sdb1 contains a file system with errors, check forced.
Pass 1: Checking inodes, blocks, and sizes
Error reading block 35750122 (Attempt to read block from filesystem resulted in short read) while doing inode scan. Ignore error?
总之,要从一个损坏的磁盘上恢复数据总是没有保证的,所以备份至关重要——"热镜像 + 轮转拷贝"才是根本之道。

参考:《LINUX SERVER HACKS 卷二》, Hacks #94 "从崩溃的磁盘恢复数据"。

另外,我的项目 cutils包含了 mirrord/fs_mirror 镜像和轮转工具。

星期二, 九月 25, 2007

python catch OSError

两种形式都可以:
except OSError, (errno, strerr):
# OR
except OSError, osexc:
print osexc.errno, osexc.message
但为什么两个都可以呢?OSError 的 instance osexc 怎么转换成 tuple 的呢?

python 关于 threading 流程

Thread.start()
|
\--->run()
|
\--->callback
默认在 callback 返回时执行 thread 的退出:
finally:
self.__stop()
如果 callback 是无限循环,可以利用 Thread.Event 通知其退出,例如 pyinotify 的 ThreadedNotifier.stop() 方法。

星期一, 九月 24, 2007

python 捕捉同级的 exception?

try:
...
except A:
raise B
except B:
*
那么在 A 中产生的异常 B 能否被"except B"捕捉并处理呢?结论是:不能!

星期四, 九月 20, 2007

RHEL5 部分内存无法使用?

因为装 RAID1 + LVM,使用了一块技嘉的板子,nvidia GeForce 6100/nForce 430 芯片,结果原来的 RHEL4 没有它的 SATA 驱动,下载的 sata_nv 驱动也始终装不上,只好换用了 RHEL5,很顺利的安装成功了。

但进入系统后,使用 free 发现 4G 的内存,却只显示 3.4GB 左右。在 BIOS 中对于显卡的 frame buffer 的设置最大也只有 256MB,不可能差这边大。

从 dmesg 的记录来看,在 Linux 启动的时候有一个 Warning 信息,
 BIOS-e820: 00000000f0000000 - 00000000f2000000 (reserved)
BIOS-e820: 00000000fec00000 - 0000000100000000 (reserved)
BIOS-e820: 0000000100000000 - 0000000120000000 (usable)
Warning only 4GB will be used.
Use a PAE enabled kernel.
3200MB HIGHMEM available.
896MB LOWMEM available.
found SMP MP-table at 000f4ad0
Using x86 segment limits to approximate NX protection
On node 0 totalpages: 1048576
DMA zone: 4096 pages, LIFO batch:0
Normal zone: 225280 pages, LIFO batch:31
HighMem zone: 819200 pages, LIFO batch:31
DMI 2.3 present.
这个警告信息比较奇怪,应该是说明了问题所在。结合以前遇到过的关于 4GB 内存不能启动的问题,估计应该是内核对大内存支持的问题。于是重新下载内核源代码并进行编译,学者处理器的内存支持为 64GB,重启后就 OK 了。

在内核 config 文件中的定义是:
CONFIG_HIGHMEM4G=y
# CONFIG_HIGHMEM64G is not set
变为
# CONFIG_HIGHMEM4G is not set
CONFIG_HIGHMEM64G=y
这里对 HIGHMEM 我还不是太清楚其含义,最近正在看《LINUX 内核解析》,应该能够得到说明。

星期二, 九月 04, 2007

python datetime.timedelta

>>> import time, datetime
>>> d = datetime.datetime(*time.localtime()[:6])
>>> print d
2007-09-04 10:10:00
>>> d + 15
Traceback (most recent call last):
File "", line 1, in
TypeError: unsupported operand type(s) for +: 'datetime.datetime' and 'int'
>>> d
datetime.datetime(2007, 9, 4, 10, 10)
>>> t = datetime.timedelta(days=15)
>>> d - t
datetime.datetime(2007, 8, 20, 10, 10)
>>> x = d - t
这样就可以得到表示 15 天前的那个时间对象。

星期一, 九月 03, 2007

sed 两个例子

1. 排除最后一行:这是在统计 Apache 的日志时用到的,我需要统计某个站点流量的总和:
zcat $logfile \
| grep $site \
| awk '{print $11}' \
| grep -v '^-' \
| sed '$!s/.*/&+\\/g' \
| bc -l


2. sed 如何表示倒数第 n 行?