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?

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?

might help you ferret out the miscreant process

I have the same and my fs_usage output looks like this:
Does this have anything to do with journalling or is it something else?

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.

re: ulrichm

you may want to examine the entries beyond one second :D 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

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

what is uptime vs. pageouts?

pmtool is part of activity monitor...

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

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

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

Do you have some kind of virtual desktop application running?

Yep. CodeTek Virtual Desktop. Hmmm.

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.

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.

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.

repeat:

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

what is uptime vs. pageouts?

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).

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?

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.

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.

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.

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. :D
I hope it helps others.

I believe it controls the short-cut buttons on the scanner.

OK, i never use them anyway, only through the programmes on my beloved G4 and they work. :)

If you want to keep these enhancements going, you might look into the preferences, and thin-out what you are asking them to do. I'm not familiar with DropDrawers, and I had discontinued DragThing until this most recent version which I am trying out again but: 1) If you are using the Window's Dock in DT, and asking it to update the names of the windows, that is asking for constant activity from DT; 2) if you have the process dock going, that is also asking for constant activity. 3) Similarly for 'Highlight running applications, Put the Trash on the Desktop, and Translucency settings. For CodeTek Virtual Desktop: (1) If you are using Mouse Focus, or (2) Switch Desktops using the Mouse, these no doubt require constant attention. (3) The frequency of updating the pager also affects attention to system events. (4) The complexity of the settings in the Applications Pane also probably plays a role.

I'm not sure why any of these would be causing a 'write' to the disk, but they would all require that significant attention be paid to system and application events. I don't notice the writing activity which you mentioned from these, but I do notice the system activity (open, read, close, of preferences, and CACHE_HIT from fs_usage). Where did you find the information about the writes?

I find CodeTeK to be very responsive, and Virtual Desktop to be very well-written and very useful. I'm sure they'll get to the bottom of whatever there is to get to the bottom of, and quickly.
---------------------
If everything else is quiet, I get cupsd activity once per second or so, and that is almost it, but again, it is not a write.

I am back at work. At home with everything quiet (nothing running but the Terminal), fs_usage shows only a cupsd every second or so and very little else. Here at work with everything as quiet, fs_usage shows about 80 lines per second of CACHE_HIT for the WindowServer. Here are 4 lines:

09:34:18 CACHE_HIT 0.000028 WindowServer
09:34:18 CACHE_HIT 0.000008 WindowServer
09:34:18 CACHE_HIT 0.000007 WindowServer
09:34:18 CACHE_HIT 0.000007 WindowServer

They *almost* cycle like that with about twenty sets of 4 (the 0.000028, 0.000008, 0.000007, 0.000007)

When I look in the Activity Monitor, it shows only the Dock, the Finder, the Terminal (with login, tsch, and fs_usage as children), Activity Monitor (with pmTool as a child), AppleSpell, and SystemUIServer. Only Terminal and Activity Monitor have children. I have no 3rd party PreferencePanes installed...no nothing that I can recall.

With 'top' and nothing else running, WindowServer uses sometimes 0.0, sometimes 0.9, sometimes 1.8% of the CPU.

There are only the occasional error in WindowServer.log:
Nov 14 08:31:53 [395] CGXPerformInitialDisplayConfiguration
Nov 14 08:31:53 [395] Display 0x42741c0: MappedDisplay Unit 0; Vendor 0x610 Model 0x9d07 S/N 0; online enabled built-in (0,0)[1152 x 864], base addr 0xb0018000
Nov 14 08:31:53 [395] Display 0x41dc9d00: VirtualDisplay Unit 0; Vendor 0x756e6b6e Model 0x76697274 S/N 0; offline enabled built-in (2176,0)[1 x 1], base addr 0xb0015000
Nov 14 08:31:54 [395] kCGErrorIllegalArgument: CGXSetWindowListTags: Operation on a window 0x1 not owned by caller SecurityAgent
Nov 14 08:31:55 [395] kCGErrorIllegalArgument: CGXOrderWindow: Operation on a window 0x1 not owned by caller SecurityAgent
Nov 14 08:32:04 [395] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "SystemUIServer" for over 1 second. Server has re-enabled them.
Nov 14 08:32:35 [395] kCGErrorIllegalArgument: CGXPostEventByConnection: invalid connection


The only difference I can think of is that this machine has Quartz Extreme and the one at home does not.

1) What is going on here;
and
2) If it is natural, why does it not happen at home?

OT, but this cracked me up.
:)

macmath:
- have a look in your startup items
- remember what is in there and where (take notes)
- clear out the entire list
- logout and back in

