tomcat-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Stan Bailes" <s...@quadcap.com>
Subject RE: VOTE: Timestamps in log
Date Wed, 05 Jul 2000 19:45:25 GMT
I have dealt with this kind of thing in the past by working
hard to avoid calling the SimpleDateFormat methods in the 
first place.   My simple strategy is to limit calls to 'format'
to no more than one per second, doing a little bit of buffer
fiddling to handle the milliseconds specially.

Having real dates in the logs is a big win.  There's no
reason that this should be slow...

Here's a reusable wrapper around SimpleDateFormat that really
speeds things up.

Stan Bailes
Quadcap Software


-------------------------------------------------------------
/**
 * Copyright 2000 Quadcap Software.
 *
 * This software may be freely redistributed in source or binary form
 * for any purpose.
 */
import java.util.Date;

import java.text.DateFormat;
import java.text.FieldPosition;
import java.text.SimpleDateFormat;

/**
 * Fast date formatter that caches recently formatted date information
 * and uses it to avoid too-frequent calls to the underlying formatter.
 *
 * @author Stan Bailes
 */
public class FastDateFormat {
    DateFormat                  df;
    long                        lastSec         = -1;
    StringBuffer                sb              = new StringBuffer();
    FieldPosition               fp              = new FieldPosition(DateFormat.MILLISECOND_FIELD);

    public FastDateFormat(DateFormat df) {
        this.df = df;
    }

    public synchronized String format(Date d) {
        final long dt = d.getTime();
        final long ds = dt / 1000;
        if (ds != lastSec) {
            sb.setLength(0);
            df.format(d, sb, fp);
            lastSec = ds;
        } else {
            int ms = (int)(dt % 1000);
            int pos = fp.getEndIndex() - 1;
            sb.setCharAt(pos--, Character.forDigit(ms % 10, 10));
            ms /= 10;
            sb.setCharAt(pos--, Character.forDigit(ms % 10, 10));
            ms /= 10;
            sb.setCharAt(pos--, Character.forDigit(ms % 10, 10));
        }
        return sb.toString();
    }

    public static void main(String[] args) {
        SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
        FastDateFormat fdf = new FastDateFormat(sdf);
        Date d = new Date();
        final int reps = 100000;
        {
            long start = System.currentTimeMillis();
            for (int i = 0; i < reps; i++) {
                d.setTime(System.currentTimeMillis());
                fdf.format(d);
            }
            long elap = System.currentTimeMillis() - start;
            System.out.println("fast: " + elap + " elapsed");
        }
        {
            long start = System.currentTimeMillis();
            for (int i = 0; i < reps; i++) {
                d.setTime(System.currentTimeMillis());
                sdf.format(d);
            }
            long elap = System.currentTimeMillis() - start;
            System.out.println("slow: " + elap + " elapsed");
        }
    }
}



> -----Original Message-----
> From: costin@costin.dnt.ro [mailto:costin@costin.dnt.ro]On Behalf Of
> Costin Manolache
> Sent: Wednesday, July 05, 2000 12:19 PM
> To: alex@jguru.com; tomcat-dev@jakarta.apache.org
> Subject: Re: VOTE: Timestamps in log
> 
> 
> > > Time-stamping anything but the access log is a waste, and formating the
> > > date is also a waste.
> >
> > I disagree; I've often been able to track down errors, by
> > synchronizing different log file entries, thanks to timestamps.  And
> > since this is usually done with grep and less, it's good that it's
> > formatted so it's legible to a human eye.
> 
> I agree with that - my only problem is that we don't have a good way
> to format the timestamp.
> 
> 
> 
> > > Most of the performance improvements between tocmat 3.1 and 3.2 comes from
> > > reducing the GC and reusing the objects. Date formating is a big GC
> > > generator, and it's almost imposible to reuse the date formating objects
> > > with the current API ( or I coulnd't find a way ).
> >
> > The date formatter itself is actually reusable ( I made it an instance
> > var), however...
> >
> > > I would be happy to vote +1 if you find a way to format the date that
> > > allows object reuse !
> > > ( and again - it wouldn't be pre-optimization )
> >
> > Aha, a challenge! :-)
> >
> > SimpleDateFormat.format(Date date, StringBuffer toAppendTo,
> > FieldPosition pos) is what I'm using, and you're right, it seems to
> > sometimes (though not always) allocate a few StringBuffers along the
> > way, which it discards for GC.  (I'd have to track this down more
> > carefully; it makes heavy use of lookup tables for strings, and uses
> > StringBuffer.append a lot.)
> 
> > Now, the current LogEntry object has a toString() method, which
> > allocates, fills, and converts a StringBuffer, which may cause at
> > least one StringBuffer and a String to be left in the heap for each
> > message, but that happens regardless of timestamping.
> 
> > I suppose that this whole process should be tuned to use only
> > stream.write() methods and no internal Strings or StringBuffers,
> > right?  Until that happens, though, we can safely write off the logger
> > as "untuned" and hopefully the extra object or two left around by the
> > date formatter won't make it *that* much less tuned (relative to other
> > processes)... Given your tuning experience, do you (perhaps with
> > reservations) agree?
> 
> Yes.
> 
> It would be great to be the "extra object or two", it's much more.
> The logging creates more GC than the request processing, and that's
> not good, but for 3.2 I don't think we want to tune up the
> formatter.
> 
> A date formater that is efficient and can be reused is very important,
> we do need date conversion for cookies and some headers
> ( and we can't turn this off :-).
> 
> I guess we can start this dicussion again when we do have a
> date formatter.
> 
> 
> ( BTW,  try to run "ab -c 40 ", with logger turned of and on with
> date and with millis, and maybe OptimizeIt. It's very interesting).
> 
> Costin
> 
> 
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: tomcat-dev-unsubscribe@jakarta.apache.org
> For additional commands, e-mail: tomcat-dev-help@jakarta.apache.org
> 
> 

Mime
View raw message