Date: Wed, 19 Oct 2011 09:17:37 +0200 From: Fabien Thomas <fabien.thomas@netasq.com> To: Bjoern A. Zeeb <bzeeb-lists@lists.zabbadoz.net> Cc: svn-src-head@freebsd.org, svn-src-all@freebsd.org, src-committers@freebsd.org Subject: Re: svn commit: r226514 - in head: lib/libpmc sys/dev/hwpmc sys/sys usr.sbin/pmcstat Message-ID: <D972EB0C-6935-4419-BBB4-8B168814A16E@netasq.com> In-Reply-To: <919B2142-241B-454B-B01E-750AB8935D3C@lists.zabbadoz.net> References: <201110181525.p9IFPhMd079276@svn.freebsd.org> <919B2142-241B-454B-B01E-750AB8935D3C@lists.zabbadoz.net>
next in thread | previous in thread | raw e-mail | index | archive | help
Badly merged my patchset... Corrected with r226526. On Oct 18, 2011, at 6:23 PM, Bjoern A. Zeeb wrote: >=20 > On 18. Oct 2011, at 15:25 , Fabien Thomas wrote: >=20 >> Author: fabient >> Date: Tue Oct 18 15:25:43 2011 >> New Revision: 226514 >> URL: http://svn.freebsd.org/changeset/base/226514 >>=20 >> Log: >> Add a flush of the current PMC log buffer before displaying the next = top. >>=20 >> As the underlying block is 4KB if the PMC throughput is low the = measurement >> will be reported on the next tick. pmcstat(8) use the modified flush = API to >> reclaim current buffer before displaying next top. >>=20 >=20 > I get this for every LINT kernel at minimum: >=20 > = /scratch/tmp/bz/head.universe/sys/modules/hwpmc/../../dev/hwpmc/hwpmc_logg= ing.c: In function 'pmclog_close': > = /scratch/tmp/bz/head.universe/sys/modules/hwpmc/../../dev/hwpmc/hwpmc_logg= ing.c:738: error: 'PMC_DEBUG_MIN_CLO' undeclared (first use in this = function) > = /scratch/tmp/bz/head.universe/sys/modules/hwpmc/../../dev/hwpmc/hwpmc_logg= ing.c:738: error: (Each undeclared identifier is reported only once > = /scratch/tmp/bz/head.universe/sys/modules/hwpmc/../../dev/hwpmc/hwpmc_logg= ing.c:738: error: for each function it appears in.) >=20 >=20 >=20 >> MFC after: 1 month >>=20 >> Modified: >> head/lib/libpmc/libpmc.c >> head/lib/libpmc/pmc.3 >> head/lib/libpmc/pmc.h >> head/lib/libpmc/pmc_configure_logfile.3 >> head/sys/dev/hwpmc/hwpmc_logging.c >> head/sys/dev/hwpmc/hwpmc_mod.c >> head/sys/sys/pmc.h >> head/sys/sys/pmclog.h >> head/usr.sbin/pmcstat/pmcstat.c >> head/usr.sbin/pmcstat/pmcstat_log.c >>=20 >> Modified: head/lib/libpmc/libpmc.c >> = =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D >> --- head/lib/libpmc/libpmc.c Tue Oct 18 14:05:18 2011 = (r226513) >> +++ head/lib/libpmc/libpmc.c Tue Oct 18 15:25:43 2011 = (r226514) >> @@ -2596,6 +2596,12 @@ pmc_flush_logfile(void) >> } >>=20 >> int >> +pmc_close_logfile(void) >> +{ >> + return (PMC_CALL(CLOSELOG,0)); >> +} >> + >> +int >> pmc_get_driver_stats(struct pmc_driverstats *ds) >> { >> struct pmc_op_getdriverstats gms; >>=20 >> Modified: head/lib/libpmc/pmc.3 >> = =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D >> --- head/lib/libpmc/pmc.3 Tue Oct 18 14:05:18 2011 = (r226513) >> +++ head/lib/libpmc/pmc.3 Tue Oct 18 15:25:43 2011 = (r226514) >> @@ -322,6 +322,10 @@ to write logged events to. >> Flush all pending log data in >> .Xr hwpmc 4 Ns Ap s >> buffers. >> +.It Fn pmc_close_logfile >> +Flush all pending log data and close >> +.Xr hwpmc 4 Ns Ap s >> +side of the stream. >> .It Fn pmc_writelog >> Append arbitrary user data to the current log file. >> .El >>=20 >> Modified: head/lib/libpmc/pmc.h >> = =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D >> --- head/lib/libpmc/pmc.h Tue Oct 18 14:05:18 2011 = (r226513) >> +++ head/lib/libpmc/pmc.h Tue Oct 18 15:25:43 2011 = (r226514) >> @@ -76,6 +76,7 @@ int pmc_attach(pmc_id_t _pmcid, pid_t _p >> int pmc_capabilities(pmc_id_t _pmc, uint32_t *_caps); >> int pmc_configure_logfile(int _fd); >> int pmc_flush_logfile(void); >> +int pmc_close_logfile(void); >> int pmc_detach(pmc_id_t _pmcid, pid_t _pid); >> int pmc_disable(int _cpu, int _pmc); >> int pmc_enable(int _cpu, int _pmc); >>=20 >> Modified: head/lib/libpmc/pmc_configure_logfile.3 >> = =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D >> --- head/lib/libpmc/pmc_configure_logfile.3 Tue Oct 18 14:05:18 2011 = (r226513) >> +++ head/lib/libpmc/pmc_configure_logfile.3 Tue Oct 18 15:25:43 2011 = (r226514) >> @@ -29,7 +29,8 @@ >> .Sh NAME >> .Nm pmc_configure_logfile , >> .Nm pmc_flush_logfile , >> -.Nm pmc_writelog >> +.Nm pmc_writelog , >> +.Nm pmc_close_logfile >> .Nd log file management >> .Sh LIBRARY >> .Lb libpmc >> @@ -41,6 +42,8 @@ >> .Fn pmc_flush_logfile void >> .Ft int >> .Fn pmc_writelog "uint32_t userdata" >> +.Ft int >> +.Fn pmc_close_logfile void >> .Sh DESCRIPTION >> The functions manage logging of >> .Xr hwpmc 4 >> @@ -72,6 +75,12 @@ Function >> will append a log entry containing the value of argument >> .Fa userdata >> to the log file. >> +.Pp >> +Function >> +.Fn pmc_close_logfile >> +will flush all pending log data and close >> +.Xr hwpmc 4 Ns Ap s >> +side of the stream. >> .Sh RETURN VALUES >> .Rv -std >> .Sh ERRORS >>=20 >> Modified: head/sys/dev/hwpmc/hwpmc_logging.c >> = =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D >> --- head/sys/dev/hwpmc/hwpmc_logging.c Tue Oct 18 14:05:18 2011 = (r226513) >> +++ head/sys/dev/hwpmc/hwpmc_logging.c Tue Oct 18 15:25:43 2011 = (r226514) >> @@ -238,7 +238,7 @@ pmclog_get_buffer(struct pmc_owner *po) >> static void >> pmclog_loop(void *arg) >> { >> - int error, last_buffer; >> + int error; >> struct pmc_owner *po; >> struct pmclog_buffer *lb; >> struct proc *p; >> @@ -253,7 +253,6 @@ pmclog_loop(void *arg) >> p =3D po->po_owner; >> td =3D curthread; >> mycred =3D td->td_ucred; >> - last_buffer =3D 0; >>=20 >> PROC_LOCK(p); >> ownercred =3D crhold(p->p_ucred); >> @@ -286,14 +285,22 @@ pmclog_loop(void *arg) >> if ((lb =3D TAILQ_FIRST(&po->po_logbuffers)) =3D=3D= NULL) { >> mtx_unlock_spin(&po->po_mtx); >>=20 >> + if (po->po_flags & PMC_PO_SHUTDOWN) { >> + mtx_unlock(&pmc_kthread_mtx); >> + /* >> + * Close the file to get = PMCLOG_EOF >> + * error in pmclog(3). >> + */ >> + fo_close(po->po_file, = curthread); >> + mtx_lock(&pmc_kthread_mtx); >> + } >> + >> (void) msleep(po, &pmc_kthread_mtx, = PWAIT, >> "pmcloop", 0); >> continue; >> } >>=20 >> TAILQ_REMOVE(&po->po_logbuffers, lb, plb_next); >> - if (po->po_flags & PMC_PO_SHUTDOWN) >> - last_buffer =3D = TAILQ_EMPTY(&po->po_logbuffers); >> mtx_unlock_spin(&po->po_mtx); >> } >>=20 >> @@ -336,14 +343,6 @@ pmclog_loop(void *arg) >> break; >> } >>=20 >> - if (last_buffer) { >> - /* >> - * Close the file to get PMCLOG_EOF error >> - * in pmclog(3). >> - */ >> - fo_close(po->po_file, curthread); >> - } >> - >> mtx_lock(&pmc_kthread_mtx); >>=20 >> /* put the used buffer back into the global pool */ >> @@ -693,6 +692,7 @@ int >> pmclog_flush(struct pmc_owner *po) >> { >> int error; >> + struct pmclog_buffer *lb; >>=20 >> PMCDBG(LOG,FLS,1, "po=3D%p", po); >>=20 >> @@ -715,11 +715,38 @@ pmclog_flush(struct pmc_owner *po) >> } >>=20 >> /* >> - * Schedule the current buffer if any. >> + * Schedule the current buffer if any and not empty. >> + */ >> + mtx_lock_spin(&po->po_mtx); >> + lb =3D po->po_curbuf; >> + if (lb && lb->plb_ptr !=3D lb->plb_base) { >> + pmclog_schedule_io(po); >> + } else >> + error =3D ENOBUFS; >> + mtx_unlock_spin(&po->po_mtx); >> + >> + error: >> + mtx_unlock(&pmc_kthread_mtx); >> + >> + return (error); >> +} >> + >> +int >> +pmclog_close(struct pmc_owner *po) >> +{ >> + >> + PMCDBG(LOG,CLO,1, "po=3D%p", po); >> + >> + mtx_lock(&pmc_kthread_mtx); >> + >> + /* >> + * Schedule the current buffer. >> */ >> mtx_lock_spin(&po->po_mtx); >> if (po->po_curbuf) >> pmclog_schedule_io(po); >> + else >> + wakeup_one(po); >> mtx_unlock_spin(&po->po_mtx); >>=20 >> /* >> @@ -728,13 +755,11 @@ pmclog_flush(struct pmc_owner *po) >> */ >> po->po_flags |=3D PMC_PO_SHUTDOWN; >>=20 >> - error: >> mtx_unlock(&pmc_kthread_mtx); >>=20 >> - return (error); >> + return (0); >> } >>=20 >> - >> void >> pmclog_process_callchain(struct pmc *pm, struct pmc_sample *ps) >> { >>=20 >> Modified: head/sys/dev/hwpmc/hwpmc_mod.c >> = =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D >> --- head/sys/dev/hwpmc/hwpmc_mod.c Tue Oct 18 14:05:18 2011 = (r226513) >> +++ head/sys/dev/hwpmc/hwpmc_mod.c Tue Oct 18 15:25:43 2011 = (r226514) >> @@ -2891,7 +2891,7 @@ pmc_syscall_handler(struct thread *td, v >> error =3D pmclog_configure_log(md, po, = cl.pm_logfd); >> } else if (po->po_flags & PMC_PO_OWNS_LOGFILE) { >> pmclog_process_closelog(po); >> - error =3D pmclog_flush(po); >> + error =3D pmclog_close(po); >> if (error =3D=3D 0) { >> LIST_FOREACH(pm, &po->po_pmcs, pm_next) >> if (pm->pm_flags & = PMC_F_NEEDS_LOGFILE && >> @@ -2907,7 +2907,6 @@ pmc_syscall_handler(struct thread *td, v >> } >> break; >>=20 >> - >> /* >> * Flush a log file. >> */ >> @@ -2928,6 +2927,25 @@ pmc_syscall_handler(struct thread *td, v >> break; >>=20 >> /* >> + * Close a log file. >> + */ >> + >> + case PMC_OP_CLOSELOG: >> + { >> + struct pmc_owner *po; >> + >> + sx_assert(&pmc_sx, SX_XLOCKED); >> + >> + if ((po =3D pmc_find_owner_descriptor(td->td_proc)) =3D=3D= NULL) { >> + error =3D EINVAL; >> + break; >> + } >> + >> + error =3D pmclog_close(po); >> + } >> + break; >> + >> + /* >> * Retrieve hardware configuration. >> */ >>=20 >>=20 >> Modified: head/sys/sys/pmc.h >> = =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D >> --- head/sys/sys/pmc.h Tue Oct 18 14:05:18 2011 = (r226513) >> +++ head/sys/sys/pmc.h Tue Oct 18 15:25:43 2011 = (r226514) >> @@ -302,7 +302,8 @@ enum pmc_event { >> __PMC_OP(PMCSETCOUNT, "Set initial count/sampling rate") = \ >> __PMC_OP(PMCSTART, "Start a PMC") = \ >> __PMC_OP(PMCSTOP, "Stop a PMC") = \ >> - __PMC_OP(WRITELOG, "Write a cookie to the log file") >> + __PMC_OP(WRITELOG, "Write a cookie to the log file") = \ >> + __PMC_OP(CLOSELOG, "Close log file") >>=20 >>=20 >> enum pmc_ops { >>=20 >> Modified: head/sys/sys/pmclog.h >> = =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D >> --- head/sys/sys/pmclog.h Tue Oct 18 14:05:18 2011 = (r226513) >> +++ head/sys/sys/pmclog.h Tue Oct 18 15:25:43 2011 = (r226514) >> @@ -243,6 +243,7 @@ int pmclog_configure_log(struct pmc_mdep >> int _logfd); >> int pmclog_deconfigure_log(struct pmc_owner *_po); >> int pmclog_flush(struct pmc_owner *_po); >> +int pmclog_close(struct pmc_owner *_po); >> void pmclog_initialize(void); >> void pmclog_process_callchain(struct pmc *_pm, struct pmc_sample = *_ps); >> void pmclog_process_closelog(struct pmc_owner *po); >>=20 >> Modified: head/usr.sbin/pmcstat/pmcstat.c >> = =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D >> --- head/usr.sbin/pmcstat/pmcstat.c Tue Oct 18 14:05:18 2011 = (r226513) >> +++ head/usr.sbin/pmcstat/pmcstat.c Tue Oct 18 15:25:43 2011 = (r226514) >> @@ -552,7 +552,7 @@ main(int argc, char **argv) >> int hcpu, option, npmc, ncpu; >> int c, check_driver_stats, current_cpu, current_sampling_count; >> int do_callchain, do_descendants, do_logproccsw, do_logprocexit; >> - int do_print; >> + int do_print, do_read; >> size_t dummy; >> int graphdepth; >> int pipefd[2], rfd; >> @@ -1328,7 +1328,7 @@ main(int argc, char **argv) >> * are killed by a SIGINT. >> */ >> runstate =3D PMCSTAT_RUNNING; >> - do_print =3D 0; >> + do_print =3D do_read =3D 0; >> do { >> if ((c =3D kevent(pmcstat_kq, NULL, 0, &kev, 1, NULL)) = <=3D 0) { >> if (errno !=3D EINTR) >> @@ -1351,8 +1351,10 @@ main(int argc, char **argv) >> (args.pa_flags & FLAG_DO_TOP)) { >> if (pmcstat_keypress_log()) >> runstate =3D = pmcstat_close_log(); >> - } else >> + } else { >> + do_read =3D 0; >> runstate =3D pmcstat_process_log(); >> + } >> break; >>=20 >> case EVFILT_SIGNAL: >> @@ -1377,9 +1379,6 @@ main(int argc, char **argv) >> /* Kill the child process if we started = it */ >> if (args.pa_flags & = FLAG_HAS_COMMANDLINE) >> pmcstat_kill_process(); >> - /* Close the pipe to self, if present. = */ >> - if (args.pa_flags & FLAG_HAS_PIPE) >> - (void) = close(pipefd[READPIPEFD]); >> runstate =3D pmcstat_close_log(); >> } else if (kev.ident =3D=3D SIGWINCH) { >> if (ioctl(fileno(args.pa_printfile), >> @@ -1394,12 +1393,15 @@ main(int argc, char **argv) >> break; >>=20 >> case EVFILT_TIMER: /* print out counting PMCs */ >> + if ((args.pa_flags & FLAG_DO_TOP) && >> + pmc_flush_logfile() !=3D ENOBUFS) >> + do_read =3D 1; >> do_print =3D 1; >> break; >>=20 >> } >>=20 >> - if (do_print) { >> + if (do_print && !do_read) { >> if ((args.pa_required & FLAG_HAS_OUTPUT_LOGFILE) = =3D=3D 0) { >> pmcstat_print_pmcs(); >> if (runstate =3D=3D PMCSTAT_FINISHED && = /* final newline */ >> @@ -1420,7 +1422,7 @@ main(int argc, char **argv) >>=20 >> /* flush any pending log entries */ >> if (args.pa_flags & (FLAG_HAS_OUTPUT_LOGFILE | FLAG_HAS_PIPE)) >> - pmc_flush_logfile(); >> + pmc_close_logfile(); >>=20 >> pmcstat_cleanup(); >>=20 >>=20 >> Modified: head/usr.sbin/pmcstat/pmcstat_log.c >> = =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D >> --- head/usr.sbin/pmcstat/pmcstat_log.c Tue Oct 18 14:05:18 2011 = (r226513) >> +++ head/usr.sbin/pmcstat/pmcstat_log.c Tue Oct 18 15:25:43 2011 = (r226514) >> @@ -1702,7 +1702,7 @@ pmcstat_close_log(void) >> * so keep the status to EXITING. >> */ >> if (args.pa_logfd !=3D -1) { >> - if (pmc_flush_logfile() < 0) >> + if (pmc_close_logfile() < 0) >> err(EX_OSERR, "ERROR: logging failed"); >> } >>=20 >=20 > --=20 > Bjoern A. Zeeb You have to have = visions! > Stop bit received. Insert coin for new address family. >=20 -- Fabien Thomas
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?D972EB0C-6935-4419-BBB4-8B168814A16E>