Question around the Metaflow UI showing old runs a...
# ask-metaflow
f
Question around the Metaflow UI showing old runs as still running when they were aborted by the SFN orchestrator: There's 2 heartbeat parameters that were recently reduced from 6 days to 1 day:
OLD_RUN_FAILURE_CUTOFF_TIME
[ for runs that do not have a heartbeat, controls at what point a running status run should be considered failed. Default is 1 day (in milliseconds)]
RUN_INACTIVE_CUTOFF_TIME
[ for runs that have a heartbeat, controls how long a run with a failed heartbeat should wait for possibly queued tasks to start and resume heartbeat updates. Default is 1 day (in seconds)] I've redeployed the UI Service with the new image, and in the UI's quick links I can confirm it's there:
Copy code
Application version: v1.2.5
Service version: 2.3.7--
For some reason, it's still showing some as running from within the last week that were previously aborted. I've also tried manually setting those two environment variables to 1 day, which also didn't seem to make a difference 🤷 Curious if there's any thoughts or pointers
b
@fresh-laptop-72652 those parameters should fix the problem and the next release of metaflow-service will have those cutoff times reduced by default
f
hmm strange, I have those two set in the ECS task environment as well
Copy code
"environment": [
                {
                    "name": "OLD_RUN_FAILURE_CUTOFF_TIME",
                    "value": "86400000"
                },
                {
                    "name": "RUN_INACTIVE_CUTOFF_TIME",
                    "value": "86400"
                },
odd that it's still showing the stale info
b
Here is a related issue that shows how these variables are used in queries- https://github.com/Netflix/metaflow-service/pull/240/files
Are you able to view your db logs to ensure that the right values are being passed through to the queries?
f
🕵️ looks like it has the right values in the query
Copy code
SELECT * FROM (
                SELECT
                    runs_v3.flow_id AS flow_id,runs_v3.run_number AS run_number,runs_v3.run_id AS run_id,runs_v3.user_name AS user_name,runs_v3.ts_epoch AS ts_epoch,runs_v3.last_heartbeat_ts AS last_heartbeat_ts,runs_v3.tags AS tags,runs_v3.system_tags AS system_tags,
                (CASE
                    WHEN system_tags ? ('user:' || user_name)
                    THEN user_name
                    ELSE NULL
                END) AS user,
                COALESCE(runs_v3.run_id, runs_v3.run_number::text) AS run
                ,
        (CASE
            WHEN end_attempt IS NOT NULL
                AND end_attempt_ok.ts_epoch < end_attempt.ts_epoch
            THEN NULL
            WHEN end_attempt_ok IS NOT NULL
            THEN end_attempt_ok.ts_epoch
            WHEN runs_v3.last_heartbeat_ts IS NOT NULL
                AND latest_failed_task IS NOT NULL
                AND @(extract(epoch from now())-runs_v3.last_heartbeat_ts)>60
            THEN runs_v3.last_heartbeat_ts*1000
            WHEN runs_v3.last_heartbeat_ts IS NOT NULL
                AND latest_failed_task IS NULL
                AND @(extract(epoch from now())-runs_v3.last_heartbeat_ts)>86400
            THEN runs_v3.last_heartbeat_ts*1000
            ELSE NULL
        END) AS finished_at
        ,
        (CASE
            WHEN end_attempt_ok.value IS TRUE
            THEN 'completed'
            WHEN runs_v3.last_heartbeat_ts IS NOT NULL
                AND latest_failed_task IS NOT NULL
                AND @(extract(epoch from now())-runs_v3.last_heartbeat_ts)>60
            THEN 'failed'
            WHEN end_attempt_ok.value IS FALSE
                AND end_attempt.ts_epoch > end_attempt_ok.ts_epoch
            THEN 'running'
            WHEN end_attempt_ok.value IS FALSE
            THEN 'failed'
            WHEN runs_v3.last_heartbeat_ts IS NULL
                AND @(extract(epoch from now())*1000-runs_v3.ts_epoch)>86400000
            THEN 'failed'
            WHEN runs_v3.last_heartbeat_ts IS NOT NULL
                AND latest_failed_task IS NULL
                AND @(extract(epoch from now())-runs_v3.last_heartbeat_ts)>86400
            THEN 'failed'
            ELSE 'running'
        END) AS status
        ,
        (CASE
            WHEN end_attempt_ok.value IS TRUE
            THEN end_attempt_ok.ts_epoch - runs_v3.ts_epoch
            WHEN end_attempt IS NOT NULL
                AND end_attempt.ts_epoch > end_attempt_ok.ts_epoch
                AND runs_v3.last_heartbeat_ts IS NOT NULL
            THEN runs_v3.last_heartbeat_ts*1000-runs_v3.ts_epoch
            WHEN end_attempt IS NOT NULL
            THEN end_attempt_ok.ts_epoch - runs_v3.ts_epoch
            WHEN runs_v3.last_heartbeat_ts IS NOT NULL
            THEN runs_v3.last_heartbeat_ts*1000-runs_v3.ts_epoch
            WHEN runs_v3.last_heartbeat_ts IS NULL
                AND @(extract(epoch from now())::bigint*1000-runs_v3.ts_epoch)>86400000
            THEN NULL
            ELSE @(extract(epoch from now())::bigint*1000-runs_v3.ts_epoch)
        END) AS duration
        
                FROM runs_v3
                
        LEFT JOIN LATERAL (
            SELECT
                ts_epoch,
                (CASE
                    WHEN pg_typeof(value)='jsonb'::regtype
                    THEN value::jsonb->>0
                    ELSE value::text
                END)::boolean as value
            FROM metadata_v3 as attempt_ok
            WHERE
                runs_v3.flow_id = attempt_ok.flow_id AND
                runs_v3.run_number = attempt_ok.run_number AND
                attempt_ok.step_name = 'end' AND
                attempt_ok.field_name = 'attempt_ok'
            ORDER BY ts_epoch DESC
            LIMIT 1
        ) as end_attempt_ok ON true
         
        LEFT JOIN LATERAL (
            SELECT ts_epoch
            FROM metadata_v3 as attempt
            WHERE
                runs_v3.flow_id = attempt.flow_id AND
                runs_v3.run_number = attempt.run_number AND
                attempt.step_name = 'end' AND
wonder if there's some sort of caching going on, although I'd of expected that to have been cleared as part of the ECS deployment when updating the env variables 🤔
b
I would expect the cache to be cleared with a restart too. You could double check that by running the query to see if you get the same results. If you do, the next thing I would look at is last_heartbeat_ts for that run
f
it seems like there might be some edge cases that could arise from missing metadata, noticing that the metadata doesn't appear to have full coverage of each of the retry attempts across all the fields/values also found some examples in the UI > 6 days, so this appears to be unrelated to those query parameters
spent some time trying to grok those queries to trace everything out but gotta head out for now
from the query the UI runs, it actually seems to consistently get the correct
duration
of
4104177
which seems right relative to the differences when looking at the underlying runs_v3 table
1678912015823
(in ms) -> Wednesday, March 15, 2023 82655.823 PM
1678916120
(in s) -> Wednesday, March 15, 2023 93520 PM
4104177
(in ms) = 1.14 hrs
I might also just be getting a bit loopy with these conversions between time units though lolsob
b
did you uncover anything?
f
hey @brave-lion-15961 sorry for the hold up – haven't had time to circle back and look into this further yet, but can quickly confirm that the old
Running
flows are still present in the UI that are > 7d (when the runs were aborted SFN executions within minutes/hours of initially running weeks ago) feel free to this thread if you'd like and I can let you guys know if I get some time and find anything in a day or two hopefully – appreciate your help in narrowing down that the gap doesn't appear related to those UI config params!