@@ -402,30 +402,73 @@ private void run() throws Exception {
402402 }
403403
404404 private Future <Void > createStoreVerticles () throws Exception {
405+ // Time the metadata loading phase - critical S3 operations
406+ metadataLoadingBeginTime = Instant .now ();
407+ LOGGER .info ("Starting store metadata loading phase" );
408+
405409 // load metadatas for the first time
406410 if (clientSideTokenGenerate ) {
411+ Instant start = Instant .now ();
407412 siteProvider .getMetadata ();
413+ recordMetadataLoadingTime ("site" , start );
414+
415+ start = Instant .now ();
408416 clientSideKeypairProvider .getMetadata ();
417+ recordMetadataLoadingTime ("client_side_keypair" , start );
409418 }
410419
411420 if (validateServiceLinks ) {
421+ Instant start = Instant .now ();
412422 serviceProvider .getMetadata ();
423+ recordMetadataLoadingTime ("service" , start );
424+
425+ start = Instant .now ();
413426 serviceLinkProvider .getMetadata ();
427+ recordMetadataLoadingTime ("service_link" , start );
414428 }
415429
416430 if (encryptedCloudFilesEnabled ) {
431+ Instant start = Instant .now ();
417432 cloudEncryptionKeyProvider .getMetadata ();
433+ recordMetadataLoadingTime ("cloud_encryption_key" , start );
418434 }
419435
436+ Instant start = Instant .now ();
420437 clientKeyProvider .getMetadata ();
438+ recordMetadataLoadingTime ("client_key" , start );
439+
440+ start = Instant .now ();
421441 keysetKeyStore .getMetadata ();
442+ recordMetadataLoadingTime ("keyset_key" , start );
443+
444+ start = Instant .now ();
422445 keysetProvider .getMetadata ();
446+ recordMetadataLoadingTime ("keyset" , start );
447+
448+ start = Instant .now ();
423449 saltProvider .getMetadata ();
450+ recordMetadataLoadingTime ("salt" , start );
451+
452+ Duration totalMetadataLoadingTime = Duration .between (metadataLoadingBeginTime , Instant .now ());
453+ LOGGER .info ("Store metadata loading phase completed in {} ms" , totalMetadataLoadingTime .toMillis ());
454+ recordPhaseTime ("store_metadata_loading" , totalMetadataLoadingTime );
424455
456+ // Time the cloud sync setup
457+ Instant cloudSyncStart = Instant .now ();
458+ LOGGER .info ("Setting up optout cloud sync" );
459+
425460 // create cloud sync for optout store
426461 OptOutCloudSync optOutCloudSync = new OptOutCloudSync (config , false );
427462 this .optOutStore .registerCloudSync (optOutCloudSync );
463+
464+ Duration cloudSyncSetupTime = Duration .between (cloudSyncStart , Instant .now ());
465+ LOGGER .info ("OptOut cloud sync setup completed in {} ms" , cloudSyncSetupTime .toMillis ());
466+ recordPhaseTime ("optout_cloud_sync_setup" , cloudSyncSetupTime );
428467
468+ // Time the rotating store verticles deployment
469+ Instant rotatingStoresStart = Instant .now ();
470+ LOGGER .info ("Starting rotating store verticles deployment" );
471+
429472 // create rotating store verticles to poll for updates
430473 Promise <Void > promise = Promise .promise ();
431474 List <Future > fs = new ArrayList <>();
@@ -454,7 +497,12 @@ private Future<Void> createStoreVerticles() throws Exception {
454497 fs .add (createAndDeployCloudSyncStoreVerticle ("optout" , fsOptOut , optOutCloudSync ));
455498 CompositeFuture .all (fs ).onComplete (ar -> {
456499 if (ar .failed ()) promise .fail (new Exception (ar .cause ()));
457- else promise .complete ();
500+ else {
501+ Duration rotatingStoresTime = Duration .between (rotatingStoresStart , Instant .now ());
502+ LOGGER .info ("Rotating store verticles deployment completed in {} ms" , rotatingStoresTime .toMillis ());
503+ recordPhaseTime ("rotating_store_verticles_deployment" , rotatingStoresTime );
504+ promise .complete ();
505+ }
458506 });
459507
460508
0 commit comments