Panther: non-stop hard drive writing Activity?

Bruce Miller · 11-13-2003, 02:41 PM

Since installing Panther, my hard drive writes small files non-stop, at about one to four times per second, by observing Activity Monitor.

They are very small, several KB to several hundred, occasionally. Oddly, only writes, almost never reads.

Running an application with drive access stops the process temporarily, and it immediately starts again, after a pause.

I'm assuming it is involved with journaling or auto-defragging, but haven’t yet seen a mention about it yet.

Am I correct, and does it have an impact on the hard drive's longevity?

yellow · 11-13-2003, 03:50 PM

Sounds unusual.. Can you tell what process in Activity monitor appears to be doing it?
How much RAM does your computer have?
Does this manifest immediately after a reboot?

mervTormel · 11-13-2003, 03:55 PM

Code:

$ sudo fs_usage

might help you ferret out the miscreant process

ulrichm · 11-13-2003, 04:14 PM

I have the same and my fs_usage output looks like this:

Code:

22:12:17  CACHE_HIT                                                                   0.000093   WindowServer
22:12:17  CACHE_HIT                                                                   0.000013   WindowServer
22:12:17  CACHE_HIT                                                                   0.000005   WindowServer
22:12:17  CACHE_HIT                                                                   0.000007   WindowServer
22:12:17  CACHE_HIT                                                                   0.000011   WindowServer
22:12:17  CACHE_HIT                                                                   0.000007   WindowServer
22:12:17  CACHE_HIT                                                                   0.000012   WindowServer
22:12:17  CACHE_HIT                                                                   0.000010   WindowServer
22:12:17  CACHE_HIT                                                                   0.000006   WindowServer
22:12:17  CACHE_HIT                                                                   0.000009   WindowServer
22:12:17  CACHE_HIT                                                                   0.000003   WindowServer
22:12:17  CACHE_HIT                                                                   0.000003   WindowServer
22:12:17  CACHE_HIT                                                                   0.000003   WindowServer
22:12:17  CACHE_HIT                                                                   0.000003   WindowServer
22:12:17  CACHE_HIT                                                                   0.000003   WindowServer
22:12:17  CACHE_HIT                                                                   0.000003   WindowServer
22:12:17  CACHE_HIT                                                                   0.000003   WindowServer
22:12:17  CACHE_HIT                                                                   0.000003   WindowServer

Does this have anything to do with journalling or is it something else?

Bruce Miller · 11-13-2003, 04:32 PM

The only processes using any real (above 5%) CPU were pmtool, kernel_task, and WindowServer.

I have 1GB RAM, 797 used, 226 free

42278 pagin
10196 pageout

13 writeout per sec.

Data In 696MB
Data Out 1,001MB

Data In 0 bytes
Data Out 28kb/sec.

Sample portion of write log occurring above 1-2 per second:

16:18:20 close 0.000108 WindowServer
16:18:20 WrData[async] 0.000236 W WindowServer
16:18:20 open ate/var/log/windowserver.log 0.000034 WindowServer
16:18:20 fstat 0.000003 WindowServer
16:18:20 write 0.000022 WindowServer
16:18:20 close 0.000160 WindowServer
16:18:20 WrData[async] 0.000208 W WindowServer
16:18:20 open ate/var/log/windowserver.log 0.000045 WindowServer
16:18:20 fstat 0.000003 WindowServer
16:18:20 write 0.000028 WindowServer
16:18:20 close 0.000108 WindowServer
16:18:20 WrData[async] 0.000225 W WindowServer
16:18:20 open ate/var/log/windowserver.log 0.000035 WindowServer
16:18:20 fstat 0.000003 WindowServer
16:18:20 write 0.000022 WindowServer
16:18:20 close 0.000163 WindowServer
16:18:20 open ate/var/log/windowserver.log 0.000037 WindowServer
16:18:20 fstat 0.000002 WindowServer
16:18:20 WrData[async] 0.001115 W WindowServer
16:18:20 write 0.000781 W WindowServer
16:18:20 close 0.000166 WindowServer

This has been happening through restarts too.

I also get the same cache hits to WindowServer rhythmically also just mentioned.

mervTormel · 11-13-2003, 04:33 PM

re: ulrichm

you may want to examine the entries beyond one second

and during a more idle interval

it could be related to journaling, but let's not derail the troubleshooting with such narrow speculation so soon.

there are going to be many cache hits regardless of journaling or not

mervTormel · 11-13-2003, 04:35 PM

Quote:


	Originally posted by Bruce Miller ... 16:18:20 close 0.000163 WindowServer 16:18:20 open ate/var/log/windowserver.log 0.000037 WindowServer 16:18:20 fstat 0.000002 WindowServer 16:18:20 WrData[async] 0.001115 W WindowServer 16:18:20 write 0.000781 W WindowServer 16:18:20 close 0.000166 WindowServer This has been happening through restarts too.

