Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

SGksIEJhcnQNCg0KPm1pbmdvQHJlZGhhZC5jb207IGxpbnV4LWJsb2NrQHZnZXIua2VybmVsLm9y
ZzsgcmFqYXRqYUBnb29nbGUuY29tDQo+U3ViamVjdDogW0VYVF0gUmU6IFtSRVNFTkQgUEFUQ0gg
djEgMS8yXSB0cmFjZTogZXZlbnRzOiBzY3NpOiBBZGQgdGFnIGluIFNDU0kNCj50cmFjZSBldmVu
dHMNCj4NCj5PbiBNb24sIDIwMTgtMDQtMTYgYXQgMTQ6MzEgKzAwMDAsIEJlYW4gSHVvIChiZWFu
aHVvKSB3cm90ZToNCj4+ICAJVFBfcHJpbnRrKCJob3N0X25vPSV1IGNoYW5uZWw9JXUgaWQ9JXUg
bHVuPSV1IGRhdGFfc2dsPSV1DQo+cHJvdF9zZ2w9JXUiIFwNCj4+IC0JCSAgIiBwcm90X29wPSVz
IGNtbmQ9KCVzICVzIHJhdz0lcykiLA0KPj4gKwkJICAiIHByb3Rfb3A9JXMgdGFnPSVkIGNtbmQ9
KCVzICVzIHJhdz0lcykiLA0KPj4NCj4+IFsgLi4uIF0NCj4+ICAJVFBfcHJpbnRrKCJob3N0X25v
PSV1IGNoYW5uZWw9JXUgaWQ9JXUgbHVuPSV1IGRhdGFfc2dsPSV1DQo+cHJvdF9zZ2w9JXUiIFwN
Cj4+IC0JCSAgIiBwcm90X29wPSVzIGNtbmQ9KCVzICVzIHJhdz0lcykgcnRuPSVkIiwNCj4+ICsJ
CSAgIiBwcm90X29wPSVzIHRhZz0lZCBjbW5kPSglcyAlcyByYXc9JXMpIHJ0bj0lZCIsDQo+PiBb
IC4uLiBdDQo+PiAgCVRQX3ByaW50aygiaG9zdF9ubz0ldSBjaGFubmVsPSV1IGlkPSV1IGx1bj0l
dSBkYXRhX3NnbD0ldSAiIFwNCj4+IC0JCSAgInByb3Rfc2dsPSV1IHByb3Rfb3A9JXMgY21uZD0o
JXMgJXMgcmF3PSVzKQ0KPnJlc3VsdD0oZHJpdmVyPSIgXA0KPj4gLQkJICAiJXMgaG9zdD0lcyBt
ZXNzYWdlPSVzIHN0YXR1cz0lcykiLA0KPj4gKwkJICAicHJvdF9zZ2w9JXUgcHJvdF9vcD0lcyB0
YWc9JWQgY21uZD0oJXMgJXMgcmF3PSVzKSAiIFwNCj4+ICsJCSAgInJlc3VsdD0oZHJpdmVyPSVz
IGhvc3Q9JXMgbWVzc2FnZT0lcyBzdGF0dXM9JXMpIiwNCj4NCj5XaGljaCB0b29scyBwcm9jZXNz
IHRoZXNlIHN0cmluZ3M/IEhhcyBpdCBiZWVuIHZlcmlmaWVkIHdoZXRoZXIgb3Igbm90IHRoZQ0K
PnRvb2xzIHRoYXQgcHJvY2VzcyB0aGVzZSBzdHJpbmdzIHN0aWxsIHdvcmsgZmluZSB3aXRoIHRo
aXMgcGF0Y2ggYXBwbGllZD8NCj4gDQoNCkkgZG9uJ3QgdXNlIG9uZSBjZXJ0YWluIHNwZWNpYWwg
dG9vbCB0byBhbmFseXplIHRoaXMgc3RyaW5nLCBJIGFtIHVzaW5nIGZ0cmFjZSB3aXRoIGV2ZW50
Lg0KV2l0aCB0YWcgaW5mb3JtYXRpb24sIEkgY2FuIHNlZSBob3cgbWFueSB0YXNrcyBpbiBzdG9y
YWdlIGRldmljZSBhbmQgZWFzaWx5IHRvIHRyYWNlIGVhY2ggcmVxdWVzdA0KdW5kZXIgbXVsdGlw
bGUgdGhyZWFkIHdvcmtsb2FkLiANCkV2ZW50IHRoZXJlIGlzIHNvbWVvbmUgd2hvIHVzaW5nIGNl
cnRhaW4gdG9vbCB0byBhbmFseXplIHRoaXMgc3RyaW5nLCBhZnRlciBhZGRpbmcgYWRkaXRpb25h
bA0KdGFnIHByaW50b3V0LCBpbiBteSBvcGluaW9uLCB0aGV5IGFyZSBoYXBweSB0byBzZWUgaXQg
dGhlcmUuIA0KDQpBZ2FpbiwgeW91IHNhaWQgaWYgd2UgYWRkIG5ldyBmZWF0dXJlIGluIGxlZ2Fj
eSBibG9jaywgd2Ugd2lsbCBhbHNvIGFkZCBuZXcgZmVhdHVyZSBpbiBibGstbXEuDQpJIHN0aWxs
IGRvbid0IHVuZGVyc3RhbmQgaGVyZS4gICJpbmNsdWRlL3RyYWNlL2V2ZW50L2Jsb2NrLmggLi4u
IHNjc2kuaCIgd2lsbCBiZSBjaGFuZ2VkPw0KSWYgeWVzLCBob3c/IEJlY2F1c2UgYmxrLW1xIGlz
IHN0aWxsIHVzaW5nIHRoZSBldmVudHMgZGVmaW5lZCBpbiBpbmNsdWRlL3RyYWNlL2V2ZW50L2Js
b2NrLmguDQoNCkJlYW4gSHVvDQoNCj5UaGFua3MsDQo+DQo+QmFydC4NCj4NCg0K

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

Hi, Bart

>mingo@redhad.com; linux-block@vger.kernel.org; rajatja@google.com
>Subject: [EXT] Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI
>trace events
>
>On Mon, 2018-04-16 at 14:31 +0000, Bean Huo (beanhuo) wrote:
>>  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u
>prot_sgl=%u" \
>> -		  " prot_op=%s cmnd=(%s %s raw=%s)",
>> +		  " prot_op=%s tag=%d cmnd=(%s %s raw=%s)",
>>
>> [ ... ]
>>  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u
>prot_sgl=%u" \
>> -		  " prot_op=%s cmnd=(%s %s raw=%s) rtn=%d",
>> +		  " prot_op=%s tag=%d cmnd=(%s %s raw=%s) rtn=%d",
>> [ ... ]
>>  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u " \
>> -		  "prot_sgl=%u prot_op=%s cmnd=(%s %s raw=%s)
>result=(driver=" \
>> -		  "%s host=%s message=%s status=%s)",
>> +		  "prot_sgl=%u prot_op=%s tag=%d cmnd=(%s %s raw=%s) " \
>> +		  "result=(driver=%s host=%s message=%s status=%s)",
>
>Which tools process these strings? Has it been verified whether or not the
>tools that process these strings still work fine with this patch applied?
> 

I don't use one certain special tool to analyze this string, I am using ftrace with event.
With tag information, I can see how many tasks in storage device and easily to trace each request
under multiple thread workload. 
Event there is someone who using certain tool to analyze this string, after adding additional
tag printout, in my opinion, they are happy to see it there. 

Again, you said if we add new feature in legacy block, we will also add new feature in blk-mq.
I still don't understand here.  "include/trace/event/block.h ... scsi.h" will be changed?
If yes, how? Because blk-mq is still using the events defined in include/trace/event/block.h.

Bean Huo

>Thanks,
>
>Bart.
>

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

T24gTW9uLCAyMDE4LTA0LTE2IGF0IDIxOjEwICswMDAwLCBCZWFuIEh1byAoYmVhbmh1bykgd3Jv
dGU6DQo+IEhpLCBCYXJ0DQo+IA0KPiA+IG1pbmdvQHJlZGhhZC5jb207IGxpbnV4LWJsb2NrQHZn
ZXIua2VybmVsLm9yZzsgcmFqYXRqYUBnb29nbGUuY29tDQo+ID4gU3ViamVjdDogW0VYVF0gUmU6
IFtSRVNFTkQgUEFUQ0ggdjEgMS8yXSB0cmFjZTogZXZlbnRzOiBzY3NpOiBBZGQgdGFnIGluIFND
U0kNCj4gPiB0cmFjZSBldmVudHMNCj4gPiANCj4gPiBPbiBNb24sIDIwMTgtMDQtMTYgYXQgMTQ6
MzEgKzAwMDAsIEJlYW4gSHVvIChiZWFuaHVvKSB3cm90ZToNCj4gPiA+ICAJVFBfcHJpbnRrKCJo
b3N0X25vPSV1IGNoYW5uZWw9JXUgaWQ9JXUgbHVuPSV1IGRhdGFfc2dsPSV1DQo+ID4gDQo+ID4g
cHJvdF9zZ2w9JXUiIFwNCj4gPiA+IC0JCSAgIiBwcm90X29wPSVzIGNtbmQ9KCVzICVzIHJhdz0l
cykiLA0KPiA+ID4gKwkJICAiIHByb3Rfb3A9JXMgdGFnPSVkIGNtbmQ9KCVzICVzIHJhdz0lcyki
LA0KPiA+ID4gDQo+ID4gPiBbIC4uLiBdDQo+ID4gPiAgCVRQX3ByaW50aygiaG9zdF9ubz0ldSBj
aGFubmVsPSV1IGlkPSV1IGx1bj0ldSBkYXRhX3NnbD0ldQ0KPiA+IA0KPiA+IHByb3Rfc2dsPSV1
IiBcDQo+ID4gPiAtCQkgICIgcHJvdF9vcD0lcyBjbW5kPSglcyAlcyByYXc9JXMpIHJ0bj0lZCIs
DQo+ID4gPiArCQkgICIgcHJvdF9vcD0lcyB0YWc9JWQgY21uZD0oJXMgJXMgcmF3PSVzKSBydG49
JWQiLA0KPiA+ID4gWyAuLi4gXQ0KPiA+ID4gIAlUUF9wcmludGsoImhvc3Rfbm89JXUgY2hhbm5l
bD0ldSBpZD0ldSBsdW49JXUgZGF0YV9zZ2w9JXUgIiBcDQo+ID4gPiAtCQkgICJwcm90X3NnbD0l
dSBwcm90X29wPSVzIGNtbmQ9KCVzICVzIHJhdz0lcykNCj4gPiANCj4gPiByZXN1bHQ9KGRyaXZl
cj0iIFwNCj4gPiA+IC0JCSAgIiVzIGhvc3Q9JXMgbWVzc2FnZT0lcyBzdGF0dXM9JXMpIiwNCj4g
PiA+ICsJCSAgInByb3Rfc2dsPSV1IHByb3Rfb3A9JXMgdGFnPSVkIGNtbmQ9KCVzICVzIHJhdz0l
cykgIiBcDQo+ID4gPiArCQkgICJyZXN1bHQ9KGRyaXZlcj0lcyBob3N0PSVzIG1lc3NhZ2U9JXMg
c3RhdHVzPSVzKSIsDQo+ID4gDQo+ID4gV2hpY2ggdG9vbHMgcHJvY2VzcyB0aGVzZSBzdHJpbmdz
PyBIYXMgaXQgYmVlbiB2ZXJpZmllZCB3aGV0aGVyIG9yIG5vdCB0aGUNCj4gPiB0b29scyB0aGF0
IHByb2Nlc3MgdGhlc2Ugc3RyaW5ncyBzdGlsbCB3b3JrIGZpbmUgd2l0aCB0aGlzIHBhdGNoIGFw
cGxpZWQ/DQo+ID4gDQo+IA0KPiBJIGRvbid0IHVzZSBvbmUgY2VydGFpbiBzcGVjaWFsIHRvb2wg
dG8gYW5hbHl6ZSB0aGlzIHN0cmluZywgSSBhbSB1c2luZyBmdHJhY2Ugd2l0aCBldmVudC4NCj4g
V2l0aCB0YWcgaW5mb3JtYXRpb24sIEkgY2FuIHNlZSBob3cgbWFueSB0YXNrcyBpbiBzdG9yYWdl
IGRldmljZSBhbmQgZWFzaWx5IHRvIHRyYWNlIGVhY2ggcmVxdWVzdA0KPiB1bmRlciBtdWx0aXBs
ZSB0aHJlYWQgd29ya2xvYWQuIA0KPiBFdmVudCB0aGVyZSBpcyBzb21lb25lIHdobyB1c2luZyBj
ZXJ0YWluIHRvb2wgdG8gYW5hbHl6ZSB0aGlzIHN0cmluZywgYWZ0ZXIgYWRkaW5nIGFkZGl0aW9u
YWwNCj4gdGFnIHByaW50b3V0LCBpbiBteSBvcGluaW9uLCB0aGV5IGFyZSBoYXBweSB0byBzZWUg
aXQgdGhlcmUuIA0KDQpTaW5jZSB5b3Ugd2FudCB0byBjaGFuZ2UgdGhlc2Ugc3RyaW5ncyBpdCBp
cyB5b3VyIGpvYiB0byBkZXRlcm1pbmUgd2hpY2gNCnVzZXIgc3BhY2UgdG9vbHMgcGFyc2UgdGhl
c2Ugc3RyaW5ncyBhbmQgYWxzbyB3aGV0aGVyIG9yIG5vdCB0aGlzIGNoYW5nZQ0Kd2lsbCBicmVh
ayBhbnkgb2YgdGhlc2UgdG9vbHMuDQoNClRoYW5rcywNCg0KQmFydC4NCg0KDQoNCg==

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

