There seems to be a memory leak with the clock format command. I've tested this in freewrap 6.74 on Windows and tclsh 8.6 on Linux with the same result.

Using this code:

for { set i 0 } { $i < 1000 } { incr i } { clock format 0 -format [expr rand()] }

I see an increase in memory of about ~2 MB. Increasing the limit from 1,000 to 10,000 yields a memory increase of ~20 MB, so it seems linear at about 2 kB leaked per iteration. Same for 100,0000, with ~200 MB increase.

The reason I discovered this is I was trying to extend "clock format" to work with milli- and microseconds, so I was doing something like this:

clock format [clock microseconds] -format {%H:%M:%S.%us}

clock format <seconds from above> -format {%H:%M:%S.123456}

which is how I ended up asking clock format to do a bunch of different formats in rapid succession.

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

John Jester <kuulgryphun@gmail.com> wrote:

There seems to be a memory leak with the clock format command. I've
tested this in freewrap 6.74 on Windows and tclsh 8.6 on Linux with
the same result.

Using this code:

for { set i 0 } { $i < 1000 } { incr i } { clock format 0 -format
[expr rand()] }

Leaks in 8.6.12 (64bit) on Linux. This results in an ever growing
process size shown in top:

while true { clock format 0 -format [expr rand()] }

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

John Jester <kuulgryphun@gmail.com> writes:

There seems to be a memory leak with the clock format command. I've
tested this in freewrap 6.74 on Windows and tclsh 8.6 on Linux with
the same result.

Using this code:

for { set i 0 } { $i < 1000 } { incr i } { clock format 0 -format [expr rand()] }

I see an increase in memory of about ~2 MB. Increasing the limit from
1,000 to 10,000 yields a memory increase of ~20 MB, so it seems linear
at about 2 kB leaked per iteration. Same for 100,0000, with ~200 MB
increase.

From what I see this is not lost memory in the sense of a true memory
link - true here means the application has allocated memory but lost any reference to that. Valgrind doesn't show anything new.

But yes, this is a way to make a Tcl process go out of any bound with
respect to maximum resident memory size.

It's the always changed -format option, which makes this. See this
script:

proc doit {nr} {
for { set i 0 } { $i < $nr } { incr i } {
clock format 0 -format $i
}
}
doit $argv

Called with the arugments 1000, 10000, 20000 etc shows an alway linar
growing maximum resident set size of the process during its lifetime.

This script

proc doit {nr} {
for { set i 0 } { $i < $nr } { incr i } {
clock format $i -format 0
}
}
doit $argv

called with the arugments 1000, 10000, 20000 etc have all the same (low) maximum resident set size of the process during its lifetime (as
expected). And run more than a magnitude faster as above.

There's some caching of processing of the -format specification in
place, or something like this.

The assumption (and probably not an immediately unreasonable) here seems
to be that you have only at max a few handful different formats but you
use any of this formats potentially again and again for different
values. And that should be fast. Think: Timestamp in an ever growing log
file.

Or so it looks at least from outside. I haven't looked so far on the implementation.

rolf

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

Thank you both for confirming the issue!

The reason I'm dealing with this is I'm trying to make a "clock format" that works with milli- or microseconds. Does anyone have a recommendation for a better way to do this?

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

On 18/05/2023 11:36, Andreas Leitgeb wrote:

John Jester <kuulgryphun@gmail.com> wrote:

The reason I'm dealing with this is I'm trying to make a
"clock format" that works with milli- or microseconds.
Does anyone have a recommendation for a better way to do this?

My suggestion: replace the %uS by a fixed string unlikely to
ever occur in a clock format result..., e.g. by %%uS, and then
use string map on the result (of the internal call) to replace
the %uS by the microseconds.

If you can accept a compromise for calling your custom clock format
then let users call it with %%uS (double percent), then your procedure
could pass the format string on to normal clock format directly, and
only needs to postprocess the result for %uS.

Passing it on directly should give a speed benefit, as clock
format seems to add stuff to the internal object of the format-
string, and by not recalculating it on each call, the cache
will accellerate future calls.

On
https://wiki.tcl-lang.org/page/Add+a+time+stamp+to+each+line+of+output
I'm using %n for milliseconds and %v for microseconds.

I guess that code could benefit from the insights gained here. In other
words, do the clock format first and mapping %n and %v later. That is
possible because the clock command leaves format groups it doesn't know
alone. The advantage of doing the mapping first was that it would still
work if those format groups would be added to the clock command in the
future.


