Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Message-ID: <2a31d520-454c-c837-ec17-12dbf879e6d3@intel.com>
Date:   Tue, 22 Feb 2022 11:27:28 +0100
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:91.0) Gecko/20100101
 Firefox/91.0 Thunderbird/91.6.1
Subject: Re: [PATCH v3 05/11] lib/ref_tracker: __ref_tracker_dir_print improve
 printing
Content-Language: en-US
To:     Eric Dumazet <edumazet@google.com>
CC:     LKML <linux-kernel@vger.kernel.org>,
        <intel-gfx@lists.freedesktop.org>,
        <dri-devel@lists.freedesktop.org>, netdev <netdev@vger.kernel.org>,
        "Jani Nikula" <jani.nikula@linux.intel.com>,
        Daniel Vetter <daniel@ffwll.ch>,
        Lucas De Marchi <lucas.demarchi@intel.com>,
        Chris Wilson <chris.p.wilson@intel.com>,
        Dmitry Vyukov <dvyukov@google.com>,
        "Jakub Kicinski" <kuba@kernel.org>
References: <20220221232542.1481315-1-andrzej.hajda@intel.com>
 <20220221232542.1481315-6-andrzej.hajda@intel.com>
 <CANn89iJxaPqTLY0BaD79Ubxx55RMtWzZk_jkpuF1cp3Wsy2RzA@mail.gmail.com>
From:   Andrzej Hajda <andrzej.hajda@intel.com>
Organization: Intel Technology Poland sp. z o.o. - ul. Slowackiego 173, 80-298
 Gdansk - KRS 101882 - NIP 957-07-52-316
