Prev: how to identify odd 1's in a binary number using regexp
Next: regexp help
From: tom.rmadilo on 5 Aug 2010 14:37
On Aug 5, 9:48 am, Ian Mac <ianmac...(a)gmail.com> wrote:
> On Aug 5, 5:09 pm, "tom.rmadilo" <tom.rmad...(a)gmail.com> wrote:
>
>
>
>
>
> > On Aug 5, 4:45 am, Ian Mac <ianmac...(a)gmail.com> wrote:
>
> > > Hello all
>
> > > What steps will reproduce the problem?
>
> > > That is a hard one, I have a procedure which I call to log the
> > > progress of a batch control job. This job has been running for many
> > > days and has called the procedure many many times (<500,000) This
> > > event has occurred 3 times during that time, it is hard to tell if it
> > > is linked to real time. The errors have occurred from 3 different
> > > start points.
>
> > > The procedure I have is quite simple
>
> > > proc log { msg } {
> > >     $::LOG_WIDGET insert end "\[[clock format [clock seconds] -format
> > > "%H:%M:%S"]\] $msg\n"
> > >     $::LOG_WIDGET see end
>
> > > }
>
> > > This is the error message which appears on the console screen.
>
> > > too many nested evaluations (infinite loop?)
> > >     while executing
> > > "dict exists $TimeZoneBad $timezone"
> > >     (procedure "GetSystemTimeZone" line 21)
> > >     invoked from within
> > > "GetSystemTimeZone"
> > >     (procedure "::tcl::clock::format" line 13)
> > >     invoked from within
> > > "clock format [clock seconds] -format "%H:%M:%S""
> > >     (procedure "log" line 2)
> > >     invoked from within
> > > "log "> about to evaluate the jobline \"$buffer\"""
> > >     (procedure "readChannel" line 24)
> > >     invoked from within
> > > "readChannel sock312"
>
> > > As you can see the log command was on this occasion invoked from my
> > > call of my procedure readChannel, on another occasions it was other of
> > > my procedures which called the log procedure.
>
> > > I would suggest there is some special case where the internal dict is
> > > nested or the like due to concurrent activity, with say an after or
> > > vwait command, although I have no proof of this, so it may be a red
> > > herring!
>
> > > I am not sure how to diagnose this internal tcl command failure
> > > further.
> > > I have looked at the body of ::tcl::clock::GetSystemTimeZone
> > > but do not understand how to proceed further.
>
> > > tcl_patchLevel 8.5.4
>
> > If $::LOG_WIDGET == "log", your proc is an infinite loop, calling
> > itself. But you could also just have exceeded the max stack depth.
>
> > However, you haven't posted enough code to say, why not post the
> > entire error message?
>
> I have posted the entire error message, as currently reported.
>
> This is the code which generates the log frame
>
> pack [TitleFrame .fMain.fMasters -text "Masters"] -fill both -expand
> no
> pack [TitleFrame .fMain.fStatus -text "Status"] -fill both -expand no
> pack [TitleFrame .fMain.fLog -text "Log"] -fill both -expand yes
>
> # -- Masters frame---------------------------
> set f [.fMain.fMasters getframe]
> set MASTER_FRAME $f
>
> # -- Log frame -------------------------------
> set f [.fMain.fLog getframe]
> pack [scrollbar $f.sbVert -command "$f.tLog yview"] -side right -fill
> y
> pack [text $f.tLog -height 8 -yscrollcommand "$f.sbVert set"] -fill
> both -expand yes -side left
>
> set LOG_WIDGET $f.tLog
>
> The procedure log is called all over the place in response to an
> incoming message from a remote task,
> so effectively it is invoked somewhere in the fileevent tree.
> However I should point out that this all worked with tcl 8.3 and I
> never saw the message.
> I believe it is something to do with the implementation of dict
> There does appear to be talk of such a bug associated with dict but I
> do not understand how to gather more evidence of the failure,
> especially as I can't create it at will.

First your code is somewhat confusing...like using foo, bar, baz as
keywords to explain some who-knows-what. "log" is usually used to name
a logging function. It might be possible that you have loaded a log
package which some conflicts with this...but who knows. My first
advice is to not use a proc named log unless it does what most procs
named log actually do: take a level and a message (or args).

But log procs sometimes add a timestamp, which would call [clock]. How
does an error in [clock] report an error using a "log" proc?

So it is possible that your code is fine, but some other error
reporting loop is suffering from an uncaught error in [clock].

I would look for any possibility that [clock] could error out and a
logging proc might enter into some infinite loop.

