From: Martin Schwidefsky zfcp host adapter log message cleanup part 1: - Shorten log output. - Increase log level for some messages. - Always print leading zeroes for wwpn and fcp-lun. --- 25-akpm/drivers/s390/scsi/zfcp_aux.c | 213 ++++---------- 25-akpm/drivers/s390/scsi/zfcp_ccw.c | 11 25-akpm/drivers/s390/scsi/zfcp_def.h | 1 25-akpm/drivers/s390/scsi/zfcp_erp.c | 515 ++++++++++++++--------------------- 25-akpm/drivers/s390/scsi/zfcp_ext.h | 1 5 files changed, 283 insertions(+), 458 deletions(-) diff -puN drivers/s390/scsi/zfcp_aux.c~s390-8-12-zfcp-log-messages-part-1 drivers/s390/scsi/zfcp_aux.c --- 25/drivers/s390/scsi/zfcp_aux.c~s390-8-12-zfcp-log-messages-part-1 2004-04-08 13:55:18.536206240 -0700 +++ 25-akpm/drivers/s390/scsi/zfcp_aux.c 2004-04-08 13:55:18.551203960 -0700 @@ -400,11 +400,6 @@ zfcp_module_init(void) atomic_set(&zfcp_data.loglevel, loglevel); - ZFCP_LOG_DEBUG(">>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>\n"); - - ZFCP_LOG_TRACE("Start Address of module: 0x%lx\n", - (unsigned long) &zfcp_module_init); - /* initialize adapter list */ INIT_LIST_HEAD(&zfcp_data.adapter_list_head); @@ -419,22 +414,18 @@ zfcp_module_init(void) retval = register_ioctl32_conversion(zfcp_ioctl_trans.cmd, zfcp_ioctl_trans.handler); if (retval != 0) { - ZFCP_LOG_INFO("Cannot register a 32-bit support of " - "the IOC handler\n"); + ZFCP_LOG_INFO("registration of ioctl32 conversion failed\n"); goto out_ioctl32; } #endif retval = misc_register(&zfcp_cfdc_misc); if (retval != 0) { - ZFCP_LOG_INFO( - "Device file for the control file data channel " - "cannot be registered\n"); + ZFCP_LOG_INFO("registration of misc device " + "zfcp_cfdc failed\n"); goto out_misc_register; } else { - ZFCP_LOG_INFO( - "Device file for the control file data channel " - "has become MAJOR/MINOR numbers %d/%d\n", - ZFCP_CFDC_DEV_MAJOR, zfcp_cfdc_misc.minor); + ZFCP_LOG_TRACE("major/minor for zfcp_cfdc: %d/%d\n", + ZFCP_CFDC_DEV_MAJOR, zfcp_cfdc_misc.minor); } /* Initialise proc semaphores */ @@ -452,7 +443,7 @@ zfcp_module_init(void) /* setup dynamic I/O */ retval = zfcp_ccw_register(); if (retval) { - ZFCP_LOG_NORMAL("Registering with common I/O layer failed.\n"); + ZFCP_LOG_NORMAL("registration with common I/O layer failed\n"); goto out_ccw_register; } @@ -521,46 +512,35 @@ zfcp_cfdc_dev_ioctl(struct inode *inode, char *bus_id = NULL; int retval = 0; - ZFCP_LOG_NORMAL( - "Control file data channel transaction opened\n"); - sg_list = kmalloc(sizeof(struct zfcp_sg_list), GFP_KERNEL); if (sg_list == NULL) { - ZFCP_LOG_NORMAL( - "Not enough memory for the scatter-gather list\n"); retval = -ENOMEM; goto out; } sg_list->count = 0; if (command != ZFCP_CFDC_IOC) { - ZFCP_LOG_NORMAL( - "IOC request code 0x%x is not valid\n", - command); + ZFCP_LOG_INFO("IOC request code 0x%x invalid\n", command); retval = -ENOTTY; goto out; } if ((sense_data_user = (struct zfcp_cfdc_sense_data*)buffer) == NULL) { - ZFCP_LOG_NORMAL( - "Sense data record is required\n"); + ZFCP_LOG_INFO("sense data record is required\n"); retval = -EINVAL; goto out; } retval = copy_from_user(&sense_data, sense_data_user, - sizeof(struct zfcp_cfdc_sense_data)); + sizeof(struct zfcp_cfdc_sense_data)); if (retval) { - ZFCP_LOG_NORMAL("Cannot copy sense data record from user space " - "memory\n"); retval = -EFAULT; goto out; } if (sense_data.signature != ZFCP_CFDC_SIGNATURE) { - ZFCP_LOG_NORMAL( - "No valid sense data request signature 0x%08x found\n", - ZFCP_CFDC_SIGNATURE); + ZFCP_LOG_INFO("invalid sense data request signature 0x%08x\n", + ZFCP_CFDC_SIGNATURE); retval = -EINVAL; goto out; } @@ -593,16 +573,14 @@ zfcp_cfdc_dev_ioctl(struct inode *inode, break; default: - ZFCP_LOG_NORMAL( - "Command code 0x%08x is not valid\n", - sense_data.command); + ZFCP_LOG_INFO("invalid command code 0x%08x\n", + sense_data.command); retval = -EINVAL; goto out; } bus_id = kmalloc(BUS_ID_SIZE, GFP_KERNEL); if (bus_id == NULL) { - ZFCP_LOG_NORMAL("Out of memory!\n"); retval = -ENOMEM; goto out; } @@ -626,7 +604,7 @@ zfcp_cfdc_dev_ioctl(struct inode *inode, kfree(bus_id); if (retval != 0) { - ZFCP_LOG_NORMAL("Specified adapter does not exist\n"); + ZFCP_LOG_INFO("invalid adapter\n"); goto out; } @@ -634,8 +612,6 @@ zfcp_cfdc_dev_ioctl(struct inode *inode, retval = zfcp_sg_list_alloc(sg_list, ZFCP_CFDC_MAX_CONTROL_FILE_SIZE); if (retval) { - ZFCP_LOG_NORMAL("Not enough memory for the " - "scatter-gather list\n"); retval = -ENOMEM; goto out; } @@ -647,8 +623,6 @@ zfcp_cfdc_dev_ioctl(struct inode *inode, sg_list, &sense_data_user->control_file, ZFCP_CFDC_MAX_CONTROL_FILE_SIZE); if (retval) { - ZFCP_LOG_NORMAL("Cannot copy control file from user " - "space memory\n"); retval = -EFAULT; goto out; } @@ -657,12 +631,10 @@ zfcp_cfdc_dev_ioctl(struct inode *inode, retval = zfcp_fsf_control_file( adapter, &fsf_req, fsf_command, option, sg_list); if (retval == -EOPNOTSUPP) { - ZFCP_LOG_NORMAL( - "Specified adapter does not support control file\n"); + ZFCP_LOG_INFO("adapter does not support cfdc\n"); goto out; } else if (retval != 0) { - ZFCP_LOG_NORMAL( - "Cannot create or queue FSF request or create SBALs\n"); + ZFCP_LOG_INFO("initiation of cfdc up/download failed\n"); retval = -EPERM; goto out; } @@ -679,8 +651,6 @@ zfcp_cfdc_dev_ioctl(struct inode *inode, retval = copy_to_user(sense_data_user, &sense_data, sizeof(struct zfcp_cfdc_sense_data)); if (retval) { - ZFCP_LOG_NORMAL( - "Cannot copy sense data record to user space memory\n"); retval = -EFAULT; goto out; } @@ -690,8 +660,6 @@ zfcp_cfdc_dev_ioctl(struct inode *inode, &sense_data_user->control_file, sg_list, ZFCP_CFDC_MAX_CONTROL_FILE_SIZE); if (retval) { - ZFCP_LOG_NORMAL("Cannot copy control file to user " - "space memory\n"); retval = -EFAULT; goto out; } @@ -709,9 +677,6 @@ zfcp_cfdc_dev_ioctl(struct inode *inode, kfree(sg_list); } - ZFCP_LOG_NORMAL( - "Control file data channel transaction closed\n"); - return retval; } @@ -804,7 +769,6 @@ zfcp_sg_list_copy_from_user(struct zfcp_ zfcp_buffer = (void*) ((page_to_pfn(sg->page) << PAGE_SHIFT) + sg->offset); if (copy_from_user(zfcp_buffer, user_buffer, length)) { - ZFCP_LOG_INFO("Memory error (copy_from_user)\n"); retval = -EFAULT; goto out; } @@ -839,7 +803,6 @@ zfcp_sg_list_copy_to_user(void *user_buf zfcp_buffer = (void*) ((page_to_pfn(sg->page) << PAGE_SHIFT) + sg->offset); if (copy_to_user(user_buffer, zfcp_buffer, length)) { - ZFCP_LOG_INFO("Memory error (copy_to_user)\n"); retval = -EFAULT; goto out; } @@ -1037,63 +1000,48 @@ zfcp_allocate_low_mem_buffers(struct zfc zfcp_mempool_alloc, zfcp_mempool_free, (void *) sizeof(struct zfcp_fsf_req_pool_element)); - if (NULL == adapter->pool.fsf_req_erp) { - ZFCP_LOG_INFO("error: pool allocation failed (fsf_req_erp)\n"); + if (NULL == adapter->pool.fsf_req_erp) return -ENOMEM; - } adapter->pool.fsf_req_scsi = mempool_create(ZFCP_POOL_FSF_REQ_SCSI_NR, zfcp_mempool_alloc, zfcp_mempool_free, (void *) sizeof(struct zfcp_fsf_req_pool_element)); - if (NULL == adapter->pool.fsf_req_scsi) { - ZFCP_LOG_INFO("error: pool allocation failed (fsf_req_scsi)\n"); + if (NULL == adapter->pool.fsf_req_scsi) return -ENOMEM; - } adapter->pool.fsf_req_abort = mempool_create(ZFCP_POOL_FSF_REQ_ABORT_NR, zfcp_mempool_alloc, zfcp_mempool_free, (void *) sizeof(struct zfcp_fsf_req_pool_element)); - if (NULL == adapter->pool.fsf_req_abort) { - ZFCP_LOG_INFO("error: pool allocation failed " - "(fsf_req_abort)\n"); + if (NULL == adapter->pool.fsf_req_abort) return -ENOMEM; - } adapter->pool.fsf_req_status_read = mempool_create(ZFCP_POOL_STATUS_READ_NR, zfcp_mempool_alloc, zfcp_mempool_free, (void *) sizeof(struct zfcp_fsf_req)); - if (NULL == adapter->pool.fsf_req_status_read) { - ZFCP_LOG_INFO("error: pool allocation failed " - "(fsf_req_status_read\n"); + if (NULL == adapter->pool.fsf_req_status_read) return -ENOMEM; - } adapter->pool.data_status_read = mempool_create(ZFCP_POOL_STATUS_READ_NR, zfcp_mempool_alloc, zfcp_mempool_free, (void *) sizeof(struct fsf_status_read_buffer)); - if (NULL == adapter->pool.data_status_read) { - ZFCP_LOG_INFO("error: pool allocation failed " - "(data_status_read)\n"); + if (NULL == adapter->pool.data_status_read) return -ENOMEM; - } adapter->pool.data_gid_pn = mempool_create(ZFCP_POOL_DATA_GID_PN_NR, zfcp_mempool_alloc, zfcp_mempool_free, (void *) sizeof(struct zfcp_gid_pn_data)); - if (NULL == adapter->pool.data_gid_pn) { - ZFCP_LOG_INFO("error: pool allocation failed (data_gid_pn)\n"); + if (NULL == adapter->pool.data_gid_pn) return -ENOMEM; - } return 0; } @@ -1229,7 +1177,7 @@ zfcp_adapter_enqueue(struct ccw_device * /* try to allocate new adapter data structure (zeroed) */ adapter = kmalloc(sizeof (struct zfcp_adapter), GFP_KERNEL); if (!adapter) { - ZFCP_LOG_INFO("error: Allocation of base adapter " + ZFCP_LOG_INFO("error: allocation of base adapter " "structure failed\n"); goto out; } @@ -1249,8 +1197,10 @@ zfcp_adapter_enqueue(struct ccw_device * goto qdio_allocate_failed; retval = zfcp_allocate_low_mem_buffers(adapter); - if (retval) + if (retval) { + ZFCP_LOG_INFO("error: pool allocation failed\n"); goto failed_low_mem_buffers; + } /* initialise reference count stuff */ atomic_set(&adapter->refcount, 0); @@ -1309,10 +1259,8 @@ zfcp_adapter_enqueue(struct ccw_device * failed_low_mem_buffers: zfcp_free_low_mem_buffers(adapter); if (qdio_free(ccw_device) != 0) - ZFCP_LOG_NORMAL - ("bug: could not free memory used by data transfer " - "mechanism for adapter %s\n", - zfcp_get_busid_by_adapter(adapter)); + ZFCP_LOG_NORMAL("bug: qdio_free for adapter %s failed\n", + zfcp_get_busid_by_adapter(adapter)); qdio_allocate_failed: zfcp_qdio_free_queues(adapter); queues_alloc_failed: @@ -1343,12 +1291,10 @@ zfcp_adapter_dequeue(struct zfcp_adapter retval = !list_empty(&adapter->fsf_req_list_head); read_unlock_irqrestore(&adapter->fsf_req_list_lock, flags); if (retval) { - ZFCP_LOG_NORMAL("bug: Adapter %s is still in use, " - "%i requests are still outstanding " - "(debug info 0x%lx)\n", - zfcp_get_busid_by_adapter(adapter), - atomic_read(&adapter->fsf_reqs_active), - (unsigned long) adapter); + ZFCP_LOG_NORMAL("bug: adapter %s (%p) still in use, " + "%i requests outstanding\n", + zfcp_get_busid_by_adapter(adapter), adapter, + atomic_read(&adapter->fsf_reqs_active)); retval = -EBUSY; goto out; } @@ -1361,21 +1307,20 @@ zfcp_adapter_dequeue(struct zfcp_adapter /* decrease number of adapters in list */ zfcp_data.adapters--; - ZFCP_LOG_TRACE("adapter 0x%lx removed from list, " + ZFCP_LOG_TRACE("adapter %s (%p) removed from list, " "%i adapters still in list\n", - (unsigned long) adapter, zfcp_data.adapters); + zfcp_get_busid_by_adapter(adapter), + adapter, zfcp_data.adapters); retval = qdio_free(adapter->ccw_device); if (retval) - ZFCP_LOG_NORMAL - ("bug: could not free memory used by data transfer " - "mechanism for adapter %s\n", - zfcp_get_busid_by_adapter(adapter)); + ZFCP_LOG_NORMAL("bug: qdio_free for adapter %s failed\n", + zfcp_get_busid_by_adapter(adapter)); zfcp_free_low_mem_buffers(adapter); /* free memory of adapter data structure and queues */ zfcp_qdio_free_queues(adapter); - ZFCP_LOG_TRACE("Freeing adapter structure.\n"); + ZFCP_LOG_TRACE("freeing adapter structure\n"); kfree(adapter); out: return; @@ -1504,9 +1449,8 @@ zfcp_nameserver_enqueue(struct zfcp_adap /* generate port structure */ port = zfcp_port_enqueue(adapter, 0, ZFCP_STATUS_PORT_NAMESERVER); if (!port) { - ZFCP_LOG_INFO("error: Could not establish a connection to the " - "fabric name server connected to the " - "adapter %s\n", + ZFCP_LOG_INFO("error: enqueue of nameserver port for " + "adapter %s failed\n", zfcp_get_busid_by_adapter(adapter)); return -ENXIO; } @@ -1569,8 +1513,8 @@ zfcp_fsf_incoming_els_rscn(struct zfcp_a range_mask = ZFCP_PORTS_RANGE_FABRIC; break; default: - ZFCP_LOG_INFO("Received RSCN with unknown " - "address format.\n"); + ZFCP_LOG_INFO("incoming RSCN with unknown " + "address format\n"); continue; } read_lock_irqsave(&zfcp_data.config_lock, flags); @@ -1581,11 +1525,8 @@ zfcp_fsf_incoming_els_rscn(struct zfcp_a /* Do we know this port? If not skip it. */ if (!atomic_test_mask (ZFCP_STATUS_PORT_DID_DID, &port->status)) { - ZFCP_LOG_INFO - ("Received state change notification." - "Trying to open the port with wwpn " - "0x%Lx. Hope it's there now.\n", - port->wwpn); + ZFCP_LOG_INFO("incoming RSCN, trying to open " + "port 0x%016Lx\n", port->wwpn); debug_text_event(adapter->erp_dbf, 1, "unsol_els_rscnu:"); zfcp_erp_port_reopen(port, @@ -1599,7 +1540,7 @@ zfcp_fsf_incoming_els_rscn(struct zfcp_a */ if ((port->d_id & range_mask) == (fcp_rscn_element->nport_did & range_mask)) { - ZFCP_LOG_TRACE("reopen did 0x%x\n", + ZFCP_LOG_TRACE("reopen did 0x%08x\n", fcp_rscn_element->nport_did); /* * Unfortunately, an RSCN does not specify the @@ -1611,10 +1552,8 @@ zfcp_fsf_incoming_els_rscn(struct zfcp_a * Where would such code be put in? * (inside or outside erp) */ - ZFCP_LOG_INFO - ("Received state change notification." - "Trying to reopen the port with wwpn " - "0x%Lx.\n", port->wwpn); + ZFCP_LOG_INFO("incoming RSCN, trying to open " + "port 0x%016Lx\n", port->wwpn); debug_text_event(adapter->erp_dbf, 1, "unsol_els_rscnk:"); zfcp_test_link(port); @@ -1642,10 +1581,8 @@ zfcp_fsf_incoming_els_plogi(struct zfcp_ read_unlock_irqrestore(&zfcp_data.config_lock, flags); if (!port || (port->wwpn != (*(wwn_t *) & els_logi->nport_wwn))) { - ZFCP_LOG_DEBUG("Re-open port indication received " - "for the non-existing port with D_ID " - "0x%3.3x, on the adapter " - "%s. Ignored.\n", + ZFCP_LOG_DEBUG("ignored incoming PLOGI for nonexisting port " + "with d_id 0x%08x on adapter %s\n", status_buffer->d_id, zfcp_get_busid_by_adapter(adapter)); } else { @@ -1673,10 +1610,8 @@ zfcp_fsf_incoming_els_logo(struct zfcp_a read_unlock_irqrestore(&zfcp_data.config_lock, flags); if (!port || (port->wwpn != els_logo->nport_wwpn)) { - ZFCP_LOG_DEBUG("Re-open port indication received " - "for the non-existing port with D_ID " - "0x%3.3x, on the adapter " - "%s. Ignored.\n", + ZFCP_LOG_DEBUG("ignored incoming LOGO for nonexisting port " + "with d_id 0x%08x on adapter %s\n", status_buffer->d_id, zfcp_get_busid_by_adapter(adapter)); } else { @@ -1691,9 +1626,8 @@ zfcp_fsf_incoming_els_unknown(struct zfc struct fsf_status_read_buffer *status_buffer) { zfcp_in_els_dbf_event(adapter, "##undef", status_buffer, 24); - ZFCP_LOG_NORMAL("warning: Unknown incoming ELS (0x%x) received " - "for the adapter %s\n", - *(u32 *) (status_buffer->payload), + ZFCP_LOG_NORMAL("warning: unknown incoming ELS 0x%08x " + "for adapter %s\n", *(u32 *) (status_buffer->payload), zfcp_get_busid_by_adapter(adapter)); } @@ -1739,12 +1673,10 @@ zfcp_gid_pn_buffers_alloc(struct zfcp_gi } } else { data = kmalloc(sizeof(struct zfcp_gid_pn_data), GFP_ATOMIC); - } + } - if (NULL == data){ - ZFCP_LOG_DEBUG("Out of memory.\n"); + if (NULL == data) return -ENOMEM; - } memset(data, 0, sizeof(*data)); data->ct.req = &data->req; @@ -1766,11 +1698,10 @@ zfcp_gid_pn_buffers_alloc(struct zfcp_gi static void zfcp_gid_pn_buffers_free(struct zfcp_gid_pn_data *gid_pn) { - if ((gid_pn->ct.pool != 0)) { + if ((gid_pn->ct.pool != 0)) mempool_free(gid_pn, gid_pn->ct.pool); - } else { + else kfree(gid_pn); - } return; } @@ -1789,11 +1720,10 @@ zfcp_ns_gid_pn_request(struct zfcp_erp_a ret = zfcp_gid_pn_buffers_alloc(&gid_pn, adapter->pool.data_gid_pn); if (ret < 0) { - ZFCP_LOG_INFO("error: Out of memory. Could not allocate " - "buffers for nameserver request GID_PN. " - "(adapter: %s)\n", + ZFCP_LOG_INFO("error: buffer allocation for gid_pn nameserver " + "request failed for adapter %s\n", zfcp_get_busid_by_adapter(adapter)); - goto out; + goto out; } /* setup nameserver request */ @@ -1817,8 +1747,8 @@ zfcp_ns_gid_pn_request(struct zfcp_erp_a ret = zfcp_fsf_send_ct(&gid_pn->ct, adapter->pool.fsf_req_erp, erp_action); if (ret) { - ZFCP_LOG_INFO("error: Could not send nameserver request GID_PN." - "(adapter %s)\n", + ZFCP_LOG_INFO("error: initiation of gid_pn nameserver request " + "failed for adapter %s\n", zfcp_get_busid_by_adapter(adapter)); zfcp_gid_pn_buffers_free(gid_pn); @@ -1862,26 +1792,23 @@ static void zfcp_ns_gid_pn_handler(unsig } /* paranoia */ if (ct_iu_req->wwpn != port->wwpn) { - ZFCP_LOG_NORMAL( - "bug: Port WWPN returned by nameserver lookup " - "does not correspond to the expected value " - "(adapter: %s, debug info: 0x%016Lx, 0x%016Lx)\n", - zfcp_get_busid_by_port(port), port->wwpn, - ct_iu_req->wwpn); + ZFCP_LOG_NORMAL("bug: wwpn 0x%016Lx returned by nameserver " + "lookup does not match expected wwpn 0x%016Lx " + "for adapter %s\n", ct_iu_req->wwpn, port->wwpn, + zfcp_get_busid_by_port(port)); goto failed; } /* looks like a valid d_id */ port->d_id = ct_iu_resp->d_id & ZFCP_DID_MASK; atomic_set_mask(ZFCP_STATUS_PORT_DID_DID, &port->status); - ZFCP_LOG_DEBUG("busid %s: WWPN=0x%Lx ---> D_ID=0x%6.6x\n", - zfcp_get_busid_by_port(port), - port->wwpn, (unsigned int) port->d_id); + ZFCP_LOG_DEBUG("adapter %s: wwpn=0x%016Lx ---> d_id=0x%08x\n", + zfcp_get_busid_by_port(port), port->wwpn, port->d_id); goto out; failed: - ZFCP_LOG_NORMAL("warning: WWPN 0x%Lx not found by nameserver lookup " - "(adapter: %s)\n", + ZFCP_LOG_NORMAL("warning: failed gid_pn nameserver request for wwpn " + "0x%016Lx for adapter %s\n", port->wwpn, zfcp_get_busid_by_port(port)); ZFCP_LOG_DEBUG("CT IUs do not match:\n"); ZFCP_HEX_DUMP(ZFCP_LOG_LEVEL_DEBUG, (char *) ct_iu_req, diff -puN drivers/s390/scsi/zfcp_ccw.c~s390-8-12-zfcp-log-messages-part-1 drivers/s390/scsi/zfcp_ccw.c --- 25/drivers/s390/scsi/zfcp_ccw.c~s390-8-12-zfcp-log-messages-part-1 2004-04-08 13:55:18.538205936 -0700 +++ 25-akpm/drivers/s390/scsi/zfcp_ccw.c 2004-04-08 13:55:18.552203808 -0700 @@ -164,9 +164,8 @@ zfcp_ccw_set_online(struct ccw_device *c goto out; retval = zfcp_erp_thread_setup(adapter); if (retval) { - ZFCP_LOG_INFO("error: out of resources. " - "error recovery thread for adapter %s " - "could not be started\n", + ZFCP_LOG_INFO("error: start of error recovery thread for " + "adapter %s failed\n", zfcp_get_busid_by_adapter(adapter)); goto out_erp_thread; } @@ -231,15 +230,15 @@ zfcp_ccw_notify(struct ccw_device *ccw_d adapter = dev_get_drvdata(&ccw_device->dev); switch (event) { case CIO_GONE: - ZFCP_LOG_NORMAL("Adapter %s: device gone.\n", + ZFCP_LOG_NORMAL("adapter %s: device gone\n", zfcp_get_busid_by_adapter(adapter)); break; case CIO_NO_PATH: - ZFCP_LOG_NORMAL("Adapter %s: no path.\n", + ZFCP_LOG_NORMAL("adapter %s: no path\n", zfcp_get_busid_by_adapter(adapter)); break; case CIO_OPER: - ZFCP_LOG_NORMAL("Adapter %s: operational again.\n", + ZFCP_LOG_NORMAL("adapter %s: operational again\n", zfcp_get_busid_by_adapter(adapter)); zfcp_erp_modify_adapter_status(adapter, ZFCP_STATUS_COMMON_RUNNING, diff -puN drivers/s390/scsi/zfcp_def.h~s390-8-12-zfcp-log-messages-part-1 drivers/s390/scsi/zfcp_def.h --- 25/drivers/s390/scsi/zfcp_def.h~s390-8-12-zfcp-log-messages-part-1 2004-04-08 13:55:18.539205784 -0700 +++ 25-akpm/drivers/s390/scsi/zfcp_def.h 2004-04-08 13:55:18.553203656 -0700 @@ -1032,7 +1032,6 @@ struct zfcp_unit { refcount drop to zero */ struct zfcp_port *port; /* remote port of unit */ atomic_t status; /* status of this logical unit */ - u32 lun_access; /* access flags for this unit */ scsi_lun_t scsi_lun; /* own SCSI LUN */ fcp_lun_t fcp_lun; /* own FCP_LUN */ u32 handle; /* handle assigned by FSF */ diff -puN drivers/s390/scsi/zfcp_erp.c~s390-8-12-zfcp-log-messages-part-1 drivers/s390/scsi/zfcp_erp.c --- 25/drivers/s390/scsi/zfcp_erp.c~s390-8-12-zfcp-log-messages-part-1 2004-04-08 13:55:18.542205328 -0700 +++ 25-akpm/drivers/s390/scsi/zfcp_erp.c 2004-04-08 13:55:18.562202288 -0700 @@ -159,31 +159,6 @@ zfcp_erp_adapter_shutdown_all(void) } /* - * function: zfcp_erp_scsi_low_mem_buffer_timeout_handler - * - * purpose: This function needs to be called whenever the SCSI command - * in the low memory buffer does not return. - * Re-opening the adapter means that the command can be returned - * by zfcp (it is guarranteed that it does not return via the - * adapter anymore). The buffer can then be used again. - * - * returns: sod all - */ -void -zfcp_erp_scsi_low_mem_buffer_timeout_handler(unsigned long data) -{ - struct zfcp_adapter *adapter = (struct zfcp_adapter *) data; - - ZFCP_LOG_NORMAL("warning: Emergency buffer for SCSI I/O timed out. " - "Restarting all operations on the adapter %s.\n", - zfcp_get_busid_by_adapter(adapter)); - debug_text_event(adapter->erp_dbf, 1, "scsi_lmem_tout"); - zfcp_erp_adapter_reopen(adapter, 0); - - return; -} - -/* * function: zfcp_fsf_scsi_er_timeout_handler * * purpose: This function needs to be called whenever a SCSI error recovery @@ -199,10 +174,9 @@ zfcp_fsf_scsi_er_timeout_handler(unsigne { struct zfcp_adapter *adapter = (struct zfcp_adapter *) data; - ZFCP_LOG_NORMAL - ("warning: Emergency buffer for SCSI error handling timed out. " - "Restarting all operations on the adapter %s.\n", - zfcp_get_busid_by_adapter(adapter)); + ZFCP_LOG_NORMAL("warning: SCSI error recovery timed out. " + "Restarting all operations on the adapter %s\n", + zfcp_get_busid_by_adapter(adapter)); debug_text_event(adapter->erp_dbf, 1, "eh_lmem_tout"); zfcp_erp_adapter_reopen(adapter, 0); @@ -225,13 +199,13 @@ zfcp_erp_adapter_reopen_internal(struct int retval; debug_text_event(adapter->erp_dbf, 5, "a_ro"); - ZFCP_LOG_DEBUG("Reopen on the adapter %s.\n", + ZFCP_LOG_DEBUG("reopen adapter %s\n", zfcp_get_busid_by_adapter(adapter)); zfcp_erp_adapter_block(adapter, clear_mask); if (atomic_test_mask(ZFCP_STATUS_COMMON_ERP_FAILED, &adapter->status)) { - ZFCP_LOG_DEBUG("skipped reopen on the failed adapter %s.\n", + ZFCP_LOG_DEBUG("skipped reopen of failed adapter %s\n", zfcp_get_busid_by_adapter(adapter)); debug_text_event(adapter->erp_dbf, 5, "a_ro_f"); /* ensure propagation of failed status to new devices */ @@ -390,9 +364,8 @@ zfcp_els(struct zfcp_port *port, u8 ls_c case ZFCP_LS_RTV: send_els->req->length = sizeof(struct zfcp_ls_rtv); send_els->resp->length = sizeof(struct zfcp_ls_rtv_acc); - ZFCP_LOG_NORMAL( - "RTV request from sid 0x%06x to did 0x%06x\n", - port->adapter->s_id, port->d_id); + ZFCP_LOG_INFO("RTV request from s_id 0x%08x to d_id 0x%08x\n", + port->adapter->s_id, port->d_id); break; case ZFCP_LS_RLS: @@ -400,10 +373,9 @@ zfcp_els(struct zfcp_port *port, u8 ls_c send_els->resp->length = sizeof(struct zfcp_ls_rls_acc); rls = (struct zfcp_ls_rls*)req; rls->port_id = port->adapter->s_id; - ZFCP_LOG_NORMAL( - "RLS request from sid 0x%06x to did 0x%06x " - "with payload(port_id=0x%06x)\n", - port->adapter->s_id, port->d_id, rls->port_id); + ZFCP_LOG_INFO("RLS request from s_id 0x%08x to d_id 0x%08x " + "(port_id=0x%08x)\n", + port->adapter->s_id, port->d_id, rls->port_id); break; case ZFCP_LS_PDISC: @@ -412,11 +384,10 @@ zfcp_els(struct zfcp_port *port, u8 ls_c pdisc = (struct zfcp_ls_pdisc*)req; pdisc->wwpn = port->adapter->wwpn; pdisc->wwnn = port->adapter->wwnn; - ZFCP_LOG_NORMAL( - "PDISC request from sid 0x%06x to did 0x%06x " - "with payload(wwpn=0x%016Lx wwnn=0x%016Lx)\n", - port->adapter->s_id, port->d_id, - pdisc->wwpn, pdisc->wwnn); + ZFCP_LOG_INFO("PDISC request from s_id 0x%08x to d_id 0x%08x " + "(wwpn=0x%016Lx, wwnn=0x%016Lx)\n", + port->adapter->s_id, port->d_id, + pdisc->wwpn, pdisc->wwnn); break; case ZFCP_LS_ADISC: @@ -427,35 +398,33 @@ zfcp_els(struct zfcp_port *port, u8 ls_c adisc->wwpn = port->adapter->wwpn; adisc->wwnn = port->adapter->wwnn; adisc->nport_id = port->adapter->s_id; - ZFCP_LOG_NORMAL( - "ADISC request from sid 0x%06x to did 0x%06x " - "with payload(wwpn=0x%016Lx wwnn=0x%016Lx " - "hard_nport_id=0x%06x nport_id=0x%06x)\n", - port->adapter->s_id, port->d_id, - adisc->wwpn, adisc->wwnn, - adisc->hard_nport_id, adisc->nport_id); + ZFCP_LOG_INFO("ADISC request from s_id 0x%08x to d_id 0x%08x " + "(wwpn=0x%016Lx, wwnn=0x%016Lx, " + "hard_nport_id=0x%08x, nport_id=0x%08x)\n", + port->adapter->s_id, port->d_id, + adisc->wwpn, adisc->wwnn, + adisc->hard_nport_id, adisc->nport_id); break; default: - ZFCP_LOG_NORMAL( - "ELS command code 0x%02x is not supported\n", ls_code); + ZFCP_LOG_NORMAL("ELS command code 0x%02x is not supported\n", + ls_code); retval = -EINVAL; goto invalid_ls_code; } retval = zfcp_fsf_send_els(send_els); if (retval != 0) { - ZFCP_LOG_NORMAL( - "ELS request could not be processed " - "(sid=0x%06x did=0x%06x)\n", - port->adapter->s_id, port->d_id); + ZFCP_LOG_NORMAL("error: initiation of Send ELS failed for port " + "0x%016Lx on adapter %s\n", + port->wwpn, zfcp_get_busid_by_port(port)); retval = -EPERM; } goto out; nomem: - ZFCP_LOG_INFO("Out of memory!\n"); + ZFCP_LOG_DEBUG("out of memory\n"); retval = -ENOMEM; invalid_ls_code: @@ -513,68 +482,53 @@ zfcp_els_handler(unsigned long data) switch (rjt->reason_code) { case ZFCP_LS_RJT_INVALID_COMMAND_CODE: - ZFCP_LOG_NORMAL( - "Invalid command code " - "(wwpn=0x%016Lx command=0x%02x)\n", - (unsigned long long)port->wwpn, - req_code); + ZFCP_LOG_INFO("invalid LS command code " + "(wwpn=0x%016Lx, command=0x%02x)\n", + port->wwpn, req_code); break; case ZFCP_LS_RJT_LOGICAL_ERROR: - ZFCP_LOG_NORMAL( - "Logical error " - "(wwpn=0x%016Lx reason_explanation=0x%02x)\n", - (unsigned long long)port->wwpn, - rjt->reason_expl); + ZFCP_LOG_INFO("logical error (wwpn=0x%016Lx, " + "reason_expl=0x%02x)\n", + port->wwpn, rjt->reason_expl); break; case ZFCP_LS_RJT_LOGICAL_BUSY: - ZFCP_LOG_NORMAL( - "Logical busy " - "(wwpn=0x%016Lx reason_explanation=0x%02x)\n", - (unsigned long long)port->wwpn, - rjt->reason_expl); + ZFCP_LOG_INFO("logical busy (wwpn=0x%016Lx, " + "reason_expl=0x%02x)\n", + port->wwpn, rjt->reason_expl); break; case ZFCP_LS_RJT_PROTOCOL_ERROR: - ZFCP_LOG_NORMAL( - "Protocol error " - "(wwpn=0x%016Lx reason_explanation=0x%02x)\n", - (unsigned long long)port->wwpn, - rjt->reason_expl); + ZFCP_LOG_INFO("protocol error (wwpn=0x%016Lx, " + "reason_expl=0x%02x)\n", + port->wwpn, rjt->reason_expl); break; case ZFCP_LS_RJT_UNABLE_TO_PERFORM: - ZFCP_LOG_NORMAL( - "Unable to perform command requested " - "(wwpn=0x%016Lx reason_explanation=0x%02x)\n", - (unsigned long long)port->wwpn, - rjt->reason_expl); + ZFCP_LOG_INFO("unable to perform command requested " + "(wwpn=0x%016Lx, reason_expl=0x%02x)\n", + port->wwpn, rjt->reason_expl); break; case ZFCP_LS_RJT_COMMAND_NOT_SUPPORTED: - ZFCP_LOG_NORMAL( - "Command not supported " - "(wwpn=0x%016Lx command=0x%02x)\n", - (unsigned long long)port->wwpn, - req_code); + ZFCP_LOG_INFO("command not supported (wwpn=0x%016Lx, " + "command=0x%02x)\n", + port->wwpn, req_code); break; case ZFCP_LS_RJT_VENDOR_UNIQUE_ERROR: - ZFCP_LOG_NORMAL( - "Vendor unique error " - "(wwpn=0x%016Lx vendor_unique=0x%02x)\n", - (unsigned long long)port->wwpn, - rjt->vendor_unique); + ZFCP_LOG_INFO("vendor specific error (wwpn=0x%016Lx, " + "vendor_unique=0x%02x)\n", + port->wwpn, rjt->vendor_unique); break; default: - ZFCP_LOG_NORMAL( - "ELS has been rejected by remote port " - "with WWPN 0x%Lx on the adapter %s " - "with the reason code 0x%02x\n", - port->wwpn, zfcp_get_busid_by_port(port), - rjt->reason_code); + ZFCP_LOG_NORMAL("ELS rejected by remote port 0x%016Lx " + "on adapter %s (reason_code=0x%02x)\n", + port->wwpn, + zfcp_get_busid_by_port(port), + rjt->reason_code); } retval = -ENXIO; break; @@ -584,57 +538,51 @@ zfcp_els_handler(unsigned long data) case ZFCP_LS_RTV: rtv = (struct zfcp_ls_rtv_acc*)resp; - ZFCP_LOG_NORMAL( - "RTV response from did 0x%06x to sid 0x%06x " - "with payload(R_A_TOV=%ds E_D_TOV=%d%cs)\n", - port->d_id, port->adapter->s_id, - rtv->r_a_tov, rtv->e_d_tov, - rtv->qualifier & ZFCP_LS_RTV_E_D_TOV_FLAG ? - 'n' : 'm'); + ZFCP_LOG_INFO("RTV response from d_id 0x%08x to s_id " + "0x%08x (R_A_TOV=%ds E_D_TOV=%d%cs)\n", + port->d_id, port->adapter->s_id, + rtv->r_a_tov, rtv->e_d_tov, + rtv->qualifier & + ZFCP_LS_RTV_E_D_TOV_FLAG ? 'n' : 'm'); break; case ZFCP_LS_RLS: rls = (struct zfcp_ls_rls_acc*)resp; - ZFCP_LOG_NORMAL( - "RLS response from did 0x%06x to sid 0x%06x " - "with payload(link_failure_count=%u " - "loss_of_sync_count=%u " - "loss_of_signal_count=%u " - "primitive_sequence_protocol_error=%u " - "invalid_transmition_word=%u " - "invalid_crc_count=%u)\n", - port->d_id, port->adapter->s_id, - rls->link_failure_count, - rls->loss_of_sync_count, - rls->loss_of_signal_count, - rls->prim_seq_prot_error, - rls->invalid_transmition_word, - rls->invalid_crc_count); + ZFCP_LOG_INFO("RLS response from d_id 0x%08x to s_id " + "0x%08x (link_failure_count=%u, " + "loss_of_sync_count=%u, " + "loss_of_signal_count=%u, " + "primitive_sequence_protocol_error=%u, " + "invalid_transmition_word=%u, " + "invalid_crc_count=%u)\n", + port->d_id, port->adapter->s_id, + rls->link_failure_count, + rls->loss_of_sync_count, + rls->loss_of_signal_count, + rls->prim_seq_prot_error, + rls->invalid_transmition_word, + rls->invalid_crc_count); break; case ZFCP_LS_PDISC: pdisc = (struct zfcp_ls_pdisc_acc*)resp; - ZFCP_LOG_NORMAL( - "PDISC response from did 0x%06x to sid 0x%06x " - "with payload(wwpn=0x%016Lx wwnn=0x%016Lx " - "vendor='%-16s')\n", - port->d_id, port->adapter->s_id, - (unsigned long long)pdisc->wwpn, - (unsigned long long)pdisc->wwnn, - pdisc->vendor_version); + ZFCP_LOG_INFO("PDISC response from d_id 0x%08x to s_id " + "0x%08x (wwpn=0x%016Lx, wwnn=0x%016Lx, " + "vendor='%-16s')\n", port->d_id, + port->adapter->s_id, pdisc->wwpn, + pdisc->wwnn, pdisc->vendor_version); break; case ZFCP_LS_ADISC: adisc = (struct zfcp_ls_adisc_acc*)resp; - ZFCP_LOG_NORMAL( - "ADISC response from did 0x%06x to sid 0x%06x " - "with payload(wwpn=0x%016Lx wwnn=0x%016Lx " - "hard_nport_id=0x%06x nport_id=0x%06x)\n", - port->d_id, port->adapter->s_id, - (unsigned long long)adisc->wwpn, - (unsigned long long)adisc->wwnn, - adisc->hard_nport_id, adisc->nport_id); - /* FIXME: missing wwnn value in port struct */ + ZFCP_LOG_INFO("ADISC response from d_id 0x%08x to s_id " + "0x%08x (wwpn=0x%016Lx, wwnn=0x%016Lx, " + "hard_nport_id=0x%08x, " + "nport_id=0x%08x)\n", port->d_id, + port->adapter->s_id, adisc->wwpn, + adisc->wwnn, adisc->hard_nport_id, + adisc->nport_id); + /* FIXME: set wwnn in during open port */ if (port->wwnn == 0) port->wwnn = adisc->wwnn; break; @@ -642,17 +590,16 @@ zfcp_els_handler(unsigned long data) break; default: - ZFCP_LOG_NORMAL( - "Unknown payload code 0x%02x received on a request " - "0x%02x from sid 0x%06x to did 0x%06x, " - "port needs to be reopened\n", - req_code, resp_code, port->adapter->s_id, port->d_id); + ZFCP_LOG_NORMAL("unknown payload code 0x%02x received for " + "request 0x%02x to d_id 0x%08x, reopen needed " + "for port 0x%016Lx on adapter %s\n", resp_code, + req_code, port->d_id, port->wwpn, + zfcp_get_busid_by_port(port)); retval = zfcp_erp_port_forced_reopen(port, 0); if (retval != 0) { - ZFCP_LOG_NORMAL( - "Cannot reopen a remote port " - "with WWPN 0x%Lx on the adapter %s\n", - port->wwpn, zfcp_get_busid_by_port(port)); + ZFCP_LOG_NORMAL("reopen of remote port 0x%016Lx on " + "adapter %s failed\n", port->wwpn, + zfcp_get_busid_by_port(port)); retval = -EPERM; } } @@ -681,16 +628,14 @@ zfcp_test_link(struct zfcp_port *port) retval = zfcp_els(port, ZFCP_LS_ADISC); if (retval != 0) { - ZFCP_LOG_NORMAL( - "Port with WWPN 0x%Lx on the adapter %s " - "needs to be reopened\n", - port->wwpn, zfcp_get_busid_by_port(port)); + ZFCP_LOG_NORMAL("reopen needed for port 0x%016Lx " + "on adapter %s\n ", port->wwpn, + zfcp_get_busid_by_port(port)); retval = zfcp_erp_port_forced_reopen(port, 0); if (retval != 0) { - ZFCP_LOG_NORMAL( - "Cannot reopen a remote port " - "with WWPN 0x%Lx on the adapter %s\n", - port->wwpn, zfcp_get_busid_by_port(port)); + ZFCP_LOG_NORMAL("reopen of remote port 0x%016Lx " + "on adapter %s failed\n", port->wwpn, + zfcp_get_busid_by_port(port)); retval = -EPERM; } } @@ -718,16 +663,15 @@ zfcp_erp_port_forced_reopen_internal(str debug_text_event(adapter->erp_dbf, 5, "pf_ro"); debug_event(adapter->erp_dbf, 5, &port->wwpn, sizeof (wwn_t)); - ZFCP_LOG_DEBUG("Forced reopen of the port with WWPN 0x%Lx " - "on the adapter %s.\n", + ZFCP_LOG_DEBUG("forced reopen of port 0x%016Lx on adapter %s\n", port->wwpn, zfcp_get_busid_by_port(port)); zfcp_erp_port_block(port, clear_mask); if (atomic_test_mask(ZFCP_STATUS_COMMON_ERP_FAILED, &port->status)) { - ZFCP_LOG_DEBUG("skipped forced reopen on the failed port " - "with WWPN 0x%Lx on the adapter %s.\n", - port->wwpn, zfcp_get_busid_by_port(port)); + ZFCP_LOG_DEBUG("skipped forced reopen of failed port 0x%016Lx " + "on adapter %s\n", port->wwpn, + zfcp_get_busid_by_port(port)); debug_text_event(adapter->erp_dbf, 5, "pf_ro_f"); debug_event(adapter->erp_dbf, 5, &port->wwpn, sizeof (wwn_t)); retval = -EIO; @@ -786,17 +730,15 @@ zfcp_erp_port_reopen_internal(struct zfc debug_text_event(adapter->erp_dbf, 5, "p_ro"); debug_event(adapter->erp_dbf, 5, &port->wwpn, sizeof (wwn_t)); - ZFCP_LOG_DEBUG("Reopen of the port with WWPN 0x%Lx " - "on the adapter %s.\n", + ZFCP_LOG_DEBUG("reopen of port 0x%016Lx on adapter %s\n", port->wwpn, zfcp_get_busid_by_port(port)); zfcp_erp_port_block(port, clear_mask); if (atomic_test_mask(ZFCP_STATUS_COMMON_ERP_FAILED, &port->status)) { - ZFCP_LOG_DEBUG - ("skipped reopen on the failed port with WWPN 0x%Lx " - "on the adapter %s.\n", port->wwpn, - zfcp_get_busid_by_port(port)); + ZFCP_LOG_DEBUG("skipped reopen of failed port 0x%016Lx " + "on adapter %s\n", port->wwpn, + zfcp_get_busid_by_port(port)); debug_text_event(adapter->erp_dbf, 5, "p_ro_f"); debug_event(adapter->erp_dbf, 5, &port->wwpn, sizeof (wwn_t)); /* ensure propagation of failed status to new devices */ @@ -855,20 +797,17 @@ zfcp_erp_unit_reopen_internal(struct zfc debug_text_event(adapter->erp_dbf, 5, "u_ro"); debug_event(adapter->erp_dbf, 5, &unit->fcp_lun, sizeof (fcp_lun_t)); - ZFCP_LOG_DEBUG("Reopen of the unit with FCP LUN 0x%Lx on the " - "port with WWPN 0x%Lx " - "on the adapter %s.\n", - unit->fcp_lun, + ZFCP_LOG_DEBUG("reopen of unit 0x%016Lx on port 0x%016Lx " + "on adapter %s\n", unit->fcp_lun, unit->port->wwpn, zfcp_get_busid_by_unit(unit)); zfcp_erp_unit_block(unit, clear_mask); if (atomic_test_mask(ZFCP_STATUS_COMMON_ERP_FAILED, &unit->status)) { - ZFCP_LOG_DEBUG - ("skipped reopen on the failed unit with FCP LUN 0x%Lx " - "on the port with WWPN 0x%Lx " "on the adapter %s.\n", - unit->fcp_lun, unit->port->wwpn, - zfcp_get_busid_by_unit(unit)); + ZFCP_LOG_DEBUG("skipped reopen of failed unit 0x%016Lx " + "on port 0x%016Lx on adapter %s\n", + unit->fcp_lun, unit->port->wwpn, + zfcp_get_busid_by_unit(unit)); debug_text_event(adapter->erp_dbf, 5, "u_ro_f"); debug_event(adapter->erp_dbf, 5, &unit->fcp_lun, sizeof (fcp_lun_t)); @@ -1115,14 +1054,10 @@ zfcp_erp_strategy_check_fsfreq(struct zf fsf_req->status |= ZFCP_STATUS_FSFREQ_DISMISSED; } if (erp_action->status & ZFCP_STATUS_ERP_TIMEDOUT) { - ZFCP_LOG_NORMAL - ("error: Error Recovery Procedure " - "step timed out. The action flag " - "is 0x%x. The FSF request " - "is at 0x%lx\n", - erp_action->action, - (unsigned long) - erp_action->fsf_req); + ZFCP_LOG_NORMAL("error: erp step timed out " + "(action=%d, fsf_req=%p)\n ", + erp_action->action, + erp_action->fsf_req); } /* * If fsf_req is neither dismissed nor completed @@ -1287,9 +1222,8 @@ zfcp_erp_thread_setup(struct zfcp_adapte retval = kernel_thread(zfcp_erp_thread, adapter, SIGCHLD); if (retval < 0) { - ZFCP_LOG_NORMAL("error: Out of resources. Could not create an " - "error recovery procedure thread " - "for the adapter %s.\n", + ZFCP_LOG_NORMAL("error: creation of erp thread failed for " + "adapter %s\n", zfcp_get_busid_by_adapter(adapter)); debug_text_event(adapter->erp_dbf, 5, "a_thset_fail"); } else { @@ -1475,11 +1409,10 @@ zfcp_erp_strategy(struct zfcp_erp_action */ if (adapter->erp_total_count == adapter->erp_low_mem_count) { debug_text_event(adapter->erp_dbf, 3, "a_st_lowmem"); - ZFCP_LOG_NORMAL - ("error: Out of memory. No mempool elements " - "available. Restarting IO on the adapter %s " - "to free mempool.\n", - zfcp_get_busid_by_adapter(adapter)); + ZFCP_LOG_NORMAL("error: no mempool elements available, " + "restarting I/O on adapter %s " + "to free mempool\n", + zfcp_get_busid_by_adapter(adapter)); zfcp_erp_adapter_reopen_internal(adapter, 0); } else { debug_text_event(adapter->erp_dbf, 2, "a_st_memw"); @@ -1618,9 +1551,8 @@ zfcp_erp_strategy_do_action(struct zfcp_ debug_text_exception(adapter->erp_dbf, 1, "a_stda_bug"); debug_event(adapter->erp_dbf, 1, &erp_action->action, sizeof (int)); - ZFCP_LOG_NORMAL("bug: Unknown error recovery procedure " - "action requested on the adapter %s " - "(debug info %d)\n", + ZFCP_LOG_NORMAL("bug: unknown erp action requested on " + "adapter %s (action=%d)\n", zfcp_get_busid_by_adapter(erp_action->adapter), erp_action->action); } @@ -1664,8 +1596,8 @@ zfcp_erp_adapter_failed(struct zfcp_adap { zfcp_erp_modify_adapter_status(adapter, ZFCP_STATUS_COMMON_ERP_FAILED, ZFCP_SET); - ZFCP_LOG_NORMAL("Adapter recovery failed on the " - "adapter %s.\n", zfcp_get_busid_by_adapter(adapter)); + ZFCP_LOG_NORMAL("adapter erp failed on adapter %s\n", + zfcp_get_busid_by_adapter(adapter)); debug_text_event(adapter->erp_dbf, 2, "a_afail"); } @@ -1681,9 +1613,7 @@ zfcp_erp_port_failed(struct zfcp_port *p zfcp_erp_modify_port_status(port, ZFCP_STATUS_COMMON_ERP_FAILED, ZFCP_SET); - ZFCP_LOG_NORMAL("Port recovery failed on the " - "port with WWPN 0x%Lx at the " - "adapter %s.\n", + ZFCP_LOG_NORMAL("port erp failed on port 0x%016Lx on adapter %s\n", port->wwpn, zfcp_get_busid_by_port(port)); debug_text_event(port->adapter->erp_dbf, 2, "p_pfail"); debug_event(port->adapter->erp_dbf, 2, &port->wwpn, sizeof (wwn_t)); @@ -1701,10 +1631,8 @@ zfcp_erp_unit_failed(struct zfcp_unit *u zfcp_erp_modify_unit_status(unit, ZFCP_STATUS_COMMON_ERP_FAILED, ZFCP_SET); - ZFCP_LOG_NORMAL("Unit recovery failed on the unit with FCP LUN 0x%Lx " - "connected to the port with WWPN 0x%Lx at the " - "adapter %s.\n", - unit->fcp_lun, + ZFCP_LOG_NORMAL("unit erp failed on unit 0x%016Lx on port 0x%016Lx " + " on adapter %s\n", unit->fcp_lun, unit->port->wwpn, zfcp_get_busid_by_unit(unit)); debug_text_event(unit->port->adapter->erp_dbf, 2, "u_ufail"); debug_event(unit->port->adapter->erp_dbf, 2, @@ -1863,13 +1791,10 @@ zfcp_erp_schedule_work(struct zfcp_unit return 0; if ((p = kmalloc(sizeof(*p), GFP_KERNEL)) == NULL) { - ZFCP_LOG_NORMAL("error: Out of resources. Could not register " - "the FCP-LUN 0x%Lx connected to " - "the port with WWPN 0x%Lx connected to " - "the adapter %s with the SCSI stack.\n", - unit->fcp_lun, - unit->port->wwpn, - zfcp_get_busid_by_unit(unit)); + ZFCP_LOG_NORMAL("error: registration at SCSI stack failed for " + "unit 0x%016Lx on port 0x%016Lx on " + "adapter %s\n", unit->fcp_lun, unit->port->wwpn, + zfcp_get_busid_by_unit(unit)); atomic_set(&unit->scsi_add_work, 0); return -ENOMEM; } @@ -2279,7 +2204,7 @@ zfcp_erp_adapter_strategy(struct zfcp_er if (retval == ZFCP_ERP_FAILED) { ZFCP_LOG_INFO("Waiting to allow the adapter %s " - "to recover itself\n.", + "to recover itself\n", zfcp_get_busid_by_adapter(adapter)); /* * SUGGESTION: substitute by @@ -2395,25 +2320,23 @@ zfcp_erp_adapter_strategy_open_qdio(stru int retval_cleanup = 0; if (atomic_test_mask(ZFCP_STATUS_ADAPTER_QDIOUP, &adapter->status)) { - ZFCP_LOG_NORMAL - ("bug: QDIO (data transfer mechanism) start-up on " - "adapter %s attempted twice. Second attempt ignored.\n", - zfcp_get_busid_by_adapter(adapter)); + ZFCP_LOG_NORMAL("bug: second attempt to set up QDIO on " + "adapter %s\n", + zfcp_get_busid_by_adapter(adapter)); goto failed_sanity; } if (qdio_establish(&adapter->qdio_init_data) != 0) { - ZFCP_LOG_INFO - ("error: Could not establish queues for QDIO (data " - "transfer mechanism) operation on adapter %s\n.", - zfcp_get_busid_by_adapter(adapter)); + ZFCP_LOG_INFO("error: establishment of QDIO queues failed " + "on adapter %s\n.", + zfcp_get_busid_by_adapter(adapter)); goto failed_qdio_establish; } ZFCP_LOG_DEBUG("queues established\n"); if (qdio_activate(adapter->ccw_device, 0) != 0) { - ZFCP_LOG_INFO("error: Could not activate queues for QDIO (data " - "transfer mechanism) operation on adapter %s\n.", + ZFCP_LOG_INFO("error: activation of QDIO queues failed " + "on adapter %s\n", zfcp_get_busid_by_adapter(adapter)); goto failed_qdio_activate; } @@ -2429,8 +2352,8 @@ zfcp_erp_adapter_strategy_open_qdio(stru sbale->addr = 0; } - ZFCP_LOG_TRACE("Calling do QDIO busid=%s, flags=0x%x, queue_no=%i, " - "index_in_queue=%i, count=%i\n", + ZFCP_LOG_TRACE("calling do_QDIO on adapter %s (flags=0x%x, " + "queue_no=%i, index_in_queue=%i, count=%i)\n", zfcp_get_busid_by_adapter(adapter), QDIO_FLAG_SYNC_INPUT, 0, 0, QDIO_MAX_BUFFERS_PER_Q); @@ -2439,17 +2362,14 @@ zfcp_erp_adapter_strategy_open_qdio(stru 0, 0, QDIO_MAX_BUFFERS_PER_Q, NULL); if (retval) { - ZFCP_LOG_NORMAL - ("bug: QDIO (data transfer mechanism) inobund transfer " - "structures could not be set-up (debug info %d)\n", - retval); + ZFCP_LOG_NORMAL("bug: setup of QDIO failed (retval=%d)\n", + retval); goto failed_do_qdio; } else { adapter->response_queue.free_index = 0; atomic_set(&adapter->response_queue.free_count, 0); - ZFCP_LOG_DEBUG - ("%i buffers successfully enqueued to response queue\n", - QDIO_MAX_BUFFERS_PER_Q); + ZFCP_LOG_DEBUG("%i buffers successfully enqueued to " + "response queue\n", QDIO_MAX_BUFFERS_PER_Q); } /* set index of first avalable SBALS / number of available SBALS */ adapter->request_queue.free_index = 0; @@ -2474,9 +2394,8 @@ zfcp_erp_adapter_strategy_open_qdio(stru retval_cleanup = qdio_shutdown(adapter->ccw_device, QDIO_FLAG_CLEANUP_USING_CLEAR); if (retval_cleanup) { - ZFCP_LOG_NORMAL - ("bug: Could not clean QDIO (data transfer mechanism) " - "queues. (debug info %i).\n", retval_cleanup); + ZFCP_LOG_NORMAL("bug: shutdown of QDIO queues failed " + "(retval=%d)\n", retval_cleanup); } else debug_text_event(adapter->req_dbf, 1, "q_clean"); @@ -2508,9 +2427,8 @@ zfcp_erp_adapter_strategy_close_qdio(str struct zfcp_adapter *adapter = erp_action->adapter; if (!atomic_test_mask(ZFCP_STATUS_ADAPTER_QDIOUP, &adapter->status)) { - ZFCP_LOG_DEBUG("Termination of QDIO (data transfer operation) " - "attempted for an inactive qdio on the " - "adapter %s....ignored.\n", + ZFCP_LOG_DEBUG("error: attempt to shut down inactive QDIO " + "queues on adapter %s\n", zfcp_get_busid_by_adapter(adapter)); retval = ZFCP_ERP_FAILED; goto out; @@ -2547,10 +2465,9 @@ zfcp_erp_adapter_strategy_close_qdio(str * FIXME(design): * What went wrong? What to do best? Proper retval? */ - ZFCP_LOG_NORMAL - ("error: Clean-up of QDIO (data transfer mechanism) " - "structures failed for adapter %s.\n", - zfcp_get_busid_by_adapter(adapter)); + ZFCP_LOG_NORMAL("bug: shutdown of QDIO queues failed on " + "adapter %s\n", + zfcp_get_busid_by_adapter(adapter)); } else { ZFCP_LOG_DEBUG("queues cleaned up\n"); debug_text_event(adapter->req_dbf, 1, "q_clean"); @@ -2631,10 +2548,9 @@ zfcp_erp_adapter_strategy_open_fsf_xconf if (zfcp_fsf_exchange_config_data(erp_action)) { retval = ZFCP_ERP_FAILED; debug_text_event(adapter->erp_dbf, 5, "a_fstx_xf"); - ZFCP_LOG_INFO("error: Out of resources. Could not " - "start exchange of configuration data " - "between the adapter %s " - "and the device driver.\n", + ZFCP_LOG_INFO("error: initiation of exchange of " + "configuration data failed for " + "adapter %s\n", zfcp_get_busid_by_adapter(adapter)); break; } @@ -2656,17 +2572,15 @@ zfcp_erp_adapter_strategy_open_fsf_xconf */ down_interruptible(&adapter->erp_ready_sem); if (erp_action->status & ZFCP_STATUS_ERP_TIMEDOUT) { - ZFCP_LOG_INFO - ("error: Exchange of configuration data between " - "the adapter with %s and the device " - "driver timed out\n", - zfcp_get_busid_by_adapter(adapter)); + ZFCP_LOG_INFO("error: exchange of configuration data " + "for adapter %s timed out\n", + zfcp_get_busid_by_adapter(adapter)); break; } if (atomic_test_mask(ZFCP_STATUS_ADAPTER_HOST_CON_INIT, &adapter->status)) { - ZFCP_LOG_DEBUG("Host connection still initialising... " - "waiting and retrying....\n"); + ZFCP_LOG_DEBUG("host connection still initialising... " + "waiting and retrying...\n"); /* sleep a little bit before retry */ set_current_state(TASK_INTERRUPTIBLE); schedule_timeout(ZFCP_EXCHANGE_CONFIG_DATA_SLEEP); @@ -2677,8 +2591,8 @@ zfcp_erp_adapter_strategy_open_fsf_xconf if (!atomic_test_mask(ZFCP_STATUS_ADAPTER_XCONFIG_OK, &adapter->status)) { - ZFCP_LOG_INFO("error: Exchange of configuration data between " - "the adapter %s and the device driver failed.\n", + ZFCP_LOG_INFO("error: exchange of configuration data for " + "adapter %s failed\n", zfcp_get_busid_by_adapter(adapter)); retval = ZFCP_ERP_FAILED; } @@ -2706,10 +2620,8 @@ zfcp_erp_adapter_strategy_open_fsf_statu for (i = 0; i < ZFCP_STATUS_READS_RECOM; i++) { temp_ret = zfcp_fsf_status_read(adapter, ZFCP_WAIT_FOR_SBAL); if (temp_ret < 0) { - ZFCP_LOG_INFO("error: Out of resources. Could not " - "set-up the infrastructure for " - "unsolicited status presentation " - "for the adapter %s.\n", + ZFCP_LOG_INFO("error: set-up of unsolicited status " + "notification failed on adapter %s\n", zfcp_get_busid_by_adapter(adapter)); retval = ZFCP_ERP_FAILED; i--; @@ -2781,9 +2693,8 @@ zfcp_erp_port_forced_strategy(struct zfc if (atomic_test_mask((ZFCP_STATUS_PORT_PHYS_OPEN | ZFCP_STATUS_COMMON_OPEN), &port->status)) { - ZFCP_LOG_DEBUG("Port wwpn=0x%Lx is open -> trying " - " close physical\n", - port->wwpn); + ZFCP_LOG_DEBUG("port 0x%016Lx is open -> trying " + "close physical\n", port->wwpn); retval = zfcp_erp_port_forced_strategy_close(erp_action); } else @@ -2793,9 +2704,8 @@ zfcp_erp_port_forced_strategy(struct zfc case ZFCP_ERP_STEP_PHYS_PORT_CLOSING: if (atomic_test_mask(ZFCP_STATUS_PORT_PHYS_OPEN, &port->status)) { - ZFCP_LOG_DEBUG - ("failed to close physical port wwpn=0x%Lx\n", - port->wwpn); + ZFCP_LOG_DEBUG("close physical failed for port " + "0x%016Lx\n", port->wwpn); retval = ZFCP_ERP_FAILED; } else retval = ZFCP_ERP_SUCCEEDED; @@ -2835,9 +2745,8 @@ zfcp_erp_port_strategy(struct zfcp_erp_a case ZFCP_ERP_STEP_UNINITIALIZED: zfcp_erp_port_strategy_clearstati(port); if (atomic_test_mask(ZFCP_STATUS_COMMON_OPEN, &port->status)) { - ZFCP_LOG_DEBUG - ("port wwpn=0x%Lx is open -> trying close\n", - port->wwpn); + ZFCP_LOG_DEBUG("port 0x%016Lx is open -> trying " + "close\n", port->wwpn); retval = zfcp_erp_port_strategy_close(erp_action); goto out; } /* else it's already closed, open it */ @@ -2845,7 +2754,7 @@ zfcp_erp_port_strategy(struct zfcp_erp_a case ZFCP_ERP_STEP_PORT_CLOSING: if (atomic_test_mask(ZFCP_STATUS_COMMON_OPEN, &port->status)) { - ZFCP_LOG_DEBUG("failed to close port wwpn=0x%Lx\n", + ZFCP_LOG_DEBUG("close failed for port 0x%016Lx\n", port->wwpn); retval = ZFCP_ERP_FAILED; goto out; @@ -2911,19 +2820,17 @@ zfcp_erp_port_strategy_open_common(struc if (!(adapter->nameserver_port)) { retval = zfcp_nameserver_enqueue(adapter); if (retval != 0) { - ZFCP_LOG_NORMAL - ("error: nameserver port not available " - "(adapter with busid %s)\n", - zfcp_get_busid_by_adapter(adapter)); + ZFCP_LOG_NORMAL("error: nameserver port " + "unavailable for adapter %s\n", + zfcp_get_busid_by_adapter(adapter)); retval = ZFCP_ERP_FAILED; break; } } if (!atomic_test_mask(ZFCP_STATUS_COMMON_UNBLOCKED, &adapter->nameserver_port->status)) { - ZFCP_LOG_DEBUG - ("nameserver port is not open -> open " - "nameserver port\n"); + ZFCP_LOG_DEBUG("nameserver port is not open -> open " + "nameserver port\n"); /* nameserver port may live again */ atomic_set_mask(ZFCP_STATUS_COMMON_RUNNING, &adapter->nameserver_port->status); @@ -2936,12 +2843,11 @@ zfcp_erp_port_strategy_open_common(struc case ZFCP_ERP_STEP_NAMESERVER_OPEN: if (!atomic_test_mask(ZFCP_STATUS_COMMON_OPEN, &adapter->nameserver_port->status)) { - ZFCP_LOG_DEBUG("failed to open nameserver port\n"); + ZFCP_LOG_DEBUG("open failed for nameserver port\n"); retval = ZFCP_ERP_FAILED; } else { ZFCP_LOG_DEBUG("nameserver port is open -> " - "ask nameserver for current D_ID of " - "port with WWPN 0x%Lx\n", + "nameserver look-up for port 0x%016Lx\n", port->wwpn); retval = zfcp_erp_port_strategy_open_common_lookup (erp_action); @@ -2952,21 +2858,20 @@ zfcp_erp_port_strategy_open_common(struc if (!atomic_test_mask(ZFCP_STATUS_PORT_DID_DID, &port->status)) { if (atomic_test_mask (ZFCP_STATUS_PORT_INVALID_WWPN, &port->status)) { - ZFCP_LOG_DEBUG - ("failed to look up the D_ID of the port wwpn=0x%Lx " - "(misconfigured WWPN?)\n", port->wwpn); + ZFCP_LOG_DEBUG("nameserver look-up failed " + "for port 0x%016Lx " + "(misconfigured WWPN?)\n", + port->wwpn); zfcp_erp_port_failed(port); retval = ZFCP_ERP_EXIT; } else { - ZFCP_LOG_DEBUG - ("failed to look up the D_ID of the port wwpn=0x%Lx\n", - port->wwpn); + ZFCP_LOG_DEBUG("nameserver look-up failed for " + "port 0x%016Lx\n", port->wwpn); retval = ZFCP_ERP_FAILED; } } else { - ZFCP_LOG_DEBUG - ("port wwpn=0x%Lx has D_ID=0x%6.6x -> trying open\n", - port->wwpn, (unsigned int) port->d_id); + ZFCP_LOG_DEBUG("port 0x%016Lx has d_id=0x%08x -> " + "trying open\n", port->wwpn, port->d_id); retval = zfcp_erp_port_strategy_open_port(erp_action); } break; @@ -2976,17 +2881,17 @@ zfcp_erp_port_strategy_open_common(struc if (atomic_test_mask((ZFCP_STATUS_COMMON_OPEN | ZFCP_STATUS_PORT_DID_DID), &port->status)) { - ZFCP_LOG_DEBUG("port wwpn=0x%Lx is open\n", port->wwpn); + ZFCP_LOG_DEBUG("port 0x%016Lx is open\n", port->wwpn); retval = ZFCP_ERP_SUCCEEDED; } else { - ZFCP_LOG_DEBUG("failed to open port wwpn=0x%Lx\n", + ZFCP_LOG_DEBUG("open failed for port 0x%016Lx\n", port->wwpn); retval = ZFCP_ERP_FAILED; } break; default: - ZFCP_LOG_NORMAL("bug: unkown erp step 0x%x\n", + ZFCP_LOG_NORMAL("bug: unknown erp step 0x%08x\n", erp_action->step); retval = ZFCP_ERP_FAILED; } @@ -3012,9 +2917,8 @@ zfcp_erp_port_strategy_open_nameserver(s case ZFCP_ERP_STEP_UNINITIALIZED: case ZFCP_ERP_STEP_PHYS_PORT_CLOSING: case ZFCP_ERP_STEP_PORT_CLOSING: - ZFCP_LOG_DEBUG - ("port wwpn=0x%Lx has D_ID=0x%6.6x -> trying open\n", - port->wwpn, (unsigned int) port->d_id); + ZFCP_LOG_DEBUG("port 0x%016Lx has d_id=0x%08x -> trying open\n", + port->wwpn, port->d_id); retval = zfcp_erp_port_strategy_open_port(erp_action); break; @@ -3023,7 +2927,7 @@ zfcp_erp_port_strategy_open_nameserver(s ZFCP_LOG_DEBUG("nameserver port is open\n"); retval = ZFCP_ERP_SUCCEEDED; } else { - ZFCP_LOG_DEBUG("failed to open nameserver port\n"); + ZFCP_LOG_DEBUG("open failed for nameserver port\n"); retval = ZFCP_ERP_FAILED; } /* this is needed anyway (dont care for retval of wakeup) */ @@ -3032,7 +2936,7 @@ zfcp_erp_port_strategy_open_nameserver(s break; default: - ZFCP_LOG_NORMAL("bug: unkown erp step 0x%x\n", + ZFCP_LOG_NORMAL("bug: unknown erp step 0x%08x\n", erp_action->step); retval = ZFCP_ERP_FAILED; } @@ -3278,25 +3182,23 @@ zfcp_erp_unit_strategy(struct zfcp_erp_a case ZFCP_ERP_STEP_UNINITIALIZED: zfcp_erp_unit_strategy_clearstati(unit); if (atomic_test_mask(ZFCP_STATUS_COMMON_OPEN, &unit->status)) { - ZFCP_LOG_DEBUG - ("unit fcp_lun=0x%Lx is open -> trying close\n", - unit->fcp_lun); + ZFCP_LOG_DEBUG("unit 0x%016Lx is open -> " + "trying close\n", unit->fcp_lun); retval = zfcp_erp_unit_strategy_close(erp_action); break; } /* else it's already closed, fall through */ case ZFCP_ERP_STEP_UNIT_CLOSING: if (atomic_test_mask(ZFCP_STATUS_COMMON_OPEN, &unit->status)) { - ZFCP_LOG_DEBUG("failed to close unit fcp_lun=0x%Lx\n", + ZFCP_LOG_DEBUG("close failed for unit 0x%016Lx\n", unit->fcp_lun); retval = ZFCP_ERP_FAILED; } else { if (erp_action->status & ZFCP_STATUS_ERP_CLOSE_ONLY) retval = ZFCP_ERP_EXIT; else { - ZFCP_LOG_DEBUG("unit fcp_lun=0x%Lx is not " - "open -> trying open\n", - unit->fcp_lun); + ZFCP_LOG_DEBUG("unit 0x%016Lx is not open -> " + "trying open\n", unit->fcp_lun); retval = zfcp_erp_unit_strategy_open(erp_action); } @@ -3305,11 +3207,11 @@ zfcp_erp_unit_strategy(struct zfcp_erp_a case ZFCP_ERP_STEP_UNIT_OPENING: if (atomic_test_mask(ZFCP_STATUS_COMMON_OPEN, &unit->status)) { - ZFCP_LOG_DEBUG("unit fcp_lun=0x%Lx is open\n", + ZFCP_LOG_DEBUG("unit 0x%016Lx is open\n", unit->fcp_lun); retval = ZFCP_ERP_SUCCEEDED; } else { - ZFCP_LOG_DEBUG("failed to open unit fcp_lun=0x%Lx\n", + ZFCP_LOG_DEBUG("open failed for unit 0x%016Lx\n", unit->fcp_lun); retval = ZFCP_ERP_FAILED; } @@ -3546,9 +3448,8 @@ zfcp_erp_action_enqueue(int action, default: debug_text_exception(adapter->erp_dbf, 1, "a_actenq_bug"); debug_event(adapter->erp_dbf, 1, &action, sizeof (int)); - ZFCP_LOG_NORMAL("bug: Unknown error recovery procedure " - "action requested on the adapter %s " - "(debug info %d)\n", + ZFCP_LOG_NORMAL("bug: unknown erp action requested " + "on adapter %s (action=%d)\n", zfcp_get_busid_by_adapter(adapter), action); goto out; } @@ -3558,8 +3459,8 @@ zfcp_erp_action_enqueue(int action, debug_text_event(adapter->erp_dbf, 4, "a_actenq_str"); debug_event(adapter->erp_dbf, 4, &stronger_action, sizeof (int)); - ZFCP_LOG_DEBUG("shortcut: need erp action %i before " - "erp action %i (adapter busid=%s)\n", + ZFCP_LOG_DEBUG("stronger erp action %d needed before " + "erp action %d on adapter %s\n", stronger_action, action, zfcp_get_busid_by_adapter(adapter)); action = stronger_action; diff -puN drivers/s390/scsi/zfcp_ext.h~s390-8-12-zfcp-log-messages-part-1 drivers/s390/scsi/zfcp_ext.h --- 25/drivers/s390/scsi/zfcp_ext.h~s390-8-12-zfcp-log-messages-part-1 2004-04-08 13:55:18.543205176 -0700 +++ 25-akpm/drivers/s390/scsi/zfcp_ext.h 2004-04-08 13:55:18.563202136 -0700 @@ -156,7 +156,6 @@ extern int zfcp_erp_unit_reopen(struct extern int zfcp_erp_unit_shutdown(struct zfcp_unit *, int); extern void zfcp_erp_unit_failed(struct zfcp_unit *); -extern void zfcp_erp_scsi_low_mem_buffer_timeout_handler(unsigned long); extern int zfcp_erp_thread_setup(struct zfcp_adapter *); extern int zfcp_erp_thread_kill(struct zfcp_adapter *); extern int zfcp_erp_wait(struct zfcp_adapter *); _