1016686 - Instance where text isn't copied to clipboard despite seeing the text copied toast; clipboard is empty

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: Text Selection, defect)

Description

[Saurabh Anand [:sawrubh]]

STR :

Visit http://nhnt11.com/ on the latest Fennec. Select the name on the website 'Nihanth Subramanya', click on Copy, it says Text copied to clipboard, open another app, try to paste the name, previously copied clipboard content is pasted

Expected :

The text I copied (and which Fennec notifies me about) should be pasted instead

Comment 1

[Aaron Train [:aaronmt]]

I wasn't able to reproduce this on Nightly (05/28).

Comment 2

[Saurabh Anand [:sawrubh]]

Can you try this again, I was just able to reproduce this intermittently on today's Nightly. Do you think an adb logcat output would help? I am very certain this bug exists.

Comment 3

[Aaron Train [:aaronmt]]

Ok.

I can reproduce this after trying a third time here. I dragged the selection handle over the name, tapped Copy on the action-bar, got the toast. My clipboard is empty.

Comment 4

[Mark Capella [:capella]]

I can't repro on my tablet ... I get some weird delays in code on my phone, but it's on cyanogenMod11 so (meh) ... what types of devices/OS ver are you seeing this on?

Comment 5

[Mark Capella [:capella]]

Also, do you have firefox sync *on* on the device involved?

Comment 6

[Mark Capella [:capella]]

Attachment: bug1016686.diff

There appears to be some sort of weird blocking going on here ...

When I added some logging (see attached patch) to inspect the value of the clipboard after we do our copy of text (to check for success) I discovered what appears to be a *lengthy* delay involving Sync.