On Mon, 2018-04-16 at 21:10 +0000, Bean Huo (beanhuo) wrote:
> Hi, Bart
> 
> > mingo@redhad.com; linux-block@vger.kernel.org; rajatja@google.com
> > Subject: [EXT] Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI
> > trace events
> > 
> > On Mon, 2018-04-16 at 14:31 +0000, Bean Huo (beanhuo) wrote:
> > >  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u
> > 
> > prot_sgl=%u" \
> > > -		  " prot_op=%s cmnd=(%s %s raw=%s)",
> > > +		  " prot_op=%s tag=%d cmnd=(%s %s raw=%s)",
> > > 
> > > [ ... ]
> > >  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u
> > 
> > prot_sgl=%u" \
> > > -		  " prot_op=%s cmnd=(%s %s raw=%s) rtn=%d",
> > > +		  " prot_op=%s tag=%d cmnd=(%s %s raw=%s) rtn=%d",
> > > [ ... ]
> > >  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u " \
> > > -		  "prot_sgl=%u prot_op=%s cmnd=(%s %s raw=%s)
> > 
> > result=(driver=" \
> > > -		  "%s host=%s message=%s status=%s)",
> > > +		  "prot_sgl=%u prot_op=%s tag=%d cmnd=(%s %s raw=%s) " \
> > > +		  "result=(driver=%s host=%s message=%s status=%s)",
> > 
> > Which tools process these strings? Has it been verified whether or not the
> > tools that process these strings still work fine with this patch applied?
> > 
> 
> I don't use one certain special tool to analyze this string, I am using ftrace with event.
> With tag information, I can see how many tasks in storage device and easily to trace each request
> under multiple thread workload. 
> Event there is someone who using certain tool to analyze this string, after adding additional
> tag printout, in my opinion, they are happy to see it there. 

Since you want to change these strings it is your job to determine which
user space tools parse these strings and also whether or not this change
will break any of these tools.

Thanks,

Bart.

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Steffen Maier]

On 04/17/2018 12:00 PM, Bean Huo (beanhuo) wrote:

> #Cat trace
> iozone-4055  [000] ....   665.039276: block_unplug: [iozone] 1 Sync
> iozone-4055  [000] ...1   665.039278: block_rq_insert: 8,48 WS 0 () 396=
04352 + 128 tag=3D18 [iozone]
> iozone-4055  [000] ...1   665.039280: block_rq_issue: 8,48 WS 0 () 3960=
4352 + 128 tag=3D18 [iozone]
> iozone-4055  [000] ...1   665.039284: scsi_dispatch_cmd_start: host_no=3D=
0 channel=3D0 id=3D0 lun=3D3 data_sgl=3D16 prot_sgl=3D0 prot_op=3DSCSI_PR=
OT_NORMAL tag=3D18 cmnd=3D(WRITE_10 lba=3D4950544 txlen=3D16 protect=3D0 =
raw=3D2a 00 00 4b 8a 10 00 00 10 00)
> iozone-4056  [002] ....   665.039284: block_dirty_buffer: 8,62 sector=3D=
44375 size=3D4096
> <idle>-0     [000] d.h2   665.039319: scsi_dispatch_cmd_done: host_no=3D=
0 channel=3D0 id=3D0 lun=3D3 data_sgl=3D16 prot_sgl=3D0 prot_op=3DSCSI_PR=
OT_NORMAL tag=3D24 cmnd=3D(WRITE_10 lba=3D4944016 txlen=3D16 protect=3D0 =
raw=3D2a 00 00 4b 70 90 00 00 10 00) result=3D(driver=3DDRIVER_OK host=3D=
DID_OK message=3DCOMMAND_COMPLETE status=3DSAM_STAT_GOOD)
> <idle>-0     [000] d.h3   665.039321: block_rq_complete: 8,48 WS () 395=
52128 + 128 tag=3D24 [0]

> iozone-4058  [003] ....   665.039362: block_bio_remap: 8,48 WS 39568768=
 + 128 <- (8,62) 337280
> iozone-4058  [003] ....   665.039364: block_bio_queue: 8,48 WS 39568768=
 + 128 [iozone]
> iozone-4058  [003] ...1   665.039366: block_getrq: 8,48 WS 39568768 + 1=
28 [iozone]

I'm not familiar with block/scsi command tagging.

Some block events now would get a tag field.
Some block events would not get a tag field (maybe because for some the=20
tag is not (yet) known).

So all block events that belong to the same request would still need to=20
be correlated by something like (devt, RWBS, LBA, length) because not=20
all have a tag field.

> Especially, the ftrace log with tag information, I can easily figure ou=
t one I/O request between block layer and SCSI.

Provided this is done correctly, I would be in favor of a solution.
Since
v4.11 commit 48b77ad60844 (``block: cleanup tracing'')\newline
v4.11 commit 82ed4db499b8 (``block: split scsi\_request out of struct=20
request'')
we don't have the SCSI CDB in block traces (nor in blktrace traditional=20
relayfs trace format, nor in ftrace 'blk' tracer binary synthesized=20
output [1]) any more (empty Packet Command payload).
Being able to correlate block events with scsi events would indeed be=20
very helpful for some cases.

Is a correlation between block and scsi only necessary for these pairs?:

block_rq_issue causes scsi_dispatch_cmd_start, and
scsi_dispatch_cmd_done causes block_rq_complete.

If so, only those two block trace events would need to get a new field?


[1] v2.6.30 commit 08a06b83ff8b (``blkftrace: binary tracing,=20
synthesizing old format'')
     v2.6.31 commit f3948f8857ef (``blktrace: fix context-info when=20
mixed-using blk tracer and trace events'')

--=20
Mit freundlichen Gr=C3=BC=C3=9Fen / Kind regards
Steffen Maier

Linux on z Systems Development

IBM Deutschland Research & Development GmbH
Vorsitzende des Aufsichtsrats: Martina Koederitz
Geschaeftsfuehrung: Dirk Wittkopp
Sitz der Gesellschaft: Boeblingen
Registergericht: Amtsgericht Stuttgart, HRB 243294

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Steffen Maier]

On 04/17/2018 12:00 PM, Bean Huo (beanhuo) wrote:

> #Cat trace
> iozone-4055  [000] ....   665.039276: block_unplug: [iozone] 1 Sync
> iozone-4055  [000] ...1   665.039278: block_rq_insert: 8,48 WS 0 () 39604352 + 128 tag=18 [iozone]
> iozone-4055  [000] ...1   665.039280: block_rq_issue: 8,48 WS 0 () 39604352 + 128 tag=18 [iozone]
> iozone-4055  [000] ...1   665.039284: scsi_dispatch_cmd_start: host_no=0 channel=0 id=0 lun=3 data_sgl=16 prot_sgl=0 prot_op=SCSI_PROT_NORMAL tag=18 cmnd=(WRITE_10 lba=4950544 txlen=16 protect=0 raw=2a 00 00 4b 8a 10 00 00 10 00)
> iozone-4056  [002] ....   665.039284: block_dirty_buffer: 8,62 sector=44375 size=4096
> <idle>-0     [000] d.h2   665.039319: scsi_dispatch_cmd_done: host_no=0 channel=0 id=0 lun=3 data_sgl=16 prot_sgl=0 prot_op=SCSI_PROT_NORMAL tag=24 cmnd=(WRITE_10 lba=4944016 txlen=16 protect=0 raw=2a 00 00 4b 70 90 00 00 10 00) result=(driver=DRIVER_OK host=DID_OK message=COMMAND_COMPLETE status=SAM_STAT_GOOD)
> <idle>-0     [000] d.h3   665.039321: block_rq_complete: 8,48 WS () 39552128 + 128 tag=24 [0]

> iozone-4058  [003] ....   665.039362: block_bio_remap: 8,48 WS 39568768 + 128 <- (8,62) 337280
> iozone-4058  [003] ....   665.039364: block_bio_queue: 8,48 WS 39568768 + 128 [iozone]
> iozone-4058  [003] ...1   665.039366: block_getrq: 8,48 WS 39568768 + 128 [iozone]

I'm not familiar with block/scsi command tagging.

Some block events now would get a tag field.
Some block events would not get a tag field (maybe because for some the 
tag is not (yet) known).

So all block events that belong to the same request would still need to 
be correlated by something like (devt, RWBS, LBA, length) because not 
all have a tag field.

> Especially, the ftrace log with tag information, I can easily figure out one I/O request between block layer and SCSI.

Provided this is done correctly, I would be in favor of a solution.
Since
v4.11 commit 48b77ad60844 (``block: cleanup tracing'')\newline
v4.11 commit 82ed4db499b8 (``block: split scsi\_request out of struct 
request'')
we don't have the SCSI CDB in block traces (nor in blktrace traditional 
relayfs trace format, nor in ftrace 'blk' tracer binary synthesized 
output [1]) any more (empty Packet Command payload).
Being able to correlate block events with scsi events would indeed be 
very helpful for some cases.

Is a correlation between block and scsi only necessary for these pairs?:

block_rq_issue causes scsi_dispatch_cmd_start, and
scsi_dispatch_cmd_done causes block_rq_complete.

If so, only those two block trace events would need to get a new field?


[1] v2.6.30 commit 08a06b83ff8b (``blkftrace: binary tracing, 
synthesizing old format'')
     v2.6.31 commit f3948f8857ef (``blktrace: fix context-info when 
mixed-using blk tracer and trace events'')

-- 
Mit freundlichen Grüßen / Kind regards
Steffen Maier

Linux on z Systems Development

IBM Deutschland Research & Development GmbH
Vorsitzende des Aufsichtsrats: Martina Koederitz
Geschaeftsfuehrung: Dirk Wittkopp
Sitz der Gesellschaft: Boeblingen
Registergericht: Amtsgericht Stuttgart, HRB 243294

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

