[SOLVED] Repeated "interrupted system call" on multiple Android devices

tomasz86 · March 10, 2020, 3:50am

I have a problem with “interrupted system call” errors on multiple Android devices. This seems to happen when a large number of small files is being scanned, e.g. when starting Syncthing. I have experienced the issue on three Android devices. All of them run Android 4.4.4 and Syncthing Fork 1.3.4.0. The file system in all cases is the default ext4.

I have searched around and found the old issue https://github.com/syncthing/syncthing-android/issues/85, which is supposed to have been fixed in 2015, so I am not sure whether these are related or not.

2020-03-10 03:36:27 Scanner (folder xxxxx-xxxxxx, item "xxxxxxxxx/xxxxxxxx/xxxxxxx/xxxxxxxxx/xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx/xxxxxx-xxxxxxx/xxxx-xxx-xxxxxxxx/xxxxxxxxx"): scan: readdirent: interrupted system call

calmh · March 10, 2020, 6:56am

@Catfriend1 Do you build with Go 1.14? If so, I’d hold off on that a while.

imsodin · March 10, 2020, 5:14pm

Looking at the issue, the lstat lobotomisation is due to a broken android filesystem/fuse implementation. That lobotomisation is not used by the third-party fs watcher library. Given this hasn’t come up anymore, I assume the underlying error in Android has been fixed sometime after Android 4.4.4. Given that’s ancient and long-time unsupported, I don’t think it’s worth investing any time in fixing this. You’ll just have to disable watching for changes.

calmh · March 10, 2020, 5:32pm

Given the lack of other reports of this issue maybe that means we can retire that specific hack now. Not that it particularly hurts to have in there, either.

Catfriend1 · March 10, 2020, 7:39pm

Could we have a RC to gather feedback from users on this? I also expect this isn’t important anymore… Android 4.4 devices also became rare and those who have one often lack enough RAM to run Syncthing with a collection of photos and music (just not telling about XY GB repos here).

calmh · March 10, 2020, 7:55pm

Every change goes into an RC.

tomasz86 · March 10, 2020, 11:40pm

Well, I can disable watching for changes, but I believe that the problem is something else than that.

I have removed the files on the devices in order to try to sync everything again. On one device, I have replaced Syncthing Fork with the official Syncthing application. The synchronisation completed successfully.

However, on another device, I have tried to synchronise the files again with Syncthing Fork, and after a few hours the application has silently crashed. This is what the log file looks like. It seems that all file operations end with “interrupted system call”.

[EEYCH] INFO: Puller (folder "XXX" (xxxxx-xxxxx), item "xxxxx/xxxxx"): opening temp file: open /storage/sdcard0/xxxxx/XXX/xxxxx/.xxxxxthing.xxxxx.tmp: interrupted system call
[EEYCH] INFO: Puller (folder "XXX" (xxxxx-xxxxx), item "xxxxx/xxxxx"): save: write /storage/sdcard0/xxxxx/XXX/xxxxx/.syncthing.xxxxx.tmp: interrupted system call
[EEYCH] INFO: Puller (folder "XXX" (xxxxx-xxxxx), item "xxxxx/xxxxx"): rename /storage/sdcard0/xxxxx/XXX/xxxxx/.syncthing.xxxxx.tmp /storage/sdcard0/xxxxx/XXX/xxxxx/xxxxx: interrupted system call
[EEYCH] INFO: Puller (folder "XXX" (xxxxx-xxxxx), item "xxxxx/xxxxx"): dst write: write /storage/sdcard0/xxxxx/XXX/xxxxx/.syncthing.xxxxx.tmp: interrupted system call
[EEYCH] INFO: Listen (BEP/relay): TLS handshake: read tcp x.x.x.x:43081->47.75.3.168:22067: i/o timeout

I have one thing in mind, which may possibly be the culprit and is completely unrelated to Syncthing. All the devices use the same specific I/O scheduler. I will try to change it to a different one, and then see whether there is any difference.

Please make sure that the code has in fact been fixed in newer versions of Android. There may be no reports because the hack is actually working and doing its job .

calmh · March 11, 2020, 5:44am

Thing is the hack is only for one specific operation, and it’s not used by the file system watcher which is the default now. Your problem seems much more pervasive than anything we’ve ever seen on stock android before.

tomasz86 · March 11, 2020, 6:15am

I have used both Syncthing and Syncthing Fork on Android for several months, but this problem has only started to show up very recently when I started to sync thousands of small files. Before, when the number of files was counted in hundreds, everything seemed to work fine.

I have done more testing:

