diff --git a/src/libpcp/src/freeresult.c b/src/libpcp/src/freeresult.c index e0206ac..9d76799 100644 --- a/src/libpcp/src/freeresult.c +++ b/src/libpcp/src/freeresult.c @@ -37,7 +37,11 @@ __pmFreeResultValues(pmResult *result) ppvsend = &result->vset[result->numpmid]; /* if _any_ vset[] -> an address within a pdubuf, we are done */ - for (ppvs = result->vset; ppvs < ppvsend; ppvs++) { +int count = 0; +fprintf(stderr, "__pmFreeResultValues rp=%p - range: start=%p end=%p\n", result, result->vset, ppvsend); + for (ppvs = result->vset; ppvs < ppvsend; ppvs++, count++) { +fprintf(stderr, "__pmFreeResultValues rp=%p - range[%d] %p -> %p\n", result, count, ppvs, *ppvs); +fprintf(stderr, "-- __pmUnpinPDUBuf __pmFreeResult: %p\n", *ppvs); if (__pmUnpinPDUBuf((void *)*ppvs)) return; } diff --git a/src/libpcp/src/interp.c b/src/libpcp/src/interp.c index e082097..d408200 100644 --- a/src/libpcp/src/interp.c +++ b/src/libpcp/src/interp.c @@ -36,6 +36,39 @@ #include "pmapi.h" #include "impl.h" +extern void pdubufdump(void); +extern void resulttrace(pmResult *result) +{ + register pmValueSet *pvs; + register pmValueSet **ppvs; + register pmValueSet **ppvsend; + + ppvsend = &result->vset[result->numpmid]; + for (ppvs = result->vset; ppvs < ppvsend; ppvs++) { + pvs = *ppvs; + if (pvs->numval > 0 && pvs->valfmt == PM_VAL_DPTR) { + int j; + for (j = 0; j < pvs->numval; j++) { +#ifdef PCP_DEBUG + if (pmDebug & DBG_TRACE_PDUBUF) { + char strbuf[20]; + fprintf(stderr, "trace(" PRINTF_P_PFX "%p) pmValueBlock pmid=%s inst=%d\n", + pvs->vlist[j].value.pval, pmIDStr_r(pvs->pmid, strbuf, sizeof(strbuf)), + pvs->vlist[j].inst); + } +#endif + } + } +#ifdef PCP_DEBUG + if (pmDebug & DBG_TRACE_PDUBUF) { + char strbuf[20]; + fprintf(stderr, "trace(" PRINTF_P_PFX "%p) vset pmid=%s\n", + pvs, pmIDStr_r(pvs->pmid, strbuf, sizeof(strbuf))); + } +#endif + } +} + #define UPD_MARK_NONE 0 #define UPD_MARK_FORW 1 #define UPD_MARK_BACK 2 @@ -173,14 +206,23 @@ cache_read(__pmArchCtl *acp, int mode, pmResult **rp) nr[mode]++; #endif - if (lfup->rp != NULL) + if (lfup->rp != NULL) { + fprintf(stderr, "cache_read freeing %p\n", lfup->rp); pmFreeResult(lfup->rp); + lfup->rp = NULL; + } save_curvol = acp->ac_log->l_curvol; lfup->sts = __pmLogRead(acp->ac_log, mode, NULL, &lfup->rp, PMLOGREAD_NEXT); if (lfup->sts < 0) lfup->rp = NULL; +else { +fprintf(stderr, "START log_read allocs(%p)\n", lfup->rp); +resulttrace(lfup->rp); +pdubufdump(); +fprintf(stderr, "END log_read allocs(%p)\n", lfup->rp); +} *rp = lfup->rp; if (posn == 0 || save_curvol != acp->ac_log->l_curvol) { @@ -239,8 +281,10 @@ __pmLogCacheClear(FILE *mfp) PM_LOCK(__pmLock_libpcp); for (cp = cache; cp < &cache[NUMCACHE]; cp++) { if (cp->mfp == mfp) { - if (cp->rp != NULL) + if (cp->rp != NULL) { + fprintf(stderr, "cache_clear freeing %p\n", cp->rp); pmFreeResult(cp->rp); + } cp->rp = NULL; cp->mfp = NULL; cp->used = 0; @@ -266,25 +310,30 @@ dumpval(FILE *f, int type, int valfmt, int mark, value *vp) } else if (type == PM_TYPE_64) { __int64_t tmp; + if (!vp->pval) goto dunno; memcpy((void *)&tmp, (void *)vp->pval->vbuf, sizeof(tmp)); fprintf(f, " v=%"PRIi64, tmp); } else if (type == PM_TYPE_U64) { __uint64_t tmp; + if (!vp->pval) goto dunno; memcpy((void *)&tmp, (void *)vp->pval->vbuf, sizeof(tmp)); fprintf(f, " v=%"PRIu64, tmp); } else if (type == PM_TYPE_FLOAT) { float tmp; + if (!vp->pval) goto dunno; memcpy((void *)&tmp, (void *)vp->pval->vbuf, sizeof(tmp)); fprintf(f, " v=%f", (double)tmp); } else if (type == PM_TYPE_DOUBLE) { double tmp; + if (!vp->pval) goto dunno; memcpy((void *)&tmp, (void *)vp->pval->vbuf, sizeof(tmp)); fprintf(f, " v=%f", tmp); } else +dunno: fprintf(f, "v=??? (lval=%d)", vp->lval); } #endif @@ -321,8 +370,10 @@ update_bounds(__pmContext *ctxp, double t_req, pmResult *logrp, int do_mark, int icp->t_prior = t_this; icp->m_prior = 1; if (icp->metric->valfmt != PM_VAL_INSITU) { - if (icp->v_prior.pval != NULL) + if (icp->v_prior.pval != NULL) { +fprintf(stderr, "-- __pmUnpinPDUBuf interp::update_bounds(1): %p\n", icp->v_prior.pval); __pmUnpinPDUBuf((void *)icp->v_prior.pval); + } icp->v_prior.pval = NULL; } #ifdef PCP_DEBUG @@ -344,8 +395,10 @@ update_bounds(__pmContext *ctxp, double t_req, pmResult *logrp, int do_mark, int icp->t_next = t_this; icp->m_next = 1; if (icp->metric->valfmt != PM_VAL_INSITU) { - if (icp->v_next.pval != NULL) + if (icp->v_next.pval != NULL) { +fprintf(stderr, "-- __pmUnpinPDUBuf interp::update_bounds(2): %p\n", icp->v_next.pval); __pmUnpinPDUBuf((void *)icp->v_next.pval); + } icp->v_next.pval = NULL; } #ifdef PCP_DEBUG @@ -399,8 +452,10 @@ update_bounds(__pmContext *ctxp, double t_req, pmResult *logrp, int do_mark, int if (pcp->valfmt == PM_VAL_INSITU) icp->v_next.lval = icp->v_prior.lval; else { - if (icp->v_next.pval != NULL) + if (icp->v_next.pval != NULL) { +fprintf(stderr, "-- __pmUnpinPDUBuf interp::update_bounds(3): %p\n", icp->v_next.pval); __pmUnpinPDUBuf((void *)icp->v_next.pval); + } icp->v_next.pval = icp->v_prior.pval; } } @@ -409,10 +464,13 @@ update_bounds(__pmContext *ctxp, double t_req, pmResult *logrp, int do_mark, int if (pcp->valfmt == PM_VAL_INSITU) icp->v_prior.lval = logrp->vset[k]->vlist[i].value.lval; else { - if (icp->v_prior.pval != NULL) + if (icp->v_prior.pval != NULL) { +fprintf(stderr, "-- __pmUnpinPDUBuf interp::update_bounds(4): %p\n", icp->v_prior.pval); __pmUnpinPDUBuf((void *)icp->v_prior.pval); + } icp->v_prior.pval = logrp->vset[k]->vlist[i].value.pval; __pmPinPDUBuf((void *)icp->v_prior.pval); +fprintf(stderr, "++ __pmPinPDUBuf interp::update_bounds(1): %p\n", icp->v_prior.pval); } if (icp->search && done_prior != NULL) { /* one we were looking for */ @@ -435,8 +493,10 @@ update_bounds(__pmContext *ctxp, double t_req, pmResult *logrp, int do_mark, int if (pcp->valfmt == PM_VAL_INSITU) icp->v_prior.lval = icp->v_next.lval; else { - if (icp->v_prior.pval != NULL) + if (icp->v_prior.pval != NULL) { +fprintf(stderr, "-- __pmUnpinPDUBuf interp::update_bounds(5): %p\n", icp->v_prior.pval); __pmUnpinPDUBuf((void *)icp->v_prior.pval); + } icp->v_prior.pval = icp->v_next.pval; } } @@ -445,10 +505,13 @@ update_bounds(__pmContext *ctxp, double t_req, pmResult *logrp, int do_mark, int if (pcp->valfmt == PM_VAL_INSITU) icp->v_next.lval = logrp->vset[k]->vlist[i].value.lval; else { - if (icp->v_next.pval != NULL) + if (icp->v_next.pval != NULL) { +fprintf(stderr, "-- __pmUnpinPDUBuf interp::update_bounds(6): %p\n", icp->v_next.pval); __pmUnpinPDUBuf((void *)icp->v_next.pval); + } icp->v_next.pval = logrp->vset[k]->vlist[i].value.pval; __pmPinPDUBuf((void *)icp->v_next.pval); +fprintf(stderr, "++ __pmPinPDUBuf interp::update_bounds(2): %p\n", icp->v_next.pval); } if (icp->search && done_next != NULL) { /* one we were looking for */ @@ -623,6 +686,7 @@ __pmLogFetchInterp(__pmContext *ctxp, int numpmid, pmID pmidlist[], pmResult **r if ((rp = (pmResult *)malloc(sizeof(pmResult) + (numpmid - 1) * sizeof(pmValueSet *))) == NULL) return -oserror(); + fprintf(stderr, "fetch_interp malloc(%p)\n", rp); rp->timestamp.tv_sec = ctxp->c_origin.tv_sec; rp->timestamp.tv_usec = ctxp->c_origin.tv_usec; @@ -660,6 +724,7 @@ __pmLogFetchInterp(__pmContext *ctxp, int numpmid, pmID pmidlist[], pmResult **r sts = __pmHashAdd((int)pmidlist[j], (void *)pcp, hcp); if (sts < 0) { rp->numpmid = j; + fprintf(stderr, "hash add fail freeing %p\n", rp); pmFreeResult(rp); free(pcp); return sts; @@ -1226,6 +1291,7 @@ retry_forw: sts = -oserror(); goto bad_alloc; } +fprintf(stderr, "malloc(%p) - __pmLogFetchInterp[FLOAT]\n", vp); vp->vlen = need; vp->vtype = PM_TYPE_FLOAT; rp->vset[j]->valfmt = PM_VAL_DPTR; @@ -1285,6 +1351,7 @@ retry_forw: sts = -oserror(); goto bad_alloc; } +fprintf(stderr, "malloc(%p) rp=%p[%d] - __pmLogFetchInterp[64]\n", vp, rp, j); vp->vlen = need; if (pcp->desc.type == PM_TYPE_64) vp->vtype = PM_TYPE_64; @@ -1428,6 +1495,7 @@ retry_forw: sts = -oserror(); goto bad_alloc; } +fprintf(stderr, "malloc(%p) rp=%p[%d] - __pmLogFetchInterp[DOUBLE]\n", vp, rp, j); vp->vlen = need; vp->vtype = PM_TYPE_DOUBLE; rp->vset[j]->valfmt = PM_VAL_DPTR; @@ -1489,6 +1557,7 @@ retry_forw: sts = -oserror(); goto bad_alloc; } +fprintf(stderr, "malloc(%p) - __pmLogFetchInterp[AGGR]\n", vp); rp->vset[j]->valfmt = PM_VAL_DPTR; rp->vset[j]->vlist[i++].value.pval = vp; memcpy((void *)vp, icp->v_prior.pval, need); @@ -1563,21 +1632,31 @@ __pmLogResetInterp(__pmContext *ctxp) t_req = __pmTimevalSub(&ctxp->c_origin, &ctxp->c_archctl->ac_log->l_label.ill_start); +fprintf(stderr, "enter __pmLogResetInterp\n"); + for (k = 0; k < hcp->hsize; k++) { +fprintf(stderr, "__pmLogResetInterp bucket[%d]\n", k); for (hp = hcp->hash[k]; hp != NULL; hp = hp->next) { pcp = (pmidcntl_t *)hp->data; +fprintf(stderr, "__pmLogResetInterp next pmidctl in bucket[%d]: pmid=%s\n", k, pmIDStr(pcp->desc.pmid)); for (icp = pcp->first; icp != NULL; icp = icp->next) { +fprintf(stderr, "__pmLogResetInterp next instctl in pmidctl in bucket[%d]\n", k); if (icp->t_prior > t_req || icp->t_next < t_req) { icp->t_prior = icp->t_next = -1; if (pcp->valfmt != PM_VAL_INSITU) { - if (icp->v_prior.pval != NULL) - __pmUnpinPDUBuf((void *)icp->v_prior.pval); - if (icp->v_next.pval != NULL) - __pmUnpinPDUBuf((void *)icp->v_next.pval); + if (icp->v_prior.pval != NULL) { +fprintf(stderr, "-- __pmUnpinPDUBuf interp::LogReset(1): %p\n", icp->v_prior.pval); +// !!! __pmUnpinPDUBuf((void *)icp->v_prior.pval); + } + if (icp->v_next.pval != NULL) { +fprintf(stderr, "-- __pmUnpinPDUBuf interp::LogReset(2): %p\n", icp->v_next.pval); +// !!! __pmUnpinPDUBuf((void *)icp->v_next.pval); + } } icp->v_prior.pval = icp->v_next.pval = NULL; } } } } +fprintf(stderr, "return __pmLogResetInterp\n"); } diff --git a/src/libpcp/src/p_result.c b/src/libpcp/src/p_result.c index 098fe08..72e6a02 100644 --- a/src/libpcp/src/p_result.c +++ b/src/libpcp/src/p_result.c @@ -489,6 +489,7 @@ __pmDecodeResult(__pmPDU *pdubuf, pmResult **result) * for the 64-bit pointer case the new buffer (newbuf) also pinned - * if numpmid != 0 see the thread-safe comments above */ +fprintf(stderr, "__pmDecodeResult result=%p pdubuf=%p\n", pr, pdubuf); *result = pr; return 0; diff --git a/src/libpcp/src/pdubuf.c b/src/libpcp/src/pdubuf.c index bb7ab26..bf58563 100644 --- a/src/libpcp/src/pdubuf.c +++ b/src/libpcp/src/pdubuf.c @@ -40,7 +40,7 @@ static bufctl_t *buf_pin; static bufctl_t *buf_pin_tail; #ifdef PCP_DEBUG -static void +void pdubufdump(void) { bufctl_t *pcp; diff --git a/src/libpcp/src/stuffvalue.c b/src/libpcp/src/stuffvalue.c index 45fcf6b..d45fb5f 100644 --- a/src/libpcp/src/stuffvalue.c +++ b/src/libpcp/src/stuffvalue.c @@ -76,6 +76,7 @@ __pmStuffValue(const pmAtomValue *avp, pmValue *vp, int type) (need < sizeof(pmValueBlock)) ? sizeof(pmValueBlock) : need); if (vp->value.pval == NULL) return -oserror(); +fprintf(stderr, "malloc(%p) - __pmStuffValue\n", vp->value.pval); vp->value.pval->vlen = (int)need; vp->value.pval->vtype = type; memcpy((void *)vp->value.pval->vbuf, (void *)src, body);