niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #215
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestFilterOversizedClosures8=== PAUSE TestFilterOversizedClosures9=== RUN TestPartSizeForNAR10=== PAUSE TestPartSizeForNAR11=== RUN TestUploadMultipart_SupersededByPeer12=== PAUSE TestUploadMultipart_SupersededByPeer13=== RUN TestDumpPathCaseHackMatchesNix14--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)15=== RUN TestDumpPathCaseHackCollision16--- PASS: TestDumpPathCaseHackCollision (0.00s)17=== RUN TestDumpPathMatchesNix18=== PAUSE TestDumpPathMatchesNix19=== RUN TestDumpPathSingleFile20=== PAUSE TestDumpPathSingleFile21=== RUN TestDumpPathWriterError22=== PAUSE TestDumpPathWriterError23=== RUN TestEncodeNixBase3224=== PAUSE TestEncodeNixBase3225=== RUN TestEncodeNixBase32WithRealHash26=== PAUSE TestEncodeNixBase32WithRealHash27=== RUN TestConvertHashToNix3228=== PAUSE TestConvertHashToNix3229=== RUN TestGetStorePathHash30=== PAUSE TestGetStorePathHash31=== RUN TestPathInfoHashCompatibility32=== PAUSE TestPathInfoHashCompatibility33=== RUN TestParsePathInfoJSON34=== PAUSE TestParsePathInfoJSON35=== RUN TestParsePathInfoJSONMultiplePaths36=== PAUSE TestParsePathInfoJSONMultiplePaths37=== RUN TestPathInfoCACompatibility38=== PAUSE TestPathInfoCACompatibility39=== RUN TestRateLimiterFeedback40=== PAUSE TestRateLimiterFeedback41=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess42=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess43=== RUN TestResolveStorePath44=== PAUSE TestResolveStorePath45=== RUN TestDoWithRetry_BodyReplayedViaGetBody46=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody47=== RUN TestShellSplit48=== PAUSE TestShellSplit49=== RUN TestShellSplitErrors50=== PAUSE TestShellSplitErrors51=== RUN TestStreamPushReportsEveryPath52=== PAUSE TestStreamPushReportsEveryPath53=== RUN TestStreamPushBatchesUnderLoad54=== PAUSE TestStreamPushBatchesUnderLoad55=== RUN TestStreamPushIsolatesFailures56=== PAUSE TestStreamPushIsolatesFailures57=== RUN TestStreamPushGivesUpOnDeadServer58=== PAUSE TestStreamPushGivesUpOnDeadServer59=== RUN TestStreamPushRequestLine60=== PAUSE TestStreamPushRequestLine61=== RUN TestSetClientTLS62=== PAUSE TestSetClientTLS63=== RUN TestSetClientTLSDoesNotMutateDefaultTransport64=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport65=== RUN TestSetClientTLSErrors66=== PAUSE TestSetClientTLSErrors67=== RUN TestStaticToken68=== PAUSE TestStaticToken69=== RUN TestFileTokenReadsAndCaches70=== PAUSE TestFileTokenReadsAndCaches71=== RUN TestFileTokenMissing72=== PAUSE TestFileTokenMissing73=== RUN TestFileTokenEmpty74=== PAUSE TestFileTokenEmpty75=== RUN TestScriptTokenNoExpiryRerunsEveryCall76=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall77=== RUN TestScriptTokenCachesUntilRefresh78=== PAUSE TestScriptTokenCachesUntilRefresh79=== RUN TestScriptTokenEmptyToken80=== PAUSE TestScriptTokenEmptyToken81=== RUN TestScriptTokenBadJSON82=== PAUSE TestScriptTokenBadJSON83=== RUN TestScriptTokenScriptFails84=== PAUSE TestScriptTokenScriptFails85=== RUN TestScriptTokenEmptyCommand86=== PAUSE TestScriptTokenEmptyCommand87=== CONT TestDoServerRequestAttachesToken88=== CONT TestScriptTokenNoExpiryRerunsEveryCall89=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess90=== CONT TestFileTokenEmpty91=== CONT TestFileTokenMissing92=== CONT TestFileTokenReadsAndCaches932026/09/18 13:10:00 WARN Rate limiter enabled after throttle name=server-test rate=594=== CONT TestStaticToken95=== CONT TestPathInfoHashCompatibility96=== CONT TestPathInfoCACompatibility97=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)98=== CONT TestSetClientTLSErrors99=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)100=== CONT TestSetClientTLS101=== CONT TestStreamPushRequestLine102=== CONT TestStreamPushGivesUpOnDeadServer103=== CONT TestStreamPushIsolatesFailures104=== CONT TestStreamPushBatchesUnderLoad105=== CONT TestStreamPushReportsEveryPath106=== CONT TestScriptTokenBadJSON107=== CONT TestShellSplitErrors108=== CONT TestScriptTokenEmptyCommand109=== CONT TestShellSplit110=== CONT TestDoWithRetry_BodyReplayedViaGetBody111=== CONT TestScriptTokenScriptFails112=== CONT TestResolveStorePath113=== CONT TestParsePathInfoJSON114=== CONT TestGetStorePathHash115--- PASS: TestFileTokenEmpty (0.00s)116=== CONT TestRateLimiterFeedback117=== CONT TestSetClientTLSDoesNotMutateDefaultTransport118=== RUN TestPathInfoCACompatibility/null_ca_field119=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon120=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon121=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI122=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI123--- PASS: TestStaticToken (0.00s)124=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512125--- PASS: TestFileTokenMissing (0.00s)1262026/09/18 13:10:00 ERROR Upload failed error="bad path" count=3127--- PASS: TestFileTokenReadsAndCaches (0.00s)128=== RUN TestRateLimiterFeedback/429_enables_limiter129--- PASS: TestShellSplitErrors (0.00s)130=== PAUSE TestRateLimiterFeedback/429_enables_limiter131=== CONT TestScriptTokenEmptyToken132=== RUN TestRateLimiterFeedback/503_enables_limiter133=== PAUSE TestRateLimiterFeedback/503_enables_limiter1342026/09/18 13:10:00 ERROR Upload failed error="connection refused" count=20135=== RUN TestParsePathInfoJSON/Nix_format136=== PAUSE TestParsePathInfoJSON/Nix_format137=== RUN TestParsePathInfoJSON/Lix_format138=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5121392026/09/18 13:10:00 ERROR Server seems unavailable, giving up on batch untried=171402026/09/18 13:10:00 ERROR Upload failed error="stale build claim" count=1141=== PAUSE TestPathInfoCACompatibility/null_ca_field142=== RUN TestPathInfoCACompatibility/old_string_format_-_text143=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text144=== CONT TestEncodeNixBase32145=== RUN TestEncodeNixBase32/test_string_hash146=== PAUSE TestEncodeNixBase32/test_string_hash147=== RUN TestEncodeNixBase32/empty_input148=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1492026/09/18 13:10:00 WARN Rate limiter enabled after throttle name=server-test rate=5150=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive151--- PASS: TestScriptTokenEmptyCommand (0.00s)152=== CONT TestDumpPathMatchesNix1532026/09/18 13:10:00 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:46363154=== CONT TestParsePathInfoJSONMultiplePaths155=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter156=== CONT TestScriptTokenCachesUntilRefresh157=== CONT TestDumpPathWriterError158=== CONT TestDumpPathSingleFile159=== CONT TestPartSizeForNAR160=== RUN TestPartSizeForNAR/zero_stays_at_minimum1612026/09/18 13:10:00 WARN Rate limiter backed off name=server-test rate=51622026/09/18 13:10:00 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:46363163=== PAUSE TestParsePathInfoJSON/Lix_format164=== RUN TestParsePathInfoJSON/empty_input165=== CONT TestUploadMultipart_SupersededByPeer166=== CONT TestConvertHashToNix32167=== RUN TestGetStorePathHash/valid_store_path168=== PAUSE TestEncodeNixBase32/empty_input169=== CONT TestFilterOversizedClosures170=== RUN TestConvertHashToNix32/SRI_format_to_Nix32171=== CONT TestCaseHackSuffix172=== RUN TestUploadMultipart_SupersededByPeer/exists173=== PAUSE TestUploadMultipart_SupersededByPeer/exists174=== RUN TestUploadMultipart_SupersededByPeer/missing175=== PAUSE TestUploadMultipart_SupersededByPeer/missing176=== PAUSE TestGetStorePathHash/valid_store_path177=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI178=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths179=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter180=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum181=== RUN TestPathInfoCACompatibility/new_structured_format_-_text182=== PAUSE TestParsePathInfoJSON/empty_input183=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32184=== CONT TestEncodeNixBase32WithRealHash185=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)186--- PASS: TestShellSplit (0.00s)187=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512188=== RUN TestFilterOversizedClosures/no_limit_keeps_everything189=== RUN TestGetStorePathHash/basename_without_hyphen_should_error190=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths191=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter192=== RUN TestPartSizeForNAR/small_stays_at_minimum193--- PASS: TestStreamPushReportsEveryPath (0.00s)194--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)195--- PASS: TestStreamPushIsolatesFailures (0.00s)196--- PASS: TestResolveStorePath (0.00s)197--- PASS: TestScriptTokenScriptFails (0.00s)198--- PASS: TestDoServerRequestAttachesToken (0.01s)199--- PASS: TestScriptTokenBadJSON (0.00s)200--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)201--- PASS: TestScriptTokenEmptyToken (0.01s)202--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)203=== CONT TestEncodeNixBase32/test_string_hash204=== CONT TestEncodeNixBase32/empty_input205--- PASS: TestEncodeNixBase32 (0.00s)206 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)207 --- PASS: TestEncodeNixBase32/empty_input (0.00s)208=== CONT TestUploadMultipart_SupersededByPeer/exists209=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything210=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error211=== RUN TestParsePathInfoJSON/whitespace_only212=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text214=== RUN TestSetClientTLS/rejects_connection_without_client_cert215=== PAUSE TestParsePathInfoJSON/whitespace_only216=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon217=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter218=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths219=== CONT TestRateLimiterFeedback/503_enables_limiter220=== RUN TestSetClientTLSErrors/missing_cert_file221--- PASS: TestEncodeNixBase32WithRealHash (0.00s)222=== CONT TestUploadMultipart_SupersededByPeer/missing223=== RUN TestConvertHashToNix32/already_Nix32_format224=== PAUSE TestPartSizeForNAR/small_stays_at_minimum225=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped226=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error227=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum228=== CONT TestRateLimiterFeedback/429_enables_limiter229=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter230=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method231=== RUN TestParsePathInfoJSON/invalid_JSON232=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter233=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths234--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)235=== PAUSE TestSetClientTLSErrors/missing_cert_file236=== RUN TestSetClientTLSErrors/missing_key_file237=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error238=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error239=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths240=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method241=== RUN TestFilterOversizedClosures/all_closures_skipped2422026/09/18 13:10:00 WARN Rate limiter enabled after throttle name=server-test rate=52432026/09/18 13:10:00 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:46097244=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum2452026/09/18 13:10:00 WARN Rate limiter enabled after throttle name=server-test rate=5246=== PAUSE TestSetClientTLSErrors/missing_key_file2472026/09/18 13:10:00 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:46827248=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2492026/09/18 13:10:00 WARN Rate limiter backed off name=server-test rate=5250=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive251--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)2522026/09/18 13:10:00 WARN Rate limiter backed off name=server-test rate=5253--- PASS: TestPathInfoHashCompatibility (0.00s)254 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)255 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)256 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)257 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)258=== PAUSE TestConvertHashToNix32/already_Nix32_format259=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert260=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error261=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method262=== RUN TestConvertHashToNix32/invalid_format263=== PAUSE TestParsePathInfoJSON/invalid_JSON264=== CONT TestPathInfoCACompatibility/new_structured_format_-_text265=== CONT TestParsePathInfoJSON/invalid_JSON266=== CONT TestPathInfoCACompatibility/old_string_format_-_text267=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts268=== RUN TestSetClientTLSErrors/missing_ca_file269=== CONT TestPathInfoCACompatibility/null_ca_field270--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)271 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.01s)272 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)273=== CONT TestGetStorePathHash/valid_store_path274=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error275=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error276=== CONT TestGetStorePathHash/basename_without_hyphen_should_error277=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA278=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA279=== RUN TestSetClientTLS/preserves_debug_logging_transport280=== PAUSE TestConvertHashToNix32/invalid_format281=== CONT TestConvertHashToNix32/SRI_format_to_Nix32282=== CONT TestConvertHashToNix32/invalid_format283=== PAUSE TestFilterOversizedClosures/all_closures_skipped284=== CONT TestParsePathInfoJSON/Nix_format285=== CONT TestParsePathInfoJSON/whitespace_only286=== CONT TestParsePathInfoJSON/empty_input287=== CONT TestParsePathInfoJSON/Lix_format288=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts289=== RUN TestPartSizeForNAR/1_TiB290=== PAUSE TestPartSizeForNAR/1_TiB291=== RUN TestPartSizeForNAR/5_TiB_S3_max_object292=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object293=== PAUSE TestSetClientTLSErrors/missing_ca_file294--- PASS: TestRateLimiterFeedback (0.02s)295 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)296 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)297 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)298 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)299--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)300 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)301 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)302=== PAUSE TestSetClientTLS/preserves_debug_logging_transport303=== CONT TestSetClientTLS/rejects_connection_without_client_cert304=== CONT TestSetClientTLS/preserves_debug_logging_transport305=== CONT TestConvertHashToNix32/already_Nix32_format306=== CONT TestFilterOversizedClosures/no_limit_keeps_everything307=== CONT TestFilterOversizedClosures/all_closures_skipped3082026/09/18 13:10:00 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50309=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3102026/09/18 13:10:00 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000311=== RUN TestPartSizeForNAR/capped_at_5_GiB312=== PAUSE TestPartSizeForNAR/capped_at_5_GiB313=== RUN TestSetClientTLSErrors/invalid_ca_file314--- PASS: TestPathInfoCACompatibility (0.03s)315 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)316 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)317 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)318 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)319 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)320--- PASS: TestGetStorePathHash (0.03s)321 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)322 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)323 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)324 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)325=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA326--- PASS: TestParsePathInfoJSON (0.03s)327 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)328 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)329 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)330 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)331 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)332--- PASS: TestConvertHashToNix32 (0.03s)333 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)334 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)335 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)336--- PASS: TestFilterOversizedClosures (0.03s)337 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)338 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)339 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)340=== CONT TestPartSizeForNAR/zero_stays_at_minimum341=== CONT TestPartSizeForNAR/capped_at_5_GiB342=== CONT TestPartSizeForNAR/5_TiB_S3_max_object343=== CONT TestPartSizeForNAR/1_TiB344=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts345=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum346=== CONT TestPartSizeForNAR/small_stays_at_minimum347=== PAUSE TestSetClientTLSErrors/invalid_ca_file348--- PASS: TestPartSizeForNAR (0.03s)349 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)350 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)351 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)352 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)353 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)354 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)355 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)356=== CONT TestSetClientTLSErrors/missing_cert_file357=== CONT TestSetClientTLSErrors/invalid_ca_file358=== CONT TestSetClientTLSErrors/missing_key_file359=== CONT TestSetClientTLSErrors/missing_ca_file360--- PASS: TestSetClientTLSErrors (0.03s)361 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)362 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)363 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)364 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3652026/09/18 13:10:00 http: TLS handshake error from 127.0.0.1:48252: remote error: tls: bad certificate366--- PASS: TestDumpPathSingleFile (0.04s)367--- PASS: TestSetClientTLS (0.03s)368 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)369 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)370 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)371--- PASS: TestStreamPushRequestLine (0.05s)372--- PASS: TestDumpPathWriterError (0.05s)373--- PASS: TestCaseHackSuffix (0.06s)374--- PASS: TestDumpPathMatchesNix (0.10s)375--- PASS: TestStreamPushBatchesUnderLoad (0.10s)376--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)377PASS378Running server tests...379The files belonging to this database system will be owned by user "nixbld".380This user must also own the server process.381382The database cluster will be initialized with locale "C".383The default database encoding has accordingly been set to "SQL_ASCII".384The default text search configuration will be set to "english".385386Data page checksums are enabled.387388creating directory /build/postgres2219139376/data ... ok389creating subdirectories ... ok390selecting dynamic shared memory implementation ... posix391selecting default "max_connections" ... 100392selecting default "shared_buffers" ... 128MB393selecting default time zone ... UTC394creating configuration files ... ok395running bootstrap script ... ok396performing post-bootstrap initialization ... ok397syncing data to disk ... ok398399initdb: warning: enabling "trust" authentication for local connections400initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.401402Success. You can now start the database server using:403404 pg_ctl -D /build/postgres2219139376/data -l logfile start405406/build/postgres2219139376:5432 - no response4072026-09-18 13:10:02.683 UTC [126] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4082026-09-18 13:10:02.684 UTC [126] LOG: listening on Unix socket "/build/postgres2219139376/.s.PGSQL.5432"4092026-09-18 13:10:02.689 UTC [133] LOG: database system was shut down at 2026-09-18 13:10:02 UTC4102026-09-18 13:10:02.692 UTC [126] LOG: database system is ready to accept connections411/build/postgres2219139376:5432 - accepting connections412=== RUN TestService_AuthMiddleware413=== PAUSE TestService_AuthMiddleware414=== RUN TestService_AuthMiddleware_MTLSProxyHeader415=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader416=== RUN TestService_AuthMiddleware_MTLSBoundSubjects417=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects418=== RUN TestService_ReadAuthMiddleware419=== PAUSE TestService_ReadAuthMiddleware420=== RUN TestService_AuthMiddleware_OIDC421=== PAUSE TestService_AuthMiddleware_OIDC422=== RUN TestService_RequireScope_OIDC423=== PAUSE TestService_RequireScope_OIDC424=== RUN TestService_ReadScope_PublicByDefault425=== PAUSE TestService_ReadScope_PublicByDefault426=== RUN TestCacheConfigHandler427=== PAUSE TestCacheConfigHandler428=== RUN TestCacheStatsHandler429=== PAUSE TestCacheStatsHandler430=== RUN TestClaim_BuildWaitComplete431=== PAUSE TestClaim_BuildWaitComplete432=== RUN TestClaim_GCMarkedOutputCountsAsAbsent433=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent434=== RUN TestClaim_TooManyStreams435=== PAUSE TestClaim_TooManyStreams436=== RUN TestClaim_HolderDisconnectKeepsClaim437=== PAUSE TestClaim_HolderDisconnectKeepsClaim438=== RUN TestClaim_FailWakesWaitersButIsNotRemembered439=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered440=== RUN TestClaim_FailWithoutKindReleases441=== PAUSE TestClaim_FailWithoutKindReleases442=== RUN TestClaim_StaleHeartbeatStolen443=== PAUSE TestClaim_StaleHeartbeatStolen444=== RUN TestClaim_TwoInstances445=== PAUSE TestClaim_TwoInstances446=== RUN TestClaim_InputsTouched447=== PAUSE TestClaim_InputsTouched448=== RUN TestClaim_StreamsThroughServer449=== PAUSE TestClaim_StreamsThroughServer450=== RUN TestPresent451=== PAUSE TestPresent452=== RUN TestClientCADerivations453=== PAUSE TestClientCADerivations454=== RUN TestClientErrorHandling455=== PAUSE TestClientErrorHandling456=== RUN TestClientIntegration457=== PAUSE TestClientIntegration458=== RUN TestClientMultipleUploads459=== PAUSE TestClientMultipleUploads460=== RUN TestClientWithDependencies461=== PAUSE TestClientWithDependencies462=== RUN TestPinProtectsFromGC463=== PAUSE TestPinProtectsFromGC464=== RUN TestResolveDBConnectionString465=== PAUSE TestResolveDBConnectionString466=== RUN TestGCAdvisoryLockBlocksConcurrentRun4672026-09-18 13:10:03.079 UTC [372] ERROR: relation "goose_db_version" does not exist at character 364682026-09-18 13:10:03.079 UTC [372] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4692026/09/18 13:10:03 OK 20241026095416_initial_model.sql (12.41ms)4702026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)4712026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.3ms)4722026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)4732026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.22ms)4742026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000004752026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.96ms)4762026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.21ms)4772026/09/18 13:10:03 goose: up to current file version: 2478--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.17s)479=== RUN TestGCBugBareHashReferences480=== PAUSE TestGCBugBareHashReferences481=== RUN TestGCMetrics482=== PAUSE TestGCMetrics483=== RUN TestGCTaskStore_StartNew484=== PAUSE TestGCTaskStore_StartNew485=== RUN TestGCTaskStore_DeduplicateSameParams486=== PAUSE TestGCTaskStore_DeduplicateSameParams487=== RUN TestGCTaskStore_ConflictDifferentParams488=== PAUSE TestGCTaskStore_ConflictDifferentParams489=== RUN TestGCTaskStore_GetEmpty490=== PAUSE TestGCTaskStore_GetEmpty491=== RUN TestGCTaskStore_GetReturnsLatest492=== PAUSE TestGCTaskStore_GetReturnsLatest493=== RUN TestGCTaskStore_CompletedAllowsNewTask494=== PAUSE TestGCTaskStore_CompletedAllowsNewTask495=== RUN TestGCTaskStore_PhaseUpdates496=== PAUSE TestGCTaskStore_PhaseUpdates497=== RUN TestGCTaskStore_Fail498=== PAUSE TestGCTaskStore_Fail499=== RUN TestGracefulShutdownDrainsInflight500=== PAUSE TestGracefulShutdownDrainsInflight501=== RUN TestService_healthCheckHandler502=== PAUSE TestService_healthCheckHandler503=== RUN TestService_readinessHandler504=== PAUSE TestService_readinessHandler505=== RUN TestGenerateLandingPage506=== PAUSE TestGenerateLandingPage507=== RUN TestCacheConfigHandlerMaxNarSize508=== PAUSE TestCacheConfigHandlerMaxNarSize509=== RUN TestCreatePendingClosureRejectsOversizedNAR510=== PAUSE TestCreatePendingClosureRejectsOversizedNAR511=== RUN TestNARDeduplicationMetadataUploadBug512=== PAUSE TestNARDeduplicationMetadataUploadBug513=== RUN TestMetricsInventory514=== PAUSE TestMetricsInventory515=== RUN TestService_NativeMTLS516=== PAUSE TestService_NativeMTLS517=== RUN TestServerTLSConfig518=== PAUSE TestServerTLSConfig519=== RUN TestMultipartCleanup520=== PAUSE TestMultipartCleanup521=== RUN TestObjectStatsTrigger522=== PAUSE TestObjectStatsTrigger523=== RUN TestOrphanedObjectsGC524=== PAUSE TestOrphanedObjectsGC525=== RUN TestOrphanedObjectsGCStressTest526=== PAUSE TestOrphanedObjectsGCStressTest527=== RUN TestResurrectedObjectNotDeleted528=== PAUSE TestResurrectedObjectNotDeleted529=== RUN TestParseSingleRange530=== PAUSE TestParseSingleRange531=== RUN TestIsValidCachePath532=== PAUSE TestIsValidCachePath533=== RUN TestReadProxyNarinfo534=== PAUSE TestReadProxyNarinfo535=== RUN TestReadProxyNarinfoAlreadyDecompressed536=== PAUSE TestReadProxyNarinfoAlreadyDecompressed537=== RUN TestReadProxyNarStreaming538=== PAUSE TestReadProxyNarStreaming539=== RUN TestReadProxy404540=== PAUSE TestReadProxy404541=== RUN TestReadProxyInvalidPath542=== PAUSE TestReadProxyInvalidPath543=== RUN TestReadProxyHead544=== PAUSE TestReadProxyHead545=== RUN TestReadProxyConditionalGet546=== PAUSE TestReadProxyConditionalGet547=== RUN TestReadProxyRootRedirectsToIndexHTML548=== PAUSE TestReadProxyRootRedirectsToIndexHTML549=== RUN TestReadProxyDisabled550=== PAUSE TestReadProxyDisabled551=== RUN TestReadRedirectNar552=== PAUSE TestReadRedirectNar553=== RUN TestReadRedirectKeepsNarinfoProxied554=== PAUSE TestReadRedirectKeepsNarinfoProxied555=== RUN TestReadProxyRangeRequest556=== PAUSE TestReadProxyRangeRequest557=== RUN TestReadRedirectUsesPublicS3URL558=== PAUSE TestReadRedirectUsesPublicS3URL559=== RUN TestRedundantMultipartUpload560=== PAUSE TestRedundantMultipartUpload561=== RUN TestCompleteMultipartUpload_ErrorButObjectExists562=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists563=== RUN TestCompletedNarNotReofferedAcrossClosures564=== PAUSE TestCompletedNarNotReofferedAcrossClosures565=== RUN TestPresignedUploadRegisteredBeforeCommit566=== PAUSE TestPresignedUploadRegisteredBeforeCommit567=== RUN TestService_Rustfstest568=== PAUSE TestService_Rustfstest569=== RUN TestParseSize570=== PAUSE TestParseSize571=== RUN TestSkippedUploadsHandler572=== PAUSE TestSkippedUploadsHandler573=== RUN TestSystemdListenerNotActivated574--- PASS: TestSystemdListenerNotActivated (0.00s)575=== RUN TestWatchdogBeatsWhenHealthy576--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)577=== RUN TestWatchdogSkipsWhenUnhealthy5782026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5802026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5812026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5822026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5832026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5842026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5852026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5862026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5872026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"588--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)589=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle590=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle591=== RUN TestProxyWriteTimeout592=== PAUSE TestProxyWriteTimeout593=== RUN TestIsValidUploadKey594=== PAUSE TestIsValidUploadKey595=== RUN TestUploadHandlersRejectInvalidKeys596=== PAUSE TestUploadHandlersRejectInvalidKeys597=== RUN TestUploadHandlersRejectOversizedBody598=== PAUSE TestUploadHandlersRejectOversizedBody599=== RUN TestService_cleanupPendingClosuresHandler600=== PAUSE TestService_cleanupPendingClosuresHandler601=== RUN TestService_createPendingClosureHandler602=== PAUSE TestService_createPendingClosureHandler603=== RUN TestService_verifyS3Integrity604=== PAUSE TestService_verifyS3Integrity605=== RUN TestCompleteMultipartUnregistered606=== PAUSE TestCompleteMultipartUnregistered607=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT608=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT609=== CONT TestService_createPendingClosureHandler610=== CONT TestIsValidUploadKey611=== RUN TestIsValidUploadKey/narinfo612=== CONT TestService_AuthMiddleware613=== CONT TestGCTaskStore_GetReturnsLatest614--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)615=== CONT TestClientIntegration616=== CONT TestService_readinessHandler617=== CONT TestService_healthCheckHandler618=== CONT TestGracefulShutdownDrainsInflight619=== CONT TestGenerateLandingPage620=== CONT TestGCTaskStore_Fail621--- PASS: TestGCTaskStore_Fail (0.00s)622=== CONT TestClientErrorHandling623=== RUN TestClientErrorHandling/InvalidStorePath6242026/09/18 13:10:03 INFO Starting HTTP server address=127.0.0.1:46573625=== CONT TestService_cleanupPendingClosuresHandler626=== CONT TestUploadHandlersRejectOversizedBody627=== CONT TestGCTaskStore_PhaseUpdates628--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)629=== CONT TestClientCADerivations630=== CONT TestUploadHandlersRejectInvalidKeys631=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info632=== CONT TestGCTaskStore_CompletedAllowsNewTask633--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)634=== CONT TestGCTaskStore_GetEmpty635=== CONT TestGCTaskStore_ConflictDifferentParams636=== CONT TestGCTaskStore_DeduplicateSameParams637=== CONT TestGCTaskStore_StartNew638=== CONT TestGCMetrics639=== CONT TestGCBugBareHashReferences640=== CONT TestResolveDBConnectionString641=== CONT TestPinProtectsFromGC642=== CONT TestClientWithDependencies643=== CONT TestClientMultipleUploads644=== PAUSE TestIsValidUploadKey/narinfo645=== PAUSE TestClientErrorHandling/InvalidStorePath646=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info647=== CONT TestPresent648--- PASS: TestGCTaskStore_GetEmpty (0.00s)649--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)650=== CONT TestClaim_StreamsThroughServer651=== CONT TestClaim_InputsTouched652=== CONT TestClaim_TwoInstances653=== CONT TestClaim_StaleHeartbeatStolen654--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)655--- PASS: TestGCTaskStore_StartNew (0.00s)656--- PASS: TestGenerateLandingPage (0.01s)657=== CONT TestClaim_FailWithoutKindReleases6582026/09/18 13:10:03 INFO Shutdown signal received, draining in-flight requests timeout=10s659=== RUN TestClientErrorHandling/InvalidAuthToken660=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal661=== PAUSE TestClientErrorHandling/InvalidAuthToken662=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal663=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key664=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key665--- PASS: TestGracefulShutdownDrainsInflight (0.07s)666=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key667=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key668=== RUN TestIsValidUploadKey/nar_zst669=== PAUSE TestIsValidUploadKey/nar_zst670=== RUN TestClientErrorHandling/ServerNotAvailable671=== RUN TestResolveDBConnectionString/flag_wins672=== PAUSE TestResolveDBConnectionString/flag_wins673=== CONT TestClaim_FailWakesWaitersButIsNotRemembered674=== RUN TestResolveDBConnectionString/file_when_flag_empty675=== PAUSE TestResolveDBConnectionString/file_when_flag_empty676=== RUN TestResolveDBConnectionString/missing_file_is_an_error677=== CONT TestClaim_HolderDisconnectKeepsClaim678=== RUN TestIsValidUploadKey/nar_xz679=== PAUSE TestIsValidUploadKey/nar_xz680=== RUN TestIsValidUploadKey/nar_plain681=== PAUSE TestIsValidUploadKey/nar_plain682=== PAUSE TestClientErrorHandling/ServerNotAvailable683=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error684=== RUN TestResolveDBConnectionString/PGHOST_allows_empty685=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty686=== RUN TestResolveDBConnectionString/nothing_configured687=== PAUSE TestResolveDBConnectionString/nothing_configured688=== RUN TestIsValidUploadKey/listing689=== PAUSE TestIsValidUploadKey/listing690=== CONT TestClaim_TooManyStreams691=== RUN TestIsValidUploadKey/build_log692=== PAUSE TestIsValidUploadKey/build_log693=== CONT TestClaim_GCMarkedOutputCountsAsAbsent694=== RUN TestIsValidUploadKey/build_log_home-manager_file695=== PAUSE TestIsValidUploadKey/build_log_home-manager_file696=== RUN TestIsValidUploadKey/build_log_plus_in_name697=== PAUSE TestIsValidUploadKey/build_log_plus_in_name698=== RUN TestIsValidUploadKey/build_log_question_mark699=== PAUSE TestIsValidUploadKey/build_log_question_mark700=== RUN TestIsValidUploadKey/build_log_equals701=== PAUSE TestIsValidUploadKey/build_log_equals702=== RUN TestIsValidUploadKey/realisation703=== PAUSE TestIsValidUploadKey/realisation704=== RUN TestIsValidUploadKey/realisation_plus_in_output705=== PAUSE TestIsValidUploadKey/realisation_plus_in_output706=== RUN TestIsValidUploadKey/nix-cache-info707=== PAUSE TestIsValidUploadKey/nix-cache-info708=== RUN TestIsValidUploadKey/index.html709=== PAUSE TestIsValidUploadKey/index.html710=== RUN TestIsValidUploadKey/narinfo_key,_nar_type711=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type712=== RUN TestIsValidUploadKey/nar_key,_narinfo_type713=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type714=== RUN TestIsValidUploadKey/listing_key,_narinfo_type715=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type716=== RUN TestIsValidUploadKey/traversal717=== PAUSE TestIsValidUploadKey/traversal718=== RUN TestIsValidUploadKey/traversal_nar719=== PAUSE TestIsValidUploadKey/traversal_nar720=== RUN TestIsValidUploadKey/absolute721=== PAUSE TestIsValidUploadKey/absolute722=== RUN TestIsValidUploadKey/empty_key723=== PAUSE TestIsValidUploadKey/empty_key724=== RUN TestIsValidUploadKey/unknown_type725=== PAUSE TestIsValidUploadKey/unknown_type726=== CONT TestClaim_BuildWaitComplete7272026-09-18 13:10:03.509 UTC [443] ERROR: relation "goose_db_version" does not exist at character 367282026-09-18 13:10:03.509 UTC [443] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7292026-09-18 13:10:03.509 UTC [444] ERROR: relation "goose_db_version" does not exist at character 367302026-09-18 13:10:03.509 UTC [444] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7312026-09-18 13:10:03.512 UTC [445] ERROR: relation "goose_db_version" does not exist at character 367322026-09-18 13:10:03.512 UTC [445] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7332026-09-18 13:10:03.517 UTC [446] ERROR: relation "goose_db_version" does not exist at character 367342026-09-18 13:10:03.517 UTC [446] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7352026-09-18 13:10:03.524 UTC [447] ERROR: relation "goose_db_version" does not exist at character 367362026-09-18 13:10:03.524 UTC [447] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7372026-09-18 13:10:03.548 UTC [448] ERROR: relation "goose_db_version" does not exist at character 367382026-09-18 13:10:03.548 UTC [448] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC739=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure740=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure741=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart742=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart743=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts744=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts745=== CONT TestCacheStatsHandler7462026/09/18 13:10:03 OK 20241026095416_initial_model.sql (54.4ms)7472026-09-18 13:10:03.579 UTC [450] ERROR: relation "goose_db_version" does not exist at character 367482026-09-18 13:10:03.579 UTC [450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7492026/09/18 13:10:03 OK 20241026095416_initial_model.sql (65.95ms)7502026/09/18 13:10:03 OK 20241026095416_initial_model.sql (51.76ms)7512026/09/18 13:10:03 OK 20241026095416_initial_model.sql (65.88ms)7522026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (13.34ms)7532026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (4.91ms)7542026/09/18 13:10:03 OK 20241026095416_initial_model.sql (53.04ms)7552026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (4ms)7562026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (4ms)7572026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)7582026-09-18 13:10:03.598 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367592026-09-18 13:10:03.598 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7602026/09/18 13:10:03 OK 20251218171726_add_pins.sql (7.68ms)7612026/09/18 13:10:03 OK 20241026095416_initial_model.sql (24.98ms)7622026/09/18 13:10:03 OK 20251218171726_add_pins.sql (6.68ms)7632026/09/18 13:10:03 OK 20251218171726_add_pins.sql (8ms)7642026/09/18 13:10:03 OK 20251218171726_add_pins.sql (7.97ms)7652026/09/18 13:10:03 OK 20251218171726_add_pins.sql (5.65ms)7662026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)7672026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (7.73ms)7682026/09/18 13:10:03 OK 20251218171726_add_pins.sql (4.53ms)7692026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (8.9ms)7702026/09/18 13:10:03 OK 20241026095416_initial_model.sql (15.29ms)7712026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (7.56ms)7722026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (8.88ms)7732026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (7.6ms)7742026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (9.76ms)7752026/09/18 13:10:03 OK 20260905000000_add_claims.sql (15.41ms)7762026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007772026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (13.11ms)7782026/09/18 13:10:03 OK 20260905000000_add_claims.sql (12.6ms)7792026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007802026/09/18 13:10:03 OK 20260905000000_add_claims.sql (14.36ms)7812026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007822026-09-18 13:10:03.626 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367832026-09-18 13:10:03.626 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7842026/09/18 13:10:03 OK 20260905000000_add_claims.sql (16.73ms)7852026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007862026/09/18 13:10:03 OK 20260905000000_add_claims.sql (16.59ms)7872026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007882026/09/18 13:10:03 OK 20251218171726_add_pins.sql (8.68ms)7892026/09/18 13:10:03 OK 1_commit_pending_closure.sql (6.87ms)7902026/09/18 13:10:03 OK 1_commit_pending_closure.sql (5.68ms)7912026/09/18 13:10:03 OK 1_commit_pending_closure.sql (5.32ms)7922026/09/18 13:10:03 OK 20260905000000_add_claims.sql (8.15ms)7932026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007942026/09/18 13:10:03 OK 20241026095416_initial_model.sql (25.87ms)7952026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.59ms)7962026/09/18 13:10:03 OK 2_object_stats_trigger.sql (3.75ms)7972026/09/18 13:10:03 goose: up to current file version: 27982026/09/18 13:10:03 OK 1_commit_pending_closure.sql (5.64ms)7992026/09/18 13:10:03 OK 2_object_stats_trigger.sql (3.71ms)8002026/09/18 13:10:03 goose: up to current file version: 28012026/09/18 13:10:03 OK 2_object_stats_trigger.sql (3.62ms)8022026/09/18 13:10:03 goose: up to current file version: 28032026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)8042026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.33ms)8052026/09/18 13:10:03 goose: up to current file version: 28062026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.62ms)8072026/09/18 13:10:03 goose: up to current file version: 28082026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.58ms)8092026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.95ms)8102026/09/18 13:10:03 goose: up to current file version: 28112026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (3.65ms)8122026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.98ms)8132026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008142026-09-18 13:10:03.645 UTC [456] ERROR: relation "goose_db_version" does not exist at character 368152026-09-18 13:10:03.645 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/09/18 13:10:03 OK 20251218171726_add_pins.sql (5.87ms)8172026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.76ms)8182026/09/18 13:10:03 OK 2_object_stats_trigger.sql (3.12ms)8192026/09/18 13:10:03 goose: up to current file version: 28202026/09/18 13:10:03 OK 20241026095416_initial_model.sql (16.08ms)8212026-09-18 13:10:03.653 UTC [457] ERROR: relation "goose_db_version" does not exist at character 368222026-09-18 13:10:03.653 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8232026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (5.68ms)8242026-09-18 13:10:03.655 UTC [459] ERROR: relation "goose_db_version" does not exist at character 368252026-09-18 13:10:03.655 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8262026-09-18 13:10:03.655 UTC [458] ERROR: relation "goose_db_version" does not exist at character 368272026-09-18 13:10:03.655 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8282026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.84ms)8292026-09-18 13:10:03.656 UTC [460] ERROR: relation "goose_db_version" does not exist at character 368302026-09-18 13:10:03.656 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-09-18 13:10:03.658 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368322026-09-18 13:10:03.658 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026-09-18 13:10:03.661 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368342026-09-18 13:10:03.661 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026-09-18 13:10:03.662 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368362026-09-18 13:10:03.662 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026/09/18 13:10:03 OK 20260905000000_add_claims.sql (13.7ms)8382026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008392026/09/18 13:10:03 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"840--- PASS: TestService_AuthMiddleware (0.28s)841=== CONT TestCacheConfigHandler842=== RUN TestCacheConfigHandler/full_config,_no_issuer843=== PAUSE TestCacheConfigHandler/full_config,_no_issuer844=== RUN TestCacheConfigHandler/no_cache_url_configured845=== PAUSE TestCacheConfigHandler/no_cache_url_configured846=== RUN TestCacheConfigHandler/no_signing_keys847=== PAUSE TestCacheConfigHandler/no_signing_keys848=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator849=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator850=== CONT TestService_ReadScope_PublicByDefault8512026/09/18 13:10:03 OK 20251218171726_add_pins.sql (12.8ms)8522026/09/18 13:10:03 OK 20241026095416_initial_model.sql (14.15ms)8532026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.35ms)8542026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)8552026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.64ms)8562026/09/18 13:10:03 goose: up to current file version: 28572026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (5.95ms)8582026/09/18 13:10:03 OK 20251218171726_add_pins.sql (5.16ms)8592026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.92ms)8602026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008612026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)8622026/09/18 13:10:03 OK 20241026095416_initial_model.sql (12.3ms)8632026/09/18 13:10:03 OK 20241026095416_initial_model.sql (12.01ms)8642026-09-18 13:10:03.683 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368652026-09-18 13:10:03.683 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8662026-09-18 13:10:03.683 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368672026-09-18 13:10:03.683 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8682026/09/18 13:10:03 OK 20241026095416_initial_model.sql (13.82ms)8692026/09/18 13:10:03 OK 20241026095416_initial_model.sql (13.83ms)8702026-09-18 13:10:03.684 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368712026-09-18 13:10:03.684 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8722026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.99ms)8732026/09/18 13:10:03 OK 20241026095416_initial_model.sql (15.36ms)8742026-09-18 13:10:03.685 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368752026-09-18 13:10:03.685 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8762026/09/18 13:10:03 OK 20241026095416_initial_model.sql (14.85ms)8772026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.33ms)8782026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008792026/09/18 13:10:03 OK 20241026095416_initial_model.sql (16.93ms)8802026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)8812026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (4ms)8822026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (4.1ms)8832026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)8842026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.3ms)8852026/09/18 13:10:03 goose: up to current file version: 28862026-09-18 13:10:03.687 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368872026-09-18 13:10:03.687 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8882026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)8892026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)8902026-09-18 13:10:03.688 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368912026-09-18 13:10:03.688 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8922026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)8932026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.47ms)8942026/09/18 13:10:03 OK 20251218171726_add_pins.sql (5.9ms)8952026/09/18 13:10:03 OK 20251218171726_add_pins.sql (5.8ms)8962026/09/18 13:10:03 OK 20251218171726_add_pins.sql (5.95ms)8972026/09/18 13:10:03 OK 20251218171726_add_pins.sql (5.08ms)8982026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.79ms)8992026/09/18 13:10:03 goose: up to current file version: 29002026/09/18 13:10:03 OK 20251218171726_add_pins.sql (7ms)9012026/09/18 13:10:03 OK 20251218171726_add_pins.sql (4.18ms)9022026/09/18 13:10:03 OK 20251218171726_add_pins.sql (6.19ms)9032026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (5.58ms)9042026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (7.23ms)9052026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)9062026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (6.07ms)9072026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (5.91ms)9082026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (7.2ms)9092026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (7.09ms)9102026/09/18 13:10:03 WARN readiness check failed error="closed pool"911--- PASS: TestService_readinessHandler (0.32s)912=== CONT TestService_RequireScope_OIDC9132026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.92ms)9142026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009152026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.36ms)9162026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009172026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.17ms)9182026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.47ms)9192026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009202026/09/18 13:10:03 OK 20241026095416_initial_model.sql (12.21ms)9212026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009222026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.34ms)9232026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009242026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.1ms)9252026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009262026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.3ms)9272026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009282026/09/18 13:10:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35503/oidc9292026/09/18 13:10:03 OK 20241026095416_initial_model.sql (14.83ms)9302026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.08ms)9312026/09/18 13:10:03 OK 20241026095416_initial_model.sql (15.65ms)9322026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.14ms)9332026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.31ms)9342026/09/18 13:10:03 OK 20241026095416_initial_model.sql (12.95ms)9352026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)9362026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)9372026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.13ms)9382026/09/18 13:10:03 OK 20241026095416_initial_model.sql (14.17ms)9392026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.44ms)9402026/09/18 13:10:03 goose: up to current file version: 29412026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.07ms)9422026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.25ms)9432026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.6ms)9442026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.79ms)9452026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.31ms)9462026/09/18 13:10:03 goose: up to current file version: 29472026/09/18 13:10:03 OK 20241026095416_initial_model.sql (15.46ms)9482026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.53ms)9492026/09/18 13:10:03 goose: up to current file version: 29502026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)9512026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2ms)9522026/09/18 13:10:03 goose: up to current file version: 29532026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.97ms)9542026/09/18 13:10:03 goose: up to current file version: 29552026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.21ms)9562026/09/18 13:10:03 goose: up to current file version: 29572026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)9582026/09/18 13:10:03 OK 20251218171726_add_pins.sql (4.26ms)9592026/09/18 13:10:03 OK 2_object_stats_trigger.sql (3.09ms)9602026/09/18 13:10:03 goose: up to current file version: 29612026/09/18 13:10:03 OK 20251218171726_add_pins.sql (4.22ms)9622026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (3.17ms)9632026/09/18 13:10:03 OK 20251218171726_add_pins.sql (4.83ms)9642026/09/18 13:10:03 OK 20251218171726_add_pins.sql (4.58ms)9652026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.72ms)9662026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)9672026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.74ms)9682026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.87ms)9692026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)9702026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)9712026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.49ms)9722026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009732026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (5.35ms)9742026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)9752026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.63ms)9762026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009772026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.03ms)9782026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009792026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.46ms)9802026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009812026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.28ms)9822026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.7ms)9832026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009842026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.58ms)9852026/09/18 13:10:03 goose: up to current file version: 29862026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.49ms)9872026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.35ms)9882026-09-18 13:10:03.728 UTC [475] ERROR: relation "goose_db_version" does not exist at character 369892026-09-18 13:10:03.728 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9902026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.33ms)9912026/09/18 13:10:03 OK 20260905000000_add_claims.sql (6.05ms)9922026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009932026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.21ms)9942026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.83ms)9952026/09/18 13:10:03 goose: up to current file version: 29962026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.88ms)9972026/09/18 13:10:03 goose: up to current file version: 29982026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.11ms)9992026/09/18 13:10:03 goose: up to current file version: 210002026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.28ms)10012026/09/18 13:10:03 goose: up to current file version: 210022026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.41ms)10032026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.06ms)10042026/09/18 13:10:03 goose: up to current file version: 210052026/09/18 13:10:03 OK 20241026095416_initial_model.sql (8.74ms)1006--- PASS: TestService_healthCheckHandler (0.36s)1007=== CONT TestService_AuthMiddleware_OIDC10082026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)10092026/09/18 13:10:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46817/oidc10102026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.18ms)10112026-09-18 13:10:03.748 UTC [476] ERROR: relation "goose_db_version" does not exist at character 3610122026-09-18 13:10:03.748 UTC [476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10132026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)10142026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.25ms)10152026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000010162026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.8ms)10172026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.77ms)10182026/09/18 13:10:03 goose: up to current file version: 210192026/09/18 13:10:03 OK 20241026095416_initial_model.sql (12.17ms)10202026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)10212026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures10222026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures10232026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures10242026/09/18 13:10:03 OK 20251218171726_add_pins.sql (11.83ms)10252026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)10262026-09-18 13:10:03.791 UTC [479] ERROR: relation "goose_db_version" does not exist at character 3610272026-09-18 13:10:03.791 UTC [479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10282026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.51ms)10292026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000010302026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.35ms)10312026/09/18 13:10:03 OK 2_object_stats_trigger.sql (3.07ms)10322026/09/18 13:10:03 goose: up to current file version: 210332026/09/18 13:10:03 INFO Received cleanup request method=DELETE path=/api/pending_closures10342026/09/18 13:10:03 OK 20241026095416_initial_model.sql (11.52ms)10352026/09/18 13:10:03 INFO Aborted multipart uploads count=010362026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)10372026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures10382026/09/18 13:10:03 OK 20251218171726_add_pins.sql (2.96ms)10392026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)10402026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.58ms)10412026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000010422026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.22ms)10432026/09/18 13:10:03 INFO Received cleanup request method=DELETE path=/api/pending_closures10442026-09-18 13:10:03.825 UTC [480] ERROR: relation "goose_db_version" does not exist at character 3610452026-09-18 13:10:03.825 UTC [480] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10462026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.51ms)10472026/09/18 13:10:03 goose: up to current file version: 210482026/09/18 13:10:03 INFO Aborted multipart uploads count=110492026/09/18 13:10:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10502026-09-18 13:10:03.832 UTC [446] ERROR: Closure does not exist: id=110512026-09-18 13:10:03.832 UTC [446] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10522026-09-18 13:10:03.832 UTC [446] STATEMENT: -- name: CommitPendingClosure :exec1053 SELECT commit_pending_closure($1::bigint)1054 1055--- PASS: TestService_cleanupPendingClosuresHandler (0.45s)1056=== CONT TestService_ReadAuthMiddleware10572026/09/18 13:10:03 WARN claim: cannot clear write deadline error="feature not supported"10582026/09/18 13:10:03 OK 20241026095416_initial_model.sql (10.83ms)10592026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)10602026/09/18 13:10:03 OK 20251218171726_add_pins.sql (4.19ms)10612026/09/18 13:10:03 WARN claim: cannot clear write deadline error="feature not supported"1062--- PASS: TestClaim_FailWithoutKindReleases (0.46s)1063=== CONT TestService_AuthMiddleware_MTLSBoundSubjects10642026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)10652026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.2ms)10662026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000010672026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.06ms)10682026/09/18 13:10:03 OK 2_object_stats_trigger.sql (3.12ms)10692026/09/18 13:10:03 goose: up to current file version: 210702026/09/18 13:10:03 WARN claim: cannot clear write deadline error="feature not supported"10712026/09/18 13:10:03 WARN claim: cannot clear write deadline error="feature not supported"10722026/09/18 13:10:03 WARN claim: cannot clear write deadline error="feature not supported"10732026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures10742026-09-18 13:10:03.911 UTC [489] ERROR: relation "goose_db_version" does not exist at character 3610752026-09-18 13:10:03.911 UTC [489] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10762026-09-18 13:10:03.929 UTC [491] ERROR: relation "goose_db_version" does not exist at character 3610772026-09-18 13:10:03.929 UTC [491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10782026/09/18 13:10:03 OK 20241026095416_initial_model.sql (11.3ms)10792026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)10802026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures10812026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.47ms)10822026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)10832026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.02ms)10842026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000010852026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.06ms)10862026/09/18 13:10:03 OK 20241026095416_initial_model.sql (11.26ms)10872026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.12ms)10882026/09/18 13:10:03 goose: up to current file version: 210892026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)10902026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.2ms)10912026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.18ms)1092=== NAME TestClientIntegration1093 client_integration_test.go:286: Created store path: /build/TestClientIntegration2941603834/002/store/sxx0jxgvgd9y4p5mz8g97f0m8xzwir9f-test-file.txt10942026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.83ms)10952026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000010962026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.85ms)10972026/09/18 13:10:03 OK 2_object_stats_trigger.sql (971.35µs)10982026/09/18 13:10:03 goose: up to current file version: 210992026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"11002026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11012026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"1102--- PASS: TestClaim_StaleHeartbeatStolen (0.65s)1103=== CONT TestService_AuthMiddleware_MTLSProxyHeader11042026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures11052026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11062026/09/18 13:10:04 INFO Uploading sxx0jxgvgd9y4p5mz8g97f0m8xzwir9f-test-file.txt (152B)1107=== NAME TestClientWithDependencies1108 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1230049219/001/store/vivikhm4zqf61373a7zd1f53anqdlzqh-test-script11092026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11102026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures11112026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11122026/09/18 13:10:04 WARN Failed to register uploaded object key=sxx0jxgvgd9y4p5mz8g97f0m8xzwir9f.ls error="server returned 404: 404 page not found\n"11132026/09/18 13:10:04 INFO Signed narinfos id=1 count=111142026/09/18 13:10:04 INFO Uploading 1 narinfos11152026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11162026/09/18 13:10:04 WARN Failed to register uploaded object key=sxx0jxgvgd9y4p5mz8g97f0m8xzwir9f.narinfo error="server returned 404: 404 page not found\n"11172026/09/18 13:10:04 INFO Completed upload id=111182026/09/18 13:10:04 INFO Upload complete. (107ms)11192026-09-18 13:10:04.115 UTC [606] ERROR: relation "goose_db_version" does not exist at character 3611202026-09-18 13:10:04.115 UTC [606] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1121 client_integration_test.go:615: Found 1 dependencies (including self)11222026/09/18 13:10:04 OK 20241026095416_initial_model.sql (10.13ms)11232026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)11242026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.86ms)11252026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.18ms)11262026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3.88ms)11272026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000011282026/09/18 13:10:04 INFO All 1 paths already cached11292026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.18ms)1130=== NAME TestClientIntegration11312026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.03ms)1132 client_integration_test.go:312: Retrieved narinfo from S3:11332026/09/18 13:10:04 goose: up to current file version: 21134 StorePath: /build/TestClientIntegration2941603834/002/store/sxx0jxgvgd9y4p5mz8g97f0m8xzwir9f-test-file.txt1135 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1136 Compression: zstd1137 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11138 NarSize: 1521139 References: 1140 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11141 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1142 client_integration_test.go:313: Decompressed .ls content (64 bytes):1143 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1144 client_integration_test.go:316: Testing garbage collection...11452026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11462026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures11472026/09/18 13:10:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures11482026/09/18 13:10:04 INFO Garbage collection started11492026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11502026/09/18 13:10:04 INFO Uploading vivikhm4zqf61373a7zd1f53anqdlzqh-test-script (136B)11512026/09/18 13:10:04 INFO Aborted multipart uploads count=011522026/09/18 13:10:04 WARN Force mode enabled - objects will be deleted immediately without grace period11532026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11542026/09/18 13:10:04 WARN Failed to register uploaded object key=log/8kd6scmvr2y26678ir30xvbnmvp8na83-test-script.drv error="server returned 404: 404 page not found\n"1155=== NAME TestClientCADerivations1156 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3571336756/001/store/6cffnidzr3h8kxi8fzldiah15h3wvsx5-ca-test11572026/09/18 13:10:04 INFO Aborted multipart uploads count=011582026/09/18 13:10:04 WARN Force mode enabled - objects will be deleted immediately without grace period11592026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11602026/09/18 13:10:04 WARN Failed to register uploaded object key=vivikhm4zqf61373a7zd1f53anqdlzqh.ls error="server returned 404: 404 page not found\n"11612026/09/18 13:10:04 INFO Signed narinfos id=1 count=111622026/09/18 13:10:04 INFO Uploading 1 narinfos11632026/09/18 13:10:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011642026/09/18 13:10:04 INFO Vacuumed table table=pending_closures11652026/09/18 13:10:04 INFO Vacuumed table table=pending_objects11662026/09/18 13:10:04 INFO Vacuumed table table=multipart_uploads11672026/09/18 13:10:04 INFO Vacuumed table table=closures11682026/09/18 13:10:04 INFO Vacuumed table table=objects11692026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11702026/09/18 13:10:04 WARN Failed to register uploaded object key=vivikhm4zqf61373a7zd1f53anqdlzqh.narinfo error="server returned 404: 404 page not found\n"1171--- PASS: TestGCMetrics (0.84s)11722026/09/18 13:10:04 INFO Completed upload id=11173=== CONT TestReadProxyInvalidPath11742026/09/18 13:10:04 INFO Upload complete. (77ms)11752026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures1176=== NAME TestClientWithDependencies1177 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1230049219/001/store) requires matching store prefix1178--- PASS: TestClientWithDependencies (0.85s)1179=== CONT TestProxyWriteTimeout1180=== RUN TestProxyWriteTimeout/narinfo1181=== PAUSE TestProxyWriteTimeout/narinfo1182=== RUN TestProxyWriteTimeout/1_GiB_nar1183=== PAUSE TestProxyWriteTimeout/1_GiB_nar1184=== RUN TestProxyWriteTimeout/10_GiB_nar1185=== PAUSE TestProxyWriteTimeout/10_GiB_nar1186=== RUN TestProxyWriteTimeout/unknown_size1187=== PAUSE TestProxyWriteTimeout/unknown_size1188=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1189=== NAME TestClientCADerivations1190 client_ca_test.go:139: Found 1 dependencies (including self)1191=== NAME TestPinProtectsFromGC1192 client_integration_test.go:667: Pinned store path: /build/TestPinProtectsFromGC3229934162/001/store/78251yzi5xhslh7mrpwqh8mf2zhm0y9g-pinned-file.txt1193 client_integration_test.go:668: Unpinned store path: /build/TestPinProtectsFromGC3229934162/001/store/7l628j16jkyprawi3zxpq5f2byh9gxaf-unpinned-file.txt11942026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11952026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"11962026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2LmVjZDk5OTYxLWZhYzctNDJjOS04ZTUyLTQ5MTZiNzAzYjNkNHgxNzg5NzM3MDAzNzkxNzcyMDQ0 parts=1011972026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1198--- PASS: TestGCBugBareHashReferences (0.92s)1199=== CONT TestSkippedUploadsHandler12002026/09/18 13:10:04 INFO Client skipped oversized paths paths=3 nar_bytes=500000000012012026/09/18 13:10:04 INFO Completed upload id=112022026/09/18 13:10:04 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012032026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures1204=== NAME TestClientMultipleUploads1205 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2013316258/001/store/76fha795mqn7yr2givhjmh4h2scqkk3b-test-file-0.txt12062026-09-18 13:10:04.313 UTC [864] ERROR: relation "goose_db_version" does not exist at character 3612072026-09-18 13:10:04.313 UTC [864] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12082026/09/18 13:10:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures1209--- PASS: TestClaim_TooManyStreams (0.86s)1210=== CONT TestParseSize1211--- PASS: TestParseSize (0.00s)1212=== CONT TestService_Rustfstest1213--- PASS: TestSkippedUploadsHandler (0.01s)1214=== CONT TestPresignedUploadRegisteredBeforeCommit12152026/09/18 13:10:04 INFO Aborted multipart uploads count=012162026-09-18 13:10:04.331 UTC [871] ERROR: relation "goose_db_version" does not exist at character 3612172026-09-18 13:10:04.331 UTC [871] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12182026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"12192026/09/18 13:10:04 OK 20241026095416_initial_model.sql (11.9ms)12202026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12212026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12222026/09/18 13:10:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=012232026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (3.5ms)12242026/09/18 13:10:04 INFO Vacuumed table table=pending_closures12252026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.92ms)12262026/09/18 13:10:04 INFO Vacuumed table table=pending_objects12272026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"12282026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)12292026/09/18 13:10:04 INFO Vacuumed table table=multipart_uploads12302026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.93ms)12312026/09/18 13:10:04 goose: successfully migrated database to version: 202609050000001232=== NAME TestClientMultipleUploads1233 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2013316258/001/store/bcsw3rf64rn7pzwsrgsflpwb48n3bq94-test-file-1.txt12342026/09/18 13:10:04 INFO Vacuumed table table=closures12352026/09/18 13:10:04 OK 20241026095416_initial_model.sql (16.54ms)12362026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.37ms)12372026/09/18 13:10:04 INFO Vacuumed table table=objects12382026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2ms)12392026/09/18 13:10:04 goose: up to current file version: 212402026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)12412026/09/18 13:10:04 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001242--- PASS: TestService_createPendingClosureHandler (0.98s)1243=== CONT TestCompletedNarNotReofferedAcrossClosures12442026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"12452026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures12462026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures12472026/09/18 13:10:04 OK 20251218171726_add_pins.sql (12.63ms)12482026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12492026/09/18 13:10:04 INFO Uploading 6cffnidzr3h8kxi8fzldiah15h3wvsx5-ca-test (144B)12502026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12512026/09/18 13:10:04 INFO Uploading 78251yzi5xhslh7mrpwqh8mf2zhm0y9g-pinned-file.txt (128B)12522026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (6.03ms)12532026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"12542026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"12552026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.67ms)12562026/09/18 13:10:04 goose: successfully migrated database to version: 202609050000001257--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (0.93s)1258=== CONT TestCompleteMultipartUpload_ErrorButObjectExists12592026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12602026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"12612026/09/18 13:10:04 WARN Failed to register uploaded object key=log/f0ra2afr8xmq4csfwnnwn85v7pq46xb9-ca-test.drv error="server returned 404: 404 page not found\n"12622026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.28ms)1263=== NAME TestClientMultipleUploads1264 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2013316258/001/store/qb5399v3v823lwd4kp4hxfjm0zk23hmy-test-file-2.txt12652026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.94ms)12662026/09/18 13:10:04 goose: up to current file version: 212672026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12682026/09/18 13:10:04 WARN Failed to register uploaded object key=6cffnidzr3h8kxi8fzldiah15h3wvsx5.ls error="server returned 404: 404 page not found\n"12692026/09/18 13:10:04 INFO Signed narinfos id=1 count=112702026-09-18 13:10:04.389 UTC [979] ERROR: relation "goose_db_version" does not exist at character 3612712026-09-18 13:10:04.389 UTC [979] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12722026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12732026-09-18 13:10:04.390 UTC [981] ERROR: relation "goose_db_version" does not exist at character 3612742026-09-18 13:10:04.390 UTC [981] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12752026/09/18 13:10:04 INFO Uploading 1 narinfos12762026/09/18 13:10:04 WARN Failed to register uploaded object key=78251yzi5xhslh7mrpwqh8mf2zhm0y9g.ls error="server returned 404: 404 page not found\n"12772026/09/18 13:10:04 INFO Signed narinfos id=1 count=112782026/09/18 13:10:04 INFO Uploading 1 narinfos12792026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12802026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12812026/09/18 13:10:04 WARN Failed to register uploaded object key=6cffnidzr3h8kxi8fzldiah15h3wvsx5.narinfo error="server returned 404: 404 page not found\n"12822026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12832026/09/18 13:10:04 WARN Failed to register uploaded object key=78251yzi5xhslh7mrpwqh8mf2zhm0y9g.narinfo error="server returned 404: 404 page not found\n"12842026/09/18 13:10:04 INFO Completed upload id=112852026/09/18 13:10:04 INFO Upload complete. (114ms)12862026/09/18 13:10:04 INFO Completed upload id=112872026/09/18 13:10:04 INFO Upload complete. (107ms)12882026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"1289=== NAME TestClientCADerivations1290 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3571336756/001/store/6cffnidzr3h8kxi8fzldiah15h3wvsx5-ca-test1291 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1292 Compression: zstd1293 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1294 NarSize: 1441295 References: 1296 Deriver: /build/TestClientCADerivations3571336756/001/store/f0ra2afr8xmq4csfwnnwn85v7pq46xb9-ca-test.drv1297 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1298 client_ca_test.go:185: Checking for realisation files in S3...1299 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1300 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13012026/09/18 13:10:04 OK 20241026095416_initial_model.sql (12.18ms)13022026/09/18 13:10:04 OK 20241026095416_initial_model.sql (14.24ms)13032026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)13042026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (3.26ms)13052026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2Ljc4MzI2NjliLWMxOGQtNDgwNC1iY2MxLWUzNjE4NzBkZWFhNHgxNzg5NzM3MDAzODk4NDY5MjQ1 parts=1013062026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13072026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.6ms)13082026/09/18 13:10:04 INFO Signed narinfos id=1 count=113092026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13102026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.78ms)13112026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"13122026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"13132026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures13142026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)13152026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (6.65ms)13162026/09/18 13:10:04 INFO Completed upload id=113172026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.92ms)13182026/09/18 13:10:04 goose: successfully migrated database to version: 202609050000001319--- PASS: TestClaim_TwoInstances (1.04s)1320=== CONT TestRedundantMultipartUpload13212026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.71ms)13222026/09/18 13:10:04 OK 20260905000000_add_claims.sql (5.51ms)13232026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013242026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.19ms)13252026/09/18 13:10:04 goose: up to current file version: 213262026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.3ms)13272026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13282026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.95ms)13292026/09/18 13:10:04 goose: up to current file version: 213302026-09-18 13:10:04.450 UTC [1048] ERROR: relation "goose_db_version" does not exist at character 3613312026-09-18 13:10:04.450 UTC [1048] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13322026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2LmVmOGIxMmViLTVmOGUtNGRmNi04ZmIzLTljODBhOThjZTZhZXgxNzg5NzM3MDAzOTUwMTIzMzYw parts=1013332026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1334--- PASS: TestCacheStatsHandler (0.90s)1335=== CONT TestReadRedirectUsesPublicS3URL13362026/09/18 13:10:04 INFO Completed upload id=113372026-09-18 13:10:04.467 UTC [1051] ERROR: relation "goose_db_version" does not exist at character 3613382026-09-18 13:10:04.467 UTC [1051] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13392026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"13402026/09/18 13:10:04 OK 20241026095416_initial_model.sql (12.98ms)13412026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13422026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)13432026/09/18 13:10:04 OK 20251218171726_add_pins.sql (8.05ms)13442026/09/18 13:10:04 INFO Aborted multipart uploads count=013452026/09/18 13:10:04 WARN Force mode enabled - objects will be deleted immediately without grace period13462026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13472026/09/18 13:10:04 OK 20241026095416_initial_model.sql (12.05ms)13482026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.43ms)1349--- PASS: TestService_ReadScope_PublicByDefault (0.82s)1350=== CONT TestCompleteMultipartUnregistered13512026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)13522026/09/18 13:10:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013532026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.93ms)13542026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013552026/09/18 13:10:04 OK 20251218171726_add_pins.sql (5.03ms)13562026/09/18 13:10:04 INFO Vacuumed table table=pending_closures13572026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.23ms)13582026/09/18 13:10:04 OK 2_object_stats_trigger.sql (9.6ms)13592026/09/18 13:10:04 goose: up to current file version: 213602026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (11.61ms)13612026/09/18 13:10:04 INFO Vacuumed table table=pending_objects13622026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures13632026/09/18 13:10:04 OK 20260905000000_add_claims.sql (5.5ms)13642026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013652026/09/18 13:10:04 INFO Vacuumed table table=multipart_uploads13662026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.97ms)13672026/09/18 13:10:04 INFO Vacuumed table table=closures13682026/09/18 13:10:04 OK 2_object_stats_trigger.sql (4.07ms)13692026/09/18 13:10:04 goose: up to current file version: 213702026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures13712026/09/18 13:10:04 INFO Vacuumed table table=objects13722026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures13732026-09-18 13:10:04.522 UTC [1175] ERROR: relation "goose_db_version" does not exist at character 3613742026-09-18 13:10:04.522 UTC [1175] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1375--- PASS: TestClaim_InputsTouched (1.13s)1376=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT13772026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures13782026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13792026/09/18 13:10:04 INFO Uploading 7l628j16jkyprawi3zxpq5f2byh9gxaf-unpinned-file.txt (128B)13802026/09/18 13:10:04 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13812026/09/18 13:10:04 INFO Uploading bcsw3rf64rn7pzwsrgsflpwb48n3bq94-test-file-1.txt (160B)13822026/09/18 13:10:04 INFO Uploading 76fha795mqn7yr2givhjmh4h2scqkk3b-test-file-0.txt (160B)13832026/09/18 13:10:04 INFO Uploading qb5399v3v823lwd4kp4hxfjm0zk23hmy-test-file-2.txt (160B)13842026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13852026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13862026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13872026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13882026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13892026/09/18 13:10:04 WARN Failed to register uploaded object key=7l628j16jkyprawi3zxpq5f2byh9gxaf.ls error="server returned 404: 404 page not found\n"13902026/09/18 13:10:04 INFO Signed narinfos id=2 count=113912026/09/18 13:10:04 INFO Uploading 1 narinfos13922026/09/18 13:10:04 OK 20241026095416_initial_model.sql (11.23ms)13932026/09/18 13:10:04 WARN Failed to register uploaded object key=qb5399v3v823lwd4kp4hxfjm0zk23hmy.ls error="server returned 404: 404 page not found\n"13942026/09/18 13:10:04 WARN Failed to register uploaded object key=bcsw3rf64rn7pzwsrgsflpwb48n3bq94.ls error="server returned 404: 404 page not found\n"13952026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13962026/09/18 13:10:04 WARN Failed to register uploaded object key=76fha795mqn7yr2givhjmh4h2scqkk3b.ls error="server returned 404: 404 page not found\n"13972026/09/18 13:10:04 INFO Signed narinfos id=1 count=113982026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13992026/09/18 13:10:04 INFO Signed narinfos id=2 count=114002026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (3.22ms)14012026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign14022026/09/18 13:10:04 INFO Signed narinfos id=3 count=114032026/09/18 13:10:04 INFO Uploading 3 narinfos14042026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14052026/09/18 13:10:04 WARN Failed to register uploaded object key=7l628j16jkyprawi3zxpq5f2byh9gxaf.narinfo error="server returned 404: 404 page not found\n"14062026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.35ms)14072026/09/18 13:10:04 INFO Completed upload id=214082026/09/18 13:10:04 INFO Upload complete. (106ms)14092026/09/18 13:10:04 WARN Failed to register uploaded object key=76fha795mqn7yr2givhjmh4h2scqkk3b.narinfo error="server returned 404: 404 page not found\n"14102026/09/18 13:10:04 WARN Failed to register uploaded object key=bcsw3rf64rn7pzwsrgsflpwb48n3bq94.narinfo error="server returned 404: 404 page not found\n"14112026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14122026/09/18 13:10:04 WARN Failed to register uploaded object key=qb5399v3v823lwd4kp4hxfjm0zk23hmy.narinfo error="server returned 404: 404 page not found\n"14132026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)1414=== NAME TestClientCADerivations1415 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1416 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1417 error: binary cache 's3://bucket16?endpoint=http://localhost:38133®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3571336756/001/store'1418 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 114192026-09-18 13:10:04.557 UTC [1231] ERROR: relation "goose_db_version" does not exist at character 3614202026-09-18 13:10:04.557 UTC [1231] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14212026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.12ms)14222026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000014232026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.17ms)14242026/09/18 13:10:04 INFO Completed upload id=114252026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1426--- PASS: TestClientCADerivations (1.18s)1427=== CONT TestReadProxyRangeRequest14282026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.54ms)14292026/09/18 13:10:04 goose: up to current file version: 214302026/09/18 13:10:04 INFO Completed upload id=21431=== RUN TestService_RequireScope_OIDC/builder_may_write1432=== PAUSE TestService_RequireScope_OIDC/builder_may_write1433=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1434=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1435=== RUN TestService_RequireScope_OIDC/ops_may_admin1436=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1437=== RUN TestService_RequireScope_OIDC/ops_may_not_write1438=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1439=== RUN TestService_RequireScope_OIDC/reader_may_not_write1440=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1441=== RUN TestService_RequireScope_OIDC/static_token_may_admin1442=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1443=== RUN TestService_RequireScope_OIDC/static_token_may_write14442026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete1445=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1446=== RUN TestService_RequireScope_OIDC/reader_may_read1447=== PAUSE TestService_RequireScope_OIDC/reader_may_read1448=== RUN TestService_RequireScope_OIDC/writer_implies_read1449=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1450=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1451=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1452=== CONT TestReadProxyDisabled1453=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1454=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1455=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1456=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1457=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1458=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1459=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1460=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1461=== CONT TestReadProxyRootRedirectsToIndexHTML14622026/09/18 13:10:04 INFO Completed upload id=314632026/09/18 13:10:04 INFO Upload complete. (140ms)1464=== NAME TestClientMultipleUploads1465 client_integration_test.go:369: Uploaded 3 paths in 180.792613ms14662026-09-18 13:10:04.572 UTC [1234] ERROR: relation "goose_db_version" does not exist at character 3614672026-09-18 13:10:04.572 UTC [1234] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14682026/09/18 13:10:04 OK 20241026095416_initial_model.sql (12.46ms)14692026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)1470--- PASS: TestClientMultipleUploads (1.13s)1471=== CONT TestReadRedirectKeepsNarinfoProxied14722026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.41ms)14732026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14742026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.94ms)14752026/09/18 13:10:04 INFO Received create pin request method=POST path=/api/pins/myapp14762026/09/18 13:10:04 OK 20241026095416_initial_model.sql (12.61ms)14772026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.16ms)14782026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000014792026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)1480--- PASS: TestService_ReadAuthMiddleware (0.77s)1481=== CONT TestReadProxyConditionalGet14822026/09/18 13:10:04 OK 1_commit_pending_closure.sql (9.43ms)14832026/09/18 13:10:04 OK 20251218171726_add_pins.sql (11.29ms)14842026/09/18 13:10:04 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3229934162/001/store/78251yzi5xhslh7mrpwqh8mf2zhm0y9g-pinned-file.txt narinfo_key=78251yzi5xhslh7mrpwqh8mf2zhm0y9g.narinfo14852026/09/18 13:10:04 OK 2_object_stats_trigger.sql (3.15ms)14862026/09/18 13:10:04 goose: up to current file version: 214872026/09/18 13:10:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures14882026/09/18 13:10:04 INFO Garbage collection started14892026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002000000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2LjM2YWZhMzk4LTU1NjktNGU0YS05ODc3LTNkN2NlNDM4Yzk2MngxNzg5NzM3MDA0MTA2OTQ0NDgz parts=1014902026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14912026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)14922026/09/18 13:10:04 INFO Completed upload id=114932026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures14942026/09/18 13:10:04 OK 20260905000000_add_claims.sql (5.83ms)14952026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000014962026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.82ms)14972026/09/18 13:10:04 INFO Aborted multipart uploads count=014982026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.98ms)14992026/09/18 13:10:04 goose: up to current file version: 215002026-09-18 13:10:04.624 UTC [1261] ERROR: relation "goose_db_version" does not exist at character 3615012026-09-18 13:10:04.624 UTC [1261] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15022026/09/18 13:10:04 WARN Force mode enabled - objects will be deleted immediately without grace period15032026/09/18 13:10:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15042026/09/18 13:10:04 WARN mTLS auth: bound subjects configured but subject DN unavailable15052026/09/18 13:10:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1506--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.79s)1507=== CONT TestReadRedirectNar15082026/09/18 13:10:04 OK 20241026095416_initial_model.sql (28.1ms)15092026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)15102026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.54ms)15112026-09-18 13:10:04.670 UTC [1265] ERROR: relation "goose_db_version" does not exist at character 3615122026-09-18 13:10:04.670 UTC [1265] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15132026-09-18 13:10:04.670 UTC [1266] ERROR: relation "goose_db_version" does not exist at character 3615142026-09-18 13:10:04.670 UTC [1266] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15152026-09-18 13:10:04.673 UTC [1267] ERROR: relation "goose_db_version" does not exist at character 3615162026-09-18 13:10:04.673 UTC [1267] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1517--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.63s)1518=== CONT TestReadProxyHead15192026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.5ms)15202026-09-18 13:10:04.678 UTC [1268] ERROR: relation "goose_db_version" does not exist at character 3615212026-09-18 13:10:04.678 UTC [1268] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15222026/09/18 13:10:04 OK 20260905000000_add_claims.sql (6.25ms)15232026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015242026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.46ms)15252026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.35ms)15262026/09/18 13:10:04 goose: up to current file version: 215272026/09/18 13:10:04 OK 20241026095416_initial_model.sql (11.06ms)15282026/09/18 13:10:04 OK 20241026095416_initial_model.sql (10.78ms)15292026/09/18 13:10:04 OK 20241026095416_initial_model.sql (9.93ms)15302026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)15312026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)15322026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)15332026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.27ms)15342026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.58ms)15352026/09/18 13:10:04 OK 20251218171726_add_pins.sql (6.13ms)15362026/09/18 13:10:04 OK 20241026095416_initial_model.sql (12.29ms)15372026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.44ms)15382026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)15392026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)15402026-09-18 13:10:04.703 UTC [1271] ERROR: relation "goose_db_version" does not exist at character 3615412026-09-18 13:10:04.703 UTC [1271] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15422026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)15432026/09/18 13:10:04 OK 20260905000000_add_claims.sql (5.03ms)15442026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015452026/09/18 13:10:04 OK 20251218171726_add_pins.sql (5.82ms)15462026/09/18 13:10:04 OK 20260905000000_add_claims.sql (5.76ms)15472026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015482026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.49ms)15492026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015502026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.74ms)15512026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.58ms)1552--- PASS: TestReadProxyInvalidPath (0.48s)1553=== CONT TestOrphanedObjectsGC15542026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.5ms)15552026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.23ms)15562026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.41ms)15572026/09/18 13:10:04 goose: up to current file version: 215582026/09/18 13:10:04 OK 2_object_stats_trigger.sql (3.52ms)15592026/09/18 13:10:04 goose: up to current file version: 215602026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.77ms)15612026/09/18 13:10:04 goose: up to current file version: 215622026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3.61ms)15632026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015642026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.71ms)15652026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.08ms)15662026/09/18 13:10:04 goose: up to current file version: 215672026/09/18 13:10:04 OK 20241026095416_initial_model.sql (11.96ms)15682026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)15692026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.51ms)15702026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.35ms)15712026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15722026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.64ms)15732026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015742026-09-18 13:10:04.740 UTC [1274] ERROR: relation "goose_db_version" does not exist at character 3615752026-09-18 13:10:04.740 UTC [1274] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15762026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures15772026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.45ms)15782026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.04ms)15792026/09/18 13:10:04 goose: up to current file version: 215802026/09/18 13:10:04 OK 20241026095416_initial_model.sql (12.7ms)15812026-09-18 13:10:04.760 UTC [1275] ERROR: relation "goose_db_version" does not exist at character 3615822026-09-18 13:10:04.760 UTC [1275] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15832026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (11.88ms)15842026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2LjVmNTI4ZTRmLTI3MDQtNDg3ZC1hNzUxLTU4MmRmMjU5NTYwY3gxNzg5NzM3MDA0MjUwNDk2MDg4 parts=1015852026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15862026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.89ms)15872026/09/18 13:10:04 INFO Completed upload id=115882026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"15892026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures15902026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.17ms)15912026-09-18 13:10:04.783 UTC [1276] ERROR: relation "goose_db_version" does not exist at character 3615922026-09-18 13:10:04.783 UTC [1276] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15932026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"15942026/09/18 13:10:04 OK 20241026095416_initial_model.sql (10.81ms)15952026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)1596--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (1.33s)1597=== CONT TestService_NativeMTLS15982026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.43ms)15992026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000016002026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.12ms)16012026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.12ms)16022026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.51ms)16032026/09/18 13:10:04 goose: up to current file version: 216042026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.27ms)16052026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3.8ms)16062026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000016072026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.98ms)16082026/09/18 13:10:04 OK 20241026095416_initial_model.sql (11.68ms)16092026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.2ms)16102026/09/18 13:10:04 goose: up to current file version: 216112026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)16122026/09/18 13:10:04 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst16132026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures16142026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.29ms)1615--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.49s)1616=== CONT TestReadProxy40416172026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)1618--- PASS: TestService_Rustfstest (0.50s)1619=== CONT TestObjectStatsTrigger16202026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.4ms)16212026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000016222026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.76ms)16232026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.82ms)16242026/09/18 13:10:04 goose: up to current file version: 216252026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures16262026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"16272026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16282026-09-18 13:10:04.869 UTC [1284] ERROR: relation "goose_db_version" does not exist at character 3616292026-09-18 13:10:04.869 UTC [1284] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16302026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures16312026/09/18 13:10:04 OK 20241026095416_initial_model.sql (11.59ms)16322026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)16332026-09-18 13:10:04.895 UTC [1286] ERROR: relation "goose_db_version" does not exist at character 3616342026-09-18 13:10:04.895 UTC [1286] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16352026/09/18 13:10:04 OK 20251218171726_add_pins.sql (5.19ms)16362026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16372026-09-18 13:10:04.902 UTC [1287] ERROR: relation "goose_db_version" does not exist at character 3616382026-09-18 13:10:04.902 UTC [1287] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16392026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (4ms)16402026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.52ms)16412026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000016422026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures16432026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.65ms)16442026/09/18 13:10:04 OK 20241026095416_initial_model.sql (11.89ms)16452026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.3ms)16462026/09/18 13:10:04 goose: up to current file version: 216472026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)16482026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16492026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.85ms)16502026/09/18 13:10:04 OK 20241026095416_initial_model.sql (11.29ms)16512026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2LjY5ZDdhZWY2LTU0YjktNGFmZi04ZjgyLTUzOWQyZTQ3NWE0Y3gxNzg5NzM3MDA0NDMwOTQxNzE5 parts=1016522026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16532026/09/18 13:10:04 INFO Signed narinfos id=1 count=116542026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16552026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.32ms)16562026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures16572026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)16582026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures16592026/09/18 13:10:04 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2LjIzZmM0MTdiLTlmODQtNDQxYS1iYjgwLTE4MGFjZWU1YzQ5YngxNzg5NzM3MDA0ODkwMDE2MDI216602026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16612026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3.35ms)16622026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000016632026/09/18 13:10:04 INFO Signed narinfos id=2 count=116642026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16652026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.32ms)16662026/09/18 13:10:04 OK 1_commit_pending_closure.sql (1.92ms)16672026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.85ms)16682026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2LjIzZmM0MTdiLTlmODQtNDQxYS1iYjgwLTE4MGFjZWU1YzQ5YngxNzg5NzM3MDA0ODkwMDE2MDI2 parts=116692026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.89ms)16702026/09/18 13:10:04 goose: up to current file version: 21671--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.55s)1672=== CONT TestReadProxyNarStreaming16732026/09/18 13:10:04 INFO Completed upload id=21674=== NAME TestClaim_BuildWaitComplete1675 claims_test.go:223: status = "build" ({Status:build Token:4 Kind:}), want "built"1676--- FAIL: TestClaim_BuildWaitComplete (1.48s)1677=== CONT TestMultipartCleanup16782026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3.49ms)16792026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000016802026/09/18 13:10:04 OK 1_commit_pending_closure.sql (1.93ms)16812026/09/18 13:10:04 OK 2_object_stats_trigger.sql (995.97µs)16822026/09/18 13:10:04 goose: up to current file version: 21683--- PASS: TestReadRedirectUsesPublicS3URL (0.50s)1684=== CONT TestReadProxyNarinfoAlreadyDecompressed16852026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16862026/09/18 13:10:04 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1687--- PASS: TestCompleteMultipartUnregistered (0.49s)1688=== CONT TestServerTLSConfig1689=== RUN TestServerTLSConfig/no_client_CA1690=== PAUSE TestServerTLSConfig/no_client_CA1691=== RUN TestServerTLSConfig/missing_CA_file1692=== PAUSE TestServerTLSConfig/missing_CA_file1693=== RUN TestServerTLSConfig/not_a_PEM_file1694=== PAUSE TestServerTLSConfig/not_a_PEM_file1695=== CONT TestReadProxyNarinfo16962026/09/18 13:10:05 INFO Received uploads request method=POST path=/api/pending_closures16972026-09-18 13:10:05.019 UTC [1298] ERROR: relation "goose_db_version" does not exist at character 3616982026-09-18 13:10:05.019 UTC [1298] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1699--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.50s)1700=== CONT TestParseSingleRange1701=== RUN TestParseSingleRange/none1702=== PAUSE TestParseSingleRange/none1703=== RUN TestParseSingleRange/unknown_unit1704=== PAUSE TestParseSingleRange/unknown_unit1705=== RUN TestParseSingleRange/multi-range_ignored1706=== PAUSE TestParseSingleRange/multi-range_ignored1707=== RUN TestParseSingleRange/malformed_no_dash1708=== PAUSE TestParseSingleRange/malformed_no_dash1709=== RUN TestParseSingleRange/malformed_both_empty1710=== PAUSE TestParseSingleRange/malformed_both_empty1711=== RUN TestParseSingleRange/malformed_end_before_start1712=== PAUSE TestParseSingleRange/malformed_end_before_start1713=== RUN TestParseSingleRange/closed1714=== PAUSE TestParseSingleRange/closed1715=== RUN TestParseSingleRange/open-ended1716=== PAUSE TestParseSingleRange/open-ended1717=== RUN TestParseSingleRange/end_clamped_to_size1718=== PAUSE TestParseSingleRange/end_clamped_to_size1719=== RUN TestParseSingleRange/suffix1720=== PAUSE TestParseSingleRange/suffix1721=== RUN TestParseSingleRange/suffix_exceeds_size1722=== PAUSE TestParseSingleRange/suffix_exceeds_size1723=== RUN TestParseSingleRange/single_byte1724=== PAUSE TestParseSingleRange/single_byte1725=== RUN TestParseSingleRange/start_past_EOF17262026-09-18 13:10:05.024 UTC [1299] ERROR: relation "goose_db_version" does not exist at character 3617272026-09-18 13:10:05.024 UTC [1299] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1728=== PAUSE TestParseSingleRange/start_past_EOF1729=== RUN TestParseSingleRange/start_far_past_EOF1730=== PAUSE TestParseSingleRange/start_far_past_EOF1731=== CONT TestResurrectedObjectNotDeleted17322026/09/18 13:10:05 OK 20241026095416_initial_model.sql (13.4ms)17332026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (2.68ms)17342026/09/18 13:10:05 OK 20241026095416_initial_model.sql (13.04ms)17352026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (3.05ms)1736--- PASS: TestReadProxyRangeRequest (0.49s)1737=== CONT TestIsValidCachePath1738=== RUN TestIsValidCachePath/narinfo1739=== PAUSE TestIsValidCachePath/narinfo1740=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1741=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1742=== RUN TestIsValidCachePath/nar_zst1743=== PAUSE TestIsValidCachePath/nar_zst1744=== RUN TestIsValidCachePath/nar_xz1745=== PAUSE TestIsValidCachePath/nar_xz1746=== RUN TestIsValidCachePath/nar_bz21747=== PAUSE TestIsValidCachePath/nar_bz21748=== RUN TestIsValidCachePath/nar_uncompressed1749=== PAUSE TestIsValidCachePath/nar_uncompressed1750=== RUN TestIsValidCachePath/ls1751=== PAUSE TestIsValidCachePath/ls1752=== RUN TestIsValidCachePath/log1753=== PAUSE TestIsValidCachePath/log1754=== RUN TestIsValidCachePath/realisation1755=== PAUSE TestIsValidCachePath/realisation1756=== RUN TestIsValidCachePath/nix-cache-info1757=== PAUSE TestIsValidCachePath/nix-cache-info1758=== RUN TestIsValidCachePath/index.html1759=== PAUSE TestIsValidCachePath/index.html1760=== RUN TestIsValidCachePath/traversal_parent1761=== PAUSE TestIsValidCachePath/traversal_parent1762=== RUN TestIsValidCachePath/traversal_in_middle1763=== PAUSE TestIsValidCachePath/traversal_in_middle1764=== RUN TestIsValidCachePath/invalid_char_e1765=== PAUSE TestIsValidCachePath/invalid_char_e1766=== RUN TestIsValidCachePath/invalid_char_u1767=== PAUSE TestIsValidCachePath/invalid_char_u1768=== RUN TestIsValidCachePath/random_path1769=== PAUSE TestIsValidCachePath/random_path1770=== RUN TestIsValidCachePath/empty1771=== PAUSE TestIsValidCachePath/empty1772=== RUN TestIsValidCachePath/leading_slash1773=== PAUSE TestIsValidCachePath/leading_slash1774=== RUN TestIsValidCachePath/wrong_extension1775=== PAUSE TestIsValidCachePath/wrong_extension1776=== RUN TestIsValidCachePath/short_hash1777=== PAUSE TestIsValidCachePath/short_hash1778=== CONT TestOrphanedObjectsGCStressTest17792026/09/18 13:10:05 OK 20251218171726_add_pins.sql (12.21ms)17802026/09/18 13:10:05 OK 20251218171726_add_pins.sql (9.99ms)17812026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (4.9ms)17822026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)17832026/09/18 13:10:05 OK 20260905000000_add_claims.sql (4.2ms)17842026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000017852026/09/18 13:10:05 OK 20260905000000_add_claims.sql (5ms)17862026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000017872026/09/18 13:10:05 OK 1_commit_pending_closure.sql (3.22ms)17882026/09/18 13:10:05 OK 1_commit_pending_closure.sql (4.2ms)17892026/09/18 13:10:05 OK 2_object_stats_trigger.sql (1.81ms)17902026/09/18 13:10:05 goose: up to current file version: 217912026-09-18 13:10:05.071 UTC [1304] ERROR: relation "goose_db_version" does not exist at character 3617922026-09-18 13:10:05.071 UTC [1304] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17932026-09-18 13:10:05.071 UTC [1305] ERROR: relation "goose_db_version" does not exist at character 3617942026-09-18 13:10:05.071 UTC [1305] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17952026/09/18 13:10:05 OK 2_object_stats_trigger.sql (1.98ms)17962026/09/18 13:10:05 goose: up to current file version: 21797--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.51s)1798=== CONT TestNARDeduplicationMetadataUploadBug17992026/09/18 13:10:05 OK 20241026095416_initial_model.sql (12.47ms)18002026/09/18 13:10:05 OK 20241026095416_initial_model.sql (12.48ms)18012026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)18022026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (2.71ms)18032026/09/18 13:10:05 OK 20251218171726_add_pins.sql (3.86ms)18042026/09/18 13:10:05 OK 20251218171726_add_pins.sql (4.61ms)18052026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)18062026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18072026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (4.57ms)1808--- PASS: TestReadProxyDisabled (0.54s)1809=== CONT TestMetricsInventory18102026/09/18 13:10:05 OK 20260905000000_add_claims.sql (4.28ms)18112026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000018122026-09-18 13:10:05.107 UTC [1308] ERROR: relation "goose_db_version" does not exist at character 3618132026-09-18 13:10:05.107 UTC [1308] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18142026/09/18 13:10:05 OK 20260905000000_add_claims.sql (4.44ms)18152026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000018162026/09/18 13:10:05 OK 1_commit_pending_closure.sql (3.18ms)18172026/09/18 13:10:05 OK 2_object_stats_trigger.sql (1.87ms)18182026/09/18 13:10:05 goose: up to current file version: 218192026/09/18 13:10:05 OK 1_commit_pending_closure.sql (4ms)18202026/09/18 13:10:05 OK 2_object_stats_trigger.sql (2.31ms)18212026/09/18 13:10:05 goose: up to current file version: 218222026/09/18 13:10:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002100000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2LmMyNTZiM2UzLTQxZDctNGY0NS1iODcyLTM0MWY5ZDAwMTM2MHgxNzg5NzM3MDA0NjIxNDE5NDU4 parts=1018232026/09/18 13:10:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18242026/09/18 13:10:05 INFO Completed upload id=218252026/09/18 13:10:05 OK 20241026095416_initial_model.sql (12.62ms)1826--- PASS: TestPresent (1.74s)1827=== CONT TestService_verifyS3Integrity18282026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)18292026-09-18 13:10:05.135 UTC [1311] ERROR: relation "goose_db_version" does not exist at character 3618302026-09-18 13:10:05.135 UTC [1311] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18312026/09/18 13:10:05 OK 20251218171726_add_pins.sql (5.8ms)18322026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)18332026/09/18 13:10:05 OK 20260905000000_add_claims.sql (4.18ms)18342026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000018352026/09/18 13:10:05 OK 1_commit_pending_closure.sql (3.34ms)1836--- PASS: TestReadRedirectKeepsNarinfoProxied (0.57s)1837=== CONT TestCreatePendingClosureRejectsOversizedNAR18382026/09/18 13:10:05 INFO Received uploads request method=POST path=/api/pending_closures1839--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1840=== CONT TestCacheConfigHandlerMaxNarSize1841--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1842=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18432026/09/18 13:10:05 INFO Received uploads request method=POST path=/1844=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18452026/09/18 13:10:05 INFO Received request for more parts method=POST path=/1846=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18472026/09/18 13:10:05 INFO Received uploads request method=POST path=/1848=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18492026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/1850--- PASS: TestUploadHandlersRejectInvalidKeys (0.06s)1851 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1852 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1853 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1854 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1855=== CONT TestClientErrorHandling/InvalidStorePath18562026-09-18 13:10:05.158 UTC [1314] ERROR: relation "goose_db_version" does not exist at character 3618572026-09-18 13:10:05.158 UTC [1314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18582026/09/18 13:10:05 OK 2_object_stats_trigger.sql (9.15ms)18592026/09/18 13:10:05 goose: up to current file version: 218602026/09/18 13:10:05 OK 20241026095416_initial_model.sql (18.33ms)18612026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)18622026/09/18 13:10:05 OK 20251218171726_add_pins.sql (3.9ms)18632026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (4.59ms)18642026/09/18 13:10:05 OK 20241026095416_initial_model.sql (9.91ms)18652026/09/18 13:10:05 OK 20260905000000_add_claims.sql (4.31ms)18662026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000018672026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (2.72ms)18682026/09/18 13:10:05 OK 1_commit_pending_closure.sql (2.85ms)18692026/09/18 13:10:05 OK 2_object_stats_trigger.sql (1.98ms)18702026/09/18 13:10:05 goose: up to current file version: 218712026/09/18 13:10:05 OK 20251218171726_add_pins.sql (5.17ms)18722026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (4.95ms)18732026-09-18 13:10:05.189 UTC [1317] ERROR: relation "goose_db_version" does not exist at character 3618742026-09-18 13:10:05.189 UTC [1317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18752026/09/18 13:10:05 OK 20260905000000_add_claims.sql (4.02ms)18762026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000018772026/09/18 13:10:05 OK 1_commit_pending_closure.sql (3.07ms)18782026/09/18 13:10:05 OK 2_object_stats_trigger.sql (1.36ms)18792026/09/18 13:10:05 goose: up to current file version: 21880--- PASS: TestReadProxyConditionalGet (0.60s)1881=== CONT TestClientErrorHandling/InvalidAuthToken18822026/09/18 13:10:05 OK 20241026095416_initial_model.sql (12.01ms)18832026-09-18 13:10:05.208 UTC [1319] ERROR: relation "goose_db_version" does not exist at character 3618842026-09-18 13:10:05.208 UTC [1319] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18852026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)1886--- PASS: TestReadRedirectNar (0.57s)1887=== CONT TestClientErrorHandling/ServerNotAvailable18882026/09/18 13:10:05 OK 20251218171726_add_pins.sql (4.17ms)18892026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)18902026/09/18 13:10:05 OK 20260905000000_add_claims.sql (4.36ms)18912026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000018922026/09/18 13:10:05 OK 20241026095416_initial_model.sql (11.73ms)18932026/09/18 13:10:05 OK 1_commit_pending_closure.sql (3.32ms)18942026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (3.07ms)18952026-09-18 13:10:05.230 UTC [1322] ERROR: relation "goose_db_version" does not exist at character 3618962026-09-18 13:10:05.230 UTC [1322] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18972026/09/18 13:10:05 OK 2_object_stats_trigger.sql (2.78ms)18982026/09/18 13:10:05 goose: up to current file version: 218992026/09/18 13:10:05 OK 20251218171726_add_pins.sql (4.22ms)19002026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (4.39ms)19012026/09/18 13:10:05 OK 20260905000000_add_claims.sql (4.17ms)19022026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000019032026/09/18 13:10:05 OK 1_commit_pending_closure.sql (3.11ms)1904--- PASS: TestReadProxyHead (0.57s)1905=== CONT TestResolveDBConnectionString/flag_wins1906=== CONT TestResolveDBConnectionString/nothing_configured1907=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1908=== CONT TestResolveDBConnectionString/missing_file_is_an_error1909=== CONT TestResolveDBConnectionString/file_when_flag_empty1910=== CONT TestIsValidUploadKey/narinfo19112026/09/18 13:10:05 OK 20241026095416_initial_model.sql (11.12ms)1912=== CONT TestIsValidUploadKey/realisation_plus_in_output1913=== CONT TestIsValidUploadKey/unknown_type1914=== CONT TestIsValidUploadKey/empty_key1915=== CONT TestIsValidUploadKey/absolute1916=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1917=== CONT TestIsValidUploadKey/index.html1918=== CONT TestIsValidUploadKey/nix-cache-info1919=== CONT TestIsValidUploadKey/traversal1920=== CONT TestIsValidUploadKey/traversal_nar1921=== CONT TestIsValidUploadKey/build_log_home-manager_file1922=== CONT TestIsValidUploadKey/realisation1923=== CONT TestIsValidUploadKey/build_log_equals1924=== CONT TestIsValidUploadKey/build_log_question_mark1925=== CONT TestIsValidUploadKey/build_log_plus_in_name1926=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1927=== CONT TestIsValidUploadKey/nar_plain1928=== CONT TestIsValidUploadKey/build_log1929=== CONT TestIsValidUploadKey/listing1930=== CONT TestIsValidUploadKey/nar_xz1931=== CONT TestIsValidUploadKey/nar_zst1932=== CONT TestIsValidUploadKey/nar_key,_narinfo_type19332026/09/18 13:10:05 OK 2_object_stats_trigger.sql (1.94ms)1934=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19352026/09/18 13:10:05 goose: up to current file version: 21936--- PASS: TestResolveDBConnectionString (0.06s)1937 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1938 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1939 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1940 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1941 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)19422026/09/18 13:10:05 INFO Received uploads request method=POST path=/1943--- PASS: TestIsValidUploadKey (0.07s)1944 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1945 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1946 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1947 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1948 --- PASS: TestIsValidUploadKey/absolute (0.00s)1949 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1950 --- PASS: TestIsValidUploadKey/index.html (0.00s)1951 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1952 --- PASS: TestIsValidUploadKey/traversal (0.00s)1953 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1954 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1955 --- PASS: TestIsValidUploadKey/realisation (0.00s)1956 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1957 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1958 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1959 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1960 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1961 --- PASS: TestIsValidUploadKey/build_log (0.00s)1962 --- PASS: TestIsValidUploadKey/listing (0.00s)1963 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1964 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1965 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)19662026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)19672026/09/18 13:10:05 OK 20251218171726_add_pins.sql (3.99ms)19682026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)19692026/09/18 13:10:05 OK 20260905000000_add_claims.sql (3.66ms)19702026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000019712026/09/18 13:10:05 OK 1_commit_pending_closure.sql (2.08ms)19722026/09/18 13:10:05 OK 2_object_stats_trigger.sql (994.53µs)19732026/09/18 13:10:05 goose: up to current file version: 219742026-09-18 13:10:05.274 UTC [1340] ERROR: relation "goose_db_version" does not exist at character 3619752026-09-18 13:10:05.274 UTC [1340] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19762026/09/18 13:10:05 OK 20241026095416_initial_model.sql (10.98ms)19772026/09/18 13:10:05 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19782026/09/18 13:10:05 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)19792026/09/18 13:10:05 OK 20251218171726_add_pins.sql (3.98ms)19802026/09/18 13:10:05 WARN mTLS auth: subject not in bound subjects subject="CN=reader"19812026/09/18 13:10:05 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1982--- PASS: TestService_NativeMTLS (0.51s)1983=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19842026/09/18 13:10:05 INFO Received request for more parts method=POST path=/19852026/09/18 13:10:05 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)19862026/09/18 13:10:05 OK 20260905000000_add_claims.sql (2.95ms)19872026/09/18 13:10:05 goose: successfully migrated database to version: 2026090500000019882026/09/18 13:10:05 OK 1_commit_pending_closure.sql (2.05ms)19892026/09/18 13:10:05 OK 2_object_stats_trigger.sql (3.07ms)19902026/09/18 13:10:05 goose: up to current file version: 21991--- PASS: TestReadProxy404 (0.53s)1992=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19932026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/1994=== CONT TestCacheConfigHandler/full_config,_no_issuer1995=== CONT TestCacheConfigHandler/no_signing_keys1996=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1997=== CONT TestCacheConfigHandler/no_cache_url_configured1998--- PASS: TestCacheConfigHandler (0.00s)1999 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2000 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2001 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2002 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2003=== CONT TestProxyWriteTimeout/narinfo2004=== CONT TestProxyWriteTimeout/10_GiB_nar2005=== CONT TestProxyWriteTimeout/1_GiB_nar2006=== CONT TestProxyWriteTimeout/unknown_size2007--- PASS: TestProxyWriteTimeout (0.00s)2008 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2009 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2010 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2011 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2012=== CONT TestService_RequireScope_OIDC/builder_may_write20132026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[write]2014=== CONT TestService_RequireScope_OIDC/static_token_may_write2015=== CONT TestService_RequireScope_OIDC/static_token_may_admin2016=== CONT TestService_RequireScope_OIDC/reader_may_not_write20172026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[read]2018=== CONT TestService_RequireScope_OIDC/ops_may_not_write20192026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[admin]2020=== CONT TestService_RequireScope_OIDC/ops_may_admin20212026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[admin]2022=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20232026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[write]2024=== CONT TestService_RequireScope_OIDC/reader_may_read20252026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[read]2026=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2027=== CONT TestService_RequireScope_OIDC/writer_implies_read20282026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[write]2029=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2030--- PASS: TestService_RequireScope_OIDC (0.86s)2031 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2032 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2033 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2034 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2035 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2036 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2037 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2038 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2039 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2040 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2041--- PASS: TestObjectStatsTrigger (0.56s)2042=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20432026/09/18 13:10:05 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2044=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2045=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20462026/09/18 13:10:05 WARN Authentication failed token_preview=eyJhbGciOi...vTc3VsoUTA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2047=== CONT TestServerTLSConfig/no_client_CA2048=== CONT TestServerTLSConfig/not_a_PEM_file20492026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[write]2050=== CONT TestServerTLSConfig/missing_CA_file2051=== CONT TestParseSingleRange/none2052=== CONT TestParseSingleRange/single_byte2053=== CONT TestParseSingleRange/suffix_exceeds_size2054=== CONT TestParseSingleRange/suffix2055=== CONT TestParseSingleRange/end_clamped_to_size2056=== CONT TestParseSingleRange/open-ended2057=== CONT TestParseSingleRange/start_past_EOF2058=== CONT TestParseSingleRange/closed2059=== CONT TestParseSingleRange/malformed_end_before_start2060=== CONT TestParseSingleRange/malformed_both_empty2061=== CONT TestParseSingleRange/malformed_no_dash2062=== CONT TestParseSingleRange/multi-range_ignored2063=== CONT TestParseSingleRange/unknown_unit2064=== CONT TestParseSingleRange/start_far_past_EOF2065--- PASS: TestParseSingleRange (0.00s)2066 --- PASS: TestParseSingleRange/none (0.00s)2067 --- PASS: TestParseSingleRange/single_byte (0.00s)2068 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2069 --- PASS: TestParseSingleRange/suffix (0.00s)2070 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2071 --- PASS: TestParseSingleRange/open-ended (0.00s)2072 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2073 --- PASS: TestParseSingleRange/closed (0.00s)2074 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2075 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2076 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2077 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2078 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2079 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2080=== CONT TestIsValidCachePath/narinfo2081=== CONT TestIsValidCachePath/invalid_char_u2082=== CONT TestIsValidCachePath/random_path2083=== CONT TestIsValidCachePath/traversal_in_middle2084=== CONT TestIsValidCachePath/traversal_parent2085=== CONT TestIsValidCachePath/index.html2086=== CONT TestIsValidCachePath/nix-cache-info2087=== CONT TestIsValidCachePath/realisation2088=== CONT TestIsValidCachePath/log2089=== CONT TestIsValidCachePath/ls2090=== CONT TestIsValidCachePath/nar_uncompressed2091=== CONT TestIsValidCachePath/nar_bz22092--- PASS: TestServerTLSConfig (0.00s)2093 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2094 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2095 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2096=== CONT TestIsValidCachePath/invalid_char_e2097=== CONT TestIsValidCachePath/nar_zst2098=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2099=== CONT TestIsValidCachePath/nar_xz2100=== CONT TestIsValidCachePath/short_hash2101=== CONT TestIsValidCachePath/wrong_extension2102=== CONT TestIsValidCachePath/leading_slash2103--- PASS: TestService_AuthMiddleware_OIDC (0.83s)2104 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2105 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2106 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2107 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2108=== CONT TestIsValidCachePath/empty2109--- PASS: TestIsValidCachePath (0.00s)2110 --- PASS: TestIsValidCachePath/narinfo (0.00s)2111 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2112 --- PASS: TestIsValidCachePath/random_path (0.00s)2113 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2114 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2115 --- PASS: TestIsValidCachePath/index.html (0.00s)2116 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2117 --- PASS: TestIsValidCachePath/realisation (0.00s)2118 --- PASS: TestIsValidCachePath/log (0.00s)2119 --- PASS: TestIsValidCachePath/ls (0.00s)2120 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2121 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2122 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2123 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2124 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2125 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2126 --- PASS: TestIsValidCachePath/short_hash (0.00s)2127 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2128 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2129 --- PASS: TestIsValidCachePath/empty (0.00s)21302026/09/18 13:10:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.107499ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2131--- PASS: TestReadProxyNarStreaming (0.47s)21322026/09/18 13:10:05 INFO Received uploads request method=POST path=/api/pending_closures21332026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21342026/09/18 13:10:05 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2Ljk1ZmNlNzIyLTExZTItNGRlYS04MjJhLTk4NzM2MGVmMjY4YXgxNzg5NzM3MDA0ODU4NzQ1OTEw parts=1221352026/09/18 13:10:05 INFO Received uploads request method=POST path=/api/pending_closures2136--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.09s)2137--- PASS: TestReadProxyNarinfo (0.48s)2138--- PASS: TestClaim_StreamsThroughServer (2.07s)2139--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.52s)21402026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21412026/09/18 13:10:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=021422026/09/18 13:10:05 INFO Vacuumed table table=pending_closures21432026/09/18 13:10:05 INFO Vacuumed table table=pending_objects21442026/09/18 13:10:05 INFO Vacuumed table table=multipart_uploads21452026/09/18 13:10:05 INFO Vacuumed table table=closures21462026/09/18 13:10:05 INFO Vacuumed table table=objects21472026/09/18 13:10:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2LmMzMDFiYjQ2LTg2MTMtNDRiMi1iOTc1LTQxYWQ5YzAzYzg2MngxNzg5NzM3MDA0OTIxODM5ODQ2 parts=122148--- PASS: TestRedundantMultipartUpload (1.08s)21492026/09/18 13:10:05 INFO Received cleanup request method=DELETE path=/api/pending_closures21502026/09/18 13:10:05 INFO Aborted multipart uploads count=12151--- PASS: TestResurrectedObjectNotDeleted (0.52s)2152--- PASS: TestMultipartCleanup (0.61s)2153=== NAME TestOrphanedObjectsGC2154 orphaned_objects_gc_test.go:290: GC Test Summary:2155 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2156 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2157 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2158 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2159 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2160--- PASS: TestOrphanedObjectsGC (0.89s)2161--- PASS: TestMetricsInventory (0.49s)2162=== NAME TestNARDeduplicationMetadataUploadBug2163 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3376300136/001/store/h7la1s9hpwqn7cdxp4i8wwpalshd55pc-file1.txt21642026/09/18 13:10:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=431.051947ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21652026/09/18 13:10:05 INFO Received uploads request method=POST path=/api/pending_closures21662026/09/18 13:10:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21672026/09/18 13:10:05 INFO Received uploads request method=POST path=/api/pending_closures21682026/09/18 13:10:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21692026/09/18 13:10:05 INFO Uploading h7la1s9hpwqn7cdxp4i8wwpalshd55pc-file1.txt (160B)21702026/09/18 13:10:05 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"21712026/09/18 13:10:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21722026/09/18 13:10:05 WARN Failed to register uploaded object key=h7la1s9hpwqn7cdxp4i8wwpalshd55pc.ls error="server returned 404: 404 page not found\n"21732026/09/18 13:10:05 INFO Signed narinfos id=1 count=121742026/09/18 13:10:05 INFO Uploading 1 narinfos21752026/09/18 13:10:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21762026/09/18 13:10:05 WARN Failed to register uploaded object key=h7la1s9hpwqn7cdxp4i8wwpalshd55pc.narinfo error="server returned 404: 404 page not found\n"21772026/09/18 13:10:05 INFO Completed upload id=121782026/09/18 13:10:05 INFO Upload complete. (101ms)2179 metadata_upload_test.go:54: Retrieved narinfo from S3:2180 StorePath: /build/TestNARDeduplicationMetadataUploadBug3376300136/001/store/h7la1s9hpwqn7cdxp4i8wwpalshd55pc-file1.txt2181 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2182 Compression: zstd2183 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2184 NarSize: 1602185 References: 2186 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf21872026/09/18 13:10:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2188 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2189 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2190 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}21912026/09/18 13:10:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2192 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3376300136/001/store/k4pwx0f02kcw55cwi47mji7abbw1rk1g-file2.txt21932026/09/18 13:10:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21942026/09/18 13:10:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21952026/09/18 13:10:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=021962026/09/18 13:10:05 INFO Vacuumed table table=pending_closures21972026/09/18 13:10:05 INFO Received uploads request method=POST path=/api/pending_closures21982026/09/18 13:10:05 INFO Vacuumed table table=pending_objects21992026/09/18 13:10:05 INFO Vacuumed table table=multipart_uploads22002026/09/18 13:10:05 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)22012026/09/18 13:10:05 INFO Vacuumed table table=closures22022026/09/18 13:10:05 INFO Vacuumed table table=objects22032026/09/18 13:10:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22042026/09/18 13:10:05 WARN Failed to register uploaded object key=k4pwx0f02kcw55cwi47mji7abbw1rk1g.ls error="server returned 404: 404 page not found\n"22052026/09/18 13:10:05 INFO Signed narinfos id=2 count=122062026/09/18 13:10:05 INFO Uploading 1 narinfos22072026/09/18 13:10:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22082026/09/18 13:10:05 WARN Failed to register uploaded object key=k4pwx0f02kcw55cwi47mji7abbw1rk1g.narinfo error="server returned 404: 404 page not found\n"22092026/09/18 13:10:05 INFO Completed upload id=222102026/09/18 13:10:05 INFO Upload complete. (92ms)2211 metadata_upload_test.go:76: Retrieved narinfo from S3:2212 StorePath: /build/TestNARDeduplicationMetadataUploadBug3376300136/001/store/k4pwx0f02kcw55cwi47mji7abbw1rk1g-file2.txt2213 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2214 Compression: zstd2215 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2216 NarSize: 1602217 References: 2218 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2219 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2220 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2221 {"version":1,"root":{"type":"regular","size":44}}2222--- PASS: TestNARDeduplicationMetadataUploadBug (0.83s)22232026/09/18 13:10:06 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=767.875618ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22242026/09/18 13:10:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22252026/09/18 13:10:06 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjRlNzQzNjctYjk1NC00N2M2LWEwYTMtMWY1ZmYxMGIyMWY2LjdhZTJjZmZiLWJhYWEtNDYxYS04ZTk5LTJkNGZiNDMyZDVkY3gxNzg5NzM3MDA1NjE3NzM2NTgx parts=1022262026/09/18 13:10:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22272026/09/18 13:10:06 INFO Completed upload id=122282026/09/18 13:10:06 INFO Received uploads request method=POST path=/api/pending_closures22292026/09/18 13:10:06 INFO Received uploads request method=POST path=/api/pending_closures22302026/09/18 13:10:06 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo22312026/09/18 13:10:06 WARN Found objects in DB but missing from S3, will re-upload count=12232--- PASS: TestService_verifyS3Integrity (0.99s)22332026/09/18 13:10:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02234=== NAME TestClientIntegration2235 client_integration_test.go:323: Objects in database after GC:2236 client_integration_test.go:323: Successfully deleted all objects with GC --force2237--- PASS: TestClientIntegration (2.82s)22382026/09/18 13:10:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02239=== NAME TestPinProtectsFromGC2240 client_integration_test.go:730: Pin successfully protected closure from garbage collection2241--- PASS: TestPinProtectsFromGC (3.23s)2242--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)2243 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2244 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.11s)2245 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.53s)22462026/09/18 13:10:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.68668281s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2247--- PASS: TestClaim_HolderDisconnectKeepsClaim (3.39s)2248=== NAME TestOrphanedObjectsGCStressTest2249 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2250 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2251 orphaned_objects_gc_test.go:509: Stress test completed successfully:2252 orphaned_objects_gc_test.go:510: - Active objects preserved: 202253 orphaned_objects_gc_test.go:511: - Objects deleted: 2102254 orphaned_objects_gc_test.go:512: - Total GC'd: 2102255--- PASS: TestOrphanedObjectsGCStressTest (2.37s)22562026/09/18 13:10:08 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22572026/09/18 13:10:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.22372ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22582026/09/18 13:10:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=368.795776ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22592026/09/18 13:10:09 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=771.831866ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22602026/09/18 13:10:09 WARN Rate limiter enabled after throttle name=s3-test rate=522612026/09/18 13:10:09 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2262=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2263 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102264 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002265--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.64s)22662026/09/18 13:10:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.522883681s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22672026/09/18 13:10:11 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22682026/09/18 13:10:11 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22692026/09/18 13:10:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.179323ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22702026/09/18 13:10:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=380.545997ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22712026/09/18 13:10:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=873.984073ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22722026/09/18 13:10:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.516228354s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2273--- PASS: TestClientErrorHandling (0.07s)2274 --- PASS: TestClientErrorHandling/InvalidStorePath (0.51s)2275 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.61s)2276 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.43s)2277FAIL2278{"timestamp":"2026-09-18T13:10:14.640494162Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:38306","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1880,"threadName":"rustfs-worker","threadId":"ThreadId(204)"}22792026-09-18 13:10:14.923 UTC [126] LOG: received smart shutdown request22802026-09-18 13:10:14.928 UTC [126] LOG: background worker "logical replication launcher" (PID 136) exited with exit code 122812026-09-18 13:10:14.947 UTC [131] LOG: shutting down22822026-09-18 13:10:14.948 UTC [131] LOG: checkpoint starting: shutdown immediate22832026-09-18 13:10:16.125 UTC [131] LOG: checkpoint complete: wrote 11259 buffers (68.7%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.226 s, sync=0.938 s, total=1.179 s; sync files=21338, longest=0.002 s, average=0.001 s; distance=287445 kB, estimate=287445 kB; lsn=0/1301B290, redo lsn=0/1301B29022842026-09-18 13:10:16.242 UTC [126] LOG: database system is shut down