Still it is hard to tell if you have run into a configuration issue, a
version issue, or an installation issue, or whether it is in [clock]
or in a logging proc which uses [clock].

Anyway, I would start by renaming your "log" proc.
From: Ian Mac on 11 Aug 2010 10:53
On Aug 5, 7:37 pm, "tom.rmadilo" <tom.rmad...(a)gmail.com> wrote:
> On Aug 5, 9:48 am, Ian Mac <ianmac...(a)gmail.com> wrote:
>
>
>
> > On Aug 5, 5:09 pm, "tom.rmadilo" <tom.rmad...(a)gmail.com> wrote:
>
> > > On Aug 5, 4:45 am, Ian Mac <ianmac...(a)gmail.com> wrote:
>
> > > > Hello all
>
> > > > What steps will reproduce the problem?
>
> > > > That is a hard one, I have a procedure which I call to log the
> > > > progress of a batch control job. This job has been running for many
> > > > days and has called the procedure many many times (<500,000) This
> > > > event has occurred 3 times during that time, it is hard to tell if it
> > > > is linked to real time. The errors have occurred from 3 different
> > > > start points.
>
> > > > The procedure I have is quite simple
>
> > > > proc log { msg } {
> > > >     $::LOG_WIDGET insert end "\[[clock format [clock seconds] -format
> > > > "%H:%M:%S"]\] $msg\n"
> > > >     $::LOG_WIDGET see end
>
> > > > }
>
> > > > This is the error message which appears on the console screen.
>
> > > > too many nested evaluations (infinite loop?)
> > > >     while executing
> > > > "dict exists $TimeZoneBad $timezone"
> > > >     (procedure "GetSystemTimeZone" line 21)
> > > >     invoked from within
> > > > "GetSystemTimeZone"
> > > >     (procedure "::tcl::clock::format" line 13)
> > > >     invoked from within
> > > > "clock format [clock seconds] -format "%H:%M:%S""
> > > >     (procedure "log" line 2)
> > > >     invoked from within
> > > > "log "> about to evaluate the jobline \"$buffer\"""
> > > >     (procedure "readChannel" line 24)
> > > >     invoked from within
> > > > "readChannel sock312"
>
> > > > As you can see the log command was on this occasion invoked from my
> > > > call of my procedure readChannel, on another occasions it was other of
> > > > my procedures which called the log procedure.
>
> > > > I would suggest there is some special case where the internal dict is
> > > > nested or the like due to concurrent activity, with say an after or
> > > > vwait command, although I have no proof of this, so it may be a red
> > > > herring!
>
> > > > I am not sure how to diagnose this internal tcl command failure
> > > > further.
> > > > I have looked at the body of ::tcl::clock::GetSystemTimeZone
> > > > but do not understand how to proceed further.
>
> > > > tcl_patchLevel 8.5.4
>
> > > If $::LOG_WIDGET == "log", your proc is an infinite loop, calling
> > > itself. But you could also just have exceeded the max stack depth.
>
> > > However, you haven't posted enough code to say, why not post the
> > > entire error message?
>
> > I have posted the entire error message, as currently reported.
>
> > This is the code which generates the log frame
>
> > pack [TitleFrame .fMain.fMasters -text "Masters"] -fill both -expand
> > no
> > pack [TitleFrame .fMain.fStatus -text "Status"] -fill both -expand no
> > pack [TitleFrame .fMain.fLog -text "Log"] -fill both -expand yes
>
> > # -- Masters frame---------------------------
> > set f [.fMain.fMasters getframe]
> > set MASTER_FRAME $f
>
> > # -- Log frame -------------------------------
> > set f [.fMain.fLog getframe]
> > pack [scrollbar $f.sbVert -command "$f.tLog yview"] -side right -fill
> > y
> > pack [text $f.tLog -height 8 -yscrollcommand "$f.sbVert set"] -fill
> > both -expand yes -side left
>
> > set LOG_WIDGET $f.tLog
>
> > The procedure log is called all over the place in response to an
> > incoming message from a remote task,
> > so effectively it is invoked somewhere in the fileevent tree.
> > However I should point out that this all worked with tcl 8.3 and I
> > never saw the message.
> > I believe it is something to do with the implementation of dict
> > There does appear to be talk of such a bug associated with dict but I
> > do not understand how to gather more evidence of the failure,
> > especially as I can't create it at will.
>
> First your code is somewhat confusing...like using foo, bar, baz as
> keywords to explain some who-knows-what. "log" is usually used to name
> a logging function. It might be possible that you have loaded a log
> package which some conflicts with this...but who knows. My first
> advice is to not use a proc named log unless it does what most procs
> named log actually do: take a level and a message (or args).
>
> But log procs sometimes add a timestamp, which would call [clock]. How
> does an error in [clock] report an error using a "log" proc?
>
> So it is possible that your code is fine, but some other error
> reporting loop is suffering from an uncaught error in [clock].
>
> I would look for any possibility that [clock] could error out and a
> logging proc might enter into some infinite loop.
>
> Still it is hard to tell if you have run into a configuration issue, a
> version issue, or an installation issue, or whether it is in [clock]
> or in a logging proc which uses [clock].
>
> Anyway, I would start by renaming your "log" proc.

