Serious issue with 10.3.8 windowserver and multiple users

Discussion in 'Apple' started by Drew D. Saur, Mar 12, 2005.

  1. Drew D. Saur

    Drew D. Saur Guest

    If you use Mac OS X 10.3.8 with fast user switching, and you have
    noticed unusual hard drive activity, then you'll want to read this.

    I have found what appears to be a serious issue with the windowserver in
    10.3.8 and multiple users / fast user switching. I have consistently
    reproduced this issue on two different machines that I own. It causes
    your /var/log/windowserver.log to expand alarmingly rapidly, and does
    not appear to be associated with any third party software. (Note: it may
    occur with earlier releases of 10.3.x as well; I have not been able to
    verify.)

    The short story is, there appears to be a bug in 10.3.8 wherein one user
    owns the window server process at any given time, and when two or more
    people begin using the machine through fast user switching, the
    windowserver daemon balks about this conflict, endlessly writing to the
    end of the windowserver log file until the conflicting user(s) log out.

    Here are the steps that can be taken to consistently reproduce it:

    1) Reboot your machine.

    2) When presented with the main login window (this presumes a multi-user
    environment), log in as a *non* administrative user.

    3) Stay logged in, and use fast user switching to switch to the admin
    user.

    4) Open a terminal window, and type "sudo tail -f
    /var/log/windowserver.log". After typing your admin password, this will
    present an active, constantly updating view of the windowserver.log
    file. The last few lines, which will be visible, may have a variety of
    interesting things, but you should not see any active updating of the
    file....yet.

    5) Keep the terminal window open. Again using fast user switching, log
    back into the non-admin account you first logged into.

    6) Log out of that account. You will go back to the main login screen.

    7) Log back into the administrative account. In the terminal window, you
    should see a few errors at the end of the windowserver.log file reported
    by the "kCGErrorIllegalArgument: CGXSetCredentials" routine. This is
    where it starts to get interesting....

    8) Keep the terminal window open. Again, using fast user switching, log
    back into the non-admin account you first logged into;

    9) Once logged back into this non-admin account, use fast user switching
    to switch right back to the admin account.

    10) When you return, you will see the windowserver.log being constantly
    appended with the following errors at the end:

    Mar 11 23:04:05 [178] kCGErrorIllegalArgument: CGXSetCredentials :
    Unauthorized user (501) for session 258
    Mar 11 23:04:05 [178] kCGErrorIllegalArgument: CGXSetCredentials :
    Unauthorized user (502) for session 258
    Mar 11 23:04:06 [178] kCGErrorIllegalArgument: CGXSetCredentials :
    Unauthorized user (501) for session 258
    Mar 11 23:04:06 [178] kCGErrorIllegalArgument: CGXSetCredentials :
    Unauthorized user (502) for session 258
    Mar 11 23:04:06 [178] kCGErrorIllegalArgument: CGXSetCredentials :
    Unauthorized user (501) for session 258
    ..
    ..
    ..

    What's going on here?

    What this means is that, as a user of a multi-user machine in 10.3.8,
    you will frequently hear the hard drive writing to this log file (and
    you will slowly lose disk space - albeit more slowly than the infamous
    iShock/10.3.8/system.log issue) as you are working, so long as you are
    one of multiple logged-in users. This is *especially* likely to happen
    if a non-admin user is the first user to log into the machine.

    The longer story:

    If you review the log contents above, the bracketed number refers to the
    individual process ID (PID) that is generating this error. In the case
    above, if you perform a 'ps- aux | grep 178' you will see that this PID
    represents the windowserver daemon:

    [admin:~]$ ps -aux | grep 178
    admin 178 24.0 3.5 69428 23152 ?? Ss 10:57PM 0:59.82
    /System/Library/Frameworks/ApplicationServices.framework/Frameworks/CoreG
    raphics.framework/Resources/WindowServer -daemon

    Although I am not sure that this is the ultimate cause, I have noticed
    that when a non-admin user is the first to log in, this user maintains
    ownership of the windowserver daemon and its operations (and ostensibly
    its systemwide caching), and this is when the problems start.

    If an admin is the first person to run the windowserver daemon, this
    problem takes a little while longer to manifest itself....but it
    eventually still does, as users switch in and out using fast user
    switching and the windowserver process is tossed around between users.

    As a side note, this seems to happen whether or not one uses the
    fantastic WinSwitch utility to perform fast user switching; one machine
    I tested it on had WinSwitch installed and the other did not.

    I only have two machines at my disposal to verify this, but it certainly
    would be interesting to see if others can reproduce this problem. It's
    quite insidious, and I am surprised that I haven't read about it
    anywhere else yet.

    Thanks for whatever you can do to identify this issue.

    Best regards,

    Drew
     
    Drew D. Saur, Mar 12, 2005
    #1
    1. Advertisements

  2. Drew D. Saur

    Elijah Baley Guest

    I am using OS X 10.3.8 on a dual 2.5 G5 with five user accounts (family
    machine). There are frequently several users logged in at the same time
    using fast user switching to move between accounts. I just pulled up the
    /var/log/windowserver.log file and found it to be only 52KB in size. I
    opened the log file with Console and found it to be empty. The scenario
    you describe does not appear to be happening on my machine.
     
    Elijah Baley, Mar 12, 2005
    #2
    1. Advertisements

  3. Drew D. Saur

    matt neuburg Guest

    So did you report this bug to Apple? If not, you're just whistling in
    the wind here, despite your superb detective work. m.
     
    matt neuburg, Mar 12, 2005
    #3
  4. Drew D. Saur

    Drew D. Saur Guest

    Yes, absolutely; I always use Apple's feedback forms when I encounter a
    bug like this.

    And, on the Apple forums, where I also posted this, people generally
    seemed more concerned about me telling Apple than trying it themselves.

    At any rate, I hope this thread can turn out to be a productive analysis
    of the issue!

    Drew
     
    Drew D. Saur, Mar 13, 2005
    #4
  5. Drew D. Saur

    Drew D. Saur Guest

    Thanks - did you try to reproduce by following the steps?

    As additional background: There are many, many scenarios under which
    this does not occur, and there are many scenarios under which the
    behavior starts and stops. I felt that a post detailing all of these
    behaviors ad nauseam would be a little tedious for people to read, so I
    avoided that. I stuck with the one method that was sure to invoke it,
    and unfortunately that starts from a reboot and proceeds as described.

    If you do have a chance to follow the steps from scratch, I would
    personally appreciate you reporting what you then find!

    FWIW, I did walk a friend through this earlier today and he also was
    able to replicate the issue. So that makes three....

    Thanks again,

    Drew
     
    Drew D. Saur, Mar 13, 2005
    #5
  6. Drew D. Saur

    matt neuburg Guest

    Excellent, thanks.
    Probably for the same reason. If there's a bug, telling Apple is enough;
    collection of further instances is irrelevant. I mean to say, I was very
    grateful to read your careful report of the problem (especially since I
    too am the discoverer and reporter of a bug that causes windowserver.log
    to get big, having to do with stuff on the desktop); and I shall try to
    avoid getting into the situation you describe (though my parents
    computer is set up as I understand you to be describing, and I've never
    seen the bug happen there); but apart from this it is quite unclear to
    me what you expect your readers, or anyone but Apple, to *do*. m.
     
    matt neuburg, Mar 13, 2005
    #6
  7. Drew D. Saur

    Drew D. Saur Guest

    That is not true. Apple is much more likely to attack a problem that
    affects more people than one which affects one person.
    I generally expect people who may have some time and who are willing to
    contribute to the general knowledge to try this out, and report back
    what they see. Even with three machines having this issue, it can't hurt
    to identify more to see if there is some sort of pattern. In particular,
    for instance, it might be interesting to know if this happens with <
    10.3.8.

    At any rate, let's see if we can get this thread back on track - not
    make it a discussion of how to approach problems, but of what people are
    finding on *this* windowserver / fast user switching problem in
    particular!

    Best regards,

    Drew
     
    Drew D. Saur, Mar 13, 2005
    #7
  8. Drew D. Saur

    G.T. Guest

    I still have 10.3.7 so I'll give it a shot bother before and after
    updating to 10.3.8.
     
    G.T., Mar 14, 2005
    #8
  9. Drew D. Saur

    Drew D. Saur Guest

    Please do! This bug is unfortunately not getting the attention it
    deserves.

    Drew
     
    Drew D. Saur, Mar 15, 2005
    #9
  10. Drew D. Saur

    Jeff Wiseman Guest

    I have a G5 iMac running OS 10.3.6. I did a real quick test using
    Drew's scenario and got basically the same results. I didn't have
    a lot of time to fool around with it but I did have the following
    additional observations:

    In my situation, the loading of the windowserver.log file is not
    continuous. Once the environment is set up for it, it seems to
    happen in 2 to 3 second bursts anytime a fast swtich occurs. In
    my case, doing a fast switch between logged in users resulted in
    nearly 250 messages being dumped into the log but then it seemed
    to stabilize until the next switch. It is as though there is some
    type of glare condition is triggered by the fast switch that
    eventually corrects itself and stops the flow of messages.
    Message generation only occurs for a period of 2 or 3 seconds
    before being shut off. However, as mentioned before, any
    subsequent fast switches seem to retrigger the burst.

    In my test I only switched between users. I did not try running
    applications or anything like that. I suppose it's possible that
    running applications that bring up new windows might potentially
    trigger these messages as well. That might be an interesting test
    as well.
     
    Jeff Wiseman, Mar 15, 2005
    #10
  11. Drew D. Saur

    Drew D. Saur Guest

    Thanks for the update, Jeff - it's interesting to note that it happens
    on earlier versions of 10.3 as well.

    I have noticed that the issue slows down after a while as well, but I
    have also noticed that on certain user switches, it never slows down.
    Unfortunately, I have not been able to identify a pattern for this.

    Drew
     
    Drew D. Saur, Mar 16, 2005
    #11
  12. Drew D. Saur

    Mike Guest

    I have the same problem on my machine and the only two users to ever
    log in are both admin users. Oddly, it seems to happen only if the
    other person logs in first. If I log in first windowserver is
    well-behaved. If she logs in first windowserver goes nuts, consumes
    50+% of the processor time and continuously writes to the log file.
     
    Mike, Mar 17, 2005
    #12
  13. Drew D. Saur

    Jeff Wiseman Guest


    I chanced upon something else that is also very interesting,
    definately a bug, and is likely related to the windowserver issue.

    I've not tested any login sequence scenarios, but I'm discovering
    that when certain people logout, the system thinks that they are
    still logged in. This could be related to the confused server
    ownership issues of the original problem.

    Just go to a terminal window and type in "who" which is supposed
    to show all logged in users. Right now, it shows my wife as being
    logged in but she logged off over a day ago.

    Obviously, this may or may not show up depending on the sequence
    of logins.
     
    Jeff Wiseman, Mar 23, 2005
    #13

  14. I chanced upon something else that is also very interesting,
    definately a bug, and is likely related to the windowserver issue.

    I've not tested any login sequence scenarios, but I'm discovering
    that when certain people logout, the system thinks that they are
    still logged in. This could be related to the confused server
    ownership issues of the original problem.

    Just go to a terminal window and type in "who" which is supposed
    to show all logged in users. Right now, it shows my wife as being
    logged in but she logged off over a day ago.

    Obviously, this may or may not show up depending on the sequence
    of logins.[/QUOTE]

    If you do

    w

    at the Terminal prompt, what do you see?

    You should only see 1 process logged into the console (yours) and a
    bunch of subprocesses to that.

    If you do

    ps -auxwww | grep -i window

    do you see the window server and loginwindow owned by you? If not,
    might be a bug. Log the problem under your AppleCare contract.
     
    Michael Vilain, Mar 23, 2005
    #14
  15. Drew D. Saur

    Drew D. Saur Guest

    If you do

    w

    at the Terminal prompt, what do you see?

    You should only see 1 process logged into the console (yours) and a
    bunch of subprocesses to that.

    If you do

    ps -auxwww | grep -i window

    do you see the window server and loginwindow owned by you? If not,
    might be a bug. Log the problem under your AppleCare contract.[/QUOTE]

    Here's an interesting thing; I did this and showed the following:

    [drew:~]$ ps -auxwww | grep -i window
    charles 552 0.0 0.3 200148 5272 ?? Ss 6:51PM 0:00.53
    /System/Library/CoreServices/loginwindow.app/Contents/MacOS/loginwindow
    console
    charles 554 0.0 2.9 216340 45152 ?? Ss 6:51PM 0:22.34
    /System/Library/Frameworks/ApplicationServices.framework/Frameworks/CoreG
    raphics.framework/Resources/WindowServer -daemon
    drew 580 0.0 0.3 198096 4644 ?? Ss 6:53PM 0:00.61
    /System/Library/CoreServices/loginwindow.app/Contents/MacOS/loginwindow
    drew 623 0.0 0.0 18172 336 std S+ 7:00PM 0:00.01
    grep -i window

    I am "drew" and the other user is "charles" - charles is also logged in,
    but I am the active user of the machine.

    A few minutes later:

    [drew:~]$ ps -auxwww | grep -i window
    drew 554 3.6 3.0 219864 47224 ?? Ss 6:51PM 0:25.85
    /System/Library/Frameworks/ApplicationServices.framework/Frameworks/CoreG
    raphics.framework/Resources/WindowServer -daemon
    charles 552 0.0 0.3 200148 5272 ?? Ss 6:51PM 0:00.53
    /System/Library/CoreServices/loginwindow.app/Contents/MacOS/loginwindow
    console
    drew 580 0.0 0.3 200460 5300 ?? Ss 6:53PM 0:00.64
    /System/Library/CoreServices/loginwindow.app/Contents/MacOS/loginwindow
    drew 641 0.0 0.0 8864 200 std R+ 7:03PM 0:00.01
    grep -i window

    ....now I own the windowserver process. Didn't really do anything to
    instigate this, other than perhaps an "su - admin" to do my tail to the
    windowserver.log to see what was going on. That might have kicked it;
    who knows.

    At any rate, in my experience, only ONE person owns windowserver at any
    given time, and that does make some sense to me. Are you saying that in
    your instance, you have more than one instance of windowserver running
    when there are multiple users logged in? Not a one of my machines
    exhibits this behavior...

    Here's another interesting thing, though; I think the story tells itself:

    [drew:~]$ whoami
    drew
    [drew:~]$ who
    charles console Mar 23 18:51
    [drew:~]$ w
    19:10 up 3:10, 1 user, load averages: 0.11 0.16 0.20
    USER TTY FROM LOGIN@ IDLE WHAT
    charles console - 18:51 19 -

    Huh?...What in the heck can cause this?

    Drew
     
    Drew D. Saur, Mar 24, 2005
    #15
  16. I've only ever seen 1 window manager process running _AND_ one
    loginwindow process. Sorry if you misunderstood what I posted.

    When I do "whoami", it displays my effective UID (can different from the
    real UID). sudo or su change your effective UID to the new user's UID.
    This behavior seems to make sense to me. What's your concern with what
    you're seeing you your system?

    It's my "SWAG" that the windows server process either starts when a user
    logs in, which is why they "own" it. Or the process is always running
    (aka it's a daemon, which on my machine seems to be the case) but is
    owned by root when only the login window is displayed. The ability to
    change user is a unix thing. Don't know if the behavior you're
    describing where it's not chuser-ing to the current user immediately is
    a bug or "feature" or the way it's designed to work. What does the
    /var/log/windowserver.log and /var/log/windowserver_last.log show?
    Anything interesting around the time you logout and your wife logs in or
    vice versa?

    I'll ask you this, is this behavior a problem? How so? Is it enough of
    a problem to want to log a support call with Apple?
     
    Michael Vilain, Mar 24, 2005
    #16
  17. Drew D. Saur

    Drew D. Saur Guest

    In the case immediately above, the issue is that I don't see myself at
    all, but only the *other* logged in user. When I FUS to the other user
    (charles), and w or who, I only see him as well.
    Yes, this makes sense; I do indeed think I misunderstood your earlier
    comments to imply that there should be more than one. No problem there,
    but back to that "w" and "who" issue: that's a strange one....

    Drew
     
    Drew D. Saur, Mar 24, 2005
    #17
  18. Drew D. Saur

    Jeff Wiseman Guest

    This is why I thought it significant relative to the original
    posting for the thread. Under certain conditions (e.g., initial
    login by standard account followed by login of admin account) the
    "owndership" of windowserver seems to be incontention. You can
    see it in the logfile by the usr IDs. I've seen situations where
    the who command shows someone being logged in who isn't.
    Obviously, the tracking of who's logged in and who ain't is also
    associated with who is supposed to be holding the windoserver
    process ownership (remember, it seems to be the switching between
    owners that is causing the problem). If the system has a bug
    where it thinks folks are logged in who aren't and then condition
    seems to be created in the same way that you initiate the other
    problem (runaway windowserver.log files), then there's a
    possibility that the two are related.

    Drews "w" and "who" issue is basically the same as the phantom
    user issue that I was talking about.
     
    Jeff Wiseman, Mar 24, 2005
    #18
  19. Drew D. Saur

    Drew D. Saur Guest

    Yes, indeed this is something I noticed in my original analysis of the
    windowserver condition.

    There's definitely something going on, and it's not cool. It bothers a
    certain bone in my body, even though it doesn't cause daily issues. It
    means that under the hood, somebody's not paying attention to some
    permission/security issues that are fairly core to the system, and it's
    really sloppy, unprofessional, and disappointing. I expect a bit more of
    Apple!

    Drew
     
    Drew D. Saur, Mar 24, 2005
    #19
    1. Advertisements

Ask a Question

Want to reply to this thread or ask your own question?

You'll need to choose a username for the site, which only take a couple of moments (here). After that, you can post your question and our members will help you out.