Re: [sip-clf] WGLC: SIPCLF Problem Statement(draft-gurbani-sipclf-problem-statement-01)

"Rainer Gerhards" <rgerhards@hq.adiscon.com> Thu, 04 February 2010 11:19 UTC

Return-Path: <rgerhards@hq.adiscon.com>
X-Original-To: sip-clf@core3.amsl.com
Delivered-To: sip-clf@core3.amsl.com
Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 35D983A6BFC for <sip-clf@core3.amsl.com>; Thu, 4 Feb 2010 03:19:25 -0800 (PST)
X-Virus-Scanned: amavisd-new at amsl.com
X-Spam-Flag: NO
X-Spam-Score: -2.524
X-Spam-Level:
X-Spam-Status: No, score=-2.524 tagged_above=-999 required=5 tests=[AWL=0.075, BAYES_00=-2.599]
Received: from mail.ietf.org ([64.170.98.32]) by localhost (core3.amsl.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 2ICLPpZI+2q0 for <sip-clf@core3.amsl.com>; Thu, 4 Feb 2010 03:19:22 -0800 (PST)
Received: from mailin.adiscon.com (hetzner.adiscon.com [85.10.198.18]) by core3.amsl.com (Postfix) with ESMTP id 7583428C108 for <sip-clf@ietf.org>; Thu, 4 Feb 2010 03:19:20 -0800 (PST)
Received: from localhost (localhost [127.0.0.1]) by mailin.adiscon.com (Postfix) with ESMTP id 05BA0241C005; Thu, 4 Feb 2010 12:06:59 +0100 (CET)
Received: from mailin.adiscon.com ([127.0.0.1]) by localhost (localhost [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id Tlo7mStTxyJT; Thu, 4 Feb 2010 12:06:58 +0100 (CET)
Received: from GRFEXC.intern.adiscon.com (pd95c774a.dip0.t-ipconnect.de [217.92.119.74]) by mailin.adiscon.com (Postfix) with ESMTP id B8802241C004; Thu, 4 Feb 2010 12:06:58 +0100 (CET)
Content-class: urn:content-classes:message
MIME-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: quoted-printable
X-MimeOLE: Produced By Microsoft Exchange V6.5
Date: Thu, 4 Feb 2010 12:20:04 +0100
Message-ID: <9B6E2A8877C38245BFB15CC491A11DA7103805@GRFEXC.intern.adiscon.com>
X-MS-Has-Attach:
X-MS-TNEF-Correlator:
Thread-Topic: [sip-clf] WGLC: SIPCLF Problem Statement(draft-gurbani-sipclf-problem-statement-01)
Thread-Index: AcqlUYW+HxKR2awkTxyRZPAyASCS+wAN4U3w
References: <7505A2C58D8F4FD88B47D10EA74649CD@china.huawei.com> <C1B972DA-0118-4E3F-8C5F-970BE4238577@cisco.com>
From: "Rainer Gerhards" <rgerhards@hq.adiscon.com>
To: "Cullen Jennings" <fluffy@cisco.com>, "SIP-CLF Mailing List" <sip-clf@ietf.org>
Subject: Re: [sip-clf] WGLC: SIPCLF Problem Statement(draft-gurbani-sipclf-problem-statement-01)
X-BeenThere: sip-clf@ietf.org
X-Mailman-Version: 2.1.9
Precedence: list
List-Id: SIP Common Log File format discussion list <sip-clf.ietf.org>
List-Unsubscribe: <https://www.ietf.org/mailman/listinfo/sip-clf>, <mailto:sip-clf-request@ietf.org?subject=unsubscribe>
List-Archive: <http://www.ietf.org/mail-archive/web/sip-clf>
List-Post: <mailto:sip-clf@ietf.org>
List-Help: <mailto:sip-clf-request@ietf.org?subject=help>
List-Subscribe: <https://www.ietf.org/mailman/listinfo/sip-clf>, <mailto:sip-clf-request@ietf.org?subject=subscribe>
X-List-Received-Date: Thu, 04 Feb 2010 11:19:25 -0000

> I was considering also saying compatibility with syslog definition of
> timestamp but my recollection of that (which may be very wrong - been
> awhile since I looked at it) left me more than a bit confused about
> syslog tmestamps. It seems that every syslog packet I have ever seen in
> the wild uses the BSD Syslog timestamp format in RFC 3164 but clearly
> that is more or less borked for any real correlation across time zones
> so it seems like 5424 version of timestamp would be better. The 5424
> allowed the local offsets which resulted in no real canonical format
> for time which mean some people implemented the full things and some
> ignored the local offsets results in interoperability problems.

Well, I don't know any such broken implementations, but they are clearly
broken. That is because time zone information MUST be part of the timestamp.
Basically, syslog reuses a RFC3339 timestamp (see section 5.6 for it's ABNF)
but places some further restrictions on it. We do not force implementers to
use a single canonical on-the-wire format, but it is always easy to obtain a
canonical representation for correlation. As far as I remember, it was
considered useful to have some information inside the timestamp of where it
was generated.

> Then
> there is the "-00:00" offset being something much different than
> "+00:00".

When parsing the timestamp, the sign s is read and "+" interpreted as 1, "-"
as -1. Then, the offset o is parsed. The final offset calculation is o * s,
and as 0*1 = 0*-1 there is no difference between the two. A agree that a
slightly more complex logic is needed to adjust the time to UTC, but the same
is true if you have UTC timestamps only and need to adjust them to local
time, what often is desired by operators. So I fail to see why this is a
problem or not "canonical enough".

> And then there is the leap seconds stuff which is nearly
> untested as far as I can tell in most products.

I have to admit I don't understand this comment. What is untested here?
RFC5424 specifically forbids leap seconds, as during our discussions we found
many cases where leap seconds caused grief. I also think the the TAI is
considering aborting the use of leap seconds for this reason as well. To the
best of my knowledge, GSP also does not use leap seconds. The ultimate reason
to abandon UTC leap seconds in syslog was the we failed to identify an
operating system that would expose leap seconds to a user process. So a
syslogd or any other syslog sender would not even be able to see that one was
introduced. From the syslog perspective, a leap second is just like any other
second, but time flows "somewhat slower". I guess we are in the same boat as
many operating systems with this perspective.

> I really don't
> understand how one write a 5424 compliant syslog message that occurs
> during the leap second but I'
>  m probably just confused. What exactly does one do if one wants to
> write something to a log file when an extra leap second is being added?

I have to admit we didn't explicitely state that case because we thought it
could actually never happen. But I would say that "Leap seconds MUST NOT be
used" to me means that it should be expressed as the 59th second of said
minute. But even if you bump the minute and use the 0 second, I cannot see
how this should be problematic. On a single system, time should still evolve
serially. For correlating events form multiple systems, the timestamp alone
is insufficient in any case. You cannot closely enough synchronize the
different real time clocks. So you need a different meachanism (like Lamport
clocks) for this in any case.

> SIP is using the email style time formats and mandating GMT. That seems
> pretty trivially translatable 

indeed, this is trivial ;) If the sip timestamp is "2010-02-02
23:15:10.1234", you just need to replace the space by "T" and add an extra
"Z", so it becomes the valid syslog timestamp
"2010-02-02T23:15:10.1234Z". It is equally trivial to convert back ;)

Rainer