PowerBIDatasetRefreshOperator task fails whereas dataset refresh succeeds

[Ohashiro]

Apache Airflow Provider(s)

microsoft-azure

Versions of Apache Airflow Providers

apache-airflow-providers-microsoft-azure==11.1.0

Apache Airflow version

2.10.2

Operating System

linux

Deployment

Google Cloud Composer

Deployment details

No response

What happened

We use the operator PowerBIDatasetRefreshOperator to refresh our PowerBI datasets. Sometimes, the task quickly fails with the following error:

airflow.exceptions.AirflowException: An error occurred: Unable to fetch the details of dataset refresh with Request Id: <request id>

However, on PowerBI side, the dataset is refreshed (timezone GMT+1, both the time in the refresh and the log are about the same):

If I understand correctly, this corresponds to an error in this function, which may mean that there was an error when trying to fetch the refresh status, even though the refresh was running. Maybe the error comes from the request to the Microsoft API, which could be improved with a retry (but we did not test for the moment).

What you think should happen instead

The task should succeed. (since the dataset refresh suceeded)

How to reproduce

On our side, we use the following configuration.

refresh_powerbi_dataset_success = PowerBIDatasetRefreshOperator(
        task_id="refresh_powerbi_dataset_success",
        conn_id="our-conn-id",
        dataset_id="our-dataset-id",
        group_id="our-group-id",
    )

The dataset ID and group ID correspond to valid PowerBI dataset and workspace.

Anything else

This bug occurs about once every 3 task runs (the task fails but the refresh succeeds). Sometimes if fails several times in a row then works again, other times it works on the first run. I think this should mean that the configuration is good (since the operator often works fine).
I haven't been able to identify any specific pattern.

Are you willing to submit PR?

• Yes I am willing to submit a PR!

Code of Conduct

• I agree to follow this project's Code of Conduct

[dabla]

Can you just specify a retry with following parameters on the PowerBIDatasetRefreshOperator?

retry_exponential_backoff=True,  # to increase the delay after each failed attempt
retry_delay=60,
retries=5,

[Ohashiro]