The scan: readdirent: interrupted system call related to File Watcher happens both in Syncthing and Syncthing Fork.
The other interrupted system call errors have so far only occurred in Syncthing Fork, although I am not sure yet whether there is any correlation here, or just a pure luck.
Right now, I have managed to complete the scanning of 22,000+ files on two devices with no errors. I switched to the official Syncthing application in both cases. I also disabled File Watcher.
Changing the I/O scheduler in Android does not make any difference.

On a side note, I have also another issue, where Syncthing seems to crash during a long scanning operation on the device with 512 MB of RAM. I suspect the low amount of memory as the culprit, as there are no crashes on the two other devices with 1 GB and 2 GB of RAM respectively.

Unfortunately, the log file produced by the Syncthing application seems to be overwritten and restarted during the crash, so there is no information there about what exactly has happened. Is it possible to have the Android application keep the old log files, as it is the case with the Windows version of Syncthing (other than running the Linux version directly from terminal)?

tomasz86 · March 12, 2020, 6:20am

I have disabled watching for changes on all three devices, and right now all of them have successfully completed the initial synchronisation.

Two of them are using the official Syncthing application, while the third I have left on Syncthing Fork. I like the Fork mainly due to its ability to start and stop Syncthing on demand, but will probably leave everything in this state for now, just to see whether everything works correctly for a longer period of time.

I am still not sure though whether the issue is limited just to this specific version of Android, as it only manifested itself when trying to sync such a large number of files. There had been no such issues when the number of files was low, and I doubt that there are many other people also trying to sync tens of thousands of files on Android.

I may try to sync the same files on a newer version of Android later and see what happens there.

Edit

I have just seen this on the third device running Syncthing Fork with watching for changes disabled.

2020-03-12 06:12:04 Scanner (folder xxxxx-xxxxx, item "xxxxx/xxxxx"): scan: readdirent: interrupted system call

I guess that this would mean that it is unrelated to the file watcher… The two other devices running the official Syncthing have shown no errors so far.

Andy · March 12, 2020, 8:22am

I also use this APP, but doesnt find “About” in the upper left Menu. What I have seen under others is “Last Changes”

Catfriend1 · March 12, 2020, 5:59pm

Ah sorry , it is Syncthing-Fork>Menu>Settings>About

tomasz86 · March 13, 2020, 1:30am

Yeah, I am also not sure whether the Fork is actually responsible for the errors. However, for the last 2 days there have been no errors on the two devices with the official Syncthing application. The overall configuration is exactly the same - watching for changes disabled with 1h rescan interval.

Unfortunately, the values seem to be unavailable. They are shown as “N/A”.

Catfriend1 · March 13, 2020, 8:01am

Oh, so the shell calls made by the app to get the limit failed or outputted something unexpected what leads to n/a

tomasz86 · March 17, 2020, 6:24am

The results after a few days of testing:

The errors have also shown up on the two other devices running the official Syncthing application, but it was usually only a single file, and they went away after some time. This probably means that the errors are unrelated to the Android wrapper.
Since the errors seem to go away by themselves, Syncthing in this state is still usable.
Turning watching for changes on makes the errors appear almost immediately. With watching for changes turned off, the errors seem to appear much less frequently.

However, I have also experienced the same errors in Android 7.1 with Syncthing Fork 1.3.4.

2020-03-17 06:11:44 Scanner (folder xxxxx-xxxxx, item "xxxxx"): scan: readdirent: interrupted system call

In this case, there are only 2200 files, but almost all of them are tiny small files. My guess would be that the errors appear when Syncthing is scanning through a large number of small files very quickly.

tomasz86 · April 25, 2020, 11:54am

I wanted to refresh this topic, as I have been experimenting heavily with Android in the recent days, and have some new findings regarding the interrupted system call problem.

I can only speak for Android 4.4 and 7.1, because these are the versions that I have access to right now, but it seems that the whole issue has nothing to do with Syncthing per se. I was doing basic file operations on the same files, e.g.

rm -r folder_with_30000_files

and during the deletion process I got

rm failed for folder_with_30000_files, Interrupted system call

I got the same error messages both on EXT4 and F2FS partitions, so at this point, I would just say that this is a problem with Android being unable to process a large number of files at the same time. In other words, Android is just being Android, and nothing can probably be done about this.

Nevertheless, Syncthing still works, and the files are processed again during consecutive scans, so I am going to just leave this be and not bother any more.

Lastly, I just want to say thank you to everyone who has helped with investigating this issue .

tomasz86 · April 29, 2020, 12:05am

I have been trying to update my devices to the newest versions of Android available, and during the testing I got these panic logs. A dozen logs has been created in a short time span, but some of them are empty. The rest are either about interrupted system call or cannot allocate memory.

Please let me know whether these are worth anything.

