search

tjibbevanderlaan / chromeos-filesystem-sftp

ChromeOS app to access SFTP server
https://chrome.google.com/webstore/detail/shared-network-folder-sft/gbheifiifcfekkamhepkeogobihicgmn
BSD 3-Clause "New" or "Revised" License
81 stars 21 forks source link

Nacl module crashes when listing directories. #25

Closed mtomasz-chromium closed 5 years ago

mtomasz-chromium commented 9 years ago

I tried to connect to my FTP account. The FTP volume is correctly mounted, but when I click on it in Files app, it shows spinner for around a minute, then the NaCL module crashes.

yoichiro commented 9 years ago

@mtomasz-chromium Thank you for the reporting. Well, was the NaCl crashed 100%?

mtomasz-chromium commented 9 years ago

Yes. I looked into dev tools, and there was even a log that nacl crashed.

yoichiro commented 9 years ago

Hmm... Could you try to connect to other account or server?

mtomasz-chromium commented 9 years ago

I tried again with the same account and it worked this time. But it took around 5 minutes to list a directory with 20 entries in the root directory.

mtomasz-chromium commented 9 years ago

Let me split these issues, and they seem to be not related.

yoichiro commented 9 years ago

@mtomasz-chromium This app uses libssh2 internally. The libssh2 session is not thread-safe. I intended to protect the session instance by my code, however, I guess that one session was accessed from multiple thread... In #31, all APIs are called as serial. At least, I don't have the crash situation using the latest code.

yoichiro commented 9 years ago

@mtomasz-chromium I close this issue, because I think that the latest version becomes more stably than old versions.

mtomasz-chromium commented 9 years ago

Today on 1.5 I was still getting crashes, but of the entire app, not only the NaCL module. I can't get any logs unfortunately...

yoichiro commented 9 years ago

@mtomasz-chromium Hmm... Do you remember the timing of the crash? What did you do at the time?

mtomasz-chromium commented 9 years ago

When listing a directory. It doesn't happen always, though. After around 10 - 20 seconds for some directories. Note, that with 1.5 listing directories is already much faster, but still some with more items take longer.

yoichiro commented 9 years ago

@mtomasz-chromium I see, I intend to keep this issue to open.

yoichiro commented 9 years ago

@mtomasz-chromium I found some places where the SFTP handle was not closed correctly.

https://github.com/yoichiro/chromeos-filesystem-sftp/blob/master/app/nacl_src/get_metadata_command.cc#L33 https://github.com/yoichiro/chromeos-filesystem-sftp/blob/master/app/nacl_src/read_directory_command.cc#L33

The SFTP handle should be closed by using the AbstractCommand::CloseSftpHandle() function... I try to modify them.

scottakam commented 9 years ago

Since 1.7.1 I get a message "The NaCl module crashed. Unmounted." when mounting any sftp directory. I'm using a 1st gen Samsung chromebook. Version: 41.0.2272.118

ericmaster commented 9 years ago

I'm getting "The NaCl module crashed. Unmounted" as well, Using version 42.0.2311.67 beta on Acer Chromebook 13 (Nyan Big)

vijayk416 commented 9 years ago

Just started to get this error as well Version 41.0.2272.118 Platform 6680.81.0 (Official Build) stable-channel daisy Firmware Google_Snow.2695.117.

This started to happen after the last Chromebook update that was rolled out over the weekend.

folbricht commented 9 years ago

Same here, also on Acer CB13. See https://github.com/yoichiro/chromeos-filesystem-sftp/issues/60 for a more detailed error message. Perhaps an ARM-specific issue?

yoichiro commented 9 years ago

@scottakam @ericmaster @vijayk416 @folbricht In the latest version 1.7.3, the way to fetch the metadata for each file was changed from sync to async. By the change, I guess that the loading metadata list was improved,,, Do you have same crash in the 1,7.3 as well?

folbricht commented 9 years ago