Thank you for the suggestion! (sorry I didn't know these fields were available)
I just tried it and still get some task fails (with the same error). I will try tweaking the parameters a little to see if it fixes the issue.
Do you know to what (which request) do these "retries" apply?

[dabla]

Those parameters apply on the whole operator, you could also try to specify the check_interval and timeout parameter, which by default both are 60 seconds, I think timeout should be greater then then check_interval, otherwise it will stop polling due to timeout.

[Ohashiro]

OK I see, so the retry is not specific to the "get status" request.
From what I understand, the issue seems to be that the very first request (to get the refresh status) fails (maybe because the refresh id is not yet available for this endpoint) and the task exits.
If I understand correctly, the retry on the operator allows us to re-run the whole process (so re-trigger a refresh), instead of retrying the request to get the refresh status already running.

[dabla]

OK I see, so the retry is not specific to the "get status" request. From what I understand, the issue seems to be that the very first request (to get the refresh status) fails (maybe because the refresh id is not yet available for this endpoint) and the task exits. If I understand correctly, the retry on the operator allows us to re-run the whole process (so re-trigger a refresh), instead of retrying the request to get the refresh status already running.

Indeed, you're correct about it. I still don't understand your issue completely, as from what I see in the code of the
PowerBIDatasetRefreshOperator, it first triggers the refresh datasets and then polls and wait for the refresh to complete (which by default has a timeout of 60 seconds). So indeed it could happen that the refresh isn't ready or started yet, but still I would expect it to retry within the timeout interval, unless of course the timeout has expired, but that's something you can parametrize.

[dabla]

I understand the issue, I've checked the code of the PowerBITrigger and the check_interval is set to 60 seconds, but the timeout is also 60 seconds by default, which means the status is only fetched once and then it fails like in your example log. So you should reduce the check_interval value to like 10 seconds for example, or even a bit less. So try setting the check_interval to 10 seconds. Maybe we should do a PR and add a check that the check_interval must be smaller than the timeout and set it to 10 seconds by default.

[Ohashiro]

Hello!
Thank you very much for taking the time to look at the code and making this suggestion.
I tried to reduce the check_interval to 5, unfortunately it did not seem to fix the issue on our side.

Also, I thought that the default timeout was 1 week because of this line:

airflow/providers/src/airflow/providers/microsoft/azure/triggers/powerbi.py

Line 57 in 608de6b

timeout: float = 60 * 60 * 24 * 7,

But maybe I got this wrong. Am I mistaken?

Regarding the bug, I think the issue may come from the very first request to get the refresh status, at this line:

airflow/providers/src/airflow/providers/microsoft/azure/triggers/powerbi.py

Line 116 in f7da5e4

dataset_refresh_status, dataset_refresh_error = await fetch_refresh_status_and_error()

This request is made by the PowerBi hook (using the method get_refresh_details_by_refresh_id) and I think that, sometimes, the API is not yet "up-to-date" with the latest refresh IDs and can't find the status of our refresh ID. So, we fall in this case:

airflow/providers/src/airflow/providers/microsoft/azure/hooks/powerbi.py

Line 159 in f7da5e4

if len(refresh_histories) == 0:

and the hook raises the error "Unable to fetch the details of dataset refresh with Request Id" (which is also what I find in my Airflow logs). Do you think it makes sense?

I did try to add a retry on this request (and it seemed to fix the bug), but I understand that you don't want to introduce this type of custom retry mechanism. Maybe another option could be to wait "check_interval" seconds BEFORE sending the first request. What do you think?

[dabla]

Hello! Thank you very much for taking the time to look at the code and making this suggestion. I tried to reduce the check_interval to 5, unfortunately it did not seem to fix the issue on our side.

Also, I thought that the default timeout was 1 week because of this line:

airflow/providers/src/airflow/providers/microsoft/azure/triggers/powerbi.py

Line 57 in 608de6b

timeout: float = 60 * 60 * 24 * 7,

But maybe I got this wrong. Am I mistaken?

Regarding the bug, I think the issue may come from the very first request to get the refresh status, at this line:

airflow/providers/src/airflow/providers/microsoft/azure/triggers/powerbi.py

Line 116 in f7da5e4

dataset_refresh_status, dataset_refresh_error = await fetch_refresh_status_and_error()

This request is made by the PowerBi hook (using the method get_refresh_details_by_refresh_id) and I think that, sometimes, the API is not yet "up-to-date" with the latest refresh IDs and can't find the status of our refresh ID. So, we fall in this case:

airflow/providers/src/airflow/providers/microsoft/azure/hooks/powerbi.py

Line 159 in f7da5e4

if len(refresh_histories) == 0:

and the hook raises the error "Unable to fetch the details of dataset refresh with Request Id" (which is also what I find in my Airflow logs). Do you think it makes sense?

I did try to add a retry on this request (and it seemed to fix the bug), but I understand that you don't want to introduce this type of custom retry mechanism. Maybe another option could be to wait "check_interval" seconds BEFORE sending the first request. What do you think?

@Ohashiro from what I can see from my smartphone (no laptop atm) your explanation does totally make sense. Waiting before doing the actual invocation could make sense, but I would suggest checking the PowerBIDatasetRefreshException and reinvoke the method after waiting for the the interval when this error occurs within the code.

[dabla]

@Ohashiro also thank you for investigating this thouroughly. It would also be nice to have a unit test which reproduces this behaviour, so on fist invocation raising an PowerBIDatasetRefreshException, then the code waits for the interval on on second invocation the call would succeed. This should be doable by mocking the PowerBI hook.

[Ohashiro]

@dabla
Thank you for your feedback! I'll be working on it today.

I have a quick question regarding the best practices. Given that the PowerBi Hook can raise PowerBIDatasetRefreshException for different scenarios (including when it didn't find the refresh Id, but not only), do you think it would be best to create a new dedicated exception for our case (ex: PowerBIDatasetRefreshIdNotFoundException) or would you rather check the exception message to see if it matches "Unable to fetch the details of dataset refresh with Request Id"?