Well I've grabbed the straw and renamed the log procedure to mylog and
after a 26hrs its failed as reported before
it is still reporting

too many nested evaluations (infinite loop?)
while executing
"dict exists $TimeZoneBad $timezone"
(procedure "GetSystemTimeZone" line 21)
invoked from within
"GetSystemTimeZone"
(procedure "::tcl::clock::format" line 13)
invoked from within
"clock format [clock seconds] -format "%H:%M:%S""
(procedure "mylog" line 2)
invoked from within
"mylog "> about to evaluate the jobline \"$buffer\"""
(procedure "readChannel" line 24)
invoked from within
"readChannel sock312"

I am still of the opinion that it is something to do with the new dict
command, which is a TCL internal and I do not understand how to
diagnose!
From: Don Porter on 11 Aug 2010 11:48
Ian Mac wrote:
> I am still of the opinion that it is something to do with the new dict
> command, which is a TCL internal and I do not understand how to
> diagnose!

You have a nested event loop. Find that. Remove it. Problem solved.

--
| Don Porter Mathematical and Computational Sciences Division |
| donald.porter(a)nist.gov Information Technology Laboratory |
| http://math.nist.gov/~DPorter/ NIST |
|______________________________________________________________________|
From: tom.rmadilo on 11 Aug 2010 12:41
On Aug 11, 7:53 am, Ian Mac <ianmac...(a)gmail.com> wrote:
> On Aug 5, 7:37 pm, "tom.rmadilo" <tom.rmad...(a)gmail.com> wrote:
>
>
>
>
>
> > On Aug 5, 9:48 am, Ian Mac <ianmac...(a)gmail.com> wrote:
>
> > > On Aug 5, 5:09 pm, "tom.rmadilo" <tom.rmad...(a)gmail.com> wrote:
>
> > > > On Aug 5, 4:45 am, Ian Mac <ianmac...(a)gmail.com> wrote:
>
> > > > > Hello all
>
> > > > > What steps will reproduce the problem?
>
> > > > > That is a hard one, I have a procedure which I call to log the
> > > > > progress of a batch control job. This job has been running for many
> > > > > days and has called the procedure many many times (<500,000) This
> > > > > event has occurred 3 times during that time, it is hard to tell if it
> > > > > is linked to real time. The errors have occurred from 3 different
> > > > > start points.
>
> > > > > The procedure I have is quite simple
>
> > > > > proc log { msg } {
> > > > >     $::LOG_WIDGET insert end "\[[clock format [clock seconds] -format
> > > > > "%H:%M:%S"]\] $msg\n"
> > > > >     $::LOG_WIDGET see end
>
> > > > > }
>
> > > > > This is the error message which appears on the console screen.
>
> > > > > too many nested evaluations (infinite loop?)
> > > > >     while executing
> > > > > "dict exists $TimeZoneBad $timezone"
> > > > >     (procedure "GetSystemTimeZone" line 21)
> > > > >     invoked from within
> > > > > "GetSystemTimeZone"
> > > > >     (procedure "::tcl::clock::format" line 13)
> > > > >     invoked from within
> > > > > "clock format [clock seconds] -format "%H:%M:%S""
> > > > >     (procedure "log" line 2)
> > > > >     invoked from within
> > > > > "log "> about to evaluate the jobline \"$buffer\"""
> > > > >     (procedure "readChannel" line 24)
> > > > >     invoked from within
> > > > > "readChannel sock312"
>
> > > > > As you can see the log command was on this occasion invoked from my
> > > > > call of my procedure readChannel, on another occasions it was other of
> > > > > my procedures which called the log procedure.
>
> > > > > I would suggest there is some special case where the internal dict is
> > > > > nested or the like due to concurrent activity, with say an after or
> > > > > vwait command, although I have no proof of this, so it may be a red
> > > > > herring!
>
> > > > > I am not sure how to diagnose this internal tcl command failure
> > > > > further.
> > > > > I have looked at the body of ::tcl::clock::GetSystemTimeZone
> > > > > but do not understand how to proceed further.
>
> > > > > tcl_patchLevel 8.5.4
>
> > > > If $::LOG_WIDGET == "log", your proc is an infinite loop, calling
> > > > itself. But you could also just have exceeded the max stack depth.
>
> > > > However, you haven't posted enough code to say, why not post the
> > > > entire error message?
>
> > > I have posted the entire error message, as currently reported.
>
> > > This is the code which generates the log frame
>
> > > pack [TitleFrame .fMain.fMasters -text "Masters"] -fill both -expand
> > > no
> > > pack [TitleFrame .fMain.fStatus -text "Status"] -fill both -expand no
> > > pack [TitleFrame .fMain.fLog -text "Log"] -fill both -expand yes
>
> > > # -- Masters frame---------------------------
> > > set f [.fMain.fMasters getframe]
> > > set MASTER_FRAME $f
>
> > > # -- Log frame -------------------------------
> > > set f [.fMain.fLog getframe]
> > > pack [scrollbar $f.sbVert -command "$f.tLog yview"] -side right -fill
> > > y
> > > pack [text $f.tLog -height 8 -yscrollcommand "$f.sbVert set"] -fill
> > > both -expand yes -side left
>
> > > set LOG_WIDGET $f.tLog
>
> > > The procedure log is called all over the place in response to an
> > > incoming message from a remote task,
> > > so effectively it is invoked somewhere in the fileevent tree.
> > > However I should point out that this all worked with tcl 8.3 and I
> > > never saw the message.
> > > I believe it is something to do with the implementation of dict
> > > There does appear to be talk of such a bug associated with dict but I
> > > do not understand how to gather more evidence of the failure,
> > > especially as I can't create it at will.
>
> > First your code is somewhat confusing...like using foo, bar, baz as
> > keywords to explain some who-knows-what. "log" is usually used to name
> > a logging function. It might be possible that you have loaded a log
> > package which some conflicts with this...but who knows. My first
> > advice is to not use a proc named log unless it does what most procs
> > named log actually do: take a level and a message (or args).
>
> > But log procs sometimes add a timestamp, which would call [clock]. How
> > does an error in [clock] report an error using a "log" proc?
>
> > So it is possible that your code is fine, but some other error
> > reporting loop is suffering from an uncaught error in [clock].
>
> > I would look for any possibility that [clock] could error out and a
> > logging proc might enter into some infinite loop.
>
> > Still it is hard to tell if you have run into a configuration issue, a
> > version issue, or an installation issue, or whether it is in [clock]
> > or in a logging proc which uses [clock].
>
> > Anyway, I would start by renaming your "log" proc.
>
> Well I've grabbed the straw and renamed the log procedure to mylog and
> after a 26hrs its failed as reported before
> it is still reporting
>
> too many nested evaluations (infinite loop?)
>     while executing
> "dict exists $TimeZoneBad $timezone"
>     (procedure "GetSystemTimeZone" line 21)
>     invoked from within
> "GetSystemTimeZone"
>     (procedure "::tcl::clock::format" line 13)
>     invoked from within
> "clock format [clock seconds] -format "%H:%M:%S""
>     (procedure "mylog" line 2)
>     invoked from within
> "mylog "> about to evaluate the jobline \"$buffer\"""
>     (procedure "readChannel" line 24)
>     invoked from within
> "readChannel sock312"
>
> I am still of the opinion that it is something to do with the new dict
> command, which is a TCL internal and I do not understand how to
> diagnose!

Interesting that it fails at exactly the same sock iteration: sock312.
Usually sock names are reused as they go away, or they used to be
reused. But, regardless...this isn't failing on the first, second,
third....invocation of [readChannel], but somewhere around the 312th
time. I would think a failure due to [dict] would show up more
randomly.
From: Gerald W. Lester on 11 Aug 2010 13:34
Don Porter wrote:
> Ian Mac wrote:
>> I am still of the opinion that it is something to do with the new dict
>> command, which is a TCL internal and I do not understand how to
>> diagnose!
>
> You have a nested event loop. Find that. Remove it. Problem solved.

Don,

I said this back on 8/5 -- and was ignored.

My guess is it not the answer he wants to hear.


--
+------------------------------------------------------------------------+
| Gerald W. Lester, President, KNG Consulting LLC |
| Email: Gerald.Lester(a)kng-consulting.net |
+------------------------------------------------------------------------+
First  |  Prev  |  Next  |  Last
Pages: 1 2 3
Prev: how to identify odd 1's in a binary number using regexp
Next: regexp help