Check the logcat (I'm about to add) for timings starting and stopping around this block:
    Cu.reportError("XYZZY " + Date.now() + " _getClipboardString() Before blocking <<<<<<<");
    Services.clipboard.getData(trans, Services.clipboard.kGlobalClipboard);
    Cu.reportError("XYZZY " + Date.now() + " _getClipboardString() After blocking  <<<<<<<");

tl;dr:
   E/GeckoConsole(28044): [JavaScript Error: "XYZZY 1405582303518 _getClipboardString() Before blocking <<<<<<<" {file: "chrome://browser/content/SelectionHandler.js" line: 940}]
   ... Sync stuff ...
   E/GeckoConsole(28044): [JavaScript Error: "XYZZY 1405582354315 _getClipboardString() After blocking  <<<<<<<" {file: "chrome://browser/content/SelectionHandler.js" line: 942}]
   E/GeckoConsole(28044): [JavaScript Error: "XYZZY 1405582354316 copySelection() Final clipboard value:  [Subramanya] ..." {file: "chrome://browser/content/SelectionHandler.js" line: 931}]

Comment 7

[Mark Capella [:capella]]

Attachment: logcatFull.txt

Comment 8

[Mark Capella [:capella]]

Adding nalexander ... maybe I don't see this right ???

Comment 9

[Mark Capella [:capella]]

forgot to needinfo it

Comment 10

[Nick Alexander :nalexander [he/him]]

(In reply to Mark Capella [:capella] from comment #9)
> forgot to needinfo it

So, I see the Sync starting, but I think it's a red herring.  I see nothing else Sync related; it would all be under the FxAccounts log tag.

It sure looks like the call to read the drawable, that eventually uses GeckoJarReader to fish a resource from omni.ja, needs to URL encode those { and } characters.  But it's not clear that's causing your selection issue, 'cuz the traceback is Favicon related, not Selection related.

Comment 11

[Mark Capella [:capella]]

So what I see is actually related to this issue. The updating of the Clipboard is being done by posting a background thread that's hanging (Clipboard.java), yet indicating to the user that the action is complete (via toast) in Selectionhandler.js.

http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/util/Clipboard.java?rev=235817065969&mark=60-60,#59

Comment 12

[Mark Capella [:capella]]

We're waiting for Favicon to do work here: http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/favicons/LoadFaviconTask.java?mark=413-418#413

ckitching has offered to provide a patch...

Comment 13

[Mark Capella [:capella]]

ckitching: your last thought was you "suspect it's because the favicon code is blocking the background thread while it downloads." (Agreed).

I wonder if the problem may be more than waiting for a long download to complete, as-in, waiting and never receiving a response for the download request. I'm seeing delays that don't seem to resolve versus just taking too long.

Either way, you suggest that |The solution is to make favicons use a different thread pool|, and that would at least confine any thread blocking to Favicon-specific code.

Comment 14

[Mark Capella [:capella]]

cc:rnewman due to general Favicon interest

Comment 15

[Mark Capella [:capella]]

Attachment: moreDetailLogcat.txt

A little more detail of the SelectionHandler "copy to clipboard" vs "favicon load" background thread interaction

Comment 16

[Mark Capella [:capella]]

Attachment: betterFullLogcat.txt

Sorry for the spam, this log shows it a little better

Comment 17

[Richard Newman [:rnewman]]

Certainly seems like an inevitable consequence of using the background thread for any kind of long-running tasks -- tasks queued up in the meantime will be blocked.

Unfortunately, our code is broadly architected to expect background operations to be serialized, so that wouldn't be a trivial change.

Comment 18

[Mark Capella [:capella]]

Right, but ouch. Basically, purely local memory operations that should happen in milliseconds like copy/paste can backup behind unrelated network operations that can take dozens of seconds.

Comment 19

[Richard Newman [:rnewman]]

(In reply to Mark Capella [:capella] from comment #18)
> Right, but ouch. Basically, purely local memory operations that should
> happen in milliseconds like copy/paste can backup behind unrelated network
> operations that can take dozens of seconds.

Assertion: if they're consistently faster than a thread switch and runnable futzing, do them on the main thread rather than backgrounding them.

Comment 20

[Mark Capella [:capella]]

Interesting ... I'll have to research why Clipboard.java works as it does ... perhaps there's a case where it also needs to load-for-paste network resources (images? link-ref'ed text?)

Comment 21

[Chris Kitching [:ckitching]]

More generally, though, we should probably avoid blocking our one and only background thread while we wait for the network. The clipboard is surely not the only thing that'll suffer from having to wait a long time for its background thread stuff to occur.
A LoadFaviconTask can stop the background thread for an extremely long time if the favicon it's trying to load is busy timing out or suchlike. This is sort of browser-killing.

A dirty hack would be to have a new thread specially for favicon work. We'd probably not find it worthwhile to have more than one, since we almost never try and load more than one favicon from the network at a time (and when we're loading lots of favicons at once from the database, we're almost never concurrently loading one from the network).

A would be to provide a small thread pool for tasks that don't care about serialisation on the background thread. We could then use information about the device's CPU count to tune the number of threads in this pool on startup. There's a library class for doing all this otherwise-complicated Runnable management (You just tell it "Make n threads and use them to execute the Runnables I throw at you").

Refactoring existing code that relies on serialisation on the background thread would be time consuming, but I think that doing so in the particular case of favicons isn't so hard. There aren't consumers of the favicon service that care about the order of favicons getting loaded, so provided the service itself is happy to run multiple transactions concurrently everything should "just work".

The overhead of having a few extra threads seems likely to be much less than the cost of blocking all background-thread work for many seconds at a time when the network is slow...

Comment 22

[Mark Capella [:capella]]

It might be easier to change the Clipboard code (?) ... we're only dealing with text transfers, but we go to the background due to:

http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/util/Clipboard.java?rev=235817065969&mark=116-118#116

This is a new area for me, but I wonder if we can use something like in GeckoInputConnection:
http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/GeckoInputConnection.java?rev=c0ef88442945&mark=506-509#502

Comment 23

[Chris Kitching [:ckitching]]

(In reply to Mark Capella [:capella] from comment #22)
> It might be easier to change the Clipboard code (?) ... we're only dealing
> with text transfers, but we go to the background due to:
> 
> http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/util/
> Clipboard.java?rev=235817065969&mark=116-118#116
> 
> This is a new area for me, but I wonder if we can use something like in
> GeckoInputConnection:
> http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/
> GeckoInputConnection.java?rev=c0ef88442945&mark=506-509#502

That's certainly work, but spawning a new thread ain't cheap. That's a hack to fix one particular aspect of a more general problem that will come back and bite us later.

If we fix this bug by tweaking the Clipboard code, we're going to encounter it again with some other subsystem gets blocked by a slow favicon load on the background thread. See my last comment.

If we fix it by tweaking the favicon code to use its own thread(s), the problem comes back when something else that does network activity on the background thread blocks for ages. This is a situation where a two-threads-and-only-two-threads-all-of-the-time model just isn't adaquete.

Richard's right, we can't generally switch to a more complicated "lots of background threads instead of the one we currently have" model, because that'll break all the code that uses the background thread to serialise things. Going and changing all those places to not rely on that serialisation would be difficult, too, and not that useful.

But what we can do is add a small thread pool for background tasks that don't care about serialisation. These can be run in parallel on worker threads disjoint from the current background thread. Favicon loads would be a great example of something that'd benefit from this, and it'd solve your problem here as a handy side effect (in a way that prevents it from returning in the future). This wouldn't be especially complicated to do, either...

Comment 24

[Richard Newman [:rnewman]]

(In reply to Chris Kitching [:ckitching] from comment #23)

> But what we can do is add a small thread pool for background tasks...

Simpler, and something we've discussed before: have a single-threaded Executor for the favicon module. No point using Android's loopers if we're just queuing runnables, and no point using a thread pool -- and thus allowing concurrent activity -- for something we want to be low priority.

If we find later that we have other background tasks which take indeterminate amounts of time and have similar requirements, then either we can share the executor or think about pooling at that point.

An equivalent approach would be to use asynchronous HTTP fetches (e.g., HttpAsyncClient), but that will be a bigger change, and probably isn't necessary here.

Focus on the simplest solution that solves the identified problem.

This problem is low-priority, unbounded-duration tasks blocking the shared background thread. The simplest solution is to put those tasks in a different thread.

Address only favicon code, because (a) we haven't found other tasks to be a problem, and (b) doing this will involve addressing the thread interplays of each moved chunk of functionality, and I don't like manufacturing excess work if we can help it.

Comment 25

[Mark Capella [:capella]]

This wfm (though I had a lot of fun building a working Thread pool with background loopers generated by a ThreadFactory) Nice weekend exercise :-D

Comment 26

[Mark Capella [:capella]]

Attachment: bug1016686v4.diff singleThreadExecutor

Maybe something simple like this?

Comment 27

[Chris Kitching [:ckitching]]

Comment on attachment 8463172 [details] [diff] [review]
bug1016686v4.diff singleThreadExecutor

Review of attachment 8463172 [details] [diff] [review]:
-----------------------------------------------------------------

::: mobile/android/base/favicons/LoadFaviconTask.java
@@ +74,3 @@
>      }
> +
> +    public LoadFaviconTask(String pageUrl, String faviconUrl, int flags, OnFaviconLoadedListener listener, 

Trailing space.

@@ +74,5 @@
>      }
> +
> +    public LoadFaviconTask(String pageUrl, String faviconUrl, int flags, OnFaviconLoadedListener listener, 
> +                           int targetWidth, boolean onlyFromLocal) {
> +        super(null);

This is a little disturbing: When I first wrote it users of LoadFaviconTask were sometimes using different threads.
Still, it's nice it can be simplified like this now, but really weird that this feature wasn't culled from the class during the earlier refactor... :/

@@ +286,5 @@
> +            public void run() {
> +                ThreadUtils.postToFaviconExecutor(new BackgroundTaskRunnable());
> +            }
> +        });
> +    }

UiAsyncTask was designed with the assumption there'd only ever be one background thread.

We now have several, so it seems like it's time to redesign it so it can work with n background threads.

This isn't complicated: you just need to cause it to take the target thread as a parameter in some way. All you really want for the favicon work is for the like that is:

                mBackgroundThreadHandler.post(new BackgroundTaskRunnable(params));

to be something like:

                mFaviconThreadHandler.post(new BackgroundTaskRunnable(params));

So: make UiAsyncTask take the thread handler to use as an argument. My solution here would be a constructor that takes the handler as an argument (and one that doesn't that uses the current background thread handler as a default). Then you just go make LoadFaviconTasks's constructor call super(somethingSomethingFaviconThread).

What you've got here is an evil one-time hack that will need to be repeated every time we ever want to put anything on a "not the background thread background thread", leading to even more spaghetti.

::: mobile/android/base/util/ThreadUtils.java
@@ +27,5 @@
>          THROW,
>      }
>  
> +    // LoadFaviconTasks are posted to a unique thread.
> +    private static final ExecutorService faviconExecutor = Executors.newSingleThreadExecutor();

Making a thread pool of one, eh?

Why did you do it this way instead of like GeckoBackgroundThread?
Why does GeckoBackgroundThread not do it this way?

Could GeckoBackgroundThread and NiftyFaviconsThread be made to extend one class?
Could the GeckoBackgroundThread class be mostly deleted and replaced with a simple ExecutorService like this?


I don't understand why two things that do literally *the same thing* are implemented in such radically different ways.

@@ +117,5 @@
>          GeckoBackgroundThread.post(runnable);
>      }
>  
> +    public static void postToFaviconExecutor(Runnable runnable) {
> +        faviconExecutor.execute(runnable);

I'm not a huge fan of this pattern in cases where the field is final (unless there's some particularly damaging mutation you don't trust your clients not to invoke upon it)

::: mobile/android/base/util/UiAsyncTask.java
@@ +58,5 @@
>              });
>          }
>      }
>  
> +    public void execute(final Params... params) {

If I find myself needing to do this I usually take a moment to rethink my approach: it can be a sign of highly dodgy OOP.

Comment 28

[Richard Newman [:rnewman]]

Comment on attachment 8463172 [details] [diff] [review]
bug1016686v4.diff singleThreadExecutor

Review of attachment 8463172 [details] [diff] [review]:
-----------------------------------------------------------------

Clearing review; chat to Chris!

::: mobile/android/base/util/ThreadUtils.java
@@ +27,5 @@
>          THROW,
>      }
>  
> +    // LoadFaviconTasks are posted to a unique thread.
> +    private static final ExecutorService faviconExecutor = Executors.newSingleThreadExecutor();

