http://bugzilla.kernel.org/show_bug.cgi?id=12224
Summary: journal activity on inactive partition causes inactive
harddrive spinup
Product: File System
Version: 2.5
KernelVersion: 2.6.27.6
Platform: All
OS/Version: Linux
Tree: Mainline
Status: NEW
Severity: low
Priority: P1
Component: ext3
AssignedTo: [email protected]
ReportedBy: [email protected]
Latest working kernel version: 2.6.27.5
Earliest failing kernel version: 2.6.27.6
Distribution: Debian stable with custom compiled vanilla kernel
Problem Description:
Activity on one partition (hda1) causes kjournald to also write to another
partition (sda1). This in turn causes the harddrive which contains sda1 to
spinup or not spindown.
I've activated laptop-mode using laptop-mode-tools. hda1 and sda1 are both
formatted with ext3.
On unaffected kernels (e.g. 2.6.27.5) btrace produces no output. On
affected kernels (e.g. 2.6.27.6, 2.6.27-rc7) btrace produces output as below.
/dev/hda1 on / type ext3 (rw,noatime,errors=remount-ro,commit=1209600)
tmpfs on /lib/init/rw type tmpfs (rw,nosuid,mode=0755)
proc on /proc type proc (rw,noexec,nosuid,nodev)
sysfs on /sys type sysfs (rw,noexec,nosuid,nodev)
udev on /dev type tmpfs (rw,mode=0755)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
devpts on /dev/pts type devpts (rw,noexec,nosuid,gid=5,mode=620)
debugfs on /sys/kernel/debug type debugfs (rw)
Steps to reproduce:
1. start "btrace /dev/sda"
2. begin compiling kernel
3. within seconds btrace begins output similar to below.
Thanks for all your work! Sorry if I've misplaced blame for this undesirable
change in behavior.
Using 2.6.27.8, btrace of /dev/sda while compiling on /dev/hda1
Dec 9 11:15:32 localhost logger: 8,0 0 1 0.000000000
1109 A WS 14375 + 8 <- (8,1) 14312
Dec 9 11:15:32 localhost logger: 8,0 0 2 0.000006705
1109 Q WS 14375 + 8 [kjournald]
Dec 9 11:15:32 localhost logger: 8,0 0 3 0.000043581
1109 G WS 14375 + 8 [kjournald]
Dec 9 11:15:32 localhost logger: 8,0 0 4 0.000065651
1109 P N [kjournald]
Dec 9 11:15:32 localhost logger: 8,0 0 5 0.000076267
1109 I W 14375 + 8 [kjournald]
Dec 9 11:15:32 localhost logger: 8,0 0 6 0.000300318
1109 D W 14375 + 8 [kjournald]
Dec 9 11:15:32 localhost logger: 8,0 0 7 0.000423518
1109 U N [kjournald] 1
Dec 9 11:15:32 localhost logger: 8,0 0 8 0.010028373
3 C W 14375 + 8 [0]
Dec 9 11:15:35 localhost logger: 8,0 0 9 3.219049689
1109 A WS 14383 + 8 <- (8,1) 14320
Dec 9 11:15:35 localhost logger: 8,0 0 10 3.219058350
1109 Q WS 14383 + 8 [kjournald]
Dec 9 11:15:35 localhost logger: 8,0 0 11 3.219095505
1109 G WS 14383 + 8 [kjournald]
Dec 9 11:15:35 localhost logger: 8,0 0 12 3.219115061
1109 P N [kjournald]
Dec 9 11:15:35 localhost logger: 8,0 0 13 3.219127074
1109 I W 14383 + 8 [kjournald]
Dec 9 11:15:35 localhost logger: 8,0 0 14 3.219344699
1109 D W 14383 + 8 [kjournald]
Dec 9 11:15:35 localhost logger: 8,0 0 15 3.219543607
1109 U N [kjournald] 1
Dec 9 11:15:35 localhost logger: 8,0 0 16 3.229477275
3 C W 14383 + 8 [0]
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
[email protected] changed:
What |Removed |Added
----------------------------------------------------------------------------
Regression|0 |1
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #1 from [email protected] 2008-12-14 14:30 -------
Reply-To: [email protected]
(switched to email. Please respond via emailed reply-to-all, not via the
bugzilla web interface).
On Sun, 14 Dec 2008 11:39:34 -0800 (PST) [email protected]
wrote:
> http://bugzilla.kernel.org/show_bug.cgi?id=12224
>
> Summary: journal activity on inactive partition causes inactive
> harddrive spinup
> Product: File System
> Version: 2.5
> KernelVersion: 2.6.27.6
> Platform: All
> OS/Version: Linux
> Tree: Mainline
> Status: NEW
> Severity: low
> Priority: P1
> Component: ext3
> AssignedTo: [email protected]
> ReportedBy: [email protected]
>
>
> Latest working kernel version: 2.6.27.5
> Earliest failing kernel version: 2.6.27.6
Thanks for being this specific.
> Distribution: Debian stable with custom compiled vanilla kernel
>
> Problem Description:
> Activity on one partition (hda1) causes kjournald to also write to another
> partition (sda1). This in turn causes the harddrive which contains sda1 to
> spinup or not spindown.
> I've activated laptop-mode using laptop-mode-tools. hda1 and sda1 are both
> formatted with ext3.
> On unaffected kernels (e.g. 2.6.27.5) btrace produces no output. On
> affected kernels (e.g. 2.6.27.6, 2.6.27-rc7) btrace produces output as below.
I think I've seen other reports of this. Maybe it was you.
> /dev/hda1 on / type ext3 (rw,noatime,errors=remount-ro,commit=1209600)
> tmpfs on /lib/init/rw type tmpfs (rw,nosuid,mode=0755)
> proc on /proc type proc (rw,noexec,nosuid,nodev)
> sysfs on /sys type sysfs (rw,noexec,nosuid,nodev)
> udev on /dev type tmpfs (rw,mode=0755)
> tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
> devpts on /dev/pts type devpts (rw,noexec,nosuid,gid=5,mode=620)
> debugfs on /sys/kernel/debug type debugfs (rw)
>
> Steps to reproduce:
> 1. start "btrace /dev/sda"
> 2. begin compiling kernel
> 3. within seconds btrace begins output similar to below.
>
>
> Thanks for all your work! Sorry if I've misplaced blame for this undesirable
> change in behavior.
>
> Using 2.6.27.8, btrace of /dev/sda while compiling on /dev/hda1
OK, that's a huge mess because bugzilla went and wordwrapped it. Let
me fix it:
> Dec 9 11:15:32 localhost logger: 8,0 0 1 0.000000000 1109 A WS 14375 + 8 <- (8,1) 14312
> Dec 9 11:15:32 localhost logger: 8,0 0 2 0.000006705 1109 Q WS 14375 + 8 [kjournald]
> Dec 9 11:15:32 localhost logger: 8,0 0 3 0.000043581 1109 G WS 14375 + 8 [kjournald]
> Dec 9 11:15:32 localhost logger: 8,0 0 4 0.000065651 1109 P N [kjournald]
> Dec 9 11:15:32 localhost logger: 8,0 0 5 0.000076267 1109 I W 14375 + 8 [kjournald]
> Dec 9 11:15:32 localhost logger: 8,0 0 6 0.000300318 1109 D W 14375 + 8 [kjournald]
> Dec 9 11:15:32 localhost logger: 8,0 0 7 0.000423518 1109 U N [kjournald] 1
> Dec 9 11:15:32 localhost logger: 8,0 0 8 0.010028373 3 C W 14375 + 8 [0]
> Dec 9 11:15:35 localhost logger: 8,0 0 9 3.219049689 1109 A WS 14383 + 8 <- (8,1) 14320
> Dec 9 11:15:35 localhost logger: 8,0 0 10 3.219058350 1109 Q WS 14383 + 8 [kjournald]
> Dec 9 11:15:35 localhost logger: 8,0 0 11 3.219095505 1109 G WS 14383 + 8 [kjournald]
> Dec 9 11:15:35 localhost logger: 8,0 0 12 3.219115061 1109 P N [kjournald]
> Dec 9 11:15:35 localhost logger: 8,0 0 13 3.219127074 1109 I W 14383 + 8 [kjournald]
> Dec 9 11:15:35 localhost logger: 8,0 0 14 3.219344699 1109 D W 14383 + 8 [kjournald]
> Dec 9 11:15:35 localhost logger: 8,0 0 15 3.219543607 1109 U N [kjournald] 1
> Dec 9 11:15:35 localhost logger: 8,0 0 16 3.229477275 3 C W 14383 + 8 [0]
I'm not familar with btrace. What are we looking at here?
The only likely commit I see in
ftp://ftp.kernel.org/pub/linux/kernel/v2.6/ChangeLog-2.6.27.6 is "ext3:
wait on all pending commits in ext3_sync_fs", but I don't see how it
could cause this.
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
[email protected] wrote:
> OK, that's a huge mess because bugzilla went and wordwrapped it. Let
> me fix it:
>
>> Dec 9 11:15:32 localhost logger: 8,0 0 1 0.000000000 1109 A WS 14375 + 8 <- (8,1) 14312
>> Dec 9 11:15:32 localhost logger: 8,0 0 2 0.000006705 1109 Q WS 14375 + 8 [kjournald]
>> Dec 9 11:15:32 localhost logger: 8,0 0 3 0.000043581 1109 G WS 14375 + 8 [kjournald]
>> Dec 9 11:15:32 localhost logger: 8,0 0 4 0.000065651 1109 P N [kjournald]
>> Dec 9 11:15:32 localhost logger: 8,0 0 5 0.000076267 1109 I W 14375 + 8 [kjournald]
>> Dec 9 11:15:32 localhost logger: 8,0 0 6 0.000300318 1109 D W 14375 + 8 [kjournald]
>> Dec 9 11:15:32 localhost logger: 8,0 0 7 0.000423518 1109 U N [kjournald] 1
>> Dec 9 11:15:32 localhost logger: 8,0 0 8 0.010028373 3 C W 14375 + 8 [0]
>> Dec 9 11:15:35 localhost logger: 8,0 0 9 3.219049689 1109 A WS 14383 + 8 <- (8,1) 14320
>> Dec 9 11:15:35 localhost logger: 8,0 0 10 3.219058350 1109 Q WS 14383 + 8 [kjournald]
>> Dec 9 11:15:35 localhost logger: 8,0 0 11 3.219095505 1109 G WS 14383 + 8 [kjournald]
>> Dec 9 11:15:35 localhost logger: 8,0 0 12 3.219115061 1109 P N [kjournald]
>> Dec 9 11:15:35 localhost logger: 8,0 0 13 3.219127074 1109 I W 14383 + 8 [kjournald]
>> Dec 9 11:15:35 localhost logger: 8,0 0 14 3.219344699 1109 D W 14383 + 8 [kjournald]
>> Dec 9 11:15:35 localhost logger: 8,0 0 15 3.219543607 1109 U N [kjournald] 1
>> Dec 9 11:15:35 localhost logger: 8,0 0 16 3.229477275 3 C W 14383 + 8 [0]
>
> I'm not familar with btrace. What are we looking at here?
Andrew, it's blktrace/blkparse output, basically. blkparse(1) manpage
has the details.
maj,min cpu seq time pid act rwbs off+len
8,0 0 1 0.000000000 1109 A WS 14375 + 8 <- (8,1) 14312
... etc
I'm not sure it gives us enough info; all we see is that there was an IO
on sdb (from sdb1)
I might suggest
# sysctl -w vm.block_dump=1
to see if you get any info about inodes on sda1 being dirtied.
(Also, I didn't see any info about sda1 in the posted fstab...)
-Eric
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #2 from [email protected] 2008-12-14 15:10 -------
[email protected] wrote:
> OK, that's a huge mess because bugzilla went and wordwrapped it. Let
> me fix it:
>
>> Dec 9 11:15:32 localhost logger: 8,0 0 1 0.000000000 1109 A WS 14375 + 8 <- (8,1) 14312
>> Dec 9 11:15:32 localhost logger: 8,0 0 2 0.000006705 1109 Q WS 14375 + 8 [kjournald]
>> Dec 9 11:15:32 localhost logger: 8,0 0 3 0.000043581 1109 G WS 14375 + 8 [kjournald]
>> Dec 9 11:15:32 localhost logger: 8,0 0 4 0.000065651 1109 P N [kjournald]
>> Dec 9 11:15:32 localhost logger: 8,0 0 5 0.000076267 1109 I W 14375 + 8 [kjournald]
>> Dec 9 11:15:32 localhost logger: 8,0 0 6 0.000300318 1109 D W 14375 + 8 [kjournald]
>> Dec 9 11:15:32 localhost logger: 8,0 0 7 0.000423518 1109 U N [kjournald] 1
>> Dec 9 11:15:32 localhost logger: 8,0 0 8 0.010028373 3 C W 14375 + 8 [0]
>> Dec 9 11:15:35 localhost logger: 8,0 0 9 3.219049689 1109 A WS 14383 + 8 <- (8,1) 14320
>> Dec 9 11:15:35 localhost logger: 8,0 0 10 3.219058350 1109 Q WS 14383 + 8 [kjournald]
>> Dec 9 11:15:35 localhost logger: 8,0 0 11 3.219095505 1109 G WS 14383 + 8 [kjournald]
>> Dec 9 11:15:35 localhost logger: 8,0 0 12 3.219115061 1109 P N [kjournald]
>> Dec 9 11:15:35 localhost logger: 8,0 0 13 3.219127074 1109 I W 14383 + 8 [kjournald]
>> Dec 9 11:15:35 localhost logger: 8,0 0 14 3.219344699 1109 D W 14383 + 8 [kjournald]
>> Dec 9 11:15:35 localhost logger: 8,0 0 15 3.219543607 1109 U N [kjournald] 1
>> Dec 9 11:15:35 localhost logger: 8,0 0 16 3.229477275 3 C W 14383 + 8 [0]
>
> I'm not familar with btrace. What are we looking at here?
Andrew, it's blktrace/blkparse output, basically. blkparse(1) manpage
has the details.
maj,min cpu seq time pid act rwbs off+len
8,0 0 1 0.000000000 1109 A WS 14375 + 8 <- (8,1) 14312
... etc
I'm not sure it gives us enough info; all we see is that there was an IO
on sdb (from sdb1)
I might suggest
# sysctl -w vm.block_dump=1
to see if you get any info about inodes on sda1 being dirtied.
(Also, I didn't see any info about sda1 in the posted fstab...)
-Eric
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
Eric Sandeen <[email protected]> writes:
> maj,min cpu seq time pid act rwbs off+len
> 8,0 0 1 0.000000000 1109 A WS 14375 + 8 <- (8,1) 14312
>
> ... etc
>
> I'm not sure it gives us enough info; all we see is that there was an IO
> on sdb (from sdb1)
>
> I might suggest
>
> # sysctl -w vm.block_dump=1
>
> to see if you get any info about inodes on sda1 being dirtied.
Like atime/diratime updates?
> (Also, I didn't see any info about sda1 in the posted fstab...)
>
> -Eric
MfG
Goswin
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #3 from [email protected] 2008-12-14 17:22 -------
Reply-To: [email protected]
Eric Sandeen <[email protected]> writes:
> maj,min cpu seq time pid act rwbs off+len
> 8,0 0 1 0.000000000 1109 A WS 14375 + 8 <- (8,1) 14312
>
> ... etc
>
> I'm not sure it gives us enough info; all we see is that there was an IO
> on sdb (from sdb1)
>
> I might suggest
>
> # sysctl -w vm.block_dump=1
>
> to see if you get any info about inodes on sda1 being dirtied.
Like atime/diratime updates?
> (Also, I didn't see any info about sda1 in the posted fstab...)
>
> -Eric
MfG
Goswin
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #4 from [email protected] 2008-12-14 17:25 -------
http://bugzilla.kernel.org/show_bug.cgi?id=12224
> I think I've seen other reports of this. ?Maybe it was you.
Yes, that was me. :)
> # sysctl -w vm.block_dump=1
>
> to see if you get any info about inodes on sda1 being dirtied.
I waited until 20:02, then ran:
# sysctl -w vm.block_dump=1; btrace /dev/sda | logger -s
and switched to a different terminal and ran in the linux kernel
directory
(on hda1):
# make clean
I waited until "btrace" indicated activity on sda1, then stopped the
"make
clean". If you would like me let it run a few more seconds let me know.
Below is the output from /var/log/syslog. The btrace and block_dump
output
is interleaved. Lines containing "logger" are from btrace.
Dec 14 20:02:11 localhost kernel: cc1(2825): dirtied inode 550552 (.2823.tmp)
on hda1
Dec 14 20:02:12 localhost kernel: cc1(2831): dirtied inode 550552 (.2829.tmp)
on hda1
Dec 14 20:02:12 localhost kernel: cc1(2831): dirtied inode 550552 (.2829.tmp)
on hda1
Dec 14 20:02:12 localhost kernel: as(2851): dirtied inode 550552 (.2847.tmp)
on hda1
Dec 14 20:02:12 localhost kernel: as(2857): dirtied inode 550552 (.2853.tmp)
on hda1
Dec 14 20:02:13 localhost kernel: cc1(2861): dirtied inode 550552 (.2859.tmp)
on hda1
Dec 14 20:02:13 localhost kernel: cc1(2866): dirtied inode 550552 (.2864.tmp)
on hda1
Dec 14 20:02:14 localhost kernel: cc1(2870): dirtied inode 550552 (.2868.tmp)
on hda1
Dec 14 20:02:14 localhost kernel: cc1(2874): dirtied inode 667799 (cc7UOalO.s)
on hda1
Dec 14 20:02:15 localhost kernel: as(2875): dirtied inode 667800 (cco6Z96S.o)
on hda1
Dec 14 20:02:15 localhost kernel: collect2(2876): dirtied inode 678207
(ccDA8hIA.ld) on hda1
Dec 14 20:02:15 localhost kernel: collect2(2876): dirtied inode 678208
(cc8CSPAJ.le) on hda1
Dec 14 20:02:15 localhost kernel: ld(2877): dirtied inode 550552 (.2872.tmp)
on hda1
Dec 14 20:02:15 localhost kernel: cc1(2889): dirtied inode 667799 (ccpOcjsE.s)
on hda1
Dec 14 20:02:15 localhost kernel: as(2890): dirtied inode 667800 (ccswKxcx.o)
on hda1
Dec 14 20:02:15 localhost kernel: collect2(2891): dirtied inode 678207
(ccUNFhhm.ld) on hda1
Dec 14 20:02:15 localhost kernel: collect2(2891): dirtied inode 678208
(ccmKXZiq.le) on hda1
Dec 14 20:02:16 localhost kernel: ld(2892): dirtied inode 550552 (.2887.tmp)
on hda1
Dec 14 20:02:16 localhost kernel: ld(2892): dirtied inode 550552 (.2887.tmp)
on hda1
Dec 14 20:02:16 localhost kernel: make(2898): READ block 10191456 on hda1
Dec 14 20:02:16 localhost kernel: make(2898): READ block 10909096 on hda1
Dec 14 20:02:16 localhost kernel: cc1(2901): dirtied inode 667799 (cc6hy8wW.s)
on hda1
Dec 14 20:02:17 localhost kernel: as(2902): dirtied inode 667800 (ccNZWld0.o)
on hda1
Dec 14 20:02:17 localhost kernel: collect2(2903): dirtied inode 678207
(ccQ6Vp5L.ld) on hda1
Dec 14 20:02:17 localhost kernel: collect2(2903): dirtied inode 678208
(cc4aaKMY.le) on hda1
Dec 14 20:02:17 localhost kernel: ld(2904): dirtied inode 550552 (.2899.tmp)
on hda1
Dec 14 20:02:17 localhost kernel: cc1(2915): dirtied inode 667799 (ccvjO98E.s)
on hda1
Dec 14 20:02:17 localhost kernel: as(2916): dirtied inode 667800 (ccGHSTjA.o)
on hda1
Dec 14 20:02:17 localhost kernel: collect2(2917): dirtied inode 678207
(cc6n7Vqv.ld) on hda1
Dec 14 20:02:17 localhost kernel: collect2(2917): dirtied inode 678208
(ccAnMFjC.le) on hda1
Dec 14 20:02:18 localhost kernel: ld(2918): dirtied inode 550552 (.2913.tmp)
on hda1
Dec 14 20:02:18 localhost kernel: cc1(2927): dirtied inode 667799 (ccgXoLEp.s)
on hda1
Dec 14 20:02:18 localhost kernel: pdflush(132): WRITE block 378016 on hda1
Dec 14 20:02:18 localhost kernel: pdflush(132): WRITE block 378024 on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16189 (syslog)
on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16189 (syslog)
on hda1
Dec 14 20:02:18 localhost kernel: pdflush(132): WRITE block 329472 on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16531
(kern.log) on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16531
(kern.log) on hda1
Dec 14 20:02:18 localhost kernel: pdflush(132): WRITE block 329480 on hda1
Dec 14 20:02:18 localhost kernel: pdflush(132): WRITE block 492056 on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16537 (debug)
on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16537 (debug)
on hda1
Dec 14 20:02:18 localhost kernel: pdflush(132): WRITE block 1851400 on hda1
Dec 14 20:02:18 localhost kernel: pdflush(132): WRITE block 10993664 on hda1
Dec 14 20:02:18 localhost kernel: as(2928): dirtied inode 667800 (cc0KvDl5.o)
on hda1
Dec 14 20:02:18 localhost kernel: pdflush(133): WRITE block 378024 on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16189 (syslog)
on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16189 (syslog)
on hda1
Dec 14 20:02:18 localhost kernel: pdflush(133): WRITE block 329464 on hda1
Dec 14 20:02:18 localhost kernel: pdflush(133): WRITE block 329472 on hda1
Dec 14 20:02:18 localhost kernel: collect2(2929): dirtied inode 678207
(ccf6U3lS.ld) on hda1
Dec 14 20:02:18 localhost kernel: collect2(2929): dirtied inode 678208
(cciOTsnM.le) on hda1
Dec 14 20:02:18 localhost kernel: pdflush(133): WRITE block 329480 on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16531
(kern.log) on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16531
(kern.log) on hda1
Dec 14 20:02:18 localhost kernel: pdflush(133): WRITE block 492048 on hda1
Dec 14 20:02:18 localhost kernel: pdflush(133): WRITE block 492056 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 378024 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 329480 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 10752024 on hda1
Dec 14 20:02:18 localhost kernel: ld(2930): dirtied inode 550552 (.2925.tmp)
on hda1
Dec 14 20:02:18 localhost kernel: gcc(2926): dirtied inode 667799 (?) on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16537 (debug)
on hda1
Dec 14 20:02:18 localhost kernel: rsyslogd(2827): dirtied inode 16537 (debug)
on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8384 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8392 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8400 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8408 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8416 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8424 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8432 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8440 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8448 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8456 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8464 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8472 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8480 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8488 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8496 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8504 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8512 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8520 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8528 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8536 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8544 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8552 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8560 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(305): WRITE block 8568 on hda1
Dec 14 20:02:18 localhost kernel: kjournald(1109): WRITE block 12520 on sda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 327960 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 1835024 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 1835048 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 378024 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 378032 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 329480 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 492056 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 492064 on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16189 (syslog)
on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16189 (syslog)
on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16189 (syslog)
on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16531
(kern.log) on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16531
(kern.log) on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16531
(kern.log) on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16537 (debug)
on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16537 (debug)
on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16537 (debug)
on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 378032 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 329480 on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16189 (syslog)
on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16189 (syslog)
on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): WRITE block 329488 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 492064 on hda1
Dec 14 20:02:19 localhost logger: 8,0 0 1 0.000000000 1109 A
WS 12583 + 8 <- (8,1) 12520
Dec 14 20:02:19 localhost logger: 8,0 0 2 0.000006426 1109 Q
WS 12583 + 8 [kjournald]
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8576 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8584 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8592 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8600 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8608 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8616 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8624 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8632 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8640 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8648 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8656 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8664 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8672 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8680 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8688 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8696 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8704 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8712 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8720 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8728 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8736 on hda1
Dec 14 20:02:19 localhost logger: 8,0 0 3 0.000039670 1109 G
WS 12583 + 8 [kjournald]
Dec 14 20:02:19 localhost logger: 8,0 0 4 0.000061461 1109 P
N [kjournald]
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16535
(user.log) on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16535
(user.log) on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16535
(user.log) on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16539
(messages) on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16539
(messages) on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16539
(messages) on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8744 on hda1
Dec 14 20:02:19 localhost logger: 8,0 0 5 0.000071797 1109 I
W 12583 + 8 [kjournald]
Dec 14 20:02:19 localhost logger: 8,0 0 6 0.000272381 1109 D
W 12583 + 8 [kjournald]
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 329488 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 378032 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 492064 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 328464 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 329208 on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16531
(kern.log) on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16531
(kern.log) on hda1
Dec 14 20:02:19 localhost logger: 8,0 0 7 0.000381893 1109 U
N [kjournald] 1
Dec 14 20:02:19 localhost logger: 8,0 0 8 0.028911225 3 C
W 12583 + 8 [0]
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8752 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8760 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8768 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8776 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 492064 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 492072 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 378032 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 329488 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 378040 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 328464 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 329208 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 329496 on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16537 (debug)
on hda1
Dec 14 20:02:19 localhost kernel: rsyslogd(2827): dirtied inode 16537 (debug)
on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8784 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8792 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8800 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8808 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8816 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8824 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8832 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8840 on hda1
Dec 14 20:02:19 localhost kernel: kjournald(305): WRITE block 8848 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 0 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 327960 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 376984 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 491760 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 8912896 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 8912904 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 8913064 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 8913184 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 8994816 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 10747904 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 10747912 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 10747920 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 10749224 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 10749384 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 10751824 on hda1
Dec 14 20:02:19 localhost kernel: pdflush(133): WRITE block 10752520 on hda1
Dec 14 20:02:19 localhost kernel: cc1(2945): dirtied inode 667799 (ccvt36ES.s)
on hda1
Dec 14 20:02:20 localhost kernel: as(2946): dirtied inode 667800 (ccM4g5ZY.o)
on hda1
Dec 14 20:02:20 localhost kernel: collect2(2947): dirtied inode 678207
(ccjYE2NG.ld) on hda1
Dec 14 20:02:20 localhost kernel: collect2(2947): dirtied inode 678208
(ccEzo3JR.le) on hda1
Dec 14 20:02:20 localhost kernel: ld(2948): dirtied inode 550552 (.2943.tmp)
on hda1
Dec 14 20:02:20 localhost kernel: cc1(2957): dirtied inode 667799 (cc6ZPFDy.s)
on hda1
Dec 14 20:02:20 localhost kernel: as(2958): dirtied inode 667800 (ccAj2mWp.o)
on hda1
Dec 14 20:02:20 localhost kernel: collect2(2959): dirtied inode 678207
(ccpJQzdj.ld) on hda1
Dec 14 20:02:20 localhost kernel: collect2(2959): dirtied inode 678208
(ccU1Uk0l.le) on hda1
Dec 14 20:02:20 localhost kernel: ld(2960): dirtied inode 550552 (.2955.tmp)
on hda1
Dec 14 20:02:21 localhost kernel: cc1(2969): dirtied inode 667799 (cc7lUzdi.s)
on hda1
Dec 14 20:02:21 localhost kernel: as(2970): dirtied inode 667800 (cc2KnxYS.o)
on hda1
Dec 14 20:02:21 localhost kernel: collect2(2971): dirtied inode 678207
(ccYyMJRv.ld) on hda1
Dec 14 20:02:21 localhost kernel: collect2(2971): dirtied inode 678208
(cc0coqFi.le) on hda1
Dec 14 20:02:21 localhost kernel: ld(2972): dirtied inode 550552 (.2967.tmp)
on hda1
Dec 14 20:02:22 localhost kernel: cc1(2981): dirtied inode 667799 (ccnYuG29.s)
on hda1
Dec 14 20:02:22 localhost kernel: as(2982): dirtied inode 667800 (ccLRJ3tt.o)
on hda1
Dec 14 20:02:22 localhost kernel: collect2(2985): dirtied inode 678207
(cc39KpHM.ld) on hda1
Dec 14 20:02:22 localhost kernel: collect2(2985): dirtied inode 678208
(ccKCIBak.le) on hda1
Dec 14 20:02:22 localhost kernel: ld(2986): dirtied inode 550552 (.2979.tmp)
on hda1
>
> (Also, I didn't see any info about sda1 in the posted fstab...)
Oops! copied the "mount" output when sda wasn't mounted. Here is the output
of "mount" current when the above output was generated:
/dev/hda1 on / type ext3 (rw,noatime,errors=remount-ro,commit=1209600)
tmpfs on /lib/init/rw type tmpfs (rw,nosuid,mode=0755)
proc on /proc type proc (rw,noexec,nosuid,nodev)
sysfs on /sys type sysfs (rw,noexec,nosuid,nodev)
udev on /dev type tmpfs (rw,mode=0755)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
devpts on /dev/pts type devpts (rw,noexec,nosuid,gid=5,mode=620)
/dev/sda1 on /mnt/sda type ext3 (rw,noatime,commit=1209600)
debugfs on /sys/kernel/debug type debugfs (rw)
C.
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
> Activity on one partition (hda1) causes kjournald to also write
> to another partition (sda1). This in turn causes the harddrive
> which contains sda1 to spinup or not spindown. I've activated
> laptop-mode using laptop-mode-tools. hda1 and sda1 are both
> formatted with ext3. On unaffected kernels (e.g. 2.6.27.5) btrace
> produces no output. On affected kernels (e.g. 2.6.27.6, 2.6.27-rc7)
> btrace produces output as below.
I've looked at the changes between 2.6.27.5 and 2.6.27.6, and I don't
see anything that might explain such a regression. Indeed, there's
only one patch between .5 and .6 that even touches ext3, and the patch
seems pretty innocent.
Is /dev/sda1 even mounted? It doesn't included up in your /etc/mtab
listing.
The only thing I can suggest is to try 2.6.27.6 with the only patch
that touches ext3 reverted (i.e., unapply it with patch -R). If the
problem still shows up, I would suggest getting the linux-2.6.27.y
tree from:
git://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-2.6.27.y.git
And then doing a git bisection search to try to find the guilty
commit.
Regards,
- Ted
commit a0b8bfb34743b6e6c2bb06ad5a270590d90270f7
Author: Arthur Jones <[email protected]>
Date: Fri Nov 7 00:05:17 2008 +0000
ext3: wait on all pending commits in ext3_sync_fs
commit c87591b719737b4e91eb1a9fa8fd55a4ff1886d6 upstream
In ext3_sync_fs, we only wait for a commit to finish if we started it, but
there may be one already in progress which will not be synced.
In the case of a data=ordered umount with pending long symlinks which are
delayed due to a long list of other I/O on the backing block device, this
causes the buffer associated with the long symlinks to not be moved to the
inode dirty list in the second phase of fsync_super. Then, before they
can be dirtied again, kjournald exits, seeing the UMOUNT flag and the
dirty pages are never written to the backing block device, causing long
symlink corruption and exposing new or previously freed block data to
userspace.
This can be reproduced with a script created
by Eric Sandeen <[email protected]>:
#!/bin/bash
umount /mnt/test2
mount /dev/sdb4 /mnt/test2
rm -f /mnt/test2/*
dd if=/dev/zero of=/mnt/test2/bigfile bs=1M count=512
touch
/mnt/test2/thisisveryveryveryveryveryveryveryveryveryveryveryveryveryveryveryverylongfilename
ln -s
/mnt/test2/thisisveryveryveryveryveryveryveryveryveryveryveryveryveryveryveryverylongfilename
/mnt/test2/link
umount /mnt/test2
mount /dev/sdb4 /mnt/test2
ls /mnt/test2/
umount /mnt/test2
To ensure all commits are synced, we flush all journal commits now when
sync_fs'ing ext3.
Signed-off-by: Arthur Jones <[email protected]>
Cc: Eric Sandeen <[email protected]>
Cc: Theodore Ts'o <[email protected]>
Cc: <[email protected]>
Signed-off-by: Andrew Morton <[email protected]>
Signed-off-by: Linus Torvalds <[email protected]>
Signed-off-by: Greg Kroah-Hartman <[email protected]>
diff --git a/fs/ext3/super.c b/fs/ext3/super.c
index f38a5af..810bf7c 100644
--- a/fs/ext3/super.c
+++ b/fs/ext3/super.c
@@ -2365,13 +2365,12 @@ static void ext3_write_super (struct super_block * sb)
static int ext3_sync_fs(struct super_block *sb, int wait)
{
- tid_t target;
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #5 from [email protected] 2008-12-14 18:47 -------
> Activity on one partition (hda1) causes kjournald to also write
> to another partition (sda1). This in turn causes the harddrive
> which contains sda1 to spinup or not spindown. I've activated
> laptop-mode using laptop-mode-tools. hda1 and sda1 are both
> formatted with ext3. On unaffected kernels (e.g. 2.6.27.5) btrace
> produces no output. On affected kernels (e.g. 2.6.27.6, 2.6.27-rc7)
> btrace produces output as below.
I've looked at the changes between 2.6.27.5 and 2.6.27.6, and I don't
see anything that might explain such a regression. Indeed, there's
only one patch between .5 and .6 that even touches ext3, and the patch
seems pretty innocent.
Is /dev/sda1 even mounted? It doesn't included up in your /etc/mtab
listing.
The only thing I can suggest is to try 2.6.27.6 with the only patch
that touches ext3 reverted (i.e., unapply it with patch -R). If the
problem still shows up, I would suggest getting the linux-2.6.27.y
tree from:
git://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-2.6.27.y.git
And then doing a git bisection search to try to find the guilty
commit.
Regards,
- Ted
commit a0b8bfb34743b6e6c2bb06ad5a270590d90270f7
Author: Arthur Jones <[email protected]>
Date: Fri Nov 7 00:05:17 2008 +0000
ext3: wait on all pending commits in ext3_sync_fs
commit c87591b719737b4e91eb1a9fa8fd55a4ff1886d6 upstream
In ext3_sync_fs, we only wait for a commit to finish if we started it, but
there may be one already in progress which will not be synced.
In the case of a data=ordered umount with pending long symlinks which are
delayed due to a long list of other I/O on the backing block device, this
causes the buffer associated with the long symlinks to not be moved to the
inode dirty list in the second phase of fsync_super. Then, before they
can be dirtied again, kjournald exits, seeing the UMOUNT flag and the
dirty pages are never written to the backing block device, causing long
symlink corruption and exposing new or previously freed block data to
userspace.
This can be reproduced with a script created
by Eric Sandeen <[email protected]>:
#!/bin/bash
umount /mnt/test2
mount /dev/sdb4 /mnt/test2
rm -f /mnt/test2/*
dd if=/dev/zero of=/mnt/test2/bigfile bs=1M count=512
touch
/mnt/test2/thisisveryveryveryveryveryveryveryveryveryveryveryveryveryveryveryverylongfilename
ln -s
/mnt/test2/thisisveryveryveryveryveryveryveryveryveryveryveryveryveryveryveryverylongfilename
/mnt/test2/link
umount /mnt/test2
mount /dev/sdb4 /mnt/test2
ls /mnt/test2/
umount /mnt/test2
To ensure all commits are synced, we flush all journal commits now when
sync_fs'ing ext3.
Signed-off-by: Arthur Jones <[email protected]>
Cc: Eric Sandeen <[email protected]>
Cc: Theodore Ts'o <[email protected]>
Cc: <[email protected]>
Signed-off-by: Andrew Morton <[email protected]>
Signed-off-by: Linus Torvalds <[email protected]>
Signed-off-by: Greg Kroah-Hartman <[email protected]>
diff --git a/fs/ext3/super.c b/fs/ext3/super.c
index f38a5af..810bf7c 100644
--- a/fs/ext3/super.c
+++ b/fs/ext3/super.c
@@ -2365,13 +2365,12 @@ static void ext3_write_super (struct super_block * sb)
static int ext3_sync_fs(struct super_block *sb, int wait)
{
- tid_t target;
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #6 from [email protected] 2008-12-14 21:07 -------
Dec 14 20:02:18 localhost kernel: kjournald(1109): WRITE block 12520 on sda1
is the first thing I see in the log above, with no indication of anything else
on sda1 before that.
If you let the system just sit idle, do you get sda1 hits from the sysctl
and/or blktrace?
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #7 from [email protected] 2008-12-15 13:49 -------
Hi,
Following Ted's suggestion, I began with 2.6.27.6 and then reversed the
patch
for commit a0b8bfb34743b6e6c2bb06ad5a270590d90270f7. This "fixed" the
problem such that activity on hda1 no longer caused kjournald to write to
sda1.
> Is /dev/sda1 even mounted? It doesn't included up in your /etc/mtab
> listing.
Just to confirm, I posted the wrong mtab previously. sda1 is mounted during
my tests. This is how it looks:
/dev/hda1 on / type ext3 (rw,noatime,errors=remount-ro,commit=1209600)
tmpfs on /lib/init/rw type tmpfs (rw,nosuid,mode=0755)
proc on /proc type proc (rw,noexec,nosuid,nodev)
sysfs on /sys type sysfs (rw,noexec,nosuid,nodev)
udev on /dev type tmpfs (rw,mode=0755)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
devpts on /dev/pts type devpts (rw,noexec,nosuid,gid=5,mode=620)
/dev/sda1 on /mnt/sda type ext3 (rw,noatime,commit=1209600)
debugfs on /sys/kernel/debug type debugfs (rw)
> ------- Comment #6 from [email protected] ?2008-12-14 21:07 -------
>
> Dec 14 20:02:18 localhost kernel: kjournald(1109): WRITE block 12520 on
> sda1
>
> is the first thing I see in the log above, with no indication of anything
> else on sda1 before that.
I only copied the lines from the log during the short compile "test".
Here is another test which is a little more clean, using 2.6.27.6
(without
the commit mentioned above reverted).
First unmount, then remount /dev/sda1 to flush the filesystem caches:
# umount /dev/sda1; mount /mnt/sda; btrace /dev/sda | logger -s
then switch to another console and restart laptop mode (to change the
commit
time on sda1):
#/etc/init.d/laptop-mode restart
Finally generate some activity on hda1. ("make menuconfig")
The following is syslog from the mount of /dev/sda1 (on /mnt/sda) until
"make
clean" finished:
Dec 15 16:34:48 localhost kernel: kjournald starting. Commit interval 5
seconds
Dec 15 16:34:48 localhost kernel: EXT3 FS on sda1, internal journal
Dec 15 16:34:48 localhost kernel: EXT3-fs: mounted filesystem with ordered
data mode.
Dec 15 16:34:54 localhost kernel: hda: cache flushes not supported
Dec 15 16:34:56 localhost kernel: hda: cache flushes not supported
Dec 15 16:34:57 localhost logger: 8,0 0 1 0.000000000 4140 A
WS 12423 + 8 <- (8,1) 12360
Dec 15 16:34:57 localhost logger: 8,0 0 2 0.000006146 4140 Q
WS 12423 + 8 [kjournald]
Dec 15 16:34:57 localhost logger: 8,0 0 3 0.000114819 4140 G
WS 12423 + 8 [kjournald]
Dec 15 16:34:57 localhost logger: 8,0 0 4 0.000143314 4140 P
N [kjournald]
Dec 15 16:34:57 localhost logger: 8,0 0 5 0.000159797 4140 I
W 12423 + 8 [kjournald]
Dec 15 16:34:57 localhost logger: 8,0 0 6 0.000348089 4140 D
W 12423 + 8 [kjournald]
Dec 15 16:34:57 localhost logger: 8,0 0 7 0.000463746 4140 U
N [kjournald] 1
Dec 15 16:34:57 localhost logger: 8,0 0 8 0.010034518 3 C
W 12423 + 8 [0]
Dec 15 16:34:57 localhost logger: 8,0 0 9 0.010557490 4140 A
WS 12431 + 8 <- (8,1) 12368
Dec 15 16:34:57 localhost logger: 8,0 0 10 0.010563916 4140 Q
WS 12431 + 8 [kjournald]
Dec 15 16:34:57 localhost logger: 8,0 0 11 0.010589617 4140 G
WS 12431 + 8 [kjournald]
Dec 15 16:34:57 localhost logger: 8,0 0 12 0.010606658 4140 P
N [kjournald]
Dec 15 16:34:57 localhost logger: 8,0 0 13 0.010616157 4140 I
W 12431 + 8 [kjournald]
Dec 15 16:34:57 localhost logger: 8,0 0 14 0.010749414 4140 D
W 12431 + 8 [kjournald]
Dec 15 16:34:57 localhost logger: 8,0 0 15 0.010836297 4140 U
N [kjournald] 1
Dec 15 16:34:57 localhost logger: 8,0 0 16 0.021000161 3 C
W 12431 + 8 [0]
Dec 15 16:34:59 localhost logger: 8,0 0 17 2.350235673 4140 A
WS 12439 + 8 <- (8,1) 12376
Dec 15 16:34:59 localhost logger: 8,0 0 18 2.350244612 4140 Q
WS 12439 + 8 [kjournald]
Dec 15 16:34:59 localhost logger: 8,0 0 19 2.350278974 4140 G
WS 12439 + 8 [kjournald]
Dec 15 16:34:59 localhost logger: 8,0 0 20 2.350301044 4140 P
N [kjournald]
Dec 15 16:34:59 localhost logger: 8,0 0 21 2.350316130 4140 I
W 12439 + 8 [kjournald]
Dec 15 16:34:59 localhost logger: 8,0 0 22 2.350568397 4140 D
W 12439 + 8 [kjournald]
Dec 15 16:34:59 localhost logger: 8,0 0 23 2.350684333 4140 U
N [kjournald] 1
Dec 15 16:34:59 localhost logger: 8,0 0 24 2.360609899 3 C
W 12439 + 8 [0]
Dec 15 16:35:52 localhost logger: 8,0 0 25 55.121164875 4140 A
WS 12447 + 8 <- (8,1) 12384
Dec 15 16:35:52 localhost logger: 8,0 0 26 55.121172697 4140 Q
WS 12447 + 8 [kjournald]
Dec 15 16:35:52 localhost logger: 8,0 0 27 55.121203707 4140 G
WS 12447 + 8 [kjournald]
Dec 15 16:35:52 localhost logger: 8,0 0 28 55.121221865 4140 P
N [kjournald]
Dec 15 16:35:52 localhost logger: 8,0 0 29 55.121232202 4140 I
W 12447 + 8 [kjournald]
Dec 15 16:35:52 localhost logger: 8,0 0 30 55.121458767 4140 D
W 12447 + 8 [kjournald]
Dec 15 16:35:52 localhost logger: 8,0 0 31 55.121571910 4140 U
N [kjournald] 1
Dec 15 16:35:52 localhost logger: 8,0 0 32 55.131824892 3 C
W 12447 + 8 [0]
Dec 15 16:35:57 localhost logger: 8,0 0 33 59.696845185 4140 A
WS 12455 + 8 <- (8,1) 12392
Dec 15 16:35:57 localhost logger: 8,0 0 34 59.696853566 4140 Q
WS 12455 + 8 [kjournald]
Dec 15 16:35:57 localhost logger: 8,0 0 35 59.696888486 4140 G
WS 12455 + 8 [kjournald]
Dec 15 16:35:57 localhost logger: 8,0 0 36 59.696908880 4140 P
N [kjournald]
Dec 15 16:35:57 localhost logger: 8,0 0 37 59.696920334 4140 I
W 12455 + 8 [kjournald]
Dec 15 16:35:57 localhost logger: 8,0 0 38 59.697142709 4140 D
W 12455 + 8 [kjournald]
Dec 15 16:35:57 localhost logger: 8,0 0 39 59.697256410 4140 U
N [kjournald] 1
Dec 15 16:35:57 localhost logger: 8,0 0 40 59.707057938 3 C
W 12455 + 8 [0]
Dec 15 16:36:04 localhost logger: 8,0 0 41 67.363585697 4140 A
WS 12463 + 8 <- (8,1) 12400
Dec 15 16:36:04 localhost logger: 8,0 0 42 67.363595196 4140 Q
WS 12463 + 8 [kjournald]
Dec 15 16:36:04 localhost logger: 8,0 0 43 67.363627043 4140 G
WS 12463 + 8 [kjournald]
Dec 15 16:36:04 localhost logger: 8,0 0 44 67.363646319 4140 P
N [kjournald]
Dec 15 16:36:04 localhost logger: 8,0 0 45 67.363657215 4140 I
W 12463 + 8 [kjournald]
Dec 15 16:36:04 localhost logger: 8,0 0 46 67.363869253 4140 D
W 12463 + 8 [kjournald]
Dec 15 16:36:04 localhost logger: 8,0 0 47 67.363980161 4140 U
N [kjournald] 1
Dec 15 16:36:04 localhost logger: 8,0 0 48 67.373786717 3 C
W 12463 + 8 [0]
>
> If you let the system just sit idle, do you get sda1 hits from the sysctl
> and/or blktrace?
If I let the system sit idle using 2.6.27.5 (the last unaffected
version) 'btrace /dev/sda' shows no activity, even if there is activity on
hda1.
If I let the system sit idle using 2.6.27.6 (the first affected
version) 'btrace /dev/sda' shows kjournald doing something with sda1 if there
is activity on hda1. If hda1 is inactive then there is also no activity on
sda1.
Thanks!
C.
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #8 from [email protected] 2008-12-16 12:35 -------
http://bugzilla.kernel.org/show_bug.cgi?id=12224
Hi all,
You might be interested to know that this problem can be reproduced by
using
an ext3 image file mounted loopback. (I.e. You don't need a separate
harddrive or partition in order to reproduce the problem.)
C.
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #9 from [email protected] 2008-12-16 14:01 -------
Are the laptop-mode tools doing remounts behind your back?
The only way I see this is if I do "mount -o remount /"; then I see kjournald
activity on other ext3 filesystems. I'll dig into that.
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #10 from [email protected] 2008-12-16 18:30 -------
On Tuesday 16 December 2008 17:01:27 [email protected] wrote:
> http://bugzilla.kernel.org/show_bug.cgi?id=12224
> ------- Comment #9 from [email protected] 2008-12-16 14:01 -------
> Are the laptop-mode tools doing remounts behind your back?
>
> The only way I see this is if I do "mount -o remount /"; then I see
> kjournald activity on other ext3 filesystems. I'll dig into that.
I don't think so: I was able to reproduce this bug using an ext3 loopback
mounted file. laptop-mode-tools does not touch loopback devices as far as I
can tell. Here is my laptop-mode.conf:
> #
> # The drives that laptop mode controls.
> # Separate them by a space, e.g. HD="/dev/hda /dev/hdb". The default is a
> # wildcard, which will get you all your IDE and SCSI/SATA drives.
> #
> HD="/dev/[hs]d[abcdefgh]"
And here is the loopback mount:
/tmp/ext3Image on /mnt/loop type ext3
(rw,noatime,loop=/dev/loop/0,commit=1209600)
(I set the commit=1209600 and noatime by hand on the loopback mounted
ext3
image file.)
Since I'm not a kernel hacker, I don't know how the code is structured.
It
feels like the kernel commit code is not fully separated by device (or
partition). When the active partition's journal is "synced" it triggers
activity on other partitions, even if the other partitions aren't active.
C.
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
[email protected] changed:
What |Removed |Added
----------------------------------------------------------------------------
OtherBugsDependingO| |11808
nThis| |
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #11 from [email protected] 2008-12-18 12:41 -------
Handled-By : Eric Sandeen <[email protected]>
Notify-Also : Theodore Tso <[email protected]>
First-Bad-Commit : c87591b719737b4e91eb1a9fa8fd55a4ff1886d6
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #12 from [email protected] 2008-12-18 15:02 -------
In a nutshell, with laptop mode on, we go down this path:
static void laptop_timer_fn(unsigned long unused)
{
pdflush_operation(laptop_flush, 0);
}
static void laptop_flush(unsigned long unused)
{
sys_sync();
}
which gets us to the new
static int ext3_sync_fs(struct super_block *sb, int wait)
{
sb->s_dirt = 0;
if (wait)
ext3_force_commit(sb);
...
which is then committing empty transactions. Seems like we should be smart
enough to skip committing transactions w/ nothing in them...?
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #13 from [email protected] 2009-01-13 14:17 -------
Care to test the patch at http://patchwork.ozlabs.org/patch/14755/ ?
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #14 from [email protected] 2009-01-14 12:35 -------
http://bugzilla.kernel.org/show_bug.cgi?id=12224
>
>
>
> ------- Comment #13 from [email protected] 2009-01-13 14:17 -------
> Care to test the patch at http://patchwork.ozlabs.org/patch/14755/ ?
Sure!
I manually patched 2.6.28. btrace showed lots of output as above.
However,
I didn't wait to see if the observed activity affected the drive spinup/down
b/c I thought maybe patching 2.6.28 was not proper.
I don't know how to git the right kernel sources to patch. Could you
prepare
a patch against an RC (or in some other way hold my hand)? Or I could wait
for some RC which includes the patch already.
Sorry for my gimpiness,
C.
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #15 from [email protected] 2009-01-14 12:44 -------
Sure, I'll gladly attach a patch. You tell me a specific kernel version, I'll
attach a patch. :) 2.6.28?
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #16 from [email protected] 2009-01-14 14:37 -------
http://bugzilla.kernel.org/show_bug.cgi?id=12224
> ------- Comment #15 from [email protected] 2009-01-14 12:44 -------
> Sure, I'll gladly attach a patch. You tell me a specific kernel version,
> I'll attach a patch. :) 2.6.28?
Yes, please! :)
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #17 from [email protected] 2009-01-14 14:58 -------
Created an attachment (id=19805)
--> (http://bugzilla.kernel.org/attachment.cgi?id=19805&action=view)
patch reverting old change & adding Jan's proposed fix
Here you go!
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #18 from [email protected] 2009-01-14 17:09 -------
http://bugzilla.kernel.org/show_bug.cgi?id=12224
I applied the patch to 2.6.28....
However there is still activity on the inactive partition (sda) if
there is
activity on the other partition (hda).
I've pasted the current output of 'btrace /dev/sda' in case it has
changed
from before.
Jan 14 19:51:29 localhost logger: 8,0 0 1 0.000000000 1138 A
WS 12599 + 8 <- (8,1) 12536
Jan 14 19:51:29 localhost logger: 8,0 0 2 0.000006426 1138 Q
WS 12599 + 8 [kjournald]
Jan 14 19:51:29 localhost logger: 8,0 0 3 0.000044978 1138 G
WS 12599 + 8 [kjournald]
Jan 14 19:51:29 localhost logger: 8,0 0 4 0.000066489 1138 P
N [kjournald]
Jan 14 19:51:29 localhost logger: 8,0 0 5 0.000081295 1138 I
W 12599 + 8 [kjournald]
Jan 14 19:51:29 localhost logger: 8,0 0 6 0.000300597 1138 D
W 12599 + 8 [kjournald]
Jan 14 19:51:29 localhost logger: 8,0 0 7 0.000492521 1138 U
N [kjournald] 1
Jan 14 19:51:29 localhost logger: 8,0 0 8 0.041120321 3 C
W 12599 + 8 [0]
Jan 14 19:51:51 localhost logger: 8,0 0 9 21.646946652 1138 A
WS 12607 + 8 <- (8,1) 12544
Jan 14 19:51:51 localhost logger: 8,0 0 10 21.646955591 1138 Q
WS 12607 + 8 [kjournald]
Jan 14 19:51:51 localhost logger: 8,0 0 11 21.646991071 1138 G
WS 12607 + 8 [kjournald]
Jan 14 19:51:51 localhost logger: 8,0 0 12 21.647011464 1138 P
N [kjournald]
Jan 14 19:51:51 localhost logger: 8,0 0 13 21.647027109 1138 I
W 12607 + 8 [kjournald]
Jan 14 19:51:51 localhost logger: 8,0 0 14 21.647229369 1138 D
W 12607 + 8 [kjournald]
Jan 14 19:51:51 localhost logger: 8,0 0 15 21.647339439 1138 U
N [kjournald] 1
Jan 14 19:51:51 localhost logger: 8,0 0 16 21.688494962 3 C
W 12607 + 8 [0]
Jan 14 19:51:55 localhost logger: 8,0 0 17 26.471770149 1138 A
WS 12615 + 8 <- (8,1) 12552
Jan 14 19:51:55 localhost logger: 8,0 0 18 26.471779368 1138 Q
WS 12615 + 8 [kjournald]
Jan 14 19:51:55 localhost logger: 8,0 0 19 26.471812613 1138 G
WS 12615 + 8 [kjournald]
Jan 14 19:51:55 localhost logger: 8,0 0 20 26.471831889 1138 P
N [kjournald]
Jan 14 19:51:55 localhost logger: 8,0 0 21 26.471846136 1138 I
W 12615 + 8 [kjournald]
Jan 14 19:51:55 localhost logger: 8,0 0 22 26.472050632 1138 D
W 12615 + 8 [kjournald]
Jan 14 19:51:55 localhost logger: 8,0 0 23 26.472162099 1138 U
N [kjournald] 1
Jan 14 19:51:55 localhost logger: 8,0 0 24 26.481685099 3 C
W 12615 + 8 [0]
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #19 from [email protected] 2009-01-15 07:48 -------
http://bugzilla.kernel.org/show_bug.cgi?id=12224
> ------- Comment #17 from [email protected] 2009-01-14 14:58 -------
> Created an attachment (id=19805)
--> (http://bugzilla.kernel.org/attachment.cgi?id=19805&action=view)
> --> (http://bugzilla.kernel.org/attachment.cgi?id=19805&action=view)
> patch reverting old change & adding Jan's proposed fix
Does this patch "revert the old change"?
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
[email protected] changed:
What |Removed |Added
----------------------------------------------------------------------------
Attachment #19805|0 |1
is obsolete| |
------- Comment #20 from [email protected] 2009-01-15 08:12 -------
Created an attachment (id=19814)
--> (http://bugzilla.kernel.org/attachment.cgi?id=19814&action=view)
Updated patch
sorry, didn't drive quilt right last time!
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
------- Comment #21 from [email protected] 2009-01-15 13:03 -------
http://bugzilla.kernel.org/show_bug.cgi?id=12224
> ------- Comment #20 from [email protected] 2009-01-15 08:12 -------
> Created an attachment (id=19814)
--> (http://bugzilla.kernel.org/attachment.cgi?id=19814&action=view)
> --> (http://bugzilla.kernel.org/attachment.cgi?id=19814&action=view)
> Updated patch
With the latest patch the problem seems to be fixed. btrace /dev/sda output
nothing after several minutes of activity on hda.
Thanks!
C.
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.
http://bugzilla.kernel.org/show_bug.cgi?id=12224
[email protected] changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |CLOSED
Resolution| |CODE_FIX
------- Comment #22 from [email protected] 2009-02-23 04:22 -------
The fix for this has landed in mainline as commit 02ac59 for ext3, and
commit 9eddac for ext4.
--
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.