1 /*
2 * scsi_logging.c
3 *
4 * Copyright (C) 2014 SUSE Linux Products GmbH
5 * Copyright (C) 2014 Hannes Reinecke <hare@suse.de>
6 *
7 * This file is released under the GPLv2
8 */
9
10 #include <linux/kernel.h>
11 #include <linux/atomic.h>
12
13 #include <scsi/scsi.h>
14 #include <scsi/scsi_cmnd.h>
15 #include <scsi/scsi_device.h>
16 #include <scsi/scsi_eh.h>
17 #include <scsi/scsi_dbg.h>
18
scsi_log_reserve_buffer(size_t * len)19 static char *scsi_log_reserve_buffer(size_t *len)
20 {
21 *len = 128;
22 return kmalloc(*len, GFP_ATOMIC);
23 }
24
scsi_log_release_buffer(char * bufptr)25 static void scsi_log_release_buffer(char *bufptr)
26 {
27 kfree(bufptr);
28 }
29
scmd_name(const struct scsi_cmnd * scmd)30 static inline const char *scmd_name(const struct scsi_cmnd *scmd)
31 {
32 return scmd->request->rq_disk ?
33 scmd->request->rq_disk->disk_name : NULL;
34 }
35
sdev_format_header(char * logbuf,size_t logbuf_len,const char * name,int tag)36 static size_t sdev_format_header(char *logbuf, size_t logbuf_len,
37 const char *name, int tag)
38 {
39 size_t off = 0;
40
41 if (name)
42 off += scnprintf(logbuf + off, logbuf_len - off,
43 "[%s] ", name);
44
45 if (WARN_ON(off >= logbuf_len))
46 return off;
47
48 if (tag >= 0)
49 off += scnprintf(logbuf + off, logbuf_len - off,
50 "tag#%d ", tag);
51 return off;
52 }
53
sdev_prefix_printk(const char * level,const struct scsi_device * sdev,const char * name,const char * fmt,...)54 void sdev_prefix_printk(const char *level, const struct scsi_device *sdev,
55 const char *name, const char *fmt, ...)
56 {
57 va_list args;
58 char *logbuf;
59 size_t off = 0, logbuf_len;
60
61 if (!sdev)
62 return;
63
64 logbuf = scsi_log_reserve_buffer(&logbuf_len);
65 if (!logbuf)
66 return;
67
68 if (name)
69 off += scnprintf(logbuf + off, logbuf_len - off,
70 "[%s] ", name);
71 if (!WARN_ON(off >= logbuf_len)) {
72 va_start(args, fmt);
73 off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
74 va_end(args);
75 }
76 dev_printk(level, &sdev->sdev_gendev, "%s", logbuf);
77 scsi_log_release_buffer(logbuf);
78 }
79 EXPORT_SYMBOL(sdev_prefix_printk);
80
scmd_printk(const char * level,const struct scsi_cmnd * scmd,const char * fmt,...)81 void scmd_printk(const char *level, const struct scsi_cmnd *scmd,
82 const char *fmt, ...)
83 {
84 va_list args;
85 char *logbuf;
86 size_t off = 0, logbuf_len;
87
88 if (!scmd || !scmd->cmnd)
89 return;
90
91 logbuf = scsi_log_reserve_buffer(&logbuf_len);
92 if (!logbuf)
93 return;
94 off = sdev_format_header(logbuf, logbuf_len, scmd_name(scmd),
95 scmd->request->tag);
96 if (off < logbuf_len) {
97 va_start(args, fmt);
98 off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
99 va_end(args);
100 }
101 dev_printk(level, &scmd->device->sdev_gendev, "%s", logbuf);
102 scsi_log_release_buffer(logbuf);
103 }
104 EXPORT_SYMBOL(scmd_printk);
105
scsi_format_opcode_name(char * buffer,size_t buf_len,const unsigned char * cdbp)106 static size_t scsi_format_opcode_name(char *buffer, size_t buf_len,
107 const unsigned char *cdbp)
108 {
109 int sa, cdb0;
110 const char *cdb_name = NULL, *sa_name = NULL;
111 size_t off;
112
113 cdb0 = cdbp[0];
114 if (cdb0 == VARIABLE_LENGTH_CMD) {
115 int len = scsi_varlen_cdb_length(cdbp);
116
117 if (len < 10) {
118 off = scnprintf(buffer, buf_len,
119 "short variable length command, len=%d",
120 len);
121 return off;
122 }
123 sa = (cdbp[8] << 8) + cdbp[9];
124 } else
125 sa = cdbp[1] & 0x1f;
126
127 if (!scsi_opcode_sa_name(cdb0, sa, &cdb_name, &sa_name)) {
128 if (cdb_name)
129 off = scnprintf(buffer, buf_len, "%s", cdb_name);
130 else {
131 off = scnprintf(buffer, buf_len, "opcode=0x%x", cdb0);
132 if (WARN_ON(off >= buf_len))
133 return off;
134 if (cdb0 >= VENDOR_SPECIFIC_CDB)
135 off += scnprintf(buffer + off, buf_len - off,
136 " (vendor)");
137 else if (cdb0 >= 0x60 && cdb0 < 0x7e)
138 off += scnprintf(buffer + off, buf_len - off,
139 " (reserved)");
140 }
141 } else {
142 if (sa_name)
143 off = scnprintf(buffer, buf_len, "%s", sa_name);
144 else if (cdb_name)
145 off = scnprintf(buffer, buf_len, "%s, sa=0x%x",
146 cdb_name, sa);
147 else
148 off = scnprintf(buffer, buf_len,
149 "opcode=0x%x, sa=0x%x", cdb0, sa);
150 }
151 WARN_ON(off >= buf_len);
152 return off;
153 }
154
__scsi_format_command(char * logbuf,size_t logbuf_len,const unsigned char * cdb,size_t cdb_len)155 size_t __scsi_format_command(char *logbuf, size_t logbuf_len,
156 const unsigned char *cdb, size_t cdb_len)
157 {
158 int len, k;
159 size_t off;
160
161 off = scsi_format_opcode_name(logbuf, logbuf_len, cdb);
162 if (off >= logbuf_len)
163 return off;
164 len = scsi_command_size(cdb);
165 if (cdb_len < len)
166 len = cdb_len;
167 /* print out all bytes in cdb */
168 for (k = 0; k < len; ++k) {
169 if (off > logbuf_len - 3)
170 break;
171 off += scnprintf(logbuf + off, logbuf_len - off,
172 " %02x", cdb[k]);
173 }
174 return off;
175 }
176 EXPORT_SYMBOL(__scsi_format_command);
177
scsi_print_command(struct scsi_cmnd * cmd)178 void scsi_print_command(struct scsi_cmnd *cmd)
179 {
180 int k;
181 char *logbuf;
182 size_t off, logbuf_len;
183
184 if (!cmd->cmnd)
185 return;
186
187 logbuf = scsi_log_reserve_buffer(&logbuf_len);
188 if (!logbuf)
189 return;
190
191 off = sdev_format_header(logbuf, logbuf_len,
192 scmd_name(cmd), cmd->request->tag);
193 if (off >= logbuf_len)
194 goto out_printk;
195 off += scnprintf(logbuf + off, logbuf_len - off, "CDB: ");
196 if (WARN_ON(off >= logbuf_len))
197 goto out_printk;
198
199 off += scsi_format_opcode_name(logbuf + off, logbuf_len - off,
200 cmd->cmnd);
201 if (off >= logbuf_len)
202 goto out_printk;
203
204 /* print out all bytes in cdb */
205 if (cmd->cmd_len > 16) {
206 /* Print opcode in one line and use separate lines for CDB */
207 off += scnprintf(logbuf + off, logbuf_len - off, "\n");
208 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);
209 scsi_log_release_buffer(logbuf);
210 for (k = 0; k < cmd->cmd_len; k += 16) {
211 size_t linelen = min(cmd->cmd_len - k, 16);
212
213 logbuf = scsi_log_reserve_buffer(&logbuf_len);
214 if (!logbuf)
215 break;
216 off = sdev_format_header(logbuf, logbuf_len,
217 scmd_name(cmd),
218 cmd->request->tag);
219 if (!WARN_ON(off > logbuf_len - 58)) {
220 off += scnprintf(logbuf + off, logbuf_len - off,
221 "CDB[%02x]: ", k);
222 hex_dump_to_buffer(&cmd->cmnd[k], linelen,
223 16, 1, logbuf + off,
224 logbuf_len - off, false);
225 }
226 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s",
227 logbuf);
228 scsi_log_release_buffer(logbuf);
229 }
230 return;
231 }
232 if (!WARN_ON(off > logbuf_len - 49)) {
233 off += scnprintf(logbuf + off, logbuf_len - off, " ");
234 hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1,
235 logbuf + off, logbuf_len - off,
236 false);
237 }
238 out_printk:
239 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);
240 scsi_log_release_buffer(logbuf);
241 }
242 EXPORT_SYMBOL(scsi_print_command);
243
244 static size_t
scsi_format_extd_sense(char * buffer,size_t buf_len,unsigned char asc,unsigned char ascq)245 scsi_format_extd_sense(char *buffer, size_t buf_len,
246 unsigned char asc, unsigned char ascq)
247 {
248 size_t off = 0;
249 const char *extd_sense_fmt = NULL;
250 const char *extd_sense_str = scsi_extd_sense_format(asc, ascq,
251 &extd_sense_fmt);
252
253 if (extd_sense_str) {
254 off = scnprintf(buffer, buf_len, "Add. Sense: %s",
255 extd_sense_str);
256 if (extd_sense_fmt)
257 off += scnprintf(buffer + off, buf_len - off,
258 "(%s%x)", extd_sense_fmt, ascq);
259 } else {
260 if (asc >= 0x80)
261 off = scnprintf(buffer, buf_len, "<<vendor>>");
262 off += scnprintf(buffer + off, buf_len - off,
263 "ASC=0x%x ", asc);
264 if (ascq >= 0x80)
265 off += scnprintf(buffer + off, buf_len - off,
266 "<<vendor>>");
267 off += scnprintf(buffer + off, buf_len - off,
268 "ASCQ=0x%x ", ascq);
269 }
270 return off;
271 }
272
273 static size_t
scsi_format_sense_hdr(char * buffer,size_t buf_len,const struct scsi_sense_hdr * sshdr)274 scsi_format_sense_hdr(char *buffer, size_t buf_len,
275 const struct scsi_sense_hdr *sshdr)
276 {
277 const char *sense_txt;
278 size_t off;
279
280 off = scnprintf(buffer, buf_len, "Sense Key : ");
281 sense_txt = scsi_sense_key_string(sshdr->sense_key);
282 if (sense_txt)
283 off += scnprintf(buffer + off, buf_len - off,
284 "%s ", sense_txt);
285 else
286 off += scnprintf(buffer + off, buf_len - off,
287 "0x%x ", sshdr->sense_key);
288 off += scnprintf(buffer + off, buf_len - off,
289 scsi_sense_is_deferred(sshdr) ? "[deferred] " : "[current] ");
290
291 if (sshdr->response_code >= 0x72)
292 off += scnprintf(buffer + off, buf_len - off, "[descriptor] ");
293 return off;
294 }
295
296 static void
scsi_log_dump_sense(const struct scsi_device * sdev,const char * name,int tag,const unsigned char * sense_buffer,int sense_len)297 scsi_log_dump_sense(const struct scsi_device *sdev, const char *name, int tag,
298 const unsigned char *sense_buffer, int sense_len)
299 {
300 char *logbuf;
301 size_t logbuf_len;
302 int i;
303
304 logbuf = scsi_log_reserve_buffer(&logbuf_len);
305 if (!logbuf)
306 return;
307
308 for (i = 0; i < sense_len; i += 16) {
309 int len = min(sense_len - i, 16);
310 size_t off;
311
312 off = sdev_format_header(logbuf, logbuf_len,
313 name, tag);
314 hex_dump_to_buffer(&sense_buffer[i], len, 16, 1,
315 logbuf + off, logbuf_len - off,
316 false);
317 dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);
318 }
319 scsi_log_release_buffer(logbuf);
320 }
321
322 static void
scsi_log_print_sense_hdr(const struct scsi_device * sdev,const char * name,int tag,const struct scsi_sense_hdr * sshdr)323 scsi_log_print_sense_hdr(const struct scsi_device *sdev, const char *name,
324 int tag, const struct scsi_sense_hdr *sshdr)
325 {
326 char *logbuf;
327 size_t off, logbuf_len;
328
329 logbuf = scsi_log_reserve_buffer(&logbuf_len);
330 if (!logbuf)
331 return;
332 off = sdev_format_header(logbuf, logbuf_len, name, tag);
333 off += scsi_format_sense_hdr(logbuf + off, logbuf_len - off, sshdr);
334 dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);
335 scsi_log_release_buffer(logbuf);
336
337 logbuf = scsi_log_reserve_buffer(&logbuf_len);
338 if (!logbuf)
339 return;
340 off = sdev_format_header(logbuf, logbuf_len, name, tag);
341 off += scsi_format_extd_sense(logbuf + off, logbuf_len - off,
342 sshdr->asc, sshdr->ascq);
343 dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);
344 scsi_log_release_buffer(logbuf);
345 }
346
347 static void
scsi_log_print_sense(const struct scsi_device * sdev,const char * name,int tag,const unsigned char * sense_buffer,int sense_len)348 scsi_log_print_sense(const struct scsi_device *sdev, const char *name, int tag,
349 const unsigned char *sense_buffer, int sense_len)
350 {
351 struct scsi_sense_hdr sshdr;
352
353 if (scsi_normalize_sense(sense_buffer, sense_len, &sshdr))
354 scsi_log_print_sense_hdr(sdev, name, tag, &sshdr);
355 else
356 scsi_log_dump_sense(sdev, name, tag, sense_buffer, sense_len);
357 }
358
359 /*
360 * Print normalized SCSI sense header with a prefix.
361 */
362 void
scsi_print_sense_hdr(const struct scsi_device * sdev,const char * name,const struct scsi_sense_hdr * sshdr)363 scsi_print_sense_hdr(const struct scsi_device *sdev, const char *name,
364 const struct scsi_sense_hdr *sshdr)
365 {
366 scsi_log_print_sense_hdr(sdev, name, -1, sshdr);
367 }
368 EXPORT_SYMBOL(scsi_print_sense_hdr);
369
370 /* Normalize and print sense buffer with name prefix */
__scsi_print_sense(const struct scsi_device * sdev,const char * name,const unsigned char * sense_buffer,int sense_len)371 void __scsi_print_sense(const struct scsi_device *sdev, const char *name,
372 const unsigned char *sense_buffer, int sense_len)
373 {
374 scsi_log_print_sense(sdev, name, -1, sense_buffer, sense_len);
375 }
376 EXPORT_SYMBOL(__scsi_print_sense);
377
378 /* Normalize and print sense buffer in SCSI command */
scsi_print_sense(const struct scsi_cmnd * cmd)379 void scsi_print_sense(const struct scsi_cmnd *cmd)
380 {
381 scsi_log_print_sense(cmd->device, scmd_name(cmd), cmd->request->tag,
382 cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE);
383 }
384 EXPORT_SYMBOL(scsi_print_sense);
385
scsi_print_result(const struct scsi_cmnd * cmd,const char * msg,int disposition)386 void scsi_print_result(const struct scsi_cmnd *cmd, const char *msg,
387 int disposition)
388 {
389 char *logbuf;
390 size_t off, logbuf_len;
391 const char *mlret_string = scsi_mlreturn_string(disposition);
392 const char *hb_string = scsi_hostbyte_string(cmd->result);
393 const char *db_string = scsi_driverbyte_string(cmd->result);
394
395 logbuf = scsi_log_reserve_buffer(&logbuf_len);
396 if (!logbuf)
397 return;
398
399 off = sdev_format_header(logbuf, logbuf_len,
400 scmd_name(cmd), cmd->request->tag);
401
402 if (off >= logbuf_len)
403 goto out_printk;
404
405 if (msg) {
406 off += scnprintf(logbuf + off, logbuf_len - off,
407 "%s: ", msg);
408 if (WARN_ON(off >= logbuf_len))
409 goto out_printk;
410 }
411 if (mlret_string)
412 off += scnprintf(logbuf + off, logbuf_len - off,
413 "%s ", mlret_string);
414 else
415 off += scnprintf(logbuf + off, logbuf_len - off,
416 "UNKNOWN(0x%02x) ", disposition);
417 if (WARN_ON(off >= logbuf_len))
418 goto out_printk;
419
420 off += scnprintf(logbuf + off, logbuf_len - off, "Result: ");
421 if (WARN_ON(off >= logbuf_len))
422 goto out_printk;
423
424 if (hb_string)
425 off += scnprintf(logbuf + off, logbuf_len - off,
426 "hostbyte=%s ", hb_string);
427 else
428 off += scnprintf(logbuf + off, logbuf_len - off,
429 "hostbyte=0x%02x ", host_byte(cmd->result));
430 if (WARN_ON(off >= logbuf_len))
431 goto out_printk;
432
433 if (db_string)
434 off += scnprintf(logbuf + off, logbuf_len - off,
435 "driverbyte=%s", db_string);
436 else
437 off += scnprintf(logbuf + off, logbuf_len - off,
438 "driverbyte=0x%02x", driver_byte(cmd->result));
439 out_printk:
440 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);
441 scsi_log_release_buffer(logbuf);
442 }
443 EXPORT_SYMBOL(scsi_print_result);
444