Closed gerroon closed 4 years ago
I tried a couple of articles and things seem to work ok. Have you tried refetching these articles? Does web UI show correct dates? If the app data is cleared, does the app break again after sync?
It seems that the server returns an incorrect date for some reason. It can be inspected with curl
if the article (or at least range) is identified.
Thanks for the reply.
The web UI shows correct dates, and I have no problem reading the articles in the web app.
I actually tried it with clean slate, it starts syncing and half way there it just stops sync, so the app has no articles to show. I will see if I can get some logs from the app too.
Could you tell me how I can inspect it with Curl?
You can reuse the API client from wallabag android app and get a new access token as described in the documentation: https://doc.wallabag.org/en/developer/api/oauth.html
Afterwards you can use the API call to get the entry:
curl --get "https://DOMAIN/wallabag/api/entries/1131.json?access_token=ZGJmNTA2MDdmYTdmNWFiZjcxOWY3MWYyYzkyZDdlNWIzOTU4NWY3NTU1MDFjOTdhMTk2MGI3YjY1ZmI2NzM5MA"
This is the analog procedure as described in the documentation in https://doc.wallabag.org/en/developer/api/methods.html#getting-existing-entries.
There may be a problem in finding the problem article. If you sure the problem is caused by some specific recently added articles, you may just check them right away as @Strubbl explained (there should be a couple of date fields in each article: published_at
, created_at
, updated_at
, starred_at
, and also created_at
and updated_at
in embedded annotations if any).
I'm afraid app logs can only narrow it down to a 30-article batch (referred to as "page" in requests), but you can also find the same page number by inspecting the server logs - it will be the last requested page (&page=X
in the query) for the "full sync" (these queries have sort=created&...&since=0&...
). The numeration is 1-based, so for example if it breaks on page=3
, then the problem is somewhere in articles 61-90.
I am not seeing anything in the logs regarding pages (var/log/prod.log) , probably I need to enable some debug somewhere.
Here I tried to capture the page from mysql tables of last 10 days. Can you spot any date issues? The only thing that sticks to me is the "NULL"s in the published data, though that might be normal.
Only thing I see is this which does not make sense to me why would it report auth error?
request.INFO: Matched route "api_get_version". {"route":"api_get_version","route_parameters":{"_controller":"Wallabag\\ApiBundle\\Controller\\UserRestController::getVersionAction","_format":"json","_route":"api_get_version"},"request_uri":"https://xxxx.xxx/wallabag/api/version.json","method":"GET"} [] [2020-01-03 10:06:26] app.ERROR: Authentication failure for user "", from IP "192.168.x.x", with UA: "okhttp/4.2.2". [] []
I tried the api refilling in the connection settings couple times, I even deleted the api keys in the user settings to make sure. Everytime it seems to grab the keys and create the api stuff in the user settings succesfully. I am not sure if this is related at all.
I am not seeing anything in the logs regarding pages (var/log/prod.log)
Sorry I wasn't clear - I meant the web server logs.
why would it report auth error?
Don't mind that. #789
I don't see any problem on the screenshot.
I guess you should either get the web server logs during the app's full sync, or the app logs of the same procedure. Or both.
Here is the access log. The last line is when the app errors out I think.
"GET /wallabag/api/entries.json?sort=created&page=12&order=asc&since=0&perPage=30 HTTP/1.1" 200 894355 "-" "okhttp/4.2.2"
"GET /wallabag/api/entries.json?sort=created&page=13&order=asc&since=0&perPage=30 HTTP/1.1" 200 831616 "-" "okhttp/4.2.2"
"GET /wallabag/api/entries.json?sort=created&page=14&order=asc&since=0&perPage=30 HTTP/1.1" 200 837916 "-" "okhttp/4.2.2"
"GET /wallabag/api/entries.json?sort=created&page=15&order=asc&since=0&perPage=30 HTTP/1.1" 200 1045514 "-" "okhttp/4.2.2"
"GET /wallabag/api/entries.json?sort=created&page=16&order=asc&since=0&perPage=30 HTTP/1.1" 200 720507 "-" "okhttp/4.2.2"
"GET /wallabag/api/entries.json?sort=created&page=17&order=asc&since=0&perPage=30 HTTP/1.1" 200 770853 "-" "okhttp/4.2.2"
"GET /wallabag/api/entries.json?sort=created&page=18&order=asc&since=0&perPage=30 HTTP/1.1" 200 1092941 "-" "okhttp/4.2.2"
"GET /wallabag/api/entries.json?sort=created&page=19&order=asc&since=0&perPage=30 HTTP/1.1" 200 721279 "-" "okhttp/4.2.2"
"GET /wallabag/api/entries.json?sort=created&page=20&order=asc&since=0&perPage=30 HTTP/1.1" 200 560516 "-" "okhttp/4.2.2"
"GET /wallabag/api/entries.json?sort=created&page=21&order=asc&since=0&perPage=30 HTTP/1.1" 200 477733 "-" "okhttp/4.2.2"
"GET /wallabag/api/entries.json?sort=created&page=22&order=asc&since=0&perPage=30 HTTP/1.1" 200 409898 "-" "okhttp/4.2.2"
And I think this the android log between the sync and errroring
1-04 15:09:47.266 17463 17821 D Updater : performUpdate() articleChanges: [TAGS_CHANGED, ADDED]
01-04 15:09:47.267 17463 17821 D Updater : performUpdate() articleChanges: [TAGS_CHANGED, ADDED]
01-04 15:09:47.267 17463 17821 D Updater : performUpdate() articleChanges: [TAGS_CHANGED, ADDED]
01-04 15:09:47.267 17463 17821 V Updater : performUpdate() performing articleDao.insertInTx()
01-04 15:09:47.277 17463 17821 V Updater : performUpdate() done articleDao.insertInTx()
01-04 15:09:47.277 17463 17821 V Updater : performUpdate() performing tagDao.insertInTx()
01-04 15:09:47.277 17463 17821 V Updater : performUpdate() done tagDao.insertInTx()
01-04 15:09:47.277 17463 17821 V Updater : performUpdate() performing articleTagsJoinDao.insertInTx()
01-04 15:09:47.277 17463 17821 V Updater : performUpdate() done articleTagsJoinDao.insertInTx()
01-04 15:09:47.277 17463 17821 D EventProcessor: onUpdateArticlesProgressEvent() started
01-04 15:09:47.280 17463 17463 D MainActivity: onUpdateArticlesProgressEvent
01-04 15:09:47.447 17463 17821 E MainService: updateArticles() exception
01-04 15:09:47.447 17463 17821 E MainService: com.squareup.moshi.JsonDataException: Not an RFC 3339 date: -0001-11-30T00:00:00-0600
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.adapters.Iso8601Utils.parse(Iso8601Utils.java:194)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.adapters.Rfc3339DateJsonAdapter.fromJson(Rfc3339DateJsonAdapter.java:39)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.adapters.Rfc3339DateJsonAdapter.fromJson(Rfc3339DateJsonAdapter.java:36)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.JsonAdapter$2.fromJson(JsonAdapter.java:137)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.ClassJsonAdapter$FieldBinding.read(ClassJsonAdapter.java:194)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.ClassJsonAdapter.fromJson(ClassJsonAdapter.java:156)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.JsonAdapter$2.fromJson(JsonAdapter.java:137)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.CollectionJsonAdapter.fromJson(CollectionJsonAdapter.java:76)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.CollectionJsonAdapter$2.fromJson(CollectionJsonAdapter.java:53)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.JsonAdapter$2.fromJson(JsonAdapter.java:137)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.ClassJsonAdapter$FieldBinding.read(ClassJsonAdapter.java:194)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.ClassJsonAdapter.fromJson(ClassJsonAdapter.java:156)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.JsonAdapter$2.fromJson(JsonAdapter.java:137)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.ClassJsonAdapter$FieldBinding.read(ClassJsonAdapter.java:194)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.ClassJsonAdapter.fromJson(ClassJsonAdapter.java:156)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.JsonAdapter$2.fromJson(JsonAdapter.java:137)
01-04 15:09:47.447 17463 17821 E MainService: at retrofit2.converter.moshi.MoshiResponseBodyConverter.convert(MoshiResponseBodyConverter.java:45)
01-04 15:09:47.447 17463 17821 E MainService: at retrofit2.converter.moshi.MoshiResponseBodyConverter.convert(MoshiResponseBodyConverter.java:27)
01-04 15:09:47.447 17463 17821 E MainService: at retrofit2.OkHttpCall.parseResponse(OkHttpCall.java:225)
01-04 15:09:47.447 17463 17821 E MainService: at retrofit2.OkHttpCall.execute(OkHttpCall.java:188)
01-04 15:09:47.447 17463 17821 E MainService: at retrofit2.DefaultCallAdapterFactory$ExecutorCallbackCall.execute(DefaultCallAdapterFactory.java:104)
01-04 15:09:47.447 17463 17821 E MainService: at com.di72nn.stuff.wallabag.apiwrapper.WallabagService.getArticles(WallabagService.java:642)
01-04 15:09:47.447 17463 17821 E MainService: at com.di72nn.stuff.wallabag.apiwrapper.WallabagService.access$100(WallabagService.java:25)
01-04 15:09:47.447 17463 17821 E MainService: at com.di72nn.stuff.wallabag.apiwrapper.WallabagService$ArticlesQueryBuilder.execute(WallabagService.java:204)
01-04 15:09:47.447 17463 17821 E MainService: at com.di72nn.stuff.wallabag.apiwrapper.WallabagService$ArticlesPageIterator.hasNext(WallabagService.java:496)
01-04 15:09:47.447 17463 17821 E MainService: at fr.gaulupeau.apps.Poche.network.Updater.performUpdate(Updater.java:177)
01-04 15:09:47.447 17463 17821 E MainService: at fr.gaulupeau.apps.Poche.network.Updater.update(Updater.java:82)
01-04 15:09:47.447 17463 17821 E MainService: at fr.gaulupeau.apps.Poche.service.MainService.updateArticles(MainService.java:433)
01-04 15:09:47.447 17463 17821 E MainService: at fr.gaulupeau.apps.Poche.service.MainService.onHandleIntent(MainService.java:100)
01-04 15:09:47.447 17463 17821 E MainService: at android.app.IntentService$ServiceHandler.handleMessage(IntentService.java:68)
01-04 15:09:47.447 17463 17821 E MainService: at android.os.Handler.dispatchMessage(Handler.java:102)
01-04 15:09:47.447 17463 17821 E MainService: at android.os.Looper.loop(Looper.java:154)
01-04 15:09:47.447 17463 17821 E MainService: at android.os.HandlerThread.run(HandlerThread.java:61)
01-04 15:09:47.447 17463 17821 E MainService: Caused by: java.lang.NumberFormatException: Invalid number: -000
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.adapters.Iso8601Utils.parseInt(Iso8601Utils.java:231)
01-04 15:09:47.447 17463 17821 E MainService: at com.squareup.moshi.adapters.Iso8601Utils.parse(Iso8601Utils.java:81)
01-04 15:09:47.447 17463 17821 E MainService: ... 32 more
01-04 15:09:47.448 17463 17821 D MainService: updateArticles() finished
01-04 15:09:47.448 17463 17821 D EventProcessor: onUpdateArticlesFinishedEvent() started
01-04 15:09:47.449 17463 17821 D EventProcessor: onActionResultEvent() started
01-04 15:09:47.449 17463 17821 D EventProcessor: onActionResultEvent() action: UPDATE_ARTICLES
01-04 15:09:47.449 17463 17821 D EventProcessor: onActionResultEvent() result is success: false
01-04 15:09:47.449 17463 17821 D EventProcessor: onActionResultEvent() result is not success; errorType: UNKNOWN
01-04 15:09:47.449 17463 17821 D EventProcessor: onActionResultEvent() result message: com.squareup.moshi.JsonDataException: Not an RFC 3339 date: -0001-11-30T00:00:00-0600
Run this:
curl --get -s 'https://YOUR.INSTANCE/api/entries.json' -H 'Authorization:Bearer YOUR_ACCESS_TOKEN' -d order=asc -d page=22 -o articles.json
Then inspect articles.json
(something like cat articles.json | python -m json.tool | less
should do) - look for -0001-11-30T00:00:00-0600
.
@di72nn
Thanks
I think I did it right but I see no prints on the terminal at all.
I got the access token then plugged in my token and the url in the line.
how I got the access token
curl -s "https://DOMAIN/wallabag/oauth/v2/token?grant_type=password&client_id=$ID&client_secret=$SECRET&username=$USER&password=$PASS"
This gave me an access token and refresh token, the I used the acccess token in the line you gave above.
Ok, I used the curl line couple entries above, I got an articles.json.
cat articles.json| python -m json.tool | grep -i 30T00
line returns no results
here is how I downloaded the articles
curl --get "https://DOMAIN/wallabag/api/entries.json?access_token=$TOKEN" > articles.json
cat articles.json| python -m json.tool | wc -l
1030
EDIT:
Only one that is similar I could find is
cat articles.json| python -m json.tool | grep -i "00-0600"
"published_at": "2019-12-31T00:00:00-0600"
EDIT2: Ok deleting that article did not do anything. I am wondering if the server is misreporting it.
If you could tell me how to search teh Mysql tables, maybe I can locate it there? I tried to go through the tables to see if I can locate anything but too many entries in the database.
I think I did it right but I see no prints on the terminal at all.
It wasn't meant to print anything, it just writes to articles.json
.
curl --get "https://DOMAIN/wallabag/api/entries.json?access_token=$TOKEN" > articles.json
The parameters are missing in this line, so it fetches a wrong "page".
Please do the following:
articles.json
,articles.json
file is created,cat articles.json | python -m json.tool | grep -i '0001-11-30T00:00:00-0600'
,If you could tell me how to search teh Mysql tables, maybe I can locate it there?
I would, but I'm not quite sure how that value is represented in SQL. Also which field to check.
Ok I think I found it
This is the article
today 2018-09-02 00:49 create -0001-11-30 00:00
how it looks in mysql
2018-09-02 00:49:42 2018-09-02 00:57:57 text/html en 15 motherboard.vice.com NULL NULL 200 0000-00-00 00:00:00 a:1:{i:0;s:15:"Daniel Oberhaus";} N;
I sorted columns by published date, and that article seems to be the only one with that format
https://i.imgur.com/Mm8frMU.png
I am also wondering why this line returns no results, should not it grab all the articles etc?
curl --get "https://DOMAIN/wallabag/api/entries.json?access_token=$TOKEN" | python -m json.tool | grep -i '0001-11-30T00:00:00-0600'
That's a peculiar conversion.
I added this articles to my wallabag instance and nothing broke. I guess it might have been a bug in older siteconfig, which is fixed now. So you can simply refetch the article.
The app started to process the publication date since 2.3.0, but there was no error because apparently this article wasn't downloaded from server until recently (because it already was in the app).
I am also wondering why this line returns no results, should not it grab all the articles etc?
It only loads 30 articles at a time by default.
Ok For the record, I copied the date from the one below and pasted into the wront date entry. It all works now.
Thanks to everyone who guided me here. However it would be nice if the app is more forgiveful with this kind of stuff, this took many hours to hunt down one article, and not everyone is a developer. I am sure it would be very quick for those who do this daily.
thanks
Ok , well maybe not so easy. The app keeps crashing afterwards. I was able to load all the articles and browse couple articles. THen I restart the app now it constantly crashes, I am not sure if this is related or not. I tried this multiple times, it crashes after grabbing all the articles.
I think this has something to do with full sync. Let me know if this is a separate issue so I can start a new one.
App logs
However it would be nice if the app is more forgiveful with this kind of stuff
Yeah, it makes sense. I'll consider it.
Seems to be #413. This is (hopefully) fixed in master
.
Try clearing app data. If it doesn't help, create a new issue.
Thanks for all the help.
I think that I got hit by 2 bugs at the same time which made the issue very complicated for my use here.
Clearing data, starting fresh does not help so created a new bug with more details to replicate the issue
You're welcome :) I hope you'll have better experience in the future.
i'm also having this bug on first sync... similar problem to #1049... also: it would be nice to have a magic SQL query to find the right entries as well... with large wallabag databases, this is hard! :)
Issue details
The app stopped syncing with the server, so I try Full Sync. During the Sull Sync I get the error in the image. After that Wallabag app refuses to start again, crashes right away, it seems to me that this even corrupts its database.
See the image
https://i.imgur.com/w7bGamI.png
Duplicate?
This started happened after I added couple very large articles, I mean very large. They are ok in the web app but I am suspecting that this causes the issue. So this needs to be tested with huge articles.
Actual behaviour
The app does not sync the latest added articles, full sync crashes the app and corrupts the app db.
Expected behaviour
It should download the latest articles.
Steps to reproduce the issue
Try adding articles from this page
https://en.wikipedia.org/wiki/Wikipedia:Wikipedia_records#Articles like https://en.wikipedia.org/wiki/Saudi_Arabian-led_intervention_in_Yemen, https://en.wikipedia.org/w/index.php?oldid=752675586
And see if those sync back
Environment details
wallabag app version:
2.3.0
wallabag app installation source (e.g. Gplay, F-Droid, manual):
Fdroid
Android OS version: LineageOS 14.1
Android ROM (e.g. stock, LineageOS, SlimRom,…): LineageOS 14.1
Android hardware: Samsung
wallabag server version: Version: 2.3.8
Do you have Two-Factor-Authentication enabled?: yes/no No
Logs
wallabag server
Please paste relevant wallabag server logs here (from file
<wallabag>/var/logs/prod.log
):(I already fixed that execution time in the php, however including it here for the record)
Web server
Please paste relevant web server logs (e.g. from nginx, Apache, …) here: Not sure about the logs, I do not see anything relevant, see
Your experience with wallabag Android appositive end note does wonders)
I love the app, I think it is great!