Increasing default timeout

Improving logging

spring-cloud-app-broker-core/src/main/java/org/springframework/cloud/appbroker/deployer/DeployerClient.java

@@ -33,13 +33,15 @@ public class DeployerClient {
 	}
 
 	Mono<String> deploy(BackingApplication backingApplication) {
-		return appDeployer.deploy(DeployApplicationRequest.builder()
-			.name(backingApplication.getName())
-			.path(backingApplication.getPath())
-			.properties(backingApplication.getProperties())
-			.environment(backingApplication.getEnvironment())
-			.services(backingApplication.getServices().stream().map(ServicesSpec::getServiceInstanceName).collect(Collectors.toList()))
-			.build())
+		return appDeployer
+			.deploy(DeployApplicationRequest
+				.builder()
+				.name(backingApplication.getName())
+				.path(backingApplication.getPath())
+				.properties(backingApplication.getProperties())
+				.environment(backingApplication.getEnvironment())
+				.services(backingApplication.getServices().stream().map(ServicesSpec::getServiceInstanceName).collect(Collectors.toList()))
+				.build())
 			.doOnRequest(l -> log.debug("Deploying application {}", backingApplication))
 			.doOnSuccess(response -> log.debug("Finished deploying application {}", backingApplication))
 			.doOnError(exception -> log.error("Error deploying application {} with error '{}'",
@@ -48,36 +50,46 @@ public class DeployerClient {
 	}
 
 	Mono<String> update(BackingApplication backingApplication) {
-		return appDeployer.update(UpdateApplicationRequest.builder()
-			.name(backingApplication.getName())
-			.path(backingApplication.getPath())
-			.properties(backingApplication.getProperties())
-			.environment(backingApplication.getEnvironment())
-			.services(backingApplication.getServices().stream().map(ServicesSpec::getServiceInstanceName).collect(Collectors.toList()))
-			.build())
-			.doOnRequest(l -> log.debug("Deploying application {}", backingApplication))
+		return appDeployer
+			.update(UpdateApplicationRequest
+				.builder()
+				.name(backingApplication.getName())
+				.path(backingApplication.getPath())
+				.properties(backingApplication.getProperties())
+				.environment(backingApplication.getEnvironment())
+				.services(backingApplication.getServices().stream().map(ServicesSpec::getServiceInstanceName).collect(Collectors.toList()))
+				.build())
+			.doOnRequest(l -> log.debug("Updating application {}", backingApplication))
 			.doOnSuccess(response -> log.debug("Finished updating application {}", backingApplication))
 			.doOnError(exception -> log.error("Error updating application {} with error {}", backingApplication, exception))
 			.map(UpdateApplicationResponse::getName);
 	}
 
 	Mono<String> undeploy(BackingApplication backingApplication) {
-		return appDeployer.undeploy(UndeployApplicationRequest.builder()
-			.properties(backingApplication.getProperties())
-			.name(backingApplication.getName())
-			.build())
+		return appDeployer
+			.undeploy(UndeployApplicationRequest
+				.builder()
+				.properties(backingApplication.getProperties())
+				.name(backingApplication.getName())
+				.build())
+			.doOnRequest(l -> log.debug("Undeploying application {}", backingApplication))
+			.doOnSuccess(response -> log.debug("Finished undeploying application {}", backingApplication))
+			.doOnError(exception -> log.error("Error undeploying application {} with error '{}'",
+				backingApplication, exception.getMessage()))
 			.map(UndeployApplicationResponse::getName);
 	}
 
 	Mono<String> createServiceInstance(BackingService backingService) {
-		return appDeployer.createServiceInstance(
-			CreateServiceInstanceRequest.builder()
-				.serviceInstanceName(backingService.getServiceInstanceName())
-				.name(backingService.getName())
-				.plan(backingService.getPlan())
-				.parameters(backingService.getParameters())
-				.properties(backingService.getProperties())
-				.build())
+		return appDeployer
+			.createServiceInstance(
+				CreateServiceInstanceRequest
+					.builder()
+					.serviceInstanceName(backingService.getServiceInstanceName())
+					.name(backingService.getName())
+					.plan(backingService.getPlan())
+					.parameters(backingService.getParameters())
+					.properties(backingService.getProperties())
+					.build())
 			.doOnRequest(l -> log.debug("Creating backing service {}", backingService.getName()))
 			.doOnSuccess(response -> log.debug("Finished creating backing service {}", backingService.getName()))
 			.doOnError(exception -> log.error("Error creating backing service {} with error '{}'",
@@ -86,26 +98,35 @@ public class DeployerClient {
 	}
 
 	Mono<String> updateServiceInstance(BackingService backingService) {
-		return appDeployer.updateServiceInstance(
-			UpdateServiceInstanceRequest.builder()
-				.serviceInstanceName(backingService.getServiceInstanceName())
-				.parameters(backingService.getParameters())
-				.properties(backingService.getProperties())
-				.rebindOnUpdate(backingService.isRebindOnUpdate())
-				.build())
-			.doOnRequest(l -> log.debug("Creating backing service {}", backingService.getName()))
-			.doOnSuccess(response -> log.debug("Finished creating backing service {}", backingService.getName()))
-			.doOnError(exception -> log.error("Error creating backing service {} with error '{}'",
+		return appDeployer
+			.updateServiceInstance(
+				UpdateServiceInstanceRequest
+					.builder()
+					.serviceInstanceName(backingService.getServiceInstanceName())
+					.parameters(backingService.getParameters())
+					.properties(backingService.getProperties())
+					.rebindOnUpdate(backingService.isRebindOnUpdate())
+					.build())
+			.doOnRequest(l -> log.debug("Updating backing service {}", backingService.getName()))
+			.doOnSuccess(response -> log.debug("Finished updating backing service {}", backingService.getName()))
+			.doOnError(exception -> log.error("Error updating backing service {} with error '{}'",
 				backingService.getName(), exception.getMessage()))
 			.map(UpdateServiceInstanceResponse::getName);
 	}
 
 	Mono<String> deleteServiceInstance(BackingService backingService) {
-		return appDeployer.deleteServiceInstance(
-			DeleteServiceInstanceRequest.builder()
-				.serviceInstanceName(backingService.getServiceInstanceName())
-				.properties(backingService.getProperties())
-				.build())
+		return appDeployer
+			.deleteServiceInstance(
+				DeleteServiceInstanceRequest
+					.builder()
+					.serviceInstanceName(backingService.getServiceInstanceName())
+					.properties(backingService.getProperties())
+					.build())
+
+			.doOnRequest(l -> log.debug("Deleting backing service {}", backingService.getName()))
+			.doOnSuccess(response -> log.debug("Finished deleting backing service {}", backingService.getName()))
+			.doOnError(exception -> log.error("Error deleting backing service {} with error '{}'",
+				backingService.getName(), exception.getMessage()))
 			.map(DeleteServiceInstanceResponse::getName);
 	}
 }

spring-cloud-app-broker-deployer-cloudfoundry/src/main/java/org/springframework/cloud/appbroker/deployer/cloudfoundry/CloudFoundryAppDeployer.java

@@ -184,10 +184,12 @@ public class CloudFoundryAppDeployer implements AppDeployer, ResourceLoaderAware
 		return operations
 			.applications()
 			.get(GetApplicationRequest.builder().name(name).build())
+			.doOnRequest(l -> logger.debug("Getting application {}", name))
+			.doOnSuccess(response -> logger.info("Success getting application {}", name))
+			.doOnError(e -> logger.warn(String.format("Error getting application %s: %s", name, e.getMessage())))
 			.map(ApplicationDetail::getId)
 			.flatMap(applicationId ->
-				updateApplicationEnvironment(applicationId, environmentVariables)
-					.thenReturn(applicationId)
+				updateApplicationEnvironment(applicationId, environmentVariables).thenReturn(applicationId)
 			)
 			.flatMap(applicationId -> Mono.zip(Mono.just(applicationId),
 				createPackageForApplication(applicationId)))
@@ -221,69 +223,92 @@ public class CloudFoundryAppDeployer implements AppDeployer, ResourceLoaderAware
 			})
 			.map(CreateDeploymentResponse::getId)
 			.flatMap(this::waitForDeploymentDeployed)
+			.doOnRequest(l -> logger.debug("Updating application {}", name))
+			.doOnSuccess(item -> logger.info("Successfully updated application {}", name))
+			.doOnError(error -> logger.error("Failed to update application {}", name))
 			.thenReturn(UpdateApplicationResponse.builder().name(name).build());
 	}
 
 	private Mono<GetDeploymentResponse> waitForDeploymentDeployed(String deploymentId) {
-		return this.client.deploymentsV3()
-						  .get(GetDeploymentRequest
-							  .builder()
-							  .deploymentId(deploymentId)
-							  .build())
-						  .filter(p -> p.getState().equals(DeploymentState.DEPLOYED))
-						  .repeatWhenEmpty(getExponentialBackOff());
-	}
-
-	private Function<Flux<Long>, Publisher<?>> getExponentialBackOff() {
-		return DelayUtils.exponentialBackOff(Duration.ofSeconds(2), Duration.ofSeconds(15), Duration.ofMinutes(10));
+		return this.client
+			.deploymentsV3()
+			.get(GetDeploymentRequest
+				.builder()
+				.deploymentId(deploymentId)
+				.build())
+			.filter(p -> p.getState().equals(DeploymentState.DEPLOYED))
+			.repeatWhenEmpty(getExponentialBackOff())
+			.doOnRequest(l -> logger.debug("Waiting for deployment deployed {}", deploymentId))
+			.doOnSuccess(response -> logger.info("Deployment deployed {}", deploymentId))
+			.doOnError(e -> logger.warn(String.format("Error waiting for deployment deployed %s: %s", deploymentId, e.getMessage())));
 	}
 
 	private Mono<CreateDeploymentResponse> createDeployment(String dropletId, String applicationId) {
-		return this.client.deploymentsV3()
-						  .create(CreateDeploymentRequest
-					   .builder()
-					   .droplet(Relationship
-						   .builder()
-						   .id(dropletId).build()).relationships(DeploymentRelationships
-						   .builder()
-						   .app(ToOneRelationship
-							   .builder()
-							   .data(Relationship.builder().id(applicationId).build())
-							   .build()
-						   ).build())
-					   .build());
+		return this.client
+			.deploymentsV3()
+			.create(CreateDeploymentRequest
+				.builder()
+				.droplet(Relationship
+					.builder()
+					.id(dropletId).build()).relationships(DeploymentRelationships
+					.builder()
+					.app(ToOneRelationship
+						.builder()
+						.data(Relationship.builder().id(applicationId).build())
+						.build()
+					).build())
+				.build())
+			.doOnRequest(l -> logger.debug("Creating deployment for application {}", applicationId))
+			.doOnSuccess(response -> logger.info("Created deployment for application {}", applicationId))
+			.doOnError(e -> logger.warn(String.format("Error creating deployment for application %s: %s", applicationId, e.getMessage())));
 	}
 
 	private Mono<GetBuildResponse> waitForBuildStaged(String buildId) {
-		return this.client.builds().get(GetBuildRequest.builder().buildId(buildId).build())
-				   .filter(p -> p.getState().equals(BuildState.STAGED))
-				   .repeatWhenEmpty(getExponentialBackOff());
+		return this.client
+			.builds().get(GetBuildRequest.builder().buildId(buildId).build())
+			.filter(p -> p.getState().equals(BuildState.STAGED))
+			.repeatWhenEmpty(getExponentialBackOff())
+			.doOnRequest(l -> logger.debug("Waiting for build staged {}", buildId))
+			.doOnSuccess(response -> logger.info("Build staged {}", buildId))
+			.doOnError(e -> logger.warn(String.format("Error waiting for build staged %s: %s", buildId, e.getMessage())));
 	}
 
 	private Mono<String> createBuildForPackage(String packageId) {
-		return this.client.builds()
-						  .create(CreateBuildRequest
-							  .builder()
-							  .getPackage(Relationship.builder().id(packageId).build())
-							  .build())
-						  .map(CreateBuildResponse::getId);
+		return this.client
+			.builds()
+			.create(CreateBuildRequest
+				.builder()
+				.getPackage(Relationship.builder().id(packageId).build())
+				.build())
+			.map(CreateBuildResponse::getId)
+			.doOnRequest(l -> logger.debug("Creating build for package {}", packageId))
+			.doOnSuccess(response -> logger.info("Created build for package {}", packageId))
+			.doOnError(e -> logger.warn(String.format("Error creating build package %s: %s", packageId, e.getMessage())));
 	}
 
-	private Mono<GetPackageResponse> waitForPackageReady(String packageId1) {
-		return this.client.packages()
-				   .get(GetPackageRequest.builder().packageId(packageId1).build())
-				   .filter(p -> p.getState().equals(PackageState.READY))
-				   .repeatWhenEmpty(getExponentialBackOff());
+	private Mono<GetPackageResponse> waitForPackageReady(String packageId) {
+		return this.client
+			.packages()
+			.get(GetPackageRequest.builder().packageId(packageId).build())
+			.filter(p -> p.getState().equals(PackageState.READY))
+			.repeatWhenEmpty(getExponentialBackOff())
+			.doOnRequest(l -> logger.debug("Waiting for package ready {}", packageId))
+			.doOnSuccess(response -> logger.info("Package ready {}", packageId))
+			.doOnError(e -> logger.warn(String.format("Error waiting for package ready %s: %s", packageId, e.getMessage())));
 	}
 
 	private Mono<UploadPackageResponse> uploadPackage(UpdateApplicationRequest request, String packageId) {
 		try {
-			return this.client.packages()
-							  .upload(UploadPackageRequest
-								  .builder()
-								  .packageId(packageId)
-								  .bits(Paths.get(getAppResource(request.getPath()).getURI()))
-								  .build());
+			return this.client
+				.packages()
+				.upload(UploadPackageRequest
+					.builder()
+					.packageId(packageId)
+					.bits(Paths.get(getAppResource(request.getPath()).getURI()))
+					.build())
+				.doOnRequest(l -> logger.debug("Uploading package {}", packageId))
+				.doOnSuccess(response -> logger.info("Package uploaded {}", packageId))
+				.doOnError(e -> logger.warn(String.format("Error uploading package %s: %s", packageId, e.getMessage())));
 		}
 		catch (IOException e) {
 			throw Exceptions.propagate(e);
@@ -306,17 +331,28 @@ public class CloudFoundryAppDeployer implements AppDeployer, ResourceLoaderAware
 						.build())
 					.build())
 				.type(PackageType.BITS)
-				.build());
+				.build())
+			.doOnRequest(l -> logger.debug("Creating package for application {}", applicationId))
+			.doOnSuccess(response -> logger.info("Created package for application {}", applicationId))
+			.doOnError(e -> logger.warn(String.format("Error creating package for application %s: %s", applicationId, e.getMessage())));
 	}
 
 	private Mono<org.cloudfoundry.client.v2.applications.UpdateApplicationResponse> updateApplicationEnvironment(
 		String applicationId, Map<String, Object> environmentVariables) {
-		return this.client.applicationsV2()
-						  .update(org.cloudfoundry.client.v2.applications.UpdateApplicationRequest
-							  .builder()
-							  .applicationId(applicationId)
-							  .putAllEnvironmentJsons(environmentVariables)
-							  .build());
+		return this.client
+			.applicationsV2()
+			.update(org.cloudfoundry.client.v2.applications.UpdateApplicationRequest
+				.builder()
+				.applicationId(applicationId)
+				.putAllEnvironmentJsons(environmentVariables)
+				.build())
+			.doOnRequest(l -> logger.debug("Updating environment for application {}", applicationId))
+			.doOnSuccess(response -> logger.info("Updated environment for application {}", applicationId))
+			.doOnError(e -> logger.warn(String.format("Error Updating environment for application %s: %s", applicationId, e.getMessage())));
+	}
+
+	private Function<Flux<Long>, Publisher<?>> getExponentialBackOff() {
+		return DelayUtils.exponentialBackOff(Duration.ofSeconds(2), Duration.ofMinutes(5), Duration.ofMinutes(10));
 	}
 
 	private Mono<Void> pushApplication(DeployApplicationRequest request,