Pk9uIE1vbiwgMjAxOC0wNC0xNiBhdCAyMDoyNyArMDAwMCwgQmVhbiBIdW8gKGJlYW5odW8pIHdy
b3RlOg0KPj4gQnkgdGhlIHdheSwgdGhlc2UgcGF0Y2hlcyBhcmUgbm90IHRvIGFkZCBuZXcgZmVh
dHVyZSwgdGhleSBhcmUganVzdCB0bw0KPj4gYWRkIHByaW50IHRhZyBhbG9uZyB3aXRoIHRoZSBv
dGhlciBleGlzdCBwcmludGVkIHJlcXVlc3QgcGFyYW1ldGVycy4NCj4NCj5BcmUgeW91IGF3YXJl
IHRoYXQgdGhlcmUgYXJlIHR3byB0YWcgZmllbGRzIGluIHN0cnVjdCByZXF1ZXN0LCBuYW1lbHkg
InRhZyINCj5hbmQgImludGVybmFsX3RhZyI/IEFyZSB5b3UgYXdhcmUgdGhhdCBob3cgdGhlc2Ug
ZmllbGRzIGFyZSB1c2VkIGRlcGVuZHMgb24NCj53aGV0aGVyIG9yIG5vdCBhIHNjaGVkdWxlciBp
cyBhdHRhY2hlZCB0byBhIHJlcXVlc3QgcXVldWU/IEhhdmUgeW91IHZlcmlmaWVkDQo+dGhhdCB0
aGUgInRhZyIgZmllbGQgY29udGFpbnMgYSBtZWFuaW5nZnVsIHZhbHVlIGZvciBibGstbXEgZm9y
IGV2ZXJ5IGJsay1tcQ0KPnRyYWNlcG9pbnQ/DQo+DQo+VGhhbmtzLA0KPg0KPkJhcnQuDQo+DQo+
DQpZZXMsIEkgbm90aWNlZCBhbmQgd2FzIGF3YXJlLCB0aGVyZSBhcmUgdGFnIGFuZCBpbnRlcm5h
bF90YWcuDQpPbmUgdGhpbmcgSSB3YXMgbm90IGF3YXJlIGlzIHRoYXQgdGhlIHBhdGNoZXMgd291
bGQgbWFrZSBzdWNoIGEgYmlnIGltcGFjdCBvbiBibGstbXEgYmFzZWQgb24NCllvdXIgY29tbWVu
dHMuDQoNCkkgYW0gbm90IGV4cGVydCBvbiBibG9jayBsYXllciwgdGhhdCBpcyB3aHkgSSBhZGRl
ZCBibG9jayBtYWludGFpbmVyIGhlcmUuDQpQbGVhc2UgcG9pbnQgb3V0IHdoaWNoIGxpbmUgYW5k
IHdoYXQgaXMgcHJvYmxlbT8gSWYgdGhlcmUgaXMgc29tZSB3cm9uZyB3aXRoIHRoZSBwYXRjaC4N
CldoaWNoIG9uZSBpcyBjb3JyZWN0ICJ0YWciIHRvIHRyYWNrIHJlcXVlc3Q/IA0KDQpUaGFua3Ms
DQovL0JlYW4gSHVvDQo=

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

>On Mon, 2018-04-16 at 20:27 +0000, Bean Huo (beanhuo) wrote:
>> By the way, these patches are not to add new feature, they are just to
>> add print tag along with the other exist printed request parameters.
>
>Are you aware that there are two tag fields in struct request, namely "tag"
>and "internal_tag"? Are you aware that how these fields are used depends on
>whether or not a scheduler is attached to a request queue? Have you verified
>that the "tag" field contains a meaningful value for blk-mq for every blk-mq
>tracepoint?
>
>Thanks,
>
>Bart.
>
>
Yes, I noticed and was aware, there are tag and internal_tag.
One thing I was not aware is that the patches would make such a big impact on blk-mq based on
Your comments.

I am not expert on block layer, that is why I added block maintainer here.
Please point out which line and what is problem? If there is some wrong with the patch.
Which one is correct "tag" to track request? 

Thanks,
//Bean Huo

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

Hi, Steve=20
Right, Please see below portion log from ftrace and blktrace,
There is no any impact on blktrace.=20
>
>Looking at the code from
>git://git.kernel.org/pub/scm/linux/kernel/git/axboe/blktrace.git
>
>It appears that it does not rely on the ftrace ring buffers.
>
>So I'm guessing blktrace is not affected by this patch.
>
>-- Steve


#/blktrace -d /dev/block/sdd14 -o - | ./blkparse -i - =20
  8,62   3     1162     0.213039583  4116  P   N [iozone]
  8,62   3     1163     0.213041146  4116  U   N [iozone] 1
  8,62   3     1164     0.213042708  4116  I  WS 39573632 + 128 [iozone]
  8,62   3     1165     0.213044791  4116  D  WS 39573632 + 128 [iozone]
  8,48   3     1166     0.213585416  4116  A  WS 39573760 + 128 <- (8,62) 3=
42272
  8,62   3     1167     0.213590104  4116  Q  WS 39573760 + 128 [iozone]
  8,62   3     1168     0.213592187  4116  G  WS 39573760 + 128 [iozone]
  8,62   3     1169     0.213594271  4116  P   N [iozone]
  8,62   3     1170     0.213595833  4116  U   N [iozone] 1
  8,62   3     1171     0.213597396  4116  I  WS 39573760 + 128 [iozone]
  8,62   3     1172     0.213600000  4116  D  WS 39573760 + 128 [iozone]
  8,48   3     1173     0.214092187  4116  A  WS 39573888 + 128 <- (8,62) 3=
42400
  8,62   3     1174     0.214094791  4116  Q  WS 39573888 + 128 [iozone]
  8,62   3     1175     0.214097916  4116  G  WS 39573888 + 128 [iozone]
  8,62   3     1176     0.214102604  4116  P   N [iozone]
  8,62   3     1177     0.214105208  4116  U   N [iozone] 1
  8,62   3     1178     0.214106771  4116  I  WS 39573888 + 128 [iozone]
  8,62   3     1179     0.214111458  4116  D  WS 39573888 + 128 [iozone]
  8,48   3     1180     0.216531771  4115  A  WS 39546496 + 128 <- (8,62) 3=
15008
  8,62   3     1181     0.216534896  4115  Q  WS 39546496 + 128 [iozone]
  8,62   3     1182     0.216538021  4115  G  WS 39546496 + 128 [iozone]
  8,62   3     1183     0.216540625  4115  P   N [iozone]
  8,62   3     1184     0.216543229  4115  U   N [iozone] 1
  8,62   3     1185     0.216544791  4115  I  WS 39546496 + 128 [iozone]
  8,62   3     1186     0.216547396  4115  D  WS 39546496 + 128 [iozone]
  8,48   3     1187     0.217146354  4115  A  WS 39546624 + 128 <- (8,62) 3=
15136
  8,62   3     1188     0.217148437  4115  Q  WS 39546624 + 128 [iozone]
  8,62   3     1189     0.217151041  4115  G  WS 39546624 + 128 [iozone]
  8,62   3     1190     0.217153646  4115  P   N [iozone]
  8,62   3     1191     0.217155208  4115  U   N [iozone] 1
  8,62   3     1192     0.217156771  4115  I  WS 39546624 + 128 [iozone]
  8,62   3     1193     0.217159896  4115  D  WS 39546624 + 128 [iozone]
  8,48   3     1194     0.217712500  4115  A  WS 39546752 + 128 <- (8,62) 3=
15264
  8,62   3     1195     0.217714583  4115  Q  WS 39546752 + 128 [iozone]
  8,62   3     1196     0.217717708  4115  G  WS 39546752 + 128 [iozone]
  8,62   3     1197     0.217722396  4115  P   N [iozone]
  8,62   3     1198     0.217724479  4115  U   N [iozone] 1
  8,62   3     1199     0.217726041  4115  I  WS 39546752 + 128 [iozone]
  8,62   3     1200     0.217728646  4115  D  WS 39546752 + 128 [iozone]
  8,62   5     1150     0.198047916     0  C  WS 39569920 + 128 [0]
  8,62   4     1104     0.198104687     0  C  WS 39576448 + 128 [0]
  8,48   5     1151     0.198182291  4116  A  WS 39570048 + 128 <- (8,62) 3=
38560
  8,62   5     1152     0.198183333  4116  Q  WS 39570048 + 128 [iozone]
  8,62   5     1153     0.198184375  4116  G  WS 39570048 + 128 [iozone]
  8,62   5     1154     0.198185937  4116  P   N [iozone]
  8,62   5     1155     0.198186458  4116  U   N [iozone] 1
  8,62   5     1156     0.198186979  4116  I  WS 39570048 + 128 [iozone]
  8,62   5     1157     0.198188541  4116  D  WS 39570048 + 128 [iozone]
  8,48   4     1105     0.198218229  4114  A  WS 39576576 + 128 <- (8,62) 3=
45088
  8,62   4     1106     0.198219271  4114  Q  WS 39576576 + 128 [iozone]
  8,62   4     1107     0.198220312  4114  G  WS 39576576 + 128 [iozone]
  8,62   4     1108     0.198221354  4114  P   N [iozone]
  8,62   4     1109     0.198221875  4114  U   N [iozone] 1
  8,62   4     1110     0.198222396  4114  I  WS 39576576 + 128 [iozone]
  8,62   4     1111     0.198223437  4114  D  WS 39576576 + 128 [iozone]
  8,62   4     1112     0.198245312  4114  C  WS 39594368 + 128 [0]
  8,62   5     1158     0.198336979     0  C  WS 39570048 + 128 [0]
  8,62   4     1113     0.198409375     0  C  WS 39576576 + 128 [0]
  8,48   5     1159     0.199219791  4113  A  WS 39594624 + 128 <- (8,62) 3=
63136
  8,62   5     1160     0.199220833  4113  Q  WS 39594624 + 128 [iozone]
  8,62   5     1161     0.199222396  4113  G  WS 39594624 + 128 [iozone]
  8,62   5     1162     0.199223437  4113  P   N [iozone]
  8,62   5     1163     0.199224479  4113  U   N [iozone] 1
  8,62   5     1164     0.199225000  4113  I  WS 39594624 + 128 [iozone]
  8,62   5     1165     0.199226562  4113  D  WS 39594624 + 128 [iozone]
  8,48   4     1114     0.199235937  4116  A  WS 39570176 + 128 <- (8,62) 3=
38688
  8,62   4     1115     0.199236979  4116  Q  WS 39570176 + 128 [iozone]
  8,62   4     1116     0.199238021  4116  G  WS 39570176 + 128 [iozone]
  8,62   4     1117     0.199239062  4116  P   N [iozone]
  8,62   4     1118     0.199239583  4116  U   N [iozone] 1
  8,62   4     1119     0.199240104  4116  I  WS 39570176 + 128 [iozone]
  8,62   4     1120     0.199241666  4116  D  WS 39570176 + 128 [iozone]
  8,62   4     1121     0.199404687     0  C  WS 39570176 + 128 [0]
  8,62   5     1166     0.199467187     0  C  WS 39594624 + 128 [0]
  8,48   5     1167     0.199960416  4113  A  WS 39594752 + 128 <- (8,62) 3=
63264
  8,62   5     1168     0.199960937  4113  Q  WS 39594752 + 128 [iozone]
  8,62   5     1169     0.199961979  4113  G  WS 39594752 + 128 [iozone]
  8,62   5     1170     0.199963541  4113  P   N [iozone]
  8,62   5     1171     0.199964062  4113  U   N [iozone] 1
  8,62   5     1172     0.199964583  4113  I  WS 39594752 + 128 [iozone]
  8,62   5     1173     0.199966146  4113  D  WS 39594752 + 128 [iozone]
  8,48   4     1122     0.199970833  4116  A  WS 39570304 + 128 <- (8,62) 3=
38816
  8,62   4     1123     0.199971875  4116  Q  WS 39570304 + 128 [iozone]
  8,62   4     1124     0.199972916  4116  G  WS 39570304 + 128 [iozone]
  8,62   4     1125     0.199973958  4116  P   N [iozone]
  8,62   4     1126     0.199974479  4116  U   N [iozone] 1

