Bug 1145916 - printing multiple copies doesn't work with e10s
Let's get started.
Got a debug build going on here.
Let's see if we can confirm this bug...
Ok, can confirm! Let's see what's up!
Ahhhhh shit - I think I know what's up.
nsCOMPtr
<
nsPrintSettingsGTK
>
settingsGTK(do_QueryInterface(settings));
NS_ENSURE_STATE(settingsGTK);
nsresult rv = nsPrintOptions :: DeserializeToPrintSettings(data, settings);
NS_ENSURE_SUCCESS(rv, rv);
// Instead of re-using the GtkPrintSettings that nsIPrintSettings is
// wrapping, we'll create a new one to deserialize to and replace it
// within nsIPrintSettings.
GtkPrintSettings * newGtkPrintSettings = gtk_print_settings_new();
for ( uint32_t i = 0 ; i < data.GTKPrintSettings().Length(); ++ i) {
CStringKeyValue pair = data.GTKPrintSettings()[i];
gtk_print_settings_set(newGtkPrintSettings,
pair.key().get(),
pair.value().get());
}
settingsGTK -> SetGtkPrintSettings(newGtkPrintSettings);
// nsPrintSettingsGTK is holding a reference to newGtkPrintSettings
g_object_unref(newGtkPrintSettings);
newGtkPrintSettings = nullptr;
NS_ENSURE_STATE(settingsGTK);
nsresult rv = nsPrintOptions :: DeserializeToPrintSettings(data, settings);
NS_ENSURE_SUCCESS(rv, rv);
// Instead of re-using the GtkPrintSettings that nsIPrintSettings is
// wrapping, we'll create a new one to deserialize to and replace it
// within nsIPrintSettings.
GtkPrintSettings * newGtkPrintSettings = gtk_print_settings_new();
for ( uint32_t i = 0 ; i < data.GTKPrintSettings().Length(); ++ i) {
CStringKeyValue pair = data.GTKPrintSettings()[i];
gtk_print_settings_set(newGtkPrintSettings,
pair.key().get(),
pair.value().get());
}
settingsGTK -> SetGtkPrintSettings(newGtkPrintSettings);
// nsPrintSettingsGTK is holding a reference to newGtkPrintSettings
g_object_unref(newGtkPrintSettings);
newGtkPrintSettings = nullptr;
return
NS_OK;
So after we call DeserializeToPrintSettings on the parent class,
we throw the settings it may have stored in the GtkPrintSettings away
, because we create a new GtkPrintSettings instead.
Wait. Waaiiiit. Doesn't that mean that we're not properly serializing
the number of copies? Like, we should be passing this massive key/value
store from the GtkPrintSettings down… and shouldn't that contain the
number of copies?
So maybe it's not in the group of things being serialized by the parent? Let's check...
No, we're sending everything correctly. What the hell?
Oh cripes, we can't even do multiple copies correctly in single process?? WTF??
Hrm. gw280 can reproduce this. Shit. :/
Ohhhhh. Damn it. PDFWriter doesn't let me do copies. Well shit.
Luckily, XCode ships with a Printer Simulator! I have to go to XCode
> Open Developer Tool > Printer Simulator to get it registered…
then I have to add the printer in the System Preferences thing under
Printers.
Ok, so now I have a new simulated printer that can hopefully do copies.
I can simulate this now, after adding the Simulated Printers as network
printers in my Ubuntu VM (needed to find my host machine IP address
relative to my VM, which was listed via ifconfig as the inet address
under vmnet1).
So here's what simulated-inkjet tells me when I try to print 5 pages from non-e10s
simulated-inkjet mike 127 [24/Jul/2015:11:42:05 -0400] 1
5
- localhost Nightly Start Page - -
simulated-inkjet mike 127 [24/Jul/2015:11:42:05 -0400] total 0 - localhost Nightly Start Page - -
simulated-inkjet mike 127 [24/Jul/2015:11:42:06 -0400] total 0 - localhost Nightly Start Page - -
simulated-inkjet mike 127 [24/Jul/2015:11:42:07 -0400] total 0 - localhost Nightly Start Page - -
simulated-inkjet mike 127 [24/Jul/2015:11:42:09 -0400] total 1 - localhost Nightly Start Page - -
simulated-inkjet mike 127 [24/Jul/2015:11:42:12 -0400] total 2 - localhost Nightly Start Page - -
simulated-inkjet mike 127 [24/Jul/2015:11:42:17 -0400] total 3 - localhost Nightly Start Page - -
simulated-inkjet mike 127 [24/Jul/2015:11:42:25 -0400] total 5 - localhost Nightly Start Page - -
And here's what I get when I try to do 6 pages from e10s:
simulated-inkjet mike 128 [24/Jul/2015:11:42:50 -0400] 1
1
- localhost Nightly Start Page - -
simulated-inkjet mike 128 [24/Jul/2015:11:42:50 -0400] total 0 - localhost Nightly Start Page - -
simulated-inkjet mike 128 [24/Jul/2015:11:42:51 -0400] total 0 - localhost Nightly Start Page - -
simulated-inkjet mike 128 [24/Jul/2015:11:42:52 -0400] total 0 - localhost Nightly Start Page - -
simulated-inkjet mike 128 [24/Jul/2015:11:42:54 -0400] total 1 - localhost Nightly Start Page - -
That highlighted number… I think that's supposed to be the number of copies. I'll confirm that right now.
I'll do non-e10s with 15 copies. If the number I get in that second slot is 15, I think that's a bingo.
simulated-inkjet mike 129 [24/Jul/2015:12:54:06 -0400] 1
15
- localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:06 -0400] total 0 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:08 -0400] total 0 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:09 -0400] total 0 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:11 -0400] total 0 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:14 -0400] total 1 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:19 -0400] total 2 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:27 -0400] total 3 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:28 -0400] total 4 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:29 -0400] total 4 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:31 -0400] total 4 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:34 -0400] total 5 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:39 -0400] total 6 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:47 -0400] total 8 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:48 -0400] total 8 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:49 -0400] total 8 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:51 -0400] total 9 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:54 -0400] total 9 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:54:59 -0400] total 11 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:55:07 -0400] total 13 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:55:08 -0400] total 13 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:55:09 -0400] total 13 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:55:11 -0400] total 14 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:55:14 -0400] total 15 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:55:19 -0400] total 15 - localhost Nightly Start Page - -
simulated-inkjet mike 129 [24/Jul/2015:12:55:27 -0400] total 15 - localhost Nightly Start Page - -
Ok, confirmed. What the fuck?
e10s:
Breakpoint 5, gtk_cups_request_encode_option (request=request@entry=0x9aa3ae8, option=option@entry=0x9cb0a3d "
InputSlot
",
value=value@entry=0x9a268e0 "") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 5, gtk_cups_request_encode_option (request=request@entry=0x9aa3ae8, option=option@entry=0x9a2ddfd "
number-up
",
value=value@entry=0x9f4d558 "1") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 5, gtk_cups_request_encode_option (request=request@entry=0x9aa3ae8, option=option@entry=0xa0067e5 "
job-sheets
",
value=value@entry=0x9d9ed60 "none,none") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 5, gtk_cups_request_encode_option (request=request@entry=0x9aa3ae8, option=option@entry=0x9dc3b3d "
cupsPrintQuality
",
value=value@entry=0x99d4cc0 "Normal") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 5, gtk_cups_request_encode_option (request=request@entry=0x9aa3ae8, option=option@entry=0xa6c237d "
MediaType
",
value=value@entry=0x99a6890 "auto") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 5, gtk_cups_request_encode_option (request=request@entry=0x9aa3ae8, option=option@entry=0xa1d7cad "
job-priority
",
value=value@entry=0x9fda268 "50") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 5, gtk_cups_request_encode_option (request=request@entry=0x9aa3ae8, option=option@entry=0x9a2de15 "
PageSize
",
value=value@entry=0x9a281b0 "Letter") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 5, gtk_cups_request_encode_option (request=request@entry=0x9aa3ae8, option=option@entry=0xa64387d "
ColorModel
",
value=value@entry=0x9c91c08 "RGB") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
non-e10s:
Breakpoint 1, gtk_cups_request_encode_option (request=request@entry=0xbe835a0,
option=option@entry=0xaa5aab5 "
InputSlot
", value=value@entry=0xca93c50 "")
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 1, gtk_cups_request_encode_option (request=request@entry=0xbe835a0,
option=option@entry=0xdae3e15 "
copies
", value=value@entry=0xe6c4938 "5")
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 1, gtk_cups_request_encode_option (request=request@entry=0xbe835a0,
option=option@entry=0xcabdf95 "
ColorModel
",
value=value@entry=0xa7306c8 "RGB") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 1, gtk_cups_request_encode_option (request=request@entry=0xbe835a0,
option=option@entry=0xa79e235 "
cupsPrintQuality
",
value=value@entry=0xe2aaac8 "Normal") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 1, gtk_cups_request_encode_option (request=request@entry=0xbe835a0,
option=option@entry=0xd9aa26d "
MediaType
",
value=value@entry=0xc3c4ed8 "auto") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 1, gtk_cups_request_encode_option (request=request@entry=0xbe835a0,
option=option@entry=0xb1d0355 "
job-priority
",
value=value@entry=0xaf38128 "50") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 1, gtk_cups_request_encode_option (request=request@entry=0xbe835a0,
option=option@entry=0xdae3e25 "
PageSize
",
value=value@entry=0x9ba1bc8 "Letter") at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 1, gtk_cups_request_encode_option (request=request@entry=0xbe835a0,
option=option@entry=0xa7306dd "
job-sheets
",
value=value@entry=0xc7c2228 "none,none")
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
Breakpoint 1, gtk_cups_request_encode_option (request=request@entry=0xbe835a0,
option=option@entry=0xab48245 "
number-up
", value=value@entry=0xa85ff30 "1")
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkcupsutils.c:485
WELL THERE'S YOUR PROBLEM RIGHT THERE.
We're, for some reason, not encoding the "copies" option. Huh. Okay, why?
Looking at each call to add_cups_options, which foreach's the settings:
e10s:
Breakpoint 6, add_cups_options (key=0x9bcac28 "print-at", value=0x9dde2d8 "now", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa5b6870 "cover-after", value=0x9f862a0 "none", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9f7afd0 "
cups-InputSlot
", value=0xa027120 "", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x99a6fc8 "reverse", value=0x9e0b0b0 "false", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa27d048 "print-pages", value=0x99bce18 "all", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa0e46b0 "paper-width", value=0xa727a70 "215.8", '9' <repeats 12 times>, "8", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9e4b9a8 "print-at-time", value=0x99ba0a0 "", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa139ce0 "paper-height", value=0x9c814c8 "279.3", '9' <repeats 12 times>, "8", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9c57c58 "
cups-number-up
", value=0xa725060 "1", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9c7f280 "
cups-job-sheets
", value=0x9f623c8 "none,none", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa00c298 "scale", value=0x9ac7ea0 "100", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa0471c0 "
cups-cupsPrintQuality
", value=0x9a4a7e0 "Normal", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa5bc118 "
cups-MediaType
", value=0x9a2de88 "auto", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9ec2710 "
cups-job-priority
", value=0x9a6d520 "50", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9fd0060 "default-source", value=0x9a04270 "", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9ec4dc8 "collate", value=0xa2f02a0 "false", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa0269b0 "media-type", value=0xa722008 "auto", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9db3af8 "
cups-PageSize
", value=0xa6fb4a0 "Letter", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9efd698 "page-set", value=0x9fa0f80 "all", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9c4b048 "
n-copies
", value=0x9b00138 "5", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x98e58a0 "cover-before", value=0x9f67170 "none", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0x9d80288 "cups-ColorModel", value=0xa127c90 "RGB", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa448960 "number-up", value=0x9b29d50 "1", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa63aa40 "paper-format", value=0xa0f8d40 "na_letter", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 6, add_cups_options (key=0xa197aa0 "printer", value=0x9f754b8 "simulated-inkjet", user_data=0xa338c80)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
non-e10s:
Breakpoint 2, add_cups_options (key=0xd931db8 "print-at",
value=0xa6d9bd8 "now", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0x9f4d110 "cover-after",
value=0xb7c2008 "none", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xadef990 "cups-InputSlot",
value=0xb7c2038 "", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xd87cab0 "reverse",
value=0xb7c2048 "false", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xb7c2018 "print-pages",
value=0xaffa4f8 "all", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xb7c2028 "paper-width",
value=0xb7c1868 "215.8", '9' <repeats 12 times>, "8", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xd89dd88 "print-at-time",
value=0xa874b68 "", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xa132938 "paper-height",
value=0xa1328e0 "279.3", '9' <repeats 12 times>, "8", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xc0d8a70 "paper-format",
value=0xb7c1dd8 "na_letter", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xb7c1a00 "
n-copies
", value=0xaf792b0 "5",
user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xad3c958 "
cups-copies
",
value=0xb7c1c18 "5", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xb7c1ec8 "cups-ColorModel",
value=0xe5703b0 "RGB", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xc62cb28 "cups-cupsPrintQuality",
value=0xa132848 "Normal", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xd9315f8 "cups-MediaType",
value=0xa51d340 "auto", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xec4ef88 "cups-job-priority",
value=0xa1327c8 "50", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xe570318 "default-source",
value=0xe570740 "", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xa132888 "collate",
value=0xd79b9c0 "false", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xa132808 "media-type",
value=0xc314d20 "auto", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xea92aa8 "cups-PageSize",
value=0xd79b980 "Letter", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xa6d9d60 "number-up",
value=0xd79b970 "1", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xd79b9d0 "cover-before",
value=0xc874f70 "none", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xb7c1e50 "cups-job-sheets",
value=0xb7f6990 "none,none", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xc62c6b0 "printer",
value=0xc314d30 "simulated-inkjet", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xa132928 "page-set",
value=0xa1ee348 "all", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xb7f69a0 "cups-number-up",
value=0xa7cb200 "1", user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
Breakpoint 2, add_cups_options (key=0xd9315d8 "scale", value=0xec4ef78 "100",
user_data=0xd931d98)
at /build/buildd/gtk+2.0-2.24.23/modules/printbackends/cups/gtkprintbackendcups.c:549
OK, here's the problem:
static
void
cups_printer_prepare_for_print (GtkPrinter * printer,
GtkPrintJob * print_job,
GtkPrintSettings * settings,
GtkPageSetup * page_setup)
{
GtkPageSet page_set;
GtkPaperSize * paper_size;
const char * ppd_paper_name;
double scale;
GtkPrintCapabilities capabilities;
cups_printer_prepare_for_print (GtkPrinter * printer,
GtkPrintJob * print_job,
GtkPrintSettings * settings,
GtkPageSetup * page_setup)
{
GtkPageSet page_set;
GtkPaperSize * paper_size;
const char * ppd_paper_name;
double scale;
GtkPrintCapabilities capabilities;
capabilities
=
cups_printer_get_capabilities (printer);
^-- That's the GTK code for getting a print job fired off. And then we get the capabilities of the printer...
The problem is that in the content process, we can't seem to get the capabilities of the printer!
So when we get to this part:
if
(capabilities
&
GTK_PRINT_CAPABILITY_COPIES)
{
if (gtk_print_settings_get_n_copies (settings) > 1 )
gtk_print_settings_set_int (settings, "cups-copies" ,
gtk_print_settings_get_n_copies (settings));
print_job -> num_copies = 1 ;
{
if (gtk_print_settings_get_n_copies (settings) > 1 )
gtk_print_settings_set_int (settings, "cups-copies" ,
gtk_print_settings_get_n_copies (settings));
print_job -> num_copies = 1 ;
}
We never enter this block, since the capabilities are unknown, so we never set cups-copies, which is what we need.
Question: Why aren't the capabilities known?
Hypothesis… the way we're enumerating printers somehow sidesteps our knowing what our target printers capabilities are… ???
Test: Add a breakpoint in the child process at the beginning of the
printing enumeration, and once just before we kick off the print job.
When we hit the first, set a breakpoint in
cups_request_avahi_printer_info_cb, and see if we hit that before we hit
the second breakpoint we added.
Result: Interesting! We never hit cups_request_avih_printer_info_cb in
the child process during that whole process. Wow! What about in the
parent? In the parent, we hit it when we show the dialog!
Ok, more information… when we enumerate the parent, we
do
actually query for all of the printers, and fill out the capabilities for each one correctly...
But, it's almost as if the GtkPrinter we get through the enumerator
isn't connected to the right PrinterSetupInfo? OR, we don't copy
the PrinterSetupInfo to the printer? Is that how it's arranged?
Ok… one variation I've noticed.
In the parent process, in avahi_create_browsers, we succeed in
attaching signal handlers… in the content process, not so much.
g_bus_get_finish is getting an G_IO_ERROR_CANCELLED error, so we never
attach some signal handlers.
I suspect this is because gtk_print_backend_cups_dispose is being
fired before avahi_create_browsers can attach in the content process,
and otherwise in the parent. Why????
Ok, so if gtk_print_backend_cups_dispose is being fired supposedly
early in the child (after the printer enumeration is done), then when is
it firing in the parent?
Yeah - the parent seems to call avahi_create_browsers really early - right near the very start.
Good order:
Dialog is opening… cups_get_printer_list, avahi_create_browsers…. dialog renders.
Printer is chosen and dialog is closed. gtk_print_backend_cups_dispose
nsDeviceContextSpecGTK::StartPrintJob
Dialog goes away… cups_get_printer_list,
nsDeviceContextSpecGTK::StartPrintJob, then
gtk_print_backend_cups_dispose, and then avahi_create_browsers. Ah hah.
AH HAH
It looks like calling gtk_print_job_send is not really allowed when
you're still in the process of enumerating printers. So now I'm doing it
in a runnable outside of that loop.
That way, we get this order:
cups_Get_printer_list, gtk_print_backend_cups_dispose,
avahi_create_browser (which still errors out…?), and then
nsDeviceContextSpecGTK::StartPrintJob.
So I don't actually fully understand what's happened here, except that
it's probably not a good idea to try to kick off a print job within a
printer enumeration loop, because things might not be "ready".
Uh, okay. Welp, patch time.
So karlt wants some more explanation of why this works.
Question: WHY DOES MY PATCH WORK?
I think it's because it makes it so that avahi_create_browsers will
still get called for the printer that we g_object_ref after the
enumerator has exited.
When we stop the enumeration of the GTK printers, it looks like we go
through every item of the printer list that GTK created, and destroy the
backends.
When we start the print job from within the enumerator, we're using a
printer that has a backend that's about to be destroyed once the
enumerator finishes.
What I know is that it looks like gtk_print_backend_cups_dispose is
called before we can call avahi_create_browser, and that seems to be the
key to hearing about whether or not a printer backend can do copies.
In single-process mode, avahi_create_browser is called long before
gtk_print_backend_cups_dispose, since dispose is called once the dialog
is closed. avahi_create_browser is called asynchronously after we get
the list of printers to populate the dialog with.
Thesis: avahi_create_browser is called too late in multi-process mode, and avahi_create_browser is needed…
We need it to call avahi_service_browser_signal_handler, which calls
avahi_service_resolver_cb, which calls avahi_connection_test_cb, which
calls cups_request_avahi_printer_info, which is necessary in order to
determine whether or not the printer can do copies.
How come deferring the print job start to an event helps?
Hypothesis: the printer backend is being destroyed before I can use it.
Test: Set a breakpoint in nsDeviceContextSpecGTK::PrinterEnumerator at
the point where we're about to kick off the job, and make note of the
printer backend memory address. Set a breakpoint in
gtk_print_backend_cups_finalize and see if we ever enter it with that
particular address.
Result: No, but it's being disposed of via gtk_print_backend_destroy,
which calls dispose on a backend, which breaks its reference to the
printer (and cancels any pending inquiries!).
Ok… I think I'm starting to understand.
Here is the order of events.
We kick off enumerating the printers, which does a bunch of setup with
signals (like printer-added), and kicks off a bunch of things to figure
out what printers are available, and what the capabilities of those
printers are.
Eventually, for each printer, we reach cups_request_printer_list_cb,
after we've gotten the list of all of the printers from CUPS. For each
printer, if it's "new" (we don't hold a reference to it in a cache I
guess?), we fire "printer-added", which is what the printer enumerator
is waiting for.
So we then run nsDeviceContextSpecGTK::PrinterEnumerator with the
printer. The problem is that we haven't fully populated the capabilities
of that printer yet! Look (from
https://git.gnome.org/browse/gtk+/tree/modules/printbackends/cups/gtkprintbackendcups.c?id=3.10.8#n3119
):
if (gtk_printer_is_new (printer))
{
g_signal_emit_by_name (backend, "printer-added", printer);
gtk_printer_set_is_new (printer, FALSE);
}
#if 0
/* Getting printer info with separate requests overwhelms cups
* when the printer list has more than a handful of printers.
*/
cups_request_printer_info (cups_backend, gtk_printer_get_name (printer));
#endif
GTK_PRINTER_CUPS (printer)->state = info->state;
GTK_PRINTER_CUPS (printer)->ipp_version_major = info->ipp_version_major;
GTK_PRINTER_CUPS (printer)->ipp_version_minor = info->ipp_version_minor;
GTK_PRINTER_CUPS (printer)->supports_copies = info->supports_copies;
GTK_PRINTER_CUPS (printer)->supports_collate = info->supports_collate;
GTK_PRINTER_CUPS (printer)->supports_number_up = info->supports_number_up;
So the nsDeviceContextSpecGTK::PrinterEnumerator is working with a printer that's not fully fleshed out!
WTF. How come the printer is new? Is the printer "new" in single-process as well?
Yes! We do! Ok, I think I've solved this m ystery...
6:57 PM
<
mconley
> karlt: ping
6:58 PM
<
karlt
> mconley: hi
6:59 PM
<
mconley
> karlt: hi! I think I've untangled this printer story. Can I run my theory by you and see if it makes sense?
6:59 PM
<
karlt
> mconley: sure
7:00 PM
<
mconley
> karlt: cool. So one thing that distinguishes printing with
e10s from non-e10s is that when we send the printer down to the child in
multi-process mode, we have to pass the name down, and then
gtk_enumerate_printers our way to success
7:01 PM
<
mconley
> karlt: when we do that, we're getting GTK to query the OS
for every printer it can find, and handing them to us as it finds them
7:02 PM
<
mconley
> looking at the CUPS backend, it looks like when a printer is
"discovered", we fire a "printer-added" signal on the printing backend -
that's what gtk_printers_enumerate (I had the order wrong in my last
sentence) is listening for
7:02 PM
<
mconley
> karlt: so far so good?
7:02 PM
<
karlt
> mconley: yes, makes sense
7:02 PM
<
mconley
> karlt: ok, so here's the problem:
7:02 PM
<
mconley
> here's where we emit the printer-added signal in the CUPS backend:
https://git.gnome.org/browse/gtk+/tree/modules/printbackends/cups/gtkprintbackendcups.c?id=3.10.8#n3119
7:03 PM
<
mconley
> so GTK dispatches the signal, and our
nsDeviceContextSpecGTK::PrinterEnumerator will execute before we move to
line 3121, right?
7:03 PM
<
mconley
> execute for the one printer we just found
7:04 PM
<
mconley
> if that's the case, the printers capabilities have not yet
been fleshed out - notice back in gtkprintbackendcups.c, on linees
3131-3139 is where we actually set up the state of the thing
7:04 PM
<
mconley
> so with our current code, we call
nsDeviceContextSpecGTK::StartPrintJob on a GtkPrinter that's not been
fully fleshed out yet, capability-wise
7:04 PM
<
karlt
> mconley: glib signal emission is usually synchronous, so it seems likely that 3121 has not run
7:05 PM
<
mconley
> karlt: so I think that's why dispatching the Event in my
patch works - we're able to go back to gtkprintbackendcups.c, and finish
setting up the capabilities of the printer
7:05 PM
<
mconley
> before we send it off to go print a thing
7:07 PM
<
mconley
> the behaviour seems really inconsistent - here's an
alternative approach that the backend uses to get information about the
printer:
https://git.gnome.org/browse/gtk+/tree/modules/printbackends/cups/gtkprintbackendcups.c?id=3.10.8#n2485
7:07 PM
<
mconley
> notice how we fire printer-added after we've set the state
7:08 PM
<
karlt
> mconley: yes, i think you've found a bug in cups_request_printer_list_cb
7:09 PM
<
mconley
> \o/
7:09 PM
<
mconley
> ?
7:09 PM
<
mconley
> :)
So I should land the workaround with the Event, and I should report the bug to the GTK maintainers.
Hey, we made it!
I've filed a GTK bug:
https://bugzilla.gnome.org/show_bug.cgi?id=753041
And I've got a new patch up for review. \o/
Woo! Landed! WE DID IT!