If your problem is now gone, as it was with me, you can narrow it down to one of the appliactions starting at login.
This way I found the HP Manager doing the weird things with my log file.
I hope it helps.

I have nothing in my login items. I used to, but prior to my last post, I removed everything and restarted. The activity still persists.

Thanks for the suggestion though.

I should have mentioned that I had already stripped all of the four desktop applications down to the most basic functions of providing simply switchable desktops (ala Linux) or giving me simply a pop-out shelf to put items into.

Especially with DragThing, I disabled everything else it could do besides that, and still got the excessive disk writes.

The writes are displayed in the Activity Monitor panel at about 2 to 8 per second, at about 20 to 80kb per. You can watch the disk capacity very slowly but constantly lowering, with an idle system.

I did receive an email from a CodeTek engineer who said there was a bug and be sure I was using the latest version, which I am, having received it the day before.

I just shut down and then booted in Safe-Mode, but not bothering to hold down the Shift key while logging in. The CACHE-HITs on WindowServer were gone from fs_usage, except when I actually moved a window. I have just restarted and they are back. So I guess I am looking at something system-installed, not user-installed.

How do I open the windowserver.log file in Console, it's 3.5MB, can access others, but can't get it to display?

CodeTek has asked for a copy to check out.

finally, after 26 hours of speculation, we get to see the real errors and the cause of your constant disk activity ?

learn how to use the file pager 'less'; use it to browse the file:

$ sudo less /var/log/windowserver.log

hmm, that logfile is secure, here:

$ ll /var/log/windowserver.log
-rw-r----- 1 root wheel - 24K 14 Nov 15:12 /var/log/windowserver.log

so, need a sudo to view it unless you're in the group wheel.

Here is portion of yesterday's WindowServer.log after a restart, and apparently after starting up and quitting DropDrawers. Seems it starts an endless process, the log continued where I cut off endlessly:

Nov 13 21:33:39 [5941] CGXPerformInitialDisplayConfiguration
Nov 13 21:33:39 [5941] Display 0x42702c0: MappedDisplay Unit 0; Vendor 0x610 Model 0x9c0b S/N 0; online enabled built-in (0,0)[1024 x 768], base addr 0xb0018000
Nov 13 21:33:39 [5941] Display 0x3f003d: MappedDisplay Unit 1; Vendor 0xffffffff Model 0xffffffff S/N -1; offline enabled (2048,0)[1 x 1], base addr 0xb0819000
Nov 13 21:33:39 [5941] Display 0x41dc9d00: VirtualDisplay Unit 0; Vendor 0x756e6b6e Model 0x76697274 S/N 0; offline enabled built-in (2049,0)[1 x 1], base addr 0xb0015000
Nov 13 21:33:40 [5941] kCGErrorIllegalArgument: CGXSetWindowListTags: Operation on a window 0x1 not owned by caller SecurityAgent
Nov 13 21:33:41 [5941] kCGErrorIllegalArgument: CGXOrderWindow: Operation on a window 0x1 not owned by caller SecurityAgent
Nov 13 21:33:54 [5941] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "SystemUIServer" for over 1 second. Server has re-enabled them.
Nov 13 21:34:09 [5941] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "Finder" for over 1 second. Server has re-enabled them.
Nov 13 21:34:11 [5941] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "Drop Drawers X" for over 1 second. Server has re-enabled them.
Nov 13 21:34:13 [5941] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "Finder" for over 1 second. Server has re-enabled them.
Nov 13 21:34:13 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:13 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:13 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:13 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:13 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:14 [5941] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "Drop Drawers X" for over 1 second. Server has re-enabled them.
Nov 13 21:34:16 [5941] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "Finder" for over 1 second. Server has re-enabled them.
Nov 13 21:34:17 [5941] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "Drop Drawers X" for over 1 second. Server has re-enabled them.
Nov 13 21:34:20 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:20 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:20 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:20 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:30 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:34:31 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:34:31 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:34:32 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:34:32 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:34:33 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:34:35 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:34:35 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:35 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:35 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:35 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:50 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:50 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:50 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:34:50 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:05 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:05 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:05 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:05 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:11 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:12 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:12 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:13 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:14 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:14 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:15 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:15 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:16 [5941] kCGErrorIllegalArgument: CGXPostEventByConnection: invalid connection
Nov 13 21:35:20 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:20 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:20 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:20 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:28 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:29 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:31 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:31 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:31 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:32 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:32 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:33 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:33 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:33 [5941] kCGErrorIllegalArgument: CGXGetWindowLevel: Invalid window 0
Nov 13 21:35:35 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:35 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:35 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:35 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:50 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:50 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:50 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area
Nov 13 21:35:50 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area

