search

syncthing / syncthing-android

Wrapper of syncthing for Android.
https://syncthing.net/
Mozilla Public License 2.0
3.47k stars 390 forks source link

Syncthing Binary Crashed - error code 2 #92

Closed alexxtasi closed 9 years ago

alexxtasi commented 10 years ago

Hi, I just updated syncthing to version 0.4.8 using Google Play (I suppose this is the version due to the comments... "disallow adding the same node multiple times" ...) When running, this popup comes:

Syncthing Binary Crashed The syncthing binary has exited with error code 2. If this error persists, try reinstalling the app and restarting your device.

I've tried both but still happens...

any suggestions ? (I am using android-2.3.7 - CyanogenMode-7.2.0-blade, on ZTE-Blade)

Nutomic commented 9 years ago

Seems like it happens when restarting syncthing after network connectivity changes, and maybe the old instance isn't fully shut down yet.

I'll make an apk with extra debugging so we see if that's really what's happening.

Nutomic commented 9 years ago

Also, can you still access localhost:8080 in a browser after the crash?

alexxtasi commented 9 years ago

I'll try it again and report

Nutomic commented 9 years ago

Here's an apk with additional logging

It should print a message (with tag SyncthingRunnable) when syncthing is restarted, which I suspect happens immediately before the crash.

Edit: You can also just install 0.5.9 from Google Play or F-Droid ;)

alexxtasi commented 9 years ago

for your question... both http://localhost:8080, http://127.0.0.1:8080 say web page not available after the crash

I'll install the new apk and test as soon as possible.

alexxtasi commented 9 years ago

I provide two log files.

1st - the error code 1 happened with no wi-fi activation

