Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Overall total and importRate metrics are wrong after bulk data import #2076

Closed
lmsurpre opened this issue Mar 12, 2021 · 2 comments
Closed

Overall total and importRate metrics are wrong after bulk data import #2076

lmsurpre opened this issue Mar 12, 2021 · 2 comments
Assignees
@prb112
Labels
bug Something isn't working bulk-data
Milestone
Sprint 2021-04

Comments

@lmsurpre
Copy link
Member

Describe the bug

2021-03-12 03:26:50.730 fhir-internal INFO Received request: tenantId:[default] dsId:[default] user:[fhiruser] method:[POST] uri:[https://****/fhir-server/api/v4/$import] originalUri:[https://****/basic/$import]
2021-03-12 03:26:51.326 fhir-internal INFO Completed request[0.596 secs]: tenantId:[default] dsId:[default] user:[fhiruser] method:[POST] uri:[https://****/fhir-server/api/v4/$import] originalUri:[https://****/basic/$import] status:[202]
2021-03-12 03:26:52.324 fhir-internal INFO ObjectStorge Object -'****/Condition_2.ndjson' - '40489339' bytes.
2021-03-12 03:26:52.906 fhir-internal INFO ObjectStorge Object -'****/Condition_3.ndjson' - '40508632' bytes.
2021-03-12 03:26:53.519 fhir-internal INFO ObjectStorge Object -'****/Condition_4.ndjson' - '40518370' bytes.
2021-03-12 03:27:11.992 fhir-internal INFO 2000 Condition resources imported in 17.451 seconds, ImportRate: 114.61/Second
2021-03-12 03:27:28.536 fhir-internal INFO 2000 Condition resources imported in 16.545 seconds, ImportRate: 120.88/Second
2021-03-12 03:27:45.227 fhir-internal INFO 2000 Condition resources imported in 16.69 seconds, ImportRate: 119.83/Second
2021-03-12 03:28:01.923 fhir-internal INFO 2000 Condition resources imported in 16.696 seconds, ImportRate: 119.79/Second
2021-03-12 03:28:18.794 fhir-internal INFO 2000 Condition resources imported in 16.871 seconds, ImportRate: 118.55/Second
2021-03-12 03:28:36.212 fhir-internal INFO 2000 Condition resources imported in 17.418 seconds, ImportRate: 114.82/Second
2021-03-12 03:28:53.156 fhir-internal INFO 2000 Condition resources imported in 16.944 seconds, ImportRate: 118.04/Second
2021-03-12 03:29:10.742 fhir-internal INFO 2000 Condition resources imported in 17.587 seconds, ImportRate: 113.72/Second
2021-03-12 03:29:27.795 fhir-internal INFO 2000 Condition resources imported in 17.053 seconds, ImportRate: 117.28/Second
2021-03-12 03:29:45.180 fhir-internal INFO 2000 Condition resources imported in 17.385 seconds, ImportRate: 115.04/Second
2021-03-12 03:30:02.052 fhir-internal INFO 2000 Condition resources imported in 16.872 seconds, ImportRate: 118.54/Second
2021-03-12 03:30:19.609 fhir-internal INFO 2000 Condition resources imported in 17.556 seconds, ImportRate: 113.92/Second
2021-03-12 03:30:36.136 fhir-internal INFO 2000 Condition resources imported in 16.528 seconds, ImportRate: 121.01/Second
2021-03-12 03:30:52.736 fhir-internal INFO 2000 Condition resources imported in 16.599 seconds, ImportRate: 120.49/Second
2021-03-12 03:31:09.932 fhir-internal INFO 2000 Condition resources imported in 17.196 seconds, ImportRate: 116.31/Second
2021-03-12 03:31:26.282 fhir-internal INFO 2000 Condition resources imported in 16.351 seconds, ImportRate: 122.32/Second
2021-03-12 03:31:42.907 fhir-internal INFO 2000 Condition resources imported in 16.625 seconds, ImportRate: 120.30/Second
2021-03-12 03:32:00.455 fhir-internal INFO 2000 Condition resources imported in 17.548 seconds, ImportRate: 113.97/Second
2021-03-12 03:32:18.096 fhir-internal INFO 2000 Condition resources imported in 17.64 seconds, ImportRate: 113.38/Second
2021-03-12 03:32:34.779 fhir-internal INFO 2000 Condition resources imported in 16.684 seconds, ImportRate: 119.88/Second
2021-03-12 03:32:50.687 fhir-internal INFO 2000 Condition resources imported in 15.908 seconds, ImportRate: 125.72/Second
2021-03-12 03:33:07.917 fhir-internal INFO 2000 Condition resources imported in 17.229 seconds, ImportRate: 116.08/Second
2021-03-12 03:33:23.424 fhir-internal INFO 2000 Condition resources imported in 15.508 seconds, ImportRate: 128.97/Second
2021-03-12 03:33:40.076 fhir-internal INFO 2000 Condition resources imported in 16.651 seconds, ImportRate: 120.11/Second
2021-03-12 03:33:56.441 fhir-internal INFO 2000 Condition resources imported in 16.366 seconds, ImportRate: 122.20/Second
2021-03-12 03:34:14.223 fhir-internal INFO 2000 Condition resources imported in 17.782 seconds, ImportRate: 112.47/Second
2021-03-12 03:34:30.968 fhir-internal INFO 2000 Condition resources imported in 16.744 seconds, ImportRate: 119.45/Second
2021-03-12 03:34:47.696 fhir-internal INFO 2000 Condition resources imported in 16.728 seconds, ImportRate: 119.56/Second
2021-03-12 03:35:05.355 fhir-internal INFO 2000 Condition resources imported in 17.659 seconds, ImportRate: 113.26/Second
2021-03-12 03:35:21.870 fhir-internal INFO 2000 Condition resources imported in 16.516 seconds, ImportRate: 121.09/Second
2021-03-12 03:35:37.901 fhir-internal INFO 2000 Condition resources imported in 16.03 seconds, ImportRate: 124.77/Second
2021-03-12 03:35:52.771 fhir-internal INFO 2000 Condition resources imported in 14.871 seconds, ImportRate: 134.49/Second
2021-03-12 03:36:08.184 fhir-internal INFO 2000 Condition resources imported in 15.413 seconds, ImportRate: 129.76/Second
2021-03-12 03:36:22.891 fhir-internal INFO 2000 Condition resources imported in 14.705 seconds, ImportRate: 136.01/Second
2021-03-12 03:36:37.999 fhir-internal INFO 2000 Condition resources imported in 15.11 seconds, ImportRate: 132.36/Second
2021-03-12 03:36:52.910 fhir-internal INFO 2000 Condition resources imported in 14.91 seconds, ImportRate: 134.14/Second
2021-03-12 03:37:08.468 fhir-internal INFO 2000 Condition resources imported in 15.559 seconds, ImportRate: 128.54/Second
2021-03-12 03:37:22.798 fhir-internal INFO 2000 Condition resources imported in 14.329 seconds, ImportRate: 139.58/Second
2021-03-12 03:37:37.551 fhir-internal INFO 2000 Condition resources imported in 14.753 seconds, ImportRate: 135.57/Second
2021-03-12 03:37:52.191 fhir-internal INFO 2000 Condition resources imported in 14.641 seconds, ImportRate: 136.60/Second
2021-03-12 03:38:07.132 fhir-internal INFO 2000 Condition resources imported in 14.94 seconds, ImportRate: 133.87/Second
2021-03-12 03:38:21.040 fhir-internal INFO 2000 Condition resources imported in 13.908 seconds, ImportRate: 143.80/Second
2021-03-12 03:38:35.677 fhir-internal INFO 2000 Condition resources imported in 14.637 seconds, ImportRate: 136.64/Second
2021-03-12 03:38:50.774 fhir-internal INFO 2000 Condition resources imported in 15.098 seconds, ImportRate: 132.47/Second
2021-03-12 03:39:06.307 fhir-internal INFO 2000 Condition resources imported in 15.533 seconds, ImportRate: 128.76/Second
2021-03-12 03:39:21.292 fhir-internal INFO 2000 Condition resources imported in 14.985 seconds, ImportRate: 133.47/Second
2021-03-12 03:39:36.138 fhir-internal INFO 2000 Condition resources imported in 14.846 seconds, ImportRate: 134.72/Second
2021-03-12 03:39:50.921 fhir-internal INFO 2000 Condition resources imported in 14.782 seconds, ImportRate: 135.30/Second
2021-03-12 03:40:06.275 fhir-internal INFO 2000 Condition resources imported in 15.355 seconds, ImportRate: 130.25/Second
2021-03-12 03:40:21.389 fhir-internal INFO 2000 Condition resources imported in 15.113 seconds, ImportRate: 132.34/Second
2021-03-12 03:40:36.312 fhir-internal INFO 2000 Condition resources imported in 14.923 seconds, ImportRate: 134.02/Second
2021-03-12 03:40:51.600 fhir-internal INFO 2000 Condition resources imported in 15.288 seconds, ImportRate: 130.82/Second
2021-03-12 03:41:07.210 fhir-internal INFO 2000 Condition resources imported in 15.611 seconds, ImportRate: 128.11/Second
2021-03-12 03:41:21.867 fhir-internal INFO 2000 Condition resources imported in 14.657 seconds, ImportRate: 136.45/Second
2021-03-12 03:41:36.896 fhir-internal INFO 2000 Condition resources imported in 15.029 seconds, ImportRate: 133.08/Second
2021-03-12 03:41:51.266 fhir-internal INFO 2000 Condition resources imported in 14.37 seconds, ImportRate: 139.18/Second
2021-03-12 03:42:07.474 fhir-internal INFO 2000 Condition resources imported in 16.208 seconds, ImportRate: 123.40/Second
2021-03-12 03:42:07.714 fhir-internal INFO Operation Type: $import
2021-03-12 03:42:07.715 fhir-internal INFO Resource Type         failures              success               processed             totalRead             totalValidation       totalWrite            fileSize              Resource Size         
2021-03-12 03:42:07.715 fhir-internal INFO Condition             0                     114000                114000                9422                  0                     1886269               121516341             1065.0                
2021-03-12 03:42:07.715 fhir-internal INFO  ---- Total: 0 ImportRate: 0.00 ----

Note the total and ImportRate output on the last line.

To Reproduce
Perform a bulk import and then check the logs. Not sure if it matters, but I'm using the an ibm-cos storageProvider.

Expected behavior
Total should list the total number of imported resources.
ImportRate should indicate the number of resources imported per second.

Additional context
It would be nice to give the importRate both in terms of resources/second but also KB/second (or similar) if possible
@lmsurpre lmsurpre added bug Something isn't working bulk-data labels Mar 12, 2021
@prb112 prb112 self-assigned this Mar 12, 2021
@prb112
Copy link
Contributor

prb112 commented Mar 12, 2021 •
edited
Loading

It'll look like that

[3/12/21, 15:02:09:434 UTC] com.ibm.fhir.bulkdata.jbatch.load.listener.Reporter            Operation Type: $import
[3/12/21, 15:02:09:434 UTC] com.ibm.fhir.bulkdata.jbatch.load.listener.Reporter            Resource Type         failures              success               processed             totalRead             totalValidation       totalWrite            fileSize              Resource Size         
[3/12/21, 15:02:09:435 UTC] com.ibm.fhir.bulkdata.jbatch.load.listener.Reporter            Patient               0                     3                     3                     2954                  0                     3563                  4303                  1434.0                
[3/12/21, 15:02:09:435 UTC] com.ibm.fhir.bulkdata.jbatch.load.listener.Reporter             ---- Total: 3 ImportRate: 0.38 ----

@prb112 prb112 added this to the Sprint 2021-04 milestone Mar 12, 2021
@lmsurpre
Copy link
Member Author

I confirm that Total and ImportRate values are now non-zero.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@prb112 prb112

Labels
bug Something isn't working bulk-data
Projects
None yet
Milestone
Sprint 2021-04
Development

No branches or pull requests
2 participants
@prb112 @lmsurpre