search

wallabag / android-app

Android application to read your articles saved in your wallabag. You can also easily add new articles.
https://www.wallabag.org
GNU General Public License v3.0
483 stars 259 forks source link

Empty unread/favorites/archived lists #793

Closed regisb closed 5 years ago

regisb commented 5 years ago

Issue details

Duplicate?

The symptoms are similar to #738, but it does not occur in the same circumstances.

Actual behaviour

After installing the Android app and configuring it to point to my own Wallabag server, the article list remains empty. The credentials are correct, as I can see 200 responses from my web server (see web server access logs below).

Note that there is a large-ish (2500) number of archived entries on this server.

Expected behaviour

When I update the "unread" list, I expect to see a list of 111 unread articles.

Steps to reproduce the issue

  1. Install app
  2. Point to personal server with credentials
  3. Wait for update article list

Environment details

Logs

wallabag server

N/A

Web server

Nginx access logs:

10.0.3.1 - - [17/Jun/2019:14:25:14 +0200] "GET /api/entries.json?perPage=30&sort=created&page=1&order=asc&since=0 HTTP/1.0" 200 634524 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:15 +0200] "GET /api/entries.json?perPage=30&sort=created&page=2&order=asc&since=0 HTTP/1.0" 200 509798 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:16 +0200] "GET /api/entries.json?perPage=30&sort=created&page=3&order=asc&since=0 HTTP/1.0" 200 538295 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:17 +0200] "GET /api/entries.json?perPage=30&sort=created&page=4&order=asc&since=0 HTTP/1.0" 200 491709 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:18 +0200] "GET /api/entries.json?perPage=30&sort=created&page=5&order=asc&since=0 HTTP/1.0" 200 548984 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:19 +0200] "GET /api/entries.json?perPage=30&sort=created&page=6&order=asc&since=0 HTTP/1.0" 200 521605 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:20 +0200] "GET /api/entries.json?perPage=30&sort=created&page=7&order=asc&since=0 HTTP/1.0" 200 533099 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:20 +0200] "GET /api/entries.json?perPage=30&sort=created&page=8&order=asc&since=0 HTTP/1.0" 200 693325 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:22 +0200] "GET /api/entries.json?perPage=30&sort=created&page=9&order=asc&since=0 HTTP/1.0" 200 731405 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:23 +0200] "GET /api/entries.json?perPage=30&sort=created&page=10&order=asc&since=0 HTTP/1.0" 200 745079 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:24 +0200] "GET /api/entries.json?perPage=30&sort=created&page=11&order=asc&since=0 HTTP/1.0" 200 716733 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:25 +0200] "GET /api/entries.json?perPage=30&sort=created&page=12&order=asc&since=0 HTTP/1.0" 200 659083 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:27 +0200] "GET /api/entries.json?perPage=30&sort=created&page=13&order=asc&since=0 HTTP/1.0" 200 656977 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:28 +0200] "GET /api/entries.json?perPage=30&sort=created&page=14&order=asc&since=0 HTTP/1.0" 200 465842 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:29 +0200] "GET /api/entries.json?perPage=30&sort=created&page=15&order=asc&since=0 HTTP/1.0" 200 341984 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:30 +0200] "GET /api/entries.json?perPage=30&sort=created&page=16&order=asc&since=0 HTTP/1.0" 200 386792 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:31 +0200] "GET /api/entries.json?perPage=30&sort=created&page=17&order=asc&since=0 HTTP/1.0" 200 951247 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:32 +0200] "GET /api/entries.json?perPage=30&sort=created&page=18&order=asc&since=0 HTTP/1.0" 200 1361858 "-" "okhttp/3.13.1"
10.0.3.1 - - [17/Jun/2019:14:25:34 +0200] "GET /api/entries.json?perPage=30&sort=created&page=19&order=asc&since=0 HTTP/1.0" 200 250196 "-" "okhttp/3.

Your experience with wallabag Android app

Wallabag is an incredibly useful app that I've been using since 2012. The Android app stopped working when I upgraded my phone.

di72nn commented 5 years ago

Hey, thanks for the report!

Can you get logcat output?

regisb commented 5 years ago

Here is a sample of the logs:

