niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #262
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestEncodeNixBase32WithRealHash97=== CONT TestPathInfoCACompatibility98=== RUN TestPathInfoCACompatibility/null_ca_field99--- PASS: TestEncodeNixBase32WithRealHash (0.00s)100=== CONT TestParsePathInfoJSONMultiplePaths101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102--- PASS: TestShellSplit (0.00s)103=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths104=== CONT TestSetClientTLS105=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths106=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths107=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths108=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths109=== CONT TestResolveStorePath110=== CONT TestSetClientTLSErrors111=== CONT TestStreamPushGivesUpOnDeadServer112=== CONT TestStreamPushRequestLine113=== CONT TestSetClientTLSDoesNotMutateDefaultTransport114=== PAUSE TestPathInfoCACompatibility/null_ca_field115=== RUN TestPathInfoCACompatibility/old_string_format_-_text116=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text117=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive118=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive119=== RUN TestPathInfoCACompatibility/new_structured_format_-_text120=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text121=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method122=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method123=== CONT TestStreamPushReportsSignatures124=== CONT TestClientSignaturesByStorePath125--- PASS: TestClientSignaturesByStorePath (0.00s)126=== CONT TestConvertHashToNix32127=== RUN TestConvertHashToNix32/SRI_format_to_Nix32128=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32129=== RUN TestConvertHashToNix32/already_Nix32_format130=== PAUSE TestConvertHashToNix32/already_Nix32_format131=== RUN TestConvertHashToNix32/invalid_format132=== PAUSE TestConvertHashToNix32/invalid_format133=== CONT TestParsePathInfoJSON134=== RUN TestParsePathInfoJSON/Nix_format135=== PAUSE TestParsePathInfoJSON/Nix_format136=== RUN TestParsePathInfoJSON/Lix_format1372026/09/23 13:01:39 ERROR Upload failed error="connection refused" count=20138=== PAUSE TestParsePathInfoJSON/Lix_format139=== RUN TestParsePathInfoJSON/empty_input1402026/09/23 13:01:39 ERROR Server seems unavailable, giving up on batch untried=17141=== PAUSE TestParsePathInfoJSON/empty_input142=== RUN TestParsePathInfoJSON/whitespace_only143=== PAUSE TestParsePathInfoJSON/whitespace_only144=== RUN TestParsePathInfoJSON/invalid_JSON145=== PAUSE TestParsePathInfoJSON/invalid_JSON146=== CONT TestPathInfoHashCompatibility147=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)148=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon150=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon151=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI152=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI153=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512154=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512155=== CONT TestGetStorePathHash156=== RUN TestGetStorePathHash/valid_store_path157=== PAUSE TestGetStorePathHash/valid_store_path158=== RUN TestGetStorePathHash/basename_without_hyphen_should_error159=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error160=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error161=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error162=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error1632026/09/23 13:01:39 ERROR Upload failed error=boom count=1164=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error1652026/09/23 13:01:39 ERROR Upload failed error=boom count=1166--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)167--- PASS: TestStreamPushReportsSignatures (0.00s)168=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess169=== CONT TestRateLimiterFeedback170=== RUN TestRateLimiterFeedback/429_enables_limiter171=== CONT TestStreamPushBatchesUnderLoad1722026/09/23 13:01:39 WARN Rate limiter enabled after throttle name=server-test rate=5173=== PAUSE TestRateLimiterFeedback/429_enables_limiter174=== RUN TestRateLimiterFeedback/503_enables_limiter175=== PAUSE TestRateLimiterFeedback/503_enables_limiter176=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter177=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter178=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter179=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter180=== CONT TestStreamPushIsolatesFailures1812026/09/23 13:01:39 ERROR Upload failed error="bad path" count=3182--- PASS: TestStreamPushIsolatesFailures (0.00s)183=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths184--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)185 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)186 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)187=== CONT TestPartSizeForNAR188=== RUN TestPartSizeForNAR/zero_stays_at_minimum189=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum190=== RUN TestPartSizeForNAR/small_stays_at_minimum191=== PAUSE TestPartSizeForNAR/small_stays_at_minimum192=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum193=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum194=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts195=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts196=== RUN TestPartSizeForNAR/1_TiB197=== PAUSE TestPartSizeForNAR/1_TiB198=== RUN TestPartSizeForNAR/5_TiB_S3_max_object199=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object200=== RUN TestPartSizeForNAR/capped_at_5_GiB201=== PAUSE TestPartSizeForNAR/capped_at_5_GiB202=== CONT TestEncodeNixBase32203=== RUN TestEncodeNixBase32/test_string_hash204=== PAUSE TestEncodeNixBase32/test_string_hash205=== RUN TestEncodeNixBase32/empty_input206=== PAUSE TestEncodeNixBase32/empty_input207=== CONT TestDumpPathWriterError2082026/09/23 13:01:39 WARN Rate limiter enabled after throttle name=server-test rate=52092026/09/23 13:01:39 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:571602102026/09/23 13:01:39 WARN Rate limiter backed off name=server-test rate=52112026/09/23 13:01:39 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57160212=== CONT TestDumpPathSingleFile213--- PASS: TestDoServerRequestAttachesToken (0.00s)214--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)215=== CONT TestDumpPathMatchesNix216--- PASS: TestStreamPushRequestLine (0.01s)217=== CONT TestUploadMultipart_SupersededByPeer218=== RUN TestUploadMultipart_SupersededByPeer/exists219=== PAUSE TestUploadMultipart_SupersededByPeer/exists220=== RUN TestUploadMultipart_SupersededByPeer/missing221=== PAUSE TestUploadMultipart_SupersededByPeer/missing222=== CONT TestStreamPushReportsEveryPath223--- PASS: TestStreamPushReportsEveryPath (0.00s)224=== CONT TestShellSplitErrors225--- PASS: TestShellSplitErrors (0.00s)226=== CONT TestScriptTokenCachesUntilRefresh227--- PASS: TestResolveStorePath (0.01s)228=== CONT TestScriptTokenEmptyCommand229--- PASS: TestScriptTokenEmptyCommand (0.00s)230=== CONT TestScriptTokenScriptFails231=== RUN TestSetClientTLS/rejects_connection_without_client_cert232=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert233=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA234=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA235=== RUN TestSetClientTLS/preserves_debug_logging_transport236=== PAUSE TestSetClientTLS/preserves_debug_logging_transport237=== CONT TestScriptTokenBadJSON238--- PASS: TestScriptTokenScriptFails (0.00s)239=== CONT TestScriptTokenEmptyToken240=== RUN TestSetClientTLSErrors/missing_cert_file241=== PAUSE TestSetClientTLSErrors/missing_cert_file242=== RUN TestSetClientTLSErrors/missing_key_file243=== PAUSE TestSetClientTLSErrors/missing_key_file244=== RUN TestSetClientTLSErrors/missing_ca_file245=== PAUSE TestSetClientTLSErrors/missing_ca_file246=== RUN TestSetClientTLSErrors/invalid_ca_file247=== PAUSE TestSetClientTLSErrors/invalid_ca_file248=== CONT TestCaseHackSuffix249--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)250=== CONT TestUploadMultipart_PartsInParallel251--- PASS: TestScriptTokenBadJSON (0.01s)252=== CONT TestFileTokenMissing253--- PASS: TestScriptTokenEmptyToken (0.01s)254=== CONT TestFilterOversizedClosures255=== RUN TestFilterOversizedClosures/no_limit_keeps_everything256=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything257=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped258=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped259=== RUN TestFilterOversizedClosures/all_closures_skipped260=== PAUSE TestFilterOversizedClosures/all_closures_skipped261=== CONT TestScriptTokenNoExpiryRerunsEveryCall262--- PASS: TestFileTokenMissing (0.00s)263=== CONT TestFileTokenEmpty264--- PASS: TestFileTokenEmpty (0.00s)265=== CONT TestRegisterUploadedObjectReusesConnections266--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)267=== CONT TestPathInfoCACompatibility/null_ca_field268=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method269=== CONT TestPathInfoCACompatibility/new_structured_format_-_text270=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive271=== CONT TestPathInfoCACompatibility/old_string_format_-_text272--- PASS: TestPathInfoCACompatibility (0.00s)273 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)274 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)275 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)276 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)277 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)278=== CONT TestFileTokenReadsAndCaches279--- PASS: TestFileTokenReadsAndCaches (0.00s)280=== CONT TestStaticToken281--- PASS: TestStaticToken (0.00s)282=== CONT TestConvertHashToNix32/SRI_format_to_Nix32283=== CONT TestParsePathInfoJSON/Nix_format284=== CONT TestConvertHashToNix32/invalid_format285=== CONT TestConvertHashToNix32/already_Nix32_format286--- PASS: TestConvertHashToNix32 (0.00s)287 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)288 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)289 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)290=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)291=== CONT TestParsePathInfoJSON/invalid_JSON292=== CONT TestParsePathInfoJSON/whitespace_only293=== CONT TestParsePathInfoJSON/empty_input294=== CONT TestParsePathInfoJSON/Lix_format295--- PASS: TestParsePathInfoJSON (0.00s)296 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)297 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)298 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)299 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)300 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)301=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI302=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512303=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon304--- PASS: TestPathInfoHashCompatibility (0.00s)305 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)306 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)307 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)308 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)309=== CONT TestGetStorePathHash/valid_store_path310=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error311=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error312=== CONT TestGetStorePathHash/basename_without_hyphen_should_error313--- PASS: TestGetStorePathHash (0.00s)314 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)315 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)316 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)317 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)318=== CONT TestRateLimiterFeedback/429_enables_limiter3192026/09/23 13:01:39 WARN Rate limiter enabled after throttle name=server-test rate=53202026/09/23 13:01:39 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:572363212026/09/23 13:01:39 WARN Rate limiter backed off name=server-test rate=5322=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter323=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter324=== CONT TestRateLimiterFeedback/503_enables_limiter3252026/09/23 13:01:39 WARN Rate limiter enabled after throttle name=server-test rate=53262026/09/23 13:01:39 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:572423272026/09/23 13:01:39 WARN Rate limiter backed off name=server-test rate=5328--- PASS: TestDumpPathSingleFile (0.04s)329=== CONT TestPartSizeForNAR/zero_stays_at_minimum330=== CONT TestEncodeNixBase32/test_string_hash331=== CONT TestPartSizeForNAR/capped_at_5_GiB332=== CONT TestPartSizeForNAR/5_TiB_S3_max_object333=== CONT TestPartSizeForNAR/1_TiB334=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts335=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum336=== CONT TestPartSizeForNAR/small_stays_at_minimum337--- PASS: TestPartSizeForNAR (0.00s)338 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)339 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)340 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)341 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)342 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)343 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)344 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)345=== CONT TestEncodeNixBase32/empty_input346--- PASS: TestEncodeNixBase32 (0.00s)347 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)348 --- PASS: TestEncodeNixBase32/empty_input (0.00s)349=== CONT TestUploadMultipart_SupersededByPeer/exists350=== CONT TestUploadMultipart_SupersededByPeer/missing351--- PASS: TestRateLimiterFeedback (0.00s)352 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)353 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)354 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)355 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)356=== CONT TestSetClientTLS/rejects_connection_without_client_cert357--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)358 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)359 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)360=== CONT TestSetClientTLS/preserves_debug_logging_transport361=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA362=== CONT TestSetClientTLSErrors/missing_cert_file363=== CONT TestSetClientTLSErrors/missing_ca_file364=== CONT TestSetClientTLSErrors/invalid_ca_file365=== CONT TestSetClientTLSErrors/missing_key_file366=== CONT TestFilterOversizedClosures/no_limit_keeps_everything367=== CONT TestFilterOversizedClosures/all_closures_skipped3682026/09/23 13:01:39 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=50369=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3702026/09/23 13:01:39 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=2000371--- PASS: TestFilterOversizedClosures (0.00s)372 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)373 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)374 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)375--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)376--- PASS: TestSetClientTLSErrors (0.01s)377 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)378 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)379 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3812026/09/23 13:01:39 http: TLS handshake error from 127.0.0.1:57248: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.01s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)386--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)387--- PASS: TestCaseHackSuffix (0.05s)388--- PASS: TestDumpPathWriterError (0.08s)389--- PASS: TestDumpPathMatchesNix (0.09s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld10".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-51526-809852379/postgres2355882728/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-51526-809852379/postgres2355882728/data -l logfile start421422/nix/var/nix/builds/nix-51526-809852379/postgres2355882728:5432 - no response4232026-09-23 13:01:46.171 UTC [51693] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-09-23 13:01:46.181 UTC [51693] LOG: listening on Unix socket "/nix/var/nix/builds/nix-51526-809852379/postgres2355882728/.s.PGSQL.5432"4252026-09-23 13:01:46.202 UTC [51701] LOG: database system was shut down at 2026-09-23 13:01:45 UTC4262026-09-23 13:01:46.217 UTC [51693] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-51526-809852379/postgres2355882728:5432 - accepting connections428{"timestamp":"2026-09-23T13:01:46.4165Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"5b5dbece-e1d6-4921-8af4-5e33c24e1fb8","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}429{"timestamp":"2026-09-23T13:01:46.519824Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3d853acd-a0c1-4949-9b7f-3e10876042c2","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}430{"timestamp":"2026-09-23T13:01:46.621481Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e03e87a1-d5fa-438a-9aae-2ef6cb53b2ea","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}431=== RUN TestService_AuthMiddleware432=== PAUSE TestService_AuthMiddleware433=== RUN TestService_AuthMiddleware_MTLSProxyHeader434=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader435=== RUN TestService_AuthMiddleware_MTLSBoundSubjects436=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects437=== RUN TestService_ReadAuthMiddleware438=== PAUSE TestService_ReadAuthMiddleware439=== RUN TestService_AuthMiddleware_OIDC440=== PAUSE TestService_AuthMiddleware_OIDC441=== RUN TestService_RequireScope_OIDC442=== PAUSE TestService_RequireScope_OIDC443=== RUN TestService_ReadScope_PublicByDefault444=== PAUSE TestService_ReadScope_PublicByDefault445=== RUN TestCacheConfigHandler446=== PAUSE TestCacheConfigHandler447=== RUN TestCacheStatsHandler448=== PAUSE TestCacheStatsHandler449=== RUN TestClientCADerivations450=== PAUSE TestClientCADerivations451=== RUN TestClientErrorHandling452=== PAUSE TestClientErrorHandling453=== RUN TestClientIntegration454=== PAUSE TestClientIntegration455=== RUN TestClientMultipleUploads456=== PAUSE TestClientMultipleUploads457=== RUN TestClientWithDependencies458=== PAUSE TestClientWithDependencies459=== RUN TestClientSharedPathCommittedMidPush460=== PAUSE TestClientSharedPathCommittedMidPush461=== RUN TestPinProtectsFromGC462=== PAUSE TestPinProtectsFromGC463=== RUN TestClientPushesUseOnePush464=== PAUSE TestClientPushesUseOnePush465=== RUN TestClientFallsBackToClosures466=== PAUSE TestClientFallsBackToClosures467=== RUN TestResolveDBConnectionString468=== PAUSE TestResolveDBConnectionString469=== RUN TestLeadElectsOneAndHandsOver470=== PAUSE TestLeadElectsOneAndHandsOver471=== RUN TestLeadIncumbentWinsAfterRestart4722026-09-23 13:01:48.227 UTC [51768] ERROR: relation "goose_db_version" does not exist at character 364732026-09-23 13:01:48.227 UTC [51768] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4742026/09/23 13:01:48 OK 20241026095416_initial_model.sql (159.34ms)4752026/09/23 13:01:48 OK 20251210153512_drop_unused_gin_index.sql (11.35ms)4762026/09/23 13:01:48 OK 20251218171726_add_pins.sql (41.06ms)4772026/09/23 13:01:48 OK 20260628120000_add_object_size_and_stats.sql (16.92ms)4782026/09/23 13:01:48 OK 20260905000000_add_claims.sql (31.42ms)4792026/09/23 13:01:48 OK 20260920000000_drop_claims.sql (34.38ms)4802026/09/23 13:01:48 OK 20260923120000_add_pushes.sql (13.41ms)4812026/09/23 13:01:48 goose: successfully migrated database to version: 202609231200004822026/09/23 13:01:48 OK 1_commit_pending_closure.sql (5ms)4832026/09/23 13:01:48 OK 2_object_stats_trigger.sql (1.54ms)4842026/09/23 13:01:48 OK 3_commit_push.sql (840.46µs)4852026/09/23 13:01:48 goose: up to current file version: 34862026/09/23 13:01:48 INFO lead: acquired remote=192.0.2.1:12344872026/09/23 13:01:49 INFO lead: released remote=192.0.2.1:12344882026/09/23 13:01:49 INFO lead: acquired remote=192.0.2.1:12344892026/09/23 13:01:49 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (2.78s)491=== RUN TestLeadEndsOnShutdown492=== PAUSE TestLeadEndsOnShutdown493=== RUN TestGCAdvisoryLockBlocksConcurrentRun4942026-09-23 13:01:50.294 UTC [51799] ERROR: relation "goose_db_version" does not exist at character 364952026-09-23 13:01:50.294 UTC [51799] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4962026/09/23 13:01:50 OK 20241026095416_initial_model.sql (69.68ms)4972026/09/23 13:01:50 OK 20251210153512_drop_unused_gin_index.sql (8.81ms)4982026/09/23 13:01:50 OK 20251218171726_add_pins.sql (24ms)4992026/09/23 13:01:50 OK 20260628120000_add_object_size_and_stats.sql (30.9ms)5002026/09/23 13:01:50 OK 20260905000000_add_claims.sql (32.86ms)5012026/09/23 13:01:50 OK 20260920000000_drop_claims.sql (11.02ms)5022026/09/23 13:01:50 OK 20260923120000_add_pushes.sql (9.05ms)5032026/09/23 13:01:50 goose: successfully migrated database to version: 202609231200005042026/09/23 13:01:50 OK 1_commit_pending_closure.sql (2.5ms)5052026/09/23 13:01:50 OK 2_object_stats_trigger.sql (565.75µs)5062026/09/23 13:01:50 OK 3_commit_push.sql (407.63µs)5072026/09/23 13:01:50 goose: up to current file version: 3508--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.26s)509=== RUN TestGCBugBareHashReferences510=== PAUSE TestGCBugBareHashReferences511=== RUN TestGCMetrics512=== PAUSE TestGCMetrics513=== RUN TestGCTaskStore_StartNew514=== PAUSE TestGCTaskStore_StartNew515=== RUN TestGCTaskStore_DeduplicateSameParams516=== PAUSE TestGCTaskStore_DeduplicateSameParams517=== RUN TestGCTaskStore_ConflictDifferentParams518=== PAUSE TestGCTaskStore_ConflictDifferentParams519=== RUN TestGCTaskStore_GetEmpty520=== PAUSE TestGCTaskStore_GetEmpty521=== RUN TestGCTaskStore_GetReturnsLatest522=== PAUSE TestGCTaskStore_GetReturnsLatest523=== RUN TestGCTaskStore_CompletedAllowsNewTask524=== PAUSE TestGCTaskStore_CompletedAllowsNewTask525=== RUN TestGCTaskStore_PhaseUpdates526=== PAUSE TestGCTaskStore_PhaseUpdates527=== RUN TestGCTaskStore_Fail528=== PAUSE TestGCTaskStore_Fail529=== RUN TestGracefulShutdownDrainsInflight530=== PAUSE TestGracefulShutdownDrainsInflight531=== RUN TestService_healthCheckHandler532=== PAUSE TestService_healthCheckHandler533=== RUN TestService_readinessHandler534=== PAUSE TestService_readinessHandler535=== RUN TestGenerateLandingPage536=== PAUSE TestGenerateLandingPage537=== RUN TestCacheConfigHandlerMaxNarSize538=== PAUSE TestCacheConfigHandlerMaxNarSize539=== RUN TestCreatePendingClosureRejectsOversizedNAR540=== PAUSE TestCreatePendingClosureRejectsOversizedNAR541=== RUN TestNARDeduplicationMetadataUploadBug542=== PAUSE TestNARDeduplicationMetadataUploadBug543=== RUN TestMetricsInventory544=== PAUSE TestMetricsInventory545=== RUN TestService_NativeMTLS546=== PAUSE TestService_NativeMTLS547=== RUN TestServerTLSConfig548=== PAUSE TestServerTLSConfig549=== RUN TestMultipartCleanup550=== PAUSE TestMultipartCleanup551=== RUN TestObjectStatsTrigger552=== PAUSE TestObjectStatsTrigger553=== RUN TestOrphanedObjectsGC554=== PAUSE TestOrphanedObjectsGC555=== RUN TestOrphanedObjectsGCStressTest556=== PAUSE TestOrphanedObjectsGCStressTest557=== RUN TestResurrectedObjectNotDeleted558=== PAUSE TestResurrectedObjectNotDeleted559=== RUN TestCreatePin_ReservedPins560=== PAUSE TestCreatePin_ReservedPins561=== RUN TestParseSingleRange562=== PAUSE TestParseSingleRange563=== RUN TestProxyHeadersOnlyTrustedOnSocket564=== PAUSE TestProxyHeadersOnlyTrustedOnSocket565=== RUN TestIsValidCachePath566=== PAUSE TestIsValidCachePath567=== RUN TestReadProxyNarinfo568=== PAUSE TestReadProxyNarinfo569=== RUN TestReadProxyNarinfoAlreadyDecompressed570=== PAUSE TestReadProxyNarinfoAlreadyDecompressed571=== RUN TestReadProxyNarStreaming572=== PAUSE TestReadProxyNarStreaming573=== RUN TestReadProxy404574=== PAUSE TestReadProxy404575=== RUN TestReadProxyInvalidPath576=== PAUSE TestReadProxyInvalidPath577=== RUN TestReadProxyHead578=== PAUSE TestReadProxyHead579=== RUN TestReadProxyConditionalGet580=== PAUSE TestReadProxyConditionalGet581=== RUN TestReadProxyRootRedirectsToIndexHTML582=== PAUSE TestReadProxyRootRedirectsToIndexHTML583=== RUN TestReadProxyDisabled584=== PAUSE TestReadProxyDisabled585=== RUN TestReadRedirectNar586=== PAUSE TestReadRedirectNar587=== RUN TestReadRedirectKeepsNarinfoProxied588=== PAUSE TestReadRedirectKeepsNarinfoProxied589=== RUN TestReadProxyRangeRequest590=== PAUSE TestReadProxyRangeRequest591=== RUN TestReadRedirectUsesPublicS3URL592=== PAUSE TestReadRedirectUsesPublicS3URL593=== RUN TestPush_OverlappingRootsStoreOneRowPerKey594=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey595=== RUN TestPush_CompleteCommitsEveryRoot596=== PAUSE TestPush_CompleteCommitsEveryRoot597=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected598=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected599=== RUN TestPush_RejectsBadRequests600=== PAUSE TestPush_RejectsBadRequests601=== RUN TestPush_SignsNarinfosOfItsPendingObjects602=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects603=== RUN TestRedundantMultipartUpload604=== PAUSE TestRedundantMultipartUpload605=== RUN TestCompleteMultipartUpload_ErrorButObjectExists606=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists607=== RUN TestCompletedNarNotReofferedAcrossClosures608=== PAUSE TestCompletedNarNotReofferedAcrossClosures609=== RUN TestPresignedUploadRegisteredBeforeCommit610=== PAUSE TestPresignedUploadRegisteredBeforeCommit611=== RUN TestService_Rustfstest612=== PAUSE TestService_Rustfstest613=== RUN TestParseSize614=== PAUSE TestParseSize615=== RUN TestSkippedUploadsHandler616=== PAUSE TestSkippedUploadsHandler617=== RUN TestSystemdListenerNotActivated618--- PASS: TestSystemdListenerNotActivated (0.00s)619=== RUN TestWatchdogBeatsWhenHealthy620--- PASS: TestWatchdogBeatsWhenHealthy (0.04s)621=== RUN TestWatchdogSkipsWhenUnhealthy6222026/09/23 13:01:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:01:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:01:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:01:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:01:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:01:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:01:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/23 13:01:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6302026/09/23 13:01:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6312026/09/23 13:01:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"632--- PASS: TestWatchdogSkipsWhenUnhealthy (0.22s)633=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle634=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle635=== RUN TestProxyWriteTimeout636=== PAUSE TestProxyWriteTimeout637=== RUN TestIsValidUploadKey638=== PAUSE TestIsValidUploadKey639=== RUN TestUploadHandlersRejectInvalidKeys640=== PAUSE TestUploadHandlersRejectInvalidKeys641=== RUN TestUploadHandlersRejectOversizedBody642=== PAUSE TestUploadHandlersRejectOversizedBody643=== RUN TestService_cleanupPendingClosuresHandler644=== PAUSE TestService_cleanupPendingClosuresHandler645=== RUN TestService_createPendingClosureHandler646=== PAUSE TestService_createPendingClosureHandler647=== RUN TestService_verifyS3Integrity648=== PAUSE TestService_verifyS3Integrity649=== RUN TestCompleteMultipartUnregistered650=== PAUSE TestCompleteMultipartUnregistered651=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT652=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT653=== CONT TestService_AuthMiddleware654=== CONT TestOrphanedObjectsGC655=== CONT TestPush_CompleteCommitsEveryRoot656=== CONT TestReadProxyInvalidPath657=== CONT TestReadRedirectNar658=== CONT TestObjectStatsTrigger659=== CONT TestReadProxyRootRedirectsToIndexHTML660=== CONT TestMultipartCleanup661=== CONT TestServerTLSConfig662=== RUN TestServerTLSConfig/no_client_CA663=== CONT TestService_NativeMTLS664=== PAUSE TestServerTLSConfig/no_client_CA665=== RUN TestServerTLSConfig/missing_CA_file666=== PAUSE TestServerTLSConfig/missing_CA_file667=== RUN TestServerTLSConfig/not_a_PEM_file668=== PAUSE TestServerTLSConfig/not_a_PEM_file669=== CONT TestMetricsInventory6702026-09-23 13:01:53.346 UTC [51851] ERROR: relation "goose_db_version" does not exist at character 366712026-09-23 13:01:53.346 UTC [51851] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6722026-09-23 13:01:53.346 UTC [51848] ERROR: relation "goose_db_version" does not exist at character 366732026-09-23 13:01:53.346 UTC [51848] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6742026-09-23 13:01:53.346 UTC [51850] ERROR: relation "goose_db_version" does not exist at character 366752026-09-23 13:01:53.346 UTC [51850] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6762026-09-23 13:01:53.347 UTC [51852] ERROR: relation "goose_db_version" does not exist at character 366772026-09-23 13:01:53.347 UTC [51852] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6782026-09-23 13:01:53.347 UTC [51849] ERROR: relation "goose_db_version" does not exist at character 366792026-09-23 13:01:53.347 UTC [51849] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6802026-09-23 13:01:53.381 UTC [51860] ERROR: relation "goose_db_version" does not exist at character 366812026-09-23 13:01:53.381 UTC [51860] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6822026-09-23 13:01:53.381 UTC [51856] ERROR: relation "goose_db_version" does not exist at character 366832026-09-23 13:01:53.381 UTC [51856] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6842026-09-23 13:01:53.394 UTC [51859] ERROR: relation "goose_db_version" does not exist at character 366852026-09-23 13:01:53.394 UTC [51859] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6862026-09-23 13:01:53.400 UTC [51857] ERROR: relation "goose_db_version" does not exist at character 366872026-09-23 13:01:53.400 UTC [51857] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6882026-09-23 13:01:53.412 UTC [51858] ERROR: relation "goose_db_version" does not exist at character 366892026-09-23 13:01:53.412 UTC [51858] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6902026/09/23 13:01:53 OK 20241026095416_initial_model.sql (89.39ms)6912026/09/23 13:01:53 OK 20241026095416_initial_model.sql (88.16ms)6922026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (22.62ms)6932026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (7.77ms)6942026/09/23 13:01:53 OK 20241026095416_initial_model.sql (113.07ms)6952026/09/23 13:01:53 OK 20241026095416_initial_model.sql (122.4ms)6962026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (7.69ms)6972026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (15.06ms)6982026/09/23 13:01:53 OK 20251218171726_add_pins.sql (30.83ms)6992026/09/23 13:01:53 OK 20241026095416_initial_model.sql (134.89ms)7002026/09/23 13:01:53 OK 20251218171726_add_pins.sql (33.11ms)7012026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (16.62ms)7022026/09/23 13:01:53 OK 20251218171726_add_pins.sql (31.01ms)7032026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (26.06ms)7042026/09/23 13:01:53 OK 20251218171726_add_pins.sql (31.82ms)7052026/09/23 13:01:53 OK 20241026095416_initial_model.sql (153.26ms)7062026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (24.37ms)7072026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (32.54ms)7082026/09/23 13:01:53 OK 20241026095416_initial_model.sql (170.9ms)7092026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (14.58ms)7102026/09/23 13:01:53 OK 20251218171726_add_pins.sql (33.36ms)7112026/09/23 13:01:53 OK 20241026095416_initial_model.sql (185.25ms)7122026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (16.27ms)7132026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (13.01ms)7142026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (38.22ms)7152026/09/23 13:01:53 OK 20241026095416_initial_model.sql (170.55ms)7162026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (7.65ms)7172026/09/23 13:01:53 OK 20251218171726_add_pins.sql (30.43ms)7182026/09/23 13:01:53 OK 20260905000000_add_claims.sql (53.43ms)7192026/09/23 13:01:53 OK 20260905000000_add_claims.sql (37.16ms)7202026/09/23 13:01:53 OK 20260905000000_add_claims.sql (37.25ms)7212026/09/23 13:01:53 OK 20251218171726_add_pins.sql (7.48ms)7222026/09/23 13:01:53 OK 20251218171726_add_pins.sql (21.15ms)7232026/09/23 13:01:53 OK 20251218171726_add_pins.sql (16.06ms)7242026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (29.8ms)7252026/09/23 13:01:53 OK 20260905000000_add_claims.sql (16.72ms)7262026/09/23 13:01:53 OK 20241026095416_initial_model.sql (138.6ms)7272026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (11.42ms)7282026/09/23 13:01:53 OK 20251210153512_drop_unused_gin_index.sql (9.82ms)7292026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (10ms)7302026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (12.74ms)7312026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (14.39ms)7322026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (19.67ms)7332026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (20.56ms)7342026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (20.47ms)7352026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (9.65ms)7362026/09/23 13:01:53 goose: successfully migrated database to version: 202609231200007372026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (20.99ms)7382026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (9.75ms)7392026/09/23 13:01:53 goose: successfully migrated database to version: 202609231200007402026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (6.98ms)7412026/09/23 13:01:53 goose: successfully migrated database to version: 202609231200007422026/09/23 13:01:53 OK 20251218171726_add_pins.sql (10ms)7432026/09/23 13:01:53 OK 1_commit_pending_closure.sql (1.31ms)7442026/09/23 13:01:53 OK 1_commit_pending_closure.sql (2.21ms)7452026/09/23 13:01:53 OK 1_commit_pending_closure.sql (2.25ms)7462026/09/23 13:01:53 OK 20260905000000_add_claims.sql (22.45ms)7472026/09/23 13:01:53 OK 2_object_stats_trigger.sql (987.04µs)7482026/09/23 13:01:53 OK 2_object_stats_trigger.sql (403.96µs)7492026/09/23 13:01:53 OK 3_commit_push.sql (344.5µs)7502026/09/23 13:01:53 goose: up to current file version: 37512026/09/23 13:01:53 OK 2_object_stats_trigger.sql (763.04µs)7522026/09/23 13:01:53 OK 3_commit_push.sql (402.46µs)7532026/09/23 13:01:53 goose: up to current file version: 37542026/09/23 13:01:53 OK 3_commit_push.sql (405.21µs)7552026/09/23 13:01:53 goose: up to current file version: 37562026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (15.91ms)7572026/09/23 13:01:53 goose: successfully migrated database to version: 202609231200007582026/09/23 13:01:53 OK 1_commit_pending_closure.sql (858.92µs)7592026/09/23 13:01:53 OK 2_object_stats_trigger.sql (258.17µs)7602026/09/23 13:01:53 OK 3_commit_push.sql (230.17µs)7612026/09/23 13:01:53 goose: up to current file version: 37622026/09/23 13:01:53 OK 20260628120000_add_object_size_and_stats.sql (36.46ms)7632026/09/23 13:01:53 OK 20260905000000_add_claims.sql (51.53ms)7642026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (71.9ms)7652026/09/23 13:01:53 OK 20260905000000_add_claims.sql (76.53ms)7662026/09/23 13:01:53 OK 20260905000000_add_claims.sql (83.81ms)7672026/09/23 13:01:53 OK 20260905000000_add_claims.sql (83.41ms)7682026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (10ms)7692026/09/23 13:01:53 goose: successfully migrated database to version: 202609231200007702026/09/23 13:01:53 OK 1_commit_pending_closure.sql (1ms)7712026/09/23 13:01:53 OK 2_object_stats_trigger.sql (227.17µs)7722026/09/23 13:01:53 OK 3_commit_push.sql (210.08µs)7732026/09/23 13:01:53 goose: up to current file version: 37742026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (61.91ms)7752026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (35.68ms)7762026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (59.66ms)7772026/09/23 13:01:53 OK 20260905000000_add_claims.sql (99.43ms)7782026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (31.58ms)7792026/09/23 13:01:53 goose: successfully migrated database to version: 202609231200007802026/09/23 13:01:53 OK 1_commit_pending_closure.sql (913.46µs)7812026/09/23 13:01:53 OK 2_object_stats_trigger.sql (226.5µs)7822026/09/23 13:01:53 OK 3_commit_push.sql (177µs)7832026/09/23 13:01:53 goose: up to current file version: 37842026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (68.16ms)7852026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (16.18ms)7862026/09/23 13:01:53 goose: successfully migrated database to version: 202609231200007872026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (33.34ms)7882026/09/23 13:01:53 goose: successfully migrated database to version: 202609231200007892026/09/23 13:01:53 OK 1_commit_pending_closure.sql (1.22ms)7902026/09/23 13:01:53 OK 1_commit_pending_closure.sql (1.31ms)7912026/09/23 13:01:53 OK 2_object_stats_trigger.sql (332.79µs)7922026/09/23 13:01:53 OK 2_object_stats_trigger.sql (343µs)7932026/09/23 13:01:53 OK 3_commit_push.sql (226.46µs)7942026/09/23 13:01:53 goose: up to current file version: 37952026/09/23 13:01:53 OK 3_commit_push.sql (209.13µs)7962026/09/23 13:01:53 goose: up to current file version: 37972026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (14.83ms)7982026/09/23 13:01:53 goose: successfully migrated database to version: 202609231200007992026/09/23 13:01:53 OK 1_commit_pending_closure.sql (808.5µs)8002026/09/23 13:01:53 OK 2_object_stats_trigger.sql (212.96µs)8012026/09/23 13:01:53 OK 3_commit_push.sql (192.63µs)8022026/09/23 13:01:53 goose: up to current file version: 38032026/09/23 13:01:53 OK 20260920000000_drop_claims.sql (44.92ms)8042026/09/23 13:01:53 OK 20260923120000_add_pushes.sql (23.44ms)8052026/09/23 13:01:53 goose: successfully migrated database to version: 202609231200008062026/09/23 13:01:53 OK 1_commit_pending_closure.sql (1.84ms)8072026/09/23 13:01:53 OK 2_object_stats_trigger.sql (490.38µs)8082026/09/23 13:01:53 OK 3_commit_push.sql (217.25µs)8092026/09/23 13:01:53 goose: up to current file version: 3810--- PASS: TestMetricsInventory (2.91s)811=== CONT TestNARDeduplicationMetadataUploadBug8122026/09/23 13:01:54 INFO Received push request method=POST path=/api/pushes8132026/09/23 13:01:54 INFO Received complete push request method=POST path=/api/pushes/1/complete814--- PASS: TestPush_CompleteCommitsEveryRoot (3.36s)815=== CONT TestCreatePendingClosureRejectsOversizedNAR8162026/09/23 13:01:54 INFO Received uploads request method=POST path=/api/pending_closures817--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)818=== CONT TestCacheConfigHandlerMaxNarSize819--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)820=== CONT TestGenerateLandingPage821--- PASS: TestGenerateLandingPage (0.00s)822=== CONT TestService_readinessHandler8232026/09/23 13:01:54 INFO Received uploads request method=POST path=/api/pending_closures8242026/09/23 13:01:54 INFO Received cleanup request method=DELETE path=/api/pending_closures8252026/09/23 13:01:54 INFO Aborted multipart uploads count=1826--- PASS: TestMultipartCleanup (3.82s)827=== CONT TestService_healthCheckHandler828--- PASS: TestReadRedirectNar (3.89s)829=== CONT TestGracefulShutdownDrainsInflight8302026/09/23 13:01:54 INFO Starting HTTP server address=127.0.0.1:574398312026/09/23 13:01:54 INFO Shutdown signal received, draining in-flight requests timeout=10s832--- PASS: TestGracefulShutdownDrainsInflight (0.07s)833=== CONT TestGCTaskStore_Fail834=== CONT TestGCTaskStore_PhaseUpdates835=== CONT TestGCTaskStore_CompletedAllowsNewTask836=== CONT TestGCTaskStore_GetReturnsLatest837--- PASS: TestGCTaskStore_Fail (0.00s)838--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)839--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)840--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)841=== CONT TestGCTaskStore_GetEmpty842--- PASS: TestGCTaskStore_GetEmpty (0.00s)843=== CONT TestGCTaskStore_ConflictDifferentParams844--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)845=== CONT TestGCTaskStore_DeduplicateSameParams846--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)847=== CONT TestGCTaskStore_StartNew848--- PASS: TestGCTaskStore_StartNew (0.00s)849=== CONT TestGCMetrics850--- PASS: TestObjectStatsTrigger (4.28s)851=== CONT TestGCBugBareHashReferences8522026/09/23 13:01:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8532026/09/23 13:01:55 WARN mTLS auth: subject not in bound subjects subject="CN=reader"854--- PASS: TestService_NativeMTLS (4.49s)855=== CONT TestLeadEndsOnShutdown856--- PASS: TestReadProxyRootRedirectsToIndexHTML (4.84s)857=== CONT TestLeadElectsOneAndHandsOver8582026-09-23 13:01:56.311 UTC [51964] ERROR: relation "goose_db_version" does not exist at character 368592026-09-23 13:01:56.311 UTC [51964] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC860--- PASS: TestReadProxyInvalidPath (5.53s)861=== CONT TestResolveDBConnectionString862=== RUN TestResolveDBConnectionString/flag_wins863=== PAUSE TestResolveDBConnectionString/flag_wins864=== RUN TestResolveDBConnectionString/file_when_flag_empty865=== PAUSE TestResolveDBConnectionString/file_when_flag_empty866=== RUN TestResolveDBConnectionString/missing_file_is_an_error867=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error868=== RUN TestResolveDBConnectionString/PGHOST_allows_empty869=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty870=== RUN TestResolveDBConnectionString/nothing_configured871=== PAUSE TestResolveDBConnectionString/nothing_configured872=== CONT TestReadProxy4048732026/09/23 13:01:56 OK 20241026095416_initial_model.sql (204.91ms)8742026/09/23 13:01:56 OK 20251210153512_drop_unused_gin_index.sql (14.24ms)8752026/09/23 13:01:56 OK 20251218171726_add_pins.sql (37.81ms)8762026/09/23 13:01:56 OK 20260628120000_add_object_size_and_stats.sql (40.04ms)8772026-09-23 13:01:56.720 UTC [51968] ERROR: relation "goose_db_version" does not exist at character 368782026-09-23 13:01:56.720 UTC [51968] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8792026/09/23 13:01:56 OK 20260905000000_add_claims.sql (93.94ms)8802026/09/23 13:01:56 OK 20260920000000_drop_claims.sql (42.27ms)8812026/09/23 13:01:56 OK 20260923120000_add_pushes.sql (22.85ms)8822026/09/23 13:01:56 goose: successfully migrated database to version: 202609231200008832026/09/23 13:01:56 OK 1_commit_pending_closure.sql (3.35ms)8842026/09/23 13:01:56 OK 2_object_stats_trigger.sql (577.33µs)8852026/09/23 13:01:56 OK 3_commit_push.sql (348.25µs)8862026/09/23 13:01:56 goose: up to current file version: 38872026/09/23 13:01:56 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"888--- PASS: TestService_AuthMiddleware (5.87s)889=== CONT TestReadProxyNarStreaming8902026/09/23 13:01:57 OK 20241026095416_initial_model.sql (275.06ms)8912026/09/23 13:01:57 OK 20251210153512_drop_unused_gin_index.sql (14.95ms)8922026/09/23 13:01:57 OK 20251218171726_add_pins.sql (26.02ms)893=== NAME TestOrphanedObjectsGC894 orphaned_objects_gc_test.go:290: GC Test Summary:895 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A896 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B897 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)898 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)899 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects900--- PASS: TestOrphanedObjectsGC (6.10s)901=== CONT TestReadProxyNarinfoAlreadyDecompressed9022026/09/23 13:01:57 OK 20260628120000_add_object_size_and_stats.sql (45.24ms)9032026/09/23 13:01:57 OK 20260905000000_add_claims.sql (91.12ms)9042026/09/23 13:01:57 OK 20260920000000_drop_claims.sql (17.28ms)9052026/09/23 13:01:57 OK 20260923120000_add_pushes.sql (18.44ms)9062026/09/23 13:01:57 goose: successfully migrated database to version: 202609231200009072026/09/23 13:01:57 OK 1_commit_pending_closure.sql (2.96ms)9082026/09/23 13:01:57 OK 2_object_stats_trigger.sql (516.29µs)9092026/09/23 13:01:57 OK 3_commit_push.sql (445.5µs)9102026/09/23 13:01:57 goose: up to current file version: 39112026-09-23 13:01:57.518 UTC [51976] ERROR: relation "goose_db_version" does not exist at character 369122026-09-23 13:01:57.518 UTC [51976] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9132026-09-23 13:01:57.538 UTC [51978] ERROR: relation "goose_db_version" does not exist at character 369142026-09-23 13:01:57.538 UTC [51978] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9152026/09/23 13:01:57 WARN readiness check failed error="closed pool"916--- PASS: TestService_readinessHandler (3.25s)917=== CONT TestClientFallsBackToClosures918=== NAME TestNARDeduplicationMetadataUploadBug919 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-51526-809852379/TestNARDeduplicationMetadataUploadBug2004349885/001/store/hcf2qwm8v5nn362ihs3l3c63b3xm6csf-file1.txt9202026/09/23 13:01:57 INFO Received push request method=POST path=/api/pushes9212026/09/23 13:01:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9222026/09/23 13:01:57 INFO Uploading hcf2qwm8v5nn362ihs3l3c63b3xm6csf-file1.txt (160B)9232026/09/23 13:01:57 WARN Failed to register uploaded object key=hcf2qwm8v5nn362ihs3l3c63b3xm6csf.ls error="server returned 404: 404 page not found\n"9242026/09/23 13:01:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9252026/09/23 13:01:57 INFO Signed narinfos id=1 count=19262026/09/23 13:01:57 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9272026/09/23 13:01:57 INFO Uploading 1 narinfos9282026/09/23 13:01:57 OK 20241026095416_initial_model.sql (198.97ms)9292026/09/23 13:01:57 OK 20251210153512_drop_unused_gin_index.sql (9.74ms)9302026/09/23 13:01:57 OK 20241026095416_initial_model.sql (250.56ms)9312026/09/23 13:01:57 INFO Received complete push request method=POST path=/api/pushes/1/complete9322026/09/23 13:01:57 WARN Failed to register uploaded object key=hcf2qwm8v5nn362ihs3l3c63b3xm6csf.narinfo error="server returned 404: 404 page not found\n"9332026/09/23 13:01:57 OK 20251210153512_drop_unused_gin_index.sql (13.14ms)9342026/09/23 13:01:57 OK 20251218171726_add_pins.sql (34.62ms)9352026/09/23 13:01:57 INFO Upload complete. (147ms)936 metadata_upload_test.go:54: Retrieved narinfo from S3:937 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestNARDeduplicationMetadataUploadBug2004349885/001/store/hcf2qwm8v5nn362ihs3l3c63b3xm6csf-file1.txt938 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst939 Compression: zstd940 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf941 NarSize: 160942 References: 943 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf944 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)945 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):946 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9472026/09/23 13:01:57 OK 20251218171726_add_pins.sql (29.65ms)9482026-09-23 13:01:57.893 UTC [51986] ERROR: relation "goose_db_version" does not exist at character 369492026-09-23 13:01:57.893 UTC [51986] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9502026/09/23 13:01:57 OK 20260628120000_add_object_size_and_stats.sql (53.41ms)9512026/09/23 13:01:57 OK 20260628120000_add_object_size_and_stats.sql (42.62ms)9522026/09/23 13:01:58 OK 20260905000000_add_claims.sql (82.29ms)953 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-51526-809852379/TestNARDeduplicationMetadataUploadBug2004349885/001/store/b58xi1jn8vgrlfm35xwzqvsbspn20i96-file2.txt9542026/09/23 13:01:58 OK 20260905000000_add_claims.sql (78.42ms)9552026/09/23 13:01:58 OK 20260920000000_drop_claims.sql (26.5ms)9562026/09/23 13:01:58 OK 20260920000000_drop_claims.sql (44.88ms)9572026/09/23 13:01:58 OK 20260923120000_add_pushes.sql (21.59ms)9582026/09/23 13:01:58 goose: successfully migrated database to version: 202609231200009592026/09/23 13:01:58 OK 1_commit_pending_closure.sql (793.08µs)9602026/09/23 13:01:58 OK 2_object_stats_trigger.sql (223.88µs)9612026/09/23 13:01:58 OK 3_commit_push.sql (197.67µs)9622026/09/23 13:01:58 goose: up to current file version: 39632026/09/23 13:01:58 OK 20260923120000_add_pushes.sql (14.84ms)9642026/09/23 13:01:58 goose: successfully migrated database to version: 202609231200009652026/09/23 13:01:58 OK 1_commit_pending_closure.sql (842.96µs)9662026/09/23 13:01:58 OK 2_object_stats_trigger.sql (243.08µs)9672026/09/23 13:01:58 OK 3_commit_push.sql (204.42µs)9682026/09/23 13:01:58 goose: up to current file version: 39692026/09/23 13:01:58 INFO Received push request method=POST path=/api/pushes9702026/09/23 13:01:58 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9712026/09/23 13:01:58 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9722026/09/23 13:01:58 INFO Signed narinfos id=2 count=19732026/09/23 13:01:58 WARN Failed to register uploaded object key=b58xi1jn8vgrlfm35xwzqvsbspn20i96.ls error="server returned 404: 404 page not found\n"9742026/09/23 13:01:58 INFO Uploading 1 narinfos9752026/09/23 13:01:58 INFO Received complete push request method=POST path=/api/pushes/2/complete9762026/09/23 13:01:58 WARN Failed to register uploaded object key=b58xi1jn8vgrlfm35xwzqvsbspn20i96.narinfo error="server returned 404: 404 page not found\n"9772026/09/23 13:01:58 INFO Upload complete. (174ms)978 metadata_upload_test.go:76: Retrieved narinfo from S3:979 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestNARDeduplicationMetadataUploadBug2004349885/001/store/b58xi1jn8vgrlfm35xwzqvsbspn20i96-file2.txt980 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst981 Compression: zstd982 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf983 NarSize: 160984 References: 985 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf986 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)987 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):988 {"version":1,"root":{"type":"regular","size":44}}9892026/09/23 13:01:58 OK 20241026095416_initial_model.sql (243.44ms)9902026/09/23 13:01:58 OK 20251210153512_drop_unused_gin_index.sql (24.68ms)9912026/09/23 13:01:58 OK 20251218171726_add_pins.sql (52.14ms)9922026/09/23 13:01:58 OK 20260628120000_add_object_size_and_stats.sql (78.87ms)993--- PASS: TestNARDeduplicationMetadataUploadBug (4.45s)994=== CONT TestReadProxyNarinfo995--- PASS: TestService_healthCheckHandler (3.63s)996=== CONT TestClientPushesUseOnePush9972026/09/23 13:01:58 OK 20260905000000_add_claims.sql (138.18ms)9982026/09/23 13:01:58 OK 20260920000000_drop_claims.sql (105.35ms)9992026/09/23 13:01:58 OK 20260923120000_add_pushes.sql (34.97ms)10002026/09/23 13:01:58 goose: successfully migrated database to version: 2026092312000010012026/09/23 13:01:58 OK 1_commit_pending_closure.sql (5.89ms)10022026/09/23 13:01:58 OK 2_object_stats_trigger.sql (2.73ms)10032026/09/23 13:01:58 OK 3_commit_push.sql (769.33µs)10042026/09/23 13:01:58 goose: up to current file version: 310052026/09/23 13:01:58 INFO Aborted multipart uploads count=010062026/09/23 13:01:58 WARN Force mode enabled - objects will be deleted immediately without grace period10072026-09-23 13:01:58.939 UTC [51998] ERROR: relation "goose_db_version" does not exist at character 3610082026-09-23 13:01:58.939 UTC [51998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10092026/09/23 13:01:58 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=010102026/09/23 13:01:58 INFO Vacuumed table table=pending_closures10112026/09/23 13:01:58 INFO Vacuumed table table=pending_objects10122026/09/23 13:01:58 INFO Vacuumed table table=multipart_uploads10132026/09/23 13:01:58 INFO Vacuumed table table=closures10142026/09/23 13:01:58 INFO Vacuumed table table=objects1015--- PASS: TestGCMetrics (3.95s)1016=== CONT TestIsValidCachePath1017=== RUN TestIsValidCachePath/narinfo1018=== PAUSE TestIsValidCachePath/narinfo1019=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1020=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1021=== RUN TestIsValidCachePath/nar_zst1022=== PAUSE TestIsValidCachePath/nar_zst1023=== RUN TestIsValidCachePath/nar_xz1024=== PAUSE TestIsValidCachePath/nar_xz1025=== RUN TestIsValidCachePath/nar_bz21026=== PAUSE TestIsValidCachePath/nar_bz21027=== RUN TestIsValidCachePath/nar_uncompressed1028=== PAUSE TestIsValidCachePath/nar_uncompressed1029=== RUN TestIsValidCachePath/ls1030=== PAUSE TestIsValidCachePath/ls1031=== RUN TestIsValidCachePath/log1032=== PAUSE TestIsValidCachePath/log1033=== RUN TestIsValidCachePath/realisation1034=== PAUSE TestIsValidCachePath/realisation1035=== RUN TestIsValidCachePath/nix-cache-info1036=== PAUSE TestIsValidCachePath/nix-cache-info1037=== RUN TestIsValidCachePath/index.html1038=== PAUSE TestIsValidCachePath/index.html1039=== RUN TestIsValidCachePath/traversal_parent1040=== PAUSE TestIsValidCachePath/traversal_parent1041=== RUN TestIsValidCachePath/traversal_in_middle1042=== PAUSE TestIsValidCachePath/traversal_in_middle1043=== RUN TestIsValidCachePath/invalid_char_e1044=== PAUSE TestIsValidCachePath/invalid_char_e1045=== RUN TestIsValidCachePath/invalid_char_u1046=== PAUSE TestIsValidCachePath/invalid_char_u1047=== RUN TestIsValidCachePath/random_path1048=== PAUSE TestIsValidCachePath/random_path1049=== RUN TestIsValidCachePath/empty1050=== PAUSE TestIsValidCachePath/empty1051=== RUN TestIsValidCachePath/leading_slash1052=== PAUSE TestIsValidCachePath/leading_slash1053=== RUN TestIsValidCachePath/wrong_extension1054=== PAUSE TestIsValidCachePath/wrong_extension1055=== RUN TestIsValidCachePath/short_hash1056=== PAUSE TestIsValidCachePath/short_hash1057=== CONT TestPinProtectsFromGC10582026-09-23 13:01:59.429 UTC [52005] ERROR: relation "goose_db_version" does not exist at character 3610592026-09-23 13:01:59.429 UTC [52005] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10602026/09/23 13:01:59 OK 20241026095416_initial_model.sql (386.98ms)10612026/09/23 13:01:59 OK 20251210153512_drop_unused_gin_index.sql (9.93ms)10622026/09/23 13:01:59 OK 20251218171726_add_pins.sql (36.1ms)10632026/09/23 13:01:59 OK 20260628120000_add_object_size_and_stats.sql (37.37ms)10642026/09/23 13:01:59 OK 20260905000000_add_claims.sql (75.67ms)10652026/09/23 13:01:59 OK 20260920000000_drop_claims.sql (74.04ms)1066--- PASS: TestGCBugBareHashReferences (4.41s)1067=== CONT TestProxyHeadersOnlyTrustedOnSocket10682026/09/23 13:01:59 OK 20241026095416_initial_model.sql (239.29ms)10692026/09/23 13:01:59 OK 20260923120000_add_pushes.sql (47.74ms)10702026/09/23 13:01:59 goose: successfully migrated database to version: 2026092312000010712026/09/23 13:01:59 OK 1_commit_pending_closure.sql (1.72ms)10722026/09/23 13:01:59 OK 2_object_stats_trigger.sql (427.33µs)10732026/09/23 13:01:59 OK 3_commit_push.sql (328µs)10742026/09/23 13:01:59 goose: up to current file version: 310752026/09/23 13:01:59 OK 20251210153512_drop_unused_gin_index.sql (19.12ms)10762026/09/23 13:01:59 OK 20251218171726_add_pins.sql (58.65ms)10772026/09/23 13:01:59 OK 20260628120000_add_object_size_and_stats.sql (68.46ms)10782026/09/23 13:02:00 OK 20260905000000_add_claims.sql (119.3ms)10792026/09/23 13:02:00 OK 20260920000000_drop_claims.sql (89.04ms)10802026/09/23 13:02:00 OK 20260923120000_add_pushes.sql (26.62ms)10812026/09/23 13:02:00 goose: successfully migrated database to version: 2026092312000010822026/09/23 13:02:00 OK 1_commit_pending_closure.sql (1.09ms)10832026/09/23 13:02:00 OK 2_object_stats_trigger.sql (303.25µs)10842026/09/23 13:02:00 OK 3_commit_push.sql (253.17µs)10852026/09/23 13:02:00 goose: up to current file version: 310862026-09-23 13:02:00.146 UTC [52009] ERROR: relation "goose_db_version" does not exist at character 3610872026-09-23 13:02:00.146 UTC [52009] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10882026/09/23 13:02:00 INFO lead: acquired remote=192.0.2.1:123410892026/09/23 13:02:00 INFO lead: released remote=192.0.2.1:12341090--- PASS: TestLeadEndsOnShutdown (4.67s)1091=== CONT TestClientSharedPathCommittedMidPush10922026/09/23 13:02:00 OK 20241026095416_initial_model.sql (398.39ms)10932026/09/23 13:02:00 OK 20251210153512_drop_unused_gin_index.sql (18.45ms)10942026/09/23 13:02:00 OK 20251218171726_add_pins.sql (42.88ms)10952026/09/23 13:02:00 INFO lead: acquired remote=192.0.2.1:123410962026/09/23 13:02:00 OK 20260628120000_add_object_size_and_stats.sql (68.52ms)10972026/09/23 13:02:00 OK 20260905000000_add_claims.sql (74.79ms)10982026/09/23 13:02:00 INFO lead: released remote=192.0.2.1:123410992026/09/23 13:02:00 OK 20260920000000_drop_claims.sql (21.33ms)11002026-09-23 13:02:00.851 UTC [52018] ERROR: relation "goose_db_version" does not exist at character 3611012026-09-23 13:02:00.851 UTC [52018] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11022026-09-23 13:02:00.852 UTC [52019] ERROR: relation "goose_db_version" does not exist at character 3611032026-09-23 13:02:00.852 UTC [52019] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11042026/09/23 13:02:00 OK 20260923120000_add_pushes.sql (11.87ms)11052026/09/23 13:02:00 goose: successfully migrated database to version: 2026092312000011062026/09/23 13:02:00 OK 1_commit_pending_closure.sql (1.54ms)11072026/09/23 13:02:00 OK 2_object_stats_trigger.sql (291.13µs)11082026/09/23 13:02:00 OK 3_commit_push.sql (281.25µs)11092026/09/23 13:02:00 goose: up to current file version: 311102026/09/23 13:02:00 INFO lead: acquired remote=192.0.2.1:123411112026/09/23 13:02:00 INFO lead: released remote=192.0.2.1:12341112--- PASS: TestLeadElectsOneAndHandsOver (5.02s)1113=== CONT TestParseSingleRange1114=== RUN TestParseSingleRange/none1115=== PAUSE TestParseSingleRange/none1116=== RUN TestParseSingleRange/unknown_unit1117=== PAUSE TestParseSingleRange/unknown_unit1118=== RUN TestParseSingleRange/multi-range_ignored1119=== PAUSE TestParseSingleRange/multi-range_ignored1120=== RUN TestParseSingleRange/malformed_no_dash1121=== PAUSE TestParseSingleRange/malformed_no_dash1122=== RUN TestParseSingleRange/malformed_both_empty1123=== PAUSE TestParseSingleRange/malformed_both_empty1124=== RUN TestParseSingleRange/malformed_end_before_start1125=== PAUSE TestParseSingleRange/malformed_end_before_start1126=== RUN TestParseSingleRange/closed1127=== PAUSE TestParseSingleRange/closed1128=== RUN TestParseSingleRange/open-ended1129=== PAUSE TestParseSingleRange/open-ended1130=== RUN TestParseSingleRange/end_clamped_to_size1131=== PAUSE TestParseSingleRange/end_clamped_to_size1132=== RUN TestParseSingleRange/suffix1133=== PAUSE TestParseSingleRange/suffix1134=== RUN TestParseSingleRange/suffix_exceeds_size1135=== PAUSE TestParseSingleRange/suffix_exceeds_size1136=== RUN TestParseSingleRange/single_byte1137=== PAUSE TestParseSingleRange/single_byte1138=== RUN TestParseSingleRange/start_past_EOF1139=== PAUSE TestParseSingleRange/start_past_EOF1140=== RUN TestParseSingleRange/start_far_past_EOF1141=== PAUSE TestParseSingleRange/start_far_past_EOF1142=== CONT TestCreatePin_ReservedPins11432026/09/23 13:02:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57525/oidc1144--- PASS: TestReadProxy404 (4.60s)1145=== CONT TestResurrectedObjectNotDeleted11462026-09-23 13:02:01.183 UTC [52028] ERROR: relation "goose_db_version" does not exist at character 3611472026-09-23 13:02:01.183 UTC [52028] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026/09/23 13:02:01 OK 20241026095416_initial_model.sql (281.96ms)11492026/09/23 13:02:01 OK 20241026095416_initial_model.sql (282.01ms)11502026/09/23 13:02:01 OK 20251210153512_drop_unused_gin_index.sql (14.58ms)11512026/09/23 13:02:01 OK 20251210153512_drop_unused_gin_index.sql (14.61ms)11522026/09/23 13:02:01 OK 20251218171726_add_pins.sql (32.81ms)11532026/09/23 13:02:01 OK 20251218171726_add_pins.sql (32.7ms)11542026/09/23 13:02:01 OK 20260628120000_add_object_size_and_stats.sql (36.38ms)11552026/09/23 13:02:01 OK 20260628120000_add_object_size_and_stats.sql (54.52ms)11562026/09/23 13:02:01 OK 20260905000000_add_claims.sql (67.52ms)11572026/09/23 13:02:01 OK 20260905000000_add_claims.sql (57.29ms)11582026/09/23 13:02:01 OK 20260920000000_drop_claims.sql (47.64ms)11592026/09/23 13:02:01 OK 20260920000000_drop_claims.sql (40.81ms)11602026/09/23 13:02:01 OK 20260923120000_add_pushes.sql (16.15ms)11612026/09/23 13:02:01 goose: successfully migrated database to version: 2026092312000011622026/09/23 13:02:01 OK 1_commit_pending_closure.sql (2.05ms)11632026/09/23 13:02:01 OK 2_object_stats_trigger.sql (445.29µs)11642026/09/23 13:02:01 OK 3_commit_push.sql (344.63µs)11652026/09/23 13:02:01 goose: up to current file version: 311662026/09/23 13:02:01 OK 20260923120000_add_pushes.sql (23.5ms)11672026/09/23 13:02:01 goose: successfully migrated database to version: 2026092312000011682026/09/23 13:02:01 OK 1_commit_pending_closure.sql (1.9ms)11692026/09/23 13:02:01 OK 2_object_stats_trigger.sql (418µs)11702026/09/23 13:02:01 OK 3_commit_push.sql (367.92µs)11712026/09/23 13:02:01 goose: up to current file version: 311722026/09/23 13:02:01 OK 20241026095416_initial_model.sql (223.68ms)11732026/09/23 13:02:01 OK 20251210153512_drop_unused_gin_index.sql (9.57ms)11742026/09/23 13:02:01 OK 20251218171726_add_pins.sql (34.68ms)11752026/09/23 13:02:01 OK 20260628120000_add_object_size_and_stats.sql (35.98ms)11762026/09/23 13:02:01 OK 20260905000000_add_claims.sql (83.11ms)11772026-09-23 13:02:01.680 UTC [52032] ERROR: relation "goose_db_version" does not exist at character 3611782026-09-23 13:02:01.680 UTC [52032] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11792026/09/23 13:02:01 OK 20260920000000_drop_claims.sql (56.29ms)11802026-09-23 13:02:01.722 UTC [52033] ERROR: relation "goose_db_version" does not exist at character 3611812026-09-23 13:02:01.722 UTC [52033] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11822026/09/23 13:02:01 OK 20260923120000_add_pushes.sql (28.98ms)11832026/09/23 13:02:01 goose: successfully migrated database to version: 2026092312000011842026/09/23 13:02:01 OK 1_commit_pending_closure.sql (4.59ms)11852026/09/23 13:02:01 OK 2_object_stats_trigger.sql (2.54ms)11862026/09/23 13:02:01 OK 3_commit_push.sql (934.92µs)11872026/09/23 13:02:01 goose: up to current file version: 31188--- PASS: TestReadProxyNarinfoAlreadyDecompressed (4.69s)1189=== CONT TestClientWithDependencies11902026/09/23 13:02:02 OK 20241026095416_initial_model.sql (278.86ms)11912026/09/23 13:02:02 OK 20251210153512_drop_unused_gin_index.sql (11.44ms)11922026/09/23 13:02:02 OK 20241026095416_initial_model.sql (274.02ms)11932026/09/23 13:02:02 OK 20251218171726_add_pins.sql (35.14ms)11942026/09/23 13:02:02 OK 20251210153512_drop_unused_gin_index.sql (18.11ms)11952026/09/23 13:02:02 OK 20260628120000_add_object_size_and_stats.sql (69.72ms)11962026/09/23 13:02:02 OK 20251218171726_add_pins.sql (53.67ms)11972026/09/23 13:02:02 OK 20260628120000_add_object_size_and_stats.sql (52.61ms)1198--- PASS: TestReadProxyNarStreaming (5.34s)1199=== CONT TestOrphanedObjectsGCStressTest12002026/09/23 13:02:02 OK 20260905000000_add_claims.sql (98.34ms)12012026/09/23 13:02:02 OK 20260905000000_add_claims.sql (92.67ms)12022026/09/23 13:02:02 OK 20260920000000_drop_claims.sql (55.87ms)12032026/09/23 13:02:02 OK 20260923120000_add_pushes.sql (23.98ms)12042026/09/23 13:02:02 goose: successfully migrated database to version: 2026092312000012052026/09/23 13:02:02 OK 1_commit_pending_closure.sql (2.94ms)12062026/09/23 13:02:02 OK 2_object_stats_trigger.sql (682.5µs)12072026/09/23 13:02:02 OK 3_commit_push.sql (818.29µs)12082026/09/23 13:02:02 goose: up to current file version: 312092026/09/23 13:02:02 OK 20260920000000_drop_claims.sql (67.86ms)12102026/09/23 13:02:02 OK 20260923120000_add_pushes.sql (24.66ms)12112026/09/23 13:02:02 goose: successfully migrated database to version: 2026092312000012122026/09/23 13:02:02 OK 1_commit_pending_closure.sql (4.93ms)12132026/09/23 13:02:02 OK 2_object_stats_trigger.sql (1.06ms)12142026/09/23 13:02:02 OK 3_commit_push.sql (1.07ms)12152026/09/23 13:02:02 goose: up to current file version: 312162026-09-23 13:02:02.435 UTC [52038] ERROR: relation "goose_db_version" does not exist at character 3612172026-09-23 13:02:02.435 UTC [52038] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12182026/09/23 13:02:02 OK 20241026095416_initial_model.sql (279.77ms)12192026/09/23 13:02:02 OK 20251210153512_drop_unused_gin_index.sql (14.89ms)12202026/09/23 13:02:02 OK 20251218171726_add_pins.sql (36.21ms)12212026/09/23 13:02:02 OK 20260628120000_add_object_size_and_stats.sql (42.65ms)12222026-09-23 13:02:02.948 UTC [52041] ERROR: relation "goose_db_version" does not exist at character 3612232026-09-23 13:02:02.948 UTC [52041] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12242026/09/23 13:02:02 OK 20260905000000_add_claims.sql (54.5ms)12252026/09/23 13:02:02 OK 20260920000000_drop_claims.sql (47.46ms)12262026-09-23 13:02:03.007 UTC [52044] ERROR: relation "goose_db_version" does not exist at character 3612272026-09-23 13:02:03.007 UTC [52044] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12282026/09/23 13:02:03 OK 20260923120000_add_pushes.sql (22.12ms)12292026/09/23 13:02:03 goose: successfully migrated database to version: 2026092312000012302026/09/23 13:02:03 OK 1_commit_pending_closure.sql (1.18ms)12312026/09/23 13:02:03 OK 2_object_stats_trigger.sql (316.63µs)12322026/09/23 13:02:03 OK 3_commit_push.sql (248.88µs)12332026/09/23 13:02:03 goose: up to current file version: 312342026/09/23 13:02:03 OK 20241026095416_initial_model.sql (152.01ms)1235--- PASS: TestReadProxyNarinfo (4.79s)1236=== CONT TestClientMultipleUploads12372026/09/23 13:02:03 OK 20251210153512_drop_unused_gin_index.sql (13.13ms)12382026/09/23 13:02:03 INFO Received uploads request method=POST path=/api/pending_closures12392026/09/23 13:02:03 OK 20251218171726_add_pins.sql (29.45ms)12402026/09/23 13:02:03 OK 20241026095416_initial_model.sql (164.62ms)12412026/09/23 13:02:03 INFO Received uploads request method=POST path=/api/pending_closures12422026/09/23 13:02:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12432026/09/23 13:02:03 INFO Uploading h9664yr01fbldf95g1h1m3v9s1flavqc-shared-dep (136B)12442026/09/23 13:02:03 INFO Uploading 4l2ak3d7n0r2mjrzqmrp77srar1bka0m-b (248B)12452026/09/23 13:02:03 OK 20260628120000_add_object_size_and_stats.sql (36.23ms)12462026/09/23 13:02:03 OK 20251210153512_drop_unused_gin_index.sql (15.48ms)12472026/09/23 13:02:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12482026/09/23 13:02:03 WARN Failed to register uploaded object key=xj1ikrcy67iz313kylp6k3f49al5n2wz.ls error="server returned 404: 404 page not found\n"12492026/09/23 13:02:03 WARN Failed to register uploaded object key=4l2ak3d7n0r2mjrzqmrp77srar1bka0m.ls error="server returned 404: 404 page not found\n"12502026/09/23 13:02:03 OK 20251218171726_add_pins.sql (22ms)12512026/09/23 13:02:03 WARN Failed to register uploaded object key=h9664yr01fbldf95g1h1m3v9s1flavqc.ls error="server returned 404: 404 page not found\n"12522026/09/23 13:02:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12532026/09/23 13:02:03 WARN Failed to register uploaded object key=nar/0b0yq8jblak35b5xbx6gk85glif1n0pdzivbmjyqsvpb0y3wr2m5.nar.zst error="server returned 404: 404 page not found\n"12542026/09/23 13:02:03 INFO Signed narinfos id=1 count=212552026/09/23 13:02:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12562026/09/23 13:02:03 INFO Signed narinfos id=2 count=212572026/09/23 13:02:03 INFO Uploading 4 narinfos12582026/09/23 13:02:03 WARN Failed to register uploaded object key=h9664yr01fbldf95g1h1m3v9s1flavqc.narinfo error="server returned 404: 404 page not found\n"12592026/09/23 13:02:03 OK 20260628120000_add_object_size_and_stats.sql (41.72ms)12602026/09/23 13:02:03 WARN Failed to register uploaded object key=xj1ikrcy67iz313kylp6k3f49al5n2wz.narinfo error="server returned 404: 404 page not found\n"12612026/09/23 13:02:03 WARN Failed to register uploaded object key=4l2ak3d7n0r2mjrzqmrp77srar1bka0m.narinfo error="server returned 404: 404 page not found\n"12622026/09/23 13:02:03 OK 20260905000000_add_claims.sql (96.97ms)12632026/09/23 13:02:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12642026/09/23 13:02:03 WARN Failed to register uploaded object key=h9664yr01fbldf95g1h1m3v9s1flavqc.narinfo error="server returned 404: 404 page not found\n"12652026/09/23 13:02:03 OK 20260920000000_drop_claims.sql (26.88ms)12662026/09/23 13:02:03 OK 20260905000000_add_claims.sql (66.8ms)12672026/09/23 13:02:03 INFO Completed upload id=112682026/09/23 13:02:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12692026/09/23 13:02:03 INFO Completed upload id=212702026/09/23 13:02:03 INFO Upload complete. (227ms)1271=== NAME TestClientFallsBackToClosures1272 client_pushes_test.go:112: Retrieved narinfo from S3:1273 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestClientFallsBackToClosures994485616/001/store/h9664yr01fbldf95g1h1m3v9s1flavqc-shared-dep1274 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1275 Compression: zstd1276 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821277 NarSize: 1361278 References: 1279 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1280 client_pushes_test.go:112: Retrieved narinfo from S3:1281 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestClientFallsBackToClosures994485616/001/store/xj1ikrcy67iz313kylp6k3f49al5n2wz-a1282 URL: nar/0b0yq8jblak35b5xbx6gk85glif1n0pdzivbmjyqsvpb0y3wr2m5.nar.zst1283 Compression: zstd1284 NarHash: sha256:0b0yq8jblak35b5xbx6gk85glif1n0pdzivbmjyqsvpb0y3wr2m51285 NarSize: 2481286 References: /nix/var/nix/builds/nix-51526-809852379/TestClientFallsBackToClosures994485616/001/store/h9664yr01fbldf95g1h1m3v9s1flavqc-shared-dep1287 CA: text:sha256:1qdd1lfvdhhkkg4q7zhrvxjf7lxlvzadljj25nmgl6458y4zr9yq1288 client_pushes_test.go:112: Retrieved narinfo from S3:1289 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestClientFallsBackToClosures994485616/001/store/4l2ak3d7n0r2mjrzqmrp77srar1bka0m-b1290 URL: nar/0b0yq8jblak35b5xbx6gk85glif1n0pdzivbmjyqsvpb0y3wr2m5.nar.zst1291 Compression: zstd1292 NarHash: sha256:0b0yq8jblak35b5xbx6gk85glif1n0pdzivbmjyqsvpb0y3wr2m51293 NarSize: 2481294 References: /nix/var/nix/builds/nix-51526-809852379/TestClientFallsBackToClosures994485616/001/store/h9664yr01fbldf95g1h1m3v9s1flavqc-shared-dep1295 CA: text:sha256:1qdd1lfvdhhkkg4q7zhrvxjf7lxlvzadljj25nmgl6458y4zr9yq12962026-09-23 13:02:03.405 UTC [52059] ERROR: relation "goose_db_version" does not exist at character 3612972026-09-23 13:02:03.405 UTC [52059] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12982026/09/23 13:02:03 OK 20260923120000_add_pushes.sql (30.65ms)12992026/09/23 13:02:03 goose: successfully migrated database to version: 2026092312000013002026/09/23 13:02:03 OK 1_commit_pending_closure.sql (1.13ms)13012026/09/23 13:02:03 INFO Received push request method=POST path=/api/pushes13022026/09/23 13:02:03 OK 2_object_stats_trigger.sql (264.13µs)13032026/09/23 13:02:03 OK 3_commit_push.sql (201.58µs)13042026/09/23 13:02:03 goose: up to current file version: 313052026/09/23 13:02:03 OK 20260920000000_drop_claims.sql (52.73ms)13062026/09/23 13:02:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13072026/09/23 13:02:03 INFO Uploading 8pr55l8r5vvbrxn5p78mj85lnxhjmdc0-shared-dep (136B)13082026/09/23 13:02:03 INFO Uploading vhba371kq6zzq98xxk8jdsk8gbvhxczq-b (248B)13092026/09/23 13:02:03 OK 20260923120000_add_pushes.sql (7.11ms)13102026/09/23 13:02:03 goose: successfully migrated database to version: 2026092312000013112026/09/23 13:02:03 OK 1_commit_pending_closure.sql (922.63µs)13122026/09/23 13:02:03 OK 2_object_stats_trigger.sql (232.88µs)13132026/09/23 13:02:03 OK 3_commit_push.sql (180.5µs)13142026/09/23 13:02:03 goose: up to current file version: 313152026/09/23 13:02:03 WARN Failed to register uploaded object key=8pr55l8r5vvbrxn5p78mj85lnxhjmdc0.ls error="server returned 404: 404 page not found\n"13162026/09/23 13:02:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13172026/09/23 13:02:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13182026/09/23 13:02:03 WARN Failed to register uploaded object key=vhba371kq6zzq98xxk8jdsk8gbvhxczq.ls error="server returned 404: 404 page not found\n"13192026/09/23 13:02:03 WARN Failed to register uploaded object key=nar/17wpf4mi9ns4ydbck131q50jgl0rqm06q0hhz2vw28qssbg14fjy.nar.zst error="server returned 404: 404 page not found\n"13202026/09/23 13:02:03 WARN Failed to register uploaded object key=qyfr5hcsliwsym4rlpxflbdyf76s9vws.ls error="server returned 404: 404 page not found\n"13212026/09/23 13:02:03 INFO Signed narinfos id=1 count=313222026/09/23 13:02:03 INFO Uploading 3 narinfos1323--- PASS: TestClientFallsBackToClosures (5.85s)1324=== CONT TestClientIntegration13252026/09/23 13:02:03 WARN Failed to register uploaded object key=8pr55l8r5vvbrxn5p78mj85lnxhjmdc0.narinfo error="server returned 404: 404 page not found\n"13262026/09/23 13:02:03 INFO Received complete push request method=POST path=/api/pushes/1/complete13272026/09/23 13:02:03 WARN Failed to register uploaded object key=qyfr5hcsliwsym4rlpxflbdyf76s9vws.narinfo error="server returned 404: 404 page not found\n"13282026/09/23 13:02:03 WARN Failed to register uploaded object key=vhba371kq6zzq98xxk8jdsk8gbvhxczq.narinfo error="server returned 404: 404 page not found\n"13292026/09/23 13:02:03 INFO Upload complete. (165ms)1330=== NAME TestClientPushesUseOnePush1331 client_pushes_test.go:97: Retrieved narinfo from S3:1332 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestClientPushesUseOnePush2769655204/001/store/8pr55l8r5vvbrxn5p78mj85lnxhjmdc0-shared-dep1333 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1334 Compression: zstd1335 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821336 NarSize: 1361337 References: 1338 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1339 client_pushes_test.go:97: Retrieved narinfo from S3:1340 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestClientPushesUseOnePush2769655204/001/store/qyfr5hcsliwsym4rlpxflbdyf76s9vws-a1341 URL: nar/17wpf4mi9ns4ydbck131q50jgl0rqm06q0hhz2vw28qssbg14fjy.nar.zst1342 Compression: zstd1343 NarHash: sha256:17wpf4mi9ns4ydbck131q50jgl0rqm06q0hhz2vw28qssbg14fjy1344 NarSize: 2481345 References: /nix/var/nix/builds/nix-51526-809852379/TestClientPushesUseOnePush2769655204/001/store/8pr55l8r5vvbrxn5p78mj85lnxhjmdc0-shared-dep1346 CA: text:sha256:1maydzh1fcl7klbqlqmpji2f13iip9viikdbz2jmwblf89hzgmb51347 client_pushes_test.go:97: Retrieved narinfo from S3:1348 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestClientPushesUseOnePush2769655204/001/store/vhba371kq6zzq98xxk8jdsk8gbvhxczq-b1349 URL: nar/17wpf4mi9ns4ydbck131q50jgl0rqm06q0hhz2vw28qssbg14fjy.nar.zst1350 Compression: zstd1351 NarHash: sha256:17wpf4mi9ns4ydbck131q50jgl0rqm06q0hhz2vw28qssbg14fjy1352 NarSize: 2481353 References: /nix/var/nix/builds/nix-51526-809852379/TestClientPushesUseOnePush2769655204/001/store/8pr55l8r5vvbrxn5p78mj85lnxhjmdc0-shared-dep1354 CA: text:sha256:1maydzh1fcl7klbqlqmpji2f13iip9viikdbz2jmwblf89hzgmb51355--- PASS: TestClientPushesUseOnePush (5.14s)1356=== CONT TestReadProxyDisabled13572026-09-23 13:02:03.679 UTC [52070] ERROR: relation "goose_db_version" does not exist at character 3613582026-09-23 13:02:03.679 UTC [52070] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13592026/09/23 13:02:03 OK 20241026095416_initial_model.sql (206.69ms)13602026/09/23 13:02:03 OK 20251210153512_drop_unused_gin_index.sql (5.78ms)13612026/09/23 13:02:03 OK 20251218171726_add_pins.sql (27.31ms)13622026/09/23 13:02:03 INFO Starting HTTP server address=/nix/var/nix/builds/nix-51526-809852379/TestProxyHeadersOnlyTrustedOnSocket3246303861/001/proxy.sock13632026/09/23 13:02:03 INFO Starting HTTP server address=127.0.0.1:5757313642026/09/23 13:02:03 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13652026/09/23 13:02:03 INFO Shutdown signal received, draining in-flight requests timeout=10s13662026/09/23 13:02:03 OK 20260628120000_add_object_size_and_stats.sql (45.94ms)1367=== CONT TestClientErrorHandling1368--- PASS: TestProxyHeadersOnlyTrustedOnSocket (4.06s)1369=== RUN TestClientErrorHandling/InvalidStorePath1370=== PAUSE TestClientErrorHandling/InvalidStorePath1371=== RUN TestClientErrorHandling/InvalidAuthToken1372=== PAUSE TestClientErrorHandling/InvalidAuthToken1373=== RUN TestClientErrorHandling/ServerNotAvailable1374=== PAUSE TestClientErrorHandling/ServerNotAvailable1375=== CONT TestReadProxyConditionalGet13762026/09/23 13:02:03 OK 20260905000000_add_claims.sql (59.76ms)1377=== NAME TestPinProtectsFromGC1378 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-51526-809852379/TestPinProtectsFromGC3192785127/001/store/d5ygdbsxl23hijw7ph098vzda2rg82v9-pinned-file.txt1379 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-51526-809852379/TestPinProtectsFromGC3192785127/001/store/lbhcvwkv4v90sjhs9zbr5q6nq4fvw7dl-unpinned-file.txt13802026/09/23 13:02:03 OK 20260920000000_drop_claims.sql (33.89ms)13812026/09/23 13:02:03 OK 20260923120000_add_pushes.sql (10.33ms)13822026/09/23 13:02:03 goose: successfully migrated database to version: 2026092312000013832026/09/23 13:02:03 OK 20241026095416_initial_model.sql (132.2ms)13842026/09/23 13:02:03 OK 1_commit_pending_closure.sql (1.59ms)13852026/09/23 13:02:03 OK 2_object_stats_trigger.sql (224µs)13862026/09/23 13:02:03 OK 3_commit_push.sql (177.92µs)13872026/09/23 13:02:03 goose: up to current file version: 313882026/09/23 13:02:03 OK 20251210153512_drop_unused_gin_index.sql (17.43ms)13892026/09/23 13:02:03 OK 20251218171726_add_pins.sql (21.28ms)13902026/09/23 13:02:03 INFO Received push request method=POST path=/api/pushes13912026/09/23 13:02:03 OK 20260628120000_add_object_size_and_stats.sql (31.23ms)13922026/09/23 13:02:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13932026/09/23 13:02:03 INFO Uploading d5ygdbsxl23hijw7ph098vzda2rg82v9-pinned-file.txt (128B)13942026/09/23 13:02:03 WARN Failed to register uploaded object key=d5ygdbsxl23hijw7ph098vzda2rg82v9.ls error="server returned 404: 404 page not found\n"13952026/09/23 13:02:03 OK 20260905000000_add_claims.sql (52.8ms)13962026/09/23 13:02:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13972026/09/23 13:02:04 INFO Signed narinfos id=1 count=113982026/09/23 13:02:04 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13992026/09/23 13:02:04 INFO Uploading 1 narinfos14002026/09/23 13:02:04 INFO Received complete push request method=POST path=/api/pushes/1/complete14012026/09/23 13:02:04 WARN Failed to register uploaded object key=d5ygdbsxl23hijw7ph098vzda2rg82v9.narinfo error="server returned 404: 404 page not found\n"14022026/09/23 13:02:04 OK 20260920000000_drop_claims.sql (58.75ms)14032026-09-23 13:02:04.058 UTC [52079] ERROR: relation "goose_db_version" does not exist at character 3614042026-09-23 13:02:04.058 UTC [52079] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14052026/09/23 13:02:04 INFO Upload complete. (172ms)14062026/09/23 13:02:04 OK 20260923120000_add_pushes.sql (13.91ms)14072026/09/23 13:02:04 goose: successfully migrated database to version: 2026092312000014082026/09/23 13:02:04 OK 1_commit_pending_closure.sql (1.06ms)14092026/09/23 13:02:04 OK 2_object_stats_trigger.sql (279.96µs)14102026/09/23 13:02:04 OK 3_commit_push.sql (246.04µs)14112026/09/23 13:02:04 goose: up to current file version: 314122026/09/23 13:02:04 INFO Received push request method=POST path=/api/pushes14132026/09/23 13:02:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14142026/09/23 13:02:04 INFO Uploading lbhcvwkv4v90sjhs9zbr5q6nq4fvw7dl-unpinned-file.txt (128B)14152026/09/23 13:02:04 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14162026/09/23 13:02:04 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14172026/09/23 13:02:04 INFO Signed narinfos id=2 count=114182026/09/23 13:02:04 INFO Uploading 1 narinfos14192026/09/23 13:02:04 WARN Failed to register uploaded object key=lbhcvwkv4v90sjhs9zbr5q6nq4fvw7dl.ls error="server returned 404: 404 page not found\n"14202026/09/23 13:02:04 INFO Received complete push request method=POST path=/api/pushes/2/complete14212026/09/23 13:02:04 WARN Failed to register uploaded object key=lbhcvwkv4v90sjhs9zbr5q6nq4fvw7dl.narinfo error="server returned 404: 404 page not found\n"14222026/09/23 13:02:04 INFO Upload complete. (97ms)14232026/09/23 13:02:04 INFO Received create pin request method=POST path=/api/pins/myapp14242026/09/23 13:02:04 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-51526-809852379/TestPinProtectsFromGC3192785127/001/store/d5ygdbsxl23hijw7ph098vzda2rg82v9-pinned-file.txt narinfo_key=d5ygdbsxl23hijw7ph098vzda2rg82v9.narinfo14252026/09/23 13:02:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures14262026/09/23 13:02:04 INFO Garbage collection started14272026/09/23 13:02:04 INFO Aborted multipart uploads count=014282026/09/23 13:02:04 WARN Force mode enabled - objects will be deleted immediately without grace period14292026/09/23 13:02:04 OK 20241026095416_initial_model.sql (207.49ms)14302026/09/23 13:02:04 OK 20251210153512_drop_unused_gin_index.sql (11.45ms)14312026-09-23 13:02:04.382 UTC [52091] ERROR: relation "goose_db_version" does not exist at character 3614322026-09-23 13:02:04.382 UTC [52091] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14332026/09/23 13:02:04 OK 20251218171726_add_pins.sql (29.94ms)14342026/09/23 13:02:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14352026/09/23 13:02:04 WARN Refused reserved pin name=worker-x86_64-linux14362026/09/23 13:02:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14372026/09/23 13:02:04 INFO Received create pin request method=POST path=/api/pins/my-app14382026/09/23 13:02:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1439--- PASS: TestCreatePin_ReservedPins (3.51s)1440=== CONT TestClientCADerivations14412026/09/23 13:02:04 OK 20260628120000_add_object_size_and_stats.sql (38.54ms)14422026/09/23 13:02:04 INFO Received push request method=POST path=/api/pushes14432026/09/23 13:02:04 OK 20260905000000_add_claims.sql (82.86ms)14442026/09/23 13:02:04 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14452026/09/23 13:02:04 INFO Uploading 5hnph9lwzndgchmv2rvj5q1k3vv84cdq-shared-dep (136B)14462026/09/23 13:02:04 INFO Uploading lrk2crc3rhy7hvipd1b74ibk7w2d11n0-top (256B)14472026/09/23 13:02:04 WARN Failed to register uploaded object key=nar/0m1khsklrl1sklmwkfx55yz8mdhqypfscwkilfsjrdgyfvrv7ay1.nar.zst error="server returned 404: 404 page not found\n"14482026/09/23 13:02:04 OK 20260920000000_drop_claims.sql (60.13ms)14492026/09/23 13:02:04 WARN Failed to register uploaded object key=lrk2crc3rhy7hvipd1b74ibk7w2d11n0.ls error="server returned 404: 404 page not found\n"14502026/09/23 13:02:04 WARN Failed to register uploaded object key=5hnph9lwzndgchmv2rvj5q1k3vv84cdq.ls error="server returned 404: 404 page not found\n"14512026/09/23 13:02:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14522026/09/23 13:02:04 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14532026/09/23 13:02:04 INFO Signed narinfos id=1 count=214542026/09/23 13:02:04 INFO Uploading 2 narinfos14552026/09/23 13:02:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=014562026/09/23 13:02:04 OK 20260923120000_add_pushes.sql (23.19ms)14572026/09/23 13:02:04 goose: successfully migrated database to version: 2026092312000014582026/09/23 13:02:04 OK 1_commit_pending_closure.sql (888.63µs)14592026/09/23 13:02:04 OK 2_object_stats_trigger.sql (208.96µs)14602026/09/23 13:02:04 OK 3_commit_push.sql (195.58µs)14612026/09/23 13:02:04 goose: up to current file version: 314622026/09/23 13:02:04 WARN Failed to register uploaded object key=5hnph9lwzndgchmv2rvj5q1k3vv84cdq.narinfo error="server returned 404: 404 page not found\n"14632026/09/23 13:02:04 INFO Received complete push request method=POST path=/api/pushes/1/complete14642026/09/23 13:02:04 WARN Failed to register uploaded object key=lrk2crc3rhy7hvipd1b74ibk7w2d11n0.narinfo error="server returned 404: 404 page not found\n"14652026/09/23 13:02:04 INFO Vacuumed table table=pending_closures14662026/09/23 13:02:04 INFO Upload complete. (194ms)1467=== NAME TestClientSharedPathCommittedMidPush1468 client_integration_test.go:680: Retrieved narinfo from S3:1469 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestClientSharedPathCommittedMidPush235859772/001/store/5hnph9lwzndgchmv2rvj5q1k3vv84cdq-shared-dep1470 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1471 Compression: zstd1472 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821473 NarSize: 1361474 References: 1475 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1476 client_integration_test.go:680: Retrieved narinfo from S3:1477 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestClientSharedPathCommittedMidPush235859772/001/store/lrk2crc3rhy7hvipd1b74ibk7w2d11n0-top1478 URL: nar/0m1khsklrl1sklmwkfx55yz8mdhqypfscwkilfsjrdgyfvrv7ay1.nar.zst1479 Compression: zstd1480 NarHash: sha256:0m1khsklrl1sklmwkfx55yz8mdhqypfscwkilfsjrdgyfvrv7ay11481 NarSize: 2561482 References: /nix/var/nix/builds/nix-51526-809852379/TestClientSharedPathCommittedMidPush235859772/001/store/5hnph9lwzndgchmv2rvj5q1k3vv84cdq-shared-dep1483 CA: text:sha256:13kcxl1c3qnajxni23sly0jlrz954z6xl4v9hxzcxbvrpzirq6p614842026/09/23 13:02:04 INFO Vacuumed table table=pending_objects14852026/09/23 13:02:04 INFO Vacuumed table table=multipart_uploads14862026/09/23 13:02:04 INFO Vacuumed table table=closures14872026/09/23 13:02:04 OK 20241026095416_initial_model.sql (234.7ms)1488--- PASS: TestClientSharedPathCommittedMidPush (4.50s)1489=== CONT TestReadRedirectUsesPublicS3URL14902026/09/23 13:02:04 OK 20251210153512_drop_unused_gin_index.sql (10.98ms)14912026/09/23 13:02:04 INFO Vacuumed table table=objects14922026/09/23 13:02:04 OK 20251218171726_add_pins.sql (45.98ms)14932026/09/23 13:02:04 OK 20260628120000_add_object_size_and_stats.sql (38.41ms)14942026/09/23 13:02:04 OK 20260905000000_add_claims.sql (66.03ms)1495--- PASS: TestResurrectedObjectNotDeleted (3.69s)1496=== CONT TestPush_OverlappingRootsStoreOneRowPerKey14972026/09/23 13:02:04 OK 20260920000000_drop_claims.sql (53.35ms)14982026/09/23 13:02:04 OK 20260923120000_add_pushes.sql (10.42ms)14992026/09/23 13:02:04 goose: successfully migrated database to version: 2026092312000015002026/09/23 13:02:04 OK 1_commit_pending_closure.sql (2.96ms)15012026/09/23 13:02:04 OK 2_object_stats_trigger.sql (559.21µs)15022026/09/23 13:02:04 OK 3_commit_push.sql (454.67µs)15032026/09/23 13:02:04 goose: up to current file version: 315042026-09-23 13:02:05.374 UTC [52108] ERROR: relation "goose_db_version" does not exist at character 3615052026-09-23 13:02:05.374 UTC [52108] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15062026-09-23 13:02:05.456 UTC [52109] ERROR: relation "goose_db_version" does not exist at character 3615072026-09-23 13:02:05.456 UTC [52109] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15082026-09-23 13:02:05.487 UTC [52110] ERROR: relation "goose_db_version" does not exist at character 3615092026-09-23 13:02:05.487 UTC [52110] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1510=== NAME TestClientWithDependencies1511 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-51526-809852379/TestClientWithDependencies1252525264/001/store/nwwqkv3x8fjggr3x8axgln0wxhfcc568-test-script15122026/09/23 13:02:05 OK 20241026095416_initial_model.sql (83.05ms)15132026/09/23 13:02:05 OK 20251210153512_drop_unused_gin_index.sql (7.3ms)1514 client_integration_test.go:615: Found 1 dependencies (including self)15152026/09/23 13:02:05 OK 20251218171726_add_pins.sql (11.14ms)15162026/09/23 13:02:05 OK 20241026095416_initial_model.sql (44.05ms)15172026/09/23 13:02:05 OK 20251210153512_drop_unused_gin_index.sql (722.04µs)15182026/09/23 13:02:05 OK 20251218171726_add_pins.sql (18.7ms)15192026-09-23 13:02:05.558 UTC [52114] ERROR: relation "goose_db_version" does not exist at character 3615202026-09-23 13:02:05.558 UTC [52114] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15212026/09/23 13:02:05 OK 20260628120000_add_object_size_and_stats.sql (26.54ms)15222026/09/23 13:02:05 OK 20241026095416_initial_model.sql (61.12ms)15232026/09/23 13:02:05 OK 20251210153512_drop_unused_gin_index.sql (8.2ms)15242026/09/23 13:02:05 OK 20260628120000_add_object_size_and_stats.sql (22.67ms)15252026/09/23 13:02:05 OK 20260905000000_add_claims.sql (21.23ms)15262026/09/23 13:02:05 OK 20251218171726_add_pins.sql (6.08ms)15272026/09/23 13:02:05 OK 20260905000000_add_claims.sql (21.1ms)15282026/09/23 13:02:05 OK 20260920000000_drop_claims.sql (16.33ms)15292026/09/23 13:02:05 OK 20260628120000_add_object_size_and_stats.sql (23.13ms)15302026/09/23 13:02:05 OK 20260920000000_drop_claims.sql (8.17ms)15312026/09/23 13:02:05 OK 20260923120000_add_pushes.sql (7.58ms)15322026/09/23 13:02:05 goose: successfully migrated database to version: 2026092312000015332026/09/23 13:02:05 OK 20260923120000_add_pushes.sql (906.63µs)15342026/09/23 13:02:05 goose: successfully migrated database to version: 2026092312000015352026/09/23 13:02:05 OK 1_commit_pending_closure.sql (1.58ms)15362026/09/23 13:02:05 INFO Received push request method=POST path=/api/pushes15372026/09/23 13:02:05 OK 20260905000000_add_claims.sql (2.58ms)15382026/09/23 13:02:05 OK 1_commit_pending_closure.sql (1.25ms)15392026/09/23 13:02:05 OK 2_object_stats_trigger.sql (680.13µs)15402026/09/23 13:02:05 OK 2_object_stats_trigger.sql (424.88µs)15412026/09/23 13:02:05 OK 3_commit_push.sql (268.42µs)15422026/09/23 13:02:05 goose: up to current file version: 315432026/09/23 13:02:05 OK 3_commit_push.sql (184.5µs)15442026/09/23 13:02:05 goose: up to current file version: 315452026/09/23 13:02:05 OK 20260920000000_drop_claims.sql (887.54µs)15462026/09/23 13:02:05 OK 20260923120000_add_pushes.sql (993.63µs)15472026/09/23 13:02:05 goose: successfully migrated database to version: 2026092312000015482026/09/23 13:02:05 OK 1_commit_pending_closure.sql (1.01ms)15492026/09/23 13:02:05 OK 2_object_stats_trigger.sql (214.46µs)15502026/09/23 13:02:05 OK 3_commit_push.sql (202.25µs)15512026/09/23 13:02:05 goose: up to current file version: 315522026/09/23 13:02:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15532026/09/23 13:02:05 INFO Uploading nwwqkv3x8fjggr3x8axgln0wxhfcc568-test-script (136B)15542026/09/23 13:02:05 OK 20241026095416_initial_model.sql (42.37ms)15552026/09/23 13:02:05 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)15562026/09/23 13:02:05 WARN Failed to register uploaded object key=nwwqkv3x8fjggr3x8axgln0wxhfcc568.ls error="server returned 404: 404 page not found\n"15572026/09/23 13:02:05 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15582026/09/23 13:02:05 WARN Failed to register uploaded object key=log/jcpj4kcbrsa3nz0fyyg21i68j2mh3qiz-test-script.drv error="server returned 404: 404 page not found\n"15592026/09/23 13:02:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15602026/09/23 13:02:05 INFO Signed narinfos id=1 count=115612026/09/23 13:02:05 INFO Uploading 1 narinfos15622026/09/23 13:02:05 OK 20251218171726_add_pins.sql (24.16ms)15632026/09/23 13:02:05 INFO Received complete push request method=POST path=/api/pushes/1/complete15642026/09/23 13:02:05 WARN Failed to register uploaded object key=nwwqkv3x8fjggr3x8axgln0wxhfcc568.narinfo error="server returned 404: 404 page not found\n"15652026/09/23 13:02:05 OK 20260628120000_add_object_size_and_stats.sql (18.76ms)15662026/09/23 13:02:05 INFO Upload complete. (106ms)1567 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-51526-809852379/TestClientWithDependencies1252525264/001/store) requires matching store prefix15682026/09/23 13:02:05 OK 20260905000000_add_claims.sql (46.9ms)15692026/09/23 13:02:05 OK 20260920000000_drop_claims.sql (24.31ms)1570--- PASS: TestClientWithDependencies (3.94s)1571=== CONT TestReadProxyHead15722026/09/23 13:02:05 OK 20260923120000_add_pushes.sql (20.95ms)15732026/09/23 13:02:05 goose: successfully migrated database to version: 2026092312000015742026/09/23 13:02:05 OK 1_commit_pending_closure.sql (966.42µs)15752026/09/23 13:02:05 OK 2_object_stats_trigger.sql (395µs)15762026/09/23 13:02:05 OK 3_commit_push.sql (222.08µs)15772026/09/23 13:02:05 goose: up to current file version: 315782026-09-23 13:02:06.019 UTC [52122] ERROR: relation "goose_db_version" does not exist at character 3615792026-09-23 13:02:06.019 UTC [52122] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1580=== NAME TestClientMultipleUploads1581 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-51526-809852379/TestClientMultipleUploads2888029931/001/store/k54jgh94gh7lafi2jb29giddj2ajcbxk-test-file-0.txt1582 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-51526-809852379/TestClientMultipleUploads2888029931/001/store/y6yg2spqkzr6kn55dz0mmkd98znrnf4b-test-file-1.txt15832026/09/23 13:02:06 OK 20241026095416_initial_model.sql (176.04ms)15842026/09/23 13:02:06 OK 20251210153512_drop_unused_gin_index.sql (6.1ms)15852026/09/23 13:02:06 OK 20251218171726_add_pins.sql (22.56ms)1586 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-51526-809852379/TestClientMultipleUploads2888029931/001/store/vnk103b6i355229yv960nyiyyk8srqhy-test-file-2.txt15872026-09-23 13:02:06.290 UTC [52129] ERROR: relation "goose_db_version" does not exist at character 3615882026-09-23 13:02:06.290 UTC [52129] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1589=== NAME TestClientIntegration1590 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-51526-809852379/TestClientIntegration856558147/002/store/ljyas8yhhs1vb25rk4iihzh9c9h1mcjc-test-file.txt15912026/09/23 13:02:06 OK 20260628120000_add_object_size_and_stats.sql (31.73ms)15922026/09/23 13:02:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01593=== NAME TestPinProtectsFromGC1594 client_integration_test.go:794: Pin successfully protected closure from garbage collection15952026/09/23 13:02:06 OK 20260905000000_add_claims.sql (35.26ms)1596--- PASS: TestReadProxyDisabled (2.76s)1597=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1598--- PASS: TestPinProtectsFromGC (7.43s)1599=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT16002026/09/23 13:02:06 OK 20260920000000_drop_claims.sql (20.89ms)16012026/09/23 13:02:06 INFO Received push request method=POST path=/api/pushes16022026/09/23 13:02:06 OK 20260923120000_add_pushes.sql (26.3ms)16032026/09/23 13:02:06 goose: successfully migrated database to version: 2026092312000016042026/09/23 13:02:06 OK 1_commit_pending_closure.sql (914.04µs)16052026/09/23 13:02:06 INFO Received push request method=POST path=/api/pushes16062026/09/23 13:02:06 OK 2_object_stats_trigger.sql (222.25µs)16072026/09/23 13:02:06 OK 3_commit_push.sql (225.21µs)16082026/09/23 13:02:06 goose: up to current file version: 316092026/09/23 13:02:06 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16102026/09/23 13:02:06 INFO Uploading y6yg2spqkzr6kn55dz0mmkd98znrnf4b-test-file-1.txt (160B)16112026/09/23 13:02:06 INFO Uploading k54jgh94gh7lafi2jb29giddj2ajcbxk-test-file-0.txt (160B)16122026/09/23 13:02:06 INFO Uploading vnk103b6i355229yv960nyiyyk8srqhy-test-file-2.txt (160B)16132026-09-23 13:02:06.412 UTC [52139] ERROR: relation "goose_db_version" does not exist at character 3616142026-09-23 13:02:06.412 UTC [52139] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16152026/09/23 13:02:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16162026/09/23 13:02:06 INFO Uploading ljyas8yhhs1vb25rk4iihzh9c9h1mcjc-test-file.txt (152B)16172026/09/23 13:02:06 WARN Failed to register uploaded object key=k54jgh94gh7lafi2jb29giddj2ajcbxk.ls error="server returned 404: 404 page not found\n"16182026/09/23 13:02:06 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16192026/09/23 13:02:06 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16202026/09/23 13:02:06 WARN Failed to register uploaded object key=y6yg2spqkzr6kn55dz0mmkd98znrnf4b.ls error="server returned 404: 404 page not found\n"16212026/09/23 13:02:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16222026/09/23 13:02:06 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16232026/09/23 13:02:06 WARN Failed to register uploaded object key=vnk103b6i355229yv960nyiyyk8srqhy.ls error="server returned 404: 404 page not found\n"16242026/09/23 13:02:06 INFO Signed narinfos id=1 count=316252026/09/23 13:02:06 INFO Uploading 3 narinfos16262026/09/23 13:02:06 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16272026/09/23 13:02:06 WARN Failed to register uploaded object key=ljyas8yhhs1vb25rk4iihzh9c9h1mcjc.ls error="server returned 404: 404 page not found\n"16282026/09/23 13:02:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16292026/09/23 13:02:06 INFO Signed narinfos id=1 count=116302026/09/23 13:02:06 INFO Uploading 1 narinfos16312026/09/23 13:02:06 OK 20241026095416_initial_model.sql (119.11ms)16322026/09/23 13:02:06 OK 20251210153512_drop_unused_gin_index.sql (6.76ms)16332026/09/23 13:02:06 WARN Failed to register uploaded object key=k54jgh94gh7lafi2jb29giddj2ajcbxk.narinfo error="server returned 404: 404 page not found\n"16342026/09/23 13:02:06 WARN Failed to register uploaded object key=vnk103b6i355229yv960nyiyyk8srqhy.narinfo error="server returned 404: 404 page not found\n"16352026/09/23 13:02:06 INFO Received complete push request method=POST path=/api/pushes/1/complete16362026/09/23 13:02:06 WARN Failed to register uploaded object key=y6yg2spqkzr6kn55dz0mmkd98znrnf4b.narinfo error="server returned 404: 404 page not found\n"16372026/09/23 13:02:06 INFO Received complete push request method=POST path=/api/pushes/1/complete16382026/09/23 13:02:06 WARN Failed to register uploaded object key=ljyas8yhhs1vb25rk4iihzh9c9h1mcjc.narinfo error="server returned 404: 404 page not found\n"16392026/09/23 13:02:06 OK 20251218171726_add_pins.sql (12.33ms)16402026/09/23 13:02:06 INFO Upload complete. (146ms)16412026/09/23 13:02:06 INFO Upload complete. (178ms)1642=== NAME TestClientMultipleUploads1643 client_integration_test.go:369: Uploaded 3 paths in 211.095709ms16442026/09/23 13:02:06 OK 20260628120000_add_object_size_and_stats.sql (40.11ms)16452026/09/23 13:02:06 INFO All 1 paths already cached1646=== NAME TestClientIntegration1647 client_integration_test.go:312: Retrieved narinfo from S3:1648 StorePath: /nix/var/nix/builds/nix-51526-809852379/TestClientIntegration856558147/002/store/ljyas8yhhs1vb25rk4iihzh9c9h1mcjc-test-file.txt1649 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1650 Compression: zstd1651 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11652 NarSize: 1521653 References: 1654 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11655 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1656 client_integration_test.go:313: Decompressed .ls content (64 bytes):1657 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1658 client_integration_test.go:316: Testing garbage collection...16592026/09/23 13:02:06 OK 20260905000000_add_claims.sql (31.3ms)1660--- PASS: TestClientMultipleUploads (3.37s)1661=== CONT TestCompleteMultipartUnregistered16622026/09/23 13:02:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures16632026/09/23 13:02:06 INFO Garbage collection started16642026/09/23 13:02:06 OK 20260920000000_drop_claims.sql (29.94ms)16652026/09/23 13:02:06 INFO Aborted multipart uploads count=016662026/09/23 13:02:06 WARN Force mode enabled - objects will be deleted immediately without grace period16672026/09/23 13:02:06 OK 20260923120000_add_pushes.sql (12.06ms)16682026/09/23 13:02:06 goose: successfully migrated database to version: 2026092312000016692026/09/23 13:02:06 OK 20241026095416_initial_model.sql (120.65ms)16702026/09/23 13:02:06 OK 1_commit_pending_closure.sql (798.54µs)16712026/09/23 13:02:06 OK 2_object_stats_trigger.sql (202µs)16722026/09/23 13:02:06 OK 3_commit_push.sql (172.79µs)16732026/09/23 13:02:06 goose: up to current file version: 316742026/09/23 13:02:06 OK 20251210153512_drop_unused_gin_index.sql (13.22ms)16752026/09/23 13:02:06 OK 20251218171726_add_pins.sql (15.04ms)1676--- PASS: TestReadProxyConditionalGet (2.85s)1677=== CONT TestService_verifyS3Integrity16782026/09/23 13:02:06 OK 20260628120000_add_object_size_and_stats.sql (44.72ms)16792026/09/23 13:02:06 OK 20260905000000_add_claims.sql (104.02ms)16802026/09/23 13:02:06 OK 20260920000000_drop_claims.sql (10.69ms)16812026/09/23 13:02:06 OK 20260923120000_add_pushes.sql (13.99ms)16822026/09/23 13:02:06 goose: successfully migrated database to version: 2026092312000016832026/09/23 13:02:06 OK 1_commit_pending_closure.sql (1.17ms)16842026/09/23 13:02:06 OK 2_object_stats_trigger.sql (252.67µs)16852026/09/23 13:02:06 OK 3_commit_push.sql (182.75µs)16862026/09/23 13:02:06 goose: up to current file version: 316872026/09/23 13:02:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=016882026/09/23 13:02:06 INFO Vacuumed table table=pending_closures16892026/09/23 13:02:06 INFO Vacuumed table table=pending_objects16902026/09/23 13:02:06 INFO Vacuumed table table=multipart_uploads16912026/09/23 13:02:06 INFO Vacuumed table table=closures16922026/09/23 13:02:06 INFO Vacuumed table table=objects1693--- PASS: TestReadRedirectUsesPublicS3URL (2.43s)1694=== CONT TestService_createPendingClosureHandler16952026-09-23 13:02:07.237 UTC [52160] ERROR: relation "goose_db_version" does not exist at character 3616962026-09-23 13:02:07.237 UTC [52160] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1697=== NAME TestClientCADerivations1698 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-51526-809852379/TestClientCADerivations4156506263/001/store/3s4cqwd358n6k1cmbw6hni2x871zd040-ca-test16992026/09/23 13:02:07 INFO Received push request method=POST path=/api/pushes1700 client_ca_test.go:139: Found 1 dependencies (including self)1701--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.58s)1702=== CONT TestService_cleanupPendingClosuresHandler17032026/09/23 13:02:07 OK 20241026095416_initial_model.sql (159.03ms)17042026/09/23 13:02:07 OK 20251210153512_drop_unused_gin_index.sql (2.72ms)17052026/09/23 13:02:07 OK 20251218171726_add_pins.sql (13.8ms)17062026/09/23 13:02:07 OK 20260628120000_add_object_size_and_stats.sql (14.52ms)17072026/09/23 13:02:07 OK 20260905000000_add_claims.sql (26.55ms)17082026/09/23 13:02:07 OK 20260920000000_drop_claims.sql (8.92ms)17092026/09/23 13:02:07 OK 20260923120000_add_pushes.sql (8.24ms)17102026/09/23 13:02:07 goose: successfully migrated database to version: 2026092312000017112026/09/23 13:02:07 OK 1_commit_pending_closure.sql (1.27ms)17122026/09/23 13:02:07 OK 2_object_stats_trigger.sql (369.92µs)17132026/09/23 13:02:07 OK 3_commit_push.sql (204.71µs)17142026/09/23 13:02:07 goose: up to current file version: 317152026/09/23 13:02:07 INFO Received push request method=POST path=/api/pushes17162026/09/23 13:02:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17172026/09/23 13:02:07 INFO Uploading 3s4cqwd358n6k1cmbw6hni2x871zd040-ca-test (144B)17182026/09/23 13:02:07 WARN Failed to register uploaded object key=3s4cqwd358n6k1cmbw6hni2x871zd040.ls error="server returned 404: 404 page not found\n"17192026/09/23 13:02:07 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17202026/09/23 13:02:07 WARN Failed to register uploaded object key=log/qgg9ab6ksh95n84z08bkkdqyspzgpdgl-ca-test.drv error="server returned 404: 404 page not found\n"17212026/09/23 13:02:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17222026/09/23 13:02:07 INFO Signed narinfos id=1 count=117232026/09/23 13:02:07 INFO Uploading 1 narinfos17242026/09/23 13:02:07 INFO Received complete push request method=POST path=/api/pushes/1/complete17252026/09/23 13:02:07 WARN Failed to register uploaded object key=3s4cqwd358n6k1cmbw6hni2x871zd040.narinfo error="server returned 404: 404 page not found\n"17262026/09/23 13:02:07 INFO Upload complete. (238ms)1727=== NAME TestClientCADerivations1728 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-51526-809852379/TestClientCADerivations4156506263/001/store/3s4cqwd358n6k1cmbw6hni2x871zd040-ca-test1729 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1730 Compression: zstd1731 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1732 NarSize: 1441733 References: 1734 Deriver: /nix/var/nix/builds/nix-51526-809852379/TestClientCADerivations4156506263/001/store/qgg9ab6ksh95n84z08bkkdqyspzgpdgl-ca-test.drv1735 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1736 client_ca_test.go:185: Checking for realisation files in S3...1737 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1738 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1739 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket37?endpoint=http://localhost:57308®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-51526-809852379/TestClientCADerivations4156506263/001/store'1740 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11741--- PASS: TestReadProxyHead (2.07s)1742=== CONT TestUploadHandlersRejectOversizedBody1743=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1744=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1745=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1746=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1747=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1748=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1749=== CONT TestUploadHandlersRejectInvalidKeys1750=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1751=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1752=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1753=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1754=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1755=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1756=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1757=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1758=== CONT TestIsValidUploadKey1759=== RUN TestIsValidUploadKey/narinfo1760=== PAUSE TestIsValidUploadKey/narinfo1761=== RUN TestIsValidUploadKey/nar_zst1762=== PAUSE TestIsValidUploadKey/nar_zst1763=== RUN TestIsValidUploadKey/nar_xz1764=== PAUSE TestIsValidUploadKey/nar_xz1765=== RUN TestIsValidUploadKey/nar_plain1766=== PAUSE TestIsValidUploadKey/nar_plain1767=== RUN TestIsValidUploadKey/listing1768=== PAUSE TestIsValidUploadKey/listing1769=== RUN TestIsValidUploadKey/build_log1770=== PAUSE TestIsValidUploadKey/build_log1771=== RUN TestIsValidUploadKey/build_log_home-manager_file1772=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1773=== RUN TestIsValidUploadKey/build_log_plus_in_name1774=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1775=== RUN TestIsValidUploadKey/build_log_question_mark1776=== PAUSE TestIsValidUploadKey/build_log_question_mark1777=== RUN TestIsValidUploadKey/build_log_equals1778=== PAUSE TestIsValidUploadKey/build_log_equals1779=== RUN TestIsValidUploadKey/realisation1780=== PAUSE TestIsValidUploadKey/realisation1781=== RUN TestIsValidUploadKey/realisation_plus_in_output1782=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1783=== RUN TestIsValidUploadKey/nix-cache-info1784=== PAUSE TestIsValidUploadKey/nix-cache-info1785=== RUN TestIsValidUploadKey/index.html1786=== PAUSE TestIsValidUploadKey/index.html1787=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1788=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1789=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1790=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1791=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1792=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1793=== RUN TestIsValidUploadKey/traversal1794=== PAUSE TestIsValidUploadKey/traversal1795=== RUN TestIsValidUploadKey/traversal_nar1796=== PAUSE TestIsValidUploadKey/traversal_nar1797=== RUN TestIsValidUploadKey/absolute1798=== PAUSE TestIsValidUploadKey/absolute1799=== RUN TestIsValidUploadKey/empty_key1800=== PAUSE TestIsValidUploadKey/empty_key1801=== RUN TestIsValidUploadKey/unknown_type1802=== PAUSE TestIsValidUploadKey/unknown_type1803=== CONT TestProxyWriteTimeout1804=== RUN TestProxyWriteTimeout/narinfo1805=== PAUSE TestProxyWriteTimeout/narinfo1806=== RUN TestProxyWriteTimeout/1_GiB_nar1807=== PAUSE TestProxyWriteTimeout/1_GiB_nar1808=== RUN TestProxyWriteTimeout/10_GiB_nar1809=== PAUSE TestProxyWriteTimeout/10_GiB_nar1810=== RUN TestProxyWriteTimeout/unknown_size1811=== PAUSE TestProxyWriteTimeout/unknown_size1812=== CONT TestReadProxyRangeRequest1813--- PASS: TestClientCADerivations (3.45s)1814=== CONT TestService_AuthMiddleware_OIDC18152026/09/23 13:02:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57655/oidc18162026-09-23 13:02:07.954 UTC [52178] ERROR: relation "goose_db_version" does not exist at character 3618172026-09-23 13:02:07.954 UTC [52178] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18182026-09-23 13:02:07.962 UTC [52179] ERROR: relation "goose_db_version" does not exist at character 3618192026-09-23 13:02:07.962 UTC [52179] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18202026-09-23 13:02:08.043 UTC [52180] ERROR: relation "goose_db_version" does not exist at character 3618212026-09-23 13:02:08.043 UTC [52180] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18222026/09/23 13:02:08 OK 20241026095416_initial_model.sql (80.51ms)18232026/09/23 13:02:08 OK 20251210153512_drop_unused_gin_index.sql (5.72ms)18242026/09/23 13:02:08 OK 20241026095416_initial_model.sql (80.12ms)18252026-09-23 13:02:08.080 UTC [52181] ERROR: relation "goose_db_version" does not exist at character 3618262026-09-23 13:02:08.080 UTC [52181] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18272026/09/23 13:02:08 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)18282026/09/23 13:02:08 OK 20251218171726_add_pins.sql (9.58ms)18292026/09/23 13:02:08 OK 20251218171726_add_pins.sql (17.28ms)18302026/09/23 13:02:08 OK 20260628120000_add_object_size_and_stats.sql (23.92ms)18312026/09/23 13:02:08 OK 20260628120000_add_object_size_and_stats.sql (21.48ms)18322026/09/23 13:02:08 OK 20260905000000_add_claims.sql (21.27ms)18332026/09/23 13:02:08 OK 20260905000000_add_claims.sql (31.65ms)18342026/09/23 13:02:08 OK 20260920000000_drop_claims.sql (20.26ms)18352026/09/23 13:02:08 OK 20241026095416_initial_model.sql (76.35ms)18362026/09/23 13:02:08 OK 20251210153512_drop_unused_gin_index.sql (9.61ms)18372026/09/23 13:02:08 OK 20260923120000_add_pushes.sql (10.93ms)18382026/09/23 13:02:08 goose: successfully migrated database to version: 2026092312000018392026/09/23 13:02:08 OK 1_commit_pending_closure.sql (2.19ms)18402026/09/23 13:02:08 OK 2_object_stats_trigger.sql (379.04µs)18412026/09/23 13:02:08 OK 3_commit_push.sql (323.33µs)18422026/09/23 13:02:08 goose: up to current file version: 318432026/09/23 13:02:08 OK 20260920000000_drop_claims.sql (20.57ms)18442026/09/23 13:02:08 OK 20260923120000_add_pushes.sql (10.86ms)18452026/09/23 13:02:08 goose: successfully migrated database to version: 2026092312000018462026/09/23 13:02:08 OK 1_commit_pending_closure.sql (1.68ms)18472026/09/23 13:02:08 OK 2_object_stats_trigger.sql (382.17µs)18482026/09/23 13:02:08 OK 3_commit_push.sql (327.04µs)18492026/09/23 13:02:08 goose: up to current file version: 318502026/09/23 13:02:08 OK 20251218171726_add_pins.sql (28.15ms)18512026/09/23 13:02:08 OK 20260628120000_add_object_size_and_stats.sql (32.89ms)18522026/09/23 13:02:08 OK 20241026095416_initial_model.sql (120.43ms)18532026/09/23 13:02:08 OK 20251210153512_drop_unused_gin_index.sql (8.77ms)18542026/09/23 13:02:08 OK 20251218171726_add_pins.sql (30.08ms)18552026/09/23 13:02:08 OK 20260905000000_add_claims.sql (47.9ms)18562026/09/23 13:02:08 OK 20260628120000_add_object_size_and_stats.sql (49.09ms)18572026/09/23 13:02:08 OK 20260920000000_drop_claims.sql (48.32ms)18582026/09/23 13:02:08 OK 20260923120000_add_pushes.sql (14.14ms)18592026/09/23 13:02:08 goose: successfully migrated database to version: 2026092312000018602026/09/23 13:02:08 OK 1_commit_pending_closure.sql (4.27ms)18612026/09/23 13:02:08 OK 2_object_stats_trigger.sql (772.58µs)18622026/09/23 13:02:08 OK 3_commit_push.sql (528.71µs)18632026/09/23 13:02:08 goose: up to current file version: 318642026/09/23 13:02:08 OK 20260905000000_add_claims.sql (51.24ms)18652026/09/23 13:02:08 OK 20260920000000_drop_claims.sql (31.63ms)18662026/09/23 13:02:08 OK 20260923120000_add_pushes.sql (26.62ms)18672026/09/23 13:02:08 goose: successfully migrated database to version: 2026092312000018682026/09/23 13:02:08 OK 1_commit_pending_closure.sql (4.38ms)18692026/09/23 13:02:08 OK 2_object_stats_trigger.sql (1.12ms)18702026/09/23 13:02:08 OK 3_commit_push.sql (825.83µs)18712026/09/23 13:02:08 goose: up to current file version: 318722026/09/23 13:02:08 INFO Received uploads request method=POST path=/api/pending_closures1873--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.17s)1874=== CONT TestCacheStatsHandler18752026/09/23 13:02:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01876=== NAME TestClientIntegration1877 client_integration_test.go:323: Objects in database after GC:1878 client_integration_test.go:323: Successfully deleted all objects with GC --force1879--- PASS: TestClientIntegration (5.15s)1880=== CONT TestService_RequireScope_OIDC18812026-09-23 13:02:08.733 UTC [52184] ERROR: relation "goose_db_version" does not exist at character 3618822026-09-23 13:02:08.733 UTC [52184] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18832026/09/23 13:02:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57659/oidc18842026/09/23 13:02:08 INFO Received uploads request method=POST path=/api/pending_closures18852026-09-23 13:02:08.902 UTC [52187] ERROR: relation "goose_db_version" does not exist at character 3618862026-09-23 13:02:08.902 UTC [52187] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18872026/09/23 13:02:08 OK 20241026095416_initial_model.sql (159.27ms)18882026/09/23 13:02:08 OK 20251210153512_drop_unused_gin_index.sql (6.5ms)18892026/09/23 13:02:09 OK 20251218171726_add_pins.sql (29.3ms)18902026/09/23 13:02:09 OK 20260628120000_add_object_size_and_stats.sql (36.96ms)18912026/09/23 13:02:09 OK 20260905000000_add_claims.sql (60.14ms)18922026/09/23 13:02:09 OK 20241026095416_initial_model.sql (194.83ms)18932026/09/23 13:02:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18942026/09/23 13:02:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18952026/09/23 13:02:09 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1896--- PASS: TestCompleteMultipartUnregistered (2.60s)1897=== CONT TestService_ReadAuthMiddleware18982026/09/23 13:02:09 OK 20260920000000_drop_claims.sql (49.74ms)18992026/09/23 13:02:09 OK 20251210153512_drop_unused_gin_index.sql (19.37ms)19002026/09/23 13:02:09 OK 20260923120000_add_pushes.sql (21.5ms)19012026/09/23 13:02:09 goose: successfully migrated database to version: 2026092312000019022026/09/23 13:02:09 OK 1_commit_pending_closure.sql (1.19ms)19032026/09/23 13:02:09 OK 2_object_stats_trigger.sql (267.29µs)19042026/09/23 13:02:09 OK 3_commit_push.sql (224.92µs)19052026/09/23 13:02:09 goose: up to current file version: 319062026/09/23 13:02:09 OK 20251218171726_add_pins.sql (30.9ms)19072026/09/23 13:02:09 OK 20260628120000_add_object_size_and_stats.sql (25.83ms)19082026/09/23 13:02:09 OK 20260905000000_add_claims.sql (55.4ms)19092026/09/23 13:02:09 OK 20260920000000_drop_claims.sql (41.4ms)19102026/09/23 13:02:09 OK 20260923120000_add_pushes.sql (16.97ms)19112026/09/23 13:02:09 goose: successfully migrated database to version: 2026092312000019122026/09/23 13:02:09 OK 1_commit_pending_closure.sql (2.43ms)19132026/09/23 13:02:09 OK 2_object_stats_trigger.sql (490.63µs)19142026/09/23 13:02:09 OK 3_commit_push.sql (317.25µs)19152026/09/23 13:02:09 goose: up to current file version: 319162026/09/23 13:02:09 INFO Received uploads request method=POST path=/api/pending_closures19172026-09-23 13:02:09.582 UTC [52190] ERROR: relation "goose_db_version" does not exist at character 3619182026-09-23 13:02:09.582 UTC [52190] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19192026/09/23 13:02:09 INFO Received uploads request method=POST path=/api/pending_closures19202026/09/23 13:02:09 INFO Received uploads request method=POST path=/api/pending_closures19212026/09/23 13:02:09 INFO Received uploads request method=POST path=/api/pending_closures19222026-09-23 13:02:09.931 UTC [52191] ERROR: relation "goose_db_version" does not exist at character 3619232026-09-23 13:02:09.931 UTC [52191] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19242026/09/23 13:02:09 OK 20241026095416_initial_model.sql (255.86ms)19252026/09/23 13:02:09 OK 20251210153512_drop_unused_gin_index.sql (16.89ms)1926=== NAME TestOrphanedObjectsGCStressTest1927 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19282026/09/23 13:02:10 OK 20251218171726_add_pins.sql (53.93ms)1929 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19302026/09/23 13:02:10 OK 20260628120000_add_object_size_and_stats.sql (73.62ms)19312026/09/23 13:02:10 OK 20260905000000_add_claims.sql (51ms)19322026/09/23 13:02:10 OK 20260920000000_drop_claims.sql (75.21ms)19332026/09/23 13:02:10 INFO Received cleanup request method=DELETE path=/api/pending_closures19342026/09/23 13:02:10 INFO Aborted multipart uploads count=019352026/09/23 13:02:10 OK 20260923120000_add_pushes.sql (21.06ms)19362026/09/23 13:02:10 goose: successfully migrated database to version: 2026092312000019372026/09/23 13:02:10 OK 1_commit_pending_closure.sql (2.62ms)19382026/09/23 13:02:10 OK 2_object_stats_trigger.sql (636.25µs)19392026/09/23 13:02:10 OK 3_commit_push.sql (413.79µs)19402026/09/23 13:02:10 goose: up to current file version: 319412026/09/23 13:02:10 INFO Received uploads request method=POST path=/api/pending_closures19422026/09/23 13:02:10 OK 20241026095416_initial_model.sql (279.78ms)19432026/09/23 13:02:10 OK 20251210153512_drop_unused_gin_index.sql (20.05ms)19442026/09/23 13:02:10 INFO Received cleanup request method=DELETE path=/api/pending_closures19452026/09/23 13:02:10 INFO Aborted multipart uploads count=119462026/09/23 13:02:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19472026-09-23 13:02:10.369 UTC [52187] ERROR: Closure does not exist: id=119482026-09-23 13:02:10.369 UTC [52187] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE19492026-09-23 13:02:10.369 UTC [52187] STATEMENT: -- name: CommitPendingClosure :exec1950 SELECT commit_pending_closure($1::bigint)1951 1952--- PASS: TestService_cleanupPendingClosuresHandler (2.93s)1953=== CONT TestCompletedNarNotReofferedAcrossClosures19542026/09/23 13:02:10 OK 20251218171726_add_pins.sql (62.69ms)19552026/09/23 13:02:10 OK 20260628120000_add_object_size_and_stats.sql (41.69ms)19562026/09/23 13:02:10 OK 20260905000000_add_claims.sql (55.78ms)19572026/09/23 13:02:10 OK 20260920000000_drop_claims.sql (70.11ms)19582026/09/23 13:02:10 OK 20260923120000_add_pushes.sql (18.04ms)19592026/09/23 13:02:10 goose: successfully migrated database to version: 2026092312000019602026/09/23 13:02:10 OK 1_commit_pending_closure.sql (4.48ms)19612026/09/23 13:02:10 OK 2_object_stats_trigger.sql (774.46µs)19622026/09/23 13:02:10 OK 3_commit_push.sql (688.54µs)19632026/09/23 13:02:10 goose: up to current file version: 31964--- PASS: TestReadProxyRangeRequest (2.86s)1965=== CONT TestService_AuthMiddleware_MTLSBoundSubjects19662026-09-23 13:02:10.710 UTC [52194] ERROR: relation "goose_db_version" does not exist at character 3619672026-09-23 13:02:10.710 UTC [52194] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19682026-09-23 13:02:10.853 UTC [52197] ERROR: relation "goose_db_version" does not exist at character 3619692026-09-23 13:02:10.853 UTC [52197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19702026/09/23 13:02:11 OK 20241026095416_initial_model.sql (227.86ms)19712026/09/23 13:02:11 OK 20251210153512_drop_unused_gin_index.sql (13.33ms)19722026/09/23 13:02:11 OK 20251218171726_add_pins.sql (26.64ms)1973=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1974=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1975=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1976=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1977=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1978=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1979=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1980=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1981=== CONT TestSkippedUploadsHandler19822026/09/23 13:02:11 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001983--- PASS: TestSkippedUploadsHandler (0.00s)1984=== CONT TestService_AuthMiddleware_MTLSProxyHeader19852026/09/23 13:02:11 OK 20260628120000_add_object_size_and_stats.sql (53.26ms)19862026/09/23 13:02:11 OK 20260905000000_add_claims.sql (94.17ms)19872026/09/23 13:02:11 OK 20241026095416_initial_model.sql (197.66ms)19882026/09/23 13:02:11 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)19892026/09/23 13:02:11 OK 20260920000000_drop_claims.sql (3.68ms)19902026/09/23 13:02:11 OK 20260923120000_add_pushes.sql (3.15ms)19912026/09/23 13:02:11 goose: successfully migrated database to version: 2026092312000019922026/09/23 13:02:11 OK 20251218171726_add_pins.sql (4.35ms)19932026/09/23 13:02:11 OK 1_commit_pending_closure.sql (2.16ms)19942026/09/23 13:02:11 OK 2_object_stats_trigger.sql (805.38µs)19952026/09/23 13:02:11 OK 3_commit_push.sql (558.79µs)19962026/09/23 13:02:11 goose: up to current file version: 319972026-09-23 13:02:11.229 UTC [52200] ERROR: relation "goose_db_version" does not exist at character 3619982026-09-23 13:02:11.229 UTC [52200] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19992026/09/23 13:02:11 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)20002026/09/23 13:02:11 OK 20260905000000_add_claims.sql (34.49ms)20012026/09/23 13:02:11 OK 20260920000000_drop_claims.sql (39.37ms)20022026/09/23 13:02:11 OK 20260923120000_add_pushes.sql (10.17ms)20032026/09/23 13:02:11 goose: successfully migrated database to version: 2026092312000020042026/09/23 13:02:11 OK 1_commit_pending_closure.sql (1.35ms)20052026/09/23 13:02:11 OK 2_object_stats_trigger.sql (334.25µs)20062026/09/23 13:02:11 OK 3_commit_push.sql (286.75µs)20072026/09/23 13:02:11 goose: up to current file version: 320082026/09/23 13:02:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20092026/09/23 13:02:11 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MjVjZTVmZDItMmVhNC00NjMxLWE0NzktYmIyZTNjZWIzNWY2LjM1YTRhNGI3LTBjYTMtNDBiMS05ZTk4LTE0ZGIwNzRmMjY2OHgxNzkwMTY4NTI5NDg1NjQxMDAw parts=1020102026/09/23 13:02:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20112026/09/23 13:02:11 INFO Completed upload id=120122026/09/23 13:02:11 INFO Received uploads request method=POST path=/api/pending_closures20132026/09/23 13:02:11 INFO Received uploads request method=POST path=/api/pending_closures20142026/09/23 13:02:11 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo20152026/09/23 13:02:11 WARN Found objects in DB but missing from S3, will re-upload count=12016--- PASS: TestService_verifyS3Integrity (4.81s)2017=== CONT TestParseSize2018--- PASS: TestParseSize (0.00s)2019=== CONT TestReadRedirectKeepsNarinfoProxied20202026/09/23 13:02:11 OK 20241026095416_initial_model.sql (177.06ms)20212026/09/23 13:02:11 OK 20251210153512_drop_unused_gin_index.sql (12.6ms)20222026/09/23 13:02:11 OK 20251218171726_add_pins.sql (24.98ms)20232026/09/23 13:02:11 OK 20260628120000_add_object_size_and_stats.sql (16.74ms)20242026/09/23 13:02:11 OK 20260905000000_add_claims.sql (36.74ms)20252026/09/23 13:02:11 OK 20260920000000_drop_claims.sql (41.74ms)2026--- PASS: TestCacheStatsHandler (3.06s)2027=== CONT TestService_Rustfstest20282026/09/23 13:02:11 OK 20260923120000_add_pushes.sql (9.97ms)20292026/09/23 13:02:11 goose: successfully migrated database to version: 2026092312000020302026/09/23 13:02:11 OK 1_commit_pending_closure.sql (1.86ms)20312026/09/23 13:02:11 OK 2_object_stats_trigger.sql (359.04µs)20322026/09/23 13:02:11 OK 3_commit_push.sql (314.83µs)20332026/09/23 13:02:11 goose: up to current file version: 320342026/09/23 13:02:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20352026/09/23 13:02:11 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MjVjZTVmZDItMmVhNC00NjMxLWE0NzktYmIyZTNjZWIzNWY2LjRhMzljNzJiLThhYmEtNDFhZS05YzI5LTY3MDQyNDE1ZWVhYngxNzkwMTY4NTI5ODUwMTI1MDAw parts=1020362026/09/23 13:02:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20372026/09/23 13:02:11 INFO Completed upload id=120382026/09/23 13:02:11 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000020392026/09/23 13:02:11 INFO Received uploads request method=POST path=/api/pending_closures20402026/09/23 13:02:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures20412026/09/23 13:02:11 INFO Aborted multipart uploads count=020422026/09/23 13:02:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=020432026/09/23 13:02:11 INFO Vacuumed table table=pending_closures20442026/09/23 13:02:11 INFO Vacuumed table table=pending_objects20452026/09/23 13:02:11 INFO Vacuumed table table=multipart_uploads20462026/09/23 13:02:11 INFO Vacuumed table table=closures20472026/09/23 13:02:11 INFO Vacuumed table table=objects2048=== RUN TestService_RequireScope_OIDC/builder_may_write2049=== PAUSE TestService_RequireScope_OIDC/builder_may_write2050=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2051=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2052=== RUN TestService_RequireScope_OIDC/ops_may_admin2053=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2054=== RUN TestService_RequireScope_OIDC/ops_may_not_write2055=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2056=== RUN TestService_RequireScope_OIDC/reader_may_not_write2057=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2058=== RUN TestService_RequireScope_OIDC/static_token_may_admin2059=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2060=== RUN TestService_RequireScope_OIDC/static_token_may_write2061=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2062=== RUN TestService_RequireScope_OIDC/reader_may_read2063=== PAUSE TestService_RequireScope_OIDC/reader_may_read2064=== RUN TestService_RequireScope_OIDC/writer_implies_read2065=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2066=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2067=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2068=== CONT TestCacheConfigHandler2069=== RUN TestCacheConfigHandler/full_config,_no_issuer2070=== PAUSE TestCacheConfigHandler/full_config,_no_issuer2071=== RUN TestCacheConfigHandler/no_cache_url_configured2072=== PAUSE TestCacheConfigHandler/no_cache_url_configured2073=== RUN TestCacheConfigHandler/no_signing_keys2074=== PAUSE TestCacheConfigHandler/no_signing_keys2075=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2076=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2077=== CONT TestPresignedUploadRegisteredBeforeCommit20782026/09/23 13:02:11 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002079--- PASS: TestService_createPendingClosureHandler (4.75s)2080=== CONT TestPush_SignsNarinfosOfItsPendingObjects2081--- PASS: TestService_ReadAuthMiddleware (2.88s)2082=== CONT TestPush_RejectsBadRequests20832026-09-23 13:02:12.064 UTC [52211] ERROR: relation "goose_db_version" does not exist at character 3620842026-09-23 13:02:12.064 UTC [52211] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20852026-09-23 13:02:12.174 UTC [52213] ERROR: relation "goose_db_version" does not exist at character 3620862026-09-23 13:02:12.174 UTC [52213] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20872026/09/23 13:02:12 OK 20241026095416_initial_model.sql (89.95ms)20882026/09/23 13:02:12 OK 20251210153512_drop_unused_gin_index.sql (8.54ms)20892026/09/23 13:02:12 OK 20251218171726_add_pins.sql (5.39ms)20902026/09/23 13:02:12 OK 20260628120000_add_object_size_and_stats.sql (7.81ms)20912026/09/23 13:02:12 OK 20260905000000_add_claims.sql (9.87ms)20922026/09/23 13:02:12 OK 20260920000000_drop_claims.sql (18.08ms)20932026/09/23 13:02:12 OK 20260923120000_add_pushes.sql (8.59ms)20942026/09/23 13:02:12 goose: successfully migrated database to version: 2026092312000020952026/09/23 13:02:12 OK 20241026095416_initial_model.sql (43.69ms)20962026/09/23 13:02:12 OK 1_commit_pending_closure.sql (1.89ms)20972026/09/23 13:02:12 OK 2_object_stats_trigger.sql (376.92µs)20982026/09/23 13:02:12 OK 3_commit_push.sql (310.58µs)20992026/09/23 13:02:12 goose: up to current file version: 321002026/09/23 13:02:12 OK 20251210153512_drop_unused_gin_index.sql (8.9ms)21012026/09/23 13:02:12 OK 20251218171726_add_pins.sql (32.37ms)21022026/09/23 13:02:12 OK 20260628120000_add_object_size_and_stats.sql (42.85ms)21032026/09/23 13:02:12 OK 20260905000000_add_claims.sql (44.27ms)21042026/09/23 13:02:12 OK 20260920000000_drop_claims.sql (44.2ms)21052026/09/23 13:02:12 OK 20260923120000_add_pushes.sql (30.93ms)21062026/09/23 13:02:12 goose: successfully migrated database to version: 2026092312000021072026/09/23 13:02:12 OK 1_commit_pending_closure.sql (5.04ms)21082026/09/23 13:02:12 OK 2_object_stats_trigger.sql (1ms)21092026/09/23 13:02:12 OK 3_commit_push.sql (859µs)21102026/09/23 13:02:12 goose: up to current file version: 321112026/09/23 13:02:12 INFO Received uploads request method=POST path=/api/pending_closures21122026/09/23 13:02:12 WARN Rate limiter enabled after throttle name=s3-test rate=521132026/09/23 13:02:12 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2114=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2115 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102116 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002117--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.37s)2118=== CONT TestCompleteMultipartUpload_ErrorButObjectExists21192026/09/23 13:02:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21202026/09/23 13:02:12 WARN mTLS auth: bound subjects configured but subject DN unavailable21212026/09/23 13:02:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2122--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.26s)2123=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected21242026-09-23 13:02:13.038 UTC [52217] ERROR: relation "goose_db_version" does not exist at character 3621252026-09-23 13:02:13.038 UTC [52217] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21262026-09-23 13:02:13.183 UTC [52219] ERROR: relation "goose_db_version" does not exist at character 3621272026-09-23 13:02:13.183 UTC [52219] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2128=== NAME TestOrphanedObjectsGCStressTest2129 orphaned_objects_gc_test.go:509: Stress test completed successfully:2130 orphaned_objects_gc_test.go:510: - Active objects preserved: 202131 orphaned_objects_gc_test.go:511: - Objects deleted: 2102132 orphaned_objects_gc_test.go:512: - Total GC'd: 2102133--- PASS: TestOrphanedObjectsGCStressTest (11.08s)2134=== CONT TestRedundantMultipartUpload21352026/09/23 13:02:13 OK 20241026095416_initial_model.sql (168.1ms)21362026/09/23 13:02:13 OK 20251210153512_drop_unused_gin_index.sql (18.57ms)21372026/09/23 13:02:13 OK 20251218171726_add_pins.sql (49.19ms)21382026-09-23 13:02:13.412 UTC [52220] ERROR: relation "goose_db_version" does not exist at character 3621392026-09-23 13:02:13.412 UTC [52220] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21402026/09/23 13:02:13 OK 20260628120000_add_object_size_and_stats.sql (46.5ms)21412026/09/23 13:02:13 OK 20241026095416_initial_model.sql (178.79ms)21422026/09/23 13:02:13 OK 20260905000000_add_claims.sql (15.57ms)21432026/09/23 13:02:13 OK 20251210153512_drop_unused_gin_index.sql (4.78ms)21442026/09/23 13:02:13 OK 20260920000000_drop_claims.sql (3.66ms)21452026/09/23 13:02:13 OK 20260923120000_add_pushes.sql (23.74ms)21462026/09/23 13:02:13 goose: successfully migrated database to version: 2026092312000021472026/09/23 13:02:13 OK 20251218171726_add_pins.sql (26.98ms)21482026/09/23 13:02:13 OK 1_commit_pending_closure.sql (2.02ms)21492026/09/23 13:02:13 OK 2_object_stats_trigger.sql (392.88µs)21502026/09/23 13:02:13 OK 3_commit_push.sql (345.75µs)21512026/09/23 13:02:13 goose: up to current file version: 321522026/09/23 13:02:13 OK 20260628120000_add_object_size_and_stats.sql (54.47ms)21532026/09/23 13:02:13 OK 20260905000000_add_claims.sql (83.95ms)21542026/09/23 13:02:13 OK 20260920000000_drop_claims.sql (29.75ms)21552026/09/23 13:02:13 OK 20241026095416_initial_model.sql (203.98ms)21562026/09/23 13:02:13 OK 20251210153512_drop_unused_gin_index.sql (15.43ms)21572026/09/23 13:02:13 OK 20260923120000_add_pushes.sql (32.45ms)21582026/09/23 13:02:13 goose: successfully migrated database to version: 2026092312000021592026/09/23 13:02:13 OK 1_commit_pending_closure.sql (2.84ms)21602026/09/23 13:02:13 OK 2_object_stats_trigger.sql (606µs)21612026/09/23 13:02:13 OK 3_commit_push.sql (364.58µs)21622026/09/23 13:02:13 goose: up to current file version: 321632026-09-23 13:02:13.717 UTC [52223] ERROR: relation "goose_db_version" does not exist at character 3621642026-09-23 13:02:13.717 UTC [52223] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21652026/09/23 13:02:13 OK 20251218171726_add_pins.sql (51.61ms)21662026-09-23 13:02:13.762 UTC [52224] ERROR: relation "goose_db_version" does not exist at character 3621672026-09-23 13:02:13.762 UTC [52224] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21682026/09/23 13:02:13 OK 20260628120000_add_object_size_and_stats.sql (45.63ms)21692026/09/23 13:02:13 OK 20260905000000_add_claims.sql (53.19ms)2170--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.74s)21712026/09/23 13:02:13 OK 20260920000000_drop_claims.sql (32.34ms)2172=== CONT TestServerTLSConfig/no_client_CA2173=== CONT TestService_ReadScope_PublicByDefault21742026/09/23 13:02:13 OK 20260923120000_add_pushes.sql (33.61ms)21752026/09/23 13:02:13 goose: successfully migrated database to version: 2026092312000021762026/09/23 13:02:13 OK 1_commit_pending_closure.sql (1.67ms)21772026/09/23 13:02:13 OK 2_object_stats_trigger.sql (445.04µs)21782026/09/23 13:02:13 OK 3_commit_push.sql (386.13µs)21792026/09/23 13:02:13 goose: up to current file version: 321802026/09/23 13:02:14 OK 20241026095416_initial_model.sql (199.23ms)21812026/09/23 13:02:14 OK 20251210153512_drop_unused_gin_index.sql (16.66ms)21822026/09/23 13:02:14 OK 20241026095416_initial_model.sql (204.13ms)21832026/09/23 13:02:14 OK 20251218171726_add_pins.sql (28.29ms)21842026/09/23 13:02:14 OK 20251210153512_drop_unused_gin_index.sql (19.09ms)21852026/09/23 13:02:14 OK 20251218171726_add_pins.sql (18.76ms)21862026/09/23 13:02:14 OK 20260628120000_add_object_size_and_stats.sql (34ms)21872026/09/23 13:02:14 OK 20260628120000_add_object_size_and_stats.sql (64.81ms)21882026/09/23 13:02:14 OK 20260905000000_add_claims.sql (95.16ms)21892026/09/23 13:02:14 OK 20260905000000_add_claims.sql (73.29ms)21902026/09/23 13:02:14 OK 20260920000000_drop_claims.sql (47.45ms)21912026/09/23 13:02:14 OK 20260920000000_drop_claims.sql (30.78ms)21922026/09/23 13:02:14 OK 20260923120000_add_pushes.sql (17.61ms)21932026/09/23 13:02:14 goose: successfully migrated database to version: 2026092312000021942026/09/23 13:02:14 OK 1_commit_pending_closure.sql (2.8ms)21952026/09/23 13:02:14 OK 2_object_stats_trigger.sql (716.58µs)21962026/09/23 13:02:14 OK 3_commit_push.sql (419.17µs)21972026/09/23 13:02:14 goose: up to current file version: 321982026/09/23 13:02:14 OK 20260923120000_add_pushes.sql (28.77ms)21992026/09/23 13:02:14 goose: successfully migrated database to version: 2026092312000022002026/09/23 13:02:14 OK 1_commit_pending_closure.sql (2.5ms)22012026/09/23 13:02:14 OK 2_object_stats_trigger.sql (494.33µs)22022026/09/23 13:02:14 OK 3_commit_push.sql (350.92µs)22032026/09/23 13:02:14 goose: up to current file version: 32204--- PASS: TestReadRedirectKeepsNarinfoProxied (2.86s)2205=== CONT TestServerTLSConfig/missing_CA_file2206=== CONT TestServerTLSConfig/not_a_PEM_file2207--- PASS: TestServerTLSConfig (0.00s)2208 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2209 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2210 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)2211=== CONT TestResolveDBConnectionString/flag_wins2212=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2213=== CONT TestResolveDBConnectionString/nothing_configured2214=== CONT TestResolveDBConnectionString/missing_file_is_an_error2215=== CONT TestResolveDBConnectionString/file_when_flag_empty2216=== CONT TestIsValidCachePath/narinfo2217=== CONT TestIsValidCachePath/index.html2218=== CONT TestIsValidCachePath/short_hash2219=== CONT TestIsValidCachePath/wrong_extension2220=== CONT TestIsValidCachePath/leading_slash2221=== CONT TestIsValidCachePath/empty2222=== CONT TestIsValidCachePath/random_path2223=== CONT TestIsValidCachePath/invalid_char_u2224=== CONT TestIsValidCachePath/invalid_char_e2225=== CONT TestIsValidCachePath/traversal_in_middle2226=== CONT TestIsValidCachePath/traversal_parent2227=== CONT TestIsValidCachePath/nar_uncompressed2228=== CONT TestIsValidCachePath/nix-cache-info2229=== CONT TestIsValidCachePath/realisation2230=== CONT TestIsValidCachePath/log2231=== CONT TestIsValidCachePath/ls2232=== CONT TestIsValidCachePath/nar_xz2233=== CONT TestIsValidCachePath/nar_bz22234=== CONT TestIsValidCachePath/nar_zst2235=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2236=== CONT TestParseSingleRange/none2237--- PASS: TestIsValidCachePath (0.00s)2238 --- PASS: TestIsValidCachePath/narinfo (0.00s)2239 --- PASS: TestIsValidCachePath/index.html (0.00s)2240 --- PASS: TestIsValidCachePath/short_hash (0.00s)2241 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2242 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2243 --- PASS: TestIsValidCachePath/empty (0.00s)2244 --- PASS: TestIsValidCachePath/random_path (0.00s)2245 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2246 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2247 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2248 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2249 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2250 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2251 --- PASS: TestIsValidCachePath/realisation (0.00s)2252 --- PASS: TestIsValidCachePath/log (0.00s)2253 --- PASS: TestIsValidCachePath/ls (0.00s)2254 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2255 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2256 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2257 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2258=== CONT TestParseSingleRange/open-ended2259=== CONT TestParseSingleRange/start_far_past_EOF2260=== CONT TestParseSingleRange/start_past_EOF2261=== CONT TestParseSingleRange/single_byte2262=== CONT TestParseSingleRange/suffix_exceeds_size2263=== CONT TestParseSingleRange/suffix2264=== CONT TestParseSingleRange/end_clamped_to_size2265=== CONT TestParseSingleRange/multi-range_ignored2266=== CONT TestParseSingleRange/malformed_no_dash2267=== CONT TestParseSingleRange/closed2268=== CONT TestParseSingleRange/malformed_end_before_start2269=== CONT TestParseSingleRange/malformed_both_empty2270=== CONT TestParseSingleRange/unknown_unit2271--- PASS: TestParseSingleRange (0.00s)2272 --- PASS: TestParseSingleRange/none (0.00s)2273 --- PASS: TestParseSingleRange/open-ended (0.00s)2274 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2275 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2276 --- PASS: TestParseSingleRange/single_byte (0.00s)2277 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2278 --- PASS: TestParseSingleRange/suffix (0.00s)2279 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2280 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2281 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2282 --- PASS: TestParseSingleRange/closed (0.00s)2283 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2284 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2285 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2286=== CONT TestClientErrorHandling/InvalidStorePath2287--- PASS: TestResolveDBConnectionString (0.03s)2288 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2289 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2290 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2291 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2292 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)22932026-09-23 13:02:14.503 UTC [52229] ERROR: relation "goose_db_version" does not exist at character 3622942026-09-23 13:02:14.503 UTC [52229] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2295--- PASS: TestService_Rustfstest (3.01s)2296=== CONT TestClientErrorHandling/ServerNotAvailable22972026/09/23 13:02:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22982026/09/23 13:02:14 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MjVjZTVmZDItMmVhNC00NjMxLWE0NzktYmIyZTNjZWIzNWY2LmJjOGQ5ZTY3LTFkNDMtNDNjNC05Yjg2LWEzOGNlOGY2ZTQ0Y3gxNzkwMTY4NTMyNjEyNzA3MDAw parts=1222992026/09/23 13:02:14 INFO Received uploads request method=POST path=/api/pending_closures2300--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.48s)2301=== CONT TestClientErrorHandling/InvalidAuthToken23022026/09/23 13:02:14 OK 20241026095416_initial_model.sql (277.16ms)23032026/09/23 13:02:14 OK 20251210153512_drop_unused_gin_index.sql (16.39ms)23042026/09/23 13:02:14 OK 20251218171726_add_pins.sql (38.65ms)23052026/09/23 13:02:14 OK 20260628120000_add_object_size_and_stats.sql (45.48ms)23062026/09/23 13:02:15 INFO Received uploads request method=POST path=/api/pending_closures23072026/09/23 13:02:15 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23082026/09/23 13:02:15 OK 20260905000000_add_claims.sql (60.27ms)23092026/09/23 13:02:15 OK 20260920000000_drop_claims.sql (26.76ms)23102026/09/23 13:02:15 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst23112026/09/23 13:02:15 INFO Received uploads request method=POST path=/api/pending_closures2312--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.24s)2313=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure23142026/09/23 13:02:15 INFO Received uploads request method=POST path=/23152026/09/23 13:02:15 OK 20260923120000_add_pushes.sql (27.09ms)23162026/09/23 13:02:15 goose: successfully migrated database to version: 2026092312000023172026/09/23 13:02:15 OK 1_commit_pending_closure.sql (1.07ms)23182026/09/23 13:02:15 OK 2_object_stats_trigger.sql (255.33µs)23192026/09/23 13:02:15 OK 3_commit_push.sql (230.04µs)23202026/09/23 13:02:15 goose: up to current file version: 323212026/09/23 13:02:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.780539ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23222026-09-23 13:02:15.173 UTC [52236] ERROR: relation "goose_db_version" does not exist at character 3623232026-09-23 13:02:15.173 UTC [52236] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23242026-09-23 13:02:15.255 UTC [52237] ERROR: relation "goose_db_version" does not exist at character 3623252026-09-23 13:02:15.255 UTC [52237] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23262026/09/23 13:02:15 INFO Received push request method=POST path=/api/pushes23272026/09/23 13:02:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.725025ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2328=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart23292026/09/23 13:02:15 INFO Received complete multipart upload request method=POST path=/2330=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts23312026/09/23 13:02:15 INFO Received request for more parts method=POST path=/23322026/09/23 13:02:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23332026/09/23 13:02:15 INFO Signed narinfos id=1 count=12334--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.52s)2335=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info23362026/09/23 13:02:15 INFO Received uploads request method=POST path=/2337=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23382026/09/23 13:02:15 INFO Received complete multipart upload request method=POST path=/2339=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23402026/09/23 13:02:15 INFO Received request for more parts method=POST path=/2341=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23422026/09/23 13:02:15 INFO Received uploads request method=POST path=/2343--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2344 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2345 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2346 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2347 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2348=== CONT TestIsValidUploadKey/narinfo2349=== CONT TestIsValidUploadKey/realisation_plus_in_output2350=== CONT TestIsValidUploadKey/unknown_type2351=== CONT TestIsValidUploadKey/empty_key2352=== CONT TestIsValidUploadKey/absolute2353=== CONT TestIsValidUploadKey/traversal_nar2354=== CONT TestIsValidUploadKey/traversal2355=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2356=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2357=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2358=== CONT TestIsValidUploadKey/index.html2359=== CONT TestIsValidUploadKey/nix-cache-info2360=== CONT TestIsValidUploadKey/build_log_home-manager_file2361=== CONT TestIsValidUploadKey/realisation2362=== CONT TestIsValidUploadKey/build_log_equals2363=== CONT TestIsValidUploadKey/build_log_question_mark2364=== CONT TestIsValidUploadKey/build_log_plus_in_name2365=== CONT TestIsValidUploadKey/nar_plain2366=== CONT TestIsValidUploadKey/build_log2367=== CONT TestIsValidUploadKey/listing2368=== CONT TestIsValidUploadKey/nar_xz2369=== CONT TestIsValidUploadKey/nar_zst2370--- PASS: TestIsValidUploadKey (0.00s)2371 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2372 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2373 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2374 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2375 --- PASS: TestIsValidUploadKey/absolute (0.00s)2376 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2377 --- PASS: TestIsValidUploadKey/traversal (0.00s)2378 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2379 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2380 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2381 --- PASS: TestIsValidUploadKey/index.html (0.00s)2382 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2383 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2384 --- PASS: TestIsValidUploadKey/realisation (0.00s)2385 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2386 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2387 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2388 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2389 --- PASS: TestIsValidUploadKey/build_log (0.00s)2390 --- PASS: TestIsValidUploadKey/listing (0.00s)2391 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2392 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2393=== CONT TestProxyWriteTimeout/narinfo2394=== CONT TestProxyWriteTimeout/10_GiB_nar2395=== CONT TestProxyWriteTimeout/unknown_size2396=== CONT TestProxyWriteTimeout/1_GiB_nar2397--- PASS: TestProxyWriteTimeout (0.00s)2398 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2399 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2400 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2401 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2402=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2403=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected24042026/09/23 13:02:15 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]2405=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2406=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected24072026/09/23 13:02:15 WARN Authentication failed token_preview=eyJhbGciOi...Rspo2lvM4A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2408=== CONT TestService_RequireScope_OIDC/builder_may_write2409=== CONT TestService_RequireScope_OIDC/static_token_may_admin2410=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2411=== CONT TestService_RequireScope_OIDC/writer_implies_read2412=== CONT TestService_RequireScope_OIDC/reader_may_read2413=== CONT TestService_RequireScope_OIDC/static_token_may_write2414=== CONT TestService_RequireScope_OIDC/ops_may_not_write2415=== CONT TestService_RequireScope_OIDC/reader_may_not_write2416=== CONT TestService_RequireScope_OIDC/ops_may_admin2417=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2418=== CONT TestCacheConfigHandler/full_config,_no_issuer2419=== CONT TestCacheConfigHandler/no_signing_keys2420=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2421=== CONT TestCacheConfigHandler/no_cache_url_configured2422--- PASS: TestCacheConfigHandler (0.00s)2423 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2424 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2425 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2426 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2427--- PASS: TestService_RequireScope_OIDC (3.22s)2428 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2429 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2430 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2431 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2432 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2433 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2434 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2435 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2436 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2437 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2438--- PASS: TestService_AuthMiddleware_OIDC (3.27s)2439 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2440 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2441 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2442 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2443--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)2444 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)2445 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2446 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)24472026/09/23 13:02:15 OK 20241026095416_initial_model.sql (174.44ms)24482026/09/23 13:02:15 OK 20251210153512_drop_unused_gin_index.sql (719.5µs)24492026/09/23 13:02:15 OK 20251218171726_add_pins.sql (13.68ms)24502026/09/23 13:02:15 OK 20260628120000_add_object_size_and_stats.sql (9.55ms)24512026/09/23 13:02:15 OK 20241026095416_initial_model.sql (115.58ms)24522026/09/23 13:02:15 OK 20251210153512_drop_unused_gin_index.sql (5.59ms)24532026/09/23 13:02:15 OK 20251218171726_add_pins.sql (18.56ms)24542026/09/23 13:02:15 OK 20260905000000_add_claims.sql (24.68ms)24552026/09/23 13:02:15 OK 20260920000000_drop_claims.sql (33.05ms)24562026/09/23 13:02:15 OK 20260628120000_add_object_size_and_stats.sql (33.65ms)24572026/09/23 13:02:15 OK 20260923120000_add_pushes.sql (12.19ms)24582026/09/23 13:02:15 goose: successfully migrated database to version: 2026092312000024592026-09-23 13:02:15.500 UTC [52238] ERROR: relation "goose_db_version" does not exist at character 3624602026-09-23 13:02:15.500 UTC [52238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC24612026/09/23 13:02:15 OK 1_commit_pending_closure.sql (1.35ms)24622026/09/23 13:02:15 OK 2_object_stats_trigger.sql (233.13µs)24632026/09/23 13:02:15 OK 3_commit_push.sql (197.17µs)24642026/09/23 13:02:15 goose: up to current file version: 324652026/09/23 13:02:15 OK 20260905000000_add_claims.sql (32.6ms)24662026/09/23 13:02:15 OK 20260920000000_drop_claims.sql (11.51ms)24672026/09/23 13:02:15 OK 20260923120000_add_pushes.sql (7.47ms)24682026/09/23 13:02:15 goose: successfully migrated database to version: 2026092312000024692026/09/23 13:02:15 OK 1_commit_pending_closure.sql (1.14ms)24702026/09/23 13:02:15 OK 2_object_stats_trigger.sql (265.96µs)24712026/09/23 13:02:15 OK 3_commit_push.sql (245.63µs)24722026/09/23 13:02:15 goose: up to current file version: 32473=== RUN TestPush_RejectsBadRequests/no_roots2474=== PAUSE TestPush_RejectsBadRequests/no_roots2475=== RUN TestPush_RejectsBadRequests/no_objects2476=== PAUSE TestPush_RejectsBadRequests/no_objects2477=== RUN TestPush_RejectsBadRequests/bad_root2478=== PAUSE TestPush_RejectsBadRequests/bad_root2479=== RUN TestPush_RejectsBadRequests/root_not_in_objects2480=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2481=== CONT TestPush_RejectsBadRequests/no_roots24822026/09/23 13:02:15 INFO Received push request method=POST path=/api/pushes2483=== CONT TestPush_RejectsBadRequests/bad_root2484=== CONT TestPush_RejectsBadRequests/root_not_in_objects24852026/09/23 13:02:15 INFO Received push request method=POST path=/api/pushes24862026/09/23 13:02:15 INFO Received push request method=POST path=/api/pushes2487=== CONT TestPush_RejectsBadRequests/no_objects24882026/09/23 13:02:15 INFO Received push request method=POST path=/api/pushes2489--- PASS: TestPush_RejectsBadRequests (3.55s)2490 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2491 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2492 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2493 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)24942026/09/23 13:02:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=821.038328ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24952026/09/23 13:02:15 OK 20241026095416_initial_model.sql (205.71ms)24962026/09/23 13:02:15 OK 20251210153512_drop_unused_gin_index.sql (19.05ms)24972026/09/23 13:02:15 OK 20251218171726_add_pins.sql (30ms)24982026/09/23 13:02:15 OK 20260628120000_add_object_size_and_stats.sql (36.23ms)24992026/09/23 13:02:15 OK 20260905000000_add_claims.sql (76.46ms)25002026/09/23 13:02:15 INFO Received uploads request method=POST path=/api/pending_closures25012026/09/23 13:02:15 OK 20260920000000_drop_claims.sql (66.68ms)25022026/09/23 13:02:16 OK 20260923120000_add_pushes.sql (28.86ms)25032026/09/23 13:02:16 goose: successfully migrated database to version: 2026092312000025042026/09/23 13:02:16 OK 1_commit_pending_closure.sql (4.32ms)25052026/09/23 13:02:16 OK 2_object_stats_trigger.sql (1.28ms)25062026/09/23 13:02:16 OK 3_commit_push.sql (1.08ms)25072026/09/23 13:02:16 goose: up to current file version: 325082026-09-23 13:02:16.057 UTC [52239] ERROR: relation "goose_db_version" does not exist at character 3625092026-09-23 13:02:16.057 UTC [52239] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25102026/09/23 13:02:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25112026/09/23 13:02:16 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjVjZTVmZDItMmVhNC00NjMxLWE0NzktYmIyZTNjZWIzNWY2Ljc1ZTYxYzdkLTI5MzItNDc4ZC1hYTcxLTZmYjA0YWFiYjI0NXgxNzkwMTY4NTM1OTQ5OTY5MDAw25122026/09/23 13:02:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjVjZTVmZDItMmVhNC00NjMxLWE0NzktYmIyZTNjZWIzNWY2Ljc1ZTYxYzdkLTI5MzItNDc4ZC1hYTcxLTZmYjA0YWFiYjI0NXgxNzkwMTY4NTM1OTQ5OTY5MDAw parts=12513--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.49s)25142026/09/23 13:02:16 INFO Received push request method=POST path=/api/pushes25152026/09/23 13:02:16 INFO Received complete push request method=POST path=/api/pushes/1/complete25162026/09/23 13:02:16 OK 20241026095416_initial_model.sql (227.7ms)25172026/09/23 13:02:16 OK 20251210153512_drop_unused_gin_index.sql (19.19ms)25182026/09/23 13:02:16 INFO Received push request method=POST path=/api/pushes25192026/09/23 13:02:16 OK 20251218171726_add_pins.sql (66.86ms)25202026/09/23 13:02:16 INFO Received complete push request method=POST path=/api/pushes/2/complete25212026-09-23 13:02:16.458 UTC [52240] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo25222026-09-23 13:02:16.458 UTC [52240] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE25232026-09-23 13:02:16.458 UTC [52240] STATEMENT: -- name: CommitPush :exec2524 SELECT commit_push($1::bigint)2525 2526--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (3.50s)25272026/09/23 13:02:16 OK 20260628120000_add_object_size_and_stats.sql (28.48ms)25282026/09/23 13:02:16 OK 20260905000000_add_claims.sql (26.91ms)25292026/09/23 13:02:16 OK 20260920000000_drop_claims.sql (18.27ms)25302026/09/23 13:02:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.471915647s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25312026/09/23 13:02:16 OK 20260923120000_add_pushes.sql (6.07ms)25322026/09/23 13:02:16 goose: successfully migrated database to version: 2026092312000025332026-09-23 13:02:16.531 UTC [52241] ERROR: relation "goose_db_version" does not exist at character 3625342026-09-23 13:02:16.531 UTC [52241] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25352026/09/23 13:02:16 OK 1_commit_pending_closure.sql (2.27ms)25362026/09/23 13:02:16 OK 2_object_stats_trigger.sql (399.92µs)25372026/09/23 13:02:16 OK 3_commit_push.sql (322.13µs)25382026/09/23 13:02:16 goose: up to current file version: 325392026/09/23 13:02:16 INFO Received uploads request method=POST path=/api/pending_closures25402026/09/23 13:02:16 INFO Received uploads request method=POST path=/api/pending_closures25412026/09/23 13:02:16 OK 20241026095416_initial_model.sql (105.72ms)25422026/09/23 13:02:16 OK 20251210153512_drop_unused_gin_index.sql (14.32ms)25432026/09/23 13:02:16 OK 20251218171726_add_pins.sql (26.7ms)25442026/09/23 13:02:16 OK 20260628120000_add_object_size_and_stats.sql (32.35ms)25452026-09-23 13:02:16.772 UTC [52242] ERROR: relation "goose_db_version" does not exist at character 3625462026-09-23 13:02:16.772 UTC [52242] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25472026/09/23 13:02:16 OK 20260905000000_add_claims.sql (30.44ms)25482026/09/23 13:02:16 OK 20260920000000_drop_claims.sql (20.48ms)25492026/09/23 13:02:16 OK 20260923120000_add_pushes.sql (8.56ms)25502026/09/23 13:02:16 goose: successfully migrated database to version: 2026092312000025512026/09/23 13:02:16 OK 1_commit_pending_closure.sql (849.54µs)25522026/09/23 13:02:16 OK 2_object_stats_trigger.sql (192.29µs)25532026/09/23 13:02:16 OK 3_commit_push.sql (152.79µs)25542026/09/23 13:02:16 goose: up to current file version: 32555--- PASS: TestService_ReadScope_PublicByDefault (2.97s)25562026/09/23 13:02:16 OK 20241026095416_initial_model.sql (94.84ms)25572026/09/23 13:02:16 OK 20251210153512_drop_unused_gin_index.sql (10.05ms)25582026/09/23 13:02:16 OK 20251218171726_add_pins.sql (15.45ms)25592026/09/23 13:02:16 OK 20260628120000_add_object_size_and_stats.sql (8.9ms)25602026/09/23 13:02:16 OK 20260905000000_add_claims.sql (13.11ms)25612026/09/23 13:02:16 OK 20260920000000_drop_claims.sql (17.32ms)25622026/09/23 13:02:16 OK 20260923120000_add_pushes.sql (5.43ms)25632026/09/23 13:02:16 goose: successfully migrated database to version: 2026092312000025642026/09/23 13:02:16 OK 1_commit_pending_closure.sql (1.12ms)25652026/09/23 13:02:16 OK 2_object_stats_trigger.sql (248.42µs)25662026/09/23 13:02:16 OK 3_commit_push.sql (214.71µs)25672026/09/23 13:02:16 goose: up to current file version: 325682026/09/23 13:02:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25692026/09/23 13:02:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"25702026/09/23 13:02:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete25712026/09/23 13:02:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MjVjZTVmZDItMmVhNC00NjMxLWE0NzktYmIyZTNjZWIzNWY2LmU4Yjk1YTZjLTBkMGYtNGQyNi1iNzZmLTdlNmVkMTU5NTYxMHgxNzkwMTY4NTM2NTcyMjk0MDAw parts=122572--- PASS: TestRedundantMultipartUpload (4.49s)25732026/09/23 13:02:18 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25742026/09/23 13:02:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.879998ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25752026/09/23 13:02:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.531388ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25762026/09/23 13:02:18 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=781.7118ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25772026/09/23 13:02:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.609652792s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25782026/09/23 13:02:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused"25792026/09/23 13:02:21 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25802026/09/23 13:02:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.621946ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25812026/09/23 13:02:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.214737ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25822026/09/23 13:02:21 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=805.423937ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25832026/09/23 13:02:22 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.539655937s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config25842026/09/23 13:02:24 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25852026/09/23 13:02:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.924672ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25862026/09/23 13:02:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.086173ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25872026/09/23 13:02:24 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=865.414937ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures25882026/09/23 13:02:25 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.706269004s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2589--- PASS: TestClientErrorHandling (0.00s)2590 --- PASS: TestClientErrorHandling/InvalidStorePath (2.78s)2591 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.69s)2592 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.91s)2593PASS2594{"timestamp":"2026-09-23T13:02:27.5315Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57675","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}25952026-09-23 13:02:27.670 UTC [51693] LOG: received smart shutdown request25962026-09-23 13:02:27.671 UTC [51693] LOG: background worker "logical replication launcher" (PID 51704) exited with exit code 125972026-09-23 13:02:27.683 UTC [51699] LOG: shutting down25982026-09-23 13:02:27.683 UTC [51699] LOG: checkpoint starting: shutdown immediate25992026-09-23 13:02:28.871 UTC [51699] LOG: checkpoint complete: wrote 13203 buffers (80.6%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.779 s, sync=0.369 s, total=1.188 s; sync files=21874, longest=0.001 s, average=0.001 s; distance=302636 kB, estimate=302636 kB; lsn=0/13F18190, redo lsn=0/13F1819026002026-09-23 13:02:28.884 UTC [51693] LOG: database system is shut down2601Running OIDC tests...2602=== RUN TestAudienceForIssuer2603=== PAUSE TestAudienceForIssuer2604=== RUN TestGlobMatch2605=== PAUSE TestGlobMatch2606=== RUN TestValidateToken_ValidToken2607=== PAUSE TestValidateToken_ValidToken2608=== RUN TestValidateToken_WrongAudience2609=== PAUSE TestValidateToken_WrongAudience2610=== RUN TestValidateToken_Expired2611=== PAUSE TestValidateToken_Expired2612=== RUN TestValidateToken_BoundClaimsMismatch2613=== PAUSE TestValidateToken_BoundClaimsMismatch2614=== RUN TestValidateToken_BoundSubjectMismatch2615=== PAUSE TestValidateToken_BoundSubjectMismatch2616=== RUN TestValidateToken_MultipleProviders2617=== PAUSE TestValidateToken_MultipleProviders2618=== RUN TestValidateToken_NoMatchingProvider2619=== PAUSE TestValidateToken_NoMatchingProvider2620=== RUN TestValidateToken_KubernetesServiceAccount2621=== PAUSE TestValidateToken_KubernetesServiceAccount2622=== RUN TestNewValidator_KubernetesRequiresCA2623=== PAUSE TestNewValidator_KubernetesRequiresCA2624=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2625=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2626=== RUN TestPins_ReservedForMatchingRule2627=== PAUSE TestPins_ReservedForMatchingRule2628=== RUN TestPins_TopLevelShorthand2629=== PAUSE TestPins_TopLevelShorthand2630=== RUN TestPins_ConfigValidation2631=== PAUSE TestPins_ConfigValidation2632=== RUN TestScopes_LegacyProviderDefaultsToWrite2633=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2634=== RUN TestScopes_Rules2635=== PAUSE TestScopes_Rules2636=== RUN TestScopes_ConfigValidation2637=== PAUSE TestScopes_ConfigValidation2638=== CONT TestAudienceForIssuer2639--- PASS: TestAudienceForIssuer (0.00s)2640=== CONT TestScopes_ConfigValidation2641=== CONT TestValidateToken_KubernetesServiceAccount2642=== CONT TestValidateToken_BoundClaimsMismatch2643=== CONT TestValidateToken_MultipleProviders2644=== CONT TestValidateToken_NoMatchingProvider2645=== CONT TestPins_TopLevelShorthand2646=== CONT TestValidateToken_BoundSubjectMismatch2647=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2648=== CONT TestPins_ReservedForMatchingRule2649--- PASS: TestScopes_ConfigValidation (0.01s)2650=== CONT TestValidateToken_Expired2651=== CONT TestValidateToken_ValidToken26522026/09/23 13:02:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57752/oidc2653--- PASS: TestPins_TopLevelShorthand (0.03s)2654=== CONT TestNewValidator_KubernetesRequiresCA26552026/09/23 13:02:29 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:577552656--- PASS: TestValidateToken_KubernetesServiceAccount (0.06s)2657=== CONT TestScopes_Rules26582026/09/23 13:02:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57757/oidc2659--- PASS: TestPins_ReservedForMatchingRule (0.07s)2660=== CONT TestScopes_LegacyProviderDefaultsToWrite26612026/09/23 13:02:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57759/oidc2662--- PASS: TestScopes_Rules (0.02s)2663=== CONT TestPins_ConfigValidation2664--- PASS: TestPins_ConfigValidation (0.00s)2665=== CONT TestValidateToken_WrongAudience26662026/09/23 13:02:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57754/oidc26672026/09/23 13:02:29 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:57761/oidc2668--- PASS: TestValidateToken_MultipleProviders (0.09s)2669=== CONT TestGlobMatch2670=== RUN TestGlobMatch/foo_foo2671=== PAUSE TestGlobMatch/foo_foo2672=== RUN TestGlobMatch/foo_bar2673=== PAUSE TestGlobMatch/foo_bar2674=== RUN TestGlobMatch/*_2675=== PAUSE TestGlobMatch/*_2676=== RUN TestGlobMatch/*_anything2677=== PAUSE TestGlobMatch/*_anything2678=== RUN TestGlobMatch/foo*_foo2679=== PAUSE TestGlobMatch/foo*_foo2680=== RUN TestGlobMatch/foo*_foobar2681=== PAUSE TestGlobMatch/foo*_foobar2682=== RUN TestGlobMatch/foo*_bar2683=== PAUSE TestGlobMatch/foo*_bar2684=== RUN TestGlobMatch/*bar_bar2685=== PAUSE TestGlobMatch/*bar_bar2686=== RUN TestGlobMatch/*bar_foobar2687=== PAUSE TestGlobMatch/*bar_foobar2688=== RUN TestGlobMatch/*bar_foo2689=== PAUSE TestGlobMatch/*bar_foo2690=== RUN TestGlobMatch/foo*bar_foobar2691=== PAUSE TestGlobMatch/foo*bar_foobar2692=== RUN TestGlobMatch/foo*bar_foo123bar2693=== PAUSE TestGlobMatch/foo*bar_foo123bar2694=== RUN TestGlobMatch/foo*bar_foobarbaz2695=== PAUSE TestGlobMatch/foo*bar_foobarbaz2696=== RUN TestGlobMatch/*/*_foo/bar2697=== PAUSE TestGlobMatch/*/*_foo/bar2698=== RUN TestGlobMatch/*/*_foo2699=== PAUSE TestGlobMatch/*/*_foo2700=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2701=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2702=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02703=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02704=== RUN TestGlobMatch/refs/*/main_refs/heads/main2705=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2706=== RUN TestGlobMatch/fo?_foo2707=== PAUSE TestGlobMatch/fo?_foo2708=== RUN TestGlobMatch/fo?_fo2709=== PAUSE TestGlobMatch/fo?_fo2710=== RUN TestGlobMatch/fo?_fooo2711=== PAUSE TestGlobMatch/fo?_fooo2712=== RUN TestGlobMatch/?oo_foo2713=== PAUSE TestGlobMatch/?oo_foo2714=== RUN TestGlobMatch/?oo_boo2715=== PAUSE TestGlobMatch/?oo_boo2716=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2717=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2718=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2719=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2720=== CONT TestGlobMatch/foo_foo2721=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2722=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2723=== CONT TestGlobMatch/?oo_boo2724=== CONT TestGlobMatch/?oo_foo2725=== CONT TestGlobMatch/fo?_fooo2726=== CONT TestGlobMatch/fo?_fo2727=== CONT TestGlobMatch/fo?_foo2728=== CONT TestGlobMatch/refs/*/main_refs/heads/main2729=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02730=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2731=== CONT TestGlobMatch/*/*_foo2732=== CONT TestGlobMatch/*/*_foo/bar2733=== CONT TestGlobMatch/foo*bar_foobarbaz2734=== CONT TestGlobMatch/foo*bar_foo123bar2735=== CONT TestGlobMatch/foo*bar_foobar2736=== CONT TestGlobMatch/*bar_foo2737=== CONT TestGlobMatch/*bar_foobar2738=== CONT TestGlobMatch/*bar_bar2739=== CONT TestGlobMatch/foo*_bar2740=== CONT TestGlobMatch/foo*_foobar2741=== CONT TestGlobMatch/foo*_foo2742=== CONT TestGlobMatch/*_anything2743=== CONT TestGlobMatch/*_2744=== CONT TestGlobMatch/foo_bar2745--- PASS: TestGlobMatch (0.00s)2746 --- PASS: TestGlobMatch/foo_foo (0.00s)2747 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2748 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2749 --- PASS: TestGlobMatch/?oo_boo (0.00s)2750 --- PASS: TestGlobMatch/?oo_foo (0.00s)2751 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2752 --- PASS: TestGlobMatch/fo?_fo (0.00s)2753 --- PASS: TestGlobMatch/fo?_foo (0.00s)2754 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2755 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2756 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2757 --- PASS: TestGlobMatch/*/*_foo (0.00s)2758 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2759 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2760 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2761 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2762 --- PASS: TestGlobMatch/*bar_foo (0.00s)2763 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2764 --- PASS: TestGlobMatch/*bar_bar (0.00s)2765 --- PASS: TestGlobMatch/foo*_bar (0.00s)2766 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2767 --- PASS: TestGlobMatch/foo*_foo (0.00s)2768 --- PASS: TestGlobMatch/*_anything (0.00s)2769 --- PASS: TestGlobMatch/*_ (0.00s)2770 --- PASS: TestGlobMatch/foo_bar (0.00s)27712026/09/23 13:02:30 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232772--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)27732026/09/23 13:02:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57766/oidc27742026/09/23 13:02:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57769/oidc2775--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)27762026/09/23 13:02:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57771/oidc2777--- PASS: TestValidateToken_ValidToken (0.10s)2778--- PASS: TestValidateToken_Expired (0.10s)27792026/09/23 13:02:30 http: TLS handshake error from 127.0.0.1:57774: remote error: tls: bad certificate2780--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)27812026/09/23 13:02:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57775/oidc27822026/09/23 13:02:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57777/oidc2783--- PASS: TestValidateToken_WrongAudience (0.04s)2784--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)27852026/09/23 13:02:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57779/oidc2786--- PASS: TestValidateToken_BoundSubjectMismatch (0.14s)27872026/09/23 13:02:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57768/oidc2788--- PASS: TestValidateToken_NoMatchingProvider (0.20s)2789PASS2790Running hook tests...2791=== RUN TestSendPathsEmpty2792=== PAUSE TestSendPathsEmpty2793=== RUN TestQueueEnqueueAndFetch2794=== PAUSE TestQueueEnqueueAndFetch2795=== RUN TestQueueDeduplication2796=== PAUSE TestQueueDeduplication2797=== RUN TestQueueRemove2798=== PAUSE TestQueueRemove2799=== RUN TestQueueFetchBatchLimit2800=== PAUSE TestQueueFetchBatchLimit2801=== RUN TestQueueRetryMovesToBack2802=== PAUSE TestQueueRetryMovesToBack2803=== RUN TestQueueFetchRemoveLifecycle2804=== PAUSE TestQueueFetchRemoveLifecycle2805=== RUN TestQueueConcurrentWriters2806=== PAUSE TestQueueConcurrentWriters2807=== RUN TestQueueRemoveLargeClosure2808=== PAUSE TestQueueRemoveLargeClosure2809=== RUN TestServerClientIntegration2810=== PAUSE TestServerClientIntegration2811=== RUN TestServerQueueError2812=== PAUSE TestServerQueueError2813=== RUN TestGetListenerSocketActivation2814 server_test.go:210: === RUN TestGetListenerSocketActivation2815 --- PASS: TestGetListenerSocketActivation (0.00s)2816 PASS2817 2818--- PASS: TestGetListenerSocketActivation (0.01s)2819=== RUN TestDrainIsolatesPoisonPath2820=== PAUSE TestDrainIsolatesPoisonPath2821=== RUN TestRunNotBlockedByPoisonHead2822=== PAUSE TestRunNotBlockedByPoisonHead2823=== RUN TestDrainGivesUpWhenServerDown2824=== PAUSE TestDrainGivesUpWhenServerDown2825=== RUN TestFailedPathPrunedByLaterClosure2826=== PAUSE TestFailedPathPrunedByLaterClosure2827=== RUN TestWorkerUploadsAndRemoves2828=== PAUSE TestWorkerUploadsAndRemoves2829=== RUN TestWorkerSkipsGCdPaths2830=== PAUSE TestWorkerSkipsGCdPaths2831=== RUN TestWorkerPrunesClosureDeps2832=== PAUSE TestWorkerPrunesClosureDeps2833=== RUN TestDrainTimeout2834=== PAUSE TestDrainTimeout2835=== CONT TestSendPathsEmpty2836=== CONT TestServerQueueError2837--- PASS: TestSendPathsEmpty (0.00s)2838=== CONT TestServerClientIntegration2839=== CONT TestWorkerUploadsAndRemoves2840=== CONT TestQueueRetryMovesToBack2841=== CONT TestDrainGivesUpWhenServerDown2842=== CONT TestQueueRemove2843=== CONT TestRunNotBlockedByPoisonHead2844=== CONT TestQueueConcurrentWriters2845=== CONT TestQueueFetchBatchLimit2846=== CONT TestQueueFetchRemoveLifecycle28472026/09/23 13:02:30 ERROR Failed to queue paths error="permission denied" count=12848--- PASS: TestServerQueueError (0.00s)2849=== CONT TestQueueRemoveLargeClosure2850--- PASS: TestServerClientIntegration (0.00s)2851=== CONT TestDrainTimeout2852--- PASS: TestQueueRemove (0.01s)2853=== CONT TestWorkerPrunesClosureDeps2854--- PASS: TestQueueFetchBatchLimit (0.01s)2855=== CONT TestWorkerSkipsGCdPaths28562026/09/23 13:02:30 INFO Uploading batch count=228572026/09/23 13:02:30 INFO Upload queue status pending=228582026/09/23 13:02:30 INFO Upload queue status pending=328592026/09/23 13:02:30 INFO Uploading batch count=228602026/09/23 13:02:30 INFO Uploading batch count=128612026/09/23 13:02:30 ERROR Upload failed error="upload failed" count=128622026/09/23 13:02:30 INFO Uploading batch count=228632026/09/23 13:02:30 ERROR Upload failed error="upload failed" count=228642026/09/23 13:02:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51526-809852379/TestDrainGivesUpWhenServerDown815310124/002/a2865--- PASS: TestQueueRetryMovesToBack (0.01s)2866=== CONT TestFailedPathPrunedByLaterClosure28672026/09/23 13:02:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51526-809852379/TestDrainGivesUpWhenServerDown815310124/002/b28682026/09/23 13:02:30 INFO Uploading batch count=228692026/09/23 13:02:30 ERROR Upload failed error="upload failed" count=228702026/09/23 13:02:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51526-809852379/TestDrainGivesUpWhenServerDown815310124/002/c2871--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2872=== CONT TestQueueDeduplication28732026/09/23 13:02:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51526-809852379/TestDrainGivesUpWhenServerDown815310124/002/d28742026/09/23 13:02:30 INFO Uploading batch count=228752026/09/23 13:02:30 ERROR Upload failed error="upload failed" count=228762026/09/23 13:02:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51526-809852379/TestDrainGivesUpWhenServerDown815310124/002/e28772026/09/23 13:02:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51526-809852379/TestDrainGivesUpWhenServerDown815310124/002/f28782026/09/23 13:02:30 ERROR Drain finished with paths left in queue remaining=1028792026/09/23 13:02:30 INFO Upload queue status pending=228802026/09/23 13:02:30 INFO Uploading batch count=128812026/09/23 13:02:30 INFO Upload queue status pending=228822026/09/23 13:02:30 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-51526-809852379/TestWorkerSkipsGCdPaths1851659945/002/nonexistent28832026/09/23 13:02:30 INFO Uploading batch count=128842026/09/23 13:02:30 ERROR Upload failed error="upload failed" count=128852026/09/23 13:02:30 INFO Uploading batch count=128862026/09/23 13:02:30 INFO Uploading batch count=128872026/09/23 13:02:30 INFO Uploading batch count=12888--- PASS: TestQueueDeduplication (0.00s)2889=== CONT TestDrainIsolatesPoisonPath2890--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2891=== CONT TestQueueEnqueueAndFetch2892--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)28932026/09/23 13:02:30 INFO Uploading batch count=428942026/09/23 13:02:30 ERROR Upload failed error="upload failed" count=428952026/09/23 13:02:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-51526-809852379/TestDrainIsolatesPoisonPath3729903973/002/bbb2896--- PASS: TestQueueEnqueueAndFetch (0.00s)28972026/09/23 13:02:30 INFO Uploading batch count=128982026/09/23 13:02:30 ERROR Upload failed error="upload failed" count=128992026/09/23 13:02:30 INFO Uploading batch count=129002026/09/23 13:02:30 ERROR Upload failed error="upload failed" count=129012026/09/23 13:02:30 INFO Uploading batch count=129022026/09/23 13:02:30 ERROR Upload failed error="upload failed" count=129032026/09/23 13:02:30 ERROR Drain finished with paths left in queue remaining=12904--- PASS: TestDrainIsolatesPoisonPath (0.00s)2905--- PASS: TestWorkerUploadsAndRemoves (0.03s)2906--- PASS: TestWorkerSkipsGCdPaths (0.02s)2907--- PASS: TestWorkerPrunesClosureDeps (0.02s)2908--- PASS: TestQueueRemoveLargeClosure (0.05s)2909--- PASS: TestQueueConcurrentWriters (0.12s)29102026/09/23 13:02:30 ERROR Upload failed error="context deadline exceeded" count=229112026/09/23 13:02:30 ERROR Drain finished with paths left in queue remaining=42912--- PASS: TestDrainTimeout (0.21s)29132026/09/23 13:02:31 INFO Uploading batch count=129142026/09/23 13:02:31 INFO Uploading batch count=129152026/09/23 13:02:31 INFO Uploading batch count=129162026/09/23 13:02:31 ERROR Upload failed error="upload failed" count=129172026/09/23 13:02:31 INFO Uploading batch count=129182026/09/23 13:02:31 ERROR Upload failed error="upload failed" count=129192026/09/23 13:02:31 INFO Uploading batch count=129202026/09/23 13:02:31 ERROR Upload failed error="upload failed" count=129212026/09/23 13:02:31 INFO Uploading batch count=129222026/09/23 13:02:31 ERROR Upload failed error="upload failed" count=129232026/09/23 13:02:31 ERROR Drain finished with paths left in queue remaining=12924--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2925PASS