Scheduler stops running: psycopg2.OperationalError: SSL SYSCALL error: EOF detected #18846

Activity

1. hpatel-higi

   added

   area:core

   kind:bugThis is a clearly a bugThis is a clearly a bug

   on Oct 8, 2021
2. hpatel-higi commented on Oct 8, 2021

   

   hpatel-higi

   on Oct 8, 2021

   Author

   More actions

   We just upgraded to version 2.1.4 from 1.10.8 and upgrade postgres to version 11. Issue happens in Azure App Service that uses Azuse Postgresql instance.
3. potiuk commented on Oct 9, 2021

   

   potiuk

   on Oct 9, 2021

   Member

   More actions

   This is problem with long running queries and your deployment configuration (killing the connection after some time of inactivity) : Likely you can solve it via setting keep-alive on your connection https://stackoverflow.com/questions/24130305/postgres-ssl-syscall-error-eof-detected-with-python-and-psycopg
4. potiuk

   closed this as completedon Oct 9, 2021
5. potiuk commented on Oct 9, 2021

   

   potiuk

   on Oct 9, 2021

   Last edited by potiuk

   Member

   More actions

   I realized that it was not entirely clear how to do it, so I added a new section to the documentation about it in #18850 . It would be great if you can see if following those docs fixes your problems @hpatel-higi
6. hpatel-higi commented on Oct 11, 2021

   

   hpatel-higi

   on Oct 11, 2021

   Author

   More actions

   I have made the changes just waiting on getting the code published. Once that has happened and ive tested this out i will let you know if it worked.

   👀React with 👀1Reacted by Jarek Potiuk
7. potiuk

   added a commit that references this issue on Oct 12, 2021

   Add information about keepalives for managed Postgres (#18850)

   ...

   f22c834
8. hpatel-higi commented on Oct 13, 2021

   

   hpatel-higi

   on Oct 13, 2021

   Author

   More actions

   Still getting that error.

   I set the sql_alchemy_connect_args values as such: sql_alchemy_connect_args = log_config.KEEPALIVE_KWARGS

   Inside log_config.py i have:

   KEEPALIVE_KWARGS: Dict[str, Any] = {
       "keepalives": 1,
       "keepalives_idle": 30,
       "keepalives_interval": 5,
       "keepalives_count": 5
   }
   
9. potiuk commented on Oct 13, 2021

   

   potiuk

   on Oct 13, 2021

   Last edited by potiuk

   Member

   More actions

   Then I think you need to do some more checking:

   a) check if the keep alives are comming (I think you should find out in Postgres logs - they should be coming every 30 seconds). I am sure Postgres logging can be set in the way to show keepalives in logs (but I am not sure how to do it - not a postgres expert)

   b) look in the logs of Postgres why maybe Postgres itself keeps on closing the connection (if it does close it - I suspected it's a firewall in between). There might be many reasons, memory problem, stale processes, lack of other resources, maximum timeouts set for query and so on. You should at least be ble to correlate the time when Airflow conection was closed and find corresponding log in Postgres server and match them - and maybe you will see who closed the connection (if you see both Postgres and Airflow seeing the "other" party to close the connection - this is likely something in between).

   c) If you see keepalives coming, and see that both postgres and airflow see the connection killd, I would advise to see if there are maybe other settings in you network that kills an established, long runnning connection with keepalives - some enterprise firewall rules etc - eventually you migh need to involve Azure support to help with finding out what is this.
10. hpatel-higi commented on Oct 13, 2021

    

    hpatel-higi

    on Oct 13, 2021

    Author

    More actions

    I keep seeing this message over and over.

    could not receive data from client: An existing connection was forcibly closed by the remote host.
11. potiuk commented on Oct 13, 2021

    

    potiuk

    on Oct 13, 2021

    Last edited by potiuk

    Member

    More actions

    could not receive data from client: An existing connection was forcibly closed by the remote host.

    Asume you see it in the Postgres DB logs? Then likely something in-between - some firewall likely. If both parties are seing the other party closed connection, then it must be the firewall. Maybe the keepalive configuration did not work for some reason (you need to double check if they are actually coming) or mayb the firewall is more aggressive.

    One thing that COULD help a bit (though it would not likely address the root cause) is if you put PGBouncer between Airflow and Postgres DB (if you don't have it already). This is a recommended solution for Postgres (See the notes in "Setting Up the Database" https://airflow.apache.org/docs/apache-airflow/stable/howto/set-up-database.html?highlight=pgbouncer#setting-up-a-postgresql-database) and while it is unlikely it will cure the cause, if you put it close to Airflow and not behind the firewall, you might instead configure PGBouncer to do more aggressive KeepAlives and possibly even recover after connection is dropped.
12. hpatel-higi commented on Oct 13, 2021

    

    hpatel-higi

    on Oct 13, 2021

    Author

    More actions

    Also these are the server parameters that were set by default, do you know if these should match the keep_alive values?:

    

    The other thing to note is that we never had issues like this before upgrading to 2.1.4 and upgrading postgres database to version 11 from 9.3. Could there be any other config value from airflow.cfg that could be causing this problem as well?
13. potiuk commented on Oct 13, 2021

    

    potiuk

    on Oct 13, 2021

    Member

    More actions

    Not that I am aware of,
14. jedcunningham

    added a commit that references this issue on Oct 14, 2021

    Add information about keepalives for managed Postgres (#18850)

    ...

    85ec578
15. hpatel-higi commented on Oct 18, 2021

    

    hpatel-higi

    on Oct 18, 2021

    Author

    More actions

    @potiuk so im getting a weird behavior now after adding the keep_alives args. Parent task in DAG succeeds but the subsequent task that should run after that task fail.

    

    In the above image you can see the parent task is still running but it marked the subsequent tasks as failed already.

    Here is the logs:

    [2021-10-18 17:12:25,191] {{taskinstance.py:1212}} INFO - Marking task as SUCCESS. dag_id=build_station_logs, task_id=init, execution_date=20211018T160000, start_date=20211018T171124, end_date=20211018T171225
    [2021-10-18 17:12:35,791] {{local_task_job.py:151}} INFO - Task exited with return code 0
    [2021-10-18 17:12:40,247] {{local_task_job.py:261}} INFO - 0 downstream tasks scheduled from follow-on schedule check
    
16. hpatel-higi commented on Oct 18, 2021

    

    hpatel-higi

    on Oct 18, 2021

    Author

    More actions

    This is also the other error we are getting now:

    2021-10-15T04:26:35.894475528Z sqlalchemy.exc.OperationalError: (psycopg2.OperationalError) server closed the connection unexpectedly
    2021-10-15T04:26:35.894479728Z 	This probably means the server terminated abnormally
    2021-10-15T04:26:35.894483628Z 	before or while processing the request.