Re: [HACKERS] External Sort timing debug statements

Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> writes:

> Applied with revisions: I made it use the VacRUsage code so that we
> could see both CPU and elapsed time, and moved the report points around
> a bit. The output with trace_sort enabled looks like this:
>
> NOTICE: begin tuple sort: nkeys = 1, workMem = 1024, randomAccess = t
> NOTICE: switching to external sort: CPU 0.05s/0.10u sec elapsed 0.15 sec
> NOTICE: finished writing run 1: CPU 0.14s/0.83u sec elapsed 0.99 sec
> NOTICE: finished writing run 2: CPU 0.25s/1.67u sec elapsed 1.94 sec
> NOTICE: finished writing run 3: CPU 0.37s/2.51u sec elapsed 2.90 sec
> NOTICE: finished writing run 4: CPU 0.48s/3.36u sec elapsed 3.86 sec

I'm not actually involved in this so maybe I'm completely off base here. But
wouldn't you want to know how many tuples are being sorted and how many data
are being written in these runs in order to be able to actually make sense of
these timing measurements?

Otherwise you would never know whether the results people will send you are
really comparable. And even if you're testing things in a well controlled
environments you'll never know if you missed something and you're comparing
two incomparable results.

--
greg