06-17 17:05:45.996  1181  3909 E NotificationService: No Channel found for pkg=fr.gaulupeau.apps.InThePoche, channelId=null, id=2, tag=EventProcessor, opPkg=fr.gaulupeau.apps.InThePoche, callingUid=10162, userId=0, incomingUserId=0, notificationUid=10162, notification=Notification(channel=null pri=0 contentView=null vibrate=null sound=null defaults=0x0 flags=0x2 color=0x00000000 vis=PRIVATE)
06-17 17:05:45.997 29115 29115 D MainActivity: onUpdateArticlesProgressEvent
06-17 17:05:46.000 29115 29502 D Updater : performUpdate() articleChanges: [ADDED]
06-17 17:05:46.022 29115 29502 I chatty  : uid=10162(fr.gaulupeau.apps.InThePoche) IntentService[M identical 28 lines
06-17 17:05:46.022 29115 29502 D Updater : performUpdate() articleChanges: [ADDED]
06-17 17:05:46.022 29115 29502 V Updater : performUpdate() performing articleDao.insertInTx()
06-17 17:05:46.043 29115 29502 V Updater : performUpdate() done articleDao.insertInTx()
06-17 17:05:46.043 29115 29502 D EventProcessor: onUpdateArticlesProgressEvent() started
06-17 17:05:46.044  1181  3909 E NotificationService: No Channel found for pkg=fr.gaulupeau.apps.InThePoche, channelId=null, id=2, tag=EventProcessor, opPkg=fr.gaulupeau.apps.InThePoche, callingUid=10162, userId=0, incomingUserId=0, notificationUid=10162, notification=Notification(channel=null pri=0 contentView=null vibrate=null sound=null defaults=0x0 flags=0x2 color=0x00000000 vis=PRIVATE)
06-17 17:05:46.044 29115 29115 D MainActivity: onUpdateArticlesProgressEvent
06-17 17:05:46.034 29115 29115 W RenderThread: type=1400 audit(0.0:920849): avc: denied { read } for name="u:object_r:vendor_default_prop:s0" dev="tmpfs" ino=15849 scontext=u:r:untrusted_app:s0:c162,c256,c512,c768 tcontext=u:object_r:vendor_default_prop:s0 tclass=file permissive=0
06-17 17:05:46.050 29115 29134 E libc    : Access denied finding property "vendor.debug.egl.swapinterval"
06-17 17:05:46.763 29115 29502 E MainService: updateArticles() exception
06-17 17:05:46.763 29115 29502 E MainService: com.squareup.moshi.JsonDataException: Expected an int but was NULL at path $._embedded.items[22].reading_time
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.JsonUtf8Reader.nextInt(JsonUtf8Reader.java:870)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.StandardJsonAdapters$7.fromJson(StandardJsonAdapters.java:162)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.StandardJsonAdapters$7.fromJson(StandardJsonAdapters.java:160)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.ClassJsonAdapter$FieldBinding.read(ClassJsonAdapter.java:205)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.ClassJsonAdapter.fromJson(ClassJsonAdapter.java:167)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.JsonAdapter$2.fromJson(JsonAdapter.java:128)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.CollectionJsonAdapter.fromJson(CollectionJsonAdapter.java:76)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.CollectionJsonAdapter$2.fromJson(CollectionJsonAdapter.java:53)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.JsonAdapter$2.fromJson(JsonAdapter.java:128)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.ClassJsonAdapter$FieldBinding.read(ClassJsonAdapter.java:205)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.ClassJsonAdapter.fromJson(ClassJsonAdapter.java:167)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.JsonAdapter$2.fromJson(JsonAdapter.java:128)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.ClassJsonAdapter$FieldBinding.read(ClassJsonAdapter.java:205)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.ClassJsonAdapter.fromJson(ClassJsonAdapter.java:167)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.JsonAdapter$2.fromJson(JsonAdapter.java:128)
06-17 17:05:46.763 29115 29502 E MainService:   at com.squareup.moshi.JsonAdapter.fromJson(JsonAdapter.java:35)
06-17 17:05:46.763 29115 29502 E MainService:   at retrofit2.converter.moshi.MoshiResponseBodyConverter.convert(MoshiResponseBodyConverter.java:42)
06-17 17:05:46.763 29115 29502 E MainService:   at retrofit2.converter.moshi.MoshiResponseBodyConverter.convert(MoshiResponseBodyConverter.java:25)
06-17 17:05:46.763 29115 29502 E MainService:   at retrofit2.ServiceMethod.toResponse(ServiceMethod.java:119)
06-17 17:05:46.763 29115 29502 E MainService:   at retrofit2.OkHttpCall.parseResponse(OkHttpCall.java:218)
06-17 17:05:46.763 29115 29502 E MainService:   at retrofit2.OkHttpCall.execute(OkHttpCall.java:180)
06-17 17:05:46.763 29115 29502 E MainService:   at retrofit2.ExecutorCallAdapterFactory$ExecutorCallbackCall.execute(ExecutorCallAdapterFactory.java:91)
06-17 17:05:46.763 29115 29502 E MainService:   at com.di72nn.stuff.wallabag.apiwrapper.WallabagService.getArticles(WallabagService.java:571)
06-17 17:05:46.763 29115 29502 E MainService:   at com.di72nn.stuff.wallabag.apiwrapper.WallabagService.access$100(WallabagService.java:25)
06-17 17:05:46.763 29115 29502 E MainService:   at com.di72nn.stuff.wallabag.apiwrapper.WallabagService$ArticlesQueryBuilder.execute(WallabagService.java:188)
06-17 17:05:46.763 29115 29502 E MainService:   at com.di72nn.stuff.wallabag.apiwrapper.WallabagService$ArticlesPageIterator.hasNext(WallabagService.java:425)
06-17 17:05:46.763 29115 29502 E MainService:   at fr.gaulupeau.apps.Poche.network.Updater.performUpdate(Updater.java:176)
06-17 17:05:46.763 29115 29502 E MainService:   at fr.gaulupeau.apps.Poche.network.Updater.update(Updater.java:81)
06-17 17:05:46.763 29115 29502 E MainService:   at fr.gaulupeau.apps.Poche.service.MainService.updateArticles(MainService.java:430)
06-17 17:05:46.763 29115 29502 E MainService:   at fr.gaulupeau.apps.Poche.service.MainService.onHandleIntent(MainService.java:100)
06-17 17:05:46.763 29115 29502 E MainService:   at android.app.IntentService$ServiceHandler.handleMessage(IntentService.java:76)
06-17 17:05:46.763 29115 29502 E MainService:   at android.os.Handler.dispatchMessage(Handler.java:106)
06-17 17:05:46.763 29115 29502 E MainService:   at android.os.Looper.loop(Looper.java:193)
06-17 17:05:46.763 29115 29502 E MainService:   at android.os.HandlerThread.run(HandlerThread.java:65)
06-17 17:05:46.763 29115 29502 D MainService: updateArticles() finished
06-17 17:05:46.763 29115 29502 D EventProcessor: onUpdateArticlesFinishedEvent() started
06-17 17:05:46.766 29115 29502 D EventProcessor: onActionResultEvent() started

(note that I'm not familiar with adb, so I have trouble filtering this output to collect only the relevant logs)

The Expected an int but was NULL error seems to be related to issue #739.

di72nn commented 5 years ago

Previously, the Expected an int but was NULL error was happening during article deletion, when the server failed to return a non-nullable id, now this is something new.

@wallabag/core can someone tell how can server return null for reading_time? It's a non-nullable column in the DB schema. I can't rule out some other obscure error, but so far an incorrect response from server is the prime suspect.

// Aaaand notifications are now broken -_- #644

di72nn commented 5 years ago

@regisb BTW, thanks for the log, it helped a lot.

Meanwhile you may check your server DB for some suspicious reading_time values of the articles you added recently. Something like this should do (the date and table name suffix may need to be adjusted): select reading_time from wallabag_entry where created_at > '2019-06-10';

regisb commented 5 years ago

I found a way to solve my problem. I found a couple articles that had NULL reading time:

>  select * from wallabag_entry where reading_time is NULL;
547|1||Newcastle Study Non-technical Summary|http://organic-center.org/uncategorized/newcastle-study-non-technical-summary/?utm_source=The Organic Scoop&utm_campaign=3aa680a698-The_Organic_Scoop_July_20146_30_2014&utm_medium=email&utm_term=0_6c4c22519d-3aa680a698-414554937|1|0||2014-07-12 00:37:02|2017-04-10 10:34:26|||||http://organic-center.org/wp-content/uploads/2014/07/BenbrookStudy3-304x1024.png||||||
1295|1||Where Are They Now? Kate Zasada|http://blog.generalassemb.ly/where-are-they-now-kate-zasada/?utm_source=GA&awesm=ga.co_ta&utm_medium=Twitter&utm_campaign=GA Blog Kate Zasada Student Spotlighta|1|0||2013-06-25 18:29:01|2017-04-10 11:05:19|||||http://blog.generalassemb.ly/blog/wp-content/uploads/2013/06/KateZasada_headshot1.jpg||||||
1450|1||Predicting Google closures|http://www.gwern.net/Google shutdowns|1|0||2013-05-04 10:20:20|2017-04-10 11:09:38|||||http://www.gwern.net/images/google/shutdownsbymonth.png||||||

I simply deleted these articles from the UI and I can now sync my mobile app without problem. As far as I am concerned, you can close this issue.

This does not explain how a non-nullable column could contain NULL data, though. However, the reading_time column does seem to be nullable:

sqlite> PRAGMA table_info(wallabag_entry);
0|id|INTEGER|1||1
1|user_id|INTEGER|0|NULL|0
2|uid|CLOB|0|NULL|0
3|title|CLOB|0|NULL|0
4|url|CLOB|0|NULL|0
5|is_archived|BOOLEAN|1||0
6|is_starred|BOOLEAN|1||0
7|content|CLOB|0|NULL|0
8|created_at|DATETIME|1||0
9|updated_at|DATETIME|1||0
10|mimetype|CLOB|0|NULL|0
11|language|CLOB|0|NULL|0
12|reading_time|INTEGER|0|NULL|0
13|domain_name|CLOB|0|NULL|0
14|preview_picture|CLOB|0|NULL|0
15|http_status|VARCHAR(3)|0|NULL|0
16|published_at|DATETIME|0|NULL|0
17|published_by|CLOB|0|NULL|0
18|headers|CLOB|0|NULL|0
19|starred_at|DATETIME|0|NULL|0
20|origin_url|CLOB|0|NULL|0
di72nn commented 5 years ago

Oh, yeah, totally forgot about SQLite. It is non-nullable for MySQL, so this is kind of a standard.

Nice to hear that you got it sorted out.

regisb commented 5 years ago

Thanks for the quick answer! And keep up the good work.