#Cat trace
iozone-4055  [000] ....   665.039276: block_unplug: [iozone] 1 Sync
iozone-4055  [000] ...1   665.039278: block_rq_insert: 8,48 WS 0 () 3960435=
2 + 128 tag=3D18 [iozone]
iozone-4055  [000] ...1   665.039280: block_rq_issue: 8,48 WS 0 () 39604352=
 + 128 tag=3D18 [iozone]
iozone-4055  [000] ...1   665.039284: scsi_dispatch_cmd_start: host_no=3D0 =
channel=3D0 id=3D0 lun=3D3 data_sgl=3D16 prot_sgl=3D0 prot_op=3DSCSI_PROT_N=
ORMAL tag=3D18 cmnd=3D(WRITE_10 lba=3D4950544 txlen=3D16 protect=3D0 raw=3D=
2a 00 00 4b 8a 10 00 00 10 00)
iozone-4056  [002] ....   665.039284: block_dirty_buffer: 8,62 sector=3D443=
75 size=3D4096
<idle>-0     [000] d.h2   665.039319: scsi_dispatch_cmd_done: host_no=3D0 c=
hannel=3D0 id=3D0 lun=3D3 data_sgl=3D16 prot_sgl=3D0 prot_op=3DSCSI_PROT_NO=
RMAL tag=3D24 cmnd=3D(WRITE_10 lba=3D4944016 txlen=3D16 protect=3D0 raw=3D2=
a 00 00 4b 70 90 00 00 10 00) result=3D(driver=3DDRIVER_OK host=3DDID_OK me=
ssage=3DCOMMAND_COMPLETE status=3DSAM_STAT_GOOD)
<idle>-0     [000] d.h3   665.039321: block_rq_complete: 8,48 WS () 3955212=
8 + 128 tag=3D24 [0]
iozone-4056  [002] ....   665.039325: block_dirty_buffer: 8,62 sector=3D443=
80 size=3D4096
iozone-4058  [003] ....   665.039362: block_bio_remap: 8,48 WS 39568768 + 1=
28 <- (8,62) 337280
iozone-4058  [003] ....   665.039364: block_bio_queue: 8,48 WS 39568768 + 1=
28 [iozone]
iozone-4058  [003] ...1   665.039366: block_getrq: 8,48 WS 39568768 + 128 [=
iozone]
iozone-4058  [003] ...1   665.039368: block_plug: [iozone]
iozone-4058  [003] ....   665.039369: block_unplug: [iozone] 1 Sync
iozone-4058  [003] ...1   665.039371: block_rq_insert: 8,48 WS 0 () 3956876=
8 + 128 tag=3D16 [iozone]
iozone-4058  [003] ...1   665.039373: block_rq_issue: 8,48 WS 0 () 39568768=
 + 128 tag=3D16 [iozone]
iozone-4058  [003] ...1   665.039375: scsi_dispatch_cmd_start: host_no=3D0 =
channel=3D0 id=3D0 lun=3D3 data_sgl=3D16 prot_sgl=3D0 prot_op=3DSCSI_PROT_N=
ORMAL tag=3D16 cmnd=3D(WRITE_10 lba=3D4946096 txlen=3D16 protect=3D0 raw=3D=
2a 00 00 4b 78 b0 00 00 10 00)
iozone-4057  [001] ....   665.039402: block_touch_buffer: 8,62 sector=3D103=
4 size=3D4096
<idle>-0     [000] d.h2   665.039410: scsi_dispatch_cmd_done: host_no=3D0 c=
hannel=3D0 id=3D0 lun=3D3 data_sgl=3D16 prot_sgl=3D0 prot_op=3DSCSI_PROT_NO=
RMAL tag=3D18 cmnd=3D(WRITE_10 lba=3D4950544 txlen=3D16 protect=3D0 raw=3D2=
a 00 00 4b 8a 10 00 00 10 00) result=3D(driver=3DDRIVER_OK host=3DDID_OK me=
ssage=3DCOMMAND_COMPLETE status=3DSAM_STAT_GOOD)
<idle>-0     [000] d.h3   665.039412: block_rq_complete: 8,48 WS () 3960435=
2 + 128 tag=3D18 [0]
iozone-4057  [001] ....   665.039415: block_dirty_buffer: 8,62 sector=3D400=
96 size=3D4096
iozone-4056  [002] ....   665.039425: block_bio_remap: 8,48 WS 39586432 + 1=
28 <- (8,62) 354944
iozone-4056  [002] ....   665.039427: block_bio_queue: 8,48 WS 39586432 + 1=
28 [iozone]
iozone-4057  [001] ....   665.039427: block_dirty_buffer: 8,62 sector=3D400=
97 size=3D4096
iozone-4056  [002] ...1   665.039430: block_getrq: 8,48 WS 39586432 + 128 [=
iozone]
iozone-4056  [002] ...1   665.039432: block_plug: [iozone]
iozone-4056  [002] ....   665.039434: block_unplug: [iozone] 1 Sync
iozone-4056  [002] ...1   665.039435: block_rq_insert: 8,48 WS 0 () 3958643=
2 + 128 tag=3D30 [iozone]
iozone-4057  [001] ....   665.039437: block_dirty_buffer: 8,62 sector=3D400=
98 size=3D4096
iozone-4056  [002] ...1   665.039437: block_rq_issue: 8,48 WS 0 () 39586432=
 + 128 tag=3D30 [iozone]
iozone-4056  [002] ...1   665.039439: scsi_dispatch_cmd_start: host_no=3D0 =
channel=3D0 id=3D0 lun=3D3 data_sgl=3D16 prot_sgl=3D0 prot_op=3DSCSI_PROT_N=
ORMAL tag=3D30 cmnd=3D(WRITE_10 lba=3D4948304 txlen=3D16 protect=3D0 raw=3D=
2a 00 00 4b 81 50 00 00 10 00)

Especially, the ftrace log with tag information, I can easily figure out on=
e I/O request between block layer and SCSI.

//Bean Huo

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

Hi, Steve 
Right, Please see below portion log from ftrace and blktrace,
There is no any impact on blktrace. 
>
>Looking at the code from
>git://git.kernel.org/pub/scm/linux/kernel/git/axboe/blktrace.git
>
>It appears that it does not rely on the ftrace ring buffers.
>
>So I'm guessing blktrace is not affected by this patch.
>
>-- Steve


#/blktrace -d /dev/block/sdd14 -o - | ./blkparse -i -  
  8,62   3     1162     0.213039583  4116  P   N [iozone]
  8,62   3     1163     0.213041146  4116  U   N [iozone] 1
  8,62   3     1164     0.213042708  4116  I  WS 39573632 + 128 [iozone]
  8,62   3     1165     0.213044791  4116  D  WS 39573632 + 128 [iozone]
  8,48   3     1166     0.213585416  4116  A  WS 39573760 + 128 <- (8,62) 342272
  8,62   3     1167     0.213590104  4116  Q  WS 39573760 + 128 [iozone]
  8,62   3     1168     0.213592187  4116  G  WS 39573760 + 128 [iozone]
  8,62   3     1169     0.213594271  4116  P   N [iozone]
  8,62   3     1170     0.213595833  4116  U   N [iozone] 1
  8,62   3     1171     0.213597396  4116  I  WS 39573760 + 128 [iozone]
  8,62   3     1172     0.213600000  4116  D  WS 39573760 + 128 [iozone]
  8,48   3     1173     0.214092187  4116  A  WS 39573888 + 128 <- (8,62) 342400
  8,62   3     1174     0.214094791  4116  Q  WS 39573888 + 128 [iozone]
  8,62   3     1175     0.214097916  4116  G  WS 39573888 + 128 [iozone]
  8,62   3     1176     0.214102604  4116  P   N [iozone]
  8,62   3     1177     0.214105208  4116  U   N [iozone] 1
  8,62   3     1178     0.214106771  4116  I  WS 39573888 + 128 [iozone]
  8,62   3     1179     0.214111458  4116  D  WS 39573888 + 128 [iozone]
  8,48   3     1180     0.216531771  4115  A  WS 39546496 + 128 <- (8,62) 315008
  8,62   3     1181     0.216534896  4115  Q  WS 39546496 + 128 [iozone]
  8,62   3     1182     0.216538021  4115  G  WS 39546496 + 128 [iozone]
  8,62   3     1183     0.216540625  4115  P   N [iozone]
  8,62   3     1184     0.216543229  4115  U   N [iozone] 1
  8,62   3     1185     0.216544791  4115  I  WS 39546496 + 128 [iozone]
  8,62   3     1186     0.216547396  4115  D  WS 39546496 + 128 [iozone]
  8,48   3     1187     0.217146354  4115  A  WS 39546624 + 128 <- (8,62) 315136
  8,62   3     1188     0.217148437  4115  Q  WS 39546624 + 128 [iozone]
  8,62   3     1189     0.217151041  4115  G  WS 39546624 + 128 [iozone]
  8,62   3     1190     0.217153646  4115  P   N [iozone]
  8,62   3     1191     0.217155208  4115  U   N [iozone] 1
  8,62   3     1192     0.217156771  4115  I  WS 39546624 + 128 [iozone]
  8,62   3     1193     0.217159896  4115  D  WS 39546624 + 128 [iozone]
  8,48   3     1194     0.217712500  4115  A  WS 39546752 + 128 <- (8,62) 315264
  8,62   3     1195     0.217714583  4115  Q  WS 39546752 + 128 [iozone]
  8,62   3     1196     0.217717708  4115  G  WS 39546752 + 128 [iozone]
  8,62   3     1197     0.217722396  4115  P   N [iozone]
  8,62   3     1198     0.217724479  4115  U   N [iozone] 1
  8,62   3     1199     0.217726041  4115  I  WS 39546752 + 128 [iozone]
  8,62   3     1200     0.217728646  4115  D  WS 39546752 + 128 [iozone]
  8,62   5     1150     0.198047916     0  C  WS 39569920 + 128 [0]
  8,62   4     1104     0.198104687     0  C  WS 39576448 + 128 [0]
  8,48   5     1151     0.198182291  4116  A  WS 39570048 + 128 <- (8,62) 338560
  8,62   5     1152     0.198183333  4116  Q  WS 39570048 + 128 [iozone]
  8,62   5     1153     0.198184375  4116  G  WS 39570048 + 128 [iozone]
  8,62   5     1154     0.198185937  4116  P   N [iozone]
  8,62   5     1155     0.198186458  4116  U   N [iozone] 1
  8,62   5     1156     0.198186979  4116  I  WS 39570048 + 128 [iozone]
  8,62   5     1157     0.198188541  4116  D  WS 39570048 + 128 [iozone]
  8,48   4     1105     0.198218229  4114  A  WS 39576576 + 128 <- (8,62) 345088
  8,62   4     1106     0.198219271  4114  Q  WS 39576576 + 128 [iozone]
  8,62   4     1107     0.198220312  4114  G  WS 39576576 + 128 [iozone]
  8,62   4     1108     0.198221354  4114  P   N [iozone]
  8,62   4     1109     0.198221875  4114  U   N [iozone] 1
  8,62   4     1110     0.198222396  4114  I  WS 39576576 + 128 [iozone]
  8,62   4     1111     0.198223437  4114  D  WS 39576576 + 128 [iozone]
  8,62   4     1112     0.198245312  4114  C  WS 39594368 + 128 [0]
  8,62   5     1158     0.198336979     0  C  WS 39570048 + 128 [0]
  8,62   4     1113     0.198409375     0  C  WS 39576576 + 128 [0]
  8,48   5     1159     0.199219791  4113  A  WS 39594624 + 128 <- (8,62) 363136
  8,62   5     1160     0.199220833  4113  Q  WS 39594624 + 128 [iozone]
  8,62   5     1161     0.199222396  4113  G  WS 39594624 + 128 [iozone]
  8,62   5     1162     0.199223437  4113  P   N [iozone]
  8,62   5     1163     0.199224479  4113  U   N [iozone] 1
  8,62   5     1164     0.199225000  4113  I  WS 39594624 + 128 [iozone]
  8,62   5     1165     0.199226562  4113  D  WS 39594624 + 128 [iozone]
  8,48   4     1114     0.199235937  4116  A  WS 39570176 + 128 <- (8,62) 338688
  8,62   4     1115     0.199236979  4116  Q  WS 39570176 + 128 [iozone]
  8,62   4     1116     0.199238021  4116  G  WS 39570176 + 128 [iozone]
  8,62   4     1117     0.199239062  4116  P   N [iozone]
  8,62   4     1118     0.199239583  4116  U   N [iozone] 1
  8,62   4     1119     0.199240104  4116  I  WS 39570176 + 128 [iozone]
  8,62   4     1120     0.199241666  4116  D  WS 39570176 + 128 [iozone]
  8,62   4     1121     0.199404687     0  C  WS 39570176 + 128 [0]
  8,62   5     1166     0.199467187     0  C  WS 39594624 + 128 [0]
  8,48   5     1167     0.199960416  4113  A  WS 39594752 + 128 <- (8,62) 363264
  8,62   5     1168     0.199960937  4113  Q  WS 39594752 + 128 [iozone]
  8,62   5     1169     0.199961979  4113  G  WS 39594752 + 128 [iozone]
  8,62   5     1170     0.199963541  4113  P   N [iozone]
  8,62   5     1171     0.199964062  4113  U   N [iozone] 1
  8,62   5     1172     0.199964583  4113  I  WS 39594752 + 128 [iozone]
  8,62   5     1173     0.199966146  4113  D  WS 39594752 + 128 [iozone]
  8,48   4     1122     0.199970833  4116  A  WS 39570304 + 128 <- (8,62) 338816
  8,62   4     1123     0.199971875  4116  Q  WS 39570304 + 128 [iozone]
  8,62   4     1124     0.199972916  4116  G  WS 39570304 + 128 [iozone]
  8,62   4     1125     0.199973958  4116  P   N [iozone]
  8,62   4     1126     0.199974479  4116  U   N [iozone] 1

