diff options
author | Swen Schillig <swen@vnet.ibm.com> | 2010-12-02 09:16:12 -0500 |
---|---|---|
committer | James Bottomley <James.Bottomley@suse.de> | 2010-12-21 13:24:44 -0500 |
commit | ae0904f60fab7cb20c48d32eefdd735e478b91fb (patch) | |
tree | e856784159e1f79696a1fbaad7b680540511a992 /drivers/s390/scsi/zfcp_dbf.c | |
parent | 6b57b159709dcb4d53e64738f2d1f73b36e41601 (diff) |
[SCSI] zfcp: Redesign of the debug tracing for recovery actions.
The tracing environment of the zfcp LLD has become very bulky and hard
to maintain. Small changes involve a large modification process which
is error-prone and not effective. This patch is the first of a set to
redesign the zfcp tracing to a more straight-forward and easy to
extend scheme. It removes all interpretation and visualization parts
and focuses on bare logging of the information.
This patch deals with all trace records of the zfcp error recovery.
Signed-off-by: Swen schillig <swen@vnet.ibm.com>
Signed-off-by: Christof Schmitt <christof.schmitt@de.ibm.com>
Signed-off-by: James Bottomley <James.Bottomley@suse.de>
Diffstat (limited to 'drivers/s390/scsi/zfcp_dbf.c')
-rw-r--r-- | drivers/s390/scsi/zfcp_dbf.c | 281 |
1 files changed, 65 insertions, 216 deletions
diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index 2cdd6b28ff7f..675503628cc9 100644 --- a/drivers/s390/scsi/zfcp_dbf.c +++ b/drivers/s390/scsi/zfcp_dbf.c | |||
@@ -50,11 +50,6 @@ static void zfcp_dbf_tag(char **p, const char *label, const char *tag) | |||
50 | *p += sprintf(*p, "\n"); | 50 | *p += sprintf(*p, "\n"); |
51 | } | 51 | } |
52 | 52 | ||
53 | static void zfcp_dbf_outs(char **buf, const char *s1, const char *s2) | ||
54 | { | ||
55 | *buf += sprintf(*buf, "%-24s%s\n", s1, s2); | ||
56 | } | ||
57 | |||
58 | static void zfcp_dbf_out(char **buf, const char *s, const char *format, ...) | 53 | static void zfcp_dbf_out(char **buf, const char *s, const char *format, ...) |
59 | { | 54 | { |
60 | va_list arg; | 55 | va_list arg; |
@@ -439,241 +434,96 @@ static struct debug_view zfcp_dbf_hba_view = { | |||
439 | .format_proc = zfcp_dbf_hba_view_format, | 434 | .format_proc = zfcp_dbf_hba_view_format, |
440 | }; | 435 | }; |
441 | 436 | ||
442 | static const char *zfcp_dbf_rec_tags[] = { | 437 | static void zfcp_dbf_set_common(struct zfcp_dbf_rec *rec, |
443 | [ZFCP_REC_DBF_ID_THREAD] = "thread", | 438 | struct zfcp_adapter *adapter, |
444 | [ZFCP_REC_DBF_ID_TARGET] = "target", | 439 | struct zfcp_port *port, |
445 | [ZFCP_REC_DBF_ID_TRIGGER] = "trigger", | 440 | struct scsi_device *sdev) |
446 | [ZFCP_REC_DBF_ID_ACTION] = "action", | ||
447 | }; | ||
448 | |||
449 | static int zfcp_dbf_rec_view_format(debug_info_t *id, struct debug_view *view, | ||
450 | char *buf, const char *_rec) | ||
451 | { | 441 | { |
452 | struct zfcp_dbf_rec_record *r = (struct zfcp_dbf_rec_record *)_rec; | 442 | rec->adapter_status = atomic_read(&adapter->status); |
453 | char *p = buf; | 443 | if (port) { |
454 | char hint[ZFCP_DBF_ID_SIZE + 1]; | 444 | rec->port_status = atomic_read(&port->status); |
455 | 445 | rec->wwpn = port->wwpn; | |
456 | memcpy(hint, r->id2, ZFCP_DBF_ID_SIZE); | 446 | rec->d_id = port->d_id; |
457 | hint[ZFCP_DBF_ID_SIZE] = 0; | 447 | } |
458 | zfcp_dbf_outs(&p, "tag", zfcp_dbf_rec_tags[r->id]); | 448 | if (sdev) { |
459 | zfcp_dbf_outs(&p, "hint", hint); | 449 | rec->lun_status = atomic_read(&sdev_to_zfcp(sdev)->status); |
460 | switch (r->id) { | 450 | rec->lun = zfcp_scsi_dev_lun(sdev); |
461 | case ZFCP_REC_DBF_ID_THREAD: | ||
462 | zfcp_dbf_out(&p, "total", "%d", r->u.thread.total); | ||
463 | zfcp_dbf_out(&p, "ready", "%d", r->u.thread.ready); | ||
464 | zfcp_dbf_out(&p, "running", "%d", r->u.thread.running); | ||
465 | break; | ||
466 | case ZFCP_REC_DBF_ID_TARGET: | ||
467 | zfcp_dbf_out(&p, "reference", "0x%016Lx", r->u.target.ref); | ||
468 | zfcp_dbf_out(&p, "status", "0x%08x", r->u.target.status); | ||
469 | zfcp_dbf_out(&p, "erp_count", "%d", r->u.target.erp_count); | ||
470 | zfcp_dbf_out(&p, "d_id", "0x%06x", r->u.target.d_id); | ||
471 | zfcp_dbf_out(&p, "wwpn", "0x%016Lx", r->u.target.wwpn); | ||
472 | zfcp_dbf_out(&p, "fcp_lun", "0x%016Lx", r->u.target.fcp_lun); | ||
473 | break; | ||
474 | case ZFCP_REC_DBF_ID_TRIGGER: | ||
475 | zfcp_dbf_out(&p, "reference", "0x%016Lx", r->u.trigger.ref); | ||
476 | zfcp_dbf_out(&p, "erp_action", "0x%016Lx", r->u.trigger.action); | ||
477 | zfcp_dbf_out(&p, "requested", "%d", r->u.trigger.want); | ||
478 | zfcp_dbf_out(&p, "executed", "%d", r->u.trigger.need); | ||
479 | zfcp_dbf_out(&p, "wwpn", "0x%016Lx", r->u.trigger.wwpn); | ||
480 | zfcp_dbf_out(&p, "fcp_lun", "0x%016Lx", r->u.trigger.fcp_lun); | ||
481 | zfcp_dbf_out(&p, "adapter_status", "0x%08x", r->u.trigger.as); | ||
482 | zfcp_dbf_out(&p, "port_status", "0x%08x", r->u.trigger.ps); | ||
483 | zfcp_dbf_out(&p, "lun_status", "0x%08x", r->u.trigger.ls); | ||
484 | break; | ||
485 | case ZFCP_REC_DBF_ID_ACTION: | ||
486 | zfcp_dbf_out(&p, "erp_action", "0x%016Lx", r->u.action.action); | ||
487 | zfcp_dbf_out(&p, "fsf_req", "0x%016Lx", r->u.action.fsf_req); | ||
488 | zfcp_dbf_out(&p, "status", "0x%08Lx", r->u.action.status); | ||
489 | zfcp_dbf_out(&p, "step", "0x%08Lx", r->u.action.step); | ||
490 | break; | ||
491 | } | 451 | } |
492 | p += sprintf(p, "\n"); | ||
493 | return p - buf; | ||
494 | } | 452 | } |
495 | 453 | ||
496 | static struct debug_view zfcp_dbf_rec_view = { | ||
497 | .name = "structured", | ||
498 | .header_proc = zfcp_dbf_view_header, | ||
499 | .format_proc = zfcp_dbf_rec_view_format, | ||
500 | }; | ||
501 | |||
502 | /** | 454 | /** |
503 | * zfcp_dbf_rec_thread - trace event related to recovery thread operation | 455 | * zfcp_dbf_rec_trig - trace event related to triggered recovery |
504 | * @id2: identifier for event | 456 | * @tag: identifier for event |
505 | * @dbf: reference to dbf structure | 457 | * @adapter: adapter on which the erp_action should run |
506 | * This function assumes that the caller is holding erp_lock. | 458 | * @port: remote port involved in the erp_action |
459 | * @sdev: scsi device involved in the erp_action | ||
460 | * @want: wanted erp_action | ||
461 | * @need: required erp_action | ||
462 | * | ||
463 | * The adapter->erp_lock has to be held. | ||
507 | */ | 464 | */ |
508 | void zfcp_dbf_rec_thread(char *id2, struct zfcp_dbf *dbf) | 465 | void zfcp_dbf_rec_trig(char *tag, struct zfcp_adapter *adapter, |
466 | struct zfcp_port *port, struct scsi_device *sdev, | ||
467 | u8 want, u8 need) | ||
509 | { | 468 | { |
510 | struct zfcp_adapter *adapter = dbf->adapter; | 469 | struct zfcp_dbf *dbf = adapter->dbf; |
511 | struct zfcp_dbf_rec_record *r = &dbf->rec_buf; | 470 | struct zfcp_dbf_rec *rec = &dbf->rec_buf; |
512 | unsigned long flags = 0; | ||
513 | struct list_head *entry; | 471 | struct list_head *entry; |
514 | unsigned ready = 0, running = 0, total; | ||
515 | |||
516 | list_for_each(entry, &adapter->erp_ready_head) | ||
517 | ready++; | ||
518 | list_for_each(entry, &adapter->erp_running_head) | ||
519 | running++; | ||
520 | total = adapter->erp_total_count; | ||
521 | |||
522 | spin_lock_irqsave(&dbf->rec_lock, flags); | ||
523 | memset(r, 0, sizeof(*r)); | ||
524 | r->id = ZFCP_REC_DBF_ID_THREAD; | ||
525 | memcpy(r->id2, id2, ZFCP_DBF_ID_SIZE); | ||
526 | r->u.thread.total = total; | ||
527 | r->u.thread.ready = ready; | ||
528 | r->u.thread.running = running; | ||
529 | debug_event(dbf->rec, 6, r, sizeof(*r)); | ||
530 | spin_unlock_irqrestore(&dbf->rec_lock, flags); | ||
531 | } | ||
532 | |||
533 | /** | ||
534 | * zfcp_dbf_rec_thread - trace event related to recovery thread operation | ||
535 | * @id2: identifier for event | ||
536 | * @adapter: adapter | ||
537 | * This function assumes that the caller does not hold erp_lock. | ||
538 | */ | ||
539 | void zfcp_dbf_rec_thread_lock(char *id2, struct zfcp_dbf *dbf) | ||
540 | { | ||
541 | struct zfcp_adapter *adapter = dbf->adapter; | ||
542 | unsigned long flags; | ||
543 | |||
544 | read_lock_irqsave(&adapter->erp_lock, flags); | ||
545 | zfcp_dbf_rec_thread(id2, dbf); | ||
546 | read_unlock_irqrestore(&adapter->erp_lock, flags); | ||
547 | } | ||
548 | |||
549 | static void zfcp_dbf_rec_target(char *id2, void *ref, struct zfcp_dbf *dbf, | ||
550 | atomic_t *status, atomic_t *erp_count, u64 wwpn, | ||
551 | u32 d_id, u64 fcp_lun) | ||
552 | { | ||
553 | struct zfcp_dbf_rec_record *r = &dbf->rec_buf; | ||
554 | unsigned long flags; | 472 | unsigned long flags; |
555 | 473 | ||
556 | spin_lock_irqsave(&dbf->rec_lock, flags); | 474 | spin_lock_irqsave(&dbf->rec_lock, flags); |
557 | memset(r, 0, sizeof(*r)); | 475 | memset(rec, 0, sizeof(*rec)); |
558 | r->id = ZFCP_REC_DBF_ID_TARGET; | ||
559 | memcpy(r->id2, id2, ZFCP_DBF_ID_SIZE); | ||
560 | r->u.target.ref = (unsigned long)ref; | ||
561 | r->u.target.status = atomic_read(status); | ||
562 | r->u.target.wwpn = wwpn; | ||
563 | r->u.target.d_id = d_id; | ||
564 | r->u.target.fcp_lun = fcp_lun; | ||
565 | r->u.target.erp_count = atomic_read(erp_count); | ||
566 | debug_event(dbf->rec, 3, r, sizeof(*r)); | ||
567 | spin_unlock_irqrestore(&dbf->rec_lock, flags); | ||
568 | } | ||
569 | |||
570 | /** | ||
571 | * zfcp_dbf_rec_adapter - trace event for adapter state change | ||
572 | * @id: identifier for trigger of state change | ||
573 | * @ref: additional reference (e.g. request) | ||
574 | * @dbf: reference to dbf structure | ||
575 | */ | ||
576 | void zfcp_dbf_rec_adapter(char *id, void *ref, struct zfcp_dbf *dbf) | ||
577 | { | ||
578 | struct zfcp_adapter *adapter = dbf->adapter; | ||
579 | 476 | ||
580 | zfcp_dbf_rec_target(id, ref, dbf, &adapter->status, | 477 | rec->id = ZFCP_DBF_REC_TRIG; |
581 | &adapter->erp_counter, 0, 0, | 478 | memcpy(rec->tag, tag, ZFCP_DBF_TAG_LEN); |
582 | ZFCP_DBF_INVALID_LUN); | 479 | zfcp_dbf_set_common(rec, adapter, port, sdev); |
583 | } | ||
584 | 480 | ||
585 | /** | 481 | list_for_each(entry, &adapter->erp_ready_head) |
586 | * zfcp_dbf_rec_port - trace event for port state change | 482 | rec->u.trig.ready++; |
587 | * @id: identifier for trigger of state change | ||
588 | * @ref: additional reference (e.g. request) | ||
589 | * @port: port | ||
590 | */ | ||
591 | void zfcp_dbf_rec_port(char *id, void *ref, struct zfcp_port *port) | ||
592 | { | ||
593 | struct zfcp_dbf *dbf = port->adapter->dbf; | ||
594 | 483 | ||
595 | zfcp_dbf_rec_target(id, ref, dbf, &port->status, | 484 | list_for_each(entry, &adapter->erp_running_head) |
596 | &port->erp_counter, port->wwpn, port->d_id, | 485 | rec->u.trig.running++; |
597 | ZFCP_DBF_INVALID_LUN); | ||
598 | } | ||
599 | 486 | ||
600 | /** | 487 | rec->u.trig.want = want; |
601 | * zfcp_dbf_rec_lun - trace event for LUN state change | 488 | rec->u.trig.need = need; |
602 | * @id: identifier for trigger of state change | ||
603 | * @ref: additional reference (e.g. request) | ||
604 | * @sdev: SCSI device | ||
605 | */ | ||
606 | void zfcp_dbf_rec_lun(char *id, void *ref, struct scsi_device *sdev) | ||
607 | { | ||
608 | struct zfcp_scsi_dev *zfcp_sdev = sdev_to_zfcp(sdev); | ||
609 | struct zfcp_port *port = zfcp_sdev->port; | ||
610 | struct zfcp_dbf *dbf = port->adapter->dbf; | ||
611 | 489 | ||
612 | zfcp_dbf_rec_target(id, ref, dbf, &zfcp_sdev->status, | 490 | debug_event(dbf->rec, 1, rec, sizeof(*rec)); |
613 | &zfcp_sdev->erp_counter, port->wwpn, port->d_id, | 491 | spin_unlock_irqrestore(&dbf->rec_lock, flags); |
614 | zfcp_scsi_dev_lun(sdev)); | ||
615 | } | 492 | } |
616 | 493 | ||
494 | |||
617 | /** | 495 | /** |
618 | * zfcp_dbf_rec_trigger - trace event for triggered error recovery | 496 | * zfcp_dbf_rec_run - trace event related to running recovery |
619 | * @id2: identifier for error recovery trigger | 497 | * @tag: identifier for event |
620 | * @ref: additional reference (e.g. request) | 498 | * @erp: erp_action running |
621 | * @want: originally requested error recovery action | ||
622 | * @need: error recovery action actually initiated | ||
623 | * @action: address of error recovery action struct | ||
624 | * @adapter: adapter | ||
625 | * @port: port | ||
626 | * @sdev: SCSI device | ||
627 | */ | 499 | */ |
628 | void zfcp_dbf_rec_trigger(char *id2, void *ref, u8 want, u8 need, void *action, | 500 | void zfcp_dbf_rec_run(char *tag, struct zfcp_erp_action *erp) |
629 | struct zfcp_adapter *adapter, struct zfcp_port *port, | ||
630 | struct scsi_device *sdev) | ||
631 | { | 501 | { |
632 | struct zfcp_dbf *dbf = adapter->dbf; | 502 | struct zfcp_dbf *dbf = erp->adapter->dbf; |
633 | struct zfcp_dbf_rec_record *r = &dbf->rec_buf; | 503 | struct zfcp_dbf_rec *rec = &dbf->rec_buf; |
634 | unsigned long flags; | 504 | unsigned long flags; |
635 | 505 | ||
636 | spin_lock_irqsave(&dbf->rec_lock, flags); | 506 | spin_lock_irqsave(&dbf->rec_lock, flags); |
637 | memset(r, 0, sizeof(*r)); | 507 | memset(rec, 0, sizeof(*rec)); |
638 | r->id = ZFCP_REC_DBF_ID_TRIGGER; | ||
639 | memcpy(r->id2, id2, ZFCP_DBF_ID_SIZE); | ||
640 | r->u.trigger.ref = (unsigned long)ref; | ||
641 | r->u.trigger.want = want; | ||
642 | r->u.trigger.need = need; | ||
643 | r->u.trigger.action = (unsigned long)action; | ||
644 | r->u.trigger.as = atomic_read(&adapter->status); | ||
645 | if (port) { | ||
646 | r->u.trigger.ps = atomic_read(&port->status); | ||
647 | r->u.trigger.wwpn = port->wwpn; | ||
648 | } | ||
649 | if (sdev) | ||
650 | r->u.trigger.ls = atomic_read(&sdev_to_zfcp(sdev)->status); | ||
651 | r->u.trigger.fcp_lun = sdev ? zfcp_scsi_dev_lun(sdev) : | ||
652 | ZFCP_DBF_INVALID_LUN; | ||
653 | debug_event(dbf->rec, action ? 1 : 4, r, sizeof(*r)); | ||
654 | spin_unlock_irqrestore(&dbf->rec_lock, flags); | ||
655 | } | ||
656 | 508 | ||
657 | /** | 509 | rec->id = ZFCP_DBF_REC_RUN; |
658 | * zfcp_dbf_rec_action - trace event showing progress of recovery action | 510 | memcpy(rec->tag, tag, ZFCP_DBF_TAG_LEN); |
659 | * @id2: identifier | 511 | zfcp_dbf_set_common(rec, erp->adapter, erp->port, erp->sdev); |
660 | * @erp_action: error recovery action struct pointer | ||
661 | */ | ||
662 | void zfcp_dbf_rec_action(char *id2, struct zfcp_erp_action *erp_action) | ||
663 | { | ||
664 | struct zfcp_dbf *dbf = erp_action->adapter->dbf; | ||
665 | struct zfcp_dbf_rec_record *r = &dbf->rec_buf; | ||
666 | unsigned long flags; | ||
667 | 512 | ||
668 | spin_lock_irqsave(&dbf->rec_lock, flags); | 513 | rec->u.run.fsf_req_id = erp->fsf_req_id; |
669 | memset(r, 0, sizeof(*r)); | 514 | rec->u.run.rec_status = erp->status; |
670 | r->id = ZFCP_REC_DBF_ID_ACTION; | 515 | rec->u.run.rec_step = erp->step; |
671 | memcpy(r->id2, id2, ZFCP_DBF_ID_SIZE); | 516 | rec->u.run.rec_action = erp->action; |
672 | r->u.action.action = (unsigned long)erp_action; | 517 | |
673 | r->u.action.status = erp_action->status; | 518 | if (erp->sdev) |
674 | r->u.action.step = erp_action->step; | 519 | rec->u.run.rec_count = |
675 | r->u.action.fsf_req = erp_action->fsf_req_id; | 520 | atomic_read(&sdev_to_zfcp(erp->sdev)->erp_counter); |
676 | debug_event(dbf->rec, 5, r, sizeof(*r)); | 521 | else if (erp->port) |
522 | rec->u.run.rec_count = atomic_read(&erp->port->erp_counter); | ||
523 | else | ||
524 | rec->u.run.rec_count = atomic_read(&erp->adapter->erp_counter); | ||
525 | |||
526 | debug_event(dbf->rec, 1, rec, sizeof(*rec)); | ||
677 | spin_unlock_irqrestore(&dbf->rec_lock, flags); | 527 | spin_unlock_irqrestore(&dbf->rec_lock, flags); |
678 | } | 528 | } |
679 | 529 | ||
@@ -1019,8 +869,7 @@ int zfcp_dbf_adapter_register(struct zfcp_adapter *adapter) | |||
1019 | 869 | ||
1020 | /* debug feature area which records recovery activity */ | 870 | /* debug feature area which records recovery activity */ |
1021 | sprintf(dbf_name, "zfcp_%s_rec", dev_name(&adapter->ccw_device->dev)); | 871 | sprintf(dbf_name, "zfcp_%s_rec", dev_name(&adapter->ccw_device->dev)); |
1022 | dbf->rec = zfcp_dbf_reg(dbf_name, 3, &zfcp_dbf_rec_view, | 872 | dbf->rec = zfcp_dbf_reg(dbf_name, 3, NULL, sizeof(struct zfcp_dbf_rec)); |
1023 | sizeof(struct zfcp_dbf_rec_record)); | ||
1024 | if (!dbf->rec) | 873 | if (!dbf->rec) |
1025 | goto err_out; | 874 | goto err_out; |
1026 | 875 | ||