Re: High lock spin time for zone->lru_lock under extreme conditions

[Ravikiran G Thirumalai <kiran@scalex86.org>]

On Sat, Jan 13, 2007 at 12:00:17AM -0800, Andrew Morton wrote:
> > On Fri, 12 Jan 2007 23:36:43 -0800 Ravikiran G Thirumalai <kiran@scalex86.org> wrote:
> > > >void __lockfunc _spin_lock_irq(spinlock_t *lock)
> > > >{
> > > >        local_irq_disable();
> > > >        ------------------------> rdtsc(t1);
> > > >        preempt_disable();
> > > >        spin_acquire(&lock->dep_map, 0, 0, _RET_IP_);
> > > >        _raw_spin_lock(lock);
> > > >        ------------------------> rdtsc(t2);
> > > >        if (lock->spin_time < (t2 - t1))
> > > >                lock->spin_time = t2 - t1;
> > > >}
> > > >
> > > >On some runs, we found that the zone->lru_lock spun for 33 seconds or more
> > > >while the maximal CS time was 3 seconds or so.
> > > 
> > > What is the "CS time"?
> > 
> > Critical Section :).  This is the maximal time interval I measured  from 
> > t2 above to the time point we release the spin lock.  This is the hold 
> > time I guess.
> 
> By no means.  The theory here is that CPUA is taking and releasing the
> lock at high frequency, but CPUB never manages to get in and take it.  In
> which case the maximum-acquisition-time is much larger than the
> maximum-hold-time.
> 
> I'd suggest that you use a similar trick to measure the maximum hold time:
> start the timer after we got the lock, stop it just before we release the
> lock (assuming that the additional rdtsc delay doesn't "fix" things, of
> course...)

Well, that is exactly what I described above  as CS time.  The
instrumentation goes like this:

void __lockfunc _spin_lock_irq(spinlock_t *lock)
{
        unsigned long long t1,t2;
        local_irq_disable();
        t1 = get_cycles_sync();
        preempt_disable();
        spin_acquire(&lock->dep_map, 0, 0, _RET_IP_);
        _raw_spin_lock(lock);
        t2 = get_cycles_sync();
        lock->raw_lock.htsc = t2;
        if (lock->spin_time < (t2 - t1))
                lock->spin_time = t2 - t1;
}
...

void __lockfunc _spin_unlock_irq(spinlock_t *lock)
{
        unsigned long long t1 ;
        spin_release(&lock->dep_map, 1, _RET_IP_);
        t1 = get_cycles_sync();
        if (lock->cs_time < (t1 -  lock->raw_lock.htsc))
                lock->cs_time = t1 -  lock->raw_lock.htsc;
        _raw_spin_unlock(lock);
        local_irq_enable();
        preempt_enable();
}

Am I missing something?  Is this not what you just described? (The
synchronizing rdtsc might not be really required at all locations, but I 
doubt if it would contribute a significant fraction to 33s  or even 
the 3s hold time on a 2.6 GHZ opteron).