ETIMEDOUT for SAP CAP App on BTP with external Postgres DB

[Andreas_S6]

Hi all,

we have a SAP CAP based application running on BTP CF. We are using an external Postgres DB for storing our data. This Postgres DB runs in a docker container which on a VM hosted on a dedicated HETZNER server.

From time to time (~10-60 mins) we see TCP connection timeouts in the SAP CAP backend like this:

2024-09-16T07:41:56.145+0000 [APP/PROC/WEB/0] STDOUT [odata] - POST /odata/v4/api/fawkes/$batch
2024-09-16T07:41:56.150+0000 [APP/PROC/WEB/0] STDOUT [odata] - > currentUser currentUser()
2024-09-16T07:41:56.150+0000 [APP/PROC/WEB/0] STDOUT [user_service] - Instantiated User Service
2024-09-16T07:41:56.150+0000 [APP/PROC/WEB/0] STDOUT [user_service] - getOrCreateUser --> Start
2024-09-16T07:41:56.150+0000 [APP/PROC/WEB/0] STDOUT [user_service] - Checking DB for employee with id 3229
2024-09-16T07:43:46.793+0000 [APP/PROC/WEB/0] STDOUT [2024-09-16T07:43:46.791Z] ERROR    Error: read ETIMEDOUT
2024-09-16T07:43:46.793+0000 [APP/PROC/WEB/0] STDOUT at TCP.onStreamRead (node:internal/stream_base_commons:217:20)
2024-09-16T07:43:46.793+0000 [APP/PROC/WEB/0] STDOUT at TCP.callbackTrampoline (node:internal/async_hooks:128:17)
2024-09-16T07:43:46.795+0000 [APP/PROC/WEB/0] STDERR [cds] - ️Uncaught Error: read ETIMEDOUT
2024-09-16T07:43:46.796+0000 [APP/PROC/WEB/0] STDERR at TCP.onStreamRead (node:internal/stream_base_commons:217:20)
2024-09-16T07:43:46.796+0000 [APP/PROC/WEB/0] STDERR at TCP.callbackTrampoline (node:internal/async_hooks:128:17) {
2024-09-16T07:43:46.796+0000 [APP/PROC/WEB/0] STDERR errno: -110,
2024-09-16T07:43:46.796+0000 [APP/PROC/WEB/0] STDERR code: 'ETIMEDOUT',
2024-09-16T07:43:46.796+0000 [APP/PROC/WEB/0] STDERR syscall: 'read'
2024-09-16T07:43:46.796+0000 [APP/PROC/WEB/0] STDERR }
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR [cds] - Error: read ETIMEDOUT
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR at /home/vcap/deps/0/node_modules/pg/lib/client.js:526:17
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR at async Object.all (/home/vcap/deps/0/node_modules/@cap-js/postgres/lib/PostgresService.js:174:26)
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR at async PostgresService._checkCollation (/home/vcap/deps/0/node_modules/@cap-js/postgres/lib/PostgresService.js:97:21)
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR at async Promise.all (index 1)
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR at async PostgresService.begin (/home/vcap/deps/0/node_modules/@cap-js/db-service/lib/common/DatabaseService.js:70:7)
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR at async PostgresService._begin [as dispatch] (/home/vcap/deps/0/node_modules/@sap/cds/lib/srv/srv-tx.js:199:3) {
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR errno: -110,
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR code: 'ETIMEDOUT',
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR syscall: 'read',
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR query: "SELECT collname FROM pg_collation WHERE collname = 'en-x-icu';\n ^",
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR id: '1397371',
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR level: 'ERROR',
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR timestamp: 1726472626799
2024-09-16T07:43:46.806+0000 [APP/PROC/WEB/0] STDERR }
2024-09-16T07:43:46.810+0000 [RTR/1] STDOUT XXX-fawkes-backend.cfapps.eu30.hana.ondemand.com - [2024-09-16T07:41:56.136234108Z] "POST /odata/v4/api/fawkes/$batch HTTP/1.1" 200 395 324 "https://XXX-approuter.cfapps.eu30.hana.ondemand.com/XXX/index.html" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36" "10.1.8.0:30362" "10.1.9.9:61175" x_forwarded_for:"45.158.172.157, 10.1.8.1, 34.159.201.78, 10.1.8.0" x_forwarded_proto:"https" vcap_request_id:"72ddb4ca-6d57-4f41-5353-47909f3e9818" response_time:110.674250 gorouter_time:0.000126 app_id:"29f701b7-10bd-4dfe-9ea0-c1a1b6d3189b" app_index:"0" instance_id:"a2de1dff-2ea3-4cc2-47db-6e54" failed_attempts:0 failed_attempts_time:"-" dns_time:0.000000 dial_time:0.000000 tls_time:0.000000 backend_time:110.674125 x_cf_routererror:"-" x_correlationid:"72ddb4ca-6d57-4f41-5353-47909f3e9818" tenantid:"fawkes" sap_passport:"-" x_scp_request_id:"10e6c249-8c08-469b-8e4b-9bcf732f1271-66E7E144-9DE41A" x_cf_app_instance:"-" x_forwarded_host:"XXX-approuter.cfapps.eu30.hana.ondemand.com" x_custom_host:"-" x_ssl_client:"-" x_ssl_client_session_id:"-" x_ssl_client_verify:"-" x_ssl_client_subject_dn:"-" x_ssl_client_subject_cn:"-" x_ssl_client_issuer_dn:"-" x_ssl_client_notbefore:"-" x_ssl_client_notafter:"-" x_cf_forwarded_url:"-" traceparent:"-" true_client_ip:"-" x_request_id:"-" x_b3_traceid:"72ddb4ca6d574f41535347909f3e9818" x_b3_spanid:"535347909f3e9818" x_b3_parentspanid:"-" b3:"72ddb4ca6d574f41535347909f3e9818-535347909f3e9818"
2024-09-16T07:43:48.138+0000 [APP/PROC/WEB/0] STDERR npm notice
2024-09-16T07:43:48.138+0000 [APP/PROC/WEB/0] STDERR npm notice New minor version of npm available! 10.7.0 -> 10.8.3
2024-09-16T07:43:48.138+0000 [APP/PROC/WEB/0] STDERR npm notice Changelog: https://github.com/npm/cli/releases/tag/v10.8.3
2024-09-16T07:43:48.138+0000 [APP/PROC/WEB/0] STDERR npm notice To update run: npm install -g npm@10.8.3
2024-09-16T07:43:48.138+0000 [APP/PROC/WEB/0] STDERR npm notice
2024-09-16T07:43:48.173+0000 [APP/PROC/WEB/0] STDOUT Exit status 0
2024-09-16T07:43:48.184+0000 [CELL/SSHD/0] STDOUT Exit status 0
2024-09-16T07:43:53.700+0000 [CELL/0] STDOUT Cell 80e41736-2c4c-42a7-9cd7-971d529a7321 stopping instance a2de1dff-2ea3-4cc2-47db-6e54
2024-09-16T07:43:53.700+0000 [CELL/0] STDOUT Cell 80e41736-2c4c-42a7-9cd7-971d529a7321 destroying container for instance a2de1dff-2ea3-4cc2-47db-6e54
2024-09-16T07:43:53.711+0000 [API/11] STDOUT Process has crashed with type: "web"
2024-09-16T07:43:53.733+0000 [API/11] STDOUT App instance exited with guid 29f701b7-10bd-4dfe-9ea0-c1a1b6d3189b payload: {"instance"=>"a2de1dff-2ea3-4cc2-47db-6e54", "index"=>0, "cell_id"=>"80e41736-2c4c-42a7-9cd7-971d529a7321", "reason"=>"CRASHED", "exit_description"=>"Codependent step exited", "crash_count"=>1, "crash_timestamp"=>1726472633684041865, "version"=>"4a8848ae-2f50-4f13-b2c5-e8a3a64f44c5"}
2024-09-16T07:43:53.758+0000 [CELL/0] STDOUT Cell 6b4fecb4-665c-4073-9832-853892f693ef creating container for instance ae994730-42d9-4bdf-55a6-bbd7
2024-09-16T07:43:53.881+0000 [PROXY/0] STDOUT Exit status 137

On Postgres Side the log looks like this (don't be confused for the timestamps not matching):

2024-09-13 16:25:17.775 UTC [239] LOG:  could not receive data from client: Connection timed out
2024-09-13 16:25:17.775 UTC [238] LOG:  could not receive data from client: Connection timed out
2024-09-13 16:46:02.959 UTC [375] LOG:  could not receive data from client: Connection timed out
2024-09-13 16:47:08.495 UTC [391] LOG:  could not receive data from client: Connection timed out
2024-09-13 16:47:08.495 UTC [392] LOG:  could not receive data from client: Connection timed out

There is no explicit firewall configured and the connection to the database itself works - at least for a certain amount of time.

For testing purposes, I subscribed to the BTP Postgres service and created a binding to the application. In this setup, I don't have any connection issues.

I have already tried these things:

• Using the same Postgres DB version in my own setup as the DB which is provisioned in BTP
• Use the same (or almost the same) configuration of the database in my own setup as the BTP Postgres DB
• Tried two different locations for providing my own postgres db

So the question is: Why do I have these connection timeouts? I'm a bit out of ideas what to try next so any help is really appreciated!

Thanks
Andreas