In-Reply-To: <CANn89iJxaPqTLY0BaD79Ubxx55RMtWzZk_jkpuF1cp3Wsy2RzA@mail.gmail.com>
Content-Type: text/plain; charset="UTF-8"; format=flowed
Content-Transfer-Encoding: 7bit
MIME-Version: 1.0
X-MS-Exchange-AntiSpam-MessageData-ChunkCount: 1
X-MS-Exchange-AntiSpam-MessageData-0: =?utf-8?B?QmtDamY0b0lHaU5uM3g0YjVSU3VxWjFnMkp3NHNTa0xyNG9kKy9salppTTRR?=
 =?utf-8?B?WHRMVm1WMG1YQ1cxWFUreEhCZHRWamV0Qk05RzVPYndndzVLY0pJTDJaZU9I?=
 =?utf-8?B?U1ViYjVKTUZtdXBPeGVCdnBQeWtVU1V1TFgyam9tY2kxL0tCL2pJaHA1Q1Zn?=
 =?utf-8?B?aFBONFhCVW5MNWNqejJjL3l0ZW9mWjV2ZjhGcVJoZG1WQ2g5aStxV2tXc1dw?=
 =?utf-8?B?Wi9OL3ZqcldxSElSQnpnMVVNeGUvcGQxMkRqOVdIU2xrMUg0RHdqTVNnN1lQ?=
 =?utf-8?B?Q2NrZHFsWU9Deld4d1kzN3IyZmxiZTAzUFM1dy9NbmJSckRKOHFyWU9RUlcw?=
 =?utf-8?B?ZEJFK1VtSndQVHFPZkx5dWZRdkpMRUkxN0R2Y1BsVVRkbk1IZzJQazB1djBl?=
 =?utf-8?B?UUNqSVRLUnlhQ09FZHdiVUZIT0ZTK0RaU1RGSi9ld1M1ekRZTlRoeXR1Z09o?=
 =?utf-8?B?ajBzTEc4V0RoR1ArUGZ0YWJVbW9EWmxmMkQrdnMvN1d5TTlDSCtNT01ycE9s?=
 =?utf-8?B?UzZNNGplUzRMUnR6Z2Y1cStRU09WZS9yMk0xc0pqUVBqQzdrNWF4R3MzblV6?=
 =?utf-8?B?cnZkcmhidGdPcTBxWHFmRFd3ZktiWEJWMHdEUGI4em1XaG5xcGxBM2FpdWNN?=
 =?utf-8?B?RFkyaThBTzNXR0dMM1E4VFpNbWFDWWV1VS9EVmd2VXc1NFk2Ym5MR3g2cjJ5?=
 =?utf-8?B?Z01OSTN3dFhBbVFOVElUcFhnK1k5NC8raGdEQjJxdUc3ZVBkWi84VGpnZHVp?=
 =?utf-8?B?ZmJvM1ZBY2JsaHhsZzVSSlFQMlBrYTN1NzRGMTAzMUNlRm1Ma0Voa2hnSWJo?=
 =?utf-8?B?d2EwODBBUHZCd0JQUUwzY3lJK0huVjVabHQxVXgzS01hMjVNMmJVVk1EY0Qr?=
 =?utf-8?B?LzVXbzQ3Tk5QNTVaYk1JQjlXZTAxbWIrS1Q0clZoUVpMYnlwR00xMUtKR1Jm?=
 =?utf-8?B?RER4UFZnWFlNZ0l0c2hQT2NYUlZFZkVWckdIRmx4OUFyeklUMHV3RXVZRmc1?=
 =?utf-8?B?Ym1IN21oek9CV2paUU1NUEVWV1FIc2VtYzJEQWJERldFT09Db2xPTWxFWEpi?=
 =?utf-8?B?YXNUYkt6SE9wT2xGY1JNVi95UHlyRGxIR056bmpxRjVGQllrYXRvc1F5b2Jm?=
 =?utf-8?B?SXh2R3BvYTRXUVh0Vy9SVTBJYSs1a1F6dG8vUHJVM3JxRysyam02ZlRVWXlm?=
 =?utf-8?B?WUhxOUV5YVpzNlZZYzV0VTdFbzVOYlNoS2N6c3pWWHNVbWtGSUpYNXZ3K2I1?=
 =?utf-8?B?RENVaDY2K2xLbFc3UW1nOWZvTlRnWkVTVkhKYjlBdHQzOXdMUUlsVTAwMU9t?=
 =?utf-8?B?cFFVSkpxeDdVL1phb3ZidnNKM25GandNcGl2Tlp0aCtCSlV0MEFXcDNsb0ZK?=
 =?utf-8?B?VEhUSzhiaklRTkRieEQvbVczeUN4aEFScnVTMUZpS0JPYVJvcFJmUE1aQm13?=
 =?utf-8?B?RWgxUXlJOGdvcnc2YXJNc3BZbzV3M3NoM2RlN1VpSGZoY1pZaHBrZS9XSFdX?=
 =?utf-8?B?aVRGalZPMzlLSlNEUEljcmlLQzhKaVhXTTRITHhHYWRNdXRCelcxWlBRU3k2?=
 =?utf-8?B?eU5xbHRtU1pTdzBRR01IQmVCT1JRWXlDUlhMMlNScGpkcEZUZW52V0lVb2w0?=
 =?utf-8?B?RnQxTkFGRlExclRBcjVmcHpYQ25xTmFlaEphMkwvYks4RzdhK3pjdldDWXYr?=
 =?utf-8?B?dnVKNUlrT1ZKT1F6YXVqcEFDbVVkei9PU2JrejM2ZDBTcXZMeEdrMVZPNFhm?=
 =?utf-8?B?UUhwcUdYbmtRSG4rWVJOQTdwRGFmLzRhYmNhN2xHb0MwMWpkemkvVzIzL0RY?=
 =?utf-8?B?ZFNwd3pPdlB3WTFlNHlSb1ltQnZVdVFtSXBVYVFlQUovSUJDVSszcWpVTzQx?=
 =?utf-8?B?anJNK1FQeTc1b3grTnd1eXZITkxVVTRSRkNmd1lWS3pINHZqWHhNR0tRekRH?=
 =?utf-8?B?UDNqckd0VVA0dTU0NFp1TlYyZDJwY1pKc0xBVjQwSHg3ZlFBMFhFRmpId2FM?=
 =?utf-8?B?ZkNRQ1dSWXFKTmZBRE9jOE9UdmhMWkp2R05neldqeWNmVlRDSDV5SFpBSVhE?=
 =?utf-8?B?L0VWaDBEUkNNRm1NS0xtaEZEczU5L09IbDhFMm1OYzZoc2llRTM2SDloN21O?=
 =?utf-8?B?Q1FUT0V2SW1VaDVYQkRaL01aaDJPb29WK1p1MzZ2L1hQM1B4RGg5WTdNV042?=
 =?utf-8?Q?J4Ey5DV/pSUlhjleB8D/auA=3D?=
X-MS-Exchange-CrossTenant-Network-Message-Id: dd0db905-a387-42a8-98f3-08d9f5edf101
X-MS-Exchange-CrossTenant-AuthSource: DM6PR11MB3180.namprd11.prod.outlook.com
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 22 Feb 2022 10:27:35.1134
 (UTC)
X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted
X-MS-Exchange-CrossTenant-Id: 46c98d88-e344-4ed4-8496-4ed7712e255d
X-MS-Exchange-CrossTenant-MailboxType: HOSTED
X-MS-Exchange-CrossTenant-UserPrincipalName: wCUgkCD42r65ZJtxfTO7bAa5ajMPsbEuo0B8RSgq92SkE2N9snBTtfEIVYHaH41Jn1pzqq+mfKFBYcZYqnnvoA==
X-MS-Exchange-Transport-CrossTenantHeadersStamped: DM5PR11MB1737
X-OriginatorOrg: intel.com
X-Spam-Status: No, score=-4.4 required=5.0 tests=BAYES_00,DKIMWL_WL_HIGH,
        DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,NICE_REPLY_A,
        RCVD_IN_DNSWL_MED,SPF_HELO_PASS,SPF_NONE,T_SCC_BODY_TEXT_LINE
        autolearn=ham autolearn_force=no version=3.4.6
