Include service instance id and binding id in INFO level log messages

This commit updates the logging calls in ServiceInstanceController and
ServiceInstanceBindingController to include the serviceInstanceId and
bindingId at the INFO log level.

Closes #434

spring-cloud-open-service-broker-autoconfigure/src/test/java/org/springframework/cloud/servicebroker/autoconfigure/web/reactive/ServiceInstanceBindingControllerIntegrationTest.java

@@ -21,6 +21,8 @@
 import org.junit.jupiter.api.extension.ExtendWith;
 import org.mockito.junit.jupiter.MockitoExtension;
 
+import org.springframework.boot.test.system.CapturedOutput;
+import org.springframework.boot.test.system.OutputCaptureExtension;
 import org.springframework.cloud.servicebroker.autoconfigure.web.AbstractServiceInstanceBindingControllerIntegrationTest;
 import org.springframework.cloud.servicebroker.controller.ServiceBrokerWebFluxExceptionHandler;
 import org.springframework.cloud.servicebroker.exception.ServiceBrokerCreateOperationInProgressException;
@@ -53,6 +55,7 @@
 import static org.springframework.cloud.servicebroker.model.ServiceBrokerRequest.ORIGINATING_IDENTITY_HEADER;
 
 @ExtendWith(MockitoExtension.class)
