niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #335
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenEmptyCommand97--- PASS: TestScriptTokenEmptyCommand (0.00s)98=== CONT TestGetStorePathHash99=== CONT TestParsePathInfoJSONMultiplePaths100=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths101=== CONT TestClientSignaturesByStorePath102--- PASS: TestClientSignaturesByStorePath (0.00s)103=== CONT TestUploadMultipart_PartsInParallel104=== CONT TestStreamPushReportsSignatures105=== CONT TestStreamPushRequestLine106=== CONT TestStreamPushGivesUpOnDeadServer107=== CONT TestDumpPathSingleFile108=== CONT TestStreamPushIsolatesFailures109=== CONT TestConvertHashToNix32110=== CONT TestStreamPushBatchesUnderLoad111=== CONT TestEncodeNixBase32WithRealHash112=== CONT TestStreamPushReportsEveryPath113=== CONT TestEncodeNixBase32114=== CONT TestDumpPathWriterError115=== CONT TestResolveStorePath116=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess117=== CONT TestShellSplitErrors118=== CONT TestParsePathInfoJSON119=== CONT TestRateLimiterFeedback120=== CONT TestDoWithRetry_BodyReplayedViaGetBody121=== CONT TestPathInfoHashCompatibility122=== CONT TestPathInfoCACompatibility123=== CONT TestSetClientTLS124=== RUN TestGetStorePathHash/valid_store_path125=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths126--- PASS: TestShellSplitErrors (0.00s)127=== RUN TestConvertHashToNix32/SRI_format_to_Nix321282026/10/01 10:20:32 ERROR Upload failed error="bad path" count=31292026/10/01 10:20:32 WARN Rate limiter enabled after throttle name=server-test rate=51302026/10/01 10:20:32 ERROR Upload failed error="connection refused" count=20131=== CONT TestCaseHackSuffix1322026/10/01 10:20:32 ERROR Server seems unavailable, giving up on batch untried=17133=== RUN TestParsePathInfoJSON/Nix_format134=== PAUSE TestParsePathInfoJSON/Nix_format135=== CONT TestFileTokenEmpty136=== CONT TestDumpPathMatchesNix137--- PASS: TestEncodeNixBase32WithRealHash (0.00s)138--- PASS: TestStreamPushIsolatesFailures (0.00s)139=== RUN TestEncodeNixBase32/test_string_hash140=== PAUSE TestEncodeNixBase32/test_string_hash141=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)142--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)1432026/10/01 10:20:32 ERROR Upload failed error=boom count=1144--- PASS: TestStreamPushReportsSignatures (0.00s)145--- PASS: TestResolveStorePath (0.00s)146=== CONT TestFilterOversizedClosures147=== CONT TestUploadMultipart_SupersededByPeer148=== RUN TestUploadMultipart_SupersededByPeer/exists149=== RUN TestParsePathInfoJSON/Lix_format150=== CONT TestScriptTokenScriptFails151=== PAUSE TestGetStorePathHash/valid_store_path152--- PASS: TestStreamPushReportsEveryPath (0.03s)1532026/10/01 10:20:32 ERROR Upload failed error=boom count=1154=== CONT TestPartSizeForNAR155=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths156=== RUN TestEncodeNixBase32/empty_input157=== RUN TestFilterOversizedClosures/no_limit_keeps_everything158=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32159=== RUN TestRateLimiterFeedback/429_enables_limiter160=== PAUSE TestRateLimiterFeedback/429_enables_limiter161=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything162=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped163=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)164=== PAUSE TestParsePathInfoJSON/Lix_format165=== RUN TestParsePathInfoJSON/empty_input166=== RUN TestGetStorePathHash/basename_without_hyphen_should_error167=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error168=== PAUSE TestEncodeNixBase32/empty_input169=== PAUSE TestUploadMultipart_SupersededByPeer/exists170=== RUN TestConvertHashToNix32/already_Nix32_format171=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths172=== RUN TestPathInfoCACompatibility/null_ca_field173=== PAUSE TestPathInfoCACompatibility/null_ca_field174=== RUN TestPathInfoCACompatibility/old_string_format_-_text175=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text176=== CONT TestScriptTokenNoExpiryRerunsEveryCall177=== CONT TestScriptTokenBadJSON1782026/10/01 10:20:32 WARN Rate limiter enabled after throttle name=server-test rate=51792026/10/01 10:20:32 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:411351802026/10/01 10:20:32 WARN Rate limiter backed off name=server-test rate=51812026/10/01 10:20:32 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:41135182=== CONT TestRegisterUploadedObjectReusesConnections183=== RUN TestPartSizeForNAR/zero_stays_at_minimum184=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum185=== RUN TestRateLimiterFeedback/503_enables_limiter186=== PAUSE TestRateLimiterFeedback/503_enables_limiter187=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped188=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon189=== PAUSE TestParsePathInfoJSON/empty_input190=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error191=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error192=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error193=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error194=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter195=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter196=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter197=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter198=== RUN TestFilterOversizedClosures/all_closures_skipped199=== PAUSE TestFilterOversizedClosures/all_closures_skipped200=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon201=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI202=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI203=== RUN TestParsePathInfoJSON/whitespace_only204=== PAUSE TestParsePathInfoJSON/whitespace_only205=== RUN TestParsePathInfoJSON/invalid_JSON206=== PAUSE TestParsePathInfoJSON/invalid_JSON207--- PASS: TestFileTokenEmpty (0.00s)208--- PASS: TestDoServerRequestAttachesToken (0.04s)209=== CONT TestStaticToken210--- PASS: TestStaticToken (0.00s)211=== CONT TestShellSplit212--- PASS: TestShellSplit (0.00s)213=== CONT TestEncodeNixBase32/test_string_hash214=== CONT TestSetClientTLSErrors215=== RUN TestSetClientTLS/rejects_connection_without_client_cert216=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert217=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA218=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA219=== RUN TestSetClientTLS/preserves_debug_logging_transport220=== PAUSE TestSetClientTLS/preserves_debug_logging_transport221=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512222=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512223=== CONT TestSetClientTLSDoesNotMutateDefaultTransport224=== CONT TestScriptTokenCachesUntilRefresh225=== CONT TestEncodeNixBase32/empty_input226=== CONT TestGetStorePathHash/valid_store_path227=== CONT TestRateLimiterFeedback/429_enables_limiter228=== CONT TestFilterOversizedClosures/no_limit_keeps_everything229=== CONT TestGetStorePathHash/basename_without_hyphen_should_error230=== CONT TestRateLimiterFeedback/503_enables_limiter231=== RUN TestSetClientTLSErrors/missing_cert_file232=== PAUSE TestSetClientTLSErrors/missing_cert_file233=== RUN TestSetClientTLSErrors/missing_key_file234=== PAUSE TestSetClientTLSErrors/missing_key_file235=== RUN TestSetClientTLSErrors/missing_ca_file236=== PAUSE TestSetClientTLSErrors/missing_ca_file237=== RUN TestSetClientTLSErrors/invalid_ca_file238=== PAUSE TestSetClientTLSErrors/invalid_ca_file239=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter240=== PAUSE TestConvertHashToNix32/already_Nix32_format241=== RUN TestConvertHashToNix32/invalid_format242=== PAUSE TestConvertHashToNix32/invalid_format243=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive244=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive245=== RUN TestPathInfoCACompatibility/new_structured_format_-_text246=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text247=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method248=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method249=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2502026/10/01 10:20:32 WARN Rate limiter enabled after throttle name=server-test rate=52512026/10/01 10:20:32 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:45519252=== RUN TestPartSizeForNAR/small_stays_at_minimum253=== PAUSE TestPartSizeForNAR/small_stays_at_minimum254=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum255=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum256=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts257=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts258=== RUN TestPartSizeForNAR/1_TiB259=== PAUSE TestPartSizeForNAR/1_TiB260=== RUN TestPartSizeForNAR/5_TiB_S3_max_object261=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped262=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object263=== RUN TestPartSizeForNAR/capped_at_5_GiB264=== CONT TestFilterOversizedClosures/all_closures_skipped265=== CONT TestFileTokenMissing2662026/10/01 10:20:32 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=50267=== CONT TestFileTokenReadsAndCaches2682026/10/01 10:20:32 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=2000269=== CONT TestParsePathInfoJSON/Nix_format270=== RUN TestUploadMultipart_SupersededByPeer/missing271=== CONT TestScriptTokenEmptyToken272--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)273=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths274=== CONT TestSetClientTLS/rejects_connection_without_client_cert275=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths276--- PASS: TestScriptTokenScriptFails (0.00s)277--- PASS: TestScriptTokenBadJSON (0.00s)278--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)279--- PASS: TestEncodeNixBase32 (0.04s)280 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)281 --- PASS: TestEncodeNixBase32/empty_input (0.00s)2822026/10/01 10:20:32 WARN Rate limiter backed off name=server-test rate=5283=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error284=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error285--- PASS: TestGetStorePathHash (0.04s)286 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)287 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)288 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)289 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)290=== CONT TestParsePathInfoJSON/whitespace_only291=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA292=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)293--- PASS: TestFilterOversizedClosures (0.03s)294 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)295 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)296 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)297=== PAUSE TestUploadMultipart_SupersededByPeer/missing298=== CONT TestParsePathInfoJSON/empty_input299=== CONT TestSetClientTLS/preserves_debug_logging_transport300--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)301 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)302 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)303--- PASS: TestFileTokenMissing (0.01s)304=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512305=== CONT TestSetClientTLSErrors/missing_cert_file306=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon307=== CONT TestSetClientTLSErrors/missing_ca_file308=== CONT TestParsePathInfoJSON/Lix_format309=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI310=== CONT TestSetClientTLSErrors/invalid_ca_file311=== CONT TestPathInfoCACompatibility/null_ca_field312=== CONT TestConvertHashToNix32/already_Nix32_format313=== CONT TestPathInfoCACompatibility/old_string_format_-_text314=== CONT TestPathInfoCACompatibility/new_structured_format_-_text315=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive316=== CONT TestUploadMultipart_SupersededByPeer/exists317=== CONT TestConvertHashToNix32/invalid_format318=== PAUSE TestPartSizeForNAR/capped_at_5_GiB319=== CONT TestSetClientTLSErrors/missing_key_file3202026/10/01 10:20:32 WARN Rate limiter enabled after throttle name=server-test rate=5321=== CONT TestParsePathInfoJSON/invalid_JSON3222026/10/01 10:20:32 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39941323=== CONT TestPartSizeForNAR/1_TiB324=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts325=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3262026/10/01 10:20:32 WARN Rate limiter backed off name=server-test rate=5327=== CONT TestPartSizeForNAR/small_stays_at_minimum328=== CONT TestConvertHashToNix32/SRI_format_to_Nix32329--- PASS: TestPathInfoHashCompatibility (0.03s)330 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)331 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)332 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)333 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)334--- PASS: TestFileTokenReadsAndCaches (0.00s)335=== CONT TestUploadMultipart_SupersededByPeer/missing336--- PASS: TestRateLimiterFeedback (0.00s)337 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)338 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)339 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)340 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)341=== CONT TestPartSizeForNAR/zero_stays_at_minimum342=== CONT TestPartSizeForNAR/capped_at_5_GiB343=== CONT TestPartSizeForNAR/5_TiB_S3_max_object344=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum345--- PASS: TestParsePathInfoJSON (0.03s)346 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)347 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)348 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)349 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)350 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)351--- PASS: TestPathInfoCACompatibility (0.00s)352 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)353 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)354 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)355 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)356 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)357--- PASS: TestPartSizeForNAR (0.01s)358 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)359 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)360 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)361 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)362 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)363 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)364 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)365--- PASS: TestConvertHashToNix32 (0.04s)366 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)367 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)368 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)369--- PASS: TestScriptTokenEmptyToken (0.00s)370--- PASS: TestSetClientTLSErrors (0.00s)371 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)372 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)373 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)374 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)375--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)376 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)377 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)378--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)379--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)3802026/10/01 10:20:32 http: TLS handshake error from 127.0.0.1:40804: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.00s)382 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)385--- PASS: TestDumpPathWriterError (0.06s)386--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)387--- PASS: TestStreamPushRequestLine (0.06s)388--- PASS: TestDumpPathSingleFile (0.07s)389--- PASS: TestCaseHackSuffix (0.03s)390--- PASS: TestDumpPathMatchesNix (0.09s)391--- PASS: TestStreamPushBatchesUnderLoad (0.14s)392--- PASS: TestUploadMultipart_PartsInParallel (0.66s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres1387613619/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: 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.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres1387613619/data -l logfile start422423/build/postgres1387613619:5432 - no response4242026-10-01 10:20:34.709 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 10:20:34.710 UTC [129] LOG: listening on Unix socket "/build/postgres1387613619/.s.PGSQL.5432"4262026-10-01 10:20:34.714 UTC [136] LOG: database system was shut down at 2026-10-01 10:20:34 UTC4272026-10-01 10:20:34.717 UTC [129] LOG: database system is ready to accept connections428/build/postgres1387613619:5432 - accepting connections429{"timestamp":"2026-10-01T10:20:34.908788187Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"f0df3356-085a-43df-866b-3c665415f869","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":501,"threadName":"rustfs-worker","threadId":"ThreadId(206)"}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 TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestLeadElectsOneAndHandsOver471=== PAUSE TestLeadElectsOneAndHandsOver472=== RUN TestLeadIncumbentWinsAfterRestart4732026-10-01 10:20:35.200 UTC [373] ERROR: relation "goose_db_version" does not exist at character 364742026-10-01 10:20:35.200 UTC [373] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4752026/10/01 10:20:35 OK 20241026095416_initial_model.sql (10.62ms)4762026/10/01 10:20:35 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)4772026/10/01 10:20:35 OK 20251218171726_add_pins.sql (2.88ms)4782026/10/01 10:20:35 OK 20260628120000_add_object_size_and_stats.sql (21.88ms)4792026/10/01 10:20:35 OK 20260905000000_add_claims.sql (2.96ms)4802026/10/01 10:20:35 OK 20260920000000_drop_claims.sql (1.88ms)4812026/10/01 10:20:35 OK 20260923120000_add_pushes.sql (1.28ms)4822026/10/01 10:20:35 goose: successfully migrated database to version: 202609231200004832026/10/01 10:20:35 OK 1_commit_pending_closure.sql (1.61ms)4842026/10/01 10:20:35 OK 2_object_stats_trigger.sql (674.55µs)4852026/10/01 10:20:35 OK 3_commit_push.sql (639.21µs)4862026/10/01 10:20:35 goose: up to current file version: 34872026/10/01 10:20:35 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 10:20:35 INFO lead: released remote=192.0.2.1:12344892026/10/01 10:20:35 INFO lead: acquired remote=192.0.2.1:12344902026/10/01 10:20:35 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (0.91s)492=== RUN TestLeadEndsOnShutdown493=== PAUSE TestLeadEndsOnShutdown494=== RUN TestGCAdvisoryLockBlocksConcurrentRun4952026-10-01 10:20:35.983 UTC [383] ERROR: relation "goose_db_version" does not exist at character 364962026-10-01 10:20:35.983 UTC [383] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4972026/10/01 10:20:35 OK 20241026095416_initial_model.sql (8.9ms)4982026/10/01 10:20:35 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)4992026/10/01 10:20:36 OK 20251218171726_add_pins.sql (3.21ms)5002026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (3.13ms)5012026/10/01 10:20:36 OK 20260905000000_add_claims.sql (2.78ms)5022026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (1.74ms)5032026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (1.33ms)5042026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200005052026/10/01 10:20:36 OK 1_commit_pending_closure.sql (1.6ms)5062026/10/01 10:20:36 OK 2_object_stats_trigger.sql (714.31µs)5072026/10/01 10:20:36 OK 3_commit_push.sql (633.43µs)5082026/10/01 10:20:36 goose: up to current file version: 3509--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)510=== RUN TestGCBugBareHashReferences511=== PAUSE TestGCBugBareHashReferences512=== RUN TestGCMetrics513=== PAUSE TestGCMetrics514=== RUN TestPushDedupSurvivesConcurrentGC515=== PAUSE TestPushDedupSurvivesConcurrentGC516=== RUN TestDeduplicatedObjectsRecordedAsPending517=== PAUSE TestDeduplicatedObjectsRecordedAsPending518=== RUN TestGCSweepSkipsPendingObjects519=== PAUSE TestGCSweepSkipsPendingObjects520=== RUN TestTombstonedObjectOfferedWithoutWaiting521=== PAUSE TestTombstonedObjectOfferedWithoutWaiting522=== RUN TestGCSweepDeliversEachKeyOnce523=== PAUSE TestGCSweepDeliversEachKeyOnce524=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection526=== RUN TestForceGCDuringPushOffersSweptObject527=== PAUSE TestForceGCDuringPushOffersSweptObject528=== RUN TestFailedS3DeleteKeepsTombstone529=== PAUSE TestFailedS3DeleteKeepsTombstone530=== RUN TestSweepSkipsRowsLockedByPush531=== PAUSE TestSweepSkipsRowsLockedByPush532=== RUN TestRegisterCompletedObjectNeedsPendingRow533=== PAUSE TestRegisterCompletedObjectNeedsPendingRow534=== RUN TestGetExistingObjectsLocksRows535=== PAUSE TestGetExistingObjectsLocksRows536=== RUN TestSweepRechecksPendingAfterLocking537=== PAUSE TestSweepRechecksPendingAfterLocking538=== RUN TestPushWaitsForSweepHoldingRow539=== PAUSE TestPushWaitsForSweepHoldingRow540=== RUN TestCommitRacingPendingCleanupKeepsObjects541=== PAUSE TestCommitRacingPendingCleanupKeepsObjects542=== RUN TestGCEndsOnShutdown543=== PAUSE TestGCEndsOnShutdown544=== RUN TestGCTaskStore_StartNew545=== PAUSE TestGCTaskStore_StartNew546=== RUN TestGCTaskStore_DeduplicateSameParams547=== PAUSE TestGCTaskStore_DeduplicateSameParams548=== RUN TestGCTaskStore_ConflictDifferentParams549=== PAUSE TestGCTaskStore_ConflictDifferentParams550=== RUN TestGCTaskStore_GetEmpty551=== PAUSE TestGCTaskStore_GetEmpty552=== RUN TestGCTaskStore_GetReturnsLatest553=== PAUSE TestGCTaskStore_GetReturnsLatest554=== RUN TestGCTaskStore_CompletedAllowsNewTask555=== PAUSE TestGCTaskStore_CompletedAllowsNewTask556=== RUN TestGCTaskStore_PhaseUpdates557=== PAUSE TestGCTaskStore_PhaseUpdates558=== RUN TestGCTaskStore_Fail559=== PAUSE TestGCTaskStore_Fail560=== RUN TestGracefulShutdownDrainsInflight561=== PAUSE TestGracefulShutdownDrainsInflight562=== RUN TestService_healthCheckHandler563=== PAUSE TestService_healthCheckHandler564=== RUN TestService_readinessHandler565=== PAUSE TestService_readinessHandler566=== RUN TestGenerateLandingPage567=== PAUSE TestGenerateLandingPage568=== RUN TestCacheConfigHandlerMaxNarSize569=== PAUSE TestCacheConfigHandlerMaxNarSize570=== RUN TestCreatePendingClosureRejectsOversizedNAR571=== PAUSE TestCreatePendingClosureRejectsOversizedNAR572=== RUN TestNARDeduplicationMetadataUploadBug573=== PAUSE TestNARDeduplicationMetadataUploadBug574=== RUN TestMetricsInventory575=== PAUSE TestMetricsInventory576=== RUN TestService_NativeMTLS577=== PAUSE TestService_NativeMTLS578=== RUN TestServerTLSConfig579=== PAUSE TestServerTLSConfig580=== RUN TestMultipartCleanup581=== PAUSE TestMultipartCleanup582=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded584=== RUN TestPendingCleanupUsesOneCutoff585=== PAUSE TestPendingCleanupUsesOneCutoff586=== RUN TestObjectStatsTrigger587=== PAUSE TestObjectStatsTrigger588=== RUN TestOrphanedObjectsGC589=== PAUSE TestOrphanedObjectsGC590=== RUN TestOrphanedObjectsGCStressTest591=== PAUSE TestOrphanedObjectsGCStressTest592=== RUN TestCreatePin_ReservedPins593=== PAUSE TestCreatePin_ReservedPins594=== RUN TestPresentReportsOnlyClosureRoots595=== PAUSE TestPresentReportsOnlyClosureRoots596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyNarStreaming609=== PAUSE TestReadProxyNarStreaming610=== RUN TestReadProxy404611=== PAUSE TestReadProxy404612=== RUN TestReadProxyInvalidPath613=== PAUSE TestReadProxyInvalidPath614=== RUN TestReadProxyHead615=== PAUSE TestReadProxyHead616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/01 10:20:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/01 10:20:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/01 10:20:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/01 10:20:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/01 10:20:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/01 10:20:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/01 10:20:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/01 10:20:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/01 10:20:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/01 10:20:36 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestIsValidUploadKey675=== PAUSE TestIsValidUploadKey676=== RUN TestUploadHandlersRejectInvalidKeys677=== PAUSE TestUploadHandlersRejectInvalidKeys678=== RUN TestUploadHandlersRejectOversizedBody679=== PAUSE TestUploadHandlersRejectOversizedBody680=== RUN TestService_cleanupPendingClosuresHandler681=== PAUSE TestService_cleanupPendingClosuresHandler682=== RUN TestService_createPendingClosureHandler683=== PAUSE TestService_createPendingClosureHandler684=== RUN TestService_verifyS3Integrity685=== PAUSE TestService_verifyS3Integrity686=== RUN TestCompleteMultipartUnregistered687=== PAUSE TestCompleteMultipartUnregistered688=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT689=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT690=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle691=== CONT TestPush_SignsNarinfosOfItsPendingObjects692=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT693=== CONT TestReadProxyRangeRequest694=== CONT TestUploadHandlersRejectInvalidKeys695=== CONT TestService_cleanupPendingClosuresHandler696=== CONT TestParseSize697--- PASS: TestParseSize (0.00s)698=== CONT TestGCTaskStore_DeduplicateSameParams699--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)700=== CONT TestGCTaskStore_StartNew701--- PASS: TestGCTaskStore_StartNew (0.00s)702=== CONT TestGCEndsOnShutdown703=== CONT TestService_Rustfstest704=== CONT TestPresignedUploadRegisteredBeforeCommit705=== CONT TestCompletedNarNotReofferedAcrossClosures706=== CONT TestCompleteMultipartUpload_ErrorButObjectExists707=== CONT TestRedundantMultipartUpload708=== CONT TestGCTaskStore_GetReturnsLatest709--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)710=== CONT TestCommitRacingPendingCleanupKeepsObjects711=== CONT TestPush_RejectsBadRequests712=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit713=== CONT TestPush_CompleteCommitsEveryRoot714=== CONT TestPush_OverlappingRootsStoreOneRowPerKey715=== CONT TestReadRedirectUsesPublicS3URL716=== CONT TestUploadHandlersRejectOversizedBody717=== CONT TestGCBugBareHashReferences718=== CONT TestGCTaskStore_GetEmpty719=== CONT TestGCTaskStore_ConflictDifferentParams720--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)721=== CONT TestPushWaitsForSweepHoldingRow722=== CONT TestService_AuthMiddleware723=== CONT TestSweepRechecksPendingAfterLocking724=== CONT TestSkippedUploadsHandler725=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info726--- PASS: TestGCTaskStore_GetEmpty (0.00s)727=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info728=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal729=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal730=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key731=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key732=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key733=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key734=== CONT TestGetExistingObjectsLocksRows7352026/10/01 10:20:36 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000736--- PASS: TestSkippedUploadsHandler (0.00s)737=== CONT TestRegisterCompletedObjectNeedsPendingRow7382026-10-01 10:20:36.356 UTC [449] ERROR: relation "goose_db_version" does not exist at character 367392026-10-01 10:20:36.356 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7402026-10-01 10:20:36.414 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367412026-10-01 10:20:36.414 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7422026-10-01 10:20:36.426 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367432026-10-01 10:20:36.426 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7442026-10-01 10:20:36.427 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367452026-10-01 10:20:36.427 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7462026/10/01 10:20:36 OK 20241026095416_initial_model.sql (19.77ms)7472026-10-01 10:20:36.435 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367482026-10-01 10:20:36.435 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC749=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts750=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts751=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure752=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure753=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart754=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart755=== CONT TestService_verifyS3Integrity7562026-10-01 10:20:36.440 UTC [455] ERROR: relation "goose_db_version" does not exist at character 367572026-10-01 10:20:36.440 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7582026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (7.39ms)7592026/10/01 10:20:36 OK 20251218171726_add_pins.sql (9.51ms)7602026/10/01 10:20:36 OK 20241026095416_initial_model.sql (28.67ms)7612026-10-01 10:20:36.456 UTC [458] ERROR: relation "goose_db_version" does not exist at character 367622026-10-01 10:20:36.456 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7632026-10-01 10:20:36.462 UTC [459] ERROR: relation "goose_db_version" does not exist at character 367642026-10-01 10:20:36.462 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7652026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (17.17ms)7662026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (15.32ms)7672026/10/01 10:20:36 OK 20241026095416_initial_model.sql (32.92ms)7682026/10/01 10:20:36 OK 20241026095416_initial_model.sql (33.09ms)7692026/10/01 10:20:36 OK 20260905000000_add_claims.sql (6.66ms)7702026/10/01 10:20:36 OK 20251218171726_add_pins.sql (7.27ms)7712026/10/01 10:20:36 OK 20241026095416_initial_model.sql (30.12ms)7722026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (4.69ms)7732026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (6.07ms)7742026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (6.28ms)7752026/10/01 10:20:36 OK 20241026095416_initial_model.sql (33.45ms)7762026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (4.45ms)7772026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (4.65ms)7782026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200007792026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (3.69ms)7802026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (16.8ms)7812026/10/01 10:20:36 OK 20251218171726_add_pins.sql (16.1ms)7822026/10/01 10:20:36 OK 1_commit_pending_closure.sql (10.83ms)7832026/10/01 10:20:36 OK 20251218171726_add_pins.sql (11.94ms)7842026/10/01 10:20:36 OK 20251218171726_add_pins.sql (16.12ms)7852026/10/01 10:20:36 OK 20251218171726_add_pins.sql (11.52ms)7862026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.23ms)7872026/10/01 10:20:36 OK 3_commit_push.sql (3.7ms)7882026/10/01 10:20:36 goose: up to current file version: 37892026/10/01 10:20:36 OK 20260905000000_add_claims.sql (8.8ms)7902026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (6.29ms)7912026/10/01 10:20:36 OK 20241026095416_initial_model.sql (26.26ms)7922026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (7.16ms)7932026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (6.99ms)7942026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (6.84ms)7952026/10/01 10:20:36 OK 20241026095416_initial_model.sql (24.62ms)7962026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)7972026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)7982026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.44ms)7992026/10/01 10:20:36 OK 20260905000000_add_claims.sql (3.66ms)8002026/10/01 10:20:36 OK 20260905000000_add_claims.sql (3.96ms)8012026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.22ms)8022026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.17ms)8032026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.12ms)8042026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200008052026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (2.68ms)8062026/10/01 10:20:36 OK 20251218171726_add_pins.sql (3.94ms)8072026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.51ms)8082026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.06ms)8092026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.28ms)8102026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.67ms)8112026-10-01 10:20:36.515 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368122026-10-01 10:20:36.515 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8132026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.94ms)8142026-10-01 10:20:36.516 UTC [460] ERROR: relation "goose_db_version" does not exist at character 368152026-10-01 10:20:36.516 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.77ms)8172026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200008182026-10-01 10:20:36.517 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368192026-10-01 10:20:36.517 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8202026-10-01 10:20:36.518 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368212026-10-01 10:20:36.518 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8222026-10-01 10:20:36.518 UTC [464] ERROR: relation "goose_db_version" does not exist at character 368232026-10-01 10:20:36.518 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8242026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (5.02ms)8252026/10/01 10:20:36 OK 2_object_stats_trigger.sql (3.49ms)8262026-10-01 10:20:36.519 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368272026-10-01 10:20:36.519 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8282026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200008292026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (4.8ms)8302026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200008312026-10-01 10:20:36.519 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368322026-10-01 10:20:36.519 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026-10-01 10:20:36.520 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368342026-10-01 10:20:36.520 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026-10-01 10:20:36.520 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368362026-10-01 10:20:36.520 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5.45ms)8382026-10-01 10:20:36.520 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368392026-10-01 10:20:36.520 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8402026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5.88ms)8412026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (4.94ms)8422026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200008432026/10/01 10:20:36 OK 3_commit_push.sql (1.64ms)8442026/10/01 10:20:36 goose: up to current file version: 38452026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.59ms)8462026-10-01 10:20:36.521 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368472026-10-01 10:20:36.521 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8482026-10-01 10:20:36.522 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368492026-10-01 10:20:36.522 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026-10-01 10:20:36.522 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368512026-10-01 10:20:36.522 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8522026-10-01 10:20:36.522 UTC [473] ERROR: relation "goose_db_version" does not exist at character 368532026-10-01 10:20:36.522 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8542026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.76ms)8552026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.93ms)8562026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.26ms)8572026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.77ms)8582026-10-01 10:20:36.525 UTC [474] ERROR: relation "goose_db_version" does not exist at character 368592026-10-01 10:20:36.525 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8602026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.76ms)8612026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.33ms)8622026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.42ms)8632026/10/01 10:20:36 OK 3_commit_push.sql (2.29ms)8642026/10/01 10:20:36 goose: up to current file version: 38652026/10/01 10:20:36 OK 20260905000000_add_claims.sql (5.16ms)8662026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.11ms)8672026/10/01 10:20:36 OK 3_commit_push.sql (2.34ms)8682026/10/01 10:20:36 goose: up to current file version: 38692026/10/01 10:20:36 OK 3_commit_push.sql (2.33ms)8702026/10/01 10:20:36 goose: up to current file version: 38712026/10/01 10:20:36 OK 3_commit_push.sql (1.86ms)8722026/10/01 10:20:36 goose: up to current file version: 38732026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.31ms)8742026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.38ms)8752026/10/01 10:20:36 INFO Received push request method=POST path=/api/pushes8762026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (4.03ms)8772026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200008782026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (3.04ms)8792026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200008802026/10/01 10:20:36 OK 1_commit_pending_closure.sql (4.28ms)8812026/10/01 10:20:36 OK 1_commit_pending_closure.sql (4.22ms)8822026/10/01 10:20:36 OK 20241026095416_initial_model.sql (14.6ms)8832026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.42ms)8842026/10/01 10:20:36 OK 2_object_stats_trigger.sql (3.12ms)8852026/10/01 10:20:36 OK 20241026095416_initial_model.sql (13.64ms)8862026/10/01 10:20:36 OK 20241026095416_initial_model.sql (15.29ms)8872026/10/01 10:20:36 OK 3_commit_push.sql (1.47ms)8882026/10/01 10:20:36 goose: up to current file version: 38892026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)8902026/10/01 10:20:36 OK 3_commit_push.sql (1.69ms)8912026/10/01 10:20:36 goose: up to current file version: 38922026/10/01 10:20:36 OK 20241026095416_initial_model.sql (13.56ms)8932026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)8942026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)8952026/10/01 10:20:36 OK 20241026095416_initial_model.sql (16.31ms)8962026/10/01 10:20:36 OK 20241026095416_initial_model.sql (13.94ms)8972026/10/01 10:20:36 OK 20241026095416_initial_model.sql (13.09ms)8982026/10/01 10:20:36 OK 20241026095416_initial_model.sql (16.98ms)8992026/10/01 10:20:36 OK 20241026095416_initial_model.sql (15.29ms)9002026/10/01 10:20:36 OK 20241026095416_initial_model.sql (15.9ms)9012026/10/01 10:20:36 OK 20241026095416_initial_model.sql (16.48ms)9022026/10/01 10:20:36 OK 20241026095416_initial_model.sql (14.27ms)9032026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)9042026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)9052026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.99ms)9062026/10/01 10:20:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9072026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)9082026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)9092026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)9102026/10/01 10:20:36 OK 20241026095416_initial_model.sql (16.02ms)9112026/10/01 10:20:36 OK 20241026095416_initial_model.sql (15.94ms)9122026/10/01 10:20:36 OK 20251218171726_add_pins.sql (6.08ms)9132026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.93ms)9142026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.7ms)9152026/10/01 10:20:36 OK 20241026095416_initial_model.sql (15.6ms)9162026/10/01 10:20:36 INFO Signed narinfos id=1 count=1917--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.28s)918=== CONT TestSweepSkipsRowsLockedByPush9192026/10/01 10:20:36 OK 20251218171726_add_pins.sql (5.61ms)9202026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.39ms)9212026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)9222026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)9232026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.81ms)9242026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)9252026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.18ms)9262026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.51ms)9272026/10/01 10:20:36 INFO Received uploads request method=POST path=/api/pending_closures9282026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.29ms)9292026/10/01 10:20:36 OK 20251218171726_add_pins.sql (5.01ms)9302026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.81ms)9312026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.6ms)9322026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.92ms)9332026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (4.74ms)9342026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5.04ms)9352026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)9362026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.92ms)9372026/10/01 10:20:36 OK 20251218171726_add_pins.sql (7.29ms)9382026/10/01 10:20:36 OK 20251218171726_add_pins.sql (7.59ms)9392026/10/01 10:20:36 OK 20251218171726_add_pins.sql (7.62ms)9402026/10/01 10:20:36 OK 20251218171726_add_pins.sql (7.16ms)9412026/10/01 10:20:36 OK 20260905000000_add_claims.sql (5.21ms)9422026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (6.72ms)9432026/10/01 10:20:36 OK 20260905000000_add_claims.sql (5.27ms)9442026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)9452026-10-01 10:20:36.558 UTC [478] ERROR: relation "goose_db_version" does not exist at character 369462026-10-01 10:20:36.558 UTC [478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9472026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.08ms)9482026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (6.61ms)9492026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (7.14ms)9502026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5.29ms)9512026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)9522026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (6.65ms)9532026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (7.25ms)9542026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.46ms)9552026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (4.23ms)9562026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5.28ms)9572026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5.25ms)9582026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5.36ms)9592026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (4.17ms)9602026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5.16ms)9612026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.23ms)9622026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.53ms)9632026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.73ms)9642026/10/01 10:20:36 OK 20260905000000_add_claims.sql (5.46ms)9652026/10/01 10:20:36 OK 20260905000000_add_claims.sql (5.29ms)9662026/10/01 10:20:36 OK 20260905000000_add_claims.sql (5.29ms)9672026/10/01 10:20:36 OK 20260905000000_add_claims.sql (5.13ms)9682026/10/01 10:20:36 OK 20260905000000_add_claims.sql (5.24ms)9692026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.63ms)9702026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (3.37ms)9712026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200009722026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200009732026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.41ms)9742026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200009752026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (2.65ms)9762026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.16ms)9772026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.45ms)9782026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.04ms)9792026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.15ms)9802026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.37ms)9812026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.16ms)9822026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.28ms)9832026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.85ms)9842026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (4.05ms)9852026/10/01 10:20:36 OK 20260905000000_add_claims.sql (5.15ms)9862026/10/01 10:20:36 OK 20260905000000_add_claims.sql (5.44ms)9872026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.36ms)9882026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.83ms)9892026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200009902026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.5ms)9912026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.94ms)9922026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200009932026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.58ms)9942026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.51ms)9952026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200009962026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.73ms)9972026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200009982026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.63ms)9992026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000010002026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.56ms)10012026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000010022026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.55ms)10032026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.64ms)10042026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.81ms)10052026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000010062026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.9ms)10072026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000010082026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.95ms)10092026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.07ms)10102026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.33ms)10112026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.27ms)10122026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.19ms)10132026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.98ms)10142026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.94ms)10152026/10/01 10:20:36 OK 3_commit_push.sql (2.7ms)10162026/10/01 10:20:36 goose: up to current file version: 310172026/10/01 10:20:36 OK 1_commit_pending_closure.sql (4.38ms)10182026/10/01 10:20:36 OK 1_commit_pending_closure.sql (4.1ms)10192026/10/01 10:20:36 OK 1_commit_pending_closure.sql (4.29ms)10202026/10/01 10:20:36 OK 3_commit_push.sql (2.6ms)10212026/10/01 10:20:36 goose: up to current file version: 310222026/10/01 10:20:36 OK 1_commit_pending_closure.sql (4.17ms)10232026/10/01 10:20:36 OK 3_commit_push.sql (7.08ms)10242026/10/01 10:20:36 goose: up to current file version: 310252026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (7.07ms)10262026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000010272026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (7.3ms)10282026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000010292026/10/01 10:20:36 OK 1_commit_pending_closure.sql (7.6ms)10302026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (7.78ms)10312026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000010322026/10/01 10:20:36 OK 2_object_stats_trigger.sql (6.37ms)10332026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (7.74ms)10342026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000010352026/10/01 10:20:36 OK 2_object_stats_trigger.sql (6.47ms)10362026/10/01 10:20:36 OK 1_commit_pending_closure.sql (7.46ms)10372026/10/01 10:20:36 INFO Received uploads request method=POST path=/api/pending_closures10382026/10/01 10:20:36 OK 2_object_stats_trigger.sql (7.13ms)10392026/10/01 10:20:36 OK 2_object_stats_trigger.sql (7.05ms)10402026/10/01 10:20:36 OK 2_object_stats_trigger.sql (7.22ms)10412026/10/01 10:20:36 OK 2_object_stats_trigger.sql (6.94ms)10422026/10/01 10:20:36 OK 20241026095416_initial_model.sql (16.07ms)10432026/10/01 10:20:36 OK 3_commit_push.sql (2.89ms)10442026/10/01 10:20:36 goose: up to current file version: 310452026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.54ms)10462026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.42ms)10472026/10/01 10:20:36 OK 2_object_stats_trigger.sql (3ms)10482026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.23ms)10492026/10/01 10:20:36 OK 3_commit_push.sql (3.19ms)10502026/10/01 10:20:36 goose: up to current file version: 310512026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.11ms)10522026/10/01 10:20:36 OK 2_object_stats_trigger.sql (3.36ms)10532026/10/01 10:20:36 OK 3_commit_push.sql (1.13ms)10542026/10/01 10:20:36 goose: up to current file version: 310552026/10/01 10:20:36 OK 3_commit_push.sql (1.71ms)10562026/10/01 10:20:36 goose: up to current file version: 310572026/10/01 10:20:36 OK 3_commit_push.sql (1.76ms)10582026/10/01 10:20:36 goose: up to current file version: 310592026/10/01 10:20:36 OK 3_commit_push.sql (1.8ms)10602026/10/01 10:20:36 goose: up to current file version: 310612026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2ms)10622026/10/01 10:20:36 OK 3_commit_push.sql (1.64ms)10632026/10/01 10:20:36 OK 3_commit_push.sql (1.42ms)10642026/10/01 10:20:36 goose: up to current file version: 310652026/10/01 10:20:36 goose: up to current file version: 310662026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.81ms)10672026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2ms)10682026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.15ms)10692026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.24ms)10702026/10/01 10:20:36 OK 3_commit_push.sql (983.17µs)10712026/10/01 10:20:36 goose: up to current file version: 310722026/10/01 10:20:36 OK 3_commit_push.sql (690.15µs)10732026/10/01 10:20:36 goose: up to current file version: 310742026/10/01 10:20:36 OK 3_commit_push.sql (929.27µs)10752026/10/01 10:20:36 goose: up to current file version: 310762026/10/01 10:20:36 OK 3_commit_push.sql (897.59µs)10772026/10/01 10:20:36 goose: up to current file version: 310782026/10/01 10:20:36 OK 20251218171726_add_pins.sql (3.37ms)1079--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.32s)1080=== CONT TestCompleteMultipartUnregistered10812026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)10822026/10/01 10:20:36 OK 20260905000000_add_claims.sql (3.77ms)10832026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (2.37ms)10842026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.27ms)10852026/10/01 10:20:36 goose: successfully migrated database to version: 202609231200001086--- PASS: TestService_Rustfstest (0.33s)1087=== CONT TestFailedS3DeleteKeepsTombstone10882026/10/01 10:20:36 OK 1_commit_pending_closure.sql (6.78ms)10892026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.45ms)10902026/10/01 10:20:36 OK 3_commit_push.sql (678.77µs)10912026/10/01 10:20:36 goose: up to current file version: 310922026-10-01 10:20:36.618 UTC [484] ERROR: relation "goose_db_version" does not exist at character 3610932026-10-01 10:20:36.618 UTC [484] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10942026/10/01 10:20:36 INFO Received uploads request method=POST path=/api/pending_closures10952026/10/01 10:20:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10962026/10/01 10:20:36 OK 20241026095416_initial_model.sql (9.26ms)10972026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)10982026/10/01 10:20:36 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10992026/10/01 10:20:36 INFO Received uploads request method=POST path=/api/pending_closures11002026/10/01 10:20:36 OK 20251218171726_add_pins.sql (2.95ms)1101--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.38s)1102=== CONT TestForceGCDuringPushOffersSweptObject1103=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1104=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1105=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1106=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1107=== CONT TestOrphanedObjectsGCStressTest11082026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (3.83ms)11092026/10/01 10:20:36 OK 20260905000000_add_claims.sql (3.57ms)1110--- PASS: TestReadProxyRangeRequest (0.39s)1111=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11122026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (2.67ms)11132026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.22ms)11142026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000011152026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.45ms)11162026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.23ms)11172026/10/01 10:20:36 OK 3_commit_push.sql (1.62ms)11182026/10/01 10:20:36 goose: up to current file version: 31119--- PASS: TestGCEndsOnShutdown (0.41s)1120=== CONT TestReadRedirectKeepsNarinfoProxied1121=== RUN TestPush_RejectsBadRequests/no_roots1122=== PAUSE TestPush_RejectsBadRequests/no_roots1123=== RUN TestPush_RejectsBadRequests/no_objects1124=== PAUSE TestPush_RejectsBadRequests/no_objects1125=== RUN TestPush_RejectsBadRequests/bad_root1126=== PAUSE TestPush_RejectsBadRequests/bad_root1127=== RUN TestPush_RejectsBadRequests/root_not_in_objects1128=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1129=== CONT TestGCSweepDeliversEachKeyOnce11302026-10-01 10:20:36.687 UTC [491] ERROR: relation "goose_db_version" does not exist at character 3611312026-10-01 10:20:36.687 UTC [491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11322026-10-01 10:20:36.689 UTC [492] ERROR: relation "goose_db_version" does not exist at character 3611332026-10-01 10:20:36.689 UTC [492] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026/10/01 10:20:36 INFO Received uploads request method=POST path=/api/pending_closures11352026/10/01 10:20:36 OK 20241026095416_initial_model.sql (19.84ms)11362026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)11372026/10/01 10:20:36 OK 20241026095416_initial_model.sql (20.79ms)11382026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)11392026/10/01 10:20:36 OK 20251218171726_add_pins.sql (3.94ms)11402026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.96ms)11412026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)11422026/10/01 10:20:36 INFO Received uploads request method=POST path=/api/pending_closures11432026/10/01 10:20:36 OK 20260905000000_add_claims.sql (3.74ms)11442026-10-01 10:20:36.729 UTC [495] ERROR: relation "goose_db_version" does not exist at character 3611452026-10-01 10:20:36.729 UTC [495] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11462026/10/01 10:20:36 INFO Received push request method=POST path=/api/pushes11472026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (4.6ms)11482026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.73ms)11492026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.68ms)11502026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.89ms)11512026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000011522026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.2ms)11532026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.64ms)11542026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.61ms)11552026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (3.19ms)11562026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000011572026-10-01 10:20:36.742 UTC [496] ERROR: relation "goose_db_version" does not exist at character 3611582026-10-01 10:20:36.742 UTC [496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11592026/10/01 10:20:36 OK 3_commit_push.sql (1.82ms)11602026/10/01 10:20:36 goose: up to current file version: 311612026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.03ms)11622026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.12ms)11632026/10/01 10:20:36 OK 3_commit_push.sql (1.56ms)11642026/10/01 10:20:36 goose: up to current file version: 311652026/10/01 10:20:36 INFO Received complete push request method=POST path=/api/pushes/1/complete11662026/10/01 10:20:36 OK 20241026095416_initial_model.sql (14.26ms)11672026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)11682026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.19ms)1169--- PASS: TestPush_CompleteCommitsEveryRoot (0.49s)1170=== CONT TestReadRedirectNar11712026-10-01 10:20:36.760 UTC [499] ERROR: relation "goose_db_version" does not exist at character 3611722026-10-01 10:20:36.760 UTC [499] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11732026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)11742026/10/01 10:20:36 OK 20241026095416_initial_model.sql (12.66ms)11752026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)11762026/10/01 10:20:36 OK 20260905000000_add_claims.sql (3.55ms)11772026/10/01 10:20:36 OK 20251218171726_add_pins.sql (3.22ms)11782026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (2.65ms)11792026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (1.99ms)11802026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000011812026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (3.43ms)11822026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.23ms)11832026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.4ms)11842026/10/01 10:20:36 OK 20260905000000_add_claims.sql (3.58ms)11852026-10-01 10:20:36.774 UTC [502] ERROR: relation "goose_db_version" does not exist at character 3611862026-10-01 10:20:36.774 UTC [502] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11872026/10/01 10:20:36 OK 20241026095416_initial_model.sql (9.05ms)11882026/10/01 10:20:36 OK 3_commit_push.sql (1.5ms)11892026/10/01 10:20:36 goose: up to current file version: 311902026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (2.33ms)11912026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)11922026/10/01 10:20:36 INFO Received push request method=POST path=/api/pushes11932026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (3.07ms)11942026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000011952026/10/01 10:20:36 OK 20251218171726_add_pins.sql (3.32ms)11962026/10/01 10:20:36 OK 1_commit_pending_closure.sql (1.85ms)11972026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.48ms)11982026/10/01 10:20:36 OK 3_commit_push.sql (1.52ms)11992026/10/01 10:20:36 goose: up to current file version: 312002026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (4.93ms)12012026/10/01 10:20:36 OK 20260905000000_add_claims.sql (3.94ms)12022026/10/01 10:20:36 INFO Aborted multipart uploads count=0 kept=012032026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.15ms)12042026/10/01 10:20:36 OK 20241026095416_initial_model.sql (12.56ms)12052026/10/01 10:20:36 WARN Force mode enabled - objects will be deleted immediately without grace period12062026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)12072026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.11ms)12082026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000012092026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.36ms)12102026/10/01 10:20:36 OK 20251218171726_add_pins.sql (2.99ms)12112026/10/01 10:20:36 OK 2_object_stats_trigger.sql (921.73µs)12122026/10/01 10:20:36 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=01213--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.53s)1214=== CONT TestTombstonedObjectOfferedWithoutWaiting12152026/10/01 10:20:36 OK 3_commit_push.sql (1.4ms)12162026/10/01 10:20:36 goose: up to current file version: 312172026/10/01 10:20:36 INFO Vacuumed table table=pending_closures12182026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)12192026/10/01 10:20:36 INFO Vacuumed table table=pending_objects12202026/10/01 10:20:36 INFO Vacuumed table table=multipart_uploads12212026/10/01 10:20:36 INFO Vacuumed table table=closures12222026/10/01 10:20:36 INFO Vacuumed table table=objects12232026/10/01 10:20:36 OK 20260905000000_add_claims.sql (3.66ms)12242026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (2.93ms)12252026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (3.16ms)12262026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000012272026/10/01 10:20:36 OK 1_commit_pending_closure.sql (3.01ms)1228--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.55s)1229=== CONT TestReadProxyDisabled1230--- PASS: TestReadRedirectUsesPublicS3URL (0.55s)1231=== CONT TestGCSweepSkipsPendingObjects12322026/10/01 10:20:36 OK 2_object_stats_trigger.sql (2.56ms)12332026/10/01 10:20:36 OK 3_commit_push.sql (1.85ms)12342026/10/01 10:20:36 goose: up to current file version: 312352026/10/01 10:20:36 INFO Received uploads request method=POST path=/api/pending_closures12362026-10-01 10:20:36.843 UTC [514] ERROR: relation "goose_db_version" does not exist at character 3612372026-10-01 10:20:36.843 UTC [514] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12382026/10/01 10:20:36 INFO Received push request method=POST path=/api/pushes12392026/10/01 10:20:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12402026/10/01 10:20:36 OK 20241026095416_initial_model.sql (11.82ms)12412026/10/01 10:20:36 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmJmYmM1MzctN2JhYS00MjU0LWFiYzUtNjEwMmViZjI2MGQ2LjJkYjg5MjI5LTEzZjUtNDk1OS1iM2RiLTY2NGQzYTk5ZGNmNHgxNzkwODUwMDM2ODM3MTIxNjY112422026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)12432026/10/01 10:20:36 OK 20251218171726_add_pins.sql (3.9ms)12442026/10/01 10:20:36 INFO Received complete push request method=POST path=/api/pushes/1/complete12452026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)12462026/10/01 10:20:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmJmYmM1MzctN2JhYS00MjU0LWFiYzUtNjEwMmViZjI2MGQ2LjJkYjg5MjI5LTEzZjUtNDk1OS1iM2RiLTY2NGQzYTk5ZGNmNHgxNzkwODUwMDM2ODM3MTIxNjY1 parts=11247--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.61s)1248=== CONT TestReadProxyRootRedirectsToIndexHTML1249--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.60s)1250=== CONT TestDeduplicatedObjectsRecordedAsPending12512026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.14ms)12522026-10-01 10:20:36.878 UTC [516] ERROR: relation "goose_db_version" does not exist at character 3612532026-10-01 10:20:36.878 UTC [516] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12542026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (2.83ms)12552026/10/01 10:20:36 INFO Received push request method=POST path=/api/pushes12562026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.17ms)12572026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000012582026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.54ms)12592026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.58ms)12602026/10/01 10:20:36 OK 3_commit_push.sql (1.56ms)12612026/10/01 10:20:36 goose: up to current file version: 312622026/10/01 10:20:36 OK 20241026095416_initial_model.sql (10.18ms)12632026/10/01 10:20:36 INFO Received cleanup request method=DELETE path=/api/pending_closures12642026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)12652026/10/01 10:20:36 INFO Aborted multipart uploads count=0 kept=012662026/10/01 10:20:36 OK 20251218171726_add_pins.sql (3.15ms)12672026/10/01 10:20:36 INFO Received uploads request method=POST path=/api/pending_closures12682026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)12692026/10/01 10:20:36 OK 20260905000000_add_claims.sql (3.36ms)12702026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (2.55ms)12712026-10-01 10:20:36.910 UTC [521] ERROR: relation "goose_db_version" does not exist at character 3612722026-10-01 10:20:36.910 UTC [521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12732026/10/01 10:20:36 INFO Received cleanup request method=DELETE path=/api/pending_closures12742026-10-01 10:20:36.910 UTC [522] ERROR: relation "goose_db_version" does not exist at character 3612752026-10-01 10:20:36.910 UTC [522] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12762026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.48ms)12772026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000012782026/10/01 10:20:36 INFO Aborted multipart uploads count=1 kept=012792026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.33ms)12802026/10/01 10:20:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12812026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.79ms)12822026-10-01 10:20:36.916 UTC [464] ERROR: Closure does not exist: id=112832026-10-01 10:20:36.916 UTC [464] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE12842026-10-01 10:20:36.916 UTC [464] STATEMENT: -- name: CommitPendingClosure :exec1285 SELECT commit_pending_closure($1::bigint)1286 1287--- PASS: TestService_cleanupPendingClosuresHandler (0.65s)1288=== CONT TestReadProxyConditionalGet12892026/10/01 10:20:36 OK 3_commit_push.sql (1.27ms)12902026/10/01 10:20:36 goose: up to current file version: 312912026/10/01 10:20:36 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1292--- PASS: TestService_AuthMiddleware (0.65s)1293=== CONT TestPushDedupSurvivesConcurrentGC12942026/10/01 10:20:36 OK 20241026095416_initial_model.sql (17.26ms)12952026/10/01 10:20:36 OK 20241026095416_initial_model.sql (18.67ms)12962026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)12972026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)12982026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.7ms)12992026/10/01 10:20:36 INFO Aborted multipart uploads count=0 kept=013002026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.98ms)13012026/10/01 10:20:36 WARN Force mode enabled - objects will be deleted immediately without grace period13022026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)13032026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (5ms)13042026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.05ms)13052026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.06ms)13062026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (2.63ms)13072026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.68ms)13082026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.35ms)13092026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000013102026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.59ms)13112026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000013122026/10/01 10:20:36 INFO Aborted multipart uploads count=0 kept=013132026/10/01 10:20:36 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=013142026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.44ms)13152026/10/01 10:20:36 OK 1_commit_pending_closure.sql (2.25ms)13162026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.75ms)13172026-10-01 10:20:36.961 UTC [528] ERROR: relation "goose_db_version" does not exist at character 3613182026-10-01 10:20:36.961 UTC [528] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13192026-10-01 10:20:36.961 UTC [529] ERROR: relation "goose_db_version" does not exist at character 3613202026-10-01 10:20:36.961 UTC [529] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13212026/10/01 10:20:36 OK 2_object_stats_trigger.sql (1.65ms)13222026/10/01 10:20:36 WARN Force mode enabled - objects will be deleted immediately without grace period13232026/10/01 10:20:36 INFO Vacuumed table table=pending_closures13242026/10/01 10:20:36 OK 3_commit_push.sql (1.35ms)13252026/10/01 10:20:36 goose: up to current file version: 313262026/10/01 10:20:36 OK 3_commit_push.sql (1.31ms)13272026/10/01 10:20:36 goose: up to current file version: 313282026/10/01 10:20:36 INFO Vacuumed table table=pending_objects13292026/10/01 10:20:36 INFO Vacuumed table table=multipart_uploads13302026/10/01 10:20:36 INFO Vacuumed table table=closures13312026/10/01 10:20:36 INFO Vacuumed table table=objects13322026/10/01 10:20:36 INFO Received complete push request method=POST path=/api/pushes/2/complete1333--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.71s)1334=== CONT TestReadProxyHead13352026/10/01 10:20:36 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=013362026/10/01 10:20:36 OK 20241026095416_initial_model.sql (11.98ms)1337--- PASS: TestGetExistingObjectsLocksRows (0.71s)1338=== CONT TestGCMetrics13392026/10/01 10:20:36 OK 20241026095416_initial_model.sql (12.64ms)13402026/10/01 10:20:36 INFO Vacuumed table table=pending_closures13412026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)13422026/10/01 10:20:36 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)13432026/10/01 10:20:36 INFO Vacuumed table table=pending_objects13442026/10/01 10:20:36 INFO Vacuumed table table=multipart_uploads13452026/10/01 10:20:36 INFO Vacuumed table table=closures13462026/10/01 10:20:36 OK 20251218171726_add_pins.sql (4.15ms)13472026/10/01 10:20:36 INFO Vacuumed table table=objects13482026/10/01 10:20:36 OK 20251218171726_add_pins.sql (3.79ms)1349--- PASS: TestSweepRechecksPendingAfterLocking (0.72s)1350=== CONT TestReadProxyInvalidPath13512026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)13522026/10/01 10:20:36 OK 20260628120000_add_object_size_and_stats.sql (3.89ms)13532026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.32ms)13542026/10/01 10:20:36 OK 20260905000000_add_claims.sql (4.75ms)13552026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (1.99ms)13562026/10/01 10:20:36 OK 20260920000000_drop_claims.sql (3.67ms)13572026/10/01 10:20:36 OK 20260923120000_add_pushes.sql (2.54ms)13582026/10/01 10:20:36 goose: successfully migrated database to version: 2026092312000013592026-10-01 10:20:37.001 UTC [538] ERROR: relation "goose_db_version" does not exist at character 3613602026-10-01 10:20:37.001 UTC [538] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13612026-10-01 10:20:37.001 UTC [539] ERROR: relation "goose_db_version" does not exist at character 3613622026-10-01 10:20:37.001 UTC [539] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13632026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (8.36ms)13642026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000013652026/10/01 10:20:37 OK 1_commit_pending_closure.sql (10.92ms)13662026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures13672026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.69ms)13682026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.74ms)13692026/10/01 10:20:37 OK 3_commit_push.sql (1.56ms)13702026/10/01 10:20:37 goose: up to current file version: 313712026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.67ms)13722026/10/01 10:20:37 OK 3_commit_push.sql (1.63ms)13732026/10/01 10:20:37 goose: up to current file version: 313742026/10/01 10:20:37 OK 20241026095416_initial_model.sql (12.15ms)13752026/10/01 10:20:37 OK 20241026095416_initial_model.sql (12.18ms)13762026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)13772026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)13782026/10/01 10:20:37 OK 20251218171726_add_pins.sql (4.65ms)13792026/10/01 10:20:37 OK 20251218171726_add_pins.sql (4.87ms)13802026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)13812026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4ms)13822026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures13832026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.59ms)13842026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.79ms)13852026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (3.09ms)13862026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (3.01ms)13872026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.03ms)13882026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000013892026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.39ms)13902026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000013912026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.18ms)13922026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.67ms)13932026-10-01 10:20:37.048 UTC [541] ERROR: relation "goose_db_version" does not exist at character 3613942026-10-01 10:20:37.048 UTC [541] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13952026/10/01 10:20:37 OK 2_object_stats_trigger.sql (2.29ms)13962026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.52ms)13972026/10/01 10:20:37 OK 3_commit_push.sql (1.2ms)13982026/10/01 10:20:37 goose: up to current file version: 313992026/10/01 10:20:37 OK 3_commit_push.sql (696.43µs)14002026/10/01 10:20:37 goose: up to current file version: 314012026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures14022026-10-01 10:20:37.055 UTC [542] ERROR: relation "goose_db_version" does not exist at character 3614032026-10-01 10:20:37.055 UTC [542] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14042026/10/01 10:20:37 OK 20241026095416_initial_model.sql (10.29ms)14052026-10-01 10:20:37.064 UTC [543] ERROR: relation "goose_db_version" does not exist at character 3614062026-10-01 10:20:37.064 UTC [543] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14072026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)14082026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.42ms)14092026/10/01 10:20:37 OK 20241026095416_initial_model.sql (8.59ms)14102026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)14112026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.32ms)14122026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.07ms)14132026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.39ms)14142026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)14152026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (1.94ms)14162026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.22ms)14172026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000014182026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.53ms)14192026/10/01 10:20:37 OK 20241026095416_initial_model.sql (10.17ms)14202026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)14212026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.05ms)14222026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.13ms)14232026/10/01 10:20:37 OK 2_object_stats_trigger.sql (866.53µs)14242026/10/01 10:20:37 OK 3_commit_push.sql (881.67µs)14252026/10/01 10:20:37 goose: up to current file version: 314262026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (1.76ms)14272026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000014282026/10/01 10:20:37 OK 20251218171726_add_pins.sql (2.89ms)14292026/10/01 10:20:37 OK 1_commit_pending_closure.sql (1.83ms)14302026/10/01 10:20:37 OK 2_object_stats_trigger.sql (684.73µs)14312026/10/01 10:20:37 OK 3_commit_push.sql (544.21µs)14322026/10/01 10:20:37 goose: up to current file version: 314332026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (2.68ms)14342026/10/01 10:20:37 OK 20260905000000_add_claims.sql (2.63ms)14352026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (1.48ms)14362026/10/01 10:20:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14372026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (1.26ms)14382026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000014392026/10/01 10:20:37 OK 1_commit_pending_closure.sql (1.41ms)14402026/10/01 10:20:37 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst14412026/10/01 10:20:37 OK 2_object_stats_trigger.sql (703.43µs)1442--- PASS: TestCompleteMultipartUnregistered (0.50s)1443=== CONT TestIsValidUploadKey14442026/10/01 10:20:37 INFO Aborted multipart uploads count=0 kept=01445=== RUN TestIsValidUploadKey/narinfo1446=== PAUSE TestIsValidUploadKey/narinfo1447=== RUN TestIsValidUploadKey/nar_zst1448=== PAUSE TestIsValidUploadKey/nar_zst1449=== RUN TestIsValidUploadKey/nar_xz1450=== PAUSE TestIsValidUploadKey/nar_xz1451=== RUN TestIsValidUploadKey/nar_plain1452=== PAUSE TestIsValidUploadKey/nar_plain1453=== RUN TestIsValidUploadKey/listing1454=== PAUSE TestIsValidUploadKey/listing1455=== RUN TestIsValidUploadKey/build_log1456=== PAUSE TestIsValidUploadKey/build_log1457=== RUN TestIsValidUploadKey/build_log_home-manager_file1458=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1459=== RUN TestIsValidUploadKey/build_log_plus_in_name1460=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1461=== RUN TestIsValidUploadKey/build_log_question_mark1462=== PAUSE TestIsValidUploadKey/build_log_question_mark1463=== RUN TestIsValidUploadKey/build_log_equals1464=== PAUSE TestIsValidUploadKey/build_log_equals1465=== RUN TestIsValidUploadKey/realisation1466=== PAUSE TestIsValidUploadKey/realisation1467=== RUN TestIsValidUploadKey/realisation_plus_in_output1468=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1469=== RUN TestIsValidUploadKey/nix-cache-info1470=== PAUSE TestIsValidUploadKey/nix-cache-info1471=== RUN TestIsValidUploadKey/index.html1472=== PAUSE TestIsValidUploadKey/index.html1473=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1474=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1475=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1476=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1477=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1478=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1479=== RUN TestIsValidUploadKey/traversal1480=== PAUSE TestIsValidUploadKey/traversal1481=== RUN TestIsValidUploadKey/traversal_nar1482=== PAUSE TestIsValidUploadKey/traversal_nar1483=== RUN TestIsValidUploadKey/absolute1484=== PAUSE TestIsValidUploadKey/absolute1485=== RUN TestIsValidUploadKey/empty_key1486=== PAUSE TestIsValidUploadKey/empty_key14872026/10/01 10:20:37 OK 3_commit_push.sql (1.02ms)1488=== RUN TestIsValidUploadKey/unknown_type14892026/10/01 10:20:37 goose: up to current file version: 31490=== PAUSE TestIsValidUploadKey/unknown_type1491=== CONT TestReadProxy40414922026/10/01 10:20:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14932026/10/01 10:20:37 WARN Force mode enabled - objects will be deleted immediately without grace period14942026/10/01 10:20:37 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=014952026/10/01 10:20:37 INFO Vacuumed table table=pending_closures14962026/10/01 10:20:37 INFO Vacuumed table table=pending_objects14972026/10/01 10:20:37 INFO Vacuumed table table=multipart_uploads14982026/10/01 10:20:37 INFO Vacuumed table table=closures14992026/10/01 10:20:37 INFO Vacuumed table table=objects15002026/10/01 10:20:37 INFO Aborted multipart uploads count=0 kept=015012026/10/01 10:20:37 WARN Force mode enabled - objects will be deleted immediately without grace period15022026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures15032026/10/01 10:20:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MmJmYmM1MzctN2JhYS00MjU0LWFiYzUtNjEwMmViZjI2MGQ2LjRmODY2MmRiLTM4MTMtNDkxNy04NThmLWYxZDY2NDFjNzYzZngxNzkwODUwMDM2NzIwMzM5MDY4 parts=1215042026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures15052026/10/01 10:20:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=015062026/10/01 10:20:37 INFO Vacuumed table table=pending_closures15072026/10/01 10:20:37 INFO Vacuumed table table=pending_objects15082026/10/01 10:20:37 INFO Vacuumed table table=multipart_uploads15092026/10/01 10:20:37 INFO Vacuumed table table=closures15102026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures15112026/10/01 10:20:37 INFO Vacuumed table table=objects1512--- PASS: TestSweepSkipsRowsLockedByPush (0.58s)1513=== CONT TestReadProxyNarStreaming15142026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures15152026-10-01 10:20:37.178 UTC [567] ERROR: relation "goose_db_version" does not exist at character 3615162026-10-01 10:20:37.178 UTC [567] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15172026/10/01 10:20:37 INFO Aborted multipart uploads count=0 kept=01518--- PASS: TestReadRedirectKeepsNarinfoProxied (0.52s)1519=== CONT TestNARDeduplicationMetadataUploadBug15202026/10/01 10:20:37 OK 20241026095416_initial_model.sql (11.14ms)15212026/10/01 10:20:37 WARN Force mode enabled - objects will be deleted immediately without grace period15222026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)15232026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.19ms)15242026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.16ms)15252026/10/01 10:20:37 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15262026/10/01 10:20:37 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."15272026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.18ms)1528--- PASS: TestFailedS3DeleteKeepsTombstone (0.61s)1529=== CONT TestReadProxyNarinfoAlreadyDecompressed15302026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.79ms)15312026-10-01 10:20:37.212 UTC [571] ERROR: relation "goose_db_version" does not exist at character 3615322026-10-01 10:20:37.212 UTC [571] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15332026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.54ms)15342026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000015352026/10/01 10:20:37 OK 1_commit_pending_closure.sql (1.82ms)15362026/10/01 10:20:37 OK 2_object_stats_trigger.sql (806.81µs)15372026/10/01 10:20:37 OK 3_commit_push.sql (1.15ms)15382026/10/01 10:20:37 goose: up to current file version: 31539--- PASS: TestGCBugBareHashReferences (0.95s)1540=== CONT TestOrphanedObjectsGC15412026/10/01 10:20:37 OK 20241026095416_initial_model.sql (11.46ms)15422026/10/01 10:20:37 INFO Aborted multipart uploads count=0 kept=015432026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)1544--- PASS: TestReadRedirectNar (0.48s)1545=== CONT TestReadProxyNarinfo15462026/10/01 10:20:37 WARN Force mode enabled - objects will be deleted immediately without grace period15472026/10/01 10:20:37 OK 20251218171726_add_pins.sql (4.14ms)15482026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.3ms)15492026/10/01 10:20:37 OK 20260905000000_add_claims.sql (4.58ms)15502026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.76ms)15512026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.76ms)15522026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000015532026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures15542026/10/01 10:20:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=015552026/10/01 10:20:37 INFO Vacuumed table table=pending_closures15562026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.66ms)15572026/10/01 10:20:37 INFO Vacuumed table table=pending_objects15582026/10/01 10:20:37 INFO Vacuumed table table=multipart_uploads15592026/10/01 10:20:37 INFO Vacuumed table table=closures15602026/10/01 10:20:37 OK 2_object_stats_trigger.sql (2.74ms)15612026/10/01 10:20:37 OK 3_commit_push.sql (1.23ms)15622026/10/01 10:20:37 goose: up to current file version: 315632026/10/01 10:20:37 INFO Vacuumed table table=objects1564--- PASS: TestGCSweepDeliversEachKeyOnce (0.58s)1565=== CONT TestObjectStatsTrigger1566--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.46s)1567=== CONT TestIsValidCachePath1568=== RUN TestIsValidCachePath/narinfo1569=== PAUSE TestIsValidCachePath/narinfo1570=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1571=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1572=== RUN TestIsValidCachePath/nar_zst1573=== PAUSE TestIsValidCachePath/nar_zst1574=== RUN TestIsValidCachePath/nar_xz1575=== PAUSE TestIsValidCachePath/nar_xz1576=== RUN TestIsValidCachePath/nar_bz21577=== PAUSE TestIsValidCachePath/nar_bz21578=== RUN TestIsValidCachePath/nar_uncompressed1579=== PAUSE TestIsValidCachePath/nar_uncompressed1580=== RUN TestIsValidCachePath/ls1581=== PAUSE TestIsValidCachePath/ls1582=== RUN TestIsValidCachePath/log1583=== PAUSE TestIsValidCachePath/log1584=== RUN TestIsValidCachePath/realisation1585=== PAUSE TestIsValidCachePath/realisation1586=== RUN TestIsValidCachePath/nix-cache-info1587=== PAUSE TestIsValidCachePath/nix-cache-info1588=== RUN TestIsValidCachePath/index.html1589=== PAUSE TestIsValidCachePath/index.html1590=== RUN TestIsValidCachePath/traversal_parent1591=== PAUSE TestIsValidCachePath/traversal_parent1592=== RUN TestIsValidCachePath/traversal_in_middle1593=== PAUSE TestIsValidCachePath/traversal_in_middle1594=== RUN TestIsValidCachePath/invalid_char_e1595=== PAUSE TestIsValidCachePath/invalid_char_e1596=== RUN TestIsValidCachePath/invalid_char_u1597=== PAUSE TestIsValidCachePath/invalid_char_u1598=== RUN TestIsValidCachePath/random_path1599=== PAUSE TestIsValidCachePath/random_path1600=== RUN TestIsValidCachePath/empty1601=== PAUSE TestIsValidCachePath/empty1602=== RUN TestIsValidCachePath/leading_slash1603=== PAUSE TestIsValidCachePath/leading_slash1604=== RUN TestIsValidCachePath/wrong_extension1605=== PAUSE TestIsValidCachePath/wrong_extension1606=== RUN TestIsValidCachePath/short_hash1607=== PAUSE TestIsValidCachePath/short_hash1608=== CONT TestPendingCleanupUsesOneCutoff16092026-10-01 10:20:37.271 UTC [581] ERROR: relation "goose_db_version" does not exist at character 3616102026-10-01 10:20:37.271 UTC [581] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16112026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures16122026/10/01 10:20:37 OK 20241026095416_initial_model.sql (12.26ms)16132026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)1614--- PASS: TestReadProxyDisabled (0.48s)1615=== CONT TestProxyHeadersOnlyTrustedOnSocket16162026/10/01 10:20:37 INFO Aborted multipart uploads count=0 kept=016172026/10/01 10:20:37 OK 20251218171726_add_pins.sql (5.76ms)16182026-10-01 10:20:37.303 UTC [585] ERROR: relation "goose_db_version" does not exist at character 3616192026-10-01 10:20:37.303 UTC [585] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16202026-10-01 10:20:37.303 UTC [586] ERROR: relation "goose_db_version" does not exist at character 3616212026-10-01 10:20:37.303 UTC [586] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16222026/10/01 10:20:37 WARN Force mode enabled - objects will be deleted immediately without grace period16232026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.96ms)16242026/10/01 10:20:37 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=016252026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.47ms)16262026/10/01 10:20:37 INFO Vacuumed table table=pending_closures16272026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (3.07ms)16282026/10/01 10:20:37 INFO Vacuumed table table=pending_objects16292026/10/01 10:20:37 INFO Vacuumed table table=multipart_uploads16302026/10/01 10:20:37 INFO Vacuumed table table=closures16312026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.43ms)16322026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000016332026/10/01 10:20:37 INFO Vacuumed table table=objects16342026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.82ms)16352026/10/01 10:20:37 OK 2_object_stats_trigger.sql (2.05ms)16362026/10/01 10:20:37 OK 20241026095416_initial_model.sql (13.64ms)16372026/10/01 10:20:37 OK 20241026095416_initial_model.sql (12.58ms)16382026/10/01 10:20:37 OK 3_commit_push.sql (1.59ms)16392026/10/01 10:20:37 goose: up to current file version: 316402026-10-01 10:20:37.326 UTC [589] ERROR: relation "goose_db_version" does not exist at character 3616412026-10-01 10:20:37.326 UTC [589] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16422026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)16432026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures16442026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (3.8ms)1645--- PASS: TestGCSweepSkipsPendingObjects (0.51s)1646=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded16472026/10/01 10:20:37 OK 20251218171726_add_pins.sql (5.02ms)16482026/10/01 10:20:37 OK 20251218171726_add_pins.sql (5.09ms)1649--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.46s)1650=== CONT TestParseSingleRange1651=== RUN TestParseSingleRange/none1652=== PAUSE TestParseSingleRange/none1653=== RUN TestParseSingleRange/unknown_unit1654=== PAUSE TestParseSingleRange/unknown_unit1655=== RUN TestParseSingleRange/multi-range_ignored16562026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (6.59ms)1657=== PAUSE TestParseSingleRange/multi-range_ignored1658=== RUN TestParseSingleRange/malformed_no_dash1659=== PAUSE TestParseSingleRange/malformed_no_dash1660=== RUN TestParseSingleRange/malformed_both_empty1661=== PAUSE TestParseSingleRange/malformed_both_empty1662=== RUN TestParseSingleRange/malformed_end_before_start1663=== PAUSE TestParseSingleRange/malformed_end_before_start1664=== RUN TestParseSingleRange/closed1665=== PAUSE TestParseSingleRange/closed1666=== RUN TestParseSingleRange/open-ended1667=== PAUSE TestParseSingleRange/open-ended1668=== RUN TestParseSingleRange/end_clamped_to_size1669=== PAUSE TestParseSingleRange/end_clamped_to_size1670=== RUN TestParseSingleRange/suffix1671=== PAUSE TestParseSingleRange/suffix1672=== RUN TestParseSingleRange/suffix_exceeds_size1673=== PAUSE TestParseSingleRange/suffix_exceeds_size1674=== RUN TestParseSingleRange/single_byte1675=== PAUSE TestParseSingleRange/single_byte1676=== RUN TestParseSingleRange/start_past_EOF1677=== PAUSE TestParseSingleRange/start_past_EOF1678=== RUN TestParseSingleRange/start_far_past_EOF1679=== PAUSE TestParseSingleRange/start_far_past_EOF1680=== CONT TestMultipartCleanup16812026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (6.81ms)16822026/10/01 10:20:37 OK 20260905000000_add_claims.sql (10.98ms)16832026/10/01 10:20:37 OK 20260905000000_add_claims.sql (9.82ms)16842026/10/01 10:20:37 OK 20241026095416_initial_model.sql (15.7ms)16852026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)16862026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (3.97ms)16872026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (3.96ms)16882026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.99ms)16892026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (3.42ms)16902026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000016912026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (3.38ms)16922026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000016932026-10-01 10:20:37.360 UTC [594] ERROR: relation "goose_db_version" does not exist at character 3616942026-10-01 10:20:37.360 UTC [594] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1695--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.49s)1696=== CONT TestPresentNotReportedWhileGCDeletesClosure16972026/10/01 10:20:37 OK 1_commit_pending_closure.sql (3.86ms)16982026/10/01 10:20:37 OK 1_commit_pending_closure.sql (4.91ms)16992026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (6.12ms)17002026/10/01 10:20:37 OK 2_object_stats_trigger.sql (2.31ms)17012026/10/01 10:20:37 OK 2_object_stats_trigger.sql (2.27ms)17022026-10-01 10:20:37.365 UTC [595] ERROR: relation "goose_db_version" does not exist at character 3617032026-10-01 10:20:37.365 UTC [595] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17042026/10/01 10:20:37 OK 3_commit_push.sql (1.98ms)17052026/10/01 10:20:37 goose: up to current file version: 317062026/10/01 10:20:37 OK 3_commit_push.sql (2.14ms)17072026/10/01 10:20:37 goose: up to current file version: 317082026/10/01 10:20:37 OK 20260905000000_add_claims.sql (5.5ms)17092026/10/01 10:20:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17102026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (3.63ms)1711--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.72s)1712=== CONT TestServerTLSConfig1713=== RUN TestServerTLSConfig/no_client_CA1714=== PAUSE TestServerTLSConfig/no_client_CA1715=== RUN TestServerTLSConfig/missing_CA_file1716=== PAUSE TestServerTLSConfig/missing_CA_file1717=== RUN TestServerTLSConfig/not_a_PEM_file1718=== PAUSE TestServerTLSConfig/not_a_PEM_file1719=== CONT TestPresentReportsOnlyClosureRoots17202026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (6.79ms)17212026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000017222026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.75ms)17232026/10/01 10:20:37 OK 20241026095416_initial_model.sql (13.61ms)17242026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.85ms)17252026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)17262026/10/01 10:20:37 OK 3_commit_push.sql (2.05ms)17272026/10/01 10:20:37 goose: up to current file version: 317282026/10/01 10:20:37 OK 20241026095416_initial_model.sql (13.02ms)17292026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)17302026/10/01 10:20:37 OK 20251218171726_add_pins.sql (4.25ms)17312026-10-01 10:20:37.393 UTC [600] ERROR: relation "goose_db_version" does not exist at character 3617322026-10-01 10:20:37.393 UTC [600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17332026/10/01 10:20:37 OK 20251218171726_add_pins.sql (5.17ms)17342026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (5.82ms)17352026/10/01 10:20:37 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MmJmYmM1MzctN2JhYS00MjU0LWFiYzUtNjEwMmViZjI2MGQ2LmFkOTIzMjJiLTc1MGEtNDAyNS05YWJmLTZkYjA1YmZlNzljM3gxNzkwODUwMDM3MDYwNzI1MzI5 parts=1017362026/10/01 10:20:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17372026/10/01 10:20:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17382026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (5.53ms)17392026/10/01 10:20:37 OK 20260905000000_add_claims.sql (5.77ms)17402026/10/01 10:20:37 INFO Completed upload id=117412026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures1742--- PASS: TestReadProxyConditionalGet (0.49s)1743=== CONT TestService_NativeMTLS17442026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.79ms)17452026/10/01 10:20:37 OK 20260905000000_add_claims.sql (4.46ms)17462026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (3.13ms)17472026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (3.76ms)17482026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000017492026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures17502026/10/01 10:20:37 OK 1_commit_pending_closure.sql (3.57ms)17512026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (3.83ms)17522026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000017532026/10/01 10:20:37 OK 2_object_stats_trigger.sql (2.2ms)17542026/10/01 10:20:37 OK 20241026095416_initial_model.sql (14.02ms)17552026/10/01 10:20:37 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17562026/10/01 10:20:37 WARN Found objects in DB but missing from S3, will re-upload count=117572026/10/01 10:20:37 OK 1_commit_pending_closure.sql (3.27ms)1758--- PASS: TestService_verifyS3Integrity (0.98s)1759=== CONT TestCreatePin_ReservedPins17602026/10/01 10:20:37 OK 3_commit_push.sql (7.79ms)17612026/10/01 10:20:37 goose: up to current file version: 317622026/10/01 10:20:37 OK 2_object_stats_trigger.sql (8.38ms)17632026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (8.78ms)17642026/10/01 10:20:37 OK 3_commit_push.sql (2ms)17652026/10/01 10:20:37 goose: up to current file version: 317662026/10/01 10:20:37 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MmJmYmM1MzctN2JhYS00MjU0LWFiYzUtNjEwMmViZjI2MGQ2LjRjNGI4Y2FkLTNkYjItNDEwZS1hYzlhLTNkZTZlMTFhNDBjNXgxNzkwODUwMDM3MDE4OTY1Nzkx parts=1217672026/10/01 10:20:37 OK 20251218171726_add_pins.sql (4.03ms)17682026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures1769--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.17s)1770=== CONT TestMetricsInventory17712026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)17722026-10-01 10:20:37.435 UTC [603] ERROR: relation "goose_db_version" does not exist at character 3617732026-10-01 10:20:37.435 UTC [603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17742026-10-01 10:20:37.436 UTC [604] ERROR: relation "goose_db_version" does not exist at character 3617752026-10-01 10:20:37.436 UTC [604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17762026/10/01 10:20:37 OK 20260905000000_add_claims.sql (4.41ms)17772026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (3.14ms)17782026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (3.24ms)17792026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000017802026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures17812026/10/01 10:20:37 OK 1_commit_pending_closure.sql (3.18ms)17822026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.69ms)1783--- PASS: TestReadProxyHead (0.47s)1784=== CONT TestProxyWriteTimeout1785=== RUN TestProxyWriteTimeout/narinfo1786=== PAUSE TestProxyWriteTimeout/narinfo1787=== RUN TestProxyWriteTimeout/1_GiB_nar1788=== PAUSE TestProxyWriteTimeout/1_GiB_nar1789=== RUN TestProxyWriteTimeout/10_GiB_nar1790=== PAUSE TestProxyWriteTimeout/10_GiB_nar1791=== RUN TestProxyWriteTimeout/unknown_size1792=== PAUSE TestProxyWriteTimeout/unknown_size1793=== CONT TestClientIntegration17942026/10/01 10:20:37 OK 3_commit_push.sql (1.64ms)17952026/10/01 10:20:37 goose: up to current file version: 317962026/10/01 10:20:37 OK 20241026095416_initial_model.sql (10.77ms)17972026-10-01 10:20:37.453 UTC [607] ERROR: relation "goose_db_version" does not exist at character 3617982026-10-01 10:20:37.453 UTC [607] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17992026/10/01 10:20:37 OK 20241026095416_initial_model.sql (11.66ms)18002026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (3.02ms)18012026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)18022026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.38ms)18032026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.98ms)18042026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)18052026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)18062026-10-01 10:20:37.465 UTC [610] ERROR: relation "goose_db_version" does not exist at character 3618072026-10-01 10:20:37.465 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18082026/10/01 10:20:37 OK 20260905000000_add_claims.sql (4.4ms)18092026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.38ms)18102026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.83ms)18112026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.99ms)18122026/10/01 10:20:37 OK 20241026095416_initial_model.sql (11.7ms)18132026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.53ms)18142026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000018152026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.49ms)18162026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000018172026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)18182026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.26ms)18192026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.27ms)18202026/10/01 10:20:37 OK 2_object_stats_trigger.sql (2.22ms)18212026/10/01 10:20:37 OK 2_object_stats_trigger.sql (2.07ms)18222026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.69ms)18232026/10/01 10:20:37 OK 3_commit_push.sql (1.48ms)18242026/10/01 10:20:37 goose: up to current file version: 318252026/10/01 10:20:37 INFO Aborted multipart uploads count=0 kept=018262026/10/01 10:20:37 OK 3_commit_push.sql (2.54ms)18272026/10/01 10:20:37 goose: up to current file version: 318282026/10/01 10:20:37 OK 20241026095416_initial_model.sql (10.1ms)18292026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.42ms)18302026/10/01 10:20:37 WARN Force mode enabled - objects will be deleted immediately without grace period18312026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)18322026-10-01 10:20:37.486 UTC [612] ERROR: relation "goose_db_version" does not exist at character 3618332026-10-01 10:20:37.486 UTC [612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18342026/10/01 10:20:37 OK 20260905000000_add_claims.sql (4.05ms)18352026/10/01 10:20:37 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=018362026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.91ms)18372026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.67ms)18382026/10/01 10:20:37 INFO Vacuumed table table=pending_closures18392026/10/01 10:20:37 INFO Vacuumed table table=pending_objects18402026/10/01 10:20:37 INFO Vacuumed table table=multipart_uploads18412026/10/01 10:20:37 INFO Vacuumed table table=closures18422026/10/01 10:20:37 INFO Vacuumed table table=objects18432026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.38ms)18442026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000018452026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.64ms)18462026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.32ms)1847--- PASS: TestGCMetrics (0.52s)1848=== CONT TestLeadEndsOnShutdown18492026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.74ms)18502026/10/01 10:20:37 OK 20260905000000_add_claims.sql (4.43ms)1851--- PASS: TestReadProxyInvalidPath (0.51s)1852=== CONT TestService_ReadScope_PublicByDefault18532026/10/01 10:20:37 OK 3_commit_push.sql (1.71ms)18542026/10/01 10:20:37 goose: up to current file version: 318552026/10/01 10:20:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18562026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (9.66ms)18572026/10/01 10:20:37 OK 20241026095416_initial_model.sql (14.92ms)18582026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.74ms)18592026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000018602026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)18612026/10/01 10:20:37 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MmJmYmM1MzctN2JhYS00MjU0LWFiYzUtNjEwMmViZjI2MGQ2LjZkMjY0MGVjLWUxZjgtNDJiMy1hMGJhLWFlNThmYTRmMDZmY3gxNzkwODUwMDM3MTMxMzQxNzQ5 error="Get \"http://127.0.0.1:1/bucket11/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"18622026/10/01 10:20:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MmJmYmM1MzctN2JhYS00MjU0LWFiYzUtNjEwMmViZjI2MGQ2Ljc5YmQxNTM3LTI3ZDQtNGY5ZC05ZjE4LTI1NWJiNjg3NzI1M3gxNzkwODUwMDM3MTIzOTc0NDQy parts=1218632026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.85ms)18642026/10/01 10:20:37 INFO Received cleanup request method=DELETE path=/api/pending_closures18652026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.52ms)18662026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.93ms)18672026/10/01 10:20:37 INFO Aborted multipart uploads count=0 kept=018682026/10/01 10:20:37 OK 3_commit_push.sql (1.43ms)18692026/10/01 10:20:37 goose: up to current file version: 318702026/10/01 10:20:37 INFO Aborted multipart uploads count=1 kept=018712026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4ms)18722026-10-01 10:20:37.521 UTC [618] ERROR: relation "goose_db_version" does not exist at character 3618732026-10-01 10:20:37.521 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18742026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.21ms)1875--- PASS: TestRedundantMultipartUpload (1.25s)1876=== CONT TestLeadElectsOneAndHandsOver18772026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.5ms)18782026/10/01 10:20:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018792026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (3.09ms)18802026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000018812026/10/01 10:20:37 INFO Vacuumed table table=pending_closures18822026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.59ms)18832026/10/01 10:20:37 INFO Vacuumed table table=pending_objects18842026/10/01 10:20:37 INFO Vacuumed table table=multipart_uploads18852026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.55ms)18862026/10/01 10:20:37 OK 3_commit_push.sql (1.5ms)18872026/10/01 10:20:37 goose: up to current file version: 318882026/10/01 10:20:37 INFO Vacuumed table table=closures18892026/10/01 10:20:37 INFO Vacuumed table table=objects1890--- PASS: TestPushWaitsForSweepHoldingRow (1.27s)1891=== CONT TestClientErrorHandling1892=== RUN TestClientErrorHandling/InvalidStorePath1893=== PAUSE TestClientErrorHandling/InvalidStorePath1894=== RUN TestClientErrorHandling/InvalidAuthToken1895=== PAUSE TestClientErrorHandling/InvalidAuthToken1896=== RUN TestClientErrorHandling/ServerNotAvailable1897=== PAUSE TestClientErrorHandling/ServerNotAvailable1898=== CONT TestResolveDBConnectionString18992026/10/01 10:20:37 OK 20241026095416_initial_model.sql (10.42ms)1900=== RUN TestResolveDBConnectionString/flag_wins1901=== PAUSE TestResolveDBConnectionString/flag_wins1902=== RUN TestResolveDBConnectionString/file_when_flag_empty1903=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1904=== RUN TestResolveDBConnectionString/missing_file_is_an_error1905=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1906=== RUN TestResolveDBConnectionString/PGHOST_allows_empty19072026-10-01 10:20:37.539 UTC [621] ERROR: relation "goose_db_version" does not exist at character 3619082026-10-01 10:20:37.539 UTC [621] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1909=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1910=== RUN TestResolveDBConnectionString/nothing_configured1911=== PAUSE TestResolveDBConnectionString/nothing_configured1912=== CONT TestClientCADerivations19132026/10/01 10:20:37 INFO Aborted multipart uploads count=0 kept=019142026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)19152026/10/01 10:20:37 WARN Force mode enabled - objects will be deleted immediately without grace period1916--- PASS: TestReadProxy404 (0.45s)1917=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock19182026/10/01 10:20:37 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=019192026/10/01 10:20:37 OK 20251218171726_add_pins.sql (4.37ms)19202026/10/01 10:20:37 INFO Vacuumed table table=pending_closures19212026/10/01 10:20:37 INFO Vacuumed table table=pending_objects19222026/10/01 10:20:37 INFO Vacuumed table table=multipart_uploads19232026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (5.17ms)19242026/10/01 10:20:37 INFO Vacuumed table table=closures1925--- PASS: TestReadProxyNarStreaming (0.42s)1926=== CONT TestCacheStatsHandler19272026/10/01 10:20:37 INFO Vacuumed table table=objects19282026/10/01 10:20:37 OK 20260905000000_add_claims.sql (4.44ms)1929--- PASS: TestPushDedupSurvivesConcurrentGC (0.64s)1930=== CONT TestClientFallsBackToClosures19312026/10/01 10:20:37 OK 20241026095416_initial_model.sql (11.54ms)19322026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.86ms)19332026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.82ms)19342026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (3.22ms)19352026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000019362026/10/01 10:20:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34269/oidc19372026/10/01 10:20:37 OK 1_commit_pending_closure.sql (3.02ms)19382026/10/01 10:20:37 OK 20251218171726_add_pins.sql (4.7ms)19392026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.87ms)19402026/10/01 10:20:37 OK 3_commit_push.sql (2.38ms)19412026/10/01 10:20:37 goose: up to current file version: 319422026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)19432026/10/01 10:20:37 OK 20260905000000_add_claims.sql (8.6ms)19442026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (3.88ms)19452026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.96ms)19462026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000019472026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.57ms)19482026-10-01 10:20:37.591 UTC [633] ERROR: relation "goose_db_version" does not exist at character 3619492026-10-01 10:20:37.591 UTC [633] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19502026-10-01 10:20:37.591 UTC [634] ERROR: relation "goose_db_version" does not exist at character 3619512026-10-01 10:20:37.591 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19522026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.86ms)19532026/10/01 10:20:37 OK 3_commit_push.sql (1.88ms)19542026/10/01 10:20:37 goose: up to current file version: 31955--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.39s)1956=== CONT TestCacheConfigHandler1957=== RUN TestCacheConfigHandler/full_config,_no_issuer1958=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1959=== RUN TestCacheConfigHandler/no_cache_url_configured1960=== PAUSE TestCacheConfigHandler/no_cache_url_configured1961=== RUN TestCacheConfigHandler/no_signing_keys1962=== PAUSE TestCacheConfigHandler/no_signing_keys1963=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1964=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1965=== CONT TestClientPushesUseOnePush19662026/10/01 10:20:37 OK 20241026095416_initial_model.sql (11.53ms)19672026/10/01 10:20:37 OK 20241026095416_initial_model.sql (12.96ms)19682026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2ms)19692026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)19702026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.44ms)19712026-10-01 10:20:37.616 UTC [638] ERROR: relation "goose_db_version" does not exist at character 3619722026-10-01 10:20:37.616 UTC [638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19732026/10/01 10:20:37 OK 20251218171726_add_pins.sql (10.27ms)1974=== NAME TestNARDeduplicationMetadataUploadBug1975 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug299943933/001/store/av28k8idhzrr5k0nl5fdhd33z61z5jn8-file1.txt19762026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (9.38ms)19772026/10/01 10:20:37 OK 20260905000000_add_claims.sql (4.02ms)19782026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)19792026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.7ms)19802026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.84ms)19812026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.46ms)19822026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000019832026-10-01 10:20:37.636 UTC [655] ERROR: relation "goose_db_version" does not exist at character 3619842026-10-01 10:20:37.636 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19852026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.73ms)19862026-10-01 10:20:37.636 UTC [656] ERROR: relation "goose_db_version" does not exist at character 3619872026-10-01 10:20:37.636 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19882026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.5ms)19892026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.37ms)19902026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000019912026/10/01 10:20:37 OK 2_object_stats_trigger.sql (2.13ms)19922026/10/01 10:20:37 OK 20241026095416_initial_model.sql (11.47ms)19932026-10-01 10:20:37.640 UTC [657] ERROR: relation "goose_db_version" does not exist at character 3619942026-10-01 10:20:37.640 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19952026/10/01 10:20:37 OK 3_commit_push.sql (1.63ms)19962026/10/01 10:20:37 goose: up to current file version: 319972026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.63ms)19982026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)19992026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.62ms)20002026/10/01 10:20:37 OK 3_commit_push.sql (1.09ms)20012026/10/01 10:20:37 goose: up to current file version: 320022026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.13ms)20032026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)20042026/10/01 10:20:37 OK 20241026095416_initial_model.sql (10.22ms)20052026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.96ms)20062026/10/01 10:20:37 OK 20241026095416_initial_model.sql (10.15ms)2007--- PASS: TestReadProxyNarinfo (0.42s)2008=== CONT TestPinProtectsFromGC20092026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)20102026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)20112026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.66ms)20122026/10/01 10:20:37 OK 20241026095416_initial_model.sql (9.52ms)20132026-10-01 10:20:37.656 UTC [658] ERROR: relation "goose_db_version" does not exist at character 3620142026-10-01 10:20:37.656 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20152026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)20162026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.41ms)20172026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000020182026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.57ms)20192026/10/01 10:20:37 OK 20251218171726_add_pins.sql (4.27ms)20202026-10-01 10:20:37.660 UTC [666] ERROR: relation "goose_db_version" does not exist at character 3620212026-10-01 10:20:37.660 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20222026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.54ms)20232026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.73ms)20242026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.79ms)20252026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)20262026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)20272026/10/01 10:20:37 OK 3_commit_push.sql (1.77ms)20282026/10/01 10:20:37 goose: up to current file version: 320292026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.39ms)20302026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.99ms)20312026/10/01 10:20:37 OK 20260905000000_add_claims.sql (4.17ms)20322026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.74ms)20332026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.88ms)20342026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.42ms)20352026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.68ms)20362026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (3.01ms)20372026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000020382026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (3.61ms)20392026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000020402026/10/01 10:20:37 OK 20241026095416_initial_model.sql (11.67ms)20412026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.52ms)20422026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000020432026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.71ms)20442026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2ms)20452026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.48ms)20462026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.71ms)20472026/10/01 10:20:37 OK 2_object_stats_trigger.sql (2.06ms)20482026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.72ms)20492026/10/01 10:20:37 OK 20241026095416_initial_model.sql (12.2ms)20502026/10/01 10:20:37 OK 3_commit_push.sql (1.35ms)20512026/10/01 10:20:37 goose: up to current file version: 320522026/10/01 10:20:37 OK 3_commit_push.sql (2.09ms)20532026/10/01 10:20:37 goose: up to current file version: 320542026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.99ms)20552026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.97ms)20562026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)20572026/10/01 10:20:37 OK 3_commit_push.sql (1.33ms)20582026/10/01 10:20:37 goose: up to current file version: 320592026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)20602026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.18ms)20612026-10-01 10:20:37.687 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3620622026-10-01 10:20:37.687 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20632026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.09ms)2064--- PASS: TestObjectStatsTrigger (0.43s)2065=== CONT TestService_ReadAuthMiddleware20662026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.39ms)20672026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.42ms)20682026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.34ms)20692026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.04ms)20702026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000020712026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (1.88ms)20722026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures20732026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.61ms)20742026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (1.65ms)20752026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000020762026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.42ms)20772026/10/01 10:20:37 OK 3_commit_push.sql (1.02ms)20782026/10/01 10:20:37 goose: up to current file version: 320792026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.41ms)20802026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.23ms)20812026/10/01 10:20:37 OK 3_commit_push.sql (1.34ms)20822026/10/01 10:20:37 goose: up to current file version: 320832026/10/01 10:20:37 OK 20241026095416_initial_model.sql (10.6ms)20842026/10/01 10:20:37 INFO Received push request method=POST path=/api/pushes20852026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures20862026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.24ms)20872026/10/01 10:20:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20882026/10/01 10:20:37 INFO Uploading av28k8idhzrr5k0nl5fdhd33z61z5jn8-file1.txt (160B)20892026/10/01 10:20:37 OK 20251218171726_add_pins.sql (10.43ms)20902026/10/01 10:20:37 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"20912026/10/01 10:20:37 WARN Failed to register uploaded object key=av28k8idhzrr5k0nl5fdhd33z61z5jn8.ls error="server returned 404: 404 page not found\n"20922026/10/01 10:20:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20932026/10/01 10:20:37 INFO Signed narinfos id=1 count=120942026/10/01 10:20:37 INFO Uploading 1 narinfos20952026/10/01 10:20:37 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1698851912/001/proxy.sock20962026/10/01 10:20:37 INFO Starting HTTP server address=127.0.0.1:4363720972026/10/01 10:20:37 WARN mTLS auth: subject not in bound subjects subject="CN=someone"20982026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)20992026/10/01 10:20:37 INFO Shutdown signal received, draining in-flight requests timeout=10s21002026/10/01 10:20:37 INFO Received cleanup request method=DELETE path=/api/pending_closures2101--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.42s)2102=== CONT TestClientSharedPathCommittedMidPush21032026/10/01 10:20:37 INFO Received complete push request method=POST path=/api/pushes/1/complete21042026/10/01 10:20:37 WARN Failed to register uploaded object key=av28k8idhzrr5k0nl5fdhd33z61z5jn8.narinfo error="server returned 404: 404 page not found\n"21052026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.38ms)21062026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.38ms)21072026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.33ms)21082026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000021092026-10-01 10:20:37.730 UTC [701] ERROR: relation "goose_db_version" does not exist at character 3621102026-10-01 10:20:37.730 UTC [701] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21112026/10/01 10:20:37 INFO Upload complete. (64ms)21122026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.52ms)2113=== NAME TestNARDeduplicationMetadataUploadBug2114 metadata_upload_test.go:54: Retrieved narinfo from S3:2115 StorePath: /build/TestNARDeduplicationMetadataUploadBug299943933/001/store/av28k8idhzrr5k0nl5fdhd33z61z5jn8-file1.txt2116 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2117 Compression: zstd2118 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2119 NarSize: 1602120 References: 2121 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf21222026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.2ms)21232026/10/01 10:20:37 OK 3_commit_push.sql (1.49ms)21242026/10/01 10:20:37 goose: up to current file version: 32125 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2126 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2127 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}21282026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures21292026/10/01 10:20:37 OK 20241026095416_initial_model.sql (10.14ms)21302026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)21312026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.5ms)21322026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)21332026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.72ms)2134--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.43s)2135=== CONT TestService_RequireScope_OIDC21362026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.47ms)21372026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures21382026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.25ms)21392026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000021402026-10-01 10:20:37.766 UTC [704] ERROR: relation "goose_db_version" does not exist at character 3621412026-10-01 10:20:37.766 UTC [704] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21422026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.25ms)21432026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.3ms)21442026/10/01 10:20:37 OK 3_commit_push.sql (1.24ms)21452026/10/01 10:20:37 goose: up to current file version: 32146=== NAME TestNARDeduplicationMetadataUploadBug2147 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug299943933/001/store/ifhyd706z8iw4dp0i2f88pm1n7cpdjy3-file2.txt21482026/10/01 10:20:37 OK 20241026095416_initial_model.sql (11.1ms)21492026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)21502026/10/01 10:20:37 OK 20251218171726_add_pins.sql (3.12ms)21512026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.35ms)21522026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.27ms)21532026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.13ms)21542026-10-01 10:20:37.799 UTC [730] ERROR: relation "goose_db_version" does not exist at character 3621552026-10-01 10:20:37.799 UTC [730] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21562026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (1.67ms)21572026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000021582026/10/01 10:20:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38683/oidc21592026/10/01 10:20:37 OK 1_commit_pending_closure.sql (1.59ms)21602026/10/01 10:20:37 OK 2_object_stats_trigger.sql (802.01µs)21612026/10/01 10:20:37 OK 3_commit_push.sql (1.05ms)21622026/10/01 10:20:37 goose: up to current file version: 321632026/10/01 10:20:37 OK 20241026095416_initial_model.sql (9.17ms)21642026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)21652026/10/01 10:20:37 OK 20251218171726_add_pins.sql (2.67ms)2166--- PASS: TestPresentReportsOnlyClosureRoots (0.44s)2167=== CONT TestClientWithDependencies21682026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (3.69ms)21692026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.11ms)21702026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.38ms)21712026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.28ms)21722026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000021732026/10/01 10:20:37 WARN mTLS auth: subject not in bound subjects subject="CN=reader"21742026/10/01 10:20:37 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2175--- PASS: TestService_NativeMTLS (0.43s)2176=== CONT TestService_AuthMiddleware_OIDC21772026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.83ms)21782026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.31ms)21792026/10/01 10:20:37 OK 3_commit_push.sql (1.51ms)21802026/10/01 10:20:37 goose: up to current file version: 321812026/10/01 10:20:37 INFO Received push request method=POST path=/api/pushes21822026/10/01 10:20:37 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21832026/10/01 10:20:37 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21842026/10/01 10:20:37 WARN Failed to register uploaded object key=ifhyd706z8iw4dp0i2f88pm1n7cpdjy3.ls error="server returned 404: 404 page not found\n"21852026/10/01 10:20:37 INFO Signed narinfos id=2 count=121862026/10/01 10:20:37 INFO Uploading 1 narinfos21872026/10/01 10:20:37 INFO Received complete push request method=POST path=/api/pushes/2/complete21882026/10/01 10:20:37 WARN Failed to register uploaded object key=ifhyd706z8iw4dp0i2f88pm1n7cpdjy3.narinfo error="server returned 404: 404 page not found\n"21892026/10/01 10:20:37 INFO Upload complete. (55ms)2190=== NAME TestNARDeduplicationMetadataUploadBug2191 metadata_upload_test.go:76: Retrieved narinfo from S3:2192 StorePath: /build/TestNARDeduplicationMetadataUploadBug299943933/001/store/ifhyd706z8iw4dp0i2f88pm1n7cpdjy3-file2.txt2193 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2194 Compression: zstd2195 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2196 NarSize: 1602197 References: 2198 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2199 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2200 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2201 {"version":1,"root":{"type":"regular","size":44}}2202--- PASS: TestNARDeduplicationMetadataUploadBug (0.67s)2203=== CONT TestClientMultipleUploads22042026-10-01 10:20:37.875 UTC [772] ERROR: relation "goose_db_version" does not exist at character 3622052026-10-01 10:20:37.875 UTC [772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22062026/10/01 10:20:37 INFO Received cleanup request method=DELETE path=/api/pending_closures2207--- PASS: TestMetricsInventory (0.45s)2208=== CONT TestService_AuthMiddleware_MTLSBoundSubjects22092026/10/01 10:20:37 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket55/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""22102026/10/01 10:20:37 INFO Aborted multipart uploads count=0 kept=122112026/10/01 10:20:37 INFO Received cleanup request method=DELETE path=/api/pending_closures22122026/10/01 10:20:37 INFO Aborted multipart uploads count=1 kept=02213--- PASS: TestMultipartCleanup (0.55s)2214=== CONT TestService_healthCheckHandler22152026/10/01 10:20:37 OK 20241026095416_initial_model.sql (10.78ms)22162026-10-01 10:20:37.895 UTC [777] ERROR: relation "goose_db_version" does not exist at character 3622172026-10-01 10:20:37.895 UTC [777] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22182026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)22192026/10/01 10:20:37 OK 20251218171726_add_pins.sql (4.6ms)2220--- PASS: TestService_ReadScope_PublicByDefault (0.41s)2221=== CONT TestService_createPendingClosureHandler22222026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.98ms)22232026/10/01 10:20:37 OK 20260905000000_add_claims.sql (4.31ms)22242026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (3.47ms)22252026/10/01 10:20:37 OK 20241026095416_initial_model.sql (12.78ms)22262026/10/01 10:20:37 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)22272026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (3.01ms)22282026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000022292026/10/01 10:20:37 OK 1_commit_pending_closure.sql (3.51ms)2230=== NAME TestClientIntegration2231 client_integration_test.go:286: Created store path: /build/TestClientIntegration553277555/002/store/gr0z7cp55d44jjxa1fa6inr0gyqy52fl-test-file.txt22322026/10/01 10:20:37 OK 20251218171726_add_pins.sql (4.73ms)22332026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.83ms)22342026/10/01 10:20:37 OK 3_commit_push.sql (1.67ms)22352026/10/01 10:20:37 goose: up to current file version: 322362026/10/01 10:20:37 OK 20260628120000_add_object_size_and_stats.sql (4.56ms)22372026/10/01 10:20:37 INFO lead: acquired remote=192.0.2.1:123422382026/10/01 10:20:37 INFO lead: released remote=192.0.2.1:12342239--- PASS: TestLeadEndsOnShutdown (0.43s)2240=== CONT TestCreatePendingClosureRejectsOversizedNAR22412026/10/01 10:20:37 INFO Received uploads request method=POST path=/api/pending_closures2242--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)2243=== CONT TestService_readinessHandler22442026/10/01 10:20:37 OK 20260905000000_add_claims.sql (3.45ms)22452026/10/01 10:20:37 OK 20260920000000_drop_claims.sql (2.4ms)22462026/10/01 10:20:37 OK 20260923120000_add_pushes.sql (2.74ms)22472026/10/01 10:20:37 goose: successfully migrated database to version: 2026092312000022482026/10/01 10:20:37 OK 1_commit_pending_closure.sql (2.33ms)22492026/10/01 10:20:37 OK 2_object_stats_trigger.sql (1.58ms)22502026-10-01 10:20:37.947 UTC [801] ERROR: relation "goose_db_version" does not exist at character 3622512026-10-01 10:20:37.947 UTC [801] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22522026/10/01 10:20:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37299/oidc22532026/10/01 10:20:38 OK 3_commit_push.sql (301.11ms)22542026/10/01 10:20:38 goose: up to current file version: 322552026/10/01 10:20:38 INFO lead: acquired remote=192.0.2.1:12342256=== NAME TestOrphanedObjectsGC2257 orphaned_objects_gc_test.go:290: GC Test Summary:2258 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2259 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2260 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2261 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2262 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2263--- PASS: TestOrphanedObjectsGC (1.03s)2264=== CONT TestGenerateLandingPage2265--- PASS: TestGenerateLandingPage (0.00s)2266=== CONT TestGCTaskStore_Fail2267--- PASS: TestGCTaskStore_Fail (0.00s)2268=== CONT TestCacheConfigHandlerMaxNarSize2269--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)2270=== CONT TestGracefulShutdownDrainsInflight22712026/10/01 10:20:38 INFO Starting HTTP server address=127.0.0.1:3658522722026/10/01 10:20:38 INFO Shutdown signal received, draining in-flight requests timeout=10s22732026-10-01 10:20:38.257 UTC [823] ERROR: relation "goose_db_version" does not exist at character 3622742026-10-01 10:20:38.257 UTC [823] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22752026/10/01 10:20:38 OK 20241026095416_initial_model.sql (30.88ms)22762026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)22772026/10/01 10:20:38 OK 20251218171726_add_pins.sql (4.46ms)22782026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes22792026-10-01 10:20:38.287 UTC [841] ERROR: relation "goose_db_version" does not exist at character 3622802026-10-01 10:20:38.287 UTC [841] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22812026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)22822026-10-01 10:20:38.289 UTC [842] ERROR: relation "goose_db_version" does not exist at character 3622832026-10-01 10:20:38.289 UTC [842] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22842026/10/01 10:20:38 OK 20241026095416_initial_model.sql (11.89ms)22852026/10/01 10:20:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22862026/10/01 10:20:38 INFO Uploading gr0z7cp55d44jjxa1fa6inr0gyqy52fl-test-file.txt (152B)22872026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (2.24ms)22882026/10/01 10:20:38 OK 20260905000000_add_claims.sql (4.47ms)2289--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.93s)2290=== CONT TestService_AuthMiddleware_MTLSProxyHeader22912026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"22922026/10/01 10:20:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22932026/10/01 10:20:38 WARN Failed to register uploaded object key=gr0z7cp55d44jjxa1fa6inr0gyqy52fl.ls error="server returned 404: 404 page not found\n"22942026/10/01 10:20:38 OK 20251218171726_add_pins.sql (4.21ms)22952026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (3.51ms)22962026/10/01 10:20:38 INFO Signed narinfos id=1 count=122972026/10/01 10:20:38 INFO Uploading 1 narinfos22982026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (4.26ms)22992026/10/01 10:20:38 goose: successfully migrated database to version: 2026092312000023002026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (5.44ms)23012026/10/01 10:20:38 INFO Received complete push request method=POST path=/api/pushes/1/complete23022026/10/01 10:20:38 WARN Failed to register uploaded object key=gr0z7cp55d44jjxa1fa6inr0gyqy52fl.narinfo error="server returned 404: 404 page not found\n"23032026/10/01 10:20:38 OK 20241026095416_initial_model.sql (10.15ms)23042026/10/01 10:20:38 OK 1_commit_pending_closure.sql (2.68ms)23052026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)23062026/10/01 10:20:38 OK 2_object_stats_trigger.sql (2.27ms)23072026/10/01 10:20:38 OK 20260905000000_add_claims.sql (4.43ms)23082026/10/01 10:20:38 OK 3_commit_push.sql (1.64ms)23092026/10/01 10:20:38 goose: up to current file version: 323102026/10/01 10:20:38 OK 20241026095416_initial_model.sql (12.56ms)23112026/10/01 10:20:38 INFO Upload complete. (64ms)23122026/10/01 10:20:38 OK 20251218171726_add_pins.sql (3.25ms)23132026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (3.15ms)23142026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)23152026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (2.81ms)23162026/10/01 10:20:38 goose: successfully migrated database to version: 2026092312000023172026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)23182026/10/01 10:20:38 OK 20251218171726_add_pins.sql (4.06ms)23192026/10/01 10:20:38 OK 1_commit_pending_closure.sql (2.71ms)23202026/10/01 10:20:38 OK 2_object_stats_trigger.sql (1.49ms)23212026/10/01 10:20:38 OK 20260905000000_add_claims.sql (3.5ms)23222026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)23232026/10/01 10:20:38 OK 3_commit_push.sql (1.83ms)23242026/10/01 10:20:38 goose: up to current file version: 323252026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (3.13ms)23262026/10/01 10:20:38 OK 20260905000000_add_claims.sql (4.14ms)23272026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (2.63ms)23282026/10/01 10:20:38 goose: successfully migrated database to version: 202609231200002329--- PASS: TestGracefulShutdownDrainsInflight (0.07s)2330=== CONT TestGCTaskStore_PhaseUpdates2331--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)2332=== CONT TestGCTaskStore_CompletedAllowsNewTask2333--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)2334=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info23352026/10/01 10:20:38 INFO Received uploads request method=POST path=/2336=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23372026/10/01 10:20:38 INFO Received complete multipart upload request method=POST path=/2338=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23392026/10/01 10:20:38 INFO Received request for more parts method=POST path=/2340=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23412026/10/01 10:20:38 INFO Received uploads request method=POST path=/2342--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)2343 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2344 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2345 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2346 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2347=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts23482026/10/01 10:20:38 INFO Received request for more parts method=POST path=/23492026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (2.98ms)23502026/10/01 10:20:38 OK 1_commit_pending_closure.sql (2.33ms)23512026-10-01 10:20:38.327 UTC [847] ERROR: relation "goose_db_version" does not exist at character 3623522026-10-01 10:20:38.327 UTC [847] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23532026/10/01 10:20:38 OK 2_object_stats_trigger.sql (2ms)23542026-10-01 10:20:38.328 UTC [848] ERROR: relation "goose_db_version" does not exist at character 3623552026-10-01 10:20:38.328 UTC [848] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23562026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (2.77ms)23572026/10/01 10:20:38 goose: successfully migrated database to version: 2026092312000023582026/10/01 10:20:38 OK 3_commit_push.sql (1.91ms)23592026/10/01 10:20:38 goose: up to current file version: 323602026/10/01 10:20:38 OK 1_commit_pending_closure.sql (2.25ms)23612026/10/01 10:20:38 OK 2_object_stats_trigger.sql (1.55ms)23622026/10/01 10:20:38 OK 3_commit_push.sql (1.56ms)23632026/10/01 10:20:38 goose: up to current file version: 323642026/10/01 10:20:38 OK 20241026095416_initial_model.sql (12.44ms)23652026/10/01 10:20:38 OK 20241026095416_initial_model.sql (14.16ms)23662026/10/01 10:20:38 INFO All 1 paths already cached2367=== NAME TestClientIntegration2368 client_integration_test.go:312: Retrieved narinfo from S3:2369 StorePath: /build/TestClientIntegration553277555/002/store/gr0z7cp55d44jjxa1fa6inr0gyqy52fl-test-file.txt2370 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2371 Compression: zstd2372 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12373 NarSize: 1522374 References: 2375 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk123762026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)23772026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)2378 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2379 client_integration_test.go:313: Decompressed .ls content (64 bytes):2380 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2381 client_integration_test.go:316: Testing garbage collection...23822026/10/01 10:20:38 OK 20251218171726_add_pins.sql (3.21ms)23832026/10/01 10:20:38 OK 20251218171726_add_pins.sql (3.3ms)2384--- PASS: TestCacheStatsHandler (0.80s)2385=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart23862026/10/01 10:20:38 INFO Received complete multipart upload request method=POST path=/23872026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (3.58ms)23882026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)23892026/10/01 10:20:38 OK 20260905000000_add_claims.sql (2.99ms)23902026/10/01 10:20:38 OK 20260905000000_add_claims.sql (3.04ms)23912026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (2.22ms)23922026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (2.18ms)23932026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (1.72ms)23942026/10/01 10:20:38 goose: successfully migrated database to version: 2026092312000023952026-10-01 10:20:38.364 UTC [884] ERROR: relation "goose_db_version" does not exist at character 3623962026-10-01 10:20:38.364 UTC [884] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23972026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (1.95ms)23982026/10/01 10:20:38 goose: successfully migrated database to version: 2026092312000023992026/10/01 10:20:38 OK 1_commit_pending_closure.sql (2.04ms)24002026/10/01 10:20:38 OK 1_commit_pending_closure.sql (1.82ms)24012026/10/01 10:20:38 OK 2_object_stats_trigger.sql (1.08ms)24022026/10/01 10:20:38 OK 2_object_stats_trigger.sql (907.67µs)24032026/10/01 10:20:38 OK 3_commit_push.sql (808.97µs)24042026/10/01 10:20:38 goose: up to current file version: 324052026/10/01 10:20:38 OK 3_commit_push.sql (634.25µs)24062026/10/01 10:20:38 goose: up to current file version: 324072026/10/01 10:20:38 OK 20241026095416_initial_model.sql (9.97ms)24082026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)24092026/10/01 10:20:38 OK 20251218171726_add_pins.sql (3.17ms)2410=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure24112026/10/01 10:20:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures24122026/10/01 10:20:38 INFO Received uploads request method=POST path=/24132026/10/01 10:20:38 INFO Garbage collection started24142026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (3.29ms)24152026/10/01 10:20:38 OK 20260905000000_add_claims.sql (2.9ms)24162026/10/01 10:20:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux24172026/10/01 10:20:38 WARN Refused reserved pin name=worker-x86_64-linux24182026/10/01 10:20:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux24192026/10/01 10:20:38 INFO Received create pin request method=POST path=/api/pins/my-app24202026/10/01 10:20:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2421=== NAME TestClientCADerivations2422 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations835328218/001/store/7pfbvlx9f8lz8f4d9gyj9i7vmh1chrri-ca-test2423--- PASS: TestCreatePin_ReservedPins (0.98s)2424=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows24252026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (2.34ms)24262026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (1.75ms)24272026/10/01 10:20:38 goose: successfully migrated database to version: 2026092312000024282026/10/01 10:20:38 INFO Aborted multipart uploads count=0 kept=024292026/10/01 10:20:38 OK 1_commit_pending_closure.sql (1.62ms)24302026/10/01 10:20:38 OK 2_object_stats_trigger.sql (596.05µs)24312026/10/01 10:20:38 OK 3_commit_push.sql (532.01µs)24322026/10/01 10:20:38 goose: up to current file version: 324332026/10/01 10:20:38 INFO lead: released remote=192.0.2.1:123424342026/10/01 10:20:38 WARN Force mode enabled - objects will be deleted immediately without grace period2435=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check24362026/10/01 10:20:38 INFO lead: acquired remote=192.0.2.1:123424372026/10/01 10:20:38 INFO lead: released remote=192.0.2.1:12342438--- PASS: TestLeadElectsOneAndHandsOver (0.93s)2439=== CONT TestPush_RejectsBadRequests/no_roots24402026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes2441=== CONT TestPush_RejectsBadRequests/bad_root24422026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes2443=== CONT TestPush_RejectsBadRequests/no_objects24442026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes2445=== CONT TestPush_RejectsBadRequests/root_not_in_objects24462026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes2447=== CONT TestIsValidUploadKey/narinfo2448=== CONT TestIsValidUploadKey/empty_key2449=== CONT TestIsValidUploadKey/unknown_type2450=== CONT TestIsValidUploadKey/absolute2451=== CONT TestIsValidUploadKey/traversal_nar2452=== CONT TestIsValidUploadKey/traversal2453=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2454=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2455--- PASS: TestPush_RejectsBadRequests (0.42s)2456 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2457 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2458 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2459 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2460=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2461=== CONT TestIsValidUploadKey/index.html2462=== CONT TestIsValidUploadKey/build_log_home-manager_file2463=== CONT TestIsValidUploadKey/build_log2464=== CONT TestIsValidUploadKey/listing2465=== CONT TestIsValidUploadKey/nar_plain2466=== CONT TestIsValidUploadKey/nar_xz2467=== CONT TestIsValidUploadKey/build_log_plus_in_name2468=== CONT TestIsValidUploadKey/nar_zst2469=== CONT TestIsValidUploadKey/nix-cache-info2470=== CONT TestIsValidUploadKey/realisation_plus_in_output2471=== CONT TestIsValidUploadKey/build_log_equals2472=== CONT TestIsValidUploadKey/realisation2473=== CONT TestIsValidUploadKey/build_log_question_mark2474=== CONT TestIsValidCachePath/narinfo2475=== CONT TestIsValidCachePath/index.html2476=== CONT TestIsValidCachePath/short_hash2477=== CONT TestIsValidCachePath/wrong_extension2478=== CONT TestIsValidCachePath/leading_slash2479=== CONT TestIsValidCachePath/empty2480=== CONT TestIsValidCachePath/random_path2481--- PASS: TestIsValidUploadKey (0.00s)2482 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2483 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2484 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2485 --- PASS: TestIsValidUploadKey/absolute (0.00s)2486 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2487 --- PASS: TestIsValidUploadKey/traversal (0.00s)2488 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2489 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2490 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2491 --- PASS: TestIsValidUploadKey/index.html (0.00s)2492 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2493 --- PASS: TestIsValidUploadKey/build_log (0.00s)2494 --- PASS: TestIsValidUploadKey/listing (0.00s)2495 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2496 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2497 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2498 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2499 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2500 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2501 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2502 --- PASS: TestIsValidUploadKey/realisation (0.00s)2503 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2504=== CONT TestIsValidCachePath/invalid_char_u2505=== CONT TestIsValidCachePath/invalid_char_e2506=== CONT TestIsValidCachePath/traversal_in_middle2507=== CONT TestIsValidCachePath/traversal_parent2508=== CONT TestIsValidCachePath/nar_uncompressed2509=== CONT TestIsValidCachePath/realisation2510=== CONT TestIsValidCachePath/log2511=== CONT TestIsValidCachePath/nix-cache-info2512=== CONT TestIsValidCachePath/ls2513=== CONT TestIsValidCachePath/nar_xz2514=== CONT TestIsValidCachePath/nar_zst2515=== CONT TestIsValidCachePath/nar_bz22516=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2517=== CONT TestParseSingleRange/none2518=== CONT TestParseSingleRange/open-ended2519=== CONT TestParseSingleRange/start_far_past_EOF2520=== CONT TestParseSingleRange/start_past_EOF2521=== CONT TestParseSingleRange/single_byte2522=== CONT TestParseSingleRange/suffix_exceeds_size2523=== CONT TestParseSingleRange/suffix2524=== CONT TestParseSingleRange/end_clamped_to_size2525=== CONT TestParseSingleRange/malformed_both_empty2526=== CONT TestParseSingleRange/closed2527=== CONT TestParseSingleRange/malformed_end_before_start2528=== CONT TestParseSingleRange/multi-range_ignored2529=== CONT TestParseSingleRange/malformed_no_dash2530--- PASS: TestIsValidCachePath (0.00s)2531 --- PASS: TestIsValidCachePath/narinfo (0.00s)2532 --- PASS: TestIsValidCachePath/index.html (0.00s)2533 --- PASS: TestIsValidCachePath/short_hash (0.00s)2534 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2535 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2536 --- PASS: TestIsValidCachePath/empty (0.00s)2537 --- PASS: TestIsValidCachePath/random_path (0.00s)2538 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2539 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2540 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2541 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2542 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2543 --- PASS: TestIsValidCachePath/realisation (0.00s)2544 --- PASS: TestIsValidCachePath/log (0.00s)2545 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2546 --- PASS: TestIsValidCachePath/ls (0.00s)2547 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2548 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2549 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2550 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2551=== CONT TestParseSingleRange/unknown_unit2552=== CONT TestServerTLSConfig/no_client_CA2553=== CONT TestServerTLSConfig/not_a_PEM_file2554--- PASS: TestParseSingleRange (0.00s)2555 --- PASS: TestParseSingleRange/none (0.00s)2556 --- PASS: TestParseSingleRange/open-ended (0.00s)2557 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2558 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2559 --- PASS: TestParseSingleRange/single_byte (0.00s)2560 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2561 --- PASS: TestParseSingleRange/suffix (0.00s)2562 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2563 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2564 --- PASS: TestParseSingleRange/closed (0.00s)2565 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2566 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2567 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2568 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2569=== CONT TestServerTLSConfig/missing_CA_file2570=== CONT TestProxyWriteTimeout/narinfo2571=== CONT TestProxyWriteTimeout/10_GiB_nar2572=== CONT TestProxyWriteTimeout/1_GiB_nar2573=== CONT TestProxyWriteTimeout/unknown_size2574=== CONT TestClientErrorHandling/InvalidStorePath2575--- PASS: TestServerTLSConfig (0.00s)2576 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2577 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2578 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2579--- PASS: TestProxyWriteTimeout (0.00s)2580 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2581 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2582 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2583 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2584=== NAME TestClientCADerivations2585 client_ca_test.go:139: Found 1 dependencies (including self)25862026/10/01 10:20:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=025872026/10/01 10:20:38 INFO Vacuumed table table=pending_closures25882026/10/01 10:20:38 INFO Vacuumed table table=pending_objects25892026/10/01 10:20:38 INFO Vacuumed table table=multipart_uploads25902026-10-01 10:20:38.492 UTC [996] ERROR: relation "goose_db_version" does not exist at character 3625912026-10-01 10:20:38.492 UTC [996] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25922026/10/01 10:20:38 INFO Vacuumed table table=closures25932026/10/01 10:20:38 INFO Vacuumed table table=objects25942026/10/01 10:20:38 OK 20241026095416_initial_model.sql (13.4ms)25952026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)2596--- PASS: TestService_ReadAuthMiddleware (0.83s)2597=== CONT TestClientErrorHandling/ServerNotAvailable25982026/10/01 10:20:38 OK 20251218171726_add_pins.sql (4.04ms)25992026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)26002026/10/01 10:20:38 OK 20260905000000_add_claims.sql (4.91ms)26012026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (3.38ms)26022026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (2.65ms)26032026/10/01 10:20:38 goose: successfully migrated database to version: 2026092312000026042026/10/01 10:20:38 OK 1_commit_pending_closure.sql (2.32ms)26052026/10/01 10:20:38 OK 2_object_stats_trigger.sql (1.52ms)26062026/10/01 10:20:38 OK 3_commit_push.sql (1.64ms)26072026/10/01 10:20:38 goose: up to current file version: 326082026-10-01 10:20:38.566 UTC [1140] ERROR: relation "goose_db_version" does not exist at character 3626092026-10-01 10:20:38.566 UTC [1140] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26102026-10-01 10:20:38.567 UTC [1141] ERROR: relation "goose_db_version" does not exist at character 3626112026-10-01 10:20:38.567 UTC [1141] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2612=== NAME TestPinProtectsFromGC2613 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC350676805/001/store/azp1h6af8kmqdfv8lk4kcyggj8l3dzsa-pinned-file.txt2614 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC350676805/001/store/xhgx8gic7zqapkdpliwg6rjhf2c3s3g5-unpinned-file.txt2615=== RUN TestService_RequireScope_OIDC/builder_may_write2616=== PAUSE TestService_RequireScope_OIDC/builder_may_write2617=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2618=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2619=== RUN TestService_RequireScope_OIDC/ops_may_admin2620=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2621=== RUN TestService_RequireScope_OIDC/ops_may_not_write2622=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2623=== RUN TestService_RequireScope_OIDC/reader_may_not_write2624=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2625=== RUN TestService_RequireScope_OIDC/static_token_may_admin2626=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2627=== RUN TestService_RequireScope_OIDC/static_token_may_write2628=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2629=== RUN TestService_RequireScope_OIDC/reader_may_read2630=== PAUSE TestService_RequireScope_OIDC/reader_may_read2631=== RUN TestService_RequireScope_OIDC/writer_implies_read2632=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2633=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2634=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2635=== CONT TestClientErrorHandling/InvalidAuthToken26362026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes26372026/10/01 10:20:38 OK 20241026095416_initial_model.sql (10.46ms)26382026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)26392026/10/01 10:20:38 OK 20241026095416_initial_model.sql (11.27ms)26402026/10/01 10:20:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26412026/10/01 10:20:38 INFO Uploading 7pfbvlx9f8lz8f4d9gyj9i7vmh1chrri-ca-test (144B)26422026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)26432026/10/01 10:20:38 OK 20251218171726_add_pins.sql (2.98ms)26442026/10/01 10:20:38 OK 20251218171726_add_pins.sql (4.06ms)26452026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)26462026/10/01 10:20:38 WARN Failed to register uploaded object key=7pfbvlx9f8lz8f4d9gyj9i7vmh1chrri.ls error="server returned 404: 404 page not found\n"26472026/10/01 10:20:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26482026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"26492026/10/01 10:20:38 WARN Failed to register uploaded object key=log/64ny0pj3kq0rqxf65bsf852lq9vaxi4h-ca-test.drv error="server returned 404: 404 page not found\n"26502026/10/01 10:20:38 INFO Received uploads request method=POST path=/api/pending_closures26512026/10/01 10:20:38 INFO Signed narinfos id=1 count=126522026/10/01 10:20:38 INFO Uploading 1 narinfos26532026/10/01 10:20:38 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26542026/10/01 10:20:38 INFO Received complete push request method=POST path=/api/pushes/1/complete26552026/10/01 10:20:38 WARN Failed to register uploaded object key=7pfbvlx9f8lz8f4d9gyj9i7vmh1chrri.narinfo error="server returned 404: 404 page not found\n"26562026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (6.82ms)26572026/10/01 10:20:38 OK 20260905000000_add_claims.sql (6.94ms)26582026/10/01 10:20:38 INFO Received uploads request method=POST path=/api/pending_closures26592026/10/01 10:20:38 OK 20260905000000_add_claims.sql (3.73ms)26602026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (2.94ms)26612026/10/01 10:20:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)26622026/10/01 10:20:38 INFO Uploading p022rx1r1lxyr5yxyhx7d1y4xr4qh7i4-shared-dep (136B)26632026/10/01 10:20:38 INFO Uploading j2fln2p4189jdq6p17qw3843h356rqaa-b (216B)26642026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (2.3ms)26652026/10/01 10:20:38 INFO Upload complete. (98ms)26662026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (3ms)26672026/10/01 10:20:38 goose: successfully migrated database to version: 2026092312000026682026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (2.08ms)26692026/10/01 10:20:38 goose: successfully migrated database to version: 2026092312000026702026/10/01 10:20:38 OK 1_commit_pending_closure.sql (2.48ms)2671=== NAME TestClientCADerivations2672 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations835328218/001/store/7pfbvlx9f8lz8f4d9gyj9i7vmh1chrri-ca-test26732026/10/01 10:20:38 WARN Failed to register uploaded object key=aj96sd82hz5i2id0m6b7xvbdvydhrq4r.ls error="server returned 404: 404 page not found\n"2674 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2675 Compression: zstd2676 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2677 NarSize: 1442678 References: 2679 Deriver: /build/TestClientCADerivations835328218/001/store/64ny0pj3kq0rqxf65bsf852lq9vaxi4h-ca-test.drv2680 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2681 client_ca_test.go:185: Checking for realisation files in S3...26822026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"26832026/10/01 10:20:38 OK 1_commit_pending_closure.sql (2.41ms)26842026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/0afb8w4ivhi8d106ab8lr299nbqcz79zydbh09gh9swvpabsfv1j.nar.zst error="server returned 404: 404 page not found\n"26852026/10/01 10:20:38 WARN Failed to register uploaded object key=p022rx1r1lxyr5yxyhx7d1y4xr4qh7i4.ls error="server returned 404: 404 page not found\n"26862026/10/01 10:20:38 OK 2_object_stats_trigger.sql (1.66ms)2687 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2688 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache26892026/10/01 10:20:38 OK 3_commit_push.sql (1.21ms)26902026/10/01 10:20:38 goose: up to current file version: 326912026/10/01 10:20:38 OK 2_object_stats_trigger.sql (1.68ms)26922026/10/01 10:20:38 OK 3_commit_push.sql (1.25ms)26932026/10/01 10:20:38 goose: up to current file version: 326942026/10/01 10:20:38 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"26952026/10/01 10:20:38 WARN mTLS auth: bound subjects configured but subject DN unavailable26962026/10/01 10:20:38 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2697--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.75s)2698=== CONT TestResolveDBConnectionString/flag_wins2699=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2700=== CONT TestResolveDBConnectionString/nothing_configured2701=== CONT TestResolveDBConnectionString/missing_file_is_an_error2702=== CONT TestResolveDBConnectionString/file_when_flag_empty2703=== CONT TestCacheConfigHandler/full_config,_no_issuer2704=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2705=== CONT TestCacheConfigHandler/no_signing_keys2706=== CONT TestCacheConfigHandler/no_cache_url_configured2707--- PASS: TestResolveDBConnectionString (0.00s)2708 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2709 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2710 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2711 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2712 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2713=== CONT TestService_RequireScope_OIDC/builder_may_write2714--- PASS: TestCacheConfigHandler (0.00s)2715 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2716 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2717 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2718 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2719=== CONT TestService_RequireScope_OIDC/static_token_may_admin2720=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2721=== CONT TestService_RequireScope_OIDC/writer_implies_read2722=== CONT TestService_RequireScope_OIDC/reader_may_read2723=== CONT TestService_RequireScope_OIDC/static_token_may_write2724=== CONT TestService_RequireScope_OIDC/reader_may_not_write2725=== CONT TestService_RequireScope_OIDC/ops_may_admin2726=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2727=== CONT TestService_RequireScope_OIDC/ops_may_not_write2728--- PASS: TestService_RequireScope_OIDC (0.82s)2729 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2730 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2731 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2732 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2733 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2734 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2735 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2736 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2737 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2738 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)27392026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes27402026/10/01 10:20:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)27412026/10/01 10:20:38 INFO Uploading qmm33xrqsq0kf2jr441346wqgnwd3nhs-shared-dep (136B)27422026/10/01 10:20:38 INFO Uploading 83k6f3x6krnwffmrn310iifax30fhhv2-b (208B)2743=== NAME TestClientMultipleUploads2744 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1542041229/001/store/wcyns87wvsabzj2mvxvjh4l974mgg345-test-file-0.txt27452026-10-01 10:20:38.649 UTC [1341] ERROR: relation "goose_db_version" does not exist at character 3627462026-10-01 10:20:38.649 UTC [1341] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27472026/10/01 10:20:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign27482026/10/01 10:20:38 WARN Failed to register uploaded object key=j2fln2p4189jdq6p17qw3843h356rqaa.ls error="server returned 404: 404 page not found\n"27492026/10/01 10:20:38 WARN Failed to register uploaded object key=4770c6m55l0f9zkm6jb9m6a09lly25gs.ls error="server returned 404: 404 page not found\n"27502026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/15m92q8wgp4ihiinggy4kvkv2l1cqmgn9rnc6d96qnxjl2mjqvci.nar.zst error="server returned 404: 404 page not found\n"27512026/10/01 10:20:38 WARN Failed to register uploaded object key=83k6f3x6krnwffmrn310iifax30fhhv2.ls error="server returned 404: 404 page not found\n"27522026/10/01 10:20:38 WARN Failed to register uploaded object key=qmm33xrqsq0kf2jr441346wqgnwd3nhs.ls error="server returned 404: 404 page not found\n"27532026/10/01 10:20:38 INFO Signed narinfos id=1 count=227542026/10/01 10:20:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign27552026/10/01 10:20:38 INFO Signed narinfos id=2 count=227562026/10/01 10:20:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27572026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"27582026/10/01 10:20:38 INFO Uploading 4 narinfos27592026/10/01 10:20:38 INFO Signed narinfos id=1 count=327602026/10/01 10:20:38 INFO Uploading 3 narinfos27612026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes27622026/10/01 10:20:38 WARN Failed to register uploaded object key=p022rx1r1lxyr5yxyhx7d1y4xr4qh7i4.narinfo error="server returned 404: 404 page not found\n"27632026/10/01 10:20:38 INFO Received uploads request method=POST path=/api/pending_closures27642026/10/01 10:20:38 WARN Failed to register uploaded object key=j2fln2p4189jdq6p17qw3843h356rqaa.narinfo error="server returned 404: 404 page not found\n"27652026/10/01 10:20:38 INFO Received uploads request method=POST path=/api/pending_closures27662026/10/01 10:20:38 WARN Failed to register uploaded object key=aj96sd82hz5i2id0m6b7xvbdvydhrq4r.narinfo error="server returned 404: 404 page not found\n"27672026/10/01 10:20:38 INFO Received uploads request method=POST path=/api/pending_closures27682026/10/01 10:20:38 WARN Failed to register uploaded object key=83k6f3x6krnwffmrn310iifax30fhhv2.narinfo error="server returned 404: 404 page not found\n"27692026/10/01 10:20:38 WARN Failed to register uploaded object key=qmm33xrqsq0kf2jr441346wqgnwd3nhs.narinfo error="server returned 404: 404 page not found\n"27702026/10/01 10:20:38 INFO Received complete push request method=POST path=/api/pushes/1/complete27712026/10/01 10:20:38 WARN Failed to register uploaded object key=4770c6m55l0f9zkm6jb9m6a09lly25gs.narinfo error="server returned 404: 404 page not found\n"27722026/10/01 10:20:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete27732026/10/01 10:20:38 WARN Failed to register uploaded object key=p022rx1r1lxyr5yxyhx7d1y4xr4qh7i4.narinfo error="server returned 404: 404 page not found\n"27742026/10/01 10:20:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)27752026/10/01 10:20:38 INFO Uploading azp1h6af8kmqdfv8lk4kcyggj8l3dzsa-pinned-file.txt (128B)27762026/10/01 10:20:38 OK 20241026095416_initial_model.sql (9.39ms)27772026/10/01 10:20:38 INFO Completed upload id=227782026/10/01 10:20:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete27792026/10/01 10:20:38 WARN Failed to register uploaded object key=azp1h6af8kmqdfv8lk4kcyggj8l3dzsa.ls error="server returned 404: 404 page not found\n"27802026/10/01 10:20:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27812026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"27822026/10/01 10:20:38 INFO Signed narinfos id=1 count=127832026/10/01 10:20:38 INFO Upload complete. (74ms)27842026/10/01 10:20:38 INFO Uploading 1 narinfos27852026/10/01 10:20:38 OK 20251210153512_drop_unused_gin_index.sql (3.62ms)27862026/10/01 10:20:38 INFO Completed upload id=127872026/10/01 10:20:38 INFO Upload complete. (110ms)2788=== NAME TestClientPushesUseOnePush2789 client_pushes_test.go:97: Retrieved narinfo from S3:2790 StorePath: /build/TestClientPushesUseOnePush222895752/001/store/qmm33xrqsq0kf2jr441346wqgnwd3nhs-shared-dep2791 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2792 Compression: zstd2793 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822794 NarSize: 1362795 References: 2796 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2797=== NAME TestClientFallsBackToClosures2798 client_pushes_test.go:112: Retrieved narinfo from S3:2799 StorePath: /build/TestClientFallsBackToClosures1004853005/001/store/p022rx1r1lxyr5yxyhx7d1y4xr4qh7i4-shared-dep2800 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2801 Compression: zstd2802 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822803 NarSize: 1362804 References: 2805 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n28062026/10/01 10:20:38 INFO Received complete push request method=POST path=/api/pushes/1/complete28072026/10/01 10:20:38 WARN Failed to register uploaded object key=azp1h6af8kmqdfv8lk4kcyggj8l3dzsa.narinfo error="server returned 404: 404 page not found\n"28082026/10/01 10:20:38 OK 20251218171726_add_pins.sql (4.46ms)2809=== NAME TestClientPushesUseOnePush2810 client_pushes_test.go:97: Retrieved narinfo from S3:2811 StorePath: /build/TestClientPushesUseOnePush222895752/001/store/4770c6m55l0f9zkm6jb9m6a09lly25gs-a2812 URL: nar/15m92q8wgp4ihiinggy4kvkv2l1cqmgn9rnc6d96qnxjl2mjqvci.nar.zst2813 Compression: zstd2814 NarHash: sha256:15m92q8wgp4ihiinggy4kvkv2l1cqmgn9rnc6d96qnxjl2mjqvci2815 NarSize: 2082816 References: /build/TestClientPushesUseOnePush222895752/001/store/qmm33xrqsq0kf2jr441346wqgnwd3nhs-shared-dep2817 CA: text:sha256:1sva5n1akf1jggc7z26c7iqjg1gcqczmjp6xkxrddyr3nrddvgh02818=== NAME TestClientFallsBackToClosures2819 client_pushes_test.go:112: Retrieved narinfo from S3:2820 StorePath: /build/TestClientFallsBackToClosures1004853005/001/store/aj96sd82hz5i2id0m6b7xvbdvydhrq4r-a2821 URL: nar/0afb8w4ivhi8d106ab8lr299nbqcz79zydbh09gh9swvpabsfv1j.nar.zst2822 Compression: zstd2823 NarHash: sha256:0afb8w4ivhi8d106ab8lr299nbqcz79zydbh09gh9swvpabsfv1j2824 NarSize: 2162825 References: /build/TestClientFallsBackToClosures1004853005/001/store/p022rx1r1lxyr5yxyhx7d1y4xr4qh7i4-shared-dep2826 CA: text:sha256:13xavcrv6051arr1b53z4mfgzp6k1qhp4w1339g91m25vs18v0a52827=== NAME TestClientPushesUseOnePush2828 client_pushes_test.go:97: Retrieved narinfo from S3:2829 StorePath: /build/TestClientPushesUseOnePush222895752/001/store/83k6f3x6krnwffmrn310iifax30fhhv2-b2830 URL: nar/15m92q8wgp4ihiinggy4kvkv2l1cqmgn9rnc6d96qnxjl2mjqvci.nar.zst2831 Compression: zstd2832 NarHash: sha256:15m92q8wgp4ihiinggy4kvkv2l1cqmgn9rnc6d96qnxjl2mjqvci2833 NarSize: 2082834 References: /build/TestClientPushesUseOnePush222895752/001/store/qmm33xrqsq0kf2jr441346wqgnwd3nhs-shared-dep2835 CA: text:sha256:1sva5n1akf1jggc7z26c7iqjg1gcqczmjp6xkxrddyr3nrddvgh02836=== NAME TestClientFallsBackToClosures2837 client_pushes_test.go:112: Retrieved narinfo from S3:2838 StorePath: /build/TestClientFallsBackToClosures1004853005/001/store/j2fln2p4189jdq6p17qw3843h356rqaa-b2839 URL: nar/0afb8w4ivhi8d106ab8lr299nbqcz79zydbh09gh9swvpabsfv1j.nar.zst2840 Compression: zstd2841 NarHash: sha256:0afb8w4ivhi8d106ab8lr299nbqcz79zydbh09gh9swvpabsfv1j2842 NarSize: 2162843 References: /build/TestClientFallsBackToClosures1004853005/001/store/p022rx1r1lxyr5yxyhx7d1y4xr4qh7i4-shared-dep2844 CA: text:sha256:13xavcrv6051arr1b53z4mfgzp6k1qhp4w1339g91m25vs18v0a528452026/10/01 10:20:38 OK 20260628120000_add_object_size_and_stats.sql (5.77ms)28462026/10/01 10:20:38 INFO Upload complete. (63ms)2847--- PASS: TestClientPushesUseOnePush (1.08s)2848--- PASS: TestClientFallsBackToClosures (1.12s)28492026/10/01 10:20:38 OK 20260905000000_add_claims.sql (3.77ms)28502026/10/01 10:20:38 OK 20260920000000_drop_claims.sql (2.97ms)2851--- PASS: TestService_healthCheckHandler (0.79s)28522026/10/01 10:20:38 OK 20260923120000_add_pushes.sql (2.13ms)28532026/10/01 10:20:38 goose: successfully migrated database to version: 202609231200002854=== NAME TestClientMultipleUploads2855 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1542041229/001/store/af96w8wsgjv18jkcax24n7caiwp86nl5-test-file-1.txt2856=== NAME TestClientWithDependencies2857 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1033274644/001/store/mj3n8lcmyzmnxx05m5am25bynx6w580n-test-script28582026/10/01 10:20:38 OK 1_commit_pending_closure.sql (2.68ms)28592026/10/01 10:20:38 OK 2_object_stats_trigger.sql (1.43ms)28602026/10/01 10:20:38 OK 3_commit_push.sql (1.19ms)28612026/10/01 10:20:38 goose: up to current file version: 328622026/10/01 10:20:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.759383ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28632026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes28642026/10/01 10:20:38 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)28652026/10/01 10:20:38 INFO Uploading 7iga1kmwi4xscdahn50zz9rgz1ah831d-top (224B)28662026/10/01 10:20:38 INFO Uploading ssrh3ws0smbr4hbh074pgc47gghsadh7-shared-dep (136B)28672026/10/01 10:20:38 WARN readiness check failed error="closed pool"2868--- PASS: TestService_readinessHandler (0.78s)28692026/10/01 10:20:38 WARN Failed to register uploaded object key=7iga1kmwi4xscdahn50zz9rgz1ah831d.ls error="server returned 404: 404 page not found\n"28702026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"28712026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/06i7q7zzy10x95wsxj2k2hfd4p7716rk5igc1qvzrikx46a9wmlq.nar.zst error="server returned 404: 404 page not found\n"28722026/10/01 10:20:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28732026/10/01 10:20:38 WARN Failed to register uploaded object key=ssrh3ws0smbr4hbh074pgc47gghsadh7.ls error="server returned 404: 404 page not found\n"28742026/10/01 10:20:38 INFO Signed narinfos id=1 count=228752026/10/01 10:20:38 INFO Uploading 2 narinfos28762026/10/01 10:20:38 INFO Received complete push request method=POST path=/api/pushes/1/complete28772026/10/01 10:20:38 WARN Failed to register uploaded object key=ssrh3ws0smbr4hbh074pgc47gghsadh7.narinfo error="server returned 404: 404 page not found\n"28782026/10/01 10:20:38 WARN Failed to register uploaded object key=7iga1kmwi4xscdahn50zz9rgz1ah831d.narinfo error="server returned 404: 404 page not found\n"2879=== NAME TestClientWithDependencies2880 client_integration_test.go:615: Found 1 dependencies (including self)2881=== NAME TestClientCADerivations2882 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2883 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2884 error: binary cache 's3://bucket64?endpoint=http://localhost:40513®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations835328218/001/store'2885 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12886--- PASS: TestClientCADerivations (1.19s)28872026/10/01 10:20:38 INFO Upload complete. (73ms)2888=== NAME TestClientSharedPathCommittedMidPush2889 client_integration_test.go:680: Retrieved narinfo from S3:2890 StorePath: /build/TestClientSharedPathCommittedMidPush888788584/001/store/ssrh3ws0smbr4hbh074pgc47gghsadh7-shared-dep2891 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2892 Compression: zstd2893 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822894 NarSize: 1362895 References: 2896 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2897=== NAME TestClientMultipleUploads2898 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1542041229/001/store/bsgbyiqf8hb5mh4vw5y108h17klqyzg4-test-file-2.txt2899=== NAME TestClientSharedPathCommittedMidPush2900 client_integration_test.go:680: Retrieved narinfo from S3:2901 StorePath: /build/TestClientSharedPathCommittedMidPush888788584/001/store/7iga1kmwi4xscdahn50zz9rgz1ah831d-top2902 URL: nar/06i7q7zzy10x95wsxj2k2hfd4p7716rk5igc1qvzrikx46a9wmlq.nar.zst2903 Compression: zstd2904 NarHash: sha256:06i7q7zzy10x95wsxj2k2hfd4p7716rk5igc1qvzrikx46a9wmlq2905 NarSize: 2242906 References: /build/TestClientSharedPathCommittedMidPush888788584/001/store/ssrh3ws0smbr4hbh074pgc47gghsadh7-shared-dep2907 CA: text:sha256:0y8wz5ki8brglpn56kc9fhqgwx357gn05k3z1pzvvy3vp9phlmg22908--- PASS: TestClientSharedPathCommittedMidPush (1.02s)2909=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2910=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2911=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2912=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2913=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2914=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2915=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2916=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2917=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2918=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected29192026/10/01 10:20:38 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]2920=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2921=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected29222026/10/01 10:20:38 WARN Authentication failed token_preview=eyJhbGciOi...5qPpODOlHQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2923--- PASS: TestService_AuthMiddleware_OIDC (0.91s)2924 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2925 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2926 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2927 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)29282026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes29292026/10/01 10:20:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)29302026/10/01 10:20:38 INFO Uploading xhgx8gic7zqapkdpliwg6rjhf2c3s3g5-unpinned-file.txt (128B)29312026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"29322026/10/01 10:20:38 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign29332026/10/01 10:20:38 WARN Failed to register uploaded object key=xhgx8gic7zqapkdpliwg6rjhf2c3s3g5.ls error="server returned 404: 404 page not found\n"29342026/10/01 10:20:38 INFO Signed narinfos id=2 count=129352026/10/01 10:20:38 INFO Uploading 1 narinfos2936--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.47s)29372026/10/01 10:20:38 INFO Received complete push request method=POST path=/api/pushes/2/complete29382026/10/01 10:20:38 WARN Failed to register uploaded object key=xhgx8gic7zqapkdpliwg6rjhf2c3s3g5.narinfo error="server returned 404: 404 page not found\n"29392026/10/01 10:20:38 INFO Upload complete. (53ms)29402026/10/01 10:20:38 INFO Received uploads request method=POST path=/api/pending_closures29412026/10/01 10:20:38 INFO Aborted multipart uploads count=0 kept=029422026/10/01 10:20:38 WARN Force mode enabled - objects will be deleted immediately without grace period29432026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes2944--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.26s)29452026/10/01 10:20:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures29462026/10/01 10:20:38 INFO Garbage collection started29472026/10/01 10:20:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)29482026/10/01 10:20:38 INFO Uploading mj3n8lcmyzmnxx05m5am25bynx6w580n-test-script (136B)29492026/10/01 10:20:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=029502026/10/01 10:20:38 INFO Vacuumed table table=pending_closures29512026/10/01 10:20:38 INFO Vacuumed table table=pending_objects29522026/10/01 10:20:38 WARN Failed to register uploaded object key=log/6m7c2x6z23q4dc4s1yhqcwcb5nq429m1-test-script.drv error="server returned 404: 404 page not found\n"29532026/10/01 10:20:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign29542026/10/01 10:20:38 INFO Vacuumed table table=multipart_uploads29552026/10/01 10:20:38 WARN Failed to register uploaded object key=mj3n8lcmyzmnxx05m5am25bynx6w580n.ls error="server returned 404: 404 page not found\n"29562026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"29572026/10/01 10:20:38 INFO Vacuumed table table=closures29582026/10/01 10:20:38 INFO Signed narinfos id=1 count=129592026/10/01 10:20:38 INFO Uploading 1 narinfos29602026/10/01 10:20:38 INFO Vacuumed table table=objects29612026/10/01 10:20:38 INFO Received complete push request method=POST path=/api/pushes/1/complete29622026/10/01 10:20:38 WARN Failed to register uploaded object key=mj3n8lcmyzmnxx05m5am25bynx6w580n.narinfo error="server returned 404: 404 page not found\n"29632026/10/01 10:20:38 INFO Received push request method=POST path=/api/pushes29642026/10/01 10:20:38 INFO Aborted multipart uploads count=0 kept=029652026/10/01 10:20:38 WARN Force mode enabled - objects will be deleted immediately without grace period29662026/10/01 10:20:38 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)29672026/10/01 10:20:38 INFO Uploading af96w8wsgjv18jkcax24n7caiwp86nl5-test-file-1.txt (160B)29682026/10/01 10:20:38 INFO Uploading bsgbyiqf8hb5mh4vw5y108h17klqyzg4-test-file-2.txt (160B)29692026/10/01 10:20:38 INFO Uploading wcyns87wvsabzj2mvxvjh4l974mgg345-test-file-0.txt (160B)29702026/10/01 10:20:38 INFO Upload complete. (63ms)29712026/10/01 10:20:38 WARN Failed to register uploaded object key=af96w8wsgjv18jkcax24n7caiwp86nl5.ls error="server returned 404: 404 page not found\n"29722026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"29732026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"2974=== NAME TestClientWithDependencies2975 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1033274644/001/store) requires matching store prefix29762026/10/01 10:20:38 WARN Failed to register uploaded object key=wcyns87wvsabzj2mvxvjh4l974mgg345.ls error="server returned 404: 404 page not found\n"29772026/10/01 10:20:38 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"29782026/10/01 10:20:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign29792026/10/01 10:20:38 WARN Failed to register uploaded object key=bsgbyiqf8hb5mh4vw5y108h17klqyzg4.ls error="server returned 404: 404 page not found\n"29802026/10/01 10:20:38 INFO Signed narinfos id=1 count=329812026/10/01 10:20:38 INFO Uploading 3 narinfos2982--- PASS: TestClientWithDependencies (1.01s)29832026/10/01 10:20:38 INFO Received uploads request method=POST path=/api/pending_closures29842026/10/01 10:20:38 WARN Failed to register uploaded object key=wcyns87wvsabzj2mvxvjh4l974mgg345.narinfo error="server returned 404: 404 page not found\n"29852026/10/01 10:20:38 INFO Received complete push request method=POST path=/api/pushes/1/complete29862026/10/01 10:20:38 WARN Failed to register uploaded object key=af96w8wsgjv18jkcax24n7caiwp86nl5.narinfo error="server returned 404: 404 page not found\n"29872026/10/01 10:20:38 WARN Failed to register uploaded object key=bsgbyiqf8hb5mh4vw5y108h17klqyzg4.narinfo error="server returned 404: 404 page not found\n"29882026/10/01 10:20:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=029892026/10/01 10:20:38 INFO Vacuumed table table=pending_closures29902026/10/01 10:20:38 INFO Upload complete. (61ms)2991=== NAME TestClientMultipleUploads2992 client_integration_test.go:369: Uploaded 3 paths in 101.312557ms29932026/10/01 10:20:38 INFO Vacuumed table table=pending_objects29942026/10/01 10:20:38 INFO Vacuumed table table=multipart_uploads29952026/10/01 10:20:38 INFO Aborted multipart uploads count=0 kept=029962026/10/01 10:20:38 INFO Vacuumed table table=closures29972026/10/01 10:20:38 INFO Vacuumed table table=objects29982026/10/01 10:20:38 WARN Force mode enabled - objects will be deleted immediately without grace period2999--- PASS: TestClientMultipleUploads (0.98s)30002026/10/01 10:20:38 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=030012026/10/01 10:20:38 INFO Vacuumed table table=pending_closures30022026/10/01 10:20:38 INFO Vacuumed table table=pending_objects30032026/10/01 10:20:38 INFO Vacuumed table table=multipart_uploads30042026/10/01 10:20:38 INFO Vacuumed table table=closures30052026/10/01 10:20:38 INFO Vacuumed table table=objects3006--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)3007 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.44s)3008 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.46s)30092026/10/01 10:20:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.979041ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30102026/10/01 10:20:38 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30112026/10/01 10:20:38 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"30122026/10/01 10:20:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete30132026/10/01 10:20:38 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MmJmYmM1MzctN2JhYS00MjU0LWFiYzUtNjEwMmViZjI2MGQ2LjE1ZTkyMzc4LWE1NWUtNGUyNi1hNjlmLTYyN2ExMGE1YWMwMngxNzkwODUwMDM4NjYyMzAwNzI4 parts=1030142026/10/01 10:20:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete30152026/10/01 10:20:38 INFO Completed upload id=130162026/10/01 10:20:38 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000030172026/10/01 10:20:38 INFO Received uploads request method=POST path=/api/pending_closures30182026/10/01 10:20:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures30192026/10/01 10:20:39 INFO Aborted multipart uploads count=0 kept=030202026/10/01 10:20:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=030212026/10/01 10:20:39 INFO Vacuumed table table=pending_closures30222026/10/01 10:20:39 INFO Vacuumed table table=pending_objects30232026/10/01 10:20:39 INFO Vacuumed table table=multipart_uploads30242026/10/01 10:20:39 INFO Vacuumed table table=closures30252026/10/01 10:20:39 INFO Vacuumed table table=objects30262026/10/01 10:20:39 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000003027--- PASS: TestService_createPendingClosureHandler (1.14s)3028=== NAME TestOrphanedObjectsGCStressTest3029 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains3030 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion3031--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)3032 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)3033 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)3034 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.83s)30352026/10/01 10:20:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=854.302442ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present3036=== NAME TestOrphanedObjectsGCStressTest3037 orphaned_objects_gc_test.go:509: Stress test completed successfully:3038 orphaned_objects_gc_test.go:510: - Active objects preserved: 203039 orphaned_objects_gc_test.go:511: - Objects deleted: 2103040 orphaned_objects_gc_test.go:512: - Total GC'd: 2103041--- PASS: TestOrphanedObjectsGCStressTest (2.68s)30422026/10/01 10:20:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.749509955s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present30432026/10/01 10:20:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=03044=== NAME TestClientIntegration3045 client_integration_test.go:323: Objects in database after GC:3046 client_integration_test.go:323: Successfully deleted all objects with GC --force3047--- PASS: TestClientIntegration (2.94s)30482026/10/01 10:20:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=030492026/10/01 10:20:40 INFO Received create pin request method=POST path=/api/pins/myapp30502026/10/01 10:20:40 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC350676805/001/store/azp1h6af8kmqdfv8lk4kcyggj8l3dzsa-pinned-file.txt narinfo_key=azp1h6af8kmqdfv8lk4kcyggj8l3dzsa.narinfo30512026/10/01 10:20:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures30522026/10/01 10:20:40 INFO Garbage collection started30532026/10/01 10:20:40 INFO Aborted multipart uploads count=0 kept=030542026/10/01 10:20:40 WARN Force mode enabled - objects will be deleted immediately without grace period30552026/10/01 10:20:40 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=030562026/10/01 10:20:40 INFO Vacuumed table table=pending_closures30572026/10/01 10:20:40 INFO Vacuumed table table=pending_objects30582026/10/01 10:20:40 INFO Vacuumed table table=multipart_uploads30592026/10/01 10:20:40 INFO Vacuumed table table=closures30602026/10/01 10:20:40 INFO Vacuumed table table=objects30612026/10/01 10:20:41 WARN Rate limiter enabled after throttle name=s3-test rate=530622026/10/01 10:20:41 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."3063=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle3064 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=103065 throttle_test.go:215: Rate limiter: enabled=true, rate=5.003066--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.09s)30672026/10/01 10:20:41 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30682026/10/01 10:20:42 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.863613ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30692026/10/01 10:20:42 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.70325ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30702026/10/01 10:20:42 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=813.258081ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config3071=== NAME TestPinProtectsFromGC3072 client_integration_test.go:840: Pin successfully protected closure from garbage collection3073--- PASS: TestPinProtectsFromGC (5.17s)30742026/10/01 10:20:43 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.541250146s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30752026/10/01 10:20:43 INFO Aborted multipart uploads count=1 kept=030762026/10/01 10:20:43 INFO Received cleanup request method=DELETE path=/api/pending_closures30772026/10/01 10:20:43 INFO Aborted multipart uploads count=1 kept=03078--- PASS: TestPendingCleanupUsesOneCutoff (6.47s)30792026/10/01 10:20:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"30802026/10/01 10:20:44 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30812026/10/01 10:20:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.274203ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30822026/10/01 10:20:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.863037ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30832026/10/01 10:20:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=734.323054ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30842026/10/01 10:20:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.512656873s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config30852026/10/01 10:20:47 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30862026/10/01 10:20:47 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.445186ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30872026/10/01 10:20:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=365.45211ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30882026/10/01 10:20:48 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=754.835858ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures30892026/10/01 10:20:49 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.657892104s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures3090--- PASS: TestClientErrorHandling (0.00s)3091 --- PASS: TestClientErrorHandling/InvalidStorePath (0.38s)3092 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.37s)3093 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.48s)3094PASS3095{"timestamp":"2026-10-01T10:20:50.998861723Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:46334","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(198)"}30962026-10-01 10:20:51.212 UTC [129] LOG: received smart shutdown request30972026-10-01 10:20:51.216 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 130982026-10-01 10:20:51.228 UTC [134] LOG: shutting down30992026-10-01 10:20:51.228 UTC [134] LOG: checkpoint starting: shutdown immediate31002026-10-01 10:20:51.696 UTC [134] LOG: checkpoint complete: wrote 10494 buffers (64.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 24 recycled; write=0.187 s, sync=0.259 s, total=0.468 s; sync files=28648, longest=0.004 s, average=0.001 s; distance=396539 kB, estimate=396539 kB; lsn=0/19AA4A28, redo lsn=0/19AA4A2831012026-10-01 10:20:51.769 UTC [129] LOG: database system is shut down3102Running OIDC tests...3103=== RUN TestAudienceForIssuer3104=== PAUSE TestAudienceForIssuer3105=== RUN TestGlobMatch3106=== PAUSE TestGlobMatch3107=== RUN TestValidateToken_ValidToken3108=== PAUSE TestValidateToken_ValidToken3109=== RUN TestValidateToken_WrongAudience3110=== PAUSE TestValidateToken_WrongAudience3111=== RUN TestValidateToken_Expired3112=== PAUSE TestValidateToken_Expired3113=== RUN TestValidateToken_BoundClaimsMismatch3114=== PAUSE TestValidateToken_BoundClaimsMismatch3115=== RUN TestValidateToken_BoundSubjectMismatch3116=== PAUSE TestValidateToken_BoundSubjectMismatch3117=== RUN TestValidateToken_MultipleProviders3118=== PAUSE TestValidateToken_MultipleProviders3119=== RUN TestValidateToken_NoMatchingProvider3120=== PAUSE TestValidateToken_NoMatchingProvider3121=== RUN TestValidateToken_KubernetesServiceAccount3122=== PAUSE TestValidateToken_KubernetesServiceAccount3123=== RUN TestNewValidator_KubernetesRequiresCA3124=== PAUSE TestNewValidator_KubernetesRequiresCA3125=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3126=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3127=== RUN TestPins_ReservedForMatchingRule3128=== PAUSE TestPins_ReservedForMatchingRule3129=== RUN TestPins_TopLevelShorthand3130=== PAUSE TestPins_TopLevelShorthand3131=== RUN TestPins_ConfigValidation3132=== PAUSE TestPins_ConfigValidation3133=== RUN TestScopes_LegacyProviderDefaultsToWrite3134=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3135=== RUN TestScopes_Rules3136=== PAUSE TestScopes_Rules3137=== RUN TestScopes_ConfigValidation3138=== PAUSE TestScopes_ConfigValidation3139=== CONT TestAudienceForIssuer3140=== CONT TestValidateToken_BoundClaimsMismatch3141=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3142=== CONT TestValidateToken_KubernetesServiceAccount3143--- PASS: TestAudienceForIssuer (0.00s)3144=== CONT TestValidateToken_WrongAudience3145=== CONT TestValidateToken_Expired3146=== CONT TestGlobMatch3147=== RUN TestGlobMatch/foo_foo3148=== PAUSE TestGlobMatch/foo_foo3149=== RUN TestGlobMatch/foo_bar3150=== PAUSE TestGlobMatch/foo_bar3151=== RUN TestGlobMatch/*_3152=== PAUSE TestGlobMatch/*_3153=== RUN TestGlobMatch/*_anything3154=== PAUSE TestGlobMatch/*_anything3155=== RUN TestGlobMatch/foo*_foo3156=== PAUSE TestGlobMatch/foo*_foo3157=== RUN TestGlobMatch/foo*_foobar3158=== PAUSE TestGlobMatch/foo*_foobar3159=== RUN TestGlobMatch/foo*_bar3160=== PAUSE TestGlobMatch/foo*_bar3161=== RUN TestGlobMatch/*bar_bar3162=== PAUSE TestGlobMatch/*bar_bar3163=== CONT TestValidateToken_ValidToken3164=== CONT TestValidateToken_NoMatchingProvider3165=== CONT TestScopes_Rules3166=== CONT TestScopes_ConfigValidation3167=== CONT TestValidateToken_BoundSubjectMismatch3168=== CONT TestScopes_LegacyProviderDefaultsToWrite3169=== CONT TestPins_ReservedForMatchingRule3170=== CONT TestPins_TopLevelShorthand3171=== CONT TestNewValidator_KubernetesRequiresCA3172=== CONT TestPins_ConfigValidation3173=== CONT TestValidateToken_MultipleProviders3174=== RUN TestGlobMatch/*bar_foobar3175=== PAUSE TestGlobMatch/*bar_foobar3176=== RUN TestGlobMatch/*bar_foo3177=== PAUSE TestGlobMatch/*bar_foo3178=== RUN TestGlobMatch/foo*bar_foobar3179=== PAUSE TestGlobMatch/foo*bar_foobar3180=== RUN TestGlobMatch/foo*bar_foo123bar3181=== PAUSE TestGlobMatch/foo*bar_foo123bar3182=== RUN TestGlobMatch/foo*bar_foobarbaz3183=== PAUSE TestGlobMatch/foo*bar_foobarbaz3184=== RUN TestGlobMatch/*/*_foo/bar3185--- PASS: TestScopes_ConfigValidation (0.00s)3186=== PAUSE TestGlobMatch/*/*_foo/bar3187=== RUN TestGlobMatch/*/*_foo3188=== PAUSE TestGlobMatch/*/*_foo3189=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3190=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3191=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03192=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03193=== RUN TestGlobMatch/refs/*/main_refs/heads/main3194=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3195=== RUN TestGlobMatch/fo?_foo3196=== PAUSE TestGlobMatch/fo?_foo3197=== RUN TestGlobMatch/fo?_fo3198=== PAUSE TestGlobMatch/fo?_fo3199=== RUN TestGlobMatch/fo?_fooo3200=== PAUSE TestGlobMatch/fo?_fooo3201=== RUN TestGlobMatch/?oo_foo3202=== PAUSE TestGlobMatch/?oo_foo3203=== RUN TestGlobMatch/?oo_boo3204=== PAUSE TestGlobMatch/?oo_boo3205=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3206=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3207=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3208=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3209=== CONT TestGlobMatch/foo_foo3210=== CONT TestGlobMatch/*bar_bar3211=== CONT TestGlobMatch/foo*_foo3212=== CONT TestGlobMatch/*_anything3213=== CONT TestGlobMatch/*_3214=== CONT TestGlobMatch/?oo_boo3215=== CONT TestGlobMatch/?oo_foo3216=== CONT TestGlobMatch/fo?_fooo3217=== CONT TestGlobMatch/fo?_fo3218=== CONT TestGlobMatch/fo?_foo3219=== CONT TestGlobMatch/*/*_foo3220=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03221=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3222=== CONT TestGlobMatch/*/*_foo/bar3223=== CONT TestGlobMatch/foo*bar_foobarbaz3224=== CONT TestGlobMatch/foo*bar_foo123bar3225--- PASS: TestPins_ConfigValidation (0.00s)3226=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3227=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3228=== CONT TestGlobMatch/foo*_bar3229=== CONT TestGlobMatch/foo*bar_foobar3230=== CONT TestGlobMatch/*bar_foo3231=== CONT TestGlobMatch/*bar_foobar3232=== CONT TestGlobMatch/foo*_foobar3233=== CONT TestGlobMatch/foo_bar3234=== CONT TestGlobMatch/refs/*/main_refs/heads/main3235--- PASS: TestGlobMatch (0.00s)3236 --- PASS: TestGlobMatch/foo_foo (0.00s)3237 --- PASS: TestGlobMatch/*bar_bar (0.00s)3238 --- PASS: TestGlobMatch/foo*_foo (0.00s)3239 --- PASS: TestGlobMatch/*_anything (0.00s)3240 --- PASS: TestGlobMatch/*_ (0.00s)3241 --- PASS: TestGlobMatch/?oo_boo (0.00s)3242 --- PASS: TestGlobMatch/?oo_foo (0.00s)3243 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3244 --- PASS: TestGlobMatch/fo?_fo (0.00s)3245 --- PASS: TestGlobMatch/fo?_foo (0.00s)3246 --- PASS: TestGlobMatch/*/*_foo (0.00s)3247 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3248 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3249 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3250 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3251 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3252 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3253 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3254 --- PASS: TestGlobMatch/foo*_bar (0.00s)3255 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3256 --- PASS: TestGlobMatch/*bar_foo (0.00s)3257 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3258 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3259 --- PASS: TestGlobMatch/foo_bar (0.00s)3260 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)32612026/10/01 10:20:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33665/oidc32622026/10/01 10:20:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39531/oidc3263--- PASS: TestValidateToken_Expired (0.03s)3264--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)32652026/10/01 10:20:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35881/oidc3266--- PASS: TestValidateToken_WrongAudience (0.05s)32672026/10/01 10:20:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44685/oidc3268--- PASS: TestValidateToken_ValidToken (0.08s)32692026/10/01 10:20:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39565/oidc3270--- PASS: TestValidateToken_BoundClaimsMismatch (0.11s)32712026/10/01 10:20:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45675/oidc3272--- PASS: TestPins_ReservedForMatchingRule (0.12s)32732026/10/01 10:20:53 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:432033274--- PASS: TestValidateToken_KubernetesServiceAccount (0.16s)32752026/10/01 10:20:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42645/oidc32762026/10/01 10:20:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41375/oidc3277--- PASS: TestValidateToken_NoMatchingProvider (0.16s)3278--- PASS: TestPins_TopLevelShorthand (0.16s)32792026/10/01 10:20:53 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233280--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.18s)32812026/10/01 10:20:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37251/oidc3282--- PASS: TestScopes_Rules (0.20s)32832026/10/01 10:20:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43795/oidc3284--- PASS: TestValidateToken_BoundSubjectMismatch (0.21s)32852026/10/01 10:20:53 http: TLS handshake error from 127.0.0.1:35880: remote error: tls: bad certificate3286--- PASS: TestNewValidator_KubernetesRequiresCA (0.27s)32872026/10/01 10:20:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46663/oidc32882026/10/01 10:20:53 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:39073/oidc3289--- PASS: TestValidateToken_MultipleProviders (0.53s)3290PASS3291Running hook tests...3292=== RUN TestSendPathsEmpty3293=== PAUSE TestSendPathsEmpty3294=== RUN TestQueueEnqueueAndFetch3295=== PAUSE TestQueueEnqueueAndFetch3296=== RUN TestQueueDeduplication3297=== PAUSE TestQueueDeduplication3298=== RUN TestQueueRemove3299=== PAUSE TestQueueRemove3300=== RUN TestQueueFetchBatchLimit3301=== PAUSE TestQueueFetchBatchLimit3302=== RUN TestQueueRetryMovesToBack3303=== PAUSE TestQueueRetryMovesToBack3304=== RUN TestQueueFetchRemoveLifecycle3305=== PAUSE TestQueueFetchRemoveLifecycle3306=== RUN TestQueueConcurrentWriters3307=== PAUSE TestQueueConcurrentWriters3308=== RUN TestQueueRemoveLargeClosure3309=== PAUSE TestQueueRemoveLargeClosure3310=== RUN TestServerClientIntegration3311=== PAUSE TestServerClientIntegration3312=== RUN TestServerQueueError3313=== PAUSE TestServerQueueError3314=== RUN TestGetListenerSocketActivation3315 server_test.go:210: === RUN TestGetListenerSocketActivation3316 --- PASS: TestGetListenerSocketActivation (0.00s)3317 PASS3318 3319--- PASS: TestGetListenerSocketActivation (0.01s)3320=== RUN TestDrainIsolatesPoisonPath3321=== PAUSE TestDrainIsolatesPoisonPath3322=== RUN TestRunNotBlockedByPoisonHead3323=== PAUSE TestRunNotBlockedByPoisonHead3324=== RUN TestDrainGivesUpWhenServerDown3325=== PAUSE TestDrainGivesUpWhenServerDown3326=== RUN TestFailedPathPrunedByLaterClosure3327=== PAUSE TestFailedPathPrunedByLaterClosure3328=== RUN TestWorkerUploadsAndRemoves3329=== PAUSE TestWorkerUploadsAndRemoves3330=== RUN TestWorkerSkipsGCdPaths3331=== PAUSE TestWorkerSkipsGCdPaths3332=== RUN TestWorkerPrunesClosureDeps3333=== PAUSE TestWorkerPrunesClosureDeps3334=== RUN TestDrainTimeout3335=== PAUSE TestDrainTimeout3336=== CONT TestSendPathsEmpty3337--- PASS: TestSendPathsEmpty (0.00s)3338=== CONT TestServerQueueError3339=== CONT TestDrainTimeout3340=== CONT TestWorkerPrunesClosureDeps3341=== CONT TestDrainGivesUpWhenServerDown3342=== CONT TestDrainIsolatesPoisonPath3343=== CONT TestWorkerUploadsAndRemoves3344=== CONT TestFailedPathPrunedByLaterClosure3345=== CONT TestRunNotBlockedByPoisonHead3346=== CONT TestQueueRetryMovesToBack33472026/10/01 10:20:53 ERROR Failed to queue paths error="permission denied" count=13348=== CONT TestServerClientIntegration3349=== CONT TestQueueRemoveLargeClosure3350=== CONT TestQueueConcurrentWriters3351=== CONT TestQueueFetchRemoveLifecycle3352=== CONT TestQueueRemove3353=== CONT TestQueueFetchBatchLimit3354=== CONT TestWorkerSkipsGCdPaths3355=== CONT TestQueueDeduplication3356=== CONT TestQueueEnqueueAndFetch3357--- PASS: TestServerQueueError (0.00s)3358--- PASS: TestServerClientIntegration (0.00s)33592026/10/01 10:20:53 INFO Uploading batch count=233602026/10/01 10:20:53 ERROR Upload failed error="upload failed" count=233612026/10/01 10:20:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4053268255/002/a33622026/10/01 10:20:53 INFO Uploading batch count=233632026/10/01 10:20:53 INFO Upload queue status pending=233642026/10/01 10:20:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4053268255/002/b3365--- PASS: TestQueueRemove (0.01s)33662026/10/01 10:20:53 INFO Upload queue status pending=333672026/10/01 10:20:53 INFO Upload queue status pending=233682026/10/01 10:20:53 INFO Uploading batch count=133692026/10/01 10:20:53 ERROR Upload failed error="upload failed" count=133702026/10/01 10:20:53 INFO Uploading batch count=233712026/10/01 10:20:53 INFO Uploading batch count=233722026/10/01 10:20:53 ERROR Upload failed error="upload failed" count=233732026/10/01 10:20:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4053268255/002/c33742026/10/01 10:20:53 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths463860044/002/nonexistent3375--- PASS: TestQueueDeduplication (0.01s)3376--- PASS: TestQueueFetchBatchLimit (0.01s)33772026/10/01 10:20:53 INFO Uploading batch count=133782026/10/01 10:20:53 ERROR Upload failed error="upload failed" count=13379--- PASS: TestQueueRetryMovesToBack (0.01s)33802026/10/01 10:20:53 INFO Uploading batch count=433812026/10/01 10:20:53 ERROR Upload failed error="upload failed" count=433822026/10/01 10:20:53 INFO Uploading batch count=133832026/10/01 10:20:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4053268255/002/d33842026/10/01 10:20:53 INFO Uploading batch count=133852026/10/01 10:20:53 INFO Upload queue status pending=233862026/10/01 10:20:53 INFO Uploading batch count=133872026/10/01 10:20:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3240331092/002/bbb33882026/10/01 10:20:53 INFO Uploading batch count=13389--- PASS: TestQueueEnqueueAndFetch (0.01s)33902026/10/01 10:20:53 INFO Uploading batch count=233912026/10/01 10:20:53 ERROR Upload failed error="upload failed" count=23392--- PASS: TestQueueFetchRemoveLifecycle (0.01s)33932026/10/01 10:20:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4053268255/002/e33942026/10/01 10:20:53 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4053268255/002/f33952026/10/01 10:20:53 INFO Uploading batch count=133962026/10/01 10:20:53 ERROR Upload failed error="upload failed" count=133972026/10/01 10:20:53 ERROR Drain finished with paths left in queue remaining=1033982026/10/01 10:20:53 INFO Uploading batch count=133992026/10/01 10:20:53 ERROR Upload failed error="upload failed" count=13400--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)34012026/10/01 10:20:53 INFO Uploading batch count=134022026/10/01 10:20:53 ERROR Upload failed error="upload failed" count=134032026/10/01 10:20:53 ERROR Drain finished with paths left in queue remaining=13404--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3405--- PASS: TestDrainIsolatesPoisonPath (0.02s)3406--- PASS: TestWorkerUploadsAndRemoves (0.03s)3407--- PASS: TestWorkerSkipsGCdPaths (0.03s)3408--- PASS: TestWorkerPrunesClosureDeps (0.03s)3409--- PASS: TestQueueRemoveLargeClosure (0.14s)3410--- PASS: TestQueueConcurrentWriters (0.21s)34112026/10/01 10:20:53 ERROR Upload failed error="context deadline exceeded" count=234122026/10/01 10:20:53 ERROR Drain finished with paths left in queue remaining=43413--- PASS: TestDrainTimeout (0.21s)34142026/10/01 10:20:54 INFO Uploading batch count=134152026/10/01 10:20:54 INFO Uploading batch count=134162026/10/01 10:20:54 INFO Uploading batch count=134172026/10/01 10:20:54 ERROR Upload failed error="upload failed" count=134182026/10/01 10:20:54 INFO Uploading batch count=134192026/10/01 10:20:54 ERROR Upload failed error="upload failed" count=134202026/10/01 10:20:54 INFO Uploading batch count=134212026/10/01 10:20:54 ERROR Upload failed error="upload failed" count=134222026/10/01 10:20:54 INFO Uploading batch count=134232026/10/01 10:20:54 ERROR Upload failed error="upload failed" count=134242026/10/01 10:20:54 ERROR Drain finished with paths left in queue remaining=13425--- PASS: TestRunNotBlockedByPoisonHead (1.03s)3426PASS