Bernd Grolig
04/04/2022, 3:02 PMKevin Kho
04/04/2022, 3:03 PMprefect server start
?Bernd Grolig
04/04/2022, 3:07 PM[36mapollo_1 |[0m > @ serve /apollo
[36mapollo_1 |[0m > node dist/index.js
[36mapollo_1 |[0m
[36mapollo_1 |[0m Building schema...
[33mgraphql_1 |[0m INFO: 172.27.0.5:36484 - "POST /graphql/ HTTP/1.1" 200 OK
[36mapollo_1 |[0m Building schema complete!
[36mapollo_1 |[0m Server ready at <http://0.0.0.0:4200> :rocket: (version: 2022.01.25)
[36mapollo_1 |[0m Sending telemetry to Prefect Technologies, Inc.: {"source":"prefect_server","type":"startup","payload":{"id":"c22d6050-de0c-4f88-b0eb-bec859f43ab6","prefect_server_version":"2022.01.25","api_version":"0.2.0"}}
[33mgraphql_1 |[0m INFO: 172.27.0.5:36512 - "POST /graphql/ HTTP/1.1" 200 OK
[35mpostgres_1 |[0m 2022-04-04 14:14:24.586 UTC [41] ERROR: insert or update on table "log" violates foreign key constraint "log_flow_run_id_fkey"
[35mpostgres_1 |[0m 2022-04-04 14:14:24.586 UTC [41] DETAIL: Key (flow_run_id)=(97484f4c-5c8c-4aa0-bac1-b31dcac0a9a9) is not present in table "flow_run".
[35mpostgres_1 |[0m 2022-04-04 14:14:24.586 UTC [41] STATEMENT: WITH "log__mutation_result_alias" AS (INSERT INTO "public"."log" ( "created", "tenant_id", "is_loaded_from_archive", "task_run_id", "name", "id", "updated", "message", "timestamp", "level", "flow_run_id", "info" ) VALUES (DEFAULT, (NULL)::uuid, DEFAULT, (NULL)::uuid, ('prefect.subprocess_heartbeat')::varchar, ('76e218e5-71b2-4622-983c-7fa452b303ff')::uuid, DEFAULT, ('Failed to send heartbeat with exception: ReadTimeout(ReadTimeoutError("HTTPConnectionPool(host=''localhost'', port=4200): Read timed out. (read timeout=15)"))
And after that statement it continues to spam the log with errors that are somehow connected, but won't stop. So this continues basically forever. Within 5 minutes the logfile has already 1.6 million lines!
This is the error message
[35mpostgres_1 |[0m 2022-04-04 14:14:24.586 UTC [41] ERROR: insert or update on table "log" violates foreign key constraint "log_flow_run_id_fkey"
[35mpostgres_1 |[0m 2022-04-04 14:14:24.586 UTC [41] DETAIL: Key (flow_run_id)=(97484f4c-5c8c-4aa0-bac1-b31dcac0a9a9) is not present in table "flow_run".
[35mpostgres_1 |[0m 2022-04-04 14:14:24.586 UTC [41] STATEMENT: WITH "log__mutation_result_alias" AS (INSERT INTO "public"."log" ( "created", "tenant_id", "is_loaded_from_archive", "task_run_id", "name", "id", "updated", "message", "timestamp", "level", "flow_run_id", "info" ) VALUES (DEFAULT, (NULL)::uuid, DEFAULT, (NULL)::uuid, ('prefect.subprocess_heartbeat')::varchar, ('76e218e5-71b2-4622-983c-7fa452b303ff')::uuid, DEFAULT, ('Failed to send heartbeat with exception: ReadTimeout(ReadTimeoutError("HTTPConnectionPool(host=''localhost'', port=4200): Read timed out. (read timeout=15)"))
[35mpostgres_1 |[0m File "<string>", line 3, in raise_from
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/urllib3/connectionpool.py", line 444, in _make_request
[35mpostgres_1 |[0m httplib_response = conn.getresponse()
[35mpostgres_1 |[0m File "/usr/lib/python3.8/http/client.py", line 1348, in getresponse
[35mpostgres_1 |[0m response.begin()
[35mpostgres_1 |[0m File "/usr/lib/python3.8/http/client.py", line 316, in begin
[35mpostgres_1 |[0m version, status, reason = self._read_status()
[35mpostgres_1 |[0m File "/usr/lib/python3.8/http/client.py", line 277, in _read_status
[35mpostgres_1 |[0m line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
[35mpostgres_1 |[0m File "/usr/lib/python3.8/socket.py", line 669, in readinto
[35mpostgres_1 |[0m return self._sock.recv_into(b)
[35mpostgres_1 |[0m socket.timeout: timed out
[35mpostgres_1 |[0m
[35mpostgres_1 |[0m During handling of the above exception, another exception occurred:
[35mpostgres_1 |[0m
[35mpostgres_1 |[0m Traceback (most recent call last):
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/requests/adapters.py", line 440, in send
[35mpostgres_1 |[0m resp = conn.urlopen(
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/urllib3/connectionpool.py", line 785, in urlopen
[35mpostgres_1 |[0m retries = retries.increment(
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/urllib3/util/retry.py", line 550, in increment
[35mpostgres_1 |[0m raise six.reraise(type(error), error, _stacktrace)
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/urllib3/packages/six.py", line 770, in reraise
[35mpostgres_1 |[0m raise value
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/urllib3/connectionpool.py", line 703, in urlopen
[35mpostgres_1 |[0m httplib_response = self._make_request(
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/urllib3/connectionpool.py", line 451, in _make_request
[35mpostgres_1 |[0m self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/urllib3/connectionpool.py", line 340, in _raise_timeout
[35mpostgres_1 |[0m raise ReadTimeoutError(
[35mpostgres_1 |[0m urllib3.exceptions.ReadTimeoutError: HTTPConnectionPool(host=''localhost'', port=4200): Read timed out. (read timeout=15)
[35mpostgres_1 |[0m
[35mpostgres_1 |[0m During handling of the above exception, another exception occurred:
[35mpostgres_1 |[0m
[35mpostgres_1 |[0m Traceback (most recent call last):
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/prefect/cli/heartbeat.py", line 68, in flow_run
[35mpostgres_1 |[0m client.update_flow_run_heartbeat(id)
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/prefect/client/client.py", line 1288, in update_flow_run_heartbeat
[35mpostgres_1 |[0m self.graphql(
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/prefect/client/client.py", line 452, in graphql
[35mpostgres_1 |[0m result = <http://self.post|self.post>(
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/prefect/client/client.py", line 407, in post
[35mpostgres_1 |[0m response = self._request(
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/prefect/client/client.py", line 641, in _request
[35mpostgres_1 |[0m response = self._send_request(
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/prefect/client/client.py", line 506, in _send_request
[35mpostgres_1 |[0m response = <http://session.post|session.post>(
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/requests/sessions.py", line 577, in post
[35mpostgres_1 |[0m return self.request(''POST'', url, data=data, json=json, **kwargs)
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/requests/sessions.py", line 529, in request
[35mpostgres_1 |[0m resp = self.send(prep, **send_kwargs)
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/requests/sessions.py", line 645, in send
[35mpostgres_1 |[0m r = adapter.send(request, **kwargs)
[35mpostgres_1 |[0m File "/var/opt/datawarehouse/prefect/.venv/lib/python3.8/site-packages/requests/adapters.py", line 532, in send
[35mpostgres_1 |[0m raise ReadTimeout(e, request=request)
[35mpostgres_1 |[0m requests.exceptions.ReadTimeout: HTTPConnectionPool(host=''localhost'', port=4200): Read timed out. (read timeout=15)')::varchar, ('2022-04-01T09:16:17.761276Z')::timestamptz, ('ERROR')::varchar, ('97484f4c-5c8c-4aa0-bac1-b31dcac0a9a9')::uuid, (NULL)::jsonb), (DEFAULT, (NULL)::uuid, DEFAULT, (NULL)::uuid, ('prefect.subprocess_heartbeat')::varchar, ('cc83da54-2f81-4ea3-afcd-506a6af4b644')::uuid, DEFAULT, ('Failed to send heartbeat with exception: ReadTimeout(ReadTimeoutError("HTTPConnectionPool(host=''localhost'', port=4200): Read timed out. (read timeout=15)"))
[35mpostgres_1 |[0m Traceback (most recent call last):
... to be continued rapidly ... (1.6 mio lines in some minutes)
Some basics to my setup:
• I'm runnng Prefect server on a VPS with Ubuntu 20.04, 6 cores, 16GB RAM.
• I have a NGINX Reverse Proxy to access my containers.
• I also updated to the latest version 1.1 today
• Prefect Local Server and all the docker containers running on the same machine
• The Apollo Server is exposed to localhost, the UI is mapped via NGINX and accessible through an subdomain.
As I mentioned the system worked wonderful last week. Maybe the problem with the logs was already present, but I was not aware, as I didn't saw the output on the terminal screen.
By analyzing the first Postgres Error it seems, that Postgres wants to access a table log and gets the error: ==> "ERROR: insert or update on table "log" violates foreign key constraint "log_flow_run_id_fkey"
The detail message shows: DETAIL: Key (flow_run_id)=(97484f4c-5c8c-4aa0-bac1-b31dcac0a9a9) is not present in table "flow_run".
So this would mean, that a certain flow can not be updated as it is not present.
As I made a clean installation with a new database, I would not expect that there is any flow id in the database...
Would be great if somebody could help me on this issue. It seems that something is messed up, but I just don't know what....
Thanks everybody!Kevin Kho
04/04/2022, 3:18 PMBernd Grolig
04/04/2022, 3:20 PMKevin Kho
04/04/2022, 3:25 PMBernd Grolig
04/04/2022, 3:26 PMKevin Kho
04/04/2022, 3:27 PMBernd Grolig
04/04/2022, 3:28 PMKevin Kho
04/04/2022, 3:50 PMBernd Grolig
04/04/2022, 3:53 PMI was more of asking if you may have some flow run that is still running and it's hitting the API, and then you restart server and the database, but that flow run is still hitting the API to log stuff, and how the API can't find that flow in the database. Does that make sense to you?
I'm pretty sure, that I stopped all flows within the UI on Friday, because, they are still buggy and I did not like that they spam the system over the weekend.Just confirming, you started the server, and then registered, and then connected the agent, and then you got all of those log table errors? Did you run the flow?
Not really: I get the errors immediately when I start the prefect server start
After the containers are up, and the ASCII art appears, Postgres starts to throw these errors rapdilyKevin Kho
04/04/2022, 4:04 PMBernd Grolig
04/04/2022, 4:06 PMKevin Kho
04/04/2022, 5:07 PMprefect server start
should be clean because it’s containers. It would be more like clearing the docker cacheAnna Geller
04/04/2022, 6:14 PMBernd Grolig
04/07/2022, 5:12 AMKevin Kho
04/07/2022, 5:28 AMBernd Grolig
04/07/2022, 7:47 PMKevin Kho
04/07/2022, 7:53 PMBernd Grolig
04/07/2022, 7:54 PMKevin Kho
04/07/2022, 7:54 PMBernd Grolig
04/07/2022, 7:56 PMKevin Kho
04/07/2022, 7:57 PMBernd Grolig
04/07/2022, 8:00 PM