[IronPython] Ironclad problem, with which someone here may be able to help

Curt Hagenlocher curt at hagenlocher.org
Thu Nov 6 15:22:53 CET 2008


When you run with -X:MTA, is the object now being finalized on a thread
other than thread #2?

On Thu, Nov 6, 2008 at 7:01 AM, William Reade
<william at resolversystems.com>wrote:

> Thanks Dino -- it seems that if I use ipy with -X:MTA, I can no longer
> reproduce the problem. However, this bothers me a bit: I'm not competent to
> follow all the consequences here, but this situation seems to imply that
> Ironclad won't be usable safely from any STA thread. Is this an intended
> restriction or a bug?
>
> Incidentally, tracking down the call stacks proved to be hard work: the
> timing changed enough that I only got a single failure over dozens of runs,
> and it turned out I'd got the logging wrong, so I didn't find out anything
> useful :(.
>
>
> Dino Viehland wrote:
>
>> I would suggest getting a snap shot of the call stacks when this is
>> happening if that's possible.  I can't pin anything down but I wonder if you
>> could have an STA object or something that otherwise requires message
>> pumping.  That message pumping could happen while you're doing a
>> Monitor.Enter call.  If that was happening maybe there is some subtle CLR
>> bug or a surprise feature?  It is surprising that Monitor.Enter can go
>> re-entrant but it can...
>>
>> So it'd be interesting to get thread snapshots and see if
>>
>>
>>
>>>               EnsureGIL (443) 2
>>>               EnsureGIL (443) 1      <- omg, wtf, bbq, etc.
>>>
>>>
>>
>> Could be happening because Thread 1 experiences contention, blocks and
>> pumps messages, causing the finalizer thread (2) to run, the lock is
>> acquired and ... ?
>>
>> Only other thing I could think of is does it repro on other machines?
>>  Maybe it's a hardware bug as unlikely as that seems?
>>
>> -----Original Message-----
>> From: users-bounces at lists.ironpython.com [mailto:
>> users-bounces at lists.ironpython.com] On Behalf Of William Reade
>> Sent: Wednesday, November 05, 2008 10:01 AM
>> To: Discussion of IronPython
>> Subject: Re: [IronPython] Ironclad problem, with which someone here may be
>> able to help
>>
>> The log starts in the middle (after many lock/unlocks, some from each
>> thread); I'm running on x86; and I have no additional AppDomains.
>>
>> I don't think it would be safe for me to entirely avoid locking during
>> finalization, but I could probably cut it down to a quick lock, on a
>> separate object, to enqueue pointers for cleanup and deallocation on the
>> main thread. However, I'm reluctant to do that until I'm sure that the
>> problem is specifically related to GC, otherwise it'll just come back as
>> soon as anyone tries any serious multithreading :).
>>
>> Curt Hagenlocher wrote:
>>
>>
>>> Locking during finalization is often considered to be a bad idea.  In
>>> particular, locking without a timeout introduces the possibility that
>>> you will hang the finalization thread, preventing further objects from
>>> being finalized.  But clearly, that's not what's happening here.
>>>
>>> Other questions that probably don't matter but might be interesting to
>>> know:
>>>
>>> Can we assume that the finalization thread isn't the first place where
>>> this lock is required?  That your log starts somewhere in the middle?
>>>
>>> Is this under x86 or x64 or both?
>>>
>>> Are you creating any additional AppDomains in the process?
>>>
>>>
>>> On Wed, Nov 5, 2008 at 10:15 AM, William Reade
>>> <william at resolversystems.com <mailto:william at resolversystems.com>>
>>> wrote:
>>>
>>>    Hi Curt
>>>
>>>    I am indeed; that's how I know thread 2 is the GC thread. Is
>>>    locking during GC forbidden?
>>>
>>>    William
>>>
>>>    Curt Hagenlocher wrote:
>>>
>>>        ...or, for that matter, any __del__ methods from within Python
>>>        -- which ultimately are handled by finalization.
>>>
>>>        On Wed, Nov 5, 2008 at 9:37 AM, Curt Hagenlocher
>>>        <curt at hagenlocher.org <mailto:curt at hagenlocher.org>
>>>        <mailto:curt at hagenlocher.org <mailto:curt at hagenlocher.org>>>
>>>        wrote:
>>>
>>>           So, the obvious question for me is whether or not you're
>>>        using any
>>>           finalizers.
>>>
>>>
>>>           On Wed, Nov 5, 2008 at 5:57 AM, William Reade
>>>           <william at resolversystems.com
>>>        <mailto:william at resolversystems.com>
>>>        <mailto:william at resolversystems.com
>>>        <mailto:william at resolversystems.com>>>
>>>
>>>           wrote:
>>>
>>>               Hi all
>>>
>>>               While running the numpy tests, I've come across a situation
>>>               which, to the best of my knowledge, is simply
>>>        impossible. I'm
>>>               hoping that one of the local .NET gurus will be able to
>>>        tell
>>>               me what I'm missing, or point me somewhere I can get
>>>        more insight.
>>>
>>>               The 4 methods involved are as follows:
>>>               -----------------------
>>>                     public int GetThreadId()
>>>                     {
>>>                         return Thread.CurrentThread.ManagedThreadId;
>>>                     }
>>>
>>>                     public void WriteFlush(string info)
>>>                     {
>>>                         Console.WriteLine(info);
>>>                         Console.Out.Flush();
>>>                     }
>>>
>>>                     public void EnsureGIL()
>>>                     {
>>>                         Monitor.Enter(this.dispatcherLock);
>>>                         this.WriteFlush(String.Format(
>>>                             "EnsureGIL ({1}) {0}", this.GetThreadId(),
>>>               Builtin.id(this.dispatcherLock)));
>>>                     }
>>>
>>>                     public void ReleaseGIL()
>>>                     {
>>>                         this.WriteFlush(String.Format(
>>>                             "ReleaseGIL ({1}) {0}\n", this.GetThreadId(),
>>>               Builtin.id(this.dispatcherLock)));
>>>                         Monitor.Exit(this.dispatcherLock);
>>>                     }
>>>               -----------------------
>>>               ...and they can, and do, occasionally produce output as
>>>        follows:
>>>               -----------------------
>>>               EnsureGIL (443) 2
>>>               EnsureGIL (443) 1      <- omg, wtf, bbq, etc.
>>>               ReleaseGIL (443) 2
>>>
>>>               EnsureGIL (443) 2
>>>               ReleaseGIL (443) 1
>>>
>>>               ReleaseGIL (443) 2
>>>               -----------------------
>>>               When this happens, the process continues happily for a
>>>        short
>>>               time and then falls over in a later call to ReleaseGIL
>>>        (after
>>>               successfully calling it several times). The error is "
>>>        Object
>>>               synchronization method was called from an
>>>        unsynchronized block
>>>               of code", which I understand to mean "you can't release
>>>        this
>>>               lock because you don't hold it".
>>>
>>>               It doesn't happen very often, but I can usually
>>>        reproduce it
>>>               by running
>>>        test_multiarray.TestFromToFile.test_malformed a few
>>>               hundred times. It may be relevant to note that thread 2
>>>        is the
>>>               GC thread, and thread 1 is the main thread. I have
>>>        considered
>>>               the following possibilities:
>>>
>>>               (1) That I'm locking on the wrong object. I believe
>>>        that isn't
>>>               the case, because it's constructed only once, as a "new
>>>               Object()" (ie, a reference type), and is only subsequently
>>>               used for locking; and, because it keeps the same ipy id
>>>               throughout.
>>>
>>>               (2) That Monitor.Enter occasionally allows two different
>>>               threads to acquire the same lock. I consider this extremely
>>>               unlikely, because... well, how many multithreaded .NET apps
>>>               already exist? If Monitor really were broken, I think we'd
>>>               probably know about it by now.
>>>
>>>               (3) That calling Flush() on a SyncTextWriter (the type of
>>>               Console.Out) doesn't actually do anything, and the
>>>        output is
>>>               somehow wrongly ordered (although I can't imagine how this
>>>               could actually be: if the locking is really working,
>>>        then my
>>>               console writes are strictly sequential). I don't have
>>>        access
>>>               to the code, so I have no idea how it's implemented,
>>>        but even
>>>               if this is the case it doesn't help much with the
>>>        fundamental
>>>               problem (the synchronisation error which follows).
>>>
>>>               Apart from the above, I'm out of ideas. Can anyone suggest
>>>               what I've missed?
>>>
>>>               William
>>>               _______________________________________________
>>>               Users mailing list
>>>               Users at lists.ironpython.com
>>>        <mailto:Users at lists.ironpython.com>
>>>        <mailto:Users at lists.ironpython.com
>>>        <mailto:Users at lists.ironpython.com>>
>>>
>>>
>>>         http://lists.ironpython.com/listinfo.cgi/users-ironpython.com
>>>
>>>
>>>
>>>
>>>  ------------------------------------------------------------------------
>>>
>>>
>>>
>>>        _______________________________________________
>>>        Users mailing list
>>>        Users at lists.ironpython.com <mailto:Users at lists.ironpython.com>
>>>        http://lists.ironpython.com/listinfo.cgi/users-ironpython.com
>>>
>>>
>>>
>>>    _______________________________________________
>>>    Users mailing list
>>>    Users at lists.ironpython.com <mailto:Users at lists.ironpython.com>
>>>    http://lists.ironpython.com/listinfo.cgi/users-ironpython.com
>>>
>>>
>>> ------------------------------------------------------------------------
>>>
>>> _______________________________________________
>>> Users mailing list
>>> Users at lists.ironpython.com
>>> http://lists.ironpython.com/listinfo.cgi/users-ironpython.com
>>>
>>>
>>>
>>
>> _______________________________________________
>> Users mailing list
>> Users at lists.ironpython.com
>> http://lists.ironpython.com/listinfo.cgi/users-ironpython.com
>>
>> _______________________________________________
>> Users mailing list
>> Users at lists.ironpython.com
>> http://lists.ironpython.com/listinfo.cgi/users-ironpython.com
>>
>>
>>
>
> _______________________________________________
> Users mailing list
> Users at lists.ironpython.com
> http://lists.ironpython.com/listinfo.cgi/users-ironpython.com
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.python.org/pipermail/ironpython-users/attachments/20081106/dfdea92b/attachment.html>


More information about the Ironpython-users mailing list