appscript CommandError timeout - always before 2**16 transactions, sometimes well before

[ken manheimer]

hi, all!  i'm very happy to be using appscript for a general iTunes playlist synchronizer, for copying iTunes playlists and tracks to filesystem directories.  i've hit upon what seems to be a hard and unexpected transaction limit, and worse, one which occasionally is aggravated and becomes a problematically low limit.  i'm hoping that this is an appropriate forum for appscript issues - please let me know if there's a better place to post this.

the behavior is an appscript.reference.CommandError timeout after some number of appscript transactions.  there seems to be a hard limit just before 2**16 (65536) commands (actually, at 65529 commands, but i presume the difference is accounted for by preliminary setup).  the limit is sometimes lower, even across separate python sessions, to somewhere a bit above 55,000, and in fact tends to be lower once the high limit has been hit.  occasionally the limit is as low as tens or hundreds of transactions, at which point working with appscript is untenable and i need to reboot my machine to clear it.

i only have one mac to test it on, so i haven't even confirmed it occurs for anyone else.  the machine is only a few months old, so doesn't have too much cruft, and it happens in every python i've tried on the machine.  (i've reproduced the problem with the appscript 0.20.0 installed via easy_install on the leopard system python 2.5.4, snow leopard system python 2.6.1, a 2.6 python built from scratch, etc;  the machine is a 2.66 GHz macbook pro.)

i'd be very interested to hear whether it occurs for others, and to make it easy for you to try:

def first_timeout():
    """Gratuitous itunes appscript reference cycle to elicit a timeout.

    It usually happens on some systems after just about 2**16 (= 2**2**2**2)
    interactions, and sometimes substantially before that."""
    import appscript
    import sys
    itunes = appscript.app('itunes')
    t = itunes.tracks[1]
    count = 0
    class PassedLimit(Exception): pass
    try:
        while True:
            count += 1
            if count % 1000 == 0:
                sys.stderr.write("%i\n" % count)
            if count > 65530:
                sys.stderr.write("%i\n" % count)
            elif count > 66000:
                raise PassedLimit
            x = t.name.get()
    except appscript.reference.CommandError:
        sys.stderr.write("got a CommandError at count %i\n" % count)
        raise
    except PassedLimit:
        sys.stderr.write("exceeded threshold without triggering the timeout\n")

to try it, paste the function into a mac python session (with appscript installed) and invoked 'first_timeout()'.  if you have iTunes populated with at least one track, you'll see a count emitted at every 1000 transactions, and either a hang and then "got a CommandError ..." message followed by a traceback, if the error is encountered, or else an "exceeded threshold ..." message if the limit was passed without triggering the timeout.

while i'm curious about the reason for the high hard limit, the reduced limits are actually a problem - even the 57000/58000 ceiling interferes with my script operation when running against a lot of playlists and tracks (88/9300), to the point that i've had to include kludgy measures to work around the problem.  i'd love it if the problem could be confirmed by others, and if it's widespread, whether someone familiar with appscript internals could look into repairing it.

