flypig.co.uk

Yesterday and over the last few days we've been looking into printing. There were some errors that needed fixing in the JavaScript and now we're digging down into the C++ code. Something has changed in the neath and the print code is expecting the page to have been "cloned" when it hasn't been. That's where we've got up to. But figuring out where the cloning is supposed to happen is proving to be difficult. It's been made harder by the fact that placing breakpoints on the print code causes the debugger to crash — apparently a bug in our version of gdb — and so we don't have anything to compare against.

So my plan is to read through the print code once again. The answer must be in there somewhere.

One thing I did manage to establish using the debugger is that the nsPrintObject::InitAsRootObject() method is being called in the ESR 91 code. That could turn out to be useful because although not in the ESR 91 version, in the ESR 87 version this is where the clone appears to take place:

nsresult nsPrintObject::InitAsRootObject(nsIDocShell* aDocShell, Document* aDoc,
                                         bool aForPrintPreview) {
[...]
  mDocument = aDoc->CreateStaticClone(mDocShell);
[...]
  return NS_OK;
}

If we look at the history of the file it may give some hints about where this clone was moved to. I need to do a git blame on a line that I can see has changed between the two.

It turns out that git blame isn't too helpful because the change appears to have mostly deleted lines rather than added or changed them. Unfortunately git blame simply doesn't work very well for deleted lines. I want to use what I think of as reverse git blame, which is using git log with the -S parameter. This searchers the diff of every commit for a particular string, which will include deleted items.

Here's what comes up as the first hit:

$ git log -1 -S "CreateStaticClone" layout/printing/nsPrintObject.cpp
commit 044b3c4332134ac0c94d4916458f9930d5091c6a
Author: Emilio Cobos Álvarez <emilio@crisal.io>
Date:   Tue Aug 25 17:45:12 2020 +0000

    Bug 1636728 - Centralize printing entry points in nsGlobalWindowOuter, and
    move cloning out of nsPrintJob. r=jwatt,geckoview-reviewers,smaug,agi
    
    This centralizes our print and preview setup in nsGlobalWindowOuter so
    that we never re-clone a clone, and so that we reuse the window.open()
    codepath to create the browsing context to clone into.
    
    For window.print, for both old print dialog / silent printing and new
    print preview UI, we now create a hidden browser (as in with visibility:
    collapse, which takes no space but still gets a layout box).
    
     * In the modern UI case, this browser is swapped with the actual print
       preview clone, and the UI takes care of removing the browser.
    
     * In the print dialog / silent printing case, the printing code calls
       window.close() from nsDocumentViewer::OnDonePrinting().
    
     * We don't need to care about the old print preview UI for this case
       because it can't be open from window.print().
    
    We need to fall back to an actual window when there's no
    nsIBrowserDOMWindow around for WPT print tests and the like, which don't
    have one. That seems fine, we could special-case this code path more if
    needed but it doesn't seem worth it.
    
    Differential Revision: https://phabricator.services.mozilla.com/D87063

"Move cloning out of nsPrintJob". That sounds relevant. A lot of the changes are happening inside nsGlobalWindowOuter.cpp as the commit message suggests. And sure enough, right in there is a brand new nsGlobalWindowOuter::Print() method which now performs the cloning. It's a very long method which I'll have to read through in full, but here's the active ingredient in relation to cloning:

Nullable<WindowProxyHolder> nsGlobalWindowOuter::Print(
    nsIPrintSettings* aPrintSettings, nsIWebProgressListener* aListener,
    nsIDocShell* aDocShellToCloneInto, IsPreview aIsPreview,
    IsForWindowDotPrint aForWindowDotPrint,
    PrintPreviewResolver&& aPrintPreviewCallback, ErrorResult& aError) {
#ifdef NS_PRINTING
[...]
  if (docToPrint->IsStaticDocument() &&
      (aIsPreview == IsPreview::Yes ||
       StaticPrefs::print_tab_modal_enabled())) {
[...]
  } else {
[...]
    nsAutoScriptBlocker blockScripts;
    RefPtr<Document> clone = docToPrint->CreateStaticClone(
        cloneDocShell, cv, ps, &hasPrintCallbacks);
    if (!clone) {
      aError.ThrowNotSupportedError("Clone operation for printing failed");
      return nullptr;
    }
  }
[...]
  return WindowProxyHolder(std::move(bc));
#else
  return nullptr;
#endif  // NS_PRINTING
}

The next obvious thing we should check is whether this method is getting called at all. My guess is not, in which case it would be nice to know how we're supposed to be calling it, and maybe we can figure that out by comparing the diff in the above commit with a callstack we get from the debugger.

First things first: does it get called?

$ EMBED_CONSOLE=1 gdb sailfish-browser
(gdb) b nsGlobalWindowOuter::Print
(gdb) info break
Num Type       Disp Enb Address            What
1   breakpoint keep y   0x0000007fba96f28c in nsGlobalWindowOuter::Print
                                           (nsIPrintSettings*,
                                           nsIWebProgressListener*, nsIDocShell*,
                                           nsGlobalWindowOuter::IsPreview,
                                           nsGlobalWindowOuter::IsForWindowDotPrint,
                                           std::function<void (mozilla::dom::
                                           PrintPreviewResultInfo const&)>&&,
                                           mozilla::ErrorResult&) 
                                           at dom/base/nsGlobalWindowOuter.cpp:5258
(gdb) r
[...]
Thread 8 "GeckoWorkerThre" received signal SIGSEGV, Segmentation fault.
[Switching to LWP 1018]
nsPrintJob::FindFocusedDocument (this=this@entry=0x7e31d9f2e0,
    aDoc=aDoc@entry=0x7f89079430)
    at layout/printing/nsPrintJob.cpp:2411
2411      nsPIDOMWindowOuter* window = aDoc->GetOriginalDocument()->GetWindow();
(gdb) 

So that's a segfault before a breakpoint: the code isn't being executed. The next step then is to try to find out where it gets executed in the changes of the upstream commit.

It looks like it might happen in the BrowserChild::RecvPrint() method:

mozilla::ipc::IPCResult BrowserChild::RecvPrint(const uint64_t& aOuterWindowID,
                                                const PrintData& aPrintData);

This goes on to call nsGlobalWindowOuter::Print() like this:

    outerWindow->Print(printSettings,
                       /* aListener = */ nullptr,
                       /* aWindowToCloneInto = */ nullptr,
                       nsGlobalWindowOuter::IsPreview::No,
                       nsGlobalWindowOuter::IsForWindowDotPrint::No,
                       /* aPrintPreviewCallback = */ nullptr, rv);

This is also not getting executed and I'm wondering whether maybe it should be.

I have to be honest, I'm not really sure which direction this is going to take tomorrow. What I am fairly sure about is that spending a night asleep won't make things any less clear! So until tomorrow it is.

If you'd like to read any of my other gecko diary entries, they're all available on my Gecko-dev Diary page.