Schelte.

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

John Jester <kuulgryphun@gmail.com> wrote:

The reason I'm dealing with this is I'm trying to make a
"clock format" that works with milli- or microseconds.
Does anyone have a recommendation for a better way to do this?

My suggestion: replace the %uS by a fixed string unlikely to
ever occur in a clock format result..., e.g. by %%uS, and then
use string map on the result (of the internal call) to replace
the %uS by the microseconds.

If you can accept a compromise for calling your custom clock format
then let users call it with %%uS (double percent), then your procedure
could pass the format string on to normal clock format directly, and
only needs to postprocess the result for %uS.

Passing it on directly should give a speed benefit, as clock
format seems to add stuff to the internal object of the format-
string, and by not recalculating it on each call, the cache
will accellerate future calls.

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

On 18/05/2023 12:08, Schelte wrote:

On
https://wiki.tcl-lang.org/page/Add+a+time+stamp+to+each+line+of+output
I'm using %n for milliseconds and %v for microseconds.

I guess that code could benefit from the insights gained here. In other words, do the clock format first and mapping %n and %v later. That is possible because the clock command leaves format groups it doesn't know alone. The advantage of doing the mapping first was that it would still
work if those format groups would be added to the clock command in the future.

Unfortunately that didn't work out because the clock code replaces %n
with \n, even though that is not documented in the manual page.

I'm going to have to pick a different letter for milliseconds, or fix it
some other way.


Schelte.

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

Schelte <nospam@wanadoo.nl> wrote:

On 18/05/2023 11:36, Andreas Leitgeb wrote:

John Jester <kuulgryphun@gmail.com> wrote:

The reason I'm dealing with this is I'm trying to make a
"clock format" that works with milli- or microseconds.
Does anyone have a recommendation for a better way to do this?

My suggestion: replace the %uS by a fixed string unlikely to
ever occur in a clock format result..., e.g. by %%uS, and then
use string map on the result (of the internal call) to replace
the %uS by the microseconds.

If you can accept a compromise for calling your custom clock format
then let users call it with %%uS (double percent), then your procedure
could pass the format string on to normal clock format directly, and
only needs to postprocess the result for %uS.

Passing it on directly should give a speed benefit, as clock
format seems to add stuff to the internal object of the format-
string, and by not recalculating it on each call, the cache
will accellerate future calls.

On
https://wiki.tcl-lang.org/page/Add+a+time+stamp+to+each+line+of+output
I'm using %n for milliseconds and %v for microseconds.

