I know there are plenty of other topics with the same error, but none that I found shared a cause…
Expected behavior
Expect (any) data to load.
Actual behavior
Consistently receiving this message on every table:
To eliminate the possibility of a UI error, I copied the offending request into Postman and it’s still failing. Ultimately, it looks like our server is timing out as Heroku is throwing a timeout at the router (see below).
This all began when adding a new table. When I saw the error, I reverted to the last functioning revision (from months earlier) and the issue persisted, so it seems this came out of nowhere with no obvious cause. The only difference is that there’s an extra table in the database that isn’t configured in Forest Admin.
Double checked DB connection string, etc, but the DB seems to be working perfectly fine. Can connect to it remotely and other applications on Heroku using the same database are functioning fine.
Since I was dealing with an issue, I since decided to upgrade, so everything should be on the latest. Confirmed that the server is running and accessible at the APPLICATION_URL
.
Failure Logs
Logs from Heroku (no other errors):
app[web.1]: GET /forest/accounts?fields%5B[FIELDS]&page%5Bnumber%5D=1&page%5Bsize%5D=50&searchExtended=0&sort=name&timezone=America%2FPhoenix - - - - ms
2021-03-29T17:45:09.281162+00:00
heroku[router]: at=error code=H12 desc="Request timeout" method=GET path="/forest/accounts?fields%5B[PAGE]&page%5Bsize%5D=50&searchExtended=0&sort=name&timezone=America%2FPhoenix" host=[HOST] request_id=3f1239f6-4624-436f-8007-d6d8efb829a4 fwd="[IP]" dyno=web.1 connect=1ms service=30000ms status=503 bytes=0 protocol=https
Context
Please provide any relevant information about your setup.
- Package Version:
- Express Version: ^4.17.1
- Sequelize Version: ^7.3.1
- Database Dialect: Postgres (SSL)
- Database Version: 12.6
- Project Name: Pharos
Hi @txtjournals welcome to our community.
I imagine that you encounter the issue on your production hosted on Heroku right?
And I supposed there is no issue on you development environment?
Have you got any error logs on your production server start?
Yes, our production environment hosted on Heroku. Our development environment has never really worked (it throws an error and redirects to the login screen), so I don’t use that as a baseline.
No error logs at all, including at startup. I even went and upgraded some of our smart actions to remove all deprecation warnings, as well.
Hi @txtjournals ,
Welcome to Forest.
Do you have any customization like route overriding or any custom code? Maybe, something containing a broken promise chain.
To debug that I suggest making the development environment working again, copy the layout from production to the development, and try to make things working in dev first.
Regards
Hi @Sliman_Medini - thanks for your response.
We have very minimal custom code. A few files in /routes that only impact 2-3 tables. All tables are failing to load, however.
I would love to get the development environment working again, but that failure seems to be something entirely different considering it’s a different error message and the UI keep kicking me out to the login screen.
Hi @txtjournals,
I find concerning that your development environment does not work, but let’s start with the production one first.
Could you share the logs of your server when it is starting? (In private if you consider it as sensitive data)
I can see that your environment is running the 7.3.1
version of forest-express-sequelize
, did you upgrade recently to this version? If that’s the case, did you follow our migration note?
Thanks in advance
Hi @jeffladiray - thanks for your help!
Startup logs are below. Yes, I followed all migration notes, however this issue started occurring back when I was on version 5. After trying everything I could to get it resolved (including rolling back to the previous working release), I decided to upgrade to v6 then to v7.
2021-04-02T19:16:13.180978+00:00 heroku[web.1]: Starting process with command `npm start`
2021-04-02T19:16:17.140133+00:00 app[web.1]:
2021-04-02T19:16:17.140210+00:00 app[web.1]: > project@0.0.1 start /app
2021-04-02T19:16:17.140211+00:00 app[web.1]: > node ./bin/www
2021-04-02T19:16:17.140211+00:00 app[web.1]:
2021-04-02T19:16:20.207818+00:00 heroku[web.1]: State changed from starting to up
2021-04-02T19:16:20.173652+00:00 app[web.1]: Your application is listening on port 43854.
2021-04-02T19:16:20.831192+00:00 app[web.1]: Your admin panel is available here: https://app.forestadmin.com/projects
Hello @txtjournals ,
Can you try to ping your server on /forest and tell me if it responds? Do you have any additional information about the error that occurs in the “network” window in the dev tool of the browser you are using?
Regards,
Hi @anon16419211 - thanks for your help!
Responds with a 204. Confirmed that it was the correct server via logs.
In fact, I do. I’m noticing CORS issues:
Access to XMLHttpRequest at '<MY_HOST>/forest/accounts?fields%5B<FIELDS>&fields<MORE_FIELDS>&searchExtended=0&sort=name&timezone=America%2FPhoenix' from origin 'https://app.forestadmin.com' has been blocked by CORS policy: No 'Access-Control-Allow-Origin' header is present on the requested resource.
I have the CORS_ORIGINS
environment variable set to https://app.forestadmin.com
and the OPTIONS
request for /forest/accounts
returns Access-Control-Allow-Origin: https://app.forestadmin.com
. Same issue with /forest/accounts/count
request. Looks similar to this issue.
If it is a CORS issue, however, I don’t understand why the Heroku router is timing out…
Hi @txtjournals !
Seems like you have two issues, could you recreate a new project from the same db on your local environment to see if it works ? Maybe some code was lost during a version upgrade
Once we get it working on your local env, we can take the steps to fix your other environments
Hi @anon94532230,
Thanks for your help! I was actually able to resolve my local issue - it was a DB hostname problem that was masked due to the browser caching a result and my local Forest Admin instance never actually receiving a request. Once I cleared cache, I was able to diagnose and resolve.
Digging into this some more, I don’t believe the CORS problem is the root issue. Whatever is causing the hangup on the server is causing a timeout. When the Heroku router returns after the timeout, since that response doesn’t include the CORS headers, that’s why I’m seeing that issue.
Hello @txtjournals,
So let me sum up, your development environment is now up and running, correct? Can you successfully login and fetch your data from the local instance?
Your remote server is hosted on Heroku, could you tell me where do you host the database? If it’s on Heroku as well, do you use self-signed certificates?
Could you please check the server console (on Heroku) to see if there are any errors or any messages when you try to access the data? Maybe also check if the database container has some logs?
I am sorry for all those questions and that it’s taking so long to be solved, but your answers would really help us to understand what’s wrong. Thank you for your patience
1 Like
Hi @anon90145840 - Thanks for your help!
Yes, development environment works great and data is loading just fine.
Yes, remote server on Heroku as is the Postgres DB. I’m not sure about the certificate, but all connection strings are managed by Heroku in the environment variables via DATABASE_URL
and DATABASE_SSL
.
Absolutely no error messages. I see web logs for the OPTIONS
and authentication requests, telling me the server is responding, but then just router timeouts on the requests for data. Here are are logs from application startup through requesting data:
2021-04-08T16:50:00.855696+00:00 heroku[web.1]: Starting process with command `npm start`
2021-04-08T16:50:03.720505+00:00 app[web.1]:
2021-04-08T16:50:03.720524+00:00 app[web.1]: > app@0.0.1 start /app
2021-04-08T16:50:03.720524+00:00 app[web.1]: > node ./bin/www
2021-04-08T16:50:03.720525+00:00 app[web.1]:
2021-04-08T16:50:05.229627+00:00 app[web.1]: Your application is listening on port 47160.
2021-04-08T16:50:05.501903+00:00 heroku[web.1]: State changed from starting to up
2021-04-08T16:50:05.801235+00:00 app[web.1]: Your admin panel is available here: https://app.forestadmin.com/projects
2021-04-08T16:50:35.712004+00:00 heroku[router]: at=info method=OPTIONS path="/forest/authentication" host=<MY_HOST>.herokuapp.com request_id=7760d555-cce6-491c-8c66-820af5093c4d fwd="<IP>" dyno=web.1 connect=0ms service=26ms status=204 bytes=405 protocol=https
2021-04-08T16:50:35.766589+00:00 app[web.1]: OPTIONS /forest/authentication 204 0 - 8.694 ms
2021-04-08T16:50:36.153030+00:00 heroku[router]: at=info method=POST path="/forest/authentication" host=<MY_HOST>.herokuapp.com request_id=ac398de1-2c47-4fa8-b94f-c16f1843a805 fwd="<IP>" dyno=web.1 connect=0ms service=361ms status=200 bytes=1286 protocol=https
2021-04-08T16:50:36.205166+00:00 app[web.1]: POST /forest/authentication 200 965 - 358.205 ms
2021-04-08T16:50:36.645840+00:00 heroku[router]: at=info method=OPTIONS path="/forest/authentication/callback?code=<CODE>&state=%7B%22renderingId%22%3A65005%7D" host=<MY_HOST>.herokuapp.com request_id=9f9d1c2c-c25b-44c5-b4ce-9f226524fe66 fwd="<IP>" dyno=web.1 connect=1ms service=27ms status=204 bytes=405 protocol=https
2021-04-08T16:50:36.703653+00:00 app[web.1]: OPTIONS /forest/authentication/callback?code=<CODE>&state=%7B%22renderingId%22%3A65005%7D 204 0 - 12.951 ms
2021-04-08T16:50:37.770620+00:00 heroku[router]: at=info method=GET path="/forest/authentication/callback?code=<CODE>&state=%7B%22renderingId%22%3A65005%7D" host=<MY_HOST>.herokuapp.com request_id=2cb56a62-bcd2-4a57-acda-2b810f9d1078 fwd="<IP>" dyno=web.1 connect=1ms service=1050ms status=200 bytes=784 protocol=https
2021-04-08T16:50:37.822825+00:00 app[web.1]: GET /forest/authentication/callback?code=<CODE>&state=%7B%22renderingId%22%3A65005%7D 200 463 - 1047.727 ms
2021-04-08T16:50:37.921670+00:00 app[web.1]: OPTIONS /forest/accounts?fields%5B<Fields>&fields%5B<More Fields>&page%5Bsize%5D=50&searchExtended=0&sort=name&timezone=America%2FPhoenix 204 0 - 0.416 ms
2021-04-08T16:50:37.869389+00:00 heroku[router]: at=info method=OPTIONS path="/forest/accounts?fields%5B<Fields>&fields%5B<More Fields>&page%5Bsize%5D=50&searchExtended=0&sort=name&timezone=America%2FPhoenix" host=<MY_HOST>.herokuapp.com request_id=ba667db9-ecc8-4d1d-b49b-d16e88db7c41 fwd="<IP>" dyno=web.1 connect=0ms service=4ms status=204 bytes=405 protocol=https
2021-04-08T16:50:38.186762+00:00 heroku[router]: at=info method=OPTIONS path="/forest/accounts/count?fields%5B<Fields>&fields%5Bvcard%5D=name&fields%5B<More_Fields>&timezone=America%2FPhoenix" host=<MY_HOST>.herokuapp.com request_id=48aee025-e6fc-4c7b-aca9-67fb87d79322 fwd="<IP>" dyno=web.1 connect=1ms service=12ms status=204 bytes=405 protocol=https
2021-04-08T16:50:38.234387+00:00 app[web.1]: OPTIONS /forest/accounts/count?fields%5B<Fields>&fields%5Bvcard%5D=name&fields%5B<More_Fields>&timezone=America%2FPhoenix 204 0 - 0.405 ms
2021-04-08T16:51:07.997277+00:00 app[web.1]: GET /forest/accounts?fields%5B<Fields>&fields%5B<More Fields>&page%5Bsize%5D=50&searchExtended=0&sort=name&timezone=America%2FPhoenix - - - - ms
2021-04-08T16:51:07.942854+00:00 heroku[router]: at=error code=H12 desc="Request timeout" method=GET path="/forest/accounts?fields%5B<Fields>&fields%5B<More Fields>&page%5Bsize%5D=50&searchExtended=0&sort=name&timezone=America%2FPhoenix" host=<MY_HOST>.herokuapp.com request_id=74436082-21e8-4a92-ad59-fab924dc799f fwd="<IP>" dyno=web.1 connect=1ms service=30000ms status=503 bytes=0 protocol=https
2021-04-08T16:51:08.264417+00:00 heroku[router]: at=error code=H12 desc="Request timeout" method=GET path="/forest/accounts/count?fields%5B<Fields>&fields%5Bvcard%5D=name&fields%5B<More_Fields>&timezone=America%2FPhoenix" host=<MY_HOST>.herokuapp.com request_id=c5ce910b-8ecb-4807-a897-9687393e5ab2 fwd="<IP>" dyno=web.1 connect=1ms service=30000ms status=503 bytes=0 protocol=https
2021-04-08T16:51:08.314993+00:00 app[web.1]: GET /forest/accounts/count?fields%5B<Fields>&fields%5Bvcard%5D=name&fields%5B<More_Fields>&timezone=America%2FPhoenix - - - - ms
I don’t see any Postgres logs whatsoever when tailing them while trying to request data. I’m not sure if this means it’s not even connecting to Postgres or if it’s all successful, but the request in ForestAdmin just isn’t returning.
Hi @txtjournals,
Sorry for not having been able to help you solve your issue so far.
We recently encountered issue with postrges databases hosted on heroku. Could you try to follow the solution steps from this thread: Unauthorized app / [object Object]
I’m not 100% sure your two issues are related but it might be the case (with heroku somehow hiding deeper logs about it).
Hi @anon37102731 - appreciate the help. I was really hoping this would be it, but alas, it appears not.
I added DATABASE_REJECT_UNAUTHORIZED=false
to the environment, keeping DATABASE_SSL=true
and am having the exact same issue: timeout with no errors.
I even have the newer version of the code in database.js
:
if (process.env.DATABASE_SSL && JSON.parse(process.env.DATABASE_SSL.toLowerCase())) {
const rejectUnauthorized = process.env.DATABASE_REJECT_UNAUTHORIZED;
if (rejectUnauthorized && (JSON.parse(rejectUnauthorized.toLowerCase()) === false)) {
databaseOptions.dialectOptions.ssl = { rejectUnauthorized: false };
} else {
databaseOptions.dialectOptions.ssl = true;
}
}
Hi @txtjournals ,
Did you give a try to make it work on a fresh development environment?
@Sliman_Medini - thanks for trying to help! Yes, sorry I had mentioned above that development environment works great. Same configuration copied from the UI and same codebase.
Ok,
Same code, same layout, only the deployment looks different.
Are you able to plug temporary the dev on the production database?