[Regression] Client crashes as soon as sync dir becomes unavailable or when sync dir is not available on startup #6049

adroste · 2017-09-23T13:19:43Z

Expected behaviour

If storage becomes unavailable, the client should notice and pause sync.

Actual behaviour

The client crashes.

Steps to reproduce

Sync to folder /x
Unmount /x
Observe ownCloud crashing

Client configuration

Client version: 2.3.3 (8242)
Operating system: macOS Sierra 10.12.6
OS language: English
Installation path of client: Default

guruz · 2017-09-25T09:22:48Z

@michaelstingl @SamuAlfageme If enough people report this, it might mandate a 2.3.4.. let's see.

SamuAlfageme · 2017-09-25T12:27:12Z

Reproduced & confirmed the regression. (e.g. on OS X):

$ sudo bindfs ~/ownCloud /Volumes/OC
$ diskutil unmountDisk force /Volumes/OC

I think there's some kind of delay on the crash-reporter (last update I see was 18h ago)

valentijnscholten · 2017-09-25T20:48:21Z

I am seeing similar behaviour on Windows 10 Pro x64 (more similar to #6050 actually).
When the user runs the owncloud client and doesn't have write access to the owncloud folder, the client won't start.

Actually it will crash before generating any logging. Or it will just hang. And then crash silently.

Also the crash reporter doesn't work in this case, it will crash as well. So no crash reports

Workaround is to run as administrator. Or to assign write permissions to the stack folder.

It makes sense the client won't work without write permissions, but it should inform the user about the missing permissions.

adroste · 2017-09-25T22:03:41Z

@valentijnscholten This is a little different from my problem. I don't have problem with permissions, but with non existing paths (e.g. external hard drive not mounted) causing the client to crash.

valentijnscholten · 2017-09-26T06:02:26Z

@progmem64 yes, my issue is more similar to #6050 (folder being readonly), but that is closed and points to this issue for follow up.

ckamm · 2017-09-26T12:08:03Z

@SamuAlfageme @guruz I can't reproduce on linux. You can't unmount the filesystem with the sync folder while the client is open because it keeps the journal file openend. If I put it on an USB stick and plug it out without unmounting, nothing bad happens. I get Error: "unable to open database file" for "/media/kamm/E9B9-AE9E/test/._sync_dba920715f43.db" and the sync fails with something like Unable to find sync dir

SamuAlfageme · 2017-09-26T12:12:14Z

@ckamm hmmm.. will try to reproduce on leenux (report in #6050 (comment) was over readonly-FS in Fedora and I assumed the same reason was behind it).

jturcotte · 2017-10-02T11:05:37Z

I'm trying the force unmount thing on macOS, and I'm getting #3046, which is not a regression (it not really fixed and still appears in our crash reports).
Force unmounting is not a common scenario, and I can't get it to crash if I unmount normally.

So the regression part could be specific to Windows.

jturcotte · 2017-10-02T11:56:09Z

Just saw that the bug report was created for macOS so this can't really be specific to Windows. I've been trying to reproduce it with current master though, not 2.3.3.

SamuAlfageme · 2017-10-02T13:24:46Z

@jturcotte @ckamm then I was wrong to assume #6050 and this one were the same. 😕

jturcotte · 2017-10-02T14:25:24Z

It's also possible that one needs a bit of luck in order to reproduce it, on any of the involved OSes. Getting the OS to unmount the disk at the right moment is quite difficult. I tried a few times on macOS and Windows, but could only get it to crash once out of my 10 tries (and it was #3046, so it's either a different issue, or it's not a regression).

Having a crash report would help figuring out what is happening. @progmem64 Could take note of the time you submit one or many of the crash reports, so that we can fish them out of the crash reporter?

ogoffart · 2017-10-17T11:02:48Z

On the crash reporter, i see crash because of the

        ENFORCE(_errId == SQLITE_OK, "Error when closing DB");

in SqlDatabase::close .

Maybe we should remove this ENFORCE and let the code recover. (I thin most of the code should be able to recover)
I don't know if this is the actual reason for this particular crash tough.

ckamm · 2017-10-17T11:12:59Z

@ogoffart Was the stacktrace at all interesting?

Yes, it seems this could be an ASSERT instead. It doesn't fix the bug, but there's a reasonable chance of things working anyway.

ogoffart · 2017-10-17T11:16:27Z

https://sentry.io/owncloud/desktop-win-and-mac/issues/370119057/

QtCore in qt_message_fatal
QtCore in QMessageLogger::fatal
libocsync.2.4.0.dylib in OCC::SqlDatabase::close
libocsync.2.4.0.dylib in OCC::SyncJournalDb::sqlFail
libocsync.2.4.0.dylib in OCC::SyncJournalDb::checkConnect
libocsync.2.4.0.dylib in OCC::SyncJournalDb::getSelectiveSyncList
owncloud in OCC::AccountSettings::refreshSelectiveSyncStatus
owncloud in OCC::AccountSettings::AccountSettings
owncloud in OCC::SettingsDialogMac::accountAdded
owncloud in OCC::SettingsDialogMac::SettingsDialogMac

As I said, i am not sure it is indeed the backtrace relative to this one crash.

guruz · 2017-10-17T11:48:12Z

@ogoffart doesn't look so much like it if it's in accountAdded?
@SamuAlfageme Do you still have the verbose client log?
@progmem64 How were you unmounting? Just by clicking the eject button in Finder? Or unmount in console? Or diskutil eject?

ogoffart · 2017-10-17T12:01:43Z

(@guruz: accountAdded is called on startup when the settingsdialog is created)

ckamm · 2017-11-10T09:12:05Z

It might be that #6129 helps with this problem. @progmem64 would you be up for testing the 2.4 nightly?

SamuAlfageme · 2018-03-15T11:06:31Z

Can confirm it still reproduces on 2.4.1 (build 9367)

guruz · 2018-03-19T15:26:32Z

@SamuAlfageme How did you unmount?

SamuAlfageme · 2018-03-19T15:27:33Z

@guruz followed the same procedure as in #6049 (comment)

guruz · 2018-05-14T18:49:49Z

I get this on my machine with 2.4 and an idle sync:

* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=10, address=0x10cdf6020)
  * frame #0: 0x00007fff5a874f6d libsystem_platform.dylib`_platform_memmove$VARIANT$Haswell + 77
    frame #1: 0x00000001083b8d8e libocsync.0.dylib`walIndexTryHdr + 78
    frame #2: 0x00000001083b89b1 libocsync.0.dylib`walIndexReadHdr + 81
    frame #3: 0x00000001083bfd00 libocsync.0.dylib`sqlite3WalCheckpoint + 288
    frame #4: 0x00000001083bfa61 libocsync.0.dylib`sqlite3WalClose + 193
    frame #5: 0x00000001083b4f34 libocsync.0.dylib`sqlite3PagerClose + 180
    frame #6: 0x00000001083c89ed libocsync.0.dylib`sqlite3BtreeClose + 189
    frame #7: 0x0000000108399d6f libocsync.0.dylib`sqlite3LeaveMutexAndCloseZombie + 159
    frame #8: 0x00000001083a59c4 libocsync.0.dylib`sqlite3Close + 276
    frame #9: 0x00000001083a58a7 libocsync.0.dylib`sqlite3_close + 23
    frame #10: 0x000000010834b34b libocsync.0.dylib`OCC::SqlDatabase::close() + 59
    frame #11: 0x0000000108358038 libocsync.0.dylib`OCC::SyncJournalDb::close() + 984
    frame #12: 0x0000000107413281 libowncloudsync.0.dylib`OCC::SyncEngine::finalize(bool) + 129
    frame #13: 0x00000001074139f8 libowncloudsync.0.dylib`OCC::SyncEngine::startSync() + 1352
    frame #14: 0x0000000107453ba4 libowncloudsync.0.dylib`OCC::SyncEngine::qt_static_metacall(QObject*, Q

This looks to me the same as https://sentry.io/owncloud/desktop-win-and-mac/issues/402884797/ mentioned by @ckamm (Why is it marked as 'resolved' in sentry?)

With master branch (newer sqlite3 version) I don't get the crash so easily, I however get it while downloading a file with a different back trace:

* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=10, address=0x10ffdd000)
  * frame #0: 0x00007fff5a870bc1 libsystem_platform.dylib`_platform_memcmp + 33
    frame #1: 0x000000010970affe libocsync.0.dylib`sqlite3WalBeginWriteTransaction + 126
    frame #2: 0x0000000109709db2 libocsync.0.dylib`sqlite3PagerBegin + 226
    frame #3: 0x00000001096e06ae libocsync.0.dylib`sqlite3BtreeBeginTrans + 606
    frame #4: 0x0000000109718fdd libocsync.0.dylib`sqlite3VdbeExec + 16205
    frame #5: 0x00000001096e4076 libocsync.0.dylib`sqlite3Step + 518
    frame #6: 0x00000001096e3cdd libocsync.0.dylib`sqlite3_step + 125
    frame #7: 0x000000010967f3d4 libocsync.0.dylib`OCC::SqlQuery::exec() + 564
    frame #8: 0x0000000109692779 libocsync.0.dylib`OCC::SyncJournalDb::setDownloadInfo(QString const&, OCC::SyncJournalDb::DownloadInfo const&) + 921
    frame #9: 0x0000000108deb856 libowncloudsync.0.dylib`OCC::PropagateDownloadFile::slotGetFinished() + 1222
    frame #10: 0x0000000108df13dc libowncloudsync.0.dylib`QtPrivate::FunctorCall<QtPrivate::IndexesList<>, QtPrivate::List<>, void, void (OCC::PropagateDownloadFile::*)()>::call(void (OCC::PropagateDownloadFile::*)(), OCC::PropagateDownloadFile*, void**) + 140
    frame #11: 0x0000000108df1343 libowncloudsync.0.dylib`void QtPrivate::FunctionPointer<void (OCC::PropagateDownloadFile::*)()>::call<QtPrivate::List<>, void>(void (OCC::PropagateDownloadFile::*)(), OCC::PropagateDownloadFile*, void**) + 99
    frame #12: 0x0000000108df1276 libowncloudsync.0.dylib`QtPrivate::QSlotObject<void (OCC::PropagateDownloadFile::*)(), QtPrivate::List<>, void>::impl(int, QtPrivate::QSlotObjectBase*, QObject*, void**, bool*) + 166
    frame #13: 0x000000010a019f7b QtCore`QMetaObject::activate(QObject*, int, int, void**) + 2347
    frame #14: 0x0000000108e61f02 libowncloudsync.0.dylib`OCC::GETFileJob::finishedSignal() + 34
    frame #15: 0x0000000108e66b6a libowncloudsync.0.dylib`OCC::GETFileJob::finished() + 154