(i'm also interested in having others try out the playlistsync script.  this is my first public release of it, and i'd be happy to have people comfortable with python and appscript use it, so if you use iTunes and have a non-apple music player you'd like to sync, please consider trying it out!)
--
ken manheimer
http://myriadicity.net


_______________________________________________
Pythonmac-SIG maillist  -  Pythonmac-SIG@...
http://mail.python.org/mailman/listinfo/pythonmac-sig

[Ned Deily]

In article
<2cd46e7f0911061558r330573d0mc5ace6fa1d7b0b77@...>,
 ken manheimer <ken.manheimer@...> wrote:
> the behavior is an appscript.reference.CommandError timeout after some
> number of appscript transactions.  there seems to be a hard limit just
> before 2**16 (65536) commands (actually, at 65529 commands, but i presume
> the difference is accounted for by preliminary setup).  the limit is
> sometimes lower, even across separate python sessions, to somewhere a bit
> above 55,000, and in fact tends to be lower once the high limit has been
> hit.  occasionally the limit is as low as tens or hundreds of transactions,
> at which point working with appscript is untenable and i need to reboot my
> machine to clear it.
[...]
> while i'm curious about the reason for the high hard limit, the reduced
> limits are actually a problem - even the 57000/58000 ceiling interferes with
> my script operation when running against a lot of playlists and tracks
> (88/9300), to the point that i've had to include kludgy measures to work
> around the problem.  i'd love it if the problem could be confirmed by
> others, and if it's widespread, whether someone familiar with appscript
> internals could look into repairing it.

A sync script sounds interesting and I plan to take a look at later.  
But a couple of quick thoughts:

Are you running on 10.6 (Snow Leopard)?  If so, perhaps you are running
into this bug:

http://db.tidbits.com/article/10643

Also, have you tried increasing the default timeout on the problematic
commands, i.e. x = t.name.get(timeout=120)?

--
 Ned Deily,
 nad@...

_______________________________________________
Pythonmac-SIG maillist  -  Pythonmac-SIG@...
http://mail.python.org/mailman/listinfo/pythonmac-sig

[ken manheimer]

On Fri, Nov 6, 2009 at 4:18 PM, Ned Deily <nad@...> wrote:

In article
<2cd46e7f0911061558r330573d0mc5ace6fa1d7b0b77@...>,

 ken manheimer <ken.manheimer@...> wrote:
> the behavior is an appscript.reference.CommandError timeout after some
> number of appscript transactions.  there seems to be a hard limit just
> before 2**16 (65536) commands (actually, at 65529 commands, but i presume
> the difference is accounted for by preliminary setup).  the limit is
> sometimes lower, even across separate python sessions, to somewhere a bit
> above 55,000, and in fact tends to be lower once the high limit has been
> hit.  occasionally the limit is as low as tens or hundreds of transactions,
> at which point working with appscript is untenable and i need to reboot my
> machine to clear it.

[...]

> while i'm curious about the reason for the high hard limit, the reduced
> limits are actually a problem - even the 57000/58000 ceiling interferes with
> my script operation when running against a lot of playlists and tracks
> (88/9300), to the point that i've had to include kludgy measures to work
> around the problem.  i'd love it if the problem could be confirmed by
> others, and if it's widespread, whether someone familiar with appscript
> internals could look into repairing it.

A sync script sounds interesting and I plan to take a look at later.
But a couple of quick thoughts:

Are you running on 10.6 (Snow Leopard)?  If so, perhaps you are running
into this bug:

http://db.tidbits.com/article/10643

i am running 10.6, and the problem accounted for there sounds suspiciously similar to what i'm experiencing, but i also experienced the apparently identical problem on 10.5 leopard, which the article says wasn't afflicted by that apple events bug.

also, while the consistent, hard limit occurring at very close to 2**16 seems likely to be explained by the return ID being limited to a short signed value, it's still odd that, once provoked, the limit varies to lower ranges - typically somewhere in the 55k range, but sometimes much lower.

Also, have you tried increasing the default timeout on the problematic
commands, i.e. x = t.name.get(timeout=120)?

i did try changing it from 120 to 240, to no avail.  that's not surprising, since there are no noticeable delays in the tens of thousands of successful transactions, until the one that gets stuck.

out of curiousity, did you try the function i included on your system?  i suspect that it's not specific to my system, but i haven't yet been able to get anyone else to test it.  (i'm including a copy of it again, below my signature.)

thanks much for your attention and suggestions.  and, i hope you'll give the sync script a try...-)

--
 Ned Deily,
 nad@...

--
ken
http://myriadicity.net

def first_timeout():
    """Gratuitous itunes appscript reference cycle to elicit a timeout.

    It usually happens on some systems after just about 2**16 (= 2**2**2**2)
    interactions, and sometimes substantially before that."""
    import appscript
    import sys
    itunes = appscript.app('itunes')
    t = itunes.tracks[1]
    count = 0
    class PassedLimit(Exception): pass
    try:
        while True:
            count += 1
            if count % 1000 == 0:
                sys.stderr.write("%i\n" % count)
            if count > 65530:
                sys.stderr.write("%i\n" % count)
            elif count > 66000:
                raise PassedLimit
            x = t.name.get()
    except appscript.reference.CommandError:
        sys.stderr.write("got a CommandError at count %i\n" % count)
        raise
    except PassedLimit:
        sys.stderr.write("exceeded threshold without triggering the timeout\n")

to try it, paste the function into a mac python session (with appscript installed) and invoke 'first_timeout()'.  if you have iTunes populated with at least one track, you'll see a count emitted at every 1000 transactions, and either a hang and then "got a CommandError ..." message followed by a traceback, if the error is encountered, or else an "exceeded threshold ..." message if the limit was passed without triggering the timeout.

_______________________________________________
Pythonmac-SIG maillist  -  Pythonmac-SIG@...
http://mail.python.org/mailman/listinfo/pythonmac-sig

[Gary Poster-3]

Hey Ken. :-)

It hung for me.

Gary

got a CommandError at count 57474
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "<stdin>", line 21, in first_timeout
  File "build/bdist.macosx-10.6-universal/egg/appscript/reference.py", line 504, in __call__
appscript.reference.CommandError: Command failed:
                OSERROR: -1712
                MESSAGE: Apple event timed out.
                COMMAND: app(u'/Applications/iTunes.app').tracks[1].name.get()


On Nov 18, 2009, at 2:54 PM, ken manheimer wrote:

> def first_timeout():
>     """Gratuitous itunes appscript reference cycle to elicit a timeout.
>
>     It usually happens on some systems after just about 2**16 (= 2**2**2**2)
>     interactions, and sometimes substantially before that."""
>     import appscript
>     import sys
>     itunes = appscript.app('itunes')
>     t = itunes.tracks[1]
>     count = 0
>     class PassedLimit(Exception): pass
>     try:
>         while True:
>             count += 1
>             if count % 1000 == 0:
>                 sys.stderr.write("%i\n" % count)
>             if count > 65530:
>                 sys.stderr.write("%i\n" % count)
>             elif count > 66000:
>                 raise PassedLimit
>             x = t.name.get()
>     except appscript.reference.CommandError:
>         sys.stderr.write("got a CommandError at count %i\n" % count)
>         raise
>     except PassedLimit:
>         sys.stderr.write("exceeded threshold without triggering the timeout\n")

_______________________________________________
Pythonmac-SIG maillist  -  Pythonmac-SIG@...
http://mail.python.org/mailman/listinfo/pythonmac-sig

[ken manheimer]

heya, gary - thanks!!  good to know.

(and, good to hear from you - hope things are going well!)

On Wed, Nov 18, 2009 at 3:08 PM, Gary Poster <gary.poster@...> wrote:

Hey Ken. :-)