panic: write /sdcard/.config/syncthing/index-v0.14.0.db/000025.log: interrupted system call

goroutine 33360 [running]:
github.com/syncthing/syncthing/lib/db.(*FileSet).Update(0x2818920, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0x2c12000, ...)
	syncthing/lib/db/set.go:144 +0x47c
github.com/syncthing/syncthing/lib/model.(*folder).updateLocals(0x2012680, 0x2c12000, 0x4, 0x3e8)
	syncthing/lib/model/folder.go:833 +0x58
github.com/syncthing/syncthing/lib/model.(*folder).updateLocalsFromPulling(0x2012680, 0x2c12000, 0x4, 0x3e8)
	syncthing/lib/model/folder.go:827 +0x34
github.com/syncthing/syncthing/lib/model.(*sendReceiveFolder).dbUpdaterRoutine.func1(0x2c12000, 0x4, 0x3e8, 0x22f, 0xea32accb)
	syncthing/lib/model/folder_sendrecv.go:1604 +0x314
github.com/syncthing/syncthing/lib/model.(*fileInfoBatch).flush(0x3b7bdd4, 0x3b7bd9c, 0x2)
	syncthing/lib/model/model.go:2699 +0x40
github.com/syncthing/syncthing/lib/model.(*sendReceiveFolder).dbUpdaterRoutine(0x2012680, 0x2422040)
	syncthing/lib/model/folder_sendrecv.go:1646 +0x3f4
github.com/syncthing/syncthing/lib/model.(*sendReceiveFolder).pullerIteration.func1(0x2012680, 0x2422040, 0xb4dc70, 0x32bcd50)
	syncthing/lib/model/folder_sendrecv.go:238 +0x24
created by github.com/syncthing/syncthing/lib/model.(*sendReceiveFolder).pullerIteration
	syncthing/lib/model/folder_sendrecv.go:236 +0x320

panic-20200428-193910.log (86.5 KB)

panic: open /sdcard/.config/syncthing/index-v0.14.0.db/000087.ldb: cannot allocate memory

goroutine 66 [running]:
github.com/syncthing/syncthing/lib/db.(*Snapshot).WithNeedTruncated(0x3f6f320, 0x199a071f, 0xf2a718f0, 0x5758b0d9, 0xfe07b19a, 0x541128d7, 0x76d84bca, 0xf37c72f9, 0x227660bd, 0x3f6f340)
	syncthing/lib/db/set.go:186 +0x204
github.com/syncthing/syncthing/lib/model.(*model).Completion(0x18241a0, 0x199a071f, 0xf2a718f0, 0x5758b0d9, 0xfe07b19a, 0x541128d7, 0x76d84bca, 0xf37c72f9, 0x227660bd, 0x1b07350, ...)
	syncthing/lib/model/model.go:795 +0x2a0
github.com/syncthing/syncthing/lib/model.(*folderSummaryService).sendSummary(0x1864e70, 0xb4ea30, 0x1b163c0, 0x1b07350, 0xb)
	syncthing/lib/model/folder_summary.go:351 +0x310
github.com/syncthing/syncthing/lib/model.(*folderSummaryService).calculateSummaries(0x1864e70, 0xb4ea30, 0x1b163c0)
	syncthing/lib/model/folder_summary.go:278 +0x190
github.com/syncthing/syncthing/lib/util.AsService.func1(0xb4ea30, 0x1b163c0, 0x1ae3040, 0x0)
	syncthing/lib/util/utils.go:183 +0x2c
github.com/syncthing/syncthing/lib/util.(*service).Serve(0x185b2f0)
	syncthing/lib/util/utils.go:247 +0x124
github.com/thejerf/suture.(*Supervisor).runService.func1(0x1894be0, 0x1, 0x40174210, 0x185b2f0)
	go/pkg/mod/github.com/thejerf/suture@v3.0.2+incompatible/supervisor.go:600 +0x34
created by github.com/thejerf/suture.(*Supervisor).runService
	go/pkg/mod/github.com/thejerf/suture@v3.0.2+incompatible/supervisor.go:588 +0x44

panic-20200428-210027.log (71.2 KB)

calmh · April 29, 2020, 5:57am

The panics are because (our usage of) the database doesn’t tolerate random write errors when it’s writing to disk. This is expected if the database-holding disk is flaky.

tomasz86 · April 29, 2020, 9:11am

Thank you very much for the explanation. Those panics occurred when the /sdcard partition was formatted to exFAT. I have now changed it to the regular FAT, and the files seem to be syncing correctly, albeit super slow, but I can live with that, as long as there no errors .

uok · April 29, 2020, 9:22am

You should also try another sd card.
Syncthing is very good at “detecting” faulty hardware.