From fluffy@cisco.com Mon Apr 27 11:49:20 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 7F29728C197 for ; Mon, 27 Apr 2009 11:49:20 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -106.592 X-Spam-Level: X-Spam-Status: No, score=-106.592 tagged_above=-999 required=5 tests=[AWL=0.007, BAYES_00=-2.599, RCVD_IN_DNSWL_MED=-4, USER_IN_WHITELIST=-100] 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 jFG0auWT4h6d for ; Mon, 27 Apr 2009 11:49:19 -0700 (PDT) Received: from sj-iport-6.cisco.com (sj-iport-6.cisco.com [171.71.176.117]) by core3.amsl.com (Postfix) with ESMTP id 97BBC28C192 for ; Mon, 27 Apr 2009 11:49:17 -0700 (PDT) X-IronPort-AV: E=Sophos;i="4.40,255,1238976000"; d="scan'208";a="293812446" Received: from sj-dkim-4.cisco.com ([171.71.179.196]) by sj-iport-6.cisco.com with ESMTP; 27 Apr 2009 18:50:38 +0000 Received: from sj-core-5.cisco.com (sj-core-5.cisco.com [171.71.177.238]) by sj-dkim-4.cisco.com (8.12.11/8.12.11) with ESMTP id n3RIoclf001049 for ; Mon, 27 Apr 2009 11:50:38 -0700 Received: from [192.168.4.177] (rcdn-fluffy-8711.cisco.com [10.99.9.18]) by sj-core-5.cisco.com (8.13.8/8.13.8) with ESMTP id n3RIob2e010500 for ; Mon, 27 Apr 2009 18:50:38 GMT Message-Id: <94C52D41-770B-415E-840D-B3BBA977632A@cisco.com> From: Cullen Jennings To: sip-ops@ietf.org Impp: xmpp:cullenfluffyjennings@jabber.org Content-Type: text/plain; charset=US-ASCII; format=flowed Content-Transfer-Encoding: 7bit Mime-Version: 1.0 (Apple Message framework v930.3) Date: Mon, 27 Apr 2009 12:50:36 -0600 X-Mailer: Apple Mail (2.930.3) DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; l=3; t=1240858238; x=1241722238; c=relaxed/simple; s=sjdkim4002; h=Content-Type:From:Subject:Content-Transfer-Encoding:MIME-Version; d=cisco.com; i=fluffy@cisco.com; z=From:=20Cullen=20Jennings=20 |Subject:=20test=201 |Sender:=20; bh=8bL2YoABIr7Q/yVWk9+JxEh/vc9FPTUkpC1Owgw9nAQ=; b=FOI4tymtpD8Vshup3C+QCnXSXiB7+6PqcsX8XxUJQZ2SmDCiw0rt2Ki1LP O7K8fTRJDa72wUrVraxKf4Z6n7HTHze42bbw3EUvYAv9y3TYkmSBoyovdlvB VOj+V9FY8A; Authentication-Results: sj-dkim-4; header.From=fluffy@cisco.com; dkim=pass ( sig from cisco.com/sjdkim4002 verified; ); Subject: [sip-ops] test 1 X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 27 Apr 2009 18:49:20 -0000 1 From fluffy@cisco.com Mon Apr 27 12:12:27 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id BC6AB3A6FED; Mon, 27 Apr 2009 12:12:27 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -106.593 X-Spam-Level: X-Spam-Status: No, score=-106.593 tagged_above=-999 required=5 tests=[AWL=0.006, BAYES_00=-2.599, RCVD_IN_DNSWL_MED=-4, USER_IN_WHITELIST=-100] 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 DVOvblVc3jvG; Mon, 27 Apr 2009 12:12:26 -0700 (PDT) Received: from sj-iport-3.cisco.com (sj-iport-3.cisco.com [171.71.176.72]) by core3.amsl.com (Postfix) with ESMTP id 9D0C53A6AB5; Mon, 27 Apr 2009 12:12:25 -0700 (PDT) X-IronPort-AV: E=Sophos;i="4.40,256,1238976000"; d="scan'208";a="157040987" Received: from sj-dkim-1.cisco.com ([171.71.179.21]) by sj-iport-3.cisco.com with ESMTP; 27 Apr 2009 19:13:46 +0000 Received: from sj-core-1.cisco.com (sj-core-1.cisco.com [171.71.177.237]) by sj-dkim-1.cisco.com (8.12.11/8.12.11) with ESMTP id n3RJDkLJ018596; Mon, 27 Apr 2009 12:13:46 -0700 Received: from [192.168.4.177] (rcdn-fluffy-8711.cisco.com [10.99.9.18]) by sj-core-1.cisco.com (8.13.8/8.13.8) with ESMTP id n3RJDjis015349; Mon, 27 Apr 2009 19:13:45 GMT Message-Id: From: Cullen Jennings To: sip-ops@ietf.org, ops-area@ietf.org, rai@ietf.org, ops-dir@ietf.org, sipping Impp: xmpp:cullenfluffyjennings@jabber.org Content-Type: text/plain; charset=US-ASCII; format=flowed; delsp=yes Content-Transfer-Encoding: 7bit Mime-Version: 1.0 (Apple Message framework v930.3) Date: Mon, 27 Apr 2009 13:13:44 -0600 X-Mailer: Apple Mail (2.930.3) DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; l=959; t=1240859626; x=1241723626; c=relaxed/simple; s=sjdkim1004; h=Content-Type:From:Subject:Content-Transfer-Encoding:MIME-Version; d=cisco.com; i=fluffy@cisco.com; z=From:=20Cullen=20Jennings=20 |Subject:=20Anouncing=20new=20Sip-Ops=20mailing=20list=20 |Sender:=20; bh=K7DuTheGRiwMCr9seyr+eB+O3RNm63clRiS/PWtDCOg=; b=UoqRUZZlBr3lpUJi34l7wn7fbSz90lCzdgOw5lSiF48YLOd9UxCLKJi4ZG IqfrVLrdbUVnnl6hzqEeWp0jYjsoKKs4j1NgrLkwOg1qGzOsQbpiy/yH3+6E VWDGR3IDptr9KzU/9DCTCA12f+BFE6CuBA1562CuM09Ls2mTD+Rk4=; Authentication-Results: sj-dkim-1; header.From=fluffy@cisco.com; dkim=pass ( sig from cisco.com/sjdkim1004 verified; ); Cc: Robert Sparks Subject: [sip-ops] Anouncing new Sip-Ops mailing list X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 27 Apr 2009 19:12:28 -0000 We have set up a new list for discussion of SIP Operational issues. You can subscribe at https://www.ietf.org/mailman/listinfo/sip-ops The purpose of the SIP-Ops mailing list is to discuss issues and requirements related to operating a SIP domain, which may drive the need for IETF standardization or Best-Common-Practice documentation. For example, issues or needs related to troubleshooting, diagnostics, security, and administration relating to operating a SIP domain would be candidates for this list. This is not a list to ask questions about implementing current standards, nor about specific product/vendor issues. Issues related to peering between domains are more appropriate for discussion in SPEERMINT. Thanks to Victor and Hadriel for running the list. Cullen PS - if you reply to this email, please trim the WGs on the too line appropriate. We don't need threads cross posted to several mailing lists. From victor.pascual.avila@gmail.com Mon Apr 27 12:20:35 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 5BE9228C1C5 for ; Mon, 27 Apr 2009 12:20:35 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.267 X-Spam-Level: X-Spam-Status: No, score=-2.267 tagged_above=-999 required=5 tests=[AWL=0.032, BAYES_00=-2.599, MIME_8BIT_HEADER=0.3] 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 iHdB5pvNJKu8 for ; Mon, 27 Apr 2009 12:20:34 -0700 (PDT) Received: from mail-bw0-f163.google.com (mail-bw0-f163.google.com [209.85.218.163]) by core3.amsl.com (Postfix) with ESMTP id 6B6B228C1D6 for ; Mon, 27 Apr 2009 12:20:31 -0700 (PDT) Received: by bwz7 with SMTP id 7so108928bwz.37 for ; Mon, 27 Apr 2009 12:21:51 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:mime-version:received:date:message-id:subject :from:to:content-type:content-transfer-encoding; bh=XCaOsDpqsxmEEJxhwV1lB7CzT6wdmYtvsKjRXEKaRWY=; b=v3gMnVg7D7L384c6XjXAqU8zruk80qBUg2rDAFb13uQT6A8ZKzWw2+38g8QNOfFPOG gik4/tOjLnRmTiLblAOvK6pQ47DHzhexQLNO9CuRPkipeA5J11T4cQ7guTRt50fgKua5 0k5aRPlDvpeoCa1Hqm5PLDoNuXgjor2xErjFY= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=mime-version:date:message-id:subject:from:to:content-type :content-transfer-encoding; b=uvfRDMEZNd2ayCYw2iO3wWtkCoF0+s96tI8tDJ10OHgzOGuUiDVbBzqdQC5+rBUjO/ fnoX7sS20HN27gX0tCzYTQJRHnF01COhG7frX9fZ5ReteHuRfXMEdqYMM6hPhpGqRst4 fdZd6iMC5n20washTCZmEWpkJW4vuKNRD6BZ4= MIME-Version: 1.0 Received: by 10.223.108.140 with SMTP id f12mr2060257fap.69.1240860111564; Mon, 27 Apr 2009 12:21:51 -0700 (PDT) Date: Mon, 27 Apr 2009 21:21:51 +0200 Message-ID: <618e24240904271221y460d9567g8da01e451f022bc4@mail.gmail.com> From: =?UTF-8?Q?Victor_Pascual_=C3=81vila?= To: sip-ops@ietf.org Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable X-Mailman-Approved-At: Mon, 27 Apr 2009 12:26:40 -0700 Subject: [sip-ops] test 2 X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 27 Apr 2009 19:20:35 -0000 2 --=20 Victor Pascual =C3=81vila From vkg@alcatel-lucent.com Wed Apr 29 07:31:39 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 07C4D3A67F3; Wed, 29 Apr 2009 07:31:39 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -1.598 X-Spam-Level: X-Spam-Status: No, score=-1.598 tagged_above=-999 required=5 tests=[AWL=-0.858, BAYES_20=-0.74] 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 r9nbOZzqpNkk; Wed, 29 Apr 2009 07:31:37 -0700 (PDT) Received: from ihemail2.lucent.com (ihemail2.lucent.com [135.245.0.35]) by core3.amsl.com (Postfix) with ESMTP id 5538D3A6809; Wed, 29 Apr 2009 07:30:47 -0700 (PDT) Received: from umail.lucent.com (h135-3-40-61.lucent.com [135.3.40.61]) by ihemail2.lucent.com (8.13.8/IER-o) with ESMTP id n3TEW8PP003014 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Wed, 29 Apr 2009 09:32:08 -0500 (CDT) Received: from [135.185.236.17] (il0015vkg1.ih.lucent.com [135.185.236.17]) by umail.lucent.com (8.13.8/TPES) with ESMTP id n3TEW8vi017596; Wed, 29 Apr 2009 09:32:08 -0500 (CDT) Message-ID: <49F864E8.20005@alcatel-lucent.com> Date: Wed, 29 Apr 2009 09:32:08 -0500 From: "Vijay K. Gurbani" Organization: Bell Labs Security Technology Research Group User-Agent: Thunderbird 2.0.0.6 (Windows/20070728) MIME-Version: 1.0 To: sip-ops@ietf.org, dispatch@ietf.org Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Scanned-By: MIMEDefang 2.57 on 135.245.2.35 Subject: [sip-ops] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 14:31:39 -0000 [Bcc'd to sipping] Hello: During the SF IETF, the SIP CLF work [2] garnered support and attention; the minutes of the ad-hoc are archived in [1]. While there was near universal support for having a common log format, there was a lot of discussion about whether the format should be text or binary, the argument for binary being that it should be much faster to search. An option for text generation is in [2] and an option for binary generation is in [3]. We realized the question is not "binary vs. text?" but "should we optimize for log generation vs. optimize for log processing?" To that extent, this email is to socialize the performance results we have obtained for generating both binary and ASCII formats, including a simulation of a worst-case analysis by retrieving the last record from large binary and ASCII files. To get these results, we generated 1 Million SIP CLF entries into an ASCII file and the same 1 Million into a binary file. The ASCII file followed the convention of [2] and the binary file that of [3]. The last entry in these files was a SIP request with a special Call-ID. We measured the time it took to search for the special Call-ID in both the binary and ASCII files. Here are the results, followed by some discussion; the source code to the programs that generated these results is also available (see [4].) Total records in binary and ASCII CLF file: 1 Million File size: Binary: 300,999,984 bytes ASCII: 258,999,984 bytes Time taken to generate the CLF file with 1 Million records: Binary CLF: 138.60s ASCII CLF: 7.26s This is a difference of almost 20x in favor of the ASCII CLF. Time taken to seek to the last record of the CLF file: Binary CLF: 3.08s ASCII CLF: 16.55s (using perl v5.6.1) 42.92s (using perl v.5.8 and v5.10) The ASCII CLF seek is five times slower using perl v5.6.1, and 13x slower using perl v5.8 and v5.10. It looks like later versions of perl may have inadvertently made the regex compiler less optimized. We don't know why. The above data is from experiments ran on an Intel dual-core (T2500 @ 2.00 GHz) IBM T60 laptop running Linux 2.6.27 with 1 GByte of memory. We also ran the programs on a more powerful machine: Intel dual-core (X6800 @ 2.93GHz) machines with 8GB RAM and a Linux 2.6.24 kernel. The results scaled accordingly. Clearly, the biggest difference in the above data is the time taken to produce the CLF file. ASCII is a lightweight approach since the SIP entity producing the ASCII CLF file already has the SIP message in text form. It is then just a matter of writing the fields out on disk. With the binary form, the SIP entity producing the binary CLF file has to calculate offsets, which takes a non-negligible amount of time. Since the entity producing the SIP CLF log file should not be over- burdened with the act of producing it, we feel that ASCII CLF generation is the only choice here (i.e., we should optimize for log generation.) Otherwise, the SIP entity producing the binary CLF file will spend an inordinate time in calculating offsets, creating a table of contents, etc. to the detriment of providing the service it is supposed to. That said, it is also clear that the the worst-case search for a record is at five to 13x slower when using ASCII. But, because searching is done offline, we feel that this sub-optimality can well be tolerated. We also feel that there is value in specifying a binary format because it allows for SIP operators who want to do such searches to convert their ASCII files to binary for optimized traversal and other such uses. A binary format must be defined so that offline processes can convert the captured ASCII data to binary format for optimized traversal. Comments and discussions on these results are welcome. If you find any errors in the programs used to generate these results, please do let us know. [1] Thread "[Sipping] Meeting Minutes: Ad-hoc Common Log Format meeting," IETF SIPPING WG, March 27, 2009. Archived at: http://www.ietf.org/mail-archive/web/sipping/current/msg17199.html [2] V. Gurbani, E. Burger, T. Anjali, H. Abdelnur and O. Festor, "The Common Log File (CLF) format for the Session Initiation Protocol (SIP)," IETF Internet-Draft, work in progress, March 9, 2009. Archived at: http://tools.ietf.org/html/draft-gurbani-sipping-clf-01 [3] A. Roach, "Binary Syntax for SIP Common Log Format," IETF Internet-Draft, work in progress, March 25, 2009. Archived at: http://tools.ietf.org/html/draft-roach-sipping-clf-syntax-00. [4] Source code available at the following URLs; please see comment block in clf-write.c on how to generate ASCII and binary CLF files. http://ect.bell-labs.com/who/vkg/IETF/sip-clf/write-clf.c http://ect.bell-labs.com/who/vkg/IETF/sip-clf/clf.h http://ect.bell-labs.com/who/vkg/IETF/sip-clf/read-clf-record.c http://ect.bell-labs.com/who/vkg/IETF/sip-clf/read-clf-record.pl http://ect.bell-labs.com/who/vkg/IETF/sip-clf/Makefile Thanks, - vijay -- Vijay K. Gurbani, Bell Laboratories, Alcatel-Lucent 1960 Lucent Lane, Rm. 9C-533, Naperville, Illinois 60566 (USA) Email: vkg@{alcatel-lucent.com,bell-labs.com,acm.org} Web: http://ect.bell-labs.com/who/vkg/ From theo@crazygreek.co.uk Wed Apr 29 08:46:42 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 631303A6B39; Wed, 29 Apr 2009 08:46:42 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -5.844 X-Spam-Level: X-Spam-Status: No, score=-5.844 tagged_above=-999 required=5 tests=[AWL=0.133, BAYES_00=-2.599, FM_FORGED_GMAIL=0.622, RCVD_IN_DNSWL_MED=-4] 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 CGpTUCYCyu1R; Wed, 29 Apr 2009 08:46:41 -0700 (PDT) Received: from exprod7og108.obsmtp.com (exprod7og108.obsmtp.com [64.18.2.169]) by core3.amsl.com (Postfix) with SMTP id BDEA93A6945; Wed, 29 Apr 2009 08:46:24 -0700 (PDT) Received: from source ([72.14.220.153]) by exprod7ob108.postini.com ([64.18.6.12]) with SMTP ID DSNKSfh2ollaZ/zRlB6EdmXO23KvFLiDgkFI@postini.com; Wed, 29 Apr 2009 08:47:48 PDT Received: by fg-out-1718.google.com with SMTP id e12so503793fga.15 for ; Wed, 29 Apr 2009 08:47:45 -0700 (PDT) MIME-Version: 1.0 Received: by 10.86.3.4 with SMTP id 4mr820606fgc.66.1241020065188; Wed, 29 Apr 2009 08:47:45 -0700 (PDT) In-Reply-To: <49F864E8.20005@alcatel-lucent.com> References: <49F864E8.20005@alcatel-lucent.com> From: Theo Zourzouvillys Date: Wed, 29 Apr 2009 16:47:25 +0100 Message-ID: <167dfb9b0904290847u322161d5h3da18771344436ec@mail.gmail.com> To: "Vijay K. Gurbani" Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable Cc: sip-ops@ietf.org, dispatch@ietf.org, sipping WG Subject: Re: [sip-ops] [dispatch] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 15:46:42 -0000 On Wed, Apr 29, 2009 at 3:32 PM, Vijay K. Gurbani wrote: > =A0If you find any errors in the programs used to generate > these results, please do let us know. actually, your test program is *grossly* skewed in favour of the ASCII implementation. If you modify it slightly to behave in a way i'd expect any developer to, you get (avg 5 runs on a crappy dell vostro desktop): Binary CLF: 0m6.947s ASCII CLF: 0m7.004s If you take i/o out of the question too and set output to /dev/null, then you get: Binary CLF: 0m0.610s ASCII CLF: 0m1.905s which is far more realistic for high throughput servers which are logging to an in-memory circular buffer or some shared memory segments. modified source: http://dev.voip.co.uk/~theo/write-clf.theo.txt diff: http://dev.voip.co.uk/~theo/write-clf.diff note that i wrote it in all of about 120 seconds, so there may be some errors in the output format, but my point stands :-) ~ Theo http://twitter.com/zourzouvillys http://crazygreek.co.uk/ From fluffy@cisco.com Wed Apr 29 09:58:00 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 9B2FB3A6DC2 for ; Wed, 29 Apr 2009 09:58:00 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -106.593 X-Spam-Level: X-Spam-Status: No, score=-106.593 tagged_above=-999 required=5 tests=[AWL=0.006, BAYES_00=-2.599, RCVD_IN_DNSWL_MED=-4, USER_IN_WHITELIST=-100] 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 5csOelMj7Bcd for ; Wed, 29 Apr 2009 09:57:59 -0700 (PDT) Received: from sj-iport-5.cisco.com (sj-iport-5.cisco.com [171.68.10.87]) by core3.amsl.com (Postfix) with ESMTP id BFD9F3A6C8C for ; Wed, 29 Apr 2009 09:57:59 -0700 (PDT) X-IronPort-AV: E=Sophos;i="4.40,267,1238976000"; d="scan'208";a="73857548" Received: from sj-dkim-4.cisco.com ([171.71.179.196]) by sj-iport-5.cisco.com with ESMTP; 29 Apr 2009 16:59:22 +0000 Received: from sj-core-2.cisco.com (sj-core-2.cisco.com [171.71.177.254]) by sj-dkim-4.cisco.com (8.12.11/8.12.11) with ESMTP id n3TGxMkM019443 for ; Wed, 29 Apr 2009 09:59:22 -0700 Received: from [192.168.4.177] (rcdn-fluffy-8711.cisco.com [10.99.9.18]) by sj-core-2.cisco.com (8.13.8/8.13.8) with ESMTP id n3TGxLbg009694 for ; Wed, 29 Apr 2009 16:59:22 GMT Message-Id: <686CEF8E-4560-42FA-9D95-23B7979E4CE9@cisco.com> From: Cullen Jennings To: sip-ops@ietf.org Impp: xmpp:cullenfluffyjennings@jabber.org Content-Type: text/plain; charset=US-ASCII; format=flowed; delsp=yes Content-Transfer-Encoding: 7bit Mime-Version: 1.0 (Apple Message framework v930.3) Date: Wed, 29 Apr 2009 10:59:21 -0600 X-Mailer: Apple Mail (2.930.3) DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; l=238; t=1241024362; x=1241888362; c=relaxed/simple; s=sjdkim4002; h=Content-Type:From:Subject:Content-Transfer-Encoding:MIME-Version; d=cisco.com; i=fluffy@cisco.com; z=From:=20Cullen=20Jennings=20 |Subject:=20Question=20about=20where=20a=20draft=20should=2 0be=20discussed... |Sender:=20; bh=dsBMsPeVPzBlh2bLhUHOI6CrYqsnKoiHESVasOGANpY=; b=YXzu/YesTyZ0Z/wn9mcFYMu5SQgR7jeV6P2YY7Cx2dD0SK36ALuK/+kQSV iQVtnSIMIqilhEJPGohxT9H6d4X/5q+o9Ps7+T7AIqT6UZNdXLJ5RkwtQFNE 4gMiNgRxQk; Authentication-Results: sj-dkim-4; header.From=fluffy@cisco.com; dkim=pass ( sig from cisco.com/sjdkim4002 verified; ); Subject: [sip-ops] Question about where a draft should be discussed... X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 16:58:00 -0000 I got a questions today about when to use this list. Roughly speaking, if you have a draft that you would like to get agenda time in WG X, then you need to discuss it on the mailing list for WG X, not here. Cullen From vkg@alcatel-lucent.com Wed Apr 29 11:11:19 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id AA6E43A67ED; Wed, 29 Apr 2009 11:11:19 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.514 X-Spam-Level: X-Spam-Status: No, score=-2.514 tagged_above=-999 required=5 tests=[AWL=0.085, 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 j2JLLYdef1XX; Wed, 29 Apr 2009 11:11:18 -0700 (PDT) Received: from ihemail3.lucent.com (ihemail3.lucent.com [135.245.0.37]) by core3.amsl.com (Postfix) with ESMTP id 7ABEA3A6D5C; Wed, 29 Apr 2009 11:11:13 -0700 (PDT) Received: from umail.lucent.com (h135-3-40-61.lucent.com [135.3.40.61]) by ihemail3.lucent.com (8.13.8/IER-o) with ESMTP id n3TICTkW011582 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Wed, 29 Apr 2009 13:12:29 -0500 (CDT) Received: from [135.185.236.17] (il0015vkg1.ih.lucent.com [135.185.236.17]) by umail.lucent.com (8.13.8/TPES) with ESMTP id n3TICT2e010603; Wed, 29 Apr 2009 13:12:29 -0500 (CDT) Message-ID: <49F8988C.9050900@alcatel-lucent.com> Date: Wed, 29 Apr 2009 13:12:28 -0500 From: "Vijay K. Gurbani" Organization: Bell Labs Security Technology Research Group User-Agent: Thunderbird 2.0.0.6 (Windows/20070728) MIME-Version: 1.0 To: Theo Zourzouvillys References: <49F864E8.20005@alcatel-lucent.com> <167dfb9b0904290847u322161d5h3da18771344436ec@mail.gmail.com> In-Reply-To: <167dfb9b0904290847u322161d5h3da18771344436ec@mail.gmail.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Scanned-By: MIMEDefang 2.57 on 135.245.2.37 Cc: sip-ops@ietf.org, dispatch@ietf.org, sipping WG Subject: Re: [sip-ops] [dispatch] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 18:11:19 -0000 Theo Zourzouvillys wrote: > actually, your test program is *grossly* skewed in favour of the ASCII > implementation. If you modify it slightly to behave in a way i'd > expect any developer to, you get (avg 5 runs on a crappy dell vostro > desktop): > > Binary CLF: 0m6.947s > ASCII CLF: 0m7.004s [...] Theo: True, using scatter-gather (s-g) writes you can optimize the binary I/O. By the same token, I can optimize the ASCII writes a bit using s-g writes; for instance, I was able to bring the average down by 1.02s for ASCII CLF using s-g writes. But we intentionally stayed away from s-g writes for the following four reasons: 1) On some systems, the value of IOV_MAX is set to a low number. For example, in Solaris 8 the value of IOV_MAX is set to 16, forcing you to do multiple s-g I/O calls (thereby negating some of the optimization effects.) 2) Some systems have a maximum ceiling on how many bytes can be transferred in one writev(), i.e., the sum of all iov_len members of the iov array should be less than a certain system-defined maximum. [Note: I seem to remember that a few years ago, the Apache lists were full of problems related to 1 and 2.] 3) Portability: I was not sure how portable the writev() system call would be on all kinds of operating environments. Since the SIP CLF is designed for all SIP entities, if a (real-time) operating system does not have the writev() system call, one is forced to used the non-optimized method anyway. Furthermore, in a RT OS, the limits for 1 and 2 will be much lower, if writev() is provided at all. 4) We did not necessarily want to make any assumptions about how implementations have created data structures to hold the results of parsing (i.e., some implementations may very well use struct's to store the text and length for each SIP token, while others may simply store the text and compute the length when needed, etc.) For the sake of demonstration, our program implements the first option (i.e., uses struct's to store the text and length), which is actually more conducive to the s-g approach, but by no means is this the only way to design your data structures. (1) is a real concern because as you can well imagine that URIs, once parsed, can be composed of many different objects (or structs in C.) As such, the representation of a composed URI in a iov structure will require multiple indexes. Hence, we wanted to use the most common denominator to do the measurements -- in our initial performance data, there is no optimization for either the binary CLF case or the ASCII CLF case. > note that i wrote it in all of about 120 seconds, so there may be some > errors in the output format, but my point stands :-) There appear to be since I cannot read the last record; but I have not had the chance to look at the output format from your program in any detail. Thanks, - vijay -- Vijay K. Gurbani, Bell Laboratories, Alcatel-Lucent 1960 Lucent Lane, Rm. 9C-533, Naperville, Illinois 60566 (USA) Email: vkg@{alcatel-lucent.com,bell-labs.com,acm.org} Web: http://ect.bell-labs.com/who/vkg/ From theo@crazygreek.co.uk Wed Apr 29 12:03:17 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id F0E9A3A6D40; Wed, 29 Apr 2009 12:03:17 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -5.847 X-Spam-Level: X-Spam-Status: No, score=-5.847 tagged_above=-999 required=5 tests=[AWL=0.130, BAYES_00=-2.599, FM_FORGED_GMAIL=0.622, RCVD_IN_DNSWL_MED=-4] 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 vDfn79ji7Vps; Wed, 29 Apr 2009 12:03:17 -0700 (PDT) Received: from exprod7og118.obsmtp.com (exprod7og118.obsmtp.com [64.18.2.8]) by core3.amsl.com (Postfix) with SMTP id 3C3CA28C2AA; Wed, 29 Apr 2009 12:02:01 -0700 (PDT) Received: from source ([209.85.218.224]) by exprod7ob118.postini.com ([64.18.6.12]) with SMTP ID DSNKSfike3mFeRqeWlX8Ps4oatnjVByy9iKl@postini.com; Wed, 29 Apr 2009 12:03:24 PDT Received: by bwz24 with SMTP id 24so1387084bwz.22 for ; Wed, 29 Apr 2009 12:03:22 -0700 (PDT) MIME-Version: 1.0 Received: by 10.204.64.67 with SMTP id d3mr594033bki.142.1241031802132; Wed, 29 Apr 2009 12:03:22 -0700 (PDT) In-Reply-To: <49F8988C.9050900@alcatel-lucent.com> References: <49F864E8.20005@alcatel-lucent.com> <167dfb9b0904290847u322161d5h3da18771344436ec@mail.gmail.com> <49F8988C.9050900@alcatel-lucent.com> From: Theo Zourzouvillys Date: Wed, 29 Apr 2009 20:03:02 +0100 Message-ID: <167dfb9b0904291203m4e74ab39s5f83cfa1be9799a0@mail.gmail.com> To: "Vijay K. Gurbani" Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Cc: sip-ops@ietf.org, dispatch@ietf.org, sipping WG Subject: Re: [sip-ops] [dispatch] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 19:03:18 -0000 On Wed, Apr 29, 2009 at 7:12 PM, Vijay K. Gurbani wrote: > 1) On some systems, the value of IOV_MAX is set to a low number. (1) is irrelivant. scatther/gather is not the only optimal method of implementing it. even on crappy old OSes, a simple memcpy() of the data is similar in performance, cache coherency caveat emptor: http://dev.voip.co.uk/~theo/write-clf.theo2.txt Binary: 0m7.400s ASCII: 0m7.038s > (1) is a real concern because as you can well imagine that URIs, > once parsed, can be composed of many different objects (or > structs in C.) As such, the representation of a composed URI > in a iov structure will require multiple indexes. i'd argue your concerns are moot - a URI composed of many different objects will need to be built into a string if it's ASCII anyway. to be honest, i through they took the performance card out of the pack so it couldn't be used any more in 2002 - if logging is causing you scalability problems, you've got far more to worry about than that. plus, any implementation not running on a modern OS is going to have other missing features needed for performance improvements outside of writev()'s limitations (ps: i'm not too concerned about binary/ascii - although i lean toward the binary side - please just don't use performance as an argument unless the figures are fair. pretty please!) ~ Theo -- http://twitter.com/zourzouvillys http://crazygreek.co.uk/ From john.elwell@siemens-enterprise.com Wed Apr 29 12:33:49 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id AB65A3A6C28; Wed, 29 Apr 2009 12:33:49 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.463 X-Spam-Level: X-Spam-Status: No, score=-2.463 tagged_above=-999 required=5 tests=[AWL=0.136, 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 q7ZUZnza1kj0; Wed, 29 Apr 2009 12:33:45 -0700 (PDT) Received: from mailgate.siemenscomms.co.uk (mailgate.siemenscomms.co.uk [195.171.110.225]) by core3.amsl.com (Postfix) with ESMTP id 02A083A6B0B; Wed, 29 Apr 2009 12:33:45 -0700 (PDT) Received: from GBNTHT12009MSX.gb002.siemens.net ([137.223.219.235]) by siemenscomms.co.uk (PMDF V6.3-x14 #31430) with ESMTP id <0KIV0040PNQIZS@siemenscomms.co.uk>; Wed, 29 Apr 2009 20:35:06 +0100 (BST) Date: Wed, 29 Apr 2009 20:34:53 +0100 From: "Elwell, John" In-reply-to: <49F864E8.20005@alcatel-lucent.com> To: "Vijay K. Gurbani" , sip-ops@ietf.org, dispatch@ietf.org Message-id: <0D5F89FAC29E2C41B98A6A762007F5D001D4B064@GBNTHT12009MSX.gb002.siemens.net> MIME-version: 1.0 X-MIMEOLE: Produced By Microsoft Exchange V6.5 Content-type: text/plain; charset=us-ascii Content-transfer-encoding: quoted-printable Thread-Topic: [Sipping] SIP-CLF: Results on ASCII vs. binary representation Thread-Index: AcnI9br/nWx/gqT5RQOLEzQ9F4PdmgACpchg Content-class: urn:content-classes:message X-MS-Has-Attach: X-MS-TNEF-Correlator: References: <49F864E8.20005@alcatel-lucent.com> Subject: Re: [sip-ops] [Sipping] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 19:33:49 -0000 Vijay, Useful figures, which do indeed suggest generating the initial log in ASCII. The question is whether we need to standardise a binary format too, or whether any off-line conversion for the purpose of optimising searches can be done in a non-standardised manner. In other words, if it is acceptable always to pass around the log in ASCII format, any system using it can perform its own optimisation to suit its own purposes. John p.s. which list - DISPATCH or SIP-OPS? =20 > -----Original Message----- > From: sipping-bounces@ietf.org=20 > [mailto:sipping-bounces@ietf.org] On Behalf Of Vijay K. Gurbani > Sent: 29 April 2009 15:32 > To: sip-ops@ietf.org; dispatch@ietf.org > Subject: [Sipping] SIP-CLF: Results on ASCII vs. binary representation >=20 > [Bcc'd to sipping] >=20 > Hello: >=20 > During the SF IETF, the SIP CLF work [2] garnered support > and attention; the minutes of the ad-hoc are archived in [1]. >=20 > While there was near universal support for having a common > log format, there was a lot of discussion about whether > the format should be text or binary, the argument for binary > being that it should be much faster to search. An option > for text generation is in [2] and an option for > binary generation is in [3]. >=20 > We realized the question is not "binary vs. text?" but > "should we optimize for log generation vs. optimize for > log processing?" To that extent, this email is to socialize > the performance results we have obtained for generating > both binary and ASCII formats, including a simulation of a > worst-case analysis by retrieving the last record from large > binary and ASCII files. >=20 > To get these results, we generated 1 Million SIP CLF entries > into an ASCII file and the same 1 Million into a binary file. > The ASCII file followed the convention of [2] and the binary > file that of [3]. The last entry in these files was a SIP > request with a special Call-ID. We measured the time it took > to search for the special Call-ID in both the binary and ASCII > files. Here are the results, followed by some discussion; the > source code to the programs that generated these results is > also available (see [4].) >=20 > Total records in binary and ASCII CLF file: 1 Million > File size: > Binary: 300,999,984 bytes > ASCII: 258,999,984 bytes >=20 > Time taken to generate the CLF file with 1 Million records: > Binary CLF: 138.60s > ASCII CLF: 7.26s >=20 > This is a difference of almost 20x in favor of the ASCII CLF. >=20 > Time taken to seek to the last record of the CLF file: > Binary CLF: 3.08s > ASCII CLF: 16.55s (using perl v5.6.1) > 42.92s (using perl v.5.8 and v5.10) >=20 > The ASCII CLF seek is five times slower using perl v5.6.1, > and 13x slower using perl v5.8 and v5.10. It looks like later > versions of perl may have inadvertently made the regex compiler > less optimized. We don't know why. >=20 > The above data is from experiments ran on an Intel dual-core > (T2500 @ 2.00 GHz) IBM T60 laptop running Linux 2.6.27 with 1 > GByte of memory. > We also ran the programs on a more powerful machine: Intel > dual-core (X6800 @ 2.93GHz) machines with 8GB RAM and a > Linux 2.6.24 kernel. The results scaled accordingly. >=20 > Clearly, the biggest difference in the above data is the time > taken to produce the CLF file. ASCII is a lightweight approach > since the SIP entity producing the ASCII CLF file already has > the SIP message in text form. It is then just a matter of > writing the fields out on disk. With the binary form, the > SIP entity producing the binary CLF file has to calculate > offsets, which takes a non-negligible amount of time. Since > the entity producing the SIP CLF log file should not be over- > burdened with the act of producing it, we feel that ASCII CLF > generation is the only choice here (i.e., we should optimize for > log generation.) Otherwise, the SIP entity producing the > binary CLF file will spend an inordinate time in calculating > offsets, creating a table of contents, etc. to the detriment > of providing the service it is supposed to. >=20 > That said, it is also clear that the the worst-case search > for a record is at five to 13x slower when using ASCII. But, > because searching is done offline, we feel that this sub-optimality > can well be tolerated. We also feel that there is value in > specifying a binary format because it allows for SIP operators > who want to do such searches to convert their ASCII files to > binary for optimized traversal and other such uses. A binary > format must be defined so that offline processes can convert > the captured ASCII data to binary format for optimized > traversal. >=20 > Comments and discussions on these results are welcome. If > you find any errors in the programs used to generate > these results, please do let us know. >=20 > [1] Thread "[Sipping] Meeting Minutes: Ad-hoc Common Log Format > meeting," IETF SIPPING WG, March 27, 2009. Archived at: > http://www.ietf.org/mail-archive/web/sipping/current/msg17199.html >=20 > [2] V. Gurbani, E. Burger, T. Anjali, H. Abdelnur and O. Festor, > "The Common Log File (CLF) format for the Session Initiation > Protocol (SIP)," IETF Internet-Draft, work in progress, March 9, > 2009. Archived at: > http://tools.ietf.org/html/draft-gurbani-sipping-clf-01 >=20 > [3] A. Roach, "Binary Syntax for SIP Common Log Format," IETF > Internet-Draft, work in progress, March 25, 2009. Archived at: > http://tools.ietf.org/html/draft-roach-sipping-clf-syntax-00. >=20 > [4] Source code available at the following URLs; please see > comment block in clf-write.c on how to generate ASCII and > binary CLF files. > http://ect.bell-labs.com/who/vkg/IETF/sip-clf/write-clf.c > http://ect.bell-labs.com/who/vkg/IETF/sip-clf/clf.h > http://ect.bell-labs.com/who/vkg/IETF/sip-clf/read-clf-record.c > http://ect.bell-labs.com/who/vkg/IETF/sip-clf/read-clf-record.pl > http://ect.bell-labs.com/who/vkg/IETF/sip-clf/Makefile >=20 > Thanks, >=20 > - vijay > --=20 > Vijay K. Gurbani, Bell Laboratories, Alcatel-Lucent > 1960 Lucent Lane, Rm. 9C-533, Naperville, Illinois 60566 (USA) > Email: vkg@{alcatel-lucent.com,bell-labs.com,acm.org} > Web: http://ect.bell-labs.com/who/vkg/ > _______________________________________________ > Sipping mailing list https://www.ietf.org/mailman/listinfo/sipping > This list is for NEW development of the application of SIP > Use sip-implementors@cs.columbia.edu for questions on current sip > Use sip@ietf.org for new developments of core SIP >=20 From mary.barnes@nortel.com Wed Apr 29 12:41:17 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id E4F1C3A6DB7; Wed, 29 Apr 2009 12:41:17 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -6.475 X-Spam-Level: X-Spam-Status: No, score=-6.475 tagged_above=-999 required=5 tests=[AWL=0.124, BAYES_00=-2.599, RCVD_IN_DNSWL_MED=-4] 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 Iqh6Ht3770MK; Wed, 29 Apr 2009 12:41:16 -0700 (PDT) Received: from zrtps0kp.nortel.com (zrtps0kp.nortel.com [47.140.192.56]) by core3.amsl.com (Postfix) with ESMTP id 8BC6A3A6A4D; Wed, 29 Apr 2009 12:40:39 -0700 (PDT) Received: from zrc2hxm0.corp.nortel.com (zrc2hxm0.corp.nortel.com [47.103.123.71]) by zrtps0kp.nortel.com (Switch-2.2.6/Switch-2.2.0) with ESMTP id n3TJfw403677; Wed, 29 Apr 2009 19:41:58 GMT X-MimeOLE: Produced By Microsoft Exchange V6.5 Content-class: urn:content-classes:message MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: quoted-printable Date: Wed, 29 Apr 2009 14:44:43 -0500 Message-ID: <1ECE0EB50388174790F9694F77522CCF1DBA1142@zrc2hxm0.corp.nortel.com> In-Reply-To: <0D5F89FAC29E2C41B98A6A762007F5D001D4B064@GBNTHT12009MSX.gb002.siemens.net> X-MS-Has-Attach: X-MS-TNEF-Correlator: Thread-Topic: [dispatch] [Sipping] SIP-CLF: Results on ASCII vs. binaryrepresentation Thread-Index: AcnI9br/nWx/gqT5RQOLEzQ9F4PdmgACpchgAACaquA= References: <49F864E8.20005@alcatel-lucent.com> <0D5F89FAC29E2C41B98A6A762007F5D001D4B064@GBNTHT12009MSX.gb002.siemens.net> From: "Mary Barnes" To: "Elwell, John" , "Vijay K. Gurbani" , , Subject: Re: [sip-ops] [dispatch] [Sipping] SIP-CLF: Results on ASCII vs. binaryrepresentation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 19:41:18 -0000 I posted a note on SIPPING WG mailing list suggesting that this discussion should occur on DISPATCH WG mailing list - sorry I should have cross-posted that one posting. =20 Mary.=20 -----Original Message----- From: dispatch-bounces@ietf.org [mailto:dispatch-bounces@ietf.org] On Behalf Of Elwell, John Sent: Wednesday, April 29, 2009 2:35 PM To: Vijay K. Gurbani; sip-ops@ietf.org; dispatch@ietf.org Subject: Re: [dispatch] [Sipping] SIP-CLF: Results on ASCII vs. binaryrepresentation Vijay, Useful figures, which do indeed suggest generating the initial log in ASCII. The question is whether we need to standardise a binary format too, or whether any off-line conversion for the purpose of optimising searches can be done in a non-standardised manner. In other words, if it is acceptable always to pass around the log in ASCII format, any system using it can perform its own optimisation to suit its own purposes. John p.s. which list - DISPATCH or SIP-OPS? =20 > -----Original Message----- > From: sipping-bounces@ietf.org > [mailto:sipping-bounces@ietf.org] On Behalf Of Vijay K. Gurbani > Sent: 29 April 2009 15:32 > To: sip-ops@ietf.org; dispatch@ietf.org > Subject: [Sipping] SIP-CLF: Results on ASCII vs. binary representation >=20 > [Bcc'd to sipping] >=20 > Hello: >=20 > During the SF IETF, the SIP CLF work [2] garnered support and=20 > attention; the minutes of the ad-hoc are archived in [1]. >=20 > While there was near universal support for having a common log format, > there was a lot of discussion about whether the format should be text=20 > or binary, the argument for binary being that it should be much faster > to search. An option for text generation is in [2] and an option for=20 > binary generation is in [3]. >=20 > We realized the question is not "binary vs. text?" but "should we=20 > optimize for log generation vs. optimize for log processing?" To that > extent, this email is to socialize the performance results we have=20 > obtained for generating both binary and ASCII formats, including a=20 > simulation of a worst-case analysis by retrieving the last record from > large binary and ASCII files. >=20 > To get these results, we generated 1 Million SIP CLF entries into an=20 > ASCII file and the same 1 Million into a binary file. > The ASCII file followed the convention of [2] and the binary file that > of [3]. The last entry in these files was a SIP request with a=20 > special Call-ID. We measured the time it took to search for the=20 > special Call-ID in both the binary and ASCII files. Here are the=20 > results, followed by some discussion; the source code to the programs=20 > that generated these results is also available (see [4].) >=20 > Total records in binary and ASCII CLF file: 1 Million File size: > Binary: 300,999,984 bytes > ASCII: 258,999,984 bytes >=20 > Time taken to generate the CLF file with 1 Million records: > Binary CLF: 138.60s > ASCII CLF: 7.26s >=20 > This is a difference of almost 20x in favor of the ASCII CLF. >=20 > Time taken to seek to the last record of the CLF file: > Binary CLF: 3.08s > ASCII CLF: 16.55s (using perl v5.6.1) > 42.92s (using perl v.5.8 and v5.10) >=20 > The ASCII CLF seek is five times slower using perl v5.6.1, > and 13x slower using perl v5.8 and v5.10. It looks like later > versions of perl may have inadvertently made the regex compiler > less optimized. We don't know why. >=20 > The above data is from experiments ran on an Intel dual-core > (T2500 @ 2.00 GHz) IBM T60 laptop running Linux 2.6.27 with 1 > GByte of memory. > We also ran the programs on a more powerful machine: Intel > dual-core (X6800 @ 2.93GHz) machines with 8GB RAM and a > Linux 2.6.24 kernel. The results scaled accordingly. >=20 > Clearly, the biggest difference in the above data is the time taken to > produce the CLF file. ASCII is a lightweight approach since the SIP=20 > entity producing the ASCII CLF file already has the SIP message in=20 > text form. It is then just a matter of writing the fields out on=20 > disk. With the binary form, the SIP entity producing the binary CLF=20 > file has to calculate offsets, which takes a non-negligible amount of=20 > time. Since the entity producing the SIP CLF log file should not be=20 > over- burdened with the act of producing it, we feel that ASCII CLF=20 > generation is the only choice here (i.e., we should optimize for log=20 > generation.) Otherwise, the SIP entity producing the binary CLF file=20 > will spend an inordinate time in calculating offsets, creating a table > of contents, etc. to the detriment of providing the service it is=20 > supposed to. >=20 > That said, it is also clear that the the worst-case search for a=20 > record is at five to 13x slower when using ASCII. But, because=20 > searching is done offline, we feel that this sub-optimality can well=20 > be tolerated. We also feel that there is value in specifying a binary > format because it allows for SIP operators who want to do such=20 > searches to convert their ASCII files to binary for optimized=20 > traversal and other such uses. A binary format must be defined so=20 > that offline processes can convert the captured ASCII data to binary=20 > format for optimized traversal. >=20 > Comments and discussions on these results are welcome. If you find=20 > any errors in the programs used to generate these results, please do=20 > let us know. >=20 > [1] Thread "[Sipping] Meeting Minutes: Ad-hoc Common Log Format > meeting," IETF SIPPING WG, March 27, 2009. Archived at: > http://www.ietf.org/mail-archive/web/sipping/current/msg17199.html >=20 > [2] V. Gurbani, E. Burger, T. Anjali, H. Abdelnur and O. Festor, > "The Common Log File (CLF) format for the Session Initiation > Protocol (SIP)," IETF Internet-Draft, work in progress, March 9, > 2009. Archived at: > http://tools.ietf.org/html/draft-gurbani-sipping-clf-01 >=20 > [3] A. Roach, "Binary Syntax for SIP Common Log Format," IETF > Internet-Draft, work in progress, March 25, 2009. Archived at: > http://tools.ietf.org/html/draft-roach-sipping-clf-syntax-00. >=20 > [4] Source code available at the following URLs; please see > comment block in clf-write.c on how to generate ASCII and > binary CLF files. > http://ect.bell-labs.com/who/vkg/IETF/sip-clf/write-clf.c > http://ect.bell-labs.com/who/vkg/IETF/sip-clf/clf.h > http://ect.bell-labs.com/who/vkg/IETF/sip-clf/read-clf-record.c > http://ect.bell-labs.com/who/vkg/IETF/sip-clf/read-clf-record.pl > http://ect.bell-labs.com/who/vkg/IETF/sip-clf/Makefile >=20 > Thanks, >=20 > - vijay > -- > Vijay K. Gurbani, Bell Laboratories, Alcatel-Lucent 1960 Lucent Lane,=20 > Rm. 9C-533, Naperville, Illinois 60566 (USA) > Email: vkg@{alcatel-lucent.com,bell-labs.com,acm.org} > Web: http://ect.bell-labs.com/who/vkg/ > _______________________________________________ > Sipping mailing list https://www.ietf.org/mailman/listinfo/sipping > This list is for NEW development of the application of SIP Use=20 > sip-implementors@cs.columbia.edu for questions on current sip Use=20 > sip@ietf.org for new developments of core SIP >=20 _______________________________________________ dispatch mailing list dispatch@ietf.org https://www.ietf.org/mailman/listinfo/dispatch From vkg@alcatel-lucent.com Wed Apr 29 13:27:13 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id AD9FC3A6EDE; Wed, 29 Apr 2009 13:27:13 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.516 X-Spam-Level: X-Spam-Status: No, score=-2.516 tagged_above=-999 required=5 tests=[AWL=0.083, 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 PycnSXVQttZA; Wed, 29 Apr 2009 13:27:12 -0700 (PDT) Received: from ihemail3.lucent.com (ihemail3.lucent.com [135.245.0.37]) by core3.amsl.com (Postfix) with ESMTP id 56EC928C265; Wed, 29 Apr 2009 13:26:01 -0700 (PDT) Received: from umail.lucent.com (h135-3-40-61.lucent.com [135.3.40.61]) by ihemail3.lucent.com (8.13.8/IER-o) with ESMTP id n3TKRKqM015814 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Wed, 29 Apr 2009 15:27:20 -0500 (CDT) Received: from [135.185.236.17] (il0015vkg1.ih.lucent.com [135.185.236.17]) by umail.lucent.com (8.13.8/TPES) with ESMTP id n3TKRKEZ004184; Wed, 29 Apr 2009 15:27:20 -0500 (CDT) Message-ID: <49F8B827.3060501@alcatel-lucent.com> Date: Wed, 29 Apr 2009 15:27:19 -0500 From: "Vijay K. Gurbani" Organization: Bell Labs Security Technology Research Group User-Agent: Thunderbird 2.0.0.6 (Windows/20070728) MIME-Version: 1.0 To: Theo Zourzouvillys References: <49F864E8.20005@alcatel-lucent.com> <167dfb9b0904290847u322161d5h3da18771344436ec@mail.gmail.com> <49F8988C.9050900@alcatel-lucent.com> <167dfb9b0904291203m4e74ab39s5f83cfa1be9799a0@mail.gmail.com> In-Reply-To: <167dfb9b0904291203m4e74ab39s5f83cfa1be9799a0@mail.gmail.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Scanned-By: MIMEDefang 2.57 on 135.245.2.37 Cc: sip-ops@ietf.org, dispatch@ietf.org Subject: Re: [sip-ops] [dispatch] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 20:27:13 -0000 Theo Zourzouvillys wrote: >> 1) On some systems, the value of IOV_MAX is set to a low number. > > (1) is irrelivant. scatther/gather is not the only optimal method of > implementing it. even on crappy old OSes, a simple memcpy() of the > data is similar in performance, cache coherency caveat emptor: > > http://dev.voip.co.uk/~theo/write-clf.theo2.txt > > Binary: 0m7.400s > ASCII: 0m7.038s So after tweaking all kinds of optimizations for binary CLF, the best we can do is approach ASCII CLF without any optimizations. This much no one will dispute, I hope. >> (1) is a real concern because as you can well imagine that URIs, >> once parsed, can be composed of many different objects (or >> structs in C.) As such, the representation of a composed URI >> in a iov structure will require multiple indexes. > > i'd argue your concerns are moot - a URI composed of many different > objects will need to be built into a string if it's ASCII anyway. Precisely my point -- since the URIs arrive in ASCII and leave in ASCII, let's just write the darn thing out in straight ASCII without too much computation and be done with it! > (ps: i'm not too concerned about binary/ascii - although i lean toward > the binary side - please just don't use performance as an argument > unless the figures are fair. pretty please!) In the final analysis, I am not too concerned about binary vs. ASCII, either; although I lean towards the ASCII side. That said, I must admit that I was afraid the only mandated CLF form would turn out to be binary CLF, and I wanted to at least raise a point that it is not a panacea. It has its strong points -- no doubt -- but it should not be the only format. Furthermore, consider that a major constituency for the upkeep of SIP servers will be the IT department. Which format do you think the IT folks will prefer? I have a strong suspicion that it will be ASCII because that is what they are used to -- they can see it, read it, are used to it, and can write tools in perl/ruby/python easily to transform it according to their needs, etc. If SIP is to find more purchase and expand mind share in these departments, then limiting a log format to binary is hardly a wise choice. My proposal is that we document both the formats but we make the ASCII format the mandatory-to-implement. A well documented binary format (contained in the same draft) will keep the telecommunication providers whose NOCs are used to dealing with binary happy. Not to mention that searches are faster with a binary format -- that much is not in dispute. Thanks, - vijay -- Vijay K. Gurbani, Bell Laboratories, Alcatel-Lucent 1960 Lucent Lane, Rm. 9C-533, Naperville, Illinois 60566 (USA) Email: vkg@{alcatel-lucent.com,bell-labs.com,acm.org} Web: http://ect.bell-labs.com/who/vkg/ From vkg@alcatel-lucent.com Wed Apr 29 13:37:00 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 0D71D28C21A; Wed, 29 Apr 2009 13:37:00 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.517 X-Spam-Level: X-Spam-Status: No, score=-2.517 tagged_above=-999 required=5 tests=[AWL=0.082, 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 NHn2atsUK3ev; Wed, 29 Apr 2009 13:36:55 -0700 (PDT) Received: from ihemail3.lucent.com (ihemail3.lucent.com [135.245.0.37]) by core3.amsl.com (Postfix) with ESMTP id E564528C28E; Wed, 29 Apr 2009 13:36:54 -0700 (PDT) Received: from umail.lucent.com (h135-3-40-61.lucent.com [135.3.40.61]) by ihemail3.lucent.com (8.13.8/IER-o) with ESMTP id n3TKcGg9023845 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Wed, 29 Apr 2009 15:38:16 -0500 (CDT) Received: from [135.185.236.17] (il0015vkg1.ih.lucent.com [135.185.236.17]) by umail.lucent.com (8.13.8/TPES) with ESMTP id n3TKcGAZ014534; Wed, 29 Apr 2009 15:38:16 -0500 (CDT) Message-ID: <49F8BAB8.1000206@alcatel-lucent.com> Date: Wed, 29 Apr 2009 15:38:16 -0500 From: "Vijay K. Gurbani" Organization: Bell Labs Security Technology Research Group User-Agent: Thunderbird 2.0.0.6 (Windows/20070728) MIME-Version: 1.0 To: "Elwell, John" References: <49F864E8.20005@alcatel-lucent.com> <0D5F89FAC29E2C41B98A6A762007F5D001D4B064@GBNTHT12009MSX.gb002.siemens.net> In-Reply-To: <0D5F89FAC29E2C41B98A6A762007F5D001D4B064@GBNTHT12009MSX.gb002.siemens.net> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Scanned-By: MIMEDefang 2.57 on 135.245.2.37 Cc: sip-ops@ietf.org, dispatch@ietf.org Subject: Re: [sip-ops] [Sipping] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 20:37:00 -0000 Elwell, John wrote: > Vijay, > > Useful figures, which do indeed suggest generating the initial log in > ASCII. The question is whether we need to standardise a binary format > too, John: Binary format is great for optimized searches. As such, standardizing it is good -- tools can be developed to operate on the ASCII data offline and convert it to binary. I just want to ensure that the binary format is not the only format chosen for the SIP CLF work. Thanks, - vijay -- Vijay K. Gurbani, Bell Laboratories, Alcatel-Lucent 1960 Lucent Lane, Rm. 9C-533, Naperville, Illinois 60566 (USA) Email: vkg@{alcatel-lucent.com,bell-labs.com,acm.org} Web: http://ect.bell-labs.com/who/vkg/ From HKaplan@acmepacket.com Wed Apr 29 13:44:19 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 5078C3A71AD; Wed, 29 Apr 2009 13:44:19 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.544 X-Spam-Level: X-Spam-Status: No, score=-2.544 tagged_above=-999 required=5 tests=[AWL=0.055, 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 5a7z95gn+-Wq; Wed, 29 Apr 2009 13:44:18 -0700 (PDT) Received: from etmail.acmepacket.com (etmail.acmepacket.com [216.41.24.6]) by core3.amsl.com (Postfix) with ESMTP id 791873A71A7; Wed, 29 Apr 2009 13:44:18 -0700 (PDT) Received: from mail.acmepacket.com (216.41.24.7) by etmail.acmepacket.com (216.41.24.6) with Microsoft SMTP Server (TLS) id 8.1.340.0; Wed, 29 Apr 2009 16:45:40 -0400 Received: from mail.acmepacket.com ([127.0.0.1]) by mail ([127.0.0.1]) with mapi; Wed, 29 Apr 2009 16:45:39 -0400 From: Hadriel Kaplan To: "Vijay K. Gurbani" , Theo Zourzouvillys Date: Wed, 29 Apr 2009 16:45:38 -0400 Thread-Topic: [dispatch] SIP-CLF: Results on ASCII vs. binary representation Thread-Index: AcnJCRuiERgOVGj2SZe+RYbB1Ujd2AAAWJig Message-ID: References: <49F864E8.20005@alcatel-lucent.com> <167dfb9b0904290847u322161d5h3da18771344436ec@mail.gmail.com> <49F8988C.9050900@alcatel-lucent.com> <167dfb9b0904291203m4e74ab39s5f83cfa1be9799a0@mail.gmail.com> <49F8B827.3060501@alcatel-lucent.com> In-Reply-To: <49F8B827.3060501@alcatel-lucent.com> Accept-Language: en-US Content-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: acceptlanguage: en-US Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: quoted-printable MIME-Version: 1.0 Cc: "sip-ops@ietf.org" , "dispatch@ietf.org" Subject: Re: [sip-ops] [dispatch] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 20:44:19 -0000 > -----Original Message----- > From: dispatch-bounces@ietf.org [mailto:dispatch-bounces@ietf.org] On > Behalf Of Vijay K. Gurbani >=20 > So after tweaking all kinds of optimizations for binary CLF, the > best we can do is approach ASCII CLF without any optimizations. > This much no one will dispute, I hope. Depends on how you plan to disambiguate legal characters in the fields from= the field separators. In binary the length field removes the need for dis= ambiguation, or a CRLF itself does it (depending on the format). In ascii,= if you have to escape characters, then that escaping and de-escaping could= be a big hit. But anyway, I think the real question that needs to be answered *first* is = "what is the purpose of the CLF?" What is it going to help admins do? Is = it for troubleshooting, or for registration audit logging, or for IDS syste= ms, etc? -hadriel From vkg@alcatel-lucent.com Wed Apr 29 14:44:36 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 9B6493A71C2; Wed, 29 Apr 2009 14:44:36 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.518 X-Spam-Level: X-Spam-Status: No, score=-2.518 tagged_above=-999 required=5 tests=[AWL=0.081, 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 5H2VwhEsNbc8; Wed, 29 Apr 2009 14:44:35 -0700 (PDT) Received: from ihemail3.lucent.com (ihemail3.lucent.com [135.245.0.37]) by core3.amsl.com (Postfix) with ESMTP id 6FD7C3A71B4; Wed, 29 Apr 2009 14:44:34 -0700 (PDT) Received: from umail.lucent.com (h135-3-40-61.lucent.com [135.3.40.61]) by ihemail3.lucent.com (8.13.8/IER-o) with ESMTP id n3TLjrVI006430 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Wed, 29 Apr 2009 16:45:53 -0500 (CDT) Received: from [135.185.236.17] (il0015vkg1.ih.lucent.com [135.185.236.17]) by umail.lucent.com (8.13.8/TPES) with ESMTP id n3TLjqIZ007923; Wed, 29 Apr 2009 16:45:53 -0500 (CDT) Message-ID: <49F8CA90.3000508@alcatel-lucent.com> Date: Wed, 29 Apr 2009 16:45:52 -0500 From: "Vijay K. Gurbani" Organization: Bell Labs Security Technology Research Group User-Agent: Thunderbird 2.0.0.6 (Windows/20070728) MIME-Version: 1.0 To: Hadriel Kaplan References: <49F864E8.20005@alcatel-lucent.com> <167dfb9b0904290847u322161d5h3da18771344436ec@mail.gmail.com> <49F8988C.9050900@alcatel-lucent.com> <167dfb9b0904291203m4e74ab39s5f83cfa1be9799a0@mail.gmail.com> <49F8B827.3060501@alcatel-lucent.com> In-Reply-To: Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Scanned-By: MIMEDefang 2.57 on 135.245.2.37 Cc: "sip-ops@ietf.org" , "dispatch@ietf.org" Subject: Re: [sip-ops] [dispatch] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 29 Apr 2009 21:44:36 -0000 Hadriel Kaplan wrote: > Depends on how you plan to disambiguate legal characters in the > fields from the field separators. In binary the length field removes > the need for disambiguation, or a CRLF itself does it (depending on > the format). In ascii, if you have to escape characters, then that > escaping and de-escaping could be a big hit. Right; this is a nagging problem at the back of my head ever since Dale pointed it out. The least impacting way to deal with this, I believe, will be not to save display-name type of constructs but only addr-spec for URIs. The generic-param construct is another potential problem. Spaces in it need to be escaped or generic-param could be simply unallowed. I don't know what the right answer should be right now. > But anyway, I think the real question that needs to be answered > *first* is "what is the purpose of the CLF?" What is it going to > help admins do? Is it for troubleshooting, or for registration audit > logging, or for IDS systems, etc? From the list above, at least for troubleshooting, logging, and IDS systems. What I do not envision CLF being used for is debugging (distinct from troubleshooting) and CDR. Thanks, - vijay -- Vijay K. Gurbani, Bell Laboratories, Alcatel-Lucent 1960 Lucent Lane, Rm. 9C-533, Naperville, Illinois 60566 (USA) Email: vkg@{alcatel-lucent.com,bell-labs.com,acm.org} Web: http://ect.bell-labs.com/who/vkg/ From adam@nostrum.com Thu Apr 30 13:07:09 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 1A9643A6FFF; Thu, 30 Apr 2009 13:07:09 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.579 X-Spam-Level: X-Spam-Status: No, score=-2.579 tagged_above=-999 required=5 tests=[AWL=0.021, BAYES_00=-2.599, SPF_PASS=-0.001] 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 nZA5zoODLZZT; Thu, 30 Apr 2009 13:07:08 -0700 (PDT) Received: from nostrum.com (nostrum-pt.tunnel.tserv2.fmt.ipv6.he.net [IPv6:2001:470:1f03:267::2]) by core3.amsl.com (Postfix) with ESMTP id 0BF253A7194; Thu, 30 Apr 2009 13:06:47 -0700 (PDT) Received: from [172.16.3.231] (vicuna-alt.estacado.net [75.53.54.121]) (authenticated bits=0) by nostrum.com (8.14.3/8.14.3) with ESMTP id n3UK86pw038397 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Thu, 30 Apr 2009 15:08:06 -0500 (CDT) (envelope-from adam@nostrum.com) Message-ID: <49FA0526.4010000@nostrum.com> Date: Thu, 30 Apr 2009 15:08:06 -0500 From: Adam Roach User-Agent: Postbox 1.0b11 (Macintosh/2009041623) MIME-Version: 1.0 To: "Vijay K. Gurbani" Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit Received-SPF: pass (nostrum.com: 75.53.54.121 is authenticated by a trusted mechanism) Cc: "sip-ops@ietf.org" , "dispatch@ietf.org" , Hadriel Kaplan Subject: [sip-ops] [dispatch] SIP-CLF: Extensibility considerations (was Results on ASCII vs. binary representation) X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 30 Apr 2009 20:07:09 -0000 Vijay K. Gurbani wrote: > Hadriel Kaplan wrote: >> But anyway, I think the real question that needs to be answered >> *first* is "what is the purpose of the CLF?" What is it going to >> help admins do? Is it for troubleshooting, or for registration audit >> logging, or for IDS systems, etc? > > From the list above, at least for troubleshooting, logging, and > IDS systems. What I do not envision CLF being used for is > debugging (distinct from troubleshooting) and CDR. Even knowing the list of purposes, if we go with a text format similar to what is proposed, we are going to be forced to nail down the complete set of log record fields now, with little hope for backwards-compatible extensibility in the future. Admittedly, we *could* go to a tagged text format (e.g. where the fields are explicitly labeled instead of being inferred by position) to address this shortcoming, but that's not what's being proposed at the moment. So, if we go down the path proposed in draft-gurbani-..., we're strapped with coming up with the perfect set of future-proof fields that encompasses everything anyone will ever need in the log file, while (at the same time) not including extraneous information that people don't want to bother generating and/or parsing. The binary format I've proposed allows for exclusion of information the logging node doesn't consider relevant, as well as inclusion of information that we don't define at this time. For me, that's almost as big a win as the efficiency in searching a file for records of interest. /a From simon.perreault@viagenie.ca Thu Apr 30 13:53:14 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 2C20F3A6F8E; Thu, 30 Apr 2009 13:53:14 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.255 X-Spam-Level: X-Spam-Status: No, score=-2.255 tagged_above=-999 required=5 tests=[AWL=0.345, BAYES_00=-2.599, NO_RELAYS=-0.001] 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 b0zbChykjIhP; Thu, 30 Apr 2009 13:53:13 -0700 (PDT) Received: from jazz.viagenie.ca (jazz.viagenie.ca [IPv6:2620:0:230:8000::2]) by core3.amsl.com (Postfix) with ESMTP id 0E3AC3A6C6F; Thu, 30 Apr 2009 13:53:13 -0700 (PDT) Received: by jazz.viagenie.ca (Postfix, from userid 8) id C9EEF14A000B; Thu, 30 Apr 2009 16:54:35 -0400 (EDT) Received: from ringo.viagenie.ca (ringo.viagenie.ca [IPv6:2620:0:230:c000::67]) by jazz.viagenie.ca (Postfix) with ESMTP id BCEB814A0001; Thu, 30 Apr 2009 16:54:35 -0400 (EDT) Message-ID: <49FA100B.2050105@viagenie.ca> Date: Thu, 30 Apr 2009 16:54:35 -0400 From: Simon Perreault User-Agent: Thunderbird 2.0.0.21 (X11/20090320) MIME-Version: 1.0 To: "Vijay K. Gurbani" References: <49F864E8.20005@alcatel-lucent.com> In-Reply-To: <49F864E8.20005@alcatel-lucent.com> X-Enigmail-Version: 0.95.6 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Cc: sip-ops@ietf.org, dispatch@ietf.org Subject: Re: [sip-ops] [dispatch] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 30 Apr 2009 20:53:14 -0000 Vijay K. Gurbani wrote, on 29/04/09 10:32 AM: > Time taken to seek to the last record of the CLF file: > Binary CLF: 3.08s > ASCII CLF: 16.55s (using perl v5.6.1) > 42.92s (using perl v.5.8 and v5.10) On my system I have Perl 5.10.0. Initially: 26.33s By eliminating the regexp loop: 16.66s (1.58x faster) while () { chomp; @fields = /[^" ]+|".*?"/g; ... And I'm surprised nobody mentioned already that C would be MUCH faster than Perl. I think that speed is not an issue in text vs binary. Simon -- STUN/TURN server --> http://numb.viagenie.ca Interplanetary news --> http://reeves.viagenie.ca vCard 4.0 --> http://www.vcarddav.org From vkg@alcatel-lucent.com Thu Apr 30 14:11:40 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 336FC3A6870; Thu, 30 Apr 2009 14:11:40 -0700 (PDT) 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 s+bcEAFdDNZV; Thu, 30 Apr 2009 14:11:39 -0700 (PDT) Received: from ihemail4.lucent.com (ihemail4.lucent.com [135.245.0.39]) by core3.amsl.com (Postfix) with ESMTP id F3AD13A6D53; Thu, 30 Apr 2009 14:10:53 -0700 (PDT) Received: from umail.lucent.com (h135-3-40-61.lucent.com [135.3.40.61]) by ihemail4.lucent.com (8.13.8/IER-o) with ESMTP id n3ULCEBB015556 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Thu, 30 Apr 2009 16:12:14 -0500 (CDT) Received: from [135.185.236.17] (il0015vkg1.ih.lucent.com [135.185.236.17]) by umail.lucent.com (8.13.8/TPES) with ESMTP id n3ULCER0028172; Thu, 30 Apr 2009 16:12:14 -0500 (CDT) Message-ID: <49FA142E.7060607@alcatel-lucent.com> Date: Thu, 30 Apr 2009 16:12:14 -0500 From: "Vijay K. Gurbani" Organization: Bell Labs Security Technology Research Group User-Agent: Thunderbird 2.0.0.6 (Windows/20070728) MIME-Version: 1.0 To: Adam Roach References: <49FA0526.4010000@nostrum.com> In-Reply-To: <49FA0526.4010000@nostrum.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Scanned-By: MIMEDefang 2.57 on 135.245.2.39 Cc: "sip-ops@ietf.org" , "dispatch@ietf.org" Subject: Re: [sip-ops] [dispatch] SIP-CLF: Extensibility considerations (was Results on ASCII vs. binary representation) X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 30 Apr 2009 21:11:40 -0000 Adam Roach wrote: > Even knowing the list of purposes, if we go with a text format > similar to what is proposed, we are going to be forced to nail down > the complete set of log record fields now, with little hope for > backwards-compatible extensibility in the future. Admittedly, we > *could* go to a tagged text format (e.g. where the fields are > explicitly labeled instead of being inferred by position) to address > this shortcoming, but that's not what's being proposed at the moment. The tagged format will add further latency to an ASCII format, so I did not include it. In the best case, I am looking for an ASCII format that is amenable to taking a line and using a regexp to break it down to its constituent fields. > So, if we go down the path proposed in draft-gurbani-..., we're > strapped with coming up with the perfect set of future-proof fields > that encompasses everything anyone will ever need in the log file, > while (at the same time) not including extraneous information that > people don't want to bother generating and/or parsing. I don't think we are constrained to a perfect set of future-proof fields. Rather, I think that there should be a list of fields that are mandatory -- and these fields should be the ones that allow for dialog and transaction identification and correlating the various forked branches to a parent transaction, etc. Regarding people don't wanting to get bothered by generating and/or parsing extra fields, even in the currently defined ASCII format, there is a delimiter after which the rest of the fields are optional. An off-the-shelf open source CLF parser can parse all the mandatory ones and can just disregard the optional ones; no harm done. Of course, since it will be written most probably in an interpreted language of some sort (and I am thinking of perl/python here), it could be extended to more easily to parse these fields. Remember that we are not the consumers of the log file, rather it is the people who will be feeding SIP servers. And given that constituency, I think they'd rather prefer to write tools that operate on ASCII. > The binary format I've proposed allows for exclusion of information > the logging node doesn't consider relevant, as well as inclusion of > information that we don't define at this time. For me, that's almost > as big a win as the efficiency in searching a file for records of > interest. Given the updated results and all, I will stop arguing on the grounds of efficiency. Reading binary CLF was always more efficient, and so is producing the binary CLF. But if the only CLF format we define is a binary CLF, then I want to be clear that we understand that we are making a tacit decision to force all implementations to deal with digesting their SIP message in this new format for logging purpose. There will be some SIP servers that already digest the incoming SIP message and turn it into binary (complete with a ToC) for efficient memory copying, etc. To these servers, producing a binary CLF will be a low impact activity. But, there are and will be SIP servers that do not carry an internal binary representation of the SIP message. We will, in essence, force these servers to do so just to produce binary CLF. And that is a big tradeoff. A binary CLF can always be produced from an ASCII one using offline transformations. It is just that producing an ASCII CLF is low-impact since the messages that enter and exit a SIP server are ASCII to begin with. Before going down the path of mandating a binary-only option, I would at the very least like us to understand the tradeoffs of the decision and keep in mind who the ultimate consumers of the log file are. Thanks, - vijay -- Vijay K. Gurbani, Bell Laboratories, Alcatel-Lucent 1960 Lucent Lane, Rm. 9C-533, Naperville, Illinois 60566 (USA) Email: vkg@{alcatel-lucent.com,bell-labs.com,acm.org} Web: http://ect.bell-labs.com/who/vkg/ From vkg@alcatel-lucent.com Thu Apr 30 14:18:04 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id B9DE93A6CA5; Thu, 30 Apr 2009 14:18:04 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.525 X-Spam-Level: X-Spam-Status: No, score=-2.525 tagged_above=-999 required=5 tests=[AWL=0.074, 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 DbytN7i5NO7I; Thu, 30 Apr 2009 14:18:03 -0700 (PDT) Received: from ihemail1.lucent.com (ihemail1.lucent.com [135.245.0.33]) by core3.amsl.com (Postfix) with ESMTP id C2F063A6C7D; Thu, 30 Apr 2009 14:18:02 -0700 (PDT) Received: from umail.lucent.com (h135-3-40-61.lucent.com [135.3.40.61]) by ihemail1.lucent.com (8.13.8/IER-o) with ESMTP id n3ULJONX012249 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Thu, 30 Apr 2009 16:19:24 -0500 (CDT) Received: from [135.185.236.17] (il0015vkg1.ih.lucent.com [135.185.236.17]) by umail.lucent.com (8.13.8/TPES) with ESMTP id n3ULJNWr004146; Thu, 30 Apr 2009 16:19:23 -0500 (CDT) Message-ID: <49FA15DB.2070108@alcatel-lucent.com> Date: Thu, 30 Apr 2009 16:19:23 -0500 From: "Vijay K. Gurbani" Organization: Bell Labs Security Technology Research Group User-Agent: Thunderbird 2.0.0.6 (Windows/20070728) MIME-Version: 1.0 To: Simon Perreault References: <49F864E8.20005@alcatel-lucent.com> <49FA100B.2050105@viagenie.ca> In-Reply-To: <49FA100B.2050105@viagenie.ca> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Scanned-By: MIMEDefang 2.57 on 135.245.2.33 Cc: sip-ops@ietf.org, dispatch@ietf.org Subject: Re: [sip-ops] [dispatch] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 30 Apr 2009 21:18:04 -0000 Simon Perreault wrote: > And I'm surprised nobody mentioned already that C would be MUCH > faster than Perl. Simon: Yes, that is always true. However, I think we should keep in mind who the ultimate consumer of the log file will be. And a big constituency is enterprises, academia, small businesses, etc. Most of the people who feed the IT-type infrastructure in such places are far more comfortable with perl and python than C/C++. Thanks, - vijay -- Vijay K. Gurbani, Bell Laboratories, Alcatel-Lucent 1960 Lucent Lane, Rm. 9C-533, Naperville, Illinois 60566 (USA) Email: vkg@{alcatel-lucent.com,bell-labs.com,acm.org} Web: http://ect.bell-labs.com/who/vkg/ From adam@nostrum.com Thu Apr 30 14:44:43 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id F09493A6B8A; Thu, 30 Apr 2009 14:44:43 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.274 X-Spam-Level: X-Spam-Status: No, score=-2.274 tagged_above=-999 required=5 tests=[AWL=-0.274, BAYES_00=-2.599, J_CHICKENPOX_47=0.6, SPF_PASS=-0.001] 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 8w+V68Ry1mpB; Thu, 30 Apr 2009 14:44:43 -0700 (PDT) Received: from nostrum.com (nostrum-pt.tunnel.tserv2.fmt.ipv6.he.net [IPv6:2001:470:1f03:267::2]) by core3.amsl.com (Postfix) with ESMTP id D03FC3A6A4E; Thu, 30 Apr 2009 14:44:42 -0700 (PDT) Received: from [172.16.3.231] (vicuna-alt.estacado.net [75.53.54.121]) (authenticated bits=0) by nostrum.com (8.14.3/8.14.3) with ESMTP id n3ULk09e045505 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Thu, 30 Apr 2009 16:46:00 -0500 (CDT) (envelope-from adam@nostrum.com) Message-ID: <49FA1C18.5020702@nostrum.com> Date: Thu, 30 Apr 2009 16:46:00 -0500 From: Adam Roach User-Agent: Postbox 1.0b11 (Macintosh/2009041623) MIME-Version: 1.0 To: Simon Perreault References: <49F864E8.20005@alcatel-lucent.com> <49FA100B.2050105@viagenie.ca> In-Reply-To: <49FA100B.2050105@viagenie.ca> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit Received-SPF: pass (nostrum.com: 75.53.54.121 is authenticated by a trusted mechanism) Cc: sip-ops@ietf.org, dispatch@ietf.org Subject: Re: [sip-ops] [dispatch] SIP-CLF: Results on ASCII vs. binary representation X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 30 Apr 2009 21:44:44 -0000 Simon Perreault wrote: > And I'm surprised nobody mentioned already that C would be MUCH faster than Perl. > > I think that speed is not an issue in text vs binary. Okay, so maybe it's not really fair to do the binary decoder in C and the text decoder in perl. Let's do an apples-to-apples comparison. As we've already established, Vijay's C program (with my optimizations) takes 6.17 seconds to find the Call-ID in a binary file on my system. His perl script takes 20.154 seconds on my system (with your optimizations, plus a 'o' flag on the regex to avoid repeated recompilations) to find it in a text log file. This will grow in complexity (and, presumably, time) once we add an escaping mechanism to the log format, but I'm happy to ignore that for now. The perl script below takes 2.359 seconds on my system to find the Call-ID of interest. That's... ummm... better than twice as fast as the C program, and approaching 10 times faster than the perl script for the text format. So, for some reason, I *do* think speed is an issue in this particular discussion. #!/usr/bin/perl $LOGFILE = "sip-clf.bin"; open(LOGFILE) or die("Could not open log file."); $search = shift || die "Usage: $0 [call-id]\n"; while (read(LOGFILE, $buffer, 4)>0) { $rec_len = unpack('N',$buffer) & 0x7FFF; read(LOGFILE,$buffer,$rec_len-4) || die $!; ($cid_ptr,$cid_len) = unpack ('x48n2',$buffer); $cid = substr($buffer, $cid_ptr-4, $cid_len); if ($cid eq $search) { print "Call-ID: $cid *** FOUND!!\n"; exit; } } (For what it's worth, I'm using perl 5.8.8) /a From theo@crazygreek.co.uk Thu Apr 30 15:03:00 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 1EA6A28C191; Thu, 30 Apr 2009 15:03:00 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -5.859 X-Spam-Level: X-Spam-Status: No, score=-5.859 tagged_above=-999 required=5 tests=[AWL=0.118, BAYES_00=-2.599, FM_FORGED_GMAIL=0.622, RCVD_IN_DNSWL_MED=-4] 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 aUo-CptLO1px; Thu, 30 Apr 2009 15:02:59 -0700 (PDT) Received: from chip3og50.obsmtp.com (chip3og50.obsmtp.com [64.18.14.165]) by core3.amsl.com (Postfix) with SMTP id D074628C1BC; Thu, 30 Apr 2009 15:02:00 -0700 (PDT) Received: from source ([209.85.220.158]) by chip3ob50.postini.com ([64.18.6.12]) with SMTP ID DSNKSfogK0xQjvo0U3X9mEbvaFSg6pajU4YQ@postini.com; Thu, 30 Apr 2009 15:03:24 PDT Received: by fxm2 with SMTP id 2so2081359fxm.37 for ; Thu, 30 Apr 2009 15:03:23 -0700 (PDT) MIME-Version: 1.0 Received: by 10.86.91.3 with SMTP id o3mr2309290fgb.46.1241129003190; Thu, 30 Apr 2009 15:03:23 -0700 (PDT) In-Reply-To: <49FA142E.7060607@alcatel-lucent.com> References: <49FA0526.4010000@nostrum.com> <49FA142E.7060607@alcatel-lucent.com> From: Theo Zourzouvillys Date: Thu, 30 Apr 2009 23:03:03 +0100 Message-ID: <167dfb9b0904301503w737e1fednc6a5213c54b02a9a@mail.gmail.com> To: "Vijay K. Gurbani" Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Cc: "sip-ops@ietf.org" , "dispatch@ietf.org" Subject: Re: [sip-ops] [dispatch] SIP-CLF: Extensibility considerations (was Results on ASCII vs. binary representation) X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 30 Apr 2009 22:03:00 -0000 On Thu, Apr 30, 2009 at 10:12 PM, Vijay K. Gurbani wrote: > A binary CLF can always be produced from an ASCII one using > offline transformations. indeed, and a binary one can be just as easily converted to an ASCII one - quicker in that direction, too :-) > It is just that producing an ASCII > CLF is low-impact since the messages that enter and exit > a SIP server are ASCII to begin with. this statement makes no sense at all in the context of this dicussion. it's not like there is a 1:1 mapping between the memory chunk received over a network card and the log line. Be it ASCII or binary, it needs to generate the record. Both are as simple as each other, whatever the scenario. ~ Theo -- http://twitter.com/zourzouvillys http://crazygreek.co.uk/ Sent from Bicester, Oxfordshire, United Kingdom From adam@nostrum.com Thu Apr 30 15:17:38 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id 2D46B3A6B29; Thu, 30 Apr 2009 15:17:38 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.567 X-Spam-Level: X-Spam-Status: No, score=-2.567 tagged_above=-999 required=5 tests=[AWL=0.033, BAYES_00=-2.599, SPF_PASS=-0.001] 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 NCAH0DlewUY5; Thu, 30 Apr 2009 15:17:37 -0700 (PDT) Received: from nostrum.com (nostrum-pt.tunnel.tserv2.fmt.ipv6.he.net [IPv6:2001:470:1f03:267::2]) by core3.amsl.com (Postfix) with ESMTP id BFB103A6853; Thu, 30 Apr 2009 15:17:36 -0700 (PDT) Received: from [172.16.3.231] (vicuna-alt.estacado.net [75.53.54.121]) (authenticated bits=0) by nostrum.com (8.14.3/8.14.3) with ESMTP id n3UMIrXS047815 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Thu, 30 Apr 2009 17:18:55 -0500 (CDT) (envelope-from adam@nostrum.com) Message-ID: <49FA23CD.9060000@nostrum.com> Date: Thu, 30 Apr 2009 17:18:53 -0500 From: Adam Roach User-Agent: Postbox 1.0b11 (Macintosh/2009041623) MIME-Version: 1.0 To: "Vijay K. Gurbani" References: <49FA0526.4010000@nostrum.com> <49FA142E.7060607@alcatel-lucent.com> In-Reply-To: <49FA142E.7060607@alcatel-lucent.com> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit Received-SPF: pass (nostrum.com: 75.53.54.121 is authenticated by a trusted mechanism) Cc: "sip-ops@ietf.org" , "dispatch@ietf.org" Subject: Re: [sip-ops] [dispatch] SIP-CLF: Extensibility considerations (was Results on ASCII vs. binary representation) X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 30 Apr 2009 22:17:38 -0000 Vijay K. Gurbani wrote: > Adam Roach wrote: >> Even knowing the list of purposes, if we go with a text format >> similar to what is proposed, we are going to be forced to nail down >> the complete set of log record fields now, with little hope for >> backwards-compatible extensibility in the future. Admittedly, we >> *could* go to a tagged text format (e.g. where the fields are >> explicitly labeled instead of being inferred by position) to address >> this shortcoming, but that's not what's being proposed at the moment. > > The tagged format will add further latency to an ASCII format, > so I did not include it. In the best case, I am looking for an > ASCII format that is amenable to taking a line and using a > regexp to break it down to its constituent fields. That's going to be pretty difficult with character escaping. You'll need powerful regex ninja skills to deal with the text format once you figure out how to handle things like spaces embedded within fields. > Remember that we are not the consumers of the log file, rather > it is the people who will be feeding SIP servers. And given > that constituency, I think they'd rather prefer to write tools > that operate on ASCII. I don't think the constituent consumers will be particularly upset by the difference between: grep 'iaMb87@evil.example.com' sip-clf.log and clfdump sip-clf.log | grep 'iaMb87@evil.example.com' > Given the updated results and all, I will stop arguing on the > grounds of efficiency. Reading binary CLF was always more > efficient, and so is producing the binary CLF. ... > But, there are and will be > SIP servers that do not carry an internal binary representation > of the SIP message. We will, in essence, force these servers > to do so just to produce binary CLF. And that is a big tradeoff. That's pure nonsense. You first acknowledge that the proposed binary format is faster to read and faster to write... and then make an argument that seems to be predicated on the opposite of that fact. The servers will need to separate the components of interest out for both the format described in your document and the format described in mine. The binary format doesn't take any ASCII fields and turn them into a binary representation (with the exception of CSeq, but a single string-to-integer transformation -- one that almost every implementation needs to perform anyway -- certainly can't be what you're objecting to). The only real processing difference is how field and record delimitation is handled -- and we already know that the speed differences between them are negligible. > A binary CLF can always be produced from an ASCII one using > offline transformations. And vice-versa -- at least, modulo the extensible tagging mechanisms inherent in the binary format. > It is just that producing an ASCII > CLF is low-impact since the messages that enter and exit > a SIP server are ASCII to begin with. Unless you're dumping literal SIP messages (which is not what you're proposing), you're still having to parse out the fields and rearrange them. This is true for BOTH formats. The impact is not significantly higher for one versus the other, and you've acknowledged that empirical data confirms this fact. > Before going down the path of mandating a binary-only option, > I would at the very least like us to understand the tradeoffs > of the decision and keep in mind who the ultimate consumers > of the log file are. While I'm sure some of the ops guys will appreciate the fact that they get to take a 20-minute coffee and/or smoking break every time they launch a query against a 60-million-record log, there's probably a larger percentage of them who would like to be able to do their jobs efficiently. At least, that's what I suspect. /a From adam@nostrum.com Thu Apr 30 16:33:33 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id E755B3A698A; Thu, 30 Apr 2009 16:33:33 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -2.268 X-Spam-Level: X-Spam-Status: No, score=-2.268 tagged_above=-999 required=5 tests=[AWL=-0.268, BAYES_00=-2.599, J_CHICKENPOX_47=0.6, SPF_PASS=-0.001] 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 dNbONJHtkNUy; Thu, 30 Apr 2009 16:33:33 -0700 (PDT) Received: from nostrum.com (nostrum-pt.tunnel.tserv2.fmt.ipv6.he.net [IPv6:2001:470:1f03:267::2]) by core3.amsl.com (Postfix) with ESMTP id BE2CB28C151; Thu, 30 Apr 2009 16:33:32 -0700 (PDT) Received: from [172.16.3.231] (vicuna-alt.estacado.net [75.53.54.121]) (authenticated bits=0) by nostrum.com (8.14.3/8.14.3) with ESMTP id n3UNYnVm052961 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Thu, 30 Apr 2009 18:34:49 -0500 (CDT) (envelope-from adam@nostrum.com) Message-ID: <49FA3599.7050709@nostrum.com> Date: Thu, 30 Apr 2009 18:34:49 -0500 From: Adam Roach User-Agent: Postbox 1.0b11 (Macintosh/2009041623) MIME-Version: 1.0 To: Theo Zourzouvillys References: <49FA0526.4010000@nostrum.com> <49FA142E.7060607@alcatel-lucent.com> <167dfb9b0904301503w737e1fednc6a5213c54b02a9a@mail.gmail.com> In-Reply-To: <167dfb9b0904301503w737e1fednc6a5213c54b02a9a@mail.gmail.com> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit Received-SPF: pass (nostrum.com: 75.53.54.121 is authenticated by a trusted mechanism) Cc: "sip-ops@ietf.org" , "dispatch@ietf.org" Subject: Re: [sip-ops] [dispatch] SIP-CLF: Extensibility considerations (was Results on ASCII vs. binary representation) X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 30 Apr 2009 23:33:34 -0000 Theo Zourzouvillys wrote: > On Thu, Apr 30, 2009 at 10:12 PM, Vijay K. Gurbani > wrote: > > >> A binary CLF can always be produced from an ASCII one using >> offline transformations. > > indeed, and a binary one can be just as easily converted to an ASCII > one - quicker in that direction, too :-) In fact, I'll help you out here. /a ------------------------------------------------------------------------ #!/usr/bin/perl $bin = shift; open(LOGFILE, $bin) or die("Could not open log file $bin."); while (read(LOGFILE, $buffer, 4) == 4) { $tmp = unpack('N',$buffer) ; $rec_len = $tmp & 0x7FFF; $flags = $tmp >> 24; read(LOGFILE,$buffer,$rec_len-4) || die $!; ($date_hi, $date_lo, $time_ns, $cseq, $resp_code, $tlv_ptr, @toc) = unpack ('N4n18',$buffer); $tlv = substr($buffer, $tlv_ptr-4); if ($flags & &RESPONSE_FLAG) { #%d %x %y %s %m %t "%c" printf ("%s %s %s %03.3d %s %s;tag=%s \"%s\"\n", ($date_hi<<32|$date_lo), &get_field(&SERVER_TXN_FIELD,$buffer,@toc), &get_field(&CLIENT_TXN_FIELD,$buffer,@toc), $resp_code, &get_field(&METHOD_FIELD,$buffer,@toc), &get_field(&TO_FIELD,$buffer,@toc), &get_field(&TO_TAG_FIELD,$buffer,@toc), &get_tlv(&CONTACT_TAG,$tlv)); } else { #%d %h %u %m %r %f %t %i "%c" %x %y printf ("%s %s %s %s %s %s;tag=%s %s;tag=%s %s \"%s\" %s %s\n", ($date_hi<<32|$date_lo), &get_tlv(&REMOTE_HOST_TAG,$tlv), &get_tlv(&AUTH_USER_TAG,$tlv), &get_field(&METHOD_FIELD,$buffer,@toc), &get_tlv(&REQUEST_URI_TAG,$tlv), &get_field(&FROM_FIELD,$buffer,@toc), &get_field(&FROM_TAG_FIELD,$buffer,@toc), &get_field(&TO_FIELD,$buffer,@toc), &get_field(&TO_TAG_FIELD,$buffer,@toc), &get_field(&CID_FIELD,$buffer,@toc), &get_tlv(&CONTACT_TAG,$tlv), &get_field(&SERVER_TXN_FIELD,$buffer,@toc), &get_field(&CLIENT_TXN_FIELD,$buffer,@toc)); } } sub RESPONSE_FLAG {0x80} sub RETRANSMISSION_FLAG {0x40} sub SENT_FLAG {0x20} sub CONTACT_TAG {0} sub REQUEST_URI_TAG {1} sub REMOTE_HOST_TAG {2} sub AUTH_USER_TAG {3} sub WHOLE_MESSAGE_TAG {4} sub SERVER_TXN_FIELD {0} sub CLIENT_TXN_FIELD {1} sub METHOD_FIELD {2} sub TO_FIELD {3} sub TO_TAG_FIELD {4} sub FROM_FIELD {5} sub FROM_TAG_FIELD {6} sub CID_FIELD {7} sub get_field { my ($field, $buffer, @toc) = @_; my ($pointer, $length) = ($toc[$field*2],$toc[$field*2+1]); my $result = substr($buffer, $pointer-4, $length); if ($result) { return $result; } return '-'; } sub get_tlv { my ($search_tag, $tlv) = @_; my (@result, $tag, $len, $value); my $offset = 0; while ($offset < length($tlv)) { ($tag, $len) = unpack ('n2',substr($tlv,$offset)); $value = substr($tlv, $offset + 4, $len); if ($tag == $search_tag) { push @result, $value } $offset += $len + 4; } if (@result) { return join ',',@result }; return "-"; } From scott.lawrence@nortel.com Thu Apr 30 17:49:21 2009 Return-Path: X-Original-To: sip-ops@core3.amsl.com Delivered-To: sip-ops@core3.amsl.com Received: from localhost (localhost [127.0.0.1]) by core3.amsl.com (Postfix) with ESMTP id E59D93A6ACA; Thu, 30 Apr 2009 17:49:21 -0700 (PDT) X-Virus-Scanned: amavisd-new at amsl.com X-Spam-Flag: NO X-Spam-Score: -5.604 X-Spam-Level: X-Spam-Status: No, score=-5.604 tagged_above=-999 required=5 tests=[AWL=0.995, BAYES_00=-2.599, RCVD_IN_DNSWL_MED=-4] 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 0N3dDXcPoFKe; Thu, 30 Apr 2009 17:49:21 -0700 (PDT) Received: from zrtps0kp.nortel.com (zrtps0kp.nortel.com [47.140.192.56]) by core3.amsl.com (Postfix) with ESMTP id D46963A67E6; Thu, 30 Apr 2009 17:49:20 -0700 (PDT) Received: from zrtphxs1.corp.nortel.com (zrtphxs1.corp.nortel.com [47.140.202.46]) by zrtps0kp.nortel.com (Switch-2.2.6/Switch-2.2.0) with ESMTP id n410o9d26819; Fri, 1 May 2009 00:50:10 GMT Received: from [127.0.0.1] ([47.17.25.99]) by zrtphxs1.corp.nortel.com with Microsoft SMTPSVC(6.0.3790.3959); Thu, 30 Apr 2009 20:49:54 -0400 From: "Scott Lawrence" To: Adam Roach In-Reply-To: <49FA23CD.9060000@nostrum.com> References: <49FA0526.4010000@nostrum.com> <49FA142E.7060607@alcatel-lucent.com> <49FA23CD.9060000@nostrum.com> Content-Type: text/plain Organization: Nortel Networks Date: Thu, 30 Apr 2009 20:49:53 -0400 Message-Id: <1241138993.3402.23.camel@scott> Mime-Version: 1.0 X-Mailer: Evolution 2.24.5 (2.24.5-1.fc10) Content-Transfer-Encoding: 7bit X-OriginalArrivalTime: 01 May 2009 00:49:54.0919 (UTC) FILETIME=[BE559F70:01C9C9F6] Cc: "sip-ops@ietf.org" , "dispatch@ietf.org" Subject: Re: [sip-ops] [dispatch] SIP-CLF: Extensibility considerations (was Results on ASCII vs. binary representation) X-BeenThere: sip-ops@ietf.org X-Mailman-Version: 2.1.9 Precedence: list List-Id: SIP Operations List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 01 May 2009 00:49:22 -0000 > Vijay K. Gurbani wrote: > > The tagged format will add further latency to an ASCII format, > > so I did not include it. In the best case, I am looking for an > > ASCII format that is amenable to taking a line and using a > > regexp to break it down to its constituent fields. Adam Roach wrote: > That's going to be pretty difficult with character escaping. You'll need > powerful regex ninja skills to deal with the text format once you figure > out how to handle things like spaces embedded within fields. Not to mention escaped double quotes. Having done a regex-based parser for just name-addr, I'd say don't go there.