Timestamp sync seems broken #1014
Comments
|
Hi, are you using the latest version? There was an earlier version where the time offset would not get reset after the difference between the server and the client got smaller than 500ms after being more than 500ms before. |
|
Yes, using 8.0.3. I think I may have found the issue. I noticed that the PartialRateLimiter was kicking off a lot, so I changed to total rate limiter and the issue seems gone. I have the feeling that because the execution of the request was being delayed, those requests didn't get the AutoTimestamp (maybe they were applied the autotimestamp before de Rate Limit wait), hence when they are finally executed they are "out of sync" of timestamp, so the Autotimestamp should run again after the Rate Limit Wait. Makes sense? |
|
I have a feeling that my assumption is 100% right. My ratelimiter kick in briefly and right there I got a couple of Timestamp errors again |
|
Right, that makes sense. I'll look into a fix, thanks for the analysis |
|
My pleasure 😊
Enviado desde mi iPhone
… El 27 feb 2022, a las 12:50, Jan Korf ***@***.***> escribió:
Right, that makes sense. I'll look into a fix, thanks for the analysis
—
Reply to this email directly, view it on GitHub, or unsubscribe.
Triage notifications on the go with GitHub Mobile for iOS or Android.
You are receiving this because you authored the thread.
|
|
Also it feels like applying by default the PartialEndpointRate limiter is too aggressive, specially if you use a mix of endpoints. In my vase it was triggering all the time on the get account info endpoint, which is an expensive one, but making way more calls on lighter endpoints. It feels like the totalRateLimiter is a better choice by default.
Enviado desde mi iPhone
… El 27 feb 2022, a las 12:58, Andres Del Rio ***@***.***> escribió:
My pleasure 😊
Enviado desde mi iPhone
>> El 27 feb 2022, a las 12:50, Jan Korf ***@***.***> escribió:
>>
>
> Right, that makes sense. I'll look into a fix, thanks for the analysis
>
> —
> Reply to this email directly, view it on GitHub, or unsubscribe.
> Triage notifications on the go with GitHub Mobile for iOS or Android.
> You are receiving this because you authored the thread.
|
|
Notice how the performance of some of my code degraded dramatically because of the rate limiter since I upgraded to 8.0.3 on friday. It went back to reasonable times today when I changed to the totalRateLimiter, with no errors or failures |
|
Hm intresting, I'll take a look at that. Also I've fixed the issue where timestamps time out when the rate limiter triggers in 8.0.4. Although that might not be an issue for you anymore if it no longer triggers ;) |
|
Yeah for me it is fine as I changed to TotalRateLimiter, but yeah definitelly will help others (It was a bit tricky to find the root cause and there may be people struggling with it out there). Thanks! |
|
Hey, how did you test the fix? I got a burst of timestam errors for 1 hour earlier today after upgrading to 8.0.4... |
|
Hm weird. I've tested it by adding an |
|
Ah! So autotimestamp by default syncs every hour? It may be that….
Enviado desde mi iPhone
… El 28 feb 2022, a las 11:20, Jan Korf ***@***.***> escribió:
Hm weird. I've tested it by adding an await Task.Delay(10000) in the spot where the rate limit would trigger, so simulating a rate limit waiting. That was correctly creating a timestamp after the rate limiting had passed.
Was it happening again after a rate limit? Or during normal process? If you have a lot of time drift, it might be that time syncing once every hour isn't often enough.
—
Reply to this email directly, view it on GitHub, or unsubscribe.
Triage notifications on the go with GitHub Mobile for iOS or Android.
You are receiving this because you authored the thread.
|
|
Yes, you can set the interval in the client options. But if you have a lot of drift the best solution might be to use a third party app to sync your server time more often with a time provider. People have been using the SP TimeSync tool with success to make sure the the time is correct, which will always be a more reliable way than trying to keep in sync by offsetting the timestamp in this library. |
|
Yeah my problem was I removed the autotimestamp interval adjustment in the options when I was investigating the rate limiter issue 😅 the issue with trying to update the OS time is that I’m running my stuff in azure app service and when I looked at it some time ago it was not very reliable to adjust the os time on those types of virtual machines
Enviado desde mi iPhone
… El 28 feb 2022, a las 11:33, Jan Korf ***@***.***> escribió:
Yes, you can set the interval in the client options. But if you have a lot of drift the best solution might be to use a third party app to sync your server time more often with a time provider. People have been using the SP TimeSync tool with success to make sure the the time is correct, which will always be a more reliable way than trying to keep in sync by offsetting the timestamp in this library.
—
Reply to this email directly, view it on GitHub, or unsubscribe.
Triage notifications on the go with GitHub Mobile for iOS or Android.
You are receiving this because you authored the thread.
|
|
Haha I see. Try using a shorter interval, and let me know if you have any more issues |
|
I’m going to switch the logging back to debug and let you know as I still some spikes in timestamp errors when i get some spikes in activity. I’ll let you know if I see anything odd
Enviado desde mi iPhone
… El 28 feb 2022, a las 11:45, Jan Korf ***@***.***> escribió:
Haha I see. Try using a shorter interval, and let me know if you have any more issues
—
Reply to this email directly, view it on GitHub, or unsubscribe.
Triage notifications on the go with GitHub Mobile for iOS or Android.
You are receiving this because you authored the thread.
|
|
I think there's still some cause-effect somewhere between the Timestamp adjustment and those failures I see. See how on the first image the timestamp is supposed to be adjusted at 1.45PM and right after taht I got a bunch of timestamp errors (when the timestamp was supposed to be adjusted just a moment before). Also it is interesting that it happens mainly on my calls to the GetAccountInfo, just in case that gets you some more insight...
|
|
Hm well the time syncing is an estimate. It's a simple procedure of recording the local timestamp, requesting the server timestamp and then comparing the 2, and adding the difference to the timestamp sent to the server for authenticated requests. Here's the source for determining the offset: The reason you get the errro mainly on the GetAccountInfoAsync call is because timestamping is only used in authenticated requests. You're running this on Azure, is time syncing necessary? I would excpect Azure server to have a correct timestamp. |
|
Yeah using it In Azure but somehow there are misalignments on the timestamps. I don’t think the problem is with your time stamp adjustment routine, i think it has something to do with volume/concurrency (I see it happen mainly when there are many calls to that method happening at the same time for different users)
Enviado desde mi iPhone
… El 28 feb 2022, a las 15:59, Jan Korf ***@***.***> escribió:
Hm well the time syncing is an estimate. It's a simple procedure of recording the local timestamp, requesting the server timestamp and then comparing the 2, and adding the difference to the timestamp sent to the server for authenticated requests. Here's the source for determining the offset:
https://github.com/JKorf/CryptoExchange.Net/blob/4c4cfbb60e0def028c074bb6a7459f019fb1c0ae/CryptoExchange.Net/Clients/RestApiClient.cs#L63
The reason you get the errro mainly on the GetAccountInfoAsync call is because timestamping is only used in authenticated requests.
You're running this on Azure, is timestamping necessary? I would excpect Azure server to have a correct timestamp.
—
Reply to this email directly, view it on GitHub, or unsubscribe.
Triage notifications on the go with GitHub Mobile for iOS or Android.
You are receiving this because you authored the thread.
|
|
I found again another occurrence of that strong correlation: whenever I see a timestamp adjustment in the logs because if some other method call, right after that the GetAccountInfo calls fail for a little while. When there has not been any recent timestamp adjustment they are fine
Enviado desde mi iPhone
… El 28 feb 2022, a las 17:28, Andres Del Rio ***@***.***> escribió:
Yeah using it I. Azure but somehow there are misalignments on the timestamps. I believe th GetAccountInfo are authenticated calls aren’t they (you are retrieving one account data, so it has to be authenticated for that account). Maybe that’s the problem? Also I don’t think the problem is with your time stamp adjustment routine, either those calls to GetAccountInfo need to eb adjusted timestamp too (I think that’s the key, and also I thought I had the feeling you were not adjusting them when I looked at your fix’s changes) or has something to do with volume/concurrency (I see it happen mainly when there are many calls to that method happening at the same time for different users)
Enviado desde mi iPhone
>> El 28 feb 2022, a las 15:59, Jan Korf ***@***.***> escribió:
>>
>
> Hm well the time syncing is an estimate. It's a simple procedure of recording the local timestamp, requesting the server timestamp and then comparing the 2, and adding the difference to the timestamp sent to the server for authenticated requests. Here's the source for determining the offset:
> https://github.com/JKorf/CryptoExchange.Net/blob/4c4cfbb60e0def028c074bb6a7459f019fb1c0ae/CryptoExchange.Net/Clients/RestApiClient.cs#L63
>
> The reason you get the errro mainly on the GetAccountInfoAsync call is because timestamping is only used in authenticated requests.
>
> You're running this on Azure, is timestamping necessary? I would excpect Azure server to have a correct timestamp.
>
> —
> Reply to this email directly, view it on GitHub, or unsubscribe.
> Triage notifications on the go with GitHub Mobile for iOS or Android.
> You are receiving this because you authored the thread.
|
|
Those differences seem way too large to me. 1100ms difference between 6 minutes, thats not right. The question is what is the cause of this.. I've thought of another potential cause of delayed requests. Can you try upping this value if you haven't already? |
|
Default connection limit was indeed a problem long ago on my code, but it's been months since that was tuned. This behaviour only started happening since the upgrade to 8.X. Has the way in which HTTP clients are handled changed? |
|
Or any concurrency race condition that you can think of? |
|
Hm request creating/sending hasnt changed much, rate limiting changed but shouldn't influence it much. Though you could try to turn the rate limiter of completely. |
|
I'm going to check on my code for any potential things that may be clogging up connections, but this has not been a problem for long (maybe something has been developing for some time and by coincidence started manifesting itself now).. Can you think of anything that maybe has made the clients more chatty? |
|
I was on 7.x 😅 I only found out when exchange info started breaking last week. I’ve done some optimisations in my code as it seems that over time I was calling way too much to GetAccountInfo (which is an expensive 10 points weight call anyway), and it feels it could be contributing to it. I’ll let you know if I still see the issue.
Thanks!
Enviado desde mi iPhone
… El 28 feb 2022, a las 22:51, Jan Korf ***@***.***> escribió:
Hm request creating/sending hasnt changed much, rate limiting changed but shouldn't influence it much. Though you could try to turn the rate limiter of completely.
Timesyncing also changed a bit, though it's mostly just the code moved from Binance to the CryptoExchange.Net base library. Obviously since there seems to be something going on with time syncing it's possible something did change and is breaking now.
What exact version were you on where you didnt have issues? I'll look into it some more tomorrow.
—
Reply to this email directly, view it on GitHub, or unsubscribe.
Triage notifications on the go with GitHub Mobile for iOS or Android.
You are receiving this because you authored the thread.
|
|
I did find another thing, in 7.x there was some functionality that would re-sync the timestamp when a timestamp error was received. This might prevent multiple errors happening for a certain time span since the time should be re-synced when the error is received. I've re-added this functionality in 8.0.5, so that might help you as well. |
|
Mmmmm that may be part of it too. After my optimisations since yesterday In my code the occurrences have been reducen massively (tipical thing that you start overloading little by little over time and only manifests itself during the perfect storm hahahaa), but I think your changes in 0.4 and 0.5 will help too 😊 the last one about resynching after a failure makes a lot of sense. Thanks a lot for all this man!
Enviado desde mi iPhone
… El 1 mar 2022, a las 10:46, Jan Korf ***@***.***> escribió:
I did find another thing, in 7.x there was some functionality that would re-sync the timestamp when a timestamp error was received. This might prevent multiple errors happening for a certain time span since the time should be re-synced when the error is received. I've re-added this functionality in 8.0.5, so that might help you as well.
—
Reply to this email directly, view it on GitHub, or unsubscribe.
Triage notifications on the go with GitHub Mobile for iOS or Android.
You are receiving this because you authored the thread.
|
|
I know what you mean haha. |
|
Interesting, this triggers the windows time syncing? Might be a good alternative to a 3rd party program |
|
Are you sure that will work in PaaS services? If I remember right it was not very workable for PaaS models
Enviado desde mi iPhone
… El 1 mar 2022, a las 15:44, Jan Korf ***@***.***> escribió:
Interesting, this triggers the windows time syncing? Might be a good alternative to a 3rd party program
—
Reply to this email directly, view it on GitHub, or unsubscribe.
Triage notifications on the go with GitHub Mobile for iOS or Android.
You are receiving this because you authored the thread.
|
|
As mentioned earlier, is you try that at most you would very temporarily syncing the VM clock, but azure would resync again with the host clock by design, so you would have to constantly update while getting all kind of errors on timestamp with Binance because of the constant fluctuations in clock adjustment. You’d better stick to JKorf‘s timestamp resync 😉
Enviado desde mi iPhone
… El 2 mar 2022, a las 1:38, HypsyNZ ***@***.***> escribió:
Interesting, this triggers the windows time syncing? Might be a good alternative to a 3rd party program
Yes this triggers the built in time-syncing mechanism of the OS, Its basically like clicking "Sync Now" but there is no cooldown.
Are you sure that will work in PaaS services?
https://docs.microsoft.com/en-us/azure/virtual-machines/windows/time-sync
It seems like you have access to w32tm
—
Reply to this email directly, view it on GitHub, or unsubscribe.
Triage notifications on the go with GitHub Mobile for iOS or Android.
You are receiving this because you authored the thread.
|
It seems I still get the problem every now and then and I don't think it's caused by the high concurrency (right before upgrading to 8.x my code was pretty much the same), so there has to be something else that may have changed, either in the way connections are handled or the timestamp syncing. I just saw that in 8.0.6 you introduced a small change around time syncing. Could that have some effect? |
|
@JKorf I think I have found somethig that has changed since 8.x that is surely impacting this. I kind of saw the other day in the logs that you are automatically "updating/keeping" trading rules" (so making regular exchangeInfo requests to Binance API) which were not there before. I can see that in the logs of my azure services too, where there are calls being made to the ExchangeInfo endpoint that were not there before. 8.x. IMO you shoul not be automaticaly making those calls (or at least not that frequently) as those are quite expensive and slow and thus more than likely being the ones causing the clogging in outbound requests and so increasing the likelyhood of timestamp missalignment (I know from experience as I was doing a similar thing in the past untill I started caching those on my side with an expiry date of 24 hours). Notice that I moved to 8.x version by the 25th and that moment is when the exchangeInfo requests spiked
Does this make sense? |
|
It seems that for every order placed you are checking the trade rules, where you are triggering the ExchangeInfor call, suuuuuper expensive and slow call. You shouldn't be doing that unless you are applying some caching
|
|
ok, last one for today today. So I see you have this option to define how often to refresh the trade rules (which you have set by default to 60 minutes, which is way too often IMO) , so I have set it to 24 hours in my code. This all makes sense now why I was seeing those spikes in failures when there was an spike in orders created from my code. This behaviour should be documented somewhere so people is aware of it.
|
|
@HypsyNZ I agree, which is why it isn't enabled by default. Which raises the question @andresdrb, are you setting the |
|
@andresdrb Just checking in, how is it atm? Any improvement? |
|
It happens less, but still happens every now and then. I still feel there's something off that was not happening before... |
|
Hi guys, I have the same issue. I am on 8.0.9 and everything runs fine on my dev machine. But when I try to deploy I run into the issue instantly. I tested this on two different machines. I synced time several times, no way out :( |
and others
Describe the bug
Since upgraded to 8.x version the timestamp sync ssems to intermitently (every few hours) fail and spend 1-2 hours out of sync (givin "Timestamp for this request was 1000ms ahead..." messages).
To Reproduce
Happens on all endpoints called (I call accountInfo, exchangeInfo, trading, etc). AutoTimestamp setting is set to true
The text was updated successfully, but these errors were encountered: