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