[Cros] ZipFiles/FilesAppBrowserTest.Test/zipFileOpen* consistently fails in DEBUG |
||||||||||
Issue descriptionSee first failure: https://ci.chromium.org/p/chromium/builders/luci.chromium.ci/linux-chromeos-dbg/6998 Culprit CL: https://chromium-review.googlesource.com/c/chromium/src/+/1150008 Unable to revert due to merge conflicts.
,
Jul 26
,
Jul 26
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/4810077ba30e7f6d975ca5d061f56ce35ad65787 commit 4810077ba30e7f6d975ca5d061f56ce35ad65787 Author: Noel Gordon <noel@chromium.org> Date: Thu Jul 26 11:16:12 2018 Disable FilesAppBrowserTest zipFileOpen tests in DEBUG NaCl module is crashing in DEBUG in the zipFileOpen* cases: causes the DEBUG bots to TIMEOUT waiting for the unzipped file results. Disable these tests in DEBUG. Tbr: hbos@ Bug: 867738 , 867842 Change-Id: If2717bcd2f427c7e8ff0bd5a532f0a9405bfc31d No-Presubmit: true No-Tree-Checks: true No-Try: true Reviewed-on: https://chromium-review.googlesource.com/1151176 Reviewed-by: Noel Gordon <noel@chromium.org> Commit-Queue: Noel Gordon <noel@chromium.org> Cr-Commit-Position: refs/heads/master@{#578259} [modify] https://crrev.com/4810077ba30e7f6d975ca5d061f56ce35ad65787/chrome/browser/chromeos/file_manager/file_manager_browsertest.cc
,
Jul 26
,
Jul 26
,
Jul 26
,
Jul 26
This should probably not be "Fixed" until the problem fixed and tests are re-enabled but it's off the sheriff's queue, thanks for helping disable.
,
Jul 26
No worries. I'm OK with "Fixed" here. We will deal with the actual fix and test re-enable in issue 867738 .
,
Jul 26
Actually, this easy to reproduce locally
assertion "var_dict.Get(request::key::kOperation).is_int()" failed: file "../../chrome/browser/resources/chromeos/zip_archiver/cpp/module.cc", line 168, function: virtual void NaclArchiveInstance::HandleMessage(const pp::Var &)
** abort() called
** Signal 4 from untrusted code: pc=332c0015d740
[253423:253461:0726/214614.247545:ERROR:nacl_process_host.cc(262)] NaCl process exited with status 64512 (0xfc00) // Handler for messages coming in from JS via postMessage().
CRASH@ chrome/browser/resources/chromeos/zip_archiver/cpp/module.cc", line 168
virtual void HandleMessage(const pp::Var& var_message) {
PP_DCHECK(var_message.is_dictionary());
pp::VarDictionary var_dict(var_message);
PP_DCHECK(var_dict.Get(request::key::kOperation).is_int()); <== CRASH
int operation = var_dict.Get(request::key::kOperation).AsInt();
if (request::IsPackRequest(operation))
HandlePackMessage(var_dict, operation);
else
HandleUnpackMessage(var_dict, operation);
}
yamaguchi-san@
Any reason the JS would send an invalid kOperation key?
,
Jul 26
I re-wrote the NaCl HandleMessage() to debug it, and it seems someone/thing is sending an _undefined_ kOperation in the first request sent to the NaCl module.
If I see an _undefined_ kOperation, I reset it to int 0 ...
// Handler for messages coming in from JS via postMessage().
virtual void HandleMessage(const pp::Var& var_message) {
PP_DCHECK(var_message.is_dictionary());
pp::VarDictionary var_dict(var_message);
PP_DCHECK(var_dict.Get(request::key::kFileSystemId).is_string());
const std::string file_system_id =
var_dict.Get(request::key::kFileSystemId).AsString();
PP_DCHECK(var_dict.Get(request::key::kRequestId).is_string());
const std::string request_id =
var_dict.Get(request::key::kRequestId).AsString();
if (!var_dict.Get(request::key::kOperation).is_int()) {
// Well what type of operation is it exactly: guess
const pp::Var op = var_dict.Get(request::key::kOperation);
std::string optype;
if (op.is_string())
optype.append("string");
else if (op.is_undefined())
optype.append("undefined");
else if (op.is_null())
optype.append("null");
// Debug the request, show its keys
std::string debug =
"HandleMessage: FSI(" + file_system_id + ") RID (" + request_id + ")";
printf("%s kOperation type [%s] \n", debug.c_str(), optype.c_str());
std::string keys("kOperation is not int!\n request keys were:");
pp::VarArray array = var_dict.GetKeys();
for (uint32_t i = 0; i < array.GetLength(); ++i)
keys.append(" " + array.Get(i).DebugString());
printf(" %s\n", keys.c_str());
// now HACK: reset the dict kOperation to an int, with value 0.
var_dict.Set(request::key::kOperation, 0);
printf(" Forcing kOperation to int 0\n");
}
PP_DCHECK(var_dict.Get(request::key::kOperation).is_int());
int operation = var_dict.Get(request::key::kOperation).AsInt();
std::string debug =
"HandleMessage: FSI(" + file_system_id + ") RID (" + request_id + ")";
printf("%s kOperation [int] %d\n", debug.c_str(), operation);
if (request::IsPackRequest(operation))
HandlePackMessage(var_dict, operation);
else
HandleUnpackMessage(var_dict, operation);
}
In the log the zipFileOpenDownloads test running DEBUG locally, I now see:
[14164:14164:0726/232936.414307:INFO:CONSOLE(0)] "Styling master document from stylesheets defined in HTML Imports is deprecated. Please refer to https://goo.gl/EGXzpw for possible migration paths.", source: (0)
[14164:14164:0726/232939.415867:INFO:CONSOLE(156)] "at /file_manager/background.js:373:27: The number of file is 0. Not changed.", source: chrome-extension://oobinhbdbiehknkpbpejbbpdbkdjmoco/test_util.js (156)
Still waiting for the following processes to finish:
./out/Debug/browser_tests --disable-gpu-process-for-dx12-vulkan-info-collection --gtest_also_run_disabled_tests --gtest_filter=ZipFiles/FilesAppBrowserTest.Test/zipFileOpenDownloads --single_process --test-launcher-output=/tmp/.org.chromium.Chromium.wU9fEs/resultsWVuMuO/test_results.xml --user-data-dir=/tmp/.org.chromium.Chromium.wU9fEs/dhDxvz8
[14164:14164:0726/232943.872558:INFO:CONSOLE(156)] "at StepsRunner.<anonymous> (/file_manager/zip_files.js:45:18): waitForFiles: expected: [["image.png","272 bytes","PNG image","Sep 2, 2013, 10:01 PM"],["text.txt","51 bytes","Plain text","Sep 2, 2013, 10:01 PM"]] actual [["archive.zip","533 bytes","Zip archive","Jan 1, 2014, 1:00 AM"]].", source: chrome-extension://oobinhbdbiehknkpbpejbbpdbkdjmoco/test_util.js (156)
[1,2098178304:13:29:45.617317] Native Client module will be loaded at base address 0x00003d9b00000000
[1,2098178304:13:29:45.898568] Native Client module will be loaded at base address 0x00004d7900000000
HandleMessage: FSI(~/Downloads/archive.zip) RID (-1) kOperation type [undefined]
kOperation is not int!
request keys were: Var<'archive_size'> Var<'encoding'> Var<'file_system_id'> Var<'operation'> Var<'request_id'>
Forcing kOperation to int 0
HandleMessage: FSI(~/Downloads/archive.zip) RID (-1) kOperation [int] 0
HandleMessage: FSI(~/Downloads/archive.zip) RID (-1) kOperation [int] 3
[14164:14164:0726/232946.170258:INFO:CONSOLE(6048)] "Requesting file system.", source: chrome-extension://hhaomjibdihmijegdhdafkllkbggdgoj/background/js/background_common_scripts.js (6048)
...
Not sure if that helps, or is safe to do, but the test does PASS with that change. Full log attached.
,
Jul 26
,
Jul 31
Looks to me like this is exposing an unzip race condition (and my feeling this is affecting Files app users).
,
Jul 31
,
Aug 10
Seems Operation type is undefined. HandleMessage: FSI(~/Downloads/archive.zip) RID (-1) kOperation type [undefined] kOperation is not int! request keys were: Var<'archive_size'> Var<'encoding'> Var<'file_system_id'> Var<'operation'> Var<'request_id'> Forcing kOperation to int 0 Looking at zip_acrhiver results.js https://cs.chromium.org/chromium/src/chrome/browser/resources/chromeos/zip_archiver/js/request.js?q=isPackRequest&dr=CSs&l=69 /** * Defines request operations. These operation should be the same as the * operations on the NaCL side. FILE_SYSTEM_ID and REQUEST_ID are mandatory * for all unpack requests, while COMPRESSOR_ID is required for all pack * requests. All the values of unpacking operations must be smaller than any * packing operation (except errors). * @enum {number} */ Operation: { READ_METADATA_DONE: 1, READ_CHUNK: 2, READ_CHUNK_DONE: 3, ... "READ_METADATA" is not defined as an operation in the JS code. It is defined as an operation in the NaCL C++ code.
,
Aug 10
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/db7657b8d3d775d3c9ce4dc338d03b0a16e808bc commit db7657b8d3d775d3c9ce4dc338d03b0a16e808bc Author: Noel Gordon <noel@chromium.org> Date: Fri Aug 10 12:17:31 2018 Add a missing ZipArchiver operation define: READ_METADATA READ_METADATA was defined in the NaCL C++ but wasn't defined in the JS code. It is a requirement of the ZipArchiver design that the operation values are defined, and have the same values, in the C++ and JS code. This is likely causing crashes in the field: it certainly caused CHECK stop crashes in DEBUG C++ NaCL code in integration test (ZipArchiver's unit_tests did not exhibit the bug at all). Define READ_METADATA in the JS, add protective code to check operation validity (make it throw, if not) when constructing pack messages in JS that will be sent to the NaCL module C++ code. Re-enable the zip integration tests that were disabled due to this bug in issue 867738 . (Those tests discovered bug 867842 ). Test: browser_test --gtest-filter="Zip*FilesApp*" No-try: true Bug: 867842 , 867738 Change-Id: Ide44e60a47d9e87322115dc66017e8e0313b2162 Reviewed-on: https://chromium-review.googlesource.com/1169485 Commit-Queue: Noel Gordon <noel@chromium.org> Reviewed-by: Luciano Pacheco <lucmult@chromium.org> Reviewed-by: Tatsuhisa Yamaguchi <yamaguchi@chromium.org> Cr-Commit-Position: refs/heads/master@{#582123} [modify] https://crrev.com/db7657b8d3d775d3c9ce4dc338d03b0a16e808bc/chrome/browser/chromeos/file_manager/file_manager_browsertest.cc [modify] https://crrev.com/db7657b8d3d775d3c9ce4dc338d03b0a16e808bc/chrome/browser/resources/chromeos/zip_archiver/cpp/request.h [modify] https://crrev.com/db7657b8d3d775d3c9ce4dc338d03b0a16e808bc/chrome/browser/resources/chromeos/zip_archiver/js/decompressor.js [modify] https://crrev.com/db7657b8d3d775d3c9ce4dc338d03b0a16e808bc/chrome/browser/resources/chromeos/zip_archiver/js/request.js
,
Aug 10
FTR, https://codereview.chromium.org/2807063002/patch/60001/70027 was the change that deleted the READ_METADATA value. #15 above brings it back.
,
Sep 25
|
||||||||||
►
Sign in to add a comment |
||||||||||
Comment 1 by hbos@chromium.org
, Jul 26