@yoichiro I'm still seeing the same crash in 1.7.3 with the same error message Unchecked runtime.lastError while running fileSystemProvider.unmount: NOT_FOUND

vijayk416 commented 9 years ago

I pushed the update to 1.7.3 through, rebooted, and am still getting the NaCl error (not the same essage above that @folbricht is getting). Is there a log I can give you?

vijayk416 commented 9 years ago

Not sure if this helps but I found this: Object background.js:177 mountPath: _generated_background_page.html:1 NativeClient: NaCl module crashed background.js:233 -1 background.js:721 onNaClModuleCrashed - -1 background.js:1074 doUnmount background.js:1087 _doUnmount background.js:1092 sftpfs://192.168.0.103:22/root background.js:1303 deleteTaskQueue: sftpfs://192.168.0.103:22/root background.js:1343 deleteMetadataCache: sftpfs://192.168.0.103:22/root extensions::sendRequest:82 Unchecked runtime.lastError while running fileSystemProvider.unmount: NOT_FOUND at null. (chrome-extension://gbheifiifcfekkamhepkeogobihicgmn/background.js:1093:43) at null. (chrome-extension://gbheifiifcfekkamhepkeogobihicgmn/background.js:1134:17) background.js:1407 Object background.js:177 mountPath: _generated_background_page.html:1 NativeClient: NaCl module crashed background.js:233 -1 background.js:721 onNaClModuleCrashed - -1 background.js:1074 doUnmount background.js:1087 _doUnmount background.js:1092 sftpfs://192.168.0.101:22/admin background.js:1303 deleteTaskQueue: sftpfs://192.168.0.101:22/admin background.js:1343 deleteMetadataCache: sftpfs://192.168.0.101:22/admin extensions::sendRequest:82 Unchecked runtime.lastError while running fileSystemProvider.unmount: NOT_FOUND at null. (chrome-extension://gbheifiifcfekkamhepkeogobihicgmn/background.js:1093:43) at null. (chrome-extension://gbheifiifcfekkamhepkeogobihicgmn/background.js:1134:17)

scottakam commented 9 years ago

I get the same error with 1.7.3 also.

yoichiro commented 9 years ago

@scottakam @vijayk416 @folbricht I see... Thanks for the quick response. Well, I have two questions. One is, is your Chromebook architecture ARM? Second is, was the fingerprint (i.e. "rsa-sha 1a2b3c4d...") displayed on the popup dialog at clicking the MOUNT button?

scottakam commented 9 years ago

It is "Samsung Exynos 5 Dual" which is ARM. Specs: http://www.samsung.com/us/computer/chrome-os-devices/XE303C12-A01US-specs

I don't get the popup anymore. When I click "mount", it goes immediately to the error message.

folbricht commented 9 years ago

Yes, I believe everyone who reported the error above has an ARM architecture (Acer CB13 == ARM). And I also don't get the fingerprint, it crashes before that, during Attempting to mount instance

yoichiro commented 9 years ago

Unfortunately, I don't have any ARM devices, therefore, I guess that I cannot fix this issue for ARM users... One thing I can do is to change nexe to pexe, however, I cannot test it...

wcsuther commented 9 years ago

I have the same problem here on an HP Chromebook 11 (armv7l)... "The NaCl module crashed. Unmounted." Thanks.

vijayk416 commented 9 years ago