I can't seem to log in on the page... It immediately asks
me for a maintainer login. (my browser had a username and password
in its vault, so I think the uid/pw was likely correct, just not maintainer-level.

I guess that code could benefit from the insights gained here. In other words, do the clock format first and mapping %n and %v later. That is possible because the clock command leaves format groups it doesn't know alone. The advantage of doing the mapping first was that it would still
work if those format groups would be added to the clock command in the future.

On one hand, it would be a benefit, if clock format starts using the
same letter for the same thing: then the wrapper just becomes a no-op
(at merely the cost of string map not finding anything to replace).

On the other hand, there's the risk, that clock format will later choose
it for something else... then people would start getting strange stuff in
their logs.

For those feeling like gambling, the "one hand" seems attractive, for
the others, using %%v and %%n puts them on safe side - after the code
is changed to do the replacement only afterwards.

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

On Thursday, May 18, 2023 at 2:36:36 AM UTC-7, Andreas Leitgeb wrote:

My suggestion: replace the %uS by a fixed string unlikely to
ever occur in a clock format result..., e.g. by %%uS, and then
use string map on the result (of the internal call) to replace
the %uS by the microseconds.

This has worked beautifully, thank you!

I allow the user to pass %us or %ms to my wrapper, which pre-processes with a string map to replace them with %%us or %%ms, then calls real clock which reverts them back to %us and %ms (as well as doing the whole format), then the wrapper post-processes
the result with another string map to replace %us or %ms with the value for micro- or milliseconds. All with no memory leak since clock format is always passed the same format string.

Thanks all, problem solved on my end. Though Tcl still has the memory leak...

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

On 2023-05-18, Andreas Leitgeb wrote:
John Jester <kuulgryphun@gmail.com> wrote:

The reason I'm dealing with this is I'm trying to make a
"clock format" that works with milli- or microseconds.

Does anyone have a recommendation for a better way to do this?

My suggestion: replace the %uS by a fixed string unlikely to
ever occur in a clock format result..., e.g. by %%uS, and then
use string map on the result (of the internal call) to replace
the %uS by the microseconds.

FWIW, it's possible to use subst here. Consider, e. g.:

proc clock-fmt-ns { fmt ts } {
set int [ expr { int ($ts) } ]
set f [ expr { $ts - $int } ]
set ms [ format %03d [ expr { round (1e3 * $f) } ] ]
set us [ format %06d [ expr { round (1e6 * $f) } ] ]
set ns [ format %09d [ expr { round (1e9 * $f) } ] ]
subst -nocommands [ clock format $int -format $fmt ]
}

puts [ clock-fmt-ns {%Y-%m-%d %T.${ms}
%Y-%m-%d %T.${us}
%Y-%m-%d %T.${ns}} 1684417855.253717 ]
## Output:
## 2023-05-18 13:50:55.254
## 2023-05-18 13:50:55.253717
## 2023-05-18 13:50:55.253716946

(Obviously floats like the one above lack precision for
nanosecond-resolution timestamps; though, say, INTEGRAL.FRACTIONAL
strings can be used instead.)

--
FSF associate member #7257 http://am-1.org/~ivan/

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

John Jester <kuulgryphun@gmail.com> writes:

On Thursday, May 18, 2023 at 2:36:36 AM UTC-7, Andreas Leitgeb wrote:

My suggestion: replace the %uS by a fixed string unlikely to
ever occur in a clock format result..., e.g. by %%uS, and then
use string map on the result (of the internal call) to replace
the %uS by the microseconds.

This has worked beautifully, thank you!
[...]
Thanks all, problem solved on my end. Though Tcl still has the memory leak...

Fine that you have found a working solution for you problem.

As already suspected in my prior analysis this is not a memory leak in a
strong sense. It's a deliberate detail of the implementation. See this
comment:

https://core.tcl-lang.org/tcl/file?udc=1&ln=1455-1482&ci=b1fc8161f1f67f28&name=library%2Fclock.tcl

and study the proc implementation for how it is done. In short for every -format and -locale combination an own parsing procedure is created (and
such scan procedures are not deleted once installed).

This script shows this:

proc doit {nr} {
for { set i 0 } { $i < $nr } { incr i } {
clock format 0 -format $i
}
}

# Populate the ::tcl::clock namespace with a first call
clock format 0

puts "Procs in the namespace ::tcl::clock [llength [info proc ::tcl::clock::*]]"
doit 1000
puts "Procs in the namespace ::tcl::clock [llength [info proc ::tcl::clock::*]]"


Procs in the namespace ::tcl::clock 52
Procs in the namespace ::tcl::clock 1052

Now, if that should stay this way or if that could or should be
implemented in another way without that side effect or if a knob or flag
should be added for use cases like you had is another question.

rolf

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

At Thu, 18 May 2023 17:03:55 +0200 Rolf Ade <rolf@pointsman.de> wrote:

John Jester <kuulgryphun@gmail.com> writes:

On Thursday, May 18, 2023 at 2:36:36 AM UTC-7, Andreas Leitgeb wrote:

My suggestion: replace the %uS by a fixed string unlikely to
ever occur in a clock format result..., e.g. by %%uS, and then
use string map on the result (of the internal call) to replace
the %uS by the microseconds.

This has worked beautifully, thank you!
[...]
Thanks all, problem solved on my end. Though Tcl still has the memory leak...

Fine that you have found a working solution for you problem.

As already suspected in my prior analysis this is not a memory leak in a strong sense. It's a deliberate detail of the implementation. See this comment:

https://core.tcl-lang.org/tcl/file?udc=1&ln=1455-1482&ci=b1fc8161f1f67f28&name=library%2Fclock.tcl

and study the proc implementation for how it is done. In short for every -format and -locale combination an own parsing procedure is created (and
such scan procedures are not deleted once installed).

This script shows this:

proc doit {nr} {
for { set i 0 } { $i < $nr } { incr i } {
clock format 0 -format $i
}
}

# Populate the ::tcl::clock namespace with a first call
clock format 0

puts "Procs in the namespace ::tcl::clock [llength [info proc ::tcl::clock::*]]"
doit 1000
puts "Procs in the namespace ::tcl::clock [llength [info proc ::tcl::clock::*]]"

Procs in the namespace ::tcl::clock 52
Procs in the namespace ::tcl::clock 1052

Now, if that should stay this way or if that could or should be
implemented in another way without that side effect or if a knob or flag should be added for use cases like you had is another question.

So I guess if one is computing a one-time format for clock format (eg [clock format ... -format $x]), then one needs to do a rename of ::tcl::clock::formatproc'$x'c to the empty string:

proc clockformatonetime {time fmt} {
set result [clock format $time -format $fmt]
rename ::tcl::clock::formatproc'$fmt'c {}
return $result
}

This should free up the space (or really recycle it).

Yep that works:

% proc doit {nr} {
for { set i 0 } { $i < $nr } { incr i } {
clock format 0 -format $i
rename ::tcl::clock::formatproc'$i'c {}
}
}
% clock format 0
Wed Dec 31 19:00:00 EST 1969
% puts "Procs in the namespace ::tcl::clock [llength [info proc ::tcl::clock::*]]"
Procs in the namespace ::tcl::clock 52
% doit 1000
% puts "Procs in the namespace ::tcl::clock [llength [info proc ::tcl::clock::*]]"
Procs in the namespace ::tcl::clock 52

rolf

--
Robert Heller -- Cell: 413-658-7953 GV: 978-633-5364
Deepwoods Software -- Custom Software Services
http://www.deepsoft.com/ -- Linux Administration Services
heller@deepsoft.com -- Webhosting Services

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

John Jester <kuulgryphun@gmail.com> wrote:

On Thursday, May 18, 2023 at 2:36:36 AM UTC-7, Andreas Leitgeb wrote:

My suggestion: replace the %uS by a fixed string unlikely to
ever occur in a clock format result..., e.g. by %%uS, and then
use string map on the result (of the internal call) to replace
the %uS by the microseconds.

This has worked beautifully, thank you!
I allow the user to pass %us or %ms to my wrapper, which pre-processes
with a string map to replace them with %%us or %%ms, then calls real
clock which reverts them back to %us and %ms (as well as doing the
whole format), then the wrapper post-processes the result with another
string map to replace %us or %ms with the value for micro- or
milliseconds.

Now that you've gone so far, do some timing tests, and judge, whether
it would be worth asking the users to use %%us or %%ms themselves
and yor procedure only doing the postprocessing. (The timing difference
will likely be *much* more than just the time for preprocessing of
the format-string, at least if lots of loglines are written)

All with no memory leak since clock format is always
passed the same format string.

Yes, that's the main advantage.

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

Robert Heller <heller@deepsoft.com> writes:

At Thu, 18 May 2023 17:03:55 +0200 Rolf Ade <rolf@pointsman.de> wrote:

As already suspected in my prior analysis this is not a memory leak in a
strong sense. It's a deliberate detail of the implementation. See this
comment:

https://core.tcl-lang.org/tcl/file?udc=1&ln=1455-1482&ci=b1fc8161f1f67f28&name=library%2Fclock.tcl
[...]
Now, if that should stay this way or if that could or should be
implemented in another way without that side effect or if a knob or flag
should be added for use cases like you had is another question.

So I guess if one is computing a one-time format for clock format (eg [clock format ... -format $x]), then one needs to do a rename of ::tcl::clock::formatproc'$x'c to the empty string:

proc clockformatonetime {time fmt} {
set result [clock format $time -format $fmt]
rename ::tcl::clock::formatproc'$fmt'c {}
return $result
}

This should free up the space (or really recycle it).

Yes, of course. You can hack your way around this implementation detail
with something like this. If you remember this thread at the occasion
you need to or should remember it. And for a general solution you need
to care about the other possible options (-base, -gmt, -locale,
-timezone) and that the scanner procs are build from the -format and
-locale combination.

Since the documentation doesn't say something about this (if I haven't
missed something) that's perhaps a tad too much detail and special case knowledge expected from Joe Programmer.