BTW
I also get something like

05-14 20:15:40:652 [ warning default ]:	QIODevice::write (QFile, "/Volumes/SC256MB/syncfolder/.owncloudsync.log"): device not open

or

05-14 20:35:13:312 [ warning sync.networkjob.get ]:	Error while writing to file -1 8192 "Input/output error"

With JOURNAL_MODE=delete I manage to get a a crash only in beginning of sync when creating the tables:

05-14 20:41:33:538 [ warning sync.database ]:	ERROR committing to the database:  "cannot commit - no transaction is active"
05-14 20:41:33:538 [ debug sync.database ]	[ OCC::SyncJournalDb::startTransaction ]:	Database Transaction is running, not starting another one!
05-14 20:41:33:538 [ debug sync.database.sql ]	[ OCC::SqlQuery::exec ]:	SQL exec "CREATE INDEX IF NOT EXISTS blacklist_index ON blacklist(path collate nocase);"
05-14 20:41:33:538 [ warning sync.database.sql ]:	Sqlite exec statement error: 10 "disk I/O error" in "CREATE INDEX IF NOT EXISTS blacklist_index ON blacklist(path collate nocase);"
05-14 20:41:33:538 [ warning sync.database.sql ]:	IOERR extended errcode:  266
05-14 20:41:33:538 [ warning sync.database.sql ]:	IOERR system errno:  5
05-14 20:41:33:538 [ warning sync.database ]:	ERROR committing to the database:  "cannot commit - no transaction is active"
05-14 20:41:33:538 [ warning sync.database ]:	SQL Error "updateErrorBlacklistTableStructure: create index blacklit" "disk I/O error"
05-14 20:41:33:539 [ critical default ]:	ASSERT: "false" in file /Users/guruz/woboq/owncloud/client/mirall/src/common/syncjournaldb.cpp, line 268
05-14 20:41:33:539 [ warning sync.database ]:	Failed to update the database structure!
05-14 20:41:33:539 [ info sync.database ]:	Forcing remote re-discovery by deleting folder Etags
05-14 20:41:33:539 [ warning sync.database.sql ]:	Sqlite prepare statement error: "out of memory" in "UPDATE metadata SET md5='_invalid_' WHERE type=2;"
05-14 20:41:33:539 [ fatal default ]:	ENFORCE: "allow_failure" in file /Users/guruz/woboq/owncloud/client/mirall/src/common/ownsql.cpp, line 269 with message: SQLITE Prepare error

