aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorStefan Richter <stefanr@s5r6.in-berlin.de>2008-03-20 17:04:36 -0400
committerStefan Richter <stefanr@s5r6.in-berlin.de>2008-04-18 11:55:34 -0400
commitad3c0fe8b8d1656a56ce2ef05ed5ccba790b4566 (patch)
tree850c39f2da71be6ae9d6c3d5a08a67fbcded0c62
parent016bf3dfcf7c7fbad8f02e72b6e01d6773426f9d (diff)
firewire: debug interrupt events
This adds debug printks for asynchronous transmission and reception and for self ID reception. They can be enabled at module load time, and at runtime via /sys/module/firewire_ohci/parameters/debug. Signed-off-by: Jarod Wilson <jwilson@redhat.com> Also added: Logging of interrupt event codes and of cancelled AT packets. The code now depends on a Kconfig variable. This makes it easier to build firewire-ohci without the feature or to make it an option in the future. The variable is currently hidden and always on. This feature inflates firewire-ohci.ko by 7 kB = 27% on x86-64 and by 4 kB = 23% on i686. Signed-off-by: Stefan Richter <stefanr@s5r6.in-berlin.de>
-rw-r--r--drivers/firewire/Kconfig5
-rw-r--r--drivers/firewire/fw-ohci.c182
2 files changed, 187 insertions, 0 deletions
diff --git a/drivers/firewire/Kconfig b/drivers/firewire/Kconfig
index 25bdc2dd9ce1..fb4d391810b6 100644
--- a/drivers/firewire/Kconfig
+++ b/drivers/firewire/Kconfig
@@ -54,6 +54,11 @@ config FIREWIRE_OHCI
54 directive, use "install modulename /bin/true" for the modules to be 54 directive, use "install modulename /bin/true" for the modules to be
55 blacklisted. 55 blacklisted.
56 56
57config FIREWIRE_OHCI_DEBUG
58 bool
59 depends on FIREWIRE_OHCI
60 default y
61
57config FIREWIRE_SBP2 62config FIREWIRE_SBP2
58 tristate "Support for storage devices (SBP-2 protocol driver)" 63 tristate "Support for storage devices (SBP-2 protocol driver)"
59 depends on FIREWIRE && SCSI 64 depends on FIREWIRE && SCSI
diff --git a/drivers/firewire/fw-ohci.c b/drivers/firewire/fw-ohci.c
index 0c4a07f11a59..b564b1aae52f 100644
--- a/drivers/firewire/fw-ohci.c
+++ b/drivers/firewire/fw-ohci.c
@@ -27,6 +27,7 @@
27#include <linux/kernel.h> 27#include <linux/kernel.h>
28#include <linux/mm.h> 28#include <linux/mm.h>
29#include <linux/module.h> 29#include <linux/module.h>
30#include <linux/moduleparam.h>
30#include <linux/pci.h> 31#include <linux/pci.h>
31#include <linux/spinlock.h> 32#include <linux/spinlock.h>
32 33
@@ -237,6 +238,179 @@ static inline struct fw_ohci *fw_ohci(struct fw_card *card)
237 238
238static char ohci_driver_name[] = KBUILD_MODNAME; 239static char ohci_driver_name[] = KBUILD_MODNAME;
239 240
241#ifdef CONFIG_FIREWIRE_OHCI_DEBUG
242
243#define OHCI_PARAM_DEBUG_IRQS 1
244#define OHCI_PARAM_DEBUG_SELFIDS 2
245#define OHCI_PARAM_DEBUG_AT_AR 4
246
247static int param_debug;
248module_param_named(debug, param_debug, int, 0644);
249MODULE_PARM_DESC(debug, "Verbose logging (default = 0"
250 ", IRQs = " __stringify(OHCI_PARAM_DEBUG_IRQS)
251 ", self-IDs = " __stringify(OHCI_PARAM_DEBUG_SELFIDS)
252 ", AT/AR events = " __stringify(OHCI_PARAM_DEBUG_AT_AR)
253 ", or a combination, or all = -1)");
254
255static void log_irqs(u32 evt)
256{
257 if (likely(!(param_debug & OHCI_PARAM_DEBUG_IRQS)))
258 return;
259
260 printk(KERN_DEBUG KBUILD_MODNAME ": IRQ %08x%s%s%s%s%s%s%s%s%s%s%s\n",
261 evt,
262 evt & OHCI1394_selfIDComplete ? " selfID" : "",
263 evt & OHCI1394_RQPkt ? " AR_req" : "",
264 evt & OHCI1394_RSPkt ? " AR_resp" : "",
265 evt & OHCI1394_reqTxComplete ? " AT_req" : "",
266 evt & OHCI1394_respTxComplete ? " AT_resp" : "",
267 evt & OHCI1394_isochRx ? " IR" : "",
268 evt & OHCI1394_isochTx ? " IT" : "",
269 evt & OHCI1394_postedWriteErr ? " postedWriteErr" : "",
270 evt & OHCI1394_cycleTooLong ? " cycleTooLong" : "",
271 evt & OHCI1394_cycle64Seconds ? " cycle64Seconds" : "",
272 evt & ~(OHCI1394_selfIDComplete | OHCI1394_RQPkt |
273 OHCI1394_RSPkt | OHCI1394_reqTxComplete |
274 OHCI1394_respTxComplete | OHCI1394_isochRx |
275 OHCI1394_isochTx | OHCI1394_postedWriteErr |
276 OHCI1394_cycleTooLong | OHCI1394_cycle64Seconds)
277 ? " ?" : "");
278}
279
280static const char *speed[] = {
281 [0] = "S100", [1] = "S200", [2] = "S400", [3] = "beta",
282};
283static const char *power[] = {
284 [0] = "+0W", [1] = "+15W", [2] = "+30W", [3] = "+45W",
285 [4] = "-3W", [5] = " ?W", [6] = "-3..-6W", [7] = "-3..-10W",
286};
287static const char port[] = { '.', '-', 'p', 'c', };
288
289static char _p(u32 *s, int shift)
290{
291 return port[*s >> shift & 3];
292}
293
294static void log_selfids(int generation, int self_id_count, u32 *s)
295{
296 if (likely(!(param_debug & OHCI_PARAM_DEBUG_SELFIDS)))
297 return;
298
299 printk(KERN_DEBUG KBUILD_MODNAME ": %d selfIDs, generation %d\n",
300 self_id_count, generation);
301
302 for (; self_id_count--; ++s)
303 if ((*s & 1 << 23) == 0)
304 printk(KERN_DEBUG "selfID 0: %08x, phy %d [%c%c%c] "
305 "%s gc=%d %s %s%s%s\n",
306 *s, *s >> 24 & 63, _p(s, 6), _p(s, 4), _p(s, 2),
307 speed[*s >> 14 & 3], *s >> 16 & 63,
308 power[*s >> 8 & 7], *s >> 22 & 1 ? "L" : "",
309 *s >> 11 & 1 ? "c" : "", *s & 2 ? "i" : "");
310 else
311 printk(KERN_DEBUG "selfID n: %08x, phy %d "
312 "[%c%c%c%c%c%c%c%c]\n",
313 *s, *s >> 24 & 63,
314 _p(s, 16), _p(s, 14), _p(s, 12), _p(s, 10),
315 _p(s, 8), _p(s, 6), _p(s, 4), _p(s, 2));
316}
317
318static const char *evts[] = {
319 [0x00] = "evt_no_status", [0x01] = "-reserved-",
320 [0x02] = "evt_long_packet", [0x03] = "evt_missing_ack",
321 [0x04] = "evt_underrun", [0x05] = "evt_overrun",
322 [0x06] = "evt_descriptor_read", [0x07] = "evt_data_read",
323 [0x08] = "evt_data_write", [0x09] = "evt_bus_reset",
324 [0x0a] = "evt_timeout", [0x0b] = "evt_tcode_err",
325 [0x0c] = "-reserved-", [0x0d] = "-reserved-",
326 [0x0e] = "evt_unknown", [0x0f] = "evt_flushed",
327 [0x10] = "-reserved-", [0x11] = "ack_complete",
328 [0x12] = "ack_pending ", [0x13] = "-reserved-",
329 [0x14] = "ack_busy_X", [0x15] = "ack_busy_A",
330 [0x16] = "ack_busy_B", [0x17] = "-reserved-",
331 [0x18] = "-reserved-", [0x19] = "-reserved-",
332 [0x1a] = "-reserved-", [0x1b] = "ack_tardy",
333 [0x1c] = "-reserved-", [0x1d] = "ack_data_error",
334 [0x1e] = "ack_type_error", [0x1f] = "-reserved-",
335 [0x20] = "pending/cancelled",
336};
337static const char *tcodes[] = {
338 [0x0] = "QW req", [0x1] = "BW req",
339 [0x2] = "W resp", [0x3] = "-reserved-",
340 [0x4] = "QR req", [0x5] = "BR req",
341 [0x6] = "QR resp", [0x7] = "BR resp",
342 [0x8] = "cycle start", [0x9] = "Lk req",
343 [0xa] = "async stream packet", [0xb] = "Lk resp",
344 [0xc] = "-reserved-", [0xd] = "-reserved-",
345 [0xe] = "link internal", [0xf] = "-reserved-",
346};
347static const char *phys[] = {
348 [0x0] = "phy config packet", [0x1] = "link-on packet",
349 [0x2] = "self-id packet", [0x3] = "-reserved-",
350};
351
352static void log_ar_at_event(char dir, int speed, u32 *header, int evt)
353{
354 int tcode = header[0] >> 4 & 0xf;
355 char specific[12];
356
357 if (likely(!(param_debug & OHCI_PARAM_DEBUG_AT_AR)))
358 return;
359
360 if (unlikely(evt >= ARRAY_SIZE(evts)))
361 evt = 0x1f;
362
363 if (header[0] == ~header[1]) {
364 printk(KERN_DEBUG "A%c %s, %s, %08x\n",
365 dir, evts[evt], phys[header[0] >> 30 & 0x3],
366 header[0]);
367 return;
368 }
369
370 switch (tcode) {
371 case 0x0: case 0x6: case 0x8:
372 snprintf(specific, sizeof(specific), " = %08x",
373 be32_to_cpu((__force __be32)header[3]));
374 break;
375 case 0x1: case 0x5: case 0x7: case 0x9: case 0xb:
376 snprintf(specific, sizeof(specific), " %x,%x",
377 header[3] >> 16, header[3] & 0xffff);
378 break;
379 default:
380 specific[0] = '\0';
381 }
382
383 switch (tcode) {
384 case 0xe: case 0xa:
385 printk(KERN_DEBUG "A%c %s, %s\n",
386 dir, evts[evt], tcodes[tcode]);
387 break;
388 case 0x0: case 0x1: case 0x4: case 0x5: case 0x9:
389 printk(KERN_DEBUG "A%c spd %x tl %02x, "
390 "%04x -> %04x, %s, "
391 "%s, %04x%08x%s\n",
392 dir, speed, header[0] >> 10 & 0x3f,
393 header[1] >> 16, header[0] >> 16, evts[evt],
394 tcodes[tcode], header[1] & 0xffff, header[2], specific);
395 break;
396 default:
397 printk(KERN_DEBUG "A%c spd %x tl %02x, "
398 "%04x -> %04x, %s, "
399 "%s%s\n",
400 dir, speed, header[0] >> 10 & 0x3f,
401 header[1] >> 16, header[0] >> 16, evts[evt],
402 tcodes[tcode], specific);
403 }
404}
405
406#else
407
408#define log_irqs(evt)
409#define log_selfids(generation, self_id_count, sid)
410#define log_ar_at_event(dir, speed, header, evt)
411
412#endif /* CONFIG_FIREWIRE_OHCI_DEBUG */
413
240static inline void reg_write(const struct fw_ohci *ohci, int offset, u32 data) 414static inline void reg_write(const struct fw_ohci *ohci, int offset, u32 data)
241{ 415{
242 writel(data, ohci->registers + offset); 416 writel(data, ohci->registers + offset);
@@ -368,6 +542,8 @@ static __le32 *handle_ar_packet(struct ar_context *ctx, __le32 *buffer)
368 p.timestamp = status & 0xffff; 542 p.timestamp = status & 0xffff;
369 p.generation = ohci->request_generation; 543 p.generation = ohci->request_generation;
370 544
545 log_ar_at_event('R', p.speed, p.header, status >> 16 & 0x1f);
546
371 /* 547 /*
372 * The OHCI bus reset handler synthesizes a phy packet with 548 * The OHCI bus reset handler synthesizes a phy packet with
373 * the new generation number when a bus reset happens (see 549 * the new generation number when a bus reset happens (see
@@ -817,6 +993,8 @@ static int handle_at_packet(struct context *context,
817 evt = le16_to_cpu(last->transfer_status) & 0x1f; 993 evt = le16_to_cpu(last->transfer_status) & 0x1f;
818 packet->timestamp = le16_to_cpu(last->res_count); 994 packet->timestamp = le16_to_cpu(last->res_count);
819 995
996 log_ar_at_event('T', packet->speed, packet->header, evt);
997
820 switch (evt) { 998 switch (evt) {
821 case OHCI1394_evt_timeout: 999 case OHCI1394_evt_timeout:
822 /* Async response transmit timed out. */ 1000 /* Async response transmit timed out. */
@@ -1118,6 +1296,8 @@ static void bus_reset_tasklet(unsigned long data)
1118 dma_free_coherent(ohci->card.device, CONFIG_ROM_SIZE, 1296 dma_free_coherent(ohci->card.device, CONFIG_ROM_SIZE,
1119 free_rom, free_rom_bus); 1297 free_rom, free_rom_bus);
1120 1298
1299 log_selfids(generation, self_id_count, ohci->self_id_buffer);
1300
1121 fw_core_handle_bus_reset(&ohci->card, ohci->node_id, generation, 1301 fw_core_handle_bus_reset(&ohci->card, ohci->node_id, generation,
1122 self_id_count, ohci->self_id_buffer); 1302 self_id_count, ohci->self_id_buffer);
1123} 1303}
@@ -1134,6 +1314,7 @@ static irqreturn_t irq_handler(int irq, void *data)
1134 return IRQ_NONE; 1314 return IRQ_NONE;
1135 1315
1136 reg_write(ohci, OHCI1394_IntEventClear, event); 1316 reg_write(ohci, OHCI1394_IntEventClear, event);
1317 log_irqs(event);
1137 1318
1138 if (event & OHCI1394_selfIDComplete) 1319 if (event & OHCI1394_selfIDComplete)
1139 tasklet_schedule(&ohci->bus_reset_tasklet); 1320 tasklet_schedule(&ohci->bus_reset_tasklet);
@@ -1436,6 +1617,7 @@ static int ohci_cancel_packet(struct fw_card *card, struct fw_packet *packet)
1436 if (packet->ack != 0) 1617 if (packet->ack != 0)
1437 goto out; 1618 goto out;
1438 1619
1620 log_ar_at_event('T', packet->speed, packet->header, 0x20);
1439 driver_data->packet = NULL; 1621 driver_data->packet = NULL;
1440 packet->ack = RCODE_CANCELLED; 1622 packet->ack = RCODE_CANCELLED;
1441 packet->callback(packet, &ohci->card, packet->ack); 1623 packet->callback(packet, &ohci->card, packet->ack);