niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #270
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.06s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestEncodeNixBase32WithRealHash97--- PASS: TestShellSplit (0.00s)98=== CONT TestPathInfoHashCompatibility99=== CONT TestGetStorePathHash100--- PASS: TestEncodeNixBase32WithRealHash (0.00s)101=== CONT TestResolveStorePath102=== RUN TestGetStorePathHash/valid_store_path103=== CONT TestDoWithRetry_BodyReplayedViaGetBody104=== CONT TestRateLimiterFeedback105=== RUN TestRateLimiterFeedback/429_enables_limiter106=== PAUSE TestRateLimiterFeedback/429_enables_limiter107=== RUN TestRateLimiterFeedback/503_enables_limiter108=== CONT TestPathInfoCACompatibility109=== PAUSE TestRateLimiterFeedback/503_enables_limiter110=== CONT TestParsePathInfoJSON111=== RUN TestParsePathInfoJSON/Nix_format112=== PAUSE TestParsePathInfoJSON/Nix_format113=== CONT TestParsePathInfoJSONMultiplePaths114=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths115=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths116=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths117=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths118=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)119=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)120=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon121=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon122=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI123=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI124=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512125=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512126=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess127=== CONT TestConvertHashToNix32128=== RUN TestConvertHashToNix32/SRI_format_to_Nix32129=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32130=== CONT TestSetClientTLSErrors1312026/09/23 13:33:45 WARN Rate limiter enabled after throttle name=server-test rate=5132=== RUN TestConvertHashToNix32/already_Nix32_format133=== PAUSE TestConvertHashToNix32/already_Nix32_format134=== RUN TestConvertHashToNix32/invalid_format135=== PAUSE TestConvertHashToNix32/invalid_format136=== RUN TestPathInfoCACompatibility/null_ca_field137=== PAUSE TestPathInfoCACompatibility/null_ca_field138=== RUN TestPathInfoCACompatibility/old_string_format_-_text139=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text140=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive141=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive142=== RUN TestPathInfoCACompatibility/new_structured_format_-_text143=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text144=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method145=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method146=== CONT TestScriptTokenEmptyCommand147--- PASS: TestScriptTokenEmptyCommand (0.00s)148=== CONT TestFileTokenEmpty149=== PAUSE TestGetStorePathHash/valid_store_path150=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter151=== CONT TestScriptTokenScriptFails152=== RUN TestGetStorePathHash/basename_without_hyphen_should_error153=== RUN TestParsePathInfoJSON/Lix_format154=== PAUSE TestParsePathInfoJSON/Lix_format155--- PASS: TestResolveStorePath (0.00s)156=== CONT TestFileTokenMissing157=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter158=== RUN TestParsePathInfoJSON/empty_input159=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter160=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error161=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error162=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error163=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter164=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error165=== PAUSE TestParsePathInfoJSON/empty_input166=== RUN TestParsePathInfoJSON/whitespace_only167=== CONT TestFileTokenReadsAndCaches168=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error169=== PAUSE TestParsePathInfoJSON/whitespace_only170=== RUN TestParsePathInfoJSON/invalid_JSON171=== PAUSE TestParsePathInfoJSON/invalid_JSON172--- PASS: TestFileTokenEmpty (0.00s)173=== CONT TestScriptTokenNoExpiryRerunsEveryCall174=== CONT TestScriptTokenBadJSON175=== CONT TestStaticToken176--- PASS: TestStaticToken (0.00s)177=== CONT TestScriptTokenEmptyToken1782026/09/23 13:33:45 WARN Rate limiter enabled after throttle name=server-test rate=51792026/09/23 13:33:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59389180=== CONT TestScriptTokenCachesUntilRefresh1812026/09/23 13:33:45 WARN Rate limiter backed off name=server-test rate=51822026/09/23 13:33:45 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59389183--- PASS: TestFileTokenMissing (0.00s)184--- PASS: TestDoServerRequestAttachesToken (0.00s)185=== CONT TestDumpPathWriterError186--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)187=== CONT TestUploadMultipart_SupersededByPeer188=== RUN TestUploadMultipart_SupersededByPeer/exists189=== PAUSE TestUploadMultipart_SupersededByPeer/exists190=== RUN TestUploadMultipart_SupersededByPeer/missing191=== PAUSE TestUploadMultipart_SupersededByPeer/missing192=== CONT TestEncodeNixBase32193=== RUN TestEncodeNixBase32/test_string_hash194=== PAUSE TestEncodeNixBase32/test_string_hash195--- PASS: TestFileTokenReadsAndCaches (0.00s)196=== CONT TestDumpPathSingleFile197=== RUN TestSetClientTLSErrors/missing_cert_file198=== PAUSE TestSetClientTLSErrors/missing_cert_file199=== RUN TestEncodeNixBase32/empty_input200=== PAUSE TestEncodeNixBase32/empty_input201=== RUN TestSetClientTLSErrors/missing_key_file202=== CONT TestDumpPathMatchesNix203=== PAUSE TestSetClientTLSErrors/missing_key_file204=== RUN TestSetClientTLSErrors/missing_ca_file205=== PAUSE TestSetClientTLSErrors/missing_ca_file206=== RUN TestSetClientTLSErrors/invalid_ca_file207=== PAUSE TestSetClientTLSErrors/invalid_ca_file208=== CONT TestFilterOversizedClosures209=== RUN TestFilterOversizedClosures/no_limit_keeps_everything210=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything211=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped212=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== RUN TestFilterOversizedClosures/all_closures_skipped214=== PAUSE TestFilterOversizedClosures/all_closures_skipped215=== CONT TestCaseHackSuffix216=== CONT TestPartSizeForNAR217--- PASS: TestScriptTokenScriptFails (0.00s)218=== RUN TestPartSizeForNAR/zero_stays_at_minimum219=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum220=== RUN TestPartSizeForNAR/small_stays_at_minimum221=== PAUSE TestPartSizeForNAR/small_stays_at_minimum222=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum223=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum224=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts225=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts226=== RUN TestPartSizeForNAR/1_TiB227=== PAUSE TestPartSizeForNAR/1_TiB228=== RUN TestPartSizeForNAR/5_TiB_S3_max_object229=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object230=== RUN TestPartSizeForNAR/capped_at_5_GiB231=== PAUSE TestPartSizeForNAR/capped_at_5_GiB232=== CONT TestUploadMultipart_PartsInParallel233--- PASS: TestScriptTokenBadJSON (0.01s)234=== CONT TestStreamPushRequestLine235--- PASS: TestScriptTokenEmptyToken (0.01s)236=== CONT TestSetClientTLSDoesNotMutateDefaultTransport2372026/09/23 13:33:45 ERROR Upload failed error=boom count=1238--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)239=== CONT TestSetClientTLS240=== RUN TestSetClientTLS/rejects_connection_without_client_cert241=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert242=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA243=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA244=== RUN TestSetClientTLS/preserves_debug_logging_transport245=== PAUSE TestSetClientTLS/preserves_debug_logging_transport246=== CONT TestRegisterUploadedObjectReusesConnections247--- PASS: TestStreamPushRequestLine (0.01s)248=== CONT TestClientSignaturesByStorePath249--- PASS: TestClientSignaturesByStorePath (0.00s)250=== CONT TestStreamPushReportsSignatures2512026/09/23 13:33:45 ERROR Upload failed error=boom count=1252--- PASS: TestStreamPushReportsSignatures (0.00s)253=== CONT TestStreamPushBatchesUnderLoad254--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)255--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)256=== CONT TestStreamPushGivesUpOnDeadServer257=== CONT TestStreamPushIsolatesFailures2582026/09/23 13:33:45 ERROR Upload failed error="bad path" count=3259--- PASS: TestStreamPushIsolatesFailures (0.00s)260=== CONT TestStreamPushReportsEveryPath261--- PASS: TestStreamPushReportsEveryPath (0.00s)262=== CONT TestShellSplitErrors263--- PASS: TestShellSplitErrors (0.00s)264=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2652026/09/23 13:33:45 ERROR Upload failed error="connection refused" count=202662026/09/23 13:33:45 ERROR Server seems unavailable, giving up on batch untried=17267=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)268=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths269--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)270 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)271 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)272--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)273=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512274=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon275=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI276--- PASS: TestPathInfoHashCompatibility (0.00s)277 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)278 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)279 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)280 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)281=== CONT TestConvertHashToNix32/SRI_format_to_Nix32282=== CONT TestPathInfoCACompatibility/null_ca_field283=== CONT TestConvertHashToNix32/invalid_format284=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method285=== CONT TestPathInfoCACompatibility/new_structured_format_-_text286=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive287=== CONT TestConvertHashToNix32/already_Nix32_format288=== CONT TestPathInfoCACompatibility/old_string_format_-_text289--- PASS: TestConvertHashToNix32 (0.00s)290 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)291 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)292 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)293--- PASS: TestPathInfoCACompatibility (0.00s)294 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)295 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)296 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)297 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)298 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)299=== CONT TestRateLimiterFeedback/429_enables_limiter300=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3012026/09/23 13:33:45 WARN Rate limiter enabled after throttle name=server-test rate=53022026/09/23 13:33:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:59465303--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)304=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3052026/09/23 13:33:45 WARN Rate limiter backed off name=server-test rate=5306=== CONT TestRateLimiterFeedback/503_enables_limiter307=== CONT TestGetStorePathHash/valid_store_path308=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error309=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error310=== CONT TestGetStorePathHash/basename_without_hyphen_should_error311=== CONT TestParsePathInfoJSON/Nix_format312--- PASS: TestGetStorePathHash (0.00s)313 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)314 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)315 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)316 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)317=== CONT TestParsePathInfoJSON/whitespace_only318=== CONT TestParsePathInfoJSON/invalid_JSON319=== CONT TestParsePathInfoJSON/Lix_format320=== CONT TestParsePathInfoJSON/empty_input321=== CONT TestUploadMultipart_SupersededByPeer/exists322--- PASS: TestParsePathInfoJSON (0.00s)323 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)324 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)325 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)326 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)327 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)328=== CONT TestUploadMultipart_SupersededByPeer/missing3292026/09/23 13:33:45 WARN Rate limiter enabled after throttle name=server-test rate=53302026/09/23 13:33:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:594713312026/09/23 13:33:45 WARN Rate limiter backed off name=server-test rate=5332--- PASS: TestRateLimiterFeedback (0.00s)333 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)334 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)335 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)336 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)337=== CONT TestEncodeNixBase32/test_string_hash338=== CONT TestEncodeNixBase32/empty_input339--- PASS: TestEncodeNixBase32 (0.00s)340 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)341 --- PASS: TestEncodeNixBase32/empty_input (0.00s)342=== CONT TestSetClientTLSErrors/missing_cert_file343=== CONT TestSetClientTLSErrors/invalid_ca_file344=== CONT TestSetClientTLSErrors/missing_ca_file345--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)346 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)347 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)348=== CONT TestSetClientTLSErrors/missing_key_file349=== CONT TestFilterOversizedClosures/no_limit_keeps_everything350=== CONT TestFilterOversizedClosures/all_closures_skipped3512026/09/23 13:33:45 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=50352=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3532026/09/23 13:33:45 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=2000354--- PASS: TestFilterOversizedClosures (0.00s)355 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)356 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)357 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)358=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts359=== CONT TestPartSizeForNAR/capped_at_5_GiB360=== CONT TestPartSizeForNAR/1_TiB361=== CONT TestPartSizeForNAR/5_TiB_S3_max_object362=== CONT TestPartSizeForNAR/small_stays_at_minimum363=== CONT TestSetClientTLS/rejects_connection_without_client_cert364=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum365=== CONT TestPartSizeForNAR/zero_stays_at_minimum366=== CONT TestSetClientTLS/preserves_debug_logging_transport367--- PASS: TestPartSizeForNAR (0.00s)368 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)369 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)370 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)371 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)372 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)373 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)374 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)375=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA376--- PASS: TestSetClientTLSErrors (0.00s)377 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)378 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)379 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)381--- PASS: TestDumpPathWriterError (0.05s)3822026/09/23 13:33:45 http: TLS handshake error from 127.0.0.1:59477: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathSingleFile (0.05s)388--- PASS: TestCaseHackSuffix (0.05s)389--- PASS: TestDumpPathMatchesNix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld1".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-66117-1423409739/postgres993951294/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: 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.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-66117-1423409739/postgres993951294/data -l logfile start421422/nix/var/nix/builds/nix-66117-1423409739/postgres993951294:5432 - no response4232026-09-23 13:33:47.135 UTC [66154] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-09-23 13:33:47.135 UTC [66154] LOG: listening on Unix socket "/nix/var/nix/builds/nix-66117-1423409739/postgres993951294/.s.PGSQL.5432"4252026-09-23 13:33:47.137 UTC [66161] LOG: database system was shut down at 2026-09-23 13:33:47 UTC4262026-09-23 13:33:47.138 UTC [66154] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-66117-1423409739/postgres993951294:5432 - accepting connections428{"timestamp":"2026-09-23T13:33:47.352502Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1357c80c-1237-407b-aee4-5300dc478332","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}429{"timestamp":"2026-09-23T13:33:47.45504Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7d65aa2d-d857-4a15-a513-c29fbaeb4a19","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestResolveDBConnectionString463=== PAUSE TestResolveDBConnectionString464=== RUN TestLeadElectsOneAndHandsOver465=== PAUSE TestLeadElectsOneAndHandsOver466=== RUN TestLeadIncumbentWinsAfterRestart4672026-09-23 13:33:47.646 UTC [66191] ERROR: relation "goose_db_version" does not exist at character 364682026-09-23 13:33:47.646 UTC [66191] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4692026/09/23 13:33:47 OK 20241026095416_initial_model.sql (3.35ms)4702026/09/23 13:33:47 OK 20251210153512_drop_unused_gin_index.sql (395.04µs)4712026/09/23 13:33:47 OK 20251218171726_add_pins.sql (907.83µs)4722026/09/23 13:33:47 OK 20260628120000_add_object_size_and_stats.sql (921.21µs)4732026/09/23 13:33:47 OK 20260905000000_add_claims.sql (920.83µs)4742026/09/23 13:33:47 OK 20260920000000_drop_claims.sql (552.5µs)4752026/09/23 13:33:47 OK 20260923120000_add_pushes.sql (417.13µs)4762026/09/23 13:33:47 goose: successfully migrated database to version: 202609231200004772026/09/23 13:33:47 OK 1_commit_pending_closure.sql (800.58µs)4782026/09/23 13:33:47 OK 2_object_stats_trigger.sql (198.5µs)4792026/09/23 13:33:47 OK 3_commit_push.sql (196.67µs)4802026/09/23 13:33:47 goose: up to current file version: 34812026/09/23 13:33:47 INFO lead: acquired remote=192.0.2.1:12344822026/09/23 13:33:48 INFO lead: released remote=192.0.2.1:12344832026/09/23 13:33:48 INFO lead: acquired remote=192.0.2.1:12344842026/09/23 13:33:48 INFO lead: released remote=192.0.2.1:1234485--- PASS: TestLeadIncumbentWinsAfterRestart (0.81s)486=== RUN TestLeadEndsOnShutdown487=== PAUSE TestLeadEndsOnShutdown488=== RUN TestGCAdvisoryLockBlocksConcurrentRun4892026-09-23 13:33:48.454 UTC [66195] ERROR: relation "goose_db_version" does not exist at character 364902026-09-23 13:33:48.454 UTC [66195] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4912026/09/23 13:33:48 OK 20241026095416_initial_model.sql (3.67ms)4922026/09/23 13:33:48 OK 20251210153512_drop_unused_gin_index.sql (382.63µs)4932026/09/23 13:33:48 OK 20251218171726_add_pins.sql (861.54µs)4942026/09/23 13:33:48 OK 20260628120000_add_object_size_and_stats.sql (860.08µs)4952026/09/23 13:33:48 OK 20260905000000_add_claims.sql (1.02ms)4962026/09/23 13:33:48 OK 20260920000000_drop_claims.sql (623.08µs)4972026/09/23 13:33:48 OK 20260923120000_add_pushes.sql (393.42µs)4982026/09/23 13:33:48 goose: successfully migrated database to version: 202609231200004992026/09/23 13:33:48 OK 1_commit_pending_closure.sql (877.21µs)5002026/09/23 13:33:48 OK 2_object_stats_trigger.sql (213.46µs)5012026/09/23 13:33:48 OK 3_commit_push.sql (200.21µs)5022026/09/23 13:33:48 goose: up to current file version: 3503--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.16s)504=== RUN TestGCBugBareHashReferences505=== PAUSE TestGCBugBareHashReferences506=== RUN TestGCMetrics507=== PAUSE TestGCMetrics508=== RUN TestGCTaskStore_StartNew509=== PAUSE TestGCTaskStore_StartNew510=== RUN TestGCTaskStore_DeduplicateSameParams511=== PAUSE TestGCTaskStore_DeduplicateSameParams512=== RUN TestGCTaskStore_ConflictDifferentParams513=== PAUSE TestGCTaskStore_ConflictDifferentParams514=== RUN TestGCTaskStore_GetEmpty515=== PAUSE TestGCTaskStore_GetEmpty516=== RUN TestGCTaskStore_GetReturnsLatest517=== PAUSE TestGCTaskStore_GetReturnsLatest518=== RUN TestGCTaskStore_CompletedAllowsNewTask519=== PAUSE TestGCTaskStore_CompletedAllowsNewTask520=== RUN TestGCTaskStore_PhaseUpdates521=== PAUSE TestGCTaskStore_PhaseUpdates522=== RUN TestGCTaskStore_Fail523=== PAUSE TestGCTaskStore_Fail524=== RUN TestGracefulShutdownDrainsInflight525=== PAUSE TestGracefulShutdownDrainsInflight526=== RUN TestService_healthCheckHandler527=== PAUSE TestService_healthCheckHandler528=== RUN TestService_readinessHandler529=== PAUSE TestService_readinessHandler530=== RUN TestGenerateLandingPage531=== PAUSE TestGenerateLandingPage532=== RUN TestCacheConfigHandlerMaxNarSize533=== PAUSE TestCacheConfigHandlerMaxNarSize534=== RUN TestCreatePendingClosureRejectsOversizedNAR535=== PAUSE TestCreatePendingClosureRejectsOversizedNAR536=== RUN TestNARDeduplicationMetadataUploadBug537=== PAUSE TestNARDeduplicationMetadataUploadBug538=== RUN TestMetricsInventory539=== PAUSE TestMetricsInventory540=== RUN TestService_NativeMTLS541=== PAUSE TestService_NativeMTLS542=== RUN TestServerTLSConfig543=== PAUSE TestServerTLSConfig544=== RUN TestMultipartCleanup545=== PAUSE TestMultipartCleanup546=== RUN TestObjectStatsTrigger547=== PAUSE TestObjectStatsTrigger548=== RUN TestOrphanedObjectsGC549=== PAUSE TestOrphanedObjectsGC550=== RUN TestOrphanedObjectsGCStressTest551=== PAUSE TestOrphanedObjectsGCStressTest552=== RUN TestResurrectedObjectNotDeleted553=== PAUSE TestResurrectedObjectNotDeleted554=== RUN TestCreatePin_ReservedPins555=== PAUSE TestCreatePin_ReservedPins556=== RUN TestParseSingleRange557=== PAUSE TestParseSingleRange558=== RUN TestProxyHeadersOnlyTrustedOnSocket559=== PAUSE TestProxyHeadersOnlyTrustedOnSocket560=== RUN TestIsValidCachePath561=== PAUSE TestIsValidCachePath562=== RUN TestReadProxyNarinfo563=== PAUSE TestReadProxyNarinfo564=== RUN TestReadProxyNarinfoAlreadyDecompressed565=== PAUSE TestReadProxyNarinfoAlreadyDecompressed566=== RUN TestReadProxyNarStreaming567=== PAUSE TestReadProxyNarStreaming568=== RUN TestReadProxy404569=== PAUSE TestReadProxy404570=== RUN TestReadProxyInvalidPath571=== PAUSE TestReadProxyInvalidPath572=== RUN TestReadProxyHead573=== PAUSE TestReadProxyHead574=== RUN TestReadProxyConditionalGet575=== PAUSE TestReadProxyConditionalGet576=== RUN TestReadProxyRootRedirectsToIndexHTML577=== PAUSE TestReadProxyRootRedirectsToIndexHTML578=== RUN TestReadProxyDisabled579=== PAUSE TestReadProxyDisabled580=== RUN TestReadRedirectNar581=== PAUSE TestReadRedirectNar582=== RUN TestReadRedirectKeepsNarinfoProxied583=== PAUSE TestReadRedirectKeepsNarinfoProxied584=== RUN TestReadProxyRangeRequest585=== PAUSE TestReadProxyRangeRequest586=== RUN TestReadRedirectUsesPublicS3URL587=== PAUSE TestReadRedirectUsesPublicS3URL588=== RUN TestPush_OverlappingRootsStoreOneRowPerKey589=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey590=== RUN TestPush_CompleteCommitsEveryRoot591=== PAUSE TestPush_CompleteCommitsEveryRoot592=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected593=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected594=== RUN TestPush_RejectsBadRequests595=== PAUSE TestPush_RejectsBadRequests596=== RUN TestPush_SignsNarinfosOfItsPendingObjects597=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects598=== RUN TestRedundantMultipartUpload599=== PAUSE TestRedundantMultipartUpload600=== RUN TestCompleteMultipartUpload_ErrorButObjectExists601=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists602=== RUN TestCompletedNarNotReofferedAcrossClosures603=== PAUSE TestCompletedNarNotReofferedAcrossClosures604=== RUN TestPresignedUploadRegisteredBeforeCommit605=== PAUSE TestPresignedUploadRegisteredBeforeCommit606=== RUN TestService_Rustfstest607=== PAUSE TestService_Rustfstest608=== RUN TestParseSize609=== PAUSE TestParseSize610=== RUN TestSkippedUploadsHandler611=== PAUSE TestSkippedUploadsHandler612=== RUN TestSystemdListenerNotActivated613--- PASS: TestSystemdListenerNotActivated (0.00s)614=== RUN TestWatchdogBeatsWhenHealthy615--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)616=== RUN TestWatchdogSkipsWhenUnhealthy6172026/09/23 13:33:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6182026/09/23 13:33:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6192026/09/23 13:33:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6202026/09/23 13:33:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6212026/09/23 13:33:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:33:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:33:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:33:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:33:48 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"626--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)627=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle628=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle629=== RUN TestProxyWriteTimeout630=== PAUSE TestProxyWriteTimeout631=== RUN TestIsValidUploadKey632=== PAUSE TestIsValidUploadKey633=== RUN TestUploadHandlersRejectInvalidKeys634=== PAUSE TestUploadHandlersRejectInvalidKeys635=== RUN TestUploadHandlersRejectOversizedBody636=== PAUSE TestUploadHandlersRejectOversizedBody637=== RUN TestService_cleanupPendingClosuresHandler638=== PAUSE TestService_cleanupPendingClosuresHandler639=== RUN TestService_createPendingClosureHandler640=== PAUSE TestService_createPendingClosureHandler641=== RUN TestService_verifyS3Integrity642=== PAUSE TestService_verifyS3Integrity643=== RUN TestCompleteMultipartUnregistered644=== PAUSE TestCompleteMultipartUnregistered645=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT646=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT647=== CONT TestRedundantMultipartUpload648=== CONT TestService_AuthMiddleware649=== CONT TestPush_SignsNarinfosOfItsPendingObjects650=== CONT TestPush_RejectsBadRequests651=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected652=== CONT TestPush_CompleteCommitsEveryRoot653=== CONT TestPush_OverlappingRootsStoreOneRowPerKey654=== CONT TestReadRedirectUsesPublicS3URL655=== CONT TestReadProxyRangeRequest656=== CONT TestReadRedirectKeepsNarinfoProxied6572026-09-23 13:33:49.071 UTC [66217] ERROR: relation "goose_db_version" does not exist at character 366582026-09-23 13:33:49.071 UTC [66217] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6592026-09-23 13:33:49.072 UTC [66218] ERROR: relation "goose_db_version" does not exist at character 366602026-09-23 13:33:49.072 UTC [66218] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6612026-09-23 13:33:49.073 UTC [66219] ERROR: relation "goose_db_version" does not exist at character 366622026-09-23 13:33:49.073 UTC [66219] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6632026-09-23 13:33:49.073 UTC [66220] ERROR: relation "goose_db_version" does not exist at character 366642026-09-23 13:33:49.073 UTC [66220] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6652026-09-23 13:33:49.073 UTC [66221] ERROR: relation "goose_db_version" does not exist at character 366662026-09-23 13:33:49.073 UTC [66221] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6672026-09-23 13:33:49.074 UTC [66222] ERROR: relation "goose_db_version" does not exist at character 366682026-09-23 13:33:49.074 UTC [66222] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6692026-09-23 13:33:49.075 UTC [66223] ERROR: relation "goose_db_version" does not exist at character 366702026-09-23 13:33:49.075 UTC [66223] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6712026-09-23 13:33:49.076 UTC [66224] ERROR: relation "goose_db_version" does not exist at character 366722026-09-23 13:33:49.076 UTC [66224] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6732026-09-23 13:33:49.076 UTC [66226] ERROR: relation "goose_db_version" does not exist at character 366742026-09-23 13:33:49.076 UTC [66226] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6752026-09-23 13:33:49.077 UTC [66225] ERROR: relation "goose_db_version" does not exist at character 366762026-09-23 13:33:49.077 UTC [66225] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6772026/09/23 13:33:49 OK 20241026095416_initial_model.sql (9.09ms)6782026/09/23 13:33:49 OK 20241026095416_initial_model.sql (6.9ms)6792026/09/23 13:33:49 OK 20241026095416_initial_model.sql (8.24ms)6802026/09/23 13:33:49 OK 20241026095416_initial_model.sql (8.97ms)6812026/09/23 13:33:49 OK 20241026095416_initial_model.sql (9.04ms)6822026/09/23 13:33:49 OK 20241026095416_initial_model.sql (8.18ms)6832026/09/23 13:33:49 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)6842026/09/23 13:33:49 OK 20241026095416_initial_model.sql (7.83ms)6852026/09/23 13:33:49 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)6862026/09/23 13:33:49 OK 20251210153512_drop_unused_gin_index.sql (758.42µs)6872026/09/23 13:33:49 OK 20251210153512_drop_unused_gin_index.sql (704.33µs)6882026/09/23 13:33:49 OK 20251210153512_drop_unused_gin_index.sql (720.29µs)6892026/09/23 13:33:49 OK 20251210153512_drop_unused_gin_index.sql (845.38µs)6902026/09/23 13:33:49 OK 20251210153512_drop_unused_gin_index.sql (762.25µs)6912026/09/23 13:33:49 OK 20241026095416_initial_model.sql (8.12ms)6922026/09/23 13:33:49 OK 20251218171726_add_pins.sql (1.47ms)6932026/09/23 13:33:49 OK 20251210153512_drop_unused_gin_index.sql (479.88µs)6942026/09/23 13:33:49 OK 20251218171726_add_pins.sql (1.9ms)6952026/09/23 13:33:49 OK 20251218171726_add_pins.sql (1.72ms)6962026/09/23 13:33:49 OK 20241026095416_initial_model.sql (8.23ms)6972026/09/23 13:33:49 OK 20251218171726_add_pins.sql (1.5ms)6982026/09/23 13:33:49 OK 20251218171726_add_pins.sql (1.8ms)6992026/09/23 13:33:49 OK 20241026095416_initial_model.sql (7.9ms)7002026/09/23 13:33:49 OK 20251210153512_drop_unused_gin_index.sql (474.63µs)7012026/09/23 13:33:49 OK 20251218171726_add_pins.sql (1.91ms)7022026/09/23 13:33:49 OK 20251218171726_add_pins.sql (2ms)7032026/09/23 13:33:49 OK 20251218171726_add_pins.sql (1.65ms)7042026/09/23 13:33:49 OK 20260628120000_add_object_size_and_stats.sql (1.73ms)7052026/09/23 13:33:49 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)7062026/09/23 13:33:49 OK 20260628120000_add_object_size_and_stats.sql (1.3ms)7072026/09/23 13:33:49 OK 20260628120000_add_object_size_and_stats.sql (1.66ms)7082026/09/23 13:33:49 OK 20260628120000_add_object_size_and_stats.sql (2.07ms)7092026/09/23 13:33:49 OK 20251218171726_add_pins.sql (1.47ms)7102026/09/23 13:33:49 OK 20260628120000_add_object_size_and_stats.sql (1.67ms)7112026/09/23 13:33:49 OK 20260628120000_add_object_size_and_stats.sql (2.19ms)7122026/09/23 13:33:49 OK 20260628120000_add_object_size_and_stats.sql (1.87ms)7132026/09/23 13:33:49 OK 20260628120000_add_object_size_and_stats.sql (1.77ms)7142026/09/23 13:33:49 OK 20251218171726_add_pins.sql (1.91ms)7152026/09/23 13:33:49 OK 20260905000000_add_claims.sql (2.35ms)7162026/09/23 13:33:49 OK 20260905000000_add_claims.sql (2.08ms)7172026/09/23 13:33:49 OK 20260905000000_add_claims.sql (1.92ms)7182026/09/23 13:33:49 OK 20260905000000_add_claims.sql (2.89ms)7192026/09/23 13:33:49 OK 20260628120000_add_object_size_and_stats.sql (2.7ms)7202026/09/23 13:33:49 OK 20260628120000_add_object_size_and_stats.sql (1.32ms)7212026/09/23 13:33:49 OK 20260920000000_drop_claims.sql (1.19ms)7222026/09/23 13:33:49 OK 20260905000000_add_claims.sql (2.39ms)7232026/09/23 13:33:49 OK 20260920000000_drop_claims.sql (1.26ms)7242026/09/23 13:33:49 OK 20260905000000_add_claims.sql (2.16ms)7252026/09/23 13:33:49 OK 20260920000000_drop_claims.sql (1.37ms)7262026/09/23 13:33:49 OK 20260905000000_add_claims.sql (3.02ms)7272026/09/23 13:33:49 OK 20260920000000_drop_claims.sql (1.03ms)7282026/09/23 13:33:49 OK 20260905000000_add_claims.sql (3.31ms)7292026/09/23 13:33:49 OK 20260923120000_add_pushes.sql (695.25µs)7302026/09/23 13:33:49 goose: successfully migrated database to version: 202609231200007312026/09/23 13:33:49 OK 20260923120000_add_pushes.sql (1.21ms)7322026/09/23 13:33:49 OK 20260920000000_drop_claims.sql (1.21ms)7332026/09/23 13:33:49 goose: successfully migrated database to version: 202609231200007342026/09/23 13:33:49 OK 20260923120000_add_pushes.sql (1.19ms)7352026/09/23 13:33:49 goose: successfully migrated database to version: 202609231200007362026/09/23 13:33:49 OK 20260923120000_add_pushes.sql (956.04µs)7372026/09/23 13:33:49 goose: successfully migrated database to version: 202609231200007382026/09/23 13:33:49 OK 20260920000000_drop_claims.sql (1.4ms)7392026/09/23 13:33:49 OK 20260920000000_drop_claims.sql (1.17ms)7402026/09/23 13:33:49 OK 20260923120000_add_pushes.sql (601.25µs)7412026/09/23 13:33:49 goose: successfully migrated database to version: 202609231200007422026/09/23 13:33:49 OK 20260920000000_drop_claims.sql (1.01ms)7432026/09/23 13:33:49 OK 20260905000000_add_claims.sql (2.1ms)7442026/09/23 13:33:49 OK 20260923120000_add_pushes.sql (594.42µs)7452026/09/23 13:33:49 goose: successfully migrated database to version: 202609231200007462026/09/23 13:33:49 OK 20260905000000_add_claims.sql (2.47ms)7472026/09/23 13:33:49 OK 20260923120000_add_pushes.sql (781.58µs)7482026/09/23 13:33:49 goose: successfully migrated database to version: 202609231200007492026/09/23 13:33:49 OK 1_commit_pending_closure.sql (1.5ms)7502026/09/23 13:33:49 OK 1_commit_pending_closure.sql (1.05ms)7512026/09/23 13:33:49 OK 20260923120000_add_pushes.sql (680.88µs)7522026/09/23 13:33:49 goose: successfully migrated database to version: 202609231200007532026/09/23 13:33:49 OK 1_commit_pending_closure.sql (1.52ms)7542026/09/23 13:33:49 OK 1_commit_pending_closure.sql (1.41ms)7552026/09/23 13:33:49 OK 2_object_stats_trigger.sql (309.08µs)7562026/09/23 13:33:49 OK 2_object_stats_trigger.sql (342.25µs)7572026/09/23 13:33:49 OK 1_commit_pending_closure.sql (821.88µs)7582026/09/23 13:33:49 OK 2_object_stats_trigger.sql (419.75µs)7592026/09/23 13:33:49 OK 1_commit_pending_closure.sql (1.41ms)7602026/09/23 13:33:49 OK 3_commit_push.sql (284.83µs)7612026/09/23 13:33:49 goose: up to current file version: 37622026/09/23 13:33:49 OK 2_object_stats_trigger.sql (502.58µs)7632026/09/23 13:33:49 OK 2_object_stats_trigger.sql (256.29µs)7642026/09/23 13:33:49 OK 3_commit_push.sql (475.17µs)7652026/09/23 13:33:49 goose: up to current file version: 37662026/09/23 13:33:49 OK 3_commit_push.sql (362.88µs)7672026/09/23 13:33:49 goose: up to current file version: 37682026/09/23 13:33:49 OK 3_commit_push.sql (266.63µs)7692026/09/23 13:33:49 OK 1_commit_pending_closure.sql (943.25µs)7702026/09/23 13:33:49 goose: up to current file version: 37712026/09/23 13:33:49 OK 2_object_stats_trigger.sql (387.58µs)7722026/09/23 13:33:49 OK 3_commit_push.sql (278.21µs)7732026/09/23 13:33:49 goose: up to current file version: 37742026/09/23 13:33:49 OK 20260920000000_drop_claims.sql (1.65ms)7752026/09/23 13:33:49 OK 1_commit_pending_closure.sql (1.35ms)7762026/09/23 13:33:49 OK 20260920000000_drop_claims.sql (1.49ms)7772026/09/23 13:33:49 OK 2_object_stats_trigger.sql (299.79µs)7782026/09/23 13:33:49 OK 3_commit_push.sql (298µs)7792026/09/23 13:33:49 goose: up to current file version: 37802026/09/23 13:33:49 OK 3_commit_push.sql (211.17µs)7812026/09/23 13:33:49 goose: up to current file version: 37822026/09/23 13:33:49 OK 2_object_stats_trigger.sql (326.79µs)7832026/09/23 13:33:49 OK 20260923120000_add_pushes.sql (553.21µs)7842026/09/23 13:33:49 goose: successfully migrated database to version: 202609231200007852026/09/23 13:33:49 OK 20260923120000_add_pushes.sql (417.21µs)7862026/09/23 13:33:49 goose: successfully migrated database to version: 202609231200007872026/09/23 13:33:49 OK 3_commit_push.sql (217.08µs)7882026/09/23 13:33:49 goose: up to current file version: 37892026/09/23 13:33:49 OK 1_commit_pending_closure.sql (647.29µs)7902026/09/23 13:33:49 OK 1_commit_pending_closure.sql (666.17µs)7912026/09/23 13:33:49 OK 2_object_stats_trigger.sql (189.13µs)7922026/09/23 13:33:49 OK 2_object_stats_trigger.sql (183.67µs)7932026/09/23 13:33:49 OK 3_commit_push.sql (170.88µs)7942026/09/23 13:33:49 goose: up to current file version: 37952026/09/23 13:33:49 OK 3_commit_push.sql (164.38µs)7962026/09/23 13:33:49 goose: up to current file version: 37972026/09/23 13:33:49 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"798--- PASS: TestService_AuthMiddleware (0.42s)799=== CONT TestReadRedirectNar8002026/09/23 13:33:49 INFO Received uploads request method=POST path=/api/pending_closures8012026/09/23 13:33:49 INFO Received uploads request method=POST path=/api/pending_closures802--- PASS: TestReadRedirectUsesPublicS3URL (0.76s)803=== CONT TestReadProxyDisabled804=== RUN TestPush_RejectsBadRequests/no_objects805=== PAUSE TestPush_RejectsBadRequests/no_objects806=== RUN TestPush_RejectsBadRequests/bad_root807=== PAUSE TestPush_RejectsBadRequests/bad_root808=== RUN TestPush_RejectsBadRequests/root_not_in_objects809=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects810=== RUN TestPush_RejectsBadRequests/no_roots811=== PAUSE TestPush_RejectsBadRequests/no_roots812=== CONT TestReadProxyRootRedirectsToIndexHTML8132026/09/23 13:33:49 INFO Received push request method=POST path=/api/pushes814--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.17s)815=== CONT TestReadProxyConditionalGet8162026-09-23 13:33:50.037 UTC [66237] ERROR: relation "goose_db_version" does not exist at character 368172026-09-23 13:33:50.037 UTC [66237] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026/09/23 13:33:50 INFO Received push request method=POST path=/api/pushes8192026/09/23 13:33:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8202026/09/23 13:33:50 INFO Signed narinfos id=1 count=1821--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.38s)822=== CONT TestReadProxyHead8232026/09/23 13:33:50 OK 20241026095416_initial_model.sql (90.04ms)8242026/09/23 13:33:50 OK 20251210153512_drop_unused_gin_index.sql (11.7ms)8252026/09/23 13:33:50 OK 20251218171726_add_pins.sql (15.97ms)8262026/09/23 13:33:50 OK 20260628120000_add_object_size_and_stats.sql (22.64ms)8272026/09/23 13:33:50 OK 20260905000000_add_claims.sql (19.47ms)8282026/09/23 13:33:50 OK 20260920000000_drop_claims.sql (14.25ms)8292026/09/23 13:33:50 OK 20260923120000_add_pushes.sql (15.4ms)8302026/09/23 13:33:50 goose: successfully migrated database to version: 202609231200008312026/09/23 13:33:50 OK 1_commit_pending_closure.sql (2.29ms)8322026/09/23 13:33:50 OK 2_object_stats_trigger.sql (529µs)8332026/09/23 13:33:50 OK 3_commit_push.sql (442µs)8342026/09/23 13:33:50 goose: up to current file version: 38352026-09-23 13:33:50.300 UTC [66240] ERROR: relation "goose_db_version" does not exist at character 368362026-09-23 13:33:50.300 UTC [66240] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC837--- PASS: TestReadRedirectKeepsNarinfoProxied (1.55s)838=== CONT TestIsValidUploadKey839=== RUN TestIsValidUploadKey/narinfo840=== PAUSE TestIsValidUploadKey/narinfo841=== RUN TestIsValidUploadKey/nar_zst842=== PAUSE TestIsValidUploadKey/nar_zst843=== RUN TestIsValidUploadKey/nar_xz844=== PAUSE TestIsValidUploadKey/nar_xz845=== RUN TestIsValidUploadKey/nar_plain846=== PAUSE TestIsValidUploadKey/nar_plain847=== RUN TestIsValidUploadKey/listing848=== PAUSE TestIsValidUploadKey/listing849=== RUN TestIsValidUploadKey/build_log850=== PAUSE TestIsValidUploadKey/build_log851=== RUN TestIsValidUploadKey/build_log_home-manager_file852=== PAUSE TestIsValidUploadKey/build_log_home-manager_file853=== RUN TestIsValidUploadKey/build_log_plus_in_name854=== PAUSE TestIsValidUploadKey/build_log_plus_in_name855=== RUN TestIsValidUploadKey/build_log_question_mark856=== PAUSE TestIsValidUploadKey/build_log_question_mark857=== RUN TestIsValidUploadKey/build_log_equals858=== PAUSE TestIsValidUploadKey/build_log_equals859=== RUN TestIsValidUploadKey/realisation860=== PAUSE TestIsValidUploadKey/realisation861=== RUN TestIsValidUploadKey/realisation_plus_in_output862=== PAUSE TestIsValidUploadKey/realisation_plus_in_output863=== RUN TestIsValidUploadKey/nix-cache-info864=== PAUSE TestIsValidUploadKey/nix-cache-info865=== RUN TestIsValidUploadKey/index.html866=== PAUSE TestIsValidUploadKey/index.html867=== RUN TestIsValidUploadKey/narinfo_key,_nar_type868=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type869=== RUN TestIsValidUploadKey/nar_key,_narinfo_type870=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type871=== RUN TestIsValidUploadKey/listing_key,_narinfo_type872=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type873=== RUN TestIsValidUploadKey/traversal874=== PAUSE TestIsValidUploadKey/traversal875=== RUN TestIsValidUploadKey/traversal_nar876=== PAUSE TestIsValidUploadKey/traversal_nar877=== RUN TestIsValidUploadKey/absolute878=== PAUSE TestIsValidUploadKey/absolute879=== RUN TestIsValidUploadKey/empty_key880=== PAUSE TestIsValidUploadKey/empty_key881=== RUN TestIsValidUploadKey/unknown_type882=== PAUSE TestIsValidUploadKey/unknown_type883=== CONT TestReadProxyInvalidPath8842026/09/23 13:33:50 OK 20241026095416_initial_model.sql (136.38ms)8852026/09/23 13:33:50 OK 20251210153512_drop_unused_gin_index.sql (9.02ms)8862026/09/23 13:33:50 OK 20251218171726_add_pins.sql (32.02ms)8872026/09/23 13:33:50 OK 20260628120000_add_object_size_and_stats.sql (27.04ms)8882026-09-23 13:33:50.546 UTC [66243] ERROR: relation "goose_db_version" does not exist at character 368892026-09-23 13:33:50.546 UTC [66243] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC890--- PASS: TestReadProxyRangeRequest (1.78s)891=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT8922026/09/23 13:33:50 OK 20260905000000_add_claims.sql (35.87ms)8932026/09/23 13:33:50 OK 20260920000000_drop_claims.sql (25.16ms)8942026/09/23 13:33:50 OK 20260923120000_add_pushes.sql (9.13ms)8952026/09/23 13:33:50 goose: successfully migrated database to version: 202609231200008962026/09/23 13:33:50 OK 1_commit_pending_closure.sql (2ms)8972026/09/23 13:33:50 OK 2_object_stats_trigger.sql (480.54µs)8982026/09/23 13:33:50 OK 3_commit_push.sql (429.83µs)8992026/09/23 13:33:50 goose: up to current file version: 39002026/09/23 13:33:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9012026/09/23 13:33:50 OK 20241026095416_initial_model.sql (112.86ms)9022026/09/23 13:33:50 OK 20251210153512_drop_unused_gin_index.sql (16.71ms)9032026/09/23 13:33:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NmI2Y2EyYjUtNjhkMC00ZGZjLWI3YmItODU5Y2FmODUzNThmLmFhZTM4ODc0LWUxMTMtNDAzYy1iMWYyLTA5ODU0NzdkNzdiOHgxNzkwMTcwNDI5MzM1MDMyMDAw parts=12904--- PASS: TestRedundantMultipartUpload (1.96s)905=== CONT TestReadProxy4049062026/09/23 13:33:50 INFO Received push request method=POST path=/api/pushes9072026/09/23 13:33:50 OK 20251218171726_add_pins.sql (32.56ms)9082026/09/23 13:33:50 OK 20260628120000_add_object_size_and_stats.sql (44.94ms)9092026/09/23 13:33:50 INFO Received complete push request method=POST path=/api/pushes/1/complete9102026/09/23 13:33:50 OK 20260905000000_add_claims.sql (37.91ms)911--- PASS: TestPush_CompleteCommitsEveryRoot (2.07s)912=== CONT TestCompleteMultipartUnregistered9132026/09/23 13:33:50 OK 20260920000000_drop_claims.sql (17.72ms)9142026/09/23 13:33:50 OK 20260923120000_add_pushes.sql (2.09ms)9152026/09/23 13:33:50 goose: successfully migrated database to version: 202609231200009162026/09/23 13:33:50 OK 1_commit_pending_closure.sql (1.55ms)9172026/09/23 13:33:50 OK 2_object_stats_trigger.sql (314.67µs)9182026/09/23 13:33:50 OK 3_commit_push.sql (330.79µs)9192026/09/23 13:33:50 goose: up to current file version: 39202026-09-23 13:33:50.880 UTC [66251] ERROR: relation "goose_db_version" does not exist at character 369212026-09-23 13:33:50.880 UTC [66251] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9222026/09/23 13:33:50 INFO Received push request method=POST path=/api/pushes9232026/09/23 13:33:50 INFO Received complete push request method=POST path=/api/pushes/1/complete9242026/09/23 13:33:50 INFO Received push request method=POST path=/api/pushes9252026/09/23 13:33:50 OK 20241026095416_initial_model.sql (78.68ms)9262026/09/23 13:33:51 OK 20251210153512_drop_unused_gin_index.sql (7.42ms)9272026/09/23 13:33:51 OK 20251218171726_add_pins.sql (15.91ms)9282026/09/23 13:33:51 INFO Received complete push request method=POST path=/api/pushes/2/complete9292026-09-23 13:33:51.030 UTC [66252] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo9302026-09-23 13:33:51.030 UTC [66252] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE9312026-09-23 13:33:51.030 UTC [66252] STATEMENT: -- name: CommitPush :exec932 SELECT commit_push($1::bigint)933 934--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (2.26s)935=== CONT TestService_verifyS3Integrity9362026/09/23 13:33:51 OK 20260628120000_add_object_size_and_stats.sql (25.68ms)9372026/09/23 13:33:51 OK 20260905000000_add_claims.sql (29.08ms)9382026/09/23 13:33:51 OK 20260920000000_drop_claims.sql (25.31ms)9392026/09/23 13:33:51 OK 20260923120000_add_pushes.sql (9.62ms)9402026/09/23 13:33:51 goose: successfully migrated database to version: 202609231200009412026/09/23 13:33:51 OK 1_commit_pending_closure.sql (3.38ms)9422026/09/23 13:33:51 OK 2_object_stats_trigger.sql (716.58µs)9432026/09/23 13:33:51 OK 3_commit_push.sql (434.13µs)9442026/09/23 13:33:51 goose: up to current file version: 3945--- PASS: TestReadRedirectNar (1.94s)946=== CONT TestReadProxyNarStreaming947--- PASS: TestReadProxyDisabled (1.78s)948=== CONT TestService_createPendingClosureHandler9492026-09-23 13:33:51.378 UTC [66259] ERROR: relation "goose_db_version" does not exist at character 369502026-09-23 13:33:51.378 UTC [66259] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9512026/09/23 13:33:51 OK 20241026095416_initial_model.sql (93.02ms)9522026/09/23 13:33:51 OK 20251210153512_drop_unused_gin_index.sql (9.52ms)953--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.83s)954=== CONT TestService_cleanupPendingClosuresHandler9552026/09/23 13:33:51 OK 20251218171726_add_pins.sql (28.19ms)9562026/09/23 13:33:51 OK 20260628120000_add_object_size_and_stats.sql (24.73ms)9572026-09-23 13:33:51.580 UTC [66262] ERROR: relation "goose_db_version" does not exist at character 369582026-09-23 13:33:51.580 UTC [66262] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9592026/09/23 13:33:51 OK 20260905000000_add_claims.sql (47.45ms)9602026/09/23 13:33:51 OK 20260920000000_drop_claims.sql (8.69ms)9612026/09/23 13:33:51 OK 20260923120000_add_pushes.sql (5.38ms)9622026/09/23 13:33:51 goose: successfully migrated database to version: 202609231200009632026/09/23 13:33:51 OK 1_commit_pending_closure.sql (2.98ms)9642026/09/23 13:33:51 OK 2_object_stats_trigger.sql (578.5µs)9652026/09/23 13:33:51 OK 3_commit_push.sql (421.92µs)9662026/09/23 13:33:51 goose: up to current file version: 39672026/09/23 13:33:51 OK 20241026095416_initial_model.sql (116.14ms)9682026/09/23 13:33:51 OK 20251210153512_drop_unused_gin_index.sql (8.85ms)969--- PASS: TestReadProxyConditionalGet (1.82s)970=== CONT TestReadProxyNarinfoAlreadyDecompressed9712026/09/23 13:33:51 OK 20251218171726_add_pins.sql (27.28ms)9722026-09-23 13:33:51.785 UTC [66263] ERROR: relation "goose_db_version" does not exist at character 369732026-09-23 13:33:51.785 UTC [66263] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9742026/09/23 13:33:51 OK 20260628120000_add_object_size_and_stats.sql (35.79ms)9752026/09/23 13:33:51 OK 20260905000000_add_claims.sql (53.15ms)9762026/09/23 13:33:51 OK 20260920000000_drop_claims.sql (11.53ms)9772026-09-23 13:33:51.881 UTC [66266] ERROR: relation "goose_db_version" does not exist at character 369782026-09-23 13:33:51.881 UTC [66266] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9792026/09/23 13:33:51 OK 20260923120000_add_pushes.sql (8.62ms)9802026/09/23 13:33:51 goose: successfully migrated database to version: 202609231200009812026/09/23 13:33:51 OK 1_commit_pending_closure.sql (2.95ms)9822026/09/23 13:33:51 OK 2_object_stats_trigger.sql (537µs)9832026/09/23 13:33:51 OK 3_commit_push.sql (394.29µs)9842026/09/23 13:33:51 goose: up to current file version: 39852026/09/23 13:33:51 OK 20241026095416_initial_model.sql (98.96ms)9862026/09/23 13:33:51 OK 20251210153512_drop_unused_gin_index.sql (8.04ms)9872026/09/23 13:33:51 OK 20251218171726_add_pins.sql (18.2ms)988--- PASS: TestReadProxyHead (1.85s)989=== CONT TestUploadHandlersRejectOversizedBody9902026/09/23 13:33:52 OK 20260628120000_add_object_size_and_stats.sql (46.46ms)991=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure992=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure993=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart994=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart995=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts996=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts997=== CONT TestReadProxyNarinfo9982026/09/23 13:33:52 OK 20241026095416_initial_model.sql (131.13ms)9992026/09/23 13:33:52 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)10002026/09/23 13:33:52 OK 20260905000000_add_claims.sql (38.59ms)10012026/09/23 13:33:52 OK 20251218171726_add_pins.sql (14.24ms)10022026/09/23 13:33:52 OK 20260920000000_drop_claims.sql (15.19ms)10032026/09/23 13:33:52 OK 20260628120000_add_object_size_and_stats.sql (17.84ms)10042026/09/23 13:33:52 OK 20260923120000_add_pushes.sql (11.49ms)10052026/09/23 13:33:52 goose: successfully migrated database to version: 2026092312000010062026/09/23 13:33:52 OK 1_commit_pending_closure.sql (2.77ms)10072026/09/23 13:33:52 OK 2_object_stats_trigger.sql (327µs)10082026/09/23 13:33:52 OK 3_commit_push.sql (247.29µs)10092026/09/23 13:33:52 goose: up to current file version: 310102026/09/23 13:33:52 OK 20260905000000_add_claims.sql (18.61ms)10112026-09-23 13:33:52.112 UTC [66269] ERROR: relation "goose_db_version" does not exist at character 3610122026-09-23 13:33:52.112 UTC [66269] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10132026/09/23 13:33:52 OK 20260920000000_drop_claims.sql (14.39ms)10142026/09/23 13:33:52 OK 20260923120000_add_pushes.sql (6.35ms)10152026/09/23 13:33:52 goose: successfully migrated database to version: 2026092312000010162026/09/23 13:33:52 OK 1_commit_pending_closure.sql (2.1ms)10172026/09/23 13:33:52 OK 2_object_stats_trigger.sql (338.96µs)10182026/09/23 13:33:52 OK 3_commit_push.sql (347.38µs)10192026/09/23 13:33:52 goose: up to current file version: 31020--- PASS: TestReadProxyInvalidPath (1.87s)1021=== CONT TestUploadHandlersRejectInvalidKeys1022=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1023=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1024=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1025=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1026=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1027=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1028=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1029=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1030=== CONT TestIsValidCachePath1031=== RUN TestIsValidCachePath/narinfo1032=== PAUSE TestIsValidCachePath/narinfo1033=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1034=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1035=== RUN TestIsValidCachePath/nar_zst1036=== PAUSE TestIsValidCachePath/nar_zst1037=== RUN TestIsValidCachePath/nar_xz1038=== PAUSE TestIsValidCachePath/nar_xz1039=== RUN TestIsValidCachePath/nar_bz21040=== PAUSE TestIsValidCachePath/nar_bz21041=== RUN TestIsValidCachePath/nar_uncompressed1042=== PAUSE TestIsValidCachePath/nar_uncompressed1043=== RUN TestIsValidCachePath/ls1044=== PAUSE TestIsValidCachePath/ls1045=== RUN TestIsValidCachePath/log1046=== PAUSE TestIsValidCachePath/log1047=== RUN TestIsValidCachePath/realisation1048=== PAUSE TestIsValidCachePath/realisation1049=== RUN TestIsValidCachePath/nix-cache-info1050=== PAUSE TestIsValidCachePath/nix-cache-info1051=== RUN TestIsValidCachePath/index.html1052=== PAUSE TestIsValidCachePath/index.html1053=== RUN TestIsValidCachePath/traversal_parent1054=== PAUSE TestIsValidCachePath/traversal_parent1055=== RUN TestIsValidCachePath/traversal_in_middle1056=== PAUSE TestIsValidCachePath/traversal_in_middle1057=== RUN TestIsValidCachePath/invalid_char_e1058=== PAUSE TestIsValidCachePath/invalid_char_e1059=== RUN TestIsValidCachePath/invalid_char_u1060=== PAUSE TestIsValidCachePath/invalid_char_u1061=== RUN TestIsValidCachePath/random_path1062=== PAUSE TestIsValidCachePath/random_path1063=== RUN TestIsValidCachePath/empty1064=== PAUSE TestIsValidCachePath/empty1065=== RUN TestIsValidCachePath/leading_slash1066=== PAUSE TestIsValidCachePath/leading_slash1067=== RUN TestIsValidCachePath/wrong_extension1068=== PAUSE TestIsValidCachePath/wrong_extension1069=== RUN TestIsValidCachePath/short_hash1070=== PAUSE TestIsValidCachePath/short_hash1071=== CONT TestGCTaskStore_ConflictDifferentParams1072--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1073=== CONT TestGCTaskStore_GetEmpty1074--- PASS: TestGCTaskStore_GetEmpty (0.00s)1075=== CONT TestGCTaskStore_DeduplicateSameParams1076--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1077=== CONT TestProxyHeadersOnlyTrustedOnSocket10782026/09/23 13:33:52 OK 20241026095416_initial_model.sql (111.99ms)10792026/09/23 13:33:52 OK 20251210153512_drop_unused_gin_index.sql (7.48ms)10802026-09-23 13:33:52.270 UTC [66272] ERROR: relation "goose_db_version" does not exist at character 3610812026-09-23 13:33:52.270 UTC [66272] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10822026/09/23 13:33:52 OK 20251218171726_add_pins.sql (10.67ms)10832026/09/23 13:33:52 OK 20260628120000_add_object_size_and_stats.sql (15.15ms)10842026-09-23 13:33:52.302 UTC [66273] ERROR: relation "goose_db_version" does not exist at character 3610852026-09-23 13:33:52.302 UTC [66273] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10862026/09/23 13:33:52 OK 20260905000000_add_claims.sql (18.67ms)10872026/09/23 13:33:52 OK 20260920000000_drop_claims.sql (26.08ms)10882026/09/23 13:33:52 OK 20260923120000_add_pushes.sql (10.99ms)10892026/09/23 13:33:52 goose: successfully migrated database to version: 2026092312000010902026/09/23 13:33:52 OK 1_commit_pending_closure.sql (2.94ms)10912026/09/23 13:33:52 OK 2_object_stats_trigger.sql (604.38µs)10922026/09/23 13:33:52 OK 3_commit_push.sql (461.21µs)10932026/09/23 13:33:52 goose: up to current file version: 310942026/09/23 13:33:52 INFO Received uploads request method=POST path=/api/pending_closures10952026/09/23 13:33:52 OK 20241026095416_initial_model.sql (85.96ms)10962026/09/23 13:33:52 OK 20251210153512_drop_unused_gin_index.sql (10.66ms)10972026/09/23 13:33:52 OK 20251218171726_add_pins.sql (26.64ms)10982026/09/23 13:33:52 OK 20241026095416_initial_model.sql (100.88ms)1099--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.90s)1100=== CONT TestGCTaskStore_StartNew1101--- PASS: TestGCTaskStore_StartNew (0.00s)1102=== CONT TestParseSingleRange1103=== RUN TestParseSingleRange/none1104=== PAUSE TestParseSingleRange/none1105=== RUN TestParseSingleRange/unknown_unit1106=== PAUSE TestParseSingleRange/unknown_unit1107=== RUN TestParseSingleRange/multi-range_ignored1108=== PAUSE TestParseSingleRange/multi-range_ignored1109=== RUN TestParseSingleRange/malformed_no_dash1110=== PAUSE TestParseSingleRange/malformed_no_dash1111=== RUN TestParseSingleRange/malformed_both_empty1112=== PAUSE TestParseSingleRange/malformed_both_empty1113=== RUN TestParseSingleRange/malformed_end_before_start1114=== PAUSE TestParseSingleRange/malformed_end_before_start1115=== RUN TestParseSingleRange/closed1116=== PAUSE TestParseSingleRange/closed1117=== RUN TestParseSingleRange/open-ended1118=== PAUSE TestParseSingleRange/open-ended1119=== RUN TestParseSingleRange/end_clamped_to_size1120=== PAUSE TestParseSingleRange/end_clamped_to_size1121=== RUN TestParseSingleRange/suffix1122=== PAUSE TestParseSingleRange/suffix1123=== RUN TestParseSingleRange/suffix_exceeds_size1124=== PAUSE TestParseSingleRange/suffix_exceeds_size1125=== RUN TestParseSingleRange/single_byte1126=== PAUSE TestParseSingleRange/single_byte1127=== RUN TestParseSingleRange/start_past_EOF1128=== PAUSE TestParseSingleRange/start_past_EOF1129=== RUN TestParseSingleRange/start_far_past_EOF1130=== PAUSE TestParseSingleRange/start_far_past_EOF1131=== CONT TestGCMetrics11322026/09/23 13:33:52 OK 20251210153512_drop_unused_gin_index.sql (9.43ms)11332026/09/23 13:33:52 OK 20260628120000_add_object_size_and_stats.sql (26.54ms)11342026-09-23 13:33:52.455 UTC [66274] ERROR: relation "goose_db_version" does not exist at character 3611352026-09-23 13:33:52.455 UTC [66274] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11362026/09/23 13:33:52 OK 20251218171726_add_pins.sql (9.56ms)11372026/09/23 13:33:52 OK 20260905000000_add_claims.sql (18.68ms)11382026/09/23 13:33:52 OK 20260628120000_add_object_size_and_stats.sql (18.24ms)11392026/09/23 13:33:52 OK 20260920000000_drop_claims.sql (13.52ms)11402026/09/23 13:33:52 OK 20260923120000_add_pushes.sql (21.36ms)11412026/09/23 13:33:52 goose: successfully migrated database to version: 2026092312000011422026/09/23 13:33:52 OK 20260905000000_add_claims.sql (27.73ms)11432026/09/23 13:33:52 OK 1_commit_pending_closure.sql (1.99ms)11442026/09/23 13:33:52 OK 2_object_stats_trigger.sql (496µs)11452026/09/23 13:33:52 OK 3_commit_push.sql (551.71µs)11462026/09/23 13:33:52 goose: up to current file version: 311472026/09/23 13:33:52 OK 20260920000000_drop_claims.sql (16.74ms)11482026/09/23 13:33:52 OK 20260923120000_add_pushes.sql (20.85ms)11492026/09/23 13:33:52 goose: successfully migrated database to version: 2026092312000011502026/09/23 13:33:52 OK 1_commit_pending_closure.sql (2.67ms)11512026/09/23 13:33:52 OK 2_object_stats_trigger.sql (559.25µs)11522026/09/23 13:33:52 OK 3_commit_push.sql (414.33µs)11532026/09/23 13:33:52 goose: up to current file version: 311542026/09/23 13:33:52 OK 20241026095416_initial_model.sql (99.13ms)1155--- PASS: TestReadProxy404 (1.86s)1156=== CONT TestCreatePin_ReservedPins11572026/09/23 13:33:52 OK 20251210153512_drop_unused_gin_index.sql (15.45ms)11582026/09/23 13:33:52 OK 20251218171726_add_pins.sql (20.21ms)11592026/09/23 13:33:52 OK 20260628120000_add_object_size_and_stats.sql (13.17ms)11602026/09/23 13:33:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59543/oidc11612026/09/23 13:33:52 OK 20260905000000_add_claims.sql (13.13ms)11622026-09-23 13:33:52.650 UTC [66277] ERROR: relation "goose_db_version" does not exist at character 3611632026-09-23 13:33:52.650 UTC [66277] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11642026/09/23 13:33:52 OK 20260920000000_drop_claims.sql (8.69ms)11652026/09/23 13:33:52 OK 20260923120000_add_pushes.sql (6.96ms)11662026/09/23 13:33:52 goose: successfully migrated database to version: 2026092312000011672026/09/23 13:33:52 OK 1_commit_pending_closure.sql (982.21µs)11682026/09/23 13:33:52 OK 2_object_stats_trigger.sql (242µs)11692026/09/23 13:33:52 OK 3_commit_push.sql (208.67µs)11702026/09/23 13:33:52 goose: up to current file version: 311712026/09/23 13:33:52 OK 20241026095416_initial_model.sql (78.59ms)11722026/09/23 13:33:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11732026/09/23 13:33:52 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)11742026/09/23 13:33:52 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1175--- PASS: TestCompleteMultipartUnregistered (1.92s)1176=== CONT TestGCBugBareHashReferences11772026/09/23 13:33:52 OK 20251218171726_add_pins.sql (18.46ms)11782026-09-23 13:33:52.796 UTC [66280] ERROR: relation "goose_db_version" does not exist at character 3611792026-09-23 13:33:52.796 UTC [66280] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11802026/09/23 13:33:52 OK 20260628120000_add_object_size_and_stats.sql (27.57ms)11812026/09/23 13:33:52 OK 20260905000000_add_claims.sql (8.66ms)11822026/09/23 13:33:52 OK 20260920000000_drop_claims.sql (19.73ms)11832026/09/23 13:33:52 OK 20260923120000_add_pushes.sql (1.82ms)11842026/09/23 13:33:52 goose: successfully migrated database to version: 2026092312000011852026/09/23 13:33:52 OK 1_commit_pending_closure.sql (1.53ms)11862026/09/23 13:33:52 OK 2_object_stats_trigger.sql (298.67µs)11872026/09/23 13:33:52 OK 3_commit_push.sql (270.63µs)11882026/09/23 13:33:52 goose: up to current file version: 311892026/09/23 13:33:52 OK 20241026095416_initial_model.sql (67.4ms)11902026/09/23 13:33:52 OK 20251210153512_drop_unused_gin_index.sql (5.58ms)11912026/09/23 13:33:52 INFO Received uploads request method=POST path=/api/pending_closures11922026/09/23 13:33:52 OK 20251218171726_add_pins.sql (18.43ms)11932026/09/23 13:33:52 OK 20260628120000_add_object_size_and_stats.sql (42.91ms)11942026/09/23 13:33:52 OK 20260905000000_add_claims.sql (33.55ms)11952026/09/23 13:33:53 OK 20260920000000_drop_claims.sql (14.93ms)11962026/09/23 13:33:53 OK 20260923120000_add_pushes.sql (2.43ms)11972026/09/23 13:33:53 goose: successfully migrated database to version: 2026092312000011982026/09/23 13:33:53 OK 1_commit_pending_closure.sql (1.7ms)11992026/09/23 13:33:53 OK 2_object_stats_trigger.sql (349.38µs)12002026/09/23 13:33:53 OK 3_commit_push.sql (329.38µs)12012026/09/23 13:33:53 goose: up to current file version: 312022026-09-23 13:33:53.098 UTC [66284] ERROR: relation "goose_db_version" does not exist at character 3612032026-09-23 13:33:53.098 UTC [66284] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1204--- PASS: TestReadProxyNarStreaming (2.03s)1205=== CONT TestResurrectedObjectNotDeleted12062026-09-23 13:33:53.338 UTC [66287] ERROR: relation "goose_db_version" does not exist at character 3612072026-09-23 13:33:53.338 UTC [66287] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12082026/09/23 13:33:53 OK 20241026095416_initial_model.sql (186.37ms)12092026/09/23 13:33:53 OK 20251210153512_drop_unused_gin_index.sql (12.66ms)12102026/09/23 13:33:53 INFO Received uploads request method=POST path=/api/pending_closures12112026/09/23 13:33:53 INFO Received uploads request method=POST path=/api/pending_closures12122026/09/23 13:33:53 INFO Received uploads request method=POST path=/api/pending_closures12132026/09/23 13:33:53 OK 20251218171726_add_pins.sql (16.37ms)12142026/09/23 13:33:53 OK 20260628120000_add_object_size_and_stats.sql (45.22ms)12152026/09/23 13:33:53 OK 20260905000000_add_claims.sql (35.09ms)12162026/09/23 13:33:53 OK 20260920000000_drop_claims.sql (12.8ms)12172026/09/23 13:33:53 OK 20260923120000_add_pushes.sql (9.84ms)12182026/09/23 13:33:53 goose: successfully migrated database to version: 2026092312000012192026/09/23 13:33:53 OK 1_commit_pending_closure.sql (1.96ms)12202026/09/23 13:33:53 OK 2_object_stats_trigger.sql (390.58µs)12212026/09/23 13:33:53 OK 3_commit_push.sql (313.54µs)12222026/09/23 13:33:53 goose: up to current file version: 312232026/09/23 13:33:53 OK 20241026095416_initial_model.sql (144.64ms)12242026/09/23 13:33:53 OK 20251210153512_drop_unused_gin_index.sql (11.19ms)12252026/09/23 13:33:53 OK 20251218171726_add_pins.sql (27.4ms)12262026/09/23 13:33:53 OK 20260628120000_add_object_size_and_stats.sql (34.01ms)12272026/09/23 13:33:53 OK 20260905000000_add_claims.sql (21.38ms)12282026/09/23 13:33:53 INFO Received cleanup request method=DELETE path=/api/pending_closures12292026/09/23 13:33:53 INFO Aborted multipart uploads count=012302026/09/23 13:33:53 INFO Received uploads request method=POST path=/api/pending_closures12312026/09/23 13:33:53 OK 20260920000000_drop_claims.sql (72.48ms)12322026/09/23 13:33:53 INFO Received cleanup request method=DELETE path=/api/pending_closures12332026/09/23 13:33:53 OK 20260923120000_add_pushes.sql (24.18ms)12342026/09/23 13:33:53 goose: successfully migrated database to version: 2026092312000012352026/09/23 13:33:53 OK 1_commit_pending_closure.sql (5.45ms)12362026/09/23 13:33:53 OK 2_object_stats_trigger.sql (901.13µs)12372026/09/23 13:33:53 OK 3_commit_push.sql (650.67µs)12382026/09/23 13:33:53 goose: up to current file version: 312392026/09/23 13:33:53 INFO Aborted multipart uploads count=112402026/09/23 13:33:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12412026-09-23 13:33:53.769 UTC [66277] ERROR: Closure does not exist: id=112422026-09-23 13:33:53.769 UTC [66277] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12432026-09-23 13:33:53.769 UTC [66277] STATEMENT: -- name: CommitPendingClosure :exec1244 SELECT commit_pending_closure($1::bigint)1245 1246--- PASS: TestService_cleanupPendingClosuresHandler (2.25s)1247=== CONT TestOrphanedObjectsGCStressTest12482026-09-23 13:33:53.861 UTC [66289] ERROR: relation "goose_db_version" does not exist at character 3612492026-09-23 13:33:53.861 UTC [66289] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1250--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.21s)1251=== CONT TestOrphanedObjectsGC12522026-09-23 13:33:54.114 UTC [66293] ERROR: relation "goose_db_version" does not exist at character 3612532026-09-23 13:33:54.114 UTC [66293] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12542026/09/23 13:33:54 OK 20241026095416_initial_model.sql (217.15ms)12552026/09/23 13:33:54 OK 20251210153512_drop_unused_gin_index.sql (11.7ms)12562026/09/23 13:33:54 OK 20251218171726_add_pins.sql (28.4ms)12572026/09/23 13:33:54 OK 20260628120000_add_object_size_and_stats.sql (37.73ms)12582026/09/23 13:33:54 OK 20260905000000_add_claims.sql (42.49ms)12592026/09/23 13:33:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1260--- PASS: TestReadProxyNarinfo (2.25s)1261=== CONT TestObjectStatsTrigger12622026/09/23 13:33:54 OK 20260920000000_drop_claims.sql (76.03ms)12632026/09/23 13:33:54 OK 20260923120000_add_pushes.sql (17.68ms)12642026/09/23 13:33:54 goose: successfully migrated database to version: 2026092312000012652026/09/23 13:33:54 OK 20241026095416_initial_model.sql (175.21ms)12662026/09/23 13:33:54 OK 1_commit_pending_closure.sql (3.64ms)12672026/09/23 13:33:54 OK 2_object_stats_trigger.sql (564.67µs)12682026/09/23 13:33:54 OK 3_commit_push.sql (433.42µs)12692026/09/23 13:33:54 goose: up to current file version: 312702026/09/23 13:33:54 OK 20251210153512_drop_unused_gin_index.sql (19.2ms)12712026/09/23 13:33:54 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NmI2Y2EyYjUtNjhkMC00ZGZjLWI3YmItODU5Y2FmODUzNThmLjQxMDg0MzlhLWNjZTktNDUxZi1iZWMyLWNlMDMyNWEwNmFiN3gxNzkwMTcwNDMyOTQzMTY4MDAw parts=1012722026/09/23 13:33:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12732026/09/23 13:33:54 INFO Completed upload id=112742026/09/23 13:33:54 INFO Received uploads request method=POST path=/api/pending_closures12752026/09/23 13:33:54 INFO Received uploads request method=POST path=/api/pending_closures12762026/09/23 13:33:54 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12772026/09/23 13:33:54 WARN Found objects in DB but missing from S3, will re-upload count=11278--- PASS: TestService_verifyS3Integrity (3.37s)1279=== CONT TestMultipartCleanup12802026/09/23 13:33:54 OK 20251218171726_add_pins.sql (44.21ms)12812026/09/23 13:33:54 OK 20260628120000_add_object_size_and_stats.sql (45.02ms)12822026/09/23 13:33:54 OK 20260905000000_add_claims.sql (48.78ms)12832026/09/23 13:33:54 OK 20260920000000_drop_claims.sql (15.62ms)12842026/09/23 13:33:54 OK 20260923120000_add_pushes.sql (14.5ms)12852026/09/23 13:33:54 goose: successfully migrated database to version: 2026092312000012862026/09/23 13:33:54 OK 1_commit_pending_closure.sql (1.64ms)12872026/09/23 13:33:54 OK 2_object_stats_trigger.sql (397.75µs)12882026/09/23 13:33:54 OK 3_commit_push.sql (331.54µs)12892026/09/23 13:33:54 goose: up to current file version: 312902026/09/23 13:33:54 INFO Starting HTTP server address=127.0.0.1:5956412912026/09/23 13:33:54 INFO Starting HTTP server address=/nix/var/nix/builds/nix-66117-1423409739/TestProxyHeadersOnlyTrustedOnSocket1879760919/001/proxy.sock12922026/09/23 13:33:54 WARN mTLS auth: subject not in bound subjects subject="CN=someone"12932026/09/23 13:33:54 INFO Shutdown signal received, draining in-flight requests timeout=10s1294--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.38s)1295=== CONT TestServerTLSConfig1296=== RUN TestServerTLSConfig/no_client_CA1297=== PAUSE TestServerTLSConfig/no_client_CA1298=== RUN TestServerTLSConfig/missing_CA_file1299=== PAUSE TestServerTLSConfig/missing_CA_file1300=== RUN TestServerTLSConfig/not_a_PEM_file1301=== PAUSE TestServerTLSConfig/not_a_PEM_file1302=== CONT TestService_NativeMTLS13032026-09-23 13:33:54.578 UTC [66298] ERROR: relation "goose_db_version" does not exist at character 3613042026-09-23 13:33:54.578 UTC [66298] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13052026/09/23 13:33:54 INFO Aborted multipart uploads count=013062026/09/23 13:33:54 OK 20241026095416_initial_model.sql (149.49ms)13072026/09/23 13:33:54 WARN Force mode enabled - objects will be deleted immediately without grace period13082026/09/23 13:33:54 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=013092026/09/23 13:33:54 INFO Vacuumed table table=pending_closures13102026/09/23 13:33:54 INFO Vacuumed table table=pending_objects13112026/09/23 13:33:54 INFO Vacuumed table table=multipart_uploads13122026/09/23 13:33:54 INFO Vacuumed table table=closures13132026/09/23 13:33:54 INFO Vacuumed table table=objects1314--- PASS: TestGCMetrics (2.33s)1315=== CONT TestMetricsInventory13162026/09/23 13:33:54 OK 20251210153512_drop_unused_gin_index.sql (11.23ms)13172026/09/23 13:33:54 OK 20251218171726_add_pins.sql (42.81ms)13182026/09/23 13:33:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13192026/09/23 13:33:54 OK 20260628120000_add_object_size_and_stats.sql (38.75ms)13202026/09/23 13:33:54 OK 20260905000000_add_claims.sql (55.28ms)13212026/09/23 13:33:54 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NmI2Y2EyYjUtNjhkMC00ZGZjLWI3YmItODU5Y2FmODUzNThmLjU1NTkzZTlhLTBiNmQtNGNhNC04MTRmLTRkNTIwMjU4OTg0ZngxNzkwMTcwNDMzNDIxNTYwMDAw parts=1013222026/09/23 13:33:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13232026/09/23 13:33:54 INFO Completed upload id=113242026/09/23 13:33:54 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013252026/09/23 13:33:54 INFO Received uploads request method=POST path=/api/pending_closures13262026/09/23 13:33:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures13272026/09/23 13:33:54 INFO Aborted multipart uploads count=013282026/09/23 13:33:54 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=013292026/09/23 13:33:54 OK 20260920000000_drop_claims.sql (65.54ms)13302026/09/23 13:33:55 OK 20260923120000_add_pushes.sql (18.12ms)13312026/09/23 13:33:55 goose: successfully migrated database to version: 2026092312000013322026/09/23 13:33:55 INFO Vacuumed table table=pending_closures13332026/09/23 13:33:55 OK 1_commit_pending_closure.sql (3.02ms)13342026/09/23 13:33:55 OK 2_object_stats_trigger.sql (706.79µs)13352026/09/23 13:33:55 OK 3_commit_push.sql (459.92µs)13362026/09/23 13:33:55 goose: up to current file version: 313372026/09/23 13:33:55 INFO Vacuumed table table=pending_objects13382026/09/23 13:33:55 INFO Vacuumed table table=multipart_uploads13392026/09/23 13:33:55 INFO Vacuumed table table=closures13402026/09/23 13:33:55 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13412026/09/23 13:33:55 WARN Refused reserved pin name=worker-x86_64-linux13422026/09/23 13:33:55 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13432026/09/23 13:33:55 INFO Received create pin request method=POST path=/api/pins/my-app13442026/09/23 13:33:55 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1345--- PASS: TestCreatePin_ReservedPins (2.50s)1346=== CONT TestNARDeduplicationMetadataUploadBug13472026/09/23 13:33:55 INFO Vacuumed table table=objects13482026/09/23 13:33:55 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013492026-09-23 13:33:55.148 UTC [66307] ERROR: relation "goose_db_version" does not exist at character 3613502026-09-23 13:33:55.148 UTC [66307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1351--- PASS: TestService_createPendingClosureHandler (3.85s)1352=== CONT TestCreatePendingClosureRejectsOversizedNAR13532026/09/23 13:33:55 INFO Received uploads request method=POST path=/api/pending_closures1354--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1355=== CONT TestCacheConfigHandlerMaxNarSize1356--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1357=== CONT TestGenerateLandingPage1358--- PASS: TestGenerateLandingPage (0.00s)1359=== CONT TestService_readinessHandler13602026/09/23 13:33:55 OK 20241026095416_initial_model.sql (167.55ms)13612026/09/23 13:33:55 OK 20251210153512_drop_unused_gin_index.sql (13.18ms)13622026/09/23 13:33:55 OK 20251218171726_add_pins.sql (38.05ms)13632026/09/23 13:33:55 OK 20260628120000_add_object_size_and_stats.sql (31.88ms)13642026/09/23 13:33:55 OK 20260905000000_add_claims.sql (23.92ms)13652026/09/23 13:33:55 OK 20260920000000_drop_claims.sql (3.93ms)13662026/09/23 13:33:55 OK 20260923120000_add_pushes.sql (7.01ms)13672026/09/23 13:33:55 goose: successfully migrated database to version: 2026092312000013682026-09-23 13:33:55.515 UTC [66310] ERROR: relation "goose_db_version" does not exist at character 3613692026-09-23 13:33:55.515 UTC [66310] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13702026/09/23 13:33:55 OK 1_commit_pending_closure.sql (29.8ms)13712026/09/23 13:33:55 OK 2_object_stats_trigger.sql (804.42µs)13722026/09/23 13:33:55 OK 3_commit_push.sql (445.58µs)13732026/09/23 13:33:55 goose: up to current file version: 31374--- PASS: TestGCBugBareHashReferences (2.87s)1375=== CONT TestService_healthCheckHandler13762026-09-23 13:33:55.678 UTC [66312] ERROR: relation "goose_db_version" does not exist at character 3613772026-09-23 13:33:55.678 UTC [66312] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13782026/09/23 13:33:55 OK 20241026095416_initial_model.sql (144.93ms)13792026/09/23 13:33:55 OK 20251210153512_drop_unused_gin_index.sql (12.59ms)13802026/09/23 13:33:55 OK 20251218171726_add_pins.sql (32.71ms)13812026/09/23 13:33:55 OK 20260628120000_add_object_size_and_stats.sql (31.85ms)13822026/09/23 13:33:55 OK 20260905000000_add_claims.sql (75.14ms)1383--- PASS: TestResurrectedObjectNotDeleted (2.78s)1384=== CONT TestGracefulShutdownDrainsInflight13852026/09/23 13:33:55 INFO Starting HTTP server address=127.0.0.1:5957113862026/09/23 13:33:55 INFO Shutdown signal received, draining in-flight requests timeout=10s13872026/09/23 13:33:55 OK 20241026095416_initial_model.sql (207.36ms)13882026/09/23 13:33:55 OK 20260920000000_drop_claims.sql (68.8ms)13892026/09/23 13:33:55 OK 20251210153512_drop_unused_gin_index.sql (9.4ms)13902026/09/23 13:33:55 OK 20260923120000_add_pushes.sql (13.95ms)13912026/09/23 13:33:55 goose: successfully migrated database to version: 2026092312000013922026/09/23 13:33:55 OK 1_commit_pending_closure.sql (3.6ms)13932026/09/23 13:33:55 OK 2_object_stats_trigger.sql (849.88µs)13942026/09/23 13:33:55 OK 3_commit_push.sql (643.38µs)13952026/09/23 13:33:55 goose: up to current file version: 313962026/09/23 13:33:55 OK 20251218171726_add_pins.sql (36.22ms)1397--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1398=== CONT TestGCTaskStore_Fail1399--- PASS: TestGCTaskStore_Fail (0.00s)1400=== CONT TestGCTaskStore_PhaseUpdates1401--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1402=== CONT TestLeadEndsOnShutdown14032026/09/23 13:33:56 OK 20260628120000_add_object_size_and_stats.sql (41.16ms)14042026/09/23 13:33:56 OK 20260905000000_add_claims.sql (6.1ms)14052026/09/23 13:33:56 OK 20260920000000_drop_claims.sql (23.42ms)14062026/09/23 13:33:56 OK 20260923120000_add_pushes.sql (27.38ms)14072026/09/23 13:33:56 goose: successfully migrated database to version: 2026092312000014082026/09/23 13:33:56 OK 1_commit_pending_closure.sql (3.25ms)14092026/09/23 13:33:56 OK 2_object_stats_trigger.sql (645.67µs)14102026/09/23 13:33:56 OK 3_commit_push.sql (378.46µs)14112026/09/23 13:33:56 goose: up to current file version: 314122026-09-23 13:33:56.462 UTC [66316] ERROR: relation "goose_db_version" does not exist at character 3614132026-09-23 13:33:56.462 UTC [66316] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14142026-09-23 13:33:56.531 UTC [66317] ERROR: relation "goose_db_version" does not exist at character 3614152026-09-23 13:33:56.531 UTC [66317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14162026/09/23 13:33:56 OK 20241026095416_initial_model.sql (241.09ms)14172026/09/23 13:33:56 OK 20251210153512_drop_unused_gin_index.sql (14.67ms)14182026/09/23 13:33:56 OK 20251218171726_add_pins.sql (98.8ms)14192026/09/23 13:33:56 OK 20241026095416_initial_model.sql (304.45ms)14202026/09/23 13:33:56 OK 20251210153512_drop_unused_gin_index.sql (16.25ms)14212026/09/23 13:33:56 OK 20260628120000_add_object_size_and_stats.sql (35.02ms)14222026/09/23 13:33:56 OK 20251218171726_add_pins.sql (18.96ms)14232026/09/23 13:33:56 OK 20260628120000_add_object_size_and_stats.sql (34.51ms)14242026/09/23 13:33:57 OK 20260905000000_add_claims.sql (67.01ms)14252026-09-23 13:33:57.014 UTC [66318] ERROR: relation "goose_db_version" does not exist at character 3614262026-09-23 13:33:57.014 UTC [66318] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14272026/09/23 13:33:57 OK 20260920000000_drop_claims.sql (27.34ms)14282026/09/23 13:33:57 OK 20260905000000_add_claims.sql (65.94ms)14292026/09/23 13:33:57 OK 20260923120000_add_pushes.sql (19.05ms)14302026/09/23 13:33:57 goose: successfully migrated database to version: 2026092312000014312026/09/23 13:33:57 OK 1_commit_pending_closure.sql (4.78ms)14322026/09/23 13:33:57 OK 2_object_stats_trigger.sql (809.25µs)14332026/09/23 13:33:57 OK 3_commit_push.sql (558.46µs)14342026/09/23 13:33:57 goose: up to current file version: 314352026-09-23 13:33:57.070 UTC [66319] ERROR: relation "goose_db_version" does not exist at character 3614362026-09-23 13:33:57.070 UTC [66319] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026/09/23 13:33:57 OK 20260920000000_drop_claims.sql (29.94ms)14382026/09/23 13:33:57 OK 20260923120000_add_pushes.sql (20.08ms)14392026/09/23 13:33:57 goose: successfully migrated database to version: 2026092312000014402026/09/23 13:33:57 OK 1_commit_pending_closure.sql (2.96ms)14412026/09/23 13:33:57 OK 2_object_stats_trigger.sql (699.71µs)14422026/09/23 13:33:57 OK 3_commit_push.sql (508.46µs)14432026/09/23 13:33:57 goose: up to current file version: 314442026/09/23 13:33:57 OK 20241026095416_initial_model.sql (265.38ms)14452026-09-23 13:33:57.338 UTC [66320] ERROR: relation "goose_db_version" does not exist at character 3614462026-09-23 13:33:57.338 UTC [66320] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14472026/09/23 13:33:57 OK 20251210153512_drop_unused_gin_index.sql (10.47ms)14482026/09/23 13:33:57 OK 20251218171726_add_pins.sql (57.22ms)14492026/09/23 13:33:57 OK 20260628120000_add_object_size_and_stats.sql (44.1ms)14502026/09/23 13:33:57 OK 20241026095416_initial_model.sql (312.19ms)14512026/09/23 13:33:57 INFO Received uploads request method=POST path=/api/pending_closures14522026/09/23 13:33:57 OK 20251210153512_drop_unused_gin_index.sql (9.87ms)14532026/09/23 13:33:57 OK 20251218171726_add_pins.sql (60ms)14542026/09/23 13:33:57 OK 20260905000000_add_claims.sql (99.07ms)14552026/09/23 13:33:57 OK 20260628120000_add_object_size_and_stats.sql (50.99ms)14562026/09/23 13:33:57 OK 20260920000000_drop_claims.sql (66.92ms)1457=== NAME TestOrphanedObjectsGC1458 orphaned_objects_gc_test.go:290: GC Test Summary:1459 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1460 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1461 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1462 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1463 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1464--- PASS: TestOrphanedObjectsGC (3.66s)1465=== CONT TestGCTaskStore_CompletedAllowsNewTask1466--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1467=== CONT TestLeadElectsOneAndHandsOver14682026/09/23 13:33:57 OK 20260923120000_add_pushes.sql (21.79ms)14692026/09/23 13:33:57 goose: successfully migrated database to version: 2026092312000014702026/09/23 13:33:57 OK 1_commit_pending_closure.sql (3.35ms)14712026/09/23 13:33:57 OK 2_object_stats_trigger.sql (1.7ms)14722026/09/23 13:33:57 OK 3_commit_push.sql (822.33µs)14732026/09/23 13:33:57 goose: up to current file version: 314742026/09/23 13:33:57 INFO Received cleanup request method=DELETE path=/api/pending_closures14752026/09/23 13:33:57 INFO Aborted multipart uploads count=114762026/09/23 13:33:57 OK 20260905000000_add_claims.sql (95.31ms)1477--- PASS: TestMultipartCleanup (3.30s)1478=== CONT TestGCTaskStore_GetReturnsLatest1479--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1480=== CONT TestProxyWriteTimeout1481=== RUN TestProxyWriteTimeout/narinfo1482=== PAUSE TestProxyWriteTimeout/narinfo1483=== RUN TestProxyWriteTimeout/1_GiB_nar1484=== PAUSE TestProxyWriteTimeout/1_GiB_nar1485=== RUN TestProxyWriteTimeout/10_GiB_nar1486=== PAUSE TestProxyWriteTimeout/10_GiB_nar1487=== RUN TestProxyWriteTimeout/unknown_size1488=== PAUSE TestProxyWriteTimeout/unknown_size1489=== CONT TestResolveDBConnectionString1490=== RUN TestResolveDBConnectionString/flag_wins1491=== PAUSE TestResolveDBConnectionString/flag_wins1492=== RUN TestResolveDBConnectionString/file_when_flag_empty1493=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1494=== RUN TestResolveDBConnectionString/missing_file_is_an_error1495=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1496=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1497=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1498=== RUN TestResolveDBConnectionString/nothing_configured1499=== PAUSE TestResolveDBConnectionString/nothing_configured1500=== CONT TestPresignedUploadRegisteredBeforeCommit15012026/09/23 13:33:57 OK 20260920000000_drop_claims.sql (42.02ms)15022026/09/23 13:33:57 OK 20241026095416_initial_model.sql (280.22ms)15032026-09-23 13:33:57.733 UTC [66323] ERROR: relation "goose_db_version" does not exist at character 3615042026-09-23 13:33:57.733 UTC [66323] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15052026/09/23 13:33:57 OK 20251210153512_drop_unused_gin_index.sql (15.81ms)15062026/09/23 13:33:57 OK 20260923120000_add_pushes.sql (25.59ms)15072026/09/23 13:33:57 goose: successfully migrated database to version: 2026092312000015082026/09/23 13:33:57 OK 1_commit_pending_closure.sql (1.77ms)15092026/09/23 13:33:57 OK 2_object_stats_trigger.sql (429.92µs)15102026/09/23 13:33:57 OK 3_commit_push.sql (389.79µs)15112026/09/23 13:33:57 goose: up to current file version: 315122026/09/23 13:33:57 OK 20251218171726_add_pins.sql (21.32ms)15132026/09/23 13:33:57 OK 20260628120000_add_object_size_and_stats.sql (45.72ms)1514--- PASS: TestObjectStatsTrigger (3.58s)1515=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle15162026/09/23 13:33:57 OK 20260905000000_add_claims.sql (89.13ms)15172026/09/23 13:33:57 OK 20260920000000_drop_claims.sql (23.57ms)15182026/09/23 13:33:57 OK 20260923120000_add_pushes.sql (28.42ms)15192026/09/23 13:33:57 goose: successfully migrated database to version: 2026092312000015202026/09/23 13:33:57 OK 1_commit_pending_closure.sql (2.67ms)15212026/09/23 13:33:57 OK 2_object_stats_trigger.sql (632.42µs)15222026/09/23 13:33:57 OK 3_commit_push.sql (424.79µs)15232026/09/23 13:33:57 goose: up to current file version: 315242026/09/23 13:33:57 OK 20241026095416_initial_model.sql (193.06ms)15252026/09/23 13:33:57 OK 20251210153512_drop_unused_gin_index.sql (13.9ms)15262026/09/23 13:33:58 OK 20251218171726_add_pins.sql (50.21ms)15272026/09/23 13:33:58 OK 20260628120000_add_object_size_and_stats.sql (41.06ms)15282026/09/23 13:33:58 OK 20260905000000_add_claims.sql (84.49ms)15292026/09/23 13:33:58 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15302026/09/23 13:33:58 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1531--- PASS: TestService_NativeMTLS (3.60s)1532=== CONT TestService_Rustfstest15332026/09/23 13:33:58 OK 20260920000000_drop_claims.sql (41.99ms)15342026/09/23 13:33:58 OK 20260923120000_add_pushes.sql (28.66ms)15352026/09/23 13:33:58 goose: successfully migrated database to version: 2026092312000015362026/09/23 13:33:58 OK 1_commit_pending_closure.sql (3.63ms)15372026/09/23 13:33:58 OK 2_object_stats_trigger.sql (661.88µs)15382026/09/23 13:33:58 OK 3_commit_push.sql (429.13µs)15392026/09/23 13:33:58 goose: up to current file version: 315402026-09-23 13:33:58.239 UTC [66329] ERROR: relation "goose_db_version" does not exist at character 3615412026-09-23 13:33:58.239 UTC [66329] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1542--- PASS: TestMetricsInventory (3.78s)1543=== CONT TestPinProtectsFromGC15442026/09/23 13:33:58 OK 20241026095416_initial_model.sql (211.76ms)15452026/09/23 13:33:58 OK 20251210153512_drop_unused_gin_index.sql (15.05ms)15462026/09/23 13:33:58 OK 20251218171726_add_pins.sql (27.15ms)15472026/09/23 13:33:58 OK 20260628120000_add_object_size_and_stats.sql (40.7ms)15482026/09/23 13:33:58 OK 20260905000000_add_claims.sql (45.1ms)15492026/09/23 13:33:58 OK 20260920000000_drop_claims.sql (34.96ms)15502026/09/23 13:33:58 OK 20260923120000_add_pushes.sql (16.15ms)15512026/09/23 13:33:58 goose: successfully migrated database to version: 2026092312000015522026/09/23 13:33:58 OK 1_commit_pending_closure.sql (2.51ms)15532026/09/23 13:33:58 OK 2_object_stats_trigger.sql (633µs)15542026/09/23 13:33:58 OK 3_commit_push.sql (519.88µs)15552026/09/23 13:33:58 goose: up to current file version: 315562026-09-23 13:33:58.779 UTC [66333] ERROR: relation "goose_db_version" does not exist at character 3615572026-09-23 13:33:58.779 UTC [66333] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15582026/09/23 13:33:58 OK 20241026095416_initial_model.sql (139.1ms)15592026/09/23 13:33:58 OK 20251210153512_drop_unused_gin_index.sql (14.68ms)15602026/09/23 13:33:59 OK 20251218171726_add_pins.sql (23.23ms)15612026/09/23 13:33:59 WARN readiness check failed error="closed pool"1562--- PASS: TestService_readinessHandler (3.88s)1563=== CONT TestSkippedUploadsHandler15642026/09/23 13:33:59 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001565=== NAME TestNARDeduplicationMetadataUploadBug1566 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-66117-1423409739/TestNARDeduplicationMetadataUploadBug1668648414/001/store/q0irgmcdkczs4ff1bgw6nj2dk4ckxk3r-file1.txt1567--- PASS: TestSkippedUploadsHandler (0.00s)1568=== CONT TestParseSize1569--- PASS: TestParseSize (0.00s)1570=== CONT TestCompletedNarNotReofferedAcrossClosures15712026/09/23 13:33:59 OK 20260628120000_add_object_size_and_stats.sql (33.72ms)15722026/09/23 13:33:59 OK 20260905000000_add_claims.sql (42.3ms)15732026/09/23 13:33:59 OK 20260920000000_drop_claims.sql (30.56ms)15742026/09/23 13:33:59 INFO Received uploads request method=POST path=/api/pending_closures15752026/09/23 13:33:59 OK 20260923120000_add_pushes.sql (14.49ms)15762026/09/23 13:33:59 goose: successfully migrated database to version: 2026092312000015772026/09/23 13:33:59 OK 1_commit_pending_closure.sql (833.17µs)15782026/09/23 13:33:59 OK 2_object_stats_trigger.sql (240.5µs)15792026/09/23 13:33:59 OK 3_commit_push.sql (196.79µs)15802026/09/23 13:33:59 goose: up to current file version: 315812026/09/23 13:33:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15822026/09/23 13:33:59 INFO Uploading q0irgmcdkczs4ff1bgw6nj2dk4ckxk3r-file1.txt (160B)15832026/09/23 13:33:59 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15842026/09/23 13:33:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15852026/09/23 13:33:59 WARN Failed to register uploaded object key=q0irgmcdkczs4ff1bgw6nj2dk4ckxk3r.ls error="server returned 404: 404 page not found\n"15862026/09/23 13:33:59 INFO Signed narinfos id=1 count=115872026/09/23 13:33:59 INFO Uploading 1 narinfos15882026/09/23 13:33:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15892026/09/23 13:33:59 WARN Failed to register uploaded object key=q0irgmcdkczs4ff1bgw6nj2dk4ckxk3r.narinfo error="server returned 404: 404 page not found\n"15902026/09/23 13:33:59 INFO Completed upload id=115912026/09/23 13:33:59 INFO Upload complete. (145ms)1592=== NAME TestNARDeduplicationMetadataUploadBug1593 metadata_upload_test.go:54: Retrieved narinfo from S3:1594 StorePath: /nix/var/nix/builds/nix-66117-1423409739/TestNARDeduplicationMetadataUploadBug1668648414/001/store/q0irgmcdkczs4ff1bgw6nj2dk4ckxk3r-file1.txt1595 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1596 Compression: zstd1597 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1598 NarSize: 1601599 References: 1600 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1601 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1602 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1603 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1604--- PASS: TestService_healthCheckHandler (3.63s)1605=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1606=== NAME TestNARDeduplicationMetadataUploadBug1607 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-66117-1423409739/TestNARDeduplicationMetadataUploadBug1668648414/001/store/9107zjfb765p4avl3sn5cxwz3xk4wn3v-file2.txt16082026/09/23 13:33:59 INFO Received uploads request method=POST path=/api/pending_closures16092026/09/23 13:33:59 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16102026/09/23 13:33:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16112026/09/23 13:33:59 INFO Signed narinfos id=2 count=116122026/09/23 13:33:59 INFO Uploading 1 narinfos16132026/09/23 13:33:59 WARN Failed to register uploaded object key=9107zjfb765p4avl3sn5cxwz3xk4wn3v.ls error="server returned 404: 404 page not found\n"16142026/09/23 13:33:59 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16152026/09/23 13:33:59 WARN Failed to register uploaded object key=9107zjfb765p4avl3sn5cxwz3xk4wn3v.narinfo error="server returned 404: 404 page not found\n"16162026/09/23 13:33:59 INFO Completed upload id=216172026/09/23 13:33:59 INFO Upload complete. (90ms)1618 metadata_upload_test.go:76: Retrieved narinfo from S3:1619 StorePath: /nix/var/nix/builds/nix-66117-1423409739/TestNARDeduplicationMetadataUploadBug1668648414/001/store/9107zjfb765p4avl3sn5cxwz3xk4wn3v-file2.txt1620 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1621 Compression: zstd1622 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1623 NarSize: 1601624 References: 1625 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1626 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1627 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1628 {"version":1,"root":{"type":"regular","size":44}}16292026/09/23 13:33:59 INFO lead: acquired remote=192.0.2.1:123416302026/09/23 13:33:59 INFO lead: released remote=192.0.2.1:12341631--- PASS: TestLeadEndsOnShutdown (3.52s)1632=== CONT TestClientSharedPathCommittedMidPush1633--- PASS: TestNARDeduplicationMetadataUploadBug (4.44s)1634=== CONT TestCacheConfigHandler1635=== RUN TestCacheConfigHandler/full_config,_no_issuer1636=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1637=== RUN TestCacheConfigHandler/no_cache_url_configured1638=== PAUSE TestCacheConfigHandler/no_cache_url_configured1639=== RUN TestCacheConfigHandler/no_signing_keys1640=== PAUSE TestCacheConfigHandler/no_signing_keys1641=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1642=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1643=== CONT TestClientWithDependencies16442026-09-23 13:33:59.532 UTC [66350] ERROR: relation "goose_db_version" does not exist at character 3616452026-09-23 13:33:59.532 UTC [66350] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16462026-09-23 13:33:59.572 UTC [66355] ERROR: relation "goose_db_version" does not exist at character 3616472026-09-23 13:33:59.572 UTC [66355] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16482026-09-23 13:33:59.649 UTC [66356] ERROR: relation "goose_db_version" does not exist at character 3616492026-09-23 13:33:59.649 UTC [66356] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16502026/09/23 13:33:59 OK 20241026095416_initial_model.sql (94.61ms)16512026/09/23 13:33:59 OK 20251210153512_drop_unused_gin_index.sql (1.61ms)16522026/09/23 13:33:59 OK 20251218171726_add_pins.sql (14.06ms)16532026/09/23 13:33:59 OK 20241026095416_initial_model.sql (86.73ms)16542026/09/23 13:33:59 OK 20260628120000_add_object_size_and_stats.sql (19.67ms)16552026/09/23 13:33:59 OK 20251210153512_drop_unused_gin_index.sql (8.23ms)16562026/09/23 13:33:59 OK 20251218171726_add_pins.sql (10.72ms)16572026/09/23 13:33:59 OK 20260905000000_add_claims.sql (26.08ms)16582026/09/23 13:33:59 OK 20260628120000_add_object_size_and_stats.sql (23.74ms)16592026/09/23 13:33:59 OK 20260920000000_drop_claims.sql (14.23ms)16602026/09/23 13:33:59 OK 20260923120000_add_pushes.sql (8.87ms)16612026/09/23 13:33:59 goose: successfully migrated database to version: 2026092312000016622026/09/23 13:33:59 OK 1_commit_pending_closure.sql (1.72ms)16632026/09/23 13:33:59 OK 2_object_stats_trigger.sql (375.83µs)16642026/09/23 13:33:59 OK 3_commit_push.sql (354.75µs)16652026/09/23 13:33:59 goose: up to current file version: 316662026/09/23 13:33:59 OK 20260905000000_add_claims.sql (37.57ms)16672026/09/23 13:33:59 OK 20260920000000_drop_claims.sql (35.84ms)16682026-09-23 13:33:59.807 UTC [66357] ERROR: relation "goose_db_version" does not exist at character 3616692026-09-23 13:33:59.807 UTC [66357] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16702026/09/23 13:33:59 OK 20241026095416_initial_model.sql (121.66ms)16712026/09/23 13:33:59 OK 20260923120000_add_pushes.sql (3.32ms)16722026/09/23 13:33:59 goose: successfully migrated database to version: 2026092312000016732026/09/23 13:33:59 OK 1_commit_pending_closure.sql (2.98ms)16742026/09/23 13:33:59 OK 2_object_stats_trigger.sql (469.83µs)16752026/09/23 13:33:59 OK 3_commit_push.sql (422.29µs)16762026/09/23 13:33:59 goose: up to current file version: 316772026/09/23 13:33:59 OK 20251210153512_drop_unused_gin_index.sql (8.21ms)16782026/09/23 13:33:59 OK 20251218171726_add_pins.sql (33.74ms)16792026/09/23 13:33:59 OK 20260628120000_add_object_size_and_stats.sql (16.73ms)16802026/09/23 13:33:59 OK 20260905000000_add_claims.sql (66.76ms)16812026/09/23 13:33:59 OK 20260920000000_drop_claims.sql (38.95ms)16822026/09/23 13:33:59 OK 20260923120000_add_pushes.sql (23.24ms)16832026/09/23 13:33:59 goose: successfully migrated database to version: 2026092312000016842026/09/23 13:34:00 OK 1_commit_pending_closure.sql (6.74ms)16852026/09/23 13:34:00 OK 2_object_stats_trigger.sql (1.21ms)16862026/09/23 13:34:00 OK 3_commit_push.sql (2.74ms)16872026/09/23 13:34:00 goose: up to current file version: 316882026/09/23 13:34:00 OK 20241026095416_initial_model.sql (181.23ms)16892026/09/23 13:34:00 INFO lead: acquired remote=192.0.2.1:123416902026/09/23 13:34:00 OK 20251210153512_drop_unused_gin_index.sql (10.17ms)16912026/09/23 13:34:00 OK 20251218171726_add_pins.sql (30.99ms)16922026/09/23 13:34:00 OK 20260628120000_add_object_size_and_stats.sql (24.76ms)16932026-09-23 13:34:00.166 UTC [66362] ERROR: relation "goose_db_version" does not exist at character 3616942026-09-23 13:34:00.166 UTC [66362] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16952026/09/23 13:34:00 OK 20260905000000_add_claims.sql (56.04ms)16962026/09/23 13:34:00 INFO lead: released remote=192.0.2.1:123416972026/09/23 13:34:00 OK 20260920000000_drop_claims.sql (48.37ms)16982026/09/23 13:34:00 OK 20260923120000_add_pushes.sql (18.67ms)16992026/09/23 13:34:00 goose: successfully migrated database to version: 2026092312000017002026/09/23 13:34:00 OK 1_commit_pending_closure.sql (3.93ms)17012026/09/23 13:34:00 OK 2_object_stats_trigger.sql (707.38µs)17022026/09/23 13:34:00 OK 3_commit_push.sql (502.92µs)17032026/09/23 13:34:00 goose: up to current file version: 317042026/09/23 13:34:00 INFO lead: acquired remote=192.0.2.1:123417052026/09/23 13:34:00 INFO lead: released remote=192.0.2.1:12341706--- PASS: TestLeadElectsOneAndHandsOver (2.62s)1707=== CONT TestClientMultipleUploads17082026/09/23 13:34:00 INFO Received uploads request method=POST path=/api/pending_closures17092026/09/23 13:34:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst17102026/09/23 13:34:00 INFO Received uploads request method=POST path=/api/pending_closures1711--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.68s)1712=== CONT TestClientIntegration17132026/09/23 13:34:00 OK 20241026095416_initial_model.sql (172.79ms)17142026/09/23 13:34:00 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)17152026/09/23 13:34:00 OK 20251218171726_add_pins.sql (38.01ms)17162026/09/23 13:34:00 OK 20260628120000_add_object_size_and_stats.sql (27.66ms)17172026/09/23 13:34:00 OK 20260905000000_add_claims.sql (63.47ms)17182026/09/23 13:34:00 OK 20260920000000_drop_claims.sql (49.87ms)17192026/09/23 13:34:00 OK 20260923120000_add_pushes.sql (41.1ms)17202026/09/23 13:34:00 goose: successfully migrated database to version: 2026092312000017212026/09/23 13:34:00 OK 1_commit_pending_closure.sql (3.83ms)17222026/09/23 13:34:00 OK 2_object_stats_trigger.sql (1.02ms)17232026/09/23 13:34:00 OK 3_commit_push.sql (819.13µs)17242026/09/23 13:34:00 goose: up to current file version: 317252026/09/23 13:34:00 INFO Received uploads request method=POST path=/api/pending_closures17262026-09-23 13:34:00.658 UTC [66368] ERROR: relation "goose_db_version" does not exist at character 3617272026-09-23 13:34:00.658 UTC [66368] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17282026/09/23 13:34:00 OK 20241026095416_initial_model.sql (233.45ms)17292026/09/23 13:34:00 OK 20251210153512_drop_unused_gin_index.sql (9.13ms)1730--- PASS: TestService_Rustfstest (2.83s)1731=== CONT TestClientErrorHandling1732=== RUN TestClientErrorHandling/InvalidStorePath1733=== PAUSE TestClientErrorHandling/InvalidStorePath1734=== RUN TestClientErrorHandling/InvalidAuthToken1735=== PAUSE TestClientErrorHandling/InvalidAuthToken1736=== RUN TestClientErrorHandling/ServerNotAvailable1737=== PAUSE TestClientErrorHandling/ServerNotAvailable1738=== CONT TestClientCADerivations17392026/09/23 13:34:01 OK 20251218171726_add_pins.sql (48.34ms)17402026/09/23 13:34:01 OK 20260628120000_add_object_size_and_stats.sql (40.87ms)17412026/09/23 13:34:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17422026/09/23 13:34:01 OK 20260905000000_add_claims.sql (62.6ms)17432026/09/23 13:34:01 OK 20260920000000_drop_claims.sql (30.8ms)17442026/09/23 13:34:01 OK 20260923120000_add_pushes.sql (27.47ms)17452026/09/23 13:34:01 goose: successfully migrated database to version: 2026092312000017462026/09/23 13:34:01 OK 1_commit_pending_closure.sql (5.22ms)17472026/09/23 13:34:01 OK 2_object_stats_trigger.sql (1.33ms)17482026/09/23 13:34:01 OK 3_commit_push.sql (772.13µs)17492026/09/23 13:34:01 goose: up to current file version: 317502026-09-23 13:34:01.212 UTC [66371] ERROR: relation "goose_db_version" does not exist at character 3617512026-09-23 13:34:01.212 UTC [66371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17522026-09-23 13:34:01.399 UTC [66372] ERROR: relation "goose_db_version" does not exist at character 3617532026-09-23 13:34:01.399 UTC [66372] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17542026/09/23 13:34:01 OK 20241026095416_initial_model.sql (169.26ms)17552026/09/23 13:34:01 OK 20251210153512_drop_unused_gin_index.sql (8.76ms)17562026/09/23 13:34:01 OK 20251218171726_add_pins.sql (28.68ms)17572026/09/23 13:34:01 OK 20260628120000_add_object_size_and_stats.sql (33.97ms)17582026-09-23 13:34:01.530 UTC [66375] ERROR: relation "goose_db_version" does not exist at character 3617592026-09-23 13:34:01.530 UTC [66375] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17602026/09/23 13:34:01 INFO Received uploads request method=POST path=/api/pending_closures17612026/09/23 13:34:01 OK 20260905000000_add_claims.sql (51.71ms)17622026/09/23 13:34:01 OK 20241026095416_initial_model.sql (136.71ms)17632026/09/23 13:34:01 OK 20260920000000_drop_claims.sql (8.67ms)17642026/09/23 13:34:01 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)17652026/09/23 13:34:01 OK 20260923120000_add_pushes.sql (8.26ms)17662026/09/23 13:34:01 goose: successfully migrated database to version: 2026092312000017672026/09/23 13:34:01 OK 1_commit_pending_closure.sql (1.75ms)17682026/09/23 13:34:01 OK 2_object_stats_trigger.sql (376.67µs)17692026/09/23 13:34:01 OK 3_commit_push.sql (296.25µs)17702026/09/23 13:34:01 goose: up to current file version: 317712026/09/23 13:34:01 OK 20251218171726_add_pins.sql (34.24ms)17722026/09/23 13:34:01 OK 20260628120000_add_object_size_and_stats.sql (35.38ms)1773=== NAME TestPinProtectsFromGC1774 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-66117-1423409739/TestPinProtectsFromGC977054660/001/store/z3aaam9mfxa6vqwv18mkw7bxdahyzpnc-pinned-file.txt1775 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-66117-1423409739/TestPinProtectsFromGC977054660/001/store/0s3bgx0qaxbfa8qd7m4ljvhnjj3frrws-unpinned-file.txt17762026/09/23 13:34:01 OK 20260905000000_add_claims.sql (61.31ms)17772026/09/23 13:34:01 OK 20241026095416_initial_model.sql (158.73ms)17782026/09/23 13:34:01 OK 20251210153512_drop_unused_gin_index.sql (10.55ms)17792026/09/23 13:34:01 OK 20260920000000_drop_claims.sql (46.78ms)17802026/09/23 13:34:01 INFO Received uploads request method=POST path=/api/pending_closures17812026/09/23 13:34:01 OK 20251218171726_add_pins.sql (28.32ms)17822026/09/23 13:34:01 OK 20260923120000_add_pushes.sql (6.6ms)17832026/09/23 13:34:01 goose: successfully migrated database to version: 2026092312000017842026/09/23 13:34:01 OK 1_commit_pending_closure.sql (988.5µs)17852026/09/23 13:34:01 OK 2_object_stats_trigger.sql (238.67µs)17862026/09/23 13:34:01 OK 3_commit_push.sql (183.75µs)17872026/09/23 13:34:01 goose: up to current file version: 317882026/09/23 13:34:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17892026/09/23 13:34:01 INFO Uploading z3aaam9mfxa6vqwv18mkw7bxdahyzpnc-pinned-file.txt (128B)17902026/09/23 13:34:01 OK 20260628120000_add_object_size_and_stats.sql (34.85ms)17912026/09/23 13:34:01 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17922026/09/23 13:34:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17932026/09/23 13:34:01 WARN Failed to register uploaded object key=z3aaam9mfxa6vqwv18mkw7bxdahyzpnc.ls error="server returned 404: 404 page not found\n"17942026/09/23 13:34:01 INFO Signed narinfos id=1 count=117952026/09/23 13:34:01 INFO Uploading 1 narinfos17962026/09/23 13:34:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17972026/09/23 13:34:01 WARN Failed to register uploaded object key=z3aaam9mfxa6vqwv18mkw7bxdahyzpnc.narinfo error="server returned 404: 404 page not found\n"17982026/09/23 13:34:01 INFO Completed upload id=117992026/09/23 13:34:01 INFO Upload complete. (138ms)18002026/09/23 13:34:01 OK 20260905000000_add_claims.sql (67.13ms)18012026/09/23 13:34:01 INFO Received uploads request method=POST path=/api/pending_closures18022026/09/23 13:34:01 OK 20260920000000_drop_claims.sql (32.08ms)18032026/09/23 13:34:01 OK 20260923120000_add_pushes.sql (24.47ms)18042026/09/23 13:34:01 goose: successfully migrated database to version: 2026092312000018052026/09/23 13:34:01 OK 1_commit_pending_closure.sql (1.11ms)18062026/09/23 13:34:01 INFO Received uploads request method=POST path=/api/pending_closures18072026/09/23 13:34:01 OK 2_object_stats_trigger.sql (259.08µs)18082026/09/23 13:34:01 OK 3_commit_push.sql (207.29µs)18092026/09/23 13:34:01 goose: up to current file version: 318102026/09/23 13:34:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18112026/09/23 13:34:01 INFO Uploading 0s3bgx0qaxbfa8qd7m4ljvhnjj3frrws-unpinned-file.txt (128B)18122026/09/23 13:34:01 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18132026/09/23 13:34:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18142026/09/23 13:34:01 INFO Signed narinfos id=2 count=118152026/09/23 13:34:01 INFO Uploading 1 narinfos18162026/09/23 13:34:01 WARN Failed to register uploaded object key=0s3bgx0qaxbfa8qd7m4ljvhnjj3frrws.ls error="server returned 404: 404 page not found\n"18172026/09/23 13:34:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18182026/09/23 13:34:01 WARN Failed to register uploaded object key=0s3bgx0qaxbfa8qd7m4ljvhnjj3frrws.narinfo error="server returned 404: 404 page not found\n"18192026/09/23 13:34:01 INFO Completed upload id=218202026/09/23 13:34:01 INFO Upload complete. (98ms)18212026/09/23 13:34:02 INFO Received create pin request method=POST path=/api/pins/myapp18222026/09/23 13:34:02 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-66117-1423409739/TestPinProtectsFromGC977054660/001/store/z3aaam9mfxa6vqwv18mkw7bxdahyzpnc-pinned-file.txt narinfo_key=z3aaam9mfxa6vqwv18mkw7bxdahyzpnc.narinfo18232026/09/23 13:34:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures18242026/09/23 13:34:02 INFO Garbage collection started18252026/09/23 13:34:02 INFO Aborted multipart uploads count=018262026/09/23 13:34:02 WARN Force mode enabled - objects will be deleted immediately without grace period18272026/09/23 13:34:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18282026/09/23 13:34:02 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NmI2Y2EyYjUtNjhkMC00ZGZjLWI3YmItODU5Y2FmODUzNThmLmQwOWM4YTBlLTNiN2UtNGRmYi05ZmFlLWMyMjBmM2RlMzZmMngxNzkwMTcwNDQxOTM0NzE0MDAw18292026/09/23 13:34:02 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NmI2Y2EyYjUtNjhkMC00ZGZjLWI3YmItODU5Y2FmODUzNThmLmQwOWM4YTBlLTNiN2UtNGRmYi05ZmFlLWMyMjBmM2RlMzZmMngxNzkwMTcwNDQxOTM0NzE0MDAw parts=11830--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.95s)1831=== CONT TestCacheStatsHandler1832=== NAME TestOrphanedObjectsGCStressTest1833 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains18342026/09/23 13:34:02 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=018352026-09-23 13:34:02.320 UTC [66392] ERROR: relation "goose_db_version" does not exist at character 3618362026-09-23 13:34:02.320 UTC [66392] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18372026/09/23 13:34:02 INFO Vacuumed table table=pending_closures1838 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18392026/09/23 13:34:02 INFO Vacuumed table table=pending_objects18402026/09/23 13:34:02 INFO Vacuumed table table=multipart_uploads18412026/09/23 13:34:02 INFO Vacuumed table table=closures18422026/09/23 13:34:02 INFO Vacuumed table table=objects18432026-09-23 13:34:02.528 UTC [66395] ERROR: relation "goose_db_version" does not exist at character 3618442026-09-23 13:34:02.528 UTC [66395] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18452026/09/23 13:34:02 OK 20241026095416_initial_model.sql (176.69ms)18462026/09/23 13:34:02 OK 20251210153512_drop_unused_gin_index.sql (5.72ms)18472026/09/23 13:34:02 OK 20251218171726_add_pins.sql (24.34ms)18482026/09/23 13:34:02 OK 20260628120000_add_object_size_and_stats.sql (33.63ms)18492026/09/23 13:34:02 INFO Received uploads request method=POST path=/api/pending_closures18502026/09/23 13:34:02 OK 20260905000000_add_claims.sql (18.42ms)18512026/09/23 13:34:02 OK 20260920000000_drop_claims.sql (7.97ms)18522026/09/23 13:34:02 OK 20260923120000_add_pushes.sql (2.31ms)18532026/09/23 13:34:02 goose: successfully migrated database to version: 2026092312000018542026/09/23 13:34:02 OK 20241026095416_initial_model.sql (92.37ms)18552026/09/23 13:34:02 OK 1_commit_pending_closure.sql (1.24ms)18562026/09/23 13:34:02 OK 2_object_stats_trigger.sql (254.67µs)18572026/09/23 13:34:02 OK 3_commit_push.sql (182.83µs)18582026/09/23 13:34:02 goose: up to current file version: 318592026/09/23 13:34:02 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)18602026-09-23 13:34:02.677 UTC [66406] ERROR: relation "goose_db_version" does not exist at character 3618612026-09-23 13:34:02.677 UTC [66406] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18622026/09/23 13:34:02 OK 20251218171726_add_pins.sql (26.71ms)18632026/09/23 13:34:02 OK 20260628120000_add_object_size_and_stats.sql (17.82ms)18642026/09/23 13:34:02 OK 20260905000000_add_claims.sql (7.21ms)18652026/09/23 13:34:02 OK 20260920000000_drop_claims.sql (8.93ms)18662026/09/23 13:34:02 OK 20260923120000_add_pushes.sql (5.89ms)18672026/09/23 13:34:02 goose: successfully migrated database to version: 2026092312000018682026/09/23 13:34:02 INFO Received uploads request method=POST path=/api/pending_closures18692026/09/23 13:34:02 OK 1_commit_pending_closure.sql (1.25ms)18702026/09/23 13:34:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18712026/09/23 13:34:02 INFO Uploading b9mm6ffgjxx5pzsx4wmymcizw4xb3li0-shared-dep (136B)18722026/09/23 13:34:02 OK 2_object_stats_trigger.sql (260µs)18732026/09/23 13:34:02 OK 3_commit_push.sql (230µs)18742026/09/23 13:34:02 goose: up to current file version: 318752026/09/23 13:34:02 WARN Failed to register uploaded object key=b9mm6ffgjxx5pzsx4wmymcizw4xb3li0.ls error="server returned 404: 404 page not found\n"18762026/09/23 13:34:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18772026/09/23 13:34:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18782026/09/23 13:34:02 INFO Signed narinfos id=2 count=118792026/09/23 13:34:02 INFO Uploading 1 narinfos18802026/09/23 13:34:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18812026/09/23 13:34:02 WARN Failed to register uploaded object key=b9mm6ffgjxx5pzsx4wmymcizw4xb3li0.narinfo error="server returned 404: 404 page not found\n"18822026/09/23 13:34:02 INFO Completed upload id=218832026/09/23 13:34:02 INFO Upload complete. (86ms)18842026/09/23 13:34:02 INFO Received uploads request method=POST path=/api/pending_closures18852026/09/23 13:34:02 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18862026/09/23 13:34:02 INFO Uploading b9mm6ffgjxx5pzsx4wmymcizw4xb3li0-shared-dep (136B)18872026/09/23 13:34:02 INFO Uploading f9hpbaiabrh6fx7mfpf6rkm2px4gwyjm-top (256B)18882026/09/23 13:34:02 OK 20241026095416_initial_model.sql (80.35ms)18892026/09/23 13:34:02 OK 20251210153512_drop_unused_gin_index.sql (6.42ms)18902026/09/23 13:34:02 WARN Failed to register uploaded object key=f9hpbaiabrh6fx7mfpf6rkm2px4gwyjm.ls error="server returned 404: 404 page not found\n"18912026/09/23 13:34:02 WARN Failed to register uploaded object key=nar/0dvhnqypfdxw6b0lccz77hlr3m3y3b3xqjwnlzd959v2b2p2516b.nar.zst error="server returned 404: 404 page not found\n"18922026/09/23 13:34:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18932026/09/23 13:34:02 WARN Failed to register uploaded object key=b9mm6ffgjxx5pzsx4wmymcizw4xb3li0.ls error="server returned 404: 404 page not found\n"18942026/09/23 13:34:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18952026/09/23 13:34:02 INFO Signed narinfos id=1 count=118962026/09/23 13:34:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign18972026/09/23 13:34:02 INFO Signed narinfos id=3 count=118982026/09/23 13:34:02 INFO Uploading 2 narinfos18992026/09/23 13:34:02 WARN Failed to register uploaded object key=f9hpbaiabrh6fx7mfpf6rkm2px4gwyjm.narinfo error="server returned 404: 404 page not found\n"19002026/09/23 13:34:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19012026/09/23 13:34:02 WARN Failed to register uploaded object key=b9mm6ffgjxx5pzsx4wmymcizw4xb3li0.narinfo error="server returned 404: 404 page not found\n"19022026/09/23 13:34:02 OK 20251218171726_add_pins.sql (90.55ms)19032026/09/23 13:34:02 INFO Completed upload id=119042026/09/23 13:34:02 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete19052026/09/23 13:34:02 INFO Completed upload id=319062026/09/23 13:34:02 INFO Upload complete. (296ms)1907=== NAME TestClientSharedPathCommittedMidPush1908 client_integration_test.go:680: Retrieved narinfo from S3:1909 StorePath: /nix/var/nix/builds/nix-66117-1423409739/TestClientSharedPathCommittedMidPush3649348646/001/store/b9mm6ffgjxx5pzsx4wmymcizw4xb3li0-shared-dep1910 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1911 Compression: zstd1912 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821913 NarSize: 1361914 References: 1915 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1916 client_integration_test.go:680: Retrieved narinfo from S3:1917 StorePath: /nix/var/nix/builds/nix-66117-1423409739/TestClientSharedPathCommittedMidPush3649348646/001/store/f9hpbaiabrh6fx7mfpf6rkm2px4gwyjm-top1918 URL: nar/0dvhnqypfdxw6b0lccz77hlr3m3y3b3xqjwnlzd959v2b2p2516b.nar.zst1919 Compression: zstd1920 NarHash: sha256:0dvhnqypfdxw6b0lccz77hlr3m3y3b3xqjwnlzd959v2b2p2516b1921 NarSize: 2561922 References: /nix/var/nix/builds/nix-66117-1423409739/TestClientSharedPathCommittedMidPush3649348646/001/store/b9mm6ffgjxx5pzsx4wmymcizw4xb3li0-shared-dep1923 CA: text:sha256:0b0d4zw54vip1d3hkz2356w7jm5nxxngh3nvkn1ryaazli6kxhzr1924=== NAME TestClientWithDependencies1925 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-66117-1423409739/TestClientWithDependencies3165159706/001/store/l8yvks0x9db1j9rpplsmfh8g43sxbzrm-test-script19262026/09/23 13:34:02 OK 20260628120000_add_object_size_and_stats.sql (33.89ms)1927--- PASS: TestClientSharedPathCommittedMidPush (3.43s)1928=== CONT TestService_ReadScope_PublicByDefault1929=== NAME TestClientWithDependencies1930 client_integration_test.go:615: Found 1 dependencies (including self)19312026/09/23 13:34:02 OK 20260905000000_add_claims.sql (33.2ms)19322026/09/23 13:34:03 OK 20260920000000_drop_claims.sql (40.31ms)19332026/09/23 13:34:03 OK 20260923120000_add_pushes.sql (15.48ms)19342026/09/23 13:34:03 goose: successfully migrated database to version: 2026092312000019352026/09/23 13:34:03 OK 1_commit_pending_closure.sql (823.79µs)19362026/09/23 13:34:03 OK 2_object_stats_trigger.sql (262.83µs)19372026/09/23 13:34:03 OK 3_commit_push.sql (202.58µs)19382026/09/23 13:34:03 goose: up to current file version: 319392026/09/23 13:34:03 INFO Received uploads request method=POST path=/api/pending_closures19402026/09/23 13:34:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19412026/09/23 13:34:03 INFO Uploading l8yvks0x9db1j9rpplsmfh8g43sxbzrm-test-script (136B)19422026/09/23 13:34:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19432026/09/23 13:34:03 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19442026/09/23 13:34:03 WARN Failed to register uploaded object key=l8yvks0x9db1j9rpplsmfh8g43sxbzrm.ls error="server returned 404: 404 page not found\n"19452026/09/23 13:34:03 WARN Failed to register uploaded object key=log/5m9708z5ff97vivrbqkj3zs59mrxj5rg-test-script.drv error="server returned 404: 404 page not found\n"19462026/09/23 13:34:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19472026/09/23 13:34:03 INFO Signed narinfos id=1 count=119482026/09/23 13:34:03 INFO Uploading 1 narinfos19492026/09/23 13:34:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19502026/09/23 13:34:03 WARN Failed to register uploaded object key=l8yvks0x9db1j9rpplsmfh8g43sxbzrm.narinfo error="server returned 404: 404 page not found\n"19512026/09/23 13:34:03 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NmI2Y2EyYjUtNjhkMC00ZGZjLWI3YmItODU5Y2FmODUzNThmLmIwZGMyMmEwLTMyYTAtNGFmNy05NDkxLWNjNjE2NjU3MDRkZngxNzkwMTcwNDQxNTk4OTQ2MDAw parts=1219522026/09/23 13:34:03 INFO Received uploads request method=POST path=/api/pending_closures1953=== NAME TestClientMultipleUploads1954 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-66117-1423409739/TestClientMultipleUploads2112138318/001/store/vs19ykwv3n9rray7fv7kmgw85125m8sx-test-file-0.txt1955--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.11s)1956=== CONT TestService_RequireScope_OIDC19572026/09/23 13:34:03 INFO Completed upload id=119582026/09/23 13:34:03 INFO Upload complete. (154ms)1959=== NAME TestClientWithDependencies1960 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-66117-1423409739/TestClientWithDependencies3165159706/001/store) requires matching store prefix1961--- PASS: TestClientWithDependencies (3.64s)1962=== CONT TestService_AuthMiddleware_MTLSBoundSubjects19632026/09/23 13:34:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59640/oidc1964=== NAME TestClientMultipleUploads1965 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-66117-1423409739/TestClientMultipleUploads2112138318/001/store/5ph7zy7klxh8qm80gqhp40daasn1swm6-test-file-1.txt1966 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-66117-1423409739/TestClientMultipleUploads2112138318/001/store/hk7qyir6f7rrh7dw27g8vngpqzip5ixc-test-file-2.txt1967=== NAME TestClientIntegration1968 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-66117-1423409739/TestClientIntegration1665519738/002/store/wblxs79sb4r1fnlalgsy72kf4zj7xk79-test-file.txt19692026/09/23 13:34:03 INFO Received uploads request method=POST path=/api/pending_closures19702026/09/23 13:34:03 INFO Received uploads request method=POST path=/api/pending_closures19712026-09-23 13:34:03.367 UTC [66440] ERROR: relation "goose_db_version" does not exist at character 3619722026-09-23 13:34:03.367 UTC [66440] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19732026/09/23 13:34:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19742026/09/23 13:34:03 INFO Received uploads request method=POST path=/api/pending_closures19752026/09/23 13:34:03 INFO Uploading wblxs79sb4r1fnlalgsy72kf4zj7xk79-test-file.txt (152B)19762026/09/23 13:34:03 INFO Received uploads request method=POST path=/api/pending_closures19772026/09/23 13:34:03 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19782026/09/23 13:34:03 INFO Uploading 5ph7zy7klxh8qm80gqhp40daasn1swm6-test-file-1.txt (160B)19792026/09/23 13:34:03 INFO Uploading vs19ykwv3n9rray7fv7kmgw85125m8sx-test-file-0.txt (160B)19802026/09/23 13:34:03 INFO Uploading hk7qyir6f7rrh7dw27g8vngpqzip5ixc-test-file-2.txt (160B)19812026/09/23 13:34:03 WARN Failed to register uploaded object key=wblxs79sb4r1fnlalgsy72kf4zj7xk79.ls error="server returned 404: 404 page not found\n"19822026/09/23 13:34:03 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19832026/09/23 13:34:03 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19842026/09/23 13:34:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19852026/09/23 13:34:03 WARN Failed to register uploaded object key=5ph7zy7klxh8qm80gqhp40daasn1swm6.ls error="server returned 404: 404 page not found\n"19862026/09/23 13:34:03 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19872026/09/23 13:34:03 WARN Failed to register uploaded object key=hk7qyir6f7rrh7dw27g8vngpqzip5ixc.ls error="server returned 404: 404 page not found\n"19882026/09/23 13:34:03 WARN Failed to register uploaded object key=vs19ykwv3n9rray7fv7kmgw85125m8sx.ls error="server returned 404: 404 page not found\n"19892026/09/23 13:34:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19902026/09/23 13:34:03 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19912026/09/23 13:34:03 INFO Signed narinfos id=1 count=119922026/09/23 13:34:03 INFO Uploading 1 narinfos19932026/09/23 13:34:03 INFO Signed narinfos id=2 count=119942026/09/23 13:34:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign19952026/09/23 13:34:03 INFO Signed narinfos id=3 count=119962026/09/23 13:34:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19972026/09/23 13:34:03 INFO Signed narinfos id=1 count=119982026/09/23 13:34:03 INFO Uploading 3 narinfos19992026/09/23 13:34:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20002026/09/23 13:34:03 WARN Failed to register uploaded object key=wblxs79sb4r1fnlalgsy72kf4zj7xk79.narinfo error="server returned 404: 404 page not found\n"20012026/09/23 13:34:03 WARN Failed to register uploaded object key=hk7qyir6f7rrh7dw27g8vngpqzip5ixc.narinfo error="server returned 404: 404 page not found\n"20022026/09/23 13:34:03 WARN Failed to register uploaded object key=5ph7zy7klxh8qm80gqhp40daasn1swm6.narinfo error="server returned 404: 404 page not found\n"20032026/09/23 13:34:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20042026/09/23 13:34:03 WARN Failed to register uploaded object key=vs19ykwv3n9rray7fv7kmgw85125m8sx.narinfo error="server returned 404: 404 page not found\n"20052026/09/23 13:34:03 INFO Completed upload id=120062026/09/23 13:34:03 INFO Upload complete. (85ms)20072026/09/23 13:34:03 INFO Completed upload id=120082026/09/23 13:34:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20092026/09/23 13:34:03 INFO Completed upload id=220102026/09/23 13:34:03 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20112026/09/23 13:34:03 INFO Completed upload id=320122026/09/23 13:34:03 INFO Upload complete. (105ms)2013=== NAME TestClientMultipleUploads2014 client_integration_test.go:369: Uploaded 3 paths in 137.68525ms20152026/09/23 13:34:03 INFO All 1 paths already cached2016=== NAME TestClientIntegration2017 client_integration_test.go:312: Retrieved narinfo from S3:2018 StorePath: /nix/var/nix/builds/nix-66117-1423409739/TestClientIntegration1665519738/002/store/wblxs79sb4r1fnlalgsy72kf4zj7xk79-test-file.txt2019 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2020 Compression: zstd2021 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12022 NarSize: 1522023 References: 2024 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12025 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2026 client_integration_test.go:313: Decompressed .ls content (64 bytes):2027 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2028 client_integration_test.go:316: Testing garbage collection...2029--- PASS: TestClientMultipleUploads (3.19s)2030=== CONT TestService_AuthMiddleware_MTLSProxyHeader20312026/09/23 13:34:03 OK 20241026095416_initial_model.sql (56.43ms)20322026/09/23 13:34:03 OK 20251210153512_drop_unused_gin_index.sql (851.75µs)20332026/09/23 13:34:03 OK 20251218171726_add_pins.sql (1.57ms)20342026/09/23 13:34:03 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)20352026/09/23 13:34:03 OK 20260905000000_add_claims.sql (1.43ms)20362026/09/23 13:34:03 OK 20260920000000_drop_claims.sql (849.46µs)20372026/09/23 13:34:03 OK 20260923120000_add_pushes.sql (853.17µs)20382026/09/23 13:34:03 goose: successfully migrated database to version: 2026092312000020392026/09/23 13:34:03 OK 1_commit_pending_closure.sql (1ms)20402026/09/23 13:34:03 OK 2_object_stats_trigger.sql (247.17µs)20412026/09/23 13:34:03 OK 3_commit_push.sql (295.08µs)20422026/09/23 13:34:03 goose: up to current file version: 320432026/09/23 13:34:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures20442026/09/23 13:34:03 INFO Garbage collection started20452026/09/23 13:34:03 INFO Aborted multipart uploads count=020462026/09/23 13:34:03 WARN Force mode enabled - objects will be deleted immediately without grace period2047--- PASS: TestCacheStatsHandler (1.39s)2048=== CONT TestService_AuthMiddleware_OIDC20492026/09/23 13:34:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59659/oidc2050=== NAME TestClientCADerivations2051 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-66117-1423409739/TestClientCADerivations1851260801/001/store/aqn5ak5x1n0vihc8pv41ml3ahkh8b660-ca-test20522026/09/23 13:34:03 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=02053 client_ca_test.go:139: Found 1 dependencies (including self)20542026/09/23 13:34:03 INFO Vacuumed table table=pending_closures20552026/09/23 13:34:03 INFO Vacuumed table table=pending_objects20562026/09/23 13:34:03 INFO Vacuumed table table=multipart_uploads20572026/09/23 13:34:03 INFO Vacuumed table table=closures20582026-09-23 13:34:03.792 UTC [66461] ERROR: relation "goose_db_version" does not exist at character 3620592026-09-23 13:34:03.792 UTC [66461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20602026/09/23 13:34:03 INFO Vacuumed table table=objects20612026/09/23 13:34:03 INFO Received uploads request method=POST path=/api/pending_closures20622026/09/23 13:34:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20632026/09/23 13:34:03 INFO Uploading aqn5ak5x1n0vihc8pv41ml3ahkh8b660-ca-test (144B)20642026/09/23 13:34:03 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20652026/09/23 13:34:03 WARN Failed to register uploaded object key=aqn5ak5x1n0vihc8pv41ml3ahkh8b660.ls error="server returned 404: 404 page not found\n"20662026/09/23 13:34:03 WARN Failed to register uploaded object key=log/w1c46agq9srxs3d20i44qzpn9plqw24h-ca-test.drv error="server returned 404: 404 page not found\n"20672026/09/23 13:34:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20682026/09/23 13:34:03 INFO Signed narinfos id=1 count=120692026/09/23 13:34:03 INFO Uploading 1 narinfos20702026/09/23 13:34:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20712026/09/23 13:34:03 WARN Failed to register uploaded object key=aqn5ak5x1n0vihc8pv41ml3ahkh8b660.narinfo error="server returned 404: 404 page not found\n"20722026/09/23 13:34:03 INFO Completed upload id=120732026/09/23 13:34:03 INFO Upload complete. (163ms)2074 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-66117-1423409739/TestClientCADerivations1851260801/001/store/aqn5ak5x1n0vihc8pv41ml3ahkh8b660-ca-test2075 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2076 Compression: zstd2077 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2078 NarSize: 1442079 References: 2080 Deriver: /nix/var/nix/builds/nix-66117-1423409739/TestClientCADerivations1851260801/001/store/w1c46agq9srxs3d20i44qzpn9plqw24h-ca-test.drv2081 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2082 client_ca_test.go:185: Checking for realisation files in S3...2083 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2084 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20852026/09/23 13:34:03 OK 20241026095416_initial_model.sql (125.49ms)20862026/09/23 13:34:03 OK 20251210153512_drop_unused_gin_index.sql (15.23ms)20872026/09/23 13:34:03 OK 20251218171726_add_pins.sql (10.09ms)2088 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket54?endpoint=http://localhost:59482®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-66117-1423409739/TestClientCADerivations1851260801/001/store'2089 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120902026-09-23 13:34:03.999 UTC [66467] ERROR: relation "goose_db_version" does not exist at character 3620912026-09-23 13:34:03.999 UTC [66467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20922026/09/23 13:34:04 OK 20260628120000_add_object_size_and_stats.sql (12.9ms)20932026-09-23 13:34:04.009 UTC [66468] ERROR: relation "goose_db_version" does not exist at character 3620942026-09-23 13:34:04.009 UTC [66468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20952026/09/23 13:34:04 OK 20260905000000_add_claims.sql (9.13ms)2096--- PASS: TestClientCADerivations (3.05s)2097=== CONT TestService_ReadAuthMiddleware20982026/09/23 13:34:04 OK 20260920000000_drop_claims.sql (28.36ms)20992026/09/23 13:34:04 OK 20260923120000_add_pushes.sql (1.22ms)21002026/09/23 13:34:04 goose: successfully migrated database to version: 2026092312000021012026/09/23 13:34:04 OK 1_commit_pending_closure.sql (822.08µs)21022026/09/23 13:34:04 OK 2_object_stats_trigger.sql (214.25µs)21032026/09/23 13:34:04 OK 3_commit_push.sql (184.88µs)21042026/09/23 13:34:04 goose: up to current file version: 321052026/09/23 13:34:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02106=== NAME TestPinProtectsFromGC2107 client_integration_test.go:794: Pin successfully protected closure from garbage collection2108--- PASS: TestPinProtectsFromGC (5.56s)2109=== CONT TestPush_RejectsBadRequests/no_objects21102026/09/23 13:34:04 INFO Received push request method=POST path=/api/pushes2111=== CONT TestPush_RejectsBadRequests/root_not_in_objects21122026/09/23 13:34:04 INFO Received push request method=POST path=/api/pushes2113=== CONT TestPush_RejectsBadRequests/bad_root21142026/09/23 13:34:04 INFO Received push request method=POST path=/api/pushes2115=== CONT TestPush_RejectsBadRequests/no_roots21162026/09/23 13:34:04 INFO Received push request method=POST path=/api/pushes2117=== CONT TestIsValidUploadKey/narinfo2118--- PASS: TestPush_RejectsBadRequests (0.93s)2119 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2120 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2121 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2122 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2123=== CONT TestIsValidUploadKey/realisation_plus_in_output2124=== CONT TestIsValidUploadKey/unknown_type2125=== CONT TestIsValidUploadKey/empty_key2126=== CONT TestIsValidUploadKey/absolute2127=== CONT TestIsValidUploadKey/traversal_nar2128=== CONT TestIsValidUploadKey/traversal2129=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2130=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2131=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2132=== CONT TestIsValidUploadKey/index.html2133=== CONT TestIsValidUploadKey/nix-cache-info2134=== CONT TestIsValidUploadKey/build_log_home-manager_file2135=== CONT TestIsValidUploadKey/realisation2136=== CONT TestIsValidUploadKey/build_log_equals2137=== CONT TestIsValidUploadKey/build_log_question_mark2138=== CONT TestIsValidUploadKey/build_log_plus_in_name2139=== CONT TestIsValidUploadKey/nar_plain2140=== CONT TestIsValidUploadKey/build_log2141=== CONT TestIsValidUploadKey/listing2142=== CONT TestIsValidUploadKey/nar_xz2143=== CONT TestIsValidUploadKey/nar_zst2144--- PASS: TestIsValidUploadKey (0.00s)2145 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2146 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2147 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2148 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2149 --- PASS: TestIsValidUploadKey/absolute (0.00s)2150 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2151 --- PASS: TestIsValidUploadKey/traversal (0.00s)2152 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2153 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2154 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2155 --- PASS: TestIsValidUploadKey/index.html (0.00s)2156 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2157 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2158 --- PASS: TestIsValidUploadKey/realisation (0.00s)2159 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2160 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2161 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2162 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2163 --- PASS: TestIsValidUploadKey/build_log (0.00s)2164 --- PASS: TestIsValidUploadKey/listing (0.00s)2165 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2166 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2167=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure21682026/09/23 13:34:04 INFO Received uploads request method=POST path=/21692026/09/23 13:34:04 OK 20241026095416_initial_model.sql (111.97ms)21702026/09/23 13:34:04 OK 20251210153512_drop_unused_gin_index.sql (8.07ms)21712026/09/23 13:34:04 OK 20251218171726_add_pins.sql (33.01ms)21722026/09/23 13:34:04 OK 20241026095416_initial_model.sql (138.01ms)21732026/09/23 13:34:04 OK 20251210153512_drop_unused_gin_index.sql (6.69ms)21742026/09/23 13:34:04 OK 20260628120000_add_object_size_and_stats.sql (28.01ms)2175=== NAME TestOrphanedObjectsGCStressTest2176 orphaned_objects_gc_test.go:509: Stress test completed successfully:2177 orphaned_objects_gc_test.go:510: - Active objects preserved: 202178 orphaned_objects_gc_test.go:511: - Objects deleted: 2102179 orphaned_objects_gc_test.go:512: - Total GC'd: 2102180--- PASS: TestOrphanedObjectsGCStressTest (10.45s)2181=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts21822026/09/23 13:34:04 INFO Received request for more parts method=POST path=/21832026/09/23 13:34:04 OK 20251218171726_add_pins.sql (16.92ms)2184=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart21852026/09/23 13:34:04 INFO Received complete multipart upload request method=POST path=/2186=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21872026/09/23 13:34:04 INFO Received uploads request method=POST path=/2188=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21892026/09/23 13:34:04 INFO Received complete multipart upload request method=POST path=/2190=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key21912026/09/23 13:34:04 INFO Received request for more parts method=POST path=/2192=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21932026/09/23 13:34:04 OK 20260628120000_add_object_size_and_stats.sql (31.5ms)21942026/09/23 13:34:04 INFO Received uploads request method=POST path=/2195=== CONT TestIsValidCachePath/narinfo2196--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2197 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2198 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2199 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2200 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2201=== CONT TestIsValidCachePath/index.html2202=== CONT TestIsValidCachePath/short_hash2203=== CONT TestIsValidCachePath/wrong_extension2204=== CONT TestIsValidCachePath/leading_slash2205=== CONT TestIsValidCachePath/empty2206=== CONT TestIsValidCachePath/random_path2207=== CONT TestIsValidCachePath/invalid_char_u2208=== CONT TestIsValidCachePath/invalid_char_e2209=== CONT TestIsValidCachePath/traversal_in_middle2210=== CONT TestIsValidCachePath/traversal_parent2211=== CONT TestIsValidCachePath/nar_uncompressed2212=== CONT TestIsValidCachePath/nix-cache-info2213=== CONT TestIsValidCachePath/realisation2214=== CONT TestIsValidCachePath/log2215=== CONT TestIsValidCachePath/ls2216=== CONT TestIsValidCachePath/nar_zst2217=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2218=== CONT TestIsValidCachePath/nar_bz22219=== CONT TestIsValidCachePath/nar_xz2220--- PASS: TestIsValidCachePath (0.00s)2221 --- PASS: TestIsValidCachePath/narinfo (0.00s)2222 --- PASS: TestIsValidCachePath/index.html (0.00s)2223 --- PASS: TestIsValidCachePath/short_hash (0.00s)2224 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2225 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2226 --- PASS: TestIsValidCachePath/empty (0.00s)2227 --- PASS: TestIsValidCachePath/random_path (0.00s)2228 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2229 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2230 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2231 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2232 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2233 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2234 --- PASS: TestIsValidCachePath/realisation (0.00s)2235 --- PASS: TestIsValidCachePath/log (0.00s)2236 --- PASS: TestIsValidCachePath/ls (0.00s)2237 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2238 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2239 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2240 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2241=== CONT TestParseSingleRange/none2242=== CONT TestParseSingleRange/open-ended2243=== CONT TestParseSingleRange/start_far_past_EOF2244=== CONT TestParseSingleRange/start_past_EOF2245=== CONT TestParseSingleRange/single_byte2246=== CONT TestParseSingleRange/suffix_exceeds_size2247=== CONT TestParseSingleRange/suffix2248=== CONT TestParseSingleRange/end_clamped_to_size2249=== CONT TestParseSingleRange/malformed_both_empty2250=== CONT TestParseSingleRange/malformed_end_before_start2251=== CONT TestParseSingleRange/multi-range_ignored2252=== CONT TestParseSingleRange/malformed_no_dash2253=== CONT TestParseSingleRange/unknown_unit2254=== CONT TestParseSingleRange/closed2255--- PASS: TestParseSingleRange (0.00s)2256 --- PASS: TestParseSingleRange/none (0.00s)2257 --- PASS: TestParseSingleRange/open-ended (0.00s)2258 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2259 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2260 --- PASS: TestParseSingleRange/single_byte (0.00s)2261 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2262 --- PASS: TestParseSingleRange/suffix (0.00s)2263 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2264 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2265 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2266 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2267 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2268 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2269 --- PASS: TestParseSingleRange/closed (0.00s)2270=== CONT TestServerTLSConfig/no_client_CA2271=== CONT TestServerTLSConfig/not_a_PEM_file22722026/09/23 13:34:04 OK 20260905000000_add_claims.sql (44.53ms)2273=== CONT TestServerTLSConfig/missing_CA_file2274--- PASS: TestServerTLSConfig (0.00s)2275 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2276 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)2277 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2278=== CONT TestProxyWriteTimeout/narinfo2279=== CONT TestProxyWriteTimeout/10_GiB_nar2280=== CONT TestProxyWriteTimeout/unknown_size2281=== CONT TestProxyWriteTimeout/1_GiB_nar2282--- PASS: TestProxyWriteTimeout (0.00s)2283 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2284 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2285 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2286 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2287=== CONT TestResolveDBConnectionString/flag_wins2288=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2289=== CONT TestResolveDBConnectionString/nothing_configured2290=== CONT TestResolveDBConnectionString/missing_file_is_an_error2291=== CONT TestResolveDBConnectionString/file_when_flag_empty2292=== CONT TestCacheConfigHandler/full_config,_no_issuer2293=== CONT TestCacheConfigHandler/no_signing_keys2294=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2295=== CONT TestCacheConfigHandler/no_cache_url_configured2296--- PASS: TestCacheConfigHandler (0.00s)2297 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2298 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2299 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2300 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2301=== CONT TestClientErrorHandling/InvalidStorePath2302--- PASS: TestResolveDBConnectionString (0.02s)2303 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2304 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2305 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2306 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2307 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)23082026/09/23 13:34:04 OK 20260920000000_drop_claims.sql (28.4ms)23092026/09/23 13:34:04 OK 20260905000000_add_claims.sql (41.18ms)23102026/09/23 13:34:04 OK 20260923120000_add_pushes.sql (8.25ms)23112026/09/23 13:34:04 goose: successfully migrated database to version: 202609231200002312--- PASS: TestService_ReadScope_PublicByDefault (1.34s)2313=== CONT TestClientErrorHandling/InvalidAuthToken23142026/09/23 13:34:04 OK 1_commit_pending_closure.sql (1.7ms)23152026/09/23 13:34:04 OK 2_object_stats_trigger.sql (235.92µs)23162026/09/23 13:34:04 OK 3_commit_push.sql (204.25µs)23172026/09/23 13:34:04 goose: up to current file version: 323182026/09/23 13:34:04 OK 20260920000000_drop_claims.sql (32.21ms)23192026/09/23 13:34:04 OK 20260923120000_add_pushes.sql (25.17ms)23202026/09/23 13:34:04 goose: successfully migrated database to version: 2026092312000023212026/09/23 13:34:04 OK 1_commit_pending_closure.sql (1.22ms)23222026/09/23 13:34:04 OK 2_object_stats_trigger.sql (260.75µs)23232026/09/23 13:34:04 OK 3_commit_push.sql (226.67µs)23242026/09/23 13:34:04 goose: up to current file version: 32325--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)2326 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2327 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2328 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)2329=== CONT TestClientErrorHandling/ServerNotAvailable23302026/09/23 13:34:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"23312026/09/23 13:34:04 WARN mTLS auth: bound subjects configured but subject DN unavailable23322026/09/23 13:34:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2333--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.37s)23342026/09/23 13:34:04 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23352026-09-23 13:34:04.652 UTC [66479] ERROR: relation "goose_db_version" does not exist at character 3623362026-09-23 13:34:04.652 UTC [66479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23372026/09/23 13:34:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.164469ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2338=== RUN TestService_RequireScope_OIDC/builder_may_write2339=== PAUSE TestService_RequireScope_OIDC/builder_may_write2340=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2341=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2342=== RUN TestService_RequireScope_OIDC/ops_may_admin2343=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2344=== RUN TestService_RequireScope_OIDC/ops_may_not_write2345=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2346=== RUN TestService_RequireScope_OIDC/reader_may_not_write2347=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2348=== RUN TestService_RequireScope_OIDC/static_token_may_admin2349=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2350=== RUN TestService_RequireScope_OIDC/static_token_may_write2351=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2352=== RUN TestService_RequireScope_OIDC/reader_may_read2353=== PAUSE TestService_RequireScope_OIDC/reader_may_read2354=== RUN TestService_RequireScope_OIDC/writer_implies_read2355=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2356=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2357=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2358=== CONT TestService_RequireScope_OIDC/builder_may_write2359=== CONT TestService_RequireScope_OIDC/static_token_may_admin2360=== CONT TestService_RequireScope_OIDC/writer_implies_read2361=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2362=== CONT TestService_RequireScope_OIDC/ops_may_not_write2363=== CONT TestService_RequireScope_OIDC/reader_may_not_write2364=== CONT TestService_RequireScope_OIDC/reader_may_read2365=== CONT TestService_RequireScope_OIDC/static_token_may_write2366=== CONT TestService_RequireScope_OIDC/ops_may_admin2367=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2368--- PASS: TestService_RequireScope_OIDC (1.65s)2369 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2370 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2371 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2372 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2373 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2374 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2375 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2376 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2377 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2378 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)23792026/09/23 13:34:04 OK 20241026095416_initial_model.sql (113.3ms)23802026/09/23 13:34:04 OK 20251210153512_drop_unused_gin_index.sql (7.48ms)23812026/09/23 13:34:04 OK 20251218171726_add_pins.sql (9.06ms)23822026/09/23 13:34:04 OK 20260628120000_add_object_size_and_stats.sql (8.76ms)23832026/09/23 13:34:04 OK 20260905000000_add_claims.sql (11.57ms)23842026/09/23 13:34:04 OK 20260920000000_drop_claims.sql (14.17ms)23852026/09/23 13:34:04 OK 20260923120000_add_pushes.sql (7.66ms)23862026/09/23 13:34:04 goose: successfully migrated database to version: 2026092312000023872026/09/23 13:34:04 OK 1_commit_pending_closure.sql (4.05ms)23882026/09/23 13:34:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=428.240626ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23892026/09/23 13:34:04 OK 2_object_stats_trigger.sql (750.54µs)23902026/09/23 13:34:04 OK 3_commit_push.sql (516.83µs)23912026/09/23 13:34:04 goose: up to current file version: 323922026-09-23 13:34:05.081 UTC [66480] ERROR: relation "goose_db_version" does not exist at character 3623932026-09-23 13:34:05.081 UTC [66480] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2394--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.66s)23952026/09/23 13:34:05 OK 20241026095416_initial_model.sql (41.29ms)23962026/09/23 13:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)23972026/09/23 13:34:05 OK 20251218171726_add_pins.sql (5.68ms)23982026/09/23 13:34:05 OK 20260628120000_add_object_size_and_stats.sql (14.35ms)23992026/09/23 13:34:05 OK 20260905000000_add_claims.sql (22.24ms)24002026/09/23 13:34:05 OK 20260920000000_drop_claims.sql (14.6ms)24012026/09/23 13:34:05 OK 20260923120000_add_pushes.sql (9.34ms)24022026/09/23 13:34:05 goose: successfully migrated database to version: 2026092312000024032026/09/23 13:34:05 OK 1_commit_pending_closure.sql (4.56ms)24042026/09/23 13:34:05 OK 2_object_stats_trigger.sql (995.96µs)24052026/09/23 13:34:05 OK 3_commit_push.sql (784.04µs)24062026/09/23 13:34:05 goose: up to current file version: 324072026/09/23 13:34:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=757.879336ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24082026-09-23 13:34:05.330 UTC [66481] ERROR: relation "goose_db_version" does not exist at character 3624092026-09-23 13:34:05.330 UTC [66481] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24102026-09-23 13:34:05.425 UTC [66482] ERROR: relation "goose_db_version" does not exist at character 3624112026-09-23 13:34:05.425 UTC [66482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24122026/09/23 13:34:05 OK 20241026095416_initial_model.sql (119.04ms)24132026/09/23 13:34:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02414=== NAME TestClientIntegration2415 client_integration_test.go:323: Objects in database after GC:2416 client_integration_test.go:323: Successfully deleted all objects with GC --force24172026/09/23 13:34:05 OK 20251210153512_drop_unused_gin_index.sql (15.54ms)2418=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2419=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2420=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2421=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected24222026/09/23 13:34:05 OK 20251218171726_add_pins.sql (22.14ms)2423=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2424=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2425=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2426=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2427=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2428=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected24292026/09/23 13:34: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]2430=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2431=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected24322026/09/23 13:34:05 WARN Authentication failed token_preview=eyJhbGciOi...ooRRe00ItA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2433--- PASS: TestService_AuthMiddleware_OIDC (1.92s)2434 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2435 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2436 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2437 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2438--- PASS: TestClientIntegration (5.16s)24392026/09/23 13:34:05 OK 20260628120000_add_object_size_and_stats.sql (43.94ms)24402026-09-23 13:34:05.578 UTC [66483] ERROR: relation "goose_db_version" does not exist at character 3624412026-09-23 13:34:05.578 UTC [66483] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24422026/09/23 13:34:05 OK 20260905000000_add_claims.sql (35.43ms)24432026/09/23 13:34:05 OK 20260920000000_drop_claims.sql (3.81ms)24442026/09/23 13:34:05 OK 20241026095416_initial_model.sql (124.16ms)24452026/09/23 13:34:05 OK 20260923120000_add_pushes.sql (2.38ms)24462026/09/23 13:34:05 goose: successfully migrated database to version: 2026092312000024472026/09/23 13:34:05 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)24482026/09/23 13:34:05 OK 1_commit_pending_closure.sql (3.97ms)24492026/09/23 13:34:05 OK 20251218171726_add_pins.sql (3.86ms)24502026/09/23 13:34:05 OK 2_object_stats_trigger.sql (944.46µs)24512026/09/23 13:34:05 OK 3_commit_push.sql (759.96µs)24522026/09/23 13:34:05 goose: up to current file version: 324532026/09/23 13:34:05 OK 20260628120000_add_object_size_and_stats.sql (5.52ms)24542026/09/23 13:34:05 OK 20260905000000_add_claims.sql (36.91ms)24552026/09/23 13:34:05 OK 20241026095416_initial_model.sql (62.15ms)24562026/09/23 13:34:05 OK 20251210153512_drop_unused_gin_index.sql (11.28ms)24572026/09/23 13:34:05 OK 20260920000000_drop_claims.sql (30.81ms)24582026/09/23 13:34:05 OK 20260923120000_add_pushes.sql (8.95ms)24592026/09/23 13:34:05 goose: successfully migrated database to version: 2026092312000024602026/09/23 13:34:05 OK 1_commit_pending_closure.sql (4.29ms)24612026/09/23 13:34:05 OK 2_object_stats_trigger.sql (1.08ms)24622026/09/23 13:34:05 OK 20251218171726_add_pins.sql (21.24ms)24632026/09/23 13:34:05 OK 3_commit_push.sql (925.79µs)24642026/09/23 13:34:05 goose: up to current file version: 324652026/09/23 13:34:05 OK 20260628120000_add_object_size_and_stats.sql (8.34ms)24662026/09/23 13:34:05 OK 20260905000000_add_claims.sql (36.06ms)24672026/09/23 13:34:05 OK 20260920000000_drop_claims.sql (25.41ms)24682026/09/23 13:34:05 OK 20260923120000_add_pushes.sql (9.64ms)24692026/09/23 13:34:05 goose: successfully migrated database to version: 2026092312000024702026/09/23 13:34:05 OK 1_commit_pending_closure.sql (4.34ms)24712026/09/23 13:34:05 OK 2_object_stats_trigger.sql (891.42µs)24722026/09/23 13:34:05 OK 3_commit_push.sql (843.79µs)24732026/09/23 13:34:05 goose: up to current file version: 32474--- PASS: TestService_ReadAuthMiddleware (1.75s)24752026/09/23 13:34:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.746144112s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24762026/09/23 13:34:06 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"24772026/09/23 13:34:06 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"24782026/09/23 13:34:06 WARN Rate limiter enabled after throttle name=s3-test rate=524792026/09/23 13:34:06 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2480=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2481 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102482 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002483--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.79s)24842026/09/23 13:34:07 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24852026/09/23 13:34:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.026189ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24862026/09/23 13:34:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=401.172951ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24872026/09/23 13:34:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=783.357683ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24882026/09/23 13:34:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.574213932s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24892026/09/23 13:34:10 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 127.0.0.1:19999: connect: connection refused"24902026/09/23 13:34:10 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24912026/09/23 13:34:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.280307ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24922026/09/23 13:34:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.877492ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24932026/09/23 13:34:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=743.984687ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24942026/09/23 13:34:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.681835286s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2495--- PASS: TestClientErrorHandling (0.00s)2496 --- PASS: TestClientErrorHandling/InvalidStorePath (1.77s)2497 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.03s)2498 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.75s)2499PASS2500{"timestamp":"2026-09-23T13:34:14.147427Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59563","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}25012026-09-23 13:34:14.253 UTC [66154] LOG: received smart shutdown request25022026-09-23 13:34:14.254 UTC [66154] LOG: background worker "logical replication launcher" (PID 66164) exited with exit code 125032026-09-23 13:34:14.257 UTC [66159] LOG: shutting down25042026-09-23 13:34:14.257 UTC [66159] LOG: checkpoint starting: shutdown immediate25052026-09-23 13:34:15.365 UTC [66159] LOG: checkpoint complete: wrote 12754 buffers (77.8%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.699 s, sync=0.358 s, total=1.109 s; sync files=21203, longest=0.001 s, average=0.001 s; distance=293335 kB, estimate=293335 kB; lsn=0/13602EC0, redo lsn=0/13602EC025062026-09-23 13:34:15.370 UTC [66154] LOG: database system is shut down2507Running OIDC tests...2508=== RUN TestAudienceForIssuer2509=== PAUSE TestAudienceForIssuer2510=== RUN TestGlobMatch2511=== PAUSE TestGlobMatch2512=== RUN TestValidateToken_ValidToken2513=== PAUSE TestValidateToken_ValidToken2514=== RUN TestValidateToken_WrongAudience2515=== PAUSE TestValidateToken_WrongAudience2516=== RUN TestValidateToken_Expired2517=== PAUSE TestValidateToken_Expired2518=== RUN TestValidateToken_BoundClaimsMismatch2519=== PAUSE TestValidateToken_BoundClaimsMismatch2520=== RUN TestValidateToken_BoundSubjectMismatch2521=== PAUSE TestValidateToken_BoundSubjectMismatch2522=== RUN TestValidateToken_MultipleProviders2523=== PAUSE TestValidateToken_MultipleProviders2524=== RUN TestValidateToken_NoMatchingProvider2525=== PAUSE TestValidateToken_NoMatchingProvider2526=== RUN TestValidateToken_KubernetesServiceAccount2527=== PAUSE TestValidateToken_KubernetesServiceAccount2528=== RUN TestNewValidator_KubernetesRequiresCA2529=== PAUSE TestNewValidator_KubernetesRequiresCA2530=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2531=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2532=== RUN TestPins_ReservedForMatchingRule2533=== PAUSE TestPins_ReservedForMatchingRule2534=== RUN TestPins_TopLevelShorthand2535=== PAUSE TestPins_TopLevelShorthand2536=== RUN TestPins_ConfigValidation2537=== PAUSE TestPins_ConfigValidation2538=== RUN TestScopes_LegacyProviderDefaultsToWrite2539=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2540=== RUN TestScopes_Rules2541=== PAUSE TestScopes_Rules2542=== RUN TestScopes_ConfigValidation2543=== PAUSE TestScopes_ConfigValidation2544=== CONT TestAudienceForIssuer2545--- PASS: TestAudienceForIssuer (0.00s)2546=== CONT TestValidateToken_NoMatchingProvider2547=== CONT TestPins_ConfigValidation2548=== CONT TestValidateToken_KubernetesServiceAccount2549=== CONT TestPins_ReservedForMatchingRule2550=== CONT TestPins_TopLevelShorthand2551=== CONT TestScopes_Rules2552=== CONT TestValidateToken_Expired2553=== CONT TestScopes_LegacyProviderDefaultsToWrite2554--- PASS: TestPins_ConfigValidation (0.00s)2555=== CONT TestValidateToken_ValidToken2556=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2557=== CONT TestNewValidator_KubernetesRequiresCA25582026/09/23 13:34:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59718/oidc2559--- PASS: TestPins_TopLevelShorthand (0.02s)2560=== CONT TestGlobMatch2561=== RUN TestGlobMatch/foo_foo2562=== PAUSE TestGlobMatch/foo_foo2563=== RUN TestGlobMatch/foo_bar2564=== PAUSE TestGlobMatch/foo_bar2565=== RUN TestGlobMatch/*_2566=== PAUSE TestGlobMatch/*_2567=== RUN TestGlobMatch/*_anything2568=== PAUSE TestGlobMatch/*_anything2569=== RUN TestGlobMatch/foo*_foo2570=== PAUSE TestGlobMatch/foo*_foo2571=== RUN TestGlobMatch/foo*_foobar2572=== PAUSE TestGlobMatch/foo*_foobar2573=== RUN TestGlobMatch/foo*_bar2574=== PAUSE TestGlobMatch/foo*_bar2575=== RUN TestGlobMatch/*bar_bar2576=== PAUSE TestGlobMatch/*bar_bar2577=== RUN TestGlobMatch/*bar_foobar2578=== PAUSE TestGlobMatch/*bar_foobar2579=== RUN TestGlobMatch/*bar_foo2580=== PAUSE TestGlobMatch/*bar_foo2581=== RUN TestGlobMatch/foo*bar_foobar2582=== PAUSE TestGlobMatch/foo*bar_foobar2583=== RUN TestGlobMatch/foo*bar_foo123bar2584=== PAUSE TestGlobMatch/foo*bar_foo123bar2585=== RUN TestGlobMatch/foo*bar_foobarbaz2586=== PAUSE TestGlobMatch/foo*bar_foobarbaz2587=== RUN TestGlobMatch/*/*_foo/bar2588=== PAUSE TestGlobMatch/*/*_foo/bar2589=== RUN TestGlobMatch/*/*_foo2590=== PAUSE TestGlobMatch/*/*_foo2591=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2592=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2593=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02594=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02595=== RUN TestGlobMatch/refs/*/main_refs/heads/main2596=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2597=== RUN TestGlobMatch/fo?_foo2598=== PAUSE TestGlobMatch/fo?_foo2599=== RUN TestGlobMatch/fo?_fo2600=== PAUSE TestGlobMatch/fo?_fo2601=== RUN TestGlobMatch/fo?_fooo2602=== PAUSE TestGlobMatch/fo?_fooo2603=== RUN TestGlobMatch/?oo_foo2604=== PAUSE TestGlobMatch/?oo_foo2605=== RUN TestGlobMatch/?oo_boo2606=== PAUSE TestGlobMatch/?oo_boo2607=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2608=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2609=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2610=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2611=== CONT TestValidateToken_MultipleProviders26122026/09/23 13:34:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59720/oidc26132026/09/23 13:34:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59722/oidc2614--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)2615=== CONT TestValidateToken_BoundSubjectMismatch26162026/09/23 13:34:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59724/oidc2617--- PASS: TestScopes_Rules (0.05s)2618=== CONT TestScopes_ConfigValidation2619--- PASS: TestScopes_ConfigValidation (0.00s)2620=== CONT TestValidateToken_BoundClaimsMismatch2621--- PASS: TestPins_ReservedForMatchingRule (0.05s)2622=== CONT TestValidateToken_WrongAudience26232026/09/23 13:34:16 http: TLS handshake error from 127.0.0.1:59727: read tcp 127.0.0.1:59726->127.0.0.1:59727: use of closed network connection2624--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)2625=== CONT TestGlobMatch/foo_foo2626=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2627=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2628=== CONT TestGlobMatch/?oo_boo2629=== CONT TestGlobMatch/?oo_foo2630=== CONT TestGlobMatch/fo?_fooo2631=== CONT TestGlobMatch/fo?_fo2632=== CONT TestGlobMatch/fo?_foo2633=== CONT TestGlobMatch/refs/*/main_refs/heads/main2634=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02635=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2636=== CONT TestGlobMatch/*/*_foo2637=== CONT TestGlobMatch/*/*_foo/bar2638=== CONT TestGlobMatch/foo*bar_foobarbaz2639=== CONT TestGlobMatch/foo*bar_foo123bar2640=== CONT TestGlobMatch/foo*bar_foobar2641=== CONT TestGlobMatch/*bar_foo2642=== CONT TestGlobMatch/*bar_foobar2643=== CONT TestGlobMatch/*bar_bar2644=== CONT TestGlobMatch/foo*_bar2645=== CONT TestGlobMatch/foo*_foobar2646=== CONT TestGlobMatch/foo*_foo2647=== CONT TestGlobMatch/*_anything2648=== CONT TestGlobMatch/*_2649=== CONT TestGlobMatch/foo_bar2650--- PASS: TestGlobMatch (0.00s)2651 --- PASS: TestGlobMatch/foo_foo (0.00s)2652 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2653 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2654 --- PASS: TestGlobMatch/?oo_boo (0.00s)2655 --- PASS: TestGlobMatch/?oo_foo (0.00s)2656 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2657 --- PASS: TestGlobMatch/fo?_fo (0.00s)2658 --- PASS: TestGlobMatch/fo?_foo (0.00s)2659 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2660 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2661 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2662 --- PASS: TestGlobMatch/*/*_foo (0.00s)2663 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2664 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2665 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2666 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2667 --- PASS: TestGlobMatch/*bar_foo (0.00s)2668 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2669 --- PASS: TestGlobMatch/*bar_bar (0.00s)2670 --- PASS: TestGlobMatch/foo*_bar (0.00s)2671 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2672 --- PASS: TestGlobMatch/foo*_foo (0.00s)2673 --- PASS: TestGlobMatch/*_anything (0.00s)2674 --- PASS: TestGlobMatch/*_ (0.00s)2675 --- PASS: TestGlobMatch/foo_bar (0.00s)26762026/09/23 13:34:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59728/oidc2677--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)26782026/09/23 13:34:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59732/oidc26792026/09/23 13:34:16 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:597302680--- PASS: TestValidateToken_WrongAudience (0.04s)2681--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)26822026/09/23 13:34:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59735/oidc2683--- PASS: TestValidateToken_ValidToken (0.09s)26842026/09/23 13:34:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59737/oidc2685--- PASS: TestValidateToken_Expired (0.10s)26862026/09/23 13:34:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59739/oidc2687--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)26882026/09/23 13:34:16 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232689--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)26902026/09/23 13:34:16 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59734/oidc2691--- PASS: TestValidateToken_NoMatchingProvider (0.12s)26922026/09/23 13:34:16 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59743/oidc26932026/09/23 13:34:16 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59746/oidc2694--- PASS: TestValidateToken_MultipleProviders (0.14s)2695PASS2696Running hook tests...2697=== RUN TestSendPathsEmpty2698=== PAUSE TestSendPathsEmpty2699=== RUN TestQueueEnqueueAndFetch2700=== PAUSE TestQueueEnqueueAndFetch2701=== RUN TestQueueDeduplication2702=== PAUSE TestQueueDeduplication2703=== RUN TestQueueRemove2704=== PAUSE TestQueueRemove2705=== RUN TestQueueFetchBatchLimit2706=== PAUSE TestQueueFetchBatchLimit2707=== RUN TestQueueRetryMovesToBack2708=== PAUSE TestQueueRetryMovesToBack2709=== RUN TestQueueFetchRemoveLifecycle2710=== PAUSE TestQueueFetchRemoveLifecycle2711=== RUN TestQueueConcurrentWriters2712=== PAUSE TestQueueConcurrentWriters2713=== RUN TestQueueRemoveLargeClosure2714=== PAUSE TestQueueRemoveLargeClosure2715=== RUN TestServerClientIntegration2716=== PAUSE TestServerClientIntegration2717=== RUN TestServerQueueError2718=== PAUSE TestServerQueueError2719=== RUN TestGetListenerSocketActivation2720 server_test.go:210: === RUN TestGetListenerSocketActivation2721 --- PASS: TestGetListenerSocketActivation (0.00s)2722 PASS2723 2724--- PASS: TestGetListenerSocketActivation (0.01s)2725=== RUN TestDrainIsolatesPoisonPath2726=== PAUSE TestDrainIsolatesPoisonPath2727=== RUN TestRunNotBlockedByPoisonHead2728=== PAUSE TestRunNotBlockedByPoisonHead2729=== RUN TestDrainGivesUpWhenServerDown2730=== PAUSE TestDrainGivesUpWhenServerDown2731=== RUN TestFailedPathPrunedByLaterClosure2732=== PAUSE TestFailedPathPrunedByLaterClosure2733=== RUN TestWorkerUploadsAndRemoves2734=== PAUSE TestWorkerUploadsAndRemoves2735=== RUN TestWorkerSkipsGCdPaths2736=== PAUSE TestWorkerSkipsGCdPaths2737=== RUN TestWorkerPrunesClosureDeps2738=== PAUSE TestWorkerPrunesClosureDeps2739=== RUN TestDrainTimeout2740=== PAUSE TestDrainTimeout2741=== CONT TestSendPathsEmpty2742=== CONT TestServerQueueError2743--- PASS: TestSendPathsEmpty (0.00s)2744=== CONT TestServerClientIntegration2745=== CONT TestQueueRemoveLargeClosure2746=== CONT TestWorkerUploadsAndRemoves2747=== CONT TestQueueConcurrentWriters2748=== CONT TestDrainTimeout2749=== CONT TestQueueRemove2750=== CONT TestWorkerPrunesClosureDeps2751=== CONT TestQueueDeduplication2752=== CONT TestQueueFetchBatchLimit27532026/09/23 13:34:16 ERROR Failed to queue paths error="permission denied" count=12754--- PASS: TestServerClientIntegration (0.00s)2755=== CONT TestWorkerSkipsGCdPaths2756--- PASS: TestServerQueueError (0.00s)2757=== CONT TestQueueEnqueueAndFetch27582026/09/23 13:34:16 INFO Upload queue status pending=22759--- PASS: TestQueueEnqueueAndFetch (0.01s)2760=== CONT TestDrainGivesUpWhenServerDown27612026/09/23 13:34:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-66117-1423409739/TestWorkerSkipsGCdPaths3967405289/002/nonexistent27622026/09/23 13:34:16 INFO Uploading batch count=127632026/09/23 13:34:16 INFO Uploading batch count=227642026/09/23 13:34:16 INFO Upload queue status pending=22765--- PASS: TestQueueFetchBatchLimit (0.01s)2766=== CONT TestRunNotBlockedByPoisonHead2767--- PASS: TestQueueRemove (0.01s)2768=== CONT TestFailedPathPrunedByLaterClosure27692026/09/23 13:34:16 INFO Upload queue status pending=227702026/09/23 13:34:16 INFO Uploading batch count=127712026/09/23 13:34:16 INFO Uploading batch count=22772--- PASS: TestQueueDeduplication (0.01s)2773=== CONT TestDrainIsolatesPoisonPath27742026/09/23 13:34:16 INFO Uploading batch count=427752026/09/23 13:34:16 ERROR Upload failed error="upload failed" count=427762026/09/23 13:34:16 INFO Uploading batch count=127772026/09/23 13:34:16 ERROR Upload failed error="upload failed" count=127782026/09/23 13:34:16 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66117-1423409739/TestDrainIsolatesPoisonPath3594614989/002/bbb27792026/09/23 13:34:16 INFO Upload queue status pending=327802026/09/23 13:34:16 INFO Uploading batch count=127812026/09/23 13:34:16 INFO Uploading batch count=127822026/09/23 13:34:16 ERROR Upload failed error="upload failed" count=127832026/09/23 13:34:16 INFO Uploading batch count=127842026/09/23 13:34:16 INFO Uploading batch count=127852026/09/23 13:34:16 ERROR Upload failed error="upload failed" count=127862026/09/23 13:34:16 INFO Uploading batch count=227872026/09/23 13:34:16 ERROR Upload failed error="upload failed" count=227882026/09/23 13:34:16 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66117-1423409739/TestDrainGivesUpWhenServerDown1174048254/002/a27892026/09/23 13:34:16 INFO Uploading batch count=127902026/09/23 13:34:16 ERROR Upload failed error="upload failed" count=127912026/09/23 13:34:16 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66117-1423409739/TestDrainGivesUpWhenServerDown1174048254/002/b27922026/09/23 13:34:16 INFO Uploading batch count=227932026/09/23 13:34:16 ERROR Upload failed error="upload failed" count=227942026/09/23 13:34:16 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66117-1423409739/TestDrainGivesUpWhenServerDown1174048254/002/c27952026/09/23 13:34:16 INFO Uploading batch count=127962026/09/23 13:34:16 ERROR Upload failed error="upload failed" count=127972026/09/23 13:34:16 ERROR Drain finished with paths left in queue remaining=127982026/09/23 13:34:16 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66117-1423409739/TestDrainGivesUpWhenServerDown1174048254/002/d27992026/09/23 13:34:16 INFO Uploading batch count=228002026/09/23 13:34:16 ERROR Upload failed error="upload failed" count=228012026/09/23 13:34:16 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66117-1423409739/TestDrainGivesUpWhenServerDown1174048254/002/e28022026/09/23 13:34:16 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-66117-1423409739/TestDrainGivesUpWhenServerDown1174048254/002/f2803--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)2804=== CONT TestQueueFetchRemoveLifecycle28052026/09/23 13:34:16 ERROR Drain finished with paths left in queue remaining=102806--- PASS: TestDrainIsolatesPoisonPath (0.00s)2807=== CONT TestQueueRetryMovesToBack2808--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2809--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2810--- PASS: TestQueueRetryMovesToBack (0.00s)2811--- PASS: TestWorkerSkipsGCdPaths (0.03s)2812--- PASS: TestWorkerUploadsAndRemoves (0.03s)2813--- PASS: TestWorkerPrunesClosureDeps (0.03s)2814--- PASS: TestQueueRemoveLargeClosure (0.05s)2815--- PASS: TestQueueConcurrentWriters (0.08s)28162026/09/23 13:34:16 ERROR Upload failed error="context deadline exceeded" count=228172026/09/23 13:34:16 ERROR Drain finished with paths left in queue remaining=42818--- PASS: TestDrainTimeout (0.21s)28192026/09/23 13:34:17 INFO Uploading batch count=128202026/09/23 13:34:17 INFO Uploading batch count=128212026/09/23 13:34:17 INFO Uploading batch count=128222026/09/23 13:34:17 ERROR Upload failed error="upload failed" count=128232026/09/23 13:34:17 INFO Uploading batch count=128242026/09/23 13:34:17 ERROR Upload failed error="upload failed" count=128252026/09/23 13:34:17 INFO Uploading batch count=128262026/09/23 13:34:17 ERROR Upload failed error="upload failed" count=128272026/09/23 13:34:17 INFO Uploading batch count=128282026/09/23 13:34:17 ERROR Upload failed error="upload failed" count=128292026/09/23 13:34:17 ERROR Drain finished with paths left in queue remaining=12830--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2831PASS