Maybe at least a -once flag with three lines of explanation in the documentation would be better (if it seems to much work / hassle /
otherwise to detrimental to reach out for another implementation which
avoids this side effect).

rolf

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

Rolf Ade <rolf@pointsman.de> wrote:

Maybe at least a -once flag ...

or "-nocache" ... But I'm not going to TIP it.

I think, the usecase is wrong-headed. "One-time" formats
are just pretty inefficient.

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

Andreas Leitgeb <avl@logic.at> writes:

Rolf Ade <rolf@pointsman.de> wrote:

Maybe at least a -once flag ...

or "-nocache" ... But I'm not going to TIP it.

Me neither. And for the same reason - I'm not convinced there is a
serious use case for it.

But still ... In general I think I prefer if Tcl would do even nonsense
thinks gracefully. And in this case it does not.

rolf

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

Am 17.05.2023 um 23:30 schrieb John Jester:

There seems to be a memory leak with the clock format command. I've tested this in freewrap 6.74 on Windows and tclsh 8.6 on Linux with the same result.

Using this code:

for { set i 0 } { $i < 1000 } { incr i } { clock format 0 -format [expr rand()] }

I see an increase in memory of about ~2 MB. Increasing the limit from 1,000 to 10,000 yields a memory increase of ~20 MB, so it seems linear at about 2 kB leaked per iteration. Same for 100,0000, with ~200 MB increase.

