Logging caches stopped to work suddenly, error 403 (all c:geo versions)

[fracz]

Describe your problem!

When trying to log a cache, the following error appears. Confirmed on two phones and two smartphones. Version 2024.04.13.

How to reproduce?

Just try to log anything.

Actual result after these steps?

No response

Expected result after these steps?

No response

Reproducible

Yes

c:geo Version

2024.04.13

System information

No response

Additional Information

No response

[greddler]

I have the same problem for a few hours.
No logging is possible.

[Tungstene]

Ditto

[eddiemuc]

Copied from #15634 / @katzamum:

Error message:
Posting Log failed.

Reason: It seems that your log was not posted. Please check it on the cache originating website.

The website responded with following message:
LOG ERROR(user=katzamum):
Problem pasting log, response is: cgeo.geocaching.connector.gc.GCLOgApi$GCWebLogResponse, status=403, isSuccessful=false, response=REsponse{protocol=http/1.1,code=403, message=Forbidden, url=https://www.geocaching.com/api/live/v1/logs/GCAFX7Y/geocacheLog}, body =

I received the same error with GC7TTV3, GC9P62K, G80YM6, GCA19TG

[eddiemuc]

Problem is very real. Our watchdog shows it since around midnight (last green build around 8pm yesterday)

Best guess for now is a website change.

I put out a notification for all c:geo versions for now.

[eddiemuc]

Update: as can be expected, the problem is reported many many times on support

[alces7]

Samma här / das gleiche Problem bei mir.

Alces7

[ztNFny]

There's a new call before sending a log:

curl 'https://www.geocaching.com/api/auth/csrf'

The result is then used in posting the log:

curl 'https://www.geocaching.com/api/live/v1/logs/GCxxx/geocacheLog'
-H 'CSRF-Token: 74exxxxxxxxxxx'
-H 'Cookie: '
--data-raw '{"images":[],"logDate":"2024-04-18T11:44:43.947Z","logText":"test","logType":4,"trackables":[],"usedFavoritePoint":false}'

EDIT: Nevermind, that's not new after all :-(
EDIT2: Yes, it is new! The csrf was previously retrieved from the log posting page

[ztNFny]

Created a PR to fix this. It's successfully tested, targeted against release.
@moving-bits @Lineflyer can we get this out asap?

Style might not be the best, but no time for anything better right now ;-)

[moving-bits]

Thanks @ztNFny for stepping in and preparing a PR so quickly!

I would be able to prepare a new release tonight, maybe late afternoon.

[eddiemuc]

Thanks @ztNFny for the quick fix. It will not solve the problem for trackables and edit/delete log. But still it is worth to ship IMHO because the vast majority of user actions will be cache log creations.

[ztNFny]

Thanks @ztNFny for the quick fix. It will not solve the problem for trackables and edit/delete log. But still it is worth to ship IMHO because the vast majority of user actions will be cache log creations.

Good point, I didn't check that. Quick fix for that comming up as well - BUT I'm unable to test as gradle broke and doesn't want to build anything right now and I'm not sure whether I can solve that ...

[ztNFny]

Tested now:
Post log: OK
Edit own log: OK
Delete own log: KO - but unrelated, that's #15587 - #15638 fixes that but is not that urgent, so it doesn't have to be included in the emergeny release if further review is wanted
Delete other log: OK
Post TB log: OK
Edit TB log: Not available
Delete TB log: Not available

So please include #15637 in the fix release

[Lineflyer]

@ztNFny Thanks for your quick reaction, fix and tests.

Anyone driving the release train already, or shall I take care of that tonight or tomorrow?

[moving-bits]

I'm still on the road, will start around 21:30

[alces7]

Well, English isn't my mother tongue.
What @ztNFny fixed may be well; I do not know what it is.
I am thankful for all help.
I only can see that I even now are refused to log my founds (error 403).
As long as the D/T is lower than 2,0 I can log founds by geocaching.com - so you understand I'm not a Premium member.

But for me the problem still remains. Sorry!
Alces7

[ztNFny]

Well, English isn't my mother tongue. What @ztNFny fixed may be well; I do not know what it is. I am thankful for all help. I only can see that I even now are refused to log my founds (error 403). As long as the D/T is lower than 2,0 I can log founds by geocaching.com - so you understand I'm not a Premium member.

But for me the problem still remains. Sorry! Alces7

No fixed version is available yet, so of course you still have the problem. You have to wait until a new update is available in Play Store.

[Lineflyer]

@moving-bits Leaving release then up to you if you are fine with that, because you can also review the changes which I cannot.

Ping me, if I need to roll the release / if you are out of time.

[moving-bits]

fixed with #15636

