[Samba] Re: XP "logon failure" but still logs on -- no roamingprofile

Brian White bcwhite at precidia.com
Sat Mar 15 00:13:37 GMT 2003


> hmmm..did you try running ...tcpdump -i eth0 ..on your samba box?
> (assuming eth0 is samba lan interface?) then you can "see" what is
> happening at the time..
> regards

Okay...  Done.  Below is the tcpdump from the time that I got the
error dialog while logging in until I initiated the logoff.  It's
about 240kB uncompressed (40kB compressed).

	http://bcwhite.dhs.org/~bcwhite/tcp.smbd-logoff_delay.gz

However, in summary...

There is pretty much constant traffic between "watertown" (the client) and
"griffon" (the server) up until:

[...]
18:36:00.011222 griffon.ott.precidia.com.netbios-ssn > watertown.ott.precidia.com.4451: S 3794220794:3794220794(0) ack 3
18:36:00.011512 griffon.ott.precidia.com.netbios-ssn > watertown.ott.precidia.com.4451: S 3794220794:3794220794(0) ack 3
18:36:00.011772 watertown.ott.precidia.com.4451 > griffon.ott.precidia.com.netbios-ssn: R 3385513384:3385513384(0) win 0
18:36:00.424875 watertown.ott.precidia.com.netbios-dgm > 10.0.3.63.netbios-dgm: 
18:36:07.211433 griffon.ott.precidia.com.www > watertown.ott.precidia.com.4454: F 837:837(0) ack 305 win 5840 (DF)
18:36:07.211750 griffon.ott.precidia.com.www > watertown.ott.precidia.com.4454: F 837:837(0) ack 305 win 5840 (DF)
18:36:07.212011 watertown.ott.precidia.com.4454 > griffon.ott.precidia.com.www: . ack 838 win 16684 (DF)

There are a few spurts of activity after that:

18:36:10.642363 watertown.ott.precidia.com.4450 > griffon.ott.precidia.com.445: P 18696:18741(45) ack 18030 win 16129 (D
18:36:10.646248 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18030:18069(39) ack 18741 win 2224 (DF
18:36:10.646558 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18030:18069(39) ack 18741 win 2224 (DF
18:36:10.766491 watertown.ott.precidia.com.4450 > griffon.ott.precidia.com.445: . ack 18069 win 16090 (DF)
18:36:11.463568 watertown.ott.precidia.com.4450 > griffon.ott.precidia.com.445: P 18741:18841(100) ack 18069 win 16090 (
18:36:11.497609 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18069:18108(39) ack 18841 win 2224 (DF
18:36:11.497914 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18069:18108(39) ack 18841 win 2224 (DF
18:36:11.669477 watertown.ott.precidia.com.4450 > griffon.ott.precidia.com.445: . ack 18108 win 17520 (DF)
18:36:11.731450 griffon1.ott.precidia.com.route > 10.0.3.63.route:  RIPv1-resp [items 8]: {10.0.2.64}(2) {10.0.2.128}(2)
18:36:11.731741 griffon1.ott.precidia.com.route > 10.0.3.63.route:  RIPv1-resp [items 8]: {10.0.2.64}(2) {10.0.2.128}(2)

Then there is a delay until I start the logoff procedure:

18:36:20.664208 watertown.ott.precidia.com.4450 > griffon.ott.precidia.com.445: P 18841:18884(43) ack 18108 win 17520 (D
18:36:20.666867 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18108:18151(43) ack 18884 win 2224 (DF
18:36:20.667168 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18108:18151(43) ack 18884 win 2224 (DF
18:36:20.667428 watertown.ott.precidia.com.4450 > griffon.ott.precidia.com.445: P 18884:18923(39) ack 18151 win 17477 (D
18:36:20.670643 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18151:18190(39) ack 18923 win 2224 (DF
18:36:20.670941 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18151:18190(39) ack 18923 win 2224 (DF
18:36:20.799476 watertown.ott.precidia.com.4450 > griffon.ott.precidia.com.445: . ack 18190 win 17438 (DF)
18:36:22.141603 watertown.ott.precidia.com.4450 > griffon.ott.precidia.com.445: P 18923:19023(100) ack 18190 win 17438 (
18:36:22.149477 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18190:18297(107) ack 19023 win 2224 (D
18:36:22.149785 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18190:18297(107) ack 19023 win 2224 (D
18:36:22.150432 watertown.ott.precidia.com.4450 > griffon.ott.precidia.com.445: P 19023:19163(140) ack 18297 win 17331 (
18:36:22.162845 griffon.ott.precidia.com.445 > watertown.ott.precidia.com.4450: P 18297:18348(51) ack 19163 win 2224 (DF
[...]

In this case, I counted 25 seconds before logging off since things seemed
to be running a bit slower (probably due to having the log level set to 20)
and didn't work the first time when I only waited 20 seconds.  It might
be related to idle time on the network before beginning logout.


I correlated these times to the log.smbd file (4060kB uncompressed,
215kB compressed), which I've placed here:

	http://bcwhite.dhs.org/~bcwhite/tcp.smbd-logoff_delay.gz

The end of the login sequence is:

[2003/03/14 18:35:59, 10] lib/util_sock.c:read_smb_length_return_keepalive(539)
  got smb length of 41
[2003/03/14 18:35:59, 6] smbd/process.c:process_smb(859)
  got message type 0x0 of len 0x29
[2003/03/14 18:35:59, 3] smbd/process.c:process_smb(860)
  Transaction 2235 of length 45
[...]


The next blips of traffic are:  (nothing shows for 18:36:07)

[2003/03/14 18:36:10, 10] lib/util_sock.c:read_smb_length_return_keepalive(539)
  got smb length of 41
[2003/03/14 18:36:10, 6] smbd/process.c:process_smb(859)
  got message type 0x0 of len 0x29
[2003/03/14 18:36:10, 3] smbd/process.c:process_smb(860)
  Transaction 2236 of length 45
[...]

[2003/03/14 18:36:11, 10] lib/util_sock.c:read_smb_length_return_keepalive(539)
  got smb length of 96
[2003/03/14 18:36:11, 6] smbd/process.c:process_smb(859)
  got message type 0x0 of len 0x60
[2003/03/14 18:36:11, 3] smbd/process.c:process_smb(860)
  Transaction 2237 of length 100
[...]


Finally, the logoff sequence begins:

[2003/03/14 18:36:20, 10] lib/util_sock.c:read_smb_length_return_keepalive(539)
  got smb length of 39
[2003/03/14 18:36:20, 6] smbd/process.c:process_smb(859)
  got message type 0x0 of len 0x27
[2003/03/14 18:36:20, 3] smbd/process.c:process_smb(860)
  Transaction 2238 of length 43
[...]



Anyway, it doesn't look to me like anything of note goes over the network
in this time.  My guess would have to be that something inside samba
or inside windoze is timing out.

-- Brian


> > > so if you reboot you get a successful logon? xp -pre sp1 ?
> >
> > Usually, yes.  I did get one case where it did not but the computer had been
> > on for a while before I tried to log on.
> >
> > SP1 was installed.  I just did another update of all critical updates but
> > it made no difference.  After I reboot, I could logon, logoff, logon, logoff,
> > but the third time I tried to logon, I got the error.
> >
> > On a hunch, I tried removing everything from the logon.bat script.  It
> > didn't help, though.  After a reboot, I could logon/off three times and
> > then I started getting the error.  Continuing logon/logoff sequences shows
> > no discernable pattern, though it only fails about 1/2 to 1/3 of the tries.
> >
> > After restoring the content of the logon.bat file, the logon process fails
> > much more often but not every time.  I began to wonder if it had something
> > to do with network activity/idle periods since when I was typing results
> > in to this message, it seemed that the next logon attempt would work.
> >
> > Taking a more patient approach to this, I've discovered that the problem is
> > at least somewhat related to how long I stay logged in.  With the full
> > login.bat content (because it makes the problem more obvious) I've discovered
> > that:
> >
> >  - Logout immediately after logon (waiting for logon.bat to complete first)
> >    causes a logon failure every time.
> >
> >  - Waiting 20 seconds after a logon failure before logout will ensure that
> >    the next logon attempt is successful.  Waiting only 10 seconds is not
> >    enough.  The next logon  attempt(after one that was successful) will fail
> >    even if I again wait over 30 _minutes_ before logout.
> >
> >  - Waiting at the "press CTRL-ALT-DELETE to logon" prompt, even up to 60
> >    seconds, does not help; it fails every time.
> >
> > Attached is the "logon.bat" file renamed to "logon.txt" so it doesn't get
> > stripped by any virus scanners.  In addition to mapping a number of network
> > drives, it also tries to map H: to /home/userid (if it exists) or to the
> > users home computer on the network if they're logging in to a different
> > machine (sort of like a unix automounter would do for home directories on
> > different machines).

                                          Brian
                                 ( bcwhite at precidia.com )

-------------------------------------------------------------------------------
"Everything that can be invented already has been."  --U.S. Patent Office, 1899


More information about the samba mailing list