+@ExtendWith(OutputCaptureExtension.class)
 class ServiceInstanceBindingControllerIntegrationTest extends AbstractServiceInstanceBindingControllerIntegrationTest {
 
 	private WebTestClient client;
@@ -65,7 +68,7 @@ void setUp() {
 	}
 
 	@Test
-	void createBindingToAppWithoutAsyncAndHeadersSucceeds() throws Exception {
+	void createBindingToAppWithoutAsyncAndHeadersSucceeds(CapturedOutput output) throws Exception {
 		setupCatalogService();
 
 		setupServiceInstanceBindingService(CreateServiceInstanceAppBindingResponse.builder()
@@ -83,6 +86,11 @@ void createBindingToAppWithoutAsyncAndHeadersSucceeds() throws Exception {
 
 		CreateServiceInstanceBindingRequest actualRequest = verifyCreateBinding();
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Creating service instance binding: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
+		assertThat(output.getOut()).contains("Creating service instance binding succeeded: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
 	}
 
 	@Test
@@ -343,7 +351,7 @@ void createBindingWithMissingFieldsFails() {
 	}
 
 	@Test
-	void getBindingToAppSucceeds() throws Exception {
+	void getBindingToAppSucceeds(CapturedOutput output) throws Exception {
 		setupServiceInstanceBindingService(GetServiceInstanceAppBindingResponse.builder()
 				.build());
 
@@ -356,6 +364,11 @@ void getBindingToAppSucceeds() throws Exception {
 
 		GetServiceInstanceBindingRequest actualRequest = verifyGetBinding();
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Getting service instance binding: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
+		assertThat(output.getOut()).contains("Getting service instance binding succeeded: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
 	}
 
 	@Test
@@ -402,7 +415,7 @@ void getBindingWithOperationInProgressFails() {
 	}
 
 	@Test
-	void deleteBindingWithoutAsyncAndHeadersSucceeds() throws Exception {
+	void deleteBindingWithoutAsyncAndHeadersSucceeds(CapturedOutput output) throws Exception {
 		setupCatalogService();
 
 		setupServiceInstanceBindingService(DeleteServiceInstanceBindingResponse.builder()
@@ -424,6 +437,11 @@ void deleteBindingWithoutAsyncAndHeadersSucceeds() throws Exception {
 		DeleteServiceInstanceBindingRequest actualRequest = verifyDeleteBinding();
 		assertThat(actualRequest.isAsyncAccepted()).isEqualTo(false);
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Deleting service instance binding: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
+		assertThat(output.getOut()).contains("Deleting service instance binding succeeded: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
 	}
 
 	@Test
@@ -570,7 +588,7 @@ void lastOperationHasInProgressStatus() {
 	}
 
 	@Test
-	void lastOperationHasSucceededStatus() throws Exception {
+	void lastOperationHasSucceededStatus(CapturedOutput output) throws Exception {
 		setupServiceInstanceBindingService(GetLastServiceBindingOperationResponse.builder()
 				.operationState(OperationState.SUCCEEDED)
 				.description("all good")
@@ -591,6 +609,11 @@ void lastOperationHasSucceededStatus() throws Exception {
 
 		GetLastServiceBindingOperationRequest actualRequest = verifyLastOperation();
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Getting last operation for service instance binding: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
+		assertThat(output.getOut()).contains("Getting last operation for service instance binding succeeded: " +
+				"serviceInstanceId=" + SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
 	}
 
 	@Test

spring-cloud-open-service-broker-autoconfigure/src/test/java/org/springframework/cloud/servicebroker/autoconfigure/web/reactive/ServiceInstanceControllerIntegrationTest.java

@@ -25,6 +25,8 @@
 import org.junit.jupiter.api.extension.ExtendWith;
 import org.mockito.junit.jupiter.MockitoExtension;
 
+import org.springframework.boot.test.system.CapturedOutput;
+import org.springframework.boot.test.system.OutputCaptureExtension;
 import org.springframework.cloud.servicebroker.autoconfigure.web.AbstractServiceInstanceControllerIntegrationTest;
 import org.springframework.cloud.servicebroker.controller.ServiceBrokerWebFluxExceptionHandler;
 import org.springframework.cloud.servicebroker.exception.ServiceBrokerAsyncRequiredException;
@@ -61,6 +63,7 @@
 import static org.springframework.cloud.servicebroker.model.ServiceBrokerRequest.ORIGINATING_IDENTITY_HEADER;
 
 @ExtendWith(MockitoExtension.class)
+@ExtendWith(OutputCaptureExtension.class)
 class ServiceInstanceControllerIntegrationTest extends AbstractServiceInstanceControllerIntegrationTest {
 
 	private WebTestClient client;
@@ -73,7 +76,7 @@ void setUp() {
 	}
 
 	@Test
-	void createServiceInstanceWithAsyncAndHeadersSucceeds() throws Exception {
+	void createServiceInstanceWithAsyncAndHeadersSucceeds(CapturedOutput output) throws Exception {
 		setupCatalogService();
 
 		setupServiceInstanceService(CreateServiceInstanceResponse.builder()
@@ -92,6 +95,9 @@ void createServiceInstanceWithAsyncAndHeadersSucceeds() throws Exception {
 		CreateServiceInstanceRequest actualRequest = verifyCreateServiceInstance();
 		assertThat(actualRequest.isAsyncAccepted()).isEqualTo(true);
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Creating service instance: serviceInstanceId=" + SERVICE_INSTANCE_ID);
+		assertThat(output.getOut()).contains("Creating service instance succeeded: serviceInstanceId=" + SERVICE_INSTANCE_ID);
 	}
 
 	@Test
@@ -464,7 +470,7 @@ void createServiceInstanceWithEmptyBodyAndMismatchedContentTypeFails() throws Ex
 	}
 
 	@Test
-	void getServiceInstanceSucceeds() throws Exception {
+	void getServiceInstanceSucceeds(CapturedOutput output) throws Exception {
 		setupServiceInstanceService(GetServiceInstanceResponse.builder()
 				.build());
 
@@ -477,6 +483,9 @@ void getServiceInstanceSucceeds() throws Exception {
 
 		GetServiceInstanceRequest actualRequest = verifyGetServiceInstance();
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Getting service instance: serviceInstanceId=" + SERVICE_INSTANCE_ID);
+		assertThat(output.getOut()).contains("Getting service instance succeeded: serviceInstanceId=" + SERVICE_INSTANCE_ID);
 	}
 
 	@Test
@@ -510,7 +519,7 @@ void getServiceInstanceWithOperationInProgressFails() throws Exception {
 	}
 
 	@Test
-	void deleteServiceInstanceWithAsyncAndHeadersSucceeds() throws Exception {
+	void deleteServiceInstanceWithAsyncAndHeadersSucceeds(CapturedOutput output) throws Exception {
 		setupCatalogService();
 
 		setupServiceInstanceService(DeleteServiceInstanceResponse.builder()
@@ -530,6 +539,9 @@ void deleteServiceInstanceWithAsyncAndHeadersSucceeds() throws Exception {
 		DeleteServiceInstanceRequest actualRequest = verifyDeleteServiceInstance();
 		assertThat(actualRequest.isAsyncAccepted()).isEqualTo(true);
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Deleting service instance: serviceInstanceId=" + SERVICE_INSTANCE_ID);
+		assertThat(output.getOut()).contains("Deleting service instance succeeded: serviceInstanceId=" + SERVICE_INSTANCE_ID);
 	}
 
 	@Test
@@ -632,7 +644,7 @@ void deleteServiceInstanceWithMissingQueryParamsFails() {
 	}
 
 	@Test
-	void updateServiceInstanceWithAsyncAndHeadersSucceeds() throws Exception {
+	void updateServiceInstanceWithAsyncAndHeadersSucceeds(CapturedOutput output) throws Exception {
 		setupCatalogService();
 
 		setupServiceInstanceService(UpdateServiceInstanceResponse.builder()
@@ -656,6 +668,9 @@ void updateServiceInstanceWithAsyncAndHeadersSucceeds() throws Exception {
 		UpdateServiceInstanceRequest actualRequest = verifyUpdateServiceInstance();
 		assertThat(actualRequest.isAsyncAccepted()).isEqualTo(true);
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Updating service instance: serviceInstanceId=" + SERVICE_INSTANCE_ID);
+		assertThat(output.getOut()).contains("Updating service instance succeeded: serviceInstanceId=" + SERVICE_INSTANCE_ID);
 	}
 
 	@Test
@@ -818,7 +833,7 @@ void lastOperationHasInProgressStatus() {
 	}
 
 	@Test
-	void lastOperationHasSucceededStatus() throws Exception {
+	void lastOperationHasSucceededStatus(CapturedOutput output) throws Exception {
 		setupServiceInstanceService(GetLastServiceOperationResponse.builder()
 				.operationState(OperationState.SUCCEEDED)
 				.description("all good")
@@ -835,6 +850,10 @@ void lastOperationHasSucceededStatus() throws Exception {
 
 		GetLastServiceOperationRequest actualRequest = verifyLastOperation();
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Getting last operation for service instance: serviceInstanceId=" + SERVICE_INSTANCE_ID);
+		assertThat(output.getOut()).contains("Getting last operation for service instance succeeded: " +
+				"serviceInstanceId=" + SERVICE_INSTANCE_ID);
 	}
 
 	@Test

spring-cloud-open-service-broker-autoconfigure/src/test/java/org/springframework/cloud/servicebroker/autoconfigure/web/servlet/ServiceInstanceBindingControllerIntegrationTest.java

@@ -21,6 +21,8 @@
 import org.junit.jupiter.api.extension.ExtendWith;
 import org.mockito.junit.jupiter.MockitoExtension;
 
+import org.springframework.boot.test.system.CapturedOutput;
+import org.springframework.boot.test.system.OutputCaptureExtension;
 import org.springframework.cloud.servicebroker.autoconfigure.web.AbstractServiceInstanceBindingControllerIntegrationTest;
 import org.springframework.cloud.servicebroker.controller.ServiceBrokerWebMvcExceptionHandler;
 import org.springframework.cloud.servicebroker.exception.ServiceBrokerCreateOperationInProgressException;
@@ -66,6 +68,7 @@
 import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.status;
 
 @ExtendWith(MockitoExtension.class)
+@ExtendWith(OutputCaptureExtension.class)
 class ServiceInstanceBindingControllerIntegrationTest extends AbstractServiceInstanceBindingControllerIntegrationTest {
 
 	private MockMvc mockMvc;
@@ -78,7 +81,7 @@ void setUp() {
 	}
 
 	@Test
-	void createBindingToAppWithoutAsyncAndHeadersSucceeds() throws Exception {
+	void createBindingToAppWithoutAsyncAndHeadersSucceeds(CapturedOutput output) throws Exception {
 		setupCatalogService();
 
 		setupServiceInstanceBindingService(CreateServiceInstanceAppBindingResponse.builder()
@@ -100,6 +103,11 @@ void createBindingToAppWithoutAsyncAndHeadersSucceeds() throws Exception {
 		CreateServiceInstanceBindingRequest actualRequest = verifyCreateBinding();
 		assertThat(actualRequest.isAsyncAccepted()).isEqualTo(false);
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Creating service instance binding: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
+		assertThat(output.getOut()).contains("Creating service instance binding succeeded: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
 	}
 
 	@Test
@@ -359,7 +367,7 @@ void createBindingWithMissingFieldsFails() throws Exception {
 	}
 
 	@Test
-	void getBindingToAppSucceeds() throws Exception {
+	void getBindingToAppSucceeds(CapturedOutput output) throws Exception {
 		setupServiceInstanceBindingService(GetServiceInstanceAppBindingResponse.builder()
 				.build());
 
@@ -376,6 +384,11 @@ void getBindingToAppSucceeds() throws Exception {
 
 		GetServiceInstanceBindingRequest actualRequest = verifyGetBinding();
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Getting service instance binding: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
+		assertThat(output.getOut()).contains("Getting service instance binding succeeded: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
 	}
 
 	@Test
@@ -434,7 +447,7 @@ void getBindingWithOperationInProgressFails() throws Exception {
 	}
 
 	@Test
-	void deleteBindingWithoutAsyncAndHeadersSucceeds() throws Exception {
+	void deleteBindingWithoutAsyncAndHeadersSucceeds(CapturedOutput output) throws Exception {
 		setupCatalogService();
 
 		setupServiceInstanceBindingService(DeleteServiceInstanceBindingResponse.builder()
@@ -459,6 +472,11 @@ void deleteBindingWithoutAsyncAndHeadersSucceeds() throws Exception {
 		DeleteServiceInstanceBindingRequest actualRequest = verifyDeleteBinding();
 		assertThat(actualRequest.isAsyncAccepted()).isEqualTo(false);
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Deleting service instance binding: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
+		assertThat(output.getOut()).contains("Deleting service instance binding succeeded: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
 	}
 
 	@Test
@@ -630,7 +648,7 @@ void lastOperationHasInProgressStatus() throws Exception {
 	}
 
 	@Test
-	void lastOperationHasSucceededStatus() throws Exception {
+	void lastOperationHasSucceededStatus(CapturedOutput output) throws Exception {
 		setupServiceInstanceBindingService(GetLastServiceBindingOperationResponse.builder()
 				.operationState(OperationState.SUCCEEDED)
 				.description("all good")
@@ -650,6 +668,12 @@ void lastOperationHasSucceededStatus() throws Exception {
 
 		GetLastServiceBindingOperationRequest actualRequest = verifyLastOperation();
 		assertHeaderValuesSet(actualRequest);
+
+		assertThat(output.getOut()).contains("Getting last operation for service instance binding: serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
+		assertThat(output.getOut()).contains("Getting last operation for service instance binding succeeded: " +
+				"serviceInstanceId="
+				+ SERVICE_INSTANCE_ID + ", bindingId=" + SERVICE_INSTANCE_BINDING_ID);
 	}
 
 	@Test