> Why did you do it this way instead of like GeckoBackgroundThread?
> Why does GeckoBackgroundThread not do it this way?

Because we don't need a Looper here. A single-threaded Executor is basically a thread that runs Runnables, getting restarted if it ever dies. 

GeckoBackgroundThread is a Thread that manages a Handler (messages in) and a Looper (an event loop). Very Androidy.

Comment 29

[Mark Capella [:capella]]

Attachment: bug1016686v4.diff

Fixed up a couple nits and re-posting "feedback?" so we don't get forgotten ...

Comment 30

[Mark Capella [:capella]]

Attachment: bug1016686p2.diff

This fixes the socket-hang issue I was seeing. This will solve this particular bug, and help backGroundThread hangs in general.

We still might should consider the (first) attached patch as perhaps a followup performance enhancement. I've been running it locally for over a week and I don't see any issues.

Comment 31

[Richard Newman [:rnewman]]

Comment on attachment 8467129 [details] [diff] [review]
bug1016686p2.diff

Review of attachment 8467129 [details] [diff] [review]:
-----------------------------------------------------------------

::: mobile/android/base/favicons/LoadFaviconTask.java
@@ +153,5 @@
>                      // Already been redirected here - abort.
>                      return null;
>                  }
>  
> +                response.getEntity().consumeContent();

