Bug #70106 for WWW-Mechanize-FireFox: long-running jobs seem to die in random places

Sat Aug 06 12:40:41 2011 dave [...] sr71.net - Ticket created

Subject:

long-running jobs seem to die in random places

I have a long-running script with a single Firefox::Mechanize instance. It seems to die about once an hour with an set of errors like this: (Sub)string is [function() {…}] at /usr/local/share/perl/5.10.1/MozRepl/RemoteObject.pm line 251. 'false' expected, at character offset 0 (before "function() {\x{2026}...") at /usr/local/share/perl/5.10.1/MozRepl/RemoteObject.pm line 239. (Sub)string is [list] at /usr/local/share/perl/5.10.1/MozRepl/RemoteObject.pm line 251 during global destruction. I've recorded the $mech->... operations that it's doing around this time, but I don't see a pattern. I wonder if the MozRepl connection simply times out after a certain period of inactivity perhaps.

Sun Aug 07 16:58:31 2011 dave [...] sr71.net - Correspondence added

From:

dave [...] sr71.net

Couple more data points: 1. It doesn't seem to take a long period to die. I've been able to get it to die very quickly, like 30 seconds 2. There's an odd mozrepl response that comes back that seems to mess things up. I have tcpdump files if it if you're interested, but they look like this: Show quoted text

repl>

repl.q("(function(repl,id){repl.breakLink(id)})(repl,11124);(function(repl,id){repl.breakLink(id)})(repl,11123);(function(repl,id){repl.breakLink(id)})(repl,11122);(function(repl,id){repl.breakLink(id)})(repl,11121);(function(repl,id){repl.breakLink(id)})(repl,11120);(function(repl,id){repl.breakLink(id)})(repl,11119);(function(repl,id){repl.breakLink(id)})(repl,11118);(function(repl,id){repl.breakLink(id)})(repl,11117);(function(repl,id){repl.breakLink(id)})(repl,11116);(function(repl,id){repl.breakLink(id)})(repl,11115);(function(repl,id){repl.breakLink(id)})(repl,11114);(function(repl,id){repl.breakLink(id)})(repl,11113);(function(repl,id){repl.breakLink(id)})(repl,11112);(function(repl,id){repl.breakLink(id)})(repl,11111);(function(repl,id){repl.breakLink(id)})(repl,11110);(function(repl,id){repl.breakLink(id)})(repl,11109);(function(repl,id){repl.breakLink(id)})(repl,11108);(function(repl,id){repl.breakLink(id)})(repl,11107);(function(repl,id){repl.breakLink(id)})(repl,11106);(function(repl,id){repl.breakLink(id)})(repl,11105);(function(repl,id){repl.breakLink(id)})(repl,11104);(function(repl,id){repl.breakLink(id)})(repl,11103);(function(repl,id){repl.breakLink(id)})(repl,11102);(function(repl,id){repl.breakLink(id)})(repl,11101);(function(repl,id){repl.breakLink(id)})(repl,11100);(function(repl,id){repl.breakLink(id)})(repl,11099);(function(repl,id){repl.breakLink(id)})(repl,11098);(function(repl,id){repl.breakLink(id)})(repl,11097);(function(repl,id){repl.breakLink(id)})(repl,11096);(function(repl,id){repl.breakLink(id)})(repl,11095);(function(repl,id){repl.breakLink(id)})(repl,11094);(function(repl,id){repl.breakLink(id)})(repl,11093);(function(repl,id){repl.breakLink(id)})(repl,11092);(function(repl,id){repl.breakLink(id)})(repl,11091);(function(repl,id){repl.breakLink(id)})(repl,11090);(function(repl,id){repl.breakLink(id)})(repl,11089);(function(repl,id){repl.breakLink(id)})(repl,11088);(function(repl,id){repl.breakLink(id)})(repl,11087);(function(repl,id){repl.breakLink(id)})(repl,11086);");;repl.ejs("repl.getAttr(4,\"linkedBrowser\")\n",""); ....> function() {...} Show quoted text

repl>

repl.q("(function(repl,id){repl.breakLink(id)})(repl,9264);(function(repl,id){repl.breakLink(id)})(repl,8265);(function(repl,id){repl.breakLink(id)})(repl,6852);(function(repl,id){repl.breakLink(id)})(repl,7716);(function(repl,id){repl.breakLink(id)})(repl,10043);(function(repl,id){repl.breakLink(id)})(repl,8641);(function(repl,id){repl.breakLink(id)})(repl,4320);(function(repl,id){repl.breakLink(id)})(repl,9667);(function(repl,id){repl.breakLink(id)})(repl,5119);(function(repl,id){repl.breakLink(id)})(repl,4725);(function(repl,id){repl.breakLink(id)})(repl,111);(function(repl,id){repl.breakLink(id)})(repl,525);(function(repl,id){repl.breakLink(id)})(repl,17);(function(repl,id){repl.breakLink(id)})(repl,20);");;repl.ejs("1==1",""); "" Show quoted text

