| SIPCLF | G. Salgueiro |
| Internet-Draft | Cisco Systems |
| Intended status: Standards Track | V. Gurbani |
| Bell Labs, Alcatel-Lucent | |
| A. B. Roach | |
| Tekelec | |
| 2011 |
Format for the Session Initiation Protocol (SIP) Common Log Format (CLF)
draft-ietf-sipclf-format-05
The SIPCLF Workgroup has defined a common log format framework for Session Initiation Protocol (SIP) servers. This common log format mimics the successful event logging format found in well-known web servers like Apache and web proxies like Squid. This document proposes an indexed text encoding format for the SIP Common Log Format (CLF) that retains the key advantages of a text-based format, while significantly increasing processing performance over a purely text-based implementation. This file format adheres to the SIP CLF data model and provides an effective encoding scheme for all mandatory and optional fields that appear in a SIP CLF record.
This Internet-Draft is submitted in full conformance with the provisions of BCP 78 and BCP 79.
Internet-Drafts are working documents of the Internet Engineering Task Force (IETF). Note that other groups may also distribute working documents as Internet-Drafts. The list of current Internet- Drafts is at http://datatracker.ietf.org/drafts/current/.
Internet-Drafts are draft documents valid for a maximum of six months and may be updated, replaced, or obsoleted by other documents at any time. It is inappropriate to use Internet-Drafts as reference material or to cite them other than as "work in progress."
Copyright (c) 2011 IETF Trust and the persons identified as the document authors. All rights reserved.
This document is subject to BCP 78 and the IETF Trust's Legal Provisions Relating to IETF Documents (http://trustee.ietf.org/license-info) in effect on the date of publication of this document. Please review these documents carefully, as they describe your rights and restrictions with respect to this document. Code Components extracted from this document must include Simplified BSD License text as described in Section 4.e of the Trust Legal Provisions and are provided without warranty as described in the Simplified BSD License.
The extensive list of benefits and the widespread adoption of the Apache Common Log Format (CLF) has prompted the development of a functionally equivalent event logging mechanism for the Session Initiation Protocol [RFC3261] (SIP). Implementing a logging scheme for SIP is a considerable challenge. This is due in part to the fact that the behavior of a SIP entity is more complex as compared to an HTTP entity. Additionally, there are shortcomings to the purely text-based HTTP Common Log Format that need to be addressed in order to allow for real-time inspection of SIP log files [I-D.ietf-sipclf-problem-statement]. Experience with Apache Common Log Format has shown that dealing with large quantities of log data can be very processor intensive, as doing so necessarily requires reading and parsing every byte in the log file(s) of interest.
An implementation independent framework for the SIP CLF has been defined in [I-D.ietf-sipclf-problem-statement]. This memo describes an indexed text file format for logging SIP messages received and sent by SIP clients, servers, and proxies that adheres to the data model presented in Section 8 of [I-D.ietf-sipclf-problem-statement]. This document defines a format that is no more difficult to generate by logging entities, while being radically faster to process. In particular, the format is optimized for both rapidly scanning through log records, as well as quickly locating commonly accessed data fields.
Further, the format proposed by this document retains the key advantage of being human readable and able to be processed using the various Unix text processing tools, such as sed, awk, perl, cut, and grep.
The key words "MUST", "MUST NOT", "REQUIRED", "SHALL", "SHALL NOT", "SHOULD", "SHOULD NOT", "RECOMMENDED", "MAY", and "OPTIONAL" in this document are to be interpreted as described in [RFC2119].
[RFC3261] defines additional terms used in this document that are specific to the SIP domain such as "proxy"; "registrar"; "redirect server"; "user agent server" or "UAS"; "user agent client" or "UAC"; "back-to-back user agent" or "B2BUA"; "dialog"; "transaction"; "server transaction".
This document uses the term "SIP Server" that is defined to include the following SIP entities: user agent server, registrar, redirect server, a SIP proxy in the role of user agent server, and a B2BUA in the role of a user agent server.
The reader is expected to be familiar with the terminology and concepts defined in [I-D.ietf-sipclf-problem-statement].
This document defines the logging syntax for the SIP CLF. This syntax is demonstrated through the use of various examples. The formatting described here does not permit these examples to be unambiguously rendered due to the constraints imposed by the formatting rules for Internet-Drafts. To avoid ambiguity and to meet the Internet-Draft layout requirements this document uses the <allOneLine/> markup convention established in [RFC4475].
For the sake of clarity and completeness, the entire text defining this markup convention from Section 2.1 of [RFC4475] is quoted below:
The IP addresses used in the examples in this document adhere to the best practices outlined in [RFC5735] and correspond to the documentation address block 192.0.2.0/24 (TEST-NET-1) as described in [RFC5737].
The Common Log Format for the Session Initiation Protocol [I-D.ietf-sipclf-problem-statement] defines a data model to which this logging format format adheres. Each SIP CLF record MUST consist of all the mandatory data model elements outlined in Section 8.1 of [I-D.ietf-sipclf-problem-statement].
All SIP CLF records MUST have the following format:
0 7 8 15 16 23 24 31
+-----------+-----------+-----------+-----------+
| Version | Record Length | 0 - 3
+-----------+-----------+-----------+-----------+
| Record Length (cont) | 0x2C | 4 - 7
+-----------+-----------+-----------+-----------+
| CSeq Pointer (Hex) | 8 - 11
+-----------+-----------+-----------+-----------+
| Response Status-Code Pointer (Hex) | 12 - 15
+-----------+-----------+-----------+-----------+
| R-URI Pointer (Hex) | 16 - 19
+-----------+-----------+-----------+-----------+
| Destination IP address:port Pointer (Hex) | 20 - 23
+-----------+-----------+-----------+-----------+
| Source IP address:port Pointer (Hex) | 24 - 27
+-----------+-----------+-----------+-----------+
| To URI Pointer (Hex) | 28 - 31
+-----------+-----------+-----------+-----------+
| To Tag Pointer (Hex) | 32 - 35
+-----------+-----------+-----------+-----------+
| From URI Pointer (Hex) | 36 - 39
+-----------+-----------+-----------+-----------+
| From Tag Pointer (Hex) | 40 - 43
+-----------+-----------+-----------+-----------+
| Call-Id Pointer (Hex) | 44 - 47
+-----------+-----------+-----------+-----------+
| Server-Txn Pointer (Hex) | 48 - 51
+-----------+-----------+-----------+-----------+
| Client-Txn Pointer (Hex) | 52 - 55
+-----------+-----------+-----------+-----------+
| Optional Fields Start Pointer (Hex) | 56 - 59
+-----------+-----------+-----------+-----------+
| 0x0A | | 60 - 63
+-----------+ +
| Timestamp | 64 - 67
+ +-----------+
| | 0x2E | 68 - 71
+-----------+-----------+-----------+-----------+
| Fractional Seconds | 0x09 | 72 - 75
+-----------+-----------+-----------+-----------+
| Flags Field | 76 - 79
+-----------+-----------+-----------+-----------+
|Flag (cont)| 0x09 | | 80 - 83
|-----------+-----------+ |
| |
| |
| Mandatory Fields (variable length) |
| |
| |
+-----------+-----------+-----------+-----------+
| 0x09 | Tag | 0x40 |\
+-----------+-----------+-----------+-----------+ \
| Vendor-ID | \
+-----------+-----------+-----------+-----------+ \
| Vendor-ID (cont) | \ Repeated
+-----------+-----------+-----------+-----------+ \ as many
| 0x2C | Length (Hex) | > times as
+-----------+-----------+-----------+-----------+ / necessary
| Len (cont)| 0x2C | | /
+-----------+-----------+ | /
| | /
| Value (variable length) | /
| |/
+-----------+-----------+-----------+-----------+
| 0x0A |
+-----------+
The format presented in Figure 1 is for a single SIP CLF log entry. While there is no actual subdivision in practice, this format can be logically subdivided into the following three distinct components:
This logical structure of the SIP CLF record format can be graphically represented as shown in Figure 2 below:
<IndexPointers>
<MandatoryFields>
<OptionalFields>
Note that Figure 1 and Figure 2 plus the terminating line-feed (0x0A) at the end of the SIP CLF record are different representations of the same format but are functionally equivalent. The representation of this format is a two line record where the <IndexPointers> metadata is on one line and the actual data like <MandatoryFields> and <OptionalFields> (if present) is on another.
The <IndexPointers> portion of the SIP CLF record (shown in Figure 3) is a 60-byte header that indicates metadata about the record.
0 7 8 15 16 23 24 31
+-----------+-----------+-----------+-----------+
| Version | Record Length | 0 - 3
+-----------+-----------+-----------+-----------+
| Record Length (cont) | 0x2C | 4 - 7
+-----------+-----------+-----------+-----------+
| CSeq Pointer (Hex) | 8 - 11
+-----------+-----------+-----------+-----------+
| Response Status-Code Pointer (Hex) | 12 - 15
+-----------+-----------+-----------+-----------+
| R-URI Pointer (Hex) | 16 - 19
+-----------+-----------+-----------+-----------+
| Destination IP address:port Pointer (Hex) | 20 - 23
+-----------+-----------+-----------+-----------+
| Source IP address:port Pointer (Hex) | 24 - 27
+-----------+-----------+-----------+-----------+
| To URI Pointer (Hex) | 28 - 31
+-----------+-----------+-----------+-----------+
| To Tag Pointer (Hex) | 32 - 35
+-----------+-----------+-----------+-----------+
| From URI Pointer (Hex) | 36 - 39
+-----------+-----------+-----------+-----------+
| From Tag Pointer (Hex) | 40 - 43
+-----------+-----------+-----------+-----------+
| Call-Id Pointer (Hex) | 44 - 47
+-----------+-----------+-----------+-----------+
| Server-Txn Pointer (Hex) | 48 - 51
+-----------+-----------+-----------+-----------+
| Client-Txn Pointer (Hex) | 52 - 55
+-----------+-----------+-----------+-----------+
| Optional Fields Start Pointer (Hex) | 56 - 59
+-----------+-----------+-----------+-----------+
The fields that make up <IndexPointers> are described below:
Bytes 8 through 55 contain hexadecimal encoded pointers that point to the starting location of each of the variable-length mandatory fields. Note that there are no delimiters between these pointer values -- they are packed together as a single, 52-character hexadecimal encoded string. The "Pointer" fields indicate absolute byte values within the record, and MUST be >=82. They point to the start of the corresponding value within the <MandatoryFields> portion. A description of each of the mandatory fields that these pointer values point to can be found in Section 4.2.
The <MandatoryFields> portion of the SIP CLF record is shown below:
0 7 8 15 16 23 24 31
+-----------+-----------+-----------+-----------+
| 0x0A | | 60 - 63
+-----------+ +
| Timestamp | 64 - 67
+ +-----------+
| | 0x2E | 68 - 71
+-----------+-----------+-----------+-----------+
| Fractional Seconds | 0x09 | 72 - 75
+-----------+-----------+-----------+-----------+
| Flags Field | 76 - 79
+-----------+-----------+-----------+-----------+
|Flag (cont)| 0x09 | | 80 - 83
|-----------+-----------+ |
| |
| |
| Mandatory Fields (variable length) |
| |
| |
+-----------+-----------+-----------+-----------+
Following the pointers in <IndexPointers>, two fixed-length fields are encoded to specify the exact time of the log entry. As before, all fields are completely filled, pre-pending values with '0' characters as necessary.
After the "Timestamp", "Fractional Seconds" and the "Flags" fields are the actual values for the mandatory fields specified in Section 8.1 of [I-D.ietf-sipclf-problem-statement], which are described below:
Whilst one may question the value of the From URI in light of [RFC4474], the From URI, nonetheless, imparts some information. For one, the From tag is important and, in the case of a REGISTER request, the From URI can provide information on whether this was a third-party registration or a first-party one.
This data MUST appear in the order listed in <IndexPointers>, and each field MUST be present. Fields are subject the maximum SIP CLF field size of 4096 bytes as detailed in Section 8 of [I-D.ietf-sipclf-problem-statement] and are separated by a single ASCII Tab character (0x09). Any Tab characters present in the data to be written will be replaced by an ASCII space character (0x20) prior to being logged.
An element will not always have an appropriate value to provide for one of these fields, even when the field is required to appear in the SIP CLF record. In such circumstances, when a given mandatory field is not present then that empty field MUST be encoded as a single horizontal dash ("-").
In the event that a field failed to parse it MUST be encoded as a single question mark ("?"). If these characters are part of a sequence of other characters, then there is no ambiguity. If the field being logged contains only one character, and that character is the literal "-", the implementation SHOULD insert an escaped %2D for that field in the SIP CLF record. Similarly, if the field contains only one character, and that character is the literal "?", the implementation SHOULD insert an escaped %3F for that field in the SIP CLF record.
The <OptionalFields> portion of the SIP CLF record is shown below:
0 7 8 15 16 23 24 31
+-----------+-----------+-----------+-----------+
| 0x09 | Tag | 0x40 |\
+-----------+-----------+-----------+-----------+ \
| Vendor-ID | \
+-----------+-----------+-----------+-----------+ \
| Vendor-ID (cont) | \ Repeated
+-----------+-----------+-----------+-----------+ \ as many
| 0x2C | Length (Hex) | > times as
+-----------+-----------+-----------+-----------+ / necessary
| Len (cont)| 0x2C | | /
+-----------+-----------+ | /
| | /
| Value (variable length) | /
| |/
+-----------+-----------+-----------+-----------+
Optional fields are those SIP message elements that are not a part of the mandatory fields list detailed in Section 8.1 of [I-D.ietf-sipclf-problem-statement]. After the <MandatoryFields> section, there is an OPTIONAL <OptionalFields> group (shown in Figure 5) that MAY appear zero or more times. This <OptionalFields> group provides extensibility to the SIP CLF. It allows SIP CLF implementers the flexibility to extend the logging capability of the indexed-ASCII representation beyond just the mandatory log elements described in Section 8.1 of [I-D.ietf-sipclf-problem-statement].
Logging any optional SIP elements MUST be done according to the format shown in Figure 5. The location of the start of <OptionalFields> within the SIP CLF record is indicated by the "Optional Fields Start Pointer" field in <IndexPointers>. After the initial Tab delimiter byte (0x09) shown in Figure 5, the optional field being logged is generally represented by the notation:
The optional field identifier (Tag@Vendor-ID) is composed of a two byte Tag and an eight byte Vendor-ID (both decimal encoded) separated by an "@" character (0x40). This uniquely identifies the optional field being logged. The format for this identifier is loosely modeled after the private use option used by the Syslog protocol [RFC5424] (Note: this is the second format detailed in Section 6.3.2 of [RFC5424]). It makes use of the Private Enterprise Number (PEN), which provides an identifier through a globally unique name space [PEN]. This syntax provides the necessary extensibility to SIP CLF to allow logging of any SIP header, body, as well as any vendor-specified SIP element.
Optional fields are logged according to the following two syntax rules:
The remaining fields in the format shown in Figure 5 are defined below:
The following are examples of optionally logged SIP elements using the syntax described in this section. All these examples only show the <OptionalFields> portion of the SIP CLF record. The mandatory <IndexPointers> and <MandatoryFields> portions of the SIP CLF are intentionally omitted for the sake of brevity. Note that all of these examples of optionally logged fields begin with a leading Tab delimiter byte (0x09) that is not apparent here.
Consider the SIP response:
SIP/2.0 180 Ringing
<allOneLine>
Via: SIP/2.0/UDP host.example.com;
branch=z9hG4bKnashds8;received=192.0.2.1
</allOneLine>
To: Bob <sip:bob@example.com>;tag=a6c85cf
From: Alice <sip:alice@example.com>;tag=1928301774
Call-ID: a84b4c76e66710
Contact: <sip:bob@192.0.2.4>
CSeq: 314159 INVITE
Content-Length: 0
00@00000000,001C,Contact: <sip:bob@192.0.2.4>
For the same SIP response the Reason-Phrase would be logged as
an optional field in the following manner:
00@00000000,0016,Reason-Phrase: Ringing
v=0
o=alice 2890844526 2890844526 IN IP4 host.example.com
s=-
c=IN IP4 host.example.com
t=0 0
m=audio 49170 RTP/AVP 0 8 97
<allOneLine>
01@00000000,008B,application/sdp v=0\r\no=alice 2890844526
2890844526 IN IP4 host.example.com\r\ns=-\r\n
c=IN IP4 host.example.com\r\nt=0 0\r\n
m=audio 49170 RTP/AVP 0 8 97\r\n
</allOneLine>
Consider the SIP message:
INVITE sip:bob@example.com SIP/2.0
Via: SIP/2.0/UDP host.example.com;branch=z9hG4bKnashds8
To: Bob <bob@example.com>
From: Alice <alice@example.com>;tag=1928301774
Call-ID: a84b4c76e66710
CSeq: 314159 INVITE
Max-Forwards: 70
Date: Thu, 21 Feb 2002 13:02:03 GMT
Contact: <sip:alice@host.example.com>
Content-Type: application/sdp
Content-Length: 147
v=0
o=UserA 2890844526 2890844526 IN IP4 example.com
s=Session SDP
c=IN IP4 host.example.com
t=0 0
m=audio 49172 RTP/AVP 0
a=rtpmap:0 PCMU/8000
03@00032473,0014,a=rtpmap:0 PCMU/8000
Perhaps a vendor wants to log that this message is the n-th
message received from a peering partner. To do so for the SIP
message shown above, the vendor would log this information as:
07@00032473,0016,1877 example.com
INVITE sip:192.0.2.10 SIP/2.0
To: <sip:192.0.2.10>
Call-ID: DL70dff590c1-1079051554@example.com
<allOneLine>
From: "Alice" <sip:1001@example.com:5060>;
tag=DL88360fa5fc;epid=0x34619b0
</allOneLine>
CSeq: 1 INVITE
Max-Forwards: 70
<allOneLine>
Via: SIP/2.0/TCP 192.0.2.200:5060;
branch=z9hG4bK-1f6be070c4-DL
</allOneLine>
Contact: "1001" <sip:1001@192.0.2.200:5060>
<allOneLine>
Allow: INVITE,CANCEL,ACK,OPTIONS,INFO,SUBSCRIBE,NOTIFY,BYE,
MESSAGE,UPDATE,REFER
</allOneLine>
Supported: replaces,norefersub
User-Agent: Some Vendor
Content-Type: application/sdp
Content-Length: 418
v=0
o=1001 1456139204 0 IN IP4 192.0.2.200
s=-
c=IN IP4 192.0.2.200
b=AS:2048
t=0 0
m=audio 13756 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=x-mpdp:192.0.2.200:13756
m=video 13758 RTP/AVP 96
a=rtpmap:96 H264/90000
<allOneLine>
a=fmtp:96 profile-level-id=420015; max-mbps=47520; max-fs=1584;
max-dpb=7680
</allOneLine>
a=x-mpdp:192.0.2.200:13758
A0000FE,0053005C005E006D007D008F009E00A000BA00C700EB00F500FE
<allOneLine>
0000000000.010 RORUU 1 INVITE - sip:192.0.2.10
192.0.2.10:5060 192.0.2.200:56485 sip:192.0.2.10 -
sip:1001@example.com:5060 DL88360fa5fc
DL70dff590c1-1079051554@example.com server-tx client-tx
</allOneLine>
begin-base64 644 clf_record
QTAwMDBGRSwwMDUzMDA1QzAwNUUwMDZEMDA3RDAwOEYwMDlFMDBBMDAwQkEwMEM3MDBF
QjAwRjUwMEZFCjAwMDAwMDAwMDAuMDEwICBST1JVVSAgIDEgSU5WSVRFICAgICAgICAt
ICAgICAgIHNpcDoxOTIuMC4yLjEwICAxOTIuMC4yLjEwOjUwNjAgMTkyLjAuMi4yMDA6
NTY0ODUgICAgICAgc2lwOjE5Mi4wLjIuMTAgIC0gICAgICAgc2lwOjEwMDFAZXhhbXBs
ZS5jb206NTA2MCAgICAgICBETDg4MzYwZmE1ZmMgICAgREw3MGRmZjU5MGMxLTEwNzkw
NTE1NTRAZXhhbXBsZS5jb20gICAgIHNlcnZlci10eCAgICAgICBjbGllbnQtdHgK
====
#!/usr/bin/perl
use strict;
my $bdata = "";
use MIME::Base64;
while(<>)
{
if (/begin-base64 644 clf_record/ .. /-- ==== --/)
{
if ( m/^\s*[^\s]+\s*$/)
{
$bdata = $bdata . $_;
}
}
}
print decode_base64($bdata);
The following SIP message is an INVITE request sent by a SIP client:
This format has been designed to allow text tools to easily process logs without needing to understand the indexing format. Index lines may be rapidly discarded by checking the first character of the line: index lines will always start with an alphabetical character, while field lines will start with a numerical character.
Within a field line, script tools can quickly split fields at the tab characters. The first 12 fields are positional, and the meaning of any subsequent fields can be determined by checking the first four characters of the field. Alternately, these non-positional fields can be located using a regular expression. For example, the "Contact value" in a request can be found by searching for the perl regex /\t0000,....,([^\t]*)/.
This document does not introduce any new security considerations beyond those discussed in [I-D.ietf-sipclf-problem-statement].
SIP CLF log files will take up substantive amount of disk space depending on traffic volume at a processing entity and the amount of information being logged. As such, any enterprise using SIP CLF should establish operational procedures for file rollovers as appropriate to the needs of the organization.
Listing such operational guidelines in this document is out of scope for this work.
This document does not require any considerations from IANA.
The authors of this document would like to acknowledge and thank Peter Musgrave for his support, guidance, and continued invaluable feedback.
This work benefited from the discussions and invaluable input by the various members of the SIPCLF working group. These include Brian Trammell, Eric Burger, Cullen Jennings, Benoit Claise, Saverio Niccolini, Dan Burnett. Special thanks to Hadriel Kaplan, Chris Lonvick, Paul E. Jones, John Elwell for their constructive comments, suggestions, and reviews that were critical to the formulation and refinement of this draft.
Thanks to Anders Nygren for his early implementation, insight, and reviews of the SIP CLF format.
| [I-D.ietf-sipclf-problem-statement] | Gurbani, V, Burger, E, Anjali, T, Abdelnur, H and O Festor, "The Common Log Format (CLF) for the Session Initiation Protocol (SIP): Framework and Data Model", Internet-Draft draft-ietf-sipclf-problem-statement-09, December 2011. |
| [RFC2119] | Bradner, S., "Key words for use in RFCs to Indicate Requirement Levels", BCP 14, RFC 2119, March 1997. |
| [RFC3261] | Rosenberg, J., Schulzrinne, H., Camarillo, G., Johnston, A., Peterson, J., Sparks, R., Handley, M. and E. Schooler, "SIP: Session Initiation Protocol", RFC 3261, June 2002. |
| [RFC5424] | Gerhards, R., "The Syslog Protocol", RFC 5424, March 2009. |