#Cat trace
iozone-4055  [000] ....   665.039276: block_unplug: [iozone] 1 Sync
iozone-4055  [000] ...1   665.039278: block_rq_insert: 8,48 WS 0 () 39604352 + 128 tag=18 [iozone]
iozone-4055  [000] ...1   665.039280: block_rq_issue: 8,48 WS 0 () 39604352 + 128 tag=18 [iozone]
iozone-4055  [000] ...1   665.039284: scsi_dispatch_cmd_start: host_no=0 channel=0 id=0 lun=3 data_sgl=16 prot_sgl=0 prot_op=SCSI_PROT_NORMAL tag=18 cmnd=(WRITE_10 lba=4950544 txlen=16 protect=0 raw=2a 00 00 4b 8a 10 00 00 10 00)
iozone-4056  [002] ....   665.039284: block_dirty_buffer: 8,62 sector=44375 size=4096
<idle>-0     [000] d.h2   665.039319: scsi_dispatch_cmd_done: host_no=0 channel=0 id=0 lun=3 data_sgl=16 prot_sgl=0 prot_op=SCSI_PROT_NORMAL tag=24 cmnd=(WRITE_10 lba=4944016 txlen=16 protect=0 raw=2a 00 00 4b 70 90 00 00 10 00) result=(driver=DRIVER_OK host=DID_OK message=COMMAND_COMPLETE status=SAM_STAT_GOOD)
<idle>-0     [000] d.h3   665.039321: block_rq_complete: 8,48 WS () 39552128 + 128 tag=24 [0]
iozone-4056  [002] ....   665.039325: block_dirty_buffer: 8,62 sector=44380 size=4096
iozone-4058  [003] ....   665.039362: block_bio_remap: 8,48 WS 39568768 + 128 <- (8,62) 337280
iozone-4058  [003] ....   665.039364: block_bio_queue: 8,48 WS 39568768 + 128 [iozone]
iozone-4058  [003] ...1   665.039366: block_getrq: 8,48 WS 39568768 + 128 [iozone]
iozone-4058  [003] ...1   665.039368: block_plug: [iozone]
iozone-4058  [003] ....   665.039369: block_unplug: [iozone] 1 Sync
iozone-4058  [003] ...1   665.039371: block_rq_insert: 8,48 WS 0 () 39568768 + 128 tag=16 [iozone]
iozone-4058  [003] ...1   665.039373: block_rq_issue: 8,48 WS 0 () 39568768 + 128 tag=16 [iozone]
iozone-4058  [003] ...1   665.039375: scsi_dispatch_cmd_start: host_no=0 channel=0 id=0 lun=3 data_sgl=16 prot_sgl=0 prot_op=SCSI_PROT_NORMAL tag=16 cmnd=(WRITE_10 lba=4946096 txlen=16 protect=0 raw=2a 00 00 4b 78 b0 00 00 10 00)
iozone-4057  [001] ....   665.039402: block_touch_buffer: 8,62 sector=1034 size=4096
<idle>-0     [000] d.h2   665.039410: scsi_dispatch_cmd_done: host_no=0 channel=0 id=0 lun=3 data_sgl=16 prot_sgl=0 prot_op=SCSI_PROT_NORMAL tag=18 cmnd=(WRITE_10 lba=4950544 txlen=16 protect=0 raw=2a 00 00 4b 8a 10 00 00 10 00) result=(driver=DRIVER_OK host=DID_OK message=COMMAND_COMPLETE status=SAM_STAT_GOOD)
<idle>-0     [000] d.h3   665.039412: block_rq_complete: 8,48 WS () 39604352 + 128 tag=18 [0]
iozone-4057  [001] ....   665.039415: block_dirty_buffer: 8,62 sector=40096 size=4096
iozone-4056  [002] ....   665.039425: block_bio_remap: 8,48 WS 39586432 + 128 <- (8,62) 354944
iozone-4056  [002] ....   665.039427: block_bio_queue: 8,48 WS 39586432 + 128 [iozone]
iozone-4057  [001] ....   665.039427: block_dirty_buffer: 8,62 sector=40097 size=4096
iozone-4056  [002] ...1   665.039430: block_getrq: 8,48 WS 39586432 + 128 [iozone]
iozone-4056  [002] ...1   665.039432: block_plug: [iozone]
iozone-4056  [002] ....   665.039434: block_unplug: [iozone] 1 Sync
iozone-4056  [002] ...1   665.039435: block_rq_insert: 8,48 WS 0 () 39586432 + 128 tag=30 [iozone]
iozone-4057  [001] ....   665.039437: block_dirty_buffer: 8,62 sector=40098 size=4096
iozone-4056  [002] ...1   665.039437: block_rq_issue: 8,48 WS 0 () 39586432 + 128 tag=30 [iozone]
iozone-4056  [002] ...1   665.039439: scsi_dispatch_cmd_start: host_no=0 channel=0 id=0 lun=3 data_sgl=16 prot_sgl=0 prot_op=SCSI_PROT_NORMAL tag=30 cmnd=(WRITE_10 lba=4948304 txlen=16 protect=0 raw=2a 00 00 4b 81 50 00 00 10 00)

Especially, the ftrace log with tag information, I can easily figure out one I/O request between block layer and SCSI.

//Bean Huo

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Steven Rostedt]

On Mon, 16 Apr 2018 21:30:54 +0000
Bart Van Assche <Bart.VanAssche@wdc.com> wrote:

> Hello Steve,
> 
> The tool I'm most concerned about is blktrace. I'm not sure though how this
> tool receives event data from the block layer core.

Yeah, blktrace is "special", it looks like it registers its callbacks
from the tracepoints, and writes the data to its own relay buffer. As
it's not relying on the output from the tracing directory, additional
fields being added shouldn't affect it.

Looking at the trace event "block_rq_requeue" we have in the blktrace
kernel code:

