From patchwork Wed Aug 29 12:17:10 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: "Motai.Hirotaka@aj.MitsubishiElectric.co.jp" X-Patchwork-Id: 10580235 Return-Path: Received: from mail.wl.linuxfoundation.org (pdx-wl-mail.web.codeaurora.org [172.30.200.125]) by pdx-korg-patchwork-2.web.codeaurora.org (Postfix) with ESMTP id 0FE2F175A for ; Wed, 29 Aug 2018 12:42:58 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id F13B42897B for ; Wed, 29 Aug 2018 12:42:57 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id E4B98289F7; Wed, 29 Aug 2018 12:42:57 +0000 (UTC) X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on pdx-wl-mail.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-5.1 required=2.0 tests=BAYES_00,DKIM_SIGNED, MAILING_LIST_MULTI,RCVD_IN_DNSWL_MED,T_DKIM_INVALID autolearn=ham version=3.3.1 Received: from mail.linuxfoundation.org (mail.linuxfoundation.org [140.211.169.12]) (using TLSv1.2 with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.wl.linuxfoundation.org (Postfix) with ESMTPS id AF2222897B for ; Wed, 29 Aug 2018 12:42:56 +0000 (UTC) Received: from mail.linux-foundation.org (localhost [127.0.0.1]) by mail.linuxfoundation.org (Postfix) with ESMTP id C2237D5A; Wed, 29 Aug 2018 12:36:52 +0000 (UTC) X-Original-To: ltsi-dev@lists.linuxfoundation.org Delivered-To: ltsi-dev@mail.linuxfoundation.org Received: from smtp2.linuxfoundation.org (smtp2.linux-foundation.org [172.17.192.36]) by mail.linuxfoundation.org (Postfix) with ESMTPS id 8B3B0D56 for ; Wed, 29 Aug 2018 12:36:46 +0000 (UTC) X-Greylist: from auto-whitelisted by SQLgrey-1.7.6 Received: from mx05.melco.co.jp (mx05.melco.co.jp [192.218.140.145]) by smtp2.linuxfoundation.org (Postfix) with ESMTPS id 983431DCF0 for ; Wed, 29 Aug 2018 12:36:38 +0000 (UTC) Received: from mr05.melco.co.jp (mr05 [133.141.98.165]) by mx05.melco.co.jp (Postfix) with ESMTP id 028C83A3260 for ; Wed, 29 Aug 2018 21:18:05 +0900 (JST) Received: from mr05.melco.co.jp (unknown [127.0.0.1]) by mr05.imss (Postfix) with ESMTP id 420l5871przRkCl for ; Wed, 29 Aug 2018 21:18:04 +0900 (JST) Received: from mf03_second.melco.co.jp (unknown [192.168.20.183]) by mr05.melco.co.jp (Postfix) with ESMTP id 420l586k6MzRkC3 for ; Wed, 29 Aug 2018 21:18:04 +0900 (JST) Received: from mf03.melco.co.jp (unknown [133.141.98.183]) by mf03_second.melco.co.jp (Postfix) with ESMTP id 420l586GwyzRkCd for ; Wed, 29 Aug 2018 21:18:04 +0900 (JST) Received: from JPN01-TY1-obe.outbound.protection.outlook.com (unknown [23.103.139.177]) by mf03.melco.co.jp (Postfix) with ESMTP id 420l58637WzRk8v for ; Wed, 29 Aug 2018 21:18:04 +0900 (JST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=mitsubishielectricgroup.onmicrosoft.com; s=selector1-mitsubishielectricgroup-onmicrosoft-com; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-SenderADCheck; bh=pqBi1FwU+e4+16EwVVoImCbZpd/+A5tpwU0w6bDMUU4=; b=OZjH4IzNk5w7iebnOiVeJX80wF5efofkMU64L8CSdz3kF9riZlGNVFSYdX1zrn7J7X1kAlsb+1tFLivRc2M+NZDf0DbWVVKQpOjXn+yT8c5sV3pzQ99moi7DzGflBHxTnpuirtBVaXQqXhs7bNZPgB0uGt8xgEWXfvhkG2O3Y+4= Received: from TY1PR01MB1692.jpnprd01.prod.outlook.com (52.133.160.145) by TY1PR01MB0762.jpnprd01.prod.outlook.com (10.167.158.149) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id 15.20.1080.15; Wed, 29 Aug 2018 12:18:03 +0000 Received: from TY1PR01MB1692.jpnprd01.prod.outlook.com ([fe80::d04e:e6f6:c782:22fa]) by TY1PR01MB1692.jpnprd01.prod.outlook.com ([fe80::d04e:e6f6:c782:22fa%2]) with mapi id 15.20.1080.015; Wed, 29 Aug 2018 12:18:03 +0000 From: "Motai.Hirotaka@aj.MitsubishiElectric.co.jp" To: "ltsi-dev@lists.linuxfoundation.org" Thread-Topic: [LTSI-dev] [PATCH 37/54] tracing: Add 'last error' error facility for hist triggers Thread-Index: AdQ/jKiuD5Rg5+vpSoStEMkBGH9YlA== Date: Wed, 29 Aug 2018 12:17:10 +0000 Deferred-Delivery: Wed, 29 Aug 2018 12:15:00 +0000 Message-ID: Accept-Language: ja-JP, en-US Content-Language: ja-JP X-MS-Has-Attach: X-MS-TNEF-Correlator: x-melpop: 1 authentication-results: spf=none (sender IP is ) smtp.mailfrom=Motai.Hirotaka@aj.MitsubishiElectric.co.jp; x-originating-ip: [153.231.200.201] x-ms-publictraffictype: Email x-microsoft-exchange-diagnostics: 1; TY1PR01MB0762; 6:pMwgPcQd9rAvkGtgkGSrnEAATKSiMXQB1nrcsncXJlUR/SKbFYVGgDvC0+12/2t2jkxce29GWVF1raHr3m8FXElyf7MbK/uQ/W6WFr0gvoUqZNZV0xXqaEJMggb5+X1wk6D6tgQ7vsZ0lE61W7sOEc24i/Fyw8utx6AZvquLBygRoonEDhdkcrjM9EbIRp7qtUT+4q9CXEdCUDJ2BFrz1WF9CxJswjboU0iD2CCvsZ0DxAiQypQSyJcAqTN/mjeJo+N9t+BRfgzp5m4sjkYSVq03oxGH+Afz3Amx2f25ipITUbhXbn9LFJqoboopfkInPTdd8a7sG48+Cmc7zn8vwns315bbKSithNHSqRkEpY82GFc7WY2nqJI/kp/UzpGuQnxU06wjOPHsBn5+wN1p0yhxq/pdbGctZ2WJAUIb+zf0gbrzuCh6Vfi0wdNjC5fS2PBOGxJaDYXSgD6TqrqUwg==; 5:Mnj/w15QC7feGqy2OnH4gZthFX89/3hmGqYDuNDMRBp1B9HgVVUMNQVUgrcl3maSCHJfKunVa4Q5EvcqEpC7+fV8xSbsBSeCoLuT46B8Yze/xN/Dwgergg8QKISiIXce2GcNBrI3c4EpnuRnuAiF6cuNCfdv7Yhi19kn12voG0s=; 7:vN+ZU3yUEjuTLK6w2h7Gtqvn1Hz49rSYKCjB3msFroV3ldg6hN03+pUyWhhvKJ8QI4VrCqap0UHs0Z2EcKLT8alTTtm6yzlrs+4hVvCUdPZHPyj7CuZ8iN0vScairI4VR2QiapPIQ6g3TGv+fdgApA2hGTRzX5K4djHtFAgHTS9bST3zFaCA3DC39tIyajXtBS3LxmK+VjarFVqnPGZhzs15Ob5E5GJoTVa/3sRDYpNyMpBtNZaksb9fME9DzjeU x-ms-office365-filtering-correlation-id: acc22f15-baa1-4454-2c85-08d60da97830 x-microsoft-antispam: BCL:0; PCL:0; RULEID:(7020095)(4652040)(8989137)(4534165)(4627221)(201703031133081)(201702281549075)(8990107)(5600074)(711020)(2017052603328)(7153060)(7193020); SRVR:TY1PR01MB0762; x-ms-traffictypediagnostic: TY1PR01MB0762: x-microsoft-antispam-prvs: x-exchange-antispam-report-test: UriScan:(42068640409301)(228905959029699); x-ms-exchange-senderadcheck: 1 x-exchange-antispam-report-cfa-test: BCL:0; PCL:0; RULEID:(6040522)(2401047)(5005006)(8121501046)(3231311)(944501410)(52105095)(93006095)(93001095)(3002001)(10201501046)(149027)(150027)(6041310)(201703131423095)(201702281528075)(20161123555045)(201703061421075)(201703061406153)(20161123562045)(20161123564045)(20161123558120)(20161123560045)(201708071742011)(7699016); SRVR:TY1PR01MB0762; BCL:0; PCL:0; RULEID:; SRVR:TY1PR01MB0762; x-forefront-prvs: 077929D941 x-forefront-antispam-report: SFV:NSPM; SFS:(10019020)(39860400002)(396003)(346002)(376002)(136003)(366004)(199004)(189003)(7696005)(186003)(72206003)(6116002)(478600001)(3846002)(1857600001)(256004)(74482002)(5250100002)(5660300001)(14444005)(966005)(2501003)(99286004)(2900100001)(8936002)(53936002)(68736007)(53946003)(33656002)(9686003)(2906002)(97736004)(6306002)(26005)(476003)(7736002)(305945005)(74316002)(6666003)(316002)(14454004)(486006)(55016002)(81166006)(5640700003)(66066001)(8676002)(86362001)(6436002)(2351001)(6506007)(106356001)(25786009)(6916009)(105586002)(102836004)(575784001)(81156014)(21314002)(579004); DIR:OUT; SFP:1102; SCL:1; SRVR:TY1PR01MB0762; H:TY1PR01MB1692.jpnprd01.prod.outlook.com; FPR:; SPF:None; LANG:en; PTR:InfoNoRecords; A:0; MX:1; received-spf: None (protection.outlook.com: aj.MitsubishiElectric.co.jp does not designate permitted sender hosts) x-microsoft-antispam-message-info: 0n+3w7PLaIiQ41DyKMzL1Z9zHtNegCecUKA8Kui43Oa+LH2/B1WXEgNHZiYzDXbhSXdNEiGJHMOLXBjTQaUd538GPMU/Y7i7B0ISNZuudAKQHgzolt5bQ0qrhiezksmoPFpdUe8iA8zVDNrO2QS2PpSWDzH8FlA/XThXJu3OGu2WBvaB6Z3G2RKv2kTZpoBdhfhg9FdNJMzaT2j53AExm+UrosqnHyRSOvVu7JUFXK1SYOD3Dk2prA8oSBiE6gTsPsSqya4VXtgyMrzdusO0gjQLs9LFQn7sPiUjsKtBFnaMW3YrUUVo90gXC6778L0mAYaiaojk2glbjyoWJbBKoRNFUGghnk+Uax6Wx5xE1RQ= spamdiagnosticoutput: 1:99 spamdiagnosticmetadata: NSPM MIME-Version: 1.0 X-OriginatorOrg: aj.MitsubishiElectric.co.jp X-MS-Exchange-CrossTenant-Network-Message-Id: acc22f15-baa1-4454-2c85-08d60da97830 X-MS-Exchange-CrossTenant-originalarrivaltime: 29 Aug 2018 12:17:22.6437 (UTC) X-MS-Exchange-CrossTenant-fromentityheader: Hosted X-MS-Exchange-CrossTenant-id: c5a75b62-4bff-4c96-a720-6621ce9978e5 X-MS-Exchange-Transport-CrossTenantHeadersStamped: TY1PR01MB0762 Subject: [LTSI-dev] [PATCH 37/54] tracing: Add 'last error' error facility for hist triggers X-BeenThere: ltsi-dev@lists.linuxfoundation.org X-Mailman-Version: 2.1.12 Precedence: list List-Id: "A list to discuss patches, development, and other things related to the LTSI project" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Sender: ltsi-dev-bounces@lists.linuxfoundation.org Errors-To: ltsi-dev-bounces@lists.linuxfoundation.org X-Virus-Scanned: ClamAV using ClamSMTP With the addition of variables and actions, it's become necessary to provide more detailed error information to users about syntax errors. Add a 'last error' facility accessible via the erroring event's 'hist' file. Reading the hist file after an error will display more detailed information about what went wrong, if information is available. This extended error information will be available until the next hist trigger command for that event. # echo xxx > /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger echo: write error: Invalid argument # cat /sys/kernel/debug/tracing/events/sched/sched_wakeup/hist ERROR: Couldn't yyy: zzz Last command: xxx Also add specific error messages for variable and action errors. Link: http://lkml.kernel.org/r/64e9c422fc8aeafcc2f7a3b4328c0cffe7969129.1516069914.git.tom.zanussi@linux.intel.com Signed-off-by: Tom Zanussi Signed-off-by: Steven Rostedt (VMware) (cherry picked from commit f404da6e1d46ced7d3b53377f1e140c486ea7350) Signed-off-by: Hirotaka MOTAI --- Documentation/trace/histogram.txt | 20 ++++ kernel/trace/trace_events_hist.c | 164 +++++++++++++++++++++++++++--- 2 files changed, 170 insertions(+), 14 deletions(-) diff --git a/Documentation/trace/histogram.txt b/Documentation/trace/histogram.txt index be612ca7..0aec2d8e 100644 --- a/Documentation/trace/histogram.txt +++ b/Documentation/trace/histogram.txt @@ -183,16 +183,36 @@ They are: common_timestamp u64 - timestamp (from ring buffer) associated with the event, in nanoseconds. May be modified by .usecs to have timestamps interpreted as microseconds. cpu int - the cpu on which the event occurred. + Extended error information + -------------------------- + + For some error conditions encountered when invoking a hist trigger + command, extended error information is available via the + corresponding event's 'hist' file. Reading the hist file after an + error will display more detailed information about what went wrong, + if information is available. This extended error information will + be available until the next hist trigger command for that event. + + If available for a given error condition, the extended error + information and usage takes the following form: + + # echo xxx > /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger + echo: write error: Invalid argument + + # cat /sys/kernel/debug/tracing/events/sched/sched_wakeup/hist + ERROR: Couldn't yyy: zzz + Last command: xxx + 6.2 'hist' trigger examples --------------------------- The first set of examples creates aggregations using the kmalloc event. The fields that can be used for the hist trigger are listed in the kmalloc event's format file: # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/format diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c index 32af5235..8719b0ea 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -346,16 +346,75 @@ struct action_data { char *fn_name; unsigned int max_var_ref_idx; struct hist_field *max_var; struct hist_field *var; } onmax; }; }; + +static char last_hist_cmd[MAX_FILTER_STR_VAL]; +static char hist_err_str[MAX_FILTER_STR_VAL]; + +static void last_cmd_set(char *str) +{ + if (!str) + return; + + strncpy(last_hist_cmd, str, MAX_FILTER_STR_VAL - 1); +} + +static void hist_err(char *str, char *var) +{ + int maxlen = MAX_FILTER_STR_VAL - 1; + + if (!str) + return; + + if (strlen(hist_err_str)) + return; + + if (!var) + var = ""; + + if (strlen(hist_err_str) + strlen(str) + strlen(var) > maxlen) + return; + + strcat(hist_err_str, str); + strcat(hist_err_str, var); +} + +static void hist_err_event(char *str, char *system, char *event, char *var) +{ + char err[MAX_FILTER_STR_VAL]; + + if (system && var) + snprintf(err, MAX_FILTER_STR_VAL, "%s.%s.%s", system, event, var); + else if (system) + snprintf(err, MAX_FILTER_STR_VAL, "%s.%s", system, event); + else + strncpy(err, var, MAX_FILTER_STR_VAL); + + hist_err(str, err); +} + +static void hist_err_clear(void) +{ + hist_err_str[0] = '\0'; +} + +static bool have_hist_err(void) +{ + if (strlen(hist_err_str)) + return true; + + return false; +} + static LIST_HEAD(synth_event_list); static DEFINE_MUTEX(synth_event_mutex); struct synth_trace_event { struct trace_entry ent; u64 fields[]; }; @@ -1443,18 +1502,20 @@ static struct trace_event_file *find_var_file(struct trace_array *tr, list_for_each_entry(var_data, &tr->hist_vars, list) { var_hist_data = var_data->hist_data; file = var_hist_data->event_file; if (file == found) continue; if (find_var_field(var_hist_data, var_name)) { - if (found) + if (found) { + hist_err_event("Variable name not unique, need to use fully qualified name (subsys.event.var) for variable: ", system, event_name, var_name); return NULL; + } found = file; } } return found; } @@ -1493,16 +1554,17 @@ find_match_var(struct hist_trigger_data *hist_data, char *var_name) char *event_name = data->onmatch.match_event; file = find_var_file(tr, system, event_name, var_name); if (!file) continue; hist_field = find_file_var(file, var_name); if (hist_field) { if (found) { + hist_err_event("Variable name not unique, need to use fully qualified name (subsys.event.var) for variable: ", system, event_name, var_name); return ERR_PTR(-EINVAL); } found = hist_field; } } } return found; @@ -1776,16 +1838,17 @@ static int parse_assignment(char *str, struct hist_trigger_attrs *attrs) ret = map_bits; goto out; } attrs->map_bits = map_bits; } else { char *assignment; if (attrs->n_assignments == TRACING_MAP_VARS_MAX) { + hist_err("Too many variables defined: ", str); ret = -EINVAL; goto out; } assignment = kstrdup(str, GFP_KERNEL); if (!assignment) { ret = -ENOMEM; goto out; @@ -2330,16 +2393,20 @@ static struct hist_field *parse_var_ref(struct hist_trigger_data *hist_data, return NULL; var_name++; var_field = find_event_var(hist_data, system, event_name, var_name); if (var_field) ref_field = create_var_ref(var_field, system, event_name); + if (!ref_field) + hist_err_event("Couldn't find variable: $", + system, event_name, var_name); + return ref_field; } static struct ftrace_event_field * parse_field(struct hist_trigger_data *hist_data, struct trace_event_file *file, char *field_str, unsigned long *flags) { struct ftrace_event_field *field = NULL; @@ -2489,16 +2556,17 @@ static struct hist_field *parse_unary(struct hist_trigger_data *hist_data, struct hist_field *operand1, *expr = NULL; unsigned long operand_flags; int ret = 0; char *s; /* we support only -(xxx) i.e. explicit parens required */ if (level > 3) { + hist_err("Too many subexpressions (3 max): ", str); ret = -EINVAL; goto free; } str++; /* skip leading '-' */ s = strchr(str, '('); if (s) @@ -2570,34 +2638,38 @@ static int check_expr_operands(struct hist_field *operand1, var = find_var_field(operand2->var.hist_data, operand2->name); if (!var) return -EINVAL; operand2_flags = var->flags; } if ((operand1_flags & HIST_FIELD_FL_TIMESTAMP_USECS) != - (operand2_flags & HIST_FIELD_FL_TIMESTAMP_USECS)) + (operand2_flags & HIST_FIELD_FL_TIMESTAMP_USECS)) { + hist_err("Timestamp units in expression don't match", NULL); return -EINVAL; + } return 0; } static struct hist_field *parse_expr(struct hist_trigger_data *hist_data, struct trace_event_file *file, char *str, unsigned long flags, char *var_name, unsigned int level) { struct hist_field *operand1 = NULL, *operand2 = NULL, *expr = NULL; unsigned long operand_flags; int field_op, ret = -EINVAL; char *sep, *operand1_str; - if (level > 3) + if (level > 3) { + hist_err("Too many subexpressions (3 max): ", str); return ERR_PTR(-EINVAL); + } field_op = contains_operator(str); if (field_op == FIELD_OP_NONE) return parse_atom(hist_data, file, str, &flags, var_name); if (field_op == FIELD_OP_UNARY_MINUS) return parse_unary(hist_data, file, str, flags, var_name, ++level); @@ -2821,35 +2893,43 @@ create_field_var_hist(struct hist_trigger_data *target_hist_data, unsigned int i, n, first = true; struct field_var_hist *var_hist; struct trace_event_file *file; struct hist_field *key_field; char *saved_filter; char *cmd; int ret; - if (target_hist_data->n_field_var_hists >= SYNTH_FIELDS_MAX) + if (target_hist_data->n_field_var_hists >= SYNTH_FIELDS_MAX) { + hist_err_event("onmatch: Too many field variables defined: ", + subsys_name, event_name, field_name); return ERR_PTR(-EINVAL); + } file = event_file(tr, subsys_name, event_name); if (IS_ERR(file)) { + hist_err_event("onmatch: Event file not found: ", + subsys_name, event_name, field_name); ret = PTR_ERR(file); return ERR_PTR(ret); } /* * Look for a histogram compatible with target. We'll use the * found histogram specification to create a new matching * histogram with our variable on it. target_hist_data is not * yet a registered histogram so we can't use that. */ hist_data = find_compatible_hist(target_hist_data, file); - if (!hist_data) + if (!hist_data) { + hist_err_event("onmatch: Matching event histogram not found: ", + subsys_name, event_name, field_name); return ERR_PTR(-EINVAL); + } /* See if a synthetic field variable has already been created */ event_var = find_synthetic_field_var(target_hist_data, subsys_name, event_name, field_name); if (!IS_ERR_OR_NULL(event_var)) return event_var; var_hist = kzalloc(sizeof(*var_hist), GFP_KERNEL); @@ -2898,27 +2978,31 @@ create_field_var_hist(struct hist_trigger_data *target_hist_data, /* Create the new histogram with our variable */ ret = event_hist_trigger_func(&trigger_hist_cmd, file, "", "hist", cmd); if (ret) { kfree(cmd); kfree(var_hist->cmd); kfree(var_hist); + hist_err_event("onmatch: Couldn't create histogram for field: ", + subsys_name, event_name, field_name); return ERR_PTR(ret); } kfree(cmd); /* If we can't find the variable, something went wrong */ event_var = find_synthetic_field_var(target_hist_data, subsys_name, event_name, field_name); if (IS_ERR_OR_NULL(event_var)) { kfree(var_hist->cmd); kfree(var_hist); + hist_err_event("onmatch: Couldn't find synthetic variable: ", + subsys_name, event_name, field_name); return ERR_PTR(-EINVAL); } n = target_hist_data->n_field_var_hists; target_hist_data->field_var_hists[n] = var_hist; target_hist_data->n_field_var_hists++; return event_var; @@ -3045,28 +3129,31 @@ static struct field_var *create_field_var(struct hist_trigger_data *hist_data, char *field_name) { struct hist_field *val = NULL, *var = NULL; unsigned long flags = HIST_FIELD_FL_VAR; struct field_var *field_var; int ret = 0; if (hist_data->n_field_vars >= SYNTH_FIELDS_MAX) { + hist_err("Too many field variables defined: ", field_name); ret = -EINVAL; goto err; } val = parse_atom(hist_data, file, field_name, &flags, NULL); if (IS_ERR(val)) { + hist_err("Couldn't parse field variable: ", field_name); ret = PTR_ERR(val); goto err; } var = create_var(hist_data, file, field_name, val->size, val->type); if (IS_ERR(var)) { + hist_err("Couldn't create or find variable: ", field_name); kfree(val); ret = PTR_ERR(var); goto err; } field_var = kzalloc(sizeof(struct field_var), GFP_KERNEL); if (!field_var) { kfree(val); @@ -3199,23 +3286,27 @@ static int onmax_create(struct hist_trigger_data *hist_data, unsigned int var_ref_idx = hist_data->n_var_refs; struct field_var *field_var; char *onmax_var_str, *param; unsigned long flags; unsigned int i; int ret = 0; onmax_var_str = data->onmax.var_str; - if (onmax_var_str[0] != '$') + if (onmax_var_str[0] != '$') { + hist_err("onmax: For onmax(x), x must be a variable: ", onmax_var_str); return -EINVAL; + } onmax_var_str++; var_field = find_target_event_var(hist_data, NULL, NULL, onmax_var_str); - if (!var_field) + if (!var_field) { + hist_err("onmax: Couldn't find onmax variable: ", onmax_var_str); return -EINVAL; + } flags = HIST_FIELD_FL_VAR_REF; ref_field = create_hist_field(hist_data, NULL, flags, NULL); if (!ref_field) return -ENOMEM; if (init_var_ref(ref_field, var_field, NULL, NULL)) { destroy_hist_field(ref_field, 0); @@ -3225,30 +3316,32 @@ static int onmax_create(struct hist_trigger_data *hist_data, hist_data->var_refs[hist_data->n_var_refs] = ref_field; ref_field->var_ref_idx = hist_data->n_var_refs++; data->onmax.var = ref_field; data->fn = onmax_save; data->onmax.max_var_ref_idx = var_ref_idx; max_var = create_var(hist_data, file, "max", sizeof(u64), "u64"); if (IS_ERR(max_var)) { + hist_err("onmax: Couldn't create onmax variable: ", "max"); ret = PTR_ERR(max_var); goto out; } data->onmax.max_var = max_var; for (i = 0; i < data->n_params; i++) { param = kstrdup(data->params[i], GFP_KERNEL); if (!param) { ret = -ENOMEM; goto out; } field_var = create_target_field_var(hist_data, NULL, NULL, param); if (IS_ERR(field_var)) { + hist_err("onmax: Couldn't create field variable: ", param); ret = PTR_ERR(field_var); kfree(param); goto out; } hist_data->max_vars[hist_data->n_max_vars++] = field_var; if (field_var->val->flags & HIST_FIELD_FL_STRING) hist_data->n_max_var_str++; @@ -3271,16 +3364,17 @@ static int parse_action_params(char *params, struct action_data *data) param = strsep(¶ms, ","); if (!param) { ret = -EINVAL; goto out; } param = strstrip(param); if (strlen(param) < 2) { + hist_err("Invalid action param: ", param); ret = -EINVAL; goto out; } saved_param = kstrdup(param, GFP_KERNEL); if (!saved_param) { ret = -ENOMEM; goto out; @@ -3446,16 +3540,19 @@ onmatch_find_var(struct hist_trigger_data *hist_data, struct action_data *data, if (!system) { system = data->onmatch.match_event_system; event = data->onmatch.match_event; } hist_field = find_event_var(hist_data, system, event, var); } + if (!hist_field) + hist_err_event("onmatch: Couldn't find onmatch param: $", system, event, var); + return hist_field; } static struct hist_field * onmatch_create_field_var(struct hist_trigger_data *hist_data, struct action_data *data, char *system, char *event, char *var) { @@ -3513,16 +3610,17 @@ static int onmatch_create(struct hist_trigger_data *hist_data, unsigned int i, var_ref_idx; unsigned int field_pos = 0; struct synth_event *event; int ret = 0; mutex_lock(&synth_event_mutex); event = find_synth_event(data->onmatch.synth_event_name); if (!event) { + hist_err("onmatch: Couldn't find synthetic event: ", data->onmatch.synth_event_name); mutex_unlock(&synth_event_mutex); return -EINVAL; } event->ref++; mutex_unlock(&synth_event_mutex); var_ref_idx = hist_data->n_var_refs; @@ -3572,22 +3670,25 @@ static int onmatch_create(struct hist_trigger_data *hist_data, } save_synth_var_ref(hist_data, var_ref); field_pos++; kfree(p); continue; } + hist_err_event("onmatch: Param type doesn't match synthetic event field type: ", + system, event_name, param); kfree(p); ret = -EINVAL; goto err; } if (field_pos != event->n_fields) { + hist_err("onmatch: Param count doesn't match synthetic event field count: ", event->name); ret = -EINVAL; goto err; } data->fn = action_trace; data->onmatch.synth_event = event; data->onmatch.var_ref_idx = var_ref_idx; out: @@ -3607,55 +3708,68 @@ static struct action_data *onmatch_parse(struct trace_array *tr, char *str) struct action_data *data; int ret = -EINVAL; data = kzalloc(sizeof(*data), GFP_KERNEL); if (!data) return ERR_PTR(-ENOMEM); match_event = strsep(&str, ")"); - if (!match_event || !str) + if (!match_event || !str) { + hist_err("onmatch: Missing closing paren: ", match_event); goto free; + } match_event_system = strsep(&match_event, "."); - if (!match_event) + if (!match_event) { + hist_err("onmatch: Missing subsystem for match event: ", match_event_system); goto free; + } - if (IS_ERR(event_file(tr, match_event_system, match_event))) + if (IS_ERR(event_file(tr, match_event_system, match_event))) { + hist_err_event("onmatch: Invalid subsystem or event name: ", + match_event_system, match_event, NULL); goto free; + } data->onmatch.match_event = kstrdup(match_event, GFP_KERNEL); if (!data->onmatch.match_event) { ret = -ENOMEM; goto free; } data->onmatch.match_event_system = kstrdup(match_event_system, GFP_KERNEL); if (!data->onmatch.match_event_system) { ret = -ENOMEM; goto free; } strsep(&str, "."); - if (!str) + if (!str) { + hist_err("onmatch: Missing . after onmatch(): ", str); goto free; + } synth_event_name = strsep(&str, "("); - if (!synth_event_name || !str) + if (!synth_event_name || !str) { + hist_err("onmatch: Missing opening paramlist paren: ", synth_event_name); goto free; + } data->onmatch.synth_event_name = kstrdup(synth_event_name, GFP_KERNEL); if (!data->onmatch.synth_event_name) { ret = -ENOMEM; goto free; } params = strsep(&str, ")"); - if (!params || !str || (str && strlen(str))) + if (!params || !str || (str && strlen(str))) { + hist_err("onmatch: Missing closing paramlist paren: ", params); goto free; + } ret = parse_action_params(params, data); if (ret) goto free; out: return data; free: onmatch_destroy(data); @@ -3720,17 +3834,19 @@ static int create_var_field(struct hist_trigger_data *hist_data, unsigned int val_idx, struct trace_event_file *file, char *var_name, char *expr_str) { unsigned long flags = 0; if (WARN_ON(val_idx >= TRACING_MAP_VALS_MAX + TRACING_MAP_VARS_MAX)) return -EINVAL; + if (find_var(hist_data, file, var_name) && !hist_data->remove) { + hist_err("Variable already defined: ", var_name); return -EINVAL; } flags |= HIST_FIELD_FL_VAR; hist_data->n_vars++; if (WARN_ON(hist_data->n_vars > TRACING_MAP_VARS_MAX)) return -EINVAL; @@ -3801,16 +3917,17 @@ static int create_key_field(struct hist_trigger_data *hist_data, hist_field = parse_expr(hist_data, file, field_str, flags, NULL, 0); if (IS_ERR(hist_field)) { ret = PTR_ERR(hist_field); goto out; } if (hist_field->flags & HIST_FIELD_FL_VAR_REF) { + hist_err("Using variable references as keys not supported: ", field_str); destroy_hist_field(hist_field, 0); ret = -EINVAL; goto out; } key_size = hist_field->size; } @@ -3914,21 +4031,23 @@ static int parse_var_defs(struct hist_trigger_data *hist_data) str = hist_data->attrs->assignment_str[i]; for (j = 0; j < TRACING_MAP_VARS_MAX; j++) { field_str = strsep(&str, ","); if (!field_str) break; var_name = strsep(&field_str, "="); if (!var_name || !field_str) { + hist_err("Malformed assignment: ", var_name); ret = -EINVAL; goto free; } if (n_vars == TRACING_MAP_VARS_MAX) { + hist_err("Too many variables defined: ", var_name); ret = -EINVAL; goto free; } s = kstrdup(var_name, GFP_KERNEL); if (!s) { ret = -ENOMEM; goto free; @@ -4670,16 +4789,21 @@ static int hist_show(struct seq_file *m, void *v) goto out_unlock; } list_for_each_entry_rcu(data, &event_file->triggers, list) { if (data->cmd_ops->trigger_type == ETT_EVENT_HIST) hist_trigger_show(m, data, n++); } + if (have_hist_err()) { + seq_printf(m, "\nERROR: %s\n", hist_err_str); + seq_printf(m, " Last command: %s\n", last_hist_cmd); + } + out_unlock: mutex_unlock(&event_mutex); return ret; } static int event_hist_open(struct inode *inode, struct file *file) { @@ -5034,16 +5158,17 @@ static int hist_register_trigger(char *glob, struct event_trigger_ops *ops, struct event_trigger_data *test, *named_data = NULL; int ret = 0; if (hist_data->attrs->name) { named_data = find_named_trigger(hist_data->attrs->name); if (named_data) { if (!hist_trigger_match(data, named_data, named_data, true)) { + hist_err("Named hist trigger doesn't match existing named trigger (includes variables): ", hist_data->attrs->name); ret = -EINVAL; goto out; } } } if (hist_data->attrs->name && !named_data) goto new; @@ -5053,23 +5178,26 @@ static int hist_register_trigger(char *glob, struct event_trigger_ops *ops, if (!hist_trigger_match(data, test, named_data, false)) continue; if (hist_data->attrs->pause) test->paused = true; else if (hist_data->attrs->cont) test->paused = false; else if (hist_data->attrs->clear) hist_clear(test); - else + else { + hist_err("Hist trigger already exists", NULL); ret = -EEXIST; + } goto out; } } new: if (hist_data->attrs->cont || hist_data->attrs->clear) { + hist_err("Can't clear or continue a nonexistent hist trigger", NULL); ret = -ENOENT; goto out; } if (hist_data->attrs->pause) data->paused = true; if (named_data) { @@ -5246,16 +5374,21 @@ static int event_hist_trigger_func(struct event_command *cmd_ops, struct event_trigger_ops *trigger_ops; struct hist_trigger_data *hist_data; struct synth_event *se; const char *se_name; bool remove = false; char *trigger, *p; int ret = 0; + if (glob && strlen(glob)) { + last_cmd_set(param); + hist_err_clear(); + } + if (!param) return -EINVAL; if (glob[0] == '!') remove = true; /* * separate the trigger from the filter (k:v [if filter]) @@ -5384,16 +5517,19 @@ static int event_hist_trigger_func(struct event_command *cmd_ops, se = find_synth_event(se_name); if (se) se->ref++; mutex_unlock(&synth_event_mutex); /* Just return zero, not the number of registered triggers */ ret = 0; out: + if (ret == 0) + hist_err_clear(); + return ret; out_unreg: cmd_ops->unreg(glob+1, trigger_ops, trigger_data, file); out_free: if (cmd_ops->set_filter) cmd_ops->set_filter(NULL, trigger_data, NULL); remove_hist_vars(hist_data);