Then while the download it doesn't crash, it just errors 👍 :

05-14 20:45:23:350 [ warning sync.database.sql ]:	Sqlite exec statement error: 10 "disk I/O error" in "INSERT OR REPLACE INTO blacklist (path, lastTryEtag, lastTryModtime, retrycount, errorstring, lastTryTime, ignoreDuration, renameTarget, errorCategory) VALUES ( ?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9)"
05-14 20:45:23:350 [ warning sync.database.sql ]:	IOERR extended errcode:  266
05-14 20:45:23:350 [ warning sync.database.sql ]:	IOERR system errno:  5
05-14 20:45:23:350 [ warning sync.propagator ]:	Could not complete propagation of "default.lay" by OCC::PropagateDownloadFile(0x7fdeee5b9e70) with status 2 and error: "Input/output error"

I'll add a commit that checks for "/Volumes" in sync directory and sets JOURNAL_MODE=delete in code. This should help with most cases..

For #6049

guruz · 2018-05-14T19:11:04Z

PR for macOS in #6526

Do we need something for Windows?
https://sentry.io/owncloud/desktop-win-and-mac/issues/426903988/
https://sentry.io/owncloud/desktop-win-and-mac/issues/130205177/
@ogoffart @ckamm If those are really the same..

ckamm · 2018-05-15T07:54:48Z

