\ts output + show printing strangeness

I was trying some measurements with \ts and found something strange.

: air:perf ; q

KDB+ 3.0 2012.12.04 Copyright (C) 1993-2012 Kx Systems

m32/ 2()core 4096MB hjh air.local 10.0.1.2 PLAY 2013.03.04 

q)M:1000*1000

q)\ts do[M]

19 368

q)\ts do[M]; show “qqq”;

“qqq”

21 4194656

q)\ts do[M] show “qqq”;

“qqq”

22 4194704

q)\ts do[M*1000] show “qqq”;

“qqq”

18828 4194752

q)\ts do[M*1000]

18800 512

q)

Two questions

  1. why does “qqq” get printed before \ts output?

2. 4194704 and 4194752 seem really strange. Even for M*10 loop, there was no increase in RSS or VM by 4MB. What is going on?

Some parse output that left me even more confused:

q)parse"\ts do[M]show"qqq""

`s

((do;M);(k){1 .Q.s x;};“qqq”))

q)parse"\ts do[M];show"qqq""

“;”

(s;(do;`M))

(k){1 .Q.s x;};“qqq”)

q)parse"\ts do[M]"

`s

(do;M)

q)parse"\ts do[M];"

“;”

(s;(do;`M))

::

q)

P.S. In case you’re curious as to how I stumbled upon this oddity: I was trying to do ‘show value “\ts expression-to-be-measured”’ inside a function so that I could use \ts away from the usual top-level q) prompt.

  1. The output appears first because it’s an attempted projection

do[M] show “qqq” is the same as do[M;] show “qqq” which would normally be the same as do[M;show “qqq”] except that it doesn’t seem to be possibe to use a projection with do

q)\ts do[1000;0N!1+1]

2

2

..

..

2

2

2

31 720j

q)\ts do[1000;] 0N!1+1

2

0 768j

So it’s showing 1+1 once, and looping over the identity function (::) 1000 times. This would also explain the parse results you’re seeing.

  1. The \ts values are just the memory requirement of showing “qqq” once

q)\ts show “qqq”

“qqq”

0 4194512j

plus the time/memory required to do the identity function that many times

q)\ts do[M]

15 368j

Long story short, don’t project the do function! 

use do[M;show “qqq”]

On Wed, Dec 12, 2012 at 8:25 AM, TerryLynch <tlyncher@gmail.com> wrote:

q)\ts show “qqq”

“qqq”

0 4194512j

Oops, how did I miss this? Embarrassing! Thanks for the explanation!

show’s overhead still seems a bit excessive but I guess it has a fair bit of magic inside… 

Yeah, it does seem pretty excessive. Try 0N! instead

the ‘excessive’ alloc is buffering used during file i/o.

Visible in (some) file reads/writes too

e.g.

q)\ts `:a set 0

0 4194560

q)\ts get`:a

0 4194960

q)\ts -1 “”

0 4194496