Google-cloud-dotnet: Authentication Problem

[bluetoothfx]

Environment details

• OS: Windows 10
• .NET version: 4.6.1
• Package name and version: Install-Package Google.Cloud.Firestore -Version 1.0.0-beta20

Problem Details:

Hello I am facing a problem on authentication. I have followed following steps to get data
from Firestore.

https://github.com/googleapis/google-cloud-dotnet/issues/2349#issuecomment-406035943

The code is running smoothly. I have created a service account json key and downloaded it
and using it in application & It is working as expected. But I have a special case on that case
I have observed it is not working & having exception.

Situation:
Suppose I am creating A wpf application on Country A & This application will be used by some Country B user. Now when I am deploying this application it is working fine. I have not
done anything special as this is not anything special on deployment. I am just coping bin/debug and sending to Country B users to test. Now Country B is 4 hours behind me. So, when in Country A the time is 00:00 , Country B time is 20:00. On that time the date for Country A advances one day then Country B. At that point when user of the Country B tries to get data they encountered following error (I suspect changing date occurring the auth. problem). Though I don't have any solid proof till now.

https://github.com/googleapis/google-cloud-dotnet/issues/2349#issuecomment-496228141

This issue automatically solve when Country B date-time changed to next day. I mean Country B users need to wait for 00:00 hour to get data. I am not so much sure about if there is something that I am missing.

But same application on same time running on Country A without any problem but Country B. Only thing that is change is Time & Date.

This issue can be reproduced if you change date/time to Country A PC on the time of development.

I will try to put more context if I find.

[jskeet]

The time zone shouldn't matter at all - but the system time in UTC does matter. So if you've been just changing the system clock directly instead of changing the system time zone, then that would explain everything. Please clarify exactly what you mean by "if you change date/time to Country A PC". In particular, if you print out DateTime.UtcNow before and after, that should not change.

[bluetoothfx]

Yes Sir, I think you are correct. If I turn off Set time Automatically & change the time like make 2 hours slower. Also keep Set time Zone Automatically as On/Checked then it gives the error. Which make your point True, if I understand.

But why this is happening to Country B I have no explanation. Because on development pc it is running smoothly but on the same time it fails to run on Country B client PC. But with the same version it starts to work again after a certain period of time on clients machine Country B. What can I do to make this consistent ?

Is there anything I am missing or What kind of information I should provide to make this more clear.

[jskeet]

It sounds like the clock on "Country B" client PC may be losing time - or someone may be manually setting it to the incorrect time. I suspect Windows is then automatically updating the time via time servers, which makes it work until the clock becomes incorrect again.

One way of checking this is to log the UTC time when you get a failure - if you're able to check that when you can provoke a failure at a point where you know the UTC time, you can easily check whether my suspicion is correct.

[bluetoothfx]

I will log the UTC time & will report back to you Sir 🖖.
Thanks for your Great Response time.

[bluetoothfx]

Dear jskeet,
I wonder if you please read through this investigation , then I may get some insight about my problem.
After investigating I have found another error. I am not sure if it is another or was the same.
But the error pattern is same. It is appearing spontaneously & have no lead. But the same
application running after sometime perfectly (which makes the pattern same).

I am sharing the error log here. I also have searched this repo issues and found about HTTP1.1 & HTTP2.0 matter. I don't know if it is related to it or not. It is a log which is created on 'Country B' users
PC. Let me know if you need more information on this.

• Error: Message: Status (StatusCode = Unavailable, Detail = "Connect Failed")

=> DateTime: 06.06.2019 20: 03: 54 | UTC: 06.06.2019 18:03:54 An Error occurred: System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (Task task)
   at Grpc.Core.Internal.ClientResponseStream`2. <MoveNext> d__5.MoveNext ()
--- End of stack trace from the previous location where the exception was triggered ---
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (Task task)
   at System.Linq.AsyncEnumerable. <ForEachAsync_> d__174`1.MoveNext ()
--- End of stack trace from the previous location where the exception was triggered ---
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (Task task)
   on Google.Cloud.Firestore.Query. <GetSnapshotAsync> d__50.MoveNext ()
--- End of stack trace from the previous location where the exception was triggered ---
   System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult ()
   at CommunicatorEngine.DataServiceCommunicator. <GetRoutes> d__2.MoveNext () Message: Status (StatusCode = Unavailable, Detail = "Connect Failed")

[jskeet]

When did this error take place? That's the important thing - you've logged a UTC time of 18:03, but is that when it actually took place?

Note that "Connect Failed" suggests it's more likely to be a networking issue - that doesn't sound like the authentication issue that you were seeing before...