Hmm. It's really unfortunate we can make sqlite crash like that. Might a strategically placed file.exists() before interacting with the db help? We could check whether _dbFile exists in checkConnect, instead of relying on _db.isOpen().

With WAL mode sqlite seems to occasionally crash when the underlying filesystem goes away.

With WAL mode sqlite seems to occasionally crash when the underlying filesystem goes away. (cherry picked from commit b1224cf)

For #6049

For #6049 (cherry picked from commit 309c53c)

SamuAlfageme · 2018-06-05T15:44:58Z

I've been stressing out the client with forced unmounts both on win and macOS at different points in the sync cycle and I don't seem to be able to make it crash. Closing here as resolved 🎉

In context of #6049 a check for the existance of the db file was introduced. That check is performed before every db access... so serveral 100 times per second.

In context of #6049 a check for the existance of the db file was introduced. That check is performed before every db access... so several 100 times per second.

This was referenced Sep 25, 2017

Never ever abort sync runs / check that the connection is indeed broken before aborting on a timeout #5859

Closed

client crashes when storage unaccessable or read only mode #6050

Closed

SamuAlfageme changed the title ~~Client crashes as soon as storage becomes unavailable~~ [Regression][SQlite] - Client crashes as soon as storage becomes unavailable Sep 25, 2017

SamuAlfageme added this to the 2.4.0 milestone Sep 25, 2017

guruz assigned ckamm Sep 25, 2017

SamuAlfageme added type:bug sev2-high labels Sep 25, 2017

ckamm assigned guruz and unassigned ckamm Sep 26, 2017

ckamm changed the title ~~[Regression][SQlite] - Client crashes as soon as storage becomes unavailable~~ [Regression][OSX] - Client crashes as soon as storage becomes unavailable Sep 26, 2017

guruz changed the title ~~[Regression][OSX] - Client crashes as soon as storage becomes unavailable~~ [Regression][macOS][Windows] Client crashes as soon as sync dir becomes unavailable or when sync dir is not available on startup Sep 28, 2017

SamuAlfageme mentioned this issue Oct 2, 2017

2.4 Alpha #6019

Closed

9 tasks

guruz mentioned this issue Oct 2, 2017

Release 2.3.4 #6069

Closed

1 task

guruz modified the milestones: 2.5.0, 2.4.2-maybe Feb 12, 2018

felixboehm added p3-medium Normal priority and removed sev2-high labels May 3, 2018

guruz added a commit that referenced this issue May 14, 2018

macOS: Don't use WAL for sqlite3 in /Volumes

179ef78

For #6049

guruz mentioned this issue May 14, 2018

macOS: Don't use WAL for sqlite3 in /Volumes #6526

Merged

ckamm added a commit that referenced this issue May 16, 2018

SyncJournal: Check file existence even for open dbs #6049

b3fd428

With WAL mode sqlite seems to occasionally crash when the underlying filesystem goes away.

ckamm added a commit that referenced this issue May 17, 2018

SyncJournal: Check file existence even for open dbs #6049

b1224cf

With WAL mode sqlite seems to occasionally crash when the underlying filesystem goes away.

ckamm added a commit that referenced this issue May 17, 2018

SyncJournal: Check file existence even for open dbs #6049

19e33d0

With WAL mode sqlite seems to occasionally crash when the underlying filesystem goes away. (cherry picked from commit b1224cf)

ckamm pushed a commit that referenced this issue May 17, 2018

macOS: Don't use WAL for sqlite3 in /Volumes

309c53c

For #6049

ckamm added the ReadyToTest QA, please validate the fix/enhancement label May 17, 2018

ckamm pushed a commit that referenced this issue May 17, 2018

macOS: Don't use WAL for sqlite3 in /Volumes

5d5e022