repl> "{"status":"ok","result":{"result":true,"type":null}}" repl>

Sun Aug 07 17:17:11 2011 corion [...] corion.net - Correspondence added

Subject:	Re: [rt.cpan.org #70106] long-running jobs seem to die in random places
Date:	Sun, 07 Aug 2011 23:16:50 +0200
To:	bug-WWW-Mechanize-FireFox [...] rt.cpan.org
From:	Max Maischein <corion [...] corion.net>

Show quoted text

> Couple more data points: > 1. It doesn't seem to take a long period to die. I've been able to get > it to die very quickly, like 30 seconds > 2. There's an odd mozrepl response that comes back that seems to mess > things up. I have tcpdump files if it if you're interested, but they > look like this:

This is weird. It seems that there is some response that MozRepl::RemoteObject does not expect, and which makes the whole thing choke. Maybe it is somehow related to the queue size and/or pending object cleanups... Maybe the problem goes away (or changes its nature) if you run your tests with an explicit use_queue => 0 in the constructor? If so, then then this problem likely is related to the accumulation of objects that get released only later on (all these stacked "repl.breaklink()" calls. Otherwise, if you can provide me with Perl code that reproduces the problem, that would be great, but likely, if it were reproducible with externally available sites, you'd already have done so... -max Show quoted text

>

> repl>

> repl.q("(function(repl,id){repl.breakLink(id)})(repl,11124);(function(repl,id){repl.breakLink(id)})(repl,11123);(function(repl,id){repl.breakLink(id)})(repl,11122);(function(repl,id){repl.breakLink(id)})(repl,11121);(function(repl,id){repl.breakLink(id)})(repl,11120);(function(repl,id){repl.breakLink(id)})(repl,11119);(function(repl,id){repl.breakLink(id)})(repl,11118);(function(repl,id){repl.breakLink(id)})(repl,11117);(function(repl,id){repl.breakLink(id)})(repl,11116);(function(repl,id){repl.breakLink(id)})(repl,11115);(function(repl,id){repl.breakLink(id)})(repl,11114);(function(repl,id){repl.breakLink(id)})(repl,11113);(function(repl,id){repl.breakLink(id)})(repl,11112);(function(repl,id){repl.breakLink(id)})(repl,11111);(function(repl,id){repl.breakLink(id)})(repl,11110);(function(repl,id){repl.breakLink(id)})(repl,11109);(function(repl,id){repl.breakLink(id)})(repl,11108);(function(repl,id){repl.breakLink(id)})(repl,11107);(function(repl,id){repl.breakLink(id)})(rep

l,1 Show quoted text

> 1106);(function(repl,id){repl.breakLink(id)})(repl,11105);(function(repl,id){repl.breakLink(id)})(repl,11104);(function(repl,id){repl.breakLink(id)})(repl,11103);(function(repl,id){repl.breakLink(id)})(repl,11102);(function(repl,id){repl.breakLink(id)})(repl,11101);(function(repl,id){repl.breakLink(id)})(repl,11100);(function(repl,id){repl.breakLink(id)})(repl,11099);(function(repl,id){repl.breakLink(id)})(repl,11098);(function(repl,id){repl.breakLink(id)})(repl,11097);(function(repl,id){repl.breakLink(id)})(repl,11096);(function(repl,id){repl.breakLink(id)})(repl,11095);(function(repl,id){repl.breakLink(id)})(repl,11094);(function(repl,id){repl.breakLink(id)})(repl,11093);(function(repl,id){repl.breakLink(id)})(repl,11092);(function(repl,id){repl.breakLink(id)})(repl,11091);(function(repl,id){repl.breakLink(id)})(repl,11090);(function(repl,id){repl.breakLink(id)})(repl,11089);(function(repl,id){repl.breakLink(id)})(repl,11088);(function(repl,id){repl.breakLink(id)})(rep

l,11 Show quoted text

> 087);(function(repl,id){repl.breakLink(id)})(repl,11086);");;repl.ejs("repl.getAttr(4,\"linkedBrowser\")\n",""); > ....> function() {...}

> repl>

> repl.q("(function(repl,id){repl.breakLink(id)})(repl,9264);(function(repl,id){repl.breakLink(id)})(repl,8265);(function(repl,id){repl.breakLink(id)})(repl,6852);(function(repl,id){repl.breakLink(id)})(repl,7716);(function(repl,id){repl.breakLink(id)})(repl,10043);(function(repl,id){repl.breakLink(id)})(repl,8641);(function(repl,id){repl.breakLink(id)})(repl,4320);(function(repl,id){repl.breakLink(id)})(repl,9667);(function(repl,id){repl.breakLink(id)})(repl,5119);(function(repl,id){repl.breakLink(id)})(repl,4725);(function(repl,id){repl.breakLink(id)})(repl,111);(function(repl,id){repl.breakLink(id)})(repl,525);(function(repl,id){repl.breakLink(id)})(repl,17);(function(repl,id){repl.breakLink(id)})(repl,20);");;repl.ejs("1==1",""); > ""

> repl> "{"status":"ok","result":{"result":true,"type":null}}" > repl>

Sun Aug 07 17:17:13 2011 The RT System itself - Status changed from 'new' to 'open'

Sun Aug 07 17:53:48 2011 dave [...] sr71.net - Correspondence added

Subject:	Re: [rt.cpan.org #70106] long-running jobs seem to die in random places
Date:	Sun, 07 Aug 2011 14:53:37 -0700
To:	bug-WWW-Mechanize-FireFox [...] rt.cpan.org
From:	Dave Hansen <dave [...] sr71.net>

On Sun, 2011-08-07 at 17:17 -0400, Max Maischein via RT wrote: Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=70106 > >

> > Couple more data points: > > 1. It doesn't seem to take a long period to die. I've been able to get > > it to die very quickly, like 30 seconds > > 2. There's an odd mozrepl response that comes back that seems to mess > > things up. I have tcpdump files if it if you're interested, but they > > look like this:

> This is weird. It seems that there is some response that > MozRepl::RemoteObject does not expect, and which makes the whole thing > choke. Maybe it is somehow related to the queue size and/or pending > object cleanups...

I found the mozrepl code spitting this back in chrome/content/repl.js: function represent(thing) { ... case 'function': s = 'function() {…}'; Perhaps a function object is getting handed back somewhere unexpected. Show quoted text

> Maybe the problem goes away (or changes its nature) if you run your > tests with an explicit > > use_queue => 0

This certainly makes it more stable, at least in the short term. I'll run with it for a while and see what it does. Show quoted text

> in the constructor? If so, then then this problem likely is related to > the accumulation of objects that get released only later on (all these > stacked "repl.breaklink()" calls. > > Otherwise, if you can provide me with Perl code that reproduces the > problem, that would be great, but likely, if it were reproducible with > externally available sites, you'd already have done so...

Here's something fairly short and sweet. It's probably quite possible to make it even smaller, but this works for me after running for 2 or 3 minutes: http://sr71.net/~dave/kill-perl-sac-mozembed.pl.txt You might have to get an account and log in on each of the four sites for this to work for you. -- Dave

Thu Aug 11 07:09:01 2011 corion [...] corion.net - Correspondence added

Subject:	Re: [rt.cpan.org #70106] long-running jobs seem to die in random places
Date:	Thu, 11 Aug 2011 13:08:49 +0200
To:	bug-WWW-Mechanize-Firefox [...] rt.cpan.org
From:	corion [...] corion.net

I'm sorry that I haven't had any time yet to look further into this problem. Another thing that I found is that MozRepl::RemoteObject is using the "syntax" input mode for mozrepl. Changing the input mode to "line" and adding the following lines to MozRepl::RemoteObject leaves it still passing its tests. Maybe this also helps with your problems, while still using the queue for releasing Javascript objects in bulk: ... my $rn = $options{repl}->repl; #warn "<$rn>"; # Set single-line input mode $options{ repl }->execute( "$rn.setInputMode('line');\n" ); $options{ json } ||= JSON->new->allow_nonref->ascii; # We talk ASCII ... Maybe the real change is to set the input mode to multiline and to append the appropriate "end of command" marker. I hope I get to looking into this next week or after YAPC::Europe. -max

Thu Aug 11 14:26:45 2011 dave [...] sr71.net - Correspondence added

Subject:	Re: [rt.cpan.org #70106] long-running jobs seem to die in random places
Date:	Thu, 11 Aug 2011 11:26:32 -0700
To:	bug-WWW-Mechanize-FireFox [...] rt.cpan.org
From:	Dave Hansen <dave [...] sr71.net>

I do think part of the issue is what folks are seeing here: http://groups.google.com/group/mozlab/browse_thread/thread/e29da9766d31a8d?hl=en FWIW, I'm running the current version of WWW-Mechanize-Firefox out of the git tree along with Firefox 3.6.19 and the old, stable MozRepl add-on. _That_ configuration seems pretty stable. But, Firefox 5.0.1 with the MozRepl 1.1beta2 code and the same version of WWW-Mechanize-Firefox actually hangs Firefox on occasion. I actually have to kill and restart it. -- Dave

Thu Aug 11 15:41:13 2011 dave [...] sr71.net - Correspondence added

Subject:	Re: [rt.cpan.org #70106] long-running jobs seem to die in random places
Date:	Thu, 11 Aug 2011 12:41:01 -0700
To:	bug-WWW-Mechanize-FireFox [...] rt.cpan.org
From:	Dave Hansen <dave [...] sr71.net>

I know for sure now that one of the bugs: MozRepl::RemoteObject: TypeError: win.document.body is null at /home/hansendc/sac/www-mechanize-firefox/lib/WWW/Mechanize/Firefox.pm line 3258 is caused by this commit: eb499a25fbf2a7f8198ed352b2ca9f9ecdba1d76 is the first bad commit commit eb499a25fbf2a7f8198ed352b2ca9f9ecdba1d76 Author: Max Maischein <corion@corion.net> Date: Sun Jul 24 20:24:58 2011 +0200 Fix PNG screenshot for Firefox 6.0 Beta I just git-bisect'd it. The following excites it pretty well: $next = 'http://www.google.com/services/'; while (1) { printf "getting '$next'\n", $moz->get($next, synchronize => 0); my $png = $moz->content_as_png(); } I think the bug probably comes from a race during unsynchronized page loads. -- Dave

Fri Aug 12 08:50:08 2011 webmaster [...] corion.net - Correspondence added

Subject:	Re: [rt.cpan.org #70106] long-running jobs seem to die in random places
Date:	Fri, 12 Aug 2011 14:51:12 +0200
To:	bug-WWW-Mechanize-FireFox [...] rt.cpan.org
From:	Max Maischein <webmaster [...] corion.net>

Show quoted text

> I do think part of the issue is what folks are seeing here: > > http://groups.google.com/group/mozlab/browse_thread/thread/e29da9766d31a8d?hl=en

Yes, that could be. I've also thought about writing a custom interactor, but the interactors are only available after 1.0 and not in the mozrepl available from addons.mozilla.org... Show quoted text

> FWIW, I'm running the current version of WWW-Mechanize-Firefox out of > the git tree along with Firefox 3.6.19 and the old, stable MozRepl > add-on. _That_ configuration seems pretty stable.

That's basically my production setup as well, and it is pretty stable for me as well. Show quoted text

> But, Firefox 5.0.1 with the MozRepl 1.1beta2 code and the same version > of WWW-Mechanize-Firefox actually hangs Firefox on occasion. I actually > have to kill and restart it.

I think I fixed at least some of the FF 4 and FF5 lockups/crashes, but if you can provoke them, that's of interest to me ;) -max

Sat Sep 24 12:44:53 2011 corion [...] corion.net - Correspondence added

Subject:	Re: [rt.cpan.org #70106] long-running jobs seem to die in random places
Date:	Sat, 24 Sep 2011 18:44:35 +0200
To:	bug-WWW-Mechanize-FireFox [...] rt.cpan.org
From:	Max Maischein <corion [...] corion.net>

Hello Dave, I've released a new version of MozRepl::RemoteObject (v0.28), which should fix the response handling from mozrepl by using "multiline" mode instead of using the "syntax" input mode as it did before. -max Am 11.08.2011 20:26, schrieb Dave Hansen via RT: Show quoted text

> Queue: WWW-Mechanize-FireFox > Ticket<URL: https://rt.cpan.org/Ticket/Display.html?id=70106> > > I do think part of the issue is what folks are seeing here: > > http://groups.google.com/group/mozlab/browse_thread/thread/e29da9766d31a8d?hl=en > > FWIW, I'm running the current version of WWW-Mechanize-Firefox out of > the git tree along with Firefox 3.6.19 and the old, stable MozRepl > add-on. _That_ configuration seems pretty stable. > > But, Firefox 5.0.1 with the MozRepl 1.1beta2 code and the same version > of WWW-Mechanize-Firefox actually hangs Firefox on occasion. I actually > have to kill and restart it. > > -- Dave > >

Tue Mar 13 18:13:56 2012 corion [...] cpan.org - Status changed from 'open' to 'resolved'