@alces7
this fix will be part of upcoming release 2024.04.18 (which is uploaded to Play Store already, may take an hour or so until it's available)

[katzamum]

Brilliant! Thank you all.

[moving-bits]

@moving-bits Leaving release then up to you if you are fine with that, because you can also review the changes which I cannot.

Ping me, if I need to roll the release / if you are out of time.

thanks, all done for now. Play Store is crunching the new release, let's see how fast they are tonight.

[john-magnus]

fixed with #15636

@alces7 this fix will be part of upcoming release 2024.04.18 (which is uploaded to Play Store already, may take an hour or so until it's available)

Testing with the 2024.04.18 "Nightly", the issue is still present and I cannot post logs. Results in an 403 error (message word below). Full version/build of the nightly is "2024.04.18-NB-a58512a".

Is the version pushed to the play store a newer build?

--
The website responded with following message: LOG ERROR(User=username):Problem pasting log, response is: cgeo.geocaching.co nnector.gc.GCLogAPIŞGCWebLogResponse, status=403, isSuccessful=false, response Response{protocol=http/1.1, code=403, message=Forbidden, url=https://www.geocaching.com/api/live/v1/logs/GCAP714/geocacheLog}, body =

[ztNFny]

a58512a is last nights build

[alces7]

Thanks a lot!Alces7  -------- Originalmeddelande --------Från: moving-bits ***@***.***> Datum: 2024-04-18 22:39 (GMT+01:00) Till: cgeo/cgeo ***@***.***> Kopia: alces7 ***@***.***>, Mention ***@***.***> Ämne: Re: [cgeo/cgeo] Logging caches stopped to work suddenly, error 403 (all c:geo versions) (Issue #15633) fixed with #15636 @alces7 this fix will be part of upcoming release 2024.04.18 (which is uploaded to Play Store already, may take an hour or so until it's available) —Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you were mentioned.Message ID: ***@***.***>

[alces7]

Have answered already by mail but will also here thank everybody who worked on this a lot! Great work done!

Vielen herzlichen Dank! 😃 👍

Alces7

[moving-bits]

Testing with the 2024.04.18 "Nightly", the issue is still present and I cannot post logs. Results in an 403 error (message word below). Full version/build of the nightly is "2024.04.18-NB-a58512a".

Is the version pushed to the play store a newer build?

Yes, it is:

Nightly 2024.04.18-nb gets build in the morning (CEST) of April 18th, so it does not yet include things merged throughout April 18th - those will be included in next day's nightly.

In contrast to this, release 2024.04.18 (without "nb") got build manually in the evening, including the fixes for the logging problems.

You can always have a look at the in-app changelog, it will list the fixes it contains.

[bekuno]

Our watchdog tests still show the same error.
The fix has not taken effect.

See for master eg. https://ci.cgeo.org/job/WatchdogTests_master/2712/testReport/cgeo.watchdog/WatchdogTest/testGeocachingLogTrackable/,
and for release eg. https://ci.cgeo.org/job/WatchdogTests_release/5414/testReport/cgeo.watchdog/WatchdogTest/testGeocachingLogTrackable/ and https://ci.cgeo.org/job/WatchdogTests_release/5414/testReport/cgeo.watchdog/WatchdogTest/testGeocachingLogCache/.

[eddiemuc]

I received only two successful logs on the test cache tonight (0:31 and 4:04). Logging fails sometimes but this doesn't seem to be consistent.

I received no successful logs for the test TB.

[ztNFny]

Our watchdog tests still show the same error.
The fix has not taken effect.

See for master eg. https://ci.cgeo.org/job/WatchdogTests_master/2712/testReport/cgeo.watchdog/WatchdogTest/testGeocachingLogTrackable/,
and for release eg. https://ci.cgeo.org/job/WatchdogTests_release/5414/testReport/cgeo.watchdog/WatchdogTest/testGeocachingLogTrackable/ and https://ci.cgeo.org/job/WatchdogTests_release/5414/testReport/cgeo.watchdog/WatchdogTest/testGeocachingLogCache/.

The fails for GeocacheLog are Response{protocol=http/1.1, code=403, message=Forbidden, url=https://www.geocaching.com/account/oauth/token} which is called during login. That's a different issue than the one fixed here.

For me logging works just fine in actual cgeo.

[alces7]

However, for me is the problem solved after an update of c:geo!
And I will once more give thanks to their help!
Alces7

[moving-bits]

We do get sporadic tickets on support still mentioning a "request verification token not found", even for users already running 2024.04.18 - maybe GC is still experiencing with different implementations?

[ztNFny]

We do get sporadic tickets on support still mentioning a "request verification token not found", even for users already running 2024.04.18 - maybe GC is still experiencing with different implementations?

I don't have any issues in emulator or real device, so unable to investigate anything. If we could get debug logs with network traces for those failing maybe there's something in there.

[moving-bits]

Some logfile extract from ticket 162056: (slightly anonymized)

04-22 12:30:57.231 29519 29721 W cgeo    : [OkHttp] HTTP-ERR: could not parse json String to 'cgeo.geocaching.connector.gc.GCLogAPI$GCWebTrackableLogResponse': 
04-22 12:30:57.231 29519 29721 W cgeo    : com.fasterxml.jackson.databind.exc.MismatchedInputException: No content to map due to end-of-input
04-22 12:30:57.231 29519 29721 W cgeo    :  at [Source: (String)""; line: 1, column: 0]
04-22 12:30:57.231 29519 29721 W cgeo    : 	at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:4765)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:4667)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3629)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3597)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at cgeo.geocaching.network.HttpRequest.lambda$requestJson$1(HttpRequest.java:109)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at cgeo.geocaching.network.HttpRequest.$r8$lambda$YlFp7Pb_EE2gLLgjSGwfPMcPRfI(HttpRequest.java:0)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at cgeo.geocaching.network.HttpRequest$$ExternalSyntheticLambda0.apply(R8$$SyntheticClass:0)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at cgeo.geocaching.network.HttpRequest.lambda$requestInternal$2(HttpRequest.java:144)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at cgeo.geocaching.network.HttpRequest.$r8$lambda$7HCCFmPnXoxDQRTOwKyTvtOTPZY(HttpRequest.java:0)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at cgeo.geocaching.network.HttpRequest$$ExternalSyntheticLambda2.apply(R8$$SyntheticClass:0)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at io.reactivex.rxjava3.internal.operators.single.SingleMap$MapSingleObserver.onSuccess(SingleMap.java:58)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at io.reactivex.rxjava3.internal.operators.single.SingleFlatMap$SingleFlatMapCallback$FlatMapSingleObserver.onSuccess(SingleFlatMap.java:112)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at io.reactivex.rxjava3.internal.operators.single.SingleCreate$Emitter.onSuccess(SingleCreate.java:68)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at cgeo.geocaching.utils.RxOkHttpUtils$1.onResponse(RxOkHttpUtils.java:48)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
04-22 12:30:57.231 29519 29721 W cgeo    : 	at java.lang.Thread.run(Thread.java:923)
04-22 12:30:57.233 29519 29657 W cgeo    : [network--9] LOG ERROR(user=UsernameXXX):Problem pasting trackable log, response is: cgeo.geocaching.connector.gc.GCLogAPI$GCWebTrackableLogResponse, status=403, isSuccessful=false, response = Response{protocol=http/1.1, code=403, message=Forbidden, url=https://www.geocaching.com/api/live/v1/logs/TBABCDE/trackableLog}, body = , request was:{"images":[],"logDate":"2024-04-20T12:29:55","logText":"XXX","trackingCode":"ABCDE","logType":48}
04-22 12:30:57.233 29519 29657 I cgeo    : [network--9] [android.view.ContextThemeWrapper].showToast(LOG ERROR(user=UsernameXXX):Problem pasting trackable log, response is: cgeo.geocaching.connector.gc.GCLogAPI$GCWebTrackableLogResponse, status=403, isSuccessful=false, response = Response{protocol=http/1.1, code=403, message=Forbidden, url=https://www.geocaching.com/api/live/v1/logs/ABCDE/trackableLog}, body = , request was:{"images":[],"logDate":"2024-04-20T12:29:55","logText":"XXX","trackingCode":"ABCDE","logType":48}){1}
04-22 12:30:57.234 29519 29657 W cgeo    : [network--9] Could not show toast 'LOG ERROR(user=UsernameXXX):Problem pasting trackable log, response is: cgeo.geocaching.connector.gc.GCLogAPI$GCWebTrackableLogResponse, status=403, isSuccessful=false, response = Response{protocol=http/1.1, code=403, message=Forbidden, url=https://www.geocaching.com/api/live/v1/logs/TBABCDE/trackableLog}, body = , request was:{"images":[],"logDate":"2024-04-20T12:29:55","logText":"XXX","trackingCode":"ABCDE","logType":48}' to user: java.lang.NullPointerException: Can't toast on a thread that has not called Looper.prepare()
04-22 12:30:57.234 29519 29519 I cgeo    : [main] WORKERTASK{log-create-trackable}:post RESULT:R=LogResult:LOG_POST_ERROR(LOG ERROR(user=UsernameXXX):Problem pasting trackable log, response is: cgeo.geocaching.connector.gc.GCLogAPI$GCWebTrackableLogResponse, status=403, isSuccessful=false, response = Response{protocol=http/1.1, code=403, message=Forbidden, url=https://www.geocaching.com/api/live/v1/logs/TBABCDE/trackableLog}, body = , request was:{"images":[],"logDate":"2024-04-20T12:29:55","logText":"XXX","trackingCode":"ABCDE","logType":48})/logId=/serviceLogId={log-create-trackable}

[ztNFny]

I was able to reproduce it for TB logs now. Those fail if after starting c:geo no cache log is send before sending the TB log 😮