diff --git a/.env.example b/.env.example index 5c9f904..03a268a 100644 --- a/.env.example +++ b/.env.example @@ -11,6 +11,11 @@ DB_RUNTIME_PASSWORD= DB_MIGRATION_USERNAME= DB_MIGRATION_PASSWORD= +# PostgreSQL Runtime Connection의 SQL 실행·lock 대기 안전선입니다. +# 0으로 비활성화할 수 없으며 lock timeout은 statement timeout보다 짧아야 합니다. +DB_STATEMENT_TIMEOUT=30s +DB_LOCK_TIMEOUT=3s + # React 개발 서버 또는 배포 Client 주소를 쉼표로 구분합니다. CORS_ALLOWED_ORIGINS=http://localhost:3000,http://localhost:5173 diff --git a/docs/development-guide.md b/docs/development-guide.md index 3d3a085..9884104 100644 --- a/docs/development-guide.md +++ b/docs/development-guide.md @@ -141,6 +141,8 @@ export DB_RUNTIME_USERNAME='제한된 애플리케이션 계정' export DB_RUNTIME_PASSWORD='로컬 Secret' export DB_MIGRATION_USERNAME='Flyway 전용 계정' export DB_MIGRATION_PASSWORD='로컬 Secret' +export DB_STATEMENT_TIMEOUT='30s' +export DB_LOCK_TIMEOUT='3s' export SPRING_PROFILES_ACTIVE=dev ./gradlew bootRun ``` @@ -151,6 +153,11 @@ export SPRING_PROFILES_ACTIVE=dev runtime 계정은 업무 DML, migration 계정은 Flyway 적용만 담당합니다. 실제 비밀번호·API Key·Token은 Git, Issue, Discussion과 로그에 올리지 않습니다. +Runtime Hikari Connection에는 기본 `statement_timeout=30s`, `lock_timeout=3s`가 +적용됩니다. 값의 검증 규칙, 적용 경계, 운영 확인 및 rollback 절차는 +[PostgreSQL Runtime Timeout 운영 가이드](reliability/postgresql-runtime-timeouts.md)를 +확인합니다. + ## 선택 사항: local Demo Seed local H2에서만 사용할 사업장과 `user_account` 더미 계정 20명이 필요할 때 @@ -254,5 +261,6 @@ Client가 안전한 형식의 `X-Request-Id`를 보내면 Server가 응답과 - [Database 문서 사용법](database-documentation.md) - [프로젝트 구조](project-structure.md) - [Transactional Outbox 운영 가이드](reliability/transactional-outbox.md) +- [PostgreSQL Runtime Timeout 운영 가이드](reliability/postgresql-runtime-timeouts.md) - [ADR 목록](adr/README.md) - [PostgreSQL RLS 적용 가이드](database/postgresql-rls-rollout.md) diff --git a/docs/reliability/postgresql-runtime-timeouts.md b/docs/reliability/postgresql-runtime-timeouts.md new file mode 100644 index 0000000..7b38556 --- /dev/null +++ b/docs/reliability/postgresql-runtime-timeouts.md @@ -0,0 +1,149 @@ +# PostgreSQL Runtime Connection Timeout 운영 가이드 + +FOWOCO Server가 생성하는 PostgreSQL Runtime Hikari Connection에는 장시간 SQL과 +lock 대기가 Connection Pool 전체 장애로 확산되지 않도록 Session 범위 안전선을 +적용합니다. + +## 설정 + +| 환경변수 | 기본값 | 의미 | +| --- | ---: | --- | +| `DB_STATEMENT_TIMEOUT` | `30s` | 개별 SQL의 최대 실행시간 | +| `DB_LOCK_TIMEOUT` | `3s` | row/table lock 획득 최대 대기시간 | + +Spring Boot `Duration` 형식을 사용합니다. `30s`, `3000ms`, `PT30S`, `1000us`를 +사용할 수 있으며 접미사가 없는 정수는 millisecond입니다. 운영에서는 혼동을 +막기 위해 단위를 명시합니다. + +두 값은 다음 조건을 모두 만족해야 합니다. + +- 0보다 크고 정확한 정수 millisecond로 표현 가능 +- `2147483647ms` 이하 +- `DB_LOCK_TIMEOUT < DB_STATEMENT_TIMEOUT` + +`1000us`는 정확히 `1ms`이므로 허용하지만 `1500us`는 millisecond 미만 remainder가 +있어 시작 단계에서 거부합니다. `0`으로 guard를 비활성화할 수 없습니다. + +## 지원하는 DataSource 구성 + +PostgreSQL mode에서는 `spring.datasource.url` 기반의 직접적인 +`jdbc:postgresql:` URL과 HikariCP만 지원합니다. URL, username, password와 선택적인 +driver는 `spring.datasource.*`를 단일 설정 원본으로 사용합니다. + +다음 구성은 중복 설정 또는 물리 Connection 초기화 보장 상실을 막기 위해 시작 +단계에서 거부합니다. + +- JNDI DataSource +- Hikari namespace의 JDBC URL, username, password, driver 중복 설정 +- Hikari `data-source-class-name`, `data-source-j-n-d-i`, `connection-init-sql` +- Hikari 이외의 명시적인 `spring.datasource.type` +- p6spy 등 wrapper/proxy JDBC URL +- `spring.datasource.connection-fetch=lazy` + +향후 DataSource proxy나 decorator를 도입하면 물리 Connection 생성 시점의 Session +초기화가 유지되는지 다시 검토해야 합니다. + +## 적용 경계 + +Runtime Pool은 새 물리 Connection을 등록하기 전에 다음과 같은 하나의 초기화 SQL을 +실행합니다. + +```sql +SELECT + pg_catalog.set_config('statement_timeout', '30000ms', false), + pg_catalog.set_config('lock_timeout', '3000ms', false) +``` + +환경변수 원문은 SQL에 들어가지 않으며 검증된 정수 millisecond만 사용합니다. +초기화 SQL이 실패한 Connection은 정상 Pool Connection으로 제공되지 않습니다. + +- PostgreSQL Runtime Hikari Connection에만 적용 +- Flyway 전용 Connection에는 미적용 +- local/test H2에는 미적용 +- 새 물리 Connection마다 한 번 실행 +- transaction 또는 checkout마다 반복 실행하지 않음 + +## Session 변경 제한 + +HikariCP는 Connection 반환 시 PostgreSQL의 모든 임의 Session parameter를 reset하지 +않습니다. Runtime production 코드에서 `SET statement_timeout`, +`SET lock_timeout` 또는 Session 범위 `set_config(..., false)`를 사용하면 다음 +요청에 변경값이 남을 수 있으므로 금지합니다. + +업무별 예외가 필요하면 별도 Issue에서 Spring Transaction 내부의 `SET LOCAL`만 +사용합니다. `SET LOCAL`은 commit 또는 rollback 후 Session 기본값으로 돌아가야 +합니다. 이번 구현에는 checkout interceptor나 Session reset proxy가 없습니다. + +## Timeout 분류와 HTTP 계약 + +PostgreSQL의 SQLState만으로 원인을 확정하지 않습니다. + +- `57014`와 canonical statement-timeout diagnostic이 함께 있으면 confirmed + statement timeout +- `55P03`과 canonical lock-timeout diagnostic이 함께 있으면 confirmed lock timeout +- SQLState만 일치하면 ambiguous cancellation 또는 lock failure +- 권한·RLS `42501`, bootstrap 인자 `22023`은 timeout이 아님 + +Confirmed timeout은 안전한 공개 오류 `503 SERVICE_TEMPORARILY_UNAVAILABLE`로 +응답합니다. `Retry-After`는 제공하지 않습니다. 복구 시점을 신뢰할 수 없기 +때문입니다. Ambiguous cancellation은 기존 `500 INTERNAL_SERVER_ERROR`를 유지합니다. + +PostgreSQL `lc_messages`가 영어가 아니면 canonical diagnostic을 확인하지 못해 실제 +timeout도 ambiguous로 처리될 수 있습니다. False positive를 막기 위한 보수적 +정책이며 confirmed metric이 과소 집계될 수 있습니다. + +Client와 Gateway는 모든 503을 자동 재시도하지 않습니다. GET처럼 본질적으로 +idempotent한 요청만 exponential backoff와 jitter로 제한적으로 재시도할 수 있습니다. +POST·PATCH 등 변경 요청은 `Idempotency-Key`로 동일 요청이 보장될 때만 재시도하며, +그렇지 않으면 자동 재시도하지 않습니다. + +## 로그와 Metric + +Confirmed 및 ambiguous 분류 로그에는 `requestId`, HTTP method, 안전한 route pattern, +classification, SQLState, exception type만 기록합니다. Raw URI, SQL, bind parameter, +PostgreSQL diagnostic message, credential, 개인정보와 stack trace는 기록하지 않습니다. +상세 원인은 request ID와 발생 시각을 기준으로 PostgreSQL 서버 로그에서 조사합니다. + +Confirmed HTTP timeout은 다음 low-cardinality counter에 집계합니다. + +```text +fowoco.database.timeouts{type="statement"} +fowoco.database.timeouts{type="lock"} +``` + +Ambiguous cancellation과 Background Outbox failure는 이 metric 범위가 아닙니다. +DB Transaction과 metric 증가는 원자적이지 않으므로 사건당 exactly-once 집계를 +보장하지 않습니다. Outbox의 retry, backoff, `maxAttempts`와 기존 metric 정책은 +변경하지 않습니다. + +## 설정 변경과 관측 + +```text +환경변수 변경 +→ 애플리케이션 전체 재시작 +→ 새 Runtime Pool 생성 +→ current_setting 확인 +→ metric과 정상 Query 관측 +``` + +기존 물리 Connection에는 환경변수 변경이 즉시 반영되지 않습니다. Staging에서는 +confirmed timeout 횟수, 정상 Query 실행시간, Pool 사용량과 Outbox 지연을 함께 +확인합니다. + +정상 workload가 반복해서 timeout되면 다음 순서로 대응합니다. + +1. Query와 index 개선 +2. Transaction 범위 축소 +3. workload 분리 +4. 후속 Issue에서 `SET LOCAL` override 검토 +5. 승인 후 전역 기본값 조정 + +전역값 상향을 첫 대응으로 사용하지 않습니다. + +## Rollback + +문제가 발생하면 이전 애플리케이션 버전을 재배포하고 Runtime Pool 전체를 +재생성한 뒤 Session 적용값을 확인합니다. `ALTER ROLE`, `ALTER DATABASE` 또는 +timeout `0` 설정으로 우회하지 않습니다. + +실제 배포 환경변수, Runtime/Flyway credential과 Secret 연결은 Issue #9의 범위입니다. diff --git a/src/main/java/com/fowoco/server/common/database/DatabaseTimeoutMetrics.java b/src/main/java/com/fowoco/server/common/database/DatabaseTimeoutMetrics.java new file mode 100644 index 0000000..6c58dfc --- /dev/null +++ b/src/main/java/com/fowoco/server/common/database/DatabaseTimeoutMetrics.java @@ -0,0 +1,34 @@ +package com.fowoco.server.common.database; + +import io.micrometer.core.instrument.Counter; +import io.micrometer.core.instrument.MeterRegistry; +import org.springframework.stereotype.Component; + +@Component +public class DatabaseTimeoutMetrics { + + private final Counter statementTimeouts; + private final Counter lockTimeouts; + + public DatabaseTimeoutMetrics(MeterRegistry meterRegistry) { + statementTimeouts = timeoutCounter(meterRegistry, "statement"); + lockTimeouts = timeoutCounter(meterRegistry, "lock"); + } + + public void recordConfirmed(DatabaseTimeoutType type) { + switch (type) { + case CONFIRMED_STATEMENT_TIMEOUT -> statementTimeouts.increment(); + case CONFIRMED_LOCK_TIMEOUT -> lockTimeouts.increment(); + default -> throw new IllegalArgumentException( + "Only confirmed database timeouts can be recorded" + ); + } + } + + private Counter timeoutCounter(MeterRegistry registry, String type) { + return Counter.builder("fowoco.database.timeouts") + .description("Confirmed PostgreSQL Runtime Connection timeouts") + .tag("type", type) + .register(registry); + } +} diff --git a/src/main/java/com/fowoco/server/common/database/DatabaseTimeoutType.java b/src/main/java/com/fowoco/server/common/database/DatabaseTimeoutType.java new file mode 100644 index 0000000..6da318e --- /dev/null +++ b/src/main/java/com/fowoco/server/common/database/DatabaseTimeoutType.java @@ -0,0 +1,10 @@ +package com.fowoco.server.common.database; + +public enum DatabaseTimeoutType { + CONFIRMED_STATEMENT_TIMEOUT, + CONFIRMED_LOCK_TIMEOUT, + AMBIGUOUS_QUERY_CANCELED, + AMBIGUOUS_LOCK_NOT_AVAILABLE, + OTHER_DATABASE_FAILURE, + NOT_DATABASE_FAILURE +} diff --git a/src/main/java/com/fowoco/server/common/database/PostgreSqlRuntimeDataSourceConfiguration.java b/src/main/java/com/fowoco/server/common/database/PostgreSqlRuntimeDataSourceConfiguration.java new file mode 100644 index 0000000..8d92153 --- /dev/null +++ b/src/main/java/com/fowoco/server/common/database/PostgreSqlRuntimeDataSourceConfiguration.java @@ -0,0 +1,166 @@ +package com.fowoco.server.common.database; + +import com.zaxxer.hikari.HikariConfig; +import com.zaxxer.hikari.HikariDataSource; +import java.util.List; +import javax.sql.DataSource; +import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty; +import org.springframework.boot.context.properties.ConfigurationProperties; +import org.springframework.boot.context.properties.EnableConfigurationProperties; +import org.springframework.boot.jdbc.autoconfigure.DataSourceProperties; +import org.springframework.context.annotation.Bean; +import org.springframework.context.annotation.Configuration; +import org.springframework.context.annotation.Primary; +import org.springframework.core.env.Environment; +import org.springframework.util.StringUtils; + +@Configuration(proxyBeanMethods = false) +@ConditionalOnProperty( + name = "app.database.tenant-context-mode", + havingValue = "postgresql" +) +@EnableConfigurationProperties(RuntimeDatabaseTimeoutProperties.class) +public class PostgreSqlRuntimeDataSourceConfiguration { + + private static final String RUNTIME_TIMEOUT_SOURCE = + "app.database.runtime-timeout.*"; + private static final List UNSUPPORTED_PROPERTIES = List.of( + "spring.datasource.jndi-name", + "spring.datasource.hikari.jdbc-url", + "spring.datasource.hikari.username", + "spring.datasource.hikari.password", + "spring.datasource.hikari.driver-class-name", + "spring.datasource.hikari.data-source-class-name", + "spring.datasource.hikari.data-source-j-n-d-i", + "spring.datasource.hikari.connection-init-sql" + ); + + @Bean + @ConfigurationProperties("spring.datasource.hikari") + public HikariConfig postgreSqlRuntimeHikariConfig() { + return new HikariConfig(); + } + + @Bean(name = "dataSource") + @Primary + public HikariDataSource dataSource( + DataSourceProperties dataSourceProperties, + HikariConfig postgreSqlRuntimeHikariConfig, + RuntimeDatabaseTimeoutProperties timeoutProperties, + Environment environment + ) { + validateSupportedConfiguration( + dataSourceProperties, + postgreSqlRuntimeHikariConfig, + environment + ); + + String jdbcUrl = dataSourceProperties.determineUrl(); + if (!jdbcUrl.startsWith("jdbc:postgresql:")) { + throw unsupported( + "spring.datasource.url", + "a direct jdbc:postgresql: URL" + ); + } + + postgreSqlRuntimeHikariConfig.setJdbcUrl(jdbcUrl); + postgreSqlRuntimeHikariConfig.setUsername( + dataSourceProperties.determineUsername() + ); + postgreSqlRuntimeHikariConfig.setPassword( + dataSourceProperties.determinePassword() + ); + String driverClassName = dataSourceProperties.determineDriverClassName(); + if (StringUtils.hasText(driverClassName)) { + postgreSqlRuntimeHikariConfig.setDriverClassName(driverClassName); + } + postgreSqlRuntimeHikariConfig.setConnectionInitSql( + connectionInitSql(timeoutProperties) + ); + postgreSqlRuntimeHikariConfig.validate(); + return new HikariDataSource(postgreSqlRuntimeHikariConfig); + } + + static String connectionInitSql(RuntimeDatabaseTimeoutProperties properties) { + return "SELECT " + + "pg_catalog.set_config('statement_timeout', '" + + properties.statementTimeoutMillis() + + "ms', false), " + + "pg_catalog.set_config('lock_timeout', '" + + properties.lockTimeoutMillis() + + "ms', false)"; + } + + private static void validateSupportedConfiguration( + DataSourceProperties dataSourceProperties, + HikariConfig hikariConfig, + Environment environment + ) { + for (String property : UNSUPPORTED_PROPERTIES) { + if (environment.containsProperty(property)) { + throw unsupported(property, "spring.datasource.* URL-based configuration"); + } + } + if (dataSourceProperties.getJndiName() != null) { + throw unsupported( + "spring.datasource.jndi-name", + "spring.datasource.* URL-based configuration" + ); + } + + rejectBoundValue(hikariConfig.getJdbcUrl(), "spring.datasource.hikari.jdbc-url"); + rejectBoundValue(hikariConfig.getUsername(), "spring.datasource.hikari.username"); + rejectBoundValue(hikariConfig.getPassword(), "spring.datasource.hikari.password"); + rejectBoundValue( + hikariConfig.getDriverClassName(), + "spring.datasource.hikari.driver-class-name" + ); + rejectBoundValue( + hikariConfig.getDataSourceClassName(), + "spring.datasource.hikari.data-source-class-name" + ); + rejectBoundValue( + hikariConfig.getDataSourceJNDI(), + "spring.datasource.hikari.data-source-j-n-d-i" + ); + rejectBoundValue( + hikariConfig.getConnectionInitSql(), + "spring.datasource.hikari.connection-init-sql" + ); + + Class type = dataSourceProperties.getType(); + if (type != null && !HikariDataSource.class.isAssignableFrom(type)) { + throw unsupported("spring.datasource.type", HikariDataSource.class.getName()); + } + + String connectionFetch = environment.getProperty( + "spring.datasource.connection-fetch" + ); + if ("lazy".equalsIgnoreCase(connectionFetch)) { + throw unsupported( + "spring.datasource.connection-fetch", + "eager Runtime Hikari connection creation" + ); + } + } + + private static void rejectBoundValue(String value, String property) { + if (value != null) { + throw unsupported(property, "spring.datasource.* URL-based configuration"); + } + } + + private static IllegalStateException unsupported( + String property, + String supportedPath + ) { + return new IllegalStateException( + "Unsupported PostgreSQL Runtime DataSource property '" + + property + + "'. Use " + + supportedPath + + "; Runtime timeout values must come only from " + + RUNTIME_TIMEOUT_SOURCE + ); + } +} diff --git a/src/main/java/com/fowoco/server/common/database/PostgreSqlTimeoutClassification.java b/src/main/java/com/fowoco/server/common/database/PostgreSqlTimeoutClassification.java new file mode 100644 index 0000000..6f366fa --- /dev/null +++ b/src/main/java/com/fowoco/server/common/database/PostgreSqlTimeoutClassification.java @@ -0,0 +1,8 @@ +package com.fowoco.server.common.database; + +public record PostgreSqlTimeoutClassification( + DatabaseTimeoutType type, + String sqlState, + String exceptionType +) { +} diff --git a/src/main/java/com/fowoco/server/common/database/PostgreSqlTimeoutClassifier.java b/src/main/java/com/fowoco/server/common/database/PostgreSqlTimeoutClassifier.java new file mode 100644 index 0000000..2d60d29 --- /dev/null +++ b/src/main/java/com/fowoco/server/common/database/PostgreSqlTimeoutClassifier.java @@ -0,0 +1,125 @@ +package com.fowoco.server.common.database; + +import java.sql.SQLException; +import java.util.ArrayDeque; +import java.util.Collections; +import java.util.IdentityHashMap; +import java.util.Queue; +import java.util.Set; +import org.springframework.stereotype.Component; + +@Component +public class PostgreSqlTimeoutClassifier { + + static final String QUERY_CANCELED_SQL_STATE = "57014"; + static final String LOCK_NOT_AVAILABLE_SQL_STATE = "55P03"; + static final String STATEMENT_TIMEOUT_DIAGNOSTIC = + "canceling statement due to statement timeout"; + static final String LOCK_TIMEOUT_DIAGNOSTIC = + "canceling statement due to lock timeout"; + + public PostgreSqlTimeoutClassification classify(Throwable failure) { + if (failure == null) { + return notDatabaseFailure(); + } + + Queue queue = new ArrayDeque<>(); + Set visited = Collections.newSetFromMap(new IdentityHashMap<>()); + PostgreSqlTimeoutClassification ambiguousQueryCanceled = null; + PostgreSqlTimeoutClassification ambiguousLockNotAvailable = null; + PostgreSqlTimeoutClassification otherDatabaseFailure = null; + queue.add(failure); + + while (!queue.isEmpty()) { + Throwable candidate = queue.remove(); + if (!visited.add(candidate)) { + continue; + } + + if (candidate instanceof SQLException sqlException) { + PostgreSqlTimeoutClassification classification = classify(sqlException); + if (isConfirmed(classification.type())) { + return classification; + } + if (classification.type() + == DatabaseTimeoutType.AMBIGUOUS_QUERY_CANCELED + && ambiguousQueryCanceled == null) { + ambiguousQueryCanceled = classification; + } else if (classification.type() + == DatabaseTimeoutType.AMBIGUOUS_LOCK_NOT_AVAILABLE + && ambiguousLockNotAvailable == null) { + ambiguousLockNotAvailable = classification; + } else if (classification.type() + == DatabaseTimeoutType.OTHER_DATABASE_FAILURE + && otherDatabaseFailure == null) { + otherDatabaseFailure = classification; + } + } + + if (candidate.getCause() != null) { + queue.add(candidate.getCause()); + } + if (candidate instanceof SQLException sqlException + && sqlException.getNextException() != null) { + queue.add(sqlException.getNextException()); + } + } + + if (ambiguousQueryCanceled != null) { + return ambiguousQueryCanceled; + } + if (ambiguousLockNotAvailable != null) { + return ambiguousLockNotAvailable; + } + if (otherDatabaseFailure != null) { + return otherDatabaseFailure; + } + return notDatabaseFailure(); + } + + private PostgreSqlTimeoutClassification classify(SQLException exception) { + String sqlState = exception.getSQLState(); + String message = exception.getMessage(); + if (QUERY_CANCELED_SQL_STATE.equals(sqlState)) { + return classification( + message != null && message.contains(STATEMENT_TIMEOUT_DIAGNOSTIC) + ? DatabaseTimeoutType.CONFIRMED_STATEMENT_TIMEOUT + : DatabaseTimeoutType.AMBIGUOUS_QUERY_CANCELED, + exception + ); + } + if (LOCK_NOT_AVAILABLE_SQL_STATE.equals(sqlState)) { + return classification( + message != null && message.contains(LOCK_TIMEOUT_DIAGNOSTIC) + ? DatabaseTimeoutType.CONFIRMED_LOCK_TIMEOUT + : DatabaseTimeoutType.AMBIGUOUS_LOCK_NOT_AVAILABLE, + exception + ); + } + return classification(DatabaseTimeoutType.OTHER_DATABASE_FAILURE, exception); + } + + private PostgreSqlTimeoutClassification classification( + DatabaseTimeoutType type, + SQLException exception + ) { + return new PostgreSqlTimeoutClassification( + type, + exception.getSQLState(), + exception.getClass().getName() + ); + } + + private boolean isConfirmed(DatabaseTimeoutType type) { + return type == DatabaseTimeoutType.CONFIRMED_STATEMENT_TIMEOUT + || type == DatabaseTimeoutType.CONFIRMED_LOCK_TIMEOUT; + } + + private PostgreSqlTimeoutClassification notDatabaseFailure() { + return new PostgreSqlTimeoutClassification( + DatabaseTimeoutType.NOT_DATABASE_FAILURE, + null, + null + ); + } +} diff --git a/src/main/java/com/fowoco/server/common/database/RuntimeDatabaseTimeoutProperties.java b/src/main/java/com/fowoco/server/common/database/RuntimeDatabaseTimeoutProperties.java new file mode 100644 index 0000000..35440e7 --- /dev/null +++ b/src/main/java/com/fowoco/server/common/database/RuntimeDatabaseTimeoutProperties.java @@ -0,0 +1,77 @@ +package com.fowoco.server.common.database; + +import java.time.Duration; +import java.time.temporal.ChronoUnit; +import org.springframework.beans.factory.InitializingBean; +import org.springframework.boot.context.properties.ConfigurationProperties; +import org.springframework.boot.convert.DurationUnit; + +@ConfigurationProperties(prefix = "app.database.runtime-timeout") +public class RuntimeDatabaseTimeoutProperties implements InitializingBean { + + static final Duration MAX_POSTGRESQL_TIMEOUT = Duration.ofMillis(Integer.MAX_VALUE); + + @DurationUnit(ChronoUnit.MILLIS) + private Duration statementTimeout = Duration.ofSeconds(30); + @DurationUnit(ChronoUnit.MILLIS) + private Duration lockTimeout = Duration.ofSeconds(3); + private long statementTimeoutMillis = 30_000L; + private long lockTimeoutMillis = 3_000L; + + public Duration getStatementTimeout() { + return statementTimeout; + } + + public void setStatementTimeout( + @DurationUnit(ChronoUnit.MILLIS) Duration statementTimeout + ) { + this.statementTimeout = statementTimeout; + } + + public Duration getLockTimeout() { + return lockTimeout; + } + + public void setLockTimeout(@DurationUnit(ChronoUnit.MILLIS) Duration lockTimeout) { + this.lockTimeout = lockTimeout; + } + + public long statementTimeoutMillis() { + return statementTimeoutMillis; + } + + public long lockTimeoutMillis() { + return lockTimeoutMillis; + } + + @Override + public void afterPropertiesSet() { + statementTimeoutMillis = validateAndConvert(statementTimeout, "statementTimeout"); + lockTimeoutMillis = validateAndConvert(lockTimeout, "lockTimeout"); + if (lockTimeout.compareTo(statementTimeout) >= 0) { + throw new IllegalArgumentException( + "lockTimeout must be shorter than statementTimeout" + ); + } + } + + private static long validateAndConvert(Duration duration, String field) { + if (duration == null) { + throw new IllegalArgumentException(field + " must not be null"); + } + if (duration.isZero() || duration.isNegative()) { + throw new IllegalArgumentException(field + " must be positive"); + } + if (duration.getNano() % 1_000_000 != 0) { + throw new IllegalArgumentException( + field + " must be aligned to whole milliseconds" + ); + } + if (duration.compareTo(MAX_POSTGRESQL_TIMEOUT) > 0) { + throw new IllegalArgumentException( + field + " must not exceed " + Integer.MAX_VALUE + " milliseconds" + ); + } + return duration.toMillis(); + } +} diff --git a/src/main/java/com/fowoco/server/common/error/ErrorCode.java b/src/main/java/com/fowoco/server/common/error/ErrorCode.java index 9ecc68d..a48dca5 100644 --- a/src/main/java/com/fowoco/server/common/error/ErrorCode.java +++ b/src/main/java/com/fowoco/server/common/error/ErrorCode.java @@ -12,6 +12,10 @@ public enum ErrorCode implements ApiErrorCode { METHOD_NOT_ALLOWED(HttpStatus.METHOD_NOT_ALLOWED, "지원하지 않는 HTTP 메서드입니다."), NOT_ACCEPTABLE(HttpStatus.NOT_ACCEPTABLE, "요청한 응답 형식을 제공할 수 없습니다."), UNSUPPORTED_MEDIA_TYPE(HttpStatus.UNSUPPORTED_MEDIA_TYPE, "지원하지 않는 요청 형식입니다."), + SERVICE_TEMPORARILY_UNAVAILABLE( + HttpStatus.SERVICE_UNAVAILABLE, + "일시적으로 요청을 처리할 수 없습니다. 잠시 후 다시 시도해 주세요." + ), INTERNAL_SERVER_ERROR(HttpStatus.INTERNAL_SERVER_ERROR, "서버에서 요청을 처리하지 못했습니다."); private final HttpStatus status; diff --git a/src/main/java/com/fowoco/server/common/error/GlobalExceptionHandler.java b/src/main/java/com/fowoco/server/common/error/GlobalExceptionHandler.java index 83f7a83..8ad6bfc 100644 --- a/src/main/java/com/fowoco/server/common/error/GlobalExceptionHandler.java +++ b/src/main/java/com/fowoco/server/common/error/GlobalExceptionHandler.java @@ -1,5 +1,9 @@ package com.fowoco.server.common.error; +import com.fowoco.server.common.database.DatabaseTimeoutMetrics; +import com.fowoco.server.common.database.DatabaseTimeoutType; +import com.fowoco.server.common.database.PostgreSqlTimeoutClassification; +import com.fowoco.server.common.database.PostgreSqlTimeoutClassifier; import com.fowoco.server.common.web.RequestIdFilter; import jakarta.servlet.http.HttpServletRequest; import jakarta.validation.ConstraintViolationException; @@ -23,6 +27,7 @@ import org.springframework.web.bind.annotation.RestControllerAdvice; import org.springframework.web.method.annotation.HandlerMethodValidationException; import org.springframework.web.method.annotation.MethodArgumentTypeMismatchException; +import org.springframework.web.servlet.HandlerMapping; import org.springframework.web.servlet.resource.NoResourceFoundException; @RestControllerAdvice @@ -31,9 +36,17 @@ public class GlobalExceptionHandler { private static final Logger log = LoggerFactory.getLogger(GlobalExceptionHandler.class); private final Clock clock; + private final PostgreSqlTimeoutClassifier timeoutClassifier; + private final DatabaseTimeoutMetrics timeoutMetrics; - public GlobalExceptionHandler(Clock clock) { + public GlobalExceptionHandler( + Clock clock, + PostgreSqlTimeoutClassifier timeoutClassifier, + DatabaseTimeoutMetrics timeoutMetrics + ) { this.clock = clock; + this.timeoutClassifier = timeoutClassifier; + this.timeoutMetrics = timeoutMetrics; } @ExceptionHandler(ApiException.class) @@ -152,6 +165,30 @@ public ResponseEntity handleUnexpected( Exception exception, HttpServletRequest request ) { + PostgreSqlTimeoutClassification classification = + timeoutClassifier.classify(exception); + if (isConfirmed(classification.type())) { + timeoutMetrics.recordConfirmed(classification.type()); + logDatabaseFailure(request, classification, confirmedLogCode(classification.type())); + return response( + ErrorCode.SERVICE_TEMPORARILY_UNAVAILABLE, + null, + List.of(), + request, + safeRoute(request) + ); + } + if (isAmbiguous(classification.type())) { + logDatabaseFailure(request, classification, classification.type().name()); + return response( + ErrorCode.INTERNAL_SERVER_ERROR, + null, + List.of(), + request, + safeRoute(request) + ); + } + String requestId = requestId(request); log.error( "Unexpected server error: requestId={}, method={}, path={}, exceptionType={}", @@ -164,18 +201,76 @@ public ResponseEntity handleUnexpected( return response(ErrorCode.INTERNAL_SERVER_ERROR, null, List.of(), request); } + private void logDatabaseFailure( + HttpServletRequest request, + PostgreSqlTimeoutClassification classification, + String logClassification + ) { + log.warn( + "Database request failure: requestId={} method={} route={} " + + "classification={} sqlState={} exceptionType={}", + requestId(request), + request.getMethod(), + safeRoute(request), + logClassification, + classification.sqlState(), + classification.exceptionType() + ); + } + + private boolean isConfirmed(DatabaseTimeoutType type) { + return type == DatabaseTimeoutType.CONFIRMED_STATEMENT_TIMEOUT + || type == DatabaseTimeoutType.CONFIRMED_LOCK_TIMEOUT; + } + + private boolean isAmbiguous(DatabaseTimeoutType type) { + return type == DatabaseTimeoutType.AMBIGUOUS_QUERY_CANCELED + || type == DatabaseTimeoutType.AMBIGUOUS_LOCK_NOT_AVAILABLE; + } + + private String confirmedLogCode(DatabaseTimeoutType type) { + return switch (type) { + case CONFIRMED_STATEMENT_TIMEOUT -> "DATABASE_STATEMENT_TIMEOUT"; + case CONFIRMED_LOCK_TIMEOUT -> "DATABASE_LOCK_TIMEOUT"; + default -> throw new IllegalArgumentException("Confirmed timeout is required"); + }; + } + + private String safeRoute(HttpServletRequest request) { + Object route = request.getAttribute( + HandlerMapping.BEST_MATCHING_PATTERN_ATTRIBUTE + ); + return route == null ? "unknown" : route.toString(); + } + private ResponseEntity response( ApiErrorCode errorCode, String message, List fieldErrors, HttpServletRequest request + ) { + return response( + errorCode, + message, + fieldErrors, + request, + request.getRequestURI() + ); + } + + private ResponseEntity response( + ApiErrorCode errorCode, + String message, + List fieldErrors, + HttpServletRequest request, + String safePath ) { ApiErrorResponse body = new ApiErrorResponse( Instant.now(clock), errorCode.status().value(), errorCode.code(), message == null || message.isBlank() ? errorCode.defaultMessage() : message, - request.getRequestURI(), + safePath, requestId(request), fieldErrors ); diff --git a/src/main/resources/application.yaml b/src/main/resources/application.yaml index 677875f..da1541d 100644 --- a/src/main/resources/application.yaml +++ b/src/main/resources/application.yaml @@ -43,6 +43,9 @@ springdoc: app: database: tenant-context-mode: transaction-only + runtime-timeout: + statement-timeout: ${DB_STATEMENT_TIMEOUT:30s} + lock-timeout: ${DB_LOCK_TIMEOUT:3s} reliability: outbox: enabled: ${OUTBOX_ENABLED:true} diff --git a/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeDataSourceConfigurationTest.java b/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeDataSourceConfigurationTest.java new file mode 100644 index 0000000..7c6e676 --- /dev/null +++ b/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeDataSourceConfigurationTest.java @@ -0,0 +1,174 @@ +package com.fowoco.server.common.database; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatThrownBy; + +import com.zaxxer.hikari.HikariConfig; +import com.zaxxer.hikari.HikariDataSource; +import java.lang.reflect.Method; +import javax.sql.DataSource; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.ValueSource; +import org.springframework.boot.jdbc.autoconfigure.DataSourceProperties; +import org.springframework.boot.test.context.runner.ApplicationContextRunner; +import org.springframework.context.annotation.Primary; +import org.springframework.mock.env.MockEnvironment; + +class PostgreSqlRuntimeDataSourceConfigurationTest { + + private final PostgreSqlRuntimeDataSourceConfiguration configuration = + new PostgreSqlRuntimeDataSourceConfiguration(); + + @Test + void createsPrimaryRuntimeHikariDataSourceWithValidatedInitSql() throws Exception { + DataSourceProperties dataSourceProperties = postgresProperties(); + HikariConfig hikariConfig = new HikariConfig(); + hikariConfig.setInitializationFailTimeout(-1); + hikariConfig.setMaximumPoolSize(7); + RuntimeDatabaseTimeoutProperties timeoutProperties = timeoutProperties(); + + try (HikariDataSource dataSource = configuration.dataSource( + dataSourceProperties, + hikariConfig, + timeoutProperties, + new MockEnvironment() + )) { + assertThat(dataSource.getJdbcUrl()) + .isEqualTo("jdbc:postgresql://localhost:5432/fowoco_config_test"); + assertThat(dataSource.getUsername()).isEqualTo("runtime_user"); + assertThat(dataSource.getMaximumPoolSize()).isEqualTo(7); + assertThat(dataSource.getConnectionInitSql()).isEqualTo( + "SELECT pg_catalog.set_config('statement_timeout', '30000ms', false), " + + "pg_catalog.set_config('lock_timeout', '3000ms', false)" + ); + } + + Method dataSourceMethod = PostgreSqlRuntimeDataSourceConfiguration.class + .getDeclaredMethod( + "dataSource", + DataSourceProperties.class, + HikariConfig.class, + RuntimeDatabaseTimeoutProperties.class, + org.springframework.core.env.Environment.class + ); + assertThat(dataSourceMethod.isAnnotationPresent(Primary.class)).isTrue(); + } + + @Test + void customConfigurationIsInactiveInTransactionOnlyMode() { + new ApplicationContextRunner() + .withUserConfiguration(PostgreSqlRuntimeDataSourceConfiguration.class) + .withPropertyValues("app.database.tenant-context-mode=transaction-only") + .run(context -> { + assertThat(context).doesNotHaveBean( + PostgreSqlRuntimeDataSourceConfiguration.class + ); + assertThat(context).doesNotHaveBean("dataSource"); + }); + } + + @ParameterizedTest + @ValueSource(strings = { + "spring.datasource.jndi-name", + "spring.datasource.hikari.jdbc-url", + "spring.datasource.hikari.username", + "spring.datasource.hikari.password", + "spring.datasource.hikari.driver-class-name", + "spring.datasource.hikari.data-source-class-name", + "spring.datasource.hikari.data-source-j-n-d-i", + "spring.datasource.hikari.connection-init-sql" + }) + void rejectsConflictingDataSourcePropertiesWithoutPrintingValues(String property) { + String sensitiveValue = "credential-or-secret-value"; + MockEnvironment environment = new MockEnvironment() + .withProperty(property, sensitiveValue); + + assertThatThrownBy(() -> configuration.dataSource( + postgresProperties(), + nonConnectingHikariConfig(), + timeoutProperties(), + environment + )) + .isInstanceOf(IllegalStateException.class) + .hasMessageContaining(property) + .hasMessageNotContaining(sensitiveValue) + .hasMessageContaining("app.database.runtime-timeout.*"); + } + + @Test + void rejectsLazyFetchNonHikariTypeAndWrappedUrl() { + MockEnvironment lazy = new MockEnvironment() + .withProperty("spring.datasource.connection-fetch", "lazy"); + assertThatThrownBy(() -> configuration.dataSource( + postgresProperties(), + nonConnectingHikariConfig(), + timeoutProperties(), + lazy + )) + .isInstanceOf(IllegalStateException.class) + .hasMessageContaining("connection-fetch"); + + DataSourceProperties nonHikari = postgresProperties(); + nonHikari.setType(DataSource.class); + MockEnvironment explicitType = new MockEnvironment() + .withProperty("spring.datasource.type", DataSource.class.getName()); + assertThatThrownBy(() -> configuration.dataSource( + nonHikari, + nonConnectingHikariConfig(), + timeoutProperties(), + explicitType + )) + .isInstanceOf(IllegalStateException.class) + .hasMessageContaining("spring.datasource.type"); + + DataSourceProperties wrapped = postgresProperties(); + wrapped.setUrl("jdbc:p6spy:postgresql://localhost:5432/fowoco_config_test"); + assertThatThrownBy(() -> configuration.dataSource( + wrapped, + nonConnectingHikariConfig(), + timeoutProperties(), + new MockEnvironment() + )) + .isInstanceOf(IllegalStateException.class) + .hasMessageContaining("jdbc:postgresql:"); + } + + @Test + void rejectsBoundHikariConnectionSourcesEvenWithRelaxedPropertyNames() { + HikariConfig hikariConfig = nonConnectingHikariConfig(); + hikariConfig.setJdbcUrl("jdbc:postgresql://other-host/other-db"); + + assertThatThrownBy(() -> configuration.dataSource( + postgresProperties(), + hikariConfig, + timeoutProperties(), + new MockEnvironment() + )) + .isInstanceOf(IllegalStateException.class) + .hasMessageContaining("spring.datasource.hikari.jdbc-url") + .hasMessageNotContaining("other-host"); + } + + private DataSourceProperties postgresProperties() { + DataSourceProperties properties = new DataSourceProperties(); + properties.setUrl("jdbc:postgresql://localhost:5432/fowoco_config_test"); + properties.setUsername("runtime_user"); + properties.setPassword("runtime_password"); + properties.setDriverClassName("org.postgresql.Driver"); + return properties; + } + + private HikariConfig nonConnectingHikariConfig() { + HikariConfig config = new HikariConfig(); + config.setInitializationFailTimeout(-1); + return config; + } + + private RuntimeDatabaseTimeoutProperties timeoutProperties() { + RuntimeDatabaseTimeoutProperties properties = + new RuntimeDatabaseTimeoutProperties(); + properties.afterPropertiesSet(); + return properties; + } +} diff --git a/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutBehaviorIntegrationTest.java b/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutBehaviorIntegrationTest.java new file mode 100644 index 0000000..aa1208f --- /dev/null +++ b/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutBehaviorIntegrationTest.java @@ -0,0 +1,136 @@ +package com.fowoco.server.common.database; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.catchThrowable; + +import java.sql.Connection; +import java.sql.PreparedStatement; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.TestInstance; +import org.junit.jupiter.api.Timeout; +import org.junit.jupiter.api.condition.EnabledIfEnvironmentVariable; + +@EnabledIfEnvironmentVariable(named = "POSTGRES_TEST_ENABLED", matches = "true") +@TestInstance(TestInstance.Lifecycle.PER_CLASS) +@Timeout(45) +class PostgreSqlRuntimeTimeoutBehaviorIntegrationTest + extends PostgreSqlRuntimeTimeoutIntegrationSupport { + + private final PostgreSqlTimeoutClassifier classifier = + new PostgreSqlTimeoutClassifier(); + + @Override + protected String statementTimeout() { + return "300ms"; + } + + @Override + protected String lockTimeout() { + return "100ms"; + } + + @AfterEach + void resetFixture() { + restoreFixtureName(); + } + + @Test + void statementTimeoutRollsBackTransactionAndPoolServesNextQuery() { + Throwable failure = catchThrowable(() -> transactionTemplate.executeWithoutResult( + status -> { + runtimeJdbc.update( + "UPDATE company SET name = ? WHERE company_id = ?", + "must roll back", + FIXTURE_COMPANY_ID + ); + runtimeJdbc.execute("SELECT pg_catalog.pg_sleep(1.0)"); + } + )); + + PostgreSqlTimeoutClassification classification = classifier.classify(failure); + assertThat(classification.type()) + .isEqualTo(DatabaseTimeoutType.CONFIRMED_STATEMENT_TIMEOUT); + assertThat(classification.sqlState()).isEqualTo("57014"); + assertThat(migrationJdbc.queryForObject( + "SELECT name FROM company WHERE company_id = ?", + String.class, + FIXTURE_COMPANY_ID + )).isEqualTo(ORIGINAL_COMPANY_NAME); + assertNormalRuntimeQuery(); + } + + @Test + void lockTimeoutDoesNotAffectLockOwnerAndPoolRecovers() throws Exception { + try (Connection lockOwner = migrationConnection()) { + lockOwner.setAutoCommit(false); + try (PreparedStatement statement = lockOwner.prepareStatement( + "SELECT company_id FROM company WHERE company_id = ? FOR UPDATE" + )) { + statement.setObject(1, FIXTURE_COMPANY_ID); + statement.executeQuery().close(); + + for (int attempt = 0; attempt < 3; attempt++) { + Throwable failure = catchThrowable(() -> + transactionTemplate.executeWithoutResult(status -> + runtimeJdbc.update( + "UPDATE company SET name = ? " + + "WHERE company_id = ?", + "blocked update", + FIXTURE_COMPANY_ID + ) + ) + ); + PostgreSqlTimeoutClassification classification = + classifier.classify(failure); + assertThat(classification.type()) + .isEqualTo(DatabaseTimeoutType.CONFIRMED_LOCK_TIMEOUT); + assertThat(classification.sqlState()).isEqualTo("55P03"); + assertThat(runtimeJdbc.queryForObject("SELECT 1", Integer.class)) + .isEqualTo(1); + } + assertThat(lockOwner.isClosed()).isFalse(); + } finally { + lockOwner.rollback(); + } + } + + transactionTemplate.executeWithoutResult(status -> runtimeJdbc.update( + "UPDATE company SET name = ? WHERE company_id = ?", + "after lock release", + FIXTURE_COMPANY_ID + )); + assertThat(migrationJdbc.queryForObject( + "SELECT name FROM company WHERE company_id = ?", + String.class, + FIXTURE_COMPANY_ID + )).isEqualTo("after lock release"); + assertNormalRuntimeQuery(); + } + + @Test + void repeatedTimeoutsDoNotPreventLaterConnectionCheckout() { + for (int attempt = 0; attempt < 3; attempt++) { + Throwable failure = catchThrowable(() -> + transactionTemplate.executeWithoutResult(status -> + runtimeJdbc.execute("SELECT pg_catalog.pg_sleep(1.0)") + ) + ); + assertThat(classifier.classify(failure).type()) + .isEqualTo(DatabaseTimeoutType.CONFIRMED_STATEMENT_TIMEOUT); + assertNormalRuntimeQuery(); + } + } + + private void assertNormalRuntimeQuery() { + assertThat(runtimeJdbc.queryForObject("SELECT 1", Integer.class)).isEqualTo(1); + assertThat(runtimeJdbc.queryForObject( + "SELECT pg_catalog.current_setting('statement_timeout')", + String.class + )).isEqualTo("300ms"); + assertThat(runtimeJdbc.queryForObject( + "SELECT pg_catalog.current_setting('lock_timeout')", + String.class + )).isEqualTo("100ms"); + } +} diff --git a/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutInitFailureIntegrationTest.java b/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutInitFailureIntegrationTest.java new file mode 100644 index 0000000..1644740 --- /dev/null +++ b/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutInitFailureIntegrationTest.java @@ -0,0 +1,43 @@ +package com.fowoco.server.common.database; + +import static org.assertj.core.api.Assertions.assertThatThrownBy; + +import com.zaxxer.hikari.HikariConfig; +import com.zaxxer.hikari.HikariDataSource; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.Timeout; +import org.junit.jupiter.api.condition.EnabledIfEnvironmentVariable; + +@EnabledIfEnvironmentVariable(named = "POSTGRES_TEST_ENABLED", matches = "true") +@Timeout(20) +class PostgreSqlRuntimeTimeoutInitFailureIntegrationTest { + + @Test + void invalidInitSqlNeverProvidesAUsablePoolConnection() { + HikariConfig config = new HikariConfig(); + config.setJdbcUrl(required("POSTGRES_TEST_URL")); + config.setUsername(required("POSTGRES_TEST_USERNAME")); + config.setPassword(required("POSTGRES_TEST_PASSWORD")); + config.setDriverClassName("org.postgresql.Driver"); + config.setMaximumPoolSize(1); + config.setMinimumIdle(0); + config.setInitializationFailTimeout(5_000L); + config.setConnectionInitSql( + "SELECT definitely_missing_runtime_timeout_function()" + ); + + assertThatThrownBy(() -> { + try (HikariDataSource dataSource = new HikariDataSource(config)) { + dataSource.getConnection().close(); + } + }).isInstanceOf(Exception.class); + } + + private String required(String name) { + String value = System.getenv(name); + if (value == null || value.isBlank()) { + throw new IllegalStateException(name + " environment variable is required."); + } + return value; + } +} diff --git a/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutIntegrationSupport.java b/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutIntegrationSupport.java new file mode 100644 index 0000000..6b19613 --- /dev/null +++ b/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutIntegrationSupport.java @@ -0,0 +1,246 @@ +package com.fowoco.server.common.database; + +import com.fowoco.server.ServerApplication; +import com.zaxxer.hikari.HikariDataSource; +import java.sql.Connection; +import java.sql.DriverManager; +import java.sql.ResultSet; +import java.sql.SQLException; +import java.sql.Statement; +import java.util.LinkedHashMap; +import java.util.Map; +import java.util.UUID; +import javax.sql.DataSource; +import org.flywaydb.core.Flyway; +import org.junit.jupiter.api.AfterAll; +import org.junit.jupiter.api.BeforeAll; +import org.springframework.boot.SpringApplication; +import org.springframework.boot.WebApplicationType; +import org.springframework.context.ConfigurableApplicationContext; +import org.springframework.core.env.MapPropertySource; +import org.springframework.core.env.StandardEnvironment; +import org.springframework.jdbc.core.JdbcTemplate; +import org.springframework.jdbc.datasource.DriverManagerDataSource; +import org.springframework.transaction.PlatformTransactionManager; +import org.springframework.transaction.support.TransactionTemplate; + +abstract class PostgreSqlRuntimeTimeoutIntegrationSupport { + + protected static final UUID FIXTURE_COMPANY_ID = + UUID.fromString("64000000-0000-0000-0000-000000000001"); + protected static final String ORIGINAL_COMPANY_NAME = "Runtime timeout fixture"; + + protected String migrationUrl; + protected String migrationUsername; + protected String migrationPassword; + protected String runtimeRole; + protected String runtimePassword; + protected ConfigurableApplicationContext applicationContext; + protected JdbcTemplate migrationJdbc; + protected JdbcTemplate runtimeJdbc; + protected HikariDataSource runtimeDataSource; + protected TransactionTemplate transactionTemplate; + + protected abstract String statementTimeout(); + + protected abstract String lockTimeout(); + + @BeforeAll + void setUpRuntimeTimeoutFixture() throws SQLException { + migrationUrl = requiredEnvironmentVariable("POSTGRES_TEST_URL"); + migrationUsername = requiredEnvironmentVariable("POSTGRES_TEST_USERNAME"); + migrationPassword = requiredEnvironmentVariable("POSTGRES_TEST_PASSWORD"); + + Flyway.configure() + .dataSource(migrationUrl, migrationUsername, migrationPassword) + .locations("classpath:db/migration", "classpath:db/migration-postgresql") + .load() + .migrate(); + + runtimeRole = "timeout_runtime_test_" + + UUID.randomUUID().toString().replace("-", "").substring(0, 12); + runtimePassword = "Timeout-test-" + UUID.randomUUID(); + try (Connection connection = migrationConnection(); + Statement statement = connection.createStatement()) { + String quotedRole = quoteIdentifier(runtimeRole); + statement.execute(""" + CREATE ROLE %s + LOGIN + PASSWORD %s + NOSUPERUSER + NOCREATEDB + NOCREATEROLE + NOINHERIT + NOREPLICATION + NOBYPASSRLS + """.formatted(quotedRole, quoteLiteral(runtimePassword))); + statement.execute( + "GRANT CONNECT ON DATABASE " + + quoteIdentifier(connection.getCatalog()) + + " TO " + + quotedRole + ); + statement.execute("GRANT USAGE ON SCHEMA public TO " + quotedRole); + statement.execute( + "GRANT SELECT, UPDATE ON TABLE public.company TO " + quotedRole + ); + } + + DataSource migrationDataSource = new DriverManagerDataSource( + migrationUrl, + migrationUsername, + migrationPassword + ); + migrationJdbc = new JdbcTemplate(migrationDataSource); + migrationJdbc.update( + """ + INSERT INTO company ( + company_id, name, status, created_at, updated_at, version + ) VALUES (?, ?, 'ACTIVE', CURRENT_TIMESTAMP, CURRENT_TIMESTAMP, 0) + ON CONFLICT (company_id) DO UPDATE SET + name = EXCLUDED.name, + updated_at = CURRENT_TIMESTAMP + """, + FIXTURE_COMPANY_ID, + ORIGINAL_COMPANY_NAME + ); + + applicationContext = startRuntimeApplication(); + runtimeDataSource = applicationContext.getBean( + "dataSource", + HikariDataSource.class + ); + runtimeJdbc = new JdbcTemplate(runtimeDataSource); + transactionTemplate = new TransactionTemplate( + applicationContext.getBean(PlatformTransactionManager.class) + ); + } + + @AfterAll + void tearDownRuntimeTimeoutFixture() throws SQLException { + if (applicationContext != null) { + applicationContext.close(); + } + if (migrationJdbc != null) { + migrationJdbc.update( + "DELETE FROM company WHERE company_id = ?", + FIXTURE_COMPANY_ID + ); + } + if (runtimeRole == null) { + return; + } + try (Connection connection = migrationConnection(); + Statement statement = connection.createStatement()) { + if (roleExists(statement, runtimeRole)) { + String quotedRole = quoteIdentifier(runtimeRole); + statement.execute("DROP OWNED BY " + quotedRole); + statement.execute("DROP ROLE " + quotedRole); + } + } + } + + protected Connection migrationConnection() throws SQLException { + return DriverManager.getConnection( + migrationUrl, + migrationUsername, + migrationPassword + ); + } + + protected int backendPid(Connection connection) throws SQLException { + try (Statement statement = connection.createStatement(); + ResultSet resultSet = statement.executeQuery( + "SELECT pg_catalog.pg_backend_pid()" + )) { + resultSet.next(); + return resultSet.getInt(1); + } + } + + protected String setting(Connection connection, String name) throws SQLException { + try (java.sql.PreparedStatement statement = connection.prepareStatement( + "SELECT pg_catalog.current_setting(?)" + )) { + statement.setString(1, name); + try (ResultSet resultSet = statement.executeQuery()) { + resultSet.next(); + return resultSet.getString(1); + } + } + } + + protected void restoreFixtureName() { + migrationJdbc.update( + "UPDATE company SET name = ?, updated_at = CURRENT_TIMESTAMP " + + "WHERE company_id = ?", + ORIGINAL_COMPANY_NAME, + FIXTURE_COMPANY_ID + ); + } + + private ConfigurableApplicationContext startRuntimeApplication() { + Map properties = new LinkedHashMap<>(); + properties.put("spring.datasource.url", migrationUrl); + properties.put("spring.datasource.username", runtimeRole); + properties.put("spring.datasource.password", runtimePassword); + properties.put("spring.datasource.driver-class-name", "org.postgresql.Driver"); + properties.put("spring.datasource.hikari.maximum-pool-size", "1"); + properties.put("spring.datasource.hikari.minimum-idle", "0"); + properties.put("spring.datasource.hikari.initialization-fail-timeout", "5000"); + properties.put("spring.datasource.hikari.pool-name", "runtime-timeout-test-pool"); + properties.put("spring.flyway.url", migrationUrl); + properties.put("spring.flyway.user", migrationUsername); + properties.put("spring.flyway.password", migrationPassword); + properties.put( + "spring.flyway.locations", + "classpath:db/migration,classpath:db/migration-postgresql" + ); + properties.put("app.database.tenant-context-mode", "postgresql"); + properties.put( + "app.database.runtime-timeout.statement-timeout", + statementTimeout() + ); + properties.put("app.database.runtime-timeout.lock-timeout", lockTimeout()); + properties.put("app.reliability.outbox.enabled", "false"); + properties.put("app.demo-seed.enabled", "false"); + properties.put("server.port", "0"); + + StandardEnvironment environment = new StandardEnvironment(); + environment.setActiveProfiles("test"); + environment.getPropertySources().addFirst( + new MapPropertySource("postgresql-runtime-timeout-test", properties) + ); + + SpringApplication application = new SpringApplication(ServerApplication.class); + application.setEnvironment(environment); + application.setWebApplicationType(WebApplicationType.SERVLET); + return application.run(); + } + + private static boolean roleExists(Statement statement, String roleName) + throws SQLException { + try (ResultSet resultSet = statement.executeQuery( + "SELECT 1 FROM pg_catalog.pg_roles WHERE rolname = " + + quoteLiteral(roleName) + )) { + return resultSet.next(); + } + } + + protected static String quoteIdentifier(String value) { + return "\"" + value.replace("\"", "\"\"") + "\""; + } + + protected static String quoteLiteral(String value) { + return "'" + value.replace("'", "''") + "'"; + } + + protected static String requiredEnvironmentVariable(String name) { + String value = System.getenv(name); + if (value == null || value.isBlank()) { + throw new IllegalStateException(name + " environment variable is required."); + } + return value; + } +} diff --git a/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutSessionIntegrationTest.java b/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutSessionIntegrationTest.java new file mode 100644 index 0000000..c508d2c --- /dev/null +++ b/src/test/java/com/fowoco/server/common/database/PostgreSqlRuntimeTimeoutSessionIntegrationTest.java @@ -0,0 +1,124 @@ +package com.fowoco.server.common.database; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatThrownBy; + +import java.sql.Connection; +import java.time.Duration; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.TestInstance; +import org.junit.jupiter.api.Timeout; +import org.junit.jupiter.api.condition.EnabledIfEnvironmentVariable; + +@EnabledIfEnvironmentVariable(named = "POSTGRES_TEST_ENABLED", matches = "true") +@TestInstance(TestInstance.Lifecycle.PER_CLASS) +@Timeout(30) +class PostgreSqlRuntimeTimeoutSessionIntegrationTest + extends PostgreSqlRuntimeTimeoutIntegrationSupport { + + @Override + protected String statementTimeout() { + return "1234ms"; + } + + @Override + protected String lockTimeout() { + return "234ms"; + } + + @Test + void appliesSessionTimeoutsOnlyToRestrictedRuntimeConnections() throws Exception { + try (Connection runtimeConnection = runtimeDataSource.getConnection(); + Connection migrationConnection = migrationConnection()) { + assertThat(setting(runtimeConnection, "statement_timeout")) + .isEqualTo("1234ms"); + assertThat(setting(runtimeConnection, "lock_timeout")) + .isEqualTo("234ms"); + assertThat(setting(migrationConnection, "statement_timeout")) + .isNotEqualTo("1234ms"); + assertThat(setting(migrationConnection, "lock_timeout")) + .isNotEqualTo("234ms"); + } + + Integer roleSettings = migrationJdbc.queryForObject( + """ + SELECT COUNT(*) + FROM pg_catalog.pg_db_role_setting settings + JOIN pg_catalog.pg_roles role ON role.oid = settings.setrole + WHERE role.rolname = ? + """, + Integer.class, + runtimeRole + ); + assertThat(roleSettings).isZero(); + } + + @Test + void appliesTimeoutsToNewPhysicalConnectionsAfterEviction() throws Exception { + int firstPid; + try (Connection connection = runtimeDataSource.getConnection()) { + firstPid = backendPid(connection); + assertRuntimeDefaults(connection); + } + + runtimeDataSource.getHikariPoolMXBean().softEvictConnections(); + + int secondPid = awaitDifferentBackend(firstPid); + assertThat(secondPid).isNotEqualTo(firstPid); + } + + @Test + void setLocalChangesReturnToDefaultsAfterCommitAndRollback() throws Exception { + transactionTemplate.executeWithoutResult(status -> { + runtimeJdbc.execute("SET LOCAL statement_timeout = '900ms'"); + runtimeJdbc.execute("SET LOCAL lock_timeout = '90ms'"); + assertThat(runtimeJdbc.queryForObject( + "SELECT pg_catalog.current_setting('statement_timeout')", + String.class + )).isEqualTo("900ms"); + }); + assertRuntimeDefaults(); + + assertThatThrownBy(() -> transactionTemplate.executeWithoutResult(status -> { + runtimeJdbc.execute("SET LOCAL statement_timeout = '800ms'"); + runtimeJdbc.execute("SET LOCAL lock_timeout = '80ms'"); + throw new ExpectedRollback(); + })).isInstanceOf(ExpectedRollback.class); + assertRuntimeDefaults(); + } + + private int awaitDifferentBackend(int previousPid) throws Exception { + long deadline = System.nanoTime() + Duration.ofSeconds(10).toNanos(); + int observedPid = previousPid; + while (System.nanoTime() < deadline) { + try (Connection connection = runtimeDataSource.getConnection()) { + observedPid = backendPid(connection); + assertRuntimeDefaults(connection); + } + if (observedPid != previousPid) { + return observedPid; + } + Thread.sleep(50L); + } + return observedPid; + } + + private void assertRuntimeDefaults() { + assertThat(runtimeJdbc.queryForObject( + "SELECT pg_catalog.current_setting('statement_timeout')", + String.class + )).isEqualTo("1234ms"); + assertThat(runtimeJdbc.queryForObject( + "SELECT pg_catalog.current_setting('lock_timeout')", + String.class + )).isEqualTo("234ms"); + } + + private void assertRuntimeDefaults(Connection connection) throws Exception { + assertThat(setting(connection, "statement_timeout")).isEqualTo("1234ms"); + assertThat(setting(connection, "lock_timeout")).isEqualTo("234ms"); + } + + private static final class ExpectedRollback extends RuntimeException { + } +} diff --git a/src/test/java/com/fowoco/server/common/database/PostgreSqlTimeoutClassifierTest.java b/src/test/java/com/fowoco/server/common/database/PostgreSqlTimeoutClassifierTest.java new file mode 100644 index 0000000..a114a7a --- /dev/null +++ b/src/test/java/com/fowoco/server/common/database/PostgreSqlTimeoutClassifierTest.java @@ -0,0 +1,153 @@ +package com.fowoco.server.common.database; + +import static org.assertj.core.api.Assertions.assertThat; + +import java.sql.SQLException; +import org.junit.jupiter.api.Test; + +class PostgreSqlTimeoutClassifierTest { + + private final PostgreSqlTimeoutClassifier classifier = + new PostgreSqlTimeoutClassifier(); + + @Test + void confirmsOnlyCanonicalStatementAndLockTimeoutDiagnostics() { + assertClassification( + sql("ERROR: canceling statement due to statement timeout", "57014"), + DatabaseTimeoutType.CONFIRMED_STATEMENT_TIMEOUT, + "57014" + ); + assertClassification( + sql("ERROR: canceling statement due to lock timeout", "55P03"), + DatabaseTimeoutType.CONFIRMED_LOCK_TIMEOUT, + "55P03" + ); + } + + @Test + void leavesGenericCancellationAndNowaitFailureAmbiguous() { + assertClassification( + sql("canceling statement due to user request", "57014"), + DatabaseTimeoutType.AMBIGUOUS_QUERY_CANCELED, + "57014" + ); + assertClassification( + sql("could not obtain lock on row in relation", "55P03"), + DatabaseTimeoutType.AMBIGUOUS_LOCK_NOT_AVAILABLE, + "55P03" + ); + assertClassification( + sql("현지화된 취소 메시지", "57014"), + DatabaseTimeoutType.AMBIGUOUS_QUERY_CANCELED, + "57014" + ); + } + + @Test + void doesNotMisclassifyPermissionBootstrapOrGeneralSqlFailures() { + assertClassification( + sql("permission denied", "42501"), + DatabaseTimeoutType.OTHER_DATABASE_FAILURE, + "42501" + ); + assertClassification( + sql("invalid bootstrap argument", "22023"), + DatabaseTimeoutType.OTHER_DATABASE_FAILURE, + "22023" + ); + assertClassification( + sql("syntax error", "42601"), + DatabaseTimeoutType.OTHER_DATABASE_FAILURE, + "42601" + ); + assertClassification( + new IllegalStateException("not a database failure"), + DatabaseTimeoutType.NOT_DATABASE_FAILURE, + null + ); + } + + @Test + void searchesCauseBeforeNextExceptionAndReturnsFirstConfirmedTimeout() { + SQLException root = sql("root", "42601"); + SQLException next = sql( + "canceling statement due to lock timeout", + "55P03" + ); + SQLException cause = sql( + "canceling statement due to statement timeout", + "57014" + ); + root.initCause(cause); + root.setNextException(next); + + PostgreSqlTimeoutClassification result = classifier.classify(root); + + assertThat(result.type()) + .isEqualTo(DatabaseTimeoutType.CONFIRMED_STATEMENT_TIMEOUT); + assertThat(result.sqlState()).isEqualTo("57014"); + assertThat(result.exceptionType()).isEqualTo(SQLException.class.getName()); + } + + @Test + void searchesWrappedAndNextExceptionsAndIgnoresSuppressedExceptions() { + SQLException root = sql("root", "42601"); + SQLException next = sql( + "canceling statement due to lock timeout", + "55P03" + ); + root.setNextException(next); + RuntimeException wrapper = new RuntimeException(new RuntimeException(root)); + + assertClassification( + wrapper, + DatabaseTimeoutType.CONFIRMED_LOCK_TIMEOUT, + "55P03" + ); + + RuntimeException onlySuppressed = new RuntimeException("outer"); + onlySuppressed.addSuppressed(sql( + "canceling statement due to statement timeout", + "57014" + )); + assertClassification( + onlySuppressed, + DatabaseTimeoutType.NOT_DATABASE_FAILURE, + null + ); + } + + @Test + void identityVisitedSetStopsCauseAndNextExceptionCycles() { + SQLException first = sql("first", "42601"); + SQLException second = sql("second", "22023"); + first.setNextException(second); + second.setNextException(first); + + assertClassification( + first, + DatabaseTimeoutType.OTHER_DATABASE_FAILURE, + "42601" + ); + } + + private void assertClassification( + Throwable failure, + DatabaseTimeoutType expectedType, + String expectedSqlState + ) { + PostgreSqlTimeoutClassification result = classifier.classify(failure); + + assertThat(result.type()).isEqualTo(expectedType); + assertThat(result.sqlState()).isEqualTo(expectedSqlState); + if (expectedSqlState == null) { + assertThat(result.exceptionType()).isNull(); + } else { + assertThat(result.exceptionType()).isEqualTo(SQLException.class.getName()); + } + } + + private SQLException sql(String message, String sqlState) { + return new SQLException(message, sqlState); + } +} diff --git a/src/test/java/com/fowoco/server/common/database/RuntimeDatabaseTimeoutPropertiesTest.java b/src/test/java/com/fowoco/server/common/database/RuntimeDatabaseTimeoutPropertiesTest.java new file mode 100644 index 0000000..469e1d9 --- /dev/null +++ b/src/test/java/com/fowoco/server/common/database/RuntimeDatabaseTimeoutPropertiesTest.java @@ -0,0 +1,117 @@ +package com.fowoco.server.common.database; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatThrownBy; + +import java.time.Duration; +import java.util.Map; +import org.junit.jupiter.api.Test; +import org.springframework.boot.context.properties.bind.Bindable; +import org.springframework.boot.context.properties.bind.Binder; +import org.springframework.boot.context.properties.source.MapConfigurationPropertySource; + +class RuntimeDatabaseTimeoutPropertiesTest { + + @Test + void defaultsAreThirtySecondsAndThreeSeconds() { + RuntimeDatabaseTimeoutProperties properties = + new RuntimeDatabaseTimeoutProperties(); + + properties.afterPropertiesSet(); + + assertThat(properties.statementTimeoutMillis()).isEqualTo(30_000L); + assertThat(properties.lockTimeoutMillis()).isEqualTo(3_000L); + } + + @Test + void bindsSpringDurationFormatsAndNormalizesToMilliseconds() { + assertTimeouts("30000", "1000us", 30_000L, 1L); + assertTimeouts("PT30S", "3000ms", 30_000L, 3_000L); + } + + @Test + void rejectsSubMillisecondZeroNegativeAndInvalidOrdering() { + assertInvalid( + Duration.ofSeconds(30), + Duration.ofNanos(1_500_000), + "whole milliseconds" + ); + assertInvalid(Duration.ZERO, Duration.ofMillis(1), "positive"); + assertInvalid(Duration.ofSeconds(30), Duration.ofMillis(-1), "positive"); + assertInvalid(Duration.ofSeconds(3), Duration.ofSeconds(3), "shorter"); + assertInvalid(Duration.ofSeconds(3), Duration.ofSeconds(4), "shorter"); + } + + @Test + void acceptsMaximumAndRejectsValuesAbovePostgreSqlIntegerBoundary() { + RuntimeDatabaseTimeoutProperties maximum = properties( + RuntimeDatabaseTimeoutProperties.MAX_POSTGRESQL_TIMEOUT, + Duration.ofMillis(Integer.MAX_VALUE - 1L) + ); + maximum.afterPropertiesSet(); + + assertThat(maximum.statementTimeoutMillis()).isEqualTo(Integer.MAX_VALUE); + assertThatThrownBy(() -> properties( + RuntimeDatabaseTimeoutProperties.MAX_POSTGRESQL_TIMEOUT.plusMillis(1), + Duration.ofMillis(1) + ).afterPropertiesSet()) + .isInstanceOf(IllegalArgumentException.class) + .hasMessageContaining("must not exceed") + .isNotInstanceOf(ArithmeticException.class); + } + + @Test + void invalidDurationTextFailsBinding() { + MapConfigurationPropertySource source = new MapConfigurationPropertySource(Map.of( + "app.database.runtime-timeout.statement-timeout", "thirty parsecs", + "app.database.runtime-timeout.lock-timeout", "3s" + )); + + assertThatThrownBy(() -> new Binder(source).bind( + "app.database.runtime-timeout", + Bindable.of(RuntimeDatabaseTimeoutProperties.class) + ).get()) + .isInstanceOf(RuntimeException.class); + } + + private void assertTimeouts( + String statement, + String lock, + long statementMillis, + long lockMillis + ) { + MapConfigurationPropertySource source = new MapConfigurationPropertySource(Map.of( + "app.database.runtime-timeout.statement-timeout", statement, + "app.database.runtime-timeout.lock-timeout", lock + )); + RuntimeDatabaseTimeoutProperties properties = new Binder(source).bind( + "app.database.runtime-timeout", + Bindable.of(RuntimeDatabaseTimeoutProperties.class) + ).get(); + properties.afterPropertiesSet(); + + assertThat(properties.statementTimeoutMillis()).isEqualTo(statementMillis); + assertThat(properties.lockTimeoutMillis()).isEqualTo(lockMillis); + } + + private void assertInvalid( + Duration statement, + Duration lock, + String messageFragment + ) { + assertThatThrownBy(() -> properties(statement, lock).afterPropertiesSet()) + .isInstanceOf(IllegalArgumentException.class) + .hasMessageContaining(messageFragment); + } + + private RuntimeDatabaseTimeoutProperties properties( + Duration statement, + Duration lock + ) { + RuntimeDatabaseTimeoutProperties properties = + new RuntimeDatabaseTimeoutProperties(); + properties.setStatementTimeout(statement); + properties.setLockTimeout(lock); + return properties; + } +} diff --git a/src/test/java/com/fowoco/server/common/error/GlobalExceptionHandlerDatabaseTimeoutTest.java b/src/test/java/com/fowoco/server/common/error/GlobalExceptionHandlerDatabaseTimeoutTest.java new file mode 100644 index 0000000..21d10c7 --- /dev/null +++ b/src/test/java/com/fowoco/server/common/error/GlobalExceptionHandlerDatabaseTimeoutTest.java @@ -0,0 +1,177 @@ +package com.fowoco.server.common.error; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.springframework.test.web.servlet.request.MockMvcRequestBuilders.get; +import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.jsonPath; +import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.status; + +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; +import com.fowoco.server.common.database.DatabaseTimeoutMetrics; +import com.fowoco.server.common.database.PostgreSqlTimeoutClassifier; +import com.fowoco.server.common.web.RequestIdFilter; +import io.micrometer.core.instrument.simple.SimpleMeterRegistry; +import java.sql.SQLException; +import java.time.Clock; +import java.time.Instant; +import java.time.ZoneOffset; +import java.util.UUID; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; +import org.springframework.test.web.servlet.MockMvc; +import org.springframework.test.web.servlet.setup.MockMvcBuilders; +import org.springframework.web.bind.annotation.GetMapping; +import org.springframework.web.bind.annotation.PathVariable; +import org.springframework.web.bind.annotation.RequestMapping; +import org.springframework.web.bind.annotation.RequestParam; +import org.springframework.web.bind.annotation.RestController; + +class GlobalExceptionHandlerDatabaseTimeoutTest { + + private static final String REQUEST_ID = + "00000000-0000-0000-0000-000000000064"; + private static final String SECRET = "worker-link-secret-token"; + private static final String SQL = "SELECT private_value FROM secret_table"; + private static final String PARAMETER = "passport-number-parameter"; + + private final SimpleMeterRegistry meterRegistry = new SimpleMeterRegistry(); + private final Logger handlerLogger = (Logger) LoggerFactory.getLogger( + GlobalExceptionHandler.class + ); + private final ListAppender logAppender = new ListAppender<>(); + private MockMvc mockMvc; + + @BeforeEach + void setUp() { + Clock fixedClock = Clock.fixed( + Instant.parse("2026-07-31T00:00:00Z"), + ZoneOffset.UTC + ); + RequestIdFilter requestIdFilter = new RequestIdFilter( + () -> UUID.fromString(REQUEST_ID) + ); + logAppender.start(); + handlerLogger.addAppender(logAppender); + mockMvc = MockMvcBuilders.standaloneSetup(new TimeoutTestController()) + .setControllerAdvice(new GlobalExceptionHandler( + fixedClock, + new PostgreSqlTimeoutClassifier(), + new DatabaseTimeoutMetrics(meterRegistry) + )) + .addFilters(requestIdFilter) + .build(); + } + + @AfterEach + void tearDown() { + handlerLogger.detachAppender(logAppender); + logAppender.stop(); + meterRegistry.close(); + } + + @Test + void confirmedStatementTimeoutUsesSafe503ResponseLogAndMetric() throws Exception { + mockMvc.perform(get("/test/sensitive/{secret}", SECRET) + .queryParam("failure", "statement")) + .andExpect(status().isServiceUnavailable()) + .andExpect(jsonPath("$.code") + .value("SERVICE_TEMPORARILY_UNAVAILABLE")) + .andExpect(jsonPath("$.path") + .value("/test/sensitive/{secret}")); + + assertThat(meterRegistry.get("fowoco.database.timeouts") + .tag("type", "statement").counter().count()).isEqualTo(1.0); + assertSafeLog("DATABASE_STATEMENT_TIMEOUT", "57014"); + } + + @Test + void confirmedLockTimeoutUses503AndLockMetric() throws Exception { + mockMvc.perform(get("/test/sensitive/{secret}", SECRET) + .queryParam("failure", "lock")) + .andExpect(status().isServiceUnavailable()) + .andExpect(jsonPath("$.code") + .value("SERVICE_TEMPORARILY_UNAVAILABLE")); + + assertThat(meterRegistry.get("fowoco.database.timeouts") + .tag("type", "lock").counter().count()).isEqualTo(1.0); + assertSafeLog("DATABASE_LOCK_TIMEOUT", "55P03"); + } + + @Test + void ambiguousCancellationUsesSafe500WithoutTimeoutMetric() throws Exception { + mockMvc.perform(get("/test/sensitive/{secret}", SECRET) + .queryParam("failure", "ambiguous")) + .andExpect(status().isInternalServerError()) + .andExpect(jsonPath("$.code").value("INTERNAL_SERVER_ERROR")) + .andExpect(jsonPath("$.path") + .value("/test/sensitive/{secret}")); + + assertThat(meterRegistry.find("fowoco.database.timeouts") + .tag("type", "statement").counter().count()).isZero(); + assertSafeLog("AMBIGUOUS_QUERY_CANCELED", "57014"); + } + + @Test + void ordinaryUnexpectedFailureKeepsExistingHandling() throws Exception { + mockMvc.perform(get("/test/sensitive/{secret}", SECRET) + .queryParam("failure", "ordinary")) + .andExpect(status().isInternalServerError()) + .andExpect(jsonPath("$.code").value("INTERNAL_SERVER_ERROR")); + + assertThat(logAppender.list).hasSize(1); + assertThat(logAppender.list.get(0).getThrowableProxy()).isNotNull(); + } + + private void assertSafeLog(String classification, String sqlState) { + assertThat(logAppender.list).hasSize(1); + ILoggingEvent event = logAppender.list.get(0); + String message = event.getFormattedMessage(); + assertThat(message) + .contains("requestId=" + REQUEST_ID) + .contains("method=GET") + .contains("route=/test/sensitive/{secret}") + .contains("classification=" + classification) + .contains("sqlState=" + sqlState) + .contains("exceptionType=java.sql.SQLException") + .doesNotContain(SECRET, SQL, PARAMETER, "canceling statement"); + assertThat(event.getThrowableProxy()).isNull(); + } + + @RestController + @RequestMapping("/test") + private static class TimeoutTestController { + + @GetMapping("/sensitive/{secret}") + private void fail( + @PathVariable String secret, + @RequestParam String failure + ) { + throw switch (failure) { + case "statement" -> wrappedSqlFailure( + "canceling statement due to statement timeout", + "57014" + ); + case "lock" -> wrappedSqlFailure( + "canceling statement due to lock timeout", + "55P03" + ); + case "ambiguous" -> wrappedSqlFailure( + "canceling statement due to user request", + "57014" + ); + default -> new IllegalStateException("ordinary failure"); + }; + } + + private RuntimeException wrappedSqlFailure(String diagnostic, String sqlState) { + SQLException sqlException = new SQLException( + diagnostic + " sql=" + SQL + " parameter=" + PARAMETER, + sqlState + ); + return new RuntimeException("database operation failed", sqlException); + } + } +} diff --git a/src/test/java/com/fowoco/server/common/error/GlobalExceptionHandlerTest.java b/src/test/java/com/fowoco/server/common/error/GlobalExceptionHandlerTest.java index ff918c6..914a8ca 100644 --- a/src/test/java/com/fowoco/server/common/error/GlobalExceptionHandlerTest.java +++ b/src/test/java/com/fowoco/server/common/error/GlobalExceptionHandlerTest.java @@ -7,6 +7,9 @@ import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.status; import com.fowoco.server.common.web.RequestIdFilter; +import com.fowoco.server.common.database.DatabaseTimeoutMetrics; +import com.fowoco.server.common.database.PostgreSqlTimeoutClassifier; +import io.micrometer.core.instrument.simple.SimpleMeterRegistry; import jakarta.validation.Valid; import jakarta.validation.constraints.NotBlank; import java.time.Clock; @@ -35,7 +38,11 @@ void setUp() { RequestIdFilter requestIdFilter = new RequestIdFilter(() -> UUID.fromString(REQUEST_ID)); mockMvc = MockMvcBuilders.standaloneSetup(new ValidationTestController()) - .setControllerAdvice(new GlobalExceptionHandler(fixedClock)) + .setControllerAdvice(new GlobalExceptionHandler( + fixedClock, + new PostgreSqlTimeoutClassifier(), + new DatabaseTimeoutMetrics(new SimpleMeterRegistry()) + )) .addFilters(requestIdFilter) .build(); }