For #6049 (cherry picked from commit 309c53c)

This was referenced Jun 3, 2018

SyncJournal: Check file existence even for open dbs #6049 nextcloud/desktop#382

Merged

macOS: Don't use WAL for sqlite3 in /Volumes nextcloud/desktop#383

Merged

SamuAlfageme closed this as completed Jun 5, 2018

TheOneRing added a commit that referenced this issue Jul 14, 2022

Don't check for db exists

9ac1183

In context of #6049 a check for the existance of the db file was introduced. That check is performed before every db access... so serveral 100 times per second.

TheOneRing mentioned this issue Jul 14, 2022

Don't check for db exists #9918

Merged

TheOneRing added a commit that referenced this issue Jul 14, 2022

Don't check for db exists

41279de

In context of #6049 a check for the existance of the db file was introduced. That check is performed before every db access... so serveral 100 times per second.

TheOneRing added a commit that referenced this issue Jul 14, 2022

Don't check for db exists

698a156

In context of #6049 a check for the existance of the db file was introduced. That check is performed before every db access... so several 100 times per second.

TheOneRing added a commit that referenced this issue Jul 22, 2022

Don't check for db exists

8351736

In context of #6049 a check for the existance of the db file was introduced. That check is performed before every db access... so several 100 times per second.

TheOneRing added a commit that referenced this issue Jul 26, 2022

Don't check for db exists

9c615b1

In context of #6049 a check for the existance of the db file was introduced. That check is performed before every db access... so several 100 times per second.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Regression] Client crashes as soon as sync dir becomes unavailable or when sync dir is not available on startup #6049

[Regression] Client crashes as soon as sync dir becomes unavailable or when sync dir is not available on startup #6049

adroste commented Sep 23, 2017

guruz commented Sep 25, 2017

SamuAlfageme commented Sep 25, 2017 •

edited

Loading

valentijnscholten commented Sep 25, 2017

adroste commented Sep 25, 2017

valentijnscholten commented Sep 26, 2017 •

edited by SamuAlfageme

Loading

ckamm commented Sep 26, 2017

SamuAlfageme commented Sep 26, 2017

jturcotte commented Oct 2, 2017

jturcotte commented Oct 2, 2017

SamuAlfageme commented Oct 2, 2017

jturcotte commented Oct 2, 2017

ogoffart commented Oct 17, 2017

ckamm commented Oct 17, 2017

ogoffart commented Oct 17, 2017

guruz commented Oct 17, 2017

ogoffart commented Oct 17, 2017 •

edited

Loading

ckamm commented Nov 10, 2017

SamuAlfageme commented Mar 15, 2018

guruz commented Mar 19, 2018

SamuAlfageme commented Mar 19, 2018

guruz commented May 14, 2018

guruz commented May 14, 2018

ckamm commented May 15, 2018 •

edited

Loading

SamuAlfageme commented Jun 5, 2018

[Regression] Client crashes as soon as sync dir becomes unavailable or when sync dir is not available on startup #6049

[Regression] Client crashes as soon as sync dir becomes unavailable or when sync dir is not available on startup #6049

Comments

adroste commented Sep 23, 2017

Expected behaviour

Actual behaviour

Steps to reproduce

Client configuration

guruz commented Sep 25, 2017

SamuAlfageme commented Sep 25, 2017 • edited Loading

valentijnscholten commented Sep 25, 2017

adroste commented Sep 25, 2017

valentijnscholten commented Sep 26, 2017 • edited by SamuAlfageme Loading

ckamm commented Sep 26, 2017

SamuAlfageme commented Sep 26, 2017

jturcotte commented Oct 2, 2017

jturcotte commented Oct 2, 2017

SamuAlfageme commented Oct 2, 2017

jturcotte commented Oct 2, 2017

ogoffart commented Oct 17, 2017

ckamm commented Oct 17, 2017

ogoffart commented Oct 17, 2017

guruz commented Oct 17, 2017

ogoffart commented Oct 17, 2017 • edited Loading

ckamm commented Nov 10, 2017

SamuAlfageme commented Mar 15, 2018

guruz commented Mar 19, 2018

SamuAlfageme commented Mar 19, 2018

guruz commented May 14, 2018

guruz commented May 14, 2018

ckamm commented May 15, 2018 • edited Loading

SamuAlfageme commented Jun 5, 2018

SamuAlfageme commented Sep 25, 2017 •

edited

Loading

valentijnscholten commented Sep 26, 2017 •

edited by SamuAlfageme

Loading

ogoffart commented Oct 17, 2017 •

edited

Loading

ckamm commented May 15, 2018 •

edited

Loading