niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #223
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestPartSizeForNAR11=== PAUSE TestPartSizeForNAR12=== RUN TestUploadMultipart_SupersededByPeer13=== PAUSE TestUploadMultipart_SupersededByPeer14=== RUN TestDumpPathCaseHackMatchesNix15--- PASS: TestDumpPathCaseHackMatchesNix (0.23s)16=== RUN TestDumpPathCaseHackCollision17--- PASS: TestDumpPathCaseHackCollision (0.00s)18=== RUN TestDumpPathMatchesNix19=== PAUSE TestDumpPathMatchesNix20=== RUN TestDumpPathSingleFile21=== PAUSE TestDumpPathSingleFile22=== RUN TestDumpPathWriterError23=== PAUSE TestDumpPathWriterError24=== RUN TestEncodeNixBase3225=== PAUSE TestEncodeNixBase3226=== RUN TestEncodeNixBase32WithRealHash27=== PAUSE TestEncodeNixBase32WithRealHash28=== RUN TestConvertHashToNix3229=== PAUSE TestConvertHashToNix3230=== RUN TestGetStorePathHash31=== PAUSE TestGetStorePathHash32=== RUN TestPathInfoHashCompatibility33=== PAUSE TestPathInfoHashCompatibility34=== RUN TestParsePathInfoJSON35=== PAUSE TestParsePathInfoJSON36=== RUN TestParsePathInfoJSONMultiplePaths37=== PAUSE TestParsePathInfoJSONMultiplePaths38=== RUN TestPathInfoCACompatibility39=== PAUSE TestPathInfoCACompatibility40=== RUN TestRateLimiterFeedback41=== PAUSE TestRateLimiterFeedback42=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess43=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess44=== RUN TestResolveStorePath45=== PAUSE TestResolveStorePath46=== RUN TestDoWithRetry_BodyReplayedViaGetBody47=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody48=== RUN TestShellSplit49=== PAUSE TestShellSplit50=== RUN TestShellSplitErrors51=== PAUSE TestShellSplitErrors52=== RUN TestStreamPushReportsEveryPath53=== PAUSE TestStreamPushReportsEveryPath54=== RUN TestStreamPushBatchesUnderLoad55=== PAUSE TestStreamPushBatchesUnderLoad56=== RUN TestStreamPushIsolatesFailures57=== PAUSE TestStreamPushIsolatesFailures58=== RUN TestStreamPushGivesUpOnDeadServer59=== PAUSE TestStreamPushGivesUpOnDeadServer60=== RUN TestStreamPushRequestLine61=== PAUSE TestStreamPushRequestLine62=== RUN TestSetClientTLS63=== PAUSE TestSetClientTLS64=== RUN TestSetClientTLSDoesNotMutateDefaultTransport65=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport66=== RUN TestSetClientTLSErrors67=== PAUSE TestSetClientTLSErrors68=== RUN TestStaticToken69=== PAUSE TestStaticToken70=== RUN TestFileTokenReadsAndCaches71=== PAUSE TestFileTokenReadsAndCaches72=== RUN TestFileTokenMissing73=== PAUSE TestFileTokenMissing74=== RUN TestFileTokenEmpty75=== PAUSE TestFileTokenEmpty76=== RUN TestScriptTokenNoExpiryRerunsEveryCall77=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall78=== RUN TestScriptTokenCachesUntilRefresh79=== PAUSE TestScriptTokenCachesUntilRefresh80=== RUN TestScriptTokenEmptyToken81=== PAUSE TestScriptTokenEmptyToken82=== RUN TestScriptTokenBadJSON83=== PAUSE TestScriptTokenBadJSON84=== RUN TestScriptTokenScriptFails85=== PAUSE TestScriptTokenScriptFails86=== RUN TestScriptTokenEmptyCommand87=== PAUSE TestScriptTokenEmptyCommand88=== CONT TestDoServerRequestAttachesToken89=== CONT TestStaticToken90=== CONT TestPathInfoCACompatibility91=== CONT TestConvertHashToNix3292=== RUN TestPathInfoCACompatibility/null_ca_field93=== PAUSE TestPathInfoCACompatibility/null_ca_field94=== CONT TestParsePathInfoJSONMultiplePaths95=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths96=== CONT TestParsePathInfoJSON97=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths98=== RUN TestParsePathInfoJSON/Nix_format99=== CONT TestGetStorePathHash100=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths101=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths102=== CONT TestSetClientTLSDoesNotMutateDefaultTransport103=== PAUSE TestParsePathInfoJSON/Nix_format104=== RUN TestGetStorePathHash/valid_store_path105=== RUN TestParsePathInfoJSON/Lix_format106=== PAUSE TestParsePathInfoJSON/Lix_format107=== RUN TestParsePathInfoJSON/empty_input108=== PAUSE TestParsePathInfoJSON/empty_input109=== RUN TestParsePathInfoJSON/whitespace_only110=== PAUSE TestParsePathInfoJSON/whitespace_only111=== RUN TestParsePathInfoJSON/invalid_JSON112=== PAUSE TestParsePathInfoJSON/invalid_JSON113=== PAUSE TestGetStorePathHash/valid_store_path114=== CONT TestSetClientTLS115=== RUN TestGetStorePathHash/basename_without_hyphen_should_error116=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error117=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error118=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error119=== CONT TestShellSplit120=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error121=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error122=== CONT TestStreamPushRequestLine123--- PASS: TestStaticToken (0.00s)124=== CONT TestSetClientTLSErrors125--- PASS: TestShellSplit (0.00s)126=== CONT TestStreamPushIsolatesFailures127=== RUN TestPathInfoCACompatibility/old_string_format_-_text128=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text129=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive130=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive131=== RUN TestPathInfoCACompatibility/new_structured_format_-_text132=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text133=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method134=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method135=== RUN TestConvertHashToNix32/SRI_format_to_Nix32136=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32137=== RUN TestConvertHashToNix32/already_Nix32_format138=== PAUSE TestConvertHashToNix32/already_Nix32_format139=== RUN TestConvertHashToNix32/invalid_format140=== PAUSE TestConvertHashToNix32/invalid_format141=== CONT TestStreamPushReportsEveryPath142=== CONT TestStreamPushGivesUpOnDeadServer143=== CONT TestShellSplitErrors144=== CONT TestPathInfoHashCompatibility145=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)146=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)147=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon148=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon149=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI150=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI151=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512152=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512153=== CONT TestScriptTokenCachesUntilRefresh1542026/09/19 11:22:21 ERROR Upload failed error="connection refused" count=201552026/09/19 11:22:21 ERROR Server seems unavailable, giving up on batch untried=17156--- PASS: TestShellSplitErrors (0.00s)1572026/09/19 11:22:21 ERROR Upload failed error="bad path" count=3158=== CONT TestStreamPushBatchesUnderLoad159--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)160=== CONT TestResolveStorePath161--- PASS: TestStreamPushReportsEveryPath (0.00s)162=== CONT TestScriptTokenEmptyCommand163--- PASS: TestScriptTokenEmptyCommand (0.00s)164=== CONT TestDoWithRetry_BodyReplayedViaGetBody165--- PASS: TestStreamPushIsolatesFailures (0.00s)166=== CONT TestScriptTokenScriptFails1672026/09/19 11:22:21 ERROR Upload failed error="stale build claim" count=1168=== RUN TestSetClientTLSErrors/missing_cert_file169=== PAUSE TestSetClientTLSErrors/missing_cert_file170=== RUN TestSetClientTLSErrors/missing_key_file1712026/09/19 11:22:21 WARN Rate limiter enabled after throttle name=server-test rate=51722026/09/19 11:22:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59042173--- PASS: TestResolveStorePath (0.01s)174=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess175=== PAUSE TestSetClientTLSErrors/missing_key_file176=== RUN TestSetClientTLSErrors/missing_ca_file177=== PAUSE TestSetClientTLSErrors/missing_ca_file178=== RUN TestSetClientTLSErrors/invalid_ca_file179=== PAUSE TestSetClientTLSErrors/invalid_ca_file180=== CONT TestScriptTokenBadJSON1812026/09/19 11:22:21 WARN Rate limiter enabled after throttle name=server-test rate=51822026/09/19 11:22:21 WARN Rate limiter backed off name=server-test rate=51832026/09/19 11:22:21 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59042184--- PASS: TestDoServerRequestAttachesToken (0.01s)185=== CONT TestRateLimiterFeedback186=== RUN TestRateLimiterFeedback/429_enables_limiter187=== PAUSE TestRateLimiterFeedback/429_enables_limiter188=== RUN TestRateLimiterFeedback/503_enables_limiter189=== PAUSE TestRateLimiterFeedback/503_enables_limiter190=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter191=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter192=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter193=== CONT TestScriptTokenEmptyToken194=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter195--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)196--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)197=== CONT TestScriptTokenNoExpiryRerunsEveryCall198=== CONT TestFileTokenEmpty199--- PASS: TestScriptTokenScriptFails (0.01s)200=== CONT TestDumpPathMatchesNix201--- PASS: TestFileTokenEmpty (0.00s)202=== CONT TestEncodeNixBase32WithRealHash203--- PASS: TestEncodeNixBase32WithRealHash (0.00s)204=== CONT TestEncodeNixBase32205=== RUN TestEncodeNixBase32/test_string_hash206=== PAUSE TestEncodeNixBase32/test_string_hash207=== RUN TestEncodeNixBase32/empty_input208=== PAUSE TestEncodeNixBase32/empty_input209=== CONT TestFilterOversizedClosures210=== RUN TestFilterOversizedClosures/no_limit_keeps_everything211=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything212=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== RUN TestSetClientTLS/rejects_connection_without_client_cert214=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped215=== RUN TestFilterOversizedClosures/all_closures_skipped216=== PAUSE TestFilterOversizedClosures/all_closures_skipped217=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert218=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA219=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA220=== RUN TestSetClientTLS/preserves_debug_logging_transport221=== PAUSE TestSetClientTLS/preserves_debug_logging_transport222=== CONT TestDumpPathWriterError223=== CONT TestDumpPathSingleFile224--- PASS: TestScriptTokenBadJSON (0.01s)225=== CONT TestUploadMultipart_SupersededByPeer226=== RUN TestUploadMultipart_SupersededByPeer/exists227=== PAUSE TestUploadMultipart_SupersededByPeer/exists228=== RUN TestUploadMultipart_SupersededByPeer/missing229=== PAUSE TestUploadMultipart_SupersededByPeer/missing230=== CONT TestPartSizeForNAR231=== RUN TestPartSizeForNAR/zero_stays_at_minimum232=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum233=== RUN TestPartSizeForNAR/small_stays_at_minimum234=== PAUSE TestPartSizeForNAR/small_stays_at_minimum235=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum236=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum237=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts238=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts239=== RUN TestPartSizeForNAR/1_TiB240=== PAUSE TestPartSizeForNAR/1_TiB241=== RUN TestPartSizeForNAR/5_TiB_S3_max_object242=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object243=== RUN TestPartSizeForNAR/capped_at_5_GiB244=== PAUSE TestPartSizeForNAR/capped_at_5_GiB245=== CONT TestFileTokenMissing246--- PASS: TestFileTokenMissing (0.00s)247=== CONT TestCaseHackSuffix248--- PASS: TestScriptTokenEmptyToken (0.01s)249=== CONT TestRegisterUploadedObjectReusesConnections250--- PASS: TestStreamPushRequestLine (0.03s)251=== CONT TestFileTokenReadsAndCaches252--- PASS: TestFileTokenReadsAndCaches (0.00s)253=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths254=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths255--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)256 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)257 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)258=== CONT TestParsePathInfoJSON/Nix_format259=== CONT TestParsePathInfoJSON/whitespace_only260=== CONT TestParsePathInfoJSON/Lix_format261=== CONT TestParsePathInfoJSON/empty_input262=== CONT TestGetStorePathHash/valid_store_path263=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error264=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error265=== CONT TestGetStorePathHash/basename_without_hyphen_should_error266--- PASS: TestGetStorePathHash (0.00s)267 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)268 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)269 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)270 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)271=== CONT TestParsePathInfoJSON/invalid_JSON272--- PASS: TestParsePathInfoJSON (0.00s)273 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)274 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)275 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)276 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)277 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)278=== CONT TestPathInfoCACompatibility/null_ca_field279=== CONT TestConvertHashToNix32/SRI_format_to_Nix32280=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method281=== CONT TestPathInfoCACompatibility/new_structured_format_-_text282=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive283=== CONT TestPathInfoCACompatibility/old_string_format_-_text284--- PASS: TestPathInfoCACompatibility (0.00s)285 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)286 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)287 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)288 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)289 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)290=== CONT TestConvertHashToNix32/invalid_format291=== CONT TestConvertHashToNix32/already_Nix32_format292=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)293=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512294--- PASS: TestConvertHashToNix32 (0.00s)295 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)296 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)297 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)298=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI299=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon300--- PASS: TestPathInfoHashCompatibility (0.00s)301 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)302 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)303 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)304 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)305=== CONT TestSetClientTLSErrors/missing_cert_file306=== CONT TestSetClientTLSErrors/missing_ca_file307=== CONT TestSetClientTLSErrors/invalid_ca_file308=== CONT TestSetClientTLSErrors/missing_key_file309=== CONT TestRateLimiterFeedback/429_enables_limiter310--- PASS: TestSetClientTLSErrors (0.01s)311 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)312 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)313 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)314 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3152026/09/19 11:22:21 WARN Rate limiter enabled after throttle name=server-test rate=53162026/09/19 11:22:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:591133172026/09/19 11:22:21 WARN Rate limiter backed off name=server-test rate=5318=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter319=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter320--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)321=== CONT TestRateLimiterFeedback/503_enables_limiter322=== CONT TestEncodeNixBase32/test_string_hash323=== CONT TestEncodeNixBase32/empty_input324--- PASS: TestEncodeNixBase32 (0.00s)325 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)326 --- PASS: TestEncodeNixBase32/empty_input (0.00s)327=== CONT TestFilterOversizedClosures/no_limit_keeps_everything328=== CONT TestFilterOversizedClosures/all_closures_skipped3292026/09/19 11:22:21 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50330=== CONT TestSetClientTLS/rejects_connection_without_client_cert3312026/09/19 11:22:21 WARN Rate limiter enabled after throttle name=server-test rate=53322026/09/19 11:22:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:59118333--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)334=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3352026/09/19 11:22:21 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000336--- PASS: TestFilterOversizedClosures (0.00s)337 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)338 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)339 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)340=== CONT TestSetClientTLS/preserves_debug_logging_transport3412026/09/19 11:22:21 WARN Rate limiter backed off name=server-test rate=5342--- PASS: TestRateLimiterFeedback (0.00s)343 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)344 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)345 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)346 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)347=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA348=== CONT TestUploadMultipart_SupersededByPeer/exists349=== CONT TestPartSizeForNAR/zero_stays_at_minimum350=== CONT TestUploadMultipart_SupersededByPeer/missing351--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)352 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)353 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)354=== CONT TestPartSizeForNAR/1_TiB355=== CONT TestPartSizeForNAR/capped_at_5_GiB356=== CONT TestPartSizeForNAR/5_TiB_S3_max_object357=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum358=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts359=== CONT TestPartSizeForNAR/small_stays_at_minimum360--- PASS: TestPartSizeForNAR (0.00s)361 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)362 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)363 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)364 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)365 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)367 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)368--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)369--- PASS: TestDumpPathWriterError (0.05s)3702026/09/19 11:22:21 http: TLS handshake error from 127.0.0.1:59121: remote error: tls: bad certificate371--- PASS: TestSetClientTLS (0.02s)372 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)373 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)374 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)375--- PASS: TestDumpPathSingleFile (0.06s)376--- PASS: TestCaseHackSuffix (0.05s)377--- PASS: TestDumpPathMatchesNix (0.08s)378--- PASS: TestStreamPushBatchesUnderLoad (0.10s)379--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)380PASS381Running server tests...382The files belonging to this database system will be owned by user "_nixbld1".383This user must also own the server process.384385The database cluster will be initialized with locale "C".386The default database encoding has accordingly been set to "SQL_ASCII".387The default text search configuration will be set to "english".388389Data page checksums are enabled.390391creating directory /nix/var/nix/builds/nix-97126-2725002786/postgres2277558922/data ... ok392creating subdirectories ... ok393selecting dynamic shared memory implementation ... posix394selecting default "max_connections" ... 100395selecting default "shared_buffers" ... 128MB396selecting default time zone ... UTC397creating configuration files ... ok398running bootstrap script ... ok399performing post-bootstrap initialization ... ok400syncing data to disk ... ok401402initdb: warning: enabling "trust" authentication for local connections403initdb: 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.404405Success. You can now start the database server using:406407 pg_ctl -D /nix/var/nix/builds/nix-97126-2725002786/postgres2277558922/data -l logfile start408409/nix/var/nix/builds/nix-97126-2725002786/postgres2277558922:5432 - no response4102026-09-19 11:22:23.210 UTC [97164] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4112026-09-19 11:22:23.210 UTC [97164] LOG: listening on Unix socket "/nix/var/nix/builds/nix-97126-2725002786/postgres2277558922/.s.PGSQL.5432"4122026-09-19 11:22:23.213 UTC [97171] LOG: database system was shut down at 2026-09-19 11:22:23 UTC4132026-09-19 11:22:23.214 UTC [97164] LOG: database system is ready to accept connections414/nix/var/nix/builds/nix-97126-2725002786/postgres2277558922:5432 - accepting connections415=== RUN TestService_AuthMiddleware416=== PAUSE TestService_AuthMiddleware417=== RUN TestService_AuthMiddleware_MTLSProxyHeader418=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader419=== RUN TestService_AuthMiddleware_MTLSBoundSubjects420=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects421=== RUN TestService_ReadAuthMiddleware422=== PAUSE TestService_ReadAuthMiddleware423=== RUN TestService_AuthMiddleware_OIDC424=== PAUSE TestService_AuthMiddleware_OIDC425=== RUN TestService_RequireScope_OIDC426=== PAUSE TestService_RequireScope_OIDC427=== RUN TestService_ReadScope_PublicByDefault428=== PAUSE TestService_ReadScope_PublicByDefault429=== RUN TestCacheConfigHandler430=== PAUSE TestCacheConfigHandler431=== RUN TestCacheStatsHandler432=== PAUSE TestCacheStatsHandler433=== RUN TestClaim_BuildWaitComplete434=== PAUSE TestClaim_BuildWaitComplete435=== RUN TestClaim_GCMarkedOutputCountsAsAbsent436=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent437=== RUN TestClaim_TooManyStreams438=== PAUSE TestClaim_TooManyStreams439=== RUN TestClaim_HolderDisconnectKeepsClaim440=== PAUSE TestClaim_HolderDisconnectKeepsClaim441=== RUN TestClaim_FailWakesWaitersButIsNotRemembered442=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered443=== RUN TestClaim_FailWithoutKindReleases444=== PAUSE TestClaim_FailWithoutKindReleases445=== RUN TestClaim_StaleHeartbeatStolen446=== PAUSE TestClaim_StaleHeartbeatStolen447=== RUN TestClaim_TwoInstances448=== PAUSE TestClaim_TwoInstances449=== RUN TestClaim_InputsTouched450=== PAUSE TestClaim_InputsTouched451=== RUN TestClaim_StreamsThroughServer452=== PAUSE TestClaim_StreamsThroughServer453=== RUN TestPresent454=== PAUSE TestPresent455=== RUN TestClientCADerivations456=== PAUSE TestClientCADerivations457=== RUN TestClientErrorHandling458=== PAUSE TestClientErrorHandling459=== RUN TestClientIntegration460=== PAUSE TestClientIntegration461=== RUN TestClientMultipleUploads462=== PAUSE TestClientMultipleUploads463=== RUN TestClientWithDependencies464=== PAUSE TestClientWithDependencies465=== RUN TestClientSharedPathCommittedMidPush466=== PAUSE TestClientSharedPathCommittedMidPush467=== RUN TestPinProtectsFromGC468=== PAUSE TestPinProtectsFromGC469=== RUN TestResolveDBConnectionString470=== PAUSE TestResolveDBConnectionString471=== RUN TestGCAdvisoryLockBlocksConcurrentRun4722026-09-19 11:22:23.490 UTC [97180] ERROR: relation "goose_db_version" does not exist at character 364732026-09-19 11:22:23.490 UTC [97180] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4742026/09/19 11:22:23 OK 20241026095416_initial_model.sql (17.7ms)4752026/09/19 11:22:23 OK 20251210153512_drop_unused_gin_index.sql (623.75µs)4762026/09/19 11:22:23 OK 20251218171726_add_pins.sql (872.71µs)4772026/09/19 11:22:23 OK 20260628120000_add_object_size_and_stats.sql (1.17ms)4782026/09/19 11:22:23 OK 20260905000000_add_claims.sql (928.04µs)4792026/09/19 11:22:23 goose: successfully migrated database to version: 202609050000004802026/09/19 11:22:23 OK 1_commit_pending_closure.sql (1.78ms)4812026/09/19 11:22:23 OK 2_object_stats_trigger.sql (189.13µs)4822026/09/19 11:22:23 goose: up to current file version: 2483--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.40s)484=== RUN TestGCBugBareHashReferences485=== PAUSE TestGCBugBareHashReferences486=== RUN TestGCMetrics487=== PAUSE TestGCMetrics488=== RUN TestGCTaskStore_StartNew489=== PAUSE TestGCTaskStore_StartNew490=== RUN TestGCTaskStore_DeduplicateSameParams491=== PAUSE TestGCTaskStore_DeduplicateSameParams492=== RUN TestGCTaskStore_ConflictDifferentParams493=== PAUSE TestGCTaskStore_ConflictDifferentParams494=== RUN TestGCTaskStore_GetEmpty495=== PAUSE TestGCTaskStore_GetEmpty496=== RUN TestGCTaskStore_GetReturnsLatest497=== PAUSE TestGCTaskStore_GetReturnsLatest498=== RUN TestGCTaskStore_CompletedAllowsNewTask499=== PAUSE TestGCTaskStore_CompletedAllowsNewTask500=== RUN TestGCTaskStore_PhaseUpdates501=== PAUSE TestGCTaskStore_PhaseUpdates502=== RUN TestGCTaskStore_Fail503=== PAUSE TestGCTaskStore_Fail504=== RUN TestGracefulShutdownDrainsInflight505=== PAUSE TestGracefulShutdownDrainsInflight506=== RUN TestService_healthCheckHandler507=== PAUSE TestService_healthCheckHandler508=== RUN TestService_readinessHandler509=== PAUSE TestService_readinessHandler510=== RUN TestGenerateLandingPage511=== PAUSE TestGenerateLandingPage512=== RUN TestCacheConfigHandlerMaxNarSize513=== PAUSE TestCacheConfigHandlerMaxNarSize514=== RUN TestCreatePendingClosureRejectsOversizedNAR515=== PAUSE TestCreatePendingClosureRejectsOversizedNAR516=== RUN TestNARDeduplicationMetadataUploadBug517=== PAUSE TestNARDeduplicationMetadataUploadBug518=== RUN TestMetricsInventory519=== PAUSE TestMetricsInventory520=== RUN TestService_NativeMTLS521=== PAUSE TestService_NativeMTLS522=== RUN TestServerTLSConfig523=== PAUSE TestServerTLSConfig524=== RUN TestMultipartCleanup525=== PAUSE TestMultipartCleanup526=== RUN TestObjectStatsTrigger527=== PAUSE TestObjectStatsTrigger528=== RUN TestOrphanedObjectsGC529=== PAUSE TestOrphanedObjectsGC530=== RUN TestOrphanedObjectsGCStressTest531=== PAUSE TestOrphanedObjectsGCStressTest532=== RUN TestResurrectedObjectNotDeleted533=== PAUSE TestResurrectedObjectNotDeleted534=== RUN TestParseSingleRange535=== PAUSE TestParseSingleRange536=== RUN TestIsValidCachePath537=== PAUSE TestIsValidCachePath538=== RUN TestReadProxyNarinfo539=== PAUSE TestReadProxyNarinfo540=== RUN TestReadProxyNarinfoAlreadyDecompressed541=== PAUSE TestReadProxyNarinfoAlreadyDecompressed542=== RUN TestReadProxyNarStreaming543=== PAUSE TestReadProxyNarStreaming544=== RUN TestReadProxy404545=== PAUSE TestReadProxy404546=== RUN TestReadProxyInvalidPath547=== PAUSE TestReadProxyInvalidPath548=== RUN TestReadProxyHead549=== PAUSE TestReadProxyHead550=== RUN TestReadProxyConditionalGet551=== PAUSE TestReadProxyConditionalGet552=== RUN TestReadProxyRootRedirectsToIndexHTML553=== PAUSE TestReadProxyRootRedirectsToIndexHTML554=== RUN TestReadProxyDisabled555=== PAUSE TestReadProxyDisabled556=== RUN TestReadRedirectNar557=== PAUSE TestReadRedirectNar558=== RUN TestReadRedirectKeepsNarinfoProxied559=== PAUSE TestReadRedirectKeepsNarinfoProxied560=== RUN TestReadProxyRangeRequest561=== PAUSE TestReadProxyRangeRequest562=== RUN TestReadRedirectUsesPublicS3URL563=== PAUSE TestReadRedirectUsesPublicS3URL564=== RUN TestRedundantMultipartUpload565=== PAUSE TestRedundantMultipartUpload566=== RUN TestCompleteMultipartUpload_ErrorButObjectExists567=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists568=== RUN TestCompletedNarNotReofferedAcrossClosures569=== PAUSE TestCompletedNarNotReofferedAcrossClosures570=== RUN TestPresignedUploadRegisteredBeforeCommit571=== PAUSE TestPresignedUploadRegisteredBeforeCommit572=== RUN TestService_Rustfstest573=== PAUSE TestService_Rustfstest574=== RUN TestParseSize575=== PAUSE TestParseSize576=== RUN TestSkippedUploadsHandler577=== PAUSE TestSkippedUploadsHandler578=== RUN TestSystemdListenerNotActivated579--- PASS: TestSystemdListenerNotActivated (0.00s)580=== RUN TestWatchdogBeatsWhenHealthy581--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)582=== RUN TestWatchdogSkipsWhenUnhealthy5832026/09/19 11:22:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5842026/09/19 11:22:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5852026/09/19 11:22:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5862026/09/19 11:22:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5872026/09/19 11:22:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5882026/09/19 11:22:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5892026/09/19 11:22:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5902026/09/19 11:22:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5912026/09/19 11:22:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5922026/09/19 11:22:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"593--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)594=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle595=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle596=== RUN TestProxyWriteTimeout597=== PAUSE TestProxyWriteTimeout598=== RUN TestIsValidUploadKey599=== PAUSE TestIsValidUploadKey600=== RUN TestUploadHandlersRejectInvalidKeys601=== PAUSE TestUploadHandlersRejectInvalidKeys602=== RUN TestUploadHandlersRejectOversizedBody603=== PAUSE TestUploadHandlersRejectOversizedBody604=== RUN TestService_cleanupPendingClosuresHandler605=== PAUSE TestService_cleanupPendingClosuresHandler606=== RUN TestService_createPendingClosureHandler607=== PAUSE TestService_createPendingClosureHandler608=== RUN TestService_verifyS3Integrity609=== PAUSE TestService_verifyS3Integrity610=== RUN TestCompleteMultipartUnregistered611=== PAUSE TestCompleteMultipartUnregistered612=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT613=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT614=== CONT TestReadProxyInvalidPath615=== CONT TestService_AuthMiddleware616=== CONT TestGCTaskStore_StartNew617--- PASS: TestGCTaskStore_StartNew (0.00s)618=== CONT TestMetricsInventory619=== CONT TestGracefulShutdownDrainsInflight620=== CONT TestNARDeduplicationMetadataUploadBug621=== CONT TestCreatePendingClosureRejectsOversizedNAR622=== CONT TestCacheConfigHandlerMaxNarSize6232026/09/19 11:22:24 INFO Received uploads request method=POST path=/api/pending_closures6242026/09/19 11:22:24 INFO Starting HTTP server address=127.0.0.1:59139625--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)626=== CONT TestReadProxy404627--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)628=== CONT TestResurrectedObjectNotDeleted629=== CONT TestGenerateLandingPage630=== CONT TestService_readinessHandler631=== CONT TestService_healthCheckHandler6322026/09/19 11:22:24 INFO Shutdown signal received, draining in-flight requests timeout=10s633--- PASS: TestGenerateLandingPage (0.01s)634=== CONT TestReadProxyNarStreaming635--- PASS: TestGracefulShutdownDrainsInflight (0.08s)636=== CONT TestReadProxyNarinfoAlreadyDecompressed6372026-09-19 11:22:24.428 UTC [97265] ERROR: relation "goose_db_version" does not exist at character 366382026-09-19 11:22:24.428 UTC [97265] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6392026-09-19 11:22:24.454 UTC [97266] ERROR: relation "goose_db_version" does not exist at character 366402026-09-19 11:22:24.454 UTC [97266] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6412026-09-19 11:22:24.456 UTC [97267] ERROR: relation "goose_db_version" does not exist at character 366422026-09-19 11:22:24.456 UTC [97267] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6432026/09/19 11:22:24 OK 20241026095416_initial_model.sql (26.63ms)6442026/09/19 11:22:24 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)6452026-09-19 11:22:24.462 UTC [97271] ERROR: relation "goose_db_version" does not exist at character 366462026-09-19 11:22:24.462 UTC [97271] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6472026/09/19 11:22:24 OK 20251218171726_add_pins.sql (2.36ms)6482026-09-19 11:22:24.463 UTC [97268] ERROR: relation "goose_db_version" does not exist at character 366492026-09-19 11:22:24.463 UTC [97268] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6502026-09-19 11:22:24.463 UTC [97270] ERROR: relation "goose_db_version" does not exist at character 366512026-09-19 11:22:24.463 UTC [97270] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6522026-09-19 11:22:24.463 UTC [97269] ERROR: relation "goose_db_version" does not exist at character 366532026-09-19 11:22:24.463 UTC [97269] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6542026-09-19 11:22:24.463 UTC [97272] ERROR: relation "goose_db_version" does not exist at character 366552026-09-19 11:22:24.463 UTC [97272] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6562026-09-19 11:22:24.465 UTC [97273] ERROR: relation "goose_db_version" does not exist at character 366572026-09-19 11:22:24.465 UTC [97273] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6582026-09-19 11:22:24.465 UTC [97274] ERROR: relation "goose_db_version" does not exist at character 366592026-09-19 11:22:24.465 UTC [97274] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6602026/09/19 11:22:24 OK 20260628120000_add_object_size_and_stats.sql (2.9ms)6612026/09/19 11:22:24 OK 20241026095416_initial_model.sql (7.57ms)6622026/09/19 11:22:24 OK 20260905000000_add_claims.sql (2.31ms)6632026/09/19 11:22:24 goose: successfully migrated database to version: 202609050000006642026/09/19 11:22:24 OK 20241026095416_initial_model.sql (7.32ms)6652026/09/19 11:22:24 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)6662026/09/19 11:22:24 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)6672026/09/19 11:22:24 OK 1_commit_pending_closure.sql (2.79ms)6682026/09/19 11:22:24 OK 20251218171726_add_pins.sql (2.94ms)6692026/09/19 11:22:24 OK 2_object_stats_trigger.sql (855.83µs)6702026/09/19 11:22:24 goose: up to current file version: 26712026/09/19 11:22:24 OK 20251218171726_add_pins.sql (2.27ms)6722026/09/19 11:22:24 OK 20260628120000_add_object_size_and_stats.sql (2.01ms)6732026/09/19 11:22:24 OK 20260628120000_add_object_size_and_stats.sql (2.18ms)6742026/09/19 11:22:24 OK 20241026095416_initial_model.sql (8.48ms)6752026/09/19 11:22:24 OK 20241026095416_initial_model.sql (8.77ms)6762026/09/19 11:22:24 OK 20241026095416_initial_model.sql (8.92ms)6772026/09/19 11:22:24 OK 20241026095416_initial_model.sql (9.39ms)6782026/09/19 11:22:24 OK 20251210153512_drop_unused_gin_index.sql (868.42µs)6792026/09/19 11:22:24 OK 20241026095416_initial_model.sql (8.21ms)6802026/09/19 11:22:24 OK 20241026095416_initial_model.sql (9.59ms)6812026/09/19 11:22:24 OK 20260905000000_add_claims.sql (2.57ms)6822026/09/19 11:22:24 goose: successfully migrated database to version: 202609050000006832026/09/19 11:22:24 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)6842026/09/19 11:22:24 OK 20260905000000_add_claims.sql (2.32ms)6852026/09/19 11:22:24 goose: successfully migrated database to version: 202609050000006862026/09/19 11:22:24 OK 20251210153512_drop_unused_gin_index.sql (664.79µs)6872026/09/19 11:22:24 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)6882026/09/19 11:22:24 OK 20251210153512_drop_unused_gin_index.sql (859.58µs)6892026/09/19 11:22:24 OK 20251210153512_drop_unused_gin_index.sql (603.17µs)6902026/09/19 11:22:24 OK 1_commit_pending_closure.sql (1.53ms)6912026/09/19 11:22:24 OK 1_commit_pending_closure.sql (1.37ms)6922026/09/19 11:22:24 OK 20251218171726_add_pins.sql (1.69ms)6932026/09/19 11:22:24 OK 2_object_stats_trigger.sql (809.54µs)6942026/09/19 11:22:24 goose: up to current file version: 26952026/09/19 11:22:24 OK 2_object_stats_trigger.sql (683.46µs)6962026/09/19 11:22:24 goose: up to current file version: 26972026/09/19 11:22:24 OK 20251218171726_add_pins.sql (1.99ms)6982026/09/19 11:22:24 OK 20251218171726_add_pins.sql (2.08ms)6992026/09/19 11:22:24 OK 20251218171726_add_pins.sql (2.91ms)7002026/09/19 11:22:24 OK 20251218171726_add_pins.sql (2.32ms)7012026/09/19 11:22:24 OK 20241026095416_initial_model.sql (8ms)7022026/09/19 11:22:24 OK 20251218171726_add_pins.sql (2.21ms)7032026/09/19 11:22:24 OK 20260628120000_add_object_size_and_stats.sql (1.74ms)7042026/09/19 11:22:24 OK 20251210153512_drop_unused_gin_index.sql (3.87ms)7052026/09/19 11:22:24 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)7062026/09/19 11:22:24 OK 20260628120000_add_object_size_and_stats.sql (4.69ms)7072026/09/19 11:22:24 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)7082026/09/19 11:22:24 OK 20260628120000_add_object_size_and_stats.sql (10.15ms)7092026/09/19 11:22:24 OK 20260628120000_add_object_size_and_stats.sql (11.24ms)7102026/09/19 11:22:24 OK 20251218171726_add_pins.sql (14.38ms)7112026/09/19 11:22:24 OK 20260905000000_add_claims.sql (24.08ms)7122026/09/19 11:22:24 goose: successfully migrated database to version: 202609050000007132026/09/19 11:22:24 OK 20260905000000_add_claims.sql (20.56ms)7142026/09/19 11:22:24 goose: successfully migrated database to version: 202609050000007152026/09/19 11:22:24 OK 20260905000000_add_claims.sql (20.46ms)7162026/09/19 11:22:24 goose: successfully migrated database to version: 202609050000007172026/09/19 11:22:24 OK 20260905000000_add_claims.sql (21.32ms)7182026/09/19 11:22:24 goose: successfully migrated database to version: 202609050000007192026/09/19 11:22:24 OK 1_commit_pending_closure.sql (1.69ms)7202026/09/19 11:22:24 OK 1_commit_pending_closure.sql (1.73ms)7212026/09/19 11:22:24 OK 1_commit_pending_closure.sql (1.88ms)7222026/09/19 11:22:24 OK 2_object_stats_trigger.sql (261µs)7232026/09/19 11:22:24 goose: up to current file version: 27242026/09/19 11:22:24 OK 2_object_stats_trigger.sql (370.75µs)7252026/09/19 11:22:24 goose: up to current file version: 27262026/09/19 11:22:24 OK 2_object_stats_trigger.sql (364.92µs)7272026/09/19 11:22:24 goose: up to current file version: 27282026/09/19 11:22:24 OK 20260905000000_add_claims.sql (22.29ms)7292026/09/19 11:22:24 OK 20260905000000_add_claims.sql (21.09ms)7302026/09/19 11:22:24 goose: successfully migrated database to version: 202609050000007312026/09/19 11:22:24 goose: successfully migrated database to version: 202609050000007322026/09/19 11:22:24 OK 20260628120000_add_object_size_and_stats.sql (13.72ms)7332026/09/19 11:22:24 OK 1_commit_pending_closure.sql (6.68ms)7342026/09/19 11:22:24 OK 2_object_stats_trigger.sql (224.67µs)7352026/09/19 11:22:24 goose: up to current file version: 27362026/09/19 11:22:24 OK 1_commit_pending_closure.sql (1.1ms)7372026/09/19 11:22:24 OK 20260905000000_add_claims.sql (1.13ms)7382026/09/19 11:22:24 goose: successfully migrated database to version: 202609050000007392026/09/19 11:22:24 OK 2_object_stats_trigger.sql (209.83µs)7402026/09/19 11:22:24 goose: up to current file version: 27412026/09/19 11:22:24 OK 1_commit_pending_closure.sql (1.39ms)7422026/09/19 11:22:24 OK 2_object_stats_trigger.sql (194.67µs)7432026/09/19 11:22:24 goose: up to current file version: 27442026/09/19 11:22:24 OK 1_commit_pending_closure.sql (891.92µs)7452026/09/19 11:22:24 OK 2_object_stats_trigger.sql (164.96µs)7462026/09/19 11:22:24 goose: up to current file version: 2747--- PASS: TestResurrectedObjectNotDeleted (0.65s)748=== CONT TestReadProxyNarinfo749=== NAME TestNARDeduplicationMetadataUploadBug750 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-97126-2725002786/TestNARDeduplicationMetadataUploadBug138353785/001/store/l9vfsgz5vng9aqa31ym4kmmpfalf9knn-file1.txt751--- PASS: TestReadProxyInvalidPath (0.73s)752=== CONT TestIsValidCachePath753=== RUN TestIsValidCachePath/narinfo754=== PAUSE TestIsValidCachePath/narinfo755=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars756=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars757=== RUN TestIsValidCachePath/nar_zst758=== PAUSE TestIsValidCachePath/nar_zst759=== RUN TestIsValidCachePath/nar_xz760=== PAUSE TestIsValidCachePath/nar_xz761=== RUN TestIsValidCachePath/nar_bz2762=== PAUSE TestIsValidCachePath/nar_bz2763=== RUN TestIsValidCachePath/nar_uncompressed764=== PAUSE TestIsValidCachePath/nar_uncompressed765=== RUN TestIsValidCachePath/ls766=== PAUSE TestIsValidCachePath/ls767=== RUN TestIsValidCachePath/log768=== PAUSE TestIsValidCachePath/log769=== RUN TestIsValidCachePath/realisation770=== PAUSE TestIsValidCachePath/realisation771=== RUN TestIsValidCachePath/nix-cache-info772=== PAUSE TestIsValidCachePath/nix-cache-info773=== RUN TestIsValidCachePath/index.html774=== PAUSE TestIsValidCachePath/index.html775=== RUN TestIsValidCachePath/traversal_parent776=== PAUSE TestIsValidCachePath/traversal_parent777=== RUN TestIsValidCachePath/traversal_in_middle778=== PAUSE TestIsValidCachePath/traversal_in_middle779=== RUN TestIsValidCachePath/invalid_char_e780=== PAUSE TestIsValidCachePath/invalid_char_e781=== RUN TestIsValidCachePath/invalid_char_u782=== PAUSE TestIsValidCachePath/invalid_char_u783=== RUN TestIsValidCachePath/random_path784=== PAUSE TestIsValidCachePath/random_path785=== RUN TestIsValidCachePath/empty786=== PAUSE TestIsValidCachePath/empty787=== RUN TestIsValidCachePath/leading_slash788=== PAUSE TestIsValidCachePath/leading_slash789=== RUN TestIsValidCachePath/wrong_extension790=== PAUSE TestIsValidCachePath/wrong_extension791=== RUN TestIsValidCachePath/short_hash792=== PAUSE TestIsValidCachePath/short_hash793=== CONT TestParseSingleRange794=== RUN TestParseSingleRange/none795=== PAUSE TestParseSingleRange/none796=== RUN TestParseSingleRange/unknown_unit797=== PAUSE TestParseSingleRange/unknown_unit798=== RUN TestParseSingleRange/multi-range_ignored799=== PAUSE TestParseSingleRange/multi-range_ignored800=== RUN TestParseSingleRange/malformed_no_dash801=== PAUSE TestParseSingleRange/malformed_no_dash802=== RUN TestParseSingleRange/malformed_both_empty803=== PAUSE TestParseSingleRange/malformed_both_empty804=== RUN TestParseSingleRange/malformed_end_before_start805=== PAUSE TestParseSingleRange/malformed_end_before_start806=== RUN TestParseSingleRange/closed807=== PAUSE TestParseSingleRange/closed808=== RUN TestParseSingleRange/open-ended809=== PAUSE TestParseSingleRange/open-ended810=== RUN TestParseSingleRange/end_clamped_to_size811=== PAUSE TestParseSingleRange/end_clamped_to_size812=== RUN TestParseSingleRange/suffix813=== PAUSE TestParseSingleRange/suffix814=== RUN TestParseSingleRange/suffix_exceeds_size815=== PAUSE TestParseSingleRange/suffix_exceeds_size816=== RUN TestParseSingleRange/single_byte817=== PAUSE TestParseSingleRange/single_byte818=== RUN TestParseSingleRange/start_past_EOF819=== PAUSE TestParseSingleRange/start_past_EOF820=== RUN TestParseSingleRange/start_far_past_EOF821=== PAUSE TestParseSingleRange/start_far_past_EOF822=== CONT TestService_Rustfstest8232026/09/19 11:22:24 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8242026/09/19 11:22:24 INFO Received uploads request method=POST path=/api/pending_closures8252026/09/19 11:22:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8262026/09/19 11:22:24 INFO Uploading l9vfsgz5vng9aqa31ym4kmmpfalf9knn-file1.txt (160B)8272026/09/19 11:22:24 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"8282026/09/19 11:22:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8292026/09/19 11:22:24 INFO Signed narinfos id=1 count=18302026/09/19 11:22:24 WARN Failed to register uploaded object key=l9vfsgz5vng9aqa31ym4kmmpfalf9knn.ls error="server returned 404: 404 page not found\n"8312026/09/19 11:22:24 INFO Uploading 1 narinfos8322026/09/19 11:22:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8332026/09/19 11:22:24 WARN Failed to register uploaded object key=l9vfsgz5vng9aqa31ym4kmmpfalf9knn.narinfo error="server returned 404: 404 page not found\n"8342026/09/19 11:22:24 INFO Completed upload id=18352026/09/19 11:22:24 INFO Upload complete. (129ms)836=== NAME TestNARDeduplicationMetadataUploadBug837 metadata_upload_test.go:54: Retrieved narinfo from S3:838 StorePath: /nix/var/nix/builds/nix-97126-2725002786/TestNARDeduplicationMetadataUploadBug138353785/001/store/l9vfsgz5vng9aqa31ym4kmmpfalf9knn-file1.txt839 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst840 Compression: zstd841 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf842 NarSize: 160843 References: 844 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf845 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)846 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):847 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}8482026/09/19 11:22:24 WARN readiness check failed error="closed pool"849--- PASS: TestService_readinessHandler (0.85s)850=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT851=== NAME TestNARDeduplicationMetadataUploadBug852 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-97126-2725002786/TestNARDeduplicationMetadataUploadBug138353785/001/store/lpllci4wdgl5zfkyfsj1cabzxfriij6w-file2.txt8532026/09/19 11:22:25 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"854--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.91s)855=== CONT TestCompleteMultipartUnregistered8562026-09-19 11:22:25.080 UTC [97299] ERROR: relation "goose_db_version" does not exist at character 368572026-09-19 11:22:25.080 UTC [97299] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8582026-09-19 11:22:25.080 UTC [97300] ERROR: relation "goose_db_version" does not exist at character 368592026-09-19 11:22:25.080 UTC [97300] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8602026/09/19 11:22:25 INFO Received uploads request method=POST path=/api/pending_closures8612026/09/19 11:22:25 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)8622026/09/19 11:22:25 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8632026/09/19 11:22:25 INFO Signed narinfos id=2 count=18642026/09/19 11:22:25 WARN Failed to register uploaded object key=lpllci4wdgl5zfkyfsj1cabzxfriij6w.ls error="server returned 404: 404 page not found\n"8652026/09/19 11:22:25 INFO Uploading 1 narinfos8662026/09/19 11:22:25 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8672026/09/19 11:22:25 WARN Failed to register uploaded object key=lpllci4wdgl5zfkyfsj1cabzxfriij6w.narinfo error="server returned 404: 404 page not found\n"8682026/09/19 11:22:25 INFO Completed upload id=28692026/09/19 11:22:25 INFO Upload complete. (104ms)870=== NAME TestNARDeduplicationMetadataUploadBug871 metadata_upload_test.go:76: Retrieved narinfo from S3:872 StorePath: /nix/var/nix/builds/nix-97126-2725002786/TestNARDeduplicationMetadataUploadBug138353785/001/store/lpllci4wdgl5zfkyfsj1cabzxfriij6w-file2.txt873 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst874 Compression: zstd875 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf876 NarSize: 160877 References: 878 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf879 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)880 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):881 {"version":1,"root":{"type":"regular","size":44}}882--- PASS: TestNARDeduplicationMetadataUploadBug (1.05s)883=== CONT TestService_verifyS3Integrity8842026/09/19 11:22:25 OK 20241026095416_initial_model.sql (33.93ms)8852026/09/19 11:22:25 OK 20241026095416_initial_model.sql (39.74ms)8862026/09/19 11:22:25 OK 20251210153512_drop_unused_gin_index.sql (5.5ms)8872026/09/19 11:22:25 OK 20251210153512_drop_unused_gin_index.sql (5.63ms)8882026/09/19 11:22:25 OK 20251218171726_add_pins.sql (1.34ms)8892026/09/19 11:22:25 OK 20251218171726_add_pins.sql (2.75ms)8902026/09/19 11:22:25 OK 20260628120000_add_object_size_and_stats.sql (7.67ms)8912026/09/19 11:22:25 OK 20260628120000_add_object_size_and_stats.sql (12.25ms)8922026/09/19 11:22:25 OK 20260905000000_add_claims.sql (22.83ms)8932026/09/19 11:22:25 goose: successfully migrated database to version: 202609050000008942026/09/19 11:22:25 OK 20260905000000_add_claims.sql (17.79ms)8952026/09/19 11:22:25 goose: successfully migrated database to version: 202609050000008962026/09/19 11:22:25 OK 1_commit_pending_closure.sql (1.51ms)8972026/09/19 11:22:25 OK 1_commit_pending_closure.sql (1.07ms)8982026/09/19 11:22:25 OK 2_object_stats_trigger.sql (231.08µs)8992026/09/19 11:22:25 goose: up to current file version: 29002026/09/19 11:22:25 OK 2_object_stats_trigger.sql (236.13µs)9012026/09/19 11:22:25 goose: up to current file version: 2902--- PASS: TestService_healthCheckHandler (1.12s)903=== CONT TestService_createPendingClosureHandler9042026-09-19 11:22:25.203 UTC [97304] ERROR: relation "goose_db_version" does not exist at character 369052026-09-19 11:22:25.203 UTC [97304] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9062026/09/19 11:22:25 OK 20241026095416_initial_model.sql (31.58ms)9072026/09/19 11:22:25 OK 20251210153512_drop_unused_gin_index.sql (4.96ms)9082026/09/19 11:22:25 OK 20251218171726_add_pins.sql (5.94ms)9092026/09/19 11:22:25 OK 20260628120000_add_object_size_and_stats.sql (17.35ms)9102026/09/19 11:22:25 OK 20260905000000_add_claims.sql (21.13ms)9112026/09/19 11:22:25 goose: successfully migrated database to version: 202609050000009122026/09/19 11:22:25 OK 1_commit_pending_closure.sql (1.61ms)9132026/09/19 11:22:25 OK 2_object_stats_trigger.sql (309.38µs)9142026/09/19 11:22:25 goose: up to current file version: 2915--- PASS: TestReadProxyNarStreaming (1.25s)916=== CONT TestService_cleanupPendingClosuresHandler9172026-09-19 11:22:25.365 UTC [97308] ERROR: relation "goose_db_version" does not exist at character 369182026-09-19 11:22:25.365 UTC [97308] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9192026/09/19 11:22:25 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"920--- PASS: TestService_AuthMiddleware (1.38s)921=== CONT TestUploadHandlersRejectOversizedBody9222026/09/19 11:22:25 OK 20241026095416_initial_model.sql (56.7ms)9232026/09/19 11:22:25 OK 20251210153512_drop_unused_gin_index.sql (999.58µs)9242026/09/19 11:22:25 OK 20251218171726_add_pins.sql (3.34ms)9252026/09/19 11:22:25 OK 20260628120000_add_object_size_and_stats.sql (14.85ms)9262026/09/19 11:22:25 OK 20260905000000_add_claims.sql (24.11ms)9272026/09/19 11:22:25 goose: successfully migrated database to version: 202609050000009282026/09/19 11:22:25 OK 1_commit_pending_closure.sql (67.65ms)9292026/09/19 11:22:25 OK 2_object_stats_trigger.sql (11.23ms)9302026/09/19 11:22:25 goose: up to current file version: 29312026-09-19 11:22:25.594 UTC [97309] ERROR: relation "goose_db_version" does not exist at character 369322026-09-19 11:22:25.594 UTC [97309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC933--- PASS: TestMetricsInventory (1.56s)934=== CONT TestUploadHandlersRejectInvalidKeys935=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info936=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info937=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal938=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal939=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key940=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key941=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key942=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key943=== CONT TestIsValidUploadKey944=== RUN TestIsValidUploadKey/narinfo945=== PAUSE TestIsValidUploadKey/narinfo946=== RUN TestIsValidUploadKey/nar_zst947=== PAUSE TestIsValidUploadKey/nar_zst948=== RUN TestIsValidUploadKey/nar_xz949=== PAUSE TestIsValidUploadKey/nar_xz950=== RUN TestIsValidUploadKey/nar_plain951=== PAUSE TestIsValidUploadKey/nar_plain952=== RUN TestIsValidUploadKey/listing953=== PAUSE TestIsValidUploadKey/listing954=== RUN TestIsValidUploadKey/build_log955=== PAUSE TestIsValidUploadKey/build_log956=== RUN TestIsValidUploadKey/build_log_home-manager_file957=== PAUSE TestIsValidUploadKey/build_log_home-manager_file958=== RUN TestIsValidUploadKey/build_log_plus_in_name959=== PAUSE TestIsValidUploadKey/build_log_plus_in_name960=== RUN TestIsValidUploadKey/build_log_question_mark961=== PAUSE TestIsValidUploadKey/build_log_question_mark962=== RUN TestIsValidUploadKey/build_log_equals963=== PAUSE TestIsValidUploadKey/build_log_equals964=== RUN TestIsValidUploadKey/realisation965=== PAUSE TestIsValidUploadKey/realisation966=== RUN TestIsValidUploadKey/realisation_plus_in_output967=== PAUSE TestIsValidUploadKey/realisation_plus_in_output968=== RUN TestIsValidUploadKey/nix-cache-info969=== PAUSE TestIsValidUploadKey/nix-cache-info970=== RUN TestIsValidUploadKey/index.html971=== PAUSE TestIsValidUploadKey/index.html972=== RUN TestIsValidUploadKey/narinfo_key,_nar_type973=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type974=== RUN TestIsValidUploadKey/nar_key,_narinfo_type975=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type976=== RUN TestIsValidUploadKey/listing_key,_narinfo_type977=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type978=== RUN TestIsValidUploadKey/traversal979=== PAUSE TestIsValidUploadKey/traversal980=== RUN TestIsValidUploadKey/traversal_nar981=== PAUSE TestIsValidUploadKey/traversal_nar982=== RUN TestIsValidUploadKey/absolute983=== PAUSE TestIsValidUploadKey/absolute984=== RUN TestIsValidUploadKey/empty_key985=== PAUSE TestIsValidUploadKey/empty_key986=== RUN TestIsValidUploadKey/unknown_type987=== PAUSE TestIsValidUploadKey/unknown_type988=== CONT TestProxyWriteTimeout989=== RUN TestProxyWriteTimeout/narinfo990=== PAUSE TestProxyWriteTimeout/narinfo991=== RUN TestProxyWriteTimeout/1_GiB_nar992=== PAUSE TestProxyWriteTimeout/1_GiB_nar993=== RUN TestProxyWriteTimeout/10_GiB_nar994=== PAUSE TestProxyWriteTimeout/10_GiB_nar995=== RUN TestProxyWriteTimeout/unknown_size996=== PAUSE TestProxyWriteTimeout/unknown_size997=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9982026/09/19 11:22:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9992026/09/19 11:22:25 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1000--- PASS: TestCompleteMultipartUnregistered (0.63s)1001=== CONT TestSkippedUploadsHandler10022026/09/19 11:22:25 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001003--- PASS: TestSkippedUploadsHandler (0.00s)1004=== CONT TestParseSize1005--- PASS: TestParseSize (0.00s)1006=== CONT TestReadProxyRangeRequest10072026/09/19 11:22:25 OK 20241026095416_initial_model.sql (99ms)10082026/09/19 11:22:25 OK 20251210153512_drop_unused_gin_index.sql (17.84ms)10092026/09/19 11:22:25 OK 20251218171726_add_pins.sql (10.85ms)10102026/09/19 11:22:25 OK 20260628120000_add_object_size_and_stats.sql (28.29ms)10112026/09/19 11:22:25 OK 20260905000000_add_claims.sql (18.9ms)10122026/09/19 11:22:25 goose: successfully migrated database to version: 202609050000001013--- PASS: TestReadProxy404 (1.76s)1014=== CONT TestPresignedUploadRegisteredBeforeCommit10152026/09/19 11:22:25 OK 1_commit_pending_closure.sql (2.63ms)10162026/09/19 11:22:25 OK 2_object_stats_trigger.sql (565.96µs)10172026/09/19 11:22:25 goose: up to current file version: 21018=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1019=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1020=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1021=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1022=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1023=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1024=== CONT TestCompletedNarNotReofferedAcrossClosures10252026-09-19 11:22:25.854 UTC [97317] ERROR: relation "goose_db_version" does not exist at character 3610262026-09-19 11:22:25.854 UTC [97317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10272026/09/19 11:22:25 OK 20241026095416_initial_model.sql (69.76ms)10282026/09/19 11:22:25 OK 20251210153512_drop_unused_gin_index.sql (5.67ms)10292026/09/19 11:22:25 OK 20251218171726_add_pins.sql (1.37ms)10302026/09/19 11:22:25 OK 20260628120000_add_object_size_and_stats.sql (8.77ms)1031--- PASS: TestReadProxyNarinfo (1.25s)1032=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10332026/09/19 11:22:25 OK 20260905000000_add_claims.sql (24.64ms)10342026/09/19 11:22:25 goose: successfully migrated database to version: 2026090500000010352026/09/19 11:22:25 OK 1_commit_pending_closure.sql (1.1ms)10362026/09/19 11:22:25 OK 2_object_stats_trigger.sql (243.92µs)10372026/09/19 11:22:25 goose: up to current file version: 210382026-09-19 11:22:26.074 UTC [97321] ERROR: relation "goose_db_version" does not exist at character 3610392026-09-19 11:22:26.074 UTC [97321] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1040--- PASS: TestService_Rustfstest (1.30s)1041=== CONT TestRedundantMultipartUpload10422026/09/19 11:22:26 OK 20241026095416_initial_model.sql (71.16ms)10432026/09/19 11:22:26 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)10442026/09/19 11:22:26 OK 20251218171726_add_pins.sql (19.99ms)10452026/09/19 11:22:26 INFO Received uploads request method=POST path=/api/pending_closures10462026/09/19 11:22:26 OK 20260628120000_add_object_size_and_stats.sql (9.4ms)10472026/09/19 11:22:26 OK 20260905000000_add_claims.sql (15.73ms)10482026/09/19 11:22:26 goose: successfully migrated database to version: 2026090500000010492026/09/19 11:22:26 OK 1_commit_pending_closure.sql (10.14ms)10502026/09/19 11:22:26 OK 2_object_stats_trigger.sql (272.17µs)10512026/09/19 11:22:26 goose: up to current file version: 21052--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.36s)1053=== CONT TestReadRedirectUsesPublicS3URL10542026/09/19 11:22:26 INFO Received uploads request method=POST path=/api/pending_closures10552026/09/19 11:22:26 INFO Received uploads request method=POST path=/api/pending_closures10562026/09/19 11:22:26 INFO Received uploads request method=POST path=/api/pending_closures10572026/09/19 11:22:26 INFO Received uploads request method=POST path=/api/pending_closures10582026-09-19 11:22:26.716 UTC [97326] ERROR: relation "goose_db_version" does not exist at character 3610592026-09-19 11:22:26.716 UTC [97326] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10602026-09-19 11:22:26.849 UTC [97327] ERROR: relation "goose_db_version" does not exist at character 3610612026-09-19 11:22:26.849 UTC [97327] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10622026/09/19 11:22:26 INFO Received cleanup request method=DELETE path=/api/pending_closures10632026/09/19 11:22:26 INFO Aborted multipart uploads count=010642026/09/19 11:22:26 INFO Received uploads request method=POST path=/api/pending_closures10652026/09/19 11:22:26 OK 20241026095416_initial_model.sql (180.02ms)10662026/09/19 11:22:26 INFO Received cleanup request method=DELETE path=/api/pending_closures10672026/09/19 11:22:26 OK 20251210153512_drop_unused_gin_index.sql (8.18ms)10682026/09/19 11:22:26 INFO Aborted multipart uploads count=110692026/09/19 11:22:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10702026-09-19 11:22:26.998 UTC [97321] ERROR: Closure does not exist: id=110712026-09-19 11:22:26.998 UTC [97321] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10722026-09-19 11:22:26.998 UTC [97321] STATEMENT: -- name: CommitPendingClosure :exec1073 SELECT commit_pending_closure($1::bigint)1074 1075--- PASS: TestService_cleanupPendingClosuresHandler (1.68s)1076=== CONT TestObjectStatsTrigger10772026/09/19 11:22:26 OK 20251218171726_add_pins.sql (11.77ms)10782026/09/19 11:22:27 OK 20241026095416_initial_model.sql (99.56ms)10792026-09-19 11:22:27.019 UTC [97329] ERROR: relation "goose_db_version" does not exist at character 3610802026-09-19 11:22:27.019 UTC [97329] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10812026/09/19 11:22:27 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)10822026-09-19 11:22:27.023 UTC [97330] ERROR: relation "goose_db_version" does not exist at character 3610832026-09-19 11:22:27.023 UTC [97330] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10842026/09/19 11:22:27 OK 20260628120000_add_object_size_and_stats.sql (21.49ms)10852026/09/19 11:22:27 OK 20251218171726_add_pins.sql (17.25ms)10862026/09/19 11:22:27 OK 20260628120000_add_object_size_and_stats.sql (37.46ms)10872026/09/19 11:22:27 OK 20260905000000_add_claims.sql (53.31ms)10882026/09/19 11:22:27 goose: successfully migrated database to version: 2026090500000010892026/09/19 11:22:27 OK 1_commit_pending_closure.sql (8.41ms)10902026/09/19 11:22:27 OK 2_object_stats_trigger.sql (619.38µs)10912026/09/19 11:22:27 goose: up to current file version: 210922026-09-19 11:22:27.100 UTC [97331] ERROR: relation "goose_db_version" does not exist at character 3610932026-09-19 11:22:27.100 UTC [97331] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10942026/09/19 11:22:27 OK 20260905000000_add_claims.sql (45.79ms)10952026/09/19 11:22:27 goose: successfully migrated database to version: 2026090500000010962026/09/19 11:22:27 OK 1_commit_pending_closure.sql (8.43ms)10972026/09/19 11:22:27 OK 2_object_stats_trigger.sql (935.83µs)10982026/09/19 11:22:27 goose: up to current file version: 210992026/09/19 11:22:27 OK 20241026095416_initial_model.sql (134.64ms)11002026/09/19 11:22:27 OK 20241026095416_initial_model.sql (141.97ms)11012026/09/19 11:22:27 OK 20251210153512_drop_unused_gin_index.sql (12.96ms)11022026/09/19 11:22:27 OK 20251210153512_drop_unused_gin_index.sql (13.15ms)11032026/09/19 11:22:27 OK 20251218171726_add_pins.sql (9.36ms)11042026/09/19 11:22:27 OK 20251218171726_add_pins.sql (15.96ms)11052026/09/19 11:22:27 OK 20241026095416_initial_model.sql (137.39ms)11062026/09/19 11:22:27 OK 20260628120000_add_object_size_and_stats.sql (36.07ms)11072026/09/19 11:22:27 OK 20251210153512_drop_unused_gin_index.sql (10.91ms)11082026/09/19 11:22:27 OK 20260628120000_add_object_size_and_stats.sql (38.85ms)11092026/09/19 11:22:27 OK 20251218171726_add_pins.sql (48.03ms)11102026/09/19 11:22:27 INFO Received uploads request method=POST path=/api/pending_closures11112026/09/19 11:22:27 OK 20260905000000_add_claims.sql (61.17ms)11122026/09/19 11:22:27 goose: successfully migrated database to version: 2026090500000011132026/09/19 11:22:27 OK 20260628120000_add_object_size_and_stats.sql (13.91ms)11142026/09/19 11:22:27 OK 20260905000000_add_claims.sql (46.96ms)11152026/09/19 11:22:27 goose: successfully migrated database to version: 2026090500000011162026/09/19 11:22:27 OK 1_commit_pending_closure.sql (3.21ms)11172026/09/19 11:22:27 OK 1_commit_pending_closure.sql (2.64ms)11182026/09/19 11:22:27 OK 2_object_stats_trigger.sql (549.13µs)11192026/09/19 11:22:27 goose: up to current file version: 211202026/09/19 11:22:27 OK 2_object_stats_trigger.sql (470.88µs)11212026/09/19 11:22:27 goose: up to current file version: 211222026/09/19 11:22:27 OK 20260905000000_add_claims.sql (52.8ms)11232026/09/19 11:22:27 goose: successfully migrated database to version: 2026090500000011242026/09/19 11:22:27 OK 1_commit_pending_closure.sql (8.91ms)11252026/09/19 11:22:27 OK 2_object_stats_trigger.sql (443.25µs)11262026/09/19 11:22:27 goose: up to current file version: 211272026-09-19 11:22:27.531 UTC [97333] ERROR: relation "goose_db_version" does not exist at character 3611282026-09-19 11:22:27.531 UTC [97333] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1129--- PASS: TestReadProxyRangeRequest (1.96s)1130=== CONT TestOrphanedObjectsGCStressTest11312026/09/19 11:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11322026/09/19 11:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11332026/09/19 11:22:27 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1Ljc0MDBmMTNiLTA3MTEtNDkzZC1hNTdiLWE3Y2M0MTZmYjg4NXgxNzg5ODE2OTQ2Mzk2OTQ5MDAw parts=1011342026/09/19 11:22:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11352026/09/19 11:22:27 INFO Completed upload id=111362026/09/19 11:22:27 INFO Received uploads request method=POST path=/api/pending_closures11372026/09/19 11:22:27 OK 20241026095416_initial_model.sql (177.12ms)11382026/09/19 11:22:27 INFO Received uploads request method=POST path=/api/pending_closures11392026/09/19 11:22:27 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11402026/09/19 11:22:27 WARN Found objects in DB but missing from S3, will re-upload count=11141--- PASS: TestService_verifyS3Integrity (2.65s)1142=== CONT TestOrphanedObjectsGC11432026/09/19 11:22:27 OK 20251210153512_drop_unused_gin_index.sql (9.38ms)11442026/09/19 11:22:27 OK 20251218171726_add_pins.sql (16.03ms)11452026/09/19 11:22:27 OK 20260628120000_add_object_size_and_stats.sql (29.95ms)11462026/09/19 11:22:27 INFO Received uploads request method=POST path=/api/pending_closures11472026/09/19 11:22:27 OK 20260905000000_add_claims.sql (48ms)11482026/09/19 11:22:27 goose: successfully migrated database to version: 2026090500000011492026/09/19 11:22:27 OK 1_commit_pending_closure.sql (7.27ms)11502026/09/19 11:22:27 OK 2_object_stats_trigger.sql (507.71µs)11512026/09/19 11:22:27 goose: up to current file version: 211522026-09-19 11:22:27.888 UTC [97338] ERROR: relation "goose_db_version" does not exist at character 3611532026-09-19 11:22:27.888 UTC [97338] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11542026/09/19 11:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11552026/09/19 11:22:28 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1Ljc0OTdlZWY4LThhMDAtNDhjZC04YTEyLWUxYzczODBlNzE5Y3gxNzg5ODE2OTQ2NjUxOTExMDAw parts=1011562026/09/19 11:22:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11572026/09/19 11:22:28 INFO Completed upload id=111582026/09/19 11:22:28 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011592026/09/19 11:22:28 INFO Received uploads request method=POST path=/api/pending_closures11602026/09/19 11:22:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures11612026/09/19 11:22:28 INFO Aborted multipart uploads count=011622026/09/19 11:22:28 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=011632026/09/19 11:22:28 INFO Received uploads request method=POST path=/api/pending_closures11642026/09/19 11:22:28 INFO Vacuumed table table=pending_closures11652026/09/19 11:22:28 INFO Vacuumed table table=pending_objects11662026/09/19 11:22:28 OK 20241026095416_initial_model.sql (166.14ms)11672026/09/19 11:22:28 OK 20251210153512_drop_unused_gin_index.sql (13.13ms)11682026/09/19 11:22:28 INFO Vacuumed table table=multipart_uploads11692026/09/19 11:22:28 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11702026/09/19 11:22:28 INFO Received uploads request method=POST path=/api/pending_closures11712026/09/19 11:22:28 INFO Vacuumed table table=closures11722026/09/19 11:22:28 OK 20251218171726_add_pins.sql (17.93ms)11732026/09/19 11:22:28 INFO Vacuumed table table=objects1174--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.31s)1175=== CONT TestGCTaskStore_GetReturnsLatest1176--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1177=== CONT TestGCTaskStore_Fail1178--- PASS: TestGCTaskStore_Fail (0.00s)1179=== CONT TestGCTaskStore_PhaseUpdates1180--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1181=== CONT TestGCTaskStore_CompletedAllowsNewTask1182--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1183=== CONT TestServerTLSConfig1184=== RUN TestServerTLSConfig/no_client_CA1185=== PAUSE TestServerTLSConfig/no_client_CA1186=== RUN TestServerTLSConfig/missing_CA_file1187=== PAUSE TestServerTLSConfig/missing_CA_file1188=== RUN TestServerTLSConfig/not_a_PEM_file1189=== PAUSE TestServerTLSConfig/not_a_PEM_file1190=== CONT TestMultipartCleanup11912026/09/19 11:22:28 OK 20260628120000_add_object_size_and_stats.sql (22.95ms)11922026/09/19 11:22:28 OK 20260905000000_add_claims.sql (29.45ms)11932026/09/19 11:22:28 goose: successfully migrated database to version: 2026090500000011942026/09/19 11:22:28 OK 1_commit_pending_closure.sql (7.12ms)11952026/09/19 11:22:28 OK 2_object_stats_trigger.sql (349.08µs)11962026/09/19 11:22:28 goose: up to current file version: 211972026/09/19 11:22:28 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001198--- PASS: TestService_createPendingClosureHandler (2.99s)1199=== CONT TestService_NativeMTLS12002026/09/19 11:22:28 INFO Received uploads request method=POST path=/api/pending_closures12012026-09-19 11:22:28.488 UTC [97344] ERROR: relation "goose_db_version" does not exist at character 3612022026-09-19 11:22:28.488 UTC [97344] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12032026/09/19 11:22:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12042026/09/19 11:22:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1LmY4MzYxYTM0LTA1YTQtNGQwMS1iZGVhLTkzZjBlMmFlZWY1MXgxNzg5ODE2OTQ4Mjk5ODM4MDAw12052026/09/19 11:22:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1LmY4MzYxYTM0LTA1YTQtNGQwMS1iZGVhLTkzZjBlMmFlZWY1MXgxNzg5ODE2OTQ4Mjk5ODM4MDAw parts=112062026/09/19 11:22:28 INFO Received uploads request method=POST path=/api/pending_closures1207--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.55s)1208=== CONT TestClaim_StaleHeartbeatStolen12092026/09/19 11:22:28 INFO Received uploads request method=POST path=/api/pending_closures12102026/09/19 11:22:28 OK 20241026095416_initial_model.sql (122.17ms)12112026/09/19 11:22:28 OK 20251210153512_drop_unused_gin_index.sql (11.16ms)12122026/09/19 11:22:28 OK 20251218171726_add_pins.sql (25.74ms)12132026/09/19 11:22:28 OK 20260628120000_add_object_size_and_stats.sql (40.96ms)1214--- PASS: TestReadRedirectUsesPublicS3URL (2.49s)1215=== CONT TestGCMetrics12162026/09/19 11:22:28 OK 20260905000000_add_claims.sql (22.02ms)12172026/09/19 11:22:28 goose: successfully migrated database to version: 2026090500000012182026/09/19 11:22:28 OK 1_commit_pending_closure.sql (1.72ms)12192026/09/19 11:22:28 OK 2_object_stats_trigger.sql (349.42µs)12202026/09/19 11:22:28 goose: up to current file version: 21221--- PASS: TestObjectStatsTrigger (2.07s)1222=== CONT TestGCBugBareHashReferences12232026-09-19 11:22:29.156 UTC [97359] ERROR: relation "goose_db_version" does not exist at character 3612242026-09-19 11:22:29.156 UTC [97359] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12252026/09/19 11:22:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12262026/09/19 11:22:29 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1LjZlMzAwOWJmLWM2MmYtNDg2NC1iOTQ2LTA1NWI1NDUwNjNkNngxNzg5ODE2OTQ3ODY3OTM2MDAw parts=1212272026/09/19 11:22:29 INFO Received uploads request method=POST path=/api/pending_closures12282026-09-19 11:22:29.274 UTC [97360] ERROR: relation "goose_db_version" does not exist at character 3612292026-09-19 11:22:29.274 UTC [97360] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12302026/09/19 11:22:29 OK 20241026095416_initial_model.sql (80.49ms)1231--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.44s)1232=== CONT TestResolveDBConnectionString1233=== RUN TestResolveDBConnectionString/flag_wins1234=== PAUSE TestResolveDBConnectionString/flag_wins1235=== RUN TestResolveDBConnectionString/file_when_flag_empty1236=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1237=== RUN TestResolveDBConnectionString/missing_file_is_an_error1238=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1239=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1240=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1241=== RUN TestResolveDBConnectionString/nothing_configured1242=== PAUSE TestResolveDBConnectionString/nothing_configured1243=== CONT TestPinProtectsFromGC12442026/09/19 11:22:29 OK 20251210153512_drop_unused_gin_index.sql (2.63ms)12452026/09/19 11:22:29 OK 20251218171726_add_pins.sql (2.04ms)12462026/09/19 11:22:29 OK 20260628120000_add_object_size_and_stats.sql (22.49ms)12472026-09-19 11:22:29.329 UTC [97363] ERROR: relation "goose_db_version" does not exist at character 3612482026-09-19 11:22:29.329 UTC [97363] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12492026/09/19 11:22:29 OK 20260905000000_add_claims.sql (27.56ms)12502026/09/19 11:22:29 goose: successfully migrated database to version: 2026090500000012512026/09/19 11:22:29 OK 1_commit_pending_closure.sql (2.71ms)12522026/09/19 11:22:29 OK 2_object_stats_trigger.sql (320µs)12532026/09/19 11:22:29 goose: up to current file version: 212542026/09/19 11:22:29 OK 20241026095416_initial_model.sql (61.69ms)12552026/09/19 11:22:29 OK 20251210153512_drop_unused_gin_index.sql (14.36ms)12562026/09/19 11:22:29 OK 20251218171726_add_pins.sql (26.62ms)12572026/09/19 11:22:29 OK 20260628120000_add_object_size_and_stats.sql (38.8ms)12582026/09/19 11:22:29 OK 20241026095416_initial_model.sql (105ms)12592026/09/19 11:22:29 OK 20251210153512_drop_unused_gin_index.sql (7.25ms)12602026/09/19 11:22:29 OK 20260905000000_add_claims.sql (25.06ms)12612026/09/19 11:22:29 goose: successfully migrated database to version: 2026090500000012622026/09/19 11:22:29 OK 1_commit_pending_closure.sql (2.09ms)12632026/09/19 11:22:29 OK 2_object_stats_trigger.sql (346µs)12642026/09/19 11:22:29 goose: up to current file version: 212652026/09/19 11:22:29 OK 20251218171726_add_pins.sql (21.55ms)12662026/09/19 11:22:29 OK 20260628120000_add_object_size_and_stats.sql (34.63ms)12672026-09-19 11:22:29.562 UTC [97364] ERROR: relation "goose_db_version" does not exist at character 3612682026-09-19 11:22:29.562 UTC [97364] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12692026/09/19 11:22:29 OK 20260905000000_add_claims.sql (39.99ms)12702026/09/19 11:22:29 goose: successfully migrated database to version: 2026090500000012712026/09/19 11:22:29 OK 1_commit_pending_closure.sql (8.75ms)12722026/09/19 11:22:29 OK 2_object_stats_trigger.sql (1.17ms)12732026/09/19 11:22:29 goose: up to current file version: 212742026/09/19 11:22:29 OK 20241026095416_initial_model.sql (206.94ms)12752026/09/19 11:22:29 OK 20251210153512_drop_unused_gin_index.sql (10ms)12762026/09/19 11:22:29 OK 20251218171726_add_pins.sql (33.79ms)12772026/09/19 11:22:29 OK 20260628120000_add_object_size_and_stats.sql (33.29ms)12782026/09/19 11:22:29 OK 20260905000000_add_claims.sql (66.83ms)12792026/09/19 11:22:29 goose: successfully migrated database to version: 2026090500000012802026/09/19 11:22:29 OK 1_commit_pending_closure.sql (3.04ms)12812026/09/19 11:22:29 OK 2_object_stats_trigger.sql (745.67µs)12822026/09/19 11:22:29 goose: up to current file version: 212832026/09/19 11:22:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12842026/09/19 11:22:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1LmQzN2IxMGY5LWRkYjEtNGYxMi1hYmQ2LWEyNTNiYTZjMDJmZXgxNzg5ODE2OTQ4NTQ4NjI0MDAw parts=121285--- PASS: TestRedundantMultipartUpload (3.93s)1286=== CONT TestClientSharedPathCommittedMidPush12872026/09/19 11:22:30 INFO Received uploads request method=POST path=/api/pending_closures12882026-09-19 11:22:30.167 UTC [97367] ERROR: relation "goose_db_version" does not exist at character 3612892026-09-19 11:22:30.167 UTC [97367] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12902026/09/19 11:22:30 INFO Received cleanup request method=DELETE path=/api/pending_closures12912026/09/19 11:22:30 INFO Aborted multipart uploads count=11292--- PASS: TestMultipartCleanup (2.17s)1293=== CONT TestClientWithDependencies12942026-09-19 11:22:30.313 UTC [97368] ERROR: relation "goose_db_version" does not exist at character 3612952026-09-19 11:22:30.313 UTC [97368] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12962026/09/19 11:22:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12972026/09/19 11:22:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1298--- PASS: TestService_NativeMTLS (2.20s)1299=== CONT TestClientMultipleUploads13002026/09/19 11:22:30 OK 20241026095416_initial_model.sql (164.33ms)13012026/09/19 11:22:30 OK 20251210153512_drop_unused_gin_index.sql (11.02ms)13022026/09/19 11:22:30 OK 20251218171726_add_pins.sql (3.42ms)13032026/09/19 11:22:30 OK 20260628120000_add_object_size_and_stats.sql (28.96ms)13042026/09/19 11:22:30 OK 20260905000000_add_claims.sql (34.38ms)13052026/09/19 11:22:30 goose: successfully migrated database to version: 2026090500000013062026/09/19 11:22:30 OK 1_commit_pending_closure.sql (2.43ms)13072026/09/19 11:22:30 OK 2_object_stats_trigger.sql (401.58µs)13082026/09/19 11:22:30 goose: up to current file version: 213092026/09/19 11:22:30 OK 20241026095416_initial_model.sql (99.97ms)13102026/09/19 11:22:30 OK 20251210153512_drop_unused_gin_index.sql (6.97ms)1311=== NAME TestOrphanedObjectsGC1312 orphaned_objects_gc_test.go:290: GC Test Summary:1313 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1314 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1315 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1316 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1317 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1318--- PASS: TestOrphanedObjectsGC (2.73s)1319=== CONT TestClientIntegration13202026/09/19 11:22:30 OK 20251218171726_add_pins.sql (30.9ms)13212026/09/19 11:22:30 OK 20260628120000_add_object_size_and_stats.sql (34.77ms)13222026-09-19 11:22:30.561 UTC [97374] ERROR: relation "goose_db_version" does not exist at character 3613232026-09-19 11:22:30.561 UTC [97374] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13242026/09/19 11:22:30 OK 20260905000000_add_claims.sql (37.16ms)13252026/09/19 11:22:30 goose: successfully migrated database to version: 2026090500000013262026/09/19 11:22:30 OK 1_commit_pending_closure.sql (2.79ms)13272026/09/19 11:22:30 OK 2_object_stats_trigger.sql (402.88µs)13282026/09/19 11:22:30 goose: up to current file version: 213292026/09/19 11:22:30 WARN claim: cannot clear write deadline error="feature not supported"13302026/09/19 11:22:30 OK 20241026095416_initial_model.sql (91.23ms)13312026/09/19 11:22:30 WARN claim: cannot clear write deadline error="feature not supported"1332--- PASS: TestClaim_StaleHeartbeatStolen (2.19s)1333=== CONT TestClientErrorHandling1334=== RUN TestClientErrorHandling/InvalidStorePath1335=== PAUSE TestClientErrorHandling/InvalidStorePath1336=== RUN TestClientErrorHandling/InvalidAuthToken1337=== PAUSE TestClientErrorHandling/InvalidAuthToken1338=== RUN TestClientErrorHandling/ServerNotAvailable1339=== PAUSE TestClientErrorHandling/ServerNotAvailable1340=== CONT TestClientCADerivations13412026/09/19 11:22:30 OK 20251210153512_drop_unused_gin_index.sql (8.69ms)13422026-09-19 11:22:30.723 UTC [97377] ERROR: relation "goose_db_version" does not exist at character 3613432026-09-19 11:22:30.723 UTC [97377] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13442026/09/19 11:22:30 OK 20251218171726_add_pins.sql (15.94ms)13452026/09/19 11:22:30 OK 20260628120000_add_object_size_and_stats.sql (9.9ms)13462026/09/19 11:22:30 OK 20260905000000_add_claims.sql (18.35ms)13472026/09/19 11:22:30 goose: successfully migrated database to version: 2026090500000013482026/09/19 11:22:30 OK 1_commit_pending_closure.sql (2.23ms)13492026/09/19 11:22:30 OK 2_object_stats_trigger.sql (373.42µs)13502026/09/19 11:22:30 goose: up to current file version: 213512026/09/19 11:22:30 OK 20241026095416_initial_model.sql (85.26ms)13522026/09/19 11:22:30 OK 20251210153512_drop_unused_gin_index.sql (3.54ms)13532026/09/19 11:22:30 OK 20251218171726_add_pins.sql (4.47ms)13542026/09/19 11:22:30 INFO Aborted multipart uploads count=013552026/09/19 11:22:30 WARN Force mode enabled - objects will be deleted immediately without grace period13562026/09/19 11:22:30 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=013572026/09/19 11:22:30 INFO Vacuumed table table=pending_closures13582026/09/19 11:22:30 INFO Vacuumed table table=pending_objects13592026/09/19 11:22:30 INFO Vacuumed table table=multipart_uploads13602026/09/19 11:22:30 INFO Vacuumed table table=closures13612026/09/19 11:22:30 INFO Vacuumed table table=objects1362--- PASS: TestGCMetrics (2.09s)1363=== CONT TestPresent13642026/09/19 11:22:30 OK 20260628120000_add_object_size_and_stats.sql (30.51ms)13652026/09/19 11:22:30 OK 20260905000000_add_claims.sql (44.23ms)13662026/09/19 11:22:30 goose: successfully migrated database to version: 2026090500000013672026/09/19 11:22:30 OK 1_commit_pending_closure.sql (6.08ms)13682026/09/19 11:22:30 OK 2_object_stats_trigger.sql (378.38µs)13692026/09/19 11:22:30 goose: up to current file version: 21370--- PASS: TestGCBugBareHashReferences (2.27s)1371=== CONT TestClaim_StreamsThroughServer13722026-09-19 11:22:31.378 UTC [97386] ERROR: relation "goose_db_version" does not exist at character 3613732026-09-19 11:22:31.378 UTC [97386] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13742026-09-19 11:22:31.397 UTC [97387] ERROR: relation "goose_db_version" does not exist at character 3613752026-09-19 11:22:31.397 UTC [97387] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13762026-09-19 11:22:31.397 UTC [97388] ERROR: relation "goose_db_version" does not exist at character 3613772026-09-19 11:22:31.397 UTC [97388] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13782026/09/19 11:22:31 OK 20241026095416_initial_model.sql (9.61ms)13792026/09/19 11:22:31 OK 20251210153512_drop_unused_gin_index.sql (463.46µs)13802026/09/19 11:22:31 OK 20251218171726_add_pins.sql (922.67µs)13812026/09/19 11:22:31 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)13822026/09/19 11:22:31 OK 20241026095416_initial_model.sql (10.17ms)13832026/09/19 11:22:31 OK 20251210153512_drop_unused_gin_index.sql (486.21µs)13842026/09/19 11:22:31 OK 20251218171726_add_pins.sql (843.46µs)13852026/09/19 11:22:31 OK 20260905000000_add_claims.sql (4.25ms)13862026/09/19 11:22:31 goose: successfully migrated database to version: 2026090500000013872026/09/19 11:22:31 OK 20260628120000_add_object_size_and_stats.sql (2.62ms)13882026/09/19 11:22:31 OK 20241026095416_initial_model.sql (12.5ms)13892026/09/19 11:22:31 OK 20251210153512_drop_unused_gin_index.sql (837.92µs)13902026/09/19 11:22:31 OK 1_commit_pending_closure.sql (1.64ms)13912026/09/19 11:22:31 OK 20260905000000_add_claims.sql (1.83ms)13922026/09/19 11:22:31 goose: successfully migrated database to version: 2026090500000013932026/09/19 11:22:31 OK 2_object_stats_trigger.sql (317.08µs)13942026/09/19 11:22:31 goose: up to current file version: 213952026/09/19 11:22:31 OK 20251218171726_add_pins.sql (1.41ms)13962026/09/19 11:22:31 OK 1_commit_pending_closure.sql (1.24ms)13972026/09/19 11:22:31 OK 2_object_stats_trigger.sql (377.5µs)13982026/09/19 11:22:31 goose: up to current file version: 213992026/09/19 11:22:31 OK 20260628120000_add_object_size_and_stats.sql (14.77ms)14002026/09/19 11:22:31 OK 20260905000000_add_claims.sql (68.18ms)14012026/09/19 11:22:31 goose: successfully migrated database to version: 2026090500000014022026/09/19 11:22:31 OK 1_commit_pending_closure.sql (1.36ms)14032026/09/19 11:22:31 OK 2_object_stats_trigger.sql (262.71µs)14042026/09/19 11:22:31 goose: up to current file version: 21405=== NAME TestPinProtectsFromGC1406 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-97126-2725002786/TestPinProtectsFromGC1445579612/001/store/nbydgds5jacxm5csigp5yn5gg64j7cyk-pinned-file.txt1407 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-97126-2725002786/TestPinProtectsFromGC1445579612/001/store/j74fn11sx6d5fx0p021lffzggwri0wzl-unpinned-file.txt14082026-09-19 11:22:31.777 UTC [97397] ERROR: relation "goose_db_version" does not exist at character 3614092026-09-19 11:22:31.777 UTC [97397] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14102026/09/19 11:22:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14112026/09/19 11:22:31 INFO Received uploads request method=POST path=/api/pending_closures1412=== NAME TestClientMultipleUploads1413 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-97126-2725002786/TestClientMultipleUploads879924578/001/store/8d3s8cfq53xn5n75pwnmjd7n4c4k5r59-test-file-0.txt14142026/09/19 11:22:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14152026/09/19 11:22:31 INFO Uploading nbydgds5jacxm5csigp5yn5gg64j7cyk-pinned-file.txt (128B)14162026/09/19 11:22:31 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14172026/09/19 11:22:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14182026/09/19 11:22:31 WARN Failed to register uploaded object key=nbydgds5jacxm5csigp5yn5gg64j7cyk.ls error="server returned 404: 404 page not found\n"14192026/09/19 11:22:31 INFO Signed narinfos id=1 count=114202026/09/19 11:22:31 INFO Uploading 1 narinfos14212026/09/19 11:22:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14222026/09/19 11:22:31 WARN Failed to register uploaded object key=nbydgds5jacxm5csigp5yn5gg64j7cyk.narinfo error="server returned 404: 404 page not found\n"1423 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-97126-2725002786/TestClientMultipleUploads879924578/001/store/77qid1g9pzv2p0zdph8rg4sys6csg5r0-test-file-1.txt14242026/09/19 11:22:31 INFO Completed upload id=114252026/09/19 11:22:31 INFO Upload complete. (222ms)14262026/09/19 11:22:31 OK 20241026095416_initial_model.sql (128.49ms)14272026/09/19 11:22:31 OK 20251210153512_drop_unused_gin_index.sql (6.99ms)14282026/09/19 11:22:32 OK 20251218171726_add_pins.sql (24.31ms)1429 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-97126-2725002786/TestClientMultipleUploads879924578/001/store/mdzjbdhmh7n9s7ziqp3xf8c5z4jgz6xm-test-file-2.txt14302026/09/19 11:22:32 OK 20260628120000_add_object_size_and_stats.sql (23.91ms)14312026/09/19 11:22:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14322026/09/19 11:22:32 OK 20260905000000_add_claims.sql (49.47ms)14332026/09/19 11:22:32 goose: successfully migrated database to version: 2026090500000014342026/09/19 11:22:32 OK 1_commit_pending_closure.sql (7.16ms)14352026/09/19 11:22:32 OK 2_object_stats_trigger.sql (304.17µs)14362026/09/19 11:22:32 goose: up to current file version: 214372026/09/19 11:22:32 INFO Received uploads request method=POST path=/api/pending_closures14382026/09/19 11:22:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14392026/09/19 11:22:32 INFO Uploading j74fn11sx6d5fx0p021lffzggwri0wzl-unpinned-file.txt (128B)14402026/09/19 11:22:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14412026/09/19 11:22:32 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14422026/09/19 11:22:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14432026/09/19 11:22:32 INFO Signed narinfos id=2 count=114442026/09/19 11:22:32 WARN Failed to register uploaded object key=j74fn11sx6d5fx0p021lffzggwri0wzl.ls error="server returned 404: 404 page not found\n"14452026/09/19 11:22:32 INFO Uploading 1 narinfos14462026/09/19 11:22:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14472026/09/19 11:22:32 WARN Failed to register uploaded object key=j74fn11sx6d5fx0p021lffzggwri0wzl.narinfo error="server returned 404: 404 page not found\n"14482026/09/19 11:22:32 INFO Completed upload id=214492026/09/19 11:22:32 INFO Upload complete. (145ms)14502026/09/19 11:22:32 INFO Received create pin request method=POST path=/api/pins/myapp14512026/09/19 11:22:32 INFO Received uploads request method=POST path=/api/pending_closures14522026-09-19 11:22:32.199 UTC [97423] ERROR: relation "goose_db_version" does not exist at character 3614532026-09-19 11:22:32.199 UTC [97423] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14542026/09/19 11:22:32 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-97126-2725002786/TestPinProtectsFromGC1445579612/001/store/nbydgds5jacxm5csigp5yn5gg64j7cyk-pinned-file.txt narinfo_key=nbydgds5jacxm5csigp5yn5gg64j7cyk.narinfo14552026/09/19 11:22:32 INFO Received uploads request method=POST path=/api/pending_closures14562026/09/19 11:22:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures14572026/09/19 11:22:32 INFO Garbage collection started14582026/09/19 11:22:32 INFO Received uploads request method=POST path=/api/pending_closures14592026/09/19 11:22:32 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14602026/09/19 11:22:32 INFO Uploading 8d3s8cfq53xn5n75pwnmjd7n4c4k5r59-test-file-0.txt (160B)14612026/09/19 11:22:32 INFO Uploading 77qid1g9pzv2p0zdph8rg4sys6csg5r0-test-file-1.txt (160B)14622026/09/19 11:22:32 INFO Uploading mdzjbdhmh7n9s7ziqp3xf8c5z4jgz6xm-test-file-2.txt (160B)14632026/09/19 11:22:32 INFO Aborted multipart uploads count=014642026/09/19 11:22:32 WARN Force mode enabled - objects will be deleted immediately without grace period14652026/09/19 11:22:32 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14662026/09/19 11:22:32 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14672026/09/19 11:22:32 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14682026/09/19 11:22:32 WARN Failed to register uploaded object key=8d3s8cfq53xn5n75pwnmjd7n4c4k5r59.ls error="server returned 404: 404 page not found\n"14692026/09/19 11:22:32 WARN Failed to register uploaded object key=77qid1g9pzv2p0zdph8rg4sys6csg5r0.ls error="server returned 404: 404 page not found\n"14702026/09/19 11:22:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign14712026/09/19 11:22:32 WARN Failed to register uploaded object key=mdzjbdhmh7n9s7ziqp3xf8c5z4jgz6xm.ls error="server returned 404: 404 page not found\n"14722026/09/19 11:22:32 INFO Signed narinfos id=3 count=114732026/09/19 11:22:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14742026/09/19 11:22:32 INFO Signed narinfos id=1 count=114752026/09/19 11:22:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14762026/09/19 11:22:32 INFO Signed narinfos id=2 count=114772026/09/19 11:22:32 INFO Uploading 3 narinfos14782026/09/19 11:22:32 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete14792026/09/19 11:22:32 WARN Failed to register uploaded object key=77qid1g9pzv2p0zdph8rg4sys6csg5r0.narinfo error="server returned 404: 404 page not found\n"14802026/09/19 11:22:32 WARN Failed to register uploaded object key=mdzjbdhmh7n9s7ziqp3xf8c5z4jgz6xm.narinfo error="server returned 404: 404 page not found\n"14812026/09/19 11:22:32 WARN Failed to register uploaded object key=8d3s8cfq53xn5n75pwnmjd7n4c4k5r59.narinfo error="server returned 404: 404 page not found\n"14822026/09/19 11:22:32 INFO Completed upload id=314832026/09/19 11:22:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14842026-09-19 11:22:32.291 UTC [97430] ERROR: relation "goose_db_version" does not exist at character 3614852026-09-19 11:22:32.291 UTC [97430] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14862026/09/19 11:22:32 INFO Completed upload id=114872026/09/19 11:22:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14882026/09/19 11:22:32 INFO Completed upload id=214892026/09/19 11:22:32 INFO Upload complete. (240ms)1490 client_integration_test.go:369: Uploaded 3 paths in 274.218458ms14912026/09/19 11:22:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1492--- PASS: TestClientMultipleUploads (1.95s)1493=== CONT TestClaim_InputsTouched14942026/09/19 11:22:32 OK 20241026095416_initial_model.sql (102.03ms)14952026/09/19 11:22:32 OK 20251210153512_drop_unused_gin_index.sql (13.09ms)14962026/09/19 11:22:32 WARN Rate limiter enabled after throttle name=s3-test rate=514972026/09/19 11:22:32 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1498=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1499 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101500 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001501--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.76s)1502=== CONT TestClaim_TwoInstances15032026/09/19 11:22:32 OK 20251218171726_add_pins.sql (21.1ms)15042026/09/19 11:22:32 INFO Received uploads request method=POST path=/api/pending_closures15052026/09/19 11:22:32 OK 20260628120000_add_object_size_and_stats.sql (31.74ms)15062026/09/19 11:22:32 OK 20241026095416_initial_model.sql (94.45ms)15072026/09/19 11:22:32 OK 20260905000000_add_claims.sql (21.03ms)15082026/09/19 11:22:32 goose: successfully migrated database to version: 2026090500000015092026/09/19 11:22:32 OK 20251210153512_drop_unused_gin_index.sql (5.83ms)15102026/09/19 11:22:32 OK 1_commit_pending_closure.sql (5.55ms)15112026/09/19 11:22:32 OK 2_object_stats_trigger.sql (268.21µs)15122026/09/19 11:22:32 goose: up to current file version: 215132026/09/19 11:22:32 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=015142026/09/19 11:22:32 OK 20251218171726_add_pins.sql (14.91ms)15152026/09/19 11:22:32 INFO Vacuumed table table=pending_closures15162026/09/19 11:22:32 INFO Vacuumed table table=pending_objects15172026/09/19 11:22:32 INFO Vacuumed table table=multipart_uploads15182026/09/19 11:22:32 OK 20260628120000_add_object_size_and_stats.sql (17.4ms)15192026/09/19 11:22:32 INFO Vacuumed table table=closures15202026/09/19 11:22:32 INFO Vacuumed table table=objects15212026/09/19 11:22:32 OK 20260905000000_add_claims.sql (23.08ms)15222026/09/19 11:22:32 goose: successfully migrated database to version: 2026090500000015232026/09/19 11:22:32 OK 1_commit_pending_closure.sql (1.28ms)15242026/09/19 11:22:32 OK 2_object_stats_trigger.sql (241.29µs)15252026/09/19 11:22:32 goose: up to current file version: 215262026/09/19 11:22:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15272026-09-19 11:22:32.504 UTC [97445] ERROR: relation "goose_db_version" does not exist at character 3615282026-09-19 11:22:32.504 UTC [97445] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15292026/09/19 11:22:32 INFO Received uploads request method=POST path=/api/pending_closures15302026/09/19 11:22:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15312026/09/19 11:22:32 INFO Uploading hhqh6vq0lg0yynwc6xrxrzr2wpfqkify-shared-dep (136B)15322026/09/19 11:22:32 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1533=== NAME TestClientIntegration1534 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-97126-2725002786/TestClientIntegration3056143266/002/store/16kdxn4m585nypcwzsdyjz4yphs73gwj-test-file.txt1535=== NAME TestClientWithDependencies1536 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-97126-2725002786/TestClientWithDependencies1403406153/001/store/fnx68wvcc8lpvbywb3xjjwj2y310npli-test-script15372026/09/19 11:22:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15382026/09/19 11:22:32 INFO Signed narinfos id=2 count=115392026/09/19 11:22:32 INFO Uploading 1 narinfos15402026/09/19 11:22:32 WARN Failed to register uploaded object key=hhqh6vq0lg0yynwc6xrxrzr2wpfqkify.ls error="server returned 404: 404 page not found\n"15412026/09/19 11:22:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15422026/09/19 11:22:32 WARN Failed to register uploaded object key=hhqh6vq0lg0yynwc6xrxrzr2wpfqkify.narinfo error="server returned 404: 404 page not found\n"15432026/09/19 11:22:32 INFO Completed upload id=215442026/09/19 11:22:32 INFO Upload complete. (148ms)15452026/09/19 11:22:32 INFO Received uploads request method=POST path=/api/pending_closures15462026/09/19 11:22:32 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15472026/09/19 11:22:32 INFO Uploading hhqh6vq0lg0yynwc6xrxrzr2wpfqkify-shared-dep (136B)15482026/09/19 11:22:32 INFO Uploading ydhadd7cq0lql54b5saw3jzlwpi9x9d5-top (256B)1549 client_integration_test.go:615: Found 1 dependencies (including self)15502026/09/19 11:22:32 OK 20241026095416_initial_model.sql (70.74ms)15512026/09/19 11:22:32 WARN Failed to register uploaded object key=nar/1zsbgzf0q6p1pqfl4cw1fahyq4jg75vi4i1jb1shj4a5mfxsvr0m.nar.zst error="server returned 404: 404 page not found\n"15522026/09/19 11:22:32 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15532026/09/19 11:22:32 OK 20251210153512_drop_unused_gin_index.sql (11.34ms)15542026/09/19 11:22:32 WARN Failed to register uploaded object key=ydhadd7cq0lql54b5saw3jzlwpi9x9d5.ls error="server returned 404: 404 page not found\n"15552026/09/19 11:22:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15562026/09/19 11:22:32 WARN Failed to register uploaded object key=hhqh6vq0lg0yynwc6xrxrzr2wpfqkify.ls error="server returned 404: 404 page not found\n"15572026/09/19 11:22:32 INFO Signed narinfos id=1 count=115582026/09/19 11:22:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15592026/09/19 11:22:32 INFO Signed narinfos id=3 count=115602026/09/19 11:22:32 INFO Uploading 2 narinfos15612026/09/19 11:22:32 OK 20251218171726_add_pins.sql (17.83ms)15622026/09/19 11:22:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15632026/09/19 11:22:32 WARN Failed to register uploaded object key=ydhadd7cq0lql54b5saw3jzlwpi9x9d5.narinfo error="server returned 404: 404 page not found\n"15642026/09/19 11:22:32 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15652026/09/19 11:22:32 WARN Failed to register uploaded object key=hhqh6vq0lg0yynwc6xrxrzr2wpfqkify.narinfo error="server returned 404: 404 page not found\n"15662026/09/19 11:22:32 INFO Completed upload id=315672026/09/19 11:22:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15682026/09/19 11:22:32 INFO Completed upload id=115692026/09/19 11:22:32 INFO Upload complete. (403ms)1570=== NAME TestClientSharedPathCommittedMidPush1571 client_integration_test.go:680: Retrieved narinfo from S3:1572 StorePath: /nix/var/nix/builds/nix-97126-2725002786/TestClientSharedPathCommittedMidPush2168027386/001/store/hhqh6vq0lg0yynwc6xrxrzr2wpfqkify-shared-dep1573 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1574 Compression: zstd1575 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821576 NarSize: 1361577 References: 1578 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1579 client_integration_test.go:680: Retrieved narinfo from S3:1580 StorePath: /nix/var/nix/builds/nix-97126-2725002786/TestClientSharedPathCommittedMidPush2168027386/001/store/ydhadd7cq0lql54b5saw3jzlwpi9x9d5-top1581 URL: nar/1zsbgzf0q6p1pqfl4cw1fahyq4jg75vi4i1jb1shj4a5mfxsvr0m.nar.zst1582 Compression: zstd1583 NarHash: sha256:1zsbgzf0q6p1pqfl4cw1fahyq4jg75vi4i1jb1shj4a5mfxsvr0m1584 NarSize: 2561585 References: /nix/var/nix/builds/nix-97126-2725002786/TestClientSharedPathCommittedMidPush2168027386/001/store/hhqh6vq0lg0yynwc6xrxrzr2wpfqkify-shared-dep1586 CA: text:sha256:1qxjj0rwila6f9k2cv2zpq01q4hy4waziy9iasgz5kccb9iw78b215872026/09/19 11:22:32 OK 20260628120000_add_object_size_and_stats.sql (27.97ms)1588--- PASS: TestClientSharedPathCommittedMidPush (2.66s)1589=== CONT TestCacheStatsHandler15902026/09/19 11:22:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15912026/09/19 11:22:32 INFO Received uploads request method=POST path=/api/pending_closures15922026/09/19 11:22:32 OK 20260905000000_add_claims.sql (38.42ms)15932026/09/19 11:22:32 goose: successfully migrated database to version: 2026090500000015942026/09/19 11:22:32 OK 1_commit_pending_closure.sql (9.71ms)15952026/09/19 11:22:32 OK 2_object_stats_trigger.sql (257.17µs)15962026/09/19 11:22:32 goose: up to current file version: 215972026/09/19 11:22:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15982026/09/19 11:22:32 INFO Uploading fnx68wvcc8lpvbywb3xjjwj2y310npli-test-script (136B)15992026/09/19 11:22:32 INFO Received uploads request method=POST path=/api/pending_closures16002026/09/19 11:22:32 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16012026/09/19 11:22:32 WARN Failed to register uploaded object key=log/mssnnxzr216fjfiys6jg38pxibnqb3rr-test-script.drv error="server returned 404: 404 page not found\n"16022026/09/19 11:22:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16032026/09/19 11:22:32 INFO Uploading 16kdxn4m585nypcwzsdyjz4yphs73gwj-test-file.txt (152B)16042026/09/19 11:22:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16052026/09/19 11:22:32 WARN Failed to register uploaded object key=fnx68wvcc8lpvbywb3xjjwj2y310npli.ls error="server returned 404: 404 page not found\n"16062026/09/19 11:22:32 INFO Signed narinfos id=1 count=116072026/09/19 11:22:32 INFO Uploading 1 narinfos16082026/09/19 11:22:32 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16092026/09/19 11:22:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16102026/09/19 11:22:32 WARN Failed to register uploaded object key=16kdxn4m585nypcwzsdyjz4yphs73gwj.ls error="server returned 404: 404 page not found\n"16112026/09/19 11:22:32 WARN Failed to register uploaded object key=fnx68wvcc8lpvbywb3xjjwj2y310npli.narinfo error="server returned 404: 404 page not found\n"16122026/09/19 11:22:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16132026/09/19 11:22:32 INFO Signed narinfos id=1 count=116142026/09/19 11:22:32 INFO Uploading 1 narinfos16152026/09/19 11:22:32 INFO Completed upload id=116162026/09/19 11:22:32 INFO Upload complete. (148ms)1617=== NAME TestClientWithDependencies1618 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-97126-2725002786/TestClientWithDependencies1403406153/001/store) requires matching store prefix16192026/09/19 11:22:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16202026/09/19 11:22:32 WARN Failed to register uploaded object key=16kdxn4m585nypcwzsdyjz4yphs73gwj.narinfo error="server returned 404: 404 page not found\n"16212026/09/19 11:22:32 INFO Completed upload id=116222026/09/19 11:22:32 INFO Upload complete. (216ms)16232026/09/19 11:22:32 INFO All 1 paths already cached1624=== NAME TestClientIntegration1625 client_integration_test.go:312: Retrieved narinfo from S3:1626 StorePath: /nix/var/nix/builds/nix-97126-2725002786/TestClientIntegration3056143266/002/store/16kdxn4m585nypcwzsdyjz4yphs73gwj-test-file.txt1627 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1628 Compression: zstd1629 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11630 NarSize: 1521631 References: 1632 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11633--- PASS: TestClientWithDependencies (2.55s)1634=== CONT TestClaim_FailWithoutKindReleases1635=== NAME TestClientIntegration1636 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1637 client_integration_test.go:313: Decompressed .ls content (64 bytes):1638 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1639 client_integration_test.go:316: Testing garbage collection...16402026/09/19 11:22:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures16412026/09/19 11:22:32 INFO Garbage collection started16422026/09/19 11:22:32 INFO Received uploads request method=POST path=/api/pending_closures16432026/09/19 11:22:32 INFO Aborted multipart uploads count=016442026/09/19 11:22:32 WARN Force mode enabled - objects will be deleted immediately without grace period1645=== NAME TestClientCADerivations1646 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-97126-2725002786/TestClientCADerivations1913737325/001/store/p77fx7pnadpdgxg8akkcblzdzm3ycrp0-ca-test1647 client_ca_test.go:139: Found 1 dependencies (including self)16482026/09/19 11:22:33 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=016492026/09/19 11:22:33 INFO Vacuumed table table=pending_closures1650=== NAME TestOrphanedObjectsGCStressTest1651 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains16522026-09-19 11:22:33.174 UTC [97484] ERROR: relation "goose_db_version" does not exist at character 3616532026-09-19 11:22:33.174 UTC [97484] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16542026/09/19 11:22:33 INFO Vacuumed table table=pending_objects16552026/09/19 11:22:33 INFO Vacuumed table table=multipart_uploads16562026/09/19 11:22:33 INFO Vacuumed table table=closures1657 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16582026/09/19 11:22:33 INFO Vacuumed table table=objects16592026/09/19 11:22:33 OK 20241026095416_initial_model.sql (9.4ms)16602026/09/19 11:22:33 OK 20251210153512_drop_unused_gin_index.sql (1.27ms)16612026/09/19 11:22:33 OK 20251218171726_add_pins.sql (1.05ms)16622026/09/19 11:22:33 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16632026/09/19 11:22:33 OK 20260628120000_add_object_size_and_stats.sql (24.66ms)16642026/09/19 11:22:33 OK 20260905000000_add_claims.sql (27.98ms)16652026/09/19 11:22:33 goose: successfully migrated database to version: 2026090500000016662026/09/19 11:22:33 OK 1_commit_pending_closure.sql (1.08ms)16672026/09/19 11:22:33 OK 2_object_stats_trigger.sql (315.79µs)16682026/09/19 11:22:33 goose: up to current file version: 216692026/09/19 11:22:33 INFO Received uploads request method=POST path=/api/pending_closures16702026/09/19 11:22:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16712026/09/19 11:22:33 INFO Uploading p77fx7pnadpdgxg8akkcblzdzm3ycrp0-ca-test (144B)16722026/09/19 11:22:33 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16732026/09/19 11:22:33 WARN Failed to register uploaded object key=log/kaxrjrxlihi7asd31kwkswd28f470d6y-ca-test.drv error="server returned 404: 404 page not found\n"16742026/09/19 11:22:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16752026/09/19 11:22:33 WARN Failed to register uploaded object key=p77fx7pnadpdgxg8akkcblzdzm3ycrp0.ls error="server returned 404: 404 page not found\n"16762026/09/19 11:22:33 INFO Signed narinfos id=1 count=116772026/09/19 11:22:33 INFO Uploading 1 narinfos16782026/09/19 11:22:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16792026/09/19 11:22:33 WARN Failed to register uploaded object key=p77fx7pnadpdgxg8akkcblzdzm3ycrp0.narinfo error="server returned 404: 404 page not found\n"16802026/09/19 11:22:33 INFO Completed upload id=116812026/09/19 11:22:33 INFO Upload complete. (199ms)16822026-09-19 11:22:33.364 UTC [97489] ERROR: relation "goose_db_version" does not exist at character 3616832026-09-19 11:22:33.364 UTC [97489] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1684=== NAME TestClientCADerivations1685 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-97126-2725002786/TestClientCADerivations1913737325/001/store/p77fx7pnadpdgxg8akkcblzdzm3ycrp0-ca-test1686 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1687 Compression: zstd1688 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1689 NarSize: 1441690 References: 1691 Deriver: /nix/var/nix/builds/nix-97126-2725002786/TestClientCADerivations1913737325/001/store/kaxrjrxlihi7asd31kwkswd28f470d6y-ca-test.drv1692 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1693 client_ca_test.go:185: Checking for realisation files in S3...1694 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1695 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16962026/09/19 11:22:33 INFO Received uploads request method=POST path=/api/pending_closures1697 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket39?endpoint=http://localhost:59128®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-97126-2725002786/TestClientCADerivations1913737325/001/store'1698 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116992026/09/19 11:22:33 OK 20241026095416_initial_model.sql (78.64ms)17002026/09/19 11:22:33 OK 20251210153512_drop_unused_gin_index.sql (6.16ms)17012026/09/19 11:22:33 OK 20251218171726_add_pins.sql (23.27ms)1702--- PASS: TestClientCADerivations (2.81s)1703=== CONT TestClaim_FailWakesWaitersButIsNotRemembered17042026/09/19 11:22:33 OK 20260628120000_add_object_size_and_stats.sql (9.01ms)17052026/09/19 11:22:33 OK 20260905000000_add_claims.sql (4.52ms)17062026/09/19 11:22:33 goose: successfully migrated database to version: 2026090500000017072026/09/19 11:22:33 OK 1_commit_pending_closure.sql (9.6ms)17082026/09/19 11:22:33 OK 2_object_stats_trigger.sql (1.03ms)17092026/09/19 11:22:33 goose: up to current file version: 217102026/09/19 11:22:33 INFO Received uploads request method=POST path=/api/pending_closures17112026/09/19 11:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17122026-09-19 11:22:33.859 UTC [97497] ERROR: relation "goose_db_version" does not exist at character 3617132026-09-19 11:22:33.859 UTC [97497] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17142026-09-19 11:22:33.864 UTC [97498] ERROR: relation "goose_db_version" does not exist at character 3617152026-09-19 11:22:33.864 UTC [97498] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17162026/09/19 11:22:33 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002000000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1LmJlMjIwZTZiLTA1NmMtNDIyYy05MTNiLTc5MTQzMWUwZGJkYXgxNzg5ODE2OTUyOTIwODE1MDAw parts=1017172026/09/19 11:22:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17182026/09/19 11:22:33 INFO Completed upload id=117192026/09/19 11:22:33 INFO Received uploads request method=POST path=/api/pending_closures17202026/09/19 11:22:33 OK 20241026095416_initial_model.sql (70.61ms)17212026/09/19 11:22:33 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)17222026/09/19 11:22:33 OK 20241026095416_initial_model.sql (53.58ms)17232026/09/19 11:22:33 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)17242026/09/19 11:22:33 OK 20251218171726_add_pins.sql (4.61ms)17252026/09/19 11:22:33 OK 20251218171726_add_pins.sql (4.41ms)17262026/09/19 11:22:33 OK 20260628120000_add_object_size_and_stats.sql (4.42ms)17272026/09/19 11:22:34 OK 20260628120000_add_object_size_and_stats.sql (56.77ms)17282026/09/19 11:22:34 OK 20260905000000_add_claims.sql (60.49ms)17292026/09/19 11:22:34 goose: successfully migrated database to version: 2026090500000017302026/09/19 11:22:34 OK 1_commit_pending_closure.sql (8.01ms)17312026/09/19 11:22:34 OK 2_object_stats_trigger.sql (670.92µs)17322026/09/19 11:22:34 goose: up to current file version: 217332026/09/19 11:22:34 OK 20260905000000_add_claims.sql (52.34ms)17342026/09/19 11:22:34 goose: successfully migrated database to version: 2026090500000017352026/09/19 11:22:34 OK 1_commit_pending_closure.sql (3.94ms)17362026/09/19 11:22:34 OK 2_object_stats_trigger.sql (543.08µs)17372026/09/19 11:22:34 goose: up to current file version: 217382026/09/19 11:22:34 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01739=== NAME TestPinProtectsFromGC1740 client_integration_test.go:794: Pin successfully protected closure from garbage collection1741--- PASS: TestPinProtectsFromGC (5.00s)1742=== CONT TestClaim_HolderDisconnectKeepsClaim17432026/09/19 11:22:34 WARN claim: cannot clear write deadline error="feature not supported"17442026/09/19 11:22:34 WARN claim: cannot clear write deadline error="feature not supported"1745--- PASS: TestClaim_FailWithoutKindReleases (1.48s)1746=== CONT TestClaim_TooManyStreams1747--- PASS: TestClaim_StreamsThroughServer (3.26s)1748=== CONT TestClaim_GCMarkedOutputCountsAsAbsent1749--- PASS: TestCacheStatsHandler (2.00s)1750=== CONT TestClaim_BuildWaitComplete17512026/09/19 11:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17522026-09-19 11:22:34.783 UTC [97508] ERROR: relation "goose_db_version" does not exist at character 3617532026-09-19 11:22:34.783 UTC [97508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17542026/09/19 11:22:34 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1LjY0MzEyN2M5LWI1Y2ItNGViZS05MTliLTZmMWYyODA3YmFmN3gxNzg5ODE2OTUzNDgwMjkxMDAw parts=1017552026/09/19 11:22:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17562026/09/19 11:22:34 INFO Completed upload id=117572026/09/19 11:22:34 WARN claim: cannot clear write deadline error="feature not supported"17582026/09/19 11:22:34 INFO Aborted multipart uploads count=017592026/09/19 11:22:34 WARN Force mode enabled - objects will be deleted immediately without grace period17602026/09/19 11:22:34 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=017612026/09/19 11:22:34 INFO Vacuumed table table=pending_closures17622026/09/19 11:22:34 INFO Vacuumed table table=pending_objects17632026/09/19 11:22:34 INFO Vacuumed table table=multipart_uploads17642026/09/19 11:22:34 INFO Vacuumed table table=closures17652026/09/19 11:22:34 INFO Vacuumed table table=objects1766--- PASS: TestClaim_InputsTouched (2.54s)1767=== CONT TestReadProxyDisabled17682026/09/19 11:22:34 OK 20241026095416_initial_model.sql (38.2ms)17692026/09/19 11:22:34 OK 20251210153512_drop_unused_gin_index.sql (3.07ms)17702026/09/19 11:22:34 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01771=== NAME TestClientIntegration1772 client_integration_test.go:323: Objects in database after GC:1773 client_integration_test.go:323: Successfully deleted all objects with GC --force17742026/09/19 11:22:34 OK 20251218171726_add_pins.sql (40.12ms)17752026/09/19 11:22:34 OK 20260628120000_add_object_size_and_stats.sql (33.44ms)1776--- PASS: TestClientIntegration (4.46s)1777=== CONT TestReadRedirectKeepsNarinfoProxied17782026/09/19 11:22:34 OK 20260905000000_add_claims.sql (7.93ms)17792026/09/19 11:22:34 goose: successfully migrated database to version: 2026090500000017802026/09/19 11:22:34 OK 1_commit_pending_closure.sql (3.59ms)17812026/09/19 11:22:34 OK 2_object_stats_trigger.sql (1.02ms)17822026/09/19 11:22:34 goose: up to current file version: 217832026/09/19 11:22:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17842026/09/19 11:22:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17852026/09/19 11:22:35 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002100000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1LmJkZDk0YWZmLTIyMjAtNGZlZC05MGM1LTRiZWI1M2NiOTc3MHgxNzg5ODE2OTUzOTMzNTkyMDAw parts=1017862026/09/19 11:22:35 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17872026/09/19 11:22:35 INFO Completed upload id=21788--- PASS: TestPresent (4.41s)1789=== CONT TestReadRedirectNar17902026/09/19 11:22:35 WARN claim: cannot clear write deadline error="feature not supported"17912026/09/19 11:22:35 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1LmY5ZmUyZGViLTk4NWEtNGM1Ny1hNjNlLTEyOGQzM2RhNDA1MHgxNzg5ODE2OTUzODA0MzE5MDAw parts=1017922026/09/19 11:22:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17932026/09/19 11:22:35 INFO Signed narinfos id=1 count=117942026/09/19 11:22:35 WARN claim: cannot clear write deadline error="feature not supported"17952026/09/19 11:22:35 WARN claim: cannot clear write deadline error="feature not supported"17962026/09/19 11:22:35 WARN claim: cannot clear write deadline error="feature not supported"17972026/09/19 11:22:35 WARN claim: cannot clear write deadline error="feature not supported"17982026/09/19 11:22:35 WARN claim: cannot clear write deadline error="feature not supported"17992026/09/19 11:22:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1800--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (1.79s)1801=== CONT TestReadProxyConditionalGet18022026/09/19 11:22:35 INFO Completed upload id=11803--- PASS: TestClaim_TwoInstances (2.93s)1804=== CONT TestReadProxyRootRedirectsToIndexHTML1805=== NAME TestOrphanedObjectsGCStressTest1806 orphaned_objects_gc_test.go:509: Stress test completed successfully:1807 orphaned_objects_gc_test.go:510: - Active objects preserved: 201808 orphaned_objects_gc_test.go:511: - Objects deleted: 2101809 orphaned_objects_gc_test.go:512: - Total GC'd: 2101810--- PASS: TestOrphanedObjectsGCStressTest (7.68s)1811=== CONT TestService_AuthMiddleware_OIDC18122026/09/19 11:22:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59348/oidc18132026-09-19 11:22:35.361 UTC [97524] ERROR: relation "goose_db_version" does not exist at character 3618142026-09-19 11:22:35.361 UTC [97524] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18152026-09-19 11:22:35.367 UTC [97525] ERROR: relation "goose_db_version" does not exist at character 3618162026-09-19 11:22:35.367 UTC [97525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18172026/09/19 11:22:35 OK 20241026095416_initial_model.sql (11.99ms)18182026/09/19 11:22:35 OK 20251210153512_drop_unused_gin_index.sql (974.63µs)18192026/09/19 11:22:35 OK 20251218171726_add_pins.sql (1.5ms)18202026/09/19 11:22:35 OK 20260628120000_add_object_size_and_stats.sql (11.51ms)18212026/09/19 11:22:35 OK 20241026095416_initial_model.sql (14.95ms)18222026/09/19 11:22:35 OK 20251210153512_drop_unused_gin_index.sql (487.83µs)18232026/09/19 11:22:35 OK 20251218171726_add_pins.sql (755.17µs)18242026/09/19 11:22:35 OK 20260905000000_add_claims.sql (12.77ms)18252026/09/19 11:22:35 goose: successfully migrated database to version: 2026090500000018262026/09/19 11:22:35 OK 20260628120000_add_object_size_and_stats.sql (12.2ms)18272026/09/19 11:22:35 OK 1_commit_pending_closure.sql (1.95ms)18282026/09/19 11:22:35 OK 2_object_stats_trigger.sql (716.33µs)18292026/09/19 11:22:35 goose: up to current file version: 218302026/09/19 11:22:35 OK 20260905000000_add_claims.sql (3.67ms)18312026/09/19 11:22:35 goose: successfully migrated database to version: 2026090500000018322026/09/19 11:22:35 OK 1_commit_pending_closure.sql (1.38ms)18332026/09/19 11:22:35 OK 2_object_stats_trigger.sql (252.38µs)18342026/09/19 11:22:35 goose: up to current file version: 218352026/09/19 11:22:35 WARN claim: cannot clear write deadline error="feature not supported"18362026/09/19 11:22:35 WARN claim: cannot clear write deadline error="feature not supported"18372026-09-19 11:22:35.705 UTC [97527] ERROR: relation "goose_db_version" does not exist at character 3618382026-09-19 11:22:35.705 UTC [97527] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18392026-09-19 11:22:35.712 UTC [97528] ERROR: relation "goose_db_version" does not exist at character 3618402026-09-19 11:22:35.712 UTC [97528] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18412026/09/19 11:22:35 WARN claim: cannot clear write deadline error="feature not supported"1842--- PASS: TestClaim_TooManyStreams (1.41s)1843=== CONT TestCacheConfigHandler1844=== RUN TestCacheConfigHandler/full_config,_no_issuer1845=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1846=== RUN TestCacheConfigHandler/no_cache_url_configured1847=== PAUSE TestCacheConfigHandler/no_cache_url_configured1848=== RUN TestCacheConfigHandler/no_signing_keys1849=== PAUSE TestCacheConfigHandler/no_signing_keys1850=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1851=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1852=== CONT TestService_ReadScope_PublicByDefault18532026/09/19 11:22:35 OK 20241026095416_initial_model.sql (17.61ms)18542026/09/19 11:22:35 OK 20251210153512_drop_unused_gin_index.sql (885.92µs)18552026/09/19 11:22:35 OK 20251218171726_add_pins.sql (1.43ms)18562026-09-19 11:22:35.770 UTC [97532] ERROR: relation "goose_db_version" does not exist at character 3618572026-09-19 11:22:35.770 UTC [97532] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18582026/09/19 11:22:35 OK 20241026095416_initial_model.sql (27.94ms)18592026/09/19 11:22:35 OK 20260628120000_add_object_size_and_stats.sql (8.48ms)18602026/09/19 11:22:35 OK 20251210153512_drop_unused_gin_index.sql (979.83µs)18612026/09/19 11:22:35 OK 20260905000000_add_claims.sql (2.28ms)18622026/09/19 11:22:35 goose: successfully migrated database to version: 2026090500000018632026/09/19 11:22:35 OK 20251218171726_add_pins.sql (2.5ms)18642026/09/19 11:22:35 OK 1_commit_pending_closure.sql (1.3ms)18652026/09/19 11:22:35 OK 2_object_stats_trigger.sql (289.42µs)18662026/09/19 11:22:35 goose: up to current file version: 218672026/09/19 11:22:35 OK 20260628120000_add_object_size_and_stats.sql (26.09ms)18682026/09/19 11:22:35 OK 20260905000000_add_claims.sql (40.64ms)18692026/09/19 11:22:35 goose: successfully migrated database to version: 2026090500000018702026/09/19 11:22:35 OK 20241026095416_initial_model.sql (72.17ms)18712026/09/19 11:22:35 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)18722026/09/19 11:22:35 OK 1_commit_pending_closure.sql (9.59ms)18732026-09-19 11:22:35.852 UTC [97533] ERROR: relation "goose_db_version" does not exist at character 3618742026-09-19 11:22:35.852 UTC [97533] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18752026/09/19 11:22:35 OK 2_object_stats_trigger.sql (488.13µs)18762026/09/19 11:22:35 goose: up to current file version: 218772026/09/19 11:22:35 OK 20251218171726_add_pins.sql (14.46ms)18782026/09/19 11:22:35 OK 20260628120000_add_object_size_and_stats.sql (8.75ms)18792026/09/19 11:22:35 OK 20260905000000_add_claims.sql (23.86ms)18802026/09/19 11:22:35 goose: successfully migrated database to version: 2026090500000018812026/09/19 11:22:35 OK 1_commit_pending_closure.sql (1.97ms)18822026/09/19 11:22:35 OK 2_object_stats_trigger.sql (333.96µs)18832026/09/19 11:22:35 goose: up to current file version: 218842026/09/19 11:22:35 INFO Received uploads request method=POST path=/api/pending_closures18852026/09/19 11:22:35 OK 20241026095416_initial_model.sql (85.38ms)18862026/09/19 11:22:35 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)18872026/09/19 11:22:35 OK 20251218171726_add_pins.sql (19.09ms)18882026/09/19 11:22:36 OK 20260628120000_add_object_size_and_stats.sql (35.09ms)18892026/09/19 11:22:36 OK 20260905000000_add_claims.sql (17.46ms)18902026/09/19 11:22:36 goose: successfully migrated database to version: 2026090500000018912026/09/19 11:22:36 OK 1_commit_pending_closure.sql (3.6ms)18922026/09/19 11:22:36 OK 2_object_stats_trigger.sql (765.83µs)18932026/09/19 11:22:36 goose: up to current file version: 218942026/09/19 11:22:36 WARN claim: cannot clear write deadline error="feature not supported"18952026/09/19 11:22:36 INFO Received uploads request method=POST path=/api/pending_closures18962026-09-19 11:22:36.219 UTC [97536] ERROR: relation "goose_db_version" does not exist at character 3618972026-09-19 11:22:36.219 UTC [97536] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18982026/09/19 11:22:36 OK 20241026095416_initial_model.sql (171.23ms)18992026/09/19 11:22:36 OK 20251210153512_drop_unused_gin_index.sql (17.09ms)1900--- PASS: TestReadProxyDisabled (1.63s)1901=== CONT TestService_RequireScope_OIDC19022026/09/19 11:22:36 OK 20251218171726_add_pins.sql (37.08ms)19032026/09/19 11:22:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59364/oidc19042026/09/19 11:22:36 OK 20260628120000_add_object_size_and_stats.sql (55.72ms)19052026-09-19 11:22:36.591 UTC [97538] ERROR: relation "goose_db_version" does not exist at character 3619062026-09-19 11:22:36.591 UTC [97538] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19072026/09/19 11:22:36 OK 20260905000000_add_claims.sql (30.28ms)19082026/09/19 11:22:36 goose: successfully migrated database to version: 2026090500000019092026/09/19 11:22:36 OK 1_commit_pending_closure.sql (9.22ms)19102026/09/19 11:22:36 OK 2_object_stats_trigger.sql (437.17µs)19112026/09/19 11:22:36 goose: up to current file version: 219122026-09-19 11:22:36.614 UTC [97541] ERROR: relation "goose_db_version" does not exist at character 3619132026-09-19 11:22:36.614 UTC [97541] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19142026-09-19 11:22:36.675 UTC [97542] ERROR: relation "goose_db_version" does not exist at character 3619152026-09-19 11:22:36.675 UTC [97542] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1916--- PASS: TestReadRedirectKeepsNarinfoProxied (1.82s)1917=== CONT TestGCTaskStore_ConflictDifferentParams1918--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1919=== CONT TestGCTaskStore_GetEmpty1920--- PASS: TestGCTaskStore_GetEmpty (0.00s)1921=== CONT TestGCTaskStore_DeduplicateSameParams1922--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1923=== CONT TestReadProxyHead19242026/09/19 11:22:36 OK 20241026095416_initial_model.sql (172.17ms)19252026/09/19 11:22:36 OK 20241026095416_initial_model.sql (136.99ms)19262026/09/19 11:22:36 OK 20251210153512_drop_unused_gin_index.sql (15.36ms)19272026/09/19 11:22:36 OK 20251210153512_drop_unused_gin_index.sql (14.23ms)19282026/09/19 11:22:36 OK 20251218171726_add_pins.sql (19.86ms)19292026/09/19 11:22:36 OK 20251218171726_add_pins.sql (14.81ms)19302026/09/19 11:22:36 OK 20260628120000_add_object_size_and_stats.sql (17.31ms)19312026/09/19 11:22:36 OK 20241026095416_initial_model.sql (127.79ms)19322026/09/19 11:22:36 OK 20251210153512_drop_unused_gin_index.sql (9.81ms)19332026/09/19 11:22:36 OK 20260628120000_add_object_size_and_stats.sql (43.56ms)19342026/09/19 11:22:36 OK 20251218171726_add_pins.sql (38.08ms)19352026/09/19 11:22:36 OK 20260905000000_add_claims.sql (61.86ms)19362026/09/19 11:22:36 goose: successfully migrated database to version: 2026090500000019372026/09/19 11:22:36 OK 1_commit_pending_closure.sql (9.08ms)19382026/09/19 11:22:36 OK 2_object_stats_trigger.sql (417.88µs)19392026/09/19 11:22:36 goose: up to current file version: 219402026/09/19 11:22:36 OK 20260628120000_add_object_size_and_stats.sql (45.84ms)19412026/09/19 11:22:36 OK 20260905000000_add_claims.sql (90.64ms)19422026/09/19 11:22:36 goose: successfully migrated database to version: 2026090500000019432026/09/19 11:22:36 OK 1_commit_pending_closure.sql (2.9ms)19442026/09/19 11:22:36 OK 2_object_stats_trigger.sql (512.17µs)19452026/09/19 11:22:36 goose: up to current file version: 219462026/09/19 11:22:36 OK 20260905000000_add_claims.sql (44.06ms)19472026/09/19 11:22:36 goose: successfully migrated database to version: 2026090500000019482026/09/19 11:22:37 OK 1_commit_pending_closure.sql (2.55ms)19492026/09/19 11:22:37 OK 2_object_stats_trigger.sql (350.21µs)19502026/09/19 11:22:37 goose: up to current file version: 21951--- PASS: TestReadRedirectNar (1.77s)1952=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1953=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1954=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1955=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1956=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1957=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1958=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1959=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1960=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1961=== CONT TestService_ReadAuthMiddleware19622026/09/19 11:22:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19632026/09/19 11:22:37 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1LjhjNDE1MzBlLTc3NGEtNDRlYy04NWE5LWFlODRmZmQ0NzBiMngxNzg5ODE2OTU1OTg1MzYzMDAw parts=1019642026/09/19 11:22:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19652026-09-19 11:22:37.365 UTC [97549] ERROR: relation "goose_db_version" does not exist at character 3619662026-09-19 11:22:37.365 UTC [97549] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19672026/09/19 11:22:37 INFO Completed upload id=119682026/09/19 11:22:37 WARN claim: cannot clear write deadline error="feature not supported"19692026/09/19 11:22:37 WARN claim: cannot clear write deadline error="feature not supported"1970--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (2.82s)1971=== CONT TestService_AuthMiddleware_MTLSProxyHeader1972--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.21s)1973=== CONT TestIsValidCachePath/narinfo1974=== CONT TestIsValidCachePath/index.html1975=== CONT TestIsValidCachePath/short_hash1976=== CONT TestIsValidCachePath/wrong_extension1977=== CONT TestIsValidCachePath/leading_slash1978=== CONT TestIsValidCachePath/invalid_char_e1979=== CONT TestIsValidCachePath/traversal_in_middle1980=== CONT TestIsValidCachePath/traversal_parent1981=== CONT TestIsValidCachePath/nar_uncompressed1982=== CONT TestIsValidCachePath/nix-cache-info1983=== CONT TestIsValidCachePath/realisation1984=== CONT TestIsValidCachePath/log1985=== CONT TestIsValidCachePath/ls1986=== CONT TestIsValidCachePath/invalid_char_u1987=== CONT TestIsValidCachePath/empty1988=== CONT TestIsValidCachePath/random_path1989=== CONT TestIsValidCachePath/nar_xz1990=== CONT TestIsValidCachePath/nar_bz21991=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1992=== CONT TestIsValidCachePath/nar_zst1993--- PASS: TestIsValidCachePath (0.00s)1994 --- PASS: TestIsValidCachePath/narinfo (0.00s)1995 --- PASS: TestIsValidCachePath/index.html (0.00s)1996 --- PASS: TestIsValidCachePath/short_hash (0.00s)1997 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1998 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1999 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2000 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2001 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2002 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2003 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2004 --- PASS: TestIsValidCachePath/realisation (0.00s)2005 --- PASS: TestIsValidCachePath/log (0.00s)2006 --- PASS: TestIsValidCachePath/ls (0.00s)2007 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2008 --- PASS: TestIsValidCachePath/empty (0.00s)2009 --- PASS: TestIsValidCachePath/random_path (0.00s)2010 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2011 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2012 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2013 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2014=== CONT TestParseSingleRange/none2015=== CONT TestParseSingleRange/open-ended2016=== CONT TestParseSingleRange/start_far_past_EOF2017=== CONT TestParseSingleRange/start_past_EOF2018=== CONT TestParseSingleRange/single_byte2019=== CONT TestParseSingleRange/suffix_exceeds_size2020=== CONT TestParseSingleRange/suffix2021=== CONT TestParseSingleRange/end_clamped_to_size2022=== CONT TestParseSingleRange/malformed_both_empty2023=== CONT TestParseSingleRange/malformed_end_before_start2024=== CONT TestParseSingleRange/multi-range_ignored2025=== CONT TestParseSingleRange/malformed_no_dash2026=== CONT TestParseSingleRange/unknown_unit2027=== CONT TestParseSingleRange/closed2028--- PASS: TestParseSingleRange (0.00s)2029 --- PASS: TestParseSingleRange/none (0.00s)2030 --- PASS: TestParseSingleRange/open-ended (0.00s)2031 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2032 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2033 --- PASS: TestParseSingleRange/single_byte (0.00s)2034 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2035 --- PASS: TestParseSingleRange/suffix (0.00s)2036 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2037 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2038 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2039 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2040 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2041 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2042 --- PASS: TestParseSingleRange/closed (0.00s)2043=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20442026/09/19 11:22:37 INFO Received uploads request method=POST path=/2045=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20462026/09/19 11:22:37 INFO Received complete multipart upload request method=POST path=/2047=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20482026/09/19 11:22:37 INFO Received request for more parts method=POST path=/2049=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20502026/09/19 11:22:37 INFO Received uploads request method=POST path=/2051--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2052 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2053 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2054 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2055 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2056=== CONT TestIsValidUploadKey/narinfo2057=== CONT TestIsValidUploadKey/unknown_type2058=== CONT TestIsValidUploadKey/empty_key2059=== CONT TestIsValidUploadKey/absolute2060=== CONT TestIsValidUploadKey/traversal_nar2061=== CONT TestIsValidUploadKey/traversal2062=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2063=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2064=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2065=== CONT TestIsValidUploadKey/index.html2066=== CONT TestIsValidUploadKey/nix-cache-info2067=== CONT TestIsValidUploadKey/realisation_plus_in_output2068=== CONT TestIsValidUploadKey/realisation2069=== CONT TestIsValidUploadKey/build_log_equals2070=== CONT TestIsValidUploadKey/build_log_question_mark2071=== CONT TestIsValidUploadKey/build_log_plus_in_name2072=== CONT TestIsValidUploadKey/build_log_home-manager_file2073=== CONT TestIsValidUploadKey/build_log2074=== CONT TestIsValidUploadKey/listing2075=== CONT TestIsValidUploadKey/nar_plain2076=== CONT TestIsValidUploadKey/nar_xz2077=== CONT TestIsValidUploadKey/nar_zst2078--- PASS: TestIsValidUploadKey (0.00s)2079 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2080 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2081 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2082 --- PASS: TestIsValidUploadKey/absolute (0.00s)2083 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2084 --- PASS: TestIsValidUploadKey/traversal (0.00s)2085 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2086 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2087 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2088 --- PASS: TestIsValidUploadKey/index.html (0.00s)2089 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2090 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2091 --- PASS: TestIsValidUploadKey/realisation (0.00s)2092 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2093 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2094 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2095 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2096 --- PASS: TestIsValidUploadKey/build_log (0.00s)2097 --- PASS: TestIsValidUploadKey/listing (0.00s)2098 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2099 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2100 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2101=== CONT TestProxyWriteTimeout/narinfo2102=== CONT TestProxyWriteTimeout/10_GiB_nar2103=== CONT TestProxyWriteTimeout/unknown_size2104=== CONT TestProxyWriteTimeout/1_GiB_nar2105--- PASS: TestProxyWriteTimeout (0.00s)2106 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2107 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2108 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2109 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2110=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure21112026/09/19 11:22:37 INFO Received uploads request method=POST path=/21122026/09/19 11:22:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21132026/09/19 11:22:37 OK 20241026095416_initial_model.sql (115.29ms)21142026/09/19 11:22:37 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)21152026/09/19 11:22:37 OK 20251218171726_add_pins.sql (33.43ms)21162026/09/19 11:22:37 OK 20260628120000_add_object_size_and_stats.sql (33.59ms)21172026/09/19 11:22:37 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=YWM2NmJkODAtZDllMS00NmUxLWI3YjQtMWY3NGY5ZDE3MGU1LmFlNDM1NTA4LWMwZTEtNDE5Zi04YzU4LTA3NTMyOTA0MmQ0N3gxNzg5ODE2OTU2MjUzNTcxMDAw parts=1021182026/09/19 11:22:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21192026/09/19 11:22:37 INFO Signed narinfos id=1 count=121202026/09/19 11:22:37 WARN claim: cannot clear write deadline error="feature not supported"21212026/09/19 11:22:37 WARN claim: cannot clear write deadline error="feature not supported"21222026/09/19 11:22:37 WARN claim: cannot clear write deadline error="feature not supported"21232026/09/19 11:22:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21242026/09/19 11:22:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21252026/09/19 11:22:37 OK 20260905000000_add_claims.sql (19.2ms)21262026/09/19 11:22:37 goose: successfully migrated database to version: 2026090500000021272026/09/19 11:22:37 INFO Completed upload id=121282026/09/19 11:22:37 WARN claim: cannot clear write deadline error="feature not supported"2129--- PASS: TestClaim_BuildWaitComplete (2.96s)2130=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts21312026/09/19 11:22:37 INFO Received request for more parts method=POST path=/21322026/09/19 11:22:37 OK 1_commit_pending_closure.sql (6.94ms)21332026/09/19 11:22:37 OK 2_object_stats_trigger.sql (320.25µs)21342026/09/19 11:22:37 goose: up to current file version: 22135=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart21362026/09/19 11:22:37 INFO Received complete multipart upload request method=POST path=/2137--- PASS: TestReadProxyConditionalGet (2.38s)2138=== CONT TestServerTLSConfig/no_client_CA2139=== CONT TestServerTLSConfig/not_a_PEM_file2140=== CONT TestServerTLSConfig/missing_CA_file2141=== CONT TestResolveDBConnectionString/flag_wins2142=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2143=== CONT TestResolveDBConnectionString/nothing_configured2144=== CONT TestResolveDBConnectionString/missing_file_is_an_error2145=== CONT TestResolveDBConnectionString/file_when_flag_empty2146=== CONT TestClientErrorHandling/InvalidStorePath2147--- PASS: TestResolveDBConnectionString (0.01s)2148 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2149 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2150 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2151 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2152 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2153=== CONT TestClientErrorHandling/ServerNotAvailable2154--- PASS: TestServerTLSConfig (0.00s)2155 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2156 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2157 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)2158--- PASS: TestService_ReadScope_PublicByDefault (2.11s)2159=== CONT TestClientErrorHandling/InvalidAuthToken21602026-09-19 11:22:37.861 UTC [97558] ERROR: relation "goose_db_version" does not exist at character 3621612026-09-19 11:22:37.861 UTC [97558] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21622026/09/19 11:22:37 OK 20241026095416_initial_model.sql (20.75ms)21632026/09/19 11:22:37 OK 20251210153512_drop_unused_gin_index.sql (475.71µs)21642026-09-19 11:22:37.892 UTC [97561] ERROR: relation "goose_db_version" does not exist at character 3621652026-09-19 11:22:37.892 UTC [97561] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21662026/09/19 11:22:37 OK 20251218171726_add_pins.sql (2.18ms)21672026/09/19 11:22:37 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)21682026/09/19 11:22:37 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21692026/09/19 11:22:37 OK 20260905000000_add_claims.sql (2.25ms)21702026/09/19 11:22:37 goose: successfully migrated database to version: 2026090500000021712026/09/19 11:22:37 OK 1_commit_pending_closure.sql (1.27ms)21722026/09/19 11:22:37 OK 2_object_stats_trigger.sql (215.29µs)21732026/09/19 11:22:37 goose: up to current file version: 221742026/09/19 11:22:37 OK 20241026095416_initial_model.sql (52.44ms)21752026/09/19 11:22:37 OK 20251210153512_drop_unused_gin_index.sql (945.42µs)21762026/09/19 11:22:37 OK 20251218171726_add_pins.sql (8.98ms)21772026/09/19 11:22:37 OK 20260628120000_add_object_size_and_stats.sql (7.67ms)21782026/09/19 11:22:37 OK 20260905000000_add_claims.sql (8.76ms)21792026/09/19 11:22:37 goose: successfully migrated database to version: 202609050000002180--- PASS: TestUploadHandlersRejectOversizedBody (0.39s)2181 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2182 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)2183 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.48s)2184=== CONT TestCacheConfigHandler/full_config,_no_issuer2185=== CONT TestCacheConfigHandler/no_signing_keys2186=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2187=== CONT TestCacheConfigHandler/no_cache_url_configured2188--- PASS: TestCacheConfigHandler (0.00s)2189 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2190 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2191 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2192 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2193=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token21942026/09/19 11:22:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.583787ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21952026/09/19 11:22:38 INFO OIDC auth successful provider=test scopes=[write]2196=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21972026/09/19 11:22:38 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2198=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2199=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22002026/09/19 11:22:38 WARN Authentication failed token_preview=eyJhbGciOi...78FSgO5XHA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]22012026/09/19 11:22:38 OK 1_commit_pending_closure.sql (2.54ms)2202--- PASS: TestService_AuthMiddleware_OIDC (1.94s)2203 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2204 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2205 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2206 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)22072026/09/19 11:22:38 OK 2_object_stats_trigger.sql (271.25µs)22082026/09/19 11:22:38 goose: up to current file version: 222092026-09-19 11:22:38.070 UTC [97562] ERROR: relation "goose_db_version" does not exist at character 3622102026-09-19 11:22:38.070 UTC [97562] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2211=== RUN TestService_RequireScope_OIDC/builder_may_write2212=== PAUSE TestService_RequireScope_OIDC/builder_may_write2213=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2214=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2215=== RUN TestService_RequireScope_OIDC/ops_may_admin2216=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2217=== RUN TestService_RequireScope_OIDC/ops_may_not_write2218=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2219=== RUN TestService_RequireScope_OIDC/reader_may_not_write2220=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2221=== RUN TestService_RequireScope_OIDC/static_token_may_admin2222=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2223=== RUN TestService_RequireScope_OIDC/static_token_may_write2224=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2225=== RUN TestService_RequireScope_OIDC/reader_may_read2226=== PAUSE TestService_RequireScope_OIDC/reader_may_read2227=== RUN TestService_RequireScope_OIDC/writer_implies_read2228=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2229=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2230=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2231=== CONT TestService_RequireScope_OIDC/builder_may_write2232=== CONT TestService_RequireScope_OIDC/static_token_may_admin2233=== CONT TestService_RequireScope_OIDC/ops_may_not_write22342026/09/19 11:22:38 INFO OIDC auth successful provider=test scopes=[write]22352026/09/19 11:22:38 INFO OIDC auth successful provider=test scopes=[admin]2236=== CONT TestService_RequireScope_OIDC/reader_may_not_write2237=== CONT TestService_RequireScope_OIDC/writer_implies_read22382026/09/19 11:22:38 INFO OIDC auth successful provider=test scopes=[read]2239=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2240=== CONT TestService_RequireScope_OIDC/ops_may_admin22412026/09/19 11:22:38 INFO OIDC auth successful provider=test scopes=[write]2242=== CONT TestService_RequireScope_OIDC/reader_may_read22432026/09/19 11:22:38 INFO OIDC auth successful provider=test scopes=[admin]2244=== CONT TestService_RequireScope_OIDC/builder_may_not_admin22452026/09/19 11:22:38 INFO OIDC auth successful provider=test scopes=[read]2246=== CONT TestService_RequireScope_OIDC/static_token_may_write22472026/09/19 11:22:38 INFO OIDC auth successful provider=test scopes=[write]2248--- PASS: TestService_RequireScope_OIDC (1.58s)2249 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2250 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2251 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2252 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2253 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2254 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2255 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2256 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2257 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2258 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2259--- PASS: TestClaim_HolderDisconnectKeepsClaim (3.81s)22602026/09/19 11:22:38 OK 20241026095416_initial_model.sql (30.29ms)22612026-09-19 11:22:38.121 UTC [97563] ERROR: relation "goose_db_version" does not exist at character 3622622026-09-19 11:22:38.121 UTC [97563] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22632026/09/19 11:22:38 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)22642026/09/19 11:22:38 OK 20251218171726_add_pins.sql (7.51ms)22652026/09/19 11:22:38 OK 20260628120000_add_object_size_and_stats.sql (6.84ms)22662026/09/19 11:22:38 OK 20260905000000_add_claims.sql (14.94ms)22672026/09/19 11:22:38 goose: successfully migrated database to version: 2026090500000022682026/09/19 11:22:38 OK 1_commit_pending_closure.sql (5.19ms)22692026/09/19 11:22:38 OK 2_object_stats_trigger.sql (292.42µs)22702026/09/19 11:22:38 goose: up to current file version: 222712026/09/19 11:22:38 OK 20241026095416_initial_model.sql (58.08ms)22722026/09/19 11:22:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.61661ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22732026/09/19 11:22:38 OK 20251210153512_drop_unused_gin_index.sql (7.72ms)22742026/09/19 11:22:38 OK 20251218171726_add_pins.sql (16.15ms)22752026/09/19 11:22:38 OK 20260628120000_add_object_size_and_stats.sql (9.52ms)22762026/09/19 11:22:38 OK 20260905000000_add_claims.sql (8.33ms)22772026/09/19 11:22:38 goose: successfully migrated database to version: 202609050000002278--- PASS: TestReadProxyHead (1.46s)22792026/09/19 11:22:38 OK 1_commit_pending_closure.sql (8.77ms)22802026/09/19 11:22:38 OK 2_object_stats_trigger.sql (388.79µs)22812026/09/19 11:22:38 goose: up to current file version: 222822026-09-19 11:22:38.251 UTC [97564] ERROR: relation "goose_db_version" does not exist at character 3622832026-09-19 11:22:38.251 UTC [97564] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22842026/09/19 11:22:38 OK 20241026095416_initial_model.sql (53.84ms)22852026/09/19 11:22:38 OK 20251210153512_drop_unused_gin_index.sql (6.75ms)22862026/09/19 11:22:38 OK 20251218171726_add_pins.sql (18.07ms)22872026/09/19 11:22:38 OK 20260628120000_add_object_size_and_stats.sql (25.25ms)22882026/09/19 11:22:38 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"22892026/09/19 11:22:38 WARN mTLS auth: bound subjects configured but subject DN unavailable22902026/09/19 11:22:38 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2291--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.35s)22922026/09/19 11:22:38 OK 20260905000000_add_claims.sql (11.12ms)22932026/09/19 11:22:38 goose: successfully migrated database to version: 2026090500000022942026/09/19 11:22:38 OK 1_commit_pending_closure.sql (3.03ms)22952026/09/19 11:22:38 OK 2_object_stats_trigger.sql (714.46µs)22962026/09/19 11:22:38 goose: up to current file version: 222972026-09-19 11:22:38.403 UTC [97565] ERROR: relation "goose_db_version" does not exist at character 3622982026-09-19 11:22:38.403 UTC [97565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22992026/09/19 11:22:38 OK 20241026095416_initial_model.sql (54.4ms)23002026/09/19 11:22:38 OK 20251210153512_drop_unused_gin_index.sql (8.02ms)23012026/09/19 11:22:38 OK 20251218171726_add_pins.sql (17.44ms)23022026-09-19 11:22:38.500 UTC [97566] ERROR: relation "goose_db_version" does not exist at character 3623032026-09-19 11:22:38.500 UTC [97566] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23042026/09/19 11:22:38 OK 20260628120000_add_object_size_and_stats.sql (9.83ms)2305--- PASS: TestService_ReadAuthMiddleware (1.26s)23062026/09/19 11:22:38 OK 20260905000000_add_claims.sql (16.01ms)23072026/09/19 11:22:38 goose: successfully migrated database to version: 2026090500000023082026/09/19 11:22:38 OK 1_commit_pending_closure.sql (2.73ms)23092026/09/19 11:22:38 OK 2_object_stats_trigger.sql (538.46µs)23102026/09/19 11:22:38 goose: up to current file version: 223112026/09/19 11:22:38 OK 20241026095416_initial_model.sql (28.9ms)23122026/09/19 11:22:38 OK 20251210153512_drop_unused_gin_index.sql (10.07ms)23132026/09/19 11:22:38 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=787.607032ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23142026/09/19 11:22:38 OK 20251218171726_add_pins.sql (10.7ms)23152026/09/19 11:22:38 OK 20260628120000_add_object_size_and_stats.sql (2.94ms)23162026/09/19 11:22:38 OK 20260905000000_add_claims.sql (18.98ms)23172026/09/19 11:22:38 goose: successfully migrated database to version: 2026090500000023182026/09/19 11:22:38 OK 1_commit_pending_closure.sql (2.58ms)23192026/09/19 11:22:38 OK 2_object_stats_trigger.sql (526.83µs)23202026/09/19 11:22:38 goose: up to current file version: 22321--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.20s)23222026/09/19 11:22:38 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23232026/09/19 11:22:38 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"23242026/09/19 11:22:38 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23252026/09/19 11:22:39 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.57591056s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23262026/09/19 11:22:41 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23272026/09/19 11:22:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.065068ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23282026/09/19 11:22:41 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.822337ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23292026/09/19 11:22:41 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=841.852014ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23302026/09/19 11:22:42 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.516119535s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23312026/09/19 11:22:44 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"23322026/09/19 11:22:44 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23332026/09/19 11:22:44 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.638018ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23342026/09/19 11:22:44 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=392.836681ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23352026/09/19 11:22:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=859.523786ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23362026/09/19 11:22:45 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.458207551s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2337--- PASS: TestClientErrorHandling (0.00s)2338 --- PASS: TestClientErrorHandling/InvalidStorePath (1.11s)2339 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.12s)2340 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.53s)2341PASS2342{"timestamp":"2026-09-19T11:22:47.237935Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59213","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1880,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}23432026-09-19 11:22:47.358 UTC [97164] LOG: received smart shutdown request23442026-09-19 11:22:47.368 UTC [97164] LOG: background worker "logical replication launcher" (PID 97174) exited with exit code 123452026-09-19 11:22:47.369 UTC [97169] LOG: shutting down23462026-09-19 11:22:47.369 UTC [97169] LOG: checkpoint starting: shutdown immediate23472026-09-19 11:22:48.657 UTC [97169] LOG: checkpoint complete: wrote 12545 buffers (76.6%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.908 s, sync=0.377 s, total=1.289 s; sync files=21676, longest=0.001 s, average=0.001 s; distance=297028 kB, estimate=297028 kB; lsn=0/1399DF68, redo lsn=0/1399DF6823482026-09-19 11:22:48.672 UTC [97164] LOG: database system is shut down2349Running OIDC tests...2350=== RUN TestGlobMatch2351=== PAUSE TestGlobMatch2352=== RUN TestAudienceForIssuer2353=== PAUSE TestAudienceForIssuer2354=== RUN TestValidateToken_ValidToken2355=== PAUSE TestValidateToken_ValidToken2356=== RUN TestValidateToken_WrongAudience2357=== PAUSE TestValidateToken_WrongAudience2358=== RUN TestValidateToken_Expired2359=== PAUSE TestValidateToken_Expired2360=== RUN TestValidateToken_BoundClaimsMismatch2361=== PAUSE TestValidateToken_BoundClaimsMismatch2362=== RUN TestValidateToken_BoundSubjectMismatch2363=== PAUSE TestValidateToken_BoundSubjectMismatch2364=== RUN TestValidateToken_MultipleProviders2365=== PAUSE TestValidateToken_MultipleProviders2366=== RUN TestValidateToken_NoMatchingProvider2367=== PAUSE TestValidateToken_NoMatchingProvider2368=== RUN TestValidateToken_KubernetesServiceAccount2369=== PAUSE TestValidateToken_KubernetesServiceAccount2370=== RUN TestNewValidator_KubernetesRequiresCA2371=== PAUSE TestNewValidator_KubernetesRequiresCA2372=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2373=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2374=== RUN TestScopes_LegacyProviderDefaultsToWrite2375=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2376=== RUN TestScopes_Rules2377=== PAUSE TestScopes_Rules2378=== RUN TestScopes_ConfigValidation2379=== PAUSE TestScopes_ConfigValidation2380=== CONT TestGlobMatch2381=== RUN TestGlobMatch/foo_foo2382=== CONT TestScopes_LegacyProviderDefaultsToWrite2383=== CONT TestValidateToken_NoMatchingProvider2384=== PAUSE TestGlobMatch/foo_foo2385=== RUN TestGlobMatch/foo_bar2386=== CONT TestValidateToken_MultipleProviders2387=== CONT TestValidateToken_BoundSubjectMismatch2388=== CONT TestValidateToken_BoundClaimsMismatch2389=== CONT TestValidateToken_Expired2390=== CONT TestValidateToken_WrongAudience2391=== CONT TestValidateToken_ValidToken2392=== CONT TestAudienceForIssuer2393--- PASS: TestAudienceForIssuer (0.00s)2394=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2395=== PAUSE TestGlobMatch/foo_bar2396=== RUN TestGlobMatch/*_2397=== PAUSE TestGlobMatch/*_2398=== RUN TestGlobMatch/*_anything2399=== PAUSE TestGlobMatch/*_anything2400=== RUN TestGlobMatch/foo*_foo2401=== PAUSE TestGlobMatch/foo*_foo2402=== RUN TestGlobMatch/foo*_foobar2403=== PAUSE TestGlobMatch/foo*_foobar2404=== RUN TestGlobMatch/foo*_bar2405=== PAUSE TestGlobMatch/foo*_bar2406=== RUN TestGlobMatch/*bar_bar2407=== PAUSE TestGlobMatch/*bar_bar2408=== RUN TestGlobMatch/*bar_foobar2409=== PAUSE TestGlobMatch/*bar_foobar2410=== RUN TestGlobMatch/*bar_foo2411=== PAUSE TestGlobMatch/*bar_foo2412=== RUN TestGlobMatch/foo*bar_foobar2413=== PAUSE TestGlobMatch/foo*bar_foobar2414=== RUN TestGlobMatch/foo*bar_foo123bar2415=== PAUSE TestGlobMatch/foo*bar_foo123bar2416=== RUN TestGlobMatch/foo*bar_foobarbaz2417=== PAUSE TestGlobMatch/foo*bar_foobarbaz2418=== RUN TestGlobMatch/*/*_foo/bar2419=== PAUSE TestGlobMatch/*/*_foo/bar2420=== RUN TestGlobMatch/*/*_foo2421=== PAUSE TestGlobMatch/*/*_foo2422=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2423=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2424=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02425=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02426=== RUN TestGlobMatch/refs/*/main_refs/heads/main2427=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2428=== RUN TestGlobMatch/fo?_foo2429=== PAUSE TestGlobMatch/fo?_foo2430=== RUN TestGlobMatch/fo?_fo2431=== PAUSE TestGlobMatch/fo?_fo2432=== RUN TestGlobMatch/fo?_fooo2433=== PAUSE TestGlobMatch/fo?_fooo2434=== RUN TestGlobMatch/?oo_foo2435=== PAUSE TestGlobMatch/?oo_foo2436=== RUN TestGlobMatch/?oo_boo2437=== PAUSE TestGlobMatch/?oo_boo2438=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2439=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2440=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2441=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2442=== CONT TestScopes_ConfigValidation24432026/09/19 11:22:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59457/oidc24442026/09/19 11:22:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59454/oidc24452026/09/19 11:22:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59450/oidc24462026/09/19 11:22:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59449/oidc2447--- PASS: TestScopes_ConfigValidation (0.00s)2448=== CONT TestValidateToken_KubernetesServiceAccount24492026/09/19 11:22:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59448/oidc24502026/09/19 11:22:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59451/oidc24512026/09/19 11:22:49 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324522026/09/19 11:22:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59452/oidc24532026/09/19 11:22:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59453/oidc24542026/09/19 11:22:49 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59456/oidc2455--- PASS: TestValidateToken_WrongAudience (0.01s)2456=== CONT TestScopes_Rules2457--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2458=== CONT TestNewValidator_KubernetesRequiresCA2459--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2460=== CONT TestGlobMatch/foo_foo2461=== CONT TestGlobMatch/*/*_foo/bar2462=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2463=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2464=== CONT TestGlobMatch/?oo_boo2465=== CONT TestGlobMatch/?oo_foo2466=== CONT TestGlobMatch/fo?_fooo2467--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2468=== CONT TestGlobMatch/fo?_foo2469=== CONT TestGlobMatch/refs/*/main_refs/heads/main2470=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02471=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2472=== CONT TestGlobMatch/*/*_foo2473=== CONT TestGlobMatch/*bar_bar2474=== CONT TestGlobMatch/foo*bar_foobarbaz2475=== CONT TestGlobMatch/foo*bar_foo123bar2476=== CONT TestGlobMatch/foo*bar_foobar2477=== CONT TestGlobMatch/*bar_foo2478=== CONT TestGlobMatch/*bar_foobar2479=== CONT TestGlobMatch/foo*_foo2480=== CONT TestGlobMatch/foo*_bar2481=== CONT TestGlobMatch/foo*_foobar2482=== CONT TestGlobMatch/*_2483=== CONT TestGlobMatch/fo?_fo2484=== CONT TestGlobMatch/*_anything2485=== CONT TestGlobMatch/foo_bar2486--- PASS: TestGlobMatch (0.00s)2487 --- PASS: TestGlobMatch/foo_foo (0.00s)2488 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2489 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2490 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2491 --- PASS: TestGlobMatch/?oo_boo (0.00s)2492 --- PASS: TestGlobMatch/?oo_foo (0.00s)2493 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2494 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2495 --- PASS: TestGlobMatch/fo?_foo (0.00s)2496 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2497 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2498 --- PASS: TestGlobMatch/*/*_foo (0.00s)2499 --- PASS: TestGlobMatch/*bar_bar (0.00s)2500 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2501 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2502 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2503 --- PASS: TestGlobMatch/*bar_foo (0.00s)2504 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2505 --- PASS: TestGlobMatch/foo*_foo (0.00s)2506 --- PASS: TestGlobMatch/foo*_bar (0.00s)2507 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2508 --- PASS: TestGlobMatch/*_ (0.00s)2509 --- PASS: TestGlobMatch/fo?_fo (0.00s)2510 --- PASS: TestGlobMatch/*_anything (0.00s)2511 --- PASS: TestGlobMatch/foo_bar (0.00s)2512--- PASS: TestValidateToken_Expired (0.01s)2513--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2514--- PASS: TestValidateToken_ValidToken (0.01s)25152026/09/19 11:22:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59471/oidc25162026/09/19 11:22:49 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:594662517--- PASS: TestValidateToken_MultipleProviders (0.01s)2518--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2519--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)2520--- PASS: TestScopes_Rules (0.01s)25212026/09/19 11:22:49 http: TLS handshake error from 127.0.0.1:59473: remote error: tls: bad certificate2522--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2523PASS2524Running hook tests...2525=== RUN TestSendPathsEmpty2526=== PAUSE TestSendPathsEmpty2527=== RUN TestQueueEnqueueAndFetch2528=== PAUSE TestQueueEnqueueAndFetch2529=== RUN TestQueueDeduplication2530=== PAUSE TestQueueDeduplication2531=== RUN TestQueueRemove2532=== PAUSE TestQueueRemove2533=== RUN TestQueueFetchBatchLimit2534=== PAUSE TestQueueFetchBatchLimit2535=== RUN TestQueueRetryMovesToBack2536=== PAUSE TestQueueRetryMovesToBack2537=== RUN TestQueueFetchRemoveLifecycle2538=== PAUSE TestQueueFetchRemoveLifecycle2539=== RUN TestQueueConcurrentWriters2540=== PAUSE TestQueueConcurrentWriters2541=== RUN TestQueueRemoveLargeClosure2542=== PAUSE TestQueueRemoveLargeClosure2543=== RUN TestServerClientIntegration2544=== PAUSE TestServerClientIntegration2545=== RUN TestServerQueueError2546=== PAUSE TestServerQueueError2547=== RUN TestGetListenerSocketActivation2548 server_test.go:210: === RUN TestGetListenerSocketActivation2549 --- PASS: TestGetListenerSocketActivation (0.00s)2550 PASS2551 2552--- PASS: TestGetListenerSocketActivation (0.02s)2553=== RUN TestDrainIsolatesPoisonPath2554=== PAUSE TestDrainIsolatesPoisonPath2555=== RUN TestRunNotBlockedByPoisonHead2556=== PAUSE TestRunNotBlockedByPoisonHead2557=== RUN TestDrainGivesUpWhenServerDown2558=== PAUSE TestDrainGivesUpWhenServerDown2559=== RUN TestFailedPathPrunedByLaterClosure2560=== PAUSE TestFailedPathPrunedByLaterClosure2561=== RUN TestWorkerUploadsAndRemoves2562=== PAUSE TestWorkerUploadsAndRemoves2563=== RUN TestWorkerSkipsGCdPaths2564=== PAUSE TestWorkerSkipsGCdPaths2565=== RUN TestWorkerPrunesClosureDeps2566=== PAUSE TestWorkerPrunesClosureDeps2567=== RUN TestDrainTimeout2568=== PAUSE TestDrainTimeout2569=== CONT TestSendPathsEmpty2570--- PASS: TestSendPathsEmpty (0.00s)2571=== CONT TestQueueRemoveLargeClosure2572=== CONT TestDrainTimeout2573=== CONT TestServerClientIntegration2574=== CONT TestWorkerPrunesClosureDeps2575=== CONT TestRunNotBlockedByPoisonHead2576=== CONT TestDrainIsolatesPoisonPath2577=== CONT TestServerQueueError2578=== CONT TestQueueFetchBatchLimit2579=== CONT TestQueueConcurrentWriters2580=== CONT TestQueueFetchRemoveLifecycle25812026/09/19 11:22:50 ERROR Failed to queue paths error="permission denied" count=12582--- PASS: TestServerClientIntegration (0.00s)2583=== CONT TestQueueRetryMovesToBack2584--- PASS: TestServerQueueError (0.00s)2585=== CONT TestWorkerUploadsAndRemoves25862026/09/19 11:22:50 INFO Upload queue status pending=225872026/09/19 11:22:50 INFO Uploading batch count=225882026/09/19 11:22:50 INFO Uploading batch count=225892026/09/19 11:22:50 INFO Upload queue status pending=325902026/09/19 11:22:50 INFO Uploading batch count=425912026/09/19 11:22:50 INFO Uploading batch count=125922026/09/19 11:22:50 ERROR Upload failed error="upload failed" count=425932026/09/19 11:22:50 ERROR Upload failed error="upload failed" count=125942026/09/19 11:22:50 INFO Upload queue status pending=225952026/09/19 11:22:50 INFO Uploading batch count=125962026/09/19 11:22:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97126-2725002786/TestDrainIsolatesPoisonPath80397036/002/bbb25972026/09/19 11:22:50 INFO Uploading batch count=125982026/09/19 11:22:50 ERROR Upload failed error="upload failed" count=12599--- PASS: TestQueueRetryMovesToBack (0.01s)2600=== CONT TestWorkerSkipsGCdPaths26012026/09/19 11:22:50 INFO Uploading batch count=126022026/09/19 11:22:50 ERROR Upload failed error="upload failed" count=126032026/09/19 11:22:50 INFO Uploading batch count=126042026/09/19 11:22:50 ERROR Upload failed error="upload failed" count=12605--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2606=== CONT TestQueueDeduplication26072026/09/19 11:22:50 ERROR Drain finished with paths left in queue remaining=12608--- PASS: TestQueueFetchBatchLimit (0.01s)2609=== CONT TestQueueRemove2610--- PASS: TestDrainIsolatesPoisonPath (0.01s)2611=== CONT TestFailedPathPrunedByLaterClosure26122026/09/19 11:22:50 INFO Upload queue status pending=226132026/09/19 11:22:50 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-97126-2725002786/TestWorkerSkipsGCdPaths1237522454/002/nonexistent26142026/09/19 11:22:50 INFO Uploading batch count=12615--- PASS: TestQueueDeduplication (0.00s)2616=== CONT TestQueueEnqueueAndFetch2617--- PASS: TestQueueRemove (0.00s)2618=== CONT TestDrainGivesUpWhenServerDown26192026/09/19 11:22:50 INFO Uploading batch count=126202026/09/19 11:22:50 ERROR Upload failed error="upload failed" count=12621--- PASS: TestQueueEnqueueAndFetch (0.00s)26222026/09/19 11:22:50 INFO Uploading batch count=126232026/09/19 11:22:50 INFO Uploading batch count=126242026/09/19 11:22:50 INFO Uploading batch count=226252026/09/19 11:22:50 ERROR Upload failed error="upload failed" count=226262026/09/19 11:22:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97126-2725002786/TestDrainGivesUpWhenServerDown2628280858/002/a26272026/09/19 11:22:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97126-2725002786/TestDrainGivesUpWhenServerDown2628280858/002/b26282026/09/19 11:22:50 INFO Uploading batch count=226292026/09/19 11:22:50 ERROR Upload failed error="upload failed" count=226302026/09/19 11:22:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97126-2725002786/TestDrainGivesUpWhenServerDown2628280858/002/c26312026/09/19 11:22:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97126-2725002786/TestDrainGivesUpWhenServerDown2628280858/002/d26322026/09/19 11:22:50 INFO Uploading batch count=226332026/09/19 11:22:50 ERROR Upload failed error="upload failed" count=226342026/09/19 11:22:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97126-2725002786/TestDrainGivesUpWhenServerDown2628280858/002/e26352026/09/19 11:22:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97126-2725002786/TestDrainGivesUpWhenServerDown2628280858/002/f2636--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)26372026/09/19 11:22:50 ERROR Drain finished with paths left in queue remaining=102638--- PASS: TestDrainGivesUpWhenServerDown (0.00s)2639--- PASS: TestWorkerUploadsAndRemoves (0.03s)2640--- PASS: TestWorkerPrunesClosureDeps (0.03s)2641--- PASS: TestWorkerSkipsGCdPaths (0.02s)2642--- PASS: TestQueueRemoveLargeClosure (0.05s)2643--- PASS: TestQueueConcurrentWriters (0.12s)26442026/09/19 11:22:50 ERROR Upload failed error="context deadline exceeded" count=226452026/09/19 11:22:50 ERROR Drain finished with paths left in queue remaining=42646--- PASS: TestDrainTimeout (0.21s)26472026/09/19 11:22:51 INFO Uploading batch count=126482026/09/19 11:22:51 INFO Uploading batch count=126492026/09/19 11:22:51 INFO Uploading batch count=126502026/09/19 11:22:51 ERROR Upload failed error="upload failed" count=126512026/09/19 11:22:51 INFO Uploading batch count=126522026/09/19 11:22:51 ERROR Upload failed error="upload failed" count=126532026/09/19 11:22:51 INFO Uploading batch count=126542026/09/19 11:22:51 ERROR Upload failed error="upload failed" count=126552026/09/19 11:22:51 INFO Uploading batch count=126562026/09/19 11:22:51 ERROR Upload failed error="upload failed" count=126572026/09/19 11:22:51 ERROR Drain finished with paths left in queue remaining=12658--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2659PASS