From mboxrd@z Thu Jan 1 00:00:00 1970 From: Sai Prakash Ranjan Subject: Re: [PATCH 2/6] pstore: Add event tracing support Date: Wed, 26 Sep 2018 15:22:59 +0530 Message-ID: <67f42dd8-31e3-99fa-06b7-bd9f860ccef8@codeaurora.org> References: Mime-Version: 1.0 Content-Type: text/plain; charset=utf-8; format=flowed Content-Transfer-Encoding: 7bit Return-path: In-Reply-To: Content-Language: en-US Sender: linux-kernel-owner@vger.kernel.org To: Joel Fernandes Cc: Tom Zanussi , Catalin Marinas , Will Deacon , Vivek Gautam , Joel Fernandes , Prasad Sodagudi , Ingo Molnar , tsoni@codeaurora.org, Anton Vorontsov , Ingo Molnar , Sibi Sankar , Laura Abbott , kernel-team , devicetree@vger.kernel.org, Kees Cook , Arnd Bergmann , linux-arm-msm@vger.kernel.org, Steven Rostedt , Jason Baron , Rob Herring , Tingwei Zhang List-Id: linux-arm-msm@vger.kernel.org On 9/26/2018 2:10 AM, Joel Fernandes wrote: > On Tue, Sep 25, 2018 at 1:39 PM, Joel Fernandes wrote: >> On Tue, Sep 25, 2018 at 1:37 PM, Joel Fernandes wrote: >>> On Sun, Sep 23, 2018 at 8:33 AM, Sai Prakash Ranjan >>> wrote: >>>> On 9/22/2018 10:07 PM, Sai Prakash Ranjan wrote: >>>>> >>>>> On 9/22/2018 2:35 PM, Joel Fernandes wrote: >>>>>> >>>>>> On Sat, Sep 8, 2018 at 4:28 PM Sai Prakash Ranjan >>>>>> wrote: >>>>>>> >>>>>>> >>>>>>> + >>>>>>> + trace_seq_init(&iter->seq); >>>>>>> + iter->ent = fbuffer->entry; >>>>>>> + event_call->event.funcs->trace(iter, 0, event); >>>>>>> + trace_seq_putc(&iter->seq, 0); >>>>>> >>>>>> >>>>>> Would it be possible to store the binary trace record in the pstore >>>>>> buffer instead of outputting text? I suspect that will both be faster >>>>>> and less space. >>>>>> >>>>> >>>>> I will try this and come back. >>>>> >>>> >>>> Hi Joel, >>>> >>>> I removed trace_seq_putc and there is some improvement seen: 203 MB/s >>>> >>>> # dd if=/dev/zero of=/dev/null status=progress >>>> 12207371264 bytes (12 GB, 11 GiB) copied, 60 s, 203 MB/s^C >>>> 24171926+0 records in >>>> 24171926+0 records out >>>> 12376026112 bytes (12 GB, 12 GiB) copied, 60.8282 s, 203 MB/s >>>> >>>> This seems good when compared to 190 MB/s seen previously. >>>> If this is Ok, then I will spin v2 with changes suggested. >>> >>> Sorry for slow reply, yes that sounds good and a worthwhile perf improvement. >>> >> >> Well so I think you should still not use spinlock to synchronize and >> split the buffer. You could expand pstore_record to have a ts field or >> introduce a new API like ->write_percpu instead of write, or >> something. But I strongly feel you should lock. For ftrace function > > Aargh, I meant you should *not* lock :-) > OK I can try this and will measure some perf difference. BTW I guess you missed my previous comment about not able to combine logs based on timestamp? Anyways I think if I add some extra ts field, then should be able to do it. Thanks, Sai -- QUALCOMM INDIA, on behalf of Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum, hosted by The Linux Foundation From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-0.6 required=3.0 tests=DKIM_INVALID,DKIM_SIGNED, HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,SPF_PASS,URIBL_BLOCKED autolearn=ham autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id EB368C43382 for ; Wed, 26 Sep 2018 09:53:17 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id 7C155214D5 for ; Wed, 26 Sep 2018 09:53:17 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=fail reason="key not found in DNS" (0-bit key) header.d=codeaurora.org header.i=@codeaurora.org header.b="BDoaKVwh"; dkim=fail reason="key not found in DNS" (0-bit key) header.d=codeaurora.org header.i=@codeaurora.org header.b="FtmkEAcR" DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 7C155214D5 Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=codeaurora.org Authentication-Results: mail.kernel.org; spf=none smtp.mailfrom=linux-kernel-owner@vger.kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1727395AbeIZQFZ (ORCPT ); Wed, 26 Sep 2018 12:05:25 -0400 Received: from smtp.codeaurora.org ([198.145.29.96]:56614 "EHLO smtp.codeaurora.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1726841AbeIZQFY (ORCPT ); Wed, 26 Sep 2018 12:05:24 -0400 Received: by smtp.codeaurora.org (Postfix, from userid 1000) id 55F7060C1D; Wed, 26 Sep 2018 09:53:13 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=codeaurora.org; s=default; t=1537955594; bh=R4vZs7YOgqX9RkzDn+JCMtYGDm1XJoCxErJBrYPclkg=; h=Subject:To:Cc:References:From:Date:In-Reply-To:From; b=BDoaKVwhWKzL8+knzb3c3ws7w0850fuDSdJI+7isSipkkt+1kj6JXR38EWPfUlTWd fWzUMvG6a8kdVjhDyCxqoVqFB2qywXGpNLMx23fmuZr+ELyHfzuFsUjfsvAg3Zjh/X Yu6IIX3GSOjTKQLDSDeNpwW3Pqexz388eavVGPe4= Received: from [10.79.129.49] (blr-bdr-fw-01_globalnat_allzones-outside.qualcomm.com [103.229.18.19]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) (Authenticated sender: saiprakash.ranjan@smtp.codeaurora.org) by smtp.codeaurora.org (Postfix) with ESMTPSA id 31C1B6053C; Wed, 26 Sep 2018 09:53:01 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=codeaurora.org; s=default; t=1537955591; bh=R4vZs7YOgqX9RkzDn+JCMtYGDm1XJoCxErJBrYPclkg=; h=Subject:To:Cc:References:From:Date:In-Reply-To:From; b=FtmkEAcRvI2FHWmrZB3CKCRytojqWkUIXsorqbvDcNG2KYqj3ODMmJoBkn6jW3ZMA kEBfenQLiKHWiuDQ1Jg75PICcReYIZFAzPc3vNUhNC+DIBaKyQ1laVPA1IyrfFPaJ8 Ap5+fSuK5ximvCPYLp8xEGhyYRLUu3BIv3RmjtyI= DMARC-Filter: OpenDMARC Filter v1.3.2 smtp.codeaurora.org 31C1B6053C Authentication-Results: pdx-caf-mail.web.codeaurora.org; dmarc=none (p=none dis=none) header.from=codeaurora.org Authentication-Results: pdx-caf-mail.web.codeaurora.org; spf=none smtp.mailfrom=saiprakash.ranjan@codeaurora.org Subject: Re: [PATCH 2/6] pstore: Add event tracing support To: Joel Fernandes Cc: Tom Zanussi , Catalin Marinas , Will Deacon , Vivek Gautam , Joel Fernandes , Prasad Sodagudi , Ingo Molnar , tsoni@codeaurora.org, Anton Vorontsov , Ingo Molnar , Sibi Sankar , Laura Abbott , kernel-team , devicetree@vger.kernel.org, Kees Cook , Arnd Bergmann , linux-arm-msm@vger.kernel.org, Steven Rostedt , Jason Baron , Rob Herring , Tingwei Zhang , "moderated list:ARM64 PORT (AARCH64 ARCHITECTURE)" , Tony Luck , Rajendra Nayak , Jim Cromie , Greg Kroah-Hartman , LKML , Bryan Huntsman , Masami Hiramatsu , Colin Cross , Joe Perches References: From: Sai Prakash Ranjan Message-ID: <67f42dd8-31e3-99fa-06b7-bd9f860ccef8@codeaurora.org> Date: Wed, 26 Sep 2018 15:22:59 +0530 User-Agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:52.0) Gecko/20100101 Thunderbird/52.9.1 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset=utf-8; format=flowed Content-Language: en-US Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On 9/26/2018 2:10 AM, Joel Fernandes wrote: > On Tue, Sep 25, 2018 at 1:39 PM, Joel Fernandes wrote: >> On Tue, Sep 25, 2018 at 1:37 PM, Joel Fernandes wrote: >>> On Sun, Sep 23, 2018 at 8:33 AM, Sai Prakash Ranjan >>> wrote: >>>> On 9/22/2018 10:07 PM, Sai Prakash Ranjan wrote: >>>>> >>>>> On 9/22/2018 2:35 PM, Joel Fernandes wrote: >>>>>> >>>>>> On Sat, Sep 8, 2018 at 4:28 PM Sai Prakash Ranjan >>>>>> wrote: >>>>>>> >>>>>>> >>>>>>> + >>>>>>> + trace_seq_init(&iter->seq); >>>>>>> + iter->ent = fbuffer->entry; >>>>>>> + event_call->event.funcs->trace(iter, 0, event); >>>>>>> + trace_seq_putc(&iter->seq, 0); >>>>>> >>>>>> >>>>>> Would it be possible to store the binary trace record in the pstore >>>>>> buffer instead of outputting text? I suspect that will both be faster >>>>>> and less space. >>>>>> >>>>> >>>>> I will try this and come back. >>>>> >>>> >>>> Hi Joel, >>>> >>>> I removed trace_seq_putc and there is some improvement seen: 203 MB/s >>>> >>>> # dd if=/dev/zero of=/dev/null status=progress >>>> 12207371264 bytes (12 GB, 11 GiB) copied, 60 s, 203 MB/s^C >>>> 24171926+0 records in >>>> 24171926+0 records out >>>> 12376026112 bytes (12 GB, 12 GiB) copied, 60.8282 s, 203 MB/s >>>> >>>> This seems good when compared to 190 MB/s seen previously. >>>> If this is Ok, then I will spin v2 with changes suggested. >>> >>> Sorry for slow reply, yes that sounds good and a worthwhile perf improvement. >>> >> >> Well so I think you should still not use spinlock to synchronize and >> split the buffer. You could expand pstore_record to have a ts field or >> introduce a new API like ->write_percpu instead of write, or >> something. But I strongly feel you should lock. For ftrace function > > Aargh, I meant you should *not* lock :-) > OK I can try this and will measure some perf difference. BTW I guess you missed my previous comment about not able to combine logs based on timestamp? Anyways I think if I add some extra ts field, then should be able to do it. Thanks, Sai -- QUALCOMM INDIA, on behalf of Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum, hosted by The Linux Foundation From mboxrd@z Thu Jan 1 00:00:00 1970 From: saiprakash.ranjan@codeaurora.org (Sai Prakash Ranjan) Date: Wed, 26 Sep 2018 15:22:59 +0530 Subject: [PATCH 2/6] pstore: Add event tracing support In-Reply-To: References: Message-ID: <67f42dd8-31e3-99fa-06b7-bd9f860ccef8@codeaurora.org> To: linux-arm-kernel@lists.infradead.org List-Id: linux-arm-kernel.lists.infradead.org On 9/26/2018 2:10 AM, Joel Fernandes wrote: > On Tue, Sep 25, 2018 at 1:39 PM, Joel Fernandes wrote: >> On Tue, Sep 25, 2018 at 1:37 PM, Joel Fernandes wrote: >>> On Sun, Sep 23, 2018 at 8:33 AM, Sai Prakash Ranjan >>> wrote: >>>> On 9/22/2018 10:07 PM, Sai Prakash Ranjan wrote: >>>>> >>>>> On 9/22/2018 2:35 PM, Joel Fernandes wrote: >>>>>> >>>>>> On Sat, Sep 8, 2018 at 4:28 PM Sai Prakash Ranjan >>>>>> wrote: >>>>>>> >>>>>>> >>>>>>> + >>>>>>> + trace_seq_init(&iter->seq); >>>>>>> + iter->ent = fbuffer->entry; >>>>>>> + event_call->event.funcs->trace(iter, 0, event); >>>>>>> + trace_seq_putc(&iter->seq, 0); >>>>>> >>>>>> >>>>>> Would it be possible to store the binary trace record in the pstore >>>>>> buffer instead of outputting text? I suspect that will both be faster >>>>>> and less space. >>>>>> >>>>> >>>>> I will try this and come back. >>>>> >>>> >>>> Hi Joel, >>>> >>>> I removed trace_seq_putc and there is some improvement seen: 203 MB/s >>>> >>>> # dd if=/dev/zero of=/dev/null status=progress >>>> 12207371264 bytes (12 GB, 11 GiB) copied, 60 s, 203 MB/s^C >>>> 24171926+0 records in >>>> 24171926+0 records out >>>> 12376026112 bytes (12 GB, 12 GiB) copied, 60.8282 s, 203 MB/s >>>> >>>> This seems good when compared to 190 MB/s seen previously. >>>> If this is Ok, then I will spin v2 with changes suggested. >>> >>> Sorry for slow reply, yes that sounds good and a worthwhile perf improvement. >>> >> >> Well so I think you should still not use spinlock to synchronize and >> split the buffer. You could expand pstore_record to have a ts field or >> introduce a new API like ->write_percpu instead of write, or >> something. But I strongly feel you should lock. For ftrace function > > Aargh, I meant you should *not* lock :-) > OK I can try this and will measure some perf difference. BTW I guess you missed my previous comment about not able to combine logs based on timestamp? Anyways I think if I add some extra ts field, then should be able to do it. Thanks, Sai -- QUALCOMM INDIA, on behalf of Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum, hosted by The Linux Foundation