Use EntityUtils.

https://hc.apache.org/httpcomponents-core-4.3.x/httpcore/apidocs/org/apache/http/util/EntityUtils.html#consume%28org.apache.http.HttpEntity%29

In fact, use consumeQuietly.

Comment 32

[Mark Capella [:capella]]

Build failed on those earlier, they require 4.1/4.2 ... or did I just code it wrong?

Comment 33

[Richard Newman [:rnewman]]

(In reply to Mark Capella [:capella] from comment #30)

> We still might should consider the (first) attached patch as perhaps a
> followup performance enhancement. I've been running it locally for over a
> week and I don't see any issues.

Separate bug: "Background thread pool for long-running tasks"?

Comment 34

[Richard Newman [:rnewman]]

(In reply to Mark Capella [:capella] from comment #32)
> Build failed on those earlier, they require 4.1/4.2 ... or did I just code
> it wrong?

Ugh, just another reason why we ship our own Apache HttpClient in Sync.

In that case: wrap this in a try-catch in case it throws IOException.

Comment 35

[Mark Capella [:capella]]

Won't the method wrap work ok?
http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/favicons/LoadFaviconTask.java?rev=3a186598d35e&mark=118-118#117

Comment 36

[Richard Newman [:rnewman]]

(In reply to Mark Capella [:capella] from comment #35)
> Won't the method wrap work ok?
> http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/favicons/
> LoadFaviconTask.java?rev=3a186598d35e&mark=118-118#117

No, we want everything to continue as it did before if we fail to consume the entity for some reason.

Oh, and we should probably always consume the entity here, so we'll need something more elaborate, such as (untested):

            // Was the response a failure?
            int status = response.getStatusLine().getStatusCode();

            // Handle HTTP status codes requesting a redirect.
            if (status >= 300 && status < 400) {
                Header header = response.getFirstHeader("Location");

                try {
                    // Handle mad webservers.
                    if (header == null) {
                        return null;
                    }

                    String newURI = header.getValue();
                    if (newURI == null || newURI.equals(faviconURI.toString())) {
                        return null;
                    }

                    if (visited.contains(newURI)) {
                        // Already been redirected here - abort.
                        return null;
                    }

                    visited.add(newURI);
                } finally {
                    try {
                        response.getEntity().consume();
                    } catch (Exception e) {
                        // Doesn't matter.
                    }
                }

                return tryDownloadRecurse(new URI(newURI), visited);
            }

            if (status >= 400) {
                try {
                    response.getEntity().consume();
                } catch (Exception e) {
                    // Doesn't matter.
                }
                return null;
            }

Comment 37

[Mark Capella [:capella]]

Attachment: bug1016686p2.diff

Ok, so instead of dropping out on the first IOException, we might still recurse forward so to speak ... good thought ... (uglier code) ...

This tests out ... and I believe is what you want ...

Comment 38

[Mark Capella [:capella]]

Attachment: bug1016686p2.diff

Sorry for the bugspam ... I decided your code was tighter ...

Comment 39

[Richard Newman [:rnewman]]

Comment on attachment 8467522 [details] [diff] [review]
bug1016686p2.diff

Review of attachment 8467522 [details] [diff] [review]:
-----------------------------------------------------------------

::: mobile/android/base/favicons/LoadFaviconTask.java
@@ +139,5 @@
>              if (status >= 300 && status < 400) {
>                  Header header = response.getFirstHeader("Location");
>  
>                  // Handle mad webservers.
> +                String newURI = null;

final String newURI;

The compiler should be able to determine that it's always assigned before use.

Comment 40

[Mark Capella [:capella]]

Push to try: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=7e561c34266a

Comment 41

[Mark Capella [:capella]]

On in we go: https://hg.mozilla.org/integration/fx-team/rev/7083568be0d5

Comment 42

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/7083568be0d5