Restarting today, there seemed to be no connection with CodeTek, only with any of the three drawer applications (DropDrawers, XShelf or Drag Thing); starting any of them started the write cycles, quitting them stopped them.

Yet, without accessing CodeTek at all, the writes started while typing this and quit when CodeTek was closed. My hard drive is idle again.

Nope, accessing the WindowServer.log started the cycling again. Here is a portion of current WindowServer.log:

Nov 14 19:51:41 [229] CGXPerformInitialDisplayConfiguration
Nov 14 19:51:41 [229] Display 0x42702c0: MappedDisplay Unit 0; Vendor 0x610 Model 0x9c0b S/N 0; online enabled built-in (0,0)[1024 x 768], base addr 0xb0018000
Nov 14 19:51:41 [229] Display 0x3f003d: MappedDisplay Unit 1; Vendor 0xffffffff Model 0xffffffff S/N -1; offline enabled (2048,0)[1 x 1], base addr 0xb0819000
Nov 14 19:51:41 [229] Display 0x41dc9d00: VirtualDisplay Unit 0; Vendor 0x756e6b6e Model 0x76697274 S/N 0; offline enabled built-in (2049,0)[1 x 1], base addr 0xb0015000
Nov 14 19:51:43 [229] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "Unknown" for over 1 second. Server has re-enabled them.
Nov 14 19:51:58 [229] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "SystemUIServer" for over 1 second. Server has re-enabled them.
Nov 14 19:51:59 [229] kCGErrorFailure: CGXDisableUpdate: UI updates were forcibly disabled by application "Finder" for over 1 second. Server has re-enabled them.
Nov 14 19:52:08 [229] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area

and continuously on and on.


BTW, is there any harm in leaving permissions set for WindowServer.log to open in Console? Nah. I won't tempt it.

I don't any longer think that CodeTek VirtualDesktop is responsible for these things. When I use it, I seem to get many lines per second in windowserver.log like this:

Nov 13 21:34:13 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid tracking area

But on the other hand, today while I was out (with VirtualDesktop off since the last reboot), I got lines and lines of these in my windowserver.log and the mouse and keyboard were obviously completely idle. So I think that whatever causes these is not VirtualDesktop related (although use of VirtualDesktop might help the problem show up a bit more).


By the way, I guess I should not be surprised, but looking at the windowserver.log shows me the names of some of the files of another user on my computer at home:
19:37:09 getattrlist /.vol/234881033/341532/magnifying glass.cwk 0.000048 AppleWorks 6
19:37:09 getattrlist /.vol/234881033/341532/magnifying glass.cwk 0.000031 AppleWorks 6

This sounds a lot like the new Darwin defrag feature, It's been noted that just reading a file *can* result in up to 20MB of disk writes.

These features are dependant on Journalling, so by disabling it you will know if this is the cause of your disk writes.

Note: this is not a solution, its a way of ruling out a possible cause. dD

No, it does not sound like the new Darwin defrag feature, sorry.

It sounds like his window manager is logging tonnes of errors.

But the question is why. I have some errors in my log, but over an hour, this is all I have: I can fire up Drag Thing without any significant increase in windowserver.log errors. I always run virtual desktop, no problems there...

G4, 450MHz, AGP graphics, no Quartz Extreme

i've seen this on my machine from time to time dating all the way back to 10.1.

i've never been able to track down the reasons. the logging is maddeningly unspecific.

Rereading my posts, I realized it sounds like my OS is out of control, but its very much the opposite, which makes it all more mysterious.

Right now, there's no disk activity at all, CPU use is 2 - 20%, and idle with the following apps running: Safari, NetMonitor, Spell Checker, MemoryStick, TigerLaunch, PTHCPU, DiskSpy, and iClock.

Launching and quitting CodeTek or DragThing had no effect on that state this time. I will be paying very close attention to anything launched that does start the runaway writes process.

I understand there has been some contradictory reporting of what starts or ends the writes cascading here, but that makes it all the more puzzling.

examine the recent log entries. the bracketed [number] is the PID of the offending process, i believe.

e.g.,

Nov 13 21:35:50 [5941] kCGErrorIllegalArgument: CGXRemoveTrackingArea : Invalid

Nov 14 19:51:41 [229] CGXPerformInitialDisplayConfiguration


$ ps -p 5941

to display the process info, if the process still exists

that's a pretty useful tidbit.

