Details : Instead of sending blocking and completion callbacks as separated
requests, adding them to a set and sending in parallel.
+Severity : normal
+Bugzilla : 12417
+Description: Disable most debugging by default
+Details : To improve performance, disable most logging (for debug purposes)
+ by default. VFSTRACE, RPCTRACE, and DLMTRACE are now off by
+ default, and HA includes fewer messages.
+
--------------------------------------------------------------------------------
2007-05-03 Cluster File Systems, Inc. <info@clusterfs.com>
{
struct obd_export *exp = cb_data;
- CDEBUG(D_HA, "%s: committing for initial connect of %s\n",
+ CDEBUG(D_RPCTRACE, "%s: committing for initial connect of %s\n",
obd->obd_name, exp->exp_client_uuid.uuid);
spin_lock(&exp->exp_lock);
lock = find_existing_lock(req->rq_export,
&dlm_req->lock_handle[0]);
if (lock != NULL) {
- DEBUG_REQ(D_HA, req, "found existing lock cookie "LPX64,
- lock->l_handle.h_cookie);
+ DEBUG_REQ(D_DLMTRACE, req, "found existing lock cookie "
+ LPX64, lock->l_handle.h_cookie);
GOTO(existing_lock, rc = 0);
}
}
while (1) {
imp = class_exp2cliimp(exp);
if (imp == NULL || imp->imp_invalid) {
- CDEBUG(D_HA, "skipping cancel on invalid import %p\n",
- imp);
+ CDEBUG(D_DLMTRACE,
+ "skipping cancel on invalid import %p\n", imp);
break;
}
ll_generate_random_uuid(uuid);
class_uuid_unparse(uuid, &sbi->ll_sb_uuid);
- CDEBUG(D_HA, "generated uuid: %s\n", sbi->ll_sb_uuid.uuid);
+ CDEBUG(D_CONFIG, "generated uuid: %s\n", sbi->ll_sb_uuid.uuid);
spin_lock(&ll_sb_lock);
list_add_tail(&sbi->ll_list, &ll_super_blocks);
loi = lsm->lsm_oinfo[i];
lov_lockhp = set->set_lockh->llh_handles + i;
if (!lustre_handle_is_used(lov_lockhp)) {
- CDEBUG(D_HA, "lov idx %d subobj "LPX64" no lock?\n",
+ CDEBUG(D_RPCTRACE,"lov idx %d subobj "LPX64" no lock\n",
loi->loi_ost_idx, loi->loi_id);
continue;
}
}
if (!UC_CACHE_IS_ACQUIRING(entry)) {
- CDEBUG(D_HA, "%s: found uptodate entry %p (key "LPU64")\n",
+ CDEBUG(D_RPCTRACE,"%s: found uptodate entry %p (key "LPU64")\n",
hash->uc_name, entry, entry->ue_key);
GOTO(out, rc = 0);
}
LBUG();
}
- DEBUG_REQ(D_HA, req, "storing generation %u for ino "LPU64,
+ DEBUG_REQ(D_INODE, req, "storing generation %u for ino "LPU64,
rec->cr_replayfid.generation, rec->cr_replayfid.id);
}
struct lustre_handle *file_fh;
LASSERT(och->och_magic == OBD_CLIENT_HANDLE_MAGIC);
file_fh = &och->och_fh;
- CDEBUG(D_HA, "updating handle from "LPX64" to "LPX64"\n",
+ CDEBUG(D_RPCTRACE, "updating handle from "LPX64" to "LPX64"\n",
file_fh->cookie, body->handle.cookie);
memcpy(&old, file_fh, sizeof(old));
memcpy(file_fh, &body->handle, sizeof(*file_fh));
sizeof(*close_body));
if (och != NULL)
LASSERT(!memcmp(&old, &close_body->handle, sizeof old));
- DEBUG_REQ(D_HA, close_req, "updating close body with new fh");
+ DEBUG_REQ(D_RPCTRACE, close_req, "updating close with new fh");
memcpy(&close_body->handle, &body->handle,
sizeof(close_body->handle));
}
LBUG();
}
- DEBUG_REQ(D_HA, open_req, "set up replay data");
+ DEBUG_REQ(D_RPCTRACE, open_req, "set up replay data");
}
void mdc_clear_open_replay_data(struct obd_client_handle *och)
struct ptlrpc_request *open_req;
struct obd_import *imp = req->rq_import;
- DEBUG_REQ(D_HA, req, "close req committed");
+ DEBUG_REQ(D_RPCTRACE, req, "close req committed");
if (mod == NULL)
return;
LASSERT(open_req != LP_POISON);
LASSERT(open_req->rq_type != LI_POISON);
- DEBUG_REQ(D_HA, open_req, "open req balanced");
+ DEBUG_REQ(D_RPCTRACE, open_req, "open req balanced");
LASSERT(open_req->rq_transno != 0);
LASSERT(open_req->rq_import == imp);
GOTO(out, rc = -EIO);
}
mod->mod_close_req = req;
- DEBUG_REQ(D_HA, mod->mod_open_req, "matched open");
+ DEBUG_REQ(D_RPCTRACE, mod->mod_open_req, "matched open");
} else {
- CDEBUG(D_HA, "couldn't find open req; expecting close error\n");
+ CDEBUG(D_RPCTRACE, "couldn't find open req; expecting error\n");
}
mdc_close_pack(req, REQ_REC_OFF, oa, oa->o_valid, och);
mdc_put_rpc_lock(obd->u.cli.cl_close_lock, NULL);
if (req->rq_repmsg == NULL) {
- CDEBUG(D_HA, "request failed to send: %p, %d\n", req,
+ CDEBUG(D_RPCTRACE, "request failed to send: %p, %d\n", req,
req->rq_status);
if (rc == 0)
rc = req->rq_status ? req->rq_status : -EIO;
if (lock->l_remote_handle.cookie == remote_hdl.cookie) {
lockh->cookie = lock->l_handle.h_cookie;
LDLM_DEBUG(lock, "restoring lock cookie");
- DEBUG_REQ(D_HA, req, "restoring lock cookie "LPX64,
+ DEBUG_REQ(D_DLMTRACE, req,"restoring lock cookie "LPX64,
lockh->cookie);
if (old_lock)
*old_lock = LDLM_LOCK_GET(lock);
lustre_msg_clear_flags(req->rq_reqmsg, MSG_RESENT);
- DEBUG_REQ(D_HA, req, "no existing lock with rhandle "LPX64,
+ DEBUG_REQ(D_DLMTRACE, req, "no existing lock with rhandle "LPX64,
remote_hdl.cookie);
}
}
if (body->valid & OBD_MD_FLMODEASIZE)
- CDEBUG(D_HA, "updating max_mdsize/max_cookiesize: %d/%d\n",
+ CDEBUG(D_INODE, "updating max_mdsize/max_cookiesize: %d/%d\n",
mds->mds_max_mdsize, mds->mds_max_cookiesize);
mds_pack_inode2fid(&body->fid1, inode);
}
case OBD_IOC_SYNC: {
- CDEBUG(D_HA, "syncing mds %s\n", obd->obd_name);
+ CDEBUG(D_INFO, "syncing mds %s\n", obd->obd_name);
rc = fsfilt_sync(obd, obd->u.obt.obt_sb);
RETURN(rc);
}
int stripe_count = 0;
LASSERT(rc == 0); /* mds_put_write_access must have succeeded */
- CDEBUG(D_HA, "destroying orphan object %s\n", fidname);
+ CDEBUG(D_INODE, "destroying orphan object %s\n", fidname);
if ((S_ISREG(inode->i_mode) && inode->i_nlink != 1) ||
(S_ISDIR(inode->i_mode) && inode->i_nlink != 2))
MDS_CHECK_RESENT(req, mds_reconstruct_generic(req));
}
- CDEBUG(D_HA, "close req->rep_len %d mdsize %d cookiesize %d\n",
+ CDEBUG(D_INODE, "close req->rep_len %d mdsize %d cookiesize %d\n",
req->rq_replen,
obd->u.mds.mds_max_mdsize, obd->u.mds.mds_max_cookiesize);
mds_counter_incr(req->rq_export, LPROC_MDS_CLOSE);
obd_transno_commit_cb(obd, transno, error);
- CDEBUG(D_HA, "cancelling %d cookies\n",
+ CDEBUG(D_RPCTRACE, "cancelling %d cookies\n",
(int)(mlcd->mlcd_cookielen / sizeof(*mlcd->mlcd_cookies)));
- rc = obd_unpackmd(obd->u.mds.mds_osc_exp, &lsm, mlcd->mlcd_lmm,
+ rc = obd_unpackmd(obd->u.mds.mds_osc_exp, &lsm, mlcd->mlcd_lmm,
mlcd->mlcd_eadatalen);
if (rc < 0) {
CERROR("bad LSM cancelling %d log cookies: rc %d\n",
__u64 transno, prev_transno;
int err;
loff_t off;
- int log_pri = D_HA;
+ int log_pri = D_RPCTRACE;
ENTRY;
if (IS_ERR(handle)) {
oldrep->rs_modes[i]);
oldrep->rs_nlocks = 0;
- DEBUG_REQ(D_HA, req, "stole locks for");
+ DEBUG_REQ(D_DLMTRACE, req, "stole locks for");
ptlrpc_schedule_difficult_reply (oldrep);
spin_unlock (&svc->srv_lock);
req->rq_status = le32_to_cpu(mcd->mcd_last_result);
lustre_msg_set_status(req->rq_repmsg, req->rq_status);
}
- DEBUG_REQ(D_HA, req, "restoring transno "LPD64"/status %d",
+ DEBUG_REQ(D_RPCTRACE, req, "restoring transno "LPD64"/status %d",
req->rq_transno, req->rq_status);
mds_steal_ack_locks(req);
MDS_UP_READ_ORPHAN_SEM(child_inode);
rc = mds_unlink_orphan(obd, dchild, child_inode, pending_dir);
- if (rc == 0) {
- item ++;
- CDEBUG(D_HA, "%s: removed orphan %s\n",
- obd->obd_name, d_name);
- } else {
- CDEBUG(D_INODE, "%s: removed orphan %s failed,"
- " rc = %d\n", obd->obd_name, d_name, rc);
+ CDEBUG(D_INODE, "%s: removed orphan %s: rc %d\n",
+ obd->obd_name, d_name, rc);
+ if (rc == 0)
+ item++;
+ else
rc = 0;
- }
next:
l_dput(dchild);
UNLOCK_INODE_MUTEX(pending_dir);
rc = obd_disconnect(fake_exp);
class_export_put(exp);
- if (rc) {
- CDEBUG(D_HA, "disconnecting export %p failed: %d\n",
- exp, rc);
- } else {
- CDEBUG(D_HA, "export %p disconnected\n", exp);
- }
+ CDEBUG(D_HA, "disconnecting export %s (%p): rc %d\n",
+ exp->exp_client_uuid.uuid, exp, rc);
}
EXIT;
}
int rc = 0;
ENTRY;
- CDEBUG(D_HA, "canceling %d in log "LPX64"\n",
+ CDEBUG(D_RPCTRACE, "canceling %d in log "LPX64"\n",
index, loghandle->lgh_id.lgl_oid);
if (index == 0) {
}
if (!ext2_clear_bit(index, llh->llh_bitmap)) {
- CDEBUG(D_HA, "catalog index %u already clear?\n", index);
+ CDEBUG(D_RPCTRACE, "catalog index %u already clear?\n", index);
RETURN(-EINVAL);
}
rec = buf;
idx = le32_to_cpu(rec->lrh_index);
if (idx < index)
- CDEBUG(D_HA, "index %u : idx %u\n", index, idx);
+ CDEBUG(D_RPCTRACE, "index %u : idx %u\n", index, idx);
while (idx < index) {
rec = ((void *)rec + le32_to_cpu(rec->lrh_len));
idx ++;
llh->llh_count++;
llh->llh_tail.lrt_index = index;
- CDEBUG(D_HA, "new recovery log "LPX64":%x for index %u of catalog "
+ CDEBUG(D_RPCTRACE,"new recovery log "LPX64":%x for index %u of catalog "
LPX64"\n", loghandle->lgh_id.lgl_oid, loghandle->lgh_id.lgl_ogen,
index, cathandle->lgh_id.lgl_oid);
/* build the record for this log in the catalog */
llog_cat_set_first_idx(cathandle, index);
rc = llog_cancel_rec(cathandle, index);
if (rc == 0)
- CDEBUG(D_HA, "cancel plain log at index %u "
- "of catalog "LPX64"\n",
+ CDEBUG(D_RPCTRACE,"cancel plain log at index %u"
+ " of catalog "LPX64"\n",
index, cathandle->lgh_id.lgl_oid);
}
}
}
}
out:
- CDEBUG(D_HA, "set catlog "LPX64" first idx %u\n",
+ CDEBUG(D_RPCTRACE, "set catlog "LPX64" first idx %u\n",
cathandle->lgh_id.lgl_oid, llh->llh_cat_idx);
}
obd = handle->lgh_ctxt->loc_exp->exp_obd;
if (handle->lgh_file->f_dentry->d_inode->i_size == 0) {
- CDEBUG(D_HA, "not reading header from 0-byte log\n");
+ CDEBUG(D_RPCTRACE, "not reading header from 0-byte log\n");
RETURN(LLOG_EEMPTY);
}
if (rc)
RETURN(rc);
- CDEBUG(D_HA, "added record "LPX64": idx: %u, %u bytes\n",
+ CDEBUG(D_RPCTRACE, "added record "LPX64": idx: %u, %u bytes\n",
loghandle->lgh_id.lgl_oid, index, rec->lrh_len);
if (rc == 0 && reccookie) {
reccookie->lgc_lgl = loghandle->lgh_id;
llog_cat_set_first_idx(cathandle, index);
rc = llog_cancel_rec(cathandle, index);
if (rc == 0)
- CDEBUG(D_HA, "cancel plain log at index"
- " %u of catalog "LPX64"\n",
+ CDEBUG(D_RPCTRACE, "cancel plain log at"
+ "index %u of catalog "LPX64"\n",
index,cathandle->lgh_id.lgl_oid);
}
}
struct filter_client_data *fcd = fed->fed_fcd;
__u64 last_rcvd;
loff_t off;
- int err, log_pri = D_HA;
+ int err, log_pri = D_RPCTRACE;
/* Propagate error code. */
if (rc)
diff = 1;
else
diff = oa->o_id - filter_last_id(filter, group);
- CDEBUG(D_HA, "filter_last_id() = "LPU64" -> diff = %d\n",
+ CDEBUG(D_RPCTRACE, "filter_last_id() = "LPU64" -> diff = %d\n",
filter_last_id(filter, group), diff);
LASSERTF(diff >= 0,"%s: "LPU64" - "LPU64" = %d\n",obd->obd_name,
RETURN(-ENOMEM);
rc = filter_statfs(obd, osfs, cfs_time_current_64() - HZ);
if (rc == 0 && osfs->os_bavail < (osfs->os_blocks >> 10)) {
- CDEBUG(D_HA,"%s: not enough space for create "LPU64"\n",
- obd->obd_name, osfs->os_bavail <<
+ CDEBUG(D_RPCTRACE,"%s: not enough space for create "
+ LPU64"\n", obd->obd_name, osfs->os_bavail <<
filter->fo_vfsmnt->mnt_sb->s_blocksize_bits);
*num = 0;
rc = -ENOSPC;
RETURN(rc);
}
- CDEBUG(D_HA, "%s: precreating %d objects in group "LPU64" at "LPU64"\n",
- obd->obd_name, *num, group, oa->o_id);
+ CDEBUG(D_RPCTRACE, "%s: precreating %d objects in group "LPU64
+ " at "LPU64"\n", obd->obd_name, *num, group, oa->o_id);
for (i = 0; i < *num && err == 0; i++) {
int cleanup_phase = 0;
if (rc)
break;
if (time_after(jiffies, enough_time)) {
- CDEBUG(D_HA, "%s: precreate slow - want %d got %d \n",
+ CDEBUG(D_RPCTRACE,
+ "%s: precreate slow - want %d got %d \n",
obd->obd_name, *num, i);
break;
}
}
*num = i;
- CDEBUG(D_HA,"%s: created %d objects for group "LPU64": "LPU64" rc %d\n",
+ CDEBUG(D_RPCTRACE,
+ "%s: created %d objects for group "LPU64": "LPU64" rc %d\n",
obd->obd_name, i, group, filter->fo_last_objids[group], rc);
RETURN(rc);
}
case OBD_IOC_SYNC: {
- CDEBUG(D_HA, "syncing ost %s\n", obd->obd_name);
+ CDEBUG(D_RPCTRACE, "syncing ost %s\n", obd->obd_name);
rc = fsfilt_sync(obd, obd->u.obt.obt_sb);
RETURN(rc);
}
{
struct filter_export_data *fed;
struct obd_device *obd = exp->exp_obd;
- static unsigned long last_msg;
- static int last_count;
- int mask = D_CACHE;
ENTRY;
LASSERT_SPIN_LOCKED(&obd->obd_osfs_lock);
fed = &exp->exp_filter_data;
- /* Don't print this to the console the first time it happens, since
- * it can happen legitimately on occasion, but only rarely. */
- if (time_after(jiffies, last_msg + 60 * HZ)) {
- last_count = 0;
- last_msg = jiffies;
- }
- if ((last_count & (-last_count)) == last_count)
- mask = D_HA /* until bug 3273 is fixed D_WARNING */;
- last_count++;
-
/* Add some margin, since there is a small race if other RPCs arrive
* out-or-order and have already consumed some grant. We want to
* leave this here in case there is a large error in accounting. */
- CDEBUG(oa->o_grant > fed->fed_grant + FILTER_GRANT_CHUNK ? mask:D_CACHE,
+ CDEBUG(D_CACHE,
"%s: cli %s/%p reports grant: "LPU64" dropped: %u, local: %lu\n",
obd->obd_name, exp->exp_client_uuid.uuid, exp, oa->o_grant,
oa->o_dropped, fed->fed_grant);
oa->o_dirty = fed->fed_grant + 4 * FILTER_GRANT_CHUNK;
obd->u.filter.fo_tot_dirty += oa->o_dirty - fed->fed_dirty;
if (fed->fed_grant < oa->o_dropped) {
- CDEBUG(D_HA,"%s: cli %s/%p reports %u dropped > fedgrant %lu\n",
+ CDEBUG(D_CACHE,"%s: cli %s/%p reports %u dropped > grant %lu\n",
obd->obd_name, exp->exp_client_uuid.uuid, exp,
oa->o_dropped, fed->fed_grant);
oa->o_dropped = 0;
struct filter_export_data *fed = &exp->exp_filter_data;
int blocksize = exp->exp_obd->u.obt.obt_sb->s_blocksize;
unsigned long used = 0, ungranted = 0, using;
- int i, rc = -ENOSPC, obj, n = 0, mask = D_CACHE;
+ int i, rc = -ENOSPC, obj, n = 0;
LASSERT_SPIN_LOCKED(&exp->exp_obd->obd_osfs_lock);
exp->exp_obd->obd_name,
exp->exp_client_uuid.uuid, exp,
used, bytes, fed->fed_grant, n);
- mask = D_RPCTRACE;
} else {
used += bytes;
rnb[n].flags |= OBD_BRW_GRANTED;
exp->exp_obd->u.filter.fo_tot_granted += ungranted;
exp->exp_obd->u.filter.fo_tot_pending += used + ungranted;
- CDEBUG(mask,
+ CDEBUG(D_CACHE,
"%s: cli %s/%p used: %lu ungranted: %lu grant: %lu dirty: %lu\n",
exp->exp_obd->obd_name, exp->exp_client_uuid.uuid, exp, used,
ungranted, fed->fed_grant, fed->fed_dirty);
rc = filter_destroy(exp, oa, NULL, NULL, NULL);
OBDO_FREE(oa);
if (rc == -ENOENT) {
- CDEBUG(D_HA, "object already removed, send cookie\n");
+ CDEBUG(D_RPCTRACE, "object already removed, send cookie\n");
llog_cancel(ctxt, NULL, 1, cookie, 0);
RETURN(0);
}
if (rc == 0)
- CDEBUG(D_HA, "object: "LPU64" in record is destroyed\n", oid);
+ CDEBUG(D_RPCTRACE, "object "LPU64" is destroyed\n", oid);
RETURN(rc);
}
OBDO_FREE(oinfo.oi_oa);
if (rc == -ENOENT) {
- CDEBUG(D_HA, "object already removed, send cookie\n");
+ CDEBUG(D_RPCTRACE, "object already removed, send cookie\n");
llog_cancel(ctxt, NULL, 1, cookie, 0);
RETURN(0);
}
if (rc == 0)
- CDEBUG(D_HA, "object: "LPU64" in record is chown/chgrp\n", oid);
+ CDEBUG(D_RPCTRACE, "object "LPU64" is chown/chgrp\n", oid);
RETURN(rc);
}
}
}
- CDEBUG(D_HA, "preallocated through id "LPU64" (next to use "LPU64")\n",
+ CDEBUG(D_RPCTRACE, "prealloc through id "LPU64", next to use "LPU64"\n",
oscc->oscc_last_id, oscc->oscc_next_id);
cfs_waitq_signal(&oscc->oscc_waitq);
body->oa.o_id = oscc->oscc_last_id + oscc->oscc_grow_count;
body->oa.o_valid |= OBD_MD_FLID;
spin_unlock(&oscc->oscc_lock);
- CDEBUG(D_HA, "preallocating through id "LPU64" (last seen "LPU64")\n",
+ CDEBUG(D_RPCTRACE, "prealloc through id "LPU64" (last seen "LPU64")\n",
body->oa.o_id, oscc->oscc_last_id);
ptlrpc_req_set_repsize(request, 2, size);
}
oscc->oscc_flags |= OSCC_FLAG_SYNC_IN_PROGRESS;
spin_unlock(&oscc->oscc_lock);
- CDEBUG(D_HA, "%s: oscc recovery started\n",
- oscc->oscc_obd->obd_name);
+ CDEBUG(D_HA, "%s: oscc recovery started - delete to "LPU64"\n",
+ oscc->oscc_obd->obd_name, oscc->oscc_next_id - 1);
/* delete from next_id on up */
oa->o_valid |= OBD_MD_FLID;
oa->o_id = oscc->oscc_next_id - 1;
- CDEBUG(D_HA, "%s: deleting to next_id: "LPU64"\n",
- oscc->oscc_obd->obd_name, oa->o_id);
-
rc = osc_real_create(exp, oa, ea, NULL);
spin_lock(&oscc->oscc_lock);
oscc->oscc_next_id++;
try_again = 0;
- CDEBUG(D_HA, "%s: set oscc_next_id = "LPU64"\n",
+ CDEBUG(D_RPCTRACE, "%s: set oscc_next_id = "LPU64"\n",
exp->exp_obd->obd_name, oscc->oscc_next_id);
} else if (oscc->oscc_flags & OSCC_FLAG_NOSPC) {
rc = -ENOSPC;
}
if (rc == 0)
- CDEBUG(D_HA, "%s: returning objid "LPU64"\n",
+ CDEBUG(D_INFO, "%s: returning objid "LPU64"\n",
obd2cli_tgt(oscc->oscc_obd), lsm->lsm_object_id);
else if (*ea == NULL)
obd_free_memmd(exp, &lsm);
imp->imp_server_timeout = 1;
imp->imp_pingable = 1;
spin_unlock(&imp->imp_lock);
- CDEBUG(D_HA, "pinging OST %s\n", obd2cli_tgt(imp->imp_obd));
+ CDEBUG(D_RPCTRACE, "pinging OST %s\n", obd2cli_tgt(imp->imp_obd));
RETURN(rc);
}
/* wait until all complete, interrupted, or an in-flight
* req times out */
- CDEBUG(D_HA, "set %p going to sleep for %d seconds\n",
+ CDEBUG(D_RPCTRACE, "set %p going to sleep for %d seconds\n",
set, timeout);
lwi = LWI_TIMEOUT_INTR(cfs_time_seconds(timeout ? timeout : 1),
ptlrpc_expired_set,
if (imp->imp_peer_committed_transno == imp->imp_last_transno_checked &&
imp->imp_generation == imp->imp_last_generation_checked) {
- CDEBUG(D_HA, "%s: skip recheck for last_committed "LPU64"\n",
+ CDEBUG(D_RPCTRACE, "%s: skip recheck: last_committed "LPU64"\n",
imp->imp_obd->obd_name, imp->imp_peer_committed_transno);
return;
}
-
- CDEBUG(D_HA, "%s: committing for last_committed "LPU64" gen %d\n",
+
+ CDEBUG(D_RPCTRACE, "%s: committing for last_committed "LPU64" gen %d\n",
imp->imp_obd->obd_name, imp->imp_peer_committed_transno,
imp->imp_generation);
imp->imp_last_transno_checked = imp->imp_peer_committed_transno;
last_req = req;
if (req->rq_import_generation < imp->imp_generation) {
- DEBUG_REQ(D_HA, req, "freeing request with old gen");
+ DEBUG_REQ(D_RPCTRACE, req, "free request with old gen");
GOTO(free_req, 0);
}
if (req->rq_replay) {
- DEBUG_REQ(D_HA, req, "keeping (FL_REPLAY)");
+ DEBUG_REQ(D_RPCTRACE, req, "keeping (FL_REPLAY)");
continue;
}
/* not yet committed */
if (req->rq_transno > imp->imp_peer_committed_transno) {
- DEBUG_REQ(D_HA, req, "stopping search");
+ DEBUG_REQ(D_RPCTRACE, req, "stopping search");
break;
}
- DEBUG_REQ(D_HA, req, "committing (last_committed "LPU64")",
+ DEBUG_REQ(D_RPCTRACE, req, "commit (last_committed "LPU64")",
imp->imp_peer_committed_transno);
free_req:
spin_lock(&req->rq_lock);
struct ptlrpc_request *req =
list_entry(tmp, struct ptlrpc_request, rq_list);
- DEBUG_REQ(D_HA, req, "inflight");
+ DEBUG_REQ(D_RPCTRACE, req, "inflight");
spin_lock (&req->rq_lock);
if (req->rq_import_generation < imp->imp_generation) {
struct ptlrpc_request *req =
list_entry(tmp, struct ptlrpc_request, rq_list);
- DEBUG_REQ(D_HA, req, "aborting waiting req");
+ DEBUG_REQ(D_RPCTRACE, req, "aborting waiting req");
spin_lock (&req->rq_lock);
if (req->rq_import_generation < imp->imp_generation) {
if (rc)
CERROR("cancel %d llog-records failed: %d\n", num_cookies, rc);
else
- CDEBUG(D_HA, "cancel %d llog-records\n", num_cookies);
+ CDEBUG(D_RPCTRACE, "cancel %d llog-records\n", num_cookies);
RETURN(rc);
}
imp->imp_force_verify = 0;
spin_unlock(&imp->imp_lock);
- CDEBUG(level == LUSTRE_IMP_FULL ? D_INFO : D_HA,
+ CDEBUG(level == LUSTRE_IMP_FULL ? D_INFO : D_RPCTRACE,
"level %s/%u force %u deactive %u pingable %u\n",
ptlrpc_import_state_name(level), level,
force, imp->imp_deactive, imp->imp_pingable);
req->rq_import_generation = generation;
ptlrpc_set_add_req(set, req);
} else {
- CDEBUG(D_HA, "don't need to ping %s ("CFS_TIME_T" > "
- CFS_TIME_T")\n", obd2cli_tgt(imp->imp_obd),
+ CDEBUG(D_INFO, "don't need to ping %s ("CFS_TIME_T
+ " > "CFS_TIME_T")\n", obd2cli_tgt(imp->imp_obd),
imp->imp_next_ping, pd->pd_this_ping);
}
}
/* Might be empty, that's OK. */
if (set->set_remaining == 0)
- CDEBUG(D_HA, "nothing to ping\n");
+ CDEBUG(D_RPCTRACE, "nothing to ping\n");
list_for_each(iter, &set->set_requests) {
struct ptlrpc_request *req =
list_entry(iter, struct ptlrpc_request,
rq_set_chain);
- DEBUG_REQ(D_HA, req, "pinging %s->%s",
+ DEBUG_REQ(D_RPCTRACE, req, "pinging %s->%s",
req->rq_import->imp_obd->obd_uuid.uuid,
obd2cli_tgt(req->rq_import->imp_obd));
(void)ptl_send_rpc(req, 0);
rc = ptlrpc_check_set(set);
/* not finished, and we are not expired, simply return */
- if (!rc && cfs_time_before(curtime,
- cfs_time_add(pd->pd_this_ping,
- cfs_time_seconds(PING_INTERVAL)))) {
- CDEBUG(D_HA, "not finished, but also not expired\n");
+ if (!rc && cfs_time_before(curtime, cfs_time_add(pd->pd_this_ping,
+ cfs_time_seconds(PING_INTERVAL)))) {
+ CDEBUG(D_RPCTRACE, "not finished, but also not expired\n");
pd->pd_recursion--;
return 0;
}
continue;
}
- CDEBUG(D_HA, "pinger initiate expire_one_request\n");
+ CDEBUG(D_RPCTRACE, "pinger initiate expire_one_request\n");
ptlrpc_expire_one_request(req);
}
mutex_up(&pinger_sem);
cfs_time_seconds(PING_INTERVAL));
pd->pd_this_ping = 0; /* XXX for debug */
- CDEBUG(D_HA, "finished a round ping\n");
+ CDEBUG(D_INFO, "finished a round ping\n");
pd->pd_recursion--;
return 0;
}
/* XXX force pinger to run, if needed */
struct obd_import *imp;
list_for_each_entry(imp, &pinger_imports, imp_pinger_chain) {
- CDEBUG(D_HA, "Checking that we need to do anything about import"
- " %s->%s\n", imp->imp_obd->obd_uuid.uuid,
- obd2cli_tgt(imp->imp_obd));
+ CDEBUG(D_RPCTRACE, "checking import %s->%s\n",
+ imp->imp_obd->obd_uuid.uuid, obd2cli_tgt(imp->imp_obd));
#ifdef ENABLE_LIBLUSTRE_RECOVERY
if (imp->imp_state == LUSTRE_IMP_DISCON && !imp->imp_deactive)
#else
mutex_down(&ctxt->loc_sem);
if (ctxt->loc_imp == NULL) {
- CDEBUG(D_HA, "no import for ctxt %p\n", ctxt);
+ CDEBUG(D_RPCTRACE, "no import for ctxt %p\n", ctxt);
GOTO(out, rc = 0);
}
if ((llcd->llcd_size - llcd->llcd_cookiebytes) < sizeof(*cookies) ||
(flags & OBD_LLOG_FL_SENDNOW)) {
- CDEBUG(D_HA, "send llcd %p:%p\n", llcd, llcd->llcd_ctxt);
+ CDEBUG(D_RPCTRACE, "send llcd %p:%p\n", llcd, llcd->llcd_ctxt);
ctxt->loc_llcd = NULL;
llcd_send(llcd);
}
ENTRY;
if (exp && (ctxt->loc_imp == exp->exp_imp_reverse)) {
- CDEBUG(D_HA, "reverse import disconnected, put llcd %p:%p\n",
+ CDEBUG(D_RPCTRACE,"reverse import disconnect, put llcd %p:%p\n",
ctxt->loc_llcd, ctxt);
mutex_down(&ctxt->loc_sem);
if (ctxt->loc_llcd != NULL) {
list_del(&llcd->llcd_list);
if (llcd->llcd_cookiebytes == 0) {
- CDEBUG(D_HA, "put empty llcd %p:%p\n",
+ CDEBUG(D_RPCTRACE, "put empty llcd %p:%p\n",
llcd, llcd->llcd_ctxt);
llcd_put(llcd);
continue;
request->rq_export->exp_obd->obd_fail) {
/* Failing over, don't handle any more reqs, send
error response instead. */
- CDEBUG(D_HA, "Dropping req %p for failed obd %s\n",
+ CDEBUG(D_RPCTRACE,"Dropping req %p for failed obd %s\n",
request, request->rq_export->exp_obd->obd_name);
request->rq_status = -ENODEV;
ptlrpc_error(request);
request->rq_status,
reply ? lustre_msg_get_status(request->rq_repmsg): -999);
else
- CDEBUG(D_HA, "request "LPU64" opc %u from %s processed in "
+ CDEBUG(D_RPCTRACE,"request "LPU64" opc %u from %s processed in "
"%ldus (%ldus total) trans "LPU64" rc %d/%d\n",
request->rq_xid, lustre_msg_get_opc(request->rq_reqmsg),
libcfs_id2str(request->rq_peer), timediff,