niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #305
· raw
1tribuchet: building on jamie2Running 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 TestStreamPushReportsEveryPath97=== CONT TestConvertHashToNix3298=== CONT TestShellSplitErrors99=== CONT TestShellSplit100--- PASS: TestShellSplitErrors (0.00s)101=== CONT TestDumpPathMatchesNix102--- PASS: TestShellSplit (0.00s)103=== CONT TestScriptTokenEmptyCommand104--- PASS: TestScriptTokenEmptyCommand (0.00s)105=== CONT TestScriptTokenScriptFails106=== CONT TestDoWithRetry_BodyReplayedViaGetBody107=== CONT TestResolveStorePath108--- PASS: TestStreamPushReportsEveryPath (0.00s)109=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess110=== CONT TestRateLimiterFeedback111=== CONT TestPathInfoCACompatibility112=== CONT TestParsePathInfoJSONMultiplePaths113=== CONT TestParsePathInfoJSON114=== CONT TestPathInfoHashCompatibility115=== CONT TestGetStorePathHash116=== CONT TestFilterOversizedClosures117=== CONT TestUploadMultipart_SupersededByPeer118=== CONT TestPartSizeForNAR119=== CONT TestEncodeNixBase32WithRealHash120=== CONT TestUploadMultipart_PartsInParallel121=== CONT TestEncodeNixBase32122=== CONT TestDumpPathWriterError123=== CONT TestRegisterUploadedObjectReusesConnections124=== CONT TestDumpPathSingleFile125=== CONT TestStaticToken126=== RUN TestConvertHashToNix32/SRI_format_to_Nix32127=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32128=== RUN TestUploadMultipart_SupersededByPeer/exists129=== PAUSE TestUploadMultipart_SupersededByPeer/exists130=== CONT TestScriptTokenBadJSON131=== RUN TestEncodeNixBase32/test_string_hash132=== RUN TestUploadMultipart_SupersededByPeer/missing1332026/10/01 09:15:17 WARN Rate limiter enabled after throttle name=server-test rate=5134--- PASS: TestScriptTokenScriptFails (0.00s)135=== CONT TestScriptTokenEmptyToken136=== RUN TestFilterOversizedClosures/no_limit_keeps_everything137=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)138=== RUN TestRateLimiterFeedback/429_enables_limiter139--- PASS: TestEncodeNixBase32WithRealHash (0.00s)140=== CONT TestStreamPushReportsSignatures141=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)142--- PASS: TestResolveStorePath (0.00s)143=== CONT TestScriptTokenCachesUntilRefresh144=== PAUSE TestRateLimiterFeedback/429_enables_limiter145=== PAUSE TestUploadMultipart_SupersededByPeer/missing146=== RUN TestConvertHashToNix32/already_Nix32_format147=== PAUSE TestEncodeNixBase32/test_string_hash148=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything149=== CONT TestScriptTokenNoExpiryRerunsEveryCall150=== CONT TestSetClientTLSErrors151=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1522026/10/01 09:15:17 ERROR Upload failed error=boom count=1153=== CONT TestFileTokenEmpty154=== CONT TestFileTokenMissing1552026/10/01 09:15:17 WARN Rate limiter enabled after throttle name=server-test rate=51562026/10/01 09:15:17 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44161157--- PASS: TestStaticToken (0.00s)158--- PASS: TestScriptTokenBadJSON (0.08s)159--- PASS: TestStreamPushReportsSignatures (0.08s)160--- PASS: TestFileTokenEmpty (0.00s)161=== PAUSE TestConvertHashToNix32/already_Nix32_format162--- PASS: TestFileTokenMissing (0.00s)1632026/10/01 09:15:17 WARN Rate limiter backed off name=server-test rate=5164=== RUN TestConvertHashToNix32/invalid_format1652026/10/01 09:15:17 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44161166=== PAUSE TestConvertHashToNix32/invalid_format167=== RUN TestPartSizeForNAR/zero_stays_at_minimum168=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum169=== RUN TestPartSizeForNAR/small_stays_at_minimum170=== PAUSE TestPartSizeForNAR/small_stays_at_minimum171=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum172=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum173=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts174=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts175=== RUN TestPartSizeForNAR/1_TiB176=== PAUSE TestPartSizeForNAR/1_TiB177=== RUN TestPartSizeForNAR/5_TiB_S3_max_object178=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object179=== RUN TestPartSizeForNAR/capped_at_5_GiB180=== PAUSE TestPartSizeForNAR/capped_at_5_GiB181=== CONT TestFileTokenReadsAndCaches182--- PASS: TestDoServerRequestAttachesToken (0.08s)183=== CONT TestClientSignaturesByStorePath184--- PASS: TestClientSignaturesByStorePath (0.00s)185=== CONT TestStreamPushRequestLine186=== RUN TestParsePathInfoJSON/Nix_format187=== PAUSE TestParsePathInfoJSON/Nix_format188=== RUN TestParsePathInfoJSON/Lix_format189=== PAUSE TestParsePathInfoJSON/Lix_format190=== RUN TestParsePathInfoJSON/empty_input191=== PAUSE TestParsePathInfoJSON/empty_input192=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths193=== RUN TestGetStorePathHash/valid_store_path194=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon195=== RUN TestRateLimiterFeedback/503_enables_limiter196=== RUN TestEncodeNixBase32/empty_input197=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped198=== CONT TestSetClientTLS199=== PAUSE TestRateLimiterFeedback/503_enables_limiter200=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter201=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter2022026/10/01 09:15:17 ERROR Upload failed error=boom count=1203=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter204=== PAUSE TestEncodeNixBase32/empty_input205=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped206=== RUN TestFilterOversizedClosures/all_closures_skipped207=== PAUSE TestFilterOversizedClosures/all_closures_skipped208=== PAUSE TestGetStorePathHash/valid_store_path209=== RUN TestGetStorePathHash/basename_without_hyphen_should_error210=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error211=== CONT TestUploadMultipart_SupersededByPeer/missing212=== RUN TestPathInfoCACompatibility/null_ca_field213=== PAUSE TestPathInfoCACompatibility/null_ca_field214=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error215=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error216=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error217=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error218=== RUN TestSetClientTLSErrors/missing_cert_file219=== PAUSE TestSetClientTLSErrors/missing_cert_file220=== RUN TestSetClientTLSErrors/missing_key_file221=== CONT TestConvertHashToNix32/SRI_format_to_Nix32222=== CONT TestConvertHashToNix32/invalid_format223=== CONT TestConvertHashToNix32/already_Nix32_format224=== CONT TestPartSizeForNAR/zero_stays_at_minimum225=== CONT TestPartSizeForNAR/5_TiB_S3_max_object226=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts227=== CONT TestPartSizeForNAR/1_TiB228=== CONT TestPartSizeForNAR/capped_at_5_GiB229=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum230=== CONT TestEncodeNixBase32/test_string_hash231=== CONT TestEncodeNixBase32/empty_input232=== CONT TestFilterOversizedClosures/no_limit_keeps_everything233=== CONT TestFilterOversizedClosures/all_closures_skipped2342026/10/01 09:15:17 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50235=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2362026/10/01 09:15:17 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=2000237=== CONT TestPartSizeForNAR/small_stays_at_minimum238=== CONT TestGetStorePathHash/valid_store_path239=== CONT TestGetStorePathHash/basename_without_hyphen_should_error240=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error241=== PAUSE TestSetClientTLSErrors/missing_key_file242=== RUN TestSetClientTLSErrors/missing_ca_file243=== PAUSE TestSetClientTLSErrors/missing_ca_file244=== RUN TestSetClientTLSErrors/invalid_ca_file245=== PAUSE TestSetClientTLSErrors/invalid_ca_file246=== CONT TestSetClientTLSErrors/missing_cert_file247=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error248--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.08s)249=== CONT TestSetClientTLSErrors/invalid_ca_file250=== RUN TestSetClientTLS/rejects_connection_without_client_cert251=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert252=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA253=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA254=== RUN TestSetClientTLS/preserves_debug_logging_transport255=== PAUSE TestSetClientTLS/preserves_debug_logging_transport256=== CONT TestSetClientTLS/rejects_connection_without_client_cert257=== CONT TestStreamPushGivesUpOnDeadServer258=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon259=== CONT TestStreamPushIsolatesFailures260=== CONT TestStreamPushBatchesUnderLoad261=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2622026/10/01 09:15:17 ERROR Upload failed error="connection refused" count=202632026/10/01 09:15:17 ERROR Upload failed error="bad path" count=32642026/10/01 09:15:17 ERROR Server seems unavailable, giving up on batch untried=17265=== CONT TestCaseHackSuffix266=== CONT TestUploadMultipart_SupersededByPeer/exists267=== RUN TestParsePathInfoJSON/whitespace_only268=== PAUSE TestParsePathInfoJSON/whitespace_only269=== RUN TestParsePathInfoJSON/invalid_JSON270=== PAUSE TestParsePathInfoJSON/invalid_JSON271=== CONT TestParsePathInfoJSON/Nix_format272=== RUN TestPathInfoCACompatibility/old_string_format_-_text273=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text274=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive275=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive276=== RUN TestPathInfoCACompatibility/new_structured_format_-_text277=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text278=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method279=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method280=== CONT TestPathInfoCACompatibility/null_ca_field281=== CONT TestParsePathInfoJSON/invalid_JSON282=== CONT TestParsePathInfoJSON/whitespace_only283=== CONT TestParsePathInfoJSON/empty_input284=== CONT TestParsePathInfoJSON/Lix_format285=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths286=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths287=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths288=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths289=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method290=== CONT TestPathInfoCACompatibility/new_structured_format_-_text291=== CONT TestPathInfoCACompatibility/old_string_format_-_text292=== CONT TestSetClientTLSErrors/missing_ca_file293=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths294=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive295--- PASS: TestScriptTokenEmptyToken (0.08s)296--- PASS: TestFileTokenReadsAndCaches (0.00s)297=== CONT TestSetClientTLSErrors/missing_key_file298=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI299=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI300=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512301=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512302=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)303--- PASS: TestConvertHashToNix32 (0.08s)304 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)305 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)306 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)307=== CONT TestSetClientTLS/preserves_debug_logging_transport308=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512309=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter310=== CONT TestRateLimiterFeedback/429_enables_limiter311=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI312=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter313=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter314=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon315=== CONT TestRateLimiterFeedback/503_enables_limiter316--- PASS: TestPathInfoHashCompatibility (0.08s)317 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)318 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)319 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)320 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)321--- PASS: TestEncodeNixBase32 (0.08s)322 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)323 --- PASS: TestEncodeNixBase32/empty_input (0.00s)324--- PASS: TestFilterOversizedClosures (0.08s)325 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)326 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)327 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)3282026/10/01 09:15:17 WARN Rate limiter enabled after throttle name=server-test rate=5329--- PASS: TestPartSizeForNAR (0.08s)330 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)331 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)332 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)333 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)334 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)335 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)336 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)3372026/10/01 09:15:17 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:36299338--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)3392026/10/01 09:15:17 WARN Rate limiter enabled after throttle name=server-test rate=5340--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)3412026/10/01 09:15:17 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:41871342--- PASS: TestGetStorePathHash (0.08s)343 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)344 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)345 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)347--- PASS: TestParsePathInfoJSON (0.08s)348 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)349 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)350 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)351 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)352 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)353--- PASS: TestSetClientTLSErrors (0.00s)354 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)355 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)356 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)357 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)358--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)359 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)360 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)3612026/10/01 09:15:17 WARN Rate limiter backed off name=server-test rate=5362--- PASS: TestStreamPushIsolatesFailures (0.00s)363--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.08s)364--- PASS: TestScriptTokenCachesUntilRefresh (0.08s)365--- PASS: TestParsePathInfoJSONMultiplePaths (0.08s)366 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)367 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)368--- PASS: TestPathInfoCACompatibility (0.08s)369 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)370 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)371 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)372 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)373 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)3742026/10/01 09:15:17 WARN Rate limiter backed off name=server-test rate=5375--- PASS: TestRateLimiterFeedback (0.08s)376 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)377 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)378 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)379 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)3802026/10/01 09:15:17 http: TLS handshake error from 127.0.0.1:53768: remote error: tls: bad certificate381--- PASS: TestSetClientTLS (0.00s)382 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)384 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)385--- PASS: TestStreamPushRequestLine (0.03s)386--- PASS: TestRegisterUploadedObjectReusesConnections (0.11s)387--- PASS: TestCaseHackSuffix (0.03s)388--- PASS: TestDumpPathSingleFile (0.12s)389--- PASS: TestDumpPathWriterError (0.13s)390--- PASS: TestDumpPathMatchesNix (0.17s)391--- PASS: TestStreamPushBatchesUnderLoad (0.10s)392--- PASS: TestUploadMultipart_PartsInParallel (0.70s)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/postgres4194437696/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/postgres4194437696/data -l logfile start422423/build/postgres4194437696:5432 - no response4242026-10-01 09:15:18.858 UTC [130] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 09:15:18.858 UTC [130] LOG: listening on Unix socket "/build/postgres4194437696/.s.PGSQL.5432"4262026-10-01 09:15:18.863 UTC [137] LOG: database system was shut down at 2026-10-01 09:15:18 UTC4272026-10-01 09:15:18.867 UTC [130] LOG: database system is ready to accept connections428/build/postgres4194437696:5432 - accepting connections429{"timestamp":"2026-10-01T09:15:19.170810072Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3c4e68ed-364b-4910-b1d2-d234c2f8ce77","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(400)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestLeadElectsOneAndHandsOver471=== PAUSE TestLeadElectsOneAndHandsOver472=== RUN TestLeadIncumbentWinsAfterRestart4732026-10-01 09:15:19.367 UTC [569] ERROR: relation "goose_db_version" does not exist at character 364742026-10-01 09:15:19.367 UTC [569] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4752026/10/01 09:15:19 OK 20241026095416_initial_model.sql (7.58ms)4762026/10/01 09:15:19 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)4772026/10/01 09:15:19 OK 20251218171726_add_pins.sql (2.09ms)4782026/10/01 09:15:19 OK 20260628120000_add_object_size_and_stats.sql (1.7ms)4792026/10/01 09:15:19 OK 20260905000000_add_claims.sql (1.97ms)4802026/10/01 09:15:19 OK 20260920000000_drop_claims.sql (1.22ms)4812026/10/01 09:15:19 OK 20260923120000_add_pushes.sql (920.3µs)4822026/10/01 09:15:19 goose: successfully migrated database to version: 202609231200004832026/10/01 09:15:19 OK 1_commit_pending_closure.sql (1.33ms)4842026/10/01 09:15:19 OK 2_object_stats_trigger.sql (671.32µs)4852026/10/01 09:15:19 OK 3_commit_push.sql (610.44µs)4862026/10/01 09:15:19 goose: up to current file version: 34872026/10/01 09:15:19 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 09:15:20 INFO lead: released remote=192.0.2.1:12344892026/10/01 09:15:20 INFO lead: acquired remote=192.0.2.1:12344902026/10/01 09:15:20 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (0.79s)492=== RUN TestLeadEndsOnShutdown493=== PAUSE TestLeadEndsOnShutdown494=== RUN TestGCAdvisoryLockBlocksConcurrentRun4952026-10-01 09:15:20.126 UTC [579] ERROR: relation "goose_db_version" does not exist at character 364962026-10-01 09:15:20.126 UTC [579] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4972026/10/01 09:15:20 OK 20241026095416_initial_model.sql (6.35ms)4982026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)4992026/10/01 09:15:20 OK 20251218171726_add_pins.sql (2.77ms)5002026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (2.67ms)5012026/10/01 09:15:20 OK 20260905000000_add_claims.sql (2.58ms)5022026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (1.47ms)5032026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (1.11ms)5042026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200005052026/10/01 09:15:20 OK 1_commit_pending_closure.sql (1.69ms)5062026/10/01 09:15:20 OK 2_object_stats_trigger.sql (870.33µs)5072026/10/01 09:15:20 OK 3_commit_push.sql (775.37µs)5082026/10/01 09:15:20 goose: up to current file version: 3509--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.11s)510=== RUN TestGCBugBareHashReferences511=== PAUSE TestGCBugBareHashReferences512=== RUN TestGCMetrics513=== PAUSE TestGCMetrics514=== RUN TestPushDedupSurvivesConcurrentGC515=== PAUSE TestPushDedupSurvivesConcurrentGC516=== RUN TestDeduplicatedObjectsRecordedAsPending517=== PAUSE TestDeduplicatedObjectsRecordedAsPending518=== RUN TestGCSweepSkipsPendingObjects519=== PAUSE TestGCSweepSkipsPendingObjects520=== RUN TestTombstonedObjectOfferedWithoutWaiting521=== PAUSE TestTombstonedObjectOfferedWithoutWaiting522=== RUN TestGCSweepDeliversEachKeyOnce523=== PAUSE TestGCSweepDeliversEachKeyOnce524=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection526=== RUN TestForceGCDuringPushOffersSweptObject527=== PAUSE TestForceGCDuringPushOffersSweptObject528=== RUN TestFailedS3DeleteKeepsTombstone529=== PAUSE TestFailedS3DeleteKeepsTombstone530=== RUN TestSweepSkipsRowsLockedByPush531=== PAUSE TestSweepSkipsRowsLockedByPush532=== RUN TestRegisterCompletedObjectNeedsPendingRow533=== PAUSE TestRegisterCompletedObjectNeedsPendingRow534=== RUN TestGetExistingObjectsLocksRows535=== PAUSE TestGetExistingObjectsLocksRows536=== RUN TestSweepRechecksPendingAfterLocking537=== PAUSE TestSweepRechecksPendingAfterLocking538=== RUN TestPushWaitsForSweepHoldingRow539=== PAUSE TestPushWaitsForSweepHoldingRow540=== RUN TestCommitRacingPendingCleanupKeepsObjects541=== PAUSE TestCommitRacingPendingCleanupKeepsObjects542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestService_NativeMTLS575=== PAUSE TestService_NativeMTLS576=== RUN TestServerTLSConfig577=== PAUSE TestServerTLSConfig578=== RUN TestMultipartCleanup579=== PAUSE TestMultipartCleanup580=== RUN TestObjectStatsTrigger581=== PAUSE TestObjectStatsTrigger582=== RUN TestOrphanedObjectsGC583=== PAUSE TestOrphanedObjectsGC584=== RUN TestOrphanedObjectsGCStressTest585=== PAUSE TestOrphanedObjectsGCStressTest586=== RUN TestCreatePin_ReservedPins587=== PAUSE TestCreatePin_ReservedPins588=== RUN TestParseSingleRange589=== PAUSE TestParseSingleRange590=== RUN TestProxyHeadersOnlyTrustedOnSocket591=== PAUSE TestProxyHeadersOnlyTrustedOnSocket592=== RUN TestIsValidCachePath593=== PAUSE TestIsValidCachePath594=== RUN TestReadProxyNarinfo595=== PAUSE TestReadProxyNarinfo596=== RUN TestReadProxyNarinfoAlreadyDecompressed597=== PAUSE TestReadProxyNarinfoAlreadyDecompressed598=== RUN TestReadProxyNarStreaming599=== PAUSE TestReadProxyNarStreaming600=== RUN TestReadProxy404601=== PAUSE TestReadProxy404602=== RUN TestReadProxyInvalidPath603=== PAUSE TestReadProxyInvalidPath604=== RUN TestReadProxyHead605=== PAUSE TestReadProxyHead606=== RUN TestReadProxyConditionalGet607=== PAUSE TestReadProxyConditionalGet608=== RUN TestReadProxyRootRedirectsToIndexHTML609=== PAUSE TestReadProxyRootRedirectsToIndexHTML610=== RUN TestReadProxyDisabled611=== PAUSE TestReadProxyDisabled612=== RUN TestReadRedirectNar613=== PAUSE TestReadRedirectNar614=== RUN TestReadRedirectKeepsNarinfoProxied615=== PAUSE TestReadRedirectKeepsNarinfoProxied616=== RUN TestReadProxyRangeRequest617=== PAUSE TestReadProxyRangeRequest618=== RUN TestReadRedirectUsesPublicS3URL619=== PAUSE TestReadRedirectUsesPublicS3URL620=== RUN TestPush_OverlappingRootsStoreOneRowPerKey621=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey622=== RUN TestPush_CompleteCommitsEveryRoot623=== PAUSE TestPush_CompleteCommitsEveryRoot624=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit625=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit626=== RUN TestPush_RejectsBadRequests627=== PAUSE TestPush_RejectsBadRequests628=== RUN TestPush_SignsNarinfosOfItsPendingObjects629=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects630=== RUN TestRedundantMultipartUpload631=== PAUSE TestRedundantMultipartUpload632=== RUN TestCompleteMultipartUpload_ErrorButObjectExists633=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists634=== RUN TestCompletedNarNotReofferedAcrossClosures635=== PAUSE TestCompletedNarNotReofferedAcrossClosures636=== RUN TestPresignedUploadRegisteredBeforeCommit637=== PAUSE TestPresignedUploadRegisteredBeforeCommit638=== RUN TestService_Rustfstest639=== PAUSE TestService_Rustfstest640=== RUN TestParseSize641=== PAUSE TestParseSize642=== RUN TestSkippedUploadsHandler643=== PAUSE TestSkippedUploadsHandler644=== RUN TestSystemdListenerNotActivated645--- PASS: TestSystemdListenerNotActivated (0.00s)646=== RUN TestWatchdogBeatsWhenHealthy647--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)648=== RUN TestWatchdogSkipsWhenUnhealthy6492026/10/01 09:15:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 09:15:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/01 09:15:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/01 09:15:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6532026/10/01 09:15:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6542026/10/01 09:15:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/01 09:15:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/01 09:15:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/01 09:15:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/01 09:15:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"659--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)660=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle661=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle662=== RUN TestProxyWriteTimeout663=== PAUSE TestProxyWriteTimeout664=== RUN TestIsValidUploadKey665=== PAUSE TestIsValidUploadKey666=== RUN TestUploadHandlersRejectInvalidKeys667=== PAUSE TestUploadHandlersRejectInvalidKeys668=== RUN TestUploadHandlersRejectOversizedBody669=== PAUSE TestUploadHandlersRejectOversizedBody670=== RUN TestService_cleanupPendingClosuresHandler671=== PAUSE TestService_cleanupPendingClosuresHandler672=== RUN TestService_createPendingClosureHandler673=== PAUSE TestService_createPendingClosureHandler674=== RUN TestService_verifyS3Integrity675=== PAUSE TestService_verifyS3Integrity676=== RUN TestCompleteMultipartUnregistered677=== PAUSE TestCompleteMultipartUnregistered678=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT679=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT680=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit681=== CONT TestService_AuthMiddleware682=== CONT TestPush_CompleteCommitsEveryRoot683=== CONT TestPush_OverlappingRootsStoreOneRowPerKey684=== CONT TestReadRedirectUsesPublicS3URL685=== CONT TestReadProxyRangeRequest686=== CONT TestReadRedirectKeepsNarinfoProxied687=== CONT TestReadRedirectNar688=== CONT TestReadProxyDisabled689=== CONT TestReadProxyRootRedirectsToIndexHTML690=== CONT TestReadProxyConditionalGet691=== CONT TestReadProxyHead692=== CONT TestReadProxyInvalidPath693=== CONT TestReadProxy404694=== CONT TestReadProxyNarStreaming695=== CONT TestReadProxyNarinfoAlreadyDecompressed696=== CONT TestReadProxyNarinfo697=== CONT TestIsValidCachePath698=== RUN TestIsValidCachePath/narinfo699=== PAUSE TestIsValidCachePath/narinfo700=== CONT TestProxyHeadersOnlyTrustedOnSocket701=== CONT TestParseSingleRange702=== CONT TestCreatePin_ReservedPins703=== CONT TestOrphanedObjectsGCStressTest704=== CONT TestOrphanedObjectsGC705=== CONT TestObjectStatsTrigger706=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars707=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars708=== RUN TestIsValidCachePath/nar_zst709=== PAUSE TestIsValidCachePath/nar_zst710=== RUN TestParseSingleRange/none711=== PAUSE TestParseSingleRange/none712=== RUN TestIsValidCachePath/nar_xz713=== PAUSE TestIsValidCachePath/nar_xz714=== RUN TestParseSingleRange/unknown_unit715=== PAUSE TestParseSingleRange/unknown_unit716=== RUN TestIsValidCachePath/nar_bz2717=== PAUSE TestIsValidCachePath/nar_bz2718=== RUN TestParseSingleRange/multi-range_ignored719=== PAUSE TestParseSingleRange/multi-range_ignored720=== RUN TestParseSingleRange/malformed_no_dash721=== PAUSE TestParseSingleRange/malformed_no_dash722=== RUN TestParseSingleRange/malformed_both_empty723=== RUN TestIsValidCachePath/nar_uncompressed724=== PAUSE TestIsValidCachePath/nar_uncompressed725=== PAUSE TestParseSingleRange/malformed_both_empty726=== RUN TestParseSingleRange/malformed_end_before_start727=== PAUSE TestParseSingleRange/malformed_end_before_start728=== RUN TestParseSingleRange/closed729=== RUN TestIsValidCachePath/ls730=== PAUSE TestParseSingleRange/closed731=== RUN TestParseSingleRange/open-ended732=== PAUSE TestIsValidCachePath/ls733=== PAUSE TestParseSingleRange/open-ended734=== RUN TestParseSingleRange/end_clamped_to_size735=== PAUSE TestParseSingleRange/end_clamped_to_size736=== RUN TestParseSingleRange/suffix737=== PAUSE TestParseSingleRange/suffix738=== RUN TestParseSingleRange/suffix_exceeds_size739=== RUN TestIsValidCachePath/log740=== PAUSE TestIsValidCachePath/log741=== PAUSE TestParseSingleRange/suffix_exceeds_size742=== RUN TestParseSingleRange/single_byte743=== PAUSE TestParseSingleRange/single_byte744=== RUN TestParseSingleRange/start_past_EOF745=== PAUSE TestParseSingleRange/start_past_EOF746=== RUN TestParseSingleRange/start_far_past_EOF747=== PAUSE TestParseSingleRange/start_far_past_EOF748=== RUN TestIsValidCachePath/realisation749=== CONT TestMultipartCleanup750=== PAUSE TestIsValidCachePath/realisation751=== RUN TestIsValidCachePath/nix-cache-info752=== PAUSE TestIsValidCachePath/nix-cache-info753=== RUN TestIsValidCachePath/index.html754=== PAUSE TestIsValidCachePath/index.html755=== RUN TestIsValidCachePath/traversal_parent756=== PAUSE TestIsValidCachePath/traversal_parent757=== RUN TestIsValidCachePath/traversal_in_middle758=== PAUSE TestIsValidCachePath/traversal_in_middle759=== RUN TestIsValidCachePath/invalid_char_e760=== PAUSE TestIsValidCachePath/invalid_char_e761=== RUN TestIsValidCachePath/invalid_char_u762=== PAUSE TestIsValidCachePath/invalid_char_u763=== RUN TestIsValidCachePath/random_path764=== PAUSE TestIsValidCachePath/random_path765=== RUN TestIsValidCachePath/empty766=== PAUSE TestIsValidCachePath/empty767=== RUN TestIsValidCachePath/leading_slash768=== PAUSE TestIsValidCachePath/leading_slash769=== RUN TestIsValidCachePath/wrong_extension770=== PAUSE TestIsValidCachePath/wrong_extension771=== RUN TestIsValidCachePath/short_hash772=== PAUSE TestIsValidCachePath/short_hash773=== CONT TestServerTLSConfig774=== RUN TestServerTLSConfig/no_client_CA775=== PAUSE TestServerTLSConfig/no_client_CA776=== RUN TestServerTLSConfig/missing_CA_file777=== PAUSE TestServerTLSConfig/missing_CA_file778=== RUN TestServerTLSConfig/not_a_PEM_file779=== PAUSE TestServerTLSConfig/not_a_PEM_file780=== CONT TestService_NativeMTLS7812026/10/01 09:15:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42821/oidc7822026-10-01 09:15:20.641 UTC [646] ERROR: relation "goose_db_version" does not exist at character 367832026-10-01 09:15:20.641 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7842026-10-01 09:15:20.659 UTC [647] ERROR: relation "goose_db_version" does not exist at character 367852026-10-01 09:15:20.659 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026-10-01 09:15:20.669 UTC [649] ERROR: relation "goose_db_version" does not exist at character 367872026-10-01 09:15:20.669 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7882026-10-01 09:15:20.671 UTC [648] ERROR: relation "goose_db_version" does not exist at character 367892026-10-01 09:15:20.671 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7902026/10/01 09:15:20 OK 20241026095416_initial_model.sql (37.17ms)7912026/10/01 09:15:20 OK 20241026095416_initial_model.sql (29.73ms)7922026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)7932026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (3.34ms)7942026/10/01 09:15:20 OK 20251218171726_add_pins.sql (7.53ms)7952026/10/01 09:15:20 OK 20251218171726_add_pins.sql (8.95ms)7962026/10/01 09:15:20 OK 20241026095416_initial_model.sql (32.33ms)7972026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (6.84ms)7982026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (8.26ms)7992026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (3.72ms)8002026-10-01 09:15:20.723 UTC [650] ERROR: relation "goose_db_version" does not exist at character 368012026-10-01 09:15:20.723 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8022026/10/01 09:15:20 OK 20241026095416_initial_model.sql (24.96ms)8032026-10-01 09:15:20.726 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368042026-10-01 09:15:20.726 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8052026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.72ms)8062026-10-01 09:15:20.728 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368072026-10-01 09:15:20.728 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8082026/10/01 09:15:20 OK 20260905000000_add_claims.sql (5.99ms)8092026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (4.63ms)8102026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (5.52ms)8112026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (3.58ms)8122026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200008132026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (5.31ms)8142026/10/01 09:15:20 OK 20251218171726_add_pins.sql (8.62ms)8152026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.28ms)8162026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (15.05ms)8172026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200008182026/10/01 09:15:20 OK 2_object_stats_trigger.sql (15.03ms)8192026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (18.74ms)8202026/10/01 09:15:20 OK 3_commit_push.sql (2.71ms)8212026/10/01 09:15:20 goose: up to current file version: 38222026/10/01 09:15:20 OK 1_commit_pending_closure.sql (6.32ms)8232026/10/01 09:15:20 OK 20251218171726_add_pins.sql (22.82ms)8242026/10/01 09:15:20 OK 2_object_stats_trigger.sql (4.76ms)8252026/10/01 09:15:20 OK 3_commit_push.sql (2.45ms)8262026/10/01 09:15:20 goose: up to current file version: 38272026/10/01 09:15:20 OK 20241026095416_initial_model.sql (34.11ms)8282026/10/01 09:15:20 OK 20260905000000_add_claims.sql (12.62ms)8292026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (3.61ms)8302026-10-01 09:15:20.771 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368312026-10-01 09:15:20.771 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8322026/10/01 09:15:20 OK 20241026095416_initial_model.sql (36.59ms)8332026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (14.25ms)8342026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (5.58ms)8352026/10/01 09:15:20 OK 20241026095416_initial_model.sql (21.04ms)8362026/10/01 09:15:20 OK 20251218171726_add_pins.sql (7.17ms)8372026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (4.32ms)8382026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200008392026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (5.7ms)8402026/10/01 09:15:20 OK 20260905000000_add_claims.sql (6.77ms)8412026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (3.25ms)8422026/10/01 09:15:20 INFO Received push request method=POST path=/api/pushes8432026-10-01 09:15:20.783 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368442026-10-01 09:15:20.783 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8452026-10-01 09:15:20.783 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368462026-10-01 09:15:20.783 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8472026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.65ms)8482026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (5.09ms)8492026/10/01 09:15:20 OK 1_commit_pending_closure.sql (6.09ms)8502026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (6.42ms)8512026/10/01 09:15:20 OK 20251218171726_add_pins.sql (5.88ms)8522026-10-01 09:15:20.797 UTC [660] ERROR: relation "goose_db_version" does not exist at character 368532026-10-01 09:15:20.797 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8542026-10-01 09:15:20.797 UTC [659] ERROR: relation "goose_db_version" does not exist at character 368552026-10-01 09:15:20.797 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8562026-10-01 09:15:20.799 UTC [661] ERROR: relation "goose_db_version" does not exist at character 368572026-10-01 09:15:20.799 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8582026/10/01 09:15:20 OK 2_object_stats_trigger.sql (17.32ms)8592026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (22.11ms)8602026/10/01 09:15:20 OK 20241026095416_initial_model.sql (26.87ms)8612026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200008622026/10/01 09:15:20 OK 20260905000000_add_claims.sql (22.03ms)8632026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (21.89ms)8642026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (22.36ms)8652026/10/01 09:15:20 OK 3_commit_push.sql (5.78ms)8662026/10/01 09:15:20 goose: up to current file version: 38672026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.28ms)8682026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (4.92ms)8692026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.91ms)8702026/10/01 09:15:20 OK 1_commit_pending_closure.sql (5.87ms)8712026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.71ms)8722026/10/01 09:15:20 OK 20260905000000_add_claims.sql (5.98ms)8732026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (3.05ms)8742026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (4.29ms)8752026/10/01 09:15:20 OK 2_object_stats_trigger.sql (3.63ms)8762026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200008772026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (3.69ms)8782026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (3.18ms)8792026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200008802026-10-01 09:15:20.820 UTC [663] ERROR: relation "goose_db_version" does not exist at character 368812026-10-01 09:15:20.820 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8822026/10/01 09:15:20 OK 3_commit_push.sql (3.39ms)8832026-10-01 09:15:20.821 UTC [664] ERROR: relation "goose_db_version" does not exist at character 368842026-10-01 09:15:20.821 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8852026/10/01 09:15:20 goose: up to current file version: 38862026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (6.74ms)8872026/10/01 09:15:20 OK 20241026095416_initial_model.sql (13.78ms)8882026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.85ms)8892026/10/01 09:15:20 OK 20241026095416_initial_model.sql (14.25ms)890--- PASS: TestReadRedirectUsesPublicS3URL (0.41s)891=== CONT TestMetricsInventory8922026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.48ms)8932026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (3.62ms)8942026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200008952026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.61ms)8962026/10/01 09:15:20 INFO Received complete push request method=POST path=/api/pushes/1/complete8972026/10/01 09:15:20 OK 20260905000000_add_claims.sql (3.4ms)8982026/10/01 09:15:20 OK 1_commit_pending_closure.sql (5.05ms)8992026/10/01 09:15:20 OK 3_commit_push.sql (1.44ms)9002026/10/01 09:15:20 goose: up to current file version: 39012026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)9022026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.41ms)9032026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.6ms)9042026/10/01 09:15:20 OK 3_commit_push.sql (2.07ms)9052026/10/01 09:15:20 goose: up to current file version: 39062026/10/01 09:15:20 OK 20241026095416_initial_model.sql (11.94ms)9072026/10/01 09:15:20 OK 1_commit_pending_closure.sql (5.04ms)9082026/10/01 09:15:20 OK 20251218171726_add_pins.sql (5.01ms)9092026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.74ms)9102026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200009112026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.3ms)9122026/10/01 09:15:20 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"913--- PASS: TestService_AuthMiddleware (0.42s)9142026/10/01 09:15:20 OK 20241026095416_initial_model.sql (13.72ms)915=== CONT TestNARDeduplicationMetadataUploadBug9162026-10-01 09:15:20.833 UTC [672] ERROR: relation "goose_db_version" does not exist at character 369172026-10-01 09:15:20.833 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9182026/10/01 09:15:20 OK 2_object_stats_trigger.sql (1.8ms)9192026-10-01 09:15:20.834 UTC [671] ERROR: relation "goose_db_version" does not exist at character 369202026-10-01 09:15:20.834 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9212026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)9222026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)923--- PASS: TestPush_CompleteCommitsEveryRoot (0.43s)924=== CONT TestCreatePendingClosureRejectsOversizedNAR9252026/10/01 09:15:20 INFO Received uploads request method=POST path=/api/pending_closures9262026/10/01 09:15:20 OK 3_commit_push.sql (1.65ms)927--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)9282026/10/01 09:15:20 goose: up to current file version: 3929=== CONT TestCacheConfigHandlerMaxNarSize9302026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.46ms)931--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)932=== CONT TestGenerateLandingPage9332026-10-01 09:15:20.837 UTC [674] ERROR: relation "goose_db_version" does not exist at character 369342026-10-01 09:15:20.837 UTC [674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9352026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)9362026-10-01 09:15:20.838 UTC [675] ERROR: relation "goose_db_version" does not exist at character 369372026-10-01 09:15:20.838 UTC [675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9382026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (5.56ms)9392026-10-01 09:15:20.839 UTC [676] ERROR: relation "goose_db_version" does not exist at character 369402026-10-01 09:15:20.839 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9412026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.67ms)9422026/10/01 09:15:20 OK 20251218171726_add_pins.sql (3.81ms)9432026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.68ms)9442026-10-01 09:15:20.840 UTC [678] ERROR: relation "goose_db_version" does not exist at character 369452026-10-01 09:15:20.840 UTC [678] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9462026/10/01 09:15:20 OK 20260905000000_add_claims.sql (3.18ms)9472026/10/01 09:15:20 OK 3_commit_push.sql (2.17ms)9482026/10/01 09:15:20 goose: up to current file version: 39492026/10/01 09:15:20 OK 20241026095416_initial_model.sql (16.9ms)950--- PASS: TestGenerateLandingPage (0.01s)951=== CONT TestService_readinessHandler9522026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.41ms)9532026-10-01 09:15:20.843 UTC [679] ERROR: relation "goose_db_version" does not exist at character 369542026-10-01 09:15:20.843 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9552026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.68ms)9562026/10/01 09:15:20 OK 20241026095416_initial_model.sql (10.21ms)9572026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (5.06ms)9582026/10/01 09:15:20 OK 20241026095416_initial_model.sql (11.43ms)9592026-10-01 09:15:20.844 UTC [681] ERROR: relation "goose_db_version" does not exist at character 369602026-10-01 09:15:20.844 UTC [681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9612026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (5.22ms)9622026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (3.11ms)9632026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.16ms)9642026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200009652026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (3.54ms)9662026-10-01 09:15:20.846 UTC [682] ERROR: relation "goose_db_version" does not exist at character 369672026-10-01 09:15:20.846 UTC [682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9682026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)9692026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)9702026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.46ms)9712026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.21ms)9722026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.1ms)9732026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200009742026/10/01 09:15:20 OK 20260905000000_add_claims.sql (3.81ms)9752026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.6ms)9762026/10/01 09:15:20 OK 2_object_stats_trigger.sql (1.57ms)9772026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.23ms)9782026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.99ms)9792026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (3.34ms)9802026/10/01 09:15:20 OK 3_commit_push.sql (2.08ms)9812026/10/01 09:15:20 goose: up to current file version: 39822026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.47ms)9832026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.57ms)9842026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.3ms)9852026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200009862026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (3.39ms)9872026/10/01 09:15:20 goose: successfully migrated database to version: 202609231200009882026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.95ms)9892026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (5.1ms)9902026/10/01 09:15:20 OK 20241026095416_initial_model.sql (12.75ms)9912026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (7.18ms)9922026/10/01 09:15:20 INFO Received push request method=POST path=/api/pushes9932026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.19ms)9942026/10/01 09:15:20 OK 20241026095416_initial_model.sql (13.8ms)9952026/10/01 09:15:20 OK 3_commit_push.sql (1.77ms)9962026/10/01 09:15:20 goose: up to current file version: 39972026/10/01 09:15:20 OK 20241026095416_initial_model.sql (12.59ms)9982026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)9992026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.41ms)10002026/10/01 09:15:20 OK 20241026095416_initial_model.sql (12.75ms)10012026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (6.4ms)10022026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.19ms)10032026/10/01 09:15:20 OK 20241026095416_initial_model.sql (14ms)10042026/10/01 09:15:20 OK 20260905000000_add_claims.sql (3.94ms)10052026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)10062026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.45ms)10072026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.36ms)10082026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)10092026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.5ms)10102026/10/01 09:15:20 OK 20241026095416_initial_model.sql (15.19ms)10112026/10/01 09:15:20 OK 3_commit_push.sql (2.22ms)10122026/10/01 09:15:20 goose: up to current file version: 310132026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)10142026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.78ms)10152026/10/01 09:15:20 OK 3_commit_push.sql (1.92ms)10162026/10/01 09:15:20 goose: up to current file version: 310172026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.16ms)10182026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.42ms)10192026/10/01 09:15:20 OK 20241026095416_initial_model.sql (12.8ms)10202026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.77ms)10212026/10/01 09:15:20 OK 20241026095416_initial_model.sql (12.05ms)10222026/10/01 09:15:20 OK 20241026095416_initial_model.sql (12.08ms)10232026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (3.31ms)10242026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.97ms)10252026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000010262026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.39ms)10272026/10/01 09:15:20 OK 20251218171726_add_pins.sql (5.83ms)10282026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.53ms)10292026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)10302026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (3ms)10312026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (3ms)10322026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000010332026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)10342026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)10352026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.95ms)10362026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (4.87ms)10372026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.74ms)10382026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.86ms)10392026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (3.18ms)10402026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000010412026/10/01 09:15:20 OK 20251218171726_add_pins.sql (3.55ms)10422026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (4.9ms)10432026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (4.8ms)10442026/10/01 09:15:20 OK 20251218171726_add_pins.sql (4.76ms)10452026/10/01 09:15:20 OK 20251218171726_add_pins.sql (3.58ms)10462026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.78ms)10472026/10/01 09:15:20 OK 20260905000000_add_claims.sql (3.2ms)10482026/10/01 09:15:20 OK 2_object_stats_trigger.sql (1.92ms)10492026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)10502026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (5.67ms)10512026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.03ms)10522026/10/01 09:15:20 OK 3_commit_push.sql (2.44ms)10532026/10/01 09:15:20 goose: up to current file version: 310542026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.92ms)10552026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (3.09ms)10562026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.4ms)10572026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (5.73ms)10582026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)10592026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.62ms)10602026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.45ms)10612026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (5.48ms)10622026/10/01 09:15:20 OK 3_commit_push.sql (2.02ms)10632026/10/01 09:15:20 goose: up to current file version: 310642026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.67ms)10652026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (5.39ms)10662026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.6ms)10672026/10/01 09:15:20 OK 3_commit_push.sql (1.97ms)10682026/10/01 09:15:20 goose: up to current file version: 310692026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.78ms)10702026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000010712026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.72ms)10722026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.98ms)10732026/10/01 09:15:20 INFO Received complete push request method=POST path=/api/pushes/1/complete10742026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (3.03ms)10752026/10/01 09:15:20 OK 20260905000000_add_claims.sql (4.92ms)10762026/10/01 09:15:20 OK 20260905000000_add_claims.sql (3.61ms)10772026/10/01 09:15:20 OK 20260905000000_add_claims.sql (3.92ms)10782026/10/01 09:15:20 OK 20260905000000_add_claims.sql (5.02ms)10792026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (4.25ms)10802026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.58ms)10812026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (3ms)10822026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000010832026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (3.06ms)10842026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000010852026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.05ms)10862026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000010872026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.11ms)10882026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.84ms)10892026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.78ms)10902026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.85ms)10912026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.29ms)10922026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.22ms)10932026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000010942026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.17ms)10952026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.22ms)10962026/10/01 09:15:20 OK 1_commit_pending_closure.sql (2.71ms)10972026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (3.6ms)10982026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000010992026/10/01 09:15:20 OK 3_commit_push.sql (1.74ms)11002026/10/01 09:15:20 goose: up to current file version: 311012026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (1.95ms)11022026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000011032026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.13ms)11042026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000011052026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (3.1ms)11062026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000011072026/10/01 09:15:20 INFO Received push request method=POST path=/api/pushes11082026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.67ms)11092026/10/01 09:15:20 INFO Received push request method=POST path=/api/pushes11102026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.54ms)11112026/10/01 09:15:20 OK 1_commit_pending_closure.sql (2.76ms)11122026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.65ms)11132026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.29ms)11142026/10/01 09:15:20 OK 1_commit_pending_closure.sql (2.53ms)11152026/10/01 09:15:20 OK 1_commit_pending_closure.sql (2.32ms)11162026/10/01 09:15:20 OK 3_commit_push.sql (1.46ms)11172026/10/01 09:15:20 goose: up to current file version: 311182026/10/01 09:15:20 OK 3_commit_push.sql (1.9ms)11192026/10/01 09:15:20 goose: up to current file version: 311202026/10/01 09:15:20 OK 1_commit_pending_closure.sql (3.33ms)11212026/10/01 09:15:20 OK 3_commit_push.sql (2.09ms)11222026/10/01 09:15:20 goose: up to current file version: 311232026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.21ms)11242026/10/01 09:15:20 OK 2_object_stats_trigger.sql (9.75ms)11252026/10/01 09:15:20 OK 2_object_stats_trigger.sql (9.67ms)11262026/10/01 09:15:20 OK 2_object_stats_trigger.sql (9.86ms)11272026/10/01 09:15:20 OK 3_commit_push.sql (8.85ms)11282026/10/01 09:15:20 goose: up to current file version: 311292026/10/01 09:15:20 OK 2_object_stats_trigger.sql (9.24ms)11302026/10/01 09:15:20 OK 3_commit_push.sql (2.39ms)11312026/10/01 09:15:20 goose: up to current file version: 311322026/10/01 09:15:20 OK 3_commit_push.sql (2.33ms)11332026/10/01 09:15:20 goose: up to current file version: 311342026/10/01 09:15:20 OK 3_commit_push.sql (2.51ms)11352026/10/01 09:15:20 goose: up to current file version: 311362026/10/01 09:15:20 OK 3_commit_push.sql (1.85ms)11372026/10/01 09:15:20 goose: up to current file version: 31138--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.51s)1139=== CONT TestService_healthCheckHandler1140--- PASS: TestReadRedirectKeepsNarinfoProxied (0.52s)1141=== CONT TestGracefulShutdownDrainsInflight11422026/10/01 09:15:20 INFO Starting HTTP server address=127.0.0.1:4462111432026/10/01 09:15:20 INFO Shutdown signal received, draining in-flight requests timeout=10s11442026-10-01 09:15:20.945 UTC [690] ERROR: relation "goose_db_version" does not exist at character 3611452026-10-01 09:15:20.945 UTC [690] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11462026-10-01 09:15:20.948 UTC [691] ERROR: relation "goose_db_version" does not exist at character 3611472026-10-01 09:15:20.948 UTC [691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026-10-01 09:15:20.951 UTC [692] ERROR: relation "goose_db_version" does not exist at character 3611492026-10-01 09:15:20.951 UTC [692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1150--- PASS: TestReadProxyRangeRequest (0.54s)1151=== CONT TestGCTaskStore_Fail1152--- PASS: TestGCTaskStore_Fail (0.00s)1153=== CONT TestGCTaskStore_PhaseUpdates1154--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1155=== CONT TestGCTaskStore_CompletedAllowsNewTask1156--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1157=== CONT TestGCTaskStore_GetReturnsLatest1158--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1159=== CONT TestGCTaskStore_GetEmpty1160--- PASS: TestGCTaskStore_GetEmpty (0.00s)1161=== CONT TestGCTaskStore_ConflictDifferentParams1162--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1163=== CONT TestGCTaskStore_DeduplicateSameParams1164--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1165=== CONT TestGCTaskStore_StartNew1166--- PASS: TestGCTaskStore_StartNew (0.00s)1167=== CONT TestCommitRacingPendingCleanupKeepsObjects11682026/10/01 09:15:20 OK 20241026095416_initial_model.sql (7.77ms)11692026/10/01 09:15:20 INFO Aborted multipart uploads count=011702026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)11712026/10/01 09:15:20 OK 20241026095416_initial_model.sql (8.01ms)11722026/10/01 09:15:20 OK 20251218171726_add_pins.sql (2.67ms)11732026/10/01 09:15:20 OK 20241026095416_initial_model.sql (8.26ms)11742026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)11752026/10/01 09:15:20 WARN Force mode enabled - objects will be deleted immediately without grace period11762026/10/01 09:15:20 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)11772026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)11782026/10/01 09:15:20 OK 20251218171726_add_pins.sql (3.11ms)11792026/10/01 09:15:20 OK 20251218171726_add_pins.sql (3.27ms)11802026/10/01 09:15:20 OK 20260905000000_add_claims.sql (3.61ms)11812026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (3.58ms)11822026/10/01 09:15:20 OK 20260628120000_add_object_size_and_stats.sql (3.17ms)11832026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.19ms)11842026/10/01 09:15:20 OK 20260905000000_add_claims.sql (2.96ms)11852026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.83ms)11862026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000011872026/10/01 09:15:20 OK 20260905000000_add_claims.sql (3.25ms)11882026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (3.1ms)11892026/10/01 09:15:20 OK 20260920000000_drop_claims.sql (2.51ms)1190--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.56s)1191=== CONT TestPushWaitsForSweepHoldingRow11922026/10/01 09:15:20 OK 1_commit_pending_closure.sql (2.88ms)11932026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (2.07ms)11942026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000011952026/10/01 09:15:20 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=011962026/10/01 09:15:20 OK 2_object_stats_trigger.sql (1.6ms)11972026/10/01 09:15:20 OK 20260923120000_add_pushes.sql (1.92ms)11982026/10/01 09:15:20 goose: successfully migrated database to version: 2026092312000011992026/10/01 09:15:20 OK 3_commit_push.sql (1.55ms)12002026/10/01 09:15:20 goose: up to current file version: 312012026/10/01 09:15:20 OK 1_commit_pending_closure.sql (2.97ms)12022026/10/01 09:15:20 OK 1_commit_pending_closure.sql (2.02ms)12032026/10/01 09:15:20 OK 2_object_stats_trigger.sql (1.43ms)12042026/10/01 09:15:20 OK 2_object_stats_trigger.sql (2.37ms)12052026/10/01 09:15:20 INFO Vacuumed table table=pending_closures12062026/10/01 09:15:20 OK 3_commit_push.sql (1.76ms)12072026/10/01 09:15:20 goose: up to current file version: 312082026/10/01 09:15:20 OK 3_commit_push.sql (1.47ms)12092026/10/01 09:15:20 goose: up to current file version: 312102026/10/01 09:15:20 INFO Vacuumed table table=pending_objects12112026/10/01 09:15:20 INFO Vacuumed table table=multipart_uploads12122026/10/01 09:15:20 INFO Vacuumed table table=closures1213--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1214=== CONT TestSweepRechecksPendingAfterLocking12152026/10/01 09:15:20 INFO Vacuumed table table=objects12162026/10/01 09:15:21 INFO Received complete push request method=POST path=/api/pushes/2/complete1217--- PASS: TestReadProxyDisabled (0.59s)1218=== CONT TestGetExistingObjectsLocksRows1219--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.60s)1220=== CONT TestRegisterCompletedObjectNeedsPendingRow12212026-10-01 09:15:21.030 UTC [703] ERROR: relation "goose_db_version" does not exist at character 3612222026-10-01 09:15:21.030 UTC [703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1223--- PASS: TestReadProxyNarinfo (0.62s)1224=== CONT TestSweepSkipsRowsLockedByPush12252026/10/01 09:15:21 OK 20241026095416_initial_model.sql (11.31ms)12262026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (6.89ms)12272026-10-01 09:15:21.058 UTC [706] ERROR: relation "goose_db_version" does not exist at character 3612282026-10-01 09:15:21.058 UTC [706] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12292026/10/01 09:15:21 OK 20251218171726_add_pins.sql (4.6ms)12302026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (5.54ms)1231--- PASS: TestReadRedirectNar (0.66s)1232=== CONT TestFailedS3DeleteKeepsTombstone12332026/10/01 09:15:21 OK 20260905000000_add_claims.sql (7.43ms)12342026/10/01 09:15:21 OK 20241026095416_initial_model.sql (11.36ms)12352026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (3.01ms)12362026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)12372026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (3.46ms)12382026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000012392026/10/01 09:15:21 OK 20251218171726_add_pins.sql (4.65ms)12402026/10/01 09:15:21 OK 1_commit_pending_closure.sql (3.12ms)12412026/10/01 09:15:21 OK 2_object_stats_trigger.sql (2.66ms)12422026-10-01 09:15:21.094 UTC [709] ERROR: relation "goose_db_version" does not exist at character 3612432026-10-01 09:15:21.094 UTC [709] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12442026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (13.86ms)12452026/10/01 09:15:21 OK 3_commit_push.sql (13.03ms)12462026/10/01 09:15:21 goose: up to current file version: 312472026/10/01 09:15:21 OK 20260905000000_add_claims.sql (4.6ms)12482026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (3.33ms)12492026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (4.03ms)12502026/10/01 09:15:21 goose: successfully migrated database to version: 202609231200001251--- PASS: TestReadProxyConditionalGet (0.70s)1252=== CONT TestForceGCDuringPushOffersSweptObject1253=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1254=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1255=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1256=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check12572026/10/01 09:15:21 OK 20241026095416_initial_model.sql (10.8ms)1258=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12592026/10/01 09:15:21 OK 1_commit_pending_closure.sql (3.39ms)12602026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)12612026/10/01 09:15:21 OK 2_object_stats_trigger.sql (2.74ms)12622026/10/01 09:15:21 OK 3_commit_push.sql (1.47ms)12632026/10/01 09:15:21 goose: up to current file version: 312642026/10/01 09:15:21 OK 20251218171726_add_pins.sql (4.06ms)1265--- PASS: TestReadProxyHead (0.71s)1266=== CONT TestGCSweepDeliversEachKeyOnce12672026-10-01 09:15:21.125 UTC [711] ERROR: relation "goose_db_version" does not exist at character 3612682026-10-01 09:15:21.125 UTC [711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12692026-10-01 09:15:21.127 UTC [713] ERROR: relation "goose_db_version" does not exist at character 3612702026-10-01 09:15:21.127 UTC [713] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12712026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)12722026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3ms)12732026-10-01 09:15:21.132 UTC [715] ERROR: relation "goose_db_version" does not exist at character 3612742026-10-01 09:15:21.132 UTC [715] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12752026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (3.45ms)12762026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.64ms)12772026/10/01 09:15:21 goose: successfully migrated database to version: 202609231200001278--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.73s)1279=== CONT TestTombstonedObjectOfferedWithoutWaiting12802026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.49ms)12812026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)12822026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.59ms)12832026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.35ms)12842026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.81ms)12852026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)12862026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.72ms)12872026/10/01 09:15:21 OK 3_commit_push.sql (1.92ms)12882026/10/01 09:15:21 goose: up to current file version: 312892026/10/01 09:15:21 OK 20251218171726_add_pins.sql (4.21ms)12902026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)12912026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.65ms)12922026-10-01 09:15:21.152 UTC [718] ERROR: relation "goose_db_version" does not exist at character 3612932026-10-01 09:15:21.152 UTC [718] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12942026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.48ms)12952026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)12962026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)12972026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.2ms)12982026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.58ms)12992026/10/01 09:15:21 OK 20251218171726_add_pins.sql (4.14ms)13002026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.77ms)13012026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000013022026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.48ms)13032026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.32ms)13042026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.93ms)13052026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.31ms)13062026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.33ms)13072026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000013082026/10/01 09:15:21 OK 3_commit_push.sql (1.77ms)13092026/10/01 09:15:21 goose: up to current file version: 313102026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.49ms)13112026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.7ms)13122026/10/01 09:15:21 OK 20241026095416_initial_model.sql (15.76ms)13132026/10/01 09:15:21 OK 2_object_stats_trigger.sql (8.99ms)13142026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (9.35ms)13152026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)13162026/10/01 09:15:21 OK 3_commit_push.sql (2.08ms)13172026/10/01 09:15:21 goose: up to current file version: 313182026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.09ms)13192026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000013202026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.27ms)13212026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.63ms)13222026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.42ms)13232026/10/01 09:15:21 OK 3_commit_push.sql (1.29ms)13242026/10/01 09:15:21 goose: up to current file version: 313252026-10-01 09:15:21.183 UTC [720] ERROR: relation "goose_db_version" does not exist at character 3613262026-10-01 09:15:21.183 UTC [720] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13272026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)13282026/10/01 09:15:21 OK 20260905000000_add_claims.sql (2.86ms)13292026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.31ms)13302026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.09ms)13312026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000013322026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.36ms)1333--- PASS: TestReadProxyNarStreaming (0.78s)1334=== CONT TestGCSweepSkipsPendingObjects13352026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.72ms)1336--- PASS: TestObjectStatsTrigger (0.78s)1337=== CONT TestDeduplicatedObjectsRecordedAsPending13382026/10/01 09:15:21 OK 3_commit_push.sql (1.69ms)13392026/10/01 09:15:21 goose: up to current file version: 313402026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.13ms)13412026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)13422026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.74ms)13432026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)13442026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.22ms)13452026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.44ms)13462026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.2ms)13472026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000013482026/10/01 09:15:21 OK 1_commit_pending_closure.sql (3.65ms)13492026-10-01 09:15:21.224 UTC [725] ERROR: relation "goose_db_version" does not exist at character 3613502026-10-01 09:15:21.224 UTC [725] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13512026/10/01 09:15:21 OK 2_object_stats_trigger.sql (2.23ms)13522026/10/01 09:15:21 OK 3_commit_push.sql (2.29ms)13532026/10/01 09:15:21 goose: up to current file version: 313542026-10-01 09:15:21.228 UTC [726] ERROR: relation "goose_db_version" does not exist at character 3613552026-10-01 09:15:21.228 UTC [726] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13562026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.05ms)13572026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)13582026/10/01 09:15:21 INFO Starting HTTP server address=127.0.0.1:4501113592026/10/01 09:15:21 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1163627076/001/proxy.sock13602026/10/01 09:15:21 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13612026/10/01 09:15:21 INFO Shutdown signal received, draining in-flight requests timeout=10s13622026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.42ms)1363--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.83s)1364=== CONT TestPushDedupSurvivesConcurrentGC13652026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.84ms)13662026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)13672026-10-01 09:15:21.246 UTC [727] ERROR: relation "goose_db_version" does not exist at character 3613682026-10-01 09:15:21.246 UTC [727] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13692026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)13702026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.91ms)13712026/10/01 09:15:21 OK 20260905000000_add_claims.sql (2.97ms)13722026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (2.81ms)13732026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (1.42ms)13742026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (1.89ms)13752026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000013762026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.41ms)13772026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.05ms)13782026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (3.02ms)13792026/10/01 09:15:21 OK 2_object_stats_trigger.sql (2.1ms)13802026/10/01 09:15:21 OK 3_commit_push.sql (1.34ms)13812026/10/01 09:15:21 goose: up to current file version: 313822026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.87ms)13832026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000013842026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.74ms)13852026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)13862026/10/01 09:15:21 OK 1_commit_pending_closure.sql (10.07ms)13872026/10/01 09:15:21 OK 20251218171726_add_pins.sql (10.18ms)13882026/10/01 09:15:21 OK 2_object_stats_trigger.sql (3.35ms)13892026/10/01 09:15:21 OK 3_commit_push.sql (3.12ms)13902026/10/01 09:15:21 goose: up to current file version: 313912026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (5.96ms)13922026/10/01 09:15:21 OK 20260905000000_add_claims.sql (4.44ms)13932026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (3.08ms)13942026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.55ms)13952026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000013962026/10/01 09:15:21 OK 1_commit_pending_closure.sql (1.99ms)13972026/10/01 09:15:21 OK 2_object_stats_trigger.sql (947.5µs)13982026/10/01 09:15:21 OK 3_commit_push.sql (542.51µs)13992026/10/01 09:15:21 goose: up to current file version: 314002026/10/01 09:15:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14012026/10/01 09:15:21 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1402--- PASS: TestService_NativeMTLS (0.87s)1403=== CONT TestGCMetrics14042026-10-01 09:15:21.302 UTC [731] ERROR: relation "goose_db_version" does not exist at character 3614052026-10-01 09:15:21.302 UTC [731] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14062026-10-01 09:15:21.304 UTC [732] ERROR: relation "goose_db_version" does not exist at character 3614072026-10-01 09:15:21.304 UTC [732] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14082026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.66ms)14092026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.97ms)14102026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (3.12ms)14112026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)14122026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.34ms)14132026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2ms)1414--- PASS: TestReadProxy404 (0.91s)1415=== CONT TestGCBugBareHashReferences14162026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.45ms)14172026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)14182026/10/01 09:15:21 OK 20260905000000_add_claims.sql (4.06ms)14192026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.56ms)14202026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.3ms)14212026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.41ms)14222026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2ms)14232026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000014242026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (1.78ms)14252026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000014262026/10/01 09:15:21 OK 1_commit_pending_closure.sql (1.51ms)14272026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.35ms)14282026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.67ms)14292026/10/01 09:15:21 OK 3_commit_push.sql (685.18µs)14302026/10/01 09:15:21 goose: up to current file version: 314312026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.33ms)14322026/10/01 09:15:21 OK 3_commit_push.sql (1.43ms)14332026/10/01 09:15:21 goose: up to current file version: 314342026-10-01 09:15:21.342 UTC [736] ERROR: relation "goose_db_version" does not exist at character 3614352026-10-01 09:15:21.342 UTC [736] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14362026/10/01 09:15:21 INFO Received uploads request method=POST path=/api/pending_closures14372026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.59ms)14382026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)14392026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.57ms)14402026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.12ms)14412026/10/01 09:15:21 OK 20260905000000_add_claims.sql (2.85ms)14422026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.69ms)14432026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.09ms)14442026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000014452026/10/01 09:15:21 OK 1_commit_pending_closure.sql (1.83ms)14462026/10/01 09:15:21 OK 2_object_stats_trigger.sql (965.31µs)14472026/10/01 09:15:21 OK 3_commit_push.sql (1.17ms)14482026/10/01 09:15:21 goose: up to current file version: 314492026/10/01 09:15:21 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14502026/10/01 09:15:21 WARN Refused reserved pin name=worker-x86_64-linux14512026/10/01 09:15:21 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14522026/10/01 09:15:21 INFO Received create pin request method=POST path=/api/pins/my-app14532026/10/01 09:15:21 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1454--- PASS: TestCreatePin_ReservedPins (0.97s)1455=== CONT TestLeadEndsOnShutdown14562026-10-01 09:15:21.393 UTC [738] ERROR: relation "goose_db_version" does not exist at character 3614572026-10-01 09:15:21.393 UTC [738] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1458--- PASS: TestReadProxyInvalidPath (0.99s)1459=== CONT TestLeadElectsOneAndHandsOver14602026/10/01 09:15:21 OK 20241026095416_initial_model.sql (12.95ms)14612026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)14622026-10-01 09:15:21.421 UTC [742] ERROR: relation "goose_db_version" does not exist at character 3614632026-10-01 09:15:21.421 UTC [742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14642026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.38ms)14652026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)14662026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.25ms)14672026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (3.11ms)14682026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.36ms)14692026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (1.92ms)14702026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000014712026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)14722026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.7ms)14732026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.23ms)14742026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.91ms)14752026/10/01 09:15:21 OK 3_commit_push.sql (1.31ms)14762026/10/01 09:15:21 goose: up to current file version: 314772026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.75ms)14782026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.85ms)14792026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (1.88ms)14802026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.2ms)14812026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000014822026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.4ms)14832026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.45ms)14842026/10/01 09:15:21 WARN readiness check failed error="closed pool"1485--- PASS: TestService_readinessHandler (0.62s)14862026/10/01 09:15:21 OK 3_commit_push.sql (1.67ms)1487=== CONT TestResolveDBConnectionString14882026/10/01 09:15:21 goose: up to current file version: 31489--- PASS: TestMetricsInventory (0.64s)1490=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1491=== RUN TestResolveDBConnectionString/flag_wins1492=== PAUSE TestResolveDBConnectionString/flag_wins1493=== RUN TestResolveDBConnectionString/file_when_flag_empty1494=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1495=== RUN TestResolveDBConnectionString/missing_file_is_an_error1496=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1497=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1498=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1499=== RUN TestResolveDBConnectionString/nothing_configured1500=== PAUSE TestResolveDBConnectionString/nothing_configured1501=== CONT TestClientFallsBackToClosures15022026/10/01 09:15:21 INFO Received cleanup request method=DELETE path=/api/pending_closures15032026-10-01 09:15:21.477 UTC [747] ERROR: relation "goose_db_version" does not exist at character 3615042026-10-01 09:15:21.477 UTC [747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15052026/10/01 09:15:21 INFO Aborted multipart uploads count=11506--- PASS: TestMultipartCleanup (1.06s)1507=== CONT TestClientPushesUseOnePush15082026/10/01 09:15:21 OK 20241026095416_initial_model.sql (7.8ms)15092026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)15102026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.8ms)15112026-10-01 09:15:21.494 UTC [749] ERROR: relation "goose_db_version" does not exist at character 3615122026-10-01 09:15:21.494 UTC [749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15132026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (2.89ms)15142026/10/01 09:15:21 OK 20260905000000_add_claims.sql (2.69ms)15152026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.97ms)15162026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.22ms)15172026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000015182026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.82ms)15192026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.34ms)15202026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.56ms)15212026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)1522--- PASS: TestService_healthCheckHandler (0.59s)1523=== CONT TestPinProtectsFromGC15242026/10/01 09:15:21 OK 3_commit_push.sql (2.16ms)15252026/10/01 09:15:21 goose: up to current file version: 315262026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.26ms)15272026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (11.31ms)1528=== NAME TestNARDeduplicationMetadataUploadBug1529 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4121983119/001/store/xm2sdp5m72lx256nqqhd0cxmvm40icdd-file1.txt15302026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.78ms)15312026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.5ms)15322026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.39ms)15332026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000015342026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.67ms)15352026/10/01 09:15:21 OK 2_object_stats_trigger.sql (2.11ms)15362026/10/01 09:15:21 OK 3_commit_push.sql (1.72ms)15372026/10/01 09:15:21 goose: up to current file version: 31538=== NAME TestOrphanedObjectsGC1539 orphaned_objects_gc_test.go:290: GC Test Summary:1540 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1541 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1542 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1543 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1544 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1545--- PASS: TestOrphanedObjectsGC (1.13s)1546=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle15472026-10-01 09:15:21.560 UTC [774] ERROR: relation "goose_db_version" does not exist at character 3615482026-10-01 09:15:21.560 UTC [774] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15492026-10-01 09:15:21.562 UTC [782] ERROR: relation "goose_db_version" does not exist at character 3615502026-10-01 09:15:21.562 UTC [782] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15512026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.64ms)15522026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.98ms)15532026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)15542026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)15552026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.59ms)15562026/10/01 09:15:21 INFO Received uploads request method=POST path=/api/pending_closures15572026/10/01 09:15:21 OK 20251218171726_add_pins.sql (5.36ms)15582026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)15592026-10-01 09:15:21.588 UTC [796] ERROR: relation "goose_db_version" does not exist at character 3615602026-10-01 09:15:21.588 UTC [796] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15612026/10/01 09:15:21 INFO Aborted multipart uploads count=015622026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (5.18ms)15632026/10/01 09:15:21 OK 20260905000000_add_claims.sql (5.09ms)15642026/10/01 09:15:21 WARN Force mode enabled - objects will be deleted immediately without grace period15652026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.52ms)15662026/10/01 09:15:21 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=015672026/10/01 09:15:21 OK 20260905000000_add_claims.sql (4.42ms)15682026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.42ms)15692026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000015702026/10/01 09:15:21 INFO Vacuumed table table=pending_closures15712026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.61ms)15722026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (3.77ms)15732026/10/01 09:15:21 OK 2_object_stats_trigger.sql (2.35ms)15742026/10/01 09:15:21 INFO Vacuumed table table=pending_objects15752026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.28ms)15762026/10/01 09:15:21 INFO Vacuumed table table=multipart_uploads15772026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (4.69ms)15782026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000015792026/10/01 09:15:21 OK 3_commit_push.sql (2.55ms)15802026/10/01 09:15:21 goose: up to current file version: 315812026/10/01 09:15:21 INFO Vacuumed table table=closures15822026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)15832026/10/01 09:15:21 INFO Vacuumed table table=objects15842026/10/01 09:15:21 OK 1_commit_pending_closure.sql (3.26ms)15852026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.94ms)15862026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.42ms)15872026/10/01 09:15:21 INFO Received push request method=POST path=/api/pushes15882026/10/01 09:15:21 OK 3_commit_push.sql (1.53ms)15892026/10/01 09:15:21 goose: up to current file version: 315902026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)1591--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.66s)1592=== CONT TestClientSharedPathCommittedMidPush15932026/10/01 09:15:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15942026/10/01 09:15:21 INFO Uploading xm2sdp5m72lx256nqqhd0cxmvm40icdd-file1.txt (160B)15952026/10/01 09:15:21 OK 20260905000000_add_claims.sql (6.93ms)15962026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.99ms)15972026/10/01 09:15:21 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15982026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (1.84ms)15992026/10/01 09:15:21 goose: successfully migrated database to version: 202609231200001600--- PASS: TestGetExistingObjectsLocksRows (0.62s)1601=== CONT TestClientWithDependencies16022026/10/01 09:15:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16032026/10/01 09:15:21 WARN Failed to register uploaded object key=xm2sdp5m72lx256nqqhd0cxmvm40icdd.ls error="server returned 404: 404 page not found\n"16042026/10/01 09:15:21 INFO Signed narinfos id=1 count=116052026/10/01 09:15:21 INFO Uploading 1 narinfos16062026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.64ms)16072026-10-01 09:15:21.629 UTC [818] ERROR: relation "goose_db_version" does not exist at character 3616082026-10-01 09:15:21.629 UTC [818] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16092026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.59ms)16102026/10/01 09:15:21 OK 3_commit_push.sql (1.49ms)16112026/10/01 09:15:21 goose: up to current file version: 316122026/10/01 09:15:21 INFO Received complete push request method=POST path=/api/pushes/1/complete16132026/10/01 09:15:21 WARN Failed to register uploaded object key=xm2sdp5m72lx256nqqhd0cxmvm40icdd.narinfo error="server returned 404: 404 page not found\n"16142026/10/01 09:15:21 INFO Upload complete. (67ms)1615=== NAME TestNARDeduplicationMetadataUploadBug1616 metadata_upload_test.go:54: Retrieved narinfo from S3:1617 StorePath: /build/TestNARDeduplicationMetadataUploadBug4121983119/001/store/xm2sdp5m72lx256nqqhd0cxmvm40icdd-file1.txt1618 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1619 Compression: zstd1620 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1621 NarSize: 1601622 References: 1623 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1624 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1625 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1626 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}16272026/10/01 09:15:21 INFO Aborted multipart uploads count=016282026/10/01 09:15:21 WARN Force mode enabled - objects will be deleted immediately without grace period16292026/10/01 09:15:21 OK 20241026095416_initial_model.sql (15.82ms)16302026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (3.15ms)16312026/10/01 09:15:21 OK 20251218171726_add_pins.sql (4.09ms)16322026-10-01 09:15:21.661 UTC [824] ERROR: relation "goose_db_version" does not exist at character 3616332026-10-01 09:15:21.661 UTC [824] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16342026/10/01 09:15:21 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=01635--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.66s)1636=== CONT TestClientMultipleUploads16372026/10/01 09:15:21 INFO Vacuumed table table=pending_closures16382026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (5.25ms)16392026/10/01 09:15:21 INFO Vacuumed table table=pending_objects16402026/10/01 09:15:21 INFO Vacuumed table table=multipart_uploads16412026/10/01 09:15:21 INFO Vacuumed table table=closures16422026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.8ms)16432026/10/01 09:15:21 INFO Vacuumed table table=objects1644--- PASS: TestSweepRechecksPendingAfterLocking (0.68s)1645=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT16462026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.96ms)16472026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.52ms)16482026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)16492026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (3.48ms)16502026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000016512026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.56ms)16522026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.94ms)1653=== NAME TestNARDeduplicationMetadataUploadBug16542026/10/01 09:15:21 OK 2_object_stats_trigger.sql (2.53ms)1655 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4121983119/001/store/nxnhsiyvjg4k1276kqw9xi003waqrnlp-file2.txt16562026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (4.93ms)16572026/10/01 09:15:21 OK 3_commit_push.sql (2.34ms)16582026/10/01 09:15:21 goose: up to current file version: 316592026/10/01 09:15:21 OK 20260905000000_add_claims.sql (2.96ms)16602026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (1.99ms)16612026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (4.07ms)16622026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000016632026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.49ms)16642026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.74ms)16652026/10/01 09:15:21 OK 3_commit_push.sql (1.87ms)16662026/10/01 09:15:21 goose: up to current file version: 316672026/10/01 09:15:21 INFO Aborted multipart uploads count=016682026/10/01 09:15:21 INFO Received uploads request method=POST path=/api/pending_closures16692026/10/01 09:15:21 WARN Force mode enabled - objects will be deleted immediately without grace period16702026/10/01 09:15:21 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=016712026/10/01 09:15:21 INFO Vacuumed table table=pending_closures16722026/10/01 09:15:21 INFO Vacuumed table table=pending_objects16732026/10/01 09:15:21 INFO Vacuumed table table=multipart_uploads16742026-10-01 09:15:21.719 UTC [866] ERROR: relation "goose_db_version" does not exist at character 3616752026-10-01 09:15:21.719 UTC [866] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16762026/10/01 09:15:21 INFO Vacuumed table table=closures16772026/10/01 09:15:21 INFO Vacuumed table table=objects16782026-10-01 09:15:21.726 UTC [867] ERROR: relation "goose_db_version" does not exist at character 3616792026-10-01 09:15:21.726 UTC [867] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16802026/10/01 09:15:21 INFO Aborted multipart uploads count=016812026/10/01 09:15:21 WARN Force mode enabled - objects will be deleted immediately without grace period16822026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.72ms)16832026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)16842026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.82ms)16852026/10/01 09:15:21 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=016862026/10/01 09:15:21 INFO Vacuumed table table=pending_closures16872026/10/01 09:15:21 INFO Vacuumed table table=pending_objects16882026/10/01 09:15:21 INFO Vacuumed table table=multipart_uploads16892026/10/01 09:15:21 INFO Vacuumed table table=closures16902026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)16912026/10/01 09:15:21 INFO Vacuumed table table=objects16922026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.14ms)16932026/10/01 09:15:21 OK 20241026095416_initial_model.sql (14.5ms)16942026/10/01 09:15:21 INFO Received uploads request method=POST path=/api/pending_closures1695--- PASS: TestSweepSkipsRowsLockedByPush (0.71s)1696=== CONT TestClientIntegration16972026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (9.12ms)16982026/10/01 09:15:21 INFO Received push request method=POST path=/api/pushes16992026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (11.22ms)17002026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.66ms)17012026/10/01 09:15:21 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17022026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.81ms)17032026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000017042026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)17052026/10/01 09:15:21 OK 1_commit_pending_closure.sql (1.91ms)17062026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.18ms)17072026/10/01 09:15:21 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17082026/10/01 09:15:21 INFO Signed narinfos id=2 count=117092026/10/01 09:15:21 WARN Failed to register uploaded object key=nxnhsiyvjg4k1276kqw9xi003waqrnlp.ls error="server returned 404: 404 page not found\n"17102026/10/01 09:15:21 INFO Uploading 1 narinfos17112026/10/01 09:15:21 OK 3_commit_push.sql (2.21ms)17122026/10/01 09:15:21 goose: up to current file version: 317132026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.78ms)17142026-10-01 09:15:21.768 UTC [888] ERROR: relation "goose_db_version" does not exist at character 3617152026-10-01 09:15:21.768 UTC [888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17162026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.7ms)17172026/10/01 09:15:21 INFO Received complete push request method=POST path=/api/pushes/2/complete17182026/10/01 09:15:21 WARN Failed to register uploaded object key=nxnhsiyvjg4k1276kqw9xi003waqrnlp.narinfo error="server returned 404: 404 page not found\n"17192026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (1.89ms)17202026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000017212026/10/01 09:15:21 INFO Upload complete. (51ms)17222026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.42ms)1723=== NAME TestNARDeduplicationMetadataUploadBug1724 metadata_upload_test.go:76: Retrieved narinfo from S3:1725 StorePath: /build/TestNARDeduplicationMetadataUploadBug4121983119/001/store/nxnhsiyvjg4k1276kqw9xi003waqrnlp-file2.txt1726 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1727 Compression: zstd1728 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1729 NarSize: 1601730 References: 1731 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17322026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.38ms)1733 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1734 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1735 {"version":1,"root":{"type":"regular","size":44}}17362026/10/01 09:15:21 OK 3_commit_push.sql (2.35ms)17372026/10/01 09:15:21 goose: up to current file version: 317382026-10-01 09:15:21.779 UTC [889] ERROR: relation "goose_db_version" does not exist at character 3617392026-10-01 09:15:21.779 UTC [889] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17402026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.21ms)17412026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)1742--- PASS: TestNARDeduplicationMetadataUploadBug (0.95s)1743=== CONT TestCompleteMultipartUnregistered17442026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.31ms)17452026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)17462026/10/01 09:15:21 OK 20260905000000_add_claims.sql (2.95ms)17472026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.88ms)17482026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.51ms)17492026/10/01 09:15:21 INFO Received uploads request method=POST path=/api/pending_closures17502026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (3.03ms)17512026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000017522026/10/01 09:15:21 INFO Aborted multipart uploads count=017532026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (2.74ms)17542026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.42ms)17552026/10/01 09:15:21 WARN Force mode enabled - objects will be deleted immediately without grace period17562026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.91ms)17572026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.19ms)17582026/10/01 09:15:21 INFO Aborted multipart uploads count=017592026/10/01 09:15:21 OK 3_commit_push.sql (2.86ms)17602026/10/01 09:15:21 goose: up to current file version: 31761--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.67s)1762=== CONT TestService_verifyS3Integrity17632026/10/01 09:15:21 WARN Force mode enabled - objects will be deleted immediately without grace period17642026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.89ms)17652026/10/01 09:15:21 OK 20260905000000_add_claims.sql (2.95ms)17662026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (3.14ms)17672026/10/01 09:15:21 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."17682026/10/01 09:15:21 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."17692026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.42ms)17702026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000017712026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.16ms)1772--- PASS: TestFailedS3DeleteKeepsTombstone (0.75s)1773=== CONT TestService_createPendingClosureHandler17742026/10/01 09:15:21 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=017752026/10/01 09:15:21 OK 2_object_stats_trigger.sql (2.19ms)17762026/10/01 09:15:21 INFO Vacuumed table table=pending_closures17772026/10/01 09:15:21 INFO Vacuumed table table=pending_objects17782026/10/01 09:15:21 OK 3_commit_push.sql (1.15ms)17792026/10/01 09:15:21 goose: up to current file version: 317802026/10/01 09:15:21 INFO Vacuumed table table=multipart_uploads17812026/10/01 09:15:21 INFO Vacuumed table table=closures17822026/10/01 09:15:21 INFO Received uploads request method=POST path=/api/pending_closures17832026/10/01 09:15:21 INFO Vacuumed table table=objects1784--- PASS: TestGCSweepDeliversEachKeyOnce (0.71s)1785=== CONT TestService_cleanupPendingClosuresHandler17862026-10-01 09:15:21.835 UTC [899] ERROR: relation "goose_db_version" does not exist at character 3617872026-10-01 09:15:21.835 UTC [899] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17882026/10/01 09:15:21 INFO Aborted multipart uploads count=017892026/10/01 09:15:21 WARN Force mode enabled - objects will be deleted immediately without grace period17902026/10/01 09:15:21 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=017912026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.71ms)17922026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)17932026/10/01 09:15:21 INFO Received uploads request method=POST path=/api/pending_closures17942026/10/01 09:15:21 INFO Vacuumed table table=pending_closures17952026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.42ms)17962026/10/01 09:15:21 INFO Vacuumed table table=pending_objects17972026/10/01 09:15:21 INFO Vacuumed table table=multipart_uploads17982026/10/01 09:15:21 INFO Vacuumed table table=closures17992026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)18002026/10/01 09:15:21 INFO Vacuumed table table=objects18012026/10/01 09:15:21 OK 20260905000000_add_claims.sql (11.33ms)1802--- PASS: TestGCSweepSkipsPendingObjects (0.68s)1803=== CONT TestClientErrorHandling1804=== RUN TestClientErrorHandling/InvalidStorePath1805=== PAUSE TestClientErrorHandling/InvalidStorePath1806=== RUN TestClientErrorHandling/InvalidAuthToken1807=== PAUSE TestClientErrorHandling/InvalidAuthToken1808=== RUN TestClientErrorHandling/ServerNotAvailable1809--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.68s)1810=== CONT TestUploadHandlersRejectOversizedBody1811=== PAUSE TestClientErrorHandling/ServerNotAvailable1812=== CONT TestUploadHandlersRejectInvalidKeys1813=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1814=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1815=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1816=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18172026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (4.11ms)1818=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1819=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1820=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1821=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1822=== CONT TestClientCADerivations18232026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.28ms)18242026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000018252026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.21ms)18262026/10/01 09:15:21 OK 2_object_stats_trigger.sql (1.67ms)18272026-10-01 09:15:21.885 UTC [903] ERROR: relation "goose_db_version" does not exist at character 3618282026-10-01 09:15:21.885 UTC [903] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18292026/10/01 09:15:21 OK 3_commit_push.sql (1.44ms)18302026/10/01 09:15:21 goose: up to current file version: 318312026/10/01 09:15:21 INFO Received uploads request method=POST path=/api/pending_closures18322026-10-01 09:15:21.963 UTC [905] ERROR: relation "goose_db_version" does not exist at character 3618332026-10-01 09:15:21.963 UTC [905] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18342026-10-01 09:15:21.964 UTC [906] ERROR: relation "goose_db_version" does not exist at character 3618352026-10-01 09:15:21.964 UTC [906] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18362026-10-01 09:15:21.965 UTC [907] ERROR: relation "goose_db_version" does not exist at character 3618372026-10-01 09:15:21.965 UTC [907] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18382026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.33ms)18392026-10-01 09:15:21.966 UTC [908] ERROR: relation "goose_db_version" does not exist at character 3618402026-10-01 09:15:21.966 UTC [908] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1841--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.85s)1842=== CONT TestIsValidUploadKey1843=== RUN TestIsValidUploadKey/narinfo1844=== PAUSE TestIsValidUploadKey/narinfo1845=== RUN TestIsValidUploadKey/nar_zst1846=== PAUSE TestIsValidUploadKey/nar_zst1847=== RUN TestIsValidUploadKey/nar_xz1848=== PAUSE TestIsValidUploadKey/nar_xz1849=== RUN TestIsValidUploadKey/nar_plain1850=== PAUSE TestIsValidUploadKey/nar_plain1851=== RUN TestIsValidUploadKey/listing1852=== PAUSE TestIsValidUploadKey/listing1853=== RUN TestIsValidUploadKey/build_log1854=== PAUSE TestIsValidUploadKey/build_log1855=== RUN TestIsValidUploadKey/build_log_home-manager_file1856=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1857=== RUN TestIsValidUploadKey/build_log_plus_in_name18582026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)1859=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1860=== RUN TestIsValidUploadKey/build_log_question_mark1861=== PAUSE TestIsValidUploadKey/build_log_question_mark1862=== RUN TestIsValidUploadKey/build_log_equals1863=== PAUSE TestIsValidUploadKey/build_log_equals1864=== RUN TestIsValidUploadKey/realisation1865=== PAUSE TestIsValidUploadKey/realisation1866=== RUN TestIsValidUploadKey/realisation_plus_in_output1867=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1868=== RUN TestIsValidUploadKey/nix-cache-info1869=== PAUSE TestIsValidUploadKey/nix-cache-info1870=== RUN TestIsValidUploadKey/index.html1871=== PAUSE TestIsValidUploadKey/index.html1872=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1873=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1874=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1875=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1876=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1877=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1878=== RUN TestIsValidUploadKey/traversal1879=== PAUSE TestIsValidUploadKey/traversal1880=== RUN TestIsValidUploadKey/traversal_nar1881=== PAUSE TestIsValidUploadKey/traversal_nar1882=== RUN TestIsValidUploadKey/absolute1883=== PAUSE TestIsValidUploadKey/absolute1884=== RUN TestIsValidUploadKey/empty_key1885=== PAUSE TestIsValidUploadKey/empty_key1886=== RUN TestIsValidUploadKey/unknown_type1887=== PAUSE TestIsValidUploadKey/unknown_type1888=== CONT TestProxyWriteTimeout1889=== RUN TestProxyWriteTimeout/narinfo1890=== PAUSE TestProxyWriteTimeout/narinfo1891=== RUN TestProxyWriteTimeout/1_GiB_nar1892=== PAUSE TestProxyWriteTimeout/1_GiB_nar1893=== RUN TestProxyWriteTimeout/10_GiB_nar1894=== PAUSE TestProxyWriteTimeout/10_GiB_nar1895=== RUN TestProxyWriteTimeout/unknown_size1896=== PAUSE TestProxyWriteTimeout/unknown_size1897=== CONT TestCacheStatsHandler18982026/10/01 09:15:21 INFO Aborted multipart uploads count=018992026/10/01 09:15:21 OK 20251218171726_add_pins.sql (4.29ms)19002026/10/01 09:15:21 WARN Force mode enabled - objects will be deleted immediately without grace period19012026/10/01 09:15:21 OK 20241026095416_initial_model.sql (7.31ms)19022026/10/01 09:15:21 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=019032026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)19042026/10/01 09:15:21 INFO Vacuumed table table=pending_closures19052026/10/01 09:15:21 INFO Vacuumed table table=pending_objects19062026/10/01 09:15:21 INFO Vacuumed table table=multipart_uploads19072026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (5.6ms)19082026/10/01 09:15:21 INFO Vacuumed table table=closures19092026/10/01 09:15:21 INFO Vacuumed table table=objects19102026/10/01 09:15:21 OK 20241026095416_initial_model.sql (9.16ms)19112026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.56ms)19122026/10/01 09:15:21 OK 20251218171726_add_pins.sql (4.13ms)19132026/10/01 09:15:21 OK 20241026095416_initial_model.sql (8.44ms)19142026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)19152026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)19162026/10/01 09:15:21 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)1917--- PASS: TestGCMetrics (0.69s)1918=== CONT TestCacheConfigHandler1919=== RUN TestCacheConfigHandler/full_config,_no_issuer1920=== PAUSE TestCacheConfigHandler/full_config,_no_issuer19212026/10/01 09:15:21 OK 20260905000000_add_claims.sql (5.64ms)1922=== RUN TestCacheConfigHandler/no_cache_url_configured1923=== PAUSE TestCacheConfigHandler/no_cache_url_configured1924=== RUN TestCacheConfigHandler/no_signing_keys1925=== PAUSE TestCacheConfigHandler/no_signing_keys1926=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1927=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1928=== CONT TestService_ReadScope_PublicByDefault19292026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.86ms)19302026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.2ms)19312026/10/01 09:15:21 OK 20251218171726_add_pins.sql (3.08ms)19322026/10/01 09:15:21 OK 20251218171726_add_pins.sql (2.16ms)19332026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (3.01ms)19342026/10/01 09:15:21 OK 20260905000000_add_claims.sql (2.78ms)19352026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)19362026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)19372026/10/01 09:15:21 OK 20260628120000_add_object_size_and_stats.sql (3.73ms)19382026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (2.65ms)19392026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (4.16ms)19402026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000019412026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.58ms)19422026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.91ms)19432026/10/01 09:15:21 OK 20260905000000_add_claims.sql (3.79ms)19442026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.17ms)19452026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000019462026/10/01 09:15:21 OK 1_commit_pending_closure.sql (2.35ms)19472026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (1.6ms)19482026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (1.64ms)19492026/10/01 09:15:21 OK 20260920000000_drop_claims.sql (1.87ms)19502026/10/01 09:15:21 OK 1_commit_pending_closure.sql (1.73ms)19512026/10/01 09:15:21 OK 2_object_stats_trigger.sql (2.02ms)19522026/10/01 09:15:21 OK 2_object_stats_trigger.sql (2.23ms)19532026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.66ms)19542026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000019552026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (2.55ms)19562026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000019572026/10/01 09:15:21 OK 20260923120000_add_pushes.sql (3.02ms)19582026/10/01 09:15:21 goose: successfully migrated database to version: 2026092312000019592026/10/01 09:15:21 OK 3_commit_push.sql (2.19ms)19602026/10/01 09:15:21 goose: up to current file version: 319612026/10/01 09:15:22 OK 3_commit_push.sql (1.75ms)19622026/10/01 09:15:22 goose: up to current file version: 319632026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.25ms)19642026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.03ms)19652026/10/01 09:15:22 OK 1_commit_pending_closure.sql (3.55ms)19662026/10/01 09:15:22 OK 2_object_stats_trigger.sql (2.65ms)19672026/10/01 09:15:22 OK 2_object_stats_trigger.sql (2.54ms)19682026/10/01 09:15:22 OK 2_object_stats_trigger.sql (2.76ms)19692026/10/01 09:15:22 OK 3_commit_push.sql (2.25ms)19702026/10/01 09:15:22 goose: up to current file version: 319712026/10/01 09:15:22 OK 3_commit_push.sql (2.17ms)19722026/10/01 09:15:22 goose: up to current file version: 319732026/10/01 09:15:22 OK 3_commit_push.sql (1.72ms)19742026/10/01 09:15:22 goose: up to current file version: 319752026/10/01 09:15:22 INFO lead: acquired remote=192.0.2.1:123419762026/10/01 09:15:22 INFO lead: released remote=192.0.2.1:12341977--- PASS: TestLeadEndsOnShutdown (0.63s)1978=== CONT TestCompletedNarNotReofferedAcrossClosures19792026/10/01 09:15:22 INFO Aborted multipart uploads count=019802026/10/01 09:15:22 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=019812026/10/01 09:15:22 INFO Vacuumed table table=pending_closures1982=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1983=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1984=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart19852026/10/01 09:15:22 INFO Vacuumed table table=pending_objects1986=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1987=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1988=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1989=== CONT TestService_RequireScope_OIDC19902026/10/01 09:15:22 INFO lead: acquired remote=192.0.2.1:123419912026/10/01 09:15:22 INFO Vacuumed table table=multipart_uploads19922026/10/01 09:15:22 INFO Vacuumed table table=closures19932026/10/01 09:15:22 INFO Vacuumed table table=objects19942026/10/01 09:15:22 INFO Aborted multipart uploads count=019952026/10/01 09:15:22 WARN Force mode enabled - objects will be deleted immediately without grace period19962026/10/01 09:15:22 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=019972026/10/01 09:15:22 INFO Vacuumed table table=pending_closures19982026/10/01 09:15:22 INFO Vacuumed table table=pending_objects19992026/10/01 09:15:22 INFO Vacuumed table table=multipart_uploads20002026/10/01 09:15:22 INFO Vacuumed table table=closures20012026/10/01 09:15:22 INFO Vacuumed table table=objects2002--- PASS: TestPushDedupSurvivesConcurrentGC (0.83s)2003=== CONT TestSkippedUploadsHandler20042026/10/01 09:15:22 INFO Client skipped oversized paths paths=3 nar_bytes=500000000020052026-10-01 09:15:22.070 UTC [918] ERROR: relation "goose_db_version" does not exist at character 3620062026-10-01 09:15:22.070 UTC [918] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20072026/10/01 09:15:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34381/oidc20082026-10-01 09:15:22.074 UTC [919] ERROR: relation "goose_db_version" does not exist at character 3620092026-10-01 09:15:22.074 UTC [919] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2010--- PASS: TestSkippedUploadsHandler (0.01s)2011=== CONT TestService_AuthMiddleware_OIDC20122026/10/01 09:15:22 OK 20241026095416_initial_model.sql (9.81ms)2013--- PASS: TestPushWaitsForSweepHoldingRow (1.11s)2014=== CONT TestParseSize2015--- PASS: TestParseSize (0.00s)2016=== CONT TestService_ReadAuthMiddleware20172026/10/01 09:15:22 OK 20241026095416_initial_model.sql (8.77ms)20182026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)20192026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (2.17ms)20202026/10/01 09:15:22 OK 20251218171726_add_pins.sql (2.91ms)20212026/10/01 09:15:22 OK 20251218171726_add_pins.sql (3.48ms)20222026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)20232026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)20242026/10/01 09:15:22 OK 20260905000000_add_claims.sql (3.38ms)20252026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.36ms)20262026/10/01 09:15:22 OK 20260905000000_add_claims.sql (3.71ms)20272026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.45ms)20282026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (3.25ms)20292026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000020302026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (2.21ms)20312026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000020322026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.51ms)20332026/10/01 09:15:22 OK 2_object_stats_trigger.sql (1.55ms)20342026/10/01 09:15:22 OK 3_commit_push.sql (2.25ms)20352026/10/01 09:15:22 goose: up to current file version: 320362026/10/01 09:15:22 OK 1_commit_pending_closure.sql (4.77ms)20372026/10/01 09:15:22 OK 2_object_stats_trigger.sql (2.55ms)20382026/10/01 09:15:22 OK 3_commit_push.sql (1.05ms)20392026/10/01 09:15:22 goose: up to current file version: 320402026-10-01 09:15:22.132 UTC [941] ERROR: relation "goose_db_version" does not exist at character 3620412026-10-01 09:15:22.132 UTC [941] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20422026/10/01 09:15:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42535/oidc20432026/10/01 09:15:22 OK 20241026095416_initial_model.sql (19.62ms)20442026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)20452026/10/01 09:15:22 OK 20251218171726_add_pins.sql (2.66ms)20462026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)20472026/10/01 09:15:22 OK 20260905000000_add_claims.sql (3.37ms)20482026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.83ms)20492026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (1.75ms)20502026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000020512026-10-01 09:15:22.179 UTC [979] ERROR: relation "goose_db_version" does not exist at character 3620522026-10-01 09:15:22.179 UTC [979] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20532026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.39ms)20542026/10/01 09:15:22 OK 2_object_stats_trigger.sql (1.27ms)20552026/10/01 09:15:22 OK 3_commit_push.sql (1.91ms)20562026/10/01 09:15:22 goose: up to current file version: 320572026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures20582026-10-01 09:15:22.188 UTC [982] ERROR: relation "goose_db_version" does not exist at character 3620592026-10-01 09:15:22.188 UTC [982] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20602026/10/01 09:15:22 INFO lead: released remote=192.0.2.1:123420612026/10/01 09:15:22 OK 20241026095416_initial_model.sql (13.26ms)20622026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)20632026/10/01 09:15:22 OK 20241026095416_initial_model.sql (8.6ms)20642026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)20652026/10/01 09:15:22 OK 20251218171726_add_pins.sql (2.71ms)20662026/10/01 09:15:22 OK 20251218171726_add_pins.sql (3.08ms)20672026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)20682026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (3.56ms)20692026/10/01 09:15:22 OK 20260905000000_add_claims.sql (3.44ms)20702026/10/01 09:15:22 OK 20260905000000_add_claims.sql (3.6ms)20712026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.34ms)20722026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.84ms)20732026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (2.42ms)20742026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000020752026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.52ms)2076--- PASS: TestGCBugBareHashReferences (0.90s)2077=== CONT TestService_Rustfstest20782026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (3.52ms)20792026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000020802026/10/01 09:15:22 OK 2_object_stats_trigger.sql (1.16ms)20812026/10/01 09:15:22 OK 3_commit_push.sql (1.05ms)20822026/10/01 09:15:22 goose: up to current file version: 320832026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.11ms)20842026/10/01 09:15:22 OK 2_object_stats_trigger.sql (1.45ms)20852026/10/01 09:15:22 OK 3_commit_push.sql (1.13ms)20862026/10/01 09:15:22 goose: up to current file version: 32087=== NAME TestPinProtectsFromGC2088 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3609965316/001/store/1xf3m7zl3037sdrrhrvrkw1r54jfa3ii-pinned-file.txt2089 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3609965316/001/store/nkmxwfsb3a8iwkjgj1w93arfa9w996vb-unpinned-file.txt20902026/10/01 09:15:22 INFO lead: acquired remote=192.0.2.1:123420912026-10-01 09:15:22.252 UTC [1104] ERROR: relation "goose_db_version" does not exist at character 3620922026-10-01 09:15:22.252 UTC [1104] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20932026/10/01 09:15:22 INFO lead: released remote=192.0.2.1:12342094--- PASS: TestLeadElectsOneAndHandsOver (0.85s)2095=== CONT TestPresignedUploadRegisteredBeforeCommit20962026/10/01 09:15:22 OK 20241026095416_initial_model.sql (8.01ms)20972026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)20982026/10/01 09:15:22 OK 20251218171726_add_pins.sql (2.88ms)20992026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures21002026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)21012026/10/01 09:15:22 OK 20260905000000_add_claims.sql (3.33ms)21022026/10/01 09:15:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21032026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures21042026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.57ms)21052026/10/01 09:15:22 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21062026/10/01 09:15:22 INFO Uploading dsawn3hy3cwk1fmh8hani4xgqxicgcfs-shared-dep (136B)21072026/10/01 09:15:22 INFO Uploading nz2map2sl9pwx4v4qbkb4sx5yh4z95xn-a (216B)21082026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (2.09ms)21092026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000021102026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures21112026/10/01 09:15:22 WARN Failed to register uploaded object key=dakmh15bm7mly0br6dkbcg3pyf7i9jb0.ls error="server returned 404: 404 page not found\n"21122026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21132026/10/01 09:15:22 WARN Failed to register uploaded object key=nz2map2sl9pwx4v4qbkb4sx5yh4z95xn.ls error="server returned 404: 404 page not found\n"21142026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/1nc8yvxkqzzlmv41y9f01daijpvk270j9h1rgwdj8cfind1ig1j9.nar.zst error="server returned 404: 404 page not found\n"21152026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21162026/10/01 09:15:22 WARN Failed to register uploaded object key=dsawn3hy3cwk1fmh8hani4xgqxicgcfs.ls error="server returned 404: 404 page not found\n"21172026/10/01 09:15:22 INFO Signed narinfos id=2 count=221182026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21192026/10/01 09:15:22 INFO Signed narinfos id=1 count=221202026/10/01 09:15:22 INFO Uploading 4 narinfos21212026/10/01 09:15:22 OK 1_commit_pending_closure.sql (10.37ms)21222026/10/01 09:15:22 WARN Failed to register uploaded object key=dakmh15bm7mly0br6dkbcg3pyf7i9jb0.narinfo error="server returned 404: 404 page not found\n"21232026/10/01 09:15:22 WARN Failed to register uploaded object key=nz2map2sl9pwx4v4qbkb4sx5yh4z95xn.narinfo error="server returned 404: 404 page not found\n"21242026/10/01 09:15:22 WARN Failed to register uploaded object key=dsawn3hy3cwk1fmh8hani4xgqxicgcfs.narinfo error="server returned 404: 404 page not found\n"21252026/10/01 09:15:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21262026/10/01 09:15:22 WARN Failed to register uploaded object key=dsawn3hy3cwk1fmh8hani4xgqxicgcfs.narinfo error="server returned 404: 404 page not found\n"21272026/10/01 09:15:22 OK 2_object_stats_trigger.sql (3.35ms)21282026/10/01 09:15:22 OK 3_commit_push.sql (984.16µs)21292026/10/01 09:15:22 goose: up to current file version: 321302026/10/01 09:15:22 INFO Completed upload id=121312026/10/01 09:15:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21322026/10/01 09:15:22 INFO Completed upload id=221332026/10/01 09:15:22 INFO Upload complete. (69ms)2134=== NAME TestClientMultipleUploads2135 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads836716810/001/store/dl4sbx1f0rmqxidilrs232asrjmnbdrs-test-file-0.txt2136--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.63s)2137=== CONT TestService_AuthMiddleware_MTLSBoundSubjects2138=== NAME TestClientFallsBackToClosures2139 client_pushes_test.go:112: Retrieved narinfo from S3:2140 StorePath: /build/TestClientFallsBackToClosures293809822/001/store/dsawn3hy3cwk1fmh8hani4xgqxicgcfs-shared-dep2141 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2142 Compression: zstd2143 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822144 NarSize: 1362145 References: 2146 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2147 client_pushes_test.go:112: Retrieved narinfo from S3:2148 StorePath: /build/TestClientFallsBackToClosures293809822/001/store/nz2map2sl9pwx4v4qbkb4sx5yh4z95xn-a2149 URL: nar/1nc8yvxkqzzlmv41y9f01daijpvk270j9h1rgwdj8cfind1ig1j9.nar.zst2150 Compression: zstd2151 NarHash: sha256:1nc8yvxkqzzlmv41y9f01daijpvk270j9h1rgwdj8cfind1ig1j92152 NarSize: 2162153 References: /build/TestClientFallsBackToClosures293809822/001/store/dsawn3hy3cwk1fmh8hani4xgqxicgcfs-shared-dep2154 CA: text:sha256:1q4rh2vcmrqyfs94pvil8pykapm4s5772hl1sn1yr5r2cylx1bg621552026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes2156 client_pushes_test.go:112: Retrieved narinfo from S3:2157 StorePath: /build/TestClientFallsBackToClosures293809822/001/store/dakmh15bm7mly0br6dkbcg3pyf7i9jb0-b2158 URL: nar/1nc8yvxkqzzlmv41y9f01daijpvk270j9h1rgwdj8cfind1ig1j9.nar.zst2159 Compression: zstd2160 NarHash: sha256:1nc8yvxkqzzlmv41y9f01daijpvk270j9h1rgwdj8cfind1ig1j92161 NarSize: 2162162 References: /build/TestClientFallsBackToClosures293809822/001/store/dsawn3hy3cwk1fmh8hani4xgqxicgcfs-shared-dep2163 CA: text:sha256:1q4rh2vcmrqyfs94pvil8pykapm4s5772hl1sn1yr5r2cylx1bg621642026-10-01 09:15:22.315 UTC [1255] ERROR: relation "goose_db_version" does not exist at character 3621652026-10-01 09:15:22.315 UTC [1255] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2166--- PASS: TestClientFallsBackToClosures (0.85s)21672026/10/01 09:15:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)2168=== CONT TestRedundantMultipartUpload21692026/10/01 09:15:22 INFO Uploading 1xf3m7zl3037sdrrhrvrkw1r54jfa3ii-pinned-file.txt (128B)21702026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes21712026/10/01 09:15:22 WARN Failed to register uploaded object key=1xf3m7zl3037sdrrhrvrkw1r54jfa3ii.ls error="server returned 404: 404 page not found\n"21722026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"21732026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21742026/10/01 09:15:22 INFO Signed narinfos id=1 count=121752026/10/01 09:15:22 INFO Uploading 1 narinfos21762026/10/01 09:15:22 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21772026/10/01 09:15:22 INFO Uploading gja1mzak68bcradna3f4x0fvpwgraxc9-shared-dep (136B)21782026/10/01 09:15:22 INFO Uploading f16f7jn8v4873vy3z0d32pagihsqis63-a (216B)21792026/10/01 09:15:22 INFO Received complete push request method=POST path=/api/pushes/1/complete21802026/10/01 09:15:22 WARN Failed to register uploaded object key=1xf3m7zl3037sdrrhrvrkw1r54jfa3ii.narinfo error="server returned 404: 404 page not found\n"21812026/10/01 09:15:22 WARN Failed to register uploaded object key=dmbspz7vd3mzq5cc1f9my6ziwp659bx5.ls error="server returned 404: 404 page not found\n"2182=== NAME TestClientWithDependencies2183 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies266103891/001/store/k4ly8gs3azh65ix7hy0bc84m0mccwmq1-test-script21842026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21852026/10/01 09:15:22 WARN Failed to register uploaded object key=gja1mzak68bcradna3f4x0fvpwgraxc9.ls error="server returned 404: 404 page not found\n"21862026/10/01 09:15:22 WARN Failed to register uploaded object key=f16f7jn8v4873vy3z0d32pagihsqis63.ls error="server returned 404: 404 page not found\n"21872026/10/01 09:15:22 OK 20241026095416_initial_model.sql (10.21ms)21882026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21892026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/0lgmw7pnncqr3sqh9dh62dw8292bswnjiaj2f87lwpxwj0zyzfif.nar.zst error="server returned 404: 404 page not found\n"21902026/10/01 09:15:22 INFO Signed narinfos id=1 count=321912026/10/01 09:15:22 INFO Uploading 3 narinfos21922026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (2.91ms)21932026/10/01 09:15:22 WARN Failed to register uploaded object key=f16f7jn8v4873vy3z0d32pagihsqis63.narinfo error="server returned 404: 404 page not found\n"21942026/10/01 09:15:22 WARN Failed to register uploaded object key=gja1mzak68bcradna3f4x0fvpwgraxc9.narinfo error="server returned 404: 404 page not found\n"21952026/10/01 09:15:22 INFO Received complete push request method=POST path=/api/pushes/1/complete21962026/10/01 09:15:22 WARN Failed to register uploaded object key=dmbspz7vd3mzq5cc1f9my6ziwp659bx5.narinfo error="server returned 404: 404 page not found\n"21972026/10/01 09:15:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21982026/10/01 09:15:22 INFO Upload complete. (71ms)21992026/10/01 09:15:22 OK 20251218171726_add_pins.sql (4.16ms)22002026/10/01 09:15:22 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst2201--- PASS: TestCompleteMultipartUnregistered (0.56s)2202=== CONT TestService_AuthMiddleware_MTLSProxyHeader22032026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)2204=== NAME TestClientMultipleUploads2205 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads836716810/001/store/94q2yd2mf779qkkhy9b271wns4dhfrcw-test-file-1.txt22062026/10/01 09:15:22 OK 20260905000000_add_claims.sql (3.54ms)22072026/10/01 09:15:22 INFO Upload complete. (68ms)2208=== NAME TestClientPushesUseOnePush2209 client_pushes_test.go:97: Retrieved narinfo from S3:2210 StorePath: /build/TestClientPushesUseOnePush2602023299/001/store/gja1mzak68bcradna3f4x0fvpwgraxc9-shared-dep2211 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2212 Compression: zstd2213 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822214 NarSize: 1362215 References: 2216 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n22172026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.52ms)2218 client_pushes_test.go:97: Retrieved narinfo from S3:2219 StorePath: /build/TestClientPushesUseOnePush2602023299/001/store/f16f7jn8v4873vy3z0d32pagihsqis63-a2220 URL: nar/0lgmw7pnncqr3sqh9dh62dw8292bswnjiaj2f87lwpxwj0zyzfif.nar.zst2221 Compression: zstd2222 NarHash: sha256:0lgmw7pnncqr3sqh9dh62dw8292bswnjiaj2f87lwpxwj0zyzfif2223 NarSize: 2162224 References: /build/TestClientPushesUseOnePush2602023299/001/store/gja1mzak68bcradna3f4x0fvpwgraxc9-shared-dep2225 CA: text:sha256:0bspdkmjggcczvkfr18i88dsf5km0i3lxbkz7hp1ilpncdjg03s722262026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (2.49ms)22272026/10/01 09:15:22 goose: successfully migrated database to version: 202609231200002228 client_pushes_test.go:97: Retrieved narinfo from S3:2229 StorePath: /build/TestClientPushesUseOnePush2602023299/001/store/dmbspz7vd3mzq5cc1f9my6ziwp659bx5-b2230 URL: nar/0lgmw7pnncqr3sqh9dh62dw8292bswnjiaj2f87lwpxwj0zyzfif.nar.zst2231 Compression: zstd2232 NarHash: sha256:0lgmw7pnncqr3sqh9dh62dw8292bswnjiaj2f87lwpxwj0zyzfif2233 NarSize: 2162234 References: /build/TestClientPushesUseOnePush2602023299/001/store/gja1mzak68bcradna3f4x0fvpwgraxc9-shared-dep2235 CA: text:sha256:0bspdkmjggcczvkfr18i88dsf5km0i3lxbkz7hp1ilpncdjg03s722362026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.43ms)2237--- PASS: TestClientPushesUseOnePush (0.87s)2238=== CONT TestCompleteMultipartUpload_ErrorButObjectExists22392026/10/01 09:15:22 OK 2_object_stats_trigger.sql (1.87ms)22402026-10-01 09:15:22.358 UTC [1333] ERROR: relation "goose_db_version" does not exist at character 3622412026-10-01 09:15:22.358 UTC [1333] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22422026/10/01 09:15:22 OK 3_commit_push.sql (1.3ms)22432026/10/01 09:15:22 goose: up to current file version: 32244=== NAME TestClientIntegration2245 client_integration_test.go:286: Created store path: /build/TestClientIntegration1741530811/002/store/6453s1p1c57h6dna801bzv8ir3lfkrzx-test-file.txt22462026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures22472026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes2248=== NAME TestClientWithDependencies2249 client_integration_test.go:615: Found 1 dependencies (including self)22502026/10/01 09:15:22 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)22512026/10/01 09:15:22 INFO Uploading fckkjvv5wf1kwmwpxfpq115pgm7vwxq5-shared-dep (136B)22522026/10/01 09:15:22 INFO Uploading 3hrsqz7m31syac0v0y9lc21z5x07wpk4-top (224B)22532026/10/01 09:15:22 OK 20241026095416_initial_model.sql (9.23ms)22542026/10/01 09:15:22 WARN Failed to register uploaded object key=3hrsqz7m31syac0v0y9lc21z5x07wpk4.ls error="server returned 404: 404 page not found\n"22552026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22562026/10/01 09:15:22 WARN Failed to register uploaded object key=fckkjvv5wf1kwmwpxfpq115pgm7vwxq5.ls error="server returned 404: 404 page not found\n"22572026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22582026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/12643nwf90c2sk5h2nzygg73101k1p0p88civww84sk4gzpb1k9m.nar.zst error="server returned 404: 404 page not found\n"22592026/10/01 09:15:22 INFO Signed narinfos id=1 count=222602026/10/01 09:15:22 INFO Uploading 2 narinfos22612026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)22622026/10/01 09:15:22 OK 20251218171726_add_pins.sql (3.25ms)22632026/10/01 09:15:22 WARN Failed to register uploaded object key=3hrsqz7m31syac0v0y9lc21z5x07wpk4.narinfo error="server returned 404: 404 page not found\n"22642026/10/01 09:15:22 INFO Received complete push request method=POST path=/api/pushes/1/complete22652026/10/01 09:15:22 WARN Failed to register uploaded object key=fckkjvv5wf1kwmwpxfpq115pgm7vwxq5.narinfo error="server returned 404: 404 page not found\n"22662026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (4.35ms)2267=== NAME TestClientMultipleUploads2268 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads836716810/001/store/yjqirl6s8cjsa5jnqw98vbqb56yy17ml-test-file-2.txt22692026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures22702026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures22712026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures22722026/10/01 09:15:22 OK 20260905000000_add_claims.sql (4.4ms)22732026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (11.35ms)22742026/10/01 09:15:22 INFO Upload complete. (80ms)22752026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (2.73ms)22762026/10/01 09:15:22 goose: successfully migrated database to version: 202609231200002277=== NAME TestClientSharedPathCommittedMidPush2278 client_integration_test.go:680: Retrieved narinfo from S3:2279 StorePath: /build/TestClientSharedPathCommittedMidPush2821317903/001/store/fckkjvv5wf1kwmwpxfpq115pgm7vwxq5-shared-dep2280 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2281 Compression: zstd2282 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822283 NarSize: 1362284 References: 2285 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n22862026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.62ms)2287 client_integration_test.go:680: Retrieved narinfo from S3:22882026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes2289 StorePath: /build/TestClientSharedPathCommittedMidPush2821317903/001/store/3hrsqz7m31syac0v0y9lc21z5x07wpk4-top2290 URL: nar/12643nwf90c2sk5h2nzygg73101k1p0p88civww84sk4gzpb1k9m.nar.zst2291 Compression: zstd2292 NarHash: sha256:12643nwf90c2sk5h2nzygg73101k1p0p88civww84sk4gzpb1k9m2293 NarSize: 2242294 References: /build/TestClientSharedPathCommittedMidPush2821317903/001/store/fckkjvv5wf1kwmwpxfpq115pgm7vwxq5-shared-dep2295 CA: text:sha256:03wrdnlwmpi8vasrlcxijgyzl6raavc76fg1d8bdd51lj789gm6g22962026/10/01 09:15:22 OK 2_object_stats_trigger.sql (1.75ms)22972026/10/01 09:15:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22982026/10/01 09:15:22 INFO Uploading nkmxwfsb3a8iwkjgj1w93arfa9w996vb-unpinned-file.txt (128B)22992026/10/01 09:15:22 OK 3_commit_push.sql (1.87ms)23002026/10/01 09:15:22 goose: up to current file version: 323012026/10/01 09:15:22 INFO Received cleanup request method=DELETE path=/api/pending_closures23022026-10-01 09:15:22.411 UTC [1459] ERROR: relation "goose_db_version" does not exist at character 3623032026-10-01 09:15:22.411 UTC [1459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2304--- PASS: TestClientSharedPathCommittedMidPush (0.80s)23052026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"2306=== CONT TestPush_SignsNarinfosOfItsPendingObjects23072026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign23082026/10/01 09:15:22 WARN Failed to register uploaded object key=nkmxwfsb3a8iwkjgj1w93arfa9w996vb.ls error="server returned 404: 404 page not found\n"23092026/10/01 09:15:22 INFO Signed narinfos id=2 count=123102026/10/01 09:15:22 INFO Uploading 1 narinfos23112026/10/01 09:15:22 INFO Aborted multipart uploads count=023122026/10/01 09:15:22 INFO Received complete push request method=POST path=/api/pushes/2/complete23132026/10/01 09:15:22 WARN Failed to register uploaded object key=nkmxwfsb3a8iwkjgj1w93arfa9w996vb.narinfo error="server returned 404: 404 page not found\n"23142026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures23152026/10/01 09:15:22 INFO Upload complete. (48ms)23162026-10-01 09:15:22.424 UTC [1480] ERROR: relation "goose_db_version" does not exist at character 3623172026-10-01 09:15:22.424 UTC [1480] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23182026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes23192026/10/01 09:15:22 OK 20241026095416_initial_model.sql (11.06ms)23202026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (2.62ms)23212026/10/01 09:15:22 INFO Received cleanup request method=DELETE path=/api/pending_closures23222026/10/01 09:15:22 INFO Aborted multipart uploads count=123232026/10/01 09:15:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23242026/10/01 09:15:22 INFO Uploading 6453s1p1c57h6dna801bzv8ir3lfkrzx-test-file.txt (152B)23252026/10/01 09:15:22 OK 20251218171726_add_pins.sql (3.56ms)23262026/10/01 09:15:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23272026-10-01 09:15:22.439 UTC [907] ERROR: Closure does not exist: id=123282026-10-01 09:15:22.439 UTC [907] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE23292026-10-01 09:15:22.439 UTC [907] STATEMENT: -- name: CommitPendingClosure :exec2330 SELECT commit_pending_closure($1::bigint)2331 2332--- PASS: TestService_cleanupPendingClosuresHandler (0.61s)2333=== CONT TestPush_RejectsBadRequests23342026/10/01 09:15:22 WARN Failed to register uploaded object key=6453s1p1c57h6dna801bzv8ir3lfkrzx.ls error="server returned 404: 404 page not found\n"23352026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23362026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"23372026/10/01 09:15:22 INFO Signed narinfos id=1 count=123382026/10/01 09:15:22 INFO Uploading 1 narinfos23392026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes23402026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (6.76ms)23412026/10/01 09:15:22 INFO Received complete push request method=POST path=/api/pushes/1/complete23422026/10/01 09:15:22 WARN Failed to register uploaded object key=6453s1p1c57h6dna801bzv8ir3lfkrzx.narinfo error="server returned 404: 404 page not found\n"23432026/10/01 09:15:22 OK 20241026095416_initial_model.sql (17.6ms)23442026/10/01 09:15:22 OK 20260905000000_add_claims.sql (11.15ms)2345--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.99s)2346=== CONT TestParseSingleRange/none2347=== CONT TestParseSingleRange/start_far_past_EOF2348=== CONT TestParseSingleRange/start_past_EOF2349=== CONT TestParseSingleRange/single_byte2350=== CONT TestParseSingleRange/suffix_exceeds_size2351=== CONT TestParseSingleRange/suffix2352=== CONT TestParseSingleRange/end_clamped_to_size2353=== CONT TestParseSingleRange/open-ended2354=== CONT TestParseSingleRange/closed2355=== CONT TestParseSingleRange/malformed_end_before_start2356=== CONT TestParseSingleRange/malformed_both_empty2357=== CONT TestParseSingleRange/malformed_no_dash2358=== CONT TestParseSingleRange/multi-range_ignored2359=== CONT TestParseSingleRange/unknown_unit2360--- PASS: TestParseSingleRange (0.00s)2361 --- PASS: TestParseSingleRange/none (0.00s)2362 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2363 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2364 --- PASS: TestParseSingleRange/single_byte (0.00s)2365 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2366 --- PASS: TestParseSingleRange/suffix (0.00s)2367 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2368 --- PASS: TestParseSingleRange/open-ended (0.00s)2369 --- PASS: TestParseSingleRange/closed (0.00s)2370 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2371 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2372 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2373 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2374 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2375=== CONT TestIsValidCachePath/narinfo2376=== CONT TestServerTLSConfig/no_client_CA2377=== CONT TestIsValidCachePath/short_hash2378=== CONT TestIsValidCachePath/wrong_extension2379=== CONT TestIsValidCachePath/leading_slash2380=== CONT TestIsValidCachePath/empty2381=== CONT TestIsValidCachePath/random_path23822026/10/01 09:15:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)2383=== CONT TestIsValidCachePath/invalid_char_u2384=== CONT TestIsValidCachePath/invalid_char_e23852026/10/01 09:15:22 INFO Uploading k4ly8gs3azh65ix7hy0bc84m0mccwmq1-test-script (136B)2386=== CONT TestIsValidCachePath/traversal_in_middle2387=== CONT TestIsValidCachePath/traversal_parent2388=== CONT TestIsValidCachePath/index.html2389=== CONT TestIsValidCachePath/nix-cache-info2390=== CONT TestIsValidCachePath/realisation2391=== CONT TestIsValidCachePath/log2392=== CONT TestIsValidCachePath/ls2393=== CONT TestIsValidCachePath/nar_uncompressed2394=== CONT TestIsValidCachePath/nar_bz22395=== CONT TestIsValidCachePath/nar_xz2396=== CONT TestIsValidCachePath/nar_zst2397=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2398--- PASS: TestIsValidCachePath (0.00s)2399 --- PASS: TestIsValidCachePath/narinfo (0.00s)2400 --- PASS: TestIsValidCachePath/short_hash (0.00s)2401 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2402 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2403 --- PASS: TestIsValidCachePath/empty (0.00s)2404 --- PASS: TestIsValidCachePath/random_path (0.00s)2405 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2406 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2407 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2408 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2409 --- PASS: TestIsValidCachePath/index.html (0.00s)2410 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2411 --- PASS: TestIsValidCachePath/realisation (0.00s)2412 --- PASS: TestIsValidCachePath/log (0.00s)2413 --- PASS: TestIsValidCachePath/ls (0.00s)2414 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2415 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2416 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2417 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2418 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2419=== CONT TestServerTLSConfig/not_a_PEM_file2420=== CONT TestServerTLSConfig/missing_CA_file2421--- PASS: TestServerTLSConfig (0.00s)2422 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2423 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2424 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2425=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows24262026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (12.21ms)24272026/10/01 09:15:22 WARN Failed to register uploaded object key=k4ly8gs3azh65ix7hy0bc84m0mccwmq1.ls error="server returned 404: 404 page not found\n"24282026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"24292026/10/01 09:15:22 WARN Failed to register uploaded object key=log/p41zw1p57gq6b1748iczhgzqhli1cff7-test-script.drv error="server returned 404: 404 page not found\n"24302026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24312026/10/01 09:15:22 INFO Received create pin request method=POST path=/api/pins/myapp24322026/10/01 09:15:22 INFO Signed narinfos id=1 count=124332026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes24342026/10/01 09:15:22 INFO Uploading 1 narinfos24352026/10/01 09:15:22 INFO Upload complete. (77ms)24362026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (12.98ms)24372026/10/01 09:15:22 INFO Received complete push request method=POST path=/api/pushes/1/complete24382026/10/01 09:15:22 WARN Failed to register uploaded object key=k4ly8gs3azh65ix7hy0bc84m0mccwmq1.narinfo error="server returned 404: 404 page not found\n"24392026/10/01 09:15:22 OK 20251218171726_add_pins.sql (9.64ms)24402026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (8.39ms)24412026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000024422026/10/01 09:15:22 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3609965316/001/store/1xf3m7zl3037sdrrhrvrkw1r54jfa3ii-pinned-file.txt narinfo_key=1xf3m7zl3037sdrrhrvrkw1r54jfa3ii.narinfo24432026/10/01 09:15:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures24442026/10/01 09:15:22 INFO Garbage collection started24452026/10/01 09:15:22 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)24462026/10/01 09:15:22 INFO Uploading yjqirl6s8cjsa5jnqw98vbqb56yy17ml-test-file-2.txt (160B)24472026/10/01 09:15:22 INFO Uploading dl4sbx1f0rmqxidilrs232asrjmnbdrs-test-file-0.txt (160B)24482026/10/01 09:15:22 INFO Uploading 94q2yd2mf779qkkhy9b271wns4dhfrcw-test-file-1.txt (160B)24492026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (9.75ms)24502026/10/01 09:15:22 WARN Failed to register uploaded object key=yjqirl6s8cjsa5jnqw98vbqb56yy17ml.ls error="server returned 404: 404 page not found\n"24512026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"24522026/10/01 09:15:22 WARN Failed to register uploaded object key=94q2yd2mf779qkkhy9b271wns4dhfrcw.ls error="server returned 404: 404 page not found\n"24532026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"24542026/10/01 09:15:22 WARN Failed to register uploaded object key=dl4sbx1f0rmqxidilrs232asrjmnbdrs.ls error="server returned 404: 404 page not found\n"24552026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign24562026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"24572026/10/01 09:15:22 INFO Signed narinfos id=1 count=324582026/10/01 09:15:22 INFO Uploading 3 narinfos24592026-10-01 09:15:22.485 UTC [1556] ERROR: relation "goose_db_version" does not exist at character 3624602026-10-01 09:15:22.485 UTC [1556] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24612026-10-01 09:15:22.486 UTC [1561] ERROR: relation "goose_db_version" does not exist at character 3624622026-10-01 09:15:22.486 UTC [1561] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24632026/10/01 09:15:22 OK 1_commit_pending_closure.sql (12.7ms)24642026/10/01 09:15:22 INFO Upload complete. (89ms)24652026/10/01 09:15:22 WARN Failed to register uploaded object key=94q2yd2mf779qkkhy9b271wns4dhfrcw.narinfo error="server returned 404: 404 page not found\n"24662026/10/01 09:15:22 INFO Aborted multipart uploads count=024672026/10/01 09:15:22 INFO Received complete push request method=POST path=/api/pushes/1/complete24682026/10/01 09:15:22 WARN Failed to register uploaded object key=yjqirl6s8cjsa5jnqw98vbqb56yy17ml.narinfo error="server returned 404: 404 page not found\n"24692026/10/01 09:15:22 WARN Failed to register uploaded object key=dl4sbx1f0rmqxidilrs232asrjmnbdrs.narinfo error="server returned 404: 404 page not found\n"2470=== NAME TestClientWithDependencies2471 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies266103891/001/store) requires matching store prefix24722026/10/01 09:15:22 OK 20260905000000_add_claims.sql (15.22ms)24732026/10/01 09:15:22 WARN Force mode enabled - objects will be deleted immediately without grace period24742026/10/01 09:15:22 OK 2_object_stats_trigger.sql (12.3ms)2475--- PASS: TestClientWithDependencies (0.87s)2476=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check24772026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (9.28ms)24782026/10/01 09:15:22 OK 3_commit_push.sql (6.75ms)24792026/10/01 09:15:22 goose: up to current file version: 324802026/10/01 09:15:22 INFO Upload complete. (89ms)2481=== NAME TestClientMultipleUploads2482 client_integration_test.go:369: Uploaded 3 paths in 123.862722ms24832026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (3.89ms)24842026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000024852026/10/01 09:15:22 INFO All 1 paths already cached24862026/10/01 09:15:22 OK 20241026095416_initial_model.sql (9.65ms)2487=== NAME TestClientIntegration2488 client_integration_test.go:312: Retrieved narinfo from S3:2489 StorePath: /build/TestClientIntegration1741530811/002/store/6453s1p1c57h6dna801bzv8ir3lfkrzx-test-file.txt2490 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst24912026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2ms)2492 Compression: zstd2493 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12494 NarSize: 1522495 References: 24962026/10/01 09:15:22 OK 20241026095416_initial_model.sql (10.27ms)2497 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk124982026/10/01 09:15:22 OK 2_object_stats_trigger.sql (1.79ms)24992026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)2500 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)25012026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)2502 client_integration_test.go:313: Decompressed .ls content (64 bytes):2503 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2504 client_integration_test.go:316: Testing garbage collection...25052026/10/01 09:15:22 OK 3_commit_push.sql (1.02ms)25062026/10/01 09:15:22 goose: up to current file version: 325072026/10/01 09:15:22 OK 20251218171726_add_pins.sql (2.45ms)25082026/10/01 09:15:22 OK 20251218171726_add_pins.sql (3.46ms)25092026/10/01 09:15:22 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=025102026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (3.13ms)25112026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)2512--- PASS: TestClientMultipleUploads (0.85s)2513=== CONT TestResolveDBConnectionString/flag_wins2514=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2515=== CONT TestResolveDBConnectionString/nothing_configured2516=== CONT TestResolveDBConnectionString/missing_file_is_an_error2517=== CONT TestResolveDBConnectionString/file_when_flag_empty2518=== CONT TestClientErrorHandling/InvalidStorePath2519--- PASS: TestResolveDBConnectionString (0.00s)2520 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2521 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2522 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2523 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2524 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)25252026/10/01 09:15:22 INFO Vacuumed table table=pending_closures25262026/10/01 09:15:22 OK 20260905000000_add_claims.sql (3.08ms)25272026/10/01 09:15:22 OK 20260905000000_add_claims.sql (2.87ms)25282026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.09ms)25292026-10-01 09:15:22.531 UTC [1600] ERROR: relation "goose_db_version" does not exist at character 3625302026-10-01 09:15:22.531 UTC [1600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25312026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (11.23ms)2532--- PASS: TestService_ReadScope_PublicByDefault (0.55s)2533=== CONT TestClientErrorHandling/InvalidAuthToken25342026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (11.96ms)25352026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000025362026/10/01 09:15:22 INFO Vacuumed table table=pending_objects25372026/10/01 09:15:22 INFO Vacuumed table table=multipart_uploads25382026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (3.44ms)25392026/10/01 09:15:22 goose: successfully migrated database to version: 202609231200002540--- PASS: TestCacheStatsHandler (0.57s)2541=== CONT TestClientErrorHandling/ServerNotAvailable25422026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.66ms)25432026/10/01 09:15:22 INFO Vacuumed table table=closures25442026/10/01 09:15:22 OK 2_object_stats_trigger.sql (2.3ms)25452026/10/01 09:15:22 OK 1_commit_pending_closure.sql (3.9ms)25462026/10/01 09:15:22 OK 3_commit_push.sql (1.32ms)25472026/10/01 09:15:22 goose: up to current file version: 325482026/10/01 09:15:22 OK 2_object_stats_trigger.sql (2.14ms)25492026/10/01 09:15:22 INFO Vacuumed table table=objects25502026/10/01 09:15:22 OK 3_commit_push.sql (1.48ms)25512026/10/01 09:15:22 goose: up to current file version: 325522026/10/01 09:15:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures25532026/10/01 09:15:22 INFO Garbage collection started25542026/10/01 09:15:22 OK 20241026095416_initial_model.sql (9.61ms)25552026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)25562026/10/01 09:15:22 OK 20251218171726_add_pins.sql (3.42ms)25572026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures25582026/10/01 09:15:22 INFO Aborted multipart uploads count=025592026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (6ms)25602026/10/01 09:15:22 WARN Force mode enabled - objects will be deleted immediately without grace period25612026/10/01 09:15:22 OK 20260905000000_add_claims.sql (3.63ms)2562=== NAME TestClientCADerivations2563 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3909457907/001/store/rzazfvairs7s2ajs0pb1riv045ljv98n-ca-test25642026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.38ms)25652026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (3.65ms)25662026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000025672026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.49ms)25682026/10/01 09:15:22 OK 2_object_stats_trigger.sql (2.37ms)25692026/10/01 09:15:22 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=025702026/10/01 09:15:22 OK 3_commit_push.sql (1.86ms)25712026/10/01 09:15:22 goose: up to current file version: 325722026-10-01 09:15:22.582 UTC [1657] ERROR: relation "goose_db_version" does not exist at character 3625732026-10-01 09:15:22.582 UTC [1657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25742026/10/01 09:15:22 INFO Vacuumed table table=pending_closures25752026/10/01 09:15:22 INFO Vacuumed table table=pending_objects25762026/10/01 09:15:22 INFO Vacuumed table table=multipart_uploads25772026/10/01 09:15:22 INFO Vacuumed table table=closures2578 client_ca_test.go:139: Found 1 dependencies (including self)25792026/10/01 09:15:22 INFO Vacuumed table table=objects2580=== RUN TestService_RequireScope_OIDC/builder_may_write2581=== PAUSE TestService_RequireScope_OIDC/builder_may_write2582=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2583=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2584=== RUN TestService_RequireScope_OIDC/ops_may_admin2585=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2586=== RUN TestService_RequireScope_OIDC/ops_may_not_write2587=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2588=== RUN TestService_RequireScope_OIDC/reader_may_not_write2589=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2590=== RUN TestService_RequireScope_OIDC/static_token_may_admin2591=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2592=== RUN TestService_RequireScope_OIDC/static_token_may_write2593=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2594=== RUN TestService_RequireScope_OIDC/reader_may_read25952026/10/01 09:15:22 OK 20241026095416_initial_model.sql (9ms)2596=== PAUSE TestService_RequireScope_OIDC/reader_may_read2597=== RUN TestService_RequireScope_OIDC/writer_implies_read2598=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2599=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2600=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2601=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key26022026/10/01 09:15:22 INFO Received request for more parts method=POST path=/2603=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info26042026/10/01 09:15:22 INFO Received uploads request method=POST path=/2605=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key26062026/10/01 09:15:22 INFO Received complete multipart upload request method=POST path=/2607=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal26082026/10/01 09:15:22 INFO Received uploads request method=POST path=/2609--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2610 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2611 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2612 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2613 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2614=== CONT TestIsValidUploadKey/narinfo2615=== CONT TestIsValidUploadKey/realisation_plus_in_output2616=== CONT TestIsValidUploadKey/unknown_type2617=== CONT TestIsValidUploadKey/empty_key2618=== CONT TestIsValidUploadKey/absolute2619=== CONT TestIsValidUploadKey/traversal_nar2620=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2621=== CONT TestIsValidUploadKey/index.html2622=== CONT TestIsValidUploadKey/nix-cache-info2623=== CONT TestIsValidUploadKey/traversal26242026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)2625=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2626=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2627=== CONT TestIsValidUploadKey/build_log_home-manager_file2628=== CONT TestIsValidUploadKey/build_log_equals2629=== CONT TestIsValidUploadKey/build_log_question_mark2630=== CONT TestIsValidUploadKey/realisation2631=== CONT TestIsValidUploadKey/nar_plain2632=== CONT TestIsValidUploadKey/build_log_plus_in_name2633=== CONT TestIsValidUploadKey/build_log2634=== CONT TestIsValidUploadKey/nar_xz2635=== CONT TestIsValidUploadKey/listing2636=== CONT TestIsValidUploadKey/nar_zst2637--- PASS: TestIsValidUploadKey (0.00s)2638 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2639 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2640 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2641 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2642 --- PASS: TestIsValidUploadKey/absolute (0.00s)2643 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2644 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2645 --- PASS: TestIsValidUploadKey/index.html (0.00s)2646 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2647 --- PASS: TestIsValidUploadKey/traversal (0.00s)2648 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2649 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2650 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2651 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2652 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2653 --- PASS: TestIsValidUploadKey/realisation (0.00s)2654 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2655 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2656 --- PASS: TestIsValidUploadKey/build_log (0.00s)2657 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2658 --- PASS: TestIsValidUploadKey/listing (0.00s)2659 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2660=== CONT TestProxyWriteTimeout/narinfo2661=== CONT TestProxyWriteTimeout/10_GiB_nar2662=== CONT TestProxyWriteTimeout/unknown_size2663=== CONT TestProxyWriteTimeout/1_GiB_nar2664--- PASS: TestService_ReadAuthMiddleware (0.51s)2665--- PASS: TestProxyWriteTimeout (0.00s)2666 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2667 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2668 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2669 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2670=== CONT TestCacheConfigHandler/full_config,_no_issuer2671=== CONT TestCacheConfigHandler/no_signing_keys2672=== CONT TestCacheConfigHandler/no_cache_url_configured2673=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2674--- PASS: TestCacheConfigHandler (0.00s)2675 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2676 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2677 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2678 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2679=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure26802026/10/01 09:15:22 INFO Received uploads request method=POST path=/2681=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts26822026/10/01 09:15:22 INFO Received request for more parts method=POST path=/26832026/10/01 09:15:22 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/present26842026/10/01 09:15:22 OK 20251218171726_add_pins.sql (18.1ms)26852026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (3.61ms)26862026/10/01 09:15:22 OK 20260905000000_add_claims.sql (2.39ms)2687=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token26882026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (1.91ms)2689=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2690=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2691=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2692=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2693=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2694=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2695=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2696=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart26972026/10/01 09:15:22 INFO Received complete multipart upload request method=POST path=/26982026-10-01 09:15:22.630 UTC [1710] ERROR: relation "goose_db_version" does not exist at character 3626992026-10-01 09:15:22.630 UTC [1710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27002026-10-01 09:15:22.630 UTC [1711] ERROR: relation "goose_db_version" does not exist at character 3627012026-10-01 09:15:22.630 UTC [1711] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27022026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (1.84ms)27032026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000027042026-10-01 09:15:22.631 UTC [1712] ERROR: relation "goose_db_version" does not exist at character 3627052026-10-01 09:15:22.631 UTC [1712] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27062026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.04ms)27072026/10/01 09:15:22 OK 2_object_stats_trigger.sql (1.14ms)27082026/10/01 09:15:22 OK 3_commit_push.sql (788.9µs)27092026/10/01 09:15:22 goose: up to current file version: 327102026-10-01 09:15:22.641 UTC [1714] ERROR: relation "goose_db_version" does not exist at character 3627112026-10-01 09:15:22.641 UTC [1714] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC27122026/10/01 09:15:22 OK 20241026095416_initial_model.sql (11.92ms)27132026/10/01 09:15:22 OK 20241026095416_initial_model.sql (12.55ms)27142026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)27152026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)27162026/10/01 09:15:22 OK 20241026095416_initial_model.sql (7.07ms)27172026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)27182026/10/01 09:15:22 OK 20251218171726_add_pins.sql (2.46ms)27192026/10/01 09:15:22 OK 20251218171726_add_pins.sql (2.89ms)27202026/10/01 09:15:22 OK 20251218171726_add_pins.sql (2.61ms)27212026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)27222026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (2.95ms)27232026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (2.96ms)27242026/10/01 09:15:22 OK 20241026095416_initial_model.sql (9.12ms)27252026/10/01 09:15:22 OK 20260905000000_add_claims.sql (2.86ms)27262026/10/01 09:15:22 OK 20260905000000_add_claims.sql (3.16ms)27272026/10/01 09:15:22 OK 20260905000000_add_claims.sql (2.02ms)27282026/10/01 09:15:22 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)27292026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.22ms)27302026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.36ms)2731--- PASS: TestService_Rustfstest (0.44s)27322026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (2.04ms)2733=== CONT TestService_RequireScope_OIDC/builder_may_write27342026/10/01 09:15:22 OK 20251218171726_add_pins.sql (2.12ms)2735=== CONT TestService_RequireScope_OIDC/static_token_may_admin2736=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2737=== CONT TestService_RequireScope_OIDC/writer_implies_read2738=== CONT TestService_RequireScope_OIDC/reader_may_read27392026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (1.88ms)2740=== CONT TestService_RequireScope_OIDC/static_token_may_write27412026/10/01 09:15:22 goose: successfully migrated database to version: 202609231200002742=== CONT TestService_RequireScope_OIDC/ops_may_not_write27432026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (2.17ms)27442026/10/01 09:15:22 goose: successfully migrated database to version: 202609231200002745=== CONT TestService_RequireScope_OIDC/reader_may_not_write27462026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (2.06ms)27472026/10/01 09:15:22 goose: successfully migrated database to version: 202609231200002748=== CONT TestService_RequireScope_OIDC/ops_may_admin2749=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2750=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token27512026/10/01 09:15:22 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)27522026/10/01 09:15:22 OK 1_commit_pending_closure.sql (1.52ms)2753--- PASS: TestService_RequireScope_OIDC (0.56s)2754 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2755 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2756 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2757 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2758 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2759 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2760 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2761 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2762 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2763 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)27642026/10/01 09:15:22 OK 1_commit_pending_closure.sql (1.62ms)27652026/10/01 09:15:22 OK 1_commit_pending_closure.sql (1.5ms)27662026/10/01 09:15:22 OK 2_object_stats_trigger.sql (708.86µs)27672026/10/01 09:15:22 OK 2_object_stats_trigger.sql (749.81µs)27682026/10/01 09:15:22 OK 2_object_stats_trigger.sql (1.05ms)27692026/10/01 09:15:22 OK 3_commit_push.sql (757.16µs)27702026/10/01 09:15:22 goose: up to current file version: 327712026/10/01 09:15:22 OK 3_commit_push.sql (723.61µs)27722026/10/01 09:15:22 goose: up to current file version: 327732026/10/01 09:15:22 OK 3_commit_push.sql (617.43µs)27742026/10/01 09:15:22 goose: up to current file version: 327752026/10/01 09:15:22 OK 20260905000000_add_claims.sql (2.51ms)2776=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected27772026/10/01 09:15:22 OK 20260920000000_drop_claims.sql (1.59ms)27782026/10/01 09:15:22 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]2779=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected27802026/10/01 09:15:22 WARN Authentication failed token_preview=eyJhbGciOi...O55SkL-2GA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2781=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2782--- PASS: TestService_AuthMiddleware_OIDC (0.55s)2783 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2784 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.01s)2785 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2786 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)27872026/10/01 09:15:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.060829ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27882026/10/01 09:15:22 OK 20260923120000_add_pushes.sql (78.95ms)27892026/10/01 09:15:22 goose: successfully migrated database to version: 2026092312000027902026/10/01 09:15:22 OK 1_commit_pending_closure.sql (2.57ms)27912026/10/01 09:15:22 OK 2_object_stats_trigger.sql (1.18ms)27922026/10/01 09:15:22 OK 3_commit_push.sql (887.28µs)27932026/10/01 09:15:22 goose: up to current file version: 327942026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes27952026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures27962026/10/01 09:15:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)27972026/10/01 09:15:22 INFO Uploading rzazfvairs7s2ajs0pb1riv045ljv98n-ca-test (144B)27982026/10/01 09:15:22 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"27992026/10/01 09:15:22 WARN Failed to register uploaded object key=rzazfvairs7s2ajs0pb1riv045ljv98n.ls error="server returned 404: 404 page not found\n"28002026/10/01 09:15:22 WARN Failed to register uploaded object key=log/9afz6xvvqj2cq1qxfvcinydvzcsjkv9c-ca-test.drv error="server returned 404: 404 page not found\n"28012026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28022026/10/01 09:15:22 INFO Signed narinfos id=1 count=128032026/10/01 09:15:22 INFO Uploading 1 narinfos28042026/10/01 09:15:22 INFO Received complete push request method=POST path=/api/pushes/1/complete28052026/10/01 09:15:22 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst28062026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures28072026/10/01 09:15:22 WARN Failed to register uploaded object key=rzazfvairs7s2ajs0pb1riv045ljv98n.narinfo error="server returned 404: 404 page not found\n"2808--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.53s)28092026/10/01 09:15:22 INFO Upload complete. (165ms)28102026/10/01 09:15:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"28112026/10/01 09:15:22 WARN mTLS auth: bound subjects configured but subject DN unavailable28122026/10/01 09:15:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2813--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.49s)2814=== NAME TestClientCADerivations2815 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3909457907/001/store/rzazfvairs7s2ajs0pb1riv045ljv98n-ca-test2816 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2817 Compression: zstd2818 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2819 NarSize: 1442820 References: 2821 Deriver: /build/TestClientCADerivations3909457907/001/store/9afz6xvvqj2cq1qxfvcinydvzcsjkv9c-ca-test.drv2822 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2823 client_ca_test.go:185: Checking for realisation files in S3...2824 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2825 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache28262026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures28272026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures2828--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.50s)28292026/10/01 09:15:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete28302026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures28312026/10/01 09:15:22 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=M2Y2NGZiZDYtZWFhNi00ZTdmLTk5NGMtMWNkMWFhOTc1MTcyLjUwMjNlMzI2LWUwYjgtNGFhYi05OTRhLWUzNGMxMWRlMDQ5MXgxNzkwODQ2MTIyMzY4MjM0OTI0 parts=1028322026/10/01 09:15:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete28332026/10/01 09:15:22 INFO Completed upload id=128342026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures28352026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures28362026/10/01 09:15:22 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo28372026/10/01 09:15:22 WARN Found objects in DB but missing from S3, will re-upload count=12838--- PASS: TestService_verifyS3Integrity (1.07s)28392026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes28402026/10/01 09:15:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete28412026/10/01 09:15:22 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2Y2NGZiZDYtZWFhNi00ZTdmLTk5NGMtMWNkMWFhOTc1MTcyLjdhOTdmNzQ2LTA4YTEtNGFlZC05MDQxLWQwMmRhN2Q4NzI4MngxNzkwODQ2MTIyODcwODk4Mjc128422026/10/01 09:15:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign28432026/10/01 09:15:22 INFO Signed narinfos id=1 count=12844--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.48s)28452026/10/01 09:15:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2Y2NGZiZDYtZWFhNi00ZTdmLTk5NGMtMWNkMWFhOTc1MTcyLjdhOTdmNzQ2LTA4YTEtNGFlZC05MDQxLWQwMmRhN2Q4NzI4MngxNzkwODQ2MTIyODcwODk4Mjc1 parts=12846--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.54s)2847=== RUN TestPush_RejectsBadRequests/no_roots2848=== PAUSE TestPush_RejectsBadRequests/no_roots2849=== RUN TestPush_RejectsBadRequests/no_objects2850=== PAUSE TestPush_RejectsBadRequests/no_objects2851=== RUN TestPush_RejectsBadRequests/bad_root2852=== PAUSE TestPush_RejectsBadRequests/bad_root2853=== RUN TestPush_RejectsBadRequests/root_not_in_objects2854=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2855=== CONT TestPush_RejectsBadRequests/no_roots28562026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes2857=== CONT TestPush_RejectsBadRequests/bad_root2858=== CONT TestPush_RejectsBadRequests/root_not_in_objects28592026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes2860=== CONT TestPush_RejectsBadRequests/no_objects28612026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes28622026/10/01 09:15:22 INFO Received push request method=POST path=/api/pushes2863--- PASS: TestPush_RejectsBadRequests (0.47s)2864 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2865 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2866 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2867 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)28682026/10/01 09:15:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2869=== NAME TestClientCADerivations2870 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2871 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2872 error: binary cache 's3://bucket62?endpoint=http://localhost:37775®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3909457907/001/store'2873 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 128742026/10/01 09:15:22 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=M2Y2NGZiZDYtZWFhNi00ZTdmLTk5NGMtMWNkMWFhOTc1MTcyLmMxNzc5NTI1LTBjM2EtNGFlYi1hNmM3LTg4NTg5NzYxNmJjY3gxNzkwODQ2MTIyNDAyOTk2NzQ1 parts=1028752026/10/01 09:15:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2876--- PASS: TestClientCADerivations (1.05s)28772026/10/01 09:15:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.196339ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present28782026/10/01 09:15:22 INFO Completed upload id=128792026/10/01 09:15:22 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000028802026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures28812026/10/01 09:15:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures28822026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures28832026/10/01 09:15:22 INFO Aborted multipart uploads count=028842026/10/01 09:15:22 INFO Aborted multipart uploads count=028852026/10/01 09:15:22 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=028862026/10/01 09:15:22 WARN Force mode enabled - objects will be deleted immediately without grace period28872026/10/01 09:15:22 INFO Vacuumed table table=pending_closures28882026/10/01 09:15:22 INFO Vacuumed table table=pending_objects28892026/10/01 09:15:22 INFO Vacuumed table table=multipart_uploads28902026/10/01 09:15:22 INFO Vacuumed table table=closures28912026/10/01 09:15:22 INFO Vacuumed table table=objects28922026/10/01 09:15:22 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=028932026/10/01 09:15:22 INFO Vacuumed table table=pending_closures28942026/10/01 09:15:22 INFO Vacuumed table table=pending_objects28952026/10/01 09:15:22 INFO Vacuumed table table=multipart_uploads28962026/10/01 09:15:22 INFO Vacuumed table table=closures28972026/10/01 09:15:22 INFO Vacuumed table table=objects28982026/10/01 09:15:22 INFO Received uploads request method=POST path=/api/pending_closures28992026/10/01 09:15:22 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002900--- PASS: TestService_createPendingClosureHandler (1.17s)29012026/10/01 09:15:22 INFO Aborted multipart uploads count=029022026/10/01 09:15:22 WARN Force mode enabled - objects will be deleted immediately without grace period29032026/10/01 09:15:23 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=02904=== NAME TestOrphanedObjectsGCStressTest2905 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains29062026/10/01 09:15:23 INFO Vacuumed table table=pending_closures29072026/10/01 09:15:23 INFO Vacuumed table table=pending_objects29082026/10/01 09:15:23 INFO Vacuumed table table=multipart_uploads29092026/10/01 09:15:23 INFO Vacuumed table table=closures29102026/10/01 09:15:23 INFO Vacuumed table table=objects2911--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2912 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.52s)2913 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.52s)2914=== NAME TestOrphanedObjectsGCStressTest2915 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion29162026/10/01 09:15:23 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"29172026/10/01 09:15:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete29182026/10/01 09:15:23 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"29192026/10/01 09:15:23 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=M2Y2NGZiZDYtZWFhNi00ZTdmLTk5NGMtMWNkMWFhOTc1MTcyLjJjYWIwMWI5LTBjY2EtNDE5MS1hMjY2LWUyYjRlMzM1MDBiZHgxNzkwODQ2MTIyNTY5OTUwMDE5 parts=1229202026/10/01 09:15:23 INFO Received uploads request method=POST path=/api/pending_closures2921--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.12s)29222026/10/01 09:15:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=800.109097ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2923--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2924 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.08s)2925 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2926 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.70s)29272026/10/01 09:15:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete29282026/10/01 09:15:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=M2Y2NGZiZDYtZWFhNi00ZTdmLTk5NGMtMWNkMWFhOTc1MTcyLmU5ZjI5Zjc1LTA1NDMtNGM4NC1hNTEyLTg0MjZmOTdmYjI3NngxNzkwODQ2MTIyODI2ODM0NTM0 parts=122929--- PASS: TestRedundantMultipartUpload (1.04s)2930=== NAME TestOrphanedObjectsGCStressTest2931 orphaned_objects_gc_test.go:509: Stress test completed successfully:2932 orphaned_objects_gc_test.go:510: - Active objects preserved: 202933 orphaned_objects_gc_test.go:511: - Objects deleted: 2102934 orphaned_objects_gc_test.go:512: - Total GC'd: 2102935--- PASS: TestOrphanedObjectsGCStressTest (3.03s)29362026/10/01 09:15:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.56706651s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present29372026/10/01 09:15:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02938=== NAME TestPinProtectsFromGC2939 client_integration_test.go:794: Pin successfully protected closure from garbage collection2940--- PASS: TestPinProtectsFromGC (2.97s)29412026/10/01 09:15:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02942=== NAME TestClientIntegration2943 client_integration_test.go:323: Objects in database after GC:2944 client_integration_test.go:323: Successfully deleted all objects with GC --force2945--- PASS: TestClientIntegration (2.81s)29462026/10/01 09:15:25 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-config29472026/10/01 09:15:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=211.074065ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29482026/10/01 09:15:26 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=394.458585ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29492026/10/01 09:15:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=808.201926ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29502026/10/01 09:15:26 WARN Rate limiter enabled after throttle name=s3-test rate=529512026/10/01 09:15:26 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2952=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2953 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102954 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002955--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.22s)29562026/10/01 09:15:27 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.502397448s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29572026/10/01 09:15:28 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"29582026/10/01 09:15:28 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-config29592026/10/01 09:15:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.978157ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29602026/10/01 09:15:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=424.194992ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29612026/10/01 09:15:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=806.57307ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29622026/10/01 09:15:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.4888193s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29632026/10/01 09:15:31 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_closures29642026/10/01 09:15:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=211.774636ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29652026/10/01 09:15:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=435.558963ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29662026/10/01 09:15:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=755.258783ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29672026/10/01 09:15:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.752221056s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2968--- PASS: TestClientErrorHandling (0.00s)2969 --- PASS: TestClientErrorHandling/InvalidStorePath (0.47s)2970 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.58s)2971 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.48s)2972PASS29732026-10-01 09:15:35.348 UTC [130] LOG: received smart shutdown request29742026-10-01 09:15:35.353 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 129752026-10-01 09:15:35.365 UTC [135] LOG: shutting down29762026-10-01 09:15:35.366 UTC [135] LOG: checkpoint starting: shutdown immediate29772026-10-01 09:15:36.865 UTC [135] LOG: checkpoint complete: wrote 10365 buffers (63.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 23 recycled; write=0.250 s, sync=1.207 s, total=1.500 s; sync files=26968, longest=0.003 s, average=0.001 s; distance=373716 kB, estimate=373716 kB; lsn=0/1845AFB8, redo lsn=0/1845AFB829782026-10-01 09:15:36.945 UTC [130] LOG: database system is shut down2979Running OIDC tests...2980=== RUN TestAudienceForIssuer2981=== PAUSE TestAudienceForIssuer2982=== RUN TestGlobMatch2983=== PAUSE TestGlobMatch2984=== RUN TestValidateToken_ValidToken2985=== PAUSE TestValidateToken_ValidToken2986=== RUN TestValidateToken_WrongAudience2987=== PAUSE TestValidateToken_WrongAudience2988=== RUN TestValidateToken_Expired2989=== PAUSE TestValidateToken_Expired2990=== RUN TestValidateToken_BoundClaimsMismatch2991=== PAUSE TestValidateToken_BoundClaimsMismatch2992=== RUN TestValidateToken_BoundSubjectMismatch2993=== PAUSE TestValidateToken_BoundSubjectMismatch2994=== RUN TestValidateToken_MultipleProviders2995=== PAUSE TestValidateToken_MultipleProviders2996=== RUN TestValidateToken_NoMatchingProvider2997=== PAUSE TestValidateToken_NoMatchingProvider2998=== RUN TestValidateToken_KubernetesServiceAccount2999=== PAUSE TestValidateToken_KubernetesServiceAccount3000=== RUN TestNewValidator_KubernetesRequiresCA3001=== PAUSE TestNewValidator_KubernetesRequiresCA3002=== RUN TestValidateToken_KubernetesIssuerFromOwnToken3003=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken3004=== RUN TestPins_ReservedForMatchingRule3005=== PAUSE TestPins_ReservedForMatchingRule3006=== RUN TestPins_TopLevelShorthand3007=== PAUSE TestPins_TopLevelShorthand3008=== RUN TestPins_ConfigValidation3009=== PAUSE TestPins_ConfigValidation3010=== RUN TestScopes_LegacyProviderDefaultsToWrite3011=== PAUSE TestScopes_LegacyProviderDefaultsToWrite3012=== RUN TestScopes_Rules3013=== PAUSE TestScopes_Rules3014=== RUN TestScopes_ConfigValidation3015=== PAUSE TestScopes_ConfigValidation3016=== CONT TestAudienceForIssuer3017=== CONT TestValidateToken_KubernetesServiceAccount3018=== CONT TestPins_ReservedForMatchingRule3019--- PASS: TestAudienceForIssuer (0.00s)3020=== CONT TestValidateToken_NoMatchingProvider3021=== CONT TestValidateToken_MultipleProviders3022=== CONT TestValidateToken_BoundSubjectMismatch3023=== CONT TestValidateToken_BoundClaimsMismatch3024=== CONT TestValidateToken_Expired3025=== CONT TestValidateToken_WrongAudience3026=== CONT TestValidateToken_ValidToken3027=== CONT TestGlobMatch3028=== RUN TestGlobMatch/foo_foo3029=== PAUSE TestGlobMatch/foo_foo3030=== RUN TestGlobMatch/foo_bar3031=== PAUSE TestGlobMatch/foo_bar3032=== RUN TestGlobMatch/*_3033=== PAUSE TestGlobMatch/*_3034=== RUN TestGlobMatch/*_anything3035=== PAUSE TestGlobMatch/*_anything3036=== RUN TestGlobMatch/foo*_foo3037=== PAUSE TestGlobMatch/foo*_foo3038=== RUN TestGlobMatch/foo*_foobar3039=== PAUSE TestGlobMatch/foo*_foobar3040=== RUN TestGlobMatch/foo*_bar3041=== PAUSE TestGlobMatch/foo*_bar3042=== RUN TestGlobMatch/*bar_bar3043=== PAUSE TestGlobMatch/*bar_bar3044=== RUN TestGlobMatch/*bar_foobar3045=== PAUSE TestGlobMatch/*bar_foobar3046=== RUN TestGlobMatch/*bar_foo3047=== PAUSE TestGlobMatch/*bar_foo3048=== RUN TestGlobMatch/foo*bar_foobar3049=== PAUSE TestGlobMatch/foo*bar_foobar3050=== RUN TestGlobMatch/foo*bar_foo123bar3051=== PAUSE TestGlobMatch/foo*bar_foo123bar3052=== RUN TestGlobMatch/foo*bar_foobarbaz3053=== PAUSE TestGlobMatch/foo*bar_foobarbaz3054=== RUN TestGlobMatch/*/*_foo/bar3055=== PAUSE TestGlobMatch/*/*_foo/bar3056=== RUN TestGlobMatch/*/*_foo3057=== PAUSE TestGlobMatch/*/*_foo3058=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3059=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3060=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03061=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03062=== RUN TestGlobMatch/refs/*/main_refs/heads/main3063=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3064=== RUN TestGlobMatch/fo?_foo3065=== PAUSE TestGlobMatch/fo?_foo3066=== RUN TestGlobMatch/fo?_fo3067=== PAUSE TestGlobMatch/fo?_fo3068=== RUN TestGlobMatch/fo?_fooo3069=== PAUSE TestGlobMatch/fo?_fooo3070=== RUN TestGlobMatch/?oo_foo3071=== PAUSE TestGlobMatch/?oo_foo3072=== RUN TestGlobMatch/?oo_boo3073=== PAUSE TestGlobMatch/?oo_boo3074=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3075=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3076=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3077=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3078=== CONT TestGlobMatch/foo_foo3079=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3080=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3081=== CONT TestGlobMatch/?oo_boo3082=== CONT TestGlobMatch/?oo_foo3083=== CONT TestGlobMatch/fo?_fooo3084=== CONT TestGlobMatch/fo?_fo3085=== CONT TestGlobMatch/fo?_foo3086=== CONT TestGlobMatch/refs/*/main_refs/heads/main3087=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03088=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3089=== CONT TestGlobMatch/*/*_foo3090=== CONT TestGlobMatch/*/*_foo/bar3091=== CONT TestGlobMatch/foo*bar_foobarbaz3092=== CONT TestGlobMatch/foo*bar_foo123bar3093=== CONT TestGlobMatch/foo*bar_foobar3094=== CONT TestGlobMatch/*bar_foo3095=== CONT TestGlobMatch/*bar_foobar3096=== CONT TestGlobMatch/*bar_bar3097=== CONT TestGlobMatch/foo*_bar3098=== CONT TestGlobMatch/foo*_foobar3099=== CONT TestGlobMatch/foo*_foo3100=== CONT TestGlobMatch/*_anything3101=== CONT TestGlobMatch/*_3102=== CONT TestGlobMatch/foo_bar3103--- PASS: TestGlobMatch (0.00s)3104 --- PASS: TestGlobMatch/foo_foo (0.00s)3105 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3106 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3107 --- PASS: TestGlobMatch/?oo_boo (0.00s)3108 --- PASS: TestGlobMatch/?oo_foo (0.00s)3109 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3110 --- PASS: TestGlobMatch/fo?_fo (0.00s)3111 --- PASS: TestGlobMatch/fo?_foo (0.00s)3112 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3113 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3114 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3115 --- PASS: TestGlobMatch/*/*_foo (0.00s)3116 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3117 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3118 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3119 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3120 --- PASS: TestGlobMatch/*bar_foo (0.00s)3121 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3122 --- PASS: TestGlobMatch/*bar_bar (0.00s)3123 --- PASS: TestGlobMatch/foo*_bar (0.00s)3124 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3125 --- PASS: TestGlobMatch/foo*_foo (0.00s)3126 --- PASS: TestGlobMatch/*_anything (0.00s)3127 --- PASS: TestGlobMatch/*_ (0.00s)3128 --- PASS: TestGlobMatch/foo_bar (0.00s)3129=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3130=== CONT TestPins_TopLevelShorthand3131=== CONT TestNewValidator_KubernetesRequiresCA3132=== CONT TestScopes_Rules3133=== CONT TestScopes_ConfigValidation3134=== CONT TestScopes_LegacyProviderDefaultsToWrite3135=== CONT TestPins_ConfigValidation3136--- PASS: TestScopes_ConfigValidation (0.00s)3137--- PASS: TestPins_ConfigValidation (0.00s)31382026/10/01 09:15:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36033/oidc3139--- PASS: TestValidateToken_ValidToken (0.02s)31402026/10/01 09:15:38 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:344073141--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)31422026/10/01 09:15:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38297/oidc3143--- PASS: TestValidateToken_WrongAudience (0.04s)31442026/10/01 09:15:38 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39275/oidc3145--- PASS: TestValidateToken_NoMatchingProvider (0.04s)31462026/10/01 09:15:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37271/oidc3147--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)31482026/10/01 09:15:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41045/oidc31492026/10/01 09:15:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35607/oidc3150--- PASS: TestPins_TopLevelShorthand (0.05s)3151--- PASS: TestPins_ReservedForMatchingRule (0.05s)31522026/10/01 09:15:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36599/oidc31532026/10/01 09:15:38 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1233154--- PASS: TestValidateToken_Expired (0.05s)3155--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)31562026/10/01 09:15:38 http: TLS handshake error from 127.0.0.1:33578: remote error: tls: bad certificate3157--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)31582026/10/01 09:15:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35263/oidc3159--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.08s)31602026/10/01 09:15:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44869/oidc3161--- PASS: TestValidateToken_BoundSubjectMismatch (0.10s)31622026/10/01 09:15:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46401/oidc3163--- PASS: TestScopes_Rules (0.11s)31642026/10/01 09:15:38 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34853/oidc31652026/10/01 09:15:38 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46149/oidc3166--- PASS: TestValidateToken_MultipleProviders (0.16s)3167PASS3168Running hook tests...3169=== RUN TestSendPathsEmpty3170=== PAUSE TestSendPathsEmpty3171=== RUN TestQueueEnqueueAndFetch3172=== PAUSE TestQueueEnqueueAndFetch3173=== RUN TestQueueDeduplication3174=== PAUSE TestQueueDeduplication3175=== RUN TestQueueRemove3176=== PAUSE TestQueueRemove3177=== RUN TestQueueFetchBatchLimit3178=== PAUSE TestQueueFetchBatchLimit3179=== RUN TestQueueRetryMovesToBack3180=== PAUSE TestQueueRetryMovesToBack3181=== RUN TestQueueFetchRemoveLifecycle3182=== PAUSE TestQueueFetchRemoveLifecycle3183=== RUN TestQueueConcurrentWriters3184=== PAUSE TestQueueConcurrentWriters3185=== RUN TestQueueRemoveLargeClosure3186=== PAUSE TestQueueRemoveLargeClosure3187=== RUN TestServerClientIntegration3188=== PAUSE TestServerClientIntegration3189=== RUN TestServerQueueError3190=== PAUSE TestServerQueueError3191=== RUN TestGetListenerSocketActivation3192 server_test.go:210: === RUN TestGetListenerSocketActivation3193 --- PASS: TestGetListenerSocketActivation (0.00s)3194 PASS3195 3196--- PASS: TestGetListenerSocketActivation (0.01s)3197=== RUN TestDrainIsolatesPoisonPath3198=== PAUSE TestDrainIsolatesPoisonPath3199=== RUN TestRunNotBlockedByPoisonHead3200=== PAUSE TestRunNotBlockedByPoisonHead3201=== RUN TestDrainGivesUpWhenServerDown3202=== PAUSE TestDrainGivesUpWhenServerDown3203=== RUN TestFailedPathPrunedByLaterClosure3204=== PAUSE TestFailedPathPrunedByLaterClosure3205=== RUN TestWorkerUploadsAndRemoves3206=== PAUSE TestWorkerUploadsAndRemoves3207=== RUN TestWorkerSkipsGCdPaths3208=== PAUSE TestWorkerSkipsGCdPaths3209=== RUN TestWorkerPrunesClosureDeps3210=== PAUSE TestWorkerPrunesClosureDeps3211=== RUN TestDrainTimeout3212=== PAUSE TestDrainTimeout3213=== CONT TestSendPathsEmpty3214=== CONT TestServerQueueError3215--- PASS: TestSendPathsEmpty (0.00s)3216=== CONT TestServerClientIntegration3217=== CONT TestWorkerUploadsAndRemoves3218=== CONT TestQueueRemoveLargeClosure3219=== CONT TestDrainTimeout3220=== CONT TestQueueConcurrentWriters3221=== CONT TestWorkerPrunesClosureDeps3222=== CONT TestQueueFetchRemoveLifecycle3223=== CONT TestQueueRetryMovesToBack32242026/10/01 09:15:38 ERROR Failed to queue paths error="permission denied" count=13225=== CONT TestQueueFetchBatchLimit3226=== CONT TestQueueRemove3227=== CONT TestQueueDeduplication3228=== CONT TestWorkerSkipsGCdPaths3229=== CONT TestDrainGivesUpWhenServerDown3230=== CONT TestQueueEnqueueAndFetch3231=== CONT TestFailedPathPrunedByLaterClosure3232=== CONT TestRunNotBlockedByPoisonHead3233=== CONT TestDrainIsolatesPoisonPath3234--- PASS: TestServerQueueError (0.00s)3235--- PASS: TestServerClientIntegration (0.00s)32362026/10/01 09:15:38 INFO Upload queue status pending=332372026/10/01 09:15:38 INFO Upload queue status pending=232382026/10/01 09:15:38 INFO Uploading batch count=132392026/10/01 09:15:38 ERROR Upload failed error="upload failed" count=132402026/10/01 09:15:38 INFO Uploading batch count=132412026/10/01 09:15:38 ERROR Upload failed error="upload failed" count=132422026/10/01 09:15:38 INFO Uploading batch count=232432026/10/01 09:15:38 INFO Uploading batch count=432442026/10/01 09:15:38 ERROR Upload failed error="upload failed" count=432452026/10/01 09:15:38 INFO Uploading batch count=232462026/10/01 09:15:38 INFO Upload queue status pending=232472026/10/01 09:15:38 INFO Uploading batch count=232482026/10/01 09:15:38 INFO Uploading batch count=132492026/10/01 09:15:38 INFO Upload queue status pending=232502026/10/01 09:15:38 ERROR Upload failed error="upload failed" count=232512026/10/01 09:15:38 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1258668486/002/nonexistent32522026/10/01 09:15:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2346298570/002/a32532026/10/01 09:15:38 INFO Uploading batch count=132542026/10/01 09:15:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3587901239/002/bbb3255--- PASS: TestQueueFetchBatchLimit (0.02s)32562026/10/01 09:15:38 INFO Uploading batch count=13257--- PASS: TestQueueDeduplication (0.02s)3258--- PASS: TestQueueFetchRemoveLifecycle (0.02s)32592026/10/01 09:15:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2346298570/002/b32602026/10/01 09:15:38 INFO Uploading batch count=13261--- PASS: TestQueueRemove (0.02s)3262--- PASS: TestQueueRetryMovesToBack (0.02s)3263--- PASS: TestQueueEnqueueAndFetch (0.02s)32642026/10/01 09:15:38 INFO Uploading batch count=232652026/10/01 09:15:38 ERROR Upload failed error="upload failed" count=232662026/10/01 09:15:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2346298570/002/c32672026/10/01 09:15:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2346298570/002/d32682026/10/01 09:15:38 INFO Uploading batch count=132692026/10/01 09:15:38 ERROR Upload failed error="upload failed" count=132702026/10/01 09:15:38 INFO Uploading batch count=232712026/10/01 09:15:38 ERROR Upload failed error="upload failed" count=232722026/10/01 09:15:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2346298570/002/e32732026/10/01 09:15:38 INFO Uploading batch count=132742026/10/01 09:15:38 ERROR Upload failed error="upload failed" count=132752026/10/01 09:15:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2346298570/002/f32762026/10/01 09:15:38 INFO Uploading batch count=132772026/10/01 09:15:38 ERROR Drain finished with paths left in queue remaining=1032782026/10/01 09:15:38 ERROR Upload failed error="upload failed" count=13279--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)32802026/10/01 09:15:38 ERROR Drain finished with paths left in queue remaining=13281--- PASS: TestDrainGivesUpWhenServerDown (0.03s)3282--- PASS: TestDrainIsolatesPoisonPath (0.03s)3283--- PASS: TestWorkerUploadsAndRemoves (0.04s)3284--- PASS: TestWorkerSkipsGCdPaths (0.04s)3285--- PASS: TestWorkerPrunesClosureDeps (0.04s)3286--- PASS: TestQueueRemoveLargeClosure (0.11s)32872026/10/01 09:15:39 ERROR Upload failed error="context deadline exceeded" count=232882026/10/01 09:15:39 ERROR Drain finished with paths left in queue remaining=43289--- PASS: TestDrainTimeout (0.22s)3290--- PASS: TestQueueConcurrentWriters (0.38s)32912026/10/01 09:15:39 INFO Uploading batch count=132922026/10/01 09:15:39 INFO Uploading batch count=132932026/10/01 09:15:39 INFO Uploading batch count=132942026/10/01 09:15:39 ERROR Upload failed error="upload failed" count=132952026/10/01 09:15:39 INFO Uploading batch count=132962026/10/01 09:15:39 ERROR Upload failed error="upload failed" count=132972026/10/01 09:15:39 INFO Uploading batch count=132982026/10/01 09:15:39 ERROR Upload failed error="upload failed" count=132992026/10/01 09:15:39 INFO Uploading batch count=133002026/10/01 09:15:39 ERROR Upload failed error="upload failed" count=133012026/10/01 09:15:39 ERROR Drain finished with paths left in queue remaining=13302--- PASS: TestRunNotBlockedByPoisonHead (1.04s)3303PASS