It hung for me.

Gary

got a CommandError at count 57474
Traceback (most recent call last):
 File "<stdin>", line 1, in <module>
 File "<stdin>", line 21, in first_timeout
 File "build/bdist.macosx-10.6-universal/egg/appscript/reference.py", line 504, in __call__
appscript.reference.CommandError: Command failed:
               OSERROR: -1712
               MESSAGE: Apple event timed out.
               COMMAND: app(u'/Applications/iTunes.app').tracks[1].name.get()

On Nov 18, 2009, at 2:54 PM, ken manheimer wrote:

> def first_timeout():
>     """Gratuitous itunes appscript reference cycle to elicit a timeout.
>
>     It usually happens on some systems after just about 2**16 (= 2**2**2**2)
>     interactions, and sometimes substantially before that."""
>     import appscript
>     import sys
>     itunes = appscript.app('itunes')
>     t = itunes.tracks[1]
>     count = 0
>     class PassedLimit(Exception): pass
>     try:
>         while True:
>             count += 1
>             if count % 1000 == 0:
>                 sys.stderr.write("%i\n" % count)
>             if count > 65530:
>                 sys.stderr.write("%i\n" % count)
>             elif count > 66000:
>                 raise PassedLimit
>             x = t.name.get()
>     except appscript.reference.CommandError:
>         sys.stderr.write("got a CommandError at count %i\n" % count)
>         raise
>     except PassedLimit:
>         sys.stderr.write("exceeded threshold without triggering the timeout\n")

--
ken
http://myriadicity.net


_______________________________________________
Pythonmac-SIG maillist  -  Pythonmac-SIG@...
http://mail.python.org/mailman/listinfo/pythonmac-sig