static void blk_register_tracepoints(void)
{
	int ret;

	ret = register_trace_block_rq_insert(blk_add_trace_rq_insert, NULL);


Where the callback blk_add_trace_rq_insert() gets called when the
trace event is hit.

static void blk_add_trace_rq_insert(void *ignore,
				    struct request_queue *q, struct request *rq)
{
	blk_add_trace_rq(rq, 0, blk_rq_bytes(rq), BLK_TA_INSERT,
			 blk_trace_request_get_cgid(q, rq));
}

Where:

static void blk_add_trace_rq(struct request *rq, int error,
			     unsigned int nr_bytes, u32 what,
			     union kernfs_node_id *cgid)
{

calls

	__blk_add_trace(bt, blk_rq_trace_sector(rq), nr_bytes, req_op(rq),
			rq->cmd_flags, what, error, 0, NULL, cgid);

Which calls either the ftrace tracing file or its own relay buffer.

Looking at the code from
git://git.kernel.org/pub/scm/linux/kernel/git/axboe/blktrace.git

It appears that it does not rely on the ftrace ring buffers.

So I'm guessing blktrace is not affected by this patch.

-- Steve

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

T24gTW9uLCAyMDE4LTA0LTE2IGF0IDE3OjI0IC0wNDAwLCBTdGV2ZW4gUm9zdGVkdCB3cm90ZToN
Cj4gT24gTW9uLCAxNiBBcHIgMjAxOCAyMDo0OToxMiArMDAwMA0KPiBCYXJ0IFZhbiBBc3NjaGUg
PEJhcnQuVmFuQXNzY2hlQHdkYy5jb20+IHdyb3RlOg0KPiANCj4gPiBXaGljaCB0b29scyBwcm9j
ZXNzIHRoZXNlIHN0cmluZ3M/IEhhcyBpdCBiZWVuIHZlcmlmaWVkIHdoZXRoZXIgb3Igbm90DQo+
ID4gdGhlIHRvb2xzIHRoYXQgcHJvY2VzcyB0aGVzZSBzdHJpbmdzIHN0aWxsIHdvcmsgZmluZSB3
aXRoIHRoaXMgcGF0Y2gNCj4gPiBhcHBsaWVkPw0KPiANCj4gSWRlYWxseSwgdG9vbHMgc2hvdWxk
bid0IHByb2Nlc3MgdHJhY2UgZXZlbnQgc3RyaW5ncywgYnV0IEknbSBzdXJlIHNvbWUNCj4gZG8u
IDotLw0KPiANCj4gR2V0dGluZyBsaWJ0cmFjZWV2ZW50IG91dCBhcyBhIGxpYnJhcnkgaXMgYSBo
aWdoIHByaW9yaXR5IG9mIG1pbmUsIGFuZA0KPiBob3BlZnVsbHkgSSBzaG91bGQgZ2V0IHNvbWV0
aGluZyBvdXQgaW4gYSBjb3VwbGUgb2YgbW9udGhzLg0KPiANCj4gSWRlYWxseSwgdG9vbHMgc2hv
dWxkIHBhcnNlIHRoZSByYXcgZGF0YSBhbmQgdGhlbiBuZXcgZmllbGRzIHdpbGwgbm90DQo+IGFm
ZmVjdCB0aGVtLg0KDQpIZWxsbyBTdGV2ZSwNCg0KVGhlIHRvb2wgSSdtIG1vc3QgY29uY2VybmVk
IGFib3V0IGlzIGJsa3RyYWNlLiBJJ20gbm90IHN1cmUgdGhvdWdoIGhvdyB0aGlzDQp0b29sIHJl
Y2VpdmVzIGV2ZW50IGRhdGEgZnJvbSB0aGUgYmxvY2sgbGF5ZXIgY29yZS4NCg0KVGhhbmtzLA0K
DQpCYXJ0Lg0KDQoNCg==

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

On Mon, 2018-04-16 at 17:24 -0400, Steven Rostedt wrote:
> On Mon, 16 Apr 2018 20:49:12 +0000
> Bart Van Assche <Bart.VanAssche@wdc.com> wrote:
> 
> > Which tools process these strings? Has it been verified whether or not
> > the tools that process these strings still work fine with this patch
> > applied?
> 
> Ideally, tools shouldn't process trace event strings, but I'm sure some
> do. :-/
> 
> Getting libtraceevent out as a library is a high priority of mine, and
> hopefully I should get something out in a couple of months.
> 
> Ideally, tools should parse the raw data and then new fields will not
> affect them.

Hello Steve,

The tool I'm most concerned about is blktrace. I'm not sure though how this
tool receives event data from the block layer core.

Thanks,

Bart.

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Steven Rostedt]

On Mon, 16 Apr 2018 20:49:12 +0000
Bart Van Assche <Bart.VanAssche@wdc.com> wrote:

> Which tools process these strings? Has it been verified whether or not
> the tools that process these strings still work fine with this patch
> applied?

Ideally, tools shouldn't process trace event strings, but I'm sure some
do. :-/

Getting libtraceevent out as a library is a high priority of mine, and
hopefully I should get something out in a couple of months.

Ideally, tools should parse the raw data and then new fields will not
affect them.

-- Steve

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

T24gTW9uLCAyMDE4LTA0LTE2IGF0IDE0OjMxICswMDAwLCBCZWFuIEh1byAoYmVhbmh1bykgd3Jv
dGU6DQo+ICAJVFBfcHJpbnRrKCJob3N0X25vPSV1IGNoYW5uZWw9JXUgaWQ9JXUgbHVuPSV1IGRh
dGFfc2dsPSV1IHByb3Rfc2dsPSV1IiBcDQo+IC0JCSAgIiBwcm90X29wPSVzIGNtbmQ9KCVzICVz
IHJhdz0lcykiLA0KPiArCQkgICIgcHJvdF9vcD0lcyB0YWc9JWQgY21uZD0oJXMgJXMgcmF3PSVz
KSIsDQo+IA0KPiBbIC4uLiBdDQo+ICAJVFBfcHJpbnRrKCJob3N0X25vPSV1IGNoYW5uZWw9JXUg
aWQ9JXUgbHVuPSV1IGRhdGFfc2dsPSV1IHByb3Rfc2dsPSV1IiBcDQo+IC0JCSAgIiBwcm90X29w
PSVzIGNtbmQ9KCVzICVzIHJhdz0lcykgcnRuPSVkIiwNCj4gKwkJICAiIHByb3Rfb3A9JXMgdGFn
PSVkIGNtbmQ9KCVzICVzIHJhdz0lcykgcnRuPSVkIiwNCj4gWyAuLi4gXQ0KPiAgCVRQX3ByaW50
aygiaG9zdF9ubz0ldSBjaGFubmVsPSV1IGlkPSV1IGx1bj0ldSBkYXRhX3NnbD0ldSAiIFwNCj4g
LQkJICAicHJvdF9zZ2w9JXUgcHJvdF9vcD0lcyBjbW5kPSglcyAlcyByYXc9JXMpIHJlc3VsdD0o
ZHJpdmVyPSIgXA0KPiAtCQkgICIlcyBob3N0PSVzIG1lc3NhZ2U9JXMgc3RhdHVzPSVzKSIsDQo+
ICsJCSAgInByb3Rfc2dsPSV1IHByb3Rfb3A9JXMgdGFnPSVkIGNtbmQ9KCVzICVzIHJhdz0lcykg
IiBcDQo+ICsJCSAgInJlc3VsdD0oZHJpdmVyPSVzIGhvc3Q9JXMgbWVzc2FnZT0lcyBzdGF0dXM9
JXMpIiwNCg0KV2hpY2ggdG9vbHMgcHJvY2VzcyB0aGVzZSBzdHJpbmdzPyBIYXMgaXQgYmVlbiB2
ZXJpZmllZCB3aGV0aGVyIG9yIG5vdA0KdGhlIHRvb2xzIHRoYXQgcHJvY2VzcyB0aGVzZSBzdHJp
bmdzIHN0aWxsIHdvcmsgZmluZSB3aXRoIHRoaXMgcGF0Y2gNCmFwcGxpZWQ/DQoNClRoYW5rcywN
Cg0KQmFydC4NCg0KDQo=

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

On Mon, 2018-04-16 at 14:31 +0000, Bean Huo (beanhuo) wrote:
>  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
> -		  " prot_op=%s cmnd=(%s %s raw=%s)",
> +		  " prot_op=%s tag=%d cmnd=(%s %s raw=%s)",
> 
> [ ... ]
>  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
> -		  " prot_op=%s cmnd=(%s %s raw=%s) rtn=%d",
> +		  " prot_op=%s tag=%d cmnd=(%s %s raw=%s) rtn=%d",
> [ ... ]
>  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u " \
> -		  "prot_sgl=%u prot_op=%s cmnd=(%s %s raw=%s) result=(driver=" \
> -		  "%s host=%s message=%s status=%s)",
> +		  "prot_sgl=%u prot_op=%s tag=%d cmnd=(%s %s raw=%s) " \
> +		  "result=(driver=%s host=%s message=%s status=%s)",

Which tools process these strings? Has it been verified whether or not
the tools that process these strings still work fine with this patch
applied?

Thanks,

Bart.

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

T24gTW9uLCAyMDE4LTA0LTE2IGF0IDIwOjI3ICswMDAwLCBCZWFuIEh1byAoYmVhbmh1bykgd3Jv
dGU6DQo+IEJ5IHRoZSB3YXksIHRoZXNlIHBhdGNoZXMgYXJlIG5vdCB0byBhZGQgbmV3IGZlYXR1
cmUsIHRoZXkgYXJlIGp1c3QgdG8NCj4gYWRkIHByaW50IHRhZyBhbG9uZyB3aXRoIHRoZSBvdGhl
ciBleGlzdCBwcmludGVkIHJlcXVlc3QgcGFyYW1ldGVycy4NCg0KQXJlIHlvdSBhd2FyZSB0aGF0
IHRoZXJlIGFyZSB0d28gdGFnIGZpZWxkcyBpbiBzdHJ1Y3QgcmVxdWVzdCwgbmFtZWx5ICJ0YWci
DQphbmQgImludGVybmFsX3RhZyI/IEFyZSB5b3UgYXdhcmUgdGhhdCBob3cgdGhlc2UgZmllbGRz
IGFyZSB1c2VkIGRlcGVuZHMgb24NCndoZXRoZXIgb3Igbm90IGEgc2NoZWR1bGVyIGlzIGF0dGFj
aGVkIHRvIGEgcmVxdWVzdCBxdWV1ZT8gSGF2ZSB5b3UgdmVyaWZpZWQNCnRoYXQgdGhlICJ0YWci
IGZpZWxkIGNvbnRhaW5zIGEgbWVhbmluZ2Z1bCB2YWx1ZSBmb3IgYmxrLW1xIGZvciBldmVyeSBi
bGstbXENCnRyYWNlcG9pbnQ/DQoNClRoYW5rcywNCg0KQmFydC4NCg0KDQoNCg==

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

On Mon, 2018-04-16 at 20:27 +0000, Bean Huo (beanhuo) wrote:
> By the way, these patches are not to add new feature, they are just to
> add print tag along with the other exist printed request parameters.

Are you aware that there are two tag fields in struct request, namely "tag"
and "internal_tag"? Are you aware that how these fields are used depends on
whether or not a scheduler is attached to a request queue? Have you verified
that the "tag" field contains a meaningful value for blk-mq for every blk-mq
tracepoint?

Thanks,

Bart.

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

Pj4+IFRoaXMgcGF0Y2ggaXMgbm90IGFjY2VwdGFibGUgYmVjYXVzZSBpdCBhZGRzIHN1cHBvcnQg
Zm9yIHRhZyB0cmFjaW5nDQo+Pj4gdG8gdGhlIGxlZ2FjeSBibG9jayBsYXllciBvbmx5LiBBbnkg
cGF0Y2ggdGhhdCBhZGRzIGEgbmV3IGZlYXR1cmUgdG8NCj4+PiB0aGUgbGVnYWN5IGJsb2NrIGxh
eWVyIG11c3QgYWxzbyBhZGQgaXQgdG8gYmxrLW1xLg0KPj4+DQo+PiBUbyBiZSBob25lc3QsIEkg
ZG9uJ3QgdW5kZXJzdGFuZCB5b3VyIHBvaW50LCBjYW4geW91IGdpdmUgbWUgbW9yZQ0KPmV4cGxh
bmF0aW9uPw0KPg0KPlRoZSBsZWdhY3kgYmxvY2sgbGF5ZXIgd2lsbCBiZSByZW1vdmVkIGFzIHNv
b24gYXMgYmxrLW1xIHByb3ZpZGVzIGFsbCB0aGUNCj5mdW5jdGlvbmFsaXR5IG9mIHRoZSBsZWdh
Y3kgYmxvY2sgbGF5ZXIgYW5kIGFzIHNvb24gYXMgaXQgcGVyZm9ybXMgYXQgbGVhc3QgYXMNCj53
ZWxsIGFzIHRoZSBsZWdhY3kgYmxvY2sgbGF5ZXIgZm9yIGFsbCB1c2UgY2FzZXMuIElmIG5ldyBm
ZWF0dXJlcyBhcmUgYWRkZWQgdG8NCj50aGUgbGVnYWN5IGJsb2NrIGxheWVyIGJ1dCBub3QgdG8g
YmxrLW1xIHRoYXQgcHJldmVudHMgcmVtb3ZhbCBvZiB0aGUgbGVnYWN5DQo+YmxvY2sgbGF5ZXIu
IEhlbmNlIHRoZSByZXF1aXJlbWVudCBJIGV4cGxhaW5lZCBpbiBteSBwcmV2aW91cyBlLW1haWwu
DQo+DQo+QmFydC4NCg0KVGhhbmtzIGZvciB5b3VyIGluZm9ybWF0aW9uLg0KSSBoYXZlIHNldmVy
YWwgcXVlc3Rpb25zIGFnYWluLg0KV2hlbiB0aGUgbGVnYWN5IGJsb2NrIGxheWVyIHdpbGwgYmUg
cmVwbGFjZWQgYnkgYmxrLW1xPyANCkFuZCAiaW5jbHVkZS90cmVjZS9ldmVudC9ibG9jay5oIC4u
IHNjc2kuaCIgd2lsbCBhbHNvIGJlIGNoYW5nZWQ/IA0KRG8geW91IGhhdmUgdGhlIHJlbGF0ZWQg
Z2l0IHJlcCBvciBtYWlsIGxpc3QgYWJvdXQgdGhpcyB0b3BpYz8NCk1heWJlIHRoaXMgaXMgZ3Jl
YXQgYmlnIGNoYW5nZSwgSSBhbSB2ZXJ5IGludGVyZXN0ZWQgaW4gdGhhdC4gQW5kIHdhbnQgdG8g
aGF2ZSBhIGxvb2sgYXQuDQoNCkJ5IHRoZSB3YXksIHRoZXNlIHBhdGNoZXMgYXJlIG5vdCB0byBh
ZGQgbmV3IGZlYXR1cmUsIHRoZXkgYXJlIGp1c3QgdG8gYWRkIHByaW50IHRhZyBhbG9uZyB3aXRo
IHRoZSBvdGhlciBleGlzdA0KUHJpbnRlZCByZXF1ZXN0IHBhcmFtZXRlcnMuICBUaGUgYmxrLW1x
IGlzIG5vdyBzdGlsbCB1c2luZyAiaW5jbHVkZS90cmFjZS9ldmV0L2Jsb2NrLmgiIGRlZmluZWQg
dHJhY2UgZXZlbnRzLg0KDQpGb3IgZXhhbXBsZTogDQp2b2lkIGJsa19tcV9zdGFydF9yZXF1ZXN0
KHN0cnVjdCByZXF1ZXN0ICpycSkgIA0Kew0KLi4uDQouLi4NCnRyYWNlX2Jsb2NrX3JxX2lzc3Vl
KHEsIHJxKTsNCi4uLg0KLi4uDQp9DQpEbyB5b3UgbWVhbiB0aGF0IHRoaXMgd2lsbCBhbHNvIGJl
IHJlbW92ZWQvcmVwbGFjZWQgYnkgc29tZW9uZSBlbHNlPw0KDQpCZWFuIEh1bw0K

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

>>> This patch is not acceptable because it adds support for tag tracing
>>> to the legacy block layer only. Any patch that adds a new feature to
>>> the legacy block layer must also add it to blk-mq.
>>>
>> To be honest, I don't understand your point, can you give me more
>explanation?
>
>The legacy block layer will be removed as soon as blk-mq provides all the
>functionality of the legacy block layer and as soon as it performs at least as
>well as the legacy block layer for all use cases. If new features are added to
>the legacy block layer but not to blk-mq that prevents removal of the legacy
>block layer. Hence the requirement I explained in my previous e-mail.
>
>Bart.

Thanks for your information.
I have several questions again.
When the legacy block layer will be replaced by blk-mq? 
And "include/trece/event/block.h .. scsi.h" will also be changed? 
Do you have the related git rep or mail list about this topic?
Maybe this is great big change, I am very interested in that. And want to have a look at.

By the way, these patches are not to add new feature, they are just to add print tag along with the other exist
Printed request parameters.  The blk-mq is now still using "include/trace/evet/block.h" defined trace events.

For example: 
void blk_mq_start_request(struct request *rq)  
{
...
...
trace_block_rq_issue(q, rq);
...
...
}
Do you mean that this will also be removed/replaced by someone else?

Bean Huo

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

On 04/16/18 10:05, Bean Huo (beanhuo) wrote:
>> On Mon, 2018-04-16 at 09:41 -0700, Rajat Jain wrote:
>>> On Mon, Apr 16, 2018 at 8:28 AM, Steven Rostedt <rostedt@goodmis.org>
>> wrote:
>>>> On Mon, 16 Apr 2018 14:31:49 +0000
>>>> "Bean Huo (beanhuo)" <beanhuo@micron.com> wrote:
>>>>
>>>>> Print the request tag along with other information while tracing a
>>>>> command.
>>>>>
>>>>> Signed-off-by: Bean Huo <beanhuo@micron.com>
>>>
>>> Acked-by: Rajat Jain <rajatja@google.com>
>>
>> This patch is not acceptable because it adds support for tag tracing to the
>> legacy block layer only. Any patch that adds a new feature to the legacy block
>> layer must also add it to blk-mq.
>>
> To be honest, I don't understand your point, can you give me more explanation?

The legacy block layer will be removed as soon as blk-mq provides all 
the functionality of the legacy block layer and as soon as it performs 
at least as well as the legacy block layer for all use cases. If new 
features are added to the legacy block layer but not to blk-mq that 
prevents removal of the legacy block layer. Hence the requirement I 
explained in my previous e-mail.

Bart.

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

SGksIEJhcnQNCg0KPk9uIE1vbiwgMjAxOC0wNC0xNiBhdCAwOTo0MSAtMDcwMCwgUmFqYXQgSmFp
biB3cm90ZToNCj4+IE9uIE1vbiwgQXByIDE2LCAyMDE4IGF0IDg6MjggQU0sIFN0ZXZlbiBSb3N0
ZWR0IDxyb3N0ZWR0QGdvb2RtaXMub3JnPg0KPndyb3RlOg0KPj4gPiBPbiBNb24sIDE2IEFwciAy
MDE4IDE0OjMxOjQ5ICswMDAwDQo+PiA+ICJCZWFuIEh1byAoYmVhbmh1bykiIDxiZWFuaHVvQG1p
Y3Jvbi5jb20+IHdyb3RlOg0KPj4gPg0KPj4gPiA+IFByaW50IHRoZSByZXF1ZXN0IHRhZyBhbG9u
ZyB3aXRoIG90aGVyIGluZm9ybWF0aW9uIHdoaWxlIHRyYWNpbmcgYQ0KPj4gPiA+IGNvbW1hbmQu
DQo+PiA+ID4NCj4+ID4gPiBTaWduZWQtb2ZmLWJ5OiBCZWFuIEh1byA8YmVhbmh1b0BtaWNyb24u
Y29tPg0KPj4NCj4+IEFja2VkLWJ5OiBSYWphdCBKYWluIDxyYWphdGphQGdvb2dsZS5jb20+DQo+
DQo+VGhpcyBwYXRjaCBpcyBub3QgYWNjZXB0YWJsZSBiZWNhdXNlIGl0IGFkZHMgc3VwcG9ydCBm
b3IgdGFnIHRyYWNpbmcgdG8gdGhlDQo+bGVnYWN5IGJsb2NrIGxheWVyIG9ubHkuIEFueSBwYXRj
aCB0aGF0IGFkZHMgYSBuZXcgZmVhdHVyZSB0byB0aGUgbGVnYWN5IGJsb2NrDQo+bGF5ZXIgbXVz
dCBhbHNvIGFkZCBpdCB0byBibGstbXEuDQo+DQpUbyBiZSBob25lc3QsIEkgZG9uJ3QgdW5kZXJz
dGFuZCB5b3VyIHBvaW50LCBjYW4geW91IGdpdmUgbWUgbW9yZSBleHBsYW5hdGlvbj8NCg0KPkJh
cnQuDQo+DQo+DQoNCg==

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

Hi, Bart

>On Mon, 2018-04-16 at 09:41 -0700, Rajat Jain wrote:
>> On Mon, Apr 16, 2018 at 8:28 AM, Steven Rostedt <rostedt@goodmis.org>
>wrote:
>> > On Mon, 16 Apr 2018 14:31:49 +0000
>> > "Bean Huo (beanhuo)" <beanhuo@micron.com> wrote:
>> >
>> > > Print the request tag along with other information while tracing a
>> > > command.
>> > >
>> > > Signed-off-by: Bean Huo <beanhuo@micron.com>
>>
>> Acked-by: Rajat Jain <rajatja@google.com>
>
>This patch is not acceptable because it adds support for tag tracing to the
>legacy block layer only. Any patch that adds a new feature to the legacy block
>layer must also add it to blk-mq.
>
To be honest, I don't understand your point, can you give me more explanation?

>Bart.
>
>

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

T24gTW9uLCAyMDE4LTA0LTE2IGF0IDA5OjQxIC0wNzAwLCBSYWphdCBKYWluIHdyb3RlOg0KPiBP
biBNb24sIEFwciAxNiwgMjAxOCBhdCA4OjI4IEFNLCBTdGV2ZW4gUm9zdGVkdCA8cm9zdGVkdEBn
b29kbWlzLm9yZz4gd3JvdGU6DQo+ID4gT24gTW9uLCAxNiBBcHIgMjAxOCAxNDozMTo0OSArMDAw
MA0KPiA+ICJCZWFuIEh1byAoYmVhbmh1bykiIDxiZWFuaHVvQG1pY3Jvbi5jb20+IHdyb3RlOg0K
PiA+IA0KPiA+ID4gUHJpbnQgdGhlIHJlcXVlc3QgdGFnIGFsb25nIHdpdGggb3RoZXIgaW5mb3Jt
YXRpb24NCj4gPiA+IHdoaWxlIHRyYWNpbmcgYSBjb21tYW5kLg0KPiA+ID4gDQo+ID4gPiBTaWdu
ZWQtb2ZmLWJ5OiBCZWFuIEh1byA8YmVhbmh1b0BtaWNyb24uY29tPg0KPiANCj4gQWNrZWQtYnk6
IFJhamF0IEphaW4gPHJhamF0amFAZ29vZ2xlLmNvbT4NCg0KVGhpcyBwYXRjaCBpcyBub3QgYWNj
ZXB0YWJsZSBiZWNhdXNlIGl0IGFkZHMgc3VwcG9ydCBmb3IgdGFnIHRyYWNpbmcgdG8gdGhlDQps
ZWdhY3kgYmxvY2sgbGF5ZXIgb25seS4gQW55IHBhdGNoIHRoYXQgYWRkcyBhIG5ldyBmZWF0dXJl
IHRvIHRoZSBsZWdhY3kgYmxvY2sNCmxheWVyIG11c3QgYWxzbyBhZGQgaXQgdG8gYmxrLW1xLg0K
DQpCYXJ0Lg0KDQoNCg0K

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bart Van Assche]