although in this case, it might be slightly less useful than i thought.

i have a couple clumps of these types of errors in the past 24 hours, but the PID on the errors is always the WindowServer, which doesn't provide any helpful info.

heh. regrets. here, all the entries are logged by the...

windowserver !!

but, the [pid] notation applies to most logs.

229 is my WindowServer pid (is that arbitrary or universal), yet 5941 pid doesn't appear for any of the apps I've mentioned (does that also dynamically change day to day).

As far as I know the pid get assigned once the process gets started, therefore by starting the application or when the computer boots. as long as the process runs it will have the same pid.

Wild Windowserver fs_usage with Clean install!
 

Using Panther on my eMac at work, the command
sudo fs_usage continues to show 60-80 lines per second of

09:34:18 CACHE_HIT 0.000028 WindowServer
09:34:18 CACHE_HIT 0.000008 WindowServer
09:34:18 CACHE_HIT 0.000007 WindowServer
09:34:18 CACHE_HIT 0.000007 WindowServer

and I have yet to trace down the reason why. Nothing interesting (any different than those errors listed in this thread) shows up in the windowserver.log, and not nearly so frequent at that.

My computer at home does not show this extreme windowserver activity under sudo fs_usage, but just shows one item per second (usually cupsd). The installations are the same, with the only difference being the network connection and that the eMac can use Quartz Extreme while my iMac at home cannot. Starting under a Safe Boot silences these messages.

Finally, I took the extreme step of erasing and re-installing Panther. Before I installed anything at all, I checked the results of sudo fs_usage and it was still the same...60-80 lines per second of the above. Similarly after all Apple Updates (and no personal installations) had been applied.

Can anyone else verify this on
1) An early vintage eMac
or
2) A Macintosh with Quartz Extreme?

PS: I'm not asking you to verify what happens after a clean install, just what the results of 'sudo fs_usage' are. :-)

Requests:

1) Could someone with an early eMac and Panther please run "sudo fs_usage" in Terminal and let me know if you see a stream of lines like:

09:34:18 CACHE_HIT 0.000028 WindowServer
09:34:18 CACHE_HIT 0.000008 WindowServer
09:34:18 CACHE_HIT 0.000007 WindowServer
09:34:18 CACHE_HIT 0.000007 WindowServer


2) Could someone whose machine has Quartz Extreme please run "sudo fs_usage" in Terminal and let me know if you see a stream of lines like those above.

Control-C will exit the command.

Thank you.

I've just read in another thread that Quartz Extreme is disabled in Safe Mode. The streams of 60-80 lines per second of lines like these

09:34:18 CACHE_HIT 0.000028 WindowServer
09:34:18 CACHE_HIT 0.000008 WindowServer
09:34:18 CACHE_HIT 0.000007 WindowServer
09:34:18 CACHE_HIT 0.000007 WindowServer

when viewing fs_usage *do not* occur when my eMac is started in Safe Mode and they *do not* occur on my summer 2001 iMac (which does not permit QE). Perhaps this is a coincidence, but I cannot check it alone.

Could someone with Quartz Extreme please run

sudo fs_usage

in Terminal while l little else is going on and tell me whether or not you get streams and streams of the lines like those 4 above (around 70 per second).

I'd like to know if it is a matter with my machine or if it is a QE thing.

Please.

I now have a report from another original model eMac 700 MHz of the same activity (with a fresh installation of Panther on it). That is, about 70 lines per second of lines like these

09:34:18 CACHE_HIT 0.000028 WindowServer
09:34:18 CACHE_HIT 0.000008 WindowServer
09:34:18 CACHE_HIT 0.000007 WindowServer
09:34:18 CACHE_HIT 0.000007 WindowServer

when runnning 'sudo fs_usage'. So, it does not seem to be something only with my eMac. If I start up from OS X 10.2.8 (still on another partition), it this does not happen.

I am guessing that it is a QE and Panther problem, but I can't verify this until I can get some results with a non-eMac with Panther and QE.

Hi guys.

Located this thread, however it never seemed to reach a conclusion?

Can you help how to solve the repeated logs noted in the command:
sudo fs_usage

