niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #301
· 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 TestShellSplit97=== CONT TestEncodeNixBase32WithRealHash98=== CONT TestStreamPushBatchesUnderLoad99=== CONT TestStreamPushGivesUpOnDeadServer100=== CONT TestSetClientTLSErrors101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102=== CONT TestScriptTokenEmptyCommand103=== CONT TestStreamPushIsolatesFailures104=== CONT TestResolveStorePath1052026/10/01 08:26:37 ERROR Upload failed error="connection refused" count=201062026/10/01 08:26:37 ERROR Server seems unavailable, giving up on batch untried=171072026/10/01 08:26:37 ERROR Upload failed error="bad path" count=3108=== CONT TestScriptTokenScriptFails109=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess110=== CONT TestScriptTokenBadJSON111=== CONT TestRateLimiterFeedback112=== RUN TestRateLimiterFeedback/429_enables_limiter113=== CONT TestScriptTokenEmptyToken114=== PAUSE TestRateLimiterFeedback/429_enables_limiter115=== CONT TestSetClientTLS116=== RUN TestRateLimiterFeedback/503_enables_limiter117=== PAUSE TestRateLimiterFeedback/503_enables_limiter118=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter1192026/10/01 08:26:37 WARN Rate limiter enabled after throttle name=server-test rate=5120=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter121=== CONT TestStreamPushReportsEveryPath122=== CONT TestPathInfoCACompatibility123=== RUN TestPathInfoCACompatibility/null_ca_field124=== CONT TestParsePathInfoJSONMultiplePaths125=== CONT TestScriptTokenNoExpiryRerunsEveryCall126=== CONT TestParsePathInfoJSON127=== CONT TestFileTokenEmpty128=== RUN TestParsePathInfoJSON/Nix_format129=== PAUSE TestParsePathInfoJSON/Nix_format1302026/10/01 08:26:37 WARN Rate limiter enabled after throttle name=server-test rate=5131=== CONT TestFileTokenMissing1322026/10/01 08:26:37 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40501133=== CONT TestGetStorePathHash134=== RUN TestGetStorePathHash/valid_store_path135=== CONT TestFileTokenReadsAndCaches136=== CONT TestConvertHashToNix32137=== CONT TestStaticToken138--- PASS: TestShellSplit (0.00s)139=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter140=== CONT TestScriptTokenCachesUntilRefresh141=== PAUSE TestPathInfoCACompatibility/null_ca_field142=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths143=== RUN TestParsePathInfoJSON/Lix_format144=== CONT TestPathInfoHashCompatibility145=== CONT TestUploadMultipart_SupersededByPeer1462026/10/01 08:26:37 WARN Rate limiter backed off name=server-test rate=5147=== RUN TestSetClientTLSErrors/missing_cert_file148=== RUN TestUploadMultipart_SupersededByPeer/exists1492026/10/01 08:26:37 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:40501150=== CONT TestSetClientTLSDoesNotMutateDefaultTransport151=== CONT TestClientSignaturesByStorePath152=== CONT TestDumpPathWriterError153--- PASS: TestEncodeNixBase32WithRealHash (0.00s)154--- PASS: TestScriptTokenEmptyCommand (0.00s)155--- PASS: TestStreamPushIsolatesFailures (0.00s)156--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)157--- PASS: TestStreamPushReportsEveryPath (0.00s)158=== CONT TestDumpPathSingleFile159=== PAUSE TestGetStorePathHash/valid_store_path160=== CONT TestEncodeNixBase32161=== RUN TestConvertHashToNix32/SRI_format_to_Nix32162=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter163=== RUN TestPathInfoCACompatibility/old_string_format_-_text164=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text165=== CONT TestShellSplitErrors166=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive167=== CONT TestRegisterUploadedObjectReusesConnections168=== PAUSE TestParsePathInfoJSON/Lix_format169=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive170=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)171=== PAUSE TestSetClientTLSErrors/missing_cert_file172=== PAUSE TestUploadMultipart_SupersededByPeer/exists173--- PASS: TestResolveStorePath (0.00s)174=== CONT TestDumpPathMatchesNix175=== RUN TestGetStorePathHash/basename_without_hyphen_should_error176=== RUN TestEncodeNixBase32/test_string_hash177=== CONT TestFilterOversizedClosures178=== CONT TestUploadMultipart_PartsInParallel179=== RUN TestUploadMultipart_SupersededByPeer/missing180=== PAUSE TestUploadMultipart_SupersededByPeer/missing181=== CONT TestCaseHackSuffix182=== CONT TestStreamPushRequestLine183=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32184=== CONT TestPartSizeForNAR185=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths186=== RUN TestParsePathInfoJSON/empty_input187=== CONT TestStreamPushReportsSignatures188=== RUN TestPathInfoCACompatibility/new_structured_format_-_text189=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)190=== RUN TestSetClientTLSErrors/missing_key_file191--- PASS: TestScriptTokenScriptFails (0.00s)192=== RUN TestSetClientTLS/rejects_connection_without_client_cert193=== RUN TestFilterOversizedClosures/no_limit_keeps_everything194=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter195=== PAUSE TestEncodeNixBase32/test_string_hash196=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error197=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error198=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text199=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything200=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths201=== RUN TestConvertHashToNix32/already_Nix32_format202=== PAUSE TestConvertHashToNix32/already_Nix32_format203=== RUN TestConvertHashToNix32/invalid_format204=== PAUSE TestParsePathInfoJSON/empty_input205=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2062026/10/01 08:26:37 ERROR Upload failed error=boom count=1207=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped208=== RUN TestFilterOversizedClosures/all_closures_skipped209=== PAUSE TestFilterOversizedClosures/all_closures_skipped2102026/10/01 08:26:37 ERROR Upload failed error=boom count=1211=== RUN TestPartSizeForNAR/zero_stays_at_minimum212=== CONT TestRateLimiterFeedback/503_enables_limiter213=== PAUSE TestConvertHashToNix32/invalid_format214=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum215=== RUN TestPartSizeForNAR/small_stays_at_minimum216=== PAUSE TestPartSizeForNAR/small_stays_at_minimum217=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum218=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum219=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts220=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths221=== CONT TestUploadMultipart_SupersededByPeer/exists222=== CONT TestFilterOversizedClosures/no_limit_keeps_everything223=== CONT TestFilterOversizedClosures/all_closures_skipped2242026/10/01 08:26:37 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50225=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon226=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon227=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2282026/10/01 08:26:37 WARN Rate limiter enabled after throttle name=server-test rate=5229=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2302026/10/01 08:26:37 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:34115231=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512232=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512233=== PAUSE TestSetClientTLSErrors/missing_key_file234=== RUN TestSetClientTLSErrors/missing_ca_file235=== PAUSE TestSetClientTLSErrors/missing_ca_file236--- PASS: TestFileTokenEmpty (0.00s)2372026/10/01 08:26:37 WARN Rate limiter backed off name=server-test rate=5238=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert239=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method240=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error241=== RUN TestEncodeNixBase32/empty_input242=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter243=== RUN TestParsePathInfoJSON/whitespace_only244=== CONT TestRateLimiterFeedback/429_enables_limiter245=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts246=== PAUSE TestParsePathInfoJSON/whitespace_only247=== RUN TestParsePathInfoJSON/invalid_JSON248=== PAUSE TestParsePathInfoJSON/invalid_JSON249=== CONT TestConvertHashToNix32/invalid_format250=== CONT TestConvertHashToNix32/already_Nix32_format251=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths252=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths253=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)254=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512255=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI256=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped257=== CONT TestParsePathInfoJSON/whitespace_only2582026/10/01 08:26:37 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=2000259=== CONT TestParsePathInfoJSON/invalid_JSON260=== CONT TestParsePathInfoJSON/Lix_format261=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error262=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error2632026/10/01 08:26:37 WARN Rate limiter enabled after throttle name=server-test rate=5264=== CONT TestGetStorePathHash/valid_store_path2652026/10/01 08:26:37 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:39767266=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA267=== CONT TestParsePathInfoJSON/empty_input268=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error269=== RUN TestSetClientTLSErrors/invalid_ca_file270=== PAUSE TestSetClientTLSErrors/invalid_ca_file271--- PASS: TestStaticToken (0.00s)2722026/10/01 08:26:37 WARN Rate limiter backed off name=server-test rate=5273=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method274=== RUN TestPartSizeForNAR/1_TiB275=== PAUSE TestPartSizeForNAR/1_TiB276=== RUN TestPartSizeForNAR/5_TiB_S3_max_object277=== CONT TestUploadMultipart_SupersededByPeer/missing278=== CONT TestPathInfoCACompatibility/null_ca_field279=== CONT TestPathInfoCACompatibility/new_structured_format_-_text280=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon281=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive282=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method283=== CONT TestPathInfoCACompatibility/old_string_format_-_text284=== CONT TestParsePathInfoJSON/Nix_format285=== CONT TestConvertHashToNix32/SRI_format_to_Nix32286=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error287=== CONT TestGetStorePathHash/basename_without_hyphen_should_error288=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA289=== RUN TestSetClientTLS/preserves_debug_logging_transport290=== PAUSE TestSetClientTLS/preserves_debug_logging_transport291=== CONT TestSetClientTLS/rejects_connection_without_client_cert292=== CONT TestSetClientTLS/preserves_debug_logging_transport293=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA294=== CONT TestSetClientTLSErrors/missing_cert_file295=== PAUSE TestEncodeNixBase32/empty_input296=== CONT TestEncodeNixBase32/test_string_hash297=== CONT TestSetClientTLSErrors/invalid_ca_file298=== CONT TestEncodeNixBase32/empty_input299=== CONT TestSetClientTLSErrors/missing_ca_file300--- PASS: TestDoServerRequestAttachesToken (0.01s)301=== CONT TestSetClientTLSErrors/missing_key_file302--- PASS: TestClientSignaturesByStorePath (0.00s)303--- PASS: TestScriptTokenBadJSON (0.00s)304=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object305=== RUN TestPartSizeForNAR/capped_at_5_GiB306--- PASS: TestScriptTokenEmptyToken (0.00s)307--- PASS: TestFileTokenMissing (0.00s)308--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)309--- PASS: TestShellSplitErrors (0.00s)310--- PASS: TestFileTokenReadsAndCaches (0.00s)311=== PAUSE TestPartSizeForNAR/capped_at_5_GiB312=== CONT TestPartSizeForNAR/zero_stays_at_minimum313--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)314--- PASS: TestDumpPathSingleFile (0.08s)315--- PASS: TestStreamPushReportsSignatures (0.00s)316=== CONT TestPartSizeForNAR/capped_at_5_GiB317=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts318=== CONT TestPartSizeForNAR/5_TiB_S3_max_object319=== CONT TestPartSizeForNAR/1_TiB320=== CONT TestPartSizeForNAR/small_stays_at_minimum321=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum322--- PASS: TestParsePathInfoJSONMultiplePaths (0.08s)323 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)324 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)325--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.09s)326--- PASS: TestFilterOversizedClosures (0.07s)327 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)328 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)329 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)330--- PASS: TestPartSizeForNAR (0.00s)331 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)332 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)333 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)334 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)335 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)336 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)337 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)338--- PASS: TestRateLimiterFeedback (0.00s)339 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)340 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)341 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)342 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)343--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)344 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)345 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)346--- PASS: TestScriptTokenCachesUntilRefresh (0.08s)347--- PASS: TestPathInfoCACompatibility (0.08s)348 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)349 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)350 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)351 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)352 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)353--- PASS: TestConvertHashToNix32 (0.08s)354 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)355 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)356 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)357--- PASS: TestGetStorePathHash (0.08s)358 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)359 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)360 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)361 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)362--- PASS: TestParsePathInfoJSON (0.08s)363 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)364 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)365 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)366 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)367 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)368--- PASS: TestPathInfoHashCompatibility (0.08s)369 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)370 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)371 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)372 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)373--- PASS: TestEncodeNixBase32 (0.08s)374 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)375 --- PASS: TestEncodeNixBase32/empty_input (0.00s)376--- PASS: TestSetClientTLSErrors (0.09s)377 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)378 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)379 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3812026/10/01 08:26:37 http: TLS handshake error from 127.0.0.1:56040: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.09s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)386--- PASS: TestStreamPushRequestLine (0.02s)387--- PASS: TestRegisterUploadedObjectReusesConnections (0.10s)388--- PASS: TestCaseHackSuffix (0.10s)389--- PASS: TestDumpPathWriterError (0.12s)390--- PASS: TestStreamPushBatchesUnderLoad (0.13s)391--- PASS: TestDumpPathMatchesNix (0.16s)392--- PASS: TestUploadMultipart_PartsInParallel (0.69s)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/postgres3122748087/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/postgres3122748087/data -l logfile start422423/build/postgres3122748087:5432 - no response4242026-10-01 08:26:39.559 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 08:26:39.559 UTC [128] LOG: listening on Unix socket "/build/postgres3122748087/.s.PGSQL.5432"4262026-10-01 08:26:39.564 UTC [135] LOG: database system was shut down at 2026-10-01 08:26:39 UTC4272026-10-01 08:26:39.567 UTC [128] LOG: database system is ready to accept connections428/build/postgres3122748087:5432 - accepting connections429{"timestamp":"2026-10-01T08:26:39.870596314Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ea862d40-8206-4e82-8cbb-50617c96005c","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(399)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-10-01 08:26:40.064 UTC [564] ERROR: relation "goose_db_version" does not exist at character 364722026-10-01 08:26:40.064 UTC [564] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/10/01 08:26:40 OK 20241026095416_initial_model.sql (7.31ms)4742026/10/01 08:26:40 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)4752026/10/01 08:26:40 OK 20251218171726_add_pins.sql (2.03ms)4762026/10/01 08:26:40 OK 20260628120000_add_object_size_and_stats.sql (2.16ms)4772026/10/01 08:26:40 OK 20260905000000_add_claims.sql (2.21ms)4782026/10/01 08:26:40 OK 20260920000000_drop_claims.sql (1.38ms)4792026/10/01 08:26:40 OK 20260923120000_add_pushes.sql (908.8µs)4802026/10/01 08:26:40 goose: successfully migrated database to version: 202609231200004812026/10/01 08:26:40 OK 1_commit_pending_closure.sql (1.37ms)4822026/10/01 08:26:40 OK 2_object_stats_trigger.sql (635.01µs)4832026/10/01 08:26:40 OK 3_commit_push.sql (535µs)4842026/10/01 08:26:40 goose: up to current file version: 34852026/10/01 08:26:40 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 08:26:40 INFO lead: released remote=192.0.2.1:12344872026/10/01 08:26:40 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 08:26:40 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.79s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-10-01 08:26:40.832 UTC [574] ERROR: relation "goose_db_version" does not exist at character 364942026-10-01 08:26:40.832 UTC [574] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/10/01 08:26:40 OK 20241026095416_initial_model.sql (8.04ms)4962026/10/01 08:26:40 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)4972026/10/01 08:26:40 OK 20251218171726_add_pins.sql (5.45ms)4982026/10/01 08:26:40 OK 20260628120000_add_object_size_and_stats.sql (3.78ms)4992026/10/01 08:26:40 OK 20260905000000_add_claims.sql (2.09ms)5002026/10/01 08:26:40 OK 20260920000000_drop_claims.sql (1.41ms)5012026/10/01 08:26:40 OK 20260923120000_add_pushes.sql (942.76µs)5022026/10/01 08:26:40 goose: successfully migrated database to version: 202609231200005032026/10/01 08:26:40 OK 1_commit_pending_closure.sql (1.56ms)5042026/10/01 08:26:40 OK 2_object_stats_trigger.sql (652.41µs)5052026/10/01 08:26:40 OK 3_commit_push.sql (498.83µs)5062026/10/01 08:26:40 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestObjectStatsTrigger579=== PAUSE TestObjectStatsTrigger580=== RUN TestOrphanedObjectsGC581=== PAUSE TestOrphanedObjectsGC582=== RUN TestOrphanedObjectsGCStressTest583=== PAUSE TestOrphanedObjectsGCStressTest584=== RUN TestCreatePin_ReservedPins585=== PAUSE TestCreatePin_ReservedPins586=== RUN TestParseSingleRange587=== PAUSE TestParseSingleRange588=== RUN TestProxyHeadersOnlyTrustedOnSocket589=== PAUSE TestProxyHeadersOnlyTrustedOnSocket590=== RUN TestIsValidCachePath591=== PAUSE TestIsValidCachePath592=== RUN TestReadProxyNarinfo593=== PAUSE TestReadProxyNarinfo594=== RUN TestReadProxyNarinfoAlreadyDecompressed595=== PAUSE TestReadProxyNarinfoAlreadyDecompressed596=== RUN TestReadProxyNarStreaming597=== PAUSE TestReadProxyNarStreaming598=== RUN TestReadProxy404599=== PAUSE TestReadProxy404600=== RUN TestReadProxyInvalidPath601=== PAUSE TestReadProxyInvalidPath602=== RUN TestReadProxyHead603=== PAUSE TestReadProxyHead604=== RUN TestReadProxyConditionalGet605=== PAUSE TestReadProxyConditionalGet606=== RUN TestReadProxyRootRedirectsToIndexHTML607=== PAUSE TestReadProxyRootRedirectsToIndexHTML608=== RUN TestReadProxyDisabled609=== PAUSE TestReadProxyDisabled610=== RUN TestReadRedirectNar611=== PAUSE TestReadRedirectNar612=== RUN TestReadRedirectKeepsNarinfoProxied613=== PAUSE TestReadRedirectKeepsNarinfoProxied614=== RUN TestReadProxyRangeRequest615=== PAUSE TestReadProxyRangeRequest616=== RUN TestReadRedirectUsesPublicS3URL617=== PAUSE TestReadRedirectUsesPublicS3URL618=== RUN TestPush_OverlappingRootsStoreOneRowPerKey619=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey620=== RUN TestPush_CompleteCommitsEveryRoot621=== PAUSE TestPush_CompleteCommitsEveryRoot622=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit623=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit624=== RUN TestPush_RejectsBadRequests625=== PAUSE TestPush_RejectsBadRequests626=== RUN TestPush_SignsNarinfosOfItsPendingObjects627=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects628=== RUN TestRedundantMultipartUpload629=== PAUSE TestRedundantMultipartUpload630=== RUN TestCompleteMultipartUpload_ErrorButObjectExists631=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists632=== RUN TestCompletedNarNotReofferedAcrossClosures633=== PAUSE TestCompletedNarNotReofferedAcrossClosures634=== RUN TestPresignedUploadRegisteredBeforeCommit635=== PAUSE TestPresignedUploadRegisteredBeforeCommit636=== RUN TestService_Rustfstest637=== PAUSE TestService_Rustfstest638=== RUN TestParseSize639=== PAUSE TestParseSize640=== RUN TestSkippedUploadsHandler641=== PAUSE TestSkippedUploadsHandler642=== RUN TestSystemdListenerNotActivated643--- PASS: TestSystemdListenerNotActivated (0.00s)644=== RUN TestWatchdogBeatsWhenHealthy645--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)646=== RUN TestWatchdogSkipsWhenUnhealthy6472026/10/01 08:26:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 08:26:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 08:26:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 08:26:40 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/01 08:26:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/01 08:26:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6532026/10/01 08:26:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6542026/10/01 08:26:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/01 08:26:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/01 08:26:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"657--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)658=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle659=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle660=== RUN TestProxyWriteTimeout661=== PAUSE TestProxyWriteTimeout662=== RUN TestIsValidUploadKey663=== PAUSE TestIsValidUploadKey664=== RUN TestUploadHandlersRejectInvalidKeys665=== PAUSE TestUploadHandlersRejectInvalidKeys666=== RUN TestUploadHandlersRejectOversizedBody667=== PAUSE TestUploadHandlersRejectOversizedBody668=== RUN TestService_cleanupPendingClosuresHandler669=== PAUSE TestService_cleanupPendingClosuresHandler670=== RUN TestService_createPendingClosureHandler671=== PAUSE TestService_createPendingClosureHandler672=== RUN TestService_verifyS3Integrity673=== PAUSE TestService_verifyS3Integrity674=== RUN TestCompleteMultipartUnregistered675=== PAUSE TestCompleteMultipartUnregistered676=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT677=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT678=== CONT TestService_AuthMiddleware679=== CONT TestRedundantMultipartUpload680=== CONT TestReadProxyNarStreaming681=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT682=== CONT TestCompleteMultipartUnregistered683=== CONT TestService_verifyS3Integrity684=== CONT TestService_createPendingClosureHandler685=== CONT TestService_cleanupPendingClosuresHandler686=== CONT TestUploadHandlersRejectOversizedBody687=== CONT TestUploadHandlersRejectInvalidKeys688=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info689=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info690=== CONT TestIsValidUploadKey691=== RUN TestIsValidUploadKey/narinfo692=== CONT TestProxyWriteTimeout693=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle694=== CONT TestSkippedUploadsHandler695=== CONT TestParseSize696=== CONT TestService_Rustfstest697=== CONT TestPresignedUploadRegisteredBeforeCommit698=== CONT TestCompletedNarNotReofferedAcrossClosures699=== CONT TestCompleteMultipartUpload_ErrorButObjectExists700=== CONT TestPush_SignsNarinfosOfItsPendingObjects701=== CONT TestPush_RejectsBadRequests702=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit703=== CONT TestPush_CompleteCommitsEveryRoot704=== CONT TestCacheConfigHandlerMaxNarSize705=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal706=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal707=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key708=== RUN TestProxyWriteTimeout/narinfo709=== PAUSE TestIsValidUploadKey/narinfo710=== RUN TestIsValidUploadKey/nar_zst711--- PASS: TestParseSize (0.00s)712=== CONT TestPush_OverlappingRootsStoreOneRowPerKey7132026/10/01 08:26:41 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000714--- PASS: TestSkippedUploadsHandler (0.01s)715=== CONT TestReadRedirectUsesPublicS3URL716=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key717=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key718=== PAUSE TestProxyWriteTimeout/narinfo719=== RUN TestProxyWriteTimeout/1_GiB_nar720=== PAUSE TestProxyWriteTimeout/1_GiB_nar721=== RUN TestProxyWriteTimeout/10_GiB_nar722--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)723=== CONT TestReadProxyRangeRequest724=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key725=== CONT TestReadRedirectKeepsNarinfoProxied726=== PAUSE TestIsValidUploadKey/nar_zst727=== RUN TestIsValidUploadKey/nar_xz728=== PAUSE TestProxyWriteTimeout/10_GiB_nar729=== RUN TestProxyWriteTimeout/unknown_size730=== PAUSE TestProxyWriteTimeout/unknown_size731=== PAUSE TestIsValidUploadKey/nar_xz732=== RUN TestIsValidUploadKey/nar_plain733=== PAUSE TestIsValidUploadKey/nar_plain734=== RUN TestIsValidUploadKey/listing735=== CONT TestReadRedirectNar736=== PAUSE TestIsValidUploadKey/listing737=== RUN TestIsValidUploadKey/build_log738=== PAUSE TestIsValidUploadKey/build_log739=== RUN TestIsValidUploadKey/build_log_home-manager_file740=== PAUSE TestIsValidUploadKey/build_log_home-manager_file741=== RUN TestIsValidUploadKey/build_log_plus_in_name742=== PAUSE TestIsValidUploadKey/build_log_plus_in_name743=== RUN TestIsValidUploadKey/build_log_question_mark744=== PAUSE TestIsValidUploadKey/build_log_question_mark745=== RUN TestIsValidUploadKey/build_log_equals746=== PAUSE TestIsValidUploadKey/build_log_equals747=== RUN TestIsValidUploadKey/realisation748=== PAUSE TestIsValidUploadKey/realisation749=== RUN TestIsValidUploadKey/realisation_plus_in_output750=== PAUSE TestIsValidUploadKey/realisation_plus_in_output751=== RUN TestIsValidUploadKey/nix-cache-info752=== PAUSE TestIsValidUploadKey/nix-cache-info753=== RUN TestIsValidUploadKey/index.html754=== PAUSE TestIsValidUploadKey/index.html755=== RUN TestIsValidUploadKey/narinfo_key,_nar_type756=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type757=== RUN TestIsValidUploadKey/nar_key,_narinfo_type758=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type759=== RUN TestIsValidUploadKey/listing_key,_narinfo_type760=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type761=== RUN TestIsValidUploadKey/traversal762=== PAUSE TestIsValidUploadKey/traversal763=== RUN TestIsValidUploadKey/traversal_nar764=== PAUSE TestIsValidUploadKey/traversal_nar765=== RUN TestIsValidUploadKey/absolute766=== PAUSE TestIsValidUploadKey/absolute767=== RUN TestIsValidUploadKey/empty_key768=== PAUSE TestIsValidUploadKey/empty_key769=== RUN TestIsValidUploadKey/unknown_type770=== PAUSE TestIsValidUploadKey/unknown_type771=== CONT TestReadProxyDisabled772=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts773=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts774=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure775=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure776=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart777=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart778=== CONT TestReadProxyRootRedirectsToIndexHTML7792026-10-01 08:26:41.280 UTC [641] ERROR: relation "goose_db_version" does not exist at character 367802026-10-01 08:26:41.280 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7812026-10-01 08:26:41.464 UTC [642] ERROR: relation "goose_db_version" does not exist at character 367822026-10-01 08:26:41.464 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7832026/10/01 08:26:41 OK 20241026095416_initial_model.sql (203.05ms)7842026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (6.49ms)7852026-10-01 08:26:41.565 UTC [643] ERROR: relation "goose_db_version" does not exist at character 367862026-10-01 08:26:41.565 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7872026/10/01 08:26:41 OK 20251218171726_add_pins.sql (11.11ms)7882026/10/01 08:26:41 OK 20241026095416_initial_model.sql (28.18ms)7892026-10-01 08:26:41.573 UTC [644] ERROR: relation "goose_db_version" does not exist at character 367902026-10-01 08:26:41.573 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7912026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (9.02ms)7922026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (5.48ms)7932026-10-01 08:26:41.576 UTC [648] ERROR: relation "goose_db_version" does not exist at character 367942026-10-01 08:26:41.576 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7952026-10-01 08:26:41.582 UTC [649] ERROR: relation "goose_db_version" does not exist at character 367962026-10-01 08:26:41.582 UTC [649] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026-10-01 08:26:41.583 UTC [650] ERROR: relation "goose_db_version" does not exist at character 367982026-10-01 08:26:41.583 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-10-01 08:26:41.589 UTC [651] ERROR: relation "goose_db_version" does not exist at character 368002026-10-01 08:26:41.589 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026/10/01 08:26:41 OK 20260905000000_add_claims.sql (18.34ms)8022026/10/01 08:26:41 OK 20251218171726_add_pins.sql (21.34ms)8032026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (5.77ms)8042026-10-01 08:26:41.601 UTC [652] ERROR: relation "goose_db_version" does not exist at character 368052026-10-01 08:26:41.601 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8062026-10-01 08:26:41.605 UTC [653] ERROR: relation "goose_db_version" does not exist at character 368072026-10-01 08:26:41.605 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8082026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (8.15ms)8092026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200008102026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (13.13ms)8112026-10-01 08:26:41.609 UTC [654] ERROR: relation "goose_db_version" does not exist at character 368122026-10-01 08:26:41.609 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8132026/10/01 08:26:41 OK 20241026095416_initial_model.sql (18.35ms)8142026-10-01 08:26:41.613 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368152026-10-01 08:26:41.613 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/10/01 08:26:41 OK 1_commit_pending_closure.sql (8.72ms)8172026/10/01 08:26:41 OK 20260905000000_add_claims.sql (8.36ms)8182026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (3.94ms)8192026/10/01 08:26:41 OK 2_object_stats_trigger.sql (2.84ms)8202026/10/01 08:26:41 OK 20241026095416_initial_model.sql (12.31ms)8212026/10/01 08:26:41 OK 20241026095416_initial_model.sql (20.31ms)8222026/10/01 08:26:41 OK 3_commit_push.sql (2.75ms)8232026/10/01 08:26:41 goose: up to current file version: 38242026/10/01 08:26:41 OK 20241026095416_initial_model.sql (12.71ms)8252026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (4.03ms)8262026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (5.38ms)8272026/10/01 08:26:41 OK 20251218171726_add_pins.sql (6.51ms)8282026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (3.92ms)8292026/10/01 08:26:41 OK 20241026095416_initial_model.sql (17.3ms)8302026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (3.64ms)8312026-10-01 08:26:41.637 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368322026-10-01 08:26:41.637 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (13.54ms)8342026/10/01 08:26:41 OK 20251218171726_add_pins.sql (18.78ms)8352026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (18.82ms)8362026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200008372026/10/01 08:26:41 OK 20241026095416_initial_model.sql (31.04ms)8382026/10/01 08:26:41 OK 20241026095416_initial_model.sql (24.87ms)8392026/10/01 08:26:41 OK 20251218171726_add_pins.sql (17.57ms)8402026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (17.71ms)8412026/10/01 08:26:41 OK 20251218171726_add_pins.sql (16.16ms)8422026/10/01 08:26:41 OK 20241026095416_initial_model.sql (22.93ms)8432026/10/01 08:26:41 OK 20241026095416_initial_model.sql (21.49ms)8442026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)8452026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (3.24ms)8462026/10/01 08:26:41 OK 20241026095416_initial_model.sql (20.37ms)8472026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (3.91ms)8482026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures8492026/10/01 08:26:41 OK 20260905000000_add_claims.sql (5.59ms)8502026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (6.51ms)8512026/10/01 08:26:41 OK 1_commit_pending_closure.sql (6.13ms)8522026/10/01 08:26:41 OK 20251218171726_add_pins.sql (10.27ms)8532026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (4.06ms)8542026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)8552026/10/01 08:26:41 OK 20251218171726_add_pins.sql (5.12ms)8562026/10/01 08:26:41 OK 20251218171726_add_pins.sql (5.07ms)8572026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (8.38ms)8582026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (8.01ms)8592026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3.18ms)8602026/10/01 08:26:41 OK 2_object_stats_trigger.sql (3.61ms)8612026-10-01 08:26:41.653 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368622026-10-01 08:26:41.653 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8632026/10/01 08:26:41 OK 20260905000000_add_claims.sql (5.27ms)8642026/10/01 08:26:41 OK 20251218171726_add_pins.sql (6.05ms)8652026/10/01 08:26:41 OK 3_commit_push.sql (2.57ms)8662026/10/01 08:26:41 goose: up to current file version: 38672026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (3.35ms)8682026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200008692026/10/01 08:26:41 OK 20251218171726_add_pins.sql (4.91ms)8702026-10-01 08:26:41.656 UTC [657] ERROR: relation "goose_db_version" does not exist at character 368712026-10-01 08:26:41.656 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8722026/10/01 08:26:41 OK 20251218171726_add_pins.sql (7.68ms)8732026/10/01 08:26:41 OK 20260905000000_add_claims.sql (4.43ms)8742026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)8752026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (6.95ms)8762026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (5.37ms)8772026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.67ms)8782026/10/01 08:26:41 OK 20260905000000_add_claims.sql (6.19ms)8792026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3.24ms)8802026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.89ms)8812026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200008822026/10/01 08:26:41 OK 20260905000000_add_claims.sql (3.44ms)8832026/10/01 08:26:41 OK 1_commit_pending_closure.sql (4.01ms)8842026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)8852026/10/01 08:26:41 OK 20241026095416_initial_model.sql (12.66ms)8862026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)8872026/10/01 08:26:41 OK 20260905000000_add_claims.sql (4.21ms)8882026/10/01 08:26:41 OK 20260905000000_add_claims.sql (4.55ms)8892026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.43ms)8902026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200008912026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (4.44ms)8922026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (6.12ms)8932026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.65ms)8942026/10/01 08:26:41 OK 2_object_stats_trigger.sql (3.06ms)8952026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.96ms)8962026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.78ms)8972026/10/01 08:26:41 OK 20260905000000_add_claims.sql (4.13ms)8982026/10/01 08:26:41 OK 1_commit_pending_closure.sql (4.03ms)8992026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3.88ms)9002026/10/01 08:26:41 OK 1_commit_pending_closure.sql (3.08ms)9012026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.84ms)9022026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200009032026/10/01 08:26:41 OK 3_commit_push.sql (2.38ms)9042026/10/01 08:26:41 goose: up to current file version: 39052026/10/01 08:26:41 OK 20260905000000_add_claims.sql (4.59ms)9062026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (4.17ms)9072026-10-01 08:26:41.667 UTC [659] ERROR: relation "goose_db_version" does not exist at character 369082026-10-01 08:26:41.667 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9092026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200009102026/10/01 08:26:41 OK 2_object_stats_trigger.sql (2.17ms)9112026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.44ms)9122026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200009132026/10/01 08:26:41 OK 20260905000000_add_claims.sql (4.14ms)9142026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.83ms)9152026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.85ms)9162026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.54ms)9172026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200009182026/10/01 08:26:41 OK 20251218171726_add_pins.sql (4.14ms)9192026/10/01 08:26:41 OK 3_commit_push.sql (1.28ms)9202026/10/01 08:26:41 goose: up to current file version: 39212026-10-01 08:26:41.669 UTC [662] ERROR: relation "goose_db_version" does not exist at character 369222026-10-01 08:26:41.669 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9232026-10-01 08:26:41.669 UTC [661] ERROR: relation "goose_db_version" does not exist at character 369242026-10-01 08:26:41.669 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9252026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.28ms)9262026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200009272026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3.39ms)9282026/10/01 08:26:41 OK 3_commit_push.sql (1.99ms)9292026/10/01 08:26:41 goose: up to current file version: 39302026/10/01 08:26:41 OK 1_commit_pending_closure.sql (3.74ms)9312026-10-01 08:26:41.670 UTC [663] ERROR: relation "goose_db_version" does not exist at character 369322026-10-01 08:26:41.670 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9332026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3.18ms)9342026/10/01 08:26:41 OK 1_commit_pending_closure.sql (3.41ms)9352026/10/01 08:26:41 OK 20241026095416_initial_model.sql (10.22ms)9362026/10/01 08:26:41 OK 1_commit_pending_closure.sql (3.66ms)9372026/10/01 08:26:41 OK 1_commit_pending_closure.sql (4.84ms)9382026/10/01 08:26:41 OK 1_commit_pending_closure.sql (2.44ms)9392026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.35ms)9402026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200009412026-10-01 08:26:41.673 UTC [664] ERROR: relation "goose_db_version" does not exist at character 369422026-10-01 08:26:41.673 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9432026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.6ms)9442026/10/01 08:26:41 OK 2_object_stats_trigger.sql (2.15ms)9452026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)9462026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)9472026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.55ms)9482026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200009492026-10-01 08:26:41.674 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369502026-10-01 08:26:41.674 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9512026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.67ms)9522026/10/01 08:26:41 OK 2_object_stats_trigger.sql (2.28ms)9532026/10/01 08:26:41 OK 2_object_stats_trigger.sql (2.42ms)9542026/10/01 08:26:41 OK 1_commit_pending_closure.sql (2.62ms)9552026/10/01 08:26:41 OK 3_commit_push.sql (2.46ms)9562026/10/01 08:26:41 goose: up to current file version: 39572026/10/01 08:26:41 OK 3_commit_push.sql (2.38ms)9582026/10/01 08:26:41 goose: up to current file version: 39592026/10/01 08:26:41 OK 3_commit_push.sql (1.93ms)9602026/10/01 08:26:41 goose: up to current file version: 39612026/10/01 08:26:41 OK 3_commit_push.sql (1.95ms)9622026/10/01 08:26:41 goose: up to current file version: 39632026/10/01 08:26:41 OK 20260905000000_add_claims.sql (3.34ms)9642026/10/01 08:26:41 OK 20251218171726_add_pins.sql (3.29ms)9652026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.21ms)9662026/10/01 08:26:41 OK 3_commit_push.sql (1.83ms)9672026/10/01 08:26:41 goose: up to current file version: 39682026/10/01 08:26:41 OK 1_commit_pending_closure.sql (3.22ms)9692026-10-01 08:26:41.677 UTC [666] ERROR: relation "goose_db_version" does not exist at character 369702026-10-01 08:26:41.677 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9712026-10-01 08:26:41.677 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369722026-10-01 08:26:41.677 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9732026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3.29ms)9742026/10/01 08:26:41 OK 2_object_stats_trigger.sql (2.79ms)9752026/10/01 08:26:41 OK 3_commit_push.sql (3.06ms)9762026/10/01 08:26:41 goose: up to current file version: 39772026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)9782026/10/01 08:26:41 OK 3_commit_push.sql (1.5ms)9792026/10/01 08:26:41 OK 20241026095416_initial_model.sql (12.43ms)9802026/10/01 08:26:41 goose: up to current file version: 39812026/10/01 08:26:41 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"982--- PASS: TestService_AuthMiddleware (0.57s)983=== CONT TestReadProxyConditionalGet9842026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.61ms)9852026/10/01 08:26:41 goose: successfully migrated database to version: 202609231200009862026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)9872026/10/01 08:26:41 OK 20260905000000_add_claims.sql (4.27ms)9882026/10/01 08:26:41 OK 1_commit_pending_closure.sql (3.05ms)9892026/10/01 08:26:41 OK 20241026095416_initial_model.sql (10.26ms)9902026/10/01 08:26:41 OK 20241026095416_initial_model.sql (11.36ms)9912026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.73ms)9922026/10/01 08:26:41 OK 20251218171726_add_pins.sql (3.46ms)9932026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3.24ms)9942026-10-01 08:26:41.688 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369952026-10-01 08:26:41.688 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9962026/10/01 08:26:41 OK 20241026095416_initial_model.sql (11.52ms)9972026/10/01 08:26:41 OK 3_commit_push.sql (1.56ms)9982026/10/01 08:26:41 goose: up to current file version: 39992026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)10002026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)10012026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)10022026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (3.04ms)10032026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000010042026/10/01 08:26:41 OK 20241026095416_initial_model.sql (11.33ms)10052026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)10062026/10/01 08:26:41 OK 20241026095416_initial_model.sql (9.53ms)10072026/10/01 08:26:41 OK 20241026095416_initial_model.sql (10.35ms)10082026/10/01 08:26:41 OK 20251218171726_add_pins.sql (3.27ms)10092026/10/01 08:26:41 OK 20251218171726_add_pins.sql (3.45ms)10102026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)10112026/10/01 08:26:41 OK 1_commit_pending_closure.sql (3.09ms)10122026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)10132026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)10142026/10/01 08:26:41 OK 20251218171726_add_pins.sql (4.36ms)10152026/10/01 08:26:41 OK 20260905000000_add_claims.sql (3.12ms)10162026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.31ms)10172026/10/01 08:26:41 OK 20241026095416_initial_model.sql (10.81ms)10182026/10/01 08:26:41 OK 20251218171726_add_pins.sql (3.57ms)10192026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (4.3ms)10202026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)10212026/10/01 08:26:41 OK 20241026095416_initial_model.sql (11.93ms)10222026/10/01 08:26:41 OK 3_commit_push.sql (1.83ms)10232026/10/01 08:26:41 goose: up to current file version: 310242026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (1.95ms)10252026/10/01 08:26:41 OK 20251218171726_add_pins.sql (3.39ms)10262026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3.17ms)10272026/10/01 08:26:41 OK 20251218171726_add_pins.sql (4ms)10282026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (4.85ms)10292026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)10302026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.42ms)10312026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000010322026/10/01 08:26:41 OK 20260905000000_add_claims.sql (3.81ms)10332026/10/01 08:26:41 OK 20260905000000_add_claims.sql (3.75ms)10342026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (4.47ms)10352026/10/01 08:26:41 OK 20251218171726_add_pins.sql (3.54ms)10362026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)10372026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (4.34ms)10382026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.6ms)10392026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.78ms)10402026/10/01 08:26:41 OK 1_commit_pending_closure.sql (3.22ms)10412026/10/01 08:26:41 OK 20251218171726_add_pins.sql (4.4ms)10422026/10/01 08:26:41 OK 20260905000000_add_claims.sql (4.56ms)10432026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures10442026/10/01 08:26:41 OK 20241026095416_initial_model.sql (9.28ms)10452026/10/01 08:26:41 OK 20260905000000_add_claims.sql (2.61ms)10462026/10/01 08:26:41 OK 20260905000000_add_claims.sql (3.19ms)10472026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)10482026/10/01 08:26:41 OK 2_object_stats_trigger.sql (2.14ms)10492026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.65ms)10502026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000010512026/10/01 08:26:41 OK 20260905000000_add_claims.sql (3.15ms)10522026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.59ms)10532026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000010542026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)10552026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.66ms)10562026/10/01 08:26:41 OK 3_commit_push.sql (1.11ms)10572026/10/01 08:26:41 goose: up to current file version: 310582026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3.04ms)10592026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.97ms)10602026/10/01 08:26:41 OK 20260905000000_add_claims.sql (2.63ms)10612026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (1.78ms)10622026/10/01 08:26:41 OK 1_commit_pending_closure.sql (1.86ms)10632026/10/01 08:26:41 OK 1_commit_pending_closure.sql (1.88ms)10642026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.06ms)10652026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000010662026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (5.03ms)10672026/10/01 08:26:41 OK 20251218171726_add_pins.sql (2.95ms)10682026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.09ms)10692026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000010702026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.22ms)10712026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000010722026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.81ms)10732026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000010742026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.85ms)10752026/10/01 08:26:41 OK 2_object_stats_trigger.sql (2.18ms)10762026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3ms)10772026/10/01 08:26:41 OK 1_commit_pending_closure.sql (2.15ms)10782026/10/01 08:26:41 OK 1_commit_pending_closure.sql (2.46ms)10792026/10/01 08:26:41 OK 3_commit_push.sql (2.47ms)10802026/10/01 08:26:41 OK 20260905000000_add_claims.sql (4.46ms)10812026/10/01 08:26:41 OK 3_commit_push.sql (2.57ms)10822026/10/01 08:26:41 goose: up to current file version: 310832026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.34ms)10842026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000010852026/10/01 08:26:41 OK 1_commit_pending_closure.sql (2.97ms)10862026/10/01 08:26:41 OK 1_commit_pending_closure.sql (2.8ms)10872026/10/01 08:26:41 goose: up to current file version: 310882026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)10892026/10/01 08:26:41 OK 2_object_stats_trigger.sql (2.29ms)10902026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.96ms)10912026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.1ms)10922026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.17ms)10932026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (1.88ms)10942026/10/01 08:26:41 OK 3_commit_push.sql (983.28µs)10952026/10/01 08:26:41 goose: up to current file version: 310962026/10/01 08:26:41 OK 3_commit_push.sql (929.15µs)10972026/10/01 08:26:41 OK 1_commit_pending_closure.sql (1.92ms)10982026/10/01 08:26:41 goose: up to current file version: 310992026/10/01 08:26:41 OK 3_commit_push.sql (857.46µs)11002026/10/01 08:26:41 goose: up to current file version: 311012026/10/01 08:26:41 OK 3_commit_push.sql (934.96µs)11022026/10/01 08:26:41 goose: up to current file version: 311032026/10/01 08:26:41 OK 20260905000000_add_claims.sql (2.14ms)11042026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (1.32ms)11052026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000011062026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.11ms)11072026/10/01 08:26:41 OK 3_commit_push.sql (651.05µs)11082026/10/01 08:26:41 goose: up to current file version: 311092026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (1.48ms)11102026/10/01 08:26:41 OK 1_commit_pending_closure.sql (1.73ms)11112026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (1.41ms)11122026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000011132026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.06ms)11142026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures11152026/10/01 08:26:41 OK 3_commit_push.sql (896.63µs)11162026/10/01 08:26:41 goose: up to current file version: 311172026/10/01 08:26:41 OK 1_commit_pending_closure.sql (1.43ms)11182026/10/01 08:26:41 OK 2_object_stats_trigger.sql (748.54µs)11192026/10/01 08:26:41 OK 3_commit_push.sql (1.25ms)11202026/10/01 08:26:41 goose: up to current file version: 311212026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures11222026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures11232026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures1124--- PASS: TestService_Rustfstest (0.64s)1125=== CONT TestReadProxyHead11262026/10/01 08:26:41 INFO Received cleanup request method=DELETE path=/api/pending_closures11272026-10-01 08:26:41.784 UTC [673] ERROR: relation "goose_db_version" does not exist at character 3611282026-10-01 08:26:41.784 UTC [673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11292026/10/01 08:26:41 INFO Aborted multipart uploads count=011302026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures11312026/10/01 08:26:41 INFO Received cleanup request method=DELETE path=/api/pending_closures11322026/10/01 08:26:41 OK 20241026095416_initial_model.sql (8.05ms)11332026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (1.1ms)11342026/10/01 08:26:41 INFO Aborted multipart uploads count=111352026/10/01 08:26:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11362026/10/01 08:26:41 OK 20251218171726_add_pins.sql (2.69ms)11372026/10/01 08:26:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11382026-10-01 08:26:41.812 UTC [651] ERROR: Closure does not exist: id=111392026-10-01 08:26:41.812 UTC [651] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE11402026-10-01 08:26:41.812 UTC [651] STATEMENT: -- name: CommitPendingClosure :exec1141 SELECT commit_pending_closure($1::bigint)1142 1143--- PASS: TestService_cleanupPendingClosuresHandler (0.70s)1144=== CONT TestReadProxyInvalidPath11452026/10/01 08:26:41 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1146--- PASS: TestCompleteMultipartUnregistered (0.70s)1147=== CONT TestReadProxy40411482026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)11492026/10/01 08:26:41 OK 20260905000000_add_claims.sql (2.91ms)11502026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.05ms)11512026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (1.93ms)11522026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000011532026/10/01 08:26:41 OK 1_commit_pending_closure.sql (2.15ms)11542026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.35ms)11552026/10/01 08:26:41 OK 3_commit_push.sql (1.77ms)11562026/10/01 08:26:41 goose: up to current file version: 311572026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures11582026-10-01 08:26:41.849 UTC [678] ERROR: relation "goose_db_version" does not exist at character 3611592026-10-01 08:26:41.849 UTC [678] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1160--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.74s)1161=== CONT TestGCSweepSkipsPendingObjects11622026/10/01 08:26:41 INFO Received push request method=POST path=/api/pushes11632026/10/01 08:26:41 OK 20241026095416_initial_model.sql (10.45ms)11642026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)11652026/10/01 08:26:41 OK 20251218171726_add_pins.sql (4.83ms)11662026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)11672026/10/01 08:26:41 OK 20260905000000_add_claims.sql (4.38ms)1168--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.77s)1169=== CONT TestGenerateLandingPage11702026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (3.09ms)1171--- PASS: TestGenerateLandingPage (0.00s)1172=== CONT TestService_readinessHandler11732026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.32ms)11742026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000011752026/10/01 08:26:41 OK 1_commit_pending_closure.sql (2.4ms)11762026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.68ms)11772026/10/01 08:26:41 OK 3_commit_push.sql (1.07ms)11782026/10/01 08:26:41 goose: up to current file version: 31179--- PASS: TestReadProxyNarStreaming (0.78s)1180=== CONT TestService_healthCheckHandler11812026-10-01 08:26:41.905 UTC [689] ERROR: relation "goose_db_version" does not exist at character 3611822026-10-01 08:26:41.905 UTC [689] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11832026-10-01 08:26:41.907 UTC [690] ERROR: relation "goose_db_version" does not exist at character 3611842026-10-01 08:26:41.907 UTC [690] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11852026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures11862026/10/01 08:26:41 OK 20241026095416_initial_model.sql (9.5ms)11872026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)11882026/10/01 08:26:41 OK 20241026095416_initial_model.sql (9.42ms)11892026/10/01 08:26:41 OK 20251218171726_add_pins.sql (2.34ms)11902026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)11912026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures11922026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (2.78ms)11932026/10/01 08:26:41 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11942026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures11952026/10/01 08:26:41 OK 20251218171726_add_pins.sql (3.13ms)11962026/10/01 08:26:41 OK 20260905000000_add_claims.sql (3.37ms)1197--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.82s)1198=== CONT TestGracefulShutdownDrainsInflight11992026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)12002026/10/01 08:26:41 INFO Starting HTTP server address=127.0.0.1:3913312012026/10/01 08:26:41 INFO Shutdown signal received, draining in-flight requests timeout=10s12022026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.23ms)12032026-10-01 08:26:41.942 UTC [691] ERROR: relation "goose_db_version" does not exist at character 3612042026-10-01 08:26:41.942 UTC [691] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12052026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.34ms)12062026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000012072026/10/01 08:26:41 OK 20260905000000_add_claims.sql (3.82ms)12082026/10/01 08:26:41 OK 1_commit_pending_closure.sql (2.48ms)12092026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.25ms)12102026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.37ms)12112026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (2.06ms)12122026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000012132026/10/01 08:26:41 OK 3_commit_push.sql (2.16ms)12142026/10/01 08:26:41 goose: up to current file version: 312152026/10/01 08:26:41 OK 1_commit_pending_closure.sql (1.98ms)12162026/10/01 08:26:41 OK 2_object_stats_trigger.sql (1.92ms)12172026/10/01 08:26:41 OK 3_commit_push.sql (1.34ms)12182026/10/01 08:26:41 goose: up to current file version: 312192026/10/01 08:26:41 OK 20241026095416_initial_model.sql (9.35ms)12202026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)12212026/10/01 08:26:41 INFO Received uploads request method=POST path=/api/pending_closures12222026/10/01 08:26:41 OK 20251218171726_add_pins.sql (3.76ms)12232026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)12242026/10/01 08:26:41 OK 20260905000000_add_claims.sql (3.03ms)12252026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (2.02ms)12262026/10/01 08:26:41 OK 20260923120000_add_pushes.sql (1.87ms)12272026/10/01 08:26:41 goose: successfully migrated database to version: 2026092312000012282026-10-01 08:26:41.976 UTC [692] ERROR: relation "goose_db_version" does not exist at character 3612292026-10-01 08:26:41.976 UTC [692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12302026/10/01 08:26:41 OK 1_commit_pending_closure.sql (2.37ms)12312026/10/01 08:26:41 OK 2_object_stats_trigger.sql (3.83ms)12322026/10/01 08:26:41 OK 3_commit_push.sql (1.29ms)12332026/10/01 08:26:41 goose: up to current file version: 31234=== RUN TestPush_RejectsBadRequests/no_roots1235=== PAUSE TestPush_RejectsBadRequests/no_roots1236=== RUN TestPush_RejectsBadRequests/no_objects1237=== PAUSE TestPush_RejectsBadRequests/no_objects1238=== RUN TestPush_RejectsBadRequests/bad_root12392026/10/01 08:26:41 OK 20241026095416_initial_model.sql (7.1ms)1240=== PAUSE TestPush_RejectsBadRequests/bad_root1241=== RUN TestPush_RejectsBadRequests/root_not_in_objects1242=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1243=== CONT TestGCTaskStore_Fail1244--- PASS: TestGCTaskStore_Fail (0.00s)1245=== CONT TestGCTaskStore_PhaseUpdates1246--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1247=== CONT TestGCTaskStore_CompletedAllowsNewTask1248--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1249=== CONT TestGCTaskStore_GetReturnsLatest1250--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1251=== CONT TestGCTaskStore_GetEmpty1252--- PASS: TestGCTaskStore_GetEmpty (0.00s)1253=== CONT TestGCTaskStore_ConflictDifferentParams1254--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1255=== CONT TestGCTaskStore_DeduplicateSameParams1256--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1257=== CONT TestGCTaskStore_StartNew1258--- PASS: TestGCTaskStore_StartNew (0.00s)1259=== CONT TestCommitRacingPendingCleanupKeepsObjects12602026/10/01 08:26:41 OK 20251210153512_drop_unused_gin_index.sql (1.05ms)12612026/10/01 08:26:41 OK 20251218171726_add_pins.sql (2.17ms)12622026/10/01 08:26:41 OK 20260628120000_add_object_size_and_stats.sql (2.35ms)12632026-10-01 08:26:41.997 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3612642026-10-01 08:26:41.997 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12652026/10/01 08:26:41 OK 20260905000000_add_claims.sql (2.06ms)12662026/10/01 08:26:41 OK 20260920000000_drop_claims.sql (1.47ms)12672026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.3ms)12682026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000012692026/10/01 08:26:42 OK 1_commit_pending_closure.sql (1.4ms)12702026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.73ms)12712026/10/01 08:26:42 OK 3_commit_push.sql (1.23ms)12722026/10/01 08:26:42 goose: up to current file version: 312732026/10/01 08:26:42 OK 20241026095416_initial_model.sql (7.25ms)12742026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)12752026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.28ms)1276--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1277=== CONT TestPushWaitsForSweepHoldingRow12782026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (2.89ms)12792026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.03ms)12802026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (3.36ms)12812026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.11ms)12822026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000012832026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.23ms)12842026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.4ms)12852026/10/01 08:26:42 OK 3_commit_push.sql (1.43ms)12862026/10/01 08:26:42 goose: up to current file version: 31287--- PASS: TestReadRedirectUsesPublicS3URL (0.91s)1288=== CONT TestSweepRechecksPendingAfterLocking1289--- PASS: TestReadProxyRangeRequest (0.86s)1290=== CONT TestGetExistingObjectsLocksRows12912026/10/01 08:26:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12922026/10/01 08:26:42 INFO Received push request method=POST path=/api/pushes12932026/10/01 08:26:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12942026/10/01 08:26:42 INFO Signed narinfos id=1 count=11295--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.89s)1296=== CONT TestRegisterCompletedObjectNeedsPendingRow12972026-10-01 08:26:42.095 UTC [703] ERROR: relation "goose_db_version" does not exist at character 3612982026-10-01 08:26:42.095 UTC [703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1299--- PASS: TestReadProxyDisabled (0.90s)1300=== CONT TestSweepSkipsRowsLockedByPush13012026/10/01 08:26:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13022026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.92ms)13032026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)13042026-10-01 08:26:42.117 UTC [708] ERROR: relation "goose_db_version" does not exist at character 3613052026-10-01 08:26:42.117 UTC [708] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13062026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.18ms)13072026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)13082026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.09ms)13092026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.57ms)13102026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (3.12ms)13112026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000013122026/10/01 08:26:42 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Nzk5MDE2ZTEtM2IyNS00NGQ5LWI0NjUtMDExNTA4MDIwZTk5LmVlODE1ZjkwLWM2Y2QtNGVlMC04NzdhLWNkZDExNDhiZjI5NXgxNzkwODQzMjAxNjYyMTkwMjQy parts=1013132026/10/01 08:26:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13142026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.57ms)13152026/10/01 08:26:42 OK 20241026095416_initial_model.sql (10.87ms)13162026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.95ms)1317--- PASS: TestReadRedirectNar (0.94s)1318=== CONT TestFailedS3DeleteKeepsTombstone13192026-10-01 08:26:42.138 UTC [722] ERROR: relation "goose_db_version" does not exist at character 3613202026-10-01 08:26:42.138 UTC [722] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13212026/10/01 08:26:42 INFO Completed upload id=113222026/10/01 08:26:42 OK 3_commit_push.sql (1.64ms)13232026/10/01 08:26:42 goose: up to current file version: 313242026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)13252026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures13262026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.66ms)13272026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures13282026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)13292026/10/01 08:26:42 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13302026/10/01 08:26:42 WARN Found objects in DB but missing from S3, will re-upload count=11331--- PASS: TestService_verifyS3Integrity (1.03s)1332=== CONT TestForceGCDuringPushOffersSweptObject1333=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1334=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1335=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1336=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1337=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection13382026/10/01 08:26:42 OK 20260905000000_add_claims.sql (4.27ms)13392026-10-01 08:26:42.159 UTC [726] ERROR: relation "goose_db_version" does not exist at character 3613402026-10-01 08:26:42.159 UTC [726] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13412026/10/01 08:26:42 OK 20241026095416_initial_model.sql (17.33ms)1342--- PASS: TestReadRedirectKeepsNarinfoProxied (0.97s)1343=== CONT TestGCSweepDeliversEachKeyOnce13442026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (14.57ms)13452026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (5.58ms)13462026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (3.35ms)13472026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000013482026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.53ms)13492026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.55ms)13502026/10/01 08:26:42 OK 2_object_stats_trigger.sql (3.33ms)13512026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (5.2ms)13522026/10/01 08:26:42 OK 3_commit_push.sql (2.65ms)13532026/10/01 08:26:42 goose: up to current file version: 313542026/10/01 08:26:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13552026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.52ms)13562026/10/01 08:26:42 OK 20241026095416_initial_model.sql (12.39ms)13572026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)13582026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures13592026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (4.17ms)13602026/10/01 08:26:42 OK 20251218171726_add_pins.sql (4.58ms)13612026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (3.83ms)13622026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000013632026/10/01 08:26:42 OK 1_commit_pending_closure.sql (3.18ms)13642026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (5.85ms)13652026/10/01 08:26:42 OK 2_object_stats_trigger.sql (2.46ms)13662026/10/01 08:26:42 OK 3_commit_push.sql (1.33ms)13672026/10/01 08:26:42 goose: up to current file version: 313682026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.41ms)13692026-10-01 08:26:42.196 UTC [730] ERROR: relation "goose_db_version" does not exist at character 3613702026-10-01 08:26:42.196 UTC [730] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13712026/10/01 08:26:42 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Nzk5MDE2ZTEtM2IyNS00NGQ5LWI0NjUtMDExNTA4MDIwZTk5LjQ3YjFmNGU3LTk0NWItNDg5NS05MzQ0LTcxNjE0ZGMwMDdjYXgxNzkwODQzMjAxNzQzNjAwOTE3 parts=1013722026/10/01 08:26:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13732026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (4.36ms)13742026-10-01 08:26:42.201 UTC [731] ERROR: relation "goose_db_version" does not exist at character 3613752026-10-01 08:26:42.201 UTC [731] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13762026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (3.47ms)13772026/10/01 08:26:42 INFO Completed upload id=113782026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000013792026/10/01 08:26:42 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013802026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures13812026/10/01 08:26:42 OK 1_commit_pending_closure.sql (3.38ms)13822026/10/01 08:26:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures13832026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.97ms)13842026/10/01 08:26:42 OK 3_commit_push.sql (1.64ms)13852026/10/01 08:26:42 goose: up to current file version: 313862026/10/01 08:26:42 INFO Received push request method=POST path=/api/pushes13872026/10/01 08:26:42 OK 20241026095416_initial_model.sql (9.48ms)13882026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)13892026/10/01 08:26:42 OK 20241026095416_initial_model.sql (10.31ms)13902026/10/01 08:26:42 INFO Aborted multipart uploads count=013912026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.45ms)13922026/10/01 08:26:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13932026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.8ms)13942026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)13952026/10/01 08:26:42 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=013962026/10/01 08:26:42 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Nzk5MDE2ZTEtM2IyNS00NGQ5LWI0NjUtMDExNTA4MDIwZTk5LjRlNjc2MmYxLTYzZDQtNGM0Yi05YzQxLTkwODEzYzZjZmFiNHgxNzkwODQzMjAyMTkzMTQwMDU513972026/10/01 08:26:42 OK 20251218171726_add_pins.sql (12.6ms)13982026/10/01 08:26:42 OK 20260905000000_add_claims.sql (13.59ms)13992026/10/01 08:26:42 INFO Vacuumed table table=pending_closures14002026/10/01 08:26:42 INFO Received complete push request method=POST path=/api/pushes/1/complete14012026/10/01 08:26:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Nzk5MDE2ZTEtM2IyNS00NGQ5LWI0NjUtMDExNTA4MDIwZTk5LjRlNjc2MmYxLTYzZDQtNGM0Yi05YzQxLTkwODEzYzZjZmFiNHgxNzkwODQzMjAyMTkzMTQwMDU5 parts=11402--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.04s)1403=== CONT TestTombstonedObjectOfferedWithoutWaiting14042026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.13ms)14052026/10/01 08:26:42 INFO Vacuumed table table=pending_objects14062026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)14072026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2ms)14082026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000014092026-10-01 08:26:42.242 UTC [735] ERROR: relation "goose_db_version" does not exist at character 3614102026-10-01 08:26:42.242 UTC [735] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14112026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads14122026/10/01 08:26:42 INFO Received push request method=POST path=/api/pushes14132026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.18ms)14142026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.2ms)14152026/10/01 08:26:42 INFO Vacuumed table table=closures14162026/10/01 08:26:42 OK 2_object_stats_trigger.sql (971.35µs)14172026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (1.8ms)14182026/10/01 08:26:42 OK 3_commit_push.sql (1.27ms)14192026/10/01 08:26:42 goose: up to current file version: 314202026/10/01 08:26:42 INFO Vacuumed table table=objects1421--- PASS: TestPush_CompleteCommitsEveryRoot (1.05s)1422=== CONT TestClientWithDependencies14232026-10-01 08:26:42.248 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3614242026-10-01 08:26:42.248 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14252026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.26ms)14262026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000014272026/10/01 08:26:42 OK 1_commit_pending_closure.sql (1.68ms)14282026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.63ms)14292026-10-01 08:26:42.253 UTC [739] ERROR: relation "goose_db_version" does not exist at character 3614302026-10-01 08:26:42.253 UTC [739] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14312026/10/01 08:26:42 OK 3_commit_push.sql (1.75ms)14322026/10/01 08:26:42 goose: up to current file version: 314332026/10/01 08:26:42 OK 20241026095416_initial_model.sql (7.8ms)14342026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)14352026/10/01 08:26:42 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014362026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.93ms)1437--- PASS: TestService_createPendingClosureHandler (1.14s)1438=== CONT TestDeduplicatedObjectsRecordedAsPending14392026/10/01 08:26:42 OK 20241026095416_initial_model.sql (9.75ms)14402026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)14412026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)14422026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.41ms)14432026/10/01 08:26:42 OK 20260905000000_add_claims.sql (4.32ms)14442026/10/01 08:26:42 OK 20251218171726_add_pins.sql (4.11ms)14452026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (2.95ms)14462026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (3.39ms)14472026/10/01 08:26:42 INFO Received complete push request method=POST path=/api/pushes/1/complete14482026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.8ms)14492026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)14502026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (3.07ms)14512026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000014522026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.81ms)14532026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.5ms)14542026/10/01 08:26:42 OK 1_commit_pending_closure.sql (3.28ms)14552026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.67ms)14562026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.98ms)14572026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.91ms)1458--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.02s)1459=== CONT TestPushDedupSurvivesConcurrentGC14602026/10/01 08:26:42 OK 3_commit_push.sql (1.54ms)14612026/10/01 08:26:42 goose: up to current file version: 314622026/10/01 08:26:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14632026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.98ms)14642026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000014652026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (3.23ms)14662026/10/01 08:26:42 INFO Received push request method=POST path=/api/pushes14672026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.44ms)14682026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (3.21ms)14692026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000014702026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.69ms)14712026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.21ms)14722026/10/01 08:26:42 OK 3_commit_push.sql (1.65ms)14732026/10/01 08:26:42 goose: up to current file version: 314742026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.45ms)14752026/10/01 08:26:42 OK 3_commit_push.sql (1.22ms)14762026/10/01 08:26:42 goose: up to current file version: 314772026/10/01 08:26:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Nzk5MDE2ZTEtM2IyNS00NGQ5LWI0NjUtMDExNTA4MDIwZTk5LjY3NDcxODc5LWUyZDUtNDU2MS05NzA1LTJlOTFkNDA3ZDYzZXgxNzkwODQzMjAxNzE3NDAyMDk4 parts=121478--- PASS: TestRedundantMultipartUpload (1.20s)1479=== CONT TestGCMetrics1480--- PASS: TestReadProxyConditionalGet (0.63s)1481=== CONT TestGCBugBareHashReferences14822026-10-01 08:26:42.339 UTC [751] ERROR: relation "goose_db_version" does not exist at character 3614832026-10-01 08:26:42.339 UTC [751] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14842026/10/01 08:26:42 INFO Aborted multipart uploads count=01485--- PASS: TestReadProxyHead (0.60s)1486=== CONT TestLeadEndsOnShutdown14872026/10/01 08:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period14882026-10-01 08:26:42.374 UTC [754] ERROR: relation "goose_db_version" does not exist at character 3614892026-10-01 08:26:42.374 UTC [754] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14902026/10/01 08:26:42 OK 20241026095416_initial_model.sql (9.42ms)14912026/10/01 08:26:42 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=014922026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)14932026-10-01 08:26:42.385 UTC [755] ERROR: relation "goose_db_version" does not exist at character 3614942026-10-01 08:26:42.385 UTC [755] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14952026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.94ms)14962026/10/01 08:26:42 INFO Vacuumed table table=pending_closures14972026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.76ms)14982026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)1499--- PASS: TestReadProxy404 (0.58s)1500=== CONT TestLeadElectsOneAndHandsOver15012026/10/01 08:26:42 INFO Vacuumed table table=pending_objects15022026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)15032026/10/01 08:26:42 OK 20260905000000_add_claims.sql (2.82ms)15042026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads15052026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.38ms)15062026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.32ms)15072026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.95ms)15082026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000015092026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)15102026/10/01 08:26:42 INFO Vacuumed table table=closures15112026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.24ms)15122026/10/01 08:26:42 OK 20241026095416_initial_model.sql (9.39ms)15132026/10/01 08:26:42 INFO Vacuumed table table=objects15142026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.87ms)15152026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.31ms)15162026/10/01 08:26:42 INFO Received complete push request method=POST path=/api/pushes/2/complete15172026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)15182026/10/01 08:26:42 OK 3_commit_push.sql (1.67ms)15192026/10/01 08:26:42 goose: up to current file version: 315202026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.27ms)1521--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.21s)1522=== CONT TestResolveDBConnectionString15232026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.2ms)15242026/10/01 08:26:42 goose: successfully migrated database to version: 202609231200001525=== RUN TestResolveDBConnectionString/flag_wins15262026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.9ms)1527=== PAUSE TestResolveDBConnectionString/flag_wins1528=== RUN TestResolveDBConnectionString/file_when_flag_empty1529=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1530=== RUN TestResolveDBConnectionString/missing_file_is_an_error1531=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1532=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1533=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1534=== RUN TestResolveDBConnectionString/nothing_configured1535=== PAUSE TestResolveDBConnectionString/nothing_configured1536=== CONT TestClientFallsBackToClosures15372026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.3ms)15382026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.43ms)15392026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (4.79ms)15402026/10/01 08:26:42 OK 3_commit_push.sql (1.63ms)15412026/10/01 08:26:42 goose: up to current file version: 315422026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.37ms)15432026-10-01 08:26:42.416 UTC [759] ERROR: relation "goose_db_version" does not exist at character 3615442026-10-01 08:26:42.416 UTC [759] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15452026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.63ms)1546--- PASS: TestReadProxyInvalidPath (0.61s)1547=== CONT TestClientPushesUseOnePush15482026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.93ms)15492026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000015502026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.13ms)15512026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.24ms)15522026/10/01 08:26:42 OK 3_commit_push.sql (1.32ms)15532026/10/01 08:26:42 goose: up to current file version: 315542026/10/01 08:26:42 OK 20241026095416_initial_model.sql (18ms)15552026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (5.61ms)15562026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures15572026/10/01 08:26:42 OK 20251218171726_add_pins.sql (4.58ms)15582026-10-01 08:26:42.455 UTC [763] ERROR: relation "goose_db_version" does not exist at character 3615592026-10-01 08:26:42.455 UTC [763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15602026-10-01 08:26:42.456 UTC [764] ERROR: relation "goose_db_version" does not exist at character 3615612026-10-01 08:26:42.456 UTC [764] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15622026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (7.27ms)15632026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.99ms)15642026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.05ms)15652026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.08ms)15662026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000015672026/10/01 08:26:42 OK 1_commit_pending_closure.sql (3.24ms)15682026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.8ms)15692026/10/01 08:26:42 OK 2_object_stats_trigger.sql (2.17ms)15702026/10/01 08:26:42 OK 20241026095416_initial_model.sql (9.96ms)15712026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)15722026/10/01 08:26:42 OK 3_commit_push.sql (1.4ms)15732026/10/01 08:26:42 goose: up to current file version: 315742026/10/01 08:26:42 WARN readiness check failed error="closed pool"1575--- PASS: TestService_readinessHandler (0.59s)1576=== CONT TestPinProtectsFromGC15772026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)15782026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.6ms)15792026/10/01 08:26:42 INFO Aborted multipart uploads count=015802026-10-01 08:26:42.479 UTC [766] ERROR: relation "goose_db_version" does not exist at character 3615812026-10-01 08:26:42.479 UTC [766] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15822026/10/01 08:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period15832026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.15ms)15842026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.07ms)15852026/10/01 08:26:42 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=015862026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)15872026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.36ms)15882026/10/01 08:26:42 INFO Vacuumed table table=pending_closures15892026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.41ms)15902026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.42ms)15912026/10/01 08:26:42 INFO Vacuumed table table=pending_objects15922026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads15932026/10/01 08:26:42 INFO Vacuumed table table=closures15942026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.34ms)15952026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000015962026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.59ms)15972026/10/01 08:26:42 INFO Vacuumed table table=objects15982026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.18ms)15992026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000016002026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.73ms)16012026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.65ms)16022026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.02ms)16032026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.98ms)16042026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)16052026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.06ms)16062026/10/01 08:26:42 OK 3_commit_push.sql (1.01ms)16072026/10/01 08:26:42 goose: up to current file version: 316082026/10/01 08:26:42 OK 3_commit_push.sql (1.03ms)16092026/10/01 08:26:42 goose: up to current file version: 316102026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.72ms)1611--- PASS: TestGCSweepSkipsPendingObjects (0.65s)1612=== CONT TestClientSharedPathCommittedMidPush16132026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)16142026/10/01 08:26:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1615--- PASS: TestService_healthCheckHandler (0.61s)1616=== CONT TestCacheConfigHandler1617=== RUN TestCacheConfigHandler/full_config,_no_issuer1618=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1619=== RUN TestCacheConfigHandler/no_cache_url_configured1620=== PAUSE TestCacheConfigHandler/no_cache_url_configured1621=== RUN TestCacheConfigHandler/no_signing_keys1622=== PAUSE TestCacheConfigHandler/no_signing_keys1623=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1624=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1625=== CONT TestClientMultipleUploads16262026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.05ms)16272026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.18ms)16282026-10-01 08:26:42.511 UTC [772] ERROR: relation "goose_db_version" does not exist at character 3616292026-10-01 08:26:42.511 UTC [772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16302026-10-01 08:26:42.514 UTC [774] ERROR: relation "goose_db_version" does not exist at character 3616312026-10-01 08:26:42.514 UTC [774] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16322026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (9.76ms)16332026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000016342026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.33ms)16352026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.74ms)16362026/10/01 08:26:42 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Nzk5MDE2ZTEtM2IyNS00NGQ5LWI0NjUtMDExNTA4MDIwZTk5LjRiNzZiNGU4LTkyZTAtNGQyNi05MGYxLWMyMDA0YWFjOGNlMXgxNzkwODQzMjAxOTQ4MTk4NTg0 parts=1216372026/10/01 08:26:42 OK 3_commit_push.sql (1.77ms)16382026/10/01 08:26:42 goose: up to current file version: 316392026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures16402026/10/01 08:26:42 OK 20241026095416_initial_model.sql (7.95ms)16412026-10-01 08:26:42.527 UTC [775] ERROR: relation "goose_db_version" does not exist at character 3616422026-10-01 08:26:42.527 UTC [775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1643--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.41s)1644=== CONT TestClientCADerivations16452026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.67ms)16462026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)16472026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (2.15ms)16482026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.3ms)16492026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.72ms)16502026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)16512026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)16522026/10/01 08:26:42 OK 20260905000000_add_claims.sql (4.07ms)16532026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.95ms)16542026/10/01 08:26:42 OK 20260905000000_add_claims.sql (4.78ms)16552026/10/01 08:26:42 OK 20241026095416_initial_model.sql (9.64ms)16562026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.04ms)16572026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000016582026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)16592026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (3.09ms)16602026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.22ms)16612026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.85ms)16622026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000016632026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.93ms)16642026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.5ms)16652026/10/01 08:26:42 OK 3_commit_push.sql (2.25ms)16662026/10/01 08:26:42 goose: up to current file version: 316672026/10/01 08:26:42 OK 1_commit_pending_closure.sql (3.28ms)16682026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.47ms)16692026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.53ms)16702026/10/01 08:26:42 OK 3_commit_push.sql (1.34ms)16712026/10/01 08:26:42 goose: up to current file version: 316722026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.07ms)16732026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.39ms)16742026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.26ms)16752026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000016762026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.2ms)16772026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.48ms)16782026/10/01 08:26:42 OK 3_commit_push.sql (1.08ms)16792026/10/01 08:26:42 goose: up to current file version: 316802026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures16812026/10/01 08:26:42 INFO Aborted multipart uploads count=016822026/10/01 08:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period16832026-10-01 08:26:42.573 UTC [781] ERROR: relation "goose_db_version" does not exist at character 3616842026-10-01 08:26:42.573 UTC [781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16852026/10/01 08:26:42 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=016862026/10/01 08:26:42 INFO Vacuumed table table=pending_closures16872026/10/01 08:26:42 INFO Vacuumed table table=pending_objects16882026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads16892026/10/01 08:26:42 INFO Vacuumed table table=closures16902026/10/01 08:26:42 INFO Vacuumed table table=objects16912026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.27ms)16922026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.83ms)16932026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.53ms)1694--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.60s)1695=== CONT TestCacheStatsHandler16962026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)16972026/10/01 08:26:42 INFO Aborted multipart uploads count=016982026/10/01 08:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period16992026-10-01 08:26:42.606 UTC [786] ERROR: relation "goose_db_version" does not exist at character 3617002026-10-01 08:26:42.606 UTC [786] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17012026/10/01 08:26:42 OK 20260905000000_add_claims.sql (10.51ms)17022026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.94ms)17032026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.39ms)17042026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000017052026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.1ms)17062026/10/01 08:26:42 OK 2_object_stats_trigger.sql (604.47µs)17072026/10/01 08:26:42 OK 3_commit_push.sql (748.31µs)17082026/10/01 08:26:42 goose: up to current file version: 317092026-10-01 08:26:42.617 UTC [788] ERROR: relation "goose_db_version" does not exist at character 3617102026-10-01 08:26:42.617 UTC [788] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17112026/10/01 08:26:42 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=017122026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.54ms)17132026-10-01 08:26:42.621 UTC [789] ERROR: relation "goose_db_version" does not exist at character 3617142026-10-01 08:26:42.621 UTC [789] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17152026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)17162026/10/01 08:26:42 INFO Vacuumed table table=pending_closures17172026/10/01 08:26:42 INFO Vacuumed table table=pending_objects17182026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads17192026/10/01 08:26:42 INFO Vacuumed table table=closures17202026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.22ms)17212026/10/01 08:26:42 INFO Vacuumed table table=objects1722--- PASS: TestSweepRechecksPendingAfterLocking (0.59s)17232026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (2.97ms)1724=== CONT TestOrphanedObjectsGC1725--- PASS: TestGetExistingObjectsLocksRows (0.57s)1726=== CONT TestReadProxyNarinfoAlreadyDecompressed17272026/10/01 08:26:42 OK 20260905000000_add_claims.sql (2.89ms)17282026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.53ms)17292026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (3.03ms)17302026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)17312026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.45ms)17322026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.98ms)17332026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000017342026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.29ms)17352026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.56ms)17362026/10/01 08:26:42 OK 1_commit_pending_closure.sql (1.43ms)17372026/10/01 08:26:42 OK 2_object_stats_trigger.sql (780.31µs)17382026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.01ms)1739--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.55s)1740=== CONT TestReadProxyNarinfo17412026/10/01 08:26:42 OK 3_commit_push.sql (2.49ms)17422026/10/01 08:26:42 goose: up to current file version: 317432026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (4.15ms)17442026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)17452026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.24ms)17462026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (1.64ms)17472026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.49ms)17482026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.1ms)17492026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000017502026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (3.01ms)17512026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.27ms)17522026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.98ms)17532026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000017542026/10/01 08:26:42 OK 2_object_stats_trigger.sql (2.01ms)17552026/10/01 08:26:42 OK 3_commit_push.sql (1.16ms)17562026/10/01 08:26:42 goose: up to current file version: 317572026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.73ms)17582026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.65ms)17592026/10/01 08:26:42 OK 3_commit_push.sql (1.53ms)17602026/10/01 08:26:42 goose: up to current file version: 317612026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures17622026/10/01 08:26:42 INFO Aborted multipart uploads count=017632026/10/01 08:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period17642026/10/01 08:26:42 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=017652026-10-01 08:26:42.699 UTC [799] ERROR: relation "goose_db_version" does not exist at character 3617662026-10-01 08:26:42.699 UTC [799] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17672026/10/01 08:26:42 INFO Vacuumed table table=pending_closures17682026/10/01 08:26:42 INFO Vacuumed table table=pending_objects17692026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads17702026/10/01 08:26:42 INFO Vacuumed table table=closures17712026/10/01 08:26:42 INFO Vacuumed table table=objects17722026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures17732026/10/01 08:26:42 INFO Aborted multipart uploads count=017742026/10/01 08:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period17752026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.06ms)17762026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)17772026-10-01 08:26:42.727 UTC [800] ERROR: relation "goose_db_version" does not exist at character 3617782026-10-01 08:26:42.727 UTC [800] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17792026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.2ms)17802026-10-01 08:26:42.729 UTC [801] ERROR: relation "goose_db_version" does not exist at character 3617812026-10-01 08:26:42.729 UTC [801] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17822026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (2.83ms)17832026/10/01 08:26:42 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=017842026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.36ms)17852026/10/01 08:26:42 INFO Vacuumed table table=pending_closures17862026/10/01 08:26:42 INFO Vacuumed table table=pending_objects17872026-10-01 08:26:42.735 UTC [802] ERROR: relation "goose_db_version" does not exist at character 3617882026-10-01 08:26:42.735 UTC [802] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17892026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads17902026/10/01 08:26:42 INFO Vacuumed table table=closures17912026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (1.91ms)17922026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.89ms)17932026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000017942026/10/01 08:26:42 OK 20241026095416_initial_model.sql (7.68ms)17952026/10/01 08:26:42 INFO Vacuumed table table=objects17962026/10/01 08:26:42 OK 1_commit_pending_closure.sql (1.48ms)17972026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)1798--- PASS: TestSweepSkipsRowsLockedByPush (0.64s)1799=== CONT TestIsValidCachePath18002026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.27ms)1801=== RUN TestIsValidCachePath/narinfo1802=== PAUSE TestIsValidCachePath/narinfo1803=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1804=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1805=== RUN TestIsValidCachePath/nar_zst1806=== PAUSE TestIsValidCachePath/nar_zst1807=== RUN TestIsValidCachePath/nar_xz1808=== PAUSE TestIsValidCachePath/nar_xz1809=== RUN TestIsValidCachePath/nar_bz21810=== PAUSE TestIsValidCachePath/nar_bz21811=== RUN TestIsValidCachePath/nar_uncompressed1812=== PAUSE TestIsValidCachePath/nar_uncompressed18132026/10/01 08:26:42 OK 20241026095416_initial_model.sql (7.6ms)1814=== RUN TestIsValidCachePath/ls1815=== PAUSE TestIsValidCachePath/ls1816=== RUN TestIsValidCachePath/log18172026/10/01 08:26:42 OK 3_commit_push.sql (1.12ms)1818=== PAUSE TestIsValidCachePath/log18192026/10/01 08:26:42 goose: up to current file version: 31820=== RUN TestIsValidCachePath/realisation1821=== PAUSE TestIsValidCachePath/realisation18222026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.18ms)1823=== RUN TestIsValidCachePath/nix-cache-info1824=== PAUSE TestIsValidCachePath/nix-cache-info1825=== RUN TestIsValidCachePath/index.html1826=== PAUSE TestIsValidCachePath/index.html1827=== RUN TestIsValidCachePath/traversal_parent1828=== PAUSE TestIsValidCachePath/traversal_parent1829=== RUN TestIsValidCachePath/traversal_in_middle1830=== PAUSE TestIsValidCachePath/traversal_in_middle1831=== RUN TestIsValidCachePath/invalid_char_e1832=== PAUSE TestIsValidCachePath/invalid_char_e1833=== RUN TestIsValidCachePath/invalid_char_u18342026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)1835=== PAUSE TestIsValidCachePath/invalid_char_u1836=== RUN TestIsValidCachePath/random_path1837=== PAUSE TestIsValidCachePath/random_path1838=== RUN TestIsValidCachePath/empty1839=== PAUSE TestIsValidCachePath/empty1840=== RUN TestIsValidCachePath/leading_slash1841=== PAUSE TestIsValidCachePath/leading_slash1842=== RUN TestIsValidCachePath/wrong_extension1843=== PAUSE TestIsValidCachePath/wrong_extension1844=== RUN TestIsValidCachePath/short_hash1845=== PAUSE TestIsValidCachePath/short_hash1846=== CONT TestProxyHeadersOnlyTrustedOnSocket18472026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.07ms)18482026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.36ms)18492026/10/01 08:26:42 OK 20241026095416_initial_model.sql (6.56ms)18502026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (945.31µs)18512026/10/01 08:26:42 OK 20260905000000_add_claims.sql (4.35ms)18522026/10/01 08:26:42 OK 20251218171726_add_pins.sql (3.77ms)18532026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)18542026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (1.53ms)18552026/10/01 08:26:42 OK 20260905000000_add_claims.sql (2.26ms)18562026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (2.59ms)18572026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.49ms)18582026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000018592026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (1.4ms)18602026/10/01 08:26:42 OK 1_commit_pending_closure.sql (1.41ms)18612026/10/01 08:26:42 OK 20260905000000_add_claims.sql (1.82ms)18622026/10/01 08:26:42 OK 2_object_stats_trigger.sql (622.99µs)18632026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.17ms)18642026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000018652026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (1.81ms)18662026/10/01 08:26:42 OK 3_commit_push.sql (1.73ms)18672026/10/01 08:26:42 goose: up to current file version: 318682026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.42ms)18692026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.7ms)18702026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000018712026/10/01 08:26:42 OK 2_object_stats_trigger.sql (763.34µs)18722026/10/01 08:26:42 OK 3_commit_push.sql (1ms)18732026/10/01 08:26:42 goose: up to current file version: 318742026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.44ms)18752026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.75ms)18762026/10/01 08:26:42 OK 3_commit_push.sql (1.47ms)18772026/10/01 08:26:42 goose: up to current file version: 318782026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures18792026/10/01 08:26:42 INFO Aborted multipart uploads count=018802026/10/01 08:26:42 INFO Aborted multipart uploads count=018812026/10/01 08:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period18822026/10/01 08:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period1883--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.54s)1884=== CONT TestParseSingleRange1885=== RUN TestParseSingleRange/none1886=== PAUSE TestParseSingleRange/none1887=== RUN TestParseSingleRange/unknown_unit1888=== PAUSE TestParseSingleRange/unknown_unit1889=== RUN TestParseSingleRange/multi-range_ignored1890=== PAUSE TestParseSingleRange/multi-range_ignored1891=== RUN TestParseSingleRange/malformed_no_dash1892=== PAUSE TestParseSingleRange/malformed_no_dash1893=== RUN TestParseSingleRange/malformed_both_empty1894=== PAUSE TestParseSingleRange/malformed_both_empty1895=== RUN TestParseSingleRange/malformed_end_before_start1896=== PAUSE TestParseSingleRange/malformed_end_before_start1897=== RUN TestParseSingleRange/closed1898=== PAUSE TestParseSingleRange/closed1899=== RUN TestParseSingleRange/open-ended1900=== PAUSE TestParseSingleRange/open-ended1901=== RUN TestParseSingleRange/end_clamped_to_size1902=== PAUSE TestParseSingleRange/end_clamped_to_size1903=== RUN TestParseSingleRange/suffix1904=== PAUSE TestParseSingleRange/suffix1905=== RUN TestParseSingleRange/suffix_exceeds_size1906=== PAUSE TestParseSingleRange/suffix_exceeds_size1907=== RUN TestParseSingleRange/single_byte1908=== PAUSE TestParseSingleRange/single_byte1909=== RUN TestParseSingleRange/start_past_EOF1910=== PAUSE TestParseSingleRange/start_past_EOF1911=== RUN TestParseSingleRange/start_far_past_EOF1912=== PAUSE TestParseSingleRange/start_far_past_EOF1913=== CONT TestCreatePin_ReservedPins19142026/10/01 08:26:42 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."19152026/10/01 08:26:42 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1916--- PASS: TestFailedS3DeleteKeepsTombstone (0.65s)1917=== CONT TestOrphanedObjectsGCStressTest19182026/10/01 08:26:42 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=019192026/10/01 08:26:42 INFO Vacuumed table table=pending_closures19202026/10/01 08:26:42 INFO Vacuumed table table=pending_objects19212026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads19222026/10/01 08:26:42 INFO Vacuumed table table=closures19232026/10/01 08:26:42 INFO Vacuumed table table=objects1924--- PASS: TestGCSweepDeliversEachKeyOnce (0.64s)1925=== CONT TestClientIntegration19262026-10-01 08:26:42.823 UTC [812] ERROR: relation "goose_db_version" does not exist at character 3619272026-10-01 08:26:42.823 UTC [812] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19282026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures1929--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.57s)1930=== CONT TestService_NativeMTLS19312026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.55ms)19322026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)19332026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.76ms)19342026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.47ms)19352026/10/01 08:26:42 OK 20260905000000_add_claims.sql (3.1ms)19362026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.46ms)19372026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (2.61ms)19382026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000019392026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.31ms)19402026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.25ms)19412026/10/01 08:26:42 OK 3_commit_push.sql (1.23ms)19422026/10/01 08:26:42 goose: up to current file version: 319432026/10/01 08:26:42 INFO Received uploads request method=POST path=/api/pending_closures19442026-10-01 08:26:42.881 UTC [849] ERROR: relation "goose_db_version" does not exist at character 3619452026-10-01 08:26:42.881 UTC [849] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1946=== NAME TestClientWithDependencies1947 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies197652285/001/store/6v7w8rfvwk65xbjgxx0gy0xd9a9y39li-test-script19482026-10-01 08:26:42.889 UTC [850] ERROR: relation "goose_db_version" does not exist at character 3619492026-10-01 08:26:42.889 UTC [850] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19502026/10/01 08:26:42 OK 20241026095416_initial_model.sql (8.31ms)19512026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)19522026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.78ms)19532026/10/01 08:26:42 OK 20241026095416_initial_model.sql (7.81ms)19542026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)19552026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)19562026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.83ms)19572026/10/01 08:26:42 OK 20260905000000_add_claims.sql (2.48ms)19582026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (1.45ms)19592026/10/01 08:26:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41923/oidc19602026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (2.54ms)19612026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.37ms)19622026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000019632026/10/01 08:26:42 OK 20260905000000_add_claims.sql (2.01ms)19642026/10/01 08:26:42 OK 1_commit_pending_closure.sql (1.63ms)19652026/10/01 08:26:42 OK 2_object_stats_trigger.sql (665.66µs)19662026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (1.76ms)19672026/10/01 08:26:42 OK 3_commit_push.sql (691.68µs)19682026/10/01 08:26:42 goose: up to current file version: 319692026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.34ms)19702026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000019712026/10/01 08:26:42 INFO Aborted multipart uploads count=019722026/10/01 08:26:42 OK 1_commit_pending_closure.sql (1.39ms)19732026/10/01 08:26:42 OK 2_object_stats_trigger.sql (591.31µs)19742026-10-01 08:26:42.916 UTC [870] ERROR: relation "goose_db_version" does not exist at character 3619752026-10-01 08:26:42.916 UTC [870] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19762026/10/01 08:26:42 OK 3_commit_push.sql (554.68µs)19772026/10/01 08:26:42 goose: up to current file version: 319782026/10/01 08:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period1979 client_integration_test.go:615: Found 1 dependencies (including self)19802026/10/01 08:26:42 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=019812026/10/01 08:26:42 INFO Vacuumed table table=pending_closures19822026/10/01 08:26:42 INFO Vacuumed table table=pending_objects19832026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads19842026/10/01 08:26:42 INFO Vacuumed table table=closures19852026/10/01 08:26:42 INFO Vacuumed table table=objects1986--- PASS: TestGCMetrics (0.62s)1987=== CONT TestObjectStatsTrigger1988--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.78s)1989=== CONT TestMultipartCleanup19902026/10/01 08:26:42 OK 20241026095416_initial_model.sql (7.64ms)19912026/10/01 08:26:42 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)19922026/10/01 08:26:42 INFO lead: acquired remote=192.0.2.1:123419932026/10/01 08:26:42 INFO lead: released remote=192.0.2.1:12341994--- PASS: TestLeadEndsOnShutdown (0.58s)1995=== CONT TestClientErrorHandling1996=== RUN TestClientErrorHandling/InvalidStorePath1997=== PAUSE TestClientErrorHandling/InvalidStorePath1998=== RUN TestClientErrorHandling/InvalidAuthToken1999=== PAUSE TestClientErrorHandling/InvalidAuthToken2000=== RUN TestClientErrorHandling/ServerNotAvailable2001=== PAUSE TestClientErrorHandling/ServerNotAvailable2002=== CONT TestServerTLSConfig2003=== RUN TestServerTLSConfig/no_client_CA2004=== PAUSE TestServerTLSConfig/no_client_CA2005=== RUN TestServerTLSConfig/missing_CA_file2006=== PAUSE TestServerTLSConfig/missing_CA_file2007=== RUN TestServerTLSConfig/not_a_PEM_file2008=== PAUSE TestServerTLSConfig/not_a_PEM_file2009=== CONT TestNARDeduplicationMetadataUploadBug20102026/10/01 08:26:42 OK 20251218171726_add_pins.sql (2.78ms)20112026/10/01 08:26:42 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)20122026/10/01 08:26:42 OK 20260905000000_add_claims.sql (2.66ms)20132026/10/01 08:26:42 OK 20260920000000_drop_claims.sql (2.3ms)20142026/10/01 08:26:42 OK 20260923120000_add_pushes.sql (1.59ms)20152026/10/01 08:26:42 goose: successfully migrated database to version: 2026092312000020162026/10/01 08:26:42 OK 1_commit_pending_closure.sql (2.24ms)20172026/10/01 08:26:42 INFO Aborted multipart uploads count=020182026/10/01 08:26:42 OK 2_object_stats_trigger.sql (1.72ms)20192026/10/01 08:26:42 OK 3_commit_push.sql (1.44ms)20202026/10/01 08:26:42 goose: up to current file version: 320212026/10/01 08:26:42 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=020222026/10/01 08:26:42 INFO Vacuumed table table=pending_closures20232026/10/01 08:26:42 INFO Vacuumed table table=pending_objects20242026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads20252026/10/01 08:26:42 INFO Vacuumed table table=closures20262026/10/01 08:26:42 INFO Vacuumed table table=objects20272026/10/01 08:26:42 INFO Aborted multipart uploads count=020282026/10/01 08:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period20292026/10/01 08:26:42 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=020302026/10/01 08:26:42 INFO Vacuumed table table=pending_closures20312026/10/01 08:26:42 INFO lead: acquired remote=192.0.2.1:123420322026/10/01 08:26:42 INFO Vacuumed table table=pending_objects20332026/10/01 08:26:42 INFO Vacuumed table table=multipart_uploads20342026/10/01 08:26:42 INFO Vacuumed table table=closures20352026/10/01 08:26:42 INFO Received push request method=POST path=/api/pushes20362026/10/01 08:26:42 INFO Vacuumed table table=objects2037--- PASS: TestPushDedupSurvivesConcurrentGC (0.72s)2038=== CONT TestCreatePendingClosureRejectsOversizedNAR20392026/10/01 08:26:43 INFO Received uploads request method=POST path=/api/pending_closures2040--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)2041=== CONT TestMetricsInventory20422026/10/01 08:26:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20432026-10-01 08:26:43.004 UTC [933] ERROR: relation "goose_db_version" does not exist at character 3620442026-10-01 08:26:43.004 UTC [933] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20452026/10/01 08:26:43 INFO Uploading 6v7w8rfvwk65xbjgxx0gy0xd9a9y39li-test-script (136B)20462026/10/01 08:26:43 WARN Failed to register uploaded object key=log/q46wqfbl8h75gm70d318ydwbfrk86qn0-test-script.drv error="server returned 404: 404 page not found\n"20472026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"20482026/10/01 08:26:43 WARN Failed to register uploaded object key=6v7w8rfvwk65xbjgxx0gy0xd9a9y39li.ls error="server returned 404: 404 page not found\n"20492026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20502026/10/01 08:26:43 INFO Signed narinfos id=1 count=120512026/10/01 08:26:43 INFO Uploading 1 narinfos20522026/10/01 08:26:43 INFO Received complete push request method=POST path=/api/pushes/1/complete20532026/10/01 08:26:43 WARN Failed to register uploaded object key=6v7w8rfvwk65xbjgxx0gy0xd9a9y39li.narinfo error="server returned 404: 404 page not found\n"20542026/10/01 08:26:43 OK 20241026095416_initial_model.sql (11.5ms)20552026-10-01 08:26:43.029 UTC [937] ERROR: relation "goose_db_version" does not exist at character 3620562026-10-01 08:26:43.029 UTC [937] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20572026-10-01 08:26:43.030 UTC [938] ERROR: relation "goose_db_version" does not exist at character 3620582026-10-01 08:26:43.030 UTC [938] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20592026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (7.28ms)20602026/10/01 08:26:43 INFO Upload complete. (78ms)20612026-10-01 08:26:43.036 UTC [956] ERROR: relation "goose_db_version" does not exist at character 3620622026-10-01 08:26:43.036 UTC [956] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20632026/10/01 08:26:43 OK 20251218171726_add_pins.sql (6.86ms)2064=== NAME TestClientWithDependencies2065 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies197652285/001/store) requires matching store prefix20662026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)2067--- PASS: TestClientWithDependencies (0.80s)2068=== CONT TestService_AuthMiddleware_OIDC20692026/10/01 08:26:43 OK 20260905000000_add_claims.sql (2.54ms)20702026/10/01 08:26:43 OK 20241026095416_initial_model.sql (8.21ms)20712026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (2.72ms)20722026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)20732026/10/01 08:26:43 OK 20241026095416_initial_model.sql (9.46ms)20742026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (1.92ms)20752026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000020762026/10/01 08:26:43 OK 20251218171726_add_pins.sql (2.49ms)20772026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)20782026/10/01 08:26:43 OK 1_commit_pending_closure.sql (1.76ms)20792026/10/01 08:26:43 OK 20241026095416_initial_model.sql (10.74ms)20802026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.2ms)20812026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (2.79ms)20822026/10/01 08:26:43 OK 20251218171726_add_pins.sql (2.69ms)20832026/10/01 08:26:43 OK 3_commit_push.sql (576.95µs)20842026/10/01 08:26:43 goose: up to current file version: 320852026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.42ms)20862026/10/01 08:26:43 OK 20260905000000_add_claims.sql (2.78ms)20872026/10/01 08:26:43 OK 20251218171726_add_pins.sql (2.58ms)20882026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)20892026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (1.59ms)20902026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (2.17ms)20912026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000020922026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)20932026/10/01 08:26:43 OK 20260905000000_add_claims.sql (3.99ms)20942026/10/01 08:26:43 OK 1_commit_pending_closure.sql (2.12ms)20952026/10/01 08:26:43 OK 20260905000000_add_claims.sql (3.18ms)20962026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (2.99ms)20972026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.62ms)20982026/10/01 08:26:43 OK 3_commit_push.sql (1.94ms)20992026/10/01 08:26:43 goose: up to current file version: 321002026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (2.71ms)21012026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000021022026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (3.37ms)21032026/10/01 08:26:43 OK 1_commit_pending_closure.sql (2.37ms)21042026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (2.57ms)21052026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000021062026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.76ms)2107--- PASS: TestPushWaitsForSweepHoldingRow (1.06s)2108=== CONT TestService_AuthMiddleware_MTLSBoundSubjects21092026/10/01 08:26:43 OK 1_commit_pending_closure.sql (2.28ms)21102026/10/01 08:26:43 OK 3_commit_push.sql (1.49ms)21112026/10/01 08:26:43 goose: up to current file version: 321122026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.34ms)21132026/10/01 08:26:43 OK 3_commit_push.sql (1.4ms)21142026/10/01 08:26:43 goose: up to current file version: 321152026-10-01 08:26:43.098 UTC [1028] ERROR: relation "goose_db_version" does not exist at character 3621162026-10-01 08:26:43.098 UTC [1028] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21172026/10/01 08:26:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41549/oidc2118--- PASS: TestGCBugBareHashReferences (0.79s)2119=== CONT TestService_ReadScope_PublicByDefault21202026/10/01 08:26:43 OK 20241026095416_initial_model.sql (10.74ms)21212026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)21222026/10/01 08:26:43 OK 20251218171726_add_pins.sql (3.95ms)21232026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (4.93ms)2124=== NAME TestPinProtectsFromGC2125 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1588065869/001/store/3afa0lp3q0m9fy8fp2ind33nsakl2ysq-pinned-file.txt2126 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1588065869/001/store/bjb78my5dw91hpnvrq9f7yxx9crc4vgp-unpinned-file.txt21272026/10/01 08:26:43 INFO lead: released remote=192.0.2.1:123421282026/10/01 08:26:43 OK 20260905000000_add_claims.sql (14.2ms)21292026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (5.5ms)21302026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (2.86ms)21312026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000021322026/10/01 08:26:43 INFO Received uploads request method=POST path=/api/pending_closures21332026/10/01 08:26:43 OK 1_commit_pending_closure.sql (2.36ms)2134=== NAME TestClientMultipleUploads2135 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4112019021/001/store/aqzjmwpgmdza1zi9z64ii09ks2jnkwzc-test-file-0.txt21362026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.81ms)21372026/10/01 08:26:43 OK 3_commit_push.sql (1.35ms)21382026/10/01 08:26:43 goose: up to current file version: 321392026/10/01 08:26:43 INFO Received uploads request method=POST path=/api/pending_closures21402026-10-01 08:26:43.160 UTC [1159] ERROR: relation "goose_db_version" does not exist at character 3621412026-10-01 08:26:43.160 UTC [1159] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21422026/10/01 08:26:43 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21432026/10/01 08:26:43 INFO Uploading bnnfjh4amyfdnnd789s3xn2c1s3yg8ij-shared-dep (136B)21442026/10/01 08:26:43 INFO Uploading x6nx23dkp87v7a125chgkdl49zi5y8qa-a (216B)21452026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/0apzdkgqj32v5mhzfxqw0aq2gyc20ldwwvi34qv7bb64i9621vqg.nar.zst error="server returned 404: 404 page not found\n"21462026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21472026/10/01 08:26:43 WARN Failed to register uploaded object key=x6nx23dkp87v7a125chgkdl49zi5y8qa.ls error="server returned 404: 404 page not found\n"21482026/10/01 08:26:43 WARN Failed to register uploaded object key=mjpp9sw0xws9z2s9sr6bkl2sp06nyn0i.ls error="server returned 404: 404 page not found\n"21492026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21502026/10/01 08:26:43 WARN Failed to register uploaded object key=bnnfjh4amyfdnnd789s3xn2c1s3yg8ij.ls error="server returned 404: 404 page not found\n"21512026/10/01 08:26:43 INFO Signed narinfos id=1 count=221522026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21532026/10/01 08:26:43 INFO Signed narinfos id=2 count=221542026/10/01 08:26:43 INFO Uploading 4 narinfos21552026/10/01 08:26:43 WARN Failed to register uploaded object key=bnnfjh4amyfdnnd789s3xn2c1s3yg8ij.narinfo error="server returned 404: 404 page not found\n"21562026/10/01 08:26:43 OK 20241026095416_initial_model.sql (8.6ms)21572026/10/01 08:26:43 WARN Failed to register uploaded object key=mjpp9sw0xws9z2s9sr6bkl2sp06nyn0i.narinfo error="server returned 404: 404 page not found\n"21582026/10/01 08:26:43 WARN Failed to register uploaded object key=bnnfjh4amyfdnnd789s3xn2c1s3yg8ij.narinfo error="server returned 404: 404 page not found\n"21592026/10/01 08:26:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21602026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)21612026/10/01 08:26:43 WARN Failed to register uploaded object key=x6nx23dkp87v7a125chgkdl49zi5y8qa.narinfo error="server returned 404: 404 page not found\n"21622026/10/01 08:26:43 OK 20251218171726_add_pins.sql (2.76ms)21632026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)2164--- PASS: TestCacheStatsHandler (0.59s)2165=== CONT TestService_ReadAuthMiddleware21662026/10/01 08:26:43 INFO Completed upload id=121672026/10/01 08:26:43 OK 20260905000000_add_claims.sql (2.57ms)21682026/10/01 08:26:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21692026/10/01 08:26:43 INFO Completed upload id=221702026/10/01 08:26:43 INFO lead: acquired remote=192.0.2.1:123421712026/10/01 08:26:43 INFO Upload complete. (75ms)2172=== NAME TestClientMultipleUploads2173 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4112019021/001/store/sk0ax97bf2fkrvd4vylkgb9fi1vz2i44-test-file-1.txt2174=== CONT TestService_RequireScope_OIDC2175--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.56s)21762026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (2.41ms)2177=== NAME TestClientFallsBackToClosures2178 client_pushes_test.go:112: Retrieved narinfo from S3:2179 StorePath: /build/TestClientFallsBackToClosures52406864/001/store/bnnfjh4amyfdnnd789s3xn2c1s3yg8ij-shared-dep2180 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2181 Compression: zstd2182 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822183 NarSize: 1362184 References: 2185 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n21862026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (1.53ms)21872026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000021882026-10-01 08:26:43.189 UTC [1230] ERROR: relation "goose_db_version" does not exist at character 3621892026-10-01 08:26:43.189 UTC [1230] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2190 client_pushes_test.go:112: Retrieved narinfo from S3:2191 StorePath: /build/TestClientFallsBackToClosures52406864/001/store/x6nx23dkp87v7a125chgkdl49zi5y8qa-a2192 URL: nar/0apzdkgqj32v5mhzfxqw0aq2gyc20ldwwvi34qv7bb64i9621vqg.nar.zst2193 Compression: zstd2194 NarHash: sha256:0apzdkgqj32v5mhzfxqw0aq2gyc20ldwwvi34qv7bb64i9621vqg2195 NarSize: 2162196 References: /build/TestClientFallsBackToClosures52406864/001/store/bnnfjh4amyfdnnd789s3xn2c1s3yg8ij-shared-dep2197 CA: text:sha256:0m0bl847nl0kh3cp2v17n2v8bzvgfxwl8174n0rrk3qairdhdvwl21982026/10/01 08:26:43 OK 1_commit_pending_closure.sql (1.46ms)21992026/10/01 08:26:43 INFO lead: released remote=192.0.2.1:12342200--- PASS: TestLeadElectsOneAndHandsOver (0.80s)2201=== CONT TestService_AuthMiddleware_MTLSProxyHeader22022026/10/01 08:26:43 OK 2_object_stats_trigger.sql (862µs)2203=== NAME TestClientFallsBackToClosures2204 client_pushes_test.go:112: Retrieved narinfo from S3:2205 StorePath: /build/TestClientFallsBackToClosures52406864/001/store/mjpp9sw0xws9z2s9sr6bkl2sp06nyn0i-b2206 URL: nar/0apzdkgqj32v5mhzfxqw0aq2gyc20ldwwvi34qv7bb64i9621vqg.nar.zst2207 Compression: zstd2208 NarHash: sha256:0apzdkgqj32v5mhzfxqw0aq2gyc20ldwwvi34qv7bb64i9621vqg2209 NarSize: 2162210 References: /build/TestClientFallsBackToClosures52406864/001/store/bnnfjh4amyfdnnd789s3xn2c1s3yg8ij-shared-dep2211 CA: text:sha256:0m0bl847nl0kh3cp2v17n2v8bzvgfxwl8174n0rrk3qairdhdvwl22122026/10/01 08:26:43 OK 3_commit_push.sql (682.55µs)22132026/10/01 08:26:43 goose: up to current file version: 322142026-10-01 08:26:43.195 UTC [1252] ERROR: relation "goose_db_version" does not exist at character 3622152026-10-01 08:26:43.195 UTC [1252] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2216--- PASS: TestClientFallsBackToClosures (0.79s)2217=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info22182026/10/01 08:26:43 INFO Received uploads request method=POST path=/2219=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key22202026/10/01 08:26:43 INFO Received complete multipart upload request method=POST path=/2221=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key22222026/10/01 08:26:43 INFO Received request for more parts method=POST path=/2223=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal22242026/10/01 08:26:43 INFO Received uploads request method=POST path=/2225--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)2226 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2227 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2228 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2229 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2230=== CONT TestProxyWriteTimeout/narinfo2231=== CONT TestProxyWriteTimeout/unknown_size2232=== CONT TestProxyWriteTimeout/10_GiB_nar2233=== CONT TestProxyWriteTimeout/1_GiB_nar2234--- PASS: TestProxyWriteTimeout (0.08s)2235 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2236 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2237 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2238 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2239=== CONT TestIsValidUploadKey/narinfo2240=== CONT TestIsValidUploadKey/nix-cache-info2241=== CONT TestIsValidUploadKey/realisation_plus_in_output2242=== CONT TestIsValidUploadKey/realisation2243=== CONT TestIsValidUploadKey/build_log_equals2244=== CONT TestIsValidUploadKey/build_log_question_mark2245=== CONT TestIsValidUploadKey/build_log_plus_in_name2246=== CONT TestIsValidUploadKey/build_log_home-manager_file2247=== CONT TestIsValidUploadKey/build_log2248=== CONT TestIsValidUploadKey/listing2249=== CONT TestIsValidUploadKey/nar_plain2250=== CONT TestIsValidUploadKey/index.html2251=== CONT TestIsValidUploadKey/nar_xz2252=== CONT TestIsValidUploadKey/nar_zst2253=== CONT TestIsValidUploadKey/traversal_nar2254=== CONT TestIsValidUploadKey/absolute2255=== CONT TestIsValidUploadKey/unknown_type2256=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2257=== CONT TestIsValidUploadKey/traversal22582026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes2259=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2260=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2261=== CONT TestIsValidUploadKey/empty_key2262--- PASS: TestIsValidUploadKey (0.08s)2263 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2264 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2265 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2266 --- PASS: TestIsValidUploadKey/realisation (0.00s)2267 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2268 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2269 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2270 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2271 --- PASS: TestIsValidUploadKey/build_log (0.00s)2272 --- PASS: TestIsValidUploadKey/listing (0.00s)2273 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2274 --- PASS: TestIsValidUploadKey/index.html (0.00s)2275 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2276 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2277 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2278 --- PASS: TestIsValidUploadKey/absolute (0.00s)2279 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2280 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2281 --- PASS: TestIsValidUploadKey/traversal (0.00s)2282 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2283 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2284 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2285=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22862026/10/01 08:26:43 INFO Received request for more parts method=POST path=/22872026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes22882026/10/01 08:26:43 OK 20241026095416_initial_model.sql (8.85ms)22892026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)22902026/10/01 08:26:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22912026/10/01 08:26:43 INFO Uploading 3afa0lp3q0m9fy8fp2ind33nsakl2ysq-pinned-file.txt (128B)22922026/10/01 08:26:43 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)22932026/10/01 08:26:43 INFO Uploading gafa87af7wak18l3574m2304xah7p56z-a (216B)22942026/10/01 08:26:43 INFO Uploading spprpn9skclcc0jr4dmh1yiyz59f6nid-shared-dep (136B)22952026/10/01 08:26:43 OK 20241026095416_initial_model.sql (7.93ms)22962026/10/01 08:26:43 OK 20251218171726_add_pins.sql (3.07ms)22972026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)22982026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"22992026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/0s0ab0lprj18bmdwxy2xndvf8r4dmg79dqkszhlkq4z1pshnmi2w.nar.zst error="server returned 404: 404 page not found\n"23002026/10/01 08:26:43 WARN Failed to register uploaded object key=cxg6kzwvkx2r6av6wlrjrp28j3frj59f.ls error="server returned 404: 404 page not found\n"23012026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"23022026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23032026/10/01 08:26:43 WARN Failed to register uploaded object key=spprpn9skclcc0jr4dmh1yiyz59f6nid.ls error="server returned 404: 404 page not found\n"23042026/10/01 08:26:43 WARN Failed to register uploaded object key=3afa0lp3q0m9fy8fp2ind33nsakl2ysq.ls error="server returned 404: 404 page not found\n"23052026/10/01 08:26:43 INFO Signed narinfos id=1 count=123062026/10/01 08:26:43 WARN Failed to register uploaded object key=gafa87af7wak18l3574m2304xah7p56z.ls error="server returned 404: 404 page not found\n"23072026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23082026/10/01 08:26:43 INFO Uploading 1 narinfos23092026/10/01 08:26:43 OK 20251218171726_add_pins.sql (4.23ms)23102026/10/01 08:26:43 INFO Signed narinfos id=1 count=323112026/10/01 08:26:43 INFO Uploading 3 narinfos23122026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (6.62ms)23132026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (4.12ms)23142026/10/01 08:26:43 WARN Failed to register uploaded object key=cxg6kzwvkx2r6av6wlrjrp28j3frj59f.narinfo error="server returned 404: 404 page not found\n"23152026/10/01 08:26:43 INFO Received complete push request method=POST path=/api/pushes/1/complete23162026/10/01 08:26:43 WARN Failed to register uploaded object key=3afa0lp3q0m9fy8fp2ind33nsakl2ysq.narinfo error="server returned 404: 404 page not found\n"2317=== NAME TestClientMultipleUploads23182026/10/01 08:26:43 OK 20260905000000_add_claims.sql (4.73ms)2319 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4112019021/001/store/88sfjdadblbk81wah8bcw71187vdkh4l-test-file-2.txt23202026/10/01 08:26:43 WARN Failed to register uploaded object key=spprpn9skclcc0jr4dmh1yiyz59f6nid.narinfo error="server returned 404: 404 page not found\n"23212026/10/01 08:26:43 OK 20260905000000_add_claims.sql (3.2ms)23222026/10/01 08:26:43 WARN Failed to register uploaded object key=gafa87af7wak18l3574m2304xah7p56z.narinfo error="server returned 404: 404 page not found\n"23232026/10/01 08:26:43 INFO Received complete push request method=POST path=/api/pushes/1/complete23242026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (3.33ms)23252026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (2.45ms)23262026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (2.77ms)23272026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000023282026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (2.55ms)23292026/10/01 08:26:43 goose: successfully migrated database to version: 202609231200002330=== NAME TestClientCADerivations2331 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1728168817/001/store/3hyfvilkj70karpb1mwz3ms48yc5s393-ca-test23322026/10/01 08:26:43 OK 1_commit_pending_closure.sql (2.4ms)23332026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes23342026/10/01 08:26:43 OK 1_commit_pending_closure.sql (2.11ms)23352026/10/01 08:26:43 INFO Upload complete. (68ms)23362026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.11ms)23372026/10/01 08:26:43 OK 2_object_stats_trigger.sql (886.79µs)23382026/10/01 08:26:43 OK 3_commit_push.sql (1.05ms)23392026/10/01 08:26:43 goose: up to current file version: 323402026/10/01 08:26:43 OK 3_commit_push.sql (1.62ms)23412026/10/01 08:26:43 goose: up to current file version: 323422026/10/01 08:26:43 INFO Upload complete. (71ms)23432026/10/01 08:26:43 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)2344=== NAME TestClientPushesUseOnePush2345 client_pushes_test.go:97: Retrieved narinfo from S3:23462026/10/01 08:26:43 INFO Uploading zfm9lzikmz58qm8lwd1clhf11shy9nn3-top (224B)2347 StorePath: /build/TestClientPushesUseOnePush2783023699/001/store/spprpn9skclcc0jr4dmh1yiyz59f6nid-shared-dep2348 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst23492026/10/01 08:26:43 INFO Uploading zzafh2dgmay0wrb9n75ri8q603xrdmnb-shared-dep (136B)2350 Compression: zstd2351 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822352 NarSize: 1362353 References: 2354 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2355--- PASS: TestReadProxyNarinfo (0.60s)2356=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart2357=== NAME TestClientPushesUseOnePush23582026/10/01 08:26:43 INFO Received complete multipart upload request method=POST path=/2359 client_pushes_test.go:97: Retrieved narinfo from S3:2360 StorePath: /build/TestClientPushesUseOnePush2783023699/001/store/gafa87af7wak18l3574m2304xah7p56z-a2361 URL: nar/0s0ab0lprj18bmdwxy2xndvf8r4dmg79dqkszhlkq4z1pshnmi2w.nar.zst2362 Compression: zstd2363 NarHash: sha256:0s0ab0lprj18bmdwxy2xndvf8r4dmg79dqkszhlkq4z1pshnmi2w2364 NarSize: 2162365 References: /build/TestClientPushesUseOnePush2783023699/001/store/spprpn9skclcc0jr4dmh1yiyz59f6nid-shared-dep2366 CA: text:sha256:12l54m0jd8dyms1ddz9s5zyxqpck1vzsi4hhmv0x2wagl074m0jk23672026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"2368=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure23692026/10/01 08:26:43 INFO Received uploads request method=POST path=/23702026/10/01 08:26:43 WARN Failed to register uploaded object key=zzafh2dgmay0wrb9n75ri8q603xrdmnb.ls error="server returned 404: 404 page not found\n"23712026/10/01 08:26:43 WARN Failed to register uploaded object key=zfm9lzikmz58qm8lwd1clhf11shy9nn3.ls error="server returned 404: 404 page not found\n"23722026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23732026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/1pnjv6f58arx6xxrhzlllji7gs5wlaagjj2r17p16j2grwyqpcb9.nar.zst error="server returned 404: 404 page not found\n"23742026/10/01 08:26:43 INFO Signed narinfos id=1 count=223752026/10/01 08:26:43 INFO Uploading 2 narinfos2376=== NAME TestClientPushesUseOnePush2377 client_pushes_test.go:97: Retrieved narinfo from S3:2378 StorePath: /build/TestClientPushesUseOnePush2783023699/001/store/cxg6kzwvkx2r6av6wlrjrp28j3frj59f-b2379 URL: nar/0s0ab0lprj18bmdwxy2xndvf8r4dmg79dqkszhlkq4z1pshnmi2w.nar.zst2380 Compression: zstd2381 NarHash: sha256:0s0ab0lprj18bmdwxy2xndvf8r4dmg79dqkszhlkq4z1pshnmi2w2382 NarSize: 2162383 References: /build/TestClientPushesUseOnePush2783023699/001/store/spprpn9skclcc0jr4dmh1yiyz59f6nid-shared-dep2384 CA: text:sha256:12l54m0jd8dyms1ddz9s5zyxqpck1vzsi4hhmv0x2wagl074m0jk23852026/10/01 08:26:43 WARN Failed to register uploaded object key=zfm9lzikmz58qm8lwd1clhf11shy9nn3.narinfo error="server returned 404: 404 page not found\n"23862026/10/01 08:26:43 INFO Received complete push request method=POST path=/api/pushes/1/complete23872026/10/01 08:26:43 WARN Failed to register uploaded object key=zzafh2dgmay0wrb9n75ri8q603xrdmnb.narinfo error="server returned 404: 404 page not found\n"2388--- PASS: TestClientPushesUseOnePush (0.83s)2389=== CONT TestPush_RejectsBadRequests/no_roots23902026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes2391=== CONT TestPush_RejectsBadRequests/bad_root23922026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes2393=== CONT TestPush_RejectsBadRequests/root_not_in_objects23942026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes2395=== CONT TestPush_RejectsBadRequests/no_objects23962026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes2397=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2398--- PASS: TestPush_RejectsBadRequests (0.79s)2399 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2400 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2401 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2402 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)24032026/10/01 08:26:43 INFO Starting HTTP server address=127.0.0.1:3348124042026/10/01 08:26:43 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2207119695/001/proxy.sock24052026/10/01 08:26:43 WARN mTLS auth: subject not in bound subjects subject="CN=someone"24062026/10/01 08:26:43 INFO Shutdown signal received, draining in-flight requests timeout=10s2407--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.52s)2408=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check24092026/10/01 08:26:43 INFO Upload complete. (69ms)2410=== NAME TestClientCADerivations2411 client_ca_test.go:139: Found 1 dependencies (including self)2412=== NAME TestClientSharedPathCommittedMidPush2413 client_integration_test.go:680: Retrieved narinfo from S3:2414 StorePath: /build/TestClientSharedPathCommittedMidPush1120381380/001/store/zzafh2dgmay0wrb9n75ri8q603xrdmnb-shared-dep2415 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2416 Compression: zstd2417 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822418 NarSize: 1362419 References: 2420 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2421 client_integration_test.go:680: Retrieved narinfo from S3:2422 StorePath: /build/TestClientSharedPathCommittedMidPush1120381380/001/store/zfm9lzikmz58qm8lwd1clhf11shy9nn3-top2423 URL: nar/1pnjv6f58arx6xxrhzlllji7gs5wlaagjj2r17p16j2grwyqpcb9.nar.zst2424 Compression: zstd2425 NarHash: sha256:1pnjv6f58arx6xxrhzlllji7gs5wlaagjj2r17p16j2grwyqpcb92426 NarSize: 2242427 References: /build/TestClientSharedPathCommittedMidPush1120381380/001/store/zzafh2dgmay0wrb9n75ri8q603xrdmnb-shared-dep2428 CA: text:sha256:0xsmkmx8pkq3sljhks2axcz3ln22ylb66as9wd5v0zbczvidnm2j2429--- PASS: TestClientSharedPathCommittedMidPush (0.77s)2430=== CONT TestResolveDBConnectionString/flag_wins2431=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2432=== CONT TestResolveDBConnectionString/nothing_configured2433=== CONT TestResolveDBConnectionString/missing_file_is_an_error2434=== CONT TestResolveDBConnectionString/file_when_flag_empty2435=== CONT TestCacheConfigHandler/full_config,_no_issuer2436=== CONT TestCacheConfigHandler/no_signing_keys2437=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2438=== CONT TestCacheConfigHandler/no_cache_url_configured2439--- PASS: TestCacheConfigHandler (0.00s)2440 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2441 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2442 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2443 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2444=== CONT TestIsValidCachePath/narinfo2445=== CONT TestIsValidCachePath/index.html2446=== CONT TestIsValidCachePath/short_hash2447=== CONT TestIsValidCachePath/wrong_extension2448=== CONT TestIsValidCachePath/leading_slash2449=== CONT TestIsValidCachePath/empty2450=== CONT TestIsValidCachePath/random_path2451=== CONT TestIsValidCachePath/invalid_char_u2452=== CONT TestIsValidCachePath/invalid_char_e2453=== CONT TestIsValidCachePath/traversal_in_middle2454=== CONT TestIsValidCachePath/traversal_parent2455=== CONT TestIsValidCachePath/nar_uncompressed2456--- PASS: TestResolveDBConnectionString (0.00s)2457 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2458 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2459 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2460 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2461 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2462=== CONT TestIsValidCachePath/nix-cache-info2463=== CONT TestIsValidCachePath/log2464=== CONT TestIsValidCachePath/ls2465=== CONT TestIsValidCachePath/realisation2466=== CONT TestIsValidCachePath/nar_xz2467=== CONT TestIsValidCachePath/nar_bz22468=== CONT TestIsValidCachePath/nar_zst2469=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2470=== CONT TestParseSingleRange/none2471=== CONT TestParseSingleRange/start_past_EOF2472--- PASS: TestIsValidCachePath (0.00s)2473 --- PASS: TestIsValidCachePath/narinfo (0.00s)2474 --- PASS: TestIsValidCachePath/index.html (0.00s)2475 --- PASS: TestIsValidCachePath/short_hash (0.00s)2476 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2477 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2478 --- PASS: TestIsValidCachePath/empty (0.00s)2479 --- PASS: TestIsValidCachePath/random_path (0.00s)2480 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2481 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2482 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2483 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2484 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2485 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2486 --- PASS: TestIsValidCachePath/log (0.00s)2487 --- PASS: TestIsValidCachePath/ls (0.00s)2488 --- PASS: TestIsValidCachePath/realisation (0.00s)2489 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2490 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2491 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2492 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2493=== CONT TestParseSingleRange/single_byte2494=== CONT TestParseSingleRange/suffix_exceeds_size2495=== CONT TestParseSingleRange/suffix2496=== CONT TestParseSingleRange/start_far_past_EOF2497=== CONT TestParseSingleRange/end_clamped_to_size2498=== CONT TestParseSingleRange/open-ended2499=== CONT TestParseSingleRange/closed2500=== CONT TestParseSingleRange/malformed_end_before_start2501=== CONT TestParseSingleRange/malformed_both_empty2502=== CONT TestParseSingleRange/malformed_no_dash2503=== CONT TestParseSingleRange/multi-range_ignored2504=== CONT TestParseSingleRange/unknown_unit2505--- PASS: TestParseSingleRange (0.00s)2506 --- PASS: TestParseSingleRange/none (0.00s)2507 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2508 --- PASS: TestParseSingleRange/single_byte (0.00s)2509 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2510 --- PASS: TestParseSingleRange/suffix (0.00s)2511 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2512 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2513 --- PASS: TestParseSingleRange/open-ended (0.00s)2514 --- PASS: TestParseSingleRange/closed (0.00s)2515 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2516 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2517 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2518 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2519 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2520=== CONT TestClientErrorHandling/InvalidStorePath25212026-10-01 08:26:43.279 UTC [1401] ERROR: relation "goose_db_version" does not exist at character 3625222026-10-01 08:26:43.279 UTC [1401] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2523=== CONT TestClientErrorHandling/ServerNotAvailable25242026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes25252026-10-01 08:26:43.289 UTC [1423] ERROR: relation "goose_db_version" does not exist at character 3625262026-10-01 08:26:43.289 UTC [1423] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25272026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes25282026/10/01 08:26:43 OK 20241026095416_initial_model.sql (11.2ms)25292026/10/01 08:26:43 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)25302026/10/01 08:26:43 INFO Uploading aqzjmwpgmdza1zi9z64ii09ks2jnkwzc-test-file-0.txt (160B)25312026/10/01 08:26:43 INFO Uploading 88sfjdadblbk81wah8bcw71187vdkh4l-test-file-2.txt (160B)25322026/10/01 08:26:43 INFO Uploading sk0ax97bf2fkrvd4vylkgb9fi1vz2i44-test-file-1.txt (160B)25332026/10/01 08:26:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)25342026/10/01 08:26:43 INFO Uploading bjb78my5dw91hpnvrq9f7yxx9crc4vgp-unpinned-file.txt (128B)25352026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)25362026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"25372026/10/01 08:26:43 WARN Failed to register uploaded object key=aqzjmwpgmdza1zi9z64ii09ks2jnkwzc.ls error="server returned 404: 404 page not found\n"25382026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"25392026/10/01 08:26:43 WARN Failed to register uploaded object key=88sfjdadblbk81wah8bcw71187vdkh4l.ls error="server returned 404: 404 page not found\n"25402026/10/01 08:26:43 OK 20251218171726_add_pins.sql (3.88ms)25412026/10/01 08:26:43 WARN Failed to register uploaded object key=bjb78my5dw91hpnvrq9f7yxx9crc4vgp.ls error="server returned 404: 404 page not found\n"25422026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"25432026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign25442026/10/01 08:26:43 INFO Signed narinfos id=2 count=125452026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"25462026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign25472026/10/01 08:26:43 WARN Failed to register uploaded object key=sk0ax97bf2fkrvd4vylkgb9fi1vz2i44.ls error="server returned 404: 404 page not found\n"25482026/10/01 08:26:43 INFO Uploading 1 narinfos25492026/10/01 08:26:43 INFO Signed narinfos id=1 count=325502026/10/01 08:26:43 INFO Uploading 3 narinfos25512026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)25522026/10/01 08:26:43 OK 20241026095416_initial_model.sql (8.71ms)25532026/10/01 08:26:43 INFO Received complete push request method=POST path=/api/pushes/2/complete25542026/10/01 08:26:43 WARN Failed to register uploaded object key=bjb78my5dw91hpnvrq9f7yxx9crc4vgp.narinfo error="server returned 404: 404 page not found\n"25552026/10/01 08:26:43 WARN Failed to register uploaded object key=aqzjmwpgmdza1zi9z64ii09ks2jnkwzc.narinfo error="server returned 404: 404 page not found\n"25562026/10/01 08:26:43 WARN Failed to register uploaded object key=sk0ax97bf2fkrvd4vylkgb9fi1vz2i44.narinfo error="server returned 404: 404 page not found\n"25572026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)25582026/10/01 08:26:43 INFO Received complete push request method=POST path=/api/pushes/1/complete25592026/10/01 08:26:43 WARN Failed to register uploaded object key=88sfjdadblbk81wah8bcw71187vdkh4l.narinfo error="server returned 404: 404 page not found\n"25602026/10/01 08:26:43 OK 20260905000000_add_claims.sql (2.65ms)25612026/10/01 08:26:43 INFO Upload complete. (48ms)25622026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (2.42ms)25632026/10/01 08:26:43 OK 20251218171726_add_pins.sql (3.54ms)25642026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (1.6ms)25652026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000025662026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)25672026/10/01 08:26:43 OK 1_commit_pending_closure.sql (2.77ms)25682026/10/01 08:26:43 OK 2_object_stats_trigger.sql (905.5µs)25692026/10/01 08:26:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36405/oidc25702026/10/01 08:26:43 INFO Upload complete. (68ms)2571=== NAME TestClientMultipleUploads2572 client_integration_test.go:369: Uploaded 3 paths in 98.268482ms25732026/10/01 08:26:43 OK 3_commit_push.sql (2.25ms)25742026/10/01 08:26:43 goose: up to current file version: 325752026/10/01 08:26:43 OK 20260905000000_add_claims.sql (3.87ms)25762026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (2.13ms)25772026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (2.92ms)25782026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000025792026/10/01 08:26:43 OK 1_commit_pending_closure.sql (2.26ms)25802026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.95ms)25812026/10/01 08:26:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"25822026/10/01 08:26:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2583--- PASS: TestService_NativeMTLS (0.50s)2584=== CONT TestClientErrorHandling/InvalidAuthToken2585--- PASS: TestClientMultipleUploads (0.83s)2586=== CONT TestServerTLSConfig/no_client_CA25872026/10/01 08:26:43 OK 3_commit_push.sql (1.14ms)2588=== CONT TestServerTLSConfig/not_a_PEM_file25892026/10/01 08:26:43 goose: up to current file version: 32590=== CONT TestServerTLSConfig/missing_CA_file2591--- PASS: TestServerTLSConfig (0.00s)2592 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2593 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2594 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2595=== NAME TestClientIntegration2596 client_integration_test.go:286: Created store path: /build/TestClientIntegration94001666/002/store/z2klzl9wzk6996gls5vwnp2plgnnay8v-test-file.txt25972026/10/01 08:26:43 INFO Received create pin request method=POST path=/api/pins/myapp25982026/10/01 08:26:43 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1588065869/001/store/3afa0lp3q0m9fy8fp2ind33nsakl2ysq-pinned-file.txt narinfo_key=3afa0lp3q0m9fy8fp2ind33nsakl2ysq.narinfo25992026/10/01 08:26:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures26002026/10/01 08:26:43 INFO Garbage collection started26012026/10/01 08:26:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux26022026/10/01 08:26:43 WARN Refused reserved pin name=worker-x86_64-linux26032026/10/01 08:26:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux26042026/10/01 08:26:43 INFO Received create pin request method=POST path=/api/pins/my-app26052026/10/01 08:26:43 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2606--- PASS: TestCreatePin_ReservedPins (0.58s)26072026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes26082026/10/01 08:26:43 INFO Aborted multipart uploads count=026092026/10/01 08:26:43 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/present26102026/10/01 08:26:43 WARN Force mode enabled - objects will be deleted immediately without grace period26112026/10/01 08:26:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26122026/10/01 08:26:43 INFO Uploading 3hyfvilkj70karpb1mwz3ms48yc5s393-ca-test (144B)26132026-10-01 08:26:43.375 UTC [1587] ERROR: relation "goose_db_version" does not exist at character 3626142026-10-01 08:26:43.375 UTC [1587] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26152026-10-01 08:26:43.379 UTC [1588] ERROR: relation "goose_db_version" does not exist at character 3626162026-10-01 08:26:43.379 UTC [1588] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26172026/10/01 08:26:43 WARN Failed to register uploaded object key=3hyfvilkj70karpb1mwz3ms48yc5s393.ls error="server returned 404: 404 page not found\n"26182026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"26192026/10/01 08:26:43 WARN Failed to register uploaded object key=log/y7f5xzpsckp2x529lxkcq5wnzvmgqmvh-ca-test.drv error="server returned 404: 404 page not found\n"26202026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26212026/10/01 08:26:43 INFO Signed narinfos id=1 count=126222026-10-01 08:26:43.380 UTC [1589] ERROR: relation "goose_db_version" does not exist at character 3626232026-10-01 08:26:43.380 UTC [1589] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26242026/10/01 08:26:43 INFO Uploading 1 narinfos26252026/10/01 08:26:43 INFO Received complete push request method=POST path=/api/pushes/1/complete26262026/10/01 08:26:43 WARN Failed to register uploaded object key=3hyfvilkj70karpb1mwz3ms48yc5s393.narinfo error="server returned 404: 404 page not found\n"26272026/10/01 08:26:43 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=026282026/10/01 08:26:43 OK 20241026095416_initial_model.sql (9.09ms)26292026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)26302026/10/01 08:26:43 OK 20241026095416_initial_model.sql (9.04ms)2631--- PASS: TestObjectStatsTrigger (0.47s)26322026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)26332026/10/01 08:26:43 INFO Upload complete. (102ms)26342026/10/01 08:26:43 OK 20251218171726_add_pins.sql (2.71ms)26352026/10/01 08:26:43 INFO Vacuumed table table=pending_closures26362026/10/01 08:26:43 OK 20241026095416_initial_model.sql (9.93ms)2637=== NAME TestClientCADerivations2638 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1728168817/001/store/3hyfvilkj70karpb1mwz3ms48yc5s393-ca-test2639 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst26402026/10/01 08:26:43 OK 20251218171726_add_pins.sql (3.07ms)2641 Compression: zstd2642 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2643 NarSize: 1442644 References: 2645 Deriver: /build/TestClientCADerivations1728168817/001/store/y7f5xzpsckp2x529lxkcq5wnzvmgqmvh-ca-test.drv2646 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2647 client_ca_test.go:185: Checking for realisation files in S3...26482026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (3.39ms)26492026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)26502026/10/01 08:26:43 INFO Vacuumed table table=pending_objects26512026/10/01 08:26:43 INFO Received uploads request method=POST path=/api/pending_closures2652 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2653 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache26542026/10/01 08:26:43 INFO Vacuumed table table=multipart_uploads26552026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (3.27ms)26562026/10/01 08:26:43 OK 20251218171726_add_pins.sql (3ms)26572026/10/01 08:26:43 OK 20260905000000_add_claims.sql (3.15ms)26582026/10/01 08:26:43 INFO Vacuumed table table=closures26592026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (2.31ms)26602026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes26612026/10/01 08:26:43 OK 20260905000000_add_claims.sql (3.75ms)26622026/10/01 08:26:43 INFO Vacuumed table table=objects26632026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)26642026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (2.24ms)26652026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000026662026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (2.57ms)26672026/10/01 08:26:43 OK 20260905000000_add_claims.sql (2.86ms)26682026/10/01 08:26:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26692026/10/01 08:26:43 INFO Uploading z2klzl9wzk6996gls5vwnp2plgnnay8v-test-file.txt (152B)26702026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (1.79ms)26712026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000026722026/10/01 08:26:43 OK 1_commit_pending_closure.sql (2.25ms)26732026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (1.76ms)26742026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.29ms)26752026/10/01 08:26:43 OK 1_commit_pending_closure.sql (2.05ms)26762026/10/01 08:26:43 OK 3_commit_push.sql (1.17ms)26772026/10/01 08:26:43 goose: up to current file version: 326782026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.24ms)26792026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (2.17ms)26802026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000026812026/10/01 08:26:43 WARN Failed to register uploaded object key=z2klzl9wzk6996gls5vwnp2plgnnay8v.ls error="server returned 404: 404 page not found\n"26822026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26832026/10/01 08:26:43 OK 3_commit_push.sql (845.67µs)26842026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"26852026/10/01 08:26:43 INFO Signed narinfos id=1 count=126862026/10/01 08:26:43 goose: up to current file version: 326872026/10/01 08:26:43 INFO Uploading 1 narinfos26882026/10/01 08:26:43 OK 1_commit_pending_closure.sql (1.71ms)26892026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.01ms)26902026-10-01 08:26:43.417 UTC [1609] ERROR: relation "goose_db_version" does not exist at character 3626912026-10-01 08:26:43.417 UTC [1609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26922026/10/01 08:26:43 OK 3_commit_push.sql (726.01µs)26932026/10/01 08:26:43 goose: up to current file version: 326942026/10/01 08:26:43 INFO Received complete push request method=POST path=/api/pushes/1/complete26952026/10/01 08:26:43 WARN Failed to register uploaded object key=z2klzl9wzk6996gls5vwnp2plgnnay8v.narinfo error="server returned 404: 404 page not found\n"26962026/10/01 08:26:43 INFO Upload complete. (51ms)26972026-10-01 08:26:43.424 UTC [1610] ERROR: relation "goose_db_version" does not exist at character 3626982026-10-01 08:26:43.424 UTC [1610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC26992026/10/01 08:26:43 OK 20241026095416_initial_model.sql (8.13ms)27002026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)27012026/10/01 08:26:43 OK 20251218171726_add_pins.sql (2.14ms)27022026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (2.78ms)27032026/10/01 08:26:43 OK 20241026095416_initial_model.sql (8.14ms)27042026/10/01 08:26:43 OK 20260905000000_add_claims.sql (3.28ms)27052026/10/01 08:26:43 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)27062026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (1.76ms)27072026/10/01 08:26:43 OK 20251218171726_add_pins.sql (2.5ms)27082026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (1.66ms)27092026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000027102026/10/01 08:26:43 OK 1_commit_pending_closure.sql (1.49ms)27112026/10/01 08:26:43 OK 20260628120000_add_object_size_and_stats.sql (2.13ms)27122026/10/01 08:26:43 OK 2_object_stats_trigger.sql (726.69µs)27132026/10/01 08:26:43 OK 3_commit_push.sql (1.09ms)27142026/10/01 08:26:43 goose: up to current file version: 327152026/10/01 08:26:43 OK 20260905000000_add_claims.sql (2.24ms)27162026/10/01 08:26:43 OK 20260920000000_drop_claims.sql (1.5ms)27172026/10/01 08:26:43 OK 20260923120000_add_pushes.sql (1.44ms)27182026/10/01 08:26:43 goose: successfully migrated database to version: 2026092312000027192026/10/01 08:26:43 OK 1_commit_pending_closure.sql (1.61ms)27202026/10/01 08:26:43 OK 2_object_stats_trigger.sql (1.16ms)27212026/10/01 08:26:43 INFO All 1 paths already cached27222026/10/01 08:26:43 OK 3_commit_push.sql (557.17µs)27232026/10/01 08:26:43 goose: up to current file version: 32724=== NAME TestClientIntegration2725 client_integration_test.go:312: Retrieved narinfo from S3:2726 StorePath: /build/TestClientIntegration94001666/002/store/z2klzl9wzk6996gls5vwnp2plgnnay8v-test-file.txt2727 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2728 Compression: zstd2729 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12730 NarSize: 1522731 References: 2732 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12733 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2734 client_integration_test.go:313: Decompressed .ls content (64 bytes):2735 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2736 client_integration_test.go:316: Testing garbage collection...2737--- PASS: TestMetricsInventory (0.46s)2738=== NAME TestNARDeduplicationMetadataUploadBug2739 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug879294961/001/store/dza3rn5qy2bx8gjfan08ri4fg8zlb712-file1.txt27402026/10/01 08:26:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"27412026/10/01 08:26:43 WARN mTLS auth: bound subjects configured but subject DN unavailable27422026/10/01 08:26:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2743--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.40s)27442026/10/01 08:26:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.488384ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2745=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2746=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2747=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2748=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2749=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2750=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2751=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2752=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2753=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2754=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2755=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured27562026/10/01 08:26:43 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]2757=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected27582026/10/01 08:26:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures27592026/10/01 08:26:43 INFO Garbage collection started27602026/10/01 08:26:43 WARN Authentication failed token_preview=eyJhbGciOi...TMYoEwMKuw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2761--- PASS: TestService_AuthMiddleware_OIDC (0.44s)2762 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2763 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2764 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2765 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)27662026/10/01 08:26:43 INFO Aborted multipart uploads count=027672026/10/01 08:26:43 WARN Force mode enabled - objects will be deleted immediately without grace period2768--- PASS: TestService_ReadScope_PublicByDefault (0.40s)2769=== NAME TestOrphanedObjectsGC2770 orphaned_objects_gc_test.go:290: GC Test Summary:2771 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2772 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2773 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2774 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2775 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2776--- PASS: TestOrphanedObjectsGC (0.88s)27772026/10/01 08:26:43 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=027782026/10/01 08:26:43 INFO Vacuumed table table=pending_closures2779=== NAME TestClientCADerivations2780 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features27812026/10/01 08:26:43 INFO Vacuumed table table=pending_objects2782 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2783 error: binary cache 's3://bucket56?endpoint=http://localhost:45253®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1728168817/001/store'2784 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 127852026/10/01 08:26:43 INFO Vacuumed table table=multipart_uploads27862026/10/01 08:26:43 INFO Vacuumed table table=closures27872026/10/01 08:26:43 INFO Received cleanup request method=DELETE path=/api/pending_closures27882026/10/01 08:26:43 INFO Vacuumed table table=objects2789--- PASS: TestClientCADerivations (0.99s)27902026/10/01 08:26:43 INFO Aborted multipart uploads count=12791--- PASS: TestMultipartCleanup (0.60s)2792--- PASS: TestService_ReadAuthMiddleware (0.34s)27932026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes27942026/10/01 08:26:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)27952026/10/01 08:26:43 INFO Uploading dza3rn5qy2bx8gjfan08ri4fg8zlb712-file1.txt (160B)27962026/10/01 08:26:43 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"27972026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign27982026/10/01 08:26:43 WARN Failed to register uploaded object key=dza3rn5qy2bx8gjfan08ri4fg8zlb712.ls error="server returned 404: 404 page not found\n"27992026/10/01 08:26:43 INFO Signed narinfos id=1 count=128002026/10/01 08:26:43 INFO Uploading 1 narinfos28012026/10/01 08:26:43 INFO Received complete push request method=POST path=/api/pushes/1/complete28022026/10/01 08:26:43 WARN Failed to register uploaded object key=dza3rn5qy2bx8gjfan08ri4fg8zlb712.narinfo error="server returned 404: 404 page not found\n"28032026/10/01 08:26:43 INFO Upload complete. (54ms)2804--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.36s)2805=== NAME TestNARDeduplicationMetadataUploadBug2806 metadata_upload_test.go:54: Retrieved narinfo from S3:2807 StorePath: /build/TestNARDeduplicationMetadataUploadBug879294961/001/store/dza3rn5qy2bx8gjfan08ri4fg8zlb712-file1.txt2808 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2809 Compression: zstd2810 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2811 NarSize: 1602812 References: 2813 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2814 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2815 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2816 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}28172026/10/01 08:26:43 INFO Received uploads request method=POST path=/api/pending_closures2818 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug879294961/001/store/9jxfjdjbrdp7xrppmv3hzganbmnv17sk-file2.txt28192026/10/01 08:26:43 INFO Aborted multipart uploads count=028202026/10/01 08:26:43 WARN Force mode enabled - objects will be deleted immediately without grace period28212026/10/01 08:26:43 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=028222026/10/01 08:26:43 INFO Vacuumed table table=pending_closures28232026/10/01 08:26:43 INFO Vacuumed table table=pending_objects28242026/10/01 08:26:43 INFO Vacuumed table table=multipart_uploads28252026/10/01 08:26:43 INFO Vacuumed table table=closures28262026/10/01 08:26:43 INFO Vacuumed table table=objects28272026/10/01 08:26:43 INFO Received uploads request method=POST path=/api/pending_closures28282026/10/01 08:26:43 INFO Aborted multipart uploads count=028292026/10/01 08:26:43 WARN Force mode enabled - objects will be deleted immediately without grace period28302026/10/01 08:26:43 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=028312026/10/01 08:26:43 INFO Vacuumed table table=pending_closures28322026/10/01 08:26:43 INFO Vacuumed table table=pending_objects28332026/10/01 08:26:43 INFO Vacuumed table table=multipart_uploads28342026/10/01 08:26:43 INFO Vacuumed table table=closures28352026/10/01 08:26:43 INFO Vacuumed table table=objects2836--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2837 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.35s)2838 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.40s)28392026/10/01 08:26:43 INFO Received push request method=POST path=/api/pushes28402026/10/01 08:26:43 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)28412026/10/01 08:26:43 WARN Failed to register uploaded object key=9jxfjdjbrdp7xrppmv3hzganbmnv17sk.ls error="server returned 404: 404 page not found\n"28422026/10/01 08:26:43 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign28432026/10/01 08:26:43 INFO Signed narinfos id=2 count=128442026/10/01 08:26:43 INFO Uploading 1 narinfos2845=== RUN TestService_RequireScope_OIDC/builder_may_write2846=== PAUSE TestService_RequireScope_OIDC/builder_may_write2847=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2848=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2849=== RUN TestService_RequireScope_OIDC/ops_may_admin2850=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2851=== RUN TestService_RequireScope_OIDC/ops_may_not_write2852=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2853=== RUN TestService_RequireScope_OIDC/reader_may_not_write2854=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2855=== RUN TestService_RequireScope_OIDC/static_token_may_admin2856=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2857=== RUN TestService_RequireScope_OIDC/static_token_may_write2858=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2859=== RUN TestService_RequireScope_OIDC/reader_may_read2860=== PAUSE TestService_RequireScope_OIDC/reader_may_read2861=== RUN TestService_RequireScope_OIDC/writer_implies_read2862=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2863=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2864=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2865=== CONT TestService_RequireScope_OIDC/builder_may_write2866=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2867=== CONT TestService_RequireScope_OIDC/reader_may_read2868=== CONT TestService_RequireScope_OIDC/writer_implies_read2869=== CONT TestService_RequireScope_OIDC/reader_may_not_write2870=== CONT TestService_RequireScope_OIDC/ops_may_not_write2871=== CONT TestService_RequireScope_OIDC/ops_may_admin2872=== CONT TestService_RequireScope_OIDC/static_token_may_write2873=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2874=== CONT TestService_RequireScope_OIDC/static_token_may_admin28752026/10/01 08:26:43 INFO Received complete push request method=POST path=/api/pushes/2/complete28762026/10/01 08:26:43 WARN Failed to register uploaded object key=9jxfjdjbrdp7xrppmv3hzganbmnv17sk.narinfo error="server returned 404: 404 page not found\n"2877--- PASS: TestService_RequireScope_OIDC (0.48s)2878 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2879 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2880 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2881 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2882 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2883 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2884 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2885 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2886 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2887 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)28882026/10/01 08:26:43 INFO Upload complete. (47ms)28892026/10/01 08:26:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=418.258613ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2890=== NAME TestNARDeduplicationMetadataUploadBug2891 metadata_upload_test.go:76: Retrieved narinfo from S3:2892 StorePath: /build/TestNARDeduplicationMetadataUploadBug879294961/001/store/9jxfjdjbrdp7xrppmv3hzganbmnv17sk-file2.txt2893 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2894 Compression: zstd2895 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2896 NarSize: 1602897 References: 2898 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2899 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2900 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2901 {"version":1,"root":{"type":"regular","size":44}}2902--- PASS: TestNARDeduplicationMetadataUploadBug (0.75s)2903--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2904 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2905 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2906 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.55s)29072026/10/01 08:26:43 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"29082026/10/01 08:26:43 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"29092026/10/01 08:26:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=879.219296ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2910=== NAME TestOrphanedObjectsGCStressTest2911 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2912 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion29132026/10/01 08:26:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.505540263s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2914 orphaned_objects_gc_test.go:509: Stress test completed successfully:2915 orphaned_objects_gc_test.go:510: - Active objects preserved: 202916 orphaned_objects_gc_test.go:511: - Objects deleted: 2102917 orphaned_objects_gc_test.go:512: - Total GC'd: 2102918--- PASS: TestOrphanedObjectsGCStressTest (2.30s)29192026/10/01 08:26:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02920=== NAME TestPinProtectsFromGC2921 client_integration_test.go:794: Pin successfully protected closure from garbage collection2922--- PASS: TestPinProtectsFromGC (2.89s)29232026/10/01 08:26:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02924=== NAME TestClientIntegration2925 client_integration_test.go:323: Objects in database after GC:2926 client_integration_test.go:323: Successfully deleted all objects with GC --force2927--- PASS: TestClientIntegration (2.69s)29282026/10/01 08:26:46 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-config29292026/10/01 08:26:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.160772ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29302026/10/01 08:26:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.558857ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29312026/10/01 08:26:46 WARN Rate limiter enabled after throttle name=s3-test rate=529322026/10/01 08:26:46 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2933=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2934 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102935 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002936--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.76s)29372026/10/01 08:26:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=746.457174ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29382026/10/01 08:26:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.469300978s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29392026/10/01 08:26:49 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"29402026/10/01 08:26:49 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-config29412026/10/01 08:26:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.410752ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29422026/10/01 08:26:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=403.811945ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29432026/10/01 08:26:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=865.205829ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29442026/10/01 08:26:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.589623001s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config29452026/10/01 08:26:52 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_closures29462026/10/01 08:26:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.555097ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29472026/10/01 08:26:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=413.087115ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29482026/10/01 08:26:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=744.855211ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures29492026/10/01 08:26:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.755421046s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2950--- PASS: TestClientErrorHandling (0.00s)2951 --- PASS: TestClientErrorHandling/InvalidStorePath (0.38s)2952 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.50s)2953 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.58s)2954PASS29552026-10-01 08:26:56.159 UTC [128] LOG: received smart shutdown request29562026-10-01 08:26:56.163 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 129572026-10-01 08:26:56.171 UTC [133] LOG: shutting down29582026-10-01 08:26:56.172 UTC [133] LOG: checkpoint starting: shutdown immediate29592026-10-01 08:26:57.753 UTC [133] LOG: checkpoint complete: wrote 10494 buffers (64.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 22 recycled; write=0.240 s, sync=1.294 s, total=1.582 s; sync files=26627, longest=0.013 s, average=0.001 s; distance=362321 kB, estimate=362321 kB; lsn=0/1793A1B8, redo lsn=0/1793A1B829602026-10-01 08:26:57.829 UTC [128] LOG: database system is shut down2961Running OIDC tests...2962=== RUN TestAudienceForIssuer2963=== PAUSE TestAudienceForIssuer2964=== RUN TestGlobMatch2965=== PAUSE TestGlobMatch2966=== RUN TestValidateToken_ValidToken2967=== PAUSE TestValidateToken_ValidToken2968=== RUN TestValidateToken_WrongAudience2969=== PAUSE TestValidateToken_WrongAudience2970=== RUN TestValidateToken_Expired2971=== PAUSE TestValidateToken_Expired2972=== RUN TestValidateToken_BoundClaimsMismatch2973=== PAUSE TestValidateToken_BoundClaimsMismatch2974=== RUN TestValidateToken_BoundSubjectMismatch2975=== PAUSE TestValidateToken_BoundSubjectMismatch2976=== RUN TestValidateToken_MultipleProviders2977=== PAUSE TestValidateToken_MultipleProviders2978=== RUN TestValidateToken_NoMatchingProvider2979=== PAUSE TestValidateToken_NoMatchingProvider2980=== RUN TestValidateToken_KubernetesServiceAccount2981=== PAUSE TestValidateToken_KubernetesServiceAccount2982=== RUN TestNewValidator_KubernetesRequiresCA2983=== PAUSE TestNewValidator_KubernetesRequiresCA2984=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2985=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2986=== RUN TestPins_ReservedForMatchingRule2987=== PAUSE TestPins_ReservedForMatchingRule2988=== RUN TestPins_TopLevelShorthand2989=== PAUSE TestPins_TopLevelShorthand2990=== RUN TestPins_ConfigValidation2991=== PAUSE TestPins_ConfigValidation2992=== RUN TestScopes_LegacyProviderDefaultsToWrite2993=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2994=== RUN TestScopes_Rules2995=== PAUSE TestScopes_Rules2996=== RUN TestScopes_ConfigValidation2997=== PAUSE TestScopes_ConfigValidation2998=== CONT TestAudienceForIssuer2999=== CONT TestValidateToken_KubernetesServiceAccount3000=== CONT TestPins_ConfigValidation3001=== CONT TestScopes_ConfigValidation3002=== CONT TestScopes_Rules3003=== CONT TestScopes_LegacyProviderDefaultsToWrite3004=== CONT TestValidateToken_BoundClaimsMismatch3005--- PASS: TestAudienceForIssuer (0.00s)3006=== CONT TestValidateToken_NoMatchingProvider3007=== CONT TestValidateToken_MultipleProviders3008=== CONT TestValidateToken_Expired3009=== CONT TestValidateToken_WrongAudience3010=== CONT TestValidateToken_ValidToken3011=== CONT TestValidateToken_BoundSubjectMismatch3012=== CONT TestGlobMatch3013=== RUN TestGlobMatch/foo_foo3014=== PAUSE TestGlobMatch/foo_foo3015=== RUN TestGlobMatch/foo_bar3016=== PAUSE TestGlobMatch/foo_bar3017=== RUN TestGlobMatch/*_3018=== PAUSE TestGlobMatch/*_3019=== RUN TestGlobMatch/*_anything3020=== PAUSE TestGlobMatch/*_anything3021=== RUN TestGlobMatch/foo*_foo3022=== PAUSE TestGlobMatch/foo*_foo3023=== RUN TestGlobMatch/foo*_foobar3024=== PAUSE TestGlobMatch/foo*_foobar3025=== RUN TestGlobMatch/foo*_bar3026=== PAUSE TestGlobMatch/foo*_bar3027=== RUN TestGlobMatch/*bar_bar3028=== PAUSE TestGlobMatch/*bar_bar3029=== RUN TestGlobMatch/*bar_foobar3030=== PAUSE TestGlobMatch/*bar_foobar3031=== RUN TestGlobMatch/*bar_foo3032=== PAUSE TestGlobMatch/*bar_foo3033=== RUN TestGlobMatch/foo*bar_foobar3034=== PAUSE TestGlobMatch/foo*bar_foobar3035=== RUN TestGlobMatch/foo*bar_foo123bar3036=== PAUSE TestGlobMatch/foo*bar_foo123bar3037=== RUN TestGlobMatch/foo*bar_foobarbaz3038=== PAUSE TestGlobMatch/foo*bar_foobarbaz3039=== RUN TestGlobMatch/*/*_foo/bar3040=== PAUSE TestGlobMatch/*/*_foo/bar3041=== RUN TestGlobMatch/*/*_foo3042=== PAUSE TestGlobMatch/*/*_foo3043=== RUN TestGlobMatch/refs/heads/*_refs/heads/main3044=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main3045=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.03046=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.03047=== RUN TestGlobMatch/refs/*/main_refs/heads/main3048=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main3049=== RUN TestGlobMatch/fo?_foo3050=== PAUSE TestGlobMatch/fo?_foo3051=== RUN TestGlobMatch/fo?_fo3052=== PAUSE TestGlobMatch/fo?_fo3053=== RUN TestGlobMatch/fo?_fooo3054=== PAUSE TestGlobMatch/fo?_fooo3055=== RUN TestGlobMatch/?oo_foo3056=== PAUSE TestGlobMatch/?oo_foo3057=== RUN TestGlobMatch/?oo_boo3058=== PAUSE TestGlobMatch/?oo_boo3059=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3060=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3061=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3062=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3063=== CONT TestGlobMatch/foo_foo3064=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main3065=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main3066=== CONT TestGlobMatch/?oo_boo3067=== CONT TestGlobMatch/?oo_foo3068=== CONT TestGlobMatch/fo?_fooo3069=== CONT TestGlobMatch/fo?_fo3070=== CONT TestGlobMatch/fo?_foo3071=== CONT TestGlobMatch/refs/*/main_refs/heads/main3072=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.03073=== CONT TestGlobMatch/refs/heads/*_refs/heads/main3074=== CONT TestGlobMatch/*/*_foo3075=== CONT TestGlobMatch/*/*_foo/bar3076=== CONT TestGlobMatch/foo*bar_foobarbaz3077=== CONT TestGlobMatch/foo*bar_foo123bar3078=== CONT TestGlobMatch/foo*bar_foobar3079=== CONT TestGlobMatch/*bar_foo3080=== CONT TestGlobMatch/*bar_foobar3081=== CONT TestGlobMatch/*bar_bar3082=== CONT TestGlobMatch/foo*_bar3083=== CONT TestGlobMatch/foo*_foobar3084=== CONT TestGlobMatch/foo*_foo3085=== CONT TestGlobMatch/*_anything3086=== CONT TestGlobMatch/*_3087=== CONT TestGlobMatch/foo_bar3088=== CONT TestPins_TopLevelShorthand3089=== CONT TestValidateToken_KubernetesIssuerFromOwnToken3090=== CONT TestNewValidator_KubernetesRequiresCA3091=== CONT TestPins_ReservedForMatchingRule3092--- PASS: TestScopes_ConfigValidation (0.00s)3093--- PASS: TestPins_ConfigValidation (0.00s)3094--- PASS: TestGlobMatch (0.00s)3095 --- PASS: TestGlobMatch/foo_foo (0.00s)3096 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)3097 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)3098 --- PASS: TestGlobMatch/?oo_boo (0.00s)3099 --- PASS: TestGlobMatch/?oo_foo (0.00s)3100 --- PASS: TestGlobMatch/fo?_fooo (0.00s)3101 --- PASS: TestGlobMatch/fo?_fo (0.00s)3102 --- PASS: TestGlobMatch/fo?_foo (0.00s)3103 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)3104 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)3105 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)3106 --- PASS: TestGlobMatch/*/*_foo (0.00s)3107 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)3108 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)3109 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)3110 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)3111 --- PASS: TestGlobMatch/*bar_foo (0.00s)3112 --- PASS: TestGlobMatch/*bar_foobar (0.00s)3113 --- PASS: TestGlobMatch/*bar_bar (0.00s)3114 --- PASS: TestGlobMatch/foo*_bar (0.00s)3115 --- PASS: TestGlobMatch/foo*_foobar (0.00s)3116 --- PASS: TestGlobMatch/foo*_foo (0.00s)3117 --- PASS: TestGlobMatch/*_anything (0.00s)3118 --- PASS: TestGlobMatch/*_ (0.00s)3119 --- PASS: TestGlobMatch/foo_bar (0.00s)31202026/10/01 08:26:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44209/oidc3121--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)31222026/10/01 08:26:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38757/oidc3123--- PASS: TestPins_ReservedForMatchingRule (0.02s)31242026/10/01 08:26:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34803/oidc3125--- PASS: TestValidateToken_Expired (0.05s)31262026/10/01 08:26:59 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40023/oidc31272026/10/01 08:26:59 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37237/oidc31282026/10/01 08:26:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43583/oidc3129--- PASS: TestValidateToken_MultipleProviders (0.06s)3130--- PASS: TestValidateToken_ValidToken (0.06s)31312026/10/01 08:26:59 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12331322026/10/01 08:26:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41331/oidc3133--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)3134--- PASS: TestScopes_Rules (0.08s)31352026/10/01 08:26:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36725/oidc3136--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)31372026/10/01 08:26:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38141/oidc31382026/10/01 08:26:59 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:418673139--- PASS: TestPins_TopLevelShorthand (0.09s)3140--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)31412026/10/01 08:26:59 http: TLS handshake error from 127.0.0.1:59876: remote error: tls: bad certificate3142--- PASS: TestNewValidator_KubernetesRequiresCA (0.11s)31432026/10/01 08:26:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38373/oidc3144--- PASS: TestValidateToken_WrongAudience (0.12s)31452026/10/01 08:26:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38629/oidc3146--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.16s)31472026/10/01 08:26:59 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35805/oidc3148--- PASS: TestValidateToken_NoMatchingProvider (0.18s)3149PASS3150Running hook tests...3151=== RUN TestSendPathsEmpty3152=== PAUSE TestSendPathsEmpty3153=== RUN TestQueueEnqueueAndFetch3154=== PAUSE TestQueueEnqueueAndFetch3155=== RUN TestQueueDeduplication3156=== PAUSE TestQueueDeduplication3157=== RUN TestQueueRemove3158=== PAUSE TestQueueRemove3159=== RUN TestQueueFetchBatchLimit3160=== PAUSE TestQueueFetchBatchLimit3161=== RUN TestQueueRetryMovesToBack3162=== PAUSE TestQueueRetryMovesToBack3163=== RUN TestQueueFetchRemoveLifecycle3164=== PAUSE TestQueueFetchRemoveLifecycle3165=== RUN TestQueueConcurrentWriters3166=== PAUSE TestQueueConcurrentWriters3167=== RUN TestQueueRemoveLargeClosure3168=== PAUSE TestQueueRemoveLargeClosure3169=== RUN TestServerClientIntegration3170=== PAUSE TestServerClientIntegration3171=== RUN TestServerQueueError3172=== PAUSE TestServerQueueError3173=== RUN TestGetListenerSocketActivation3174 server_test.go:210: === RUN TestGetListenerSocketActivation3175 --- PASS: TestGetListenerSocketActivation (0.00s)3176 PASS3177 3178--- PASS: TestGetListenerSocketActivation (0.01s)3179=== RUN TestDrainIsolatesPoisonPath3180=== PAUSE TestDrainIsolatesPoisonPath3181=== RUN TestRunNotBlockedByPoisonHead3182=== PAUSE TestRunNotBlockedByPoisonHead3183=== RUN TestDrainGivesUpWhenServerDown3184=== PAUSE TestDrainGivesUpWhenServerDown3185=== RUN TestFailedPathPrunedByLaterClosure3186=== PAUSE TestFailedPathPrunedByLaterClosure3187=== RUN TestWorkerUploadsAndRemoves3188=== PAUSE TestWorkerUploadsAndRemoves3189=== RUN TestWorkerSkipsGCdPaths3190=== PAUSE TestWorkerSkipsGCdPaths3191=== RUN TestWorkerPrunesClosureDeps3192=== PAUSE TestWorkerPrunesClosureDeps3193=== RUN TestDrainTimeout3194=== PAUSE TestDrainTimeout3195=== CONT TestSendPathsEmpty3196=== CONT TestServerQueueError3197--- PASS: TestSendPathsEmpty (0.00s)3198=== CONT TestServerClientIntegration3199=== CONT TestQueueRemoveLargeClosure3200=== CONT TestQueueConcurrentWriters3201=== CONT TestQueueFetchRemoveLifecycle3202=== CONT TestQueueRetryMovesToBack3203=== CONT TestQueueFetchBatchLimit3204=== CONT TestQueueRemove3205=== CONT TestQueueDeduplication3206=== CONT TestWorkerUploadsAndRemoves3207=== CONT TestDrainTimeout3208=== CONT TestQueueEnqueueAndFetch32092026/10/01 08:26:59 ERROR Failed to queue paths error="permission denied" count=13210=== CONT TestDrainGivesUpWhenServerDown3211=== CONT TestWorkerPrunesClosureDeps3212=== CONT TestFailedPathPrunedByLaterClosure3213=== CONT TestRunNotBlockedByPoisonHead3214--- PASS: TestServerClientIntegration (0.00s)3215=== CONT TestDrainIsolatesPoisonPath3216=== CONT TestWorkerSkipsGCdPaths3217--- PASS: TestServerQueueError (0.00s)32182026/10/01 08:26:59 INFO Upload queue status pending=232192026/10/01 08:26:59 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3210473471/002/nonexistent32202026/10/01 08:26:59 INFO Uploading batch count=132212026/10/01 08:26:59 ERROR Upload failed error="upload failed" count=132222026/10/01 08:26:59 INFO Uploading batch count=432232026/10/01 08:26:59 ERROR Upload failed error="upload failed" count=432242026/10/01 08:26:59 INFO Upload queue status pending=332252026/10/01 08:26:59 INFO Uploading batch count=132262026/10/01 08:26:59 ERROR Upload failed error="upload failed" count=132272026/10/01 08:26:59 INFO Uploading batch count=232282026/10/01 08:26:59 INFO Upload queue status pending=232292026/10/01 08:26:59 INFO Uploading batch count=132302026/10/01 08:26:59 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2113877871/002/bbb32312026/10/01 08:26:59 INFO Uploading batch count=232322026/10/01 08:26:59 ERROR Upload failed error="upload failed" count=23233--- PASS: TestQueueDeduplication (0.02s)32342026/10/01 08:26:59 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2442417821/002/a32352026/10/01 08:26:59 INFO Upload queue status pending=23236--- PASS: TestQueueFetchBatchLimit (0.02s)32372026/10/01 08:26:59 INFO Uploading batch count=132382026/10/01 08:26:59 INFO Uploading batch count=232392026/10/01 08:26:59 INFO Uploading batch count=132402026/10/01 08:26:59 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2442417821/002/b3241--- PASS: TestQueueEnqueueAndFetch (0.02s)3242--- PASS: TestQueueRetryMovesToBack (0.02s)32432026/10/01 08:26:59 INFO Uploading batch count=13244--- PASS: TestQueueFetchRemoveLifecycle (0.02s)3245--- PASS: TestQueueRemove (0.02s)32462026/10/01 08:26:59 INFO Uploading batch count=232472026/10/01 08:26:59 ERROR Upload failed error="upload failed" count=232482026/10/01 08:26:59 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2442417821/002/c32492026/10/01 08:26:59 INFO Uploading batch count=132502026/10/01 08:26:59 ERROR Upload failed error="upload failed" count=132512026/10/01 08:26:59 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2442417821/002/d32522026/10/01 08:26:59 INFO Uploading batch count=132532026/10/01 08:26:59 ERROR Upload failed error="upload failed" count=132542026/10/01 08:26:59 INFO Uploading batch count=132552026/10/01 08:26:59 ERROR Upload failed error="upload failed" count=132562026/10/01 08:26:59 INFO Uploading batch count=232572026/10/01 08:26:59 ERROR Upload failed error="upload failed" count=232582026/10/01 08:26:59 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2442417821/002/e3259--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)32602026/10/01 08:26:59 ERROR Drain finished with paths left in queue remaining=132612026/10/01 08:26:59 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2442417821/002/f32622026/10/01 08:26:59 ERROR Drain finished with paths left in queue remaining=103263--- PASS: TestDrainIsolatesPoisonPath (0.02s)3264--- PASS: TestDrainGivesUpWhenServerDown (0.03s)3265--- PASS: TestWorkerPrunesClosureDeps (0.04s)3266--- PASS: TestWorkerSkipsGCdPaths (0.04s)3267--- PASS: TestWorkerUploadsAndRemoves (0.04s)3268--- PASS: TestQueueRemoveLargeClosure (0.07s)32692026/10/01 08:26:59 ERROR Upload failed error="context deadline exceeded" count=232702026/10/01 08:26:59 ERROR Drain finished with paths left in queue remaining=43271--- PASS: TestDrainTimeout (0.22s)3272--- PASS: TestQueueConcurrentWriters (0.38s)32732026/10/01 08:27:00 INFO Uploading batch count=132742026/10/01 08:27:00 INFO Uploading batch count=132752026/10/01 08:27:00 INFO Uploading batch count=132762026/10/01 08:27:00 ERROR Upload failed error="upload failed" count=132772026/10/01 08:27:00 INFO Uploading batch count=132782026/10/01 08:27:00 ERROR Upload failed error="upload failed" count=132792026/10/01 08:27:00 INFO Uploading batch count=132802026/10/01 08:27:00 ERROR Upload failed error="upload failed" count=132812026/10/01 08:27:00 INFO Uploading batch count=132822026/10/01 08:27:00 ERROR Upload failed error="upload failed" count=132832026/10/01 08:27:00 ERROR Drain finished with paths left in queue remaining=13284--- PASS: TestRunNotBlockedByPoisonHead (1.03s)3285PASS