On Mon, 2018-04-16 at 09:41 -0700, Rajat Jain wrote:
> On Mon, Apr 16, 2018 at 8:28 AM, Steven Rostedt <rostedt@goodmis.org> wrote:
> > On Mon, 16 Apr 2018 14:31:49 +0000
> > "Bean Huo (beanhuo)" <beanhuo@micron.com> wrote:
> > 
> > > Print the request tag along with other information
> > > while tracing a command.
> > > 
> > > Signed-off-by: Bean Huo <beanhuo@micron.com>
> 
> Acked-by: Rajat Jain <rajatja@google.com>

This patch is not acceptable because it adds support for tag tracing to the
legacy block layer only. Any patch that adds a new feature to the legacy block
layer must also add it to blk-mq.

Bart.

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Rajat Jain]

On Mon, Apr 16, 2018 at 8:28 AM, Steven Rostedt <rostedt@goodmis.org> wrote:
> On Mon, 16 Apr 2018 14:31:49 +0000
> "Bean Huo (beanhuo)" <beanhuo@micron.com> wrote:
>
>> Print the request tag along with other information
>> while tracing a command.
>>
>> Signed-off-by: Bean Huo <beanhuo@micron.com>
Acked-by: Rajat Jain <rajatja@google.com>

>> ---
>
> I don't see any issue with the tracing part.
>
> Acked-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
>
> Others need to check the content.
>
> -- Steve

Re: [RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Steven Rostedt]

On Mon, 16 Apr 2018 14:31:49 +0000
"Bean Huo (beanhuo)" <beanhuo@micron.com> wrote:

> Print the request tag along with other information
> while tracing a command.
> 
> Signed-off-by: Bean Huo <beanhuo@micron.com>
> ---

I don't see any issue with the tracing part.

Acked-by: Steven Rostedt (VMware) <rostedt@goodmis.org>

Others need to check the content.

-- Steve

[RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

Print the request tag along with other information
while tracing a command.

Signed-off-by: Bean Huo <beanhuo@micron.com>
---
 include/trace/events/scsi.h | 20 +++++++++++++-------
 1 file changed, 13 insertions(+), 7 deletions(-)

diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
index f624969..a4ada90 100644
--- a/include/trace/events/scsi.h
+++ b/include/trace/events/scsi.h
@@ -210,6 +210,7 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
 		__field( unsigned int,	lun	)
 		__field( unsigned int,	opcode	)
 		__field( unsigned int,	cmd_len )
+		__field( int,		tag )
 		__field( unsigned int,	data_sglen )
 		__field( unsigned int,	prot_sglen )
 		__field( unsigned char,	prot_op )
@@ -223,6 +224,7 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
 		__entry->lun		=3D cmd->device->lun;
 		__entry->opcode		=3D cmd->cmnd[0];
 		__entry->cmd_len	=3D cmd->cmd_len;
+		__entry->tag		=3D cmd->request->tag;
 		__entry->data_sglen	=3D scsi_sg_count(cmd);
 		__entry->prot_sglen	=3D scsi_prot_sg_count(cmd);
 		__entry->prot_op	=3D scsi_get_prot_op(cmd);
@@ -230,10 +232,10 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
 	),
=20
 	TP_printk("host_no=3D%u channel=3D%u id=3D%u lun=3D%u data_sgl=3D%u prot_=
sgl=3D%u" \
-		  " prot_op=3D%s cmnd=3D(%s %s raw=3D%s)",
+		  " prot_op=3D%s tag=3D%d cmnd=3D(%s %s raw=3D%s)",
 		  __entry->host_no, __entry->channel, __entry->id,
 		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
-		  show_prot_op_name(__entry->prot_op),
+		  show_prot_op_name(__entry->prot_op), __entry->tag,
 		  show_opcode_name(__entry->opcode),
 		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len))
