Use time.time() for dag file process start time

[ephraimbuddy]

We currently use Psutil's create_time for process start time,
which gives the time the process started using the system clock. We can use
time.time to track when the process started processing the files instead.

In breeze, once the laptop hibbernates, you would have to restart the dag
processor but this fixes it. Since this does not happen in other deployments,
we suspect this issue is peculiar to breeze.

Closes: #47937, Closes: #47294

[jedcunningham]

You've probably found the right root cause, but returning now for start_time isn't the fix I don't think.

[ephraimbuddy]

Updated

Dismiss following Jed comment

[ashb]

We don't compare it to time.monotonic though -- we compare it to time.time()

airflow/airflow/dag_processing/manager.py

Lines 972 to 975 in 8242ba5

	now = time.time()
	processors_to_remove = []
	for file, processor in self._processors.items():
	duration = now - processor.start_time

[ephraimbuddy]

I ha

We don't compare it to time.monotonic though -- we compare it to time.time()

airflow/airflow/dag_processing/manager.py

Lines 972 to 975 in 8242ba5

	now = time.time()
	processors_to_remove = []
	for file, processor in self._processors.items():
	duration = now - processor.start_time

Yeah. My description is wrong. I will update the commit message

[ashb]

https://github.com/giampaolo/psutil/blob/a17550784b0d3175da01cdb02cee1bc6b61637dc/psutil/__init__.py#L766-L773

If you are worried about process reuse and the start_time being wrong, then call proc.create_time() once first.

However the chance of process reuse happening and being the cause of the bugs is tiny. I'm not saying it can't happen, but that the for it to, a large number of processes need to have been created, enough for the pid to overflow and wrap around. I don't know what the limit is, but I suspect it's somewhere around 64k processes on OSX.

[ephraimbuddy]

https://github.com/giampaolo/psutil/blob/a17550784b0d3175da01cdb02cee1bc6b61637dc/psutil/__init__.py#L766-L773

If you are worried about process reuse and the start_time being wrong, then call proc.create_time() once first.

However the chance of process reuse happening and being the cause of the bugs is tiny. I'm not saying it can't happen, but that the for it to, a large number of processes need to have been created, enough for the pid to overflow and wrap around. I don't know what the limit is, but I suspect it's somewhere around 64k processes on OSX.

I was able to determine that it’s not process reuse by printing out the previous PIDs before process creation and checking it with the new ID.

My observation is that any process created after the heartbeat recovery message of say recovered after 290ms use the time before the recovery instead of the time after the recovery which is when the process started being used for file processing. So instead of using the process start time, we can use the time that the process started processing the files.

[github-actions]

This pull request has been automatically marked as stale because it has not had recent activity. It will be closed in 5 days if no further activity occurs. Thank you for your contributions.

[ashb]

Closed in favour of #50238