Problem with connection database

[MCCALL,DON (HP-USA,ex1)]

Hi Claus,
I have a guy in my lab looking at it (strictly 'off the record').
I have also been able to reproduce the corruption in the connections.tdb
by stressing (using a looping smbclient script) samba 2.2 CVS on a 
LINUX 2.2.19pre17-compact box, IF I use the "use mmap=false" smb.conf
parameter, to force all
the reads/writes/seeks, etc to the connections.tdb to be filesystem instead
of mmap stuff.  Based on this, and your senario, where it looks like the
locking tdb is being
stressed by a LOT of access due to these huge files, it seems like it may be
some sort of race 
condition, but I'm completely guessing here.
I am going to refine my reproduction senario on this platform (Linux)
and see if I can get Andrew/Jeremy involved (they can't really do much if
it's 
only happening on HP-UX, but if I make it reproducable on Linux, maybe they
can help).

I agree with you, it's very odd that the same sort of corruption would occur
with both gcc and cc complies, as well as the fact that people have reported
this accross HP-UX opsys 9.05/10.20/11.0, where you KNOW so much has changed
with the libc, etc...  My suspicion is that HP-UX is seeing this so much
because we 
are NOT using mmap, and so the stress is showing up when the tdb files are
being manipulated
strictly via fs calls.

I will certainly post any progress to both samba technical and samba mailing
lists,
cc'ing you.

-----Original Message-----
From: Claus Svarer [mailto:csvarer at nru.dk]
Sent: Thursday, September 06, 2001 5:53 AM
To: MCCALL,DON (HP-USA,ex1)
Subject: Re: Problem with connection database


Hi Don

I saw you last week send a message to the samba-technical mailing list, that
you
were able to reproduce the error (corruction in connection.tdb database
file).
Have you had any response from people trying to find the reason for the
corruption. I believe you are right that it can be problems with the type
casting in the tdb code that doesn't work at the HP system (there was
another
mail at the samba-technical about that, a guy that try to lint at the code).
The
only problem I have with this explanation is that we have seen the same
problems
even if we use gcc to compile the code (I don't know if this totally changes
the
way to handle the system calls, I belive the calls are declared through HP
system include files?)

We are a bit frustrated that the samba.server still chrashes at least once a
day
for us, therefor I look very much forward to hearing about a solution.

Best regards
Claus

"MCCALL,DON (HP-USA,ex1)" wrote:

> Hi Claus,
> Tell me a little more about the environment in which this is happening:
>
> max concurrent connections to samba (guess; how many pc's max
> would be connected to your samba server at any given time):
> average concurrent connections to samba(smbstatus during working hrs):
> how long (average) between the time you bring samba up, and FIRST log
> message involving any tdb database?:
> Look in dmesg, and /var/adm/syslog/syslog.log - any unusual messages
> there about full system tables, or filesystem full, etc?:
> any core files show up?(use "file core" to determine if smbd or not, and
> date of core):
>
>
> You might want to bring samba down, remove any log files, and then make a
> simple cron job that runs every few minutes and  parses all the log files
> for any tdb failure.  once it
> spots a tbd failure, the cron job would copy all the log files to another
> directory, do an smbstatus to a file in that same directory, and stop.
> Then we could try to see what was going on around the FIRST error
> logged, without a lot of extra stuff after the fact.  You might want to
> turn your log level up a bit as well, so that we'd get more info about
> what was being done at the time of the 1st error as well; since you're
> going to copy the files off to a safe location once you hit the first
error,
> hopefully we won't wrap around and miss it.
>
> I'm also going to post a message to the samba list to see if anyone else
> can look in their logs to see if any of these errors are showing up on
2.2.x
> on archetectures OTHER than HP-UX...  Right now the only ones I have seen
> are on HP-UX 9.05, 10.20 and 11.xx...  I consider that somewhat
> suspicious...
>
> Thanks,
>
> Don
>
>
> -----Original Message-----
> From: Claus Svarer [mailto:csvarer at nru.dk]
> Sent: Tuesday, August 28, 2001 1:16 PM
> To: MCCALL,DON (HP-USA,ex1)
> Cc: 'samba-technical at lists.samba.org'
> Subject: Re: Problem with connection database
>
> Hi Don,
>
> Regarding problems with .tdb files at a HP-UX 11.00 system.
>
> The reason that I believe that it has something to do with large files is
> that it mostly are four users using Netscape Messenger (with the mail box
at
> a net drive) that experience the problems. These four people are also the
> only ones that has these > 200 MByte files and it is almost always in
these
> mail files we first experience the problem when the connections.tdb
database
> are corrupted again.
>
> I have today tried to compile the Samba CVS (2.2.2-pre) using gcc 3.0.1
> instead of the HP ANSI-C compiler, but we see excatly the same problems,
> that the connection database chrashes, with error messages that look like:
>
> [2001/08/28 15:09:10, 0] tdb/tdbutil.c:tdb_log(342)
>   tdb(/usr/local/samba/var/locks/connections.tdb): rec_read bad magic 0x0
at
> offset=28399
> [2001/08/28 15:09:10, 0] tdb/tdbutil.c:tdb_log(342)
>   tdb(/usr/local/samba/var/locks/connections.tdb): rec_read bad magic
> 0x3b8b97af at offset=127840
> [2001/08/28 15:15:17, 0] tdb/tdbutil.c:tdb_log(342)
>   tdb(/usr/local/samba/var/locks/connections.tdb): rec_read bad magic
> 0x42424242 at offset=82540
> [2001/08/28 15:15:52, 0] smbd/oplock.c:request_oplock_break(1010)
>   request_oplock_break: no response received to oplock break request to
pid
> 23374 on port 59593 for dev = 40020002, inode = 2126454
>   for dev = 40020002, inode = 2126454, tv_sec = 3b8b8ca5, tv_usec = 275c3
> [2001/08/28 15:15:52, 0] smbd/open.c:open_mode_check(554)
>   open_mode_check: exlusive oplock left by process 23374 after break ! For
> file Netscape/nru/Cache/fat.db, dev = 40020002, inode = 2
> l
>
> I don't know if anybody can trace down why the connections .tdb chrashes
> (Don MCCALL posted an example of a chrashed tdb lock file to the mailing
> list the other day). Could it be a result of what was reported earlier
this
> month at the samba-tecnical mailing list  by andreas moroder
> claudiamoroder at st-ulrich.suedtirol.net Tue, 14 Aug 2001 22:33:54 +0200
that:
>
> Hello,
>
> I did run lclint ( YES I really did it ) over the tdb.c file. I got
> thousand,
>
> no billions of warnings. Most of them are not worth checking except the
>
> warnings about different types.
>
> at line 150     fl.l_type = rw_type;   l_type is short int , rw_type MAY
be
>
> they are the same, but I don't know if it is guaranted on every machine
>
> at line tdb->locked[list+1].ltype = ltype;    int is assigned to unsigned
> int
>
> Another proble are the functions that return values that are never
checked.
>
> At line 610 the return value of tdb_oob is ignored.
>
> At line 207 tdb_spinunlock
>
> and many more.
>
> Most of the functions seem to give back valuable return values, so they
>
> should all be checked.
>
> Any proposal that could help in solving this problem with the samba at the
> hp-ux system will be very welcome.
>
> Best regards
> Claus Svarer
>
>
> "MCCALL,DON (HP-USA,ex1)" wrote:
>
> Hi Claus,
> Please cc the samba-technical list on your emails regarding this, so we
can
> get
> more people involved in the issue.
> I am interested in your observation regarding large files - how are you
able
>
> to
> tell that accessing these files are causing the problem?  and is there ANY
> way
> you can FORCE this problem to happen, so I could reproduce it under
> controlled
> circumstances?
>
> Thanks,
> don
> -----Original Message-----
> From: Claus Svarer [ mailto:csvarer at nru.dk <mailto:csvarer at nru.dk> ]
> Sent: Monday, August 27, 2001 11:09 AM
> To: MCCALL,DON (HP-USA,ex1)
> Subject: Re: Problem with connection database
>
> Hi Don
>
> Thanks for looking at the problem. I don't believe the error condition
have
> been
> wrapped out of the log files because with this low log level (1) the log
> files
> as far as I can see only is wrapped every second day (or about that).
>
> One other observation that we have had is that it is the really large
files
> that
> causes the problems. Especially, there mailbox'es from the email system
> (Netscape Messenger with the files at the net) causes problems probably
> because
> of the files sizes (200 MByte or more).
>
> Thanks for your help
>
> BR
> Claus
>
> "MCCALL,DON (HP-USA,ex1)" wrote:
>
> > Hi Claus,
> > I haven't had as much time as I would like to look at this, and I'm not
as
>
> > up on the tdb stuff as I would like,
> > so I'm posting my initial observations back to the samba-technical list
as
>
> > well, in hopes these will suggest a course of action to someone more
> > knowlegable - to me it appears to almost be a race condition of some
sort:
>
> >
> > All of the bad magic number reports in the log all boil down to the
> > following magic numbers:
> >
> > magic 0x42424242
> > magic 0x0
> > magic 0x10000
> > magic 0x3122
> > magic 0x41ed
> > magic 0x4d8
> > magic 0xd9fee666
> >
> > And of course
> >
> > magic 0x26011999  is reported when a free call is made, because this is
> the
> > TDB_MAGIC number, not the TDB_MAGIC_FREE number...  what does this mean?
> > something crapped out before changing the magic number to free_magic,
but
> > somehow put it in the list to be freed???...
> >
> > The offsets reported all boil down to:
> >
> > 0x0 offset=18676
> > 0x0 offset=2
> > 0x0 offset=24113
> > 0x0 offset=26003
> > 0x0 offset=26019
> > 0x0 offset=4589
> > 0x0 offset=620
> > 0x0 offset=64
> > 0x0 offset=65536
> > 0x10000 offset=2834
> > 0x3122 offset=0
> > 0x41ed offset=45336
> > 0x42424242 offset=1316
> > 0x42424242 offset=18676
> > 0x42424242 offset=2556
> > 0x42424242 offset=5656
> > 0x42424242 offset=620
> > 0x42424242 offset=6276
> > 0x42424242 offset=6896
> > 0x42424242 offset=696
> > 0x42424242 offset=7516
> >
> > 0x4d8 offset=25496
> > 0xd9fee666 offset=11856
> > 0xd9fee666 offset=15576
> > 0xd9fee666 offset=16816
> > 0xd9fee666 offset=18676
> > 0xd9fee666 offset=45336
> > 0xd9fee666 offset=696
> > 0xd9fee666 offset=73596
> > 0xd9fee666 offset=88740
> >
> > and the offsets where it is reporting bad magic because it's NOT
> > TDB_FREE_MAGIC is:
> >
> > 0x26011999 offset=16816
> > 0x26011999 offset=18676
> > 0x26011999 offset=49156
> >
> > Ok, we are trying to FREE the above three offsets;
> > the 1st to got bad magic when the were being tried to
> > read/write or something as well; maybe comparing what was going on when
it
>
> > was being freed as opposed to being allocated/read/wrote, and the timing
> of
> > that might give us some clues....
> >
> > We also have a bunch of tdb_oob len xxxxxxx beyond eof at
> >
> > at the following len/eof's:
> >
> > -1627389928 65536
> > -2147483577 65536
> > -788529101 65536
> > 1109419649 73732
> > 1111638598 73732   >>> this is 0x42424246
> > 1111638598 90112   in fact all of the
> > 1111638618 24576   ones in this range look
> > 1111638618 65536   like we just have the initialized
> > 1111638618 73732   memory except for last byte<<<<<<
> > 131137560 65536
> > 1346978887 65536
> > 16777247 65536
> > 181207044 65536
> > 181207044 73732
> > 485512 65536
> > 65560 65536
> > 875573320 65536
> > 925905992 65536
> > 956301336 65536
> >
> > With all this, it APPEARS that a link in the list is broken, so we are
> just
> > following out to 'random' offsets in the tdb file; we are prevented from
> > making really BAD mistakes by the fact that the TDB_MAGIC for each
record
> is
> > checked, and processing stops at a bad magic number; but how the link
got
> > corrupted to begin with is still evaiding me...
> >
> > I haven't been able to pin down the initial corruptor in the logs; we
may
> > have missed this, and are now seeing only the results of a corruption
> whose
> > log entry has already wrapped.
> >
> > Hope this will suggest something to some one more knowlegable on the tdb
> > than myself.  I still have your logs, etc. if someone else on the list
> > wishes to help out.
> > Don
> >
> > -----Original Message-----
> > From: Claus Svarer [ mailto:csvarer at nru.dk <mailto:csvarer at nru.dk> ]
> > Sent: Friday, August 24, 2001 5:33
> > To: MCCALL,DON (HP-USA,ex1)
> > Subject: Problem with connection database
> >
> > Hi Don
> >
> > Our server have now recreated the connection.tdb error again. I have
> > made a gzipped tar file of all the log and lock files that was at the
> > server when it chrashed (attached to this mail). I don't know if you can
> > find out what happens, but as you know the error message is:
> >
> > fog:/users/csvarer 22 : smbstatus | more
> > INFO: Debug class all level = 1   (pid 843 from pid 843)
> > tdb(/usr/local/samba/var/locks/connections.tdb): rec_read bad magic
> > 0x42424242 at offset=5656
> >
> > If I search int the log file I can find several machines that sees this
> > problem. At the time where we observed the problem no new machines was
> > authorizing against the samba server.
> >
> > Best regards
> > Claus