The reason I discovered this is I was trying to extend "clock format" to work with milli- and microseconds, so I was doing something like this:

clock format [clock microseconds] -format {%H:%M:%S.%us}

clock format <seconds from above> -format {%H:%M:%S.123456}

which is how I ended up asking clock format to do a bunch of different formats in rapid succession.

John,
if you want to look in speed-up of the clock command, magic Sergey
Brester, has made a speed-up of factor 20 implementation.

It is in the TCL branch https://core.tcl-lang.org/tcl/timeline?r=sebres-8-7-clock-speedup-cr2

It would be great, if this gem could be considered and merged one day. Unfortunately, the work of Sergey is so high level, that nobody eles understands it. There are a couple of propositions by him in core
branches, all starting with "sebres" (his login).

Take care,
Harald

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

Harald Oehlmann schrieb am Montag, 22. Mai 2023 um 09:05:49 UTC+2:

Am 17.05.2023 um 23:30 schrieb John Jester:

There seems to be a memory leak with the clock format command. I've tested this in freewrap 6.74 on Windows and tclsh 8.6 on Linux with the same result.

Using this code:

for { set i 0 } { $i < 1000 } { incr i } { clock format 0 -format [expr rand()] }

I see an increase in memory of about ~2 MB. Increasing the limit from 1,000 to 10,000 yields a memory increase of ~20 MB, so it seems linear at about 2 kB leaked per iteration. Same for 100,0000, with ~200 MB increase.

The reason I discovered this is I was trying to extend "clock format" to work with milli- and microseconds, so I was doing something like this:

clock format [clock microseconds] -format {%H:%M:%S.%us}

clock format <seconds from above> -format {%H:%M:%S.123456}

which is how I ended up asking clock format to do a bunch of different formats in rapid succession.

John,
if you want to look in speed-up of the clock command, magic Sergey
Brester, has made a speed-up of factor 20 implementation.

It is in the TCL branch https://core.tcl-lang.org/tcl/timeline?r=sebres-8-7-clock-speedup-cr2

It would be great, if this gem could be considered and merged one day. Unfortunately, the work of Sergey is so high level, that nobody eles understands it. There are a couple of propositions by him in core
branches, all starting with "sebres" (his login).

Take care,
Harald

With all the tct changes underway we should try to convince sebres to join again.

rene

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

* Rolf Ade <rolf@pointsman.de>
| John Jester <kuulgryphun@gmail.com> writes:

| > There seems to be a memory leak with the clock format command. I've
| > tested this in freewrap 6.74 on Windows and tclsh 8.6 on Linux with
| > the same result.
--<snip-snip>--

| It's the always changed -format option, which makes this.
--<snip-snip>--
| There's some caching of processing of the -format specification in
| place, or something like this.

For each format, a cached proc is created in library/clock.tcl, and
cleared only if the locale changes.

proc ::tcl::clock::Initialize {} {
variable FormatProc; # Array mapping format group
# and locale to the name of a procedure
# that renders the given format

proc ::tcl::clock::format
# Build a procedure to format the result. Cache the built procedure's name
# in the 'FormatProc' array to avoid losing its internal representation,
# which contains the name resolution.


for { set i 0 } { $i < 1000 } { incr i } {
clock format 0 -format [expr rand()] ;
puts [array size tcl::clock::FormatProc]
}
=>
1
2
3
...
1000

So this seems to be Broken As Designed...

R'

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)