niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #304
· 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.03s)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=== CONT TestEncodeNixBase32WithRealHash98=== CONT TestEncodeNixBase3299--- PASS: TestScriptTokenEmptyCommand (0.00s)100--- PASS: TestEncodeNixBase32WithRealHash (0.00s)101=== CONT TestScriptTokenScriptFails102=== CONT TestScriptTokenBadJSON103=== CONT TestScriptTokenEmptyToken104=== CONT TestScriptTokenCachesUntilRefresh105=== CONT TestScriptTokenNoExpiryRerunsEveryCall106=== CONT TestFileTokenEmpty107=== CONT TestFileTokenMissing108=== CONT TestFileTokenReadsAndCaches109=== CONT TestStaticToken110--- PASS: TestStaticToken (0.00s)111--- PASS: TestScriptTokenScriptFails (0.00s)112=== CONT TestDumpPathSingleFile113=== CONT TestSetClientTLSDoesNotMutateDefaultTransport114=== CONT TestSetClientTLS115=== CONT TestClientSignaturesByStorePath116=== CONT TestStreamPushReportsSignatures117=== CONT TestStreamPushRequestLine118=== CONT TestStreamPushGivesUpOnDeadServer119=== CONT TestStreamPushIsolatesFailures120=== CONT TestStreamPushBatchesUnderLoad121=== CONT TestStreamPushReportsEveryPath122=== CONT TestShellSplitErrors123=== CONT TestUploadMultipart_SupersededByPeer124=== CONT TestShellSplit125=== RUN TestEncodeNixBase32/test_string_hash126=== CONT TestSetClientTLSErrors127=== CONT TestDumpPathWriterError128--- PASS: TestFileTokenEmpty (0.00s)129--- PASS: TestClientSignaturesByStorePath (0.00s)130--- PASS: TestFileTokenMissing (0.00s)131--- PASS: TestFileTokenReadsAndCaches (0.00s)132--- PASS: TestScriptTokenBadJSON (0.00s)133=== CONT TestDumpPathMatchesNix1342026/10/01 08:35:21 ERROR Upload failed error="connection refused" count=20135=== CONT TestPathInfoHashCompatibility1362026/10/01 08:35:21 ERROR Server seems unavailable, giving up on batch untried=17137=== CONT TestParsePathInfoJSONMultiplePaths138--- PASS: TestScriptTokenEmptyToken (0.00s)139=== CONT TestConvertHashToNix32140=== RUN TestConvertHashToNix32/SRI_format_to_Nix32141=== PAUSE TestEncodeNixBase32/test_string_hash1422026/10/01 08:35:21 ERROR Upload failed error="bad path" count=3143=== RUN TestEncodeNixBase32/empty_input144=== PAUSE TestEncodeNixBase32/empty_input145=== CONT TestPartSizeForNAR146=== RUN TestPartSizeForNAR/zero_stays_at_minimum147=== CONT TestParsePathInfoJSON148=== RUN TestParsePathInfoJSON/Nix_format149=== CONT TestGetStorePathHash150=== RUN TestGetStorePathHash/valid_store_path151=== CONT TestDoWithRetry_BodyReplayedViaGetBody152=== PAUSE TestParsePathInfoJSON/Nix_format153=== RUN TestParsePathInfoJSON/Lix_format154=== PAUSE TestParsePathInfoJSON/Lix_format1552026/10/01 08:35:21 ERROR Upload failed error=boom count=1156=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1572026/10/01 08:35:21 ERROR Upload failed error=boom count=1158=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)159=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon160=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon161=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI162=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI163=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512164=== RUN TestParsePathInfoJSON/empty_input165=== PAUSE TestParsePathInfoJSON/empty_input166=== CONT TestFilterOversizedClosures167=== RUN TestFilterOversizedClosures/no_limit_keeps_everything168=== RUN TestUploadMultipart_SupersededByPeer/exists169=== CONT TestUploadMultipart_PartsInParallel170=== CONT TestResolveStorePath171=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum172=== PAUSE TestGetStorePathHash/valid_store_path173--- PASS: TestShellSplitErrors (0.00s)174=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths175=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess176=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512177--- PASS: TestStreamPushReportsEveryPath (0.00s)178--- PASS: TestShellSplit (0.00s)179=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything180=== PAUSE TestUploadMultipart_SupersededByPeer/exists181=== RUN TestPartSizeForNAR/small_stays_at_minimum182=== RUN TestGetStorePathHash/basename_without_hyphen_should_error183--- PASS: TestStreamPushIsolatesFailures (0.00s)184--- PASS: TestStreamPushReportsSignatures (0.00s)185=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped186=== RUN TestUploadMultipart_SupersededByPeer/missing1872026/10/01 08:35:21 WARN Rate limiter enabled after throttle name=server-test rate=51882026/10/01 08:35:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39121189--- PASS: TestResolveStorePath (0.00s)190=== CONT TestCaseHackSuffix191=== RUN TestSetClientTLSErrors/missing_cert_file192=== CONT TestRateLimiterFeedback193=== RUN TestRateLimiterFeedback/429_enables_limiter194=== PAUSE TestRateLimiterFeedback/429_enables_limiter195=== RUN TestRateLimiterFeedback/503_enables_limiter196=== PAUSE TestRateLimiterFeedback/503_enables_limiter197=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter198=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter1992026/10/01 08:35:21 WARN Rate limiter enabled after throttle name=server-test rate=5200=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter201=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter202=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths203=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths204=== CONT TestRegisterUploadedObjectReusesConnections205=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32206=== RUN TestConvertHashToNix32/already_Nix32_format207=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths208--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)209=== RUN TestParsePathInfoJSON/whitespace_only210=== PAUSE TestConvertHashToNix32/already_Nix32_format211=== RUN TestConvertHashToNix32/invalid_format212=== PAUSE TestPartSizeForNAR/small_stays_at_minimum213=== CONT TestEncodeNixBase32/test_string_hash214--- PASS: TestDoServerRequestAttachesToken (0.01s)215=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)216=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI217=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512218=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon219--- PASS: TestPathInfoHashCompatibility (0.00s)220 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)221 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)222 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)223 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)224=== CONT TestRateLimiterFeedback/429_enables_limiter225--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)226=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter227=== RUN TestSetClientTLS/rejects_connection_without_client_cert228=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert229=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA230=== PAUSE TestUploadMultipart_SupersededByPeer/missing231=== CONT TestPathInfoCACompatibility2322026/10/01 08:35:21 WARN Rate limiter backed off name=server-test rate=52332026/10/01 08:35:21 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:391212342026/10/01 08:35:21 WARN Rate limiter enabled after throttle name=server-test rate=52352026/10/01 08:35:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:41067236=== CONT TestEncodeNixBase32/empty_input2372026/10/01 08:35:21 WARN Rate limiter backed off name=server-test rate=5238=== CONT TestUploadMultipart_SupersededByPeer/missing239=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped240--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)241=== CONT TestRateLimiterFeedback/503_enables_limiter242=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error243=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter244=== PAUSE TestSetClientTLSErrors/missing_cert_file245=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths246=== PAUSE TestParsePathInfoJSON/whitespace_only247=== PAUSE TestConvertHashToNix32/invalid_format248=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA249=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum250=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths251=== CONT TestUploadMultipart_SupersededByPeer/exists252=== RUN TestSetClientTLSErrors/missing_key_file253=== PAUSE TestSetClientTLSErrors/missing_key_file254=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error255=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error256=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error257=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error258=== CONT TestGetStorePathHash/valid_store_path259=== RUN TestParsePathInfoJSON/invalid_JSON260=== PAUSE TestParsePathInfoJSON/invalid_JSON261=== CONT TestParsePathInfoJSON/Nix_format262=== RUN TestPathInfoCACompatibility/null_ca_field263=== PAUSE TestPathInfoCACompatibility/null_ca_field264=== CONT TestConvertHashToNix32/already_Nix32_format265=== RUN TestSetClientTLS/preserves_debug_logging_transport266=== RUN TestSetClientTLSErrors/missing_ca_file267=== PAUSE TestSetClientTLSErrors/missing_ca_file268=== RUN TestSetClientTLSErrors/invalid_ca_file269=== PAUSE TestSetClientTLSErrors/invalid_ca_file270--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)271--- PASS: TestDumpPathSingleFile (0.04s)272=== CONT TestConvertHashToNix32/SRI_format_to_Nix32273=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error274=== CONT TestParsePathInfoJSON/whitespace_only275=== CONT TestSetClientTLSErrors/missing_cert_file2762026/10/01 08:35:21 WARN Rate limiter enabled after throttle name=server-test rate=5277=== CONT TestSetClientTLSErrors/invalid_ca_file2782026/10/01 08:35:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:35957279=== CONT TestSetClientTLSErrors/missing_key_file2802026/10/01 08:35:21 WARN Rate limiter backed off name=server-test rate=5281=== CONT TestParsePathInfoJSON/Lix_format282=== CONT TestConvertHashToNix32/invalid_format283=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum284=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts285=== RUN TestPathInfoCACompatibility/old_string_format_-_text286=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text287=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive288=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive289=== RUN TestPathInfoCACompatibility/new_structured_format_-_text290=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text291=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method292=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method293=== CONT TestPathInfoCACompatibility/null_ca_field294=== PAUSE TestSetClientTLS/preserves_debug_logging_transport295=== CONT TestSetClientTLS/rejects_connection_without_client_cert296=== RUN TestFilterOversizedClosures/all_closures_skipped297=== PAUSE TestFilterOversizedClosures/all_closures_skipped298=== CONT TestPathInfoCACompatibility/old_string_format_-_text299=== CONT TestSetClientTLS/preserves_debug_logging_transport300=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive301=== CONT TestFilterOversizedClosures/no_limit_keeps_everything302--- PASS: TestEncodeNixBase32 (0.01s)303 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)304 --- PASS: TestEncodeNixBase32/empty_input (0.00s)305=== CONT TestGetStorePathHash/basename_without_hyphen_should_error306=== CONT TestParsePathInfoJSON/empty_input307=== CONT TestParsePathInfoJSON/invalid_JSON308=== CONT TestSetClientTLSErrors/missing_ca_file309=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts310=== RUN TestPartSizeForNAR/1_TiB311=== PAUSE TestPartSizeForNAR/1_TiB312=== CONT TestPathInfoCACompatibility/new_structured_format_-_text313=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method314=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error315=== CONT TestFilterOversizedClosures/all_closures_skipped3162026/10/01 08:35:21 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50317=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3182026/10/01 08:35:21 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=2000319=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA320--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)321 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)322 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)323--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)324=== RUN TestPartSizeForNAR/5_TiB_S3_max_object325=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object326=== RUN TestPartSizeForNAR/capped_at_5_GiB327=== PAUSE TestPartSizeForNAR/capped_at_5_GiB328=== CONT TestPartSizeForNAR/zero_stays_at_minimum329--- PASS: TestConvertHashToNix32 (0.04s)330 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)331 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)332 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)333=== CONT TestPartSizeForNAR/small_stays_at_minimum334=== CONT TestPartSizeForNAR/1_TiB335=== CONT TestPartSizeForNAR/capped_at_5_GiB336=== CONT TestPartSizeForNAR/5_TiB_S3_max_object337=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts338--- PASS: TestParsePathInfoJSON (0.04s)339 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)340 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)341 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)342 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)343 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)344--- PASS: TestGetStorePathHash (0.04s)345 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)347 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)348 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)349=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum350--- PASS: TestFilterOversizedClosures (0.04s)351 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)352 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)353 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)354--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)355 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)356 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)357--- PASS: TestRateLimiterFeedback (0.00s)358 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.03s)359 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.03s)360 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)361 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)362--- PASS: TestPathInfoCACompatibility (0.00s)363 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)364 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)365 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)366 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)367 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)368--- PASS: TestPartSizeForNAR (0.04s)369 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)370 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)372 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)373 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)374 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)375 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)376--- PASS: TestSetClientTLSErrors (0.04s)377 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)378 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)379 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3812026/10/01 08:35:21 http: TLS handshake error from 127.0.0.1:48310: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.04s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)386--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)387--- PASS: TestStreamPushRequestLine (0.06s)388--- PASS: TestDumpPathWriterError (0.06s)389--- PASS: TestCaseHackSuffix (0.06s)390--- PASS: TestDumpPathMatchesNix (0.10s)391--- PASS: TestStreamPushBatchesUnderLoad (0.10s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)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/postgres3867333943/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/postgres3867333943/data -l logfile start422423/build/postgres3867333943:5432 - no response4242026-10-01 08:35:23.324 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 08:35:23.324 UTC [128] LOG: listening on Unix socket "/build/postgres3867333943/.s.PGSQL.5432"4262026-10-01 08:35:23.328 UTC [135] LOG: database system was shut down at 2026-10-01 08:35:23 UTC4272026-10-01 08:35:23.331 UTC [128] LOG: database system is ready to accept connections428/build/postgres3867333943:5432 - accepting connections429{"timestamp":"2026-10-01T08:35:23.52263776Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"0d1b1bdd-06b4-408c-9d85-095a9e242407","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(208)"}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 TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-10-01 08:35:23.703 UTC [369] ERROR: relation "goose_db_version" does not exist at character 364722026-10-01 08:35:23.703 UTC [369] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/10/01 08:35:23 OK 20241026095416_initial_model.sql (8.55ms)4742026/10/01 08:35:23 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)4752026/10/01 08:35:23 OK 20251218171726_add_pins.sql (2.54ms)4762026/10/01 08:35:23 OK 20260628120000_add_object_size_and_stats.sql (2.23ms)4772026/10/01 08:35:23 OK 20260905000000_add_claims.sql (2.51ms)4782026/10/01 08:35:23 OK 20260920000000_drop_claims.sql (1.54ms)4792026/10/01 08:35:23 OK 20260923120000_add_pushes.sql (1.14ms)4802026/10/01 08:35:23 goose: successfully migrated database to version: 202609231200004812026/10/01 08:35:23 OK 1_commit_pending_closure.sql (1.43ms)4822026/10/01 08:35:23 OK 2_object_stats_trigger.sql (615.21µs)4832026/10/01 08:35:23 OK 3_commit_push.sql (506.17µs)4842026/10/01 08:35:23 goose: up to current file version: 34852026/10/01 08:35:23 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 08:35:24 INFO lead: released remote=192.0.2.1:12344872026/10/01 08:35:24 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 08:35:24 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.77s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-10-01 08:35:24.458 UTC [380] ERROR: relation "goose_db_version" does not exist at character 364942026-10-01 08:35:24.458 UTC [380] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/10/01 08:35:24 OK 20241026095416_initial_model.sql (8.33ms)4962026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)4972026/10/01 08:35:24 OK 20251218171726_add_pins.sql (2.62ms)4982026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (2.65ms)4992026/10/01 08:35:24 OK 20260905000000_add_claims.sql (2.49ms)5002026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (1.5ms)5012026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (1.11ms)5022026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200005032026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.42ms)5042026/10/01 08:35:24 OK 2_object_stats_trigger.sql (600.71µs)5052026/10/01 08:35:24 OK 3_commit_push.sql (491.69µs)5062026/10/01 08:35:24 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.11s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestObjectStatsTrigger579=== PAUSE TestObjectStatsTrigger580=== RUN TestOrphanedObjectsGC581=== PAUSE TestOrphanedObjectsGC582=== RUN TestOrphanedObjectsGCStressTest583=== PAUSE TestOrphanedObjectsGCStressTest584=== RUN TestCreatePin_ReservedPins585=== PAUSE TestCreatePin_ReservedPins586=== RUN TestParseSingleRange587=== PAUSE TestParseSingleRange588=== RUN TestProxyHeadersOnlyTrustedOnSocket589=== PAUSE TestProxyHeadersOnlyTrustedOnSocket590=== RUN TestIsValidCachePath591=== PAUSE TestIsValidCachePath592=== RUN TestReadProxyNarinfo593=== PAUSE TestReadProxyNarinfo594=== RUN TestReadProxyNarinfoAlreadyDecompressed595=== PAUSE TestReadProxyNarinfoAlreadyDecompressed596=== RUN TestReadProxyNarStreaming597=== PAUSE TestReadProxyNarStreaming598=== RUN TestReadProxy404599=== PAUSE TestReadProxy404600=== RUN TestReadProxyInvalidPath601=== PAUSE TestReadProxyInvalidPath602=== RUN TestReadProxyHead603=== PAUSE TestReadProxyHead604=== RUN TestReadProxyConditionalGet605=== PAUSE TestReadProxyConditionalGet606=== RUN TestReadProxyRootRedirectsToIndexHTML607=== PAUSE TestReadProxyRootRedirectsToIndexHTML608=== RUN TestReadProxyDisabled609=== PAUSE TestReadProxyDisabled610=== RUN TestReadRedirectNar611=== PAUSE TestReadRedirectNar612=== RUN TestReadRedirectKeepsNarinfoProxied613=== PAUSE TestReadRedirectKeepsNarinfoProxied614=== RUN TestReadProxyRangeRequest615=== PAUSE TestReadProxyRangeRequest616=== RUN TestReadRedirectUsesPublicS3URL617=== PAUSE TestReadRedirectUsesPublicS3URL618=== RUN TestPush_OverlappingRootsStoreOneRowPerKey619=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey620=== RUN TestPush_CompleteCommitsEveryRoot621=== PAUSE TestPush_CompleteCommitsEveryRoot622=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit623=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit624=== RUN TestPush_RejectsBadRequests625=== PAUSE TestPush_RejectsBadRequests626=== RUN TestPush_SignsNarinfosOfItsPendingObjects627=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects628=== RUN TestRedundantMultipartUpload629=== PAUSE TestRedundantMultipartUpload630=== RUN TestCompleteMultipartUpload_ErrorButObjectExists631=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists632=== RUN TestCompletedNarNotReofferedAcrossClosures633=== PAUSE TestCompletedNarNotReofferedAcrossClosures634=== RUN TestPresignedUploadRegisteredBeforeCommit635=== PAUSE TestPresignedUploadRegisteredBeforeCommit636=== RUN TestService_Rustfstest637=== PAUSE TestService_Rustfstest638=== RUN TestParseSize639=== PAUSE TestParseSize640=== RUN TestSkippedUploadsHandler641=== PAUSE TestSkippedUploadsHandler642=== RUN TestSystemdListenerNotActivated643--- PASS: TestSystemdListenerNotActivated (0.00s)644=== RUN TestWatchdogBeatsWhenHealthy645--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)646=== RUN TestWatchdogSkipsWhenUnhealthy6472026/10/01 08:35:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 08:35:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 08:35:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 08:35:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/01 08:35:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/01 08:35:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6532026/10/01 08:35:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6542026/10/01 08:35:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/01 08:35:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/01 08:35:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"657--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)658=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle659=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle660=== RUN TestProxyWriteTimeout661=== PAUSE TestProxyWriteTimeout662=== RUN TestIsValidUploadKey663=== PAUSE TestIsValidUploadKey664=== RUN TestUploadHandlersRejectInvalidKeys665=== PAUSE TestUploadHandlersRejectInvalidKeys666=== RUN TestUploadHandlersRejectOversizedBody667=== PAUSE TestUploadHandlersRejectOversizedBody668=== RUN TestService_cleanupPendingClosuresHandler669=== PAUSE TestService_cleanupPendingClosuresHandler670=== RUN TestService_createPendingClosureHandler671=== PAUSE TestService_createPendingClosureHandler672=== RUN TestService_verifyS3Integrity673=== PAUSE TestService_verifyS3Integrity674=== RUN TestCompleteMultipartUnregistered675=== PAUSE TestCompleteMultipartUnregistered676=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT677=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT678=== CONT TestPresignedUploadRegisteredBeforeCommit679=== CONT TestMultipartCleanup680=== CONT TestService_AuthMiddleware681=== CONT TestPushWaitsForSweepHoldingRow682=== CONT TestCompleteMultipartUpload_ErrorButObjectExists683=== CONT TestRedundantMultipartUpload684=== CONT TestPush_SignsNarinfosOfItsPendingObjects685=== CONT TestPush_RejectsBadRequests686=== CONT TestUploadHandlersRejectInvalidKeys687=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit688=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT689=== CONT TestPush_CompleteCommitsEveryRoot690=== CONT TestCompleteMultipartUnregistered691=== CONT TestPush_OverlappingRootsStoreOneRowPerKey692=== CONT TestService_verifyS3Integrity693=== CONT TestReadRedirectUsesPublicS3URL694=== CONT TestService_createPendingClosureHandler695=== CONT TestReadProxyRangeRequest696=== CONT TestReadRedirectKeepsNarinfoProxied697=== CONT TestService_cleanupPendingClosuresHandler698=== CONT TestCommitRacingPendingCleanupKeepsObjects699=== CONT TestUploadHandlersRejectOversizedBody700=== CONT TestGCTaskStore_StartNew701--- PASS: TestGCTaskStore_StartNew (0.00s)702=== CONT TestSweepRechecksPendingAfterLocking703=== CONT TestCompletedNarNotReofferedAcrossClosures704=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info705=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info706=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal707=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal708=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key709=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key710=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key711=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key712=== CONT TestGetExistingObjectsLocksRows7132026-10-01 08:35:24.820 UTC [447] ERROR: relation "goose_db_version" does not exist at character 367142026-10-01 08:35:24.820 UTC [447] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7152026-10-01 08:35:24.825 UTC [448] ERROR: relation "goose_db_version" does not exist at character 367162026-10-01 08:35:24.825 UTC [448] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7172026-10-01 08:35:24.837 UTC [449] ERROR: relation "goose_db_version" does not exist at character 367182026-10-01 08:35:24.837 UTC [449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7192026-10-01 08:35:24.846 UTC [450] ERROR: relation "goose_db_version" does not exist at character 367202026-10-01 08:35:24.846 UTC [450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC721=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure722=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure723=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart724=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart7252026-10-01 08:35:24.869 UTC [451] ERROR: relation "goose_db_version" does not exist at character 367262026-10-01 08:35:24.869 UTC [451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC727=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts728=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts729=== CONT TestRegisterCompletedObjectNeedsPendingRow7302026-10-01 08:35:24.869 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367312026-10-01 08:35:24.869 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7322026/10/01 08:35:24 OK 20241026095416_initial_model.sql (27.36ms)7332026/10/01 08:35:24 OK 20241026095416_initial_model.sql (22.73ms)7342026/10/01 08:35:24 OK 20241026095416_initial_model.sql (27.31ms)7352026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (4.18ms)7362026-10-01 08:35:24.877 UTC [456] ERROR: relation "goose_db_version" does not exist at character 367372026-10-01 08:35:24.877 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7382026-10-01 08:35:24.877 UTC [457] ERROR: relation "goose_db_version" does not exist at character 367392026-10-01 08:35:24.877 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7402026-10-01 08:35:24.877 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367412026-10-01 08:35:24.877 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7422026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (4.84ms)7432026-10-01 08:35:24.879 UTC [458] ERROR: relation "goose_db_version" does not exist at character 367442026-10-01 08:35:24.879 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7452026-10-01 08:35:24.880 UTC [459] ERROR: relation "goose_db_version" does not exist at character 367462026-10-01 08:35:24.880 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7472026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (12.32ms)7482026/10/01 08:35:24 OK 20251218171726_add_pins.sql (11ms)7492026/10/01 08:35:24 OK 20251218171726_add_pins.sql (12.31ms)7502026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (5.44ms)7512026/10/01 08:35:24 OK 20251218171726_add_pins.sql (5.44ms)7522026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (5.58ms)7532026/10/01 08:35:24 OK 20260905000000_add_claims.sql (4.71ms)7542026/10/01 08:35:24 OK 20241026095416_initial_model.sql (25.61ms)7552026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (6.08ms)7562026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.96ms)7572026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (4.61ms)7582026/10/01 08:35:24 OK 20260905000000_add_claims.sql (6.69ms)7592026/10/01 08:35:24 OK 20241026095416_initial_model.sql (23.06ms)7602026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (11.18ms)7612026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200007622026/10/01 08:35:24 OK 20251218171726_add_pins.sql (11.75ms)7632026/10/01 08:35:24 OK 20241026095416_initial_model.sql (19.39ms)7642026/10/01 08:35:24 OK 20260905000000_add_claims.sql (13.12ms)7652026/10/01 08:35:24 OK 20241026095416_initial_model.sql (20.45ms)7662026/10/01 08:35:24 OK 20241026095416_initial_model.sql (19.04ms)7672026/10/01 08:35:24 OK 20241026095416_initial_model.sql (24.36ms)7682026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (10.66ms)7692026/10/01 08:35:24 OK 20241026095416_initial_model.sql (20.7ms)7702026/10/01 08:35:24 OK 20241026095416_initial_model.sql (20.42ms)7712026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)7722026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)7732026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (4.3ms)7742026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)7752026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)7762026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.42ms)7772026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200007782026/10/01 08:35:24 OK 1_commit_pending_closure.sql (3.52ms)7792026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)7802026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.52ms)7812026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)7822026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.9ms)7832026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (5.5ms)7842026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.48ms)7852026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200007862026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.75ms)7872026/10/01 08:35:24 OK 3_commit_push.sql (1.59ms)7882026/10/01 08:35:24 goose: up to current file version: 37892026/10/01 08:35:24 OK 20251218171726_add_pins.sql (4.69ms)7902026/10/01 08:35:24 OK 20251218171726_add_pins.sql (5.16ms)7912026/10/01 08:35:24 OK 20251218171726_add_pins.sql (4.92ms)7922026/10/01 08:35:24 OK 20251218171726_add_pins.sql (4.88ms)7932026/10/01 08:35:24 OK 20251218171726_add_pins.sql (5.06ms)7942026/10/01 08:35:24 OK 2_object_stats_trigger.sql (2.19ms)7952026/10/01 08:35:24 OK 20251218171726_add_pins.sql (5ms)7962026/10/01 08:35:24 OK 20251218171726_add_pins.sql (4.3ms)7972026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.74ms)7982026/10/01 08:35:24 OK 20260905000000_add_claims.sql (4.25ms)7992026/10/01 08:35:24 OK 3_commit_push.sql (1.5ms)8002026/10/01 08:35:24 goose: up to current file version: 38012026/10/01 08:35:24 OK 2_object_stats_trigger.sql (2.35ms)8022026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.64ms)8032026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.3ms)8042026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.27ms)8052026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)8062026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.45ms)8072026/10/01 08:35:24 OK 3_commit_push.sql (755.41µs)8082026/10/01 08:35:24 goose: up to current file version: 38092026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.13ms)8102026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.8ms)8112026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.88ms)8122026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.39ms)8132026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200008142026-10-01 08:35:24.929 UTC [461] ERROR: relation "goose_db_version" does not exist at character 368152026-10-01 08:35:24.929 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026-10-01 08:35:24.929 UTC [462] ERROR: relation "goose_db_version" does not exist at character 368172026-10-01 08:35:24.929 UTC [462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026-10-01 08:35:24.929 UTC [463] ERROR: relation "goose_db_version" does not exist at character 368192026-10-01 08:35:24.929 UTC [463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8202026/10/01 08:35:24 OK 20260905000000_add_claims.sql (4.47ms)8212026/10/01 08:35:24 OK 20260905000000_add_claims.sql (4.25ms)8222026-10-01 08:35:24.930 UTC [464] ERROR: relation "goose_db_version" does not exist at character 368232026-10-01 08:35:24.930 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8242026-10-01 08:35:24.930 UTC [465] ERROR: relation "goose_db_version" does not exist at character 368252026-10-01 08:35:24.930 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8262026/10/01 08:35:24 OK 20260905000000_add_claims.sql (5.16ms)8272026/10/01 08:35:24 OK 20260905000000_add_claims.sql (5.3ms)8282026/10/01 08:35:24 OK 20260905000000_add_claims.sql (5.23ms)8292026-10-01 08:35:24.931 UTC [466] ERROR: relation "goose_db_version" does not exist at character 368302026-10-01 08:35:24.931 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-10-01 08:35:24.931 UTC [467] ERROR: relation "goose_db_version" does not exist at character 368322026-10-01 08:35:24.931 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026/10/01 08:35:24 OK 20260905000000_add_claims.sql (4.91ms)8342026/10/01 08:35:24 OK 1_commit_pending_closure.sql (3.13ms)8352026/10/01 08:35:24 OK 20260905000000_add_claims.sql (4.83ms)8362026-10-01 08:35:24.932 UTC [469] ERROR: relation "goose_db_version" does not exist at character 368372026-10-01 08:35:24.932 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8382026-10-01 08:35:24.932 UTC [468] ERROR: relation "goose_db_version" does not exist at character 368392026-10-01 08:35:24.932 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8402026-10-01 08:35:24.932 UTC [470] ERROR: relation "goose_db_version" does not exist at character 368412026-10-01 08:35:24.932 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8422026-10-01 08:35:24.933 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368432026-10-01 08:35:24.933 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8442026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.61ms)8452026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.7ms)8462026-10-01 08:35:24.934 UTC [472] ERROR: relation "goose_db_version" does not exist at character 368472026-10-01 08:35:24.934 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8482026/10/01 08:35:24 OK 2_object_stats_trigger.sql (2.67ms)8492026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.69ms)8502026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.8ms)8512026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.83ms)8522026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.41ms)8532026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.51ms)8542026/10/01 08:35:24 OK 3_commit_push.sql (1.23ms)8552026/10/01 08:35:24 goose: up to current file version: 38562026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.41ms)8572026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200008582026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.33ms)8592026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200008602026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.78ms)8612026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200008622026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.76ms)8632026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200008642026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.84ms)8652026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200008662026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.86ms)8672026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200008682026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.89ms)8692026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200008702026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.72ms)8712026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.8ms)8722026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.03ms)8732026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.49ms)8742026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.71ms)8752026/10/01 08:35:24 OK 2_object_stats_trigger.sql (2.15ms)8762026/10/01 08:35:24 OK 2_object_stats_trigger.sql (2.23ms)8772026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.72ms)8782026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.79ms)8792026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.28ms)8802026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.95ms)8812026/10/01 08:35:24 OK 3_commit_push.sql (1.32ms)8822026/10/01 08:35:24 goose: up to current file version: 38832026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.9ms)8842026/10/01 08:35:24 OK 3_commit_push.sql (1.2ms)8852026/10/01 08:35:24 goose: up to current file version: 38862026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.85ms)8872026/10/01 08:35:24 OK 3_commit_push.sql (1.93ms)8882026/10/01 08:35:24 goose: up to current file version: 38892026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.94ms)8902026/10/01 08:35:24 OK 3_commit_push.sql (1.8ms)8912026/10/01 08:35:24 goose: up to current file version: 38922026/10/01 08:35:24 OK 3_commit_push.sql (1.54ms)8932026/10/01 08:35:24 goose: up to current file version: 38942026/10/01 08:35:24 OK 3_commit_push.sql (1.78ms)8952026/10/01 08:35:24 goose: up to current file version: 38962026/10/01 08:35:24 OK 3_commit_push.sql (1.8ms)8972026/10/01 08:35:24 goose: up to current file version: 38982026/10/01 08:35:24 INFO Received uploads request method=POST path=/api/pending_closures8992026/10/01 08:35:24 OK 20241026095416_initial_model.sql (10.79ms)9002026/10/01 08:35:24 OK 20241026095416_initial_model.sql (12.08ms)9012026/10/01 08:35:24 OK 20241026095416_initial_model.sql (13.08ms)9022026/10/01 08:35:24 OK 20241026095416_initial_model.sql (13.79ms)9032026/10/01 08:35:24 OK 20241026095416_initial_model.sql (10.98ms)9042026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)9052026/10/01 08:35:24 OK 20241026095416_initial_model.sql (11.08ms)9062026/10/01 08:35:24 OK 20241026095416_initial_model.sql (14.1ms)9072026/10/01 08:35:24 OK 20241026095416_initial_model.sql (13.3ms)9082026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)9092026/10/01 08:35:24 OK 20241026095416_initial_model.sql (11.8ms)9102026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)9112026/10/01 08:35:24 OK 20241026095416_initial_model.sql (12.57ms)9122026/10/01 08:35:24 OK 20241026095416_initial_model.sql (13.93ms)9132026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)9142026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)9152026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)9162026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.42ms)9172026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)9182026/10/01 08:35:24 OK 20251218171726_add_pins.sql (3.59ms)9192026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)9202026/10/01 08:35:24 OK 20241026095416_initial_model.sql (12.09ms)9212026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)9222026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)9232026/10/01 08:35:24 OK 20251218171726_add_pins.sql (4.02ms)9242026/10/01 08:35:24 OK 20251218171726_add_pins.sql (3.97ms)9252026/10/01 08:35:24 OK 20251218171726_add_pins.sql (3.86ms)9262026/10/01 08:35:24 OK 20251218171726_add_pins.sql (3.78ms)9272026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)9282026/10/01 08:35:24 OK 20251218171726_add_pins.sql (3.6ms)9292026/10/01 08:35:24 OK 20251218171726_add_pins.sql (3.08ms)9302026/10/01 08:35:24 OK 20251218171726_add_pins.sql (4.26ms)9312026/10/01 08:35:24 OK 20251218171726_add_pins.sql (4.22ms)9322026/10/01 08:35:24 OK 20251218171726_add_pins.sql (4.32ms)9332026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)9342026/10/01 08:35:24 INFO Received uploads request method=POST path=/api/pending_closures9352026/10/01 08:35:24 OK 20251218171726_add_pins.sql (4.46ms)9362026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4ms)9372026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (3.69ms)9382026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)9392026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)9402026/10/01 08:35:24 OK 20251218171726_add_pins.sql (4.26ms)9412026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.39ms)9422026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)9432026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (3.73ms)9442026/10/01 08:35:24 OK 20260905000000_add_claims.sql (3.54ms)9452026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)9462026/10/01 08:35:24 OK 20260905000000_add_claims.sql (3.29ms)9472026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)9482026/10/01 08:35:24 OK 20260905000000_add_claims.sql (3.58ms)9492026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)9502026/10/01 08:35:24 OK 20260905000000_add_claims.sql (3.76ms)9512026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)9522026/10/01 08:35:24 OK 20260905000000_add_claims.sql (3.56ms)9532026/10/01 08:35:24 OK 20260905000000_add_claims.sql (3.64ms)9542026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.2ms)9552026/10/01 08:35:24 OK 20260905000000_add_claims.sql (3.77ms)9562026/10/01 08:35:24 OK 20260905000000_add_claims.sql (4.3ms)9572026/10/01 08:35:24 OK 20260905000000_add_claims.sql (3.75ms)9582026/10/01 08:35:24 OK 20260905000000_add_claims.sql (2.93ms)9592026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.08ms)9602026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (3.13ms)9612026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (2.59ms)9622026/10/01 08:35:24 OK 20260905000000_add_claims.sql (3.22ms)9632026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (1.71ms)9642026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200009652026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (2.34ms)9662026/10/01 08:35:24 OK 20260905000000_add_claims.sql (2.44ms)9672026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (2.62ms)9682026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (2.12ms)9692026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (1.41ms)9702026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200009712026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (1.68ms)9722026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200009732026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (2.15ms)9742026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (1.57ms)9752026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200009762026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (2.35ms)9772026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (2.44ms)9782026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (1.63ms)9792026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200009802026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (2.11ms)9812026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (1.57ms)9822026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200009832026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.06ms)9842026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (2.02ms)9852026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.7ms)9862026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.67ms)9872026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.08ms)9882026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200009892026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.65ms)9902026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200009912026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.17ms)9922026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.24ms)9932026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.15ms)9942026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.12ms)9952026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200009962026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.18ms)9972026/10/01 08:35:24 goose: successfully migrated database to version: 202609231200009982026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.88ms)9992026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (2.08ms)10002026/10/01 08:35:24 goose: successfully migrated database to version: 2026092312000010012026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.72ms)10022026/10/01 08:35:24 OK 1_commit_pending_closure.sql (2.27ms)10032026/10/01 08:35:24 OK 3_commit_push.sql (1.09ms)10042026/10/01 08:35:24 goose: up to current file version: 310052026-10-01 08:35:24.972 UTC [475] ERROR: relation "goose_db_version" does not exist at character 3610062026-10-01 08:35:24.972 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10072026/10/01 08:35:24 OK 20260923120000_add_pushes.sql (3.32ms)10082026/10/01 08:35:24 OK 3_commit_push.sql (1.74ms)10092026/10/01 08:35:24 goose: up to current file version: 310102026/10/01 08:35:24 goose: successfully migrated database to version: 2026092312000010112026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.73ms)10122026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.83ms)10132026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.37ms)10142026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.77ms)10152026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.88ms)10162026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.78ms)10172026/10/01 08:35:24 OK 3_commit_push.sql (1.15ms)10182026/10/01 08:35:24 goose: up to current file version: 310192026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.1ms)10202026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.96ms)10212026/10/01 08:35:24 OK 3_commit_push.sql (1.09ms)10222026/10/01 08:35:24 goose: up to current file version: 310232026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.12ms)10242026/10/01 08:35:24 OK 3_commit_push.sql (980.25µs)10252026/10/01 08:35:24 goose: up to current file version: 310262026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.15ms)10272026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.23ms)10282026/10/01 08:35:24 OK 1_commit_pending_closure.sql (1.52ms)10292026/10/01 08:35:24 OK 2_object_stats_trigger.sql (1.42ms)10302026/10/01 08:35:24 OK 3_commit_push.sql (1.42ms)10312026/10/01 08:35:24 goose: up to current file version: 310322026/10/01 08:35:24 OK 2_object_stats_trigger.sql (919.03µs)10332026/10/01 08:35:24 OK 3_commit_push.sql (670.85µs)10342026/10/01 08:35:24 goose: up to current file version: 310352026/10/01 08:35:24 OK 3_commit_push.sql (734.83µs)10362026/10/01 08:35:24 goose: up to current file version: 310372026/10/01 08:35:24 OK 3_commit_push.sql (652.95µs)10382026/10/01 08:35:24 goose: up to current file version: 310392026/10/01 08:35:24 OK 3_commit_push.sql (834.89µs)10402026/10/01 08:35:24 goose: up to current file version: 310412026/10/01 08:35:24 OK 2_object_stats_trigger.sql (909.85µs)10422026/10/01 08:35:24 OK 3_commit_push.sql (618.65µs)10432026/10/01 08:35:24 goose: up to current file version: 310442026/10/01 08:35:24 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1045--- PASS: TestService_AuthMiddleware (0.24s)1046=== CONT TestSweepSkipsRowsLockedByPush10472026/10/01 08:35:24 OK 3_commit_push.sql (558.47µs)10482026/10/01 08:35:24 goose: up to current file version: 310492026/10/01 08:35:24 OK 20241026095416_initial_model.sql (7.78ms)10502026/10/01 08:35:24 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)10512026/10/01 08:35:24 OK 20251218171726_add_pins.sql (2.69ms)10522026/10/01 08:35:24 INFO Received uploads request method=POST path=/api/pending_closures10532026/10/01 08:35:24 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)10542026/10/01 08:35:24 OK 20260905000000_add_claims.sql (3.13ms)10552026/10/01 08:35:24 OK 20260920000000_drop_claims.sql (2.3ms)10562026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.01ms)10572026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000010582026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.06ms)10592026/10/01 08:35:25 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10602026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures10612026/10/01 08:35:25 OK 2_object_stats_trigger.sql (801.55µs)10622026/10/01 08:35:25 OK 3_commit_push.sql (547.85µs)10632026/10/01 08:35:25 goose: up to current file version: 31064--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.27s)1065=== CONT TestServerTLSConfig1066=== RUN TestServerTLSConfig/no_client_CA1067=== PAUSE TestServerTLSConfig/no_client_CA1068=== RUN TestServerTLSConfig/missing_CA_file1069=== PAUSE TestServerTLSConfig/missing_CA_file1070=== RUN TestServerTLSConfig/not_a_PEM_file1071=== PAUSE TestServerTLSConfig/not_a_PEM_file1072=== CONT TestFailedS3DeleteKeepsTombstone1073=== RUN TestPush_RejectsBadRequests/no_roots1074=== PAUSE TestPush_RejectsBadRequests/no_roots1075=== RUN TestPush_RejectsBadRequests/no_objects1076=== PAUSE TestPush_RejectsBadRequests/no_objects1077=== RUN TestPush_RejectsBadRequests/bad_root1078=== PAUSE TestPush_RejectsBadRequests/bad_root1079=== RUN TestPush_RejectsBadRequests/root_not_in_objects1080=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1081=== CONT TestService_NativeMTLS10822026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures10832026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures10842026-10-01 08:35:25.045 UTC [482] ERROR: relation "goose_db_version" does not exist at character 3610852026-10-01 08:35:25.045 UTC [482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10862026/10/01 08:35:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10872026/10/01 08:35:25 INFO Received push request method=POST path=/api/pushes10882026/10/01 08:35:25 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmNhOTc2MDYtMTc1Yi00YTVlLTgyNTUtYWQ1YWE3ZDBkMTRiLjJjM2YxOGU4LTE3OTgtNGZiNC05MWIwLTY5YTkwNThiN2QyOXgxNzkwODQzNzI1MDMzMDc4OTc410892026/10/01 08:35:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmNhOTc2MDYtMTc1Yi00YTVlLTgyNTUtYWQ1YWE3ZDBkMTRiLjJjM2YxOGU4LTE3OTgtNGZiNC05MWIwLTY5YTkwNThiN2QyOXgxNzkwODQzNzI1MDMzMDc4OTc4 parts=11090--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.33s)1091=== CONT TestForceGCDuringPushOffersSweptObject1092=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1093=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1094=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1095=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1096=== CONT TestMetricsInventory10972026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.28ms)10982026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)10992026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.46ms)11002026/10/01 08:35:25 INFO Received push request method=POST path=/api/pushes11012026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)11022026/10/01 08:35:25 INFO Received complete push request method=POST path=/api/pushes/1/complete11032026/10/01 08:35:25 OK 20260905000000_add_claims.sql (2.8ms)11042026/10/01 08:35:25 INFO Received cleanup request method=DELETE path=/api/pending_closures11052026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.3ms)11062026/10/01 08:35:25 INFO Aborted multipart uploads count=111072026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.25ms)11082026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000011092026/10/01 08:35:25 OK 1_commit_pending_closure.sql (1.66ms)1110--- PASS: TestPush_CompleteCommitsEveryRoot (0.35s)1111=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11122026/10/01 08:35:25 OK 2_object_stats_trigger.sql (731.13µs)1113--- PASS: TestMultipartCleanup (0.35s)1114=== CONT TestNARDeduplicationMetadataUploadBug11152026-10-01 08:35:25.081 UTC [491] ERROR: relation "goose_db_version" does not exist at character 3611162026-10-01 08:35:25.081 UTC [491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11172026/10/01 08:35:25 OK 3_commit_push.sql (1.71ms)11182026/10/01 08:35:25 goose: up to current file version: 311192026-10-01 08:35:25.081 UTC [492] ERROR: relation "goose_db_version" does not exist at character 3611202026-10-01 08:35:25.081 UTC [492] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11212026/10/01 08:35:25 INFO Received complete push request method=POST path=/api/pushes/1/complete11222026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures11232026/10/01 08:35:25 INFO Received push request method=POST path=/api/pushes11242026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.75ms)11252026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.15ms)11262026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)11272026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures11282026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)11292026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.09ms)11302026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.29ms)11312026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.69ms)11322026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.53ms)11332026/10/01 08:35:25 INFO Received push request method=POST path=/api/pushes11342026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.77ms)11352026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.65ms)11362026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.36ms)11372026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.48ms)11382026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (7.91ms)11392026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000011402026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (8.43ms)11412026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000011422026/10/01 08:35:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11432026/10/01 08:35:25 OK 1_commit_pending_closure.sql (3.53ms)11442026/10/01 08:35:25 OK 1_commit_pending_closure.sql (3.34ms)11452026/10/01 08:35:25 INFO Signed narinfos id=1 count=11146--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.39s)1147=== CONT TestGCSweepDeliversEachKeyOnce11482026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.75ms)11492026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.4ms)11502026/10/01 08:35:25 OK 3_commit_push.sql (1.23ms)11512026/10/01 08:35:25 goose: up to current file version: 311522026/10/01 08:35:25 OK 3_commit_push.sql (738.61µs)11532026/10/01 08:35:25 goose: up to current file version: 311542026-10-01 08:35:25.132 UTC [498] ERROR: relation "goose_db_version" does not exist at character 3611552026-10-01 08:35:25.132 UTC [498] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11562026/10/01 08:35:25 OK 20241026095416_initial_model.sql (9.71ms)11572026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)11582026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures11592026/10/01 08:35:25 INFO Aborted multipart uploads count=011602026-10-01 08:35:25.153 UTC [501] ERROR: relation "goose_db_version" does not exist at character 3611612026-10-01 08:35:25.153 UTC [501] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11622026/10/01 08:35:25 OK 20251218171726_add_pins.sql (2.96ms)11632026-10-01 08:35:25.153 UTC [502] ERROR: relation "goose_db_version" does not exist at character 3611642026-10-01 08:35:25.153 UTC [502] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11652026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period11662026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)11672026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.38ms)1168--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.43s)1169=== CONT TestCreatePendingClosureRejectsOversizedNAR11702026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures1171--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1172=== CONT TestTombstonedObjectOfferedWithoutWaiting11732026/10/01 08:35:25 INFO Aborted multipart uploads count=011742026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.16ms)11752026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period11762026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.01ms)11772026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000011782026/10/01 08:35:25 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=011792026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.03ms)11802026/10/01 08:35:25 OK 20241026095416_initial_model.sql (8.62ms)11812026/10/01 08:35:25 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=011822026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.54ms)11832026/10/01 08:35:25 OK 20241026095416_initial_model.sql (9.58ms)11842026/10/01 08:35:25 INFO Vacuumed table table=pending_closures11852026/10/01 08:35:25 OK 3_commit_push.sql (1.28ms)11862026/10/01 08:35:25 goose: up to current file version: 311872026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)11882026/10/01 08:35:25 INFO Vacuumed table table=pending_closures11892026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)11902026/10/01 08:35:25 INFO Vacuumed table table=pending_objects11912026/10/01 08:35:25 INFO Vacuumed table table=pending_objects11922026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads11932026/10/01 08:35:25 INFO Received cleanup request method=DELETE path=/api/pending_closures11942026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.18ms)11952026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.31ms)11962026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads11972026/10/01 08:35:25 INFO Vacuumed table table=closures11982026/10/01 08:35:25 INFO Vacuumed table table=objects11992026/10/01 08:35:25 INFO Aborted multipart uploads count=012002026/10/01 08:35:25 INFO Vacuumed table table=closures12012026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (4.03ms)12022026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures12032026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (4.32ms)12042026/10/01 08:35:25 INFO Vacuumed table table=objects12052026/10/01 08:35:25 INFO Received complete push request method=POST path=/api/pushes/2/complete12062026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.75ms)12072026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.48ms)1208--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.45s)1209=== CONT TestCacheConfigHandlerMaxNarSize12102026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.27ms)1211--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1212=== CONT TestGCSweepSkipsPendingObjects1213--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.45s)12142026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (1.9ms)1215=== CONT TestGenerateLandingPage1216--- PASS: TestGenerateLandingPage (0.00s)1217=== CONT TestDeduplicatedObjectsRecordedAsPending12182026/10/01 08:35:25 INFO Received cleanup request method=DELETE path=/api/pending_closures12192026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.83ms)12202026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000012212026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.57ms)12222026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000012232026/10/01 08:35:25 INFO Aborted multipart uploads count=112242026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.32ms)12252026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.93ms)12262026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.31ms)12272026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.21ms)12282026/10/01 08:35:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12292026/10/01 08:35:25 OK 3_commit_push.sql (971.53µs)12302026/10/01 08:35:25 goose: up to current file version: 312312026-10-01 08:35:25.191 UTC [463] ERROR: Closure does not exist: id=112322026-10-01 08:35:25.191 UTC [463] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE12332026-10-01 08:35:25.191 UTC [463] STATEMENT: -- name: CommitPendingClosure :exec1234 SELECT commit_pending_closure($1::bigint)1235 12362026/10/01 08:35:25 OK 3_commit_push.sql (669.21µs)12372026/10/01 08:35:25 goose: up to current file version: 31238--- PASS: TestService_cleanupPendingClosuresHandler (0.46s)1239=== CONT TestService_readinessHandler12402026-10-01 08:35:25.194 UTC [510] ERROR: relation "goose_db_version" does not exist at character 3612412026-10-01 08:35:25.194 UTC [510] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12422026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures12432026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures12442026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures12452026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures12462026/10/01 08:35:25 OK 20241026095416_initial_model.sql (18.03ms)12472026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)12482026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.82ms)12492026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)12502026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.17ms)12512026/10/01 08:35:25 INFO Received push request method=POST path=/api/pushes12522026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.73ms)12532026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.59ms)12542026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000012552026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.54ms)12562026-10-01 08:35:25.239 UTC [515] ERROR: relation "goose_db_version" does not exist at character 3612572026-10-01 08:35:25.239 UTC [515] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12582026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.41ms)12592026/10/01 08:35:25 OK 3_commit_push.sql (996.79µs)12602026/10/01 08:35:25 goose: up to current file version: 31261--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.52s)12622026/10/01 08:35:25 OK 20241026095416_initial_model.sql (8.32ms)1263=== CONT TestClientIntegration12642026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.15ms)12652026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.23ms)12662026-10-01 08:35:25.262 UTC [519] ERROR: relation "goose_db_version" does not exist at character 3612672026-10-01 08:35:25.262 UTC [519] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12682026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)12692026-10-01 08:35:25.265 UTC [521] ERROR: relation "goose_db_version" does not exist at character 3612702026-10-01 08:35:25.265 UTC [521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12712026-10-01 08:35:25.265 UTC [522] ERROR: relation "goose_db_version" does not exist at character 3612722026-10-01 08:35:25.265 UTC [522] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1273--- PASS: TestReadProxyRangeRequest (0.53s)1274=== CONT TestService_healthCheckHandler12752026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.36ms)12762026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.27ms)12772026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.33ms)12782026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000012792026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.47ms)12802026/10/01 08:35:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12812026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.46ms)12822026/10/01 08:35:25 OK 3_commit_push.sql (1.45ms)12832026/10/01 08:35:25 goose: up to current file version: 312842026/10/01 08:35:25 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1285--- PASS: TestCompleteMultipartUnregistered (0.54s)1286=== CONT TestClientErrorHandling1287=== RUN TestClientErrorHandling/InvalidStorePath1288=== PAUSE TestClientErrorHandling/InvalidStorePath1289=== RUN TestClientErrorHandling/InvalidAuthToken1290=== PAUSE TestClientErrorHandling/InvalidAuthToken1291=== RUN TestClientErrorHandling/ServerNotAvailable1292=== PAUSE TestClientErrorHandling/ServerNotAvailable1293=== CONT TestGracefulShutdownDrainsInflight12942026/10/01 08:35:25 INFO Starting HTTP server address=127.0.0.1:3688912952026/10/01 08:35:25 INFO Shutdown signal received, draining in-flight requests timeout=10s12962026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.43ms)12972026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.98ms)12982026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)12992026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.46ms)13002026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.14ms)13012026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)13022026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.88ms)13032026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.54ms)13042026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.43ms)13052026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)13062026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.73ms)13072026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)13082026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.68ms)13092026/10/01 08:35:25 OK 20260905000000_add_claims.sql (9.39ms)13102026/10/01 08:35:25 OK 20260905000000_add_claims.sql (9.83ms)13112026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (8.44ms)13122026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (3.06ms)13132026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.71ms)13142026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.53ms)13152026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000013162026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.67ms)13172026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000013182026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.25ms)13192026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000013202026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.48ms)13212026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.22ms)13222026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.17ms)13232026/10/01 08:35:25 OK 2_object_stats_trigger.sql (2.05ms)13242026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.67ms)13252026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.62ms)13262026/10/01 08:35:25 OK 3_commit_push.sql (1.49ms)13272026/10/01 08:35:25 goose: up to current file version: 313282026/10/01 08:35:25 OK 3_commit_push.sql (1.53ms)13292026/10/01 08:35:25 goose: up to current file version: 313302026/10/01 08:35:25 OK 3_commit_push.sql (1.5ms)13312026/10/01 08:35:25 goose: up to current file version: 31332--- PASS: TestReadRedirectUsesPublicS3URL (0.58s)1333=== CONT TestClientCADerivations13342026-10-01 08:35:25.324 UTC [527] ERROR: relation "goose_db_version" does not exist at character 3613352026-10-01 08:35:25.324 UTC [527] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1336--- PASS: TestReadRedirectKeepsNarinfoProxied (0.59s)1337=== CONT TestGCTaskStore_Fail1338--- PASS: TestGCTaskStore_Fail (0.00s)1339=== CONT TestGCTaskStore_PhaseUpdates1340--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1341=== CONT TestCacheConfigHandler1342=== RUN TestCacheConfigHandler/full_config,_no_issuer1343=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1344=== RUN TestCacheConfigHandler/no_cache_url_configured1345=== PAUSE TestCacheConfigHandler/no_cache_url_configured1346=== RUN TestCacheConfigHandler/no_signing_keys1347=== PAUSE TestCacheConfigHandler/no_signing_keys1348=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1349=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1350=== CONT TestGCTaskStore_CompletedAllowsNewTask1351--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1352=== CONT TestClientMultipleUploads13532026/10/01 08:35:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13542026-10-01 08:35:25.341 UTC [531] ERROR: relation "goose_db_version" does not exist at character 3613552026-10-01 08:35:25.341 UTC [531] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13562026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.36ms)13572026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)1358--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1359=== CONT TestService_ReadScope_PublicByDefault13602026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.66ms)13612026/10/01 08:35:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZmNhOTc2MDYtMTc1Yi00YTVlLTgyNTUtYWQ1YWE3ZDBkMTRiLjk2ZmIyNDQ0LTZiOWYtNDNkYy1iMmFkLTAzNDZhM2JhMzdhOXgxNzkwODQzNzI1MDQ1NDY3OTg5 parts=1013622026/10/01 08:35:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13632026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)1364--- PASS: TestGetExistingObjectsLocksRows (0.56s)1365=== CONT TestGCTaskStore_GetReturnsLatest1366--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1367=== CONT TestResolveDBConnectionString13682026/10/01 08:35:25 INFO Completed upload id=11369=== RUN TestResolveDBConnectionString/flag_wins1370=== PAUSE TestResolveDBConnectionString/flag_wins1371=== RUN TestResolveDBConnectionString/file_when_flag_empty1372=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1373=== RUN TestResolveDBConnectionString/missing_file_is_an_error1374=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1375=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1376=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1377=== RUN TestResolveDBConnectionString/nothing_configured1378=== PAUSE TestResolveDBConnectionString/nothing_configured1379=== CONT TestGCTaskStore_GetEmpty1380--- PASS: TestGCTaskStore_GetEmpty (0.00s)1381=== CONT TestPushDedupSurvivesConcurrentGC13822026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures13832026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.38ms)13842026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.18ms)13852026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures13862026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.35ms)13872026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.26ms)13882026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000013892026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)13902026/10/01 08:35:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13912026/10/01 08:35:25 WARN Found objects in DB but missing from S3, will re-upload count=113922026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.07ms)1393--- PASS: TestService_verifyS3Integrity (0.63s)1394=== CONT TestCacheStatsHandler13952026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.66ms)13962026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.07ms)13972026/10/01 08:35:25 OK 3_commit_push.sql (1.47ms)13982026/10/01 08:35:25 goose: up to current file version: 313992026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)14002026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.14ms)14012026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.57ms)14022026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.19ms)14032026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000014042026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.08ms)14052026/10/01 08:35:25 INFO Aborted multipart uploads count=014062026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.62ms)14072026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period14082026/10/01 08:35:25 OK 3_commit_push.sql (7.12ms)14092026/10/01 08:35:25 goose: up to current file version: 314102026-10-01 08:35:25.386 UTC [559] ERROR: relation "goose_db_version" does not exist at character 3614112026-10-01 08:35:25.386 UTC [559] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1412--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.52s)1413=== CONT TestGCMetrics14142026/10/01 08:35:25 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=014152026/10/01 08:35:25 INFO Vacuumed table table=pending_closures14162026/10/01 08:35:25 INFO Vacuumed table table=pending_objects14172026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads14182026/10/01 08:35:25 INFO Vacuumed table table=closures14192026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.1ms)14202026/10/01 08:35:25 INFO Vacuumed table table=objects14212026-10-01 08:35:25.407 UTC [563] ERROR: relation "goose_db_version" does not exist at character 3614222026-10-01 08:35:25.407 UTC [563] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14232026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (3.27ms)1424--- PASS: TestSweepRechecksPendingAfterLocking (0.67s)1425=== CONT TestClientFallsBackToClosures14262026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.96ms)14272026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)14282026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.01ms)14292026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.35ms)14302026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.41ms)14312026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000014322026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.96ms)14332026/10/01 08:35:25 INFO Aborted multipart uploads count=014342026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.28ms)14352026/10/01 08:35:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14362026-10-01 08:35:25.426 UTC [568] ERROR: relation "goose_db_version" does not exist at character 3614372026-10-01 08:35:25.426 UTC [568] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14382026/10/01 08:35:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1439--- PASS: TestService_NativeMTLS (0.42s)1440=== CONT TestGCBugBareHashReferences14412026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)14422026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period14432026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.9ms)14442026/10/01 08:35:25 OK 3_commit_push.sql (905.99µs)14452026/10/01 08:35:25 goose: up to current file version: 314462026/10/01 08:35:25 OK 20251218171726_add_pins.sql (2.9ms)14472026-10-01 08:35:25.431 UTC [569] ERROR: relation "goose_db_version" does not exist at character 3614482026-10-01 08:35:25.431 UTC [569] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14492026/10/01 08:35:25 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=014502026/10/01 08:35:25 INFO Vacuumed table table=pending_closures14512026/10/01 08:35:25 INFO Vacuumed table table=pending_objects14522026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads14532026/10/01 08:35:25 INFO Vacuumed table table=closures14542026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)14552026/10/01 08:35:25 INFO Vacuumed table table=objects14562026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.18ms)14572026-10-01 08:35:25.439 UTC [572] ERROR: relation "goose_db_version" does not exist at character 3614582026-10-01 08:35:25.439 UTC [572] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14592026/10/01 08:35:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14602026/10/01 08:35:25 OK 20241026095416_initial_model.sql (13.93ms)14612026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (10.21ms)14622026/10/01 08:35:25 INFO Aborted multipart uploads count=014632026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)1464--- PASS: TestPushWaitsForSweepHoldingRow (0.72s)1465=== CONT TestClientPushesUseOnePush14662026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period14672026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (3.33ms)14682026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000014692026/10/01 08:35:25 OK 20241026095416_initial_model.sql (13.16ms)14702026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures14712026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)14722026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.88ms)14732026/10/01 08:35:25 OK 20251218171726_add_pins.sql (4.61ms)14742026/10/01 08:35:25 OK 2_object_stats_trigger.sql (2.04ms)14752026/10/01 08:35:25 OK 3_commit_push.sql (1.81ms)14762026/10/01 08:35:25 goose: up to current file version: 314772026/10/01 08:35:25 OK 20251218171726_add_pins.sql (5.72ms)14782026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (6.5ms)14792026/10/01 08:35:25 OK 20241026095416_initial_model.sql (13.16ms)14802026/10/01 08:35:25 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=014812026/10/01 08:35:25 INFO Vacuumed table table=pending_closures14822026/10/01 08:35:25 INFO Vacuumed table table=pending_objects14832026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads14842026/10/01 08:35:25 INFO Vacuumed table table=closures14852026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (3.2ms)14862026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.96ms)14872026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (5.37ms)14882026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (3.22ms)14892026/10/01 08:35:25 INFO Vacuumed table table=objects14902026/10/01 08:35:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZmNhOTc2MDYtMTc1Yi00YTVlLTgyNTUtYWQ1YWE3ZDBkMTRiLmU2ODNkZjgxLTJhMjAtNDA1ZS05NzdmLTY1YTEzOGRmNmQyOHgxNzkwODQzNzI1MDk1MzUwMTc2 parts=1214912026/10/01 08:35:25 OK 20251218171726_add_pins.sql (5.11ms)14922026/10/01 08:35:25 OK 20260905000000_add_claims.sql (5.19ms)1493--- PASS: TestSweepSkipsRowsLockedByPush (0.50s)1494=== CONT TestPinProtectsFromGC1495--- PASS: TestRedundantMultipartUpload (0.74s)1496=== CONT TestClientSharedPathCommittedMidPush14972026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.82ms)14982026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000014992026-10-01 08:35:25.472 UTC [575] ERROR: relation "goose_db_version" does not exist at character 3615002026-10-01 08:35:25.472 UTC [575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15012026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (3.67ms)15022026/10/01 08:35:25 OK 1_commit_pending_closure.sql (3.21ms)15032026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (5.99ms)15042026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.9ms)15052026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (3.2ms)15062026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000015072026/10/01 08:35:25 OK 3_commit_push.sql (2.48ms)15082026/10/01 08:35:25 goose: up to current file version: 315092026/10/01 08:35:25 OK 20260905000000_add_claims.sql (4.17ms)15102026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.78ms)15112026/10/01 08:35:25 OK 2_object_stats_trigger.sql (2.17ms)15122026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.69ms)15132026/10/01 08:35:25 OK 3_commit_push.sql (5.46ms)15142026/10/01 08:35:25 goose: up to current file version: 315152026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (6.42ms)15162026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000015172026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.86ms)15182026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.23ms)15192026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.05ms)15202026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.66ms)15212026/10/01 08:35:25 OK 3_commit_push.sql (1.14ms)15222026/10/01 08:35:25 goose: up to current file version: 315232026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.62ms)15242026/10/01 08:35:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15252026-10-01 08:35:25.499 UTC [580] ERROR: relation "goose_db_version" does not exist at character 3615262026-10-01 08:35:25.499 UTC [580] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15272026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)1528--- PASS: TestMetricsInventory (0.44s)1529=== CONT TestLeadElectsOneAndHandsOver15302026/10/01 08:35:25 OK 20260905000000_add_claims.sql (4.3ms)15312026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (3.21ms)15322026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.5ms)15332026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000015342026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures15352026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.2ms)15362026/10/01 08:35:25 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZmNhOTc2MDYtMTc1Yi00YTVlLTgyNTUtYWQ1YWE3ZDBkMTRiLmY1OWFkNTZjLThmMzItNGQ3NC1hM2E2LTgwZDA0ZjU2YmE0MngxNzkwODQzNzI1MjAyOTc4ODQx parts=1015372026/10/01 08:35:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15382026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.99ms)15392026-10-01 08:35:25.515 UTC [583] ERROR: relation "goose_db_version" does not exist at character 3615402026-10-01 08:35:25.515 UTC [583] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15412026/10/01 08:35:25 OK 3_commit_push.sql (1.28ms)15422026/10/01 08:35:25 goose: up to current file version: 315432026/10/01 08:35:25 INFO Completed upload id=115442026/10/01 08:35:25 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015452026/10/01 08:35:25 OK 20241026095416_initial_model.sql (18.2ms)15462026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures15472026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)15482026/10/01 08:35:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures15492026/10/01 08:35:25 OK 20251218171726_add_pins.sql (4.07ms)15502026/10/01 08:35:25 INFO Aborted multipart uploads count=015512026-10-01 08:35:25.535 UTC [585] ERROR: relation "goose_db_version" does not exist at character 3615522026-10-01 08:35:25.535 UTC [585] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15532026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)15542026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.31ms)15552026/10/01 08:35:25 INFO Aborted multipart uploads count=015562026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period15572026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.56ms)15582026/10/01 08:35:25 OK 20260905000000_add_claims.sql (4.25ms)15592026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.72ms)15602026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.56ms)15612026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (1.94ms)15622026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000015632026/10/01 08:35:25 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=015642026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)15652026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.14ms)15662026/10/01 08:35:25 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15672026/10/01 08:35:25 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."15682026/10/01 08:35:25 INFO Vacuumed table table=pending_closures15692026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.69ms)15702026/10/01 08:35:25 INFO Vacuumed table table=pending_objects15712026/10/01 08:35:25 OK 3_commit_push.sql (1.03ms)15722026/10/01 08:35:25 goose: up to current file version: 31573--- PASS: TestFailedS3DeleteKeepsTombstone (0.55s)1574=== CONT TestClientWithDependencies15752026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.57ms)15762026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.63ms)15772026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads15782026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.52ms)15792026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)15802026-10-01 08:35:25.554 UTC [588] ERROR: relation "goose_db_version" does not exist at character 3615812026-10-01 08:35:25.554 UTC [588] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15822026/10/01 08:35:25 INFO Vacuumed table table=closures15832026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.34ms)15842026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000015852026-10-01 08:35:25.556 UTC [589] ERROR: relation "goose_db_version" does not exist at character 3615862026-10-01 08:35:25.556 UTC [589] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15872026/10/01 08:35:25 INFO Vacuumed table table=objects15882026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.9ms)15892026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.54ms)15902026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.33ms)15912026/10/01 08:35:25 OK 3_commit_push.sql (1.75ms)15922026/10/01 08:35:25 goose: up to current file version: 315932026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)15942026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.47ms)15952026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (3.22ms)15962026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.16ms)15972026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200001598=== NAME TestNARDeduplicationMetadataUploadBug1599 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2071646817/001/store/dqbygylghcpgr2y05q75axh7zzbvc2i1-file1.txt16002026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.37ms)16012026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)16022026/10/01 08:35:25 OK 1_commit_pending_closure.sql (3.22ms)16032026/10/01 08:35:25 OK 20241026095416_initial_model.sql (12.12ms)16042026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.51ms)16052026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures16062026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)16072026/10/01 08:35:25 OK 3_commit_push.sql (1.26ms)16082026/10/01 08:35:25 goose: up to current file version: 316092026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.56ms)16102026/10/01 08:35:25 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001611--- PASS: TestService_createPendingClosureHandler (0.85s)1612=== CONT TestGCTaskStore_ConflictDifferentParams1613--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1614=== CONT TestService_ReadAuthMiddleware16152026-10-01 08:35:25.580 UTC [610] ERROR: relation "goose_db_version" does not exist at character 3616162026-10-01 08:35:25.580 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16172026/10/01 08:35:25 INFO Aborted multipart uploads count=016182026/10/01 08:35:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16192026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.98ms)16202026/10/01 08:35:25 OK 20251218171726_add_pins.sql (4.21ms)16212026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period1622--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.42s)1623=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16242026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.48ms)16252026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.66ms)16262026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (1.99ms)16272026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (1.85ms)16282026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000016292026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.71ms)16302026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.53ms)16312026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.66ms)16322026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.69ms)16332026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.2ms)16342026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000016352026/10/01 08:35:25 OK 3_commit_push.sql (1.08ms)16362026/10/01 08:35:25 goose: up to current file version: 316372026/10/01 08:35:25 WARN readiness check failed error="closed pool"1638--- PASS: TestService_readinessHandler (0.40s)1639=== CONT TestLeadEndsOnShutdown16402026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.89ms)16412026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.24ms)16422026/10/01 08:35:25 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=016432026/10/01 08:35:25 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZmNhOTc2MDYtMTc1Yi00YTVlLTgyNTUtYWQ1YWE3ZDBkMTRiLjQ2NzlhMDE2LWRiOGYtNGUwZS05ODFhLTRjYjRmM2RmZWIzNHgxNzkwODQzNzI1MjIyMzIxNjE0 parts=1216442026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.61ms)16452026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)16462026/10/01 08:35:25 INFO Vacuumed table table=pending_closures16472026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures16482026/10/01 08:35:25 INFO Vacuumed table table=pending_objects16492026/10/01 08:35:25 OK 3_commit_push.sql (1.37ms)16502026/10/01 08:35:25 goose: up to current file version: 316512026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads16522026/10/01 08:35:25 INFO Vacuumed table table=closures16532026/10/01 08:35:25 OK 20251218171726_add_pins.sql (9.1ms)1654--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.87s)1655=== CONT TestService_AuthMiddleware_OIDC16562026/10/01 08:35:25 INFO Vacuumed table table=objects1657--- PASS: TestGCSweepDeliversEachKeyOnce (0.49s)1658=== CONT TestGCTaskStore_DeduplicateSameParams1659--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1660=== CONT TestReadProxyNarinfoAlreadyDecompressed16612026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)16622026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.03ms)16632026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.15ms)16642026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.17ms)16652026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000016662026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.2ms)16672026-10-01 08:35:25.623 UTC [637] ERROR: relation "goose_db_version" does not exist at character 3616682026-10-01 08:35:25.623 UTC [637] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16692026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures16702026/10/01 08:35:25 OK 2_object_stats_trigger.sql (2.22ms)16712026/10/01 08:35:25 OK 3_commit_push.sql (1.23ms)16722026/10/01 08:35:25 goose: up to current file version: 31673--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.45s)1674=== CONT TestService_AuthMiddleware_MTLSProxyHeader16752026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.49ms)16762026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)16772026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures16782026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.49ms)16792026/10/01 08:35:25 INFO Received push request method=POST path=/api/pushes16802026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)16812026/10/01 08:35:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16822026/10/01 08:35:25 INFO Uploading dqbygylghcpgr2y05q75axh7zzbvc2i1-file1.txt (160B)16832026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.05ms)16842026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (1.97ms)16852026/10/01 08:35:25 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16862026/10/01 08:35:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16872026/10/01 08:35:25 WARN Failed to register uploaded object key=dqbygylghcpgr2y05q75axh7zzbvc2i1.ls error="server returned 404: 404 page not found\n"16882026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.27ms)16892026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000016902026/10/01 08:35:25 INFO Signed narinfos id=1 count=116912026/10/01 08:35:25 INFO Uploading 1 narinfos16922026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.62ms)16932026/10/01 08:35:25 INFO Aborted multipart uploads count=016942026-10-01 08:35:25.660 UTC [658] ERROR: relation "goose_db_version" does not exist at character 3616952026-10-01 08:35:25.660 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16962026/10/01 08:35:25 INFO Received complete push request method=POST path=/api/pushes/1/complete16972026/10/01 08:35:25 WARN Failed to register uploaded object key=dqbygylghcpgr2y05q75axh7zzbvc2i1.narinfo error="server returned 404: 404 page not found\n"16982026-10-01 08:35:25.662 UTC [659] ERROR: relation "goose_db_version" does not exist at character 3616992026-10-01 08:35:25.662 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17002026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period17012026/10/01 08:35:25 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=017022026/10/01 08:35:25 OK 2_object_stats_trigger.sql (7.46ms)17032026/10/01 08:35:25 INFO Upload complete. (60ms)17042026/10/01 08:35:25 OK 3_commit_push.sql (1.62ms)17052026/10/01 08:35:25 goose: up to current file version: 317062026/10/01 08:35:25 INFO Vacuumed table table=pending_closures1707=== NAME TestNARDeduplicationMetadataUploadBug1708 metadata_upload_test.go:54: Retrieved narinfo from S3:1709 StorePath: /build/TestNARDeduplicationMetadataUploadBug2071646817/001/store/dqbygylghcpgr2y05q75axh7zzbvc2i1-file1.txt1710 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1711 Compression: zstd1712 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1713 NarSize: 1601714 References: 1715 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17162026/10/01 08:35:25 INFO Vacuumed table table=pending_objects17172026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads17182026/10/01 08:35:25 INFO Vacuumed table table=closures1719 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1720 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1721 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}17222026/10/01 08:35:25 INFO Vacuumed table table=objects1723--- PASS: TestService_healthCheckHandler (0.41s)1724=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle17252026/10/01 08:35:25 OK 20241026095416_initial_model.sql (9.78ms)1726--- PASS: TestGCSweepSkipsPendingObjects (0.50s)1727=== CONT TestReadRedirectNar17282026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.34ms)17292026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)17302026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)17312026-10-01 08:35:25.683 UTC [662] ERROR: relation "goose_db_version" does not exist at character 3617322026-10-01 08:35:25.683 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17332026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.07ms)17342026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.16ms)17352026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)17362026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)17372026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.92ms)17382026-10-01 08:35:25.693 UTC [667] ERROR: relation "goose_db_version" does not exist at character 3617392026-10-01 08:35:25.693 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17402026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.54ms)17412026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.54ms)17422026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.47ms)17432026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.33ms)17442026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000017452026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.51ms)17462026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000017472026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.92ms)17482026/10/01 08:35:25 OK 20241026095416_initial_model.sql (12ms)17492026/10/01 08:35:25 OK 1_commit_pending_closure.sql (1.93ms)1750=== NAME TestClientIntegration1751 client_integration_test.go:286: Created store path: /build/TestClientIntegration3810040534/002/store/hckckbd4881pzsr8hrhp3vfhy2ajxlhq-test-file.txt17522026/10/01 08:35:25 OK 2_object_stats_trigger.sql (960.15µs)17532026/10/01 08:35:25 OK 2_object_stats_trigger.sql (959.95µs)17542026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)17552026/10/01 08:35:25 OK 3_commit_push.sql (844.97µs)17562026/10/01 08:35:25 goose: up to current file version: 317572026/10/01 08:35:25 OK 3_commit_push.sql (1.13ms)17582026/10/01 08:35:25 goose: up to current file version: 317592026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.8ms)1760=== NAME TestNARDeduplicationMetadataUploadBug1761 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2071646817/001/store/a697ixq4m643w8i3sw6pzs3540qpqfi3-file2.txt17622026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)17632026-10-01 08:35:25.710 UTC [702] ERROR: relation "goose_db_version" does not exist at character 3617642026-10-01 08:35:25.710 UTC [702] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17652026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.74ms)17662026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)17672026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.18ms)17682026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.41ms)17692026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.53ms)17702026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (1.98ms)17712026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000017722026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)17732026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.31ms)17742026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.23ms)17752026/10/01 08:35:25 OK 3_commit_push.sql (1.03ms)17762026/10/01 08:35:25 goose: up to current file version: 317772026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.37ms)17782026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.28ms)17792026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.03ms)17802026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)17812026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.28ms)17822026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200001783--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.65s)1784=== CONT TestIsValidUploadKey1785=== RUN TestIsValidUploadKey/narinfo1786=== PAUSE TestIsValidUploadKey/narinfo1787=== RUN TestIsValidUploadKey/nar_zst1788=== PAUSE TestIsValidUploadKey/nar_zst1789=== RUN TestIsValidUploadKey/nar_xz1790=== PAUSE TestIsValidUploadKey/nar_xz1791=== RUN TestIsValidUploadKey/nar_plain1792=== PAUSE TestIsValidUploadKey/nar_plain1793=== RUN TestIsValidUploadKey/listing1794=== PAUSE TestIsValidUploadKey/listing1795=== RUN TestIsValidUploadKey/build_log1796=== PAUSE TestIsValidUploadKey/build_log1797=== RUN TestIsValidUploadKey/build_log_home-manager_file1798=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1799=== RUN TestIsValidUploadKey/build_log_plus_in_name1800=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1801=== RUN TestIsValidUploadKey/build_log_question_mark1802=== PAUSE TestIsValidUploadKey/build_log_question_mark1803=== RUN TestIsValidUploadKey/build_log_equals1804=== PAUSE TestIsValidUploadKey/build_log_equals1805=== RUN TestIsValidUploadKey/realisation1806=== PAUSE TestIsValidUploadKey/realisation1807=== RUN TestIsValidUploadKey/realisation_plus_in_output1808=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1809=== RUN TestIsValidUploadKey/nix-cache-info1810=== PAUSE TestIsValidUploadKey/nix-cache-info1811=== RUN TestIsValidUploadKey/index.html1812=== PAUSE TestIsValidUploadKey/index.html1813=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1814=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1815=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1816=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1817=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1818=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1819=== RUN TestIsValidUploadKey/traversal1820=== PAUSE TestIsValidUploadKey/traversal1821=== RUN TestIsValidUploadKey/traversal_nar1822=== PAUSE TestIsValidUploadKey/traversal_nar1823=== RUN TestIsValidUploadKey/absolute1824=== PAUSE TestIsValidUploadKey/absolute1825=== RUN TestIsValidUploadKey/empty_key1826=== PAUSE TestIsValidUploadKey/empty_key1827=== RUN TestIsValidUploadKey/unknown_type1828=== PAUSE TestIsValidUploadKey/unknown_type1829=== CONT TestReadProxyDisabled18302026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.22ms)18312026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.11ms)18322026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.23ms)18332026/10/01 08:35:25 OK 3_commit_push.sql (1.21ms)18342026/10/01 08:35:25 goose: up to current file version: 318352026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.23ms)1836--- PASS: TestService_ReadScope_PublicByDefault (0.39s)1837=== CONT TestProxyWriteTimeout1838=== RUN TestProxyWriteTimeout/narinfo1839=== PAUSE TestProxyWriteTimeout/narinfo1840=== RUN TestProxyWriteTimeout/1_GiB_nar1841=== PAUSE TestProxyWriteTimeout/1_GiB_nar1842=== RUN TestProxyWriteTimeout/10_GiB_nar1843=== PAUSE TestProxyWriteTimeout/10_GiB_nar1844=== RUN TestProxyWriteTimeout/unknown_size1845=== PAUSE TestProxyWriteTimeout/unknown_size1846=== CONT TestService_RequireScope_OIDC18472026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.7ms)18482026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.49ms)18492026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.24ms)18502026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000018512026/10/01 08:35:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42831/oidc18522026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.13ms)18532026/10/01 08:35:25 OK 2_object_stats_trigger.sql (2.19ms)18542026/10/01 08:35:25 OK 3_commit_push.sql (1.33ms)18552026/10/01 08:35:25 goose: up to current file version: 318562026-10-01 08:35:25.754 UTC [763] ERROR: relation "goose_db_version" does not exist at character 3618572026-10-01 08:35:25.754 UTC [763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18582026-10-01 08:35:25.756 UTC [770] ERROR: relation "goose_db_version" does not exist at character 3618592026-10-01 08:35:25.756 UTC [770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1860=== NAME TestClientMultipleUploads1861 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2762872033/001/store/51nhmv60hh2h080iws9jh57a4dpdysqc-test-file-0.txt18622026/10/01 08:35:25 INFO Received push request method=POST path=/api/pushes18632026/10/01 08:35:25 INFO Received push request method=POST path=/api/pushes18642026/10/01 08:35:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18652026/10/01 08:35:25 INFO Uploading hckckbd4881pzsr8hrhp3vfhy2ajxlhq-test-file.txt (152B)18662026/10/01 08:35:25 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1867=== NAME TestClientCADerivations1868 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3910703512/001/store/h1g11qgbzyf48bcja9ndnpkw51yhi2sp-ca-test18692026/10/01 08:35:25 OK 20241026095416_initial_model.sql (9.09ms)18702026/10/01 08:35:25 WARN Failed to register uploaded object key=hckckbd4881pzsr8hrhp3vfhy2ajxlhq.ls error="server returned 404: 404 page not found\n"18712026/10/01 08:35:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18722026/10/01 08:35:25 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18732026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)18742026/10/01 08:35:25 INFO Signed narinfos id=1 count=118752026/10/01 08:35:25 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18762026/10/01 08:35:25 INFO Uploading 1 narinfos18772026/10/01 08:35:25 INFO Signed narinfos id=2 count=118782026/10/01 08:35:25 OK 20241026095416_initial_model.sql (12.52ms)18792026/10/01 08:35:25 INFO Uploading 1 narinfos18802026/10/01 08:35:25 WARN Failed to register uploaded object key=a697ixq4m643w8i3sw6pzs3540qpqfi3.ls error="server returned 404: 404 page not found\n"18812026/10/01 08:35:25 INFO Received complete push request method=POST path=/api/pushes/1/complete18822026/10/01 08:35:25 WARN Failed to register uploaded object key=hckckbd4881pzsr8hrhp3vfhy2ajxlhq.narinfo error="server returned 404: 404 page not found\n"18832026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)18842026/10/01 08:35:25 OK 20251218171726_add_pins.sql (4.09ms)18852026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures18862026/10/01 08:35:25 INFO Received complete push request method=POST path=/api/pushes/2/complete18872026/10/01 08:35:25 WARN Failed to register uploaded object key=a697ixq4m643w8i3sw6pzs3540qpqfi3.narinfo error="server returned 404: 404 page not found\n"18882026/10/01 08:35:25 INFO Upload complete. (40ms)18892026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.32ms)18902026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)1891=== NAME TestNARDeduplicationMetadataUploadBug1892 metadata_upload_test.go:76: Retrieved narinfo from S3:1893 StorePath: /build/TestNARDeduplicationMetadataUploadBug2071646817/001/store/a697ixq4m643w8i3sw6pzs3540qpqfi3-file2.txt1894 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1895 Compression: zstd1896 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1897 NarSize: 1601898 References: 1899 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1900 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1901 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1902 {"version":1,"root":{"type":"regular","size":44}}19032026/10/01 08:35:25 INFO Upload complete. (56ms)19042026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)19052026/10/01 08:35:25 OK 20260905000000_add_claims.sql (4.1ms)1906--- PASS: TestCacheStatsHandler (0.43s)1907=== CONT TestReadProxyHead1908--- PASS: TestNARDeduplicationMetadataUploadBug (0.71s)1909=== CONT TestParseSingleRange1910=== RUN TestParseSingleRange/none1911=== PAUSE TestParseSingleRange/none1912=== RUN TestParseSingleRange/unknown_unit1913=== PAUSE TestParseSingleRange/unknown_unit1914=== RUN TestParseSingleRange/multi-range_ignored1915=== PAUSE TestParseSingleRange/multi-range_ignored1916=== RUN TestParseSingleRange/malformed_no_dash1917=== PAUSE TestParseSingleRange/malformed_no_dash1918=== RUN TestParseSingleRange/malformed_both_empty1919=== PAUSE TestParseSingleRange/malformed_both_empty1920=== RUN TestParseSingleRange/malformed_end_before_start1921=== PAUSE TestParseSingleRange/malformed_end_before_start1922=== RUN TestParseSingleRange/closed1923=== PAUSE TestParseSingleRange/closed1924=== RUN TestParseSingleRange/open-ended1925=== PAUSE TestParseSingleRange/open-ended1926=== RUN TestParseSingleRange/end_clamped_to_size1927=== PAUSE TestParseSingleRange/end_clamped_to_size1928=== RUN TestParseSingleRange/suffix1929=== PAUSE TestParseSingleRange/suffix1930=== RUN TestParseSingleRange/suffix_exceeds_size1931=== PAUSE TestParseSingleRange/suffix_exceeds_size1932=== RUN TestParseSingleRange/single_byte1933=== PAUSE TestParseSingleRange/single_byte1934=== RUN TestParseSingleRange/start_past_EOF1935=== PAUSE TestParseSingleRange/start_past_EOF1936=== RUN TestParseSingleRange/start_far_past_EOF1937=== PAUSE TestParseSingleRange/start_far_past_EOF1938=== CONT TestReadProxyInvalidPath19392026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.73ms)19402026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.39ms)19412026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.39ms)19422026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000019432026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.58ms)1944=== NAME TestClientMultipleUploads1945 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2762872033/001/store/r5sz9740661kzrcy0zclqalsrhiqb8n6-test-file-1.txt19462026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.13ms)19472026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.5ms)19482026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000019492026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.53ms)19502026/10/01 08:35:25 OK 3_commit_push.sql (1.64ms)19512026/10/01 08:35:25 goose: up to current file version: 319522026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.71ms)19532026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.57ms)19542026/10/01 08:35:25 OK 3_commit_push.sql (666.59µs)19552026/10/01 08:35:25 goose: up to current file version: 31956=== NAME TestClientCADerivations1957 client_ca_test.go:139: Found 1 dependencies (including self)19582026-10-01 08:35:25.805 UTC [856] ERROR: relation "goose_db_version" does not exist at character 3619592026-10-01 08:35:25.805 UTC [856] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19602026/10/01 08:35:25 INFO Aborted multipart uploads count=019612026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period19622026/10/01 08:35:25 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=019632026-10-01 08:35:25.814 UTC [874] ERROR: relation "goose_db_version" does not exist at character 3619642026-10-01 08:35:25.814 UTC [874] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19652026/10/01 08:35:25 INFO Vacuumed table table=pending_closures19662026/10/01 08:35:25 INFO Vacuumed table table=pending_objects19672026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads19682026/10/01 08:35:25 INFO Vacuumed table table=closures19692026/10/01 08:35:25 INFO Vacuumed table table=objects1970--- PASS: TestGCMetrics (0.43s)1971=== CONT TestReadProxyRootRedirectsToIndexHTML19722026/10/01 08:35:25 INFO All 1 paths already cached19732026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.55ms)1974=== NAME TestClientIntegration1975 client_integration_test.go:312: Retrieved narinfo from S3:1976 StorePath: /build/TestClientIntegration3810040534/002/store/hckckbd4881pzsr8hrhp3vfhy2ajxlhq-test-file.txt1977 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1978 Compression: zstd1979 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11980 NarSize: 1521981 References: 1982 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk119832026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)1984=== NAME TestClientMultipleUploads1985 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2762872033/001/store/q6kc3z5qw44vjs0a527r9qvc5innizcs-test-file-2.txt1986=== NAME TestClientIntegration1987 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1988 client_integration_test.go:313: Decompressed .ls content (64 bytes):1989 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1990 client_integration_test.go:316: Testing garbage collection...19912026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.53ms)19922026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.62ms)19932026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)19942026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)19952026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.53ms)19962026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.73ms)19972026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)19982026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.87ms)19992026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.39ms)20002026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000020012026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.12ms)20022026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.39ms)20032026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (1.95ms)20042026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.84ms)20052026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.35ms)20062026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000020072026/10/01 08:35:25 INFO Aborted multipart uploads count=020082026/10/01 08:35:25 OK 3_commit_push.sql (7.59ms)20092026/10/01 08:35:25 goose: up to current file version: 320102026/10/01 08:35:25 OK 1_commit_pending_closure.sql (8.36ms)20112026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.45ms)20122026/10/01 08:35:25 OK 3_commit_push.sql (1.53ms)20132026/10/01 08:35:25 goose: up to current file version: 320142026/10/01 08:35:25 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=020152026/10/01 08:35:25 INFO Vacuumed table table=pending_closures20162026/10/01 08:35:25 INFO Vacuumed table table=pending_objects20172026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads20182026/10/01 08:35:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures20192026/10/01 08:35:25 INFO Garbage collection started20202026/10/01 08:35:25 INFO Vacuumed table table=closures20212026-10-01 08:35:25.868 UTC [985] ERROR: relation "goose_db_version" does not exist at character 3620222026-10-01 08:35:25.868 UTC [985] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20232026/10/01 08:35:25 INFO Vacuumed table table=objects20242026-10-01 08:35:25.873 UTC [986] ERROR: relation "goose_db_version" does not exist at character 3620252026-10-01 08:35:25.873 UTC [986] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20262026/10/01 08:35:25 INFO Aborted multipart uploads count=020272026/10/01 08:35:25 INFO Aborted multipart uploads count=020282026/10/01 08:35:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40657/oidc20292026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period20302026/10/01 08:35:25 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=020312026/10/01 08:35:25 WARN Force mode enabled - objects will be deleted immediately without grace period20322026/10/01 08:35:25 INFO Vacuumed table table=pending_closures20332026/10/01 08:35:25 INFO Vacuumed table table=pending_objects20342026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads20352026/10/01 08:35:25 INFO Vacuumed table table=closures20362026/10/01 08:35:25 INFO Vacuumed table table=objects20372026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.87ms)2038--- PASS: TestPushDedupSurvivesConcurrentGC (0.53s)2039=== CONT TestReadProxyNarinfo20402026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)20412026/10/01 08:35:25 OK 20241026095416_initial_model.sql (10.41ms)20422026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.08ms)20432026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)20442026/10/01 08:35:25 INFO Received push request method=POST path=/api/pushes20452026/10/01 08:35:25 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=020462026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)20472026/10/01 08:35:25 OK 20251218171726_add_pins.sql (2.99ms)20482026/10/01 08:35:25 INFO Vacuumed table table=pending_closures20492026/10/01 08:35:25 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20502026/10/01 08:35:25 INFO Uploading q6kc3z5qw44vjs0a527r9qvc5innizcs-test-file-2.txt (160B)20512026/10/01 08:35:25 INFO Uploading r5sz9740661kzrcy0zclqalsrhiqb8n6-test-file-1.txt (160B)20522026/10/01 08:35:25 INFO Uploading 51nhmv60hh2h080iws9jh57a4dpdysqc-test-file-0.txt (160B)20532026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.74ms)20542026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)20552026-10-01 08:35:25.900 UTC [1063] ERROR: relation "goose_db_version" does not exist at character 3620562026-10-01 08:35:25.900 UTC [1063] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20572026/10/01 08:35:25 INFO Vacuumed table table=pending_objects20582026/10/01 08:35:25 INFO Vacuumed table table=multipart_uploads20592026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (3.8ms)20602026/10/01 08:35:25 WARN Failed to register uploaded object key=q6kc3z5qw44vjs0a527r9qvc5innizcs.ls error="server returned 404: 404 page not found\n"20612026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.6ms)20622026/10/01 08:35:25 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20632026/10/01 08:35:25 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"20642026/10/01 08:35:25 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20652026/10/01 08:35:25 WARN Failed to register uploaded object key=r5sz9740661kzrcy0zclqalsrhiqb8n6.ls error="server returned 404: 404 page not found\n"20662026/10/01 08:35:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20672026/10/01 08:35:25 WARN Failed to register uploaded object key=51nhmv60hh2h080iws9jh57a4dpdysqc.ls error="server returned 404: 404 page not found\n"20682026/10/01 08:35:25 INFO Signed narinfos id=1 count=320692026/10/01 08:35:25 INFO Uploading 3 narinfos20702026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.78ms)20712026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (3.43ms)20722026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000020732026/10/01 08:35:25 INFO Vacuumed table table=closures20742026/10/01 08:35:25 WARN Failed to register uploaded object key=q6kc3z5qw44vjs0a527r9qvc5innizcs.narinfo error="server returned 404: 404 page not found\n"20752026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2ms)20762026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000020772026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2ms)20782026/10/01 08:35:25 WARN Failed to register uploaded object key=r5sz9740661kzrcy0zclqalsrhiqb8n6.narinfo error="server returned 404: 404 page not found\n"20792026/10/01 08:35:25 INFO Received complete push request method=POST path=/api/pushes/1/complete20802026/10/01 08:35:25 WARN Failed to register uploaded object key=51nhmv60hh2h080iws9jh57a4dpdysqc.narinfo error="server returned 404: 404 page not found\n"20812026/10/01 08:35:25 INFO Vacuumed table table=objects20822026/10/01 08:35:25 INFO Received push request method=POST path=/api/pushes20832026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.55ms)20842026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.45ms)20852026/10/01 08:35:25 OK 3_commit_push.sql (1.24ms)20862026/10/01 08:35:25 goose: up to current file version: 320872026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.31ms)20882026/10/01 08:35:25 OK 3_commit_push.sql (1.24ms)20892026/10/01 08:35:25 goose: up to current file version: 320902026/10/01 08:35:25 INFO lead: acquired remote=192.0.2.1:123420912026/10/01 08:35:25 INFO Upload complete. (58ms)2092=== NAME TestClientMultipleUploads20932026/10/01 08:35:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)2094 client_integration_test.go:369: Uploaded 3 paths in 87.976689ms20952026/10/01 08:35:25 INFO Uploading h1g11qgbzyf48bcja9ndnpkw51yhi2sp-ca-test (144B)20962026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.19ms)20972026/10/01 08:35:25 WARN Failed to register uploaded object key=log/8vslgi10csizdsxkqz7dc6kf6plb2272-ca-test.drv error="server returned 404: 404 page not found\n"20982026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)20992026/10/01 08:35:25 WARN Failed to register uploaded object key=h1g11qgbzyf48bcja9ndnpkw51yhi2sp.ls error="server returned 404: 404 page not found\n"21002026/10/01 08:35:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21012026/10/01 08:35:25 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21022026/10/01 08:35:25 INFO Signed narinfos id=1 count=121032026/10/01 08:35:25 INFO Uploading 1 narinfos21042026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.62ms)2105--- PASS: TestClientMultipleUploads (0.59s)2106=== CONT TestReadProxy40421072026/10/01 08:35:25 INFO Received complete push request method=POST path=/api/pushes/1/complete21082026/10/01 08:35:25 WARN Failed to register uploaded object key=h1g11qgbzyf48bcja9ndnpkw51yhi2sp.narinfo error="server returned 404: 404 page not found\n"21092026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (3.45ms)21102026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.02ms)21112026/10/01 08:35:25 INFO Upload complete. (94ms)21122026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.88ms)2113=== NAME TestClientCADerivations2114 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3910703512/001/store/h1g11qgbzyf48bcja9ndnpkw51yhi2sp-ca-test2115 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2116 Compression: zstd2117 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2118 NarSize: 1442119 References: 2120 Deriver: /build/TestClientCADerivations3910703512/001/store/8vslgi10csizdsxkqz7dc6kf6plb2272-ca-test.drv2121 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2122 client_ca_test.go:185: Checking for realisation files in S3...21232026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.35ms)21242026/10/01 08:35:25 goose: successfully migrated database to version: 202609231200002125 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2126 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21272026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.5ms)21282026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.36ms)21292026/10/01 08:35:25 OK 3_commit_push.sql (1.38ms)21302026/10/01 08:35:25 goose: up to current file version: 321312026-10-01 08:35:25.951 UTC [1172] ERROR: relation "goose_db_version" does not exist at character 3621322026-10-01 08:35:25.951 UTC [1172] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21332026/10/01 08:35:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21342026/10/01 08:35:25 WARN mTLS auth: bound subjects configured but subject DN unavailable21352026/10/01 08:35:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2136--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.37s)2137=== CONT TestIsValidCachePath2138=== RUN TestIsValidCachePath/narinfo2139=== PAUSE TestIsValidCachePath/narinfo2140=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars2141=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars2142=== RUN TestIsValidCachePath/nar_zst2143=== PAUSE TestIsValidCachePath/nar_zst2144=== RUN TestIsValidCachePath/nar_xz2145=== PAUSE TestIsValidCachePath/nar_xz2146=== RUN TestIsValidCachePath/nar_bz22147=== PAUSE TestIsValidCachePath/nar_bz22148=== RUN TestIsValidCachePath/nar_uncompressed2149=== PAUSE TestIsValidCachePath/nar_uncompressed2150=== RUN TestIsValidCachePath/ls2151=== PAUSE TestIsValidCachePath/ls2152=== RUN TestIsValidCachePath/log2153=== PAUSE TestIsValidCachePath/log2154=== RUN TestIsValidCachePath/realisation2155=== PAUSE TestIsValidCachePath/realisation2156=== RUN TestIsValidCachePath/nix-cache-info2157=== PAUSE TestIsValidCachePath/nix-cache-info2158=== RUN TestIsValidCachePath/index.html2159=== PAUSE TestIsValidCachePath/index.html2160=== RUN TestIsValidCachePath/traversal_parent2161=== PAUSE TestIsValidCachePath/traversal_parent2162=== RUN TestIsValidCachePath/traversal_in_middle2163=== PAUSE TestIsValidCachePath/traversal_in_middle2164=== RUN TestIsValidCachePath/invalid_char_e2165=== PAUSE TestIsValidCachePath/invalid_char_e2166=== RUN TestIsValidCachePath/invalid_char_u2167=== PAUSE TestIsValidCachePath/invalid_char_u2168=== RUN TestIsValidCachePath/random_path2169=== PAUSE TestIsValidCachePath/random_path2170=== RUN TestIsValidCachePath/empty2171=== PAUSE TestIsValidCachePath/empty2172=== RUN TestIsValidCachePath/leading_slash2173=== PAUSE TestIsValidCachePath/leading_slash2174=== RUN TestIsValidCachePath/wrong_extension2175=== PAUSE TestIsValidCachePath/wrong_extension2176=== RUN TestIsValidCachePath/short_hash2177=== PAUSE TestIsValidCachePath/short_hash2178=== CONT TestReadProxyConditionalGet21792026-10-01 08:35:25.963 UTC [1193] ERROR: relation "goose_db_version" does not exist at character 3621802026-10-01 08:35:25.963 UTC [1193] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2181=== NAME TestPinProtectsFromGC2182 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC499612380/001/store/xavcmhf5k2pqqpidgvd2akaw2m13s80f-pinned-file.txt2183 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC499612380/001/store/mm21fmv1jqymicwk7dv8cnkp9w4w6grw-unpinned-file.txt21842026/10/01 08:35:25 OK 20241026095416_initial_model.sql (12.65ms)21852026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)2186--- PASS: TestService_ReadAuthMiddleware (0.39s)2187=== CONT TestProxyHeadersOnlyTrustedOnSocket21882026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.96ms)21892026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)21902026/10/01 08:35:25 OK 20241026095416_initial_model.sql (11.75ms)21912026/10/01 08:35:25 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)21922026/10/01 08:35:25 OK 20260905000000_add_claims.sql (4.13ms)21932026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.87ms)21942026/10/01 08:35:25 OK 20251218171726_add_pins.sql (3.61ms)21952026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.64ms)21962026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000021972026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures21982026/10/01 08:35:25 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)21992026/10/01 08:35:25 OK 1_commit_pending_closure.sql (2.68ms)22002026/10/01 08:35:25 INFO lead: acquired remote=192.0.2.1:123422012026/10/01 08:35:25 INFO lead: released remote=192.0.2.1:12342202--- PASS: TestLeadEndsOnShutdown (0.40s)2203=== CONT TestOrphanedObjectsGCStressTest22042026/10/01 08:35:25 OK 2_object_stats_trigger.sql (1.77ms)22052026/10/01 08:35:25 OK 20260905000000_add_claims.sql (3.22ms)22062026/10/01 08:35:25 OK 3_commit_push.sql (1.3ms)22072026/10/01 08:35:25 goose: up to current file version: 322082026/10/01 08:35:25 INFO Received uploads request method=POST path=/api/pending_closures22092026/10/01 08:35:25 OK 20260920000000_drop_claims.sql (2.41ms)22102026/10/01 08:35:25 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)22112026/10/01 08:35:25 INFO Uploading xlrackqy3ffz29s0rvajdirrrxp08i0p-shared-dep (136B)22122026/10/01 08:35:25 INFO Uploading ic9ivi2qc5caraq9x9k524s8c88bhbyx-b (216B)22132026/10/01 08:35:25 OK 20260923120000_add_pushes.sql (2.08ms)22142026/10/01 08:35:25 goose: successfully migrated database to version: 2026092312000022152026-10-01 08:35:26.000 UTC [1337] ERROR: relation "goose_db_version" does not exist at character 3622162026-10-01 08:35:26.000 UTC [1337] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22172026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.65ms)22182026/10/01 08:35:26 WARN Failed to register uploaded object key=na0vkg8y2a96r8xcmcllpqjc5admj32l.ls error="server returned 404: 404 page not found\n"22192026/10/01 08:35:26 WARN Failed to register uploaded object key=xlrackqy3ffz29s0rvajdirrrxp08i0p.ls error="server returned 404: 404 page not found\n"22202026/10/01 08:35:26 WARN Failed to register uploaded object key=nar/1ndmg36da453hzfbvbkan0d86y3lqf82cig7s5qlcrqdbyp4akha.nar.zst error="server returned 404: 404 page not found\n"22212026/10/01 08:35:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22222026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.64ms)22232026/10/01 08:35:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22242026/10/01 08:35:26 WARN Failed to register uploaded object key=ic9ivi2qc5caraq9x9k524s8c88bhbyx.ls error="server returned 404: 404 page not found\n"22252026/10/01 08:35:26 INFO Signed narinfos id=1 count=222262026/10/01 08:35:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22272026/10/01 08:35:26 INFO Signed narinfos id=2 count=222282026/10/01 08:35:26 OK 3_commit_push.sql (1.23ms)22292026/10/01 08:35:26 goose: up to current file version: 322302026/10/01 08:35:26 INFO Uploading 4 narinfos22312026/10/01 08:35:26 WARN Failed to register uploaded object key=xlrackqy3ffz29s0rvajdirrrxp08i0p.narinfo error="server returned 404: 404 page not found\n"22322026/10/01 08:35:26 WARN Failed to register uploaded object key=ic9ivi2qc5caraq9x9k524s8c88bhbyx.narinfo error="server returned 404: 404 page not found\n"22332026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes22342026/10/01 08:35:26 WARN Failed to register uploaded object key=na0vkg8y2a96r8xcmcllpqjc5admj32l.narinfo error="server returned 404: 404 page not found\n"2235=== NAME TestClientWithDependencies2236 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies548249547/001/store/nam67icajmzjpnb5g6jx0x71l01k3v2y-test-script22372026/10/01 08:35:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22382026/10/01 08:35:26 WARN Failed to register uploaded object key=xlrackqy3ffz29s0rvajdirrrxp08i0p.narinfo error="server returned 404: 404 page not found\n"2239=== NAME TestClientCADerivations2240 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2241 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2242 error: binary cache 's3://bucket40?endpoint=http://localhost:34331®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3910703512/001/store'2243 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 122442026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.36ms)22452026/10/01 08:35:26 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)22462026/10/01 08:35:26 INFO Uploading bh12pl4v27i57g99pvlsiqdrnpfapmnp-shared-dep (136B)22472026/10/01 08:35:26 INFO Uploading jmixkx9310ayh0rmcxxjyrgfq588a76g-top (224B)22482026/10/01 08:35:26 INFO Completed upload id=122492026/10/01 08:35:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22502026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.78ms)2251--- PASS: TestClientCADerivations (0.71s)2252=== CONT TestSkippedUploadsHandler22532026/10/01 08:35:26 INFO Client skipped oversized paths paths=3 nar_bytes=500000000022542026/10/01 08:35:26 INFO Completed upload id=222552026/10/01 08:35:26 INFO Upload complete. (65ms)2256--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.41s)2257=== CONT TestReadProxyNarStreaming22582026/10/01 08:35:26 WARN Failed to register uploaded object key=bh12pl4v27i57g99pvlsiqdrnpfapmnp.ls error="server returned 404: 404 page not found\n"22592026/10/01 08:35:26 WARN Failed to register uploaded object key=nar/0xi93jkirg1nz1j61ngkrfkqiqbqmwaiflk152clnr19nmp2avhh.nar.zst error="server returned 404: 404 page not found\n"2260=== NAME TestClientFallsBackToClosures2261 client_pushes_test.go:112: Retrieved narinfo from S3:2262 StorePath: /build/TestClientFallsBackToClosures2718607103/001/store/xlrackqy3ffz29s0rvajdirrrxp08i0p-shared-dep2263 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2264 Compression: zstd2265 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822266 NarSize: 1362267 References: 2268 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n22692026/10/01 08:35:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22702026/10/01 08:35:26 WARN Failed to register uploaded object key=jmixkx9310ayh0rmcxxjyrgfq588a76g.ls error="server returned 404: 404 page not found\n"22712026/10/01 08:35:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22722026/10/01 08:35:26 INFO Signed narinfos id=1 count=222732026/10/01 08:35:26 INFO Uploading 2 narinfos22742026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.44ms)2275--- PASS: TestSkippedUploadsHandler (0.00s)2276=== CONT TestService_Rustfstest2277=== NAME TestClientFallsBackToClosures2278 client_pushes_test.go:112: Retrieved narinfo from S3:2279 StorePath: /build/TestClientFallsBackToClosures2718607103/001/store/na0vkg8y2a96r8xcmcllpqjc5admj32l-a2280 URL: nar/1ndmg36da453hzfbvbkan0d86y3lqf82cig7s5qlcrqdbyp4akha.nar.zst2281 Compression: zstd2282 NarHash: sha256:1ndmg36da453hzfbvbkan0d86y3lqf82cig7s5qlcrqdbyp4akha2283 NarSize: 2162284 References: /build/TestClientFallsBackToClosures2718607103/001/store/xlrackqy3ffz29s0rvajdirrrxp08i0p-shared-dep2285 CA: text:sha256:0y95jpmj18yblbwpj95z2hsljp40d24wvn3jz1gczb155y5z2in622862026/10/01 08:35:26 WARN Failed to register uploaded object key=jmixkx9310ayh0rmcxxjyrgfq588a76g.narinfo error="server returned 404: 404 page not found\n"22872026/10/01 08:35:26 INFO Received complete push request method=POST path=/api/pushes/1/complete22882026/10/01 08:35:26 WARN Failed to register uploaded object key=bh12pl4v27i57g99pvlsiqdrnpfapmnp.narinfo error="server returned 404: 404 page not found\n"2289 client_pushes_test.go:112: Retrieved narinfo from S3:2290 StorePath: /build/TestClientFallsBackToClosures2718607103/001/store/ic9ivi2qc5caraq9x9k524s8c88bhbyx-b2291 URL: nar/1ndmg36da453hzfbvbkan0d86y3lqf82cig7s5qlcrqdbyp4akha.nar.zst2292 Compression: zstd2293 NarHash: sha256:1ndmg36da453hzfbvbkan0d86y3lqf82cig7s5qlcrqdbyp4akha2294 NarSize: 2162295 References: /build/TestClientFallsBackToClosures2718607103/001/store/xlrackqy3ffz29s0rvajdirrrxp08i0p-shared-dep2296 CA: text:sha256:0y95jpmj18yblbwpj95z2hsljp40d24wvn3jz1gczb155y5z2in622972026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)2298--- PASS: TestClientFallsBackToClosures (0.62s)2299=== CONT TestCreatePin_ReservedPins23002026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes23012026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.84ms)23022026/10/01 08:35:26 INFO Upload complete. (57ms)2303=== NAME TestClientSharedPathCommittedMidPush2304 client_integration_test.go:680: Retrieved narinfo from S3:2305 StorePath: /build/TestClientSharedPathCommittedMidPush292685877/001/store/bh12pl4v27i57g99pvlsiqdrnpfapmnp-shared-dep2306 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2307 Compression: zstd2308 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822309 NarSize: 1362310 References: 2311 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2312--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.40s)2313=== CONT TestOrphanedObjectsGC23142026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.23ms)23152026/10/01 08:35:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23162026/10/01 08:35:26 INFO Uploading xavcmhf5k2pqqpidgvd2akaw2m13s80f-pinned-file.txt (128B)2317=== NAME TestClientSharedPathCommittedMidPush2318 client_integration_test.go:680: Retrieved narinfo from S3:2319 StorePath: /build/TestClientSharedPathCommittedMidPush292685877/001/store/jmixkx9310ayh0rmcxxjyrgfq588a76g-top2320 URL: nar/0xi93jkirg1nz1j61ngkrfkqiqbqmwaiflk152clnr19nmp2avhh.nar.zst2321 Compression: zstd2322 NarHash: sha256:0xi93jkirg1nz1j61ngkrfkqiqbqmwaiflk152clnr19nmp2avhh2323 NarSize: 2242324 References: /build/TestClientSharedPathCommittedMidPush292685877/001/store/bh12pl4v27i57g99pvlsiqdrnpfapmnp-shared-dep2325 CA: text:sha256:16d7zvhd6d888v7ggbz31i5dkkizxqp36f3q069mw6g4sar0caad23262026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes23272026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.95ms)23282026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000023292026/10/01 08:35:26 WARN Failed to register uploaded object key=xavcmhf5k2pqqpidgvd2akaw2m13s80f.ls error="server returned 404: 404 page not found\n"23302026/10/01 08:35:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign2331--- PASS: TestClientSharedPathCommittedMidPush (0.57s)23322026/10/01 08:35:26 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"2333=== CONT TestObjectStatsTrigger23342026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.6ms)23352026/10/01 08:35:26 INFO Signed narinfos id=1 count=123362026/10/01 08:35:26 INFO Uploading 1 narinfos23372026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.61ms)23382026/10/01 08:35:26 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)23392026/10/01 08:35:26 INFO Uploading n04grz24wwggaabyx33ff5cdc8hm526i-b (216B)23402026/10/01 08:35:26 INFO Uploading if5bnil0zjnzl0p9rwqcxn4k7sxz6pzg-shared-dep (136B)23412026/10/01 08:35:26 INFO Received complete push request method=POST path=/api/pushes/1/complete23422026/10/01 08:35:26 WARN Failed to register uploaded object key=xavcmhf5k2pqqpidgvd2akaw2m13s80f.narinfo error="server returned 404: 404 page not found\n"23432026-10-01 08:35:26.045 UTC [1515] ERROR: relation "goose_db_version" does not exist at character 3623442026-10-01 08:35:26.045 UTC [1515] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2345=== NAME TestClientWithDependencies2346 client_integration_test.go:615: Found 1 dependencies (including self)23472026-10-01 08:35:26.046 UTC [1517] ERROR: relation "goose_db_version" does not exist at character 3623482026-10-01 08:35:26.046 UTC [1517] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23492026/10/01 08:35:26 WARN Failed to register uploaded object key=nar/10f61a00hjgx5giis6h26ld5fqrb8kfvamv65k539v6cda7i5di3.nar.zst error="server returned 404: 404 page not found\n"23502026/10/01 08:35:26 WARN Failed to register uploaded object key=66shm831c6hg5j3wid08rg11vmyzl3p2.ls error="server returned 404: 404 page not found\n"23512026/10/01 08:35:26 WARN Failed to register uploaded object key=n04grz24wwggaabyx33ff5cdc8hm526i.ls error="server returned 404: 404 page not found\n"23522026/10/01 08:35:26 WARN Failed to register uploaded object key=if5bnil0zjnzl0p9rwqcxn4k7sxz6pzg.ls error="server returned 404: 404 page not found\n"23532026/10/01 08:35:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23542026/10/01 08:35:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23552026/10/01 08:35:26 INFO Signed narinfos id=1 count=323562026/10/01 08:35:26 INFO Uploading 3 narinfos23572026/10/01 08:35:26 OK 3_commit_push.sql (8.04ms)23582026/10/01 08:35:26 goose: up to current file version: 323592026/10/01 08:35:26 INFO Upload complete. (54ms)23602026/10/01 08:35:26 WARN Failed to register uploaded object key=if5bnil0zjnzl0p9rwqcxn4k7sxz6pzg.narinfo error="server returned 404: 404 page not found\n"23612026/10/01 08:35:26 WARN Failed to register uploaded object key=66shm831c6hg5j3wid08rg11vmyzl3p2.narinfo error="server returned 404: 404 page not found\n"23622026/10/01 08:35:26 INFO Received complete push request method=POST path=/api/pushes/1/complete23632026/10/01 08:35:26 WARN Failed to register uploaded object key=n04grz24wwggaabyx33ff5cdc8hm526i.narinfo error="server returned 404: 404 page not found\n"23642026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures2365--- PASS: TestGCBugBareHashReferences (0.63s)2366=== CONT TestParseSize2367--- PASS: TestParseSize (0.00s)2368=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info23692026/10/01 08:35:26 INFO Received uploads request method=POST path=/2370=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23712026/10/01 08:35:26 INFO Received request for more parts method=POST path=/2372=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23732026/10/01 08:35:26 INFO Received complete multipart upload request method=POST path=/2374=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23752026/10/01 08:35:26 INFO Received uploads request method=POST path=/2376--- PASS: TestUploadHandlersRejectInvalidKeys (0.06s)2377 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2378 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2379 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2380 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2381=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure23822026/10/01 08:35:26 INFO Received uploads request method=POST path=/23832026/10/01 08:35:26 INFO Upload complete. (62ms)2384=== NAME TestClientPushesUseOnePush2385 client_pushes_test.go:97: Retrieved narinfo from S3:2386 StorePath: /build/TestClientPushesUseOnePush2545692430/001/store/if5bnil0zjnzl0p9rwqcxn4k7sxz6pzg-shared-dep2387 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2388 Compression: zstd2389 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822390 NarSize: 1362391 References: 2392 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n23932026/10/01 08:35:26 INFO lead: released remote=192.0.2.1:123423942026/10/01 08:35:26 OK 20241026095416_initial_model.sql (12.2ms)2395 client_pushes_test.go:97: Retrieved narinfo from S3:2396 StorePath: /build/TestClientPushesUseOnePush2545692430/001/store/66shm831c6hg5j3wid08rg11vmyzl3p2-a2397 URL: nar/10f61a00hjgx5giis6h26ld5fqrb8kfvamv65k539v6cda7i5di3.nar.zst2398 Compression: zstd2399 NarHash: sha256:10f61a00hjgx5giis6h26ld5fqrb8kfvamv65k539v6cda7i5di32400 NarSize: 2162401 References: /build/TestClientPushesUseOnePush2545692430/001/store/if5bnil0zjnzl0p9rwqcxn4k7sxz6pzg-shared-dep2402 CA: text:sha256:0sv9ns3ijhdib1pzh2alba7l2wh6wa24p0zknhql1ljjgx9nc8wb24032026/10/01 08:35:26 OK 20241026095416_initial_model.sql (13.05ms)24042026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)24052026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)2406 client_pushes_test.go:97: Retrieved narinfo from S3:2407 StorePath: /build/TestClientPushesUseOnePush2545692430/001/store/n04grz24wwggaabyx33ff5cdc8hm526i-b2408 URL: nar/10f61a00hjgx5giis6h26ld5fqrb8kfvamv65k539v6cda7i5di3.nar.zst2409 Compression: zstd2410 NarHash: sha256:10f61a00hjgx5giis6h26ld5fqrb8kfvamv65k539v6cda7i5di32411 NarSize: 2162412 References: /build/TestClientPushesUseOnePush2545692430/001/store/if5bnil0zjnzl0p9rwqcxn4k7sxz6pzg-shared-dep2413 CA: text:sha256:0sv9ns3ijhdib1pzh2alba7l2wh6wa24p0zknhql1ljjgx9nc8wb24142026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.08ms)24152026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.08ms)2416--- PASS: TestClientPushesUseOnePush (0.62s)2417=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts24182026/10/01 08:35:26 INFO Received request for more parts method=POST path=/24192026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)24202026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)24212026-10-01 08:35:26.077 UTC [1537] ERROR: relation "goose_db_version" does not exist at character 3624222026-10-01 08:35:26.077 UTC [1537] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24232026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.76ms)24242026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.9ms)24252026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.06ms)24262026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.43ms)2427--- PASS: TestReadRedirectNar (0.40s)2428=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart24292026/10/01 08:35:26 INFO Received complete multipart upload request method=POST path=/24302026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.73ms)24312026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000024322026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (3.24ms)24332026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000024342026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.48ms)24352026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.58ms)24362026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.86ms)24372026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.75ms)24382026/10/01 08:35:26 OK 3_commit_push.sql (1.15ms)24392026/10/01 08:35:26 goose: up to current file version: 324402026/10/01 08:35:26 OK 3_commit_push.sql (1.19ms)24412026/10/01 08:35:26 goose: up to current file version: 324422026/10/01 08:35:26 OK 20241026095416_initial_model.sql (9.7ms)24432026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)2444--- PASS: TestReadProxyDisabled (0.37s)2445=== CONT TestServerTLSConfig/no_client_CA2446=== CONT TestServerTLSConfig/not_a_PEM_file24472026-10-01 08:35:26.100 UTC [1574] ERROR: relation "goose_db_version" does not exist at character 3624482026-10-01 08:35:26.100 UTC [1574] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2449=== CONT TestServerTLSConfig/missing_CA_file2450--- PASS: TestServerTLSConfig (0.00s)2451 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2452 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2453 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2454=== CONT TestPush_RejectsBadRequests/no_roots24552026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes2456=== CONT TestPush_RejectsBadRequests/root_not_in_objects24572026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes2458=== CONT TestPush_RejectsBadRequests/bad_root24592026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes2460=== CONT TestPush_RejectsBadRequests/no_objects24612026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes2462=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2463--- PASS: TestPush_RejectsBadRequests (0.27s)2464 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2465 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2466 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2467 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)24682026/10/01 08:35:26 OK 20251218171726_add_pins.sql (9ms)24692026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)24702026/10/01 08:35:26 OK 20260905000000_add_claims.sql (2.86ms)24712026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (1.6ms)24722026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.05ms)24732026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000024742026/10/01 08:35:26 INFO lead: acquired remote=192.0.2.1:123424752026-10-01 08:35:26.115 UTC [1577] ERROR: relation "goose_db_version" does not exist at character 3624762026-10-01 08:35:26.115 UTC [1577] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24772026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.13ms)24782026-10-01 08:35:26.116 UTC [1578] ERROR: relation "goose_db_version" does not exist at character 3624792026-10-01 08:35:26.116 UTC [1578] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24802026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.23ms)24812026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.6ms)24822026-10-01 08:35:26.117 UTC [1579] ERROR: relation "goose_db_version" does not exist at character 3624832026-10-01 08:35:26.117 UTC [1579] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24842026/10/01 08:35:26 INFO lead: released remote=192.0.2.1:12342485--- PASS: TestLeadElectsOneAndHandsOver (0.61s)2486=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check24872026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)24882026/10/01 08:35:26 OK 3_commit_push.sql (1.94ms)24892026/10/01 08:35:26 goose: up to current file version: 324902026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes24912026/10/01 08:35:26 INFO Received push request method=POST path=/api/pushes24922026/10/01 08:35:26 OK 20251218171726_add_pins.sql (2.91ms)2493=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2494=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2495=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2496=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2497=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2498=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2499=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2500=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2501=== CONT TestClientErrorHandling/InvalidStorePath25022026/10/01 08:35:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25032026/10/01 08:35:26 INFO Uploading mm21fmv1jqymicwk7dv8cnkp9w4w6grw-unpinned-file.txt (128B)25042026/10/01 08:35:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25052026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)25062026/10/01 08:35:26 INFO Uploading nam67icajmzjpnb5g6jx0x71l01k3v2y-test-script (136B)25072026/10/01 08:35:26 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"25082026/10/01 08:35:26 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign25092026/10/01 08:35:26 WARN Failed to register uploaded object key=mm21fmv1jqymicwk7dv8cnkp9w4w6grw.ls error="server returned 404: 404 page not found\n"25102026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.5ms)25112026/10/01 08:35:26 INFO Signed narinfos id=2 count=125122026/10/01 08:35:26 INFO Uploading 1 narinfos25132026/10/01 08:35:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25142026/10/01 08:35:26 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"25152026/10/01 08:35:26 WARN Failed to register uploaded object key=log/4gdkzd2scz508q5qqrd53cf1fimbphqp-test-script.drv error="server returned 404: 404 page not found\n"25162026/10/01 08:35:26 WARN Failed to register uploaded object key=nam67icajmzjpnb5g6jx0x71l01k3v2y.ls error="server returned 404: 404 page not found\n"25172026/10/01 08:35:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign2518=== CONT TestClientErrorHandling/ServerNotAvailable25192026/10/01 08:35:26 INFO Signed narinfos id=1 count=125202026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.76ms)25212026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.49ms)25222026/10/01 08:35:26 INFO Uploading 1 narinfos25232026/10/01 08:35:26 INFO Received complete push request method=POST path=/api/pushes/2/complete25242026/10/01 08:35:26 WARN Failed to register uploaded object key=mm21fmv1jqymicwk7dv8cnkp9w4w6grw.narinfo error="server returned 404: 404 page not found\n"25252026/10/01 08:35:26 OK 20241026095416_initial_model.sql (12.5ms)25262026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)25272026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.3ms)25282026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000025292026/10/01 08:35:26 OK 20241026095416_initial_model.sql (11.69ms)25302026/10/01 08:35:26 INFO Upload complete. (48ms)25312026/10/01 08:35:26 WARN Failed to register uploaded object key=nam67icajmzjpnb5g6jx0x71l01k3v2y.narinfo error="server returned 404: 404 page not found\n"25322026/10/01 08:35:26 INFO Received complete push request method=POST path=/api/pushes/1/complete25332026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)25342026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)25352026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.39ms)25362026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.87ms)2537=== CONT TestClientErrorHandling/InvalidAuthToken25382026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.58ms)25392026/10/01 08:35:26 OK 20251218171726_add_pins.sql (4.2ms)25402026/10/01 08:35:26 OK 3_commit_push.sql (1.4ms)25412026/10/01 08:35:26 goose: up to current file version: 325422026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.67ms)25432026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)25442026/10/01 08:35:26 INFO Upload complete. (62ms)25452026/10/01 08:35:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46091/oidc25462026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)25472026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.47ms)25482026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)2549=== NAME TestClientWithDependencies2550 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies548249547/001/store) requires matching store prefix25512026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.7ms)2552--- PASS: TestClientWithDependencies (0.60s)2553=== CONT TestCacheConfigHandler/full_config,_no_issuer25542026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.39ms)25552026/10/01 08:35:26 OK 20260905000000_add_claims.sql (4.23ms)2556=== CONT TestCacheConfigHandler/no_signing_keys2557=== CONT TestCacheConfigHandler/no_cache_url_configured2558=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2559--- PASS: TestCacheConfigHandler (0.00s)2560 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2561 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2562 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2563 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2564=== CONT TestResolveDBConnectionString/flag_wins2565=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2566=== CONT TestResolveDBConnectionString/missing_file_is_an_error2567=== CONT TestResolveDBConnectionString/file_when_flag_empty2568=== CONT TestResolveDBConnectionString/nothing_configured2569=== CONT TestIsValidUploadKey/narinfo2570=== CONT TestIsValidUploadKey/unknown_type2571=== CONT TestIsValidUploadKey/empty_key2572=== CONT TestIsValidUploadKey/absolute2573=== CONT TestIsValidUploadKey/traversal_nar2574=== CONT TestIsValidUploadKey/traversal2575=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2576=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2577=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2578=== CONT TestIsValidUploadKey/index.html2579=== CONT TestIsValidUploadKey/nix-cache-info2580=== CONT TestIsValidUploadKey/realisation_plus_in_output2581=== CONT TestIsValidUploadKey/realisation2582=== CONT TestIsValidUploadKey/build_log_equals2583=== CONT TestIsValidUploadKey/build_log_question_mark2584=== CONT TestIsValidUploadKey/build_log_plus_in_name2585=== CONT TestIsValidUploadKey/build_log_home-manager_file2586=== CONT TestIsValidUploadKey/build_log2587=== CONT TestIsValidUploadKey/listing2588=== CONT TestIsValidUploadKey/nar_plain2589=== CONT TestIsValidUploadKey/nar_xz2590=== CONT TestIsValidUploadKey/nar_zst2591=== CONT TestProxyWriteTimeout/narinfo2592--- PASS: TestResolveDBConnectionString (0.00s)2593 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2594 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2595 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2596 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2597 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2598=== CONT TestProxyWriteTimeout/10_GiB_nar2599=== CONT TestProxyWriteTimeout/unknown_size2600=== CONT TestProxyWriteTimeout/1_GiB_nar2601=== CONT TestParseSingleRange/none2602=== CONT TestParseSingleRange/start_past_EOF2603=== CONT TestParseSingleRange/single_byte2604=== CONT TestParseSingleRange/suffix_exceeds_size2605=== CONT TestParseSingleRange/start_far_past_EOF2606=== CONT TestParseSingleRange/suffix2607=== CONT TestParseSingleRange/end_clamped_to_size2608=== CONT TestParseSingleRange/open-ended2609=== CONT TestParseSingleRange/closed2610=== CONT TestParseSingleRange/malformed_end_before_start2611=== CONT TestParseSingleRange/malformed_both_empty2612--- PASS: TestIsValidUploadKey (0.00s)2613 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2614 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2615 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2616 --- PASS: TestIsValidUploadKey/absolute (0.00s)2617 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2618 --- PASS: TestIsValidUploadKey/traversal (0.00s)2619 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2620 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2621 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2622 --- PASS: TestIsValidUploadKey/index.html (0.00s)2623 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2624 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2625 --- PASS: TestIsValidUploadKey/realisation (0.00s)2626 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2627 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2628 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2629 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2630 --- PASS: TestIsValidUploadKey/build_log (0.00s)2631 --- PASS: TestIsValidUploadKey/listing (0.00s)2632 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2633 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2634 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2635=== CONT TestParseSingleRange/malformed_no_dash2636=== CONT TestParseSingleRange/multi-range_ignored2637=== CONT TestParseSingleRange/unknown_unit2638=== CONT TestIsValidCachePath/narinfo2639=== CONT TestIsValidCachePath/wrong_extension2640=== CONT TestIsValidCachePath/leading_slash2641=== CONT TestIsValidCachePath/empty2642=== CONT TestIsValidCachePath/random_path2643--- PASS: TestProxyWriteTimeout (0.00s)2644 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2645 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2646 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2647 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2648=== CONT TestIsValidCachePath/short_hash2649=== CONT TestIsValidCachePath/invalid_char_u2650=== CONT TestIsValidCachePath/invalid_char_e2651=== CONT TestIsValidCachePath/traversal_in_middle2652=== CONT TestIsValidCachePath/traversal_parent2653--- PASS: TestParseSingleRange (0.00s)2654 --- PASS: TestParseSingleRange/none (0.00s)2655 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2656 --- PASS: TestParseSingleRange/single_byte (0.00s)2657 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2658 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2659 --- PASS: TestParseSingleRange/suffix (0.00s)2660 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2661 --- PASS: TestParseSingleRange/open-ended (0.00s)2662 --- PASS: TestParseSingleRange/closed (0.00s)2663 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2664 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2665 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2666 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2667 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2668=== CONT TestIsValidCachePath/index.html2669=== CONT TestIsValidCachePath/realisation26702026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.43ms)2671=== CONT TestIsValidCachePath/nar_xz26722026/10/01 08:35:26 goose: successfully migrated database to version: 202609231200002673=== CONT TestIsValidCachePath/nix-cache-info2674=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2675=== CONT TestIsValidCachePath/ls2676=== CONT TestIsValidCachePath/log2677=== CONT TestIsValidCachePath/nar_bz22678=== CONT TestIsValidCachePath/nar_uncompressed2679=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2680--- PASS: TestReadProxyHead (0.36s)2681=== CONT TestIsValidCachePath/nar_zst2682--- PASS: TestIsValidCachePath (0.00s)2683 --- PASS: TestIsValidCachePath/narinfo (0.00s)2684 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2685 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2686 --- PASS: TestIsValidCachePath/empty (0.00s)2687 --- PASS: TestIsValidCachePath/random_path (0.00s)2688 --- PASS: TestIsValidCachePath/short_hash (0.00s)2689 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2690 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2691 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2692 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2693 --- PASS: TestIsValidCachePath/index.html (0.00s)2694 --- PASS: TestIsValidCachePath/realisation (0.00s)2695 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2696 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2697 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2698 --- PASS: TestIsValidCachePath/ls (0.00s)2699 --- PASS: TestIsValidCachePath/log (0.00s)2700 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2701 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2702 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2703=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2704=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected27052026/10/01 08:35:26 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]2706=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected27072026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.4ms)27082026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (3.48ms)27092026/10/01 08:35:26 OK 1_commit_pending_closure.sql (3.09ms)27102026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.07ms)27112026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000027122026/10/01 08:35:26 WARN Authentication failed token_preview=eyJhbGciOi...G0wSHZOYuA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]27132026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (2.67ms)27142026/10/01 08:35:26 goose: successfully migrated database to version: 202609231200002715--- PASS: TestService_AuthMiddleware_OIDC (0.51s)2716 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2717 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2718 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2719 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)27202026/10/01 08:35:26 OK 2_object_stats_trigger.sql (2.09ms)27212026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.31ms)27222026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.55ms)27232026/10/01 08:35:26 OK 3_commit_push.sql (1.79ms)27242026/10/01 08:35:26 goose: up to current file version: 327252026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.77ms)27262026/10/01 08:35:26 OK 2_object_stats_trigger.sql (1.58ms)27272026/10/01 08:35:26 OK 3_commit_push.sql (1.45ms)27282026/10/01 08:35:26 goose: up to current file version: 327292026/10/01 08:35:26 OK 3_commit_push.sql (1.38ms)27302026/10/01 08:35:26 goose: up to current file version: 327312026/10/01 08:35:26 INFO Received create pin request method=POST path=/api/pins/myapp2732--- PASS: TestReadProxyInvalidPath (0.38s)27332026/10/01 08:35:26 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC499612380/001/store/xavcmhf5k2pqqpidgvd2akaw2m13s80f-pinned-file.txt narinfo_key=xavcmhf5k2pqqpidgvd2akaw2m13s80f.narinfo27342026/10/01 08:35:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures27352026/10/01 08:35:26 INFO Garbage collection started27362026-10-01 08:35:26.181 UTC [1659] ERROR: relation "goose_db_version" does not exist at character 3627372026-10-01 08:35:26.181 UTC [1659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27382026/10/01 08:35:26 INFO Aborted multipart uploads count=02739--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.37s)27402026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period27412026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.55ms)27422026/10/01 08:35:26 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/present27432026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)27442026-10-01 08:35:26.208 UTC [1678] ERROR: relation "goose_db_version" does not exist at character 3627452026-10-01 08:35:26.208 UTC [1678] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27462026/10/01 08:35:26 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=027472026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.16ms)27482026/10/01 08:35:26 INFO Vacuumed table table=pending_closures27492026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.59ms)27502026/10/01 08:35:26 INFO Vacuumed table table=pending_objects27512026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads27522026/10/01 08:35:26 INFO Vacuumed table table=closures27532026/10/01 08:35:26 OK 20260905000000_add_claims.sql (2.92ms)27542026/10/01 08:35:26 INFO Vacuumed table table=objects27552026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (1.81ms)27562026-10-01 08:35:26.219 UTC [1679] ERROR: relation "goose_db_version" does not exist at character 3627572026-10-01 08:35:26.219 UTC [1679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27582026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (1.64ms)27592026/10/01 08:35:26 goose: successfully migrated database to version: 202609231200002760=== RUN TestService_RequireScope_OIDC/builder_may_write2761=== PAUSE TestService_RequireScope_OIDC/builder_may_write2762=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2763=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2764=== RUN TestService_RequireScope_OIDC/ops_may_admin2765=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2766=== RUN TestService_RequireScope_OIDC/ops_may_not_write2767=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2768=== RUN TestService_RequireScope_OIDC/reader_may_not_write2769=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2770=== RUN TestService_RequireScope_OIDC/static_token_may_admin2771=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2772=== RUN TestService_RequireScope_OIDC/static_token_may_write2773=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2774=== RUN TestService_RequireScope_OIDC/reader_may_read2775=== PAUSE TestService_RequireScope_OIDC/reader_may_read2776=== RUN TestService_RequireScope_OIDC/writer_implies_read2777=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2778=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2779=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2780=== CONT TestService_RequireScope_OIDC/builder_may_write2781=== CONT TestService_RequireScope_OIDC/ops_may_admin2782=== CONT TestService_RequireScope_OIDC/writer_implies_read2783=== CONT TestService_RequireScope_OIDC/reader_may_not_write2784=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2785=== CONT TestService_RequireScope_OIDC/reader_may_read27862026/10/01 08:35:26 OK 1_commit_pending_closure.sql (2.02ms)2787=== CONT TestService_RequireScope_OIDC/static_token_may_write2788=== CONT TestService_RequireScope_OIDC/static_token_may_admin2789=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2790=== CONT TestService_RequireScope_OIDC/ops_may_not_write27912026/10/01 08:35:26 OK 20241026095416_initial_model.sql (9.45ms)27922026-10-01 08:35:26.223 UTC [1680] ERROR: relation "goose_db_version" does not exist at character 3627932026-10-01 08:35:26.223 UTC [1680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27942026/10/01 08:35:26 OK 2_object_stats_trigger.sql (936.83µs)2795--- PASS: TestService_RequireScope_OIDC (0.49s)2796 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2797 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2798 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2799 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2800 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2801 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2802 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2803 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2804 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2805 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)28062026/10/01 08:35:26 OK 3_commit_push.sql (733.73µs)28072026/10/01 08:35:26 goose: up to current file version: 328082026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)28092026/10/01 08:35:26 OK 20251218171726_add_pins.sql (2.72ms)28102026-10-01 08:35:26.227 UTC [1681] ERROR: relation "goose_db_version" does not exist at character 3628112026-10-01 08:35:26.227 UTC [1681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2812--- PASS: TestReadProxyNarinfo (0.34s)28132026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (2.81ms)28142026/10/01 08:35:26 OK 20260905000000_add_claims.sql (3.32ms)28152026/10/01 08:35:26 OK 20241026095416_initial_model.sql (9.57ms)28162026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)28172026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (2.07ms)28182026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (1.47ms)28192026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000028202026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.18ms)28212026/10/01 08:35:26 OK 1_commit_pending_closure.sql (1.39ms)28222026/10/01 08:35:26 OK 20251218171726_add_pins.sql (3.11ms)28232026/10/01 08:35:26 OK 2_object_stats_trigger.sql (675.49µs)28242026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)28252026/10/01 08:35:26 OK 3_commit_push.sql (551.77µs)28262026/10/01 08:35:26 goose: up to current file version: 32827--- PASS: TestReadProxy404 (0.32s)28282026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (3.27ms)28292026/10/01 08:35:26 OK 20251218171726_add_pins.sql (2.57ms)28302026/10/01 08:35:26 OK 20241026095416_initial_model.sql (10.79ms)28312026/10/01 08:35:26 OK 20260905000000_add_claims.sql (2.5ms)28322026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (2.8ms)28332026/10/01 08:35:26 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)28342026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (1.93ms)28352026/10/01 08:35:26 OK 20260905000000_add_claims.sql (2.62ms)28362026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (1.53ms)28372026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000028382026/10/01 08:35:26 OK 20251218171726_add_pins.sql (2.76ms)28392026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (1.63ms)28402026/10/01 08:35:26 OK 1_commit_pending_closure.sql (1.57ms)28412026/10/01 08:35:26 OK 2_object_stats_trigger.sql (692.45µs)28422026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (1.26ms)28432026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000028442026/10/01 08:35:26 OK 3_commit_push.sql (531.86µs)28452026/10/01 08:35:26 goose: up to current file version: 328462026/10/01 08:35:26 OK 20260628120000_add_object_size_and_stats.sql (2.79ms)28472026/10/01 08:35:26 OK 1_commit_pending_closure.sql (1.46ms)28482026/10/01 08:35:26 OK 2_object_stats_trigger.sql (620.25µs)28492026/10/01 08:35:26 OK 3_commit_push.sql (537.09µs)28502026/10/01 08:35:26 goose: up to current file version: 328512026/10/01 08:35:26 OK 20260905000000_add_claims.sql (2.72ms)28522026/10/01 08:35:26 OK 20260920000000_drop_claims.sql (1.95ms)28532026/10/01 08:35:26 OK 20260923120000_add_pushes.sql (1.38ms)28542026/10/01 08:35:26 goose: successfully migrated database to version: 2026092312000028552026/10/01 08:35:26 OK 1_commit_pending_closure.sql (1.53ms)28562026/10/01 08:35:26 OK 2_object_stats_trigger.sql (694.15µs)28572026/10/01 08:35:26 OK 3_commit_push.sql (572.09µs)28582026/10/01 08:35:26 goose: up to current file version: 32859--- PASS: TestReadProxyConditionalGet (0.31s)28602026/10/01 08:35:26 INFO Starting HTTP server address=127.0.0.1:3850528612026/10/01 08:35:26 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2524900196/001/proxy.sock28622026/10/01 08:35:26 WARN mTLS auth: subject not in bound subjects subject="CN=someone"28632026/10/01 08:35:26 INFO Shutdown signal received, draining in-flight requests timeout=10s2864--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.30s)28652026/10/01 08:35:26 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.228991ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2866--- PASS: TestReadProxyNarStreaming (0.29s)2867--- PASS: TestService_Rustfstest (0.31s)2868--- PASS: TestObjectStatsTrigger (0.31s)28692026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures28702026/10/01 08:35:26 INFO Aborted multipart uploads count=028712026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period28722026/10/01 08:35:26 INFO Received uploads request method=POST path=/api/pending_closures28732026/10/01 08:35:26 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=028742026/10/01 08:35:26 INFO Vacuumed table table=pending_closures28752026/10/01 08:35:26 INFO Vacuumed table table=pending_objects28762026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads28772026/10/01 08:35:26 INFO Vacuumed table table=closures28782026/10/01 08:35:26 INFO Vacuumed table table=objects28792026/10/01 08:35:26 INFO Aborted multipart uploads count=028802026/10/01 08:35:26 WARN Force mode enabled - objects will be deleted immediately without grace period28812026/10/01 08:35:26 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=028822026/10/01 08:35:26 INFO Vacuumed table table=pending_closures28832026/10/01 08:35:26 INFO Vacuumed table table=pending_objects28842026/10/01 08:35:26 INFO Vacuumed table table=multipart_uploads28852026/10/01 08:35:26 INFO Vacuumed table table=closures28862026/10/01 08:35:26 INFO Vacuumed table table=objects2887--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2888 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.30s)2889 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.29s)28902026/10/01 08:35:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux28912026/10/01 08:35:26 WARN Refused reserved pin name=worker-x86_64-linux28922026/10/01 08:35:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux28932026/10/01 08:35:26 INFO Received create pin request method=POST path=/api/pins/my-app28942026/10/01 08:35:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2895--- PASS: TestCreatePin_ReservedPins (0.40s)28962026/10/01 08:35:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"28972026/10/01 08:35:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"28982026/10/01 08:35:26 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=434.717305ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2899=== NAME TestOrphanedObjectsGC2900 orphaned_objects_gc_test.go:290: GC Test Summary:2901 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2902 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2903 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2904 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2905 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2906--- PASS: TestOrphanedObjectsGC (0.56s)2907--- PASS: TestUploadHandlersRejectOversizedBody (0.13s)2908 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2909 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2910 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.86s)29112026/10/01 08:35:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=802.377139ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2912=== NAME TestOrphanedObjectsGCStressTest2913 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2914 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2915 orphaned_objects_gc_test.go:509: Stress test completed successfully:2916 orphaned_objects_gc_test.go:510: - Active objects preserved: 202917 orphaned_objects_gc_test.go:511: - Objects deleted: 2102918 orphaned_objects_gc_test.go:512: - Total GC'd: 2102919--- PASS: TestOrphanedObjectsGCStressTest (1.45s)29202026/10/01 08:35:27 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.735502438s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29212026/10/01 08:35:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02922=== NAME TestClientIntegration2923 client_integration_test.go:323: Objects in database after GC:2924 client_integration_test.go:323: Successfully deleted all objects with GC --force2925--- PASS: TestClientIntegration (2.62s)29262026/10/01 08:35:28 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02927=== NAME TestPinProtectsFromGC2928 client_integration_test.go:794: Pin successfully protected closure from garbage collection2929--- PASS: TestPinProtectsFromGC (2.71s)29302026/10/01 08:35:28 WARN Rate limiter enabled after throttle name=s3-test rate=529312026/10/01 08:35:28 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2932=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2933 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102934 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002935--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (2.89s)29362026/10/01 08:35:29 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-config29372026/10/01 08:35:29 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.487934ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29382026/10/01 08:35:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.441251ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29392026/10/01 08:35:30 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=809.738335ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29402026/10/01 08:35:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.55260739s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29412026/10/01 08:35:32 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"29422026/10/01 08:35:32 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-config29432026/10/01 08:35:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.079195ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29442026/10/01 08:35:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.562551ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29452026/10/01 08:35:33 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=862.658394ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29462026/10/01 08:35:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.544995973s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29472026/10/01 08:35:35 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_closures29482026/10/01 08:35:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.645552ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29492026/10/01 08:35:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=421.113844ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29502026/10/01 08:35:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=759.759205ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29512026/10/01 08:35:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.733768076s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2952--- PASS: TestClientErrorHandling (0.00s)2953 --- PASS: TestClientErrorHandling/InvalidStorePath (0.30s)2954 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.37s)2955 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.83s)2956PASS29572026-10-01 08:35:39.174 UTC [128] LOG: received smart shutdown request29582026-10-01 08:35:39.177 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 129592026-10-01 08:35:39.188 UTC [133] LOG: shutting down29602026-10-01 08:35:39.188 UTC [133] LOG: checkpoint starting: shutdown immediate29612026-10-01 08:35:39.997 UTC [133] LOG: checkpoint complete: wrote 10464 buffers (63.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 22 recycled; write=0.176 s, sync=0.606 s, total=0.809 s; sync files=26627, longest=0.002 s, average=0.001 s; distance=362307 kB, estimate=362307 kB; lsn=0/17936B10, redo lsn=0/17936B1029622026-10-01 08:35:40.070 UTC [128] LOG: database system is shut down2963Running OIDC tests...2964=== RUN TestAudienceForIssuer2965=== PAUSE TestAudienceForIssuer2966=== RUN TestGlobMatch2967=== PAUSE TestGlobMatch2968=== RUN TestValidateToken_ValidToken2969=== PAUSE TestValidateToken_ValidToken2970=== RUN TestValidateToken_WrongAudience2971=== PAUSE TestValidateToken_WrongAudience2972=== RUN TestValidateToken_Expired2973=== PAUSE TestValidateToken_Expired2974=== RUN TestValidateToken_BoundClaimsMismatch2975=== PAUSE TestValidateToken_BoundClaimsMismatch2976=== RUN TestValidateToken_BoundSubjectMismatch2977=== PAUSE TestValidateToken_BoundSubjectMismatch2978=== RUN TestValidateToken_MultipleProviders2979=== PAUSE TestValidateToken_MultipleProviders2980=== RUN TestValidateToken_NoMatchingProvider2981=== PAUSE TestValidateToken_NoMatchingProvider2982=== RUN TestValidateToken_KubernetesServiceAccount2983=== PAUSE TestValidateToken_KubernetesServiceAccount2984=== RUN TestNewValidator_KubernetesRequiresCA2985=== PAUSE TestNewValidator_KubernetesRequiresCA2986=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2987=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2988=== RUN TestPins_ReservedForMatchingRule2989=== PAUSE TestPins_ReservedForMatchingRule2990=== RUN TestPins_TopLevelShorthand2991=== PAUSE TestPins_TopLevelShorthand2992=== RUN TestPins_ConfigValidation2993=== PAUSE TestPins_ConfigValidation2994=== RUN TestScopes_LegacyProviderDefaultsToWrite2995=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2996=== RUN TestScopes_Rules2997=== PAUSE TestScopes_Rules2998=== RUN TestScopes_ConfigValidation2999=== PAUSE TestScopes_ConfigValidation3000=== CONT TestAudienceForIssuer3001=== CONT TestPins_ConfigValidation3002--- PASS: TestAudienceForIssuer (0.00s)3003=== CONT TestValidateToken_KubernetesServiceAccount3004=== CONT TestScopes_Rules3005=== CONT TestValidateToken_NoMatchingProvider3006=== CONT TestValidateToken_MultipleProviders3007=== CONT TestValidateToken_BoundSubjectMismatch3008=== CONT TestValidateToken_BoundClaimsMismatch3009=== CONT TestValidateToken_Expired3010=== CONT TestValidateToken_WrongAudience3011=== CONT TestValidateToken_ValidToken3012--- PASS: TestPins_ConfigValidation (0.00s)3013=== CONT TestGlobMatch3014=== CONT TestPins_ReservedForMatchingRule3015=== CONT TestPins_TopLevelShorthand3016=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3017=== CONT TestScopes_ConfigValidation3018=== CONT TestScopes_LegacyProviderDefaultsToWrite3019=== CONT TestNewValidator_KubernetesRequiresCA3020=== RUN TestGlobMatch/foo_foo3021=== PAUSE TestGlobMatch/foo_foo3022=== RUN TestGlobMatch/foo_bar3023=== PAUSE TestGlobMatch/foo_bar3024=== RUN TestGlobMatch/*_3025=== PAUSE TestGlobMatch/*_3026=== RUN TestGlobMatch/*_anything3027=== PAUSE TestGlobMatch/*_anything3028=== RUN TestGlobMatch/foo*_foo3029=== PAUSE TestGlobMatch/foo*_foo3030=== RUN TestGlobMatch/foo*_foobar3031=== PAUSE TestGlobMatch/foo*_foobar3032=== RUN TestGlobMatch/foo*_bar3033=== PAUSE TestGlobMatch/foo*_bar3034=== RUN TestGlobMatch/*bar_bar3035=== PAUSE TestGlobMatch/*bar_bar3036=== RUN TestGlobMatch/*bar_foobar3037=== PAUSE TestGlobMatch/*bar_foobar3038=== RUN TestGlobMatch/*bar_foo3039=== PAUSE TestGlobMatch/*bar_foo3040=== RUN TestGlobMatch/foo*bar_foobar3041=== PAUSE TestGlobMatch/foo*bar_foobar3042=== RUN TestGlobMatch/foo*bar_foo123bar3043=== PAUSE TestGlobMatch/foo*bar_foo123bar3044=== RUN TestGlobMatch/foo*bar_foobarbaz3045=== PAUSE TestGlobMatch/foo*bar_foobarbaz3046=== RUN TestGlobMatch/*/*_foo/bar3047=== PAUSE TestGlobMatch/*/*_foo/bar3048=== RUN TestGlobMatch/*/*_foo3049=== PAUSE TestGlobMatch/*/*_foo3050=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3051=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3052=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03053=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03054=== RUN TestGlobMatch/refs/*/main_refs/heads/main3055=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3056=== RUN TestGlobMatch/fo?_foo3057=== PAUSE TestGlobMatch/fo?_foo3058=== RUN TestGlobMatch/fo?_fo3059=== PAUSE TestGlobMatch/fo?_fo3060=== RUN TestGlobMatch/fo?_fooo3061=== PAUSE TestGlobMatch/fo?_fooo3062=== RUN TestGlobMatch/?oo_foo3063=== PAUSE TestGlobMatch/?oo_foo3064=== RUN TestGlobMatch/?oo_boo3065=== PAUSE TestGlobMatch/?oo_boo3066=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3067=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3068=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3069=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3070=== CONT TestGlobMatch/foo_foo3071=== CONT TestGlobMatch/fo?_fo3072=== CONT TestGlobMatch/fo?_foo3073=== CONT TestGlobMatch/refs/*/main_refs/heads/main3074=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03075=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3076=== CONT TestGlobMatch/*/*_foo3077=== CONT TestGlobMatch/*/*_foo/bar3078=== CONT TestGlobMatch/foo*bar_foobarbaz3079=== CONT TestGlobMatch/foo*bar_foo123bar3080=== CONT TestGlobMatch/foo*bar_foobar3081=== CONT TestGlobMatch/*bar_foo3082=== CONT TestGlobMatch/*bar_foobar3083=== CONT TestGlobMatch/*bar_bar3084=== CONT TestGlobMatch/foo*_bar3085=== CONT TestGlobMatch/foo*_foobar3086=== CONT TestGlobMatch/?oo_boo3087=== CONT TestGlobMatch/fo?_fooo3088=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3089=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3090=== CONT TestGlobMatch/foo*_foo3091=== CONT TestGlobMatch/*_anything3092=== CONT TestGlobMatch/*_3093=== CONT TestGlobMatch/foo_bar3094=== CONT TestGlobMatch/?oo_foo3095--- PASS: TestGlobMatch (0.00s)3096 --- PASS: TestGlobMatch/foo_foo (0.00s)3097 --- PASS: TestGlobMatch/fo?_fo (0.00s)3098 --- PASS: TestGlobMatch/fo?_foo (0.00s)3099 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3100 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3101 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3102 --- PASS: TestGlobMatch/*/*_foo (0.00s)3103 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3104 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3105 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3106 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3107 --- PASS: TestGlobMatch/*bar_foo (0.00s)3108 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3109 --- PASS: TestGlobMatch/*bar_bar (0.00s)3110 --- PASS: TestGlobMatch/foo*_bar (0.00s)3111 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3112 --- PASS: TestGlobMatch/?oo_boo (0.00s)3113 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3114 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3115 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3116 --- PASS: TestGlobMatch/foo*_foo (0.00s)3117 --- PASS: TestGlobMatch/*_anything (0.00s)3118 --- PASS: TestGlobMatch/*_ (0.00s)3119 --- PASS: TestGlobMatch/foo_bar (0.00s)3120 --- PASS: TestGlobMatch/?oo_foo (0.00s)3121--- PASS: TestScopes_ConfigValidation (0.00s)31222026/10/01 08:35:41 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:374293123--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)31242026/10/01 08:35:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39037/oidc3125--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)31262026/10/01 08:35:41 http: TLS handshake error from 127.0.0.1:44692: remote error: tls: bad certificate3127--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)31282026/10/01 08:35:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46315/oidc31292026/10/01 08:35:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42633/oidc3130--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.10s)3131--- PASS: TestValidateToken_BoundSubjectMismatch (0.10s)31322026/10/01 08:35:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45195/oidc3133--- PASS: TestValidateToken_Expired (0.11s)31342026/10/01 08:35:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42483/oidc31352026/10/01 08:35:41 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41491/oidc31362026/10/01 08:35:41 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34681/oidc3137--- PASS: TestValidateToken_WrongAudience (0.16s)3138--- PASS: TestValidateToken_MultipleProviders (0.16s)31392026/10/01 08:35:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42761/oidc3140--- PASS: TestValidateToken_ValidToken (0.16s)31412026/10/01 08:35:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38169/oidc3142--- PASS: TestPins_TopLevelShorthand (0.21s)31432026/10/01 08:35:41 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233144--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.24s)31452026/10/01 08:35:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34635/oidc3146--- PASS: TestPins_ReservedForMatchingRule (0.28s)31472026/10/01 08:35:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38277/oidc31482026/10/01 08:35:41 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44891/oidc3149--- PASS: TestValidateToken_NoMatchingProvider (0.35s)3150--- PASS: TestScopes_Rules (0.36s)3151PASS3152Running hook tests...3153=== RUN TestSendPathsEmpty3154=== PAUSE TestSendPathsEmpty3155=== RUN TestQueueEnqueueAndFetch3156=== PAUSE TestQueueEnqueueAndFetch3157=== RUN TestQueueDeduplication3158=== PAUSE TestQueueDeduplication3159=== RUN TestQueueRemove3160=== PAUSE TestQueueRemove3161=== RUN TestQueueFetchBatchLimit3162=== PAUSE TestQueueFetchBatchLimit3163=== RUN TestQueueRetryMovesToBack3164=== PAUSE TestQueueRetryMovesToBack3165=== RUN TestQueueFetchRemoveLifecycle3166=== PAUSE TestQueueFetchRemoveLifecycle3167=== RUN TestQueueConcurrentWriters3168=== PAUSE TestQueueConcurrentWriters3169=== RUN TestQueueRemoveLargeClosure3170=== PAUSE TestQueueRemoveLargeClosure3171=== RUN TestServerClientIntegration3172=== PAUSE TestServerClientIntegration3173=== RUN TestServerQueueError3174=== PAUSE TestServerQueueError3175=== RUN TestGetListenerSocketActivation3176 server_test.go:210: === RUN TestGetListenerSocketActivation3177 --- PASS: TestGetListenerSocketActivation (0.00s)3178 PASS3179 3180--- PASS: TestGetListenerSocketActivation (0.01s)3181=== RUN TestDrainIsolatesPoisonPath3182=== PAUSE TestDrainIsolatesPoisonPath3183=== RUN TestRunNotBlockedByPoisonHead3184=== PAUSE TestRunNotBlockedByPoisonHead3185=== RUN TestDrainGivesUpWhenServerDown3186=== PAUSE TestDrainGivesUpWhenServerDown3187=== RUN TestFailedPathPrunedByLaterClosure3188=== PAUSE TestFailedPathPrunedByLaterClosure3189=== RUN TestWorkerUploadsAndRemoves3190=== PAUSE TestWorkerUploadsAndRemoves3191=== RUN TestWorkerSkipsGCdPaths3192=== PAUSE TestWorkerSkipsGCdPaths3193=== RUN TestWorkerPrunesClosureDeps3194=== PAUSE TestWorkerPrunesClosureDeps3195=== RUN TestDrainTimeout3196=== PAUSE TestDrainTimeout3197=== CONT TestSendPathsEmpty3198=== CONT TestDrainIsolatesPoisonPath3199=== CONT TestDrainGivesUpWhenServerDown3200--- PASS: TestSendPathsEmpty (0.00s)3201=== CONT TestServerQueueError3202=== CONT TestServerClientIntegration3203=== CONT TestQueueRemoveLargeClosure3204=== CONT TestQueueConcurrentWriters3205=== CONT TestQueueFetchRemoveLifecycle3206=== CONT TestQueueRetryMovesToBack3207=== CONT TestWorkerUploadsAndRemoves32082026/10/01 08:35:41 ERROR Failed to queue paths error="permission denied" count=13209=== CONT TestDrainTimeout3210=== CONT TestWorkerPrunesClosureDeps3211=== CONT TestQueueFetchBatchLimit3212=== CONT TestQueueRemove3213=== CONT TestWorkerSkipsGCdPaths3214=== CONT TestQueueDeduplication3215--- PASS: TestServerClientIntegration (0.00s)3216=== CONT TestQueueEnqueueAndFetch3217=== CONT TestFailedPathPrunedByLaterClosure3218--- PASS: TestServerQueueError (0.00s)3219=== CONT TestRunNotBlockedByPoisonHead32202026/10/01 08:35:41 INFO Uploading batch count=432212026/10/01 08:35:41 ERROR Upload failed error="upload failed" count=432222026/10/01 08:35:41 INFO Uploading batch count=232232026/10/01 08:35:41 INFO Upload queue status pending=232242026/10/01 08:35:41 INFO Upload queue status pending=332252026/10/01 08:35:41 INFO Upload queue status pending=232262026/10/01 08:35:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath521032526/002/bbb32272026/10/01 08:35:41 INFO Uploading batch count=13228--- PASS: TestQueueFetchBatchLimit (0.01s)32292026/10/01 08:35:41 INFO Uploading batch count=132302026/10/01 08:35:41 ERROR Upload failed error="upload failed" count=13231--- PASS: TestQueueEnqueueAndFetch (0.01s)32322026/10/01 08:35:41 INFO Uploading batch count=232332026/10/01 08:35:41 INFO Uploading batch count=132342026/10/01 08:35:41 ERROR Upload failed error="upload failed" count=13235--- PASS: TestQueueDeduplication (0.01s)32362026/10/01 08:35:41 INFO Uploading batch count=232372026/10/01 08:35:41 ERROR Upload failed error="upload failed" count=232382026/10/01 08:35:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1728279872/002/a32392026/10/01 08:35:41 INFO Upload queue status pending=232402026/10/01 08:35:41 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths122056234/002/nonexistent32412026/10/01 08:35:41 INFO Uploading batch count=132422026/10/01 08:35:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1728279872/002/b3243--- PASS: TestQueueFetchRemoveLifecycle (0.02s)3244--- PASS: TestQueueRetryMovesToBack (0.02s)32452026/10/01 08:35:41 INFO Uploading batch count=132462026/10/01 08:35:41 ERROR Upload failed error="upload failed" count=13247--- PASS: TestQueueRemove (0.01s)32482026/10/01 08:35:41 INFO Uploading batch count=132492026/10/01 08:35:41 INFO Uploading batch count=132502026/10/01 08:35:41 INFO Uploading batch count=232512026/10/01 08:35:41 ERROR Upload failed error="upload failed" count=232522026/10/01 08:35:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1728279872/002/c32532026/10/01 08:35:41 INFO Uploading batch count=132542026/10/01 08:35:41 ERROR Upload failed error="upload failed" count=132552026/10/01 08:35:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1728279872/002/d32562026/10/01 08:35:41 INFO Uploading batch count=132572026/10/01 08:35:41 ERROR Upload failed error="upload failed" count=132582026/10/01 08:35:41 ERROR Drain finished with paths left in queue remaining=132592026/10/01 08:35:41 INFO Uploading batch count=232602026/10/01 08:35:41 ERROR Upload failed error="upload failed" count=232612026/10/01 08:35:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1728279872/002/e3262--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)32632026/10/01 08:35:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1728279872/002/f32642026/10/01 08:35:41 ERROR Drain finished with paths left in queue remaining=103265--- PASS: TestDrainIsolatesPoisonPath (0.02s)3266--- PASS: TestDrainGivesUpWhenServerDown (0.02s)3267--- PASS: TestWorkerPrunesClosureDeps (0.03s)3268--- PASS: TestWorkerUploadsAndRemoves (0.03s)3269--- PASS: TestWorkerSkipsGCdPaths (0.03s)3270--- PASS: TestQueueRemoveLargeClosure (0.14s)3271--- PASS: TestQueueConcurrentWriters (0.15s)32722026/10/01 08:35:42 ERROR Upload failed error="context deadline exceeded" count=232732026/10/01 08:35:42 ERROR Drain finished with paths left in queue remaining=43274--- PASS: TestDrainTimeout (0.21s)32752026/10/01 08:35:42 INFO Uploading batch count=132762026/10/01 08:35:42 INFO Uploading batch count=132772026/10/01 08:35:42 INFO Uploading batch count=132782026/10/01 08:35:42 ERROR Upload failed error="upload failed" count=132792026/10/01 08:35:42 INFO Uploading batch count=132802026/10/01 08:35:42 ERROR Upload failed error="upload failed" count=132812026/10/01 08:35:42 INFO Uploading batch count=132822026/10/01 08:35:42 ERROR Upload failed error="upload failed" count=132832026/10/01 08:35:42 INFO Uploading batch count=132842026/10/01 08:35:42 ERROR Upload failed error="upload failed" count=132852026/10/01 08:35:42 ERROR Drain finished with paths left in queue remaining=13286--- PASS: TestRunNotBlockedByPoisonHead (1.02s)3287PASS