[bluetoothfx]

Yes. But there is other internet activity happening on that application which was ok. Even I was connected to teamviewer when this error happened. So can't tell there was no internet activity. There was connection present but what other parameters should I check? And is there anything that I am missing to get data? Like creating connection or something. After some moments later it starts to work again. Is there any kind of connection object messing with me?

I have logged both datetime.now & utctime.now. Yes that when it happened.

[bluetoothfx]

Yes you are correct, that is a connection related issue. But is there anything left to do for me.

[jskeet]

It doesn't need to be "no internet connectivity" that's the problem. Some proxies have issues with HTTP/2.0, for example. I'm afraid it's very difficult to tell what's going on from the description here - I appreciate that intermittent issues can be very hard to track down.

I would possibly suggest writing a program which just issues a simple request (e.g. fetching a document snapshot) once every 10 seconds and log the results.

[bluetoothfx]

How long should I log? And what information I should log? Snapshot means just getting data? Or you mean something else.

[jskeet]

Document snapshot as in the Firestore API. You only need to log success or the error code, along with the time. It does sound like the Auth was entirely due to clock problems; this is probably very separate.

I suggest logging for 24 hours if possible, so we can see any patterns.

[bluetoothfx]

Ok. I will try to keep sampling Document snapshot as it is described here:
https://googleapis.github.io/google-cloud-dotnet/docs/Google.Cloud.Firestore/userguide.html#fetching-a-document-snapshot

Also will Log DateTime & DateTimeUtc ~24 hours on client PC. After having much information, I will get back. If anything you need more please just post. I will add up. Or I miss anything just give me a touch.

Thanks for everything.

[bluetoothfx]

Hello,
I have tried to log by requesting Firestore with 10 second interval. Though I didn't make it to 24 hours because of Usage limitation. If you please take a look on this, I will be glad. Also client reported that while the process was running there was network (internet) disconnection for sometime.

reqrspLog.txt

Thanks.

[jskeet]

Looking through your logs, the errors are these combinations of status codes and details:

• Status(StatusCode=Unavailable, Detail="Connect Failed")
• Status(StatusCode=Unavailable, Detail="Name resolution failure")
• Status(StatusCode=Unknown, Detail="Stream removed")

All of these look like network failures to me. If the client was reporting that they had network problems at the same time anyway, that would explain everything.

Are you still aware of any problems in the situation where a) the system clock is set correctly; b) the network is okay?

[bluetoothfx]

I have checked for sometime and didn't get anything beside this. So there might me something wrong with their connection. I will keep continue my investigation regarding this issue. And will post here if anything found.

[jskeet]

I'm going to close this issue now as I haven't heard anything more and I suspect the failures were due to network issues. If you run into other issues, please feel free to either open a new issue or add a comment to this one, depending on what's most appropriate.

[bluetoothfx]

Hello, sorry that it took much time to give you respond. There is some strange behavior regarding this issue. I am just telling this here because if it meant something to you or others.
My client has 2 internet connection one is WiFi and another is Mobile internet.

Event 01:
We were connected with some remote desktop and he showed me that when he was trying to get
data from Firestore (it was failing 2-3 times) after then suddenly it succeeded with WiFi broadband.

Event 02:
We were trying to get data and failing again and again after then he connected his mobile internet
with his laptop (switched his connection from WiFi broadband to mobile internet) and tried, then it works like champ. No error & no problem. BTW mobile internet speed is much slower then WiFi connection.

Is there anything which might occur this type of error? Client is in Germany.

[jskeet]

Without knowing what the exact error is in each case, it's very hard to say. Switching between network connections may well trigger any number of things that could fix transient errors without really explaining those errors.

If you can reproduce the problem more reliably, or at least provide a lot more information, we could have a look - but at the moment there's nothing more I can do.

[bluetoothfx]

Yes, understood your point & agreed. I will paste error log here if it is helpful, other wise there is also nothing in my hand really to share with you. It is very strange on the same internet connectivity the network is connected and we are doing communication over it and also other internet things is working but Firestore connection is failing sometimes, seems very strange.

Will share the log by today/tomorrow. If it helps to lead you anything.

Thanks.

[bluetoothfx]

The error is same as before. All the debug trace is same.

StatusCode=Unavailable, Detail="Connect Failed" which you have previously stated as a network problem. You may close the issue if needed, If I know something regarding this in future, I will share. Thanks for everything.

[jskeet]

Right, I'll leave it closed - note that it might also be a proxy issue, if you have a proxy that doesn't handle HTTP/2.0 properly.