11-17 16:57:41.160 I/ActivityManager(  199): Starting: Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.nutomic.syncthingandroid/.activities.MainActivity } from pid 284
11-17 16:57:41.250 I/ActivityManager(  199): Start proc com.nutomic.syncthingandroid for activity com.nutomic.syncthingandroid/.activities.MainActivity: pid=1463 uid=10080 gids={1015, 3003}
11-17 16:57:43.100 I/ActivityManager(  199): Displayed com.nutomic.syncthingandroid/.activities.MainActivity: +1s854ms (total +5s208ms)
11-17 16:57:43.240 I/SyncthingNativeCode( 1463): 14:57:43 INFO: Generating RSA key and certificate...
11-17 17:00:44.530 I/SyncthingNativeCode( 1463): 15:00:44 INFO: Device ID: PKO2E7K-JRDJXQ4-TFESGER-IC5GSTQ-NXK5WCD-HEDOKIA-WJU6HXN-JJIGHAF
11-17 17:00:44.840 E/dalvikvm( 1463): Could not find class 'android.content.ClipboardManager', referenced from method com.nutomic.syncthingandroid.syncthing.RestApi.copyDeviceId
11-17 17:00:44.840 W/dalvikvm( 1463): VFY: unable to resolve check-cast 42 (Landroid/content/ClipboardManager;) in Lcom/nutomic/syncthingandroid/syncthing/RestApi;
11-17 17:00:44.850 D/dalvikvm( 1463): VFY: dead code 0x002b-003b in Lcom/nutomic/syncthingandroid/syncthing/RestApi;.copyDeviceId (Ljava/lang/String;)V
11-17 17:00:44.860 I/SyncthingService( 1463): Web GUI will be available at http://127.0.0.1:8080
11-17 17:00:44.860 I/SyncthingService( 1463): Starting syncthing according to current state and preferences
11-17 17:00:45.400 W/PostTask( 1463):   at com.nutomic.syncthingandroid.syncthing.PostTask.doInBackground(PostTask.java:49)
11-17 17:00:45.400 W/PostTask( 1463):   at com.nutomic.syncthingandroid.syncthing.PostTask.doInBackground(PostTask.java:22)
11-17 17:01:09.130 I/SyncthingNativeCode( 1463): [PKO2E] 15:01:09 INFO: syncthing v0.10.5 (go1.3.3 linux-arm android) felix@T420 2014-11-04 04:11:54 UTC
11-17 17:01:09.130 I/SyncthingNativeCode( 1463): [PKO2E] 15:01:09 INFO: My ID: PKO2E7K-JRDJXQ4-TFESGER-IC5GSTQ-NXK5WCD-HEDOKIA-WJU6HXN-JJIGHAF
11-17 17:01:09.340 I/SyncthingNativeCode( 1463): [PKO2E] 15:01:09 INFO: Starting web GUI on http://127.0.0.1:8080/
11-17 17:01:09.340 I/SyncthingNativeCode( 1463): [PKO2E] 15:01:09 INFO: Loading HTTPS certificate: open /data/data/com.nutomic.syncthingandroid/files/https-cert.pem: no such file or directory
11-17 17:01:09.350 I/SyncthingNativeCode( 1463): [PKO2E] 15:01:09 INFO: Creating new HTTPS certificate
11-17 17:01:09.350 I/SyncthingNativeCode( 1463): [PKO2E] 15:01:09 INFO: Generating RSA key and certificate...
11-17 17:05:33.770 I/SyncthingNativeCode( 1463): [PKO2E] 15:05:33 INFO: Starting UPnP discovery...
11-17 17:05:33.770 I/SyncthingNativeCode( 1463): [PKO2E] 15:05:33 INFO: write udp4: network is unreachable
11-17 17:05:33.770 I/SyncthingNativeCode( 1463): [PKO2E] 15:05:33 INFO: write udp4: network is unreachable
11-17 17:05:33.770 I/SyncthingNativeCode( 1463): [PKO2E] 15:05:33 INFO: UPnP discovery complete (found 0 devices).
11-17 17:05:33.780 I/SyncthingNativeCode( 1463): [PKO2E] 15:05:33 INFO: Starting local discovery announcements
11-17 17:05:33.780 I/SyncthingNativeCode( 1463): [PKO2E] 15:05:33 INFO: Local discovery over IPv6 unavailable
11-17 17:05:33.780 I/SyncthingNativeCode( 1463): [PKO2E] 15:05:33 INFO: Starting global discovery announcements
11-17 17:05:33.780 I/SyncthingNativeCode( 1463): [PKO2E] 15:05:33 OK: Ready to synchronize camera (read only; no external updates accepted)
11-17 17:05:33.790 I/SyncthingNativeCode( 1463): [PKO2E] 15:05:33 INFO: Device PKO2E7K-JRDJXQ4-TFESGER-IC5GSTQ-NXK5WCD-HEDOKIA-WJU6HXN-JJIGHAF is "localhost" at [dynamic]
11-17 17:05:33.830 I/SyncthingService( 1463): Web GUI has come online at http://127.0.0.1:8080
11-17 17:05:34.420 I/RestApi ( 1463): Syncthing version is v0.10.5
11-17 17:05:49.520 I/SyncthingNativeCode( 1463): [PKO2E] 15:05:49 INFO: Completed initial scan (ro) of folder camera
11-17 17:33:53.080 I/ActivityManager(  199): Starting: Intent { act=folder_settings_fragment cmp=com.nutomic.syncthingandroid/.activities.SettingsActivity (has extras) } from pid 1463
11-17 17:33:53.690 I/ActivityManager(  199): Displayed com.nutomic.syncthingandroid/.activities.SettingsActivity: +568ms
11-17 17:33:57.580 I/ActivityManager(  199): Starting: Intent { cmp=com.nutomic.syncthingandroid/.activities.FolderPickerActivity } from pid 1463
11-17 17:33:57.660 I/dalvikvm( 1463): Could not find method com.nutomic.syncthingandroid.activities.FolderPickerActivity.getExternalFilesDirs, referenced from method com.nutomic.syncthingandroid.activities.FolderPickerActivity.onCreate
11-17 17:33:57.660 W/dalvikvm( 1463): VFY: unable to resolve virtual method 12176: Lcom/nutomic/syncthingandroid/activities/FolderPickerActivity;.getExternalFilesDirs (Ljava/lang/String;)[Ljava/io/File;
11-17 17:33:57.660 D/dalvikvm( 1463): VFY: dead code 0x004e-0055 in Lcom/nutomic/syncthingandroid/activities/FolderPickerActivity;.onCreate (Landroid/os/Bundle;)V
11-17 17:33:58.030 I/ActivityManager(  199): Displayed com.nutomic.syncthingandroid/.activities.FolderPickerActivity: +381ms
11-17 17:34:40.510 I/SyncthingService( 1463): Starting syncthing according to current state and preferences
11-17 17:34:41.430 I/SyncthingNativeCode( 1463): [PKO2E] 15:34:41 INFO: Shutting down
11-17 17:34:41.430 I/SyncthingNativeCode( 1463): [PKO2E] 15:34:41 OK: Exiting
11-17 17:34:41.990 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:41.990 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:42.270 W/PostTask( 1463):   at com.nutomic.syncthingandroid.syncthing.PostTask.doInBackground(PostTask.java:49)
11-17 17:34:42.270 W/PostTask( 1463):   at com.nutomic.syncthingandroid.syncthing.PostTask.doInBackground(PostTask.java:22)
11-17 17:34:42.430 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:42.430 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:42.670 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:42.670 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:43.790 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:43.790 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:44.660 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:44.660 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:45.910 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:45.910 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:47.490 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:47.490 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:47.860 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:47.860 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:49.330 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:49.330 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:49.900 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:49.900 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:50.280 I/ActivityManager(  199): Starting: Intent { cmp=com.nutomic.syncthingandroid/.activities.MainActivity bnds=[0,533][480,629] } from pid -1
11-17 17:34:50.280 W/ActivityManager(  199): startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { cmp=com.nutomic.syncthingandroid/.activities.MainActivity bnds=[0,533][480,629] }
11-17 17:34:51.050 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:51.050 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:51.900 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:51.900 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:52.980 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:52.980 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:53.730 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:53.730 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:55.220 I/SyncthingService( 1463): Shutting down service
11-17 17:34:55.850 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:62)
11-17 17:34:55.850 W/GetTask ( 1463):   at com.nutomic.syncthingandroid.syncthing.GetTask.doInBackground(GetTask.java:26)
11-17 17:34:57.920 W/PostTask( 1463):   at com.nutomic.syncthingandroid.syncthing.PostTask.doInBackground(PostTask.java:49)
11-17 17:34:57.920 W/PostTask( 1463):   at com.nutomic.syncthingandroid.syncthing.PostTask.doInBackground(PostTask.java:22)
11-17 17:34:58.100 I/ActivityManager(  199): Starting: Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=com.nutomic.syncthingandroid/.activities.MainActivity } from pid 284
11-17 17:34:59.820 I/ActivityManager(  199): Displayed com.nutomic.syncthingandroid/.activities.MainActivity: +1s570ms (total +3s750ms)
11-17 17:35:01.810 I/SyncthingService( 1463): Web GUI will be available at http://127.0.0.1:8080
11-17 17:35:01.810 I/SyncthingService( 1463): Starting syncthing according to current state and preferences
11-17 17:35:03.520 W/PostTask( 1463):   at com.nutomic.syncthingandroid.syncthing.PostTask.doInBackground(PostTask.java:49)
11-17 17:35:03.520 W/PostTask( 1463):   at com.nutomic.syncthingandroid.syncthing.PostTask.doInBackground(PostTask.java:22)
11-17 17:35:15.910 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:15 INFO: syncthing v0.10.5 (go1.3.3 linux-arm android) felix@T420 2014-11-04 04:11:54 UTC
11-17 17:35:15.910 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:15 INFO: My ID: PKO2E7K-JRDJXQ4-TFESGER-IC5GSTQ-NXK5WCD-HEDOKIA-WJU6HXN-JJIGHAF
11-17 17:35:16.570 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:16 INFO: Starting web GUI on http://127.0.0.1:8080/
11-17 17:35:50.350 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:50 INFO: syncthing v0.10.5 (go1.3.3 linux-arm android) felix@T420 2014-11-04 04:11:54 UTC
11-17 17:35:50.370 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:50 INFO: My ID: PKO2E7K-JRDJXQ4-TFESGER-IC5GSTQ-NXK5WCD-HEDOKIA-WJU6HXN-JJIGHAF
11-17 17:35:50.400 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:50 FATAL: Cannot open database: resource temporarily unavailable - Is another copy of Syncthing already running?
11-17 17:35:50.400 W/SyncthingNativeCode( 1463): Syncthing binary crashed with error code 1
11-17 17:35:58.080 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 INFO: Starting UPnP discovery...
11-17 17:35:58.090 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 INFO: write udp4: network is unreachable
11-17 17:35:58.090 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 INFO: write udp4: network is unreachable
11-17 17:35:58.090 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 INFO: UPnP discovery complete (found 0 devices).
11-17 17:35:58.090 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 INFO: Starting local discovery announcements
11-17 17:35:58.090 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 INFO: Local discovery over IPv6 unavailable
11-17 17:35:58.090 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 INFO: Starting global discovery announcements
11-17 17:35:58.090 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 OK: Ready to synchronize camera (read only; no external updates accepted)
11-17 17:35:58.090 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 OK: Ready to synchronize sync (read-write)
11-17 17:35:58.090 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 INFO: Folder "sync" is running with LenientMtimes workaround. Syncing may not work properly.
11-17 17:35:58.090 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 INFO: Device PKO2E7K-JRDJXQ4-TFESGER-IC5GSTQ-NXK5WCD-HEDOKIA-WJU6HXN-JJIGHAF is "localhost" at [dynamic]
11-17 17:35:58.120 I/SyncthingService( 1463): Web GUI has come online at http://127.0.0.1:8080
11-17 17:35:58.450 I/SyncthingNativeCode( 1463): [PKO2E] 15:35:58 INFO: Completed initial scan (ro) of folder camera
11-17 17:35:58.680 I/SyncthingService( 1463): Web GUI has come online at http://127.0.0.1:8080
11-17 17:35:59.170 I/RestApi ( 1463): Syncthing version is v0.10.5
11-17 17:35:59.750 I/RestApi ( 1463): Syncthing version is v0.10.5