so, if you examine your /var/log/windowserver.log, i bet it's getting beat to death.

what is uptime vs. pageouts?

mervTormel · 11-13-2003, 04:39 PM

pmtool is part of activity monitor...

/Applications/Utilities/Activity Monitor.app/Contents/Resources/pmTool

what is beating on your windowserver, flooding the log file?

macmath · 11-13-2003, 04:44 PM

....just to throw everybody off the path to the real solution...

Do you have some kind of virtual desktop application running?

Bruce Miller · 11-13-2003, 04:52 PM

Yep. CodeTek Virtual Desktop. Hmmm.

macmath · 11-13-2003, 04:56 PM

I have (and love) CodeTek Virtual Desktop too.

I don't think I get writes to the windowserver like you do, but if I move some windows in the pager and then go to the real windows and move/work with them, I get a ton of these:

Nov 13 15:45:44 [189] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 15:45:44 [189] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 15:45:44 [189] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area

whereas otherwise I do not.

These might very well be different issues, but I have noticed this in the past, so when mervTormel mentioned Windowserver, I thought I'd chime in.

ulrichm · 11-13-2003, 05:04 PM

Quote:


	Originally posted by mervTormel you may want to examine the entries beyond one second and during a more idle interval it could be related to journaling, but let's not derail the troubleshooting with such narrow speculation so soon. there are going to be many cache hits regardless of journaling or not

I let fs_usage run for a couple of seconds and only WindowServer shows up.

re: macmath: No, I do not have any Virtual Desktops installed.

macmath · 11-13-2003, 05:08 PM

I just did some further checking of the windowserver.log file and errors such as those I included above can occur even without VirtualDesktop running. They seem to be less common with VirtualDesktop off, however.

Anyway, VirtualDesktop is probably not a problem.

mervTormel · 11-13-2003, 05:10 PM

Quote:


	Originally posted by Bruce Miller Yep. CodeTek Virtual Desktop. Hmmm.

repeat:

so, if you examine your /var/log/windowserver.log, i bet it's getting beat to death.

what is uptime vs. pageouts?

Bruce Miller · 11-13-2003, 05:18 PM

Disabling CodeTEk log-in and restarting, and 75% of the disk writing stopped, but still have a bit of the constant writes (with no reads), about once every two to five seconds now.

So it seems its pretty obvious that these are log file writes (which restarting cleared out viewing free disk space before and after). Now onto the other(s) processes probably doing the same. Drop Drawers is suspect number one.

I did upgrade to Panther, installed the latest Panther compatible CodeTek version, but I see they added yet another update yesterday, so that may resolve it. Will have to check on the other haxies that "seemed" okay from Jaguar.

