From 32fb9b57aef35b82434cfb4c9de18b484fc3ec88 Mon Sep 17 00:00:00 2001 From: Tim Shimmin Date: Fri, 2 Sep 2005 16:41:43 +1000 Subject: [XFS] Fix up the calculation of the reservation overhead to hopefully include all the components which make up the transaction in the ondisk log. Having this incomplete has shown up as problems on IRIX when some v2 log changes went in. The symptom was the msg of "xfs_log_write: reservation ran out. Need to up reservation" and was seen on synchronous writes on files with lots of holes (and therefore lots of extents). SGI-PV: 931457 SGI-Modid: xfs-linux:xfs-kern:23095a Signed-off-by: Tim Shimmin Signed-off-by: Nathan Scott --- fs/xfs/xfs_log.c | 54 +++++++++++++++++++++++++++++++++++++++++------------- 1 file changed, 41 insertions(+), 13 deletions(-) (limited to 'fs/xfs/xfs_log.c') diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c index 1cd2ac16387..42975cb9e53 100644 --- a/fs/xfs/xfs_log.c +++ b/fs/xfs/xfs_log.c @@ -3179,29 +3179,57 @@ xlog_ticket_get(xlog_t *log, * and their unit amount is the total amount of space required. * * The following lines of code account for non-transaction data - * which occupy space in the on-disk log. + * which occupy space in the on-disk log. + * + * Normal form of a transaction is: + * ... + * and then there are LR hdrs, split-recs and roundoff at end of syncs. + * + * We need to account for all the leadup data and trailer data + * around the transaction data. + * And then we need to account for the worst case in terms of using + * more space. + * The worst case will happen if: + * - the placement of the transaction happens to be such that the + * roundoff is at its maximum + * - the transaction data is synced before the commit record is synced + * i.e. | + * Therefore the commit record is in its own Log Record. + * This can happen as the commit record is called with its + * own region to xlog_write(). + * This then means that in the worst case, roundoff can happen for + * the commit-rec as well. + * The commit-rec is smaller than padding in this scenario and so it is + * not added separately. */ + /* for trans header */ + unit_bytes += sizeof(xlog_op_header_t); + unit_bytes += sizeof(xfs_trans_header_t); + /* for start-rec */ - unit_bytes += sizeof(xlog_op_header_t); + unit_bytes += sizeof(xlog_op_header_t); + + /* for LR headers */ + num_headers = ((unit_bytes + log->l_iclog_size-1) >> log->l_iclog_size_log); + unit_bytes += log->l_iclog_hsize * num_headers; - /* for padding */ + /* for commit-rec LR header - note: padding will subsume the ophdr */ + unit_bytes += log->l_iclog_hsize; + + /* for split-recs - ophdrs added when data split over LRs */ + unit_bytes += sizeof(xlog_op_header_t) * num_headers; + + /* for roundoff padding for transaction data and one for commit record */ if (XFS_SB_VERSION_HASLOGV2(&log->l_mp->m_sb) && - log->l_mp->m_sb.sb_logsunit > 1) { + log->l_mp->m_sb.sb_logsunit > 1) { /* log su roundoff */ - unit_bytes += log->l_mp->m_sb.sb_logsunit; + unit_bytes += 2*log->l_mp->m_sb.sb_logsunit; } else { /* BB roundoff */ - unit_bytes += BBSIZE; + unit_bytes += 2*BBSIZE; } - /* for commit-rec */ - unit_bytes += sizeof(xlog_op_header_t); - - /* for LR headers */ - num_headers = ((unit_bytes + log->l_iclog_size-1) >> log->l_iclog_size_log); - unit_bytes += log->l_iclog_hsize * num_headers; - tic->t_unit_res = unit_bytes; tic->t_curr_res = unit_bytes; tic->t_cnt = cnt; -- cgit v1.2.3 From 7e9c63961558092d584936a874cf3fee80002eb6 Mon Sep 17 00:00:00 2001 From: Tim Shimmin Date: Fri, 2 Sep 2005 16:42:05 +1000 Subject: [XFS] 929956 add log debugging and tracing info SGI-PV: 931456 SGI-Modid: xfs-linux:xfs-kern:23155a Signed-off-by: Tim Shimmin Signed-off-by: Nathan Scott --- fs/xfs/xfs_log.c | 161 +++++++++++++++++++++++++++++++++++++++++++++++++++---- 1 file changed, 151 insertions(+), 10 deletions(-) (limited to 'fs/xfs/xfs_log.c') diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c index 42975cb9e53..54a6f114240 100644 --- a/fs/xfs/xfs_log.c +++ b/fs/xfs/xfs_log.c @@ -159,11 +159,15 @@ xfs_buftarg_t *xlog_target; void xlog_trace_loggrant(xlog_t *log, xlog_ticket_t *tic, xfs_caddr_t string) { - if (! log->l_grant_trace) { - log->l_grant_trace = ktrace_alloc(1024, KM_NOSLEEP); - if (! log->l_grant_trace) + unsigned long cnts; + + if (!log->l_grant_trace) { + log->l_grant_trace = ktrace_alloc(2048, KM_NOSLEEP); + if (!log->l_grant_trace) return; } + /* ticket counts are 1 byte each */ + cnts = ((unsigned long)tic->t_ocnt) | ((unsigned long)tic->t_cnt) << 8; ktrace_enter(log->l_grant_trace, (void *)tic, @@ -178,10 +182,10 @@ xlog_trace_loggrant(xlog_t *log, xlog_ticket_t *tic, xfs_caddr_t string) (void *)((unsigned long)CYCLE_LSN(log->l_tail_lsn)), (void *)((unsigned long)BLOCK_LSN(log->l_tail_lsn)), (void *)string, - (void *)((unsigned long)13), - (void *)((unsigned long)14), - (void *)((unsigned long)15), - (void *)((unsigned long)16)); + (void *)((unsigned long)tic->t_trans_type), + (void *)cnts, + (void *)((unsigned long)tic->t_curr_res), + (void *)((unsigned long)tic->t_unit_res)); } void @@ -274,9 +278,11 @@ xfs_log_done(xfs_mount_t *mp, * Release ticket if not permanent reservation or a specifc * request has been made to release a permanent reservation. */ + xlog_trace_loggrant(log, ticket, "xfs_log_done: (non-permanent)"); xlog_ungrant_log_space(log, ticket); xlog_state_put_ticket(log, ticket); } else { + xlog_trace_loggrant(log, ticket, "xfs_log_done: (permanent)"); xlog_regrant_reserve_log_space(log, ticket); } @@ -399,7 +405,8 @@ xfs_log_reserve(xfs_mount_t *mp, int cnt, xfs_log_ticket_t *ticket, __uint8_t client, - uint flags) + uint flags, + uint t_type) { xlog_t *log = mp->m_log; xlog_ticket_t *internal_ticket; @@ -421,13 +428,19 @@ xfs_log_reserve(xfs_mount_t *mp, if (*ticket != NULL) { ASSERT(flags & XFS_LOG_PERM_RESERV); internal_ticket = (xlog_ticket_t *)*ticket; + xlog_trace_loggrant(log, internal_ticket, "xfs_log_reserve: existing ticket (permanent trans)"); xlog_grant_push_ail(mp, internal_ticket->t_unit_res); retval = xlog_regrant_write_log_space(log, internal_ticket); } else { /* may sleep if need to allocate more tickets */ internal_ticket = xlog_ticket_get(log, unit_bytes, cnt, client, flags); + internal_ticket->t_trans_type = t_type; *ticket = internal_ticket; + xlog_trace_loggrant(log, internal_ticket, + (internal_ticket->t_flags & XLOG_TIC_PERM_RESERV) ? + "xfs_log_reserve: create new ticket (permanent trans)" : + "xfs_log_reserve: create new ticket"); xlog_grant_push_ail(mp, (internal_ticket->t_unit_res * internal_ticket->t_cnt)); @@ -601,8 +614,9 @@ xfs_log_unmount_write(xfs_mount_t *mp) if (! (XLOG_FORCED_SHUTDOWN(log))) { reg[0].i_addr = (void*)&magic; reg[0].i_len = sizeof(magic); + XLOG_VEC_SET_TYPE(®[0], XLOG_REG_TYPE_UNMOUNT); - error = xfs_log_reserve(mp, 600, 1, &tic, XFS_LOG, 0); + error = xfs_log_reserve(mp, 600, 1, &tic, XFS_LOG, 0, 0); if (!error) { /* remove inited flag */ ((xlog_ticket_t *)tic)->t_flags = 0; @@ -1272,6 +1286,7 @@ xlog_commit_record(xfs_mount_t *mp, reg[0].i_addr = NULL; reg[0].i_len = 0; + XLOG_VEC_SET_TYPE(®[0], XLOG_REG_TYPE_COMMIT); ASSERT_ALWAYS(iclog); if ((error = xlog_write(mp, reg, 1, ticket, commitlsnp, @@ -1604,6 +1619,117 @@ xlog_state_finish_copy(xlog_t *log, +/* + * print out info relating to regions written which consume + * the reservation + */ +#if defined(XFS_LOG_RES_DEBUG) +STATIC void +xlog_print_tic_res(xfs_mount_t *mp, xlog_ticket_t *ticket) +{ + uint i; + uint ophdr_spc = ticket->t_res_num_ophdrs * (uint)sizeof(xlog_op_header_t); + + /* match with XLOG_REG_TYPE_* in xfs_log.h */ + static char *res_type_str[XLOG_REG_TYPE_MAX] = { + "bformat", + "bchunk", + "efi_format", + "efd_format", + "iformat", + "icore", + "iext", + "ibroot", + "ilocal", + "iattr_ext", + "iattr_broot", + "iattr_local", + "qformat", + "dquot", + "quotaoff", + "LR header", + "unmount", + "commit", + "trans header" + }; + static char *trans_type_str[XFS_TRANS_TYPE_MAX] = { + "SETATTR_NOT_SIZE", + "SETATTR_SIZE", + "INACTIVE", + "CREATE", + "CREATE_TRUNC", + "TRUNCATE_FILE", + "REMOVE", + "LINK", + "RENAME", + "MKDIR", + "RMDIR", + "SYMLINK", + "SET_DMATTRS", + "GROWFS", + "STRAT_WRITE", + "DIOSTRAT", + "WRITE_SYNC", + "WRITEID", + "ADDAFORK", + "ATTRINVAL", + "ATRUNCATE", + "ATTR_SET", + "ATTR_RM", + "ATTR_FLAG", + "CLEAR_AGI_BUCKET", + "QM_SBCHANGE", + "DUMMY1", + "DUMMY2", + "QM_QUOTAOFF", + "QM_DQALLOC", + "QM_SETQLIM", + "QM_DQCLUSTER", + "QM_QINOCREATE", + "QM_QUOTAOFF_END", + "SB_UNIT", + "FSYNC_TS", + "GROWFSRT_ALLOC", + "GROWFSRT_ZERO", + "GROWFSRT_FREE", + "SWAPEXT" + }; + + xfs_fs_cmn_err(CE_WARN, mp, + "xfs_log_write: reservation summary:\n" + " trans type = %s (%u)\n" + " unit res = %d bytes\n" + " current res = %d bytes\n" + " total reg = %u bytes (o/flow = %u bytes)\n" + " ophdrs = %u (ophdr space = %u bytes)\n" + " ophdr + reg = %u bytes\n" + " num regions = %u\n", + ((ticket->t_trans_type <= 0 || + ticket->t_trans_type > XFS_TRANS_TYPE_MAX) ? + "bad-trans-type" : trans_type_str[ticket->t_trans_type-1]), + ticket->t_trans_type, + ticket->t_unit_res, + ticket->t_curr_res, + ticket->t_res_arr_sum, ticket->t_res_o_flow, + ticket->t_res_num_ophdrs, ophdr_spc, + ticket->t_res_arr_sum + + ticket->t_res_o_flow + ophdr_spc, + ticket->t_res_num); + + for (i = 0; i < ticket->t_res_num; i++) { + uint r_type = ticket->t_res_arr[i].r_type; + cmn_err(CE_WARN, + "region[%u]: %s - %u bytes\n", + i, + ((r_type <= 0 || r_type > XLOG_REG_TYPE_MAX) ? + "bad-rtype" : res_type_str[r_type-1]), + ticket->t_res_arr[i].r_len); + } +} +#else +#define xlog_print_tic_res(mp, ticket) +#endif + /* * Write some region out to in-core log * @@ -1677,16 +1803,21 @@ xlog_write(xfs_mount_t * mp, * xlog_op_header_t and may need to be double word aligned. */ len = 0; - if (ticket->t_flags & XLOG_TIC_INITED) /* acct for start rec of xact */ + if (ticket->t_flags & XLOG_TIC_INITED) { /* acct for start rec of xact */ len += sizeof(xlog_op_header_t); + XLOG_TIC_ADD_OPHDR(ticket); + } for (index = 0; index < nentries; index++) { len += sizeof(xlog_op_header_t); /* each region gets >= 1 */ + XLOG_TIC_ADD_OPHDR(ticket); len += reg[index].i_len; + XLOG_TIC_ADD_REGION(ticket, reg[index].i_len, reg[index].i_type); } contwr = *start_lsn = 0; if (ticket->t_curr_res < len) { + xlog_print_tic_res(mp, ticket); #ifdef DEBUG xlog_panic( "xfs_log_write: reservation ran out. Need to up reservation"); @@ -1790,6 +1921,7 @@ xlog_write(xfs_mount_t * mp, len += sizeof(xlog_op_header_t); /* from splitting of region */ /* account for new log op header */ ticket->t_curr_res -= sizeof(xlog_op_header_t); + XLOG_TIC_ADD_OPHDR(ticket); } xlog_verify_dest_ptr(log, ptr); @@ -2282,6 +2414,9 @@ restart: */ if (log_offset == 0) { ticket->t_curr_res -= log->l_iclog_hsize; + XLOG_TIC_ADD_REGION(ticket, + log->l_iclog_hsize, + XLOG_REG_TYPE_LRHEADER); INT_SET(head->h_cycle, ARCH_CONVERT, log->l_curr_cycle); ASSIGN_LSN(head->h_lsn, log); ASSERT(log->l_curr_block >= 0); @@ -2468,6 +2603,7 @@ xlog_regrant_write_log_space(xlog_t *log, #endif tic->t_curr_res = tic->t_unit_res; + XLOG_TIC_RESET_RES(tic); if (tic->t_cnt > 0) return (0); @@ -2608,6 +2744,7 @@ xlog_regrant_reserve_log_space(xlog_t *log, XLOG_GRANT_SUB_SPACE(log, ticket->t_curr_res, 'w'); XLOG_GRANT_SUB_SPACE(log, ticket->t_curr_res, 'r'); ticket->t_curr_res = ticket->t_unit_res; + XLOG_TIC_RESET_RES(ticket); xlog_trace_loggrant(log, ticket, "xlog_regrant_reserve_log_space: sub current res"); xlog_verify_grant_head(log, 1); @@ -2624,6 +2761,7 @@ xlog_regrant_reserve_log_space(xlog_t *log, xlog_verify_grant_head(log, 0); GRANT_UNLOCK(log, s); ticket->t_curr_res = ticket->t_unit_res; + XLOG_TIC_RESET_RES(ticket); } /* xlog_regrant_reserve_log_space */ @@ -3237,10 +3375,13 @@ xlog_ticket_get(xlog_t *log, tic->t_tid = (xlog_tid_t)((__psint_t)tic & 0xffffffff); tic->t_clientid = client; tic->t_flags = XLOG_TIC_INITED; + tic->t_trans_type = 0; if (xflags & XFS_LOG_PERM_RESERV) tic->t_flags |= XLOG_TIC_PERM_RESERV; sv_init(&(tic->t_sema), SV_DEFAULT, "logtick"); + XLOG_TIC_RESET_RES(tic); + return tic; } /* xlog_ticket_get */ -- cgit v1.2.3