@@ -253,6 +255,7 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
 		__field( int,		rtn	)
 		__field( unsigned int,	opcode	)
 		__field( unsigned int,	cmd_len )
+		__field( int,		tag )
 		__field( unsigned int,	data_sglen )
 		__field( unsigned int,	prot_sglen )
 		__field( unsigned char,	prot_op )
@@ -267,6 +270,7 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
 		__entry->rtn		=3D rtn;
 		__entry->opcode		=3D cmd->cmnd[0];
 		__entry->cmd_len	=3D cmd->cmd_len;
+		__entry->tag		=3D cmd->request->tag;
 		__entry->data_sglen	=3D scsi_sg_count(cmd);
 		__entry->prot_sglen	=3D scsi_prot_sg_count(cmd);
 		__entry->prot_op	=3D scsi_get_prot_op(cmd);
@@ -274,10 +278,10 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
 	),
=20
 	TP_printk("host_no=3D%u channel=3D%u id=3D%u lun=3D%u data_sgl=3D%u prot_=
sgl=3D%u" \
-		  " prot_op=3D%s cmnd=3D(%s %s raw=3D%s) rtn=3D%d",
+		  " prot_op=3D%s tag=3D%d cmnd=3D(%s %s raw=3D%s) rtn=3D%d",
 		  __entry->host_no, __entry->channel, __entry->id,
 		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
-		  show_prot_op_name(__entry->prot_op),
+		  show_prot_op_name(__entry->prot_op), __entry->tag,
 		  show_opcode_name(__entry->opcode),
 		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len),
@@ -298,6 +302,7 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 		__field( int,		result	)
 		__field( unsigned int,	opcode	)
 		__field( unsigned int,	cmd_len )
+		__field( int,		tag )
 		__field( unsigned int,	data_sglen )
 		__field( unsigned int,	prot_sglen )
 		__field( unsigned char,	prot_op )
@@ -312,6 +317,7 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 		__entry->result		=3D cmd->result;
 		__entry->opcode		=3D cmd->cmnd[0];
 		__entry->cmd_len	=3D cmd->cmd_len;
+		__entry->tag		=3D cmd->request->tag;
 		__entry->data_sglen	=3D scsi_sg_count(cmd);
 		__entry->prot_sglen	=3D scsi_prot_sg_count(cmd);
 		__entry->prot_op	=3D scsi_get_prot_op(cmd);
@@ -319,11 +325,11 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 	),
=20
 	TP_printk("host_no=3D%u channel=3D%u id=3D%u lun=3D%u data_sgl=3D%u " \
-		  "prot_sgl=3D%u prot_op=3D%s cmnd=3D(%s %s raw=3D%s) result=3D(driver=
=3D" \
-		  "%s host=3D%s message=3D%s status=3D%s)",
+		  "prot_sgl=3D%u prot_op=3D%s tag=3D%d cmnd=3D(%s %s raw=3D%s) " \
+		  "result=3D(driver=3D%s host=3D%s message=3D%s status=3D%s)",
 		  __entry->host_no, __entry->channel, __entry->id,
 		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
-		  show_prot_op_name(__entry->prot_op),
+		  show_prot_op_name(__entry->prot_op), __entry->tag,
 		  show_opcode_name(__entry->opcode),
 		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len),
--=20
2.7.4

[RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

Print the request tag along with other information
while tracing a command.

Signed-off-by: Bean Huo <beanhuo@micron.com>
---
 include/trace/events/scsi.h | 20 +++++++++++++-------
 1 file changed, 13 insertions(+), 7 deletions(-)

diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
index f624969..a4ada90 100644
--- a/include/trace/events/scsi.h
+++ b/include/trace/events/scsi.h
@@ -210,6 +210,7 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
 		__field( unsigned int,	lun	)
 		__field( unsigned int,	opcode	)
 		__field( unsigned int,	cmd_len )
+		__field( int,		tag )
 		__field( unsigned int,	data_sglen )
 		__field( unsigned int,	prot_sglen )
 		__field( unsigned char,	prot_op )
@@ -223,6 +224,7 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
 		__entry->lun		= cmd->device->lun;
 		__entry->opcode		= cmd->cmnd[0];
 		__entry->cmd_len	= cmd->cmd_len;
+		__entry->tag		= cmd->request->tag;
 		__entry->data_sglen	= scsi_sg_count(cmd);
 		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
 		__entry->prot_op	= scsi_get_prot_op(cmd);
@@ -230,10 +232,10 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
 	),
 
 	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
-		  " prot_op=%s cmnd=(%s %s raw=%s)",
+		  " prot_op=%s tag=%d cmnd=(%s %s raw=%s)",
 		  __entry->host_no, __entry->channel, __entry->id,
 		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
-		  show_prot_op_name(__entry->prot_op),
+		  show_prot_op_name(__entry->prot_op), __entry->tag,
 		  show_opcode_name(__entry->opcode),
 		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len))
@@ -253,6 +255,7 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
 		__field( int,		rtn	)
 		__field( unsigned int,	opcode	)
 		__field( unsigned int,	cmd_len )
+		__field( int,		tag )
 		__field( unsigned int,	data_sglen )
 		__field( unsigned int,	prot_sglen )
 		__field( unsigned char,	prot_op )
@@ -267,6 +270,7 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
 		__entry->rtn		= rtn;
 		__entry->opcode		= cmd->cmnd[0];
 		__entry->cmd_len	= cmd->cmd_len;
+		__entry->tag		= cmd->request->tag;
 		__entry->data_sglen	= scsi_sg_count(cmd);
 		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
 		__entry->prot_op	= scsi_get_prot_op(cmd);
@@ -274,10 +278,10 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
 	),
 
 	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
-		  " prot_op=%s cmnd=(%s %s raw=%s) rtn=%d",
+		  " prot_op=%s tag=%d cmnd=(%s %s raw=%s) rtn=%d",
 		  __entry->host_no, __entry->channel, __entry->id,
 		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
-		  show_prot_op_name(__entry->prot_op),
+		  show_prot_op_name(__entry->prot_op), __entry->tag,
 		  show_opcode_name(__entry->opcode),
 		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len),
@@ -298,6 +302,7 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 		__field( int,		result	)
 		__field( unsigned int,	opcode	)
 		__field( unsigned int,	cmd_len )
+		__field( int,		tag )
 		__field( unsigned int,	data_sglen )
 		__field( unsigned int,	prot_sglen )
 		__field( unsigned char,	prot_op )
@@ -312,6 +317,7 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 		__entry->result		= cmd->result;
 		__entry->opcode		= cmd->cmnd[0];
 		__entry->cmd_len	= cmd->cmd_len;
+		__entry->tag		= cmd->request->tag;
 		__entry->data_sglen	= scsi_sg_count(cmd);
 		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
 		__entry->prot_op	= scsi_get_prot_op(cmd);
@@ -319,11 +325,11 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 	),
 
 	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u " \
-		  "prot_sgl=%u prot_op=%s cmnd=(%s %s raw=%s) result=(driver=" \
-		  "%s host=%s message=%s status=%s)",
+		  "prot_sgl=%u prot_op=%s tag=%d cmnd=(%s %s raw=%s) " \
+		  "result=(driver=%s host=%s message=%s status=%s)",
 		  __entry->host_no, __entry->channel, __entry->id,
 		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
-		  show_prot_op_name(__entry->prot_op),
+		  show_prot_op_name(__entry->prot_op), __entry->tag,
 		  show_opcode_name(__entry->opcode),
 		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len),
-- 
2.7.4

[RESEND PATCH v1 1/2] trace: events: scsi: Add tag in SCSI trace events

[Bean Huo (beanhuo)]

Print the request tag along with other information
while tracing a command.

Signed-off-by: Bean Huo <beanhuo@micron.com>
---
 include/trace/events/scsi.h | 20 +++++++++++++-------
 1 file changed, 13 insertions(+), 7 deletions(-)

diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
index f624969..a4ada90 100644
--- a/include/trace/events/scsi.h
+++ b/include/trace/events/scsi.h
@@ -210,6 +210,7 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
 		__field( unsigned int,	lun	)
 		__field( unsigned int,	opcode	)
 		__field( unsigned int,	cmd_len )
+		__field( int,		tag )
 		__field( unsigned int,	data_sglen )
 		__field( unsigned int,	prot_sglen )
 		__field( unsigned char,	prot_op )
@@ -223,6 +224,7 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
 		__entry->lun		= cmd->device->lun;
 		__entry->opcode		= cmd->cmnd[0];
 		__entry->cmd_len	= cmd->cmd_len;
+		__entry->tag		= cmd->request->tag;
 		__entry->data_sglen	= scsi_sg_count(cmd);
 		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
 		__entry->prot_op	= scsi_get_prot_op(cmd);
@@ -230,10 +232,10 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
 	),
 
 	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
-		  " prot_op=%s cmnd=(%s %s raw=%s)",
+		  " prot_op=%s tag=%d cmnd=(%s %s raw=%s)",
 		  __entry->host_no, __entry->channel, __entry->id,
 		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
-		  show_prot_op_name(__entry->prot_op),
+		  show_prot_op_name(__entry->prot_op), __entry->tag,
 		  show_opcode_name(__entry->opcode),
 		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len))
@@ -253,6 +255,7 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
 		__field( int,		rtn	)
 		__field( unsigned int,	opcode	)
 		__field( unsigned int,	cmd_len )
+		__field( int,		tag )
 		__field( unsigned int,	data_sglen )
 		__field( unsigned int,	prot_sglen )
 		__field( unsigned char,	prot_op )
@@ -267,6 +270,7 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
 		__entry->rtn		= rtn;
 		__entry->opcode		= cmd->cmnd[0];
 		__entry->cmd_len	= cmd->cmd_len;
+		__entry->tag		= cmd->request->tag;
 		__entry->data_sglen	= scsi_sg_count(cmd);
 		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
 		__entry->prot_op	= scsi_get_prot_op(cmd);
@@ -274,10 +278,10 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
 	),
 
 	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
-		  " prot_op=%s cmnd=(%s %s raw=%s) rtn=%d",
+		  " prot_op=%s tag=%d cmnd=(%s %s raw=%s) rtn=%d",
 		  __entry->host_no, __entry->channel, __entry->id,
 		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
-		  show_prot_op_name(__entry->prot_op),
+		  show_prot_op_name(__entry->prot_op), __entry->tag,
 		  show_opcode_name(__entry->opcode),
 		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len),
@@ -298,6 +302,7 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 		__field( int,		result	)
 		__field( unsigned int,	opcode	)
 		__field( unsigned int,	cmd_len )
+		__field( int,		tag )
 		__field( unsigned int,	data_sglen )
 		__field( unsigned int,	prot_sglen )
 		__field( unsigned char,	prot_op )
@@ -312,6 +317,7 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 		__entry->result		= cmd->result;
 		__entry->opcode		= cmd->cmnd[0];
 		__entry->cmd_len	= cmd->cmd_len;
+		__entry->tag		= cmd->request->tag;
 		__entry->data_sglen	= scsi_sg_count(cmd);
 		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
 		__entry->prot_op	= scsi_get_prot_op(cmd);
@@ -319,11 +325,11 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 	),
 
 	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u " \
-		  "prot_sgl=%u prot_op=%s cmnd=(%s %s raw=%s) result=(driver=" \
-		  "%s host=%s message=%s status=%s)",
+		  "prot_sgl=%u prot_op=%s tag=%d cmnd=(%s %s raw=%s) " \
+		  "result=(driver=%s host=%s message=%s status=%s)",
 		  __entry->host_no, __entry->channel, __entry->id,
 		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
-		  show_prot_op_name(__entry->prot_op),
+		  show_prot_op_name(__entry->prot_op), __entry->tag,
 		  show_opcode_name(__entry->opcode),
 		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len),
-- 
2.7.4