[clue-tech] IBM xSeries; hwclock & /dev/rtc; kjournald
mike havlicek
mhavlicek1 at yahoo.com
Sat Feb 21 22:32:27 MST 2009
Thanks for the suggestions.
The system in question is an IBM xSeries 360 8686-1RX with 4 cpus.
I have found that there are issues with hwclock accessing /dev/rtc when running CentOS linux on this machine type.
Two approaches to "alleviating" the "problems" with hwclock accessing /dev/rtc have had the side effect of my no longer seeing kjournald related I/O errors and other filesystem access nastiness that ultimately resulted in my realizing shutdown by the "pull the power plug" method.
I mainly confined myself to looking at /sbin/hwclock in terms of
"hwclock --show" and strace/ltrace. Kernel adjustments that seem to have circumvented disaster were to disable ACPI using the latest CentOS 5.2 PAE kernels and building kernel.org kernels (v2.6.18.8, v2.6.28.6) using a load of a stock CentOS 5.2 kernel-2.6.18-19.el5PAE config with no modifications. The custom builds running both with and without ACPI allow hwclock to execute with a sane final return and I haven't experienced filesystem disaster (yet). ACPI enabled with the CentOS kernels always results in a select() timeout on /dev/rtc. The root underlying approaches to working "around??/with??" /dev/rtc are clearly different .... I am including some strace output .....
Any ideas why ACPI would have this effect? For brevity I haven't included
the full strace output from stock kernel hwclock breakage with ACPI. That
ends with:
-----(strace hwclock running kernel-2.6.18-92.el5PAE acpi enabled)-------
<snip>
open("/dev/rtc", O_RDONLY|O_LARGEFILE) = 4
ioctl(4, RTC_UIE_ON, 0) = 0
select(5, [4], NULL, NULL, {5, 0}) = 0 (Timeout)
<snip>
write(2, "select() to /dev/rtc to wait for"..., 54select() to /dev/rtc to wait for clock tick timed out
) = 54
ioctl(4, RTC_UIE_OFF, 0) = 0
close(4) = 0
exit_group(1) = ?
--------------------------------------------------------------------------
Regardless, the resulting output from strace/ltrace on hwclock still doesn't give me a warm fuzzy feeling when running the custom built kernel.org kernel even when the final return is "sane" (for one thing the open on /dev/rtc still gets a -1), but it does still leave ACPI as an option if there is any reason to enable it.
I think I will stick to running a "stock" CentOS kernel with ACPI disabled
for now. I don't know the pros and cons of each treatment of rtc versus ACPI on this server..... (honestly my general rule in the past has always been to disable power management features on servers). Any suggested ACPI
guidelines?
I do know that the results I have seen so far from running with ACPI enabled on the stock CentOS kernels has been undesirable. Maybe if
I wish hard enough, it will turn out that all of this is because the
machine is so old and there is a magic flash to fix it all.
Haven't yet tried to break things by mucking with SYSFS_DEPRICATED_V2
which as was was mentioned might affect udev et al:) A totally different
exercise...
-Mike
Sorry about the long previously posted dmesg output and the length of this post... Here are outputs of "strace /sbin/hwclock" running two different seemingly functional kernels. I wonder if one is preferable
to the other... With my luck none of this actually has anything to
do with the filesystem errors as they will probably show up after
a few days ... hehe ... actually they always showed up pretty quickly
before.
-----(strace hwclock running kernel-2.6.18-92.el5PAE acpi=off)---------
execve("/sbin/hwclock", ["hwclock", "--show"], [/* 36 vars */]) = 0
brk(0) = 0x8174000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=45738, ...}) = 0
mmap2(NULL, 45738, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7fd2000
close(3) = 0
open("/lib/libaudit.so.0", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0p\314g\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=84976, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fd1000
mmap2(0x67b000, 82244, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x67b000
mmap2(0x68e000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13) = 0x68e000
close(3) = 0
open("/lib/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0000O\216\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1602320, ...}) = 0
mmap2(0x8cf000, 1320356, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x8cf000
mmap2(0xa0c000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13d) = 0xa0c000
mmap2(0xa0f000, 9636, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xa0f000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fd0000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb7fd06c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_page
s:1, seg_not_present:0, useable:1}) = 0
mprotect(0xa0c000, 8192, PROT_READ) = 0
mprotect(0x8c6000, 4096, PROT_READ) = 0
munmap(0xb7fd2000, 45738) = 0
gettimeofday({1235277330, 648346}, NULL) = 0
socket(PF_NETLINK, SOCK_RAW, 9) = 3
fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
brk(0) = 0x8174000
brk(0x8195000) = 0x8195000
open("/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=56426096, ...}) = 0
mmap2(NULL, 2097152, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb7dd0000
close(4) = 0
getuid32() = 0
open("/dev/rtc", O_RDONLY|O_LARGEFILE) = 4
close(4) = 0
stat64("/etc/adjtime", {st_mode=S_IFREG|0644, st_size=46, ...}) = 0
open("/etc/adjtime", O_RDONLY|O_LARGEFILE) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=46, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fdd000
read(4, "0.000000 1235276549 0.000000\n123"..., 4096) = 46
close(4) = 0
munmap(0xb7fdd000, 4096) = 0
open("/dev/rtc", O_RDONLY|O_LARGEFILE) = 4
ioctl(4, RTC_UIE_ON, 0) = 0
select(5, [4], NULL, NULL, {5, 0}) = 1 (in [4], left {4, 770000})
ioctl(4, RTC_UIE_OFF, 0) = 0
close(4) = 0
gettimeofday({1235277330, 895780}, NULL) = 0
open("/dev/rtc", O_RDONLY|O_LARGEFILE) = 4
ioctl(4, RTC_RD_TIME, {tm_sec=31, tm_min=35, tm_hour=21, tm_mday=21, tm_mon=1, tm_year=109, ...}) = 0
close(4) = 0
open("/etc/localtime", O_RDONLY) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fdd000
read(4, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0"..., 4096) = 2427
close(4) = 0
munmap(0xb7fdd000, 4096) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
open("/usr/share/locale/locale.alias", O_RDONLY) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=2528, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fdd000
read(4, "# Locale name alias data base.\n#"..., 4096) = 2528
read(4, "", 4096) = 0
close(4) = 0
munmap(0xb7fdd000, 4096) = 0
open("/usr/share/locale/en_US.UTF-8/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en_US.utf8/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en_US/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en.UTF-8/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en.utf8/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
fstat64(1, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fdd000
write(1, "Sat 21 Feb 2009 09:35:31 PM MST "..., 51Sat 21 Feb 2009 09:35:31 PM MST -0.247434 seconds
) = 51
exit_group(0) = ?
-------------------------(end strace output)--------------------
-----(strace hwclcok running kernel-2.6.18-92.el5PAE acpi=off)---------
execve("/sbin/hwclock", ["hwclock", "--show"], [/* 36 vars */]) = 0
brk(0) = 0x8051000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=45738, ...}) = 0
mmap2(NULL, 45738, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7fd6000
close(3) = 0
open("/lib/libaudit.so.0", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0p\314g\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=84976, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fd5000
mmap2(0x67b000, 82244, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x67b000
mmap2(0x68e000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13) = 0x68e000
close(3) = 0
open("/lib/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0000O\216\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1602320, ...}) = 0
mmap2(0x8cf000, 1320356, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x8cf000
mmap2(0xa0c000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13d) = 0xa0c000
mmap2(0xa0f000, 9636, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xa0f000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fd4000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb7fd46c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_page
s:1, seg_not_present:0, useable:1}) = 0
mprotect(0xa0c000, 8192, PROT_READ) = 0
mprotect(0x8c6000, 4096, PROT_READ) = 0
munmap(0xb7fd6000, 45738) = 0
gettimeofday({1235273746, 764551}, NULL) = 0
socket(PF_NETLINK, SOCK_RAW, 9) = 3
fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
brk(0) = 0x8051000
brk(0x8072000) = 0x8072000
open("/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=56426096, ...}) = 0
mmap2(NULL, 2097152, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb7dd4000
close(4) = 0
getuid32() = 0
open("/dev/rtc", O_RDONLY|O_LARGEFILE) = -1 ENODEV (No such device)
iopl(0x3) = 0
stat64("/etc/adjtime", {st_mode=S_IFREG|0644, st_size=46, ...}) = 0
open("/etc/adjtime", O_RDONLY|O_LARGEFILE) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=46, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe1000
read(4, "0.000000 1235268284 0.000000\n123"..., 4096) = 46
close(4) = 0
munmap(0xb7fe1000, 4096) = 0
gettimeofday({1235273746, 861975}, NULL) = 0
open("/etc/localtime", O_RDONLY) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe1000
read(4, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0"..., 4096) = 2427
close(4) = 0
munmap(0xb7fe1000, 4096) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
open("/usr/share/locale/locale.alias", O_RDONLY) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=2528, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe1000
read(4, "# Locale name alias data base.\n#"..., 4096) = 2528
read(4, "", 4096) = 0
close(4) = 0
munmap(0xb7fe1000, 4096) = 0
open("/usr/share/locale/en_US.UTF-8/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en_US.utf8/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en_US/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en.UTF-8/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en.utf8/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/en/LC_MESSAGES/util-linux.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
fstat64(1, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe1000
write(1, "Sat 21 Feb 2009 08:35:47 PM MST "..., 51Sat 21 Feb 2009 08:35:47 PM MST -0.097424 seconds
) = 51
exit_group(0) = ?
-------------------------(end strace output)--------------------
I think this last kernel generates the same style treatment with
ACPI enabled.
--- On Thu, 2/19/09, David L. Anselmi <anselmi at anselmi.us> wrote:
> From: David L. Anselmi <anselmi at anselmi.us>
> Subject: Re: [clue-tech] SYSFS_DEPRECIATED_V2
> To: "CLUE technical discussion" <clue-tech at cluedenver.org>
> Date: Thursday, February 19, 2009, 5:39 PM
> Kevin Fenzi wrote:
> > On Thu, 19 Feb 2009 08:27:00 -0800 (PST)
> > mike havlicek <mhavlicek1 at yahoo.com> wrote:
> >
> >> Hello,
> >>
> >> I am building a v2.6.28.6 kernel for use with
> CentOS 5.2. In general
> >> whats a definitative way to determine if a distro
> needs this feature?
> >
> > Well, if it's set in the existing vendor kernel,
> there is likely a good
> > reason for it.
>
> Yeah, I'd use the same config they do.
>
> > ...snip...
> >
> >> Ultimately I am trying to alleviate some more
> irritating problems
> >> that I see from this vanilla install:
> >>
> >> - calls to hwclock fail
> >> - kjournald eventually fails
> >>
> >> I also get messages of the form:
> >>
> >> EXT3-fs error (device dm-3) in start_transaction:
> Journal has aborted
> >>
> >> and from syslogd
> >>
> >> kernel: journal commit I/O error.
> >
> > I don't think building a custom newer kernel is
> likely to fix I/O
> > errors. That sounds like your drive or controller is
> having issues.
> > It's hard to say without the full dmesg output.
>
> Likewise, unless you have evidence that these problems are
> due to kernel
> bugs that have been fixed, building a new kernel seems more
> effort than
> it's worth.
>
> Dave
> _______________________________________________
> clue-tech mailing list
> clue-tech at cluedenver.org
> http://www.cluedenver.org/mailman/listinfo/clue-tech
More information about the clue-tech
mailing list