2nd - error code 1 happened after wifi activation

11-17 17:51:43.960 I/ActivityManager(  199): Starting: Intent { cmp=com.nutomic.syncthingandroid/.activities.MainActivity bnds=[0,533][480,629] } from pid -1
11-17 17:51:43.960 W/ActivityManager(  199): startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { cmp=com.nutomic.syncthingandroid/.activities.MainActivity bnds=[0,533][480,629] }
11-17 17:52:06.520 I/SyncthingNativeCode( 1463): [PKO2E] 15:52:06 INFO: syncthing v0.10.5 (go1.3.3 linux-arm android) felix@T420 2014-11-04 04:11:54 UTC
11-17 17:52:06.530 I/SyncthingNativeCode( 1463): [PKO2E] 15:52:06 INFO: My ID: PKO2E7K-JRDJXQ4-TFESGER-IC5GSTQ-NXK5WCD-HEDOKIA-WJU6HXN-JJIGHAF
11-17 17:52:06.710 I/SyncthingNativeCode( 1463): [PKO2E] 15:52:06 FATAL: Cannot open database: resource temporarily unavailable - Is another copy of Syncthing already running?
11-17 17:52:06.730 W/SyncthingNativeCode( 1463): Syncthing binary crashed with error code 1
11-17 17:53:13.640 I/ActivityManager(  199): Starting: Intent { cmp=com.nutomic.syncthingandroid/.activities.WebGuiActivity } from pid 1463
11-17 17:53:13.980 I/ActivityManager(  199): Displayed com.nutomic.syncthingandroid/.activities.WebGuiActivity: +337ms
11-17 17:56:09.990 I/ActivityManager(  199): Starting: Intent { cmp=com.nutomic.syncthingandroid/.activities.MainActivity bnds=[0,533][480,629] } from pid -1
11-17 17:56:09.990 W/ActivityManager(  199): startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { cmp=com.nutomic.syncthingandroid/.activities.MainActivity bnds=[0,533][480,629] }
11-17 17:57:05.360 I/ActivityManager(  199): Starting: Intent { cmp=com.nutomic.syncthingandroid/.activities.MainActivity bnds=[0,533][480,629] } from pid -1
11-17 17:57:05.360 W/ActivityManager(  199): startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { cmp=com.nutomic.syncthingandroid/.activities.MainActivity bnds=[0,533][480,629] }

In both cases I can't see SyncthingRunnable in the log , am I doing the right thing ? (catching syncthing on catlog) Also in both cases syncthing seem to work "fine" after the error appears (also the localhost:8080) !!

what do you thing ? regards

Nutomic commented 9 years ago

Ah it could also happen because you set "Always run in background" and have "Sync only when chargin" checked, and then change the charging state.

In some way, it seems to start a new instance before the old one is shut down. Can you figure out any specific steps to reproduce, including your current settings?

Otherwise I'll try to log some timings for the starting and stopping.

alexxtasi commented 9 years ago

Actually I have not done any changes in the configuration. I have not set "Always run in background" or "Sync only when charging" checked. Just while the test (coping the log) my phone was charging ! (by the way, these options seem to be disabled - cannot check the box)

Can not find out any steps to reproduce, sorry

In my configuration, I have just setup a node and a shared directory (with about 25 mp3 or ogg files there), which was setup and synced at the first place (since my first syncthing installation).

Maybe at the end, this is minor (sometimes happens sometimes not)... I will report again if I find any steps for this