Re: [PATCH v3 1/2] iommu/arm-smmu-v3: Print better events records

[Pranjal Shrivastava <praan@google.com>]

On Mon, Sep 30, 2024 at 12:15:10PM -0700, Nicolin Chen wrote:
> On Sat, Sep 28, 2024 at 12:51:42AM +0000, Pranjal Shrivastava wrote:
> 
> > +static const char * const class_str[] = {
> > +       [0] = "CD fetch",
> > +       [1] = "Stage 1 translation table fetch",
> > +       [2] = "Input address caused fault ",
> > +       [3] = "Reserved",
> > +};
> 
> s/class_str/event_class_str
> 

Ack.

> > @@ -1756,6 +1784,66 @@ arm_smmu_find_master(struct arm_smmu_device *smmu, u32 sid)
> >         return rb_entry(node, struct arm_smmu_stream, node)->master;
> >  }
> > 
> > +static void arm_smmu_dump_raw_event(struct arm_smmu_device *smmu,
> > +                                   struct arm_smmu_event *event)
> > +{
> > +       int i;
> > +
> > +       dev_err(smmu->dev, "event 0x%02x received: master %s:\n",
> > +               event->id, event->master_name);
> > +
> > +       for (i = 0; i < EVTQ_ENT_DWORDS; ++i)
> > +               dev_err(smmu->dev, "\t0x%016llx\n",
> > +                        (unsigned long long)event->raw[i]);
> 
> Though I know that is what we have been doing in the driver, I
> wonder if we have to cast from u64 to ull?
> 

I think we can do that? Are we avoiding potential compiler troubles?

> > +static void arm_smmu_dump_event(struct arm_smmu_device *smmu,
> > +                               struct arm_smmu_event *event)
> > +{
> > +       char title[256] = {0};
> > +       char mastr[256] = {0};
> > +       char addrs[256] = {0};
> > +       char flags[256] = {0};
> > +       char other[256] = {0};
> > +
> > +       snprintf(title, 256, "Unexpected event received: %s\n", event_str[event->id]);
> > +       snprintf(mastr, 256, "\tmaster: %s sid: 0x%08x.0x%05x\n",
> > +                event->master_name, event->sid, event->ssid);
> > +
> > +       switch (event->id) {
> > +       case EVT_ID_TRANSLATION_FAULT:
> > +       case EVT_ID_ADDR_SIZE_FAULT:
> > +       case EVT_ID_ACCESS_FAULT:
> > +       case EVT_ID_PERMISSION_FAULT:
> > +               snprintf(addrs, 256, "\tiova = %#llx ipa = %#llx\n", event->iova, event->ipa);
> > +               snprintf(flags, 256, "\t%s%s%s%s%s%s\n",
> > +                               event->privileged ? "Priv |" : "Unpriv |",
> > +                               event->instruction ? " Inst |" : " Data |",
> > +                               event->read ? " Read |" : " Write |",
> 
> Indentations are not matched with the snprintf(mastr line:
> 		snprintf(flags, 256, "\t%s%s%s%s%s%s\n",
> 			 event->privileged ? "Priv |" : "Unpriv |",
> 			 ...
> 

Ack, will fix this in the next version..

> > +                               event->s2 ? "S2|" : "S1|", class_str[event->class],
> 
> The previous flags have spaces: " Inst |", " Read |". So, maybe:
> 			 " S2 |" and " S1 |" here?
> 

Ack. I'm guessing even in the worst case we'd get to 78 chars so adding
a space should be fine?

> > +                               ((event->id == EVT_ID_PERMISSION_FAULT) &&
> > +                                (event->class == EVTQ_1_CLASS_TT)) ?
> > +                                 (FIELD_GET(EVTQ_1_TT_READ, event->raw[1]) ?
> > +                                 "|TTD Read" : "|TTD Write") : "");
> 
> I'd try to avoid that nested ternary. Perhaps:
> 	char ttrnd[32] = {0};
> 	...
> 	case EVT_ID_PERMISSION_FAULT:
> 		if (event->class == EVTQ_1_CLASS_TT) {
> 			snprintf(ttrnd, 256, "%s",
> 				 FIELD_GET(EVTQ_1_TT_READ, event->raw[1]) ?
> 				 " | TTD Read" : " | TTD Write");
> 		}
> 		fallthrough;
> 	case EVT_ID_TRANSLATION_FAULT:
> 	case EVT_ID_ADDR_SIZE_FAULT:
> 	case EVT_ID_ACCESS_FAULT:
> 		snprintf(flags, 256, "\t%s%s%s%s%s%s\n",
> 			 event->privileged ? "Priv |" : "Unpriv |",
> 			 event->instruction ? " Inst |" : " Data |",
> 			 event->read ? " Read |" : " Write |",
> 			 event->s2 ? " S2 |" : " S1 |",
> 			 event_class_str[event->class], ttrnd);
> 

Hmm, I like that idea. I'll add something like this!

> > +               snprintf(other, 256, "\tSTAG = %#x Stall = %#x\n",
> > +                               event->stag, event->stall);
> > +               break;
> > +
> > +       case EVT_ID_STE_FETCH_FAULT:
> > +       case EVT_ID_CD_FETCH_FAULT:
> > +       case EVT_ID_VMS_FETCH_FAULT:
> > +               snprintf(addrs, 256, "\tFetch address: %#llx\n", event->ipa);
> > +               break;
> > +       }
> > +
> > +       dev_err(smmu->dev, "%s%s%s%s%s", title, mastr,
> > +               strlen(addrs) ? addrs : "",
> > +               strlen(flags) ? flags : "",
> > +               strlen(other) ? other : "");
> 
> It looks to me that you init-ed them well, so maybe strlen isn't
> necessary?
> 

True, missed that, will remove this.

> > +
> > +       arm_smmu_dump_raw_event(smmu, event);
> > +}
> 
> I assume these prints would look good, yet, would you please try
> triggering a FAULT to give us a showcase in the commit message?
> 

Sure, let me arrange for a sample FAULT log in the next version!

> > +static void arm_smmu_get_evt_info(struct arm_smmu_device *smmu, u64 *evt,
> > +                                 struct arm_smmu_event *event)
> > +{
> > +       mutex_lock(&smmu->streams_mutex);
> > +       event->master = arm_smmu_find_master(smmu, event->sid);
> > +       mutex_unlock(&smmu->streams_mutex);
> > +
> > +       if (event->master)
> > +               event->master_name = dev_name(event->master->dev);
> > +       else
> > +               event->master_name = "(unassigned sid)";
> 
> Likely safer for dev_name to be in the mutex too.
> 

Ack.

> Thanks
> Nicolin

Thanks,
Pranjal