App connection timed out

1

As of yesterday, I can no longer view the logs without errors:

2021-09-28T10:52:43.384290272Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:52:45.316346348Z app[f15d975f] ams [info] 2021/09/28 12:52:45 #245 soc unexpected status: 403 (mr42hh)
2021-09-28T10:52:45.600410905Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:52:46.662876138Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:52:48.661364922Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:53:04.975410482Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:53:12.888346911Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:53:26.173710310Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:53:40.994420458Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:53:45.750380508Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:53:48.896199903Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:53:53.232225574Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:53:53.877478231Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"
2021-09-28T10:54:05.152611034Z proxy[f15d975f] ams [error] error.code=2001 error.message="App connection timed out"

I’ve checked my single instance is healthy.

Looks like a potential infrastructure problem?

2

We’ve added this yesterday.

We now log errors for non-HTTP handlers. This should give more visibility into anything going wrong when not using the http handler. Errors happening at our proxy’s level were previously only sent to app logs for HTTP requests.

I think these are mislabeled, I’m pushing out a fix. I believe these are actually “app connection idle” errors. These happen if your connection doesn’t send or receive bytes for 60 seconds.

3

@jerome I would suggest to not log connection idle as it’s not an error state. I’m also seeing this multiple times per second. App is working as normal.

4

These are errors are actual errors. If the connection was not closed gracefully then it means either the client or the app will get an error.

This might’ve surfaced a bug where we’re not ever closing these connections :thinking:. However, once one end closes the connection, it should definitely stop the transfer. If neither the client nor the app has closed the connection (for any reason) before 60 seconds of inactivity, it is forcefully closed.

I deployed a change that sets the level for this particular log to “warning”.

I’ll investigate to see if these errors are actually “real” or a side effect of something were doing wrong.

5

It would be helpful if the error told me what connection it is even referring to. I have a GRPC endpoint and don’t care for how long clients keep the connection open. I would definitely care about not getting the log file swamped :wink:

6

Turning it off for now, until I figure out a better solution. Possibly putting this specific error at the debug level so you can filter it out.