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