search

CCI-MOC / xdmod-cntr

A project to prototype the use of XDMOD with OpenStack and OpenShift on the MOC
1 stars 5 forks source link

xdmod ticket #31301 having some difficulty with shredding/ingesting data #219

Open rob-baron opened 1 year ago

rob-baron commented 1 year ago

Robert Bartlett Baron, reported 11 months ago I've attached the sadder and ingestor logs. Am not getting any errors from them, but am not seeing the data in xdmod. LOG shredder.log (562 KB) LOG ingestor.log (1.42 MB) Gregary Dean , said 10 months ago Cc: joachimw@bu.edu, msd@bu.edu Ticket: https://help.xdmod.org/support/tickets/31301

Hi Robert,

I looked through the logs you sent and it seems the data is being ingested and aggregated without error. It looks like you were ingesting and aggregating data for the time period 2018-04-18 - 2018-04-30. Is this correct? Just to confirm, was some part of this time range selected when you were looking for data in XDMoD?

Just so we are on the same page, when you say you are not seeing the data in XDMoD you mean that you are not seeing any data at all for this time range. Are you seeing the "No data available for the criteria specified" message?

Thanks, Greg Dean

Robert Bartlett Baron , said 10 months ago Greg,

I am looking for the data from the time period of 2019-01-11 to 2022-09-02.

I had previous run the dataset that you pointed me at for testing if the system was actually working to specification. Your test dataset is the 2018-04-19 - 2018-04-30.

Now, consider shredding.log. Here are the entries for the first file at line 1539:

2022-09-27 16:42:10 [debug] Initializing first file iterator: /root/xdmod_data/kaizen/2022-08-24T00:00:00_2022-08-25T00:00:00.json

2022-09-27 16:42:10 [info] Scanning file: /root/xdmod_data/kaizen/2022-08-24T00:00:00_2022-08-25T00:00:00.json

2022-09-27 16:42:10 [debug] Parsing /root/xdmod_data/kaizen/2022-08-24T00:00:00_2022-08-25T00:00:00.json

2022-09-27 16:42:10 [debug] Registering filter: xdmod.external_process

2022-09-27 16:42:10 [debug] Creating filter xdmod.external_process: jq -c '.[] | .["record_type"] += if .["event_type"] == "compute.instance.exists" then "ADMINISTRATIVE" else "ACCOUNTING" end | .["service_provider"] += "${SERVICE_PROVIDER}"'

2022-09-27 16:42:10 [debug] Adding filter xdmod.external_process to stream: jq

2022-09-27 16:42:11 [debug] Parsed 16 records

2022-09-27 16:42:11 [debug] Validating data against schema /etc/xdmod/etl/etl_schemas.d/cloud_openstack/event.schema.json

2022-09-27 16:42:11 [info] Found 16 records

2022-09-27 16:42:11 [debug] Requested 22 record fields: domain, event_type, generated, host, instance_id, instance_type, project_name, user_name, user_id, resource_id, project_id, request_id, vcpus, memory_mb, disk_gb, state, service, record_type, size, created_at, volume_id, service_provider

2022-09-27 16:42:11 [debug] Processing destination field map

2022-09-27 16:42:11 [debug] Insert SQL for table key 'openstack_raw_event':

INSERT INTO modw_cloud.openstack_raw_event (domain, event_type, record_type, event_time_utc, create_time_utc, provider_instance_identifier, hostname, user_name, user_id, resource_id, instance_type, provider_account, project_name, request_id, project_id, openstack_resource_id, disk_gb, num_cores, memory_mb, size, volume_id, state, service_provider) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) ON DUPLICATE KEY UPDATE domain = COALESCE(VALUES(domain), domain), event_type = COALESCE(VALUES(event_type), event_type), record_type = COALESCE(VALUES(record_type), record_type), event_time_utc = COALESCE(VALUES(event_time_utc), event_time_utc), create_time_utc = COALESCE(VALUES(create_time_utc), create_time_utc), provider_instance_identifier = COALESCE(VALUES(provider_instance_identifier), provider_instance_identifier), hostname = COALESCE(VALUES(hostname), hostname), user_name = COALESCE(VALUES(user_name), user_name), user_id = COALESCE(VALUES(user_id), user_id), resource_id = COALESCE(VALUES(resource_id), resource_id), instance_type = COALESCE(VALUES(instance_type), instance_type), provider_account = COALESCE(VALUES(provider_account), provider_account), project_name = COALESCE(VALUES(project_name), project_name), request_id = COALESCE(VALUES(request_id), request_id), project_id = COALESCE(VALUES(project_id), project_id), openstack_resource_id = COALESCE(VALUES(openstack_resource_id), openstack_resource_id), disk_gb = COALESCE(VALUES(disk_gb), disk_gb), num_cores = COALESCE(VALUES(num_cores), num_cores), memory_mb = COALESCE(VALUES(memory_mb), memory_mb), size = COALESCE(VALUES(size), size), volume_id = COALESCE(VALUES(volume_id), volume_id), state = COALESCE(VALUES(state), state), service_provider = COALESCE(VALUES(service_provider), service_provider)

2022-09-27 16:42:11 [debug] Insert SQL for table key 'openstack_raw_instance_type':

INSERT INTO modw_cloud.openstack_raw_instance_type (instance_type, resource_id, display, num_cores, memory_mb, disk_gb, start_time) VALUES (?, ?, ?, ?, ?, ?, ?) ON DUPLICATE KEY UPDATE instance_type = COALESCE(VALUES(instance_type), instance_type), resource_id = COALESCE(VALUES(resource_id), resource_id), display = COALESCE(VALUES(display), display), num_cores = COALESCE(VALUES(num_cores), num_cores), memory_mb = COALESCE(VALUES(memory_mb), memory_mb), disk_gb = COALESCE(VALUES(disk_gb), disk_gb), start_time = COALESCE(VALUES(start_time), start_time)

2022-09-27 16:42:11 [debug] Current file iterator no longer valid, checking next iterator.

As I don't see any errors, it would appear that this shredded fine, but was not picked up for ingestion. The date on the data is 2022-08-25 which is well outside the range that you provided of 2018-04-18 to 2018-04-30.

The data in this file is as follows:

/root/xdmod_data/kaizen/2022-08-24T00:00:00_2022-08-25T00:00:00.json [ { "availability_zone": "nova", "created_at": "2022-08-24T15:47:02.000000", "display_name": "ssbddata4", "domain": "default", "event_type": "volume.create.start", "generated": "2022-08-24T15:47:02", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "39ea1a2d-5db5-46df-80db-a7f5a87b4830", "service": "Cinder", "size": 45, "status": "creating", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:47:02.000000", "display_name": "ssbddata4", "domain": "default", "event_type": "volume.create.end", "generated": "2022-08-24T15:47:12", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "39ea1a2d-5db5-46df-80db-a7f5a87b4830", "service": "Cinder", "size": 45, "status": "available", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:43:30.000000", "display_name": "ssbddata3", "domain": "default", "event_type": "volume.create.start", "generated": "2022-08-24T15:43:30", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "fc5ef5ab-faf1-4f4a-9b2e-146e35d93e53", "service": "Cinder", "size": 50, "status": "creating", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:43:30.000000", "display_name": "ssbddata3", "domain": "default", "event_type": "volume.create.end", "generated": "2022-08-24T15:43:40", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "fc5ef5ab-faf1-4f4a-9b2e-146e35d93e53", "service": "Cinder", "size": 50, "status": "available", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:42:18.000000", "display_name": "ssbddata2", "domain": "default", "event_type": "volume.create.start", "generated": "2022-08-24T15:42:18", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "74717bca-b7cd-4082-8415-e48975ff6db5", "service": "Cinder", "size": 50, "status": "creating", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:42:18.000000", "display_name": "ssbddata2", "domain": "default", "event_type": "volume.create.end", "generated": "2022-08-24T15:42:28", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "74717bca-b7cd-4082-8415-e48975ff6db5", "service": "Cinder", "size": 50, "status": "available", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:39:06.000000", "display_name": "", "domain": "default", "event_type": "volume.create.start", "generated": "2022-08-24T15:39:06", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "b5621370-dbc2-4358-8ac3-ad52c49e71ce", "service": "Cinder", "size": 50, "status": "creating", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:39:06.000000", "display_name": "", "domain": "default", "event_type": "volume.create.end", "generated": "2022-08-24T15:39:16", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "b5621370-dbc2-4358-8ac3-ad52c49e71ce", "service": "Cinder", "size": 50, "status": "available", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:39:06.000000", "display_name": "", "domain": "default", "event_type": "volume.create.start", "generated": "2022-08-24T15:39:06", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "054caf0b-4361-4f62-902f-f602c5d3bbc1", "service": "Cinder", "size": 50, "status": "creating", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:39:06.000000", "display_name": "", "domain": "default", "event_type": "volume.create.end", "generated": "2022-08-24T15:39:16", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "054caf0b-4361-4f62-902f-f602c5d3bbc1", "service": "Cinder", "size": 50, "status": "available", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:39:05.000000", "display_name": "", "domain": "default", "event_type": "volume.create.start", "generated": "2022-08-24T15:39:05", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "968e12f0-6b61-4c32-bb56-3414e90eecb0", "service": "Cinder", "size": 50, "status": "creating", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:39:05.000000", "display_name": "", "domain": "default", "event_type": "volume.create.end", "generated": "2022-08-24T15:39:15", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "968e12f0-6b61-4c32-bb56-3414e90eecb0", "service": "Cinder", "size": 50, "status": "available", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:39:05.000000", "display_name": "", "domain": "default", "event_type": "volume.create.start", "generated": "2022-08-24T15:39:05", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "521ee733-9580-4d1b-8eaa-09d03e83a3e5", "service": "Cinder", "size": 50, "status": "creating", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T15:39:05.000000", "display_name": "", "domain": "default", "event_type": "volume.create.end", "generated": "2022-08-24T15:39:15", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "521ee733-9580-4d1b-8eaa-09d03e83a3e5", "service": "Cinder", "size": 50, "status": "available", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T14:58:03.000000", "display_name": "ctrl", "domain": "default", "event_type": "volume.create.start", "generated": "2022-08-24T14:58:03", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "ff759547-f77a-48d0-989a-321d4a2588dc", "service": "Cinder", "size": 60, "status": "creating", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" }, { "availability_zone": "nova", "created_at": "2022-08-24T14:58:03.000000", "display_name": "ctrl", "domain": "default", "event_type": "volume.create.end", "generated": "2022-08-24T14:58:13", "host": "", "message_id": "", "project_id": "1946da68d11f4db0a05eb8db16b35267", "project_name": "Serverless computing class (CS7680 - Northeastern)", "raw": {}, "request_id": "", "resource_id": "ff759547-f77a-48d0-989a-321d4a2588dc", "service": "Cinder", "size": 60, "status": "available", "tenant_id": "1946da68d11f4db0a05eb8db16b35267", "type": "", "user_id": "f32615e2eb3d419abc90ef846d07ab6c", "user_name": "yang.chengha@northeastern.edu" } ]

So any suggestions?

Robert Bartlett Baron , said 10 months ago Greg,

Should we set up a conference call to discuss/debug what is occurring on my system?

Rob Robert Bartlett Baron , said 10 months ago Greg,

Should we set up a conference call to discuss/debug what is occurring on my system?

Rob Gregary Dean , said 10 months ago Cc: joachimw@bu.edu, msd@bu.edu Ticket: https://help.xdmod.org/support/tickets/31301

Hi Rob,

Thanks for the information. Let's look at a couple of other things before we decide to have a call.

I do have a question about the events you listed in your last message. All of those events are volume.create.start/end events and deal with volumes, not OpenStack compute instances. The cloud realm aggregates and displays data about instances, not volumes. Is the sample you posted representative of what is in your other files or is that one an outlier? If your files don't contain compute events(compute.instance.create.start, compute.instance.pause.start, etc) then you are not going to see any information in the user interface.

I have a couple of sql queries I'd like you to run that would give me some more information about why you are not seeing data. After you run xdmod-shredder can you run the following query? This is just to make sure that data is being shredded correctly. I haven't seen anything in the logs to say it hasn't but I want to make sure we don't take anything for granted.

SELECT from_unixtime(event_time_utc), from_unixtime(event_time_utc) FROM modw_cloud.openstack_raw_event;

After that, run the xdmod-ingestor command again and run the following queries.

SELECT from_unixtime(min(event_time_ts)), from_unixtime(max(event_time_ts)) FROM modw_cloud.openstack_staging_event; SELECT from_unixtime(min(event_time_ts)), from_unixtime(max(event_time_ts)) FROM modw_cloud.event; SELECT min(start_time), max(end_time) FROM modw_cloud.session_records;

If there is a place in the ingestion process that is breaking down and not ingesting this data properly these queries should help us see that.

Also, would you be ok with sending me some of the log files you are shredding? I can try ingesting as well and see if I can replicate the issue you are experiencing.

Thanks, Greg Dean Robert Bartlett Baron , said 10 months ago Attached is a tgz file (tar -zxvf ...) for the data that I am trying to shred and ingest TGZ kaizen_data.tgz (185 KB) Robert Bartlett Baron , said 10 months ago Greg,

I am going to reply to your response piecemeal.

I do have a question about the events you listed in your last message. All of those events are volume.create.start/end events and deal with volumes, not OpenStack compute instances. The cloud realm aggregates and displays data about instances, not volumes. Is the sample you posted representative of what is in your other files or is that one an outlier? If your files don't contain compute events(compute.instance.create.start, compute.instance.pause.start, etc) then you are not going to see any information in the user interface.

This was from a student project, so they were probably trying to figure out how to create and delete volumes (and figure out what to do with them).

So yes, we need to report on the volumes that people create and may or may not necessarily be in use at the time of reporting.

We have the preference that people create instances from volumes, so they will create the volumes first, and eventually create the instances associated with the volumes. Often they will delete the instances without deleting the volumes (I have personally done this, though not as a general practice).

Does this mean that your uses can create a volume and xdmod will not report on that volume unless it is associated with an instance?

How do you report on a volume that was associated with an instance, however the instance has been deleted but the volume still exists?

Part of why we need to report on disk usage is that disks can only be allocated to one user and not oversubscribed like CPUs. Robert Bartlett Baron , said 10 months ago the results from the first query:

| 1970-01-01 00:33:39 | 1970-01-01 00:33:39 | +-------------------------------+-------------------------------+ 1045374 rows in set, 65535 warnings (35.58 sec)

All of the rows have the same data.

The ingestor query returned:

MariaDB [(none)]> SELECT from_unixtime(min(event_time_ts)), from_unixtime(max(event_time_ts)) FROM modw_cloud.openstack_staging_event; +-----------------------------------+-----------------------------------+ | from_unixtime(min(event_time_ts)) | from_unixtime(max(event_time_ts)) | +-----------------------------------+-----------------------------------+ | 2019-01-11 19:09:45.000000 | 2022-09-01 14:50:09.000000 | +-----------------------------------+-----------------------------------+ 1 row in set (0.00 sec)

MariaDB [(none)]> SELECT from_unixtime(min(event_time_ts)), from_unixtime(max(event_time_ts)) FROM modw_cloud.event; +-----------------------------------+-----------------------------------+ | from_unixtime(min(event_time_ts)) | from_unixtime(max(event_time_ts)) | +-----------------------------------+-----------------------------------+ | 2018-04-17 19:23:00.418847 | 2022-09-01 14:50:09.000000 | +-----------------------------------+-----------------------------------+ 1 row in set (0.01 sec)

MariaDB [(none)]> SELECT min(start_time), max(end_time) FROM modw_cloud.session_records; +---------------------+---------------------+ | min(start_time) | max(end_time) | +---------------------+---------------------+ | 2018-04-18 14:58:38 | 2018-04-30 23:00:54 | +---------------------+---------------------+ 1 row in set (0.04 sec)

The ingestor log follows:

2022-10-27 13:25:51 [notice] xdmod-ingestor start (process_start_time: 2022-10-27 13:25:51) 2022-10-27 13:25:52 [notice] Start processing section 'xdmod.staging-ingest-common' 2022-10-27 13:25:52 [notice] (action: xdmod.staging-ingest-common.organization (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877152.0261, end_time: 1666877152.1935, elapsed_time: 0.16739, records_examined: 1, records_loaded: 1) 2022-10-27 13:25:52 [notice] (action: xdmod.staging-ingest-common.resource-types (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877152.2286, end_time: 1666877152.4158, elapsed_time: 0.18717, records_examined: 12, records_loaded: 12) 2022-10-27 13:25:52 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/cloud_openstack/unknown_resource_type.sql' using delimiter '//' containing 2 statements 2022-10-27 13:25:52 [notice] Finished Processing 2 SQL statements 2022-10-27 13:25:52 [notice] (action: xdmod.staging-ingest-common.ResourceTypesStagingUnknown (ETL\Maintenance\ExecuteSql), start_time: 1666877152.4494, end_time: 1666877152.5009, elapsed_time: 0.05149) 2022-10-27 13:25:52 [notice] (action: xdmod.staging-ingest-common.resource-config (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877152.5274, end_time: 1666877152.625, elapsed_time: 0.09762, records_examined: 4, records_loaded: 4) 2022-10-27 13:25:52 [notice] (action: xdmod.staging-ingest-common.resources (ETL\Ingestor\DatabaseIngestor), start_time: 1666877152.6599, end_time: 1666877152.6997, elapsed_time: 0.03986, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:52 [notice] (action: xdmod.staging-ingest-common.resource-specs (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877152.7281, end_time: 1666877152.823, elapsed_time: 0.09491, records_examined: 4, records_loaded: 4) 2022-10-27 13:25:52 [notice] Finished processing section 'xdmod.staging-ingest-common' 2022-10-27 13:25:52 [notice] Start processing section 'xdmod.staging-ingest-jobs' 2022-10-27 13:25:52 [notice] (action: xdmod.staging-ingest-jobs.pi-resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877152.8695, end_time: 1666877152.9586, elapsed_time: 0.08909, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:53 [notice] (action: xdmod.staging-ingest-jobs.pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877152.991, end_time: 1666877153.0424, elapsed_time: 0.05138, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:53 [notice] (action: xdmod.staging-ingest-jobs.resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877153.0758, end_time: 1666877153.1274, elapsed_time: 0.05163, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:53 [notice] (action: xdmod.staging-ingest-jobs.union-user-pi--pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877153.176, end_time: 1666877153.2158, elapsed_time: 0.03987, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:53 [notice] (action: xdmod.staging-ingest-jobs.union-user-pi--user (ETL\Ingestor\DatabaseIngestor), start_time: 1666877153.2465, end_time: 1666877153.2876, elapsed_time: 0.04109, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:53 [notice] (action: xdmod.staging-ingest-jobs.union-user-pi-resource--pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877153.3186, end_time: 1666877153.3584, elapsed_time: 0.03982, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:53 [notice] (action: xdmod.staging-ingest-jobs.union-user-pi-resource--user (ETL\Ingestor\DatabaseIngestor), start_time: 1666877153.3889, end_time: 1666877153.4303, elapsed_time: 0.04141, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:53 [notice] (action: xdmod.staging-ingest-jobs.user-pi-resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877153.4615, end_time: 1666877153.5005, elapsed_time: 0.039, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:53 [notice] (action: xdmod.staging-ingest-jobs.qos (ETL\Ingestor\DatabaseIngestor), start_time: 1666877153.5299, end_time: 1666877153.5872, elapsed_time: 0.05728, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:53 [notice] (action: xdmod.staging-ingest-jobs.job (ETL\Ingestor\DatabaseIngestor), start_time: 1666877153.6183, end_time: 1666877153.694, elapsed_time: 0.07573, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:53 [notice] Finished processing section 'xdmod.staging-ingest-jobs' 2022-10-27 13:25:54 [notice] Start processing section 'xdmod.hpcdb-ingest-common' 2022-10-27 13:25:54 [notice] (action: xdmod.hpcdb-ingest-common.resource-types (ETL\Ingestor\DatabaseIngestor), start_time: 1666877154.4991, end_time: 1666877154.5385, elapsed_time: 0.0394, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:54 [notice] (action: xdmod.hpcdb-ingest-common.organizations (ETL\Ingestor\DatabaseIngestor), start_time: 1666877154.5657, end_time: 1666877154.6019, elapsed_time: 0.03621, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:54 [notice] (action: xdmod.hpcdb-ingest-common.resources (ETL\Ingestor\DatabaseIngestor), start_time: 1666877154.6271, end_time: 1666877154.6659, elapsed_time: 0.03879, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:54 [notice] (action: xdmod.hpcdb-ingest-common.resource-specs (ETL\Ingestor\DatabaseIngestor), start_time: 1666877154.6899, end_time: 1666877154.8476, elapsed_time: 0.15776, records_examined: 4, records_loaded: 4) 2022-10-27 13:25:54 [notice] (action: xdmod.hpcdb-ingest-common.resource-allocated (ETL\Ingestor\DatabaseIngestor), start_time: 1666877154.8726, end_time: 1666877154.9553, elapsed_time: 0.08269, records_examined: 4, records_loaded: 4) 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-common.qos (ETL\Ingestor\DatabaseIngestor), start_time: 1666877154.9807, end_time: 1666877155.0615, elapsed_time: 0.08076, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-common.accounts (ETL\Ingestor\DatabaseIngestor), start_time: 1666877155.0867, end_time: 1666877155.1414, elapsed_time: 0.05469, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-common.allocations (ETL\Ingestor\DatabaseIngestor), start_time: 1666877155.1749, end_time: 1666877155.2352, elapsed_time: 0.06021, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-common.people (ETL\Ingestor\DatabaseIngestor), start_time: 1666877155.2601, end_time: 1666877155.3131, elapsed_time: 0.05299, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-common.requests (ETL\Ingestor\DatabaseIngestor), start_time: 1666877155.3346, end_time: 1666877155.3708, elapsed_time: 0.03626, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-common.allocation-breakdown (ETL\Ingestor\DatabaseIngestor), start_time: 1666877155.3957, end_time: 1666877155.4401, elapsed_time: 0.04435, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-common.allocations-on-resources (ETL\Ingestor\DatabaseIngestor), start_time: 1666877155.4659, end_time: 1666877155.4999, elapsed_time: 0.03398, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-common.email-addresses (ETL\Ingestor\DatabaseIngestor), start_time: 1666877155.5258, end_time: 1666877155.5616, elapsed_time: 0.03583, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-common.principal-investigators (ETL\Ingestor\DatabaseIngestor), start_time: 1666877155.586, end_time: 1666877155.6231, elapsed_time: 0.03704, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-common.system-accounts (ETL\Ingestor\DatabaseIngestor), start_time: 1666877155.6489, end_time: 1666877155.704, elapsed_time: 0.05502, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] Finished processing section 'xdmod.hpcdb-ingest-common' 2022-10-27 13:25:55 [notice] Start processing section 'xdmod.hpcdb-ingest-jobs' 2022-10-27 13:25:55 [notice] (action: xdmod.hpcdb-ingest-jobs.jobs (ETL\Ingestor\DatabaseIngestor), start_time: 1666877155.745, end_time: 1666877155.8036, elapsed_time: 0.05859, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:55 [notice] Finished processing section 'xdmod.hpcdb-ingest-jobs' 2022-10-27 13:25:56 [notice] Start processing section 'xdmod.hpcdb-prep-xdw-job-ingest-by-new-jobs' 2022-10-27 13:25:56 [notice] Table mod_hpcdb.hpcdb_jobs_to_ingest does not exist, creating. 2022-10-27 13:25:56 [notice] (action: xdmod.hpcdb-prep-xdw-job-ingest-by-new-jobs.jobs (ETL\Ingestor\DatabaseIngestor), start_time: 1666877156.0449, end_time: 1666877156.1671, elapsed_time: 0.12216, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:56 [notice] Finished processing section 'xdmod.hpcdb-prep-xdw-job-ingest-by-new-jobs' 2022-10-27 13:25:57 [notice] Start processing section 'xdmod.hpcdb-xdw-ingest-common' 2022-10-27 13:25:57 [notice] (action: xdmod.hpcdb-xdw-ingest-common.account (ETL\Ingestor\DatabaseIngestor), start_time: 1666877157.3473, end_time: 1666877157.4298, elapsed_time: 0.08253, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:57 [notice] (action: xdmod.hpcdb-xdw-ingest-common.allocation-breakdown (ETL\Ingestor\DatabaseIngestor), start_time: 1666877157.4663, end_time: 1666877157.6513, elapsed_time: 0.18505, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:57 [notice] (action: xdmod.hpcdb-xdw-ingest-common.allocation (ETL\Ingestor\DatabaseIngestor), start_time: 1666877157.6881, end_time: 1666877157.7432, elapsed_time: 0.05507, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:57 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877157.7793, end_time: 1666877157.8228, elapsed_time: 0.04349, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:57 [notice] (action: xdmod.hpcdb-xdw-ingest-common.allocation-on-resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877157.8535, end_time: 1666877157.9194, elapsed_time: 0.06593, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:58 [notice] (action: xdmod.hpcdb-xdw-ingest-common.field-of-science (ETL\Ingestor\DatabaseIngestor), start_time: 1666877157.9547, end_time: 1666877158.0666, elapsed_time: 0.11191, records_examined: 1, records_loaded: 1) 2022-10-27 13:25:58 [notice] (action: xdmod.hpcdb-xdw-ingest-common.field-of-science-hierarchy (ETL\Ingestor\DatabaseIngestor), start_time: 1666877158.1025, end_time: 1666877158.2969, elapsed_time: 0.19442, records_examined: 1, records_loaded: 1) 2022-10-27 13:25:58 [notice] (action: xdmod.hpcdb-xdw-ingest-common.organization (ETL\Ingestor\DatabaseIngestor), start_time: 1666877158.3296, end_time: 1666877158.4929, elapsed_time: 0.16333, records_examined: 1, records_loaded: 1) 2022-10-27 13:25:58 [notice] (action: xdmod.hpcdb-xdw-ingest-common.pi-person (ETL\Ingestor\DatabaseIngestor), start_time: 1666877158.5271, end_time: 1666877158.6798, elapsed_time: 0.15265, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:58 [notice] (action: xdmod.hpcdb-xdw-ingest-common.person (ETL\Ingestor\DatabaseIngestor), start_time: 1666877158.7125, end_time: 1666877158.7835, elapsed_time: 0.07108, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:58 [notice] (action: xdmod.hpcdb-xdw-ingest-common.people-under-pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877158.8165, end_time: 1666877158.8651, elapsed_time: 0.04859, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:58 [notice] (action: xdmod.hpcdb-xdw-ingest-common.principal-investigator (ETL\Ingestor\DatabaseIngestor), start_time: 1666877158.9001, end_time: 1666877158.9694, elapsed_time: 0.06934, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:59 [notice] (action: xdmod.hpcdb-xdw-ingest-common.qos (ETL\Ingestor\DatabaseIngestor), start_time: 1666877159.0039, end_time: 1666877159.0577, elapsed_time: 0.05375, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:59 [notice] (action: xdmod.hpcdb-xdw-ingest-common.request (ETL\Ingestor\DatabaseIngestor), start_time: 1666877159.0947, end_time: 1666877159.1552, elapsed_time: 0.06044, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:59 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource-type (ETL\Ingestor\DatabaseIngestor), start_time: 1666877159.1939, end_time: 1666877159.2413, elapsed_time: 0.04746, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:59 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource-spec (ETL\Ingestor\DatabaseIngestor), start_time: 1666877159.2765, end_time: 1666877159.4214, elapsed_time: 0.14493, records_examined: 4, records_loaded: 4) 2022-10-27 13:25:59 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource-allocated (ETL\Ingestor\DatabaseIngestor), start_time: 1666877159.4559, end_time: 1666877159.5413, elapsed_time: 0.0854, records_examined: 4, records_loaded: 4) 2022-10-27 13:25:59 [notice] (action: xdmod.hpcdb-xdw-ingest-common.service-provider (ETL\Ingestor\DatabaseIngestor), start_time: 1666877159.5771, end_time: 1666877159.6192, elapsed_time: 0.04203, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:59 [notice] (action: xdmod.hpcdb-xdw-ingest-common.system-account (ETL\Ingestor\DatabaseIngestor), start_time: 1666877159.6517, end_time: 1666877159.722, elapsed_time: 0.07024, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:59 [notice] Finished processing section 'xdmod.hpcdb-xdw-ingest-common' 2022-10-27 13:25:59 [notice] Start processing section 'xdmod.hpcdb-xdw-ingest-jobs' 2022-10-27 13:25:59 [notice] (action: xdmod.hpcdb-xdw-ingest-jobs.node-count (ETL\Ingestor\DatabaseIngestor), start_time: 1666877159.7664, end_time: 1666877159.8111, elapsed_time: 0.04468, records_examined: 0, records_loaded: 0) 2022-10-27 13:25:59 [notice] (action: xdmod.hpcdb-xdw-ingest-jobs.queue (ETL\Ingestor\DatabaseIngestor), start_time: 1666877159.8429, end_time: 1666877159.8843, elapsed_time: 0.04141, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:00 [notice] (action: xdmod.hpcdb-xdw-ingest-jobs.hosts (ETL\Ingestor\HpcdbHostsIngestor), start_time: 1666877159.9148, end_time: 1666877160.0005, elapsed_time: 0.0857, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:00 [notice] (action: xdmod.hpcdb-xdw-ingest-jobs.job-hosts (ETL\Ingestor\DatabaseIngestor), start_time: 1666877160.035, end_time: 1666877160.1024, elapsed_time: 0.06748, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:00 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/jobs/jobhosts-post-ingest-truncate.sql' using delimiter '//' containing 1 statements 2022-10-27 13:26:00 [notice] Finished Processing 1 SQL statements 2022-10-27 13:26:00 [notice] (action: xdmod.hpcdb-xdw-ingest-jobs.jobhosts-post-truncate (ETL\Maintenance\ExecuteSql), start_time: 1666877160.1367, end_time: 1666877160.2594, elapsed_time: 0.12269) 2022-10-27 13:26:00 [notice] Altering table modw.job_records 2022-10-27 13:26:00 [notice] Altering table modw.job_tasks 2022-10-27 13:26:00 [notice] (action: xdmod.hpcdb-xdw-ingest-jobs.job-records-job-tasks (ETL\Ingestor\DatabaseIngestor), start_time: 1666877160.283, end_time: 1666877160.4201, elapsed_time: 0.13715, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:00 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/jobs/job-record-hpc-post-ingest.sql' using delimiter '//' containing 2 statements 2022-10-27 13:26:00 [notice] Finished Processing 2 SQL statements 2022-10-27 13:26:00 [notice] (action: xdmod.hpcdb-xdw-ingest-jobs.HpcdbPostIngestJobUpdates (ETL\Maintenance\ExecuteSql), start_time: 1666877160.4522, end_time: 1666877160.5159, elapsed_time: 0.0637) 2022-10-27 13:26:00 [notice] Finished processing section 'xdmod.hpcdb-xdw-ingest-jobs' 2022-10-27 13:26:00 [notice] Ingesting generic cloud log files 2022-10-27 13:26:04 [notice] Start processing section 'xdmod.staging-ingest-common' 2022-10-27 13:26:04 [notice] (action: xdmod.staging-ingest-common.organization (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877164.293, end_time: 1666877164.4366, elapsed_time: 0.14364, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:04 [notice] (action: xdmod.staging-ingest-common.resource-types (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877164.4664, end_time: 1666877164.6486, elapsed_time: 0.18221, records_examined: 12, records_loaded: 12) 2022-10-27 13:26:04 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/cloud_openstack/unknown_resource_type.sql' using delimiter '//' containing 2 statements 2022-10-27 13:26:04 [notice] Finished Processing 2 SQL statements 2022-10-27 13:26:04 [notice] (action: xdmod.staging-ingest-common.ResourceTypesStagingUnknown (ETL\Maintenance\ExecuteSql), start_time: 1666877164.6805, end_time: 1666877164.7345, elapsed_time: 0.05398) 2022-10-27 13:26:04 [notice] (action: xdmod.staging-ingest-common.resource-config (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877164.76, end_time: 1666877164.9062, elapsed_time: 0.14618, records_examined: 4, records_loaded: 4) 2022-10-27 13:26:04 [notice] (action: xdmod.staging-ingest-common.resources (ETL\Ingestor\DatabaseIngestor), start_time: 1666877164.9392, end_time: 1666877164.9848, elapsed_time: 0.04555, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:05 [notice] (action: xdmod.staging-ingest-common.resource-specs (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877165.0153, end_time: 1666877165.1149, elapsed_time: 0.09964, records_examined: 4, records_loaded: 4) 2022-10-27 13:26:05 [notice] Finished processing section 'xdmod.staging-ingest-common' 2022-10-27 13:26:05 [notice] Start processing section 'xdmod.jobs-cloud-common' 2022-10-27 13:26:05 [notice] Altering table modw_cloud.event 2022-10-27 13:26:05 [notice] Altering table modw_cloud.cloud_resource_specs 2022-10-27 13:26:05 [notice] Altering table modw_cloud.session_records 2022-10-27 13:26:05 [notice] (action: xdmod.jobs-cloud-common.CloudTableManagement (ETL\Maintenance\ManageTables), start_time: 1666877165.1632, end_time: 1666877165.5054, elapsed_time: 0.3422) 2022-10-27 13:26:05 [notice] (action: xdmod.jobs-cloud-common.CloudAssetTypeInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877165.5295, end_time: 1666877165.5673, elapsed_time: 0.03778, records_examined: 5, records_loaded: 5) 2022-10-27 13:26:05 [notice] (action: xdmod.jobs-cloud-common.CloudEventTypeInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877165.5991, end_time: 1666877165.6596, elapsed_time: 0.06048, records_examined: 65, records_loaded: 65) 2022-10-27 13:26:05 [notice] (action: xdmod.jobs-cloud-common.CloudRecordTypeInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877165.6894, end_time: 1666877165.7324, elapsed_time: 0.04303, records_examined: 4, records_loaded: 4) 2022-10-27 13:26:05 [notice] (action: xdmod.jobs-cloud-common.CloudHostUnknownInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877165.8017, end_time: 1666877165.8481, elapsed_time: 0.04632, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:05 [notice] (action: xdmod.jobs-cloud-common.CloudAccountUnknownInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877165.8891, end_time: 1666877165.9333, elapsed_time: 0.04422, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-common.CloudInstanceUnknownInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877165.9725, end_time: 1666877166.0151, elapsed_time: 0.04253, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-common.CloudInstanceTypeUnknownInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877166.0513, end_time: 1666877166.1034, elapsed_time: 0.05208, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-common.CloudImageUnknownInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877166.1421, end_time: 1666877166.1895, elapsed_time: 0.04735, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-common.MemoryBucketGenerator (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877166.2304, end_time: 1666877166.2739, elapsed_time: 0.04345, records_examined: 8, records_loaded: 8) 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-common.ProcessorBucketGenerator (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877166.3095, end_time: 1666877166.3536, elapsed_time: 0.04417, records_examined: 7, records_loaded: 7) 2022-10-27 13:26:06 [notice] Finished processing section 'xdmod.jobs-cloud-common' 2022-10-27 13:26:06 [notice] Start processing section 'xdmod.jobs-cloud-import-users-generic' 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-import-users-generic.GenericCloudStagingUserIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877166.4221, end_time: 1666877166.501, elapsed_time: 0.07884, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-import-users-generic.GenericCloudStagingUserResourceIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877166.5389, end_time: 1666877166.5834, elapsed_time: 0.0445, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-import-users-generic.GenericCloudCloudStagingHpcdbPeopleIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877166.6215, end_time: 1666877166.6675, elapsed_time: 0.046, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-import-users-generic.GenericCloudloudStagingHpcdbSystemAccountIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877166.7052, end_time: 1666877166.7486, elapsed_time: 0.04337, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-import-users-generic.GenericCloudCloudStagingSystemAccountIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877166.788, end_time: 1666877166.8323, elapsed_time: 0.04429, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:06 [notice] (action: xdmod.jobs-cloud-import-users-generic.GenericCloudCloudStagingPersonIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877166.8688, end_time: 1666877166.943, elapsed_time: 0.07427, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:06 [notice] Finished processing section 'xdmod.jobs-cloud-import-users-generic' 2022-10-27 13:26:06 [notice] Start processing section 'xdmod.hpcdb-ingest-common' 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.resource-types (ETL\Ingestor\DatabaseIngestor), start_time: 1666877166.9971, end_time: 1666877167.0414, elapsed_time: 0.04434, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.organizations (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.0807, end_time: 1666877167.1238, elapsed_time: 0.04316, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.resources (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.1589, end_time: 1666877167.2125, elapsed_time: 0.0535, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.resource-specs (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.2647, end_time: 1666877167.3143, elapsed_time: 0.04953, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.resource-allocated (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.3515, end_time: 1666877167.4379, elapsed_time: 0.08645, records_examined: 4, records_loaded: 4) 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.qos (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.4752, end_time: 1666877167.5195, elapsed_time: 0.04434, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.accounts (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.5594, end_time: 1666877167.6024, elapsed_time: 0.043, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.allocations (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.6475, end_time: 1666877167.6912, elapsed_time: 0.04377, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.people (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.7254, end_time: 1666877167.7688, elapsed_time: 0.04344, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.requests (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.8011, end_time: 1666877167.8444, elapsed_time: 0.04325, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:07 [notice] (action: xdmod.hpcdb-ingest-common.allocation-breakdown (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.8741, end_time: 1666877167.9129, elapsed_time: 0.03874, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-ingest-common.allocations-on-resources (ETL\Ingestor\DatabaseIngestor), start_time: 1666877167.9466, end_time: 1666877167.9917, elapsed_time: 0.04519, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-ingest-common.email-addresses (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.0253, end_time: 1666877168.0672, elapsed_time: 0.04186, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-ingest-common.principal-investigators (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.1002, end_time: 1666877168.1447, elapsed_time: 0.04447, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-ingest-common.system-accounts (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.1753, end_time: 1666877168.2204, elapsed_time: 0.04509, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] Finished processing section 'xdmod.hpcdb-ingest-common' 2022-10-27 13:26:08 [notice] Start processing section 'xdmod.hpcdb-xdw-ingest-common' 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-xdw-ingest-common.account (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.278, end_time: 1666877168.3209, elapsed_time: 0.0429, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-xdw-ingest-common.allocation-breakdown (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.3553, end_time: 1666877168.4192, elapsed_time: 0.06396, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-xdw-ingest-common.allocation (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.4528, end_time: 1666877168.4973, elapsed_time: 0.04458, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.5315, end_time: 1666877168.5762, elapsed_time: 0.04475, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-xdw-ingest-common.allocation-on-resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.6131, end_time: 1666877168.6538, elapsed_time: 0.04062, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-xdw-ingest-common.field-of-science (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.6887, end_time: 1666877168.7319, elapsed_time: 0.04323, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:08 [notice] (action: xdmod.hpcdb-xdw-ingest-common.field-of-science-hierarchy (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.7702, end_time: 1666877168.922, elapsed_time: 0.15182, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.organization (ETL\Ingestor\DatabaseIngestor), start_time: 1666877168.9578, end_time: 1666877169.1318, elapsed_time: 0.17402, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.pi-person (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.168, end_time: 1666877169.2444, elapsed_time: 0.07639, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.person (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.2805, end_time: 1666877169.351, elapsed_time: 0.07049, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.people-under-pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.3887, end_time: 1666877169.4299, elapsed_time: 0.04126, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.principal-investigator (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.4612, end_time: 1666877169.5018, elapsed_time: 0.04059, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.qos (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.5327, end_time: 1666877169.5678, elapsed_time: 0.03505, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.request (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.5961, end_time: 1666877169.6341, elapsed_time: 0.03799, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource-type (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.6662, end_time: 1666877169.7074, elapsed_time: 0.04125, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource-spec (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.7372, end_time: 1666877169.7737, elapsed_time: 0.03654, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource-allocated (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.8021, end_time: 1666877169.8404, elapsed_time: 0.03833, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.service-provider (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.8707, end_time: 1666877169.9098, elapsed_time: 0.03917, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] (action: xdmod.hpcdb-xdw-ingest-common.system-account (ETL\Ingestor\DatabaseIngestor), start_time: 1666877169.9406, end_time: 1666877169.9791, elapsed_time: 0.03843, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:09 [notice] Finished processing section 'xdmod.hpcdb-xdw-ingest-common' 2022-10-27 13:26:10 [notice] Start processing section 'xdmod.jobs-cloud-extract-generic' 2022-10-27 13:26:10 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudAccountIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877170.0204, end_time: 1666877170.0841, elapsed_time: 0.06373, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:10 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudHostIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877170.1146, end_time: 1666877170.1554, elapsed_time: 0.04081, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:10 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudImageIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877170.1856, end_time: 1666877170.2275, elapsed_time: 0.04183, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:10 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudInstanceTypeIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877170.2578, end_time: 1666877170.315, elapsed_time: 0.05716, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:10 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudInstanceIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877170.3439, end_time: 1666877170.3805, elapsed_time: 0.03657, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:10 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudVolumeAssetIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877170.4076, end_time: 1666877170.4444, elapsed_time: 0.03687, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:10 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/cloud_generic/post_ingest_updates.sql' using delimiter '//' containing 4 statements 2022-10-27 13:26:10 [notice] Finished Processing 4 SQL statements 2022-10-27 13:26:10 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudPostIngestUpdates (ETL\Maintenance\ExecuteSql), start_time: 1666877170.4741, end_time: 1666877170.587, elapsed_time: 0.11286) 2022-10-27 13:26:10 [notice] Altering table modw_cloud.generic_cloud_staging_event 2022-10-27 13:26:10 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudStagingEventIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877170.6079, end_time: 1666877170.7827, elapsed_time: 0.17481, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:10 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudRootVolumeAssetIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877170.8098, end_time: 1666877170.8512, elapsed_time: 0.04137, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:10 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudIpAddressAssetIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877170.8771, end_time: 1666877170.9151, elapsed_time: 0.03797, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:10 [notice] Altering table modw_cloud.event 2022-10-27 13:26:11 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudEventIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877170.941, end_time: 1666877170.9924, elapsed_time: 0.05143, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:11 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudInstanceDataIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877171.0315, end_time: 1666877171.0808, elapsed_time: 0.0493, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:11 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudEventAssetRootVolumeIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877171.1161, end_time: 1666877171.2029, elapsed_time: 0.08677, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:11 [notice] (action: xdmod.jobs-cloud-extract-generic.GenericCloudEventAssetIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877171.2467, end_time: 1666877171.2991, elapsed_time: 0.05238, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:11 [notice] Finished processing section 'xdmod.jobs-cloud-extract-generic' 2022-10-27 13:26:11 [notice] Start processing section 'xdmod.jobs-cloud-ingest-pi' 2022-10-27 13:26:11 [notice] (action: xdmod.jobs-cloud-ingest-pi.pi-resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877171.3555, end_time: 1666877171.412, elapsed_time: 0.05649, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:11 [notice] (action: xdmod.jobs-cloud-ingest-pi.pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877171.4486, end_time: 1666877171.4931, elapsed_time: 0.04445, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:11 [notice] (action: xdmod.jobs-cloud-ingest-pi.union-user-pi--pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877171.5279, end_time: 1666877171.5721, elapsed_time: 0.04413, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:11 [notice] (action: xdmod.jobs-cloud-ingest-pi.union-user-pi-resource--pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877171.6063, end_time: 1666877171.6496, elapsed_time: 0.04331, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:11 [notice] (action: xdmod.jobs-cloud-ingest-pi.user-pi-resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877171.686, end_time: 1666877171.7282, elapsed_time: 0.04216, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:11 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/cloud_common/pi_to_account.sql' using delimiter '//' containing 1 statements 2022-10-27 13:26:11 [notice] Finished Processing 1 SQL statements 2022-10-27 13:26:11 [notice] (action: xdmod.jobs-cloud-ingest-pi.UpdateCloudProjectToPI (ETL\Maintenance\ExecuteSql), start_time: 1666877171.7654, end_time: 1666877171.8213, elapsed_time: 0.05599) 2022-10-27 13:26:11 [notice] Finished processing section 'xdmod.jobs-cloud-ingest-pi' 2022-10-27 13:26:11 [notice] Ingesting cloud resource specs 2022-10-27 13:26:12 [notice] Start processing section 'xdmod.ingest-cloud-resource-specs' 2022-10-27 13:26:12 [notice] Altering table modw_cloud.cloud_resource_specs 2022-10-27 13:26:12 [notice] (action: xdmod.ingest-cloud-resource-specs.CloudResourceSpecsReconstructor (ETL\Ingestor\CloudResourceSpecsStateTransformIngestor), start_time: 1666877172.1361, end_time: 1666877172.2353, elapsed_time: 0.09926, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:12 [notice] Finished processing section 'xdmod.ingest-cloud-resource-specs' 2022-10-27 13:26:12 [notice] Ingesting OpenStack event log data 2022-10-27 13:26:16 [notice] Start processing section 'xdmod.staging-ingest-common' 2022-10-27 13:26:16 [notice] (action: xdmod.staging-ingest-common.organization (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877176.487, end_time: 1666877176.6221, elapsed_time: 0.13507, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:16 [notice] (action: xdmod.staging-ingest-common.resource-types (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877176.6513, end_time: 1666877176.8236, elapsed_time: 0.1723, records_examined: 12, records_loaded: 12) 2022-10-27 13:26:16 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/cloud_openstack/unknown_resource_type.sql' using delimiter '//' containing 2 statements 2022-10-27 13:26:16 [notice] Finished Processing 2 SQL statements 2022-10-27 13:26:16 [notice] (action: xdmod.staging-ingest-common.ResourceTypesStagingUnknown (ETL\Maintenance\ExecuteSql), start_time: 1666877176.8553, end_time: 1666877176.9062, elapsed_time: 0.0509) 2022-10-27 13:26:17 [notice] (action: xdmod.staging-ingest-common.resource-config (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877176.9296, end_time: 1666877177.0242, elapsed_time: 0.09458, records_examined: 4, records_loaded: 4) 2022-10-27 13:26:17 [notice] (action: xdmod.staging-ingest-common.resources (ETL\Ingestor\DatabaseIngestor), start_time: 1666877177.0567, end_time: 1666877177.0952, elapsed_time: 0.03851, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:17 [notice] (action: xdmod.staging-ingest-common.resource-specs (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877177.1257, end_time: 1666877177.2162, elapsed_time: 0.09054, records_examined: 4, records_loaded: 4) 2022-10-27 13:26:17 [notice] Finished processing section 'xdmod.staging-ingest-common' 2022-10-27 13:26:17 [notice] Start processing section 'xdmod.jobs-cloud-common' 2022-10-27 13:26:17 [notice] Altering table modw_cloud.event 2022-10-27 13:26:17 [notice] Altering table modw_cloud.cloud_resource_specs 2022-10-27 13:26:17 [notice] Altering table modw_cloud.session_records

rob-baron commented 1 year ago

2022-10-27 13:26:17 [notice] (action: xdmod.jobs-cloud-common.CloudTableManagement (ETL\Maintenance\ManageTables), start_time: 1666877177.2605, end_time: 1666877177.5862, elapsed_time: 0.32575) 2022-10-27 13:26:17 [notice] (action: xdmod.jobs-cloud-common.CloudAssetTypeInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877177.6063, end_time: 1666877177.6425, elapsed_time: 0.03622, records_examined: 5, records_loaded: 5) 2022-10-27 13:26:17 [notice] (action: xdmod.jobs-cloud-common.CloudEventTypeInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877177.6711, end_time: 1666877177.7249, elapsed_time: 0.05381, records_examined: 65, records_loaded: 65) 2022-10-27 13:26:17 [notice] (action: xdmod.jobs-cloud-common.CloudRecordTypeInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877177.7546, end_time: 1666877177.7938, elapsed_time: 0.0392, records_examined: 4, records_loaded: 4) 2022-10-27 13:26:17 [notice] (action: xdmod.jobs-cloud-common.CloudHostUnknownInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877177.8222, end_time: 1666877177.857, elapsed_time: 0.03485, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:17 [notice] (action: xdmod.jobs-cloud-common.CloudAccountUnknownInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877177.8846, end_time: 1666877177.9216, elapsed_time: 0.03705, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:17 [notice] (action: xdmod.jobs-cloud-common.CloudInstanceUnknownInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877177.9486, end_time: 1666877177.9854, elapsed_time: 0.03677, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:18 [notice] (action: xdmod.jobs-cloud-common.CloudInstanceTypeUnknownInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877178.0471, end_time: 1666877178.0894, elapsed_time: 0.04233, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:18 [notice] (action: xdmod.jobs-cloud-common.CloudImageUnknownInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877178.1155, end_time: 1666877178.1541, elapsed_time: 0.03858, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:18 [notice] (action: xdmod.jobs-cloud-common.MemoryBucketGenerator (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877178.1819, end_time: 1666877178.2222, elapsed_time: 0.04029, records_examined: 8, records_loaded: 8) 2022-10-27 13:26:18 [notice] (action: xdmod.jobs-cloud-common.ProcessorBucketGenerator (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877178.2505, end_time: 1666877178.2902, elapsed_time: 0.03968, records_examined: 7, records_loaded: 7) 2022-10-27 13:26:18 [notice] Finished processing section 'xdmod.jobs-cloud-common' 2022-10-27 13:26:18 [notice] Start processing section 'xdmod.jobs-cloud-import-users-openstack' 2022-10-27 13:26:20 [notice] (action: xdmod.jobs-cloud-import-users-openstack.OpenStackStagingUserIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877178.3403, end_time: 1666877180.7976, elapsed_time: 2.45726, records_examined: 207, records_loaded: 207) 2022-10-27 13:26:27 [notice] (action: xdmod.jobs-cloud-import-users-openstack.OpenStackCloudStagingUserResourceIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877180.8285, end_time: 1666877187.5631, elapsed_time: 6.73461, records_examined: 207, records_loaded: 207) 2022-10-27 13:26:27 [notice] (action: xdmod.jobs-cloud-import-users-openstack.OpenStackCloudStagingHpcdbPeopleIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877187.5933, end_time: 1666877187.6779, elapsed_time: 0.0846, records_examined: 207, records_loaded: 207) 2022-10-27 13:26:27 [notice] (action: xdmod.jobs-cloud-import-users-openstack.OpenStackCloudStagingHpcdbSystemAccountIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877187.7051, end_time: 1666877187.7778, elapsed_time: 0.07272, records_examined: 207, records_loaded: 207) 2022-10-27 13:26:27 [notice] (action: xdmod.jobs-cloud-import-users-openstack.OpenStackCloudStagingSystemAccountIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877187.8056, end_time: 1666877187.8924, elapsed_time: 0.0868, records_examined: 207, records_loaded: 207) 2022-10-27 13:26:28 [notice] (action: xdmod.jobs-cloud-import-users-openstack.OpenStackCloudStagingPersonIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877187.9208, end_time: 1666877188.1245, elapsed_time: 0.2037, records_examined: 207, records_loaded: 207) 2022-10-27 13:26:28 [notice] Finished processing section 'xdmod.jobs-cloud-import-users-openstack' 2022-10-27 13:26:28 [notice] Start processing section 'xdmod.hpcdb-ingest-common' 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.resource-types (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.1722, end_time: 1666877188.2138, elapsed_time: 0.04158, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.organizations (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.244, end_time: 1666877188.2838, elapsed_time: 0.03981, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.resources (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.3122, end_time: 1666877188.3524, elapsed_time: 0.04026, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.resource-specs (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.3828, end_time: 1666877188.4264, elapsed_time: 0.04355, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.resource-allocated (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.454, end_time: 1666877188.5152, elapsed_time: 0.06117, records_examined: 4, records_loaded: 4) 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.qos (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.5448, end_time: 1666877188.5845, elapsed_time: 0.03962, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.accounts (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.6153, end_time: 1666877188.6558, elapsed_time: 0.04057, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.allocations (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.6846, end_time: 1666877188.7263, elapsed_time: 0.04163, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.people (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.7552, end_time: 1666877188.797, elapsed_time: 0.0418, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.requests (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.8281, end_time: 1666877188.8691, elapsed_time: 0.04105, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:28 [notice] (action: xdmod.hpcdb-ingest-common.allocation-breakdown (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.8988, end_time: 1666877188.9373, elapsed_time: 0.03854, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-ingest-common.allocations-on-resources (ETL\Ingestor\DatabaseIngestor), start_time: 1666877188.9688, end_time: 1666877189.0064, elapsed_time: 0.03754, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-ingest-common.email-addresses (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.0341, end_time: 1666877189.1011, elapsed_time: 0.06704, records_examined: 207, records_loaded: 207) 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-ingest-common.principal-investigators (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.129, end_time: 1666877189.1686, elapsed_time: 0.03964, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-ingest-common.system-accounts (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.1978, end_time: 1666877189.2615, elapsed_time: 0.06376, records_examined: 414, records_loaded: 414) 2022-10-27 13:26:29 [notice] Finished processing section 'xdmod.hpcdb-ingest-common' 2022-10-27 13:26:29 [notice] Start processing section 'xdmod.hpcdb-xdw-ingest-common' 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-xdw-ingest-common.account (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.3062, end_time: 1666877189.3757, elapsed_time: 0.06949, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-xdw-ingest-common.allocation-breakdown (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.4061, end_time: 1666877189.444, elapsed_time: 0.03787, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-xdw-ingest-common.allocation (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.4748, end_time: 1666877189.5149, elapsed_time: 0.04013, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.5422, end_time: 1666877189.5804, elapsed_time: 0.03821, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-xdw-ingest-common.allocation-on-resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.6099, end_time: 1666877189.65, elapsed_time: 0.04002, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-xdw-ingest-common.field-of-science (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.6792, end_time: 1666877189.7174, elapsed_time: 0.0382, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:29 [notice] (action: xdmod.hpcdb-xdw-ingest-common.field-of-science-hierarchy (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.7545, end_time: 1666877189.8975, elapsed_time: 0.14295, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:30 [notice] (action: xdmod.hpcdb-xdw-ingest-common.organization (ETL\Ingestor\DatabaseIngestor), start_time: 1666877189.9702, end_time: 1666877190.1452, elapsed_time: 0.17493, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:30 [notice] (action: xdmod.hpcdb-xdw-ingest-common.pi-person (ETL\Ingestor\DatabaseIngestor), start_time: 1666877190.1771, end_time: 1666877190.2464, elapsed_time: 0.0693, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:30 [notice] (action: xdmod.hpcdb-xdw-ingest-common.person (ETL\Ingestor\DatabaseIngestor), start_time: 1666877190.2808, end_time: 1666877190.4596, elapsed_time: 0.1788, records_examined: 207, records_loaded: 207) 2022-10-27 13:26:30 [notice] (action: xdmod.hpcdb-xdw-ingest-common.people-under-pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877190.4945, end_time: 1666877190.5371, elapsed_time: 0.04267, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:30 [notice] (action: xdmod.hpcdb-xdw-ingest-common.principal-investigator (ETL\Ingestor\DatabaseIngestor), start_time: 1666877190.5742, end_time: 1666877190.6149, elapsed_time: 0.04069, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:30 [notice] (action: xdmod.hpcdb-xdw-ingest-common.qos (ETL\Ingestor\DatabaseIngestor), start_time: 1666877190.6496, end_time: 1666877190.6946, elapsed_time: 0.04506, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:30 [notice] (action: xdmod.hpcdb-xdw-ingest-common.request (ETL\Ingestor\DatabaseIngestor), start_time: 1666877190.728, end_time: 1666877190.7733, elapsed_time: 0.04524, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:30 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource-type (ETL\Ingestor\DatabaseIngestor), start_time: 1666877190.8101, end_time: 1666877190.8504, elapsed_time: 0.0403, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:30 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource-spec (ETL\Ingestor\DatabaseIngestor), start_time: 1666877190.8855, end_time: 1666877190.9279, elapsed_time: 0.04247, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:31 [notice] (action: xdmod.hpcdb-xdw-ingest-common.resource-allocated (ETL\Ingestor\DatabaseIngestor), start_time: 1666877190.9626, end_time: 1666877191.0028, elapsed_time: 0.04019, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:31 [notice] (action: xdmod.hpcdb-xdw-ingest-common.service-provider (ETL\Ingestor\DatabaseIngestor), start_time: 1666877191.0377, end_time: 1666877191.0803, elapsed_time: 0.0426, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:31 [notice] (action: xdmod.hpcdb-xdw-ingest-common.system-account (ETL\Ingestor\DatabaseIngestor), start_time: 1666877191.1162, end_time: 1666877191.1833, elapsed_time: 0.0671, records_examined: 414, records_loaded: 414) 2022-10-27 13:26:31 [notice] Finished processing section 'xdmod.hpcdb-xdw-ingest-common' 2022-10-27 13:26:31 [notice] Start processing section 'xdmod.jobs-cloud-extract-openstack' 2022-10-27 13:26:31 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackEventMapInitializer (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877191.2364, end_time: 1666877191.3181, elapsed_time: 0.08174, records_examined: 60, records_loaded: 60) 2022-10-27 13:26:34 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackCloudAccountIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877191.3548, end_time: 1666877194.4561, elapsed_time: 3.10135, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:36 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackCloudHostIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877194.4969, end_time: 1666877196.7283, elapsed_time: 2.23138, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:38 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackCloudImageIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877196.7584, end_time: 1666877198.8791, elapsed_time: 2.12066, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:45 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackCloudInstanceTypeIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877198.9124, end_time: 1666877205.7243, elapsed_time: 6.81186, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:52 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackVolumeIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877205.7801, end_time: 1666877212.5835, elapsed_time: 6.80344, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:56 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackInstanceIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877212.6144, end_time: 1666877216.8806, elapsed_time: 4.26621, records_examined: 2, records_loaded: 2) 2022-10-27 13:26:56 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/cloud_openstack/unknown_domain.sql' using delimiter '//' containing 1 statements 2022-10-27 13:26:56 [notice] Finished Processing 1 SQL statements 2022-10-27 13:26:56 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackUnknownDomainIngestor (ETL\Maintenance\ExecuteSql), start_time: 1666877216.918, end_time: 1666877216.9867, elapsed_time: 0.06872) 2022-10-27 13:26:59 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackDomainIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877217.0155, end_time: 1666877219.4576, elapsed_time: 2.44211, records_examined: 0, records_loaded: 0) 2022-10-27 13:26:59 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackDomainToSubmissionVenueMappingStagingIngestor (ETL\Ingestor\StructuredFileIngestor), start_time: 1666877219.5074, end_time: 1666877219.6397, elapsed_time: 0.13221, records_examined: 1, records_loaded: 1) 2022-10-27 13:26:59 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackDomainToSubmissionVenueMappingIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877219.6768, end_time: 1666877219.7946, elapsed_time: 0.11775, records_examined: 2, records_loaded: 2) 2022-10-27 13:26:59 [notice] Altering table modw_cloud.openstack_staging_event 2022-10-27 13:31:39 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackCloudStagingEventIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877219.8238, end_time: 1666877499.5661, elapsed_time: 279.74223, records_examined: 1740, records_loaded: 1740) 2022-10-27 13:31:39 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackCloudRootVolumeIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877499.6671, end_time: 1666877499.7565, elapsed_time: 0.08947, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:39 [notice] Altering table modw_cloud.event 2022-10-27 13:31:40 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackCloudEventIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877499.7951, end_time: 1666877500.4683, elapsed_time: 0.67313, records_examined: 464, records_loaded: 464) 2022-10-27 13:31:40 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackInstanceDataIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877500.5317, end_time: 1666877500.6564, elapsed_time: 0.12468, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:40 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackCloudEventAssetRootVolumeIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877500.6922, end_time: 1666877500.744, elapsed_time: 0.05179, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:40 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackCloudEventAssetIngestor (ETL\Ingestor\DatabaseIngestor), start_time: 1666877500.7795, end_time: 1666877500.8233, elapsed_time: 0.04384, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:40 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/cloud_openstack/post_ingest_update.sql' using delimiter '//' containing 8 statements 2022-10-27 13:31:43 [notice] Finished Processing 8 SQL statements 2022-10-27 13:31:43 [notice] (action: xdmod.jobs-cloud-extract-openstack.OpenStackCloudPostIngestUpdates (ETL\Maintenance\ExecuteSql), start_time: 1666877500.8619, end_time: 1666877503.4077, elapsed_time: 2.54582) 2022-10-27 13:31:43 [notice] Finished processing section 'xdmod.jobs-cloud-extract-openstack' 2022-10-27 13:31:43 [notice] Start processing section 'xdmod.jobs-cloud-ingest-pi' 2022-10-27 13:31:43 [notice] (action: xdmod.jobs-cloud-ingest-pi.pi-resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877503.4587, end_time: 1666877503.5139, elapsed_time: 0.05519, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:43 [notice] (action: xdmod.jobs-cloud-ingest-pi.pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877503.5513, end_time: 1666877503.6202, elapsed_time: 0.06895, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:43 [notice] (action: xdmod.jobs-cloud-ingest-pi.union-user-pi--pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877503.6817, end_time: 1666877503.7428, elapsed_time: 0.06117, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:43 [notice] (action: xdmod.jobs-cloud-ingest-pi.union-user-pi-resource--pi (ETL\Ingestor\DatabaseIngestor), start_time: 1666877503.7894, end_time: 1666877503.8496, elapsed_time: 0.06021, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:43 [notice] (action: xdmod.jobs-cloud-ingest-pi.user-pi-resource (ETL\Ingestor\DatabaseIngestor), start_time: 1666877503.9171, end_time: 1666877503.9885, elapsed_time: 0.07147, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:44 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/cloud_common/pi_to_account.sql' using delimiter '//' containing 1 statements 2022-10-27 13:31:44 [notice] Finished Processing 1 SQL statements 2022-10-27 13:31:44 [notice] (action: xdmod.jobs-cloud-ingest-pi.UpdateCloudProjectToPI (ETL\Maintenance\ExecuteSql), start_time: 1666877504.0364, end_time: 1666877504.1052, elapsed_time: 0.06884) 2022-10-27 13:31:44 [notice] Finished processing section 'xdmod.jobs-cloud-ingest-pi' 2022-10-27 13:31:44 [notice] Ingesting cloud resource specs 2022-10-27 13:31:44 [notice] Start processing section 'xdmod.ingest-cloud-resource-specs' 2022-10-27 13:31:44 [notice] Altering table modw_cloud.cloud_resource_specs 2022-10-27 13:31:44 [notice] (action: xdmod.ingest-cloud-resource-specs.CloudResourceSpecsReconstructor (ETL\Ingestor\CloudResourceSpecsStateTransformIngestor), start_time: 1666877504.4715, end_time: 1666877504.5695, elapsed_time: 0.09802, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:44 [notice] Finished processing section 'xdmod.ingest-cloud-resource-specs' 2022-10-27 13:31:50 [notice] Start processing section 'xdmod.jobs-xdw-aggregate' 2022-10-27 13:31:50 [notice] Table modw_aggregates.jobfact_by_day_joblist does not exist, creating. 2022-10-27 13:31:50 [notice] (action: xdmod.jobs-xdw-aggregate.table-create (ETL\Maintenance\ManageTables), start_time: 1666877510.3655, end_time: 1666877510.3982, elapsed_time: 0.03269) 2022-10-27 13:31:50 [notice] Table modw_aggregates.jobfact_by_day does not exist, creating. 2022-10-27 13:31:50 [notice] aggregate start (action: xdmod.jobs-xdw-aggregate.aggregate-days (ETL\Aggregator\JobListAggregator), unit: day, start_date: none, end_date: none) 2022-10-27 13:31:50 [notice] aggregate end (action: xdmod.jobs-xdw-aggregate.aggregate-days (ETL\Aggregator\JobListAggregator), unit: day, periods: 0, start_date: none, end_date: none, start_time: 1666877510.5163, end_time: 1666877510.5787, elapsed_time: 0.06238) 2022-10-27 13:31:50 [notice] end (action: xdmod.jobs-xdw-aggregate.aggregate-days (ETL\Aggregator\JobListAggregator), start_time: 1666877510.4222, end_time: 1666877510.595, elapsed_time: 0.003m) 2022-10-27 13:31:50 [notice] Table modw_aggregates.jobfact_by_month does not exist, creating. 2022-10-27 13:31:50 [notice] aggregate start (action: xdmod.jobs-xdw-aggregate.aggregate (ETL\Aggregator\SimpleAggregator), unit: month, start_date: none, end_date: none) 2022-10-27 13:31:50 [notice] aggregate end (action: xdmod.jobs-xdw-aggregate.aggregate (ETL\Aggregator\SimpleAggregator), unit: month, periods: 0, start_date: none, end_date: none, start_time: 1666877510.7295, end_time: 1666877510.7908, elapsed_time: 0.06125) 2022-10-27 13:31:50 [notice] Table modw_aggregates.jobfact_by_quarter does not exist, creating. 2022-10-27 13:31:50 [notice] aggregate start (action: xdmod.jobs-xdw-aggregate.aggregate (ETL\Aggregator\SimpleAggregator), unit: quarter, start_date: none, end_date: none) 2022-10-27 13:31:50 [notice] aggregate end (action: xdmod.jobs-xdw-aggregate.aggregate (ETL\Aggregator\SimpleAggregator), unit: quarter, periods: 0, start_date: none, end_date: none, start_time: 1666877510.9029, end_time: 1666877510.9672, elapsed_time: 0.06428) 2022-10-27 13:31:50 [notice] Table modw_aggregates.jobfact_by_year does not exist, creating. 2022-10-27 13:31:51 [notice] aggregate start (action: xdmod.jobs-xdw-aggregate.aggregate (ETL\Aggregator\SimpleAggregator), unit: year, start_date: none, end_date: none) 2022-10-27 13:31:51 [notice] Duplicate column after substitution: ("${aggregation_unit}: ${:PERIOD_VALUE}") '${aggregation_unit}' -> 'year' 2022-10-27 13:31:51 [notice] aggregate end (action: xdmod.jobs-xdw-aggregate.aggregate (ETL\Aggregator\SimpleAggregator), unit: year, periods: 0, start_date: none, end_date: none, start_time: 1666877511.0762, end_time: 1666877511.1485, elapsed_time: 0.07236) 2022-10-27 13:31:51 [notice] end (action: xdmod.jobs-xdw-aggregate.aggregate (ETL\Aggregator\SimpleAggregator), start_time: 1666877510.6185, end_time: 1666877511.1665, elapsed_time: 0.009m) 2022-10-27 13:31:51 [notice] (action: xdmod.jobs-xdw-aggregate.aggregation-joblist (ETL\Ingestor\ExplodeTransformIngestor), start_time: 1666877511.1939, end_time: 1666877511.2668, elapsed_time: 0.07286, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:51 [notice] Finished processing section 'xdmod.jobs-xdw-aggregate' 2022-10-27 13:31:51 [notice] start (action: Jobs.build-filter-list) 2022-10-27 13:31:51 [notice] start (action: Jobs.build-filter-list.provider) 2022-10-27 13:31:51 [notice] end (action: Jobs.build-filter-list.provider, start_time: 1666877511.3781, end_time: 1666877511.5136) 2022-10-27 13:31:51 [notice] start (action: Jobs.build-filter-list.pi) 2022-10-27 13:31:51 [notice] end (action: Jobs.build-filter-list.pi, start_time: 1666877511.5239, end_time: 1666877511.6047) 2022-10-27 13:31:51 [notice] start (action: Jobs.build-filter-list.person) 2022-10-27 13:31:51 [notice] end (action: Jobs.build-filter-list.person, start_time: 1666877511.6144, end_time: 1666877511.6609) 2022-10-27 13:31:51 [notice] start (action: Jobs.build-filter-list.qos) 2022-10-27 13:31:51 [notice] end (action: Jobs.build-filter-list.qos, start_time: 1666877511.6707, end_time: 1666877511.8195) 2022-10-27 13:31:51 [notice] start (action: Jobs.build-filter-list.queue) 2022-10-27 13:31:51 [notice] end (action: Jobs.build-filter-list.queue, start_time: 1666877511.8296, end_time: 1666877511.9797) 2022-10-27 13:31:51 [notice] start (action: Jobs.build-filter-list.username) 2022-10-27 13:31:52 [notice] end (action: Jobs.build-filter-list.username, start_time: 1666877511.9905, end_time: 1666877512.1338) 2022-10-27 13:31:52 [notice] start (action: Jobs.build-filter-list.resource_type) 2022-10-27 13:31:52 [notice] end (action: Jobs.build-filter-list.resource_type, start_time: 1666877512.1432, end_time: 1666877512.286) 2022-10-27 13:31:52 [notice] start (action: Jobs.build-filter-list.resource) 2022-10-27 13:31:52 [notice] end (action: Jobs.build-filter-list.resource, start_time: 1666877512.2958, end_time: 1666877512.4414) 2022-10-27 13:31:52 [notice] start (action: Jobs.build-filter-list.nsfdirectorate) 2022-10-27 13:31:52 [notice] end (action: Jobs.build-filter-list.nsfdirectorate, start_time: 1666877512.4521, end_time: 1666877512.6001) 2022-10-27 13:31:52 [notice] start (action: Jobs.build-filter-list.parentscience) 2022-10-27 13:31:52 [notice] end (action: Jobs.build-filter-list.parentscience, start_time: 1666877512.6094, end_time: 1666877512.7828) 2022-10-27 13:31:52 [notice] start (action: Jobs.build-filter-list.jobwaittime) 2022-10-27 13:31:52 [notice] end (action: Jobs.build-filter-list.jobwaittime, start_time: 1666877512.792, end_time: 1666877512.9208) 2022-10-27 13:31:52 [notice] start (action: Jobs.build-filter-list.gpucount) 2022-10-27 13:31:53 [notice] end (action: Jobs.build-filter-list.gpucount, start_time: 1666877512.9293, end_time: 1666877513.1121) 2022-10-27 13:31:53 [notice] start (action: Jobs.build-filter-list.jobsize) 2022-10-27 13:31:53 [notice] end (action: Jobs.build-filter-list.jobsize, start_time: 1666877513.1208, end_time: 1666877513.2285) 2022-10-27 13:31:53 [notice] start (action: Jobs.build-filter-list.fieldofscience) 2022-10-27 13:31:53 [notice] end (action: Jobs.build-filter-list.fieldofscience, start_time: 1666877513.2369, end_time: 1666877513.3558) 2022-10-27 13:31:53 [notice] start (action: Jobs.build-filter-list.jobwalltime) 2022-10-27 13:31:53 [notice] end (action: Jobs.build-filter-list.jobwalltime, start_time: 1666877513.3631, end_time: 1666877513.5133) 2022-10-27 13:31:53 [notice] start (action: Jobs.build-filter-list.nodecount) 2022-10-27 13:31:53 [notice] end (action: Jobs.build-filter-list.nodecount, start_time: 1666877513.521, end_time: 1666877513.6351) 2022-10-27 13:31:53 [notice] end (action: Jobs.build-filter-list, start_time: 1666877511.3184, end_time: 1666877513.6445) 2022-10-27 13:31:53 [notice] Aggregating Cloud data 2022-10-27 13:31:54 [notice] Start processing section 'xdmod.cloud-state-pipeline' 2022-10-27 13:31:54 [notice] (action: xdmod.cloud-state-pipeline.cloud-state-action (ETL\Ingestor\CloudStateReconstructorTransformIngestor), start_time: 1666877514.1433, end_time: 1666877514.2685, elapsed_time: 0.12526, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:54 [notice] Processing SQL file '/etc/xdmod/etl/etl_sql.d/cloud_common/delete_session_records.sql' using delimiter '//' containing 1 statements 2022-10-27 13:31:54 [notice] Finished Processing 1 SQL statements 2022-10-27 13:31:54 [notice] (action: xdmod.cloud-state-pipeline.delete-session-records (ETL\Maintenance\ExecuteSql), start_time: 1666877514.3019, end_time: 1666877514.3368, elapsed_time: 0.03489) 2022-10-27 13:31:54 [notice] Altering table modw_cloud.session_records 2022-10-27 13:31:54 [notice] (action: xdmod.cloud-state-pipeline.cloud-session-records (ETL\Ingestor\DatabaseIngestor), start_time: 1666877514.3644, end_time: 1666877514.4222, elapsed_time: 0.05779, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:54 [notice] Altering table modw_cloud.cloudfact_by_day 2022-10-27 13:31:54 [notice] aggregate start (action: xdmod.cloud-state-pipeline.CloudEventAggregatorByDay (ETL\Aggregator\JobListAggregator), unit: day, start_date: none, end_date: none) 2022-10-27 13:31:54 [notice] aggregate end (action: xdmod.cloud-state-pipeline.CloudEventAggregatorByDay (ETL\Aggregator\JobListAggregator), unit: day, periods: 0, start_date: none, end_date: none, start_time: 1666877514.4929, end_time: 1666877514.5997, elapsed_time: 0.1068) 2022-10-27 13:31:54 [notice] end (action: xdmod.cloud-state-pipeline.CloudEventAggregatorByDay (ETL\Aggregator\JobListAggregator), start_time: 1666877514.4537, end_time: 1666877514.6165, elapsed_time: 0.003m) 2022-10-27 13:31:54 [notice] aggregate start (action: xdmod.cloud-state-pipeline.CloudEventAggregator (ETL\Aggregator\SimpleAggregator), unit: month, start_date: none, end_date: none) 2022-10-27 13:31:54 [notice] aggregate end (action: xdmod.cloud-state-pipeline.CloudEventAggregator (ETL\Aggregator\SimpleAggregator), unit: month, periods: 0, start_date: none, end_date: none, start_time: 1666877514.671, end_time: 1666877514.7287, elapsed_time: 0.05771) 2022-10-27 13:31:54 [notice] aggregate start (action: xdmod.cloud-state-pipeline.CloudEventAggregator (ETL\Aggregator\SimpleAggregator), unit: quarter, start_date: none, end_date: none) 2022-10-27 13:31:54 [notice] aggregate end (action: xdmod.cloud-state-pipeline.CloudEventAggregator (ETL\Aggregator\SimpleAggregator), unit: quarter, periods: 0, start_date: none, end_date: none, start_time: 1666877514.7628, end_time: 1666877514.8174, elapsed_time: 0.05465) 2022-10-27 13:31:54 [notice] aggregate start (action: xdmod.cloud-state-pipeline.CloudEventAggregator (ETL\Aggregator\SimpleAggregator), unit: year, start_date: none, end_date: none) 2022-10-27 13:31:54 [notice] Duplicate column after substitution: ("${aggregation_unit}: ${:PERIOD_VALUE}") '${aggregation_unit}' -> 'year' 2022-10-27 13:31:54 [notice] aggregate end (action: xdmod.cloud-state-pipeline.CloudEventAggregator (ETL\Aggregator\SimpleAggregator), unit: year, periods: 0, start_date: none, end_date: none, start_time: 1666877514.8522, end_time: 1666877514.9174, elapsed_time: 0.06512) 2022-10-27 13:31:54 [notice] end (action: xdmod.cloud-state-pipeline.CloudEventAggregator (ETL\Aggregator\SimpleAggregator), start_time: 1666877514.6414, end_time: 1666877514.9333, elapsed_time: 0.005m) 2022-10-27 13:31:55 [notice] (action: xdmod.cloud-state-pipeline.CloudAggregatorSessionlist (ETL\Ingestor\ExplodeTransformIngestor), start_time: 1666877514.9594, end_time: 1666877515.0583, elapsed_time: 0.09894, records_examined: 0, records_loaded: 0) 2022-10-27 13:31:55 [notice] Finished processing section 'xdmod.cloud-state-pipeline' 2022-10-27 13:31:55 [notice] Aggregating Cloud Resource Specification data 2022-10-27 13:31:55 [notice] Start processing section 'xdmod.aggregate-cloud-resource-specs' 2022-10-27 13:31:55 [notice] Table modw_aggregates.resourcespecsfact_by_day does not exist, creating. 2022-10-27 13:31:55 [notice] aggregate start (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: day, start_date: none, end_date: none) 2022-10-27 13:31:55 [notice] aggregate end (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: day, periods: 0, start_date: none, end_date: none, start_time: 1666877515.4098, end_time: 1666877515.4837, elapsed_time: 0.07394) 2022-10-27 13:31:55 [notice] Table modw_aggregates.resourcespecsfact_by_month does not exist, creating. 2022-10-27 13:31:55 [notice] aggregate start (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: month, start_date: none, end_date: none) 2022-10-27 13:31:55 [notice] aggregate end (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: month, periods: 0, start_date: none, end_date: none, start_time: 1666877515.543, end_time: 1666877515.5995, elapsed_time: 0.05656) 2022-10-27 13:31:55 [notice] Table modw_aggregates.resourcespecsfact_by_quarter does not exist, creating. 2022-10-27 13:31:55 [notice] aggregate start (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: quarter, start_date: none, end_date: none) 2022-10-27 13:31:55 [notice] aggregate end (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: quarter, periods: 0, start_date: none, end_date: none, start_time: 1666877515.6636, end_time: 1666877515.7181, elapsed_time: 0.05451) 2022-10-27 13:31:55 [notice] Table modw_aggregates.resourcespecsfact_by_year does not exist, creating. 2022-10-27 13:31:55 [notice] aggregate start (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: year, start_date: none, end_date: none) 2022-10-27 13:31:55 [notice] Duplicate column after substitution: ("${aggregation_unit}: ${:PERIOD_VALUE}") '${aggregation_unit}' -> 'year' 2022-10-27 13:31:55 [notice] aggregate end (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: year, periods: 0, start_date: none, end_date: none, start_time: 1666877515.7835, end_time: 1666877515.8525, elapsed_time: 0.06897) 2022-10-27 13:31:55 [notice] end (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), start_time: 1666877515.3615, end_time: 1666877515.8731, elapsed_time: 0.009m) 2022-10-27 13:31:55 [notice] Finished processing section 'xdmod.aggregate-cloud-resource-specs' 2022-10-27 13:31:55 [notice] start (action: Cloud.build-filter-list) 2022-10-27 13:31:56 [notice] start (action: Cloud.build-filter-list.vm_size_memory) 2022-10-27 13:31:56 [notice] end (action: Cloud.build-filter-list.vm_size_memory, start_time: 1666877516.0058, end_time: 1666877516.2251) 2022-10-27 13:31:56 [notice] start (action: Cloud.build-filter-list.vm_size) 2022-10-27 13:31:56 [notice] end (action: Cloud.build-filter-list.vm_size, start_time: 1666877516.2349, end_time: 1666877516.4048) 2022-10-27 13:31:56 [notice] start (action: Cloud.build-filter-list.username) 2022-10-27 13:31:56 [notice] end (action: Cloud.build-filter-list.username, start_time: 1666877516.4149, end_time: 1666877516.5591) 2022-10-27 13:31:56 [notice] start (action: Cloud.build-filter-list.pi) 2022-10-27 13:31:56 [notice] end (action: Cloud.build-filter-list.pi, start_time: 1666877516.5669, end_time: 1666877516.6859) 2022-10-27 13:31:56 [notice] start (action: Cloud.build-filter-list.fieldofscience) 2022-10-27 13:31:56 [notice] end (action: Cloud.build-filter-list.fieldofscience, start_time: 1666877516.6944, end_time: 1666877516.8436) 2022-10-27 13:31:56 [notice] start (action: Cloud.build-filter-list.parentscience) 2022-10-27 13:31:57 [notice] end (action: Cloud.build-filter-list.parentscience, start_time: 1666877516.8532, end_time: 1666877517.014) 2022-10-27 13:31:57 [notice] start (action: Cloud.build-filter-list.nsfdirectorate) 2022-10-27 13:31:57 [notice] end (action: Cloud.build-filter-list.nsfdirectorate, start_time: 1666877517.0237, end_time: 1666877517.1974) 2022-10-27 13:31:57 [notice] start (action: Cloud.build-filter-list.submission_venue) 2022-10-27 13:31:57 [notice] end (action: Cloud.build-filter-list.submission_venue, start_time: 1666877517.2094, end_time: 1666877517.3665) 2022-10-27 13:31:57 [notice] start (action: Cloud.build-filter-list.provider) 2022-10-27 13:31:57 [notice] end (action: Cloud.build-filter-list.provider, start_time: 1666877517.3764, end_time: 1666877517.4605) 2022-10-27 13:31:57 [notice] start (action: Cloud.build-filter-list.domain) 2022-10-27 13:31:57 [notice] end (action: Cloud.build-filter-list.domain, start_time: 1666877517.4707, end_time: 1666877517.6369) 2022-10-27 13:31:57 [notice] start (action: Cloud.build-filter-list.project) 2022-10-27 13:31:57 [notice] end (action: Cloud.build-filter-list.project, start_time: 1666877517.6473, end_time: 1666877517.8779) 2022-10-27 13:31:57 [notice] start (action: Cloud.build-filter-list.person) 2022-10-27 13:31:57 [notice] end (action: Cloud.build-filter-list.person, start_time: 1666877517.891, end_time: 1666877517.9398) 2022-10-27 13:31:57 [notice] start (action: Cloud.build-filter-list.resource) 2022-10-27 13:31:58 [notice] end (action: Cloud.build-filter-list.resource, start_time: 1666877517.9514, end_time: 1666877518.1497) 2022-10-27 13:31:58 [notice] start (action: Cloud.build-filter-list.configuration) 2022-10-27 13:31:58 [notice] end (action: Cloud.build-filter-list.configuration, start_time: 1666877518.1601, end_time: 1666877518.3139) 2022-10-27 13:31:58 [notice] end (action: Cloud.build-filter-list, start_time: 1666877515.9131, end_time: 1666877518.3217) 2022-10-27 13:31:58 [notice] Storage realm not enabled, not aggregating 2022-10-27 13:31:58 [notice] Aggregating Cloud Resource Specification data 2022-10-27 13:31:58 [notice] Start processing section 'xdmod.aggregate-cloud-resource-specs' 2022-10-27 13:31:58 [notice] aggregate start (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: day, start_date: none, end_date: none) 2022-10-27 13:31:58 [notice] aggregate end (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: day, periods: 0, start_date: none, end_date: none, start_time: 1666877518.6165, end_time: 1666877518.6657, elapsed_time: 0.04912) 2022-10-27 13:31:58 [notice] aggregate start (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: month, start_date: none, end_date: none) 2022-10-27 13:31:58 [notice] aggregate end (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: month, periods: 0, start_date: none, end_date: none, start_time: 1666877518.7065, end_time: 1666877518.7565, elapsed_time: 0.05004) 2022-10-27 13:31:58 [notice] aggregate start (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: quarter, start_date: none, end_date: none) 2022-10-27 13:31:58 [notice] aggregate end (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: quarter, periods: 0, start_date: none, end_date: none, start_time: 1666877518.7887, end_time: 1666877518.8353, elapsed_time: 0.04659) 2022-10-27 13:31:58 [notice] aggregate start (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: year, start_date: none, end_date: none) 2022-10-27 13:31:58 [notice] Duplicate column after substitution: ("${aggregation_unit}: ${:PERIOD_VALUE}") '${aggregation_unit}' -> 'year' 2022-10-27 13:31:58 [notice] aggregate end (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), unit: year, periods: 0, start_date: none, end_date: none, start_time: 1666877518.8652, end_time: 1666877518.9236, elapsed_time: 0.05834) 2022-10-27 13:31:58 [notice] end (action: xdmod.aggregate-cloud-resource-specs.CloudResourceSpecsAggregator (ETL\Aggregator\SimpleAggregator), start_time: 1666877518.5907, end_time: 1666877518.938, elapsed_time: 0.006m) 2022-10-27 13:31:58 [notice] Finished processing section 'xdmod.aggregate-cloud-resource-specs' 2022-10-27 13:31:58 [notice] xdmod-ingestor end (process_end_time: 2022-10-27 13:31:58)

Robert Bartlett Baron , said 10 months ago Greg,

Haven't heard from you in the past 11 days. Was wondering what the current status is?

Were you able to replicate what I am seeing?

Do you need anything?

Would a call be useful?

Rob. Gregary Dean , said 9 months ago Cc: joachimw@bu.edu, msd@bu.edu, syockel@g.harvard.edu Ticket: https://help.xdmod.org/support/tickets/31301

Hi Robert,

Thanks for sending the log files and I'm sorry for the delay in responding. It looks like the data is being ingested properly but not making it into the aggregation tables. In the last query you ran, the MAX(end_time) should be much closer to the value in the second column of the query you ran before it. The aggregation tables are the tables that the user interface gets its data from. In looking at the log files you sent it seems like they only contain events related to volumes, such as when a volume is created or deleted. XDMoD's cloud metrics are only for compute instances, such as how many core hours consumed, the number of VM sessions started, or the number of VM sessions ended. It does not contain any metrics related to volumes. If you do not have instances events, such as when instances are created, paused, resumed, or deleted, in your logs then no data will be shown in the user interface. The XDMoD website has a list of available cloud metrics, https://open.xdmod.org/10.0/cloud.html

In response to your questions.

Does this mean that your uses can create a volume and xdmod will not report on that volume unless it is associated with an instance? XDMoD will not report on that volume at all as XDMoD does not have any metrics related to attached volumes

How do you report on a volume that was associated with an instance, however the instance has been deleted but the volume still exists? XDMoD does not report this information.

As I said earlier, it looks like the reason you are not seeing any data in the user interface is that your logs do not contain the necessary information, i.e., events related to instances such as creating, deleting, pausing, etc, that XDMoD needs for the cloud metrics that currently exist.

Again, I'm sorry for the delay in getting back to you.

-greg Robert Bartlett Baron , said 9 months ago OK, I have gotten things to appear in the UI.
Gregary Dean , said 9 months ago Cc: joachimw@bu.edu, msd@bu.edu, syockel@g.harvard.edu Ticket: https://help.xdmod.org/support/tickets/31301

Hi Robert, ​ Great! I'm glad to hear you got it working. ​ -greg