I have the same problems with hundreds of lines between written every few seconds. :(

I'm assuming you are talking about the CACHE_HIT lines from WindowServer
Why is this a problem? These lines are not being written to any file, hence disk space usage is not an issue. They merely reflect the fact that the WindowServer process is reading some data from a file (and that this file is cached in memory so the read is actually from RAM).

Yes. I was referring the logs, an example as below:
11:04:02 CACHE_HIT 0.000011 WindowServer
11:04:02 CACHE_HIT 0.000010 WindowServer
11:04:02 CACHE_HIT 0.000009 WindowServer
11:04:02 CACHE_HIT 0.000005 WindowServer
11:04:02 CACHE_HIT 0.000004 WindowServer
11:04:02 CACHE_HIT 0.000004 WindowServer

Hmm. Well interesting question? Maybe you are right and it is not a problem? Although another user in this topic noted that he only had a handful of logs and not thousands every few seconds. Could you please run sudo fs_usage and let me know the output please.

It does not sound like just RAM memory activity. I can hear the harddrive working.

Everything works ok, and enough time has gone by that I have come to accept it, but my original concern was that I was losing cpu cycles to something that did not need to be happening. To a greenhorn like me, 70-80 hits each second seems like a lot, and like it might get in the way of processes you want to be happening. Also, if it shouldn't be happening, then something could be wrong that will sneak up and bite you later. Perhaps SML has similar concerns. That having been said, if you watch fs_usage, the WindowServer hits seem to move out of the way when you have other processes active.

Exactly right macmath. I just want to make sure my new powerbook is running at its best performance and not wasting cpu and RAM and harddrive speed with an error proble.

Perhaps if some other users can note the output of the command, we may find it is perfectly normal?!

SML, if you can afford to increase your RAM from 256 to 640 or 768MB, I think that your PB would run circles around what it does now (and no doubt it does well now).

I didn't see any entries from WindowServer when I ran fs_usage for about a minute just now. But I don't have Quartz Extreme - I'm on an iBook from fall 2001.

If you hear drive activity, that is not from the CACHE_HIT's. It is something else. First thing to check is the pageins/pageouts listed under the System Memory tab in Activity Monitor. Lots of pageouts indicates you need more RAM.

There were heaps of constant page in/outs on the pmTool.

The system memory is pretty full with two or three apps running. Page ins/outs are 28047/19620 with the system turned on for a few hours. Seems constant though and not increasing - although I can still hear the hard drive activity.

So it sounds like something other than virtual memory is hitting the drive. If you are seeing a lot of CACHE_HIT's when you do fs_usage, it might be useful to filter them out so you can better see what is happening. You could do this with:

sudo fs_usage | grep -v CACHE_HIT

If there is something else you want to filter out, just add another grep -v for that at the end. E.g. to filter out all lines with "foo bar" in them:

sudo fs_usage | grep -v CACHE_HIT | grep -v "foo bar"

It is easy to see what is happening just from the fs_usage output. There is nothing else apart from the following .... and with the odd usual app process such as cups every minute or two. Here is the output with further detail - command
"sudo fs_usage -w"

16:48:05.077 CACHE_HIT A=0x118f6000 0.000004 WindowServer
16:48:05.077 CACHE_HIT A=0x118f6000 0.000004 WindowServer
16:48:05.077 CACHE_HIT A=0x118f6000 0.000004 WindowServer
16:48:05.077 CACHE_HIT A=0x118f6000 0.000004 WindowServer
16:48:05.078 CACHE_HIT A=0x118f6000 0.000004 WindowServer
16:48:05.078 CACHE_HIT A=0x118f6000 0.000004 WindowServer
16:48:05.078 CACHE_HIT A=0x118f6000 0.000004 WindowServer

Agree that more RAM will be great for my PB, but that is not the problem in this situation. Another user running 1.2Gb of RAM has the same problem.

Sorry, I've only just come across this thread. I had found the exact same problem on a friends ibook. After removal of the HPDeskjet driver the quite loud disk activity stopped.

Running SnapzPro?
 

I had this problem -- repeated errors logged to the windowserver.log.

Turns out the problem is a known (to Ambrosia) problem caused by an interaction between SnapzPro and any other application (for me, Codetek Desktop) that creates a weird (to WindowServer, invalid) window.

Quitting SnapzPro solved it for me.

Details here.

yep. same problem here. ambrosia blames it on another app. the only thing i think i had running was the launchbar 4 beta...

Sorry to bring up a very old thread, but it relates to my problem. Has anyone been able to fix this issue?

Here are the recent entries of my windowserver.log file:

Also getting the 60-80 instances of CACHE_HIT.

I too have tried disabling all startup items.

I believe this problem is preventing me from getting MythTV to operate properly, because everytime I run it it bails out and I get a new "kCGErrorIllegalArgument: CGXPostEventByConnection: invalid connection" entry in the log.

I have searched all over the place and have found nothing, so any help is appreciated.

This issue is solved (for me) by Tiger.