nerzhul / ncsms-android

repository for the ncsms on Android
95 stars 38 forks source link

Error while doing full sync #182

Closed Idix closed 6 years ago

Idix commented 6 years ago
### Steps to reproduce 1. Reinit synchronisation cursor on account 2. Start a synchronisation ### Expected behaviour SMS messages should be synchronised to the owncloud instance ### Actual behaviour * No synchronisation is occuring. * Application is showing a synchronisation popup every 5 seconds. ### Server configuration **Nextcloud version:** Nextcloud 12.0.3 **OCsms version:** 1.21.2 **PHP version:** PHP 5.6.30 **Webserver:** Nginx **HTTPS:** Yes with lets encrypt certificate ### Client configuration **Android version:** 7.1.2 / LineageOS 14.1-20180207 **Phone:** Samsung galaxy S2 / i9100 **Nextcloud SMS app version:** 2.0.1 from f-droid ### Logs ``` 02-15 08:58:02.123 3919 3919 W View : requestLayout() improperly called by com.android.systemui.statusbar.NotificationOverflowIconsView{2f738b4 V.E...... ......ID 90,33-450,33 #7f12027a app:id/overflow_icons_view} during layout: running second layout pass 02-15 08:58:02.124 3919 3919 W View : requestLayout() improperly called by StatusBarIconView(slot= icon=StatusBarIcon(icon=Icon(typ=RESOURCE pkg=android id=0x010806e9) visible user=-1 ) notification=Notification(pri=-1 contentView=null vibrate=null sound=null tick defaults=0x0 flags=0x2 color=0xff607d8b vis=PUBLIC)) during layout: running second layout pass 02-15 08:58:02.124 3919 3919 W View : requestLayout() improperly called by com.android.systemui.statusbar.NotificationOverflowContainer{944e37f VFE...C.. ......ID 0,0-480,66} during layout: running second layout pass 02-15 08:58:03.685 5740 7881 I ASyncSMSSync: Server API version: 1 02-15 08:58:03.981 5740 7881 I OCSMSOwnCloudClient: SMS Push request said: status true - OK 02-15 08:58:03.987 5740 7881 I OCSMSOwnCloudClient: LastMessageDate set to: 0 02-15 08:58:04.030 5740 7881 I AndroidSmsFetcher: bufferMessagesSinceDate for INBOX sinceDate 0 02-15 08:58:04.122 5740 7881 I AndroidSmsFetcher: Retrieved 13 messages. 02-15 08:58:04.150 5740 7881 I AndroidSmsFetcher: 13 messages read from content://sms/inbox 02-15 08:58:04.166 5740 7881 I AndroidSmsFetcher: bufferMessagesSinceDate for SENT sinceDate 0 02-15 08:58:04.207 5740 7881 I AndroidSmsFetcher: Retrieved 18 messages. 02-15 08:58:04.244 5740 7881 I AndroidSmsFetcher: 18 messages read from content://sms/sent 02-15 08:58:04.260 5740 7881 I AndroidSmsFetcher: bufferMessagesSinceDate for DRAFTS sinceDate 0 02-15 08:58:04.288 4146 4158 E SmsProvider: Invalid request: content://sms/drafts 02-15 08:58:04.299 5740 7881 I AndroidSmsFetcher: No message retrieved. 02-15 08:58:04.760 3919 3919 W View : requestLayout() improperly called by com.android.systemui.statusbar.NotificationOverflowIconsView{2f738b4 V.E...... ......ID 90,33-450,33 #7f12027a app:id/overflow_icons_view} during layout: running second layout pass 02-15 08:58:04.761 3919 3919 W View : requestLayout() improperly called by StatusBarIconView(slot= icon=StatusBarIcon(icon=Icon(typ=RESOURCE pkg=android id=0x010806e9) visible user=-1 ) notification=Notification(pri=-1 contentView=null vibrate=null sound=null tick defaults=0x0 flags=0x2 color=0xff607d8b vis=PUBLIC)) during layout: running second layout pass 02-15 08:58:04.761 3919 3919 W View : requestLayout() improperly called by com.android.systemui.statusbar.NotificationOverflowContainer{944e37f VFE...C.. ......ID 0,0-480,66} during layout: running second layout pass 02-15 08:58:06.890 5740 7881 I ASyncSMSSync: Server API version: 1 02-15 08:58:07.178 5740 7881 I OCSMSOwnCloudClient: SMS Push request said: status true - OK 02-15 08:58:07.185 5740 7881 I OCSMSOwnCloudClient: LastMessageDate set to: 0 02-15 08:58:07.241 5740 7881 I AndroidSmsFetcher: bufferMessagesSinceDate for INBOX sinceDate 0 02-15 08:58:07.396 5740 7881 I AndroidSmsFetcher: Retrieved 13 messages. 02-15 08:58:07.440 5740 7881 I AndroidSmsFetcher: 13 messages read from content://sms/inbox 02-15 08:58:07.460 5740 7881 I AndroidSmsFetcher: bufferMessagesSinceDate for SENT sinceDate 0 02-15 08:58:07.513 5740 7881 I AndroidSmsFetcher: Retrieved 18 messages. 02-15 08:58:07.572 5740 7881 I AndroidSmsFetcher: 18 messages read from content://sms/sent 02-15 08:58:07.591 5740 7881 I AndroidSmsFetcher: bufferMessagesSinceDate for DRAFTS sinceDate 0 02-15 08:58:07.628 4146 5460 E SmsProvider: Invalid request: content://sms/drafts 02-15 08:58:07.642 5740 7881 I AndroidSmsFetcher: No message retrieved. ```
nerzhul commented 6 years ago

hello the sync popup is the real sync cursor popup is shown on each transfer to server. I don't see any error in the log you shown, all seems good.

Idix commented 6 years ago

Hi,

I have two problems with this :

Thanks, Idix

Idix commented 6 years ago

Hi,

After some digging I found why the messages don't get synchronised. The application is sending the messages with a negative timestamp.

Here is an extract received by nextcloud, numbers and messages have been removed.

array(73) {
  ...
  [70]=>
  array(8) {
    ["_id"]=>
    int(68)
    ["mbox"]=>
    int(1)
    ["type"]=>
    int(2)
    ["date"]=>
    int(-1615270374)
    ["body"]=>
    string(4) "XXXXX"
    ["address"]=>
    string(17) "XXXXXX"
    ["read"]=>
    string(4) "true"
    ["seen"]=>
    string(4) "true"
  }
  [71]=>
  array(8) {
    ["_id"]=>
    int(69)
    ["mbox"]=>
    int(1)
    ["type"]=>
    int(2)
    ["date"]=>
    int(-1615264449)
    ["body"]=>
    string(20) "XXXX"
    ["address"]=>
    string(17) "XXXX"
    ["read"]=>
    string(4) "true"
    ["seen"]=>
    string(4) "true"
  }
  [72]=>
  array(8) {
    ["_id"]=>
    int(71)
    ["mbox"]=>
    int(1)
    ["type"]=>
    int(2)
    ["date"]=>
    int(-1615158797)
    ["body"]=>
    string(9) "XXXX"
    ["address"]=>
    string(17) "XXXX"
    ["read"]=>
    string(4) "true"
    ["seen"]=>
    string(4) "true"
  }
}
nerzhul commented 6 years ago

@Idix interesting output, seems to be a underflow somewhere on the client, or a conversion error.

nerzhul commented 6 years ago

I pushed 2.0.3 tag, it will be pushed to play store soon. I think it's a conversion issue between gomobile & java, due to the 32b part in golang, now date is correctly in 64b

Idix commented 6 years ago

Thanks @nerzhul, any chance that you send me the build in some manner ? I don't have the play store on my phone (no gapps) and f-droid takes a week or so to push an update.

nerzhul commented 6 years ago

Send me a mail at contact at unix-experience dot fr and i will send you the APK

Idix commented 6 years ago

Hi @nerzhul, it was indeed an issue with underflow of the timestamp. I still have another problem but I will open a new issue for it.