I had just assumed that those tiny writes were the "auto-defragging" or something, never thinking of runaway log writing, the most obvious (although the apps didn't misbehave that way back in 10.2.6, I booted back to double-check).

Bruce Miller · 11-13-2003, 05:49 PM

I identified the other two apps, observing fs_uasge: MemoryStick and iClock. Both are worth having to me, but I will certainly be on the lookout for alternatives or updates. No more disk thrashing. Thanks for the help.

Now I realize what a resouces pig PalmDesktop really is, even with log-in, all options and Hotsync manager turned off.

I'll be paying more attention to added applications and their headroom in the future.

BTW, how exactly DOES auto-defragging process files?

macmath · 11-13-2003, 06:38 PM

Bruce, just so I can compare to my windowserver.log file, what do you get if you type:

sudo cat /var/log/windowserver.log | grep 16:18:20

[This will give what was happening in windowserver.log at the same time as your data below.]

You might not want/need to post all of it, if it is very long.

Thanks in advance.

mervTormel · 11-13-2003, 06:45 PM

Quote:


	Originally posted by macmath Bruce, just so I can compare to my windowserver.log file, what do you get if you type: sudo cat /var/log/windowserver.log \| grep 16:18:20 [This will give what was happening in windowserver.log at the same time as your data below.] You might not want/need to post all of it, if it is very long.

hmm, that grep is unsound. how about looking at the log qua log to see what we can see qua see.

one can discern a lot from wholesale examination, then when we are confident of a dataset, add filters.

no sudo needed, i believe.

just peruse:

$ less /var/log/windowserver.log

this is what should have been examined when we discovered the flood of writes in fs_usage.

Bruce Miller · 11-14-2003, 02:28 AM

Further investigation revealed that having BOTH CodeTek Virtual Desktop and Drop Drawers launched caused the very high disk writes.

Individually either halved the writes per second, quitting both and idle system disk writes nearly ceased (except for Memory Stick's 15 second polling interval and other more rare items).

The really odd thing is that while Drop Drawers is quite aged, with last updating in 2002, trying two other latest versions similar tools, freeware XShelf and popular DragThing, both very recently updated for Panther, did the exact same thing, writing small files to disk at the distressing rate of about twice per second when launched. Quitting either, and the constant disk writing ceased immediately.

With CodeTek, that makes four out of four desktop enhancement apps doing this. Again, none exhibited the same behavior in Jaguar.

Has something fundamentally changed in Panther, and why isn't it being better addressed by authors? I have an email in to CodeTek about the phenomenon, and anticipate a typically pretty prompt reply.

ulrichm · 11-14-2003, 04:42 AM

I have finally found the culprit: HP ScanJet Manager for my HP5500c Scanner. Removing it from the StartupItems also removed the constant writing activity to the windowserver.log file. The scanner still works as before, therefore I do not quite know what this Manager did, but like with some human Managers it seems superfluous.

I hope it helps others.

11-13-2003, 02:41 PM	#1
Bruce Miller Major Leaguer Join Date: Mar 2002 Location: Rochester, NY Posts: 359	Panther: non-stop hard drive writing Activity? Since installing Panther, my hard drive writes small files non-stop, at about one to four times per second, by observing Activity Monitor. They are very small, several KB to several hundred, occasionally. Oddly, only writes, almost never reads. Running an application with drive access stops the process temporarily, and it immediately starts again, after a pause. I'm assuming it is involved with journaling or auto-defragging, but haven’t yet seen a mention about it yet. Am I correct, and does it have an impact on the hard drive's longevity?

11-13-2003, 03:55 PM	#3
mervTormel League Commissioner Join Date: Jan 2002 Posts: 5,536	Code: $ sudo fs_usage might help you ferret out the miscreant process

11-13-2003, 04:32 PM	#5
Bruce Miller Major Leaguer Join Date: Mar 2002 Location: Rochester, NY Posts: 359	The only processes using any real (above 5%) CPU were pmtool, kernel_task, and WindowServer. I have 1GB RAM, 797 used, 226 free 42278 pagin 10196 pageout 13 writeout per sec. Data In 696MB Data Out 1,001MB Data In 0 bytes Data Out 28kb/sec. Sample portion of write log occurring above 1-2 per second: 16:18:20 close 0.000108 WindowServer 16:18:20 WrData[async] 0.000236 W WindowServer 16:18:20 open ate/var/log/windowserver.log 0.000034 WindowServer 16:18:20 fstat 0.000003 WindowServer 16:18:20 write 0.000022 WindowServer 16:18:20 close 0.000160 WindowServer 16:18:20 WrData[async] 0.000208 W WindowServer 16:18:20 open ate/var/log/windowserver.log 0.000045 WindowServer 16:18:20 fstat 0.000003 WindowServer 16:18:20 write 0.000028 WindowServer 16:18:20 close 0.000108 WindowServer 16:18:20 WrData[async] 0.000225 W WindowServer 16:18:20 open ate/var/log/windowserver.log 0.000035 WindowServer 16:18:20 fstat 0.000003 WindowServer 16:18:20 write 0.000022 WindowServer 16:18:20 close 0.000163 WindowServer 16:18:20 open ate/var/log/windowserver.log 0.000037 WindowServer 16:18:20 fstat 0.000002 WindowServer 16:18:20 WrData[async] 0.001115 W WindowServer 16:18:20 write 0.000781 W WindowServer 16:18:20 close 0.000166 WindowServer This has been happening through restarts too. I also get the same cache hits to WindowServer rhythmically also just mentioned. Last edited by Bruce Miller; 11-13-2003 at 04:35 PM.

Thread Tools
Show Printable Version Email this Page
Display Modes	Rate This Thread
Switch to Linear Mode Hybrid Mode Switch to Threaded Mode	Rate This Thread:

11-13-2003, 03:50 PM	#2
yellow Moderator Join Date: Jan 2002 Posts: 10,660	Sounds unusual.. Can you tell what process in Activity monitor appears to be doing it? How much RAM does your computer have? Does this manifest immediately after a reboot?

11-13-2003, 04:33 PM	#6
mervTormel League Commissioner Join Date: Jan 2002 Posts: 5,536	re: ulrichm you may want to examine the entries beyond one second and during a more idle interval it could be related to journaling, but let's not derail the troubleshooting with such narrow speculation so soon. there are going to be many cache hits regardless of journaling or not

11-13-2003, 04:39 PM	#8
mervTormel League Commissioner Join Date: Jan 2002 Posts: 5,536	pmtool is part of activity monitor... /Applications/Utilities/Activity Monitor.app/Contents/Resources/pmTool what is beating on your windowserver, flooding the log file?

11-13-2003, 04:44 PM	#9
macmath MVP Join Date: Mar 2002 Location: Elsewhere Posts: 1,476	....just to throw everybody off the path to the real solution... Do you have some kind of virtual desktop application running?

11-13-2003, 04:52 PM	#10
Bruce Miller Major Leaguer Join Date: Mar 2002 Location: Rochester, NY Posts: 359	Yep. CodeTek Virtual Desktop. Hmmm.

11-13-2003, 04:56 PM	#11
macmath MVP Join Date: Mar 2002 Location: Elsewhere Posts: 1,476	I have (and love) CodeTek Virtual Desktop too. I don't think I get writes to the windowserver like you do, but if I move some windows in the pager and then go to the real windows and move/work with them, I get a ton of these: Nov 13 15:45:44 [189] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area Nov 13 15:45:44 [189] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area Nov 13 15:45:44 [189] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area whereas otherwise I do not. These might very well be different issues, but I have noticed this in the past, so when mervTormel mentioned Windowserver, I thought I'd chime in.

11-13-2003, 05:08 PM	#13
macmath MVP Join Date: Mar 2002 Location: Elsewhere Posts: 1,476	I just did some further checking of the windowserver.log file and errors such as those I included above can occur even without VirtualDesktop running. They seem to be less common with VirtualDesktop off, however. Anyway, VirtualDesktop is probably not a problem.

11-13-2003, 05:18 PM	#15
Bruce Miller Major Leaguer Join Date: Mar 2002 Location: Rochester, NY Posts: 359	Disabling CodeTEk log-in and restarting, and 75% of the disk writing stopped, but still have a bit of the constant writes (with no reads), about once every two to five seconds now. So it seems its pretty obvious that these are log file writes (which restarting cleared out viewing free disk space before and after). Now onto the other(s) processes probably doing the same. Drop Drawers is suspect number one. I did upgrade to Panther, installed the latest Panther compatible CodeTek version, but I see they added yet another update yesterday, so that may resolve it. Will have to check on the other haxies that "seemed" okay from Jaguar. I had just assumed that those tiny writes were the "auto-defragging" or something, never thinking of runaway log writing, the most obvious (although the apps didn't misbehave that way back in 10.2.6, I booted back to double-check).

11-13-2003, 05:49 PM	#16
Bruce Miller Major Leaguer Join Date: Mar 2002 Location: Rochester, NY Posts: 359	I identified the other two apps, observing fs_uasge: MemoryStick and iClock. Both are worth having to me, but I will certainly be on the lookout for alternatives or updates. No more disk thrashing. Thanks for the help. Now I realize what a resouces pig PalmDesktop really is, even with log-in, all options and Hotsync manager turned off. I'll be paying more attention to added applications and their headroom in the future. BTW, how exactly DOES auto-defragging process files?

11-13-2003, 06:38 PM	#17
macmath MVP Join Date: Mar 2002 Location: Elsewhere Posts: 1,476	Bruce, just so I can compare to my windowserver.log file, what do you get if you type: sudo cat /var/log/windowserver.log \| grep 16:18:20 [This will give what was happening in windowserver.log at the same time as your data below.] You might not want/need to post all of it, if it is very long. Thanks in advance.

11-14-2003, 02:28 AM	#19
Bruce Miller Major Leaguer Join Date: Mar 2002 Location: Rochester, NY Posts: 359	Further investigation revealed that having BOTH CodeTek Virtual Desktop and Drop Drawers launched caused the very high disk writes. Individually either halved the writes per second, quitting both and idle system disk writes nearly ceased (except for Memory Stick's 15 second polling interval and other more rare items). The really odd thing is that while Drop Drawers is quite aged, with last updating in 2002, trying two other latest versions similar tools, freeware XShelf and popular DragThing, both very recently updated for Panther, did the exact same thing, writing small files to disk at the distressing rate of about twice per second when launched. Quitting either, and the constant disk writing ceased immediately. With CodeTek, that makes four out of four desktop enhancement apps doing this. Again, none exhibited the same behavior in Jaguar. Has something fundamentally changed in Panther, and why isn't it being better addressed by authors? I have an email in to CodeTek about the phenomenon, and anticipate a typically pretty prompt reply.

11-14-2003, 04:42 AM	#20
ulrichm All Star Join Date: Oct 2003 Location: The Netherlands Posts: 741	I have finally found the culprit: HP ScanJet Manager for my HP5500c Scanner. Removing it from the StartupItems also removed the constant writing activity to the windowserver.log file. The scanner still works as before, therefore I do not quite know what this Manager did, but like with some human Managers it seems superfluous. I hope it helps others.