Unable to ingest PowerBI

[rdaudt]

Hi.

We are running openmetadata 1.5.3 in OpenShift in Azure. We are having trouble retrieving metadata from PowerBI. The pipeline runs for about 1 hour and completes with SUCCESS status. But it doesn't fetch any metadata and we find error messages in the log.
I have reproduced the entire log below. Log snippets that call my attention are:

1. Access token is generated successfully
   [2025-01-24T21:10:56.939+0000] {client.py:84} INFO - Generating PowerBi access token
   [2025-01-24T21:10:57.087+0000] {client.py:101} INFO - PowerBi Access Token generated successfully

2. but then it repeats it several times
   [2025-01-24T21:10:59.504+0000] {client.py:224} WARNING - sleep 30 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 100 more time(s)...

3. after timeout it returns
   TypeError: metadata.ingestion.source.dashboard.powerbi.models.GroupsResponse() argument after ** must be a mapping, not NoneType

4. after time we get the message that it was not able to fetch workspaces
   [2025-01-24T22:15:37.220+0000] {metadata.py:208} ERROR - Unable to fetch any PowerBI workspaces

It strikes me like a privileges-related issue, but this is just a wild guess. Has anybody run into similar issue?
Appreciate any help with this.

Thanks

=================================
Full Log
[2025-01-24T21:10:56.492+0000] {ingestion_pipeline_mixin.py:52} DEBUG - Created Pipeline Status for pipeline Power BI at ... pipelineState=<PipelineState.running: 'running'> startDate=Timestamp(root=1737753056292) timestamp=Timestamp(root=1737753056292) endDate=None status=None
[2025-01-24T21:10:56.939+0000] {client.py:84} INFO - Generating PowerBi access token
[2025-01-24T21:10:56.940+0000] {client.py:91} INFO - Token does not exist in the cache. Getting a new token.
[2025-01-24T21:10:57.087+0000] {client.py:101} INFO - PowerBi Access Token generated successfully
[2025-01-24T21:10:57.125+0000] {test_connections.py:203} INFO - Running GetDashboards...
[2025-01-24T21:10:57.428+0000] {test_connections.py:228} INFO - Test connection results:
[2025-01-24T21:10:57.428+0000] {test_connections.py:229} INFO - lastUpdatedAt=None status=<StatusType.Running: 'Running'> steps=[TestConnectionStepResult(name='GetDashboards', mandatory=True, passed=True, message=None, errorLog=None)]
[2025-01-24T21:10:57.429+0000] {metadata.py:57} DEBUG - Source type:powerbi,<class 'metadata.ingestion.source.dashboard.powerbi.metadata.PowerbiSource'> configured
[2025-01-24T21:10:59.504+0000] {client.py:224} WARNING - sleep 30 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 100 more time(s)...
[2025-01-24T21:11:29.551+0000] {client.py:224} WARNING - sleep 60 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 99 more time(s)...
[2025-01-24T21:12:31.249+0000] {client.py:224} WARNING - sleep 30 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 100 more time(s)...
[2025-01-24T21:13:01.295+0000] {client.py:224} WARNING - sleep 60 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 99 more time(s)...
[2025-01-24T21:14:03.251+0000] {client.py:224} WARNING - sleep 30 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 100 more time(s)...
[2025-01-24T21:14:33.292+0000] {client.py:224} WARNING - sleep 60 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 99 more time(s)...
[2025-01-24T21:15:33.682+0000] {client.py:224} WARNING - sleep 30 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 100 more time(s)...
[2025-01-24T21:16:03.725+0000] {client.py:224} WARNING - sleep 60 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 99 more time(s)...
[2025-01-24T21:17:04.736+0000] {client.py:224} WARNING - sleep 90 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 98 more time(s)...
[2025-01-24T21:18:35.000+0000] {client.py:224} WARNING - sleep 120 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 97 more time(s)...
[2025-01-24T21:20:35.157+0000] {client.py:224} WARNING - sleep 150 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 96 more time(s)...
[2025-01-24T21:23:05.318+0000] {client.py:224} WARNING - sleep 180 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 95 more time(s)...
[2025-01-24T21:26:05.499+0000] {client.py:224} WARNING - sleep 210 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 94 more time(s)...
[2025-01-24T21:29:35.686+0000] {client.py:224} WARNING - sleep 240 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 93 more time(s)...
[2025-01-24T21:33:35.928+0000] {client.py:224} WARNING - sleep 270 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 92 more time(s)...
[2025-01-24T21:38:06.049+0000] {client.py:224} WARNING - sleep 300 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 91 more time(s)...
[2025-01-24T21:43:06.234+0000] {client.py:224} WARNING - sleep 330 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 90 more time(s)...
[2025-01-24T21:48:36.546+0000] {client.py:224} WARNING - sleep 360 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 89 more time(s)...
[2025-01-24T21:54:36.731+0000] {client.py:224} WARNING - sleep 390 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 88 more time(s)...
[2025-01-24T22:01:06.864+0000] {client.py:224} WARNING - sleep 420 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 87 more time(s)...
[2025-01-24T22:08:07.093+0000] {client.py:224} WARNING - sleep 450 seconds and retrying https://api.powerbi.com/v1.0/myorg/admin/groups 86 more time(s)...
[2025-01-24T22:15:37.220+0000] {client.py:235} DEBUG - Traceback (most recent call last):
File "/home/airflow/.local/lib/python3.10/site-packages/metadata/ingestion/source/dashboard/powerbi/client.py", line 231, in fetch_all_workspaces
response = GroupsResponse(**response_data)
TypeError: metadata.ingestion.source.dashboard.powerbi.models.GroupsResponse() argument after ** must be a mapping, not NoneType
[2025-01-24T22:15:37.220+0000] {client.py:236} WARNING - Error fetching workspaces: metadata.ingestion.source.dashboard.powerbi.models.GroupsResponse() argument after ** must be a mapping, not NoneType
[2025-01-24T22:15:37.221+0000] {metadata.py:208} ERROR - Unable to fetch any PowerBI workspaces
[2025-01-24T22:15:37.222+0000] {metadata.py:59} DEBUG - Source type:powerbi,<class 'metadata.ingestion.source.dashboard.powerbi.metadata.PowerbiSource'> prepared
[2025-01-24T22:15:37.749+0000] {metadata.py:68} DEBUG - Sink type:metadata-rest, <class 'metadata.ingestion.sink.metadata_rest.MetadataRestSink'> configured
[2025-01-24T22:15:37.750+0000] {topology_runner.py:166} DEBUG - Processing node producer='get_services' stages=[NodeStage(type_=<class 'metadata.generated.schema.entity.services.dashboardService.DashboardService'>, processor='yield_create_request_dashboard_service', nullable=False, must_return=True, overwrite=False, consumer=None, context='dashboard_service', store_all_in_context=False, clear_context=False, store_fqn=False, cache_entities=True, use_cache=False), NodeStage(type_=<class 'metadata.ingestion.models.ometa_classification.OMetaTagAndClassification'>, processor='yield_bulk_tags', nullable=True, must_return=False, overwrite=True, consumer=None, context=None, store_all_in_context=False, clear_context=False, store_fqn=False, cache_entities=False, use_cache=False)] children=['bulk_data_model', 'dashboard'] post_process=['mark_dashboards_as_deleted', 'mark_datamodels_as_deleted'] threads=False
[2025-01-24T22:15:37.750+0000] {topology_runner.py:231} DEBUG - Processing stage: type_=<class 'metadata.generated.schema.entity.services.dashboardService.DashboardService'> processor='yield_create_request_dashboard_service' nullable=False must_return=True overwrite=False consumer=None context='dashboard_service' store_all_in_context=False clear_context=False store_fqn=False cache_entities=True use_cache=False
[2025-01-24T22:15:37.996+0000] {topology_runner.py:231} DEBUG - Processing stage: type_=<class 'metadata.ingestion.models.ometa_classification.OMetaTagAndClassification'> processor='yield_bulk_tags' nullable=True must_return=False overwrite=True consumer=None context=None store_all_in_context=False clear_context=False store_fqn=False cache_entities=False use_cache=False
[2025-01-24T22:15:37.996+0000] {topology_runner.py:166} DEBUG - Processing node producer='list_datamodels' stages=[NodeStage(type_=<class 'metadata.generated.schema.entity.data.dashboardDataModel.DashboardDataModel'>, processor='yield_bulk_datamodel', nullable=True, must_return=False, overwrite=True, consumer=['dashboard_service'], context=None, store_all_in_context=False, clear_context=False, store_fqn=False, cache_entities=False, use_cache=True)] children=None post_process=None threads=False
[2025-01-24T22:15:37.997+0000] {topology_runner.py:166} DEBUG - Processing node producer='get_dashboard' stages=[NodeStage(type_=<class 'metadata.ingestion.models.ometa_classification.OMetaTagAndClassification'>, processor='yield_tags', nullable=True, must_return=False, overwrite=True, consumer=None, context=None, store_all_in_context=False, clear_context=False, store_fqn=False, cache_entities=False, use_cache=False), NodeStage(type_=<class 'metadata.generated.schema.entity.data.chart.Chart'>, processor='yield_dashboard_chart', nullable=True, must_return=False, overwrite=True, consumer=['dashboard_service'], context='charts', store_all_in_context=True, clear_context=True, store_fqn=False, cache_entities=False, use_cache=True), NodeStage(type_=<class 'metadata.generated.schema.entity.data.dashboardDataModel.DashboardDataModel'>, processor='yield_datamodel', nullable=True, must_return=False, overwrite=True, consumer=['dashboard_service'], context='dataModels', store_all_in_context=True, clear_context=True, store_fqn=False, cache_entities=False, use_cache=True), NodeStage(type_=<class 'metadata.generated.schema.entity.data.dashboard.Dashboard'>, processor='yield_dashboard', nullable=False, must_return=False, overwrite=True, consumer=['dashboard_service'], context='dashboard', store_all_in_context=False, clear_context=False, store_fqn=False, cache_entities=False, use_cache=True), NodeStage(type_=<class 'metadata.generated.schema.api.lineage.addLineage.AddLineageRequest'>, processor='yield_dashboard_lineage', nullable=True, must_return=False, overwrite=True, consumer=['dashboard_service'], context=None, store_all_in_context=False, clear_context=False, store_fqn=False, cache_entities=False, use_cache=False), NodeStage(type_=<class 'metadata.generated.schema.type.usageRequest.UsageRequest'>, processor='yield_dashboard_usage', nullable=True, must_return=False, overwrite=True, consumer=['dashboard_service'], context=None, store_all_in_context=False, clear_context=False, store_fqn=False, cache_entities=False, use_cache=False)] children=None post_process=None threads=False
[2025-01-24T22:15:37.997+0000] {topology_runner.py:252} DEBUG - Post processing node producer='get_services' stages=[NodeStage(type_=<class 'metadata.generated.schema.entity.services.dashboardService.DashboardService'>, processor='yield_create_request_dashboard_service', nullable=False, must_return=True, overwrite=False, consumer=None, context='dashboard_service', store_all_in_context=False, clear_context=False, store_fqn=False, cache_entities=True, use_cache=False), NodeStage(type_=<class 'metadata.ingestion.models.ometa_classification.OMetaTagAndClassification'>, processor='yield_bulk_tags', nullable=True, must_return=False, overwrite=True, consumer=None, context=None, store_all_in_context=False, clear_context=False, store_fqn=False, cache_entities=False, use_cache=False)] children=['bulk_data_model', 'dashboard'] post_process=['mark_dashboards_as_deleted', 'mark_datamodels_as_deleted'] threads=False
[2025-01-24T22:15:37.997+0000] {dashboard_service.py:415} INFO - Mark Deleted Dashboards set to True
[2025-01-24T22:15:38.044+0000] {dashboard_service.py:429} INFO - Mark Deleted Datamodels set to True
[2025-01-24T22:15:38.208+0000] {ingestion_pipeline_mixin.py:52} DEBUG - Created Pipeline Status for pipeline Power BI at ... pipelineState=<PipelineState.success: 'success'> startDate=Timestamp(root=1737753056292) timestamp=Timestamp(root=1737753056292) endDate=Timestamp(root=1737756938131) status=IngestionStatus(root=[StepSummary(name='PowerBI', records=0, updated_records=0, warnings=0, errors=0, filtered=0, failures=None), StepSummary(name='OpenMetadata', records=0, updated_records=0, warnings=0, errors=0, filtered=0, failures=None)])
[2025-01-24T22:15:38.209+0000] {base.py:133} WARNING - Error trying to close the step <metadata.ingestion.source.dashboard.powerbi.metadata.PowerbiSource object at 0x7f557c796d10> due to [[Errno 2] No such file or directory: '/tmp/pbitFiles']
[2025-01-24T22:15:38.209+0000] {logger.py:181} INFO - �[1mStatuses detailed info:�[0m
[2025-01-24T22:15:38.209+0000] {logger.py:181} INFO - �[1mPowerBI Status:�[0m
[2025-01-24T22:15:38.210+0000] {logger.py:181} INFO - {'failures': [], 'filtered': [], 'records': [], 'source_start_time': 1737753056.5937996, 'updated_records': [], 'warnings': []}�[0m
[2025-01-24T22:15:38.210+0000] {logger.py:181} INFO - �[1mOpenMetadata Status:�[0m
[2025-01-24T22:15:38.210+0000] {logger.py:181} INFO - {'failures': [], 'filtered': [], 'records': [], 'source_start_time': 1737756937.749853, 'updated_records': [], 'warnings': []}�[0m
[2025-01-24T22:15:38.210+0000] {logger.py:181} INFO - �[1mExecution Time Summary�[0m
[2025-01-24T22:15:38.212+0000] {logger.py:181} INFO -
�[0m
[2025-01-24T22:15:38.212+0000] {logger.py:181} INFO - �[1mWorkflow PowerBI Summary:�[0m
[2025-01-24T22:15:38.212+0000] {logger.py:181} INFO - Processed records: 0�[0m
[2025-01-24T22:15:38.212+0000] {logger.py:181} INFO - Updated records: 0�[0m
[2025-01-24T22:15:38.213+0000] {logger.py:181} INFO - Warnings: 0�[0m
[2025-01-24T22:15:38.213+0000] {logger.py:181} INFO - Errors: 0�[0m
[2025-01-24T22:15:38.213+0000] {logger.py:181} INFO - �[1mWorkflow OpenMetadata Summary:�[0m
[2025-01-24T22:15:38.213+0000] {logger.py:181} INFO - Processed records: 0�[0m
[2025-01-24T22:15:38.213+0000] {logger.py:181} INFO - Updated records: 0�[0m
[2025-01-24T22:15:38.214+0000] {logger.py:181} INFO - Warnings: 0�[0m
[2025-01-24T22:15:38.214+0000] {logger.py:181} INFO - Errors: 0�[0m
[2025-01-24T22:15:38.214+0000] {logger.py:181} INFO - �[1m�[36;1mSuccess %: 100.0�[0m
[2025-01-24T22:15:38.214+0000] {logger.py:181} INFO - �[1m�[36;1mWorkflow finished in time: 1.0h 4.0m 41.62s�[0m
[2025-01-24T22:15:38.214+0000] {base.py:133} WARNING - Error trying to close the step <metadata.ingestion.source.dashboard.powerbi.metadata.PowerbiSource object at 0x7f557c796d10> due to [[Errno 2] No such file or directory: '/tmp/pbitFiles']
[2025-01-24T22:15:38.215+0000] {python.py:237} INFO - Done. Returned value was: None
[2025-01-24T22:15:38.279+0000] {local_task_job_runner.py:240} INFO - Task exited with return code 0
[2025-01-24T22:15:38.301+0000] {taskinstance.py:3498} INFO - 0 downstream tasks scheduled from follow-on schedule check
[2025-01-24T22:15:38.304+0000] {local_task_job_runner.py:222} INFO - ::endgroup::

[Prajwal214]

@rdaudt this is has been resolved in v1.5.15 or higher version, you can test the same

[rdaudt]

We are already running v1.5.3. Thanks, anyways, for checking this out.