X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on
        lindbergh.monkeyblade.net
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org


On 22.02.2022 01:08, Eric Dumazet wrote:
> On Mon, Feb 21, 2022 at 3:26 PM Andrzej Hajda <andrzej.hajda@intel.com> wrote:
>> To improve readibility of ref_tracker printing following changes
>     readability
>
>> have been performed:
>> - reports are printed per stack_handle - log is more compact,
>> - added display name for ref_tracker_dir,
>> - stack trace is printed indented, in the same printk call,
>> - total number of references is printed every time,
>> - print info about dropped references.
>>
>> Signed-off-by: Andrzej Hajda <andrzej.hajda@intel.com>
>> ---
>>   include/linux/ref_tracker.h | 15 +++++--
>>   lib/ref_tracker.c           | 90 ++++++++++++++++++++++++++++++++-----
>>   2 files changed, 91 insertions(+), 14 deletions(-)
>>
>> diff --git a/include/linux/ref_tracker.h b/include/linux/ref_tracker.h
>> index 3e9e9df2a41f5..a2cf1f6309adb 100644
>> --- a/include/linux/ref_tracker.h
>> +++ b/include/linux/ref_tracker.h
>> @@ -17,12 +17,19 @@ struct ref_tracker_dir {
>>          bool                    dead;
>>          struct list_head        list; /* List of active trackers */
>>          struct list_head        quarantine; /* List of dead trackers */
>> +       char                    name[32];
>>   #endif
>>   };
>>
>>   #ifdef CONFIG_REF_TRACKER
>> -static inline void ref_tracker_dir_init(struct ref_tracker_dir *dir,
>> -                                       unsigned int quarantine_count)
>> +
>> +// Temporary allow two and three arguments, until consumers are converted
>> +#define ref_tracker_dir_init(_d, _q, args...) _ref_tracker_dir_init(_d, _q, ##args, #_d)
>> +#define _ref_tracker_dir_init(_d, _q, _n, ...) __ref_tracker_dir_init(_d, _q, _n)
>> +
>> +static inline void __ref_tracker_dir_init(struct ref_tracker_dir *dir,
>> +                                       unsigned int quarantine_count,
>> +                                       const char *name)
>>   {
>>          INIT_LIST_HEAD(&dir->list);
>>          INIT_LIST_HEAD(&dir->quarantine);
>> @@ -31,6 +38,7 @@ static inline void ref_tracker_dir_init(struct ref_tracker_dir *dir,
>>          dir->dead = false;
>>          refcount_set(&dir->untracked, 1);
>>          refcount_set(&dir->no_tracker, 1);
>> +       strlcpy(dir->name, name, sizeof(dir->name));
>>          stack_depot_init();
>>   }
>>
>> @@ -51,7 +59,8 @@ int ref_tracker_free(struct ref_tracker_dir *dir,
>>   #else /* CONFIG_REF_TRACKER */
>>
>>   static inline void ref_tracker_dir_init(struct ref_tracker_dir *dir,
>> -                                       unsigned int quarantine_count)
>> +                                       unsigned int quarantine_count,
>> +                                       ...)
>>   {
>>   }
>>
>> diff --git a/lib/ref_tracker.c b/lib/ref_tracker.c
>> index 5e9f90bbf771b..ab1253fde244e 100644
>> --- a/lib/ref_tracker.c
>> +++ b/lib/ref_tracker.c
>> @@ -1,11 +1,16 @@
>>   // SPDX-License-Identifier: GPL-2.0-or-later
>> +
>> +#define pr_fmt(fmt) "ref_tracker: " fmt
>> +
>>   #include <linux/export.h>
>> +#include <linux/list_sort.h>
>>   #include <linux/ref_tracker.h>
>>   #include <linux/slab.h>
>>   #include <linux/stacktrace.h>
>>   #include <linux/stackdepot.h>
>>
>>   #define REF_TRACKER_STACK_ENTRIES 16
>> +#define STACK_BUF_SIZE 1024
>>
>>   struct ref_tracker {
>>          struct list_head        head;   /* anchor into dir->list or dir->quarantine */
>> @@ -14,24 +19,87 @@ struct ref_tracker {
>>          depot_stack_handle_t    free_stack_handle;
>>   };
>>
>> -void __ref_tracker_dir_print(struct ref_tracker_dir *dir,
>> -                          unsigned int display_limit)
>> +struct ref_tracker_dir_stats {
>> +       int total;
>> +       int count;
>> +       struct {
>> +               depot_stack_handle_t stack_handle;
>> +               unsigned int count;
>> +       } stacks[];
>> +};
>> +
>> +static struct ref_tracker_dir_stats *
>> +ref_tracker_get_stats(struct ref_tracker_dir *dir, unsigned int limit)
>>   {
>> +       struct ref_tracker_dir_stats *stats;
>>          struct ref_tracker *tracker;
>> -       unsigned int i = 0;
>>
>> -       lockdep_assert_held(&dir->lock);
>> +       stats = kmalloc(struct_size(stats, stacks, limit),
>> +                       GFP_NOWAIT | __GFP_NOWARN);
> I would be more comfortable if the allocation was done by the caller,
> possibly using GFP_KERNEL and evenutally kvmalloc(),
> instead of under dir->lock ?

I though also about it, but decided to left this change to another patch 
as the change can be substantial and could open another discussion.

I am not sure what you mean by 'caller' but it could be even external 
user of the API:
1. alloc data for ref_tracker_dir_stats.
2. take locks, if necessary.
3. gather stats (ref_tracker_get_stats) atomically.
4. release taken locks.
5. print stats.

This way, allocation and printing would happen outside locks.

>
>
>> +       if (!stats)
>> +               return ERR_PTR(-ENOMEM);
>> +       stats->total = 0;
>> +       stats->count = 0;
>>
>>          list_for_each_entry(tracker, &dir->list, head) {
>> -               if (i < display_limit) {
>> -                       pr_err("leaked reference.\n");
>> -                       if (tracker->alloc_stack_handle)
>> -                               stack_depot_print(tracker->alloc_stack_handle);
>> -                       i++;
>> -               } else {
>> -                       break;
>> +               depot_stack_handle_t stack = tracker->alloc_stack_handle;
>> +               int i;
>> +
>> +               ++stats->total;
>> +               for (i = 0; i < stats->count; ++i)
>> +                       if (stats->stacks[i].stack_handle == stack)
>> +                               break;
>> +               if (i >= limit)
>> +                       continue;
>> +               if (i >= stats->count) {
>> +                       stats->stacks[i].stack_handle = stack;
>> +                       stats->stacks[i].count = 0;
>> +                       ++stats->count;
>>                  }
>> +               ++stats->stacks[i].count;
>> +       }
>> +
>> +       return stats;
>> +}
>> +
>> +void __ref_tracker_dir_print(struct ref_tracker_dir *dir,
>> +                          unsigned int display_limit)
>> +{
>> +       struct ref_tracker_dir_stats *stats;
>> +       unsigned int i = 0, skipped;
>> +       depot_stack_handle_t stack;
>> +       char *sbuf;
>> +
>> +       lockdep_assert_held(&dir->lock);
>> +
>> +       if (list_empty(&dir->list))
>> +               return;
>> +
>> +       stats = ref_tracker_get_stats(dir, display_limit);
>> +       if (IS_ERR(stats)) {
>> +               pr_err("%s@%pK: couldn't get stats, error %pe\n",
>> +                      dir->name, dir, stats);
>> +               return;
>>          }
>> +
>> +       sbuf = kmalloc(STACK_BUF_SIZE, GFP_NOWAIT | __GFP_NOWARN);
> Same remark. These allocations are most probably going to happen from process
> context, I think GFP_KERNEL is more robust.

The problem is that in my scenario it can be called under spinlock, this 
is why I want almost everywhere non-sleeping allocations.

>
> This is debugging infra, it would be sad if we give up at this point,
> after storing MB of traces :)

My approach was to avoid allocations if the system is short on memory - 
better to keep it alive, and we still get the report, just without 
stacktraces, one can print full stats later (for example via sysfs, or 
trigger to dmesg) - big chances that the bug will be still there.
If you think that is no-go, alternatives I see:
- go back to GFP_ATOMIC,
- print stack directly, without using stack_depot_snprint,
- pre-allocate buffer.

Regards
Andrzej

>
>> +
>> +       for (i = 0, skipped = stats->total; i < stats->count; ++i) {
>> +               stack = stats->stacks[i].stack_handle;
>> +               if (sbuf && !stack_depot_snprint(stack, sbuf, STACK_BUF_SIZE, 4))
>> +                       sbuf[0] = 0;
>> +               pr_err("%s@%pK has %d/%d users at\n%s\n", dir->name, dir,
>> +                      stats->stacks[i].count, stats->total, sbuf);
>> +               skipped -= stats->stacks[i].count;
>> +       }
>> +
>> +       if (skipped)
>> +               pr_err("%s@%pK skipped reports about %d/%d users.\n",
>> +                      dir->name, dir, skipped, stats->total);
>> +
>> +       kfree(sbuf);
>> +
>> +       kfree(stats);
>>   }
>>   EXPORT_SYMBOL(__ref_tracker_dir_print);
>>
>> --
>> 2.25.1
>>