Yup, looks like I am arm Mozilla/5.0 (X11; CrOS armv7l 6680.81.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.118 Safari/537.36

If you want to test it I can try manually installing the update. It's in my best interest ;)

andmalc commented 9 years ago

Same error on 1.7.3 Samsung Series 3 - ARM On Dev channel, Chrome 43.0.2357.5 No fingerprint.

yusukes commented 9 years ago

I ran into the same crash on my HP Chromebook 11 (ARM). When I clicked "MOUNT", it immediately crashed leaving the following message to chrome://system (ui_log > Expand).

[12,3057381376:05:33:26.816059] Native Client module will be loaded at base address 0x0000000000000000 SftpThread: Constructor

\ Signal 11 from untrusted code: pc=1df8e4 [1589:1611:0408/223326:ERROR:nacl_process_host.cc(296)] NaCl process exited with status 62720 (0xf500)

The version of SFTP File System I used was 1.7.3, and Chrome OS revision was as follows.

Chromium 43.0.2335.0 (Developer Build) (32-bit) Revision 7d5ac7c6e034df98d631fa92cf51e10239469a97 Platform 6749.0.0 (Official Build) dev-channel daisy_spring test

According to arm-nacl-objdump -dC sftp_unstripped_arm.nexe, 0x1df8e4 is at the very beginning of nacl_io::DispatchRun.

001df8e0 nacl_io::DispatchRun(void*, int): 1df8e0: e3c00103 bic r0, r0, #-1073741824 ; 0xc0000000 1df8e4: e5903000 ldr r3, [r0] 1df8e8: e16d41f0 strd r4, [sp, #-16]! 1df8ec: e1a04000 mov r4, r0 1df8f0: e58d6008 str r6, [sp, #8]

geosmiles commented 9 years ago

Same issue here: Samsung ARM Series 3. I have a chromeOS update the other day, so I don't know if the two are related? Version 41.0.2272.118 Platform 6680.81.0 (Official Build) stable-channel daisy Firmware Google_Snow.2695.117.0

wcsuther commented 9 years ago

Well, I'd be willing to pitch in $10 to get an ARM chromebook for the developer so that he might be able to get this running again...anyone else?

Great extension, there doesn't seem to be another one like it available (especially using keys vs. passwords..)

vijayk416 commented 9 years ago

I am good for $10.

folbricht commented 9 years ago

$20 from me if it helps getting this extension to work on ARM.

yoichiro commented 9 years ago

Recently, I released the latest version 1.7.4. This version should output logs for debug from NaCl module to the stderr. The logs can be seen in the chrome://system page. The chrome://system page has the "ui_log" item. When you expand the "ui_log" output, then you will find the logs.

If I can know the logs when the error occurred and the NaCl module crashed, I may find the cause... Can somenone check the ui_log output?

wcsuther commented 9 years ago

How much of that log file do you need?

yoichiro commented 9 years ago

I don't have any ARM Chromebook. If you don't provide the log on your device to me, I can't fix this issue, because I have no clue enough...

wcsuther commented 9 years ago

Is this what you need?

\ Signal 11 from untrusted code: pc=1e32c4 [1609:1675:0412/112830:ERROR:nacl_process_host.cc(293)] NaCl process exited with status 62720 (0xf500) [41:41:0412/112833:ERROR:resource_request_policy.cc(57)] Denying load of chrome-extension://apdfllckaahabafndbhieahigkjlhalf/page_embed_script.js from hosted app. [54,3057508352:15:28:57.358714] Native Client module will be loaded at base address 0x0000000000000000 SftpInstance::SftpInstance SftpInstance::SftpInstance End SftpInstance::HandleMessage SftpInstance::HandleMessage connect 0 SftpThread::SftpThread SftpInstance::HandleMessage SftpThread instance created SftpThread::ConnectAndHandshake SftpThread::ConnectAndHandshake Thread started SftpInstance::HandleMessage End SftpThread::ConnectAndHandshakeImpl SftpThread::InitializeLibssh2 SftpThread::InitializeLibssh2 rc=0 SftpThread::ConnectToSshServer SftpThread::ConnectToSshServer sock=3

\ Signal 11 from untrusted code: pc=1e32c4 [1609:1675:0412/112857:ERROR:nacl_process_host.cc(293)] NaCl process exited with status 62720 (0xf500) [71,3057508352:15:29:06.938209] Native Client module will be loaded at base address 0x0000000000000000 SftpInstance::SftpInstance SftpInstance::SftpInstance End SftpInstance::HandleMessage SftpInstance::HandleMessage connect 0 SftpThread::SftpThread SftpInstance::HandleMessage SftpThread instance created SftpThread::ConnectAndHandshake SftpThread::ConnectAndHandshake Thread started SftpInstance::HandleMessage End SftpThread::ConnectAndHandshakeImpl SftpThread::InitializeLibssh2 SftpThread::InitializeLibssh2 rc=0 SftpThread::ConnectToSshServer SftpThread::ConnectToSshServer sock=3

yoichiro commented 9 years ago

@wcsuther Yes! Thank you for providing the log. Could you check that, was this message "\ Signal 11 from untrusted code: pc=1e32c4" shown after the mesasge "SftpThread::ConnectToSshServer sock=3" everytime?

I would like to get the output from other people as well.

wcsuther commented 9 years ago

Yes, it's the same every time. Thank you for your work on this!

folbricht commented 9 years ago

This is the log from my Acer CB13

[37,3057094656:22:27:54.386042] Native Client module will be loaded at base address 0x0000000000000000 SftpInstance::SftpInstance SftpInstance::SftpInstance End SftpInstance::HandleMessage SftpInstance::HandleMessage connect 0 SftpThread::SftpThread SftpInstance::HandleMessage SftpThread instance created SftpThread::ConnectAndHandshake SftpThread::ConnectAndHandshake Thread started SftpInstance::HandleMessage End SftpThread::ConnectAndHandshakeImpl SftpThread::InitializeLibssh2 SftpThread::InitializeLibssh2 rc=0 SftpThread::ConnectToSshServer SftpThread::ConnectToSshServer sock=3

\ Signal 11 from untrusted code: pc=1e32c4 [5038:6487:0413/162755:ERROR:nacl_process_host.cc(293)] NaCl process exited with status 62720 (0xf500)

scottakam commented 9 years ago

Looks like I get the same.

[1584:1584:0413/211526:ERROR:external_cache.cc(109)] ExternalCache cannot find external_crx /var/cache/external_cache/fobcpibfeplaikcclojfdhfdmbbeofai-2.0.crx [1584:2022:0413/211621:ERROR:channel.cc(305)] RawChannel read error (connection broken) [84,3057434624:01:16:45.895654] Native Client module will be loaded at base address 0x0000000000000000 SftpInstance::SftpInstance SftpInstance::SftpInstance End SftpInstance::HandleMessage SftpInstance::HandleMessage connect 0 SftpThread::SftpThread SftpInstance::HandleMessage SftpThread instance created SftpThread::ConnectAndHandshake SftpThread::ConnectAndHandshake Thread started SftpInstance::HandleMessage End SftpThread::ConnectAndHandshakeImpl SftpThread::InitializeLibssh2 SftpThread::InitializeLibssh2 rc=0 SftpThread::ConnectToSshServer SftpThread::ConnectToSshServer sock=3

\ Signal 11 from untrusted code: pc=1e32c4 [1584:2022:0413/211646:ERROR:nacl_process_host.cc(293)] NaCl process exited with status 62720 (0xf500)

yoichiro commented 9 years ago

Thank you for the reporting of the log. Probably, I may know the cause of the crash on ARM device.

The lines near the last log are the following:

https://github.com/yoichiro/chromeos-filesystem-sftp/blob/master/app/nacl_src/sftp_thread.cc#L338

int SftpThread::ConnectToSshServer(const std::string &hostname, const int port)
  throw(CommunicationException)
{
  ...
  int sock;
  sock = socket(PF_INET, SOCK_STREAM, IPPROTO_TCP);
  fprintf(stderr, "SftpThread::ConnectToSshServer sock=%d\n", sock);
  struct sockaddr_in sin;
  sin.sin_family = AF_INET;
  sin.sin_port = htons(port);
  memcpy(&sin.sin_addr.s_addr, hostent->h_addr_list[0], hostent->h_length);
  int rc;
  rc = connect(sock, (struct sockaddr*)(&sin), sizeof(struct sockaddr_in));
  fprintf(stderr, "SftpThread::ConnectToSshServer rc=%d\n", rc);
  if (rc != 0) {
    THROW_COMMUNICATION_EXCEPTION("connect() failed", rc);
  }
  return sock;
}

The function socket() returned the handle value of the socket successfully. But, the next log "SftpThread::ConnectToSshServer rc=%d\n" was not shown, instead, the NaCl module crashed. That is, the function connect() may be failed.

Well, I found a bad situation. The sockaddr_in structure was not initialized by zero. Probably, the sin_zero field has the random value. In this case, the connect() function and other functions regarding Socket may have a undefined behavior depending on the environment.

https://silviocesare.wordpress.com/2007/10/22/setting-sin_zero-to-0-in-struct-sockaddr_in/

As the result, I should add a new code to set zero value to the sin_zero field, I guess...

yoichiro commented 9 years ago

I have just released a new version 1.7.5 including the modification above. If you are using the ARM-based Chromebook, could you try to use the new version?

When some error occurs again, please post a comment here with the debug log again...

scottakam commented 9 years ago

I get farther now. I get the attempting to mount instance message before the crash.

[3,3056959488:11:36:48.930182] Native Client module will be loaded at base address 0x0000000000000000 [1515:1585:0414/073700:ERROR:rlz.cc(43)] Not implemented reached in bool GoogleUpdateSettings::GetLanguage(base::string16*) [41:41:0414/073702:ERROR:resource_request_policy.cc(57)] Denying load of chrome-extension://apdfllckaahabafndbhieahigkjlhalf/page_embed_script.js from hosted app. [19,3056959488:11:37:08.656080] Native Client module will be loaded at base address 0x0000000000000000 SftpInstance::SftpInstance SftpInstance::SftpInstance End SftpInstance::HandleMessage SftpInstance::HandleMessage connect 0 SftpThread::SftpThread SftpInstance::HandleMessage SftpThread instance created SftpThread::ConnectAndHandshake SftpThread::ConnectAndHandshake Thread started SftpInstance::HandleMessage End SftpThread::ConnectAndHandshakeImpl SftpThread::InitializeLibssh2 SftpThread::InitializeLibssh2 rc=0 SftpThread::ConnectToSshServer SftpThread::ConnectToSshServer sock=3

\ Signal 11 from untrusted code: pc=1e32c4 [1515:1591:0414/073708:ERROR:nacl_process_host.cc(293)] NaCl process exited with status 62720 (0xf500) [WARNING:flash/platform/pepper/pep_module.cpp(63)] SANDBOXED [36,3056959488:11:40:18.357459] Native Client module will be loaded at base address 0x0000000000000000 SftpInstance::SftpInstance SftpInstance::SftpInstance End SftpInstance::HandleMessage SftpInstance::HandleMessage connect 0 SftpThread::SftpThread SftpInstance::HandleMessage SftpThread instance created SftpThread::ConnectAndHandshake SftpThread::ConnectAndHandshake Thread started SftpInstance::HandleMessage End SftpThread::ConnectAndHandshakeImpl SftpThread::InitializeLibssh2 SftpThread::InitializeLibssh2 rc=0 SftpThread::ConnectToSshServer SftpThread::ConnectToSshServer sock=3

\ Signal 11 from untrusted code: pc=1e32c4 [1515:1591:0414/074018:ERROR:nacl_process_host.cc(293)] NaCl process exited with status 62720 (0xf500) uname Linux localhost 3.8.11 #1 SMP Thu Apr 2 00:21:50 PDT 2015 armv7l SAMSUNG EXYNOS5 (Flattened Device Tree) GNU/Linux

yoichiro commented 9 years ago

@scottakam Thank you for your cooperation. What was the version number of the SFTP File System application at retrieving the log above?

folbricht commented 9 years ago

This is with 1.7.5.

[37,3057139712:13:42:04.171754] Native Client module will be loaded at base address 0x0000000000000000 SftpInstance::SftpInstance SftpInstance::SftpInstance End SftpInstance::HandleMessage SftpInstance::HandleMessage connect 0 SftpThread::SftpThread SftpInstance::HandleMessage SftpThread instance created SftpThread::ConnectAndHandshake SftpThread::ConnectAndHandshake Thread started SftpInstance::HandleMessage End SftpThread::ConnectAndHandshakeImpl SftpThread::InitializeLibssh2 SftpThread::InitializeLibssh2 rc=0 SftpThread::ConnectToSshServer SftpThread::ConnectToSshServer sock=3 SftpThread::ConnectToSshServer sockaddr_in ready

\ Signal 11 from untrusted code: pc=1e3314 [5100:6493:0414/074204:ERROR:nacl_process_host.cc(293)] NaCl process exited with status 62720 (0xf500) [5100:6493:0414/074234:ERROR:channel.cc(305)] RawChannel read error (connection broken)

yoichiro commented 9 years ago

@folbricht Thank you for your cooperation. I could understand that the previous modification could not fix this issue...

scottakam commented 9 years ago

Version 1.7.5

ericmaster commented 9 years ago

I have Version 1.7.5 as well, still getting error. Where can I see the detailed log btw? I might be able to share mine as well

wcsuther commented 9 years ago

1.7.5 here too:

[1584:1584:0414/135319:ERROR:external_cache.cc(109)] ExternalCache cannot find external_crx /var/cache/external_cache/fobcpibfeplaikcclojfdhfdmbbeofai-2.0.crx [3,3057659904:17:53:23.127460] Native Client module will be loaded at base address 0x0000000000000000 [1584:1741:0414/135328:ERROR:rlz.cc(43)] Not implemented reached in bool GoogleUpdateSettings::GetLanguage(base::string16*) [18,3057659904:17:53:42.017421] Native Client module will be loaded at base address 0x0000000000000000 [35:35:0414/135400:ERROR:resource_request_policy.cc(57)] Denying load of chrome-extension://apdfllckaahabafndbhieahigkjlhalf/page_embed_script.js from hosted app. [35:35:0414/135409:ERROR:resource_request_policy.cc(57)] Denying load of chrome-extension://apdfllckaahabafndbhieahigkjlhalf/page_embed_script.js from hosted app. [WARNING:flash/platform/pepper/pep_module.cpp(63)] SANDBOXED [1584:1584:0414/135559:ERROR:external_cache.cc(109)] ExternalCache cannot find external_crx /var/cache/external_cache/fobcpibfeplaikcclojfdhfdmbbeofai-2.0.crx [1632:1632:0414/175644:ERROR:sync_control_vsync_provider.cc(60)] glXGetSyncValuesOML should not return TRUE with a media stream counter of 0. [1632:1632:0414/175726:ERROR:sync_control_vsync_provider.cc(60)] glXGetSyncValuesOML should not return TRUE with a media stream counter of 0. [37,3057659904:17:57:34.435802] Native Client module will be loaded at base address 0x0000000000000000 SftpInstance::SftpInstance SftpInstance::SftpInstance End SftpInstance::HandleMessage SftpInstance::HandleMessage connect 0 SftpThread::SftpThread SftpInstance::HandleMessage SftpThread instance created SftpThread::ConnectAndHandshake SftpThread::ConnectAndHandshake Thread started SftpInstance::HandleMessage End SftpThread::ConnectAndHandshakeImpl SftpThread::InitializeLibssh2 SftpThread::InitializeLibssh2 rc=0 SftpThread::ConnectToSshServer SftpThread::ConnectToSshServer sock=3 SftpThread::ConnectToSshServer sockaddr_in ready

\ Signal 11 from untrusted code: pc=1e3314 [1584:1628:0414/135734:ERROR:nacl_process_host.cc(293)] NaCl process exited with status 62720 (0xf500) [mi] EQ overflowing. Additional events will be discarded until existing events are processed.