xref: /linux/drivers/scsi/scsi_logging.c (revision 0ad53fe3ae82443c74ff8cfd7bd13377cc1134a3)
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 	return rq->rq_disk ? rq->rq_disk->disk_name : NULL;
34 }
35 
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 
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 
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 				 scsi_cmd_to_rq((struct scsi_cmnd *)scmd)->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 
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 
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 
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), scsi_cmd_to_rq(cmd)->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 		for (k = 0; k < cmd->cmd_len; k += 16) {
210 			size_t linelen = min(cmd->cmd_len - k, 16);
211 
212 			off = sdev_format_header(logbuf, logbuf_len,
213 						 scmd_name(cmd),
214 						 scsi_cmd_to_rq(cmd)->tag);
215 			if (!WARN_ON(off > logbuf_len - 58)) {
216 				off += scnprintf(logbuf + off, logbuf_len - off,
217 						 "CDB[%02x]: ", k);
218 				hex_dump_to_buffer(&cmd->cmnd[k], linelen,
219 						   16, 1, logbuf + off,
220 						   logbuf_len - off, false);
221 			}
222 			dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s",
223 				   logbuf);
224 		}
225 		goto out;
226 	}
227 	if (!WARN_ON(off > logbuf_len - 49)) {
228 		off += scnprintf(logbuf + off, logbuf_len - off, " ");
229 		hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1,
230 				   logbuf + off, logbuf_len - off,
231 				   false);
232 	}
233 out_printk:
234 	dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);
235 out:
236 	scsi_log_release_buffer(logbuf);
237 }
238 EXPORT_SYMBOL(scsi_print_command);
239 
240 static size_t
241 scsi_format_extd_sense(char *buffer, size_t buf_len,
242 		       unsigned char asc, unsigned char ascq)
243 {
244 	size_t off = 0;
245 	const char *extd_sense_fmt = NULL;
246 	const char *extd_sense_str = scsi_extd_sense_format(asc, ascq,
247 							    &extd_sense_fmt);
248 
249 	if (extd_sense_str) {
250 		off = scnprintf(buffer, buf_len, "Add. Sense: %s",
251 				extd_sense_str);
252 		if (extd_sense_fmt)
253 			off += scnprintf(buffer + off, buf_len - off,
254 					 "(%s%x)", extd_sense_fmt, ascq);
255 	} else {
256 		if (asc >= 0x80)
257 			off = scnprintf(buffer, buf_len, "<<vendor>>");
258 		off += scnprintf(buffer + off, buf_len - off,
259 				 "ASC=0x%x ", asc);
260 		if (ascq >= 0x80)
261 			off += scnprintf(buffer + off, buf_len - off,
262 					 "<<vendor>>");
263 		off += scnprintf(buffer + off, buf_len - off,
264 				 "ASCQ=0x%x ", ascq);
265 	}
266 	return off;
267 }
268 
269 static size_t
270 scsi_format_sense_hdr(char *buffer, size_t buf_len,
271 		      const struct scsi_sense_hdr *sshdr)
272 {
273 	const char *sense_txt;
274 	size_t off;
275 
276 	off = scnprintf(buffer, buf_len, "Sense Key : ");
277 	sense_txt = scsi_sense_key_string(sshdr->sense_key);
278 	if (sense_txt)
279 		off += scnprintf(buffer + off, buf_len - off,
280 				 "%s ", sense_txt);
281 	else
282 		off += scnprintf(buffer + off, buf_len - off,
283 				 "0x%x ", sshdr->sense_key);
284 	off += scnprintf(buffer + off, buf_len - off,
285 		scsi_sense_is_deferred(sshdr) ? "[deferred] " : "[current] ");
286 
287 	if (sshdr->response_code >= 0x72)
288 		off += scnprintf(buffer + off, buf_len - off, "[descriptor] ");
289 	return off;
290 }
291 
292 static void
293 scsi_log_dump_sense(const struct scsi_device *sdev, const char *name, int tag,
294 		    const unsigned char *sense_buffer, int sense_len)
295 {
296 	char *logbuf;
297 	size_t logbuf_len;
298 	int i;
299 
300 	logbuf = scsi_log_reserve_buffer(&logbuf_len);
301 	if (!logbuf)
302 		return;
303 
304 	for (i = 0; i < sense_len; i += 16) {
305 		int len = min(sense_len - i, 16);
306 		size_t off;
307 
308 		off = sdev_format_header(logbuf, logbuf_len,
309 					 name, tag);
310 		hex_dump_to_buffer(&sense_buffer[i], len, 16, 1,
311 				   logbuf + off, logbuf_len - off,
312 				   false);
313 		dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);
314 	}
315 	scsi_log_release_buffer(logbuf);
316 }
317 
318 static void
319 scsi_log_print_sense_hdr(const struct scsi_device *sdev, const char *name,
320 			 int tag, const struct scsi_sense_hdr *sshdr)
321 {
322 	char *logbuf;
323 	size_t off, logbuf_len;
324 
325 	logbuf = scsi_log_reserve_buffer(&logbuf_len);
326 	if (!logbuf)
327 		return;
328 	off = sdev_format_header(logbuf, logbuf_len, name, tag);
329 	off += scsi_format_sense_hdr(logbuf + off, logbuf_len - off, sshdr);
330 	dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);
331 	scsi_log_release_buffer(logbuf);
332 
333 	logbuf = scsi_log_reserve_buffer(&logbuf_len);
334 	if (!logbuf)
335 		return;
336 	off = sdev_format_header(logbuf, logbuf_len, name, tag);
337 	off += scsi_format_extd_sense(logbuf + off, logbuf_len - off,
338 				      sshdr->asc, sshdr->ascq);
339 	dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);
340 	scsi_log_release_buffer(logbuf);
341 }
342 
343 static void
344 scsi_log_print_sense(const struct scsi_device *sdev, const char *name, int tag,
345 		     const unsigned char *sense_buffer, int sense_len)
346 {
347 	struct scsi_sense_hdr sshdr;
348 
349 	if (scsi_normalize_sense(sense_buffer, sense_len, &sshdr))
350 		scsi_log_print_sense_hdr(sdev, name, tag, &sshdr);
351 	else
352 		scsi_log_dump_sense(sdev, name, tag, sense_buffer, sense_len);
353 }
354 
355 /*
356  * Print normalized SCSI sense header with a prefix.
357  */
358 void
359 scsi_print_sense_hdr(const struct scsi_device *sdev, const char *name,
360 		     const struct scsi_sense_hdr *sshdr)
361 {
362 	scsi_log_print_sense_hdr(sdev, name, -1, sshdr);
363 }
364 EXPORT_SYMBOL(scsi_print_sense_hdr);
365 
366 /* Normalize and print sense buffer with name prefix */
367 void __scsi_print_sense(const struct scsi_device *sdev, const char *name,
368 			const unsigned char *sense_buffer, int sense_len)
369 {
370 	scsi_log_print_sense(sdev, name, -1, sense_buffer, sense_len);
371 }
372 EXPORT_SYMBOL(__scsi_print_sense);
373 
374 /* Normalize and print sense buffer in SCSI command */
375 void scsi_print_sense(const struct scsi_cmnd *cmd)
376 {
377 	scsi_log_print_sense(cmd->device, scmd_name(cmd),
378 			     scsi_cmd_to_rq((struct scsi_cmnd *)cmd)->tag,
379 			     cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE);
380 }
381 EXPORT_SYMBOL(scsi_print_sense);
382 
383 void scsi_print_result(const struct scsi_cmnd *cmd, const char *msg,
384 		       int disposition)
385 {
386 	char *logbuf;
387 	size_t off, logbuf_len;
388 	const char *mlret_string = scsi_mlreturn_string(disposition);
389 	const char *hb_string = scsi_hostbyte_string(cmd->result);
390 	unsigned long cmd_age = (jiffies - cmd->jiffies_at_alloc) / HZ;
391 
392 	logbuf = scsi_log_reserve_buffer(&logbuf_len);
393 	if (!logbuf)
394 		return;
395 
396 	off = sdev_format_header(logbuf, logbuf_len, scmd_name(cmd),
397 				 scsi_cmd_to_rq((struct scsi_cmnd *)cmd)->tag);
398 
399 	if (off >= logbuf_len)
400 		goto out_printk;
401 
402 	if (msg) {
403 		off += scnprintf(logbuf + off, logbuf_len - off,
404 				 "%s: ", msg);
405 		if (WARN_ON(off >= logbuf_len))
406 			goto out_printk;
407 	}
408 	if (mlret_string)
409 		off += scnprintf(logbuf + off, logbuf_len - off,
410 				 "%s ", mlret_string);
411 	else
412 		off += scnprintf(logbuf + off, logbuf_len - off,
413 				 "UNKNOWN(0x%02x) ", disposition);
414 	if (WARN_ON(off >= logbuf_len))
415 		goto out_printk;
416 
417 	off += scnprintf(logbuf + off, logbuf_len - off, "Result: ");
418 	if (WARN_ON(off >= logbuf_len))
419 		goto out_printk;
420 
421 	if (hb_string)
422 		off += scnprintf(logbuf + off, logbuf_len - off,
423 				 "hostbyte=%s ", hb_string);
424 	else
425 		off += scnprintf(logbuf + off, logbuf_len - off,
426 				 "hostbyte=0x%02x ", host_byte(cmd->result));
427 	if (WARN_ON(off >= logbuf_len))
428 		goto out_printk;
429 
430 	off += scnprintf(logbuf + off, logbuf_len - off,
431 			 "driverbyte=DRIVER_OK ");
432 
433 	off += scnprintf(logbuf + off, logbuf_len - off,
434 			 "cmd_age=%lus", cmd_age);
435 
436 out_printk:
437 	dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);
438 	scsi_log_release_buffer(logbuf);
439 }
440 EXPORT_SYMBOL(scsi_print_result);
441